Hi,

SIP server keeps on sending Ringing event to SBC and Music is not playing in SIP log I could see "music service failed" before EventTreatmentNotApplied.

SIP server log:

12:01:43.771 Trc 04541 RequestApplyTreatment received from [1436] (00000029 URServer xx.xx.xx.xx:38730)
message RequestApplyTreatment
AttributeThisDN '2288'
AttributeConnID 00010331e72c3005
AttributeTreatmentType 8 (TreatmentPlayAnnouncementAndDigits)
AttributeTreatmentParms [360] 00 05 01 00..
'MAX_DIGITS' 1
'START_TIMEOUT' 5
'DIGIT_TIMEOUT' 5
'TOTAL_TIMEOUT' 37
'PROMPT'(list) '1'(list) 'INTERRUPTABLE' 1
'ID' 1005148
'2'(list) 'INTERRUPTABLE' 1
'ID' 1005149
'3'(list) 'INTERRUPTABLE' 1
'ID' 3005148
'4'(list) 'INTERRUPTABLE' 1
'ID' 3005149
'5'(list) 'INTERRUPTABLE' 1
'ID' 2005148
'6'(list) 'INTERRUPTABLE' 1
'ID' 2005149
AttributeReferenceID 60
12:01:43.771 Int 04543 Interaction message "RequestApplyTreatment" received from 1436 ("URServer")
12:01:43.771 -- created: CRequest@d59f06e0 RequestApplyTreatment-URServer[1436]/60
12:01:43.771: $+TLIB:CTI:Unknown:0:27
12:01:43.771 +++ CIFace::Request +++
-- new invoke
-- thisCall by party
Parsed: RequestApplyTreatment
From: URServer[1436]/60
Numbers: +<2288> -<none>
Calls: d7582600:1 none
Parties: 2288.d78df6a0-d7582600:1
none
Status: parsed:1 queued:0 sent:0 acked:0 preevent:0 event:0 context:0 transferred:0
-----
-- validate
-- state check: ok
CIFace: Sent CRequest@d59f06e0 RequestApplyTreatment-URServer[1436]/60
FinishRequest CRequest@d59f06e0 RequestApplyTreatment-URServer[1436]/60
IFace stats: q=0 s=0
-- complete
12:01:43.771: RID:CUUID>60:D30F13DFNH72R5G55VTGNUV64G000005:
12:01:43.771: Selected for Dn (geo-loc[]:partitionId[SipServerDefaultPartition]:cpdCapability[]): Service MSML_TRT (geo-loc[], priority[0], capacity 0 (0% of 0))
12:01:43.771: GSProxyRegistar: Round robin slot selected for [MSML_TRT]
12:01:43.771: Assocaited transport for the device [3087] changed from [:0:0] to [xx.xx.xx.xx:5060:2]
12:01:43.771: Assocaited transport returned from device [3087] [xx.xx.xx.xx:5060:2]
12:01:43.771 SIPCONN(MSML_TRT): set monitor 00000000d724d190, 00000000d7561a90
12:01:43.771: Sc(784):step 0, Tr(785,SipTransactionConnectMediaService) - begin
12:01:43.771 SIPCONN(+46xxxxxxxxx): re-invite-called-initiated
12:01:43.771 SIPCONN(+46xxxxxxxxx): SIPCONN(00000000d751e950,B6R8F50T3T10T7DGMFJN3GBF1800000D) +Tr(785,SipTransactionConnectMediaService)
12:01:43.771 SIPCONN(MSML_TRT): re-invite-null
12:01:43.771 SIPCONN(MSML_TRT): SIPCONN(00000000d724d190,B6R8F50T3T10T7DGMFJN3GBF1800000E) +Tr(785,SipTransactionConnectMediaService)
12:01:43.771 SIPCONN(+46xxxxxxxxx): GetOffer
12:01:43.771 SIPCONN(+46xxxxxxxxx): GetOffer::ReturnOffer
12:01:43.771 SIPCONN(+46xxxxxxxxx): NotifyOnOffer
12:01:43.771 SIPCONN(MSML_TRT): SendOffer
12:01:43.771 SIPCONN(MSML_TRT): re-invite-null
12:01:43.771 SIPCONN(MSML_TRT): SendOffer::Invite
12:01:43.771: SipDialog: set monitor 00000000d724d248
12:01:43.771 SIPCONN(MSML_TRT): main dialog 0 created, flags 0x200021f
Session value of the SDP is [1423868433]
Version values of the SDP is [1719436089]
12:01:43.771 SIPCONN(MSML_TRT): Local contact: '<sip:+46xxxxxxxxx@SRV74xxx:11000;transport=tcp>'
12:01:43.771: Assocaited transport for the device [3087] changed from [xx.xx.xx.xx:5060:2] to [xx.xx.xx.xx:5060:2]
12:01:43.771: Assocaited transport returned from device [3087] [xx.xx.xx.xx:5060:2]
12:01:43.771: HA:MESSAGE:TYPE[sipStackSync] NOT SYNCED
12:01:43.771: SIPDLG[2359]: register TRN[60915]
12:01:43.771: SIPDLG[2359]: TRN[60915] flags set to 0x6
12:01:43.771: ERROR: ffffffff, InitiateDialog(requestUri,*device, from, to, content, extraHeaders, false), SipConnection.cpp,4758
12:01:43.771: ERROR: ffffffff, SendInvite(m_localContent,flags), SipConnectionConnect.cpp,734
12:01:43.771: ConnectAbort: state:2
12:01:43.771 SIPCONN(+46xxxxxxxxx): SIPCONN(00000000d751e950,B6R8F50T3T10T7DGMFJN3GBF1800000D) -Tr(785,SipTransactionConnectMediaService)
12:01:43.771 SIPCONN(MSML_TRT): SIPCONN(00000000d724d190,B6R8F50T3T10T7DGMFJN3GBF1800000E) -Tr(785,SipTransactionConnectMediaService)
12:01:43.771 SIPCONN(+46xxxxxxxxx): ClrMediaPeer
12:01:43.771 SIPCONN(MSML_TRT): ClrMediaPeer
12:01:43.771: music service failed
12:01:43.771 SIPCONN(MSML_TRT): ClrMediaPeer
12:01:43.771: SIPTS: HandleMediaServiceFailed
12:01:43.771: SIPTS: SendTreatmentApplied
12:01:43.771: Adding OtherTrunkName(Elion_Trunk): done
-- thisCall by party
SetContext: for party 2288.d78df6a0-d7582600:1
+++ CIFace::Event +++
+++ Pre-event +++
Type EventTreatmentNotApplied
Devices: <2288/2288> <-/-> <-/->
Calls: 16778221/00010331e72c3005/16778221.d7582600/c:2/r:1 0/none
Parties: D2288/2288.d78df6a0-d7582600:1/l:2/r:1/Queued,RtRequest,Destination
none
none
Cause: Null/0, Info: 50
Flags: divert=0 hook=0 postCall=0 active=1 moveAll=1 callType=1 hideOtherPi=0 InternalOther=0
--- Pre-event ---
+++ TreatmentError +++
@12:01:43.7710 [0] 8.1.104.34 distribute_response: message EventTreatmentNotApplied
AttributeEventSequenceNumber 0000000000001178
AttributeTimeinuSecs 771000
AttributeTimeinSecs 1646650903 (12:01:43)
AttributeTreatmentParms [360] 00 05 01 00..
'MAX_DIGITS' 1
'START_TIMEOUT' 5
'DIGIT_TIMEOUT' 5
'TOTAL_TIMEOUT' 37
'PROMPT'(list) '1'(list) 'INTERRUPTABLE' 1
'ID' 1005148
'2'(list) 'INTERRUPTABLE' 1
'ID' 1005149
'3'(list) 'INTERRUPTABLE' 1
'ID' 3005148
'4'(list) 'INTERRUPTABLE' 1
'ID' 3005149
'5'(list) 'INTERRUPTABLE' 1
'ID' 2005148
'6'(list) 'INTERRUPTABLE' 1
'ID' 2005149
AttributeExtensions [53] 00 02 00 00..
'OtherTrunkName' 'Elion_Trunk'
'BusinessCall' 1
AttributeReferenceID 60
AttributeErrorCode 50
AttributeErrorMessage 'Unspecified error'
AttributeTreatmentType 8 (TreatmentPlayAnnouncementAndDigits)
AttributePartyUUID '7KO7DODIFL3OJ3J5OC20PC9B7K00012O'
AttributeThisQueue '2288'
AttributeThisDNRole 2
AttributeThisDN '2288'
AttributeCustomerID 'Environment'
AttributeANI '+46xxxxxxxxx'
AttributeDNIS '+46xxxxxxxx'
AttributeUserData [185] 00 07 00 00..
'PersonalIDnumber' 'Unknown_+46xxxxxxxxx'
'Skype' 'Unknown'
'MediaType' 'voice'
'CCPhoneNumber' '2288'
'_transferDest' '2288'
'CustomersPhoneNumber' '46xxxxxxxxx'
'Authentication Result' ''
AttributeCallUUID 'D30F13DFNH72R5G55VTGNUV64G000005'
AttributeConnID 00010331e72c3005
AttributeCallID 16778221
AttributePropagatedCallType 2
AttributeCallType 2
AttributeCallState 0
12:01:43.771 Int 04544 Interaction message "EventTreatmentNotApplied" generated
12:01:43.771 Trc 04542 EventTreatmentNotApplied sent to [1436] (00000029 URServer 10.39.35.32:38730)
12:01:43.771 Trc 04542 EventTreatmentNotApplied sent to [1460] (0000002a URServer_HA 10.39.35.34:36218)
12:01:43.771 Trc 04542 EventTreatmentNotApplied sent to [1440] (00000028 Stat_Server_ERS_HA 10.39.35.31:59277)
12:01:43.771 Trc 04542 EventTreatmentNotApplied sent to [1672] (00000027 Stat_Server_ERS 10.39.34.58:41863)
12:01:43.771 Trc 04542 EventTreatmentNotApplied sent to [1560] (00000026 Stat_Server_CCP_HA 10.39.35.31:56929)
12:01:43.771 Trc 04542 EventTreatmentNotApplied sent to [1580] (00000025 Stat_Server_CCP 10.39.34.58:54862)
12:01:43.771 Trc 04542 EventTreatmentNotApplied sent to [1684] (00000024 Stat_Server_CCA_HA 10.39.35.31:35896)
12:01:43.771 Trc 04542 EventTreatmentNotApplied sent to [948] (00000023 Stat_Server_CCA 10.39.34.58:40418)
--- TreatmentError ---
+++ Post-event +++
Type EventTreatmentNotApplied
Devices: <2288/2288> <-/-> <-/->
Calls: 16778221/00010331e72c3005/16778221.d7582600/c:2/r:1 0/none
Parties: D2288/2288.d78df6a0-d7582600:1/l:2/r:1/Queued,RtRequest,Destination
none
none
Cause: Null/0, Info: 50
Flags: divert=0 hook=0 postCall=0 active=1 moveAll=1 callType=1 hideOtherPi=0 InternalOther=0
--- Post-event ---
--- CIFace::Event ---
12:01:43.771 SIPCONN(MSML_TRT): Active transaction(60915) discarded
12:01:43.771: SipDialog: ClearCall(phone=0,state=0, reject[set:0;conf:603])
12:01:43.771: SipDialog::Terminate(state=0,reason=0)
12:01:43.771: SipDialog: set monitor 0000000000000000
12:01:43.771 SIPCONN(MSML_TRT): DetachMediaPeer
12:01:43.771 SIPCONN(+46xxxxxxxxx): re-invite-called-initiated
12:01:43.771 SIPCONN(+46xxxxxxxxx): SIPCONN(00000000d751e950,B6R8F50T3T10T7DGMFJN3GBF1800000D) +Tr(785,SipTransactionConnectMediaService)
12:01:43.771 SIPCONN(+46xxxxxxxxx): park-initiated
12:01:43.771 SIPCONN(+46xxxxxxxxx): SIPCONN(00000000d751e950,B6R8F50T3T10T7DGMFJN3GBF1800000D) -Tr(785,SipTransactionConnectMediaService)
12:01:43.771: MediaService type 3 does not have associated connection.
12:01:43.771: Tr(785,SipTransactionConnectMediaService):completed
12:01:43.771: Sc(784):step 0, Tr(785,SipTransactionConnectMediaService) - completed
12:01:43.771: Sc(784):step 1, Tr(786,SipTransactionProcessMsml) - begin
12:01:43.771: Sc(784):step 1, Tr(786,SipTransactionProcessMsml) - failed
12:01:43.771: Tr(784,SipScenario):failed
12:01:43.771: SIPCM: transaction Tr(784,SipScenario) failed
12:01:43.771: PI-1: 00 S[IN]D[+46xxxxxxxxx]C[*D[+46xxxxxxxxx]]P[-]
12:01:43.771: PI-1: 00 S[QN]D[2288]E[-]
12:01:43.771: SipCallManager::OnTransactionFailure: Internal context, doesn't notify
12:01:43.771: OnRequestFailed
-- thisCall by party
12:01:43.771: call1 16778221 idle
12:01:43.771: free_dcr 00000000d780c770
12:01:43.771 --- CIFace::Request ---
12:01:43.771: $-TLIB:CTI:Unknown:0:1448


