Troubleshoot VoLTE Call Failure because of 5012 (DIAMETER_UNABLE_TO_COMPLY) at CPS

Introduction

This document describes how to troubleshoot Voice over Long Term Evolution(VoLTE) call failure because of 5012 (DIAMETER_UNABLE_TO_COMPLY) at Cisco Policy Suite (CPS).

Problem

Reported VoLTE call failures because of 5012 (DIAMETER_UNABLE_TO_COMPLY) at CPS. 

These are the consolidated-engine logs where you can see the command code Rx_AAR (265) -Request that was received by the CPS and answer sent back to the IP Multimedia Subsystem (IMS) from the CPS over the Rx interface with result-Code  DIAMETER_UNABLE_TO_COMPLY (5012).

=========  HOSTNAME-qnsXX  [yyyy-mm-dd 15:32:00,673] ============

POLICY RESULT ERROR:  null

        session action = None

        TRIGGER: Message: com.broadhop.diameter2.messages.DiameterRequestMessage

                Application Id: Rx (16777236)
                Command Code: Rx_AAR (265)

                Dest realm: XXXX.ims.mncXYZ.mccXYZ.3gppnetwork.org

                Device protocol: RX_TGPP

                End to end id: 204492743 (0x0c304fc7)

                Hop by hop id: 2985189310 (0xb1ee5fbe)

                Origin state: 0

.

.

.


        SENT MESSAGES (asynchronous):  <<<<<<<<<<<

        Message: com.broadhop.diameter2.messages.DiameterResponseMessage

                Application Id: Rx (16777236)

                Command Code: Rx_AAA (265)

                Dest host: XXXX.ims.mncXYZ.mccXYZ.3gppnetwork.org
                Dest realm:XXXX.ims.mncXYZ.mccXYZ.3gppnetwork.org

                Device protocol: RX_TGPP

                End to end id: 204492743 (0x0c304fc7)

                Hop by hop id: 2985189310 (0xb1ee5fbe)

                Origin state: 0

                Stack name: null

                Origin realm: XXXX.ims.mncXYZ.mccXYZ.3gppnetwork.org

                Session-Id: pcsf-stdn.imsgroup1-111-1111111.aaa.sbc.bbb.com;316160;1;5.2551556468.2;pcsf-stdn.imsgroup1-111-1111111

                Auth-Application-Id: 16777236

                QPS-Internal-Route-Record-Host: XXXX.ims.mncXYZ.mccXYZ.3gppnetwork.org

                QPS-Internal-Route-Record-Realm: XXXX.ims.mncXYZ.mccXYZ.3gppnetwork.org

                Result-Code: DIAMETER_UNABLE_TO_COMPLY (5012)  <<<<<<<<<<<<<

Troubleshoot

Here is the behavior as seen in consolidated-engine logs:

For failure case, consolidated-engine logs show, 5012 for the Authorization/Authentication Request(AAR), when checked the Req Message, you can see CPS is printing codec data in Hex format [highlighted in bold].

Failure Case: (Engine Logs)

HOSTNAME-qnsXX   [yyyy-mm-dd 15:33:02,529] ===============================================
POLICY RESULT ERROR:  null
        session action = None
        TRIGGER: Message: com.broadhop.diameter2.messages.DiameterRequestMessage
                Application Id: Rx (16777236)
                Command Code: Rx_AAR (265)
                Dest realm: YYYY.mncXYZ.mccXYZ.3gppnetwork.org
                Device protocol: RX_TGPP
                End to end id: 90747852 (0x0568b3cc)
                Hop by hop id: 2509770985 (0x959810e9)
                Origin state: 0
                Stack name: null
                Origin host: XXXX.ims.mncXYZ.mccXYZ.3gppnetwork.org
                Origin realm: XXXX.ims.mncXYZ.mccXYZ.3gppnetwork.org
                Session-Id: pcsf-stdn.imsgroup1-111-1111111.aaa.sbc.bbb.com;316160;1;5.2551556468.2;pcsf-stdn.imsgroup1-111-1111111
                Auth-Application-Id: 16777236
                Media-Component-Description:
                                Media-Component-Number: 1
                                Media-Sub-Component:
                                                Flow-Number: 1
                                                Flow-Description:
                                Media-Sub-Component:
                                                Flow-Number: 2
                                               

