[Oct  8 13:15:33] Asterisk SVN-branch-12-r400671 built by root @ <hostname> on a i686 running Linux on 2013-10-01 16:12:22 UTC
[Oct  8 13:15:33] VERBOSE[18206] config.c:   == Parsing '/etc/asterisk/logger.conf': Found
[Oct  8 13:15:33] VERBOSE[18206] logger.c:  Asterisk Queue Logger restarted
[Oct  8 13:16:04] Asterisk SVN-branch-12-r400671 built by root @ <hostname> on a i686 running Linux on 2013-10-01 16:12:22 UTC
[Oct  8 13:16:04] DEBUG[18206] config.c: Parsing /etc/asterisk/logger.conf
[Oct  8 13:16:04] VERBOSE[18206] config.c:   == Parsing '/etc/asterisk/logger.conf': Found
[Oct  8 13:16:04] VERBOSE[18206] logger.c:  Asterisk Queue Logger restarted
[Oct  8 13:16:18] DEBUG[18073] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:16:23] DEBUG[18073] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:16:28] DEBUG[18073] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:16:30] DEBUG[18081] threadpool.c: Worker thread idle timeout reached. Dying.
[Oct  8 13:16:30] DEBUG[18077] threadpool.c: Destroying worker thread 2
[Oct  8 13:16:30] DEBUG[18082] threadpool.c: Worker thread idle timeout reached. Dying.
[Oct  8 13:16:30] DEBUG[18083] threadpool.c: Worker thread idle timeout reached. Dying.
[Oct  8 13:16:30] DEBUG[18077] threadpool.c: Destroying worker thread 3
[Oct  8 13:16:30] DEBUG[18077] threadpool.c: Destroying worker thread 4
[Oct  8 13:16:33] DEBUG[18073] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:16:33] DEBUG[18209] manager.c: Running action 'Login'
[Oct  8 13:16:33] VERBOSE[18209] manager.c:   == Manager 'test' logged on from 127.0.0.1
[Oct  8 13:16:34] DEBUG[18080] threadpool.c: Worker thread idle timeout reached. Dying.
[Oct  8 13:16:34] DEBUG[18077] threadpool.c: Destroying worker thread 1
[Oct  8 13:16:34] DEBUG[18084] threadpool.c: Worker thread idle timeout reached. Dying.
[Oct  8 13:16:34] DEBUG[18059] threadpool.c: Destroying worker thread 5
[Oct  8 13:16:34] DEBUG[18079] threadpool.c: Worker thread idle timeout reached. Dying.
[Oct  8 13:16:34] DEBUG[18077] threadpool.c: Destroying worker thread 0
[Oct  8 13:16:38] DEBUG[18073] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:16:43] DEBUG[18073] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:16:48] DEBUG[18073] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:16:52] DEBUG[18077] threadpool.c: Increasing threadpool SIP's size by 5
[Oct  8 13:16:52] DEBUG[18213] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint phone_B
[Oct  8 13:16:52] DEBUG[18213] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint phone_B
[Oct  8 13:16:52] DEBUG[18213] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint phone_B
[Oct  8 13:16:52] DEBUG[18213] res_pjsip_authenticator_digest.c: Calculated nonce 1381256212/16f4b5e327c60317f941f700a91bf8d4. Actual nonce is 1381256212/16f4b5e327c60317f941f700a91bf8d4
[Oct  8 13:16:52] DEBUG[18213] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x978606c'
[Oct  8 13:16:52] DEBUG[18213] res_rtp_asterisk.c: Allocated port 16880 for RTP instance '0x978606c'
[Oct  8 13:16:52] DEBUG[18213] rtp_engine.c: RTP instance '0x978606c' is setup and ready to go
[Oct  8 13:16:52] DEBUG[18213] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x978606c'
[Oct  8 13:16:52] DEBUG[18213] rtp_engine.c: Setting payload 0 based on m type on 0xb5808548
[Oct  8 13:16:52] DEBUG[18213] rtp_engine.c: Setting payload 8 based on m type on 0xb5808548
[Oct  8 13:16:52] DEBUG[18213] rtp_engine.c: Setting payload 9 based on m type on 0xb5808548
[Oct  8 13:16:52] DEBUG[18213] rtp_engine.c: Setting payload 111 based on m type on 0xb5808548
[Oct  8 13:16:52] DEBUG[18213] rtp_engine.c: Setting payload 18 based on m type on 0xb5808548
[Oct  8 13:16:52] DEBUG[18213] rtp_engine.c: Setting payload 58 based on m type on 0xb5808548
[Oct  8 13:16:52] DEBUG[18213] rtp_engine.c: Setting payload 118 based on m type on 0xb5808548
[Oct  8 13:16:52] DEBUG[18213] rtp_engine.c: Setting payload 58 based on m type on 0xb5808548
[Oct  8 13:16:52] DEBUG[18213] rtp_engine.c: Setting payload 96 based on m type on 0xb5808548
[Oct  8 13:16:52] DEBUG[18213] rtp_engine.c: Copying payload 0 from 0xb5808548 to 0x9786194
[Oct  8 13:16:52] DEBUG[18213] rtp_engine.c: Copying payload 8 from 0xb5808548 to 0x9786194
[Oct  8 13:16:52] DEBUG[18213] rtp_engine.c: Copying payload 9 from 0xb5808548 to 0x9786194
[Oct  8 13:16:52] DEBUG[18213] rtp_engine.c: Copying payload 18 from 0xb5808548 to 0x9786194
[Oct  8 13:16:52] DEBUG[18213] rtp_engine.c: Copying payload 58 from 0xb5808548 to 0x9786194
[Oct  8 13:16:52] DEBUG[18213] rtp_engine.c: Copying payload 96 from 0xb5808548 to 0x9786194
[Oct  8 13:16:52] DEBUG[18213] rtp_engine.c: Copying payload 111 from 0xb5808548 to 0x9786194
[Oct  8 13:16:52] DEBUG[18213] rtp_engine.c: Copying payload 118 from 0xb5808548 to 0x9786194
[Oct  8 13:16:52] DEBUG[18213] res_pjsip_session.c: Method is INVITE, Response is 100 Trying
[Oct  8 13:16:52] DEBUG[18213] res_pjsip_session.c: Source of transaction state change is TX_MSG
[Oct  8 13:16:52] DEBUG[18213] res_pjsip_session.c: Sending response
[Oct  8 13:16:52] DEBUG[18213] res_pjsip_session.c: Method is INVITE, Response is 100 Trying
[Oct  8 13:16:52] DEBUG[18213] res_pjsip_session.c: Method is INVITE
[Oct  8 13:16:52] DEBUG[18071] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:16:52] DEBUG[18209] manager.c: Examining event:
Event: Newchannel
Privilege: call,all
SequenceNumber: 0
File: manager_channels.c
Line: 602
Func: channel_snapshot_update
Channel: PJSIP/phone_B-00000000
ChannelState: 4
ChannelStateDesc: Ring
CallerIDNum: 1002
CallerIDName: Phone B
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
AccountCode: 
Context: default
Exten: s
Priority: 1
Uniqueid: 1381256212.0


[Oct  8 13:16:52] DEBUG[18213] chan_pjsip.c: Started PBX on new PJSIP channel PJSIP/phone_B-00000000
[Oct  8 13:16:52] DEBUG[18218] logger.c: CALL_ID [C-00000000] created by thread.
[Oct  8 13:16:52] DEBUG[18070] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:16:52] DEBUG[18209] manager.c: Examining event:
Event: TestEvent
Privilege: test,all
SequenceNumber: 1
File: manager.c
Line: 7677
Func: test_suite_event_cb
Type: StateChange
State: CallIDChange
AppFile: channel_internal_api.c
AppFunction: ast_channel_callid_set
AppLine: 925
State: CallIDChange
Channel: PJSIP/phone_B-00000000
CallID: [C-00000000]
PriorCallID: 


[Oct  8 13:16:52] DEBUG[18218][C-00000000] logger.c: CALL_ID [C-00000000] bound to thread.
[Oct  8 13:16:52] DEBUG[18218][C-00000000] pbx.c: Launching 'AgentLogin'
[Oct  8 13:16:52] VERBOSE[18218][C-00000000] pbx.c:     -- Executing [552@internal:1] AgentLogin("PJSIP/phone_B-00000000", "1002") in new stack
[Oct  8 13:16:52] DEBUG[18071] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:16:52] DEBUG[18209] manager.c: Examining event:
Event: Newexten
Privilege: call,all
SequenceNumber: 2
File: manager_channels.c
Line: 602
Func: channel_snapshot_update
Channel: PJSIP/phone_B-00000000
ChannelState: 4
ChannelStateDesc: Ring
CallerIDNum: 1002
CallerIDName: Phone B
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
AccountCode: 
Context: internal
Exten: 552
Priority: 1
Uniqueid: 1381256212.0
Extension: 552
Application: AgentLogin
AppData: 1002


[Oct  8 13:16:52] DEBUG[18218][C-00000000] bridge.c: Bridge technology native_dahdi does not have any capabilities we want.
[Oct  8 13:16:52] DEBUG[18218][C-00000000] bridge.c: Bridge technology simple_bridge does not have any capabilities we want.
[Oct  8 13:16:52] DEBUG[18218][C-00000000] bridge.c: Bridge technology softmix does not have any capabilities we want.
[Oct  8 13:16:52] DEBUG[18218][C-00000000] bridge.c: Bridge technology native_rtp does not have any capabilities we want.
[Oct  8 13:16:52] DEBUG[18218][C-00000000] bridge.c: Chose bridge technology holding_bridge
[Oct  8 13:16:52] DEBUG[18218][C-00000000] bridge.c: Bridge 4cd44abb-660a-41c1-9ff8-c394e72dbb7a: calling holding_bridge technology constructor
[Oct  8 13:16:52] DEBUG[18218][C-00000000] bridge.c: Bridge 4cd44abb-660a-41c1-9ff8-c394e72dbb7a: calling holding_bridge technology start
[Oct  8 13:16:52] DEBUG[18071] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:16:52] DEBUG[18209] manager.c: Examining event:
Event: BridgeCreate
Privilege: call,all
SequenceNumber: 3
File: manager_bridges.c
Line: 218
Func: bridge_snapshot_update
BridgeUniqueid: 4cd44abb-660a-41c1-9ff8-c394e72dbb7a
BridgeType: agent_hold
BridgeTechnology: holding_bridge
BridgeNumChannels: 0


[Oct  8 13:16:52] DEBUG[18071] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:16:52] DEBUG[18067] devicestate.c: Changing state for PJSIP/phone_B - state 2 (In use)
[Oct  8 13:16:52] DEBUG[18209] manager.c: Examining event:
Event: Newstate
Privilege: call,all
SequenceNumber: 4
File: manager_channels.c
Line: 602
Func: channel_snapshot_update
Channel: PJSIP/phone_B-00000000
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 1002
CallerIDName: Phone B
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
AccountCode: 
Context: internal
Exten: 552
Priority: 1
Uniqueid: 1381256212.0


