Summary:ASTERISK-12980: crash after transfer
Reporter:Daniel Wagner (dwagner)Labels:
Date Opened:2008-10-29 12:52:30Date Closed:2008-12-15 12:11:17.000-0600
Versions:Frequency of
Environment:Attachments:( 0) asterisk-1.4.22-chan-sip-nullp.patch
( 1) asterisk-svn-head-chan-sip-nullp.patch
Description:sometimes asterisk crashes after a transfer

side info:
it should be mentioned that i use this snom pickup patch:
may you can tell me if this patch can produce this error.
is there an official pickup solution for snom / asterisk?
the *8 feature is nice but it does not show the caller-number.



#0  0xb7f35406 in pthread_mutex_unlock () from /lib/tls/i686/cmov/libpthread.so.0
No symbol table info available.
#1  0xb62edd70 in handle_request_invite (p=0x873f8e8, req=0xb6296fcc, debug=0, seqno=1, sin=0xb62982f0, recount=0xb6298300,
   e=0xb62971ef "sip:115@", nounlock=0xb6298304) at /usr/src/install-asterisk/asterisk-1.4.22-rc5/include/asterisk/lock.h:745
       __r1 = 0 '\0'
       __r2 = <value optimized out>
       res = <value optimized out>
       gotdest = <value optimized out>
       p_replaces = <value optimized out>
       replace_id = 0xb6294250 "542e98367ad0a77f6f56a3e06bc2b175@"
       required = 0xb62fd88a " %d =-\n\n"
       required_profile = <value optimized out>
       c = <value optimized out>
       reinvite = <value optimized out>
       __PRETTY_FUNCTION__ = "handle_request_invite"
#2  0xb62f2981 in handle_request (p=0x873f8e8, req=0xb6296fcc, sin=0xb62982f0, recount=0xb6298300, nounlock=0xb6298304) at chan_sip.c:15793
       cmd = 0xb62971e8 "INVITE"
       cseq = <value optimized out>
       useragent = 0xb62973a5 "snom320/6.5.18"
       seqno = 1
       len = <value optimized out>
       ignore = 0
       respid = <value optimized out>
       res = <value optimized out>
       debug = 0
       e = 0xb62971ef "sip:115@"
       __PRETTY_FUNCTION__ = "handle_request"
#3  0xb62f40b9 in sipsock_read (id=0x81eebd8, fd=13, events=1, ignore=0x0) at chan_sip.c:15953
       r = <value optimized out>
       req = {rlPart1 = 0xb62971e8 "INVITE", rlPart2 = 0xb62971ef "sip:115@", len = 1233, headers = 19, method = 5, lines = 19, flags = 0,
 header = {0xb62971e8 "INVITE", 0xb629720c "Via: SIP/2.0/UDP;branch=z9hG4bK-ie22y2k5yny1;rport",
   0xb6297251 "From: <sip:112@>;tag=bqp8eqlpfg", 0xb629727d "To: \"00676XXXX4521\" <sip:00676XXXX4521@>",
   0xb62972b2 "Call-ID: 3c278bd56b6c-puz1t64gnz7t@snom320-00041324A9DD", 0xb62972eb "CSeq: 1 INVITE", 0xb62972fb "Max-Forwards: 70",
   0xb629730d "Contact: <sip:112@;line=r8a9j9qd>;flow-id=1", 0xb629734a "Replaces: 542e98367ad0a77f6f56a3e06bc2b175@",
   0xb6297382 "P-Key-Flags: keys=\"3\"", 0xb6297399 "User-Agent: snom320/6.5.18", 0xb62973b5 "Accept: application/sdp",
   0xb62973ce "Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO", 0xb6297428 "Allow-Events: talk, hold, refer",
   0xb6297449 "Supported: timer, 100rel, replaces, callerid", 0xb6297477 "Session-Expires: 3600;refresher=uas", 0xb629749c "Min-SE: 90",
   0xb62974a8 "Content-Type: application/sdp", 0xb62974c7 "Content-Length: 475", 0xb62974dc "", 0x0 <repeats 44 times>}, line = {0xb62974de "v=0",
   0xb62974e3 "o=root 1627402099 1627402099 IN IP4", 0xb6297514 "s=call", 0xb629751c "c=IN IP4", 0xb6297532 "t=0 0",
   0xb6297539 "m=audio 65186 RTP/AVP 0 8 9 98 3 18 4 101", 0xb6297564 "a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:oo/hwndeKUi3yD8y56uxNTq4p5hV1lLvgvKZRx2T",
   0xb62975b8 "a=rtpmap:0 pcmu/8000", 0xb62975ce "a=rtpmap:8 pcma/8000", 0xb62975e4 "a=rtpmap:9 g722/8000", 0xb62975fa "a=rtpmap:98 g726-32/8000",
   0xb6297614 "a=rtpmap:3 gsm/8000", 0xb6297629 "a=rtpmap:18 g729/8000", 0xb6297640 "a=rtpmap:4 g723/8000", 0xb6297656 "a=rtpmap:101 telephone-event/8000",
   0xb6297679 "a=fmtp:101 0-16", 0xb629768a "a=ptime:20", 0xb6297696 "a=encryption:optional", 0xb62976ad "a=sendrecv", 0xb62976b9 "",
   0x0 <repeats 44 times>},
 data = "INVITE\000sip:115@\000SIP/2.0\000\000Via: SIP/2.0/UDP;branch=z9hG4bK-ie22y2k5yny1;rport\000\000From: <sip:112@>;tag=bqp8eqlpfg\000\000To: \"00676XXXX4521\" <sip:00676XXXX4521@>"..., sdp_start = 0, sdp_end = 0}
       sin = {sin_family = 2, sin_port = 8712, sin_addr = {s_addr = 1879113928}, sin_zero = "\000\000\000\000\000\000\000"}
       p = (struct sip_pvt *) 0x873f8e8
       res = <value optimized out>
       len = 16
       nounlock = 0
       recount = 0
       lockretry = 100
       __PRETTY_FUNCTION__ = "sipsock_read"
