10192761.000 |08:02:10.506 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192762.000 |08:02:11.512 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192763.000 |08:02:12.782 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192764.000 |08:02:13.164 |SdlSig |ReapOldTokenRegistrationsTimer |wait |SIPStationInit(2,100,65,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[R:H-H:1,N:0,L:0,V:0,Z:0,D:0] 10192765.000 |08:02:13.164 |SdlSig |SdlPollReqTimer |wait |SdlLinkControl(2,100,18,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |*TraceFlagOverrode 10192765.001 |08:02:13.164 |SdlError | | | | | |SdlLinkHandler::sendPollRequest - Did not received Poll Response. Going Down. NodeId: 1, AppId: 300, TCPAddr[:0] 10192765.002 |08:02:13.164 |SdlError | | | | | |SdlLinkHandler::sendPollRequest - Did not received Poll Response. Going Down. NodeId: 2, AppId: 300, TCPAddr[:0] 10192765.003 |08:02:13.164 |SdlError | | | | | |SdlLinkHandler::sendPollRequest - Did not received Poll Response. Going Down. NodeId: 3, AppId: 300, TCPAddr[:0] 10192766.000 |08:02:13.787 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192767.000 |08:02:13.834 |SdlSig |DeviceEventReceiptMonitoringTimer |wait |StationInit(2,100,57,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[R:H-H:0,N:0,L:0,V:0,Z:0,D:0] 10192768.000 |08:02:14.800 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192769.000 |08:02:14.800 |SdlStat |Period: 6s #Lines: 61 #Bytes: 14183 Total Number of Buffers: 10000 Free LWM: 9952 Free LWM(total): 9305 10192770.000 |08:02:15.819 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192771.000 |08:02:16.841 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192772.000 |08:02:17.845 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192773.000 |08:02:18.858 |SdlSig |DeviceEventReceiptMonitoringTimer |wait |StationInit(2,100,57,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[R:H-H:2,N:0,L:0,V:0,Z:0,D:0] 10192774.000 |08:02:18.858 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192775.000 |08:02:19.868 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192776.000 |08:02:20.878 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192777.000 |08:02:20.878 |SdlStat |Period: 6s #Lines: 7 #Bytes: 1830 Total Number of Buffers: 10000 Free LWM: 9998 Free LWM(total): 9305 10192778.000 |08:02:21.889 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192779.000 |08:02:22.993 |AppInfo |EnvProcessUdpHandler::handle_input - handle = 335 10192780.000 |08:02:22.993 |AppInfo |EnvProcessUdpHandler::handle_input Status: 0, Id: 0 10192781.000 |08:02:23.181 |SdlSig |UdpDataInd |wait |SIPUdp(2,100,63,1) |EnvProcessUdpPort(2,100,238,1) |2,100,238,1.109326^*^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] varStatus=0 varId=0 varSrcIpAddr=3232238083 varIpPort=5060 varFamily=2 10192781.001 |08:02:23.181 |AppInfo |//SIP/SIPUdp/wait_UdpDataInd: Incoming SIP UDP message size 352 from 192.168.10.3:[5060]: [1115440,NET] OPTIONS sip:192.168.10.8 SIP/2.0 From: ;tag=ACU-9b5e55b-1629ee65 To: Contact: Call-ID: f124c526-1dd1-11b2-a2b1-9edbcf6c9442@192.168.10.3 CSeq: 592515 OPTIONS Content-Length: 0 Max-Forwards: 70 Via: SIP/2.0/UDP 192.168.10.3:5060;branch=z9hG4bKf124f122-1dd1-11b2-a768-8790f96d8ee3;rport 10192782.000 |08:02:23.181 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192783.000 |08:02:23.181 |SdlSig |SIPSPISignal |wait |SIPHandler(2,100,72,1) |SIPUdp(2,100,63,1) |2,100,238,1.109326^192.168.10.3^* |*TraceFlagOverrode 10192783.001 |08:02:23.181 |AppInfo |//SIP/Stack/Info/0x0/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 (SIP_NETWORK_MSG), for event 1 (SIPSPI_EV_NEW_MESSAGE) 10192783.002 |08:02:23.181 |AppInfo |//SIP/Stack/Transport/0x0/sipTransportProcessNWNewConnMsg: context=(nil) 10192783.003 |08:02:23.181 |AppInfo |//SIP/Stack/Info/0x0/sipSPIAddContextToTable: Added context(0x10212c70) with key=[454527] to table 10192783.004 |08:02:23.181 |AppInfo |//SIP/Stack/Transport/0x0/sipSPIUpdateResponseInfo: Dialog Transaction Address 192.168.10.3,Port 5060, Transport 1, SentBy Port 5060 10192783.005 |08:02:23.181 |AppInfo |//SIP/Stack/States/0x10212c70/sipSPIChangeState: 0x10212c70 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE) 10192783.006 |08:02:23.181 |AppInfo |//SIP/Stack/Transport/0x0/sipSPIUpdateResponseInfo: Subsq Transaction Address 192.168.10.3,Port 5060, Transport 1, SentBy Port 5060 10192783.007 |08:02:23.181 |AppInfo |//SIP/Stack/Transport/0x0/sipSPIUpdateResponseInfo: Subsq Transaction Address 192.168.10.3,Port 5060, Transport 1, SentBy Port 5060 10192783.008 |08:02:23.181 |AppInfo |//SIP/Stack/Error/0x0/httpish_msg_free: Freeing NULL pointer! 10192783.009 |08:02:23.181 |AppInfo |//SIP/SIPHandler/ccbId=454878/scbId=0/findDevicePID: Routed to SIPD by sipAddr 10192783.010 |08:02:23.181 |AppInfo |//SIP/Stack/Info/0x10212c70/sact_idle_new_message_options: ccsip_api_options_ind returned: SIP_SUCCESS 10192783.011 |08:02:23.181 |AppInfo |//SIP/Stack/States/0x10212c70/sipSPIChangeState: 0x10212c70 : State change from (STATE_IDLE, SUBSTATE_NONE) to (SIP_STATE_OPTIONS_WAIT, SUBSTATE_NONE) 10192783.012 |08:02:23.181 |AppInfo |//SIP/Stack/Info/0x10212c70/sipSPIUaddCcbToTable: Added to table. ccb=0x10212c70 key=f124c526-1dd1-11b2-a2b1-9edbcf6c9442@192.168.10.3 10192784.000 |08:02:23.181 |SdlSig |SIPOptionsInd |restart0 |SIPD(2,100,74,125) |SIPHandler(2,100,72,1) |2,100,238,1.109326^192.168.10.3^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] ccbID= 454878 --TransType=2 --TransSecurity=0 PeerAddr = 192.168.10.3:5060 10192785.000 |08:02:23.181 |SdlSig |SIPOptionsResp |wait |SIPHandler(2,100,72,1) |SIPD(2,100,74,125) |2,100,238,1.109326^192.168.10.3^* |[T:N-H:0,N:0,L:0,V:0,Z:0,D:0] ccbID= 454878 --TransType=2 --TransSecurity=0 PeerAddr = 192.168.10.3:5060 10192785.001 |08:02:23.181 |AppInfo |//SIP/Stack/Info/0x0/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 (SIP_APPLICATION_MSG), for event 39 (SIPSPI_EV_CC_OPTIONS_RESP) 10192785.002 |08:02:23.181 |AppInfo |//SIP/Stack/Info/0x10212c70/sipSPISendOptionsResponse: Associated container=0xb6eaa410 to Options Response 10192785.003 |08:02:23.181 |AppInfo |//SIP/Stack/Transport/0x10212c70/sipSPITransportSendMessage: msg=0xb6e1a718, addr=192.168.10.3, port=5060, sentBy_port=5060, is_req=0, transp 10192785.004 |08:02:23.181 |AppInfo |//SIP/Stack/Transport/0x10212c70/sipTransportPostSendMessage: Posting send for msg=0xb6e1a718, addr=192.168.10.3, port=5060, connId=0 for U 10192785.005 |08:02:23.181 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/sip_stop_timer: type=SIP_TIMER_REMOVE_TRANSACTION value=32000 retries=0 10192785.006 |08:02:23.181 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/sip_start_timer: type=SIP_TIMER_REMOVE_TRANSACTION value=32000 retries=0 10192786.000 |08:02:23.181 |SdlSig |SIPSPISignal |wait |SIPUdp(2,100,63,1) |SIPHandler(2,100,72,1) |2,100,238,1.109326^192.168.10.3^* |*TraceFlagOverrode 10192786.001 |08:02:23.181 |AppInfo |//SIP/SIPUdp/wait_SdlSPISignal: Outgoing SIP UDP message to 192.168.10.3:[5060]: [1115441,NET] SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.10.3:5060;branch=z9hG4bKf124f122-1dd1-11b2-a768-8790f96d8ee3;rport From: ;tag=ACU-9b5e55b-1629ee65 To: ;tag=1826188159 Date: Wed, 02 Sep 2015 08:02:23 GMT Call-ID: f124c526-1dd1-11b2-a2b1-9edbcf6c9442@192.168.10.3 CSeq: 592515 OPTIONS Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY Content-Length: 0 10192787.000 |08:02:23.181 |SdlSig |UdpSendReq |start |EnvProcessUdpPort(2,100,238,1) |SIPUdp(2,100,63,1) |2,100,238,1.109326^192.168.10.3^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] varId=0 varIpAddr=3232238083 varIpPort=5060 varFamily=2 10192787.001 |08:02:23.181 |AppInfo |EnvProcessUdpPort - EnvProcessUdpHandler::fireSignal() varId = 0 10192787.002 |08:02:23.181 |AppInfo |EnvProcessUdpHandler::fireSignal - SEND: index = 0, handler = 0x10544140 10192787.003 |08:02:23.181 |AppInfo |EnvProcessUdpPort::fireSignal - SEND, destination = 192.168.10.3:5060 10192787.004 |08:02:23.181 |AppInfo |EnvProcessUdpPort - EnvProcessUdpHandler::send(buff, 428, 192.168.10.3:5060) 10192788.000 |08:02:23.184 |SdlSig |ReapOldTokenRegistrationsTimer |wait |SIPStationInit(2,100,65,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[R:H-H:1,N:0,L:0,V:0,Z:0,D:0] 10192789.000 |08:02:23.184 |SdlSig |SdlPollReqTimer |wait |SdlLinkControl(2,100,18,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |*TraceFlagOverrode 10192789.001 |08:02:23.184 |SdlError | | | | | |SdlLinkHandler::sendPollRequest - Did not received Poll Response. Going Down. NodeId: 1, AppId: 300, TCPAddr[:0] 10192789.002 |08:02:23.184 |SdlError | | | | | |SdlLinkHandler::sendPollRequest - Did not received Poll Response. Going Down. NodeId: 2, AppId: 300, TCPAddr[:0] 10192789.003 |08:02:23.184 |SdlError | | | | | |SdlLinkHandler::sendPollRequest - Did not received Poll Response. Going Down. NodeId: 3, AppId: 300, TCPAddr[:0] 10192790.000 |08:02:23.875 |SdlSig |DeviceEventReceiptMonitoringTimer |wait |StationInit(2,100,57,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[R:H-H:0,N:0,L:0,V:0,Z:0,D:0] 10192791.000 |08:02:24.217 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192792.000 |08:02:24.299 |SdlSig |SIPPingReqTimer |restart0 |SIPD(2,100,74,124) |SdlTimerService(2,100,3,1) |2,100,37,1.1200^*^* |[R:H-H:0,N:0,L:0,V:0,Z:0,D:0] 10192793.000 |08:02:24.299 |SdlSig |SIPPingReq |wait |SIPHandler(2,100,72,1) |SIPD(2,100,74,124) |2,100,37,1.1200^*^* |[T:N-H:0,N:0,L:0,V:0,Z:0,D:0] ccbID= 454879 maxForward=0 --TransType=1 --TransSecurity=0 PeerAddr = 192.168.10.4:5060 10192793.001 |08:02:24.299 |AppInfo |//SIP/Stack/Info/0x0/sipSPIAddContextToTable: Added context(0x10206e30) with key=[454528] to table 10192793.002 |08:02:24.299 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/populateTargetInfo: port=5060, isIPAddr=1, type=2, target_port=5060, outboundProxyAddr.isIPAddr=0, target_type=0 10192793.003 |08:02:24.299 |AppInfo |//SIP/Stack/States/0x10206e30/sipSPIChangeState: 0x10206e30 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE) 10192793.004 |08:02:24.299 |AppInfo |//SIP/Stack/Info/0x0/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 (SIP_APPLICATION_MSG), for event 38 (SIPSPI_EV_CC_OPTIONS) 10192793.005 |08:02:24.299 |AppInfo |//SIP/Stack/Info/0x10206e30/sipSPIUaddCcbToTable: Added to table. ccb=0x10206e30 key=f0872d80-5e61ad10-1dc2d-80aa8c0@192.168.10.8 10192793.006 |08:02:24.299 |AppInfo |//SIP/Stack/States/0x10206e30/sipSPIChangeState: 0x10206e30 : State change from (STATE_IDLE, SUBSTATE_NONE) to (SIP_STATE_OPTIONS_WAIT, SUBSTATE_NONE) 10192793.007 |08:02:24.299 |AppInfo |//SIP/Stack/Info/0x10206e30/sipSPIAddViaParams: inserted z9hG4bK1dfc666b930fc into via branch list 10192793.008 |08:02:24.299 |AppInfo |//SIP/Stack/Error/0x10206e30/sipSPIAddPrivacyHeader: Orig Container is NULL...should have value 10192793.009 |08:02:24.299 |AppInfo |//SIP/Stack/Error/0x10206e30/sipSPIAddAssertedIDHeader: Orig Container is NULL...should have value 10192793.010 |08:02:24.299 |AppInfo |//SIP/Stack/Error/0x10206e30/sipSPIAddPreferredIDHeader: Orig Container is NULL...should have value 10192793.011 |08:02:24.299 |AppInfo |//SIP/Stack/Info/0x10206e30/sipSPISendOptionsRequest: Associated container=0xb6eb5d10 to Options 10192793.012 |08:02:24.299 |AppInfo |//SIP/Stack/Transport/0x10206e30/sipSPITransportSendMessage: msg=0xb6eaa7c0, addr=192.168.10.4, port=5060, sentBy_port=0, is_req=1, transp 10192793.013 |08:02:24.299 |AppInfo |//SIP/Stack/Transport/0x0/sipInstanceGetConnectionId: Registering gcb=0x10206e30 with connection=0xfe2de80 context list 10192793.014 |08:02:24.299 |AppInfo |//SIP/Stack/Transport/0x10206e30/sipTransportLogicSendMsg: Set to send the msg=0xb6eaa7c0 10192793.015 |08:02:24.299 |AppInfo |//SIP/Stack/Transport/0x10206e30/sipTransportPostSendMessage: Posting send for msg=0xb6eaa7c0, addr=192.168.10.4, port=5060, connId=13159 for T 10192793.016 |08:02:24.299 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/sip_stop_timer: type=SIP_TIMER_TRYING value=500 retries=6 10192793.017 |08:02:24.299 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/sip_start_timer: type=SIP_TIMER_TRYING value=500 retries=6 10192794.000 |08:02:24.299 |AppInfo |SIPSocketProtocol(2,100,13,553)::handleWriteComplete 10192795.000 |08:02:24.299 |SdlSig |SIPSPISignal |wait |SIPTcp(2,100,64,1) |SIPHandler(2,100,72,1) |2,100,37,1.1200^*^* |*TraceFlagOverrode 10192795.001 |08:02:24.299 |AppInfo |SIPTcp - wait_SdlSPISignal: Outgoing SIP TCP message to 192.168.10.4 on port 5060 index 13159 [1115442,NET] OPTIONS sip:192.168.10.4:5060 SIP/2.0 Via: SIP/2.0/TCP 192.168.10.8:5060;branch=z9hG4bK1dfc666b930fc From: ;tag=1857549118 To: Date: Wed, 02 Sep 2015 08:02:24 GMT Call-ID: f0872d80-5e61ad10-1dc2d-80aa8c0@192.168.10.8 User-Agent: Cisco-CUCM9.1 CSeq: 101 OPTIONS Contact: Max-Forwards: 0 Content-Length: 0 10192796.000 |08:02:24.304 |AppInfo |SIPSocketProtocol(2,100,13,553)::handleReadComplete send SdlReadRsp: size 642 10192797.000 |08:02:24.304 |SdlSig |SdlReadRsp |wait |SIPTcp(2,100,64,1) |SdlTCPConnection(2,100,13,553) |2,100,13,553.9572^192.168.10.4^* |*TraceFlagOverrode 10192797.001 |08:02:24.304 |AppInfo |SIPTcp - SdlRead bufferLen=642 10192797.002 |08:02:24.304 |AppInfo |//SIP/Stack/Error/0x0/httpish_cache_header_val: DROPPING unregistered header Accept-Encoding: identity 10192797.003 |08:02:24.304 |AppInfo |//SIP/Stack/Error/0x0/httpish_cache_header_val: DROPPING unregistered header Accept-Language: en 10192797.004 |08:02:24.304 |AppInfo |SIPTcp - wait_SdlReadRsp: Incoming SIP TCP message from 192.168.10.4 on port 5060 index 13159 with 642 bytes: [1115443,NET] SIP/2.0 200 Ok Via: SIP/2.0/TCP 192.168.10.8:5060;branch=z9hG4bK1dfc666b930fc From: ;tag=1857549118 To: Call-ID: f0872d80-5e61ad10-1dc2d-80aa8c0@192.168.10.8 CSeq: 101 OPTIONS Content-Length: 0 User-Agent: ApplianX-Gateway Allow: INVITE Allow: ACK Allow: BYE Allow: CANCEL Allow: OPTIONS Allow: NOTIFY Allow: REFER Allow: PRACK Allow: INFO Allow: UPDATE Allow: MESSAGE Accept: application/sdp Accept: application/isup Accept: application/qsig Accept: multipart/mixed Accept-Encoding: identity Accept-Language: en Supported: 100rel Supported: replaces Supported: X-AcuAX-ROPR 10192797.005 |08:02:24.304 |AppInfo |SIPTcp - SignalCounter = 337369 10192798.000 |08:02:24.304 |SdlSig |SIPSPISignal |wait |SIPHandler(2,100,72,1) |SIPTcp(2,100,64,1) |2,100,13,553.9572^192.168.10.4^* |*TraceFlagOverrode 10192798.001 |08:02:24.304 |AppInfo |//SIP/Stack/Info/0x0/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 (SIP_NETWORK_MSG), for event 1 (SIPSPI_EV_NEW_MESSAGE) 10192798.002 |08:02:24.304 |AppInfo |//SIP/Stack/Transport/0x0/sipTransportProcessNWNewConnMsg: context=0xf553560 10192798.003 |08:02:24.304 |AppInfo |//SIP/Stack/Transport/0x0/sipConnectionManagerProcessNewConnMsg: gConnTab=0xf553560, addr=192.168.10.4, port=5060, connid=13159, transport=TCP 10192798.004 |08:02:24.304 |AppInfo |//SIP/Stack/Info/0x0/sipHolderGetConnInstance: Return existing connection for port 5060 connId 13159 10192798.005 |08:02:24.304 |AppInfo |//SIP/Stack/Info/0x10206e30/sipSPIMatchRespToReqTran: removing unneeded z9hG4bK1dfc666b930fc from via branch list 10192798.006 |08:02:24.304 |AppInfo |//SIP/Stack/Info/0x10206e30/sipSPICheckResponseExt: non-INVITE response with no RSEQ - do not disable IS_REL1XX 10192798.007 |08:02:24.304 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/sip_stop_timer: type=SIP_TIMER_TRYING value=500 retries=6 10192798.008 |08:02:24.304 |AppInfo |//SIP/SIPHandler/ccbId=454879/scbId=0/findDevicePID: Routed to SIPD by ccbId/scbId 10192798.009 |08:02:24.304 |AppInfo |//SIP/Stack/Info/0x10206e30/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be 10192798.010 |08:02:24.304 |AppInfo |//SIP/Stack/Transport/0x0/sipConnectionManagerUnregisterCtxtInCon: gConnTab=0xf553560, addr=192.168.10.4, port=5060, unregistering context= 10192798.011 |08:02:24.304 |AppInfo |//SIP/Stack/Info/0x10206e30/sipSPIUfreeOneCCB: Freeing ccb 10206e30 10192799.000 |08:02:24.304 |SdlSig |SIPPingResult |restart0 |SIPD(2,100,74,124) |SIPHandler(2,100,72,1) |2,100,13,553.9572^192.168.10.4^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] ccbID= 454879 interErr=F resp=200 state=0 --TransType=1 --TransSecurity=0 PeerAddr = 192.168.10.4:5060 10192800.000 |08:02:25.226 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192801.000 |08:02:25.345 |SdlSig |SIPTimer |wait |SIPHandler(2,100,72,1) |SdlTimerService(2,100,3,1) |2,100,13,16.2^192.168.10.4^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] TimerType=SIP_TIMER_REMOVE_STALE_PING_RECORD value=300000 numRetries=0 10192801.001 |08:02:25.345 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/wait_SIPTimer: TimerExpired type=SIP_TIMER_REMOVE_STALE_PING_RECORD value=300000 retries=0 10192801.002 |08:02:25.345 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/sip_stop_timer: type=SIP_TIMER_REMOVE_STALE_PING_RECORD value=300000 retries=0 10192801.003 |08:02:25.345 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/sip_start_timer: type=SIP_TIMER_REMOVE_STALE_PING_RECORD value=300000 retries=0 10192802.000 |08:02:26.242 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192803.000 |08:02:26.242 |SdlStat |Period: 6s #Lines: 89 #Bytes: 18049 Total Number of Buffers: 10000 Free LWM: 9969 Free LWM(total): 9305 10192804.000 |08:02:27.251 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192805.000 |08:02:28.265 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192806.000 |08:02:28.661 |SdlSig |SIPPingReqTimer |restart0 |SIPD(2,100,74,125) |SdlTimerService(2,100,3,1) |2,100,37,1.1200^*^* |[R:H-H:0,N:0,L:0,V:0,Z:0,D:0] 10192807.000 |08:02:28.661 |SdlSig |SIPPingReq |wait |SIPHandler(2,100,72,1) |SIPD(2,100,74,125) |2,100,37,1.1200^*^* |[T:N-H:0,N:0,L:0,V:0,Z:0,D:0] ccbID= 454880 maxForward=0 --TransType=1 --TransSecurity=0 PeerAddr = 192.168.10.3:5060 10192807.001 |08:02:28.661 |AppInfo |//SIP/Stack/Info/0x0/sipSPIAddContextToTable: Added context(0x10214438) with key=[454529] to table 10192807.002 |08:02:28.661 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/populateTargetInfo: port=5060, isIPAddr=1, type=2, target_port=5060, outboundProxyAddr.isIPAddr=0, target_type=0 10192807.003 |08:02:28.661 |AppInfo |//SIP/Stack/States/0x10214438/sipSPIChangeState: 0x10214438 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE) 10192807.004 |08:02:28.661 |AppInfo |//SIP/Stack/Info/0x0/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 (SIP_APPLICATION_MSG), for event 38 (SIPSPI_EV_CC_OPTIONS) 10192807.005 |08:02:28.661 |AppInfo |//SIP/Stack/Info/0x10214438/sipSPIUaddCcbToTable: Added to table. ccb=0x10214438 key=f2e98780-5e61ad14-1dc2e-80aa8c0@192.168.10.8 10192807.006 |08:02:28.661 |AppInfo |//SIP/Stack/States/0x10214438/sipSPIChangeState: 0x10214438 : State change from (STATE_IDLE, SUBSTATE_NONE) to (SIP_STATE_OPTIONS_WAIT, SUBSTATE_NONE) 10192807.007 |08:02:28.661 |AppInfo |//SIP/Stack/Info/0x10214438/sipSPIAddViaParams: inserted z9hG4bK1dfc7401712c8 into via branch list 10192807.008 |08:02:28.661 |AppInfo |//SIP/Stack/Error/0x10214438/sipSPIAddPrivacyHeader: Orig Container is NULL...should have value 10192807.009 |08:02:28.661 |AppInfo |//SIP/Stack/Error/0x10214438/sipSPIAddAssertedIDHeader: Orig Container is NULL...should have value 10192807.010 |08:02:28.661 |AppInfo |//SIP/Stack/Error/0x10214438/sipSPIAddPreferredIDHeader: Orig Container is NULL...should have value 10192807.011 |08:02:28.661 |AppInfo |//SIP/Stack/Info/0x10214438/sipSPISendOptionsRequest: Associated container=0xb6eb5d10 to Options 10192807.012 |08:02:28.661 |AppInfo |//SIP/Stack/Transport/0x10214438/sipSPITransportSendMessage: msg=0xb6eaa7c0, addr=192.168.10.3, port=5060, sentBy_port=0, is_req=1, transp 10192807.013 |08:02:28.661 |AppInfo |//SIP/Stack/Transport/0x0/sipInstanceGetConnectionId: Registering gcb=0x10214438 with connection=0xfe2df90 context list 10192807.014 |08:02:28.661 |AppInfo |//SIP/Stack/Transport/0x10214438/sipTransportLogicSendMsg: Set to send the msg=0xb6eaa7c0 10192807.015 |08:02:28.661 |AppInfo |//SIP/Stack/Transport/0x10214438/sipTransportPostSendMessage: Posting send for msg=0xb6eaa7c0, addr=192.168.10.3, port=5060, connId=13188 for T 10192807.016 |08:02:28.661 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/sip_stop_timer: type=SIP_TIMER_TRYING value=500 retries=6 10192807.017 |08:02:28.661 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/sip_start_timer: type=SIP_TIMER_TRYING value=500 retries=6 10192808.000 |08:02:28.661 |AppInfo |SIPSocketProtocol(2,100,13,582)::handleWriteComplete 10192809.000 |08:02:28.661 |SdlSig |SIPSPISignal |wait |SIPTcp(2,100,64,1) |SIPHandler(2,100,72,1) |2,100,37,1.1200^*^* |*TraceFlagOverrode 10192809.001 |08:02:28.661 |AppInfo |SIPTcp - wait_SdlSPISignal: Outgoing SIP TCP message to 192.168.10.3 on port 5060 index 13188 [1115444,NET] OPTIONS sip:192.168.10.3:5060 SIP/2.0 Via: SIP/2.0/TCP 192.168.10.8:5060;branch=z9hG4bK1dfc7401712c8 From: ;tag=70405749 To: Date: Wed, 02 Sep 2015 08:02:28 GMT Call-ID: f2e98780-5e61ad14-1dc2e-80aa8c0@192.168.10.8 User-Agent: Cisco-CUCM9.1 CSeq: 101 OPTIONS Contact: Max-Forwards: 0 Content-Length: 0 10192810.000 |08:02:28.664 |AppInfo |SIPSocketProtocol(2,100,13,582)::handleReadComplete send SdlReadRsp: size 640 10192811.000 |08:02:28.664 |SdlSig |SdlReadRsp |wait |SIPTcp(2,100,64,1) |SdlTCPConnection(2,100,13,582) |2,100,13,582.1297^192.168.10.3^* |*TraceFlagOverrode 10192811.001 |08:02:28.664 |AppInfo |SIPTcp - SdlRead bufferLen=640 10192811.002 |08:02:28.664 |AppInfo |//SIP/Stack/Error/0x0/httpish_cache_header_val: DROPPING unregistered header Accept-Encoding: identity 10192811.003 |08:02:28.664 |AppInfo |//SIP/Stack/Error/0x0/httpish_cache_header_val: DROPPING unregistered header Accept-Language: en 10192811.004 |08:02:28.665 |AppInfo |SIPTcp - wait_SdlReadRsp: Incoming SIP TCP message from 192.168.10.3 on port 5060 index 13188 with 640 bytes: [1115445,NET] SIP/2.0 200 Ok Via: SIP/2.0/TCP 192.168.10.8:5060;branch=z9hG4bK1dfc7401712c8 From: ;tag=70405749 To: Call-ID: f2e98780-5e61ad14-1dc2e-80aa8c0@192.168.10.8 CSeq: 101 OPTIONS Content-Length: 0 User-Agent: ApplianX-Gateway Allow: INVITE Allow: ACK Allow: BYE Allow: CANCEL Allow: OPTIONS Allow: NOTIFY Allow: REFER Allow: PRACK Allow: INFO Allow: UPDATE Allow: MESSAGE Accept: application/sdp Accept: application/isup Accept: application/qsig Accept: multipart/mixed Accept-Encoding: identity Accept-Language: en Supported: 100rel Supported: replaces Supported: X-AcuAX-ROPR 10192811.005 |08:02:28.665 |AppInfo |SIPTcp - SignalCounter = 337370 10192812.000 |08:02:28.665 |SdlSig |SIPSPISignal |wait |SIPHandler(2,100,72,1) |SIPTcp(2,100,64,1) |2,100,13,582.1297^192.168.10.3^* |*TraceFlagOverrode 10192812.001 |08:02:28.665 |AppInfo |//SIP/Stack/Info/0x0/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 (SIP_NETWORK_MSG), for event 1 (SIPSPI_EV_NEW_MESSAGE) 10192812.002 |08:02:28.665 |AppInfo |//SIP/Stack/Transport/0x0/sipTransportProcessNWNewConnMsg: context=0xf553560 10192812.003 |08:02:28.665 |AppInfo |//SIP/Stack/Transport/0x0/sipConnectionManagerProcessNewConnMsg: gConnTab=0xf553560, addr=192.168.10.3, port=5060, connid=13188, transport=TCP 10192812.004 |08:02:28.665 |AppInfo |//SIP/Stack/Info/0x0/sipHolderGetConnInstance: Return existing connection for port 5060 connId 13188 10192812.005 |08:02:28.665 |AppInfo |//SIP/Stack/Info/0x10214438/sipSPIMatchRespToReqTran: removing unneeded z9hG4bK1dfc7401712c8 from via branch list 10192812.006 |08:02:28.665 |AppInfo |//SIP/Stack/Info/0x10214438/sipSPICheckResponseExt: non-INVITE response with no RSEQ - do not disable IS_REL1XX 10192812.007 |08:02:28.665 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/sip_stop_timer: type=SIP_TIMER_TRYING value=500 retries=6 10192812.008 |08:02:28.665 |AppInfo |//SIP/SIPHandler/ccbId=454880/scbId=0/findDevicePID: Routed to SIPD by ccbId/scbId 10192812.009 |08:02:28.665 |AppInfo |//SIP/Stack/Info/0x10214438/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be 10192812.010 |08:02:28.665 |AppInfo |//SIP/Stack/Transport/0x0/sipConnectionManagerUnregisterCtxtInCon: gConnTab=0xf553560, addr=192.168.10.3, port=5060, unregistering context= 10192812.011 |08:02:28.665 |AppInfo |//SIP/Stack/Info/0x10214438/sipSPIUfreeOneCCB: Freeing ccb 10214438 10192813.000 |08:02:28.665 |SdlSig |SIPPingResult |restart0 |SIPD(2,100,74,125) |SIPHandler(2,100,72,1) |2,100,13,582.1297^192.168.10.3^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] ccbID= 454880 interErr=F resp=200 state=0 --TransType=1 --TransSecurity=0 PeerAddr = 192.168.10.3:5060 10192814.000 |08:02:28.887 |SdlSig |DeviceEventReceiptMonitoringTimer |wait |StationInit(2,100,57,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[R:H-H:0,N:0,L:0,V:0,Z:0,D:0] 10192815.000 |08:02:29.283 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192816.000 |08:02:30.297 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192817.000 |08:02:31.310 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192818.000 |08:02:31.973 |SdlSig |SIPTimer |wait |SIPHandler(2,100,72,1) |SdlTimerService(2,100,3,1) |2,100,238,1.109325^192.168.10.4^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] TimerType=SIP_TIMER_REMOVE_TRANSACTION value=32000 numRetries=0 10192818.001 |08:02:31.973 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/wait_SIPTimer: TimerExpired type=SIP_TIMER_REMOVE_TRANSACTION value=32000 retries=0 10192818.002 |08:02:31.973 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/sip_stop_timer: type=SIP_TIMER_REMOVE_TRANSACTION value=32000 retries=0 10192818.003 |08:02:31.973 |AppInfo |//SIP/Stack/Info/0x101fdf80/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be 10192818.004 |08:02:31.973 |AppInfo |//SIP/Stack/Transport/0x0/sipConnectionManagerUnregisterCtxtInCon: gConnTab=0xf5535a0, addr=192.168.10.4, port=5060, unregistering context= 10192818.005 |08:02:31.973 |AppInfo |//SIP/Stack/Error/0x0/sipConnectionManagerUnregisterCtxtInCon: Could not find conn holder for addr=192.168.10.4 10192818.006 |08:02:31.973 |AppInfo |//SIP/Stack/Transport/0x101fdf80/sipSPITransportContextCleanup: Could not purge context gcb=0x101fdf80 from the connection; gcb 10192818.007 |08:02:31.973 |AppInfo |//SIP/Stack/Info/0x101fdf80/sipSPIUfreeOneCCB: Freeing ccb 101fdf80 10192819.000 |08:02:32.320 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192820.000 |08:02:32.320 |SdlStat |Period: 6s #Lines: 57 #Bytes: 11117 Total Number of Buffers: 10000 Free LWM: 9973 Free LWM(total): 9305 10192821.000 |08:02:33.540 |SdlSig |ReapOldTokenRegistrationsTimer |wait |SIPStationInit(2,100,65,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[R:H-H:5,N:0,L:0,V:0,Z:0,D:0] 10192822.000 |08:02:33.540 |SdlSig |SdlPollReqTimer |wait |SdlLinkControl(2,100,18,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |*TraceFlagOverrode 10192822.001 |08:02:33.540 |SdlError | | | | | |SdlLinkHandler::sendPollRequest - Did not received Poll Response. Going Down. NodeId: 1, AppId: 300, TCPAddr[:0] 10192822.002 |08:02:33.540 |SdlError | | | | | |SdlLinkHandler::sendPollRequest - Did not received Poll Response. Going Down. NodeId: 2, AppId: 300, TCPAddr[:0] 10192822.003 |08:02:33.540 |SdlError | | | | | |SdlLinkHandler::sendPollRequest - Did not received Poll Response. Going Down. NodeId: 3, AppId: 300, TCPAddr[:0] 10192823.000 |08:02:33.542 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192824.000 |08:02:33.556 |SdlSig |CdrFileTimer |wait |EnvProcessCdr(2,100,239,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:N-H:0,N:0,L:0,V:0,Z:0,D:0] 10192824.001 |08:02:33.556 |AppInfo |EnvProcessCdr::wait_CdrFileTimer 10192825.000 |08:02:33.891 |SdlSig |DeviceEventReceiptMonitoringTimer |wait |StationInit(2,100,57,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[R:H-H:0,N:0,L:0,V:0,Z:0,D:0] 10192826.000 |08:02:34.549 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192827.000 |08:02:35.571 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192828.000 |08:02:36.585 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192829.000 |08:02:37.595 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192830.000 |08:02:38.605 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192831.000 |08:02:38.605 |SdlStat |Period: 6s #Lines: 14 #Bytes: 3648 Total Number of Buffers: 10000 Free LWM: 9994 Free LWM(total): 9305 10192832.000 |08:02:38.904 |SdlSig |DeviceEventReceiptMonitoringTimer |wait |StationInit(2,100,57,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[R:H-H:0,N:0,L:0,V:0,Z:0,D:0] 10192833.000 |08:02:39.618 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192834.000 |08:02:40.640 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192835.000 |08:02:41.642 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192836.000 |08:02:42.656 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192837.000 |08:02:43.956 |SdlSig |ReapOldTokenRegistrationsTimer |wait |SIPStationInit(2,100,65,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[R:H-H:5,N:0,L:0,V:0,Z:0,D:0] 10192837.001 |08:02:43.956 |AppInfo |SIPStationInit: mOutstandingTokens = 0, resetting to zero 10192838.000 |08:02:43.956 |SdlSig |DeviceEventReceiptMonitoringTimer |wait |StationInit(2,100,57,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[R:H-H:0,N:0,L:0,V:0,Z:0,D:0] 10192839.000 |08:02:43.956 |SdlSig |SdlPollReqTimer |wait |SdlLinkControl(2,100,18,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |*TraceFlagOverrode 10192839.001 |08:02:43.956 |SdlError | | | | | |SdlLinkHandler::sendPollRequest - Did not received Poll Response. Going Down. NodeId: 1, AppId: 300, TCPAddr[:0] 10192839.002 |08:02:43.956 |SdlError | | | | | |SdlLinkHandler::sendPollRequest - Did not received Poll Response. Going Down. NodeId: 2, AppId: 300, TCPAddr[:0] 10192839.003 |08:02:43.956 |SdlError | | | | | |SdlLinkHandler::sendPollRequest - Did not received Poll Response. Going Down. NodeId: 3, AppId: 300, TCPAddr[:0] 10192840.000 |08:02:43.969 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192841.000 |08:02:44.982 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192842.000 |08:02:44.982 |SdlStat |Period: 6s #Lines: 14 #Bytes: 3673 Total Number of Buffers: 10000 Free LWM: 9993 Free LWM(total): 9305 10192843.000 |08:02:46.004 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192844.000 |08:02:47.017 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192845.000 |08:02:48.035 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192846.000 |08:02:48.968 |SdlSig |DeviceEventReceiptMonitoringTimer |wait |StationInit(2,100,57,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[R:H-H:0,N:0,L:0,V:0,Z:0,D:0] 10192847.000 |08:02:49.049 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192848.000 |08:02:50.067 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192849.000 |08:02:50.067 |SdlStat |Period: 6s #Lines: 6 #Bytes: 1567 Total Number of Buffers: 10000 Free LWM: 9998 Free LWM(total): 9305 10192850.000 |08:02:51.077 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192851.000 |08:02:52.082 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192852.000 |08:02:53.092 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192853.000 |08:02:54.295 |SdlSig |ReapOldTokenRegistrationsTimer |wait |SIPStationInit(2,100,65,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[R:H-H:6,N:0,L:0,V:0,Z:0,D:0] 10192854.000 |08:02:54.296 |SdlSig |DeviceEventReceiptMonitoringTimer |wait |StationInit(2,100,57,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[R:H-H:5,N:0,L:0,V:0,Z:0,D:0] 10192855.000 |08:02:54.296 |SdlSig |SdlPollReqTimer |wait |SdlLinkControl(2,100,18,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |*TraceFlagOverrode 10192855.001 |08:02:54.296 |SdlError | | | | | |SdlLinkHandler::sendPollRequest - Did not received Poll Response. Going Down. NodeId: 1, AppId: 300, TCPAddr[:0] 10192855.002 |08:02:54.296 |SdlError | | | | | |SdlLinkHandler::sendPollRequest - Did not received Poll Response. Going Down. NodeId: 2, AppId: 300, TCPAddr[:0] 10192855.003 |08:02:54.296 |SdlError | | | | | |SdlLinkHandler::sendPollRequest - Did not received Poll Response. Going Down. NodeId: 3, AppId: 300, TCPAddr[:0] 10192856.000 |08:02:54.297 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192857.000 |08:02:55.208 |SdlSig |SIPTimer |wait |SIPHandler(2,100,72,1) |SdlTimerService(2,100,3,1) |2,100,238,1.109326^192.168.10.3^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] TimerType=SIP_TIMER_REMOVE_TRANSACTION value=32000 numRetries=0 10192857.001 |08:02:55.208 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/wait_SIPTimer: TimerExpired type=SIP_TIMER_REMOVE_TRANSACTION value=32000 retries=0 10192857.002 |08:02:55.208 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/sip_stop_timer: type=SIP_TIMER_REMOVE_TRANSACTION value=32000 retries=0 10192857.003 |08:02:55.208 |AppInfo |//SIP/Stack/Info/0x10212c70/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be 10192857.004 |08:02:55.208 |AppInfo |//SIP/Stack/Transport/0x0/sipConnectionManagerUnregisterCtxtInCon: gConnTab=0xf5535a0, addr=192.168.10.3, port=5060, unregistering context= 10192857.005 |08:02:55.208 |AppInfo |//SIP/Stack/Error/0x0/sipConnectionManagerUnregisterCtxtInCon: Could not find conn holder for addr=192.168.10.3 10192857.006 |08:02:55.208 |AppInfo |//SIP/Stack/Transport/0x10212c70/sipSPITransportContextCleanup: Could not purge context gcb=0x10212c70 from the connection; gcb 10192857.007 |08:02:55.209 |AppInfo |//SIP/Stack/Info/0x10212c70/sipSPIUfreeOneCCB: Freeing ccb 10212c70 10192858.000 |08:02:55.313 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192859.000 |08:02:56.319 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192860.000 |08:02:56.319 |SdlStat |Period: 6s #Lines: 20 #Bytes: 4704 Total Number of Buffers: 10000 Free LWM: 9992 Free LWM(total): 9305 10192861.000 |08:02:57.325 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192862.000 |08:02:58.245 |SdlSig |SdlReadRsp |wait |SIPTcp(2,100,64,1) |SdlTCPConnection(2,100,13,578) |2,100,13,578.991^192.168.20.32^* |*TraceFlagOverrode 10192862.001 |08:02:58.245 |AppInfo |SIPTcp - SdlRead bufferLen=880 10192862.002 |08:02:58.245 |AppInfo |SIPTcp - wait_SdlReadRsp: Incoming SIP TCP message from 192.168.20.32 on port 49409 index 13184 with 880 bytes: [0,NET] REGISTER sip:192.168.10.8 SIP/2.0 Via: SIP/2.0/TCP 192.168.20.32:49409;branch=z9hG4bK561a7a0e From: ;tag=c07bbca0e1875b0c06caf1fa-7aa0f025 To: Call-ID: c07bbca0-e18700d2-2edf5940-50df2378@192.168.20.32 Max-Forwards: 70 Date: Wed, 02 Sep 2015 08:02:54 GMT CSeq: 22442 REGISTER User-Agent: Cisco-CP9951/9.4.2 Contact: ;+sip.instance="";+u.sip!devicename.ccm.cisco.com="SEPC07BBCA0E187";+u.sip!model.ccm.cisco.com="537" Supported: replaces,join,sdp-anat,norefersub,resource-priority,extended-refer,X-cisco-callinfo,X-cisco-serviceuri,X-cisco-escapecodes,X-cisco-service-control,X-cisco-srtp-fallback,X-cisco-monrec,X-cisco-config,X-cisco-sis-7.0.0,X-cisco-xsi-8.0.1 Content-Length: 0 Expires: 3600 10192862.003 |08:02:58.245 |AppInfo |SIPTcp - SignalCounter = 337371 10192863.000 |08:02:58.245 |SdlSig |SIPSPISignal |wait |SIPHandler(2,100,72,1) |SIPTcp(2,100,64,1) |2,100,13,578.991^192.168.20.32^SEPC07BBCA0E187 |*TraceFlagOverrode 10192863.001 |08:02:58.245 |AppInfo |//SIP/Stack/Info/0x0/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 (SIP_NETWORK_MSG), for event 1 (SIPSPI_EV_NEW_MESSAGE) 10192863.002 |08:02:58.245 |AppInfo |//SIP/Stack/Transport/0x0/sipTransportProcessNWNewConnMsg: context=(nil) 10192863.003 |08:02:58.245 |AppInfo |//SIP/Stack/Transport/0x0/sipConnectionManagerProcessNewConnMsg: gConnTab=0xf553560, addr=192.168.20.32, port=49409, connid=13184, transport=TCP 10192863.004 |08:02:58.245 |AppInfo |//SIP/Stack/Info/0x0/sipHolderGetConnInstance: Return existing connection for port 49409 connId 13184 10192863.005 |08:02:58.245 |AppInfo |//SIP/Stack/Info/0x0/sipSPIFindRegisterCcb: *****CCB NOT found in UAS Request table. ccb=(nil) 10192863.006 |08:02:58.245 |AppInfo |//SIP/Stack/Info/0x0/sipSPIAddContextToTable: Added context(0x102114a8) with key=[454530] to table 10192863.007 |08:02:58.245 |AppInfo |//SIP/Stack/Transport/0x0/sipSPIUpdateResponseInfo: Dialog Transaction Address 192.168.20.32,Port 49409, Transport 2, SentBy Port 49409 10192863.008 |08:02:58.245 |AppInfo |//SIP/Stack/States/0x102114a8/sipSPIChangeState: 0x102114a8 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE) 10192863.009 |08:02:58.245 |AppInfo |//SIP/Stack/Transport/0x0/sipSPIUpdateResponseInfo: Subsq Transaction Address 192.168.20.32,Port 49409, Transport 2, SentBy Port 5060 10192863.010 |08:02:58.245 |AppInfo |//SIP/Stack/Transport/0x0/sipSPIUpdateResponseInfo: Subsq Transaction Address 192.168.20.32,Port 49409, Transport 2, SentBy Port 49409 10192863.011 |08:02:58.245 |AppInfo |//SIP/Stack/Transport/0x102114a8/sipSPISendResponse: Sending INFO Response to the transport layer 10192863.012 |08:02:58.245 |AppInfo |//SIP/Stack/Transport/0x102114a8/sipSPITransportSendMessage: msg=0xb6e30ec8, addr=192.168.20.32, port=49409, sentBy_port=49409, is_req=0, transp 10192863.013 |08:02:58.245 |AppInfo |//SIP/Stack/Transport/0x0/sipInstanceGetConnectionId: Registering gcb=0x102114a8 with connection=0xfe2df08 context list 10192863.014 |08:02:58.245 |AppInfo |//SIP/Stack/Transport/0x102114a8/sipTransportLogicSendMsg: Connection obtained...sending msg=0xb6e30ec8 10192863.015 |08:02:58.245 |AppInfo |//SIP/Stack/Transport/0x102114a8/sipTransportPostSendMessage: Posting send for msg=0xb6e30ec8, addr=192.168.20.32, port=49409, connId=13184 for T 10192863.016 |08:02:58.245 |AppInfo |//SIP/Stack/Info/0x102114a8/sipSPIUaddCcbToTable: Added to table. ccb=0x102114a8 key=c07bbca0-e18700d2-2edf5940-50df2378@192.168.20.324901c07bbca0e1875b0c06caf1fa-7aa0f025 10192863.017 |08:02:58.245 |AppInfo |//SIP/SIPHandler/ccbId=454881/scbId=0/findDevicePID: Routed to SIPStationInit 10192863.018 |08:02:58.245 |AppInfo |//SIP/Stack/Event/0x102114a8/sact_idle_new_message_register: ccsip_api_register_ind return value : SIP_SUCCESS 10192863.019 |08:02:58.245 |AppInfo |//SIP/Stack/States/0x102114a8/sipSPIChangeState: 0x102114a8 : State change from (STATE_IDLE, SUBSTATE_NONE) to (SIP_STATE_INCOMING_REGISTER, SUBSTATE_NONE) 10192864.000 |08:02:58.245 |SdlSig |SIPSPISignal |wait |SIPTcp(2,100,64,1) |SIPHandler(2,100,72,1) |2,100,13,578.991^192.168.20.32^SEPC07BBCA0E187 |*TraceFlagOverrode 10192864.001 |08:02:58.245 |AppInfo |SIPTcp - wait_SdlSPISignal: Outgoing SIP TCP message to 192.168.20.32 on port 49409 index 13184 [1115447,NET] SIP/2.0 100 Trying Via: SIP/2.0/TCP 192.168.20.32:49409;branch=z9hG4bK561a7a0e From: ;tag=c07bbca0e1875b0c06caf1fa-7aa0f025 To: Date: Wed, 02 Sep 2015 08:02:58 GMT Call-ID: c07bbca0-e18700d2-2edf5940-50df2378@192.168.20.32 CSeq: 22442 REGISTER Content-Length: 0 10192865.000 |08:02:58.245 |SdlSig |SIPRegisterInd |wait |SIPStationInit(2,100,65,1) |SIPHandler(2,100,72,1) |2,100,13,578.991^192.168.20.32^SEPC07BBCA0E187 |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] ccbID= 454881 --TransType=1 --TransSecurity=0 PeerAddr = 192.168.20.32:49409 MAC = DeviceName = X509SubjectName = SubjectAltname = 10192865.001 |08:02:58.245 |AppInfo |SIPStationInit: connID=13184, SEPC07BBCA0E187, 192.168.20.32:49409, checkTcpConnection: Connection index 13184 matches 10192865.002 |08:02:58.245 |AppInfo |SIPStationInit: connID=13184, SEPC07BBCA0E187, 192.168.20.32:49409, Routing to D (2,100,66,143), regCount=724 10192866.000 |08:02:58.245 |SdlSig |SIPRegisterInd |wait |SIPStationD(2,100,66,143) |SIPStationInit(2,100,65,1) |2,100,13,578.991^192.168.20.32^SEPC07BBCA0E187 |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] ccbID= 454881 --TransType=1 --TransSecurity=0 PeerAddr = 192.168.20.32:49409 MAC = C07BBCA0E187 DeviceName = SEPC07BBCA0E187 X509SubjectName = SubjectAltname = 10192866.001 |08:02:58.245 |AppInfo |SIPStationD(143) - setUaTypeAndCepn: uaType is CISCO_ENHANCED_PHONE 10192866.002 |08:02:58.245 |AppInfo |SIPStationD(143) - Received REGISTER from 4901@192.168.20.32:49409 10192866.003 |08:02:58.245 |AppInfo |SIPStationD(143) - parseSupportedHeader: X-cisco-callinfo=T X-cisco-serviceuri=T X-cisco-escapecodes=T X-cisco-service-control=T X-cisco-duplicate-reg=F X-cisco-graceful-reg=F X-cisco-srtp-fallback=T X-cisco-ix=F X-cisco-monrec=T X-cisco-xsi=T xsi-version=8.0.1 X-cisco-sis=T sis-version=7.0.0 extended-refer=T norefersub=T join=T cso[rcc=T,sc=T,max=6] slNotify=3 hsNotify=3 blfNotify=3 fi[joinReq=T,cfwdAny=T,coaching=T,oosAlarm=T,joinDXferPolicy=2,xCiscoNumber=T,OrigCalled=T,iXChannel=F,BFCP=F,mobileConnectStatusRefresh=F,confDisplayInstanceSupport=T]MobilityExtension Feature Indication is empty 10192866.004 |08:02:58.245 |AppInfo |SIPStationD(143) - storeContactHeader: Request-URI is sip:8c3deb6d-a503-8513-4601-7d77a85ce60b@192.168.20.32:49409;transport=tcp 10192866.005 |08:02:58.245 |AppInfo |setSIPAoR: aor = sip:4901@192.168.10.8 10192866.006 |08:02:58.245 |AppInfo |SIPStationD(143) - Register refresh #723 for line 1 10192867.000 |08:02:58.245 |SdlSig |SIPRegisterResp |wait |SIPHandler(2,100,72,1) |SIPStationD(2,100,66,143) |2,100,13,578.991^192.168.20.32^SEPC07BBCA0E187 |[T:N-H:0,N:0,L:0,V:0,Z:0,D:0] ccbID= 454881 --TransType=1 --TransSecurity=0 PeerAddr= 192.168.20.32:49409 respCode= 200 action= 2 device= 10192867.001 |08:02:58.245 |AppInfo |//SIP/Stack/Info/0x0/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 (SIP_APPLICATION_MSG), for event 42 (SIPSPI_EV_REGISTER_RESP) 10192867.002 |08:02:58.245 |AppInfo |//SIP/Stack/Info/0x102114a8/sipSPISendResponse: Associated container=0xb6e9f790 to REGISTER Response 200 10192867.003 |08:02:58.245 |AppInfo |//SIP/Stack/Transport/0x102114a8/sipSPISendResponse: Sending INFO Response to the transport layer 10192867.004 |08:02:58.245 |AppInfo |//SIP/Stack/Transport/0x102114a8/sipSPITransportSendMessage: msg=0xb6e30ec8, addr=192.168.20.32, port=49409, sentBy_port=49409, is_req=0, transp 10192867.005 |08:02:58.245 |AppInfo |//SIP/Stack/Transport/0x0/sipInstanceGetConnectionId: gcb=0x102114a8 is already on connection=0xfe2df08 context_list 10192867.006 |08:02:58.245 |AppInfo |//SIP/Stack/Transport/0x102114a8/sipTransportLogicSendMsg: Connection obtained...sending msg=0xb6e30ec8 10192867.007 |08:02:58.245 |AppInfo |//SIP/Stack/Transport/0x102114a8/sipTransportPostSendMessage: Posting send for msg=0xb6e30ec8, addr=192.168.20.32, port=49409, connId=13184 for T 10192867.008 |08:02:58.245 |AppInfo |//SIP/Stack/Info/0x102114a8/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be 10192867.009 |08:02:58.245 |AppInfo |//SIP/Stack/Transport/0x0/sipConnectionManagerUnregisterCtxtInCon: gConnTab=0xf553560, addr=192.168.20.32, port=49409, unregistering context= 10192867.010 |08:02:58.245 |AppInfo |//SIP/Stack/Info/0x102114a8/sipSPIUfreeOneCCB: Freeing ccb 102114a8 10192867.011 |08:02:58.245 |AppInfo |//SIP/Stack/Transport/0x0/sipSPITransportSendMessage: gcb has cleanedup, Done with send operations for this context 10192868.000 |08:02:58.245 |SdlSig |SIPSPISignal |wait |SIPTcp(2,100,64,1) |SIPHandler(2,100,72,1) |2,100,13,578.991^192.168.20.32^SEPC07BBCA0E187 |*TraceFlagOverrode 10192868.001 |08:02:58.245 |AppInfo |SIPTcp - wait_SdlSPISignal: Outgoing SIP TCP message to 192.168.20.32 on port 49409 index 13184 [1115448,NET] SIP/2.0 200 OK Via: SIP/2.0/TCP 192.168.20.32:49409;branch=z9hG4bK561a7a0e From: ;tag=c07bbca0e1875b0c06caf1fa-7aa0f025 To: ;tag=288052331 Date: Wed, 02 Sep 2015 08:02:58 GMT Call-ID: c07bbca0-e18700d2-2edf5940-50df2378@192.168.20.32 CSeq: 22442 REGISTER Expires: 120 Contact: ;+sip.instance="";+u.sip!devicename.ccm.cisco.com="SEPC07BBCA0E187";+u.sip!model.ccm.cisco.com="537" Supported: X-cisco-srtp-fallback,X-cisco-sis-6.0.0 Content-Length: 0 10192869.000 |08:02:58.339 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192870.000 |08:02:59.356 |SdlSig |DeviceEventReceiptMonitoringTimer |wait |StationInit(2,100,57,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[R:H-H:2,N:0,L:0,V:0,Z:0,D:0] 10192871.000 |08:02:59.357 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192872.000 |08:02:59.986 |AppInfo |EnvProcessUdpHandler::handle_input - handle = 335 10192873.000 |08:02:59.986 |AppInfo |EnvProcessUdpHandler::handle_input Status: 0, Id: 0 10192874.000 |08:02:59.986 |SdlSig |UdpDataInd |wait |SIPUdp(2,100,63,1) |EnvProcessUdpPort(2,100,238,1) |2,100,238,1.109327^*^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] varStatus=0 varId=0 varSrcIpAddr=3232238084 varIpPort=5060 varFamily=2 10192874.001 |08:02:59.986 |AppInfo |//SIP/SIPUdp/wait_UdpDataInd: Incoming SIP UDP message size 355 from 192.168.10.4:[5060]: [1115449,NET] OPTIONS sip:192.168.10.8 SIP/2.0 From: ;tag=ACU-7f3e74b4-185e4b6e To: Contact: Call-ID: 07307a68-1dd2-11b2-8692-f8c0887083ae@192.168.10.4 CSeq: 11162270 OPTIONS Content-Length: 0 Max-Forwards: 70 Via: SIP/2.0/UDP 192.168.10.4:5060;branch=z9hG4bK0730c37e-1dd2-11b2-ae97-f390eeb13d6d;rport 10192875.000 |08:02:59.987 |SdlSig |SIPSPISignal |wait |SIPHandler(2,100,72,1) |SIPUdp(2,100,63,1) |2,100,238,1.109327^192.168.10.4^* |*TraceFlagOverrode 10192875.001 |08:02:59.987 |AppInfo |//SIP/Stack/Info/0x0/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 (SIP_NETWORK_MSG), for event 1 (SIPSPI_EV_NEW_MESSAGE) 10192875.002 |08:02:59.987 |AppInfo |//SIP/Stack/Transport/0x0/sipTransportProcessNWNewConnMsg: context=(nil) 10192875.003 |08:02:59.987 |AppInfo |//SIP/Stack/Info/0x0/sipSPIAddContextToTable: Added context(0x102085f8) with key=[454531] to table 10192875.004 |08:02:59.987 |AppInfo |//SIP/Stack/Transport/0x0/sipSPIUpdateResponseInfo: Dialog Transaction Address 192.168.10.4,Port 5060, Transport 1, SentBy Port 5060 10192875.005 |08:02:59.987 |AppInfo |//SIP/Stack/States/0x102085f8/sipSPIChangeState: 0x102085f8 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE) 10192875.006 |08:02:59.987 |AppInfo |//SIP/Stack/Transport/0x0/sipSPIUpdateResponseInfo: Subsq Transaction Address 192.168.10.4,Port 5060, Transport 1, SentBy Port 5060 10192875.007 |08:02:59.987 |AppInfo |//SIP/Stack/Transport/0x0/sipSPIUpdateResponseInfo: Subsq Transaction Address 192.168.10.4,Port 5060, Transport 1, SentBy Port 5060 10192875.008 |08:02:59.987 |AppInfo |//SIP/Stack/Error/0x0/httpish_msg_free: Freeing NULL pointer! 10192875.009 |08:02:59.987 |AppInfo |//SIP/SIPHandler/ccbId=454882/scbId=0/findDevicePID: Routed to SIPD by sipAddr 10192875.010 |08:02:59.987 |AppInfo |//SIP/Stack/Info/0x102085f8/sact_idle_new_message_options: ccsip_api_options_ind returned: SIP_SUCCESS 10192875.011 |08:02:59.987 |AppInfo |//SIP/Stack/States/0x102085f8/sipSPIChangeState: 0x102085f8 : State change from (STATE_IDLE, SUBSTATE_NONE) to (SIP_STATE_OPTIONS_WAIT, SUBSTATE_NONE) 10192875.012 |08:02:59.987 |AppInfo |//SIP/Stack/Info/0x102085f8/sipSPIUaddCcbToTable: Added to table. ccb=0x102085f8 key=07307a68-1dd2-11b2-8692-f8c0887083ae@192.168.10.4 10192876.000 |08:02:59.987 |SdlSig |SIPOptionsInd |restart0 |SIPD(2,100,74,124) |SIPHandler(2,100,72,1) |2,100,238,1.109327^192.168.10.4^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] ccbID= 454882 --TransType=2 --TransSecurity=0 PeerAddr = 192.168.10.4:5060 10192877.000 |08:02:59.987 |SdlSig |SIPOptionsResp |wait |SIPHandler(2,100,72,1) |SIPD(2,100,74,124) |2,100,238,1.109327^192.168.10.4^* |[T:N-H:0,N:0,L:0,V:0,Z:0,D:0] ccbID= 454882 --TransType=2 --TransSecurity=0 PeerAddr = 192.168.10.4:5060 10192877.001 |08:02:59.987 |AppInfo |//SIP/Stack/Info/0x0/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 (SIP_APPLICATION_MSG), for event 39 (SIPSPI_EV_CC_OPTIONS_RESP) 10192877.002 |08:02:59.987 |AppInfo |//SIP/Stack/Info/0x102085f8/sipSPISendOptionsResponse: Associated container=0xb2d1fdc8 to Options Response 10192877.003 |08:02:59.987 |AppInfo |//SIP/Stack/Transport/0x102085f8/sipSPITransportSendMessage: msg=0xb6e30ec8, addr=192.168.10.4, port=5060, sentBy_port=5060, is_req=0, transp 10192877.004 |08:02:59.987 |AppInfo |//SIP/Stack/Transport/0x102085f8/sipTransportPostSendMessage: Posting send for msg=0xb6e30ec8, addr=192.168.10.4, port=5060, connId=0 for U 10192877.005 |08:02:59.987 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/sip_stop_timer: type=SIP_TIMER_REMOVE_TRANSACTION value=32000 retries=0 10192877.006 |08:02:59.987 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/sip_start_timer: type=SIP_TIMER_REMOVE_TRANSACTION value=32000 retries=0 10192878.000 |08:02:59.987 |SdlSig |SIPSPISignal |wait |SIPUdp(2,100,63,1) |SIPHandler(2,100,72,1) |2,100,238,1.109327^192.168.10.4^* |*TraceFlagOverrode 10192878.001 |08:02:59.987 |AppInfo |//SIP/SIPUdp/wait_SdlSPISignal: Outgoing SIP UDP message to 192.168.10.4:[5060]: [1115450,NET] SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.10.4:5060;branch=z9hG4bK0730c37e-1dd2-11b2-ae97-f390eeb13d6d;rport From: ;tag=ACU-7f3e74b4-185e4b6e To: ;tag=1745311530 Date: Wed, 02 Sep 2015 08:02:59 GMT Call-ID: 07307a68-1dd2-11b2-8692-f8c0887083ae@192.168.10.4 CSeq: 11162270 OPTIONS Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY Content-Length: 0 10192879.000 |08:02:59.987 |SdlSig |UdpSendReq |start |EnvProcessUdpPort(2,100,238,1) |SIPUdp(2,100,63,1) |2,100,238,1.109327^192.168.10.4^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] varId=0 varIpAddr=3232238084 varIpPort=5060 varFamily=2 10192879.001 |08:02:59.987 |AppInfo |EnvProcessUdpPort - EnvProcessUdpHandler::fireSignal() varId = 0 10192879.002 |08:02:59.987 |AppInfo |EnvProcessUdpHandler::fireSignal - SEND: index = 0, handler = 0x10544140 10192879.003 |08:02:59.987 |AppInfo |EnvProcessUdpPort::fireSignal - SEND, destination = 192.168.10.4:5060 10192879.004 |08:02:59.987 |AppInfo |EnvProcessUdpPort - EnvProcessUdpHandler::send(buff, 431, 192.168.10.4:5060) 10192880.000 |08:03:00.358 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192881.000 |08:03:01.376 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192882.000 |08:03:02.385 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192883.000 |08:03:02.385 |SdlStat |Period: 6s #Lines: 89 #Bytes: 19033 Total Number of Buffers: 10000 Free LWM: 9950 Free LWM(total): 9305 10192884.000 |08:03:03.041 |SdlSig |SdlReadRsp |wait |SIPTcp(2,100,64,1) |SdlTCPConnection(2,100,13,558) |2,100,13,558.4317^192.168.20.33^* |*TraceFlagOverrode 10192884.001 |08:03:03.041 |AppInfo |SIPTcp - SdlRead bufferLen=880 10192884.002 |08:03:03.041 |AppInfo |SIPTcp - wait_SdlReadRsp: Incoming SIP TCP message from 192.168.20.33 on port 52923 index 13164 with 880 bytes: [0,NET] REGISTER sip:192.168.10.8 SIP/2.0 Via: SIP/2.0/TCP 192.168.20.33:52923;branch=z9hG4bK4f160d09 From: ;tag=c07bbca0dd6857793b08e6b3-3ac450e2 To: Call-ID: c07bbca0-dd68001a-4bd8b1c8-50688027@192.168.20.33 Max-Forwards: 70 Date: Wed, 02 Sep 2015 08:03:00 GMT CSeq: 22425 REGISTER User-Agent: Cisco-CP9951/9.4.2 Contact: ;+sip.instance="";+u.sip!devicename.ccm.cisco.com="SEPC07BBCA0DD68";+u.sip!model.ccm.cisco.com="537" Supported: replaces,join,sdp-anat,norefersub,resource-priority,extended-refer,X-cisco-callinfo,X-cisco-serviceuri,X-cisco-escapecodes,X-cisco-service-control,X-cisco-srtp-fallback,X-cisco-monrec,X-cisco-config,X-cisco-sis-7.0.0,X-cisco-xsi-8.0.1 Content-Length: 0 Expires: 3600 10192884.003 |08:03:03.041 |AppInfo |SIPTcp - SignalCounter = 337372 10192885.000 |08:03:03.042 |SdlSig |SIPSPISignal |wait |SIPHandler(2,100,72,1) |SIPTcp(2,100,64,1) |2,100,13,558.4317^192.168.20.33^SEPC07BBCA0DD68 |*TraceFlagOverrode 10192885.001 |08:03:03.042 |AppInfo |//SIP/Stack/Info/0x0/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 (SIP_NETWORK_MSG), for event 1 (SIPSPI_EV_NEW_MESSAGE) 10192885.002 |08:03:03.042 |AppInfo |//SIP/Stack/Transport/0x0/sipTransportProcessNWNewConnMsg: context=(nil) 10192885.003 |08:03:03.042 |AppInfo |//SIP/Stack/Transport/0x0/sipConnectionManagerProcessNewConnMsg: gConnTab=0xf553560, addr=192.168.20.33, port=52923, connid=13164, transport=TCP 10192885.004 |08:03:03.042 |AppInfo |//SIP/Stack/Info/0x0/sipHolderGetConnInstance: Return existing connection for port 52923 connId 13164 10192885.005 |08:03:03.042 |AppInfo |//SIP/Stack/Info/0x0/sipSPIFindRegisterCcb: *****CCB NOT found in UAS Request table. ccb=(nil) 10192885.006 |08:03:03.042 |AppInfo |//SIP/Stack/Info/0x0/sipSPIAddContextToTable: Added context(0x1021d2e8) with key=[454532] to table 10192885.007 |08:03:03.042 |AppInfo |//SIP/Stack/Transport/0x0/sipSPIUpdateResponseInfo: Dialog Transaction Address 192.168.20.33,Port 52923, Transport 2, SentBy Port 52923 10192885.008 |08:03:03.042 |AppInfo |//SIP/Stack/States/0x1021d2e8/sipSPIChangeState: 0x1021d2e8 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE) 10192885.009 |08:03:03.042 |AppInfo |//SIP/Stack/Transport/0x0/sipSPIUpdateResponseInfo: Subsq Transaction Address 192.168.20.33,Port 52923, Transport 2, SentBy Port 5060 10192885.010 |08:03:03.042 |AppInfo |//SIP/Stack/Transport/0x0/sipSPIUpdateResponseInfo: Subsq Transaction Address 192.168.20.33,Port 52923, Transport 2, SentBy Port 52923 10192885.011 |08:03:03.042 |AppInfo |//SIP/Stack/Transport/0x1021d2e8/sipSPISendResponse: Sending INFO Response to the transport layer 10192885.012 |08:03:03.042 |AppInfo |//SIP/Stack/Transport/0x1021d2e8/sipSPITransportSendMessage: msg=0xb6eaa7c0, addr=192.168.20.33, port=52923, sentBy_port=52923, is_req=0, transp 10192885.013 |08:03:03.042 |AppInfo |//SIP/Stack/Transport/0x0/sipInstanceGetConnectionId: Registering gcb=0x1021d2e8 with connection=0xfe2e788 context list 10192885.014 |08:03:03.042 |AppInfo |//SIP/Stack/Transport/0x1021d2e8/sipTransportLogicSendMsg: Connection obtained...sending msg=0xb6eaa7c0 10192885.015 |08:03:03.042 |AppInfo |//SIP/Stack/Transport/0x1021d2e8/sipTransportPostSendMessage: Posting send for msg=0xb6eaa7c0, addr=192.168.20.33, port=52923, connId=13164 for T 10192885.016 |08:03:03.042 |AppInfo |//SIP/Stack/Info/0x1021d2e8/sipSPIUaddCcbToTable: Added to table. ccb=0x1021d2e8 key=c07bbca0-dd68001a-4bd8b1c8-50688027@192.168.20.334903c07bbca0dd6857793b08e6b3-3ac450e2 10192885.017 |08:03:03.042 |AppInfo |//SIP/SIPHandler/ccbId=454883/scbId=0/findDevicePID: Routed to SIPStationInit 10192885.018 |08:03:03.042 |AppInfo |//SIP/Stack/Event/0x1021d2e8/sact_idle_new_message_register: ccsip_api_register_ind return value : SIP_SUCCESS 10192885.019 |08:03:03.042 |AppInfo |//SIP/Stack/States/0x1021d2e8/sipSPIChangeState: 0x1021d2e8 : State change from (STATE_IDLE, SUBSTATE_NONE) to (SIP_STATE_INCOMING_REGISTER, SUBSTATE_NONE) 10192886.000 |08:03:03.042 |SdlSig |SIPSPISignal |wait |SIPTcp(2,100,64,1) |SIPHandler(2,100,72,1) |2,100,13,558.4317^192.168.20.33^SEPC07BBCA0DD68 |*TraceFlagOverrode 10192886.001 |08:03:03.042 |AppInfo |SIPTcp - wait_SdlSPISignal: Outgoing SIP TCP message to 192.168.20.33 on port 52923 index 13164 [1115452,NET] SIP/2.0 100 Trying Via: SIP/2.0/TCP 192.168.20.33:52923;branch=z9hG4bK4f160d09 From: ;tag=c07bbca0dd6857793b08e6b3-3ac450e2 To: Date: Wed, 02 Sep 2015 08:03:03 GMT Call-ID: c07bbca0-dd68001a-4bd8b1c8-50688027@192.168.20.33 CSeq: 22425 REGISTER Content-Length: 0 10192887.000 |08:03:03.042 |SdlSig |SIPRegisterInd |wait |SIPStationInit(2,100,65,1) |SIPHandler(2,100,72,1) |2,100,13,558.4317^192.168.20.33^SEPC07BBCA0DD68 |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] ccbID= 454883 --TransType=1 --TransSecurity=0 PeerAddr = 192.168.20.33:52923 MAC = DeviceName = X509SubjectName = SubjectAltname = 10192887.001 |08:03:03.042 |AppInfo |SIPStationInit: connID=13164, SEPC07BBCA0DD68, 192.168.20.33:52923, checkTcpConnection: Connection index 13164 matches 10192887.002 |08:03:03.042 |AppInfo |SIPStationInit: connID=13164, SEPC07BBCA0DD68, 192.168.20.33:52923, Routing to D (2,100,66,137), regCount=4307 10192888.000 |08:03:03.042 |SdlSig |SIPRegisterInd |wait |SIPStationD(2,100,66,137) |SIPStationInit(2,100,65,1) |2,100,13,558.4317^192.168.20.33^SEPC07BBCA0DD68 |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] ccbID= 454883 --TransType=1 --TransSecurity=0 PeerAddr = 192.168.20.33:52923 MAC = C07BBCA0DD68 DeviceName = SEPC07BBCA0DD68 X509SubjectName = SubjectAltname = 10192888.001 |08:03:03.042 |AppInfo |SIPStationD(137) - setUaTypeAndCepn: uaType is CISCO_ENHANCED_PHONE 10192888.002 |08:03:03.042 |AppInfo |SIPStationD(137) - Received REGISTER from 4903@192.168.20.33:52923 10192888.003 |08:03:03.042 |AppInfo |SIPStationD(137) - parseSupportedHeader: X-cisco-callinfo=T X-cisco-serviceuri=T X-cisco-escapecodes=T X-cisco-service-control=T X-cisco-duplicate-reg=F X-cisco-graceful-reg=F X-cisco-srtp-fallback=T X-cisco-ix=F X-cisco-monrec=T X-cisco-xsi=T xsi-version=8.0.1 X-cisco-sis=T sis-version=7.0.0 extended-refer=T norefersub=T join=T cso[rcc=T,sc=T,max=6] slNotify=3 hsNotify=3 blfNotify=3 fi[joinReq=T,cfwdAny=T,coaching=T,oosAlarm=T,joinDXferPolicy=2,xCiscoNumber=T,OrigCalled=T,iXChannel=F,BFCP=F,mobileConnectStatusRefresh=F,confDisplayInstanceSupport=T]MobilityExtension Feature Indication is empty 10192888.004 |08:03:03.042 |AppInfo |SIPStationD(137) - storeContactHeader: Request-URI is sip:2c7ec663-dfe4-d859-c636-3bf387cf7d20@192.168.20.33:52923;transport=tcp 10192888.005 |08:03:03.042 |AppInfo |setSIPAoR: aor = sip:4903@192.168.10.8 10192888.006 |08:03:03.042 |AppInfo |SIPStationD(137) - Register refresh #4306 for line 1 10192889.000 |08:03:03.043 |SdlSig |SIPRegisterResp |wait |SIPHandler(2,100,72,1) |SIPStationD(2,100,66,137) |2,100,13,558.4317^192.168.20.33^SEPC07BBCA0DD68 |[T:N-H:0,N:0,L:0,V:0,Z:0,D:0] ccbID= 454883 --TransType=1 --TransSecurity=0 PeerAddr= 192.168.20.33:52923 respCode= 200 action= 2 device= 10192889.001 |08:03:03.043 |AppInfo |//SIP/Stack/Info/0x0/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 (SIP_APPLICATION_MSG), for event 42 (SIPSPI_EV_REGISTER_RESP) 10192889.002 |08:03:03.043 |AppInfo |//SIP/Stack/Info/0x1021d2e8/sipSPISendResponse: Associated container=0xb2d29838 to REGISTER Response 200 10192889.003 |08:03:03.043 |AppInfo |//SIP/Stack/Transport/0x1021d2e8/sipSPISendResponse: Sending INFO Response to the transport layer 10192889.004 |08:03:03.043 |AppInfo |//SIP/Stack/Transport/0x1021d2e8/sipSPITransportSendMessage: msg=0xb6eb4bb8, addr=192.168.20.33, port=52923, sentBy_port=52923, is_req=0, transp 10192889.005 |08:03:03.043 |AppInfo |//SIP/Stack/Transport/0x0/sipInstanceGetConnectionId: gcb=0x1021d2e8 is already on connection=0xfe2e788 context_list 10192889.006 |08:03:03.043 |AppInfo |//SIP/Stack/Transport/0x1021d2e8/sipTransportLogicSendMsg: Connection obtained...sending msg=0xb6eb4bb8 10192889.007 |08:03:03.043 |AppInfo |//SIP/Stack/Transport/0x1021d2e8/sipTransportPostSendMessage: Posting send for msg=0xb6eb4bb8, addr=192.168.20.33, port=52923, connId=13164 for T 10192889.008 |08:03:03.043 |AppInfo |//SIP/Stack/Info/0x1021d2e8/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be 10192889.009 |08:03:03.043 |AppInfo |//SIP/Stack/Transport/0x0/sipConnectionManagerUnregisterCtxtInCon: gConnTab=0xf553560, addr=192.168.20.33, port=52923, unregistering context= 10192889.010 |08:03:03.043 |AppInfo |//SIP/Stack/Info/0x1021d2e8/sipSPIUfreeOneCCB: Freeing ccb 1021d2e8 10192889.011 |08:03:03.043 |AppInfo |//SIP/Stack/Transport/0x0/sipSPITransportSendMessage: gcb has cleanedup, Done with send operations for this context 10192890.000 |08:03:03.043 |SdlSig |SIPSPISignal |wait |SIPTcp(2,100,64,1) |SIPHandler(2,100,72,1) |2,100,13,558.4317^192.168.20.33^SEPC07BBCA0DD68 |*TraceFlagOverrode 10192890.001 |08:03:03.043 |AppInfo |SIPTcp - wait_SdlSPISignal: Outgoing SIP TCP message to 192.168.20.33 on port 52923 index 13164 [1115453,NET] SIP/2.0 200 OK Via: SIP/2.0/TCP 192.168.20.33:52923;branch=z9hG4bK4f160d09 From: ;tag=c07bbca0dd6857793b08e6b3-3ac450e2 To: ;tag=1302336225 Date: Wed, 02 Sep 2015 08:03:03 GMT Call-ID: c07bbca0-dd68001a-4bd8b1c8-50688027@192.168.20.33 CSeq: 22425 REGISTER Expires: 120 Contact: ;+sip.instance="";+u.sip!devicename.ccm.cisco.com="SEPC07BBCA0DD68";+u.sip!model.ccm.cisco.com="537" Supported: X-cisco-srtp-fallback,X-cisco-sis-6.0.0 Content-Length: 0 10192891.000 |08:03:03.391 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192892.000 |08:03:04.694 |SdlSig |ReapOldTokenRegistrationsTimer |wait |SIPStationInit(2,100,65,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[R:H-H:6,N:0,L:0,V:0,Z:0,D:0] 10192893.000 |08:03:04.694 |SdlSig |DeviceEventReceiptMonitoringTimer |wait |StationInit(2,100,57,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[R:H-H:3,N:0,L:0,V:0,Z:0,D:0] 10192894.000 |08:03:04.695 |SdlSig |SdlPollReqTimer |wait |SdlLinkControl(2,100,18,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |*TraceFlagOverrode 10192894.001 |08:03:04.695 |SdlError | | | | | |SdlLinkHandler::sendPollRequest - Did not received Poll Response. Going Down. NodeId: 1, AppId: 300, TCPAddr[:0] 10192894.002 |08:03:04.695 |SdlError | | | | | |SdlLinkHandler::sendPollRequest - Did not received Poll Response. Going Down. NodeId: 2, AppId: 300, TCPAddr[:0] 10192894.003 |08:03:04.695 |SdlError | | | | | |SdlLinkHandler::sendPollRequest - Did not received Poll Response. Going Down. NodeId: 3, AppId: 300, TCPAddr[:0] 10192895.000 |08:03:04.697 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192896.000 |08:03:05.704 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192897.000 |08:03:06.709 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192898.000 |08:03:07.729 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192899.000 |08:03:08.739 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192900.000 |08:03:08.739 |SdlStat |Period: 6s #Lines: 62 #Bytes: 14242 Total Number of Buffers: 10000 Free LWM: 9950 Free LWM(total): 9305 10192901.000 |08:03:10.331 |SdlSig |DeviceEventReceiptMonitoringTimer |wait |StationInit(2,100,57,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[R:H-H:3,N:0,L:0,V:0,Z:0,D:0] 10192902.000 |08:03:10.333 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192903.000 |08:03:11.340 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192904.000 |08:03:12.354 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192905.000 |08:03:13.359 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192906.000 |08:03:14.381 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192907.000 |08:03:14.381 |SdlStat |Period: 6s #Lines: 6 #Bytes: 1567 Total Number of Buffers: 10000 Free LWM: 9998 Free LWM(total): 9305 10192908.000 |08:03:14.959 |SdlSig |ReapOldTokenRegistrationsTimer |wait |SIPStationInit(2,100,65,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[R:H-H:2,N:0,L:0,V:0,Z:0,D:0] 10192909.000 |08:03:14.959 |SdlSig |SdlPollReqTimer |wait |SdlLinkControl(2,100,18,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |*TraceFlagOverrode 10192909.001 |08:03:14.959 |SdlError | | | | | |SdlLinkHandler::sendPollRequest - Did not received Poll Response. Going Down. NodeId: 1, AppId: 300, TCPAddr[:0] 10192909.002 |08:03:14.960 |SdlError | | | | | |SdlLinkHandler::sendPollRequest - Did not received Poll Response. Going Down. NodeId: 2, AppId: 300, TCPAddr[:0] 10192909.003 |08:03:14.960 |SdlError | | | | | |SdlLinkHandler::sendPollRequest - Did not received Poll Response. Going Down. NodeId: 3, AppId: 300, TCPAddr[:0] 10192910.000 |08:03:15.163 |SdlSig |SdlReadRsp |wait |SIPTcp(2,100,64,1) |SdlTCPConnection(2,100,13,575) |2,100,13,575.3422^192.168.20.35^* |*TraceFlagOverrode 10192910.001 |08:03:15.163 |AppInfo |SIPTcp - SdlRead bufferLen=904 10192910.002 |08:03:15.163 |AppInfo |SIPTcp - wait_SdlReadRsp: Incoming SIP TCP message from 192.168.20.35 on port 49246 index 13181 with 904 bytes: [1115454,NET] REGISTER sip:192.168.10.8 SIP/2.0 Via: SIP/2.0/TCP 192.168.20.35:49246;branch=z9hG4bK39a7129e From: ;tag=c07bbca0ded4498376babdd5-429bdb53 To: Call-ID: c07bbca0-ded4001c-30195863-05279309@192.168.20.35 Max-Forwards: 70 Date: Wed, 02 Sep 2015 08:03:06 GMT CSeq: 21499 REGISTER User-Agent: Cisco-CP9951/9.4.2 Contact: ;+sip.instance="";+u.sip!devicename.ccm.cisco.com="SEPC07BBCA0DED4";+u.sip!model.ccm.cisco.com="537";expires=0;cisco-keep-alive Supported: replaces,join,sdp-anat,norefersub,resource-priority,extended-refer,X-cisco-callinfo,X-cisco-serviceuri,X-cisco-escapecodes,X-cisco-service-control,X-cisco-srtp-fallback,X-cisco-monrec,X-cisco-config,X-cisco-sis-7.0.0,X-cisco-xsi-8.0.1 Content-Length: 0 Expires: 0 10192910.003 |08:03:15.163 |AppInfo |SIPTcp - SignalCounter = 337373 10192911.000 |08:03:15.163 |SdlSig |SIPSPISignal |wait |SIPHandler(2,100,72,1) |SIPTcp(2,100,64,1) |2,100,13,575.3422^192.168.20.35^* |*TraceFlagOverrode 10192911.001 |08:03:15.163 |AppInfo |//SIP/Stack/Info/0x0/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 (SIP_NETWORK_MSG), for event 1 (SIPSPI_EV_NEW_MESSAGE) 10192911.002 |08:03:15.163 |AppInfo |//SIP/Stack/Transport/0x0/sipTransportProcessNWNewConnMsg: context=(nil) 10192911.003 |08:03:15.163 |AppInfo |//SIP/Stack/Transport/0x0/sipConnectionManagerProcessNewConnMsg: gConnTab=0xf553560, addr=192.168.20.35, port=49246, connid=13181, transport=TCP 10192911.004 |08:03:15.163 |AppInfo |//SIP/Stack/Info/0x0/sipHolderGetConnInstance: Return existing connection for port 49246 connId 13181 10192911.005 |08:03:15.163 |AppInfo |//SIP/Stack/Info/0x0/sipSPIFindRegisterCcb: *****CCB NOT found in UAS Request table. ccb=(nil) 10192911.006 |08:03:15.163 |AppInfo |//SIP/Stack/Info/0x0/sipSPIAddContextToTable: Added context(0x102026d8) with key=[454533] to table 10192911.007 |08:03:15.163 |AppInfo |//SIP/Stack/Transport/0x0/sipSPIUpdateResponseInfo: Dialog Transaction Address 192.168.20.35,Port 49246, Transport 2, SentBy Port 49246 10192911.008 |08:03:15.163 |AppInfo |//SIP/Stack/States/0x102026d8/sipSPIChangeState: 0x102026d8 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE) 10192911.009 |08:03:15.163 |AppInfo |//SIP/Stack/Transport/0x0/sipSPIUpdateResponseInfo: Subsq Transaction Address 192.168.20.35,Port 49246, Transport 2, SentBy Port 5060 10192911.010 |08:03:15.164 |AppInfo |//SIP/Stack/Transport/0x0/sipSPIUpdateResponseInfo: Subsq Transaction Address 192.168.20.35,Port 49246, Transport 2, SentBy Port 49246 10192911.011 |08:03:15.164 |AppInfo |//SIP/Stack/Transport/0x102026d8/sipSPISendResponse: Sending INFO Response to the transport layer 10192911.012 |08:03:15.164 |AppInfo |//SIP/Stack/Transport/0x102026d8/sipSPITransportSendMessage: msg=0xb6eaa7c0, addr=192.168.20.35, port=49246, sentBy_port=49246, is_req=0, transp 10192911.013 |08:03:15.164 |AppInfo |//SIP/Stack/Transport/0x0/sipInstanceGetConnectionId: Registering gcb=0x102026d8 with connection=0xfe2e128 context list 10192911.014 |08:03:15.164 |AppInfo |//SIP/Stack/Transport/0x102026d8/sipTransportLogicSendMsg: Connection obtained...sending msg=0xb6eaa7c0 10192911.015 |08:03:15.164 |AppInfo |//SIP/Stack/Transport/0x102026d8/sipTransportPostSendMessage: Posting send for msg=0xb6eaa7c0, addr=192.168.20.35, port=49246, connId=13181 for T 10192911.016 |08:03:15.164 |AppInfo |//SIP/Stack/Info/0x102026d8/sipSPIUaddCcbToTable: Added to table. ccb=0x102026d8 key=c07bbca0-ded4001c-30195863-05279309@192.168.20.354902c07bbca0ded4498376babdd5-429bdb53 10192911.017 |08:03:15.164 |AppInfo |//SIP/SIPHandler/ccbId=454884/scbId=0/findDevicePID: Routed to SIPStationInit 10192911.018 |08:03:15.164 |AppInfo |//SIP/Stack/Event/0x102026d8/sact_idle_new_message_register: ccsip_api_register_ind return value : SIP_SUCCESS 10192911.019 |08:03:15.164 |AppInfo |//SIP/Stack/States/0x102026d8/sipSPIChangeState: 0x102026d8 : State change from (STATE_IDLE, SUBSTATE_NONE) to (SIP_STATE_INCOMING_REGISTER, SUBSTATE_NONE) 10192912.000 |08:03:15.164 |SdlSig |SIPSPISignal |wait |SIPTcp(2,100,64,1) |SIPHandler(2,100,72,1) |2,100,13,575.3422^192.168.20.35^* |*TraceFlagOverrode 10192912.001 |08:03:15.164 |AppInfo |SIPTcp - wait_SdlSPISignal: Outgoing SIP TCP message to 192.168.20.35 on port 49246 index 13181 [1115455,NET] SIP/2.0 100 Trying Via: SIP/2.0/TCP 192.168.20.35:49246;branch=z9hG4bK39a7129e From: ;tag=c07bbca0ded4498376babdd5-429bdb53 To: Date: Wed, 02 Sep 2015 08:03:15 GMT Call-ID: c07bbca0-ded4001c-30195863-05279309@192.168.20.35 CSeq: 21499 REGISTER Content-Length: 0 10192913.000 |08:03:15.164 |SdlSig |SIPRegisterInd |wait |SIPStationInit(2,100,65,1) |SIPHandler(2,100,72,1) |2,100,13,575.3422^192.168.20.35^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] ccbID= 454884 --TransType=1 --TransSecurity=0 PeerAddr = 192.168.20.35:49246 MAC = DeviceName = X509SubjectName = SubjectAltname = 10192914.000 |08:03:15.164 |SdlSig |SIPRegisterResp |wait |SIPHandler(2,100,72,1) |SIPStationInit(2,100,65,1) |2,100,13,575.3422^192.168.20.35^* |[T:N-H:0,N:0,L:0,V:0,Z:0,D:0] ccbID= 454884 --TransType=1 --TransSecurity=0 PeerAddr= 192.168.20.35:49246 respCode= 200 action= 2 device= 10192914.001 |08:03:15.164 |AppInfo |//SIP/Stack/Info/0x0/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 (SIP_APPLICATION_MSG), for event 42 (SIPSPI_EV_REGISTER_RESP) 10192914.002 |08:03:15.164 |AppInfo |//SIP/Stack/Info/0x102026d8/sipSPISendResponse: Associated container=0xb6e5fa60 to REGISTER Response 200 10192914.003 |08:03:15.164 |AppInfo |//SIP/Stack/Transport/0x102026d8/sipSPISendResponse: Sending INFO Response to the transport layer 10192914.004 |08:03:15.164 |AppInfo |//SIP/Stack/Transport/0x102026d8/sipSPITransportSendMessage: msg=0xb6e1a718, addr=192.168.20.35, port=49246, sentBy_port=49246, is_req=0, transp 10192914.005 |08:03:15.164 |AppInfo |//SIP/Stack/Transport/0x0/sipInstanceGetConnectionId: gcb=0x102026d8 is already on connection=0xfe2e128 context_list 10192914.006 |08:03:15.164 |AppInfo |//SIP/Stack/Transport/0x102026d8/sipTransportLogicSendMsg: Connection obtained...sending msg=0xb6e1a718 10192914.007 |08:03:15.164 |AppInfo |//SIP/Stack/Transport/0x102026d8/sipTransportPostSendMessage: Posting send for msg=0xb6e1a718, addr=192.168.20.35, port=49246, connId=13181 for T 10192914.008 |08:03:15.164 |AppInfo |//SIP/Stack/Info/0x102026d8/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be 10192914.009 |08:03:15.164 |AppInfo |//SIP/Stack/Transport/0x0/sipConnectionManagerUnregisterCtxtInCon: gConnTab=0xf553560, addr=192.168.20.35, port=49246, unregistering context= 10192914.010 |08:03:15.164 |AppInfo |//SIP/Stack/Info/0x102026d8/sipSPIUfreeOneCCB: Freeing ccb 102026d8 10192914.011 |08:03:15.164 |AppInfo |//SIP/Stack/Transport/0x0/sipSPITransportSendMessage: gcb has cleanedup, Done with send operations for this context 10192915.000 |08:03:15.165 |SdlSig |SIPSPISignal |wait |SIPTcp(2,100,64,1) |SIPHandler(2,100,72,1) |2,100,13,575.3422^192.168.20.35^* |*TraceFlagOverrode 10192915.001 |08:03:15.165 |AppInfo |SIPTcp - wait_SdlSPISignal: Outgoing SIP TCP message to 192.168.20.35 on port 49246 index 13181 [1115456,NET] SIP/2.0 200 OK Via: SIP/2.0/TCP 192.168.20.35:49246;branch=z9hG4bK39a7129e From: ;tag=c07bbca0ded4498376babdd5-429bdb53 To: ;tag=74171101 Date: Wed, 02 Sep 2015 08:03:15 GMT Call-ID: c07bbca0-ded4001c-30195863-05279309@192.168.20.35 CSeq: 21499 REGISTER Expires: 0 Content-Length: 0 10192916.000 |08:03:15.479 |SdlSig |DeviceEventReceiptMonitoringTimer |wait |StationInit(2,100,57,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[R:H-H:2,N:0,L:0,V:0,Z:0,D:0] 10192917.000 |08:03:15.480 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192918.000 |08:03:16.282 |SdlSig |SdlReadRsp |wait |SIPTcp(2,100,64,1) |SdlTCPConnection(2,100,13,577) |2,100,13,577.3509^192.168.20.34^* |*TraceFlagOverrode 10192918.001 |08:03:16.282 |AppInfo |SIPTcp - SdlRead bufferLen=879 10192918.002 |08:03:16.282 |AppInfo |SIPTcp - wait_SdlReadRsp: Incoming SIP TCP message from 192.168.20.34 on port 52151 index 13183 with 879 bytes: [0,NET] REGISTER sip:192.168.10.8 SIP/2.0 Via: SIP/2.0/TCP 192.168.20.34:52151;branch=z9hG4bK133a7d22 From: ;tag=64e9502f65080db83d58f140-21fcbf03 To: Call-ID: 64e9502f-65080003-7c9c1649-14c76d97@192.168.20.34 Max-Forwards: 70 Date: Wed, 02 Sep 2015 08:03:12 GMT CSeq: 3604 REGISTER User-Agent: Cisco-CP9951/9.4.2 Contact: ;+sip.instance="";+u.sip!devicename.ccm.cisco.com="SEP64E9502F6508";+u.sip!model.ccm.cisco.com="537" Supported: replaces,join,sdp-anat,norefersub,resource-priority,extended-refer,X-cisco-callinfo,X-cisco-serviceuri,X-cisco-escapecodes,X-cisco-service-control,X-cisco-srtp-fallback,X-cisco-monrec,X-cisco-config,X-cisco-sis-7.0.0,X-cisco-xsi-8.0.1 Content-Length: 0 Expires: 3600 10192918.003 |08:03:16.282 |AppInfo |SIPTcp - SignalCounter = 337374 10192919.000 |08:03:16.282 |SdlSig |SIPSPISignal |wait |SIPHandler(2,100,72,1) |SIPTcp(2,100,64,1) |2,100,13,577.3509^192.168.20.34^SEP64E9502F6508 |*TraceFlagOverrode 10192919.001 |08:03:16.282 |AppInfo |//SIP/Stack/Info/0x0/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 (SIP_NETWORK_MSG), for event 1 (SIPSPI_EV_NEW_MESSAGE) 10192919.002 |08:03:16.282 |AppInfo |//SIP/Stack/Transport/0x0/sipTransportProcessNWNewConnMsg: context=(nil) 10192919.003 |08:03:16.282 |AppInfo |//SIP/Stack/Transport/0x0/sipConnectionManagerProcessNewConnMsg: gConnTab=0xf553560, addr=192.168.20.34, port=52151, connid=13183, transport=TCP 10192919.004 |08:03:16.282 |AppInfo |//SIP/Stack/Info/0x0/sipHolderGetConnInstance: Return existing connection for port 52151 connId 13183 10192919.005 |08:03:16.282 |AppInfo |//SIP/Stack/Info/0x0/sipSPIFindRegisterCcb: *****CCB NOT found in UAS Request table. ccb=(nil) 10192919.006 |08:03:16.282 |AppInfo |//SIP/Stack/Info/0x0/sipSPIAddContextToTable: Added context(0x1020b588) with key=[454534] to table 10192919.007 |08:03:16.282 |AppInfo |//SIP/Stack/Transport/0x0/sipSPIUpdateResponseInfo: Dialog Transaction Address 192.168.20.34,Port 52151, Transport 2, SentBy Port 52151 10192919.008 |08:03:16.282 |AppInfo |//SIP/Stack/States/0x1020b588/sipSPIChangeState: 0x1020b588 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE) 10192919.009 |08:03:16.282 |AppInfo |//SIP/Stack/Transport/0x0/sipSPIUpdateResponseInfo: Subsq Transaction Address 192.168.20.34,Port 52151, Transport 2, SentBy Port 5060 10192919.010 |08:03:16.282 |AppInfo |//SIP/Stack/Transport/0x0/sipSPIUpdateResponseInfo: Subsq Transaction Address 192.168.20.34,Port 52151, Transport 2, SentBy Port 52151 10192919.011 |08:03:16.282 |AppInfo |//SIP/Stack/Transport/0x1020b588/sipSPISendResponse: Sending INFO Response to the transport layer 10192919.012 |08:03:16.282 |AppInfo |//SIP/Stack/Transport/0x1020b588/sipSPITransportSendMessage: msg=0xb6eaa7c0, addr=192.168.20.34, port=52151, sentBy_port=52151, is_req=0, transp 10192919.013 |08:03:16.282 |AppInfo |//SIP/Stack/Transport/0x0/sipInstanceGetConnectionId: Registering gcb=0x1020b588 with connection=0xfe2e018 context list 10192919.014 |08:03:16.282 |AppInfo |//SIP/Stack/Transport/0x1020b588/sipTransportLogicSendMsg: Connection obtained...sending msg=0xb6eaa7c0 10192919.015 |08:03:16.282 |AppInfo |//SIP/Stack/Transport/0x1020b588/sipTransportPostSendMessage: Posting send for msg=0xb6eaa7c0, addr=192.168.20.34, port=52151, connId=13183 for T 10192919.016 |08:03:16.282 |AppInfo |//SIP/Stack/Info/0x1020b588/sipSPIUaddCcbToTable: Added to table. ccb=0x1020b588 key=64e9502f-65080003-7c9c1649-14c76d97@192.168.20.34490464e9502f65080db83d58f140-21fcbf03 10192919.017 |08:03:16.282 |AppInfo |//SIP/SIPHandler/ccbId=454885/scbId=0/findDevicePID: Routed to SIPStationInit 10192919.018 |08:03:16.282 |AppInfo |//SIP/Stack/Event/0x1020b588/sact_idle_new_message_register: ccsip_api_register_ind return value : SIP_SUCCESS 10192919.019 |08:03:16.282 |AppInfo |//SIP/Stack/States/0x1020b588/sipSPIChangeState: 0x1020b588 : State change from (STATE_IDLE, SUBSTATE_NONE) to (SIP_STATE_INCOMING_REGISTER, SUBSTATE_NONE) 10192920.000 |08:03:16.283 |SdlSig |SIPSPISignal |wait |SIPTcp(2,100,64,1) |SIPHandler(2,100,72,1) |2,100,13,577.3509^192.168.20.34^SEP64E9502F6508 |*TraceFlagOverrode 10192920.001 |08:03:16.283 |AppInfo |SIPTcp - wait_SdlSPISignal: Outgoing SIP TCP message to 192.168.20.34 on port 52151 index 13183 [1115458,NET] SIP/2.0 100 Trying Via: SIP/2.0/TCP 192.168.20.34:52151;branch=z9hG4bK133a7d22 From: ;tag=64e9502f65080db83d58f140-21fcbf03 To: Date: Wed, 02 Sep 2015 08:03:16 GMT Call-ID: 64e9502f-65080003-7c9c1649-14c76d97@192.168.20.34 CSeq: 3604 REGISTER Content-Length: 0 10192921.000 |08:03:16.283 |SdlSig |SIPRegisterInd |wait |SIPStationInit(2,100,65,1) |SIPHandler(2,100,72,1) |2,100,13,577.3509^192.168.20.34^SEP64E9502F6508 |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] ccbID= 454885 --TransType=1 --TransSecurity=0 PeerAddr = 192.168.20.34:52151 MAC = DeviceName = X509SubjectName = SubjectAltname = 10192921.001 |08:03:16.283 |AppInfo |SIPStationInit: connID=13183, SEP64E9502F6508, 192.168.20.34:52151, checkTcpConnection: Connection index 13183 matches 10192921.002 |08:03:16.283 |AppInfo |SIPStationInit: connID=13183, SEP64E9502F6508, 192.168.20.34:52151, Routing to D (2,100,66,142), regCount=3504 10192922.000 |08:03:16.283 |SdlSig |SIPRegisterInd |wait |SIPStationD(2,100,66,142) |SIPStationInit(2,100,65,1) |2,100,13,577.3509^192.168.20.34^SEP64E9502F6508 |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] ccbID= 454885 --TransType=1 --TransSecurity=0 PeerAddr = 192.168.20.34:52151 MAC = 64E9502F6508 DeviceName = SEP64E9502F6508 X509SubjectName = SubjectAltname = 10192922.001 |08:03:16.283 |AppInfo |SIPStationD(142) - setUaTypeAndCepn: uaType is CISCO_ENHANCED_PHONE 10192922.002 |08:03:16.283 |AppInfo |SIPStationD(142) - Received REGISTER from 4904@192.168.20.34:52151 10192922.003 |08:03:16.283 |AppInfo |SIPStationD(142) - parseSupportedHeader: X-cisco-callinfo=T X-cisco-serviceuri=T X-cisco-escapecodes=T X-cisco-service-control=T X-cisco-duplicate-reg=F X-cisco-graceful-reg=F X-cisco-srtp-fallback=T X-cisco-ix=F X-cisco-monrec=T X-cisco-xsi=T xsi-version=8.0.1 X-cisco-sis=T sis-version=7.0.0 extended-refer=T norefersub=T join=T cso[rcc=T,sc=T,max=6] slNotify=3 hsNotify=3 blfNotify=3 fi[joinReq=T,cfwdAny=T,coaching=T,oosAlarm=T,joinDXferPolicy=2,xCiscoNumber=T,OrigCalled=T,iXChannel=F,BFCP=F,mobileConnectStatusRefresh=F,confDisplayInstanceSupport=T]MobilityExtension Feature Indication is empty 10192922.004 |08:03:16.283 |AppInfo |SIPStationD(142) - storeContactHeader: Request-URI is sip:b4ec11cf-d671-9c3c-397b-f84599c6af4d@192.168.20.34:52151;transport=tcp 10192922.005 |08:03:16.283 |AppInfo |setSIPAoR: aor = sip:4904@192.168.10.8 10192922.006 |08:03:16.283 |AppInfo |SIPStationD(142) - Register refresh #3503 for line 1 10192923.000 |08:03:16.283 |SdlSig |SIPRegisterResp |wait |SIPHandler(2,100,72,1) |SIPStationD(2,100,66,142) |2,100,13,577.3509^192.168.20.34^SEP64E9502F6508 |[T:N-H:0,N:0,L:0,V:0,Z:0,D:0] ccbID= 454885 --TransType=1 --TransSecurity=0 PeerAddr= 192.168.20.34:52151 respCode= 200 action= 2 device= 10192923.001 |08:03:16.284 |AppInfo |//SIP/Stack/Info/0x0/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 (SIP_APPLICATION_MSG), for event 42 (SIPSPI_EV_REGISTER_RESP) 10192923.002 |08:03:16.284 |AppInfo |//SIP/Stack/Info/0x1020b588/sipSPISendResponse: Associated container=0xb6e4eec0 to REGISTER Response 200 10192923.003 |08:03:16.284 |AppInfo |//SIP/Stack/Transport/0x1020b588/sipSPISendResponse: Sending INFO Response to the transport layer 10192923.004 |08:03:16.284 |AppInfo |//SIP/Stack/Transport/0x1020b588/sipSPITransportSendMessage: msg=0xb6e92de8, addr=192.168.20.34, port=52151, sentBy_port=52151, is_req=0, transp 10192923.005 |08:03:16.284 |AppInfo |//SIP/Stack/Transport/0x0/sipInstanceGetConnectionId: gcb=0x1020b588 is already on connection=0xfe2e018 context_list 10192923.006 |08:03:16.284 |AppInfo |//SIP/Stack/Transport/0x1020b588/sipTransportLogicSendMsg: Connection obtained...sending msg=0xb6e92de8 10192923.007 |08:03:16.284 |AppInfo |//SIP/Stack/Transport/0x1020b588/sipTransportPostSendMessage: Posting send for msg=0xb6e92de8, addr=192.168.20.34, port=52151, connId=13183 for T 10192923.008 |08:03:16.284 |AppInfo |//SIP/Stack/Info/0x1020b588/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be 10192923.009 |08:03:16.284 |AppInfo |//SIP/Stack/Transport/0x0/sipConnectionManagerUnregisterCtxtInCon: gConnTab=0xf553560, addr=192.168.20.34, port=52151, unregistering context= 10192923.010 |08:03:16.284 |AppInfo |//SIP/Stack/Info/0x1020b588/sipSPIUfreeOneCCB: Freeing ccb 1020b588 10192923.011 |08:03:16.284 |AppInfo |//SIP/Stack/Transport/0x0/sipSPITransportSendMessage: gcb has cleanedup, Done with send operations for this context 10192924.000 |08:03:16.284 |SdlSig |SIPSPISignal |wait |SIPTcp(2,100,64,1) |SIPHandler(2,100,72,1) |2,100,13,577.3509^192.168.20.34^SEP64E9502F6508 |*TraceFlagOverrode 10192924.001 |08:03:16.284 |AppInfo |SIPTcp - wait_SdlSPISignal: Outgoing SIP TCP message to 192.168.20.34 on port 52151 index 13183 [1115459,NET] SIP/2.0 200 OK Via: SIP/2.0/TCP 192.168.20.34:52151;branch=z9hG4bK133a7d22 From: ;tag=64e9502f65080db83d58f140-21fcbf03 To: ;tag=1013871497 Date: Wed, 02 Sep 2015 08:03:16 GMT Call-ID: 64e9502f-65080003-7c9c1649-14c76d97@192.168.20.34 CSeq: 3604 REGISTER Expires: 120 Contact: ;+sip.instance="";+u.sip!devicename.ccm.cisco.com="SEP64E9502F6508";+u.sip!model.ccm.cisco.com="537" Supported: X-cisco-srtp-fallback,X-cisco-sis-6.0.0 Content-Length: 0 10192925.000 |08:03:16.563 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192926.000 |08:03:17.572 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192927.000 |08:03:18.590 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192928.000 |08:03:19.599 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192929.000 |08:03:20.622 |SdlSig |DeviceEventReceiptMonitoringTimer |wait |StationInit(2,100,57,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[R:H-H:2,N:0,L:0,V:0,Z:0,D:0] 10192930.000 |08:03:20.622 |SdlStat |Period: 6s #Lines: 103 #Bytes: 22929 Total Number of Buffers: 10000 Free LWM: 9965 Free LWM(total): 9305 10192931.000 |08:03:20.623 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192932.000 |08:03:20.815 |SdlSig |B2BLinkQualityTimer |wait |ViPRManager(2,100,43,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[R:H-H:0,N:0,L:0,V:0,Z:0,D:0] 10192932.001 |08:03:20.815 |AppInfo |wait_B2BLinkQualityTimer - Started 10192932.002 |08:03:20.815 |AppInfo |wait_B2BLinkQualityTimer - B2BLinkQualityTimer set for 120 seconds 10192933.000 |08:03:21.635 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192934.000 |08:03:22.644 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192935.000 |08:03:23.203 |AppInfo |EnvProcessUdpHandler::handle_input - handle = 335 10192936.000 |08:03:23.203 |AppInfo |EnvProcessUdpHandler::handle_input Status: 0, Id: 0 10192937.000 |08:03:23.203 |SdlSig |UdpDataInd |wait |SIPUdp(2,100,63,1) |EnvProcessUdpPort(2,100,238,1) |2,100,238,1.109328^*^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] varStatus=0 varId=0 varSrcIpAddr=3232238083 varIpPort=5060 varFamily=2 10192937.001 |08:03:23.204 |AppInfo |//SIP/SIPUdp/wait_UdpDataInd: Incoming SIP UDP message size 354 from 192.168.10.3:[5060]: [1115460,NET] OPTIONS sip:192.168.10.8 SIP/2.0 From: ;tag=ACU-686f2f19-19c0a9b9 To: Contact: Call-ID: 150813e4-1dd2-11b2-88ce-c1a635d8dd32@192.168.10.3 CSeq: 9681043 OPTIONS Content-Length: 0 Max-Forwards: 70 Via: SIP/2.0/UDP 192.168.10.3:5060;branch=z9hG4bK1508406c-1dd2-11b2-9127-cc6d9849d94f;rport 10192938.000 |08:03:23.204 |SdlSig |SIPSPISignal |wait |SIPHandler(2,100,72,1) |SIPUdp(2,100,63,1) |2,100,238,1.109328^192.168.10.3^* |*TraceFlagOverrode 10192938.001 |08:03:23.204 |AppInfo |//SIP/Stack/Info/0x0/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 (SIP_NETWORK_MSG), for event 1 (SIPSPI_EV_NEW_MESSAGE) 10192938.002 |08:03:23.204 |AppInfo |//SIP/Stack/Transport/0x0/sipTransportProcessNWNewConnMsg: context=(nil) 10192938.003 |08:03:23.204 |AppInfo |//SIP/Stack/Info/0x0/sipSPIAddContextToTable: Added context(0x1020e518) with key=[454535] to table 10192938.004 |08:03:23.204 |AppInfo |//SIP/Stack/Transport/0x0/sipSPIUpdateResponseInfo: Dialog Transaction Address 192.168.10.3,Port 5060, Transport 1, SentBy Port 5060 10192938.005 |08:03:23.204 |AppInfo |//SIP/Stack/States/0x1020e518/sipSPIChangeState: 0x1020e518 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE) 10192938.006 |08:03:23.204 |AppInfo |//SIP/Stack/Transport/0x0/sipSPIUpdateResponseInfo: Subsq Transaction Address 192.168.10.3,Port 5060, Transport 1, SentBy Port 5060 10192938.007 |08:03:23.204 |AppInfo |//SIP/Stack/Transport/0x0/sipSPIUpdateResponseInfo: Subsq Transaction Address 192.168.10.3,Port 5060, Transport 1, SentBy Port 5060 10192938.008 |08:03:23.204 |AppInfo |//SIP/Stack/Error/0x0/httpish_msg_free: Freeing NULL pointer! 10192938.009 |08:03:23.204 |AppInfo |//SIP/SIPHandler/ccbId=454886/scbId=0/findDevicePID: Routed to SIPD by sipAddr 10192938.010 |08:03:23.204 |AppInfo |//SIP/Stack/Info/0x1020e518/sact_idle_new_message_options: ccsip_api_options_ind returned: SIP_SUCCESS 10192938.011 |08:03:23.204 |AppInfo |//SIP/Stack/States/0x1020e518/sipSPIChangeState: 0x1020e518 : State change from (STATE_IDLE, SUBSTATE_NONE) to (SIP_STATE_OPTIONS_WAIT, SUBSTATE_NONE) 10192938.012 |08:03:23.204 |AppInfo |//SIP/Stack/Info/0x1020e518/sipSPIUaddCcbToTable: Added to table. ccb=0x1020e518 key=150813e4-1dd2-11b2-88ce-c1a635d8dd32@192.168.10.3 10192939.000 |08:03:23.204 |SdlSig |SIPOptionsInd |restart0 |SIPD(2,100,74,125) |SIPHandler(2,100,72,1) |2,100,238,1.109328^192.168.10.3^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] ccbID= 454886 --TransType=2 --TransSecurity=0 PeerAddr = 192.168.10.3:5060 10192940.000 |08:03:23.204 |SdlSig |SIPOptionsResp |wait |SIPHandler(2,100,72,1) |SIPD(2,100,74,125) |2,100,238,1.109328^192.168.10.3^* |[T:N-H:0,N:0,L:0,V:0,Z:0,D:0] ccbID= 454886 --TransType=2 --TransSecurity=0 PeerAddr = 192.168.10.3:5060 10192940.001 |08:03:23.204 |AppInfo |//SIP/Stack/Info/0x0/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 (SIP_APPLICATION_MSG), for event 39 (SIPSPI_EV_CC_OPTIONS_RESP) 10192940.002 |08:03:23.204 |AppInfo |//SIP/Stack/Info/0x1020e518/sipSPISendOptionsResponse: Associated container=0xb2d4c3c0 to Options Response 10192940.003 |08:03:23.204 |AppInfo |//SIP/Stack/Transport/0x1020e518/sipSPITransportSendMessage: msg=0xb6e1a718, addr=192.168.10.3, port=5060, sentBy_port=5060, is_req=0, transp 10192940.004 |08:03:23.204 |AppInfo |//SIP/Stack/Transport/0x1020e518/sipTransportPostSendMessage: Posting send for msg=0xb6e1a718, addr=192.168.10.3, port=5060, connId=0 for U 10192940.005 |08:03:23.204 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/sip_stop_timer: type=SIP_TIMER_REMOVE_TRANSACTION value=32000 retries=0 10192940.006 |08:03:23.204 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/sip_start_timer: type=SIP_TIMER_REMOVE_TRANSACTION value=32000 retries=0 10192941.000 |08:03:23.204 |SdlSig |SIPSPISignal |wait |SIPUdp(2,100,63,1) |SIPHandler(2,100,72,1) |2,100,238,1.109328^192.168.10.3^* |*TraceFlagOverrode 10192941.001 |08:03:23.204 |AppInfo |//SIP/SIPUdp/wait_SdlSPISignal: Outgoing SIP UDP message to 192.168.10.3:[5060]: [1115461,NET] SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.10.3:5060;branch=z9hG4bK1508406c-1dd2-11b2-9127-cc6d9849d94f;rport From: ;tag=ACU-686f2f19-19c0a9b9 To: ;tag=421403014 Date: Wed, 02 Sep 2015 08:03:23 GMT Call-ID: 150813e4-1dd2-11b2-88ce-c1a635d8dd32@192.168.10.3 CSeq: 9681043 OPTIONS Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY Content-Length: 0 10192942.000 |08:03:23.204 |SdlSig |UdpSendReq |start |EnvProcessUdpPort(2,100,238,1) |SIPUdp(2,100,63,1) |2,100,238,1.109328^192.168.10.3^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] varId=0 varIpAddr=3232238083 varIpPort=5060 varFamily=2 10192942.001 |08:03:23.204 |AppInfo |EnvProcessUdpPort - EnvProcessUdpHandler::fireSignal() varId = 0 10192942.002 |08:03:23.204 |AppInfo |EnvProcessUdpHandler::fireSignal - SEND: index = 0, handler = 0x10544140 10192942.003 |08:03:23.204 |AppInfo |EnvProcessUdpPort::fireSignal - SEND, destination = 192.168.10.3:5060 10192942.004 |08:03:23.204 |AppInfo |EnvProcessUdpPort - EnvProcessUdpHandler::send(buff, 429, 192.168.10.3:5060) 10192943.000 |08:03:23.654 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192944.000 |08:03:24.672 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192945.000 |08:03:25.249 |SdlSig |ReapOldTokenRegistrationsTimer |wait |SIPStationInit(2,100,65,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[R:H-H:2,N:0,L:0,V:0,Z:0,D:0] 10192946.000 |08:03:25.249 |SdlSig |SdlPollReqTimer |wait |SdlLinkControl(2,100,18,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |*TraceFlagOverrode 10192946.001 |08:03:25.249 |SdlError | | | | | |SdlLinkHandler::sendPollRequest - Did not received Poll Response. Going Down. NodeId: 1, AppId: 300, TCPAddr[:0] 10192946.002 |08:03:25.249 |SdlError | | | | | |SdlLinkHandler::sendPollRequest - Did not received Poll Response. Going Down. NodeId: 2, AppId: 300, TCPAddr[:0] 10192946.003 |08:03:25.249 |SdlError | | | | | |SdlLinkHandler::sendPollRequest - Did not received Poll Response. Going Down. NodeId: 3, AppId: 300, TCPAddr[:0] 10192947.000 |08:03:25.754 |SdlSig |DeviceEventReceiptMonitoringTimer |wait |StationInit(2,100,57,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[R:H-H:2,N:0,L:0,V:0,Z:0,D:0] 10192948.000 |08:03:25.755 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192949.000 |08:03:25.872 |SdlSig |SIPPingReqTimer |restart0 |SIPD(2,100,74,124) |SdlTimerService(2,100,3,1) |2,100,37,1.1200^*^* |[R:H-H:0,N:0,L:0,V:0,Z:0,D:0] 10192950.000 |08:03:25.872 |SdlSig |SIPPingReq |wait |SIPHandler(2,100,72,1) |SIPD(2,100,74,124) |2,100,37,1.1200^*^* |[T:N-H:0,N:0,L:0,V:0,Z:0,D:0] ccbID= 454887 maxForward=0 --TransType=1 --TransSecurity=0 PeerAddr = 192.168.10.4:5060 10192950.001 |08:03:25.872 |AppInfo |//SIP/Stack/Info/0x0/sipSPIAddContextToTable: Added context(0x1021eab0) with key=[454536] to table 10192950.002 |08:03:25.872 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/populateTargetInfo: port=5060, isIPAddr=1, type=2, target_port=5060, outboundProxyAddr.isIPAddr=0, target_type=0 10192950.003 |08:03:25.872 |AppInfo |//SIP/Stack/States/0x1021eab0/sipSPIChangeState: 0x1021eab0 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE) 10192950.004 |08:03:25.872 |AppInfo |//SIP/Stack/Info/0x0/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 (SIP_APPLICATION_MSG), for event 38 (SIPSPI_EV_CC_OPTIONS) 10192950.005 |08:03:25.872 |AppInfo |//SIP/Stack/Info/0x1021eab0/sipSPIUaddCcbToTable: Added to table. ccb=0x1021eab0 key=14e30a00-5e61ad4d-1dc2f-80aa8c0@192.168.10.8 10192950.006 |08:03:25.872 |AppInfo |//SIP/Stack/States/0x1021eab0/sipSPIChangeState: 0x1021eab0 : State change from (STATE_IDLE, SUBSTATE_NONE) to (SIP_STATE_OPTIONS_WAIT, SUBSTATE_NONE) 10192950.007 |08:03:25.872 |AppInfo |//SIP/Stack/Info/0x1021eab0/sipSPIAddViaParams: inserted z9hG4bK1dfc8580965d5 into via branch list 10192950.008 |08:03:25.872 |AppInfo |//SIP/Stack/Error/0x1021eab0/sipSPIAddPrivacyHeader: Orig Container is NULL...should have value 10192950.009 |08:03:25.872 |AppInfo |//SIP/Stack/Error/0x1021eab0/sipSPIAddAssertedIDHeader: Orig Container is NULL...should have value 10192950.010 |08:03:25.872 |AppInfo |//SIP/Stack/Error/0x1021eab0/sipSPIAddPreferredIDHeader: Orig Container is NULL...should have value 10192950.011 |08:03:25.872 |AppInfo |//SIP/Stack/Info/0x1021eab0/sipSPISendOptionsRequest: Associated container=0xb6eb5d10 to Options 10192950.012 |08:03:25.872 |AppInfo |//SIP/Stack/Transport/0x1021eab0/sipSPITransportSendMessage: msg=0xb6eaa7c0, addr=192.168.10.4, port=5060, sentBy_port=0, is_req=1, transp 10192950.013 |08:03:25.872 |AppInfo |//SIP/Stack/Transport/0x0/sipInstanceGetConnectionId: Registering gcb=0x1021eab0 with connection=0xfe2de80 context list 10192950.014 |08:03:25.872 |AppInfo |//SIP/Stack/Transport/0x1021eab0/sipTransportLogicSendMsg: Set to send the msg=0xb6eaa7c0 10192950.015 |08:03:25.872 |AppInfo |//SIP/Stack/Transport/0x1021eab0/sipTransportPostSendMessage: Posting send for msg=0xb6eaa7c0, addr=192.168.10.4, port=5060, connId=13159 for T 10192950.016 |08:03:25.872 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/sip_stop_timer: type=SIP_TIMER_TRYING value=500 retries=6 10192950.017 |08:03:25.872 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/sip_start_timer: type=SIP_TIMER_TRYING value=500 retries=6 10192951.000 |08:03:25.872 |AppInfo |SIPSocketProtocol(2,100,13,553)::handleWriteComplete 10192952.000 |08:03:25.872 |SdlSig |SIPSPISignal |wait |SIPTcp(2,100,64,1) |SIPHandler(2,100,72,1) |2,100,37,1.1200^*^* |*TraceFlagOverrode 10192952.001 |08:03:25.872 |AppInfo |SIPTcp - wait_SdlSPISignal: Outgoing SIP TCP message to 192.168.10.4 on port 5060 index 13159 [1115462,NET] OPTIONS sip:192.168.10.4:5060 SIP/2.0 Via: SIP/2.0/TCP 192.168.10.8:5060;branch=z9hG4bK1dfc8580965d5 From: ;tag=2012318518 To: Date: Wed, 02 Sep 2015 08:03:25 GMT Call-ID: 14e30a00-5e61ad4d-1dc2f-80aa8c0@192.168.10.8 User-Agent: Cisco-CUCM9.1 CSeq: 101 OPTIONS Contact: Max-Forwards: 0 Content-Length: 0 10192953.000 |08:03:25.876 |AppInfo |SIPSocketProtocol(2,100,13,553)::handleReadComplete send SdlReadRsp: size 642 10192954.000 |08:03:25.876 |SdlSig |SdlReadRsp |wait |SIPTcp(2,100,64,1) |SdlTCPConnection(2,100,13,553) |2,100,13,553.9573^192.168.10.4^* |*TraceFlagOverrode 10192954.001 |08:03:25.876 |AppInfo |SIPTcp - SdlRead bufferLen=642 10192954.002 |08:03:25.876 |AppInfo |//SIP/Stack/Error/0x0/httpish_cache_header_val: DROPPING unregistered header Accept-Encoding: identity 10192954.003 |08:03:25.876 |AppInfo |//SIP/Stack/Error/0x0/httpish_cache_header_val: DROPPING unregistered header Accept-Language: en 10192954.004 |08:03:25.877 |AppInfo |SIPTcp - wait_SdlReadRsp: Incoming SIP TCP message from 192.168.10.4 on port 5060 index 13159 with 642 bytes: [1115463,NET] SIP/2.0 200 Ok Via: SIP/2.0/TCP 192.168.10.8:5060;branch=z9hG4bK1dfc8580965d5 From: ;tag=2012318518 To: Call-ID: 14e30a00-5e61ad4d-1dc2f-80aa8c0@192.168.10.8 CSeq: 101 OPTIONS Content-Length: 0 User-Agent: ApplianX-Gateway Allow: INVITE Allow: ACK Allow: BYE Allow: CANCEL Allow: OPTIONS Allow: NOTIFY Allow: REFER Allow: PRACK Allow: INFO Allow: UPDATE Allow: MESSAGE Accept: application/sdp Accept: application/isup Accept: application/qsig Accept: multipart/mixed Accept-Encoding: identity Accept-Language: en Supported: 100rel Supported: replaces Supported: X-AcuAX-ROPR 10192954.005 |08:03:25.877 |AppInfo |SIPTcp - SignalCounter = 337375 10192955.000 |08:03:25.877 |SdlSig |SIPSPISignal |wait |SIPHandler(2,100,72,1) |SIPTcp(2,100,64,1) |2,100,13,553.9573^192.168.10.4^* |*TraceFlagOverrode 10192955.001 |08:03:25.877 |AppInfo |//SIP/Stack/Info/0x0/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 (SIP_NETWORK_MSG), for event 1 (SIPSPI_EV_NEW_MESSAGE) 10192955.002 |08:03:25.877 |AppInfo |//SIP/Stack/Transport/0x0/sipTransportProcessNWNewConnMsg: context=0xf553560 10192955.003 |08:03:25.877 |AppInfo |//SIP/Stack/Transport/0x0/sipConnectionManagerProcessNewConnMsg: gConnTab=0xf553560, addr=192.168.10.4, port=5060, connid=13159, transport=TCP 10192955.004 |08:03:25.877 |AppInfo |//SIP/Stack/Info/0x0/sipHolderGetConnInstance: Return existing connection for port 5060 connId 13159 10192955.005 |08:03:25.877 |AppInfo |//SIP/Stack/Info/0x1021eab0/sipSPIMatchRespToReqTran: removing unneeded z9hG4bK1dfc8580965d5 from via branch list 10192955.006 |08:03:25.877 |AppInfo |//SIP/Stack/Info/0x1021eab0/sipSPICheckResponseExt: non-INVITE response with no RSEQ - do not disable IS_REL1XX 10192955.007 |08:03:25.877 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/sip_stop_timer: type=SIP_TIMER_TRYING value=500 retries=6 10192955.008 |08:03:25.877 |AppInfo |//SIP/SIPHandler/ccbId=454887/scbId=0/findDevicePID: Routed to SIPD by ccbId/scbId 10192955.009 |08:03:25.877 |AppInfo |//SIP/Stack/Info/0x1021eab0/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be 10192955.010 |08:03:25.877 |AppInfo |//SIP/Stack/Transport/0x0/sipConnectionManagerUnregisterCtxtInCon: gConnTab=0xf553560, addr=192.168.10.4, port=5060, unregistering context= 10192955.011 |08:03:25.877 |AppInfo |//SIP/Stack/Info/0x1021eab0/sipSPIUfreeOneCCB: Freeing ccb 1021eab0 10192956.000 |08:03:25.877 |SdlSig |SIPPingResult |restart0 |SIPD(2,100,74,124) |SIPHandler(2,100,72,1) |2,100,13,553.9573^192.168.10.4^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] ccbID= 454887 interErr=F resp=200 state=0 --TransType=1 --TransSecurity=0 PeerAddr = 192.168.10.4:5060 10192957.000 |08:03:26.768 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192958.000 |08:03:26.768 |SdlStat |Period: 6s #Lines: 90 #Bytes: 18221 Total Number of Buffers: 10000 Free LWM: 9968 Free LWM(total): 9305 10192959.000 |08:03:27.774 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192960.000 |08:03:28.788 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192961.000 |08:03:29.273 |SdlSig |SIPPingReqTimer |restart0 |SIPD(2,100,74,125) |SdlTimerService(2,100,3,1) |2,100,37,1.1200^*^* |[R:H-H:1,N:0,L:0,V:0,Z:0,D:0] 10192962.000 |08:03:29.274 |SdlSig |SIPPingReq |wait |SIPHandler(2,100,72,1) |SIPD(2,100,74,125) |2,100,37,1.1200^*^* |[T:N-H:0,N:0,L:0,V:0,Z:0,D:0] ccbID= 454888 maxForward=0 --TransType=1 --TransSecurity=0 PeerAddr = 192.168.10.3:5060 10192962.001 |08:03:29.274 |AppInfo |//SIP/Stack/Info/0x0/sipSPIAddContextToTable: Added context(0x102249b0) with key=[454537] to table 10192962.002 |08:03:29.274 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/populateTargetInfo: port=5060, isIPAddr=1, type=2, target_port=5060, outboundProxyAddr.isIPAddr=0, target_type=0 10192962.003 |08:03:29.274 |AppInfo |//SIP/Stack/States/0x102249b0/sipSPIChangeState: 0x102249b0 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE) 10192962.004 |08:03:29.274 |AppInfo |//SIP/Stack/Info/0x0/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 (SIP_APPLICATION_MSG), for event 38 (SIPSPI_EV_CC_OPTIONS) 10192962.005 |08:03:29.274 |AppInfo |//SIP/Stack/Info/0x102249b0/sipSPIUaddCcbToTable: Added to table. ccb=0x102249b0 key=17456400-5e61ad51-1dc30-80aa8c0@192.168.10.8 10192962.006 |08:03:29.274 |AppInfo |//SIP/Stack/States/0x102249b0/sipSPIChangeState: 0x102249b0 : State change from (STATE_IDLE, SUBSTATE_NONE) to (SIP_STATE_OPTIONS_WAIT, SUBSTATE_NONE) 10192962.007 |08:03:29.274 |AppInfo |//SIP/Stack/Info/0x102249b0/sipSPIAddViaParams: inserted z9hG4bK1dfc940b7d717 into via branch list 10192962.008 |08:03:29.274 |AppInfo |//SIP/Stack/Error/0x102249b0/sipSPIAddPrivacyHeader: Orig Container is NULL...should have value 10192962.009 |08:03:29.274 |AppInfo |//SIP/Stack/Error/0x102249b0/sipSPIAddAssertedIDHeader: Orig Container is NULL...should have value 10192962.010 |08:03:29.274 |AppInfo |//SIP/Stack/Error/0x102249b0/sipSPIAddPreferredIDHeader: Orig Container is NULL...should have value 10192962.011 |08:03:29.274 |AppInfo |//SIP/Stack/Info/0x102249b0/sipSPISendOptionsRequest: Associated container=0xb6eb5d10 to Options 10192962.012 |08:03:29.274 |AppInfo |//SIP/Stack/Transport/0x102249b0/sipSPITransportSendMessage: msg=0xb6eaa7c0, addr=192.168.10.3, port=5060, sentBy_port=0, is_req=1, transp 10192962.013 |08:03:29.274 |AppInfo |//SIP/Stack/Transport/0x0/sipInstanceGetConnectionId: Registering gcb=0x102249b0 with connection=0xfe2df90 context list 10192962.014 |08:03:29.274 |AppInfo |//SIP/Stack/Transport/0x102249b0/sipTransportLogicSendMsg: Set to send the msg=0xb6eaa7c0 10192962.015 |08:03:29.274 |AppInfo |//SIP/Stack/Transport/0x102249b0/sipTransportPostSendMessage: Posting send for msg=0xb6eaa7c0, addr=192.168.10.3, port=5060, connId=13188 for T 10192962.016 |08:03:29.274 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/sip_stop_timer: type=SIP_TIMER_TRYING value=500 retries=6 10192962.017 |08:03:29.274 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/sip_start_timer: type=SIP_TIMER_TRYING value=500 retries=6 10192963.000 |08:03:29.274 |AppInfo |SIPSocketProtocol(2,100,13,582)::handleWriteComplete 10192964.000 |08:03:29.274 |SdlSig |SIPSPISignal |wait |SIPTcp(2,100,64,1) |SIPHandler(2,100,72,1) |2,100,37,1.1200^*^* |*TraceFlagOverrode 10192964.001 |08:03:29.274 |AppInfo |SIPTcp - wait_SdlSPISignal: Outgoing SIP TCP message to 192.168.10.3 on port 5060 index 13188 [1115464,NET] OPTIONS sip:192.168.10.3:5060 SIP/2.0 Via: SIP/2.0/TCP 192.168.10.8:5060;branch=z9hG4bK1dfc940b7d717 From: ;tag=1271820796 To: Date: Wed, 02 Sep 2015 08:03:29 GMT Call-ID: 17456400-5e61ad51-1dc30-80aa8c0@192.168.10.8 User-Agent: Cisco-CUCM9.1 CSeq: 101 OPTIONS Contact: Max-Forwards: 0 Content-Length: 0 10192965.000 |08:03:29.277 |AppInfo |SIPSocketProtocol(2,100,13,582)::handleReadComplete send SdlReadRsp: size 642 10192966.000 |08:03:29.277 |SdlSig |SdlReadRsp |wait |SIPTcp(2,100,64,1) |SdlTCPConnection(2,100,13,582) |2,100,13,582.1298^192.168.10.3^* |*TraceFlagOverrode 10192966.001 |08:03:29.277 |AppInfo |SIPTcp - SdlRead bufferLen=642 10192966.002 |08:03:29.277 |AppInfo |//SIP/Stack/Error/0x0/httpish_cache_header_val: DROPPING unregistered header Accept-Encoding: identity 10192966.003 |08:03:29.277 |AppInfo |//SIP/Stack/Error/0x0/httpish_cache_header_val: DROPPING unregistered header Accept-Language: en 10192966.004 |08:03:29.277 |AppInfo |SIPTcp - wait_SdlReadRsp: Incoming SIP TCP message from 192.168.10.3 on port 5060 index 13188 with 642 bytes: [1115465,NET] SIP/2.0 200 Ok Via: SIP/2.0/TCP 192.168.10.8:5060;branch=z9hG4bK1dfc940b7d717 From: ;tag=1271820796 To: Call-ID: 17456400-5e61ad51-1dc30-80aa8c0@192.168.10.8 CSeq: 101 OPTIONS Content-Length: 0 User-Agent: ApplianX-Gateway Allow: INVITE Allow: ACK Allow: BYE Allow: CANCEL Allow: OPTIONS Allow: NOTIFY Allow: REFER Allow: PRACK Allow: INFO Allow: UPDATE Allow: MESSAGE Accept: application/sdp Accept: application/isup Accept: application/qsig Accept: multipart/mixed Accept-Encoding: identity Accept-Language: en Supported: 100rel Supported: replaces Supported: X-AcuAX-ROPR 10192966.005 |08:03:29.278 |AppInfo |SIPTcp - SignalCounter = 337376 10192967.000 |08:03:29.278 |SdlSig |SIPSPISignal |wait |SIPHandler(2,100,72,1) |SIPTcp(2,100,64,1) |2,100,13,582.1298^192.168.10.3^* |*TraceFlagOverrode 10192967.001 |08:03:29.278 |AppInfo |//SIP/Stack/Info/0x0/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 (SIP_NETWORK_MSG), for event 1 (SIPSPI_EV_NEW_MESSAGE) 10192967.002 |08:03:29.278 |AppInfo |//SIP/Stack/Transport/0x0/sipTransportProcessNWNewConnMsg: context=0xf553560 10192967.003 |08:03:29.278 |AppInfo |//SIP/Stack/Transport/0x0/sipConnectionManagerProcessNewConnMsg: gConnTab=0xf553560, addr=192.168.10.3, port=5060, connid=13188, transport=TCP 10192967.004 |08:03:29.278 |AppInfo |//SIP/Stack/Info/0x0/sipHolderGetConnInstance: Return existing connection for port 5060 connId 13188 10192967.005 |08:03:29.278 |AppInfo |//SIP/Stack/Info/0x102249b0/sipSPIMatchRespToReqTran: removing unneeded z9hG4bK1dfc940b7d717 from via branch list 10192967.006 |08:03:29.278 |AppInfo |//SIP/Stack/Info/0x102249b0/sipSPICheckResponseExt: non-INVITE response with no RSEQ - do not disable IS_REL1XX 10192967.007 |08:03:29.278 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/sip_stop_timer: type=SIP_TIMER_TRYING value=500 retries=6 10192967.008 |08:03:29.278 |AppInfo |//SIP/SIPHandler/ccbId=454888/scbId=0/findDevicePID: Routed to SIPD by ccbId/scbId 10192967.009 |08:03:29.278 |AppInfo |//SIP/Stack/Info/0x102249b0/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be 10192967.010 |08:03:29.278 |AppInfo |//SIP/Stack/Transport/0x0/sipConnectionManagerUnregisterCtxtInCon: gConnTab=0xf553560, addr=192.168.10.3, port=5060, unregistering context= 10192967.011 |08:03:29.278 |AppInfo |//SIP/Stack/Info/0x102249b0/sipSPIUfreeOneCCB: Freeing ccb 102249b0 10192968.000 |08:03:29.278 |SdlSig |SIPPingResult |restart0 |SIPD(2,100,74,125) |SIPHandler(2,100,72,1) |2,100,13,582.1298^192.168.10.3^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] ccbID= 454888 interErr=F resp=200 state=0 --TransType=1 --TransSecurity=0 PeerAddr = 192.168.10.3:5060 10192969.000 |08:03:29.805 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192970.000 |08:03:30.900 |SdlSig |DeviceEventReceiptMonitoringTimer |wait |StationInit(2,100,57,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[R:H-H:2,N:0,L:0,V:0,Z:0,D:0] 10192971.000 |08:03:30.901 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10192972.000 |08:03:31.013 |SdlSig |SIPPeriodicReINVITETimer |inCall_delivered |SIPCdpc(2,100,75,1388) |SdlTimerService(2,100,3,1) |2,100,13,563.4320^192.168.30.22^SEP4931AAAAAAAA |*TraceFlagOverrode 10192972.001 |08:03:31.013 |AppInfo |SIPCdpc(1388) - star_SIPPeriodicReINVITETimer: SIPPeriodicReINVITETimer pops up at [inCall_delivered] 10192972.002 |08:03:31.013 |AppInfo |SIPCdpc(1388) - star_SIPPeriodicReINVITETimer: ReINVITE is not sent 10192973.000 |08:03:31.013 |SdlSig |SIPTimer |wait |SIPHandler(2,100,72,1) |SdlTimerService(2,100,3,1) |2,100,13,563.4320^192.168.30.22^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] TimerType=SIP_TIMER_EXPIRES value=1800000 numRetries=0 10192973.001 |08:03:31.013 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/wait_SIPTimer: TimerExpired type=SIP_TIMER_EXPIRES value=1800000 retries=0 10192973.002 |08:03:31.013 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/sip_stop_timer: type=SIP_TIMER_EXPIRES value=1800000 retries=0 10192973.003 |08:03:31.013 |AppInfo |//SIP/Stack/Error/0x10220278/act_recdinvite_expires_timeout: Out of retries 10192973.004 |08:03:31.013 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/sip_stop_timer: type=SIP_TIMER_EXPIRES value=1800000 retries=0 10192973.005 |08:03:31.013 |AppInfo |//SIP/Stack/Info/0x10220278/ccsip_set_cc_cause_for_spi_err: Categorized cause:102, category:129 10192973.006 |08:03:31.013 |AppInfo |//SIP/Stack/Transport/0x10220278/sipSPITransportSendMessage: msg=0xb6e1a718, addr=192.168.30.22, port=49196, sentBy_port=5060, is_req=0, transp 10192973.007 |08:03:31.013 |AppInfo |//SIP/Stack/Transport/0x10220278/sipTransportPostSendMessage: Posting send for msg=0xb6e1a718, addr=192.168.30.22, port=49196, connId=13169 for T 10192973.008 |08:03:31.014 |AppInfo |//SIP/Stack/Info/0x10220278/sentInviteResponse4xx: Sent 4xx Error 10192973.009 |08:03:31.014 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/sip_stop_timer: type=SIP_TIMER_CONNECT value=500 retries=6 10192973.010 |08:03:31.014 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/sip_start_timer: type=SIP_TIMER_CONNECT value=500 retries=6 10192973.011 |08:03:31.014 |AppInfo |//SIP/SIPHandler/ccbId=454645/scbId=0/ccsip_api_call_disconnected: ccb->cc_disc_cause (102); ccb->sip_disc_cause(487) 10192973.012 |08:03:31.014 |AppInfo |//SIP/SIPHandler/ccbId=454645/scbId=0/findDevicePID: Routed to SIPD by ccbId/scbId 10192973.013 |08:03:31.014 |AppInfo |//SIP/Stack/States/0x10220278/sipSPIChangeState: 0x10220278 : State change from (STATE_SENT_ALERTING, SUBSTATE_NONE) to (STATE_DISCONNECTING, SUBSTATE_NONE) 10192974.000 |08:03:31.014 |SdlSig |SIPSPISignal |wait |SIPTcp(2,100,64,1) |SIPHandler(2,100,72,1) |2,100,13,563.4320^192.168.30.22^* |*TraceFlagOverrode 10192974.001 |08:03:31.014 |AppInfo |SIPTcp - wait_SdlSPISignal: Outgoing SIP TCP message to 192.168.30.22 on port 49196 index 13169 [1115466,NET] SIP/2.0 487 Request Cancelled Via: SIP/2.0/TCP 192.168.30.22:5060;branch=z9hG4bK-7867a-1d65503d-3a281f78 From: "yorknorth";tag=4f91c48-161ea8c0-13c4-5506-7867a-16550fe-7867a To: "";tag=454645~946f5a50-7410-423d-a5bb-36fb6cd3f0d0-44251768 Date: Wed, 02 Sep 2015 07:33:30 GMT Call-ID: 4faebf8-161ea8c0-13c4-5506-7867a-5b8c0d60-7867a CSeq: 1 INVITE Allow-Events: presence Reason: Q.850;cause=102 Content-Length: 0 10192975.000 |08:03:31.014 |SdlSig |SIPDisconnInd |wait |SIPStationD(2,100,66,139) |SIPHandler(2,100,72,1) |2,100,13,563.4320^192.168.30.22^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] CcbId= 454645 --TransType=1 --TransSecurity=0 PeerAddr = 192.168.30.22:49196 Sip_disc_cause= 487 cause=102 isReasonHdrVal= F 10192976.000 |08:03:31.014 |SdlSig |SIPDisconnInd |translate |SIPStationCdfc(2,100,67,1210) |SIPStationD(2,100,66,139) |2,100,13,563.4320^192.168.30.22^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] CcbId= 454645 --TransType=1 --TransSecurity=0 PeerAddr = 192.168.30.22:49196 Sip_disc_cause= 487 cause=102 isReasonHdrVal= F 10192977.000 |08:03:31.014 |SdlSig |SIPDisconnInd |inCall_delivered |SIPCdpc(2,100,75,1388) |SIPStationCdfc(2,100,67,1210) |2,100,13,563.4320^192.168.30.22^* |[R:N-H:0,N:2,L:0,V:0,Z:0,D:0] CcbId= 454645 --TransType=1 --TransSecurity=0 PeerAddr = 192.168.30.22:49196 Sip_disc_cause= 487 cause=102 isReasonHdrVal= F 10192978.000 |08:03:31.014 |SdlSig |DSetCallPhase |wait |SIPStationD(2,100,66,139) |SIPStationCdfc(2,100,67,1210) |2,100,13,563.4320^192.168.30.22^* |[R:N-H:0,N:2,L:0,V:0,Z:0,D:0] CallPhase=CALL_CLEARING 10192978.001 |08:03:31.014 |AppInfo |SIPStationD(139) - DEBUG- wait_DSetCallPhase updateACall=44251768 from Phase=0 to callPhase=3. 10192979.000 |08:03:31.014 |SdlSig |DSetCallState |wait |SIPStationD(2,100,66,139) |SIPStationCdfc(2,100,67,1210) |2,100,13,563.4320^192.168.30.22^* |[R:N-H:0,N:1,L:0,V:0,Z:0,D:0] CallState = disconnect_request11 10192980.000 |08:03:31.014 |SdlSig |CcDisconnInd |restart0 |LineControl(2,100,167,211) |SIPCdpc(2,100,75,1388) |2,100,13,563.4320^192.168.30.22^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] CI=44251768 CI.branch=0 c.l=1 c.cid=8 c.cs=0 c.lc=0 c.r=0 cv=1191182367 globalDisconnect=F FDataType=0opId=0ssType=0 SsKey=0invokeId=0resultExp=Fbpda=FTransparentData=null CanSupportSIPTandN=false TransId=0 AllowBitMask=0x0 UserAgentOrServer= OrigDDName=locale: 1 Name: UnicodeName: pi: 0 mCallerId= mCallerName= 10192981.000 |08:03:31.014 |SdlSig |CcDisconnInd |call_initiated1 |LineCdpc(2,100,168,1184) |LineControl(2,100,167,211) |2,100,13,563.4320^192.168.30.22^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] CI=44251768 CI.branch=0 c.l=1 c.cid=8 c.cs=0 c.lc=0 c.r=0 cv=1191182367 globalDisconnect=F FDataType=0opId=0ssType=0 SsKey=0invokeId=0resultExp=Fbpda=FTransparentData=null CanSupportSIPTandN=false TransId=0 AllowBitMask=0x0 UserAgentOrServer= OrigDDName=locale: 1 Name: UnicodeName: pi: 0 mCallerId= mCallerName= 10192982.000 |08:03:31.014 |SdlSig |CcDisconnInd |wait |Cc(2,100,213,1) |LineCdpc(2,100,168,1184) |2,100,13,563.4320^192.168.30.22^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] CI=44251768 CI.branch=0 c.l=1 c.cid=8 c.cs=0 c.lc=0 c.r=0 cv=1191182367 globalDisconnect=F FDataType=0opId=0ssType=0 SsKey=0invokeId=0resultExp=Fbpda=FTransparentData=null CanSupportSIPTandN=false TransId=0 AllowBitMask=0x0 UserAgentOrServer= OrigDDName=locale: 1 Name: UnicodeName: pi: 0 mCallerId= mCallerName= 10192983.000 |08:03:31.014 |SdlSig |CcDisconnInd |tcc_call_alerting6 |Cdcc(2,100,212,391) |Cc(2,100,213,1) |2,100,13,563.4320^192.168.30.22^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] CI=44251768 CI.branch=0 c.l=1 c.cid=8 c.cs=0 c.lc=0 c.r=0 cv=1191182367 globalDisconnect=F FDataType=0opId=0ssType=0 SsKey=0invokeId=0resultExp=Fbpda=FTransparentData=null CanSupportSIPTandN=false TransId=0 AllowBitMask=0x0 UserAgentOrServer= OrigDDName=locale: 1 Name: UnicodeName: pi: 0 mCallerId= mCallerName= 10192983.001 |08:03:31.014 |AppInfo |Cdcc::isStaticTransactionApplicable 10192983.002 |08:03:31.014 |AppInfo |processCCMFeatureData: operationIeIdd=0 10192984.000 |08:03:31.014 |SdlSig |SsDataInd |wait |ForwardManager(2,100,193,1) |Cdcc(2,100,212,391) |2,100,13,563.4320^192.168.30.22^* |[R:N-H:0,N:1,L:0,V:0,Z:0,D:0] SsType=33554438 SsKey=0 SsNode=2 SsParty=44251768 DevId=(0,0,0) BCC=6 OtherParty=44251825 NodeOtherParty=2 clearType = 0 CSS=:2c8cf414-5250-5ef6-1c7e-92b2c99f28bb CNumInfo = 0 CNameInfo = 0 ssDevType=4 ssOtherDevType=4 FDataType=0opId=0ssType=0 SsKey=0invokeId=0resultExp=Fbpda=F ssCause = 1191182367 ssUserState = 2 ssOtherUserState = 5 PL=5 PLDmn=0 networkDomain= delayAPTimer=F geolocInfo={geolocPkid=, filterPkid=, geolocVal=, devType=4} cfwdTimerAction=0 matchInterceptPartition= matchInterceptPattern= 10192984.001 |08:03:31.014 |AppInfo |ForwardManager - wait_SsDataInd - Key= 0x0, party= 44251768, BCC= 6 10192984.002 |08:03:31.014 |AppInfo |ForwardManager - findCallBySsParty - Found entry for party= 44251768, callkey= 0x86 10192985.000 |08:03:31.014 |SdlSig |DropPartyReq |await_command |MatrixControl(2,100,135,402) |Cdcc(2,100,212,391) |2,100,13,563.4320^192.168.30.22^* |[R:N-H:0,N:1,L:0,V:0,Z:0,D:0] ClearType= 0 10192986.000 |08:03:31.014 |SdlSig |SsDataInd |awaitingCallResponse |Forwarding(2,100,192,134) |ForwardManager(2,100,193,1) |2,100,13,563.4320^192.168.30.22^* |[R:N-H:0,N:1,L:0,V:0,Z:0,D:0] SsType=33554438 SsKey=0 SsNode=2 SsParty=44251768 DevId=(0,0,0) BCC=6 OtherParty=44251825 NodeOtherParty=2 clearType = 0 CSS=:2c8cf414-5250-5ef6-1c7e-92b2c99f28bb CNumInfo = 0 CNameInfo = 0 ssDevType=4 ssOtherDevType=4 FDataType=0opId=0ssType=0 SsKey=0invokeId=0resultExp=Fbpda=F ssCause = 1191182367 ssUserState = 2 ssOtherUserState = 5 PL=5 PLDmn=0 networkDomain= delayAPTimer=F geolocInfo={geolocPkid=, filterPkid=, geolocVal=, devType=4} cfwdTimerAction=0 matchInterceptPartition= matchInterceptPattern= 10192987.000 |08:03:31.014 |SdlSig |AuDisconnectRequest |wait |ConnectionManager(2,100,207,1) |MatrixControl(2,100,135,402) |2,100,13,563.4320^192.168.30.22^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] CI1=44251768 CI2=44251825 sc=0 disconnType=1 ssReason=0 clearType=0 IF1Created=F IF2Created=F party1.mMediaCoordinatorNodeId=0 party2.mMediaCoordinatorNodeId=0 party1.dtmCall=0 party2.dtmCall=0 reconnectPending=F forceStop=F 10192987.001 |08:03:31.014 |AppInfo |!!ERROR!! -ConnectionManager- wait_AuDisconnectRequest :CI NOT FOUND IN TABLE,CI(44251768,44251825),discType=1,IFCreated(0,0),PID(0-0,0-0),IFHandling(0,0),MCNode(0,0) 10192988.000 |08:03:31.014 |SdlSig |AuDisconnectReply |dissolving |MatrixControl(2,100,135,402) |ConnectionManager(2,100,207,1) |2,100,13,563.4320^192.168.30.22^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] CI1=44251768 CI2=44251825 sc=245 disconnType=1 ssReason=0 clearType=0 IF1Created=F IF2Created=F party1.mMediaCoordinatorNodeId=0 party2.mMediaCoordinatorNodeId=0 party1.dtmCall=0 party2.dtmCall=0 reconnectPending=F forceStop=F 10192988.001 |08:03:31.014 |AppInfo |MatrixControl:updatePartyMediaCoordinatorNodeId: party1 videoCapable=0, party 2 videocapable=0 10192988.002 |08:03:31.014 |Stopping | | |MatrixControl(2,100,135,402) |MatrixControl(2,100,135,402) | |NumOfCurrentInstances: 1 10192989.000 |08:03:31.015 |SdlSig |DropErr |disconnect_clearing_profile |Cdcc(2,100,212,391) |MatrixControl(2,100,135,402) |2,100,13,563.4320^192.168.30.22^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] AuStatusCode= 245 10192989.001 |08:03:31.015 |AppInfo |Cdcc - (0000391) - resetMediaSecurity 10192990.000 |08:03:31.015 |SdlSig |CcDisconnReq |restart0 |LineControl(2,100,167,217) |Cdcc(2,100,212,391) |2,100,13,563.4320^192.168.30.22^* |[R:N-H:0,N:1,L:0,V:0,Z:0,D:0] CI=44251825 CI.branch=0 clearType=0 c.l=1 c.cid=8 c.cs=0 c.lc=0 c.r=0 cv=1191182367 FDataType=0opId=0ssType=0 SsKey=0invokeId=0resultExp=Fbpda=F OnBehalf=Device rfr=0 localPatternUsage=2 connectedPatternUsage=2 rdDestPart= rdDestPatt= rdDestCdpn=pi=0si1 lrnCepn= redDestName=locale: 1 Name: UnicodeName: pi: 0 annId=0 lHPMemCEPN= cHPMemCEPN= dtmCall=F dtmDisconn=F dtmMcNodeId=0 forcedClear=F TransparentData=null CanSupportSIPTandN=false TransId=0 AllowBitMask=0x0 UserAgentOrServer= OrigDDName=locale: 1 Name: UnicodeName: pi: 0 mCallerId= mCallerName= mediaCause=0 10192991.000 |08:03:31.015 |SdlSig |CcRelReq |restart0 |LineControl(2,100,167,211) |Cdcc(2,100,212,391) |2,100,13,563.4320^192.168.30.22^* |[R:N-H:0,N:1,L:0,V:0,Z:0,D:0] CI=44251768 CI.branch=0 c.l=0 dtmCall=F dtmDisconn=F dtmMcNodeId=0 FDataType=0opId=0ssType=0 SsKey=0invokeId=0resultExp=Fbpda=FTransparentData=null CanSupportSIPTandN=true TransId=0 AllowBitMask=0x0 UserAgentOrServer=Cisco-CP9951/9.4.2 OrigDDName=locale: 1 Name: UnicodeName: pi: 0 mCallerId= mCallerName= 10192992.000 |08:03:31.015 |SdlSig |CcDisconnReq |call_received7 |LineCdpc(2,100,168,1199) |LineControl(2,100,167,217) |2,100,13,563.4320^192.168.30.22^* |[R:N-H:0,N:1,L:0,V:0,Z:0,D:0] CI=44251825 CI.branch=0 clearType=0 c.l=1 c.cid=8 c.cs=0 c.lc=0 c.r=0 cv=1191182367 FDataType=0opId=0ssType=0 SsKey=0invokeId=0resultExp=Fbpda=F OnBehalf=Device rfr=0 localPatternUsage=2 connectedPatternUsage=2 rdDestPart= rdDestPatt= rdDestCdpn=pi=0si1 lrnCepn= redDestName=locale: 1 Name: UnicodeName: pi: 0 annId=0 lHPMemCEPN= cHPMemCEPN= dtmCall=F dtmDisconn=F dtmMcNodeId=0 forcedClear=F TransparentData=null CanSupportSIPTandN=false TransId=0 AllowBitMask=0x0 UserAgentOrServer= OrigDDName=locale: 1 Name: UnicodeName: pi: 0 mCallerId= mCallerName= mediaCause=0 10192992.001 |08:03:31.015 |AppInfo |LineCdpc(1199): -dispatchToAllDevices-, sigName=CcDisconnReq, device=SEPC07BBCA0E187 10192993.000 |08:03:31.015 |SdlSig |CcRelReq |call_initiated1 |LineCdpc(2,100,168,1184) |LineControl(2,100,167,211) |2,100,13,563.4320^192.168.30.22^* |[R:N-H:0,N:1,L:0,V:0,Z:0,D:0] CI=44251768 CI.branch=0 c.l=0 dtmCall=F dtmDisconn=F dtmMcNodeId=0 FDataType=0opId=0ssType=0 SsKey=0invokeId=0resultExp=Fbpda=FTransparentData=null CanSupportSIPTandN=true TransId=0 AllowBitMask=0x0 UserAgentOrServer=Cisco-CP9951/9.4.2 OrigDDName=locale: 1 Name: UnicodeName: pi: 0 mCallerId= mCallerName= 10192993.001 |08:03:31.015 |AppInfo |LineCdpc(1184): -dispatchToAllDevices-, sigName=CcRelReq, device=SEP4931AAAAAAAA 10192994.000 |08:03:31.015 |SdlSig |CcDisconnReq |wait |SIPStationD(2,100,66,143) |LineCdpc(2,100,168,1199) |2,100,13,563.4320^192.168.30.22^* |[R:N-H:0,N:1,L:0,V:0,Z:0,D:0] CI=44251825 CI.branch=0 clearType=0 c.l=1 c.cid=8 c.cs=0 c.lc=0 c.r=0 cv=1191182367 FDataType=0opId=0ssType=0 SsKey=0invokeId=0resultExp=Fbpda=F OnBehalf=Device rfr=0 localPatternUsage=2 connectedPatternUsage=2 rdDestPart= rdDestPatt= rdDestCdpn=pi=0si1 lrnCepn= redDestName=locale: 1 Name: UnicodeName: pi: 0 annId=0 lHPMemCEPN= cHPMemCEPN= dtmCall=F dtmDisconn=F dtmMcNodeId=0 forcedClear=F TransparentData=null CanSupportSIPTandN=false TransId=0 AllowBitMask=0x0 UserAgentOrServer= OrigDDName=locale: 1 Name: UnicodeName: pi: 0 mCallerId= mCallerName= mediaCause=0 10192995.000 |08:03:31.015 |SdlSig |CcRelReq |wait |SIPStationD(2,100,66,139) |LineCdpc(2,100,168,1184) |2,100,13,563.4320^192.168.30.22^* |[R:N-H:0,N:1,L:0,V:0,Z:0,D:0] CI=44251768 CI.branch=0 c.l=0 dtmCall=F dtmDisconn=F dtmMcNodeId=0 FDataType=0opId=0ssType=0 SsKey=0invokeId=0resultExp=Fbpda=FTransparentData=null CanSupportSIPTandN=true TransId=0 AllowBitMask=0x0 UserAgentOrServer=Cisco-CP9951/9.4.2 OrigDDName=locale: 1 Name: UnicodeName: pi: 0 mCallerId= mCallerName= 10192996.000 |08:03:31.015 |SdlSig |CcDisconnReq |translate |SIPStationCdfc(2,100,67,1225) |SIPStationD(2,100,66,143) |2,100,13,563.4320^192.168.30.22^* |[R:N-H:0,N:1,L:0,V:0,Z:0,D:0] CI=44251825 CI.branch=0 clearType=0 c.l=1 c.cid=8 c.cs=0 c.lc=0 c.r=0 cv=1191182367 FDataType=0opId=0ssType=0 SsKey=0invokeId=0resultExp=Fbpda=F OnBehalf=Device rfr=0 localPatternUsage=2 connectedPatternUsage=2 rdDestPart= rdDestPatt= rdDestCdpn=pi=0si1 lrnCepn= redDestName=locale: 1 Name: UnicodeName: pi: 0 annId=0 lHPMemCEPN= cHPMemCEPN= dtmCall=F dtmDisconn=F dtmMcNodeId=0 forcedClear=F TransparentData=null CanSupportSIPTandN=false TransId=0 AllowBitMask=0x0 UserAgentOrServer= OrigDDName=locale: 1 Name: UnicodeName: pi: 0 mCallerId= mCallerName= mediaCause=0 10192996.001 |08:03:31.015 |AppInfo |SIPStationCdfc::checkAndInsertAnn annId = 0, s.sv = 2 10192997.000 |08:03:31.015 |SdlSig |CcRelReq |disconnect_indication12 |SIPStationCdfc(2,100,67,1210) |SIPStationD(2,100,66,139) |2,100,13,563.4320^192.168.30.22^* |[R:N-H:0,N:3,L:0,V:0,Z:0,D:0] CI=44251768 CI.branch=0 c.l=0 dtmCall=F dtmDisconn=F dtmMcNodeId=0 FDataType=0opId=0ssType=0 SsKey=0invokeId=0resultExp=Fbpda=FTransparentData=null CanSupportSIPTandN=true TransId=0 AllowBitMask=0x0 UserAgentOrServer=Cisco-CP9951/9.4.2 OrigDDName=locale: 1 Name: UnicodeName: pi: 0 mCallerId= mCallerName= 10192998.000 |08:03:31.015 |SdlSig |CcDisconnReq |outCall_180Rcvd |SIPCdpc(2,100,75,1403) |SIPStationCdfc(2,100,67,1225) |2,100,13,563.4320^192.168.30.22^* |[R:N-H:0,N:3,L:0,V:0,Z:0,D:0] CI=44251825 CI.branch=0 clearType=0 c.l=1 c.cid=8 c.cs=0 c.lc=0 c.r=0 cv=1191182367 FDataType=0opId=0ssType=0 SsKey=0invokeId=0resultExp=Fbpda=F OnBehalf=Device rfr=0 localPatternUsage=2 connectedPatternUsage=2 rdDestPart= rdDestPatt= rdDestCdpn=pi=0si1 lrnCepn= redDestName=locale: 1 Name: UnicodeName: pi: 0 annId=0 lHPMemCEPN= cHPMemCEPN= dtmCall=F dtmDisconn=F dtmMcNodeId=0 forcedClear=F TransparentData=null CanSupportSIPTandN=false TransId=0 AllowBitMask=0x0 UserAgentOrServer= OrigDDName=locale: 1 Name: UnicodeName: pi: 0 mCallerId= mCallerName= mediaCause=0 10192998.001 |08:03:31.015 |AppInfo |SIPCdpc(1403) - addTransparencyInfo: Transparency info is NULL. Not attaching anything. 10192998.002 |08:03:31.015 |AppInfo |SIPCdpc(1403) - getDefAe: SIPCdpc=1403, nodeId=2, processNumber=66 ci=44251825, branch=0 10192999.000 |08:03:31.015 |SdlSig |DSetCallPhase |wait |SIPStationD(2,100,66,143) |SIPStationCdfc(2,100,67,1225) |2,100,13,563.4320^192.168.30.22^* |[R:N-H:0,N:5,L:0,V:0,Z:0,D:0] CallPhase=CALL_CLEARING 10192999.001 |08:03:31.015 |AppInfo |SIPStationD(143) - DEBUG- wait_DSetCallPhase updateACall=44251825 from Phase=5 to callPhase=3. 10193000.000 |08:03:31.015 |SdlSig |DSetCallState |wait |SIPStationD(2,100,66,143) |SIPStationCdfc(2,100,67,1225) |2,100,13,563.4320^192.168.30.22^* |[R:N-H:0,N:4,L:0,V:0,Z:0,D:0] CallState = disconnect_request11 10193001.000 |08:03:31.015 |SdlSig |CcRelReq |disconnectRcvd |SIPCdpc(2,100,75,1388) |SIPStationCdfc(2,100,67,1210) |2,100,13,563.4320^192.168.30.22^* |[R:N-H:0,N:3,L:0,V:0,Z:0,D:0] CI=44251768 CI.branch=0 c.l=0 dtmCall=F dtmDisconn=F dtmMcNodeId=0 FDataType=0opId=0ssType=0 SsKey=0invokeId=0resultExp=Fbpda=FTransparentData=null CanSupportSIPTandN=true TransId=0 AllowBitMask=0x0 UserAgentOrServer=Cisco-CP9951/9.4.2 OrigDDName=locale: 1 Name: UnicodeName: pi: 0 mCallerId= mCallerName= 10193002.000 |08:03:31.015 |SdlSig-O |MXAgenaCloseLogicalChannel |NA RemoteSignal |MediaTerminationPointControl(1,100,130,2) |SIPCdpc(2,100,75,1403) |2,100,13,563.4320^192.168.30.22^* |[R:N-H:0,N:3,L:0,V:0,Z:0,D:0] ConferenceID= 16781567 PartyId= 33554953 streamFlag=F ClearType= 0 PortHandling=0 ci=44251825 lcn=0 PT=F PTId=0 switchingToFax=F ConnType=0 10193003.000 |08:03:31.015 |SdlSig |MrmDeallocateMtpResourceReq |waiting |MediaResourceManager(2,100,131,1) |SIPCdpc(2,100,75,1403) |2,100,13,563.4320^192.168.30.22^* |[R:N-H:0,N:2,L:0,V:0,Z:0,D:0] ClearType= 0 CI=44251827 Count=0 10193004.000 |08:03:31.015 |SdlSig |CcRelInd |restart0 |LineControl(2,100,167,211) |SIPCdpc(2,100,75,1388) |2,100,13,563.4320^192.168.30.22^* |[R:N-H:0,N:1,L:0,V:0,Z:0,D:0] CI=44251768 CI.branch=0 c.l=1 c.cid=8 c.cs=0 c.lc=0 c.r=0 CV=0 isDeskPickup=F dtmDisconn=F FDataType=0opId=0ssType=0 SsKey=0invokeId=0resultExp=Fbpda=FTransparentData=null CanSupportSIPTandN=false TransId=0 AllowBitMask=0x0 UserAgentOrServer= OrigDDName=locale: 1 Name: UnicodeName: pi: 0 mCallerId= mCallerName= 10193005.000 |08:03:31.015 |SdlSig-O |DeallocateMtpResourceReq |NA RemoteSignal |MediaTerminationPointControl(1,100,130,2) |MediaResourceManager(2,100,131,1) |2,100,13,563.4320^192.168.30.22^* |[R:N-H:0,N:1,L:0,V:0,Z:0,D:0] ClearType= 0 CI=44251827 Count=1 10193006.000 |08:03:31.015 |SdlSig |CcRelInd |call_initiated1 |LineCdpc(2,100,168,1184) |LineControl(2,100,167,211) |2,100,13,563.4320^192.168.30.22^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] CI=44251768 CI.branch=0 c.l=1 c.cid=8 c.cs=0 c.lc=0 c.r=0 CV=0 isDeskPickup=F dtmDisconn=F FDataType=0opId=0ssType=0 SsKey=0invokeId=0resultExp=Fbpda=FTransparentData=null CanSupportSIPTandN=false TransId=0 AllowBitMask=0x0 UserAgentOrServer= OrigDDName=locale: 1 Name: UnicodeName: pi: 0 mCallerId= mCallerName= 10193006.001 |08:03:31.015 |AppInfo |LineCdpc(1184)dispatchKeyReleaseReq - mDevicePid(2, 66, 139); mSelectedDPid(0, 0, 0), mOnBehalfOf(), rfr(0) 10193007.000 |08:03:31.015 |SdlSig |CcRelInd |wait |Cc(2,100,213,1) |LineCdpc(2,100,168,1184) |2,100,13,563.4320^192.168.30.22^* |[R:N-H:0,N:1,L:0,V:0,Z:0,D:0] CI=44251768 CI.branch=0 c.l=1 c.cid=8 c.cs=0 c.lc=0 c.r=0 CV=0 isDeskPickup=F dtmDisconn=F FDataType=0opId=0ssType=0 SsKey=0invokeId=0resultExp=Fbpda=FTransparentData=null CanSupportSIPTandN=false TransId=0 AllowBitMask=0x0 UserAgentOrServer= OrigDDName=locale: 1 Name: UnicodeName: pi: 0 mCallerId= mCallerName= 10193008.000 |08:03:31.015 |SdlSig |DStopInd |restart0 |LineControl(2,100,167,211) |LineCdpc(2,100,168,1184) |2,100,13,563.4320^192.168.30.22^* |[R:N-H:0,N:1,L:0,V:0,Z:0,D:0] 10193008.001 |08:03:31.015 |AppInfo |Line Control:: restart_DStopInd Release Call Instance = 1 10193008.002 |08:03:31.015 |AppInfo |LineControl::sendSNFNotifyIndForPresenceWithAlerting mPrecenceWithAlertingChangeNotifySubscribed=0, calllist#=0 10193008.003 |08:03:31.015 |AppInfo |LineControl (211) - DStopInd - Line become idle 10193008.004 |08:03:31.015 |AppInfo |LineControl(211) - 0 calls, 0 CiReq, busyTrigger=40, maxCall=40 10193009.000 |08:03:31.015 |SdlSig |CcRelInd |tcc_await_two_way_release10 |Cdcc(2,100,212,391) |Cc(2,100,213,1) |2,100,13,563.4320^192.168.30.22^* |[R:N-H:0,N:1,L:0,V:0,Z:0,D:0] CI=44251768 CI.branch=0 c.l=1 c.cid=8 c.cs=0 c.lc=0 c.r=0 CV=0 isDeskPickup=F dtmDisconn=F FDataType=0opId=0ssType=0 SsKey=0invokeId=0resultExp=Fbpda=FTransparentData=null CanSupportSIPTandN=false TransId=0 AllowBitMask=0x0 UserAgentOrServer= OrigDDName=locale: 1 Name: UnicodeName: pi: 0 mCallerId= mCallerName= 10193009.001 |08:03:31.015 |AppInfo |processCCMFeatureData: operationIeIdd=0 10193010.000 |08:03:31.015 |SdlSig |DStopConf |call_initiated1 |LineCdpc(2,100,168,1184) |LineControl(2,100,167,211) |2,100,13,563.4320^192.168.30.22^* |[R:N-H:0,N:1,L:0,V:0,Z:0,D:0] varChannelStatus=0 10193010.001 |08:03:31.015 |Stopping | | |LineCdpc(2,100,168,1184) |LineCdpc(2,100,168,1184) | |NumOfCurrentInstances: 2 10193011.000 |08:03:31.015 |SdlSig |SsDataInd |wait |ForwardManager(2,100,193,1) |Cdcc(2,100,212,391) |2,100,13,563.4320^192.168.30.22^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] SsType=33554438 SsKey=0 SsNode=2 SsParty=44251768 DevId=(0,0,0) BCC=7 OtherParty=44251825 NodeOtherParty=2 clearType = 0 CSS=:2c8cf414-5250-5ef6-1c7e-92b2c99f28bb CNumInfo = 0 CNameInfo = 0 ssDevType=4 ssOtherDevType=4 FDataType=0opId=0ssType=0 SsKey=0invokeId=0resultExp=Fbpda=F ssCause = 0 ssUserState = 4 ssOtherUserState = 5 PL=5 PLDmn=0 networkDomain= delayAPTimer=F geolocInfo={geolocPkid=, filterPkid=, geolocVal=, devType=4} cfwdTimerAction=0 matchInterceptPartition= matchInterceptPattern= 10193011.001 |08:03:31.015 |AppInfo |ForwardManager - wait_SsDataInd - Key= 0x0, party= 44251768, BCC= 7 10193011.002 |08:03:31.015 |AppInfo |ForwardManager - findCallBySsParty - Found entry for party= 44251768, callkey= 0x86 10193011.003 |08:03:31.015 |AppInfo |ForwardManager - wait_SsDataInd - removeActiveCallIndexMapBySsParty party= 44251768 10193012.000 |08:03:31.015 |SdlSig |SsDataInd |awaitingCallResponse |Forwarding(2,100,192,134) |ForwardManager(2,100,193,1) |2,100,13,563.4320^192.168.30.22^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] SsType=33554438 SsKey=0 SsNode=2 SsParty=44251768 DevId=(0,0,0) BCC=7 OtherParty=44251825 NodeOtherParty=2 clearType = 0 CSS=:2c8cf414-5250-5ef6-1c7e-92b2c99f28bb CNumInfo = 0 CNameInfo = 0 ssDevType=4 ssOtherDevType=4 FDataType=0opId=0ssType=0 SsKey=0invokeId=0resultExp=Fbpda=F ssCause = 0 ssUserState = 4 ssOtherUserState = 5 PL=5 PLDmn=0 networkDomain= delayAPTimer=F geolocInfo={geolocPkid=, filterPkid=, geolocVal=, devType=4} cfwdTimerAction=0 matchInterceptPartition= matchInterceptPattern= 10193012.001 |08:03:31.015 |AppInfo |Forwarding - awaitingCallResponse_SsDataInd - BASIC_CALL_RELEASE - Origination Release. party= 44251768, callKey= 0x86 10193013.000 |08:03:31.016 |SdlSig |SIPDisconnReq |wait |SIPHandler(2,100,72,1) |SIPCdpc(2,100,75,1403) |2,100,13,563.4320^192.168.30.22^* |[T:N-H:0,N:1,L:0,V:0,Z:0,D:0] CcbId= 454873 --TransType=1 --TransSecurity=0 PeerAddr = 192.168.20.32:49409 ccCause= 0 sip_disc_cause= 487 10193013.001 |08:03:31.016 |AppInfo |//SIP/Stack/Info/0x0/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 (SIP_APPLICATION_MSG), for event 8 (SIPSPI_EV_CC_CALL_DISCONNECT) 10193013.002 |08:03:31.016 |AppInfo |//SIP/Stack/Error/0x0/sipSPIUcccause_to_sipcause: Unknown PSTN cause code from CCAPI:0 10193013.003 |08:03:31.016 |AppInfo |//SIP/Stack/Info/0x102231f8/sipSPISendCancel: Associated container=0xb6eb5d10 to Cancel 10193013.004 |08:03:31.016 |AppInfo |//SIP/Stack/Transport/0x102231f8/sipSPISendCancel: Sending CANCEL to the transport layer 10193013.005 |08:03:31.016 |AppInfo |//SIP/Stack/Transport/0x102231f8/sipSPITransportSendMessage: msg=0xb6e1a718, addr=192.168.20.32, port=49409, sentBy_port=0, is_req=1, transp 10193013.006 |08:03:31.016 |AppInfo |//SIP/Stack/Transport/0x0/sipInstanceGetConnectionId: gcb=0x102231f8 is already on connection=0xfe2df08 context_list 10193013.007 |08:03:31.016 |AppInfo |//SIP/Stack/Transport/0x102231f8/sipTransportLogicSendMsg: Set to send the msg=0xb6e1a718 10193013.008 |08:03:31.016 |AppInfo |//SIP/Stack/Transport/0x102231f8/sipTransportPostSendMessage: Posting send for msg=0xb6e1a718, addr=192.168.20.32, port=49409, connId=13184 for T 10193013.009 |08:03:31.016 |AppInfo |//SIP/Stack/Info/0x102231f8/sentCancelDisconnecting: Sent Cancel Request, starting CancelWaitResponseTimer 10193013.010 |08:03:31.016 |AppInfo |//SIP/Stack/States/0x102231f8/sipSPIChangeState: 0x102231f8 : State change from (STATE_RECD_PROCEEDING, SUBSTATE_PROCEEDING_PROCEEDING) to (STATE_DISCONNECTING, SUBSTATE_NONE) 10193013.011 |08:03:31.016 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/sip_stop_timer: type=SIP_TIMER_DISCONNECT value=500 retries=10 10193013.012 |08:03:31.016 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/sip_start_timer: type=SIP_TIMER_DISCONNECT value=500 retries=10 10193014.000 |08:03:31.016 |SdlSig |SIPSPISignal |wait |SIPTcp(2,100,64,1) |SIPHandler(2,100,72,1) |2,100,13,563.4320^192.168.30.22^* |*TraceFlagOverrode 10193014.001 |08:03:31.016 |AppInfo |SIPTcp - wait_SdlSPISignal: Outgoing SIP TCP message to 192.168.20.32 on port 49409 index 13184 [1115467,NET] CANCEL sip:8c3deb6d-a503-8513-4601-7d77a85ce60b@192.168.20.32:49409;transport=tcp SIP/2.0 Via: SIP/2.0/TCP 192.168.10.8:5060;branch=z9hG4bK1dfc5126d9faf From: ;tag=454873~946f5a50-7410-423d-a5bb-36fb6cd3f0d0-44251825 To: Date: Wed, 02 Sep 2015 08:01:33 GMT Call-ID: d2213200-5e61acdd-1dc2c-80aa8c0@192.168.10.8 CSeq: 101 CANCEL Max-Forwards: 70 Reason: Q.850; cause=31 Content-Length: 0 10193015.000 |08:03:31.016 |SdlSig |SdlReadRsp |wait |SIPTcp(2,100,64,1) |SdlTCPConnection(2,100,13,563) |2,100,13,563.4336^192.168.30.22^* |*TraceFlagOverrode 10193015.001 |08:03:31.016 |AppInfo |SIPTcp - SdlRead bufferLen=497 10193015.002 |08:03:31.016 |AppInfo |SIPTcp - wait_SdlReadRsp: Incoming SIP TCP message from 192.168.30.22 on port 49196 index 13169 with 497 bytes: [1115468,NET] ACK sip:4901@192.168.10.8;transport=TCP SIP/2.0 From: "yorknorth";tag=4f91c48-161ea8c0-13c4-5506-7867a-16550fe-7867a To: "";tag=454645~946f5a50-7410-423d-a5bb-36fb6cd3f0d0-44251768 Call-ID: 4faebf8-161ea8c0-13c4-5506-7867a-5b8c0d60-7867a CSeq: 1 ACK Via: SIP/2.0/TCP 192.168.30.22:5060;branch=z9hG4bK-7867a-1d65503d-3a281f78 Max-Forwards: 70 Contact: Content-Length: 0 10193015.003 |08:03:31.016 |AppInfo |SIPTcp - SignalCounter = 337377 10193016.000 |08:03:31.016 |SdlSig |SIPRelReq |wait |SIPHandler(2,100,72,1) |SIPCdpc(2,100,75,1388) |2,100,13,563.4320^192.168.30.22^* |[T:N-H:0,N:1,L:0,V:0,Z:0,D:0] CcbId= 454645 --TransType=1 --TransSecurity=0 PeerAddr = 192.168.30.22:49196 ccCause= 0 sip_disc_cause= 0 10193016.001 |08:03:31.016 |AppInfo |//SIP/Stack/Info/0x0/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 (SIP_APPLICATION_MSG), for event 8 (SIPSPI_EV_CC_CALL_DISCONNECT) 10193017.000 |08:03:31.017 |SdlSig |SIPSPISignal |wait |SIPHandler(2,100,72,1) |SIPTcp(2,100,64,1) |2,100,13,563.4336^192.168.30.22^* |*TraceFlagOverrode 10193017.001 |08:03:31.017 |AppInfo |//SIP/Stack/Info/0x0/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 (SIP_NETWORK_MSG), for event 1 (SIPSPI_EV_NEW_MESSAGE) 10193017.002 |08:03:31.017 |AppInfo |//SIP/Stack/Transport/0x0/sipTransportProcessNWNewConnMsg: context=(nil) 10193017.003 |08:03:31.017 |AppInfo |//SIP/Stack/Transport/0x0/sipConnectionManagerProcessNewConnMsg: gConnTab=0xf553560, addr=192.168.30.22, port=49196, connid=13169, transport=TCP 10193017.004 |08:03:31.017 |AppInfo |//SIP/Stack/Info/0x0/sipHolderGetConnInstance: Return existing connection for port 49196 connId 13169 10193017.005 |08:03:31.017 |AppInfo |//SIP/Stack/Info/0x10220278/sipSPIFindCcbUASRespTable: *****CCB found in UAS Response table. ccb=0x10220278 10193017.006 |08:03:31.017 |AppInfo |//SIP/Stack/Transport/0x0/sipSPIUpdateResponseInfo: Subsq Transaction Address 192.168.30.22,Port 49196, Transport 2, SentBy Port 5060 10193017.007 |08:03:31.017 |AppInfo |//SIP/Stack/Transport/0x0/sipSPIUpdateResponseInfo: Subsq Transaction Address 192.168.30.22,Port 49196, Transport 2, SentBy Port 5060 10193017.008 |08:03:31.017 |AppInfo |//SIP/SIPHandler/ccbId=454645/scbId=0/findDevicePID: Routed to SIPD by ccbId/scbId 10193017.009 |08:03:31.017 |AppInfo |//SIP/Stack/States/0x10220278/sipSPIChangeState: 0x10220278 : State change from (STATE_DISCONNECTING, SUBSTATE_NONE) to (STATE_DEAD, SUBSTATE_NONE) 10193017.010 |08:03:31.017 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/sip_stop_timer: type=SIP_TIMER_CONNECT value=500 retries=6 10193017.011 |08:03:31.017 |AppInfo |//SIP/Stack/Info/0x10220278/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be 10193017.012 |08:03:31.017 |AppInfo |//SIP/Stack/Transport/0x0/sipConnectionManagerUnregisterCtxtInCon: gConnTab=0xf553560, addr=192.168.30.22, port=49196, unregistering context= 10193017.013 |08:03:31.017 |AppInfo |//SIP/Stack/Transport/0x10220278/sipSPITransportContextCleanup: Could not purge context gcb=0x10220278 from the connection; gcb 10193017.014 |08:03:31.017 |AppInfo |//SIP/Stack/Info/0x10220278/sipSPIUfreeOneCCB: Freeing ccb 10220278 10193018.000 |08:03:31.017 |SdlSig |SIPRelCompInd |wait |SIPStationD(2,100,66,139) |SIPHandler(2,100,72,1) |2,100,13,563.4336^192.168.30.22^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] CcbId= 454645 --TransType=1 --TransSecurity=0 PeerAddr = 192.168.30.22:49196 10193019.000 |08:03:31.017 |SdlSig |SIPRelCompInd |release_request19 |SIPStationCdfc(2,100,67,1210) |SIPStationD(2,100,66,139) |2,100,13,563.4336^192.168.30.22^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] CcbId= 454645 --TransType=1 --TransSecurity=0 PeerAddr = 192.168.30.22:49196 10193020.000 |08:03:31.017 |SdlSig |SIPRelCompInd |releaseRequest |SIPCdpc(2,100,75,1388) |SIPStationCdfc(2,100,67,1210) |2,100,13,563.4336^192.168.30.22^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] CcbId= 454645 --TransType=1 --TransSecurity=0 PeerAddr = 192.168.30.22:49196 10193020.001 |08:03:31.017 |AppInfo |SIPCdpc(1388) - updateCallStatsForCallCompletion: SIPCdpc=1388, nodeId=2, processNumber=66 10193020.002 |08:03:31.017 |AppInfo |SIPCdpc(1388) - terminateOobDtmf: Termination not required. 10193021.000 |08:03:31.017 |SdlSig |PolicyAndCACUnregisterReq |wait |ReservationMgr(2,100,103,1) |SIPCdpc(2,100,75,1388) |2,100,13,563.4336^192.168.30.22^* |[R:N-H:0,N:1,L:0,V:0,Z:0,D:0] CI= 44251768 ClearType=0 10193022.000 |08:03:31.017 |SdlSig |DStopInd |stop_indication |SIPStationCdfc(2,100,67,1210) |SIPCdpc(2,100,75,1388) |2,100,13,563.4336^192.168.30.22^* |[R:N-H:0,N:2,L:0,V:0,Z:0,D:0] 10193023.000 |08:03:31.017 |SdlSig |CACUnregisterReq |wait |RSVPSession(2,100,100,392) |ReservationMgr(2,100,103,1) |2,100,13,563.4336^192.168.30.22^* |[R:N-H:0,N:3,L:0,V:0,Z:0,D:0] CI= 44251768 ClearType=0 10193024.000 |08:03:31.017 |SdlSig |DStopConf |stop_indication |SIPCdpc(2,100,75,1388) |SIPStationCdfc(2,100,67,1210) |2,100,13,563.4336^192.168.30.22^* |[R:N-H:0,N:1,L:0,V:0,Z:0,D:0] varChannelStatus=0 10193024.001 |08:03:31.017 |Stopping | | |SIPCdpc(2,100,75,1388) |SIPCdpc(2,100,75,1388) | |NumOfCurrentInstances: 2 10193025.000 |08:03:31.018 |SdlSig |DStopInd |wait |SIPStationD(2,100,66,139) |SIPStationCdfc(2,100,67,1210) |2,100,13,563.4336^192.168.30.22^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] 10193025.001 |08:03:31.018 |AppInfo |SIPStationD(139) - terminateCallLinkage: No Linked SIPStationCdfc. 10193025.002 |08:03:31.018 |AppInfo |SIPStationD(139) - wait_DStopInd: DEBUG: SIPStationCdfc(1210) removed. Calltable contains 0 calls. 10193025.003 |08:03:31.018 |AppInfo |SIPStationD(139) - adding linestruct at index 2 pattern 4932 10193025.004 |08:03:31.018 |AppInfo |SIPStationD(139) - adding linestruct at index 3 pattern 4999 10193025.005 |08:03:31.018 |AppInfo |SIPStationD(139) - adding linestruct at index 4 pattern 4933 10193026.000 |08:03:31.018 |SdlSig |DStopConf |stop_indication |SIPStationCdfc(2,100,67,1210) |SIPStationD(2,100,66,139) |2,100,13,563.4336^192.168.30.22^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] varChannelStatus=0 10193026.001 |08:03:31.018 |Stopping | | |SIPStationCdfc(2,100,67,1210) |SIPStationCdfc(2,100,67,1210) | |NumOfCurrentInstances: 2 10193027.000 |08:03:31.018 |SdlSig |CACUnregisterReq |active |LBMInterface(2,100,169,1) |ReservationMgr(2,100,103,1) |2,100,13,563.4336^192.168.30.22^* |[T:N-H:0,N:0,L:0,V:0,Z:0,D:0] CI= 44251768 ClearType=0 10193027.001 |08:03:31.018 |AppInfo |LBMIF: CI: 44251768 UNREG 2,100,75,1388 dev 0xb6e8c268 10193027.002 |08:03:31.018 |AppInfo |LBMIF: CI: 44251768 BW REL> dev 0xb6e8c268 212090865900001207 10193027.003 |08:03:31.018 |AppInfo |LBMIF: REL XML> (2582) 212090865900001207 Hub_None|Hub_None 10193027.004 |08:03:31.018 |AppInfo |LBMIF: Sending to LOCAL LBM 10193028.000 |08:03:31.020 |SdlSig |SdlDataInd |active |LBMInterface(2,100,169,1) |SdlTCPConnection(2,100,13,1) |2,100,13,1.2591^*^* |*TraceFlagOverrode 10193028.001 |08:03:31.020 |AppInfo |LBMIF: REL XML< (2582) 212090865900001207 S A:N,0 V:N,0 I:N,0 10193028.002 |08:03:31.020 |AppInfo |LBMIF: CI: 44251768 BW REL;tag=454873~946f5a50-7410-423d-a5bb-36fb6cd3f0d0-44251825 To: ;tag=c07bbca0e1875b0b7194bd98-2333ba4b Call-ID: d2213200-5e61acdd-1dc2c-80aa8c0@192.168.10.8 Date: Wed, 02 Sep 2015 08:03:27 GMT CSeq: 101 CANCEL Server: Cisco-CP9951/9.4.2 Content-Length: 0 10193029.003 |08:03:31.020 |AppInfo |SIPTcp - SignalCounter = 337378 10193030.000 |08:03:31.020 |SdlSig |SIPSPISignal |wait |SIPHandler(2,100,72,1) |SIPTcp(2,100,64,1) |2,100,13,578.992^192.168.20.32^* |*TraceFlagOverrode 10193030.001 |08:03:31.020 |AppInfo |//SIP/Stack/Info/0x0/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 (SIP_NETWORK_MSG), for event 1 (SIPSPI_EV_NEW_MESSAGE) 10193030.002 |08:03:31.020 |AppInfo |//SIP/Stack/Transport/0x0/sipTransportProcessNWNewConnMsg: context=(nil) 10193030.003 |08:03:31.020 |AppInfo |//SIP/Stack/Transport/0x0/sipConnectionManagerProcessNewConnMsg: gConnTab=0xf553560, addr=192.168.20.32, port=49409, connid=13184, transport=TCP 10193030.004 |08:03:31.020 |AppInfo |//SIP/Stack/Info/0x0/sipHolderGetConnInstance: Return existing connection for port 49409 connId 13184 10193030.005 |08:03:31.020 |AppInfo |//SIP/Stack/Info/0x102231f8/sipSPIMatchRespToReqTran: removing unneeded z9hG4bK1dfc5126d9faf from via branch list 10193030.006 |08:03:31.020 |AppInfo |//SIP/Stack/Error/0x0/sipSPIRemoveBranchName: invalid ccb, bName or branch list for sipSPIRemoveBranchName 10193030.007 |08:03:31.020 |AppInfo |//SIP/Stack/Info/0x102231f8/sipSPICheckResponseExt: non-INVITE response with no RSEQ - do not disable IS_REL1XX 10193030.008 |08:03:31.020 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/sip_stop_timer: type=SIP_TIMER_DISCONNECT value=500 retries=10 10193030.009 |08:03:31.020 |AppInfo |//SIP/SIPHandler/ccbId=454873/scbId=0/findDevicePID: Routed to SIPD by ccbId/scbId 10193031.000 |08:03:31.020 |SdlSig |SIPRelCompInd |wait |SIPStationD(2,100,66,143) |SIPHandler(2,100,72,1) |2,100,13,578.992^192.168.20.32^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] CcbId= 454873 --TransType=1 --TransSecurity=0 PeerAddr = 192.168.20.32:49409 10193032.000 |08:03:31.020 |SdlSig |SIPRelCompInd |disconnect_request11 |SIPStationCdfc(2,100,67,1225) |SIPStationD(2,100,66,143) |2,100,13,578.992^192.168.20.32^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] CcbId= 454873 --TransType=1 --TransSecurity=0 PeerAddr = 192.168.20.32:49409 10193033.000 |08:03:31.020 |SdlSig |SIPRelCompInd |disconnectSent |SIPCdpc(2,100,75,1403) |SIPStationCdfc(2,100,67,1225) |2,100,13,578.992^192.168.20.32^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] CcbId= 454873 --TransType=1 --TransSecurity=0 PeerAddr = 192.168.20.32:49409 10193033.001 |08:03:31.020 |AppInfo |SIPCdpc(1403) - updateCallStatsForCallCompletion: SIPCdpc=1403, nodeId=2, processNumber=66 10193033.002 |08:03:31.020 |AppInfo |SIPCdpc(1403) - terminateOobDtmf: Termination not required. 10193034.000 |08:03:31.020 |SdlSig |CcRelInd |restart0 |LineControl(2,100,167,217) |SIPCdpc(2,100,75,1403) |2,100,13,578.992^192.168.20.32^* |[R:N-H:0,N:2,L:0,V:0,Z:0,D:0] CI=44251825 CI.branch=0 c.l=1 c.cid=8 c.cs=0 c.lc=0 c.r=0 CV=0 isDeskPickup=F dtmDisconn=F FDataType=0opId=0ssType=0 SsKey=0invokeId=0resultExp=Fbpda=FTransparentData=null CanSupportSIPTandN=false TransId=0 AllowBitMask=0x0 UserAgentOrServer= OrigDDName=locale: 1 Name: UnicodeName: pi: 0 mCallerId= mCallerName= 10193035.000 |08:03:31.020 |SdlSig |PolicyAndCACUnregisterReq |wait |ReservationMgr(2,100,103,1) |SIPCdpc(2,100,75,1403) |2,100,13,578.992^192.168.20.32^* |[R:N-H:0,N:2,L:0,V:0,Z:0,D:0] CI= 44251825 ClearType=0 10193036.000 |08:03:31.020 |SdlSig |DStopInd |stop_indication |SIPStationCdfc(2,100,67,1225) |SIPCdpc(2,100,75,1403) |2,100,13,578.992^192.168.20.32^* |[R:N-H:0,N:3,L:0,V:0,Z:0,D:0] 10193037.000 |08:03:31.020 |SdlSig |CcRelInd |call_received7 |LineCdpc(2,100,168,1199) |LineControl(2,100,167,217) |2,100,13,578.992^192.168.20.32^* |[R:N-H:0,N:4,L:0,V:0,Z:0,D:0] CI=44251825 CI.branch=0 c.l=1 c.cid=8 c.cs=0 c.lc=0 c.r=0 CV=0 isDeskPickup=F dtmDisconn=F FDataType=0opId=0ssType=0 SsKey=0invokeId=0resultExp=Fbpda=FTransparentData=null CanSupportSIPTandN=false TransId=0 AllowBitMask=0x0 UserAgentOrServer= OrigDDName=locale: 1 Name: UnicodeName: pi: 0 mCallerId= mCallerName= 10193037.001 |08:03:31.020 |AppInfo |LineCdpc(1199)dispatchKeyReleaseReq - mDevicePid(0, 0, 0); mSelectedDPid(0, 0, 0), mOnBehalfOf(Device), rfr(0) 10193038.000 |08:03:31.020 |SdlSig |CACUnregisterReq |wait |RSVPSession(2,100,100,392) |ReservationMgr(2,100,103,1) |2,100,13,578.992^192.168.20.32^* |[R:N-H:0,N:5,L:0,V:0,Z:0,D:0] CI= 44251825 ClearType=0 10193039.000 |08:03:31.020 |SdlSig |DStopConf |stop_indication |SIPCdpc(2,100,75,1403) |SIPStationCdfc(2,100,67,1225) |2,100,13,578.992^192.168.20.32^* |[R:N-H:0,N:3,L:0,V:0,Z:0,D:0] varChannelStatus=0 10193039.001 |08:03:31.020 |Stopping | | |SIPCdpc(2,100,75,1403) |SIPCdpc(2,100,75,1403) | |NumOfCurrentInstances: 1 10193040.000 |08:03:31.021 |SdlSig |DStopInd |wait |SIPStationD(2,100,66,143) |SIPStationCdfc(2,100,67,1225) |2,100,13,578.992^192.168.20.32^* |[R:N-H:0,N:2,L:0,V:0,Z:0,D:0] 10193040.001 |08:03:31.021 |AppInfo |SIPStationD(143) - terminateCallLinkage: No Linked SIPStationCdfc. 10193040.002 |08:03:31.021 |AppInfo |SIPStationD(143) - wait_DStopInd: DEBUG: SIPStationCdfc(1225) removed. Calltable contains 0 calls. 10193041.000 |08:03:31.021 |SdlSig |CcRelInd |wait |Cc(2,100,213,1) |LineCdpc(2,100,168,1199) |2,100,13,578.992^192.168.20.32^* |[R:N-H:0,N:2,L:0,V:0,Z:0,D:0] CI=44251825 CI.branch=0 c.l=1 c.cid=8 c.cs=0 c.lc=0 c.r=0 CV=0 isDeskPickup=F dtmDisconn=F FDataType=0opId=0ssType=0 SsKey=0invokeId=0resultExp=Fbpda=FTransparentData=null CanSupportSIPTandN=false TransId=0 AllowBitMask=0x0 UserAgentOrServer= OrigDDName=locale: 1 Name: UnicodeName: pi: 0 mCallerId= mCallerName= 10193042.000 |08:03:31.021 |SdlSig |DStopInd |restart0 |LineControl(2,100,167,217) |LineCdpc(2,100,168,1199) |2,100,13,578.992^192.168.20.32^* |[R:N-H:0,N:2,L:0,V:0,Z:0,D:0] 10193042.001 |08:03:31.021 |AppInfo |deleteCi: Unable to find the device that owns the call with CI=44251825 10193042.002 |08:03:31.021 |AppInfo |Line Control:: restart_DStopInd Release Call Instance = 1 10193042.003 |08:03:31.021 |AppInfo |Line Control:: restart_DStopInd Release Call Instance = 2 10193042.004 |08:03:31.021 |AppInfo |Line Control:: restart_DStopInd Release Call Instance = 3 10193042.005 |08:03:31.021 |AppInfo |Line Control:: restart_DStopInd Release Call Instance = 4 10193042.006 |08:03:31.021 |AppInfo |Line Control:: restart_DStopInd Release Call Instance = 5 10193042.007 |08:03:31.021 |AppInfo |Line Control:: restart_DStopInd Release Call Instance = 6 10193042.008 |08:03:31.021 |AppInfo |Line Control:: restart_DStopInd Release Call Instance = 7 10193042.009 |08:03:31.021 |AppInfo |Line Control:: restart_DStopInd Release Call Instance = 8 10193042.010 |08:03:31.021 |AppInfo |Line Control:: restart_DStopInd Release Call Instance = 9 10193042.011 |08:03:31.021 |AppInfo |Line Control:: restart_DStopInd Release Call Instance = 10 10193042.012 |08:03:31.021 |AppInfo |Line Control:: restart_DStopInd Release Call Instance = 11 10193042.013 |08:03:31.021 |AppInfo |Line Control:: restart_DStopInd Release Call Instance = 12 10193042.014 |08:03:31.021 |AppInfo |Line Control:: restart_DStopInd Release Call Instance = 13 10193042.015 |08:03:31.021 |AppInfo |Line Control:: restart_DStopInd Release Call Instance = 14 10193042.016 |08:03:31.021 |AppInfo |Line Control:: restart_DStopInd Release Call Instance = 15 10193042.017 |08:03:31.021 |AppInfo |LineControl::sendSNFNotifyIndForPresenceWithAlerting mPrecenceWithAlertingChangeNotifySubscribed=0, calllist#=0 10193042.018 |08:03:31.021 |AppInfo |LineControl (217) - DStopInd - Line become idle 10193042.019 |08:03:31.021 |AppInfo |LineControl(217) - 0 calls, 0 CiReq, busyTrigger=40, maxCall=40 10193043.000 |08:03:31.021 |SdlSig |DStopConf |stop_indication |SIPStationCdfc(2,100,67,1225) |SIPStationD(2,100,66,143) |2,100,13,578.992^192.168.20.32^* |[R:N-H:0,N:3,L:0,V:0,Z:0,D:0] varChannelStatus=0 10193043.001 |08:03:31.021 |Stopping | | |SIPStationCdfc(2,100,67,1225) |SIPStationCdfc(2,100,67,1225) | |NumOfCurrentInstances: 1 10193044.000 |08:03:31.021 |SdlSig |CcRelInd |tcc_await_outgoing_release9 |Cdcc(2,100,212,391) |Cc(2,100,213,1) |2,100,13,578.992^192.168.20.32^* |[R:N-H:0,N:2,L:0,V:0,Z:0,D:0] CI=44251825 CI.branch=0 c.l=1 c.cid=8 c.cs=0 c.lc=0 c.r=0 CV=0 isDeskPickup=F dtmDisconn=F FDataType=0opId=0ssType=0 SsKey=0invokeId=0resultExp=Fbpda=FTransparentData=null CanSupportSIPTandN=false TransId=0 AllowBitMask=0x0 UserAgentOrServer= OrigDDName=locale: 1 Name: UnicodeName: pi: 0 mCallerId= mCallerName= 10193044.001 |08:03:31.021 |AppInfo |processCCMFeatureData: operationIeIdd=0 10193045.000 |08:03:31.021 |SdlSig |DStopConf |call_received7 |LineCdpc(2,100,168,1199) |LineControl(2,100,167,217) |2,100,13,578.992^192.168.20.32^* |[R:N-H:0,N:3,L:0,V:0,Z:0,D:0] varChannelStatus=0 10193045.001 |08:03:31.021 |Stopping | | |LineCdpc(2,100,168,1199) |LineCdpc(2,100,168,1199) | |NumOfCurrentInstances: 1 10193046.000 |08:03:31.021 |SdlSig |SsDataInd |wait |ForwardManager(2,100,193,1) |Cdcc(2,100,212,391) |2,100,13,578.992^192.168.20.32^* |[R:N-H:0,N:1,L:0,V:0,Z:0,D:0] SsType=33554438 SsKey=0 SsNode=2 SsParty=44251825 DevId=(0,0,0) BCC=7 OtherParty=44251768 NodeOtherParty=2 clearType = 0 CSS=:2c8cf414-5250-5ef6-1c7e-92b2c99f28bb CNumInfo = 0 CNameInfo = 0 ssDevType=4 ssOtherDevType=4 FDataType=0opId=0ssType=0 SsKey=0invokeId=0resultExp=Fbpda=F ssCause = 0 ssUserState = 4 ssOtherUserState = 4 PL=5 PLDmn=0 networkDomain= delayAPTimer=F geolocInfo={geolocPkid=, filterPkid=, geolocVal=, devType=4} cfwdTimerAction=0 matchInterceptPartition= matchInterceptPattern= 10193046.001 |08:03:31.021 |AppInfo |ForwardManager - wait_SsDataInd - Key= 0x0, party= 44251825, BCC= 7 10193046.002 |08:03:31.021 |AppInfo |ForwardManager - findCallBySsParty - Found entry for party= 44251825, callkey= 0x86 10193046.003 |08:03:31.021 |AppInfo |ForwardManager - wait_SsDataInd - BASIC_CALL_RELEASE - mPartyToActiveCallIndexMap - Removed entry Destparty= 44251825, callkey= 0x86 10193047.000 |08:03:31.021 |SdlSig |PolicyAndCACUnassociateReq |wait |ReservationMgr(2,100,103,1) |Cdcc(2,100,212,391) |2,100,13,578.992^192.168.20.32^* |[R:N-H:0,N:1,L:0,V:0,Z:0,D:0] CI= 44251768 aCI=44251768 bCI=44251825 ClearType=0 10193048.000 |08:03:31.021 |SdlSig |SsDataInd |awaitingCallResponse |Forwarding(2,100,192,134) |ForwardManager(2,100,193,1) |2,100,13,578.992^192.168.20.32^* |[R:N-H:0,N:2,L:0,V:0,Z:0,D:0] SsType=33554438 SsKey=0 SsNode=2 SsParty=44251825 DevId=(0,0,0) BCC=7 OtherParty=44251768 NodeOtherParty=2 clearType = 0 CSS=:2c8cf414-5250-5ef6-1c7e-92b2c99f28bb CNumInfo = 0 CNameInfo = 0 ssDevType=4 ssOtherDevType=4 FDataType=0opId=0ssType=0 SsKey=0invokeId=0resultExp=Fbpda=F ssCause = 0 ssUserState = 4 ssOtherUserState = 4 PL=5 PLDmn=0 networkDomain= delayAPTimer=F geolocInfo={geolocPkid=, filterPkid=, geolocVal=, devType=4} cfwdTimerAction=0 matchInterceptPartition= matchInterceptPattern= 10193048.001 |08:03:31.021 |AppInfo |Forwarding - awaitingCallResponse_SsDataInd - BASIC_CALL_RELEASE - Stopping Forwarding on destination Release. party= 44251825, callKey= 0x86 10193048.002 |08:03:31.021 |AppInfo |Forwarding - stopCFNATimer - callKey= 0x86 10193049.000 |08:03:31.021 |SdlSig |CACUnassociateReq |wait |RSVPSession(2,100,100,392) |ReservationMgr(2,100,103,1) |2,100,13,578.992^192.168.20.32^* |[R:N-H:0,N:1,L:0,V:0,Z:0,D:0] CI= 44251768 aCI=44251768 bCI=44251825 ClearType=0 10193050.000 |08:03:31.021 |SdlSig |ForwardStopInd |wait |ForwardManager(2,100,193,1) |Forwarding(2,100,192,134) |2,100,13,578.992^192.168.20.32^* |[R:N-H:0,N:1,L:0,V:0,Z:0,D:0] 10193050.001 |08:03:31.021 |AppInfo |ForwardManager - wait_ForwardStopInd - Stop Forwarding - Pid=(2,192,134), callkey= 0x86 10193050.002 |08:03:31.021 |AppInfo |ForwardManager - removeActiveCallTableEntry - mPartyToActiveCallIndexMap - Removed entry Origparty= 44251768, callkey= 0x86 10193050.003 |08:03:31.021 |AppInfo |ForwardManager - removeActiveCallTableEntry - mForwardActiveCallTable - Removed call entry for Origparty= 44251768, Destparty= 0, callkey= 0x86 10193051.000 |08:03:31.021 |SdlSig |RSVPStopInd |wait |ReservationMgr(2,100,103,1) |RSVPSession(2,100,100,392) |2,100,13,578.992^192.168.20.32^* |[R:N-H:0,N:1,L:0,V:0,Z:0,D:0] 10193052.000 |08:03:31.021 |SdlSig |ForwardStopConf |awaitingStopConfirmation |Forwarding(2,100,192,134) |ForwardManager(2,100,193,1) |2,100,13,578.992^192.168.20.32^* |[R:N-H:0,N:1,L:0,V:0,Z:0,D:0] 10193052.001 |08:03:31.021 |AppInfo |Forwarding - awaitingStopConfirmation_ForwardStopConf - callKey= 0x86 10193052.002 |08:03:31.021 |AppInfo |Forwarding - unregisterRelRejInterceptRequest - callKey= 0x86 10193052.003 |08:03:31.021 |AppInfo |Forwarding - unregisterRelRejInterceptRequest - Unregistered RelRej Intercept- party= 44251768, callKey= 0x86 10193052.004 |08:03:31.021 |AppInfo |Forwarding - cleanupFwdLoopPreventionTables - decrement mFwdLoopPreventionTable[4901:17307f4a-350e-5986-8dfc-1c2708e0ec4e] fwdCount= 0, callKey= 0x86 10193052.005 |08:03:31.021 |AppInfo |Forwarding - cleanupFwdLoopPreventionTables - remove mFwdLoopPreventionTable[4901:17307f4a-350e-5986-8dfc-1c2708e0ec4e], callKey= 0x86 10193052.006 |08:03:31.021 |AppInfo |Forwarding - cleanupFwdLoopPreventionTables - remove mFwdToTable, callKey= 0x86 10193052.007 |08:03:31.021 |Stopping | | |Forwarding(2,100,192,134) |Forwarding(2,100,192,134) | |NumOfCurrentInstances: 1 10193053.000 |08:03:31.021 |SdlSig |RSVPStopConf |wait |RSVPSession(2,100,100,392) |ReservationMgr(2,100,103,1) |2,100,13,578.992^192.168.20.32^* |[R:N-H:0,N:1,L:0,V:0,Z:0,D:0] 10193053.001 |08:03:31.021 |Stopping | | |RSVPSession(2,100,100,392) |RSVPSession(2,100,100,392) | |NumOfCurrentInstances: 1 10193054.000 |08:03:31.021 |SdlSig |SsUnregisterRelRejInterceptReq |wait |Cc(2,100,213,1) |Forwarding(2,100,192,134) |2,100,13,578.992^192.168.20.32^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] SsType=33554438 SsKey=0 SsNode=2 SsParty=44251768 handler=0 10193055.000 |08:03:31.021 |SdlSig |SsUnregisterRelRejInterceptReq |await_stop_timer_expiry |Cdcc(2,100,212,391) |Cc(2,100,213,1) |2,100,13,578.992^192.168.20.32^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] SsType=33554438 SsKey=0 SsNode=2 SsParty=44251768 handler=0 10193055.001 |08:03:31.021 |AppInfo |remove an entry from release intercept queue given ssType 10193056.000 |08:03:31.021 |SdlSig |CACUnregisterReq |active |LBMInterface(2,100,169,1) |ReservationMgr(2,100,103,1) |2,100,13,578.992^192.168.20.32^* |[T:N-H:0,N:1,L:0,V:0,Z:0,D:0] CI= 44251825 ClearType=0 10193056.001 |08:03:31.022 |AppInfo |LBMIF: CI: 44251825 UNREG 2,100,75,1403 dev 0xb6e5fce0 10193057.000 |08:03:31.022 |SdlSig |SNFNotifyInd |initialized |SubscriptionManager(2,100,55,1) |LineControl(2,100,167,217) |2,100,13,578.992^192.168.20.32^* |[T:N-H:0,N:0,L:0,V:0,Z:0,D:0] SNFSubscriptionId = 2|0|20, SNFNotifyMsg: state = 0, reason = 0, retryAfter = -1, subscriptionType = REGISTRATION BUSY_AVAILABLE_IDLE , content = SNFLegacyContent with content data set to: idle, cepn = 8c3deb6d-a503-8513-4601-7d77a85ce60b, mSubscribeePid = (2,167,217) 10193057.001 |08:03:31.022 |AppInfo |SMDMSharedData::findSubscriptionIdExistsInSubscribeeState - SubscriptionId=2|0|20 found 10193057.002 |08:03:31.022 |AppInfo |SMDMSharedData::updateSubscribeeStateAndNotify - updated state entry for outSubId = 2|0|20, NotifyMsg = SNFNotifyMsg: state = 0, reason = 0, retryAfter = -1, subscriptionType = REGISTRATION BUSY_AVAILABLE_IDLE , content = SNFLegacyContent with content data set to: idle, cepn = 8c3deb6d-a503-8513-4601-7d77a85ce60b, mSubscribeePid = (2,167,217) , and sent notify to subscribers 10193058.000 |08:03:31.022 |SdlSig |SNFNotifyReq |idle |RoutePlanManager(2,100,80,1) |SubscriptionManager(2,100,55,1) |2,100,13,578.992^192.168.20.32^* |[R:N-H:0,N:1,L:0,V:0,Z:0,D:0] SNFSubscriptionId = 2|0|20, SNFNotifyMsg: state = 0, reason = 0, retryAfter = -1, subscriptionType = REGISTRATION BUSY_AVAILABLE_IDLE , content = SNFLegacyContent with content data set to: idle, cepn = 8c3deb6d-a503-8513-4601-7d77a85ce60b, mSubscribeePid = (2,167,217) 10193059.000 |08:03:31.022 |SdlSig-O |SNFNotifyReq |NA RemoteSignal |SubscriptionManager(3,100,55,1) |SubscriptionManager(2,100,55,1) |2,100,13,578.992^192.168.20.32^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] SNFSubscriptionId = 3|0|22, SNFNotifyMsg: state = 0, reason = 0, retryAfter = -1, subscriptionType = REGISTRATION BUSY_AVAILABLE_IDLE , content = SNFLegacyContent with content data set to: idle, cepn = 8c3deb6d-a503-8513-4601-7d77a85ce60b, mSubscribeePid = (2,167,217) 10193060.000 |08:03:31.022 |SdlSig |CACUnassociateReq |active |LBMInterface(2,100,169,1) |ReservationMgr(2,100,103,1) |2,100,13,578.992^192.168.20.32^* |[T:N-H:0,N:0,L:0,V:0,Z:0,D:0] CI= 44251768 aCI=44251768 bCI=44251825 ClearType=0 10193060.001 |08:03:31.022 |AppInfo |LBMIF: CI: 44251768 UNASSOC 44251825 10193060.002 |08:03:31.022 |AppInfo |LBMIF: CI: 44251768 STOPPED 10193060.003 |08:03:31.022 |AppInfo |LBMIF: CI: 44251825 UNASSOC' 44251768 10193060.004 |08:03:31.022 |AppInfo |LBMIF: CI: 44251825 STOPPED 10193061.000 |08:03:31.022 |SdlSig |LBMStopInd |wait |ReservationMgr(2,100,103,1) |LBMInterface(2,100,169,1) |2,100,13,578.992^192.168.20.32^* |[R:N-H:0,N:1,L:0,V:0,Z:0,D:0] CI= 44251768 CI= 0 10193062.000 |08:03:31.022 |SdlSig |LBMStopInd |wait |ReservationMgr(2,100,103,1) |LBMInterface(2,100,169,1) |2,100,13,578.992^192.168.20.32^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] CI= 44251825 CI= 0 10193063.000 |08:03:31.062 |SdlSig |SdlReadRsp |wait |SIPTcp(2,100,64,1) |SdlTCPConnection(2,100,13,578) |2,100,13,578.993^192.168.20.32^* |*TraceFlagOverrode 10193063.001 |08:03:31.062 |AppInfo |SIPTcp - SdlRead bufferLen=709 10193063.002 |08:03:31.062 |AppInfo |SIPTcp - wait_SdlReadRsp: Incoming SIP TCP message from 192.168.20.32 on port 49409 index 13184 with 709 bytes: [1115470,NET] SIP/2.0 487 Request Cancelled Via: SIP/2.0/TCP 192.168.10.8:5060;branch=z9hG4bK1dfc5126d9faf From: ;tag=454873~946f5a50-7410-423d-a5bb-36fb6cd3f0d0-44251825 To: ;tag=c07bbca0e1875b0b7194bd98-2333ba4b Call-ID: d2213200-5e61acdd-1dc2c-80aa8c0@192.168.10.8 Date: Wed, 02 Sep 2015 08:03:27 GMT CSeq: 101 INVITE Server: Cisco-CP9951/9.4.2 Contact: Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE,INFO Remote-Party-ID: "4901" ;party=called;id-type=subscriber;privacy=off;screen=yes Allow-Events: kpml,dialog Content-Length: 0 10193063.003 |08:03:31.062 |AppInfo |SIPTcp - SignalCounter = 337379 10193064.000 |08:03:31.063 |SdlSig |SIPSPISignal |wait |SIPHandler(2,100,72,1) |SIPTcp(2,100,64,1) |2,100,13,578.993^192.168.20.32^* |*TraceFlagOverrode 10193064.001 |08:03:31.063 |AppInfo |//SIP/Stack/Info/0x0/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 (SIP_NETWORK_MSG), for event 1 (SIPSPI_EV_NEW_MESSAGE) 10193064.002 |08:03:31.063 |AppInfo |//SIP/Stack/Transport/0x0/sipTransportProcessNWNewConnMsg: context=(nil) 10193064.003 |08:03:31.063 |AppInfo |//SIP/Stack/Transport/0x0/sipConnectionManagerProcessNewConnMsg: gConnTab=0xf553560, addr=192.168.20.32, port=49409, connid=13184, transport=TCP 10193064.004 |08:03:31.063 |AppInfo |//SIP/Stack/Info/0x0/sipHolderGetConnInstance: Return existing connection for port 49409 connId 13184 10193064.005 |08:03:31.063 |AppInfo |//SIP/Stack/Info/0x102231f8/sipSPICheckResponseExt: INVITE response with no RSEQ - disable IS_REL1XX 10193064.006 |08:03:31.063 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/sip_stop_timer: type=SIP_TIMER_EXPIRES value=300000 retries=0 10193064.007 |08:03:31.063 |AppInfo |//SIP/Stack/Transport/0x102231f8/sipSPISendAck: Sending ACK to the transport layer 10193064.008 |08:03:31.063 |AppInfo |//SIP/Stack/Transport/0x102231f8/sipSPITransportSendMessage: msg=0xb6eb0ae8, addr=192.168.20.32, port=49409, sentBy_port=0, is_req=1, transp 10193064.009 |08:03:31.063 |AppInfo |//SIP/Stack/Transport/0x0/sipInstanceGetConnectionId: gcb=0x102231f8 is already on connection=0xfe2df08 context_list 10193064.010 |08:03:31.063 |AppInfo |//SIP/Stack/Transport/0x102231f8/sipTransportLogicSendMsg: Set to send the msg=0xb6eb0ae8 10193064.011 |08:03:31.063 |AppInfo |//SIP/Stack/Transport/0x102231f8/sipTransportPostSendMessage: Posting send for msg=0xb6eb0ae8, addr=192.168.20.32, port=49409, connId=13184 for T 10193064.012 |08:03:31.063 |AppInfo |//SIP/Stack/Info/0x102231f8/sentErrorResponseCallClose: Sent Error Response since the Gw is Shutdown 10193064.013 |08:03:31.063 |AppInfo |//SIP/Stack/States/0x102231f8/sipSPIChangeState: 0x102231f8 : State change from (STATE_DISCONNECTING, SUBSTATE_NONE) to (STATE_DEAD, SUBSTATE_NONE) 10193064.014 |08:03:31.063 |AppInfo |//SIP/Stack/Info/0x102231f8/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be 10193064.015 |08:03:31.063 |AppInfo |//SIP/Stack/Transport/0x0/sipConnectionManagerUnregisterCtxtInCon: gConnTab=0xf553560, addr=192.168.20.32, port=49409, unregistering context= 10193064.016 |08:03:31.063 |AppInfo |//SIP/Stack/Info/0x102231f8/sipSPIUfreeOneCCB: Freeing ccb 102231f8 10193064.017 |08:03:31.063 |AppInfo |//SIP/Stack/Transport/0x0/sipSPITransportSendMessage: gcb has cleanedup, Done with send operations for this context 10193065.000 |08:03:31.063 |SdlSig |SIPSPISignal |wait |SIPTcp(2,100,64,1) |SIPHandler(2,100,72,1) |2,100,13,578.993^192.168.20.32^* |*TraceFlagOverrode 10193065.001 |08:03:31.063 |AppInfo |SIPTcp - wait_SdlSPISignal: Outgoing SIP TCP message to 192.168.20.32 on port 49409 index 13184 [1115471,NET] ACK sip:8c3deb6d-a503-8513-4601-7d77a85ce60b@192.168.20.32:49409;transport=tcp SIP/2.0 Via: SIP/2.0/TCP 192.168.10.8:5060;branch=z9hG4bK1dfc5126d9faf From: ;tag=454873~946f5a50-7410-423d-a5bb-36fb6cd3f0d0-44251825 To: ;tag=c07bbca0e1875b0b7194bd98-2333ba4b Date: Wed, 02 Sep 2015 08:01:33 GMT Call-ID: d2213200-5e61acdd-1dc2c-80aa8c0@192.168.10.8 Max-Forwards: 70 CSeq: 101 ACK Allow-Events: presence, kpml Content-Length: 0 10193066.000 |08:03:31.914 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10193067.000 |08:03:32.019 |SdlSig |SIPTimer |wait |SIPHandler(2,100,72,1) |SdlTimerService(2,100,3,1) |2,100,238,1.109327^192.168.10.4^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] TimerType=SIP_TIMER_REMOVE_TRANSACTION value=32000 numRetries=0 10193068.000 |08:03:32.019 |SdlStat |Period: 6s #Lines: 316 #Bytes: 74501 Total Number of Buffers: 10000 Free LWM: 9890 Free LWM(total): 9305 10193067.001 |08:03:32.019 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/wait_SIPTimer: TimerExpired type=SIP_TIMER_REMOVE_TRANSACTION value=32000 retries=0 10193067.002 |08:03:32.019 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/sip_stop_timer: type=SIP_TIMER_REMOVE_TRANSACTION value=32000 retries=0 10193067.003 |08:03:32.019 |AppInfo |//SIP/Stack/Info/0x102085f8/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be 10193067.004 |08:03:32.019 |AppInfo |//SIP/Stack/Transport/0x0/sipConnectionManagerUnregisterCtxtInCon: gConnTab=0xf5535a0, addr=192.168.10.4, port=5060, unregistering context= 10193067.005 |08:03:32.019 |AppInfo |//SIP/Stack/Error/0x0/sipConnectionManagerUnregisterCtxtInCon: Could not find conn holder for addr=192.168.10.4 10193067.006 |08:03:32.019 |AppInfo |//SIP/Stack/Transport/0x102085f8/sipSPITransportContextCleanup: Could not purge context gcb=0x102085f8 from the connection; gcb 10193067.007 |08:03:32.019 |AppInfo |//SIP/Stack/Info/0x102085f8/sipSPIUfreeOneCCB: Freeing ccb 102085f8 10193069.000 |08:03:32.931 |SdlSig |DbObjectCacheTimer |initialized |Db(2,100,202,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:H-H:0,N:0,L:0,V:0,Z:0,D:0] AppCorr: 0 10193070.000 |08:03:33.582 |SdlSig |CdrFileTimer |wait |EnvProcessCdr(2,100,239,1) |SdlTimerService(2,100,3,1) |2,100,139,1.1^*^* |[T:N-H:0,N:0,L:0,V:0,Z:0,D:0] 10193070.001 |08:03:33.582 |AppInfo |EnvProcessCdr::wait_CdrFileTimer