Troubleshooting Guide for Cisco Unified SIP Proxy

First Published: September 21, 2015

NOTE: Works with document’s Advanced Properties “First Published” property. Click File | Properties | Advanced Properties | Custom.

Last Updated: September 21, 2015

 

Contents

Application Note: Troubleshooting High CPU Issues

Application Note: Ping Mechanism in Cisco Unified SIP Proxy

Application Note: Simplified Call Routing Using Modify-key

Application Note: CUSP Logging on SRE Platforms

Application Note: Role Based Authorization using Radius (AAA)

Application Note: Troubleshooting High CPU Issues

This note describes the common causes and symptoms of high CPU utilization on Cisco Unified SIP Proxy (CUSP) running on Cisco Services-Ready Engine (SRE) and Cisco UCS servers. Also, the note provides guidelines to diagnose and troubleshoot the condition.

CPU Graph Definitions for Cisco Unified SIP Proxy

Cisco Unified SIP Proxy captures average and peak CPU utilization data (with resolution in seconds) and updates the following graphs:

■        CPU per Second

■        CPU per Minute

■        CPU per Hour

The Average CPU definition for minute and hour graph is as follows:

1-hour graph: Cisco Unified SIP Proxy takes the average of peak CPU from one minute window for the corresponding hour.

72-hour graph: Cisco Unified SIP Proxy takes the average of peak CPU from 1-hour window for the corresponding 72 hours.

If the system is actively taking calls under normal load, the CPU utilization on the Max CPU line (with one hour and 72-hour graphs) is expected to reach 100 percent. However, a CPU utilization tending toward 100 percent on the average CPU line indicates system malfunction.

High CPU Utilization Scenarios on Cisco Unified SIP Proxy

Majorly average CPU utilization on CUSP spikes during the following scenarios:

1.     Calls Per Second (CPS) crossing the license limit

Performance data is collected at a 30-second interval, and all the statistics are calculated based on this data (average, peak CPS, and so on). If this peak rate is maintained, then the five minute average increases. If the peak rate crosses license limit, then CUSP rejects all calls for 30 seconds and observes if the five minute average is below the limit. If five minute average is not below the license limit, then CUSP rejects calls in 30-second duration until the five minute average drops below the limit.

If CPS crosses the license limit condition, following set of information is seen in default trace logs:

license.LicenseChecker – Average Request Rate exceeded the licensed limit of 100.0/sec

license.LicenseChecker – Current Average Request Rate: 123.24/sec

license.LicenseChecker – Request Rate calculated for last 300 seconds divided into 10 blocks of 30 seconds each

license.LicenseChecker – 9019 0 0 0 9239 0 0 6183 0 11242 à Calls received in 30 seconds windows

license.LicenseChecker – Dropping requests until the average request rate is 100.0 or less

If peak CPS (CPS across any 30-second window) exceeds the license limit, it is highly recommended to increase the license limit to avoid any unexpected service outage. Since Calls gets rejected by CUSP during these conditions, entity pumping the traffic to the CUSP may retry the calls again. It can lead to CPS avalanche and CPU spike.

2.     Tracing set to debug levels

Trace logging set to debug level on CUSP can lead to high CPU utilization (due to logging activity) for the following components:

■        Proxy-core

■        Proxy-transactions

■        Routing

■        Base-Tracing

Recommendations on enabling logging with CUSP SRE Module in production environments can be found in the section CUSP Logging on SRE Platforms.

3.     GUI-based SIP logging

SIP logging in CUSP can be enabled from command-line Interface (CLI) or Graphical User Interface (GUI). Enabling the logging from GUI leads to storing logs in Postgres database for supporting operations like search, delete, and so on. Since database operations on CPU are intensive, we recommend not using GUI based logging for SIP.  The alternative is to use CLI-based logging with logs stored in PFS file system. For analysis, logs can be retrieved offline using FTP.

For limitations of GUI-based SIP logging, refer http://www.cisco.com/c/en/us/td/docs/voice_ip_comm/cusp/rel8_5/OLH/gui_config_olh/troubleshooting.html.     

4.     Network issues causing socket level exceptions in CUSP

Some of the commonly seen cases where CPU utilization is high with CPS less than the minimum value are:

■        Socket level exceptions related to remote element connections

■        Network connection flapping and network elements going up and down

■        Remote element not responding in the same rate as it is receiving requests      

For example, DsSipLlApi.Connection - Exception while accessing the socket channel: closing it and java.io.IOException: socket read error.

Symptoms

In genuine cases where average CPU goes high, the following behavior is expected from CUSP:

■        No response to incoming requests

■        Delay in call routing

Currently CUSP does not have CPU-based call admission control to reject calls on reaching the threshold. When CUSP responds with any failure response (4XX/5XX), it doesn’t mean that CUSP is getting into high CPU utilization state.

Debugging CUSP with High CPU Utilization

There are no specific debugs required or present for handling high CPU utilization conditions. To verify if high average-CPU utilization on CUSP is related to CUSP or the network, the following steps are recommended:

■        Check the performance data using “show performance-data cps” command for any license over limit condition. With this data, you get the call-rate information for last 30 minutes.