[Oct  8 13:16:52] DEBUG[18062] devicestate.c: Processing device state change for 'PJSIP/phone_B'
[Oct  8 13:16:52] DEBUG[18062] devicestate.c: Adding per-server state of 'In use' for 'PJSIP/phone_B'
[Oct  8 13:16:52] DEBUG[18062] devicestate.c: Aggregate devstate result is 'In use' for 'PJSIP/phone_B'
[Oct  8 13:16:52] DEBUG[18062] devicestate.c: Aggregate state for device 'PJSIP/phone_B' has changed to 'In use'
[Oct  8 13:16:52] DEBUG[18179] app_queue.c: Device 'PJSIP/phone_B' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Oct  8 13:16:52] DEBUG[18068] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:16:52] DEBUG[18209] manager.c: Examining event:
Event: ExtensionStatus
Privilege: call,all
SequenceNumber: 5
File: manager.c
Line: 6088
Func: manager_state_cb
Exten: 1002
Context: internal
Hint: PJSIP/phone_B
Status: 1


[Oct  8 13:16:52] DEBUG[18068] app_queue.c: Extension '1002@internal' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Oct  8 13:16:52] DEBUG[18209] manager.c: Examining event:
Event: ExtensionStatus
Privilege: call,all
SequenceNumber: 6
File: manager.c
Line: 6088
Func: manager_state_cb
Exten: phone_B
Context: internal
Hint: PJSIP/phone_B
Status: 1


[Oct  8 13:16:52] DEBUG[18068] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:16:52] DEBUG[18068] app_queue.c: Extension 'phone_B@internal' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Oct  8 13:16:52] DEBUG[18213] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x978606c'
[Oct  8 13:16:52] DEBUG[18213] rtp_engine.c: Setting payload 0 based on m type on 0xb5807fd8
[Oct  8 13:16:52] DEBUG[18213] rtp_engine.c: Setting payload 8 based on m type on 0xb5807fd8
[Oct  8 13:16:52] DEBUG[18213] rtp_engine.c: Setting payload 96 based on m type on 0xb5807fd8
[Oct  8 13:16:52] DEBUG[18213] rtp_engine.c: Copying payload 0 from 0xb5807fd8 to 0x9786194
[Oct  8 13:16:52] DEBUG[18213] rtp_engine.c: Copying payload 8 from 0xb5807fd8 to 0x9786194
[Oct  8 13:16:52] DEBUG[18213] rtp_engine.c: Copying payload 96 from 0xb5807fd8 to 0x9786194
[Oct  8 13:16:52] DEBUG[18213] res_pjsip_session.c: Method is INVITE, Response is 200 OK
[Oct  8 13:16:52] DEBUG[18213] res_pjsip_session.c: Source of transaction state change is TX_MSG
[Oct  8 13:16:52] DEBUG[18213] res_pjsip_session.c: Sending response
[Oct  8 13:16:52] DEBUG[18213] res_pjsip_session.c: Method is INVITE, Response is 200 OK
[Oct  8 13:16:52] DEBUG[18218][C-00000000] res_rtp_asterisk.c: 0x978a588 -- Probation learning mode pass with source address 10.24.18.165:4040
[Oct  8 13:16:52] DEBUG[18218][C-00000000] channel.c: Set channel PJSIP/phone_B-00000000 to write format gsm
[Oct  8 13:16:52] DEBUG[18218][C-00000000] res_rtp_asterisk.c: Ooh, format changed from unknown to ulaw
[Oct  8 13:16:52] DEBUG[18218][C-00000000] res_rtp_asterisk.c: Created smoother: format: ulaw ms: 20 len: 160
[Oct  8 13:16:52] DEBUG[18218][C-00000000] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second
[Oct  8 13:16:52] VERBOSE[18218][C-00000000] file.c:     -- <PJSIP/phone_B-00000000> Playing 'agent-loginok.gsm' (language 'en')
[Oct  8 13:16:52] DEBUG[18213] res_pjsip_session.c: Received request
[Oct  8 13:16:52] DEBUG[18213] res_pjsip_session.c: Method is ACK
[Oct  8 13:16:53] DEBUG[18073] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:16:54] DEBUG[18218][C-00000000] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[Oct  8 13:16:54] DEBUG[18218][C-00000000] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[Oct  8 13:16:54] DEBUG[18218][C-00000000] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[Oct  8 13:16:54] DEBUG[18218][C-00000000] channel.c: Set channel PJSIP/phone_B-00000000 to write format ulaw
[Oct  8 13:16:54] VERBOSE[18218][C-00000000] app_agent_pool.c:   == Agent '1002' logged in (format ulaw/ulaw)
[Oct  8 13:16:54] DEBUG[18071] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:16:54] DEBUG[18209] manager.c: Examining event:
Event: AgentLogin
Privilege: agent,all
SequenceNumber: 7
File: manager.c
Line: 1443
Func: manager_default_msg_cb
Channel: PJSIP/phone_B-00000000
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 1002
CallerIDName: Phone B
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
AccountCode: 
Context: internal
Exten: 552
Priority: 1
Uniqueid: 1381256212.0
Agent: 1002


[Oct  8 13:16:54] DEBUG[18218][C-00000000] bridge_channel.c: Bridge 4cd44abb-660a-41c1-9ff8-c394e72dbb7a: 0xb55676dc(PJSIP/phone_B-00000000) is joining
[Oct  8 13:16:54] DEBUG[18218][C-00000000] bridge_channel.c: Bridge 4cd44abb-660a-41c1-9ff8-c394e72dbb7a: pushing 0xb55676dc(PJSIP/phone_B-00000000)
[Oct  8 13:16:54] DEBUG[18218][C-00000000] bridge_roles.c: Set role 'holding_participant'
[Oct  8 13:16:54] DEBUG[18218][C-00000000] bridge.c: Putting interval hook 0x9590e9c with interval 1000 in the heap on features 0xb5792ae4
[Oct  8 13:16:54] DEBUG[18218][C-00000000] bridge_roles.c: Set role 'holding_participant'
[Oct  8 13:16:54] VERBOSE[18218][C-00000000] bridge_channel.c:     -- Channel PJSIP/phone_B-00000000 joined 'holding_bridge' agent_hold-bridge <4cd44abb-660a-41c1-9ff8-c394e72dbb7a>
[Oct  8 13:16:54] DEBUG[18071] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:16:54] DEBUG[18209] manager.c: Examining event:
Event: BridgeEnter
Privilege: call,all
SequenceNumber: 8
File: manager_bridges.c
Line: 279
Func: channel_enter_cb
BridgeUniqueid: 4cd44abb-660a-41c1-9ff8-c394e72dbb7a
BridgeType: agent_hold
BridgeTechnology: holding_bridge
BridgeNumChannels: 1
Channel: PJSIP/phone_B-00000000
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 1002
CallerIDName: Phone B
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
AccountCode: 
Context: internal
Exten: 552
Priority: 1
Uniqueid: 1381256212.0


[Oct  8 13:16:54] DEBUG[18218][C-00000000] bridge.c: Bridge 4cd44abb-660a-41c1-9ff8-c394e72dbb7a is happy that channel PJSIP/phone_B-00000000 already has read format ulaw
[Oct  8 13:16:54] DEBUG[18218][C-00000000] bridge.c: Bridge 4cd44abb-660a-41c1-9ff8-c394e72dbb7a is happy that channel PJSIP/phone_B-00000000 already has write format ulaw
[Oct  8 13:16:54] DEBUG[18218][C-00000000] bridge.c: Bridge 4cd44abb-660a-41c1-9ff8-c394e72dbb7a: 0xb55676dc(PJSIP/phone_B-00000000) is joining holding_bridge technology
[Oct  8 13:16:54] VERBOSE[18218][C-00000000] res_musiconhold.c:     -- Started music on hold, class 'default', on PJSIP/phone_B-00000000
[Oct  8 13:16:54] DEBUG[18218][C-00000000] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second
[Oct  8 13:16:54] DEBUG[18071] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:16:54] DEBUG[18209] manager.c: Examining event:
Event: MusicOnHoldStart
Privilege: call,all
SequenceNumber: 9
File: manager_channels.c
Line: 974
Func: channel_moh_start_cb
Channel: PJSIP/phone_B-00000000
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 1002
CallerIDName: Phone B
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
AccountCode: 
Context: internal
Exten: 552
Priority: 1
Uniqueid: 1381256212.0
Class: default


[Oct  8 13:16:54] DEBUG[18218][C-00000000] channel.c: Set channel PJSIP/phone_B-00000000 to write format slin
[Oct  8 13:16:54] DEBUG[18218][C-00000000] res_musiconhold.c: PJSIP/phone_B-00000000 Opened file 0 '/var/lib/asterisk/moh/manolo_camp-morning_coffee'
[Oct  8 13:16:55] DEBUG[18218][C-00000000] bridge_channel.c: Executing hook 0x9590e9c on 0xb55676dc(PJSIP/phone_B-00000000)
[Oct  8 13:16:55] DEBUG[18218][C-00000000] bridge_channel.c: Updating interval hook 0x9590e9c with interval 1000 on 0xb55676dc(PJSIP/phone_B-00000000)
[Oct  8 13:16:55] DEBUG[18218][C-00000000] bridge_channel.c: Hook 0x9590e9c on 0xb55676dc(PJSIP/phone_B-00000000) wants to happen in the future, stopping our traversal
[Oct  8 13:16:55] DEBUG[18218][C-00000000] bridge_channel.c: Executing hook 0x9590e9c on 0xb55676dc(PJSIP/phone_B-00000000)
[Oct  8 13:16:55] DEBUG[18218][C-00000000] bridge_channel.c: Updating interval hook 0x9590e9c with interval 1000 on 0xb55676dc(PJSIP/phone_B-00000000)
[Oct  8 13:16:55] DEBUG[18218][C-00000000] bridge_channel.c: Hook 0x9590e9c on 0xb55676dc(PJSIP/phone_B-00000000) wants to happen in the future, stopping our traversal
[Oct  8 13:16:56] DEBUG[18218][C-00000000] bridge_channel.c: Executing hook 0x9590e9c on 0xb55676dc(PJSIP/phone_B-00000000)
[Oct  8 13:16:56] DEBUG[18218][C-00000000] bridge_channel.c: Updating interval hook 0x9590e9c with interval 1000 on 0xb55676dc(PJSIP/phone_B-00000000)
[Oct  8 13:16:56] DEBUG[18218][C-00000000] bridge_channel.c: Hook 0x9590e9c on 0xb55676dc(PJSIP/phone_B-00000000) wants to happen in the future, stopping our traversal
[Oct  8 13:16:57] DEBUG[18218][C-00000000] res_rtp_asterisk.c: Got RTCP report of 64 bytes
[Oct  8 13:16:57] DEBUG[18071] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:16:57] DEBUG[18209] manager.c: Examining event:
Event: RTCPReceived
Privilege: reporting,all
SequenceNumber: 10
File: manager.c
Line: 1443
Func: manager_default_msg_cb
Channel: PJSIP/phone_B-00000000
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 1002
CallerIDName: Phone B
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
AccountCode: 
Context: internal
Exten: 552
Priority: 1
Uniqueid: 1381256212.0
From: 10.24.18.165:4041
RTT: 0.0000
SSRC: 0x1b8518f2
PT: 200(SR)
ReportCount: 1
SentNTP: 2086588356.529907712
SentRTP: 1456090575
SentPackets: 223
SentOctets: 35680
Report0SourceSSRC: 0x406d5ca1
Report0FractionLost: 0
Report0CumulativeLost: 0
Report0HighestSequence: 24510
Report0SequenceNumberCycles: 0
Report0IAJitter: 38
Report0LSR: 0
Report0DLSR: 0.0000


