********************************************************************************************************* 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" ;tag=f1ce50d13affcad4o1 To: Remote-Party-ID: "Short CID" ;screen=yes;party=calling Call-ID: 350a8255-2d83a720@192.168.0.205 CSeq: 101 INVITE Max-Forwards: 70 Contact: SPA3000 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" ;tag=f1ce50d13affcad4o1 (74) Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 3: To: (34) Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 4: Remote-Party-ID: "Short CID" ;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 (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" ;tag=f1ce50d13affcad4o1 To: ;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: 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" ;tag=f1ce50d13affcad4o1 To: ;tag=as561d72ff Call-ID: 350a8255-2d83a720@192.168.0.205 CSeq: 101 ACK Max-Forwards: 70 Contact: SPA3000 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" ;tag=f1ce50d13affcad4o1 (74) Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 3: To: ;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 (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" ;tag=f1ce50d13affcad4o1 To: Remote-Party-ID: "Short CID" ;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 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" ;tag=f1ce50d13affcad4o1 (74) Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 3: To: (34) Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 4: Remote-Party-ID: "Short CID" ;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 (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 Jun 6 15:14:41 VERBOSE[8500] logger.c: list_route: hop: 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" ;tag=f1ce50d13affcad4o1 To: 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: 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" ;tag=f1ce50d13affcad4o1 To: ;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: 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" ;tag=f1ce50d13affcad4o1 To: ;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 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" ;tag=f1ce50d13affcad4o1 (74) Jun 6 15:14:41 DEBUG[8500] chan_sip.c: Header 3: To: ;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 (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 ;tag=e23e090b1771ef00o1 To: Remote-Party-ID: "Grand Rapids M ;screen=yes;party=calling Call-ID: 3215be27-6aba5c94@192.168.0.205 CSeq: 101 INVITE Max-Forwards: 70 Contact: SPA3000 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 ;tag=e23e090b1771ef00o1 (75) Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Header 3: To: (34) Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Header 4: Remote-Party-ID: "Grand Rapids M ;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 (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 ;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 ;tag=e23e090b1771ef00o1 To: ;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: 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 ;tag=e23e090b1771ef00o1 To: Remote-Party-ID: "Grand Rapids M ;screen=yes;party=calling Call-ID: 3215be27-6aba5c94@192.168.0.205 CSeq: 101 INVITE Max-Forwards: 70 Contact: SPA3000 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 ;tag=e23e090b1771ef00o1 (75) Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Header 3: To: (34) Jun 6 14:53:29 DEBUG[8500] chan_sip.c: Header 4: Remote-Party-ID: "Grand Rapids M ;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 (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 ;tag=e23e090b1771ef00o1 To: ;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: 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 ;tag=e23e090b1771ef00o1 To: Remote-Party-ID: "Grand Rapids M ;screen=yes;party=calling Call-ID: 3215be27-6aba5c94@192.168.0.205 CSeq: 101 INVITE Max-Forwards: 70 Contact: SPA3000 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 ;tag=e23e090b1771ef00o1 (75) Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Header 3: To: (34) Jun 6 14:53:30 DEBUG[8500] chan_sip.c: Header 4: Remote-Party-ID: "Grand Rapids M ;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 (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 ;tag=e23e090b1771ef00o1 To: ;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: 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 ;tag=e23e090b1771ef00o1 To: Remote-Party-ID: "Grand Rapids M ;screen=yes;party=calling Call-ID: 3215be27-6aba5c94@192.168.0.205 CSeq: 101 INVITE Max-Forwards: 70 Contact: SPA3000 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 ;tag=e23e090b1771ef00o1 (75) Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Header 3: To: (34) Jun 6 14:53:32 DEBUG[8500] chan_sip.c: Header 4: Remote-Party-ID: "Grand Rapids M ;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 (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 ;tag=e23e090b1771ef00o1 To: ;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: 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 ;tag=e23e090b1771ef00o1 To: Remote-Party-ID: "Grand Rapids M ;screen=yes;party=calling Call-ID: 3215be27-6aba5c94@192.168.0.205 CSeq: 101 INVITE Max-Forwards: 70 Contact: SPA3000 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 ;tag=e23e090b1771ef00o1 (75) Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Header 3: To: (34) Jun 6 14:53:36 DEBUG[8500] chan_sip.c: Header 4: Remote-Party-ID: "Grand Rapids M ;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 (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 ;tag=e23e090b1771ef00o1 To: ;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: 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 ;tag=e23e090b1771ef00o1 To: ;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: 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 ;tag=e23e090b1771ef00o1 To: Remote-Party-ID: "Grand Rapids M ;screen=yes;party=calling Call-ID: 3215be27-6aba5c94@192.168.0.205 CSeq: 101 INVITE Max-Forwards: 70 Contact: SPA3000 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 ;tag=e23e090b1771ef00o1 (75) Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Header 3: To: (34) Jun 6 14:53:44 DEBUG[8500] chan_sip.c: Header 4: Remote-Party-ID: "Grand Rapids M ;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 (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 ;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 ;tag=e23e090b1771ef00o1 To: ;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: 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 ;tag=e23e090b1771ef00o1 To: ;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: 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 ;tag=e23e090b1771ef00o1 To: ;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: 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 ;tag=e23e090b1771ef00o1 To: ;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: 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 ;tag=e23e090b1771ef00o1 To: Remote-Party-ID: "Grand Rapids M ;screen=yes;party=calling Call-ID: 3215be27-6aba5c94@192.168.0.205 CSeq: 101 INVITE Max-Forwards: 70 Contact: SPA3000 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 ;tag=e23e090b1771ef00o1 (75) Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Header 3: To: (34) Jun 6 14:54:00 DEBUG[8500] chan_sip.c: Header 4: Remote-Party-ID: "Grand Rapids M ;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 (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 ;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 ;tag=e23e090b1771ef00o1 To: ;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: 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 ;tag=e23e090b1771ef00o1 To: ;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: 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 ;tag=e23e090b1771ef00o1 To: ;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: 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 ;tag=e23e090b1771ef00o1 To: ;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: 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 ;tag=e23e090b1771ef00o1 To: ;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: Proxy-Authenticate: Digest realm="asterisk", nonce="38f45611" Content-Length: 0