[asterisk-dev] [Code Review] 4053: res_pjsip_history: A debugging module for busy systems
Joshua Colp
reviewboard at asterisk.org
Wed Nov 5 07:06:57 CST 2014
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviewboard.asterisk.org/r/4053/#review13687
-----------------------------------------------------------
/trunk/res/res_pjsip_history.c
<https://reviewboard.asterisk.org/r/4053/#comment24181>
This can be allocated without a lock.
- Joshua Colp
On Oct. 8, 2014, 1:55 p.m., Matt Jordan wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviewboard.asterisk.org/r/4053/
> -----------------------------------------------------------
>
> (Updated Oct. 8, 2014, 1:55 p.m.)
>
>
> Review request for Asterisk Developers.
>
>
> Repository: Asterisk
>
>
> Description
> -------
>
> While debugging things at SIPit, I found that the capabilities afforded by res_pjsip_logger to be inadequate for tracing SIP messages on the CLI. Often, so many requests/responses were received -- often with very large SDPs -- in a short period of time that after a single call scenario, the initial requests/responses had already been expunged from the CLI buffer. Furthermore, displaying every single SIP request/response was often counterproductive - OPTIONS, SUBSCRIBE, and even REGISTER requests were often interleaved in the call scenarios, making it difficult to find or trace portions of a call.
>
> This isn't the fault of res_pjsip_logger: it was doing exactly what it was designed to do. And res_pjsip_logger is absolutely necessary for getting full logs when a problem occurs. However, it isn't designed for debugging things on the CLI. Hence, this module.
>
> res_pjsip_history records every request/response received/transmitted through the PJSIP stack, but does not bother dumping them to the CLI. Instead, it provides a few CLI comamnds to access the recorded messages:
>
> * pjsip set history {on|off} - enable/disable the history
> * pjsip show history [min [max]] - display the entire history, or segments of the history.
> * pjsip show entry {num} - display a particular history entry
>
> Because we store all received/transmitted requests/responses, the module is only suitable for debugging purposes. Leaving it permanently odd is a bad idea, for obvious reasons. When the history is turned off, all messages are purged and the history reset.
>
> As an example, we can record some history and display all of the messages:
>
> *CLI> pjsip show history
> No. Timestamp Rx/Tx Address Call-ID SIP Message
> ==== ============== ==================== ==================== ============
> 0000 1412775534.791 RX: 127.0.0.1:22428 d56324c8f042034aae29 OPTIONS sip:127.0.0.1 SIP/2.0
> 0001 1412775534.792 TX: 127.0.0.1:22428 d56324c8f042034aae29 SIP/2.0 200 OK
> 0002 1412775540.277 RX: 127.0.0.1:22428 86cd74e458e76b79e267 OPTIONS sip:127.0.0.1 SIP/2.0
> 0003 1412775540.277 TX: 127.0.0.1:22428 86cd74e458e76b79e267 SIP/2.0 200 OK
> 0004 1412775541.763 RX: 127.0.0.1:22428 f4c0050f5b604fc52ecc INVITE sip:200 at 127.0.0.1 SIP/2.0
> 0005 1412775541.765 TX: 127.0.0.1:22428 f4c0050f5b604fc52ecc SIP/2.0 200 OK
> 0006 1412775541.766 TX: 127.0.0.1:22428 f4c0050f5b604fc52ecc SIP/2.0 200 OK
> 0007 1412775541.780 RX: 127.0.0.1:22428 f4c0050f5b604fc52ecc ACK sip:127.0.0.1:5060 SIP/2.0
> 0008 1412775543.767 RX: 127.0.0.1:22428 f4c0050f5b604fc52ecc BYE sip:127.0.0.1:5060 SIP/2.0
> 0009 1412775543.768 TX: 127.0.0.1:22428 f4c0050f5b604fc52ecc SIP/2.0 200 OK
> 0010 1412775547.823 RX: 127.0.0.1:22428 ab6fc9f37aa1dc5ed038 SUBSCRIBE sip:1000 at 127.0.0.1 SIP/2.0
> 0011 1412775547.824 TX: 127.0.0.1:22428 ab6fc9f37aa1dc5ed038 SIP/2.0 481 Call/Transaction Does Not Exist
> 0012 1412775547.826 RX: 127.0.0.1:22428 ba4ed4625cbb3282b34c REGISTER sip:127.0.0.1 SIP/2.0
> 0013 1412775547.841 TX: 127.0.0.1:22428 ba4ed4625cbb3282b34c SIP/2.0 200 OK
> 0014 1412775549.854 RX: 127.0.0.1:34899 ca022bf6e5a31b306bfd REGISTER sip:127.0.0.1 SIP/2.0
> 0015 1412775549.870 TX: 127.0.0.1:34899 ca022bf6e5a31b306bfd SIP/2.0 200 OK
> 0016 1412775549.876 RX: 127.0.0.1:34899 d92c91d540a36d2cbca1 SUBSCRIBE sip:1000 at 127.0.0.1 SIP/2.0
> 0017 1412775549.876 TX: 127.0.0.1:34899 d92c91d540a36d2cbca1 SIP/2.0 200 OK
> 0018 1412775549.877 TX: 127.0.0.1:34899 d92c91d540a36d2cbca1 NOTIFY sip:1000 at 127.0.0.1:34899;transport=udp;registering_acc=127_0_0_1 SIP/2.0
> 0019 1412775549.877 RX: 127.0.0.1:34899 32cca4f61cbba6cbe47f OPTIONS sip:127.0.0.1 SIP/2.0
> 0020 1412775549.877 TX: 127.0.0.1:34899 32cca4f61cbba6cbe47f SIP/2.0 200 OK
> 0021 1412775549.889 RX: 127.0.0.1:34899 d92c91d540a36d2cbca1 SIP/2.0 200 OK
> 0022 1412775555.376 RX: 127.0.0.1:34899 f65c7ea06475be757d2c INVITE sip:1000 at 127.0.0.1 SIP/2.0
> 0023 1412775555.377 TX: 127.0.0.1:34899 f65c7ea06475be757d2c SIP/2.0 487 Request Terminated
> 0024 1412775555.382 TX: 127.0.0.1:34899 6ddb9f94-9c20-4f83-8 INVITE sip:1000 at 127.0.0.1:34899;transport=udp;registering_acc=127_0_0_1 SIP/2.0
> 0025 1412775555.383 TX: 127.0.0.1:34899 f65c7ea06475be757d2c SIP/2.0 487 Request Terminated
> 0026 1412775560.135 RX: 127.0.0.1:34899 f65c7ea06475be757d2c CANCEL sip:1000 at 127.0.0.1 SIP/2.0
> 0027 1412775560.135 TX: 127.0.0.1:34899 f65c7ea06475be757d2c SIP/2.0 200 OK
> 0028 1412775560.135 TX: 127.0.0.1:34899 f65c7ea06475be757d2c SIP/2.0 487 Request Terminated
> 0029 1412775560.146 RX: 127.0.0.1:34899 f65c7ea06475be757d2c ACK sip:1000 at 127.0.0.1 SIP/2.0
>
> Alternatively, we can display on a subset of the messages:
>
> *CLI> pjsip show history 4 9
> No. Timestamp Rx/Tx Address Call-ID SIP Message
> ==== ============== ==================== ==================== ============
> 0004 1412775541.763 RX: 127.0.0.1:22428 f4c0050f5b604fc52ecc INVITE sip:200 at 127.0.0.1 SIP/2.0
> 0005 1412775541.765 TX: 127.0.0.1:22428 f4c0050f5b604fc52ecc SIP/2.0 200 OK
> 0006 1412775541.766 TX: 127.0.0.1:22428 f4c0050f5b604fc52ecc SIP/2.0 200 OK
> 0007 1412775541.780 RX: 127.0.0.1:22428 f4c0050f5b604fc52ecc ACK sip:127.0.0.1:5060 SIP/2.0
> 0008 1412775543.767 RX: 127.0.0.1:22428 f4c0050f5b604fc52ecc BYE sip:127.0.0.1:5060 SIP/2.0
> *CLI>
>
> We can narrow down things further by displaying only a specific entry in the history:
>
> *CLI> pjsip show entry 4
> INVITE sip:200 at 127.0.0.1 SIP/2.0
> Call-ID: f4c0050f5b604fc52ecca628a9393d3f at 0:0:0:0:0:0:0:0
> CSeq: 1 INVITE
> From: "1000" <sip:1000 at 127.0.0.1>;tag=aece8db8
> To: <sip:200 at 127.0.0.1>
> Via: SIP/2.0/UDP 127.0.0.1:22428;branch=z9hG4bK-3833-5f28322b65a22d22475a18c1b3cb8260
> Max-Forwards: 70
> Contact: "1000" <sip:1000 at 127.0.0.1:22428;transport=udp;registering_acc=127_0_0_1>
> User-Agent: Jitsi2.4.4997Linux
> Content-Type: application/sdp
> Content-Length: 783
>
> v=0
> o=1000 0 0 IN IP4 127.0.0.1
> s=-
> c=IN IP4 127.0.0.1
> t=0 0
> m=audio 5012 RTP/AVP 96 97 98 9 100 102 0 8 103 3 104 101
> a=rtpmap:96 opus/48000/2
> a=fmtp:96 usedtx=1
> a=rtpmap:97 SILK/24000
> a=rtpmap:98 SILK/16000
> a=rtpmap:9 G722/8000
> a=rtpmap:100 speex/32000
> a=rtpmap:102 speex/16000
> a=rtpmap:0 PCMU/8000
> a=rtpmap:8 PCMA/8000
> a=rtpmap:103 iLBC/8000
> a=rtpmap:3 GSM/8000
> a=rtpmap:104 speex/8000
> a=rtpmap:101 telephone-event/8000
> a=extmap:1 urn:ietf:params:rtp-hdrext:csrc-audio-level
> m=video 5014 RTP/AVP 105 99
> a=recvonly
> a=rtpmap:105 H264/90000
> a=fmtp:105 profile-level-id=4DE01f;packetization-mode=1
> a=imageattr:105 send * recv [x=[0-1360],y=[0-768]]
> a=rtpmap:99 H264/90000
> a=fmtp:99 profile-level-id=4DE01f
> a=imageattr:99 send * recv [x=[0-1360],y=[0-768]]
>
> *CLI>
>
>
> Because we cache the actual PJSIP tdata/rdata structures, this module could be taken further in the future by adding filtering mechanisms. Ideally, someone could filter the history on particular call-ids, message types, etc. However, at the sake of having something (and not going too crazy with this on an initial patch), the initial functionality provided in this module should be fairly useful.
>
>
> Diffs
> -----
>
> /trunk/res/res_pjsip_history.c PRE-CREATION
>
> Diff: https://reviewboard.asterisk.org/r/4053/diff/
>
>
> Testing
> -------
>
>
> Thanks,
>
> Matt Jordan
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.digium.com/pipermail/asterisk-dev/attachments/20141105/2e5ec05c/attachment.html>
More information about the asterisk-dev
mailing list