Dec 25 18:08:54 VERBOSE[31019] logger.c: <-- SIP read from 192.168.254.1:8917: REGISTER sip:cojensen.net SIP/2.0 Via: SIP/2.0/UDP 192.168.254.60:8917;branch=z9hG4bK-d87543-36012c2fd261e812-1--d87543-;rport Max-Forwards: 70 Contact: To: "Kai-Uwe Jensen" From: "Kai-Uwe Jensen";tag=fa206066 Call-ID: 2114db24f931c153@TUFETUFOMi5hbWVyaWNhcy5ocHFjb3JwLm5ldA.. CSeq: 1 REGISTER Expires: 3600 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO Supported: eventlist User-Agent: eyeBeam release 3010n stamp 19039 Content-Length: 0 Dec 25 18:08:54 DEBUG[31019] chan_sip.c: Header 0: REGISTER sip:cojensen.net SIP/2.0 (33) Dec 25 18:08:54 DEBUG[31019] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.254.60:8917;branch=z9hG4bK-d87543-36012c2fd261e812-1--d87543-;rport (92) Dec 25 18:08:54 DEBUG[31019] chan_sip.c: Header 2: Max-Forwards: 70 (16) Dec 25 18:08:54 DEBUG[31019] chan_sip.c: Header 3: Contact: (42) Dec 25 18:08:54 DEBUG[31019] chan_sip.c: Header 4: To: "Kai-Uwe Jensen" (46) Dec 25 18:08:54 DEBUG[31019] chan_sip.c: Header 5: From: "Kai-Uwe Jensen";tag=fa206066 (61) Dec 25 18:08:54 DEBUG[31019] chan_sip.c: Header 6: Call-ID: 2114db24f931c153@TUFETUFOMi5hbWVyaWNhcy5ocHFjb3JwLm5ldA.. (66) Dec 25 18:08:54 DEBUG[31019] chan_sip.c: Header 7: CSeq: 1 REGISTER (16) Dec 25 18:08:54 DEBUG[31019] chan_sip.c: Header 8: Expires: 3600 (13) Dec 25 18:08:54 DEBUG[31019] chan_sip.c: Header 9: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO (81) Dec 25 18:08:54 DEBUG[31019] chan_sip.c: Header 10: Supported: eventlist (20) Dec 25 18:08:54 DEBUG[31019] chan_sip.c: Header 11: User-Agent: eyeBeam release 3010n stamp 19039 (45) Dec 25 18:08:54 DEBUG[31019] chan_sip.c: Header 12: Content-Length: 0 (17) Dec 25 18:08:54 DEBUG[31019] chan_sip.c: Header 13: (0) Dec 25 18:08:54 VERBOSE[31019] logger.c: --- (13 headers 0 lines)Dec 25 18:08:54 VERBOSE[31019] logger.c: --- (13 headers 0 lines)--- Dec 25 18:08:54 DEBUG[31019] acl.c: ##### Testing 192.168.254.1 with 192.168.254.0 Dec 25 18:08:54 DEBUG[31019] chan_sip.c: Allocating new SIP dialog for 2114db24f931c153@TUFETUFOMi5hbWVyaWNhcy5ocHFjb3JwLm5ldA.. - REGISTER (No RTP) Dec 25 18:08:54 DEBUG[31019] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER Dec 25 18:08:54 VERBOSE[31019] logger.c: Using latest REGISTER request as basis request Dec 25 18:08:54 VERBOSE[31019] logger.c: Sending to 192.168.254.60 : 8917 (non-NAT) Dec 25 18:08:54 VERBOSE[31019] logger.c: Transmitting (NAT) to 192.168.254.1:8917: SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.254.60:8917;branch=z9hG4bK-d87543-36012c2fd261e812-1--d87543-;received=192.168.254.1;rport=8917 From: "Kai-Uwe Jensen";tag=fa206066 To: "Kai-Uwe Jensen" Call-ID: 2114db24f931c153@TUFETUFOMi5hbWVyaWNhcy5ocHFjb3JwLm5ldA.. CSeq: 1 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- Dec 25 18:08:54 VERBOSE[31019] logger.c: Transmitting (NAT) to 192.168.254.1:8917: SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.254.60:8917;branch=z9hG4bK-d87543-36012c2fd261e812-1--d87543-;received=192.168.254.1;rport=8917 From: "Kai-Uwe Jensen";tag=fa206066 To: "Kai-Uwe Jensen";tag=as01440088 Call-ID: 2114db24f931c153@TUFETUFOMi5hbWVyaWNhcy5ocHFjb3JwLm5ldA.. CSeq: 1 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: WWW-Authenticate: Digest realm="asterisk", nonce="31861045" Content-Length: 0 --- Dec 25 18:08:54 VERBOSE[31019] logger.c: Scheduling destruction of call '2114db24f931c153@TUFETUFOMi5hbWVyaWNhcy5ocHFjb3JwLm5ldA..' in 15000 ms Dec 25 18:08:54 VERBOSE[31019] logger.c: <-- SIP read from 192.168.254.1:8917: REGISTER sip:cojensen.net SIP/2.0 Via: SIP/2.0/UDP 192.168.254.60:8917;branch=z9hG4bK-d87543-9368d632d5427c63-1--d87543-;rport Max-Forwards: 70 Contact: To: "Kai-Uwe Jensen" From: "Kai-Uwe Jensen";tag=fa206066 Call-ID: 2114db24f931c153@TUFETUFOMi5hbWVyaWNhcy5ocHFjb3JwLm5ldA.. CSeq: 2 REGISTER Expires: 3600 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO Supported: eventlist User-Agent: eyeBeam release 3010n stamp 19039 Authorization: Digest username="ext2003",realm="asterisk",nonce="31861045",uri="sip:cojensen.net",response="42d8714cf0b78cc7e725fc086fd0904f",algorithm=MD5 Content-Length: 0 Dec 25 18:08:54 DEBUG[31019] chan_sip.c: Header 0: REGISTER sip:cojensen.net SIP/2.0 (33) Dec 25 18:08:54 DEBUG[31019] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.254.60:8917;branch=z9hG4bK-d87543-9368d632d5427c63-1--d87543-;rport (92) Dec 25 18:08:54 DEBUG[31019] chan_sip.c: Header 2: Max-Forwards: 70 (16) Dec 25 18:08:54 DEBUG[31019] chan_sip.c: Header 3: Contact: (42) Dec 25 18:08:54 DEBUG[31019] chan_sip.c: Header 4: To: "Kai-Uwe Jensen" (46) Dec 25 18:08:54 DEBUG[31019] chan_sip.c: Header 5: From: "Kai-Uwe Jensen";tag=fa206066 (61) Dec 25 18:08:54 DEBUG[31019] chan_sip.c: Header 6: Call-ID: 2114db24f931c153@TUFETUFOMi5hbWVyaWNhcy5ocHFjb3JwLm5ldA.. (66) Dec 25 18:08:54 DEBUG[31019] chan_sip.c: Header 7: CSeq: 2 REGISTER (16) Dec 25 18:08:54 DEBUG[31019] chan_sip.c: Header 8: Expires: 3600 (13) Dec 25 18:08:54 DEBUG[31019] chan_sip.c: Header 9: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO (81) Dec 25 18:08:54 DEBUG[31019] chan_sip.c: Header 10: Supported: eventlist (20) Dec 25 18:08:54 DEBUG[31019] chan_sip.c: Header 11: User-Agent: eyeBeam release 3010n stamp 19039 (45) Dec 25 18:08:54 DEBUG[31019] chan_sip.c: Header 12: Authorization: Digest username="ext2003",realm="asterisk",nonce="31861045",uri="sip:cojensen.net",response="42d8714cf0b78cc7e725fc086fd0904f",algorithm=MD5 (155) Dec 25 18:08:54 DEBUG[31019] chan_sip.c: Header 13: Content-Length: 0 (17) Dec 25 18:08:54 DEBUG[31019] chan_sip.c: Header 14: (0) Dec 25 18:08:54 VERBOSE[31019] logger.c: --- (14 headers 0 lines)Dec 25 18:08:54 VERBOSE[31019] logger.c: --- (14 headers 0 lines)--- Dec 25 18:08:54 DEBUG[31019] chan_sip.c: = Found Their Call ID: 2114db24f931c153@TUFETUFOMi5hbWVyaWNhcy5ocHFjb3JwLm5ldA.. Their Tag fa206066 Our tag: as01440088 Dec 25 18:08:54 DEBUG[31019] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER Dec 25 18:08:54 VERBOSE[31019] logger.c: Using latest REGISTER request as basis request Dec 25 18:08:54 VERBOSE[31019] logger.c: Sending to 192.168.254.60 : 8917 (NAT) Dec 25 18:08:54 VERBOSE[31019] logger.c: Transmitting (NAT) to 192.168.254.1:8917: SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.254.60:8917;branch=z9hG4bK-d87543-9368d632d5427c63-1--d87543-;received=192.168.254.1;rport=8917 From: "Kai-Uwe Jensen";tag=fa206066 To: "Kai-Uwe Jensen" Call-ID: 2114db24f931c153@TUFETUFOMi5hbWVyaWNhcy5ocHFjb3JwLm5ldA.. CSeq: 2 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- Dec 25 18:08:54 VERBOSE[31019] logger.c: -- Saved useragent "eyeBeam release 3010n stamp 19039" for peer ext2003 Dec 25 18:08:54 VERBOSE[31019] logger.c: Transmitting (NAT) to 192.168.254.1:8917: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.254.60:8917;branch=z9hG4bK-d87543-9368d632d5427c63-1--d87543-;received=192.168.254.1;rport=8917 From: "Kai-Uwe Jensen";tag=fa206066 To: "Kai-Uwe Jensen";tag=as01440088 Call-ID: 2114db24f931c153@TUFETUFOMi5hbWVyaWNhcy5ocHFjb3JwLm5ldA.. CSeq: 2 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Expires: 3600 Contact: ;expires=3600 Date: Mon, 26 Dec 2005 01:08:54 GMT Content-Length: 0 --- Dec 25 18:08:54 VERBOSE[31019] logger.c: Scheduling destruction of call '2114db24f931c153@TUFETUFOMi5hbWVyaWNhcy5ocHFjb3JwLm5ldA..' in 15000 ms Dec 25 18:08:54 DEBUG[31017] chan_sip.c: Checking device state for peer ext2003 Dec 25 18:08:54 DEBUG[31017] devicestate.c: Changing state for SIP/ext2003 - state 1 (Not in use) Dec 25 18:08:54 DEBUG[31017] chan_sip.c: Checking device state for peer ext2003 Dec 25 18:08:54 DEBUG[31017] chan_sip.c: Checking device state for peer ext2003 Dec 25 18:08:54 DEBUG[31029] app_queue.c: Device 'SIP/ext2003' changed to state '1' (Not in use) Dec 25 18:08:56 DEBUG[31019] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) Dec 25 18:08:56 DEBUG[31019] acl.c: ##### Testing 192.168.254.1 with 192.168.254.0 Dec 25 18:08:56 DEBUG[31019] chan_sip.c: Header 0: OPTIONS sip:ext2003@192.168.254.60:8917 SIP/2.0 (47) Dec 25 18:08:56 DEBUG[31019] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.254.250:5060;branch=z9hG4bK2e687acb;rport (66) Dec 25 18:08:56 DEBUG[31019] chan_sip.c: Header 2: From: "Asterisk" ;tag=as30f46212 (62) Dec 25 18:08:56 DEBUG[31019] chan_sip.c: Header 3: To: (37) Dec 25 18:08:56 DEBUG[31019] chan_sip.c: Header 4: Contact: (39) Dec 25 18:08:56 DEBUG[31019] chan_sip.c: Header 5: Call-ID: 4dc055f505720e0d4b21f4f347cbbd85@192.168.254.250 (57) Dec 25 18:08:56 DEBUG[31019] chan_sip.c: Header 6: CSeq: 102 OPTIONS (17) Dec 25 18:08:56 DEBUG[31019] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Dec 25 18:08:56 DEBUG[31019] chan_sip.c: Header 8: Max-Forwards: 70 (16) Dec 25 18:08:56 DEBUG[31019] chan_sip.c: Header 9: Date: Mon, 26 Dec 2005 01:08:56 GMT (35) Dec 25 18:08:56 DEBUG[31019] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Dec 25 18:08:56 DEBUG[31019] chan_sip.c: Header 11: Content-Length: 0 (17) Dec 25 18:08:56 DEBUG[31019] chan_sip.c: Header 12: (0) Dec 25 18:08:56 VERBOSE[31019] logger.c: 12 headers, 0 lines Dec 25 18:08:56 VERBOSE[31019] logger.c: Reliably Transmitting (no NAT) to 192.168.254.1:8917: OPTIONS sip:ext2003@192.168.254.60:8917 SIP/2.0 Via: SIP/2.0/UDP 192.168.254.250:5060;branch=z9hG4bK2e687acb;rport From: "Asterisk" ;tag=as30f46212 To: Contact: Call-ID: 4dc055f505720e0d4b21f4f347cbbd85@192.168.254.250 CSeq: 102 OPTIONS User-Agent: Asterisk PBX Max-Forwards: 70 Date: Mon, 26 Dec 2005 01:08:56 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Length: 0 --- Dec 25 18:08:56 DEBUG[31019] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #59 Dec 25 18:08:56 VERBOSE[31019] logger.c: <-- SIP read from 192.168.254.1:8917: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.254.250:5060;branch=z9hG4bK2e687acb;rport=5060;received=67.174.106.30 Contact: To: ;tag=48432137 From: "Asterisk";tag=as30f46212 Call-ID: 4dc055f505720e0d4b21f4f347cbbd85@192.168.254.250 CSeq: 102 OPTIONS Accept: application/sdp Accept-Language: en Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO Supported: eventlist User-Agent: eyeBeam release 3010n stamp 19039 Content-Length: 0 Dec 25 18:08:56 DEBUG[31019] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Dec 25 18:08:56 DEBUG[31019] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.254.250:5060;branch=z9hG4bK2e687acb;rport=5060;received=67.174.106.30 (94) Dec 25 18:08:56 DEBUG[31019] chan_sip.c: Header 2: Contact: (34) Dec 25 18:08:56 DEBUG[31019] chan_sip.c: Header 3: To: ;tag=48432137 (50) Dec 25 18:08:56 DEBUG[31019] chan_sip.c: Header 4: From: "Asterisk";tag=as30f46212 (61) Dec 25 18:08:56 DEBUG[31019] chan_sip.c: Header 5: Call-ID: 4dc055f505720e0d4b21f4f347cbbd85@192.168.254.250 (57) Dec 25 18:08:56 DEBUG[31019] chan_sip.c: Header 6: CSeq: 102 OPTIONS (17) Dec 25 18:08:56 DEBUG[31019] chan_sip.c: Header 7: Accept: application/sdp (23) Dec 25 18:08:56 DEBUG[31019] chan_sip.c: Header 8: Accept-Language: en (19) Dec 25 18:08:56 DEBUG[31019] chan_sip.c: Header 9: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO (81) Dec 25 18:08:56 DEBUG[31019] chan_sip.c: Header 10: Supported: eventlist (20) Dec 25 18:08:56 DEBUG[31019] chan_sip.c: Header 11: User-Agent: eyeBeam release 3010n stamp 19039 (45) Dec 25 18:08:56 DEBUG[31019] chan_sip.c: Header 12: Content-Length: 0 (17) Dec 25 18:08:56 DEBUG[31019] chan_sip.c: Header 13: (0) Dec 25 18:08:56 VERBOSE[31019] logger.c: --- (13 headers 0 lines)Dec 25 18:08:56 VERBOSE[31019] logger.c: --- (13 headers 0 lines)--- Dec 25 18:08:56 DEBUG[31019] chan_sip.c: = Found Their Call ID: 4dc055f505720e0d4b21f4f347cbbd85@192.168.254.250 Their Tag Our tag: as30f46212 Dec 25 18:08:56 DEBUG[31019] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #59 Dec 25 18:08:56 DEBUG[31019] chan_sip.c: Stopping retransmission on '4dc055f505720e0d4b21f4f347cbbd85@192.168.254.250' of Request 102: Match Found Dec 25 18:08:56 NOTICE[31019] chan_sip.c: Peer 'ext2003' is now REACHABLE! (86ms / 2000ms) Dec 25 18:08:56 VERBOSE[31019] logger.c: Destroying call '4dc055f505720e0d4b21f4f347cbbd85@192.168.254.250' Dec 25 18:08:56 DEBUG[31017] chan_sip.c: Checking device state for peer ext2003 Dec 25 18:08:56 DEBUG[31017] devicestate.c: Changing state for SIP/ext2003 - state 1 (Not in use) Dec 25 18:08:56 DEBUG[31017] chan_sip.c: Checking device state for peer ext2003 Dec 25 18:08:56 DEBUG[31017] chan_sip.c: Checking device state for peer ext2003 Dec 25 18:08:56 DEBUG[31030] app_queue.c: Device 'SIP/ext2003' changed to state '1' (Not in use) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP) Dec 25 18:08:58 DEBUG[31019] acl.c: ##### Testing 192.168.254.1 with 192.168.254.0 Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Header 0: NOTIFY sip:ext2003@192.168.254.60:8917 SIP/2.0 (46) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.254.250:5060;branch=z9hG4bK755abe8d;rport (66) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Header 2: From: "Asterisk" ;tag=as5233fb62 (62) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Header 3: To: (37) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Header 4: Contact: (39) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Header 5: Call-ID: 702604a424e7a795749b16155593beb3@192.168.254.250 (57) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Header 6: CSeq: 102 NOTIFY (16) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Header 8: Max-Forwards: 70 (16) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Header 9: Event: message-summary (22) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Header 10: Content-Type: application/simple-message-summary (48) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Header 11: Content-Length: 80 (18) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Header 12: (0) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Line: Messages-Waiting: no (20) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Line: Message-Account: sip:asterisk@ (30) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Line: Voice-Message: 0/0 (0/0) (24) Dec 25 18:08:58 VERBOSE[31019] logger.c: 12 headers, 3 lines Dec 25 18:08:58 VERBOSE[31019] logger.c: Reliably Transmitting (NAT) to 192.168.254.1:8917: NOTIFY sip:ext2003@192.168.254.60:8917 SIP/2.0 Via: SIP/2.0/UDP 192.168.254.250:5060;branch=z9hG4bK755abe8d;rport From: "Asterisk" ;tag=as5233fb62 To: Contact: Call-ID: 702604a424e7a795749b16155593beb3@192.168.254.250 CSeq: 102 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: message-summary Content-Type: application/simple-message-summary Content-Length: 80 Messages-Waiting: no Message-Account: sip:asterisk@ Voice-Message: 0/0 (0/0) --- Dec 25 18:08:58 DEBUG[31019] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #62 Dec 25 18:08:58 VERBOSE[31019] logger.c: Scheduling destruction of call '702604a424e7a795749b16155593beb3@192.168.254.250' in 15000 ms Dec 25 18:08:58 VERBOSE[31019] logger.c: <-- SIP read from 192.168.254.1:8917: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.254.250:5060;branch=z9hG4bK755abe8d;rport=5060;received=67.174.106.30 Contact: To: ;tag=8f2b151a From: "Asterisk";tag=as5233fb62 Call-ID: 702604a424e7a795749b16155593beb3@192.168.254.250 CSeq: 102 NOTIFY User-Agent: eyeBeam release 3010n stamp 19039 Content-Length: 0 Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.254.250:5060;branch=z9hG4bK755abe8d;rport=5060;received=67.174.106.30 (94) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Header 2: Contact: (34) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Header 3: To: ;tag=8f2b151a (50) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Header 4: From: "Asterisk";tag=as5233fb62 (61) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Header 5: Call-ID: 702604a424e7a795749b16155593beb3@192.168.254.250 (57) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Header 6: CSeq: 102 NOTIFY (16) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Header 7: User-Agent: eyeBeam release 3010n stamp 19039 (45) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Header 8: Content-Length: 0 (17) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Header 9: (0) Dec 25 18:08:58 VERBOSE[31019] logger.c: --- (9 headers 0 lines)Dec 25 18:08:58 VERBOSE[31019] logger.c: --- (9 headers 0 lines)--- Dec 25 18:08:58 DEBUG[31019] chan_sip.c: = Found Their Call ID: 702604a424e7a795749b16155593beb3@192.168.254.250 Their Tag Our tag: as5233fb62 Dec 25 18:08:58 DEBUG[31019] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #62 Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Stopping retransmission on '702604a424e7a795749b16155593beb3@192.168.254.250' of Request 102: Match Found Dec 25 18:08:58 VERBOSE[31019] logger.c: Destroying call '702604a424e7a795749b16155593beb3@192.168.254.250' Dec 25 18:08:58 VERBOSE[31019] logger.c: <-- SIP read from 192.168.254.252:5060: INVITE sip:2600@192.168.254.250;user=phone SIP/2.0 Via: SIP/2.0/UDP 192.168.254.252:5060;branch=z9hG4bK4e7a183f30B6FEEE From: "Kai-Uwe Jensen" ;tag=35B07255-37F0B6F2 To: CSeq: 1 INVITE Call-ID: 4fbcd061-6b9d8b93-f54b8b88@192.168.254.252 Contact: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER User-Agent: PolycomSoundPointIP-SPIP_500-UA/1.6.2.0041 Supported: 100rel,replace Allow-Events: talk,hold,conference Max-Forwards: 70 Content-Type: application/sdp Content-Length: 243 v=0 o=- 1135559102 1135559102 IN IP4 192.168.254.252 s=Polycom IP Phone c=IN IP4 192.168.254.252 t=0 0 m=audio 2224 RTP/AVP 0 8 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=rtpmap:101 telephone-event/8000 Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Header 0: INVITE sip:2600@192.168.254.250;user=phone SIP/2.0 (50) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.254.252:5060;branch=z9hG4bK4e7a183f30B6FEEE (68) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Header 2: From: "Kai-Uwe Jensen" ;tag=35B07255-37F0B6F2 (74) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Header 3: To: (41) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Header 4: CSeq: 1 INVITE (14) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Header 5: Call-ID: 4fbcd061-6b9d8b93-f54b8b88@192.168.254.252 (51) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Header 6: Contact: (43) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Header 7: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER (96) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Header 8: User-Agent: PolycomSoundPointIP-SPIP_500-UA/1.6.2.0041 (54) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Header 9: Supported: 100rel,replace (25) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Header 10: Allow-Events: talk,hold,conference (34) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Header 11: Max-Forwards: 70 (16) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Header 12: Content-Type: application/sdp (29) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Header 13: Content-Length: 243 (19) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Header 14: (0) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Line: v=0 (3) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Line: o=- 1135559102 1135559102 IN IP4 192.168.254.252 (48) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Line: s=Polycom IP Phone (18) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Line: c=IN IP4 192.168.254.252 (24) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Line: t=0 0 (5) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Line: m=audio 2224 RTP/AVP 0 8 18 101 (31) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Line: a=rtpmap:18 G729/8000 (21) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Dec 25 18:08:58 VERBOSE[31019] logger.c: --- (14 headers 10 lines)Dec 25 18:08:58 VERBOSE[31019] logger.c: --- (14 headers 10 lines)--- Dec 25 18:08:58 DEBUG[31019] chan_sip.c: = No match Their Call ID: 2114db24f931c153@TUFETUFOMi5hbWVyaWNhcy5ocHFjb3JwLm5ldA.. Their Tag fa206066 Our tag: as01440088 Dec 25 18:08:58 DEBUG[31019] acl.c: ##### Testing 192.168.254.252 with 192.168.254.0 Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Allocating new SIP dialog for 4fbcd061-6b9d8b93-f54b8b88@192.168.254.252 - INVITE (With RTP) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Begin: parsing SIP "Supported: 100rel,replace" Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Found SIP option: -100rel- Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Matched SIP option: 100rel Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Found SIP option: -replace- Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Found no match for SIP option: replace (Please file bug report!) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: * SIP extension value: 2 for call 4fbcd061-6b9d8b93-f54b8b88@192.168.254.252 Dec 25 18:08:58 VERBOSE[31019] logger.c: Using INVITE request as basis request - 4fbcd061-6b9d8b93-f54b8b88@192.168.254.252 Dec 25 18:08:58 VERBOSE[31019] logger.c: Sending to 192.168.254.252 : 5060 (non-NAT) Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Setting NAT on RTP to 0 Dec 25 18:08:58 DEBUG[31019] chan_sip.c: Setting NAT on VRTP to 0 Dec 25 18:08:58 VERBOSE[31019] logger.c: Reliably Transmitting (no NAT) to 192.168.254.252:5060: SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 192.168.254.252:5060;branch=z9hG4bK4e7a183f30B6FEEE;received=192.168.254.252 From: "Kai-Uwe Jensen" ;tag=35B07255-37F0B6F2 To: ;tag=as5e233d1b Call-ID: 4fbcd061-6b9d8b93-f54b8b88@192.168.254.252 CSeq: 1 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Proxy-Authenticate: Digest realm="asterisk", nonce="1c735844" Content-Length: 0 --- Dec 25 18:08:58 DEBUG[31019] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #64 Dec 25 18:08:58 VERBOSE[31019] logger.c: Scheduling destruction of call '4fbcd061-6b9d8b93-f54b8b88@192.168.254.252' in 15000 ms Dec 25 18:08:58 VERBOSE[31019] logger.c: Found user 'ext2006' Dec 25 18:08:59 VERBOSE[31019] logger.c: <-- SIP read from 192.168.254.252:5060: ACK sip:2600@192.168.254.250 SIP/2.0 Via: SIP/2.0/UDP 192.168.254.252:5060;branch=z9hG4bK4e7a183f30B6FEEE From: "Kai-Uwe Jensen" ;tag=35B07255-37F0B6F2 To: ;tag=as5e233d1b CSeq: 1 ACK Call-ID: 4fbcd061-6b9d8b93-f54b8b88@192.168.254.252 Contact: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER User-Agent: PolycomSoundPointIP-SPIP_500-UA/1.6.2.0041 Max-Forwards: 70 Content-Length: 0 Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Header 0: ACK sip:2600@192.168.254.250 SIP/2.0 (36) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.254.252:5060;branch=z9hG4bK4e7a183f30B6FEEE (68) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Header 2: From: "Kai-Uwe Jensen" ;tag=35B07255-37F0B6F2 (74) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Header 3: To: ;tag=as5e233d1b (56) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Header 4: CSeq: 1 ACK (11) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Header 5: Call-ID: 4fbcd061-6b9d8b93-f54b8b88@192.168.254.252 (51) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Header 6: Contact: (43) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Header 7: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER (96) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Header 8: User-Agent: PolycomSoundPointIP-SPIP_500-UA/1.6.2.0041 (54) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Header 9: Max-Forwards: 70 (16) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Header 10: Content-Length: 0 (17) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Header 11: (0) Dec 25 18:08:59 VERBOSE[31019] logger.c: --- (11 headers 0 lines)Dec 25 18:08:59 VERBOSE[31019] logger.c: --- (11 headers 0 lines)--- Dec 25 18:08:59 DEBUG[31019] chan_sip.c: = Found Their Call ID: 4fbcd061-6b9d8b93-f54b8b88@192.168.254.252 Their Tag 35B07255-37F0B6F2 Our tag: as5e233d1b Dec 25 18:08:59 DEBUG[31019] chan_sip.c: **** Received ACK (6) - Command in SIP ACK Dec 25 18:08:59 DEBUG[31019] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #64 Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Stopping retransmission on '4fbcd061-6b9d8b93-f54b8b88@192.168.254.252' of Response 1: Match Found Dec 25 18:08:59 VERBOSE[31019] logger.c: <-- SIP read from 192.168.254.252:5060: INVITE sip:2600@192.168.254.250;user=phone SIP/2.0 Via: SIP/2.0/UDP 192.168.254.252:5060;branch=z9hG4bK5a6747ac285B7127 From: "Kai-Uwe Jensen" ;tag=35B07255-37F0B6F2 To: CSeq: 2 INVITE Call-ID: 4fbcd061-6b9d8b93-f54b8b88@192.168.254.252 Contact: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER User-Agent: PolycomSoundPointIP-SPIP_500-UA/1.6.2.0041 Supported: 100rel,replace Allow-Events: talk,hold,conference Proxy-Authorization: Digest username="ext2006", realm="asterisk", nonce="1c735844", uri="sip:2600@192.168.254.250;user=phone", response="f8c55ec7ecc9802a7aa06cf3bacca188", algorithm=MD5 Max-Forwards: 70 Content-Type: application/sdp Content-Length: 243 v=0 o=- 1135559102 1135559102 IN IP4 192.168.254.252 s=Polycom IP Phone c=IN IP4 192.168.254.252 t=0 0 m=audio 2224 RTP/AVP 0 8 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=rtpmap:101 telephone-event/8000 Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Header 0: INVITE sip:2600@192.168.254.250;user=phone SIP/2.0 (50) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.254.252:5060;branch=z9hG4bK5a6747ac285B7127 (68) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Header 2: From: "Kai-Uwe Jensen" ;tag=35B07255-37F0B6F2 (74) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Header 3: To: (41) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Header 4: CSeq: 2 INVITE (14) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Header 5: Call-ID: 4fbcd061-6b9d8b93-f54b8b88@192.168.254.252 (51) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Header 6: Contact: (43) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Header 7: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER (96) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Header 8: User-Agent: PolycomSoundPointIP-SPIP_500-UA/1.6.2.0041 (54) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Header 9: Supported: 100rel,replace (25) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Header 10: Allow-Events: talk,hold,conference (34) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Header 11: Proxy-Authorization: Digest username="ext2006", realm="asterisk", nonce="1c735844", uri="sip:2600@192.168.254.250;user=phone", response="f8c55ec7ecc9802a7aa06cf3bacca188", algorithm=MD5 (185) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Header 12: Max-Forwards: 70 (16) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Header 13: Content-Type: application/sdp (29) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Header 14: Content-Length: 243 (19) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Header 15: (0) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Line: v=0 (3) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Line: o=- 1135559102 1135559102 IN IP4 192.168.254.252 (48) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Line: s=Polycom IP Phone (18) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Line: c=IN IP4 192.168.254.252 (24) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Line: t=0 0 (5) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Line: m=audio 2224 RTP/AVP 0 8 18 101 (31) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Line: a=rtpmap:18 G729/8000 (21) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Dec 25 18:08:59 VERBOSE[31019] logger.c: --- (15 headers 10 lines)Dec 25 18:08:59 VERBOSE[31019] logger.c: --- (15 headers 10 lines)--- Dec 25 18:08:59 DEBUG[31019] chan_sip.c: = Found Their Call ID: 4fbcd061-6b9d8b93-f54b8b88@192.168.254.252 Their Tag 35B07255-37F0B6F2 Our tag: as5e233d1b Dec 25 18:08:59 DEBUG[31019] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE Dec 25 18:08:59 VERBOSE[31019] logger.c: Using INVITE request as basis request - 4fbcd061-6b9d8b93-f54b8b88@192.168.254.252 Dec 25 18:08:59 VERBOSE[31019] logger.c: Sending to 192.168.254.252 : 5060 (non-NAT) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Setting NAT on RTP to 0 Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Setting NAT on VRTP to 0 Dec 25 18:08:59 VERBOSE[31019] logger.c: Found user 'ext2006' Dec 25 18:08:59 VERBOSE[31019] logger.c: Found RTP audio format 0 Dec 25 18:08:59 VERBOSE[31019] logger.c: Found RTP audio format 8 Dec 25 18:08:59 VERBOSE[31019] logger.c: Found RTP audio format 18 Dec 25 18:08:59 VERBOSE[31019] logger.c: Found RTP audio format 101 Dec 25 18:08:59 VERBOSE[31019] logger.c: Peer audio RTP is at port 192.168.254.252:2224 Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Peer audio RTP is at port 192.168.254.252:2224 Dec 25 18:08:59 VERBOSE[31019] logger.c: Peer video RTP is at port 192.168.254.252:65535 Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Peer video RTP is at port 192.168.254.252:65535 Dec 25 18:08:59 VERBOSE[31019] logger.c: Found description format PCMU Dec 25 18:08:59 VERBOSE[31019] logger.c: Found description format PCMA Dec 25 18:08:59 VERBOSE[31019] logger.c: Found description format G729 Dec 25 18:08:59 VERBOSE[31019] logger.c: Found description format telephone-event Dec 25 18:08:59 VERBOSE[31019] logger.c: Capabilities: us - 0x104 (ulaw|g729), peer - audio=0x10c (ulaw|alaw|g729)/video=0x0 (nothing), combined - 0x104 (ulaw|g729) Dec 25 18:08:59 VERBOSE[31019] logger.c: Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Checking SIP call limits for device ext2006 Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Updating call counter for incoming call Dec 25 18:08:59 VERBOSE[31019] logger.c: Looking for 2600 in home (domain 192.168.254.250) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: build_route: Contact hop: Dec 25 18:08:59 VERBOSE[31019] logger.c: list_route: hop: Dec 25 18:08:59 VERBOSE[31019] logger.c: Transmitting (no NAT) to 192.168.254.252:5060: SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.254.252:5060;branch=z9hG4bK5a6747ac285B7127;received=192.168.254.252 From: "Kai-Uwe Jensen" ;tag=35B07255-37F0B6F2 To: Call-ID: 4fbcd061-6b9d8b93-f54b8b88@192.168.254.252 CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- Dec 25 18:08:59 DEBUG[31017] chan_sip.c: Checking device state for peer ext2006 Dec 25 18:08:59 DEBUG[31017] devicestate.c: Changing state for SIP/ext2006 - state 2 (In use) Dec 25 18:08:59 DEBUG[31017] chan_sip.c: Checking device state for peer ext2006 Dec 25 18:08:59 DEBUG[31017] chan_sip.c: Checking device state for peer ext2006 Dec 25 18:08:59 DEBUG[31031] pbx.c: Launching 'Goto' Dec 25 18:08:59 VERBOSE[31031] logger.c: -- Executing Goto("SIP/ext2006-ca22", "confline|s|1") in new stack Dec 25 18:08:59 VERBOSE[31031] logger.c: -- Goto (confline,s,1) Dec 25 18:08:59 DEBUG[31031] pbx.c: Launching 'Answer' Dec 25 18:08:59 VERBOSE[31031] logger.c: -- Executing Answer("SIP/ext2006-ca22", "") in new stack Dec 25 18:08:59 DEBUG[31031] chan_sip.c: sip_answer(SIP/ext2006-ca22) Dec 25 18:08:59 VERBOSE[31031] logger.c: We're at 192.168.254.250 port 9028 Dec 25 18:08:59 VERBOSE[31031] logger.c: Video is at 192.168.254.250 port 9040 Dec 25 18:08:59 VERBOSE[31031] logger.c: Adding codec 0x4 (ulaw) to SDP Dec 25 18:08:59 VERBOSE[31031] logger.c: Adding codec 0x100 (g729) to SDP Dec 25 18:08:59 VERBOSE[31031] logger.c: Adding non-codec 0x1 (telephone-event) to SDP Dec 25 18:08:59 VERBOSE[31031] logger.c: Reliably Transmitting (no NAT) to 192.168.254.252:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.254.252:5060;branch=z9hG4bK5a6747ac285B7127;received=192.168.254.252 From: "Kai-Uwe Jensen" ;tag=35B07255-37F0B6F2 To: ;tag=as182e3cdd Call-ID: 4fbcd061-6b9d8b93-f54b8b88@192.168.254.252 CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Type: application/sdp Content-Length: 268 v=0 o=root 30966 30966 IN IP4 192.168.254.250 s=session c=IN IP4 192.168.254.250 t=0 0 m=audio 9028 RTP/AVP 0 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- Dec 25 18:08:59 DEBUG[31031] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #66 Dec 25 18:08:59 DEBUG[31031] pbx.c: Launching 'Wait' Dec 25 18:08:59 VERBOSE[31031] logger.c: -- Executing Wait("SIP/ext2006-ca22", "1") in new stack Dec 25 18:08:59 DEBUG[31017] chan_sip.c: Checking device state for peer ext2006 Dec 25 18:08:59 DEBUG[31017] devicestate.c: Changing state for SIP/ext2006 - state 2 (In use) Dec 25 18:08:59 DEBUG[31017] chan_sip.c: Checking device state for peer ext2006 Dec 25 18:08:59 DEBUG[31017] chan_sip.c: Checking device state for peer ext2006 Dec 25 18:08:59 DEBUG[31032] app_queue.c: Device 'SIP/ext2006' changed to state '2' (In use) Dec 25 18:08:59 DEBUG[31033] app_queue.c: Device 'SIP/ext2006' changed to state '2' (In use) Dec 25 18:08:59 VERBOSE[31019] logger.c: <-- SIP read from 192.168.254.252:5060: ACK sip:2600@192.168.254.250 SIP/2.0 Via: SIP/2.0/UDP 192.168.254.252:5060;branch=z9hG4bKf47fcfbE6D866BA From: "Kai-Uwe Jensen" ;tag=35B07255-37F0B6F2 To: ;tag=as182e3cdd CSeq: 2 ACK Call-ID: 4fbcd061-6b9d8b93-f54b8b88@192.168.254.252 Contact: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER User-Agent: PolycomSoundPointIP-SPIP_500-UA/1.6.2.0041 Max-Forwards: 70 Content-Length: 0 Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Header 0: ACK sip:2600@192.168.254.250 SIP/2.0 (36) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.254.252:5060;branch=z9hG4bKf47fcfbE6D866BA (67) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Header 2: From: "Kai-Uwe Jensen" ;tag=35B07255-37F0B6F2 (74) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Header 3: To: ;tag=as182e3cdd (56) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Header 4: CSeq: 2 ACK (11) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Header 5: Call-ID: 4fbcd061-6b9d8b93-f54b8b88@192.168.254.252 (51) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Header 6: Contact: (43) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Header 7: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER (96) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Header 8: User-Agent: PolycomSoundPointIP-SPIP_500-UA/1.6.2.0041 (54) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Header 9: Max-Forwards: 70 (16) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Header 10: Content-Length: 0 (17) Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Header 11: (0) Dec 25 18:08:59 VERBOSE[31019] logger.c: --- (11 headers 0 lines)Dec 25 18:08:59 VERBOSE[31019] logger.c: --- (11 headers 0 lines)--- Dec 25 18:08:59 DEBUG[31019] chan_sip.c: = Found Their Call ID: 4fbcd061-6b9d8b93-f54b8b88@192.168.254.252 Their Tag 35B07255-37F0B6F2 Our tag: as182e3cdd Dec 25 18:08:59 DEBUG[31019] chan_sip.c: **** Received ACK (6) - Command in SIP ACK Dec 25 18:08:59 DEBUG[31019] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #66 Dec 25 18:08:59 DEBUG[31019] chan_sip.c: Stopping retransmission on '4fbcd061-6b9d8b93-f54b8b88@192.168.254.252' of Response 2: Match Found Dec 25 18:09:00 DEBUG[31031] pbx.c: Launching 'BackGround' Dec 25 18:09:00 VERBOSE[31031] logger.c: -- Executing BackGround("SIP/ext2006-ca22", "enter-conf-call-number") in new stack Dec 25 18:09:00 DEBUG[31031] channel.c: Set channel SIP/ext2006-ca22 to write format gsm Dec 25 18:09:00 DEBUG[31031] rtp.c: Ooh, format changed from unknown to ulaw Dec 25 18:09:00 DEBUG[31031] channel.c: Scheduling timer at 160 sample intervals Dec 25 18:09:00 VERBOSE[31031] logger.c: -- Playing 'enter-conf-call-number' (language 'en') Dec 25 18:09:00 DEBUG[31031] rtp.c: Got RTCP report of 92 bytes Dec 25 18:09:01 DEBUG[31031] rtp.c: Sending dtmf: 56 (8), at 192.168.254.252 Dec 25 18:09:01 DEBUG[31031] channel.c: Scheduling timer at 0 sample intervals Dec 25 18:09:01 DEBUG[31031] channel.c: Set channel SIP/ext2006-ca22 to write format ulaw Dec 25 18:09:01 DEBUG[31031] pbx.c: Oooh, got something to jump out with ('8')! Dec 25 18:09:01 DEBUG[31031] rtp.c: Sending dtmf: 57 (9), at 192.168.254.252 Dec 25 18:09:02 DEBUG[31031] rtp.c: Sending dtmf: 56 (8), at 192.168.254.252 Dec 25 18:09:02 DEBUG[31031] rtp.c: Sending dtmf: 55 (7), at 192.168.254.252 Dec 25 18:09:02 DEBUG[31031] rtp.c: Sending dtmf: 55 (7), at 192.168.254.252 Dec 25 18:09:02 DEBUG[31031] rtp.c: Sending dtmf: 54 (6), at 192.168.254.252 Dec 25 18:09:03 VERBOSE[31019] logger.c: <-- SIP read from 192.168.254.1:8917: Dec 25 18:09:03 DEBUG[31019] chan_sip.c: Header 0: (0) Dec 25 18:09:03 VERBOSE[31019] logger.c: --- (0 headers 0 lines)Dec 25 18:09:03 VERBOSE[31019] logger.c: --- (0 headers 0 lines) Nat keepalive Dec 25 18:09:03 VERBOSE[31019] logger.c: --- (0 headers 0 lines) Nat keepalive --- Dec 25 18:09:03 DEBUG[31031] rtp.c: Sending dtmf: 50 (2), at 192.168.254.252 Dec 25 18:09:03 DEBUG[31031] rtp.c: Sending dtmf: 35 (#), at 192.168.254.252 Dec 25 18:09:03 VERBOSE[31031] logger.c: == CDR updated on SIP/ext2006-ca22 Dec 25 18:09:03 DEBUG[31031] pbx.c: Launching 'Goto' Dec 25 18:09:03 VERBOSE[31031] logger.c: -- Executing Goto("SIP/ext2006-ca22", "8987762|1") in new stack Dec 25 18:09:03 VERBOSE[31031] logger.c: -- Goto (confline,8987762,1) Dec 25 18:09:03 DEBUG[31031] pbx.c: Launching 'Wait' Dec 25 18:09:03 VERBOSE[31031] logger.c: -- Executing Wait("SIP/ext2006-ca22", "1") in new stack Dec 25 18:09:04 DEBUG[31021] chan_iax2.c: Allocate call number Dec 25 18:09:04 DEBUG[31021] chan_iax2.c: Registration created on call 2 Dec 25 18:09:04 DEBUG[31031] pbx.c: Launching 'MeetMe' Dec 25 18:09:04 VERBOSE[31031] logger.c: -- Executing MeetMe("SIP/ext2006-ca22", "8987762|MPxwsvn") in new stack Dec 25 18:09:04 DEBUG[31031] config.c: Parsing /etc/asterisk/meetme.conf Dec 25 18:09:04 DEBUG[31031] chan_zap.c: Using channel -2 Dec 25 18:09:04 DEBUG[31031] channel.c: Set channel Zap/pseudo-1298643543 to read format slin Dec 25 18:09:04 DEBUG[31031] channel.c: Set channel Zap/pseudo-1298643543 to write format slin Dec 25 18:09:04 DEBUG[31031] chan_zap.c: Using channel -2 Dec 25 18:09:04 DEBUG[31031] channel.c: Set channel Zap/pseudo-1304465079 to read format slin Dec 25 18:09:04 DEBUG[31031] channel.c: Set channel Zap/pseudo-1304465079 to write format slin Dec 25 18:09:04 VERBOSE[31031] logger.c: -- Created MeetMe conference 1023 for conference '8987762' Dec 25 18:09:04 DEBUG[31031] channel.c: Set channel SIP/ext2006-ca22 to write format gsm Dec 25 18:09:04 DEBUG[31031] rtp.c: Difference is 24376, ms is 3067 Dec 25 18:09:04 DEBUG[31031] channel.c: Scheduling timer at 160 sample intervals Dec 25 18:09:04 VERBOSE[31031] logger.c: -- Playing 'conf-waitforleader' (language 'en') Dec 25 18:09:04 DEBUG[31017] devicestate.c: Changing state for Zap/pseudo - state 2 (In use) Dec 25 18:09:04 DEBUG[31017] devicestate.c: Changing state for Zap/pseudo - state 2 (In use) Dec 25 18:09:04 DEBUG[31035] app_queue.c: Device 'Zap/pseudo' changed to state '2' (In use) Dec 25 18:09:04 DEBUG[31036] app_queue.c: Device 'Zap/pseudo' changed to state '2' (In use) Dec 25 18:09:07 DEBUG[31031] channel.c: Scheduling timer at 0 sample intervals Dec 25 18:09:07 DEBUG[31031] channel.c: Scheduling timer at 0 sample intervals Dec 25 18:09:07 DEBUG[31031] channel.c: Set channel SIP/ext2006-ca22 to write format ulaw Dec 25 18:09:07 DEBUG[31031] channel.c: Set channel SIP/ext2006-ca22 to write format slin Dec 25 18:09:07 DEBUG[31031] channel.c: Set channel SIP/ext2006-ca22 to read format slin Dec 25 18:09:07 DEBUG[31031] app_meetme.c: Placed channel SIP/ext2006-ca22 in ZAP conf 1023 Dec 25 18:09:07 DEBUG[31031] channel.c: Set channel SIP/ext2006-ca22 to write format slin Dec 25 18:09:07 VERBOSE[31031] logger.c: -- Started music on hold, class 'default', on SIP/ext2006-ca22 Dec 25 18:09:07 DEBUG[31031] channel.c: Scheduling timer at 160 sample intervals Dec 25 18:09:07 DEBUG[31031] channel.c: Generator got voice, switching to phase locked mode Dec 25 18:09:07 DEBUG[31031] channel.c: Scheduling timer at 0 sample intervals Dec 25 18:09:07 DEBUG[31031] channel.c: Set channel SIP/ext2006-ca22 to write format slin Dec 25 18:09:07 DEBUG[31031] channel.c: Set channel SIP/ext2006-ca22 to write format slin Dec 25 18:09:07 DEBUG[31031] res_musiconhold.c: SIP/ext2006-ca22 Opened file 6 '/var/lib/asterisk/mohmp3/MoH' Dec 25 18:09:08 DEBUG[31034] chan_zap.c: DTMF digit: 2 on Zap/pseudo-1304465079 ########################################################################3 Crash + Restart ########################################################################3 Dec 25 18:09:12 VERBOSE[31080] logger.c: Asterisk Event Logger Started /var/log/asterisk/event_log Dec 25 18:09:12 VERBOSE[31080] logger.c: == Parsing '/etc/asterisk/dnsmgr.conf': Dec 25 18:09:12 VERBOSE[31080] logger.c: == Parsing '/etc/asterisk/dnsmgr.conf': Found