[Oct  8 13:16:57] DEBUG[18218][C-00000000] bridge_channel.c: Executing hook 0x9590e9c on 0xb55676dc(PJSIP/phone_B-00000000)
[Oct  8 13:16:57] DEBUG[18218][C-00000000] bridge_channel.c: Updating interval hook 0x9590e9c with interval 1000 on 0xb55676dc(PJSIP/phone_B-00000000)
[Oct  8 13:16:57] DEBUG[18218][C-00000000] bridge_channel.c: Hook 0x9590e9c on 0xb55676dc(PJSIP/phone_B-00000000) wants to happen in the future, stopping our traversal
[Oct  8 13:16:57] DEBUG[18071] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:16:57] DEBUG[18209] manager.c: Examining event:
Event: RTCPSent
Privilege: reporting,all
SequenceNumber: 11
File: manager.c
Line: 1443
Func: manager_default_msg_cb
Channel: PJSIP/phone_B-00000000
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 1002
CallerIDName: Phone B
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
AccountCode: 
Context: internal
Exten: 552
Priority: 1
Uniqueid: 1381256212.0
To: 10.24.18.165:4041
SSRC: 0x406d5ca1
PT: 200(SR)
ReportCount: 1
SentNTP: 1381256217.3030396928
SentRTP: 39840
SentPackets: 249
SentOctets: 39840
Report0SourceSSRC: 0x1b8518f2
Report0FractionLost: 0
Report0CumulativeLost: 0
Report0HighestSequence: 58628
Report0SequenceNumberCycles: 0
Report0IAJitter: 0
Report0LSR: 1313089126
Report0DLSR: 0.5500


[Oct  8 13:16:58] DEBUG[18073] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:16:58] DEBUG[18218][C-00000000] bridge_channel.c: Executing hook 0x9590e9c on 0xb55676dc(PJSIP/phone_B-00000000)
[Oct  8 13:16:58] DEBUG[18218][C-00000000] bridge_channel.c: Updating interval hook 0x9590e9c with interval 1000 on 0xb55676dc(PJSIP/phone_B-00000000)
[Oct  8 13:16:58] DEBUG[18218][C-00000000] bridge_channel.c: Hook 0x9590e9c on 0xb55676dc(PJSIP/phone_B-00000000) wants to happen in the future, stopping our traversal
[Oct  8 13:16:59] DEBUG[18218][C-00000000] bridge_channel.c: Executing hook 0x9590e9c on 0xb55676dc(PJSIP/phone_B-00000000)
[Oct  8 13:16:59] DEBUG[18218][C-00000000] app_agent_pool.c: Agent 1002: Login complete.
[Oct  8 13:16:59] DEBUG[18218][C-00000000] bridge_channel.c: Updating interval hook 0x9590e9c with interval 1000 on 0xb55676dc(PJSIP/phone_B-00000000)
[Oct  8 13:16:59] DEBUG[18218][C-00000000] bridge_channel.c: Hook 0x9590e9c on 0xb55676dc(PJSIP/phone_B-00000000) wants to happen in the future, stopping our traversal
[Oct  8 13:16:59] DEBUG[18067] devicestate.c: Checking if I can find provider for "Agent" - number: 1002
[Oct  8 13:16:59] DEBUG[18067] devicestate.c: Changing state for Agent:1002 - state 1 (Not in use)
[Oct  8 13:16:59] DEBUG[18062] devicestate.c: Processing device state change for 'Agent:1002'
[Oct  8 13:16:59] DEBUG[18062] devicestate.c: Adding per-server state of 'Not in use' for 'Agent:1002'
[Oct  8 13:16:59] DEBUG[18062] devicestate.c: Aggregate devstate result is 'Not in use' for 'Agent:1002'
[Oct  8 13:16:59] DEBUG[18062] devicestate.c: Aggregate state for device 'Agent:1002' has changed to 'Not in use'
[Oct  8 13:16:59] DEBUG[18068] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:16:59] DEBUG[18209] manager.c: Examining event:
Event: ExtensionStatus
Privilege: call,all
SequenceNumber: 12
File: manager.c
Line: 6088
Func: manager_state_cb
Exten: 666
Context: internal
Hint: Agent:1002
Status: 0


[Oct  8 13:16:59] DEBUG[18068] app_queue.c: Extension '666@internal' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Oct  8 13:16:59] DEBUG[18179] app_queue.c: Device 'Agent:1002' changed to state '1' (Not in use)
[Oct  8 13:16:59] DEBUG[18062] devicestate.c: Processing device state change for 'Queue:test_avail'
[Oct  8 13:16:59] DEBUG[18071] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:16:59] DEBUG[18062] devicestate.c: Adding per-server state of 'Not in use' for 'Queue:test_avail'
[Oct  8 13:16:59] DEBUG[18062] devicestate.c: Aggregate devstate result is 'Not in use' for 'Queue:test_avail'
[Oct  8 13:16:59] DEBUG[18062] devicestate.c: Aggregate state for device 'Queue:test_avail' has changed to 'Not in use'
[Oct  8 13:16:59] DEBUG[18179] app_queue.c: Device 'Queue:test_avail' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Oct  8 13:16:59] DEBUG[18209] manager.c: Examining event:
Event: QueueMemberStatus
Privilege: agent,all
SequenceNumber: 13
File: manager.c
Line: 1443
Func: manager_default_msg_cb
MemberName: Agent B
Interface: Agent/1002@internal
Membership: static
Queue: test
StateInterface: Agent:1002
Penalty: 0
CallsTaken: 0
LastCall: 0
Status: 1
Ringinuse: 0
Paused: 0


[Oct  8 13:17:00] DEBUG[18218][C-00000000] bridge_channel.c: Executing hook 0x9590e9c on 0xb55676dc(PJSIP/phone_B-00000000)
[Oct  8 13:17:00] DEBUG[18218][C-00000000] bridge_channel.c: Updating interval hook 0x9590e9c with interval 1000 on 0xb55676dc(PJSIP/phone_B-00000000)
[Oct  8 13:17:00] DEBUG[18218][C-00000000] bridge_channel.c: Hook 0x9590e9c on 0xb55676dc(PJSIP/phone_B-00000000) wants to happen in the future, stopping our traversal
[Oct  8 13:17:01] DEBUG[18218][C-00000000] bridge_channel.c: Executing hook 0x9590e9c on 0xb55676dc(PJSIP/phone_B-00000000)
[Oct  8 13:17:01] DEBUG[18218][C-00000000] bridge_channel.c: Updating interval hook 0x9590e9c with interval 1000 on 0xb55676dc(PJSIP/phone_B-00000000)
[Oct  8 13:17:01] DEBUG[18218][C-00000000] bridge_channel.c: Hook 0x9590e9c on 0xb55676dc(PJSIP/phone_B-00000000) wants to happen in the future, stopping our traversal
[Oct  8 13:17:01] DEBUG[18218][C-00000000] bridge_channel.c: Executing hook 0x9590e9c on 0xb55676dc(PJSIP/phone_B-00000000)
[Oct  8 13:17:01] DEBUG[18218][C-00000000] bridge_channel.c: Updating interval hook 0x9590e9c with interval 1000 on 0xb55676dc(PJSIP/phone_B-00000000)
[Oct  8 13:17:01] DEBUG[18218][C-00000000] bridge_channel.c: Hook 0x9590e9c on 0xb55676dc(PJSIP/phone_B-00000000) wants to happen in the future, stopping our traversal
[Oct  8 13:17:02] DEBUG[18218][C-00000000] res_rtp_asterisk.c: Got RTCP report of 64 bytes
[Oct  8 13:17:02] DEBUG[18071] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:02] DEBUG[18209] manager.c: Examining event:
Event: RTCPReceived
Privilege: reporting,all
SequenceNumber: 14
File: manager.c
Line: 1443
Func: manager_default_msg_cb
Channel: PJSIP/phone_B-00000000
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 1002
CallerIDName: Phone B
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
AccountCode: 
Context: internal
Exten: 552
Priority: 1
Uniqueid: 1381256212.0
From: 10.24.18.165:4041
RTT: 0.4912
SSRC: 0x1b8518f2
PT: 200(SR)
ReportCount: 1
SentNTP: 2086588361.529907712
SentRTP: 2523279055
SentPackets: 473
SentOctets: 75680
Report0SourceSSRC: 0x406d5ca1
Report0FractionLost: 0
Report0CumulativeLost: 0
Report0HighestSequence: 24759
Report0SequenceNumberCycles: 0
Report0IAJitter: 5
Report0LSR: 3399073126
Report0DLSR: 4.4400


[Oct  8 13:17:02] DEBUG[18218][C-00000000] bridge_channel.c: Executing hook 0x9590e9c on 0xb55676dc(PJSIP/phone_B-00000000)
[Oct  8 13:17:02] DEBUG[18218][C-00000000] bridge_channel.c: Updating interval hook 0x9590e9c with interval 1000 on 0xb55676dc(PJSIP/phone_B-00000000)
[Oct  8 13:17:02] DEBUG[18218][C-00000000] bridge_channel.c: Hook 0x9590e9c on 0xb55676dc(PJSIP/phone_B-00000000) wants to happen in the future, stopping our traversal
[Oct  8 13:17:02] DEBUG[18071] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:02] DEBUG[18209] manager.c: Examining event:
Event: RTCPSent
Privilege: reporting,all
SequenceNumber: 15
File: manager.c
Line: 1443
Func: manager_default_msg_cb
Channel: PJSIP/phone_B-00000000
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 1002
CallerIDName: Phone B
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
AccountCode: 
Context: internal
Exten: 552
Priority: 1
Uniqueid: 1381256212.0
To: 10.24.18.165:4041
SSRC: 0x406d5ca1
PT: 200(SR)
ReportCount: 1
SentNTP: 1381256222.3030855680
SentRTP: 79840
SentPackets: 499
SentOctets: 79840
Report0SourceSSRC: 0x1b8518f2
Report0FractionLost: 0
Report0CumulativeLost: 0
Report0HighestSequence: 58879
Report0SequenceNumberCycles: 0
Report0IAJitter: 1
Report0LSR: 1313416806
Report0DLSR: 0.5510


