### Description
Started from the [minimal proxy config](https://github.com/kamailio/kamailio/blob/master/misc/examples/mixed/kamaili...), we tried to run **more than 1** process using TLS, and, unforntunately it crashed.
Everything is working fine **using TLS with 1 child**. Everything is working fine with **more than 1 child process without TLS**.
To ease the reproduction, we set an env var called `TARGET` at container instanciation, its value is set to a reachable SIP address using TLS (without DNS resolution).
To reproduce issue you will need pjsip/pjsua with SSL/TLS enabled: * install OpenSSL (`sudo apt-get install openssl` for ubuntu) * [install pjsip using autoconf](https://trac.pjsip.org/repos/wiki/Getting-Started/Autoconf) * [manually configure TLS support if necessary](https://trac.pjsip.org/repos/wiki/TLS) * [build and install pjsua](https://trac.pjsip.org/repos/wiki/Python_SIP/Build_Install)
We've seen on some issues that a low memory allocation could be an issue using TLS, so we are running kamailio using more memory `kamailio -DD -E -M 256 -m 1024` (still crashing).
### Troubleshooting
#### Reproduction
Here are the steps to reproduce the issue: * start from [Kamailio minimal proxy config](https://github.com/kamailio/kamailio/blob/master/misc/examples/mixed/kamaili...) * enable TLS by adding/uncommenting following lines:
```diff @@ -1,4 +1,5 @@ #!KAMAILIO +#!define WITH_TLS # # Kamailio (OpenSER) SIP Server v5.2 - default configuration script # - web: https://www.kamailio.org @@ -28,7 +29,7 @@ ####### Global Parameters #########
### LOG Levels: 3=DBG, 2=INFO, 1=NOTICE, 0=WARN, -1=ERR -debug=2 +debug=3 log_stderror=no
memdbg=5 @@ -38,10 +39,13 @@ log_facility=LOG_LOCAL0 log_prefix="{$mt $hdr(CSeq) $ci} "
/* number of SIP routing processes */ -children=2 +children=1
/* uncomment the next line to disable TCP (default on) */ # disable_tcp=yes +#!ifdef WITH_TLS +enable_tls=yes +#!endif
/* uncomment the next line to disable the auto discovery of local aliases * based on reverse DNS on IPs (default on) */ @@ -65,6 +69,9 @@ children=2 ####### Modules Section ########
/* set paths to location of modules */ +#!ifdef WITH_TLS +loadmodule "tls.so" +#!endif loadmodule "jsonrpcs.so" loadmodule "kex.so" loadmodule "corex.so" @@ -85,6 +92,9 @@ loadmodule "counters.so"
# ----------------- setting module-specific parameters ---------------
+#!ifdef WITH_TLS +modparam("tls", "config", "/etc/kamailio/tls.cfg") +#!endif
# ----- jsonrpcs params ----- modparam("jsonrpcs", "pretty_format", 1) @@ -180,7 +190,7 @@ request_route { }
# update $du to set the destination address for proxying - $du = "sip:" + $rd + ":9"; + $du = $env(TARGET); route(RELAY); exit; } ```
* use a proper `tls.cfg` file with self-signed certificates: ```c [server:default] method = TLSv1 verify_certificate = no require_certificate = no private_key = /etc/kamailio/privkey.pem certificate = /etc/kamailio/server-cert.pem
[client:default] #method = TLSv1 verify_certificate = no require_certificate = no ```
* use following `Dockerfile`: ```docker FROM kamailio/kamailio-ci:master-alpine
# Override default kamailio configuration COPY kamailio.cfg /etc/kamailio/kamailio.cfg COPY tls.cfg /etc/kamailio/tls.cfg COPY privkey.pem /etc/kamailio/privkey.pem COPY server-cert.pem /etc/kamailio/server-cert.pem ``` * build docker image `docker build -f Dockerfile -t kamailio-tls-issue .` * launch docker container using your own `TARGET`: ```sh docker run -it -p 5061:5061/tcp -e "TARGET=sip:AA.BB.CC.DD;transport=tls" kamailio-tls-issue ``` * make a SIP call with pjsua: ```sh pjsua --stun-srv=stun.l.google.com:19302 --use-tls --no-tcp --no-udp --use-srtp=2 --local-port=5062 --id=sip:alice@localhost "sip:bob@localhost;transport=tls" ```
**Everything should work fine because we only used 1 child process**
* stop everything * update your `kamailio.cfg` by setting `children=2` (or above) * reproduce steps (build docker image, launch container, make a SIP call) * kamailio should crash with specific logs (see `Log messages` section)
#### Log Messages
Log messages from kamailio proxy: ```c 11(16) DEBUG: {1 32554 INVITE 1k3Hcf7IVCnjmhjZIJXU5S0x-LRhyB2x} <script>: new branch [0] to sip:bob@localhost;transport=tls 11(16) DEBUG: {1 32554 INVITE 1k3Hcf7IVCnjmhjZIJXU5S0x-LRhyB2x} <core> [core/msg_translator.c:2933]: create_via_hf(): id added: <;i=1>, rcv proto=3 11(16) DEBUG: {1 32554 INVITE 1k3Hcf7IVCnjmhjZIJXU5S0x-LRhyB2x} <core> [core/tcp_main.c:1747]: tcp_send(): no open tcp connection found, opening new one 11(16) DEBUG: {1 32554 INVITE 1k3Hcf7IVCnjmhjZIJXU5S0x-LRhyB2x} <core> [core/ip_addr.c:229]: print_ip(): tcpconn_new: new tcp connection: 34.240.160.168 11(16) DEBUG: {1 32554 INVITE 1k3Hcf7IVCnjmhjZIJXU5S0x-LRhyB2x} <core> [core/tcp_main.c:999]: tcpconn_new(): on port 5061, type 3 11(16) DEBUG: {1 32554 INVITE 1k3Hcf7IVCnjmhjZIJXU5S0x-LRhyB2x} <core> [core/tcp_main.c:1305]: tcpconn_add(): hashes: 1752:0:0, 2 11(16) DEBUG: {1 32554 INVITE 1k3Hcf7IVCnjmhjZIJXU5S0x-LRhyB2x} tls [tls_server.c:199]: tls_complete_init(): completing tls connection initialization 11(16) DEBUG: {1 32554 INVITE 1k3Hcf7IVCnjmhjZIJXU5S0x-LRhyB2x} tls [tls_server.c:162]: tls_get_connect_server_name(): xavp with outbound server name not found 11(16) DEBUG: {1 32554 INVITE 1k3Hcf7IVCnjmhjZIJXU5S0x-LRhyB2x} tls [tls_server.c:142]: tls_get_connect_server_id(): xavp with outbound server id not found 11(16) DEBUG: {1 32554 INVITE 1k3Hcf7IVCnjmhjZIJXU5S0x-LRhyB2x} tls [tls_server.c:228]: tls_complete_init(): Using initial TLS domain TLSc<default> (dom 0x7fe7740bdaf0 ctx 0x55d98553ca40 sn []) 11(16) DEBUG: {1 32554 INVITE 1k3Hcf7IVCnjmhjZIJXU5S0x-LRhyB2x} tls [tls_domain.c:1155]: tls_lookup_private_key(): Private key lookup for SSL_CTX-0x55d98553ca40: 0 11(16) DEBUG: {1 32554 INVITE 1k3Hcf7IVCnjmhjZIJXU5S0x-LRhyB2x} tls [tls_domain.c:737]: sr_ssl_ctx_info_callback(): SSL handshake started 11(16) DEBUG: {1 32554 INVITE 1k3Hcf7IVCnjmhjZIJXU5S0x-LRhyB2x} <core> [core/tcp_main.c:2641]: tcpconn_1st_send(): pending write on new connection 0x7fe7742cd200 (-1/122 bytes written) (err: 11 - Resource temporarily unavailable) 13(18) DEBUG: <core> [core/tcp_main.c:3540]: handle_ser_child(): read response= 7fe7742cd200, 5, fd 29 from 11 (16) 13(18) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG: io_watch_add(0x55d984d52f20, 29, 2, 0x7fe7742cd200), fd_no=18 11(16) DEBUG: {1 32554 INVITE 1k3Hcf7IVCnjmhjZIJXU5S0x-LRhyB2x} tm [t_funcs.c:372]: t_relay_to(): new transaction forwarded 11(16) DEBUG: {1 32554 INVITE 1k3Hcf7IVCnjmhjZIJXU5S0x-LRhyB2x} <core> [core/receive.c:353]: receive_msg(): request-route executed in: 10827 usec 11(16) DEBUG: {1 32554 INVITE 1k3Hcf7IVCnjmhjZIJXU5S0x-LRhyB2x} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list 0 11(16) DEBUG: {1 32554 INVITE 1k3Hcf7IVCnjmhjZIJXU5S0x-LRhyB2x} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list 0 11(16) DEBUG: {1 32554 INVITE 1k3Hcf7IVCnjmhjZIJXU5S0x-LRhyB2x} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list 0 11(16) DEBUG: {1 32554 INVITE 1k3Hcf7IVCnjmhjZIJXU5S0x-LRhyB2x} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list 0 11(16) DEBUG: {1 32554 INVITE 1k3Hcf7IVCnjmhjZIJXU5S0x-LRhyB2x} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list 0 11(16) DEBUG: {1 32554 INVITE 1k3Hcf7IVCnjmhjZIJXU5S0x-LRhyB2x} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list 0 11(16) DEBUG: {1 32554 INVITE 1k3Hcf7IVCnjmhjZIJXU5S0x-LRhyB2x} <core> [core/xavp.c:495]: xavp_destroy_list(): destroying xavp list 0 11(16) DEBUG: {1 32554 INVITE 1k3Hcf7IVCnjmhjZIJXU5S0x-LRhyB2x} <core> [core/receive.c:457]: receive_msg(): cleaning up 13(18) DEBUG: <core> [core/io_wait.h:777]: io_watch_chg(): DBG: io_watch_chg (0x55d984d52f20, 29, 0x1, 0xffffffff) fd_no=19 called 13(18) DEBUG: <core> [core/io_wait.h:602]: io_watch_del(): DBG: io_watch_del (0x55d984d52f20, 29, -1, 0x0) fd_no=19 called 13(18) DEBUG: <core> [core/tcp_main.c:4196]: handle_tcpconn_ev(): sending to child, events 1 13(18) DEBUG: <core> [core/tcp_main.c:3875]: send2child(): selected tcp worker 1 12(17) for activity on [tls:172.17.0.2:5061], 0x7fe7742cd200 12(17) DEBUG: <core> [core/tcp_read.c:1767]: handle_io(): received n=8 con=0x7fe7742cd200, fd=7 13(18) DEBUG: <core> [core/tcp_main.c:3279]: handle_tcp_child(): dead tcp child 1 (pid 17, no 12) (shutting down?) 13(18) DEBUG: <core> [core/io_wait.h:602]: io_watch_del(): DBG: io_watch_del (0x55d984d52f20, 27, -1, 0x0) fd_no=18 called 13(18) CRITICAL: <core> [core/pass_fd.c:277]: receive_fd(): EOF on 24 13(18) DEBUG: <core> [core/tcp_main.c:3512]: handle_ser_child(): dead child 12, pid 17 (shutting down?) 13(18) DEBUG: <core> [core/io_wait.h:602]: io_watch_del(): DBG: io_watch_del (0x55d984d52f20, 24, -1, 0x0) fd_no=17 called 0(1) ALERT: <core> [main.c:740]: handle_sigs(): child process 17 exited by a signal 11 0(1) ALERT: <core> [main.c:743]: handle_sigs(): core was generated 0(1) INFO: <core> [main.c:766]: handle_sigs(): terminating due to SIGCHLD 0(1) DEBUG: <core> [main.c:768]: handle_sigs(): terminating due to SIGCHLD 10(15) INFO: <core> [main.c:821]: sig_usr(): signal 15 received 1(6) INFO: <core> [main.c:821]: sig_usr(): signal 15 received 8(13) INFO: <core> [main.c:821]: sig_usr(): signal 15 received 7(12) INFO: <core> [main.c:821]: sig_usr(): signal 15 received 6(11) INFO: <core> [main.c:821]: sig_usr(): signal 15 received 5(10) INFO: <core> [main.c:821]: sig_usr(): signal 15 received 4(9) INFO: <core> [main.c:821]: sig_usr(): signal 15 received 3(8) INFO: <core> [main.c:821]: sig_usr(): signal 15 received 13(18) INFO: <core> [main.c:821]: sig_usr(): signal 15 received 9(14) INFO: <core> [main.c:821]: sig_usr(): signal 15 received 11(16) INFO: <core> [main.c:821]: sig_usr(): signal 15 received 2(7) INFO: <core> [main.c:821]: sig_usr(): signal 15 received 0(1) DEBUG: tm [t_funcs.c:85]: tm_shutdown(): start 0(1) DEBUG: tm [t_funcs.c:88]: tm_shutdown(): emptying hash table 0(1) DEBUG: tm [h_table.c:133]: free_cell_helper(): freeing transaction 0x7fe7742c9580 from h_table.c:465 0(1) DEBUG: tm [t_funcs.c:90]: tm_shutdown(): removing semaphores 0(1) DEBUG: tm [t_funcs.c:92]: tm_shutdown(): destroying tmcb lists 0(1) DEBUG: tm [t_funcs.c:95]: tm_shutdown(): done ```
### Additional Information
* **Kamailio Version** : Kamailio (OpenSER) SIP Server v5.2
* **Operating System**:
Kamailio was running on Linux Alpine from [kamailio/kamailio-ci:master-alpine](https://hub.docker.com/r/kamailio/kamailio-ci/) docker image.