[SR-Users] Guidance tracking down "qm_free(): BUG: freeing already freed pointer"

Tue Jul 27 16:34:09 CEST 2021

Correct--that it when I see the "qm_free(): BUG: freeing already freed 
pointer" error.  -A

On Tuesday, July 27, 2021 9:05:45 AM CDT Daniel-Constantin Mierla wrote:
> Hello,
> 
> to be clear for me: the error messages pop up only when outbound module
> is used and only for branches that are routed using outbound-specific
> connections?
> 
> Cheers,
> Daniel
> 
> On 25.07.21 04:55, Anthony Joseph Messina wrote:
> > I've come a bit further to find how to reproduce...
> > 
> > I have a single proxy/registrar mhomed setup and am trying to use outbound
> > (rather than nathelper) to test a few UACs that seem to maintain their
> > connection better with outbound.  (I am also using the dialog module).
> > 
> > Everything else seems to work properly in light testing, except for the
> > "qm_free(): BUG" issue, which only pops up when an "outbound" UAC is one
> > of
> > the branches (the other branches are not using outbound and are always
> > directly connected on the "internal" side of the mhomed network.
> > 
> > ####!define WITH_NAT -- disabled for outbound
> > #!define WITH_OUTBOUND
> > 
> > #!ifdef WITH_OUTBOUND
> > modparam("registrar", "outbound_mode", 1)
> > modparam("registrar", "flow_timer", 25)
> > #!endif
> > 
> > Snippet of the WITHINDLG route:
> > 
> > # Handle requests within SIP dialogs
> > route[WITHINDLG] {
> > 
> >         if(!has_totag()) return;
> >         
> >         # sequential request withing a dialog should
> >         # take the path determined by record-routing
> >         if(loose_route()) {
> >         
> >                 # dlg_manage() with dlg_match_mode=2
> >                 dlg_manage();
> >                 
> >                 #route(DLGURI); -- NAT disabled
> > 
> > On Friday, July 23, 2021 9:08:37 AM CDT Anthony Joseph Messina wrote:
> >> It's built upon the standard branch_route, but is customized to add
> >> rtpengine and dialog storage.
> >> 
> >> I've attached the related routes.  Thanks.  -A
> >> 
> >> On Friday, July 23, 2021 2:43:04 AM CDT Daniel-Constantin Mierla wrote:
> >>> Hello,
> >>> 
> >>> is it a custom configuration file or simply the default kamailio.cfg
> >>> with parts of branch_route enabled/disabled? If it is custom, can you
> >>> paste here the content of the branch route that you disable/enable parts
> >>> of it and get the error messages?
> >>> 
> >>> Overall, seem like trying to (re-)use a terminated transaction or
> >>> branch.
> >>> 
> >>> Cheers,
> >>> Daniel
> >>> 
> >>> On 23.07.21 00:19, Anthony Joseph Messina wrote:
> >>>> I'm seeking guidance on how to track down "qm_free(): BUG: freeing
> >>>> already
> >>>> freed pointer" which occurs only on branched calls.  These errors don't
> >>>> crash so I don't get any core dumps.  The different log entries below
> >>>> are
> >>>> the result of me selectively disabling sections of the script that
> >>>> apply
> >>>> in branch route, all to no avail.  I'm running Kamailio on the current
> >>>> tip of the 5.5 branch (1f9f6fff6e).  I'm reviewing
> >>>> https://www.kamailio.org/wiki/tutorials/troubleshooting/memory in the
> >>>> meantime as a place to start.
> >>>> 
> >>>> 
> >>>> version: kamailio 5.5.1-5.git1f9f6fff6e.fc34 (x86_64/linux) 7abebb
> >>>> 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_BLOCKLIST,
> >>>> HAVE_RESOLV_RES, TLS_PTHREAD_MUTEX_SHARED 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.
> >>>> 
> >>>> CRITICAL: <core> [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing
> >>>> already freed pointer (0x7f04b8f47e90), called from core:
> >>>> core/data_lump.c: free_lump(470), first free textops: textops.c:
> >>>> add_hf_helper(3474) - ignoring CRITICAL: <core>
> >>>> [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing already freed
> >>>> pointer
> >>>> (0x7f04b8f06c70), called from core: core/data_lump.c: free_lump(470),
> >>>> first free textops: textops.c: add_hf_helper(3474) - ignoring CRITICAL:
> >>>> <core> [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing already freed
> >>>> pointer (0x7f08e8f9cf80), called from core: core/data_lump.c:
> >>>> free_lump(470), first free core: core/parser/msg_parser.c:
> >>>> reset_ua(994)
> >>>> - ignoring CRITICAL: <core> [core/mem/q_malloc.c:519]: qm_free(): BUG:
> >>>> freeing already freed pointer (0x7f2afafa60d8), called from core:
> >>>> core/parser/sdp/sdp.c: free_sdp(825), first free core:
> >>>> core/parser/sdp/sdp.c: init_p_payload_attr(183) - ignoring CRITICAL:
> >>>> <core> [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing already freed
> >>>> pointer (0x7f2afae2a018), called from core: core/data_lump.c:
> >>>> free_lump(470), first free core: core/parser/msg_parser.c:
> >>>> reset_ua(994)
> >>>> - ignoring CRITICAL: <core> [core/mem/q_malloc.c:519]: qm_free(): BUG:
> >>>> freeing already freed pointer (0x7f2afae431e8), called from core:
> >>>> core/data_lump.c: free_lump(470), first free core:
> >>>> core/parser/msg_parser.c: reset_ua(994) - ignoring CRITICAL: <core>
> >>>> [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing already freed
> >>>> pointer
> >>>> (0x7f2afafa3900), called from core: core/data_lump.c: free_lump(470),
> >>>> first free core: core/parser/msg_parser.c: reset_ua(994) - ignoring
> >>>> CRITICAL: <core> [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing
> >>>> already freed pointer (0x7f5fd4044ef0), called from core:
> >>>> core/data_lump.c: free_lump(470), first free core:
> >>>> core/parser/msg_parser.c: reset_ua(994) - ignoring CRITICAL: <core>
> >>>> [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing already freed
> >>>> pointer
> >>>> (0x7ffbb2d2e2f0), called from core: core/data_lump.c: free_lump(470),
> >>>> first free core: core/parser/msg_parser.c: reset_ua(994) - ignoring
> >>>> CRITICAL: <core> [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing
> >>>> already freed pointer (0x7f6d1a50b1d8), called from core:
> >>>> core/data_lump.c: free_lump(470), first free core:
> >>>> core/parser/msg_parser.c: reset_ua(994) - ignoring CRITICAL: <core>
> >>>> [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing already freed
> >>>> pointer
> >>>> (0x7fc19c165c70), called from core: core/parser/msg_parser.c:
> >>>> reset_instance(916), first free core: core/parser/parse_addr_spec.c:
> >>>> free_to_params(895) - ignoring CRITICAL: <core>
> >>>> [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing already freed
> >>>> pointer
> >>>> (0x7fc19c17adb8), called from core: core/parser/msg_parser.c:
> >>>> reset_instance(916), first free core: core/parser/parse_addr_spec.c:
> >>>> free_to_params(895) - ignoring CRITICAL: <core>
> >>>> [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing already freed
> >>>> pointer
> >>>> (0x7fc19c125790), called from core: core/data_lump.c: free_lump(470),
> >>>> first free core: core/parser/msg_parser.c: reset_ua(994) - ignoring
> >>>> CRITICAL: <core> [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing
> >>>> already freed pointer (0x7f4d969c9d48), called from core:
> >>>> core/data_lump.c: free_lump(470), first free core:
> >>>> core/parser/msg_parser.c: reset_ua(994) - ignoring CRITICAL: <core>
> >>>> [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing already freed
> >>>> pointer
> >>>> (0x7fc29bdca3d0), called from core: core/data_lump.c: free_lump(470),
> >>>> first free textops: textops.c: add_hf_helper(3474) - ignoring CRITICAL:
> >>>> <core> [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing already freed
> >>>> pointer (0x7fc2c2eccc80), called from core: core/data_lump.c:
> >>>> free_lump(470), first free textops: textops.c: add_hf_helper(3474) -
> >>>> ignoring CRITICAL: <core> [core/mem/q_malloc.c:519]: qm_free(): BUG:
> >>>> freeing already freed pointer (0x7fc2c2ec52c0), called from core:
> >>>> core/data_lump.c: free_lump(470), first free core:
> >>>> core/parser/msg_parser.c: reset_ua(994) - ignoring CRITICAL: <core>
> >>>> [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing already freed
> >>>> pointer
> >>>> (0x7f910c04e240), called from core: core/data_lump.c: free_lump(470),
> >>>> first free textops: textops.c: add_hf_helper(3474) - ignoring CRITICAL:
> >>>> <core> [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing already freed
> >>>> pointer (0x7fa351286b18), called from core: core/parser/msg_parser.c:
> >>>> reset_instance(916), first free core: core/parser/parse_addr_spec.c:
> >>>> free_to_params(895) - ignoring CRITICAL: <core>
> >>>> [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing already freed
> >>>> pointer
> >>>> (0x7fa3512a7ae8), called from core: core/data_lump.c: free_lump(470),
> >>>> first free textops: textops.c: add_hf_helper(3474) - ignoring CRITICAL:
> >>>> <core> [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing already freed
> >>>> pointer (0x7fa0777d9e70), called from core: core/parser/msg_parser.c:
> >>>> reset_instance(916), first free core: core/parser/parse_addr_spec.c:
> >>>> free_to_params(895) - ignoring CRITICAL: <core>
> >>>> [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing already freed
> >>>> pointer
> >>>> (0x7fa0777d7a80), called from core: core/parser/msg_parser.c:
> >>>> reset_instance(916), first free core: core/parser/parse_addr_spec.c:
> >>>> free_to_params(895) - ignoring CRITICAL: <core>
> >>>> [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing already freed
> >>>> pointer
> >>>> (0x7f4f2c92cf20), called from core: core/data_lump.c: free_lump(470),
> >>>> first free core: core/parser/msg_parser.c: reset_ua(994) - ignoring
> >>>> CRITICAL: <core> [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing
> >>>> already freed pointer (0x7f4f2c8afa00), called from core:
> >>>> core/data_lump.c: free_lump(470), first free textops: textops.c:
> >>>> add_hf_helper(3474) - ignoring CRITICAL: <core>
> >>>> [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing already freed
> >>>> pointer
> >>>> (0x7f4f2c92aa48), called from core: core/parser/sdp/sdp.c:
> >>>> free_sdp(825),
> >>>> first free core: core/parser/msg_parser.c: reset_ua(994) - ignoring
> >>>> CRITICAL: <core> [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing
> >>>> already freed pointer (0x7fe55825eb30), called from core:
> >>>> core/parser/sdp/sdp.c: free_sdp(825), first free core:
> >>>> core/parser/sdp/sdp.c: init_p_payload_attr(183) - ignoring CRITICAL:
> >>>> <core> [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing already freed
> >>>> pointer (0x7f6526db8378), called from core: core/parser/sdp/sdp.c:
> >>>> free_sdp(825), first free core: core/parser/msg_parser.c: reset_ua(994)
> >>>> -
> >>>> ignoring CRITICAL: <core> [core/mem/q_malloc.c:519]: qm_free(): BUG:
> >>>> freeing already freed pointer (0x7fcd9b465980), called from core:
> >>>> core/parser/msg_parser.c: reset_instance(916), first free core:
> >>>> core/parser/hf.c: free_hdr_field_lst(217) - ignoring CRITICAL: <core>
> >>>> [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing already freed
> >>>> pointer
> >>>> (0x7ff7ca92ff60), called from core: core/parser/msg_parser.c:
> >>>> reset_instance(916), first free core: core/parser/parse_addr_spec.c:
> >>>> free_to_params(895) - ignoring CRITICAL: <core>
> >>>> [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing already freed
> >>>> pointer
> >>>> (0x7f978a2dc938), called from core: core/parser/msg_parser.c:
> >>>> reset_instance(916), first free core: core/parser/parse_addr_spec.c:
> >>>> free_to_params(895) - ignoring CRITICAL: <core>
> >>>> [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing already freed
> >>>> pointer
> >>>> (0x7f978a2b7eb8), called from core: core/parser/msg_parser.c:
> >>>> reset_instance(916), first free core: core/parser/parse_addr_spec.c:
> >>>> free_to_params(895) - ignoring CRITICAL: <core>
> >>>> [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing already freed
> >>>> pointer
> >>>> (0x7fa1556c1610), called from core: core/parser/sdp/sdp.c:
> >>>> free_sdp(825),
> >>>> first free core: core/parser/msg_parser.c: reset_ua(994) - ignoring
> >>>> CRITICAL: <core> [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing
> >>>> already freed pointer (0x7fd81dfbba78), called from core:
> >>>> core/parser/sdp/sdp.c: free_sdp(825), first free core:
> >>>> core/parser/msg_parser.c: reset_ua(994) - ignoring CRITICAL: <core>
> >>>> [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing already freed
> >>>> pointer
> >>>> (0x7fb2750d9988), called from core: core/parser/sdp/sdp.c:
> >>>> free_sdp(825),
> >>>> first free core: core/parser/msg_parser.c: reset_ua(994) - ignoring
> >>>> CRITICAL: <core> [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing
> >>>> already freed pointer (0x7fb2750e1b28), called from core:
> >>>> core/parser/msg_parser.c: reset_instance(916), first free core:
> >>>> core/parser/parse_addr_spec.c: free_to_params(895) - ignoring CRITICAL:
> >>>> <core> [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing already freed
> >>>> pointer (0x7f32f7b45d30), called from core: core/parser/msg_parser.c:
> >>>> reset_instance(916), first free core: core/parser/hf.c:
> >>>> free_hdr_field_lst(217) - ignoring CRITICAL: <core>
> >>>> [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing already freed
> >>>> pointer
> >>>> (0x7f35849e1940), called from core: core/parser/msg_parser.c:
> >>>> reset_instance(916), first free core: core/parser/hf.c:
> >>>> free_hdr_field_lst(217) - ignoring CRITICAL: <core>
> >>>> [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing already freed
> >>>> pointer
> >>>> (0x7fd3a2c04280), called from core: core/parser/sdp/sdp.c:
> >>>> free_sdp(825),
> >>>> first free core: core/parser/msg_parser.c: reset_ua(994) - ignoring
> >>>> CRITICAL: <core> [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing
> >>>> already freed pointer (0x7f5de857a040), called from core:
> >>>> core/parser/msg_parser.c: reset_instance(916), first free core:
> >>>> core/parser/hf.c: free_hdr_field_lst(217) - ignoring
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 228 bytes
Desc: This is a digitally signed message part.
URL: <http://lists.kamailio.org/pipermail/sr-users/attachments/20210727/cbf35bec/attachment.sig>