Cannot dial local numbers starting with 6

[g18c]

I have a customer complaining they cant dial local numbers starting with 6.

Dialplan is minimal: ? .

Any ideas on this? Checked numbers sent to exchange, they are correct as per the trunk and call status.

Plugging analog phone in to trunk and the number dials OK.

Any ideas?

 

[IPGuru]

if you are sending to line what is the clear cause (turn on line in call settings )?
this should help identify the problem.



A Maintenance contract is essential, not a Luxury.
Do things on the cheap & it will cost you dear

 

[g18c]

Thanks for the reply IPGuru, where is that setting please? I cant find it searching online for hte reference "line in call settings ip office

 

[IPGuru]

it is a filter setting in system monitor


A Maintenance contract is essential, not a Luxury.
Do things on the cheap & it will cost you dear

 

[yankblan]

Seen this on Norstar phones through expansion modules with PRI on a 8.0; only a reboot solves it and then it comes back, sometimes on a different module with a different digit.

What is your setup?

ACSS-SME

http://interconnexionsld.ca/

 

[g18c]

Setup is really minimal, user short code of:

9N; Dial N => trunk group 0 (analog lines, 3 enabled on the ATM4 combo card, all in group 0)

I'm not using ARS, i trimmed everything to make it as simple as possible, even using the wildcard '? .' short code and exactly the same issue.

Calls to mobile work, calls to most numbers work, just some specific ones dont work and it seems to vary - customer complains its my config, but my argument is the shortcode '9N; N' should work for all numbers especially when call status shows the correct digits sent the analog but the call never connects. 9N; N doesn't differentiate between 95500567 and 965464564!

And i know its not the trunks as i plug an analog phone in and the numbers that have issues dial fine.

Its a partner who supplied the equipment and we just configured it, i wish we hadn't now its a nightmare and they dont want to pay for Avaya $364 yearly support to escalate it.

From all the many system configs i have done i cant understand why theirs works for some numbers but not others.

I can only suspect its a bug.

 

[intrigrant]

With proper knowledge of the system and tracing the events you can solve this issue.
I have no experience with analog lines but a lot can mess up stuff.

Are you sure it only happens to numbers starting with a 6?
Did you try to send the numbers "en bloc"? Use ARS with secondary dialtone and set a shortcode like SC=N;,TN=N,Action=dial,line idand set the dial timeout to 4 seconds.
Change the analog line settings:
Dial timer adjustments.
Dial tone recognition timer.
Did you do a impedance check on the trunks?
Did you ground the IP Office propery?
Did you changed the DTMF send time on the analog trunks? Maybe the dtmf tone length is too short. Or you need to increase/decrease the TX volume on the line.
.... more, read the help files and use google

 

[TouchToneTommy]

Can you duplicate the problem? Does it happen on ALL of the analog trunks, or only when you hit a specific one? What is the setting for Await Dial Tone on the Analogue Options tab of the line(s)? Can you monitor the line with a butt set when the call fails to determine if the IPO is dialing before the CO is ready to accept digits?

 

[snowman50]

Check you have not programmed a short code starting with 96.

By the way the 2numbers you have quoted have different dialing lengths .
Would that make a difference in your area.

 

[g18c]

Thanks for replies guys, to confirm:

Enbloc
Yes i am using enbloc, shortcode is 9N; N. Dial delay time = 3, dial delay count = 0. The system is correctly waiting for 3 seconds from the last key press before dialing, this works.

Trunk settings
Trunk type = Loop Start ICLID
DTMF Dialing
Impedance = 600 (set by automatic impedance detection)
Pulse width = 500ms
Await dial tone = 3000ms
Echo cancellation = 16ms
Main hum freq. = off
Mark = 37ms
Space = 37ms
Inter-diigit pause = 500ms
Ring persistency = 200ms
Ring off Max = 5000ms
Disconnect clear = 90ms
DTMF On & Off = both 80ms
Agains = 0dB

Locale is set correctly as per our country, in fact these are the same settings i have used for hundreds of installs with the same ISP. I will change the DTMF thanks.

Number length
As for my example i meant to give the same number length (sorry!), so what they are saying is the 96... range does not work for some numbers (others within the range are OK), but 95... numbers are OK for all. Using a $10 analog telephone directly in the trunk the same number dials OK.

Shortcode
No shortcode for any number starting with a digit, they are all default, short code features are only set with * prefix as per default setup.

 

[g18c]

Done a trace on the system, we have 8N; => N dial trunk group 0.

We are dialing 86503945, we hear ringing for 2 rings, then the call drops.

On status it shows trunk line is selected and numbers sent.

Same issue across all trunks.

Trace is below:

Thanks for all the help so far really appreciate it.

UNICODE-UTF8
aru

********** SysMonitor v10.1 (67) **********

********** contact made with 10.100.11.50 at 10:54:34 19/12/2013 **********