■        Check short duration packet capture on CUSP (host router interface) or switch to check the responsiveness for incoming requests and delay in forwarding the requests.

■        Check the default trace logs on CUSP for any exceptions and check if they are related to network.

Limitations

■        Information on process-level CPU utilization on CUSP is not available. This information helps in identifying the process consuming more CPU in genuine cases. It is addressed as part of serviceability enhancement release.

■        No existing TCP or TLS connection to understand any hung or open connections. It reduces the need for packet capture in connection failure condition. This issue is addressed as part of serviceability enhancement release.

■        Enabling debug traces lead to CPU issues. Development is going on to set an alert when user is enabling debug traces from CLI or GUI. Refer to DDTS (CSCut49136) for more details.

■        SIP logging enablement from CLI and GUI is not in sync and there is no option for user to enable PFS-based SIP logging from GUI. Refer to DDTS (CSCus98850) for more details.

Application Note: Ping Mechanism in Cisco Unified SIP Proxy

This note describes different configuration methods available in Cisco Unified SIP Proxy (CUSP) running on Cisco Services-Ready Engine (SRE) and Cisco UCS servers. The configuration methods are used for monitoring the status of server group elements, PING logic, and debugging issues related to element status. Also, it provides recommendations for troubleshooting PING related issues in production environments.

Methods Available for Element Monitoring

Unified SIP proxy supports following SIP methods for status monitoring. Actual SIP method used depends on the method chosen while defining the PING network.

■        OPTIONS

■        PING

■        INFO

CUSP supports the following three different types of PING mechanisms:

■        Proactive PING

■        Reactive PING

■        Adaptive PING

Proactive PING

With Proactive PING, pinging is performed to enable and disable network elements, and both are pinged at the same interval. This method will consume more bandwidth compared to reactive or adaptive options.

Reactive PING

With Reactive PING, pinging is performed only to disable elements. This method is used where network bandwidth consumption is a concern.

Adaptive PING

With Proactive PING, pinging is performed to enable and disable elements, but both pings are at different intervals.

Configuration

Enable SIP ping at global level using the following CLI command: server-group sip global-ping. Or, select Enable for Global Ping under general settings of Server Groups section in graphical user interface.

Define PING server group for the corresponding network. PING group can be configured using GUI as well as CLI. The following configuration is an example for enabling PING using SIP OPTIONS method for all the server group elements using network sipnet3:

server-group sip ping-options sipnet3 9.35.30.109 4004

method OPTIONS – Method can be (OPTIONS / PING / INFO)

 ping-type adaptive 2000 2000 – ping-type can be proactive/adaptive/reactive

 timeout 500 – maximum time between ping and corresponding response

 end ping

For more details on configuration, refer to the following CLI or GUI configuration guides:

http://www.cisco.com/c/en/us/td/docs/voice_ip_comm/cusp/rel8_5/cli_config/cusp_cli_config.html

http://www.cisco.com/c/en/us/td/docs/voice_ip_comm/cusp/rel8_5/OLH/gui_config_olh.html

Behavioral difference with transports

By default, CUSP sets the retry count as two for UDP and as one for TCP, and TLS transports. CUSP sets the retry count for the element to the values mentioned and starts to decrement when it fails to get a response from the remote element. On reaching a retry count of zero, CUSP will mark the element as disabled (down) and take the element out of call routing. On receiving successful PING response from the element that is marked as disabled, it will mark the element is ‘enabled’ (UP) and reset the retry count to the configured values. CUSP will maintain the same retry count on successful responses from elements that are already in UP state. Changing the retry count can be done using CLI as well GUI. Following are the default configuration created for server group retry for different transports.

server-group sip element-retries udp 2                                                                                                                                   server-group sip element-retries tls 1                                                                                                                                     server-group sip element-retries tcp 1

Debugging

1.     Using Trace logs

UDP Element: Enabling “sip-ping” component logs to debug level will provide the following details.

Element is up and steady:

[DsPingThread: network=vcusporig3 type=proactive/adaptive] DEBUG 2015.07.09 16:23:44:902 DsPings.PingThread – Sending adaptive ping to the up element vcusporig3:9.35.30.169:5060:1 numTries=2 – When sending OPTIONS to Element

[DsPingUDPResponseThread: network=vcusporig3] DEBUG 2015.07.09 16:23:44:904 DsPings.PingObject – Endpoint(vcusporig3:9.35.30.169:5060:1 numTries=2): number of tries reset to: 2 – On successful response, count will get reset to 2

Element is down and steady:

[DsPingThread: network=vcusporig3 type=proactive/adaptive] DEBUG 2015.07.09 16:37:45:035 servergroups.PingObjectIterator - Ping List: [vcusporig3:9.35.30.169:5060:1 numTries=2] – First PING request sent

[DsPingStatusThread: network=vcusporig3] DEBUG 2015.07.09 16:37:45:668 DsPings.StatusThread - Endpoint(vcusporig3:9.35.30.169:5060:1 numTries=2): Ping timeout – First PING Request timed out