Codec-Data: uplink\r\noffer\r\nm=audio 50010 RTP/AVP 99 97 105 96\r\na=rtpmap:99 AMR-WB/16000/1\r\na=fmtp:99 mode-change-capability=2;max-re
d=0\r\na=rtpmap:97 AMR/8000/1\r\na=fmtp:97 mode-change-capability=2;max-red=0\r\na=rtpmap:105 telephone-event/16000\r\na=fmtp:105 0-15\r\na=rtpmap:96 telephone-event/8000\r
\na=fmtp:96 0-15\r\na=curr:qos local none\r\na=curr:qos remote none\r\na=des:qos mandatory local sendrecv\r\na=des:qos optional remote sendrecv\r\na=ptime:20\r\na=maxptime:
240\r\n  (0x75706c696e6b0d0a6f666665720d0a6d3d617564696f203530303130205254502f415650203939203937203130352039360d0a613d7274706d61703a393920414d522d57422f31363030302f310d0a613
d666d74703a3939206d6f64652d6368616e67652d6361706162696c6974793d323b6d61782d7265643d300d0a613d7274706d61703a393720414d522f383030302f310d0a613d666d74703a3937206d6f64652d63686
16e67652d6361706162696c6974793d323b6d61782d7265643d300d0a613d7274706d61703a3130352074656c6570686f6e652d6576656e742f31363030300d0a613d666d74703a31303520302d31350d0a613d72747
06d61703a39362074656c6570686f6e652d6576656e742f383030300d0a613d666d74703a393620302d31350d0a613d637572723a716f73206c6f63616c206e6f6e650d0a613d637572723a716f732072656d6f74652
06e6f6e650d0a613d6465733a716f73206d616e6461746f7279206c6f63616c2073656e64726563760d0a613d6465733a716f73206f7074696f6e616c2072656d6f74652073656e64726563760d0a613d7074696d653
a32300d0a613d6d6178)
                                Codec-Data: downlink\r\nanswer\r\nm=audio 36602 RTP/AVP 97 96\r\na=rtpmap:97 AMR/8000/1\r\na=fmtp:97 mode-set=0,2,4,7; mode-change-period=2;
mode-change-capability=2; mode-change-neighbor=1; max-red=0\r\na=rtpmap:96 telephone-event/8000\r\na=fmtp:96 0-15\r\na=curr:qos local sendrecv\r\na=curr:qos remote none\r\
na=des:qos mandatory local sendrecv\r\na=des:qos mandatory remote sendrecv\r\na=conf:qos remote sendrecv\r\na=maxptime:40\r\n(0x646f776e6c696e6b0d0a616e737765720d0a6d3d617
564696f203336363032205254502f4156502039372039360d0a613d7274706d61703a393720414d522f383030302f310d0a613d666d74703a3937206d6f64652d7365743d302c322c342c373b206d6f64652d6368616
e67652d706572696f643d323b206d6f64652d6368616e67652d6361706162696c6974793d323b206d6f64652d6368616e67652d6e65696768626f723d313b206d61782d7265643d300d0a613d7274706d61703a39362
074656c6570686f6e652d6576656e742f383030300d0a613d666d74703a393620302d31350d0a613d637572723a716f73206c6f63616c2073656e64726563760d0a613d637572723a716f732072656d6f7465206e6f6
e650d0a613d6465733a716f73206d616e6461746f7279206c6f63616c2073656e64726563760d0a613d6465733a716f73206d616e6461746f72792072656d6f74652073656e64726563760d0a613d636f6e663a716f7
32072656d6f74652073656e64726563760d0a613d6d6178707)

