[Home]

Summary:ASTERISK-08672: SIP conversations drop after 30 seconds, started about 72 hours ago with no changes in network. Strangely similar to 0008193
Reporter:fordattenborough (fordattenborough)Labels:
Date Opened:2007-01-28 02:14:02.000-0600Date Closed:2007-03-09 14:27:23.000-0600
Priority:MajorRegression?No
Status:Closed/CompleteComponents:Core/General
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:
Description:Here's the layout:

Cisco PRI gateway ---- Asterisk Server ----- Various sip devices
  10.1.0.15             10.1.0.11             10.1.0.0/24

An incoming call into the gateway is forwarded to the * server.  The * server has been running flawlessly for months in passing the calls to Various sip devices on the lan.  The calls persist for around 30 seconds until the following error shows up on the console:

   -- Executing Goto("SIP/10.1.0.11-08b8cda8", "blahblah|7420|1") in new stack
   -- Goto (blahblah,7420,1)
   -- Executing Dial("SIP/10.1.0.11-08b8cda8", "SIP/7420blahblah.1") in new stack
   -- Called 7420blahblah.1
   -- SIP/7420blahblah.1-08b926d8 is ringing
   -- SIP/7420blahblah.1-08b926d8 answered SIP/10.1.0.11-08b8cda8
   -- Attempting native bridge of SIP/10.1.0.11-08b8cda8 and SIP/7420blahblah.1-08b926d8

Jan 28 00:33:06 WARNING[15432]: chan_sip.c:1227 retrans_pkt: Maximum retries exceeded on transmission 9D1923EB-ADDA11DB-830CC41D-A19902DF@10.1.0.15 for seqno 101 (Critical Response)
Jan 28 00:33:06 WARNING[15432]: chan_sip.c:1244 retrans_pkt: Hanging up call 9D1923EB-ADDA11DB-830CC41D-A19902DF@10.1.0.15 - no reply to our critical packet.
 == Spawn extension (blahblah, 7420, 1) exited non-zero on 'SIP/10.1.0.11-08b8cda8'

Here's the circumstances.

The configuration on all devices has not changed.
The problem is repeatable even though:

The Cisco PRI gateway was replaced with a completely new gateway out of the box.
Two new * servers were built with configurations from backup and from scratch, one with 1.2.14 and 1.4 (and latest svn) in a fit of desperation to try to find a scenario where the problem did not happen.  According to the Cisco PRI gateway, the PRI stays up but the SIP session drops.  Here are relevant configuration snippets:

sip.conf
[10.1.0.15]
context=blahblah
type=friend
host=10.1.0.15
dtmfmode=rfc2833
disallow=all
allow=ulaw

[7420blahblah.1]
type=friend
secret=blahblah
host=dynamic
canreinvite=no
disallow=all
allow=ulaw
context=blahblah
dtmfmode=rfc2833

Here is the snippet from the sip debug with CID's and other things changed to protect the innocent.

<-- SIP read from 10.1.0.15:50500:
INVITE sip:3213213210@10.1.0.11:5060 SIP/2.0
Via: SIP/2.0/UDP  10.1.0.15:5060;branch=z9hG4bK2B42096
From: <sip:1231231234@10.1.0.11>;tag=48ADB5C-1F8
To: <sip:3213213210@10.1.0.11>
Date: Sun, 28 Jan 2007 08:10:13 GMT
Call-ID: D0375890-ADDD11DB-8318C41D-A19902DF@10.1.0.15
Supported: 100rel,timer,replaces
Min-SE:  1800
Cisco-Guid: 3493088200-2916946395-2159018007-3769300304
User-Agent: Cisco-SIPGateway/IOS-12.x
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, COMET, REFER, SUBSCRIBE, NOTIFY, INFO, UPDATE, REGISTER
CSeq: 101 INVITE
Max-Forwards: 70
Remote-Party-ID: "pending" <sip:1231231234@10.1.0.15>;party=calling;screen=yes;privacy=off
Timestamp: 1169971813
Contact: <sip:1231231234@10.1.0.15:5060>
Expires: 180
Allow-Events: telephone-event
Content-Type: application/sdp
Content-Length: 182