********** System (10.100.11.50) has been up and running for 7mins and 27secs(447816mS) **********

********** Warning: TEXT File Logging selected **********


********** Warning: TEXT Logging to File STOPPED on 19/12/2013 10:54:34 **********
447816mS PRN: Monitor Started IP=10.100.11.110 IP 500 V2 8.1(65) FOSS-AUH
(IP Office: Supports Unicode, System Locale is default)
447816mS PRN: LAW=A PRI=0, BRI=2, ALOG=4, VCOMP=20, MDM=0, WAN=0, MODU=0 LANM=0 CkSRC=0 VMAIL=1(VER=2 TYP=3) 1-X=0 CALLS=0(TOT=6)
448107mS RES: Thu 19/12/2013 10:51:05 FreeMem=60766800(2) CMMsg=3 (4) Buff=5200 954 999 12447 5 Links=7398 BTree=0 CPU=1/4/7322/19530/19703/2
448107mS RES2: IP 500 V2 8.1(65) Tasks=48 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=51 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=16 TAPI=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
448107mS RES4: XML MemObjs=45 PoolMem=2097152(1) FreeMem=2082064(1)
452016mS PRN: +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
452016mS PRN: + loader: 1.33
452016mS PRN: + cpu: id 12 board 4 pld 25 type c10 options ac02
452016mS PRN: + cpu: sn 12WZ445006DV
452016mS PRN: + fpga: id 1 issue 0 build 827
452016mS PRN: +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
452016mS PRN: ++++++++++++++++++++ LIST OF MODULES ++++++++++++++++++++
452016mS PRN: +------------------------------------------------------------
452017mS PRN: + Slot 1: Base COMBO6210 Board=0x02 PLD=0x04
452017mS PRN: + Mezzanine ATM4 Board=0x08 PLD=0x07
452017mS PRN: +------------------------------------------------------------
452017mS PRN: + Slot 2: Base COMBO6210 Board=0x02 PLD=0x04
452017mS PRN: + Mezzanine BRI4 Board=0x01 PLD=0x08
452017mS PRN: +------------------------------------------------------------
452017mS PRN: + Slot 3: Base NONE
452017mS PRN: + Mezzanine NONE
452017mS PRN: +------------------------------------------------------------
452017mS PRN: + Slot 4: Base NONE
452017mS PRN: + Mezzanine NONE
452017mS PRN: +------------------------------------------------------------
452018mS PRN: +++++++++++++++++ END OF LIST OF MODULES +++++++++++++++
452018mS PRN: +++++++++++++++++ LIST OF MEMORY CARDS ++++++++++++++++++
452018mS PRN: +------------------------------------------------------------
452018mS PRN: + System SD Card: MNTD
452018mS PRN: + CID Register: 0x4134325344344742300a20016e00c90b
452018mS PRN: + CSD Register: 0x400e00325b5900001da77f800a40002d
452018mS PRN: + SCR Register: 0x0235800001000000
452019mS PRN: + OCR Register: 0xc0ff8000
452020mS PRN: + Status Register: 0x0000000002000000040090003206
452020mS PRN: +------------------------------------------------------------
452020mS PRN: + Optional SD Card: UMNT
452020mS PRN: +------------------------------------------------------------
452020mS PRN: ++++++++++++++ END OF LIST OF MEMORY CARDS +++++++++++++
452020mS PRN: ++++++++++++++++++++ MEMORY CAPTURE +++++++++++++++++++++
452020mS PRN: +------------------------------------------------------------
452021mS PRN: + 0x00000001, 0x00000000, 0x00000000, 0x00000014, 0x00000000
452021mS PRN: + 0x00000001, 0x00000000, 0x00000013, 0x00000000, 0x00000000
452021mS PRN: + 0x00000000, 0x00000000, 0x00000000, 0x00000014, 0x00000000
452021mS PRN: + 0x00000002, 0x00000000, 0x00000000, 0x00000000, 0x00000000
452021mS PRN: + 0x00000000, 0x00000000, 0x00000000, 0x00000000, 0x00000000
452021mS PRN: + 0x00000000, 0x00000000, 0x00000000, 0x00000000, 0x00000000
452021mS PRN: + 0x00000000, 0x00000000, 0x00000000, 0x00000000, 0x00000000
452021mS PRN: + 0x00000000, 0x00000000, 0x00000000, 0x00000000, 0x00000000
452021mS PRN: + 0x00000000, 0x51a715a1, 0x87257962, 0x9db1cf11, 0x4069ee36
452021mS PRN: +------------------------------------------------------------
452021mS PRN: +++++++++++++++++ END OF MEMORY CAPTURE ++++++++++++++++