[DsPingStatusThread: network=vcusporig3] DEBUG 2015.07.09 16:37:45:668 DsPings.PingObject - Endpoint(vcusporig3:9.35.30.169:5060:1 numTries=1): number of tries left: 1 – Number of tries decrements by one

[DsPingStatusThread: network=vcusporig3] DEBUG 2015.07.09 16:37:47:672 DsPings.StatusThread - Endpoint(vcusporig3:9.35.30.169:5060:1 numTries=1): Ping timeout – Second PING Request timed out

[DsPingStatusThread: network=vcusporig3] DEBUG 2015.07.09 16:37:47:672 DsPings.PingObject - Endpoint(vcusporig3:9.35.30.169:5060:1 numTries=0): number of tries left: 0 – Number of tries decrements by one

[DsPingThread: network=vcusporig3 type=reactive] DEBUG 2015.07.09 16:37:48:143 DsPings.PingThread - Sending adaptive ping to the down element vcusporig3:9.35.30.169:5060:1 numTries=0 – Proactive PING sent to an element that is marked as down

Element status fluctuating:

16:45:32:337 DsPings.PingThread - Sending adaptive ping to the down element                       vcusporig3:9.35.30.169:5060:1 numTries=0 – Proactive PING sent to an element that is marked as down

[DsPingStatusThread: network=vcusporig3] DEBUG 2015.07.09 16:45:32:883 DsPings.StatusThread - Endpoint(vcusporig3:9.35.30.169:5060:1 numTries=0): Ping timeout

[DsPingUDPResponseThread: network=vcusporig3] DEBUG 2015.07.09 16:45:33:343 DsPings.DsPingsSipInterfaceImpl – Endpoint(vcusporig3:9.35.30.169:5060:1 numTries=0):            Received UDP ping response – Received successful response for PING Request

[DsPingUDPResponseThread: network=vcusporig3] DEBUG 2015.07.09 16:45:33:343 DsPings.PingObject - Endpoint(vcusporig3:9.35.30.169:5060:1 numTries=2): number of tries reset to: 2 – Element gets marked as UP and NumTries gets reset to 2

TCP and TLS element: Ping logic for TCP and TLS works in the same way as how it works with UDP. With default configurations, numtries for PING will be set to one for both TCP and TLS. The following log is seen with TCP element with fluctuating status.

 

[DsPingThread: network=vcusporig3 type=reactive] DEBUG 2015.07.09 17:15:47:459 DsPings.PingThread - Sending adaptive ping to the down element vcusporig3:9.35.30.162:5060:2 numTries=0

[TCP/TLS Pinging Queue.1] DEBUG 2015.07.09 17:15:48:719 DsPings.DsPingsSipInterfaceImpl -Endpoint(vcusporig3:9.35.30.162:5060:2 numTries=0): TCP ping connection setup succeeded

[DsPingTCPResponseThread: vcusporig3:9.35.30.162:5060:2 numTries=1] DEBUG 2015.07.09 17:15:48:720 DsPings.PingObject – Endpoint(vcusporig3:9.35.30.162:5060:2 numTries=1): number of tries reset to: 1

Retry count default value (1) of TCP and TLS can be changed using below mentioned global command                   server-group sip element-retries tcp <1-10>                                                                                                                       server-group sip element-retries tls <1-10>

2.     Using Packet capture

Short duration packet capture on host router interface (in case of SRE Module) or on switch port (for both SRE CUSP and vCUSP) should help in checking the PING traffic towards the elements that are marked as down. Packet capture will help in understanding the status of PING threads and response from remote elements. With firewall in between remote element and CUSP, there are high chances of packet drops that results in element getting marked as down even though the remote element is up and running. Packet capture taken on CUSP side can rule out such issues.

3.     Using JMC

Using JMC (Java mission control) running on a remote machine administration connects to CUSP using CUSP IP address and ephemeral port (9999) to check the status of CUSP including ping threads. For information on connecting CUSP using JConsole or JMC, refer https://techzone.cisco.com/t5/Cisco-Unified-SIP-Proxy-CUSP/Configure-JCONSOLE-for-CUSP/ta-p/520457.

If there is no PING traffic from CUSP, JConsole or JMC connection to CUSP can provide information about ping threads running in CUSP.

PING logic

■        CUSP server group monitoring is based on configured SIP network.

■        CUSP default PING mechanism is adaptive.

■        Properties of SIP PING server group defined are applicable for all the server groups defined under one SIP network.

■        Ping interval defined in SIP PING server group is the interval between two consecutive ping requests originated from ping source.

Note: To prevent pings from being sent out in bursts, elements are not pinged simultaneously; they are pinged at a specified interval. For example, the ping interval is set to 50 milliseconds and there are three elements configured for a server group. A ping is sent to the first element. After 50 milliseconds, a ping is sent to the second element. Finally, after an additional 50 milliseconds, a ping is sent to the third element.

■        CUSP will originate PING request with max-forwards set to “0” to ensure it gets response from the immediate element.

■        CUSP PING mechanism doesn’t need licensing. CUSP PING logic runs in cases of no license or exceeded license as well.

