[asterisk-users] Asterisk 1.4.5, Cisco 7960, call dropped when sip client put on hold/transfer

Mon Jun 25 12:51:43 CDT 2007

Hello,

I've been racking my brain over this for much of the day so I thought
the list would probably be more helpful. A few days ago I upgraded
from Asterisk 1.2 to Asterisk 1.4.5. Everything appeared to be working
properly.

However, on the first business day, we realized that when transferring
calls (not using call parking, using the built in transfer buttons on
a Cisco 7960) would not work. This error would occur:

Spawn extension (companyname-default, 304, 1) exited non-zero on
'SIP/302-0824f618'

In the case above, phone extension 304 and 302 were talking, and 304
pressed 'hold'.  302 gets dropped, as indicated above. I enabled sip
debuggint (fully below) and notice that I get:

SIP/2.0 488 Not Acceptable Here
Warning: 399 SDP Not Acceptable

Lots of info about the 488 implies some codec issue between the
endpoints, so I changed my sip.conf [general] to only permit ulaw, as
well as the same in the phone's config (SIPxxx.conf). Didn't help.
Since it's cleaner this way, this is how I currently have left it.

Strangely, transfers work if they come from a ZAP channel TO a queue
or directly to voicemail (via an extension) but will NOT work if
anything is being sent directly TO a SIP client.

I also tested with a Grandstream Budgetone phone, I have the exact
same issue, so it doesnt appear to be a firmware issue with the
Cisco's (which are on the latest, 8.6)

Here are all of the headers starting from when someone presses "hold"

=============================
=============================

<--- SIP read from 192.168.96.91:5060 --->

<------------->
--- (0 headers 0 lines) Nat keepalive ---
ivan*CLI>
<--- SIP read from 192.168.96.18:50422 --->
INVITE sip:302 at 192.168.96.5:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.96.18:5060;branch=z9hG4bK50f5380a
From: <sip:304 at 192.168.96.18:5060;user=phone;transport=udp>;tag=001200348d021a566e942586-7ba72702
To: "User Name 1" <sip:302 at 192.168.96.5>;tag=as2a70a5c3
Call-ID: 67e209da06e0de2465f9d19206041a5a at 192.168.96.5
Max-Forwards: 70
Date: Mon, 25 Jun 2007 17:09:59 GMT
CSeq: 101 INVITE
User-Agent: Cisco-CP7960G/8.0
Contact: <sip:304 at 192.168.96.18:5060;user=phone;transport=udp>
Accept: application/sdp
Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE
Supported: replaces,join,norefersub
Content-Length: 278
Content-Type: application/sdp
Content-Disposition: session;handling=optional

v=0
o=Cisco-SIPUA 26847 2 IN IP4 192.168.96.18
s=SIP Call
t=0 0
m=audio 26612 RTP/AVP 0 8 18 101
c=IN IP4 192.168.96.18
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendonly

<------------->
--- (16 headers 13 lines) ---
Sending to 192.168.96.18 : 5060 (no NAT)
Found RTP audio format 0
Found RTP audio format 8
Found RTP audio format 18
Found RTP audio format 101
Peer audio RTP is at port 192.168.96.18:26612
Found description format PCMU for ID 0
Found description format PCMA for ID 8
Found description format G729 for ID 18
Got unsupported a:fmtp in SDP offer
Found description format telephone-event for ID 101
Got unsupported a:fmtp in SDP offer
Capabilities: us - 0x4 (ulaw), peer - audio=0x10c
(ulaw|alaw|g729)/video=0x0 (nothing), combined - 0x4 (ulaw)
Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1
(telephone-event), combined - 0x1 (telephone-event)
Peer audio RTP is at port 192.168.96.18:26612
Audio is at 192.168.96.5 port 12846
Adding codec 0x4 (ulaw) to SDP
Adding non-codec 0x1 (telephone-event) to SDP

<--- Transmitting (no NAT) to 192.168.96.18:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP
192.168.96.18:5060;branch=z9hG4bK50f5380a;received=192.168.96.18
From: <sip:304 at 192.168.96.18:5060;user=phone;transport=udp>;tag=001200348d021a566e942586-7ba72702
To: "User Name 1" <sip:302 at 192.168.96.5>;tag=as2a70a5c3
Call-ID: 67e209da06e0de2465f9d19206041a5a at 192.168.96.5
CSeq: 101 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Contact: <sip:302 at 192.168.96.5>
Content-Type: application/sdp
Content-Length: 240

