*CLI> *CLI> set debug 4 Core debug was 5 and is now 4 The 'set debug' command is deprecated and will be removed in a future release. Please use 'core set debug' instead. *CLI> set verbose 4 Verbosity was 5 and is now 4 The 'set verbose' command is deprecated and will be removed in a future release. Please use 'core set verbose' instead. *CLI> sip debug SIP Debugging enabled The 'sip debug' command is deprecated and will be removed in a future release. Please use 'sip set debug' instead. *CLI> [Dec 18 12:04:40] <--- SIP read from 192.168.1.12:5060 ---> PUBLISH sip:112@asterisk.lls.com SIP/2.0 Via: SIP/2.0/UDP 192.168.1.12:5060;branch=z9hG4bK-oo3je2e8hf96;rport From: "Russell <112>" ;tag=wedaw0bvfd To: "Russell <112>" Call-ID: 3c2a29a95f37-hhpinl3ot1hy@snom360-000413231B20 CSeq: 1 PUBLISH Max-Forwards: 70 Event: proxy-config Content-Type: application/text Content-Length: 0 <-------------> [Dec 18 12:04:40] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 0: PUBLISH sip:112@asterisk.lls.com SIP/2.0 (40) [Dec 18 12:04:40] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.12:5060;branch=z9hG4bK-oo3je2e8hf96;rport (68) [Dec 18 12:04:40] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 2: From: "Russell <112>" ;tag=wedaw0bvfd (63) [Dec 18 12:04:40] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 3: To: "Russell <112>" (46) [Dec 18 12:04:40] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 4: Call-ID: 3c2a29a95f37-hhpinl3ot1hy@snom360-000413231B20 (55) [Dec 18 12:04:40] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 5: CSeq: 1 PUBLISH (15) [Dec 18 12:04:40] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 6: Max-Forwards: 70 (16) [Dec 18 12:04:40] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 7: Event: proxy-config (19) [Dec 18 12:04:40] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 8: Content-Type: application/text (30) [Dec 18 12:04:40] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 9: Content-Length: 0 (17) [Dec 18 12:04:40] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 10: (0) [Dec 18 12:04:40] --- (10 headers 0 lines) --- [Dec 18 12:04:40] <--- Transmitting (no NAT) to 192.168.1.12:5060 ---> SIP/2.0 501 Method Not Implemented Via: SIP/2.0/UDP 192.168.1.12:5060;branch=z9hG4bK-oo3je2e8hf96;received=192.168.1.12;rport=5060 From: "Russell <112>" ;tag=wedaw0bvfd To: "Russell <112>" ;tag=as381b0fc6 Call-ID: 3c2a29a95f37-hhpinl3ot1hy@snom360-000413231B20 CSeq: 1 PUBLISH User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 <------------> [Dec 18 12:04:40] DEBUG[26961]: chan_sip.c:14631 sipsock_read: Invalid SIP message - rejected , no callid, len 391 [Dec 18 12:04:40] <--- SIP read from 192.168.1.12:5060 ---> PUBLISH sip:112@asterisk.lls.com SIP/2.0 Via: SIP/2.0/UDP 192.168.1.12:5060;branch=z9hG4bK-fttulatvgvcc;rport From: "Russell <112>" ;tag=ahs1c7fc7i To: "Russell <112>" Call-ID: 3c2a29a9aae6-hhbl546mm34c@snom360-000413231B20 CSeq: 1 PUBLISH Max-Forwards: 70 Event: proxy-config Content-Type: application/text Content-Length: 0 <-------------> [Dec 18 12:04:40] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 0: PUBLISH sip:112@asterisk.lls.com SIP/2.0 (40) [Dec 18 12:04:40] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.12:5060;branch=z9hG4bK-fttulatvgvcc;rport (68) [Dec 18 12:04:40] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 2: From: "Russell <112>" ;tag=ahs1c7fc7i (63) [Dec 18 12:04:40] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 3: To: "Russell <112>" (46) [Dec 18 12:04:40] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 4: Call-ID: 3c2a29a9aae6-hhbl546mm34c@snom360-000413231B20 (55) [Dec 18 12:04:40] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 5: CSeq: 1 PUBLISH (15) [Dec 18 12:04:40] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 6: Max-Forwards: 70 (16) [Dec 18 12:04:40] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 7: Event: proxy-config (19) [Dec 18 12:04:40] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 8: Content-Type: application/text (30) [Dec 18 12:04:40] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 9: Content-Length: 0 (17) [Dec 18 12:04:40] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 10: (0) [Dec 18 12:04:40] --- (10 headers 0 lines) --- [Dec 18 12:04:40] <--- Transmitting (no NAT) to 192.168.1.12:5060 ---> SIP/2.0 501 Method Not Implemented Via: SIP/2.0/UDP 192.168.1.12:5060;branch=z9hG4bK-fttulatvgvcc;received=192.168.1.12;rport=5060 From: "Russell <112>" ;tag=ahs1c7fc7i To: "Russell <112>" ;tag=as55614c4a Call-ID: 3c2a29a9aae6-hhbl546mm34c@snom360-000413231B20 CSeq: 1 PUBLISH User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 <------------> [Dec 18 12:04:40] DEBUG[26961]: chan_sip.c:14631 sipsock_read: Invalid SIP message - rejected , no callid, len 391 [Dec 18 12:04:41] <--- SIP read from 192.168.1.12:5060 ---> PUBLISH sip:112@asterisk.lls.com SIP/2.0 Via: SIP/2.0/UDP 192.168.1.12:5060;branch=z9hG4bK-kwqdrq8n28o3;rport From: "Russell <112>" ;tag=1u2xm9fyr4 To: "Russell <112>" Call-ID: 3c2a29aa30d4-01g67nucz85b@snom360-000413231B20 CSeq: 1 PUBLISH Max-Forwards: 70 Event: number-guessing Content-Type: application/text Content-Length: 26 Number: 114 Max-Hits: 3 <-------------> [Dec 18 12:04:41] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 0: PUBLISH sip:112@asterisk.lls.com SIP/2.0 (40) [Dec 18 12:04:41] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.12:5060;branch=z9hG4bK-kwqdrq8n28o3;rport (68) [Dec 18 12:04:41] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 2: From: "Russell <112>" ;tag=1u2xm9fyr4 (63) [Dec 18 12:04:41] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 3: To: "Russell <112>" (46) [Dec 18 12:04:41] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 4: Call-ID: 3c2a29aa30d4-01g67nucz85b@snom360-000413231B20 (55) [Dec 18 12:04:41] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 5: CSeq: 1 PUBLISH (15) [Dec 18 12:04:41] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 6: Max-Forwards: 70 (16) [Dec 18 12:04:41] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 7: Event: number-guessing (22) [Dec 18 12:04:41] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 8: Content-Type: application/text (30) [Dec 18 12:04:41] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 9: Content-Length: 26 (18) [Dec 18 12:04:41] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 10: (0) [Dec 18 12:04:41] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: Number: 114 (11) [Dec 18 12:04:41] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: Max-Hits: 3 (11) [Dec 18 12:04:41] --- (10 headers 2 lines) --- [Dec 18 12:04:41] <--- Transmitting (no NAT) to 192.168.1.12:5060 ---> SIP/2.0 501 Method Not Implemented Via: SIP/2.0/UDP 192.168.1.12:5060;branch=z9hG4bK-kwqdrq8n28o3;received=192.168.1.12;rport=5060 From: "Russell <112>" ;tag=1u2xm9fyr4 To: "Russell <112>" ;tag=as5fb8c255 Call-ID: 3c2a29aa30d4-01g67nucz85b@snom360-000413231B20 CSeq: 1 PUBLISH User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 <------------> [Dec 18 12:04:41] DEBUG[26961]: chan_sip.c:14631 sipsock_read: Invalid SIP message - rejected , no callid, len 421 [Dec 18 12:04:42] <--- SIP read from 192.168.1.12:5060 ---> INVITE sip:114@asterisk.lls.com SIP/2.0 Via: SIP/2.0/UDP 192.168.1.12:5060;branch=z9hG4bK-b6v2328eisbs;rport From: "Russell <112>" ;tag=b0il0llhg2 To: Call-ID: 3c2a29a9249f-6f6t96vpfbuu@snom360-000413231B20 CSeq: 1 INVITE Max-Forwards: 70 Contact: ;flow-id=1 P-Key-Flags: resolution="31x13", keys="4" User-Agent: snom360/6.5.1 Accept: application/sdp Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Supported: timer, 100rel, replaces, callerid Session-Expires: 3600;refresher=uas Min-SE: 90 Content-Type: application/sdp Content-Length: 310 v=0 o=root 474818365 474818365 IN IP4 192.168.1.12 s=call c=IN IP4 192.168.1.12 t=0 0 m=audio 61426 RTP/AVP 0 8 9 2 3 18 4 a=rtpmap:0 pcmu/8000 a=rtpmap:8 pcma/8000 a=rtpmap:9 g722/8000 a=rtpmap:2 g726-32/8000 a=rtpmap:3 gsm/8000 a=rtpmap:18 g729/8000 a=rtpmap:4 g723/8000 a=ptime:20 a=sendrecv <-------------> [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 0: INVITE sip:114@asterisk.lls.com SIP/2.0 (39) [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.12:5060;branch=z9hG4bK-b6v2328eisbs;rport (68) [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 2: From: "Russell <112>" ;tag=b0il0llhg2 (63) [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 3: To: (30) [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 4: Call-ID: 3c2a29a9249f-6f6t96vpfbuu@snom360-000413231B20 (55) [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 5: CSeq: 1 INVITE (14) [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 6: Max-Forwards: 70 (16) [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 7: Contact: ;flow-id=1 (60) [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 8: P-Key-Flags: resolution="31x13", keys="4" (41) [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 9: User-Agent: snom360/6.5.1 (25) [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 10: Accept: application/sdp (23) [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 11: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 12: Allow-Events: talk, hold, refer (31) [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 13: Supported: timer, 100rel, replaces, callerid (44) [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 14: Session-Expires: 3600;refresher=uas (35) [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 15: Min-SE: 90 (10) [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 16: Content-Type: application/sdp (29) [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 17: Content-Length: 310 (19) [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 18: (0) [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: v=0 (3) [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: o=root 474818365 474818365 IN IP4 192.168.1.12 (46) [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: s=call (6) [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: c=IN IP4 192.168.1.12 (21) [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: t=0 0 (5) [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: m=audio 61426 RTP/AVP 0 8 9 2 3 18 4 (36) [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: a=rtpmap:0 pcmu/8000 (20) [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: a=rtpmap:8 pcma/8000 (20) [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: a=rtpmap:9 g722/8000 (20) [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: a=rtpmap:2 g726-32/8000 (23) [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: a=rtpmap:3 gsm/8000 (19) [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: a=rtpmap:18 g729/8000 (21) [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: a=rtpmap:4 g723/8000 (20) [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: a=ptime:20 (10) [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: a=sendrecv (10) [Dec 18 12:04:42] --- (18 headers 15 lines) --- [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:2559 do_setnat: Setting NAT on RTP to Off [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:4264 sip_alloc: Allocating new SIP dialog for 3c2a29a9249f-6f6t96vpfbuu@snom360-000413231B20 - INVITE (With RTP) [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:14453 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:1662 parse_sip_options: Begin: parsing SIP "Supported: timer, 100rel, replaces, callerid" [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:1670 parse_sip_options: Found SIP option: -timer- [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:1676 parse_sip_options: Matched SIP option: timer [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:1670 parse_sip_options: Found SIP option: -100rel- [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:1676 parse_sip_options: Matched SIP option: 100rel [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:1670 parse_sip_options: Found SIP option: -replaces- [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:1676 parse_sip_options: Matched SIP option: replaces [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:1670 parse_sip_options: Found SIP option: -callerid- [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:1684 parse_sip_options: Found no match for SIP option: callerid (Please file bug report!) [Dec 18 12:04:42] Sending to 192.168.1.12 : 5060 (NAT) [Dec 18 12:04:42] Using INVITE request as basis request - 3c2a29a9249f-6f6t96vpfbuu@snom360-000413231B20 [Dec 18 12:04:42] Found peer '112' [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:2559 do_setnat: Setting NAT on RTP to Off [Dec 18 12:04:42] <--- Reliably Transmitting (no NAT) to 192.168.1.12:5060 ---> SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 192.168.1.12:5060;branch=z9hG4bK-b6v2328eisbs;received=192.168.1.12;rport=5060 From: "Russell <112>" ;tag=b0il0llhg2 To: ;tag=as1eece7b1 Call-ID: 3c2a29a9249f-6f6t96vpfbuu@snom360-000413231B20 CSeq: 1 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Proxy-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="5b93fb13" Content-Length: 0 <------------> [Dec 18 12:04:42] DEBUG[26961]: chan_sip.c:1957 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #22 [Dec 18 12:04:42] Scheduling destruction of SIP dialog '3c2a29a9249f-6f6t96vpfbuu@snom360-000413231B20' in 32000 ms (Method: INVITE) [Dec 18 12:04:43] <--- SIP read from 192.168.1.12:5060 ---> ACK sip:114@asterisk.lls.com SIP/2.0 Via: SIP/2.0/UDP 192.168.1.12:5060;branch=z9hG4bK-b6v2328eisbs;rport From: "Russell <112>" ;tag=b0il0llhg2 To: ;tag=as1eece7b1 Call-ID: 3c2a29a9249f-6f6t96vpfbuu@snom360-000413231B20 CSeq: 1 ACK Max-Forwards: 70 Contact: ;flow-id=1 Content-Length: 0 <-------------> [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 0: ACK sip:114@asterisk.lls.com SIP/2.0 (36) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.12:5060;branch=z9hG4bK-b6v2328eisbs;rport (68) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 2: From: "Russell <112>" ;tag=b0il0llhg2 (63) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 3: To: ;tag=as1eece7b1 (45) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 4: Call-ID: 3c2a29a9249f-6f6t96vpfbuu@snom360-000413231B20 (55) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 5: CSeq: 1 ACK (11) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 6: Max-Forwards: 70 (16) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 7: Contact: ;flow-id=1 (60) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 8: Content-Length: 0 (17) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 9: (0) [Dec 18 12:04:43] --- (9 headers 0 lines) --- [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:14453 handle_request: **** Received ACK (6) - Command in SIP ACK [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:2061 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #22 [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:2071 __sip_ack: Stopping retransmission on '3c2a29a9249f-6f6t96vpfbuu@snom360-000413231B20' of Response 1: Match Not Found [Dec 18 12:04:43] <--- SIP read from 192.168.1.12:5060 ---> INVITE sip:114@asterisk.lls.com SIP/2.0 Via: SIP/2.0/UDP 192.168.1.12:5060;branch=z9hG4bK-pm2iapais9y2;rport From: "Russell <112>" ;tag=b0il0llhg2 To: Call-ID: 3c2a29a9249f-6f6t96vpfbuu@snom360-000413231B20 CSeq: 2 INVITE Max-Forwards: 70 Contact: ;flow-id=1 P-Key-Flags: resolution="31x13", keys="4" User-Agent: snom360/6.5.1 Accept: application/sdp Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Supported: timer, 100rel, replaces, callerid Session-Expires: 3600;refresher=uas Min-SE: 90 Proxy-Authorization: Digest username="112",realm="asterisk",nonce="5b93fb13",uri="sip:114@asterisk.lls.com",response="5c214cab93b35fa503fe6dab19acc38c",algorithm=md5 Content-Type: application/sdp Content-Length: 310 v=0 o=root 474818365 474818365 IN IP4 192.168.1.12 s=call c=IN IP4 192.168.1.12 t=0 0 m=audio 61426 RTP/AVP 0 8 9 2 3 18 4 a=rtpmap:0 pcmu/8000 a=rtpmap:8 pcma/8000 a=rtpmap:9 g722/8000 a=rtpmap:2 g726-32/8000 a=rtpmap:3 gsm/8000 a=rtpmap:18 g729/8000 a=rtpmap:4 g723/8000 a=ptime:20 a=sendrecv <-------------> [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 0: INVITE sip:114@asterisk.lls.com SIP/2.0 (39) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.12:5060;branch=z9hG4bK-pm2iapais9y2;rport (68) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 2: From: "Russell <112>" ;tag=b0il0llhg2 (63) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 3: To: (30) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 4: Call-ID: 3c2a29a9249f-6f6t96vpfbuu@snom360-000413231B20 (55) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 5: CSeq: 2 INVITE (14) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 6: Max-Forwards: 70 (16) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 7: Contact: ;flow-id=1 (60) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 8: P-Key-Flags: resolution="31x13", keys="4" (41) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 9: User-Agent: snom360/6.5.1 (25) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 10: Accept: application/sdp (23) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 11: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 12: Allow-Events: talk, hold, refer (31) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 13: Supported: timer, 100rel, replaces, callerid (44) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 14: Session-Expires: 3600;refresher=uas (35) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 15: Min-SE: 90 (10) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 16: Proxy-Authorization: Digest username="112",realm="asterisk",nonce="5b93fb13",uri="sip:114@asterisk.lls.com",response="5c214cab93b35fa503fe6dab19acc38c",algorithm=md5 (165) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 17: Content-Type: application/sdp (29) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 18: Content-Length: 310 (19) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 19: (0) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: v=0 (3) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: o=root 474818365 474818365 IN IP4 192.168.1.12 (46) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: s=call (6) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: c=IN IP4 192.168.1.12 (21) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: t=0 0 (5) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: m=audio 61426 RTP/AVP 0 8 9 2 3 18 4 (36) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: a=rtpmap:0 pcmu/8000 (20) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: a=rtpmap:8 pcma/8000 (20) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: a=rtpmap:9 g722/8000 (20) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: a=rtpmap:2 g726-32/8000 (23) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: a=rtpmap:3 gsm/8000 (19) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: a=rtpmap:18 g729/8000 (21) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: a=rtpmap:4 g723/8000 (20) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: a=ptime:20 (10) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: a=sendrecv (10) [Dec 18 12:04:43] --- (19 headers 15 lines) --- [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:14453 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Dec 18 12:04:43] Sending to 192.168.1.12 : 5060 (NAT) [Dec 18 12:04:43] Using INVITE request as basis request - 3c2a29a9249f-6f6t96vpfbuu@snom360-000413231B20 [Dec 18 12:04:43] Found peer '112' [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:2559 do_setnat: Setting NAT on RTP to Off [Dec 18 12:04:43] Found RTP audio format 0 [Dec 18 12:04:43] Found RTP audio format 8 [Dec 18 12:04:43] Found RTP audio format 9 [Dec 18 12:04:43] Found RTP audio format 2 [Dec 18 12:04:43] Found RTP audio format 3 [Dec 18 12:04:43] Found RTP audio format 18 [Dec 18 12:04:43] Found RTP audio format 4 [Dec 18 12:04:43] Peer audio RTP is at port 192.168.1.12:61426 [Dec 18 12:04:43] Found description format pcmu for ID 0 [Dec 18 12:04:43] Found description format pcma for ID 8 [Dec 18 12:04:43] Found description format g722 for ID 9 [Dec 18 12:04:43] Found description format g726-32 for ID 2 [Dec 18 12:04:43] Found description format gsm for ID 3 [Dec 18 12:04:43] Found description format g729 for ID 18 [Dec 18 12:04:43] Found description format g723 for ID 4 [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:5068 process_sdp: T38 state changed to 0 on channel [Dec 18 12:04:43] Capabilities: us - 0x8 (alaw), peer - audio=0x190f (g723|gsm|ulaw|alaw|g726|g729|g722)/video=0x0 (nothing), combined - 0x8 (alaw) [Dec 18 12:04:43] Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) [Dec 18 12:04:43] Peer audio RTP is at port 192.168.1.12:61426 [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:5145 process_sdp: We're settling with these formats: 0x8 (alaw) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:13237 handle_request_invite: Checking SIP call limits for device 112 [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:2978 update_call_counter: Updating call counter for incoming call [Dec 18 12:04:43] Looking for 114 in from-sip (domain asterisk.lls.com) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:3766 sip_new: *** Our native formats are 0x8 (alaw) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:3767 sip_new: *** Joint capabilities are 0x8 (alaw) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:3768 sip_new: *** Our capabilities are 0x8 (alaw) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:3769 sip_new: *** AST_CODEC_CHOOSE formats are 0x8 (alaw) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:3792 sip_new: This channel will not be able to handle video. [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:7891 build_route: build_route: Contact hop: ;flow-id=1 [Dec 18 12:04:43] list_route: hop: [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:13310 handle_request_invite: SIP/112-00708ee0: New call is still down.... Trying... [Dec 18 12:04:43] <--- Transmitting (no NAT) to 192.168.1.12:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.1.12:5060;branch=z9hG4bK-pm2iapais9y2;received=192.168.1.12;rport=5060 From: "Russell <112>" ;tag=b0il0llhg2 To: Call-ID: 3c2a29a9249f-6f6t96vpfbuu@snom360-000413231B20 CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Dec 18 12:04:43] DEBUG[26961]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/112-00708ee0 [Dec 18 12:04:43] DEBUG[26944]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 112 [Dec 18 12:04:43] DEBUG[26944]: chan_sip.c:15048 sip_devicestate: Checking device state for peer 112 [Dec 18 12:04:43] DEBUG[26944]: devicestate.c:287 do_state_change: Changing state for SIP/112 - state 1 (Not in use) [Dec 18 12:04:43] DEBUG[26944]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 112 [Dec 18 12:04:43] DEBUG[26944]: chan_sip.c:15048 sip_devicestate: Checking device state for peer 112 [Dec 18 12:04:43] DEBUG[26944]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for IAX - 112 [Dec 18 12:04:43] DEBUG[26944]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 112 [Dec 18 12:04:43] DEBUG[26944]: chan_sip.c:15048 sip_devicestate: Checking device state for peer 112 [Dec 18 12:04:43] DEBUG[26971]: pbx.c:1767 pbx_extension_helper: Launching 'Macro' [Dec 18 12:04:43] -- Executing [114@from-sip:1] Macro("SIP/112-00708ee0", "stdsip||"Sip/114"") in new stack [Dec 18 12:04:43] DEBUG[26971]: pbx.c:1767 pbx_extension_helper: Launching 'Dial' [Dec 18 12:04:43] DEBUG[26972]: app_queue.c:546 changethread: Device 'SIP/112' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Dec 18 12:04:43] -- Executing [s@macro-stdsip:1] Dial("SIP/112-00708ee0", ""Sip/114"|10|Trt") in new stack [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:15106 sip_request_call: Asked to create a SIP channel with formats: 0x8 (alaw) [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:4264 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:2559 do_setnat: Setting NAT on RTP to Off [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:3766 sip_new: *** Our native formats are 0x8 (alaw) [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:3767 sip_new: *** Joint capabilities are 0x0 (nothing) [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:3768 sip_new: *** Our capabilities are 0x8 (alaw) [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:3769 sip_new: *** AST_CODEC_CHOOSE formats are 0x8 (alaw) [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:3771 sip_new: *** Our preferred formats from the incoming channel are 0x8 (alaw) [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:3792 sip_new: This channel will not be able to handle video. [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:16701 sip_set_rtp_peer: Early remote bridge setting SIP '6c26754c34bd37352e76a9ed62b36b98@192.168.1.13' - Sending media to 192.168.1.12 [Dec 18 12:04:43] DEBUG[26971]: rtp.c:1572 ast_rtp_make_compatible: Seeded SDP of 'SIP/114-0070ebe0' with that of 'SIP/112-00708ee0' [Dec 18 12:04:43] DEBUG[26971]: channel.c:3185 ast_channel_inherit_variables: Not copying variable STACK-macro-stdsip-s-1. [Dec 18 12:04:43] DEBUG[26971]: channel.c:3185 ast_channel_inherit_variables: Not copying variable MACRO_DEPTH. [Dec 18 12:04:43] DEBUG[26971]: channel.c:3185 ast_channel_inherit_variables: Not copying variable ARG2. [Dec 18 12:04:43] DEBUG[26971]: channel.c:3185 ast_channel_inherit_variables: Not copying variable ARG1. [Dec 18 12:04:43] DEBUG[26971]: channel.c:3185 ast_channel_inherit_variables: Not copying variable MACRO_PRIORITY. [Dec 18 12:04:43] DEBUG[26971]: channel.c:3185 ast_channel_inherit_variables: Not copying variable MACRO_CONTEXT. [Dec 18 12:04:43] DEBUG[26971]: channel.c:3185 ast_channel_inherit_variables: Not copying variable MACRO_EXTEN. [Dec 18 12:04:43] DEBUG[26971]: channel.c:3185 ast_channel_inherit_variables: Not copying variable STACK-from-sip-114-1. [Dec 18 12:04:43] DEBUG[26971]: channel.c:3185 ast_channel_inherit_variables: Not copying variable SIPCALLID. [Dec 18 12:04:43] DEBUG[26971]: channel.c:3185 ast_channel_inherit_variables: Not copying variable SIPUSERAGENT. [Dec 18 12:04:43] DEBUG[26971]: channel.c:3185 ast_channel_inherit_variables: Not copying variable SIPDOMAIN. [Dec 18 12:04:43] DEBUG[26971]: channel.c:3185 ast_channel_inherit_variables: Not copying variable SIPURI. [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:2812 sip_call: Outgoing Call for 114 [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:2978 update_call_counter: Updating call counter for outgoing call [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:2826 sip_call: Our T38 capability (0), joint T38 capability (0) [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:6122 add_sdp: ** Our capability: 0x8 (alaw) Video flag: False [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:6123 add_sdp: ** Our prefcodec: 0x8 (alaw) [Dec 18 12:04:43] Audio is at 192.168.1.13 port 18646 [Dec 18 12:04:43] Adding codec 0x8 (alaw) to SDP [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:6254 add_sdp: -- Done with adding codecs to SDP [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:6299 add_sdp: Done building SDP. Settling with this capability: 0x8 (alaw) [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:4527 parse_request: Header 0: INVITE sip:114@192.168.1.19:5060;line=jpw6wl0r SIP/2.0 (54) [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:4527 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.13:5060;branch=z9hG4bK49ff876c;rport (63) [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:4527 parse_request: Header 2: From: "Russell Brown" ;tag=as6ba21d96 (67) [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:4527 parse_request: Header 3: To: (45) [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:4527 parse_request: Header 4: Contact: (39) [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:4527 parse_request: Header 5: Call-ID: 6c26754c34bd37352e76a9ed62b36b98@192.168.1.13 (54) [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:4527 parse_request: Header 6: CSeq: 102 INVITE (16) [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:4527 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:4527 parse_request: Header 8: Max-Forwards: 70 (16) [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:4527 parse_request: Header 9: Date: Mon, 18 Dec 2006 12:04:43 GMT (35) [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:4527 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:4527 parse_request: Header 11: Supported: replaces (19) [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:4527 parse_request: Header 12: Content-Type: application/sdp (29) [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:4527 parse_request: Header 13: Content-Length: 184 (19) [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:4527 parse_request: Header 14: (0) [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:4559 parse_request: Line: v=0 (3) [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:4559 parse_request: Line: o=root 26938 26938 IN IP4 192.168.1.12 (38) [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:4559 parse_request: Line: s=session (9) [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:4559 parse_request: Line: c=IN IP4 192.168.1.12 (21) [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:4559 parse_request: Line: t=0 0 (5) [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:4559 parse_request: Line: m=audio 61426 RTP/AVP 8 (23) [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:4559 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:4559 parse_request: Line: a=silenceSupp:off - - - - (25) [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:4559 parse_request: Line: a=ptime:20 (10) [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:4559 parse_request: Line: a=sendrecv (10) [Dec 18 12:04:43] Reliably Transmitting (no NAT) to 192.168.1.19:5060: INVITE sip:114@192.168.1.19:5060;line=jpw6wl0r SIP/2.0 Via: SIP/2.0/UDP 192.168.1.13:5060;branch=z9hG4bK49ff876c;rport From: "Russell Brown" ;tag=as6ba21d96 To: Contact: Call-ID: 6c26754c34bd37352e76a9ed62b36b98@192.168.1.13 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Mon, 18 Dec 2006 12:04:43 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Type: application/sdp Content-Length: 184 v=0 o=root 26938 26938 IN IP4 192.168.1.12 s=session c=IN IP4 192.168.1.12 t=0 0 m=audio 61426 RTP/AVP 8 a=rtpmap:8 PCMA/8000 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Dec 18 12:04:43] DEBUG[26971]: chan_sip.c:1957 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #24 [Dec 18 12:04:43] -- Called 114 [Dec 18 12:04:43] <--- Transmitting (no NAT) to 192.168.1.12:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.1.12:5060;branch=z9hG4bK-pm2iapais9y2;received=192.168.1.12;rport=5060 From: "Russell <112>" ;tag=b0il0llhg2 To: ;tag=as623481be Call-ID: 3c2a29a9249f-6f6t96vpfbuu@snom360-000413231B20 CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Dec 18 12:04:43] <--- SIP read from 192.168.1.19:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.1.13:5060;branch=z9hG4bK49ff876c;rport=5060 From: "Russell Brown" ;tag=as6ba21d96 To: "Tim <114>" ;tag=juolbo8jqi Call-ID: 6c26754c34bd37352e76a9ed62b36b98@192.168.1.13 CSeq: 102 INVITE Contact: ;flow-id=1 Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Content-Length: 0 <-------------> [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 0: SIP/2.0 180 Ringing (19) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.13:5060;branch=z9hG4bK49ff876c;rport=5060 (68) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 2: From: "Russell Brown" ;tag=as6ba21d96 (67) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 3: To: "Tim <114>" ;tag=juolbo8jqi (72) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 4: Call-ID: 6c26754c34bd37352e76a9ed62b36b98@192.168.1.13 (54) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 5: CSeq: 102 INVITE (16) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 6: Contact: ;flow-id=1 (60) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 8: Allow-Events: talk, hold, refer (31) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 9: Content-Length: 0 (17) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 10: (0) [Dec 18 12:04:43] --- (10 headers 0 lines) --- [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:2104 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #24 - INVITE (got response) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:2113 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '6c26754c34bd37352e76a9ed62b36b98@192.168.1.13' Request 102: Found [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:11531 handle_response_invite: SIP response 180 to standard invite [Dec 18 12:04:43] DEBUG[26961]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/114-0070ebe0 [Dec 18 12:04:43] DEBUG[26944]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 114 [Dec 18 12:04:43] DEBUG[26944]: chan_sip.c:15048 sip_devicestate: Checking device state for peer 114 [Dec 18 12:04:43] DEBUG[26944]: devicestate.c:287 do_state_change: Changing state for SIP/114 - state 1 (Not in use) [Dec 18 12:04:43] -- SIP/114-0070ebe0 is ringing [Dec 18 12:04:43] DEBUG[26944]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 114 [Dec 18 12:04:43] DEBUG[26944]: chan_sip.c:15048 sip_devicestate: Checking device state for peer 114 [Dec 18 12:04:43] DEBUG[26944]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 114 [Dec 18 12:04:43] DEBUG[26944]: chan_sip.c:15048 sip_devicestate: Checking device state for peer 114 [Dec 18 12:04:43] DEBUG[26973]: app_queue.c:546 changethread: Device 'SIP/114' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Dec 18 12:04:43] <--- SIP read from 192.168.1.19:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.1.13:5060;branch=z9hG4bK49ff876c;rport=5060 From: "Russell Brown" ;tag=as6ba21d96 To: "Tim <114>" ;tag=juolbo8jqi Call-ID: 6c26754c34bd37352e76a9ed62b36b98@192.168.1.13 CSeq: 102 INVITE Contact: ;flow-id=1 Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Content-Length: 0 <-------------> [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 0: SIP/2.0 180 Ringing (19) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.13:5060;branch=z9hG4bK49ff876c;rport=5060 (68) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 2: From: "Russell Brown" ;tag=as6ba21d96 (67) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 3: To: "Tim <114>" ;tag=juolbo8jqi (72) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 4: Call-ID: 6c26754c34bd37352e76a9ed62b36b98@192.168.1.13 (54) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 5: CSeq: 102 INVITE (16) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 6: Contact: ;flow-id=1 (60) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 8: Allow-Events: talk, hold, refer (31) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 9: Content-Length: 0 (17) [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 10: (0) [Dec 18 12:04:43] --- (10 headers 0 lines) --- [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:2113 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '6c26754c34bd37352e76a9ed62b36b98@192.168.1.13' Request 102: Found [Dec 18 12:04:43] DEBUG[26961]: chan_sip.c:11531 handle_response_invite: SIP response 180 to standard invite [Dec 18 12:04:43] -- SIP/114-0070ebe0 is ringing [Dec 18 12:04:44] <--- SIP read from 192.168.1.19:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.1.13:5060;branch=z9hG4bK49ff876c;rport=5060 From: "Russell Brown" ;tag=as6ba21d96 To: "Tim <114>" ;tag=juolbo8jqi Call-ID: 6c26754c34bd37352e76a9ed62b36b98@192.168.1.13 CSeq: 102 INVITE Contact: ;flow-id=1 Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Content-Length: 0 <-------------> [Dec 18 12:04:44] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 0: SIP/2.0 180 Ringing (19) [Dec 18 12:04:44] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.13:5060;branch=z9hG4bK49ff876c;rport=5060 (68) [Dec 18 12:04:44] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 2: From: "Russell Brown" ;tag=as6ba21d96 (67) [Dec 18 12:04:44] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 3: To: "Tim <114>" ;tag=juolbo8jqi (72) [Dec 18 12:04:44] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 4: Call-ID: 6c26754c34bd37352e76a9ed62b36b98@192.168.1.13 (54) [Dec 18 12:04:44] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 5: CSeq: 102 INVITE (16) [Dec 18 12:04:44] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 6: Contact: ;flow-id=1 (60) [Dec 18 12:04:44] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Dec 18 12:04:44] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 8: Allow-Events: talk, hold, refer (31) [Dec 18 12:04:44] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 9: Content-Length: 0 (17) [Dec 18 12:04:44] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 10: (0) [Dec 18 12:04:44] --- (10 headers 0 lines) --- [Dec 18 12:04:44] DEBUG[26961]: chan_sip.c:2113 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '6c26754c34bd37352e76a9ed62b36b98@192.168.1.13' Request 102: Found [Dec 18 12:04:44] DEBUG[26961]: chan_sip.c:11531 handle_response_invite: SIP response 180 to standard invite [Dec 18 12:04:44] -- SIP/114-0070ebe0 is ringing [Dec 18 12:04:45] <--- SIP read from 192.168.1.19:5060 ---> SIP/2.0 200 Ok Via: SIP/2.0/UDP 192.168.1.13:5060;branch=z9hG4bK49ff876c;rport=5060 From: "Russell Brown" ;tag=as6ba21d96 To: "Tim <114>" ;tag=juolbo8jqi Call-ID: 6c26754c34bd37352e76a9ed62b36b98@192.168.1.13 CSeq: 102 INVITE Contact: ;flow-id=1 User-Agent: snom300/6.5.1 Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Supported: timer, 100rel, replaces, callerid Content-Type: application/sdp Content-Length: 162 v=0 o=root 177845956 177845957 IN IP4 192.168.1.19 s=call c=IN IP4 192.168.1.19 t=0 0 m=audio 59226 RTP/AVP 8 a=rtpmap:8 pcma/8000 a=ptime:20 a=sendrecv <-------------> [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 0: SIP/2.0 200 Ok (14) [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.13:5060;branch=z9hG4bK49ff876c;rport=5060 (68) [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 2: From: "Russell Brown" ;tag=as6ba21d96 (67) [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 3: To: "Tim <114>" ;tag=juolbo8jqi (72) [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 4: Call-ID: 6c26754c34bd37352e76a9ed62b36b98@192.168.1.13 (54) [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 5: CSeq: 102 INVITE (16) [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 6: Contact: ;flow-id=1 (60) [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 7: User-Agent: snom300/6.5.1 (25) [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 8: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 9: Allow-Events: talk, hold, refer (31) [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 10: Supported: timer, 100rel, replaces, callerid (44) [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 11: Content-Type: application/sdp (29) [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 12: Content-Length: 162 (19) [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 13: (0) [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: v=0 (3) [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: o=root 177845956 177845957 IN IP4 192.168.1.19 (46) [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: s=call (6) [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: c=IN IP4 192.168.1.19 (21) [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: t=0 0 (5) [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: m=audio 59226 RTP/AVP 8 (23) [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: a=rtpmap:8 pcma/8000 (20) [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: a=ptime:20 (10) [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: a=sendrecv (10) [Dec 18 12:04:45] --- (13 headers 9 lines) --- [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:2053 __sip_ack: Acked pending invite 102 [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:2071 __sip_ack: Stopping retransmission on '6c26754c34bd37352e76a9ed62b36b98@192.168.1.13' of Request 102: Match Not Found [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:11531 handle_response_invite: SIP response 200 to standard invite [Dec 18 12:04:45] Found RTP audio format 8 [Dec 18 12:04:45] Peer audio RTP is at port 192.168.1.19:59226 [Dec 18 12:04:45] Found description format pcma for ID 8 [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:5068 process_sdp: T38 state changed to 0 on channel SIP/114-0070ebe0 [Dec 18 12:04:45] Capabilities: us - 0x8 (alaw), peer - audio=0x8 (alaw)/video=0x0 (nothing), combined - 0x8 (alaw) [Dec 18 12:04:45] Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) [Dec 18 12:04:45] Peer audio RTP is at port 192.168.1.19:59226 [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:5145 process_sdp: We're settling with these formats: 0x8 (alaw) [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:5152 process_sdp: We have an owner, now see if we need to change this call [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:2978 update_call_counter: Updating call counter for outgoing call [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:7891 build_route: build_route: Contact hop: ;flow-id=1 [Dec 18 12:04:45] list_route: hop: [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:5576 reqprep: Strict routing enforced for session 6c26754c34bd37352e76a9ed62b36b98@192.168.1.13 [Dec 18 12:04:45] set_destination: Parsing for address/port to send to [Dec 18 12:04:45] set_destination: set destination to 192.168.1.19, port 5060 [Dec 18 12:04:45] Transmitting (no NAT) to 192.168.1.19:5060: ACK sip:114@192.168.1.19:5060;line=jpw6wl0r SIP/2.0 Via: SIP/2.0/UDP 192.168.1.13:5060;branch=z9hG4bK21098a23;rport From: "Russell Brown" ;tag=as6ba21d96 To: ;tag=juolbo8jqi Contact: Call-ID: 6c26754c34bd37352e76a9ed62b36b98@192.168.1.13 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Dec 18 12:04:45] DEBUG[26971]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/114-0070ebe0 [Dec 18 12:04:45] DEBUG[26944]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 114 [Dec 18 12:04:45] DEBUG[26944]: chan_sip.c:15048 sip_devicestate: Checking device state for peer 114 [Dec 18 12:04:45] DEBUG[26944]: devicestate.c:287 do_state_change: Changing state for SIP/114 - state 1 (Not in use) [Dec 18 12:04:45] DEBUG[26944]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 114 [Dec 18 12:04:45] DEBUG[26944]: chan_sip.c:15048 sip_devicestate: Checking device state for peer 114 [Dec 18 12:04:45] -- SIP/114-0070ebe0 answered SIP/112-00708ee0 [Dec 18 12:04:45] DEBUG[26971]: chan_sip.c:16701 sip_set_rtp_peer: Early remote bridge setting SIP '3c2a29a9249f-6f6t96vpfbuu@snom360-000413231B20' - Sending media to 192.168.1.19 [Dec 18 12:04:45] DEBUG[26971]: rtp.c:1507 ast_rtp_early_bridge: Setting early bridge SDP of 'SIP/112-00708ee0' with that of 'SIP/114-0070ebe0' [Dec 18 12:04:45] DEBUG[26971]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/112-00708ee0 [Dec 18 12:04:45] DEBUG[26971]: chan_sip.c:3428 sip_answer: SIP answering channel: SIP/112-00708ee0 [Dec 18 12:04:45] DEBUG[26971]: chan_sip.c:6354 transmit_response_with_sdp: Setting framing from config on incoming call [Dec 18 12:04:45] DEBUG[26971]: chan_sip.c:6122 add_sdp: ** Our capability: 0x8 (alaw) Video flag: True [Dec 18 12:04:45] DEBUG[26971]: chan_sip.c:6123 add_sdp: ** Our prefcodec: 0x0 (nothing) [Dec 18 12:04:45] Audio is at 192.168.1.13 port 16928 [Dec 18 12:04:45] Adding codec 0x8 (alaw) to SDP [Dec 18 12:04:45] DEBUG[26971]: chan_sip.c:6254 add_sdp: -- Done with adding codecs to SDP [Dec 18 12:04:45] DEBUG[26971]: chan_sip.c:6299 add_sdp: Done building SDP. Settling with this capability: 0x8 (alaw) [Dec 18 12:04:45] <--- Reliably Transmitting (no NAT) to 192.168.1.12:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.12:5060;branch=z9hG4bK-pm2iapais9y2;received=192.168.1.12;rport=5060 From: "Russell <112>" ;tag=b0il0llhg2 To: ;tag=as623481be Call-ID: 3c2a29a9249f-6f6t96vpfbuu@snom360-000413231B20 CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 184 v=0 o=root 26938 26938 IN IP4 192.168.1.19 s=session c=IN IP4 192.168.1.19 t=0 0 m=audio 59226 RTP/AVP 8 a=rtpmap:8 PCMA/8000 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <------------> [Dec 18 12:04:45] DEBUG[26971]: chan_sip.c:1957 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #26 [Dec 18 12:04:45] DEBUG[26974]: app_queue.c:546 changethread: Device 'SIP/114' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Dec 18 12:04:45] DEBUG[26944]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 114 [Dec 18 12:04:45] DEBUG[26944]: chan_sip.c:15048 sip_devicestate: Checking device state for peer 114 [Dec 18 12:04:45] DEBUG[26944]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 112 [Dec 18 12:04:45] DEBUG[26944]: chan_sip.c:15048 sip_devicestate: Checking device state for peer 112 [Dec 18 12:04:45] DEBUG[26944]: devicestate.c:287 do_state_change: Changing state for SIP/112 - state 1 (Not in use) [Dec 18 12:04:45] DEBUG[26944]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 112 [Dec 18 12:04:45] DEBUG[26944]: chan_sip.c:15048 sip_devicestate: Checking device state for peer 112 [Dec 18 12:04:45] DEBUG[26944]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for IAX - 112 [Dec 18 12:04:45] DEBUG[26944]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 112 [Dec 18 12:04:45] DEBUG[26944]: chan_sip.c:15048 sip_devicestate: Checking device state for peer 112 [Dec 18 12:04:45] DEBUG[26975]: app_queue.c:546 changethread: Device 'SIP/112' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Dec 18 12:04:45] <--- SIP read from 192.168.1.12:5060 ---> ACK sip:114@192.168.1.13 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.12:5060;branch=z9hG4bK-avrszqnp5ps7;rport From: "Russell <112>" ;tag=b0il0llhg2 To: ;tag=as623481be Call-ID: 3c2a29a9249f-6f6t96vpfbuu@snom360-000413231B20 CSeq: 2 ACK Max-Forwards: 70 Contact: ;flow-id=1 Content-Length: 0 <-------------> [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 0: ACK sip:114@192.168.1.13 SIP/2.0 (32) [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.12:5060;branch=z9hG4bK-avrszqnp5ps7;rport (68) [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 2: From: "Russell <112>" ;tag=b0il0llhg2 (63) [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 3: To: ;tag=as623481be (45) [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 4: Call-ID: 3c2a29a9249f-6f6t96vpfbuu@snom360-000413231B20 (55) [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 5: CSeq: 2 ACK (11) [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 6: Max-Forwards: 70 (16) [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 7: Contact: ;flow-id=1 (60) [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 8: Content-Length: 0 (17) [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 9: (0) [Dec 18 12:04:45] --- (9 headers 0 lines) --- [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:14453 handle_request: **** Received ACK (6) - Command in SIP ACK [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:2061 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #26 [Dec 18 12:04:45] DEBUG[26961]: chan_sip.c:2071 __sip_ack: Stopping retransmission on '3c2a29a9249f-6f6t96vpfbuu@snom360-000413231B20' of Response 2: Match Not Found [Dec 18 12:04:47] <--- SIP read from 192.168.1.12:5060 ---> INFO sip:114@192.168.1.13 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.12:5060;branch=z9hG4bK-h79921jon1ic;rport From: "Russell <112>" ;tag=b0il0llhg2 To: ;tag=as623481be Call-ID: 3c2a29a9249f-6f6t96vpfbuu@snom360-000413231B20 CSeq: 3 INFO Max-Forwards: 70 Contact: ;flow-id=1 User-Agent: snom360/6.5.1 Content-Type: application/dtmf-relay Content-Length: 26 Signal=* Duration=1065280 <-------------> [Dec 18 12:04:47] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 0: INFO sip:114@192.168.1.13 SIP/2.0 (33) [Dec 18 12:04:47] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.12:5060;branch=z9hG4bK-h79921jon1ic;rport (68) [Dec 18 12:04:47] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 2: From: "Russell <112>" ;tag=b0il0llhg2 (63) [Dec 18 12:04:47] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 3: To: ;tag=as623481be (45) [Dec 18 12:04:47] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 4: Call-ID: 3c2a29a9249f-6f6t96vpfbuu@snom360-000413231B20 (55) [Dec 18 12:04:47] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 5: CSeq: 3 INFO (12) [Dec 18 12:04:47] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 6: Max-Forwards: 70 (16) [Dec 18 12:04:47] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 7: Contact: ;flow-id=1 (60) [Dec 18 12:04:47] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 8: User-Agent: snom360/6.5.1 (25) [Dec 18 12:04:47] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 9: Content-Type: application/dtmf-relay (36) [Dec 18 12:04:47] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 10: Content-Length: 26 (18) [Dec 18 12:04:47] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 11: (0) [Dec 18 12:04:47] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: Signal=* (8) [Dec 18 12:04:47] --- (11 headers 2 lines) --- [Dec 18 12:04:47] DEBUG[26961]: chan_sip.c:14453 handle_request: **** Received INFO (13) - Command in SIP INFO [Dec 18 12:04:47] Receiving INFO! [Dec 18 12:04:47] * DTMF-relay event received: * [Dec 18 12:04:47] <--- Transmitting (no NAT) to 192.168.1.12:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.12:5060;branch=z9hG4bK-h79921jon1ic;received=192.168.1.12;rport=5060 From: "Russell <112>" ;tag=b0il0llhg2 To: ;tag=as623481be Call-ID: 3c2a29a9249f-6f6t96vpfbuu@snom360-000413231B20 CSeq: 3 INFO User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Dec 18 12:04:47] DTMF[26971]: channel.c:2128 __ast_read: DTMF end '*' received on SIP/112-00708ee0 [Dec 18 12:04:47] DEBUG[26971]: channel.c:3726 ast_generic_bridge: Got DTMF begin on channel (SIP/112-00708ee0) [Dec 18 12:04:47] DEBUG[26971]: channel.c:3990 ast_channel_bridge: Bridge stops bridging channels SIP/112-00708ee0 and SIP/114-0070ebe0 [Dec 18 12:04:50] <--- SIP read from 192.168.1.12:5060 ---> INFO sip:114@192.168.1.13 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.12:5060;branch=z9hG4bK-bl453qbe536o;rport From: "Russell <112>" ;tag=b0il0llhg2 To: ;tag=as623481be Call-ID: 3c2a29a9249f-6f6t96vpfbuu@snom360-000413231B20 CSeq: 4 INFO Max-Forwards: 70 Contact: ;flow-id=1 User-Agent: snom360/6.5.1 Content-Type: application/dtmf-relay Content-Length: 22 Signal=# Duration=160 <-------------> [Dec 18 12:04:50] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 0: INFO sip:114@192.168.1.13 SIP/2.0 (33) [Dec 18 12:04:50] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.12:5060;branch=z9hG4bK-bl453qbe536o;rport (68) [Dec 18 12:04:50] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 2: From: "Russell <112>" ;tag=b0il0llhg2 (63) [Dec 18 12:04:50] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 3: To: ;tag=as623481be (45) [Dec 18 12:04:50] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 4: Call-ID: 3c2a29a9249f-6f6t96vpfbuu@snom360-000413231B20 (55) [Dec 18 12:04:50] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 5: CSeq: 4 INFO (12) [Dec 18 12:04:50] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 6: Max-Forwards: 70 (16) [Dec 18 12:04:50] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 7: Contact: ;flow-id=1 (60) [Dec 18 12:04:50] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 8: User-Agent: snom360/6.5.1 (25) [Dec 18 12:04:50] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 9: Content-Type: application/dtmf-relay (36) [Dec 18 12:04:50] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 10: Content-Length: 22 (18) [Dec 18 12:04:50] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 11: (0) [Dec 18 12:04:50] DEBUG[26961]: chan_sip.c:4559 parse_request: Line: Signal=# (8) [Dec 18 12:04:50] --- (11 headers 2 lines) --- [Dec 18 12:04:50] DEBUG[26961]: chan_sip.c:14453 handle_request: **** Received INFO (13) - Command in SIP INFO [Dec 18 12:04:50] Receiving INFO! [Dec 18 12:04:50] * DTMF-relay event received: # [Dec 18 12:04:50] <--- Transmitting (no NAT) to 192.168.1.12:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.12:5060;branch=z9hG4bK-bl453qbe536o;received=192.168.1.12;rport=5060 From: "Russell <112>" ;tag=b0il0llhg2 To: ;tag=as623481be Call-ID: 3c2a29a9249f-6f6t96vpfbuu@snom360-000413231B20 CSeq: 4 INFO User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Dec 18 12:04:50] DTMF[26971]: channel.c:2128 __ast_read: DTMF end '#' received on SIP/112-00708ee0 [Dec 18 12:04:55] <--- SIP read from 192.168.1.12:5060 ---> BYE sip:114@192.168.1.13 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.12:5060;branch=z9hG4bK-ttdi369kxiez;rport From: "Russell <112>" ;tag=b0il0llhg2 To: ;tag=as623481be Call-ID: 3c2a29a9249f-6f6t96vpfbuu@snom360-000413231B20 CSeq: 5 BYE Max-Forwards: 70 Contact: ;flow-id=1 User-Agent: snom360/6.5.1 RTP-RxStat: Total_Rx_Pkts=454,Rx_Pkts=454,Rx_Pkts_Lost=0,Remote_Rx_Pkts_Lost=0 RTP-TxStat: Total_Tx_Pkts=448,Tx_Pkts=448,Remote_Tx_Pkts=240 Content-Length: 0 <-------------> [Dec 18 12:04:55] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 0: BYE sip:114@192.168.1.13 SIP/2.0 (32) [Dec 18 12:04:55] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.12:5060;branch=z9hG4bK-ttdi369kxiez;rport (68) [Dec 18 12:04:55] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 2: From: "Russell <112>" ;tag=b0il0llhg2 (63) [Dec 18 12:04:55] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 3: To: ;tag=as623481be (45) [Dec 18 12:04:55] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 4: Call-ID: 3c2a29a9249f-6f6t96vpfbuu@snom360-000413231B20 (55) [Dec 18 12:04:55] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 5: CSeq: 5 BYE (11) [Dec 18 12:04:55] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 6: Max-Forwards: 70 (16) [Dec 18 12:04:55] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 7: Contact: ;flow-id=1 (60) [Dec 18 12:04:55] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 8: User-Agent: snom360/6.5.1 (25) [Dec 18 12:04:55] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 9: RTP-RxStat: Total_Rx_Pkts=454,Rx_Pkts=454,Rx_Pkts_Lost=0,Remote_Rx_Pkts_Lost=0 (78) [Dec 18 12:04:55] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 10: RTP-TxStat: Total_Tx_Pkts=448,Tx_Pkts=448,Remote_Tx_Pkts=240 (60) [Dec 18 12:04:55] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 11: Content-Length: 0 (17) [Dec 18 12:04:55] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 12: (0) [Dec 18 12:04:55] --- (12 headers 0 lines) --- [Dec 18 12:04:55] DEBUG[26961]: chan_sip.c:14453 handle_request: **** Received BYE (8) - Command in SIP BYE [Dec 18 12:04:55] Sending to 192.168.1.12 : 5060 (NAT) [Dec 18 12:04:55] DEBUG[26961]: chan_sip.c:1615 sip_alreadygone: Setting SIP_ALREADYGONE on dialog 3c2a29a9249f-6f6t96vpfbuu@snom360-000413231B20 [Dec 18 12:04:55] DEBUG[26961]: chan_sip.c:14030 handle_request_bye: Received bye, issuing owner hangup .[Dec 18 12:04:55] <--- Transmitting (NAT) to 192.168.1.12:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.12:5060;branch=z9hG4bK-ttdi369kxiez;received=192.168.1.12;rport=5060 From: "Russell <112>" ;tag=b0il0llhg2 To: ;tag=as623481be Call-ID: 3c2a29a9249f-6f6t96vpfbuu@snom360-000413231B20 CSeq: 5 BYE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Dec 18 12:04:55] DEBUG[26971]: channel.c:3682 ast_generic_bridge: Didn't get a frame from channel: SIP/112-00708ee0 [Dec 18 12:04:55] DEBUG[26971]: channel.c:3990 ast_channel_bridge: Bridge stops bridging channels SIP/112-00708ee0 and SIP/114-0070ebe0 [Dec 18 12:04:55] DEBUG[26971]: channel.c:1606 ast_hangup: Hanging up channel 'SIP/114-0070ebe0' [Dec 18 12:04:55] DEBUG[26971]: chan_sip.c:3278 sip_hangup: Hangup call SIP/114-0070ebe0, SIP callid 6c26754c34bd37352e76a9ed62b36b98@192.168.1.13) [Dec 18 12:04:55] DEBUG[26971]: chan_sip.c:3286 sip_hangup: update_call_counter(114) - decrement call limit counter on hangup [Dec 18 12:04:55] DEBUG[26971]: chan_sip.c:2978 update_call_counter: Updating call counter for outgoing call [Dec 18 12:04:55] Scheduling destruction of SIP dialog '6c26754c34bd37352e76a9ed62b36b98@192.168.1.13' in 32000 ms (Method: INVITE) [Dec 18 12:04:55] DEBUG[26971]: chan_sip.c:5576 reqprep: Strict routing enforced for session 6c26754c34bd37352e76a9ed62b36b98@192.168.1.13 [Dec 18 12:04:55] set_destination: Parsing for address/port to send to [Dec 18 12:04:55] set_destination: set destination to 192.168.1.19, port 5060 [Dec 18 12:04:55] Reliably Transmitting (no NAT) to 192.168.1.19:5060: BYE sip:114@192.168.1.19:5060;line=jpw6wl0r SIP/2.0 Via: SIP/2.0/UDP 192.168.1.13:5060;branch=z9hG4bK5529f826;rport From: "Russell Brown" ;tag=as6ba21d96 To: ;tag=juolbo8jqi Call-ID: 6c26754c34bd37352e76a9ed62b36b98@192.168.1.13 CSeq: 103 BYE User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Dec 18 12:04:55] DEBUG[26971]: chan_sip.c:1957 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #28 [Dec 18 12:04:55] DEBUG[26971]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/114-0070ebe0 [Dec 18 12:04:55] DEBUG[26971]: rtp.c:1467 ast_rtp_early_bridge: Channel '' has no RTP, not doing anything [Dec 18 12:04:55] DEBUG[26971]: app_dial.c:1640 dial_exec_full: Exiting with DIALSTATUS=ANSWER. [Dec 18 12:04:55] DEBUG[26971]: app_macro.c:253 _macro_exec: Spawn extension (macro-stdsip,s,1) exited non-zero on 'SIP/112-00708ee0' in macro 'stdsip' [Dec 18 12:04:55] DEBUG[26971]: pbx.c:2363 __ast_pbx_run: Spawn extension (macro-stdsip,s,1) exited non-zero on 'SIP/112-00708ee0' [Dec 18 12:04:55] == Spawn extension (macro-stdsip, s, 1) exited non-zero on 'SIP/112-00708ee0' [Dec 18 12:04:55] DEBUG[26944]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 114 [Dec 18 12:04:55] DEBUG[26971]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '"Russell Brown" <01780471802>' [Dec 18 12:04:55] DEBUG[26944]: chan_sip.c:15048 sip_devicestate: Checking device state for peer 114 [Dec 18 12:04:55] DEBUG[26971]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '01780471802' [Dec 18 12:04:55] DEBUG[26944]: devicestate.c:287 do_state_change: Changing state for SIP/114 - state 1 (Not in use) [Dec 18 12:04:55] DEBUG[26971]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '114' [Dec 18 12:04:55] DEBUG[26976]: app_queue.c:546 changethread: Device 'SIP/114' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Dec 18 12:04:55] DEBUG[26944]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 114 [Dec 18 12:04:55] DEBUG[26944]: chan_sip.c:15048 sip_devicestate: Checking device state for peer 114 [Dec 18 12:04:55] DEBUG[26944]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 114 [Dec 18 12:04:55] DEBUG[26944]: chan_sip.c:15048 sip_devicestate: Checking device state for peer 114 [Dec 18 12:04:55] DEBUG[26971]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'from-sip' [Dec 18 12:04:55] DEBUG[26971]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/112-00708ee0' [Dec 18 12:04:55] DEBUG[26971]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/114-0070ebe0' [Dec 18 12:04:55] DEBUG[26971]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'Dial' [Dec 18 12:04:55] DEBUG[26971]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '"Sip/114"|10|Trt' [Dec 18 12:04:55] DEBUG[26971]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-12-18 12:04:43' [Dec 18 12:04:55] DEBUG[26971]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-12-18 12:04:45' [Dec 18 12:04:55] DEBUG[26971]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-12-18 12:04:55' [Dec 18 12:04:55] DEBUG[26971]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '12' [Dec 18 12:04:55] DEBUG[26971]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '10' [Dec 18 12:04:55] DEBUG[26971]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' [Dec 18 12:04:55] DEBUG[26971]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' [Dec 18 12:04:55] DEBUG[26971]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '' [Dec 18 12:04:55] DEBUG[26971]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '1166443483.0' [Dec 18 12:04:55] DEBUG[26971]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '' [Dec 18 12:04:55] DEBUG[26971]: channel.c:1606 ast_hangup: Hanging up channel 'SIP/112-00708ee0' [Dec 18 12:04:55] DEBUG[26971]: chan_sip.c:3278 sip_hangup: Hangup call SIP/112-00708ee0, SIP callid 3c2a29a9249f-6f6t96vpfbuu@snom360-000413231B20) [Dec 18 12:04:55] DEBUG[26971]: chan_sip.c:3286 sip_hangup: update_call_counter(112) - decrement call limit counter on hangup [Dec 18 12:04:55] DEBUG[26971]: chan_sip.c:2978 update_call_counter: Updating call counter for incoming call [Dec 18 12:04:55] DEBUG[26971]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/112-00708ee0 [Dec 18 12:04:55] DEBUG[26944]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 112 [Dec 18 12:04:55] DEBUG[26944]: chan_sip.c:15048 sip_devicestate: Checking device state for peer 112 [Dec 18 12:04:55] DEBUG[26944]: devicestate.c:287 do_state_change: Changing state for SIP/112 - state 1 (Not in use) [Dec 18 12:04:55] DEBUG[26944]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 112 [Dec 18 12:04:55] DEBUG[26944]: chan_sip.c:15048 sip_devicestate: Checking device state for peer 112 [Dec 18 12:04:55] DEBUG[26944]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for IAX - 112 [Dec 18 12:04:55] DEBUG[26944]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 112 [Dec 18 12:04:55] DEBUG[26944]: chan_sip.c:15048 sip_devicestate: Checking device state for peer 112 [Dec 18 12:04:55] DEBUG[26977]: app_queue.c:546 changethread: Device 'SIP/112' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Dec 18 12:04:56] <--- SIP read from 192.168.1.19:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.13:5060;branch=z9hG4bK5529f826;rport=5060 From: "Russell Brown" ;tag=as6ba21d96 To: "Tim <114>" ;tag=juolbo8jqi Call-ID: 6c26754c34bd37352e76a9ed62b36b98@192.168.1.13 CSeq: 103 BYE Contact: ;flow-id=1 User-Agent: snom300/6.5.1 RTP-RxStat: Total_Rx_Pkts=448,Rx_Pkts=448,Rx_Pkts_Lost=0,Remote_Rx_Pkts_Lost=0 RTP-TxStat: Total_Tx_Pkts=480,Tx_Pkts=480,Remote_Tx_Pkts=241 Content-Length: 0 <-------------> [Dec 18 12:04:56] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 0: SIP/2.0 200 OK (14) [Dec 18 12:04:56] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.13:5060;branch=z9hG4bK5529f826;rport=5060 (68) [Dec 18 12:04:56] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 2: From: "Russell Brown" ;tag=as6ba21d96 (67) [Dec 18 12:04:56] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 3: To: "Tim <114>" ;tag=juolbo8jqi (72) [Dec 18 12:04:56] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 4: Call-ID: 6c26754c34bd37352e76a9ed62b36b98@192.168.1.13 (54) [Dec 18 12:04:56] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 5: CSeq: 103 BYE (13) [Dec 18 12:04:56] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 6: Contact: ;flow-id=1 (60) [Dec 18 12:04:56] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 7: User-Agent: snom300/6.5.1 (25) [Dec 18 12:04:56] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 8: RTP-RxStat: Total_Rx_Pkts=448,Rx_Pkts=448,Rx_Pkts_Lost=0,Remote_Rx_Pkts_Lost=0 (78) [Dec 18 12:04:56] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 9: RTP-TxStat: Total_Tx_Pkts=480,Tx_Pkts=480,Remote_Tx_Pkts=241 (60) [Dec 18 12:04:56] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 10: Content-Length: 0 (17) [Dec 18 12:04:56] DEBUG[26961]: chan_sip.c:4527 parse_request: Header 11: (0) [Dec 18 12:04:56] --- (11 headers 0 lines) --- [Dec 18 12:04:56] DEBUG[26961]: chan_sip.c:2061 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #28 [Dec 18 12:04:56] DEBUG[26961]: chan_sip.c:2071 __sip_ack: Stopping retransmission on '6c26754c34bd37352e76a9ed62b36b98@192.168.1.13' of Request 103: Match Not Found [Dec 18 12:04:56] Really destroying SIP dialog '6c26754c34bd37352e76a9ed62b36b98@192.168.1.13' Method: INVITE [Dec 18 12:04:56] Really destroying SIP dialog '3c2a29a9249f-6f6t96vpfbuu@snom360-000413231B20' Method: BYE *CLI> stop now [Dec 18 12:05:04] Beginning asterisk shutdown.... [Dec 18 12:05:04] Executing last minute cleanups [Dec 18 12:05:04] == Destroying musiconhold processes [Dec 18 12:05:04] Asterisk cleanly ending (0). [Dec 18 12:05:04] DEBUG[26938]: asterisk.c:1193 quit_handler: Asterisk ending (0).