[sr-dev] [kamailio/kamailio] tls: configuration override with multiple server roles on same socket (#1574)

VolodyaIvanets notifications at github.com
Mon Jun 25 15:32:12 CEST 2018 

Hello,

I'm using Kamailio v. 5.1.0-21 on CentOs 6 machine, installed from repository. It is running behind the NAT. I'm using Htek and Zoiper phones for testing. Below is content from my tls.cfg configuration file:
```
[server:default]
method = TLSv1.2
method = SSLv23
require_certificate = yes
verify_certificate = yes
private_key = /var/kamailio/certificates/default/server/key.pem
certificate = /var/kamailio/certificates/default/server/cert.pem
ca_list = /var/kamailio/certificates/default/CA/cert.pem

[server:172.16.30.205:5061]
method = SSLv23
require_certificate = yes
verify_certificate = yes
private_key = /var/kamailio/certificates/first.my-domain.com/server/key.pem
certificate = /var/kamailio/certificates/first.my-domain.com/server/cert.pem
ca_list = /var/kamailio/certificates/first.my-domain.com/CA/cert.pem
server_name = "first.my-domain.com"

[server:172.16.30.205:5061]
method = SSLv23
require_certificate = yes
verify_certificate = yes
private_key = /var/kamailio/certificates/second.my-domain.com/server/key.pem
certificate = /var/kamailio/certificates/second.my-domain.com/server/cert.pem
ca_list = /var/kamailio/certificates/second.my-domain.com/CA/cert.pem
server_name = "second.my-domain.com"

[client:default]
verify_certificate = yes
require_certificate = yes
```

My **first** phone is configured with certificate for _first.my-domain.com_ and **second** - for _second.my-domain.com_.

When I try to connect with **first** phone, it fails. I get following output in Kamailio log file:
```
Jun 25 15:36:50 kamailio-dev /usr/sbin/kamailio[8180]: DEBUG: <core> [core/ip_addr.c:229]: print_ip(): tcpconn_new: new tcp connection: office_with_phones_public_ip_address
Jun 25 15:36:50 kamailio-dev /usr/sbin/kamailio[8180]: DEBUG: <core> [core/tcp_main.c:999]: tcpconn_new(): on port 5360, type 3
Jun 25 15:36:50 kamailio-dev /usr/sbin/kamailio[8180]: DEBUG: <core> [core/tcp_main.c:1309]: tcpconn_add(): hashes: 480:2863:2253, 1
Jun 25 15:36:50 kamailio-dev /usr/sbin/kamailio[8180]: DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG: io_watch_add(0xa4ea20, 55, 2, 0x7f605f124d10), fd_no=42
Jun 25 15:36:50 kamailio-dev /usr/sbin/kamailio[8180]: DEBUG: <core> [core/io_wait.h:602]: io_watch_del(): DBG: io_watch_del (0xa4ea20, 55, -1, 0x0) fd_no=43 called
Jun 25 15:36:50 kamailio-dev /usr/sbin/kamailio[8180]: DEBUG: <core> [core/tcp_main.c:4196]: handle_tcpconn_ev(): sending to child, events 1
Jun 25 15:36:50 kamailio-dev /usr/sbin/kamailio[8180]: DEBUG: <core> [core/tcp_main.c:3878]: send2child(): selected tcp worker 0 31(8168) for activity on [tls:172.16.30.205:5061], 0x7f605f124d10
Jun 25 15:36:50 kamailio-dev /usr/sbin/kamailio[8168]: DEBUG: <core> [core/tcp_read.c:1740]: handle_io(): received n=8 con=0x7f605f124d10, fd=12
Jun 25 15:36:50 kamailio-dev /usr/sbin/kamailio[8168]: DEBUG: tls [tls_server.c:199]: tls_complete_init(): completing tls connection initialization
Jun 25 15:36:50 kamailio-dev /usr/sbin/kamailio[8168]: DEBUG: tls [tls_server.c:228]: tls_complete_init(): Using initial TLS domain TLSs<172.16.30.205:5061> (dom 0x7f605eaa7f38 ctx 0x7f605ed545b0 sn [second.my-domain.com])
Jun 25 15:36:50 kamailio-dev /usr/sbin/kamailio[8168]: DEBUG: tls [tls_domain.c:724]: sr_ssl_ctx_info_callback(): SSL handshake started
Jun 25 15:36:50 kamailio-dev /usr/sbin/kamailio[8168]: DEBUG: tls [tls_domain.c:927]: tls_server_name_cb(): SSL_get_servername returned NULL: return SSL_TLSEXT_ERR_NOACK
Jun 25 15:36:50 kamailio-dev /usr/sbin/kamailio[8168]: DEBUG: <core> [core/tcp_main.c:2460]: tcpconn_do_send(): sending...
Jun 25 15:36:50 kamailio-dev /usr/sbin/kamailio[8168]: DEBUG: <core> [core/tcp_main.c:2494]: tcpconn_do_send(): after real write: c= 0x7f605f124d10 n=2401 fd=12
Jun 25 15:36:50 kamailio-dev /usr/sbin/kamailio[8168]: DEBUG: <core> [core/tcp_main.c:2495]: tcpconn_do_send(): buf=
Jun 25 15:36:50 kamailio-dev /usr/sbin/kamailio[8168]: DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG: io_watch_add(0xa92cc0, 12, 2, 0x7f605f124d10), fd_no=1
Jun 25 15:36:51 kamailio-dev /usr/sbin/kamailio[8168]: DEBUG: <core> [core/tcp_main.c:2460]: tcpconn_do_send(): sending...
Jun 25 15:36:51 kamailio-dev /usr/sbin/kamailio[8168]: DEBUG: <core> [core/tcp_main.c:2494]: tcpconn_do_send(): after real write: c= 0x7f605f124d10 n=7 fd=12
Jun 25 15:36:51 kamailio-dev /usr/sbin/kamailio[8168]: DEBUG: <core> [core/tcp_main.c:2495]: tcpconn_do_send(): buf=
Jun 25 15:36:51 kamailio-dev /usr/sbin/kamailio[8168]: ERROR: tls [tls_util.h:42]: tls_err_ret(): TLS accept:error:140890B2:SSL routines:SSL3_GET_CLIENT_CERTIFICATE:no certificate returned
Jun 25 15:36:51 kamailio-dev /usr/sbin/kamailio[8168]: ERROR: <core> [core/tcp_read.c:1485]: tcp_read_req(): ERROR: tcp_read_req: error reading - c: 0x7f605f124d10 r: 0x7f605f124d90
Jun 25 15:36:51 kamailio-dev /usr/sbin/kamailio[8168]: DEBUG: <core> [core/io_wait.h:602]: io_watch_del(): DBG: io_watch_del (0xa92cc0, 12, -1, 0x10) fd_no=2 called
Jun 25 15:36:51 kamailio-dev /usr/sbin/kamailio[8168]: DEBUG: <core> [core/tcp_read.c:1664]: release_tcpconn(): releasing con 0x7f605f124d10, state -2, fd=12, id=1 ([office_with_phones_public_ip_address]:5360 -> [office_with_phones_public_ip_address]:5061)
Jun 25 15:36:51 kamailio-dev /usr/sbin/kamailio[8168]: DEBUG: <core> [core/tcp_read.c:1665]: release_tcpconn(): extra_data 0x7f605f0bb8f8
Jun 25 15:36:51 kamailio-dev /usr/sbin/kamailio[8180]: DEBUG: <core> [core/tcp_main.c:3308]: handle_tcp_child(): reader response= 7f605f124d10, -2 from 0
Jun 25 15:36:51 kamailio-dev /usr/sbin/kamailio[8180]: DEBUG: tls [tls_server.c:667]: tls_h_close(): Closing SSL connection 0x7f605f0bb8f8
```

However **second** phone connects with no problems:
```
Jun 25 15:40:41 kamailio-dev /usr/sbin/kamailio[9155]: DEBUG: <core> [core/ip_addr.c:229]: print_ip(): tcpconn_new: new tcp connection: office_with_phones_public_ip_address
Jun 25 15:40:41 kamailio-dev /usr/sbin/kamailio[9155]: DEBUG: <core> [core/tcp_main.c:999]: tcpconn_new(): on port 53732, type 3
Jun 25 15:40:41 kamailio-dev /usr/sbin/kamailio[9155]: DEBUG: <core> [core/tcp_main.c:1309]: tcpconn_add(): hashes: 1406:4017:3155, 1
Jun 25 15:40:41 kamailio-dev /usr/sbin/kamailio[9155]: DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG: io_watch_add(0xa4ea20, 55, 2, 0x7fa084d00d10), fd_no=42
Jun 25 15:40:41 kamailio-dev /usr/sbin/kamailio[9155]: DEBUG: <core> [core/io_wait.h:602]: io_watch_del(): DBG: io_watch_del (0xa4ea20, 55, -1, 0x0) fd_no=43 called
Jun 25 15:40:41 kamailio-dev /usr/sbin/kamailio[9155]: DEBUG: <core> [core/tcp_main.c:4196]: handle_tcpconn_ev(): sending to child, events 1
Jun 25 15:40:41 kamailio-dev /usr/sbin/kamailio[9155]: DEBUG: <core> [core/tcp_main.c:3878]: send2child(): selected tcp worker 0 31(9146) for activity on [tls:172.16.30.205:5061], 0x7fa084d00d10
Jun 25 15:40:41 kamailio-dev /usr/sbin/kamailio[9146]: DEBUG: <core> [core/tcp_read.c:1740]: handle_io(): received n=8 con=0x7fa084d00d10, fd=12
Jun 25 15:40:41 kamailio-dev /usr/sbin/kamailio[9146]: DEBUG: tls [tls_server.c:199]: tls_complete_init(): completing tls connection initialization
Jun 25 15:40:41 kamailio-dev /usr/sbin/kamailio[9146]: DEBUG: tls [tls_server.c:228]: tls_complete_init(): Using initial TLS domain TLSs<172.16.30.205:5061> (dom 0x7fa084683f38 ctx 0x7fa0849305b0 sn [second.my-domain.com])
Jun 25 15:40:41 kamailio-dev /usr/sbin/kamailio[9146]: DEBUG: tls [tls_domain.c:724]: sr_ssl_ctx_info_callback(): SSL handshake started
Jun 25 15:40:41 kamailio-dev /usr/sbin/kamailio[9146]: DEBUG: tls [tls_domain.c:927]: tls_server_name_cb(): SSL_get_servername returned NULL: return SSL_TLSEXT_ERR_NOACK
Jun 25 15:40:41 kamailio-dev /usr/sbin/kamailio[9146]: DEBUG: <core> [core/tcp_main.c:2460]: tcpconn_do_send(): sending...
Jun 25 15:40:41 kamailio-dev /usr/sbin/kamailio[9146]: DEBUG: <core> [core/tcp_main.c:2494]: tcpconn_do_send(): after real write: c= 0x7fa084d00d10 n=2406 fd=12
Jun 25 15:40:41 kamailio-dev /usr/sbin/kamailio[9146]: DEBUG: <core> [core/tcp_main.c:2495]: tcpconn_do_send(): buf=
Jun 25 15:40:41 kamailio-dev /usr/sbin/kamailio[9146]: DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG: io_watch_add(0xa92cc0, 12, 2, 0x7fa084d00d10), fd_no=1
Jun 25 15:40:41 kamailio-dev /usr/sbin/kamailio[9146]: DEBUG: tls [tls_domain.c:736]: sr_ssl_ctx_info_callback(): SSL handshake done
Jun 25 15:40:41 kamailio-dev /usr/sbin/kamailio[9146]: DEBUG: tls [tls_domain.c:740]: sr_ssl_ctx_info_callback(): SSL disable renegotiation
Jun 25 15:40:41 kamailio-dev /usr/sbin/kamailio[9146]: DEBUG: tls [tls_server.c:415]: tls_accept(): TLS accept successful
Jun 25 15:40:41 kamailio-dev /usr/sbin/kamailio[9146]: DEBUG: tls [tls_server.c:422]: tls_accept(): tls_accept: new connection from office_with_phones_public_ip_address:53732 using TLSv1/SSLv3 AES256-GCM-SHA384 256
Jun 25 15:40:41 kamailio-dev /usr/sbin/kamailio[9146]: DEBUG: tls [tls_server.c:425]: tls_accept(): tls_accept: local socket: 172.16.30.205:5061
Jun 25 15:40:41 kamailio-dev /usr/sbin/kamailio[9146]: DEBUG: tls [tls_server.c:372]: tls_dump_cert_info(): tls_accept: client certificate subject:/C=UA/ST=Lviv/O=Test/OU=Dev/CN=second.my-domain.com/emailAddress=volodya at my-domain.com
Jun 25 15:40:41 kamailio-dev /usr/sbin/kamailio[9146]: DEBUG: tls [tls_server.c:376]: tls_dump_cert_info(): tls_accept: client certificate issuer:/C=UA/ST=Lviv/L=Lviv/O=Test/OU=Dev/CN=second.my-domain.com/emailAddress=volodya at my-domain.com
```

After swapping `[server:172.16.30.205:5061]` sections in tls.cfg, **first** phone can connect:
```
Jun 25 15:47:04 kamailio-dev /usr/sbin/kamailio[9852]: DEBUG: <core> [core/ip_addr.c:229]: print_ip(): tcpconn_new: new tcp connection: office_with_phones_public_ip_address
Jun 25 15:47:04 kamailio-dev /usr/sbin/kamailio[9852]: DEBUG: <core> [core/tcp_main.c:999]: tcpconn_new(): on port 42055, type 3
Jun 25 15:47:04 kamailio-dev /usr/sbin/kamailio[9852]: DEBUG: <core> [core/tcp_main.c:1309]: tcpconn_add(): hashes: 54:2809:2331, 1
Jun 25 15:47:04 kamailio-dev /usr/sbin/kamailio[9852]: DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG: io_watch_add(0xa4ea20, 55, 2, 0x7f5ce90d2eb0), fd_no=42
Jun 25 15:47:04 kamailio-dev /usr/sbin/kamailio[9852]: DEBUG: <core> [core/io_wait.h:602]: io_watch_del(): DBG: io_watch_del (0xa4ea20, 55, -1, 0x0) fd_no=43 called
Jun 25 15:47:04 kamailio-dev /usr/sbin/kamailio[9852]: DEBUG: <core> [core/tcp_main.c:4196]: handle_tcpconn_ev(): sending to child, events 1
Jun 25 15:47:04 kamailio-dev /usr/sbin/kamailio[9852]: DEBUG: <core> [core/tcp_main.c:3878]: send2child(): selected tcp worker 0 31(9842) for activity on [tls:172.16.30.205:5061], 0x7f5ce90d2eb0
Jun 25 15:47:04 kamailio-dev /usr/sbin/kamailio[9842]: DEBUG: <core> [core/tcp_read.c:1740]: handle_io(): received n=8 con=0x7f5ce90d2eb0, fd=12
Jun 25 15:47:04 kamailio-dev /usr/sbin/kamailio[9842]: DEBUG: tls [tls_server.c:199]: tls_complete_init(): completing tls connection initialization
Jun 25 15:47:04 kamailio-dev /usr/sbin/kamailio[9842]: DEBUG: tls [tls_server.c:228]: tls_complete_init(): Using initial TLS domain TLSs<172.16.30.205:5061> (dom 0x7f5ce8a55fd8 ctx 0x7f5ce8d025b0 sn [first.my-domain.com])
Jun 25 15:47:04 kamailio-dev /usr/sbin/kamailio[9842]: DEBUG: tls [tls_domain.c:724]: sr_ssl_ctx_info_callback(): SSL handshake started
Jun 25 15:47:04 kamailio-dev /usr/sbin/kamailio[9842]: DEBUG: tls [tls_domain.c:927]: tls_server_name_cb(): SSL_get_servername returned NULL: return SSL_TLSEXT_ERR_NOACK
Jun 25 15:47:04 kamailio-dev /usr/sbin/kamailio[9842]: DEBUG: <core> [core/tcp_main.c:2460]: tcpconn_do_send(): sending...
Jun 25 15:47:04 kamailio-dev /usr/sbin/kamailio[9842]: DEBUG: <core> [core/tcp_main.c:2494]: tcpconn_do_send(): after real write: c= 0x7f5ce90d2eb0 n=2371 fd=12
Jun 25 15:47:04 kamailio-dev /usr/sbin/kamailio[9842]: DEBUG: <core> [core/tcp_main.c:2495]: tcpconn_do_send(): buf=
Jun 25 15:47:04 kamailio-dev /usr/sbin/kamailio[9842]: DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG: io_watch_add(0xa92cc0, 12, 2, 0x7f5ce90d2eb0), fd_no=1
Jun 25 15:47:05 kamailio-dev /usr/sbin/kamailio[9842]: DEBUG: tls [tls_domain.c:736]: sr_ssl_ctx_info_callback(): SSL handshake done
Jun 25 15:47:05 kamailio-dev /usr/sbin/kamailio[9842]: DEBUG: tls [tls_domain.c:740]: sr_ssl_ctx_info_callback(): SSL disable renegotiation
Jun 25 15:47:05 kamailio-dev /usr/sbin/kamailio[9842]: DEBUG: tls [tls_server.c:415]: tls_accept(): TLS accept successful
Jun 25 15:47:05 kamailio-dev /usr/sbin/kamailio[9842]: DEBUG: tls [tls_server.c:422]: tls_accept(): tls_accept: new connection from office_with_phones_public_ip_address:42055 using TLSv1/SSLv3 AES128-SHA 128
Jun 25 15:47:05 kamailio-dev /usr/sbin/kamailio[9842]: DEBUG: tls [tls_server.c:425]: tls_accept(): tls_accept: local socket: 172.16.30.205:5061
Jun 25 15:47:05 kamailio-dev /usr/sbin/kamailio[9842]: DEBUG: tls [tls_server.c:372]: tls_dump_cert_info(): tls_accept: client certificate subject:/C=UA/ST=Lviv/O=Test/OU=Dev/CN=first.my-domain.com/emailAddress=volodya at my-domain.com
Jun 25 15:47:05 kamailio-dev /usr/sbin/kamailio[9842]: DEBUG: tls [tls_server.c:376]: tls_dump_cert_info(): tls_accept: client certificate issuer:/C=UA/ST=Lviv/L=Lviv/O=Test/OU=Dev/CN=first.my-domain.com/emailAddress=volodya at my-domain.com
```

... but **second** phone can not:
```
Jun 25 15:43:51 kamailio-dev /usr/sbin/kamailio[9354]: DEBUG: <core> [core/ip_addr.c:229]: print_ip(): tcpconn_new: new tcp connection: office_with_phones_public_ip_address
Jun 25 15:43:51 kamailio-dev /usr/sbin/kamailio[9354]: DEBUG: <core> [core/tcp_main.c:999]: tcpconn_new(): on port 53873, type 3
Jun 25 15:43:51 kamailio-dev /usr/sbin/kamailio[9354]: DEBUG: <core> [core/tcp_main.c:1309]: tcpconn_add(): hashes: 1772:3107:4033, 1
Jun 25 15:43:51 kamailio-dev /usr/sbin/kamailio[9354]: DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG: io_watch_add(0xa4ea20, 55, 2, 0x7fc8bd364eb0), fd_no=42
Jun 25 15:43:51 kamailio-dev /usr/sbin/kamailio[9354]: DEBUG: <core> [core/io_wait.h:602]: io_watch_del(): DBG: io_watch_del (0xa4ea20, 55, -1, 0x0) fd_no=43 called
Jun 25 15:43:51 kamailio-dev /usr/sbin/kamailio[9354]: DEBUG: <core> [core/tcp_main.c:4196]: handle_tcpconn_ev(): sending to child, events 1
Jun 25 15:43:51 kamailio-dev /usr/sbin/kamailio[9354]: DEBUG: <core> [core/tcp_main.c:3878]: send2child(): selected tcp worker 0 31(9344) for activity on [tls:172.16.30.205:5061], 0x7fc8bd364eb0
Jun 25 15:43:51 kamailio-dev /usr/sbin/kamailio[9344]: DEBUG: <core> [core/tcp_read.c:1740]: handle_io(): received n=8 con=0x7fc8bd364eb0, fd=12
Jun 25 15:43:51 kamailio-dev /usr/sbin/kamailio[9344]: DEBUG: tls [tls_server.c:199]: tls_complete_init(): completing tls connection initialization
Jun 25 15:43:51 kamailio-dev /usr/sbin/kamailio[9344]: DEBUG: tls [tls_server.c:228]: tls_complete_init(): Using initial TLS domain TLSs<172.16.30.205:5061> (dom 0x7fc8bcce7fd8 ctx 0x7fc8bcf945b0 sn [first.my-domain.com])
Jun 25 15:43:51 kamailio-dev /usr/sbin/kamailio[9344]: DEBUG: tls [tls_domain.c:724]: sr_ssl_ctx_info_callback(): SSL handshake started
Jun 25 15:43:51 kamailio-dev /usr/sbin/kamailio[9344]: DEBUG: tls [tls_domain.c:927]: tls_server_name_cb(): SSL_get_servername returned NULL: return SSL_TLSEXT_ERR_NOACK
Jun 25 15:43:51 kamailio-dev /usr/sbin/kamailio[9344]: DEBUG: <core> [core/tcp_main.c:2460]: tcpconn_do_send(): sending...
Jun 25 15:43:51 kamailio-dev /usr/sbin/kamailio[9344]: DEBUG: <core> [core/tcp_main.c:2494]: tcpconn_do_send(): after real write: c= 0x7fc8bd364eb0 n=2376 fd=12
Jun 25 15:43:51 kamailio-dev /usr/sbin/kamailio[9344]: DEBUG: <core> [core/tcp_main.c:2495]: tcpconn_do_send(): buf=
Jun 25 15:43:51 kamailio-dev /usr/sbin/kamailio[9344]: DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG: io_watch_add(0xa92cc0, 12, 2, 0x7fc8bd364eb0), fd_no=1
Jun 25 15:43:51 kamailio-dev /usr/sbin/kamailio[9344]: ERROR: tls [tls_util.h:42]: tls_err_ret(): TLS accept:error:14094418:SSL routines:SSL3_READ_BYTES:tlsv1 alert unknown ca
Jun 25 15:43:51 kamailio-dev /usr/sbin/kamailio[9344]: ERROR: <core> [core/tcp_read.c:1485]: tcp_read_req(): ERROR: tcp_read_req: error reading - c: 0x7fc8bd364eb0 r: 0x7fc8bd364f30
Jun 25 15:43:51 kamailio-dev /usr/sbin/kamailio[9344]: DEBUG: <core> [core/io_wait.h:602]: io_watch_del(): DBG: io_watch_del (0xa92cc0, 12, -1, 0x10) fd_no=2 called
Jun 25 15:43:51 kamailio-dev /usr/sbin/kamailio[9344]: DEBUG: <core> [core/tcp_read.c:1664]: release_tcpconn(): releasing con 0x7fc8bd364eb0, state -2, fd=12, id=1 ([office_with_phones_public_ip_address]:53873 -> [office_with_phones_public_ip_address]:5061)
Jun 25 15:43:51 kamailio-dev /usr/sbin/kamailio[9344]: DEBUG: <core> [core/tcp_read.c:1665]: release_tcpconn(): extra_data 0x7fc8bd168508
Jun 25 15:43:51 kamailio-dev /usr/sbin/kamailio[9354]: DEBUG: <core> [core/tcp_main.c:3308]: handle_tcp_child(): reader response= 7fc8bd364eb0, -2 from 0
Jun 25 15:43:51 kamailio-dev /usr/sbin/kamailio[9354]: DEBUG: tls [tls_server.c:667]: tls_h_close(): Closing SSL connection 0x7fc8bd168508
```

10-th line in each output from above shows that last server role which is configured for particular socket is used to establish connection, ignoring previous ones. Please let me know if my configuration is correct or it needs to be adjusted.

Thank you very much!

-- 
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/1574
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.kamailio.org/pipermail/sr-dev/attachments/20180625/e3a0c8b6/attachment-0001.html>

More information about the sr-dev mailing list