[Oct  8 13:17:03] DEBUG[18073] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:03] DEBUG[18218][C-00000000] bridge_channel.c: Executing hook 0x9590e9c on 0xb55676dc(PJSIP/phone_B-00000000)
[Oct  8 13:17:03] DEBUG[18218][C-00000000] bridge_channel.c: Updating interval hook 0x9590e9c with interval 1000 on 0xb55676dc(PJSIP/phone_B-00000000)
[Oct  8 13:17:03] DEBUG[18218][C-00000000] bridge_channel.c: Hook 0x9590e9c on 0xb55676dc(PJSIP/phone_B-00000000) wants to happen in the future, stopping our traversal
[Oct  8 13:17:04] DEBUG[18218][C-00000000] bridge_channel.c: Executing hook 0x9590e9c on 0xb55676dc(PJSIP/phone_B-00000000)
[Oct  8 13:17:04] DEBUG[18218][C-00000000] bridge_channel.c: Updating interval hook 0x9590e9c with interval 1000 on 0xb55676dc(PJSIP/phone_B-00000000)
[Oct  8 13:17:04] DEBUG[18218][C-00000000] bridge_channel.c: Hook 0x9590e9c on 0xb55676dc(PJSIP/phone_B-00000000) wants to happen in the future, stopping our traversal
[Oct  8 13:17:05] DEBUG[18218][C-00000000] bridge_channel.c: Executing hook 0x9590e9c on 0xb55676dc(PJSIP/phone_B-00000000)
[Oct  8 13:17:05] DEBUG[18218][C-00000000] bridge_channel.c: Updating interval hook 0x9590e9c with interval 1000 on 0xb55676dc(PJSIP/phone_B-00000000)
[Oct  8 13:17:05] DEBUG[18218][C-00000000] bridge_channel.c: Hook 0x9590e9c on 0xb55676dc(PJSIP/phone_B-00000000) wants to happen in the future, stopping our traversal
[Oct  8 13:17:06] DEBUG[18218][C-00000000] bridge_channel.c: Executing hook 0x9590e9c on 0xb55676dc(PJSIP/phone_B-00000000)
[Oct  8 13:17:06] DEBUG[18218][C-00000000] bridge_channel.c: Updating interval hook 0x9590e9c with interval 1000 on 0xb55676dc(PJSIP/phone_B-00000000)
[Oct  8 13:17:06] DEBUG[18218][C-00000000] bridge_channel.c: Hook 0x9590e9c on 0xb55676dc(PJSIP/phone_B-00000000) wants to happen in the future, stopping our traversal
[Oct  8 13:17:07] DEBUG[18218][C-00000000] bridge_channel.c: Executing hook 0x9590e9c on 0xb55676dc(PJSIP/phone_B-00000000)
[Oct  8 13:17:07] DEBUG[18218][C-00000000] bridge_channel.c: Updating interval hook 0x9590e9c with interval 1000 on 0xb55676dc(PJSIP/phone_B-00000000)
[Oct  8 13:17:07] DEBUG[18218][C-00000000] bridge_channel.c: Hook 0x9590e9c on 0xb55676dc(PJSIP/phone_B-00000000) wants to happen in the future, stopping our traversal
[Oct  8 13:17:07] DEBUG[18218][C-00000000] res_rtp_asterisk.c: Got RTCP report of 64 bytes
[Oct  8 13:17:07] DEBUG[18071] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:07] DEBUG[18209] manager.c: Examining event:
Event: RTCPReceived
Privilege: reporting,all
SequenceNumber: 16
File: manager.c
Line: 1443
Func: manager_default_msg_cb
Channel: PJSIP/phone_B-00000000
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 1002
CallerIDName: Phone B
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
AccountCode: 
Context: internal
Exten: 552
Priority: 1
Uniqueid: 1381256212.0
From: 10.24.18.165:4041
RTT: 0.4035
SSRC: 0x1b8518f2
PT: 200(SR)
ReportCount: 1
SentNTP: 2086588366.529907712
SentRTP: 3590467535
SentPackets: 723
SentOctets: 115680
Report0SourceSSRC: 0x406d5ca1
Report0FractionLost: 0
Report0CumulativeLost: 0
Report0HighestSequence: 25009
Report0SequenceNumberCycles: 0
Report0IAJitter: 0
Report0LSR: 3399400813
Report0DLSR: 4.4400


[Oct  8 13:17:07] DEBUG[18071] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:07] DEBUG[18209] manager.c: Examining event:
Event: RTCPSent
Privilege: reporting,all
SequenceNumber: 17
File: manager.c
Line: 1443
Func: manager_default_msg_cb
Channel: PJSIP/phone_B-00000000
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 1002
CallerIDName: Phone B
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
AccountCode: 
Context: internal
Exten: 552
Priority: 1
Uniqueid: 1381256212.0
To: 10.24.18.165:4041
SSRC: 0x406d5ca1
PT: 200(SR)
ReportCount: 1
SentNTP: 1381256227.3031326720
SentRTP: 119840
SentPackets: 749
SentOctets: 119840
Report0SourceSSRC: 0x1b8518f2
Report0FractionLost: 0
Report0CumulativeLost: 0
Report0HighestSequence: 59129
Report0SequenceNumberCycles: 0
Report0IAJitter: 1
Report0LSR: 1313744486
Report0DLSR: 0.5530


[Oct  8 13:17:07] DEBUG[18218][C-00000000] bridge_channel.c: Executing hook 0x9590e9c on 0xb55676dc(PJSIP/phone_B-00000000)
[Oct  8 13:17:07] DEBUG[18218][C-00000000] bridge_channel.c: Updating interval hook 0x9590e9c with interval 1000 on 0xb55676dc(PJSIP/phone_B-00000000)
[Oct  8 13:17:07] DEBUG[18218][C-00000000] bridge_channel.c: Hook 0x9590e9c on 0xb55676dc(PJSIP/phone_B-00000000) wants to happen in the future, stopping our traversal
[Oct  8 13:17:08] DEBUG[18073] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:08] DEBUG[18218][C-00000000] bridge_channel.c: Executing hook 0x9590e9c on 0xb55676dc(PJSIP/phone_B-00000000)
[Oct  8 13:17:08] DEBUG[18218][C-00000000] bridge_channel.c: Updating interval hook 0x9590e9c with interval 1000 on 0xb55676dc(PJSIP/phone_B-00000000)
[Oct  8 13:17:08] DEBUG[18218][C-00000000] bridge_channel.c: Hook 0x9590e9c on 0xb55676dc(PJSIP/phone_B-00000000) wants to happen in the future, stopping our traversal
[Oct  8 13:17:09] DEBUG[18218][C-00000000] bridge_channel.c: Executing hook 0x9590e9c on 0xb55676dc(PJSIP/phone_B-00000000)
[Oct  8 13:17:09] DEBUG[18218][C-00000000] bridge_channel.c: Updating interval hook 0x9590e9c with interval 1000 on 0xb55676dc(PJSIP/phone_B-00000000)
[Oct  8 13:17:09] DEBUG[18218][C-00000000] bridge_channel.c: Hook 0x9590e9c on 0xb55676dc(PJSIP/phone_B-00000000) wants to happen in the future, stopping our traversal
[Oct  8 13:17:09] DEBUG[18209] manager.c: Running action 'AgentLogoff'
[Oct  8 13:17:09] DEBUG[18218][C-00000000] bridge_channel.c: Executing hook 0x9590e9c on 0xb55676dc(PJSIP/phone_B-00000000)
[Oct  8 13:17:09] DEBUG[18218][C-00000000] app_agent_pool.c: Agent 1002: Deferred logoff.
[Oct  8 13:17:09] DEBUG[18218][C-00000000] bridge_channel.c: Setting 0xb55676dc(PJSIP/phone_B-00000000) state from:0 to:1
[Oct  8 13:17:09] DEBUG[18218][C-00000000] bridge_channel.c: Updating interval hook 0x9590e9c with interval 1000 on 0xb55676dc(PJSIP/phone_B-00000000)
[Oct  8 13:17:09] DEBUG[18218][C-00000000] bridge_channel.c: Hook 0x9590e9c on 0xb55676dc(PJSIP/phone_B-00000000) wants to happen in the future, stopping our traversal
[Oct  8 13:17:09] DEBUG[18218][C-00000000] bridge_channel.c: Bridge 4cd44abb-660a-41c1-9ff8-c394e72dbb7a: pulling 0xb55676dc(PJSIP/phone_B-00000000)
[Oct  8 13:17:09] VERBOSE[18218][C-00000000] bridge_channel.c:     -- Channel PJSIP/phone_B-00000000 left 'holding_bridge' agent_hold-bridge <4cd44abb-660a-41c1-9ff8-c394e72dbb7a>
[Oct  8 13:17:09] DEBUG[18218][C-00000000] bridge_channel.c: Bridge 4cd44abb-660a-41c1-9ff8-c394e72dbb7a: 0xb55676dc(PJSIP/phone_B-00000000) is leaving holding_bridge technology
[Oct  8 13:17:09] VERBOSE[18218][C-00000000] res_musiconhold.c:     -- Stopped music on hold on PJSIP/phone_B-00000000
[Oct  8 13:17:09] DEBUG[18218][C-00000000] channel.c: Set channel PJSIP/phone_B-00000000 to write format ulaw
[Oct  8 13:17:09] DEBUG[18218][C-00000000] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[Oct  8 13:17:09] DEBUG[18218][C-00000000] bridge_roles.c: Removing bridge role holding_participant from channel PJSIP/phone_B-00000000
[Oct  8 13:17:09] DEBUG[18071] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:09] DEBUG[18209] manager.c: Examining event:
Event: MusicOnHoldStop
Privilege: call,all
SequenceNumber: 18
File: manager_channels.c
Line: 665
Func: publish_basic_channel_event
Channel: PJSIP/phone_B-00000000
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 1002
CallerIDName: Phone B
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
AccountCode: 
Context: internal
Exten: 552
Priority: 1
Uniqueid: 1381256212.0


[Oct  8 13:17:09] DEBUG[18071] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:09] DEBUG[18209] manager.c: Examining event:
Event: BridgeLeave
Privilege: call,all
SequenceNumber: 19
File: manager_bridges.c
Line: 299
Func: channel_leave_cb
BridgeUniqueid: 4cd44abb-660a-41c1-9ff8-c394e72dbb7a
BridgeType: agent_hold
BridgeTechnology: holding_bridge
BridgeNumChannels: 0
Channel: PJSIP/phone_B-00000000
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 1002
CallerIDName: Phone B
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
AccountCode: 
Context: internal
Exten: 552
Priority: 1
Uniqueid: 1381256212.0


[Oct  8 13:17:09] DEBUG[18067] devicestate.c: Checking if I can find provider for "Agent" - number: 1002
[Oct  8 13:17:09] DEBUG[18067] devicestate.c: Changing state for Agent:1002 - state 5 (Unavailable)
[Oct  8 13:17:09] DEBUG[18071] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:09] DEBUG[18209] manager.c: Examining event:
Event: AgentLogoff
Privilege: agent,all
SequenceNumber: 20
File: manager.c
Line: 1443
Func: manager_default_msg_cb
Channel: PJSIP/phone_B-00000000
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 1002
CallerIDName: Phone B
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
AccountCode: 
Context: internal
Exten: 552
Priority: 1
Uniqueid: 1381256212.0
Agent: 1002
Logintime: 17


