IPO SP2 - Remote worker can't call the voicemail after the primary IPO fails

[UCMen33260]

Hi team,

I deployed 2 IPO Select with the latest release (SP2) (primary and secondary) and an SBCE cluster used only for remote workers.
All is work fine for my remote workers.
But, when the primary IPO fails, remote worker (registered correctly on the secondary IPO) cannot call the voicemail (*17).
I have 200 vmpro ports one the primary IPO, and the voicemail configuration is on "centralized mode ).

The error on tracesbc is:

│SIP/2.0 480 Temporarily Unavailable │
18:39:00.302 │ │Via: SIP/2.0/TLS 10.219.6.93:5061;branch=z9hG4bK-s1632-000273005535-1--s1632- │
18:39:00.302 │ │Record-Route: <sip:10.219.6.93:5061;ipcs-line=4346;lr;transport=tls;subid_ipcs=3174493599> │
18:39:00.302 │ │From: <sip:100@mydomain.com>;tag=d152d106-984f-4fef-902f-d8e9fc15c6c2 │
18:39:00.302 │ │Call-ID: e74169fe-aec6-4643-95dd-0575ec61b458 │
18:39:00.302 │ │CSeq: 3 INVITE │
18:39:00.302 │◄─Te│Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,REFER,NOTIFY,SUBSCRIBE,REGISTER,PUBLISH,UPDATE │
18:39:00.302 │◄──2│Supported: timer,100rel │
18:39:00.302 │────│Server: IP Office 11.0.4.2.0 build 58 │
18:39:00.302 │──IN│Reason: Q.850;cause=34;text="No circuit/channel available" │
18:39:00.302 │◄──T│Content-Length: 0 │
18:39:00.302 │ │To: <sip:*17@mydomain.com>;tag=7d7eb501ac0740c2

And on Monitor logs, it's the same issue, and error code:

7319527mS Sip: 0adb065b0000041a 10004.1050.0 23 test1.0(f62bace8) INVITE Received ep 0adb065b0000041a 10004.1050.0 23 test1.0(f62b3c10), dialog f62bace8
7319527mS Sip: 0adb065b0000041a 10004.1050.0 23 test1.0(f62bace8) LR is On and route is Route: <sip:10.219.6.93:5061;ipcs-line=4016;lr;transport=tls;subid_ipcs=3174493599>
7319527mS Sip: 0adb065b0000041a 10004.1050.0 23 test1.0(f62bace8) UpdateSIPCallState SIPDialog::INITIAL(0) -> SIPDialog::INVITE_RCVD(9)
7319527mS Sip: 0adb065b0000041a 10004.1050.0 23 test1.0(f62bace8) UpdateSDPState SIPDialog::IDLE(0) -> SIPDialog::OFFER_RCVD(2)
7319527mS Sip: 0adb065b0000041a 10004.1050.0 23 test1.0(f62bace8) SdpClone
7319527mS Sip: 0adb065b0000041a 10004.1050.0 23 test1.0(f62bace8) SIPDialog::BuildFastStartFromSDPOffer sdpmsg f7284d10
7319527mS Sip: 0adb065b0000041a 10004.1050.0 23 test1.0(f62bace8) FindConnectionParameters: found bandwidth info, bw_count=1, memorizing only first one
7319528mS Sip: 0adb065b0000041a 10004.1050.0 23 test1.0(f62bace8) SIPDialog::FindConnectionParameters: found media proto <RTP/AVP>
7319528mS Sip: 0adb065b0000041a 10004.1050.0 23 test1.0(f62bace8) BuildFastStartFromSDPOffer: known_stream 1 media_type 0 stream_type 5 allow_stream 1
7319528mS Sip: 0adb065b0000041a 10004.1050.0 23 test1.0(f62bace8) SIPDialog::BuildFastStartFromAudioMediaSDPOffer reinvite 0 mRTP_PType 255 prefer_existing_codec 0
7319528mS Sip: 0adb065b0000041a 10004.1050.0 23 test1.0(f62bace8) FindConnectionParameters: found bandwidth info, bw_count=1, memorizing only first one
7319528mS Sip: 0adb065b0000041a 10004.1050.0 23 test1.0(f62bace8) HandleSDPContext: found_rfc2833 with payload 101
7319528mS Sip: 0adb065b0000041a 10004.1050.0 23 test1.0(f62bace8) SetRfc2833TxPayload: use RFC2833 for dtmf
7319528mS Sip: 0adb065b0000041a 10004.1050.0 23 test1.0(f62bace8) SetRfc2833TxPayload: payload 101 set_rx 1
7319528mS Sip: FindContactParameters mFarDisplayString <> mFarDisplayNumber <100> restricted 0
7319528mS Sip: 0adb065b0000041a 10004.1050.0 23 test1.0(f62bace8) Process SIP request dialog f62bace8, method INVITE in state SIPDialog::INVITE_RCVD(9)
7319528mS Sip: 0adb065b0000041a 10004.1050.0 23 test1.0(f62bace8) UpdateClone mMesg f62af430 smsg f62a7560
7319528mS Sip: 0adb065b0000041a 10004.1050.0 23 test1.0(f62bace8) CMSetup forwarded to call model owner_ep 0adb065b0000041a 10004.1050.0 23 test1.0(f62b3c10), dialog f62bace8 has sdp 1
7319529mS Sip: 0adb065b0000041a 10004.1050.0 -1 test1.0(f62bace8) Terminating dialog f62bace8, state SIPDialog::INVITE_RCVD(9) for cause CMCauseNoChannel
7319529mS Sip: 0adb065b0000041a 10004.1050.0 -1 test1.0(f62bace8) SendSIPResponse: INVITE code 480 SENT TO 10.219.6.93 5061
7319529mS SIP Call Tx: phone
SIP/2.0 480 Temporarily Unavailable
Via: SIP/2.0/TLS 10.219.6.93:5061;branch=z9hG4bK-s1632-000040841991-1--s1632-
Record-Route: <sip:10.219.6.93:5061;ipcs-line=4016;lr;transport=tls;subid_ipcs=3174493599>
From: <sip:100@mydomain.com>;tag=54333172-2ede-4df8-aa90-a3e04c1e64ac
Call-ID: 52ba2706-beb1-4b8d-851d-2d05bb71beae
CSeq: 1 INVITE
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,REFER,NOTIFY,SUBSCRIBE,REGISTER,PUBLISH,UPDATE
Supported: timer,100rel
Server: IP Office 11.0.4.2.0 build 58
Reason: Q.850;cause=34;text="No circuit/channel available"
Content-Length: 0
To: <sip:*17@mydomain.com>;tag=44bd9df81a001b01

