Cannot make outgoing calls thru Analog trunks randomly

[clarkstyx18]

We have 4 analog trunks, most of the time we can make calls but there are some instance wherein we cannot make outgoing calls, at first, I though it was line impedance issue so I ran tests on all the lines selecting the best matched impendance. I also tried resetting the settings to factory default but still we cant make outgoing calls on some lines. The problem with outgoing call is random, by looking at system status, and dialling thru those 4 lines over and over again, I can see that the issue is not with a specific line, it keeps on jumping to another line, example, sometimes I can make a call through line 1, after several attempt, I cant make outgoing anymore.. here is the monitor log below:


939217mS PRN: 711: Feature Key Pressed 3
939237mS RES: Sun 20/5/2012 09:48:24 FreeMem=68597684(1) CMMsg=5 (6) Buff=5200 946 858 7447 5 Links=5124
939238mS RES2: IP 500 V2 6.1(22) Tasks=42 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=72 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 SSA=1 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
939367mS CMCallEvt: 0.1170.0 -1 BaseEP: NEW CMEndpoint f5363338 TOTAL NOW=1 CALL_LIST=0
939368mS CMCallEvt: 0.1170.0 -1 Clark.-1: NEW CMExtnEndpoint f5363338, Name=Clark, Extn=711, Phys Extn=711
939368mS CMCallEvt: CREATE CALL:53 (f5362edc)
939368mS CMCallEvt: 0.1171.0 -1 BaseEP: NEW CMEndpoint f5361ac8 TOTAL NOW=2 CALL_LIST=0
939369mS CMExtnEvt: Clark: CMExtnHandler::SetCurrent( id: 0->1170 )
939369mS CMExtnEvt: v=2 State, new=Idle old=PortRecoverDelay,0,0,Clark
939371mS CMExtnRx: v=711, p1=0
CMSetup
Line: type=DigitalExtn 2 Call: lid=0 id=1170 in=0
Called[9155] Type=Default (100) Reason=CMDRdirect Calling[711] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=Clark
IE CMIECallingPartyKName (226)(Type=CMNameDefault) name=Clark
939371mS CMCallEvt: 0.1170.0 53 Clark.0: StateChange: END=A CMCSIdle->CMCSDialInitiated
939371mS CMExtnEvt: v=2 State, new=Dialling old=Idle,0,0,Clark
939372mS CMTARGET: 0.1170.0 53 Clark.0: LOOKUP CALL ROUTE: type=100 called_party=9155 sub= calling=711 dir=out complete=0 ses=0
939372mS CMTARGET: 0.1170.0 53 Clark.0: ADD TARGET (N): number=9155 type=100 depth=1 nobar=1 setorig=1 ses=0
939372mS CMTARGET: 0.1170.0 53 Clark.0: USER SC: 9155 2 155 sc=type=Dial code=9N, num=N
939373mS CMARS: FindActiveARSByGroupID GroupID=0 - Not Found
939373mS CMLRQ: FindActiveLRQByGroupID GroupID=0 - Not Found
939373mS CMTARGET: Group Id: 0 has NOT been found in Line: 1
939373mS CMTARGET: Group Id: 0 has NOT been found in Line: 2
939374mS CMTARGET: Problem with Line Id: 19 - check_DNS 1 OperationalTest: 0, IP address: 192.168.2.100
939374mS CMTARGET: Problem with Line Id: 20 - check_DNS 1 OperationalTest: 0, IP address: 192.168.2.25
939374mS ATMCMLine: [8] MakeTarget() line_group_id=0
939374mS ATMCMLine: [8] ReleaseCompleteTimer(OK)
939374mS CMCallEvt: 0.1172.0 -1 BaseEP: NEW CMEndpoint f535a9c0 TOTAL NOW=3 CALL_LIST=1
939376mS ATMCMLine: [8] MakeTarget() returned: 0.1172.0 53 Alog Trunk:8
939376mS CMTARGET: DIAL LINE: 53 GROUP = 0 SUCCESS = f535a9c0
939377mS CMTARGET: 0.1170.0 53 Clark.0: CancelTimer CMTCDialToneTimeout
939377mS CMTARGET: 0.1170.0 53 Clark.0: INITIAL TARGETING SUCCEEDED
939377mS CMTARGET: 0.1170.0 53 Clark.0: GetNoAnswerTimer:18
939377mS CMCallEvt: 0.1170.0 53 Clark.0: StateChange: END=A CMCSDialInitiated->CMCSDialling
939378mS CMExtnTx: v=711, p1=0
CMSetupAck
Line: type=DigitalExtn 2 Call: lid=0 id=1170 in=0
BChan: slot=0 chan=5
Timed: 20/05/12 09:48
939378mS CMCallEvt: 0.1171.0 53 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering
939379mS CMCallEvt: 0.1172.0 53 Alog Trunk:8: StateChange: END=T CMCSIdle->CMCSOffering
939379mS CMLineTx: v=8
CMSetup
Line: type=AnalogueLine 8 Call: lid=0 id=1172 in=0
Called[155] Type=Unknown (0) Reason=CMDRdirect Calling[711] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
BChan: slot=0 chan=5
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=Clark
IE CMIECallingPartyKName (226)(Type=CMNameDefault) name=Clark
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=Clark
IE CMIERespondingPartyKName (229)(Type=CMNameDefault) name=Clark
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=711
IE CMIEDeviceDetail (231) LOCALE=ara HW=15 VER=6 class=CMDeviceStdPhone type=26 number=2 channel=0 rx_gain=32 tx_gain=32 ep_callid=1170 ipaddr=192.168.2.201 apps=0
IE CMIEMohSourceId (247) MOH Source = 255
Display [Clark>155]
Timed: 20/05/12 09:48
Locale: ara
939379mS ATMCMLine: [8] line_group_id=0, CMLinkLayer=CmLlIdle, direction ok
939380mS ATMCMLine: [8] bearer(2) compatibility ok - can make call
939380mS ATMCMLine: [8] StateChange Idle->Initiated
939380mS ATMCMLine: [8] CMLinkLayer Tx: 'Seize'
939381mS CD: CALL: 0.1170.0 BState=Idle Cut=0 Music=0.0 Aend="Clark(711)" (0.5) Bend="Line 8" [Line 8] (0.0) CalledNum=9155 () CallingNum=711 (Clark) Internal=0 Time=13 AState=Dialling
939382mS ATMChannel: [8] CMLinkLayer Rx: 'Seize' (ls)
939382mS ATMIO: [8] BLOCK FORWARDING ON
939382mS ATMIO: [8] TRUNK SEIZE
939382mS ATMChannel: [8] StateChange Idle->Seizing
939436mS ATMChannel: [8] External Rx: 'Seized' (ls)
939436mS ATMChannel: [8] CMLinkLayer Tx: 'SetupAck'
939436mS ATMIO: [8] CLI DETECTION OFF, EQUALISER OFF
939436mS ATMChannel: [8] StateChange Seizing->AwaitDialTone
939437mS ATMCMLine: [8] CMLinkLayer Rx: 'SetupAck' callid=(lid=0, id=1172, in=1)
939437mS ATMCMLine: [8] CM Tx: 'CMSetupAck' callid=(lid=0, id=1172, in=0)
939437mS CMLineRx: v=8
CMSetupAck
Line: type=AnalogueLine 8 Call: lid=0 id=1172 in=0
BChan: slot=3 chan=4
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=9155
IE CMIEDeviceDetail (231) LOCALE=ara HW=15 VER=6 class=CMDeviceAlogTrunk type=0 number=8 channel=0 rx_gain=32 tx_gain=32 ep_callid=1172 ipaddr=192.168.2.201 apps=0
939437mS CMCallEvt: 0.1171.0 53 TargetingEP: RequestEnd 0.1172.0 53 Alog Trunk:8
939438mS CMTARGET: 0.1170.0 53 Clark.0: CancelTimer CMTCNoAnswerTimeout
939438mS CMCallEvt: 0.1171.0 -1 BaseEP: DELETE CMEndpoint f5361ac8 TOTAL NOW=2 CALL_LIST=1
939439mS CMCallEvt: 0.1172.0 53 Alog Trunk:8: StateChange: END=B CMCSOffering->CMCSOverlapRecv
939439mS ATMCMLine: [8] ControlEchoCancellation ON
939439mS ATMCMLine: [8] CMLinkLayer Tx: 'EchoControl'
939440mS CD: CALL: 0.1170.0 BState=Idle Cut=2 Music=0.0 Aend="Clark(711)" (0.5) Bend="Line 8" [Line 8] (3.4) CalledNum=155 () CallingNum=711 (Clark) Internal=0 Time=72 AState=Dialling
939440mS ATMChannel: [8] CMLinkLayer Rx: 'EchoControl' (ls)
939441mS ATMIO: [8] ECHO CANCELLATION ON
939441mS CMMap: PCG::MapBChan pcp[93]b1r0 cp_b f554cd3c other_cp_b 0 type CGTypeSimple
939441mS CMMap: PCG::MapBChan pcp[85]b1r0 cp_b f59c1aac other_cp_b f554cd3c type CGTypeSimple
939441mS CMMap: a=0.5 b=3.4 M1
940380mS ATMCMLine: 0.1172.0 53 Alog Trunk:8 ReportTargetTimer
941017mS ATMChannel: [7] Sloppy timeout(2000ms)
941017mS ATMIO: [7] TRUNK RELEASE (no line dropped)
941017mS ATMChannel: [7] StateChange Releasing->Idle
941017mS ATMIO: [7] ECHO CANCELLATION OFF
941017mS ATMIO: [7] BLOCK FORWARDING OFF
941017mS ATMChannel: [7] CMLinkLayer Tx: 'Idle'
941018mS ATMCMLine: [7] CMLinkLayer Rx: 'Idle' callid=(lid=0, id=0, in=1)
941018mS ATMCMLine: [7] StateChange DiscReq->Idle
941018mS ATMCMLine: [7] Dumping: 'CMReleaseComp' callid=(lid=0, id=1169, in=0)
942437mS ATMChannel: [8] Sloppy timeout(3000ms)
942437mS ATMChannel: [8] StateChange AwaitDialTone->Connected
942437mS ATMChannel: [8] CMLinkLayer Tx: 'StartDial'
942437mS ATMCMLine: [8] CMLinkLayer Rx: 'StartDial' callid=(lid=0, id=1172, in=1)
942438mS ATMCMLine: [8] StateChange Initiated->OverlapSend
942438mS ATMCMLine: [8] CMLinkLayer Tx: 'DialDigits'
942439mS ATMChannel: [8] CMLinkLayer Rx: 'DialDigits' (ls)
942439mS ATMIO: [8] TONE DIAL (3 digits)
942439mS ATMChannel: [8] StateChange Connected->ToneDialing
942937mS ATMChannel: [8] Sloppy timeout(495ms)
942937mS ATMIO: [8] BLOCK FORWARDING OFF
942937mS ATMChannel: [8] StateChange ToneDialing->Connected
942937mS ATMChannel: [8] CMLinkLayer Tx: 'DigitsDone'
942937mS ATMChannel: [8] CMLinkLayer Tx: 'LineAnswer'
942938mS ATMCMLine: [8] CMLinkLayer Rx: 'DigitsDone' callid=(lid=0, id=1172, in=1)
942938mS ATMCMLine: [8] StateChange OverlapSend->Active
942938mS ATMCMLine: [8] CM Tx: 'CMProgress' callid=(lid=0, id=1172, in=0)
942938mS CMLineRx: v=8
CMProgress
Line: type=AnalogueLine 8 Call: lid=0 id=1172 in=0
BChan: slot=3 chan=4
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=9155
IE CMIEDeviceDetail (231) LOCALE=ara HW=15 VER=6 class=CMDeviceAlogTrunk type=0 number=8 channel=0 rx_gain=32 tx_gain=32 ep_callid=1172 ipaddr=192.168.2.201 apps=0
942939mS CMCallEvt: 0.1172.0 53 Alog Trunk:8: StateChange: END=B CMCSOverlapRecv->CMCSAccept
942939mS CMCallEvt: 0.1170.0 53 Clark.0: StateChange: END=A CMCSDialling->CMCSRingBack
942940mS CMExtnEvt: v=2 State, new=Alerting old=Dialling,0,0,Clark
942940mS CMExtnTx: v=711, p1=0
CMProgress
Line: type=DigitalExtn 2 Call: lid=0 id=1170 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=9155
IE CMIEDeviceDetail (231) LOCALE=ara HW=15 VER=6 class=CMDeviceAlogTrunk type=0 number=8 channel=0 rx_gain=32 tx_gain=32 ep_callid=1172 ipaddr=192.168.2.201 apps=0
Timed: 20/05/12 09:48
942941mS ATMCMLine: [8] CM Tx: 'CMAlerting' callid=(lid=0, id=1172, in=0)
942941mS CMLineRx: v=8
CMAlerting
Line: type=AnalogueLine 8 Call: lid=0 id=1172 in=0
BChan: slot=3 chan=4
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=9155
IE CMIEDeviceDetail (231) LOCALE=ara HW=15 VER=6 class=CMDeviceAlogTrunk type=0 number=8 channel=0 rx_gain=32 tx_gain=32 ep_callid=1172 ipaddr=192.168.2.201 apps=0
942941mS CMCallEvt: 0.1172.0 53 Alog Trunk:8: StateChange: END=B CMCSAccept->CMCSRinging
942942mS CMExtnTx: v=711, p1=0
CMProgress
Line: type=DigitalExtn 2 Call: lid=0 id=1170 in=0
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=9155
IE CMIEDeviceDetail (231) LOCALE=ara HW=15 VER=6 class=CMDeviceAlogTrunk type=0 number=8 channel=0 rx_gain=32 tx_gain=32 ep_callid=1172 ipaddr=192.168.2.201 apps=0
IE CMIEProgressIndicator (30) cs=CMCSITUT (0), loc=CMLUser (0), pd=CMPDInbandPattern (8)
Timed: 20/05/12 09:48
942942mS ATMCMLine: [8] CMLinkLayer Rx: 'LineAnswer' callid=(lid=0, id=1172, in=1)
942942mS ATMCMLine: [8] CM Tx: 'CMConnect' callid=(lid=0, id=1172, in=0)
942943mS CMLineRx: v=8
CMConnect
Line: type=AnalogueLine 8 Call: lid=0 id=1172 in=0
BChan: slot=3 chan=4
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=9155
IE CMIEDeviceDetail (231) LOCALE=ara HW=15 VER=6 class=CMDeviceAlogTrunk type=0 number=8 channel=0 rx_gain=32 tx_gain=32 ep_callid=1172 ipaddr=192.168.2.201 apps=0
942943mS CMCallEvt: 0.1172.0 53 Alog Trunk:8: StateChange: END=B CMCSRinging->CMCSConnReq
942943mS CMCallEvt: 0.1170.0 53 Clark.0: StateChange: END=A CMCSRingBack->CMCSOGConnReq
942943mS CMExtnEvt: v=2 State, new=Connected old=Alerting,0,0,Clark
942944mS CMExtnTx: v=711, p1=0
CMConnect
Line: type=DigitalExtn 2 Call: lid=0 id=1170 in=0
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=9155
IE CMIEDeviceDetail (231) LOCALE=ara HW=15 VER=6 class=CMDeviceAlogTrunk type=0 number=8 channel=0 rx_gain=32 tx_gain=32 ep_callid=1172 ipaddr=192.168.2.201 apps=0
Timed: 20/05/12 09:48
942944mS CMExtnRx: v=711, p1=0
CMConnectAck
Line: type=DigitalExtn 2 Call: lid=0 id=1170 in=0
942944mS CMCallEvt: 0.1170.0 53 Clark.0: StateChange: END=A CMCSOGConnReq->CMCSConnected
942944mS CMTARGET: 0.1170.0 53 Clark.0: ~CMTargetHandler f5351440 ep f5363338
942945mS CMCallEvt: 0.1172.0 53 Alog Trunk:8: StateChange: END=B CMCSConnReq->CMCSConnected
942946mS CMLineTx: v=8
CMConnectAck
Line: type=AnalogueLine 8 Call: lid=0 id=1172 in=0
BChan: slot=0 chan=5
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=Clark
IE CMIERespondingPartyKName (229)(Type=CMNameDefault) name=Clark
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=711
IE CMIEDeviceDetail (231) LOCALE=ara HW=15 VER=6 class=CMDeviceStdPhone type=26 number=2 channel=0 rx_gain=32 tx_gain=32 ep_callid=1170 ipaddr=192.168.2.201 apps=0
943380mS ATMCMLine: 0.1172.0 53 Alog Trunk:8 ReportTargetTimer
943380mS CD: CALL: 0.1170.0 BState=Connected Cut=3 Music=0.0 Aend="Clark(711)" (0.5) Bend="Line 8" [Line 8] (3.4) CalledNum=155 () CallingNum=711 (Clark) Internal=0 Time=4012 AState=Connected

 

[clarkstyx18]

any solutions?

 

[intrigrant]

It is sunday and most of us are having breakfast with the family and have croissants and jus 'd orange, tomorrow you might get a answer ( or not as we here do NOT use analog trunks anymore since the millenium change ).

If it ain't dutch it ain't much

 

[amriddle01]

Sloppy timeouts on the trunks, disconnect clear issue I think

 

[clarkstyx18]

@intrigrant , oh yeah, I forgot its Sunday today, for us its the first day of the week here in Dubai

 

[clarkstyx18]

@amriddle - disconnect clear is checked and is set to 90ms.. does it also affect outgoing calls?

 

[amriddle01]

90 ms, that seems rather short.. it will effect outgoing if the trunks are tied up doing nothing

 

[clarkstyx18]

Ive changed it to 500ms and its still the same.. any other suggestions?>

 

[snowman50]

check each line before the system with a BUTT set in case you have an issue with the TELCO lines.

I have had issues in the past on other systems with a fault on the line itself.

Test each line and make sure you can call from them before the system

 

[clarkstyx18]

@snowman - i dont have Butt set so I am using just regular analog telephones to test each lines, is it sufficient? or I really need a butt set to test it properly, where can I get it? any brand you suggest?