[Feb 8 09:02:18] VERBOSE[17251] logger.c: <--- SIP read from 192.168.30.178:5060 ---> INVITE sip:6000@192.168.30.254:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.30.178;branch=z9hG4bKbd36df310 Max-Forwards: 70 Content-Length: 564 To: 6000 From: Don Wright ;tag=205714ae9d2ac6b Call-ID: b6d07bd0a85bb952fc3184f5e5ba5169@192.168.30.178 CSeq: 92868388 INVITE Supported: timer Session-Expires: 30 Allow-Events: talk,hold,conference Allow:NOTIFY,REFER,OPTIONS,INVITE,ACK,CANCEL,BYE,INFO Content-Type: application/sdp Contact: Don Wright Supported: replaces User-Agent: Aastra 480i/1.4.2.3000 Brcm Callctrl/1.5.1.0 MxSF/v3.2.8.45 v=0 o=MxSIP 0 186891758 IN IP4 192.168.30.178 s=SIP Call c=IN IP4 192.168.30.178 t=0 0 m=audio 3000 RTP/AVP 0 18 96 102 107 104 105 106 97 98 2 99 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:18 G729/8000 a=rtpmap:96 BV16/8000 a=rtpmap:102 BV32/16000 a=rtpmap:107 L16/16000 a=rtpmap:104 PCMU/16000 a=rtpmap:105 PCMA/16000 a=rtpmap:106 L16/8000 a=rtpmap:97 G726-16/8000 a=rtpmap:98 G726-24/8000 a=rtpmap:2 G726-32/8000 a=rtpmap:99 G726-40/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 a=silenceSupp:on - - - - <-------------> [Feb 8 09:02:18] VERBOSE[17251] logger.c: --- (16 headers 23 lines) --- [Feb 8 09:02:18] DEBUG[17251] acl.c: ##### Testing 192.168.30.178 with 192.168.0.0 [Feb 8 09:02:18] DEBUG[17251] acl.c: ##### Testing 192.168.30.178 with 10.0.0.0 [Feb 8 09:02:18] DEBUG[17251] acl.c: ##### Testing 192.168.30.178 with 172.16.0.0 [Feb 8 09:02:18] DEBUG[17251] acl.c: ##### Testing 192.168.30.178 with 169.254.0.0 [Feb 8 09:02:18] DEBUG[17251] chan_sip.c: Setting NAT on RTP to Off [Feb 8 09:02:18] DEBUG[17251] chan_sip.c: Setting NAT on VRTP to Off [Feb 8 09:02:18] DEBUG[17251] chan_sip.c: Allocating new SIP dialog for b6d07bd0a85bb952fc3184f5e5ba5169@192.168.30.178 - INVITE (With RTP) [Feb 8 09:02:18] DEBUG[17251] chan_sip.c: Begin: parsing SIP "Supported: timer" [Feb 8 09:02:18] DEBUG[17251] chan_sip.c: Found SIP option: -timer- [Feb 8 09:02:18] DEBUG[17251] chan_sip.c: Matched SIP option: timer [Feb 8 09:02:18] VERBOSE[17251] logger.c: Sending to 192.168.30.178 : 5060 (no NAT) [Feb 8 09:02:18] VERBOSE[17251] logger.c: Using INVITE request as basis request - b6d07bd0a85bb952fc3184f5e5ba5169@192.168.30.178 [Feb 8 09:02:18] DEBUG[17251] chan_sip.c: Setting NAT on RTP to Off [Feb 8 09:02:18] DEBUG[17251] chan_sip.c: Setting NAT on VRTP to Off [Feb 8 09:02:18] VERBOSE[17251] logger.c: <--- Reliably Transmitting (no NAT) to 192.168.30.178:5060 ---> SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 192.168.30.178;branch=z9hG4bKbd36df310;received=192.168.30.178 From: Don Wright ;tag=205714ae9d2ac6b To: 6000 ;tag=as1fff5ac6 Call-ID: b6d07bd0a85bb952fc3184f5e5ba5169@192.168.30.178 CSeq: 92868388 INVITE User-Agent: Asterisk PBX (Fireworx) Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Proxy-Authenticate: Digest algorithm=MD5, realm="fireworx", nonce="37a6a820" Content-Length: 0 <------------> [Feb 8 09:02:18] VERBOSE[17251] logger.c: Scheduling destruction of SIP dialog 'b6d07bd0a85bb952fc3184f5e5ba5169@192.168.30.178' in 32000 ms (Method: INVITE) [Feb 8 09:02:18] VERBOSE[17251] logger.c: Found user '6004' [Feb 8 09:02:18] VERBOSE[17251] logger.c: <--- SIP read from 192.168.30.178:5060 ---> ACK sip:6000@192.168.30.254:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.30.178;branch=z9hG4bKbd36df310 Max-Forwards: 70 Content-Length: 0 To: 6000 ;tag=as1fff5ac6 From: Don Wright ;tag=205714ae9d2ac6b Call-ID: b6d07bd0a85bb952fc3184f5e5ba5169@192.168.30.178 CSeq: 92868388 ACK User-Agent: Aastra 480i/1.4.2.3000 Brcm Callctrl/1.5.1.0 MxSF/v3.2.8.45 <-------------> [Feb 8 09:02:18] VERBOSE[17251] logger.c: --- (9 headers 0 lines) --- [Feb 8 09:02:18] DEBUG[17251] chan_sip.c: Stopping retransmission on 'b6d07bd0a85bb952fc3184f5e5ba5169@192.168.30.178' of Response 92868388: Match Not Found [Feb 8 09:02:18] VERBOSE[17251] logger.c: <--- SIP read from 192.168.30.178:5060 ---> INVITE sip:6000@192.168.30.254:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.30.178;branch=z9hG4bKa476babd8 Max-Forwards: 70 Content-Length: 564 To: 6000 From: Don Wright ;tag=205714ae9d2ac6b Call-ID: b6d07bd0a85bb952fc3184f5e5ba5169@192.168.30.178 CSeq: 92868389 INVITE Supported: timer Session-Expires: 30 Allow-Events: talk,hold,conference Allow:NOTIFY,REFER,OPTIONS,INVITE,ACK,CANCEL,BYE,INFO Contact: Don Wright Content-Type: application/sdp Supported: replaces Proxy-Authorization:Digest response="bcdda3f01a4387ece69ad082e4fa74f0",username="6004",realm="fireworx",nonce="37a6a820",algorithm=MD5,uri="sip:6000@192.168.30.254:5060" User-Agent: Aastra 480i/1.4.2.3000 Brcm Callctrl/1.5.1.0 MxSF/v3.2.8.45 v=0 o=MxSIP 0 186891758 IN IP4 192.168.30.178 s=SIP Call c=IN IP4 192.168.30.178 t=0 0 m=audio 3000 RTP/AVP 0 18 96 102 107 104 105 106 97 98 2 99 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:18 G729/8000 a=rtpmap:96 BV16/8000 a=rtpmap:102 BV32/16000 a=rtpmap:107 L16/16000 a=rtpmap:104 PCMU/16000 a=rtpmap:105 PCMA/16000 a=rtpmap:106 L16/8000 a=rtpmap:97 G726-16/8000 a=rtpmap:98 G726-24/8000 a=rtpmap:2 G726-32/8000 a=rtpmap:99 G726-40/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 a=silenceSupp:on - - - - <-------------> [Feb 8 09:02:18] VERBOSE[17251] logger.c: --- (17 headers 23 lines) --- [Feb 8 09:02:18] VERBOSE[17251] logger.c: Sending to 192.168.30.178 : 5060 (no NAT) [Feb 8 09:02:18] VERBOSE[17251] logger.c: Using INVITE request as basis request - b6d07bd0a85bb952fc3184f5e5ba5169@192.168.30.178 [Feb 8 09:02:18] DEBUG[17251] chan_sip.c: Setting NAT on RTP to Off [Feb 8 09:02:18] DEBUG[17251] chan_sip.c: Setting NAT on VRTP to Off [Feb 8 09:02:18] DEBUG[17251] sched.c: Attempted to delete nonexistent schedule entry 0! [Feb 8 09:02:18] DEBUG[17251] sched.c: Attempted to delete nonexistent schedule entry 0! [Feb 8 09:02:18] DEBUG[17251] sched.c: Attempted to delete nonexistent schedule entry 0! [Feb 8 09:02:18] DEBUG[17251] sched.c: Attempted to delete nonexistent schedule entry 0! [Feb 8 09:02:18] DEBUG[17251] sched.c: Attempted to delete nonexistent schedule entry 0! [Feb 8 09:02:18] DEBUG[17251] sched.c: Attempted to delete nonexistent schedule entry 0! [Feb 8 09:02:18] DEBUG[17251] sched.c: Attempted to delete nonexistent schedule entry 0! [Feb 8 09:02:18] DEBUG[17251] sched.c: Attempted to delete nonexistent schedule entry 0! [Feb 8 09:02:18] DEBUG[17251] sched.c: Attempted to delete nonexistent schedule entry 0! [Feb 8 09:02:18] DEBUG[17251] sched.c: Attempted to delete nonexistent schedule entry 0! [Feb 8 09:02:18] DEBUG[17251] sched.c: Attempted to delete nonexistent schedule entry 0! [Feb 8 09:02:18] VERBOSE[17251] logger.c: Found user '6004' [Feb 8 09:02:18] VERBOSE[17251] logger.c: Found RTP audio format 0 [Feb 8 09:02:18] VERBOSE[17251] logger.c: Found RTP audio format 18 [Feb 8 09:02:18] VERBOSE[17251] logger.c: Found RTP audio format 96 [Feb 8 09:02:18] VERBOSE[17251] logger.c: Found RTP audio format 102 [Feb 8 09:02:18] VERBOSE[17251] logger.c: Found RTP audio format 107 [Feb 8 09:02:18] VERBOSE[17251] logger.c: Found RTP audio format 104 [Feb 8 09:02:18] VERBOSE[17251] logger.c: Found RTP audio format 105 [Feb 8 09:02:18] VERBOSE[17251] logger.c: Found RTP audio format 106 [Feb 8 09:02:18] VERBOSE[17251] logger.c: Found RTP audio format 97 [Feb 8 09:02:18] VERBOSE[17251] logger.c: Found RTP audio format 98 [Feb 8 09:02:18] VERBOSE[17251] logger.c: Found RTP audio format 2 [Feb 8 09:02:18] VERBOSE[17251] logger.c: Found RTP audio format 99 [Feb 8 09:02:18] VERBOSE[17251] logger.c: Found RTP audio format 8 [Feb 8 09:02:18] VERBOSE[17251] logger.c: Found RTP audio format 101 [Feb 8 09:02:18] VERBOSE[17251] logger.c: Peer audio RTP is at port 192.168.30.178:3000 [Feb 8 09:02:18] VERBOSE[17251] logger.c: Found audio description format PCMU for ID 0 [Feb 8 09:02:18] VERBOSE[17251] logger.c: Found audio description format G729 for ID 18 [Feb 8 09:02:18] VERBOSE[17251] logger.c: Found unknown media description format BV16 for ID 96 [Feb 8 09:02:18] VERBOSE[17251] logger.c: Found unknown media description format BV32 for ID 102 [Feb 8 09:02:18] VERBOSE[17251] logger.c: Found audio description format L16 for ID 107 [Feb 8 09:02:18] VERBOSE[17251] logger.c: Found audio description format PCMU for ID 104 [Feb 8 09:02:18] VERBOSE[17251] logger.c: Found audio description format PCMA for ID 105 [Feb 8 09:02:18] VERBOSE[17251] logger.c: Found audio description format L16 for ID 106 [Feb 8 09:02:18] VERBOSE[17251] logger.c: Found unknown media description format G726-16 for ID 97 [Feb 8 09:02:18] VERBOSE[17251] logger.c: Found unknown media description format G726-24 for ID 98 [Feb 8 09:02:18] VERBOSE[17251] logger.c: Found audio description format G726-32 for ID 2 [Feb 8 09:02:18] VERBOSE[17251] logger.c: Found unknown media description format G726-40 for ID 99 [Feb 8 09:02:18] VERBOSE[17251] logger.c: Found audio description format PCMA for ID 8 [Feb 8 09:02:18] VERBOSE[17251] logger.c: Found audio description format telephone-event for ID 101 [Feb 8 09:02:18] VERBOSE[17251] logger.c: Got unsupported a:fmtp in SDP offer [Feb 8 09:02:18] DEBUG[17251] chan_sip.c: T38 state changed to 0 on channel [Feb 8 09:02:18] VERBOSE[17251] logger.c: Capabilities: us - 0x104 (ulaw|g729), peer - audio=0x94c (ulaw|alaw|g726|slin|g729)/video=0x0 (nothing), combined - 0x104 (ulaw|g729) [Feb 8 09:02:18] VERBOSE[17251] logger.c: Non-codec capabilities (dtmf): us - 0x0 (nothing), peer - 0x1 (telephone-event), combined - 0x0 (nothing) [Feb 8 09:02:18] VERBOSE[17251] logger.c: Peer audio RTP is at port 192.168.30.178:3000 [Feb 8 09:02:18] DEBUG[17251] chan_sip.c: We're settling with these formats: 0x104 (ulaw|g729) [Feb 8 09:02:18] DEBUG[17251] chan_sip.c: Checking SIP call limits for device 6004 [Feb 8 09:02:18] DEBUG[17251] chan_sip.c: Updating call counter for incoming call [Feb 8 09:02:18] DEBUG[17251] chan_sip.c: Call from peer '6004' is 1 out of 4 [Feb 8 09:02:18] DEBUG[17251] devicestate.c: Notification of state change to be queued on device/channel SIP/6004 [Feb 8 09:02:18] VERBOSE[17251] logger.c: Looking for 6000 in default-super (domain 192.168.30.254) [Feb 8 09:02:18] DEBUG[17152] chan_sip.c: Checking device state for peer 6004 [Feb 8 09:02:18] DEBUG[17152] devicestate.c: Changing state for SIP/6004 - state 2 (In use) [Feb 8 09:02:18] DEBUG[17152] chan_sip.c: Checking device state for peer 6004 [Feb 8 09:02:18] DEBUG[17152] chan_sip.c: Checking device state for peer 6004 [Feb 8 09:02:18] VERBOSE[17152] logger.c: Reliably Transmitting (no NAT) to 192.168.30.200:5060: NOTIFY sip:6002@192.168.30.200:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK20820fe1;rport From: ;tag=as1ec546fb To: "Reception 6002" ;tag=F43D395A-94BE4C3B Contact: Call-ID: dedf8637-a30ce658-849d1cb9@192.168.30.200 CSeq: 103 NOTIFY User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Event: presence Content-Type: application/xpidf+xml Subscription-State: active Content-Length: 353
--- [Feb 8 09:02:18] DEBUG[17251] chan_sip.c: *** Our native formats are 0x4 (ulaw) [Feb 8 09:02:18] DEBUG[17251] chan_sip.c: *** Joint capabilities are 0x104 (ulaw|g729) [Feb 8 09:02:18] DEBUG[17251] chan_sip.c: *** Our capabilities are 0x104 (ulaw|g729) [Feb 8 09:02:18] DEBUG[17251] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Feb 8 09:02:18] DEBUG[17251] chan_sip.c: This channel will not be able to handle video. [Feb 8 09:02:18] DEBUG[17251] chan_sip.c: build_route: Contact hop: Don Wright [Feb 8 09:02:18] VERBOSE[17251] logger.c: list_route: hop: [Feb 8 09:02:18] DEBUG[17251] chan_sip.c: SIP/6004-08ce1c68: New call is still down.... Trying... [Feb 8 09:02:18] VERBOSE[17251] logger.c: <--- Transmitting (no NAT) to 192.168.30.178:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.30.178;branch=z9hG4bKa476babd8;received=192.168.30.178 From: Don Wright ;tag=205714ae9d2ac6b To: 6000 Call-ID: b6d07bd0a85bb952fc3184f5e5ba5169@192.168.30.178 CSeq: 92868389 INVITE User-Agent: Asterisk PBX (Fireworx) Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Feb 8 09:02:18] DEBUG[17251] devicestate.c: Notification of state change to be queued on device/channel SIP/6004-08ce1c68 [Feb 8 09:02:18] DEBUG[17251] devicestate.c: Notification of state change to be queued on device/channel SIP/6004 [Feb 8 09:02:18] VERBOSE[17152] logger.c: Extension Changed 6004[default-local] new state InUse for Notify User 6002 [Feb 8 09:02:18] DEBUG[17152] chan_sip.c: Checking device state for peer 6004 [Feb 8 09:02:18] VERBOSE[17152] logger.c: Reliably Transmitting (no NAT) to 192.168.30.193:5060: NOTIFY sip:6001@192.168.30.193:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK239c1166;rport From: ;tag=as0bf510b1 To: Reception 6001 ;tag=8a19c21100 Contact: Call-ID: 9602d6bad327dfab CSeq: 103 NOTIFY User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 211 confirmed --- [Feb 8 09:02:18] VERBOSE[17152] logger.c: Extension Changed 6004[default-local] new state InUse for Notify User 6001 [Feb 8 09:02:18] DEBUG[17152] chan_sip.c: Checking device state for peer 6004 [Feb 8 09:02:18] VERBOSE[17152] logger.c: Reliably Transmitting (no NAT) to 192.168.30.162:2060: NOTIFY sip:6000@192.168.30.162:2060;line=307oc8ge SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK0dda052a;rport From: ;tag=as7d02ed49 To: ;tag=xl4ze4djv5 Contact: Call-ID: 3c267017194a-f3nna9a3is4w CSeq: 104 NOTIFY User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 206 confirmed --- [Feb 8 09:02:18] VERBOSE[17152] logger.c: Extension Changed 6004[default-local] new state InUse for Notify User 6000 [Feb 8 09:02:18] DEBUG[17152] chan_sip.c: Checking device state for peer 6004-08ce1c68 [Feb 8 09:02:18] DEBUG[17152] devicestate.c: Changing state for SIP/6004-08ce1c68 - state 4 (Invalid) [Feb 8 09:02:18] DEBUG[17152] chan_sip.c: Checking device state for peer 6004 [Feb 8 09:02:18] DEBUG[17152] devicestate.c: Changing state for SIP/6004 - state 2 (In use) [Feb 8 09:02:18] DEBUG[17152] chan_sip.c: Checking device state for peer 6004 [Feb 8 09:02:18] DEBUG[17276] app_queue.c: Device 'SIP/6004' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Feb 8 09:02:18] DEBUG[17276] app_queue.c: Device 'SIP/6004-08ce1c68' changed to state '4' (Invalid) but we don't care because they're not a member of any queue. [Feb 8 09:02:18] DEBUG[17276] app_queue.c: Device 'SIP/6004' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Feb 8 09:02:18] DEBUG[18719] pbx.c: Expression result is '0' [Feb 8 09:02:18] DEBUG[18719] pbx.c: Expression result is '3' [Feb 8 09:02:18] DEBUG[18719] pbx.c: Launching 'GotoIf' [Feb 8 09:02:18] VERBOSE[18719] logger.c: -- Executing [6000@default-super:1] GotoIf("SIP/6004-08ce1c68", "0?3") in new stack [Feb 8 09:02:18] DEBUG[18719] pbx.c: Not taking any branch [Feb 8 09:02:18] DEBUG[18719] pbx.c: Function result is '6004' [Feb 8 09:02:18] DEBUG[18719] pbx.c: Launching 'Set' [Feb 8 09:02:18] VERBOSE[18719] logger.c: -- Executing [6000@default-super:2] Set("SIP/6004-08ce1c68", "GROUP(OUTGOING)=6004") in new stack [Feb 8 09:02:18] DEBUG[18719] pbx.c: Launching 'Set' [Feb 8 09:02:18] VERBOSE[18719] logger.c: -- Executing [6000@default-super:3] Set("SIP/6004-08ce1c68", "OUTBOUND_GROUP_ONCE=6000@INCOMING") in new stack [Feb 8 09:02:18] DEBUG[18719] pbx.c: Function result is '0' [Feb 8 09:02:18] DEBUG[18719] pbx.c: Launching 'Set' [Feb 8 09:02:18] VERBOSE[18719] logger.c: -- Executing [6000@default-super:4] Set("SIP/6004-08ce1c68", "GROUPCOUNT=0") in new stack [Feb 8 09:02:18] VERBOSE[17251] logger.c: <--- SIP read from 192.168.30.200:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK20820fe1;rport From: ;tag=as1ec546fb To: "Reception 6002" ;tag=F43D395A-94BE4C3B CSeq: 103 NOTIFY Call-ID: dedf8637-a30ce658-849d1cb9@192.168.30.200 Contact: Event: presence User-Agent: PolycomSoundPointIP-SPIP_550-UA/3.0.0.0258 Content-Length: 0 <-------------> [Feb 8 09:02:18] VERBOSE[17251] logger.c: --- (10 headers 0 lines) --- [Feb 8 09:02:18] DEBUG[17251] chan_sip.c: Acked pending invite 103 [Feb 8 09:02:18] DEBUG[17251] chan_sip.c: Stopping retransmission on 'dedf8637-a30ce658-849d1cb9@192.168.30.200' of Request 103: Match Not Found [Feb 8 09:02:18] VERBOSE[17251] logger.c: SIP Response message for INCOMING dialog NOTIFY arrived [Feb 8 09:02:18] DEBUG[18719] pbx.c: Function result is '0' [Feb 8 09:02:18] DEBUG[18719] pbx.c: Launching 'Set' [Feb 8 09:02:18] VERBOSE[18719] logger.c: -- Executing [6000@default-super:5] Set("SIP/6004-08ce1c68", "GROUPCOUNT2=0") in new stack [Feb 8 09:02:18] DEBUG[18719] pbx.c: Launching 'Set' [Feb 8 09:02:18] VERBOSE[18719] logger.c: -- Executing [6000@default-super:6] Set("SIP/6004-08ce1c68", "DB(default/wrapup/6000/lastcall)=1202479338.0") in new stack [Feb 8 09:02:18] VERBOSE[17251] logger.c: <--- SIP read from 192.168.30.162:2060 ---> SIP/2.0 200 Ok Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK0dda052a;rport=5060 From: ;tag=as7d02ed49 To: ;tag=xl4ze4djv5 Call-ID: 3c267017194a-f3nna9a3is4w CSeq: 104 NOTIFY Content-Length: 0 <-------------> [Feb 8 09:02:18] VERBOSE[17251] logger.c: --- (7 headers 0 lines) --- [Feb 8 09:02:18] DEBUG[17251] chan_sip.c: Acked pending invite 104 [Feb 8 09:02:18] DEBUG[17251] chan_sip.c: Stopping retransmission on '3c267017194a-f3nna9a3is4w' of Request 104: Match Not Found [Feb 8 09:02:18] VERBOSE[17251] logger.c: SIP Response message for INCOMING dialog NOTIFY arrived [Feb 8 09:02:18] VERBOSE[17251] logger.c: <--- SIP read from 192.168.30.193:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK239c1166;rport=5060;received=192.168.30.254 From: ;tag=as0bf510b1 To: Reception 6001 ;tag=8a19c21100 Call-ID: 9602d6bad327dfab CSeq: 103 NOTIFY Contact: Reception 6001 Server: Aastra 57i/2.1.2.30 Content-Length: 0 <-------------> [Feb 8 09:02:18] VERBOSE[17251] logger.c: --- (9 headers 0 lines) --- [Feb 8 09:02:18] DEBUG[17251] chan_sip.c: Acked pending invite 103 [Feb 8 09:02:18] DEBUG[17251] chan_sip.c: Stopping retransmission on '9602d6bad327dfab' of Request 103: Match Not Found [Feb 8 09:02:18] VERBOSE[17251] logger.c: SIP Response message for INCOMING dialog NOTIFY arrived [Feb 8 09:02:18] DEBUG[18719] pbx.c: Launching 'Macro' [Feb 8 09:02:18] VERBOSE[18719] logger.c: -- Executing [6000@default-super:7] Macro("SIP/6004-08ce1c68", "default-dial|SIP/6000|6000|default|20|en|6000@default|twWkKM(all-tapi^1202479338.0)||default||Local/0@default-local|Local/s@default-aa-servicemainmenubutton1englishsubmenu") in new stack [Feb 8 09:02:18] DEBUG[18719] pbx.c: Function result is '6004' [Feb 8 09:02:18] DEBUG[18719] pbx.c: Function result is 'Don Wright' [Feb 8 09:02:18] DEBUG[18719] pbx.c: Launching 'NoOp' [Feb 8 09:02:18] VERBOSE[18719] logger.c: -- Executing [s@macro-default-dial:1] NoOp("SIP/6004-08ce1c68", ""CALL TO LOCAL EXTENSION FROM 6004(Don Wright)"") in new stack [Feb 8 09:02:18] DEBUG[18719] app_macro.c: Executed application: NoOp [Feb 8 09:02:18] DEBUG[18719] pbx.c: Launching 'UserEvent' [Feb 8 09:02:18] VERBOSE[18719] logger.c: -- Executing [s@macro-default-dial:2] UserEvent("SIP/6004-08ce1c68", "TAPI|TAPIEVENT: LINE_NEWCALL default") in new stack [Feb 8 09:02:18] DEBUG[18719] app_macro.c: Executed application: UserEvent [Feb 8 09:02:18] DEBUG[18719] pbx.c: Launching 'UserEvent' [Feb 8 09:02:18] VERBOSE[18719] logger.c: -- Executing [s@macro-default-dial:3] UserEvent("SIP/6004-08ce1c68", "TAPI|TAPIEVENT: LINE_CALLSTATE LINECALLSTATE_OFFERING") in new stack [Feb 8 09:02:18] DEBUG[18719] app_macro.c: Executed application: UserEvent [Feb 8 09:02:18] DEBUG[18719] pbx.c: Launching 'UserEvent' [Feb 8 09:02:18] VERBOSE[18719] logger.c: -- Executing [s@macro-default-dial:4] UserEvent("SIP/6004-08ce1c68", "TAPI|TAPIEVENT: SET CALLERID ") in new stack [Feb 8 09:02:18] DEBUG[18719] app_macro.c: Executed application: UserEvent [Feb 8 09:02:18] DEBUG[18719] pbx.c: Launching 'UserEvent' [Feb 8 09:02:18] VERBOSE[18719] logger.c: -- Executing [s@macro-default-dial:5] UserEvent("SIP/6004-08ce1c68", "TAPI|TAPIEVENT: LINE_CALLINFO LINECALLINFOSTATE_CALLERID") in new stack [Feb 8 09:02:18] DEBUG[18719] app_macro.c: Executed application: UserEvent [Feb 8 09:02:18] DEBUG[18719] pbx.c: Launching 'AGI' [Feb 8 09:02:18] VERBOSE[18719] logger.c: -- Executing [s@macro-default-dial:6] AGI("SIP/6004-08ce1c68", "/var/www/scopserv/telephony/scripts/agi/dial.php") in new stack [Feb 8 09:02:18] VERBOSE[18719] logger.c: -- Launched AGI Script /var/www/scopserv/telephony/scripts/agi/dial.php [Feb 8 09:02:18] DEBUG[18719] db.c: Unable to find key 'MonitorIncoming' in family 'default/6000' [Feb 8 09:02:18] DEBUG[18719] db.c: Unable to find key 'HotDesk' in family 'default/6000' [Feb 8 09:02:18] DEBUG[18719] db.c: Unable to find key 'DoNotDisturb' in family 'default/6000' [Feb 8 09:02:18] DEBUG[18719] db.c: Unable to find key 'SIP/6000' in family 'dnd' [Feb 8 09:02:18] DEBUG[18719] db.c: Unable to find key 'CallWaiting' in family 'default/6000' [Feb 8 09:02:18] DEBUG[18719] db.c: Unable to find key 'CallForward_Internal' in family 'default/6000' [Feb 8 09:02:18] DEBUG[18719] db.c: Unable to find key 'CallForwardOnBusy_Internal' in family 'default/6000' [Feb 8 09:02:18] DEBUG[18719] db.c: Unable to find key 'CallForwardOnNoAnswer_Internal' in family 'default/6000' [Feb 8 09:02:18] DEBUG[18719] db.c: Unable to find key 'CallForwardOnUnavailable_Internal' in family 'default/6000' [Feb 8 09:02:18] VERBOSE[18719] logger.c: -- AGI Script Executing Application: (SetMusicOnHold) Options: (default) [Feb 8 09:02:18] DEBUG[18723] manager.c: Manager received command 'login' [Feb 8 09:02:18] VERBOSE[18723] logger.c: == Parsing '/etc/asterisk/manager.conf': [Feb 8 09:02:18] DEBUG[18723] config.c: Parsing /etc/asterisk/manager.conf [Feb 8 09:02:18] VERBOSE[18723] logger.c: Found [Feb 8 09:02:18] DEBUG[18723] acl.c: 127.0.0.1/255.255.255.255 appended to acl for peer [Feb 8 09:02:18] DEBUG[18723] acl.c: ##### Testing 127.0.0.1 with 127.0.0.1 [Feb 8 09:02:18] DEBUG[18723] manager.c: Manager received command 'ExtensionState' [Feb 8 09:02:18] DEBUG[18723] chan_sip.c: Checking device state for peer 6000 [Feb 8 09:02:18] VERBOSE[18719] logger.c: /var/www/scopserv/telephony/scripts/agi/dial.php: Extension State for '6000' is '0'. [Feb 8 09:02:18] VERBOSE[18719] logger.c: -- AGI Script Executing Application: (NoOp) Options: (STATUS:) [Feb 8 09:02:18] VERBOSE[18719] logger.c: -- /var/www/scopserv/telephony/scripts/agi/dial.php: Doing the action dial with params : 6000 [Feb 8 09:02:18] DEBUG[18719] db.c: Unable to find key 'CallerInternalNumber' in family 'default/6004' [Feb 8 09:02:18] DEBUG[18719] db.c: Unable to find key 'CallerInternalName' in family 'default/6004' [Feb 8 09:02:18] DEBUG[18719] db.c: Unable to find key 'HotDesk' in family 'default/6004' [Feb 8 09:02:18] VERBOSE[18719] logger.c: /var/www/scopserv/telephony/scripts/agi/dial.php: Dial string is SIP/6000|20|twWkKM(all-tapi^1202479338.0)|. [Feb 8 09:02:18] VERBOSE[18719] logger.c: -- AGI Script Executing Application: (Dial) Options: (SIP/6000|20|twWkKM(all-tapi^1202479338.0)|) [Feb 8 09:02:18] DEBUG[18719] chan_sip.c: Asked to create a SIP channel with formats: 0x4 (ulaw) [Feb 8 09:02:18] DEBUG[18719] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Feb 8 09:02:18] DEBUG[18719] sched.c: Attempted to delete nonexistent schedule entry 0! [Feb 8 09:02:18] DEBUG[18719] sched.c: Attempted to delete nonexistent schedule entry 0! [Feb 8 09:02:18] DEBUG[18719] sched.c: Attempted to delete nonexistent schedule entry 0! [Feb 8 09:02:18] DEBUG[18719] sched.c: Attempted to delete nonexistent schedule entry 0! [Feb 8 09:02:18] DEBUG[18719] sched.c: Attempted to delete nonexistent schedule entry 0! [Feb 8 09:02:18] DEBUG[18719] sched.c: Attempted to delete nonexistent schedule entry 0! [Feb 8 09:02:18] DEBUG[18719] sched.c: Attempted to delete nonexistent schedule entry 0! [Feb 8 09:02:18] DEBUG[18719] sched.c: Attempted to delete nonexistent schedule entry 0! [Feb 8 09:02:18] DEBUG[18719] sched.c: Attempted to delete nonexistent schedule entry 0! [Feb 8 09:02:18] DEBUG[18719] sched.c: Attempted to delete nonexistent schedule entry 0! [Feb 8 09:02:18] DEBUG[18719] sched.c: Attempted to delete nonexistent schedule entry 0! [Feb 8 09:02:18] DEBUG[18719] chan_sip.c: Setting NAT on RTP to Off [Feb 8 09:02:18] DEBUG[18719] acl.c: ##### Testing 192.168.30.162 with 192.168.0.0 [Feb 8 09:02:18] DEBUG[18719] acl.c: ##### Testing 192.168.30.162 with 10.0.0.0 [Feb 8 09:02:18] DEBUG[18719] acl.c: ##### Testing 192.168.30.162 with 172.16.0.0 [Feb 8 09:02:18] DEBUG[18719] acl.c: ##### Testing 192.168.30.162 with 169.254.0.0 [Feb 8 09:02:18] DEBUG[18719] chan_sip.c: *** Our native formats are 0x4 (ulaw) [Feb 8 09:02:18] DEBUG[18719] chan_sip.c: *** Joint capabilities are 0x0 (nothing) [Feb 8 09:02:18] DEBUG[18719] chan_sip.c: *** Our capabilities are 0x104 (ulaw|g729) [Feb 8 09:02:18] DEBUG[18719] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Feb 8 09:02:18] DEBUG[18719] chan_sip.c: *** Our preferred formats from the incoming channel are 0x4 (ulaw) [Feb 8 09:02:18] DEBUG[18719] chan_sip.c: This channel will not be able to handle video. [Feb 8 09:02:18] DEBUG[18719] channel.c: Not copying variable TOUCH_MONITOR. [Feb 8 09:02:18] DEBUG[18719] channel.c: Not copying variable MACRO_DEPTH. [Feb 8 09:02:18] DEBUG[18719] channel.c: Not copying variable ARG12. [Feb 8 09:02:18] DEBUG[18719] channel.c: Not copying variable ARG11. [Feb 8 09:02:18] DEBUG[18719] channel.c: Not copying variable ARG10. [Feb 8 09:02:18] DEBUG[18719] channel.c: Not copying variable ARG9. [Feb 8 09:02:18] DEBUG[18719] channel.c: Not copying variable ARG8. [Feb 8 09:02:18] DEBUG[18719] channel.c: Not copying variable ARG7. [Feb 8 09:02:18] DEBUG[18719] channel.c: Not copying variable ARG6. [Feb 8 09:02:18] DEBUG[18719] channel.c: Not copying variable ARG5. [Feb 8 09:02:18] DEBUG[18719] channel.c: Not copying variable ARG4. [Feb 8 09:02:18] DEBUG[18719] channel.c: Not copying variable ARG3. [Feb 8 09:02:18] DEBUG[18719] channel.c: Not copying variable ARG2. [Feb 8 09:02:18] DEBUG[18719] channel.c: Not copying variable ARG1. [Feb 8 09:02:18] DEBUG[18719] channel.c: Not copying variable MACRO_PRIORITY. [Feb 8 09:02:18] DEBUG[18719] channel.c: Not copying variable MACRO_CONTEXT. [Feb 8 09:02:18] DEBUG[18719] channel.c: Not copying variable MACRO_EXTEN. [Feb 8 09:02:18] DEBUG[18719] channel.c: Not copying variable GROUPCOUNT2. [Feb 8 09:02:18] DEBUG[18719] channel.c: Not copying variable GROUPCOUNT. [Feb 8 09:02:18] DEBUG[18719] channel.c: Not copying variable SPYGROUP. [Feb 8 09:02:18] DEBUG[18719] channel.c: Not copying variable INBOUND_GROUP. [Feb 8 09:02:18] DEBUG[18719] channel.c: Not copying variable SIPCALLID. [Feb 8 09:02:18] DEBUG[18719] channel.c: Not copying variable SIPUSERAGENT. [Feb 8 09:02:18] DEBUG[18719] channel.c: Not copying variable SIPDOMAIN. [Feb 8 09:02:18] DEBUG[18719] channel.c: Not copying variable SIPURI. [Feb 8 09:02:18] DEBUG[18719] chan_sip.c: Outgoing Call for 6000 [Feb 8 09:02:18] DEBUG[18719] chan_sip.c: Updating call counter for outgoing call [Feb 8 09:02:18] DEBUG[18719] chan_sip.c: Call to peer '6000' is 1 out of 6 [Feb 8 09:02:18] DEBUG[18719] devicestate.c: Notification of state change to be queued on device/channel SIP/6000 [Feb 8 09:02:18] DEBUG[18719] chan_sip.c: Our T38 capability (0), joint T38 capability (0) [Feb 8 09:02:18] DEBUG[17152] chan_sip.c: Checking device state for peer 6000 [Feb 8 09:02:18] DEBUG[17152] devicestate.c: Changing state for SIP/6000 - state 6 (Ringing) [Feb 8 09:02:18] DEBUG[18719] chan_sip.c: ** Our capability: 0x4 (ulaw) Video flag: False [Feb 8 09:02:18] DEBUG[17152] chan_sip.c: Checking device state for peer 6000 [Feb 8 09:02:18] DEBUG[18719] chan_sip.c: ** Our prefcodec: 0x4 (ulaw) [Feb 8 09:02:18] DEBUG[17152] chan_sip.c: Checking device state for peer 6000 [Feb 8 09:02:18] DEBUG[17276] app_queue.c: Device 'SIP/6000' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. [Feb 8 09:02:18] VERBOSE[18719] logger.c: Audio is at 192.168.30.254 port 10480 [Feb 8 09:02:18] VERBOSE[18719] logger.c: Adding codec 0x4 (ulaw) to SDP [Feb 8 09:02:18] DEBUG[18719] chan_sip.c: -- Done with adding codecs to SDP [Feb 8 09:02:18] DEBUG[18719] chan_sip.c: Done building SDP. Settling with this capability: 0x4 (ulaw) [Feb 8 09:02:18] VERBOSE[18719] logger.c: Reliably Transmitting (no NAT) to 192.168.30.162:2060: INVITE sip:6000@192.168.30.162:2060;line=307oc8ge SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK6761680d;rport From: "Don Wright" ;tag=as5b1fd0ea To: Contact: Call-ID: 2ecf0b72687235855a6b5c350188e0dd@192.168.30.254 CSeq: 102 INVITE User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Remote-Party-ID: "Don Wright" ;privacy=off;screen=no Date: Fri, 08 Feb 2008 14:02:18 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Type: application/sdp Content-Length: 188 v=0 o=root 17063 17063 IN IP4 192.168.30.254 s=session c=IN IP4 192.168.30.254 t=0 0 m=audio 10480 RTP/AVP 0 a=rtpmap:0 PCMU/8000 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Feb 8 09:02:18] VERBOSE[18719] logger.c: -- Called 6000 [Feb 8 09:02:18] VERBOSE[17152] logger.c: Reliably Transmitting (no NAT) to 192.168.30.200:5060: NOTIFY sip:6002@192.168.30.200:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK129e674a;rport From: ;tag=as2d926193 To: "Reception 6002" ;tag=868B9436-DAD76617 Contact: Call-ID: 31382413-766b0334-3e527895@192.168.30.200 CSeq: 103 NOTIFY User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Event: presence Content-Type: application/xpidf+xml Subscription-State: active Content-Length: 353
--- [Feb 8 09:02:18] VERBOSE[17152] logger.c: Extension Changed 6000[default-local] new state Ringing for Notify User 6002 [Feb 8 09:02:18] DEBUG[17152] chan_sip.c: Checking device state for peer 6000 [Feb 8 09:02:18] VERBOSE[17152] logger.c: Reliably Transmitting (no NAT) to 192.168.30.193:5060: NOTIFY sip:6001@192.168.30.193:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK5d5c9977;rport From: ;tag=as43a73733 To: Reception 6001 ;tag=553a7c9816 Contact: Call-ID: db25cf758f0c7d5d CSeq: 103 NOTIFY User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 229 early --- [Feb 8 09:02:18] VERBOSE[17152] logger.c: Extension Changed 6000[default-local] new state Ringing for Notify User 6001 [Feb 8 09:02:18] DEBUG[17152] chan_sip.c: Checking device state for peer 6000 [Feb 8 09:02:18] VERBOSE[17152] logger.c: Reliably Transmitting (no NAT) to 192.168.30.162:2060: NOTIFY sip:6000@192.168.30.162:2060;line=307oc8ge SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK7f429bb9;rport From: ;tag=as2333a6cb To: ;tag=tcw3etzs3a Contact: Call-ID: 3c2670171858-a4rpauw7l41k CSeq: 104 NOTIFY User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 224 early --- [Feb 8 09:02:18] VERBOSE[17152] logger.c: Extension Changed 6000[default-local] new state Ringing for Notify User 6000 [Feb 8 09:02:18] VERBOSE[17251] logger.c: <--- SIP read from 192.168.30.200:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK129e674a;rport From: ;tag=as2d926193 To: "Reception 6002" ;tag=868B9436-DAD76617 CSeq: 103 NOTIFY Call-ID: 31382413-766b0334-3e527895@192.168.30.200 Contact: Event: presence User-Agent: PolycomSoundPointIP-SPIP_550-UA/3.0.0.0258 Content-Length: 0 <-------------> [Feb 8 09:02:18] VERBOSE[17251] logger.c: --- (10 headers 0 lines) --- [Feb 8 09:02:18] DEBUG[17251] chan_sip.c: Acked pending invite 103 [Feb 8 09:02:18] DEBUG[17251] chan_sip.c: Stopping retransmission on '31382413-766b0334-3e527895@192.168.30.200' of Request 103: Match Not Found [Feb 8 09:02:18] VERBOSE[17251] logger.c: SIP Response message for INCOMING dialog NOTIFY arrived [Feb 8 09:02:18] VERBOSE[17251] logger.c: <--- SIP read from 192.168.30.162:2060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK6761680d;rport=5060 From: "Don Wright" ;tag=as5b1fd0ea To: ;tag=xxog573r0f Call-ID: 2ecf0b72687235855a6b5c350188e0dd@192.168.30.254 CSeq: 102 INVITE Contact: ;flow-id=1 Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer, call-info Content-Length: 0 <-------------> [Feb 8 09:02:18] VERBOSE[17251] logger.c: --- (10 headers 0 lines) --- [Feb 8 09:02:18] DEBUG[17251] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '2ecf0b72687235855a6b5c350188e0dd@192.168.30.254' Request 102: Found [Feb 8 09:02:18] DEBUG[17251] devicestate.c: Notification of state change to be queued on device/channel SIP/6000-08ce6448 [Feb 8 09:02:18] DEBUG[17152] chan_sip.c: Checking device state for peer 6000-08ce6448 [Feb 8 09:02:18] DEBUG[17251] devicestate.c: Notification of state change to be queued on device/channel SIP/6000 [Feb 8 09:02:18] DEBUG[17152] devicestate.c: Changing state for SIP/6000-08ce6448 - state 4 (Invalid) [Feb 8 09:02:18] DEBUG[17276] app_queue.c: Device 'SIP/6000-08ce6448' changed to state '4' (Invalid) but we don't care because they're not a member of any queue. [Feb 8 09:02:18] DEBUG[17152] chan_sip.c: Checking device state for peer 6000 [Feb 8 09:02:18] DEBUG[17152] devicestate.c: Changing state for SIP/6000 - state 6 (Ringing) [Feb 8 09:02:18] DEBUG[17276] app_queue.c: Device 'SIP/6000' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. [Feb 8 09:02:18] DEBUG[17152] chan_sip.c: Checking device state for peer 6000 [Feb 8 09:02:18] VERBOSE[18719] logger.c: -- SIP/6000-08ce6448 is ringing [Feb 8 09:02:18] VERBOSE[18719] logger.c: <--- Transmitting (no NAT) to 192.168.30.178:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.30.178;branch=z9hG4bKa476babd8;received=192.168.30.178 From: Don Wright ;tag=205714ae9d2ac6b To: 6000 ;tag=as6889e0e3 Call-ID: b6d07bd0a85bb952fc3184f5e5ba5169@192.168.30.178 CSeq: 92868389 INVITE User-Agent: Asterisk PBX (Fireworx) Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Feb 8 09:02:18] VERBOSE[17251] logger.c: <--- SIP read from 192.168.30.193:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK5d5c9977;rport=5060;received=192.168.30.254 From: ;tag=as43a73733 To: Reception 6001 ;tag=553a7c9816 Call-ID: db25cf758f0c7d5d CSeq: 103 NOTIFY Contact: Reception 6001 Server: Aastra 57i/2.1.2.30 Content-Length: 0 <-------------> [Feb 8 09:02:18] VERBOSE[17251] logger.c: --- (9 headers 0 lines) --- [Feb 8 09:02:18] DEBUG[17251] chan_sip.c: Acked pending invite 103 [Feb 8 09:02:18] DEBUG[17251] chan_sip.c: Stopping retransmission on 'db25cf758f0c7d5d' of Request 103: Match Not Found [Feb 8 09:02:18] VERBOSE[17251] logger.c: SIP Response message for INCOMING dialog NOTIFY arrived [Feb 8 09:02:18] VERBOSE[17251] logger.c: Retransmitting #1 (no NAT) to 192.168.30.162:2060: NOTIFY sip:6000@192.168.30.162:2060;line=307oc8ge SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK7f429bb9;rport From: ;tag=as2333a6cb To: ;tag=tcw3etzs3a Contact: Call-ID: 3c2670171858-a4rpauw7l41k CSeq: 104 NOTIFY User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 224 early --- [Feb 8 09:02:19] VERBOSE[17251] logger.c: <--- SIP read from 192.168.30.162:2060 ---> SIP/2.0 200 Ok Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK7f429bb9;rport=5060 From: ;tag=as2333a6cb To: ;tag=tcw3etzs3a Call-ID: 3c2670171858-a4rpauw7l41k CSeq: 104 NOTIFY Content-Length: 0 <-------------> [Feb 8 09:02:19] VERBOSE[17251] logger.c: --- (7 headers 0 lines) --- [Feb 8 09:02:19] DEBUG[17251] chan_sip.c: Acked pending invite 104 [Feb 8 09:02:19] DEBUG[17251] chan_sip.c: Stopping retransmission on '3c2670171858-a4rpauw7l41k' of Request 104: Match Not Found [Feb 8 09:02:19] VERBOSE[17251] logger.c: SIP Response message for INCOMING dialog NOTIFY arrived [Feb 8 09:02:19] VERBOSE[17251] logger.c: <--- SIP read from 192.168.30.162:2060 ---> SIP/2.0 200 Ok Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK7f429bb9;rport=5060 From: ;tag=as2333a6cb To: ;tag=tcw3etzs3a Call-ID: 3c2670171858-a4rpauw7l41k CSeq: 104 NOTIFY Content-Length: 0 <-------------> [Feb 8 09:02:19] VERBOSE[17251] logger.c: --- (7 headers 0 lines) --- [Feb 8 09:02:19] DEBUG[17251] chan_sip.c: Stopping retransmission on '3c2670171858-a4rpauw7l41k' of Request 104: Match Found [Feb 8 09:02:19] VERBOSE[17251] logger.c: SIP Response message for INCOMING dialog NOTIFY arrived [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'show uptime' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] app_queue.c: Queue default-remote_agent_test has no realtime members defined. No need for update [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] app_queue.c: Queue default-sales has no realtime members defined. No need for update [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'ExtensionState' [Feb 8 09:02:19] DEBUG[17250] chan_sip.c: Checking device state for peer 6002 [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'ExtensionState' [Feb 8 09:02:19] DEBUG[17250] chan_sip.c: Checking device state for peer 6003 [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] app_queue.c: Queue default-service has no realtime members defined. No need for update [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'ExtensionState' [Feb 8 09:02:19] DEBUG[17250] chan_sip.c: Checking device state for peer 6002 [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'ExtensionState' [Feb 8 09:02:19] DEBUG[17250] chan_sip.c: Checking device state for peer 6003 [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'ChanSpy' in family 'default/5006' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'DoNotDisturb' in family 'default/5006' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'CallWaiting' in family 'default/5006' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'Login' in family 'default/5006/Agent' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'Paused' in family 'default/5006/Agent' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'HotDesk' in family 'default/5006' [Feb 8 09:02:19] VERBOSE[17251] logger.c: <--- SIP read from 192.168.30.162:2060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK6761680d;rport=5060 From: "Don Wright" ;tag=as5b1fd0ea To: ;tag=xxog573r0f Call-ID: 2ecf0b72687235855a6b5c350188e0dd@192.168.30.254 CSeq: 102 INVITE Contact: ;flow-id=1 Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer, call-info Content-Length: 0 <-------------> [Feb 8 09:02:19] VERBOSE[17251] logger.c: --- (10 headers 0 lines) --- [Feb 8 09:02:19] DEBUG[17251] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '2ecf0b72687235855a6b5c350188e0dd@192.168.30.254' Request 102: Found [Feb 8 09:02:19] VERBOSE[18719] logger.c: -- SIP/6000-08ce6448 is ringing [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'ChanSpy' in family 'default/6000' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'DoNotDisturb' in family 'default/6000' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'CallWaiting' in family 'default/6000' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'Login' in family 'default/6000/Agent' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'Paused' in family 'default/6000/Agent' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'HotDesk' in family 'default/6000' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'ChanSpy' in family 'default/6001' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'DoNotDisturb' in family 'default/6001' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'CallWaiting' in family 'default/6001' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'Login' in family 'default/6001/Agent' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'Paused' in family 'default/6001/Agent' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'HotDesk' in family 'default/6001' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'ChanSpy' in family 'default/6002' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'DoNotDisturb' in family 'default/6002' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'CallWaiting' in family 'default/6002' [Feb 8 09:02:19] DEBUG[17251] chan_sip.c: Auto destroying SIP dialog '568d652a-a9cecc0b-2c93392c@192.168.30.200' [Feb 8 09:02:19] DEBUG[17251] chan_sip.c: Destroying SIP dialog 568d652a-a9cecc0b-2c93392c@192.168.30.200 [Feb 8 09:02:19] VERBOSE[17251] logger.c: Really destroying SIP dialog '568d652a-a9cecc0b-2c93392c@192.168.30.200' Method: REGISTER [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'Login' in family 'default/6002/Agent' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'Paused' in family 'default/6002/Agent' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'HotDesk' in family 'default/6002' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'ChanSpy' in family 'default/6003' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'DoNotDisturb' in family 'default/6003' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'CallWaiting' in family 'default/6003' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'Login' in family 'default/6003/Agent' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'Paused' in family 'default/6003/Agent' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'HotDesk' in family 'default/6003' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'ChanSpy' in family 'default/6004' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'DoNotDisturb' in family 'default/6004' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'CallWaiting' in family 'default/6004' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'Login' in family 'default/6004/Agent' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'Paused' in family 'default/6004/Agent' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'HotDesk' in family 'default/6004' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'ChanSpy' in family 'default/6005' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'DoNotDisturb' in family 'default/6005' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'CallWaiting' in family 'default/6005' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'Login' in family 'default/6005/Agent' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'Paused' in family 'default/6005/Agent' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'HotDesk' in family 'default/6005' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'ChanSpy' in family 'default/6013' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'DoNotDisturb' in family 'default/6013' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'CallWaiting' in family 'default/6013' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'Login' in family 'default/6013/Agent' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'Paused' in family 'default/6013/Agent' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'HotDesk' in family 'default/6013' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'ChanSpy' in family 'default/6014' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'DoNotDisturb' in family 'default/6014' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'CallWaiting' in family 'default/6014' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'Login' in family 'default/6014/Agent' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'Paused' in family 'default/6014/Agent' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] db.c: Unable to find key 'HotDesk' in family 'default/6014' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'GetVar' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'GetVar' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'GetVar' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'GetVar' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'GetVar' [Feb 8 09:02:19] DEBUG[17250] manager.c: Manager received command 'GetVar' [Feb 8 09:02:19] DEBUG[18719] rtp.c: Got RTCP report of 52 bytes [Feb 8 09:02:19] VERBOSE[17251] logger.c: <--- SIP read from 192.168.30.162:2060 ---> SIP/2.0 200 Ok Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK6761680d;rport=5060 From: "Don Wright" ;tag=as5b1fd0ea To: ;tag=xxog573r0f Call-ID: 2ecf0b72687235855a6b5c350188e0dd@192.168.30.254 CSeq: 102 INVITE Contact: ;flow-id=1 User-Agent: snom360/7.1.30 Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer, call-info Supported: timer, 100rel, replaces, callerid Content-Type: application/sdp Content-Length: 275 v=0 o=root 1979473300 1979473301 IN IP4 192.168.30.162 s=call c=IN IP4 192.168.30.162 t=0 0 m=audio 10598 RTP/AVP 0 a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:+tumwVb1omZ0p1G370p0ffASE6Zxjw69BKqoc9JX a=rtpmap:0 pcmu/8000 a=ptime:20 a=encryption:optional a=sendrecv <-------------> [Feb 8 09:02:19] VERBOSE[17251] logger.c: --- (13 headers 11 lines) --- [Feb 8 09:02:19] DEBUG[17251] chan_sip.c: Acked pending invite 102 [Feb 8 09:02:19] DEBUG[17251] chan_sip.c: Stopping retransmission on '2ecf0b72687235855a6b5c350188e0dd@192.168.30.254' of Request 102: Match Not Found [Feb 8 09:02:19] VERBOSE[17251] logger.c: Found RTP audio format 0 [Feb 8 09:02:19] VERBOSE[17251] logger.c: Peer audio RTP is at port 192.168.30.162:10598 [Feb 8 09:02:19] VERBOSE[17251] logger.c: Got unsupported a:crypto in SDP offer [Feb 8 09:02:19] VERBOSE[17251] logger.c: Found audio description format pcmu for ID 0 [Feb 8 09:02:19] DEBUG[17251] chan_sip.c: T38 state changed to 0 on channel SIP/6000-08ce6448 [Feb 8 09:02:19] VERBOSE[17251] logger.c: Capabilities: us - 0x104 (ulaw|g729), peer - audio=0x4 (ulaw)/video=0x0 (nothing), combined - 0x4 (ulaw) [Feb 8 09:02:19] VERBOSE[17251] logger.c: Non-codec capabilities (dtmf): us - 0x0 (nothing), peer - 0x0 (nothing), combined - 0x0 (nothing) [Feb 8 09:02:19] VERBOSE[17251] logger.c: Peer audio RTP is at port 192.168.30.162:10598 [Feb 8 09:02:19] DEBUG[17251] chan_sip.c: We're settling with these formats: 0x4 (ulaw) [Feb 8 09:02:19] DEBUG[17251] chan_sip.c: Updating call counter for outgoing call [Feb 8 09:02:19] DEBUG[17251] devicestate.c: Notification of state change to be queued on device/channel SIP/6000 [Feb 8 09:02:19] DEBUG[17251] chan_sip.c: build_route: Contact hop: ;flow-id=1 [Feb 8 09:02:19] DEBUG[17152] chan_sip.c: Checking device state for peer 6000 [Feb 8 09:02:19] DEBUG[17152] devicestate.c: Changing state for SIP/6000 - state 2 (In use) [Feb 8 09:02:19] DEBUG[17152] chan_sip.c: Checking device state for peer 6000 [Feb 8 09:02:19] DEBUG[17152] chan_sip.c: Checking device state for peer 6000 [Feb 8 09:02:19] VERBOSE[17251] logger.c: list_route: hop: [Feb 8 09:02:19] DEBUG[17251] chan_sip.c: Strict routing enforced for session 2ecf0b72687235855a6b5c350188e0dd@192.168.30.254 [Feb 8 09:02:19] VERBOSE[17152] logger.c: Reliably Transmitting (no NAT) to 192.168.30.200:5060: NOTIFY sip:6002@192.168.30.200:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK1de80774;rport From: ;tag=as2d926193 To: "Reception 6002" ;tag=868B9436-DAD76617 Contact: Call-ID: 31382413-766b0334-3e527895@192.168.30.200 CSeq: 104 NOTIFY User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Event: presence Content-Type: application/xpidf+xml Subscription-State: active Content-Length: 353
--- [Feb 8 09:02:19] VERBOSE[17251] logger.c: set_destination: Parsing for address/port to send to [Feb 8 09:02:19] VERBOSE[17251] logger.c: set_destination: set destination to 192.168.30.162, port 2060 [Feb 8 09:02:19] VERBOSE[17251] logger.c: Transmitting (no NAT) to 192.168.30.162:2060: ACK sip:6000@192.168.30.162:2060;line=307oc8ge SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK223ee051;rport From: "Don Wright" ;tag=as5b1fd0ea To: ;tag=xxog573r0f Contact: Call-ID: 2ecf0b72687235855a6b5c350188e0dd@192.168.30.254 CSeq: 102 ACK User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Remote-Party-ID: "Don Wright" ;privacy=off;screen=no Content-Length: 0 --- [Feb 8 09:02:19] DEBUG[17276] app_queue.c: Device 'SIP/6000' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Feb 8 09:02:19] VERBOSE[17152] logger.c: Extension Changed 6000[default-local] new state InUse for Notify User 6002 [Feb 8 09:02:19] DEBUG[17152] chan_sip.c: Checking device state for peer 6000 [Feb 8 09:02:19] VERBOSE[17152] logger.c: Reliably Transmitting (no NAT) to 192.168.30.193:5060: NOTIFY sip:6001@192.168.30.193:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK5f988a3c;rport From: ;tag=as43a73733 To: Reception 6001 ;tag=553a7c9816 Contact: Call-ID: db25cf758f0c7d5d CSeq: 104 NOTIFY User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 211 confirmed --- [Feb 8 09:02:19] DEBUG[18719] devicestate.c: Notification of state change to be queued on device/channel SIP/6000-08ce6448 [Feb 8 09:02:19] DEBUG[18719] devicestate.c: Notification of state change to be queued on device/channel SIP/6000 [Feb 8 09:02:19] VERBOSE[18719] logger.c: -- SIP/6000-08ce6448 answered SIP/6004-08ce1c68 [Feb 8 09:02:19] DEBUG[18719] pbx.c: Launching 'UserEvent' [Feb 8 09:02:19] VERBOSE[18719] logger.c: -- Executing [s@macro-all-tapi:1] UserEvent("SIP/6000-08ce6448", "TAPI|TAPIEVENT [~1202479338.0] LINE_CALLSTATE LINECALLSTATE_CONNECTED") in new stack [Feb 8 09:02:19] DEBUG[18719] app_macro.c: Executed application: UserEvent [Feb 8 09:02:19] DEBUG[18719] app_dial.c: Macro exited with status 0 [Feb 8 09:02:19] VERBOSE[17152] logger.c: Extension Changed 6000[default-local] new state InUse for Notify User 6001 [Feb 8 09:02:19] DEBUG[17152] chan_sip.c: Checking device state for peer 6000 [Feb 8 09:02:19] VERBOSE[17152] logger.c: Reliably Transmitting (no NAT) to 192.168.30.162:2060: NOTIFY sip:6000@192.168.30.162:2060;line=307oc8ge SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK1c058d91;rport From: ;tag=as2333a6cb To: ;tag=tcw3etzs3a Contact: Call-ID: 3c2670171858-a4rpauw7l41k CSeq: 105 NOTIFY User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 206 confirmed --- [Feb 8 09:02:19] VERBOSE[17152] logger.c: Extension Changed 6000[default-local] new state InUse for Notify User 6000 [Feb 8 09:02:19] DEBUG[17152] chan_sip.c: Checking device state for peer 6000-08ce6448 [Feb 8 09:02:19] DEBUG[17152] devicestate.c: Changing state for SIP/6000-08ce6448 - state 4 (Invalid) [Feb 8 09:02:19] DEBUG[17152] chan_sip.c: Checking device state for peer 6000 [Feb 8 09:02:19] DEBUG[17152] devicestate.c: Changing state for SIP/6000 - state 2 (In use) [Feb 8 09:02:19] DEBUG[17152] chan_sip.c: Checking device state for peer 6000 [Feb 8 09:02:19] DEBUG[17276] app_queue.c: Device 'SIP/6000-08ce6448' changed to state '4' (Invalid) but we don't care because they're not a member of any queue. [Feb 8 09:02:19] DEBUG[17276] app_queue.c: Device 'SIP/6000' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Feb 8 09:02:19] DEBUG[18719] devicestate.c: Notification of state change to be queued on device/channel SIP/6004-08ce1c68 [Feb 8 09:02:19] DEBUG[18719] devicestate.c: Notification of state change to be queued on device/channel SIP/6004 [Feb 8 09:02:19] DEBUG[18719] chan_sip.c: SIP answering channel: SIP/6004-08ce1c68 [Feb 8 09:02:19] DEBUG[18719] chan_sip.c: Setting framing from config on incoming call [Feb 8 09:02:19] DEBUG[18719] chan_sip.c: ** Our capability: 0x104 (ulaw|g729) Video flag: True [Feb 8 09:02:19] DEBUG[18719] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [Feb 8 09:02:19] VERBOSE[18719] logger.c: Audio is at 192.168.30.254 port 14146 [Feb 8 09:02:19] VERBOSE[18719] logger.c: Adding codec 0x4 (ulaw) to SDP [Feb 8 09:02:19] VERBOSE[18719] logger.c: Adding codec 0x100 (g729) to SDP [Feb 8 09:02:19] DEBUG[18719] chan_sip.c: -- Done with adding codecs to SDP [Feb 8 09:02:19] DEBUG[18719] chan_sip.c: Done building SDP. Settling with this capability: 0x104 (ulaw|g729) [Feb 8 09:02:19] VERBOSE[18719] logger.c: <--- Reliably Transmitting (no NAT) to 192.168.30.178:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.30.178;branch=z9hG4bKa476babd8;received=192.168.30.178 From: Don Wright ;tag=205714ae9d2ac6b To: 6000 ;tag=as6889e0e3 Call-ID: b6d07bd0a85bb952fc3184f5e5ba5169@192.168.30.178 CSeq: 92868389 INVITE User-Agent: Asterisk PBX (Fireworx) Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 235 v=0 o=root 17063 17063 IN IP4 192.168.30.254 s=session c=IN IP4 192.168.30.254 t=0 0 m=audio 14146 RTP/AVP 0 18 a=rtpmap:0 PCMU/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <------------> [Feb 8 09:02:19] DEBUG[17152] chan_sip.c: Checking device state for peer 6004-08ce1c68 [Feb 8 09:02:19] DEBUG[17152] devicestate.c: Changing state for SIP/6004-08ce1c68 - state 4 (Invalid) [Feb 8 09:02:19] DEBUG[17152] chan_sip.c: Checking device state for peer 6004 [Feb 8 09:02:19] DEBUG[17152] devicestate.c: Changing state for SIP/6004 - state 2 (In use) [Feb 8 09:02:19] DEBUG[17152] chan_sip.c: Checking device state for peer 6004 [Feb 8 09:02:19] DEBUG[17276] app_queue.c: Device 'SIP/6004-08ce1c68' changed to state '4' (Invalid) but we don't care because they're not a member of any queue. [Feb 8 09:02:19] DEBUG[17276] app_queue.c: Device 'SIP/6004' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Feb 8 09:02:19] VERBOSE[17251] logger.c: <--- SIP read from 192.168.30.200:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK1de80774;rport From: ;tag=as2d926193 To: "Reception 6002" ;tag=868B9436-DAD76617 CSeq: 104 NOTIFY Call-ID: 31382413-766b0334-3e527895@192.168.30.200 Contact: Event: presence User-Agent: PolycomSoundPointIP-SPIP_550-UA/3.0.0.0258 Content-Length: 0 <-------------> [Feb 8 09:02:19] VERBOSE[17251] logger.c: --- (10 headers 0 lines) --- [Feb 8 09:02:19] DEBUG[17251] chan_sip.c: Acked pending invite 104 [Feb 8 09:02:19] DEBUG[17251] chan_sip.c: Stopping retransmission on '31382413-766b0334-3e527895@192.168.30.200' of Request 104: Match Not Found [Feb 8 09:02:19] VERBOSE[17251] logger.c: SIP Response message for INCOMING dialog NOTIFY arrived [Feb 8 09:02:19] VERBOSE[17251] logger.c: <--- SIP read from 192.168.30.193:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK5f988a3c;rport=5060;received=192.168.30.254 From: ;tag=as43a73733 To: Reception 6001 ;tag=553a7c9816 Call-ID: db25cf758f0c7d5d CSeq: 104 NOTIFY Contact: Reception 6001 Server: Aastra 57i/2.1.2.30 Content-Length: 0 <-------------> [Feb 8 09:02:19] VERBOSE[17251] logger.c: --- (9 headers 0 lines) --- [Feb 8 09:02:19] DEBUG[17251] chan_sip.c: Acked pending invite 104 [Feb 8 09:02:19] DEBUG[17251] chan_sip.c: Stopping retransmission on 'db25cf758f0c7d5d' of Request 104: Match Not Found [Feb 8 09:02:19] VERBOSE[17251] logger.c: SIP Response message for INCOMING dialog NOTIFY arrived [Feb 8 09:02:19] DEBUG[18719] rtp.c: Ooh, format changed from unknown to ulaw [Feb 8 09:02:19] DEBUG[18719] rtp.c: Created smoother: format: 4 ms: 20 len: 160 [Feb 8 09:02:20] VERBOSE[17251] logger.c: Retransmitting #1 (no NAT) to 192.168.30.162:2060: NOTIFY sip:6000@192.168.30.162:2060;line=307oc8ge SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK1c058d91;rport From: ;tag=as2333a6cb To: ;tag=tcw3etzs3a Contact: Call-ID: 3c2670171858-a4rpauw7l41k CSeq: 105 NOTIFY User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 206 confirmed --- [Feb 8 09:02:20] VERBOSE[17251] logger.c: <--- SIP read from 192.168.30.162:2060 ---> SIP/2.0 200 Ok Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK1c058d91;rport=5060 From: ;tag=as2333a6cb To: ;tag=tcw3etzs3a Call-ID: 3c2670171858-a4rpauw7l41k CSeq: 105 NOTIFY Content-Length: 0 <-------------> [Feb 8 09:02:20] VERBOSE[17251] logger.c: --- (7 headers 0 lines) --- [Feb 8 09:02:20] DEBUG[17251] chan_sip.c: Acked pending invite 105 [Feb 8 09:02:20] DEBUG[17251] chan_sip.c: Stopping retransmission on '3c2670171858-a4rpauw7l41k' of Request 105: Match Not Found [Feb 8 09:02:20] VERBOSE[17251] logger.c: SIP Response message for INCOMING dialog NOTIFY arrived [Feb 8 09:02:20] VERBOSE[17251] logger.c: <--- SIP read from 192.168.30.162:2060 ---> SIP/2.0 200 Ok Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK1c058d91;rport=5060 From: ;tag=as2333a6cb To: ;tag=tcw3etzs3a Call-ID: 3c2670171858-a4rpauw7l41k CSeq: 105 NOTIFY Content-Length: 0 <-------------> [Feb 8 09:02:20] VERBOSE[17251] logger.c: --- (7 headers 0 lines) --- [Feb 8 09:02:20] DEBUG[17251] chan_sip.c: Stopping retransmission on '3c2670171858-a4rpauw7l41k' of Request 105: Match Found [Feb 8 09:02:20] VERBOSE[17251] logger.c: SIP Response message for INCOMING dialog NOTIFY arrived [Feb 8 09:02:20] VERBOSE[17251] logger.c: <--- SIP read from 192.168.30.178:5060 ---> ACK sip:6000@192.168.30.254 SIP/2.0 Via: SIP/2.0/UDP 192.168.30.178;branch=z9hG4bKf5dab4ae8 Max-Forwards: 70 Content-Length: 0 To: 6000 ;tag=as6889e0e3 From: Don Wright ;tag=205714ae9d2ac6b Call-ID: b6d07bd0a85bb952fc3184f5e5ba5169@192.168.30.178 CSeq: 92868389 ACK Contact: Don Wright Proxy-Authorization:Digest response="bcdda3f01a4387ece69ad082e4fa74f0",username="6004",realm="fireworx",nonce="37a6a820",algorithm=MD5,uri="sip:6000@192.168.30.254:5060" User-Agent: Aastra 480i/1.4.2.3000 Brcm Callctrl/1.5.1.0 MxSF/v3.2.8.45 <-------------> [Feb 8 09:02:20] VERBOSE[17251] logger.c: --- (11 headers 0 lines) --- [Feb 8 09:02:20] DEBUG[17251] chan_sip.c: Stopping retransmission on 'b6d07bd0a85bb952fc3184f5e5ba5169@192.168.30.178' of Response 92868389: Match Not Found [Feb 8 09:02:20] DEBUG[18719] rtp.c: Ooh, format changed from unknown to ulaw [Feb 8 09:02:20] DEBUG[18719] rtp.c: Created smoother: format: 4 ms: 20 len: 160 [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'show uptime' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] app_queue.c: Queue default-remote_agent_test has no realtime members defined. No need for update [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] app_queue.c: Queue default-sales has no realtime members defined. No need for update [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'ExtensionState' [Feb 8 09:02:20] DEBUG[17250] chan_sip.c: Checking device state for peer 6002 [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'ExtensionState' [Feb 8 09:02:20] DEBUG[17250] chan_sip.c: Checking device state for peer 6003 [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] app_queue.c: Queue default-service has no realtime members defined. No need for update [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'ExtensionState' [Feb 8 09:02:20] DEBUG[17250] chan_sip.c: Checking device state for peer 6002 [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'ExtensionState' [Feb 8 09:02:20] DEBUG[17250] chan_sip.c: Checking device state for peer 6003 [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] db.c: Unable to find key 'ChanSpy' in family 'default/6006' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] db.c: Unable to find key 'DoNotDisturb' in family 'default/6006' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] db.c: Unable to find key 'CallWaiting' in family 'default/6006' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] db.c: Unable to find key 'Login' in family 'default/6006/Agent' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] db.c: Unable to find key 'Paused' in family 'default/6006/Agent' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] db.c: Unable to find key 'HotDesk' in family 'default/6006' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] db.c: Unable to find key 'ChanSpy' in family 'default/6007' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] db.c: Unable to find key 'DoNotDisturb' in family 'default/6007' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] db.c: Unable to find key 'CallWaiting' in family 'default/6007' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] db.c: Unable to find key 'Login' in family 'default/6007/Agent' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] db.c: Unable to find key 'Paused' in family 'default/6007/Agent' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] db.c: Unable to find key 'HotDesk' in family 'default/6007' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] db.c: Unable to find key 'ChanSpy' in family 'default/6056' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] db.c: Unable to find key 'DoNotDisturb' in family 'default/6056' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] db.c: Unable to find key 'CallWaiting' in family 'default/6056' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] db.c: Unable to find key 'Login' in family 'default/6056/Agent' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] db.c: Unable to find key 'Paused' in family 'default/6056/Agent' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] db.c: Unable to find key 'HotDesk' in family 'default/6056' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] db.c: Unable to find key 'ChanSpy' in family 'default/6057' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] db.c: Unable to find key 'DoNotDisturb' in family 'default/6057' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] db.c: Unable to find key 'CallWaiting' in family 'default/6057' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] db.c: Unable to find key 'Login' in family 'default/6057/Agent' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] db.c: Unable to find key 'Paused' in family 'default/6057/Agent' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] db.c: Unable to find key 'HotDesk' in family 'default/6057' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] db.c: Unable to find key 'ChanSpy' in family 'default/6058' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] db.c: Unable to find key 'DoNotDisturb' in family 'default/6058' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] db.c: Unable to find key 'CallWaiting' in family 'default/6058' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] db.c: Unable to find key 'Login' in family 'default/6058/Agent' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] db.c: Unable to find key 'Paused' in family 'default/6058/Agent' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] db.c: Unable to find key 'HotDesk' in family 'default/6058' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] db.c: Unable to find key 'ChanSpy' in family 'default/6363' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] db.c: Unable to find key 'DoNotDisturb' in family 'default/6363' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] db.c: Unable to find key 'CallWaiting' in family 'default/6363' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] db.c: Unable to find key 'Login' in family 'default/6363/Agent' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] db.c: Unable to find key 'Paused' in family 'default/6363/Agent' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] db.c: Unable to find key 'HotDesk' in family 'default/6363' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'GetVar' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'GetVar' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'GetVar' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'GetVar' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'GetVar' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'GetVar' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'GetVar' [Feb 8 09:02:20] DEBUG[17250] manager.c: Manager received command 'GetVar' [Feb 8 09:02:21] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:21] DEBUG[17250] manager.c: Manager received command 'show uptime' [Feb 8 09:02:21] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:21] DEBUG[17250] app_queue.c: Queue default-remote_agent_test has no realtime members defined. No need for update [Feb 8 09:02:21] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:21] DEBUG[17250] app_queue.c: Queue default-sales has no realtime members defined. No need for update [Feb 8 09:02:21] DEBUG[17250] manager.c: Manager received command 'ExtensionState' [Feb 8 09:02:21] DEBUG[17250] chan_sip.c: Checking device state for peer 6002 [Feb 8 09:02:21] DEBUG[17250] manager.c: Manager received command 'ExtensionState' [Feb 8 09:02:21] DEBUG[17250] chan_sip.c: Checking device state for peer 6003 [Feb 8 09:02:21] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:21] DEBUG[17250] app_queue.c: Queue default-service has no realtime members defined. No need for update [Feb 8 09:02:21] DEBUG[17250] manager.c: Manager received command 'ExtensionState' [Feb 8 09:02:21] DEBUG[17250] chan_sip.c: Checking device state for peer 6002 [Feb 8 09:02:21] DEBUG[17250] manager.c: Manager received command 'ExtensionState' [Feb 8 09:02:21] DEBUG[17250] chan_sip.c: Checking device state for peer 6003 [Feb 8 09:02:21] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:21] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:21] DEBUG[17250] manager.c: Manager received command 'GetVar' [Feb 8 09:02:21] DEBUG[17250] manager.c: Manager received command 'GetVar' [Feb 8 09:02:21] DEBUG[17250] manager.c: Manager received command 'GetVar' [Feb 8 09:02:21] DEBUG[17250] manager.c: Manager received command 'GetVar' [Feb 8 09:02:21] DEBUG[17250] manager.c: Manager received command 'GetVar' [Feb 8 09:02:21] DEBUG[17250] manager.c: Manager received command 'GetVar' [Feb 8 09:02:21] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:21] DEBUG[17250] manager.c: Manager received command 'GetVar' [Feb 8 09:02:22] DEBUG[17250] manager.c: Manager received command 'GetVar' [Feb 8 09:02:22] DEBUG[18730] manager.c: Manager received command 'login' [Feb 8 09:02:22] VERBOSE[18730] logger.c: == Parsing '/etc/asterisk/manager.conf': [Feb 8 09:02:22] DEBUG[18730] config.c: Parsing /etc/asterisk/manager.conf [Feb 8 09:02:22] VERBOSE[18730] logger.c: Found [Feb 8 09:02:22] DEBUG[18730] acl.c: 127.0.0.1/255.255.255.255 appended to acl for peer [Feb 8 09:02:22] DEBUG[18730] acl.c: ##### Testing 127.0.0.1 with 127.0.0.1 [Feb 8 09:02:22] DEBUG[18730] manager.c: Manager received command 'Command' [Feb 8 09:02:22] DEBUG[18730] db.c: Unable to find key 'ChanSpy' in family 'default/6002' [Feb 8 09:02:22] DEBUG[18730] manager.c: Manager received command 'Command' [Feb 8 09:02:22] DEBUG[18730] db.c: Unable to find key 'DoNotDisturb' in family 'default/6002' [Feb 8 09:02:22] DEBUG[18730] manager.c: Manager received command 'Command' [Feb 8 09:02:22] DEBUG[18730] manager.c: Manager received command 'Command' [Feb 8 09:02:22] DEBUG[18730] manager.c: Manager received command 'Command' [Feb 8 09:02:22] DEBUG[18730] manager.c: Manager received command 'Command' [Feb 8 09:02:22] DEBUG[18730] db.c: Unable to find key 'CallWaiting' in family 'default/6002' [Feb 8 09:02:22] DEBUG[18730] manager.c: Manager received command 'Command' [Feb 8 09:02:22] DEBUG[18730] db.c: Unable to find key 'Login' in family 'default/6002/Agent' [Feb 8 09:02:22] DEBUG[18730] manager.c: Manager received command 'Command' [Feb 8 09:02:22] DEBUG[18730] db.c: Unable to find key 'Paused' in family 'default/6002/Agent' [Feb 8 09:02:22] DEBUG[18730] manager.c: Manager received command 'Command' [Feb 8 09:02:22] DEBUG[18730] db.c: Unable to find key 'HotDesk' in family 'default/6002' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'show uptime' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] app_queue.c: Queue default-remote_agent_test has no realtime members defined. No need for update [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] app_queue.c: Queue default-sales has no realtime members defined. No need for update [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'ExtensionState' [Feb 8 09:02:23] DEBUG[17250] chan_sip.c: Checking device state for peer 6002 [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'ExtensionState' [Feb 8 09:02:23] DEBUG[17250] chan_sip.c: Checking device state for peer 6003 [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] app_queue.c: Queue default-service has no realtime members defined. No need for update [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'ExtensionState' [Feb 8 09:02:23] DEBUG[17250] chan_sip.c: Checking device state for peer 6002 [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'ExtensionState' [Feb 8 09:02:23] DEBUG[17250] chan_sip.c: Checking device state for peer 6003 [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'ChanSpy' in family 'default/6008' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'DoNotDisturb' in family 'default/6008' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'CallForward' in family 'default/6008' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'CallForwardOnBusy' in family 'default/6008' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'CallWaiting' in family 'default/6008' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'Login' in family 'default/6008/Agent' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'Paused' in family 'default/6008/Agent' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'HotDesk' in family 'default/6008' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'ChanSpy' in family 'default/6009' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'DoNotDisturb' in family 'default/6009' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'CallWaiting' in family 'default/6009' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'Login' in family 'default/6009/Agent' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'Paused' in family 'default/6009/Agent' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'HotDesk' in family 'default/6009' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'ChanSpy' in family 'default/6010' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'DoNotDisturb' in family 'default/6010' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'CallWaiting' in family 'default/6010' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'Login' in family 'default/6010/Agent' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'Paused' in family 'default/6010/Agent' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'HotDesk' in family 'default/6010' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'ChanSpy' in family 'default/6011' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'DoNotDisturb' in family 'default/6011' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'CallWaiting' in family 'default/6011' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'Login' in family 'default/6011/Agent' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'Paused' in family 'default/6011/Agent' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'HotDesk' in family 'default/6011' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'ChanSpy' in family 'default/6012' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'DoNotDisturb' in family 'default/6012' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'CallWaiting' in family 'default/6012' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'Login' in family 'default/6012/Agent' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'Paused' in family 'default/6012/Agent' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'HotDesk' in family 'default/6012' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'ChanSpy' in family 'default/6364' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'DoNotDisturb' in family 'default/6364' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'CallWaiting' in family 'default/6364' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'Login' in family 'default/6364/Agent' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'Paused' in family 'default/6364/Agent' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'HotDesk' in family 'default/6364' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'ChanSpy' in family 'default/1' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'DoNotDisturb' in family 'default/1' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'CallForward' in family 'default/1' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'CallForwardOnBusy' in family 'default/1' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'CallForwardOnNoAnswer' in family 'default/1' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'CallWaiting' in family 'default/1' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'Login' in family 'default/1/Agent' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'Paused' in family 'default/1/Agent' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'HotDesk' in family 'default/1' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'ChanSpy' in family 'default/2' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'DoNotDisturb' in family 'default/2' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'CallForward' in family 'default/2' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'CallForwardOnBusy' in family 'default/2' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'CallForwardOnNoAnswer' in family 'default/2' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'CallWaiting' in family 'default/2' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'Login' in family 'default/2/Agent' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'Paused' in family 'default/2/Agent' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'HotDesk' in family 'default/2' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'ChanSpy' in family 'default/3' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'DoNotDisturb' in family 'default/3' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'CallForward' in family 'default/3' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'CallForwardOnBusy' in family 'default/3' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'CallForwardOnNoAnswer' in family 'default/3' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'CallWaiting' in family 'default/3' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'Login' in family 'default/3/Agent' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'Paused' in family 'default/3/Agent' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'HotDesk' in family 'default/3' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'ChanSpy' in family 'default/4' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'DoNotDisturb' in family 'default/4' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'CallForward' in family 'default/4' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'CallForwardOnBusy' in family 'default/4' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'CallForwardOnNoAnswer' in family 'default/4' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'CallWaiting' in family 'default/4' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'Login' in family 'default/4/Agent' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'Paused' in family 'default/4/Agent' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'HotDesk' in family 'default/4' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'ChanSpy' in family 'default/5' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'DoNotDisturb' in family 'default/5' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'CallForward' in family 'default/5' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'CallForwardOnBusy' in family 'default/5' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'CallForwardOnNoAnswer' in family 'default/5' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'CallWaiting' in family 'default/5' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'Login' in family 'default/5/Agent' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'Paused' in family 'default/5/Agent' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] db.c: Unable to find key 'HotDesk' in family 'default/5' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'GetVar' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'GetVar' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'GetVar' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'GetVar' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'GetVar' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'GetVar' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'Command' [Feb 8 09:02:23] DEBUG[18719] rtp.c: Got RTCP report of 84 bytes [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'GetVar' [Feb 8 09:02:23] DEBUG[17250] manager.c: Manager received command 'GetVar' [Feb 8 09:02:23] VERBOSE[17251] logger.c: <--- SIP read from 192.168.30.162:2060 ---> BYE sip:6004@192.168.30.254 SIP/2.0 Via: SIP/2.0/UDP 192.168.30.162:2060;branch=z9hG4bK-ltxfna96e1va;rport From: ;tag=xxog573r0f To: "Don Wright" ;tag=as5b1fd0ea Call-ID: 2ecf0b72687235855a6b5c350188e0dd@192.168.30.254 CSeq: 1 BYE Max-Forwards: 70 Contact: ;flow-id=1 User-Agent: snom360/7.1.30 RTP-RxStat: Total_Rx_Pkts=157,Rx_Pkts=157,Rx_Pkts_Lost=1,Remote_Rx_Pkts_Lost=0 RTP-TxStat: Total_Tx_Pkts=183,Tx_Pkts=183,Remote_Tx_Pkts=0 Content-Length: 0 <-------------> [Feb 8 09:02:23] VERBOSE[17251] logger.c: --- (12 headers 0 lines) --- [Feb 8 09:02:23] VERBOSE[17251] logger.c: Sending to 192.168.30.162 : 2060 (NAT) [Feb 8 09:02:23] DEBUG[17251] chan_sip.c: Setting SIP_ALREADYGONE on dialog 2ecf0b72687235855a6b5c350188e0dd@192.168.30.254 [Feb 8 09:02:23] DEBUG[17251] chan_sip.c: Received bye, issuing owner hangup [Feb 8 09:02:23] VERBOSE[17251] logger.c: <--- Transmitting (NAT) to 192.168.30.162:2060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.30.162:2060;branch=z9hG4bK-ltxfna96e1va;received=192.168.30.162;rport=2060 From: ;tag=xxog573r0f To: "Don Wright" ;tag=as5b1fd0ea Call-ID: 2ecf0b72687235855a6b5c350188e0dd@192.168.30.254 CSeq: 1 BYE User-Agent: Asterisk PBX (Fireworx) Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Feb 8 09:02:23] DEBUG[18719] channel.c: Didn't get a frame from channel: SIP/6000-08ce6448 [Feb 8 09:02:23] DEBUG[18719] channel.c: Bridge stops bridging channels SIP/6004-08ce1c68 and SIP/6000-08ce6448 [Feb 8 09:02:23] DEBUG[18719] channel.c: Hanging up channel 'SIP/6000-08ce6448' [Feb 8 09:02:23] DEBUG[18719] chan_sip.c: Hangup call SIP/6000-08ce6448, SIP callid 2ecf0b72687235855a6b5c350188e0dd@192.168.30.254) [Feb 8 09:02:23] DEBUG[18719] chan_sip.c: update_call_counter(6000) - decrement call limit counter on hangup [Feb 8 09:02:23] DEBUG[18719] chan_sip.c: Updating call counter for outgoing call [Feb 8 09:02:23] DEBUG[18719] chan_sip.c: Call to peer '6000' removed from call limit 6 [Feb 8 09:02:23] DEBUG[18719] devicestate.c: Notification of state change to be queued on device/channel SIP/6000 [Feb 8 09:02:23] DEBUG[18719] devicestate.c: Notification of state change to be queued on device/channel SIP/6000-08ce6448 [Feb 8 09:02:23] DEBUG[18719] devicestate.c: Notification of state change to be queued on device/channel SIP/6000 [Feb 8 09:02:23] DEBUG[18719] rtp.c: Channel '' has no RTP, not doing anything [Feb 8 09:02:23] DEBUG[18719] app_dial.c: Exiting with DIALSTATUS=ANSWER. [Feb 8 09:02:23] DEBUG[17152] chan_sip.c: Checking device state for peer 6000 [Feb 8 09:02:23] DEBUG[17152] devicestate.c: Changing state for SIP/6000 - state 1 (Not in use) [Feb 8 09:02:23] DEBUG[17152] chan_sip.c: Checking device state for peer 6000 [Feb 8 09:02:23] DEBUG[17276] app_queue.c: Device 'SIP/6000' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Feb 8 09:02:23] VERBOSE[18719] logger.c: -- AGI Script /var/www/scopserv/telephony/scripts/agi/dial.php completed, returning 0 [Feb 8 09:02:23] DEBUG[18719] app_macro.c: Executed application: AGI [Feb 8 09:02:23] DEBUG[18719] pbx.c: Expression result is '1' [Feb 8 09:02:23] DEBUG[18719] pbx.c: Launching 'GotoIf' [Feb 8 09:02:23] VERBOSE[18719] logger.c: -- Executing [6000@default-super:8] GotoIf("SIP/6004-08ce1c68", "1?9:10") in new stack [Feb 8 09:02:23] DEBUG[17152] chan_sip.c: Checking device state for peer 6000 [Feb 8 09:02:23] VERBOSE[17152] logger.c: Reliably Transmitting (no NAT) to 192.168.30.200:5060: NOTIFY sip:6002@192.168.30.200:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK0b2453d4;rport From: ;tag=as2d926193 To: "Reception 6002" ;tag=868B9436-DAD76617 Contact: Call-ID: 31382413-766b0334-3e527895@192.168.30.200 CSeq: 105 NOTIFY User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Event: presence Content-Type: application/xpidf+xml Subscription-State: active Content-Length: 348
--- [Feb 8 09:02:23] VERBOSE[17152] logger.c: Extension Changed 6000[default-local] new state Idle for Notify User 6002 [Feb 8 09:02:23] DEBUG[17152] chan_sip.c: Checking device state for peer 6000 [Feb 8 09:02:23] VERBOSE[17152] logger.c: Reliably Transmitting (no NAT) to 192.168.30.193:5060: NOTIFY sip:6001@192.168.30.193:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK7b0cdc57;rport From: ;tag=as43a73733 To: Reception 6001 ;tag=553a7c9816 Contact: Call-ID: db25cf758f0c7d5d CSeq: 105 NOTIFY User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 212 terminated --- [Feb 8 09:02:23] VERBOSE[17152] logger.c: Extension Changed 6000[default-local] new state Idle for Notify User 6001 [Feb 8 09:02:23] DEBUG[17152] chan_sip.c: Checking device state for peer 6000 [Feb 8 09:02:23] VERBOSE[17152] logger.c: Reliably Transmitting (no NAT) to 192.168.30.162:2060: NOTIFY sip:6000@192.168.30.162:2060;line=307oc8ge SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK71aa656a;rport From: ;tag=as2333a6cb To: ;tag=tcw3etzs3a Contact: Call-ID: 3c2670171858-a4rpauw7l41k CSeq: 106 NOTIFY User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 207 terminated --- [Feb 8 09:02:23] VERBOSE[17152] logger.c: Extension Changed 6000[default-local] new state Idle for Notify User 6000 [Feb 8 09:02:23] DEBUG[17152] chan_sip.c: Checking device state for peer 6000-08ce6448 [Feb 8 09:02:23] VERBOSE[18719] logger.c: -- Goto (default-super,6000,9) [Feb 8 09:02:23] DEBUG[18719] pbx.c: Launching 'Hangup' [Feb 8 09:02:23] VERBOSE[18719] logger.c: -- Executing [6000@default-super:9] Hangup("SIP/6004-08ce1c68", "") in new stack [Feb 8 09:02:23] DEBUG[18719] pbx.c: Spawn extension (default-super,6000,9) exited non-zero on 'SIP/6004-08ce1c68' [Feb 8 09:02:23] VERBOSE[18719] logger.c: == Spawn extension (default-super, 6000, 9) exited non-zero on 'SIP/6004-08ce1c68' [Feb 8 09:02:23] DEBUG[18719] channel.c: Soft-Hanging up channel 'SIP/6004-08ce1c68' [Feb 8 09:02:23] DEBUG[18719] channel.c: Hanging up channel 'SIP/6004-08ce1c68' [Feb 8 09:02:23] DEBUG[18719] chan_sip.c: Hangup call SIP/6004-08ce1c68, SIP callid b6d07bd0a85bb952fc3184f5e5ba5169@192.168.30.178) [Feb 8 09:02:23] DEBUG[18719] chan_sip.c: update_call_counter(6004) - decrement call limit counter on hangup [Feb 8 09:02:23] DEBUG[18719] chan_sip.c: Updating call counter for incoming call [Feb 8 09:02:23] DEBUG[18719] chan_sip.c: Call from peer '6004' removed from call limit 4 [Feb 8 09:02:23] DEBUG[18719] devicestate.c: Notification of state change to be queued on device/channel SIP/6004 [Feb 8 09:02:23] VERBOSE[18719] logger.c: Scheduling destruction of SIP dialog 'b6d07bd0a85bb952fc3184f5e5ba5169@192.168.30.178' in 32000 ms (Method: ACK) [Feb 8 09:02:23] DEBUG[18719] chan_sip.c: Strict routing enforced for session b6d07bd0a85bb952fc3184f5e5ba5169@192.168.30.178 [Feb 8 09:02:23] VERBOSE[18719] logger.c: set_destination: Parsing for address/port to send to [Feb 8 09:02:23] VERBOSE[18719] logger.c: set_destination: set destination to 192.168.30.178, port 5060 [Feb 8 09:02:23] VERBOSE[18719] logger.c: Reliably Transmitting (no NAT) to 192.168.30.178:5060: BYE sip:6004@192.168.30.178;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK4b8a0c31;rport From: 6000 ;tag=as6889e0e3 To: Don Wright ;tag=205714ae9d2ac6b Call-ID: b6d07bd0a85bb952fc3184f5e5ba5169@192.168.30.178 CSeq: 102 BYE User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Content-Length: 0 --- [Feb 8 09:02:23] DEBUG[17152] devicestate.c: Changing state for SIP/6000-08ce6448 - state 4 (Invalid) [Feb 8 09:02:23] DEBUG[17152] chan_sip.c: Checking device state for peer 6000 [Feb 8 09:02:23] DEBUG[17152] devicestate.c: Changing state for SIP/6000 - state 1 (Not in use) [Feb 8 09:02:23] DEBUG[17152] chan_sip.c: Checking device state for peer 6000 [Feb 8 09:02:23] DEBUG[17152] chan_sip.c: Checking device state for peer 6004 [Feb 8 09:02:23] DEBUG[17152] devicestate.c: Changing state for SIP/6004 - state 1 (Not in use) [Feb 8 09:02:23] DEBUG[17152] chan_sip.c: Checking device state for peer 6004 [Feb 8 09:02:23] DEBUG[17276] app_queue.c: Device 'SIP/6000-08ce6448' changed to state '4' (Invalid) but we don't care because they're not a member of any queue. [Feb 8 09:02:23] VERBOSE[17251] logger.c: Really destroying SIP dialog '2ecf0b72687235855a6b5c350188e0dd@192.168.30.254' Method: BYE [Feb 8 09:02:23] DEBUG[17276] app_queue.c: Device 'SIP/6000' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Feb 8 09:02:23] DEBUG[17276] app_queue.c: Device 'SIP/6004' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Feb 8 09:02:23] VERBOSE[17251] logger.c: <--- SIP read from 192.168.30.200:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK0b2453d4;rport From: ;tag=as2d926193 To: "Reception 6002" ;tag=868B9436-DAD76617 CSeq: 105 NOTIFY Call-ID: 31382413-766b0334-3e527895@192.168.30.200 Contact: Event: presence User-Agent: PolycomSoundPointIP-SPIP_550-UA/3.0.0.0258 Content-Length: 0 <-------------> [Feb 8 09:02:23] VERBOSE[17251] logger.c: --- (10 headers 0 lines) --- [Feb 8 09:02:23] DEBUG[17251] chan_sip.c: Acked pending invite 105 [Feb 8 09:02:23] DEBUG[17251] chan_sip.c: Stopping retransmission on '31382413-766b0334-3e527895@192.168.30.200' of Request 105: Match Not Found [Feb 8 09:02:23] VERBOSE[17251] logger.c: SIP Response message for INCOMING dialog NOTIFY arrived [Feb 8 09:02:23] DEBUG[18719] devicestate.c: Notification of state change to be queued on device/channel SIP/6004-08ce1c68 [Feb 8 09:02:23] DEBUG[18719] devicestate.c: Notification of state change to be queued on device/channel SIP/6004 [Feb 8 09:02:23] DEBUG[18719] pbx.c: Function result is '"Don Wright" <6004>' [Feb 8 09:02:23] DEBUG[18719] pbx.c: Function result is '6004' [Feb 8 09:02:23] DEBUG[18719] pbx.c: Function result is '6000' [Feb 8 09:02:23] DEBUG[18719] pbx.c: Function result is 'default-super' [Feb 8 09:02:23] DEBUG[18719] pbx.c: Function result is 'SIP/6004-08ce1c68' [Feb 8 09:02:23] DEBUG[18719] pbx.c: Function result is 'SIP/6000-08ce6448' [Feb 8 09:02:23] DEBUG[18719] pbx.c: Function result is 'Hangup' [Feb 8 09:02:23] DEBUG[18719] pbx.c: Function result is '' [Feb 8 09:02:23] DEBUG[18719] pbx.c: Function result is '2008-02-08 09:02:18' [Feb 8 09:02:23] DEBUG[18719] pbx.c: Function result is '2008-02-08 09:02:19' [Feb 8 09:02:23] DEBUG[18719] pbx.c: Function result is '2008-02-08 09:02:23' [Feb 8 09:02:23] DEBUG[18719] pbx.c: Function result is '5' [Feb 8 09:02:23] DEBUG[18719] pbx.c: Function result is '4' [Feb 8 09:02:23] DEBUG[18719] pbx.c: Function result is 'ANSWERED' [Feb 8 09:02:23] DEBUG[18719] pbx.c: Function result is 'DOCUMENTATION' [Feb 8 09:02:23] DEBUG[18719] pbx.c: Function result is '6004' [Feb 8 09:02:23] DEBUG[18719] pbx.c: Function result is '1202479338.0' [Feb 8 09:02:23] DEBUG[18719] pbx.c: Function result is '' [Feb 8 09:02:23] DEBUG[17152] chan_sip.c: Checking device state for peer 6004 [Feb 8 09:02:23] VERBOSE[17152] logger.c: Reliably Transmitting (no NAT) to 192.168.30.200:5060: NOTIFY sip:6002@192.168.30.200:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK40c524e5;rport From: ;tag=as1ec546fb To: "Reception 6002" ;tag=F43D395A-94BE4C3B Contact: Call-ID: dedf8637-a30ce658-849d1cb9@192.168.30.200 CSeq: 104 NOTIFY User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Event: presence Content-Type: application/xpidf+xml Subscription-State: active Content-Length: 348
--- [Feb 8 09:02:23] VERBOSE[17152] logger.c: Extension Changed 6004[default-local] new state Idle for Notify User 6002 [Feb 8 09:02:23] DEBUG[17152] chan_sip.c: Checking device state for peer 6004 [Feb 8 09:02:23] VERBOSE[17152] logger.c: Reliably Transmitting (no NAT) to 192.168.30.193:5060: NOTIFY sip:6001@192.168.30.193:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK6ef83432;rport From: ;tag=as0bf510b1 To: Reception 6001 ;tag=8a19c21100 Contact: Call-ID: 9602d6bad327dfab CSeq: 104 NOTIFY User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 212 terminated --- [Feb 8 09:02:23] VERBOSE[17152] logger.c: Extension Changed 6004[default-local] new state Idle for Notify User 6001 [Feb 8 09:02:23] DEBUG[17152] chan_sip.c: Checking device state for peer 6004 [Feb 8 09:02:23] VERBOSE[17152] logger.c: Reliably Transmitting (no NAT) to 192.168.30.162:2060: NOTIFY sip:6000@192.168.30.162:2060;line=307oc8ge SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK071269bd;rport From: ;tag=as7d02ed49 To: ;tag=xl4ze4djv5 Contact: Call-ID: 3c267017194a-f3nna9a3is4w CSeq: 105 NOTIFY User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 207 terminated --- [Feb 8 09:02:23] VERBOSE[17152] logger.c: Extension Changed 6004[default-local] new state Idle for Notify User 6000 [Feb 8 09:02:23] DEBUG[17152] chan_sip.c: Checking device state for peer 6004-08ce1c68 [Feb 8 09:02:23] DEBUG[18719] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record. [Feb 8 09:02:23] DEBUG[18719] cdr_addon_mysql.c: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid,userfield) VALUES ('2008-02-08 09:02:18','\"Don Wright\" <6004>','6004','6000','default-super', 'SIP/6004-08ce1c68','SIP/6000-08ce6448','Hangup','',5,4,'ANSWERED',3,'6004','1202479338.0','') [Feb 8 09:02:23] DEBUG[17152] devicestate.c: Changing state for SIP/6004-08ce1c68 - state 4 (Invalid) [Feb 8 09:02:23] DEBUG[17152] chan_sip.c: Checking device state for peer 6004 [Feb 8 09:02:23] DEBUG[17152] devicestate.c: Changing state for SIP/6004 - state 1 (Not in use) [Feb 8 09:02:23] DEBUG[17152] chan_sip.c: Checking device state for peer 6004 [Feb 8 09:02:23] DEBUG[17276] app_queue.c: Device 'SIP/6004-08ce1c68' changed to state '4' (Invalid) but we don't care because they're not a member of any queue. [Feb 8 09:02:23] DEBUG[17276] app_queue.c: Device 'SIP/6004' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Feb 8 09:02:23] VERBOSE[17251] logger.c: <--- SIP read from 192.168.30.162:2060 ---> SIP/2.0 200 Ok Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK71aa656a;rport=5060 From: ;tag=as2333a6cb To: ;tag=tcw3etzs3a Call-ID: 3c2670171858-a4rpauw7l41k CSeq: 106 NOTIFY Content-Length: 0 <------------->