someone have the same issue on this IPO release?

Regards

 

[janni78]

You're only showing SIP filters, you should probably do a default trace to see why it can't dial *17.

Assuming this works for local users that failover.

"Trying is the first step to failure..." - Homer

 

[UCMen33260]

It doesn't work for local users too.

 

[janni78]

In that case do a trace with default settings so you'll see what the IP Office is trying to do.

"Trying is the first step to failure..." - Homer

 

[UCMen33260]

Here is the trace with default settings on Monitor:


********** Warning: Logging to Screen Started **********
12:19:38 436997mS SIP Rx: TLS 10.219.6.93:44225 -> 10.219.6.91:5061
INVITE sip:*17@mydomain.com SIP/2.0
From: <sip:100@mydomain.com>;tag=2234eff9-8634-4f97-9c71-4b141101500d
To: <sip:*17@mydomain.com>
CSeq: 1 INVITE
Call-ID: ac2f74f5-2ea2-446a-82ba-95485c18304c
Contact: <sip:100@10.219.6.93:5061;transport=tls;subid_ipcs=3020754252>;+sip.instance="<urn:uuid:a921180a-2271-441d-a8ec-6296383c625a>"
Record-Route: <sip:10.219.6.93:5061;ipcs-line=4872;lr;transport=tls;subid_ipcs=3020754252>
Allow: INVITE,ACK,OPTIONS,BYE,CANCEL,NOTIFY,MESSAGE,REFER,INFO,PUBLISH,UPDATE
Supported: eventlist,outbound,replaces
User-Agent: Avaya Communicator Android/3.7.4 (FA-RELEASE41-BUILD.2; SM-J415FN)
Max-Forwards: 69
Via: SIP/2.0/TLS 10.219.6.93:5061;branch=z9hG4bK-s1632-001881905005-1--s1632-
Accept-Language: fr
Content-Type: application/sdp
P-Conference: OutdialPrompt=false, FeedbackPrompts=false, UCCP=true, Video=true, WebCollaboration=true
Content-Length: 540

v=0
o=sip:100@192.0.0.4 5 2 IN IP4 10.219.6.93
s=-
c=IN IP4 10.219.6.93
b=TIAS:64000
t=0 0
a=activetalker:1
m=audio 40842 RTP/AVP 116 9 8 0 110 18 101
a=sendrecv
a=rtpmap:116 OPUS/48000/2
a=fmtp:116 maxplaybackrate=16000;sprop-maxcapturerate=16000;maxaveragebitrate=20000;stereo=0;sprop-stereo=0;cbr=0;useinbandfec=1;usedtx=0
a=minptime:20
a=maxptime:20
a=rtpmap:9 G722/8000/1
a=rtpmap:8 PCMA/8000/1
a=rtpmap:0 PCMU/8000/1
a=rtpmap:110 G726-32/8000/1
a=rtpmap:18 G729/8000/1
a=rtpmap:101 telephone-event/8000
a=ptime:20
12:19:38 436997mS CMCallEvt: 0000000000000000 0.1020.0 -1 BaseEP: NEW CMEndpoint f60b4c30 TOTAL NOW=1 CALL_LIST=0
12:19:38 436998mS CMCallEvt: 0000000000000000 0.1020.0 -1 test1.-1: NEW CMExtnEndpoint f60b4c30, Name=test1, Extn=100, Phys Extn=100
12:19:38 436998mS CMMap: IP::SetCodec pcp[19]b0r0 0 -> f644ee38
12:19:38 436998mS CMCallEvt: CREATE CALL:10 (f7058868)
12:19:38 436998mS CMCallEvt: 0000000000000000 0.1021.0 -1 BaseEP: NEW CMEndpoint f60b2600 TOTAL NOW=2 CALL_LIST=0
12:19:38 436998mS CMExtnEvt: test1: CMExtnHandler::SetCurrent( id: 0->1020 )
12:19:38 436998mS SIP Tx: TLS 10.219.6.91:5061 -> 10.219.6.93:44225
SIP/2.0 100 Trying
Via: SIP/2.0/TLS 10.219.6.93:5061;branch=z9hG4bK-s1632-001881905005-1--s1632-
Record-Route: <sip:10.219.6.93:5061;ipcs-line=4872;lr;transport=tls;subid_ipcs=3020754252>
From: <sip:100@mydomain.com>;tag=2234eff9-8634-4f97-9c71-4b141101500d
Call-ID: ac2f74f5-2ea2-446a-82ba-95485c18304c
CSeq: 1 INVITE
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,REFER,NOTIFY,SUBSCRIBE,REGISTER,PUBLISH,UPDATE
Supported: timer,100rel
Server: IP Office 11.0.4.2.0 build 58
Content-Length: 0
To: <sip:*17@mydomain.com>;tag=979e4af7820134f6