v=0
o=root 1431 1433 IN IP4 192.168.96.16
s=session
c=IN IP4 192.168.96.16
t=0 0
m=audio 27002 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=recvonly

<------------>
set_destination: Parsing
<sip:302 at 192.168.96.16:5060;user=phone;transport=udp> for address/port
to send to
set_destination: set destination to 192.168.96.16, port 5060
Audio is at 192.168.96.5 port 16816
Adding non-codec 0x1 (telephone-event) to SDP
Reliably Transmitting (no NAT) to 192.168.96.16:5060:
INVITE sip:302 at 192.168.96.16:5060;user=phone;transport=udp SIP/2.0
Via: SIP/2.0/UDP 192.168.96.5:5060;branch=z9hG4bK7f41a807;rport
From: <sip:304 at 192.168.96.5;user=phone>;tag=as2c9302cc
To: "User Name 1" <sip:302 at 192.168.96.5>;tag=001200347d27001a7e20b127-2129053d
Contact: <sip:304 at 192.168.96.5>
Call-ID: 00120034-7d27000f-5f89ed49-5278b958 at 192.168.96.16
CSeq: 103 INVITE
User-Agent: Asterisk PBX
Max-Forwards: 70
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
X-asterisk-Info: SIP re-invite (External RTP bridge)
Content-Type: application/sdp
Content-Length: 202

v=0
o=root 1431 1433 IN IP4 192.168.96.5
s=session
c=IN IP4 192.168.96.5
t=0 0
m=audio 16816 RTP/AVP 101
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=sendrecv

---
    -- Started music on hold, class 'default', on SIP/302-0824f618
    -- Stopped music on hold on SIP/302-0824f618
ivan*CLI>
<--- SIP read from 192.168.96.18:50422 --->
ACK sip:302 at 192.168.96.5:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.96.18:5060;branch=z9hG4bK77d2c2d8
From: <sip:304 at 192.168.96.18:5060;user=phone;transport=udp>;tag=001200348d021a566e942586-7ba72702
To: "User Name 1" <sip:302 at 192.168.96.5>;tag=as2a70a5c3
Call-ID: 67e209da06e0de2465f9d19206041a5a at 192.168.96.5
Max-Forwards: 70
Date: Mon, 25 Jun 2007 17:09:59 GMT
CSeq: 101 ACK
User-Agent: Cisco-CP7960G/8.0
Content-Length: 0

<------------->
--- (10 headers 0 lines) ---
ivan*CLI>
<--- SIP read from 192.168.96.16:50074 --->
SIP/2.0 488 Not Acceptable Here
Via: SIP/2.0/UDP 192.168.96.5:5060;branch=z9hG4bK7f41a807;rport
From: <sip:304 at 192.168.96.5;user=phone>;tag=as2c9302cc
To: "User Name 1" <sip:302 at 192.168.96.5>;tag=001200347d27001a7e20b127-2129053d
Call-ID: 00120034-7d27000f-5f89ed49-5278b958 at 192.168.96.16
Date: Mon, 25 Jun 2007 17:06:25 GMT
CSeq: 103 INVITE
Warning: 399 SDP Not Acceptable
Server: Cisco-CP7960G/8.0
Contact: <sip:302 at 192.168.96.16:5060;user=phone;transport=udp>
Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE
Content-Length: 0

<------------->
--- (12 headers 0 lines) ---
set_destination: Parsing
<sip:302 at 192.168.96.16:5060;user=phone;transport=udp> for address/port
to send to
set_destination: set destination to 192.168.96.16, port 5060
Transmitting (no NAT) to 192.168.96.16:5060:
ACK sip:302 at 192.168.96.16:5060;user=phone;transport=udp SIP/2.0
Via: SIP/2.0/UDP 192.168.96.5:5060;branch=z9hG4bK7f41a807;rport
From: <sip:304 at 192.168.96.5;user=phone>;tag=as2c9302cc
To: "User Name 1" <sip:302 at 192.168.96.5>;tag=001200347d27001a7e20b127-2129053d
Contact: <sip:304 at 192.168.96.5>
Call-ID: 00120034-7d27000f-5f89ed49-5278b958 at 192.168.96.16
CSeq: 103 ACK
User-Agent: Asterisk PBX
Max-Forwards: 70
Content-Length: 0

