[Home]

Summary:ASTERISK-13582: Blind transfer to parking from SIP phone crashes Asterisk
Reporter:Erik De Decker (erik_dedecker)Labels:
Date Opened:2009-02-14 06:22:42.000-0600Date Closed:2009-02-23 10:49:19.000-0600
Priority:CriticalRegression?No
Status:Closed/CompleteComponents:Features/Parking
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:
Description:ested with SIP phone Thomson ST2030 firmware V1.66 (and others)

After a BLIND transfer to a parking lot, using the phone transfer button, the ST2030 hangsup the call ( channel status is AST_CAUSE_NORMAL_CLEARING 16)

Two issues arise :

1. the saydigits application (ast_say_digits line 502 in features.c) announcing the parking lot, tries to acces a hangup channel and crashes Asterisk.

2. If this line is commented to avoid the issue, chan_sip.c tries to free the allocated channel structures ( ast_free(d->req.data)lines 15901 150903 in chan_sip.c) and crashes Asterisk with a glibc free() error.

Before making any suggestions on how to correct the issue I would like to have your advise on how avoid the crash by testing the channel status before calling ast_say_digits and ast_free(d->req.data)

Testing d->chan2->hangupcause and not calling free() may not be the solution because the channel still hangs arround. You can check this at the CLI with core show channels. At a stop now it will eventually clear but its not nice to have zombies hanging around !

Thanks in advance  

Erik



****** ADDITIONAL INFORMATION ******

Here is the SIP trace of the phone how initiated the tranfer to the parking lot
ATTENTION : The code provoking the cash (lines mentionned above) was commented
(there are also some debug messages I used for tracing the issue)

Trace is from the moment we press the transfer button on the phone before dialing the parking lot after having accepted the call.

<--- SIP read from UDP://192.168.202.195:5060 --->
INVITE sip:2031@192.168.202.197;user=phone SIP/2.0
Via: SIP/2.0/UDP 192.168.202.195:5060;branch=z9hG4bK7920258692081536042-29918892
From: <sip:2032@192.168.202.195:5060;user=phone>;tag=c0a80101-1c85f2f
To: <sip:2031@192.168.202.197>;tag=as0bf7ac0b
Call-ID: 3fd1057412abf5b6427b259c2fc5dd4c@192.168.202.197
CSeq: 1 INVITE
Max-Forwards: 70
Supported: timer, replaces
Session-Expires: 1800;refresher=uas
Allow-Events: refer,dialog,message-summary,check-sync,talk,hold
Contact: <sip:2032@192.168.202.195:5060;user=phone>
User-Agent: THOMSON ST2030 hw5 fw1.66 00-1F-9F-16-1F-73
Content-Type: application/sdp
Content-Length: 151

v=0
o=2032 29909139 29909140 IN IP4 192.168.202.195
s=-
c=IN IP4 192.168.202.195
t=0 0
m=audio 41000 RTP/AVP 0
a=rtpmap:0 PCMU/8000
a=sendonly

<------------->
[2009-02-14 13:13:23] VERBOSE[9881] logger.c: --- (14 headers 8 lines) ---
[2009-02-14 13:13:23] VERBOSE[9881] logger.c: Sending to 192.168.202.195 : 5060 (no NAT)
[2009-02-14 13:13:23] VERBOSE[9881] logger.c: Found RTP audio format 0
[2009-02-14 13:13:23] VERBOSE[9881] logger.c: Peer audio RTP is at port 192.168.202.195:41000
[2009-02-14 13:13:23] VERBOSE[9881] logger.c: Found audio description format PCMU for ID 0
[2009-02-14 13:13:23] VERBOSE[9881] logger.c: Capabilities: us - 0x50e (gsm|ulaw|alaw|g729|ilbc), peer - audio=0x4 (ulaw)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x4 (ulaw)
[2009-02-14 13:13:23] VERBOSE[9881] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing)
[2009-02-14 13:13:23] VERBOSE[9881] logger.c: Peer audio RTP is at port 192.168.202.195:41000
[2009-02-14 13:13:23] VERBOSE[9881] logger.c:
<--- Transmitting (no NAT) to 192.168.202.195:5060 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.202.195:5060;branch=z9hG4bK7920258692081536042-29918892;received=192.168.202.195
From: <sip:2032@192.168.202.195:5060;user=phone>;tag=c0a80101-1c85f2f
To: <sip:2031@192.168.202.197>;tag=as0bf7ac0b
Call-ID: 3fd1057412abf5b6427b259c2fc5dd4c@192.168.202.197
CSeq: 1 INVITE
User-Agent: Asterisk PBX 1.6.0.5
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces, timer
Require: timer
Session-Expires: 1800;refresher=uac
Contact: <sip:2031@192.168.202.197>
Content-Length: 0