12:19:38 436999mS CMExtnRx: v=100, p1=0
CMSetup
Line: type=SIPLine 360 Call: lid=10000 id=1020 in=0
Called[*17] Type=Default (100) Reason=CMDRdirect SndComp Calling[100] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=CallIndSigCon CMTR=64 CMST=Default CMU1=ALaw
IE CMIEFastStartInfoData (6) 6 item(s)
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=test1
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=100
12:19:38 436999mS CMCallEvt: 0adb065b000003fc 10000.1020.0 10 test1.0: StateChange: END=A CMCSIdle->CMCSDialInitiated
12:19:38 436999mS CMExtnEvt: v=0 State, new=Dialling old=Idle,0,0,test1
12:19:38 436999mS CMTARGET: 0adb065b000003fc 10000.1020.0 10 test1.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=*17 sub= calling=100 calling_sub= dir=out complete=1 ses=0
12:19:38 436999mS CMTARGET: 0adb065b000003fc 10000.1020.0 10 test1.0: ADD TARGET (N): number=*17 type=100 depth=1 nobar=1 setorig=1 ses=0
12:19:38 436999mS CMTARGET: 0adb065b000003fc 10000.1020.0 10 test1.0: SYS SC: *17 3 sc=type=VoicemailCollect code=*17, num="?"U callinfop->sending_complete=1 secondary_dialtone=
12:19:38 436999mS CMTARGET: 0adb065b000003fc 10000.1020.0 10 test1.0: ADD VM TARGET
12:19:38 436999mS CMTARGET: 0adb065b000003fc 10000.1020.0 10 test1.0: Voicemail for remote user test1 via link to PBX:10.219.6.90
12:19:38 436999mS CMLineTx: v=1
CMRestart
Line: type=IPLine 1 Call: lid=0 id=-1 in=0
BC: CMTC=Speech CMTM=CallIndSigCon CMTR=64 CMST=Default CMU1=ALaw
UUI type=User2User [...] [0x00 0x00 0x00 ]
Display [fra]
Locale: fra
12:19:38 436999mS CMTARGET: 0adb065b000003fc 10000.1020.0 10 test1.0: ADD VM TARGET: FAILED availability=0
12:19:39 437000mS CMTARGET: 0adb065b000003fc 10000.1020.0 10 test1.0: NO INITIAL TARGETS: ??
12:19:39 437000mS CMTARGET: 0adb065b000003fc 10000.1020.0 10 test1.0: Fallback() targeting failed
12:19:39 437000mS CMLOGGING: CALL:2020/03/2512:19,00:00:00,000,100,O,*17,*17,test1,,,1,,"",0,n/a
12:19:39 437000mS CMExtnEvt: test1: CALL LOST (CMCauseNoChannel)
12:19:39 437000mS CMExtnEvt: test1: Extn(100) Calling Party Number(100) Type(CMNTypeInternal)
12:19:39 437000mS CMCallEvt: 0adb065b000003fc 10000.1020.0 -1 test1.0: StateChange: END=X CMCSDialInitiated->CMCSCompleted
12:19:39 437000mS CMExtnEvt: v=0 State, new=PortRecoverDelay old=Dialling,0,0,test1
12:19:39 437000mS CMExtnTx: v=100, p1=0
CMReleaseComp
Line: type=SIPLine 360 Call: lid=10000 id=1020 in=0
Called[*17] Type=Voicemail (102) Reason=CMDRdirect Calling[100] Type=Internal Plan=Default
Cause=34, No cct/chan available
Timed: 25/03/20 12:19
12:19:39 437001mS SIP Tx: TLS 10.219.6.91:5061 -> 10.219.6.93:44225
SIP/2.0 480 Temporarily Unavailable
Via: SIP/2.0/TLS 10.219.6.93:5061;branch=z9hG4bK-s1632-001881905005-1--s1632-
Record-Route: <sip:10.219.6.93:5061;ipcs-line=4872;lr;transport=tls;subid_ipcs=3020754252>
From: <sip:100@mydomain.com>;tag=2234eff9-8634-4f97-9c71-4b141101500d
Call-ID: ac2f74f5-2ea2-446a-82ba-95485c18304c
CSeq: 1 INVITE
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,REFER,NOTIFY,SUBSCRIBE,REGISTER,PUBLISH,UPDATE
Supported: timer,100rel
Server: IP Office 11.0.4.2.0 build 58
Reason: Q.850;cause=34;text="No circuit/channel available"
Content-Length: 0
To: <sip:*17@mydomain.com>;tag=979e4af7820134f6

12:19:39 437001mS CMExtnEvt: test1: CMExtnHandler::SetCurrent( id: 1020->0 )
12:19:39 437001mS CMCallEvt: 0adb065b000003fc 10000.1020.0 -1 test1.-1: StateChange: END=X CMCSCompleted->CMCSDelete
12:19:39 437001mS CMCallEvt: 0000000000000000 0.1021.0 -1 BaseEP: DELETE CMEndpoint f60b2600 TOTAL NOW=1 CALL_LIST=0
12:19:39 437001mS CMCallEvt: END CALL:10 (f7058868)
12:19:39 437001mS CMTARGET: 0adb065b000003fc 10000.1020.0 -1 BaseEP: ~CMTargetHandler f60bc0a8 ep f60b4c30
12:19:39 437001mS CMCallEvt: 0adb065b000003fc 10000.1020.0 -1 BaseEP: DELETE CMEndpoint f60b4c30 TOTAL NOW=0 CALL_LIST=0
12:19:39 437002mS CMMap: a=1.500 b=0.0 Mapper::FreeCodec freed CMRTVocoder(f644ee38) resource busy 0, total 3520
12:19:39 437002mS CMLineRx: v=1
CMRestartAck
Line: type=IPLine 1 Call: lid=0 id=-1 in=0
BC: CMTC=Speech CMTM=CallIndSigCon CMTR=64 CMST=Default CMU1=ALaw
UUI type=User2User [...] [0x00 0x00 0x00 ]
Display [fra]
Locale: fra
12:19:39 437038mS SIP Rx: TLS 10.219.6.93:41111 -> 10.219.6.91:5061
ACK sip:*17@mydomain.com SIP/2.0
From: <sip:100@mydomain.com>;tag=2234eff9-8634-4f97-9c71-4b141101500d
To: <sip:*17@mydomain.com>;tag=979e4af7820134f6
CSeq: 1 ACK
Call-ID: ac2f74f5-2ea2-446a-82ba-95485c18304c
Contact: <sip:100@10.219.6.93:5061;transport=tls;subid_ipcs=3020754252>;+sip.instance="<urn:uuid:a921180a-2271-441d-a8ec-6296383c625a>"
Max-Forwards: 70
Via: SIP/2.0/TLS 10.219.6.93:5061;branch=z9hG4bK-s1632-001881905005-1--s1632-
Content-Length: 0