********** SysMonitor v10.1 (67) [connected to 10.100.11.50 (FOSS-AUH)] **********
507015mS PRN: Monitor Status IP 500 V2 8.1(65)
507016mS PRN: LAW=A PRI=0, BRI=2, ALOG=4, VCOMP=20, MDM=0, WAN=0, MODU=0 LANM=0 CkSRC=0 VMAIL=1(VER=2 TYP=3) 1-X=0 CALLS=0(TOT=6)
530818mS PRN: 10: Digit Pressed 8
530819mS CMCallEvt: 0.1019.0 -1 BaseEP: NEW CMEndpoint f52552b4 TOTAL NOW=1 CALL_LIST=0
530819mS CMCallEvt: 0.1019.0 -1 Christine.-1: NEW CMExtnEndpoint f52552b4, Name=Christine, Extn=10, Phys Extn=10
530819mS CMCallEvt: CREATE CALL:7 (f5254dc8)
530820mS CMCallEvt: 0.1020.0 -1 BaseEP: NEW CMEndpoint f52538fc TOTAL NOW=2 CALL_LIST=0
530821mS CMExtnEvt: Christine: CMExtnHandler::SetCurrent( id: 0->1019 )
530822mS CMExtnRx: v=10, p1=0
CMSetup
Line: type=DigitalExtn 2 Call: lid=0 id=1019 in=0
Called[] Type=Default (100) Reason=CMDRdirect Calling[10] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=Christine
IE CMIECallingPartyKName (226)(Type=CMNameDefault) name=Christine
530822mS CMCallEvt: 0.1019.0 7 Christine.0: StateChange: END=A CMCSIdle->CMCSDialInitiated
530822mS CMExtnEvt: v=1 State, new=Dialling old=Idle,0,0,Christine
530823mS CMTARGET: 0.1019.0 7 Christine.0: LOOKUP CALL ROUTE: type=100 called_party= sub= calling=10 dir=out complete=0 ses=0
530823mS CMTARGET: 0.1019.0 7 Christine.0: ADD TARGET (N): number= type=100 depth=1 nobar=1 setorig=1 ses=0
530823mS CMCallEvt: 0.1019.0 7 Christine.0: StateChange: END=A CMCSDialInitiated->CMCSDialling
530824mS CMExtnTx: v=10, p1=0
CMSetupAck
Line: type=DigitalExtn 2 Call: lid=0 id=1019 in=0
BChan: slot=0 chan=1
Timed: 19/12/13 10:52
530824mS CMExtnRx: v=10, p1=0
CMInformation
Line: type=DigitalExtn 2 Call: lid=0 id=1019 in=0
Called[8] Type=Default (100) Reason=CMDRdirect
530824mS CMTARGET: 0.1019.0 7 Christine.0: Setting Hard Timer 3000
530825mS CMTARGET: 0.1019.0 7 Christine.0: LOOKUP CALL ROUTE: type=100 called_party=8 sub= calling=10 dir=out complete=0 ses=0
530825mS CMTARGET: 0.1019.0 7 Christine.0: ADD TARGET (N): number=8 type=100 depth=1 nobar=1 setorig=1 ses=0
530826mS CD: CALL: 0.1019.0 BState=Idle Cut=0 Music=0.0 Aend="Christine(10)" (0.1) Bend="" [] (0.0) CalledNum=8 () CallingNum=10 (Christine) Internal=1 Time=7 AState=Dialling
531111mS RES: Thu 19/12/2013 10:52:28 FreeMem=60743716(2) CMMsg=3 (4) Buff=5200 954 999 12447 5 Links=7396 BTree=0 CPU=8/13/7322/19038/19703/2
531111mS RES2: IP 500 V2 8.1(65) Tasks=48 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=52 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=16 TAPI=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
531111mS RES4: XML MemObjs=45 PoolMem=2097152(1) FreeMem=2082064(1)
531445mS PRN: 10: Digit Pressed 6
531446mS CMExtnRx: v=10, p1=0
CMInformation
Line: type=DigitalExtn 2 Call: lid=0 id=1019 in=0
Called[6] Type=Default (100) Reason=CMDRdirect
531446mS CMTARGET: 0.1019.0 7 Christine.0: Setting Hard Timer 3000
531446mS CMTARGET: 0.1019.0 7 Christine.0: LOOKUP CALL ROUTE: type=100 called_party=86 sub= calling=10 dir=out complete=0 ses=0
531446mS CMTARGET: 0.1019.0 7 Christine.0: ADD TARGET (N): number=86 type=100 depth=1 nobar=1 setorig=1 ses=0
531783mS PRN: 10: Digit Pressed 5
531783mS CMExtnRx: v=10, p1=0
CMInformation
Line: type=DigitalExtn 2 Call: lid=0 id=1019 in=0
Called[5] Type=Default (100) Reason=CMDRdirect
531784mS CMTARGET: 0.1019.0 7 Christine.0: Setting Hard Timer 3000
531784mS CMTARGET: 0.1019.0 7 Christine.0: LOOKUP CALL ROUTE: type=100 called_party=865 sub= calling=10 dir=out complete=0 ses=0
531784mS CMTARGET: 0.1019.0 7 Christine.0: ADD TARGET (N): number=865 type=100 depth=1 nobar=1 setorig=1 ses=0
532683mS PRN: 10: Digit Pressed 0
532684mS CMExtnRx: v=10, p1=0
CMInformation
Line: type=DigitalExtn 2 Call: lid=0 id=1019 in=0
Called[0] Type=Default (100) Reason=CMDRdirect
532684mS CMTARGET: 0.1019.0 7 Christine.0: Setting Hard Timer 3000
532684mS CMTARGET: 0.1019.0 7 Christine.0: LOOKUP CALL ROUTE: type=100 called_party=8650 sub= calling=10 dir=out complete=0 ses=0
532684mS CMTARGET: 0.1019.0 7 Christine.0: ADD TARGET (N): number=8650 type=100 depth=1 nobar=1 setorig=1 ses=0
533333mS PRN: 10: Digit Pressed 3
533334mS CMExtnRx: v=10, p1=0
CMInformation
Line: type=DigitalExtn 2 Call: lid=0 id=1019 in=0
Called[3] Type=Default (100) Reason=CMDRdirect
533334mS CMTARGET: 0.1019.0 7 Christine.0: Setting Hard Timer 3000
533334mS CMTARGET: 0.1019.0 7 Christine.0: LOOKUP CALL ROUTE: type=100 called_party=86503 sub= calling=10 dir=out complete=0 ses=0
533334mS CMTARGET: 0.1019.0 7 Christine.0: ADD TARGET (N): number=86503 type=100 depth=1 nobar=1 setorig=1 ses=0
533770mS PRN: 10: Digit Pressed 9
533770mS CMExtnRx: v=10, p1=0
CMInformation
Line: type=DigitalExtn 2 Call: lid=0 id=1019 in=0
Called[9] Type=Default (100) Reason=CMDRdirect
533771mS CMTARGET: 0.1019.0 7 Christine.0: Setting Hard Timer 3000
533771mS CMTARGET: 0.1019.0 7 Christine.0: LOOKUP CALL ROUTE: type=100 called_party=865039 sub= calling=10 dir=out complete=0 ses=0
533771mS CMTARGET: 0.1019.0 7 Christine.0: ADD TARGET (N): number=865039 type=100 depth=1 nobar=1 setorig=1 ses=0
534058mS PRN: 10: Digit Pressed 4
534058mS CMExtnRx: v=10, p1=0
CMInformation
Line: type=DigitalExtn 2 Call: lid=0 id=1019 in=0
Called[4] Type=Default (100) Reason=CMDRdirect
534059mS CMTARGET: 0.1019.0 7 Christine.0: Setting Hard Timer 3000
534059mS CMTARGET: 0.1019.0 7 Christine.0: LOOKUP CALL ROUTE: type=100 called_party=8650394 sub= calling=10 dir=out complete=0 ses=0
534059mS CMTARGET: 0.1019.0 7 Christine.0: ADD TARGET (N): number=8650394 type=100 depth=1 nobar=1 setorig=1 ses=0
534333mS PRN: 10: Digit Pressed 5
534333mS CMExtnRx: v=10, p1=0
CMInformation
Line: type=DigitalExtn 2 Call: lid=0 id=1019 in=0
Called[5] Type=Default (100) Reason=CMDRdirect
534334mS CMTARGET: 0.1019.0 7 Christine.0: Setting Hard Timer 3000
534334mS CMTARGET: 0.1019.0 7 Christine.0: LOOKUP CALL ROUTE: type=100 called_party=86503945 sub= calling=10 dir=out complete=0 ses=0
534334mS CMTARGET: 0.1019.0 7 Christine.0: ADD TARGET (N): number=86503945 type=100 depth=1 nobar=1 setorig=1 ses=0
537334mS CMTARGET: 0.1019.0 7 Christine.0: TimerExpired cause=CMTCDelayedProcessing
537334mS CMTARGET: 0.1019.0 7 Christine.0: LOOKUP CALL ROUTE: type=100 called_party=86503945 sub= calling=10 dir=out complete=1 ses=0
537334mS CMTARGET: 0.1019.0 7 Christine.0: ADD TARGET (N): number=86503945 type=100 depth=1 nobar=1 setorig=1 ses=0
537335mS CMTARGET: 0.1019.0 7 Christine.0: USER SC: 86503945 3 6503945 sc=type=Dial code=8N;, num=N
537335mS CMARS: FindActiveARSByGroupID GroupID=0 - Not Found
537335mS CMLRQ: FindActiveLRQByGroupID GroupID=0 - Not Found
537335mS CMTARGET: Group Id: 0 has NOT been found in Line: 5
537335mS CMTARGET: Group Id: 0 has NOT been found in Line: 6
537336mS CMCallEvt: 0.1021.0 -1 BaseEP: NEW CMEndpoint f524b1c0 TOTAL NOW=3 CALL_LIST=1
537340mS CMTARGET: DIAL LINE: 7 GROUP = 0 SUCCESS = f524b1c0
537340mS CMTARGET: 0.1019.0 7 Christine.0: INITIAL TARGETING SUCCEEDED
537340mS CMTARGET: 0.1019.0 7 Christine.0: GetNoAnswerTimer:15
537340mS CMCallEvt: 0.1019.0 7 Christine.0: StateChange: END=A CMCSDialling->CMCSDialled
537340mS CMExtnEvt: v=1 State, new=Proceeding old=Dialling,0,0,Christine
537340mS CMExtnTx: v=10, p1=0
CMProceeding
Line: type=DigitalExtn 2 Call: lid=0 id=1019 in=0
Timed: 19/12/13 10:52
537341mS CMCallEvt: 0.1020.0 7 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering
537342mS CMCallEvt: 0.1021.0 7 Alog Trunk:3: StateChange: END=T CMCSIdle->CMCSOffering
537342mS CMLineTx: v=3
CMSetup
Line: type=AnalogueLine 3 Call: lid=0 id=1021 in=0
Called[6503945] Type=Unknown (0) Reason=CMDRdirect SndComp Calling[10] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=Christine
IE CMIECallingPartyKName (226)(Type=CMNameDefault) name=Christine
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=Christine
IE CMIERespondingPartyKName (229)(Type=CMNameDefault) name=Christine
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=10
IE CMIEDeviceDetail (231) LOCALE=aru HW=15 VER=8 class=CMDeviceStdPhone type=78 number=1 channel=0 rx_gain=32 tx_gain=32 ep_callid=1019 ipaddr=10.100.11.50 apps=0
IE CMIEMohSourceId (247) MOH Source = 255
Display [Christine>6503945]
Timed: 19/12/13 10:52
Locale: aru
537343mS CD: CALL: 0.1019.0 BState=Idle Cut=1 Music=0.0 Aend="Christine(10)" (0.1) Bend="Line 3" [Line 3] (0.0) CalledNum=86503945 () CallingNum=10 (Christine) Internal=0 Time=6524 AState=Dialled
537388mS CMLineRx: v=3
CMSetupAck
Line: type=AnalogueLine 3 Call: lid=0 id=1021 in=0
BChan: slot=1 chan=3
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=86503945
IE CMIEDeviceDetail (231) LOCALE=aru HW=15 VER=8 class=CMDeviceAlogTrunk type=0 number=3 channel=0 rx_gain=32 tx_gain=32 ep_callid=1021 ipaddr=10.100.11.50 apps=0
537389mS CMCallEvt: 0.1020.0 7 TargetingEP: RequestEnd 0.1021.0 7 Alog Trunk:3
537389mS CMTARGET: 0.1019.0 7 Christine.0: CancelTimer CMTCNoAnswerTimeout
537389mS CMCallEvt: 0.1020.0 -1 BaseEP: DELETE CMEndpoint f52538fc TOTAL NOW=2 CALL_LIST=1
537390mS CMCallEvt: 0.1021.0 7 Alog Trunk:3: StateChange: END=B CMCSOffering->CMCSOverlapRecv
537391mS CMLineRx: v=3
CMProceeding
Line: type=AnalogueLine 3 Call: lid=0 id=1021 in=0
BChan: slot=1 chan=3
IE CMIEProgressIndicator (30) cs=CMCSITUT (0), loc=CMLUser (0), pd=CMPDNotISDN (1)
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=86503945
IE CMIEDeviceDetail (231) LOCALE=aru HW=15 VER=8 class=CMDeviceAlogTrunk type=0 number=3 channel=0 rx_gain=32 tx_gain=32 ep_callid=1021 ipaddr=10.100.11.50 apps=0
537391mS CMCallEvt: 0.1021.0 7 Alog Trunk:3: StateChange: END=B CMCSOverlapRecv->CMCSAccept
537391mS CD: CALL: 0.1019.0 BState=Ringing Cut=3 Music=0.0 Aend="Christine(10)" (0.1) Bend="Line 3" [Line 3] (1.3) CalledNum=6503945 () CallingNum=10 (Christine) Internal=0 Time=6572 AState=Dialled
537392mS CMMap: PCG::MapBChan pcp[94]b1r0 cp_b f52a167c other_cp_b 0 type CGTypeSimple
537392mS CMMap: PCG::MapBChan pcp[80]b1r0 cp_b f59a1dd0 other_cp_b f52a167c type CGTypeSimple
537392mS CMMap: a=0.1 b=1.3 M12
537611mS RES: Thu 19/12/2013 10:52:34 FreeMem=60741692(2) CMMsg=3 (4) Buff=5200 954 999 12447 5 Links=7389 BTree=0 CPU=1/3/7322/19584/19703/2
537611mS RES2: IP 500 V2 8.1(65) Tasks=48 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=52 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=16 TAPI=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
537611mS RES4: XML MemObjs=45 PoolMem=2097152(1) FreeMem=2082064(1)
541342mS CD: CALL: 0.1019.0 BState=Ringing Cut=3 Music=0.0 Aend="Christine(10)" (0.1) Bend="Line 3" [Line 3] (1.3) CalledNum=6503945 () CallingNum=10 (Christine) Internal=0 Time=10523 AState=Dialled
541530mS CMLineRx: v=3
CMProgress
Line: type=AnalogueLine 3 Call: lid=0 id=1021 in=0
BChan: slot=1 chan=3
IE CMIEProgressIndicator (30) cs=CMCSITUT (0), loc=CMLUser (0), pd=CMPDNotISDN (1)
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=86503945
IE CMIEDeviceDetail (231) LOCALE=aru HW=15 VER=8 class=CMDeviceAlogTrunk type=0 number=3 channel=0 rx_gain=32 tx_gain=32 ep_callid=1021 ipaddr=10.100.11.50 apps=0
541530mS CMCallEvt: 0.1021.0 7 Alog Trunk:3: StateChange: END=B CMCSAccept->CMCSRinging
541530mS CMCallEvt: 0.1019.0 7 Christine.0: StateChange: END=A CMCSDialled->CMCSRingBack
541531mS CMExtnEvt: v=1 State, new=Alerting old=Proceeding,0,0,Christine
541532mS CMExtnTx: v=10, p1=0
CMProgress
Line: type=DigitalExtn 2 Call: lid=0 id=1019 in=0
IE CMIEProgressIndicator (30) cs=CMCSITUT (0), loc=CMLUser (0), pd=CMPDNotISDN (1)
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=86503945
IE CMIEDeviceDetail (231) LOCALE=aru HW=15 VER=8 class=CMDeviceAlogTrunk type=0 number=3 channel=0 rx_gain=32 tx_gain=32 ep_callid=1021 ipaddr=10.100.11.50 apps=0
Timed: 19/12/13 10:52
541532mS CMLineRx: v=3
CMAlerting
Line: type=AnalogueLine 3 Call: lid=0 id=1021 in=0
BChan: slot=1 chan=3
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=86503945
IE CMIEDeviceDetail (231) LOCALE=aru HW=15 VER=8 class=CMDeviceAlogTrunk type=0 number=3 channel=0 rx_gain=32 tx_gain=32 ep_callid=1021 ipaddr=10.100.11.50 apps=0
541533mS CMLineRx: v=3
CMConnect
Line: type=AnalogueLine 3 Call: lid=0 id=1021 in=0
BChan: slot=1 chan=3
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=86503945
IE CMIEDeviceDetail (231) LOCALE=aru HW=15 VER=8 class=CMDeviceAlogTrunk type=0 number=3 channel=0 rx_gain=32 tx_gain=32 ep_callid=1021 ipaddr=10.100.11.50 apps=0
541533mS CMCallEvt: 0.1021.0 7 Alog Trunk:3: StateChange: END=B CMCSRinging->CMCSConnReq
541533mS CMCallEvt: 0.1019.0 7 Christine.0: StateChange: END=A CMCSRingBack->CMCSOGConnReq
541533mS CMExtnEvt: v=1 State, new=Connected old=Alerting,0,0,Christine
541533mS CMExtnTx: v=10, p1=0
CMConnect
Line: type=DigitalExtn 2 Call: lid=0 id=1019 in=0
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=86503945
IE CMIEDeviceDetail (231) LOCALE=aru HW=15 VER=8 class=CMDeviceAlogTrunk type=0 number=3 channel=0 rx_gain=32 tx_gain=32 ep_callid=1021 ipaddr=10.100.11.50 apps=0
Timed: 19/12/13 10:52
541534mS CMExtnRx: v=10, p1=0
CMConnectAck
Line: type=DigitalExtn 2 Call: lid=0 id=1019 in=0
541534mS CMCallEvt: 0.1019.0 7 Christine.0: StateChange: END=A CMCSOGConnReq->CMCSConnected
541534mS CMTARGET: 0.1019.0 7 Christine.0: ~CMTargetHandler f524da10 ep f52552b4
541535mS CMCallEvt: 0.1021.0 7 Alog Trunk:3: StateChange: END=B CMCSConnReq->CMCSConnected
541536mS CMLineTx: v=3
CMConnectAck
Line: type=AnalogueLine 3 Call: lid=0 id=1021 in=0
BChan: slot=0 chan=1
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=Christine
IE CMIERespondingPartyKName (229)(Type=CMNameDefault) name=Christine
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=10
IE CMIEDeviceDetail (231) LOCALE=aru HW=15 VER=8 class=CMDeviceStdPhone type=78 number=1 channel=0 rx_gain=32 tx_gain=32 ep_callid=1019 ipaddr=10.100.11.50 apps=0
541536mS CD: CALL: 0.1019.0 BState=Connected Cut=3 Music=0.0 Aend="Christine(10)" (0.1) Bend="Line 3" [Line 3] (1.3) CalledNum=6503945 () CallingNum=10 (Christine) Internal=0 Time=10717 AState=Connected
546322mS CMLineRx: v=3
CMReleaseComp
Line: type=AnalogueLine 3 Call: lid=0 id=1021 in=0
BChan: slot=1 chan=3
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=86503945
IE CMIEDeviceDetail (231) LOCALE=aru HW=15 VER=8 class=CMDeviceAlogTrunk type=0 number=3 channel=0 rx_gain=32 tx_gain=32 ep_callid=1021 ipaddr=10.100.11.50 apps=0
Cause=16, Normal call clearing
546323mS CMCallEvt: 0.1021.0 7 Alog Trunk:3: StateChange: END=B CMCSConnected->CMCSCompleted
546324mS CMLOGGING: CALL:2013/12/1910:52,00:00:04,000,10,O,6503945,86503945,Christine,,,0,,""n/a,0
546324mS CD: CALL: 0.1019.0 BState=Disconnecting Cut=1 Music=0.0 Aend="Christine(10)" (0.1) Bend="Line 3" [Line 3] (1.3) CalledNum=6503945 () CallingNum=10 (Christine) Internal=0 Time=15505 AState=Connected
546325mS CD: CALL: 0.1019.0 Deleted
546325mS CMExtnEvt: Christine: CALL LOST (CMCauseNormal)
546325mS CMExtnEvt: Christine: Extn(10) Calling Party Number(10) Type(CMNTypeInternal)
546326mS CMCallEvt: 0.1019.0 -1 Christine.0: StateChange: END=X CMCSConnected->CMCSCompleted
546326mS CMExtnEvt: v=1 State, new=PortRecoverDelay old=Connected,0,0,Christine
546327mS CMExtnTx: v=10, p1=0
CMReleaseComp
Line: type=DigitalExtn 2 Call: lid=0 id=1019 in=0
Called[86503945] Type=Default (100) Reason=CMDRdirect Calling[10] Type=Internal Plan=Default
Cause=16, Normal call clearing
Timed: 19/12/13 10:52
546327mS CMExtnEvt: Christine: CMExtnHandler::SetCurrent( id: 1019->0 )
546327mS CMCallEvt: 0.1019.0 -1 Christine.-1: StateChange: END=X CMCSCompleted->CMCSDelete
546328mS CMCallEvt: 0.1019.0 -1 BaseEP: DELETE CMEndpoint f52552b4 TOTAL NOW=1 CALL_LIST=0
546328mS CMCallEvt: 0.1021.0 -1 Alog Trunk:3: StateChange: END=X CMCSCompleted->CMCSDelete
546329mS CMCallEvt: END CALL:7 (f5254dc8)
546329mS CMCallEvt: 0.1021.0 -1 BaseEP: DELETE CMEndpoint f524b1c0 TOTAL NOW=0 CALL_LIST=0
546330mS CMMap: PCG::UnmapBChan pcp[94]b1r0 cp_b f52a167c other_cp_b f59a1dd0
546330mS CMMap: a=1.3 b=0.1 M02
546331mS CMMap: PCG::UnmapBChan pcp[80]b1r0 cp_b f59a1dd0 other_cp_b 0
546614mS RES: Thu 19/12/2013 10:52:43 FreeMem=60766768(2) CMMsg=3 (4) Buff=5200 954 999 12447 5 Links=7398 BTree=0 CPU=2/4/7322/19506/19703/2
546614mS RES2: IP 500 V2 8.1(65) Tasks=48 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=52 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=16 TAPI=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
546614mS RES4: XML MemObjs=45 PoolMem=2097152(1) FreeMem=2082064(1)
548327mS CMExtnEvt: Christine: Recover Timer reason=CMTRWrapUp
548327mS CMExtnEvt: v=1 State, new=Idle old=PortRecoverDelay,0,0,Christine
548328mS CMExtnTx: v=10, p1=0
CMVoiceMailStatus
Line: type=DigitalExtn 2 Call: lid=0 id=-1 in=0
Called[Christine Msgs=4 Old=0 Sav=0] Type=Default (100) Reason=CMDRdirect Calling[00000004] Type=Default Plan=Default
Display [Christine Msgs=4]
Timed: 19/12/13 10:52

