OK, this is a weird one. Also, I should note that this was tested under 7.1.3 and seems to have broken under 8.6.1. We want to route calls between UC sites on-net seamlessly, meaning we don't want users to have to dial differently when dialing between UC sites, Therefore, we created a on-net translation partition and CSS. Every UC site has their DID ranges (with the leading access digit, 9) added to the on-net translation partition as a translation pattern, The translation pattern strips the access digit and routes the call using a CSS that includes the partition that contains all of the directory numbers. Under normal circumstances, this works great.
However, when we test AAR by reducing the inter-region bandwidth, these calls fail. The calling phone reports the "Network Congestion, Rerouting" like it should, but does not connect and the receiving phone does not ring. Now here's the part that has been frying my brain all day: In that same situation if I dial the remote phone without the access code, AAR works. Now we aren't blocking inter-site calls on-net, and each phone's CSS include the main phone partition, so it's no mystery why the call completes. But why does AAR work if the DN is called directly, but does not if the call first hits a translation pattern that translates it to the same number and equivelent CSS as the direct call? The translation pattern does not take part in the AAR routing, does it? The only thing I can think of is that the orginal dialed number someone comes into play, but I don't see how; the AAR destination is determined by the AAR Destination Mask under the DN settings and in our case, that overwrites the destination completely,
Here is the trace file...
14:49:50.201 |before AAR invoked: cgpn = "15159998578" cdpn = "14148882085" prefix digits = "" alternate num = "14148882085" cdcc=3903016, mAARHopCount=0, calledPartyPartition = "c1d5ad5f-0837-420a-a8ba-9fc671e90b27" AARPartition = "a51f4bf6-2b4f-dd80-7e8c-8910b9a6e66c"|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.201 |AAR invoked: cgpn = "15159998578" cdpn = "14148882085" prefix digits = "" alternate num = "14148882085" AAR CSS= "11e298d8-7fe1-476c-5e61-12888bbdd978" cdcc=3903016, mAARHopCount=1|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.201 |Digit Analysis: star_DaReq: daReq.partitionSearchSpace(11e298d8-7fe1-476c-5e61-12888bbdd978), filteredPartitionSearchSpaceString(NACH01_Direct_PSTN_PT), partitionSearchSpaceString(NACH01_Direct_PSTN_PT)|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.201 |Digit Analysis: star_DaReq: Matching Legacy Numeric, digits=14148882085|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.202 |Digit Analysis: getDaRes data: daRes.ssType=[0] Intercept DAMR.sstype=[0], TPcount=[0], DAMR.NotifyCount=[0], DaRes.NotifyCount=[0]|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.202 |Digit analysis: match(pi="1",fqcn="15159998578", cn="15159998578", plv="5", pss="NACH01_Direct_PSTN_PT", TodFilteredPss="NACH01_Direct_PSTN_PT", dd="14148882085",dac="0")|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.202 |Digit analysis: potentialMatches=PotentialMatchesExist|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.202 |ForwardManager - wait_SsDataInd - Key= 0x0, party= 101689732, BCC= 12|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.202 |ForwardManager - findCallBySsParty - Found entry for party= 101689732, callkey= 0xE9E22 |6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.202 |LineCdpc(4452481): -dispatchToAllDevices-, sigName=CcNotifyReq, device=SEPD4BED9712345|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.202 |ForwardManager - wait_SsExtendCallErr - mPartyToActiveCallIndexMap - Added Entry for party= 101689732, callkey= 0xE9E22|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.202 |ForwardManager - findCallBySsParty - Found entry for party= 101689732, callkey= 0xE9E22 |6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.202 |Forwarding - awaitingCallResponse_SsExtendCallErr. ErrorCode= 3, callKey= 0xE9E22|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.202 |Forwarding - awaitingCallResponse_SsRelRejInterceptInd - CFB processing. party= 101689732, cause= 0, BCC= 12, callKey= 0xE9E22|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.202 |Forwarding - unregisterRelRejInterceptRequest - callKey= 0xE9E22|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.202 |Forwarding - unregisterRelRejInterceptRequest - Unregistered RelRej Intercept- party= 101689732, callKey= 0xE9E22|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.202 |Forwarding - unregisterRelRejInterceptRequest - callKey= 0xE9E22|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.202 |Forwarding - unregisterRelRejInterceptRequest - Unregistered RelRej Intercept- party= 101689732, callKey= 0xE9E22|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.202 |Forwarding - sendClearCallReq - callKey= 0xE9E22, party= 101689732|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.202 |Forwarding - awaitingCallResponse_SsRelRejInterceptInd - no CFB dest or CFAP dest - Clear the call - party= 101689732, callKey= 0xE9E22|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.202 |star_CcNotifyReq - bmask=0x100000 displayName.length=2 (€B).|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.202 |StationD: (0453595) DisplayNotify timeOutValue=10 notify='€B' content='Network congestion,rerouting' ver=85720014.|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.202 |StationD: (0453595) StationOutputDisplayText don't need to send, because mIsALegacyDevice = 0|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.202 |remove an entry from release intercept queue given ssType|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.202 |processCCMFeatureData: operationIeIdd=0|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.202 |EnvProcessCdr::wait_DbCdrReq|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.202 |EnvProcessCdr::wait_DbCdrReq DETAILED Entries 3327771, Inserts 3124247, ZeroCalls 203524, StartRecords 0, Default 0|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.202 |EnvProcessCdr::formatCdrData|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.202 |!!ERROR!! -ConnectionManager- wait_AuDisconnectRequest :CI NOT FOUND IN TABLE,CI(101689732,0),discType=1,IFCreated(0,0),PID(0-0,0-0),IFHandling(0,0),MCNode(0,0)|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.202 |MatrixControl:updatePartyMediaCoordinatorNodeId: party1 videoCapable=0, party 2 videocapable=0|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.203 |StationD: (0453595) StopTone.|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.203 |LineControl TEST DEBUGS: Number of entries in CallTable is = 1
|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.203 |StationD: (0453595) DEBUG- star_DSetCallPhase updateACall=101689732 from Phase=0 to callPhase=3.|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.203 |StationD: (0453595) DEBUG- star_DSetCallState(15) State of cdpc(7747145) is 6.|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.203 |StationD: (0453595) SetLamp mode=1, stim=9 stimInst=1.|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.203 |StationD: (0453595) ClearPromptStatus lineInstance=1 callReference=101689732.|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.203 |StationD: (0453595) CallState callState=2 lineInstance=1 callReference=101689732 privacy=0 sccp_precedenceLv=4 precedenceDm=0|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.203 |StationD: (0453595) SelectSoftKeys instance=0 reference=0 softKeySetIndex=0 validKeyMask=ffffffff.|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.203 |StationD: (0453595) DefineTimeDate timeDateInfo=7/23/2013 14:49:50,2 systemTime=1374608990.|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.203 |StationD: (0453595) restart0_DStopInd: No Linked StationCdpc.|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.203 |StationD: (0453595) INFO restart0_DStopInd: Enable NewCall on line=1 limit=4 listSize=0|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.203 |StationD: (0453595) restart0_DStopInd: DEBUG: StationCdpc(7747145) removed. Calltable contains 0 calls.|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.203 |LineCdpc(4452481)dispatchKeyReleaseReq - mDevicePid(6, 57, 453595); mSelectedDPid(0, 0, 0), mOnBehalfOf(Aar), rfr(0)|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.203 |StationD: (0453595) SetSpeakerMode speakermode=2(Off).|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.203 |LineControl(217263) - Release call instance=1 for CI=101689732|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.203 |LineControl::sendSNFNotifyIndForPresenceWithAlerting mPrecenceWithAlertingChangeNotifySubscribed=0, calllist#=0|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.203 |LineControl (217263) - DStopInd - Line become idle|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.203 |LineControl(217263) - 0 calls, 0 CiReq, busyTrigger=2, maxCall=4|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
14:49:50.203 |processCCMFeatureData: operationIeIdd=0|6,100,13,9190377.89^10.192.183.84^SEPD4BED9712345