12:19:39 437200mS SIP Rx: TLS 10.219.6.93:44225 -> 10.219.6.91:5061
INVITE sip:*17@mydomain.com SIP/2.0
From: <sip:100@mydomain.com>;tag=2234eff9-8634-4f97-9c71-4b141101500d
To: <sip:*17@mydomain.com>
CSeq: 2 INVITE
Call-ID: ac2f74f5-2ea2-446a-82ba-95485c18304c
Contact: <sip:100@10.219.6.93:5061;subid_ipcs=3020754252;transport=tls>;+sip.instance="<urn:uuid:a921180a-2271-441d-a8ec-6296383c625a>"
Record-Route: <sip:10.219.6.93:5061;ipcs-line=4873;lr;transport=tls;subid_ipcs=3020754252>
Allow: INVITE,ACK,OPTIONS,BYE,CANCEL,NOTIFY,MESSAGE,REFER,INFO,PUBLISH,UPDATE
Supported: eventlist,outbound,replaces
User-Agent: Avaya Communicator Android/3.7.4 (FA-RELEASE41-BUILD.2; SM-J415FN)
Max-Forwards: 69
Via: SIP/2.0/TLS 10.219.6.93:5061;branch=z9hG4bK-s1632-002069538375-1--s1632-
Accept-Language: fr
Content-Type: application/sdp
P-Conference: OutdialPrompt=false, FeedbackPrompts=false, UCCP=true, Video=true, WebCollaboration=true
Content-Length: 541

v=0
o=sips:100@192.0.0.4 5 3 IN IP4 10.219.6.93
s=-
c=IN IP4 10.219.6.93
b=TIAS:64000
t=0 0
a=activetalker:1
m=audio 40844 RTP/AVP 116 9 8 0 110 18 101
a=sendrecv
a=rtpmap:116 OPUS/48000/2
a=fmtp:116 maxplaybackrate=16000;sprop-maxcapturerate=16000;maxaveragebitrate=20000;stereo=0;sprop-stereo=0;cbr=0;useinbandfec=1;usedtx=0
a=minptime:20
a=maxptime:20
a=rtpmap:9 G722/8000/1
a=rtpmap:8 PCMA/8000/1
a=rtpmap:0 PCMU/8000/1
a=rtpmap:110 G726-32/8000/1
a=rtpmap:18 G729/8000/1
a=rtpmap:101 telephone-event/8000
a=ptime:20
12:19:39 437200mS CMCallEvt: 0000000000000000 0.1022.0 -1 BaseEP: NEW CMEndpoint f60b4c30 TOTAL NOW=1 CALL_LIST=0
12:19:39 437200mS CMCallEvt: 0000000000000000 0.1022.0 -1 test1.-1: NEW CMExtnEndpoint f60b4c30, Name=test1, Extn=100, Phys Extn=100
12:19:39 437200mS CMMap: IP::SetCodec pcp[21]b0r0 0 -> f60b8818
12:19:39 437201mS CMCallEvt: CREATE CALL:11 (f7058868)
12:19:39 437201mS CMCallEvt: 0000000000000000 0.1023.0 -1 BaseEP: NEW CMEndpoint f60b2600 TOTAL NOW=2 CALL_LIST=0
12:19:39 437201mS CMExtnEvt: test1: CMExtnHandler::SetCurrent( id: 0->1022 )
12:19:39 437201mS CMExtnEvt: v=0 State, new=Idle old=PortRecoverDelay,0,0,test1
12:19:39 437201mS SIP Tx: TLS 10.219.6.91:5061 -> 10.219.6.93:44225
SIP/2.0 100 Trying
Via: SIP/2.0/TLS 10.219.6.93:5061;branch=z9hG4bK-s1632-002069538375-1--s1632-
Record-Route: <sip:10.219.6.93:5061;ipcs-line=4873;lr;transport=tls;subid_ipcs=3020754252>
From: <sip:100@mydomain.com>;tag=2234eff9-8634-4f97-9c71-4b141101500d
Call-ID: ac2f74f5-2ea2-446a-82ba-95485c18304c
CSeq: 2 INVITE
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,REFER,NOTIFY,SUBSCRIBE,REGISTER,PUBLISH,UPDATE
Supported: timer,100rel
Server: IP Office 11.0.4.2.0 build 58
Content-Length: 0
To: <sip:*17@mydomain.com>;tag=88f8fb0afef45cfb

