Add probe logging to RtcEventLog.

webrtc/logging/rtc_event_log/rtc_event_log.cc

 /*
  *  Copyright (c) 2015 The WebRTC project authors. All Rights Reserved.
  *
  *  Use of this source code is governed by a BSD-style license
  *  that can be found in the LICENSE file in the root of the source
  *  tree. An additional intellectual property rights grant can be found
  *  in the file PATENTS.  All contributing project authors may
  *  be found in the AUTHORS file in the root of the source tree.
  */
 
@@ skipping 51 matching lines @@
   void LogVideoReceiveStreamConfig(
       const VideoReceiveStream::Config& config) override;
   void LogVideoSendStreamConfig(const VideoSendStream::Config& config) override;
   void LogAudioReceiveStreamConfig(
       const AudioReceiveStream::Config& config) override;
   void LogAudioSendStreamConfig(const AudioSendStream::Config& config) override;
   void LogRtpHeader(PacketDirection direction,
                     MediaType media_type,
                     const uint8_t* header,
                     size_t packet_length) override;
+  void LogRtpHeader(PacketDirection direction,

[terelius, 2017/02/01 13:38:19]

Assuming we always log outgoing packets by calling this function, could we
rename the two functions to LogIncomingRtpHeader and LogOutgoingRtpHeader and
drop the PacketDirection?

[philipel, 2017/02/17 15:15:02]

We could do that, but we will still log outgoing packets that don't have a
cluster id (RTX for example), but I guess you could just use the constant
PacketInfo::kNotAProbe in that case.

[terelius, 2017/02/17 15:50:43]

As far as I can tell, all outgoing packets will have a cluster id with  this CL.
The only call to LogRtpHeader(kOutgoingPacket, ...) is in
RTPSender::SendPacketToNetwork. 

[philipel, 2017/02/20 09:46:47]

If we want to do this change I think we should do it in a separate CL.

+                    MediaType media_type,
+                    const uint8_t* header,
+                    size_t packet_length,
+                    int probe_cluster_id) override;
   void LogRtcpPacket(PacketDirection direction,
                      MediaType media_type,
                      const uint8_t* packet,
                      size_t length) override;
   void LogAudioPlayout(uint32_t ssrc) override;
   void LogBwePacketLossEvent(int32_t bitrate,
                              uint8_t fraction_loss,
                              int32_t total_packets) override;
   void LogAudioNetworkAdaptation(
       const AudioNetworkAdaptor::EncoderRuntimeConfig& config) override;
+  void LogProbeClusterCreated(int id,
+                              int bitrate_bps,
+                              int min_probes,
+                              int min_bytes) override;
+  void LogProbeResultSuccess(int id, int bitrate_bps) override;
+  void LogProbeResultFailure(int id,
+                             ProbeFailureReason failure_reason) override;
 
  private:
   void StoreEvent(std::unique_ptr<rtclog::Event>* event);
+  void LogProbeResult(int id,
+                      rtclog::BweProbeResult::ResultType result,
+                      int bitrate_bps);
 
   // Message queue for passing control messages to the logging thread.
   SwapQueue<RtcEventLogHelperThread::ControlMessage> message_queue_;
 
   // Message queue for passing events to the logging thread.
   SwapQueue<std::unique_ptr<rtclog::Event> > event_queue_;
 
   RtcEventLogHelperThread helper_thread_;
   rtc::ThreadChecker thread_checker_;
 
@@ skipping 236 matching lines @@
     extension->set_id(e.id);
   }
 
   StoreEvent(&event);
 }
 
 void RtcEventLogImpl::LogRtpHeader(PacketDirection direction,
                                    MediaType media_type,
                                    const uint8_t* header,
                                    size_t packet_length) {
+  LogRtpHeader(direction, media_type, header, packet_length,
+               PacketInfo::kNotAProbe);
+}
+
+void RtcEventLogImpl::LogRtpHeader(PacketDirection direction,
+                                   MediaType media_type,
+                                   const uint8_t* header,
+                                   size_t packet_length,
+                                   int probe_cluster_id) {
   // Read header length (in bytes) from packet data.
   if (packet_length < 12u) {
     return;  // Don't read outside the packet.
   }
   const bool x = (header[0] & 0x10) != 0;
   const uint8_t cc = header[0] & 0x0f;
   size_t header_length = 12u + cc * 4u;
 
   if (x) {
     if (packet_length < 12u + cc * 4u + 4u) {
       return;  // Don't read outside the packet.
     }
     size_t x_len = ByteReader<uint16_t>::ReadBigEndian(header + 14 + cc * 4);
     header_length += (x_len + 1) * 4;
   }
 
   std::unique_ptr<rtclog::Event> rtp_event(new rtclog::Event());
   rtp_event->set_timestamp_us(rtc::TimeMicros());
   rtp_event->set_type(rtclog::Event::RTP_EVENT);
   rtp_event->mutable_rtp_packet()->set_incoming(direction == kIncomingPacket);
   rtp_event->mutable_rtp_packet()->set_type(ConvertMediaType(media_type));
   rtp_event->mutable_rtp_packet()->set_packet_length(packet_length);
   rtp_event->mutable_rtp_packet()->set_header(header, header_length);
+  if (probe_cluster_id != PacketInfo::kNotAProbe)
+    rtp_event->mutable_rtp_packet()->set_probe_cluster_id(probe_cluster_id);
   StoreEvent(&rtp_event);
 }
 
 void RtcEventLogImpl::LogRtcpPacket(PacketDirection direction,
                                     MediaType media_type,
                                     const uint8_t* packet,
                                     size_t length) {
   std::unique_ptr<rtclog::Event> rtcp_event(new rtclog::Event());
   rtcp_event->set_timestamp_us(rtc::TimeMicros());
   rtcp_event->set_type(rtclog::Event::RTCP_EVENT);
@@ skipping 78 matching lines @@
   }
   if (config.enable_fec)
     audio_network_adaptation->set_enable_fec(*config.enable_fec);
   if (config.enable_dtx)
     audio_network_adaptation->set_enable_dtx(*config.enable_dtx);
   if (config.num_channels)
     audio_network_adaptation->set_num_channels(*config.num_channels);
   StoreEvent(&event);
 }
 