<------------>
[2009-02-14 13:13:23] VERBOSE[9881] logger.c: Audio is at 192.168.202.197 port 8186
[2009-02-14 13:13:23] VERBOSE[9881] logger.c: Adding codec 0x4 (ulaw) to SDP
[2009-02-14 13:13:23] VERBOSE[9881] logger.c:
<--- Reliably Transmitting (no NAT) to 192.168.202.195:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.202.195:5060;branch=z9hG4bK7920258692081536042-29918892;received=192.168.202.195
From: <sip:2032@192.168.202.195:5060;user=phone>;tag=c0a80101-1c85f2f
To: <sip:2031@192.168.202.197>;tag=as0bf7ac0b
Call-ID: 3fd1057412abf5b6427b259c2fc5dd4c@192.168.202.197
CSeq: 1 INVITE
User-Agent: Asterisk PBX 1.6.0.5
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces, timer
Require: timer
Session-Expires: 1800;refresher=uac
Contact: <sip:2031@192.168.202.197>
Content-Type: application/sdp
Content-Length: 210

v=0
o=root 409069394 409069395 IN IP4 192.168.202.197
s=Asterisk PBX 1.6.0.5
c=IN IP4 192.168.202.197
t=0 0
m=audio 8186 RTP/AVP 0
a=rtpmap:0 PCMU/8000
a=silenceSupp:off - - - -
a=ptime:20
a=recvonly

<------------>
[2009-02-14 13:13:23] VERBOSE[9900] logger.c:     -- Started music on hold, class 'default', on SIP/2031-08264758
[2009-02-14 13:13:23] VERBOSE[9881] logger.c:
<--- SIP read from UDP://192.168.202.195:5060 --->
ACK sip:2031@192.168.202.197;user=phone SIP/2.0
Via: SIP/2.0/UDP 192.168.202.195:5060;branch=z9hG4bK2185369103192647158-29918922
From: <sip:2032@192.168.202.195:5060;user=phone>;tag=c0a80101-1c85f2f
To: <sip:2031@192.168.202.197>;tag=as0bf7ac0b
Call-ID: 3fd1057412abf5b6427b259c2fc5dd4c@192.168.202.197
CSeq: 1 ACK
Max-Forwards: 70
Allow-Events: refer,dialog,message-summary,check-sync,talk,hold
User-Agent: THOMSON ST2030 hw5 fw1.66 00-1F-9F-16-1F-73
Content-Length: 0


<------------->
[2009-02-14 13:13:23] VERBOSE[9881] logger.c: --- (10 headers 0 lines) ---
[2009-02-14 13:13:30] VERBOSE[9881] logger.c:
<--- SIP read from UDP://192.168.202.195:5060 --->
REFER sip:2031@192.168.202.197;user=phone SIP/2.0
Via: SIP/2.0/UDP 192.168.202.195:5060;branch=z9hG4bK4697585329354209219-29922120
From: <sip:2032@192.168.202.195:5060;user=phone>;tag=c0a80101-1c85f2f
To: <sip:2031@192.168.202.197>;tag=as0bf7ac0b
Call-ID: 3fd1057412abf5b6427b259c2fc5dd4c@192.168.202.197
CSeq: 2 REFER
Max-Forwards: 70
Referred-By: <sip:2032@192.168.202.195>
Refer-To: <sip:50@192.168.202.197:5060>
Contact: <sip:2032@192.168.202.195:5060;user=phone>
Allow-Events: refer,dialog,message-summary,check-sync,talk,hold
User-Agent: THOMSON ST2030 hw5 fw1.66 00-1F-9F-16-1F-73
Content-Length: 0


