← View all posts
March 15, 2017

Debugging encrypted RTP is more fun than it used to be

Contributed by Nils Ohlmeier, Hacking on real time communications since 2002

If you ever were in the situation to try to find out why the video quality of your WebRTC call was not good, you probably have also sworn at the encrypted RTP and RTCP. Instead of trying to put log statements into your locally compiled Firefox version, you can now simply request logging of the RTP and RTCP packets.

Bug 1343640 adds support in Firefox version 55 to log the RTP header plus the first five bytes of the payload unencrypted. RTCP will be logged in full and unencrypted.

How to turn on RTP logging

As described on Firefox Media Logging page you have to set environment variables to turn on the logging. Note that we now need to use MOZ_LOG instead of NSPR_LOG as used to be the case. So a real world example which logs the SDP and the RTP would look like this:

  MOZ_LOG=timestamp,signaling:5,jsep:5,rtplogger:5
  MOZ_LOG_FILE=/tmp/logs/moz.log

Alternatively you can also open ‘about:networking‘ in your Firefox browser, open the ‘Logging‘ tab, replace the ‘Current Log Modules‘ value with the MOZ_LOG value from above and click the ‘Set Log Modules‘ button next to it.

Firefox network logging

The result in the log

With those settings, if you now make your WebRTC call with Firefox the moz.log file will contain lines likes this:

  I 14:53:41.688890  000000 81 c9 00 07 90 2f 9e 2e bc 5e 9a 40 00 00 00 00
                            00 00 46 e1 00 00 01 11 09 f3 64 32 00 02 4a 79
                            81 ca 00 0c 90 2f 9e 2e 01 26 7b 39 63 30 30 65
                            62 39 32 2d 31 61 66 62 2d 39 64 34 39 2d 61 34
                            37 64 2d 39 31 66 36 34 65 65 65 36 39 66 35 7d
                            00 00 00 00 81 cb 00 01 90 2f 9e 2e
                            RTCP_PACKET 55f7a768a2ded2f1| Transmit video[{ec753ef6-11c1-be4f-bf5b-33cd30a1146c}]
  O 14:53:41.689346  000000 81 c9 00 07 bc 5e 9a 40 90 2f 9e 2e 00 00 00 00
                            00 00 4a 8b 00 00 01 06 09 f0 ec ae 00 04 c2 1d
                            81 ca 00 0c bc 5e 9a 40 01 26 7b 65 36 62 33 64
                            61 62 38 2d 30 39 61 36 2d 31 33 34 66 2d 62 61
                            65 33 2d 34 63 36 33 65 62 65 63 34 64 36 31 7d
                            00 00 00 00 81 cb 00 01 bc 5e 9a 40
                            RTCP_PACKET 55f7a768a2ded2f1| Receive audio[{65610c20-05d7-8c4d-babf-1e153f90e5b0}]

Note: the lines are broken over several lines here for readability. In the log file each packet is just one really long line.

The log lines are in the text2pcap format. RTP packets will have RTP_PACKET at the end of the line, which allows you to filter for either that or RTCP packets. You might have also noticed that the track ID from the MSID is present. So if you have access to the SDP from the signaling, for example on ‘about:webrtc‘, you can also filter all incoming and outgoing RTP and RTCP messages for a single audio or video track.

Limitations

Right now you will see all incoming RTCP packets multiple times if the call had more then one track in it. The reason is that each track is able to decrypt the RTCP and forwards it down into its RTP stack. But the relevance filtering of the RTCP message happens a lot later in the RTP/RTCP stack.

Convert logs into PCAP

Finally here is one handy line to convert all RTP and RTCP from the log file into a PCAP file which can be loaded and analyzed with Wireshark:

  egrep '(RTP_PACKET|RTCP_PACKET)' moz.log | text2pcap -D -n -l 1 -i 17 -u 1234,1235 -t '%H:%M:%S.' - rtp.pcap

Wireshark allows you now easily to search for example for NACKs or PLIs in the RTCP and check if the requested video packet got send to or by Firefox.

Sample RTP in Wireshark

Note: sometimes Wireshark will show just UDP packets and not RTP. In that case just do a right mouse click on one of the UDP packets and chose “Decode As” and then select RTP from the drop down menu. Then Wireshark will decode the RTP and RTCP packets properly.

And here are two filter criteria for future reference:

  • NACK: ‘rtcp.rtpfb.fmt == 1’
  • PLI: ‘rtcp.psfb.fmt == 1’

Update

If your log lines start with an extra GECKO like this “GECKO(23379) | I 16:36:58.954388” you might need to tweak you grep command to something like this:

  egrep '(RTP_PACKET|RTCP_PACKET)' moz.log | cut -d '|' -f 2 | text2pcap -D -n -l 1 -i 17 -u 1234,1235 -t '%H:%M:%S.' - rtp.pcap