v=0
o=CiscoSystemsSIP-GW-UserAgent 5830 9051 IN IP4 10.1.0.15
s=SIP Call
c=IN IP4 10.1.0.15
t=0 0
m=audio 18850 RTP/AVP 0
c=IN IP4 10.1.0.15
a=rtpmap:0 PCMU/8000
a=ptime:20

--- (20 headers 9 lines) ---
Using INVITE request as basis request - D0375890-ADDD11DB-8318C41D-A19902DF@10.1.0.15
Sending to 10.1.0.15 : 5060 (non-NAT)
Found no matching peer or user for '10.1.0.15:50500'
Found RTP audio format 0
Peer audio RTP is at port 10.1.0.15:18850
Found description format PCMU
Capabilities: us - 0x4 (ulaw), peer - audio=0x4 (ulaw)/video=0x0 (nothing), combined - 0x4 (ulaw)
Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing)
Looking for 3213213210 in inbound-did (domain 10.1.0.11)
list_route: hop: <sip:1231231234@10.1.0.15:5060>
Transmitting (no NAT) to 10.1.0.15:5060:
SIP/2.0 100 Trying
Via: SIP/2.0/UDP  10.1.0.15:5060;branch=z9hG4bK2B42096;received=10.1.0.15
From: <sip:1231231234@10.1.0.11>;tag=48ADB5C-1F8
To: <sip:3213213210@10.1.0.11>
Call-ID: D0375890-ADDD11DB-8318C41D-A19902DF@10.1.0.15
CSeq: 101 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:3213213210@10.1.0.11>
Content-Length: 0


---
   -- Executing Goto("SIP/10.1.0.11-08b8fe40", "blahblah-tucson-az-520|7420|1") in new stack
   -- Goto (blahblah-tucson-az-520,7420,1)
   -- Executing Dial("SIP/10.1.0.11-08b8fe40", "SIP/7420blahblah.1") in new stack
We're at 10.1.0.11 port 16114
Adding codec 0x4 (ulaw) to SDP
Adding non-codec 0x1 (telephone-event) to SDP
13 headers, 10 lines
Reliably Transmitting (no NAT) to 10.1.1.105:5060:
INVITE sip:7420blahblah.1@10.1.1.105:5060 SIP/2.0
Via: SIP/2.0/UDP 10.1.0.11:5060;branch=z9hG4bK45d61d09;rport
From: "1231231234" <sip:1231231234@10.1.0.11>;tag=as4023b022
To: <sip:7420blahblah.1@10.1.1.105:5060>
Contact: <sip:1231231234@10.1.0.11>
Call-ID: 5ff9cead74c50489349b927e2d628cad@10.1.0.11
CSeq: 102 INVITE
User-Agent: Asterisk PBX
Max-Forwards: 70
Date: Sun, 28 Jan 2007 07:55:37 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Content-Type: application/sdp
Content-Length: 210

v=0
o=root 15315 15315 IN IP4 10.1.0.11
s=session
c=IN IP4 10.1.0.11
t=0 0
m=audio 16114 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -

---
   -- Called 7420blahblah.1
voip3*CLI>
<-- SIP read from 10.1.1.105:5060:
SIP/2.0 100 Trying
To: <sip:7420blahblah.1@10.1.1.105:5060>
From: "1231231234" <sip:1231231234@10.1.0.11>;tag=as4023b022
Call-ID: 5ff9cead74c50489349b927e2d628cad@10.1.0.11
CSeq: 102 INVITE
Via: SIP/2.0/UDP 10.1.0.11:5060;branch=z9hG4bK45d61d09
Server: Linksys/PAP2-3.1.12(LS)
Content-Length: 0


