Igor Potjevlesch
2014-06-25 12:49:29 UTC
Hello,
We updated this morning Kamailio in 4.1.4 with your patch.
Kamailio crashed again this afternoon.
here an extract from /var/log/messages :
Jun 25 13:49:01 /usr/local/sbin/kamailio[20259]: WARNING: <script>:
time=[Wed Jun 25 13:49:01 2014] call
id=[***@A.B.C.D] call seq=[929405] contact
header=[<sip:***@A.B.C.D:2057;transport=UDP>] from
uri=[sip:***@domain;user=phone] from tag=[16632949] request's
method=[INVITE] request's uri=[sip:***@domain;user=phone] to
uri=[sip:***@domain;user=phone] to tag=[<null>] sip message
id=[46275] process id=[20259] ip source=[A.B.C.D] flags=[2]
ua=[(innovaphone IP6010/9.00 hotfix24 [9.061271/9061271/300])], INVITE from
'untrusted' host
Jun 25 13:49:01 /usr/local/sbin/kamailio[20259]: WARNING: <script>:
time=[Wed Jun 25 13:49:01 2014] call
id=[***@A.B.C.D] call seq=[929405] contact
header=[<sip:***@A.B.C.D:2057;transport=UDP>] from
uri=[sip:***@domain;user=phone] from tag=[16632949] request's
method=[INVITE] request's uri=[sip:***@domain;user=phone] to
uri=[sip:***@domain;user=phone] to tag=[<null>] sip message
id=[46275] process id=[20259] ip source=[A.B.C.D] flags=[2], INVITE from an
authorized SIP trunk
Jun 25 13:49:01 /usr/local/sbin/kamailio[20259]: WARNING: <script>:
time=[Wed Jun 25 13:49:01 2014] call
id=[***@A.B.C.D] call seq=[929405] contact
header=[<sip:***@A.B.C.D:2057;transport=UDP>] from
uri=[sip:***@domain;user=phone] from tag=[16632949] request's
method=[INVITE] request's uri=[sip:***@domain;user=phone] to
uri=[sip:***@domain;user=phone] to tag=[<null>] sip message
id=[46275] process id=[20259] ip source=[A.B.C.D] flags=[2], INVITE from an
authorized SDA for current SIP trunk
Jun 25 13:49:01 /usr/local/sbin/kamailio[20259]: INFO: carrierroute
[cr_func.c:710]: cr_do_route(): uri 0123456789 was rewritten to
sip:***@GW, carrier 1, domain 1
Jun 25 13:49:02 /usr/local/sbin/kamailio[20259]: : <core>
[mem/q_malloc.c:140]: qm_debug_frag(): BUG: qm_*: fragm. 0x7f12803cb450
(address 0x7f12803cb480) beginning overwritten(abcdefed)!
And this is the btfull :
#0 0x0000003d6f6328a5 in raise () from /lib64/libc.so.6
No symbol table info available.
#1 0x0000003d6f634085 in abort () from /lib64/libc.so.6
No symbol table info available.
#2 0x0000000000546d3c in qm_debug_frag (qm=0x7f1280275010,
f=0x7f12803cb450) at mem/q_malloc.c:142
#3 0x0000000000548b26 in qm_free (qm=0x7f1280275010, p=0x7f12803cb480,
file=0x6276a0 "<core>: parser/parse_ppi_pai.c", func=0x627a00
"free_pai_ppi_body", line=102) at mem/q_malloc.c:464
#4 0x000000000056e5e6 in free_pai_ppi_body (pid_b=0x7f12803cb480) at
parser/parse_ppi_pai.c:102
#5 0x000000000054fee0 in clean_hdr_field (hf=0x7f1274c3c238) at
parser/hf.c:126
#6 0x00007f127cb6dde6 in acc_onreply (t=0x7f1274c157f0,
req=0x7f1274c3ac08, reply=0x7f12804a6d70, code=200) at acc_logic.c:501
#7 0x00007f127cb6e30a in tmcb_func (t=0x7f1274c157f0, type=512,
ps=0x7fff0b015580) at acc_logic.c:573
#8 0x00007f127ed68478 in run_trans_callbacks_internal
(cb_lst=0x7f1274c15860, type=512, trans=0x7f1274c157f0,
params=0x7fff0b015580) at t_hooks.c:290
#9 0x00007f127ed6868a in run_trans_callbacks_with_buf (type=512,
rbuf=0x7f1274c158b0, req=0x7f1274c3ac08, repl=0x7f12804a6d70, flags=200) at
t_hooks.c:336
#10 0x00007f127ed9ac06 in relay_reply (t=0x7f1274c157f0,
p_msg=0x7f12804a6d70, branch=0, msg_status=200, cancel_data=0x7fff0b0158e0,
do_put_on_wait=1) at t_reply.c:2001
#11 0x00007f127ed9d0b7 in reply_received (p_msg=0x7f12804a6d70) at
t_reply.c:2499
#12 0x000000000045d837 in do_forward_reply (msg=0x7f12804a6d70, mode=0) at
forward.c:777
#13 0x000000000045e0f8 in forward_reply (msg=0x7f12804a6d70) at
forward.c:860
#14 0x00000000004a58e7 in receive_msg (buf=0x924600 "SIP/2.0 200 OK\r\nVia:
SIP/2.0/UDP
A.B.C.D;branch=z9hG4bK512b.82b197888826f6b60c0c63b79801294d.0;received=A.B.C.D\r\nVia:
SIP/2.0/UDP A.B.C.D:2057;branch=z9hG4bK-129F259C;rport=2057\r\nCall-ID:
cb0"...,
len=1124, rcv_info=0x7fff0b015c60) at receive.c:273
#15 0x000000000053c9a8 in udp_rcv_loop () at udp_server.c:536
#16 0x000000000046d42b in main_loop () at main.c:1617
#17 0x0000000000470533 in main (argc=7, argv=0x7fff0b015f98) at main.c:2545
It seems to be the same problem but in a different source. Can you help me?
Regards,
Igor.
We updated this morning Kamailio in 4.1.4 with your patch.
Kamailio crashed again this afternoon.
here an extract from /var/log/messages :
Jun 25 13:49:01 /usr/local/sbin/kamailio[20259]: WARNING: <script>:
time=[Wed Jun 25 13:49:01 2014] call
id=[***@A.B.C.D] call seq=[929405] contact
header=[<sip:***@A.B.C.D:2057;transport=UDP>] from
uri=[sip:***@domain;user=phone] from tag=[16632949] request's
method=[INVITE] request's uri=[sip:***@domain;user=phone] to
uri=[sip:***@domain;user=phone] to tag=[<null>] sip message
id=[46275] process id=[20259] ip source=[A.B.C.D] flags=[2]
ua=[(innovaphone IP6010/9.00 hotfix24 [9.061271/9061271/300])], INVITE from
'untrusted' host
Jun 25 13:49:01 /usr/local/sbin/kamailio[20259]: WARNING: <script>:
time=[Wed Jun 25 13:49:01 2014] call
id=[***@A.B.C.D] call seq=[929405] contact
header=[<sip:***@A.B.C.D:2057;transport=UDP>] from
uri=[sip:***@domain;user=phone] from tag=[16632949] request's
method=[INVITE] request's uri=[sip:***@domain;user=phone] to
uri=[sip:***@domain;user=phone] to tag=[<null>] sip message
id=[46275] process id=[20259] ip source=[A.B.C.D] flags=[2], INVITE from an
authorized SIP trunk
Jun 25 13:49:01 /usr/local/sbin/kamailio[20259]: WARNING: <script>:
time=[Wed Jun 25 13:49:01 2014] call
id=[***@A.B.C.D] call seq=[929405] contact
header=[<sip:***@A.B.C.D:2057;transport=UDP>] from
uri=[sip:***@domain;user=phone] from tag=[16632949] request's
method=[INVITE] request's uri=[sip:***@domain;user=phone] to
uri=[sip:***@domain;user=phone] to tag=[<null>] sip message
id=[46275] process id=[20259] ip source=[A.B.C.D] flags=[2], INVITE from an
authorized SDA for current SIP trunk
Jun 25 13:49:01 /usr/local/sbin/kamailio[20259]: INFO: carrierroute
[cr_func.c:710]: cr_do_route(): uri 0123456789 was rewritten to
sip:***@GW, carrier 1, domain 1
Jun 25 13:49:02 /usr/local/sbin/kamailio[20259]: : <core>
[mem/q_malloc.c:140]: qm_debug_frag(): BUG: qm_*: fragm. 0x7f12803cb450
(address 0x7f12803cb480) beginning overwritten(abcdefed)!
And this is the btfull :
#0 0x0000003d6f6328a5 in raise () from /lib64/libc.so.6
No symbol table info available.
#1 0x0000003d6f634085 in abort () from /lib64/libc.so.6
No symbol table info available.
#2 0x0000000000546d3c in qm_debug_frag (qm=0x7f1280275010,
f=0x7f12803cb450) at mem/q_malloc.c:142
#3 0x0000000000548b26 in qm_free (qm=0x7f1280275010, p=0x7f12803cb480,
file=0x6276a0 "<core>: parser/parse_ppi_pai.c", func=0x627a00
"free_pai_ppi_body", line=102) at mem/q_malloc.c:464
#4 0x000000000056e5e6 in free_pai_ppi_body (pid_b=0x7f12803cb480) at
parser/parse_ppi_pai.c:102
#5 0x000000000054fee0 in clean_hdr_field (hf=0x7f1274c3c238) at
parser/hf.c:126
#6 0x00007f127cb6dde6 in acc_onreply (t=0x7f1274c157f0,
req=0x7f1274c3ac08, reply=0x7f12804a6d70, code=200) at acc_logic.c:501
#7 0x00007f127cb6e30a in tmcb_func (t=0x7f1274c157f0, type=512,
ps=0x7fff0b015580) at acc_logic.c:573
#8 0x00007f127ed68478 in run_trans_callbacks_internal
(cb_lst=0x7f1274c15860, type=512, trans=0x7f1274c157f0,
params=0x7fff0b015580) at t_hooks.c:290
#9 0x00007f127ed6868a in run_trans_callbacks_with_buf (type=512,
rbuf=0x7f1274c158b0, req=0x7f1274c3ac08, repl=0x7f12804a6d70, flags=200) at
t_hooks.c:336
#10 0x00007f127ed9ac06 in relay_reply (t=0x7f1274c157f0,
p_msg=0x7f12804a6d70, branch=0, msg_status=200, cancel_data=0x7fff0b0158e0,
do_put_on_wait=1) at t_reply.c:2001
#11 0x00007f127ed9d0b7 in reply_received (p_msg=0x7f12804a6d70) at
t_reply.c:2499
#12 0x000000000045d837 in do_forward_reply (msg=0x7f12804a6d70, mode=0) at
forward.c:777
#13 0x000000000045e0f8 in forward_reply (msg=0x7f12804a6d70) at
forward.c:860
#14 0x00000000004a58e7 in receive_msg (buf=0x924600 "SIP/2.0 200 OK\r\nVia:
SIP/2.0/UDP
A.B.C.D;branch=z9hG4bK512b.82b197888826f6b60c0c63b79801294d.0;received=A.B.C.D\r\nVia:
SIP/2.0/UDP A.B.C.D:2057;branch=z9hG4bK-129F259C;rport=2057\r\nCall-ID:
cb0"...,
len=1124, rcv_info=0x7fff0b015c60) at receive.c:273
#15 0x000000000053c9a8 in udp_rcv_loop () at udp_server.c:536
#16 0x000000000046d42b in main_loop () at main.c:1617
#17 0x0000000000470533 in main (argc=7, argv=0x7fff0b015f98) at main.c:2545
It seems to be the same problem but in a different source. Can you help me?
Regards,
Igor.
Hello,
we didn't set the early media parameter . its '0' by default, isn't it?
regards,
Igor
Hello,
we didn't set the early media parameter . its '0' by default, isn't it?
regards,
Igor
Hello,
if you get a record for 180 response, then you have also the early_media
parameter set for acc module, isn't it?
In the morning I pushed a patch that should fix this issue. Use latest
release 4.1.4 and see if works fine. Report the results to know that it is
gone or not.
Cheers,
Daniel
Hello,
We don't use $ai in xlog nor in other process. only in ACC.
modparam("acc", "db_flag", FLT_ACC)
modparam("acc", "db_missed_flag", 3)
modparam("acc", "db_url", DBURLWO)
modparam("acc", "db_extra",
"src_user=$fU;username=$Au;src_domain=$fd;src_ip=$si;src_pai=$ai;"
"dst_ouser=$tU;dst_user=$rU;dst_domain=$rd")
For the 3781-4b1-572014182635-OGNAJ-1-A.B.C.D there is a code 180
ringing in the INVITE in ACC table.
regards,
Igor
Daniel-Constantin Mierla - http://www.asipto.comhttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
parameter set for acc module, isn't it?
In the morning I pushed a patch that should fix this issue. Use latest
release 4.1.4 and see if works fine. Report the results to know that it is
gone or not.
Cheers,
Daniel
Hello,
We don't use $ai in xlog nor in other process. only in ACC.
modparam("acc", "db_flag", FLT_ACC)
modparam("acc", "db_missed_flag", 3)
modparam("acc", "db_url", DBURLWO)
modparam("acc", "db_extra",
"src_user=$fU;username=$Au;src_domain=$fd;src_ip=$si;src_pai=$ai;"
"dst_ouser=$tU;dst_user=$rU;dst_domain=$rd")
For the 3781-4b1-572014182635-OGNAJ-1-A.B.C.D there is a code 180
ringing in the INVITE in ACC table.
regards,
Igor
Few more things...
Are you recording 1xx events? Can you check to see if there is another
record in acc table for the same call? You can search by call-id
3781-4b1-572014182635-OGNAJ-1-A.B.C.D
Eventually, send also the parameters you set for acc module.
Cheers,
Daniel
Hello,
so you don't print $ai in xlog() statements nor use it in any
assignments or other functions besides acc parameter?
Cheers,
Daniel
Hello,
We do not access to the P-asserted-identity in our configuration but
we added the field PAI in the db base ACC ( for INVITE, ACK and BYE) .
I dont know if it's in request_route, failure_route or branch_route .
(gdb) p mem_block
$3 = (struct qm_block *) 0x7f6a6bef1010
(gdb) p shm_block
$4 = (struct qm_block *) 0x7f6a5666a000
Regards,
Igor
Daniel-Constantin Mierla - http://www.asipto.comhttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
--
Daniel-Constantin Mierla - http://www.asipto.comhttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
--Are you recording 1xx events? Can you check to see if there is another
record in acc table for the same call? You can search by call-id
3781-4b1-572014182635-OGNAJ-1-A.B.C.D
Eventually, send also the parameters you set for acc module.
Cheers,
Daniel
Hello,
so you don't print $ai in xlog() statements nor use it in any
assignments or other functions besides acc parameter?
Cheers,
Daniel
Hello,
We do not access to the P-asserted-identity in our configuration but
we added the field PAI in the db base ACC ( for INVITE, ACK and BYE) .
I dont know if it's in request_route, failure_route or branch_route .
(gdb) p mem_block
$3 = (struct qm_block *) 0x7f6a6bef1010
(gdb) p shm_block
$4 = (struct qm_block *) 0x7f6a5666a000
Regards,
Igor
Hello,
cloning to shm for tm seems ok. Can you tell where you access
P-Asserted-Identity header, via variables? Does it happen in request_route,
failure_route or branch_route?
p mem_block
p shm_block
I want to see if parsed filed point to shm or pkg memory.
Cheers,
Daniel
Hello,
at least I narrowed it down a bit. It is empty also in the clone stored
in transaction, so it happens either during cloning or before. I will have
to check these parts.
Cheers,
Daniel
Hello,
(gdb) p *t->uas.request->pai
$1 = {type = HDR_PAI_T, name = {
s = 0x7f6a60cd34b8 "P-Asserted-Identity: \"0987654321\"
INVITE, BYE, REGISTER, ACK, OPTIONS, CANCEL, SUBSCRIBE, NOTIFY, INFO,
REFER, UPD"..., len = 19}, body = {
path,"..., len = 43}, len = 66, parsed = 0x7f6a6d81da88, next =
0x7f6a60cd3f10}
(gdb) p *((p_id_body_t*)(t->uas.request->pai->parsed))
$2 = {id = 0x0, num_ids = 0, next = 0x0}
*Did *you find one thing in common between the 2 occurrences? Do you
have any ideas about what is the cause of this pai reset?
Regards,
Igor
Daniel-Constantin Mierla - http://www.asipto.comhttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
--
Daniel-Constantin Mierla - http://www.asipto.comhttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
--cloning to shm for tm seems ok. Can you tell where you access
P-Asserted-Identity header, via variables? Does it happen in request_route,
failure_route or branch_route?
p mem_block
p shm_block
I want to see if parsed filed point to shm or pkg memory.
Cheers,
Daniel
Hello,
at least I narrowed it down a bit. It is empty also in the clone stored
in transaction, so it happens either during cloning or before. I will have
to check these parts.
Cheers,
Daniel
Hello,
(gdb) p *t->uas.request->pai
$1 = {type = HDR_PAI_T, name = {
s = 0x7f6a60cd34b8 "P-Asserted-Identity: \"0987654321\"
INVITE, BYE, REGISTER, ACK, OPTIONS, CANCEL, SUBSCRIBE, NOTIFY, INFO,
REFER, UPD"..., len = 19}, body = {
path,"..., len = 43}, len = 66, parsed = 0x7f6a6d81da88, next =
0x7f6a60cd3f10}
(gdb) p *((p_id_body_t*)(t->uas.request->pai->parsed))
$2 = {id = 0x0, num_ids = 0, next = 0x0}
*Did *you find one thing in common between the 2 occurrences? Do you
have any ideas about what is the cause of this pai reset?
Regards,
Igor
Hello,
p *t->uas.request->pai
p *((p_id_body_t*)(t->uas.request->pai->parsed))
Cheers,
Daniel
Hello,
(gdb) frame 5
#5 0x00007f6a687e9b43 in acc_onreply (t=0x7f6a60d16ff8,
req=0x7f6a60cd2c10, reply=0x7f6a6c119aa8, code=200) at acc_logic.c:471
471 acc_db_request(req);
--
Daniel-Constantin Mierla - http://www.asipto.comhttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
--p *t->uas.request->pai
p *((p_id_body_t*)(t->uas.request->pai->parsed))
Cheers,
Daniel
Hello,
(gdb) frame 5
#5 0x00007f6a687e9b43 in acc_onreply (t=0x7f6a60d16ff8,
req=0x7f6a60cd2c10, reply=0x7f6a6c119aa8, code=200) at acc_logic.c:471
471 acc_db_request(req);
--
Daniel-Constantin Mierla - http://www.asipto.comhttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
Daniel-Constantin Mierla - http://www.asipto.comhttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
--
Daniel-Constantin Mierla - http://www.asipto.comhttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
Daniel-Constantin Mierla - http://www.asipto.comhttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
--
Daniel-Constantin Mierla - http://www.asipto.comhttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
Daniel-Constantin Mierla - http://www.asipto.comhttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda