ASTERISK-14766: TCP calls no longer bridge (last working version was 1.6.0.1?)

[Home]

Summary: ASTERISK-14766: TCP calls no longer bridge (last working version was 1.6.0.1?)

Reporter: Dan Radio (whys) Labels:

Date Opened: 2009-09-03 15:53:08 Date Closed: 2009-09-17 21:18:45

Priority: Major Regression? No

Status: Closed/Complete Components: Channels/chan_sip/TCP-TLS

Versions: Frequency of
Occurrence

Related
Issues:

Environment: Attachments:

Description: When dialing Microsoft Exchange server (which requires SIP over TCP), the call no longer bridges. To my knowledge, this works in 1.6.0.1 but not in 1.6.0.14, 1.6.1.x or 1.6.2.0

tested on CentOS release 5.3 2.6.18-128.2.1.el5

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

Below are wireshark graphs of working and non-working sessions.

137.28.94.174 Phone
172.28.1.42 Asterisk
172.28.1.68 Exchange server

Working 1.6.0.1 session:
===================================================
|Time | 137.28.94.174 | 172.28.1.42 | 172.28.1.68 |
|14.450 | INVITE SDP ( telephone-event) | |SIP From: sip:364774@172.28.1.42 To:sip:999999@172.28.1.42
| |(50438) ------------------> (5060) | |
|14.451 | 401 Unauthorized | |SIP Status
| |(5061) <------------------ (5060) | |
|14.547 | ACK | | |SIP Request
| |(50452) ------------------> (5060) | |
|14.621 | INVITE SDP ( telephone-event) | |SIP From: sip:364774@172.28.1.42 To:sip:999999@172.28.1.42
| |(50438) ------------------> (5060) | |
|14.622 | 100 Trying| | |SIP Status
| |(5061) <------------------ (5060) | |
|14.623 | 200 OK SDP ( telephone-event) | |SIP Status
| |(5061) <------------------ (5060) | |
|14.840 | RTP (g711U) | |RTP Num packets:3 Duration:0.040s SSRC:0xB622E98F
| |(31182) ------------------> (12556) | |
|14.860 | RTP (g711U) | |RTP Num packets:4 Duration:0.061s SSRC:0x65D76195
| |(31182) <------------------ (12556) | |
|14.889 | ACK | | |SIP Request
| |(50438) ------------------> (5060) | |
|14.890 | INVITE SDP ( telephone-event) | |SIP Request
| |(5061) <------------------ (5060) | |
|14.901 | RTP (g711U) | |RTP Num packets:19 Duration:0.359s SSRC:0xB622E98F
| |(31182) ------------------> (12556) | |
|15.067 | 200 OK SDP ( telephone-event) | |SIP Status
| |(50438) ------------------> (5060) | |
|15.068 | ACK | | |SIP Request
| |(5061) <------------------ (5060) | |
|15.068 | INVITE SDP ( telephone-event) | |SIP Request
| |(5061) <------------------ (5060) | |
|15.080 | | RTP (g711U) |RTP Num packets:8 Duration:0.140s SSRC:0x1142A5A1
| | |(15710) ------------------> (61440) |
|15.352 | 200 OK SDP ( telephone-event) | |SIP Status
| |(50438) ------------------> (5060) | |
|15.355 | ACK | | |SIP Request
| |(5061) <------------------ (5060) | |
|22.887 | BYE | | |SIP Request
| |(50438) ------------------> (5060) | |
|22.887 | 200 OK | | |SIP Status
| |(5061) <------------------ (5060) | |

Non-Working 1.6.2 session:

|Time | 172.28.1.42 | 172.28.1.68 |
|14.844 | INVITE SDP ( telephone-event) |SIP From: sip:364774@172.28.1.42 To:sip:340000@exch08.uwec.edu:5065
| |(53462) ------------------> (5065) |
|14.845 | 100 Trying| |SIP Status
| |(53462) <------------------ (5065) |
|14.854 | 180 Ringing |SIP Status
| |(53462) <------------------ (5065) |
|14.880 | RTP (g711U) |RTP Num packets:3 Duration:0.041s SSRC:0x1142A5A1
| |(15710) ------------------> (61440) |
|14.928 | 200 OK SDP ( telephone-event) |SIP Status
| |(53462) <------------------ (5065) |
|14.932 | ACK | |SIP Request
| |(53462) ------------------> (5065) |
|14.941 | RTP (g711U) |RTP Num packets:7 Duration:0.119s SSRC:0x1142A5A1
| |(15710) ------------------> (61440) |
|15.126 | INVITE SDP ( telephone-event) |SIP From: sip:364774@172.28.1.42 To:sip:340000@exch08.uwec.edu:5065
| |(53462) ------------------> (5065) |
|15.127 | 100 Trying| |SIP Status
| |(53462) <------------------ (5065) |
|15.223 | 200 OK SDP ( telephone-event) |SIP Status
| |(53462) <------------------ (5065) |
|15.225 | ACK | |SIP Request
| |(53462) ------------------> (5065) |
|15.241 | RTP (g711U) |RTP Num packets:2 Duration:0.020s SSRC:0x1142A5A1
| |(15710) ------------------> (61440) |
|22.888 | INVITE SDP ( telephone-event) |SIP From: sip:364774@172.28.1.42 To:sip:340000@exch08.uwec.edu:5065
| |(53462) ------------------> (5065) |
|22.888 | 100 Trying| |SIP Status
| |(53462) <------------------ (5065) |
|22.934 | RTP (g711U) |RTP Num packets:15 Duration:0.245s SSRC:0x107171F2
| |(15710) <------------------ (61440) |
|22.963 | 200 OK SDP ( telephone-event) |SIP Status
| |(53462) <------------------ (5065) |
|22.964 | ACK | |SIP Request
| |(53462) ------------------> (5065) |
|23.157 | BYE | |SIP Request
| |(53462) ------------------> (5065) |
|23.159 | 200 OK | |SIP Status
| |(53462) <------------------ (5065) |

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

SIP Trace Working 1.6.0.1 session:
===================================================

<--- SIP read from UDP:137.28.94.174:50438 --->
INVITE sip:999999@172.28.1.42 SIP/2.0
Via: SIP/2.0/UDP 137.28.94.174:5061;branch=z9hG4bK512405b0
From: "364774" <sip:364774@172.28.1.42>;tag=000f8fe922b61dba651174b9-265c1b1c
To: <sip:999999@172.28.1.42>
Call-ID: 000f8fe9-22b6004c-0eaea2d5-221fefba@137.28.94.174
Max-Forwards: 70
Date: Wed, 02 Sep 2009 18:24:14 GMT
CSeq: 101 INVITE
User-Agent: Cisco-CP7960G/8.0
Contact: <sip:364774@137.28.94.174:5061;user=phone;transport=udp>
Expires: 180
Accept: application/sdp
Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE
Remote-Party-ID: "364774" <sip:364774@172.28.1.42>;party=calling;id-type=subscriber;privacy=off;screen=yes
Supported: replaces,join,norefersub
Content-Length: 274
Content-Type: application/sdp
Content-Disposition: session;handling=optional

