rendered paste body*********************************************************************************************************
HERE WE HAVE TWO INCOMING CALLS. THE FIRST COMPLETED NORMALLY, THE SECOND FAILED
6165550000 and 6165555555 replace actual calling numbers
1111111111 replaces an existing number for which we have defined an incoming route
(This is to illustrate that the 's' is NOT the main issue here, although it may
be a separate issue that should be addressed)
NOTE ALSO THAT EVEN THOUGH THE FIRST CALL COMPLETES, WE ARE GETTING THIS LINE:
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Found no match for SIP option: x-sipura (Please file bug report!)
*********************************************************************************************************
<-- SIP read from 192.168.0.205:5061:
INVITE sip:1111111111@192.168.0.200 SIP/2.0
Via: SIP/2.0/UDP 192.168.0.205:5061;branch=z9hG4bK-865a619c
From: "Short CID" <sip:6165550000@192.168.0.200>;tag=f1ce50d13affcad4o1
To: <sip:1111111111@192.168.0.200>
Remote-Party-ID: "Short CID" <sip:6165550000@192.168.0.200>;screen=yes;party=calling
Call-ID: 350a8255-2d83a720@192.168.0.205
CSeq: 101 INVITE
Max-Forwards: 70
Contact: SPA3000 <sip:6165550000@192.168.0.205:5061>
Expires: 240
User-Agent: Linksys/SPA3000-3.1.10(GWd)
Content-Length: 446
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: x-sipura
Content-Type: application/sdp
v=0
o=- 6134514 6134514 IN IP4 192.168.0.205
s=-
c=IN IP4 192.168.0.205
t=0 0
m=audio 16478 RTP/AVP 0 2 4 8 18 96 97 98 100 101
a=rtpmap:0 PCMU/8000
a=rtpmap:2 G726-32/8000
a=rtpmap:4 G723/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729a/8000
a=rtpmap:96 G726-40/8000
a=rtpmap:97 G726-24/8000
a=rtpmap:98 G726-16/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
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 0: INVITE sip:1111111111@192.168.0.200 SIP/2.0 (43)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.0.205:5061;branch=z9hG4bK-865a619c (59)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 2: From: "Short CID" <sip:6165550000@192.168.0.200>;tag=f1ce50d13affcad4o1 (74)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 3: To: <sip:1111111111@192.168.0.200> (34)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 4: Remote-Party-ID: "Short CID" <sip:6165550000@192.168.0.200>;screen=yes;party=calling (87)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 5: Call-ID: 350a8255-2d83a720@192.168.0.205 (40)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 6: CSeq: 101 INVITE (16)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 7: Max-Forwards: 70 (16)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 8: Contact: SPA3000 <sip:6165550000@192.168.0.205:5061> (52)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 9: Expires: 240 (12)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 10: User-Agent: Linksys/SPA3000-3.1.10(GWd) (39)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 11: Content-Length: 446 (19)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 12: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 13: Supported: x-sipura (19)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 14: Content-Type: application/sdp (29)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 15: (0)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Line: v=0 (3)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Line: o=- 6134514 6134514 IN IP4 192.168.0.205 (40)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Line: s=- (3)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Line: c=IN IP4 192.168.0.205 (22)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Line: t=0 0 (5)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Line: m=audio 16478 RTP/AVP 0 2 4 8 18 96 97 98 100 101 (49)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Line: a=rtpmap:2 G726-32/8000 (23)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Line: a=rtpmap:4 G723/8000 (20)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Line: a=rtpmap:18 G729a/8000 (22)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Line: a=rtpmap:96 G726-40/8000 (24)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Line: a=rtpmap:97 G726-24/8000 (24)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Line: a=rtpmap:98 G726-16/8000 (24)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Line: a=rtpmap:100 NSE/8000 (21)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Line: a=fmtp:100 192-193 (18)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Line: a=fmtp:101 0-15 (15)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Line: a=ptime:30 (10)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Line: a=sendrecv (10)
Jun 6 15:14:41 VERBOSE[8500] logger.c: --- (15 headers 20 lines)Jun 6 15:14:41 VERBOSE[8500] logger.c: --- (15 headers 20 lines)---
Jun 6 15:14:41 DEBUG[8500] acl.c: ##### Testing 192.168.0.205 with 192.168.0.0
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Allocating new SIP dialog for 350a8255-2d83a720@192.168.0.205 - INVITE (With RTP)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Begin: parsing SIP "Supported: x-sipura"
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Found SIP option: -x-sipura-
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Found no match for SIP option: x-sipura (Please file bug report!)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: * SIP extension value: 0 for call 350a8255-2d83a720@192.168.0.205
Jun 6 15:14:41 VERBOSE[8500] logger.c: Using INVITE request as basis request - 350a8255-2d83a720@192.168.0.205
Jun 6 15:14:41 VERBOSE[8500] logger.c: Sending to 192.168.0.205 : 5061 (NAT)
Jun 6 15:14:41 VERBOSE[8500] logger.c: Found peer 'pstn'
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Setting NAT on RTP to 0
Jun 6 15:14:41 VERBOSE[8500] logger.c: Reliably Transmitting (no NAT) to 192.168.0.205:5061:
SIP/2.0 407 Proxy Authentication Required
Via: SIP/2.0/UDP 192.168.0.205:5061;branch=z9hG4bK-865a619c;received=192.168.0.205
From: "Short CID" <sip:6165550000@192.168.0.200>;tag=f1ce50d13affcad4o1
To: <sip:1111111111@192.168.0.200>;tag=as561d72ff
Call-ID: 350a8255-2d83a720@192.168.0.205
CSeq: 101 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:1111111111@192.168.0.200>
Proxy-Authenticate: Digest realm="asterisk", nonce="37fdc30d"
Content-Length: 0
---
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #22017
Jun 6 15:14:41 VERBOSE[8500] logger.c: Scheduling destruction of call '350a8255-2d83a720@192.168.0.205' in 15000 ms
Jun 6 15:14:41 VERBOSE[8500] logger.c:
<-- SIP read from 192.168.0.205:5061:
ACK sip:1111111111@192.168.0.200 SIP/2.0
Via: SIP/2.0/UDP 192.168.0.205:5061;branch=z9hG4bK-865a619c
From: "Short CID" <sip:6165550000@192.168.0.200>;tag=f1ce50d13affcad4o1
To: <sip:1111111111@192.168.0.200>;tag=as561d72ff
Call-ID: 350a8255-2d83a720@192.168.0.205
CSeq: 101 ACK
Max-Forwards: 70
Contact: SPA3000 <sip:6165550000@192.168.0.205:5061>
User-Agent: Linksys/SPA3000-3.1.10(GWd)
Content-Length: 0
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 0: ACK sip:1111111111@192.168.0.200 SIP/2.0 (40)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.0.205:5061;branch=z9hG4bK-865a619c (59)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 2: From: "Short CID" <sip:6165550000@192.168.0.200>;tag=f1ce50d13affcad4o1 (74)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 3: To: <sip:1111111111@192.168.0.200>;tag=as561d72ff (49)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 4: Call-ID: 350a8255-2d83a720@192.168.0.205 (40)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 5: CSeq: 101 ACK (13)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 6: Max-Forwards: 70 (16)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 7: Contact: SPA3000 <sip:6165550000@192.168.0.205:5061> (52)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 8: User-Agent: Linksys/SPA3000-3.1.10(GWd) (39)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 9: Content-Length: 0 (17)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 10: (0)
Jun 6 15:14:41 VERBOSE[8500] logger.c: --- (10 headers 0 lines)Jun 6 15:14:41 VERBOSE[8500] logger.c: --- (10 headers 0 lines)---
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: **** Received ACK (6) - Command in SIP ACK
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #22017
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Stopping retransmission on '350a8255-2d83a720@192.168.0.205' of Response 101: Match Found
Jun 6 15:14:41 VERBOSE[8500] logger.c:
<-- SIP read from 192.168.0.205:5061:
INVITE sip:1111111111@192.168.0.200 SIP/2.0
Via: SIP/2.0/UDP 192.168.0.205:5061;branch=z9hG4bK-82b5d698
From: "Short CID" <sip:6165550000@192.168.0.200>;tag=f1ce50d13affcad4o1
To: <sip:1111111111@192.168.0.200>
Remote-Party-ID: "Short CID" <sip:6165550000@192.168.0.200>;screen=yes;party=calling
Call-ID: 350a8255-2d83a720@192.168.0.205
CSeq: 102 INVITE
Max-Forwards: 70
Proxy-Authorization: Digest username="pstn",realm="asterisk",nonce="37fdc30d",uri="sip:1111111111@192.168.0.200",algorithm=MD5,response="b586bb2a4f6000b4cca52b4618ad554a"
Contact: SPA3000 <sip:6165550000@192.168.0.205:5061>
Expires: 240
User-Agent: Linksys/SPA3000-3.1.10(GWd)
Content-Length: 446
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: x-sipura
Content-Type: application/sdp
v=0
o=- 6134514 6134514 IN IP4 192.168.0.205
s=-
c=IN IP4 192.168.0.205
t=0 0
m=audio 16478 RTP/AVP 0 2 4 8 18 96 97 98 100 101
a=rtpmap:0 PCMU/8000
a=rtpmap:2 G726-32/8000
a=rtpmap:4 G723/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729a/8000
a=rtpmap:96 G726-40/8000
a=rtpmap:97 G726-24/8000
a=rtpmap:98 G726-16/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
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 0: INVITE sip:1111111111@192.168.0.200 SIP/2.0 (43)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.0.205:5061;branch=z9hG4bK-82b5d698 (59)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 2: From: "Short CID" <sip:6165550000@192.168.0.200>;tag=f1ce50d13affcad4o1 (74)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 3: To: <sip:1111111111@192.168.0.200> (34)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 4: Remote-Party-ID: "Short CID" <sip:6165550000@192.168.0.200>;screen=yes;party=calling (87)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 5: Call-ID: 350a8255-2d83a720@192.168.0.205 (40)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 6: CSeq: 102 INVITE (16)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 7: Max-Forwards: 70 (16)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 8: Proxy-Authorization: Digest username="pstn",realm="asterisk",nonce="37fdc30d",uri="sip:1111111111@192.168.0.200",algorithm=MD5,response="b586bb2a4f6000b4cca52b4618ad554a" (170)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 9: Contact: SPA3000 <sip:6165550000@192.168.0.205:5061> (52)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 10: Expires: 240 (12)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 11: User-Agent: Linksys/SPA3000-3.1.10(GWd) (39)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 12: Content-Length: 446 (19)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 13: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 14: Supported: x-sipura (19)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 15: Content-Type: application/sdp (29)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 16: (0)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Line: v=0 (3)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Line: o=- 6134514 6134514 IN IP4 192.168.0.205 (40)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Line: s=- (3)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Line: c=IN IP4 192.168.0.205 (22)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Line: t=0 0 (5)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Line: m=audio 16478 RTP/AVP 0 2 4 8 18 96 97 98 100 101 (49)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Line: a=rtpmap:2 G726-32/8000 (23)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Line: a=rtpmap:4 G723/8000 (20)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Line: a=rtpmap:18 G729a/8000 (22)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Line: a=rtpmap:96 G726-40/8000 (24)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Line: a=rtpmap:97 G726-24/8000 (24)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Line: a=rtpmap:98 G726-16/8000 (24)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Line: a=rtpmap:100 NSE/8000 (21)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Line: a=fmtp:100 192-193 (18)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Line: a=fmtp:101 0-15 (15)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Line: a=ptime:30 (10)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Line: a=sendrecv (10)
Jun 6 15:14:41 VERBOSE[8500] logger.c: --- (16 headers 20 lines)Jun 6 15:14:41 VERBOSE[8500] logger.c: --- (16 headers 20 lines)---
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Begin: parsing SIP "Supported: x-sipura"
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Found SIP option: -x-sipura-
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Found no match for SIP option: x-sipura (Please file bug report!)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: * SIP extension value: 0 for call 350a8255-2d83a720@192.168.0.205
Jun 6 15:14:41 VERBOSE[8500] logger.c: Using INVITE request as basis request - 350a8255-2d83a720@192.168.0.205
Jun 6 15:14:41 VERBOSE[8500] logger.c: Sending to 192.168.0.205 : 5061 (non-NAT)
Jun 6 15:14:41 VERBOSE[8500] logger.c: Found peer 'pstn'
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Setting NAT on RTP to 0
Jun 6 15:14:41 VERBOSE[8500] logger.c: Found RTP audio format 0
Jun 6 15:14:41 VERBOSE[8500] logger.c: Found RTP audio format 2
Jun 6 15:14:41 VERBOSE[8500] logger.c: Found RTP audio format 4
Jun 6 15:14:41 VERBOSE[8500] logger.c: Found RTP audio format 8
Jun 6 15:14:41 VERBOSE[8500] logger.c: Found RTP audio format 18
Jun 6 15:14:41 VERBOSE[8500] logger.c: Found RTP audio format 96
Jun 6 15:14:41 VERBOSE[8500] logger.c: Found RTP audio format 97
Jun 6 15:14:41 VERBOSE[8500] logger.c: Found RTP audio format 98
Jun 6 15:14:41 VERBOSE[8500] logger.c: Found RTP audio format 100
Jun 6 15:14:41 VERBOSE[8500] logger.c: Found RTP audio format 101
Jun 6 15:14:41 VERBOSE[8500] logger.c: Peer audio RTP is at port 192.168.0.205:16478
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Peer audio RTP is at port 192.168.0.205:16478
Jun 6 15:14:41 VERBOSE[8500] logger.c: Found description format PCMU
Jun 6 15:14:41 VERBOSE[8500] logger.c: Found description format G726-32
Jun 6 15:14:41 VERBOSE[8500] logger.c: Found description format G723
Jun 6 15:14:41 VERBOSE[8500] logger.c: Found description format PCMA
Jun 6 15:14:41 VERBOSE[8500] logger.c: Found description format G729a
Jun 6 15:14:41 VERBOSE[8500] logger.c: Found description format G726-40
Jun 6 15:14:41 VERBOSE[8500] logger.c: Found description format G726-24
Jun 6 15:14:41 VERBOSE[8500] logger.c: Found description format G726-16
Jun 6 15:14:41 VERBOSE[8500] logger.c: Found description format NSE
Jun 6 15:14:41 VERBOSE[8500] logger.c: Found description format telephone-event
Jun 6 15:14:41 VERBOSE[8500] logger.c: Capabilities: us - 0x4 (ulaw), peer - audio=0x51d (g723|ulaw|alaw|g726|g729|ilbc)/video=0x0 (nothing), combined - 0x4 (ulaw)
Jun 6 15:14:41 VERBOSE[8500] logger.c: Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Checking SIP call limits for device pstn
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Updating call counter for incoming call
Jun 6 15:14:41 VERBOSE[8500] logger.c: Looking for 1111111111 in from-trunk (domain 192.168.0.200)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: build_route: Contact hop: SPA3000 <sip:6165550000@192.168.0.205:5061>
Jun 6 15:14:41 VERBOSE[8500] logger.c: list_route: hop: <sip:6165550000@192.168.0.205:5061>
Jun 6 15:14:41 VERBOSE[8500] logger.c: Transmitting (no NAT) to 192.168.0.205:5061:
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.0.205:5061;branch=z9hG4bK-82b5d698;received=192.168.0.205
From: "Short CID" <sip:6165550000@192.168.0.200>;tag=f1ce50d13affcad4o1
To: <sip:1111111111@192.168.0.200>
Call-ID: 350a8255-2d83a720@192.168.0.205
CSeq: 102 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:1111111111@192.168.0.200>
Content-Length: 0
---
Jun 6 15:14:41 DEBUG[8490] chan_sip.c: Checking device state for peer pstn
Jun 6 15:14:41 DEBUG[8490] devicestate.c: Changing state for SIP/pstn - state 2 (In use)
Jun 6 15:14:41 DEBUG[15988] pbx.c: Launching 'Set'
Jun 6 15:14:41 VERBOSE[15988] logger.c: -- Executing Set("SIP/pstn-7f0a", "FROM_DID=1111111111") in new stack
Jun 6 15:14:41 DEBUG[15988] pbx.c: Launching 'Goto'
Jun 6 15:14:41 VERBOSE[15988] logger.c: -- Executing Goto("SIP/pstn-7f0a", "ivr-2|s|1") in new stack
Jun 6 15:14:41 VERBOSE[15988] logger.c: -- Goto (ivr-2,s,1)
Jun 6 15:14:41 DEBUG[15988] pbx.c: Launching 'Set'
Jun 6 15:14:41 VERBOSE[15988] logger.c: -- Executing Set("SIP/pstn-7f0a", "LOOPCOUNT=0") in new stack
Jun 6 15:14:41 DEBUG[15988] pbx.c: Launching 'Set'
Jun 6 15:14:41 VERBOSE[15988] logger.c: -- Executing Set("SIP/pstn-7f0a", "__DIR-CONTEXT=default") in new stack
Jun 6 15:14:41 DEBUG[15988] pbx.c: Launching 'Answer'
Jun 6 15:14:41 VERBOSE[15988] logger.c: -- Executing Answer("SIP/pstn-7f0a", "") in new stack
Jun 6 15:14:41 DEBUG[8490] chan_sip.c: Checking device state for peer pstn
Jun 6 15:14:41 DEBUG[8490] channel.c: Avoiding initial deadlock for 'SIP/pstn-7f0a'
Jun 6 15:14:41 DEBUG[15988] chan_sip.c: sip_answer(SIP/pstn-7f0a)
Jun 6 15:14:41 DEBUG[8490] channel.c: Avoiding initial deadlock for 'SIP/pstn-7f0a'
Jun 6 15:14:41 VERBOSE[15988] logger.c: We're at 192.168.0.200 port 13248
Jun 6 15:14:41 VERBOSE[15988] logger.c: Adding codec 0x4 (ulaw) to SDP
Jun 6 15:14:41 VERBOSE[15988] logger.c: Adding non-codec 0x1 (telephone-event) to SDP
Jun 6 15:14:41 DEBUG[8490] channel.c: Avoiding initial deadlock for 'SIP/pstn-7f0a'
Jun 6 15:14:41 DEBUG[15989] app_queue.c: Device 'SIP/pstn' changed to state '2' (In use)
Jun 6 15:14:41 VERBOSE[15988] logger.c: Reliably Transmitting (no NAT) to 192.168.0.205:5061:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.0.205:5061;branch=z9hG4bK-82b5d698;received=192.168.0.205
From: "Short CID" <sip:6165550000@192.168.0.200>;tag=f1ce50d13affcad4o1
To: <sip:1111111111@192.168.0.200>;tag=as5d4bec92
Call-ID: 350a8255-2d83a720@192.168.0.205
CSeq: 102 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:1111111111@192.168.0.200>
Content-Type: application/sdp
Content-Length: 216
v=0
o=root 2802 2802 IN IP4 192.168.0.200
s=session
c=IN IP4 192.168.0.200
t=0 0
m=audio 13248 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
---
Jun 6 15:14:41 DEBUG[15988] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #22019
Jun 6 15:14:41 DEBUG[15988] pbx.c: Launching 'Wait'
Jun 6 15:14:41 VERBOSE[15988] logger.c: -- Executing Wait("SIP/pstn-7f0a", "1") in new stack
Jun 6 15:14:41 DEBUG[8490] devicestate.c: Changing state for SIP/pstn - state 2 (In use)
Jun 6 15:14:41 DEBUG[15990] app_queue.c: Device 'SIP/pstn' changed to state '2' (In use)
Jun 6 15:14:41 VERBOSE[8500] logger.c:
<-- SIP read from 192.168.0.205:5061:
ACK sip:1111111111@192.168.0.200 SIP/2.0
Via: SIP/2.0/UDP 192.168.0.205:5061;branch=z9hG4bK-879927c0
From: "Short CID" <sip:6165550000@192.168.0.200>;tag=f1ce50d13affcad4o1
To: <sip:1111111111@192.168.0.200>;tag=as5d4bec92
Call-ID: 350a8255-2d83a720@192.168.0.205
CSeq: 102 ACK
Max-Forwards: 70
Proxy-Authorization: Digest username="pstn",realm="asterisk",nonce="37fdc30d",uri="sip:1111111111@192.168.0.200",algorithm=MD5,response="78ef6acebdc7dc1e9c818bdf8094a357"
Contact: SPA3000 <sip:6165550000@192.168.0.205:5061>
User-Agent: Linksys/SPA3000-3.1.10(GWd)
Content-Length: 0
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 0: ACK sip:1111111111@192.168.0.200 SIP/2.0 (40)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.0.205:5061;branch=z9hG4bK-879927c0 (59)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 2: From: "Short CID" <sip:6165550000@192.168.0.200>;tag=f1ce50d13affcad4o1 (74)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 3: To: <sip:1111111111@192.168.0.200>;tag=as5d4bec92 (49)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 4: Call-ID: 350a8255-2d83a720@192.168.0.205 (40)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 5: CSeq: 102 ACK (13)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 6: Max-Forwards: 70 (16)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 7: Proxy-Authorization: Digest username="pstn",realm="asterisk",nonce="37fdc30d",uri="sip:1111111111@192.168.0.200",algorithm=MD5,response="78ef6acebdc7dc1e9c818bdf8094a357" (170)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 8: Contact: SPA3000 <sip:6165550000@192.168.0.205:5061> (52)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 9: User-Agent: Linksys/SPA3000-3.1.10(GWd) (39)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 10: Content-Length: 0 (17)
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 11: (0)
Jun 6 15:14:41 VERBOSE[8500] logger.c: --- (11 headers 0 lines)Jun 6 15:14:41 VERBOSE[8500] logger.c: --- (11 headers 0 lines)---
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: **** Received ACK (6) - Command in SIP ACK
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #22019
Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Stopping retransmission on '350a8255-2d83a720@192.168.0.205' of Response 102: Match Found
Jun 6 15:14:41 DEBUG[8498] chan_iax2.c: Peer lastms 60, historicms 60, maxms 2000
Jun 6 15:14:42 DEBUG[15988] pbx.c: Launching 'Set'
Jun 6 15:14:42 VERBOSE[15988] logger.c: -- Executing Set("SIP/pstn-7f0a", "TIMEOUT(digit)=3") in new stack
Jun 6 15:14:42 VERBOSE[15988] logger.c: -- Digit timeout set to 3
Jun 6 15:14:42 DEBUG[15988] pbx.c: Launching 'Set'
Jun 6 15:14:42 VERBOSE[15988] logger.c: -- Executing Set("SIP/pstn-7f0a", "TIMEOUT(response)=5") in new stack
Jun 6 15:14:42 VERBOSE[15988] logger.c: -- Response timeout set to 5
Jun 6 15:14:42 DEBUG[15988] pbx.c: Launching 'BackGround'
Jun 6 15:14:42 VERBOSE[15988] logger.c: -- Executing BackGround("SIP/pstn-7f0a", "custom/ivr-main") in new stack
Jun 6 15:14:42 DEBUG[15988] channel.c: Set channel SIP/pstn-7f0a to write format slin
Jun 6 15:14:42 DEBUG[15988] rtp.c: Ooh, format changed from unknown to ulaw
Jun 6 15:14:42 DEBUG[15988] channel.c: Scheduling timer at 160 sample intervals
Jun 6 15:14:42 VERBOSE[15988] logger.c: -- Playing 'custom/ivr-main' (language 'en')
Jun 6 15:14:42 DEBUG[8498] chan_iax2.c: Peer lastms 58, historicms 58, maxms 2000
Jun 6 15:14:43 DEBUG[8498] chan_iax2.c: Allocate call number
Jun 6 15:14:43 DEBUG[8498] chan_iax2.c: Registration created on call 2
Jun 6 15:14:49 DEBUG[9802] manager.c: Manager received command 'Command'
Jun 6 15:14:49 DEBUG[9802] manager.c: Manager received command 'Command'
Jun 6 15:14:49 VERBOSE[8500] logger.c:
etc. etc. - at this point the call has been answered and we are into the IVR, which is where we want to be.
**********************************************************************************************************
THIS IS A CALL THAT DID *NOT* COMPLETE. THE *ONLY* SIGNIFICANT DIFFERENCE IS THE LENGTH OF CALLER ID NAME
**********************************************************************************************************
Jun 6 14:53:29 VERBOSE[8500] logger.c:
<-- SIP read from 192.168.0.205:5061:
INVITE sip:1111111111@192.168.0.200 SIP/2.0
Via: SIP/2.0/UDP 192.168.0.205:5061;branch=z9hG4bK-9b329b78
From: "Grand Rapids M <sip:6165555555@192.168.0.200>;tag=e23e090b1771ef00o1
To: <sip:1111111111@192.168.0.200>
Remote-Party-ID: "Grand Rapids M <sip:6165555555@192.168.0.200>;screen=yes;party=calling
Call-ID: 3215be27-6aba5c94@192.168.0.205
CSeq: 101 INVITE
Max-Forwards: 70
Contact: SPA3000 <sip:6165555555@192.168.0.205:5061>
Expires: 240
User-Agent: Linksys/SPA3000-3.1.10(GWd)
Content-Length: 446
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: x-sipura
Content-Type: application/sdp
v=0
o=- 6007312 6007312 IN IP4 192.168.0.205
s=-
c=IN IP4 192.168.0.205
t=0 0
m=audio 16476 RTP/AVP 0 2 4 8 18 96 97 98 100 101
a=rtpmap:0 PCMU/8000
a=rtpmap:2 G726-32/8000
a=rtpmap:4 G723/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729a/8000
a=rtpmap:96 G726-40/8000
a=rtpmap:97 G726-24/8000
a=rtpmap:98 G726-16/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
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Header 0: INVITE sip:1111111111@192.168.0.200 SIP/2.0 (43)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.0.205:5061;branch=z9hG4bK-9b329b78 (59)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Header 2: From: "Grand Rapids M <sip:6165555555@192.168.0.200>;tag=e23e090b1771ef00o1 (75)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Header 3: To: <sip:1111111111@192.168.0.200> (34)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Header 4: Remote-Party-ID: "Grand Rapids M <sip:6165555555@192.168.0.200>;screen=yes;party=calling (88)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Header 5: Call-ID: 3215be27-6aba5c94@192.168.0.205 (40)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Header 6: CSeq: 101 INVITE (16)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Header 7: Max-Forwards: 70 (16)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Header 8: Contact: SPA3000 <sip:6165555555@192.168.0.205:5061> (52)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Header 9: Expires: 240 (12)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Header 10: User-Agent: Linksys/SPA3000-3.1.10(GWd) (39)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Header 11: Content-Length: 446 (19)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Header 12: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Header 13: Supported: x-sipura (19)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Header 14: Content-Type: application/sdp (29)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Header 15: (0)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Line: v=0 (3)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Line: o=- 6007312 6007312 IN IP4 192.168.0.205 (40)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Line: s=- (3)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Line: c=IN IP4 192.168.0.205 (22)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Line: t=0 0 (5)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Line: m=audio 16476 RTP/AVP 0 2 4 8 18 96 97 98 100 101 (49)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Line: a=rtpmap:2 G726-32/8000 (23)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Line: a=rtpmap:4 G723/8000 (20)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Line: a=rtpmap:18 G729a/8000 (22)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Line: a=rtpmap:96 G726-40/8000 (24)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Line: a=rtpmap:97 G726-24/8000 (24)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Line: a=rtpmap:98 G726-16/8000 (24)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Line: a=rtpmap:100 NSE/8000 (21)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Line: a=fmtp:100 192-193 (18)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Line: a=fmtp:101 0-15 (15)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Line: a=ptime:30 (10)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Line: a=sendrecv (10)
Jun 6 14:53:29 VERBOSE[8500] logger.c: --- (15 headers 20 lines)Jun 6 14:53:29 VERBOSE[8500] logger.c: --- (15 headers 20 lines)---
Jun 6 14:53:29 DEBUG[8500] acl.c: ##### Testing 192.168.0.205 with 192.168.0.0
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Allocating new SIP dialog for 3215be27-6aba5c94@192.168.0.205 - INVITE (With RTP)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Begin: parsing SIP "Supported: x-sipura"
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Found SIP option: -x-sipura-
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Found no match for SIP option: x-sipura (Please file bug report!)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: * SIP extension value: 0 for call 3215be27-6aba5c94@192.168.0.205
Jun 6 14:53:29 VERBOSE[8500] logger.c: Using INVITE request as basis request - 3215be27-6aba5c94@192.168.0.205
Jun 6 14:53:29 VERBOSE[8500] logger.c: Sending to 192.168.0.205 : 5061 (NAT)
Jun 6 14:53:29 WARNING[8500] chan_sip.c: No closing quote found in '"Grand Rapids M <sip:6165555555@192.168.0.200>;tag=e23e090b1771ef00o1'
Jun 6 14:53:29 NOTICE[8500] chan_sip.c: From address missing 'sip:', using it anyway
Jun 6 14:53:29 VERBOSE[8500] logger.c: Found peer 'pstn'
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Setting NAT on RTP to 0
Jun 6 14:53:29 VERBOSE[8500] logger.c: Reliably Transmitting (no NAT) to 192.168.0.205:5061:
SIP/2.0 407 Proxy Authentication Required
Via: SIP/2.0/UDP 192.168.0.205:5061;branch=z9hG4bK-9b329b78;received=192.168.0.205
From: "Grand Rapids M <sip:6165555555@192.168.0.200>;tag=e23e090b1771ef00o1
To: <sip:1111111111@192.168.0.200>;tag=as4ae98eb6
Call-ID: 3215be27-6aba5c94@192.168.0.205
CSeq: 101 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:1111111111@192.168.0.200>
Proxy-Authenticate: Digest realm="asterisk", nonce="36e0d06b"
Content-Length: 0
---
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #21633
Jun 6 14:53:29 VERBOSE[8500] logger.c: Scheduling destruction of call '3215be27-6aba5c94@192.168.0.205' in 15000 ms
Jun 6 14:53:29 VERBOSE[8500] logger.c:
<-- SIP read from 192.168.0.205:5061:
INVITE sip:1111111111@192.168.0.200 SIP/2.0
Via: SIP/2.0/UDP 192.168.0.205:5061;branch=z9hG4bK-9b329b78
From: "Grand Rapids M <sip:6165555555@192.168.0.200>;tag=e23e090b1771ef00o1
To: <sip:1111111111@192.168.0.200>
Remote-Party-ID: "Grand Rapids M <sip:6165555555@192.168.0.200>;screen=yes;party=calling
Call-ID: 3215be27-6aba5c94@192.168.0.205
CSeq: 101 INVITE
Max-Forwards: 70
Contact: SPA3000 <sip:6165555555@192.168.0.205:5061>
Expires: 240
User-Agent: Linksys/SPA3000-3.1.10(GWd)
Content-Length: 446
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: x-sipura
Content-Type: application/sdp
v=0
o=- 6007312 6007312 IN IP4 192.168.0.205
s=-
c=IN IP4 192.168.0.205
t=0 0
m=audio 16476 RTP/AVP 0 2 4 8 18 96 97 98 100 101
a=rtpmap:0 PCMU/8000
a=rtpmap:2 G726-32/8000
a=rtpmap:4 G723/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729a/8000
a=rtpmap:96 G726-40/8000
a=rtpmap:97 G726-24/8000
a=rtpmap:98 G726-16/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
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Header 0: INVITE sip:1111111111@192.168.0.200 SIP/2.0 (43)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.0.205:5061;branch=z9hG4bK-9b329b78 (59)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Header 2: From: "Grand Rapids M <sip:6165555555@192.168.0.200>;tag=e23e090b1771ef00o1 (75)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Header 3: To: <sip:1111111111@192.168.0.200> (34)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Header 4: Remote-Party-ID: "Grand Rapids M <sip:6165555555@192.168.0.200>;screen=yes;party=calling (88)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Header 5: Call-ID: 3215be27-6aba5c94@192.168.0.205 (40)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Header 6: CSeq: 101 INVITE (16)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Header 7: Max-Forwards: 70 (16)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Header 8: Contact: SPA3000 <sip:6165555555@192.168.0.205:5061> (52)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Header 9: Expires: 240 (12)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Header 10: User-Agent: Linksys/SPA3000-3.1.10(GWd) (39)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Header 11: Content-Length: 446 (19)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Header 12: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Header 13: Supported: x-sipura (19)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Header 14: Content-Type: application/sdp (29)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Header 15: (0)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Line: v=0 (3)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Line: o=- 6007312 6007312 IN IP4 192.168.0.205 (40)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Line: s=- (3)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Line: c=IN IP4 192.168.0.205 (22)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Line: t=0 0 (5)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Line: m=audio 16476 RTP/AVP 0 2 4 8 18 96 97 98 100 101 (49)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Line: a=rtpmap:2 G726-32/8000 (23)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Line: a=rtpmap:4 G723/8000 (20)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Line: a=rtpmap:18 G729a/8000 (22)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Line: a=rtpmap:96 G726-40/8000 (24)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Line: a=rtpmap:97 G726-24/8000 (24)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Line: a=rtpmap:98 G726-16/8000 (24)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Line: a=rtpmap:100 NSE/8000 (21)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Line: a=fmtp:100 192-193 (18)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Line: a=fmtp:101 0-15 (15)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Line: a=ptime:30 (10)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Line: a=sendrecv (10)
Jun 6 14:53:29 VERBOSE[8500] logger.c: --- (15 headers 20 lines)Jun 6 14:53:29 VERBOSE[8500] logger.c: --- (15 headers 20 lines)---
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Ignoring SIP message because of retransmit (INVITE Seqno 101, ours 101)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Begin: parsing SIP "Supported: x-sipura"
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Found SIP option: -x-sipura-
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Found no match for SIP option: x-sipura (Please file bug report!)
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: * SIP extension value: 0 for call 3215be27-6aba5c94@192.168.0.205
Jun 6 14:53:29 VERBOSE[8500] logger.c: Ignoring this INVITE request
Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Got a SIP re-invite for call 3215be27-6aba5c94@192.168.0.205
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: SIP TIMER: Rescheduling retransmission #21633 (1) SIP/2.0 - 1
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: ** SIP timers: Rescheduling retransmission 2 to 1000 ms (t1 500 ms (Retrans id #21633))
Jun 6 14:53:30 VERBOSE[8500] logger.c: Retransmitting #1 (no NAT) to 192.168.0.205:5061:
SIP/2.0 407 Proxy Authentication Required
Via: SIP/2.0/UDP 192.168.0.205:5061;branch=z9hG4bK-9b329b78;received=192.168.0.205
From: "Grand Rapids M <sip:6165555555@192.168.0.200>;tag=e23e090b1771ef00o1
To: <sip:1111111111@192.168.0.200>;tag=as4ae98eb6
Call-ID: 3215be27-6aba5c94@192.168.0.205
CSeq: 101 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:1111111111@192.168.0.200>
Proxy-Authenticate: Digest realm="asterisk", nonce="36e0d06b"
Content-Length: 0
---
Jun 6 14:53:30 VERBOSE[8500] logger.c: Destroying call '4221dd196c9e27523811f955423fd796@67.15.199.23'
Jun 6 14:53:30 VERBOSE[8500] logger.c:
<-- SIP read from 192.168.0.205:5061:
INVITE sip:1111111111@192.168.0.200 SIP/2.0
Via: SIP/2.0/UDP 192.168.0.205:5061;branch=z9hG4bK-9b329b78
From: "Grand Rapids M <sip:6165555555@192.168.0.200>;tag=e23e090b1771ef00o1
To: <sip:1111111111@192.168.0.200>
Remote-Party-ID: "Grand Rapids M <sip:6165555555@192.168.0.200>;screen=yes;party=calling
Call-ID: 3215be27-6aba5c94@192.168.0.205
CSeq: 101 INVITE
Max-Forwards: 70
Contact: SPA3000 <sip:6165555555@192.168.0.205:5061>
Expires: 240
User-Agent: Linksys/SPA3000-3.1.10(GWd)
Content-Length: 446
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: x-sipura
Content-Type: application/sdp
v=0
o=- 6007312 6007312 IN IP4 192.168.0.205
s=-
c=IN IP4 192.168.0.205
t=0 0
m=audio 16476 RTP/AVP 0 2 4 8 18 96 97 98 100 101
a=rtpmap:0 PCMU/8000
a=rtpmap:2 G726-32/8000
a=rtpmap:4 G723/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729a/8000
a=rtpmap:96 G726-40/8000
a=rtpmap:97 G726-24/8000
a=rtpmap:98 G726-16/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
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Header 0: INVITE sip:1111111111@192.168.0.200 SIP/2.0 (43)
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.0.205:5061;branch=z9hG4bK-9b329b78 (59)
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Header 2: From: "Grand Rapids M <sip:6165555555@192.168.0.200>;tag=e23e090b1771ef00o1 (75)
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Header 3: To: <sip:1111111111@192.168.0.200> (34)
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Header 4: Remote-Party-ID: "Grand Rapids M <sip:6165555555@192.168.0.200>;screen=yes;party=calling (88)
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Header 5: Call-ID: 3215be27-6aba5c94@192.168.0.205 (40)
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Header 6: CSeq: 101 INVITE (16)
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Header 7: Max-Forwards: 70 (16)
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Header 8: Contact: SPA3000 <sip:6165555555@192.168.0.205:5061> (52)
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Header 9: Expires: 240 (12)
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Header 10: User-Agent: Linksys/SPA3000-3.1.10(GWd) (39)
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Header 11: Content-Length: 446 (19)
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Header 12: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61)
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Header 13: Supported: x-sipura (19)
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Header 14: Content-Type: application/sdp (29)
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Header 15: (0)
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Line: v=0 (3)
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Line: o=- 6007312 6007312 IN IP4 192.168.0.205 (40)
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Line: s=- (3)
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Line: c=IN IP4 192.168.0.205 (22)
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Line: t=0 0 (5)
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Line: m=audio 16476 RTP/AVP 0 2 4 8 18 96 97 98 100 101 (49)
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20)
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Line: a=rtpmap:2 G726-32/8000 (23)
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Line: a=rtpmap:4 G723/8000 (20)
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20)
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Line: a=rtpmap:18 G729a/8000 (22)
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Line: a=rtpmap:96 G726-40/8000 (24)
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Line: a=rtpmap:97 G726-24/8000 (24)
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Line: a=rtpmap:98 G726-16/8000 (24)
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Line: a=rtpmap:100 NSE/8000 (21)
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Line: a=fmtp:100 192-193 (18)
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33)
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Line: a=fmtp:101 0-15 (15)
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Line: a=ptime:30 (10)
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Line: a=sendrecv (10)
Jun 6 14:53:30 VERBOSE[8500] logger.c: --- (15 headers 20 lines)Jun 6 14:53:30 VERBOSE[8500] logger.c: --- (15 headers 20 lines)---
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Ignoring SIP message because of retransmit (INVITE Seqno 101, ours 101)
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Begin: parsing SIP "Supported: x-sipura"
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Found SIP option: -x-sipura-
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Found no match for SIP option: x-sipura (Please file bug report!)
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: * SIP extension value: 0 for call 3215be27-6aba5c94@192.168.0.205
Jun 6 14:53:30 VERBOSE[8500] logger.c: Ignoring this INVITE request
Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Got a SIP re-invite for call 3215be27-6aba5c94@192.168.0.205
Jun 6 14:53:31 DEBUG[8500] chan_sip.c: SIP TIMER: Rescheduling retransmission #21633 (2) SIP/2.0 - 1
Jun 6 14:53:31 DEBUG[8500] chan_sip.c: ** SIP timers: Rescheduling retransmission 3 to 2000 ms (t1 500 ms (Retrans id #21633))
Jun 6 14:53:31 VERBOSE[8500] logger.c: Retransmitting #2 (no NAT) to 192.168.0.205:5061:
SIP/2.0 407 Proxy Authentication Required
Via: SIP/2.0/UDP 192.168.0.205:5061;branch=z9hG4bK-9b329b78;received=192.168.0.205
From: "Grand Rapids M <sip:6165555555@192.168.0.200>;tag=e23e090b1771ef00o1
To: <sip:1111111111@192.168.0.200>;tag=as4ae98eb6
Call-ID: 3215be27-6aba5c94@192.168.0.205
CSeq: 101 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:1111111111@192.168.0.200>
Proxy-Authenticate: Digest realm="asterisk", nonce="36e0d06b"
Content-Length: 0
---
Jun 6 14:53:31 VERBOSE[8500] logger.c: Destroying call 'aed89cee-6cac8b75@192.168.15.100'
Jun 6 14:53:32 VERBOSE[8500] logger.c:
<-- SIP read from 192.168.0.205:5061:
INVITE sip:1111111111@192.168.0.200 SIP/2.0
Via: SIP/2.0/UDP 192.168.0.205:5061;branch=z9hG4bK-9b329b78
From: "Grand Rapids M <sip:6165555555@192.168.0.200>;tag=e23e090b1771ef00o1
To: <sip:1111111111@192.168.0.200>
Remote-Party-ID: "Grand Rapids M <sip:6165555555@192.168.0.200>;screen=yes;party=calling
Call-ID: 3215be27-6aba5c94@192.168.0.205
CSeq: 101 INVITE
Max-Forwards: 70
Contact: SPA3000 <sip:6165555555@192.168.0.205:5061>
Expires: 240
User-Agent: Linksys/SPA3000-3.1.10(GWd)
Content-Length: 446
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: x-sipura
Content-Type: application/sdp
v=0
o=- 6007312 6007312 IN IP4 192.168.0.205
s=-
c=IN IP4 192.168.0.205
t=0 0
m=audio 16476 RTP/AVP 0 2 4 8 18 96 97 98 100 101
a=rtpmap:0 PCMU/8000
a=rtpmap:2 G726-32/8000
a=rtpmap:4 G723/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729a/8000
a=rtpmap:96 G726-40/8000
a=rtpmap:97 G726-24/8000
a=rtpmap:98 G726-16/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
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Header 0: INVITE sip:1111111111@192.168.0.200 SIP/2.0 (43)
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.0.205:5061;branch=z9hG4bK-9b329b78 (59)
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Header 2: From: "Grand Rapids M <sip:6165555555@192.168.0.200>;tag=e23e090b1771ef00o1 (75)
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Header 3: To: <sip:1111111111@192.168.0.200> (34)
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Header 4: Remote-Party-ID: "Grand Rapids M <sip:6165555555@192.168.0.200>;screen=yes;party=calling (88)
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Header 5: Call-ID: 3215be27-6aba5c94@192.168.0.205 (40)
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Header 6: CSeq: 101 INVITE (16)
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Header 7: Max-Forwards: 70 (16)
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Header 8: Contact: SPA3000 <sip:6165555555@192.168.0.205:5061> (52)
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Header 9: Expires: 240 (12)
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Header 10: User-Agent: Linksys/SPA3000-3.1.10(GWd) (39)
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Header 11: Content-Length: 446 (19)
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Header 12: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61)
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Header 13: Supported: x-sipura (19)
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Header 14: Content-Type: application/sdp (29)
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Header 15: (0)
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Line: v=0 (3)
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Line: o=- 6007312 6007312 IN IP4 192.168.0.205 (40)
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Line: s=- (3)
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Line: c=IN IP4 192.168.0.205 (22)
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Line: t=0 0 (5)
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Line: m=audio 16476 RTP/AVP 0 2 4 8 18 96 97 98 100 101 (49)
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20)
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Line: a=rtpmap:2 G726-32/8000 (23)
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Line: a=rtpmap:4 G723/8000 (20)
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20)
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Line: a=rtpmap:18 G729a/8000 (22)
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Line: a=rtpmap:96 G726-40/8000 (24)
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Line: a=rtpmap:97 G726-24/8000 (24)
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Line: a=rtpmap:98 G726-16/8000 (24)
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Line: a=rtpmap:100 NSE/8000 (21)
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Line: a=fmtp:100 192-193 (18)
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33)
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Line: a=fmtp:101 0-15 (15)
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Line: a=ptime:30 (10)
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Line: a=sendrecv (10)
Jun 6 14:53:32 VERBOSE[8500] logger.c: --- (15 headers 20 lines)Jun 6 14:53:32 VERBOSE[8500] logger.c: --- (15 headers 20 lines)---
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Ignoring SIP message because of retransmit (INVITE Seqno 101, ours 101)
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Begin: parsing SIP "Supported: x-sipura"
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Found SIP option: -x-sipura-
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Found no match for SIP option: x-sipura (Please file bug report!)
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: * SIP extension value: 0 for call 3215be27-6aba5c94@192.168.0.205
Jun 6 14:53:32 VERBOSE[8500] logger.c: Ignoring this INVITE request
Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Got a SIP re-invite for call 3215be27-6aba5c94@192.168.0.205
Jun 6 14:53:33 DEBUG[8500] chan_sip.c: SIP TIMER: Rescheduling retransmission #21633 (3) SIP/2.0 - 1
Jun 6 14:53:33 DEBUG[8500] chan_sip.c: ** SIP timers: Rescheduling retransmission 4 to 4000 ms (t1 500 ms (Retrans id #21633))
Jun 6 14:53:33 VERBOSE[8500] logger.c: Retransmitting #3 (no NAT) to 192.168.0.205:5061:
SIP/2.0 407 Proxy Authentication Required
Via: SIP/2.0/UDP 192.168.0.205:5061;branch=z9hG4bK-9b329b78;received=192.168.0.205
From: "Grand Rapids M <sip:6165555555@192.168.0.200>;tag=e23e090b1771ef00o1
To: <sip:1111111111@192.168.0.200>;tag=as4ae98eb6
Call-ID: 3215be27-6aba5c94@192.168.0.205
CSeq: 101 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:1111111111@192.168.0.200>
Proxy-Authenticate: Digest realm="asterisk", nonce="36e0d06b"
Content-Length: 0
---
Jun 6 14:53:36 VERBOSE[8500] logger.c:
<-- SIP read from 192.168.0.205:5061:
INVITE sip:1111111111@192.168.0.200 SIP/2.0
Via: SIP/2.0/UDP 192.168.0.205:5061;branch=z9hG4bK-9b329b78
From: "Grand Rapids M <sip:6165555555@192.168.0.200>;tag=e23e090b1771ef00o1
To: <sip:1111111111@192.168.0.200>
Remote-Party-ID: "Grand Rapids M <sip:6165555555@192.168.0.200>;screen=yes;party=calling
Call-ID: 3215be27-6aba5c94@192.168.0.205
CSeq: 101 INVITE
Max-Forwards: 70
Contact: SPA3000 <sip:6165555555@192.168.0.205:5061>
Expires: 240
User-Agent: Linksys/SPA3000-3.1.10(GWd)
Content-Length: 446
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: x-sipura
Content-Type: application/sdp
v=0
o=- 6007312 6007312 IN IP4 192.168.0.205
s=-
c=IN IP4 192.168.0.205
t=0 0
m=audio 16476 RTP/AVP 0 2 4 8 18 96 97 98 100 101
a=rtpmap:0 PCMU/8000
a=rtpmap:2 G726-32/8000
a=rtpmap:4 G723/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729a/8000
a=rtpmap:96 G726-40/8000
a=rtpmap:97 G726-24/8000
a=rtpmap:98 G726-16/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
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Header 0: INVITE sip:1111111111@192.168.0.200 SIP/2.0 (43)
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.0.205:5061;branch=z9hG4bK-9b329b78 (59)
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Header 2: From: "Grand Rapids M <sip:6165555555@192.168.0.200>;tag=e23e090b1771ef00o1 (75)
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Header 3: To: <sip:1111111111@192.168.0.200> (34)
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Header 4: Remote-Party-ID: "Grand Rapids M <sip:6165555555@192.168.0.200>;screen=yes;party=calling (88)
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Header 5: Call-ID: 3215be27-6aba5c94@192.168.0.205 (40)
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Header 6: CSeq: 101 INVITE (16)
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Header 7: Max-Forwards: 70 (16)
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Header 8: Contact: SPA3000 <sip:6165555555@192.168.0.205:5061> (52)
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Header 9: Expires: 240 (12)
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Header 10: User-Agent: Linksys/SPA3000-3.1.10(GWd) (39)
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Header 11: Content-Length: 446 (19)
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Header 12: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61)
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Header 13: Supported: x-sipura (19)
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Header 14: Content-Type: application/sdp (29)
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Header 15: (0)
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Line: v=0 (3)
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Line: o=- 6007312 6007312 IN IP4 192.168.0.205 (40)
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Line: s=- (3)
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Line: c=IN IP4 192.168.0.205 (22)
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Line: t=0 0 (5)
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Line: m=audio 16476 RTP/AVP 0 2 4 8 18 96 97 98 100 101 (49)
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20)
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Line: a=rtpmap:2 G726-32/8000 (23)
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Line: a=rtpmap:4 G723/8000 (20)
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20)
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Line: a=rtpmap:18 G729a/8000 (22)
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Line: a=rtpmap:96 G726-40/8000 (24)
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Line: a=rtpmap:97 G726-24/8000 (24)
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Line: a=rtpmap:98 G726-16/8000 (24)
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Line: a=rtpmap:100 NSE/8000 (21)
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Line: a=fmtp:100 192-193 (18)
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33)
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Line: a=fmtp:101 0-15 (15)
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Line: a=ptime:30 (10)
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Line: a=sendrecv (10)
Jun 6 14:53:36 VERBOSE[8500] logger.c: --- (15 headers 20 lines)Jun 6 14:53:36 VERBOSE[8500] logger.c: --- (15 headers 20 lines)---
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Ignoring SIP message because of retransmit (INVITE Seqno 101, ours 101)
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Begin: parsing SIP "Supported: x-sipura"
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Found SIP option: -x-sipura-
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Found no match for SIP option: x-sipura (Please file bug report!)
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: * SIP extension value: 0 for call 3215be27-6aba5c94@192.168.0.205
Jun 6 14:53:36 VERBOSE[8500] logger.c: Ignoring this INVITE request
Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Got a SIP re-invite for call 3215be27-6aba5c94@192.168.0.205
Jun 6 14:53:37 DEBUG[8500] chan_sip.c: SIP TIMER: Rescheduling retransmission #21633 (4) SIP/2.0 - 1
Jun 6 14:53:37 DEBUG[8500] chan_sip.c: ** SIP timers: Rescheduling retransmission 5 to 4000 ms (t1 500 ms (Retrans id #21633))
Jun 6 14:53:37 VERBOSE[8500] logger.c: Retransmitting #4 (no NAT) to 192.168.0.205:5061:
SIP/2.0 407 Proxy Authentication Required
Via: SIP/2.0/UDP 192.168.0.205:5061;branch=z9hG4bK-9b329b78;received=192.168.0.205
From: "Grand Rapids M <sip:6165555555@192.168.0.200>;tag=e23e090b1771ef00o1
To: <sip:1111111111@192.168.0.200>;tag=as4ae98eb6
Call-ID: 3215be27-6aba5c94@192.168.0.205
CSeq: 101 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:1111111111@192.168.0.200>
Proxy-Authenticate: Digest realm="asterisk", nonce="36e0d06b"
Content-Length: 0
---
Jun 6 14:53:38 VERBOSE[8500] logger.c: --- (0 headers 0 lines)Jun 6 14:53:38 VERBOSE[8500] logger.c: --- (0 headers 0 lines) Nat keepalive Jun 6 14:53:38 VERBOSE[8500] logger.c: --- (0 headers 0 lines) Nat keepalive ---
Jun 6 14:53:40 DEBUG[8498] chan_iax2.c: Peer lastms 51, historicms 51, maxms 2000
Jun 6 14:53:41 DEBUG[8500] chan_sip.c: SIP TIMER: Rescheduling retransmission #21633 (5) SIP/2.0 - 1
Jun 6 14:53:41 DEBUG[8500] chan_sip.c: ** SIP timers: Rescheduling retransmission 6 to 4000 ms (t1 500 ms (Retrans id #21633))
Jun 6 14:53:41 VERBOSE[8500] logger.c: Retransmitting #5 (no NAT) to 192.168.0.205:5061:
SIP/2.0 407 Proxy Authentication Required
Via: SIP/2.0/UDP 192.168.0.205:5061;branch=z9hG4bK-9b329b78;received=192.168.0.205
From: "Grand Rapids M <sip:6165555555@192.168.0.200>;tag=e23e090b1771ef00o1
To: <sip:1111111111@192.168.0.200>;tag=as4ae98eb6
Call-ID: 3215be27-6aba5c94@192.168.0.205
CSeq: 101 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:1111111111@192.168.0.200>
Proxy-Authenticate: Digest realm="asterisk", nonce="36e0d06b"
Content-Length: 0
<-- SIP read from 192.168.0.205:5061:
INVITE sip:1111111111@192.168.0.200 SIP/2.0
Via: SIP/2.0/UDP 192.168.0.205:5061;branch=z9hG4bK-9b329b78
From: "Grand Rapids M <sip:6165555555@192.168.0.200>;tag=e23e090b1771ef00o1
To: <sip:1111111111@192.168.0.200>
Remote-Party-ID: "Grand Rapids M <sip:6165555555@192.168.0.200>;screen=yes;party=calling
Call-ID: 3215be27-6aba5c94@192.168.0.205
CSeq: 101 INVITE
Max-Forwards: 70
Contact: SPA3000 <sip:6165555555@192.168.0.205:5061>
Expires: 240
User-Agent: Linksys/SPA3000-3.1.10(GWd)
Content-Length: 446
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: x-sipura
Content-Type: application/sdp
v=0
o=- 6007312 6007312 IN IP4 192.168.0.205
s=-
c=IN IP4 192.168.0.205
t=0 0
m=audio 16476 RTP/AVP 0 2 4 8 18 96 97 98 100 101
a=rtpmap:0 PCMU/8000
a=rtpmap:2 G726-32/8000
a=rtpmap:4 G723/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729a/8000
a=rtpmap:96 G726-40/8000
a=rtpmap:97 G726-24/8000
a=rtpmap:98 G726-16/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
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Header 0: INVITE sip:1111111111@192.168.0.200 SIP/2.0 (43)
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.0.205:5061;branch=z9hG4bK-9b329b78 (59)
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Header 2: From: "Grand Rapids M <sip:6165555555@192.168.0.200>;tag=e23e090b1771ef00o1 (75)
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Header 3: To: <sip:1111111111@192.168.0.200> (34)
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Header 4: Remote-Party-ID: "Grand Rapids M <sip:6165555555@192.168.0.200>;screen=yes;party=calling (88)
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Header 5: Call-ID: 3215be27-6aba5c94@192.168.0.205 (40)
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Header 6: CSeq: 101 INVITE (16)
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Header 7: Max-Forwards: 70 (16)
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Header 8: Contact: SPA3000 <sip:6165555555@192.168.0.205:5061> (52)
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Header 9: Expires: 240 (12)
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Header 10: User-Agent: Linksys/SPA3000-3.1.10(GWd) (39)
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Header 11: Content-Length: 446 (19)
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Header 12: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61)
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Header 13: Supported: x-sipura (19)
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Header 14: Content-Type: application/sdp (29)
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Header 15: (0)
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Line: v=0 (3)
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Line: o=- 6007312 6007312 IN IP4 192.168.0.205 (40)
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Line: s=- (3)
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Line: c=IN IP4 192.168.0.205 (22)
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Line: t=0 0 (5)
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Line: m=audio 16476 RTP/AVP 0 2 4 8 18 96 97 98 100 101 (49)
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20)
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Line: a=rtpmap:2 G726-32/8000 (23)
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Line: a=rtpmap:4 G723/8000 (20)
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20)
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Line: a=rtpmap:18 G729a/8000 (22)
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Line: a=rtpmap:96 G726-40/8000 (24)
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Line: a=rtpmap:97 G726-24/8000 (24)
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Line: a=rtpmap:98 G726-16/8000 (24)
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Line: a=rtpmap:100 NSE/8000 (21)
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Line: a=fmtp:100 192-193 (18)
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33)
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Line: a=fmtp:101 0-15 (15)
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Line: a=ptime:30 (10)
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Line: a=sendrecv (10)
Jun 6 14:53:44 VERBOSE[8500] logger.c: --- (15 headers 20 lines)Jun 6 14:53:44 VERBOSE[8500] logger.c: --- (15 headers 20 lines)---
Jun 6 14:53:44 DEBUG[8500] acl.c: ##### Testing 192.168.0.205 with 192.168.0.0
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Allocating new SIP dialog for 3215be27-6aba5c94@192.168.0.205 - INVITE (With RTP)
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Begin: parsing SIP "Supported: x-sipura"
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Found SIP option: -x-sipura-
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Found no match for SIP option: x-sipura (Please file bug report!)
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: * SIP extension value: 0 for call 3215be27-6aba5c94@192.168.0.205
Jun 6 14:53:44 VERBOSE[8500] logger.c: Using INVITE request as basis request - 3215be27-6aba5c94@192.168.0.205
Jun 6 14:53:44 VERBOSE[8500] logger.c: Sending to 192.168.0.205 : 5061 (NAT)
Jun 6 14:53:44 WARNING[8500] chan_sip.c: No closing quote found in '"Grand Rapids M <sip:6165555555@192.168.0.200>;tag=e23e090b1771ef00o1'
Jun 6 14:53:44 NOTICE[8500] chan_sip.c: From address missing 'sip:', using it anyway
Jun 6 14:53:44 VERBOSE[8500] logger.c: Found peer 'pstn'
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Setting NAT on RTP to 0
Jun 6 14:53:44 VERBOSE[8500] logger.c: Reliably Transmitting (no NAT) to 192.168.0.205:5061:
SIP/2.0 407 Proxy Authentication Required
Via: SIP/2.0/UDP 192.168.0.205:5061;branch=z9hG4bK-9b329b78;received=192.168.0.205
From: "Grand Rapids M <sip:6165555555@192.168.0.200>;tag=e23e090b1771ef00o1
To: <sip:1111111111@192.168.0.200>;tag=as4a2d2beb
Call-ID: 3215be27-6aba5c94@192.168.0.205
CSeq: 101 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:1111111111@192.168.0.200>
Proxy-Authenticate: Digest realm="asterisk", nonce="6dd53cbc"
Content-Length: 0
---
Jun 6 14:53:44 DEBUG[8500] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #21638
Jun 6 14:53:44 VERBOSE[8500] logger.c: Scheduling destruction of call '3215be27-6aba5c94@192.168.0.205' in 15000 ms
Jun 6 14:53:45 DEBUG[8500] chan_sip.c: SIP TIMER: Rescheduling retransmission #21638 (1) SIP/2.0 - 1
Jun 6 14:53:45 DEBUG[8500] chan_sip.c: ** SIP timers: Rescheduling retransmission 2 to 1000 ms (t1 500 ms (Retrans id #21638))
Jun 6 14:53:45 VERBOSE[8500] logger.c: Retransmitting #1 (no NAT) to 192.168.0.205:5061:
SIP/2.0 407 Proxy Authentication Required
Via: SIP/2.0/UDP 192.168.0.205:5061;branch=z9hG4bK-9b329b78;received=192.168.0.205
From: "Grand Rapids M <sip:6165555555@192.168.0.200>;tag=e23e090b1771ef00o1
To: <sip:1111111111@192.168.0.200>;tag=as4a2d2beb
Call-ID: 3215be27-6aba5c94@192.168.0.205
CSeq: 101 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:1111111111@192.168.0.200>
Proxy-Authenticate: Digest realm="asterisk", nonce="6dd53cbc"
Content-Length: 0
---
Jun 6 14:53:46 DEBUG[8500] chan_sip.c: SIP TIMER: Rescheduling retransmission #21638 (2) SIP/2.0 - 1
Jun 6 14:53:46 DEBUG[8500] chan_sip.c: ** SIP timers: Rescheduling retransmission 3 to 2000 ms (t1 500 ms (Retrans id #21638))
Jun 6 14:53:46 VERBOSE[8500] logger.c: Retransmitting #2 (no NAT) to 192.168.0.205:5061:
SIP/2.0 407 Proxy Authentication Required
Via: SIP/2.0/UDP 192.168.0.205:5061;branch=z9hG4bK-9b329b78;received=192.168.0.205
From: "Grand Rapids M <sip:6165555555@192.168.0.200>;tag=e23e090b1771ef00o1
To: <sip:1111111111@192.168.0.200>;tag=as4a2d2beb
Call-ID: 3215be27-6aba5c94@192.168.0.205
CSeq: 101 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:1111111111@192.168.0.200>
Proxy-Authenticate: Digest realm="asterisk", nonce="6dd53cbc"
Content-Length: 0
---
Jun 6 14:53:56 DEBUG[8500] chan_sip.c: SIP TIMER: Rescheduling retransmission #21638 (5) SIP/2.0 - 1
Jun 6 14:53:56 DEBUG[8500] chan_sip.c: ** SIP timers: Rescheduling retransmission 6 to 4000 ms (t1 500 ms (Retrans id #21638))
Jun 6 14:53:56 VERBOSE[8500] logger.c: Retransmitting #5 (no NAT) to 192.168.0.205:5061:
SIP/2.0 407 Proxy Authentication Required
Via: SIP/2.0/UDP 192.168.0.205:5061;branch=z9hG4bK-9b329b78;received=192.168.0.205
From: "Grand Rapids M <sip:6165555555@192.168.0.200>;tag=e23e090b1771ef00o1
To: <sip:1111111111@192.168.0.200>;tag=as4a2d2beb
Call-ID: 3215be27-6aba5c94@192.168.0.205
CSeq: 101 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:1111111111@192.168.0.200>
Proxy-Authenticate: Digest realm="asterisk", nonce="6dd53cbc"
Content-Length: 0
<-- SIP read from 192.168.0.205:5061:
INVITE sip:1111111111@192.168.0.200 SIP/2.0
Via: SIP/2.0/UDP 192.168.0.205:5061;branch=z9hG4bK-9b329b78
From: "Grand Rapids M <sip:6165555555@192.168.0.200>;tag=e23e090b1771ef00o1
To: <sip:1111111111@192.168.0.200>
Remote-Party-ID: "Grand Rapids M <sip:6165555555@192.168.0.200>;screen=yes;party=calling
Call-ID: 3215be27-6aba5c94@192.168.0.205
CSeq: 101 INVITE
Max-Forwards: 70
Contact: SPA3000 <sip:6165555555@192.168.0.205:5061>
Expires: 240
User-Agent: Linksys/SPA3000-3.1.10(GWd)
Content-Length: 446
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: x-sipura
Content-Type: application/sdp
v=0
o=- 6007312 6007312 IN IP4 192.168.0.205
s=-
c=IN IP4 192.168.0.205
t=0 0
m=audio 16476 RTP/AVP 0 2 4 8 18 96 97 98 100 101
a=rtpmap:0 PCMU/8000
a=rtpmap:2 G726-32/8000
a=rtpmap:4 G723/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729a/8000
a=rtpmap:96 G726-40/8000
a=rtpmap:97 G726-24/8000
a=rtpmap:98 G726-16/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
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Header 0: INVITE sip:1111111111@192.168.0.200 SIP/2.0 (43)
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.0.205:5061;branch=z9hG4bK-9b329b78 (59)
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Header 2: From: "Grand Rapids M <sip:6165555555@192.168.0.200>;tag=e23e090b1771ef00o1 (75)
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Header 3: To: <sip:1111111111@192.168.0.200> (34)
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Header 4: Remote-Party-ID: "Grand Rapids M <sip:6165555555@192.168.0.200>;screen=yes;party=calling (88)
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Header 5: Call-ID: 3215be27-6aba5c94@192.168.0.205 (40)
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Header 6: CSeq: 101 INVITE (16)
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Header 7: Max-Forwards: 70 (16)
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Header 8: Contact: SPA3000 <sip:6165555555@192.168.0.205:5061> (52)
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Header 9: Expires: 240 (12)
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Header 10: User-Agent: Linksys/SPA3000-3.1.10(GWd) (39)
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Header 11: Content-Length: 446 (19)
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Header 12: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61)
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Header 13: Supported: x-sipura (19)
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Header 14: Content-Type: application/sdp (29)
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Header 15: (0)
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Line: v=0 (3)
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Line: o=- 6007312 6007312 IN IP4 192.168.0.205 (40)
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Line: s=- (3)
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Line: c=IN IP4 192.168.0.205 (22)
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Line: t=0 0 (5)
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Line: m=audio 16476 RTP/AVP 0 2 4 8 18 96 97 98 100 101 (49)
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20)
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Line: a=rtpmap:2 G726-32/8000 (23)
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Line: a=rtpmap:4 G723/8000 (20)
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20)
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Line: a=rtpmap:18 G729a/8000 (22)
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Line: a=rtpmap:96 G726-40/8000 (24)
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Line: a=rtpmap:97 G726-24/8000 (24)
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Line: a=rtpmap:98 G726-16/8000 (24)
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Line: a=rtpmap:100 NSE/8000 (21)
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Line: a=fmtp:100 192-193 (18)
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33)
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Line: a=fmtp:101 0-15 (15)
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Line: a=ptime:30 (10)
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Line: a=sendrecv (10)
Jun 6 14:54:00 VERBOSE[8500] logger.c: --- (15 headers 20 lines)Jun 6 14:54:00 VERBOSE[8500] logger.c: --- (15 headers 20 lines)---
Jun 6 14:54:00 DEBUG[8500] acl.c: ##### Testing 192.168.0.205 with 192.168.0.0
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Allocating new SIP dialog for 3215be27-6aba5c94@192.168.0.205 - INVITE (With RTP)
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Begin: parsing SIP "Supported: x-sipura"
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Found SIP option: -x-sipura-
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Found no match for SIP option: x-sipura (Please file bug report!)
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: * SIP extension value: 0 for call 3215be27-6aba5c94@192.168.0.205
Jun 6 14:54:00 VERBOSE[8500] logger.c: Using INVITE request as basis request - 3215be27-6aba5c94@192.168.0.205
Jun 6 14:54:00 VERBOSE[8500] logger.c: Sending to 192.168.0.205 : 5061 (NAT)
Jun 6 14:54:00 WARNING[8500] chan_sip.c: No closing quote found in '"Grand Rapids M <sip:6165555555@192.168.0.200>;tag=e23e090b1771ef00o1'
Jun 6 14:54:00 NOTICE[8500] chan_sip.c: From address missing 'sip:', using it anyway
Jun 6 14:54:00 VERBOSE[8500] logger.c: Found peer 'pstn'
Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Setting NAT on RTP to 0
Jun 6 14:54:00 VERBOSE[8500] logger.c: Reliably Transmitting (no NAT) to 192.168.0.205:5061:
SIP/2.0 407 Proxy Authentication Required
Via: SIP/2.0/UDP 192.168.0.205:5061;branch=z9hG4bK-9b329b78;received=192.168.0.205
From: "Grand Rapids M <sip:6165555555@192.168.0.200>;tag=e23e090b1771ef00o1
To: <sip:1111111111@192.168.0.200>;tag=as77e15e96
Call-ID: 3215be27-6aba5c94@192.168.0.205
CSeq: 101 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:1111111111@192.168.0.200>
Proxy-Authenticate: Digest realm="asterisk", nonce="38f45611"
Content-Length: 0
---
Jun 6 14:54:01 DEBUG[8500] chan_sip.c: SIP TIMER: Rescheduling retransmission #21652 (1) SIP/2.0 - 1
Jun 6 14:54:01 DEBUG[8500] chan_sip.c: ** SIP timers: Rescheduling retransmission 2 to 1000 ms (t1 500 ms (Retrans id #21652))
Jun 6 14:54:01 VERBOSE[8500] logger.c: Retransmitting #1 (no NAT) to 192.168.0.205:5061:
SIP/2.0 407 Proxy Authentication Required
Via: SIP/2.0/UDP 192.168.0.205:5061;branch=z9hG4bK-9b329b78;received=192.168.0.205
From: "Grand Rapids M <sip:6165555555@192.168.0.200>;tag=e23e090b1771ef00o1
To: <sip:1111111111@192.168.0.200>;tag=as77e15e96
Call-ID: 3215be27-6aba5c94@192.168.0.205
CSeq: 101 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:1111111111@192.168.0.200>
Proxy-Authenticate: Digest realm="asterisk", nonce="38f45611"
Content-Length: 0
---
Jun 6 14:54:02 DEBUG[8500] chan_sip.c: SIP TIMER: Rescheduling retransmission #21652 (2) SIP/2.0 - 1
Jun 6 14:54:02 DEBUG[8500] chan_sip.c: ** SIP timers: Rescheduling retransmission 3 to 2000 ms (t1 500 ms (Retrans id #21652))
Jun 6 14:54:02 VERBOSE[8500] logger.c: Retransmitting #2 (no NAT) to 192.168.0.205:5061:
SIP/2.0 407 Proxy Authentication Required
Via: SIP/2.0/UDP 192.168.0.205:5061;branch=z9hG4bK-9b329b78;received=192.168.0.205
From: "Grand Rapids M <sip:6165555555@192.168.0.200>;tag=e23e090b1771ef00o1
To: <sip:1111111111@192.168.0.200>;tag=as77e15e96
Call-ID: 3215be27-6aba5c94@192.168.0.205
CSeq: 101 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:1111111111@192.168.0.200>
Proxy-Authenticate: Digest realm="asterisk", nonce="38f45611"
Content-Length: 0
---
Jun 6 14:54:04 DEBUG[8500] chan_sip.c: SIP TIMER: Rescheduling retransmission #21652 (3) SIP/2.0 - 1
Jun 6 14:54:04 DEBUG[8500] chan_sip.c: ** SIP timers: Rescheduling retransmission 4 to 4000 ms (t1 500 ms (Retrans id #21652))
Jun 6 14:54:04 VERBOSE[8500] logger.c: Retransmitting #3 (no NAT) to 192.168.0.205:5061:
SIP/2.0 407 Proxy Authentication Required
Via: SIP/2.0/UDP 192.168.0.205:5061;branch=z9hG4bK-9b329b78;received=192.168.0.205
From: "Grand Rapids M <sip:6165555555@192.168.0.200>;tag=e23e090b1771ef00o1
To: <sip:1111111111@192.168.0.200>;tag=as77e15e96
Call-ID: 3215be27-6aba5c94@192.168.0.205
CSeq: 101 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:1111111111@192.168.0.200>
Proxy-Authenticate: Digest realm="asterisk", nonce="38f45611"
Content-Length: 0
---
Jun 6 14:54:08 DEBUG[8500] chan_sip.c: SIP TIMER: Rescheduling retransmission #21652 (4) SIP/2.0 - 1
Jun 6 14:54:08 DEBUG[8500] chan_sip.c: ** SIP timers: Rescheduling retransmission 5 to 4000 ms (t1 500 ms (Retrans id #21652))
Jun 6 14:54:08 VERBOSE[8500] logger.c: Retransmitting #4 (no NAT) to 192.168.0.205:5061:
SIP/2.0 407 Proxy Authentication Required
Via: SIP/2.0/UDP 192.168.0.205:5061;branch=z9hG4bK-9b329b78;received=192.168.0.205
From: "Grand Rapids M <sip:6165555555@192.168.0.200>;tag=e23e090b1771ef00o1
To: <sip:1111111111@192.168.0.200>;tag=as77e15e96
Call-ID: 3215be27-6aba5c94@192.168.0.205
CSeq: 101 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:1111111111@192.168.0.200>
Proxy-Authenticate: Digest realm="asterisk", nonce="38f45611"
Content-Length: 0