Closed Bug 1465253 Opened 2 years ago Closed 2 years ago

rtplogger MOZ_LOG setting truncates lines

Categories

(Core :: WebRTC, defect, P2)

61 Branch
defect

Tracking

()

RESOLVED FIXED
mozilla62
Tracking Status
firefox62 --- fixed

People

(Reporter: thaloun, Assigned: drno)

References

(Blocks 1 open bug)

Details

Attachments

(1 file)

User Agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/66.0.3359.139 Safari/537.36

Steps to reproduce:

Turn up webrtc logging as instructed in https://blog.mozilla.org/webrtc/debugging-encrypted-rtp-is-more-fun-than-it-used-to-be/ and make a call on hangouts or similar service. Examine log file.


Actual results:

The logfile contains packet headers with scrubbed contents, plus metadata indicating rtp versus rtcp.  Except, for larger packets, the text is cut off, critically leaving off the metadata, making it impossible to attribute the packet to one media stream or another.

Example:
2018-05-24 20:20:40.603572 UTC - [51016:Socket Thread]: D/signaling [Socket Thread|SrtpFlow] SrtpFlow.cpp:198: Successfully protected an SRTCP packet of len 94
2018-05-24 20:20:40.603574 UTC - [51016:Socket Thread]: D/signaling [Socket Thread|MediaPipeline] MediaPipeline.cpp:1878: ae5575fa75870621| Receive video sending RTCP packet
2018-05-24 20:20:40.608196 UTC - [51016:Unnamed thread 0x7fb102af1b80]: V/signaling [|WebrtcVideoSessionConduit] VideoConduit.cpp:2179: SendRtp Sent RTP Packet seq 9943, len 1193, SSRC 453575858 (0x1b0904b2)
2018-05-24 20:20:40.608376 UTC - [51016:Socket Thread]: D/signaling [Socket Thread|RtpLogger] RtpLogger.cpp:76: O 13:20:40.608328  000000 90 78 26 d7 12 4d e0 78 1b 09 04 b2 be de 00 03 12 1c b8 52 40 71 34 6d 69 64 5f 30 90 e0 9c fd 06 20 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 0
2018-05-24 20:20:40.608423 UTC - [51016:Socket Thread]: D/signaling [Socket Thread|SrtpFlow] SrtpFlow.cpp:152: Successfully protected an SRTP packet of len 1203
2018-05-24 20:20:40.608425 UTC - [51016:Socket Thread]: D/signaling [Socket Thread|MediaPipeline] MediaPipeline.cpp:1878: ae5575fa75870621| Transmit video[{02e9ccc8-40cd-4363-a379-bc9c78203187}] sending RTP packet




Expected results:

All the packet should have been written.  Or in lieu, some of the redundant 00 data should have been elided.  In that case the packet sizes from any reconstructed pcaps would be wrong but the number and the important header parts would be correct.
Blocks: hangouts
Per Bug 1431543, triaging this as a Core: WebRTC issue.
Component: Untriaged → WebRTC
Product: Firefox → Core
Nils, who should have a look at this one ?
Rank: 15
Flags: needinfo?(drno)
Priority: -- → P2
Assignee: nobody → drno
Status: UNCONFIRMED → NEW
Ever confirmed: true
Flags: needinfo?(drno)
Comment on attachment 8986096 [details]
Bug 1465253: use postfix as prefix when logging and log in clear.

https://reviewboard.mozilla.org/r/251554/#review257928

Hmm. This is probably ok from a security perspective.

::: media/webrtc/signaling/src/mediapipeline/RtpLogger.cpp:37
(Diff revision 1)
>  bool RtpLogger::IsPacketLoggingOn() {
>    return CSFLogTestLevel(CSF_LOG_DEBUG);
>  }
>  
>  void RtpLogger::LogPacket(const MediaPacket& packet, bool input,
>                            size_t headerLength, std::string desc) {

It seems that |headerLength| is no longer used.
Attachment #8986096 - Flags: review?(docfaraday) → review+
Pushed by drno@ohlmeier.org:
https://hg.mozilla.org/integration/autoland/rev/3c53e83acb19
use postfix as prefix when logging and log in clear. r=bwc
https://hg.mozilla.org/mozilla-central/rev/3c53e83acb19
Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla62
You need to log in before you can comment on or make changes to this bug.