call unobtainable when failover server active

[megaa]

Hi Guys,
the customer has two IPO servers (primary and secondary), when the primery goes down, all of the h.323 extensions are register to the secondary (that's normal). But when an extension tries to call an other one , the call is ringing, but when the called picks up the call, the phone shows "unobtainable".
from the monitor:

15:58:04 639913mS CMCallEvt: c0a8b90c310003f0 446.822084592.0 2 pkaszab.0: StateChange: END=T CMCSRinging->CMCSConnReq
15:58:04 639913mS CMCallEvt: 0000000000000000 0.822084591.0 2 TargetingEP: RequestEnd c0a8b90c310003f0 446.822084592.0 2 pkaszab.0
15:58:04 639913mS CMTARGET: c0a8b90c310003ee 417.822084590.0 2 pkulik.0: CancelTimer CMTCCoverageTimeout
15:58:04 639913mS CMCallEvt: 0000000000000000 0.822084591.0 -1 BaseEP: DELETE CMEndpoint f502b528 TOTAL NOW=2 CALL_LIST=1
15:58:04 639913mS CMExtnEvt: v=98 State, new=Connected old=Ringing,0,0,pkaszab
15:58:04 639914mS CMCallEvt: c0a8b90c310003ee 417.822084590.0 2 pkulik.0: StateChange: END=A CMCSRingBack->CMCSOGConnReq
15:58:04 639914mS CMExtnEvt: v=106 State, new=Connected old=Alerting,0,0,pkulik
15:58:04 639914mS CMExtnTx: v=551, p1=0
CMFacility
Line: type=IPLine 350 Call: lid=446 id=822084592 in=0
Timed: 09/03/24 15:58
15:58:04 639914mS CMExtnTx: v=555, p1=0
CMConnect
Line: type=IPLine 350 Call: lid=417 id=822084590 in=0
IE CMIERespondingPartyName (228)(Type=CMNameInternalUser) name=pkaszab
IE CMIERespondingPartyKName (229)(Type=CMNameDefault) name=Kaszab Péter
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=551
IE CMIEDeviceDetail (231) c0a8b90c310003f0 LOCALE=hun HW=11 VER=11 class=CMDeviceH323Phone type=87 number=98 channel=0 features=0x10000400 rx_gain=32 tx_gain=32
ep_callid=822084592 ipaddr=192.168.185.12 apps=0 loc=0 em_a_loc=0 em_d_loc=0 features2=0x30 is_spcall=0 ignores_dtmf=1
avgsid=<>
Timed: 09/03/24 15:58
15:58:04 639914mS CMExtnRx: v=555, p1=0
CMConnectAck
Line: type=IPLine 350 Call: lid=417 id=822084590 in=0
15:58:04 639914mS CMCallEvt: c0a8b90c310003ee 417.822084590.0 2 pkulik.0: StateChange: END=A CMCSOGConnReq->CMCSConnected
15:58:04 639914mS CMTARGET: c0a8b90c310003ee 417.822084590.0 2 pkulik.0: ~CMTargetHandler f5024208 ep f5022280
15:58:04 639914mS CMCallEvt: c0a8b90c310003f0 446.822084592.0 2 pkaszab.0: StateChange: END=B CMCSConnReq->CMCSConnected
15:58:04 639914mS CMExtnTx: v=551, p1=0
CMConnectAck
Line: type=IPLine 350 Call: lid=446 id=822084592 in=0
IE CMIERespondingPartyName (228)(Type=CMNameInternalUser) name=pkulik
IE CMIERespondingPartyKName (229)(Type=CMNameDefault) name=Kulik Pál
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=555
IE CMIEDeviceDetail (231) c0a8b90c310003ee LOCALE=hun HW=11 VER=11 class=CMDeviceH323Phone type=87 number=69 channel=0 features=0x10000420 rx_gain=32 tx_gain=32
ep_callid=822084590 ipaddr=192.168.185.12 apps=0 loc=0 em_a_loc=0 em_d_loc=0 features2=0x20 is_spcall=0 ignores_dtmf=1
avgsid=<>
Timed: 09/03/24 15:58
15:58:04 639914mS H323Evt: PortmAvayaH323Phone:ortmPhoneDelayFacMsg: 551 - delay disabled
15:58:04 639914mS CMExtnTx: v=551, p1=11298
CMFacility
Line: type=IPLine 350 Call: lid=446 id=98 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
15:58:04 639915mS JadeMapper: Activated media RTP port: 40756, isVMConn: 0 (inUsePorts: 2, activeChannels: 2, freeChannels: 3518)
15:58:04 639915mS CMMap: PCG::MapBChan pcp[7]b0r1 cp_b f50269d8 other_cp_b 0 type CGTypeSimple
15:58:04 639915mS CMMap: PCG::MapBChan pcp[5]b0r1 cp_b f5011dc8 other_cp_b f50269d8 type CGTypeSimple
15:58:04 639915mS JadeMapper: Sending Map B Chan: 0x1 0x1f5 0x1 0x1f4 1 2
15:58:04 639916mS CMMap: PlatformConnectionAudioSAP::ConnectVoice (configure) pcp[5]b0r1 echo_cancellation set to 1
15:58:04 639916mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[5]b0r1 Configure 1.500
15:58:04 639916mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[7]b0r1 Configure 1.501
15:58:04 639916mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[7]b0r1 ConnectIndication 1.501
15:58:04 639916mS JadeRemoteMapper: RTP Relay is 1 on port 40756
15:58:04 639916mS JadeRemoteMapper: RTP Relay is 1 on port 40754
15:58:04 639925mS CMCallEvt: EXPIRY TIMEOUT CALL:2, CMCauseNoChannel
15:58:04 639925mS CMLOGGING: CALL:2024/03/0915:57,00:00:01,004,555,O,551,551,pkulik,,,1,,"",0,n/a
15:58:04 639925mS CMExtnEvt: pkulik: CALL LOST (CMCauseNoChannel)
15:58:04 639925mS CMExtnEvt: pkulik: Extn(555) Calling Party Number(555) Type(CMNTypeInternal)
15:58:04 639925mS CMCallEvt: c0a8b90c310003ee 417.822084590.0 -1 pkulik.0: StateChange: END=X CMCSConnected->CMCSCompletedTone
15:58:04 639925mS CMExtnTx: v=555, p1=0
CMFacility
Line: type=IPLine 350 Call: lid=417 id=822084590 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
Timed: 09/03/24 15:58
15:58:04 639925mS CMExtnTx: v=555, p1=11301
CMFacility
Line: type=IPLine 350 Call: lid=417 id=106 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
15:58:04 639926mS CMExtnTx: v=555, p1=0
CMFacility
Line: type=IPLine 350 Call: lid=417 id=822084590 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
Timed: 09/03/24 15:58
15:58:04 639926mS H323Evt: PortmAvayaH323Phone:ortmPhoneDelayFacMsg: 555 - delay disabled
15:58:04 639926mS CMExtnTx: v=555, p1=11301
CMFacility
Line: type=IPLine 350 Call: lid=417 id=106 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
15:58:04 639926mS CMExtnEvt: v=106 State, new=CMESCompleted old=Connected,0,0,pkulik
15:58:04 639926mS CMExtnEvt: pkaszab: CALL LOST (CMCauseNoChannel)
15:58:04 639926mS CMExtnEvt: pkaszab: Extn(551) Calling Party Number(555) Type(CMNTypeInternal)
15:58:04 639926mS CMCallEvt: c0a8b90c310003f0 446.822084592.0 -1 pkaszab.0: StateChange: END=X CMCSConnected->CMCSCompletedTone
15:58:04 639926mS CMExtnTx: v=551, p1=0
CMFacility
Line: type=IPLine 350 Call: lid=446 id=822084592 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
Timed: 09/03/24 15:58
15:58:04 639926mS CMExtnTx: v=551, p1=11298
CMFacility
Line: type=IPLine 350 Call: lid=446 id=98 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
15:58:04 639926mS CMExtnTx: v=551, p1=0
CMFacility
Line: type=IPLine 350 Call: lid=446 id=822084592 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
Timed: 09/03/24 15:58
15:58:04 639926mS H323Evt: PortmAvayaH323Phone:ortmPhoneDelayFacMsg: 551 - delay disabled
15:58:04 639926mS CMExtnTx: v=551, p1=11298
CMFacility
Line: type=IPLine 350 Call: lid=446 id=98 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
15:58:04 639926mS CMExtnEvt: v=98 State, new=CMESCompleted old=Connected,0,0,pkaszab
15:58:04 639926mS CMCallEvt: END CALL:2 (f502eec0)
15:58:04 639926mS CMMap: PCG::UnmapBChan pcp[5]b0r1 cp_b f5011dc8 other_cp_b f50269d8
15:58:04 639926mS JadeMapper: Sending Map B Chan: 0x1 0x1f5 0x1 0x1f4 0 2
15:58:04 639926mS CMMap: PCG::UnmapBChan pcp[7]b0r1 cp_b f50269d8 other_cp_b 0
15:58:04 639927mS CMMap: PlatformConnectionAudioSAP::ConnectVoice (configure) pcp[5]b0r1 echo_cancellation set to 0
15:58:04 639927mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[5]b0r1 Configure 1.500
15:58:04 639927mS CMMap: PlatformConnectionAudioSAP::ConnectVoice (configure) pcp[7]b0r1 echo_cancellation set to 0
15:58:04 639927mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[7]b0r1 Configure 1.501
15:58:04 639927mS JadeRemoteMapper: RTP Relay is 0 on port 40756
15:58:04 639927mS JadeRemoteMapper: RTP Relay is 0 on port 40754
15:58:05 640259mS H323Evt: Recv: RegistrationRequest 192.168.185.59; Extn(455), time since last RRQ-KA 123000, Endpoints registered: 128; Endpoints in registration: 0
15:58:06 641249mS H323Evt: Recv: RegistrationRequest 192.168.185.90; Extn(301), time since last RRQ-KA 122996, Endpoints registered: 128; Endpoints in registration: 0
15:58:06 641756mS CMExtnTx: v=551, p1=11298
CMFacility
Line: type=IPLine 350 Call: lid=446 id=98 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
15:58:06 641756mS CMExtnRx: v=551, p1=0
CMReleaseComp
Line: type=IPLine 350 Call: lid=446 id=822084592 in=0
15:58:06 641756mS CMCallEvt: c0a8b90c310003f0 446.822084592.0 -1 pkaszab.0: StateChange: END=X CMCSCompletedTone->CMCSCompleted
15:58:06 641756mS CMExtnTx: v=551, p1=0
CMFacility
Line: type=IPLine 350 Call: lid=446 id=822084592 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
Timed: 09/03/24 15:58
15:58:06 641756mS CMExtnEvt: v=98 State, new=PortRecoverDelay old=CMESCompleted,0,0,pkaszab
15:58:06 641756mS CMExtnEvt: pkaszab: CALL LOST (CMCauseForceClear)
15:58:06 641756mS CMExtnEvt: pkaszab: Extn(551) Calling Party Number(555) Type(CMNTypeInternal)
15:58:06 641756mS CMExtnEvt: pkaszab: CMExtnHandler::SetCurrent( id: 822084592->0 )
15:58:06 641756mS CMCallEvt: c0a8b90c310003f0 446.822084592.0 -1 pkaszab.-1: StateChange: END=X CMCSCompleted->CMCSDelete
15:58:06 641756mS CMCallEvt: c0a8b90c310003f0 446.822084592.0 -1 BaseEP: DELETE CMEndpoint f5031478 TOTAL NOW=1 CALL_LIST=0
15:58:06 641757mS JadeMapper: Disabled media RTP port: 40756 (inUsePorts: 2, activeChannels: 1, activeChannelFreed: 1)
15:58:06 641757mS CMMap: a=1.501 b=0.0 Mapper::FreeCodec freed CMRTVocoder(f501e250) resource busy 1, total 3520
15:58:06 641757mS JadeMapper: Deallocated media RTP port: 40756 (inUsePorts: 1, activeChannels: 1, freeChannels: 3519, activeChannelFreed: 0)
15:58:06 641757mS JadeMapper: Media RTP port: 40756 is already freed (inUsePorts: 1, activeChannels: 1, freeChannels: 3519)
15:58:07 642256mS H323Evt: Recv: RegistrationRequest 192.168.185.140; Extn(459), time since last RRQ-KA 123000, Endpoints registered: 128; Endpoints in registration: 0
15:58:08 643257mS H323Evt: Recv: RegistrationRequest 192.168.185.151; Extn(415), time since last RRQ-KA 122997, Endpoints registered: 128; Endpoints in registration: 0
15:58:08 643756mS CMExtnEvt: pkaszab: Recover Timer reason=CMTRWrapUp
15:58:08 643756mS CMExtnEvt: v=98 State, new=Idle old=PortRecoverDelay,0,0,pkaszab
15:58:08 643756mS CMExtnTx: v=551, p1=0
CMVoiceMailStatus
Line: type=IPLine 350 Call: lid=0 id=-1 in=0
Called[pkaszab Msgs=0 Old=0 Sav=0] Type=Default (100) Reason=CMDRdirect Calling[00000000] Type=Default Plan=Default
Display [pkaszab Msgs=0]
Timed: 09/03/24 15:58
15:58:09 644264mS H323Evt: Recv: RegistrationRequest 192.168.185.142; Extn(386), time since last RRQ-KA 122999, Endpoints registered: 128; Endpoints in registration: 0
15:58:09 644810mS CMExtnTx: v=555, p1=11301
CMFacility
Line: type=IPLine 350 Call: lid=417 id=106 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
15:58:09 644810mS CMExtnRx: v=555, p1=0
CMReleaseComp
Line: type=IPLine 350 Call: lid=417 id=822084590 in=0
15:58:09 644811mS CMCallEvt: c0a8b90c310003ee 417.822084590.0 -1 pkulik.0: StateChange: END=X CMCSCompletedTone->CMCSCompleted
15:58:09 644811mS CMExtnTx: v=555, p1=0
CMFacility
Line: type=IPLine 350 Call: lid=417 id=822084590 in=0
IE CMIEFastStartInfoData (6) 2 item(s)

please advice

Thanks

 

[IPOTS]

The secondary server needs to be configured like the primary as far as call routing. Short codes, ARS configuration etc....
Are you using SIP trunks on the Primary or sending them over to an expansion?
If you are using SIP trunk on the primary they don't failover, you need to allocate SIP trunk channels on the secondary as well.

https://ipoffice-techsolutions.com/

 

[megaa]

HI IPOTS,
thank you, but the issue is with the calls between extensions, not with the public network...
There is no need to configure any short codes for extension to extension calls.
but On the other hand, i reserved the SIP trunk licenses on the secondary server..

 

[IPOTS]

I see, the error CMCauseNoChannel is this issue. But this usually related to an external call.
So all the H323 endpoint reregister to the secondary and you cannot dial extension to extension, is that correct?

Are there any expansion involved?

https://ipoffice-techsolutions.com/

 

[megaa]

yes, correct. there are no expansions in the system...
thanks

 

[IPOTS]

What version are you running on? I have never seen this issue. If the phone register then station to station dialing should be working within the same system.

https://ipoffice-techsolutions.com/

 

[megaa]

yes, i have more than 150 installed systems, but i have never met this kind of issue before...
11.1.3.1, but the issue was the same on 11.1.2.4
im thinking about to re-install the secondary server, because it seems to me an RTP/VCM resource issue of the server. The server not able to open the RTP channels..

 

[IPOTS]

Please let us know what the resolve was. I looked a some of my 11.1.3.1 Primary and Secondary configs and don't see anything that would restrict or cause this issue.
As you stated it sounds like a VCM/RTP issue.

https://ipoffice-techsolutions.com/

 

[VinylDave]

Assume you tried disabling direct media on the h323 extensions?

 

[megaa]

VinylDave , yes, disabled