********** SysMonitor v10.1 (67) [connected to 10.100.11.50 (FOSS-AUH)] **********
567862mS PRN: Monitor Status IP 500 V2 8.1(65)
567862mS PRN: LAW=A PRI=0, BRI=2, ALOG=4, VCOMP=20, MDM=0, WAN=0, MODU=0 LANM=0 CkSRC=0 VMAIL=1(VER=2 TYP=3) 1-X=0 CALLS=0(TOT=7)
606369mS CMExtnEvt: Christine: No user activity

 

[g18c]

Snipping the log i can see it connected ringing the other party twice, then disconnects with code 16, normal. My disconnect clear is set to 90ms.

Strangest of all if this were a normal trunk issue it would do it for all calls - but this only happens on some numbers.

IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=86503945
IE CMIEDeviceDetail (231) LOCALE=aru HW=15 VER=8 class=CMDeviceAlogTrunk type=0 number=3 channel=0 rx_gain=32 tx_gain=32 ep_callid=1021 ipaddr=10.100.11.50 apps=0
Cause=16, Normal call clearing
546323mS CMCallEvt: 0.1021.0 7 Alog Trunk:3: StateChange: END=B CMCSConnected->CMCSCompleted
546324mS CMLOGGING: CALL:2013/12/1910:52,00:00:04,000,10,O,6503945,86503945,Christine,,,0,,""n/a,0
546324mS CD: CALL: 0.1019.0 BState=Disconnecting Cut=1 Music=0.0 Aend="Christine(10)" (0.1) Bend="Line 3" [Line 3] (1.3) CalledNum=6503945 () CallingNum=10 (Christine) Internal=0 Time=15505 AState=Connected
546325mS CD: CALL: 0.1019.0 Deleted
546325mS CMExtnEvt: Christine: CALL LOST (CMCauseNormal)
546325mS CMExtnEvt: Christine: Extn(10) Calling Party Number(10) Type(CMNTypeInternal)
546326mS CMCallEvt: 0.1019.0 -1 Christine.0: StateChange: END=X CMCSConnected->CMCSCompleted
546326mS CMExtnEvt: v=1 State, new=PortRecoverDelay old=Connected,0,0,Christine
546327mS CMExtnTx: v=10, p1=0
CMReleaseComp
Line: type=DigitalExtn 2 Call: lid=0 id=1019 in=0
Called[86503945] Type=Default (100) Reason=CMDRdirect Calling[10] Type=Internal Plan=Default
Cause=16, Normal call clearing

 

