Not to bring back a post from the dead, but I had a chance to test this today when one of our sites lost its PRI for 10-15 minutes.
Line 5 is PRI
Line 31 is SCN Line
Strangely the automatic out of service route did not work, in monitor I got:
3086389036mS CMARS: FORM: MainAll - Received Number: 13103413125
3086389036mS CMARS: CMARSTargetingPending
3086389729mS ISDNL1Evt: v=5 peb=5,F1 F3
3086389732mS PRN: Falc 5 slip
3086389732mS PRN: WARNING:
3086389732mS PRN: ****Reset Slip Store Falc 5 2 0
3086389732mS PRN:
3086389732mS PRN: WARNING:
3086389732mS PRN: 12:29:15
3086389733mS PRN:
3086389733mS ISDNL1Evt: v=5 peb=5,F3 F1
3086392370mS ISDNL1Evt: v=5 peb=5,F1 F3
3086392371mS PRN: Falc 5 slip
3086392371mS PRN: WARNING:
3086392371mS PRN: ****Reset Slip Store Falc 5 2 0
3086392371mS PRN:
3086392372mS PRN: WARNING:
3086392372mS PRN: 12:29:18
3086392372mS PRN:
3086392374mS ISDNL1Evt: v=5 peb=5,F3 F1
3086393912mS ISDNL1Evt: v=5 peb=5,F1 F3
3086393915mS ISDNL1Evt: v=5 peb=5,F3 F1
3086394023mS CMARS: Case 1 - dial_delay_time: 4000 has expired - Resolve what we might have - Called Number: 13103413125 Addr: f55e705c
3086394023mS CMARS: FORM: MainAll - Received Number: 13103413125
3086394024mS CMARS: FOUND A SHORT CODE - short_code: 1XXXXXXXXXX; - Tel: 1N - Called_Party: 13103413125 - Line Group Id: 1
3086394024mS CMARS: CMARSHandler::FindActiveARSByGroupID GroupID=1
3086394024mS CMLRQ: CMLRQHandler::FindActiveLRQByGroupID GroupID=1
3086394024mS CMTARGET: Problem with Line Id: 31, Unlicenced -1, NewCallResourceCheck( ) -1
3086394024mS CMLineTx: v=5
CMRestart
Line: type=Q931Line 5 Call: lid=0 id=-1 in=0
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
Display [enu]
Locale: enu
3086394025mS CMTARGET: Problem with Line Id: 5 - preselected: 00000000, Unlicenced: 0, OperationalTest: 1, NewCallResourceCheck: -1
3086394025mS CMARS: LINE with group ID: 1 HAS NO CHANNEL: 34 - ATTEMPT OTHER TARGETS
3086394025mS CMTARGET: Problem with Line Id: 31, Unlicenced -1, NewCallResourceCheck( ) -1
3086394026mS CMLineTx: v=5
CMRestart
Line: type=Q931Line 5 Call: lid=0 id=-1 in=0
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
Display [enu]
Locale: enu
3086394026mS CMTARGET: Problem with Line Id: 5 - preselected: 00000000, Unlicenced: 0, OperationalTest: 1, NewCallResourceCheck: -1
3086394026mS CMARS: No Alternate ARS Or User Priority lower than ARS Priority - Remain on the Current Form: MainAll
3086394026mS CMARS: CMARSTargetingBusy
3086394027mS CMCallEvt: 0.30670.0 8502 ARS for MainAll: StateChange: END=B CMCSOverlapRecv->CMCSAccept
3086394027mS CMCallEvt: 0.30668.0 8502 MattP.1: StateChange: END=A CMCSDialling->CMCSRingBack
3086394027mS CMExtnEvt: v=6 State, new=Alerting old=Dialling,0,0,MattP
3086394028mS CMExtnTx: v=8510, p1=0
CMProgress
Line: type=DigitalExtn 3 Call: lid=0 id=30668 in=0
IE CMIEProgressIndicator (30) cs=CMCSITUT (0), loc=CMLUser (0), pd=CMPDInbandPattern (8)
Display [WAITING_FOR_LINE]
Timed: 21/07/09 12:29
3086394028mS CD: CALL: 0.30668.0 BState=Ringing Cut=3 Music=0.0 Aend="MattP(8510)" (20.14) Bend="" [] (0.0) CalledNum=13103413125 () CallingNum=8510 (MattP) Internal=1 Time=9019 AState=Ringing
3086394029mS CMMap: a=21.7 b=0.0 DTMF::AllocateRAS allocated CMRTTonegen resource busy 5, total 8
3086394029mS CMMap: a=21.7 b=1.255 T
3086394029mS CMMap: PCG::MapBChan pcp[141]b1r0 cp_b f56bd33c other_cp_b f5a084f8 type CGTypeDTMF
3086394029mS CMMap: a=21.7 b=20.14 M2
3086394029mS CMMap: DTMF:

layTones g T[479] ,EEEEE
3086394030mS CMMap: Started playing tones, cp[141]b1r0 (from g null)
3086394030mS CMMap: cp[141]b1r0 SetOperGroup from g null to g null not executed, playing tones in progress ,EEEEE
3086394391mS RES: Tue 21/7/2009 12:29:20 FreeMem=74921684(1) CMMsg=9 (10) Buff=200 948 999 7412 5 Links=769
3086394391mS RES2: RTEngine=0, CMRTEngine=0, Timer=66, Poll=0, Ready=0, CMReady=0, CMQueue=0, VPNNQueue=0
3086394525mS ISDNL1Evt: v=5 peb=5,F1 F3
3086394529mS ISDNL1Evt: v=5 peb=5,F3 F1
3086395023mS CMARS: Retarget existing BUSY targets - Num of Busy Targets: 1 - Current Form: MainAll
3086395850mS CMMap: PCG::UnmapBChan pcp[141]b1r0 cp_b f56bd33c other_cp_b f5a084f8
3086395850mS CMMap: a=21.7 b=20.14 M0
3086395850mS CMMap: a=21.7 b=0.0 T0
3086395850mS CMMap: a=21.7 b=0.0 DTMF::~DTMF freed CMRTTonegen resource busy 4, total 8
3086395851mS CMMap: a=21.7 b=0.0 DTMF::AllocateRAS allocated CMRTTonegen resource busy 5, total 8
3086395851mS CMMap: a=21.7 b=1.255 T
3086395851mS CMMap: PCG::MapBChan pcp[141]b1r0 cp_b f56bd33c other_cp_b f5a084f8 type CGTypeDTMF
3086395851mS CMMap: a=21.7 b=20.14 M2
3086395851mS CMMap: DTMF:

layTones g T[480] ,EEEEE
3086395852mS CMMap: Started playing tones, cp[141]b1r0 (from g null)
3086395852mS CMMap: cp[141]b1r0 SetOperGroup from g null to g null not executed, playing tones in progress ,EEEEE
3086396376mS ISDNL1Evt: v=5 peb=5,F1 F3
3086396379mS PRN: Falc 5 slip
3086396379mS PRN: WARNING:
3086396379mS PRN: ****Reset Slip Store Falc 5 0 0
3086396379mS PRN:
3086396379mS PRN: WARNING:
3086396379mS PRN: 12:29:22
3086396379mS PRN:
3086396379mS ISDNL1Evt: v=5 peb=5,F3 F1
3086396484mS ISDNL1Evt: v=5 peb=5,F1 F3
3086396487mS ISDNL1Evt: v=5 peb=5,F3 F1
3086397501mS ISDNL1Evt: v=5 peb=5,F1 F3
3086397504mS ISDNL1Evt: v=5 peb=5,F3 F1
3086397672mS CMMap: PCG::UnmapBChan pcp[141]b1r0 cp_b f56bd33c other_cp_b f5a084f8
3086397672mS CMMap: a=21.7 b=20.14 M0
3086397672mS CMMap: a=21.7 b=0.0 T0
3086397673mS CMMap: a=21.7 b=0.0 DTMF::~DTMF freed CMRTTonegen resource busy 4, total 8
3086398030mS ISDNL3Evt: v=5 p1=5,p2=1001,p3=5,p4=0,s1=
3086398740mS PRN: WARNING:
3086398740mS PRN: 3086398740 - CCU: 16, Called ccup_rtcp_report_status. status_type=0x8
3086398740mS PRN:
3086398740mS SPY: 3086398740 - CCU: 16, Called ccup_rtcp_report_status. status_type=0x8
3086399997mS ISDNL1Evt: v=5 peb=5,F1 F3
3086399999mS PRN: Falc 5 slip
3086400000mS PRN: WARNING:
3086400000mS PRN: ****Reset Slip Store Falc 5 2 0
3086400000mS PRN:
3086400000mS PRN: WARNING:
3086400000mS PRN: 12:29:25
3086400000mS PRN:
3086400001mS ISDNL1Evt: v=5 peb=5,F3 F1
3086400988mS ISDNL1Evt: v=5 peb=5,F1 F3
3086400991mS PRN: Falc 5 slip
3086400991mS PRN: WARNING:
3086400991mS PRN: ****Reset Slip Store Falc 5 2 0
3086400991mS PRN:
3086400992mS PRN: WARNING:
3086400992mS PRN: 12:29:26
3086400992mS PRN:
3086400992mS ISDNL1Evt: v=5 peb=5,F3 F1
3086401023mS CMARS: Retarget existing BUSY targets - Num of Busy Targets: 1 - Current Form: MainAll
3086401024mS CMMap: a=21.7 b=0.0 DTMF::AllocateRAS allocated CMRTTonegen resource busy 5, total 8
3086401024mS CMMap: a=21.7 b=1.255 T
3086401024mS CMMap: PCG::MapBChan pcp[141]b1r0 cp_b f56bd33c other_cp_b f5a084f8 type CGTypeDTMF
3086401024mS CMMap: a=21.7 b=20.14 M2
3086401024mS CMMap: DTMF:

layTones g T[481] ,EEEEE
3086401025mS CMMap: Started playing tones, cp[141]b1r0 (from g null)
3086401025mS CMMap: cp[141]b1r0 SetOperGroup from g null to g null not executed, playing tones in progress ,EEEEE
3086401094mS ISDNL1Evt: v=5 peb=5,F1 F3
3086401098mS ISDNL1Evt: v=5 peb=5,F3 F1
3086401391mS RES: Tue 21/7/2009 12:29:27 FreeMem=74921684(1) CMMsg=9 (10) Buff=200 948 999 7414 5 Links=770
3086401391mS RES2: RTEngine=0, CMRTEngine=0, Timer=62, Poll=0, Ready=0, CMReady=0, CMQueue=0, VPNNQueue=0
3086401863mS ISDNL1Evt: v=5 peb=5,F1 F3
3086401863mS PRN: Falc 5 slip
3086401863mS PRN: WARNING:
3086401863mS PRN: ****Reset Slip Store Falc 5 2 0
3086401864mS PRN:
3086401864mS PRN: WARNING:
3086401864mS PRN: 12:29:27
3086401864mS PRN:
3086401866mS ISDNL1Evt: v=5 peb=5,F3 F1
3086402547mS ISDNL1Evt: v=5 peb=5,F1 F3
3086402552mS PRN: Falc 5 slip
3086402552mS PRN: WARNING:
3086402552mS PRN: ****Reset Slip Store Falc 5 0 20
3086402552mS PRN:
3086402552mS PRN: WARNING:
3086402552mS PRN: 12:29:28
3086402552mS PRN:
3086402556mS PRN: Falc 5 slip
3086402556mS PRN: WARNING:
3086402556mS PRN: ****Reset Slip Store Falc 5 2 0
3086402556mS PRN:
3086402556mS PRN: WARNING:
3086402556mS PRN: 12:29:28
3086402556mS PRN:
3086402560mS PRN: Falc 5 slip
3086402560mS PRN: WARNING:
3086402560mS PRN: ****Reset Slip Store Falc 5 2 0
3086402560mS PRN:
3086402560mS PRN: WARNING:
3086402561mS PRN: 12:29:28
3086402561mS PRN:
3086402562mS ISDNL1Evt: v=5 peb=5,F3 F1
3086402846mS CMMap: PCG::UnmapBChan pcp[141]b1r0 cp_b f56bd33c other_cp_b f5a084f8
3086402846mS CMMap: a=21.7 b=20.14 M0
3086402846mS CMMap: a=21.7 b=0.0 T0
3086402846mS CMMap: a=21.7 b=0.0 DTMF::~DTMF freed CMRTTonegen resource busy 4, total 8
3086403044mS ISDNL1Evt: v=5 peb=5,F1 F3
3086403047mS PRN: Falc 5 slip
3086403047mS PRN: WARNING:
3086403047mS PRN: ****Reset Slip Store Falc 5 2 0
3086403047mS PRN:
3086403047mS PRN: WARNING:
3086403047mS PRN: 12:29:28
3086403047mS PRN:
3086403047mS ISDNL1Evt: v=5 peb=5,F3 F1
3086406299mS ISDNL1Evt: v=5 peb=5,F1 F3
3086406301mS PRN: Falc 5 slip
3086406301mS PRN: WARNING:
3086406302mS PRN: ****Reset Slip Store Falc 5 2 0
3086406302mS PRN:
3086406302mS PRN: WARNING:
3086406302mS PRN: 12:29:32
3086406302mS PRN:
3086406306mS PRN: Falc 5 slip
3086406306mS PRN: WARNING:
3086406306mS PRN: ****Reset Slip Store Falc 5 2 0
3086406306mS PRN:
3086406306mS PRN: WARNING:
3086406306mS PRN: 12:29:32
3086406306mS PRN:
3086406310mS PRN: Falc 5 slip
3086406310mS PRN: WARNING:
3086406310mS PRN: ****Reset Slip Store Falc 5 2 0
3086406310mS PRN:
3086406310mS PRN: WARNING:
3086406310mS PRN: 12:29:32
3086406311mS PRN:
3086406312mS ISDNL1Evt: v=5 peb=5,F3 F1
3086407023mS CMARS: Retarget existing BUSY targets - Num of Busy Targets: 1 - Current Form: MainAll
3086407023mS CMARS: Target: Short_Code: 1XXXXXXXXXX; - Line_Group_ID: 1 - Telephone_Number: 1N - Line_Status: CMARS_OUTOFSERVICE
3086407023mS CMTARGET: Problem with Line Id: 31, Unlicenced -1, NewCallResourceCheck( ) -1
When I use a manual Short Code (*9N) for the SCN based route it works fine.
Any ideas?