DEBUG MSGS:
                INFO   : (core) Tagging message with ID: RX_TGPP
                INFO   : (rx) Sending 265 Message on session pcsf-stdn.imsgroup1-111-1111111.aaa.sbc.bbb.com;316160;1;5.2551556468.2;pcsf-stdn.imsgroup1-111-1111111
                INFO   : (balance) Error found,  rolling back transaction
                ERROR  : (core) Error processing policy request:  null
        SERVICE CALC MSGS:
        USE CASES:
        SENT MESSAGES (asynchronous):
        Message: com.broadhop.diameter2.messages.DiameterResponseMessage
                Application Id: Rx (16777236)
                Command Code: Rx_AAA (265)
                Dest host: XXXX.ims.mncXYZ.mccXYZ.3gppnetwork.org
                Dest realm: XXXX.ims.mncXYZ.mccXYZ.3gppnetwork.org
                Device protocol: RX_TGPP
                End to end id: 90747852 (0x0568b3cc)
                Hop by hop id: 2509770985 (0x959810e9)
                Origin state: 0
                Stack name: null
                Origin realm: YYYY.ims.mncXYZ.mccXYZ.3gppnetwork.org
                Session-Id: pcsf-stdn.imsgroup1-111-1111111.aaa.sbc.bbb.com;316160;1;5.2551556468.2;pcsf-stdn.imsgroup1-111-1111111
                Auth-Application-Id: 16777236
                QPS-Internal-Route-Record-Host: XXXX.ims.mncXYZ.mccXYZ.3gppnetwork.org
                QPS-Internal-Route-Record-Realm: XXXX.ims.mncXYZ.mccXYZ.3gppnetwork.org
                Result-Code: DIAMETER_UNABLE_TO_COMPLY (5012)

Success Case: (Engine Logs)

For success case, no Hex data is seen in both uplink and downlink codec and no difference in AAR  in both success and failure cases.

For success case, you can refer to INFO : (core) Successful load by key: imsiFramedIpKey:111111111111111:172.16.xx.yy under DEBUG MSG which was not present in the failure scenario.

HOSTNAME-qnsXX  [yyyy-mm-dd 15:33:30,543] 
POLICY RESULT SUCCESS:
        session action = None
        domainId = IMS
        locationId = ims
        SERVICES: IMS_DEFAULT
        TRIGGER: Message: com.broadhop.diameter2.messages.DiameterRequestMessage
                Application Id: Rx (16777236)
                Command Code: Rx_AAR (265)
                Dest realm: YYYY.ims.mncXYZ.mccXYZ.3gppnetwork.org
                Device protocol: RX_TGPP
                End to end id: 182837146 (0x0ae5df9a)
                Hop by hop id: 2274945953 (0x8798eba1)
                Origin state: 0
                Stack name: null
                Origin host: XXXX.ims.mncXYZ.mccXYZ.3gppnetwork.org
                Origin realm: XXXX.ims.mncXYZ.mccXYZ.3gppnetwork.org
                Session-Id: pcsf-stdn.imsgroup1-111-1111111.aaa.sbc.bbb.com;316160;1;5.2551556468.2;pcsf-stdn.imsgroup1-111-1111111
                Auth-Application-Id: 16777236
                Media-Component-Description:
                                Media-Component-Number: 1
                                Media-Sub-Component:
                                                Flow-Number: 1
                                                
                                Media-Sub-Component:
                                                Flow-Number: 2
                                                
                                Codec-Data: uplink\r\noffer\r\nm=audio 50008 RTP/AVP 116 107 118 96 111 110\r\na=rtpmap:116 AMR-WB/16000/1\r\na=fmtp:116 mode-change-capabil
ity=2;max-red=220\r\na=rtpmap:107 AMR-WB/16000/1\r\na=fmtp:107 octet-align=1;mode-change-capability=2;max-red=220\r\na=rtpmap:118 AMR/8000/1\r\na=fmtp:118 mode-change-capab
ility=2;max-red=220\r\na=rtpmap:96 AMR/8000/1\r\na=fmtp:96 octet-align=1;mode-change-capability=2;max-red=220\r\na=rtpmap:111 telephone-event/16000\r\na=fmtp:111 0-15\r\na=
rtpmap:110 telephone-event/8000\r\na=fmtp:110 0-15\r\na=curr:qos local none\r\na=curr:qos remote none\r\na=des:qos mandatory local sendrecv\r\na=des:qos optional remote sen
drecv\r\na=ptime:20\r\na=maxptime:240\r\n (uplink
offer
m=audio 50008 RTP/AVP 116 107 118 96 111 110 Note: Codec-Data is in readable form not like how it was in failure case.
a=rtpmap:116 AMR-WB/16000/1
a=fmtp:116 mode-change-capability=2;max-red=220
a=rtpmap:107 AMR-WB/16000/1
a=fmtp:107 octet-align=1;mode-change-capability=2;max-red=220
a=rtpmap:118 AMR/8000/1
a=fmtp:118 mode-change-capability=2;max-red=220
a=rtpmap:96 AMR/8000/1
a=fmtp:96 octet-align=1;mode-change-capability=2;max-red=220
a=rtpmap:111 telephone-event/16000
a=fmtp:111 0-15
a=rtpmap:110 telephone-event/8000
a=fmtp:110 0-15
a=curr:qos local none
a=curr:qos remote none
a=des:qos mandatory local sendrecv
a=des:qos optional remote sendrecv
a=ptime:20
a=maxptime:240
)
                                Codec-Data: downlink\r\nanswer\r\nm=audio 3302 RTP/AVP 118 110\r\na=rtpmap:118 AMR/8000/1\r\na=fmtp:118 mode-set=0,2,4,7; mode-change-period