--- (8 headers 0 lines) ---
voip3*CLI>
<-- SIP read from 10.1.1.105:5060:
SIP/2.0 180 Ringing
To: <sip:7420blahblah.1@10.1.1.105:5060>;tag=879e2047f81c7425i0
From: "1231231234" <sip:1231231234@10.1.0.11>;tag=as4023b022
Call-ID: 5ff9cead74c50489349b927e2d628cad@10.1.0.11
CSeq: 102 INVITE
Via: SIP/2.0/UDP 10.1.0.11:5060;branch=z9hG4bK45d61d09
Server: Linksys/PAP2-3.1.12(LS)
Content-Length: 0


--- (8 headers 0 lines) ---
   -- SIP/7420blahblah.1-08ba73f8 is ringing
Transmitting (no NAT) to 10.1.0.15:5060:
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP  10.1.0.15:5060;branch=z9hG4bK2B42096;received=10.1.0.15
From: <sip:1231231234@10.1.0.11>;tag=48ADB5C-1F8
To: <sip:3213213210@10.1.0.11>;tag=as7443a592
Call-ID: D0375890-ADDD11DB-8318C41D-A19902DF@10.1.0.15
CSeq: 101 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:3213213210@10.1.0.11>
Content-Length: 0


---
We're at 10.1.0.11 port 13264
Adding codec 0x4 (ulaw) to SDP
Transmitting (no NAT) to 10.1.0.15:5060:
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP  10.1.0.15:5060;branch=z9hG4bK2B42096;received=10.1.0.15
From: <sip:1231231234@10.1.0.11>;tag=48ADB5C-1F8
To: <sip:3213213210@10.1.0.11>;tag=as7443a592
Call-ID: D0375890-ADDD11DB-8318C41D-A19902DF@10.1.0.15
CSeq: 101 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:3213213210@10.1.0.11>
Content-Type: application/sdp
Content-Length: 154

v=0
o=root 15315 15315 IN IP4 10.1.0.11
s=session
c=IN IP4 10.1.0.11
t=0 0
m=audio 13264 RTP/AVP 0
a=rtpmap:0 PCMU/8000
a=silenceSupp:off - - - -

---
voip3*CLI>
<-- SIP read from 10.1.0.15:50500:
INFO sip:3213213210@10.1.0.11:5060 SIP/2.0
Via: SIP/2.0/UDP  10.1.0.15:5060;branch=z9hG4bK2B526FF
From: <sip:1231231234@10.1.0.11>;tag=48ADB5C-1F8
To: <sip:3213213210@10.1.0.11>;tag=as7443a592
Date: Sun, 28 Jan 2007 08:10:13 GMT
Call-ID: D0375890-ADDD11DB-8318C41D-A19902DF@10.1.0.15
User-Agent: Cisco-SIPGateway/IOS-12.x
Max-Forwards: 70
Timestamp: 1169971813
CSeq: 102 INFO
Contact: <sip:1231231234@10.1.0.15:5060>
Remote-Party-ID: "WIRELESS CALLER" <sip:10.1.0.15>;party=called;screen=no;privacy=off
Content-Length: 0


--- (13 headers 0 lines) ---
Receiving INFO!
Transmitting (no NAT) to 10.1.0.15:5060:
SIP/2.0 403 Unauthorized
Via: SIP/2.0/UDP  10.1.0.15:5060;branch=z9hG4bK2B526FF;received=10.1.0.15
From: <sip:1231231234@10.1.0.11>;tag=48ADB5C-1F8
To: <sip:3213213210@10.1.0.11>;tag=as7443a592
Call-ID: D0375890-ADDD11DB-8318C41D-A19902DF@10.1.0.15
CSeq: 102 INFO
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Content-Length: 0

