[OpenSIPS-Users] Users Digest, Vol 37, Issue 33

Wed Aug 24 11:37:17 CEST 2011

Hi

I've been changing the tcp-related things in my cfg file and rebuilding
opensips-1.7+tls (downloaded from opensips release directory, and from
svn) but the problem is still there - TCP connection broken after
server's sent just 1 message back to the sip client.

 * I was using the same SIP clients to test 1.6.4+tls and 1.7+tls, and
they work on 1.6.4_tls but not 1.7+tls
 * The same cfg file (with the necessary migrations) that worked on
opensips 1.6.4+tls was used but 1.7+tls just doesn't work
 * As soon as I removed opensips 1.7+tls and reinstalled 1.6.4+tls,
everything worked again. So the problem is not to do with my host
 * I built my debian packages using:
  $ make all TLS=1, then
  $ make deb TLS=1

I'm wondering if it is to do with the changes in 1.7 tcp layer? Are
there other things I need to add/modify in my cfg file to use 1.7 tls?
Has anyone succeeded in using opensips 1.7+tls on registrations/calls?
I'm lost where to look and would highly appreciate any suggestions!

Yufei

On 17/08/11 17:49, users-request at lists.opensips.org wrote:
> Hi Vlad
>
> Thanks very much for your response to my problems 2 and 3 - and they're
> solved :)
>
> About my problem 1: Registrations over TLS doesn't work on opensips 1.7:
> so far it seems the server can only successfully send one message back
> to the client and fail on sending the second:
>
> 1. In my route[register] that processes registrations, if I use
> sl_send_reply("100", "Trying"), then the process is:
>    initial REGISTER ---->
>    <--------- 100 -------
> Then server will then fail to send 401.
>
> 2. If I remove sl_send_reply("100", "Trying"), the process is:
>  --- initial REGISTER ---->
>  <---- 401 challenge -----
>  --- REGISTER+auth ------->
> Then server thinks the registration was successful and put it in the
> location table fine, but failed to send OK back to client. I've got a
> log with debug=6 that shows things since the success of authorization:
>
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27699]:
> DBG:auth:check_response: authorization is OK
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27699]:
> DBG:core:db_free_columns: freeing result columns at 0x8241630
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27699]:
> DBG:core:db_free_rows: freeing 1 rows
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27699]: DBG:core:db_free_row:
> freeing row values at 0x82403cc
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27699]:
> DBG:core:db_free_rows: freeing rows at 0x82403c4
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27699]:
> DBG:core:db_free_result: freeing result set at 0x824034c
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27699]:
> MY-DBUG:REGISTER:REGISTERED: user at myserver.com, cseq=2
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27699]:
> DBG:core:parse_headers: flags=ffffffffffffffff
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27699]:
> DBG:core:parse_headers: flags=8000000
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27699]:
> DBG:core:parse_headers: flags=ffffffffffffffff
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27699]:
> DBG:registrar:build_contact: created Contact HF: Contact:
> <sip:user at 127.0.1.1:5060>;expires=60;received="sip:10.82.131.132:16689;transport=TLS"^M
>
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27699]:
> DBG:core:parse_headers: flags=ffffffffffffffff
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27699]:
> DBG:core:check_ip_address: params 10.82.131.132, 127.0.1.1, 0
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27699]:
> DBG:sl:run_sl_callbacks: callback id 1 entered
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27699]:
> DBG:siptrace:trace_sl_onreply_out: trace off...
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27699]:
> DBG:sl:run_sl_callbacks: callback id 0 entered
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27699]: DBG:core:tcp_send:
> tcp connection found (0xa79246f8), acquiring fd
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27762]:
> DBG:core:handle_ser_child: read response= a79246f8, 1, fd -1 from 39
> (27699)
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27699]: DBG:core:tcp_send: c=
> 0xa79246f8, n=8
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27699]: DBG:core:tcp_send:
> after receive_fd: c= 0xa79246f8 n=4 fd=52
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27699]: DBG:core:tcp_send:
> sending...
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27699]:
> DBG:core:tls_update_fd: New fd is 52
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27699]: ERROR:core:tls_write:
> something wrong in SSL:
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27699]:
> ERROR:core:tls_blocking_write: failed to send data
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27699]:
> ERROR:core:tsend_stream: tsend_stream: failed to send: (32) Broken pipe
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27699]: DBG:core:tcp_send:
> after write: c= 0xa79246f8 n=-1 fd=52
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27699]: DBG:core:tcp_send:
> buf= SIP/2.0 200 OK^M Via: SIP/2.0/TLS
> 127.0.1.1:5060;branch=z9hG4bK-13722-1-3;rport=16689;received=10.82.131.132^M
> From: user <sip:user at myserver.com:5060>;tag=1^M To: user
> <sip:user at myserver.com>;tag=4d01edab9105ba9cff8de765aa181a6e.e2bb^M
> Call-ID: 1-13722 at 127.0.1.1^M CSeq: 2 REGISTER^M Contact:
> <sip:user at 127.0.1.1:5060>;expires=60;received="sip:10.82.131.132:16689;transport=TLS"^M
> Server: OpenSIPS (1.7.0-beta-tls (i386/linux))^M Content-Length: 0^M ^M
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27699]: ERROR:core:tcp_send:
> failed to send
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27762]:
> DBG:core:handle_ser_child: read response= a79246f8, -2, fd -1 from 39
> (27699)
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27762]:
> DBG:core:tcpconn_destroy: delaying (0xa79246f8, flags 0002) ...
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27699]: ERROR:sl:msg_send:
> tcp_send failed
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27699]:
> ERROR:signaling:sig_send_reply_mod: failed to send reply with sl module
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27699]:
> ERROR:registrar:send_reply: failed to send 200 OK
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27699]:
> DBG:core:destroy_avp_list: destroying list 0xa794a198
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27699]: DBG:core:receive_msg:
> cleaning up
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27699]:
> DBG:core:io_watch_del: io_watch_del (0x8168f20, 51, -1, 0x10) fd_no=2
> called
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27699]:
> DBG:core:release_tcpconn:  releasing con 0xa79246f8, state -2, fd=51, id=19
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27699]:
> DBG:core:release_tcpconn:  extra_data 0xa7934814
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27762]:
> DBG:core:handle_tcp_child: reader response= a79246f8, -2 from 0
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27762]:
> DBG:core:tcpconn_destroy: destroying connection 0xa79246f8, flags 0002
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27762]: DBG:core:tls_close:
> closing SSL connection
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27762]:
> DBG:core:tls_update_fd: New fd is 112
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27762]:
> DBG:core:tls_shutdown: first phase of 2-way handshake completed succesfuly
> Aug 17 10:21:07 server2 /usr/sbin/opensips[27762]:
> DBG:core:tls_tcpconn_clean: entered
> Aug 17 10:21:19 server2 /usr/sbin/opensips[27681]:
> DBG:core:udp_rcv_loop: probing packet received len = 2
>
> Any suggestions where I should look? Thanks very much!
>
> Yufei
>
>

--
Yufei Tao
Red Embedded

This E-mail and any attachments hereto are strictly confidential and intended solely for the addressee. If you are not the intended addressee please notify the sender by return and delete the message.

You must not disclose, forward or copy this E-mail or attachments to any third party without the prior consent of the sender.

Red Embedded Design, Company Number 06688253 Registered in England: The Waterfront, Salts Mill Rd, Saltaire, BD17 7EZ