<------------->
[2009-02-14 13:13:30] VERBOSE[9881] logger.c: --- (13 headers 0 lines) ---
[2009-02-14 13:13:30] VERBOSE[9881] logger.c: Call 3fd1057412abf5b6427b259c2fc5dd4c@192.168.202.197 got a SIP call transfer from caller: (REFER)!
[2009-02-14 13:13:30] VERBOSE[9881] logger.c: SIP transfer to extension 50@DefaultOutgoingRule by 2032@192.168.202.195
[2009-02-14 13:13:30] VERBOSE[9881] chan_sip.c:  ******** Still OK ccccccccc ***********
[2009-02-14 13:13:30] VERBOSE[9881] chan_sip.c:  ******** Still OK ddddddddd ***********
[2009-02-14 13:13:30] VERBOSE[9901] chan_sip.c:  ******** Still OK aaaaaaaaaa ***********
[2009-02-14 13:13:30] VERBOSE[9901] features.c: ********** STILL OK 666666 ***********
[2009-02-14 13:13:30] VERBOSE[9901] features.c: ********** park_call_full 11111 ***********
[2009-02-14 13:13:30] VERBOSE[9901] features.c: ********** park_call_full 333333 ***********
[2009-02-14 13:13:30] VERBOSE[9901] logger.c:     -- Started music on hold, class 'default', on SIP/2031-08264758
[2009-02-14 13:13:30] VERBOSE[9901] features.c: ********** park_call_full 44444 ***********
[2009-02-14 13:13:30] VERBOSE[9901] logger.c:   == Parked SIP/2031-08264758 on 51@parkedcalls. Will timeout back to extension [DefaultOutgoingRule] 2032, 1 in 75 seconds
[2009-02-14 13:13:30] VERBOSE[9901] features.c: ********** park_call_full 55555 ***********
[2009-02-14 13:13:30] VERBOSE[9901] features.c: ********** park_call_full 66666 ***********
[2009-02-14 13:13:30] VERBOSE[9901] features.c: ********** park_call_full 77777 ***********
[2009-02-14 13:13:30] VERBOSE[9901] logger.c:     -- Added extension '51' priority 1 to parkedcalls (0x825ab18)
[2009-02-14 13:13:30] VERBOSE[9901] features.c: ********** STILL OK 11111 ***********
[2009-02-14 13:13:30] VERBOSE[9901] features.c: ********** STILL OK 55555 ***********
[2009-02-14 13:13:30] VERBOSE[9901] chan_sip.c:  ******** Still OK bbbbbbbbbb ***********
[2009-02-14 13:13:30] VERBOSE[9901] logger.c:
<--- Transmitting (no NAT) to 192.168.202.195:5060 --->
SIP/2.0 202 Accepted
Via: SIP/2.0/UDP 192.168.202.195:5060;branch=z9hG4bK4697585329354209219-29922120;received=192.168.202.195
From: <sip:2032@192.168.202.195:5060;user=phone>;tag=c0a80101-1c85f2f
To: <sip:2031@192.168.202.197>;tag=as0bf7ac0b
Call-ID: 3fd1057412abf5b6427b259c2fc5dd4c@192.168.202.197
CSeq: 2 REFER
User-Agent: Asterisk PBX 1.6.0.5
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces, timer
Contact: <sip:2031@192.168.202.197>
Content-Length: 0


<------------>
[2009-02-14 13:13:30] VERBOSE[9901] chan_sip.c:  ******** sip_park_thread ccccccc ***********
[2009-02-14 13:13:30] VERBOSE[9901] chan_sip.c:  ******** sip_park_thread ddddddddd ***********
[2009-02-14 13:13:30] VERBOSE[9901] chan_sip.c:  ******** sip_park_thread  hhhhhhhhh  ***********
[2009-02-14 13:13:30] VERBOSE[9901] logger.c: set_destination: Parsing <sip:2032@192.168.202.195:5060;user=phone> for address/port to send to
[2009-02-14 13:13:30] VERBOSE[9901] logger.c: set_destination: set destination to 192.168.202.195, port 5060
[2009-02-14 13:13:30] VERBOSE[9901] logger.c: Reliably Transmitting (no NAT) to 192.168.202.195:5060:
NOTIFY sip:2032@192.168.202.195:5060;user=phone SIP/2.0
Via: SIP/2.0/UDP 192.168.202.197:5060;branch=z9hG4bK2b4b2b07;rport
Max-Forwards: 70
From: <sip:2031@192.168.202.197>;tag=as0bf7ac0b
To: <sip:2032@192.168.202.195:5060;user=phone>;tag=c0a80101-1c85f2f
Contact: <sip:2031@192.168.202.197>
Call-ID: 3fd1057412abf5b6427b259c2fc5dd4c@192.168.202.197
CSeq: 103 NOTIFY
User-Agent: Asterisk PBX 1.6.0.5
Event: refer;id=2
Subscription-state: terminated;reason=noresource
Content-Type: message/sipfrag;version=2.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces, timer
Content-Length: 16

