No response to IP trunk call request...

[edbisw]

Just rolled out 4.2.14 on two Avaya IP 406 switches this week. Both are connected with Advanced Small Community Networking, and have a huntgroup that has ext's on both switches and it is that huntgroup that started having problems this week, where even when an ext. was logged in on the side that did not "host" the huntgroup, the ext's would not ring.

Rebooting the remote switch would fix it. But I continued to get the following errors off and on in System Status:

No Response to IP trunk call request
IP Trunk Line Number: 10
Remote end IP address: 10.10.10.27 (which is the other end)

The same error comes up in System Status for the other Avaya switch too, with the IP of the other switch.

T1 error or Avaya switch problem or 4.2.14 bug???

 

[tlpeter]

It could be possible that the trunk was down
A reboot of the ipoffice probably did wake the route
Let monitor run and see if you can find something in there

What kind of connection is in between ?


ACA - Implement IP Office
ACS - Implement IP Office
ACA - Implement IP Telephony
ACA - Voice Services Management
______________
Women and cats can do as they please and men and dogs should relax and get used to the idea!

 

[edbisw]

It is a T1 Flex PRI between them. Two T1's on one side (bonded or dual T1) and a single Flex PRI T1 on the other side.

SysMonitor has continued to be inconclusive, but I might be missing something. Is there a document on how to read it?

Otherwise, this continues to happen even though the T1's tested "clean" by the phone company.

 

[tlpeter]

That has been a while

http://marketingtools.avaya.com/knowledgebase/ipoffice/mergedProjects/monitor/index.htm?scn.htm

and

http://marketingtools.avaya.com/knowledgebase/ipoffice/mergedProjects/monitor/index.htm?t1.htm

Look for more options there if think you need them

Is the alarm red or black ?

Red is current and black is past !!!

ACS - Implement IP Office
ACA - Implement IP Telephony -- ACA - Design IP Telephony
ACA - Voice Services Management
______________
Women and cats can do as they please and men and dogs should relax and get used to the idea!

 

[edbisw]

Thanks, I turned on a bunch of additional logging under the T1 and SCN tabs now in the Monitor.

The alarm isn't a particular color in System Status. Just shows up as an alarm on the line for the SCN.

But thanks to the increased monitoring, I got a call drop and captured it and the issues that came up before I saw the "CALL LOST" error...

