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

Anthony Joseph Messina amessina at messinet.com
Sun Jul 25 04:55:03 CEST 2021


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/20210724/21c331e2/attachment.sig>


More information about the sr-users mailing list