<html>
<head>
<meta http-equiv="content-type" content="text/html; charset=UTF-8">
</head>
<body>
Hello<br>
<br>
As of five days ago, my OpenSIPS 'SBC' for Microsoft Teams has
started failing outbound Teams calls (with no changes to the config
and after everything was working for many weeks prior).<br>
<br>
In the direction where OpenSIPS sends the INVITE to Microsoft,
everything still works normally. It's only problematic in the
direction where Microsoft sends the INVITE to OpenSIPS.<br>
<br>
In my logs, I can see it accepts the first TLS connection, however
after the INVITE is received, Microsoft tries to establish another
TLS connection from the same IP and that fails during the TLS
handshake.<br>
<pre>Jul 7 00:10:02 msteams /usr/sbin/opensips[26344]: INFO:core:probe_max_sock_buff: using snd buffer of 416 kb
Jul 7 00:10:02 msteams /usr/sbin/opensips[26344]: INFO:core:init_sock_keepalive: TCP keepalive enabled on socket 178
Jul 7 00:10:02 msteams /usr/sbin/opensips[26326]: NOTICE:tls_mgm:verify_callback: depth = 2, verify success
Jul 7 00:10:02 msteams /usr/sbin/opensips[26326]: NOTICE:tls_mgm:verify_callback: depth = 1, verify success
Jul 7 00:10:02 msteams /usr/sbin/opensips[26326]: NOTICE:tls_mgm:verify_callback: depth = 0, verify success
Jul 7 00:10:02 msteams /usr/sbin/opensips[26326]: INFO:proto_tls:tls_accept: New TLS connection from 52.114.76.76:2560 accepted
Jul 7 00:10:02 msteams /usr/sbin/opensips[26326]: INFO:proto_tls:tls_dump_cert_info: tls_accept: client TLS certificate subject: /CN=sip.pstnhub.microsoft.com, issuer: /C=US/ST=Washington/L=Redmond/O=Microsoft Corporation/OU=Microsoft IT/CN=Microsoft IT TLS CA 4
Jul 7 00:10:02 msteams /usr/sbin/opensips[26326]: INFO:proto_tls:tls_dump_cert_info: tls_accept: local TLS server certificate subject: /CN=msteams.switchtel.co.za, issuer: /C=US/O=Let's Encrypt/CN=Let's Encrypt Authority X3
Jul 7 00:10:02 msteams /usr/sbin/opensips[26326]: Call from <a class="moz-txt-link-freetext" href="sip:+27105000470@sip.pstnhub.microsoft.com:5061;user=phone">sip:+27105000470@sip.pstnhub.microsoft.com:5061;user=phone</a> to <a class="moz-txt-link-freetext" href="sip:+27875500000@samsip1.switchtel.co.za">sip:+27875500000@samsip1.switchtel.co.za</a>, Socket tls:52.114.76.76:2560 to tls:196.216.192.19:5061, Contact-URI=<a class="moz-txt-link-freetext" href="sip:api-du-b-usea.pstnhub.microsoft.com:443;x-i=346158ef-e50e-4a58-9f08-af7e7813acef;x-c=720af6d686d05fba9a27b237dd0a5ecb/d/8/222b0a8fe57c4584ab717a05b7f0b93f">sip:api-du-b-usea.pstnhub.microsoft.com:443;x-i=346158ef-e50e-4a58-9f08-af7e7813acef;x-c=720af6d686d05fba9a27b237dd0a5ecb/d/8/222b0a8fe57c4584ab717a05b7f0b93f</a>, Teams_Domain=msteams.switchtel.co.za
</pre>
The logs above show the connection from 52.114.76.76:2560 was
successful, client and server certificates verified, and the INVITE
packet was received from Microsoft.<br>
The logs below show the connection from 52.114.76.76:2561 and
52.114.76.76:2562, just two seconds later, with TLS handshake
failure. The 2 second gap is the time it takes to send the "200 OK";
that is transmitting via the initial connection, however, it seems
that Microsoft thinks the first connection is dead and attempts to
reconnect.<br>
<pre>
Jul 7 00:10:04 msteams /usr/sbin/opensips[26344]: INFO:core:probe_max_sock_buff: using snd buffer of 416 kb
Jul 7 00:10:04 msteams /usr/sbin/opensips[26344]: INFO:core:init_sock_keepalive: TCP keepalive enabled on socket 179
Jul 7 00:10:04 msteams /usr/sbin/opensips[26328]: ERROR:proto_tls:tls_accept: New TLS connection from 52.114.76.76:2561 failed to accept
Jul 7 00:10:04 msteams /usr/sbin/opensips[26328]: ERROR:proto_tls:tls_read_req: failed to do pre-tls reading
Jul 7 00:10:04 msteams /usr/sbin/opensips[26344]: INFO:core:probe_max_sock_buff: using snd buffer of 416 kb
Jul 7 00:10:04 msteams /usr/sbin/opensips[26344]: INFO:core:init_sock_keepalive: TCP keepalive enabled on socket 179
Jul 7 00:10:04 msteams /usr/sbin/opensips[26328]: ERROR:proto_tls:tls_accept: New TLS connection from 52.114.76.76:2562 failed to accept
Jul 7 00:10:04 msteams /usr/sbin/opensips[26328]: ERROR:proto_tls:tls_read_req: failed to do pre-tls reading
</pre>
If I take a TShark sample, the first connection gets "Certificate,
Client Key Exchange, Certificate Verify, Change Cipher Spec,
Encrypted Handshake Message" while the second and third connections
seem to lack this part of the TLS handshake:<br>
<br>
<pre> 22 9.027531791 52.114.76.76 â 196.216.192.19 TLSv1.2 2370 Client Hello
23 9.027555818 196.216.192.19 â 52.114.76.76 TCP 54 5061 â 7106 [ACK] Seq=1 Ack=2317 Win=63232 Len=0
24 9.030106811 196.216.192.19 â 52.114.76.76 TLSv1.2 2934 Server Hello, Certificate
25 9.030278247 196.216.192.19 â 52.114.76.76 TLSv1.2 230 Server Key Exchange, Certificate Request, Server Hello Done
26 9.223719073 52.114.76.76 â 196.216.192.19 TCP 60 7106 â 5061 [ACK] Seq=2317 Ack=3057 Win=525568 Len=0
27 9.226831508 52.114.76.76 â 196.216.192.19 TLSv1.2 3823 Certificate, Client Key Exchange, Certificate Verify, Change Cipher Spec, Encrypted Handshake Message
28 9.226854910 196.216.192.19 â 52.114.76.76 TCP 54 5061 â 7106 [ACK] Seq=3057 Ack=6086 Win=62080 Len=0
29 9.228225293 196.216.192.19 â 52.114.76.76 TLSv1.2 2248 New Session Ticket, Change Cipher Spec, Encrypted Handshake Message
30 9.421672079 52.114.76.76 â 196.216.192.19 TCP 60 7106 â 5061 [ACK] Seq=6086 Ack=5251 Win=525568 Len=0
31 9.423493322 52.114.76.76 â 196.216.192.19 TLSv1.2 2092 Application Data
32 9.423517425 196.216.192.19 â 52.114.76.76 TCP 54 5061 â 7106 [ACK] Seq=5251 Ack=8124 Win=63232 Len=0
33 9.424490692 196.216.192.19 â 52.114.76.76 TLSv1.2 478 Application Data
34 9.583038834 196.216.192.19 â 52.114.76.76 TLSv1.2 931 Application Data
35 9.661329748 52.114.76.76 â 196.216.192.19 TCP 60 7106 â 5061 [ACK] Seq=8124 Ack=5675 Win=525056 Len=0
36 9.817636273 52.114.76.76 â 196.216.192.19 TCP 60 7106 â 5061 [ACK] Seq=8124 Ack=6552 Win=524288 Len=0
37 9.994327854 52.114.132.46 â 196.216.192.19 TLSv1.2 99 Application Data
38 9.994448210 196.216.192.19 â 52.114.132.46 TLSv1.2 85 Application Data
39 9.994468209 196.216.192.19 â 52.114.132.46 TLSv1.2 116 Application Data, Application Data
40 9.994631776 196.216.192.19 â 52.114.132.46 TLSv1.2 85 Application Data
41 10.251655099 52.114.132.46 â 196.216.192.19 TCP 60 8768 â 5061 [ACK] Seq=46 Ack=94 Win=2051 Len=0
42 10.294541880 52.114.132.46 â 196.216.192.19 TCP 60 8768 â 5061 [ACK] Seq=46 Ack=125 Win=2051 Len=0
43 10.585625776 196.216.192.19 â 52.114.76.76 TLSv1.2 1377 Application Data
44 10.779516806 52.114.76.76 â 196.216.192.19 TCP 66 7107 â 5061 [SYN] Seq=0 Win=64240 Len=0 MSS=1440 WS=256 SACK_PERM=1
45 10.779555363 196.216.192.19 â 52.114.76.76 TCP 66 5061 â 7107 [SYN, ACK] Seq=0 Ack=1 Win=64240 Len=0 MSS=1460 SACK_PERM=1 WS=128
46 10.833193731 52.114.76.76 â 196.216.192.19 TCP 60 7106 â 5061 [ACK] Seq=8124 Ack=7875 Win=525568 Len=0
47 10.971578923 52.114.76.76 â 196.216.192.19 TCP 60 7107 â 5061 [ACK] Seq=1 Ack=1 Win=525568 Len=0
48 10.971928866 52.114.76.76 â 196.216.192.19 TLSv1.2 210 Client Hello
49 10.971952878 196.216.192.19 â 52.114.76.76 TCP 54 5061 â 7107 [ACK] Seq=1 Ack=157 Win=64128 Len=0
50 10.974370873 196.216.192.19 â 52.114.76.76 TLSv1.2 2934 Server Hello, Certificate
51 10.974542533 196.216.192.19 â 52.114.76.76 TLSv1.2 226 Server Key Exchange, Certificate Request, Server Hello Done
52 11.086085952 196.216.192.19 â 52.114.76.76 TLSv1.2 1377 Application Data
53 11.166263352 52.114.76.76 â 196.216.192.19 TCP 60 7107 â 5061 [ACK] Seq=157 Ack=3053 Win=525568 Len=0
54 11.166844774 52.114.76.76 â 196.216.192.19 TCP 60 7107 â 5061 [FIN, ACK] Seq=157 Ack=3053 Win=525568 Len=0
55 11.167276748 196.216.192.19 â 52.114.76.76 TCP 54 5061 â 7107 [FIN, ACK] Seq=3053 Ack=158 Win=64128 Len=0
56 11.170033533 52.114.76.76 â 196.216.192.19 TCP 66 7108 â 5061 [SYN] Seq=0 Win=64240 Len=0 MSS=1440 WS=256 SACK_PERM=1
57 11.170072225 196.216.192.19 â 52.114.76.76 TCP 66 5061 â 7108 [SYN, ACK] Seq=0 Ack=1 Win=64240 Len=0 MSS=1460 SACK_PERM=1 WS=128
58 11.333176171 52.114.76.76 â 196.216.192.19 TCP 60 7106 â 5061 [ACK] Seq=8124 Ack=9198 Win=524032 Len=0
59 11.359073241 52.114.76.76 â 196.216.192.19 TCP 60 7107 â 5061 [ACK] Seq=158 Ack=3054 Win=525568 Len=0
60 11.363647189 52.114.76.76 â 196.216.192.19 TCP 60 7108 â 5061 [ACK] Seq=1 Ack=1 Win=525568 Len=0
</pre>
My config includes:<br>
<br>
tcp_connection_lifetime=600<br>
tcp_connect_timeout=3000<br>
<br>
modparam("proto_tls", "tls_max_msg_chunks", 8)<br>
modparam("tls_mgm", "tls_send_timeout", 2000)<br>
modparam("tls_mgm", "tls_handshake_timeout", 3000)<br>
<br>
<br>
These are fairly generous time-outs aimed to compensate for slow
response from Microsoft and the fact that their SIP proxy is on a
different continent to mine, with approximately 180ms round-trip
time in latency (typical submarine cable latency from South Africa
to Europe).<br>
<br>
It doesn't appear to be certificate-related, as the first connection
verifies the certificates in both directions and connections are
to/from the same IP addresses. The second and third connections
appear to be attempts to re-establish a connection after something
goes wrong with the initial connection. <br>
<br>
Microsoft is logging "Server Time-out - TLS misconfiguration on the
SBC".<br>
<br>
I'm at a bit of a loss as to why the TLS connection - in one
direction only - is suddenly becoming problematic and why OpenSIPS
fails to accept re-connections from the same host that, two seconds
prior, it was happy to accept a connection from.<br>
<br>
Any help would be most appreciated!<br>
<br>
Thanks<br>
<br>
Kind Regards<br>
Greg<br>
</body>
</html>