[OpenSIPS-Users] Intermittent TLS Problem -

Mon Jun 18 08:15:38 EDT 2018

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

-- 

*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/20180618/a9046862/attachment.html>