=2; mode-change-capability=2; mode-change-neighbor=1; max-red=0\r\na=rtpmap:110 telephone-event/8000\r\na=fmtp:110 0-15\r\na=curr:qos local sendrecv\r\na=curr:qos remote no
ne\r\na=des:qos mandatory local sendrecv\r\na=des:qos mandatory remote sendrecv\r\na=conf:qos remote sendrecv\r\na=maxptime:40\r\n (downlink
answer
m=audio 3302 RTP/AVP 118 110
a=rtpmap:118 AMR/8000/1
a=fmtp:118 mode-set=0,2,4,7; mode-change-period=2; mode-change-capability=2; mode-change-neighbor=1; max-red=0
a=rtpmap:110 telephone-event/8000
a=fmtp:110 0-15
a=curr:qos local sendrecv
a=curr:qos remote none
a=des:qos mandatory local sendrecv
a=des:qos mandatory remote sendrecv
a=conf:qos remote sendrecv
a=maxptime:40
)
                                Media-Type: AUDIO (0)
                                Max-Requested-Bandwidth-UL: 64000
                                Max-Requested-Bandwidth-DL: 41000
                                Flow-Status: ENABLED (2)
                                RS-Bandwidth: 0
                                RR-Bandwidth: 0
                Subscription-Id:
                                Subscription-Id-Type: END_USER_SIP_URI (2)
                                Subscription-Id-Data: sip:+911234567890@ims.mncXYZ.mccXYZ.3gppnetwork.org
                Subscription-Id:
                                Subscription-Id-Type: END_USER_IMSI (1)
                                Subscription-Id-Data: <1111111111111111>
                AF-Charging-Identifier: "PCSF:1-sbc"
                Specific-Action: INDICATION_OF_LOSS_OF_BEARER (2)
                Specific-Action: INDICATION_OF_RECOVERY_OF_BEARER (3)
                Specific-Action: INDICATION_OF_RELEASE_OF_BEARER (4)
                Specific-Action: IP_CAN_CHANGE (6)
                Framed-IP-Address: 172.16.xx.yy (0x0aAAAAcB)
                Supported-Features:
                                Vendor-Id: XXXX
                                
                Service-Info-Status: FINAL SERVICE INFORMATION (0)
                QPS-Internal-Route-Record-Host: XXXX.ims.mncXYZ.mccXYZ.3gppnetwork.org
                QPS-Internal-Route-Record-Realm: XXXX.ims.mncXYZ.mccXYZ.3gppnetwork.org
        DEBUG MSGS:
                INFO   : (core) Tagging message with ID: RX_TGPP
                INFO   : (core) Successful load by key: imsiFramedIpKey:111111111111111:172.16.xx.yy  <<<<<<<<<
                INFO   : (core) Start session triggered
                INFO   : (rx) Success binding to Gx session 0008-diamproxy.AAAA.cisco.com;11111111;111111111;5c765a28-3b02 by IMSI And IP Address
                INFO   : (TGPP) [Rel8, Rel9, Rel10] features supported for Vendor-Id XXXX, Feature-List-ID X
                INFO   : (core) domain: IMS
                INFO   : (rx) Sending AAA Message on session pcsf-stdn.imsgroup1-111-1111111.aaa.sbc.bbb.com;316160;1;5.2551556468.2;pcsf-stdn.imsgroup1-111-1111111
                INFO   : (gx) Installing preconfigured rule: _1_1_2_AF_AUDIO
                INFO   : (gx) Installing preconfigured rule: _1_1_1_AF_AUDIO
                INFO   : (et) Event trigger 2 added
                INFO   : (et) Event trigger 5 added
                INFO   : (et) Event trigger 6 added
                INFO   : (et) Event trigger 7 added
                INFO   : (gx) Sending RAR Message on session 0008-diamproxy.AAAA.cisco.com;11111111;111111111;5c765a28-3b02
        SERVICE CALC MSGS:
        USE CASES:
                INFO   : (use-cases) Use case 'XXXX IMS Default', status: true, Condition: No Condition Set
        SENT MESSAGES (asynchronous):
        Message: com.broadhop.diameter2.messages.DiameterResponseMessage
                Application Id: Rx (16777236)
                Command Code: Rx_AAA (265)
                Dest host: XXXX.ims.mncXYZ.mccXYZ.3gppnetwork.org
                Dest realm: XXXX.ims.mncXYZ.mccXYZ.3gppnetwork.org
                Device protocol: RX_TGPP
                End to end id: 182837146 (0x0ae5df9a)
                Hop by hop id: 2274945953 (0x8798eba1)
                Origin state: 0
                Stack name: null
                Origin realm: pcrf.mncXYZ.mccXYZ.3gppnetwork.org
                Session-Id: pcsf-stdn.imsgroup1-111-1111111.aaa.sbc.bbb.com;316160;1;5.2551556468.2;pcsf-stdn.imsgroup1-111-1111111
                Auth-Application-Id: 16777236
                IP-CAN-Type: 3GPP_EPS (5)
                RAT-Type: EUTRAN (1004)
                Supported-Features:
                        Vendor-Id: XXXX
                        
                QPS-Internal-Route-Record-Host: XXXX.ims.mncXYZ.mccXYZ.3gppnetwork.org
                QPS-Internal-Route-Record-Realm: XXXX.ims.mncXYZ.mccXYZ.3gppnetwork.org
           Result-Code: DIAMETER_SUCCESS (2001)
        
 