[Oct  8 13:17:09] DEBUG[18062] devicestate.c: Processing device state change for 'Agent:1002'
[Oct  8 13:17:09] DEBUG[18062] devicestate.c: Adding per-server state of 'Unavailable' for 'Agent:1002'
[Oct  8 13:17:09] DEBUG[18062] devicestate.c: Aggregate devstate result is 'Unavailable' for 'Agent:1002'
[Oct  8 13:17:09] DEBUG[18062] devicestate.c: Aggregate state for device 'Agent:1002' has changed to 'Unavailable'
[Oct  8 13:17:09] VERBOSE[18218][C-00000000] app_agent_pool.c:   == Agent '1002' logged out.  Logged in for 17 seconds.
[Oct  8 13:17:09] DEBUG[18068] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:09] DEBUG[18218][C-00000000] pbx.c: Spawn extension (internal,552,1) exited non-zero on 'PJSIP/phone_B-00000000'
[Oct  8 13:17:09] DEBUG[18068] app_queue.c: Extension '666@internal' changed to state '5' (Unavailable) but we don't care because they're not a member of any queue.
[Oct  8 13:17:09] VERBOSE[18218][C-00000000] pbx.c:   == Spawn extension (internal, 552, 1) exited non-zero on 'PJSIP/phone_B-00000000'
[Oct  8 13:17:09] DEBUG[18218][C-00000000] channel.c: Soft-Hanging up channel 'PJSIP/phone_B-00000000'
[Oct  8 13:17:09] DEBUG[18179] app_queue.c: Device 'Agent:1002' changed to state '5' (Unavailable)
[Oct  8 13:17:09] DEBUG[18071] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:09] DEBUG[18209] manager.c: Examining event:
Event: ExtensionStatus
Privilege: call,all
SequenceNumber: 21
File: manager.c
Line: 6088
Func: manager_state_cb
Exten: 666
Context: internal
Hint: Agent:1002
Status: 4


[Oct  8 13:17:09] DEBUG[18062] devicestate.c: Processing device state change for 'Queue:test_avail'
[Oct  8 13:17:09] DEBUG[18062] devicestate.c: Adding per-server state of 'In use' for 'Queue:test_avail'
[Oct  8 13:17:09] DEBUG[18209] manager.c: Examining event:
Event: QueueMemberStatus
Privilege: agent,all
SequenceNumber: 22
File: manager.c
Line: 1443
Func: manager_default_msg_cb
MemberName: Agent B
Interface: Agent/1002@internal
Membership: static
Queue: test
StateInterface: Agent:1002
Penalty: 0
CallsTaken: 0
LastCall: 0
Status: 5
Ringinuse: 0
Paused: 0


[Oct  8 13:17:09] DEBUG[18062] devicestate.c: Aggregate devstate result is 'In use' for 'Queue:test_avail'
[Oct  8 13:17:09] DEBUG[18062] devicestate.c: Aggregate state for device 'Queue:test_avail' has changed to 'In use'
[Oct  8 13:17:09] DEBUG[18071] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:09] DEBUG[18209] manager.c: Examining event:
Event: SoftHangupRequest
Privilege: call,all
SequenceNumber: 23
File: manager_channels.c
Line: 705
Func: channel_hangup_request_cb
Channel: PJSIP/phone_B-00000000
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 1002
CallerIDName: Phone B
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
AccountCode: 
Context: internal
Exten: 552
Priority: 1
Uniqueid: 1381256212.0
Cause: 16


[Oct  8 13:17:09] DEBUG[18179] app_queue.c: Device 'Queue:test_avail' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Oct  8 13:17:09] DEBUG[18218][C-00000000] channel.c: Soft-Hanging up channel 'PJSIP/phone_B-00000000'
[Oct  8 13:17:09] DEBUG[18218][C-00000000] pbx.c: Launching 'NoOp'
[Oct  8 13:17:09] VERBOSE[18218][C-00000000] pbx.c:     -- Executing [h@internal:1] NoOp("PJSIP/phone_B-00000000", "=== Hang up handler ===") in new stack
[Oct  8 13:17:09] DEBUG[18071] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:09] DEBUG[18209] manager.c: Examining event:
Event: Newexten
Privilege: call,all
SequenceNumber: 24
File: manager_channels.c
Line: 602
Func: channel_snapshot_update
Channel: PJSIP/phone_B-00000000
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 1002
CallerIDName: Phone B
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
AccountCode: 
Context: internal
Exten: h
Priority: 1
Uniqueid: 1381256212.0
Extension: h
Application: NoOp
AppData: === Hang up handler ===


[Oct  8 13:17:09] DEBUG[18218][C-00000000] channel.c: Hanging up channel 'PJSIP/phone_B-00000000'
[Oct  8 13:17:09] DEBUG[18218][C-00000000] chan_pjsip.c: AST hangup cause 16 (no match found in PJSIP)
[Oct  8 13:17:09] DEBUG[18213] res_pjsip_session.c: Method is BYE
[Oct  8 13:17:09] DEBUG[18071] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:09] DEBUG[18066] cdr.c: Finalized CDR for PJSIP/phone_B-00000000 - start 1381256212.463802 answer 1381256212.464435 end 1381256229.875670 dispo ANSWERED
[Oct  8 13:17:09] DEBUG[18067] devicestate.c: Changing state for PJSIP/phone_B - state 1 (Not in use)
[Oct  8 13:17:09] DEBUG[18066] cdr_radius.c: Unable to create RADIUS record. CDR not recorded!
[Oct  8 13:17:09] DEBUG[18209] manager.c: Examining event:
Event: Hangup
Privilege: call,all
SequenceNumber: 25
File: manager_channels.c
Line: 602
Func: channel_snapshot_update
Channel: PJSIP/phone_B-00000000
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 1002
CallerIDName: Phone B
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
AccountCode: 
Context: internal
Exten: h
Priority: 2
Uniqueid: 1381256212.0
Cause: 16
Cause-txt: Normal Clearing


[Oct  8 13:17:09] DEBUG[18062] devicestate.c: Processing device state change for 'PJSIP/phone_B'
[Oct  8 13:17:09] DEBUG[18062] devicestate.c: Adding per-server state of 'Not in use' for 'PJSIP/phone_B'
[Oct  8 13:17:09] DEBUG[18062] devicestate.c: Aggregate devstate result is 'Not in use' for 'PJSIP/phone_B'
[Oct  8 13:17:09] DEBUG[18062] devicestate.c: Aggregate state for device 'PJSIP/phone_B' has changed to 'Not in use'
[Oct  8 13:17:09] DEBUG[18179] app_queue.c: Device 'PJSIP/phone_B' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Oct  8 13:17:09] DEBUG[18068] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:09] DEBUG[18068] app_queue.c: Extension '1002@internal' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Oct  8 13:17:09] DEBUG[18068] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:09] DEBUG[18068] app_queue.c: Extension 'phone_B@internal' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Oct  8 13:17:09] DEBUG[18066] res_config_sqlite.c: About to query table structure: SELECT sql FROM sqlite_master WHERE type='table' AND tbl_name='ast_cdr'
[Oct  8 13:17:09] DEBUG[18209] manager.c: Examining event:
Event: ExtensionStatus
Privilege: call,all
SequenceNumber: 26
File: manager.c
Line: 6088
Func: manager_state_cb
Exten: 1002
Context: internal
Hint: PJSIP/phone_B
Status: 0


[Oct  8 13:17:09] DEBUG[18209] manager.c: Examining event:
Event: ExtensionStatus
Privilege: call,all
SequenceNumber: 27
File: manager.c
Line: 6088
Func: manager_state_cb
Exten: phone_B
Context: internal
Hint: PJSIP/phone_B
Status: 0


[Oct  8 13:17:09] DEBUG[18066] res_config_sqlite.c: SQL query: INSERT INTO ast_cdr (clid,src,dst,dcontext,channel,lastapp,lastdata,start,answer,end,duration,billsec,disposition,amaflags,uniqueid) VALUES ('"Phone B" <1002>','1002','h','internal','PJSIP/phone_B-00000000','NoOp','=== Hang up handler ===','2013-10-08 13:16:52','2013-10-08 13:16:52','2013-10-08 13:17:09','17','17','ANSWERED','DOCUMENTATION','1381256212.0')
[Oct  8 13:17:09] DEBUG[18213] res_pjsip_session.c: Source of transaction state change is RX_MSG
[Oct  8 13:17:09] DEBUG[18213] res_pjsip_session.c: Received response
[Oct  8 13:17:09] DEBUG[18213] res_pjsip_session.c: Response is 200 OK
[Oct  8 13:17:09] DEBUG[18213] res_pjsip_session.c: Destroying SIP session with endpoint phone_B
[Oct  8 13:17:09] DEBUG[18213] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x978606c'
[Oct  8 13:17:09] DEBUG[18213] rtp_engine.c: Destroyed RTP instance '0x978606c'
[Oct  8 13:17:09] DEBUG[18213] taskprocessor.c: destroying taskprocessor '2826ab50-bc87-4f82-8b28-18fd7a9c3a37'
[Oct  8 13:17:13] DEBUG[18073] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:18] DEBUG[18073] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:23] DEBUG[18073] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:28] DEBUG[18213] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint phone_B
[Oct  8 13:17:28] DEBUG[18213] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint phone_B
[Oct  8 13:17:28] DEBUG[18213] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint phone_B
[Oct  8 13:17:28] DEBUG[18213] res_pjsip_authenticator_digest.c: Calculated nonce 1381256248/4b57ef509ea5b85c0a17ff4bb7530e08. Actual nonce is 1381256248/4b57ef509ea5b85c0a17ff4bb7530e08
[Oct  8 13:17:28] DEBUG[18213] rtp_engine.c: Using engine 'asterisk' for RTP instance '0xb2a4d234'
[Oct  8 13:17:28] DEBUG[18213] res_rtp_asterisk.c: Allocated port 10040 for RTP instance '0xb2a4d234'
[Oct  8 13:17:28] DEBUG[18213] rtp_engine.c: RTP instance '0xb2a4d234' is setup and ready to go
[Oct  8 13:17:28] DEBUG[18213] res_rtp_asterisk.c: Setup RTCP on RTP instance '0xb2a4d234'
[Oct  8 13:17:28] DEBUG[18213] rtp_engine.c: Setting payload 0 based on m type on 0xb5808548
[Oct  8 13:17:28] DEBUG[18213] rtp_engine.c: Setting payload 8 based on m type on 0xb5808548
[Oct  8 13:17:28] DEBUG[18213] rtp_engine.c: Setting payload 9 based on m type on 0xb5808548
[Oct  8 13:17:28] DEBUG[18213] rtp_engine.c: Setting payload 111 based on m type on 0xb5808548
[Oct  8 13:17:28] DEBUG[18213] rtp_engine.c: Setting payload 18 based on m type on 0xb5808548
[Oct  8 13:17:28] DEBUG[18213] rtp_engine.c: Setting payload 58 based on m type on 0xb5808548
[Oct  8 13:17:28] DEBUG[18213] rtp_engine.c: Setting payload 118 based on m type on 0xb5808548
[Oct  8 13:17:28] DEBUG[18213] rtp_engine.c: Setting payload 58 based on m type on 0xb5808548
[Oct  8 13:17:28] DEBUG[18213] rtp_engine.c: Setting payload 96 based on m type on 0xb5808548
[Oct  8 13:17:28] DEBUG[18213] rtp_engine.c: Copying payload 0 from 0xb5808548 to 0xb2a4d35c
[Oct  8 13:17:28] DEBUG[18213] rtp_engine.c: Copying payload 8 from 0xb5808548 to 0xb2a4d35c
[Oct  8 13:17:28] DEBUG[18213] rtp_engine.c: Copying payload 9 from 0xb5808548 to 0xb2a4d35c
[Oct  8 13:17:28] DEBUG[18213] rtp_engine.c: Copying payload 18 from 0xb5808548 to 0xb2a4d35c
[Oct  8 13:17:28] DEBUG[18213] rtp_engine.c: Copying payload 58 from 0xb5808548 to 0xb2a4d35c
[Oct  8 13:17:28] DEBUG[18213] rtp_engine.c: Copying payload 96 from 0xb5808548 to 0xb2a4d35c
[Oct  8 13:17:28] DEBUG[18213] rtp_engine.c: Copying payload 111 from 0xb5808548 to 0xb2a4d35c
[Oct  8 13:17:28] DEBUG[18213] rtp_engine.c: Copying payload 118 from 0xb5808548 to 0xb2a4d35c
[Oct  8 13:17:28] DEBUG[18213] res_pjsip_session.c: Method is INVITE, Response is 100 Trying
[Oct  8 13:17:28] DEBUG[18213] res_pjsip_session.c: Source of transaction state change is TX_MSG
[Oct  8 13:17:28] DEBUG[18213] res_pjsip_session.c: Sending response
[Oct  8 13:17:28] DEBUG[18213] res_pjsip_session.c: Method is INVITE, Response is 100 Trying
[Oct  8 13:17:28] DEBUG[18213] res_pjsip_session.c: Method is INVITE
[Oct  8 13:17:28] DEBUG[18071] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:28] DEBUG[18209] manager.c: Examining event:
Event: Newchannel
Privilege: call,all
SequenceNumber: 28
File: manager_channels.c
Line: 602
Func: channel_snapshot_update
Channel: PJSIP/phone_B-00000001
ChannelState: 4
ChannelStateDesc: Ring
CallerIDNum: 1002
CallerIDName: Phone B
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
AccountCode: 
Context: default
Exten: s
Priority: 1
Uniqueid: 1381256248.2


