[OpenSIPS-Users] Intermittent TLS Problem -

Tue Jun 19 04:24:48 EDT 2018

Hi Liviu,

Thanks for taking the time to come back to me.

I am happy to report that updating the timeout value to 500ms has solved
the issue and calls are now connecting consistently. Now that you've
clarified that the timeout values are in ms it all makes sense - I already
had these set at 60 as per the error report, double the cited default value
in the module docs. The reason I hadn't considered increasing this further
is that the docs state that this is a value in seconds so I had always
believed I was misunderstanding that the value represented - with a single
call attempt how could 60 seconds not be enough?!

Is there a way to contribute to the documentation so that I can make this
edit myself or would this be a maintained by the module owner?

Best Regards,

Callum

On Tue, Jun 19, 2018 at 7:57 AM Liviu Chircu <liviu at opensips.org> wrote:

> Hi,
>
> Looking at both successful and failed attempts, the TLS connection seems
> to be properly established in both cases.  However, for some unknown
> reason, writing the effective data (from the client side) may either take a
> quick 400 us, or it may time out after 60 ms!
>
> As a first way of troubleshooting this, I suggest we increase the
> tls_mgm's module "tls_send_timeout" to some ridiculous value (e.g. 2000 ms)
> and see if the client write timeouts still happen.
>
> Best regards,
>
> Liviu Chircu
> OpenSIPS Developerhttp://www.opensips-solutions.com
>
> On 18.06.2018 18:05, Callum Guy wrote:
>
> Hi All,
>
> Further to this issue I have established that the fault occurs when the
> server does not provide a finish "Encrypted Handshake Message" following
> key/cert exchange.
>
> Based on my test patterns it seems to indicate that this improves
> *slightly* over time meaning that its gets a bit more reliable after a
> few calls have been processed by the remote. This doesn't mean that the
> calls don't ever fail though, it goes from 50% failure rate to 20% perhaps.
>
> Does anyone have confidence that this indicates a fault with the remote
> system rather than the OpenSIPs implementation?
>
> Thanks
>
> On Mon, Jun 18, 2018 at 1:15 PM Callum Guy <callum.guy at x-on.co.uk> wrote:
>
>> Hi All,
>>
>> I'm running a TLS protected service using OpenSIPs 2.3.3
>> and openssl-1.0.2k-12.el7.x86_64 on a CentOS 7.5 server. RTPProxy is in
>> place to forward all the media on every call.
>>
>> OpenSIPs is acting as a proxy to an internal FreeSWITCH instance and
>> handling all inbound and outbound TLS negotiation.
>>
>> The call scenario is:
>> Leg A: carrier -> opensips -> freeswitch (answer)
>> Leg B: freeswitch -> opensips ->carrier
>>
>> I have a situation where calls sometimes fail during TLS negotiation on
>> the B leg. The exact same call will work only seconds before and then the
>> subsequent call will fail. This is still a test service so there is no
>> traffic on the platform which would effect the calls.
>>
>> The destination carrier is Twilio where we are targeting a custom domain
>> which provides three separate fallback IP's. The logs (below) show each
>> being attempted in sequence and OpenSIPs is reporting failure.
>>
>> I have a packet capture (SIP encrypted) which shows that the carrier
>> (Twilio) are setting up the connection and attempting to change the cipher
>> spec, from my understanding it looks like this is what triggers the errors
>> in OpenSIPs which then returns a SIP packet to Twilio before trying the
>> next IP in the list (see screen shot below).
>>
>> When viewing the packet capture on a call which was not affected I don't
>> see wireshark reporting "Change Cipher Spec" from the carrier network so at
>> present this is the main suspicion. Unfortunately this is as far as my
>> current understanding can take me so while i continue to research i wanted
>> to reach out to see is anyone in the community can help! Let me know if I
>> can provide any further information.
>>
>> Thanks!
>>
>> *OpenSIPs Log*
>>
>> Jun 18 11:20:33 opensips[6373]: INFO: [INVITE] (outbound) REST response:
>> RU: sip:+35361234567 <+353%2061%20234%20567>
>> @custom.pstn.ie1.twilio.com:5061;transport=tls DU: sip:
>> custom.pstn.ie1.twilio.com:5061 FU: "+4940261234567
>> <+49%2040%20261234567>" <si
>> ps:+4940261234567 at 172.20.0.101> To(
>> sip:35361234567 at 172.18.0.110:5061;transport=tls) From(
>> sip:+40261234567 at 172.20.0.101) ID:137a5be9-ed84-1236-10aa-d0431e9b59cf
>> Jun 18 11:20:33 opensips[6373]: INFO:core:probe_max_sock_buff: using snd
>> buffer of 416 kb
>> Jun 18 11:20:33 opensips[6373]: INFO:core:init_sock_keepalive: TCP
>> keepalive enabled on socket 29
>> Jun 18 11:20:33 opensips[6373]: NOTICE:tls_mgm:verify_callback: depth = 2
>> Jun 18 11:20:33 opensips[6373]: NOTICE:tls_mgm:verify_callback: preverify
>> is good: verify return: 1
>> Jun 18 11:20:33 opensips[6373]: NOTICE:tls_mgm:verify_callback: depth = 1
>> Jun 18 11:20:33 opensips[6373]: NOTICE:tls_mgm:verify_callback: preverify
>> is good: verify return: 1
>> Jun 18 11:20:33 opensips[6373]: NOTICE:tls_mgm:verify_callback: depth = 0
>> Jun 18 11:20:33 opensips[6373]: NOTICE:tls_mgm:verify_callback: preverify
>> is good: verify return: 1
>> *Jun 18 11:20:34 opensips[6373]: ERROR:proto_tls:tls_blocking_write: TLS
>> send timeout (60)*
>> *Jun 18 11:20:34 opensips[6373]: ERROR:proto_tls:proto_tls_send: failed
>> to send*
>> *Jun 18 11:20:34 opensips[6373]: ERROR:tm:msg_send: send()
>> to 54.171.127.194:5061 <http://54.171.127.194:5061/> for proto tls/3 failed*
>> *Jun 18 11:20:34 opensips[6373]: ERROR:tm:t_forward_nonack: sending
>> request failed*
>> Jun 18 11:20:34 opensips[6373]: INFO:core:probe_max_sock_buff: using snd
>> buffer of 416 kb
>> Jun 18 11:20:34 opensips[6373]: INFO:core:init_sock_keepalive: TCP
>> keepalive enabled on socket 29
>> Jun 18 11:20:34 opensips[6373]: NOTICE:tls_mgm:verify_callback: depth = 2
>> Jun 18 11:20:34 opensips[6373]: NOTICE:tls_mgm:verify_callback: preverify
>> is good: verify return: 1
>> Jun 18 11:20:34 opensips[6373]: NOTICE:tls_mgm:verify_callback: depth = 1
>> Jun 18 11:20:34 opensips[6373]: NOTICE:tls_mgm:verify_callback: preverify
>> is good: verify return: 1
>> Jun 18 11:20:34 opensips[6373]: NOTICE:tls_mgm:verify_callback: depth = 0
>> Jun 18 11:20:34 opensips[6373]: NOTICE:tls_mgm:verify_callback: preverify
>> is good: verify return: 1
>> *Jun 18 11:20:34 opensips[6373]: ERROR:proto_tls:tls_blocking_write: TLS
>> send timeout (60)*
>> *Jun 18 11:20:34 opensips[6373]: ERROR:proto_tls:proto_tls_send: failed
>> to send*
>> *Jun 18 11:20:34 opensips[6373]: ERROR:tm:msg_send: send()
>> to 54.171.127.193:5061 <http://54.171.127.193:5061/> for proto tls/3 failed*
>> *Jun 18 11:20:34 opensips[6373]: ERROR:tm:t_forward_nonack: sending
>> request failed*
>> Jun 18 11:20:34 opensips[6373]: INFO:core:probe_max_sock_buff: using snd
>> buffer of 416 kb
>> Jun 18 11:20:34 opensips[6373]: INFO:core:init_sock_keepalive: TCP
>> keepalive enabled on socket 29
>> Jun 18 11:20:34 opensips[6373]: NOTICE:tls_mgm:verify_callback: depth = 2
>> Jun 18 11:20:34 opensips[6373]: NOTICE:tls_mgm:verify_callback: preverify
>> is good: verify return: 1
>> Jun 18 11:20:34 opensips[6373]: NOTICE:tls_mgm:verify_callback: depth = 1
>> Jun 18 11:20:34 opensips[6373]: NOTICE:tls_mgm:verify_callback: preverify
>> is good: verify return: 1
>> Jun 18 11:20:34 opensips[6373]: NOTICE:tls_mgm:verify_callback: depth = 0
>> Jun 18 11:20:34 opensips[6373]: NOTICE:tls_mgm:verify_callback: preverify
>> is good: verify return: 1
>> *Jun 18 11:20:34 opensips[6373]: ERROR:proto_tls:tls_blocking_write: TLS
>> send timeout (60)*
>> *Jun 18 11:20:34 opensips[6373]: ERROR:proto_tls:proto_tls_send: failed
>> to send*
>> *Jun 18 11:20:34 opensips[6373]: ERROR:tm:msg_send: send()
>> to 54.171.127.192:5061 <http://54.171.127.192:5061/> for proto tls/3 failed*
>> *Jun 18 11:20:34 opensips[6373]: ERROR:tm:t_forward_nonack: sending
>> request failed*
>> *Jun 18 11:20:34 opensips[6373]: ERROR:tm:w_t_relay: t_forward_nonack
>> failed*
>> *Jun 18 11:20:34 opensips[6373]: ERROR: Failed to relay call - DU:<null>
>> [INVITE] To(sip:35361234567 at 172.18.0.110:5061;transport=tls)
>> From(sip:+40261234567 at 172.20.0.101 <sip%3A%2B40261234567 at 172.20.0.101>)
>> ID:137a5be9-ed84-1236-10aa-d0431e9b59*
>>
>> *Wireshark Failure:*
>> https://ibb.co/ici8Ny
>>
>> *Wireshark Working:*
>> https://ibb.co/kePF2y
>>
>> --
>> Callum Guy
>> Head of Information Security
>> X-on
>>
> --
> Callum Guy
> Head of Information Security
> X-on
>
>
> *0333 332 0000  |  www.x-on.co.uk <http://www.x-on.co.uk>  |   **
> <https://www.linkedin.com/company/x-on>   <https://www.facebook.com/XonTel>
>   <https://twitter.com/xonuk> *
> X-on is a trading name of Storacall Technology Ltd a limited company
> registered in England and Wales.
> Registered Office : Avaland House, 110 London Road, Apsley, Hemel
> Hempstead, Herts, HP3 9SD. Company Registration No. 2578478.
> The information in this e-mail is confidential and for use by the
> addressee(s) only. If you are not the intended recipient, please notify
> X-on immediately on +44(0)333 332 0000 <+44%20333%20332%200000> and
> delete the
> message from your computer. If you are not a named addressee you must not
> use, disclose, disseminate, distribute, copy, print or reply to this email. Views
> or opinions expressed by an individual
> within this email may not necessarily reflect the views of X-on or its
> associated companies. Although X-on routinely screens for viruses,
> addressees should scan this email and any attachments
> for viruses. X-on makes no representation or warranty as to the absence of
> viruses in this email or any attachments.
>
>
>
> _______________________________________________
> Users mailing listUsers at lists.opensips.orghttp://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
>
-- 
Callum Guy
Head of Information Security
X-on

-- 

*0333 332 0000  |  www.x-on.co.uk <http://www.x-on.co.uk>  |   ** 
<https://www.linkedin.com/company/x-on>   <https://www.facebook.com/XonTel> 
  <https://twitter.com/xonuk> *

X-on
is a trading 
name of Storacall Technology Ltd a limited company registered in
England 
and Wales.

Registered Office : Avaland House, 110 London Road, Apsley, 
Hemel Hempstead,
Herts, HP3 9SD. Company Registration No. 2578478.

The 
information in this e-mail is confidential and for use by the addressee(s)

only. If you are not the intended recipient, please notify X-on immediately 
on +44(0)333 332 0000 and delete the
message from your computer. If you are 
not a named addressee you must not use,
disclose, disseminate, distribute, 
copy, print or reply to this email. Views
or opinions expressed by an 
individual
within this email may not necessarily
reflect the views of X-on 
or its associated companies. Although X-on routinely
screens for viruses, 
addressees should scan this email and any attachments
for
viruses. X-on 
makes no representation or warranty as to the absence of viruses
in this 
email or any attachments.

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.opensips.org/pipermail/users/attachments/20180619/06a9645c/attachment-0001.html>