[OpenSIPS-Users] SIP CLient <- TLS --> OpenSIPS <- UDP -> SIP Server
Anil M Pannikode
anil.pannikode at sympatico.ca
Fri Jun 19 23:14:40 CEST 2009
Looks like this is a bug / timing issue in OpenSIPS.
In "tls_server.c" , function 'tls_blocking_write'
If I change the
#define MAX_SSL_RETRIES 32
to
#define MAX_SSL_RETRIES 320
The connection succeeds and it works. I added a few log lines and it looks
like
n = poll(&pf, 1, timeout);
is returning straight away without actually waiting for timeout (revents set
to 4) and the retries count exceeds 32 and the call fails.
It is almost like it did not have enough time to receive the response.
I am running OpenSIPS on a VM.
I don't think this is the correct way to fix this issue. I will leave it to
experts to handle.
Regards
Anil
-----Original Message-----
From: Anil M Pannikode (hotmail) [mailto:anilpannikode at hotmail.com]
Sent: Friday, June 19, 2009 5:59 AM
To: 'Bogdan-Andrei Iancu'
Cc: 'users at lists.opensips.org'
Subject: RE: [OpenSIPS-Users] SIP CLient <- TLS --> OpenSIPS <- UDP -> SIP
Server
We are still not able to get TLS working. The OpsnSIPS logs shows the
following
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]: DBG:core:parse_to:
display={"Anonymous"}, ruri={sip:Anonymous at sip1.mydomain.com}
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]: Method : INVITE
from 10.10.20.246 fd sip1.mydomain.com
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]:
DBG:maxfwd:is_maxfwd_present: value = 70
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]: DBG:tm:t_newtran:
transaction on entrance=0xffffffff
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]:
DBG:core:parse_headers: flags=ffffffffffffffff
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]:
DBG:core:parse_to_param: tag=772432463135364100001E34
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]: DBG:core:parse_to:
end of header reached, state=29
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]: DBG:core:parse_to:
display={}, ruri={sip:9999999999 at IPGateway.mydomain.com;user=phone}
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]:
DBG:core:get_hdr_field: <To> [86];
uri=[sip:9999999999 at IPGateway.mydomain.com;user=phone]
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]:
DBG:core:get_hdr_field: to body
[<sip:9999999999 at IPGateway.mydomain.com;user=phone>]
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]:
DBG:core:get_hdr_field: cseq <CSeq>: <2> <INVITE>
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]:
DBG:core:get_hdr_field: content_length=401
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]:
DBG:core:get_hdr_field: found end of header
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]:
DBG:core:parse_headers: flags=78
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]:
DBG:tm:t_lookup_request: start searching: hash=39696, isACK=0
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]:
DBG:tm:matching_3261: RFC3261 transaction matching failed
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]:
DBG:tm:t_lookup_request: no transaction found
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]:
DBG:tm:run_reqin_callbacks: trans=0xb40250e8, callback type 1, id 0 entered
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]:
DBG:core:parse_headers: flags=ffffffffffffffff
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]:
DBG:core:check_via_address: params 10.10.20.246, 10.10.20.246, 0
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]:
DBG:core:_shm_resize: resize(0) called
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]:
DBG:tm:_reply_light: reply sent out. buf=0x82a30c0: SIP/2.0 1...,
shmem=0xb40141c8: SIP/2.0 1
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]:
DBG:tm:_reply_light: finished
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]: DBG:core:mk_proxy:
doing DNS lookup...
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]:
DBG:core:parse_headers: flags=2000
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]: DBG:core:tcp_send:
no open tcp connection found, opening new one
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]: DBG:core:print_ip:
tcpconn_new: new tcp connection to: 10.10.20.206
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]:
DBG:core:tcpconn_new: on port 5061, type 3
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]:
DBG:core:tls_tcpconn_init: entered: Creating a whole new ssl connection
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]:
DBG:core:tls_tcpconn_init: TLS client domain AVP found = 'sip1.mydomain.com'
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]:
DBG:core:tls_find_client_domain_name: virtual TLS client domain found
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]:
DBG:core:tls_tcpconn_init: found name based TLS client domain
'sip1.mydomain.com'
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]:
DBG:core:tls_tcpconn_init: Setting in CONNECT mode (client)
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]: DBG:core:tcp_send:
sending...
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]:
DBG:core:tls_update_fd: New fd is 8
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]:
ERROR:core:tls_blocking_write: too many retries with no operation
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]: DBG:core:tcp_send:
after write: c= 0xb40284d8 n=-1 fd=8
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2114]:
DBG:core:handle_ser_child: read response= b40284d8, 2, fd 25 from 1 (2103)
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2114]:
DBG:core:tcpconn_add: hashes: 463, 36
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2114]:
DBG:core:io_watch_add: io_watch_add(0x826a9c0, 25, 2, 0xb40284d8), fd_no=17
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]: DBG:core:tcp_send:
buf= INVITE sip:9999999999 at 10.10.20.206:5061;transport=tls SIP/2.0^M Via:
SIP/2.0/TLS 10.10.10.193:5061;branch=z9hG4bK01b9.1a760103.0^M Via:
SIP/2.0/UDP
10.10.20.246:5060;received=10.10.20.246;rport=5060;branch=z9hG4bK3270876536-
394448^M Route:
<sip:10.10.10.193;r2=on;lr=on>,<sip:10.10.10.193:5061;transport=tls;r2=on;lr
=on>^M Max-Forwards: 69^M Allow:
SUBSCRIBE,NOTIFY,REFER,INVITE,ACK,OPTIONS,CANCEL,BYE^M Supported:
timer,replaces,TIMER^M From: "Anonymous"
<sip:Anonymous at sip1.mydomain.com>;tag=Test_3270532536-328912^M To:
<sip:9999999999 at IPGateway.mydomain.com;user=phone>;tag=772432463135364100001
E34^M Call-ID: 01B2270F8E81400000000029 at IPGateway.mydomain.com^M CSeq: 2
INVITE^M Min-SE: 10^M Contact: <sip:Test at 10.10.20.246:5060>^M Content-Type:
application/sdp^M Content-Length: 401^M ^M v=0^M o=Test 256 3 IN IP4
10.10.20.246^M s=SipSession with Test^M i=Test^M u=http://www.Test.com^M
c=IN IP4 10.10.20.246^M t=0 0^M
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]:
ERROR:core:tcp_send: failed to send
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]: ERROR:tm:msg_send:
tcp_send failed
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]:
ERROR:tm:t_forward_nonack: sending request failed
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]: DBG:tm:t_relay_to:
t_forward_nonack returned error
Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]:
DBG:core:parse_headers: flags=ffffffffffffffff
Based on the wireshark traces.
- OpenSIPS sends a 'Client Helo' to Gateway
- Before it receives the 'Server Helo' back , it is sending '477 Send
failed' back to Media gateway.
- Gateway sends 'Server Helo' back to OpenSIPS.
In the config I have set the following values
tls_handshake_timeout=60
tls_send_timeout=60
However it looks like the OpenSIPS is returning failure way too early (in
less than 1 second)
And there are no firewalls between these two servers.
Any help will be appreciated.
Regards
Anil
-----Original Message-----
From: Bogdan-Andrei Iancu [mailto:bogdan at voice-system.ro]
Sent: Wednesday, June 10, 2009 2:12 PM
To: Anil M Pannikode (hotmail)
Cc: users at lists.opensips.org
Subject: Re: [OpenSIPS-Users] SIP CLient <- TLS --> OpenSIPS <- UDP -> SIP
Server
Hi Anil,
The error you get means opensips is unable to send the message out -
typically this means so OS / network related issue. Like the connection
could not be established because firewall, nat, etc...
Is the client where opensips tries to connect to behind a nat?
Regards,
Bogdan
Anil M Pannikode (hotmail) wrote:
>
> Here are the log files from opensips server.
>
> Jun 5 16:24:45 pc10-10-10-193 /usr/sbin/opensips[7162]:
> DBG:core:tcp_send: no open tcp connection found, opening new one
>
> Jun 5 16:24:45 pc10-10-10-193 /usr/sbin/opensips[7162]:
> DBG:core:print_ip: tcpconn_new: new tcp connection to: 10.10.20.206
>
> Jun 5 16:24:45 pc10-10-10-193 /usr/sbin/opensips[7162]:
> DBG:core:tcpconn_new: on port 5061, type 3
>
> Jun 5 16:24:45 pc10-10-10-193 /usr/sbin/opensips[7162]:
> DBG:core:tls_tcpconn_init: entered: Creating a whole new ssl connection
>
> Jun 5 16:24:45 pc10-10-10-193 /usr/sbin/opensips[7162]:
> DBG:core:tls_tcpconn_init: name based TLS client domains are disabled
>
> Jun 5 16:24:45 pc10-10-10-193 /usr/sbin/opensips[7162]:
> DBG:core:tls_tcpconn_init: no TLS client doman AVP set, looking for
> socket based TLS client domain
>
> Jun 5 16:24:45 pc10-10-10-193 /usr/sbin/opensips[7162]:
> DBG:core:tls_find_client_domain: virtual TLS client domain not found,
> Using default TLS client domain settings
>
> Jun 5 16:24:45 pc10-10-10-193 /usr/sbin/opensips[7162]:
> DBG:core:tls_tcpconn_init: found socket based TLS client domain
> [0.0.0.0:0]
>
> Jun 5 16:24:45 pc10-10-10-193 /usr/sbin/opensips[7162]:
> DBG:core:tls_tcpconn_init: Setting in CONNECT mode (client)
>
> Jun 5 16:24:45 pc10-10-10-193 /usr/sbin/opensips[7172]:
> DBG:core:handle_ser_child: read response= b3f5b400, 2, fd 25 from 2
> (7162)
>
> Jun 5 16:24:45 pc10-10-10-193 /usr/sbin/opensips[7172]:
> DBG:core:tcpconn_add: hashes: 463, 2
>
> Jun 5 16:24:45 pc10-10-10-193 /usr/sbin/opensips[7172]:
> DBG:core:io_watch_add: io_watch_add(0x826a9c0, 25, 2, 0xb3f5b400),
> fd_no=17
>
> *Jun 5 16:24:45 pc10-10-10-193 /usr/sbin/opensips[7162]:
> DBG:core:tcp_send: sending... *
>
> *Jun 5 16:24:45 pc10-10-10-193 /usr/sbin/opensips[7162]:
> DBG:core:tls_update_fd: New fd is 9 *
>
> *Jun 5 16:24:45 pc10-10-10-193 /usr/sbin/opensips[7162]:
> ERROR:core:tls_blocking_write: too many retries with no operation *
>
> *Jun 5 16:24:45 pc10-10-10-193 /usr/sbin/opensips[7162]:
> DBG:core:tcp_send: after write: c= 0xb3f5b400 n=-1 fd=9 *
>
> * *
>
> * *
>
> Wireshark shows "SSL Client helo" to server and "SSL Server helo" back
> from server.
>
> Is there a way to get more detailed error on the SSL Issues ?
>
> Anil
>
> *From:* users-bounces at lists.opensips.org
> [mailto:users-bounces at lists.opensips.org] *On Behalf Of *Anil M
> Pannikode (hotmail)
> *Sent:* Wednesday, June 03, 2009 10:01 AM
> *To:* users at lists.opensips.org
> *Subject:* [OpenSIPS-Users] SIP CLient <- TLS --> OpenSIPS <- UDP ->
> SIP Server
>
> I am having the same issue as the following email which I found in the
> archive, Do we know if there is solution to this issue ? I tried the
> suggested solution , however still not working.
>
> Anil
>
> *Bogdan-Andrei Iancu* bogdan at voice-system.ro
>
<mailto:users%40lists.opensips.org?Subject=%5BOpenSIPS-Users%5D%20Problem%20
in%20sending%20outbound%20SIP%20messages%20via%0A%20TLS&In-Reply-To=c443f41b
0808200558x3bb41aaft33d6c6a45aa7d9b%40mail.gmail.com>
> /Sun Aug 31 01:10:56 CEST 2008/
>
> * Previous message: [OpenSIPS-Users] Problem in sending outbound
> SIP messages via TLS
> <http://www.openser.org/pipermail/users/2008-August/000193.html>
> * Next message: [OpenSIPS-Users] Simple question: Asterisk with
> Zoiper (no sound).
> <http://www.openser.org/pipermail/users/2008-August/000194.html>
> * *Messages sorted by:* [ date ]
> <http://www.openser.org/pipermail/users/2008-August/date.html#369>
> [ thread ]
> <http://www.openser.org/pipermail/users/2008-August/thread.html#369>
> [ subject ]
>
<http://www.openser.org/pipermail/users/2008-August/subject.html#369>
> [ author ]
> <http://www.openser.org/pipermail/users/2008-August/author.html#369>
>
>
> ------------------------------------------------------------------------
> Hi,
>
> have you tried with:
>
> tls_verify_server = 0
> tls_verify_client = 0
> tls_require_client_certificate = 0
>
> Regards,
> Bogdan
>
> Nachiket Tarate wrote:
> >/ /
> >/ Hi,/
> >/ /
> >/ I am currently trying to make Secure RTP calls between my SIP client /
> >/ and the eyeBeam. When eyeBeam is configured for encrypted calls, it /
> >/ uses Secure RTP for media and TLS for SIP signalling./
> >/ /
> >/ I have configured the OpenSIPs server with TLS support./
> >/ /
> >/ The scenario is as shown below:/
> >/ /
> >/ /
> >/ ---------------- UDP ------------------ TLS
-------------/
> >/ | My SIP Client | <-----> | OpenSIPs Server | <-----> | eyeBeam 1.5
|/
> >/ ---------------- ------------------
-------------/
> >/ Linux Machine Linux Machine Widows XP /
> >/ machine/
> >/ /
> >/ When a call is made from eyeBeam to My SIP client the call gets /
> >/ established properly and the OpenSIPs server acts as a gateway./
> >/ /
> >/ But when a call is made from My SIP client to eyeBeam the OpenSIPs /
> >/ returns the *477 Send failed* response to My SIP client./
> >/ /
> >/ By enabling the debug informaiton on OpenSIPs server, I found that it /
> >/ couldn't do TLS handshake with the eyeBeam and so couldn't send the /
> >/ SIP Request from My SIP client to the eyeBeam./
> >/ /
> >/ In brief the OpenSIPs server can accept the inbound messages via TLS /
> >/ but *it can't send outbound messages via TLS*./
> >/ /
> >/ Can anybody help me to resolve this problem? Please see my /
> >/ opensips.cfg file and OpenSIPs server logs attached with this mail./
> >/ /
> >/ Thanks,/
> >/ NT/
> >/ /
> >/ /
> >/
------------------------------------------------------------------------/
> >/ /
> >/ _______________________________________________/
> >/ Users mailing list/
> >/ Users at lists.opensips.org
<http://lists.opensips.org/cgi-bin/mailman/listinfo/users>/
> >/ http://lists.opensips.org/cgi-bin/mailman/listinfo/users/
>
>
> ------------------------------------------------------------------------
>
> * Previous message: [OpenSIPS-Users] Problem in sending outbound
> SIP messages via TLS
> <http://www.openser.org/pipermail/users/2008-August/000193.html>
> * Next message: [OpenSIPS-Users] Simple question: Asterisk with
> Zoiper (no sound).
> <http://www.openser.org/pipermail/users/2008-August/000194.html>
> * *Messages sorted by:* [ date ]
> <http://www.openser.org/pipermail/users/2008-August/date.html#369>
> [ thread ]
> <http://www.openser.org/pipermail/users/2008-August/thread.html#369>
> [ subject ]
>
<http://www.openser.org/pipermail/users/2008-August/subject.html#369>
> [ author ]
> <http://www.openser.org/pipermail/users/2008-August/author.html#369>
>
>
> ------------------------------------------------------------------------
>
> More information about the Users mailing list
> <http://lists.opensips.org/cgi-bin/mailman/listinfo/users>
>
> ------------------------------------------------------------------------
>
> _______________________________________________
> Users mailing list
> Users at lists.opensips.org
> http://lists.opensips.org/cgi-bin/mailman/listinfo/users
>
More information about the Users
mailing list