[Oct  8 13:17:28] DEBUG[18213] chan_pjsip.c: Started PBX on new PJSIP channel PJSIP/phone_B-00000001
[Oct  8 13:17:28] DEBUG[18225] logger.c: CALL_ID [C-00000001] created by thread.
[Oct  8 13:17:28] DEBUG[18070] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:28] DEBUG[18209] manager.c: Examining event:
Event: TestEvent
Privilege: test,all
SequenceNumber: 29
File: manager.c
Line: 7677
Func: test_suite_event_cb
Type: StateChange
State: CallIDChange
AppFile: channel_internal_api.c
AppFunction: ast_channel_callid_set
AppLine: 925
State: CallIDChange
Channel: PJSIP/phone_B-00000001
CallID: [C-00000001]
PriorCallID: 


[Oct  8 13:17:28] DEBUG[18225][C-00000001] logger.c: CALL_ID [C-00000001] bound to thread.
[Oct  8 13:17:28] DEBUG[18225][C-00000001] pbx.c: Launching 'AgentLogin'
[Oct  8 13:17:28] VERBOSE[18225][C-00000001] pbx.c:     -- Executing [552@internal:1] AgentLogin("PJSIP/phone_B-00000001", "1002") in new stack
[Oct  8 13:17:28] DEBUG[18071] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:28] DEBUG[18209] manager.c: Examining event:
Event: Newexten
Privilege: call,all
SequenceNumber: 30
File: manager_channels.c
Line: 602
Func: channel_snapshot_update
Channel: PJSIP/phone_B-00000001
ChannelState: 4
ChannelStateDesc: Ring
CallerIDNum: 1002
CallerIDName: Phone B
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
AccountCode: 
Context: internal
Exten: 552
Priority: 1
Uniqueid: 1381256248.2
Extension: 552
Application: AgentLogin
AppData: 1002


[Oct  8 13:17:28] DEBUG[18071] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:28] DEBUG[18209] manager.c: Examining event:
Event: Newstate
Privilege: call,all
SequenceNumber: 31
File: manager_channels.c
Line: 602
Func: channel_snapshot_update
Channel: PJSIP/phone_B-00000001
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 1002
CallerIDName: Phone B
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
AccountCode: 
Context: internal
Exten: 552
Priority: 1
Uniqueid: 1381256248.2


[Oct  8 13:17:28] DEBUG[18067] devicestate.c: Changing state for PJSIP/phone_B - state 2 (In use)
[Oct  8 13:17:28] DEBUG[18062] devicestate.c: Processing device state change for 'PJSIP/phone_B'
[Oct  8 13:17:28] DEBUG[18062] devicestate.c: Adding per-server state of 'In use' for 'PJSIP/phone_B'
[Oct  8 13:17:28] DEBUG[18062] devicestate.c: Aggregate devstate result is 'In use' for 'PJSIP/phone_B'
[Oct  8 13:17:28] DEBUG[18062] devicestate.c: Aggregate state for device 'PJSIP/phone_B' has changed to 'In use'
[Oct  8 13:17:28] DEBUG[18213] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xb2a4d234'
[Oct  8 13:17:28] DEBUG[18213] rtp_engine.c: Setting payload 0 based on m type on 0xb5807fd8
[Oct  8 13:17:28] DEBUG[18068] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:28] DEBUG[18213] rtp_engine.c: Setting payload 8 based on m type on 0xb5807fd8
[Oct  8 13:17:28] DEBUG[18213] rtp_engine.c: Setting payload 96 based on m type on 0xb5807fd8
[Oct  8 13:17:28] DEBUG[18068] app_queue.c: Extension '1002@internal' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Oct  8 13:17:28] DEBUG[18213] rtp_engine.c: Copying payload 0 from 0xb5807fd8 to 0xb2a4d35c
[Oct  8 13:17:28] DEBUG[18068] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:28] DEBUG[18213] rtp_engine.c: Copying payload 8 from 0xb5807fd8 to 0xb2a4d35c
[Oct  8 13:17:28] DEBUG[18068] app_queue.c: Extension 'phone_B@internal' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Oct  8 13:17:28] DEBUG[18213] rtp_engine.c: Copying payload 96 from 0xb5807fd8 to 0xb2a4d35c
[Oct  8 13:17:28] DEBUG[18179] app_queue.c: Device 'PJSIP/phone_B' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Oct  8 13:17:28] DEBUG[18213] res_pjsip_session.c: Method is INVITE, Response is 200 OK
[Oct  8 13:17:28] DEBUG[18213] res_pjsip_session.c: Source of transaction state change is TX_MSG
[Oct  8 13:17:28] DEBUG[18213] res_pjsip_session.c: Sending response
[Oct  8 13:17:28] DEBUG[18213] res_pjsip_session.c: Method is INVITE, Response is 200 OK
[Oct  8 13:17:28] DEBUG[18209] manager.c: Examining event:
Event: ExtensionStatus
Privilege: call,all
SequenceNumber: 32
File: manager.c
Line: 6088
Func: manager_state_cb
Exten: 1002
Context: internal
Hint: PJSIP/phone_B
Status: 1


[Oct  8 13:17:28] DEBUG[18209] manager.c: Examining event:
Event: ExtensionStatus
Privilege: call,all
SequenceNumber: 33
File: manager.c
Line: 6088
Func: manager_state_cb
Exten: phone_B
Context: internal
Hint: PJSIP/phone_B
Status: 1


[Oct  8 13:17:28] DEBUG[18073] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:28] DEBUG[18225][C-00000001] res_rtp_asterisk.c: 0xb2a51750 -- Probation learning mode pass with source address 10.24.18.165:4042
[Oct  8 13:17:28] DEBUG[18225][C-00000001] channel.c: Set channel PJSIP/phone_B-00000001 to write format gsm
[Oct  8 13:17:28] DEBUG[18225][C-00000001] res_rtp_asterisk.c: Ooh, format changed from unknown to ulaw
[Oct  8 13:17:28] DEBUG[18225][C-00000001] res_rtp_asterisk.c: Created smoother: format: ulaw ms: 20 len: 160
[Oct  8 13:17:28] DEBUG[18225][C-00000001] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second
[Oct  8 13:17:28] VERBOSE[18225][C-00000001] file.c:     -- <PJSIP/phone_B-00000001> Playing 'agent-loginok.gsm' (language 'en')
[Oct  8 13:17:28] DEBUG[18213] res_pjsip_session.c: Received request
[Oct  8 13:17:28] DEBUG[18213] res_pjsip_session.c: Method is ACK
[Oct  8 13:17:29] DEBUG[18225][C-00000001] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[Oct  8 13:17:29] DEBUG[18225][C-00000001] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[Oct  8 13:17:29] DEBUG[18225][C-00000001] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[Oct  8 13:17:29] DEBUG[18225][C-00000001] channel.c: Set channel PJSIP/phone_B-00000001 to write format ulaw
[Oct  8 13:17:29] VERBOSE[18225][C-00000001] app_agent_pool.c:   == Agent '1002' logged in (format ulaw/ulaw)
[Oct  8 13:17:29] DEBUG[18071] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:29] DEBUG[18209] manager.c: Examining event:
Event: AgentLogin
Privilege: agent,all
SequenceNumber: 34
File: manager.c
Line: 1443
Func: manager_default_msg_cb
Channel: PJSIP/phone_B-00000001
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 1002
CallerIDName: Phone B
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
AccountCode: 
Context: internal
Exten: 552
Priority: 1
Uniqueid: 1381256248.2
Agent: 1002


[Oct  8 13:17:29] DEBUG[18225][C-00000001] bridge_channel.c: Bridge 4cd44abb-660a-41c1-9ff8-c394e72dbb7a: 0xb28b227c(PJSIP/phone_B-00000001) is joining
[Oct  8 13:17:29] DEBUG[18225][C-00000001] bridge_channel.c: Bridge 4cd44abb-660a-41c1-9ff8-c394e72dbb7a: pushing 0xb28b227c(PJSIP/phone_B-00000001)
[Oct  8 13:17:29] DEBUG[18225][C-00000001] bridge_roles.c: Set role 'holding_participant'
[Oct  8 13:17:29] DEBUG[18225][C-00000001] bridge.c: Putting interval hook 0xb2a56c94 with interval 1000 in the heap on features 0xb24b7ae4
[Oct  8 13:17:29] DEBUG[18225][C-00000001] bridge_roles.c: Set role 'holding_participant'
[Oct  8 13:17:29] VERBOSE[18225][C-00000001] bridge_channel.c:     -- Channel PJSIP/phone_B-00000001 joined 'holding_bridge' agent_hold-bridge <4cd44abb-660a-41c1-9ff8-c394e72dbb7a>
[Oct  8 13:17:29] DEBUG[18225][C-00000001] bridge.c: Bridge 4cd44abb-660a-41c1-9ff8-c394e72dbb7a is happy that channel PJSIP/phone_B-00000001 already has read format ulaw
[Oct  8 13:17:29] DEBUG[18225][C-00000001] bridge.c: Bridge 4cd44abb-660a-41c1-9ff8-c394e72dbb7a is happy that channel PJSIP/phone_B-00000001 already has write format ulaw
[Oct  8 13:17:29] DEBUG[18225][C-00000001] bridge.c: Bridge 4cd44abb-660a-41c1-9ff8-c394e72dbb7a: 0xb28b227c(PJSIP/phone_B-00000001) is joining holding_bridge technology
[Oct  8 13:17:29] DEBUG[18071] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:29] DEBUG[18209] manager.c: Examining event:
Event: BridgeEnter
Privilege: call,all
SequenceNumber: 35
File: manager_bridges.c
Line: 279
Func: channel_enter_cb
BridgeUniqueid: 4cd44abb-660a-41c1-9ff8-c394e72dbb7a
BridgeType: agent_hold
BridgeTechnology: holding_bridge
BridgeNumChannels: 1
Channel: PJSIP/phone_B-00000001
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 1002
CallerIDName: Phone B
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
AccountCode: 
Context: internal
Exten: 552
Priority: 1
Uniqueid: 1381256248.2