+void RtcEventLogImpl::LogProbeClusterCreated(int id,

[terelius, 2017/02/01 13:38:19]

Please add unit test.

[philipel, 2017/02/17 15:15:02]

Done.

+                                             int bitrate_bps,
+                                             int min_probes,
+                                             int min_bytes) {
+  std::unique_ptr<rtclog::Event> event(new rtclog::Event());
+  event->set_timestamp_us(rtc::TimeMicros());
+  event->set_type(rtclog::Event::BWE_PROBE_CLUSTER_CREATED_EVENT);
+
+  auto probe_cluster = event->mutable_probe_cluster();
+  probe_cluster->set_id(id);
+  probe_cluster->set_bitrate_bps(bitrate_bps);
+  probe_cluster->set_min_probes(min_probes);
+  probe_cluster->set_min_bytes(min_bytes);
+  StoreEvent(&event);
+}
+
+void RtcEventLogImpl::LogProbeResultSuccess(int id, int bitrate_bps) {

[terelius, 2017/02/01 13:38:19]

Please add unit test.

[philipel, 2017/02/17 15:15:02]

Done.

+  LogProbeResult(id, rtclog::BweProbeResult::SUCCESS, bitrate_bps);
+}
+
+void RtcEventLogImpl::LogProbeResultFailure(int id,

[terelius, 2017/02/01 13:38:19]

Please add unit test.

[philipel, 2017/02/17 15:15:02]

Done.

+                                            ProbeFailureReason failure_reason) {
+  rtclog::BweProbeResult::ResultType result;
+  switch (failure_reason) {
+    case kInvalidSendReceiveInterval:
+      result = rtclog::BweProbeResult::INVALID_SEND_RECEIVE_INTERVAL;
+      break;
+    case kInvalidSendReceiveRatio:
+      result = rtclog::BweProbeResult::INVALID_SEND_RECEIVE_RATIO;
+      break;
+    case kTimeout:
+      result = rtclog::BweProbeResult::TIMEOUT;
+      break;
+  }
+  LogProbeResult(id, result, -1);
+}
+
+void RtcEventLogImpl::LogProbeResult(int id,
+                                     rtclog::BweProbeResult::ResultType result,
+                                     int bitrate_bps) {
+  std::unique_ptr<rtclog::Event> event(new rtclog::Event());
+  event->set_timestamp_us(rtc::TimeMicros());
+  event->set_type(rtclog::Event::BWE_PROBE_RESULT_EVENT);
+
+  auto probe_result = event->mutable_probe_result();
+  probe_result->set_id(id);
+  probe_result->set_result(result);
+  if (result == rtclog::BweProbeResult::SUCCESS)
+    probe_result->set_bitrate_bps(bitrate_bps);
+  StoreEvent(&event);
+}
+
 void RtcEventLogImpl::StoreEvent(std::unique_ptr<rtclog::Event>* event) {
   if (!event_queue_.Insert(event)) {
     LOG(LS_ERROR) << "WebRTC event log queue full. Dropping event.";
   }
   helper_thread_.SignalNewEvent();
 }
 
 bool RtcEventLog::ParseRtcEventLog(const std::string& file_name,
                                    rtclog::EventStream* result) {
   char tmp_buffer[1024];
@@ skipping 28 matching lines @@
 #else
   return std::unique_ptr<RtcEventLog>(new RtcEventLogNullImpl());
 #endif  // ENABLE_RTC_EVENT_LOG
 }
 
 std::unique_ptr<RtcEventLog> RtcEventLog::CreateNull() {
   return std::unique_ptr<RtcEventLog>(new RtcEventLogNullImpl());
 }
 
 }  // namespace webrtc