12:19:39 437202mS CMExtnRx: v=100, p1=0
CMSetup
Line: type=SIPLine 360 Call: lid=10000 id=1022 in=0
Called[*17] Type=Default (100) Reason=CMDRdirect SndComp Calling[100] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=CallIndSigCon CMTR=64 CMST=Default CMU1=ALaw
IE CMIEFastStartInfoData (6) 6 item(s)
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=test1
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=100
12:19:39 437202mS CMCallEvt: 0adb065b000003fe 10000.1022.0 11 test1.0: StateChange: END=A CMCSIdle->CMCSDialInitiated
12:19:39 437202mS CMExtnEvt: v=0 State, new=Dialling old=Idle,0,0,test1
12:19:39 437202mS CMTARGET: 0adb065b000003fe 10000.1022.0 11 test1.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=*17 sub= calling=100 calling_sub= dir=out complete=1 ses=0
12:19:39 437202mS CMTARGET: 0adb065b000003fe 10000.1022.0 11 test1.0: ADD TARGET (N): number=*17 type=100 depth=1 nobar=1 setorig=1 ses=0
12:19:39 437202mS CMTARGET: 0adb065b000003fe 10000.1022.0 11 test1.0: SYS SC: *17 3 sc=type=VoicemailCollect code=*17, num="?"U callinfop->sending_complete=1 secondary_dialtone=
12:19:39 437202mS CMTARGET: 0adb065b000003fe 10000.1022.0 11 test1.0: ADD VM TARGET
12:19:39 437202mS CMTARGET: 0adb065b000003fe 10000.1022.0 11 test1.0: Voicemail for remote user test1 via link to PBX:10.219.6.90
12:19:39 437202mS CMLineTx: v=1
CMRestart
Line: type=IPLine 1 Call: lid=0 id=-1 in=0
BC: CMTC=Speech CMTM=CallIndSigCon CMTR=64 CMST=Default CMU1=ALaw
UUI type=User2User [...] [0x00 0x00 0x00 ]
Display [fra]
Locale: fra
12:19:39 437202mS CMTARGET: 0adb065b000003fe 10000.1022.0 11 test1.0: ADD VM TARGET: FAILED availability=0
12:19:39 437202mS CMTARGET: 0adb065b000003fe 10000.1022.0 11 test1.0: NO INITIAL TARGETS: ??
12:19:39 437203mS CMTARGET: 0adb065b000003fe 10000.1022.0 11 test1.0: Fallback() targeting failed
12:19:39 437203mS CMLOGGING: CALL:2020/03/2512:19,00:00:00,000,100,O,*17,*17,test1,,,1,,"",0,n/a
12:19:39 437203mS CMExtnEvt: test1: CALL LOST (CMCauseNoChannel)
12:19:39 437203mS CMExtnEvt: test1: Extn(100) Calling Party Number(100) Type(CMNTypeInternal)
12:19:39 437203mS CMCallEvt: 0adb065b000003fe 10000.1022.0 -1 test1.0: StateChange: END=X CMCSDialInitiated->CMCSCompleted
12:19:39 437203mS CMExtnEvt: v=0 State, new=PortRecoverDelay old=Dialling,0,0,test1
12:19:39 437203mS CMExtnTx: v=100, p1=0
CMReleaseComp
Line: type=SIPLine 360 Call: lid=10000 id=1022 in=0
Called[*17] Type=Voicemail (102) Reason=CMDRdirect Calling[100] Type=Internal Plan=Default
Cause=34, No cct/chan available
Timed: 25/03/20 12:19
12:19:39 437203mS SIP Tx: TLS 10.219.6.91:5061 -> 10.219.6.93:44225
SIP/2.0 480 Temporarily Unavailable
Via: SIP/2.0/TLS 10.219.6.93:5061;branch=z9hG4bK-s1632-002069538375-1--s1632-
Record-Route: <sip:10.219.6.93:5061;ipcs-line=4873;lr;transport=tls;subid_ipcs=3020754252>
From: <sip:100@mydomain.com>;tag=2234eff9-8634-4f97-9c71-4b141101500d
Call-ID: ac2f74f5-2ea2-446a-82ba-95485c18304c
CSeq: 2 INVITE
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,REFER,NOTIFY,SUBSCRIBE,REGISTER,PUBLISH,UPDATE
Supported: timer,100rel
Server: IP Office 11.0.4.2.0 build 58
Reason: Q.850;cause=34;text="No circuit/channel available"
Content-Length: 0
To: <sip:*17@mydomain.com>;tag=88f8fb0afef45cfb

12:19:39 437203mS CMExtnEvt: test1: CMExtnHandler::SetCurrent( id: 1022->0 )
12:19:39 437203mS CMCallEvt: 0adb065b000003fe 10000.1022.0 -1 test1.-1: StateChange: END=X CMCSCompleted->CMCSDelete
12:19:39 437204mS CMCallEvt: 0000000000000000 0.1023.0 -1 BaseEP: DELETE CMEndpoint f60b2600 TOTAL NOW=1 CALL_LIST=0
12:19:39 437204mS CMCallEvt: END CALL:11 (f7058868)
12:19:39 437204mS CMTARGET: 0adb065b000003fe 10000.1022.0 -1 BaseEP: ~CMTargetHandler f60bc0a8 ep f60b4c30
12:19:39 437204mS CMCallEvt: 0adb065b000003fe 10000.1022.0 -1 BaseEP: DELETE CMEndpoint f60b4c30 TOTAL NOW=0 CALL_LIST=0
12:19:39 437204mS SIP Rx: TLS 10.219.6.93:44225 -> 10.219.6.91:5061
OPTIONS sip:mydomain.com SIP/2.0
From: <sip:100@mydomain.com>;tag=5fe8b7f8-129b-4e28-a77c-8e04d7ea7b5e
To: <sip:100@mydomain.com>
CSeq: 1 OPTIONS
Call-ID: c9d7f86a-b74a-4b97-97b2-83a98ee03235
Contact: <sip:100@10.219.6.93:5061;transport=tls;subid_ipcs=3020754252>;+sip.instance="<urn:uuid:a921180a-2271-441d-a8ec-6296383c625a>";+av.sip.iptolerance;+av.sip.sig=4
Record-Route: <sip:10.219.6.93:5061;ipcs-line=4874;lr;transport=tls;subid_ipcs=3020754252>
Allow: INVITE,ACK,OPTIONS,BYE,CANCEL,NOTIFY,MESSAGE,REFER,INFO,PUBLISH,UPDATE
Supported: eventlist,outbound,replaces
User-Agent: Avaya Communicator Android/3.7.4 (FA-RELEASE41-BUILD.2; SM-J415FN)
Max-Forwards: 69
Via: SIP/2.0/TLS 10.219.6.93:5061;branch=z9hG4bK-s1632-002134198621-1--s1632-
Content-Length: 0

12:19:39 437204mS SIP Tx: TLS 10.219.6.91:5061 -> 10.219.6.93:44225
SIP/2.0 200 OK
Via: SIP/2.0/TLS 10.219.6.93:5061;branch=z9hG4bK-s1632-002134198621-1--s1632-
Record-Route: <sip:10.219.6.93:5061;ipcs-line=4874;lr;transport=tls;subid_ipcs=3020754252>
From: <sip:100@mydomain.com>;tag=5fe8b7f8-129b-4e28-a77c-8e04d7ea7b5e
Call-ID: c9d7f86a-b74a-4b97-97b2-83a98ee03235
CSeq: 1 OPTIONS
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,REFER,NOTIFY,SUBSCRIBE,REGISTER,PUBLISH,UPDATE
Supported: timer,100rel
Server: IP Office 11.0.4.2.0 build 58
Content-Type: application/sdp
Content-Length: 215
To: <sip:100@mydomain.com>

