[Sep 15 15:15:16] DEBUG[16316] channel.c: Scheduling timer at 0 sample intervals
[Sep 15 15:15:16] DEBUG[16316] chan_sip.c: SIP transfer: trying to masquerade SIP/9000-b7733798 into SIP/1851-b797a020
[Sep 15 15:15:16] DEBUG[16316] channel.c: Planning to masquerade channel SIP/9000-b7733798 into the structure of SIP/1851-b797a020
[Sep 15 15:15:16] DEBUG[16316] channel.c: Done planning to masquerade channel SIP/9000-b7733798 into the structure of SIP/1851-b797a020
[Sep 15 15:15:16] DEBUG[16316] chan_sip.c: SIP transfer: Succeeded to masquerade channels.
[Sep 15 15:15:16] DEBUG[16316] chan_sip.c: SIP attended transfer: Unlocking channel SIP/1851-b797a020
[Sep 15 15:15:16] DEBUG[16080] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=106)
[Sep 15 15:15:16] DEBUG[28362] channel.c: Actually Masquerading SIP/9000-b7733798(6) into the structure of SIP/1851-b797a020(6)
[Sep 15 15:15:16] DEBUG[28362] channel.c: Got clone lock for masquerade on 'SIP/9000-b7733798' at 0xb772e748
[Sep 15 15:15:16] DEBUG[28362] chan_sip.c: SIP Fixup: New owner for dialogue eec7b5ca-cea6a0a5-3be2a950@192.168.21.74: SIP/9000-b7733798<MASQ> (Old parent: SIP/9000-b7733798)
[Sep 15 15:15:16] DEBUG[28362] chan_sip.c: Hangup call SIP/9000-b7733798<MASQ>, SIP callid eec7b5ca-cea6a0a5-3be2a950@192.168.21.74)
[Sep 15 15:15:16] DEBUG[28362] chan_sip.c: Updating call counter for incoming call
[Sep 15 15:15:16] DEBUG[28362] chan_sip.c: Call from peer '1851' removed from call limit 4
[Sep 15 15:15:16] DEBUG[28362] devicestate.c: Notification of state change to be queued on device/channel SIP/1851
[Sep 15 15:15:16] DEBUG[28362] channel.c: Putting channel SIP/9000-b7733798 in 8/8 formats
[Sep 15 15:15:16] DEBUG[28362] chan_sip.c: SIP Fixup: New owner for dialogue call-F10F2891-3765-2B10-081A-494C@192.168.0.2: SIP/9000-b7733798 (Old parent: SIP/1851-b797a020<ZOMBIE>)
[Sep 15 15:15:16] DEBUG[28362] channel.c: Released clone lock on 'SIP/1851-b797a020<ZOMBIE>'
[Sep 15 15:15:16] DEBUG[28362] channel.c: Done Masquerading SIP/9000-b7733798 (6)
[Sep 15 15:15:16] DEBUG[27441] channel.c: Didn't get a frame from channel: SIP/1851-b797a020<ZOMBIE>
[Sep 15 15:15:16] DEBUG[27441] channel.c: Bridge stops bridging channels SIP/1851-b797a020<ZOMBIE> and SIP/1851-0919b320
[Sep 15 15:15:16] DEBUG[27441] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
[Sep 15 15:15:16] DEBUG[27441] 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-09-15 15:14:05','0119425088','0119425088','s','default-application-acd-internal_sales', 'SIP/9000-b7733798','SIP/1851-0919b320','Queue','default-internal_sales|t
|||900|',71,71,'ANSWERED',3,'9000','1221484445.965','0800')
[Sep 15 15:15:16] DEBUG[16312] devicestate.c: No provider found, checking channel drivers for SIP - 1851
[Sep 15 15:15:16] DEBUG[16312] chan_sip.c: Checking device state for peer 1851
[Sep 15 15:15:16] DEBUG[16312] devicestate.c: Changing state for SIP/1851 - state 8 (On Hold)
[Sep 15 15:15:16] DEBUG[16312] devicestate.c: No provider found, checking channel drivers for SIP - 1851
[Sep 15 15:15:16] DEBUG[16312] chan_sip.c: Checking device state for peer 1851
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Function result is '0119425088'
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Function result is '0119425088'
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Function result is 's'
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Function result is 'default-application-acd-internal_sales'
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Function result is 'SIP/9000-b7733798'
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Function result is 'SIP/1851-0919b320'
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Function result is 'Queue'
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Function result is 'default-internal_sales|t|||900|'
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Function result is '2008-09-15 15:14:05'
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Function result is '2008-09-15 15:14:05'
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Function result is '2008-09-15 15:15:16'
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Function result is '71'
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Function result is '71'
[Sep 15 15:15:16] DEBUG[16317] app_queue.c: Device 'SIP/1851' changed to state '8' (On Hold) but we don't care because they're not a member of any queue.
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Function result is 'ANSWERED'
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Function result is 'DOCUMENTATION'
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Function result is '9000'
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Function result is '1221484445.965'
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Function result is '0800'
[Sep 15 15:15:16] DEBUG[27441] channel.c: Hanging up channel 'SIP/1851-0919b320'
[Sep 15 15:15:16] DEBUG[27441] chan_sip.c: Updating call counter for outgoing call
[Sep 15 15:15:16] DEBUG[27441] devicestate.c: Notification of state change to be queued on device/channel SIP/1851
[Sep 15 15:15:16] DEBUG[16312] devicestate.c: No provider found, checking channel drivers for SIP - 1851
[Sep 15 15:15:16] DEBUG[27441] chan_sip.c: Call to peer '1851' removed from call limit 4
[Sep 15 15:15:16] DEBUG[16312] chan_sip.c: Checking device state for peer 1851
[Sep 15 15:15:16] DEBUG[27441] devicestate.c: Notification of state change to be queued on device/channel SIP/1851
[Sep 15 15:15:16] DEBUG[16312] devicestate.c: Changing state for SIP/1851 - state 1 (Not in use)
[Sep 15 15:15:16] DEBUG[27441] chan_sip.c: SIP Transfer: Not hanging up right now... Rescheduling hangup for 23c8f2ce2addf1f601491fa13aface74@192.168.21.250.
[Sep 15 15:15:16] DEBUG[16312] devicestate.c: No provider found, checking channel drivers for SIP - 1851
[Sep 15 15:15:16] DEBUG[16312] chan_sip.c: Checking device state for peer 1851
[Sep 15 15:15:16] DEBUG[16317] app_queue.c: Device 'SIP/1851' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Sep 15 15:15:16] DEBUG[27441] devicestate.c: Notification of state change to be queued on device/channel SIP/1851
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Spawn extension (default-application-acd-internal_sales,s,9) exited non-zero on 'SIP/1851-b797a020<ZOMBIE>'
[Sep 15 15:15:16] DEBUG[27441] channel.c: Soft-Hanging up channel 'SIP/1851-b797a020<ZOMBIE>'
[Sep 15 15:15:16] DEBUG[16312] devicestate.c: No provider found, checking channel drivers for SIP - 1851
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Launching 'Goto'
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Expression result is '0'
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Expression result is '2'
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Launching 'GotoIf'
[Sep 15 15:15:16] DEBUG[16312] chan_sip.c: Checking device state for peer 1851
[Sep 15 15:15:16] DEBUG[16312] devicestate.c: Changing state for SIP/1851 - state 1 (Not in use)
[Sep 15 15:15:16] DEBUG[16312] devicestate.c: No provider found, checking channel drivers for SIP - 1851
[Sep 15 15:15:16] DEBUG[16312] chan_sip.c: Checking device state for peer 1851
[Sep 15 15:15:16] DEBUG[16317] app_queue.c: Device 'SIP/1851' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Sep 15 15:15:16] DEBUG[16312] devicestate.c: No provider found, checking channel drivers for SIP - 1851
[Sep 15 15:15:16] DEBUG[16312] chan_sip.c: Checking device state for peer 1851
[Sep 15 15:15:16] DEBUG[16312] devicestate.c: Changing state for SIP/1851 - state 1 (Not in use)
[Sep 15 15:15:16] DEBUG[16317] app_queue.c: Device 'SIP/1851' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Sep 15 15:15:16] DEBUG[16312] devicestate.c: No provider found, checking channel drivers for SIP - 1851
[Sep 15 15:15:16] DEBUG[16312] chan_sip.c: Checking device state for peer 1851
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Launching 'ResetCDR'
[Sep 15 15:15:16] DEBUG[27441] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
[Sep 15 15:15:16] DEBUG[27441] 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-09-15 15:15:16','\"Patience Okafor\" <1851>','1851','s','default-application-acd-internal_sales', 'SIP/1851-b797a020','Local/1910@default-local-6f11,1','Dial','L
ocal/1910@default-local/n|',0,0,'NO ANSWER',3,'9000','1221484478.971','0910')
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Function result is '"Patience Okafor" <1851>'
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Function result is '1851'
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Function result is 's'
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Function result is 'default-application-acd-internal_sales'
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Function result is 'SIP/1851-b797a020'
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Function result is 'Local/1910@default-local-6f11,1'
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Function result is 'Dial'
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Function result is 'Local/1910@default-local/n|'
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Function result is '2008-09-15 15:15:16'
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Function result is ''
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Function result is '2008-09-15 15:15:16'
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Function result is '0'
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Function result is '0'
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Function result is 'NO ANSWER'
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Function result is 'DOCUMENTATION'
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Function result is '9000'
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Function result is '1221484478.971'
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Function result is '0910'
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Launching 'NoCDR'
[Sep 15 15:15:16] DEBUG[27441] pbx.c: Launching 'System'
[Sep 15 15:15:16] DEBUG[16316] chan_sip.c: = No match Their Call ID: 3340bd774c34fc852b487ff23837ac5c@192.168.21.250 Their Tag 541986DD-B3B745A4 Our tag: as341e10fe
[Sep 15 15:15:16] DEBUG[16316] chan_sip.c: = No match Their Call ID: eec7b5ca-cea6a0a5-3be2a950@192.168.21.74 Their Tag E9CDFACB-722B9016 Our tag: as24b086d3
[Sep 15 15:15:16] DEBUG[16316] chan_sip.c: = Found Their Call ID: 23c8f2ce2addf1f601491fa13aface74@192.168.21.250 Their Tag 11A7B49B-8E33B4E6 Our tag: as5cd87538
[Sep 15 15:15:16] DEBUG[16316] chan_sip.c: Stopping retransmission on '23c8f2ce2addf1f601491fa13aface74@192.168.21.250' of Request 103: Match Found
[Sep 15 15:15:16] DEBUG[16316] chan_sip.c: = No match Their Call ID: 3340bd774c34fc852b487ff23837ac5c@192.168.21.250 Their Tag 541986DD-B3B745A4 Our tag: as341e10fe
[Sep 15 15:15:16] DEBUG[16316] chan_sip.c: = No match Their Call ID: eec7b5ca-cea6a0a5-3be2a950@192.168.21.74 Their Tag E9CDFACB-722B9016 Our tag: as24b086d3
[Sep 15 15:15:16] DEBUG[16316] chan_sip.c: = Found Their Call ID: 23c8f2ce2addf1f601491fa13aface74@192.168.21.250 Their Tag 11A7B49B-8E33B4E6 Our tag: as5cd87538
[Sep 15 15:15:16] DEBUG[16316] chan_sip.c: **** Received BYE (8) - Command in SIP BYE
[Sep 15 15:15:16] DEBUG[16316] chan_sip.c: Setting SIP_ALREADYGONE on dialog 23c8f2ce2addf1f601491fa13aface74@192.168.21.250
[Sep 15 15:15:16] DEBUG[16316] chan_sip.c: Received bye, no owner, selfdestruct soon.
[Sep 15 15:15:16] DEBUG[16080] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=106)
[Sep 15 15:15:16] DEBUG[16316] chan_sip.c: = No match Their Call ID: 3340bd774c34fc852b487ff23837ac5c@192.168.21.250 Their Tag 541986DD-B3B745A4 Our tag: as341e10fe
[Sep 15 15:15:16] DEBUG[16316] chan_sip.c: = Found Their Call ID: eec7b5ca-cea6a0a5-3be2a950@192.168.21.74 Their Tag E9CDFACB-722B9016 Our tag: as24b086d3
[Sep 15 15:15:16] DEBUG[16316] chan_sip.c: Stopping retransmission on 'eec7b5ca-cea6a0a5-3be2a950@192.168.21.74' of Request 102: Match Found
[Sep 15 15:15:16] DEBUG[16080] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=106)
[Sep 15 15:15:16] DEBUG[16080] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=106)
[Sep 15 15:15:16] DEBUG[16080] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=106)
[Sep 15 15:15:16] DEBUG[16080] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=106)
[Sep 15 15:15:16] DEBUG[16080] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=106)
[Sep 15 15:15:16] DEBUG[16080] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=106)
[Sep 15 15:15:16] DEBUG[16080] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=106)
[Sep 15 15:15:16] DEBUG[27441] channel.c: Hanging up zombie 'SIP/1851-b797a020<ZOMBIE>'
[Sep 15 15:15:16] DEBUG[27441] devicestate.c: Notification of state change to be queued on device/channel SIP/1851
[Sep 15 15:15:16] DEBUG[16312] devicestate.c: No provider found, checking channel drivers for SIP - 1851
[Sep 15 15:15:16] DEBUG[16312] chan_sip.c: Checking device state for peer 1851
[Sep 15 15:15:16] DEBUG[16312] devicestate.c: Changing state for SIP/1851 - state 1 (Not in use)
[Sep 15 15:15:16] DEBUG[16312] devicestate.c: No provider found, checking channel drivers for SIP - 1851
[Sep 15 15:15:16] DEBUG[16312] chan_sip.c: Checking device state for peer 1851
[Sep 15 15:15:16] DEBUG[16317] app_queue.c: Device 'SIP/1851' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Sep 15 15:15:16] DEBUG[16080] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=106)
[Sep 15 15:15:16] DEBUG[16080] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=106)
[Sep 15 15:15:16] DEBUG[16080] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=106)
[Sep 15 15:15:16] DEBUG[16080] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=106)
[Sep 15 15:15:16] DEBUG[16080] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=106)
[Sep 15 15:15:16] DEBUG[16080] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=106)
[Sep 15 15:15:16] DEBUG[16080] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=106)
[Sep 15 15:15:16] DEBUG[16080] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=106)
[Sep 15 15:15:16] DEBUG[16080] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=106)
[Sep 15 15:15:16] DEBUG[16080] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=106)
[Sep 15 15:15:16] DEBUG[16080] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=106)
[Sep 15 15:15:16] DEBUG[16080] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=106)
[Sep 15 15:15:16] DEBUG[16080] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=106)
[Sep 15 15:15:16] DEBUG[16080] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=106)
[Sep 15 15:15:16] DEBUG[16080] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=106)
[Sep 15 15:15:16] DEBUG[16080] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=106)
[Sep 15 15:15:16] DEBUG[16080] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=106)
[Sep 15 15:15:16] DEBUG[16080] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=106)
[Sep 15 15:15:16] DEBUG[16080] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=106)
[Sep 15 15:15:16] DEBUG[16080] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=106)
[Sep 15 15:15:16] DEBUG[16080] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=106)
[Sep 15 15:15:16] DEBUG[16080] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=106)
[Sep 15 15:15:16] DEBUG[16080] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=106)
[Sep 15 15:15:16] DEBUG[16080] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=106)
[Sep 15 15:15:16] DEBUG[16080] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=106)
[Sep 15 15:15:16] DEBUG[13046] rtp.c: Got RTCP report of 80 bytes
[Sep 15 15:15:16] DEBUG[16391] manager.c: Manager received command 'Command'
[Sep 15 15:15:16] DEBUG[16391] app_queue.c: Queue default-service_centre has no realtime members defined. No need for update
[Sep 15 15:15:16] DEBUG[16080] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=106)
[Sep 15 15:15:16] DEBUG[16391] manager.c: Manager received command 'Command'
[Sep 15 15:15:16] DEBUG[16080] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=106)
[Sep 15 15:15:16] DEBUG[16391] manager.c: Manager received command 'Command'
[Sep 15 15:15:16] DEBUG[16391] manager.c: Manager received command 'Command'
[Sep 15 15:15:16] DEBUG[16391] manager.c: Manager received command 'Command'
[Sep 15 15:15:17] DEBUG[16391] manager.c: Manager received command 'show uptime'