RM Log:
2022-03-07 12:01:01.255 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1472 2 ProcessTimerEvent:m_nClientSocketState=2 m_nClientSocket=38429952 m_nServerSocketState=0 m_nServerSocket=0 m_bFailureReported=1
2022-03-07T12:01:02.252 Std 20003 WARN 00000000-00000000 13120 08500000 VGSocket::NotifySocketError nErrorCode 10060
2022-03-07 12:01:02.252 DBUG 00000000-00000000 13120 09400901 RMCommTCPBonding.cxx:1025 208792208 VGSocketError nSocket=38429952
2022-03-07 12:01:02.252 DBUG 00000000-00000000 13120 09400901 RMCommTCPBonding.cxx:929 208792208 VGSocketClosed nSocket=38429952
2022-03-07T12:01:02.252 Std 20070 WARN 00000000-00000000 13120 09400304 Client socket 38429952 is closed. Hence cleaned all the socket message buffer
2022-03-07 12:01:02.525 DBUG 00000000-00000000 13128 09400901 DataModule.cxx:3843 Datamodule 1da7e670: Convert Subscription data to string and send to remote node:
2022-03-07 12:01:02.525 DBUG 00000000-00000000 9596 09400901 RMServiceMgrCCPProxy.cxx:397 ProcessEvent
2022-03-07 12:01:02.525 DBUG 00000000-00000000 9596 09400901 RMServiceMgrBase.cxx:152 SendMessageToAllRemote()
2022-03-07 12:01:02.525 DBUG 00000000-00000000 9596 09400901 RMClusterMgr.cxx:318 CMClusterMgr::SendMessageMultiple( mask=0x0, len=311 )
2022-03-07 12:01:03.258 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1308 208792208 ProcessTimerEvent
2022-03-07 12:01:03.258 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1387 208792208 ProcessTimerEvent: m_nTotalNodes=0 bNetworkUp=1
2022-03-07 12:01:03.258 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1465 208792208 ProcessTimerEvent: Server 2
2022-03-07 12:01:03.258 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1472 2 ProcessTimerEvent:m_nClientSocketState=4 m_nClientSocket=0 m_nServerSocketState=0 m_nServerSocket=0 m_bFailureReported=1
2022-03-07 12:01:03.258 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:337 208792208 Connect nServerId=2
2022-03-07 12:01:03.258 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:366 Setting source local address to xx.xx.xx.xx
2022-03-07 12:01:03.258 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:449 208792208 Connect nServerId=2 nSocket=38447392
2022-03-07 12:01:05.261 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1308 208792208 ProcessTimerEvent
2022-03-07 12:01:05.261 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1387 208792208 ProcessTimerEvent: m_nTotalNodes=0 bNetworkUp=1
2022-03-07 12:01:05.261 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1465 208792208 ProcessTimerEvent: Server 2
2022-03-07 12:01:05.261 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1472 2 ProcessTimerEvent:m_nClientSocketState=2 m_nClientSocket=38447392 m_nServerSocketState=0 m_nServerSocket=0 m_bFailureReported=1
2022-03-07 12:01:05.597 DBUG 00000000-00000000 5684 08500000 VGSIPTransportMgr.cxx:3766 VGSIPTransportMgr::ResolveDNS for xx.xx.xx.xx:5070
2022-03-07 12:01:05.597 DBUG 00000000-00000000 5684 08500000 VGSIPTransportMgr.cxx:3883 VGSIPTransportMgr::ResolveDNS nResult 2; CallID<9DEAFDD9-B70D-4690-BC9C-2A6A904628DC-5164@xx.xx.xx.xx>
2022-03-07 12:01:05.597 DBUG 00000000-00000000 5684 08500000 VGSIPTransportMgr.cxx:1858 Not Changing m_nSendState from 0 to SENDSTATE_NONE
2022-03-07 12:01:05.597 DBUG 00000000-00000000 5684 09400901 GVPRMSIPMonitor.cxx:342 Calling Send Options to: sip:xx.xx.xx.xx:5070
2022-03-07 12:01:05.597 DBUG 00000000-00000000 5684 08500000 VGSIPTransportMgr.cxx:3766 VGSIPTransportMgr::ResolveDNS for xx.xx.xx.xx:0
2022-03-07 12:01:05.597 DBUG 00000000-00000000 5684 08500000 VGSIPTransportMgr.cxx:3883 VGSIPTransportMgr::ResolveDNS nResult 2; CallID<D41061F6-0C84-42DC-B5B6-3B7FA486254E-5164@xx.xx.xx.xx>
2022-03-07 12:01:05.597 DBUG 00000000-00000000 5684 08500000 VGSIPTransaction.cxx:781 VGSIPTransaction::NotifyTransactionError, nError -203
2022-03-07 12:01:05.597 DBUG 00000000-00000000 5684 08500000 VGSIPUserAgent.cxx:2595 VGSIPUserAgent::NotifyTransactionError nError -203
2022-03-07 12:01:05.597 DBUG 00000000-00000000 5684 09400901 GVPRMSIPMonitor.cxx:342 Calling Send Options to: sips:xx.xx.xx.xx:0
2022-03-07 12:01:05.597 DBUG 00000000-00000000 5684 09400901 GVPRMSIPMonitor.cxx:388 Changing resource to offline: sips:xx.xx.xx.xx:0
2022-03-07 12:01:05.597 DBUG 00000000-00000000 9380 09400901 GVPRMSIPMonitor.cxx:285 Changing resource to online: sip:xx.xx.xx.xx:5070
2022-03-07 12:01:07.262 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1308 208792208 ProcessTimerEvent
2022-03-07 12:01:07.262 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1387 208792208 ProcessTimerEvent: m_nTotalNodes=0 bNetworkUp=1
2022-03-07 12:01:07.262 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1465 208792208 ProcessTimerEvent: Server 2
2022-03-07 12:01:07.262 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1472 2 ProcessTimerEvent:m_nClientSocketState=2 m_nClientSocket=38447392 m_nServerSocketState=0 m_nServerSocket=0 m_bFailureReported=1
2022-03-07 12:01:07.526 DBUG 00000000-00000000 13128 09400901 DataModule.cxx:3843 Datamodule 1da7e670: Convert Subscription data to string and send to remote node:
2022-03-07 12:01:07.526 DBUG 00000000-00000000 9596 09400901 RMServiceMgrCCPProxy.cxx:397 ProcessEvent
2022-03-07 12:01:07.526 DBUG 00000000-00000000 9596 09400901 RMServiceMgrBase.cxx:152 SendMessageToAllRemote()
2022-03-07 12:01:07.526 DBUG 00000000-00000000 9596 09400901 RMClusterMgr.cxx:318 CMClusterMgr::SendMessageMultiple( mask=0x0, len=311 )
2022-03-07 12:01:09.266 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1308 208792208 ProcessTimerEvent
2022-03-07 12:01:09.266 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1387 208792208 ProcessTimerEvent: m_nTotalNodes=0 bNetworkUp=1
2022-03-07 12:01:09.266 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1465 208792208 ProcessTimerEvent: Server 2
2022-03-07 12:01:09.266 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1472 2 ProcessTimerEvent:m_nClientSocketState=2 m_nClientSocket=38447392 m_nServerSocketState=0 m_nServerSocket=0 m_bFailureReported=1
2022-03-07 12:01:10.600 DBUG 00000000-00000000 5684 08500000 VGSIPTransportMgr.cxx:3766 VGSIPTransportMgr::ResolveDNS for xx.xx.xx.xx:5070
2022-03-07 12:01:10.600 DBUG 00000000-00000000 5684 08500000 VGSIPTransportMgr.cxx:3883 VGSIPTransportMgr::ResolveDNS nResult 2; CallID<42D593BC-90F9-4103-3999-DB29077D5AA5-5164@xx.xx.xx.xx>
2022-03-07 12:01:10.600 DBUG 00000000-00000000 5684 08500000 VGSIPTransportMgr.cxx:1858 Not Changing m_nSendState from 0 to SENDSTATE_NONE
2022-03-07 12:01:10.600 DBUG 00000000-00000000 5684 09400901 GVPRMSIPMonitor.cxx:342 Calling Send Options to: sip:xx.xx.xx.xx:5070
2022-03-07 12:01:10.600 DBUG 00000000-00000000 5684 08500000 VGSIPTransportMgr.cxx:3766 VGSIPTransportMgr::ResolveDNS for xx.xx.xx.xx:0
2022-03-07 12:01:10.600 DBUG 00000000-00000000 5684 08500000 VGSIPTransportMgr.cxx:3883 VGSIPTransportMgr::ResolveDNS nResult 2; CallID<FEB08331-E202-4E9F-4195-6A18C301ED44-5164@xx.xx.xx.xx>
2022-03-07 12:01:10.600 DBUG 00000000-00000000 5684 08500000 VGSIPTransaction.cxx:781 VGSIPTransaction::NotifyTransactionError, nError -203
2022-03-07 12:01:10.600 DBUG 00000000-00000000 5684 08500000 VGSIPUserAgent.cxx:2595 VGSIPUserAgent::NotifyTransactionError nError -203
2022-03-07 12:01:10.600 DBUG 00000000-00000000 5684 09400901 GVPRMSIPMonitor.cxx:342 Calling Send Options to: sips:xx.xx.xx.xx:0
2022-03-07 12:01:10.600 DBUG 00000000-00000000 5684 09400901 GVPRMSIPMonitor.cxx:388 Changing resource to offline: sips:xx.xx.xx.xx:0
2022-03-07 12:01:10.600 DBUG 00000000-00000000 9380 09400901 GVPRMSIPMonitor.cxx:285 Changing resource to online: sip:xx.xx.xx.xx:5070
2022-03-07 12:01:11.268 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1308 208792208 ProcessTimerEvent
2022-03-07 12:01:11.268 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1387 208792208 ProcessTimerEvent: m_nTotalNodes=0 bNetworkUp=1
2022-03-07 12:01:11.268 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1465 208792208 ProcessTimerEvent: Server 2
2022-03-07 12:01:11.268 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1472 2 ProcessTimerEvent:m_nClientSocketState=2 m_nClientSocket=38447392 m_nServerSocketState=0 m_nServerSocket=0 m_bFailureReported=1
2022-03-07 12:01:12.527 DBUG 00000000-00000000 13128 09400901 DataModule.cxx:3843 Datamodule 1da7e670: Convert Subscription data to string and send to remote node:
2022-03-07 12:01:12.527 DBUG 00000000-00000000 9596 09400901 RMServiceMgrCCPProxy.cxx:397 ProcessEvent
2022-03-07 12:01:12.527 DBUG 00000000-00000000 9596 09400901 RMServiceMgrBase.cxx:152 SendMessageToAllRemote()
2022-03-07 12:01:12.527 DBUG 00000000-00000000 9596 09400901 RMClusterMgr.cxx:318 CMClusterMgr::SendMessageMultiple( mask=0x0, len=311 )
2022-03-07 12:01:13.269 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1308 208792208 ProcessTimerEvent
2022-03-07 12:01:13.269 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1387 208792208 ProcessTimerEvent: m_nTotalNodes=0 bNetworkUp=1
2022-03-07 12:01:13.269 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1465 208792208 ProcessTimerEvent: Server 2
2022-03-07 12:01:13.269 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1472 2 ProcessTimerEvent:m_nClientSocketState=2 m_nClientSocket=38447392 m_nServerSocketState=0 m_nServerSocket=0 m_bFailureReported=1
2022-03-07 12:01:15.272 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1308 208792208 ProcessTimerEvent
2022-03-07 12:01:15.272 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1387 208792208 ProcessTimerEvent: m_nTotalNodes=0 bNetworkUp=1
2022-03-07 12:01:15.272 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1465 208792208 ProcessTimerEvent: Server 2
2022-03-07 12:01:15.272 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1472 2 ProcessTimerEvent:m_nClientSocketState=2 m_nClientSocket=38447392 m_nServerSocketState=0 m_nServerSocket=0 m_bFailureReported=1
2022-03-07 12:01:15.602 DBUG 00000000-00000000 5684 08500000 VGSIPTransportMgr.cxx:3766 VGSIPTransportMgr::ResolveDNS for xx.xx.xx.xx:5070
2022-03-07 12:01:15.602 DBUG 00000000-00000000 5684 08500000 VGSIPTransportMgr.cxx:3883 VGSIPTransportMgr::ResolveDNS nResult 2; CallID<749417DF-BF8D-4842-BDAD-32572DB1BC30-5164@xx.xx.xx.xx>
2022-03-07 12:01:15.602 DBUG 00000000-00000000 5684 08500000 VGSIPTransportMgr.cxx:1858 Not Changing m_nSendState from 0 to SENDSTATE_NONE
2022-03-07 12:01:15.602 DBUG 00000000-00000000 5684 09400901 GVPRMSIPMonitor.cxx:342 Calling Send Options to: sip:xx.xx.xx.xx:5070
2022-03-07 12:01:15.602 DBUG 00000000-00000000 5684 08500000 VGSIPTransportMgr.cxx:3766 VGSIPTransportMgr::ResolveDNS for xx.xx.xx.xx:0
2022-03-07 12:01:15.602 DBUG 00000000-00000000 5684 08500000 VGSIPTransportMgr.cxx:3883 VGSIPTransportMgr::ResolveDNS nResult 2; CallID<49BD2B7E-826D-49E5-90AB-0CFBBE414F33-5164@xx.xx.xx.xx>
2022-03-07 12:01:15.602 DBUG 00000000-00000000 5684 08500000 VGSIPTransaction.cxx:781 VGSIPTransaction::NotifyTransactionError, nError -203
2022-03-07 12:01:15.602 DBUG 00000000-00000000 5684 08500000 VGSIPUserAgent.cxx:2595 VGSIPUserAgent::NotifyTransactionError nError -203
2022-03-07 12:01:15.602 DBUG 00000000-00000000 5684 09400901 GVPRMSIPMonitor.cxx:342 Calling Send Options to: sips:xx.xx.xx.xx:0
2022-03-07 12:01:15.602 DBUG 00000000-00000000 5684 09400901 GVPRMSIPMonitor.cxx:388 Changing resource to offline: sips:xx.xx.xx.xx:0
2022-03-07 12:01:15.602 DBUG 00000000-00000000 9380 09400901 GVPRMSIPMonitor.cxx:285 Changing resource to online: sip:xx.xx.xx.xx:5070
2022-03-07 12:01:17.276 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1308 208792208 ProcessTimerEvent
2022-03-07 12:01:17.276 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1387 208792208 ProcessTimerEvent: m_nTotalNodes=0 bNetworkUp=1
2022-03-07 12:01:17.276 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1465 208792208 ProcessTimerEvent: Server 2
2022-03-07 12:01:17.276 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1472 2 ProcessTimerEvent:m_nClientSocketState=2 m_nClientSocket=38447392 m_nServerSocketState=0 m_nServerSocket=0 m_bFailureReported=1
2022-03-07 12:01:17.529 DBUG 00000000-00000000 13128 09400901 DataModule.cxx:3843 Datamodule 1da7e670: Convert Subscription data to string and send to remote node:
2022-03-07 12:01:17.529 DBUG 00000000-00000000 9596 09400901 RMServiceMgrCCPProxy.cxx:397 ProcessEvent
2022-03-07 12:01:17.529 DBUG 00000000-00000000 9596 09400901 RMServiceMgrBase.cxx:152 SendMessageToAllRemote()
2022-03-07 12:01:17.529 DBUG 00000000-00000000 9596 09400901 RMClusterMgr.cxx:318 CMClusterMgr::SendMessageMultiple( mask=0x0, len=311 )
2022-03-07 12:01:19.277 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1308 208792208 ProcessTimerEvent
2022-03-07 12:01:19.277 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1387 208792208 ProcessTimerEvent: m_nTotalNodes=0 bNetworkUp=1
2022-03-07 12:01:19.277 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1465 208792208 ProcessTimerEvent: Server 2
2022-03-07 12:01:19.277 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1472 2 ProcessTimerEvent:m_nClientSocketState=2 m_nClientSocket=38447392 m_nServerSocketState=0 m_nServerSocket=0 m_bFailureReported=1
2022-03-07 12:01:20.604 DBUG 00000000-00000000 5684 08500000 VGSIPTransportMgr.cxx:3766 VGSIPTransportMgr::ResolveDNS for xx.xx.xx.xx:5070
2022-03-07 12:01:20.604 DBUG 00000000-00000000 5684 08500000 VGSIPTransportMgr.cxx:3883 VGSIPTransportMgr::ResolveDNS nResult 2; CallID<C389B0B6-43DC-49D4-F392-ECED94AFAEC2-5164@xx.xx.xx.xx>
2022-03-07 12:01:20.604 DBUG 00000000-00000000 5684 08500000 VGSIPTransportMgr.cxx:1858 Not Changing m_nSendState from 0 to SENDSTATE_NONE
2022-03-07 12:01:20.604 DBUG 00000000-00000000 5684 09400901 GVPRMSIPMonitor.cxx:342 Calling Send Options to: sip:xx.xx.xx.xx:5070
2022-03-07 12:01:20.604 DBUG 00000000-00000000 5684 08500000 VGSIPTransportMgr.cxx:3766 VGSIPTransportMgr::ResolveDNS for xx.xx.xx.xx:0
2022-03-07 12:01:20.604 DBUG 00000000-00000000 5684 08500000 VGSIPTransportMgr.cxx:3883 VGSIPTransportMgr::ResolveDNS nResult 2; CallID<A5FE695D-8079-4F9A-BB88-C94C1164DF37-5164@xx.xx.xx.xx>
2022-03-07 12:01:20.604 DBUG 00000000-00000000 5684 08500000 VGSIPTransaction.cxx:781 VGSIPTransaction::NotifyTransactionError, nError -203
2022-03-07 12:01:20.604 DBUG 00000000-00000000 5684 08500000 VGSIPUserAgent.cxx:2595 VGSIPUserAgent::NotifyTransactionError nError -203
2022-03-07 12:01:20.604 DBUG 00000000-00000000 5684 09400901 GVPRMSIPMonitor.cxx:342 Calling Send Options to: sips:xx.xx.xx.xx:0
2022-03-07 12:01:20.604 DBUG 00000000-00000000 5684 09400901 GVPRMSIPMonitor.cxx:388 Changing resource to offline: sips:xx.xx.xx.xx:0
2022-03-07 12:01:20.604 DBUG 00000000-00000000 9380 09400901 GVPRMSIPMonitor.cxx:285 Changing resource to online: sip:xx.xx.xx.xx:5070
2022-03-07 12:01:21.280 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1308 208792208 ProcessTimerEvent
2022-03-07 12:01:21.280 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1387 208792208 ProcessTimerEvent: m_nTotalNodes=0 bNetworkUp=1
2022-03-07 12:01:21.280 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1465 208792208 ProcessTimerEvent: Server 2
2022-03-07 12:01:21.280 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1472 2 ProcessTimerEvent:m_nClientSocketState=2 m_nClientSocket=38447392 m_nServerSocketState=0 m_nServerSocket=0 m_bFailureReported=1
2022-03-07 12:01:22.530 DBUG 00000000-00000000 13128 09400901 DataModule.cxx:3843 Datamodule 1da7e670: Convert Subscription data to string and send to remote node:
2022-03-07 12:01:22.530 DBUG 00000000-00000000 9596 09400901 RMServiceMgrCCPProxy.cxx:397 ProcessEvent
2022-03-07 12:01:22.530 DBUG 00000000-00000000 9596 09400901 RMServiceMgrBase.cxx:152 SendMessageToAllRemote()
2022-03-07 12:01:22.530 DBUG 00000000-00000000 9596 09400901 RMClusterMgr.cxx:318 CMClusterMgr::SendMessageMultiple( mask=0x0, len=311 )
2022-03-07 12:01:23.283 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1308 208792208 ProcessTimerEvent
2022-03-07 12:01:23.283 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1387 208792208 ProcessTimerEvent: m_nTotalNodes=0 bNetworkUp=1
2022-03-07 12:01:23.283 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1465 208792208 ProcessTimerEvent: Server 2
2022-03-07 12:01:23.283 DBUG 00000000-00000000 7952 09400901 RMCommTCPBonding.cxx:1472 2 ProcessTimerEvent:m_nClientSocketState=2 m_nClientSocket=38447392 m_nServerSocketState=0 m_nServerSocket=0 m_bFailureReported=1
2022-03-07T12:01:24.277 Std 20003 WARN 00000000-00000000 13120 08500000 VGSocket::NotifySocketError nErrorCode 10060
2022-03-07 12:01:24.277 DBUG 00000000-00000000 13120 09400901 RMCommTCPBonding.cxx:1025 208792208 VGSocketError nSocket=38447392
2022-03-07 12:01:24.277 DBUG 00000000-00000000 13120 09400901 RMCommTCPBonding.cxx:929 208792208 VGSocketClosed nSocket=38447392
2022-03-07T12:01:24.277 Std 20070 WARN 00000000-00000000 13120 09400304 Client socket 38447392 is closed. Hence cleaned all the socket message buffer
2022-03-07 12:01:25.285 DBUG