■        Any 4XX/5XX response to PING request will be treated as successful response and element status will be updated accordingly.

■        An element responding with 503 (due to SIP services or application unavailability) will be marked as UP and it will be used for routing the calls. There is a DDTS filed (CSCus98962) to change the behavior with 503.

■        SIP logging in CUSP will not capture SIP logs corresponding to PING. Use debug level trace logs for ping component (sip-ping).

■        In case of proactive ping, CUSP creates below list of threads for each UDP ping network:

—      DsPingThread (type = proactive/adaptive)

—      DsPingListenThread

—      DsPingStatusThread

—      DsPingUDPResponseThread

Note: If CUSP has three different UDP networks serving multiple server groups, the total number of ping threads running will be 12 (Number of Ping networks multiplied by 4). This count can help in matching the ping threads and check if there is any thread leak present.

■        In case of  reactive ping, CUSP creates below list of threads for each UDP ping network

—      DsPingThread (type = reactive)

—      DsPingListenThread

—      DsPingStatusThread

—      DsPingUDPResponseThread

Note: If CUSP has three different UDP networks serving multiple server groups, the total number of ping threads running will be 14 (Number of Ping networks multiplied by 4). This count can help in matching the ping threads and check if there is any thread leak present.  

■        In case of  adaptive ping, CUSP create below list of threads for each UDP ping network

—      DsPingThread (type = proactive/adaptive)

—      DsPingThread (type = reactive)

—      DsPingListenThread

—      DsPingStatusThread

—      DsPingUDPResponseThread

Note: If CUSP has three different UDP networks serving multiple server groups, the total number of ping threads running will be 15 (Number of Ping networks multiplied by 5). This count can help in matching the ping threads and check if there is any thread leak present.

■        In case of TCP or TLS elements, CUSP will create one “DsPingResponseThread” for each element in the network. The remaining threads per network will be same as UDP.

■        Any changes to server group (Element addition, deletion, changing properties of an element, addition of server group, or deletion of server group) will result in re-initialization of Ping threads for all the networks.

■        In case of TCP or TLS transports, CUSP will use ephemeral source port for sending SIP PING messages to the server group elements. In this case, the PING port defined in the PING server group is of no-op.

■        Element status is controlled not just by the PINGs but also by the normal SIP traffic. The elements status can go down if the endpoint does not respond to SIP traffic.

Recommendations

■        With adaptive PING configuration, it is recommended to configure shorter interval for disabling (down) and longer interval for enabling (up). This will make CUSP to send PING requests relatively faster in disabled state.

■        It is highly recommended to enable SIP PING on all the server groups. Server group defined without SIP PING can lead to infinite disabled (down) state for elements in that group.

■         Enabling debug level trace logs for sip-ping component will have performance impact and it is highly recommended to enable sip-ping debugs only if required with CPS on CUSP less than 25 CPS. For more details on enabling logs on SRE platforms, refer App Note for CUSP Logging On SRE Platforms.

■        It is highly recommended not to use same server group element defined in multiple server groups that are using different networks. In these conditions, network elements marked as disabled (down) on group will lead to marking the element as disabled (down) in other networks as well.

■        In case of a network element that is marked as disabled (down) and not coming up, follow the following debugging steps:

—      Short duration packet capture on CUSP to monitor PING traffic.

—      Connect to CUSP using JConsole or JMC and check the corresponding ping threads existence and corresponding status if PINGs are not going at all or to selective elements.

—      If connecting to CUSP using JConsole or JMC is a problem (due to restrictions in customer environment), enable trace logs (debug) for sip-ping component for short duration and check the CUSP PING behavior towards problematic elements.

Application Note: Simplified Call Routing Using Modify-key

Problem description:  In complex deployments where route tables gets implemented with huge number of entries for supporting  granual routing (as mentioned in below example) maintaining configuration gets cumbersome.

policy lookup Cusp-Route-Policy

sequence 200 Cusp-Route-Table request-uri uri-component user

  rule prefix

  end sequence

end policy

!

route table Cusp-Route-Table

key 2080 target-destination Cusp-OutLeg-Nw-Group outlegB

key 2081 target-destination Cusp-OutLeg-Nw-Group outlegB

key 2082 target-destination Cusp-OutLeg-Nw-Group outlegB

key 2083 target-destination Cusp-OutLeg-Nw-Group outlegB

key 2084 target-destination Cusp-OutLeg-Nw-Group outlegB

key 2085 target-destination Cusp-OutLeg-Nw-Group outlegB

key 2086 target-destination Cusp-OutLeg-Nw-Group outlegB

key 2087 target-destination Cusp-OutLeg-Nw-Group outlegB

key 2088 target-destination Cusp-OutLeg-Nw-Group outlegB

key 2089 target-destination Cusp-OutLeg-Nw-Group outlegB

key 3080 target-destination Cusp-OutLeg-Nw-Group outlegB

key 3081 target-destination Cusp-OutLeg-Nw-Group outlegB

key 3082 target-destination Cusp-OutLeg-Nw-Group outlegB

