[OpenSIPS-Users] Unexpected Dispatcher TLS interaction
Bogdan-Andrei Iancu
bogdan at opensips.org
Mon Apr 8 18:45:05 CEST 2013
Those are not errors :) - there are the logs I added to debug the issue
(they were added by my patch).
I will push the fix on SVN, so revert my patch and update from SVN - it
should work like a charm after that.
Thanks and regards,
Bogdan-Andrei Iancu
OpenSIPS Founder and Developer
http://www.opensips-solutions.com
On 04/08/2013 07:42 PM, John Quick wrote:
> Calls now work ok, but there are a lot of errors reported, all the time -
> not just when I call. Perhaps connected with keep-alives?
>
> 2013-04-08 17:37:53 ERROR:core:get_send_socket: current binding is
> 0x7fa98a9a03f0, proto 1
> 2013-04-08 17:37:53 ERROR:core:msg_send: received socket is 0x7fa98a9a03f0,
> proto 1, required proto is 1
> 2013-04-08 17:37:53 ERROR:core:msg_send: selected socket is 0x7fa98a9a03f0,
> proto 1
> 2013-04-08 17:37:58 ERROR:tm:msg_send: received socket is 0x7fa98a9a0228,
> proto 3, required proto is 3
> 2013-04-08 17:37:58 ERROR:tm:msg_send: selected socket is 0x7fa98a9a0228,
> proto 3
> 2013-04-08 17:37:58 ERROR:tm:msg_send: received socket is 0x7fa98a9a03f0,
> proto 1, required proto is 1
> 2013-04-08 17:37:58 ERROR:tm:msg_send: selected socket is 0x7fa98a9a03f0,
> proto 1
> 2013-04-08 17:38:21 ERROR:sl:msg_send: received socket is 0x7fa98a9a03f0,
> proto 1, required proto is 1
> 2013-04-08 17:38:21 ERROR:sl:msg_send: selected socket is 0x7fa98a9a03f0,
> proto 1
> 2013-04-08 17:38:57 ERROR:sl:msg_send: received socket is 0x7fa98a9a03f0,
> proto 1, required proto is 1
> 2013-04-08 17:38:57 ERROR:sl:msg_send: selected socket is 0x7fa98a9a03f0,
> proto 1
> 2013-04-08 17:39:33 ERROR:sl:msg_send: received socket is 0x7fa98a9a03f0,
> proto 1, required proto is 1
> 2013-04-08 17:39:33 ERROR:sl:msg_send: selected socket is 0x7fa98a9a03f0,
> proto 1
>
> John
>
>
> -----Original Message-----
> From: Bogdan-Andrei Iancu [mailto:bogdan at opensips.org]
> Sent: 08 April 2013 16:44
> To: john.quick at smartvox.co.uk
> Cc: 'OpenSIPS users mailling list'
> Subject: Re: [OpenSIPS-Users] Unexpected Dispatcher TLS interaction
>
> Hello John,
>
> Thanks for the info - found the problem. Revert the prev patch and apply
> this one (which also contains the patch). Please have it tested.
>
> Regards,
>
> Bogdan-Andrei Iancu
> OpenSIPS Founder and Developer
> http://www.opensips-solutions.com
>
>
> On 04/08/2013 05:16 PM, John Quick wrote:
>> Hi Bogdan,
>>
>> Here is the extra output with your patch:
>> 2013-04-08 15:13:41 INFO:core:probe_max_sock_buff: using snd buffer
>> of 255 kb
>> 2013-04-08 15:13:41 INFO:core:init_sock_keepalive: -- TCP keepalive
>> enabled on socket
>> 2013-04-08 15:13:41 INFO:core:tls_accept: New TLS connection from
>> 81.104.44.9:2105 accepted
>> 2013-04-08 15:13:41 INFO:core:tls_accept: Client did not present a
>> TLS certificate
>> 2013-04-08 15:13:41 INFO:core:tls_dump_cert_info: tls_accept: local
>> TLS server certificate subject: /C=GB/ST=Hertfordshire/O=Smartvox
> Limited/.....
>> 2013-04-08 15:13:41 ERROR:sl:msg_send: received socket is
>> 0x7f5b485c3228, proto 3, required proto is 3
>> 2013-04-08 15:13:41 ERROR:sl:msg_send: selected socket is
>> 0x7f5b485c3228, proto 3
>> 2013-04-08 15:13:41 ERROR:sl:msg_send: received socket is
>> 0x7f5b485c3228, proto 3, required proto is 3
>> 2013-04-08 15:13:41 ERROR:sl:msg_send: selected socket is
>> 0x7f5b485c3228, proto 3
>> 2013-04-08 15:13:45 ERROR:sl:msg_send: received socket is
>> 0x7f5b485c3228, proto 3, required proto is 3
>> 2013-04-08 15:13:45 ERROR:sl:msg_send: selected socket is
>> 0x7f5b485c3228, proto 3
>> 2013-04-08 15:13:45 ERROR:tm:msg_send: received socket is
>> 0x7f5b485c3228, proto 3, required proto is 3
>> 2013-04-08 15:13:45 ERROR:tm:msg_send: selected socket is
>> 0x7f5b485c3228, proto 3
>> 2013-04-08 15:13:46 ERROR:core:get_send_socket: current binding is
>> 0x7f5b485c3228, proto 3
>> 2013-04-08 15:13:46 ERROR:core:get_send_socket: default UDP selected
>> 2013-04-08 15:13:46 ERROR:tm:msg_send: received socket is
>> 0x7f5b485c33f0, proto 1, required proto is 1
>> 2013-04-08 15:13:46 ERROR:tm:msg_send: selected socket is
>> 0x7f5b485c33f0, proto 1
>> 2013-04-08 15:13:46 ERROR:tm:msg_send: received socket is
>> 0x7f5b485c33f0, proto 1, required proto is 1
>> 2013-04-08 15:13:46 ERROR:tm:msg_send: selected socket is
>> 0x7f5b485c33f0, proto 1
>> 2013-04-08 15:13:46 ERROR:core:get_send_socket: current binding is
>> 0x7f5b485c33f0, proto 1
>> 2013-04-08 15:13:46 ERROR:tm:msg_send: received socket is
>> 0x7f5b485c3228, proto 3, required proto is 1
>> 2013-04-08 15:13:46 ERROR:tm:msg_send: selected socket is
>> 0x7f5b485c3228, proto 3
>> 2013-04-08 15:13:46 ERROR:core:udp_send:
>> sendto(sock,0x7f5b350454d0,1261,0,0x7f5b350418b8,16): Broken pipe(32)
>> 2013-04-08 15:13:46 ERROR:tm:msg_send: udp_send failed
>> 2013-04-08 15:13:46 ERROR:tm:t_forward_nonack: sending request failed
>> 2013-04-08 15:13:46 ERROR:tm:w_t_relay: t_forward_nonack failed
>> 2013-04-08 15:13:46 ERROR:sl:msg_send: received socket is
>> 0x7f5b485c3228, proto 3, required proto is 3
>> 2013-04-08 15:13:46 ERROR:sl:msg_send: selected socket is
>> 0x7f5b485c3228, proto 3
>> 2013-04-08 15:13:46 ERROR:tm:msg_send: received socket is
>> 0x7f5b485c3228, proto 3, required proto is 3
>> 2013-04-08 15:13:46 ERROR:tm:msg_send: selected socket is
>> 0x7f5b485c3228, proto 3
>>
>> John
>>
>>
>> -----Original Message-----
>> From: Bogdan-Andrei Iancu [mailto:bogdan at opensips.org]
>> Sent: 08 April 2013 13:18
>> To: john.quick at smartvox.co.uk
>> Cc: 'OpenSIPS users mailling list'
>> Subject: Re: [OpenSIPS-Users] Unexpected Dispatcher TLS interaction
>>
>> Hi John,
>>
>> So, UDP is still tried - I see the "udp_send" is calls after the failover.
>>
>> I suspect that somehow the outgoing socket is wrongly selected, as
>> "Broken pipe" cannot be generated on UDP.
>>
>> To check what kind of interface is selected by msg_send() , I made
>> here a small patch to print some stuff - if you could apply it and get
>> the logs it will be really helpful.
>>
>> Regards,
>>
>> Bogdan-Andrei Iancu
>> OpenSIPS Founder and Developer
>> http://www.opensips-solutions.com
>>
>>
>> On 04/08/2013 02:00 PM, John Quick wrote:
>>> Hi Bogda,
>>>
>>> Here is the log output you requested:
>>> 2013-04-08 11:52:31 Failure_Route: Trying next dispatcher target.
>>> ru=sip:200800002 at b1.x-onsip.net;user=phone du=<null>
>>> 2013-04-08 11:52:31 t_relay failed
>>>
>>> 2013-04-08 11:52:31 ERROR:core:udp_send:
>>> sendto(sock,0x7f51a476c110,1261,0,0x7f51a47534a8,16): Broken pipe(32)
>>> 2013-04-08 11:52:31 ERROR:tm:msg_send: udp_send failed
>>> 2013-04-08 11:52:31 ERROR:tm:t_forward_nonack: sending request
>>> failed
>>> 2013-04-08 11:52:31 ERROR:tm:w_t_relay: t_forward_nonack failed
>>>
>>> John
>>>
>>> -----Original Message-----
>>> From: Bogdan-Andrei Iancu [mailto:bogdan at opensips.org]
>>> Sent: 08 April 2013 11:31
>>> To: john.quick at smartvox.co.uk; OpenSIPS users mailling list
>>> Subject: Re: [OpenSIPS-Users] Unexpected Dispatcher TLS interaction
>>>
>>> Hello John,
>>>
>>> By default, the protocol selection (for outbound part) is done based
>>> on RURI
>>> - as the call comes via TLS, I expect to have a "transport=TLS" in
>>> RURI, param which will be preserved after doing dispatcher
>>> (dispatcher changes domain and port part). So, I guess, opensips is
>>> trying to set the call out via TLS (after dispatcher).
>>>
>>> Could you:
>>> 1) print $ru and $du after dispatcher (before t_relay)
>>> 2) post here the err logs from t_relay
>>>
>>> Regards,
>>>
>>> Bogdan-Andrei Iancu
>>> OpenSIPS Founder and Developer
>>> http://www.opensips-solutions.com
>>>
>>>
>>> On 04/08/2013 11:43 AM, John Quick wrote:
>>>> I have been running some tests using the Dispatcher module on v1.9
>>>> of OpenSIPS and found an unexpected interaction with the transport
>>>> protocol of the received INVITE request. When the INVITE request is
>>>> received over UDP, Dispatcher works fine for all destinations in the
>>>> set, but when the INVITE is received over TLS only the first
>>>> Dispatcher destination works. The second and subsequent destinations
>>> (after calls to ds_next_domain) all fail. i.e.
>>>> in this code, t_relay() returns false:
>>>> ds_next_domain("1", "0");
>>>> if (!t_relay()) {
>>>> xlog("L_WARN", " t_relay failed");
>>>> sl_reply_error();
>>>> }
>>>>
>>>> I suspect this is a problem with transport protocol selection for
>>>> the onward request because the following alternative code works:
>>>> ds_next_domain("1", "0");
>>>> force_send_socket(udp:<interface-address>);
>>>> if (!t_relay()) {
>>>> xlog("L_WARN", " t_relay failed");
>>>> sl_reply_error();
>>>> }
>>>>
>>>> The problem also happens for the first destination in a new
>>>> destination set (e.g. using ds_select_domain("2", "0")), after
>>>> exhausting all members of set 1.
>>>>
>>>> I would expect Dispatcher to use the same transport for the first
>>>> and all subsequent destinations, but it actually looks like it is
>>>> using UDP for the first and then using the transport of the received
>>>> request for subsequent destinations. Can the transport be specified
>>>> in the destination field of the dispatcher table? For example, could
>>>> this field be set to "sip:<destination-ip>;transport=udp" ?
>>>>
>>>> John Quick
>>>> Smartvox Limited
>>>> Web: www.smartvox.co.uk
>>>>
>>>>
>>>>
>>>>
>>>> _______________________________________________
>>>> Users mailing list
>>>> Users at lists.opensips.org
>>>> http://lists.opensips.org/cgi-bin/mailman/listinfo/users
>>>>
>
More information about the Users
mailing list