[SR-Users] Failed to create a TLS connection when a 'loose' tls_method is configured
Leonid Fainshtein
leonid.fainshtein at xorcom.com
Sun Sep 4 10:53:45 CEST 2022
Hi,
I have a problem creating a TLS connection when tls_method is configured as
one of the "loose" methods: SSLv23, TLSv1+, TLSv1.1+, TLSv1.2+.
The problem doesn't happen when the tls_method is defined "strictly":
TLSv1, TLSv1.1, or TLSv1.2.
The problem is reproducible with the modern Yealink phones and also with
sipexer.
I have Kamailio v.5.5.4 installed from the Kamailio repo (
http://deb.kamailio.org/kamailio55), on Ubuntu 18.04, OpenSSL
ver.1.1.1-1ubuntu2.1~18.04.20
The sipexer output:
--------------------------
$ ./sipexer -register -vl 3 -co -com -ex 60 -fuser 2001 -cb -au 2001 -ap
"......" -sd -sw 20000 -tk ./id_rsa tls:nnnnnnnnn.com:5061
[debug] [sipexer.go:912] main.main(): parsed socket address argument
({Val:tls:nnnnnnnnn.com:5061 Proto:tls Addr:nnnnnnnnn.com Port:5061
PortNo:5061 AType:8 ProtoId:3})
[debug] [sipexer.go:1800] main.SIPExerSendTLS(): client:
192.168.0.178:41586 connected to: 142.93.233.32:5061
[debug] [sipexer.go:1803] main.SIPExerSendTLS(): [48 130 1 34 48 13 6 9 42
134 72 134 247 13 1 1 1 5 0 3 130 1 15 0 48 130 1 10 2 130 1 1 0 222 21 229
237 77 230 193 157 183 132 186 194 65 98 162 250 243 232 189 223 115 181 41
199 130 221 201 143 254 218 254 201 82 173 233 44 158 103 150 78 210 162
187 138 5 179 11 47 208 0 117 27 186 180 197 229 94 13 63 72 227 27 169 127
197 173 67 52 182 68 140 220 132 20 241 57 24 182 29 234 58 60 214 145 225
29 251 240 190 159 43 233 53 57 121 159 81 4 200 12 193 90 91 158 78 196 25
202 74 111 106 215 164 12 178 120 129 8 81 1 245 181 149 20 47 197 165 74
126 24 249 241 187 197 249 209 192 11 204 254 110 19 248 79 122 11 131 24
101 155 237 110 186 5 214 88 79 255 185 156 52 12 29 222 254 76 71 171 142
28 69 22 34 31 111 105 87 7 108 68 6 23 199 236 134 154 42 208 199 158 190
48 193 192 179 120 189 199 117 71 104 231 127 73 128 91 234 168 175 207 55
6 191 144 209 25 10 182 27 53 182 182 96 248 198 206 220 207 102 236 194 96
67 159 34 112 81 145 2 166 207 86 247 232 117 126 158 214 215 10 226 68 81
235 169 81 2 3 1 0 1] <nil>
[debug] [sipexer.go:1804] main.SIPExerSendTLS(): CN=nnnnnnnnn.com
[debug] [sipexer.go:1803] main.SIPExerSendTLS(): [48 130 2 34....247 31 2 3
1 0 1] <nil>
[debug] [sipexer.go:1804] main.SIPExerSendTLS(): CN=ZeroSSL RSA Domain
Secure Site CA,O=ZeroSSL,C=AT
[debug] [sipexer.go:1803] main.SIPExerSendTLS(): [48 130 2 34 48 ....130 15
2 3 1 0 1] <nil>
[debug] [sipexer.go:1804] main.SIPExerSendTLS(): CN=USERTrust RSA
Certification Authority,O=The USERTRUST Network,L=Jersey City,ST=New
Jersey,C=US
[debug] [sipexer.go:1806] main.SIPExerSendTLS(): client: handshake: true
[debug] [sipexer.go:1807] main.SIPExerSendTLS(): client: mutual: true
[info] [sipexer.go:1432] main.SIPExerDialogLoop(): local socket address:
192.168.0.178:41586 (tls)
[info] [sipexer.go:1433] main.SIPExerDialogLoop(): local via address:
192.168.0.178:41586
[info] [sipexer.go:1434] main.SIPExerDialogLoop(): sending to tls
142.xx.yy.32:5061: [[---
REGISTER sip:nnnnnnnnn.com:5061;transport=tls SIP/2.0
Via: SIP/2.0/TLS 192.168.0.178:41586
;rport;branch=z9hG4bKSG.f7a247eb-5440-4e7a-8a5a-4f849684f30d
From: <sip:2001 at nnnnnnnnn.com>;tag=33e66091-193c-4535-b659-d5e562aca5a4
To: <sip:2001 at nnnnnnnnn.com>
Call-ID: 4556156d-e8da-4632-82f7-f3ab3c4c73a1
CSeq: 621470 REGISTER
Date: Sun, 04 Sep 2022 11:21:33 IDT
Contact: <sip:192.168.0.178:41586;transport=tls>
Expires: 60
User-Agent: SIPExer v1.0.2
Content-Length: 0
[info] [sipexer.go:1436] main.SIPExerDialogLoop(): ---]]
[error] [sipexer.go:1312] main.SIPExerDialogReadBytes(): not receiving
after 32000ms (bytes 0 - EOF)
[debug] [sipexer.go:1009] main.SIPExerExit(): return code: -1154
The Kamailio debug log:
---------------------------------
Sep 4 08:21:33 cpbxmt-demo187 kamailio[23878]: 46(25550) DEBUG: <core>
[core/ip_addr.c:577]: print_ip(): tcpconn_new: new tcp connection:
207.232.46.53
Sep 4 08:21:33 cpbxmt-demo187 kamailio[23878]: 46(25550) DEBUG: <core>
[core/tcp_main.c:1175]: tcpconn_new(): on port 18566, type 3, socket 72
Sep 4 08:21:33 cpbxmt-demo187 kamailio[23878]: 46(25550) DEBUG: <core>
[core/tcp_main.c:1507]: tcpconn_add(): hashes: 1963:2250:2856, 16
Sep 4 08:21:33 cpbxmt-demo187 kamailio[23878]: 46(25550) DEBUG: <core>
[core/io_wait.h:375]: io_watch_add(): processing
io_watch_add(0x5648d2a55e40, 72, 2, 0x7f9dcaf01958) - fd_no=63
Sep 4 08:21:33 cpbxmt-demo187 kamailio[23878]: 46(25550) DEBUG: <core>
[core/io_wait.h:600]: io_watch_del(): DBG: io_watch_del (0x5648d2a55e40,
72, -1, 0x0) fd_no=64 called
Sep 4 08:21:33 cpbxmt-demo187 kamailio[23878]: 46(25550) DEBUG: <core>
[core/tcp_main.c:4471]: handle_tcpconn_ev(): sending to child, events 1
Sep 4 08:21:33 cpbxmt-demo187 kamailio[23878]: 46(25550) DEBUG: <core>
[core/tcp_main.c:4141]: send2child(): selected tcp worker idx:7 proc:45
pid:25549 for activity on [tls:142.xx.yy.32:5061], 0x7f9dcaf01958
Sep 4 08:21:33 cpbxmt-demo187 kamailio[23878]: 45(25549) DEBUG: <core>
[core/tcp_read.c:1737]: handle_io(): received n=8 con=0x7f9dcaf01958, fd=10
Sep 4 08:21:33 cpbxmt-demo187 kamailio[23878]: 45(25549) DEBUG: tls
[tls_server.c:244]: tls_complete_init(): completing tls connection
initialization
Sep 4 08:21:33 cpbxmt-demo187 kamailio[23878]: 45(25549) DEBUG: tls
[tls_server.c:274]: tls_complete_init(): Using initial TLS domain
TLSs<default> (dom 0x7f9dc4c17078 ctx 0x7f9dc4c65da0 sn [])
Sep 4 08:21:33 cpbxmt-demo187 kamailio[23878]: 45(25549) DEBUG: tls
[tls_domain.c:1208]: tls_lookup_private_key(): Private key lookup for
SSL_CTX-0x7f9dc4c65da0: (nil)
Sep 4 08:21:33 cpbxmt-demo187 kamailio[23878]: 45(25549) DEBUG: tls
[tls_domain.c:778]: sr_ssl_ctx_info_callback(): SSL handshake started
Sep 4 08:21:33 cpbxmt-demo187 kamailio[23878]: 45(25549) DEBUG: tls
[tls_domain.c:979]: tls_server_name_cb(): received server_name (TLS
extension): 'tmx.cpbxmt-demo187.xorcom.com'
Sep 4 08:21:33 cpbxmt-demo187 kamailio[23878]: 45(25549) DEBUG: tls
[tls_domain.c:998]: tls_server_name_cb(): TLS cfg domain selected for
received server name [tmx.cpbxmt-demo187.xorcom.com]: socket [:0] server
name='' - switching SSL CTX to 0x7f9dc4c65da0 dom 0x7f9dc4c17078 (default)
Sep 4 08:21:33 cpbxmt-demo187 kamailio[23878]: 45(25549) DEBUG: <core>
[core/tcp_main.c:2720]: tcpconn_do_send(): sending...
Sep 4 08:21:33 cpbxmt-demo187 kamailio[23878]: 45(25549) DEBUG: <core>
[core/tcp_main.c:2753]: tcpconn_do_send(): after real write: c=
0x7f9dcaf01958 n=5435 fd=10
Sep 4 08:21:33 cpbxmt-demo187 kamailio[23878]: 45(25549) DEBUG: <core>
[core/tcp_main.c:2754]: tcpconn_do_send(): buf=
Sep 4 08:21:33 cpbxmt-demo187 kamailio[23878]: #026#003#003
Sep 4 08:21:33 cpbxmt-demo187 kamailio[23878]: 45(25549) DEBUG: <core>
[core/io_wait.h:375]: io_watch_add(): processing
io_watch_add(0x5648d29e8c80, 10, 2, 0x7f9dcaf01958) - fd_no=1
Sep 4 08:21:33 cpbxmt-demo187 kamailio[23878]: 45(25549) DEBUG: tls
[tls_domain.c:1208]: tls_lookup_private_key(): Private key lookup for
SSL_CTX-0x7f9dc4c65da0: (nil)
Sep 4 08:21:33 cpbxmt-demo187 kamailio[23878]: 45(25549) DEBUG: tls
[tls_domain.c:790]: sr_ssl_ctx_info_callback(): SSL handshake done
Sep 4 08:21:33 cpbxmt-demo187 kamailio[23878]: 45(25549) DEBUG: tls
[tls_domain.c:778]: sr_ssl_ctx_info_callback(): SSL handshake started
Sep 4 08:21:33 cpbxmt-demo187 kamailio[23878]: 45(25549) DEBUG: tls
[tls_domain.c:782]: sr_ssl_ctx_info_callback(): SSL renegotiation initiated
by client
Sep 4 08:21:33 cpbxmt-demo187 kamailio[23878]: 45(25549) DEBUG: tls
[tls_domain.c:790]: sr_ssl_ctx_info_callback(): SSL handshake done
Sep 4 08:21:33 cpbxmt-demo187 kamailio[23878]: 45(25549) DEBUG: tls
[tls_domain.c:778]: sr_ssl_ctx_info_callback(): SSL handshake started
Sep 4 08:21:33 cpbxmt-demo187 kamailio[23878]: 45(25549) DEBUG: tls
[tls_domain.c:782]: sr_ssl_ctx_info_callback(): SSL renegotiation initiated
by client
Sep 4 08:21:33 cpbxmt-demo187 kamailio[23878]: 45(25549) DEBUG: tls
[tls_domain.c:790]: sr_ssl_ctx_info_callback(): SSL handshake done
Sep 4 08:21:33 cpbxmt-demo187 kamailio[23878]: 45(25549) DEBUG: tls
[tls_server.c:470]: tls_accept(): TLS accept successful
Sep 4 08:21:33 cpbxmt-demo187 kamailio[23878]: 45(25549) DEBUG: tls
[tls_server.c:477]: tls_accept(): tls_accept: new connection from
207.232.46.53:18566 using TLSv1.3 TLS_AES_256_GCM_SHA384 256
Sep 4 08:21:33 cpbxmt-demo187 kamailio[23878]: 45(25549) DEBUG: tls
[tls_server.c:480]: tls_accept(): tls_accept: local socket:
142.xx.yy.32:5061
Sep 4 08:21:33 cpbxmt-demo187 kamailio[23878]: 45(25549) DEBUG: tls
[tls_server.c:491]: tls_accept(): tls_accept: client did not present a
certificate
Sep 4 08:21:33 cpbxmt-demo187 kamailio[23878]: 45(25549) DEBUG: tls
[tls_server.c:1245]: tls_h_read_f(): Reading on a renegotiation of
connection (n:-1) (2)
Sep 4 08:21:33 cpbxmt-demo187 kamailio[23878]: 45(25549) DEBUG: <core>
[core/tcp_read.c:1503]: tcp_read_req(): EOF
Sep 4 08:21:33 cpbxmt-demo187 kamailio[23878]: 45(25549) DEBUG: <core>
[core/io_wait.h:600]: io_watch_del(): DBG: io_watch_del (0x5648d29e8c80,
10, -1, 0x10) fd_no=2 called
Sep 4 08:21:33 cpbxmt-demo187 kamailio[23878]: 45(25549) DEBUG: <core>
[core/tcp_read.c:1872]: handle_io(): removing from list 0x7f9dcaf01958 id
16 fd 10, state 2, flags 4018, main fd 72, refcnt 2 ([207.232.46.53]:18566
-> [207.232.46.53]:5061)
Sep 4 08:21:33 cpbxmt-demo187 kamailio[23878]: 45(25549) DEBUG: <core>
[core/tcp_read.c:1656]: release_tcpconn(): releasing con 0x7f9dcaf01958,
state -1, fd=10, id=16 ([207.232.46.53]:18566 -> [207.232.46.53]:5061)
Sep 4 08:21:33 cpbxmt-demo187 kamailio[23878]: 45(25549) DEBUG: <core>
[core/tcp_read.c:1660]: release_tcpconn(): extra_data 0x7f9dcaefe628
Sep 4 08:21:33 cpbxmt-demo187 kamailio[23878]: 46(25550) DEBUG: <core>
[core/tcp_main.c:3573]: handle_tcp_child(): reader response= 7f9dcaf01958,
-1 from 7
Sep 4 08:21:33 cpbxmt-demo187 kamailio[23878]: 46(25550) DEBUG: tls
[tls_server.c:729]: tls_h_tcpconn_close_f(): Closing SSL connection
0x7f9dcaefe628
As far as I understood the log, the certificate was accepted but something
wrong happened later.
Any suggestion?
Best regards,
Leonid Fainshtein
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.kamailio.org/pipermail/sr-users/attachments/20220904/a4ef0f8f/attachment.htm>
More information about the sr-users
mailing list