=~=~=~=~=~=~=~=~=~=~=~= PuTTY log 2006.08.22 17:07:27 =~=~=~=~=~=~=~=~=~=~=~= thirtythree*CLI> show version thirtythree*CLI> Asterisk SVN-trunk-r39706 built by root @ thirtythree on a i686 running Linux on 2006-08-14 06:14:08 UTC thirtythree*CLI> thirtythree*CLI> thirtythree*CLI> thirtythree*CLI> [Aug 22 17:07:44] DEBUG[4252]: chan_iax2.c:7087 socket_process: Peer Prodigy: got pong, lastms 2, historicms 2, maxms 2000 thirtythree*CLI> <-- SIP read from 203.82.162.21:5060: INVITE sip:100397@203.82.162.33 SIP/2.0 Via: SIP/2.0/UDP 203.82.162.21:5060;branch=z9hG4bK-392983f4 From: 100398 ;tag=7f36a7dabea76d04o0 To: Remote-Party-ID: 100398 ;screen=yes;party=calling Call-ID: e1b0a912-a7969d2c@203.82.162.21 CSeq: 101 INVITE Max-Forwards: 70 Contact: 100398 Expires: 240 User-Agent: Linksys/SPA2100-3.3.6 Content-Length: 401 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, PRACK, REFER Supported: 100rel, x-sipura Content-Type: application/sdp v=0 o=- 10571927 10571927 IN IP4 203.82.162.21 s=- c=IN IP4 203.82.162.21 t=0 0 m=audio 16448 RTP/AVP 8 0 2 4 18 96 97 98 101 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:2 G726-32/8000 a=rtpmap:4 G723/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:101 telephone-event/8000 a=fmtp:101 0-15 a thirtythree*CLI> =ptime:30 a=sendrecv thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 0: INVITE sip:100397@203.82.162.33 SIP/2.0 (39) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 1: Via: SIP/2.0/UDP 203.82.162.21:5060;branch=z9hG4bK-392983f4 (59) thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 2: From: 100398 ;tag=7f36a7dabea76d04o0 (62) thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 3: To: (30) thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 4: Remote-Party-ID: 100398 ;screen=yes;party=calling (75) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 5: Call-ID: e1b0a912-a7969d2c@203.82.162.21 (40) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 6: CSeq: 101 INVITE (16) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 7: Max-Forwards: 70 (16) thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 8: Contact: 100398 (47) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 9: Expires: 240 (12) thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 10: User-Agent: Linksys/SPA2100-3.3.6 (33) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 11: Content-Length: 401 (19) thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 12: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, PRACK, REFER (68) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 13: Supported: 100rel, x-sipura (27) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 14: Content-Type: application/sdp (29) thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 15: (0) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: v=0 (3) thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: o=- 10571927 10571927 IN IP4 203.82.162.21 (42) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: s=- (3) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: c=IN IP4 203.82.162.21 (22) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: t=0 0 (5) thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: m=audio 16448 RTP/AVP 8 0 2 4 18 96 97 98 101 (45) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=rtpmap:2 G726-32/8000 (23) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=rtpmap:4 G723/8000 (20) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=rtpmap:18 G729a/8000 (22) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=rtpmap:96 G726-40/8000 (24) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=rtpmap:97 G726-24/8000 (24) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=rtpmap:98 G726-16/8000 (24) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=fmtp:101 0-15 (15) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=ptime:30 (10) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=sendrecv (10) --- (15 headers 18 lines) --- [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4105 sip_alloc: Allocating new SIP dialog for e1b0a912-a7969d2c@203.82.162.21 - INVITE (With RTP) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:14007 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:1612 parse_sip_options: Begin: parsing SIP "Supported: 100rel, x-sipura" [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:1620 parse_sip_options: Found SIP option: -100rel- [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:1626 parse_sip_options: Matched SIP option: 100rel [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:1620 parse_sip_options: Found SIP option: -x-sipura- [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:1632 parse_sip_options: Found private SIP option, not supported: x-sipura Sending to 203.82.162.21 : 5060 (no NAT) Using INVITE request as basis request - e1b0a912-a7969d2c@203.82.162.21 [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:8650 check_user_full: Setting NAT on RTP to Off thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:8655 check_user_full: Setting NAT on VRTP to Off [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:8660 check_user_full: Setting NAT on UDPTL to Off Reliably Transmitting (no NAT) to 203.82.162.21:5060: SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 203.82.162.21:5060;branch=z9hG4bK-392983f4;received=203.82.162.21 From: 100398 ;tag=7f36a7dabea76d04o0 To: ;tag=as7c2e5167 Call-ID: e1b0a912-a7969d2c@203.82.162.21 CSeq: 101 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Proxy-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="01654f64" Content-Length: 0 --- [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 0: SIP/2.0 407 Proxy Authentication Required (41) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 1: Via: SIP/2.0/UDP 203.82.162.21:5060;branch=z9hG4bK-392983f4;received=203.82.162.21 (82) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 2: From: 100398 ;tag=7f36a7dabea76d04o0 (62) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 3: To: ;tag=as7c2e5167 (45) thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 4: Call-ID: e1b0a912-a7969d2c@203.82.162.21 (40) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 5: CSeq: 101 INVITE (16) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 6: User-Agent: Asterisk PBX (24) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 8: Supported: replaces (19) thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 9: Contact: (35) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 10: Proxy-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="01654f64" (76) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 11: Content-Length: 0 (17) thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 12: (0) thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:1903 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #1156 Scheduling destruction of SIP dialog 'e1b0a912-a7969d2c@203.82.162.21' in 32000 ms (Method: INVITE) Found user '100398' thirtythree*CLI> <-- SIP read from 203.82.162.21:5060: ACK sip:100397@203.82.162.33 SIP/2.0 Via: SIP/2.0/UDP 203.82.162.21:5060;branch=z9hG4bK-392983f4 From: 100398 ;tag=7f36a7dabea76d04o0 To: ;tag=as7c2e5167 Call-ID: e1b0a912-a7969d2c@203.82.162.21 CSeq: 101 ACK Max-Forwards: 70 Contact: 100398 User-Agent: Linksys/SPA2100-3.3.6 Content-Length: 0 [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 0: ACK sip:100397@203.82.162.33 SIP/2.0 (36) thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 1: Via: SIP/2.0/UDP 203.82.162.21:5060;branch=z9hG4bK-392983f4 (59) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 2: From: 100398 ;tag=7f36a7dabea76d04o0 (62) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 3: To: ;tag=as7c2e5167 (45) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 4: Call-ID: e1b0a912-a7969d2c@203.82.162.21 (40) thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 5: CSeq: 101 ACK (13) thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 6: Max-Forwards: 70 (16) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 7: Contact: 100398 (47) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 8: User-Agent: Linksys/SPA2100-3.3.6 (33) thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 9: Content-Length: 0 (17) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 10: (0) --- (10 headers 0 lines) --- [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:14007 handle_request: **** Received ACK (6) - Command in SIP ACK thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:1996 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #1156 [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:2006 __sip_ack: Stopping retransmission on 'e1b0a912-a7969d2c@203.82.162.21' of Response 101: Match Not Found thirtythree*CLI> <-- SIP read from 203.82.162.21:5060: INVITE sip:100397@203.82.162.33 SIP/2.0 Via: SIP/2.0/UDP 203.82.162.21:5060;branch=z9hG4bK-a1d976f4 From: 100398 ;tag=7f36a7dabea76d04o0 To: Remote-Party-ID: 100398 ;screen=yes;party=calling Call-ID: e1b0a912-a7969d2c@203.82.162.21 CSeq: 102 INVITE Max-Forwards: 70 Proxy-Authorization: Digest username="100398",realm="asterisk",nonce="01654f64",uri="sip:100397@203.82.162.33",algorithm=MD5,response="c22e265f2c2a187ee48d7ff16f32a99d" Contact: 100398 Expires: 240 User-Agent: Linksys/SPA2100-3.3.6 Content-Length: 401 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, PRACK, REFER Supported: 100rel, x-sipura Content-Type: application/sdp v=0 o=- 10571927 10571927 IN IP4 203.82.162.21 s=- c=IN IP4 203.82.162.21 t=0 0 m=audio 16448 RTP/AVP 8 0 2 4 18 96 97 98 101 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:2 G726-32/8000 a=rtpmap:4 G723/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:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 a=sendrecv thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 0: INVITE sip:100397@203.82.162.33 SIP/2.0 (39) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 1: Via: SIP/2.0/UDP 203.82.162.21:5060;branch=z9hG4bK-a1d976f4 (59) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 2: From: 100398 ;tag=7f36a7dabea76d04o0 (62) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 3: To: (30) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 4: Remote-Party-ID: 100398 ;screen=yes;party=calling (75) thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 5: Call-ID: e1b0a912-a7969d2c@203.82.162.21 (40) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 6: CSeq: 102 INVITE (16) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 7: Max-Forwards: 70 (16) thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 8: Proxy-Authorization: Digest username="100398",realm="asterisk",nonce="01654f64",uri="sip:100397@203.82.162.33",algorithm=MD5,response="c22e265f2c2a187ee48d7ff16f32a99d" (168) thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 9: Contact: 100398 (47) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 10: Expires: 240 (12) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 11: User-Agent: Linksys/SPA2100-3.3.6 (33) thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 12: Content-Length: 401 (19) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 13: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, PRACK, REFER (68) thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 14: Supported: 100rel, x-sipura (27) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 15: Content-Type: application/sdp (29) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 16: (0) thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: v=0 (3) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: o=- 10571927 10571927 IN IP4 203.82.162.21 (42) thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: s=- (3) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: c=IN IP4 203.82.162.21 (22) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: t=0 0 (5) thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: m=audio 16448 RTP/AVP 8 0 2 4 18 96 97 98 101 (45) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=rtpmap:2 G726-32/8000 (23) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=rtpmap:4 G723/8000 (20) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=rtpmap:18 G729a/8000 (22) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=rtpmap:96 G726-40/8000 (24) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=rtpmap:97 G726-24/8000 (24) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=rtpmap:98 G726-16/8000 (24) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=fmtp:101 0-15 (15) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=ptime:30 (10) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=sendrecv (10) --- (16 headers 18 lines) --- [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:14007 handle_request: **** Received INVITE (5) - Command in SIP INVITE Sending to 203.82.162.21 : 5060 (no NAT) Using INVITE request as basis request - e1b0a912-a7969d2c@203.82.162.21 [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:8650 check_user_full: Setting NAT on RTP to Off [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:8655 check_user_full: Setting NAT on VRTP to Off [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:8660 check_user_full: Setting NAT on UDPTL to Off Found user '100398' Found RTP audio format 8 Found RTP audio format 0 Found RTP audio format 2 Found RTP audio format 4 Found RTP audio format 18 Found RTP audio format 96 Found RTP audio format 97 thirtythree*CLI> Found RTP audio format 98 Found RTP audio format 101 Peer audio RTP is at port 203.82.162.21:16448 [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4644 process_sdp: Peer doesn't provide T.38 UDPTL Found description format PCMA for ID 8 Found description format PCMU for ID 0 Found description format G726-32 for ID 2 Found description format G723 for ID 4 thirtythree*CLI> Found description format G729a for ID 18 thirtythree*CLI> Found description format G726-40 for ID 96 Found description format G726-24 for ID 97 Found description format G726-16 for ID 98 thirtythree*CLI> Found description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer thirtythree*CLI> Got unsupported a:ptime in SDP offer thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4830 process_sdp: T38 state changed to 0 on channel Capabilities: us - 0xc (ulaw|alaw), peer - audio=0xd0d (g723|ulaw|alaw|g726|g729|ilbc)/video=0x0 (nothing), combined - 0xc (ulaw|alaw) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) thirtythree*CLI> Peer audio RTP is at port 203.82.162.21:16448 thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4900 process_sdp: We're settling with these formats: 0xc (ulaw|alaw) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:12820 handle_request_invite: Checking SIP call limits for device 100398 thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:2871 update_call_counter: Updating call counter for incoming call Looking for 100397 in from-internal (domain 203.82.162.33) thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:3600 sip_new: *** Our native formats are 0x8 (alaw) thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:3601 sip_new: *** Joint capabilities are 0xc (ulaw|alaw) thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:3602 sip_new: *** Our capabilities are 0xc (ulaw|alaw) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:3603 sip_new: *** AST_CODEC_CHOOSE formats are 0x8 (alaw) thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:3626 sip_new: This channel will not be able to handle video. thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:7591 build_route: build_route: Contact hop: 100398 list_route: hop: [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:12890 handle_request_invite: SIP/100398-0841c0f0: New call is still down.... Trying... thirtythree*CLI> Transmitting (no NAT) to 203.82.162.21:5060: SIP/2.0 100 Trying Via: SIP/2.0/UDP 203.82.162.21:5060;branch=z9hG4bK-a1d976f4;received=203.82.162.21 From: 100398 ;tag=7f36a7dabea76d04o0 To: Call-ID: e1b0a912-a7969d2c@203.82.162.21 CSeq: 102 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 --- thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 0: SIP/2.0 100 Trying (18) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 1: Via: SIP/2.0/UDP 203.82.162.21:5060;branch=z9hG4bK-a1d976f4;received=203.82.162.21 (82) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 2: From: 100398 ;tag=7f36a7dabea76d04o0 (62) thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 3: To: (30) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 4: Call-ID: e1b0a912-a7969d2c@203.82.162.21 (40) thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 5: CSeq: 102 INVITE (16) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 6: User-Agent: Asterisk PBX (24) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 8: Supported: replaces (19) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 9: Contact: (35) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 10: Content-Length: 0 (17) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 11: (0) [Aug 22 17:08:25] DEBUG[4247]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/100398-0841c0f0 [Aug 22 17:08:25] DEBUG[4240]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 100398 [Aug 22 17:08:25] DEBUG[4240]: chan_sip.c:14591 sip_devicestate: Checking device state for peer 100398 [Aug 22 17:08:25] DEBUG[4240]: devicestate.c:287 do_state_change: Changing state for SIP/100398 - state 8 (On Hold) [Aug 22 17:08:25] DEBUG[4240]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 100398 [Aug 22 17:08:25] DEBUG[4240]: chan_sip.c:14591 sip_devicestate: Checking device state for peer 100398 [Aug 22 17:08:25] DEBUG[31078]: pbx.c:1680 pbx_extension_helper: Launching 'Dial' -- Executing [100397@from-internal:1] Dial("SIP/100398-0841c0f0", "SIP/100397") in new stack thirtythree*CLI> [Aug 22 17:08:25] DEBUG[31079]: app_queue.c:536 changethread: Device 'SIP/100398' changed to state '8' (On Hold) but we don't care because they're not a member of any queue. thirtythree*CLI> [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:14649 sip_request_call: Asked to create a SIP channel with formats: 0x8 (alaw) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4105 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:2502 create_addr_from_peer: Our T38 capability (3856) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:2512 create_addr_from_peer: Setting NAT on RTP to Off [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:2518 create_addr_from_peer: Setting NAT on VRTP to Off [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:2524 create_addr_from_peer: Setting NAT on UDPTL to Off [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:3600 sip_new: *** Our native formats are 0x8 (alaw) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:3601 sip_new: *** Joint capabilities are 0x0 (nothing) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:3602 sip_new: *** Our capabilities are 0xc (ulaw|alaw) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:3603 sip_new: *** AST_CODEC_CHOOSE formats are 0x8 (alaw) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:3605 sip_new: *** Our preferred formats from the incoming channel are 0x8 (alaw) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:3626 sip_new: This channel will not be able to handle video. thirtythree*CLI> [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:16125 sip_set_rtp_peer: Early remote bridge setting SIP '73004854379bd13b1b7124bc3f4ec581@203.82.162.33' - Sending media to 203.82.162.21 [Aug 22 17:08:25] DEBUG[31078]: rtp.c:1418 ast_rtp_make_compatible: Seeded SDP of 'SIP/100397-08430da8' with that of 'SIP/100398-0841c0f0' [Aug 22 17:08:25] DEBUG[31078]: channel.c:3011 ast_channel_inherit_variables: Not copying variable STACK-from-internal-100397-1. [Aug 22 17:08:25] DEBUG[31078]: channel.c:3011 ast_channel_inherit_variables: Not copying variable SIPCALLID. [Aug 22 17:08:25] DEBUG[31078]: channel.c:3011 ast_channel_inherit_variables: Not copying variable SIPUSERAGENT. [Aug 22 17:08:25] DEBUG[31078]: channel.c:3011 ast_channel_inherit_variables: Not copying variable SIPDOMAIN. [Aug 22 17:08:25] DEBUG[31078]: channel.c:3011 ast_channel_inherit_variables: Not copying variable SIPURI. [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:2710 sip_call: Outgoing Call for 100397 [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:2871 update_call_counter: Updating call counter for outgoing call [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:2718 sip_call: Our T38 capability (3856), joint T38 capability (3856) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:5809 add_sdp: ** Our capability: 0xc (ulaw|alaw) Video flag: False [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:5810 add_sdp: ** Our prefcodec: 0x8 (alaw) Audio is at 203.82.162.33 port 17806 Adding codec 0x8 (alaw) to SDP Adding codec 0x4 (ulaw) to SDP Adding non-codec 0x1 (telephone-event) to SDP [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:5962 add_sdp: -- Done with adding codecs to SDP [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:6001 add_sdp: Done building SDP. Settling with this capability: 0xc (ulaw|alaw) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 0: INVITE sip:100397@203.82.162.20:5060 SIP/2.0 (44) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 1: Via: SIP/2.0/UDP 203.82.162.33:5060;branch=z9hG4bK4ed132e9 (58) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 2: From: "100398" ;tag=as2d4bf9db (56) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 3: To: (35) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 4: Contact: (35) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 5: Call-ID: 73004854379bd13b1b7124bc3f4ec581@203.82.162.33 (55) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 6: CSeq: 102 INVITE (16) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 8: Max-Forwards: 70 (16) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 9: Date: Tue, 22 Aug 2006 07:08:25 GMT (35) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 11: Supported: replaces (19) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 12: Content-Type: application/sdp (29) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 13: Content-Length: 252 (19) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 14: (0) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4357 parse_request: Line: v=0 (3) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4357 parse_request: Line: o=root 4236 4236 IN IP4 203.82.162.21 (37) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4357 parse_request: Line: s=session (9) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4357 parse_request: Line: c=IN IP4 203.82.162.21 (22) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4357 parse_request: Line: t=0 0 (5) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4357 parse_request: Line: m=audio 16448 RTP/AVP 8 0 101 (29) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4357 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4357 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4357 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4357 parse_request: Line: a=fmtp:101 0-16 (15) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4357 parse_request: Line: a=silenceSupp:off - - - - (25) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4357 parse_request: Line: a=sendrecv (10) Reliably Transmitting (no NAT) to 203.82.162.20:5060: INVITE sip:100397@203.82.162.20:5060 SIP/2.0 Via: SIP/2.0/UDP 203.82.162.33:5060;branch=z9hG4bK4ed132e9 From: "100398" ;tag=as2d4bf9db To: Contact: Call-ID: 73004854379bd13b1b7124bc3f4ec581@203.82.162.33 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Tue, 22 Aug 2006 07:08:25 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Type: application/sdp Content-Length: 252 v=0 o=root 4236 4236 IN IP4 203.82.162.21 s=session c=IN IP4 203.82.162.21 t=0 0 m=audio 16448 RTP/AVP 8 0 101 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=sendrecv --- [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 0: INVITE sip:100397@203.82.162.20:5060 SIP/2.0 (44) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 1: Via: SIP/2.0/UDP 203.82.162.33:5060;branch=z9hG4bK4ed132e9 (58) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 2: From: "100398" ;tag=as2d4bf9db (56) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 3: To: (35) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 4: Contact: (35) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 5: Call-ID: 73004854379bd13b1b7124bc3f4ec581@203.82.162.33 (55) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 6: CSeq: 102 INVITE (16) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 8: Max-Forwards: 70 (16) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 9: Date: Tue, 22 Aug 2006 07:08:25 GMT (35) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 11: Supported: replaces (19) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 12: Content-Type: application/sdp (29) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 13: Content-Length: 252 (19) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 14: (0) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4357 parse_request: Line: v=0 (3) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4357 parse_request: Line: o=root 4236 4236 IN IP4 203.82.162.21 (37) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4357 parse_request: Line: s=session (9) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4357 parse_request: Line: c=IN IP4 203.82.162.21 (22) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4357 parse_request: Line: t=0 0 (5) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4357 parse_request: Line: m=audio 16448 RTP/AVP 8 0 101 (29) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4357 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4357 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4357 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4357 parse_request: Line: a=fmtp:101 0-16 (15) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4357 parse_request: Line: a=silenceSupp:off - - - - (25) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4357 parse_request: Line: a=sendrecv (10) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:1903 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #1158 -- Called 100397 <-- SIP read from 203.82.162.20:5060: SIP/2.0 100 Trying To: From: "100398" ;tag=as2d4bf9db Call-ID: 73004854379bd13b1b7124bc3f4ec581@203.82.162.33 CSeq: 102 INVITE Via: SIP/2.0/UDP 203.82.162.33:5060;branch=z9hG4bK4ed132e9 Server: Linksys/SPA2100-3.3.6 Content-Length: 0 [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 0: SIP/2.0 100 Trying (18) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 1: To: (35) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 2: From: "100398" ;tag=as2d4bf9db (56) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 3: Call-ID: 73004854379bd13b1b7124bc3f4ec581@203.82.162.33 (55) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 4: CSeq: 102 INVITE (16) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 5: Via: SIP/2.0/UDP 203.82.162.33:5060;branch=z9hG4bK4ed132e9 (58) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 6: Server: Linksys/SPA2100-3.3.6 (29) thirtythree*CLI> [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 7: Content-Length: 0 (17) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 8: (0) --- (8 headers 0 lines) --- [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:2039 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #1158 - INVITE (got response) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:2048 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '73004854379bd13b1b7124bc3f4ec581@203.82.162.33' Request 102: Found [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:11178 handle_response_invite: SIP response 100 to standard invite <-- SIP read from 203.82.162.20:5060: SIP/2.0 180 Ringing To: ;tag=f13d983b46d20034i0 From: "100398" ;tag=as2d4bf9db Call-ID: 73004854379bd13b1b7124bc3f4ec581@203.82.162.33 CSeq: 102 INVITE Via: SIP/2.0/UDP 203.82.162.33:5060;branch=z9hG4bK4ed132e9 Server: Linksys/SPA2100-3.3.6 Remote-Party-ID: 100397 ;screen=yes;party=called Content-Length: 0 [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 0: SIP/2.0 180 Ringing (19) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 1: To: ;tag=f13d983b46d20034i0 (58) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 2: From: "100398" ;tag=as2d4bf9db (56) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 3: Call-ID: 73004854379bd13b1b7124bc3f4ec581@203.82.162.33 (55) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 4: CSeq: 102 INVITE (16) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 5: Via: SIP/2.0/UDP 203.82.162.33:5060;branch=z9hG4bK4ed132e9 (58) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 6: Server: Linksys/SPA2100-3.3.6 (29) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 7: Remote-Party-ID: 100397 ;screen=yes;party=called (74) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 8: Content-Length: 0 (17) [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 9: (0) --- (9 headers 0 lines) --- [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:2048 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '73004854379bd13b1b7124bc3f4ec581@203.82.162.33' Request 102: Found [Aug 22 17:08:25] DEBUG[4247]: chan_sip.c:11178 handle_response_invite: SIP response 180 to standard invite [Aug 22 17:08:25] DEBUG[4247]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/100397-08430da8 [Aug 22 17:08:25] DEBUG[4240]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 100397 -- SIP/100397-08430da8 is ringing [Aug 22 17:08:25] DEBUG[4240]: chan_sip.c:14591 sip_devicestate: Checking device state for peer 100397 [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:16125 sip_set_rtp_peer: Early remote bridge setting SIP 'e1b0a912-a7969d2c@203.82.162.21' - Sending media to 203.82.162.33 [Aug 22 17:08:25] DEBUG[4240]: devicestate.c:287 do_state_change: Changing state for SIP/100397 - state 8 (On Hold) [Aug 22 17:08:25] DEBUG[31078]: rtp.c:1354 ast_rtp_early_bridge: Setting early bridge SDP of 'SIP/100398-0841c0f0' with that of 'SIP/100397-08430da8' [Aug 22 17:08:25] DEBUG[4240]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 100397 Transmitting (no NAT) to 203.82.162.21:5060: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 203.82.162.21:5060;branch=z9hG4bK-a1d976f4;received=203.82.162.21 From: 100398 ;tag=7f36a7dabea76d04o0 To: ;tag=as47f8a336 Call-ID: e1b0a912-a7969d2c@203.82.162.21 CSeq: 102 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 --- [Aug 22 17:08:25] DEBUG[31080]: app_queue.c:536 changethread: Device 'SIP/100397' changed to state '8' (On Hold) but we don't care because they're not a member of any queue. [Aug 22 17:08:25] DEBUG[4240]: chan_sip.c:14591 sip_devicestate: Checking device state for peer 100397 [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 0: SIP/2.0 180 Ringing (19) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 1: Via: SIP/2.0/UDP 203.82.162.21:5060;branch=z9hG4bK-a1d976f4;received=203.82.162.21 (82) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 2: From: 100398 ;tag=7f36a7dabea76d04o0 (62) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 3: To: ;tag=as47f8a336 (45) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 4: Call-ID: e1b0a912-a7969d2c@203.82.162.21 (40) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 5: CSeq: 102 INVITE (16) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 6: User-Agent: Asterisk PBX (24) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 8: Supported: replaces (19) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 9: Contact: (35) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 10: Content-Length: 0 (17) [Aug 22 17:08:25] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 11: (0) thirtythree*CLI> <-- SIP read from 203.82.162.20:5060: SIP/2.0 200 OK To: ;tag=f13d983b46d20034i0 From: "100398" ;tag=as2d4bf9db Call-ID: 73004854379bd13b1b7124bc3f4ec581@203.82.162.33 CSeq: 102 INVITE Via: SIP/2.0/UDP 203.82.162.33:5060;branch=z9hG4bK4ed132e9 Contact: 100397 Server: Linksys/SPA2100-3.3.6 Remote-Party-ID: 100397 ;screen=yes;party=called Content-Length: 212 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, PRACK, REFER Supported: 100rel, x-sipura Content-Type: application/sdp v=0 o=- 10584244 10584244 IN IP4 203.82.162.20 s=- c=IN IP4 203.82.162.20 t=0 0 m=audio 16396 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 a=sendrecv thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 0: SIP/2.0 200 OK (14) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 1: To: ;tag=f13d983b46d20034i0 (58) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 2: From: "100398" ;tag=as2d4bf9db (56) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 3: Call-ID: 73004854379bd13b1b7124bc3f4ec581@203.82.162.33 (55) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 4: CSeq: 102 INVITE (16) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 5: Via: SIP/2.0/UDP 203.82.162.33:5060;branch=z9hG4bK4ed132e9 (58) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 6: Contact: 100397 (47) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 7: Server: Linksys/SPA2100-3.3.6 (29) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 8: Remote-Party-ID: 100397 ;screen=yes;party=called (74) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 9: Content-Length: 212 (19) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 10: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, PRACK, REFER (68) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 11: Supported: 100rel, x-sipura (27) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 12: Content-Type: application/sdp (29) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 13: (0) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: v=0 (3) [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: o=- 10584244 10584244 IN IP4 203.82.162.20 (42) [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: s=- (3) [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: c=IN IP4 203.82.162.20 (22) [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: t=0 0 (5) [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: m=audio 16396 RTP/AVP 8 101 (27) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=fmtp:101 0-15 (15) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=ptime:30 (10) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=sendrecv (10) --- (13 headers 11 lines) --- thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:1988 __sip_ack: Acked pending invite 102 thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:2006 __sip_ack: Stopping retransmission on '73004854379bd13b1b7124bc3f4ec581@203.82.162.33' of Request 102: Match Not Found [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:11178 handle_response_invite: SIP response 200 to standard invite thirtythree*CLI> Found RTP audio format 8 Found RTP audio format 101 thirtythree*CLI> Peer audio RTP is at port 203.82.162.20:16396 thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4644 process_sdp: Peer doesn't provide T.38 UDPTL Found description format PCMA for ID 8 Found description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer Got unsupported a:ptime in SDP offer [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4830 process_sdp: T38 state changed to 0 on channel SIP/100397-08430da8 Capabilities: us - 0xc (ulaw|alaw), peer - audio=0x8 (alaw)/video=0x0 (nothing), combined - 0x8 (alaw) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Peer audio RTP is at port 203.82.162.20:16396 Peer video RTP is at port 203.82.162.20:15624 [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4900 process_sdp: We're settling with these formats: 0x8 (alaw) [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4907 process_sdp: We have an owner, now see if we need to change this call [Aug 22 17:08:36] DEBUG[4247]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/100397 [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:2871 update_call_counter: Updating call counter for outgoing call [Aug 22 17:08:36] DEBUG[4240]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 100397 [Aug 22 17:08:36] DEBUG[4240]: chan_sip.c:14591 sip_devicestate: Checking device state for peer 100397 thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:7591 build_route: build_route: Contact hop: 100397 list_route: hop: [Aug 22 17:08:36] DEBUG[4240]: devicestate.c:287 do_state_change: Changing state for SIP/100397 - state 8 (On Hold) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4240]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 100397 [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:5340 reqprep: Strict routing enforced for session 73004854379bd13b1b7124bc3f4ec581@203.82.162.33 set_destination: Parsing for address/port to send to [Aug 22 17:08:36] DEBUG[31081]: app_queue.c:536 changethread: Device 'SIP/100397' changed to state '8' (On Hold) but we don't care because they're not a member of any queue. [Aug 22 17:08:36] DEBUG[4240]: chan_sip.c:14591 sip_devicestate: Checking device state for peer 100397 thirtythree*CLI> set_destination: set destination to 203.82.162.20, port 5060 Transmitting (no NAT) to 203.82.162.20:5060: ACK sip:100397@203.82.162.20:5060 SIP/2.0 Via: SIP/2.0/UDP 203.82.162.33:5060;branch=z9hG4bK4cd3a2d6 From: "100398" ;tag=as2d4bf9db To: ;tag=f13d983b46d20034i0 Contact: Call-ID: 73004854379bd13b1b7124bc3f4ec581@203.82.162.33 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 0: ACK sip:100397@203.82.162.20:5060 SIP/2.0 (41) [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 1: Via: SIP/2.0/UDP 203.82.162.33:5060;branch=z9hG4bK4cd3a2d6 (58) [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 2: From: "100398" ;tag=as2d4bf9db (56) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 3: To: ;tag=f13d983b46d20034i0 (58) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 4: Contact: (35) [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 5: Call-ID: 73004854379bd13b1b7124bc3f4ec581@203.82.162.33 (55) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 6: CSeq: 102 ACK (13) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 7: User-Agent: Asterisk PBX (24) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 8: Max-Forwards: 70 (16) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 9: Content-Length: 0 (17) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 10: (0) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[31078]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/100397-08430da8 thirtythree*CLI> -- SIP/100397-08430da8 answered SIP/100398-0841c0f0 [Aug 22 17:08:36] DEBUG[4240]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 100397 [Aug 22 17:08:36] DEBUG[4240]: chan_sip.c:14591 sip_devicestate: Checking device state for peer 100397 thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4240]: devicestate.c:287 do_state_change: Changing state for SIP/100397 - state 8 (On Hold) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[31082]: app_queue.c:536 changethread: Device 'SIP/100397' changed to state '8' (On Hold) but we don't care because they're not a member of any queue. thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4240]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 100397 thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4240]: chan_sip.c:14591 sip_devicestate: Checking device state for peer 100397 thirtythree*CLI> [Aug 22 17:08:36] DEBUG[31078]: chan_sip.c:16125 sip_set_rtp_peer: Early remote bridge setting SIP 'e1b0a912-a7969d2c@203.82.162.21' - Sending media to 203.82.162.20 [Aug 22 17:08:36] DEBUG[31078]: rtp.c:1354 ast_rtp_early_bridge: Setting early bridge SDP of 'SIP/100398-0841c0f0' with that of 'SIP/100397-08430da8' [Aug 22 17:08:36] DEBUG[31078]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/100398-0841c0f0 thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4240]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 100398 thirtythree*CLI> [Aug 22 17:08:36] DEBUG[31078]: chan_sip.c:3311 sip_answer: SIP answering channel: SIP/100398-0841c0f0 thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4240]: chan_sip.c:14591 sip_devicestate: Checking device state for peer 100398 thirtythree*CLI> [Aug 22 17:08:36] DEBUG[31078]: chan_sip.c:5809 add_sdp: ** Our capability: 0xc (ulaw|alaw) Video flag: True thirtythree*CLI> [Aug 22 17:08:36] DEBUG[31078]: chan_sip.c:5810 add_sdp: ** Our prefcodec: 0x0 (nothing) Audio is at 203.82.162.33 port 15864 [Aug 22 17:08:36] DEBUG[4240]: devicestate.c:287 do_state_change: Changing state for SIP/100398 - state 8 (On Hold) [Aug 22 17:08:36] DEBUG[4240]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 100398 [Aug 22 17:08:36] DEBUG[4240]: chan_sip.c:14591 sip_devicestate: Checking device state for peer 100398 thirtythree*CLI> Adding codec 0x8 (alaw) to SDP thirtythree*CLI> Adding codec 0x4 (ulaw) to SDP thirtythree*CLI> Adding non-codec 0x1 (telephone-event) to SDP [Aug 22 17:08:36] DEBUG[31083]: app_queue.c:536 changethread: Device 'SIP/100398' changed to state '8' (On Hold) but we don't care because they're not a member of any queue. thirtythree*CLI> [Aug 22 17:08:36] DEBUG[31078]: chan_sip.c:5962 add_sdp: -- Done with adding codecs to SDP thirtythree*CLI> [Aug 22 17:08:36] DEBUG[31078]: chan_sip.c:6001 add_sdp: Done building SDP. Settling with this capability: 0xc (ulaw|alaw) Reliably Transmitting (no NAT) to 203.82.162.21:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 203.82.162.21:5060;branch=z9hG4bK-a1d976f4;received=203.82.162.21 From: 100398 ;tag=7f36a7dabea76d04o0 To: ;tag=as47f8a336 Call-ID: e1b0a912-a7969d2c@203.82.162.21 CSeq: 102 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 252 v=0 o=root 4236 4236 IN IP4 203.82.162.20 s=session c=IN IP4 203.82.162.20 t=0 0 m=audio 16396 RTP/AVP 8 0 101 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=sendrecv --- thirtythree*CLI> [Aug 22 17:08:36] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 0: SIP/2.0 200 OK (14) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 1: Via: SIP/2.0/UDP 203.82.162.21:5060;branch=z9hG4bK-a1d976f4;received=203.82.162.21 (82) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 2: From: 100398 ;tag=7f36a7dabea76d04o0 (62) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 3: To: ;tag=as47f8a336 (45) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 4: Call-ID: e1b0a912-a7969d2c@203.82.162.21 (40) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 5: CSeq: 102 INVITE (16) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 6: User-Agent: Asterisk PBX (24) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 8: Supported: replaces (19) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 9: Contact: (35) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 10: Content-Type: application/sdp (29) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 11: Content-Length: 252 (19) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 12: (0) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[31078]: chan_sip.c:4357 parse_request: Line: v=0 (3) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[31078]: chan_sip.c:4357 parse_request: Line: o=root 4236 4236 IN IP4 203.82.162.20 (37) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[31078]: chan_sip.c:4357 parse_request: Line: s=session (9) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[31078]: chan_sip.c:4357 parse_request: Line: c=IN IP4 203.82.162.20 (22) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[31078]: chan_sip.c:4357 parse_request: Line: t=0 0 (5) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[31078]: chan_sip.c:4357 parse_request: Line: m=audio 16396 RTP/AVP 8 0 101 (29) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[31078]: chan_sip.c:4357 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[31078]: chan_sip.c:4357 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[31078]: chan_sip.c:4357 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[31078]: chan_sip.c:4357 parse_request: Line: a=fmtp:101 0-16 (15) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[31078]: chan_sip.c:4357 parse_request: Line: a=silenceSupp:off - - - - (25) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[31078]: chan_sip.c:4357 parse_request: Line: a=sendrecv (10) [Aug 22 17:08:36] DEBUG[31078]: chan_sip.c:1903 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #1160 -- Native bridging SIP/100398-0841c0f0 and SIP/100397-08430da8 thirtythree*CLI> <-- SIP read from 203.82.162.21:5060: ACK sip:100397@203.82.162.33 SIP/2.0 Via: SIP/2.0/UDP 203.82.162.21:5060;branch=z9hG4bK-4bb85d01 From: 100398 ;tag=7f36a7dabea76d04o0 To: ;tag=as47f8a336 Call-ID: e1b0a912-a7969d2c@203.82.162.21 CSeq: 102 ACK Max-Forwards: 70 Proxy-Authorization: Digest username="100398",realm="asterisk",nonce="01654f64",uri="sip:100397@203.82.162.33",algorithm=MD5,response="c30c40c97d93d549803ad9f761234c13" Contact: 100398 User-Agent: Linksys/SPA2100-3.3.6 Content-Length: 0 thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 0: ACK sip:100397@203.82.162.33 SIP/2.0 (36) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 1: Via: SIP/2.0/UDP 203.82.162.21:5060;branch=z9hG4bK-4bb85d01 (59) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 2: From: 100398 ;tag=7f36a7dabea76d04o0 (62) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 3: To: ;tag=as47f8a336 (45) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 4: Call-ID: e1b0a912-a7969d2c@203.82.162.21 (40) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 5: CSeq: 102 ACK (13) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 6: Max-Forwards: 70 (16) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 7: Proxy-Authorization: Digest username="100398",realm="asterisk",nonce="01654f64",uri="sip:100397@203.82.162.33",algorithm=MD5,response="c30c40c97d93d549803ad9f761234c13" (168) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 8: Contact: 100398 (47) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 9: User-Agent: Linksys/SPA2100-3.3.6 (33) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 10: Content-Length: 0 (17) thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 11: (0) --- (11 headers 0 lines) --- thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:14007 handle_request: **** Received ACK (6) - Command in SIP ACK thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:1996 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #1160 thirtythree*CLI> [Aug 22 17:08:36] DEBUG[4247]: chan_sip.c:2006 __sip_ack: Stopping retransmission on 'e1b0a912-a7969d2c@203.82.162.21' of Response 102: Match Not Found thirtythree*CLI> <-- SIP read from 203.82.162.21:5060: INVITE sip:100397@203.82.162.33 SIP/2.0 Via: SIP/2.0/UDP 203.82.162.21:5060;branch=z9hG4bK-55ad66e8 From: 100398 ;tag=7f36a7dabea76d04o0 To: ;tag=as47f8a336 Remote-Party-ID: 100398 ;screen=yes;party=calling Call-ID: e1b0a912-a7969d2c@203.82.162.21 CSeq: 103 INVITE Max-Forwards: 70 Proxy-Authorization: Digest username="100398",realm="asterisk",nonce="01654f64",uri="sip:100397@203.82.162.33",algorithm=MD5,response="c22e265f2c2a187ee48d7ff16f32a99d" Contact: 100398 Expires: 30 User-Agent: Linksys/SPA2100-3.3.6 Content-Length: 271 Content-Type: application/sdp v=0 o=- 10573174 10573174 IN IP4 203.82.162.21 s=- c=IN IP4 203.82.162.21 t=0 0 m=image 16448 udptl t38 a=T38FaxVersion:0 a=T38MaxBitRate:14400 a=T38FaxRateManagement:transferredTCF a=T38FaxMaxBuffer:200 a=T38FaxMaxDatagram:200 a=T38FaxUdpEC:t38UDPRedundancy thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 0: INVITE sip:100397@203.82.162.33 SIP/2.0 (39) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 1: Via: SIP/2.0/UDP 203.82.162.21:5060;branch=z9hG4bK-55ad66e8 (59) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 2: From: 100398 ;tag=7f36a7dabea76d04o0 (62) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 3: To: ;tag=as47f8a336 (45) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 4: Remote-Party-ID: 100398 ;screen=yes;party=calling (75) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 5: Call-ID: e1b0a912-a7969d2c@203.82.162.21 (40) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 6: CSeq: 103 INVITE (16) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 7: Max-Forwards: 70 (16) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 8: Proxy-Authorization: Digest username="100398",realm="asterisk",nonce="01654f64",uri="sip:100397@203.82.162.33",algorithm=MD5,response="c22e265f2c2a187ee48d7ff16f32a99d" (168) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 9: Contact: 100398 (47) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 10: Expires: 30 (11) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 11: User-Agent: Linksys/SPA2100-3.3.6 (33) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 12: Content-Length: 271 (19) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 13: Content-Type: application/sdp (29) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 14: (0) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: v=0 (3) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: o=- 10573174 10573174 IN IP4 203.82.162.21 (42) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: s=- (3) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: c=IN IP4 203.82.162.21 (22) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: t=0 0 (5) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: m=image 16448 udptl t38 (23) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=T38FaxVersion:0 (17) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=T38MaxBitRate:14400 (21) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=T38FaxRateManagement:transferredTCF (37) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=T38FaxMaxBuffer:200 (21) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=T38FaxMaxDatagram:200 (23) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=T38FaxUdpEC:t38UDPRedundancy (30) thirtythree*CLI> --- (14 headers 12 lines) --- thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:14007 handle_request: **** Received INVITE (5) - Command in SIP INVITE thirtythree*CLI> Sending to 203.82.162.21 : 5060 (no NAT) thirtythree*CLI> Got T.38 offer in SDP in dialog e1b0a912-a7969d2c@203.82.162.21 thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4574 process_sdp: T38 state changed to 4 on channel SIP/100398-0841c0f0 thirtythree*CLI> Peer doesn't provide audio thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4640 process_sdp: Peer T.38 UDPTL is at port 203.82.162.21:16448 thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4757 process_sdp: FaxVersion: 0 thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4732 process_sdp: T38MaxBitRate: 14400 thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4794 process_sdp: RateMangement: transferredTCF thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4727 process_sdp: MaxBufferSize:200 thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4766 process_sdp: FaxMaxDatagram: 200 thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4803 process_sdp: UDP EC: t38UDPRedundancy thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4823 process_sdp: Our T38 capability = (3856), peer T38 capability (16160), joint T38 capability (3872) thirtythree*CLI> Capabilities: us - 0xc (ulaw|alaw), peer - audio=0x0 (nothing)/video=0x0 (nothing), combined - 0x0 (nothing) thirtythree*CLI> Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) thirtythree*CLI> [Aug 22 17:08:38] NOTICE[4247]: chan_sip.c:4858 process_sdp: No compatible codecs, not accepting this offer! thirtythree*CLI> Transmitting (no NAT) to 203.82.162.21:5060: SIP/2.0 488 Not acceptable here Via: SIP/2.0/UDP 203.82.162.21:5060;branch=z9hG4bK-55ad66e8;received=203.82.162.21 From: 100398 ;tag=7f36a7dabea76d04o0 To: ;tag=as47f8a336 Call-ID: e1b0a912-a7969d2c@203.82.162.21 CSeq: 103 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 X-Asterisk-HangupCause: Normal Clearing X-Asterisk-HangupCauseCode: 16 --- thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 0: SIP/2.0 488 Not acceptable here (31) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 1: Via: SIP/2.0/UDP 203.82.162.21:5060;branch=z9hG4bK-55ad66e8;received=203.82.162.21 (82) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 2: From: 100398 ;tag=7f36a7dabea76d04o0 (62) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 3: To: ;tag=as47f8a336 (45) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 4: Call-ID: e1b0a912-a7969d2c@203.82.162.21 (40) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 5: CSeq: 103 INVITE (16) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 6: User-Agent: Asterisk PBX (24) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 8: Supported: replaces (19) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 9: Contact: (35) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 10: Content-Length: 0 (17) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 11: X-Asterisk-HangupCause: Normal Clearing (39) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 12: X-Asterisk-HangupCauseCode: 16 (30) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 13: (0) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:14218 sipsock_read: SIP message could not be handled, bad request: e1b0a912-a7969d2c@203.82.162.21 thirtythree*CLI> <-- SIP read from 203.82.162.21:5060: ACK sip:100397@203.82.162.33 SIP/2.0 Via: SIP/2.0/UDP 203.82.162.21:5060;branch=z9hG4bK-55ad66e8 From: 100398 ;tag=7f36a7dabea76d04o0 To: ;tag=as47f8a336 Call-ID: e1b0a912-a7969d2c@203.82.162.21 CSeq: 103 ACK Max-Forwards: 70 Proxy-Authorization: Digest username="100398",realm="asterisk",nonce="01654f64",uri="sip:100397@203.82.162.33",algorithm=MD5,response="c30c40c97d93d549803ad9f761234c13" Contact: 100398 User-Agent: Linksys/SPA2100-3.3.6 Content-Length: 0 thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 0: ACK sip:100397@203.82.162.33 SIP/2.0 (36) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 1: Via: SIP/2.0/UDP 203.82.162.21:5060;branch=z9hG4bK-55ad66e8 (59) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 2: From: 100398 ;tag=7f36a7dabea76d04o0 (62) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 3: To: ;tag=as47f8a336 (45) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 4: Call-ID: e1b0a912-a7969d2c@203.82.162.21 (40) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 5: CSeq: 103 ACK (13) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 6: Max-Forwards: 70 (16) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 7: Proxy-Authorization: Digest username="100398",realm="asterisk",nonce="01654f64",uri="sip:100397@203.82.162.33",algorithm=MD5,response="c30c40c97d93d549803ad9f761234c13" (168) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 8: Contact: 100398 (47) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 9: User-Agent: Linksys/SPA2100-3.3.6 (33) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 10: Content-Length: 0 (17) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 11: (0) --- (11 headers 0 lines) --- thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:14007 handle_request: **** Received ACK (6) - Command in SIP ACK thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:2006 __sip_ack: Stopping retransmission on 'e1b0a912-a7969d2c@203.82.162.21' of Response 103: Match Found thirtythree*CLI> <-- SIP read from 203.82.162.21:5060: INVITE sip:100397@203.82.162.33 SIP/2.0 Via: SIP/2.0/UDP 203.82.162.21:5060;branch=z9hG4bK-246a0e2e From: 100398 ;tag=7f36a7dabea76d04o0 To: ;tag=as47f8a336 Remote-Party-ID: 100398 ;screen=yes;party=calling Call-ID: e1b0a912-a7969d2c@203.82.162.21 CSeq: 104 INVITE Max-Forwards: 70 Proxy-Authorization: Digest username="100398",realm="asterisk",nonce="01654f64",uri="sip:100397@203.82.162.33",algorithm=MD5,response="c22e265f2c2a187ee48d7ff16f32a99d" Contact: 100398 Expires: 30 User-Agent: Linksys/SPA2100-3.3.6 Content-Length: 156 Content-Type: application/sdp v=0 o=- 10573175 10573175 IN IP4 203.82.162.21 s=- c=IN IP4 203.82.162.21 t=0 0 m=audio 16448 RTP/AVP 8 a=rtpmap:8 PCMA/8000 a=ptime:30 a=sendrecv thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 0: INVITE sip:100397@203.82.162.33 SIP/2.0 (39) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 1: Via: SIP/2.0/UDP 203.82.162.21:5060;branch=z9hG4bK-246a0e2e (59) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 2: From: 100398 ;tag=7f36a7dabea76d04o0 (62) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 3: To: ;tag=as47f8a336 (45) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 4: Remote-Party-ID: 100398 ;screen=yes;party=calling (75) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 5: Call-ID: e1b0a912-a7969d2c@203.82.162.21 (40) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 6: CSeq: 104 INVITE (16) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 7: Max-Forwards: 70 (16) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 8: Proxy-Authorization: Digest username="100398",realm="asterisk",nonce="01654f64",uri="sip:100397@203.82.162.33",algorithm=MD5,response="c22e265f2c2a187ee48d7ff16f32a99d" (168) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 9: Contact: 100398 (47) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 10: Expires: 30 (11) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 11: User-Agent: Linksys/SPA2100-3.3.6 (33) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 12: Content-Length: 156 (19) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 13: Content-Type: application/sdp (29) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 14: (0) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: v=0 (3) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: o=- 10573175 10573175 IN IP4 203.82.162.21 (42) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: s=- (3) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: c=IN IP4 203.82.162.21 (22) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: t=0 0 (5) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: m=audio 16448 RTP/AVP 8 (23) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=ptime:30 (10) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=sendrecv (10) thirtythree*CLI> --- (14 headers 9 lines) --- thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:14007 handle_request: **** Received INVITE (5) - Command in SIP INVITE thirtythree*CLI> Sending to 203.82.162.21 : 5060 (no NAT) thirtythree*CLI> Found RTP audio format 8 thirtythree*CLI> Peer audio RTP is at port 203.82.162.21:16448 thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4644 process_sdp: Peer doesn't provide T.38 UDPTL thirtythree*CLI> Found description format PCMA for ID 8 thirtythree*CLI> Got unsupported a:ptime in SDP offer thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4830 process_sdp: T38 state changed to 0 on channel SIP/100398-0841c0f0 thirtythree*CLI> Capabilities: us - 0xc (ulaw|alaw), peer - audio=0x8 (alaw)/video=0x0 (nothing), combined - 0x8 (alaw) thirtythree*CLI> Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) thirtythree*CLI> Peer audio RTP is at port 203.82.162.21:16448 thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4900 process_sdp: We're settling with these formats: 0x8 (alaw) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4907 process_sdp: We have an owner, now see if we need to change this call thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/100398 thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4240]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 100398 thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:12868 handle_request_invite: Got a SIP re-invite for call e1b0a912-a7969d2c@203.82.162.21 thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4240]: chan_sip.c:14591 sip_devicestate: Checking device state for peer 100398 thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:12957 handle_request_invite: SIP/100398-0841c0f0: This call is UP.... thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4240]: devicestate.c:287 do_state_change: Changing state for SIP/100398 - state 8 (On Hold) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:5809 add_sdp: ** Our capability: 0x8 (alaw) Video flag: True thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4240]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 100398 thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:5810 add_sdp: ** Our prefcodec: 0x0 (nothing) thirtythree*CLI> Audio is at 203.82.162.33 port 15864 [Aug 22 17:08:38] DEBUG[4240]: chan_sip.c:14591 sip_devicestate: Checking device state for peer 100398 thirtythree*CLI> Adding codec 0x8 (alaw) to SDP thirtythree*CLI> [Aug 22 17:08:38] DEBUG[31084]: app_queue.c:536 changethread: Device 'SIP/100398' changed to state '8' (On Hold) but we don't care because they're not a member of any queue. thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:5962 add_sdp: -- Done with adding codecs to SDP thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:6001 add_sdp: Done building SDP. Settling with this capability: 0x8 (alaw) Reliably Transmitting (no NAT) to 203.82.162.21:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 203.82.162.21:5060;branch=z9hG4bK-246a0e2e;received=203.82.162.21 From: 100398 ;tag=7f36a7dabea76d04o0 To: ;tag=as47f8a336 Call-ID: e1b0a912-a7969d2c@203.82.162.21 CSeq: 104 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 172 v=0 o=root 4236 4237 IN IP4 203.82.162.20 s=session c=IN IP4 203.82.162.20 t=0 0 m=audio 16396 RTP/AVP 8 a=rtpmap:8 PCMA/8000 a=silenceSupp:off - - - - a=sendrecv --- thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 0: SIP/2.0 200 OK (14) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 1: Via: SIP/2.0/UDP 203.82.162.21:5060;branch=z9hG4bK-246a0e2e;received=203.82.162.21 (82) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 2: From: 100398 ;tag=7f36a7dabea76d04o0 (62) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 3: To: ;tag=as47f8a336 (45) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 4: Call-ID: e1b0a912-a7969d2c@203.82.162.21 (40) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 5: CSeq: 104 INVITE (16) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 6: User-Agent: Asterisk PBX (24) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 8: Supported: replaces (19) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 9: Contact: (35) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 10: Content-Type: application/sdp (29) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 11: Content-Length: 172 (19) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 12: (0) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: v=0 (3) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: o=root 4236 4237 IN IP4 203.82.162.20 (37) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: s=session (9) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: c=IN IP4 203.82.162.20 (22) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: t=0 0 (5) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: m=audio 16396 RTP/AVP 8 (23) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=silenceSupp:off - - - - (25) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=sendrecv (10) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:1903 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #1161 thirtythree*CLI> <-- SIP read from 203.82.162.21:5060: ACK sip:100397@203.82.162.33 SIP/2.0 Via: SIP/2.0/UDP 203.82.162.21:5060;branch=z9hG4bK-35e91fa2 From: 100398 ;tag=7f36a7dabea76d04o0 To: ;tag=as47f8a336 Call-ID: e1b0a912-a7969d2c@203.82.162.21 CSeq: 104 ACK Max-Forwards: 70 Proxy-Authorization: Digest username="100398",realm="asterisk",nonce="01654f64",uri="sip:100397@203.82.162.33",algorithm=MD5,response="c30c40c97d93d549803ad9f761234c13" Contact: 100398 User-Agent: Linksys/SPA2100-3.3.6 Content-Length: 0 thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 0: ACK sip:100397@203.82.162.33 SIP/2.0 (36) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 1: Via: SIP/2.0/UDP 203.82.162.21:5060;branch=z9hG4bK-35e91fa2 (59) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 2: From: 100398 ;tag=7f36a7dabea76d04o0 (62) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 3: To: ;tag=as47f8a336 (45) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 4: Call-ID: e1b0a912-a7969d2c@203.82.162.21 (40) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 5: CSeq: 104 ACK (13) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 6: Max-Forwards: 70 (16) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 7: Proxy-Authorization: Digest username="100398",realm="asterisk",nonce="01654f64",uri="sip:100397@203.82.162.33",algorithm=MD5,response="c30c40c97d93d549803ad9f761234c13" (168) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 8: Contact: 100398 (47) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 9: User-Agent: Linksys/SPA2100-3.3.6 (33) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 10: Content-Length: 0 (17) thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 11: (0) --- (11 headers 0 lines) --- thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:14007 handle_request: **** Received ACK (6) - Command in SIP ACK thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:1996 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #1161 thirtythree*CLI> [Aug 22 17:08:38] DEBUG[4247]: chan_sip.c:2006 __sip_ack: Stopping retransmission on 'e1b0a912-a7969d2c@203.82.162.21' of Response 104: Match Not Found thirtythree*CLI> <-- SIP read from 203.82.162.20:5060: INVITE sip:100398@203.82.162.33 SIP/2.0 Via: SIP/2.0/UDP 203.82.162.20:5060;branch=z9hG4bK-2728c071 From: ;tag=f13d983b46d20034i0 To: "100398" ;tag=as2d4bf9db Remote-Party-ID: 100397 ;screen=yes;party=called Call-ID: 73004854379bd13b1b7124bc3f4ec581@203.82.162.33 CSeq: 101 INVITE Max-Forwards: 70 Contact: 100397 Expires: 30 User-Agent: Linksys/SPA2100-3.3.6 Content-Length: 271 Content-Type: application/sdp v=0 o=- 10585625 10585625 IN IP4 203.82.162.20 s=- c=IN IP4 203.82.162.20 t=0 0 m=image 16396 udptl t38 a=T38FaxVersion:0 a=T38MaxBitRate:14400 a=T38FaxRateManagement:transferredTCF a=T38FaxMaxBuffer:200 a=T38FaxMaxDatagram:200 a=T38FaxUdpEC:t38UDPRedundancy thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 0: INVITE sip:100398@203.82.162.33 SIP/2.0 (39) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 1: Via: SIP/2.0/UDP 203.82.162.20:5060;branch=z9hG4bK-2728c071 (59) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 2: From: ;tag=f13d983b46d20034i0 (60) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 3: To: "100398" ;tag=as2d4bf9db (54) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 4: Remote-Party-ID: 100397 ;screen=yes;party=called (74) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 5: Call-ID: 73004854379bd13b1b7124bc3f4ec581@203.82.162.33 (55) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 6: CSeq: 101 INVITE (16) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 7: Max-Forwards: 70 (16) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 8: Contact: 100397 (47) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 9: Expires: 30 (11) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 10: User-Agent: Linksys/SPA2100-3.3.6 (33) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 11: Content-Length: 271 (19) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 12: Content-Type: application/sdp (29) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 13: (0) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: v=0 (3) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: o=- 10585625 10585625 IN IP4 203.82.162.20 (42) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: s=- (3) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: c=IN IP4 203.82.162.20 (22) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: t=0 0 (5) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: m=image 16396 udptl t38 (23) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=T38FaxVersion:0 (17) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=T38MaxBitRate:14400 (21) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=T38FaxRateManagement:transferredTCF (37) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=T38FaxMaxBuffer:200 (21) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=T38FaxMaxDatagram:200 (23) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=T38FaxUdpEC:t38UDPRedundancy (30) --- (13 headers 12 lines) --- thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:14007 handle_request: **** Received INVITE (5) - Command in SIP INVITE thirtythree*CLI> Sending to 203.82.162.20 : 5060 (no NAT) thirtythree*CLI> Got T.38 offer in SDP in dialog 73004854379bd13b1b7124bc3f4ec581@203.82.162.33 thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4574 process_sdp: T38 state changed to 4 on channel SIP/100397-08430da8 Peer doesn't provide audio thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4640 process_sdp: Peer T.38 UDPTL is at port 203.82.162.20:16396 thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4757 process_sdp: FaxVersion: 0 thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4732 process_sdp: T38MaxBitRate: 14400 thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4794 process_sdp: RateMangement: transferredTCF thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4727 process_sdp: MaxBufferSize:200 thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4766 process_sdp: FaxMaxDatagram: 200 thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4803 process_sdp: UDP EC: t38UDPRedundancy thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4823 process_sdp: Our T38 capability = (3856), peer T38 capability (16160), joint T38 capability (3872) thirtythree*CLI> Capabilities: us - 0xc (ulaw|alaw), peer - audio=0x0 (nothing)/video=0x0 (nothing), combined - 0x0 (nothing) thirtythree*CLI> Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) thirtythree*CLI> [Aug 22 17:08:39] NOTICE[4247]: chan_sip.c:4858 process_sdp: No compatible codecs, not accepting this offer! thirtythree*CLI> Transmitting (no NAT) to 203.82.162.20:5060: SIP/2.0 488 Not acceptable here Via: SIP/2.0/UDP 203.82.162.20:5060;branch=z9hG4bK-2728c071;received=203.82.162.20 From: ;tag=f13d983b46d20034i0 To: "100398" ;tag=as2d4bf9db Call-ID: 73004854379bd13b1b7124bc3f4ec581@203.82.162.33 CSeq: 101 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 X-Asterisk-HangupCause: Normal Clearing X-Asterisk-HangupCauseCode: 16 --- thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 0: SIP/2.0 488 Not acceptable here (31) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 1: Via: SIP/2.0/UDP 203.82.162.20:5060;branch=z9hG4bK-2728c071;received=203.82.162.20 (82) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 2: From: ;tag=f13d983b46d20034i0 (60) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 3: To: "100398" ;tag=as2d4bf9db (54) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 4: Call-ID: 73004854379bd13b1b7124bc3f4ec581@203.82.162.33 (55) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 5: CSeq: 101 INVITE (16) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 6: User-Agent: Asterisk PBX (24) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 8: Supported: replaces (19) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 9: Contact: (35) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 10: Content-Length: 0 (17) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 11: X-Asterisk-HangupCause: Normal Clearing (39) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 12: X-Asterisk-HangupCauseCode: 16 (30) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 13: (0) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:14218 sipsock_read: SIP message could not be handled, bad request: 73004854379bd13b1b7124bc3f4ec581@203.82.162.33 thirtythree*CLI> <-- SIP read from 203.82.162.20:5060: ACK sip:100398@203.82.162.33 SIP/2.0 Via: SIP/2.0/UDP 203.82.162.20:5060;branch=z9hG4bK-2728c071 From: ;tag=f13d983b46d20034i0 To: "100398" ;tag=as2d4bf9db Call-ID: 73004854379bd13b1b7124bc3f4ec581@203.82.162.33 CSeq: 101 ACK Max-Forwards: 70 Contact: 100397 User-Agent: Linksys/SPA2100-3.3.6 Content-Length: 0 thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 0: ACK sip:100398@203.82.162.33 SIP/2.0 (36) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 1: Via: SIP/2.0/UDP 203.82.162.20:5060;branch=z9hG4bK-2728c071 (59) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 2: From: ;tag=f13d983b46d20034i0 (60) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 3: To: "100398" ;tag=as2d4bf9db (54) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 4: Call-ID: 73004854379bd13b1b7124bc3f4ec581@203.82.162.33 (55) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 5: CSeq: 101 ACK (13) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 6: Max-Forwards: 70 (16) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 7: Contact: 100397 (47) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 8: User-Agent: Linksys/SPA2100-3.3.6 (33) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 9: Content-Length: 0 (17) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 10: (0) thirtythree*CLI> --- (10 headers 0 lines) --- thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:14007 handle_request: **** Received ACK (6) - Command in SIP ACK thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:2006 __sip_ack: Stopping retransmission on '73004854379bd13b1b7124bc3f4ec581@203.82.162.33' of Response 101: Match Found thirtythree*CLI> <-- SIP read from 203.82.162.20:5060: INVITE sip:100398@203.82.162.33 SIP/2.0 Via: SIP/2.0/UDP 203.82.162.20:5060;branch=z9hG4bK-a7d30adc From: ;tag=f13d983b46d20034i0 To: "100398" ;tag=as2d4bf9db Remote-Party-ID: 100397 ;screen=yes;party=called Call-ID: 73004854379bd13b1b7124bc3f4ec581@203.82.162.33 CSeq: 102 INVITE Max-Forwards: 70 Contact: 100397 Expires: 30 User-Agent: Linksys/SPA2100-3.3.6 Content-Length: 156 Content-Type: application/sdp v=0 o=- 10585626 10585626 IN IP4 203.82.162.20 s=- c=IN IP4 203.82.162.20 t=0 0 m=audio 16396 RTP/AVP 8 a=rtpmap:8 PCMA/8000 a=ptime:30 a=sendrecv thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 0: INVITE sip:100398@203.82.162.33 SIP/2.0 (39) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 1: Via: SIP/2.0/UDP 203.82.162.20:5060;branch=z9hG4bK-a7d30adc (59) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 2: From: ;tag=f13d983b46d20034i0 (60) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 3: To: "100398" ;tag=as2d4bf9db (54) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 4: Remote-Party-ID: 100397 ;screen=yes;party=called (74) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 5: Call-ID: 73004854379bd13b1b7124bc3f4ec581@203.82.162.33 (55) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 6: CSeq: 102 INVITE (16) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 7: Max-Forwards: 70 (16) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 8: Contact: 100397 (47) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 9: Expires: 30 (11) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 10: User-Agent: Linksys/SPA2100-3.3.6 (33) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 11: Content-Length: 156 (19) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 12: Content-Type: application/sdp (29) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 13: (0) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: v=0 (3) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: o=- 10585626 10585626 IN IP4 203.82.162.20 (42) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: s=- (3) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: c=IN IP4 203.82.162.20 (22) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: t=0 0 (5) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: m=audio 16396 RTP/AVP 8 (23) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=ptime:30 (10) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=sendrecv (10) thirtythree*CLI> --- (13 headers 9 lines) --- thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:14007 handle_request: **** Received INVITE (5) - Command in SIP INVITE thirtythree*CLI> Sending to 203.82.162.20 : 5060 (no NAT) thirtythree*CLI> Found RTP audio format 8 thirtythree*CLI> Peer audio RTP is at port 203.82.162.20:16396 thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4644 process_sdp: Peer doesn't provide T.38 UDPTL thirtythree*CLI> Found description format PCMA for ID 8 thirtythree*CLI> Got unsupported a:ptime in SDP offer thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4830 process_sdp: T38 state changed to 0 on channel SIP/100397-08430da8 thirtythree*CLI> Capabilities: us - 0xc (ulaw|alaw), peer - audio=0x8 (alaw)/video=0x0 (nothing), combined - 0x8 (alaw) thirtythree*CLI> Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) thirtythree*CLI> Peer audio RTP is at port 203.82.162.20:16396 thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4900 process_sdp: We're settling with these formats: 0x8 (alaw) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4907 process_sdp: We have an owner, now see if we need to change this call thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/100397 thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:12868 handle_request_invite: Got a SIP re-invite for call 73004854379bd13b1b7124bc3f4ec581@203.82.162.33 thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4240]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 100397 thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:12957 handle_request_invite: SIP/100397-08430da8: This call is UP.... thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:5809 add_sdp: ** Our capability: 0x8 (alaw) Video flag: True thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4240]: chan_sip.c:14591 sip_devicestate: Checking device state for peer 100397 thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:5810 add_sdp: ** Our prefcodec: 0x8 (alaw) thirtythree*CLI> Audio is at 203.82.162.33 port 17806 thirtythree*CLI> Adding codec 0x8 (alaw) to SDP thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:5962 add_sdp: -- Done with adding codecs to SDP thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4240]: devicestate.c:287 do_state_change: Changing state for SIP/100397 - state 8 (On Hold) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:6001 add_sdp: Done building SDP. Settling with this capability: 0x8 (alaw) thirtythree*CLI> Reliably Transmitting (no NAT) to 203.82.162.20:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 203.82.162.20:5060;branch=z9hG4bK-a7d30adc;received=203.82.162.20 From: ;tag=f13d983b46d20034i0 To: "100398" ;tag=as2d4bf9db Call-ID: 73004854379bd13b1b7124bc3f4ec581@203.82.162.33 CSeq: 102 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 172 v=0 o=root 4236 4237 IN IP4 203.82.162.21 s=session c=IN IP4 203.82.162.21 t=0 0 m=audio 16448 RTP/AVP 8 a=rtpmap:8 PCMA/8000 a=silenceSupp:off - - - - a=sendrecv --- [Aug 22 17:08:39] DEBUG[4240]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 100397 thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 0: SIP/2.0 200 OK (14) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 1: Via: SIP/2.0/UDP 203.82.162.20:5060;branch=z9hG4bK-a7d30adc;received=203.82.162.20 (82) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 2: From: ;tag=f13d983b46d20034i0 (60) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 3: To: "100398" ;tag=as2d4bf9db (54) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 4: Call-ID: 73004854379bd13b1b7124bc3f4ec581@203.82.162.33 (55) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 5: CSeq: 102 INVITE (16) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[31085]: app_queue.c:536 changethread: Device 'SIP/100397' changed to state '8' (On Hold) but we don't care because they're not a member of any queue. thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4240]: chan_sip.c:14591 sip_devicestate: Checking device state for peer 100397 thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 6: User-Agent: Asterisk PBX (24) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 8: Supported: replaces (19) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 9: Contact: (35) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 10: Content-Type: application/sdp (29) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 11: Content-Length: 172 (19) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 12: (0) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: v=0 (3) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: o=root 4236 4237 IN IP4 203.82.162.21 (37) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: s=session (9) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: c=IN IP4 203.82.162.21 (22) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: t=0 0 (5) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: m=audio 16448 RTP/AVP 8 (23) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=silenceSupp:off - - - - (25) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4357 parse_request: Line: a=sendrecv (10) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:1903 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #1162 thirtythree*CLI> <-- SIP read from 203.82.162.20:5060: ACK sip:100398@203.82.162.33 SIP/2.0 Via: SIP/2.0/UDP 203.82.162.20:5060;branch=z9hG4bK-b1d5cb6f From: ;tag=f13d983b46d20034i0 To: "100398" ;tag=as2d4bf9db Call-ID: 73004854379bd13b1b7124bc3f4ec581@203.82.162.33 CSeq: 102 ACK Max-Forwards: 70 Contact: 100397 User-Agent: Linksys/SPA2100-3.3.6 Content-Length: 0 thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 0: ACK sip:100398@203.82.162.33 SIP/2.0 (36) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 1: Via: SIP/2.0/UDP 203.82.162.20:5060;branch=z9hG4bK-b1d5cb6f (59) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 2: From: ;tag=f13d983b46d20034i0 (60) [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 3: To: "100398" ;tag=as2d4bf9db (54) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 4: Call-ID: 73004854379bd13b1b7124bc3f4ec581@203.82.162.33 (55) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 5: CSeq: 102 ACK (13) [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 6: Max-Forwards: 70 (16) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 7: Contact: 100397 (47) [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 8: User-Agent: Linksys/SPA2100-3.3.6 (33) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 9: Content-Length: 0 (17) thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 10: (0) --- (10 headers 0 lines) --- thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:14007 handle_request: **** Received ACK (6) - Command in SIP ACK thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:1996 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #1162 thirtythree*CLI> [Aug 22 17:08:39] DEBUG[4247]: chan_sip.c:2006 __sip_ack: Stopping retransmission on '73004854379bd13b1b7124bc3f4ec581@203.82.162.33' of Response 102: Match Not Found thirtythree*CLI> [Aug 22 17:08:44] DEBUG[4255]: chan_iax2.c:7087 socket_process: Peer Prodigy: got pong, lastms 1, historicms 1, maxms 2000 thirtythree*CLI> [Aug 22 17:09:24] DEBUG[4263]: manager.c:1812 process_message: Manager received command 'Command' thirtythree*CLI> [Aug 22 17:09:24] DEBUG[4263]: manager.c:1812 process_message: Manager received command 'Command' thirtythree*CLI> [Aug 22 17:09:44] DEBUG[4258]: chan_iax2.c:7087 socket_process: Peer Prodigy: got pong, lastms 1, historicms 1, maxms 2000 thirtythree*CLI> <-- SIP read from 203.82.162.21:5060: BYE sip:100397@203.82.162.33 SIP/2.0 Via: SIP/2.0/UDP 203.82.162.21:5060;branch=z9hG4bK-c94e3880 From: 100398 ;tag=7f36a7dabea76d04o0 To: ;tag=as47f8a336 Call-ID: e1b0a912-a7969d2c@203.82.162.21 CSeq: 105 BYE Max-Forwards: 70 Proxy-Authorization: Digest username="100398",realm="asterisk",nonce="01654f64",uri="sip:100397@203.82.162.33",algorithm=MD5,response="69a0068d11aebc4d77dd352493f12739" User-Agent: Linksys/SPA2100-3.3.6 Content-Length: 0 thirtythree*CLI> [Aug 22 17:09:49] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 0: BYE sip:100397@203.82.162.33 SIP/2.0 (36) thirtythree*CLI> [Aug 22 17:09:49] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 1: Via: SIP/2.0/UDP 203.82.162.21:5060;branch=z9hG4bK-c94e3880 (59) thirtythree*CLI> [Aug 22 17:09:49] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 2: From: 100398 ;tag=7f36a7dabea76d04o0 (62) thirtythree*CLI> [Aug 22 17:09:49] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 3: To: ;tag=as47f8a336 (45) thirtythree*CLI> [Aug 22 17:09:49] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 4: Call-ID: e1b0a912-a7969d2c@203.82.162.21 (40) thirtythree*CLI> [Aug 22 17:09:49] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 5: CSeq: 105 BYE (13) thirtythree*CLI> [Aug 22 17:09:49] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 6: Max-Forwards: 70 (16) thirtythree*CLI> [Aug 22 17:09:49] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 7: Proxy-Authorization: Digest username="100398",realm="asterisk",nonce="01654f64",uri="sip:100397@203.82.162.33",algorithm=MD5,response="69a0068d11aebc4d77dd352493f12739" (168) thirtythree*CLI> [Aug 22 17:09:49] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 8: User-Agent: Linksys/SPA2100-3.3.6 (33) thirtythree*CLI> [Aug 22 17:09:49] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 9: Content-Length: 0 (17) thirtythree*CLI> [Aug 22 17:09:49] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 10: (0) --- (10 headers 0 lines) --- thirtythree*CLI> [Aug 22 17:09:49] DEBUG[4247]: chan_sip.c:14007 handle_request: **** Received BYE (8) - Command in SIP BYE thirtythree*CLI> Sending to 203.82.162.21 : 5060 (no NAT) thirtythree*CLI> Transmitting (no NAT) to 203.82.162.21:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 203.82.162.21:5060;branch=z9hG4bK-c94e3880;received=203.82.162.21 From: 100398 ;tag=7f36a7dabea76d04o0 To: ;tag=as47f8a336 Call-ID: e1b0a912-a7969d2c@203.82.162.21 CSeq: 105 BYE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 --- thirtythree*CLI> [Aug 22 17:09:49] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 0: SIP/2.0 200 OK (14) thirtythree*CLI> [Aug 22 17:09:49] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 1: Via: SIP/2.0/UDP 203.82.162.21:5060;branch=z9hG4bK-c94e3880;received=203.82.162.21 (82) thirtythree*CLI> [Aug 22 17:09:49] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 2: From: 100398 ;tag=7f36a7dabea76d04o0 (62) thirtythree*CLI> [Aug 22 17:09:49] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 3: To: ;tag=as47f8a336 (45) thirtythree*CLI> [Aug 22 17:09:49] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 4: Call-ID: e1b0a912-a7969d2c@203.82.162.21 (40) thirtythree*CLI> [Aug 22 17:09:49] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 5: CSeq: 105 BYE (13) thirtythree*CLI> [Aug 22 17:09:49] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 6: User-Agent: Asterisk PBX (24) thirtythree*CLI> [Aug 22 17:09:49] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) thirtythree*CLI> [Aug 22 17:09:49] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 8: Supported: replaces (19) thirtythree*CLI> [Aug 22 17:09:49] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 9: Contact: (35) thirtythree*CLI> [Aug 22 17:09:49] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 10: Content-Length: 0 (17) thirtythree*CLI> [Aug 22 17:09:49] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 11: (0) thirtythree*CLI> [Aug 22 17:09:49] DEBUG[31078]: rtp.c:2686 ast_rtp_bridge: Oooh, got a hangup thirtythree*CLI> [Aug 22 17:09:49] DEBUG[31078]: channel.c:3709 ast_channel_bridge: Returning from native bridge, channels: SIP/100398-0841c0f0, SIP/100397-08430da8 thirtythree*CLI> [Aug 22 17:09:49] DEBUG[31078]: channel.c:1519 ast_hangup: Hanging up channel 'SIP/100397-08430da8' thirtythree*CLI> [Aug 22 17:09:49] DEBUG[31078]: chan_sip.c:3172 sip_hangup: Hangup call SIP/100397-08430da8, SIP callid 73004854379bd13b1b7124bc3f4ec581@203.82.162.33) thirtythree*CLI> [Aug 22 17:09:49] DEBUG[31078]: chan_sip.c:3180 sip_hangup: update_call_counter(100397) - decrement call limit counter on hangup thirtythree*CLI> [Aug 22 17:09:49] DEBUG[31078]: chan_sip.c:2871 update_call_counter: Updating call counter for outgoing call thirtythree*CLI> [Aug 22 17:09:49] DEBUG[31078]: chan_sip.c:5340 reqprep: Strict routing enforced for session 73004854379bd13b1b7124bc3f4ec581@203.82.162.33 thirtythree*CLI> set_destination: Parsing for address/port to send to thirtythree*CLI> set_destination: set destination to 203.82.162.20, port 5060 thirtythree*CLI> Reliably Transmitting (no NAT) to 203.82.162.20:5060: BYE sip:100397@203.82.162.20:5060 SIP/2.0 Via: SIP/2.0/UDP 203.82.162.33:5060;branch=z9hG4bK70ce330d From: "100398" ;tag=as2d4bf9db To: ;tag=f13d983b46d20034i0 Contact: Call-ID: 73004854379bd13b1b7124bc3f4ec581@203.82.162.33 CSeq: 103 BYE User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- thirtythree*CLI> [Aug 22 17:09:49] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 0: BYE sip:100397@203.82.162.20:5060 SIP/2.0 (41) thirtythree*CLI> [Aug 22 17:09:49] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 1: Via: SIP/2.0/UDP 203.82.162.33:5060;branch=z9hG4bK70ce330d (58) thirtythree*CLI> [Aug 22 17:09:49] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 2: From: "100398" ;tag=as2d4bf9db (56) thirtythree*CLI> [Aug 22 17:09:49] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 3: To: ;tag=f13d983b46d20034i0 (58) thirtythree*CLI> [Aug 22 17:09:49] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 4: Contact: (35) thirtythree*CLI> [Aug 22 17:09:49] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 5: Call-ID: 73004854379bd13b1b7124bc3f4ec581@203.82.162.33 (55) thirtythree*CLI> [Aug 22 17:09:49] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 6: CSeq: 103 BYE (13) thirtythree*CLI> [Aug 22 17:09:49] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 7: User-Agent: Asterisk PBX (24) thirtythree*CLI> [Aug 22 17:09:49] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 8: Max-Forwards: 70 (16) thirtythree*CLI> [Aug 22 17:09:49] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 9: Content-Length: 0 (17) thirtythree*CLI> [Aug 22 17:09:49] DEBUG[31078]: chan_sip.c:4325 parse_request: Header 10: (0) thirtythree*CLI> [Aug 22 17:09:49] DEBUG[31078]: chan_sip.c:1903 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #1163 thirtythree*CLI> [Aug 22 17:09:49] DEBUG[31078]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/100397-08430da8 thirtythree*CLI> [Aug 22 17:09:49] DEBUG[31078]: rtp.c:1317 ast_rtp_early_bridge: Channel '' has no RTP, not doing anything thirtythree*CLI> [Aug 22 17:09:49] DEBUG[31078]: app_dial.c:1631 dial_exec_full: Exiting with DIALSTATUS=ANSWER. thirtythree*CLI> [Aug 22 17:09:49] DEBUG[31078]: pbx.c:2276 __ast_pbx_run: Spawn extension (from-internal,100397,1) exited non-zero on 'SIP/100398-0841c0f0' thirtythree*CLI> [Aug 22 17:09:49] DEBUG[31078]: pbx.c:1680 pbx_extension_helper: Launching 'Macro' thirtythree*CLI> -- Executing [h@from-internal:1] Macro("SIP/100398-0841c0f0", "hangupcall") in new stack thirtythree*CLI> [Aug 22 17:09:49] DEBUG[31078]: pbx.c:1680 pbx_extension_helper: Launching 'ResetCDR' thirtythree*CLI> -- Executing [s@macro-hangupcall:1] ResetCDR("SIP/100398-0841c0f0", "w") in new stack thirtythree*CLI> [Aug 22 17:09:49] DEBUG[31078]: pbx.c:1534 pbx_substitute_variables_helper_full: Function result is '"100398" <100398>' thirtythree*CLI> [Aug 22 17:09:49] DEBUG[31078]: pbx.c:1534 pbx_substitute_variables_helper_full: Function result is '100398' thirtythree*CLI> [Aug 22 17:09:49] DEBUG[31078]: pbx.c:1534 pbx_substitute_variables_helper_full: Function result is '100397' thirtythree*CLI> [Aug 22 17:09:49] DEBUG[31078]: pbx.c:1534 pbx_substitute_variables_helper_full: Function result is 'from-internal' thirtythree*CLI> [Aug 22 17:09:49] DEBUG[31078]: pbx.c:1534 pbx_substitute_variables_helper_full: Function result is 'SIP/100398-0841c0f0' thirtythree*CLI> [Aug 22 17:09:49] DEBUG[31078]: pbx.c:1534 pbx_substitute_variables_helper_full: Function result is 'SIP/100397-08430da8' thirtythree*CLI> [Aug 22 17:09:49] DEBUG[4240]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 100397 thirtythree*CLI> [Aug 22 17:09:49] DEBUG[4240]: chan_sip.c:14591 sip_devicestate: Checking device state for peer 100397 [Aug 22 17:09:49] DEBUG[31078]: pbx.c:1534 pbx_substitute_variables_helper_full: Function result is 'ResetCDR' [Aug 22 17:09:49] DEBUG[31078]: pbx.c:1534 pbx_substitute_variables_helper_full: Function result is 'w' thirtythree*CLI> [Aug 22 17:09:49] DEBUG[4240]: devicestate.c:287 do_state_change: Changing state for SIP/100397 - state 8 (On Hold) thirtythree*CLI> [Aug 22 17:09:49] DEBUG[31078]: pbx.c:1534 pbx_substitute_variables_helper_full: Function result is '2006-08-22 17:08:25' [Aug 22 17:09:49] DEBUG[31078]: pbx.c:1534 pbx_substitute_variables_helper_full: Function result is '2006-08-22 17:08:36' thirtythree*CLI> [Aug 22 17:09:49] DEBUG[4240]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 100397 thirtythree*CLI> [Aug 22 17:09:49] DEBUG[31078]: pbx.c:1534 pbx_substitute_variables_helper_full: Function result is '2006-08-22 17:09:49' [Aug 22 17:09:49] DEBUG[4240]: chan_sip.c:14591 sip_devicestate: Checking device state for peer 100397 thirtythree*CLI> [Aug 22 17:09:49] DEBUG[31086]: app_queue.c:536 changethread: Device 'SIP/100397' changed to state '8' (On Hold) but we don't care because they're not a member of any queue. thirtythree*CLI> [Aug 22 17:09:49] DEBUG[31078]: pbx.c:1534 pbx_substitute_variables_helper_full: Function result is '84' [Aug 22 17:09:49] DEBUG[31078]: pbx.c:1534 pbx_substitute_variables_helper_full: Function result is '73' [Aug 22 17:09:49] DEBUG[31078]: pbx.c:1534 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' [Aug 22 17:09:49] DEBUG[31078]: pbx.c:1534 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' [Aug 22 17:09:49] DEBUG[31078]: pbx.c:1534 pbx_substitute_variables_helper_full: Function result is '' [Aug 22 17:09:49] DEBUG[31078]: pbx.c:1534 pbx_substitute_variables_helper_full: Function result is '1156230505.4' [Aug 22 17:09:49] DEBUG[31078]: pbx.c:1534 pbx_substitute_variables_helper_full: Function result is '' [Aug 22 17:09:49] DEBUG[31078]: pbx.c:1680 pbx_extension_helper: Launching 'NoCDR' -- Executing [s@macro-hangupcall:2] NoCDR("SIP/100398-0841c0f0", "") in new stack [Aug 22 17:09:49] WARNING[31078]: cdr.c:422 ast_cdr_free: CDR on channel 'SIP/100398-0841c0f0' not posted [Aug 22 17:09:49] WARNING[31078]: cdr.c:424 ast_cdr_free: CDR on channel 'SIP/100398-0841c0f0' lacks end [Aug 22 17:09:49] DEBUG[31078]: pbx.c:1680 pbx_extension_helper: Launching 'Wait' -- Executing [s@macro-hangupcall:3] Wait("SIP/100398-0841c0f0", "5") in new stack [Aug 22 17:09:49] DEBUG[31078]: app_macro.c:244 _macro_exec: Spawn extension (macro-hangupcall,s,3) exited non-zero on 'SIP/100398-0841c0f0' in macro 'hangupcall' [Aug 22 17:09:49] DEBUG[31078]: pbx.c:2396 __ast_pbx_run: Spawn extension (macro-hangupcall,s,3) exited non-zero on 'SIP/100398-0841c0f0' [Aug 22 17:09:49] DEBUG[31078]: channel.c:1519 ast_hangup: Hanging up channel 'SIP/100398-0841c0f0' [Aug 22 17:09:49] DEBUG[31078]: chan_sip.c:3172 sip_hangup: Hangup call SIP/100398-0841c0f0, SIP callid e1b0a912-a7969d2c@203.82.162.21) thirtythree*CLI> [Aug 22 17:09:49] DEBUG[31078]: chan_sip.c:3180 sip_hangup: update_call_counter(100398) - decrement call limit counter on hangup [Aug 22 17:09:49] DEBUG[31078]: chan_sip.c:2871 update_call_counter: Updating call counter for incoming call [Aug 22 17:09:49] DEBUG[31078]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/100398-0841c0f0 [Aug 22 17:09:49] DEBUG[4240]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 100398 [Aug 22 17:09:49] DEBUG[4240]: chan_sip.c:14591 sip_devicestate: Checking device state for peer 100398 thirtythree*CLI> [Aug 22 17:09:49] DEBUG[4240]: devicestate.c:287 do_state_change: Changing state for SIP/100398 - state 8 (On Hold) thirtythree*CLI> [Aug 22 17:09:49] DEBUG[4240]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 100398 thirtythree*CLI> [Aug 22 17:09:49] DEBUG[4240]: chan_sip.c:14591 sip_devicestate: Checking device state for peer 100398 thirtythree*CLI> [Aug 22 17:09:49] DEBUG[31087]: app_queue.c:536 changethread: Device 'SIP/100398' changed to state '8' (On Hold) but we don't care because they're not a member of any queue. thirtythree*CLI> <-- SIP read from 203.82.162.20:5060: SIP/2.0 200 OK To: ;tag=f13d983b46d20034i0 From: "100398" ;tag=as2d4bf9db Call-ID: 73004854379bd13b1b7124bc3f4ec581@203.82.162.33 CSeq: 103 BYE Via: SIP/2.0/UDP 203.82.162.33:5060;branch=z9hG4bK70ce330d Server: Linksys/SPA2100-3.3.6 Content-Length: 0 thirtythree*CLI> [Aug 22 17:09:49] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 0: SIP/2.0 200 OK (14) [Aug 22 17:09:49] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 1: To: ;tag=f13d983b46d20034i0 (58) [Aug 22 17:09:49] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 2: From: "100398" ;tag=as2d4bf9db (56) thirtythree*CLI> [Aug 22 17:09:49] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 3: Call-ID: 73004854379bd13b1b7124bc3f4ec581@203.82.162.33 (55) [Aug 22 17:09:49] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 4: CSeq: 103 BYE (13) [Aug 22 17:09:49] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 5: Via: SIP/2.0/UDP 203.82.162.33:5060;branch=z9hG4bK70ce330d (58) thirtythree*CLI> [Aug 22 17:09:49] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 6: Server: Linksys/SPA2100-3.3.6 (29) [Aug 22 17:09:49] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 7: Content-Length: 0 (17) [Aug 22 17:09:49] DEBUG[4247]: chan_sip.c:4325 parse_request: Header 8: (0) --- (8 headers 0 lines) --- thirtythree*CLI> [Aug 22 17:09:49] DEBUG[4247]: chan_sip.c:1996 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #1163 [Aug 22 17:09:49] DEBUG[4247]: chan_sip.c:2006 __sip_ack: Stopping retransmission on '73004854379bd13b1b7124bc3f4ec581@203.82.162.33' of Request 103: Match Not Found Really destroying SIP dialog '73004854379bd13b1b7124bc3f4ec581@203.82.162.33' Method: ACK thirtythree*CLI> Really destroying SIP dialog 'e1b0a912-a7969d2c@203.82.162.21' Method: BYE thirtythree*CLI> exit ]0;root@thirtythree:~[root@thirtythree ~]# exasterisk -rc Asterisk SVN-trunk-r39706, Copyright (C) 1999 - 2006 Digium, Inc. and others. Created by Mark Spencer Asterisk comes with ABSOLUTELY NO WARRANTY; type 'show warranty' for details. This is free software, with components licensed under the GNU General Public License version 2 and other licenses; you are welcome to redistribute it under certain conditions. Type 'show license' for details. ========================================================================= [ Booting... [ Reading Master Configuration ] [ Initializing Custom Configuration Options ] Connected to Asterisk SVN-trunk-r39706 currently running on thirtythree (pid = 4236) thirtythree*CLI> -- Remote UNIX connection Verbosity is at least 4 thirtythree*CLI> sip bno debug thirtythree*CLI> SIP Debugging Disabled thirtythree*CLI> set verbose 0 thirtythree*CLI> Verbosity is now OFF thirtythree*CLI> set debug 0 thirtythree*CLI> Core debug is now OFF thirtythree*CLI> exit ]0;root@thirtythree:~[root@thirtythree ~]# exit logout