--- (12 headers 0 lines) ---
Destroying call '212215e20eb6e69a38299d9a0979d1db@10.1.0.11'
voip3*CLI>
<-- SIP read from 10.1.1.105:5060:
SIP/2.0 200 OK
To: <sip:7420blahblah.1@10.1.1.105:5060>;tag=879e2047f81c7425i0
From: "1231231234" <sip:1231231234@10.1.0.11>;tag=as4023b022
Call-ID: 5ff9cead74c50489349b927e2d628cad@10.1.0.11
CSeq: 102 INVITE
Via: SIP/2.0/UDP 10.1.0.11:5060;branch=z9hG4bK45d61d09
Contact: blahblah HP Fax <sip:7420blahblah.1@10.1.1.105:5060>
Server: Linksys/PAP2-3.1.12(LS)
Content-Length: 249
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: x-sipura
Content-Type: application/sdp

v=0
o=- 507201 507201 IN IP4 10.1.1.105
s=-
c=IN IP4 10.1.1.105
t=0 0
m=audio 16438 RTP/AVP 0 100 101
a=rtpmap:0 PCMU/8000
a=rtpmap:100 NSE/8000
a=fmtp:100 192-193
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:30
a=sendrecv

--- (12 headers 13 lines) ---
Found RTP audio format 0
Found RTP audio format 100
Found RTP audio format 101
Peer audio RTP is at port 10.1.1.105:16438
Found description format PCMU
Found description format NSE
Found description format telephone-event
Capabilities: us - 0x4 (ulaw), peer - audio=0x4 (ulaw)/video=0x0 (nothing), combined - 0x4 (ulaw)
Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event)
list_route: hop: <sip:7420blahblah.1@10.1.1.105:5060>
set_destination: Parsing <sip:7420blahblah.1@10.1.1.105:5060> for address/port to send to
set_destination: set destination to 10.1.1.105, port 5060
Transmitting (no NAT) to 10.1.1.105:5060:
ACK sip:7420blahblah.1@10.1.1.105:5060 SIP/2.0
Via: SIP/2.0/UDP 10.1.0.11:5060;branch=z9hG4bK5441c481;rport
From: "1231231234" <sip:1231231234@10.1.0.11>;tag=as4023b022
To: <sip:7420blahblah.1@10.1.1.105:5060>;tag=879e2047f81c7425i0
Contact: <sip:1231231234@10.1.0.11>
Call-ID: 5ff9cead74c50489349b927e2d628cad@10.1.0.11
CSeq: 102 ACK
User-Agent: Asterisk PBX
Max-Forwards: 70
Content-Length: 0


---
   -- SIP/7420blahblah.1-08ba73f8 answered SIP/10.1.0.11-08b8fe40
We're at 10.1.0.11 port 13264
Adding codec 0x4 (ulaw) to SDP
Reliably Transmitting (no NAT) to 10.1.0.15:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP  10.1.0.15:5060;branch=z9hG4bK2B42096;received=10.1.0.15
From: <sip:1231231234@10.1.0.11>;tag=48ADB5C-1F8
To: <sip:3213213210@10.1.0.11>;tag=as7443a592
Call-ID: D0375890-ADDD11DB-8318C41D-A19902DF@10.1.0.15
CSeq: 101 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:3213213210@10.1.0.11>
Content-Type: application/sdp
Content-Length: 154

v=0
o=root 15315 15316 IN IP4 10.1.0.11
s=session
c=IN IP4 10.1.0.11
t=0 0
m=audio 13264 RTP/AVP 0
a=rtpmap:0 PCMU/8000
a=silenceSupp:off - - - -

---
   -- Attempting native bridge of SIP/10.1.0.11-08b8fe40 and SIP/7420blahblah.1-08ba73f8
voip3*CLI>
<-- SIP read from 10.1.0.15:50500:
ACK sip:3213213210@10.1.0.11:5060 SIP/2.0
Via: SIP/2.0/UDP  10.1.0.15:5060;branch=z9hG4bK2B611B5
From: <sip:1231231234@10.1.0.11>;tag=48ADB5C-1F8
To: <sip:3213213210@10.1.0.11>;tag=as7443a592
Date: Sun, 28 Jan 2007 08:10:13 GMT
Call-ID: D0375890-ADDD11DB-8318C41D-A19902DF@10.1.0.15
Max-Forwards: 70
CSeq: 101 ACK
Content-Length: 0