key 3083 target-destination Cusp-OutLeg-Nw-Group outlegB

key 3084 target-destination Cusp-OutLeg-Nw-Group outlegB

key 3085 target-destination Cusp-OutLeg-Nw-Group outlegB

key 4084 target-destination Cusp-OutLeg-Nw-Group outlegB

end route table

!

Solution: In scenarios where route table contains numbers of similar pattern, route table can be simplified by using “modify-key” option in the route policy.

Keys of similar patterns in the route table can be matched by a regular expression (modify-key parameter in the route policy).  The replace will be used as a key in the route table. This match-replace pattern is only for route table lookup and does not perform any message normalization.  This will reduce the overall configuration complexity.

In the above definition we can see three types of patterns:

                  Series starting from 2080 to 2089

                  Series starting from 3080 to 3085

                  Number 4084

The patterns defined above can be replaced with multiple regular expressions and replace it with a single number that can be used for corresponding route table lookup.

policy lookup Cusp-Route-Policy

sequence 200 Cusp-Route-Table request-uri uri-component user

  modify-key 208. 2084

  rule prefix

  end sequence

sequence 300 Cusp-Route-Table request-uri uri-component user

  modify-key 308[0-5] 3084

  rule prefix

  end sequence

sequence 400 Cusp-Route-Table request-uri uri-component user

  rule exact

  end sequence

end policy

      route table Cusp-Route-Table

key 2084 target-destination Cusp-OutLeg-Nw-Group outlegB

key 3084 target-destination Cusp-OutLeg-Nw-Group outlegB

key 4084 target-destination Cusp-OutLeg-Nw-Group outlegB

end route table

Additional Information

Policy lookup modify-key match/replace option supports all numerical regular expressions and the scope of the modify-key is limited to the respective sequence only. For example, Policy defined below has six match patterns covering different range. This definition will reduce the route table entries to significantly a small number (7) at a cost of route table with 1000 plus entries to eight entries.

policy lookup Cusp-Route-Policy

 sequence 200 Cusp-Route-Table2 request-uri uri-component user

  modify-key 208. 2084

  rule prefix

  end sequence

 sequence 300 Cusp-Route-Table3 request-uri uri-component user

  modify-key 308. 3084

  rule prefix

  end sequence

 sequence 400 Cusp-Route-Table4 request-uri uri-component user

  rule exact

  end sequence

 sequence 500 Cusp-Route-Table5 request-uri uri-component user

  modify-key 508[2-4] 5084

  rule exact

  end sequence

 sequence 600 Cusp-Route-Table6 request-uri uri-component user

  modify-key 6[0-8].[0-8] 6084

  rule prefix

  end sequence

 sequence 700 Cusp-Route-Table7 request-uri uri-component user

  modify-key 7[000-999] 7084

  rule prefix

  end sequence

 sequence 800 Cusp-Route-Table8 request-uri uri-component user

  modify-key 8..[00-99] 8084

  rule prefix

  end sequence

 end policy

!

Application Note: CUSP Logging on SRE Platforms

This document describes different logging options available for CUSP deployed on SRE platforms and recommendations for enabling logs in production environment.

Logging Options available in CUSP

Cisco Unified SIP Proxy has three different types of logging mechanisms. Each of them captures different set of information that can be used for diagnosing issues in production. These debugs can be enabled to diagnose/root cause issues and need not be turned on all the time. Below are the available logging options in CUSP. Details can be found in the next set of sections.

■        Trace logs

■        SIP logs

■        Peg Counting

 

Trace Logs

Trace logs captures the proxy application level logging and is used to debug: errors related to call routing, server group element status errors, load balancing issues, license updates, access and configuration related changes. Trace enable is used to enable trace logging. Level can be set for various categories.

There are different levels of logging available in CUSP. The major ones are:

Info: provide the brief history of the function calls along with transaction parameters.

Debug: Verbose level of logging and defined only for running with minimal calls volume. It is not recommended to enable debug level of trace logging for any component in production systems. This can severely impact the performance of the CUSP. This is designed for troubleshooting issues under test environments only.  If you accidentally enabled debug level with high call volume and see any side effects on the CUSP, please reboot the box. 

Default: Captures exceptions and major error debugs. Default is equal to warn level tracing.

Show trace options will display the levels for each category.

Trace file rotates every 10MB.

CUSP now supports 5 GB of trace logs but default-logging size is 200MB.

Trace log can be accessed by FTPing to the module.  (cusp/log/trace)

SIP Logging

By default sip logging will be turned off. SIP logging captures the complete sip transactions handled by CUSP including ping messages. Logs are stored in the system for a week by default and get overwritten after that. SIP logging will be useful to deal with issues related to normalizations, header modifications etc.

“show sip message log” will display the sip logs

SIP log can be accessed by ftping to the module. (cusp/log/sipmsg/)

Peg Counting

By default peg counting will be turned off. Peg counting captures the total SIP requests and responses handled by CUSP within the defined interval. Data for the defined interval will be captured and append to the peg counting log file. Peg counting can be used for debugging issues related to overloading of CUSP in record route mode. Minimum interval recommended for peg counting is 60 seconds.