v=0
o=Cisco-SIPUA 3036 0 IN IP4 137.28.94.174
s=SIP Call
t=0 0
m=audio 24422 RTP/AVP 0 8 18 96
c=IN IP4 137.28.94.174
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-15
a=sendrecv

<------------->
--- (18 headers 13 lines) ---
== Using SIP RTP CoS mark 5
Sending to 137.28.94.174 : 5061 (no NAT)
Using INVITE request as basis request - 000f8fe9-22b6004c-0eaea2d5-221fefba@137.28.94.174
Found peer '364774' for '364774' from 137.28.94.174:50438

<--- Reliably Transmitting (no NAT) to 137.28.94.174:5061 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 137.28.94.174:5061;branch=z9hG4bK512405b0;received=137.28.94.174
From: "364774" <sip:364774@172.28.1.42>;tag=000f8fe922b61dba651174b9-265c1b1c
To: <sip:999999@172.28.1.42>;tag=as0ab1bd40
Call-ID: 000f8fe9-22b6004c-0eaea2d5-221fefba@137.28.94.174
CSeq: 101 INVITE
Server: Asterisk PBX 1.6.2.0-rc1
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="656ce60e"
Content-Length: 0

<------------>
Scheduling destruction of SIP dialog '000f8fe9-22b6004c-0eaea2d5-221fefba@137.28.94.174' in 32000 ms (Method: INVITE)
asterisk2*CLI>
<--- SIP read from UDP:137.28.94.174:50517 --->
ACK sip:999999@172.28.1.42 SIP/2.0
Via: SIP/2.0/UDP 137.28.94.174:5061;branch=z9hG4bK512405b0
From: "364774" <sip:364774@172.28.1.42>;tag=000f8fe922b61dba651174b9-265c1b1c
To: <sip:999999@172.28.1.42>;tag=as0ab1bd40
Call-ID: 000f8fe9-22b6004c-0eaea2d5-221fefba@137.28.94.174
Date: Wed, 02 Sep 2009 18:24:14 GMT
CSeq: 101 ACK
Content-Length: 0

<------------->
--- (8 headers 0 lines) ---
asterisk2*CLI>
<--- SIP read from UDP:137.28.94.174:50438 --->
INVITE sip:999999@172.28.1.42 SIP/2.0
Via: SIP/2.0/UDP 137.28.94.174:5061;branch=z9hG4bK67794013
From: "364774" <sip:364774@172.28.1.42>;tag=000f8fe922b61dba651174b9-265c1b1c
To: <sip:999999@172.28.1.42>
Call-ID: 000f8fe9-22b6004c-0eaea2d5-221fefba@137.28.94.174
Max-Forwards: 70
Date: Wed, 02 Sep 2009 18:24:14 GMT
CSeq: 102 INVITE
User-Agent: Cisco-CP7960G/8.0
Contact: <sip:364774@137.28.94.174:5061;user=phone;transport=udp>
Authorization: Digest username="364774",realm="asterisk",uri="sip:999999@172.28.1.42",response="2957f36f6ce85042a43f9343f6fb3b26",nonce="656ce60e",algorithm=MD5
Expires: 180
Accept: application/sdp
Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE
Remote-Party-ID: "364774" <sip:364774@172.28.1.42>;party=calling;id-type=subscriber;privacy=off;screen=yes
Supported: replaces,join,norefersub
Content-Length: 274
Content-Type: application/sdp
Content-Disposition: session;handling=optional

v=0
o=Cisco-SIPUA 3036 0 IN IP4 137.28.94.174
s=SIP Call
t=0 0
m=audio 24422 RTP/AVP 0 8 18 96
c=IN IP4 137.28.94.174
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-15
a=sendrecv

<------------->
--- (19 headers 13 lines) ---
Sending to 137.28.94.174 : 5061 (no NAT)
Using INVITE request as basis request - 000f8fe9-22b6004c-0eaea2d5-221fefba@137.28.94.174
Found peer '364774' for '364774' from 137.28.94.174:50438
Found RTP audio format 0
Found RTP audio format 8
Found RTP audio format 18
Found RTP audio format 96
Peer audio RTP is at port 137.28.94.174:24422
Found audio description format PCMU for ID 0
Found audio description format PCMA for ID 8
Found audio description format G729 for ID 18
Found audio description format telephone-event for ID 96
Capabilities: us - 0x8000e (gsm|ulaw|alaw|h263), peer - audio=0x10c (ulaw|alaw|g729)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0xc (ulaw|alaw)
Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event)
Peer audio RTP is at port 137.28.94.174:24422
Looking for 999999 in phones (domain 172.28.1.42)
list_route: hop: <sip:364774@137.28.94.174:5061;user=phone;transport=udp>

<--- Transmitting (no NAT) to 137.28.94.174:5061 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 137.28.94.174:5061;branch=z9hG4bK67794013;received=137.28.94.174
From: "364774" <sip:364774@172.28.1.42>;tag=000f8fe922b61dba651174b9-265c1b1c
To: <sip:999999@172.28.1.42>
Call-ID: 000f8fe9-22b6004c-0eaea2d5-221fefba@137.28.94.174
CSeq: 102 INVITE
Server: Asterisk PBX 1.6.2.0-rc1
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Contact: <sip:999999@172.28.1.42>
Content-Length: 0

<------------>
-- Executing [999999@phones:1] Answer("SIP/364774-08342938", "") in new stack
Audio is at 172.28.1.42 port 17030
Adding codec 0x4 (ulaw) to SDP
Adding codec 0x8 (alaw) to SDP
Adding non-codec 0x1 (telephone-event) to SDP

<--- Reliably Transmitting (no NAT) to 137.28.94.174:5061 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 137.28.94.174:5061;branch=z9hG4bK67794013;received=137.28.94.174
From: "364774" <sip:364774@172.28.1.42>;tag=000f8fe922b61dba651174b9-265c1b1c
To: <sip:999999@172.28.1.42>;tag=as12968315
Call-ID: 000f8fe9-22b6004c-0eaea2d5-221fefba@137.28.94.174
CSeq: 102 INVITE
Server: Asterisk PBX 1.6.2.0-rc1
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Contact: <sip:999999@172.28.1.42>
Content-Type: application/sdp
Content-Length: 284

v=0
o=root 976721118 976721118 IN IP4 172.28.1.42
s=Asterisk PBX 1.6.2.0-rc1
c=IN IP4 172.28.1.42
t=0 0
m=audio 17030 RTP/AVP 0 8 96
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv

<------------>
-- Executing [999999@phones:2] Set("SIP/364774-08342938", "MBEXT=364774") in new stack
-- Executing [999999@phones:3] Dial("SIP/364774-08342938", "SIP/exchange1/340000") in new stack
== Using SIP RTP CoS mark 5
Audio is at 172.28.1.42 port 10450
Adding codec 0x4 (ulaw) to SDP
Adding codec 0x8 (alaw) to SDP
Adding non-codec 0x1 (telephone-event) to SDP
Reliably Transmitting (no NAT) to 172.28.1.68:5065:
INVITE sip:340000@exch08.uwec.edu:5065 SIP/2.0
Via: SIP/2.0/TCP 172.28.1.42:5060;branch=z9hG4bK79dfe0fe;rport
Max-Forwards: 70
From: "364774" <sip:364774@172.28.1.42>;tag=as17ce3f94
To: <sip:340000@exch08.uwec.edu:5065>
Contact: <sip:364774@172.28.1.42;transport=TCP>
Call-ID: 1290cc7c281a56a4667b73942fd6cada@172.28.1.42
CSeq: 102 INVITE
User-Agent: Asterisk PBX 1.6.2.0-rc1
Date: Wed, 02 Sep 2009 13:10:40 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Type: application/sdp
Content-Length: 284

v=0
o=root 218050453 218050453 IN IP4 172.28.1.42
s=Asterisk PBX 1.6.2.0-rc1
c=IN IP4 172.28.1.42
t=0 0
m=audio 10450 RTP/AVP 0 8 96
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv

---
-- Called exchange1/340000
asterisk2*CLI>
<--- SIP read from TCP:172.28.1.68:5065 --->
SIP/2.0 100 Trying
FROM: "364774"<sip:364774@172.28.1.42>;tag=as17ce3f94
TO: <sip:340000@exch08.uwec.edu:5065>
CSEQ: 102 INVITE
CALL-ID: 1290cc7c281a56a4667b73942fd6cada@172.28.1.42
VIA: SIP/2.0/TCP 172.28.1.42:5060;branch=z9hG4bK79dfe0fe;rport
CONTENT-LENGTH: 0

<------------->
--- (7 headers 0 lines) ---
asterisk2*CLI>
<--- SIP read from TCP:172.28.1.68:5065 --->
SIP/2.0 180 Ringing
FROM: "364774"<sip:364774@172.28.1.42>;tag=as17ce3f94
TO: <sip:340000@exch08.uwec.edu:5065>;epid=9B905B0782;tag=5f4866e9
CSEQ: 102 INVITE
CALL-ID: 1290cc7c281a56a4667b73942fd6cada@172.28.1.42
VIA: SIP/2.0/TCP 172.28.1.42:5060;branch=z9hG4bK79dfe0fe;rport
CONTENT-LENGTH: 0
SERVER: RTCC/3.0.0.0

<------------->
--- (8 headers 0 lines) ---
asterisk2*CLI>
<--- SIP read from UDP:137.28.94.174:50438 --->
ACK sip:999999@172.28.1.42 SIP/2.0
Via: SIP/2.0/UDP 137.28.94.174:5061;branch=z9hG4bK03bf5be6
From: "364774" <sip:364774@172.28.1.42>;tag=000f8fe922b61dba651174b9-265c1b1c
To: <sip:999999@172.28.1.42>;tag=as12968315
Call-ID: 000f8fe9-22b6004c-0eaea2d5-221fefba@137.28.94.174
Max-Forwards: 70
Date: Wed, 02 Sep 2009 18:24:14 GMT
CSeq: 102 ACK
User-Agent: Cisco-CP7960G/8.0
Authorization: Digest username="364774",realm="asterisk",uri="sip:999999@172.28.1.42",response="2957f36f6ce85042a43f9343f6fb3b26",nonce="656ce60e",algorithm=MD5
Remote-Party-ID: "364774" <sip:364774@172.28.1.42>;party=calling;id-type=subscriber;privacy=off;screen=yes
Content-Length: 0

<------------->
--- (12 headers 0 lines) ---
asterisk2*CLI>
<--- SIP read from TCP:172.28.1.68:5065 --->
SIP/2.0 200 OK
FROM: "364774"<sip:364774@172.28.1.42>;tag=as17ce3f94
TO: <sip:340000@exch08.uwec.edu:5065>;epid=9B905B0782;tag=5f4866e9
CSEQ: 102 INVITE
CALL-ID: 1290cc7c281a56a4667b73942fd6cada@172.28.1.42
VIA: SIP/2.0/TCP 172.28.1.42:5060;branch=z9hG4bK79dfe0fe;rport
CONTACT: <sip:EXCH08.uwec.edu:5065;transport=Tcp;maddr=172.28.1.68>;automata
CONTENT-LENGTH: 190
CONTENT-TYPE: application/sdp
ALLOW: UPDATE
SERVER: RTCC/3.0.0.0
ALLOW: Ack, Cancel, Bye,Invite,Message,Info,Service,Options,BeNotify

v=0
o=- 0 0 IN IP4 172.28.1.68
s=Microsoft Exchange Speech Engine
c=IN IP4 172.28.1.68
t=0 0
m=audio 22144 RTP/AVP 0 8 96
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-16
a=ptime:20

<------------->
--- (12 headers 9 lines) ---
Really destroying SIP dialog '000f8fe9-22b60004-4fc65070-6ccc00f4@137.28.94.174' Method: REGISTER
asterisk2*CLI>
<--- SIP read from UDP:137.28.94.174:50438 --->
BYE sip:999999@172.28.1.42 SIP/2.0
Via: SIP/2.0/UDP 137.28.94.174:5061;branch=z9hG4bK4e5788a2
From: "364774" <sip:364774@172.28.1.42>;tag=000f8fe922b6183572fb52e6-1c3fec7b
To: <sip:999999@172.28.1.42>;tag=as76095cdf
Call-ID: 000f8fe9-22b60044-5e58687e-2b1017aa@137.28.94.174
Max-Forwards: 70
Date: Tue, 01 Sep 2009 21:44:41 GMT
CSeq: 103 BYE
User-Agent: Cisco-CP7960G/8.0
Content-Length: 0
Authorization: Digest username="364774",realm="asterisk",uri="sip:999999@172.28.1.42",response="f28f5ff0df64dfd73bf0b64ba8d78d57",nonce="44d15dad",algorithm=MD5

<------------->
--- (11 headers 0 lines) ---

<--- Transmitting (no NAT) to 137.28.94.174:50438 --->
SIP/2.0 481 Call leg/transaction does not exist
Via: SIP/2.0/UDP 137.28.94.174:5061;branch=z9hG4bK4e5788a2;received=137.28.94.174
From: "364774" <sip:364774@172.28.1.42>;tag=000f8fe922b6183572fb52e6-1c3fec7b
To: <sip:999999@172.28.1.42>;tag=as76095cdf
Call-ID: 000f8fe9-22b60044-5e58687e-2b1017aa@137.28.94.174
CSeq: 103 BYE
Server: Asterisk PBX 1.6.2.0-rc1
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0