#4  0x080ac920 in ast_io_wait (ioc=0x81eed60, howlong=1) at io.c:279
       res = 1
       x = 0
       origcnt = 1
ASTERISK-1  0xb62c2f72 in do_monitor (data=0x0) at chan_sip.c:16172
       res = <value optimized out>
---Type <return> to continue, or q <return> to quit---
       sip = (struct sip_pvt *) 0x86ef6d8
       t = 1225292880
       fastrestart = 1
       lastpeernum = 5
       curpeernum = 5
       reloading = <value optimized out>
       __PRETTY_FUNCTION__ = "do_monitor"
ASTERISK-2  0x08100100 in dummy_start (data=0x81efb68) at utils.c:912
       _buffer = {__routine = 0x806a8c0 <ast_unregister_thread>, __arg = 0xb6298bb0, __canceltype = 0, __prev = 0x0}
       ret = <value optimized out>
ASTERISK-3  0xb7f33240 in start_thread () from /lib/tls/i686/cmov/libpthread.so.0
No symbol table info available.
ASTERISK-4  0xb7e4f49e in clone () from /lib/tls/i686/cmov/libc.so.6
No symbol table info available.
Comments:By: Ulf Theobald (tweety) 2008-10-30 19:26:15

Same problem here. Last log entry was :
NOTICE[9273] chan_sip.c: Supervised transfer attempted to replace non-existing call id (447864c10a3058c72ad8d4e00b150e55@!

Think the attached patches should fix this issue also in asterisk head... uhm, i hope so ;-)

By: Ulf Theobald (tweety) 2008-12-02 15:43:08.000-0600

*Push* No fix!?

By: Daniel Wagner (dwagner) 2008-12-03 01:10:04.000-0600

unfortunately I can not reproduce or test the patch above, because of many fundamental problems in asterisk 1.4 we have decided to take a step back to 1.2.


By: Ulf Theobald (tweety) 2008-12-03 04:01:00.000-0600

Without the patch, some Asterisk installations crashed about every week (doing call pickups). With applied patch, the uptime of these installations are now > 1 month.

If you'd take a look at the code, you see, there's a check, if "p->refer->refer_call->owner" is valid. But there's no check before calling  ast_channel_unlock(p->refer->refer_call->owner)!

By: Daniel Wagner (dwagner) 2008-12-03 04:04:36.000-0600

after implementing the patch I can say that our system with 70 extensions had been worked for one week only.

By: Tan Tuerel (thsgmbh) 2008-12-03 04:04:58.000-0600

I have the same crashes nearly every day with this snom pickup patch (pickup with replace header and callid).

Log entry: "supervised transfer...".

I will also try the given patch and report the result.


By: Ulf Theobald (tweety) 2008-12-03 04:10:15.000-0600

@dwagner: i know, but these crashes are caused by other bugs in res_features for example.

By: Joshua C. Colp (jcolp) 2008-12-09 15:20:05.000-0600

I'm trying to understand this issue more... is this only applicable when using the Snom pickup patch or even without it?

By: Daniel Wagner (dwagner) 2008-12-10 01:05:25.000-0600

today I can say, this issue is also applicable without the pickup patch.  I think there are major bugs in the chan_sip or res_features of asterisk 1.4. I had about 3 crashes a week with 1.4 (with and without any patch). Therefore I decided to go a step back to 1.2. since I've had no problems. thanx

By: Ulf Theobald (tweety) 2008-12-10 03:07:34.000-0600

@file: Please take a look at my attached patches.

If "p->refer->refer_call->owner" is NULL, error = 1. But later, you'd simply call ast_channel_unlock(p->refer->refer_call->owner)!

By: Digium Subversion (svnbot) 2008-12-15 12:11:16.000-0600

Repository: asterisk
Revision: 164350

U   branches/1.4/channels/chan_sip.c

r164350 | file | 2008-12-15 12:11:16 -0600 (Mon, 15 Dec 2008) | 6 lines

Do not try to unlock a non-existant channel if the transfer fails.
(closes issue ASTERISK-12980)
Reported by: dwagner
     asterisk-1.4.22-chan-sip-nullp.patch uploaded by tweety (license 608)