602856586mS PRN: 2160: Digit Pressed 3
602856588mS CMTARGET: 255.20064.0 4465 CC HMB 1.1: Setting Hard Timer 4000
602856588mS CMTARGET: 255.20064.0 4465 CC HMB 1.1: LOOKUP CALL ROUTE: type=100 called_party=3 sub= calling=41543xxxxx dir=out complete=0 ses=0
602856588mS CMTARGET: 255.20064.0 4465 CC HMB 1.1: ADD TARGET (N): number=3 type=100 depth=1 nobar=1 setorig=1 ses=0
602856806mS PRN: 2160: Digit Pressed 1
602856808mS CMTARGET: 255.20064.0 4465 CC HMB 1.1: Setting Hard Timer 4000
602856808mS CMTARGET: 255.20064.0 4465 CC HMB 1.1: LOOKUP CALL ROUTE: type=100 called_party=31 sub= calling=41543xxxxx dir=out complete=0 ses=0
602856808mS CMTARGET: 255.20064.0 4465 CC HMB 1.1: ADD TARGET (N): number=31 type=100 depth=1 nobar=1 setorig=1 ses=0
602857102mS PRN: 2160: Digit Pressed 0
602857104mS CMTARGET: 255.20064.0 4465 CC HMB 1.1: Setting Hard Timer 4000
602857104mS CMTARGET: 255.20064.0 4465 CC HMB 1.1: LOOKUP CALL ROUTE: type=100 called_party=310 sub= calling=41543xxxxx dir=out complete=0 ses=0
602857104mS CMTARGET: 255.20064.0 4465 CC HMB 1.1: ADD TARGET (N): number=310 type=100 depth=1 nobar=1 setorig=1 ses=0
602857383mS PRN: 2160: Digit Pressed 7
602857384mS CMTARGET: 255.20064.0 4465 CC HMB 1.1: Setting Hard Timer 4000
602857384mS CMTARGET: 255.20064.0 4465 CC HMB 1.1: LOOKUP CALL ROUTE: type=100 called_party=3107 sub= calling=41543xxxxx dir=out complete=0 ses=0
602857385mS CMTARGET: 255.20064.0 4465 CC HMB 1.1: ADD TARGET (N): number=3107 type=100 depth=1 nobar=1 setorig=1 ses=0
602857385mS CMTARGET: 255.20064.0 4465 CC HMB 1.1: HG call targeting occuring here
602857386mS CMTARGET: 255.20064.0 4465 CC HMB 1.1: PrimeForHGTarget: bookinggroup setorig=1 recall=0 resetExtnVars 1
602857386mS CMTARGET: 255.20064.0 4465 CC HMB 1.1: AddHGTarget bookinggroup (depth=2) allowq=1 type=CMNTypeDefault
602857386mS CMCallEvt: 0.20066.0 -1 BaseEP: NEW CMEndpoint fe9e5c8c TOTAL NOW=5 CALL_LIST=2
602857387mS CMTARGET: 255.20064.0 4465 CC HMB 1.1: AddHGTargetRingGroup bookinggroup ring_attempt_count 0
602857387mS CMTARGET: 255.20064.0 4465 CC HMB 1.1: bookinggroup: Not using 3100: Non Tapi User not logged in And FwdU Off
602857388mS CMTARGET: 255.20064.0 4465 CC HMB 1.1: bookinggroup: Not using 3101: LII Uninitialised And FwdU Off
602857388mS CMTARGET: 255.20064.0 4465 CC HMB 1.1: bookinggroup: Not using 3102: LII Uninitialised And FwdU Off
602857388mS CMTARGET: 255.20064.0 4465 CC HMB 1.1: bookinggroup: Not using 2183: Non Tapi User not logged in And FwdU Off
602857389mS CMTARGET: 255.20064.0 4465 CC HMB 1.1: bookinggroup: Not using 2184: Non Tapi User not logged in And FwdU Off
602857389mS CMTARGET: 255.20064.0 4465 CC HMB 1.1: bookinggroup: Not using 2185: Non Tapi User not logged in And FwdU Off
602857389mS CMTARGET: 255.20064.0 4465 CC HMB 1.1: ADD USER: booking sb1 depth=3 disallow_cw=0 dnd=0 real_call=1 group_call=1 type(CMNTypeDefault) incl(0x0) excpt(0x3c), allow_redir(1) remote=00000000
602857390mS CMCallEvt: 0.20067.0 -1 BaseEP: NEW CMEndpoint fea44fa0 TOTAL NOW=6 CALL_LIST=2
602857391mS PRN: Created MH fea2ecec parent 261.20067.0 -1 booking sb1.-1
602857392mS CMTARGET: 261.20067.0 4465 booking sb1.0: ADD PRIMARY
602857393mS CMTARGET: 255.20064.0 4465 CC HMB 1.1: bookinggroup: Not using 2181: Non Tapi User not logged in And FwdU Off
602857393mS CMTARGET: 255.20064.0 4465 CC HMB 1.1: bookinggroup: Not using 2182: LII Uninitialised And FwdU Off
602857394mS CMTARGET: 255.20064.0 4465 CC HMB 1.1: CancelTimer CMTCDelayedProcessing
602857394mS CMTARGET: 255.20064.0 4465 CC HMB 1.1: INITIAL TARGETING SUCCEEDED
602857394mS CMTARGET: 255.20064.0 4465 CC HMB 1.1: GetNoAnswerTimer:15
602857395mS CMCallEvt: 0.20065.0 4465 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering
602857396mS SCN DHG ServiceChg: TriggerUpdateHGAPP 3107 GCs(1) QCs(0) LOCAL
602857396mS SCN DHG ServiceChg: VPNNetworkedPBX(10.220.0.27)::UpdateHGAPP
602857397mS SCN Ctrl Tx: SendHGAPP HG(3107)
602857398mS CMCallEvt: 261.20067.0 4465 booking sb1.0: StateChange: END=T CMCSIdle->CMCSOffering
602857401mS CMExtnEvt: booking sb1: CMExtnHandler::SetCurrent( id: 0->20067 )
602857404mS CMCallEvt: 261.20067.0 4465 booking sb1.0: StateChange: END=T CMCSOffering->CMCSRinging
602857405mS CMExtnEvt: v=5 State, new=Ringing old=Idle,0,0,booking sb1
602857405mS SCN DHG LongestIdle: TriggerUpdateLII: extn(2180) state(1) idle_time(602758333) mass_update (0)
602857406mS CMCallEvt: 0.20065.0 4465 TargetingEP: StateChange: END=B CMCSOffering->CMCSRinging
602857407mS CMCallEvt: 255.20064.0 4465 CC HMB 1.1: StateChange: END=A CMCSDialling->CMCSRingBack
602857407mS CMExtnEvt: v=39 State, new=Alerting old=Dialling,0,0,CC HMB 1
602857412mS CD: CALL: 255.20064.0 BState=Ringing Cut=1 Music=2.0 Aend="CC HMB 1(2160)" (0.0) Bend="bookinggroup(3107)" [booking sb1(2180)] (0.0) CalledNum=3107 (bookinggroup) CallingNum=41543xxxxx () Internal=1 Time=1409 AState=Ringing
602857605mS SCN Ctrl Tx: VPNNetworkedPBX(10.220.0.27)::UpdateLII Unicode(2) TimeNow(602857605)
602857606mS SCN Ctrl Tx: extn(2180) state(1) idle_time(602758333) mass_update(0)
602857850mS H323Evt: RTP(50t): 10.200.0.27/49154 10.210.0.158/50068 CODEC 5 PKTSZ=160 RFC2833=off AGE=1819 SENT 50 (avg size=160) RECV 36 (avg size=160)
602858400mS PRN: VPNN: SendRIP to pbx 10.220.0.27
602858400mS AVRIP Tx: v=10.220.0.27 send=0 receive=0
PLATFORM: requiresvoicemail 0 operational 1 version 3 recordsupported 1
Platform Id 0 Version 4.2(14)
Name LPB-IP406Office
Codepage 2, Unicode UnicodeSupportOn
Time offset: 0
602859739mS CMTARGET: TransferProposal: X_call: ID=4465 Aend=2160 -> 3107
602859740mS CMTARGET: TransferProposal: Y_call: ID=4464 Aend=41543xxxxx -> 2160
602859740mS CMTARGET: Surviving Call=4465
602859740mS CMTARGET: Goodbying Call=4464
602859740mS CMTARGET: AEND 41543xxxxx -> 3107 BEND
602859743mS CMCallEvt: 255.20064.0 4465 CC HMB 1.1: CompleteTransfer to 255.20063.0 (255.20063.0 4464 CC HMB 1.0) (Return @ 0ms -> null)
602859745mS CMExtnEvt: CC HMB 1: CALL LOST (CMCauseTransfer)
602859746mS CMExtnEvt: CC HMB 1: Extn(2160) Calling Party Number(41543xxxxx) Type(CMNTypeUnknown)
602859746mS CMCallEvt: 255.20064.0 -1 CC HMB 1.1: StateChange: END=X CMCSRingBack->CMCSCompleted
602859749mS CMExtnEvt: v=39 State, new=PortRecoverDelay old=Alerting,0,0,CC HMB 1
602859750mS CMExtnEvt: CC HMB 1: CMExtnHandler::SetCurrent( id: 20064->0 )
602859752mS CMCallEvt: 255.20064.0 -1 CC HMB 1.-1: StateChange: END=X CMCSCompleted->CMCSDelete
602859752mS CMTARGET: 255.20064.0 -1 CC HMB 1.-1: ChangeOriginator: To 5.19.1 4465 Q931 Trunk:5 CHAN=1
602859756mS CD: CALL: 5.19.1 BState=Ringing Cut=1 Music=2.0 Aend="Line 5" (7.2) Bend="bookinggroup(3107)" [booking sb1(2180)] (0.0) CalledNum= () CallingNum=41543xxxxx () Internal=0 Time=3753 AState=Connected
602859758mS CMLOGGING: CALL:2009/04/2711:02,00:00:17,003,,O,,,,,,1,,""n/a,0
602859759mS CD: CALL: 255.20064.0 BState=Connected Cut=1 Music=0.0 Aend="" (0.0) Bend="" [CC HMB 1(2160)] (0.0) CalledNum= () CallingNum=2160 (CC HMB 1) Internal=1 Time=21536 AState=Idle
602859760mS CD: CALL: 255.20064.0 Deleted
602859761mS CMExtnEvt: CC HMB 1: CALL LOST (CMCauseTransfer)
602859761mS CMExtnEvt: CC HMB 1: Extn(2160) Calling Party Number(41543xxxxx) Type(CMNTypeUnknown)
602859764mS CMCallEvt: 255.20063.0 -1 CC HMB 1.-1: StateChange: END=X CMCSConnected->CMCSDelete
602859764mS CMCallEvt: END CALL:4464 (fe9d7e70)
602859769mS PRN: Destroyed MH fea4cfcc parent unknown
602859770mS CMCallEvt: 255.20063.0 -1 BaseEP: DELETE CMEndpoint fea586d8 TOTAL NOW=5 CALL_LIST=1
602859771mS PRN: Destroyed MH fea17c04 parent unknown
602859772mS CMCallEvt: 255.20064.0 -1 BaseEP: DELETE CMEndpoint fea20f80 TOTAL NOW=4 CALL_LIST=1
602859773mS CD: CALL: 5.19.1 BState=Ringing Cut=1 Music=2.0 Aend="Line 5" (7.2) Bend="bookinggroup(3107)" [booking sb1(2180)] (0.0) CalledNum= () CallingNum=41543xxxxx () Internal=0 Time=3771 AState=Connected
602859778mS T1DSP: T1 DSP: Slot B: Gains Chan 1 Tx 10 Rx 10
602859779mS H323Evt: RTP(END): 10.200.0.27/49152 10.210.0.158/50068 CODEC 5 PKTSZ=160 RFC2833=off AGE=17602 SENT 691 RECV 672 RTdelay=1320 jitter=29 loss=0 remotejitter=20 remoteloss=0
602859780mS H323Evt: RTP(END): 10.200.0.27/49154 10.210.0.158/50068 CODEC 5 PKTSZ=160 RFC2833=off AGE=3748 SENT 146 RECV 129 RTdelay=0 jitter=833 loss=17 remotejitter=0 remoteloss=0
602859792mS CD: CALLSYNC: cs02
602861752mS CMExtnEvt: CC HMB 1: Recover Timer reason=CMTRWrapUp
602861752mS CMExtnEvt: v=39 State, new=Idle old=PortRecoverDelay,0,0,CC HMB 1
602861752mS SCN DHG LongestIdle: TriggerUpdateLII: extn(2160) state(0) idle_time(602861752) mass_update (0)
602861753mS SCN Ctrl Tx: VPNNetworkedPBX(10.220.0.27)::UpdateLII Unicode(2) TimeNow(602861753)
602861753mS SCN Ctrl Tx: extn(2160) state(0) idle_time(602861752) mass_update(0)