<------------>
Really destroying SIP dialog '000f8fe9-22b60005-45a29f4a-40d75964@137.28.94.174' Method: REGISTER
Really destroying SIP dialog '000f8fe9-22b60003-19d2baa4-421d6dd1@137.28.94.174' Method: REGISTER
asterisk2*CLI>
<--- SIP read from TCP:172.28.1.68:54478 --->
OPTIONS sip:172.28.1.42:5060 SIP/2.0
FROM: <sip:EXCH08.uwec.edu:5060;transport=Tcp;ms-opaque=e106e8272c05b89b>;epid=ECE8109714;tag=16ec86bf58
TO: <sip:172.28.1.42:5060>
CSEQ: 1272 OPTIONS
CALL-ID: 9def567f876b42829ab7abf210a29a66
MAX-FORWARDS: 70
VIA: SIP/2.0/TCP 172.28.1.68:54478;branch=z9hG4bKa5756858
ACCEPT: application/sdp
CONTENT-LENGTH: 0
USER-AGENT: RTCC/3.0.0.0

<------------->
--- (10 headers 0 lines) ---
Looking for s in default (domain 172.28.1.42)
asterisk2*CLI>
<--- Transmitting (no NAT) to 172.28.1.68:54478 --->
SIP/2.0 200 OK
Via: SIP/2.0/TCP 172.28.1.68:54478;branch=z9hG4bKa5756858;received=172.28.1.68
From: <sip:EXCH08.uwec.edu:5060;transport=Tcp;ms-opaque=e106e8272c05b89b>;epid=ECE8109714;tag=16ec86bf58
To: <sip:172.28.1.42:5060>;tag=as1bd3b7ee
Call-ID: 9def567f876b42829ab7abf210a29a66
CSeq: 1272 OPTIONS
Server: Asterisk PBX 1.6.2.0-rc1
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Contact: <sip:172.28.1.42;transport=TCP>
Accept: application/sdp
Content-Length: 0

<------------>
Scheduling destruction of SIP dialog '9def567f876b42829ab7abf210a29a66' in 32000 ms (Method: OPTIONS)
asterisk2*CLI>
<--- SIP read from UDP:137.28.94.174:50438 --->
BYE sip:999999@172.28.1.42 SIP/2.0
Via: SIP/2.0/UDP 137.28.94.174:5061;branch=z9hG4bK4a05bbbd
From: "364774" <sip:364774@172.28.1.42>;tag=000f8fe922b61dba651174b9-265c1b1c
To: <sip:999999@172.28.1.42>;tag=as12968315
Call-ID: 000f8fe9-22b6004c-0eaea2d5-221fefba@137.28.94.174
Max-Forwards: 70
Date: Wed, 02 Sep 2009 18:24:20 GMT
CSeq: 103 BYE
User-Agent: Cisco-CP7960G/8.0
Content-Length: 0
Authorization: Digest username="364774",realm="asterisk",uri="sip:999999@172.28.1.42",response="2fa759b0307670984f92d9aa13ce3554",nonce="656ce60e",algorithm=MD5

<------------->
--- (11 headers 0 lines) ---
Sending to 137.28.94.174 : 5061 (no NAT)

<--- Transmitting (no NAT) to 137.28.94.174:5061 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 137.28.94.174:5061;branch=z9hG4bK4a05bbbd;received=137.28.94.174
From: "364774" <sip:364774@172.28.1.42>;tag=000f8fe922b61dba651174b9-265c1b1c
To: <sip:999999@172.28.1.42>;tag=as12968315
Call-ID: 000f8fe9-22b6004c-0eaea2d5-221fefba@137.28.94.174
CSeq: 103 BYE
Server: Asterisk PBX 1.6.2.0-rc1
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0

<------------>
Scheduling destruction of SIP dialog '1290cc7c281a56a4667b73942fd6cada@172.28.1.42' in 32000 ms (Method: INVITE)
== Spawn extension (phones, 999999, 3) exited non-zero on 'SIP/364774-08342938'
asterisk2*CLI>
<--- SIP read from UDP:137.28.94.174:50438 --->
BYE sip:999999@172.28.1.42 SIP/2.0
Via: SIP/2.0/UDP 137.28.94.174:5061;branch=z9hG4bK4e5788a2
From: "364774" <sip:364774@172.28.1.42>;tag=000f8fe922b6183572fb52e6-1c3fec7b
To: <sip:999999@172.28.1.42>;tag=as76095cdf
Call-ID: 000f8fe9-22b60044-5e58687e-2b1017aa@137.28.94.174
Max-Forwards: 70
Date: Tue, 01 Sep 2009 21:44:41 GMT
CSeq: 103 BYE
User-Agent: Cisco-CP7960G/8.0
Content-Length: 0
Authorization: Digest username="364774",realm="asterisk",uri="sip:999999@172.28.1.42",response="f28f5ff0df64dfd73bf0b64ba8d78d57",nonce="44d15dad",algorithm=MD5

<------------->
--- (11 headers 0 lines) ---

<--- Transmitting (no NAT) to 137.28.94.174:50438 --->
SIP/2.0 481 Call leg/transaction does not exist
Via: SIP/2.0/UDP 137.28.94.174:5061;branch=z9hG4bK4e5788a2;received=137.28.94.174
From: "364774" <sip:364774@172.28.1.42>;tag=000f8fe922b6183572fb52e6-1c3fec7b
To: <sip:999999@172.28.1.42>;tag=as76095cdf
Call-ID: 000f8fe9-22b60044-5e58687e-2b1017aa@137.28.94.174
CSeq: 103 BYE
Server: Asterisk PBX 1.6.2.0-rc1
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0

<------------>
Really destroying SIP dialog '000f8fe9-22b6004c-0eaea2d5-221fefba@137.28.94.174' Method: BYE
asterisk2*CLI>
<--- SIP read from UDP:137.28.94.174:50438 --->
BYE sip:999999@172.28.1.42 SIP/2.0
Via: SIP/2.0/UDP 137.28.94.174:5061;branch=z9hG4bK4e5788a2
From: "364774" <sip:364774@172.28.1.42>;tag=000f8fe922b6183572fb52e6-1c3fec7b
To: <sip:999999@172.28.1.42>;tag=as76095cdf
Call-ID: 000f8fe9-22b60044-5e58687e-2b1017aa@137.28.94.174
Max-Forwards: 70
Date: Tue, 01 Sep 2009 21:44:41 GMT
CSeq: 103 BYE
User-Agent: Cisco-CP7960G/8.0
Content-Length: 0
Authorization: Digest username="364774",realm="asterisk",uri="sip:999999@172.28.1.42",response="f28f5ff0df64dfd73bf0b64ba8d78d57",nonce="44d15dad",algorithm=MD5

<------------->
--- (11 headers 0 lines) ---