[g18c]

*bump* any chance of someones opinion on what could be going on here with the above trace? Thanks in advance guys, appreciate the help so far.

 

[tlpeter]

Your trace is not complete.
It already starts with call ended.
Provide a trace from the beginning of this call till the end.


BAZINGA!

I'm not insane, my mother had me tested!

 

[g18c]

Hi @tlpeter, full trace is above the snipped post, 19 Dec 13 2:05 - that shows everything before the handset is even lifted.

 

[tlpeter]

How could i have missed that
I do not see any odd stuff in the trace.
I do see it is using slot 3 on card 1 which is a ATM card.
Can you use a normal analog phone and dial the number on the analog trunk itself?
If not then it is not the IPO.
If you can then you need to find out why it does not work


BAZINGA!

I'm not insane, my mother had me tested!

 

[amriddle01]

You have also missed that he has already tried that, and he can make calls while directly connected to the trunk

 

[tlpeter]

Ok, i will get some coffee right now.
Some more questions (even if this is already mentioned)
Does the user has user shortcodes for dialing?
What is the shortcode in the the ARS?
What are the system shortcodes for outbound dialing?
Is there a line shortcode configured and if yes, what is it?
Are there any user rights configured with shortcodes?

The system checks shortcodes in this order:

1 line shortcodes
2 user right shortcodes
3 user shortcodes
4 system shortcodes.