---
Scheduling destruction of SIP dialog
'67e209da06e0de2465f9d19206041a5a at 192.168.96.5' in 32000 ms (Method:
ACK)
set_destination: Parsing
<sip:304 at 192.168.96.18:5060;user=phone;transport=udp> for address/port
to send to
set_destination: set destination to 192.168.96.18, port 5060
Reliably Transmitting (no NAT) to 192.168.96.18:5060:
BYE sip:304 at 192.168.96.18:5060;user=phone;transport=udp SIP/2.0
Via: SIP/2.0/UDP 192.168.96.5:5060;branch=z9hG4bK27d10c95;rport
From: "User Name 1" <sip:302 at 192.168.96.5>;tag=as2a70a5c3
To: <sip:304 at 192.168.96.18:5060;user=phone;transport=udp>;tag=001200348d021a566e942586-7ba72702
Call-ID: 67e209da06e0de2465f9d19206041a5a at 192.168.96.5
CSeq: 104 BYE
User-Agent: Asterisk PBX
Max-Forwards: 70
Content-Length: 0

---
  == Spawn extension (companyname-default, 304, 1) exited non-zero on
'SIP/302-0824f618'
Scheduling destruction of SIP dialog
'00120034-7d27000f-5f89ed49-5278b958 at 192.168.96.16' in 32000 ms
(Method: ACK)
set_destination: Parsing
<sip:302 at 192.168.96.16:5060;user=phone;transport=udp> for address/port
to send to
set_destination: set destination to 192.168.96.16, port 5060
Reliably Transmitting (no NAT) to 192.168.96.16:5060:
BYE sip:302 at 192.168.96.16:5060;user=phone;transport=udp SIP/2.0
Via: SIP/2.0/UDP 192.168.96.5:5060;branch=z9hG4bK06cc5909;rport
From: <sip:304 at 192.168.96.5;user=phone>;tag=as2c9302cc
To: "User Name 1" <sip:302 at 192.168.96.5>;tag=001200347d27001a7e20b127-2129053d
Call-ID: 00120034-7d27000f-5f89ed49-5278b958 at 192.168.96.16
CSeq: 104 BYE
User-Agent: Asterisk PBX
Max-Forwards: 70
Content-Length: 0

---
ivan*CLI>
<--- SIP read from 192.168.96.18:50422 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.96.5:5060;branch=z9hG4bK27d10c95;rport
From: "User Name 1" <sip:302 at 192.168.96.5>;tag=as2a70a5c3
To: <sip:304 at 192.168.96.18:5060;user=phone;transport=udp>;tag=001200348d021a566e942586-7ba72702
Call-ID: 67e209da06e0de2465f9d19206041a5a at 192.168.96.5
Date: Mon, 25 Jun 2007 17:09:59 GMT
CSeq: 104 BYE
Server: Cisco-CP7960G/8.0
Content-Length: 0

<------------->
--- (9 headers 0 lines) ---
SIP Response message for INCOMING dialog BYE arrived
Really destroying SIP dialog
'67e209da06e0de2465f9d19206041a5a at 192.168.96.5' Method: ACK
ivan*CLI>
<--- SIP read from 192.168.96.16:50075 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.96.5:5060;branch=z9hG4bK06cc5909;rport
From: <sip:304 at 192.168.96.5;user=phone>;tag=as2c9302cc
To: "User Name 1" <sip:302 at 192.168.96.5>;tag=001200347d27001a7e20b127-2129053d
Call-ID: 00120034-7d27000f-5f89ed49-5278b958 at 192.168.96.16
Date: Mon, 25 Jun 2007 17:06:25 GMT
CSeq: 104 BYE
Server: Cisco-CP7960G/8.0
Content-Length: 0

<------------->
--- (9 headers 0 lines) ---
Really destroying SIP dialog
'00120034-7d27000f-5f89ed49-5278b958 at 192.168.96.16' Method: ACK

=============================
=============================

Any help or thoughts would be appreciated!

--falz