<--- Transmitting (no NAT) to 137.28.94.174:50438 --->
SIP/2.0 481 Call leg/transaction does not exist
Via: SIP/2.0/UDP 137.28.94.174:5061;branch=z9hG4bK4e5788a2;received=137.28.94.174
From: "364774" <sip:364774@172.28.1.42>;tag=000f8fe922b6183572fb52e6-1c3fec7b
To: <sip:999999@172.28.1.42>;tag=as76095cdf
Call-ID: 000f8fe9-22b60044-5e58687e-2b1017aa@137.28.94.174
CSeq: 103 BYE
Server: Asterisk PBX 1.6.2.0-rc1
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0

<------------>
asterisk2*CLI> sip set debug off
SIP Debugging Disabled
asterisk2*CLI>

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

SIP Trace Non-Working 1.6.2 session:
===================================================

<--- SIP read from UDP:137.28.94.174:50438 --->
INVITE sip:999999@172.28.1.42 SIP/2.0
Via: SIP/2.0/UDP 137.28.94.174:5061;branch=z9hG4bK512405b0
From: "364774" <sip:364774@172.28.1.42>;tag=000f8fe922b61dba651174b9-265c1b1c
To: <sip:999999@172.28.1.42>
Call-ID: 000f8fe9-22b6004c-0eaea2d5-221fefba@137.28.94.174
Max-Forwards: 70
Date: Wed, 02 Sep 2009 18:24:14 GMT
CSeq: 101 INVITE
User-Agent: Cisco-CP7960G/8.0
Contact: <sip:364774@137.28.94.174:5061;user=phone;transport=udp>
Expires: 180
Accept: application/sdp
Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE
Remote-Party-ID: "364774" <sip:364774@172.28.1.42>;party=calling;id-type=subscriber;privacy=off;screen=yes
Supported: replaces,join,norefersub
Content-Length: 274
Content-Type: application/sdp
Content-Disposition: session;handling=optional

v=0
o=Cisco-SIPUA 3036 0 IN IP4 137.28.94.174
s=SIP Call
t=0 0
m=audio 24422 RTP/AVP 0 8 18 96
c=IN IP4 137.28.94.174
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-15
a=sendrecv

<------------->
--- (18 headers 13 lines) ---
== Using SIP RTP CoS mark 5
Sending to 137.28.94.174 : 5061 (no NAT)
Using INVITE request as basis request - 000f8fe9-22b6004c-0eaea2d5-221fefba@137.28.94.174
Found peer '364774' for '364774' from 137.28.94.174:50438

<--- Reliably Transmitting (no NAT) to 137.28.94.174:5061 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 137.28.94.174:5061;branch=z9hG4bK512405b0;received=137.28.94.174
From: "364774" <sip:364774@172.28.1.42>;tag=000f8fe922b61dba651174b9-265c1b1c
To: <sip:999999@172.28.1.42>;tag=as0ab1bd40
Call-ID: 000f8fe9-22b6004c-0eaea2d5-221fefba@137.28.94.174
CSeq: 101 INVITE
Server: Asterisk PBX 1.6.2.0-rc1
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="656ce60e"
Content-Length: 0

<------------>
Scheduling destruction of SIP dialog '000f8fe9-22b6004c-0eaea2d5-221fefba@137.28.94.174' in 32000 ms (Method: INVITE)
asterisk2*CLI>
<--- SIP read from UDP:137.28.94.174:50517 --->
ACK sip:999999@172.28.1.42 SIP/2.0
Via: SIP/2.0/UDP 137.28.94.174:5061;branch=z9hG4bK512405b0
From: "364774" <sip:364774@172.28.1.42>;tag=000f8fe922b61dba651174b9-265c1b1c
To: <sip:999999@172.28.1.42>;tag=as0ab1bd40
Call-ID: 000f8fe9-22b6004c-0eaea2d5-221fefba@137.28.94.174
Date: Wed, 02 Sep 2009 18:24:14 GMT
CSeq: 101 ACK
Content-Length: 0

<------------->
--- (8 headers 0 lines) ---
asterisk2*CLI>
<--- SIP read from UDP:137.28.94.174:50438 --->
INVITE sip:999999@172.28.1.42 SIP/2.0
Via: SIP/2.0/UDP 137.28.94.174:5061;branch=z9hG4bK67794013
From: "364774" <sip:364774@172.28.1.42>;tag=000f8fe922b61dba651174b9-265c1b1c
To: <sip:999999@172.28.1.42>
Call-ID: 000f8fe9-22b6004c-0eaea2d5-221fefba@137.28.94.174
Max-Forwards: 70
Date: Wed, 02 Sep 2009 18:24:14 GMT
CSeq: 102 INVITE
User-Agent: Cisco-CP7960G/8.0
Contact: <sip:364774@137.28.94.174:5061;user=phone;transport=udp>
Authorization: Digest username="364774",realm="asterisk",uri="sip:999999@172.28.1.42",response="2957f36f6ce85042a43f9343f6fb3b26",nonce="656ce60e",algorithm=MD5
Expires: 180
Accept: application/sdp
Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE
Remote-Party-ID: "364774" <sip:364774@172.28.1.42>;party=calling;id-type=subscriber;privacy=off;screen=yes
Supported: replaces,join,norefersub
Content-Length: 274
Content-Type: application/sdp
Content-Disposition: session;handling=optional

v=0
o=Cisco-SIPUA 3036 0 IN IP4 137.28.94.174
s=SIP Call
t=0 0
m=audio 24422 RTP/AVP 0 8 18 96
c=IN IP4 137.28.94.174
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-15
a=sendrecv

<------------->
--- (19 headers 13 lines) ---
Sending to 137.28.94.174 : 5061 (no NAT)
Using INVITE request as basis request - 000f8fe9-22b6004c-0eaea2d5-221fefba@137.28.94.174
Found peer '364774' for '364774' from 137.28.94.174:50438
Found RTP audio format 0
Found RTP audio format 8
Found RTP audio format 18
Found RTP audio format 96
Peer audio RTP is at port 137.28.94.174:24422
Found audio description format PCMU for ID 0
Found audio description format PCMA for ID 8
Found audio description format G729 for ID 18
Found audio description format telephone-event for ID 96
Capabilities: us - 0x8000e (gsm|ulaw|alaw|h263), peer - audio=0x10c (ulaw|alaw|g729)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0xc (ulaw|alaw)
Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event)
Peer audio RTP is at port 137.28.94.174:24422
Looking for 999999 in phones (domain 172.28.1.42)
list_route: hop: <sip:364774@137.28.94.174:5061;user=phone;transport=udp>

