Sep 21 09:48:49 VERBOSE[11889] logger.c: Asterisk Event Logger restarted Sep 21 09:48:49 VERBOSE[11889] logger.c: Asterisk Queue Logger restarted Sep 21 09:49:00 DEBUG[11903] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) Sep 21 09:49:00 DEBUG[11903] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) Sep 21 09:49:00 DEBUG[11903] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) Sep 21 09:49:00 DEBUG[11903] chan_sip.c: Stopping retransmission on '59ec079654926e8843b8320c1e74175d@192.168.100.143' of Request 102: Match Found Sep 21 09:49:00 DEBUG[11903] chan_sip.c: Stopping retransmission on '18f7a77360cceab5536b193d64426c82@192.168.100.143' of Request 102: Match Found Sep 21 09:49:00 DEBUG[11903] chan_sip.c: Stopping retransmission on '68857316610795af14886f903bbc2ae1@192.168.100.143' of Request 102: Match Found Sep 21 09:49:04 DEBUG[11903] chan_sip.c: Allocating new SIP dialog for oGwlOGdfi7o8IFMi@192.168.100.113 - REGISTER (No RTP) Sep 21 09:49:04 DEBUG[11903] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER Sep 21 09:49:04 DEBUG[11903] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER Sep 21 09:49:04 VERBOSE[11903] logger.c: -- Saved useragent "IP PHONE 2 V1.52.007 CFG0 " for peer 2003 Sep 21 09:49:04 DEBUG[11892] chan_sip.c: Checking device state for peer 2003 Sep 21 09:49:04 DEBUG[11892] devicestate.c: Changing state for SIP/2003 - state 1 (Not in use) Sep 21 09:49:04 DEBUG[11915] app_queue.c: Device 'SIP/2003' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Sep 21 09:49:16 VERBOSE[11903] logger.c: <-- SIP read from 192.168.100.178:5060: INVITE sip:2003@192.168.100.143 SIP/2.0 Via: SIP/2.0/UDP 192.168.100.178:5060;branch=z9hG4bKuNOKUgFxEMya893Y;rport Max-Forwards: 70 User-Agent: IP PHONE 2 V1.52.007 CFG0 From: "2007" ;tag=wMTIase1FbX5VOfE To: "2003" Call-ID: FZk7d0lnH94jBJcv@192.168.100.178 Contact: CSeq: 1 INVITE Supported: replaces Content-Type: application/sdp Content-Length: 168 v=0 o=- 18475302 59400747 IN IP4 192.168.100.178 s=SIP CALL c=IN IP4 192.168.100.178 t=0 0 m=audio 1722 RTP/AVP 18 0 a=rtpmap:18 G729/8000 a=rtpmap:0 PCMU/8000 Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 0: INVITE sip:2003@192.168.100.143 SIP/2.0 (39) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.178:5060;branch=z9hG4bKuNOKUgFxEMya893Y;rport (74) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 2: Max-Forwards: 70 (16) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 3: User-Agent: IP PHONE 2 V1.52.007 CFG0 (41) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 4: From: "2007" ;tag=wMTIase1FbX5VOfE (60) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 5: To: "2003" (37) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 6: Call-ID: FZk7d0lnH94jBJcv@192.168.100.178 (41) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 7: Contact: (40) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 8: CSeq: 1 INVITE (14) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 9: Supported: replaces (19) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 10: Content-Type: application/sdp (29) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 11: Content-Length: 168 (19) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 12: (0) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Line: v=0 (3) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Line: o=- 18475302 59400747 IN IP4 192.168.100.178 (44) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Line: s=SIP CALL (10) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Line: c=IN IP4 192.168.100.178 (24) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Line: t=0 0 (5) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Line: m=audio 1722 RTP/AVP 18 0 (25) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Line: a=rtpmap:18 G729/8000 (21) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Sep 21 09:49:16 VERBOSE[11903] logger.c: --- (12 headers 8 lines)Sep 21 09:49:16 VERBOSE[11903] logger.c: --- (12 headers 8 lines)--- Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Allocating new SIP dialog for FZk7d0lnH94jBJcv@192.168.100.178 - INVITE (With RTP) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Begin: parsing SIP "Supported: replaces" Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Found SIP option: -replaces- Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Matched SIP option: replaces Sep 21 09:49:16 DEBUG[11903] chan_sip.c: * SIP extension value: 1 for call FZk7d0lnH94jBJcv@192.168.100.178 Sep 21 09:49:16 VERBOSE[11903] logger.c: Using INVITE request as basis request - FZk7d0lnH94jBJcv@192.168.100.178 Sep 21 09:49:16 VERBOSE[11903] logger.c: Sending to 192.168.100.178 : 5060 (NAT) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Setting NAT on RTP to 524288 Sep 21 09:49:16 VERBOSE[11903] logger.c: Reliably Transmitting (NAT) to 192.168.100.178:5060: SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 192.168.100.178:5060;branch=z9hG4bKuNOKUgFxEMya893Y;received=192.168.100.178;rport=5060 From: "2007" ;tag=wMTIase1FbX5VOfE To: "2003" ;tag=as3773fbd3 Call-ID: FZk7d0lnH94jBJcv@192.168.100.178 CSeq: 1 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Proxy-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="4488d0e6" Content-Length: 0 --- Sep 21 09:49:16 DEBUG[11903] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #28 Sep 21 09:49:16 VERBOSE[11903] logger.c: Scheduling destruction of call 'FZk7d0lnH94jBJcv@192.168.100.178' in 15000 ms Sep 21 09:49:16 VERBOSE[11903] logger.c: Found user '2007' Sep 21 09:49:16 VERBOSE[11903] logger.c: <-- SIP read from 192.168.100.178:5060: ACK sip:2003@192.168.100.143 SIP/2.0 Via: SIP/2.0/UDP 192.168.100.178:5060;branch=z9hG4bKuNOKUgFxEMya893Y;rport Max-Forwards: 70 User-Agent: IP PHONE 2 V1.52.007 CFG0 From: "2007" ;tag=wMTIase1FbX5VOfE To: "2003" ;tag=as3773fbd3 Call-ID: FZk7d0lnH94jBJcv@192.168.100.178 Contact: CSeq: 1 ACK Content-Length: 0 Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 0: ACK sip:2003@192.168.100.143 SIP/2.0 (36) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.178:5060;branch=z9hG4bKuNOKUgFxEMya893Y;rport (74) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 2: Max-Forwards: 70 (16) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 3: User-Agent: IP PHONE 2 V1.52.007 CFG0 (41) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 4: From: "2007" ;tag=wMTIase1FbX5VOfE (60) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 5: To: "2003" ;tag=as3773fbd3 (52) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 6: Call-ID: FZk7d0lnH94jBJcv@192.168.100.178 (41) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 7: Contact: (40) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 8: CSeq: 1 ACK (11) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 9: Content-Length: 0 (17) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 10: (0) Sep 21 09:49:16 VERBOSE[11903] logger.c: --- (10 headers 0 lines)Sep 21 09:49:16 VERBOSE[11903] logger.c: --- (10 headers 0 lines)--- Sep 21 09:49:16 DEBUG[11903] chan_sip.c: **** Received ACK (6) - Command in SIP ACK Sep 21 09:49:16 DEBUG[11903] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #28 Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Stopping retransmission on 'FZk7d0lnH94jBJcv@192.168.100.178' of Response 1: Match Found Sep 21 09:49:16 VERBOSE[11903] logger.c: <-- SIP read from 192.168.100.178:5060: INVITE sip:2003@192.168.100.143 SIP/2.0 Via: SIP/2.0/UDP 192.168.100.178:5060;branch=z9hG4bK6vJ47OVSZKgI82U0;rport Max-Forwards: 70 User-Agent: IP PHONE 2 V1.52.007 CFG0 From: "2007" ;tag=wMTIase1FbX5VOfE To: "2003" Call-ID: FZk7d0lnH94jBJcv@192.168.100.178 Contact: Proxy-Authorization: Digest username="2007", realm="asterisk", nonce="4488d0e6", uri="sip:2003@192.168.100.143", response="3db3a7a02c053b97c7adccd1172cfcab", algorithm=MD5 CSeq: 2 INVITE Supported: replaces Content-Type: application/sdp Content-Length: 168 v=0 o=- 74291523 92303497 IN IP4 192.168.100.178 s=SIP CALL c=IN IP4 192.168.100.178 t=0 0 m=audio 1722 RTP/AVP 18 0 a=rtpmap:18 G729/8000 a=rtpmap:0 PCMU/8000 Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 0: INVITE sip:2003@192.168.100.143 SIP/2.0 (39) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.178:5060;branch=z9hG4bK6vJ47OVSZKgI82U0;rport (74) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 2: Max-Forwards: 70 (16) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 3: User-Agent: IP PHONE 2 V1.52.007 CFG0 (41) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 4: From: "2007" ;tag=wMTIase1FbX5VOfE (60) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 5: To: "2003" (37) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 6: Call-ID: FZk7d0lnH94jBJcv@192.168.100.178 (41) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 7: Contact: (40) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 8: Proxy-Authorization: Digest username="2007", realm="asterisk", nonce="4488d0e6", uri="sip:2003@192.168.100.143", response="3db3a7a02c053b97c7adccd1172cfcab", algorithm=MD5 (171) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 9: CSeq: 2 INVITE (14) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 10: Supported: replaces (19) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 11: Content-Type: application/sdp (29) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 12: Content-Length: 168 (19) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 13: (0) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Line: v=0 (3) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Line: o=- 74291523 92303497 IN IP4 192.168.100.178 (44) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Line: s=SIP CALL (10) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Line: c=IN IP4 192.168.100.178 (24) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Line: t=0 0 (5) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Line: m=audio 1722 RTP/AVP 18 0 (25) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Line: a=rtpmap:18 G729/8000 (21) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Sep 21 09:49:16 VERBOSE[11903] logger.c: --- (13 headers 8 lines)Sep 21 09:49:16 VERBOSE[11903] logger.c: --- (13 headers 8 lines)--- Sep 21 09:49:16 DEBUG[11903] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE Sep 21 09:49:16 VERBOSE[11903] logger.c: Using INVITE request as basis request - FZk7d0lnH94jBJcv@192.168.100.178 Sep 21 09:49:16 VERBOSE[11903] logger.c: Sending to 192.168.100.178 : 5060 (NAT) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Setting NAT on RTP to 524288 Sep 21 09:49:16 VERBOSE[11903] logger.c: Found user '2007' Sep 21 09:49:16 VERBOSE[11903] logger.c: Found RTP audio format 18 Sep 21 09:49:16 VERBOSE[11903] logger.c: Found RTP audio format 0 Sep 21 09:49:16 VERBOSE[11903] logger.c: Peer audio RTP is at port 192.168.100.178:1722 Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Peer audio RTP is at port 192.168.100.178:1722 Sep 21 09:49:16 VERBOSE[11903] logger.c: Found description format G729 Sep 21 09:49:16 VERBOSE[11903] logger.c: Found description format PCMU Sep 21 09:49:16 VERBOSE[11903] logger.c: Capabilities: us - 0x104 (ulaw|g729), peer - audio=0x104 (ulaw|g729)/video=0x0 (nothing), combined - 0x104 (ulaw|g729) Sep 21 09:49:16 VERBOSE[11903] logger.c: Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Checking SIP call limits for device 2007 Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Updating call counter for incoming call Sep 21 09:49:16 VERBOSE[11903] logger.c: Looking for 2003 in phones (domain 192.168.100.143) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: build_route: Contact hop: Sep 21 09:49:16 VERBOSE[11903] logger.c: list_route: hop: Sep 21 09:49:16 VERBOSE[11903] logger.c: Transmitting (NAT) to 192.168.100.178:5060: SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.100.178:5060;branch=z9hG4bK6vJ47OVSZKgI82U0;received=192.168.100.178;rport=5060 From: "2007" ;tag=wMTIase1FbX5VOfE To: "2003" Call-ID: FZk7d0lnH94jBJcv@192.168.100.178 CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- Sep 21 09:49:16 DEBUG[11892] chan_sip.c: Checking device state for peer 2007 Sep 21 09:49:16 DEBUG[11892] devicestate.c: Changing state for SIP/2007 - state 2 (In use) Sep 21 09:49:16 DEBUG[11917] pbx.c: Launching 'Dial' Sep 21 09:49:16 VERBOSE[11917] logger.c: -- Executing Dial("SIP/2007-094241f8", "SIP/2003") in new stack Sep 21 09:49:16 DEBUG[11917] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) Sep 21 09:49:16 DEBUG[11917] chan_sip.c: Setting NAT on RTP to 524288 Sep 21 09:49:16 DEBUG[11917] channel.c: Not copying variable STACK-phones-2003-1. Sep 21 09:49:16 DEBUG[11917] channel.c: Not copying variable SIPCALLID. Sep 21 09:49:16 DEBUG[11917] channel.c: Not copying variable SIPUSERAGENT. Sep 21 09:49:16 DEBUG[11917] channel.c: Not copying variable SIPDOMAIN. Sep 21 09:49:16 DEBUG[11917] channel.c: Not copying variable SIPURI. Sep 21 09:49:16 DEBUG[11917] chan_sip.c: Outgoing Call for 2003 Sep 21 09:49:16 DEBUG[11917] chan_sip.c: Updating call counter for outgoing call Sep 21 09:49:16 VERBOSE[11917] logger.c: We're at 192.168.100.143 port 13358 Sep 21 09:49:16 VERBOSE[11917] logger.c: Adding codec 0x4 (ulaw) to SDP Sep 21 09:49:16 VERBOSE[11917] logger.c: Adding codec 0x100 (g729) to SDP Sep 21 09:49:16 VERBOSE[11917] logger.c: Adding non-codec 0x1 (telephone-event) to SDP Sep 21 09:49:16 DEBUG[11917] chan_sip.c: Header 0: INVITE sip:2003@192.168.100.113:5060 SIP/2.0 (44) Sep 21 09:49:16 DEBUG[11917] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK7fc65c4f;rport (66) Sep 21 09:49:16 DEBUG[11917] chan_sip.c: Header 2: From: "2007" ;tag=as1cfffb3a (54) Sep 21 09:49:16 DEBUG[11917] chan_sip.c: Header 3: To: (35) Sep 21 09:49:16 DEBUG[11917] chan_sip.c: Header 4: Contact: (35) Sep 21 09:49:16 DEBUG[11917] chan_sip.c: Header 5: Call-ID: 43649e36476654f373ad343b407f5e82@192.168.100.143 (57) Sep 21 09:49:16 DEBUG[11917] chan_sip.c: Header 6: CSeq: 102 INVITE (16) Sep 21 09:49:16 DEBUG[11917] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Sep 21 09:49:16 DEBUG[11917] chan_sip.c: Header 8: Max-Forwards: 70 (16) Sep 21 09:49:16 DEBUG[11917] chan_sip.c: Header 9: Date: Thu, 21 Sep 2006 01:49:16 GMT (35) Sep 21 09:49:16 DEBUG[11917] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Sep 21 09:49:16 DEBUG[11917] chan_sip.c: Header 11: Content-Type: application/sdp (29) Sep 21 09:49:16 DEBUG[11917] chan_sip.c: Header 12: Content-Length: 269 (19) Sep 21 09:49:16 DEBUG[11917] chan_sip.c: Header 13: (0) Sep 21 09:49:16 DEBUG[11917] chan_sip.c: Line: v=0 (3) Sep 21 09:49:16 DEBUG[11917] chan_sip.c: Line: o=root 11889 11889 IN IP4 192.168.100.143 (41) Sep 21 09:49:16 DEBUG[11917] chan_sip.c: Line: s=session (9) Sep 21 09:49:16 DEBUG[11917] chan_sip.c: Line: c=IN IP4 192.168.100.143 (24) Sep 21 09:49:16 DEBUG[11917] chan_sip.c: Line: t=0 0 (5) Sep 21 09:49:16 DEBUG[11917] chan_sip.c: Line: m=audio 13358 RTP/AVP 0 18 101 (30) Sep 21 09:49:16 DEBUG[11917] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Sep 21 09:49:16 DEBUG[11917] chan_sip.c: Line: a=rtpmap:18 G729/8000 (21) Sep 21 09:49:16 DEBUG[11917] chan_sip.c: Line: a=fmtp:18 annexb=no (19) Sep 21 09:49:16 DEBUG[11917] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Sep 21 09:49:16 DEBUG[11917] chan_sip.c: Line: a=fmtp:101 0-16 (15) Sep 21 09:49:16 DEBUG[11917] chan_sip.c: Line: a=silenceSupp:off - - - - (25) Sep 21 09:49:16 VERBOSE[11917] logger.c: 13 headers, 12 lines Sep 21 09:49:16 VERBOSE[11917] logger.c: Reliably Transmitting (NAT) to 192.168.100.113:5060: INVITE sip:2003@192.168.100.113:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK7fc65c4f;rport From: "2007" ;tag=as1cfffb3a To: Contact: Call-ID: 43649e36476654f373ad343b407f5e82@192.168.100.143 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Thu, 21 Sep 2006 01:49:16 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Type: application/sdp Content-Length: 269 v=0 o=root 11889 11889 IN IP4 192.168.100.143 s=session c=IN IP4 192.168.100.143 t=0 0 m=audio 13358 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 - - - - --- Sep 21 09:49:16 DEBUG[11917] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #30 Sep 21 09:49:16 VERBOSE[11917] logger.c: -- Called 2003 Sep 21 09:49:16 DEBUG[11918] app_queue.c: Device 'SIP/2007' changed to state '2' (In use) but we don't care because they're not a member of any queue. Sep 21 09:49:16 VERBOSE[11903] logger.c: <-- SIP read from 192.168.100.113:5060: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK7fc65c4f;rport Call-ID: 43649e36476654f373ad343b407f5e82@192.168.100.143 CSeq: 102 INVITE From: "2007" ;tag=as1cfffb3a To: ;tag=JZZVnacUNFUm2iKR Contact: Content-Length: 0 Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 0: SIP/2.0 180 Ringing (19) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK7fc65c4f;rport (66) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 2: Call-ID: 43649e36476654f373ad343b407f5e82@192.168.100.143 (57) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 3: CSeq: 102 INVITE (16) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 4: From: "2007" ;tag=as1cfffb3a (54) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 5: To: ;tag=JZZVnacUNFUm2iKR (56) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 6: Contact: (40) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 7: Content-Length: 0 (17) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: Header 8: (0) Sep 21 09:49:16 VERBOSE[11903] logger.c: --- (8 headers 0 lines)Sep 21 09:49:16 VERBOSE[11903] logger.c: --- (8 headers 0 lines)--- Sep 21 09:49:16 DEBUG[11903] chan_sip.c: *** SIP TIMER: Cancelling retransmission #30 - INVITE (got response) Sep 21 09:49:16 DEBUG[11903] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '43649e36476654f373ad343b407f5e82@192.168.100.143' Request 102: Found Sep 21 09:49:16 DEBUG[11903] chan_sip.c: SIP response 180 to standard invite Sep 21 09:49:16 VERBOSE[11917] logger.c: -- SIP/2003-09429b28 is ringing Sep 21 09:49:16 VERBOSE[11917] logger.c: Transmitting (NAT) to 192.168.100.178:5060: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.100.178:5060;branch=z9hG4bK6vJ47OVSZKgI82U0;received=192.168.100.178;rport=5060 From: "2007" ;tag=wMTIase1FbX5VOfE To: "2003" ;tag=as099a99d9 Call-ID: FZk7d0lnH94jBJcv@192.168.100.178 CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- Sep 21 09:49:16 DEBUG[11892] chan_sip.c: Checking device state for peer 2003 Sep 21 09:49:16 DEBUG[11892] devicestate.c: Changing state for SIP/2003 - state 6 (Ringing) Sep 21 09:49:16 DEBUG[11919] app_queue.c: Device 'SIP/2003' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. Sep 21 09:49:17 VERBOSE[11903] logger.c: <-- SIP read from 192.168.100.113:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK7fc65c4f;rport Call-ID: 43649e36476654f373ad343b407f5e82@192.168.100.143 CSeq: 102 INVITE From: "2007" ;tag=as1cfffb3a To: ;tag=JZZVnacUNFUm2iKR Contact: Allow: INVITE, ACK, OPTIONS, BYE, CANCEL, REFER, NOTIFY, INFO, PRACK, UPDATE, MESSAGE Supported: replaces Content-Type: application/sdp Content-Length: 198 v=0 o=- 15167983 71831437 IN IP4 192.168.100.113 s=SIP CALL c=IN IP4 192.168.100.113 t=0 0 m=audio 1722 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK7fc65c4f;rport (66) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 2: Call-ID: 43649e36476654f373ad343b407f5e82@192.168.100.143 (57) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 3: CSeq: 102 INVITE (16) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 4: From: "2007" ;tag=as1cfffb3a (54) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 5: To: ;tag=JZZVnacUNFUm2iKR (56) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 6: Contact: (40) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 7: Allow: INVITE, ACK, OPTIONS, BYE, CANCEL, REFER, NOTIFY, INFO, PRACK, UPDATE, MESSAGE (85) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 8: Supported: replaces (19) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 9: Content-Type: application/sdp (29) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 10: Content-Length: 198 (19) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 11: (0) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Line: v=0 (3) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Line: o=- 15167983 71831437 IN IP4 192.168.100.113 (44) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Line: s=SIP CALL (10) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Line: c=IN IP4 192.168.100.113 (24) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Line: t=0 0 (5) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Line: m=audio 1722 RTP/AVP 0 101 (26) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Line: a=fmtp:101 0-15 (15) Sep 21 09:49:17 VERBOSE[11903] logger.c: --- (11 headers 9 lines)Sep 21 09:49:17 VERBOSE[11903] logger.c: --- (11 headers 9 lines)--- Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Acked pending invite 102 Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Stopping retransmission on '43649e36476654f373ad343b407f5e82@192.168.100.143' of Request 102: Match Found Sep 21 09:49:17 DEBUG[11903] chan_sip.c: SIP response 200 to standard invite Sep 21 09:49:17 VERBOSE[11903] logger.c: Found RTP audio format 0 Sep 21 09:49:17 VERBOSE[11903] logger.c: Found RTP audio format 101 Sep 21 09:49:17 VERBOSE[11903] logger.c: Peer audio RTP is at port 192.168.100.113:1722 Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Peer audio RTP is at port 192.168.100.113:1722 Sep 21 09:49:17 VERBOSE[11903] logger.c: Found description format PCMU Sep 21 09:49:17 VERBOSE[11903] logger.c: Found description format telephone-event Sep 21 09:49:17 VERBOSE[11903] logger.c: Capabilities: us - 0x104 (ulaw|g729), peer - audio=0x4 (ulaw)/video=0x0 (nothing), combined - 0x4 (ulaw) Sep 21 09:49:17 VERBOSE[11903] logger.c: Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: build_route: Contact hop: Sep 21 09:49:17 VERBOSE[11903] logger.c: list_route: hop: Sep 21 09:49:17 VERBOSE[11903] logger.c: set_destination: Parsing for address/port to send to Sep 21 09:49:17 VERBOSE[11903] logger.c: set_destination: set destination to 192.168.100.113, port 5060 Sep 21 09:49:17 VERBOSE[11903] logger.c: Transmitting (NAT) to 192.168.100.113:5060: ACK sip:2003@192.168.100.113:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK1798e3b9;rport From: "2007" ;tag=as1cfffb3a To: ;tag=JZZVnacUNFUm2iKR Contact: Call-ID: 43649e36476654f373ad343b407f5e82@192.168.100.143 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Sep 21 09:49:17 VERBOSE[11917] logger.c: -- SIP/2003-09429b28 answered SIP/2007-094241f8 Sep 21 09:49:17 DEBUG[11917] chan_sip.c: sip_answer(SIP/2007-094241f8) Sep 21 09:49:17 VERBOSE[11917] logger.c: We're at 192.168.100.143 port 14462 Sep 21 09:49:17 VERBOSE[11917] logger.c: Adding codec 0x4 (ulaw) to SDP Sep 21 09:49:17 VERBOSE[11917] logger.c: Adding codec 0x100 (g729) to SDP Sep 21 09:49:17 VERBOSE[11917] logger.c: Reliably Transmitting (NAT) to 192.168.100.178:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.100.178:5060;branch=z9hG4bK6vJ47OVSZKgI82U0;received=192.168.100.178;rport=5060 From: "2007" ;tag=wMTIase1FbX5VOfE To: "2003" ;tag=as099a99d9 Call-ID: FZk7d0lnH94jBJcv@192.168.100.178 CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Type: application/sdp Content-Length: 213 v=0 o=root 11889 11889 IN IP4 192.168.100.143 s=session c=IN IP4 192.168.100.143 t=0 0 m=audio 14462 RTP/AVP 0 18 a=rtpmap:0 PCMU/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=silenceSupp:off - - - - --- Sep 21 09:49:17 DEBUG[11917] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #32 Sep 21 09:49:17 VERBOSE[11917] logger.c: -- Attempting native bridge of SIP/2007-094241f8 and SIP/2003-09429b28 Sep 21 09:49:17 DEBUG[11917] chan_sip.c: Deferring reinvite on SIP 'FZk7d0lnH94jBJcv@192.168.100.178' - It's audio will be redirected to IP 192.168.100.113 Sep 21 09:49:17 DEBUG[11917] chan_sip.c: Sending reinvite on SIP '43649e36476654f373ad343b407f5e82@192.168.100.143' - It's audio soon redirected to IP 192.168.100.178 Sep 21 09:49:17 VERBOSE[11917] logger.c: set_destination: Parsing for address/port to send to Sep 21 09:49:17 VERBOSE[11917] logger.c: set_destination: set destination to 192.168.100.113, port 5060 Sep 21 09:49:17 VERBOSE[11917] logger.c: We're at 192.168.100.143 port 13358 Sep 21 09:49:17 VERBOSE[11917] logger.c: Adding codec 0x4 (ulaw) to SDP Sep 21 09:49:17 VERBOSE[11917] logger.c: Adding codec 0x100 (g729) to SDP Sep 21 09:49:17 VERBOSE[11917] logger.c: Adding non-codec 0x1 (telephone-event) to SDP Sep 21 09:49:17 DEBUG[11917] chan_sip.c: Header 0: INVITE sip:2003@192.168.100.113:5060 SIP/2.0 (44) Sep 21 09:49:17 DEBUG[11917] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK5752a0ba;rport (66) Sep 21 09:49:17 DEBUG[11917] chan_sip.c: Header 2: From: "2007" ;tag=as1cfffb3a (54) Sep 21 09:49:17 DEBUG[11917] chan_sip.c: Header 3: To: ;tag=JZZVnacUNFUm2iKR (56) Sep 21 09:49:17 DEBUG[11917] chan_sip.c: Header 4: Contact: (35) Sep 21 09:49:17 DEBUG[11917] chan_sip.c: Header 5: Call-ID: 43649e36476654f373ad343b407f5e82@192.168.100.143 (57) Sep 21 09:49:17 DEBUG[11917] chan_sip.c: Header 6: CSeq: 103 INVITE (16) Sep 21 09:49:17 DEBUG[11917] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Sep 21 09:49:17 DEBUG[11917] chan_sip.c: Header 8: Max-Forwards: 70 (16) Sep 21 09:49:17 DEBUG[11917] chan_sip.c: Header 9: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Sep 21 09:49:17 DEBUG[11917] chan_sip.c: Header 10: X-asterisk-info: SIP re-invite (RTP bridge) (43) Sep 21 09:49:17 DEBUG[11917] chan_sip.c: Header 11: Content-Type: application/sdp (29) Sep 21 09:49:17 DEBUG[11917] chan_sip.c: Header 12: Content-Length: 268 (19) Sep 21 09:49:17 DEBUG[11917] chan_sip.c: Header 13: (0) Sep 21 09:49:17 DEBUG[11917] chan_sip.c: Line: v=0 (3) Sep 21 09:49:17 DEBUG[11917] chan_sip.c: Line: o=root 11889 11890 IN IP4 192.168.100.178 (41) Sep 21 09:49:17 DEBUG[11917] chan_sip.c: Line: s=session (9) Sep 21 09:49:17 DEBUG[11917] chan_sip.c: Line: c=IN IP4 192.168.100.178 (24) Sep 21 09:49:17 DEBUG[11917] chan_sip.c: Line: t=0 0 (5) Sep 21 09:49:17 DEBUG[11917] chan_sip.c: Line: m=audio 1722 RTP/AVP 0 18 101 (29) Sep 21 09:49:17 DEBUG[11917] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Sep 21 09:49:17 DEBUG[11917] chan_sip.c: Line: a=rtpmap:18 G729/8000 (21) Sep 21 09:49:17 DEBUG[11917] chan_sip.c: Line: a=fmtp:18 annexb=no (19) Sep 21 09:49:17 DEBUG[11917] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Sep 21 09:49:17 DEBUG[11917] chan_sip.c: Line: a=fmtp:101 0-16 (15) Sep 21 09:49:17 DEBUG[11917] chan_sip.c: Line: a=silenceSupp:off - - - - (25) Sep 21 09:49:17 VERBOSE[11917] logger.c: 13 headers, 12 lines Sep 21 09:49:17 DEBUG[11892] chan_sip.c: Checking device state for peer 2003 Sep 21 09:49:17 DEBUG[11892] channel.c: Avoiding initial deadlock for 'SIP/2003-09429b28' Sep 21 09:49:17 VERBOSE[11917] logger.c: Reliably Transmitting (NAT) to 192.168.100.113:5060: INVITE sip:2003@192.168.100.113:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK5752a0ba;rport From: "2007" ;tag=as1cfffb3a To: ;tag=JZZVnacUNFUm2iKR Contact: Call-ID: 43649e36476654f373ad343b407f5e82@192.168.100.143 CSeq: 103 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY X-asterisk-info: SIP re-invite (RTP bridge) Content-Type: application/sdp Content-Length: 268 v=0 o=root 11889 11890 IN IP4 192.168.100.178 s=session c=IN IP4 192.168.100.178 t=0 0 m=audio 1722 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 - - - - --- Sep 21 09:49:17 DEBUG[11917] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #33 Sep 21 09:49:17 DEBUG[11892] devicestate.c: Changing state for SIP/2003 - state 2 (In use) Sep 21 09:49:17 DEBUG[11892] chan_sip.c: Checking device state for peer 2007 Sep 21 09:49:17 DEBUG[11892] devicestate.c: Changing state for SIP/2007 - state 2 (In use) Sep 21 09:49:17 DEBUG[11920] app_queue.c: Device 'SIP/2003' changed to state '2' (In use) but we don't care because they're not a member of any queue. Sep 21 09:49:17 DEBUG[11921] app_queue.c: Device 'SIP/2007' changed to state '2' (In use) but we don't care because they're not a member of any queue. Sep 21 09:49:17 VERBOSE[11903] logger.c: <-- SIP read from 192.168.100.113:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK5752a0ba;rport Call-ID: 43649e36476654f373ad343b407f5e82@192.168.100.143 CSeq: 103 INVITE From: "2007" ;tag=as1cfffb3a To: ;tag=JZZVnacUNFUm2iKR Contact: Allow: INVITE, ACK, OPTIONS, BYE, CANCEL, REFER, NOTIFY, INFO, PRACK, UPDATE, MESSAGE Supported: replaces Content-Type: application/sdp Content-Length: 198 v=0 o=- 85339874 75293082 IN IP4 192.168.100.113 s=SIP CALL c=IN IP4 192.168.100.113 t=0 0 m=audio 1722 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK5752a0ba;rport (66) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 2: Call-ID: 43649e36476654f373ad343b407f5e82@192.168.100.143 (57) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 3: CSeq: 103 INVITE (16) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 4: From: "2007" ;tag=as1cfffb3a (54) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 5: To: ;tag=JZZVnacUNFUm2iKR (56) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 6: Contact: (40) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 7: Allow: INVITE, ACK, OPTIONS, BYE, CANCEL, REFER, NOTIFY, INFO, PRACK, UPDATE, MESSAGE (85) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 8: Supported: replaces (19) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 9: Content-Type: application/sdp (29) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 10: Content-Length: 198 (19) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 11: (0) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Line: v=0 (3) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Line: o=- 85339874 75293082 IN IP4 192.168.100.113 (44) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Line: s=SIP CALL (10) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Line: c=IN IP4 192.168.100.113 (24) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Line: t=0 0 (5) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Line: m=audio 1722 RTP/AVP 0 101 (26) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Line: a=fmtp:101 0-15 (15) Sep 21 09:49:17 VERBOSE[11903] logger.c: --- (11 headers 9 lines)Sep 21 09:49:17 VERBOSE[11903] logger.c: --- (11 headers 9 lines)--- Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Acked pending invite 103 Sep 21 09:49:17 DEBUG[11903] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #33 Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Stopping retransmission on '43649e36476654f373ad343b407f5e82@192.168.100.143' of Request 103: Match Found Sep 21 09:49:17 DEBUG[11903] chan_sip.c: SIP response 200 to RE-invite on outgoing call 43649e36476654f373ad343b407f5e82@192.168.100.143 Sep 21 09:49:17 VERBOSE[11903] logger.c: Found RTP audio format 0 Sep 21 09:49:17 VERBOSE[11903] logger.c: Found RTP audio format 101 Sep 21 09:49:17 VERBOSE[11903] logger.c: Peer audio RTP is at port 192.168.100.113:1722 Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Peer audio RTP is at port 192.168.100.113:1722 Sep 21 09:49:17 VERBOSE[11903] logger.c: Found description format PCMU Sep 21 09:49:17 VERBOSE[11903] logger.c: Found description format telephone-event Sep 21 09:49:17 VERBOSE[11903] logger.c: Capabilities: us - 0x104 (ulaw|g729), peer - audio=0x4 (ulaw)/video=0x0 (nothing), combined - 0x4 (ulaw) Sep 21 09:49:17 VERBOSE[11903] logger.c: Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: build_route: Retaining previous route: Sep 21 09:49:17 VERBOSE[11903] logger.c: set_destination: Parsing for address/port to send to Sep 21 09:49:17 VERBOSE[11903] logger.c: set_destination: set destination to 192.168.100.113, port 5060 Sep 21 09:49:17 VERBOSE[11903] logger.c: Transmitting (NAT) to 192.168.100.113:5060: ACK sip:2003@192.168.100.113:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK466cb2ca;rport From: "2007" ;tag=as1cfffb3a To: ;tag=JZZVnacUNFUm2iKR Contact: Call-ID: 43649e36476654f373ad343b407f5e82@192.168.100.143 CSeq: 103 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Sep 21 09:49:17 VERBOSE[11903] logger.c: <-- SIP read from 192.168.100.178:5060: ACK sip:2003@192.168.100.143 SIP/2.0 Via: SIP/2.0/UDP 192.168.100.178:5060;branch=z9hG4bK4Ve0l5HOzuvZfEoc;rport Max-Forwards: 70 User-Agent: IP PHONE 2 V1.52.007 CFG0 From: "2007" ;tag=wMTIase1FbX5VOfE To: "2003" ;tag=as099a99d9 Call-ID: FZk7d0lnH94jBJcv@192.168.100.178 Contact: Proxy-Authorization: Digest username="2007", realm="asterisk", nonce="4488d0e6", uri="sip:2003@192.168.100.143", response="3c64c77be4241131af2638ecc3bd3bbf", algorithm=MD5 CSeq: 2 ACK Content-Length: 0 Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 0: ACK sip:2003@192.168.100.143 SIP/2.0 (36) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.178:5060;branch=z9hG4bK4Ve0l5HOzuvZfEoc;rport (74) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 2: Max-Forwards: 70 (16) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 3: User-Agent: IP PHONE 2 V1.52.007 CFG0 (41) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 4: From: "2007" ;tag=wMTIase1FbX5VOfE (60) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 5: To: "2003" ;tag=as099a99d9 (52) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 6: Call-ID: FZk7d0lnH94jBJcv@192.168.100.178 (41) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 7: Contact: (40) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 8: Proxy-Authorization: Digest username="2007", realm="asterisk", nonce="4488d0e6", uri="sip:2003@192.168.100.143", response="3c64c77be4241131af2638ecc3bd3bbf", algorithm=MD5 (171) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 9: CSeq: 2 ACK (11) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 10: Content-Length: 0 (17) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 11: (0) Sep 21 09:49:17 VERBOSE[11903] logger.c: --- (11 headers 0 lines)Sep 21 09:49:17 VERBOSE[11903] logger.c: --- (11 headers 0 lines)--- Sep 21 09:49:17 DEBUG[11903] chan_sip.c: **** Received ACK (6) - Command in SIP ACK Sep 21 09:49:17 DEBUG[11903] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #32 Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Stopping retransmission on 'FZk7d0lnH94jBJcv@192.168.100.178' of Response 2: Match Found Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Sending pending reinvite on 'FZk7d0lnH94jBJcv@192.168.100.178' Sep 21 09:49:17 VERBOSE[11903] logger.c: set_destination: Parsing for address/port to send to Sep 21 09:49:17 VERBOSE[11903] logger.c: set_destination: set destination to 192.168.100.178, port 5060 Sep 21 09:49:17 VERBOSE[11903] logger.c: We're at 192.168.100.143 port 14462 Sep 21 09:49:17 VERBOSE[11903] logger.c: Adding codec 0x4 (ulaw) to SDP Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 0: INVITE sip:2007@192.168.100.178:5060 SIP/2.0 (44) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK1884c1f1;rport (66) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 2: From: "2003" ;tag=as099a99d9 (54) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 3: To: "2007" ;tag=wMTIase1FbX5VOfE (58) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 4: Contact: (35) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 5: Call-ID: FZk7d0lnH94jBJcv@192.168.100.178 (41) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 6: CSeq: 102 INVITE (16) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 8: Max-Forwards: 70 (16) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 9: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 10: X-asterisk-info: SIP re-invite (RTP bridge) (43) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 11: Content-Type: application/sdp (29) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 12: Content-Length: 165 (19) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 13: (0) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Line: v=0 (3) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Line: o=root 11889 11890 IN IP4 192.168.100.113 (41) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Line: s=session (9) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Line: c=IN IP4 192.168.100.113 (24) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Line: t=0 0 (5) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Line: m=audio 1722 RTP/AVP 0 (22) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Line: a=silenceSupp:off - - - - (25) Sep 21 09:49:17 VERBOSE[11903] logger.c: 13 headers, 8 lines Sep 21 09:49:17 VERBOSE[11903] logger.c: Reliably Transmitting (NAT) to 192.168.100.178:5060: INVITE sip:2007@192.168.100.178:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK1884c1f1;rport From: "2003" ;tag=as099a99d9 To: "2007" ;tag=wMTIase1FbX5VOfE Contact: Call-ID: FZk7d0lnH94jBJcv@192.168.100.178 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY X-asterisk-info: SIP re-invite (RTP bridge) Content-Type: application/sdp Content-Length: 165 v=0 o=root 11889 11890 IN IP4 192.168.100.113 s=session c=IN IP4 192.168.100.113 t=0 0 m=audio 1722 RTP/AVP 0 a=rtpmap:0 PCMU/8000 a=silenceSupp:off - - - - --- Sep 21 09:49:17 DEBUG[11903] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #34 Sep 21 09:49:17 VERBOSE[11903] logger.c: <-- SIP read from 192.168.100.178:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK1884c1f1;rport Call-ID: FZk7d0lnH94jBJcv@192.168.100.178 CSeq: 102 INVITE From: "2003" ;tag=as099a99d9 To: "2007" ;tag=wMTIase1FbX5VOfE Contact: Allow: INVITE, ACK, OPTIONS, BYE, CANCEL, REFER, NOTIFY, INFO, PRACK, UPDATE, MESSAGE Supported: replaces Content-Type: application/sdp Content-Length: 142 v=0 o=- 75484989 22764494 IN IP4 192.168.100.178 s=SIP CALL c=IN IP4 192.168.100.178 t=0 0 m=audio 1722 RTP/AVP 0 a=rtpmap:0 PCMU/8000 Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK1884c1f1;rport (66) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 2: Call-ID: FZk7d0lnH94jBJcv@192.168.100.178 (41) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 3: CSeq: 102 INVITE (16) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 4: From: "2003" ;tag=as099a99d9 (54) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 5: To: "2007" ;tag=wMTIase1FbX5VOfE (58) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 6: Contact: (40) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 7: Allow: INVITE, ACK, OPTIONS, BYE, CANCEL, REFER, NOTIFY, INFO, PRACK, UPDATE, MESSAGE (85) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 8: Supported: replaces (19) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 9: Content-Type: application/sdp (29) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 10: Content-Length: 142 (19) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Header 11: (0) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Line: v=0 (3) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Line: o=- 75484989 22764494 IN IP4 192.168.100.178 (44) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Line: s=SIP CALL (10) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Line: c=IN IP4 192.168.100.178 (24) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Line: t=0 0 (5) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Line: m=audio 1722 RTP/AVP 0 (22) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Sep 21 09:49:17 VERBOSE[11903] logger.c: --- (11 headers 7 lines)Sep 21 09:49:17 VERBOSE[11903] logger.c: --- (11 headers 7 lines)--- Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Acked pending invite 102 Sep 21 09:49:17 DEBUG[11903] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #34 Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Stopping retransmission on 'FZk7d0lnH94jBJcv@192.168.100.178' of Request 102: Match Found Sep 21 09:49:17 DEBUG[11903] chan_sip.c: SIP response 200 to RE-invite on outgoing call FZk7d0lnH94jBJcv@192.168.100.178 Sep 21 09:49:17 VERBOSE[11903] logger.c: Found RTP audio format 0 Sep 21 09:49:17 VERBOSE[11903] logger.c: Peer audio RTP is at port 192.168.100.178:1722 Sep 21 09:49:17 DEBUG[11903] chan_sip.c: Peer audio RTP is at port 192.168.100.178:1722 Sep 21 09:49:17 VERBOSE[11903] logger.c: Found description format PCMU Sep 21 09:49:17 VERBOSE[11903] logger.c: Capabilities: us - 0x104 (ulaw|g729), peer - audio=0x4 (ulaw)/video=0x0 (nothing), combined - 0x4 (ulaw) Sep 21 09:49:17 VERBOSE[11903] logger.c: Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) Sep 21 09:49:17 DEBUG[11903] chan_sip.c: build_route: Contact hop: Sep 21 09:49:17 VERBOSE[11903] logger.c: list_route: hop: Sep 21 09:49:17 VERBOSE[11903] logger.c: set_destination: Parsing for address/port to send to Sep 21 09:49:17 VERBOSE[11903] logger.c: set_destination: set destination to 192.168.100.178, port 5060 Sep 21 09:49:17 VERBOSE[11903] logger.c: Transmitting (NAT) to 192.168.100.178:5060: ACK sip:2007@192.168.100.178:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK2dd821f0;rport From: "2003" ;tag=as099a99d9 To: "2007" ;tag=wMTIase1FbX5VOfE Contact: Call-ID: FZk7d0lnH94jBJcv@192.168.100.178 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Sep 21 09:49:19 DEBUG[11903] chan_sip.c: Auto destroying call 'oGwlOGdfi7o8IFMi@192.168.100.113' Sep 21 09:49:19 VERBOSE[11903] logger.c: Destroying call 'oGwlOGdfi7o8IFMi@192.168.100.113' Sep 21 09:49:44 VERBOSE[11903] logger.c: Reloading SIP Sep 21 09:49:44 DEBUG[11903] config.c: Parsing /etc/asterisk/sip.conf Sep 21 09:49:44 DEBUG[11903] config.c: Parsing /etc/asterisk/sip_notify.conf Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 0: OPTIONS sip:2006@192.168.100.142:5060 SIP/2.0 (45) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK277ad2ae;rport (66) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 2: From: "asterisk" ;tag=as16adce98 (62) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 3: To: (35) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 4: Contact: (39) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 5: Call-ID: 34f7cb8f0ee3d325637641ad272e73b9@192.168.100.143 (57) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 6: CSeq: 102 OPTIONS (17) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 8: Max-Forwards: 70 (16) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 9: Date: Thu, 21 Sep 2006 01:49:44 GMT (35) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 11: Content-Length: 0 (17) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 12: (0) Sep 21 09:49:44 VERBOSE[11903] logger.c: 12 headers, 0 lines Sep 21 09:49:44 VERBOSE[11903] logger.c: Reliably Transmitting (NAT) to 192.168.100.142:5060: OPTIONS sip:2006@192.168.100.142:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK277ad2ae;rport From: "asterisk" ;tag=as16adce98 To: Contact: Call-ID: 34f7cb8f0ee3d325637641ad272e73b9@192.168.100.143 CSeq: 102 OPTIONS User-Agent: Asterisk PBX Max-Forwards: 70 Date: Thu, 21 Sep 2006 01:49:44 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Length: 0 --- Sep 21 09:49:44 DEBUG[11903] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #35 Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 0: OPTIONS sip:2007@192.168.100.178:5060 SIP/2.0 (45) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK629e3f67;rport (66) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 2: From: "asterisk" ;tag=as62d2b10b (62) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 3: To: (35) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 4: Contact: (39) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 5: Call-ID: 31b008724aa7afe62b749a9b7edfb3d8@192.168.100.143 (57) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 6: CSeq: 102 OPTIONS (17) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 8: Max-Forwards: 70 (16) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 9: Date: Thu, 21 Sep 2006 01:49:44 GMT (35) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 11: Content-Length: 0 (17) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 12: (0) Sep 21 09:49:44 VERBOSE[11903] logger.c: 12 headers, 0 lines Sep 21 09:49:44 VERBOSE[11903] logger.c: Reliably Transmitting (NAT) to 192.168.100.178:5060: OPTIONS sip:2007@192.168.100.178:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK629e3f67;rport From: "asterisk" ;tag=as62d2b10b To: Contact: Call-ID: 31b008724aa7afe62b749a9b7edfb3d8@192.168.100.143 CSeq: 102 OPTIONS User-Agent: Asterisk PBX Max-Forwards: 70 Date: Thu, 21 Sep 2006 01:49:44 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Length: 0 --- Sep 21 09:49:44 DEBUG[11903] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #37 Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 0: OPTIONS sip:2003@192.168.100.113:5060 SIP/2.0 (45) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK396e9312;rport (66) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 2: From: "asterisk" ;tag=as1a217aaf (62) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 3: To: (35) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 4: Contact: (39) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 5: Call-ID: 0aeeb75573742a6b547bc01b69042fab@192.168.100.143 (57) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 6: CSeq: 102 OPTIONS (17) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 8: Max-Forwards: 70 (16) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 9: Date: Thu, 21 Sep 2006 01:49:44 GMT (35) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 11: Content-Length: 0 (17) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 12: (0) Sep 21 09:49:44 VERBOSE[11903] logger.c: 12 headers, 0 lines Sep 21 09:49:44 VERBOSE[11903] logger.c: Reliably Transmitting (NAT) to 192.168.100.113:5060: OPTIONS sip:2003@192.168.100.113:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK396e9312;rport From: "asterisk" ;tag=as1a217aaf To: Contact: Call-ID: 0aeeb75573742a6b547bc01b69042fab@192.168.100.143 CSeq: 102 OPTIONS User-Agent: Asterisk PBX Max-Forwards: 70 Date: Thu, 21 Sep 2006 01:49:44 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Length: 0 --- Sep 21 09:49:44 DEBUG[11903] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #39 Sep 21 09:49:44 VERBOSE[11903] logger.c: <-- SIP read from 192.168.100.142:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK277ad2ae;rport Call-ID: 34f7cb8f0ee3d325637641ad272e73b9@192.168.100.143 CSeq: 102 OPTIONS From: "asterisk" ;tag=as16adce98 To: ;tag=t1pIG8b0i04cdGvJ Contact: Allow: INVITE, ACK, OPTIONS, BYE, CANCEL, REFER, NOTIFY, INFO, PRACK, UPDATE, MESSAGE Accept: application/sdp, message/sipfrag, application/dtmf-relay Supported: replaces Content-Length: 0 Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK277ad2ae;rport (66) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 2: Call-ID: 34f7cb8f0ee3d325637641ad272e73b9@192.168.100.143 (57) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 3: CSeq: 102 OPTIONS (17) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 4: From: "asterisk" ;tag=as16adce98 (62) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 5: To: ;tag=t1pIG8b0i04cdGvJ (56) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 6: Contact: (40) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 7: Allow: INVITE, ACK, OPTIONS, BYE, CANCEL, REFER, NOTIFY, INFO, PRACK, UPDATE, MESSAGE (85) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 8: Accept: application/sdp, message/sipfrag, application/dtmf-relay (64) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 9: Supported: replaces (19) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 10: Content-Length: 0 (17) Sep 21 09:49:44 VERBOSE[11903] logger.c: --- (11 headers 0 lines)Sep 21 09:49:44 VERBOSE[11903] logger.c: --- (11 headers 0 lines)--- Sep 21 09:49:44 DEBUG[11903] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #35 Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Stopping retransmission on '34f7cb8f0ee3d325637641ad272e73b9@192.168.100.143' of Request 102: Match Found Sep 21 09:49:44 VERBOSE[11903] logger.c: Destroying call '34f7cb8f0ee3d325637641ad272e73b9@192.168.100.143' Sep 21 09:49:44 VERBOSE[11903] logger.c: <-- SIP read from 192.168.100.178:5060: SIP/2.0 486 Busy Here Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK629e3f67;rport Call-ID: 31b008724aa7afe62b749a9b7edfb3d8@192.168.100.143 CSeq: 102 OPTIONS From: "asterisk" ;tag=as62d2b10b To: ;tag=50cUFXaBcv8byKVY Contact: Allow: INVITE, ACK, OPTIONS, BYE, CANCEL, REFER, NOTIFY, INFO, PRACK, UPDATE, MESSAGE Accept: application/sdp, message/sipfrag, application/dtmf-relay Supported: replaces Content-Length: 0 Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 0: SIP/2.0 486 Busy Here (21) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK629e3f67;rport (66) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 2: Call-ID: 31b008724aa7afe62b749a9b7edfb3d8@192.168.100.143 (57) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 3: CSeq: 102 OPTIONS (17) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 4: From: "asterisk" ;tag=as62d2b10b (62) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 5: To: ;tag=50cUFXaBcv8byKVY (56) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 6: Contact: (40) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 7: Allow: INVITE, ACK, OPTIONS, BYE, CANCEL, REFER, NOTIFY, INFO, PRACK, UPDATE, MESSAGE (85) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 8: Accept: application/sdp, message/sipfrag, application/dtmf-relay (64) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 9: Supported: replaces (19) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 10: Content-Length: 0 (17) Sep 21 09:49:44 VERBOSE[11903] logger.c: --- (11 headers 0 lines)Sep 21 09:49:44 VERBOSE[11903] logger.c: --- (11 headers 0 lines)--- Sep 21 09:49:44 DEBUG[11903] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #37 Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Stopping retransmission on '31b008724aa7afe62b749a9b7edfb3d8@192.168.100.143' of Request 102: Match Found Sep 21 09:49:44 VERBOSE[11903] logger.c: Destroying call '31b008724aa7afe62b749a9b7edfb3d8@192.168.100.143' Sep 21 09:49:44 VERBOSE[11903] logger.c: <-- SIP read from 192.168.100.113:5060: SIP/2.0 486 Busy Here Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK396e9312;rport Call-ID: 0aeeb75573742a6b547bc01b69042fab@192.168.100.143 CSeq: 102 OPTIONS From: "asterisk" ;tag=as1a217aaf To: ;tag=mIFQPBB8eUTOQGCO Contact: Allow: INVITE, ACK, OPTIONS, BYE, CANCEL, REFER, NOTIFY, INFO, PRACK, UPDATE, MESSAGE Accept: application/sdp, message/sipfrag, application/dtmf-relay Supported: replaces Content-Length: 0 Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 0: SIP/2.0 486 Busy Here (21) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK396e9312;rport (66) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 2: Call-ID: 0aeeb75573742a6b547bc01b69042fab@192.168.100.143 (57) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 3: CSeq: 102 OPTIONS (17) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 4: From: "asterisk" ;tag=as1a217aaf (62) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 5: To: ;tag=mIFQPBB8eUTOQGCO (56) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 6: Contact: (40) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 7: Allow: INVITE, ACK, OPTIONS, BYE, CANCEL, REFER, NOTIFY, INFO, PRACK, UPDATE, MESSAGE (85) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 8: Accept: application/sdp, message/sipfrag, application/dtmf-relay (64) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 9: Supported: replaces (19) Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Header 10: Content-Length: 0 (17) Sep 21 09:49:44 VERBOSE[11903] logger.c: --- (11 headers 0 lines)Sep 21 09:49:44 VERBOSE[11903] logger.c: --- (11 headers 0 lines)--- Sep 21 09:49:44 DEBUG[11903] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #39 Sep 21 09:49:44 DEBUG[11903] chan_sip.c: Stopping retransmission on '0aeeb75573742a6b547bc01b69042fab@192.168.100.143' of Request 102: Match Found Sep 21 09:49:44 VERBOSE[11903] logger.c: Destroying call '0aeeb75573742a6b547bc01b69042fab@192.168.100.143' Sep 21 09:49:48 VERBOSE[11903] logger.c: <-- SIP read from 192.168.100.113:5060: INVITE sip:2007@192.168.100.143 SIP/2.0 Via: SIP/2.0/UDP 192.168.100.113:5060;branch=z9hG4bKDYUnNcF0Gl61ypR9;rport Max-Forwards: 70 User-Agent: IP PHONE 2 V1.52.007 CFG0 From: ;tag=JZZVnacUNFUm2iKR To: "2007" ;tag=as1cfffb3a Call-ID: 43649e36476654f373ad343b407f5e82@192.168.100.143 Contact: CSeq: 1 INVITE Supported: replaces Content-Type: application/sdp Content-Length: 202 v=0 o=- 11924329 61972850 IN IP4 192.168.100.113 s=SIP CALL c=IN IP4 0.0.0.0 t=0 0 m=audio 1722 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendonly Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Header 0: INVITE sip:2007@192.168.100.143 SIP/2.0 (39) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.113:5060;branch=z9hG4bKDYUnNcF0Gl61ypR9;rport (74) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Header 2: Max-Forwards: 70 (16) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Header 3: User-Agent: IP PHONE 2 V1.52.007 CFG0 (41) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Header 4: From: ;tag=JZZVnacUNFUm2iKR (58) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Header 5: To: "2007" ;tag=as1cfffb3a (52) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Header 6: Call-ID: 43649e36476654f373ad343b407f5e82@192.168.100.143 (57) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Header 7: Contact: (40) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Header 8: CSeq: 1 INVITE (14) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Header 9: Supported: replaces (19) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Header 10: Content-Type: application/sdp (29) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Header 11: Content-Length: 202 (19) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Header 12: (0) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Line: v=0 (3) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Line: o=- 11924329 61972850 IN IP4 192.168.100.113 (44) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Line: s=SIP CALL (10) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Line: c=IN IP4 0.0.0.0 (16) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Line: t=0 0 (5) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Line: m=audio 1722 RTP/AVP 0 101 (26) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Line: a=fmtp:101 0-15 (15) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Line: a=sendonly (10) Sep 21 09:49:48 VERBOSE[11903] logger.c: --- (12 headers 10 lines)Sep 21 09:49:48 VERBOSE[11903] logger.c: --- (12 headers 10 lines)--- Sep 21 09:49:48 DEBUG[11903] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Begin: parsing SIP "Supported: replaces" Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Found SIP option: -replaces- Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Matched SIP option: replaces Sep 21 09:49:48 DEBUG[11903] chan_sip.c: * SIP extension value: 1 for call 43649e36476654f373ad343b407f5e82@192.168.100.143 Sep 21 09:49:48 VERBOSE[11903] logger.c: Using INVITE request as basis request - 43649e36476654f373ad343b407f5e82@192.168.100.143 Sep 21 09:49:48 VERBOSE[11903] logger.c: Sending to 192.168.100.113 : 5060 (NAT) Sep 21 09:49:48 VERBOSE[11903] logger.c: Found RTP audio format 0 Sep 21 09:49:48 VERBOSE[11903] logger.c: Found RTP audio format 101 Sep 21 09:49:48 VERBOSE[11903] logger.c: Peer audio RTP is at port 0.0.0.0:1722 Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Peer audio RTP is at port 0.0.0.0:1722 Sep 21 09:49:48 VERBOSE[11903] logger.c: Found description format PCMU Sep 21 09:49:48 VERBOSE[11903] logger.c: Found description format telephone-event Sep 21 09:49:48 VERBOSE[11903] logger.c: Capabilities: us - 0x104 (ulaw|g729), peer - audio=0x4 (ulaw)/video=0x0 (nothing), combined - 0x4 (ulaw) Sep 21 09:49:48 VERBOSE[11903] logger.c: Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Sep 21 09:49:48 DEBUG[11903] channel.c: Set channel SIP/2007-094241f8 to write format slin Sep 21 09:49:48 VERBOSE[11903] logger.c: -- Started music on hold, class 'default', on channel 'SIP/2007-094241f8' Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Got a SIP re-invite for call 43649e36476654f373ad343b407f5e82@192.168.100.143 Sep 21 09:49:48 VERBOSE[11903] logger.c: We're at 192.168.100.143 port 13358 Sep 21 09:49:48 VERBOSE[11903] logger.c: Adding codec 0x4 (ulaw) to SDP Sep 21 09:49:48 VERBOSE[11903] logger.c: Adding codec 0x100 (g729) to SDP Sep 21 09:49:48 VERBOSE[11903] logger.c: Adding non-codec 0x1 (telephone-event) to SDP Sep 21 09:49:48 VERBOSE[11903] logger.c: Reliably Transmitting (NAT) to 192.168.100.113:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.100.113:5060;branch=z9hG4bKDYUnNcF0Gl61ypR9;received=192.168.100.113;rport=5060 From: ;tag=JZZVnacUNFUm2iKR To: "2007" ;tag=as1cfffb3a Call-ID: 43649e36476654f373ad343b407f5e82@192.168.100.143 CSeq: 1 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 11889 11891 IN IP4 192.168.100.178 s=session c=IN IP4 192.168.100.178 t=0 0 m=audio 1722 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 - - - - --- Sep 21 09:49:48 DEBUG[11903] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #44 Sep 21 09:49:48 DEBUG[11917] rtp.c: Oooh, 'SIP/2003-09429b28' changed end address to 0.0.0.0:0 (format 4) Sep 21 09:49:48 DEBUG[11917] rtp.c: Oooh, 'SIP/2003-09429b28' changed end vaddress to 0.0.0.0:0 (format 4) Sep 21 09:49:48 DEBUG[11917] rtp.c: Oooh, 'SIP/2003-09429b28' was 192.168.100.113:1722/(format 4) Sep 21 09:49:48 DEBUG[11917] rtp.c: Oooh, 'SIP/2003-09429b28' was 0.0.0.0:0/(format 4) Sep 21 09:49:48 DEBUG[11917] chan_sip.c: Sending reinvite on SIP 'FZk7d0lnH94jBJcv@192.168.100.178' - It's audio soon redirected to IP 192.168.100.143 Sep 21 09:49:48 VERBOSE[11917] logger.c: set_destination: Parsing for address/port to send to Sep 21 09:49:48 VERBOSE[11917] logger.c: set_destination: set destination to 192.168.100.178, port 5060 Sep 21 09:49:48 VERBOSE[11917] logger.c: We're at 192.168.100.143 port 14462 Sep 21 09:49:48 VERBOSE[11917] logger.c: Adding codec 0x4 (ulaw) to SDP Sep 21 09:49:48 DEBUG[11917] chan_sip.c: Header 0: INVITE sip:2007@192.168.100.178:5060 SIP/2.0 (44) Sep 21 09:49:48 DEBUG[11917] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK1ae33d4f;rport (66) Sep 21 09:49:48 DEBUG[11917] chan_sip.c: Header 2: From: "2003" ;tag=as099a99d9 (54) Sep 21 09:49:48 DEBUG[11917] chan_sip.c: Header 3: To: "2007" ;tag=wMTIase1FbX5VOfE (58) Sep 21 09:49:48 DEBUG[11917] chan_sip.c: Header 4: Contact: (35) Sep 21 09:49:48 DEBUG[11917] chan_sip.c: Header 5: Call-ID: FZk7d0lnH94jBJcv@192.168.100.178 (41) Sep 21 09:49:48 DEBUG[11917] chan_sip.c: Header 6: CSeq: 103 INVITE (16) Sep 21 09:49:48 DEBUG[11917] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Sep 21 09:49:48 DEBUG[11917] chan_sip.c: Header 8: Max-Forwards: 70 (16) Sep 21 09:49:48 DEBUG[11917] chan_sip.c: Header 9: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Sep 21 09:49:48 DEBUG[11917] chan_sip.c: Header 10: X-asterisk-info: SIP re-invite (RTP bridge) (43) Sep 21 09:49:48 DEBUG[11917] chan_sip.c: Header 11: Content-Type: application/sdp (29) Sep 21 09:49:48 DEBUG[11917] chan_sip.c: Header 12: Content-Length: 166 (19) Sep 21 09:49:48 DEBUG[11917] chan_sip.c: Header 13: (0) Sep 21 09:49:48 DEBUG[11917] chan_sip.c: Line: v=0 (3) Sep 21 09:49:48 DEBUG[11917] chan_sip.c: Line: o=root 11889 11891 IN IP4 192.168.100.143 (41) Sep 21 09:49:48 DEBUG[11917] chan_sip.c: Line: s=session (9) Sep 21 09:49:48 DEBUG[11917] chan_sip.c: Line: c=IN IP4 192.168.100.143 (24) Sep 21 09:49:48 DEBUG[11917] chan_sip.c: Line: t=0 0 (5) Sep 21 09:49:48 DEBUG[11917] chan_sip.c: Line: m=audio 14462 RTP/AVP 0 (23) Sep 21 09:49:48 DEBUG[11917] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Sep 21 09:49:48 DEBUG[11917] chan_sip.c: Line: a=silenceSupp:off - - - - (25) Sep 21 09:49:48 VERBOSE[11917] logger.c: 13 headers, 8 lines Sep 21 09:49:48 VERBOSE[11917] logger.c: Reliably Transmitting (NAT) to 192.168.100.178:5060: INVITE sip:2007@192.168.100.178:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK1ae33d4f;rport From: "2003" ;tag=as099a99d9 To: "2007" ;tag=wMTIase1FbX5VOfE Contact: Call-ID: FZk7d0lnH94jBJcv@192.168.100.178 CSeq: 103 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY X-asterisk-info: SIP re-invite (RTP bridge) Content-Type: application/sdp Content-Length: 166 v=0 o=root 11889 11891 IN IP4 192.168.100.143 s=session c=IN IP4 192.168.100.143 t=0 0 m=audio 14462 RTP/AVP 0 a=rtpmap:0 PCMU/8000 a=silenceSupp:off - - - - --- Sep 21 09:49:48 DEBUG[11917] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #45 Sep 21 09:49:48 DEBUG[11893] res_musiconhold.c: Read 185 bytes of audio while expecting 1600 Sep 21 09:49:48 VERBOSE[11903] logger.c: <-- SIP read from 192.168.100.113:5060: ACK sip:2007@192.168.100.143 SIP/2.0 Via: SIP/2.0/UDP 192.168.100.113:5060;branch=z9hG4bKCSowKj73gGG0BHDO;rport Max-Forwards: 70 User-Agent: IP PHONE 2 V1.52.007 CFG0 From: ;tag=JZZVnacUNFUm2iKR To: "2007" ;tag=as1cfffb3a Call-ID: 43649e36476654f373ad343b407f5e82@192.168.100.143 Contact: CSeq: 1 ACK Content-Length: 0 Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Header 0: ACK sip:2007@192.168.100.143 SIP/2.0 (36) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.113:5060;branch=z9hG4bKCSowKj73gGG0BHDO;rport (74) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Header 2: Max-Forwards: 70 (16) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Header 3: User-Agent: IP PHONE 2 V1.52.007 CFG0 (41) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Header 4: From: ;tag=JZZVnacUNFUm2iKR (58) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Header 5: To: "2007" ;tag=as1cfffb3a (52) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Header 6: Call-ID: 43649e36476654f373ad343b407f5e82@192.168.100.143 (57) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Header 7: Contact: (40) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Header 8: CSeq: 1 ACK (11) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Header 9: Content-Length: 0 (17) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Header 10: (0) Sep 21 09:49:48 VERBOSE[11903] logger.c: --- (10 headers 0 lines)Sep 21 09:49:48 VERBOSE[11903] logger.c: --- (10 headers 0 lines)--- Sep 21 09:49:48 DEBUG[11903] chan_sip.c: **** Received ACK (6) - Command in SIP ACK Sep 21 09:49:48 DEBUG[11903] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #44 Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Stopping retransmission on '43649e36476654f373ad343b407f5e82@192.168.100.143' of Response 1: Match Found Sep 21 09:49:48 VERBOSE[11903] logger.c: <-- SIP read from 192.168.100.178:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK1ae33d4f;rport Call-ID: FZk7d0lnH94jBJcv@192.168.100.178 CSeq: 103 INVITE From: "2003" ;tag=as099a99d9 To: "2007" ;tag=wMTIase1FbX5VOfE Contact: Allow: INVITE, ACK, OPTIONS, BYE, CANCEL, REFER, NOTIFY, INFO, PRACK, UPDATE, MESSAGE Supported: replaces Content-Type: application/sdp Content-Length: 142 v=0 o=- 65762322 54625253 IN IP4 192.168.100.178 s=SIP CALL c=IN IP4 192.168.100.178 t=0 0 m=audio 1722 RTP/AVP 0 a=rtpmap:0 PCMU/8000 Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK1ae33d4f;rport (66) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Header 2: Call-ID: FZk7d0lnH94jBJcv@192.168.100.178 (41) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Header 3: CSeq: 103 INVITE (16) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Header 4: From: "2003" ;tag=as099a99d9 (54) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Header 5: To: "2007" ;tag=wMTIase1FbX5VOfE (58) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Header 6: Contact: (40) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Header 7: Allow: INVITE, ACK, OPTIONS, BYE, CANCEL, REFER, NOTIFY, INFO, PRACK, UPDATE, MESSAGE (85) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Header 8: Supported: replaces (19) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Header 9: Content-Type: application/sdp (29) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Header 10: Content-Length: 142 (19) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Header 11: (0) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Line: v=0 (3) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Line: o=- 65762322 54625253 IN IP4 192.168.100.178 (44) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Line: s=SIP CALL (10) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Line: c=IN IP4 192.168.100.178 (24) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Line: t=0 0 (5) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Line: m=audio 1722 RTP/AVP 0 (22) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Sep 21 09:49:48 VERBOSE[11903] logger.c: --- (11 headers 7 lines)Sep 21 09:49:48 VERBOSE[11903] logger.c: --- (11 headers 7 lines)--- Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Acked pending invite 103 Sep 21 09:49:48 DEBUG[11903] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #45 Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Stopping retransmission on 'FZk7d0lnH94jBJcv@192.168.100.178' of Request 103: Match Found Sep 21 09:49:48 DEBUG[11903] chan_sip.c: SIP response 200 to RE-invite on outgoing call FZk7d0lnH94jBJcv@192.168.100.178 Sep 21 09:49:48 VERBOSE[11903] logger.c: Found RTP audio format 0 Sep 21 09:49:48 VERBOSE[11903] logger.c: Peer audio RTP is at port 192.168.100.178:1722 Sep 21 09:49:48 DEBUG[11903] chan_sip.c: Peer audio RTP is at port 192.168.100.178:1722 Sep 21 09:49:48 VERBOSE[11903] logger.c: Found description format PCMU Sep 21 09:49:48 VERBOSE[11903] logger.c: Capabilities: us - 0x104 (ulaw|g729), peer - audio=0x4 (ulaw)/video=0x0 (nothing), combined - 0x4 (ulaw) Sep 21 09:49:48 VERBOSE[11903] logger.c: Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) Sep 21 09:49:48 DEBUG[11903] chan_sip.c: build_route: Retaining previous route: Sep 21 09:49:48 VERBOSE[11903] logger.c: set_destination: Parsing for address/port to send to Sep 21 09:49:48 VERBOSE[11903] logger.c: set_destination: set destination to 192.168.100.178, port 5060 Sep 21 09:49:48 VERBOSE[11903] logger.c: Transmitting (NAT) to 192.168.100.178:5060: ACK sip:2007@192.168.100.178:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK29ad2c0e;rport From: "2003" ;tag=as099a99d9 To: "2007" ;tag=wMTIase1FbX5VOfE Contact: Call-ID: FZk7d0lnH94jBJcv@192.168.100.178 CSeq: 103 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Sep 21 09:49:48 NOTICE[11893] res_musiconhold.c: Request to schedule in the past?!?! Sep 21 09:49:48 DEBUG[11893] res_musiconhold.c: Read 184 bytes of audio while expecting 1600 Sep 21 09:49:48 DEBUG[11917] channel.c: Auto-deactivating generator Sep 21 09:49:48 DEBUG[11917] channel.c: Set channel SIP/2007-094241f8 to write format ulaw Sep 21 09:49:48 VERBOSE[11917] logger.c: -- Stopped music on hold on SIP/2007-094241f8 Sep 21 09:49:50 VERBOSE[11903] logger.c: <-- SIP read from 192.168.100.113:5060: INVITE sip:2006@192.168.100.143 SIP/2.0 Via: SIP/2.0/UDP 192.168.100.113:5060;branch=z9hG4bK9NbkKaIWBNuflTuB;rport Max-Forwards: 70 User-Agent: IP PHONE 2 V1.52.007 CFG0 From: "2003" ;tag=tDelXfepblJ4S4hM To: "2006" Call-ID: HuPWJRxkK5c7m4YT@192.168.100.113 Contact: CSeq: 1 INVITE Supported: replaces Content-Type: application/sdp Content-Length: 224 v=0 o=- 86939173 36118752 IN IP4 192.168.100.113 s=SIP CALL c=IN IP4 192.168.100.113 t=0 0 m=audio 1722 RTP/AVP 18 0 101 a=rtpmap:18 G729/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 0: INVITE sip:2006@192.168.100.143 SIP/2.0 (39) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.113:5060;branch=z9hG4bK9NbkKaIWBNuflTuB;rport (74) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 2: Max-Forwards: 70 (16) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 3: User-Agent: IP PHONE 2 V1.52.007 CFG0 (41) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 4: From: "2003" ;tag=tDelXfepblJ4S4hM (60) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 5: To: "2006" (37) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 6: Call-ID: HuPWJRxkK5c7m4YT@192.168.100.113 (41) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 7: Contact: (40) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 8: CSeq: 1 INVITE (14) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 9: Supported: replaces (19) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 10: Content-Type: application/sdp (29) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 11: Content-Length: 224 (19) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 12: (0) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Line: v=0 (3) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Line: o=- 86939173 36118752 IN IP4 192.168.100.113 (44) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Line: s=SIP CALL (10) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Line: c=IN IP4 192.168.100.113 (24) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Line: t=0 0 (5) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Line: m=audio 1722 RTP/AVP 18 0 101 (29) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Line: a=rtpmap:18 G729/8000 (21) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Line: a=fmtp:101 0-15 (15) Sep 21 09:49:50 VERBOSE[11903] logger.c: --- (12 headers 10 lines)Sep 21 09:49:50 VERBOSE[11903] logger.c: --- (12 headers 10 lines)--- Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Allocating new SIP dialog for HuPWJRxkK5c7m4YT@192.168.100.113 - INVITE (With RTP) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Begin: parsing SIP "Supported: replaces" Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Found SIP option: -replaces- Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Matched SIP option: replaces Sep 21 09:49:50 DEBUG[11903] chan_sip.c: * SIP extension value: 1 for call HuPWJRxkK5c7m4YT@192.168.100.113 Sep 21 09:49:50 VERBOSE[11903] logger.c: Using INVITE request as basis request - HuPWJRxkK5c7m4YT@192.168.100.113 Sep 21 09:49:50 VERBOSE[11903] logger.c: Sending to 192.168.100.113 : 5060 (NAT) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Setting NAT on RTP to 524288 Sep 21 09:49:50 VERBOSE[11903] logger.c: Reliably Transmitting (NAT) to 192.168.100.113:5060: SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 192.168.100.113:5060;branch=z9hG4bK9NbkKaIWBNuflTuB;received=192.168.100.113;rport=5060 From: "2003" ;tag=tDelXfepblJ4S4hM To: "2006" ;tag=as40e58400 Call-ID: HuPWJRxkK5c7m4YT@192.168.100.113 CSeq: 1 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Proxy-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="7b7af5c7" Content-Length: 0 --- Sep 21 09:49:50 DEBUG[11903] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #46 Sep 21 09:49:50 VERBOSE[11903] logger.c: Scheduling destruction of call 'HuPWJRxkK5c7m4YT@192.168.100.113' in 15000 ms Sep 21 09:49:50 VERBOSE[11903] logger.c: Found user '2003' Sep 21 09:49:50 VERBOSE[11903] logger.c: <-- SIP read from 192.168.100.113:5060: ACK sip:2006@192.168.100.143 SIP/2.0 Via: SIP/2.0/UDP 192.168.100.113:5060;branch=z9hG4bK9NbkKaIWBNuflTuB;rport Max-Forwards: 70 User-Agent: IP PHONE 2 V1.52.007 CFG0 From: "2003" ;tag=tDelXfepblJ4S4hM To: "2006" ;tag=as40e58400 Call-ID: HuPWJRxkK5c7m4YT@192.168.100.113 Contact: CSeq: 1 ACK Content-Length: 0 Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 0: ACK sip:2006@192.168.100.143 SIP/2.0 (36) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.113:5060;branch=z9hG4bK9NbkKaIWBNuflTuB;rport (74) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 2: Max-Forwards: 70 (16) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 3: User-Agent: IP PHONE 2 V1.52.007 CFG0 (41) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 4: From: "2003" ;tag=tDelXfepblJ4S4hM (60) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 5: To: "2006" ;tag=as40e58400 (52) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 6: Call-ID: HuPWJRxkK5c7m4YT@192.168.100.113 (41) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 7: Contact: (40) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 8: CSeq: 1 ACK (11) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 9: Content-Length: 0 (17) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 10: (0) Sep 21 09:49:50 VERBOSE[11903] logger.c: --- (10 headers 0 lines)Sep 21 09:49:50 VERBOSE[11903] logger.c: --- (10 headers 0 lines)--- Sep 21 09:49:50 DEBUG[11903] chan_sip.c: **** Received ACK (6) - Command in SIP ACK Sep 21 09:49:50 DEBUG[11903] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #46 Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Stopping retransmission on 'HuPWJRxkK5c7m4YT@192.168.100.113' of Response 1: Match Found Sep 21 09:49:50 VERBOSE[11903] logger.c: <-- SIP read from 192.168.100.113:5060: INVITE sip:2006@192.168.100.143 SIP/2.0 Via: SIP/2.0/UDP 192.168.100.113:5060;branch=z9hG4bKzdCQ0cmyZ1gmmd87;rport Max-Forwards: 70 User-Agent: IP PHONE 2 V1.52.007 CFG0 From: "2003" ;tag=tDelXfepblJ4S4hM To: "2006" Call-ID: HuPWJRxkK5c7m4YT@192.168.100.113 Contact: Proxy-Authorization: Digest username="2003", realm="asterisk", nonce="7b7af5c7", uri="sip:2006@192.168.100.143", response="63677b83af9ef8dc71063b5dfe8aecae", algorithm=MD5 CSeq: 2 INVITE Supported: replaces Content-Type: application/sdp Content-Length: 224 v=0 o=- 49247640 03227478 IN IP4 192.168.100.113 s=SIP CALL c=IN IP4 192.168.100.113 t=0 0 m=audio 1722 RTP/AVP 18 0 101 a=rtpmap:18 G729/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 0: INVITE sip:2006@192.168.100.143 SIP/2.0 (39) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.113:5060;branch=z9hG4bKzdCQ0cmyZ1gmmd87;rport (74) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 2: Max-Forwards: 70 (16) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 3: User-Agent: IP PHONE 2 V1.52.007 CFG0 (41) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 4: From: "2003" ;tag=tDelXfepblJ4S4hM (60) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 5: To: "2006" (37) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 6: Call-ID: HuPWJRxkK5c7m4YT@192.168.100.113 (41) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 7: Contact: (40) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 8: Proxy-Authorization: Digest username="2003", realm="asterisk", nonce="7b7af5c7", uri="sip:2006@192.168.100.143", response="63677b83af9ef8dc71063b5dfe8aecae", algorithm=MD5 (171) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 9: CSeq: 2 INVITE (14) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 10: Supported: replaces (19) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 11: Content-Type: application/sdp (29) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 12: Content-Length: 224 (19) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 13: (0) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Line: v=0 (3) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Line: o=- 49247640 03227478 IN IP4 192.168.100.113 (44) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Line: s=SIP CALL (10) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Line: c=IN IP4 192.168.100.113 (24) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Line: t=0 0 (5) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Line: m=audio 1722 RTP/AVP 18 0 101 (29) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Line: a=rtpmap:18 G729/8000 (21) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Line: a=fmtp:101 0-15 (15) Sep 21 09:49:50 VERBOSE[11903] logger.c: --- (13 headers 10 lines)Sep 21 09:49:50 VERBOSE[11903] logger.c: --- (13 headers 10 lines)--- Sep 21 09:49:50 DEBUG[11903] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE Sep 21 09:49:50 VERBOSE[11903] logger.c: Using INVITE request as basis request - HuPWJRxkK5c7m4YT@192.168.100.113 Sep 21 09:49:50 VERBOSE[11903] logger.c: Sending to 192.168.100.113 : 5060 (NAT) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Setting NAT on RTP to 524288 Sep 21 09:49:50 VERBOSE[11903] logger.c: Found user '2003' Sep 21 09:49:50 VERBOSE[11903] logger.c: Found RTP audio format 18 Sep 21 09:49:50 VERBOSE[11903] logger.c: Found RTP audio format 0 Sep 21 09:49:50 VERBOSE[11903] logger.c: Found RTP audio format 101 Sep 21 09:49:50 VERBOSE[11903] logger.c: Peer audio RTP is at port 192.168.100.113:1722 Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Peer audio RTP is at port 192.168.100.113:1722 Sep 21 09:49:50 VERBOSE[11903] logger.c: Found description format G729 Sep 21 09:49:50 VERBOSE[11903] logger.c: Found description format PCMU Sep 21 09:49:50 VERBOSE[11903] logger.c: Found description format telephone-event Sep 21 09:49:50 VERBOSE[11903] logger.c: Capabilities: us - 0x104 (ulaw|g729), peer - audio=0x104 (ulaw|g729)/video=0x0 (nothing), combined - 0x104 (ulaw|g729) Sep 21 09:49:50 VERBOSE[11903] logger.c: Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Checking SIP call limits for device 2003 Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Updating call counter for incoming call Sep 21 09:49:50 VERBOSE[11903] logger.c: Looking for 2006 in phones (domain 192.168.100.143) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: build_route: Contact hop: Sep 21 09:49:50 VERBOSE[11903] logger.c: list_route: hop: Sep 21 09:49:50 VERBOSE[11903] logger.c: Transmitting (NAT) to 192.168.100.113:5060: SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.100.113:5060;branch=z9hG4bKzdCQ0cmyZ1gmmd87;received=192.168.100.113;rport=5060 From: "2003" ;tag=tDelXfepblJ4S4hM To: "2006" Call-ID: HuPWJRxkK5c7m4YT@192.168.100.113 CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- Sep 21 09:49:50 DEBUG[11892] chan_sip.c: Checking device state for peer 2003 Sep 21 09:49:50 DEBUG[11892] devicestate.c: Changing state for SIP/2003 - state 2 (In use) Sep 21 09:49:50 DEBUG[11927] pbx.c: Launching 'Dial' Sep 21 09:49:50 VERBOSE[11927] logger.c: -- Executing Dial("SIP/2003-09431908", "SIP/2006") in new stack Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Setting NAT on RTP to 524288 Sep 21 09:49:50 DEBUG[11927] channel.c: Not copying variable STACK-phones-2006-1. Sep 21 09:49:50 DEBUG[11927] channel.c: Not copying variable SIPCALLID. Sep 21 09:49:50 DEBUG[11927] channel.c: Not copying variable SIPUSERAGENT. Sep 21 09:49:50 DEBUG[11927] channel.c: Not copying variable SIPDOMAIN. Sep 21 09:49:50 DEBUG[11927] channel.c: Not copying variable SIPURI. Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Outgoing Call for 2006 Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Updating call counter for outgoing call Sep 21 09:49:50 VERBOSE[11927] logger.c: We're at 192.168.100.143 port 13516 Sep 21 09:49:50 VERBOSE[11927] logger.c: Adding codec 0x100 (g729) to SDP Sep 21 09:49:50 VERBOSE[11927] logger.c: Adding non-codec 0x1 (telephone-event) to SDP Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Header 0: INVITE sip:2006@192.168.100.142:5060 SIP/2.0 (44) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK0e57d9f7;rport (66) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Header 2: From: "2003" ;tag=as133c9356 (54) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Header 3: To: (35) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Header 4: Contact: (35) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Header 5: Call-ID: 0cf81c53097df9274ce2975d1448ec50@192.168.100.143 (57) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Header 6: CSeq: 102 INVITE (16) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Header 8: Max-Forwards: 70 (16) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Header 9: Date: Thu, 21 Sep 2006 01:49:50 GMT (35) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Header 11: Content-Type: application/sdp (29) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Header 12: Content-Length: 245 (19) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Header 13: (0) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Line: v=0 (3) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Line: o=root 11889 11889 IN IP4 192.168.100.143 (41) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Line: s=session (9) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Line: c=IN IP4 192.168.100.143 (24) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Line: t=0 0 (5) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Line: m=audio 13516 RTP/AVP 18 101 (28) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Line: a=rtpmap:18 G729/8000 (21) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Line: a=fmtp:18 annexb=no (19) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Line: a=fmtp:101 0-16 (15) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Line: a=silenceSupp:off - - - - (25) Sep 21 09:49:50 VERBOSE[11927] logger.c: 13 headers, 11 lines Sep 21 09:49:50 VERBOSE[11927] logger.c: Reliably Transmitting (NAT) to 192.168.100.142:5060: INVITE sip:2006@192.168.100.142:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK0e57d9f7;rport From: "2003" ;tag=as133c9356 To: Contact: Call-ID: 0cf81c53097df9274ce2975d1448ec50@192.168.100.143 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Thu, 21 Sep 2006 01:49:50 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Type: application/sdp Content-Length: 245 v=0 o=root 11889 11889 IN IP4 192.168.100.143 s=session c=IN IP4 192.168.100.143 t=0 0 m=audio 13516 RTP/AVP 18 101 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- Sep 21 09:49:50 DEBUG[11927] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #48 Sep 21 09:49:50 VERBOSE[11927] logger.c: -- Called 2006 Sep 21 09:49:50 DEBUG[11928] app_queue.c: Device 'SIP/2003' changed to state '2' (In use) but we don't care because they're not a member of any queue. Sep 21 09:49:50 VERBOSE[11903] logger.c: <-- SIP read from 192.168.100.142:5060: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK0e57d9f7;rport Call-ID: 0cf81c53097df9274ce2975d1448ec50@192.168.100.143 CSeq: 102 INVITE From: "2003" ;tag=as133c9356 To: ;tag=48KmtZG8ss54cwzX Contact: Content-Length: 0 Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 0: SIP/2.0 180 Ringing (19) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK0e57d9f7;rport (66) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 2: Call-ID: 0cf81c53097df9274ce2975d1448ec50@192.168.100.143 (57) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 3: CSeq: 102 INVITE (16) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 4: From: "2003" ;tag=as133c9356 (54) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 5: To: ;tag=48KmtZG8ss54cwzX (56) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 6: Contact: (40) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 7: Content-Length: 0 (17) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 8: (0) Sep 21 09:49:50 VERBOSE[11903] logger.c: --- (8 headers 0 lines)Sep 21 09:49:50 VERBOSE[11903] logger.c: --- (8 headers 0 lines)--- Sep 21 09:49:50 DEBUG[11903] chan_sip.c: *** SIP TIMER: Cancelling retransmission #48 - INVITE (got response) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '0cf81c53097df9274ce2975d1448ec50@192.168.100.143' Request 102: Found Sep 21 09:49:50 DEBUG[11903] chan_sip.c: SIP response 180 to standard invite Sep 21 09:49:50 VERBOSE[11927] logger.c: -- SIP/2006-0943a788 is ringing Sep 21 09:49:50 VERBOSE[11927] logger.c: Transmitting (NAT) to 192.168.100.113:5060: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.100.113:5060;branch=z9hG4bKzdCQ0cmyZ1gmmd87;received=192.168.100.113;rport=5060 From: "2003" ;tag=tDelXfepblJ4S4hM To: "2006" ;tag=as45192896 Call-ID: HuPWJRxkK5c7m4YT@192.168.100.113 CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- Sep 21 09:49:50 DEBUG[11892] chan_sip.c: Checking device state for peer 2006 Sep 21 09:49:50 DEBUG[11892] devicestate.c: Changing state for SIP/2006 - state 6 (Ringing) Sep 21 09:49:50 DEBUG[11929] app_queue.c: Device 'SIP/2006' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. Sep 21 09:49:50 VERBOSE[11903] logger.c: <-- SIP read from 192.168.100.142:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK0e57d9f7;rport Call-ID: 0cf81c53097df9274ce2975d1448ec50@192.168.100.143 CSeq: 102 INVITE From: "2003" ;tag=as133c9356 To: ;tag=48KmtZG8ss54cwzX Contact: Allow: INVITE, ACK, OPTIONS, BYE, CANCEL, REFER, NOTIFY, INFO, PRACK, UPDATE, MESSAGE Supported: replaces Content-Type: application/sdp Content-Length: 200 v=0 o=- 81390443 97188893 IN IP4 192.168.100.142 s=SIP CALL c=IN IP4 192.168.100.142 t=0 0 m=audio 1722 RTP/AVP 18 101 a=rtpmap:18 G729/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK0e57d9f7;rport (66) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 2: Call-ID: 0cf81c53097df9274ce2975d1448ec50@192.168.100.143 (57) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 3: CSeq: 102 INVITE (16) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 4: From: "2003" ;tag=as133c9356 (54) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 5: To: ;tag=48KmtZG8ss54cwzX (56) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 6: Contact: (40) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 7: Allow: INVITE, ACK, OPTIONS, BYE, CANCEL, REFER, NOTIFY, INFO, PRACK, UPDATE, MESSAGE (85) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 8: Supported: replaces (19) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 9: Content-Type: application/sdp (29) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 10: Content-Length: 200 (19) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Header 11: (0) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Line: v=0 (3) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Line: o=- 81390443 97188893 IN IP4 192.168.100.142 (44) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Line: s=SIP CALL (10) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Line: c=IN IP4 192.168.100.142 (24) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Line: t=0 0 (5) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Line: m=audio 1722 RTP/AVP 18 101 (27) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Line: a=rtpmap:18 G729/8000 (21) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Line: a=fmtp:101 0-15 (15) Sep 21 09:49:50 VERBOSE[11903] logger.c: --- (11 headers 9 lines)Sep 21 09:49:50 VERBOSE[11903] logger.c: --- (11 headers 9 lines)--- Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Acked pending invite 102 Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Stopping retransmission on '0cf81c53097df9274ce2975d1448ec50@192.168.100.143' of Request 102: Match Found Sep 21 09:49:50 DEBUG[11903] chan_sip.c: SIP response 200 to standard invite Sep 21 09:49:50 VERBOSE[11903] logger.c: Found RTP audio format 18 Sep 21 09:49:50 VERBOSE[11903] logger.c: Found RTP audio format 101 Sep 21 09:49:50 VERBOSE[11903] logger.c: Peer audio RTP is at port 192.168.100.142:1722 Sep 21 09:49:50 DEBUG[11903] chan_sip.c: Peer audio RTP is at port 192.168.100.142:1722 Sep 21 09:49:50 VERBOSE[11903] logger.c: Found description format G729 Sep 21 09:49:50 VERBOSE[11903] logger.c: Found description format telephone-event Sep 21 09:49:50 VERBOSE[11903] logger.c: Capabilities: us - 0x100 (g729), peer - audio=0x100 (g729)/video=0x0 (nothing), combined - 0x100 (g729) Sep 21 09:49:50 VERBOSE[11903] logger.c: Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Sep 21 09:49:50 DEBUG[11903] chan_sip.c: build_route: Contact hop: Sep 21 09:49:50 VERBOSE[11903] logger.c: list_route: hop: Sep 21 09:49:50 VERBOSE[11903] logger.c: set_destination: Parsing for address/port to send to Sep 21 09:49:50 VERBOSE[11903] logger.c: set_destination: set destination to 192.168.100.142, port 5060 Sep 21 09:49:50 VERBOSE[11903] logger.c: Transmitting (NAT) to 192.168.100.142:5060: ACK sip:2006@192.168.100.142:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK4622a6fa;rport From: "2003" ;tag=as133c9356 To: ;tag=48KmtZG8ss54cwzX Contact: Call-ID: 0cf81c53097df9274ce2975d1448ec50@192.168.100.143 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Sep 21 09:49:50 VERBOSE[11927] logger.c: -- SIP/2006-0943a788 answered SIP/2003-09431908 Sep 21 09:49:50 DEBUG[11927] chan_sip.c: sip_answer(SIP/2003-09431908) Sep 21 09:49:50 VERBOSE[11927] logger.c: We're at 192.168.100.143 port 19332 Sep 21 09:49:50 VERBOSE[11927] logger.c: Adding codec 0x100 (g729) to SDP Sep 21 09:49:50 VERBOSE[11927] logger.c: Adding codec 0x4 (ulaw) to SDP Sep 21 09:49:50 VERBOSE[11927] logger.c: Adding non-codec 0x1 (telephone-event) to SDP Sep 21 09:49:50 VERBOSE[11927] logger.c: Reliably Transmitting (NAT) to 192.168.100.113:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.100.113:5060;branch=z9hG4bKzdCQ0cmyZ1gmmd87;received=192.168.100.113;rport=5060 From: "2003" ;tag=tDelXfepblJ4S4hM To: "2006" ;tag=as45192896 Call-ID: HuPWJRxkK5c7m4YT@192.168.100.113 CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Type: application/sdp Content-Length: 269 v=0 o=root 11889 11889 IN IP4 192.168.100.143 s=session c=IN IP4 192.168.100.143 t=0 0 m=audio 19332 RTP/AVP 18 0 101 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- Sep 21 09:49:50 DEBUG[11927] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #50 Sep 21 09:49:50 VERBOSE[11927] logger.c: -- Attempting native bridge of SIP/2003-09431908 and SIP/2006-0943a788 Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Deferring reinvite on SIP 'HuPWJRxkK5c7m4YT@192.168.100.113' - It's audio will be redirected to IP 192.168.100.142 Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Sending reinvite on SIP '0cf81c53097df9274ce2975d1448ec50@192.168.100.143' - It's audio soon redirected to IP 192.168.100.113 Sep 21 09:49:50 VERBOSE[11927] logger.c: set_destination: Parsing for address/port to send to Sep 21 09:49:50 VERBOSE[11927] logger.c: set_destination: set destination to 192.168.100.142, port 5060 Sep 21 09:49:50 VERBOSE[11927] logger.c: We're at 192.168.100.143 port 13516 Sep 21 09:49:50 VERBOSE[11927] logger.c: Adding codec 0x100 (g729) to SDP Sep 21 09:49:50 VERBOSE[11927] logger.c: Adding codec 0x4 (ulaw) to SDP Sep 21 09:49:50 VERBOSE[11927] logger.c: Adding non-codec 0x1 (telephone-event) to SDP Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Header 0: INVITE sip:2006@192.168.100.142:5060 SIP/2.0 (44) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK004b9273;rport (66) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Header 2: From: "2003" ;tag=as133c9356 (54) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Header 3: To: ;tag=48KmtZG8ss54cwzX (56) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Header 4: Contact: (35) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Header 5: Call-ID: 0cf81c53097df9274ce2975d1448ec50@192.168.100.143 (57) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Header 6: CSeq: 103 INVITE (16) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Header 8: Max-Forwards: 70 (16) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Header 9: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Header 10: X-asterisk-info: SIP re-invite (RTP bridge) (43) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Header 11: Content-Type: application/sdp (29) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Header 12: Content-Length: 268 (19) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Header 13: (0) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Line: v=0 (3) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Line: o=root 11889 11890 IN IP4 192.168.100.113 (41) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Line: s=session (9) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Line: c=IN IP4 192.168.100.113 (24) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Line: t=0 0 (5) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Line: m=audio 1722 RTP/AVP 18 0 101 (29) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Line: a=rtpmap:18 G729/8000 (21) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Line: a=fmtp:18 annexb=no (19) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Line: a=fmtp:101 0-16 (15) Sep 21 09:49:50 DEBUG[11927] chan_sip.c: Line: a=silenceSupp:off - - - - (25) Sep 21 09:49:50 VERBOSE[11927] logger.c: 13 headers, 12 lines Sep 21 09:49:50 DEBUG[11892] chan_sip.c: Checking device state for peer 2006 Sep 21 09:49:50 DEBUG[11892] channel.c: Avoiding initial deadlock for 'SIP/2006-0943a788' Sep 21 09:49:50 VERBOSE[11927] logger.c: Reliably Transmitting (NAT) to 192.168.100.142:5060: INVITE sip:2006@192.168.100.142:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK004b9273;rport From: "2003" ;tag=as133c9356 To: ;tag=48KmtZG8ss54cwzX Contact: Call-ID: 0cf81c53097df9274ce2975d1448ec50@192.168.100.143 CSeq: 103 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY X-asterisk-info: SIP re-invite (RTP bridge) Content-Type: application/sdp Content-Length: 268 v=0 o=root 11889 11890 IN IP4 192.168.100.113 s=session c=IN IP4 192.168.100.113 t=0 0 m=audio 1722 RTP/AVP 18 0 101 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- Sep 21 09:49:50 DEBUG[11927] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #51 Sep 21 09:49:50 DEBUG[11892] devicestate.c: Changing state for SIP/2006 - state 2 (In use) Sep 21 09:49:50 DEBUG[11892] chan_sip.c: Checking device state for peer 2003 Sep 21 09:49:50 DEBUG[11892] devicestate.c: Changing state for SIP/2003 - state 2 (In use) Sep 21 09:49:50 DEBUG[11930] app_queue.c: Device 'SIP/2006' changed to state '2' (In use) but we don't care because they're not a member of any queue. Sep 21 09:49:50 DEBUG[11931] app_queue.c: Device 'SIP/2003' changed to state '2' (In use) but we don't care because they're not a member of any queue. Sep 21 09:49:51 VERBOSE[11903] logger.c: <-- SIP read from 192.168.100.142:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK004b9273;rport Call-ID: 0cf81c53097df9274ce2975d1448ec50@192.168.100.143 CSeq: 103 INVITE From: "2003" ;tag=as133c9356 To: ;tag=48KmtZG8ss54cwzX Contact: Allow: INVITE, ACK, OPTIONS, BYE, CANCEL, REFER, NOTIFY, INFO, PRACK, UPDATE, MESSAGE Supported: replaces Content-Type: application/sdp Content-Length: 200 v=0 o=- 91963036 40600105 IN IP4 192.168.100.142 s=SIP CALL c=IN IP4 192.168.100.142 t=0 0 m=audio 1722 RTP/AVP 18 101 a=rtpmap:18 G729/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK004b9273;rport (66) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 2: Call-ID: 0cf81c53097df9274ce2975d1448ec50@192.168.100.143 (57) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 3: CSeq: 103 INVITE (16) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 4: From: "2003" ;tag=as133c9356 (54) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 5: To: ;tag=48KmtZG8ss54cwzX (56) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 6: Contact: (40) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 7: Allow: INVITE, ACK, OPTIONS, BYE, CANCEL, REFER, NOTIFY, INFO, PRACK, UPDATE, MESSAGE (85) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 8: Supported: replaces (19) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 9: Content-Type: application/sdp (29) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 10: Content-Length: 200 (19) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 11: (0) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Line: v=0 (3) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Line: o=- 91963036 40600105 IN IP4 192.168.100.142 (44) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Line: s=SIP CALL (10) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Line: c=IN IP4 192.168.100.142 (24) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Line: t=0 0 (5) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Line: m=audio 1722 RTP/AVP 18 101 (27) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Line: a=rtpmap:18 G729/8000 (21) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Line: a=fmtp:101 0-15 (15) Sep 21 09:49:51 VERBOSE[11903] logger.c: --- (11 headers 9 lines)Sep 21 09:49:51 VERBOSE[11903] logger.c: --- (11 headers 9 lines)--- Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Acked pending invite 103 Sep 21 09:49:51 DEBUG[11903] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #51 Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Stopping retransmission on '0cf81c53097df9274ce2975d1448ec50@192.168.100.143' of Request 103: Match Found Sep 21 09:49:51 DEBUG[11903] chan_sip.c: SIP response 200 to RE-invite on outgoing call 0cf81c53097df9274ce2975d1448ec50@192.168.100.143 Sep 21 09:49:51 VERBOSE[11903] logger.c: Found RTP audio format 18 Sep 21 09:49:51 VERBOSE[11903] logger.c: Found RTP audio format 101 Sep 21 09:49:51 VERBOSE[11903] logger.c: Peer audio RTP is at port 192.168.100.142:1722 Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Peer audio RTP is at port 192.168.100.142:1722 Sep 21 09:49:51 VERBOSE[11903] logger.c: Found description format G729 Sep 21 09:49:51 VERBOSE[11903] logger.c: Found description format telephone-event Sep 21 09:49:51 VERBOSE[11903] logger.c: Capabilities: us - 0x100 (g729), peer - audio=0x100 (g729)/video=0x0 (nothing), combined - 0x100 (g729) Sep 21 09:49:51 VERBOSE[11903] logger.c: Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: build_route: Retaining previous route: Sep 21 09:49:51 VERBOSE[11903] logger.c: set_destination: Parsing for address/port to send to Sep 21 09:49:51 VERBOSE[11903] logger.c: set_destination: set destination to 192.168.100.142, port 5060 Sep 21 09:49:51 VERBOSE[11903] logger.c: Transmitting (NAT) to 192.168.100.142:5060: ACK sip:2006@192.168.100.142:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK2e8c660c;rport From: "2003" ;tag=as133c9356 To: ;tag=48KmtZG8ss54cwzX Contact: Call-ID: 0cf81c53097df9274ce2975d1448ec50@192.168.100.143 CSeq: 103 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Sep 21 09:49:51 VERBOSE[11903] logger.c: <-- SIP read from 192.168.100.113:5060: ACK sip:2006@192.168.100.143 SIP/2.0 Via: SIP/2.0/UDP 192.168.100.113:5060;branch=z9hG4bKJGtLBNSfz1dVSQ2Y;rport Max-Forwards: 70 User-Agent: IP PHONE 2 V1.52.007 CFG0 From: "2003" ;tag=tDelXfepblJ4S4hM To: "2006" ;tag=as45192896 Call-ID: HuPWJRxkK5c7m4YT@192.168.100.113 Contact: Proxy-Authorization: Digest username="2003", realm="asterisk", nonce="7b7af5c7", uri="sip:2006@192.168.100.143", response="9bba04819df306b6bcaffa7f0a163d06", algorithm=MD5 CSeq: 2 ACK Content-Length: 0 Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 0: ACK sip:2006@192.168.100.143 SIP/2.0 (36) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.113:5060;branch=z9hG4bKJGtLBNSfz1dVSQ2Y;rport (74) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 2: Max-Forwards: 70 (16) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 3: User-Agent: IP PHONE 2 V1.52.007 CFG0 (41) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 4: From: "2003" ;tag=tDelXfepblJ4S4hM (60) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 5: To: "2006" ;tag=as45192896 (52) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 6: Call-ID: HuPWJRxkK5c7m4YT@192.168.100.113 (41) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 7: Contact: (40) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 8: Proxy-Authorization: Digest username="2003", realm="asterisk", nonce="7b7af5c7", uri="sip:2006@192.168.100.143", response="9bba04819df306b6bcaffa7f0a163d06", algorithm=MD5 (171) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 9: CSeq: 2 ACK (11) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 10: Content-Length: 0 (17) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 11: (0) Sep 21 09:49:51 VERBOSE[11903] logger.c: --- (11 headers 0 lines)Sep 21 09:49:51 VERBOSE[11903] logger.c: --- (11 headers 0 lines)--- Sep 21 09:49:51 DEBUG[11903] chan_sip.c: **** Received ACK (6) - Command in SIP ACK Sep 21 09:49:51 DEBUG[11903] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #50 Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Stopping retransmission on 'HuPWJRxkK5c7m4YT@192.168.100.113' of Response 2: Match Found Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Sending pending reinvite on 'HuPWJRxkK5c7m4YT@192.168.100.113' Sep 21 09:49:51 VERBOSE[11903] logger.c: set_destination: Parsing for address/port to send to Sep 21 09:49:51 VERBOSE[11903] logger.c: set_destination: set destination to 192.168.100.113, port 5060 Sep 21 09:49:51 VERBOSE[11903] logger.c: We're at 192.168.100.143 port 19332 Sep 21 09:49:51 VERBOSE[11903] logger.c: Adding codec 0x100 (g729) to SDP Sep 21 09:49:51 VERBOSE[11903] logger.c: Adding non-codec 0x1 (telephone-event) to SDP Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 0: INVITE sip:2003@192.168.100.113:5060 SIP/2.0 (44) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK57e1ed51;rport (66) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 2: From: "2006" ;tag=as45192896 (54) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 3: To: "2003" ;tag=tDelXfepblJ4S4hM (58) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 4: Contact: (35) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 5: Call-ID: HuPWJRxkK5c7m4YT@192.168.100.113 (41) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 6: CSeq: 102 INVITE (16) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 8: Max-Forwards: 70 (16) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 9: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 10: X-asterisk-info: SIP re-invite (RTP bridge) (43) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 11: Content-Type: application/sdp (29) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 12: Content-Length: 244 (19) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 13: (0) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Line: v=0 (3) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Line: o=root 11889 11890 IN IP4 192.168.100.142 (41) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Line: s=session (9) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Line: c=IN IP4 192.168.100.142 (24) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Line: t=0 0 (5) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Line: m=audio 1722 RTP/AVP 18 101 (27) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Line: a=rtpmap:18 G729/8000 (21) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Line: a=fmtp:18 annexb=no (19) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Line: a=fmtp:101 0-16 (15) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Line: a=silenceSupp:off - - - - (25) Sep 21 09:49:51 VERBOSE[11903] logger.c: 13 headers, 11 lines Sep 21 09:49:51 VERBOSE[11903] logger.c: Reliably Transmitting (NAT) to 192.168.100.113:5060: INVITE sip:2003@192.168.100.113:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK57e1ed51;rport From: "2006" ;tag=as45192896 To: "2003" ;tag=tDelXfepblJ4S4hM Contact: Call-ID: HuPWJRxkK5c7m4YT@192.168.100.113 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY X-asterisk-info: SIP re-invite (RTP bridge) Content-Type: application/sdp Content-Length: 244 v=0 o=root 11889 11890 IN IP4 192.168.100.142 s=session c=IN IP4 192.168.100.142 t=0 0 m=audio 1722 RTP/AVP 18 101 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- Sep 21 09:49:51 DEBUG[11903] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #52 Sep 21 09:49:51 VERBOSE[11903] logger.c: <-- SIP read from 192.168.100.113:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK57e1ed51;rport Call-ID: HuPWJRxkK5c7m4YT@192.168.100.113 CSeq: 102 INVITE From: "2006" ;tag=as45192896 To: "2003" ;tag=tDelXfepblJ4S4hM Contact: Allow: INVITE, ACK, OPTIONS, BYE, CANCEL, REFER, NOTIFY, INFO, PRACK, UPDATE, MESSAGE Supported: replaces Content-Type: application/sdp Content-Length: 200 v=0 o=- 20051768 80657457 IN IP4 192.168.100.113 s=SIP CALL c=IN IP4 192.168.100.113 t=0 0 m=audio 1722 RTP/AVP 18 101 a=rtpmap:18 G729/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK57e1ed51;rport (66) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 2: Call-ID: HuPWJRxkK5c7m4YT@192.168.100.113 (41) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 3: CSeq: 102 INVITE (16) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 4: From: "2006" ;tag=as45192896 (54) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 5: To: "2003" ;tag=tDelXfepblJ4S4hM (58) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 6: Contact: (40) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 7: Allow: INVITE, ACK, OPTIONS, BYE, CANCEL, REFER, NOTIFY, INFO, PRACK, UPDATE, MESSAGE (85) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 8: Supported: replaces (19) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 9: Content-Type: application/sdp (29) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 10: Content-Length: 200 (19) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Header 11: (0) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Line: v=0 (3) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Line: o=- 20051768 80657457 IN IP4 192.168.100.113 (44) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Line: s=SIP CALL (10) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Line: c=IN IP4 192.168.100.113 (24) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Line: t=0 0 (5) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Line: m=audio 1722 RTP/AVP 18 101 (27) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Line: a=rtpmap:18 G729/8000 (21) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Line: a=fmtp:101 0-15 (15) Sep 21 09:49:51 VERBOSE[11903] logger.c: --- (11 headers 9 lines)Sep 21 09:49:51 VERBOSE[11903] logger.c: --- (11 headers 9 lines)--- Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Acked pending invite 102 Sep 21 09:49:51 DEBUG[11903] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #52 Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Stopping retransmission on 'HuPWJRxkK5c7m4YT@192.168.100.113' of Request 102: Match Found Sep 21 09:49:51 DEBUG[11903] chan_sip.c: SIP response 200 to RE-invite on outgoing call HuPWJRxkK5c7m4YT@192.168.100.113 Sep 21 09:49:51 VERBOSE[11903] logger.c: Found RTP audio format 18 Sep 21 09:49:51 VERBOSE[11903] logger.c: Found RTP audio format 101 Sep 21 09:49:51 VERBOSE[11903] logger.c: Peer audio RTP is at port 192.168.100.113:1722 Sep 21 09:49:51 DEBUG[11903] chan_sip.c: Peer audio RTP is at port 192.168.100.113:1722 Sep 21 09:49:51 VERBOSE[11903] logger.c: Found description format G729 Sep 21 09:49:51 VERBOSE[11903] logger.c: Found description format telephone-event Sep 21 09:49:51 VERBOSE[11903] logger.c: Capabilities: us - 0x104 (ulaw|g729), peer - audio=0x100 (g729)/video=0x0 (nothing), combined - 0x100 (g729) Sep 21 09:49:51 VERBOSE[11903] logger.c: Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Sep 21 09:49:51 DEBUG[11903] chan_sip.c: build_route: Contact hop: Sep 21 09:49:51 VERBOSE[11903] logger.c: list_route: hop: Sep 21 09:49:51 VERBOSE[11903] logger.c: set_destination: Parsing for address/port to send to Sep 21 09:49:51 VERBOSE[11903] logger.c: set_destination: set destination to 192.168.100.113, port 5060 Sep 21 09:49:51 VERBOSE[11903] logger.c: Transmitting (NAT) to 192.168.100.113:5060: ACK sip:2003@192.168.100.113:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK5731a4a2;rport From: "2006" ;tag=as45192896 To: "2003" ;tag=tDelXfepblJ4S4hM Contact: Call-ID: HuPWJRxkK5c7m4YT@192.168.100.113 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Sep 21 09:49:53 VERBOSE[11903] logger.c: <-- SIP read from 192.168.100.113:5060: REFER sip:2006@192.168.100.143 SIP/2.0 Via: SIP/2.0/UDP 192.168.100.113:5060;branch=z9hG4bKo83lYrSmZDrABDsB;rport Max-Forwards: 70 User-Agent: IP PHONE 2 V1.52.007 CFG0 From: "2003" ;tag=tDelXfepblJ4S4hM To: "2006" ;tag=as45192896 Call-ID: HuPWJRxkK5c7m4YT@192.168.100.113 Contact: Proxy-Authorization: Digest username="2003", realm="asterisk", nonce="7b7af5c7", uri="sip:2006@192.168.100.143", response="24af500f2374a9744e3fd90696e01a9c", algorithm=MD5 CSeq: 3 REFER Refer-To: sip:2007@192.168.100.143?Replaces=43649e36476654f373ad343b407f5e82%40192.168.100.143%3bto-tag%3das1cfffb3a%3bfrom-tag%3dJZZVnacUNFUm2iKR Referred-By: Content-Length: 0 Sep 21 09:49:53 DEBUG[11903] chan_sip.c: Header 0: REFER sip:2006@192.168.100.143 SIP/2.0 (38) Sep 21 09:49:53 DEBUG[11903] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.113:5060;branch=z9hG4bKo83lYrSmZDrABDsB;rport (74) Sep 21 09:49:53 DEBUG[11903] chan_sip.c: Header 2: Max-Forwards: 70 (16) Sep 21 09:49:53 DEBUG[11903] chan_sip.c: Header 3: User-Agent: IP PHONE 2 V1.52.007 CFG0 (41) Sep 21 09:49:53 DEBUG[11903] chan_sip.c: Header 4: From: "2003" ;tag=tDelXfepblJ4S4hM (60) Sep 21 09:49:53 DEBUG[11903] chan_sip.c: Header 5: To: "2006" ;tag=as45192896 (52) Sep 21 09:49:53 DEBUG[11903] chan_sip.c: Header 6: Call-ID: HuPWJRxkK5c7m4YT@192.168.100.113 (41) Sep 21 09:49:53 DEBUG[11903] chan_sip.c: Header 7: Contact: (40) Sep 21 09:49:53 DEBUG[11903] chan_sip.c: Header 8: Proxy-Authorization: Digest username="2003", realm="asterisk", nonce="7b7af5c7", uri="sip:2006@192.168.100.143", response="24af500f2374a9744e3fd90696e01a9c", algorithm=MD5 (171) Sep 21 09:49:53 DEBUG[11903] chan_sip.c: Header 9: CSeq: 3 REFER (13) Sep 21 09:49:53 DEBUG[11903] chan_sip.c: Header 10: Refer-To: sip:2007@192.168.100.143?Replaces=43649e36476654f373ad343b407f5e82%40192.168.100.143%3bto-tag%3das1cfffb3a%3bfrom-tag%3dJZZVnacUNFUm2iKR (146) Sep 21 09:49:53 DEBUG[11903] chan_sip.c: Header 11: Referred-By: (39) Sep 21 09:49:53 DEBUG[11903] chan_sip.c: Header 12: Content-Length: 0 (17) Sep 21 09:49:53 DEBUG[11903] chan_sip.c: Header 13: (0) Sep 21 09:49:53 VERBOSE[11903] logger.c: --- (13 headers 0 lines)Sep 21 09:49:53 VERBOSE[11903] logger.c: --- (13 headers 0 lines)--- Sep 21 09:49:53 DEBUG[11903] chan_sip.c: **** Received REFER (9) - Command in SIP REFER Sep 21 09:49:53 DEBUG[11903] chan_sip.c: SIP call transfer received for call HuPWJRxkK5c7m4YT@192.168.100.113 (REFER)! Sep 21 09:49:53 VERBOSE[11903] logger.c: Transfer to 2007 in phones Sep 21 09:49:53 VERBOSE[11903] logger.c: Transfer from 2003 in phones Sep 21 09:49:53 DEBUG[11903] chan_sip.c: Assigning Replace-Call-ID Info 43649e36476654f373ad343b407f5e82@192.168.100.143 to REPLACE_CALL_ID Sep 21 09:49:53 DEBUG[11903] chan_sip.c: 202 Accepted (supervised) Sep 21 09:49:53 DEBUG[11903] channel.c: Planning to masquerade channel SIP/2006-0943a788 into the structure of SIP/2003-09429b28 Sep 21 09:49:53 DEBUG[11903] channel.c: Done planning to masquerade channel SIP/2006-0943a788 into the structure of SIP/2003-09429b28 Sep 21 09:49:53 VERBOSE[11903] logger.c: Transmitting (NAT) to 192.168.100.113:5060: SIP/2.0 202 Accepted Via: SIP/2.0/UDP 192.168.100.113:5060;branch=z9hG4bKo83lYrSmZDrABDsB;received=192.168.100.113;rport=5060 From: "2003" ;tag=tDelXfepblJ4S4hM To: "2006" ;tag=as45192896 Call-ID: HuPWJRxkK5c7m4YT@192.168.100.113 CSeq: 3 REFER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 X-Asterisk-HangupCause: Normal Clearing --- Sep 21 09:49:53 VERBOSE[11903] logger.c: set_destination: Parsing for address/port to send to Sep 21 09:49:53 VERBOSE[11903] logger.c: set_destination: set destination to 192.168.100.113, port 5060 Sep 21 09:49:53 VERBOSE[11903] logger.c: Reliably Transmitting (NAT) to 192.168.100.113:5060: NOTIFY sip:2003@192.168.100.113:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK2c21d83e;rport From: "2006" ;tag=as45192896 To: "2003" ;tag=tDelXfepblJ4S4hM Contact: Call-ID: HuPWJRxkK5c7m4YT@192.168.100.113 CSeq: 103 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: refer;id=3 Subscription-state: terminated;reason=noresource Content-Type: message/sipfrag;version=2.0 Content-Length: 14 SIP/2.0 200 OK --- Sep 21 09:49:53 DEBUG[11903] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #53 Sep 21 09:49:53 VERBOSE[11903] logger.c: set_destination: Parsing for address/port to send to Sep 21 09:49:53 VERBOSE[11903] logger.c: set_destination: set destination to 192.168.100.113, port 5060 Sep 21 09:49:53 VERBOSE[11903] logger.c: Reliably Transmitting (NAT) to 192.168.100.113:5060: BYE sip:2003@192.168.100.113:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK1c4c84a3;rport From: "2006" ;tag=as45192896 To: "2003" ;tag=tDelXfepblJ4S4hM Contact: Call-ID: HuPWJRxkK5c7m4YT@192.168.100.113 CSeq: 104 BYE User-Agent: Asterisk PBX Max-Forwards: 70 X-Asterisk-HangupCause: Normal Clearing Content-Length: 0 --- Sep 21 09:49:53 DEBUG[11903] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #54 Sep 21 09:49:53 DEBUG[11917] channel.c: Actually Masquerading SIP/2006-0943a788(6) into the structure of SIP/2003-09429b28(6) Sep 21 09:49:53 DEBUG[11917] channel.c: Got clone lock for masquerade on 'SIP/2006-0943a788' at 0x94230d4 Sep 21 09:49:53 DEBUG[11917] chan_sip.c: Hangup call SIP/2006-0943a788, SIP callid 43649e36476654f373ad343b407f5e82@192.168.100.143) Sep 21 09:49:53 DEBUG[11917] chan_sip.c: update_call_counter(2003) - decrement call limit counter Sep 21 09:49:53 DEBUG[11917] chan_sip.c: Updating call counter for incoming call Sep 21 09:49:53 VERBOSE[11917] logger.c: Scheduling destruction of call '43649e36476654f373ad343b407f5e82@192.168.100.143' in 32000 ms Sep 21 09:49:53 VERBOSE[11917] logger.c: set_destination: Parsing for address/port to send to Sep 21 09:49:53 VERBOSE[11917] logger.c: set_destination: set destination to 192.168.100.113, port 5060 Sep 21 09:49:53 VERBOSE[11917] logger.c: Reliably Transmitting (NAT) to 192.168.100.113:5060: BYE sip:2003@192.168.100.113:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK5529049c;rport From: "2007" ;tag=as1cfffb3a To: ;tag=JZZVnacUNFUm2iKR Contact: Call-ID: 43649e36476654f373ad343b407f5e82@192.168.100.143 CSeq: 104 BYE User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Sep 21 09:49:53 DEBUG[11917] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #56 Sep 21 09:49:53 WARNING[11917] channel.c: Unable to find a codec translation path from g729 to ulaw Sep 21 09:49:53 WARNING[11917] channel.c: Unable to find a codec translation path from g729 to ulaw Sep 21 09:49:53 DEBUG[11917] channel.c: Putting channel SIP/2006-0943a788 in 4/4 formats Sep 21 09:49:53 DEBUG[11917] channel.c: Released clone lock on 'SIP/2003-09429b28' Sep 21 09:49:53 DEBUG[11917] channel.c: Done Masquerading SIP/2006-0943a788 (6) Sep 21 09:49:53 DEBUG[11917] rtp.c: Oooh, something is weird, backing out Sep 21 09:49:53 VERBOSE[11917] logger.c: -- Attempting native bridge of SIP/2007-094241f8 and SIP/2006-0943a788 Sep 21 09:49:53 DEBUG[11917] rtp.c: Channel codec0 = 4 is not codec1 = 256, cannot native bridge in RTP. Sep 21 09:49:53 WARNING[11917] channel.c: No path to translate from SIP/2007-094241f8(4) to SIP/2006-0943a788(256) Sep 21 09:49:53 WARNING[11917] channel.c: Can't make SIP/2007-094241f8 and SIP/2006-0943a788 compatible Sep 21 09:49:53 WARNING[11917] res_features.c: Bridge failed on channels SIP/2007-094241f8 and SIP/2006-0943a788 Sep 21 09:49:53 DEBUG[11917] pbx.c: Function result is '"2003" <2003>' Sep 21 09:49:53 DEBUG[11917] pbx.c: Function result is '2003' Sep 21 09:49:53 DEBUG[11917] pbx.c: Function result is '2006' Sep 21 09:49:53 DEBUG[11917] pbx.c: Function result is 'phones' Sep 21 09:49:53 DEBUG[11917] pbx.c: Function result is 'SIP/2003-09431908' Sep 21 09:49:53 DEBUG[11917] pbx.c: Function result is 'SIP/2006-0943a788' Sep 21 09:49:53 DEBUG[11917] pbx.c: Function result is 'Dial' Sep 21 09:49:53 DEBUG[11917] pbx.c: Function result is 'SIP/2006' Sep 21 09:49:53 DEBUG[11917] pbx.c: Function result is '2006-09-21 09:49:50' Sep 21 09:49:53 DEBUG[11917] pbx.c: Function result is '2006-09-21 09:49:50' Sep 21 09:49:53 DEBUG[11917] pbx.c: Function result is '2006-09-21 09:49:53' Sep 21 09:49:53 DEBUG[11917] pbx.c: Function result is '3' Sep 21 09:49:53 DEBUG[11917] pbx.c: Function result is '3' Sep 21 09:49:53 DEBUG[11917] pbx.c: Function result is 'ANSWERED' Sep 21 09:49:53 DEBUG[11917] pbx.c: Function result is 'DOCUMENTATION' Sep 21 09:49:53 DEBUG[11917] pbx.c: Function result is '(null)' Sep 21 09:49:53 DEBUG[11917] pbx.c: Function result is '1158803390.2' Sep 21 09:49:53 DEBUG[11917] pbx.c: Function result is '(null)' Sep 21 09:49:53 DEBUG[11917] channel.c: Hanging up channel 'SIP/2006-0943a788' Sep 21 09:49:53 DEBUG[11917] chan_sip.c: Hangup call SIP/2006-0943a788, SIP callid 0cf81c53097df9274ce2975d1448ec50@192.168.100.143) Sep 21 09:49:53 DEBUG[11917] chan_sip.c: update_call_counter(2006) - decrement call limit counter Sep 21 09:49:53 DEBUG[11917] chan_sip.c: Updating call counter for outgoing call Sep 21 09:49:53 VERBOSE[11917] logger.c: Scheduling destruction of call '0cf81c53097df9274ce2975d1448ec50@192.168.100.143' in 32000 ms Sep 21 09:49:53 VERBOSE[11917] logger.c: set_destination: Parsing for address/port to send to Sep 21 09:49:53 VERBOSE[11917] logger.c: set_destination: set destination to 192.168.100.142, port 5060 Sep 21 09:49:53 VERBOSE[11917] logger.c: Reliably Transmitting (NAT) to 192.168.100.142:5060: BYE sip:2006@192.168.100.142:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK077fe2e2;rport From: "2003" ;tag=as133c9356 To: ;tag=48KmtZG8ss54cwzX Contact: Call-ID: 0cf81c53097df9274ce2975d1448ec50@192.168.100.143 CSeq: 104 BYE User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Sep 21 09:49:53 DEBUG[11917] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #58 Sep 21 09:49:53 DEBUG[11917] app_dial.c: Exiting with DIALSTATUS=ANSWER. Sep 21 09:49:53 DEBUG[11917] pbx.c: Spawn extension (phones,2003,1) exited non-zero on 'SIP/2007-094241f8' Sep 21 09:49:53 DEBUG[11917] pbx.c: Function result is '"2007" <2007>' Sep 21 09:49:53 DEBUG[11917] pbx.c: Function result is '2007' Sep 21 09:49:53 DEBUG[11917] pbx.c: Function result is '2003' Sep 21 09:49:53 DEBUG[11917] pbx.c: Function result is 'phones' Sep 21 09:49:53 DEBUG[11917] pbx.c: Function result is 'SIP/2007-094241f8' Sep 21 09:49:53 DEBUG[11917] pbx.c: Function result is 'SIP/2003-09429b28' Sep 21 09:49:53 DEBUG[11917] pbx.c: Function result is 'Dial' Sep 21 09:49:53 DEBUG[11917] pbx.c: Function result is 'SIP/2003' Sep 21 09:49:53 DEBUG[11917] pbx.c: Function result is '2006-09-21 09:49:16' Sep 21 09:49:53 DEBUG[11917] pbx.c: Function result is '2006-09-21 09:49:17' Sep 21 09:49:53 DEBUG[11917] pbx.c: Function result is '2006-09-21 09:49:53' Sep 21 09:49:53 DEBUG[11917] pbx.c: Function result is '37' Sep 21 09:49:53 DEBUG[11917] pbx.c: Function result is '36' Sep 21 09:49:53 DEBUG[11917] pbx.c: Function result is 'ANSWERED' Sep 21 09:49:53 DEBUG[11917] pbx.c: Function result is 'DOCUMENTATION' Sep 21 09:49:53 DEBUG[11917] pbx.c: Function result is '(null)' Sep 21 09:49:53 DEBUG[11917] pbx.c: Function result is '1158803356.0' Sep 21 09:49:53 DEBUG[11917] pbx.c: Function result is '(null)' Sep 21 09:49:53 DEBUG[11917] channel.c: Hanging up channel 'SIP/2007-094241f8' Sep 21 09:49:53 DEBUG[11917] chan_sip.c: Hangup call SIP/2007-094241f8, SIP callid FZk7d0lnH94jBJcv@192.168.100.178) Sep 21 09:49:53 DEBUG[11917] chan_sip.c: update_call_counter(2007) - decrement call limit counter Sep 21 09:49:53 DEBUG[11917] chan_sip.c: Updating call counter for outgoing call Sep 21 09:49:53 VERBOSE[11917] logger.c: Scheduling destruction of call 'FZk7d0lnH94jBJcv@192.168.100.178' in 32000 ms Sep 21 09:49:53 VERBOSE[11917] logger.c: set_destination: Parsing for address/port to send to Sep 21 09:49:53 VERBOSE[11917] logger.c: set_destination: set destination to 192.168.100.178, port 5060 Sep 21 09:49:53 VERBOSE[11917] logger.c: Reliably Transmitting (NAT) to 192.168.100.178:5060: BYE sip:2007@192.168.100.178:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK38f074a2;rport From: "2003" ;tag=as099a99d9 To: "2007" ;tag=wMTIase1FbX5VOfE Contact: Call-ID: FZk7d0lnH94jBJcv@192.168.100.178 CSeq: 104 BYE User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Sep 21 09:49:53 DEBUG[11917] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #60 Sep 21 09:49:53 DEBUG[11927] rtp.c: Oooh, got a hangup Sep 21 09:49:53 DEBUG[11927] channel.c: Returning from native bridge, channels: SIP/2003-09431908, SIP/2003-09429b28 Sep 21 09:49:53 DEBUG[11927] channel.c: Hanging up zombie 'SIP/2003-09429b28' Sep 21 09:49:53 DEBUG[11927] app_dial.c: Exiting with DIALSTATUS=ANSWER. Sep 21 09:49:53 DEBUG[11927] pbx.c: Spawn extension (phones,2006,1) exited non-zero on 'SIP/2003-09431908' Sep 21 09:49:53 DEBUG[11927] channel.c: Hanging up channel 'SIP/2003-09431908' Sep 21 09:49:53 DEBUG[11927] chan_sip.c: Hangup call SIP/2003-09431908, SIP callid HuPWJRxkK5c7m4YT@192.168.100.113) Sep 21 09:49:53 DEBUG[11927] chan_sip.c: update_call_counter(2003) - decrement call limit counter Sep 21 09:49:53 DEBUG[11927] chan_sip.c: Updating call counter for outgoing call Sep 21 09:49:53 DEBUG[11892] chan_sip.c: Checking device state for peer 2006 Sep 21 09:49:53 VERBOSE[11903] logger.c: <-- SIP read from 192.168.100.142:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK077fe2e2;rport Call-ID: 0cf81c53097df9274ce2975d1448ec50@192.168.100.143 CSeq: 104 BYE From: "2003" ;tag=as133c9356 To: ;tag=48KmtZG8ss54cwzX Contact: Content-Length: 0 Sep 21 09:49:53 DEBUG[11903] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Sep 21 09:49:53 DEBUG[11903] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK077fe2e2;rport (66) Sep 21 09:49:53 DEBUG[11903] chan_sip.c: Header 2: Call-ID: 0cf81c53097df9274ce2975d1448ec50@192.168.100.143 (57) Sep 21 09:49:53 DEBUG[11903] chan_sip.c: Header 3: CSeq: 104 BYE (13) Sep 21 09:49:53 DEBUG[11903] chan_sip.c: Header 4: From: "2003" ;tag=as133c9356 (54) Sep 21 09:49:53 DEBUG[11903] chan_sip.c: Header 5: To: ;tag=48KmtZG8ss54cwzX (56) Sep 21 09:49:53 DEBUG[11903] chan_sip.c: Header 6: Contact: (40) Sep 21 09:49:53 DEBUG[11903] chan_sip.c: Header 7: Content-Length: 0 (17) Sep 21 09:49:53 DEBUG[11903] chan_sip.c: Header 8: (0) Sep 21 09:49:53 VERBOSE[11903] logger.c: --- (8 headers 0 lines)Sep 21 09:49:53 VERBOSE[11903] logger.c: --- (8 headers 0 lines)--- Sep 21 09:49:53 DEBUG[11903] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #58 Sep 21 09:49:53 DEBUG[11903] chan_sip.c: Stopping retransmission on '0cf81c53097df9274ce2975d1448ec50@192.168.100.143' of Request 104: Match Found Sep 21 09:49:53 VERBOSE[11903] logger.c: Destroying call '0cf81c53097df9274ce2975d1448ec50@192.168.100.143' Sep 21 09:49:53 VERBOSE[11903] logger.c: <-- SIP read from 192.168.100.178:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK38f074a2;rport Call-ID: FZk7d0lnH94jBJcv@192.168.100.178 CSeq: 104 BYE From: "2003" ;tag=as099a99d9 To: "2007" ;tag=wMTIase1FbX5VOfE Contact: Content-Length: 0 Sep 21 09:49:53 DEBUG[11903] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Sep 21 09:49:53 DEBUG[11903] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK38f074a2;rport (66) Sep 21 09:49:53 DEBUG[11903] chan_sip.c: Header 2: Call-ID: FZk7d0lnH94jBJcv@192.168.100.178 (41) Sep 21 09:49:53 DEBUG[11903] chan_sip.c: Header 3: CSeq: 104 BYE (13) Sep 21 09:49:53 DEBUG[11903] chan_sip.c: Header 4: From: "2003" ;tag=as099a99d9 (54) Sep 21 09:49:53 DEBUG[11903] chan_sip.c: Header 5: To: "2007" ;tag=wMTIase1FbX5VOfE (58) Sep 21 09:49:53 DEBUG[11903] chan_sip.c: Header 6: Contact: (40) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 7: Content-Length: 0 (17) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 8: (0) Sep 21 09:49:54 VERBOSE[11903] logger.c: --- (8 headers 0 lines)Sep 21 09:49:54 VERBOSE[11903] logger.c: --- (8 headers 0 lines)--- Sep 21 09:49:54 DEBUG[11903] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #60 Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Stopping retransmission on 'FZk7d0lnH94jBJcv@192.168.100.178' of Request 104: Match Found Sep 21 09:49:54 DEBUG[11903] chan_sip.c: SIP TIMER: Rescheduling retransmission #56 (1) BYE - 8 Sep 21 09:49:54 DEBUG[11903] chan_sip.c: ** SIP timers: Rescheduling retransmission 2 to 104 ms (t1 52 ms (Retrans id #56)) Sep 21 09:49:54 VERBOSE[11903] logger.c: Retransmitting #1 (NAT) to 192.168.100.113:5060: BYE sip:2003@192.168.100.113:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK5529049c;rport From: "2007" ;tag=as1cfffb3a To: ;tag=JZZVnacUNFUm2iKR Contact: Call-ID: 43649e36476654f373ad343b407f5e82@192.168.100.143 CSeq: 104 BYE User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Sep 21 09:49:54 VERBOSE[11903] logger.c: Destroying call 'FZk7d0lnH94jBJcv@192.168.100.178' Sep 21 09:49:54 VERBOSE[11903] logger.c: <-- SIP read from 192.168.100.113:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK2c21d83e;rport Call-ID: HuPWJRxkK5c7m4YT@192.168.100.113 CSeq: 103 NOTIFY From: "2006" ;tag=as45192896 To: "2003" ;tag=tDelXfepblJ4S4hM Contact: Content-Length: 0 Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK2c21d83e;rport (66) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 2: Call-ID: HuPWJRxkK5c7m4YT@192.168.100.113 (41) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 3: CSeq: 103 NOTIFY (16) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 4: From: "2006" ;tag=as45192896 (54) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 5: To: "2003" ;tag=tDelXfepblJ4S4hM (58) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 6: Contact: (40) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 7: Content-Length: 0 (17) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 8: (0) Sep 21 09:49:54 VERBOSE[11903] logger.c: --- (8 headers 0 lines)Sep 21 09:49:54 VERBOSE[11903] logger.c: --- (8 headers 0 lines)--- Sep 21 09:49:54 DEBUG[11903] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #53 Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Stopping retransmission on 'HuPWJRxkK5c7m4YT@192.168.100.113' of Request 103: Match Found Sep 21 09:49:54 DEBUG[11892] devicestate.c: Changing state for SIP/2006 - state 1 (Not in use) Sep 21 09:49:54 DEBUG[11892] chan_sip.c: Checking device state for peer 2007 Sep 21 09:49:54 DEBUG[11892] devicestate.c: Changing state for SIP/2007 - state 1 (Not in use) Sep 21 09:49:54 DEBUG[11892] chan_sip.c: Checking device state for peer 2003 Sep 21 09:49:54 DEBUG[11892] devicestate.c: Changing state for SIP/2003 - state 1 (Not in use) Sep 21 09:49:54 DEBUG[11892] chan_sip.c: Checking device state for peer 2003 Sep 21 09:49:54 DEBUG[11892] devicestate.c: Changing state for SIP/2003 - state 1 (Not in use) Sep 21 09:49:54 DEBUG[11932] app_queue.c: Device 'SIP/2006' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Sep 21 09:49:54 DEBUG[11933] app_queue.c: Device 'SIP/2007' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Sep 21 09:49:54 DEBUG[11934] app_queue.c: Device 'SIP/2003' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Sep 21 09:49:54 DEBUG[11935] app_queue.c: Device 'SIP/2003' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Sep 21 09:49:54 DEBUG[11903] chan_sip.c: SIP TIMER: Rescheduling retransmission #56 (2) BYE - 8 Sep 21 09:49:54 DEBUG[11903] chan_sip.c: ** SIP timers: Rescheduling retransmission 3 to 208 ms (t1 52 ms (Retrans id #56)) Sep 21 09:49:54 VERBOSE[11903] logger.c: Retransmitting #2 (NAT) to 192.168.100.113:5060: BYE sip:2003@192.168.100.113:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK5529049c;rport From: "2007" ;tag=as1cfffb3a To: ;tag=JZZVnacUNFUm2iKR Contact: Call-ID: 43649e36476654f373ad343b407f5e82@192.168.100.143 CSeq: 104 BYE User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Sep 21 09:49:54 VERBOSE[11903] logger.c: <-- SIP read from 192.168.100.113:5060: BYE sip:2006@192.168.100.143 SIP/2.0 Via: SIP/2.0/UDP 192.168.100.113:5060;branch=z9hG4bKZHUsYE3hATqTCVbv;rport Max-Forwards: 70 User-Agent: IP PHONE 2 V1.52.007 CFG0 From: "2003" ;tag=tDelXfepblJ4S4hM To: "2006" ;tag=as45192896 Call-ID: HuPWJRxkK5c7m4YT@192.168.100.113 Contact: Proxy-Authorization: Digest username="2003", realm="asterisk", nonce="7b7af5c7", uri="sip:2006@192.168.100.143", response="f3a9907c770746c06b038f36ce18a33a", algorithm=MD5 CSeq: 4 BYE Content-Length: 0 Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 0: BYE sip:2006@192.168.100.143 SIP/2.0 (36) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.113:5060;branch=z9hG4bKZHUsYE3hATqTCVbv;rport (74) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 2: Max-Forwards: 70 (16) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 3: User-Agent: IP PHONE 2 V1.52.007 CFG0 (41) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 4: From: "2003" ;tag=tDelXfepblJ4S4hM (60) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 5: To: "2006" ;tag=as45192896 (52) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 6: Call-ID: HuPWJRxkK5c7m4YT@192.168.100.113 (41) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 7: Contact: (40) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 8: Proxy-Authorization: Digest username="2003", realm="asterisk", nonce="7b7af5c7", uri="sip:2006@192.168.100.143", response="f3a9907c770746c06b038f36ce18a33a", algorithm=MD5 (171) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 9: CSeq: 4 BYE (11) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 10: Content-Length: 0 (17) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 11: (0) Sep 21 09:49:54 VERBOSE[11903] logger.c: --- (11 headers 0 lines)Sep 21 09:49:54 VERBOSE[11903] logger.c: --- (11 headers 0 lines)--- Sep 21 09:49:54 DEBUG[11903] chan_sip.c: **** Received BYE (8) - Command in SIP BYE Sep 21 09:49:54 VERBOSE[11903] logger.c: Sending to 192.168.100.113 : 5060 (NAT) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Received bye, no owner, selfdestruct soon. .Sep 21 09:49:54 VERBOSE[11903] logger.c: Transmitting (NAT) to 192.168.100.113:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.100.113:5060;branch=z9hG4bKZHUsYE3hATqTCVbv;received=192.168.100.113;rport=5060 From: "2003" ;tag=tDelXfepblJ4S4hM To: "2006" ;tag=as45192896 Call-ID: HuPWJRxkK5c7m4YT@192.168.100.113 CSeq: 4 BYE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- Sep 21 09:49:54 VERBOSE[11903] logger.c: <-- SIP read from 192.168.100.113:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK1c4c84a3;rport Call-ID: HuPWJRxkK5c7m4YT@192.168.100.113 CSeq: 104 BYE From: "2006" ;tag=as45192896 To: "2003" ;tag=tDelXfepblJ4S4hM Contact: Content-Length: 0 Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK1c4c84a3;rport (66) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 2: Call-ID: HuPWJRxkK5c7m4YT@192.168.100.113 (41) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 3: CSeq: 104 BYE (13) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 4: From: "2006" ;tag=as45192896 (54) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 5: To: "2003" ;tag=tDelXfepblJ4S4hM (58) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 6: Contact: (40) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 7: Content-Length: 0 (17) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 8: (0) Sep 21 09:49:54 VERBOSE[11903] logger.c: --- (8 headers 0 lines)Sep 21 09:49:54 VERBOSE[11903] logger.c: --- (8 headers 0 lines)--- Sep 21 09:49:54 DEBUG[11903] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #54 Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Stopping retransmission on 'HuPWJRxkK5c7m4YT@192.168.100.113' of Request 104: Match Found Sep 21 09:49:54 VERBOSE[11903] logger.c: Destroying call 'HuPWJRxkK5c7m4YT@192.168.100.113' Sep 21 09:49:54 VERBOSE[11903] logger.c: <-- SIP read from 192.168.100.113:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK5529049c;rport Call-ID: 43649e36476654f373ad343b407f5e82@192.168.100.143 CSeq: 104 BYE From: "2007" ;tag=as1cfffb3a To: ;tag=JZZVnacUNFUm2iKR Contact: Content-Length: 0 Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK5529049c;rport (66) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 2: Call-ID: 43649e36476654f373ad343b407f5e82@192.168.100.143 (57) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 3: CSeq: 104 BYE (13) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 4: From: "2007" ;tag=as1cfffb3a (54) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 5: To: ;tag=JZZVnacUNFUm2iKR (56) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 6: Contact: (40) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 7: Content-Length: 0 (17) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 8: (0) Sep 21 09:49:54 VERBOSE[11903] logger.c: --- (8 headers 0 lines)Sep 21 09:49:54 VERBOSE[11903] logger.c: --- (8 headers 0 lines)--- Sep 21 09:49:54 DEBUG[11903] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #56 Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Stopping retransmission on '43649e36476654f373ad343b407f5e82@192.168.100.143' of Request 104: Match Found Sep 21 09:49:54 VERBOSE[11903] logger.c: Destroying call '43649e36476654f373ad343b407f5e82@192.168.100.143' Sep 21 09:49:54 VERBOSE[11903] logger.c: <-- SIP read from 192.168.100.113:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK5529049c;rport Call-ID: 43649e36476654f373ad343b407f5e82@192.168.100.143 CSeq: 104 BYE From: "2007" ;tag=as1cfffb3a To: ;tag=JZZVnacUNFUm2iKR Contact: Content-Length: 0 Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK5529049c;rport (66) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 2: Call-ID: 43649e36476654f373ad343b407f5e82@192.168.100.143 (57) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 3: CSeq: 104 BYE (13) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 4: From: "2007" ;tag=as1cfffb3a (54) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 5: To: ;tag=JZZVnacUNFUm2iKR (56) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 6: Contact: (40) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 7: Content-Length: 0 (17) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 8: (0) Sep 21 09:49:54 VERBOSE[11903] logger.c: --- (8 headers 0 lines)Sep 21 09:49:54 VERBOSE[11903] logger.c: --- (8 headers 0 lines)--- Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Allocating new SIP dialog for 43649e36476654f373ad343b407f5e82@192.168.100.143 - SIP/2.0 (No RTP) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: That's odd... Got a response on a call we dont know about. Cseq 104 Cmd SIP/2.0 Sep 21 09:49:54 VERBOSE[11903] logger.c: Destroying call '43649e36476654f373ad343b407f5e82@192.168.100.143' Sep 21 09:49:54 VERBOSE[11903] logger.c: <-- SIP read from 192.168.100.113:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK5529049c;rport Call-ID: 43649e36476654f373ad343b407f5e82@192.168.100.143 CSeq: 104 BYE From: "2007" ;tag=as1cfffb3a To: ;tag=JZZVnacUNFUm2iKR Contact: Content-Length: 0 Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.143:5060;branch=z9hG4bK5529049c;rport (66) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 2: Call-ID: 43649e36476654f373ad343b407f5e82@192.168.100.143 (57) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 3: CSeq: 104 BYE (13) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 4: From: "2007" ;tag=as1cfffb3a (54) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 5: To: ;tag=JZZVnacUNFUm2iKR (56) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 6: Contact: (40) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 7: Content-Length: 0 (17) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Header 8: (0) Sep 21 09:49:54 VERBOSE[11903] logger.c: --- (8 headers 0 lines)Sep 21 09:49:54 VERBOSE[11903] logger.c: --- (8 headers 0 lines)--- Sep 21 09:49:54 DEBUG[11903] chan_sip.c: Allocating new SIP dialog for 43649e36476654f373ad343b407f5e82@192.168.100.143 - SIP/2.0 (No RTP) Sep 21 09:49:54 DEBUG[11903] chan_sip.c: That's odd... Got a response on a call we dont know about. Cseq 104 Cmd SIP/2.0 Sep 21 09:49:54 VERBOSE[11903] logger.c: Destroying call '43649e36476654f373ad343b407f5e82@192.168.100.143' Sep 21 09:50:08 VERBOSE[11903] logger.c: <-- SIP read from 192.168.100.113:5060: REGISTER sip:192.168.100.143 SIP/2.0 Via: SIP/2.0/UDP 192.168.100.113:5060;branch=z9hG4bKQCC0foRNQxmz0jgO;rport Max-Forwards: 70 User-Agent: IP PHONE 2 V1.52.007 CFG0 From: "2003" ;tag=89bKH0QP6OS86i9E To: "2003" Call-ID: oGwlOGdfi7o8IFMi@192.168.100.113 CSeq: 13844 REGISTER Contact: Expires: 120 Content-Length: 0 Sep 21 09:50:08 DEBUG[11903] chan_sip.c: Header 0: REGISTER sip:192.168.100.143 SIP/2.0 (36) Sep 21 09:50:08 DEBUG[11903] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.113:5060;branch=z9hG4bKQCC0foRNQxmz0jgO;rport (74) Sep 21 09:50:08 DEBUG[11903] chan_sip.c: Header 2: Max-Forwards: 70 (16) Sep 21 09:50:08 DEBUG[11903] chan_sip.c: Header 3: User-Agent: IP PHONE 2 V1.52.007 CFG0 (41) Sep 21 09:50:08 DEBUG[11903] chan_sip.c: Header 4: From: "2003" ;tag=89bKH0QP6OS86i9E (60) Sep 21 09:50:08 DEBUG[11903] chan_sip.c: Header 5: To: "2003" (37) Sep 21 09:50:08 DEBUG[11903] chan_sip.c: Header 6: Call-ID: oGwlOGdfi7o8IFMi@192.168.100.113 (41) Sep 21 09:50:08 DEBUG[11903] chan_sip.c: Header 7: CSeq: 13844 REGISTER (20) Sep 21 09:50:08 DEBUG[11903] chan_sip.c: Header 8: Contact: (40) Sep 21 09:50:08 DEBUG[11903] chan_sip.c: Header 9: Expires: 120 (12) Sep 21 09:50:08 DEBUG[11903] chan_sip.c: Header 10: Content-Length: 0 (17) Sep 21 09:50:08 DEBUG[11903] chan_sip.c: Header 11: (0) Sep 21 09:50:08 VERBOSE[11903] logger.c: --- (11 headers 0 lines)Sep 21 09:50:08 VERBOSE[11903] logger.c: --- (11 headers 0 lines)--- Sep 21 09:50:08 DEBUG[11903] chan_sip.c: Allocating new SIP dialog for oGwlOGdfi7o8IFMi@192.168.100.113 - REGISTER (No RTP) Sep 21 09:50:08 DEBUG[11903] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER Sep 21 09:50:08 VERBOSE[11903] logger.c: Using latest REGISTER request as basis request Sep 21 09:50:08 VERBOSE[11903] logger.c: Sending to 192.168.100.113 : 5060 (NAT) Sep 21 09:50:08 VERBOSE[11903] logger.c: Transmitting (NAT) to 192.168.100.113:5060: SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.100.113:5060;branch=z9hG4bKQCC0foRNQxmz0jgO;received=192.168.100.113;rport=5060 From: "2003" ;tag=89bKH0QP6OS86i9E To: "2003" Call-ID: oGwlOGdfi7o8IFMi@192.168.100.113 CSeq: 13844 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- Sep 21 09:50:08 VERBOSE[11903] logger.c: Transmitting (NAT) to 192.168.100.113:5060: SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.100.113:5060;branch=z9hG4bKQCC0foRNQxmz0jgO;received=192.168.100.113;rport=5060 From: "2003" ;tag=89bKH0QP6OS86i9E To: "2003" ;tag=as09316f17 Call-ID: oGwlOGdfi7o8IFMi@192.168.100.113 CSeq: 13844 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="305fe2d0" Content-Length: 0 --- Sep 21 09:50:08 VERBOSE[11903] logger.c: Scheduling destruction of call 'oGwlOGdfi7o8IFMi@192.168.100.113' in 15000 ms Sep 21 09:50:08 VERBOSE[11903] logger.c: <-- SIP read from 192.168.100.113:5060: REGISTER sip:192.168.100.143 SIP/2.0 Via: SIP/2.0/UDP 192.168.100.113:5060;branch=z9hG4bKwu67ttsavv7yiIhY;rport Max-Forwards: 70 User-Agent: IP PHONE 2 V1.52.007 CFG0 From: "2003" ;tag=89bKH0QP6OS86i9E To: "2003" Call-ID: oGwlOGdfi7o8IFMi@192.168.100.113 CSeq: 13845 REGISTER Contact: Expires: 120 Authorization: Digest username="2003", realm="asterisk", nonce="305fe2d0", uri="sip:192.168.100.143", response="2a462e925aed482f1604765c7b9c2d32", algorithm=MD5 Content-Length: 0 Sep 21 09:50:08 DEBUG[11903] chan_sip.c: Header 0: REGISTER sip:192.168.100.143 SIP/2.0 (36) Sep 21 09:50:08 DEBUG[11903] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.100.113:5060;branch=z9hG4bKwu67ttsavv7yiIhY;rport (74) Sep 21 09:50:08 DEBUG[11903] chan_sip.c: Header 2: Max-Forwards: 70 (16) Sep 21 09:50:08 DEBUG[11903] chan_sip.c: Header 3: User-Agent: IP PHONE 2 V1.52.007 CFG0 (41) Sep 21 09:50:08 DEBUG[11903] chan_sip.c: Header 4: From: "2003" ;tag=89bKH0QP6OS86i9E (60) Sep 21 09:50:08 DEBUG[11903] chan_sip.c: Header 5: To: "2003" (37) Sep 21 09:50:08 DEBUG[11903] chan_sip.c: Header 6: Call-ID: oGwlOGdfi7o8IFMi@192.168.100.113 (41) Sep 21 09:50:08 DEBUG[11903] chan_sip.c: Header 7: CSeq: 13845 REGISTER (20) Sep 21 09:50:08 DEBUG[11903] chan_sip.c: Header 8: Contact: (40) Sep 21 09:50:08 DEBUG[11903] chan_sip.c: Header 9: Expires: 120 (12) Sep 21 09:50:08 DEBUG[11903] chan_sip.c: Header 10: Authorization: Digest username="2003", realm="asterisk", nonce="305fe2d0", uri="sip:192.168.100.143", response="2a462e925aed482f1604765c7b9c2d32", algorithm=MD5 (160) Sep 21 09:50:08 DEBUG[11903] chan_sip.c: Header 11: Content-Length: 0 (17) Sep 21 09:50:08 DEBUG[11903] chan_sip.c: Header 12: (0) Sep 21 09:50:08 VERBOSE[11903] logger.c: --- (12 headers 0 lines)Sep 21 09:50:08 VERBOSE[11903] logger.c: --- (12 headers 0 lines)--- Sep 21 09:50:08 DEBUG[11903] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER Sep 21 09:50:08 VERBOSE[11903] logger.c: Using latest REGISTER request as basis request Sep 21 09:50:08 VERBOSE[11903] logger.c: Sending to 192.168.100.113 : 5060 (NAT) Sep 21 09:50:08 VERBOSE[11903] logger.c: Transmitting (NAT) to 192.168.100.113:5060: SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.100.113:5060;branch=z9hG4bKwu67ttsavv7yiIhY;received=192.168.100.113;rport=5060 From: "2003" ;tag=89bKH0QP6OS86i9E To: "2003" Call-ID: oGwlOGdfi7o8IFMi@192.168.100.113 CSeq: 13845 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- Sep 21 09:50:08 VERBOSE[11903] logger.c: Transmitting (NAT) to 192.168.100.113:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.100.113:5060;branch=z9hG4bKwu67ttsavv7yiIhY;received=192.168.100.113;rport=5060 From: "2003" ;tag=89bKH0QP6OS86i9E To: "2003" ;tag=as09316f17 Call-ID: oGwlOGdfi7o8IFMi@192.168.100.113 CSeq: 13845 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Expires: 120 Contact: ;expires=120 Date: Thu, 21 Sep 2006 01:50:08 GMT Content-Length: 0 --- Sep 21 09:50:08 VERBOSE[11903] logger.c: Scheduling destruction of call 'oGwlOGdfi7o8IFMi@192.168.100.113' in 15000 ms Sep 21 09:50:08 DEBUG[11892] chan_sip.c: Checking device state for peer 2003 Sep 21 09:50:08 DEBUG[11892] devicestate.c: Changing state for SIP/2003 - state 1 (Not in use) Sep 21 09:50:08 DEBUG[11938] app_queue.c: Device 'SIP/2003' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Sep 21 09:50:08 NOTICE[11893] res_musiconhold.c: Request to schedule in the past?!?!