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

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