v=0
o=UserA 757206277 1128004180 IN IP4 10.219.6.91
s=Session SDP
c=IN IP4 10.219.6.91
t=0 0
m=audio 8000 RTP/AVP 8 9 18
a=rtpmap:8 PCMA/8000
a=rtpmap:9 G722/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
12:19:39 437205mS CMMap: a=1.500 b=0.0 Mapper::FreeCodec freed CMRTVocoder(f60b8818) resource busy 0, total 3520
12:19:39 437205mS CMLineRx: v=1
CMRestartAck
Line: type=IPLine 1 Call: lid=0 id=-1 in=0
BC: CMTC=Speech CMTM=CallIndSigCon CMTR=64 CMST=Default CMU1=ALaw
UUI type=User2User [...] [0x00 0x00 0x00 ]
Display [fra]
Locale: fra
12:19:39 437207mS SIP Rx: TLS 10.219.6.93:42062 -> 10.219.6.91:5061
ACK sip:*17@mydomain.com SIP/2.0
From: <sip:100@mydomain.com>;tag=2234eff9-8634-4f97-9c71-4b141101500d
To: <sip:*17@mydomain.com>;tag=88f8fb0afef45cfb
CSeq: 2 ACK
Call-ID: ac2f74f5-2ea2-446a-82ba-95485c18304c
Contact: <sip:100@10.219.6.93:5061;subid_ipcs=3020754252;transport=tls>;+sip.instance="<urn:uuid:a921180a-2271-441d-a8ec-6296383c625a>"
Max-Forwards: 70
Via: SIP/2.0/TLS 10.219.6.93:5061;branch=z9hG4bK-s1632-002069538375-1--s1632-
Content-Length: 0

12:19:39 437398mS SIP Rx: TLS 10.219.6.93:44225 -> 10.219.6.91:5061
INVITE sip:*17@mydomain.com SIP/2.0
From: <sip:100@mydomain.com>;tag=2234eff9-8634-4f97-9c71-4b141101500d
To: <sip:*17@mydomain.com>
CSeq: 3 INVITE
Call-ID: ac2f74f5-2ea2-446a-82ba-95485c18304c
Contact: <sip:100@10.219.6.93:5061;transport=tls;subid_ipcs=3020754252>;+sip.instance="<urn:uuid:a921180a-2271-441d-a8ec-6296383c625a>"
Record-Route: <sip:10.219.6.93:5061;ipcs-line=4875;lr;transport=tls;subid_ipcs=3020754252>
Allow: INVITE,ACK,OPTIONS,BYE,CANCEL,NOTIFY,MESSAGE,REFER,INFO,PUBLISH,UPDATE
Supported: eventlist,outbound,replaces
User-Agent: Avaya Communicator Android/3.7.4 (FA-RELEASE41-BUILD.2; SM-J415FN)
Max-Forwards: 69
Via: SIP/2.0/TLS 10.219.6.93:5061;branch=z9hG4bK-s1632-001721067489-1--s1632-
Accept-Language: fr
Content-Type: application/sdp
P-Conference: OutdialPrompt=false, FeedbackPrompts=false, UCCP=true, Video=true, WebCollaboration=true
Content-Length: 540

v=0
o=sip:100@192.0.0.4 5 4 IN IP4 10.219.6.93
s=-
c=IN IP4 10.219.6.93
b=TIAS:64000
t=0 0
a=activetalker:1
m=audio 40846 RTP/AVP 116 9 8 0 110 18 101
a=sendrecv
a=rtpmap:116 OPUS/48000/2
a=fmtp:116 maxplaybackrate=16000;sprop-maxcapturerate=16000;maxaveragebitrate=20000;stereo=0;sprop-stereo=0;cbr=0;useinbandfec=1;usedtx=0
a=minptime:20
a=maxptime:20
a=rtpmap:9 G722/8000/1
a=rtpmap:8 PCMA/8000/1
a=rtpmap:0 PCMU/8000/1
a=rtpmap:110 G726-32/8000/1
a=rtpmap:18 G729/8000/1
a=rtpmap:101 telephone-event/8000
a=ptime:20
12:19:39 437398mS CMCallEvt: 0000000000000000 0.1024.0 -1 BaseEP: NEW CMEndpoint f60b4c30 TOTAL NOW=1 CALL_LIST=0
12:19:39 437398mS CMCallEvt: 0000000000000000 0.1024.0 -1 test1.-1: NEW CMExtnEndpoint f60b4c30, Name=test1, Extn=100, Phys Extn=100
12:19:39 437398mS CMMap: IP::SetCodec pcp[23]b0r0 0 -> f60aff28
12:19:39 437399mS CMCallEvt: CREATE CALL:12 (f709cb50)
12:19:39 437399mS CMCallEvt: 0000000000000000 0.1025.0 -1 BaseEP: NEW CMEndpoint f60ae1a0 TOTAL NOW=2 CALL_LIST=0
12:19:39 437399mS CMExtnEvt: test1: CMExtnHandler::SetCurrent( id: 0->1024 )
12:19:39 437399mS CMExtnEvt: v=0 State, new=Idle old=PortRecoverDelay,0,0,test1
12:19:39 437399mS SIP Tx: TLS 10.219.6.91:5061 -> 10.219.6.93:44225
SIP/2.0 100 Trying
Via: SIP/2.0/TLS 10.219.6.93:5061;branch=z9hG4bK-s1632-001721067489-1--s1632-
Record-Route: <sip:10.219.6.93:5061;ipcs-line=4875;lr;transport=tls;subid_ipcs=3020754252>
From: <sip:100@mydomain.com>;tag=2234eff9-8634-4f97-9c71-4b141101500d
Call-ID: ac2f74f5-2ea2-446a-82ba-95485c18304c
CSeq: 3 INVITE
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,REFER,NOTIFY,SUBSCRIBE,REGISTER,PUBLISH,UPDATE
Supported: timer,100rel
Server: IP Office 11.0.4.2.0 build 58
Content-Length: 0
To: <sip:*17@mydomain.com>;tag=178c1950ea2d46e7