“show sip peg-counting log” will display the peg counting logs

Peg log can be accessed by FTPing to the module (cusp/log/pegcount/)

Impact of Record-Route

By default record route will be turned off (this mode is called as lite mode). In lite mode only the initial transaction of the call will be traversed via CUSP and CUSP will be out of the loop for the next set of transactions within the dialog. With record route enabled (network level) CUSP will add its own route header while forwarding requests. With record route option CUSP will be in the signaling path for all the transactions related to a call. Since number of messages traversing Unified SIP Proxy will be more, there will be significant impact on the performance with logging enabled. In record route mode it is always recommended to check the number of transactions / messages involved for targeted call flows.

Tests Overview

Tests are primarily designed to capture the different set of logs that are needed to diagnose the common problem we can see in the deployment.

Routing: This set of logs is identified to diagnose the issues related to call routing / load balancing errors. Below are the components that deal with these types of errors.

■        Routing

■        Proxy-transactions

■        Proxy-core

Combination of sip logging, peg counting and routing logs around problematic period can be used to nail down the issue further. Info level logging for these components can provide overview of the issue.

PING issues: This set of logs are identified to diagnose the issues related to server group element status change / flapping / PING failures / load balancing issues / call retry failures. Following are the components that deal with this type of errors:

■        sip-ping

■        Routing

Combination of sip logging, peg counting around this period can be used to resolve the issue.

Test scope and Results

Tests are conducted on SRE 910 platforms running 8.5.8 version of CUSP. Info level trace logging for below components are enabled for all the tests conducted.

■        Config-management

■        Accounting

Tests are executed with two set of trace level debugs which deals with routing issues and ping related issues and for all these cases sip logging and peg counting is enabled. Below is the consolidated data for tests executed.

 

 

CPS – Calls per second

CC calls – Contact center calls, with record routing enabled approximately 11 transactions will be handled by CUSP for a single call.

Recommendations

With no record route option (for any deployments)

■        Combination of Info level trace logs sip logs, peg counting can be enabled for routing components and sip-ping for a max CPS of 50

■        Combinational logs should not be enabled for CPS beyond 50

■        Only sip logging / peg counting alone can be enabled for CPS beyond 50

With record route option (for contact center deployments)

■        Combination of Info level trace logs sip logs, peg counting can be enabled for routing components and sip-ping for a max CPS of 25

■        Combinational logs should not be enabled for CPS beyond 25

■        Only peg counting alone can be enabled for CPS beyond 25

■        Impact of logging combinations for all other deployments need to be investigated separately

Application Note: Role Based Authorization using Radius (AAA)

Problem Description:  For role based authorization to work with AAA configuration on SRE module, the Unified SIP Proxy user needs to be configured both on the radius server and on the module. The duplicate configuration of users on CUSP and on radius server must be avoided. Also, authorization should work correctly even if the users are configured only on the radius server.

Solution Overview:  By inserting correct attributes in the Radius Access-Response to the Access-Request send by CUSP, it is possible to provide role-based access only with configurations in the radius server.

Please add the following Cisco vendor specific attribute for adding the radius user to a CUSP group.

cisco-avpair= "fndn:groups=cusp-group"

Configuring Role Based Access in Unified SIP Proxy GUI

To configure role based access (user login privileges based on the role assigned) with user information provided only in radius server, use the following configurations in Unified SIP proxy.

1.       Choose Configure > AAA > Authentication

Provide Radius server details in the page to enable remote login validation.

2.       Choose Configure > AAA > Authorization to enable authorization.

3.       Choose Configure > Privileges to create a privilege group.

Create the group with appropriate permissions required for this user group (this has to be done by the CUSP administrator. The user details are provided during installation).

4.       In the Included Operations tab, select the check box corresponding to the required privileges to assign operational privileges to the group.

5.       Choose Configure > Groups to create a CUSP User Group.

6.       Click on the CUSP User Group to assign privileges (See Step 4) to the group.    

Configuring Role Based Access in Radius Server

The following configuration provided is based on the Openradius.

Note: Radius server configuration varies based on the radius server used in deployment.

1.       Add Cisco Unified SIP Proxy IP address in the clients file

Client 9.41.12.29 {

   ipaddr                       = 9.41.12.29

   secret                       = cusp

}

2.       Add users to the radius server user file

cusp Cleartest-Password   := “cusp”

                   cisco-avpair     = “fndn:groups=cusp-group”

test  Cleartest-Password   := “test”

                   cisco-avpair     = “fndn:groups=cusp-group”

Above “cisco-avpair” is nothing but the user group created in the CUSP. With this association, users (cusp/test in the above example) will get all the capabilities / roles assigned to the cusp user group “cusp-group”.

Additional Information

To create multiple user groups with different privileges (view only / read write of sections / full read write / install or backup-restore), the procedure discussed in earlier sections need to be followed for different user / privilege groups. Users assigned with corresponding cisco-avpair in Radius server will reflect the login capabilities defined in the privilege group.

Sample Unified SIP Proxy Configuration with Multiple User Groups with Different Privileges

