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

Daniel-Constantin Mierla miconda at gmail.com
Tue Jul 27 16:05:45 CEST 2021 

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
>>>>
>>>> __________________________________________________________
>>>> Kamailio - Users Mailing List - Non Commercial Discussions
>>>>   * sr-users at lists.kamailio.org
>>>> Important: keep the mailing list in the recipients, do not reply only to the sender!
>>>> Edit mailing list options or unsubscribe:
>>>>   * https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users

-- 
Daniel-Constantin Mierla -- www.asipto.com
www.twitter.com/miconda -- www.linkedin.com/in/miconda

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.kamailio.org/pipermail/sr-users/attachments/20210727/9fc6cdc8/attachment.htm>

More information about the sr-users mailing list