12:19:39 437400mS CMExtnRx: v=100, p1=0
CMSetup
Line: type=SIPLine 360 Call: lid=10000 id=1024 in=0
Called[*17] Type=Default (100) Reason=CMDRdirect SndComp Calling[100] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=CallIndSigCon CMTR=64 CMST=Default CMU1=ALaw
IE CMIEFastStartInfoData (6) 6 item(s)
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=test1
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=100
12:19:39 437400mS CMCallEvt: 0adb065b00000400 10000.1024.0 12 test1.0: StateChange: END=A CMCSIdle->CMCSDialInitiated
12:19:39 437400mS CMExtnEvt: v=0 State, new=Dialling old=Idle,0,0,test1
12:19:39 437400mS CMTARGET: 0adb065b00000400 10000.1024.0 12 test1.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=*17 sub= calling=100 calling_sub= dir=out complete=1 ses=0
12:19:39 437400mS CMTARGET: 0adb065b00000400 10000.1024.0 12 test1.0: ADD TARGET (N): number=*17 type=100 depth=1 nobar=1 setorig=1 ses=0
12:19:39 437400mS CMTARGET: 0adb065b00000400 10000.1024.0 12 test1.0: SYS SC: *17 3 sc=type=VoicemailCollect code=*17, num="?"U callinfop->sending_complete=1 secondary_dialtone=
12:19:39 437400mS CMTARGET: 0adb065b00000400 10000.1024.0 12 test1.0: ADD VM TARGET
12:19:39 437400mS CMTARGET: 0adb065b00000400 10000.1024.0 12 test1.0: Voicemail for remote user test1 via link to PBX:10.219.6.90
12:19:39 437400mS CMLineTx: v=1
CMRestart
Line: type=IPLine 1 Call: lid=0 id=-1 in=0
BC: CMTC=Speech CMTM=CallIndSigCon CMTR=64 CMST=Default CMU1=ALaw
UUI type=User2User [...] [0x00 0x00 0x00 ]
Display [fra]
Locale: fra
12:19:39 437400mS CMTARGET: 0adb065b00000400 10000.1024.0 12 test1.0: ADD VM TARGET: FAILED availability=0
12:19:39 437400mS CMTARGET: 0adb065b00000400 10000.1024.0 12 test1.0: NO INITIAL TARGETS: ??
12:19:39 437400mS CMTARGET: 0adb065b00000400 10000.1024.0 12 test1.0: Fallback() targeting failed
12:19:39 437401mS CMLOGGING: CALL:2020/03/2512:19,00:00:00,000,100,O,*17,*17,test1,,,1,,"",0,n/a
12:19:39 437401mS CMExtnEvt: test1: CALL LOST (CMCauseNoChannel)
12:19:39 437401mS CMExtnEvt: test1: Extn(100) Calling Party Number(100) Type(CMNTypeInternal)
12:19:39 437401mS CMCallEvt: 0adb065b00000400 10000.1024.0 -1 test1.0: StateChange: END=X CMCSDialInitiated->CMCSCompleted
12:19:39 437401mS CMExtnEvt: v=0 State, new=PortRecoverDelay old=Dialling,0,0,test1
12:19:39 437401mS CMExtnTx: v=100, p1=0
CMReleaseComp
Line: type=SIPLine 360 Call: lid=10000 id=1024 in=0
Called[*17] Type=Voicemail (102) Reason=CMDRdirect Calling[100] Type=Internal Plan=Default
Cause=34, No cct/chan available
Timed: 25/03/20 12:19
12:19:39 437401mS SIP Tx: TLS 10.219.6.91:5061 -> 10.219.6.93:44225
SIP/2.0 480 Temporarily Unavailable
Via: SIP/2.0/TLS 10.219.6.93:5061;branch=z9hG4bK-s1632-001721067489-1--s1632-
Record-Route: <sip:10.219.6.93:5061;ipcs-line=4875;lr;transport=tls;subid_ipcs=3020754252>
From: <sip:100@mydomain.com>;tag=2234eff9-8634-4f97-9c71-4b141101500d
Call-ID: ac2f74f5-2ea2-446a-82ba-95485c18304c
CSeq: 3 INVITE
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,REFER,NOTIFY,SUBSCRIBE,REGISTER,PUBLISH,UPDATE
Supported: timer,100rel
Server: IP Office 11.0.4.2.0 build 58
Reason: Q.850;cause=34;text="No circuit/channel available"
Content-Length: 0
To: <sip:*17@mydomain.com>;tag=178c1950ea2d46e7

12:19:39 437401mS CMExtnEvt: test1: CMExtnHandler::SetCurrent( id: 1024->0 )
12:19:39 437401mS CMCallEvt: 0adb065b00000400 10000.1024.0 -1 test1.-1: StateChange: END=X CMCSCompleted->CMCSDelete
12:19:39 437401mS CMCallEvt: 0000000000000000 0.1025.0 -1 BaseEP: DELETE CMEndpoint f60ae1a0 TOTAL NOW=1 CALL_LIST=0
12:19:39 437401mS CMCallEvt: END CALL:12 (f709cb50)
12:19:39 437401mS CMTARGET: 0adb065b00000400 10000.1024.0 -1 BaseEP: ~CMTargetHandler f60bc0a8 ep f60b4c30
12:19:39 437401mS CMCallEvt: 0adb065b00000400 10000.1024.0 -1 BaseEP: DELETE CMEndpoint f60b4c30 TOTAL NOW=0 CALL_LIST=0
12:19:39 437402mS CMMap: a=1.500 b=0.0 Mapper::FreeCodec freed CMRTVocoder(f60aff28) resource busy 0, total 3520
12:19:39 437402mS CMLineRx: v=1
CMRestartAck
Line: type=IPLine 1 Call: lid=0 id=-1 in=0
BC: CMTC=Speech CMTM=CallIndSigCon CMTR=64 CMST=Default CMU1=ALaw
UUI type=User2User [...] [0x00 0x00 0x00 ]
Display [fra]
Locale: fra
12:19:39 437404mS SIP Rx: TLS 10.219.6.93:42062 -> 10.219.6.91:5061
ACK sip:*17@mydomain.com SIP/2.0
From: <sip:100@mydomain.com>;tag=2234eff9-8634-4f97-9c71-4b141101500d
To: <sip:*17@mydomain.com>;tag=178c1950ea2d46e7
CSeq: 3 ACK
Call-ID: ac2f74f5-2ea2-446a-82ba-95485c18304c
Contact: <sip:100@10.219.6.93:5061;transport=tls;subid_ipcs=3020754252>;+sip.instance="<urn:uuid:a921180a-2271-441d-a8ec-6296383c625a>"
Max-Forwards: 70
Via: SIP/2.0/TLS 10.219.6.93:5061;branch=z9hG4bK-s1632-001721067489-1--s1632-
Content-Length: 0