<--- Transmitting (no NAT) to 137.28.94.174:5061 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 137.28.94.174:5061;branch=z9hG4bK67794013;received=137.28.94.174
From: "364774" <sip:364774@172.28.1.42>;tag=000f8fe922b61dba651174b9-265c1b1c
To: <sip:999999@172.28.1.42>
Call-ID: 000f8fe9-22b6004c-0eaea2d5-221fefba@137.28.94.174
CSeq: 102 INVITE
Server: Asterisk PBX 1.6.2.0-rc1
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Contact: <sip:999999@172.28.1.42>
Content-Length: 0

<------------>
-- Executing [999999@phones:1] Answer("SIP/364774-08342938", "") in new stack
Audio is at 172.28.1.42 port 17030
Adding codec 0x4 (ulaw) to SDP
Adding codec 0x8 (alaw) to SDP
Adding non-codec 0x1 (telephone-event) to SDP

<--- Reliably Transmitting (no NAT) to 137.28.94.174:5061 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 137.28.94.174:5061;branch=z9hG4bK67794013;received=137.28.94.174
From: "364774" <sip:364774@172.28.1.42>;tag=000f8fe922b61dba651174b9-265c1b1c
To: <sip:999999@172.28.1.42>;tag=as12968315
Call-ID: 000f8fe9-22b6004c-0eaea2d5-221fefba@137.28.94.174
CSeq: 102 INVITE
Server: Asterisk PBX 1.6.2.0-rc1
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Contact: <sip:999999@172.28.1.42>
Content-Type: application/sdp
Content-Length: 284

v=0
o=root 976721118 976721118 IN IP4 172.28.1.42
s=Asterisk PBX 1.6.2.0-rc1
c=IN IP4 172.28.1.42
t=0 0
m=audio 17030 RTP/AVP 0 8 96
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv

<------------>
-- Executing [999999@phones:2] Set("SIP/364774-08342938", "MBEXT=364774") in new stack
-- Executing [999999@phones:3] Dial("SIP/364774-08342938", "SIP/exchange1/340000") in new stack
== Using SIP RTP CoS mark 5
Audio is at 172.28.1.42 port 10450
Adding codec 0x4 (ulaw) to SDP
Adding codec 0x8 (alaw) to SDP
Adding non-codec 0x1 (telephone-event) to SDP
Reliably Transmitting (no NAT) to 172.28.1.68:5065:
INVITE sip:340000@exch08.uwec.edu:5065 SIP/2.0
Via: SIP/2.0/TCP 172.28.1.42:5060;branch=z9hG4bK79dfe0fe;rport
Max-Forwards: 70
From: "364774" <sip:364774@172.28.1.42>;tag=as17ce3f94
To: <sip:340000@exch08.uwec.edu:5065>
Contact: <sip:364774@172.28.1.42;transport=TCP>
Call-ID: 1290cc7c281a56a4667b73942fd6cada@172.28.1.42
CSeq: 102 INVITE
User-Agent: Asterisk PBX 1.6.2.0-rc1
Date: Wed, 02 Sep 2009 13:10:40 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Type: application/sdp
Content-Length: 284

v=0
o=root 218050453 218050453 IN IP4 172.28.1.42
s=Asterisk PBX 1.6.2.0-rc1
c=IN IP4 172.28.1.42
t=0 0
m=audio 10450 RTP/AVP 0 8 96
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv

---
-- Called exchange1/340000
asterisk2*CLI>
<--- SIP read from TCP:172.28.1.68:5065 --->
SIP/2.0 100 Trying
FROM: "364774"<sip:364774@172.28.1.42>;tag=as17ce3f94
TO: <sip:340000@exch08.uwec.edu:5065>
CSEQ: 102 INVITE
CALL-ID: 1290cc7c281a56a4667b73942fd6cada@172.28.1.42
VIA: SIP/2.0/TCP 172.28.1.42:5060;branch=z9hG4bK79dfe0fe;rport
CONTENT-LENGTH: 0

<------------->
--- (7 headers 0 lines) ---
asterisk2*CLI>
<--- SIP read from TCP:172.28.1.68:5065 --->
SIP/2.0 180 Ringing
FROM: "364774"<sip:364774@172.28.1.42>;tag=as17ce3f94
TO: <sip:340000@exch08.uwec.edu:5065>;epid=9B905B0782;tag=5f4866e9
CSEQ: 102 INVITE
CALL-ID: 1290cc7c281a56a4667b73942fd6cada@172.28.1.42
VIA: SIP/2.0/TCP 172.28.1.42:5060;branch=z9hG4bK79dfe0fe;rport
CONTENT-LENGTH: 0
SERVER: RTCC/3.0.0.0

<------------->
--- (8 headers 0 lines) ---
asterisk2*CLI>
<--- SIP read from UDP:137.28.94.174:50438 --->
ACK sip:999999@172.28.1.42 SIP/2.0
Via: SIP/2.0/UDP 137.28.94.174:5061;branch=z9hG4bK03bf5be6
From: "364774" <sip:364774@172.28.1.42>;tag=000f8fe922b61dba651174b9-265c1b1c
To: <sip:999999@172.28.1.42>;tag=as12968315
Call-ID: 000f8fe9-22b6004c-0eaea2d5-221fefba@137.28.94.174
Max-Forwards: 70
Date: Wed, 02 Sep 2009 18:24:14 GMT
CSeq: 102 ACK
User-Agent: Cisco-CP7960G/8.0
Authorization: Digest username="364774",realm="asterisk",uri="sip:999999@172.28.1.42",response="2957f36f6ce85042a43f9343f6fb3b26",nonce="656ce60e",algorithm=MD5
Remote-Party-ID: "364774" <sip:364774@172.28.1.42>;party=calling;id-type=subscriber;privacy=off;screen=yes
Content-Length: 0

<------------->
--- (12 headers 0 lines) ---
asterisk2*CLI>
<--- SIP read from TCP:172.28.1.68:5065 --->
SIP/2.0 200 OK
FROM: "364774"<sip:364774@172.28.1.42>;tag=as17ce3f94
TO: <sip:340000@exch08.uwec.edu:5065>;epid=9B905B0782;tag=5f4866e9
CSEQ: 102 INVITE
CALL-ID: 1290cc7c281a56a4667b73942fd6cada@172.28.1.42
VIA: SIP/2.0/TCP 172.28.1.42:5060;branch=z9hG4bK79dfe0fe;rport
CONTACT: <sip:EXCH08.uwec.edu:5065;transport=Tcp;maddr=172.28.1.68>;automata
CONTENT-LENGTH: 190
CONTENT-TYPE: application/sdp
ALLOW: UPDATE
SERVER: RTCC/3.0.0.0
ALLOW: Ack, Cancel, Bye,Invite,Message,Info,Service,Options,BeNotify

v=0
o=- 0 0 IN IP4 172.28.1.68
s=Microsoft Exchange Speech Engine
c=IN IP4 172.28.1.68
t=0 0
m=audio 22144 RTP/AVP 0 8 96
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-16
a=ptime:20