SIP/2.0 200 OK

---
[2009-02-14 13:13:30] VERBOSE[9901] chan_sip.c:  ******** sip_park_thread iiiiiiiiii ***********
[2009-02-14 13:13:30] VERBOSE[9901] chan_sip.c:  ******** sip_park_thread jjjjjjjjjj ***********
[2009-02-14 13:13:30] VERBOSE[9901] chan_sip.c:  ******** sip_park_thread kkkkkkkkkk ***********
[2009-02-14 13:13:30] VERBOSE[9901] chan_sip.c:  ******** sip_park_thread lllllllll ***********
[2009-02-14 13:13:30] VERBOSE[9901] chan_sip.c:  ******** sip_park_thread llll *********** chan1 SIP/2031-08264758 0 chan2 SIP/2032-0826f200 chan2 16
[2009-02-14 13:13:30] VERBOSE[9901] chan_sip.c:  ******** sip_park_thread ffffffffff ***********
[2009-02-14 13:13:30] VERBOSE[9901] chan_sip.c:  ******** sip_park_thread gggggggggg ***********
[2009-02-14 13:13:30] VERBOSE[9881] logger.c:
<--- SIP read from UDP://192.168.202.195:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.202.197:5060;branch=z9hG4bK2b4b2b07;rport
From: "2031"<sip:2031@192.168.202.197>;tag=as0bf7ac0b
To: <sip:2032@192.168.202.195:5060;user=phone>;tag=c0a80101-1c85f2f
Call-ID: 3fd1057412abf5b6427b259c2fc5dd4c@192.168.202.197
CSeq: 103 NOTIFY
Content-Length: 0


<------------->
[2009-02-14 13:13:30] VERBOSE[9881] logger.c: --- (7 headers 0 lines) ---
[2009-02-14 13:13:30] VERBOSE[9881] logger.c: SIP Response message for INCOMING dialog NOTIFY arrived
[2009-02-14 13:13:30] VERBOSE[9881] logger.c:
<--- SIP read from UDP://192.168.202.195:5060 --->
BYE sip:2031@192.168.202.197;user=phone SIP/2.0
Via: SIP/2.0/UDP 192.168.202.195:5060;branch=z9hG4bK7030258692081536043-29922131
From: <sip:2032@192.168.202.195:5060;user=phone>;tag=c0a80101-1c85f2f
To: <sip:2031@192.168.202.197>;tag=as0bf7ac0b
Call-ID: 3fd1057412abf5b6427b259c2fc5dd4c@192.168.202.197
CSeq: 3 BYE
Max-Forwards: 70
Allow-Events: refer,dialog,message-summary,check-sync,talk,hold
User-Agent: THOMSON ST2030 hw5 fw1.66 00-1F-9F-16-1F-73
Content-Length: 0


<------------->
[2009-02-14 13:13:30] VERBOSE[9881] logger.c: --- (10 headers 0 lines) ---
[2009-02-14 13:13:30] VERBOSE[9881] logger.c: Sending to 192.168.202.195 : 5060 (no NAT)
[2009-02-14 13:13:30] VERBOSE[9881] logger.c:
<--- Transmitting (no NAT) to 192.168.202.195:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.202.195:5060;branch=z9hG4bK7030258692081536043-29922131;received=192.168.202.195
From: <sip:2032@192.168.202.195:5060;user=phone>;tag=c0a80101-1c85f2f
To: <sip:2031@192.168.202.197>;tag=as0bf7ac0b
Call-ID: 3fd1057412abf5b6427b259c2fc5dd4c@192.168.202.197
CSeq: 3 BYE
User-Agent: Asterisk PBX 1.6.0.5
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces, timer
Contact: <sip:2031@192.168.202.197>
Comments:By: snuffy (snuffy) 2009-02-14 21:58:45.000-0600

Assigned to you jpeeler since you love parking..
By: Erik De Decker (erik_dedecker) 2009-02-15 14:42:35.000-0600

issue similar to 0013978 and related to 0013820.

I suggest to add the a test to check if the channel has not been hangup before playing digits. In addition, the channels should be freed up, one at a time with, again, a test to check if the channel has not been hangup already (instead of freeing up both at once using the dual struc)
By: Erik De Decker (erik_dedecker) 2009-02-16 04:34:29.000-0600

