6 Sep
2013
6 Sep
'13
11:52 a.m.
Just for fun, I caused another crash, and this time got this backtrace:
#0 0x000000000054274d in qm_status (qm=0x7f7a3a24a010) at
mem/q_malloc.c:775
#1 0x000000000053c10d in qm_debug_frag (qm=0x7f7a3a24a010,
f=0x7f7a3a4fc918)
at mem/q_malloc.c:141
#2 0x000000000053d32a in qm_malloc (qm=0x7f7a3a24a010, size=952,
file=0x5e5434 "<core>: rvalue.c", func=0x5e9fb4
"rval_new_empty",
line=236)
at mem/q_malloc.c:384
#3 0x00000000004bddee in rval_new_empty (extra_size=102) at rvalue.c:236
#4 0x00000000004bde65 in rval_new_str (s=0x7fffcb1c9110, extra_size=80)
at rvalue.c:260
#5 0x00000000004c057d in rval_convert (h=0x7fffcb1caf50,
msg=0x7f7a39799920,
type=RV_STR, v=0x7f7a3a3fd3d0, c=0x7fffcb1c92d0) at rvalue.c:1321
#6 0x00000000004c1a31 in rval_str_lop2 (h=0x7fffcb1caf50,
msg=0x7f7a39799920,
res=0x7fffcb1c9778, op=RVE_EQ_OP, l=0x7f7a3a3fd3d0, c1=0x7fffcb1c92d0,
r=0x7f7a3a3fdbd0, c2=0x0) at rvalue.c:1752
#7 0x00000000004c2667 in rval_expr_eval_int (h=0x7fffcb1caf50,
msg=0x7f7a39799920, res=0x7fffcb1c9778, rve=0x7f7a3a3fe2e8) at
rvalue.c:2058
#8 0x0000000000418dca in do_action (h=0x7fffcb1caf50, a=0x7f7a3a4001e8,
msg=0x7f7a39799920) at action.c:1050
#9 0x0000000000421ce7 in run_actions (h=0x7fffcb1caf50, a=0x7f7a3a3fd1a8,
msg=0x7f7a39799920) at action.c:1573
#10 0x00000000004206af in do_action (h=0x7fffcb1caf50, a=0x7f7a3a4006c0,
msg=0x7f7a39799920) at action.c:1374
#11 0x0000000000421ce7 in run_actions (h=0x7fffcb1caf50, a=0x7f7a3a3f3958,
msg=0x7f7a39799920) at action.c:1573
#12 0x0000000000419012 in do_action (h=0x7fffcb1caf50, a=0x7f7a3a405f80,
msg=0x7f7a39799920) at action.c:1065
#13 0x0000000000421ce7 in run_actions (h=0x7fffcb1caf50, a=0x7f7a3a405f80,
msg=0x7f7a39799920) at action.c:1573
#14 0x000000000041906b in do_action (h=0x7fffcb1caf50, a=0x7f7a3a4060c0,
msg=0x7f7a39799920) at action.c:1069
#15 0x0000000000421ce7 in run_actions (h=0x7fffcb1caf50, a=0x7f7a3a3da6a8,
msg=0x7f7a39799920) at action.c:1573
#16 0x0000000000416f5a in do_action (h=0x7fffcb1caf50, a=0x7f7a3a4125d0,
msg=0x7f7a39799920) at action.c:690
#17 0x0000000000421ce7 in run_actions (h=0x7fffcb1caf50, a=0x7f7a3a40b828,
msg=0x7f7a39799920) at action.c:1573
#18 0x0000000000422471 in run_top_route (a=0x7f7a3a40b828,
msg=0x7f7a39799920,
c=0x0) at action.c:1658
#19 0x00007f7a3954ce90 in run_failure_handlers (t=0x7f7935779ad8,
rpl=0x7f7a3a4fa4a8, code=404, extra_flags=64) at t_reply.c:1024
#20 0x00007f7a3954e00b in t_should_relay_response (Trans=0x7f7935779ad8,
new_code=404, branch=0, should_store=0x7fffcb1cb230,
should_relay=0x7fffcb1cb234, cancel_data=0x7fffcb1cb440,
reply=0x7f7a3a4fa4a8)
at t_reply.c:1300
#21 0x00007f7a3954fb98 in relay_reply (t=0x7f7935779ad8,
p_msg=0x7f7a3a4fa4a8,
branch=0, msg_status=404, cancel_data=0x7fffcb1cb440, do_put_on_wait=1)
at t_reply.c:1703
#22 0x00007f7a39552cce in reply_received (p_msg=0x7f7a3a4fa4a8) at
t_reply.c:2370
#23 0x00000000004591b1 in do_forward_reply (msg=0x7f7a3a4fa4a8, mode=0)
at forward.c:799
#24 0x0000000000459a40 in forward_reply (msg=0x7f7a3a4fa4a8) at
forward.c:882
#25 0x000000000049f776 in receive_msg (
buf=0x910e20 "SIP/2.0 404 Not Found\r\nVia: SIP/2.0/UDP
55.177.31.199;branch=z9hG4bK80fd.c731a837.0\r\nVia: SIP/2.0/UDP
68.68.120.41:5060;branch=z9hG4bK0cB61aa236182c0cf4d\r\nRecord-Route:
<sip:55.177.31.199;lr=on;ftag=gK0c275042;vsf=", 'A' <repeats 38
times>,
"--;dlgcor=a9.aca2>\r\nFrom:
<sip:16784841111@68.68.120.41>;tag=gK0c275042\r\nTo:
<sip:12066513489@55.177.31.199>;tag=ed7d54e69a\r\nCall-ID:
185377618_113020350(a)68.68.120.41\r\nCSeq: 15495 INVITE\r\nContact:
<sip:5282797646@195.105.225.111:5060;transport=udp>\r\nSupported:
100rel, replaces, norefersub\r\nAllow-Events: refer\r\nAllow: INVITE,
ACK, CANCEL, BYE, REFER, PRACK, INFO, UPDATE\r\nAccept:
application/sdp\r\nUser-Agent: snomONE/4.5.1.1107 Zeta
Perseids\r\nContent-Length: 0\r\n\r\n", len=717,
rcv_info=0x7fffcb1cb7c0) at receive.c:272
#26 0x0000000000532665 in udp_rcv_loop () at udp_server.c:557
#27 0x00000000004688a1 in main_loop () at main.c:1638
#28 0x000000000046b84a in main (argc=13, argv=0x7fffcb1cbaf8) at main.c:2566
This time, the overwritten fragment was:
Sep 6 04:47:54 gw1 /usr/local/sbin/kamailio[19629]: : <core>
[mem/q_malloc.c:140]: qm_debug_frag(): BUG: qm_*: fragm. 0x7f7a3a4fc918
(address 0x7f7a3a4fc948) beginning overwritten(3e653834323335)!
This time, the pedigree of the fragment address was much shorter:
Sep 6 04:47:50 gw1 /usr/local/sbin/kamailio[19631]: DEBUG: <core>
[mem/q_malloc.c:413]: qm_malloc(): qm_malloc(0x7f7a3a24a010, 56) returns
address 0x7f7a3a4fc918 frag. 0x7f7a3a4fc8e8 (size=96) on 1 -th hit
Sep 6 04:47:50 gw1 /usr/local/sbin/kamailio[19631]: DEBUG: <core>
[mem/q_malloc.c:437]: qm_free(): qm_free(0x7f7a3a24a010,
0x7f7a3a4fc918), called from <core>: data_lump.c: free_duped_lump_list(626)
Sep 6 04:47:54 gw1 /usr/local/sbin/kamailio[19627]: DEBUG: <core>
[mem/q_malloc.c:413]: qm_malloc(): qm_malloc(0x7f7a3a24a010, 48) returns
address 0x7f7a3a4fc918 frag. 0x7f7a3a4fc8e8 (size=48) on 1 -th hit
Sep 6 04:47:54 gw1 /usr/local/sbin/kamailio[19627]: DEBUG: <core>
[db_res.c:184]: db_allocate_rows(): allocate 48 bytes for rows at
0x7f7a3a4fc918
Sep 6 04:47:54 gw1 /usr/local/sbin/kamailio[19627]: DEBUG: <core>
[db_res.c:62]: db_free_rows(): freeing rows at 0x7f7a3a4fc918
Sep 6 04:47:54 gw1 /usr/local/sbin/kamailio[19627]: DEBUG: <core>
[mem/q_malloc.c:437]: qm_free(): qm_free(0x7f7a3a24a010,
0x7f7a3a4fc918), called from <core>: db_res.c: db_free_rows(63)
Sep 6 04:47:54 gw1 /usr/local/sbin/kamailio[19627]: DEBUG: <core>
[mem/q_malloc.c:413]: qm_malloc(): qm_malloc(0x7f7a3a24a010, 48) returns
address 0x7f7a3a4fc918 frag. 0x7f7a3a4fc8e8 (size=48) on 1 -th hit
Sep 6 04:47:54 gw1 /usr/local/sbin/kamailio[19627]: DEBUG: <core>
[db_val.c:127]: db_str2val(): allocate 48 bytes memory for STRING at
0x7f7a3a4fc918
Sep 6 04:47:54 gw1 /usr/local/sbin/kamailio[19627]: DEBUG: <core>
[db_row.c:68]: db_free_row(): free VAL_STRING[14]
'<urn:uuid:d3bcbc0b-7fde-4db5-9871-79efb9b07aab>' at 0x7f7a3a4fc918
Sep 6 04:47:54 gw1 /usr/local/sbin/kamailio[19627]: DEBUG: <core>
[mem/q_malloc.c:437]: qm_free(): qm_free(0x7f7a3a24a010,
0x7f7a3a4fc918), called from <core>: db_row.c: db_free_row(69)
Sep 6 04:47:54 gw1 /usr/local/sbin/kamailio[19627]: DEBUG: <core>
[mem/q_malloc.c:413]: qm_malloc(): qm_malloc(0x7f7a3a24a010, 48) returns
address 0x7f7a3a4fc918 frag. 0x7f7a3a4fc8e8 (size=48) on 1 -th hit
Sep 6 04:47:54 gw1 /usr/local/sbin/kamailio[19629]: DEBUG: <core>
[mem/q_malloc.c:413]: qm_malloc(): qm_malloc(0x7f7a3a24a010, 952)
returns address 0x7f7a3a4fc948 frag. 0x7f7a3a4fc918 (size=952) on 1 -th hit
Sep 6 04:47:54 gw1 /usr/local/sbin/kamailio[19629]: DEBUG: <core>
[mem/q_malloc.c:472]: qm_free(): qm_free: freeing frag. 0x7f7a3a4fc918
alloc'ed from <core>: rvalue.c: rval_new_empty(236)
Sep 6 04:47:54 gw1 /usr/local/sbin/kamailio[19629]: : <core>
[mem/q_malloc.c:140]: qm_debug_frag(): BUG: qm_*: fragm. 0x7f7a3a4fc918
(address 0x7f7a3a4fc948) beginning overwritten(3e653834323335)!
Sep 6 04:48:06 gw1 /usr/local/sbin/kamailio[19627]: DEBUG: qm_status:
6792. N address=0x7f7a3a4fc918 frag=0x7f7a3a4fc8e8 size=48 used=1
But the common factor is database involvement beforehand.
Am I right to suppose that this points to a buffer overflow in
db_postgres or libsrdb1 somewhere?
-- Alex
--
Alex Balashov - Principal
Evariste Systems LLC
235 E Ponce de Leon Ave
Suite 106
Decatur, GA 30030
United States
Tel: +1-678-954-0670
Web: http://www.evaristesys.com/, http://www.alexbalashov.com/