--- (9 headers 0 lines) ---
Retransmitting #1 (no NAT) to 10.1.0.15:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP  10.1.0.15:5060;branch=z9hG4bK2B42096;received=10.1.0.15
From: <sip:1231231234@10.1.0.11>;tag=48ADB5C-1F8
To: <sip:3213213210@10.1.0.11>;tag=as7443a592
Call-ID: D0375890-ADDD11DB-8318C41D-A19902DF@10.1.0.15
CSeq: 101 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:3213213210@10.1.0.11>
Content-Type: application/sdp
Content-Length: 154

v=0
o=root 15315 15316 IN IP4 10.1.0.11
s=session
c=IN IP4 10.1.0.11
t=0 0
m=audio 13264 RTP/AVP 0
a=rtpmap:0 PCMU/8000
a=silenceSupp:off - - - -

---
voip3*CLI>
<-- SIP read from 10.1.0.15:50500:
ACK sip:3213213210@10.1.0.11:5060 SIP/2.0
Via: SIP/2.0/UDP  10.1.0.15:5060;branch=z9hG4bK2B611B5
From: <sip:1231231234@10.1.0.11>;tag=48ADB5C-1F8
To: <sip:3213213210@10.1.0.11>;tag=as7443a592
Date: Sun, 28 Jan 2007 08:10:13 GMT
Call-ID: D0375890-ADDD11DB-8318C41D-A19902DF@10.1.0.15
Max-Forwards: 70
CSeq: 101 ACK
Content-Length: 0

--- (10 headers 0 lines) ---
Destroying call '450984c0269a45835c7462ba0c1e2bcb@10.1.0.11'
Retransmitting #2 (no NAT) to 10.1.0.15:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP  10.1.0.15:5060;branch=z9hG4bK2B42096;received=10.1.0.15
From: <sip:1231231234@10.1.0.11>;tag=48ADB5C-1F8
To: <sip:3213213210@10.1.0.11>;tag=as7443a592
Call-ID: D0375890-ADDD11DB-8318C41D-A19902DF@10.1.0.15
CSeq: 101 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:3213213210@10.1.0.11>
Content-Type: application/sdp
Content-Length: 154

v=0
o=root 15315 15316 IN IP4 10.1.0.11
s=session
c=IN IP4 10.1.0.11
t=0 0
m=audio 13264 RTP/AVP 0
a=rtpmap:0 PCMU/8000
a=silenceSupp:off - - - -

---
voip3*CLI>
<-- SIP read from 10.1.0.15:50500:
ACK sip:3213213210@10.1.0.11:5060 SIP/2.0
Via: SIP/2.0/UDP  10.1.0.15:5060;branch=z9hG4bK2B611B5
From: <sip:1231231234@10.1.0.11>;tag=48ADB5C-1F8
To: <sip:3213213210@10.1.0.11>;tag=as7443a592
Date: Sun, 28 Jan 2007 08:10:13 GMT
Call-ID: D0375890-ADDD11DB-8318C41D-A19902DF@10.1.0.15
Max-Forwards: 70
CSeq: 101 ACK
Content-Length: 0

--- (10 headers 0 lines) ---
Destroying call '68d184603b902c77207c68112f28473e@10.1.0.11'
Jan 28 00:55:43 NOTICE[16167]: rtp.c:576 ast_rtp_read: Unknown RTP codec 100 received
Retransmitting #3 (no NAT) to 10.1.0.15:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP  10.1.0.15:5060;branch=z9hG4bK2B42096;received=10.1.0.15
From: <sip:1231231234@10.1.0.11>;tag=48ADB5C-1F8
To: <sip:3213213210@10.1.0.11>;tag=as7443a592
Call-ID: D0375890-ADDD11DB-8318C41D-A19902DF@10.1.0.15
CSeq: 101 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:3213213210@10.1.0.11>
Content-Type: application/sdp
Content-Length: 154

