I'm facing the problem is: When I use MS dialer (under Win2000 or XP Pro) to test the inbound call. It cannot show the caller id while Call Alerting event.
I use Activa TSP 1.6 under windows 2000 or XP. The version of my testing Asterisk is 1.6.2.18.
Below is a debug log that generated from TSP
07/13/11 00:41:11 TRACE Asterisk protocol header: Asterisk Call Manager/1.1
07/13/11 00:41:11 TRACE <== asterisk protocol response__________________________
07/13/11 00:41:11 TRACE Connect() returns ok
07/13/11 00:41:11 TRACE ASTCstaProvider::OpenMonitor device = 4004 => 4004
07/13/11 00:41:11 TRACE first monitor for this device: {4004,1}
07/13/11 00:41:11 TRACE AddTapiLine xref=1 htapiLine=0x10377 pTapiLine=0x28b83f0
07/13/11 00:41:11 TRACE TSPI_lineGetNumAddressIDs hdLine=0000000000000001
07/13/11 00:41:17 TRACE ASTProvider::HandleEvent => newchannel
07/13/11 00:41:17 TRACE OnNewChannelEvent:CFT: ev.m_uniqueId="1310488877.185"; ev.m_callerId="4002"; ev.m_callerIdName="Room"; ev.m_state="Down"; ev.m_channel="SIP/4002-00000081"; m_pxCstaProvider->OnNewChannelEvent(ev);
07/13/11 00:41:17 TRACE Create AsteriskCall with uniqueId = 1310488877.185 and callid =2
07/13/11 00:41:17 TRACE Call does not contains UserData
07/13/11 00:41:17 TRACE Call does not containsCallId
07/13/11 00:41:17 TRACE Call is NOT predictive
07/13/11 00:41:17 TRACE setting {1310488877.185}.callerID=4002, callerIdName=Room
07/13/11 00:41:17 TRACE setting {1310488877.185}.channel=SIP/4002-00000081, address=4002
07/13/11 00:41:17 TRACE state = DOWN => do nothing
07/13/11 00:41:17 TRACE <== asterisk protocol event _______________________________
07/13/11 00:41:17 TRACE ASTProvider::HandleEvent => newstate
07/13/11 00:41:17 TRACE OnNewStateEvent:CFT: ev.m_uniqueId="1310488877.185"; ev.m_callerIdName="Room"; ev.m_state="Ring"; ev.m_channel="SIP/4002-00000081"; m_pxCstaProvider->OnNewStateEvent(ev);
07/13/11 00:41:17 TRACE Call does not contains UserData
07/13/11 00:41:17 TRACE Call does not containsCallId
07/13/11 00:41:17 TRACE Call is NOT predictive
07/13/11 00:41:17 TRACE setting {1310488877.185}.callerID=4002, callerIdName=Room
07/13/11 00:41:17 TRACE state = RING => Send ORIGINATED to {1310488877.185}.address=4002
07/13/11 00:41:17 TRACE ASTCstaProvider::handleConnectionOriginated uniqueId=1310488877.185, address=4002
07/13/11 00:41:17 TRACE AddConnectionToCallModel {2, 4002} => INITIALIZED
07/13/11 00:41:17 TRACE done, now CALL map has 1 items
07/13/11 00:41:17 TRACE GetMonitorSetFromCallModel = 2
07/13/11 00:41:17 TRACE num_monitors = 0
07/13/11 00:41:17 TRACE do not send EVENTS because not exist any monitors in call 2
07/13/11 00:41:17 TRACE <== asterisk protocol event _______________________________
07/13/11 00:41:17 TRACE ASTProvider::HandleEvent => dial
07/13/11 00:41:17 TRACE <== asterisk protocol event _______________________________
07/13/11 00:41:17 TRACE ASTProvider::HandleEvent => newstate
07/13/11 00:41:17 TRACE OnNewStateEvent:CFT: ev.m_uniqueId="1310488877.185"; ev.m_callerIdName="Room"; ev.m_state="Busy"; ev.m_channel="SIP/4002-00000081"; m_pxCstaProvider->OnNewStateEvent(ev);
07/13/11 00:41:17 TRACE Call does not contains UserData
07/13/11 00:41:17 TRACE Call does not containsCallId
07/13/11 00:41:17 TRACE Call is NOT predictive
07/13/11 00:41:17 TRACE setting {1310488877.185}.callerID=4002, callerIdName=Room
07/13/11 00:41:17 TRACE state = BUSY => do nothing
07/13/11 00:41:17 TRACE <== asterisk protocol event _______________________________
07/13/11 00:41:17 TRACE ASTProvider::HandleEvent => hangup
07/13/11 00:41:17 TRACE OnHangup:CFT: ev.m_uniqueId="1310488877.185"; ev.m_cause="20"; m_pxCstaProvider->OnHangupEvent(ev);
07/13/11 00:41:17 TRACE GetStateOfDevice {2, 4002}
07/13/11 00:41:17 TRACE deviceState = INITIALIZED
07/13/11 00:41:17 TRACE handleConnectionDisconnected {1310488877.185} to 4002
07/13/11 00:41:17 TRACE ASTCallMap::GetLogicAddress(0x362d100)
07/13/11 00:41:17 TRACE ASTCstaProvider::handleConnectionDisconnected uniqueId=1310488877.185, logicaddress=4002, cause=-1
07/13/11 00:41:17 TRACE GetMonitorSetFromCallModel = 2
07/13/11 00:41:17 TRACE num_monitors = 0
07/13/11 00:41:17 WARN do not send EVENTS because not exist any monitors in call 2
07/13/11 00:41:17 TRACE RemoveConnection {2}=> 4002
07/13/11 00:41:17 TRACE removed uniqueId=1310488877.185 call from MAP
07/13/11 00:41:17 TRACE handleCallDisconnected {2} was the last one
07/13/11 00:41:17 TRACE GetMonitorSetFromCallModel = 2
07/13/11 00:41:17 TRACE callerId not found
07/13/11 00:41:17 WARN do not send EVENTS because not exist any monitors in call 2
07/13/11 00:41:17 TRACE RemoveCall {2}
07/13/11 00:41:17 TRACE {2} NOT IN CALL-MONITOR MAP
07/13/11 00:41:17 TRACE removed entry with callId=2 from MAP
07/13/11 00:41:17 TRACE <== asterisk protocol event _______________________________
07/13/11 00:41:41 TRACE ASTProvider::HandleEvent => newchannel
07/13/11 00:41:41 TRACE OnNewChannelEvent:CFT: ev.m_uniqueId="1310488901.186"; ev.m_callerId="4002"; ev.m_callerIdName="Room"; ev.m_state="Down"; ev.m_channel="SIP/4002-00000082"; m_pxCstaProvider->OnNewChannelEvent(ev);
07/13/11 00:41:41 TRACE Create AsteriskCall with uniqueId = 1310488901.186 and callid =3
07/13/11 00:41:41 TRACE Call does not contains UserData
07/13/11 00:41:41 TRACE Call does not containsCallId
07/13/11 00:41:41 TRACE Call is NOT predictive
07/13/11 00:41:41 TRACE setting {1310488901.186}.callerID=4002, callerIdName=Room
07/13/11 00:41:41 TRACE setting {1310488901.186}.channel=SIP/4002-00000082, address=4002
07/13/11 00:41:41 TRACE state = DOWN => do nothing
07/13/11 00:41:41 TRACE <== asterisk protocol event _______________________________
07/13/11 00:41:41 TRACE ASTProvider::HandleEvent => newstate
07/13/11 00:41:41 TRACE OnNewStateEvent:CFT: ev.m_uniqueId="1310488901.186"; ev.m_callerIdName="Room"; ev.m_state="Ring"; ev.m_channel="SIP/4002-00000082"; m_pxCstaProvider->OnNewStateEvent(ev);
07/13/11 00:41:41 TRACE Call does not contains UserData
07/13/11 00:41:41 TRACE Call does not containsCallId
07/13/11 00:41:41 TRACE Call is NOT predictive
07/13/11 00:41:41 TRACE setting {1310488901.186}.callerID=4002, callerIdName=Room
07/13/11 00:41:41 TRACE state = RING => Send ORIGINATED to {1310488901.186}.address=4002
07/13/11 00:41:41 TRACE ASTCstaProvider::handleConnectionOriginated uniqueId=1310488901.186, address=4002
07/13/11 00:41:41 TRACE AddConnectionToCallModel {3, 4002} => INITIALIZED
07/13/11 00:41:41 TRACE done, now CALL map has 1 items
07/13/11 00:41:41 TRACE GetMonitorSetFromCallModel = 3
07/13/11 00:41:41 TRACE num_monitors = 0
07/13/11 00:41:41 TRACE do not send EVENTS because not exist any monitors in call 3
07/13/11 00:41:41 TRACE <== asterisk protocol event _______________________________
07/13/11 00:41:41 TRACE ASTProvider::HandleEvent => newchannel
07/13/11 00:41:41 TRACE OnNewChannelEvent:CFT: ev.m_uniqueId="1310488901.187"; ev.m_callerId=""; ev.m_callerIdName=""; ev.m_state="Down"; ev.m_channel="SIP/4004-00000083"; m_pxCstaProvider->OnNewChannelEvent(ev);
07/13/11 00:41:41 TRACE Create AsteriskCall with uniqueId = 1310488901.187 and callid =4
07/13/11 00:41:41 TRACE setting {1310488901.187}.callerID=, callerIdName=
07/13/11 00:41:41 TRACE setting {1310488901.187}.channel=SIP/4004-00000083, address=4004
07/13/11 00:41:42 TRACE state = DOWN => do nothing
07/13/11 00:41:42 TRACE <== asterisk protocol event _______________________________
07/13/11 00:41:42 TRACE ASTProvider::HandleEvent => dial
07/13/11 00:41:42 TRACE OnDialEvent:CFT: ev.m_srcUniqueId="1310488901.186"; ev.m_destUniqueId="1310488901.187"; ev.m_callerIdName="Room"; ev.m_callerId="4002"; m_pxCstaProvider->OnDialEvent(ev);
07/13/11 00:41:42 TRACE linked calls {1310488901.186} <- {1310488901.187}
07/13/11 00:41:42 TRACE Call does not contains UserData
07/13/11 00:41:42 TRACE Call does not containsCallId
07/13/11 00:41:42 TRACE Call is NOT predictive
07/13/11 00:41:42 TRACE Dial event don't contain callid, we try to get it using GetLogicCallId
07/13/11 00:41:42 TRACE Call logicCallId(): 3
07/13/11 00:41:42 TRACE GetMonitorSetFromCallModel = 4
07/13/11 00:41:42 TRACE callerId not found
07/13/11 00:41:42 TRACE overriding {1310488901.187}.4 to new callId 3
07/13/11 00:41:42 TRACE RemoveCall {4}
07/13/11 00:41:42 TRACE {4} NOT IN CALL-MONITOR MAP
07/13/11 00:41:42 TRACE overriding {1310488901.186}. to new callerid 4002
07/13/11 00:41:42 TRACE <== asterisk protocol event _______________________________
07/13/11 00:41:42 TRACE ASTProvider::HandleEvent => newcallerid
07/13/11 00:41:42 TRACE OnNewCallerIdEvent:CFT: ev.m_uniqueId="1310488901.187"; ev.m_callerId="4004"; ev.m_callerIdName=""; m_pxCstaProvider->OnNewCallerIdEvent(ev);
07/13/11 00:41:42 TRACE overriding {1310488901.187}. to new callerId 4004
07/13/11 00:41:42 TRACE <== asterisk protocol event _______________________________
07/13/11 00:41:42 TRACE ASTProvider::HandleEvent => newstate
07/13/11 00:41:42 TRACE OnNewStateEvent:CFT: ev.m_uniqueId="1310488901.187"; ev.m_callerIdName=""; ev.m_state="Ringing"; ev.m_channel="SIP/4004-00000083"; m_pxCstaProvider->OnNewStateEvent(ev);
07/13/11 00:41:42 TRACE state = RINGING => Send ALERTING to {1310488901.187}.address=4004
07/13/11 00:41:42 TRACE ASTCstaProvider::handleConnectionAlerting uniqueId=1310488901.187, address=4004
07/13/11 00:41:42 TRACE ASTCallMap::GetSourceCall(0x362b5c0)
07/13/11 00:41:42 TRACE SourceCall is 1310488901.186
07/13/11 00:41:42 TRACE GetCIDInfoFromSourceCall(1310488901.187)
07/13/11 00:41:42 TRACE Exiting with cid/cidname/userData=4002/Room/
07/13/11 00:41:42 TRACE AddConnectionToCallModel {3, 4004} => ALERTING
07/13/11 00:41:42 TRACE done, now CALL map has 1 items
07/13/11 00:41:42 TRACE overriding calledNumber from 4004 => 4004
07/13/11 00:41:42 TRACE source call is {1310488901.186} and lastRedirection=
07/13/11 00:41:42 TRACE GetMonitorSetFromCallModel = 3
07/13/11 00:41:42 TRACE num_monitors = 1
07/13/11 00:41:42 TRACE sending event:CFTE:ALERTING to xref=1, address=4004, callid=3, lastRedirection=, userData=
07/13/11 00:41:42 TRACE OnAlerting xref=1 callId=3, alertingDevice=4004, callerId=4002, callerIdName=Room, calledID=4004 userData= cause=0
07/13/11 00:41:42 TRACE searching a TapiCall with callId 3 in tapiLine 0x28b83f0
07/13/11 00:41:42 TRACE LINE_NEWCALL
07/13/11 00:41:42 TRACE ASTTapiProvider::AddTapiCall pNewTapiCall=0x28bfda0 callId=3, htapicall=0x10366, callerId=4002, calledId=4004 userData=
07/13/11 00:41:42 TRACE first TapiCall for this callid: => 0x28bfda0
07/13/11 00:41:42 TRACE alertingDevice callerid = 4004
07/13/11 00:41:42 TRACE htapiline=0x10377, deviceID=4004, htapicall=0x10366, callerid=4002, callerIdName=Room, calleddevice=4004, lastRedirection= userData=
07/13/11 00:41:42 TRACE LINECALLSTATE_OFFERING htapicall=0x10366
07/13/11 00:41:42 TRACE <== asterisk protocol event _______________________________
07/13/11 00:41:42 TRACE TSPI_lineGetCallInfo hdCall=0x28bfda0 callerId=4002, callerIdName=Room, calledId=4004, calledIdName=4004, connectedId=4002, connectedIdName=Room, redirectingId=, redirectingIdName=, redirectionId=4004, userData=, isPredictive=0, dwOrigin=0x80
07/13/11 00:41:42 TRACE TSPI_lineGetCallInfo hdCall=0x28bfda0 callerId=4002, callerIdName=Room, calledId=4004, calledIdName=4004, connectedId=4002, connectedIdName=Room, redirectingId=, redirectingIdName=, redirectionId=4004, userData=, isPredictive=0, dwOrigin=0x80
07/13/11 00:41:42 TRACE TSPI_lineAccept hdCall=00000000028BFDA0
07/13/11 00:41:42 TRACE TSPI_lineGetCallInfo hdCall=0x28bfda0 callerId=4002, callerIdName=Room, calledId=4004, calledIdName=4004, connectedId=4002, connectedIdName=Room, redirectingId=, redirectingIdName=, redirectionId=4004, userData=, isPredictive=0, dwOrigin=0x80
07/13/11 00:41:44 TRACE ASTProvider::HandleEvent => newstate
07/13/11 00:41:44 TRACE OnNewStateEvent:CFT: ev.m_uniqueId="1310488901.187"; ev.m_callerIdName=""; ev.m_state="Up"; ev.m_channel="SIP/4004-00000083"; m_pxCstaProvider->OnNewStateEvent(ev);
07/13/11 00:41:44 TRACE state = UP => Send ESTABLISHED to {1310488901.187}.address=4004
07/13/11 00:41:44 TRACE ASTCstaProvider::handleConnectionConnected uniqueId=1310488901.187, address=4004
07/13/11 00:41:44 TRACE ASTCallMap::GetSourceCall(0x362b5c0)
07/13/11 00:41:44 TRACE SourceCall is 1310488901.186
07/13/11 00:41:44 TRACE GetCIDInfoFromSourceCall(1310488901.187)
07/13/11 00:41:44 TRACE Exiting with cid/cidname/userData=4002/Room/
07/13/11 00:41:44 TRACE AddConnectionToCallModel {3, 4004} => CONNECTED
07/13/11 00:41:44 TRACE done, now CALL map has 1 items
07/13/11 00:41:44 TRACE source call is {1310488901.186} and lastRedirection=
07/13/11 00:41:44 TRACE GetMonitorSetFromCallModel = 3
07/13/11 00:41:44 TRACE num_monitors = 1
07/13/11 00:41:44 TRACE sending event:CFTE:ESTABLISHED to xref=1, address=4004, callid=3, lastRedirection=, userData=
07/13/11 00:41:44 TRACE OnEstablished xref=1 callId=3, establishedDevice=4004, callerId=4002, callerIdName=Room, calledDevice =4004, lastRedirectingDevice=, userData= cause=0
07/13/11 00:41:44 TRACE searching a TapiCall with callId 3 in tapiLine 0x28b83f0
07/13/11 00:41:44 TRACE htapiline=0x10377, deviceID=4004, htapicall=0x10366, callerid=4002, callerIdName=Room, calleddevice=4004, lastRedirection=, userData=
07/13/11 00:41:44 TRACE LINECALLSTATE_CONNECTED htapicall=0x10366
07/13/11 00:41:44 TRACE <== asterisk protocol event _______________________________
07/13/11 00:41:44 TRACE ASTProvider::HandleEvent => newstate
07/13/11 00:41:44 TRACE OnNewStateEvent:CFT: ev.m_uniqueId="1310488901.186"; ev.m_callerIdName="Room"; ev.m_state="Up"; ev.m_channel="SIP/4002-00000082"; m_pxCstaProvider->OnNewStateEvent(ev);
07/13/11 00:41:44 TRACE Call does not contains UserData
07/13/11 00:41:44 TRACE Call does not containsCallId
07/13/11 00:41:44 TRACE Call is NOT predictive
07/13/11 00:41:44 TRACE setting {1310488901.186}.callerID=4002, callerIdName=Room
07/13/11 00:41:44 TRACE state = UP => Send ESTABLISHED to {1310488901.186}.address=4002
07/13/11 00:41:44 TRACE ASTCstaProvider::handleConnectionConnected uniqueId=1310488901.186, address=4002
07/13/11 00:41:44 TRACE ASTCallMap::GetSourceCall(0x362d100)
07/13/11 00:41:44 TRACE SourceCall is 1310488901.186
07/13/11 00:41:44 TRACE GetCIDInfoFromSourceCall(1310488901.186)
07/13/11 00:41:44 TRACE Exiting with cid/cidname/userData=4002/Room/
07/13/11 00:41:44 TRACE event minimization RULE-8: Do not send ESTABLISHED if there is a destination call: second established is wrong (indicates audio is up but established was already sent)
07/13/11 00:41:44 TRACE <== asterisk protocol event _______________________________
07/13/11 00:41:44 TRACE ASTProvider::HandleEvent => bridge
07/13/11 00:41:44 TRACE OnLinkEvent:CFT: ev.m_srcUniqueId="1310488901.186"; ev.m_destUniqueId="1310488901.187"; m_pxCstaProvider->OnLinkEvent(ev);
07/13/11 00:41:44 TRACE set {1310488901.187}.lastRedirectionDevice=
07/13/11 00:41:44 TRACE <== asterisk protocol event _______________________________
07/13/11 00:41:44 TRACE TSPI_lineGetCallInfo hdCall=0x28bfda0 callerId=4002, callerIdName=Room, calledId=4004, calledIdName=4004, connectedId=4002, connectedIdName=Room, redirectingId=, redirectingIdName=, redirectionId=4004, userData=, isPredictive=0, dwOrigin=0x80
07/13/11 00:41:46 TRACE ASTProvider::HandleEvent => unlink
07/13/11 00:41:46 TRACE <== asterisk protocol event _______________________________
07/13/11 00:41:46 TRACE ASTProvider::HandleEvent => hangup
07/13/11 00:41:46 TRACE OnHangup:CFT: ev.m_uniqueId="1310488901.187"; ev.m_cause="16"; m_pxCstaProvider->OnHangupEvent(ev);
07/13/11 00:41:46 TRACE GetStateOfDevice {3, 4002}
07/13/11 00:41:46 TRACE deviceState = INITIALIZED
07/13/11 00:41:46 TRACE callMap.size == 2
07/13/11 00:41:46 TRACE handleConnectionDisconnected {1310488901.187} to 4004
07/13/11 00:41:46 TRACE ASTCallMap::GetLogicAddress(0x362b5c0)
07/13/11 00:41:46 TRACE ASTCstaProvider::handleConnectionDisconnected uniqueId=1310488901.187, logicaddress=4004, cause=0
07/13/11 00:41:46 TRACE GetMonitorSetFromCallModel = 3
07/13/11 00:41:46 TRACE num_monitors = 1
07/13/11 00:41:46 TRACE sending event:CFTE:CONNCLEARED to xref=1, address=4004, callid=3
07/13/11 00:41:46 TRACE OnConnectionCleared xref=1 callId=3, releasingDevice=4004 cause=0
07/13/11 00:41:46 TRACE searching a TapiCall with callId 3 in tapiLine 0x28b83f0
07/13/11 00:41:46 TRACE htapiline=0x10377, deviceID=4004, htapicall=0x10366, releasingDevice=4004, callerid=N/A, callerIdName=N/A, calleddevice=N/A, lastRedirection=N/A
07/13/11 00:41:46 TRACE LINECALLSTATE_IDLE NORMAL htapicall=0x10366
07/13/11 00:41:46 TRACE RemoveConnection {3}=> 4004
07/13/11 00:41:46 TRACE removed uniqueId=1310488901.187 call from MAP
07/13/11 00:41:46 TRACE <== asterisk protocol event _______________________________
07/13/11 00:41:46 TRACE ASTProvider::HandleEvent => dial
07/13/11 00:41:46 TRACE <== asterisk protocol event _______________________________
07/13/11 00:41:46 TRACE ASTProvider::HandleEvent => hangup
07/13/11 00:41:46 TRACE OnHangup:CFT: ev.m_uniqueId="1310488901.186"; ev.m_cause="16"; m_pxCstaProvider->OnHangupEvent(ev);
07/13/11 00:41:46 TRACE GetStateOfDevice {3, 4002}
07/13/11 00:41:46 TRACE deviceState = INITIALIZED
07/13/11 00:41:46 TRACE handleConnectionDisconnected {1310488901.186} to 4002
07/13/11 00:41:46 TRACE ASTCallMap::GetLogicAddress(0x362d100)
07/13/11 00:41:46 TRACE ASTCstaProvider::handleConnectionDisconnected uniqueId=1310488901.186, logicaddress=4002, cause=0
07/13/11 00:41:46 TRACE GetMonitorSetFromCallModel = 3
07/13/11 00:41:46 TRACE num_monitors = 0
07/13/11 00:41:46 WARN do not send EVENTS because not exist any monitors in call 3
07/13/11 00:41:46 TRACE RemoveConnection {3}=> 4002
07/13/11 00:41:46 TRACE removed uniqueId=1310488901.186 call from MAP
07/13/11 00:41:46 TRACE handleCallDisconnected {3} was the last one
07/13/11 00:41:46 TRACE GetMonitorSetFromCallModel = 3
07/13/11 00:41:46 TRACE callerId not found
07/13/11 00:41:46 WARN do not send EVENTS because not exist any monitors in call 3
07/13/11 00:41:46 TRACE RemoveCall {3}
07/13/11 00:41:46 TRACE {3} NOT IN CALL-MONITOR MAP
07/13/11 00:41:46 TRACE removed entry with callId=3 from MAP
07/13/11 00:41:46 TRACE <== asterisk protocol event _______________________________
07/13/11 00:41:46 TRACE TSPI_lineCloseCall() hdCall=0x28bfda0
07/13/11 00:41:46 TRACE ASTTapiProvider::RemoveTapiCall hdrivercall=0x28bfda0
07/13/11 00:41:46 TRACE call had callid=3
07/13/11 00:41:46 TRACE …with 1 associated hdrvrcalls
07/13/11 00:41:46 TRACE delete htcall 0x10366 and hdrvCall 0x28bfda0
07/13/11 00:41:46 TRACE deleted the last htapicall and the set of callid 3
07/13/11 00:41:46 TRACE deleting pTapiCall addrs=4004 htapiCall=0x10366
07/13/11 00:41:48 TRACE TSPI_lineClose() hdLine=0x1
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
I'm facing the problem is: When I use MS dialer (under Win2000 or XP Pro) to test the inbound call. It cannot show the caller id while Call Alerting event.
I use Activa TSP 1.6 under windows 2000 or XP. The version of my testing Asterisk is 1.6.2.18.
Below is a debug log that generated from TSP
07/13/11 00:41:11 TRACE Asterisk protocol header: Asterisk Call Manager/1.1
07/13/11 00:41:11 TRACE <== asterisk protocol response__________________________
07/13/11 00:41:11 TRACE Connect() returns ok
07/13/11 00:41:11 TRACE ASTCstaProvider::OpenMonitor device = 4004 => 4004
07/13/11 00:41:11 TRACE first monitor for this device: {4004,1}
07/13/11 00:41:11 TRACE AddTapiLine xref=1 htapiLine=0x10377 pTapiLine=0x28b83f0
07/13/11 00:41:11 TRACE TSPI_lineGetNumAddressIDs hdLine=0000000000000001
07/13/11 00:41:17 TRACE ASTProvider::HandleEvent => newchannel
07/13/11 00:41:17 TRACE OnNewChannelEvent:CFT: ev.m_uniqueId="1310488877.185"; ev.m_callerId="4002"; ev.m_callerIdName="Room"; ev.m_state="Down"; ev.m_channel="SIP/4002-00000081"; m_pxCstaProvider->OnNewChannelEvent(ev);
07/13/11 00:41:17 TRACE Create AsteriskCall with uniqueId = 1310488877.185 and callid =2
07/13/11 00:41:17 TRACE Call does not contains UserData
07/13/11 00:41:17 TRACE Call does not containsCallId
07/13/11 00:41:17 TRACE Call is NOT predictive
07/13/11 00:41:17 TRACE setting {1310488877.185}.callerID=4002, callerIdName=Room
07/13/11 00:41:17 TRACE setting {1310488877.185}.channel=SIP/4002-00000081, address=4002
07/13/11 00:41:17 TRACE state = DOWN => do nothing
07/13/11 00:41:17 TRACE <== asterisk protocol event _______________________________
07/13/11 00:41:17 TRACE ASTProvider::HandleEvent => newstate
07/13/11 00:41:17 TRACE OnNewStateEvent:CFT: ev.m_uniqueId="1310488877.185"; ev.m_callerIdName="Room"; ev.m_state="Ring"; ev.m_channel="SIP/4002-00000081"; m_pxCstaProvider->OnNewStateEvent(ev);
07/13/11 00:41:17 TRACE Call does not contains UserData
07/13/11 00:41:17 TRACE Call does not containsCallId
07/13/11 00:41:17 TRACE Call is NOT predictive
07/13/11 00:41:17 TRACE setting {1310488877.185}.callerID=4002, callerIdName=Room
07/13/11 00:41:17 TRACE state = RING => Send ORIGINATED to {1310488877.185}.address=4002
07/13/11 00:41:17 TRACE ASTCstaProvider::handleConnectionOriginated uniqueId=1310488877.185, address=4002
07/13/11 00:41:17 TRACE AddConnectionToCallModel {2, 4002} => INITIALIZED
07/13/11 00:41:17 TRACE done, now CALL map has 1 items
07/13/11 00:41:17 TRACE GetMonitorSetFromCallModel = 2
07/13/11 00:41:17 TRACE num_monitors = 0
07/13/11 00:41:17 TRACE do not send EVENTS because not exist any monitors in call 2
07/13/11 00:41:17 TRACE <== asterisk protocol event _______________________________
07/13/11 00:41:17 TRACE ASTProvider::HandleEvent => dial
07/13/11 00:41:17 TRACE <== asterisk protocol event _______________________________
07/13/11 00:41:17 TRACE ASTProvider::HandleEvent => newstate
07/13/11 00:41:17 TRACE OnNewStateEvent:CFT: ev.m_uniqueId="1310488877.185"; ev.m_callerIdName="Room"; ev.m_state="Busy"; ev.m_channel="SIP/4002-00000081"; m_pxCstaProvider->OnNewStateEvent(ev);
07/13/11 00:41:17 TRACE Call does not contains UserData
07/13/11 00:41:17 TRACE Call does not containsCallId
07/13/11 00:41:17 TRACE Call is NOT predictive
07/13/11 00:41:17 TRACE setting {1310488877.185}.callerID=4002, callerIdName=Room
07/13/11 00:41:17 TRACE state = BUSY => do nothing
07/13/11 00:41:17 TRACE <== asterisk protocol event _______________________________
07/13/11 00:41:17 TRACE ASTProvider::HandleEvent => hangup
07/13/11 00:41:17 TRACE OnHangup:CFT: ev.m_uniqueId="1310488877.185"; ev.m_cause="20"; m_pxCstaProvider->OnHangupEvent(ev);
07/13/11 00:41:17 TRACE GetStateOfDevice {2, 4002}
07/13/11 00:41:17 TRACE deviceState = INITIALIZED
07/13/11 00:41:17 TRACE handleConnectionDisconnected {1310488877.185} to 4002
07/13/11 00:41:17 TRACE ASTCallMap::GetLogicAddress(0x362d100)
07/13/11 00:41:17 TRACE ASTCstaProvider::handleConnectionDisconnected uniqueId=1310488877.185, logicaddress=4002, cause=-1
07/13/11 00:41:17 TRACE GetMonitorSetFromCallModel = 2
07/13/11 00:41:17 TRACE num_monitors = 0
07/13/11 00:41:17 WARN do not send EVENTS because not exist any monitors in call 2
07/13/11 00:41:17 TRACE RemoveConnection {2}=> 4002
07/13/11 00:41:17 TRACE removed uniqueId=1310488877.185 call from MAP
07/13/11 00:41:17 TRACE handleCallDisconnected {2} was the last one
07/13/11 00:41:17 TRACE GetMonitorSetFromCallModel = 2
07/13/11 00:41:17 TRACE callerId not found
07/13/11 00:41:17 WARN do not send EVENTS because not exist any monitors in call 2
07/13/11 00:41:17 TRACE RemoveCall {2}
07/13/11 00:41:17 TRACE {2} NOT IN CALL-MONITOR MAP
07/13/11 00:41:17 TRACE removed entry with callId=2 from MAP
07/13/11 00:41:17 TRACE <== asterisk protocol event _______________________________
07/13/11 00:41:41 TRACE ASTProvider::HandleEvent => newchannel
07/13/11 00:41:41 TRACE OnNewChannelEvent:CFT: ev.m_uniqueId="1310488901.186"; ev.m_callerId="4002"; ev.m_callerIdName="Room"; ev.m_state="Down"; ev.m_channel="SIP/4002-00000082"; m_pxCstaProvider->OnNewChannelEvent(ev);
07/13/11 00:41:41 TRACE Create AsteriskCall with uniqueId = 1310488901.186 and callid =3
07/13/11 00:41:41 TRACE Call does not contains UserData
07/13/11 00:41:41 TRACE Call does not containsCallId
07/13/11 00:41:41 TRACE Call is NOT predictive
07/13/11 00:41:41 TRACE setting {1310488901.186}.callerID=4002, callerIdName=Room
07/13/11 00:41:41 TRACE setting {1310488901.186}.channel=SIP/4002-00000082, address=4002
07/13/11 00:41:41 TRACE state = DOWN => do nothing
07/13/11 00:41:41 TRACE <== asterisk protocol event _______________________________
07/13/11 00:41:41 TRACE ASTProvider::HandleEvent => newstate
07/13/11 00:41:41 TRACE OnNewStateEvent:CFT: ev.m_uniqueId="1310488901.186"; ev.m_callerIdName="Room"; ev.m_state="Ring"; ev.m_channel="SIP/4002-00000082"; m_pxCstaProvider->OnNewStateEvent(ev);
07/13/11 00:41:41 TRACE Call does not contains UserData
07/13/11 00:41:41 TRACE Call does not containsCallId
07/13/11 00:41:41 TRACE Call is NOT predictive
07/13/11 00:41:41 TRACE setting {1310488901.186}.callerID=4002, callerIdName=Room
07/13/11 00:41:41 TRACE state = RING => Send ORIGINATED to {1310488901.186}.address=4002
07/13/11 00:41:41 TRACE ASTCstaProvider::handleConnectionOriginated uniqueId=1310488901.186, address=4002
07/13/11 00:41:41 TRACE AddConnectionToCallModel {3, 4002} => INITIALIZED
07/13/11 00:41:41 TRACE done, now CALL map has 1 items
07/13/11 00:41:41 TRACE GetMonitorSetFromCallModel = 3
07/13/11 00:41:41 TRACE num_monitors = 0
07/13/11 00:41:41 TRACE do not send EVENTS because not exist any monitors in call 3
07/13/11 00:41:41 TRACE <== asterisk protocol event _______________________________
07/13/11 00:41:41 TRACE ASTProvider::HandleEvent => newchannel
07/13/11 00:41:41 TRACE OnNewChannelEvent:CFT: ev.m_uniqueId="1310488901.187"; ev.m_callerId=""; ev.m_callerIdName=""; ev.m_state="Down"; ev.m_channel="SIP/4004-00000083"; m_pxCstaProvider->OnNewChannelEvent(ev);
07/13/11 00:41:41 TRACE Create AsteriskCall with uniqueId = 1310488901.187 and callid =4
07/13/11 00:41:41 TRACE setting {1310488901.187}.callerID=, callerIdName=
07/13/11 00:41:41 TRACE setting {1310488901.187}.channel=SIP/4004-00000083, address=4004
07/13/11 00:41:42 TRACE state = DOWN => do nothing
07/13/11 00:41:42 TRACE <== asterisk protocol event _______________________________
07/13/11 00:41:42 TRACE ASTProvider::HandleEvent => dial
07/13/11 00:41:42 TRACE OnDialEvent:CFT: ev.m_srcUniqueId="1310488901.186"; ev.m_destUniqueId="1310488901.187"; ev.m_callerIdName="Room"; ev.m_callerId="4002"; m_pxCstaProvider->OnDialEvent(ev);
07/13/11 00:41:42 TRACE linked calls {1310488901.186} <- {1310488901.187}
07/13/11 00:41:42 TRACE Call does not contains UserData
07/13/11 00:41:42 TRACE Call does not containsCallId
07/13/11 00:41:42 TRACE Call is NOT predictive
07/13/11 00:41:42 TRACE Dial event don't contain callid, we try to get it using GetLogicCallId
07/13/11 00:41:42 TRACE Call logicCallId(): 3
07/13/11 00:41:42 TRACE GetMonitorSetFromCallModel = 4
07/13/11 00:41:42 TRACE callerId not found
07/13/11 00:41:42 TRACE overriding {1310488901.187}.4 to new callId 3
07/13/11 00:41:42 TRACE RemoveCall {4}
07/13/11 00:41:42 TRACE {4} NOT IN CALL-MONITOR MAP
07/13/11 00:41:42 TRACE overriding {1310488901.186}. to new callerid 4002
07/13/11 00:41:42 TRACE <== asterisk protocol event _______________________________
07/13/11 00:41:42 TRACE ASTProvider::HandleEvent => newcallerid
07/13/11 00:41:42 TRACE OnNewCallerIdEvent:CFT: ev.m_uniqueId="1310488901.187"; ev.m_callerId="4004"; ev.m_callerIdName=""; m_pxCstaProvider->OnNewCallerIdEvent(ev);
07/13/11 00:41:42 TRACE overriding {1310488901.187}. to new callerId 4004
07/13/11 00:41:42 TRACE <== asterisk protocol event _______________________________
07/13/11 00:41:42 TRACE ASTProvider::HandleEvent => newstate
07/13/11 00:41:42 TRACE OnNewStateEvent:CFT: ev.m_uniqueId="1310488901.187"; ev.m_callerIdName=""; ev.m_state="Ringing"; ev.m_channel="SIP/4004-00000083"; m_pxCstaProvider->OnNewStateEvent(ev);
07/13/11 00:41:42 TRACE state = RINGING => Send ALERTING to {1310488901.187}.address=4004
07/13/11 00:41:42 TRACE ASTCstaProvider::handleConnectionAlerting uniqueId=1310488901.187, address=4004
07/13/11 00:41:42 TRACE ASTCallMap::GetSourceCall(0x362b5c0)
07/13/11 00:41:42 TRACE SourceCall is 1310488901.186
07/13/11 00:41:42 TRACE GetCIDInfoFromSourceCall(1310488901.187)
07/13/11 00:41:42 TRACE Exiting with cid/cidname/userData=4002/Room/
07/13/11 00:41:42 TRACE AddConnectionToCallModel {3, 4004} => ALERTING
07/13/11 00:41:42 TRACE done, now CALL map has 1 items
07/13/11 00:41:42 TRACE overriding calledNumber from 4004 => 4004
07/13/11 00:41:42 TRACE source call is {1310488901.186} and lastRedirection=
07/13/11 00:41:42 TRACE GetMonitorSetFromCallModel = 3
07/13/11 00:41:42 TRACE num_monitors = 1
07/13/11 00:41:42 TRACE sending event:CFTE:ALERTING to xref=1, address=4004, callid=3, lastRedirection=, userData=
07/13/11 00:41:42 TRACE OnAlerting xref=1 callId=3, alertingDevice=4004, callerId=4002, callerIdName=Room, calledID=4004 userData= cause=0
07/13/11 00:41:42 TRACE searching a TapiCall with callId 3 in tapiLine 0x28b83f0
07/13/11 00:41:42 TRACE LINE_NEWCALL
07/13/11 00:41:42 TRACE ASTTapiProvider::AddTapiCall pNewTapiCall=0x28bfda0 callId=3, htapicall=0x10366, callerId=4002, calledId=4004 userData=
07/13/11 00:41:42 TRACE first TapiCall for this callid: => 0x28bfda0
07/13/11 00:41:42 TRACE alertingDevice callerid = 4004
07/13/11 00:41:42 TRACE htapiline=0x10377, deviceID=4004, htapicall=0x10366, callerid=4002, callerIdName=Room, calleddevice=4004, lastRedirection= userData=
07/13/11 00:41:42 TRACE LINECALLSTATE_OFFERING htapicall=0x10366
07/13/11 00:41:42 TRACE <== asterisk protocol event _______________________________
07/13/11 00:41:42 TRACE TSPI_lineGetCallInfo hdCall=0x28bfda0 callerId=4002, callerIdName=Room, calledId=4004, calledIdName=4004, connectedId=4002, connectedIdName=Room, redirectingId=, redirectingIdName=, redirectionId=4004, userData=, isPredictive=0, dwOrigin=0x80
07/13/11 00:41:42 TRACE TSPI_lineGetCallInfo hdCall=0x28bfda0 callerId=4002, callerIdName=Room, calledId=4004, calledIdName=4004, connectedId=4002, connectedIdName=Room, redirectingId=, redirectingIdName=, redirectionId=4004, userData=, isPredictive=0, dwOrigin=0x80
07/13/11 00:41:42 TRACE TSPI_lineAccept hdCall=00000000028BFDA0
07/13/11 00:41:42 TRACE TSPI_lineGetCallInfo hdCall=0x28bfda0 callerId=4002, callerIdName=Room, calledId=4004, calledIdName=4004, connectedId=4002, connectedIdName=Room, redirectingId=, redirectingIdName=, redirectionId=4004, userData=, isPredictive=0, dwOrigin=0x80
07/13/11 00:41:44 TRACE ASTProvider::HandleEvent => newstate
07/13/11 00:41:44 TRACE OnNewStateEvent:CFT: ev.m_uniqueId="1310488901.187"; ev.m_callerIdName=""; ev.m_state="Up"; ev.m_channel="SIP/4004-00000083"; m_pxCstaProvider->OnNewStateEvent(ev);
07/13/11 00:41:44 TRACE state = UP => Send ESTABLISHED to {1310488901.187}.address=4004
07/13/11 00:41:44 TRACE ASTCstaProvider::handleConnectionConnected uniqueId=1310488901.187, address=4004
07/13/11 00:41:44 TRACE ASTCallMap::GetSourceCall(0x362b5c0)
07/13/11 00:41:44 TRACE SourceCall is 1310488901.186
07/13/11 00:41:44 TRACE GetCIDInfoFromSourceCall(1310488901.187)
07/13/11 00:41:44 TRACE Exiting with cid/cidname/userData=4002/Room/
07/13/11 00:41:44 TRACE AddConnectionToCallModel {3, 4004} => CONNECTED
07/13/11 00:41:44 TRACE done, now CALL map has 1 items
07/13/11 00:41:44 TRACE source call is {1310488901.186} and lastRedirection=
07/13/11 00:41:44 TRACE GetMonitorSetFromCallModel = 3
07/13/11 00:41:44 TRACE num_monitors = 1
07/13/11 00:41:44 TRACE sending event:CFTE:ESTABLISHED to xref=1, address=4004, callid=3, lastRedirection=, userData=
07/13/11 00:41:44 TRACE OnEstablished xref=1 callId=3, establishedDevice=4004, callerId=4002, callerIdName=Room, calledDevice =4004, lastRedirectingDevice=, userData= cause=0
07/13/11 00:41:44 TRACE searching a TapiCall with callId 3 in tapiLine 0x28b83f0
07/13/11 00:41:44 TRACE htapiline=0x10377, deviceID=4004, htapicall=0x10366, callerid=4002, callerIdName=Room, calleddevice=4004, lastRedirection=, userData=
07/13/11 00:41:44 TRACE LINECALLSTATE_CONNECTED htapicall=0x10366
07/13/11 00:41:44 TRACE <== asterisk protocol event _______________________________
07/13/11 00:41:44 TRACE ASTProvider::HandleEvent => newstate
07/13/11 00:41:44 TRACE OnNewStateEvent:CFT: ev.m_uniqueId="1310488901.186"; ev.m_callerIdName="Room"; ev.m_state="Up"; ev.m_channel="SIP/4002-00000082"; m_pxCstaProvider->OnNewStateEvent(ev);
07/13/11 00:41:44 TRACE Call does not contains UserData
07/13/11 00:41:44 TRACE Call does not containsCallId
07/13/11 00:41:44 TRACE Call is NOT predictive
07/13/11 00:41:44 TRACE setting {1310488901.186}.callerID=4002, callerIdName=Room
07/13/11 00:41:44 TRACE state = UP => Send ESTABLISHED to {1310488901.186}.address=4002
07/13/11 00:41:44 TRACE ASTCstaProvider::handleConnectionConnected uniqueId=1310488901.186, address=4002
07/13/11 00:41:44 TRACE ASTCallMap::GetSourceCall(0x362d100)
07/13/11 00:41:44 TRACE SourceCall is 1310488901.186
07/13/11 00:41:44 TRACE GetCIDInfoFromSourceCall(1310488901.186)
07/13/11 00:41:44 TRACE Exiting with cid/cidname/userData=4002/Room/
07/13/11 00:41:44 TRACE event minimization RULE-8: Do not send ESTABLISHED if there is a destination call: second established is wrong (indicates audio is up but established was already sent)
07/13/11 00:41:44 TRACE <== asterisk protocol event _______________________________
07/13/11 00:41:44 TRACE ASTProvider::HandleEvent => bridge
07/13/11 00:41:44 TRACE OnLinkEvent:CFT: ev.m_srcUniqueId="1310488901.186"; ev.m_destUniqueId="1310488901.187"; m_pxCstaProvider->OnLinkEvent(ev);
07/13/11 00:41:44 TRACE set {1310488901.187}.lastRedirectionDevice=
07/13/11 00:41:44 TRACE <== asterisk protocol event _______________________________
07/13/11 00:41:44 TRACE TSPI_lineGetCallInfo hdCall=0x28bfda0 callerId=4002, callerIdName=Room, calledId=4004, calledIdName=4004, connectedId=4002, connectedIdName=Room, redirectingId=, redirectingIdName=, redirectionId=4004, userData=, isPredictive=0, dwOrigin=0x80
07/13/11 00:41:46 TRACE ASTProvider::HandleEvent => unlink
07/13/11 00:41:46 TRACE <== asterisk protocol event _______________________________
07/13/11 00:41:46 TRACE ASTProvider::HandleEvent => hangup
07/13/11 00:41:46 TRACE OnHangup:CFT: ev.m_uniqueId="1310488901.187"; ev.m_cause="16"; m_pxCstaProvider->OnHangupEvent(ev);
07/13/11 00:41:46 TRACE GetStateOfDevice {3, 4002}
07/13/11 00:41:46 TRACE deviceState = INITIALIZED
07/13/11 00:41:46 TRACE callMap.size == 2
07/13/11 00:41:46 TRACE handleConnectionDisconnected {1310488901.187} to 4004
07/13/11 00:41:46 TRACE ASTCallMap::GetLogicAddress(0x362b5c0)
07/13/11 00:41:46 TRACE ASTCstaProvider::handleConnectionDisconnected uniqueId=1310488901.187, logicaddress=4004, cause=0
07/13/11 00:41:46 TRACE GetMonitorSetFromCallModel = 3
07/13/11 00:41:46 TRACE num_monitors = 1
07/13/11 00:41:46 TRACE sending event:CFTE:CONNCLEARED to xref=1, address=4004, callid=3
07/13/11 00:41:46 TRACE OnConnectionCleared xref=1 callId=3, releasingDevice=4004 cause=0
07/13/11 00:41:46 TRACE searching a TapiCall with callId 3 in tapiLine 0x28b83f0
07/13/11 00:41:46 TRACE htapiline=0x10377, deviceID=4004, htapicall=0x10366, releasingDevice=4004, callerid=N/A, callerIdName=N/A, calleddevice=N/A, lastRedirection=N/A
07/13/11 00:41:46 TRACE LINECALLSTATE_IDLE NORMAL htapicall=0x10366
07/13/11 00:41:46 TRACE RemoveConnection {3}=> 4004
07/13/11 00:41:46 TRACE removed uniqueId=1310488901.187 call from MAP
07/13/11 00:41:46 TRACE <== asterisk protocol event _______________________________
07/13/11 00:41:46 TRACE ASTProvider::HandleEvent => dial
07/13/11 00:41:46 TRACE <== asterisk protocol event _______________________________
07/13/11 00:41:46 TRACE ASTProvider::HandleEvent => hangup
07/13/11 00:41:46 TRACE OnHangup:CFT: ev.m_uniqueId="1310488901.186"; ev.m_cause="16"; m_pxCstaProvider->OnHangupEvent(ev);
07/13/11 00:41:46 TRACE GetStateOfDevice {3, 4002}
07/13/11 00:41:46 TRACE deviceState = INITIALIZED
07/13/11 00:41:46 TRACE handleConnectionDisconnected {1310488901.186} to 4002
07/13/11 00:41:46 TRACE ASTCallMap::GetLogicAddress(0x362d100)
07/13/11 00:41:46 TRACE ASTCstaProvider::handleConnectionDisconnected uniqueId=1310488901.186, logicaddress=4002, cause=0
07/13/11 00:41:46 TRACE GetMonitorSetFromCallModel = 3
07/13/11 00:41:46 TRACE num_monitors = 0
07/13/11 00:41:46 WARN do not send EVENTS because not exist any monitors in call 3
07/13/11 00:41:46 TRACE RemoveConnection {3}=> 4002
07/13/11 00:41:46 TRACE removed uniqueId=1310488901.186 call from MAP
07/13/11 00:41:46 TRACE handleCallDisconnected {3} was the last one
07/13/11 00:41:46 TRACE GetMonitorSetFromCallModel = 3
07/13/11 00:41:46 TRACE callerId not found
07/13/11 00:41:46 WARN do not send EVENTS because not exist any monitors in call 3
07/13/11 00:41:46 TRACE RemoveCall {3}
07/13/11 00:41:46 TRACE {3} NOT IN CALL-MONITOR MAP
07/13/11 00:41:46 TRACE removed entry with callId=3 from MAP
07/13/11 00:41:46 TRACE <== asterisk protocol event _______________________________
07/13/11 00:41:46 TRACE TSPI_lineCloseCall() hdCall=0x28bfda0
07/13/11 00:41:46 TRACE ASTTapiProvider::RemoveTapiCall hdrivercall=0x28bfda0
07/13/11 00:41:46 TRACE call had callid=3
07/13/11 00:41:46 TRACE …with 1 associated hdrvrcalls
07/13/11 00:41:46 TRACE delete htcall 0x10366 and hdrvCall 0x28bfda0
07/13/11 00:41:46 TRACE deleted the last htapicall and the set of callid 3
07/13/11 00:41:46 TRACE deleting pTapiCall addrs=4004 htapiCall=0x10366
07/13/11 00:41:48 TRACE TSPI_lineClose() hdLine=0x1
Hi!
The Tapi app open a monitor on 4004, and 4004 recieve an incoming call from 4002.
The fired events were:
OnAlerting xref=1 callId=3, alertingDevice=4004, callerId=4002, callerIdName=Room, calledID=4004 userData= cause=0
OnEstablished xref=1 callId=3, establishedDevice=4004, callerId=4002, callerIdName=Room, calledDevice =4004, lastRedirectingDevice=, userData= cause=0 0
It seems that the callerid is correct, what callerid are you specting?
ActivaTeam.