benitezfede - 2011-11-15

Hi,
I have posted this in the Open Discussion forum by mistake so I will move it here because it is where it belongs. Aplogize for the repost.

2011-11-13 14:00:18 PST
Hi everyone,
I am using TAPILib3 and ActivaTSP to create a call popup application for our Trixbox 2.8.0.4 installation.

For some reason I am unable to receive call notification events. I set up ActivaTSP to monitor extensions from 110-113 and I do a call from 113 to 110 and no notification is raised. I paste the logs (sorry if its too much but I dont want to leave anything that may help out) as I couldnt determine what can be wrong here.

I would really appreciate if someone can give me a hand with this.

11/13/11 21:49:23  TRACE  TSPI_providerEnumDevices()
11/13/11 21:49:23  TRACE  Dn expression to filter: 110-113,
11/13/11 21:49:23  TRACE  Valid expression: 110-113
11/13/11 21:49:23  TRACE  Total DN number = 4
11/13/11 21:49:23  TRACE   DN = 110
11/13/11 21:49:23  TRACE   DN = 111
11/13/11 21:49:23  TRACE   DN = 112
11/13/11 21:49:23  TRACE   DN = 113
11/13/11 21:49:23  TRACE  TSPI_providerInit()
11/13/11 21:49:23  INFO   __________________ ASTProvider::Create __________________
11/13/11 21:49:23  INFO   *** ASTProvider::Create() ***
11/13/11 21:49:23  INFO   __________________ ASTCstaProvider::Create __________________
11/13/11 21:49:23  INFO        $Revision: 554 $
11/13/11 21:49:23  INFO   _____________________________________________________________
11/13/11 21:49:23  INFO   __________________ ASTTapiProvider::Create __________________
11/13/11 21:49:23  INFO   _  ActivaTSP.tsp vV1.8.2.1042 $Revision: 554 $                                  _
11/13/11 21:49:23  INFO   _____________________________________________________________
11/13/11 21:49:23  TRACE  TSPI_lineGetDevCaps() dwDeviceIdBase=0x5 dwDeviceID=0x5
11/13/11 21:49:23  TRACE  TSPI_lineGetAddressCaps() dwDeviceID=0x5 dwAddressID=0x0
11/13/11 21:49:23  TRACE  TSPI_lineGetDevCaps() dwDeviceIdBase=0x5 dwDeviceID=0x6
11/13/11 21:49:23  TRACE  TSPI_lineGetAddressCaps() dwDeviceID=0x6 dwAddressID=0x0
11/13/11 21:49:23  TRACE  TSPI_lineGetDevCaps() dwDeviceIdBase=0x5 dwDeviceID=0x7
11/13/11 21:49:23  TRACE  TSPI_lineGetAddressCaps() dwDeviceID=0x7 dwAddressID=0x0
11/13/11 21:49:23  TRACE  TSPI_lineGetDevCaps() dwDeviceIdBase=0x5 dwDeviceID=0x8
11/13/11 21:49:23  TRACE  TSPI_lineGetAddressCaps() dwDeviceID=0x8 dwAddressID=0x0
11/13/11 21:49:25  TRACE  TSPI_lineOpen() dwDeviceID=0x5 htLine=0x10255
11/13/11 21:49:25  INFO   Connect(192.168.1.14,5038,ast,password)
11/13/11 21:49:25  TRACE  ASTProvider::SendCommand =>
Action: Challenge
AuthType: MD5
ActionID: 1

11/13/11 21:49:25  TRACE  ASTProvider::ReaderProc
11/13/11 21:49:25  TRACE  Asterisk protocol header: Asterisk Call Manager/1.1
11/13/11 21:49:25  TRACE0 HEADER: response DATA: Success
11/13/11 21:49:25  TRACE0 HEADER: actionid DATA: 1
11/13/11 21:49:25  TRACE0 HEADER: challenge DATA: 131565631
11/13/11 21:49:25  TRACE   <== asterisk protocol response__________________________
11/13/11 21:49:25  TRACE  ASTProvider::SendCommand =>
Action: Login
AuthType: MD5
UserName: ast
Key: e50b4c78d92aa196c22ae387049acc3d
ActionID: 1