v=0
o=root 15315 15316 IN IP4 10.1.0.11
s=session
c=IN IP4 10.1.0.11
t=0 0
m=audio 13264 RTP/AVP 0
a=rtpmap:0 PCMU/8000
a=silenceSupp:off - - - -

---
voip3*CLI>
<-- SIP read from 10.1.0.15:50500:
ACK sip:3213213210@10.1.0.11:5060 SIP/2.0
Via: SIP/2.0/UDP  10.1.0.15:5060;branch=z9hG4bK2B611B5
From: <sip:1231231234@10.1.0.11>;tag=48ADB5C-1F8
To: <sip:3213213210@10.1.0.11>;tag=as7443a592
Date: Sun, 28 Jan 2007 08:10:13 GMT
Call-ID: D0375890-ADDD11DB-8318C41D-A19902DF@10.1.0.15
Max-Forwards: 70
CSeq: 101 ACK
Content-Length: 0


--- (9 headers 0 lines) ---
Retransmitting #4 (no NAT) to 10.1.0.15:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP  10.1.0.15:5060;branch=z9hG4bK2B42096;received=10.1.0.15
From: <sip:1231231234@10.1.0.11>;tag=48ADB5C-1F8
To: <sip:3213213210@10.1.0.11>;tag=as7443a592
Call-ID: D0375890-ADDD11DB-8318C41D-A19902DF@10.1.0.15
CSeq: 101 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:3213213210@10.1.0.11>
Content-Type: application/sdp
Content-Length: 154

v=0
o=root 15315 15316 IN IP4 10.1.0.11
s=session
c=IN IP4 10.1.0.11
t=0 0
m=audio 13264 RTP/AVP 0
a=rtpmap:0 PCMU/8000
a=silenceSupp:off - - - -

---
voip3*CLI>
<-- SIP read from 10.1.0.15:50500:
ACK sip:3213213210@10.1.0.11:5060 SIP/2.0
Via: SIP/2.0/UDP  10.1.0.15:5060;branch=z9hG4bK2B611B5
From: <sip:1231231234@10.1.0.11>;tag=48ADB5C-1F8
To: <sip:3213213210@10.1.0.11>;tag=as7443a592
Date: Sun, 28 Jan 2007 08:10:13 GMT
Call-ID: D0375890-ADDD11DB-8318C41D-A19902DF@10.1.0.15
Max-Forwards: 70
CSeq: 101 ACK
Content-Length: 0


--- (9 headers 0 lines) ---
voip3*CLI>
<-- SIP read from 189.171.113.210:5060:

--- (0 headers 0 lines) Nat keepalive ---
Retransmitting ASTERISK-1 (no NAT) to 10.1.0.15:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP  10.1.0.15:5060;branch=z9hG4bK2B42096;received=10.1.0.15
From: <sip:1231231234@10.1.0.11>;tag=48ADB5C-1F8
To: <sip:3213213210@10.1.0.11>;tag=as7443a592
Call-ID: D0375890-ADDD11DB-8318C41D-A19902DF@10.1.0.15
CSeq: 101 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:3213213210@10.1.0.11>
Content-Type: application/sdp
Content-Length: 154

v=0
o=root 15315 15316 IN IP4 10.1.0.11
s=session
c=IN IP4 10.1.0.11
t=0 0
m=audio 13264 RTP/AVP 0
a=rtpmap:0 PCMU/8000
a=silenceSupp:off - - - -

---
voip3*CLI>
<-- SIP read from 10.1.0.15:50500:
ACK sip:3213213210@10.1.0.11:5060 SIP/2.0
Via: SIP/2.0/UDP  10.1.0.15:5060;branch=z9hG4bK2B611B5
From: <sip:1231231234@10.1.0.11>;tag=48ADB5C-1F8
To: <sip:3213213210@10.1.0.11>;tag=as7443a592
Date: Sun, 28 Jan 2007 08:10:13 GMT
Call-ID: D0375890-ADDD11DB-8318C41D-A19902DF@10.1.0.15
Max-Forwards: 70
CSeq: 101 ACK
Content-Length: 0