etc. .

 

[edbisw]

I think I might have something that is more relevant...

I started noticing events like this in SysMonitor:

605850330mS CMExtnEvt: Dod: CALL LOST (CMCauseNormal)

Then this looks like a problem during a transfer, to me:

605745848mS CMExtnEvt: CC HMB 1: CALL LOST (CMCauseTransfer)

I picked out one of these problems can got all of the events that happened for this transfer. The call transfer is from ext. 2160 (a Hot Desk ext. that is part of a huntgroup) to the another huntgroup (ext. 3107).

What stood out to me was in the last lines. The second to the last line shows a loss of 78%. Yet it is a value of "256" slightly above that. There is no loss on the "remote" side, and the RTdelay is 0 in both cases which makes me think it is not a network issue, but something else that is kicking up the loss value. What, I don't know...


605745825mS CMTARGET: TransferProposal: X_call: ID=4542 Aend=2160 -> 3107
605745825mS CMTARGET: TransferProposal: Y_call: ID=4541 Aend=41520xxxxx -> 2160
605745825mS CMTARGET: Surviving Call=4542
605745825mS CMTARGET: Goodbying Call=4541
605745825mS CMTARGET: AEND 41520xxxxx -> 3107 BEND
605745829mS CMCallEvt: 255.20391.0 4542 CC HMB 1.1: CompleteTransfer to 255.20390.0 (255.20390.0 4541 CC HMB 1.0) (Return @ 0ms -> null)
605745831mS CMExtnEvt: CC HMB 1: CALL LOST (CMCauseTransfer)
605745832mS CMExtnEvt: CC HMB 1: Extn(2160) Calling Party Number(41520xxxxx) Type(CMNTypeUnknown)
605745832mS CMCallEvt: 255.20391.0 -1 CC HMB 1.1: StateChange: END=X CMCSRingBack->CMCSCompleted
605745835mS CMExtnEvt: v=39 State, new=PortRecoverDelay old=Alerting,0,0,CC HMB 1
605745836mS CMExtnEvt: CC HMB 1: CMExtnHandler::SetCurrent( id: 20391->0 )
605745838mS CMCallEvt: 255.20391.0 -1 CC HMB 1.-1: StateChange: END=X CMCSCompleted->CMCSDelete
605745839mS CMTARGET: 255.20391.0 -1 CC HMB 1.-1: ChangeOriginator: To 5.16.1 4542 Q931 Trunk:5 CHAN=1
605745842mS CD: CALL: 5.16.1 BState=Ringing Cut=1 Music=2.0 Aend="Line 5" (7.2) Bend="bookinggroup(3107)" [booking sb1(2180)] (0.0) CalledNum= () CallingNum=41520xxxxx () Internal=0 Time=3644 AState=Connected
605745845mS CMLOGGING: CALL:2009/04/2711:51,00:00:12,006,,O,,,,,,1,,""n/a,0
605745845mS CD: CALL: 255.20391.0 BState=Connected Cut=1 Music=0.0 Aend="" (0.0) Bend="" [CC HMB 1(2160)] (0.0) CalledNum= () CallingNum=2160 (CC HMB 1) Internal=1 Time=19015 AState=Idle
605745847mS CD: CALL: 255.20391.0 Deleted
605745848mS CMExtnEvt: CC HMB 1: CALL LOST (CMCauseTransfer)
605745848mS CMExtnEvt: CC HMB 1: Extn(2160) Calling Party Number(41520xxxxx) Type(CMNTypeUnknown)
605745850mS CMCallEvt: 255.20390.0 -1 CC HMB 1.-1: StateChange: END=X CMCSConnected->CMCSDelete
605745851mS CMCallEvt: END CALL:4541 (fea61e1c)
605745857mS PRN: Destroyed MH fea25f14 parent unknown
605745858mS CMCallEvt: 255.20390.0 -1 BaseEP: DELETE CMEndpoint fea2acfc TOTAL NOW=7 CALL_LIST=2
605745858mS PRN: Destroyed MH fea25e08 parent unknown
605745860mS CMCallEvt: 255.20391.0 -1 BaseEP: DELETE CMEndpoint fea0dcc0 TOTAL NOW=6 CALL_LIST=2
605745861mS CD: CALL: 5.16.1 BState=Ringing Cut=1 Music=2.0 Aend="Line 5" (7.2) Bend="bookinggroup(3107)" [booking sb1(2180)] (0.0) CalledNum= () CallingNum=41520xxxxx () Internal=0 Time=3663 AState=Connected
605745867mS T1DSP: T1 DSP: Slot B: Gains Chan 1 Tx 10 Rx 10
605745867mS H323Evt: RTP(END): 10.200.0.27/49152 10.210.0.158/50068 CODEC 5 PKTSZ=160 RFC2833=off AGE=12619 SENT 448 RECV 427 RTdelay=0 jitter=0 loss=256 remotejitter=0 remoteloss=0
605745868mS H323Evt: RTP(END): 10.200.0.27/49154 10.210.0.158/50068 CODEC 5 PKTSZ=160 RFC2833=off AGE=3638 SENT 150 RECV 70 RTdelay=0 jitter=26 loss=78 remotejitter=0 remoteloss=0
605745885mS CD: CALLSYNC: cs02

 

[mattKnight]

Are you quite sure that your agents are logged into the group?

Take Care

Matt
I have always wished that my computer would be as easy to use as my telephone.
My wish has come true. I no longer know how to use my telephone.

 

[edbisw]

I had assumed so. But also if no one is logged in to the receiving huntgroup it should go to voicemail.