<------------->
--- (12 headers 9 lines) ---
Really destroying SIP dialog '000f8fe9-22b60004-4fc65070-6ccc00f4@137.28.94.174' Method: REGISTER
asterisk2*CLI>
<--- SIP read from UDP:137.28.94.174:50438 --->
BYE sip:999999@172.28.1.42 SIP/2.0
Via: SIP/2.0/UDP 137.28.94.174:5061;branch=z9hG4bK4e5788a2
From: "364774" <sip:364774@172.28.1.42>;tag=000f8fe922b6183572fb52e6-1c3fec7b
To: <sip:999999@172.28.1.42>;tag=as76095cdf
Call-ID: 000f8fe9-22b60044-5e58687e-2b1017aa@137.28.94.174
Max-Forwards: 70
Date: Tue, 01 Sep 2009 21:44:41 GMT
CSeq: 103 BYE
User-Agent: Cisco-CP7960G/8.0
Content-Length: 0
Authorization: Digest username="364774",realm="asterisk",uri="sip:999999@172.28.1.42",response="f28f5ff0df64dfd73bf0b64ba8d78d57",nonce="44d15dad",algorithm=MD5

<------------->
--- (11 headers 0 lines) ---

<--- Transmitting (no NAT) to 137.28.94.174:50438 --->
SIP/2.0 481 Call leg/transaction does not exist
Via: SIP/2.0/UDP 137.28.94.174:5061;branch=z9hG4bK4e5788a2;received=137.28.94.174
From: "364774" <sip:364774@172.28.1.42>;tag=000f8fe922b6183572fb52e6-1c3fec7b
To: <sip:999999@172.28.1.42>;tag=as76095cdf
Call-ID: 000f8fe9-22b60044-5e58687e-2b1017aa@137.28.94.174
CSeq: 103 BYE
Server: Asterisk PBX 1.6.2.0-rc1
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0

<------------>
Really destroying SIP dialog '000f8fe9-22b60005-45a29f4a-40d75964@137.28.94.174' Method: REGISTER
Really destroying SIP dialog '000f8fe9-22b60003-19d2baa4-421d6dd1@137.28.94.174' Method: REGISTER
asterisk2*CLI>
<--- SIP read from TCP:172.28.1.68:54478 --->
OPTIONS sip:172.28.1.42:5060 SIP/2.0
FROM: <sip:EXCH08.uwec.edu:5060;transport=Tcp;ms-opaque=e106e8272c05b89b>;epid=ECE8109714;tag=16ec86bf58
TO: <sip:172.28.1.42:5060>
CSEQ: 1272 OPTIONS
CALL-ID: 9def567f876b42829ab7abf210a29a66
MAX-FORWARDS: 70
VIA: SIP/2.0/TCP 172.28.1.68:54478;branch=z9hG4bKa5756858
ACCEPT: application/sdp
CONTENT-LENGTH: 0
USER-AGENT: RTCC/3.0.0.0

<------------->
--- (10 headers 0 lines) ---
Looking for s in default (domain 172.28.1.42)
asterisk2*CLI>
<--- Transmitting (no NAT) to 172.28.1.68:54478 --->
SIP/2.0 200 OK
Via: SIP/2.0/TCP 172.28.1.68:54478;branch=z9hG4bKa5756858;received=172.28.1.68
From: <sip:EXCH08.uwec.edu:5060;transport=Tcp;ms-opaque=e106e8272c05b89b>;epid=ECE8109714;tag=16ec86bf58
To: <sip:172.28.1.42:5060>;tag=as1bd3b7ee
Call-ID: 9def567f876b42829ab7abf210a29a66
CSeq: 1272 OPTIONS
Server: Asterisk PBX 1.6.2.0-rc1
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Contact: <sip:172.28.1.42;transport=TCP>
Accept: application/sdp
Content-Length: 0

<------------>
Scheduling destruction of SIP dialog '9def567f876b42829ab7abf210a29a66' in 32000 ms (Method: OPTIONS)
asterisk2*CLI>
<--- SIP read from UDP:137.28.94.174:50438 --->
BYE sip:999999@172.28.1.42 SIP/2.0
Via: SIP/2.0/UDP 137.28.94.174:5061;branch=z9hG4bK4a05bbbd
From: "364774" <sip:364774@172.28.1.42>;tag=000f8fe922b61dba651174b9-265c1b1c
To: <sip:999999@172.28.1.42>;tag=as12968315
Call-ID: 000f8fe9-22b6004c-0eaea2d5-221fefba@137.28.94.174
Max-Forwards: 70
Date: Wed, 02 Sep 2009 18:24:20 GMT
CSeq: 103 BYE
User-Agent: Cisco-CP7960G/8.0
Content-Length: 0
Authorization: Digest username="364774",realm="asterisk",uri="sip:999999@172.28.1.42",response="2fa759b0307670984f92d9aa13ce3554",nonce="656ce60e",algorithm=MD5

<------------->
--- (11 headers 0 lines) ---
Sending to 137.28.94.174 : 5061 (no NAT)

<--- Transmitting (no NAT) to 137.28.94.174:5061 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 137.28.94.174:5061;branch=z9hG4bK4a05bbbd;received=137.28.94.174
From: "364774" <sip:364774@172.28.1.42>;tag=000f8fe922b61dba651174b9-265c1b1c
To: <sip:999999@172.28.1.42>;tag=as12968315
Call-ID: 000f8fe9-22b6004c-0eaea2d5-221fefba@137.28.94.174
CSeq: 103 BYE
Server: Asterisk PBX 1.6.2.0-rc1
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0

<------------>
Scheduling destruction of SIP dialog '1290cc7c281a56a4667b73942fd6cada@172.28.1.42' in 32000 ms (Method: INVITE)
== Spawn extension (phones, 999999, 3) exited non-zero on 'SIP/364774-08342938'
asterisk2*CLI>
<--- SIP read from UDP:137.28.94.174:50438 --->
BYE sip:999999@172.28.1.42 SIP/2.0
Via: SIP/2.0/UDP 137.28.94.174:5061;branch=z9hG4bK4e5788a2
From: "364774" <sip:364774@172.28.1.42>;tag=000f8fe922b6183572fb52e6-1c3fec7b
To: <sip:999999@172.28.1.42>;tag=as76095cdf
Call-ID: 000f8fe9-22b60044-5e58687e-2b1017aa@137.28.94.174
Max-Forwards: 70
Date: Tue, 01 Sep 2009 21:44:41 GMT
CSeq: 103 BYE
User-Agent: Cisco-CP7960G/8.0
Content-Length: 0
Authorization: Digest username="364774",realm="asterisk",uri="sip:999999@172.28.1.42",response="f28f5ff0df64dfd73bf0b64ba8d78d57",nonce="44d15dad",algorithm=MD5

<------------->
--- (11 headers 0 lines) ---