--- (9 headers 0 lines) ---
voip3*CLI>
<-- SIP read from 65.100.102.252:1024:

--- (0 headers 0 lines) Nat keepalive ---
voip3*CLI>
<-- SIP read from 10.1.0.1:2310:



--- (0 headers 1 lines) ---
Retransmitting ASTERISK-2 (no NAT) to 10.1.0.15:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP  10.1.0.15:5060;branch=z9hG4bK2B42096;received=10.1.0.15
From: <sip:1231231234@10.1.0.11>;tag=48ADB5C-1F8
To: <sip:3213213210@10.1.0.11>;tag=as7443a592
Call-ID: D0375890-ADDD11DB-8318C41D-A19902DF@10.1.0.15
CSeq: 101 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:3213213210@10.1.0.11>
Content-Type: application/sdp
Content-Length: 154

v=0
o=root 15315 15316 IN IP4 10.1.0.11
s=session
c=IN IP4 10.1.0.11
t=0 0
m=audio 13264 RTP/AVP 0
a=rtpmap:0 PCMU/8000
a=silenceSupp:off - - - -

---
voip3*CLI>
<-- SIP read from 10.1.0.15:50500:
ACK sip:3213213210@10.1.0.11:5060 SIP/2.0
Via: SIP/2.0/UDP  10.1.0.15:5060;branch=z9hG4bK2B611B5
From: <sip:1231231234@10.1.0.11>;tag=48ADB5C-1F8
To: <sip:3213213210@10.1.0.11>;tag=as7443a592
Date: Sun, 28 Jan 2007 08:10:13 GMT
Call-ID: D0375890-ADDD11DB-8318C41D-A19902DF@10.1.0.15
Max-Forwards: 70
CSeq: 101 ACK
Content-Length: 0


--- (9 headers 0 lines) ---
Destroying call '5a2b905646ccb953586eb2ad37f87faf@127.0.0.1'
Jan 28 00:56:00 WARNING[15432]: chan_sip.c:1227 retrans_pkt: Maximum retries exceeded on transmission D0375890-ADDD11DB-8318C41D-A19902DF@10.1.0.15 for seqno 101 (Critical Response)
Jan 28 00:56:00 WARNING[15432]: chan_sip.c:1244 retrans_pkt: Hanging up call D0375890-ADDD11DB-8318C41D-A19902DF@10.1.0.15 - no reply to our critical packet.
Scheduling destruction of call '5ff9cead74c50489349b927e2d628cad@10.1.0.11' in 32000 ms
set_destination: Parsing <sip:7420blahblah.1@10.1.1.105:5060> for address/port to send to
set_destination: set destination to 10.1.1.105, port 5060
Reliably Transmitting (no NAT) to 10.1.1.105:5060:
BYE sip:7420blahblah.1@10.1.1.105:5060 SIP/2.0
Via: SIP/2.0/UDP 10.1.0.11:5060;branch=z9hG4bK79d46e8f;rport
From: "1231231234" <sip:1231231234@10.1.0.11>;tag=as4023b022
To: <sip:7420blahblah.1@10.1.1.105:5060>;tag=879e2047f81c7425i0
Call-ID: 5ff9cead74c50489349b927e2d628cad@10.1.0.11
CSeq: 103 BYE
User-Agent: Asterisk PBX
Max-Forwards: 70
Content-Length: 0


---
 == Spawn extension (blahblah-tucson-az-520, 7420, 1) exited non-zero on 'SIP/10.1.0.11-08b8fe40'
voip3*CLI>
<-- SIP read from 10.1.1.105:5060:
SIP/2.0 200 OK
To: <sip:7420blahblah.1@10.1.1.105:5060>;tag=879e2047f81c7425i0
From: "1231231234" <sip:1231231234@10.1.0.11>;tag=as4023b022
Call-ID: 5ff9cead74c50489349b927e2d628cad@10.1.0.11
CSeq: 103 BYE
Via: SIP/2.0/UDP 10.1.0.11:5060;branch=z9hG4bK79d46e8f
Server: Linksys/PAP2-3.1.12(LS)
Content-Length: 0