11/13/11 21:49:25  TRACE  Connect() returns ok
11/13/11 21:49:25  TRACE  ASTCstaProvider::OpenMonitor device = 110 => 110
11/13/11 21:49:25  TRACE    first monitor for this device: {110,1}
11/13/11 21:49:25  TRACE  AddTapiLine xref=1 htapiLine=0x10255 pTapiLine=0x352e490
11/13/11 21:49:25  TRACE  TSPI_lineGetNumAddressIDs hdLine=00000001
11/13/11 21:49:25  TRACE0 HEADER: response DATA: Success
11/13/11 21:49:25  TRACE0 HEADER: actionid DATA: 1
11/13/11 21:49:25  TRACE0 HEADER: message DATA: Authentication accepted
11/13/11 21:49:25  TRACE   <== asterisk protocol response__________________________
11/13/11 21:49:25  TRACE  TSPI_lineOpen() dwDeviceID=0x6 htLine=0x10233
11/13/11 21:49:25  INFO   Connect(192.168.1.14,5038,ast,password)
11/13/11 21:49:25  TRACE  ASTCstaProvider::OpenMonitor device = 111 => 111
11/13/11 21:49:25  TRACE    first monitor for this device: {111,2}
11/13/11 21:49:25  TRACE  AddTapiLine xref=2 htapiLine=0x10233 pTapiLine=0x352ee38
11/13/11 21:49:25  TRACE  TSPI_lineGetNumAddressIDs hdLine=00000002
11/13/11 21:49:26  TRACE  TSPI_lineOpen() dwDeviceID=0x7 htLine=0x10211
11/13/11 21:49:26  INFO   Connect(192.168.1.14,5038,ast,password)
11/13/11 21:49:26  TRACE  ASTCstaProvider::OpenMonitor device = 112 => 112
11/13/11 21:49:26  TRACE    first monitor for this device: {112,3}
11/13/11 21:49:26  TRACE  AddTapiLine xref=3 htapiLine=0x10211 pTapiLine=0x352eea8
11/13/11 21:49:26  TRACE  TSPI_lineGetNumAddressIDs hdLine=00000003
11/13/11 21:49:26  TRACE  TSPI_lineOpen() dwDeviceID=0x8 htLine=0x101ff
11/13/11 21:49:26  INFO   Connect(192.168.1.14,5038,ast,password)
11/13/11 21:49:26  TRACE  ASTCstaProvider::OpenMonitor device = 113 => 113
11/13/11 21:49:26  TRACE    first monitor for this device: {113,4}
11/13/11 21:49:26  TRACE  AddTapiLine xref=4 htapiLine=0x101ff pTapiLine=0x352ef50
11/13/11 21:49:26  TRACE  TSPI_lineGetNumAddressIDs hdLine=00000004
11/13/11 21:49:38  TRACE0 HEADER: event DATA: Newchannel
11/13/11 21:49:38  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:38  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:38  TRACE0 HEADER: channelstate DATA: 4
11/13/11 21:49:38  TRACE0 HEADER: channelstatedesc DATA: Ring
11/13/11 21:49:38  TRACE0 HEADER: calleridnum DATA: 110
11/13/11 21:49:38  TRACE0 HEADER: calleridname DATA: device
11/13/11 21:49:38  TRACE0 HEADER: accountcode DATA:
11/13/11 21:49:38  TRACE0 HEADER: uniqueid DATA: 1321220980.134
11/13/11 21:49:38  TRACE  ASTProvider::HandleEvent => newchannel
11/13/11 21:49:38  TRACE  OnNewChannelEvent:CFT: ev.m_uniqueId="1321220980.134"; ev.m_callerId="110"; ev.m_callerIdName="device"; ev.m_state="Ring"; ev.m_channel="IAX2/110-13966"; m_pxCstaProvider->OnNewChannelEvent(ev);
11/13/11 21:49:38  TRACE  Create AsteriskCall with uniqueId = 1321220980.134 and callid =2
11/13/11 21:49:38  TRACE  Call does not contains UserData
11/13/11 21:49:38  TRACE  Call does not containsCallId
11/13/11 21:49:38  TRACE  Call is NOT predictive
11/13/11 21:49:38  TRACE    setting {1321220980.134}.callerID=110, callerIdName=device
11/13/11 21:49:38  TRACE    setting {1321220980.134}.channel=IAX2/110-13966, address=110
11/13/11 21:49:38  TRACE    state = RING => Send ORIGINATED to {1321220980.134}.address=110
11/13/11 21:49:38  TRACE  ASTCstaProvider::handleConnectionOriginated uniqueId=1321220980.134, address=110
11/13/11 21:49:38  TRACE0 ================================================================= start callmap dump…
11/13/11 21:49:38  TRACE0 DUMP OF ASTERISK CALLS MAP: {UNIQUEID} => call info:
11/13/11 21:49:38  TRACE0   {1321220980.134}.110 numDevice=110 callID=2 state=Ring chann=IAX2/110-13966 CID=110 CIDName=device ConLineNum= ConLineName= lastRedir= source= userData= cause=0
11/13/11 21:49:38  TRACE0 DUMP OF MONITOR CALLS MAP: {CALL_ID} => DEVICE: => STATE
11/13/11 21:49:38  TRACE0 ================================================================= end callmap dump…
11/13/11 21:49:38  TRACE  AddConnectionToCallModel {2, 110} => INITIALIZED
11/13/11 21:49:38  TRACE   done, now CALL map has 1 items
11/13/11 21:49:38  TRACE  GetMonitorSetFromCallModel = 2
11/13/11 21:49:38  TRACE    num_monitors = 1
11/13/11 21:49:38  TRACE      sending event:CFTE:ORIGINATED to xref=1, address=110, callid=2
11/13/11 21:49:38  TRACE  OnOriginated xref=1 callId=2, originatingDevice=110 cause=0
11/13/11 21:49:38  TRACE   searching a TapiCall with callId 2 in tapiLine 0x352e490
11/13/11 21:49:38  TRACE    TapiCall not found
11/13/11 21:49:38  TRACE   <== asterisk protocol event _______________________________
11/13/11 21:49:38  TRACE0 HEADER: event DATA: ChannelUpdate
11/13/11 21:49:38  TRACE0 HEADER: privilege DATA: system,all
11/13/11 21:49:38  TRACE0 HEADER: channel DATA:
11/13/11 21:49:38  TRACE0 HEADER: channeltype DATA: IAX2
11/13/11 21:49:38  TRACE0 HEADER: iax2-callno-local DATA: 13966
11/13/11 21:49:38  TRACE0 HEADER: iax2-callno-remote DATA: 86
11/13/11 21:49:38  TRACE0 HEADER: iax2-peer DATA:
11/13/11 21:49:38  TRACE0 ASTProvider::HandleEvent => channelupdate
11/13/11 21:49:38  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:38  TRACE0 HEADER: event DATA: NewCallerid
11/13/11 21:49:38  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:38  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:38  TRACE0 HEADER: calleridnum DATA: 110
11/13/11 21:49:38  TRACE0 HEADER: calleridname DATA: fede
11/13/11 21:49:38  TRACE0 HEADER: uniqueid DATA: 1321220980.134
11/13/11 21:49:38  TRACE0 HEADER: cid-callingpres DATA: 1 (Presentation Allowed, Passed Screen)
11/13/11 21:49:38  TRACE  ASTProvider::HandleEvent => newcallerid
11/13/11 21:49:38  TRACE  OnNewCallerIdEvent:CFT: ev.m_uniqueId="1321220980.134"; ev.m_callerId="110"; ev.m_callerIdName="fede"; m_pxCstaProvider->OnNewCallerIdEvent(ev);
11/13/11 21:49:38  TRACE  Call does not contains UserData
11/13/11 21:49:38  TRACE  Call does not containsCallId
11/13/11 21:49:38  TRACE  Call is NOT predictive
11/13/11 21:49:38  TRACE    overriding {1321220980.134}.device to new calleridname fede
11/13/11 21:49:38  TRACE   <== asterisk protocol event _______________________________
11/13/11 21:49:38  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:38  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:38  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:38  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:38  TRACE0 HEADER: commandid DATA: 103267778
11/13/11 21:49:38  TRACE0 HEADER: command DATA: GET VARIABLE ARG2
11/13/11 21:49:38  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:38  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:38  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:38  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:38  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:38  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:38  TRACE0 HEADER: commandid DATA: 103267778
11/13/11 21:49:38  TRACE0 HEADER: command DATA: GET VARIABLE ARG2
11/13/11 21:49:38  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:38  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:38  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:38  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:38  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:38  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:38  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:38  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:38  TRACE0 HEADER: commandid DATA: 2097990137
11/13/11 21:49:38  TRACE0 HEADER: command DATA: GET VARIABLE ARG1
11/13/11 21:49:38  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:38  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:38  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:38  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:38  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:38  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:38  TRACE0 HEADER: commandid DATA: 2097990137
11/13/11 21:49:38  TRACE0 HEADER: command DATA: GET VARIABLE ARG1
11/13/11 21:49:38  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:38  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:38  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:38  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:38  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:38  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:38  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:38  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:38  TRACE0 HEADER: commandid DATA: 1795317097
11/13/11 21:49:38  TRACE0 HEADER: command DATA: DATABASE GET "AMPUSER" "113/recording"
11/13/11 21:49:38  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:38  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:38  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:38  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:38  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:38  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:38  TRACE0 HEADER: commandid DATA: 1795317097
11/13/11 21:49:38  TRACE0 HEADER: command DATA: DATABASE GET "AMPUSER" "113/recording"
11/13/11 21:49:38  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:38  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:38  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:38  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:38  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:38  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:38  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:38  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:38  TRACE0 HEADER: commandid DATA: 1510461845
11/13/11 21:49:38  TRACE0 HEADER: command DATA: VERBOSE "Inbound recording not enabled" 1
11/13/11 21:49:38  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:38  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:38  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:38  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:38  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:38  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:38  TRACE0 HEADER: commandid DATA: 1510461845
11/13/11 21:49:38  TRACE0 HEADER: command DATA: VERBOSE "Inbound recording not enabled" 1
11/13/11 21:49:38  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:38  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:38  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:38  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 787835315
11/13/11 21:49:39  TRACE0 HEADER: command DATA: VERBOSE "Starting New Dialparties.agi" 1
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 787835315
11/13/11 21:49:39  TRACE0 HEADER: command DATA: VERBOSE "Starting New Dialparties.agi" 1
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 246707071
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE AMPMGRUSER
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 246707071
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE AMPMGRUSER
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 2069969120
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE AMPMGRPASS
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 2069969120
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE AMPMGRPASS
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1195979083
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE CWINUSEBUSY
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1195979083
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE CWINUSEBUSY
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1272110242
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE ASTVERSION
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1272110242
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE ASTVERSION
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 2121155657
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE ASTCHANDAHDI
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 2121155657
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE ASTCHANDAHDI
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1407019446
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE CWIGNORE
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1407019446
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE CWIGNORE
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1290138995
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE CFIGNORE
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1290138995
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE CFIGNORE
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1181078055
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE HAS_EXTENSION_STATE
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1181078055
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE HAS_EXTENSION_STATE
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1803679008
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE priority
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1803679008
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE priority
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 517391647
11/13/11 21:49:39  TRACE0 HEADER: command DATA: VERBOSE "Caller ID name is 'fede' number is '110'" 1
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 517391647
11/13/11 21:49:39  TRACE0 HEADER: command DATA: VERBOSE "Caller ID name is 'fede' number is '110'" 1
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 817245353
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE QUEUEWAIT
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 817245353
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE QUEUEWAIT
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 938769888
11/13/11 21:49:39  TRACE0 HEADER: command DATA: SET VARIABLE __KEEPCID "TRUE"
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 938769888
11/13/11 21:49:39  TRACE0 HEADER: command DATA: SET VARIABLE __KEEPCID "TRUE"
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1388343190
11/13/11 21:49:39  TRACE0 HEADER: command DATA: SET VARIABLE DIALSTATUS_CW ""
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1388343190
11/13/11 21:49:39  TRACE0 HEADER: command DATA: SET VARIABLE DIALSTATUS_CW ""
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1999446505
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE ARG1
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1999446505
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE ARG1
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1208394942
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE ARG2
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1208394942
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE ARG2
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1135871171
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE RingGroupMethod
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1135871171
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE RingGroupMethod
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 547880605
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE ALERT_INFO
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 547880605
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE ALERT_INFO
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1027277702
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE SIPADDHEADER
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1027277702
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE SIPADDHEADER
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1619009817
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE PR_DIALSTATUS
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1619009817
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE PR_DIALSTATUS
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1810116811
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE FMGRP
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1810116811
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE FMGRP
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1298769947
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE NODEST
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1298769947
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE NODEST
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1200379484
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE RINGGROUP_INDEX
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1200379484
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE RINGGROUP_INDEX
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 246846178
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE USE_CONFIRMATION
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 246846178
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE USE_CONFIRMATION
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 792810023
11/13/11 21:49:39  TRACE0 HEADER: command DATA: VERBOSE "USE_CONFIRMATION:  'FALSE'" 5
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 792810023
11/13/11 21:49:39  TRACE0 HEADER: command DATA: VERBOSE "USE_CONFIRMATION:  'FALSE'" 5
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1011688860
11/13/11 21:49:39  TRACE0 HEADER: command DATA: VERBOSE "RINGGROUP_INDEX:   ''" 5
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1011688860
11/13/11 21:49:39  TRACE0 HEADER: command DATA: VERBOSE "RINGGROUP_INDEX:   ''" 5
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1945820461
11/13/11 21:49:39  TRACE0 HEADER: command DATA: VERBOSE "Methodology of ring is  'none'" 1
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1945820461
11/13/11 21:49:39  TRACE0 HEADER: command DATA: VERBOSE "Methodology of ring is  'none'" 1
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 844174611
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE ARG3
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 844174611
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE ARG3
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1470521565
11/13/11 21:49:39  TRACE0 HEADER: command DATA: VERBOSE "Added extension 113 to extension map" 3
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1470521565
11/13/11 21:49:39  TRACE0 HEADER: command DATA: VERBOSE "Added extension 113 to extension map" 3
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1063046805
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE ARG4
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1063046805
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE ARG4
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1968879403
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE SCREEN
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1968879403
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE SCREEN
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1782031063
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE FROM_DID
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1782031063
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE FROM_DID
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1619271587
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE ASTVARLIBDIR
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1619271587
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE ASTVARLIBDIR
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1718591784
11/13/11 21:49:39  TRACE0 HEADER: command DATA: DATABASE GET "CF" "113"
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1718591784
11/13/11 21:49:39  TRACE0 HEADER: command DATA: DATABASE GET "CF" "113"
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 861199875
11/13/11 21:49:39  TRACE0 HEADER: command DATA: VERBOSE "Extension 113 cf is disabled" 3
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 861199875
11/13/11 21:49:39  TRACE0 HEADER: command DATA: VERBOSE "Extension 113 cf is disabled" 3
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1284368846
11/13/11 21:49:39  TRACE0 HEADER: command DATA: DATABASE GET "DND" "113"
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1284368846
11/13/11 21:49:39  TRACE0 HEADER: command DATA: DATABASE GET "DND" "113"
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1069537797
11/13/11 21:49:39  TRACE0 HEADER: command DATA: VERBOSE "Extension 113 do not disturb is disabled" 3
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1069537797
11/13/11 21:49:39  TRACE0 HEADER: command DATA: VERBOSE "Extension 113 do not disturb is disabled" 3
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 900086067
11/13/11 21:49:39  TRACE0 HEADER: command DATA: DATABASE GET "CW" "113"
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 900086067
11/13/11 21:49:39  TRACE0 HEADER: command DATA: DATABASE GET "CW" "113"
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 319892468
11/13/11 21:49:39  TRACE0 HEADER: command DATA: DATABASE GET "CFB" "113"
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 319892468
11/13/11 21:49:39  TRACE0 HEADER: command DATA: DATABASE GET "CFB" "113"
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 79104024
11/13/11 21:49:39  TRACE0 HEADER: command DATA: DATABASE GET "CFU" "113"
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 79104024
11/13/11 21:49:39  TRACE0 HEADER: command DATA: DATABASE GET "CFU" "113"
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 2012653234
11/13/11 21:49:39  TRACE0 HEADER: command DATA: VERBOSE "extnum 113 has:  cw: 1; hascfb: 0  hascfu: 0 " 4
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 2012653234
11/13/11 21:49:39  TRACE0 HEADER: command DATA: VERBOSE "extnum 113 has:  cw: 1; hascfb: 0  hascfu: 0 " 4
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1907607622
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE EXTENSION_STATE(113)
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1907607622
11/13/11 21:49:39  TRACE0 HEADER: command DATA: GET VARIABLE EXTENSION_STATE(113)
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 502258532
11/13/11 21:49:39  TRACE0 HEADER: command DATA: VERBOSE "EXTENSION_STATE: 0 (NOT_INUSE)" 1
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 502258532
11/13/11 21:49:39  TRACE0 HEADER: command DATA: VERBOSE "EXTENSION_STATE: 0 (NOT_INUSE)" 1
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 978201395
11/13/11 21:49:39  TRACE0 HEADER: command DATA: DATABASE GET "AMPUSER" "113/device"
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 978201395
11/13/11 21:49:39  TRACE0 HEADER: command DATA: DATABASE GET "AMPUSER" "113/device"
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 670969486
11/13/11 21:49:39  TRACE0 HEADER: command DATA: DATABASE GET "DEVICE" "113/dial"
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 670969486
11/13/11 21:49:39  TRACE0 HEADER: command DATA: DATABASE GET "DEVICE" "113/dial"
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 108590449
11/13/11 21:49:39  TRACE0 HEADER: command DATA: DATABASE PUT "CALLTRACE" "113" "110"
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 108590449
11/13/11 21:49:39  TRACE0 HEADER: command DATA: DATABASE PUT "CALLTRACE" "113" "110"
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1167241169
11/13/11 21:49:39  TRACE0 HEADER: command DATA: VERBOSE "dbset CALLTRACE/113 to 110" 3
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1167241169
11/13/11 21:49:39  TRACE0 HEADER: command DATA: VERBOSE "dbset CALLTRACE/113 to 110" 3
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 415876426
11/13/11 21:49:39  TRACE0 HEADER: command DATA: SET VARIABLE FILTERED_DIAL "113"
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 415876426
11/13/11 21:49:39  TRACE0 HEADER: command DATA: SET VARIABLE FILTERED_DIAL "113"
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 364747340
11/13/11 21:49:39  TRACE0 HEADER: command DATA: VERBOSE "Filtered ARG3: 113" 3
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 364747340
11/13/11 21:49:39  TRACE0 HEADER: command DATA: VERBOSE "Filtered ARG3: 113" 3
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1906161543
11/13/11 21:49:39  TRACE0 HEADER: command DATA: SET VARIABLE ds "IAX2/113,\"\",tr"
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1906161543
11/13/11 21:49:39  TRACE0 HEADER: command DATA: SET VARIABLE ds "IAX2/113,\"\",tr"
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: Start
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1781704670
11/13/11 21:49:39  TRACE0 HEADER: command DATA: SET PRIORITY normdial
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: AGIExec
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: subevent DATA: End
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:39  TRACE0 HEADER: commandid DATA: 1781704670
11/13/11 21:49:39  TRACE0 HEADER: command DATA: SET PRIORITY normdial
11/13/11 21:49:39  TRACE0 HEADER: resultcode DATA: 200
11/13/11 21:49:39  TRACE0 HEADER: result DATA: Success
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => agiexec
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: Newchannel
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/113-1598
11/13/11 21:49:39  TRACE0 HEADER: channelstate DATA: 0
11/13/11 21:49:39  TRACE0 HEADER: channelstatedesc DATA: Down
11/13/11 21:49:39  TRACE0 HEADER: calleridnum DATA:
11/13/11 21:49:39  TRACE0 HEADER: calleridname DATA:
11/13/11 21:49:39  TRACE0 HEADER: accountcode DATA:
11/13/11 21:49:39  TRACE0 HEADER: uniqueid DATA: 1321220980.135
11/13/11 21:49:39  TRACE  ASTProvider::HandleEvent => newchannel
11/13/11 21:49:39  TRACE  OnNewChannelEvent:CFT: ev.m_uniqueId="1321220980.135"; ev.m_callerId=""; ev.m_callerIdName=""; ev.m_state="Down"; ev.m_channel="IAX2/113-1598"; m_pxCstaProvider->OnNewChannelEvent(ev);
11/13/11 21:49:39  TRACE  Create AsteriskCall with uniqueId = 1321220980.135 and callid =3
11/13/11 21:49:39  TRACE    setting {1321220980.135}.callerID=, callerIdName=
11/13/11 21:49:39  TRACE    setting {1321220980.135}.channel=IAX2/113-1598, address=113
11/13/11 21:49:39  TRACE    state = DOWN => do nothing
11/13/11 21:49:39  TRACE   <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: ChannelUpdate
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: system,all
11/13/11 21:49:39  TRACE0 HEADER: channel DATA:
11/13/11 21:49:39  TRACE0 HEADER: channeltype DATA: IAX2
11/13/11 21:49:39  TRACE0 HEADER: iax2-callno-local DATA: 1598
11/13/11 21:49:39  TRACE0 HEADER: iax2-callno-remote DATA: 0
11/13/11 21:49:39  TRACE0 HEADER: iax2-peer DATA:
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => channelupdate
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: Newstate
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/113-1598
11/13/11 21:49:39  TRACE0 HEADER: channelstate DATA: 5
11/13/11 21:49:39  TRACE0 HEADER: channelstatedesc DATA: Ringing
11/13/11 21:49:39  TRACE0 HEADER: calleridnum DATA: 110
11/13/11 21:49:39  TRACE0 HEADER: calleridname DATA: fede
11/13/11 21:49:39  TRACE0 HEADER: uniqueid DATA: 1321220980.135
11/13/11 21:49:39  TRACE  ASTProvider::HandleEvent => newstate
11/13/11 21:49:39  TRACE  OnNewStateEvent:CFT: ev.m_uniqueId="1321220980.135"; ev.m_callerIdName="fede"; ev.m_state="Ringing"; ev.m_channel="IAX2/113-1598"; m_pxCstaProvider->OnNewStateEvent(ev);
11/13/11 21:49:39  TRACE  Call does not contains UserData
11/13/11 21:49:39  TRACE  Call does not containsCallId
11/13/11 21:49:39  TRACE  Call is NOT predictive
11/13/11 21:49:39  TRACE    setting {1321220980.135}.callerID=, callerIdName=fede
11/13/11 21:49:39  TRACE    state = RINGING => Send ALERTING to {1321220980.135}.address=113
11/13/11 21:49:39  TRACE  ASTCstaProvider::handleConnectionAlerting uniqueId=1321220980.135, address=113
11/13/11 21:49:39  TRACE  ASTCallMap::GetSourceCall(0x34e83f8)
11/13/11 21:49:39  TRACE    SourceCall is 1321220980.135
11/13/11 21:49:39  TRACE0 ASTCallMap::GetLogicCallId(0x34e83f8)
11/13/11 21:49:39  TRACE  GetCIDInfoFromSourceCall(1321220980.135)
11/13/11 21:49:39  TRACE    Exiting with cid/cidname/userData=//
11/13/11 21:49:39  TRACE0 ================================================================= start callmap dump…
11/13/11 21:49:39  TRACE0 DUMP OF ASTERISK CALLS MAP: {UNIQUEID} => call info:
11/13/11 21:49:39  TRACE0   {1321220980.134}.110 numDevice=110 callID=2 state=Ring chann=IAX2/110-13966 CID=110 CIDName=fede ConLineNum= ConLineName= lastRedir= source= userData= cause=0
11/13/11 21:49:39  TRACE0   {1321220980.135}.113 numDevice=113 callID=3 state=Ringing chann=IAX2/113-1598 CID= CIDName=fede ConLineNum= ConLineName= lastRedir= source= userData= cause=0
11/13/11 21:49:39  TRACE0 DUMP OF MONITOR CALLS MAP: {CALL_ID} => DEVICE: => STATE
11/13/11 21:49:39  TRACE0      => 110 => INITIALIZED
11/13/11 21:49:39  TRACE0 ================================================================= end callmap dump…
11/13/11 21:49:39  TRACE  AddConnectionToCallModel {3, 113} => ALERTING
11/13/11 21:49:39  TRACE   done, now CALL map has 2 items
11/13/11 21:49:39  TRACE    event minimization RULE-4: (callerid = ) == (called = ) == (address = 113)
11/13/11 21:49:39  TRACE   <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: NewCallerid
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: channel DATA: IAX2/113-1598
11/13/11 21:49:39  TRACE0 HEADER: calleridnum DATA: 113
11/13/11 21:49:39  TRACE0 HEADER: calleridname DATA:
11/13/11 21:49:39  TRACE0 HEADER: uniqueid DATA: 1321220980.135
11/13/11 21:49:39  TRACE0 HEADER: cid-callingpres DATA: 1 (Presentation Allowed, Passed Screen)
11/13/11 21:49:39  TRACE  ASTProvider::HandleEvent => newcallerid
11/13/11 21:49:39  TRACE  OnNewCallerIdEvent:CFT: ev.m_uniqueId="1321220980.135"; ev.m_callerId="113"; ev.m_callerIdName=""; m_pxCstaProvider->OnNewCallerIdEvent(ev);
11/13/11 21:49:39  TRACE    overriding {1321220980.135}. to new callerId 113
11/13/11 21:49:39  TRACE   <== asterisk protocol event _______________________________
11/13/11 21:49:39  TRACE0 HEADER: event DATA: ExtensionStatus
11/13/11 21:49:39  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:39  TRACE0 HEADER: exten DATA: 113
11/13/11 21:49:39  TRACE0 HEADER: context DATA: ext-local
11/13/11 21:49:39  TRACE0 HEADER: hint DATA: IAX2/113&Custom:DND113
11/13/11 21:49:39  TRACE0 HEADER: status DATA: 8
11/13/11 21:49:39  TRACE0 ASTProvider::HandleEvent => extensionstatus
11/13/11 21:49:39  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:41  TRACE0 HEADER: event DATA: ExtensionStatus
11/13/11 21:49:41  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:41  TRACE0 HEADER: exten DATA: 110
11/13/11 21:49:41  TRACE0 HEADER: context DATA: ext-local
11/13/11 21:49:41  TRACE0 HEADER: hint DATA: IAX2/110&Custom:DND110
11/13/11 21:49:41  TRACE0 HEADER: status DATA: 1
11/13/11 21:49:41  TRACE0 ASTProvider::HandleEvent => extensionstatus
11/13/11 21:49:41  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:41  TRACE0 HEADER: event DATA: PeerStatus
11/13/11 21:49:41  TRACE0 HEADER: privilege DATA: system,all
11/13/11 21:49:41  TRACE0 HEADER: channeltype DATA: IAX2
11/13/11 21:49:41  TRACE0 HEADER: peer DATA: IAX2/110
11/13/11 21:49:41  TRACE0 HEADER: peerstatus DATA: Registered
11/13/11 21:49:41  TRACE0 ASTProvider::HandleEvent => peerstatus
11/13/11 21:49:41  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:44  TRACE0 HEADER: event DATA: Newstate
11/13/11 21:49:44  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:44  TRACE0 HEADER: channel DATA: IAX2/113-1598
11/13/11 21:49:44  TRACE0 HEADER: channelstate DATA: 6
11/13/11 21:49:44  TRACE0 HEADER: channelstatedesc DATA: Up
11/13/11 21:49:44  TRACE0 HEADER: calleridnum DATA: 113
11/13/11 21:49:44  TRACE0 HEADER: calleridname DATA:
11/13/11 21:49:44  TRACE0 HEADER: uniqueid DATA: 1321220980.135
11/13/11 21:49:44  TRACE  ASTProvider::HandleEvent => newstate
11/13/11 21:49:44  TRACE  OnNewStateEvent:CFT: ev.m_uniqueId="1321220980.135"; ev.m_callerIdName=""; ev.m_state="Up"; ev.m_channel="IAX2/113-1598"; m_pxCstaProvider->OnNewStateEvent(ev);
11/13/11 21:49:44  TRACE    state = UP => Send ESTABLISHED to {1321220980.135}.address=113
11/13/11 21:49:44  TRACE  ASTCstaProvider::handleConnectionConnected uniqueId=1321220980.135, address=113
11/13/11 21:49:44  TRACE  ASTCallMap::GetSourceCall(0x34e83f8)
11/13/11 21:49:44  TRACE    SourceCall is 1321220980.135
11/13/11 21:49:44  TRACE  GetCIDInfoFromSourceCall(1321220980.135)
11/13/11 21:49:44  TRACE    Exiting with cid/cidname/userData=113/fede/
11/13/11 21:49:44  TRACE0 ================================================================= start callmap dump…
11/13/11 21:49:44  TRACE0 DUMP OF ASTERISK CALLS MAP: {UNIQUEID} => call info:
11/13/11 21:49:44  TRACE0   {1321220980.134}.110 numDevice=110 callID=2 state=Ring chann=IAX2/110-13966 CID=110 CIDName=fede ConLineNum= ConLineName= lastRedir= source= userData= cause=0
11/13/11 21:49:44  TRACE0   {1321220980.135}.113 numDevice=113 callID=3 state=not known chann=IAX2/113-1598 CID=113 CIDName=fede ConLineNum= ConLineName= lastRedir= source= userData= cause=0
11/13/11 21:49:44  TRACE0 DUMP OF MONITOR CALLS MAP: {CALL_ID} => DEVICE: => STATE
11/13/11 21:49:44  TRACE0      => 110 => INITIALIZED
11/13/11 21:49:44  TRACE0      => 113 => ALERTING
11/13/11 21:49:44  TRACE0 ================================================================= end callmap dump…
11/13/11 21:49:44  TRACE  AddConnectionToCallModel {3, 113} => CONNECTED
11/13/11 21:49:44  TRACE   done, now CALL map has 2 items
11/13/11 21:49:44  TRACE    event minimization RULE-4: (callerid = 113) == (called = 113) == (address = 113)
11/13/11 21:49:44  TRACE   <== asterisk protocol event _______________________________
11/13/11 21:49:44  TRACE0 HEADER: event DATA: ChannelUpdate
11/13/11 21:49:44  TRACE0 HEADER: privilege DATA: system,all
11/13/11 21:49:44  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:44  TRACE0 HEADER: channeltype DATA: IAX2
11/13/11 21:49:44  TRACE0 HEADER: iax2-callno-local DATA: 13966
11/13/11 21:49:44  TRACE0 HEADER: iax2-callno-remote DATA: 86
11/13/11 21:49:44  TRACE0 HEADER: iax2-peer DATA:
11/13/11 21:49:44  TRACE0 ASTProvider::HandleEvent => channelupdate
11/13/11 21:49:44  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:44  TRACE0 HEADER: event DATA: Newstate
11/13/11 21:49:44  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:44  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:44  TRACE0 HEADER: channelstate DATA: 6
11/13/11 21:49:44  TRACE0 HEADER: channelstatedesc DATA: Up
11/13/11 21:49:44  TRACE0 HEADER: calleridnum DATA: 110
11/13/11 21:49:44  TRACE0 HEADER: calleridname DATA: fede
11/13/11 21:49:44  TRACE0 HEADER: uniqueid DATA: 1321220980.134
11/13/11 21:49:44  TRACE  ASTProvider::HandleEvent => newstate
11/13/11 21:49:44  TRACE  OnNewStateEvent:CFT: ev.m_uniqueId="1321220980.134"; ev.m_callerIdName="fede"; ev.m_state="Up"; ev.m_channel="IAX2/110-13966"; m_pxCstaProvider->OnNewStateEvent(ev);
11/13/11 21:49:44  TRACE  Call does not contains UserData
11/13/11 21:49:44  TRACE  Call does not containsCallId
11/13/11 21:49:44  TRACE  Call is NOT predictive
11/13/11 21:49:44  TRACE    setting {1321220980.134}.callerID=110, callerIdName=fede
11/13/11 21:49:44  TRACE    state = UP => Send ESTABLISHED to {1321220980.134}.address=110
11/13/11 21:49:44  TRACE  ASTCstaProvider::handleConnectionConnected uniqueId=1321220980.134, address=110
11/13/11 21:49:44  TRACE  ASTCallMap::GetSourceCall(0x34e79f8)
11/13/11 21:49:44  TRACE    SourceCall is 1321220980.134
11/13/11 21:49:44  TRACE  GetCIDInfoFromSourceCall(1321220980.134)
11/13/11 21:49:44  TRACE    Exiting with cid/cidname/userData=110/fede/
11/13/11 21:49:44  TRACE0 ================================================================= start callmap dump…
11/13/11 21:49:44  TRACE0 DUMP OF ASTERISK CALLS MAP: {UNIQUEID} => call info:
11/13/11 21:49:44  TRACE0   {1321220980.134}.110 numDevice=110 callID=2 state=not known chann=IAX2/110-13966 CID=110 CIDName=fede ConLineNum= ConLineName= lastRedir= source= userData= cause=0
11/13/11 21:49:44  TRACE0   {1321220980.135}.113 numDevice=113 callID=3 state=not known chann=IAX2/113-1598 CID=113 CIDName=fede ConLineNum= ConLineName= lastRedir= source= userData= cause=0
11/13/11 21:49:44  TRACE0 DUMP OF MONITOR CALLS MAP: {CALL_ID} => DEVICE: => STATE
11/13/11 21:49:44  TRACE0      => 110 => INITIALIZED
11/13/11 21:49:44  TRACE0      => 113 => CONNECTED
11/13/11 21:49:44  TRACE0 ================================================================= end callmap dump…
11/13/11 21:49:44  TRACE  AddConnectionToCallModel {2, 110} => CONNECTED
11/13/11 21:49:44  TRACE   done, now CALL map has 2 items
11/13/11 21:49:44  TRACE    event minimization RULE-4: (callerid = 110) == (called = 110) == (address = 110)
11/13/11 21:49:44  TRACE   <== asterisk protocol event _______________________________
11/13/11 21:49:44  TRACE0 HEADER: event DATA: NewAccountCode
11/13/11 21:49:44  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:44  TRACE0 HEADER: channel DATA: IAX2/113-1598
11/13/11 21:49:44  TRACE0 HEADER: uniqueid DATA: 1321220980.135
11/13/11 21:49:44  TRACE0 HEADER: accountcode DATA:
11/13/11 21:49:44  TRACE0 HEADER: oldaccountcode DATA:
11/13/11 21:49:44  TRACE0 ASTProvider::HandleEvent => newaccountcode
11/13/11 21:49:44  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:44  TRACE0 HEADER: event DATA: Bridge
11/13/11 21:49:44  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:44  TRACE0 HEADER: bridgestate DATA: Link
11/13/11 21:49:44  TRACE0 HEADER: bridgetype DATA: core
11/13/11 21:49:44  TRACE0 HEADER: channel1 DATA: IAX2/110-13966
11/13/11 21:49:44  TRACE0 HEADER: channel2 DATA: IAX2/113-1598
11/13/11 21:49:44  TRACE0 HEADER: uniqueid1 DATA: 1321220980.134
11/13/11 21:49:44  TRACE0 HEADER: uniqueid2 DATA: 1321220980.135
11/13/11 21:49:44  TRACE0 HEADER: callerid1 DATA: 110
11/13/11 21:49:44  TRACE0 HEADER: callerid2 DATA: 113
11/13/11 21:49:44  TRACE  ASTProvider::HandleEvent => bridge
11/13/11 21:49:44  TRACE  OnLinkEvent:CFT: ev.m_srcUniqueId="1321220980.134"; ev.m_destUniqueId="1321220980.135"; m_pxCstaProvider->OnLinkEvent(ev);
11/13/11 21:49:44  TRACE    set {1321220980.135}.lastRedirectionDevice=
11/13/11 21:49:44  TRACE   <== asterisk protocol event _______________________________
11/13/11 21:49:44  TRACE0 HEADER: event DATA: ExtensionStatus
11/13/11 21:49:44  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:44  TRACE0 HEADER: exten DATA: 113
11/13/11 21:49:44  TRACE0 HEADER: context DATA: ext-local
11/13/11 21:49:44  TRACE0 HEADER: hint DATA: IAX2/113&Custom:DND113
11/13/11 21:49:44  TRACE0 HEADER: status DATA: 1
11/13/11 21:49:44  TRACE0 ASTProvider::HandleEvent => extensionstatus
11/13/11 21:49:44  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:46  TRACE0 HEADER: event DATA: Unlink
11/13/11 21:49:46  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:46  TRACE0 HEADER: channel1 DATA: IAX2/110-13966
11/13/11 21:49:46  TRACE0 HEADER: channel2 DATA: IAX2/113-1598
11/13/11 21:49:46  TRACE0 HEADER: uniqueid1 DATA: 1321220980.134
11/13/11 21:49:46  TRACE0 HEADER: uniqueid2 DATA: 1321220980.135
11/13/11 21:49:46  TRACE0 HEADER: callerid1 DATA: 110
11/13/11 21:49:46  TRACE0 HEADER: callerid2 DATA: 113
11/13/11 21:49:46  TRACE  ASTProvider::HandleEvent => unlink
11/13/11 21:49:46  TRACE   <== asterisk protocol event _______________________________
11/13/11 21:49:46  TRACE0 HEADER: event DATA: Hangup
11/13/11 21:49:46  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:46  TRACE0 HEADER: channel DATA: IAX2/113-1598
11/13/11 21:49:46  TRACE0 HEADER: uniqueid DATA: 1321220980.135
11/13/11 21:49:46  TRACE0 HEADER: calleridnum DATA: 113
11/13/11 21:49:46  TRACE0 HEADER: calleridname DATA: <unknown>
11/13/11 21:49:46  TRACE0 HEADER: cause DATA: 16
11/13/11 21:49:46  TRACE0 HEADER: cause-txt DATA: Normal Clearing
11/13/11 21:49:46  TRACE  ASTProvider::HandleEvent => hangup
11/13/11 21:49:46  TRACE  OnHangup:CFT: ev.m_uniqueId="1321220980.135"; ev.m_cause="16"; m_pxCstaProvider->OnHangupEvent(ev);
11/13/11 21:49:46  TRACE0 ASTCallMap::GetLogicCallId(0x34e83f8)
11/13/11 21:49:46  TRACE  GetStateOfDevice {3, 113}
11/13/11 21:49:46  TRACE     deviceState = CONNECTED
11/13/11 21:49:46  TRACE   callMap.size == 2
11/13/11 21:49:46  TRACE    handleConnectionDisconnected {1321220980.135} to 113
11/13/11 21:49:46  TRACE  ASTCallMap::GetLogicAddress(0x34e83f8)
11/13/11 21:49:46  TRACE  ASTCstaProvider::handleConnectionDisconnected uniqueId=1321220980.135, logicaddress=113, cause=0
11/13/11 21:49:46  TRACE0 ASTCallMap::GetLogicCallId(0x34e83f8)
11/13/11 21:49:46  TRACE0 ================================================================= start callmap dump…
11/13/11 21:49:46  TRACE0 DUMP OF ASTERISK CALLS MAP: {UNIQUEID} => call info:
11/13/11 21:49:46  TRACE0   {1321220980.134}.110 numDevice=110 callID=2 state=not known chann=IAX2/110-13966 CID=110 CIDName=fede ConLineNum= ConLineName= lastRedir= source= userData= cause=0
11/13/11 21:49:46  TRACE0   {1321220980.135}.113 numDevice=113 callID=3 state=not known chann=IAX2/113-1598 CID=113 CIDName=fede ConLineNum= ConLineName= lastRedir= source=CSTA1321220980.134 userData= cause=0
11/13/11 21:49:46  TRACE0 DUMP OF MONITOR CALLS MAP: {CALL_ID} => DEVICE: => STATE
11/13/11 21:49:46  TRACE0      => 110 => CONNECTED
11/13/11 21:49:46  TRACE0      => 113 => CONNECTED
11/13/11 21:49:46  TRACE0 ================================================================= end callmap dump…
11/13/11 21:49:46  TRACE  GetMonitorSetFromCallModel = 3
11/13/11 21:49:46  TRACE    num_monitors = 1
11/13/11 21:49:46  TRACE      sending event:CFTE:CONNCLEARED to xref=4, address=113, callid=3
11/13/11 21:49:46  TRACE  OnConnectionCleared xref=4 callId=3, releasingDevice=113 cause=0
11/13/11 21:49:46  TRACE   searching a TapiCall with callId 3 in tapiLine 0x352ef50
11/13/11 21:49:46  WARN     TapiCall {callId=3, hdriverline=0x352ef50} not in TSP-call-map so ignore event.
11/13/11 21:49:46  TRACE  RemoveConnection {3}=> 113
11/13/11 21:49:46  TRACE    removed uniqueId=1321220980.135 call from MAP
11/13/11 21:49:46  TRACE    handleCallDisconnected {3} was the last one
11/13/11 21:49:46  TRACE  GetMonitorSetFromCallModel = 3
11/13/11 21:49:46  TRACE    callerId not found
11/13/11 21:49:46  WARN     do not send EVENTS because not exist any monitors in call 3
11/13/11 21:49:46  TRACE  RemoveCall {3}
11/13/11 21:49:46  TRACE      {3} NOT IN CALL-MONITOR MAP
11/13/11 21:49:46  TRACE    removed entry with callId=3 from MAP
11/13/11 21:49:46  TRACE   <== asterisk protocol event _______________________________
11/13/11 21:49:46  TRACE0 HEADER: event DATA: Hangup
11/13/11 21:49:46  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:46  TRACE0 HEADER: channel DATA: IAX2/110-13966
11/13/11 21:49:46  TRACE0 HEADER: uniqueid DATA: 1321220980.134
11/13/11 21:49:46  TRACE0 HEADER: calleridnum DATA: 110
11/13/11 21:49:46  TRACE0 HEADER: calleridname DATA: fede
11/13/11 21:49:46  TRACE0 HEADER: cause DATA: 16
11/13/11 21:49:46  TRACE0 HEADER: cause-txt DATA: Normal Clearing
11/13/11 21:49:46  TRACE  ASTProvider::HandleEvent => hangup
11/13/11 21:49:46  TRACE  OnHangup:CFT: ev.m_uniqueId="1321220980.134"; ev.m_cause="16"; m_pxCstaProvider->OnHangupEvent(ev);
11/13/11 21:49:46  TRACE0 ASTCallMap::GetLogicCallId(0x34e79f8)
11/13/11 21:49:46  TRACE  GetStateOfDevice {2, 110}
11/13/11 21:49:46  TRACE     deviceState = CONNECTED
11/13/11 21:49:46  TRACE    handleConnectionDisconnected {1321220980.134} to 110
11/13/11 21:49:46  TRACE  ASTCallMap::GetLogicAddress(0x34e79f8)
11/13/11 21:49:46  TRACE  ASTCstaProvider::handleConnectionDisconnected uniqueId=1321220980.134, logicaddress=110, cause=0
11/13/11 21:49:46  TRACE0 ASTCallMap::GetLogicCallId(0x34e79f8)
11/13/11 21:49:46  TRACE0 ================================================================= start callmap dump…
11/13/11 21:49:46  TRACE0 DUMP OF ASTERISK CALLS MAP: {UNIQUEID} => call info:
11/13/11 21:49:46  TRACE0   {1321220980.134}.110 numDevice=110 callID=2 state=not known chann=IAX2/110-13966 CID=110 CIDName=fede ConLineNum= ConLineName= lastRedir= source= userData= cause=0
11/13/11 21:49:46  TRACE0 DUMP OF MONITOR CALLS MAP: {CALL_ID} => DEVICE: => STATE
11/13/11 21:49:46  TRACE0      => 110 => CONNECTED
11/13/11 21:49:46  TRACE0 ================================================================= end callmap dump…
11/13/11 21:49:46  TRACE  GetMonitorSetFromCallModel = 2
11/13/11 21:49:46  TRACE    num_monitors = 1
11/13/11 21:49:46  TRACE      sending event:CFTE:CONNCLEARED to xref=1, address=110, callid=2
11/13/11 21:49:46  TRACE  OnConnectionCleared xref=1 callId=2, releasingDevice=110 cause=0
11/13/11 21:49:46  TRACE   searching a TapiCall with callId 2 in tapiLine 0x352e490
11/13/11 21:49:46  WARN     TapiCall {callId=2, hdriverline=0x352e490} not in TSP-call-map so ignore event.
11/13/11 21:49:46  TRACE  RemoveConnection {2}=> 110
11/13/11 21:49:46  TRACE    removed uniqueId=1321220980.134 call from MAP
11/13/11 21:49:46  TRACE    handleCallDisconnected {2} was the last one
11/13/11 21:49:46  TRACE  GetMonitorSetFromCallModel = 2
11/13/11 21:49:46  TRACE    callerId not found
11/13/11 21:49:46  WARN     do not send EVENTS because not exist any monitors in call 2
11/13/11 21:49:46  TRACE  RemoveCall {2}
11/13/11 21:49:46  TRACE      {2} NOT IN CALL-MONITOR MAP
11/13/11 21:49:46  TRACE    removed entry with callId=2 from MAP
11/13/11 21:49:46  TRACE   <== asterisk protocol event _______________________________
11/13/11 21:49:46  TRACE0 HEADER: event DATA: ExtensionStatus
11/13/11 21:49:46  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:46  TRACE0 HEADER: exten DATA: 113
11/13/11 21:49:46  TRACE0 HEADER: context DATA: ext-local
11/13/11 21:49:46  TRACE0 HEADER: hint DATA: IAX2/113&Custom:DND113
11/13/11 21:49:46  TRACE0 HEADER: status DATA: 0
11/13/11 21:49:46  TRACE0 ASTProvider::HandleEvent => extensionstatus
11/13/11 21:49:46  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:46  TRACE0 HEADER: event DATA: ExtensionStatus
11/13/11 21:49:46  TRACE0 HEADER: privilege DATA: call,all
11/13/11 21:49:46  TRACE0 HEADER: exten DATA: 110
11/13/11 21:49:46  TRACE0 HEADER: context DATA: ext-local
11/13/11 21:49:46  TRACE0 HEADER: hint DATA: IAX2/110&Custom:DND110
11/13/11 21:49:46  TRACE0 HEADER: status DATA: 0
11/13/11 21:49:46  TRACE0 ASTProvider::HandleEvent => extensionstatus
11/13/11 21:49:46  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:50  TRACE0 HEADER: event DATA: PeerStatus
11/13/11 21:49:50  TRACE0 HEADER: privilege DATA: system,all
11/13/11 21:49:50  TRACE0 HEADER: channeltype DATA: IAX2
11/13/11 21:49:50  TRACE0 HEADER: peer DATA: IAX2/110
11/13/11 21:49:50  TRACE0 HEADER: peerstatus DATA: Registered
11/13/11 21:49:50  TRACE0 ASTProvider::HandleEvent => peerstatus
11/13/11 21:49:50  TRACE0  <== asterisk protocol event _______________________________
11/13/11 21:49:52  TRACE  TSPI_lineClose() hdLine=0x4
11/13/11 21:49:52  TRACE  RemoveTapiLine hdrvLine=0x4
11/13/11 21:49:52  TRACE    was 113
11/13/11 21:49:52  TRACE  ASTCstaProvider::CloseMonitor xref = 4
11/13/11 21:49:52  TRACE    erase xref map entry
11/13/11 21:49:52  TRACE      erase extension map entry
11/13/11 21:49:52  TRACE    return 1!
11/13/11 21:49:52  TRACE  TSPI_lineClose() hdLine=0x3
11/13/11 21:49:52  TRACE  RemoveTapiLine hdrvLine=0x3
11/13/11 21:49:52  TRACE    was 112
11/13/11 21:49:52  TRACE  ASTCstaProvider::CloseMonitor xref = 3
11/13/11 21:49:52  TRACE    erase xref map entry
11/13/11 21:49:52  TRACE      erase extension map entry
11/13/11 21:49:52  TRACE    return 1!
11/13/11 21:49:52  TRACE  TSPI_lineClose() hdLine=0x2
11/13/11 21:49:52  TRACE  RemoveTapiLine hdrvLine=0x2
11/13/11 21:49:52  TRACE    was 111
11/13/11 21:49:52  TRACE  ASTCstaProvider::CloseMonitor xref = 2
11/13/11 21:49:52  TRACE    erase xref map entry
11/13/11 21:49:52  TRACE      erase extension map entry
11/13/11 21:49:52  TRACE    return 1!
11/13/11 21:49:52  TRACE  TSPI_lineClose() hdLine=0x1
11/13/11 21:49:52  TRACE  RemoveTapiLine hdrvLine=0x1
11/13/11 21:49:52  TRACE    was 110
11/13/11 21:49:52  TRACE  ASTCstaProvider::CloseMonitor xref = 1
11/13/11 21:49:52  TRACE    erase xref map entry
11/13/11 21:49:52  TRACE      erase extension map entry
11/13/11 21:49:52  TRACE    return 1!
11/13/11 21:49:52  INFO   Disconnect socked and clear callmaps because no line is open.
11/13/11 21:49:52  INFO   Socket closed without errors.
11/13/11 21:49:52  INFO   Socket recv code = -1
11/13/11 21:49:52  INFO   Error code 10053, The virtual circuit was terminated due to a time-out or other failure. The application should close the socket as it is no longer usable.
11/13/11 21:49:52  TRACE  ASTProvider::ReaderProc EXITS
11/13/11 21:49:52  TRACE  WaitReaderThread => Thread terminated nicely

11/13/11 21:49:52  TRACE   CallMapCleanup() cleaning maps
11/13/11 21:49:52  TRACE  TSPI_providerShutdown()
11/13/11 21:49:52  TRACE  TSPI_providerShutdown()
11/13/11 21:49:52  TRACE   CallMapCleanup() cleaning maps
11/13/11 21:49:52  TRACE   CallMapCleanup() cleaning maps

Thanks,
Federico