Search the Asterisk Blog

Debugging SIP message traffic with PJSIP History

By Matt Jordan

Debugging SIP Messages the Traditional Way

Since its release, the PJSIP stack has provided logging of SIP message traffic via the pjsip set logger  CLI command. This dumps all received and transmitted SIP messages as a VERBOSE message. This is useful for two scenarios:

  1. When wanting to log all SIP messages in an Asterisk log file.
  2. When attempting to debug SIP messages in real-time via the CLI.

In the first scenario, the existing CLI command works just fine. However, when attempting to debug live SIP calls on a production system with pjsip set logger , the amount of traffic will often flood the CLI. This makes it incredibly difficult to debug SIP calls via the CLI, requiring the use of either the generated log file (which can also be large), or third party tools (such as Wireshark or tcpdump).

While third party tools are often fantastic for helping troubleshoot VoIP issues, on some production systems, it may not be possible to install said tools. As such, it’s still sometimes nice if Asterisk can help troubleshoot issues as well. Coming in Asterisk 13.8.0, a new module – res_pjsip_history  – has been added that provides capturing, filtering, and display of SIP messages. In this post, we’ll cover how to use the module, as well as potential avenues for future enhancements to its functionality.

Using the PJSIP History Module

The PJSIP history module maintains an in-memory history of all sent/received SIP messages that pass through the PJSIP stack. Because the history is stored in-memory, it does not start capturing until told to, and users should be careful to turn off the capture and not leave it running. You can run your system out of memory if you leave it on permanently!

Capturing Messages

To start capturing, run the pjsip set history on  command:

You can stop capturing by running the pjsip set history off  command:

This doesn’t clear the captured history, it merely stops capturing new SIP messages. You can re-enable the capture by running pjsip set history on  again. To clear the history, run pjsip set history clear :

Manipulating a Capture

All of that is fine and good, but how do we look at captured messages?

To show the entire history, we can use pjsip show history , which will provide a summary of the history:

That can be a lot of messages on a busy system. To look at a particular SIP message, we can tell Asterisk to display a specific entry:

Note that the entry numbers are displayed in the left hand column, and are simply a monotonically increasing value for each SIP message received or transmitted. Now that we have a particular INVITE request, we could filter our SIP messages further. pjsip show history  supports a simple filter query syntax similar to SQL or other query languages. To see everything in this dialog, we can filter by SIP Call-ID using pjsip show history where sip.msg.call-id = "3-14157@127.0.1.1" :

There are a number of fields currently supported by the pjsip show history  command, including:

  • number : The PJSIP history entry number
  • timestamp : The time the SIP message was sent or received
  • addr : The source/destination address the SIP message was received from/transmitted to
  • sip.msg.request.method : The SIP request method
  • sip.msg.call-id : The SIP Call-ID header value

The query syntax supports all normal boolean operators, as well as a regex operator ‘LIKE’. This provides quite a bit of flexibility when searching through a large SIP history.

Extending the PJSIP History Filters

Of course, there are a lot of fields in a SIP message that are not currently supported by the pjsip show history  command. In the first release of this module, we wanted to focus on providing what we thought were the most useful fields, as opposed to a comprehensive list of headers/fields that may not be terribly useful. If, however, there is a field that you think would be useful to have, the module is relatively easy to extend!

First, we’d define a new entry to the table of allowed_fields , shown below:

We need to provide three things for an entry here:

  • symbol : The name of the field we want the user to enter. Each one of these in the table has to be unique.
  • return_type : The type of value the user has to enter. This has to be one of the OPT_XXX  types defined in include/asterisk/config_options.h . The functions that define how a boolean operator will handle the field will understand the values defined there, and will know how to interpret the field’s type. Note that OPT_NOOP_T  is used for timestamps, and OPT_SOCKADDR_T  for IP addresses.
  • get_field : Our callback function that determines how to extract the field’s actual value from a PJSIP history entry.

The next step is simply to define the callback function that is referenced by the get_field  attribute. A callback function takes in a pointer to a struct pjsip_history_entry  instance, and must return a void  pointer to the field in that struct  that is the value to be used in the expression. For example, the SIP Call-ID header is extracted as shown below:

The boolean expression evaluators will know that the field pointed to by this function is a string as the return_type  attribute in the allowed_fields  table is a OPT_CHAR_ARRAY_T , and will handle it accordingly.

There Are 4 Comments

  • Pete Kirkham says:

    I’ve tried this:
    *CLI> pjsip show history where sip.msg.request.method =INVITE
    Command ‘pjsip show history where sip.msg.request.method =INVITE’ failed.
    *CLI> [Feb 9 18:27:08] WARNING[3404]: res_pjsip_history.c:992 evaluate_history_entry: Expression was unbalanced: 2 results remained after evaluation
    pjsip show history where sip.msg.request.method = ‘INVITE’
    No. Timestamp (Dir) Address SIP Message
    ===== ========== ============================== ===================================

    What’s the correct syntax.
    There are INVITE records in the file

    • Matt Jordan says:

      The parser in the history module is sensitive to proper spacing. In your example, you don’t have a space between the ‘=’ operator and the SIP request method that you’re trying to filter on; as a result, the two are being combined into a single token, resulting in an unbalanced expression.

      An example of filtering on REGISTER requests:

      asterisk*CLI> pjsip show history where sip.msg.request.method = REGISTER
      No. Timestamp (Dir) Address SIP Message
      ===== ========== ============================== ===================================
      00000 1486663329 * ==> 10.XXX.XX.XX:5060 REGISTER sip:sip.digiumcloud.net:5060 SIP/2.0
      00002 1486663329 * ==> 10.XXX.XX.XX:5060 REGISTER sip:sip.digiumcloud.net:5060 SIP/2.0
      00004 1486663331 * ==> 10.XXX.XX.XX:5060 REGISTER sip:sip.digiumcloud.net:5060 SIP/2.0
      00006 1486663331 * ==> 10.XXX.XX.XX:5060 REGISTER sip:sip.digiumcloud.net:5060 SIP/2.0

Add to the Discussion

Your email address will not be published. Required fields are marked *

About the Author

Matt Jordan

Matt is CTO at Digium and the project lead for Asterisk. Matt joined the team in 2011, and since then has been involved in the development of both Asterisk and the Asterisk Test Suite. His background in software development can best be described as “eclectic”, having worked in a variety of industries. Uniting the various experiences, however, is a firm belief in good software development practices and methodologies and the effect they have on producing quality software (and keeping software developers from going insane).

See All of Matt's Articles

More From
The Digium Blog

  • No items