[sr-dev] [kamailio/kamailio] Memory use after free - qm_realloc(): BUG: trying to realloc an already freed pointer (#2475)

gormania notifications at github.com
Fri Sep 11 01:15:38 CEST 2020


<!--
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 'admin at 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

```

#### 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
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.kamailio.org/pipermail/sr-dev/attachments/20200910/6f1c6f85/attachment-0001.htm>


More information about the sr-dev mailing list