aaa authentication server remote

  address 9.0.0.174 credentials hidden à   Radius Server with default authorization port (1812)

  exit

aaa policy system

  authentication-order remote local à try Remote login based on radius and retry using local credentials if remote fails

  exit

license agent max-sessions 9

 

privilege radiustest create à Group with Privilege set 1

privilege radadmin create à Group with Privilege set 2

 

groupname cusp-group create à User Group 1

groupname cusp-admin-group create à User Group 2

username xxxx create

(Privileges created based on capabilities selected in the GUI)

privilege radiustest description "radius test"

privilege radadmin description "radadmin"

privilege radiustest operation cusp.readonlyconfiguration

privilege radiustest operation system.backup

privilege radiustest operation software.install

privilege radadmin operation services.manage

privilege radadmin operation cusp.readonlyconfiguration          

privilege radadmin operation software.install                          

privilege radadmin operation system.debug

privilege radadmin operation user.pin

privilege radadmin operation security.aaa

privilege radadmin operation group.configuration                                            

privilege radadmin operation cusp.configuration

privilege radadmin operation system.view

privilege radadmin operation services.configuration

privilege radadmin operation security.access

privilege radadmin operation system.backup

privilege radadmin operation user.password

privilege radadmin operation security.password

privilege radadmin operation security.pin

privilege radadmin operation user.configuration

privilege radadmin operation system.configuration

(Association of privilege group to user group)

groupname Administrators member xxxx

groupname pfs-privusers member cli

groupname cusp-group privilege radiustest                                 

groupname cusp-admin-group privilege radadmin

Module Trace logs

 

se-9-41-12-29# clear trace file

se-9-41-12-29# trace aaa all

se-9-41-12-29# sh trace buffer

23015 07/11 16:09:04.123 aaa authentication "jaas messages" FndnLoginContext:  Username is cuspadmin Session ID is 53BFBEC8-6613B16E

23015 07/11 16:09:04.123 aaa authentication "jaas messages" FndnLoginContext: Authentication source is RADIUS

23015 07/11 16:09:04.123 aaa authorization "jaas messages" FndnAuthorize SessionID 53BFBEC8-6613B16E: Initializing Authorization object

23015 07/11 16:09:04.123 aaa authorization "jaas messages" FndnAuthorize SessionID 53BFBEC8-6613B16E: Initializing Grouplist

23015 07/11 16:09:04.123 aaa authorization "jaas messages" FndnAuthorize SessionID 53BFBEC8-6613B16E: Getting GM instance

23015 07/11 16:09:04.123 aaa authorization "jaas messages" FndnAuthorize SessionID 53BFBEC8-6613B16E: Building GroupList

23015 07/11 16:09:04.123 aaa authorization "jaas messages" FndnAuthorize SessionID 53BFBEC8-6613B16E: GroupPrincipal is cusp-admin-group

23015 07/11 16:09:04.123 aaa authorization "jaas messages" FndnAuthorize SessionID 53BFBEC8-6613B16E: Building PrivilegeList

23015 07/11 16:09:04.123 aaa authorization "jaas messages" FndnAuthorize SessionID 53BFBEC8-6613B16E: Building OpList

23015 07/11 16:09:04.123 aaa authorization "jaas messages" FndnAuthorize SessionID 53BFBEC8-6613B16E: Checking for superuser

23015 07/11 16:09:04.123 aaa authentication "jaas messages" FndnLoginContext: Making Accounting call

23015 07/11 16:09:04.123 aaa acct "acct info" AcctLib: new FndnAcctRequest: host=se-9-41-12-29,user=cuspadmin,sess=53BFBEC8-6613B16E

23015 07/11 16:09:04.123 aaa acct "acct info" AcctLib: FndnAcctRequest:setEvent=login

23015 07/11 16:09:04.123 aaa acct "acct info" AcctLib: FndnAcctRequest:setStatus=1

23015 07/11 16:09:04.123 aaa acct "acct info" AcctLib: FndnAcctRequest:setSource=1

23015 07/11 16:09:04.123 aaa acct "acct info" AcctLib: FndnAcctRequest:addStringAttribute type=308 value=9.0.0.112

23015 07/11 16:09:04.123 aaa acct "acct info" AcctLib: FndnAcctRequest:addStringAttribute type=301 value=GUI

23015 07/11 16:09:04.123 aaa acct "acct info" AcctLib: FndnAcctRequest:send request enter for event=login

23015 07/11 16:09:04.123 aaa acct "acct info" AcctLib: FndnAcctRequest:send attribute:ATTR_ACCT_SESSION_ID=53BFBEC8-6613B16E

23015 07/11 16:09:04.123 aaa acct "acct info" AcctLib: FndnAcctRequest:send attribute:ATTR_USER_NAME=cuspadmin

23015 07/11 16:09:04.123 aaa acct "acct info" AcctLib: FndnAcctRequest:send attribute:ATTR_NAS_IDENTIFIER=se-9-41-12-29

23015 07/11 16:09:04.123 aaa acct "acct info" AcctLib: FndnAcctRequest:send attribute:ATTR_ACCT_STATUS_TYPE=1