12:19:39 437531mS SIP Rx: TLS 10.219.6.93:44225 -> 10.219.6.91:5061
OPTIONS sip:mydomain.com SIP/2.0
From: <sip:100@mydomain.com>;tag=27764cbc-fe69-4e4c-8a5f-1bbce08959ba
To: <sip:100@mydomain.com>
CSeq: 1 OPTIONS
Call-ID: 2568d6a2-8f28-40e4-b671-3cc750dc14c2
Contact: <sip:100@10.219.6.93:5061;transport=tls;subid_ipcs=3020754252>;+sip.instance="<urn:uuid:a921180a-2271-441d-a8ec-6296383c625a>";+av.sip.iptolerance;+av.sip.sig=4
Record-Route: <sip:10.219.6.93:5061;ipcs-line=4876;lr;transport=tls;subid_ipcs=3020754252>
Allow: INVITE,ACK,OPTIONS,BYE,CANCEL,NOTIFY,MESSAGE,REFER,INFO,PUBLISH,UPDATE
Supported: eventlist,outbound,replaces
User-Agent: Avaya Communicator Android/3.7.4 (FA-RELEASE41-BUILD.2; SM-J415FN)
Max-Forwards: 69
Via: SIP/2.0/TLS 10.219.6.93:5061;branch=z9hG4bK-s1632-000788120310-1--s1632-
Content-Length: 0

12:19:39 437531mS SIP Tx: TLS 10.219.6.91:5061 -> 10.219.6.93:44225
SIP/2.0 200 OK
Via: SIP/2.0/TLS 10.219.6.93:5061;branch=z9hG4bK-s1632-000788120310-1--s1632-
Record-Route: <sip:10.219.6.93:5061;ipcs-line=4876;lr;transport=tls;subid_ipcs=3020754252>
From: <sip:100@mydomain.com>;tag=27764cbc-fe69-4e4c-8a5f-1bbce08959ba
Call-ID: 2568d6a2-8f28-40e4-b671-3cc750dc14c2
CSeq: 1 OPTIONS
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,REFER,NOTIFY,SUBSCRIBE,REGISTER,PUBLISH,UPDATE
Supported: timer,100rel
Server: IP Office 11.0.4.2.0 build 58
Content-Type: application/sdp
Content-Length: 215
To: <sip:100@mydomain.com>

v=0
o=UserA 2019289970 692677390 IN IP4 10.219.6.91
s=Session SDP
c=IN IP4 10.219.6.91
t=0 0
m=audio 8000 RTP/AVP 8 9 18
a=rtpmap:8 PCMA/8000
a=rtpmap:9 G722/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
12:19:41 439402mS CMExtnEvt: test1: Recover Timer reason=CMTRWrapUp
12:19:41 439402mS CMExtnEvt: v=0 State, new=Idle old=PortRecoverDelay,0,0,test1
12:19:42 440331mS PRN: IPOKeepaliveTask::Main sending keepalives at 5000 ms

********** Warning: Logging to Screen Stopped **********

 

[janni78]

It seems to try and connect to the primary server.

Have you configured fallback vm on the primary?
What does System Status show on Voicemail?


"Trying is the first step to failure..." - Homer

 

[UCMen33260]

I found the issue but it's strange on the SP2:

I need to activate manually the VMPro backup server (see screenshot).
When I activate the backup VMPro, the secondary server change status from unknown to centralized and calls to VMPro works again !

 

[janni78]

Have you done everything according to this?

[URL unfurl="true"]https://support.avaya.com/ext/index?page=content&id=SOLN240526[/url]

"Trying is the first step to failure..." - Homer

 

[UCMen33260]

Yes synchronization is maked fine and tested.
My modules created on VMPro (Prmiary) are replicated on the secondary.
But, VMPro on the secondary still ask to manually activate the backup vmpro.

 

[UCMen33260]

This note is important !!
------
For Complete resiliency of voicemail (example if the primary server has an outage or network outage) then you require

a) For solutions using IP Phones registered with the Primary server: at least one IP Phone must be located at Secondary server location and registered to Primary server, so that when the network outage happens at primary server the phone goes in the discover mode and tries Primary first and the eventually registers to secondary. This is what causes the Secondary Server voicemail to switch from None (when Primary is unreachable) to Centralized and then it answers all calls for entire solution.

http://marketingtools.avaya.com/kno...liency/index.htm?when_does_failover_occur.htm

-----
So, if I don't have hard phones, automatic failover for VMPro doesn't work, no?

 

[sizbut]

How long are you waiting? Its not immediate. On my IP Office Select rig:

[ul]
[li]During normal operation SSA shows "Centralized/Inactive".[/li]
[li]When the primary becomes unavailable, that changes to the "none/Backup Activation Pending" within 10 seconds.[/li]
[li]It then takes another 4 minutes before it automatically changes to "Centralized/Backup Active".[/li]
[/ul]

None of that surpises me. Resiliency always takes a few minutes to kick it. If it didn't, even the simplest network changes would have the services going up/down/flip-flopping and driving everyone mad.

Stuck in a never ending cycle of file copying.

 

[UCMen33260]

@Sizbut: I suggest that your IPO release is not the latest one.
VMPro failover is an issue on the latest release, I invite you to test on your own lab.
I found another issue: when you reboot IPO, DNS IP address is changed on the first IP address enterred on the system at the first install. This issue impact presence on IX.
I opened SR on Avaya support.

 

[sizbut]

@UCMen33260 - WTF do you think I was doing!!!! Why do you assume that because it works it must be an error in our systems. That's a very strange approach to asking for help. Good luck, hope you get some help from someone else.

Stuck in a never ending cycle of file copying.

 

[UCMen33260]

@Sizbut: good luck for you too.