<html><head><style>pre,code,address {
margin: 0px;
}
h1,h2,h3,h4,h5,h6 {
margin-top: 0.2em;
margin-bottom: 0.2em;
}
ol,ul {
margin-top: 0em;
margin-bottom: 0em;
}
blockquote {
margin-top: 0em;
margin-bottom: 0em;
}
</style></head><body><div></div><div>Hi list,</div><div><br></div><div>We're currently experiencing crashes on two OpenSIPS production servers, occurring several times daily. These instances are handling high call volumes (200–500 CPS).</div><div><br></div><div>I was able to capture a core dump, which appears to point to a double free issue within the dialog module.</div><div><br></div><div>The servers are running OpenSIPS installed via the official YUM repositories on CentOS 9.</div><div><br></div><div>I'd greatly appreciate any assistance in determining whether this is a bug in OpenSIPS itself or potentially a misconfiguration on my end. I've reviewed the configuration but haven't found anything that would obviously cause the dialog to be freed twice.</div><div><br></div><div>Thanks in advance!!</div><div></div><div><br></div><div>May 30 09:54:26 za-cl-jhb-avm-billing1.imcore.co.za opensips[2075647]: May 30 07:54:26 [2075647] CRITICAL:core:sig_usr: segfault in process pid: 2075647, id: 13</div><div>May 30 09:54:27 za-cl-jhb-avm-billing1.imcore.co.za opensips[2075638]: May 30 07:54:27 [2075638] WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 100 ms ago (now 70802550 ms), delaying execution</div><div>May 30 09:54:27 za-cl-jhb-avm-billing1.imcore.co.za opensips[2075638]: May 30 07:54:27 [2075638] WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 190 ms ago (now 70802640 ms), delaying execution</div><div>May 30 09:54:27 za-cl-jhb-avm-billing1.imcore.co.za opensips[2075638]: May 30 07:54:27 [2075638] WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 290 ms ago (now 70802740 ms), delaying execution</div><div>May 30 09:54:27 za-cl-jhb-avm-billing1.imcore.co.za opensips[2075638]: May 30 07:54:27 [2075638] WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 390 ms ago (now 70802840 ms), delaying execution</div><div>May 30 09:54:27 za-cl-jhb-avm-billing1.imcore.co.za opensips[2075638]: May 30 07:54:27 [2075638] WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 490 ms ago (now 70802940 ms), delaying execution</div><div>May 30 09:54:27 za-cl-jhb-avm-billing1.imcore.co.za opensips[2075638]: May 30 07:54:27 [2075638] WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 590 ms ago (now 70803040 ms), delaying execution</div><div>May 30 09:54:27 za-cl-jhb-avm-billing1.imcore.co.za opensips[2075638]: May 30 07:54:27 [2075638] WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 690 ms ago (now 70803140 ms), delaying execution</div><div>May 30 09:54:27 za-cl-jhb-avm-billing1.imcore.co.za opensips[2075638]: May 30 07:54:27 [2075638] WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 790 ms ago (now 70803240 ms), delaying execution</div><div>May 30 09:54:27 za-cl-jhb-avm-billing1.imcore.co.za opensips[2075638]: May 30 07:54:27 [2075638] WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 880 ms ago (now 70803330 ms), delaying execution</div><div>May 30 09:54:27 za-cl-jhb-avm-billing1.imcore.co.za opensips[2075638]: May 30 07:54:27 [2075638] WARNING:core:timer_ticker: timer task <tm-timer> already scheduled 980 ms ago (now 70803330 ms), delaying execution</div><div>May 30 09:54:27 za-cl-jhb-avm-billing1.imcore.co.za opensips[2075638]: May 30 07:54:27 [2075638] WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 980 ms ago (now 70803430 ms), delaying execution</div><div>May 30 09:54:28 za-cl-jhb-avm-billing1.imcore.co.za opensips[2075638]: May 30 07:54:28 [2075638] WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 1080 ms ago (now 70803530 ms), delaying execution</div><div>May 30 09:54:28 za-cl-jhb-avm-billing1.imcore.co.za opensips[2075638]: May 30 07:54:28 [2075638] WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 1180 ms ago (now 70803630 ms), delaying execution</div><div>May 30 09:54:28 za-cl-jhb-avm-billing1.imcore.co.za opensips[2075638]: May 30 07:54:28 [2075638] WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 1280 ms ago (now 70803730 ms), delaying execution</div><div>May 30 09:54:28 za-cl-jhb-avm-billing1.imcore.co.za opensips[2075638]: May 30 07:54:28 [2075638] WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 1380 ms ago (now 70803830 ms), delaying execution</div><div>May 30 09:54:28 za-cl-jhb-avm-billing1.imcore.co.za opensips[2075617]: May 30 07:54:28 [2075617] INFO:core:handle_sigs: child process 2075647 exited by a signal 11</div><div>May 30 09:54:28 za-cl-jhb-avm-billing1.imcore.co.za opensips[2075617]: May 30 07:54:28 [2075617] INFO:core:handle_sigs: core was generated</div><div>May 30 09:54:28 za-cl-jhb-avm-billing1.imcore.co.za opensips[2075617]: May 30 07:54:28 [2075617] INFO:core:handle_sigs: terminating due to SIGCHLD</div><div>May 30 09:54:28 za-cl-jhb-avm-billing1.imcore.co.za opensips[2075638]: May 30 07:54:28 [2075638] INFO:core:sig_usr: signal 15 received</div><div>May 30 09:54:28 za-cl-jhb-avm-billing1.imcore.co.za opensips[2075617]: May 30 07:54:28 [2075617] INFO:core:shutdown_opensips: process 1(2075635) [MI FIFO] terminated, still waiting for 11 more</div><div>May 30 09:54:28 za-cl-jhb-avm-billing1.imcore.co.za opensips[2075637]: May 30 07:54:28 [2075637] INFO:core:sig_usr: signal 15 received</div><div>May 30 09:54:28 za-cl-jhb-avm-billing1.imcore.co.za opensips[2075617]: May 30 07:54:28 [2075617] INFO:core:shutdown_opensips: process 2(2075636) [HTTPD *:8888] terminated, still waiting for 10 more</div><div>May 30 09:54:28 za-cl-jhb-avm-billing1.imcore.co.za opensips[2075617]: May 30 07:54:28 [2075617] INFO:core:shutdown_opensips: process 4(2075638) [timer] terminated, still waiting for 9 more</div><div>May 30 09:54:28 za-cl-jhb-avm-billing1.imcore.co.za opensips[2075617]: May 30 07:54:28 [2075617] INFO:core:shutdown_opensips: process 3(2075637) [time_keeper] terminated, still waiting for 8 more</div><div>May 30 09:54:33 za-cl-jhb-avm-billing1.imcore.co.za opensips[2075617]: May 30 07:54:33 [2075617] INFO:core:cleanup: cleanup</div><div>May 30 09:54:34 za-cl-jhb-avm-billing1.imcore.co.za opensips[2075617]: Thank you for running opensips</div><div>May 30 09:54:34 za-cl-jhb-avm-billing1.imcore.co.za systemd[1]: opensips.service: Main process exited, code=exited, status=139/n/a</div><div>May 30 09:54:34 za-cl-jhb-avm-billing1.imcore.co.za systemd[1]: opensips.service: Failed with result 'exit-code'.</div><div>May 30 09:54:34 za-cl-jhb-avm-billing1.imcore.co.za systemd[1]: opensips.service: Consumed 29min 51.610s CPU time.</div><div>May 30 09:54:34 za-cl-jhb-avm-billing1.imcore.co.za systemd[1]: opensips.service: Scheduled restart job, restart counter is at 4.</div><div>May 30 09:54:34 za-cl-jhb-avm-billing1.imcore.co.za systemd[1]: Stopped OpenSIPS is a very fast and flexible SIP (RFC3261) server.</div><div>May 30 09:54:34 za-cl-jhb-avm-billing1.imcore.co.za systemd[1]: opensips.service: Consumed 29min 51.610s CPU time.</div><div><br></div><div>coredump backtrace</div><div><br></div><div>(gdb) bt</div><div>#0 0x00007f3300f5c9bd in __strlen_avx2 () from /lib64/libc.so.6</div><div>#1 0x00007f3300e600f8 in __vfprintf_internal () from /lib64/libc.so.6</div><div>#2 0x00007f3300e608bf in buffered_vfprintf () from /lib64/libc.so.6</div><div>#3 0x0000556064e7835c in vfprintf (__ap=<optimized out>, __fmt=<optimized out>, __stream=<optimized out>) at /usr/include/bits/stdio2.h:109</div><div>#4 stderr_dprint (log_level=<optimized out>, facility=<optimized out>, module=<optimized out>, func=<optimized out>, format=<optimized out>, ap=<optimized out>) at /usr/src/debug/opensips-3.4.12-1.el9.x86_64/dprint.c:484</div><div>#5 0x0000556064e734e8 in dprint (log_level=-2, facility=128, module=0x55606504693c "core", func=0x556065078e98 <__FUNCTION__.1> "fm_free", </div><div> stderr_fmt=0x556065075900 "%s [%d] %s<b>CRITICAL:core:%s: freeing already freed %s pointer (%p), first free: %s: %s(%ld) - aborting!\n", </b></div><div> syslog_fmt=0x556065075908 "%sCRITICAL:core:%s: freeing already freed %s pointer (%p), first free: %s: %s(%ld) - aborting!\n", </div><div> format=0x556065075968 "freeing already freed %s pointer (%p), first free: %s: %s(%ld) - aborting!\n") at /usr/src/debug/opensips-3.4.12-1.el9.x86_64/dprint.c:698</div><div>#6 0x0000556064f368c6 in fm_free (fm=<optimized out>, p=0x7f32c11781b8, file=<optimized out>, func=<optimized out>, line=<optimized out>) at mem/f_malloc_dyn.h:240</div><div>#7 0x00007f3277549d3d in _shm_free (line=183, function=<synthetic pointer>, file=0x7f327757e0fc "dlg_hash.c", ptr=0x7f32c11781b8) at ../../evi/../mem/shm_mem.h:550</div><div>#8 free_dlg_dlg (dlg=0x7f32beab9148) at /usr/src/debug/opensips-3.4.12-1.el9.x86_64/modules/dialog/dlg_hash.c:183</div><div>#9 0x00007f327755133f in _unref_dlg (dlg=0x7f32beab9148, cnt=<optimized out>) at /usr/src/debug/opensips-3.4.12-1.el9.x86_64/modules/dialog/dlg_hash.c:1040</div><div>#10 0x00007f327753cc80 in dlg_onreply (<a href="mailto:t=t@entry">t=t@entry</a>=0x0, <a href="mailto:type=type@entry">type=type@entry</a>=4096, <a href="mailto:param=param@entry">param=param@entry</a>=0x7ffe5c0b72e0) at /usr/src/debug/opensips-3.4.12-1.el9.x86_64/modules/dialog/dlg_handlers.c:829</div><div>#11 0x00007f327753e94b in unreference_dialog_create (dialog=<optimized out>) at /usr/src/debug/opensips-3.4.12-1.el9.x86_64/modules/dialog/dlg_handlers.c:1254</div><div>#12 0x00007f327877c79b in empty_tmcb_list (head=0x7f32c224bbf0) at /usr/src/debug/opensips-3.4.12-1.el9.x86_64/modules/tm/t_hooks.c:53</div><div>#13 0x00007f327876cbff in free_cell (dead_cell=0x7f32c224bb80) at /usr/src/debug/opensips-3.4.12-1.el9.x86_64/modules/tm/h_table.c:127</div><div>#14 0x00007f32787982be in wait_handler (wait_tl=0x7f32c224bc00) at /usr/src/debug/opensips-3.4.12-1.el9.x86_64/modules/tm/timer.c:478</div><div>#15 timer_routine (ticks=70802, set=<optimized out>) at /usr/src/debug/opensips-3.4.12-1.el9.x86_64/modules/tm/timer.c:1115</div><div>#16 0x0000556064f0bca9 in handle_timer_job () at /usr/src/debug/opensips-3.4.12-1.el9.x86_64/timer.c:1018</div><div>#17 0x000055606502b5d5 in handle_io.constprop.2 (fm=0x7f32f8e82d20, event_type=1, idx=<optimized out>) at /usr/src/debug/opensips-3.4.12-1.el9.x86_64/timer.c:765</div><div>#18 0x0000556065037c08 in io_wait_loop_epoll.constprop.3.isra.0 (repeat=<optimized out>, t=<optimized out>, h=<optimized out>) at /usr/src/debug/opensips-3.4.12-1.el9.x86_64/io_wait_loop.h:305</div><div>#19 0x0000556064f0ebed in start_timer_extra_processes (chd_rank=<optimized out>) at /usr/src/debug/opensips-3.4.12-1.el9.x86_64/timer.c:932</div><div>#20 0x0000556064e52581 in main_loop () at /usr/src/debug/opensips-3.4.12-1.el9.x86_64/main.c:249</div><div>#21 main (argc=<optimized out>, argv=<optimized out>) at /usr/src/debug/opensips-3.4.12-1.el9.x86_64/main.c:966</div><div>(gdb)</div><div><br></div><div>Regards</div><div>Trevor Steyn</div><div><span></span></div></body></html>