<!-- Kamailio Project uses GitHub Issues only for bugs in the code or feature requests. Please use this template only for bug reports. If you have questions about using Kamailio or related to its configuration file, ask on sr-users mailing list: * http://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users If you have questions about developing extensions to Kamailio or its existing C code, ask on sr-dev mailing list: * http://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-dev Please try to fill this template as much as possible for any issue. It helps the developers to troubleshoot the issue. If there is no content to be filled in a section, the entire section can be removed. You can delete the comments from the template sections when filling. You can delete next line and everything above before submitting (it is a comment). --> ### Description <!-- Explain what you did, what you expected to happen, and what actually happened. --> Intermittent CRITICAL memory use after free at startup. ### Troubleshooting #### Reproduction <!-- If the issue can be reproduced, describe how it can be done. --> This happens intermittently on startup. Because our container restarts automatically and the issue is not seen other than at startup it is ultimately innocuous. But the restarts are a false alarm for sys admin. #### Debugging Data <!-- If you got a core dump, use gdb to extract troubleshooting data - full backtrace, local variables and the list of the code at the issue location. gdb /path/to/kamailio /path/to/corefile bt full info locals list If you are familiar with gdb, feel free to attach more of what you consider to be relevant. --> ``` (paste your debugging data here) ``` #### Log Messages <!-- Check the syslog file and if there are relevant log messages printed by Kamailio, add them next, or attach to issue, or provide a link to download them (e.g., to a pastebin site). --> ``` Sep 10 15:29:22 product-name process-name[1764]: new user &#39;admin(a)172.51.1.1&#39; added Sep 10 15:29:22 product-name process-name[1764]: Starting xxxx 1.5.8-0+gxxxxxxxx Sep 10 15:29:22 product-name process-name[1764]: Setting core dump pattern Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: tls [tls_init.c:503]: init_tls_compression(): disabling compression... Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: <core> [core/sctp_core.c:74]: sctp_core_check_support(): SCTP API not enabled - if you want to use it, load sctp module Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: <core> [core/tcp_main.c:5042]: init_tcp(): using epoll_lt as the io watch method (auto detected) Sep 10 15:29:22 product-name process-name[1764]: Listening on Sep 10 15:29:22 product-name process-name[1764]: udp: 172.51.1.1:5060 advertise 172.51.1.1:5060 Sep 10 15:29:22 product-name process-name[1764]: tcp: 172.51.1.1:5060 advertise 172.51.1.1:5060 Sep 10 15:29:22 product-name process-name[1764]: tls: 172.51.1.1:5061 advertise 172.51.1.1:5060 Sep 10 15:29:22 product-name process-name[1764]: Aliases: Sep 10 15:29:22 product-name process-name[1764]: tls: bb48d50a0892:5061 Sep 10 15:29:22 product-name process-name[1764]: tcp: bb48d50a0892:5060 Sep 10 15:29:22 product-name process-name[1764]: udp: bb48d50a0892:5060 Sep 10 15:29:22 product-name process-name[1764]: *: 172.51.1.1:* Sep 10 15:29:22 product-name process-name[1764]: Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: db_sqlite [db_sqlite.c:218]: mod_init(): SQlite library version 3.16.2 (compiled using 3.16.2) Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: rr [../outbound/api.h:52]: ob_load_api(): unable to import bind_ob - maybe module is not loaded Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: rr [rr_mod.c:177]: mod_init(): outbound module not available Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: http_async_client [http_async_client_mod.c:222]: mod_init(): Initializing Http Async module Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: [App] xxxx init Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: [---] Location reporting format: custom-1 Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: [---] Logging of location reporting: DISABLED Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: tls [tls_mod.c:377]: mod_init(): With ECDH-Support! Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: tls [tls_mod.c:380]: mod_init(): With Diffie Hellman Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: auth [auth_mod.c:345]: mod_init(): qop set, but nonce-count (nonce_count) support disabled Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: tls [tls_init.c:719]: init_tls_h(): compiled with openssl version "OpenSSL 1.0.2u 20 Dec 2019" (0x1000215f), kerberos support: off, compression: on Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: tls [tls_init.c:723]: init_tls_h(): installed openssl library version "OpenSSL 1.0.2u 20 Dec 2019" (0x1000215f), kerberos support: off, zlib compression: off Sep 10 15:29:22 product-name process-name[1764]: compiler: gcc -I. -I.. -I../include -fPIC -DOPENSSL_PIC -DOPENSSL_THREADS -D_REENTRANT -DDSO_DLFCN -DHAVE_DLFCN_H -m64 -DL_ENDIAN -g -O2 -fdebug-prefix-map=/build/openssl1.0-NNAFzi/openssl1.0-1.0.2u=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2 -Wl,-z,relro -Wa,--noexecstack -Wall -DMD32_REG_T=int -DOPENSSL_IA32_SSE2 -DOPENSSL_BN_ASM_MONT -DOPENSSL_BN_ASM_MONT5 -DOPENSSL_BN_ASM_GF2m -DRC4_ASM -DSHA1_ASM -DSHA256_ASM -DSHA512_ASM -DMD5_ASM -DAES_ASM -DVPAES_ASM -DBSAES_ASM -DWHIRLPOOL_ASM -DGHASH_ASM -DECP_NISTZ256_ASM Sep 10 15:29:22 product-name process-name[1764]: 0(1) WARNING: tls [tls_init.c:784]: init_tls_h(): openssl bug #1491 (crash/mem leaks on low memory) workaround enabled (on low memory tls operations will fail preemptively) with free memory thresholds 7864320 and 3932160 bytes Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: <core> [core/cfg/cfg_ctx.c:595]: cfg_set_now(): tls.low_mem_threshold1 has been changed to 7864320 Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: <core> [core/cfg/cfg_ctx.c:595]: cfg_set_now(): tls.low_mem_threshold2 has been changed to 3932160 Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: <core> [main.c:2779]: main(): processes (at least): 15 - shm size: 67108864 - pkg size: 8388608 Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: <core> [core/udp_server.c:154]: probe_max_receive_buffer(): SO_RCVBUF is initially 212992 Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: <core> [core/udp_server.c:206]: probe_max_receive_buffer(): SO_RCVBUF is finally 425984 Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: http_async_client [async_http.c:101]: async_http_init_sockets(): inter-process event notification sockets initialized Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: http_async_client [async_http.c:101]: async_http_init_sockets(): inter-process event notification sockets initialized Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: tls [tls_domain.c:303]: ksr_tls_fill_missing(): TLSs<default>: tls_method=18 Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: tls [tls_domain.c:315]: ksr_tls_fill_missing(): TLSs<default>: certificate='/etc/kamailio/publickey.pem' Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: tls [tls_domain.c:322]: ksr_tls_fill_missing(): TLSs<default>: ca_list='(null)' Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: tls [tls_domain.c:329]: ksr_tls_fill_missing(): TLSs<default>: crl='(null)' Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: tls [tls_domain.c:333]: ksr_tls_fill_missing(): TLSs<default>: require_certificate=0 Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: tls [tls_domain.c:340]: ksr_tls_fill_missing(): TLSs<default>: cipher_list='(null)' Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: tls [tls_domain.c:347]: ksr_tls_fill_missing(): TLSs<default>: private_key='/etc/kamailio/privatekey.pem' Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: tls [tls_domain.c:351]: ksr_tls_fill_missing(): TLSs<default>: verify_certificate=0 Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: tls [tls_domain.c:354]: ksr_tls_fill_missing(): TLSs<default>: verify_depth=9 Sep 10 15:29:22 product-name process-name[1764]: 0(1) NOTICE: tls [tls_domain.c:1087]: ksr_tls_fix_domain(): registered server_name callback handler for socket [:0], server_name='<default>' ... Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: tls [tls_domain.c:707]: set_verification(): TLSs<default>: No client certificate required and no checks performed Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: tls [tls_domain.c:303]: ksr_tls_fill_missing(): TLSc<default>: tls_method=18 Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: tls [tls_domain.c:315]: ksr_tls_fill_missing(): TLSc<default>: certificate='(null)' Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: tls [tls_domain.c:322]: ksr_tls_fill_missing(): TLSc<default>: ca_list='/etc/kamailio/sipcacert.pem' Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: tls [tls_domain.c:329]: ksr_tls_fill_missing(): TLSc<default>: crl='(null)' Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: tls [tls_domain.c:333]: ksr_tls_fill_missing(): TLSc<default>: require_certificate=1 Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: tls [tls_domain.c:340]: ksr_tls_fill_missing(): TLSc<default>: cipher_list='(null)' Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: tls [tls_domain.c:347]: ksr_tls_fill_missing(): TLSc<default>: private_key='(null)' Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: tls [tls_domain.c:351]: ksr_tls_fill_missing(): TLSc<default>: verify_certificate=1 Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: tls [tls_domain.c:354]: ksr_tls_fill_missing(): TLSc<default>: verify_depth=9 Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: tls [tls_domain.c:692]: set_verification(): TLSc<default>: Server MUST present valid certificate Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: http_async_client [async_http.c:84]: async_http_init_worker(): started worker process: 1 Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: http_async_client [async_http.c:84]: async_http_init_worker(): started worker process: 2 Sep 10 15:29:22 product-name process-name[1764]: 8(160) INFO: ctl [io_listener.c:214]: io_listen_loop(): io_listen_loop: using epoll_lt io watch method (config) Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: <core> [main.c:783]: handle_sigs(): SIGCHLD received, but no child has stopped, ignoring it Sep 10 15:29:22 product-name process-name[1764]: 6(158) CRITICAL: <core> [core/mem/q_malloc.c:646]: qm_realloc(): BUG: trying to realloc an already freed pointer 0x7f7d3413f928 , fragment 0x7f7d3413f8f0 -- aborting Sep 10 15:29:22 product-name process-name[1764]: 14(166) CRITICAL: <core> [core/pass_fd.c:277]: receive_fd(): EOF on 23 Sep 10 15:29:22 product-name process-name[1764]: 0(1) ALERT: <core> [main.c:766]: handle_sigs(): child process 158 exited by a signal 6 Sep 10 15:29:22 product-name process-name[1764]: 0(1) ALERT: <core> [main.c:769]: handle_sigs(): core was not generated Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: <core> [main.c:792]: handle_sigs(): terminating due to SIGCHLD Sep 10 15:29:22 product-name process-name[1764]: 1(153) INFO: <core> [main.c:847]: sig_usr(): signal 15 received Sep 10 15:29:22 product-name process-name[1764]: 2(154) INFO: <core> [main.c:847]: sig_usr(): signal 15 received Sep 10 15:29:22 product-name process-name[1764]: 4(156) INFO: <core> [main.c:847]: sig_usr(): signal 15 received Sep 10 15:29:22 product-name process-name[1764]: 14(166) CRITICAL: <core> [core/pass_fd.c:277]: receive_fd(): EOF on 15 Sep 10 15:29:22 product-name process-name[1764]: 3(155) INFO: <core> [main.c:847]: sig_usr(): signal 15 received Sep 10 15:29:22 product-name process-name[1764]: 14(166) CRITICAL: <core> [core/pass_fd.c:277]: receive_fd(): EOF on 18 Sep 10 15:29:22 product-name process-name[1764]: 7(159) INFO: <core> [main.c:847]: sig_usr(): signal 15 received Sep 10 15:29:22 product-name process-name[1764]: 5(157) INFO: <core> [main.c:847]: sig_usr(): signal 15 received Sep 10 15:29:22 product-name process-name[1764]: 9(161) INFO: <core> [main.c:847]: sig_usr(): signal 15 received Sep 10 15:29:22 product-name process-name[1764]: 10(162) INFO: <core> [main.c:847]: sig_usr(): signal 15 received Sep 10 15:29:22 product-name process-name[1764]: 8(160) INFO: <core> [main.c:847]: sig_usr(): signal 15 received Sep 10 15:29:22 product-name process-name[1764]: 11(163) INFO: <core> [main.c:847]: sig_usr(): signal 15 received Sep 10 15:29:22 product-name process-name[1764]: 14(166) INFO: <core> [main.c:847]: sig_usr(): signal 15 received Sep 10 15:29:22 product-name process-name[1764]: 13(165) INFO: <core> [main.c:847]: sig_usr(): signal 15 received Sep 10 15:29:22 product-name process-name[1764]: 12(164) INFO: <core> [main.c:847]: sig_usr(): signal 15 received Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: db_sqlite [db_sqlite.c:227]: mod_destroy(): SQlite terminate Sep 10 15:29:22 product-name process-name[1764]: 0(1) INFO: <core> [core/sctp_core.c:53]: sctp_core_destroy(): SCTP API not initialized ``` #### SIP Traffic <!-- If the issue is exposed by processing specific SIP messages, grab them with ngrep or save in a pcap file, then add them next, or attach to issue, or provide a link to download them (e.g., to a pastebin site). --> ``` Occurs at startup before SIP traffic relevant. ``` ### Possible Solutions <!-- If you found a solution or workaround for the issue, describe it. Ideally, provide a pull request with a fix. --> ### Additional Information * **Kamailio Version** - output of `kamailio -v` ``` version: kamailio 5.3.4 (x86_64/linux) f7690e-dirty flags: USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, USE_RAW_SOCKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MMAP, PKG_MALLOC, Q_MALLOC, F_MALLOC, TLSF_MALLOC, DBG_SR_MEMORY, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLACKLIST, HAVE_RESOLV_RES ADAPTIVE_WAIT_LOOPS 1024, MAX_RECV_BUFFER_SIZE 262144, MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. id: f7690e -dirty compiled with gcc 6.3.0 ``` * **Operating System**: <!-- Details about the operating system, the type: Linux (e.g.,: Debian 8.4, Ubuntu 16.04, CentOS 7.1, ...), MacOS, xBSD, Solaris, ...; Kernel details (output of `uname -a`) --> ``` Running under docker on Centos 7 Linux bb48d50a0892 3.10.0-1062.el7.x86_64 #1 SMP Wed Aug 7 18:08:02 UTC 2019 x86_64 GNU/Linux ``` -- 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/2475