From the consolidated-qns logs also it seems that binding of Gx with Rx session does not happen. This can be seen in the consolidated-qns logs by an exception shown here.

HOSTNAME-qnsXX yyyy-mm-dd 02:23:03,445 [pool-3-thread-1] WARN  c.b.policy.impl.RulesPolicyService - An exception was thrown while executing a policy action.

java.lang.NullPointerException: null   <<<<<<<<<<

        at com.broadhop.diameter2.policy.rx.tgpp.DiameterRxTGPPDeviceMgr.getGxSession(DiameterRxTGPPDeviceMgr.java:1104)

        at com.broadhop.diameter2.policy.rx.tgpp.DiameterRxTGPPDeviceMgr.filterEvent(DiameterRxTGPPDeviceMgr.java:7418)

        at com.broadhop.blueprint.master.MasterBlueprint.filterEvent(MasterBlueprint.java:1283)

        at com.broadhop.blueprint.master.MasterBlueprint.executionPreSession2(MasterBlueprint.java:245)

        at com.broadhop.policy.Rule_Execute_Presession_Phase_2__392a9765_1022_4823_b082_cde9f22abf37__e4BawWmREeKEu46lGH_XOQ__0.consequence(Unknown Source)

Solution

The full DB scan throttle is enabled and is set to 5. It is observed that the number of Rx AARs increases and goes beyond 110 (5*22), and at the same time, Rx AAA responses 5012 are observed.

This because the throttle is set to 5 and there are 22 QNS VMs and the full DB scan only allows 110 requests.

All other requests are being dropped with the error response. All the AAR requests do a full DB scan as they have not yet configured IMSIandframedIP key in lookaside keys.

This is the procedure to resolve the issue:

Step 1. Add imsiFramedIpKey under PB – cluster – lookaside key prefixes.

Step 2. Wait until publish successfully (wait 5 min after publish).

Step 3. Go back to the “Cluster Manager” terminal and restart qns process using restartall.sh script.

Step 4. Once restart operation is completed run diaganostics.sh script to verify CPS is up and running.

Step 5. Login to the one of the QNS OSGI console using telnet command:

telnet <qns vm host name> 9091        [Eg:- telnet qns01 9091]


Execute “rebuildAllSkRings” command on OSGI console to rebuild the configured “Lookaside Key Prefixes” so qns process start utilizing it

osgi> rebuildAllSkRings

                                           Please wait until execution completes

                                           Execute “disconnect” command on console and it waits for user input just press “Enter” key to come out from OSGI console.

                                                         osgi> disconnect

Disconnect from console? (y/n; default=y)

Connection closed by foreign host.