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:[email protected]] Sent: Friday, June 19, 2009 5:59 AM To: 'Bogdan-Andrei Iancu' Cc: '[email protected]' 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:[email protected]} 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:[email protected];user=phone} Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]: DBG:core:get_hdr_field: <To> [86]; uri=[sip:[email protected];user=phone] Jun 17 03:41:23 sip-proxy-dev2 /usr/sbin/opensips[2103]: DBG:core:get_hdr_field: to body [<sip:[email protected];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:[email protected]: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:[email protected]>;tag=Test_3270532536-328912^M To: <sip:[email protected];user=phone>;tag=772432463135364100001 E34^M Call-ID: [email protected]^m CSeq: 2 INVITE^M Min-SE: 10^M Contact: <sip:[email protected]: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:[email protected]] Sent: Wednesday, June 10, 2009 2:12 PM To: Anil M Pannikode (hotmail) Cc: [email protected] 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:* [email protected] > [mailto:[email protected]] *On Behalf Of *Anil M > Pannikode (hotmail) > *Sent:* Wednesday, June 03, 2009 10:01 AM > *To:* [email protected] > *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 > [email protected] > http://lists.opensips.org/cgi-bin/mailman/listinfo/users > _______________________________________________ Users mailing list [email protected] http://lists.opensips.org/cgi-bin/mailman/listinfo/users