<--- Transmitting (no NAT) to 137.28.94.174:50438 --->
SIP/2.0 481 Call leg/transaction does not exist
Via: SIP/2.0/UDP 137.28.94.174:5061;branch=z9hG4bK4e5788a2;received=137.28.94.174
From: "364774" <sip:364774@172.28.1.42>;tag=000f8fe922b6183572fb52e6-1c3fec7b
To: <sip:999999@172.28.1.42>;tag=as76095cdf
Call-ID: 000f8fe9-22b60044-5e58687e-2b1017aa@137.28.94.174
CSeq: 103 BYE
Server: Asterisk PBX 1.6.2.0-rc1
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0

<------------>
Really destroying SIP dialog '000f8fe9-22b6004c-0eaea2d5-221fefba@137.28.94.174' Method: BYE
asterisk2*CLI>
<--- SIP read from UDP:137.28.94.174:50438 --->
BYE sip:999999@172.28.1.42 SIP/2.0
Via: SIP/2.0/UDP 137.28.94.174:5061;branch=z9hG4bK4e5788a2
From: "364774" <sip:364774@172.28.1.42>;tag=000f8fe922b6183572fb52e6-1c3fec7b
To: <sip:999999@172.28.1.42>;tag=as76095cdf
Call-ID: 000f8fe9-22b60044-5e58687e-2b1017aa@137.28.94.174
Max-Forwards: 70
Date: Tue, 01 Sep 2009 21:44:41 GMT
CSeq: 103 BYE
User-Agent: Cisco-CP7960G/8.0
Content-Length: 0
Authorization: Digest username="364774",realm="asterisk",uri="sip:999999@172.28.1.42",response="f28f5ff0df64dfd73bf0b64ba8d78d57",nonce="44d15dad",algorithm=MD5

<------------->
--- (11 headers 0 lines) ---

<--- Transmitting (no NAT) to 137.28.94.174:50438 --->
SIP/2.0 481 Call leg/transaction does not exist
Via: SIP/2.0/UDP 137.28.94.174:5061;branch=z9hG4bK4e5788a2;received=137.28.94.174
From: "364774" <sip:364774@172.28.1.42>;tag=000f8fe922b6183572fb52e6-1c3fec7b
To: <sip:999999@172.28.1.42>;tag=as76095cdf
Call-ID: 000f8fe9-22b60044-5e58687e-2b1017aa@137.28.94.174
CSeq: 103 BYE
Server: Asterisk PBX 1.6.2.0-rc1
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0

Comments: By: Dan Radio (whys) 2009-09-03 16:08:40

Sorry, I see no way to edit this report. Please ignore the first two graphs. Below are the correct graphs.

Working 1.6.0.1 session:
===================================================

|Time | 172.28.1.42 | 172.28.1.68 |
|14.844 | INVITE SDP ( telephone-event) |SIP From: sip:364774@172.28.1.42 To:sip:340000@exch08.uwec.edu:5065
| |(53462) ------------------> (5065) |
|14.845 | 100 Trying| |SIP Status
| |(53462) <------------------ (5065) |
|14.854 | 180 Ringing |SIP Status
| |(53462) <------------------ (5065) |
|14.880 | RTP (g711U) |RTP Num packets:3 Duration:0.041s SSRC:0x1142A5A1
| |(15710) ------------------> (61440) |
|14.928 | 200 OK SDP ( telephone-event) |SIP Status
| |(53462) <------------------ (5065) |
|14.932 | ACK | |SIP Request
| |(53462) ------------------> (5065) |
|14.941 | RTP (g711U) |RTP Num packets:7 Duration:0.119s SSRC:0x1142A5A1
| |(15710) ------------------> (61440) |
|15.126 | INVITE SDP ( telephone-event) |SIP From: sip:364774@172.28.1.42 To:sip:340000@exch08.uwec.edu:5065
| |(53462) ------------------> (5065) |
|15.127 | 100 Trying| |SIP Status
| |(53462) <------------------ (5065) |
|15.223 | 200 OK SDP ( telephone-event) |SIP Status
| |(53462) <------------------ (5065) |
|15.225 | ACK | |SIP Request
| |(53462) ------------------> (5065) |
|15.241 | RTP (g711U) |RTP Num packets:2 Duration:0.020s SSRC:0x1142A5A1
| |(15710) ------------------> (61440) |
|22.888 | INVITE SDP ( telephone-event) |SIP From: sip:364774@172.28.1.42 To:sip:340000@exch08.uwec.edu:5065
| |(53462) ------------------> (5065) |
|22.888 | 100 Trying| |SIP Status
| |(53462) <------------------ (5065) |
|22.934 | RTP (g711U) |RTP Num packets:15 Duration:0.245s SSRC:0x107171F2
| |(15710) <------------------ (61440) |
|22.963 | 200 OK SDP ( telephone-event) |SIP Status
| |(53462) <------------------ (5065) |
|22.964 | ACK | |SIP Request
| |(53462) ------------------> (5065) |
|23.157 | BYE | |SIP Request
| |(53462) ------------------> (5065) |
|23.159 | 200 OK | |SIP Status
| |(53462) <------------------ (5065) |

Non-Working 1.6.0.14 session:

|Time | 172.28.1.42 | 172.28.1.68 |
|6.865 | INVITE SDP ( telephone-event) |SIP From: sip:364774@172.28.1.42 To:sip:340000@exch08.uwec.edu:5065
| |(59229) ------------------> (5065) |
|6.866 | 100 Trying| |SIP Status
| |(59229) <------------------ (5065) |
|6.906 | 180 Ringing |SIP Status
| |(59229) <------------------ (5065) |
|6.919 | RTP (g711U) |RTP Num packets:3 Duration:0.024s SSRC:0xF8F641A4
| |(13540) <------------------ (29184) |
|6.946 | 200 OK SDP ( telephone-event) |SIP Status
| |(59229) <------------------ (5065) |
|26.004 | RTP (g711U) |RTP Num packets:187 Duration:3.718s SSRC:0x27EFD11
| |(13540) ------------------> (29184) |
|40.391 | BYE | |SIP Request
| |(59229) <------------------ (5065) |
|40.392 | 200 OK | |SIP Status
| |(59229) ------------------> (5065) |
By: Leif Madsen (lmadsen) 2009-09-16 08:41:08

Honestly, it is preferred that you attach your debugging output to a file instead of inline as it makes the issue quite unweildy to handle going forward. However, I'm still marking this as Acknowledged.

The one piece of information you may be missing is the 'sip history' along with the Asterisk console output.
By: Elazar Broad (ebroad) 2009-09-16 09:19:31

Please try the patch from https://issues.asterisk.org/view.php?id=15896.
By: Stefan Tichy (st) 2009-09-16 10:18:24

Just tried it using 1.6.2.0-rc1. Apparently the patch solves the problem.
By: Dan Radio (whys) 2009-09-17 14:54:33

Confirmed. Applied patch to 1.6.2.0-rc1 and it seems to solve the problem.
This issue can be closed.

Thanks!