New subject: uac_req_send + evroute + crash

6 Dec 2023


      Hello,
Any idea about the crash below? I found a ticket regarding to this, I made some comments and backtraces there also:
https://github.com/kamailio/kamailio/issues/3635
Now this crash is very frequently, 3-4 times every day. There is a timer mechnism, where kamailio refreshes registrations towards asterisk automically to ensure continuous availability for mobile users.
The crash exists 3-5 secs after this refresh process, but not always. Sometimes this process runs fine only CRITICAL logs appears (mentioned below) after it, but sometimes kamailio crashes during writing these CRITICAL logs.
Peter
From: Dr. Barabás Péter via sr-users sr-users@lists.kamailio.org
Date: Wednesday, 2023. November 15. 17:03
To: Kamailio (SER) - Users Mailing List sr-users@lists.kamailio.org
Cc: Dr. Barabás Péter dr.peter.barabas@gmail.com
Subject: [SR-Users] Re: uac_req_send + evroute + crash
Hello Daniel,
I’m using kamailio 5.7.2 currently and this misterious crash occurs again. Now core files are generated also, here is the trace:
(gdb) bt
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x00007fae9a2d0859 in __GI_abort () at abort.c:79
#2  0x00005614ad79afd8 in qm_debug_check_frag (qm=0x7fae78e77000, f=0x7fae79805028, file=0x7fae77c8c134 "uac: uac_send.c", line=860, efile=0x5614ad936f99 "core/mem/q_malloc.c", eline=511) at core/mem/q_malloc.c:129
#3  0x00005614ad79f7c1 in qm_free (qmp=0x7fae78e77000, p=0x7fae79805060, file=0x7fae77c8c134 "uac: uac_send.c", func=0x7fae77c8cf10 <__func__.15157> "uac_send_tm_callback", line=860, mname=0x7fae77c8c014 "uac") at core/mem/q_malloc.c:511
#4  0x00005614ad7ab410 in qm_shm_free (qmp=0x7fae78e77000, p=0x7fae79805060, file=0x7fae77c8c134 "uac: uac_send.c", func=0x7fae77c8cf10 <__func__.15157> "uac_send_tm_callback", line=860, mname=0x7fae77c8c014 "uac") at core/mem/q_malloc.c:1350
#5  0x00007fae77c3686b in uac_send_tm_callback (t=0x7fae797dcf40, type=131072, ps=0x7fff8bd990d0) at uac_send.c:860
#6  0x00007fae783abc27 in run_trans_callbacks_internal (cb_lst=0x7fae797dcfe8, type=131072, trans=0x7fae797dcf40, params=0x7fff8bd990d0) at t_hooks.c:241
#7  0x00007fae783abd1e in run_trans_callbacks (type=131072, trans=0x7fae797dcf40, req=0x0, rpl=0x0, code=0) at t_hooks.c:261
#8  0x00007fae782bd8cb in free_cell_helper (dead_cell=0x7fae797dcf40, silent=0, fname=0x7fae783e9f62 "timer.c", fline=653) at h_table.c:165
#9  0x00007fae7837649c in wait_handler (ti=724701450, wait_tl=0x7fae797dcff8, data=0x7fae797dcf40) at timer.c:653
#10 0x00005614ad50be68 in timer_list_expire (t=724701450, h=0x7fae78ef5d18, slow_l=0x7fae78ef95e0, slow_mark=33641) at core/timer.c:857
#11 0x00005614ad50c3a7 in timer_handler () at core/timer.c:922
#12 0x00005614ad50c8d5 in timer_main () at core/timer.c:961
#13 0x00005614ad45fbf3 in main_loop () at main.c:1833
#14 0x00005614ad46ae93 in main (argc=14, argv=0x7fff8bd99b48) at main.c:3086
I think it occurs only if $uac_req(evroute) is set to 1 and I define the event_route[uac:reply] route.
My uac_reply route is easy:
if ($uac_req(evcode)==200) {
        xlog("L_INFO", "Registration for user $fU has been refreshed successfully.");
        $sht(vtp=>asterisk_restarted) = $null;
        route(SAVE_REG);
    }
    else {
        xlog("L_INFO", "Registration failed: $uac_req(evcode)");
    }