23015 07/11 16:09:04.127 aaa acct "acct info" AcctLib: FndnAcctRequest:send attribute:ATTR_ACCT_AUTHENTIC=1

23015 07/11 16:09:04.127 aaa acct "acct info" AcctLib: FndnAcctRequest:send attribute:ATTR_CLIENT_IP=fndn:client-ip=9.0.0.112

23015 07/11 16:09:04.127 aaa acct "acct info" AcctLib: FndnAcctRequest:send attribute:ATTR_USER_INTERFACE=fndn:user-interface=GUI

23015 07/11 16:09:04.127 aaa acct "acct info" AcctLib: FndnAcctRequest:send sending record to service

Module Show Commands

se-9-41-12-29# show aaa policy

AAA policy: system

  authentication-order remote local

  merge-attributes enable

  preferred-server remote

AAA server: remote

  retries 3

  timeout 5

se-9-41-12-29# show privileges

pfs-read

pfs-readwrite

(Privilege groups created by admin)

radadmin

radiustest

superuser

5 total privilege(s)

se-9-41-12-29#

 

se-9-41-12-29# show privilege detail radadmin

Privilege:          radadmin

Description:        radadmin

Privilege Members:  <none> à members will be derived based on radius based login

Operations:         cusp.configuration cusp.readonlyconfiguration

                    group.configuration security.aaa security.access

                    security.password security.pin services.configuration

                    services.manage software.install system.backup

                    system.configuration system.debug system.view

                    user.configuration user.password user.pin

se-9-41-12-29#

se-9-41-12-29# show users

(Users created for local authentication)

cli

gui

 

2 total user(s)

se-9-41-12-29#

Radius Server logs

Listening on authentication address 9.0.0.174 port 1812

Listening on accounting address * port 1813

Listening on command file /var/run/radiusd/radiusd.sock

Listening on proxy address 9.0.0.174 port 1814

Ready to process requests.

rad_recv: Access-Request packet from host 9.41.12.29 port 32778, id=0, length=76

        User-Name = "cuspadmin"

        User-Password = "cuspadmin"

        Service-Type = Login-User

        NAS-Identifier = "se-9-41-12-29"

        NAS-Port = 0

+- entering group authorize {...}

++[preprocess] returns ok

++[chap] returns noop

++[mschap] returns noop

[suffix] No '@' in User-Name = "cuspadmin", looking up realm NULL

[suffix] No such realm "NULL"

++[suffix] returns noop

[eap] No EAP-Message, not doing EAP

++[eap] returns noop

++[unix] returns notfound

[files] users: Matched entry cuspadmin at line 65

++[files] returns ok

++[pap] returns updated

Found Auth-Type = PAP

+- entering group PAP {...}

[pap] login attempt with password "cuspadmin"

[pap] Using clear text password "cuspadmin"

[pap] User authenticated successfully

++[pap] returns ok

+- entering group post-auth {...}

++[exec] returns noop

Sending Access-Accept of id 0 to 9.41.12.29 port 32778

        Cisco-AVPair = "fndn:groups=cusp-admin-group"

Finished request 0.

Going to the next request

Waking up in 4.9 seconds.

Cleaning up request 0 ID 0 with timestamp +11

Ready to process requests.

Users created from Radius Server

Users created with one set of login privileges –“cusp-view-group”:

cusp Cleartext-Password := "cusp"

            cisco-avpair= "fndn:groups=cusp-group"

 

test Cleartext-Password := "test"

            cisco-avpair= "fndn:groups=cusp-view-group"

 

cusp90 Cleartext-Password := "cusp90"

            cisco-avpair= "fndn:groups=cusp- view-group"

 

cisco Cleartext-Password := "cisco"

            cisco-avpair= "fndn:groups=cusp- view-group"

 

cuspdt Cleartext-Password := "cuspdt"

            cisco-avpair= "fndn:groups=cusp- view-group"

(Users created with one set of login privileges –“cusp-admin-group”)

cuspadmin Cleartext-Password := "cuspadmin"

            cisco-avpair= "fndn:groups=cusp-admin-group"

 

cusp90admin Cleartext-Password := "cusp90admin"

            cisco-avpair= "fndn:groups=cusp-admin-group"

Troubleshooting Tips

To troubleshoot the scenario where Radius server is rejecting or not responding to access request, verify:

1.       Radius Server listens on wrong interface (Radius server running on server with multiple interfaces).

2.       User is already present in the Linux system password file (/etc/passwords). When the system user login takes priority, radius verification is based on the /etc/passwords first. In case of failure, it will check for raddb user information.   

Improper privileges with login:

Cisco and the Cisco logo are trademarks or registered trademarks of Cisco and/or its affiliates in the U.S. and other countries. To view a list of Cisco trademarks, go to this URL: www.cisco.com/go/trademarks. Third-party trademarks mentioned are the property of their respective owners. The use of the word partner does not imply a partnership relationship between Cisco and any other company. (1110R)

Cisco Unified SIP Proxy Software

© 2015 Cisco Systems, Inc. All rights reserved.