Thanks, I'll analyze the logs as I get a chance very soon.
Cheers,
Daniel
On Fri, Sep 6, 2013 at 10:52 AM, Alex Balashov <abalashov(a)evaristesys.com>wrote;wrote:
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 <185377618_113020350(a)68.68.120.41>\r\nCSeq\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/
______________________________**_________________
sr-dev mailing list
sr-dev(a)lists.sip-router.org
http://lists.sip-router.org/**cgi-bin/mailman/listinfo/sr-**dev<http://l…