<p></p>

<h3>Description</h3>

<p>Intermittent CRITICAL memory use after free at startup.</p>
<h3>Troubleshooting</h3>
<h4>Reproduction</h4>

<p>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.</p>
<h4>Debugging Data</h4>

<pre><code>(paste your debugging data here)
</code></pre>
<h4>Log Messages</h4>

<pre><code>Sep 10 15:29:22 product-name process-name[1764]: new user 'admin@172.51.1.1' 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

</code></pre>
<h4>SIP Traffic</h4>

<pre><code>Occurs at startup before SIP traffic relevant.
</code></pre>
<h3>Possible Solutions</h3>

<h3>Additional Information</h3>
<ul>
<li><strong>Kamailio Version</strong> - output of <code>kamailio -v</code></li>
</ul>
<pre><code>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
</code></pre>
<ul>
<li><strong>Operating System</strong>:</li>
</ul>

<pre><code>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
</code></pre>

<p style="font-size:small;-webkit-text-size-adjust:none;color:#666;">—<br />You are receiving this because you are subscribed to this thread.<br />Reply to this email directly, <a href="https://github.com/kamailio/kamailio/issues/2475">view it on GitHub</a>, or <a href="https://github.com/notifications/unsubscribe-auth/ABO7UZPQP32RIXP5XB6VFR3SFFMZVANCNFSM4RGCSVTA">unsubscribe</a>.<img src="https://github.com/notifications/beacon/ABO7UZKS5TASX7UKBB5WIZ3SFFMZVA5CNFSM4RGCSVTKYY3PNVWWK3TUL52HS4DFUVEXG43VMWVGG33NNVSW45C7NFSM4KNDZUFQ.gif" height="1" width="1" alt="" /></p>
<script type="application/ld+json">[
{
"@context": "http://schema.org",
"@type": "EmailMessage",
"potentialAction": {
"@type": "ViewAction",
"target": "https://github.com/kamailio/kamailio/issues/2475",
"url": "https://github.com/kamailio/kamailio/issues/2475",
"name": "View Issue"
},
"description": "View this Issue on GitHub",
"publisher": {
"@type": "Organization",
"name": "GitHub",
"url": "https://github.com"
}
}
]</script>