Somewhere in there it must go wrong if it is a system problem.


BAZINGA!

I'm not insane, my mother had me tested!

 

[g18c]

Thanks for the time, i had stronger than coffee last night from the headache of this project

There are no system shortcodes for dialing (the ? . default was deleted), they are all defined in user rights shortcodes (they want to restrict who can dial).

Users dont have shortcodes defined, they are inherited from applying user group rights.

I setup the user rights shortcodes to dial directly to the trunk (for testing) and bypassing the ARS. The shortcode is 8N; => dial N, trunkgroup 0. I also tried 8N => N and also ? => . same thing each time.

I am using analog trunks, i don't think they have line shortcodes - I've certainly not set anything other than the above and i've used the same setup on tons of other sites. On the BRI cards (that are not in use, they are in a different trunkgroup 1, no line short codes are defined).

Only trunks enabled in trunkgroup 0 are the analog trunks, they have 3 trunks active, 4th is disabled. Same issue happens regardless of trunk that is selected.

From the user perspective, the call actually connects to the trunk line and we can hearing ringing (verified as per the call status, correct number is being sent too), it rings twice, then automatically hangs up!

Calling the same number with a $5 analog handset the call goes through fine without any issue and continues to ring until the other side answer (or not!)... it certainly doesn't hang up after 2 rings.

 

[tlpeter]

Then i am out of option as we only do SIP or ISDN over here.
Analog trunks are getting rare for a PBX.


BAZINGA!

I'm not insane, my mother had me tested!