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

Daniel-Constantin Mierla miconda at gmail.com
Thu Jul 29 21:16:08 CEST 2021


I haven't developed nor used the outbound module myself, the lack of
support in hardphones made it unsolicited so far.

Maybe there is someone else that uses the outbound module and can share
the experience. There was a recent pull request to the module, so I
assume it's used by others.

Cheers,
Daniel

On 27.07.21 16:34, Anthony Joseph Messina wrote:
> 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

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




More information about the sr-users mailing list