[Oct  8 13:17:29] VERBOSE[18225][C-00000001] res_musiconhold.c:     -- Started music on hold, class 'default', on PJSIP/phone_B-00000001
[Oct  8 13:17:29] DEBUG[18225][C-00000001] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second
[Oct  8 13:17:29] DEBUG[18071] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:29] DEBUG[18209] manager.c: Examining event:
Event: MusicOnHoldStart
Privilege: call,all
SequenceNumber: 36
File: manager_channels.c
Line: 974
Func: channel_moh_start_cb
Channel: PJSIP/phone_B-00000001
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 1002
CallerIDName: Phone B
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
AccountCode: 
Context: internal
Exten: 552
Priority: 1
Uniqueid: 1381256248.2
Class: default


[Oct  8 13:17:29] DEBUG[18225][C-00000001] channel.c: Set channel PJSIP/phone_B-00000001 to write format slin
[Oct  8 13:17:29] DEBUG[18225][C-00000001] res_musiconhold.c: PJSIP/phone_B-00000001 Opened file 0 '/var/lib/asterisk/moh/manolo_camp-morning_coffee'
[Oct  8 13:17:30] DEBUG[18225][C-00000001] res_rtp_asterisk.c: Got RTCP report of 64 bytes
[Oct  8 13:17:30] DEBUG[18071] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:30] DEBUG[18209] manager.c: Examining event:
Event: RTCPReceived
Privilege: reporting,all
SequenceNumber: 37
File: manager.c
Line: 1443
Func: manager_default_msg_cb
Channel: PJSIP/phone_B-00000001
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 1002
CallerIDName: Phone B
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
AccountCode: 
Context: internal
Exten: 552
Priority: 1
Uniqueid: 1381256248.2
From: 10.24.18.165:4043
RTT: 0.0000
SSRC: 0xebf60cfa
PT: 200(SR)
ReportCount: 1
SentNTP: 2086588389.1180708864
SentRTP: 1912887270
SentPackets: 111
SentOctets: 17760
Report0SourceSSRC: 0x09940dc3
Report0FractionLost: 0
Report0CumulativeLost: 0
Report0HighestSequence: 24259
Report0SequenceNumberCycles: 0
Report0IAJitter: 24331
Report0LSR: 0
Report0DLSR: 0.0000


[Oct  8 13:17:30] DEBUG[18225][C-00000001] bridge_channel.c: Executing hook 0xb2a56c94 on 0xb28b227c(PJSIP/phone_B-00000001)
[Oct  8 13:17:30] DEBUG[18225][C-00000001] app_agent_pool.c: Agent 1002: Deferred logoff.
[Oct  8 13:17:30] DEBUG[18225][C-00000001] bridge_channel.c: Setting 0xb28b227c(PJSIP/phone_B-00000001) state from:0 to:1
[Oct  8 13:17:30] DEBUG[18225][C-00000001] bridge_channel.c: Updating interval hook 0xb2a56c94 with interval 1000 on 0xb28b227c(PJSIP/phone_B-00000001)
[Oct  8 13:17:30] DEBUG[18225][C-00000001] bridge_channel.c: Hook 0xb2a56c94 on 0xb28b227c(PJSIP/phone_B-00000001) wants to happen in the future, stopping our traversal
[Oct  8 13:17:30] DEBUG[18225][C-00000001] bridge_channel.c: Bridge 4cd44abb-660a-41c1-9ff8-c394e72dbb7a: pulling 0xb28b227c(PJSIP/phone_B-00000001)
[Oct  8 13:17:30] VERBOSE[18225][C-00000001] bridge_channel.c:     -- Channel PJSIP/phone_B-00000001 left 'holding_bridge' agent_hold-bridge <4cd44abb-660a-41c1-9ff8-c394e72dbb7a>
[Oct  8 13:17:30] DEBUG[18225][C-00000001] bridge_channel.c: Bridge 4cd44abb-660a-41c1-9ff8-c394e72dbb7a: 0xb28b227c(PJSIP/phone_B-00000001) is leaving holding_bridge technology
[Oct  8 13:17:30] VERBOSE[18225][C-00000001] res_musiconhold.c:     -- Stopped music on hold on PJSIP/phone_B-00000001
[Oct  8 13:17:30] DEBUG[18225][C-00000001] channel.c: Set channel PJSIP/phone_B-00000001 to write format ulaw
[Oct  8 13:17:30] DEBUG[18225][C-00000001] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[Oct  8 13:17:30] DEBUG[18071] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:30] DEBUG[18209] manager.c: Examining event:
Event: MusicOnHoldStop
Privilege: call,all
SequenceNumber: 38
File: manager_channels.c
Line: 665
Func: publish_basic_channel_event
Channel: PJSIP/phone_B-00000001
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 1002
CallerIDName: Phone B
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
AccountCode: 
Context: internal
Exten: 552
Priority: 1
Uniqueid: 1381256248.2


[Oct  8 13:17:30] DEBUG[18225][C-00000001] bridge_roles.c: Removing bridge role holding_participant from channel PJSIP/phone_B-00000001
[Oct  8 13:17:30] DEBUG[18071] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:30] DEBUG[18209] manager.c: Examining event:
Event: BridgeLeave
Privilege: call,all
SequenceNumber: 39
File: manager_bridges.c
Line: 299
Func: channel_leave_cb
BridgeUniqueid: 4cd44abb-660a-41c1-9ff8-c394e72dbb7a
BridgeType: agent_hold
BridgeTechnology: holding_bridge
BridgeNumChannels: 0
Channel: PJSIP/phone_B-00000001
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 1002
CallerIDName: Phone B
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
AccountCode: 
Context: internal
Exten: 552
Priority: 1
Uniqueid: 1381256248.2


[Oct  8 13:17:30] DEBUG[18067] devicestate.c: Checking if I can find provider for "Agent" - number: 1002
[Oct  8 13:17:30] DEBUG[18067] devicestate.c: Changing state for Agent:1002 - state 5 (Unavailable)
[Oct  8 13:17:30] DEBUG[18071] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:30] DEBUG[18062] devicestate.c: Processing device state change for 'Agent:1002'
[Oct  8 13:17:30] DEBUG[18209] manager.c: Examining event:
Event: AgentLogoff
Privilege: agent,all
SequenceNumber: 40
File: manager.c
Line: 1443
Func: manager_default_msg_cb
Channel: PJSIP/phone_B-00000001
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 1002
CallerIDName: Phone B
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
AccountCode: 
Context: internal
Exten: 552
Priority: 1
Uniqueid: 1381256248.2
Agent: 1002
Logintime: 2


[Oct  8 13:17:30] VERBOSE[18225][C-00000001] app_agent_pool.c:   == Agent '1002' logged out.  Logged in for 2 seconds.
[Oct  8 13:17:30] DEBUG[18225][C-00000001] pbx.c: Spawn extension (internal,552,1) exited non-zero on 'PJSIP/phone_B-00000001'
[Oct  8 13:17:30] DEBUG[18062] devicestate.c: Adding per-server state of 'Unavailable' for 'Agent:1002'
[Oct  8 13:17:30] VERBOSE[18225][C-00000001] pbx.c:   == Spawn extension (internal, 552, 1) exited non-zero on 'PJSIP/phone_B-00000001'
[Oct  8 13:17:30] DEBUG[18225][C-00000001] channel.c: Soft-Hanging up channel 'PJSIP/phone_B-00000001'
[Oct  8 13:17:30] DEBUG[18062] devicestate.c: Aggregate devstate result is 'Unavailable' for 'Agent:1002'
[Oct  8 13:17:30] DEBUG[18062] devicestate.c: Aggregate state for device 'Agent:1002' has not changed from 'Unavailable'
[Oct  8 13:17:30] DEBUG[18071] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:30] DEBUG[18209] manager.c: Examining event:
Event: SoftHangupRequest
Privilege: call,all
SequenceNumber: 41
File: manager_channels.c
Line: 705
Func: channel_hangup_request_cb
Channel: PJSIP/phone_B-00000001
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 1002
CallerIDName: Phone B
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
AccountCode: 
Context: internal
Exten: 552
Priority: 1
Uniqueid: 1381256248.2
Cause: 16


[Oct  8 13:17:30] DEBUG[18225][C-00000001] channel.c: Soft-Hanging up channel 'PJSIP/phone_B-00000001'
[Oct  8 13:17:30] DEBUG[18225][C-00000001] pbx.c: Launching 'NoOp'
[Oct  8 13:17:30] VERBOSE[18225][C-00000001] pbx.c:     -- Executing [h@internal:1] NoOp("PJSIP/phone_B-00000001", "=== Hang up handler ===") in new stack
[Oct  8 13:17:30] DEBUG[18071] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:30] DEBUG[18209] manager.c: Examining event:
Event: Newexten
Privilege: call,all
SequenceNumber: 42
File: manager_channels.c
Line: 602
Func: channel_snapshot_update
Channel: PJSIP/phone_B-00000001
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 1002
CallerIDName: Phone B
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
AccountCode: 
Context: internal
Exten: h
Priority: 1
Uniqueid: 1381256248.2
Extension: h
Application: NoOp
AppData: === Hang up handler ===


[Oct  8 13:17:30] DEBUG[18225][C-00000001] channel.c: Hanging up channel 'PJSIP/phone_B-00000001'
[Oct  8 13:17:30] DEBUG[18225][C-00000001] chan_pjsip.c: AST hangup cause 16 (no match found in PJSIP)
[Oct  8 13:17:30] DEBUG[18213] res_pjsip_session.c: Method is BYE
[Oct  8 13:17:30] DEBUG[18066] cdr.c: Finalized CDR for PJSIP/phone_B-00000001 - start 1381256248.138801 answer 1381256248.139445 end 1381256250.805569 dispo ANSWERED
[Oct  8 13:17:30] DEBUG[18071] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:30] DEBUG[18209] manager.c: Examining event:
Event: Hangup
Privilege: call,all
SequenceNumber: 43
File: manager_channels.c
Line: 602
Func: channel_snapshot_update
Channel: PJSIP/phone_B-00000001
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 1002
CallerIDName: Phone B
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
AccountCode: 
Context: internal
Exten: h
Priority: 2
Uniqueid: 1381256248.2
Cause: 16
Cause-txt: Normal Clearing