--- (8 headers 0 lines) ---
Destroying call '5ff9cead74c50489349b927e2d628cad@10.1.0.11'
Destroying call 'D0375890-ADDD11DB-8318C41D-A19902DF@10.1.0.15'


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

Will pay for a solution.
Comments:By: fordattenborough (fordattenborough) 2007-01-29 00:07:24.000-0600

For what its worth, I back-revved the server to 1.2.13 and was able to restore functionality.  For lack of a better word, it seems like 1.2.14 and 1.4 have some additional 'sensitivities' that contribute to this issue.
By: fordattenborough (fordattenborough) 2007-01-29 19:41:04.000-0600

Found similar unresolved discussion on:

http://lists.digium.com/pipermail/asterisk-users/2006-September/165275.html

http://groups.google.com/group/asterisk-es/browse_thread/thread/e31361de2a2d5ca5/02f53c21044b89ed?lnk=st&q=Maximum+retries+exceeded+on+transmission&rnum=1&hl=en#02f53c21044b89ed


By: Joshua C. Colp (jcolp) 2007-01-30 10:36:44.000-0600

I suspect your issue is the INFO coming in before the call is answered, this may screw up chan_sip so it will ignore the final response on a packet.
By: Joshua C. Colp (jcolp) 2007-01-30 10:37:50.000-0600

Since I just know you love INFO like this...
By: Serge Vecher (serge-v) 2007-02-02 12:59:26.000-0600

As per bug guidelines, can you please attach a SIP _debug_ trace illustrating the problem. Please do the following:
1) Prepare test environment (reduce the amount of unrelated traffic on the server);
2) Make sure your logger.conf has the following line:
  console => notice,warning,error,debug
3) restart Asterisk with the following command:
  'asterisk -Tvvvvvdddddngc | tee /tmp/verbosedebug.txt'
4) Enable SIP transaction logging with the following CLI commands:
set debug 4
set verbose 4
sip debug
5) Trim startup information and attach verbosedebug.txt to the issue.
By: Serge Vecher (serge-v) 2007-02-02 13:04:38.000-0600

also, if you are in the position to do so, it would be helpful if you could narrow down the revision of 1.2 svn where breakage has occurred. This lists all changes to chan_sip in 1.2 branch http://svn.digium.com/view/asterisk/branches/1.2/channels/chan_sip.c?rev=53103&view=log

1.2.13 corresponds to rev. 45412, so that's the starting point. Thanks!
By: Olle Johansson (oej) 2007-02-02 14:11:05.000-0600

Yes, this INFO package adds to the brew. This is a duplicate bug report.

Can you explain the INFO package that Cisco sent?
By: Olle Johansson (oej) 2007-02-02 14:14:46.000-0600

In the future, please add debug logs as attached files and NOT in the bug report. Thank you.
By: fordattenborough (fordattenborough) 2007-02-02 18:29:23.000-0600

Thank you for finally taking a look at this issue.  What I'll do is build up another * server and set up a test configuration to try to exploit the issue again.  Which version of * would you like me to test with?  Please advise.
By: Serge Vecher (serge-v) 2007-02-05 15:17:19.000-0600

fordattenborough: since you have a budget for a solution to this, can you please email oej directly at oej at edvina.net?
By: Serge Vecher (serge-v) 2007-02-26 16:06:40.000-0600

alright, since oej has marked this as a duplicate and there's been no reply to my suggestion, I'm assuming something is in the works. If you need to post further on this issue, please do so in bug 5215. Thanks.
By: Olle Johansson (oej) 2007-03-09 14:27:23.000-0600

So the Cisco sends and INFO during the INVITE to try to update the Caller ID NAME.

There's no event in Asterisk to update caller ID names, and this is not a standard SIP way to do it. In fact, there's no standard SIP way to update caller IDs during a call.

The other issue is what is reported in the related bug report - that Asterisk can't handle two simultaneous SIP transactions.