This issue does not appear with version 1.4.20.1

Using # button to transfer a call to a parking crashes Asterisk version 1.4.20.1 ! So the bug has been introduced by resolving the bug of # transfer to parking !?
By: Jeff Peeler (jpeeler) 2009-02-18 16:00:50.000-0600

I've reproduced this for all of 1.6 but the latest 1.4 does not seem to not have this issue. Now to find out why.


By: Digium Subversion (svnbot) 2009-02-19 11:40:48.000-0600

Repository: asterisk
Revision: 177445

U   branches/1.6.0/channels/chan_sip.c

------------------------------------------------------------------------
r177445 | jpeeler | 2009-02-19 11:40:47 -0600 (Thu, 19 Feb 2009) | 6 lines

Remove invalid ast_free calls for static character arrays

(issue ASTERISK-13582)
Reported by: erik_dedecker


------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=177445
By: Jeff Peeler (jpeeler) 2009-02-19 11:49:21.000-0600

I'm not seeing any channels besides the masqueraded ones hung up before the parking lot is announced. With the change above included are you still seeing the crash in 1.6.0? If so, please attach a backtrace (see doc/backtrace.txt).

Note: 1.6.1 and trunk are crashing in the exact same scenario but for a different reason.
By: Digium Subversion (svnbot) 2009-02-19 18:35:54.000-0600

Repository: asterisk
Revision: 177624

U   trunk/channels/chan_sip.c

------------------------------------------------------------------------
r177624 | jpeeler | 2009-02-19 18:35:53 -0600 (Thu, 19 Feb 2009) | 7 lines

Set sip_request ast_str data to NULL so ast_str_copy allocates space properly
in copy_request

(issue ASTERISK-13582)
Reported by: erik_dedecker


------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=177624
By: Digium Subversion (svnbot) 2009-02-19 18:36:28.000-0600

Repository: asterisk
Revision: 177625

_U  branches/1.6.0/

------------------------------------------------------------------------
r177625 | jpeeler | 2009-02-19 18:36:28 -0600 (Thu, 19 Feb 2009) | 12 lines

Blocked revisions 177624 via svnmerge

........
 r177624 | jpeeler | 2009-02-19 18:35:53 -0600 (Thu, 19 Feb 2009) | 7 lines
 
 Set sip_request ast_str data to NULL so ast_str_copy allocates space properly
 in copy_request
 
 (issue ASTERISK-13582)
 Reported by: erik_dedecker
........

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=177625
By: Digium Subversion (svnbot) 2009-02-19 18:38:20.000-0600

Repository: asterisk
Revision: 177626

_U  branches/1.6.1/
U   branches/1.6.1/channels/chan_sip.c

------------------------------------------------------------------------
r177626 | jpeeler | 2009-02-19 18:38:20 -0600 (Thu, 19 Feb 2009) | 13 lines

Merged revisions 177624 via svnmerge from
https://origsvn.digium.com/svn/asterisk/trunk

........
 r177624 | jpeeler | 2009-02-19 18:35:53 -0600 (Thu, 19 Feb 2009) | 7 lines
 
 Set sip_request ast_str data to NULL so ast_str_copy allocates space properly
 in copy_request
 
 (issue ASTERISK-13582)
 Reported by: erik_dedecker
........

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=177626
By: Erik De Decker (erik_dedecker) 2009-02-22 05:48:27.000-0600

Asterisk 1.6.1 revision 177624 behaves correctly with respect to the reported bug.
(asterisk does not crash anymore)

We noticed however that the call does not return to the originating parker: the call is dropped after a failed dial. I suggest that this is issue is opened as seperate bug and look at it when I have time.

Pulsar*CLI>
   -- Added extension 'SIP02031' priority 1 to park-dial (0x8278860)
 == Timeout for SIP/2030-0828ccd0 parked on 51 (default). Returning to park-dial,SIP02031,1
   -- Executing [SIP02031@park-dial:1] Dial("SIP/2030-0828ccd0", "SIP/2031|30|TWtw") in new stack
 == Using SIP RTP CoS mark 5
 == Everyone is busy/congested at this time (1:0/0/1)
   -- Auto fallthrough, channel 'SIP/2030-0828ccd0' status is 'CHANUNAVAIL'
By: Jeff Peeler (jpeeler) 2009-02-23 10:49:19.000-0600

Well, yes, the new problem should be opened as a separate issue. Closing this one, thanks for the feedback.