Waiting-for-Line on Analog Lines

[BobBamburg]

I have an IP500 with 4 Analog Lines. When Dialing Out, I enter 9 and the number and SOMETIMES I get "Waiting-For-Line" and a beep. After a few seconds, the system will go ahead and dial. Other times, it dials immediately.

This is a new install, pretty much right out of the box runing 4.0(5).


Does anyone know why this happens?

 

[ProviderReborn]

Could be one of a few things.

-Either you have 4 people on the line, so system is waiting for free line.

-Some thing has not set right in your ARS/Outgoing line group ID.

-Or your lines are not clearing down quick enough from previous calls.

Get a look in call status and see what you have happening call wise when you get the issue you mention.

If nothing perhaps you may wish to provide some monitor information

ACA - IP Office Implement
ACA - IP Telephony
ACS - IP Office Implement (Aug 30th)

 

[BobBamburg]

I am the only one using the phone at this time.
This is the first call after a reboot and it did it.
Here is some of the log. Hope it helps.

*********************************************************

2570316mS CMARS: FORM: Main - Received Number: 8236225555
2570317mS CMARS: FOUND A SHORT CODE - short_code: xxxxxxxxxxN - Tel: N - Called_Party: 8236225555 - Line Group Id: 0
2570317mS CMARS: CMARSHandler::FindActiveARSByGroupID GroupID=0
2570318mS CMARS: FOUND LINE - Line Id: 10 - using line group id: 0 - Called Number: 8236225555 - Calling Number: 8204
2570318mS CMARS: SEND Setup TO LINE
2570319mS CMLineTx: v=10
CMSetup
Line: type=AnalogueLine 10 Call: lid=0 id=1041 in=0
Called[8236225555] Type=Default (100) Reason=CMDRdirect Calling[8204] Type=Internal Plan=Default
BC: CMTC=3K1Audio CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
IE CMIECallingPartyName (110) Marsha
Locale: enu
2570319mS CD: CALL: 0.1038.0 State=0 Cut=2 Music=0.0 Aend="Marsha(8204)" (20.4) Bend="" [Line 10] (0.0) CalledNum=8236225555 () CallingNum=8204 (Marsha) Internal=1 Time=3979 AState=7
2570634mS RES: Thu 20/9/2007 13:45:48 FreeMem=84232500(7) CMMsg=4 (5) Buff=200 963 998 7198 5 Links=445
2574319mS CD: CALL: 0.1038.0 State=0 Cut=2 Music=0.0 Aend="Marsha(8204)" (20.4) Bend="" [Line 10] (0.0) CalledNum=8236225555 () CallingNum=8204 (Marsha) Internal=1 Time=7979 AState=7
2575320mS PRN: Windowed EchoCancellation stopped: chunnel=1, command= 0x501
2575321mS CMLineRx: v=10
CMReleaseComp
Line: type=AnalogueLine 10 Call: lid=0 id=1041 in=0
BChan: slot=5 chan=2
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=8236225555
IE CMIEDeviceDetail (231) LOCALE=enu HW=8 VER=4 class=CMDeviceAlogTrunk type=0 number=10 channel=0 gain=0
2575321mS CMARS: LINE ep Received: CMReleaseComp - child->state = CMCSOffering - ARS Call State = CMCSOverlapRecv
2575322mS CMARS: Target: Short_Code: xxxxxxxxxxN - Line_Group_ID: 0 has been set to: CMARS_OUTOFSERVICE
2575323mS CMExtnTx: v=8204, p1=0
CMProgress
Line: type=DigitalExtn 2 Call: lid=0 id=1038 in=0
IE CMIEProgressIndicator (30) cs=CMCSITUT (0), loc=CMLUser (0), pd=CMPDInbandPattern (8)
Display [WAITING FOR LINE]
Timed: 20/09/07 13:45
2575323mS CD: CALL: 0.1038.0 State=1 Cut=3 Music=0.0 Aend="Marsha(8204)" (20.4) Bend="" [] (0.0) CalledNum=8236225555 () CallingNum=8204 (Marsha) Internal=1 Time=8983 AState=1
2575634mS RES: Thu 20/9/2007 13:45:53 FreeMem=84237460(9) CMMsg=4 (5) Buff=200 963 998 7198 5 Links=445
2576322mS CMARS: Retarget existing BUSY targets - Num of Busy Targets: 1 - Current Form: Main
2576322mS CMMap: a=21.7 b=0.0 DTMF::AllocateRAS allocated CMRTTonegen resource busy 5, total 8
2576322mS CMMap: a=21.7 b=1.255 T
2576323mS CMMap: PCG::MapBChan pcp[74]b1r0 cp_b f5ddf856 other_cp_b f5e2bfe6 type CGTypeDTMF
2576323mS CMMap: a=21.7 b=20.4 M2
2576323mS CMMap: DTMF:layTones g T[20] ,EEEEE
2576323mS CMMap: Started playing tones, cp[74]b1r0 (from g null)
2576323mS CMMap: cp[74]b1r0 SetOperGroup from g null to g null not executed, playing tones in progress ,EEEEE
2578144mS CMMap: PCG::UnmapBChan pcp[74]b1r0 cp_b f5ddf856 other_cp_b f5e2bfe6
2578144mS CMMap: a=21.7 b=20.4 M0
2578144mS CMMap: a=21.7 b=0.0 T0
2578144mS CMMap: a=21.7 b=0.0 DTMF::~DTMF freed CMRTTonegen resource busy 4, total 8
2582322mS CMARS: Retarget existing BUSY targets - Num of Busy Targets: 1 - Current Form: Main
2582322mS CMARS: Target: Short_Code: xxxxxxxxxxN - Line_Group_ID: 0 - Telephone_Number: N - Line_Status: CMARS_OUTOFSERVICE
2582323mS CMARS: FOUND LINE - Line Id: 11 - using line group id: 0 - Short Code: xxxxxxxxxxN - Called Number: 8236225555 - Calling Number: 8204
2582323mS CMARS: Retarget result=SEND Setup TO LINE
2582324mS CMLineTx: v=11
CMSetup
Line: type=AnalogueLine 11 Call: lid=0 id=1042 in=0
Called[8236225555] Type=Default (100) Reason=CMDRdirect Calling[8204] Type=Internal Plan=Default
BC: CMTC=3K1Audio CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
IE CMIECallingPartyName (110) Marsha
Locale: enu
2582324mS CD: CALL: 0.1038.0 State=1 Cut=3 Music=0.0 Aend="Marsha(8204)" (20.4) Bend="" [Line 11] (0.0) CalledNum=8236225555 () CallingNum=8204 (Marsha) Internal=1 Time=15984 AState=1
2582325mS CMMap: a=21.7 b=0.0 DTMF::AllocateRAS allocated CMRTTonegen resource busy 5, total 8
2582325mS CMMap: a=21.7 b=1.255 T
2582325mS CMMap: PCG::MapBChan pcp[74]b1r0 cp_b f5ddf856 other_cp_b f5e2bfe6 type CGTypeDTMF
2582325mS CMMap: a=21.7 b=20.4 M2
2582326mS CMMap: DTMF:layTones g T[21] ,EEEEE
2582326mS CMMap: Started playing tones, cp[74]b1r0 (from g null)
2582326mS CMMap: cp[74]b1r0 SetOperGroup from g null to g null not executed, playing tones in progress ,EEEEE
2582375mS CMLineRx: v=11
CMSetupAck
Line: type=AnalogueLine 11 Call: lid=0 id=1042 in=0
BChan: slot=5 chan=3
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=8236225555
IE CMIEDeviceDetail (231) LOCALE=enu HW=8 VER=4 class=CMDeviceAlogTrunk type=0 number=11 channel=0 gain=0
2582375mS CMARS: LINE ep Received: CMSetupAck - child->state = CMCSOffering - ARS Call State = CMCSAccept
2582376mS CMTARGET: TargetOnProgress: res: 1
2582376mS CMARS: LINE IS NOW THE B END OF THE CALL - CMARSEndpoint::RequestEnd()
2582376mS CMARS: CMARSEndpoint::CallLost(cause=124) - Address: 0.1040.0 12 ARS for Main - Call State: CMCSAccept
2582376mS CMARS: ~CMARSEndpoint() - Address: f5d93310
2582377mS PRN: Windowed EchoCancellation started: chunnel=2, command= 0x8402
2582378mS CMMap: Playing in progress, cp[74]b1r0 g null
2582378mS CMMap: cp[74]b1r0 SetOperGroup from g null to g G[22] not executed, playing tones in progress ,EEEEE
2582378mS CMMap: PCG::MapBChan pcp[60]b1r0 cp_b f5e188b6 other_cp_b 0 type CGTypeSimple
2582634mS RES: Thu 20/9/2007 13:46:00 FreeMem=84238168(8) CMMsg=4 (5) Buff=200 962 998 7198 5 Links=438
2584147mS CMMap: PCG::UnmapBChan pcp[74]b1r0 cp_b f5ddf856 other_cp_b f5e2bfe6
2584147mS CMMap: a=21.7 b=20.4 M0
2584147mS CMMap: a=21.7 b=0.0 T0
2584147mS CMMap: a=21.7 b=0.0 DTMF::~DTMF freed CMRTTonegen resource busy 4, total 8
2584148mS CMMap: PCG::MapBChan pcp[74]b1r0 cp_b f5ddf856 other_cp_b f5e188b6 type CGTypeSimple
2584148mS CMMap: a=5.3 b=20.4 M1
2586324mS CD: CALL: 0.1038.0 State=0 Cut=3 Music=0.0 Aend="Marsha(8204)" (20.4) Bend="Line 11" [Line 11] (5.3) CalledNum=8236225555 () CallingNum=8204 (Marsha) Internal=0 Time=19984 AState=1
2586995mS CMLineRx: v=11
CMProgress
Line: type=AnalogueLine 11 Call: lid=0 id=1042 in=0
BChan: slot=5 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=8236225555
IE CMIEDeviceDetail (231) LOCALE=enu HW=8 VER=4 class=CMDeviceAlogTrunk type=0 number=11 channel=0 gain=0
2586996mS CMExtnTx: v=8204, p1=0
CMProgress
Line: type=DigitalExtn 2 Call: lid=0 id=1038 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=8236225555
IE CMIEDeviceDetail (231) LOCALE=enu HW=8 VER=4 class=CMDeviceAlogTrunk type=0 number=11 channel=0 gain=0
Timed: 20/09/07 13:46
2586996mS CMLineRx: v=11
CMAlerting
Line: type=AnalogueLine 11 Call: lid=0 id=1042 in=0
BChan: slot=5 chan=3
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=8236225555
IE CMIEDeviceDetail (231) LOCALE=enu HW=8 VER=4 class=CMDeviceAlogTrunk type=0 number=11 channel=0 gain=0
2586997mS CMExtnTx: v=8204, p1=0
CMProgress
Line: type=DigitalExtn 2 Call: lid=0 id=1038 in=0
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=8236225555
IE CMIEDeviceDetail (231) LOCALE=enu HW=8 VER=4 class=CMDeviceAlogTrunk type=0 number=11 channel=0 gain=0
IE CMIEProgressIndicator (30) cs=CMCSITUT (0), loc=CMLUser (0), pd=CMPDInbandPattern (8)
Timed: 20/09/07 13:46
2586997mS CMLineRx: v=11
CMConnect
Line: type=AnalogueLine 11 Call: lid=0 id=1042 in=0
BChan: slot=5 chan=3
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=8236225555
IE CMIEDeviceDetail (231) LOCALE=enu HW=8 VER=4 class=CMDeviceAlogTrunk type=0 number=11 channel=0 gain=0
2586997mS CMExtnTx: v=8204, p1=0
CMConnect
Line: type=DigitalExtn 2 Call: lid=0 id=1038 in=0
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=8236225555
IE CMIEDeviceDetail (231) LOCALE=enu HW=8 VER=4 class=CMDeviceAlogTrunk type=0 number=11 channel=0 gain=0
Timed: 20/09/07 13:46
2586998mS CMExtnRx: v=8204, p1=0
CMConnectAck
Line: type=DigitalExtn 2 Call: lid=0 id=1038 in=0
2586998mS CMTARGET: 0.1038.0 12 Marsha.0: ~CMTargetHandler
2586998mS CMLineTx: v=11
CMConnectAck
Line: type=AnalogueLine 11 Call: lid=0 id=1042 in=0
BChan: slot=20 chan=4
IE CMIERespondingPartyName (228) Marsha
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=8204
IE CMIEDeviceDetail (231) LOCALE=enu HW=8 VER=4 class=CMDeviceStdPhone type=27 number=4 channel=0 gain=0
2586999mS CD: CALL: 0.1038.0 State=2 Cut=3 Music=0.0 Aend="Marsha(8204)" (20.4) Bend="Line 11" [Line 11] (5.3) CalledNum=8236225555 () CallingNum=8204 (Marsha) Internal=0 Time=20659 AState=2
2589317mS CMExtnRx: v=8204, p1=0
CMReleaseComp
Line: type=DigitalExtn 2 Call: lid=0 id=1038 in=0
2589318mS CMLOGGING: CALL:2007/09/2013:45,00:00:09,000,8204,O,98236225555,98236225555,Marsha,,,1,,""n/a,0
2589319mS CD: CALL: 0.1038.0 State=2 Cut=2 Music=0.0 Aend="Marsha(8204)" (20.4) Bend="Line 11" [Line 11] (5.3) CalledNum=8236225555 () CallingNum=8204 (Marsha) Internal=0 Time=22978 AState=0
2589319mS CD: CALL: 0.1038.0 Deleted
2589321mS CMMap: PCG::UnmapBChan pcp[60]b1r0 cp_b f5e188b6 other_cp_b f5ddf856
2589322mS CMMap: a=20.4 b=5.3 M0
2589322mS CMMap: PCG::UnmapBChan pcp[74]b1r0 cp_b f5ddf856 other_cp_b 0
2589634mS RES: Thu 20/9/2007 13:46:07 FreeMem=84256896(17) CMMsg=4 (5) Buff=200 963 998 7198 5 Links=450
2591319mS CMExtnTx: v=8204, p1=0
CMVoiceMailStatus
Line: type=DigitalExtn 2 Call: lid=0 id=-1 in=0
Called[Marsha Msgs=0 Old=0 Sav=0] Type=Default (100) Reason=CMDRdirect Calling[00000000] Type=Default Plan=Default
Display [Marsha Msgs=0]
Timed: 20/09/07 13:46
2591321mS PRN: Windowed EchoCancellation stopped: chunnel=2, command= 0x502
2607449mS ERR: TFTP Write:: Too many retries (from 172.16.1.1, 62222) file=nasystem
2607455mS ERR: TFTP Write:: Too many retries (from 172.16.1.1, 62223) file=nasystem
2607634mS RES: Thu 20/9/2007 13:46:25 FreeMem=84259736(17) CMMsg=4 (5) Buff=200 963 1000 7198 5 Links=454

 

[ProviderReborn]

I see the words out of service.
I you have four lines check they are all in service. Also tell me what call status says when you are doing this.

ACA - IP Office Implement
ACA - IP Telephony
ACS - IP Office Implement (Aug 30th)