[Oct  8 13:17:30] DEBUG[18066] cdr_radius.c: Unable to create RADIUS record. CDR not recorded!
[Oct  8 13:17:30] DEBUG[18067] devicestate.c: Changing state for PJSIP/phone_B - state 1 (Not in use)
[Oct  8 13:17:30] DEBUG[18062] devicestate.c: Processing device state change for 'PJSIP/phone_B'
[Oct  8 13:17:30] DEBUG[18062] devicestate.c: Adding per-server state of 'Not in use' for 'PJSIP/phone_B'
[Oct  8 13:17:30] DEBUG[18062] devicestate.c: Aggregate devstate result is 'Not in use' for 'PJSIP/phone_B'
[Oct  8 13:17:30] DEBUG[18062] devicestate.c: Aggregate state for device 'PJSIP/phone_B' has changed to 'Not in use'
[Oct  8 13:17:30] DEBUG[18066] res_config_sqlite.c: SQL query: INSERT INTO ast_cdr (clid,src,dst,dcontext,channel,lastapp,lastdata,start,answer,end,duration,billsec,disposition,amaflags,uniqueid) VALUES ('"Phone B" <1002>','1002','h','internal','PJSIP/phone_B-00000001','NoOp','=== Hang up handler ===','2013-10-08 13:17:28','2013-10-08 13:17:28','2013-10-08 13:17:30','2','2','ANSWERED','DOCUMENTATION','1381256248.2')
[Oct  8 13:17:30] DEBUG[18179] app_queue.c: Device 'PJSIP/phone_B' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Oct  8 13:17:30] DEBUG[18068] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:30] DEBUG[18209] manager.c: Examining event:
Event: ExtensionStatus
Privilege: call,all
SequenceNumber: 44
File: manager.c
Line: 6088
Func: manager_state_cb
Exten: 1002
Context: internal
Hint: PJSIP/phone_B
Status: 0


[Oct  8 13:17:30] DEBUG[18068] app_queue.c: Extension '1002@internal' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Oct  8 13:17:30] DEBUG[18209] manager.c: Examining event:
Event: ExtensionStatus
Privilege: call,all
SequenceNumber: 45
File: manager.c
Line: 6088
Func: manager_state_cb
Exten: phone_B
Context: internal
Hint: PJSIP/phone_B
Status: 0


[Oct  8 13:17:30] DEBUG[18068] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:30] DEBUG[18068] app_queue.c: Extension 'phone_B@internal' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Oct  8 13:17:30] DEBUG[18213] res_pjsip_session.c: Source of transaction state change is RX_MSG
[Oct  8 13:17:30] DEBUG[18213] res_pjsip_session.c: Received response
[Oct  8 13:17:30] DEBUG[18213] res_pjsip_session.c: Response is 200 OK
[Oct  8 13:17:30] DEBUG[18213] res_pjsip_session.c: Destroying SIP session with endpoint phone_B
[Oct  8 13:17:30] DEBUG[18213] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xb2a4d234'
[Oct  8 13:17:30] DEBUG[18213] rtp_engine.c: Destroyed RTP instance '0xb2a4d234'
[Oct  8 13:17:30] DEBUG[18213] taskprocessor.c: destroying taskprocessor '63e93cc4-1e5e-4fdb-960a-2b98fe01f491'
[Oct  8 13:17:33] DEBUG[18073] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:38] DEBUG[18073] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:43] DEBUG[18073] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:44] DEBUG[18206] taskprocessor.c: destroying taskprocessor 'ast_msg_queue'
[Oct  8 13:17:44] VERBOSE[18206] asterisk.c: Asterisk cleanly ending (0).
[Oct  8 13:17:44] VERBOSE[18206] asterisk.c: Executing last minute cleanups
[Oct  8 13:17:44] DEBUG[18071] manager.c: Mansession: 0x95b4e0c refcount now 2
[Oct  8 13:17:44] DEBUG[18209] manager.c: Examining event:
Event: Shutdown
Privilege: system,all
SequenceNumber: 46
File: manager.c
Line: 1460
Func: manager_generic_msg_cb
Shutdown: Cleanly
Restart: False


[Oct  8 13:17:44] VERBOSE[18206] res_musiconhold.c:   == Destroying musiconhold processes
[Oct  8 13:17:44] DEBUG[18206] res_musiconhold.c: Destroying MOH class 'default'
[Oct  8 13:17:44] DEBUG[18076] taskprocessor.c: destroying taskprocessor 'a7c4cbd0-0981-4c53-ac55-a7af4585ad79'
[Oct  8 13:17:44] VERBOSE[18206] pbx.c:   == Unregistered application 'CallCompletionCancel'
[Oct  8 13:17:44] VERBOSE[18206] pbx.c:   == Unregistered application 'CallCompletionRequest'
[Oct  8 13:17:44] DEBUG[18206] logger.c: Unregistered dynamic logger level 'CC' with index 16.
[Oct  8 13:17:44] DEBUG[18206] taskprocessor.c: destroying taskprocessor 'CCSS core'
[Oct  8 13:17:44] DEBUG[18206] taskprocessor.c: destroying taskprocessor 'e7db0eb3-7add-4a88-94ce-4057a14ed676'
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action BridgeList
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action BridgeInfo
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action Ping
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action Events
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action Logoff
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action Login
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action Challenge
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action Hangup
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action Status
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action Setvar
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action Getvar
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action GetConfig
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action GetConfigJSON
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action UpdateConfig
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action CreateConfig
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action ListCategories
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action Redirect
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action Atxfer
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action Originate
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action Command
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action ExtensionState
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action PresenceState
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action AbsoluteTimeout
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action MailboxStatus
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action MailboxCount
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action ListCommands
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action SendText
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action UserEvent
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action WaitEvent
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action CoreSettings
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action CoreStatus
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action Reload
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action CoreShowChannels
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action ModuleLoad
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action ModuleCheck
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action AOCMessage
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action Filter
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action BlindTransfer
[Oct  8 13:17:44] VERBOSE[18206] pbx.c:   == Unregistered custom function AMI_CLIENT
[Oct  8 13:17:44] DEBUG[18071] taskprocessor.c: destroying taskprocessor '2f9c6700-98c4-4ece-9772-7906214522d1'
[Oct  8 13:17:44] DEBUG[18206] tcptls.c: Stopped server :: AMI server
[Oct  8 13:17:44] DEBUG[18206] tcptls.c: Stopped server :: AMI TLS server
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action LocalOptimizeAway
[Oct  8 13:17:44] DEBUG[18206] channel.c: Unregistering channel type 'Local'
[Oct  8 13:17:44] VERBOSE[18206] channel.c:   == Unregistered channel type 'Local'
[Oct  8 13:17:44] VERBOSE[18206] pbx.c:   == Unregistered application 'Answer'
[Oct  8 13:17:44] VERBOSE[18206] pbx.c:   == Unregistered application 'BackGround'
[Oct  8 13:17:44] DEBUG[18069] taskprocessor.c: destroying taskprocessor 'c6b6a9c2-9731-4d6b-bd4c-aa4ae3d79f71'
[Oct  8 13:17:44] VERBOSE[18206] pbx.c:   == Unregistered application 'Busy'
[Oct  8 13:17:44] VERBOSE[18206] pbx.c:   == Unregistered application 'Congestion'
[Oct  8 13:17:44] DEBUG[18068] taskprocessor.c: destroying taskprocessor 'c4f3c13e-399c-4eed-90f6-27cb346b9e84'
[Oct  8 13:17:44] VERBOSE[18206] pbx.c:   == Unregistered application 'ExecIfTime'
[Oct  8 13:17:44] VERBOSE[18206] pbx.c:   == Unregistered application 'Goto'
[Oct  8 13:17:44] VERBOSE[18206] pbx.c:   == Unregistered application 'GotoIf'
[Oct  8 13:17:44] VERBOSE[18206] pbx.c:   == Unregistered application 'GotoIfTime'
[Oct  8 13:17:44] VERBOSE[18206] pbx.c:   == Unregistered application 'ImportVar'
[Oct  8 13:17:44] VERBOSE[18206] pbx.c:   == Unregistered application 'Hangup'
[Oct  8 13:17:44] VERBOSE[18206] pbx.c:   == Unregistered application 'Incomplete'
[Oct  8 13:17:44] VERBOSE[18206] pbx.c:   == Unregistered application 'NoOp'
[Oct  8 13:17:44] VERBOSE[18206] pbx.c:   == Unregistered application 'Proceeding'
[Oct  8 13:17:44] VERBOSE[18206] pbx.c:   == Unregistered application 'Progress'
[Oct  8 13:17:44] VERBOSE[18206] pbx.c:   == Unregistered application 'RaiseException'
[Oct  8 13:17:44] VERBOSE[18206] pbx.c:   == Unregistered application 'Ringing'
[Oct  8 13:17:44] VERBOSE[18206] pbx.c:   == Unregistered application 'SayAlpha'
[Oct  8 13:17:44] VERBOSE[18206] pbx.c:   == Unregistered application 'SayAlphaCase'
[Oct  8 13:17:44] VERBOSE[18206] pbx.c:   == Unregistered application 'SayDigits'
[Oct  8 13:17:44] VERBOSE[18206] pbx.c:   == Unregistered application 'SayNumber'
[Oct  8 13:17:44] VERBOSE[18206] pbx.c:   == Unregistered application 'SayPhonetic'
[Oct  8 13:17:44] VERBOSE[18206] pbx.c:   == Unregistered application 'Set'
[Oct  8 13:17:44] VERBOSE[18206] pbx.c:   == Unregistered application 'MSet'
[Oct  8 13:17:44] VERBOSE[18206] pbx.c:   == Unregistered application 'SetAMAFlags'
[Oct  8 13:17:44] VERBOSE[18206] pbx.c:   == Unregistered application 'Wait'
[Oct  8 13:17:44] VERBOSE[18206] pbx.c:   == Unregistered application 'WaitExten'
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action ShowDialPlan
[Oct  8 13:17:44] VERBOSE[18206] pbx.c:   == Unregistered custom function EXCEPTION
[Oct  8 13:17:44] VERBOSE[18206] pbx.c:   == Unregistered custom function TESTTIME
[Oct  8 13:17:44] DEBUG[18206] bridge.c: Waiting for bridge manager thread to die.
[Oct  8 13:17:44] VERBOSE[18206] pbx.c:   == Unregistered custom function FEATUREMAP
[Oct  8 13:17:44] VERBOSE[18206] pbx.c:   == Unregistered custom function FEATURE
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action Bridge
[Oct  8 13:17:44] VERBOSE[18206] pbx.c:   == Unregistered application 'Bridge'
[Oct  8 13:17:44] DEBUG[18206] tcptls.c: Stopped server :: http server
[Oct  8 13:17:44] DEBUG[18206] channel.c: Unregistering channel type 'Surrogate'
[Oct  8 13:17:44] VERBOSE[18206] channel.c:   == Unregistered channel type 'Surrogate'
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action DataGet
[Oct  8 13:17:44] VERBOSE[18206] pbx.c:   == Unregistered custom function MESSAGE
[Oct  8 13:17:44] VERBOSE[18206] pbx.c:   == Unregistered custom function MESSAGE_DATA
[Oct  8 13:17:44] VERBOSE[18206] pbx.c:   == Unregistered application 'MessageSend'
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action MessageSend
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action DBGet
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action DBPut
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action DBDel
[Oct  8 13:17:44] VERBOSE[18206] manager.c:   == Manager unregistered action DBDelTree
[Oct  8 13:17:44] DEBUG[18206] taskprocessor.c: destroying taskprocessor 'Sorcery-control'
[Oct  8 13:17:44] DEBUG[18206] taskprocessor.c: destroying taskprocessor 'Sorcery'
[Oct  8 13:17:44] DEBUG[18206] asterisk.c: Asterisk ending (0).