the SAVE_REG route is the following:
route[SAVE_REG] {
    xlog("L_INFO", "Saving pbx registration...:$fU");
    $var(maxExpiry) = MAX_PBX_REG_EXPIRY;
    route(GET_CLIENT_ID);
    sql_pvquery("ca", "select count(*) from pbxusers where user = '$fU'", "$var(pbxusersCnt)");
    if ($var(pbxusersCnt)>0) {
        if ($var(clientId) == 0) {
            sql_query("ca", "update pbxusers set expiry = TIMESTAMPADD(SECOND, $var(maxExpiry), SYSDATE()), online=1 where user = '$fU'");
        }
        else {
            sql_query("ca", "update pbxusers set client_id = '$var(clientId)', expiry = TIMESTAMPADD(SECOND, $var(maxExpiry), SYSDATE()), online=1 where user = '$fU'");
        }
    }
    else {
        sql_query("ca", "insert into pbxusers (user, expiry, client_id, online) values ('$fU', TIMESTAMPADD(SECOND, $var(maxExpiry), SYSDATE()), '$var(clientId)', 0)");
    }
}
And GET_CLIENT_ID route is:
route[GET_CLIENT_ID] {
     $var(clientId) = 0;
     if (is_present_hf("X-AT-ClientId")) {
        $var(clientId) = $hdr(X-AT-ClientId);
     }
}
Any idea, is it a bug or I do something wrong in config files?
Peter
From: Dr. Barabás Péter via sr-users sr-users@lists.kamailio.org
Date: Sunday, 2023. October 8. 18:49
To: miconda@gmail.com miconda@gmail.com, Kamailio (SER) - Users Mailing List sr-users@lists.kamailio.org
Cc: Dr. Barabás Péter dr.peter.barabas@gmail.com
Subject: [SR-Users] Re: uac_req_send + evroute + crash
Hello Daniel,
I do not see any “failed to send request with authentication”.
The next CRITICAL log appears after calling uac_req_send():
CRITICAL: <core> [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing already freed pointer (0x7f114995ada8), called from uac: uac_send.c: uac_send_tm_callback(860), first free uac: uac_send.c: uac_resend_tm_callback(732) - ignoring
Now we use kamailio 5.7.2 and no crash has come, but the critical logs above exist.
I saw a ticket in github: https://github.com/kamailio/kamailio/issues/3522, may the crash be similar or the same to that?
I will make a try next week with downgrading to 5.6.2 and try to reproduce the crash.
Peter
From: Daniel-Constantin Mierla miconda@gmail.com
Date: Friday, 2023. October 6. 13:55
To: Dr. Barabás Péter dr.peter.barabas@gmail.com, Kamailio (SER) - Users Mailing List sr-users@lists.kamailio.org
Subject: Re: [SR-Users] uac_req_send + evroute + crash
Hello,
do you also get error log messages that include "failed to send request with authentication"?
Which CRITICAL log appears when you call uac_req_send()? You pasted a couple of them in the initial email?
Cheers,
Daniel
On 05.10.23 17:32, Dr. Barabás Péter wrote:
Hello,
I used kamailio version 5.6.2. I refreshed to 5.7.2 today.
As I remember it was in kamailio long time ago therefore I could skip evroute route.
But this CRITICAL log appears always when I call uac_req_send().
I call it with settings:
$uac_req(auser) = $var(username);
$uac_req(apasswd) = $var(password);
Where username and password are retrived from web service before call.
In event_route I got first 401 after 200.
Peter
From: Daniel-Constantin Mierla miconda@gmail.commailto:miconda@gmail.com
Date: Thursday, 2023. October 5. 17:25
To: Kamailio (SER) - Users Mailing List sr-users@lists.kamailio.orgmailto:sr-users@lists.kamailio.org
Cc: Dr. Barabás Péter dr.peter.barabas@gmail.commailto:dr.peter.barabas@gmail.com
Subject: Re: [SR-Users] uac_req_send + evroute + crash
Hello,
On 05.10.23 16:34, Dr. Barabás Péter via sr-users wrote:
Hi All,
I use kamailio In front of Asterisk and kamailio needs to refresh registrations periodically towards Asterisk to ensure the availability of users from Asterisk side.
I use uac module and call uac_req_send() for sending REGISTER requests.
I set $uac_req(evroute)=1
The event_route[uac:reply] is called fine, but in kamailio logs I see the next lines:
CRITICAL: <core> [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing already freed pointer (0x7f114995ada8), called from uac: uac_send.c: uac_send_tm_callback(860), first free uac: uac_send.c: uac_resend_tm_callback(732) - ignoring
After some time, kamailio has crashed.
CRITICAL: <core> [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing already freed pointer (0x7f114995ada8), called from uac: uac_send.c: uac_send_tm_callback(860), first free uac: uac_send.c: uac_resend_tm_callback(732) – ignoring
CRITICAL: <core> [core/pass_fd.c:277]: receive_fd(): EOF on 34
ALERT: <core> [main.c:774]: handle_sigs(): child process 1407950 exited by a signal 6
what version of Kamailio are you using? Is Asterisk challenging for authentication?
Does it happen every time or seldom?
Cheers,
Daniel
--
Daniel-Constantin Mierla (@ asipto.com)
twitter.com/miconda -- linkedin.com/in/miconda
Kamailio Consultancy and Development Services
Kamailio Advanced Training - Online - Nov 14-16, 2023 -- asipto.com
--
Daniel-Constantin Mierla (@ asipto.com)
twitter.com/miconda -- linkedin.com/in/miconda
Kamailio Consultancy and Development Services
Kamailio Advanced Training - Online - Nov 14-16, 2023 -- asipto.com