Adds logging of configuration information for VideoReceiveStream

webrtc/modules/audio_coding/main/acm2/acm_dump.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.
  */
 
 #include "webrtc/modules/audio_coding/main/acm2/acm_dump.h"
 
 #include <deque>
 
 #include "webrtc/base/checks.h"
 #include "webrtc/base/thread_annotations.h"
 #include "webrtc/system_wrappers/interface/clock.h"
 #include "webrtc/system_wrappers/interface/critical_section_wrapper.h"
 #include "webrtc/system_wrappers/interface/file_wrapper.h"
 
+
 #ifdef RTC_AUDIOCODING_DEBUG_DUMP
 // Files generated at build-time by the protobuf compiler.
 #ifdef WEBRTC_ANDROID_PLATFORM_BUILD
 #include "external/webrtc/webrtc/modules/audio_coding/dump.pb.h"
 #else
 #include "webrtc/audio_coding/dump.pb.h"
 #endif
 #endif
 
 namespace webrtc {
 
-// Noop implementation if flag is not set
+// Noop implementation if flag is not set.
 #ifndef RTC_AUDIOCODING_DEBUG_DUMP
 class AcmDumpImpl final : public AcmDump {
  public:
   void StartLogging(const std::string& file_name, int duration_ms) override{};
-  void LogRtpPacket(bool incoming,
-                    const uint8_t* packet,
-                    size_t length) override{};
+  void LogVideoReceiveStreamConfig(
+      const webrtc::VideoReceiveStream::Config& config) override{};
+  void LogVideoSendStreamConfig(
+      const webrtc::VideoSendStream::Config& config) override{};
+  void LogRtpHeader(bool incoming,
+                    MediaType media_type,
+                    const uint8_t* header,
+                    size_t header_length,
+                    size_t total_length) override{};
+  void LogRtcpPacket(bool incoming,
+                     MediaType media_type,
+                     const uint8_t* packet,
+                     size_t length) override{};
   void LogDebugEvent(DebugEvent event_type,
                      const std::string& event_message) override{};
   void LogDebugEvent(DebugEvent event_type) override{};
 };
 #else
 
 class AcmDumpImpl final : public AcmDump {
  public:
   AcmDumpImpl();
 
   void StartLogging(const std::string& file_name, int duration_ms) override;
-  void LogRtpPacket(bool incoming,
-                    const uint8_t* packet,
-                    size_t length) override;
+  void LogVideoReceiveStreamConfig(
+      const webrtc::VideoReceiveStream::Config& config) override;
+  void LogVideoSendStreamConfig(
+      const webrtc::VideoSendStream::Config& config) override;
+  void LogRtpHeader(bool incoming,
+                    MediaType media_type,
+                    const uint8_t* header,
+                    size_t header_length,
+                    size_t total_length) override;
+  void LogRtcpPacket(bool incoming,
+                     MediaType media_type,
+                     const uint8_t* packet,
+                     size_t length) override;
   void LogDebugEvent(DebugEvent event_type,
                      const std::string& event_message) override;
   void LogDebugEvent(DebugEvent event_type) override;
 
  private:
   // This function is identical to LogDebugEvent, but requires holding the lock.
   void LogDebugEventLocked(DebugEvent event_type,
                            const std::string& event_message)
       EXCLUSIVE_LOCKS_REQUIRED(crit_);
   // Stops logging and clears the stored data and buffers.
@@ skipping 49 matching lines @@
       currently_logging_(false),
       start_time_us_(0),
       duration_us_(0),
       clock_(webrtc::Clock::GetRealTimeClock()) {
 }
 
 void AcmDumpImpl::StartLogging(const std::string& file_name, int duration_ms) {
   CriticalSectionScoped lock(crit_.get());
   Clear();
   if (file_->OpenFile(file_name.c_str(), false) != 0) {
+    // printf("Cannot open file %s\n", file_name.c_str());

[ivoc, 2015/07/14 12:13:13]

Should be removed.

[terelius, 2015/07/16 12:47:02]

Done.

     return;
   }
+
   // Add LOG_START event to the recent event list. This call will also remove
   // any events that are too old from the recent event list.
   LogDebugEventLocked(DebugEvent::kLogStart, "");
   currently_logging_ = true;
   start_time_us_ = clock_->TimeInMicroseconds();
   duration_us_ = static_cast<int64_t>(duration_ms) * 1000;
   // Write all the recent events to the log file.
+  // TODO(terelius): Rvalue references are unapproved. Do we need it?

[ivoc, 2015/07/14 12:13:13]

I agree that it's not necessary. It should be auto& event. I can't recall why I
used this in the first place :-)

[terelius, 2015/07/16 12:47:02]

Done.

   for (auto&& event : recent_log_events_) {
     StoreToFile(&event);
   }
   recent_log_events_.clear();
 }
 
-void AcmDumpImpl::LogRtpPacket(bool incoming,
-                               const uint8_t* packet,
-                               size_t length) {
+void AcmDumpImpl::LogVideoReceiveStreamConfig(
+    const webrtc::VideoReceiveStream::Config& config) {
+  CriticalSectionScoped lock(crit_.get());
+
+  ACMDumpEvent event;
+  const int64_t timestamp = clock_->TimeInMicroseconds();
+  event.set_timestamp_us(timestamp);
+  event.set_type(webrtc::ACMDumpEvent::RECEIVER_CONFIG_EVENT);
+
+  ACMDumpVideoReceiveConfig* receiver_config = event.mutable_receiver_config();
+  receiver_config->set_remote_ssrc(config.rtp.remote_ssrc);
+  receiver_config->set_local_ssrc(config.rtp.local_ssrc);
+
+  switch (config.rtp.rtcp_mode) {

[ivoc, 2015/07/14 12:13:13]

I think it would be clearer to refactor this into a small function that converts
from one enum to the other. See the convertDebugEvent in the anonymous namespace
(this was suggested to me during a previous code review).

[terelius, 2015/07/16 12:47:02]

Done.

+    case newapi::kRtcpCompound:
+      receiver_config->set_rtcp_mode(ACMDumpVideoReceiveConfig::RTCP_COMPOUND);
+      break;
+    case newapi::kRtcpReducedSize:
+      receiver_config->set_rtcp_mode(
+          ACMDumpVideoReceiveConfig::RTCP_REDUCEDSIZE);
+      break;
+      // Compiler should warn if anyone adds unhandled new modes.

[stefan-webrtc, 2015/07/14 13:28:56]

No need for this comment I think.

[terelius, 2015/07/16 12:47:02]

I'll put a general warning/explanation of why there are no default cases in the
anonymous namespace just before the conversion functions.

+  }
+  receiver_config->set_receiver_reference_time_report(
+      config.rtp.rtcp_xr.receiver_reference_time_report);
+  receiver_config->set_remb(config.rtp.remb);
+
+  for (const auto& r : config.rtp.rtx) {

[ivoc, 2015/07/14 12:13:13]

I'm not a fan of single-letter variable names (in most cases). I think r should
be renamed to something more descriptive, maybe rtx_pair?

[terelius, 2015/07/16 12:47:02]

Done.

+    RtxMap* translation = receiver_config->add_rtx_map();
+    translation->set_payload_type(r.first);
+    translation->mutable_config()->set_rtx_ssrc(r.second.ssrc);
+    translation->mutable_config()->set_rtx_payload_type(r.second.payload_type);
+  }
+
+  for (const auto& e : config.rtp.extensions) {

[ivoc, 2015/07/14 12:13:13]

e should be renamed to something more descriptive as well.

[terelius, 2015/07/16 12:47:02]

I'll change this, but I'll explain why I think the current naming is fine.

If I wanted to perform this loop in pseudo code I would write
for each extension e:
  do something with e

Translating this to C++ in the natural way gives code like
for (auto e ; extensions)
  do something with e

In cases like this, I don't think it is a problem to have a short
(undescriptive) variable name since the scope is very short. This is similar to
using i,j,k for loop indices. While i wouldn't be a good name for a persistent
variable, there is little risk for confusion for local variables in a short
loop.

+    RtpHeaderExtension* extension = receiver_config->add_header_extensions();
+    extension->set_name(e.name);
+    extension->set_id(e.id);
+  }
+
+  for (const auto& d : config.decoders) {

[ivoc, 2015/07/14 12:13:13]

Same for d.

[terelius, 2015/07/16 12:47:02]

Done.

+    DecoderConfig* decoder = receiver_config->add_decoders();
+    decoder->set_name(d.payload_name);
+    decoder->set_payload_type(d.payload_type);
+  }
+  // TODO(terelius): We should use a separate event stream for config events.
+  // The current approach of storing the configuration together with the
+  // RTP events causes the configuration information to be removed 10s
+  // after the ReceiveStream is created.

[ivoc, 2015/07/14 12:13:13]

I disagree. We can store this ACMDumpEvent as a member of the AcmDump class.
That way it is retained permanently until we need it. The best way to do it is
to first put it in the recent_log_events_ list (like what your code does now),
and then when removing old events (in the AddRecentEvent function), if the type
is RECEIVER_CONFIG_EVENT, then copy it to the class member. 

When starting a log, we should first dump this new class member to the log file
before storing the rest of the recent_log_events_.

That way we always have the most recent config struct available, while still
supporting config changes during the logging process itself.

[terelius, 2015/07/16 12:47:02]

Acknowledged. I'll leave the comment as a reminder that we have to fix this in
some way.

+  HandleEvent(&event);
+}
+
+void AcmDumpImpl::LogVideoSendStreamConfig(
+    const webrtc::VideoSendStream::Config& config) {
+  CriticalSectionScoped lock(crit_.get());
+
+  ACMDumpEvent event;
+  const int64_t timestamp = clock_->TimeInMicroseconds();
+  event.set_timestamp_us(timestamp);
+  event.set_type(webrtc::ACMDumpEvent::SENDER_CONFIG_EVENT);
+
+  ACMDumpVideoSendConfig* sender_config = event.mutable_sender_config();
+
+  for (const auto& s : config.rtp.ssrcs) {

[ivoc, 2015/07/14 12:13:13]

s should be more descriptive.

[terelius, 2015/07/16 12:47:02]

Done.

+    sender_config->add_ssrcs(s);
+  }
+
+  for (const auto& e : config.rtp.extensions) {

[ivoc, 2015/07/14 12:13:13]

Same here.

[terelius, 2015/07/16 12:47:02]

Done.

+    RtpHeaderExtension* extension = sender_config->add_header_extensions();
+    extension->set_name(e.name);
+    extension->set_id(e.id);
+  }
+
+  for (const auto& r : config.rtp.rtx.ssrcs) {

[ivoc, 2015/07/14 12:13:13]

And here.

[terelius, 2015/07/16 12:47:02]

Done.

+    sender_config->add_rtx_ssrcs(r);
+  }
+  sender_config->set_rtx_payload_type(config.rtp.rtx.payload_type);
+
+  sender_config->set_c_name(config.rtp.c_name);
+
+  EncoderConfig* encoder = sender_config->mutable_encoder();
+  encoder->set_name(config.encoder_settings.payload_name);
+  encoder->set_payload_type(config.encoder_settings.payload_type);
+
+  // TODO(terelius): We should use a separate event stream for config events.
+  // The current approach of storing the configuration together with the
+  // RTP events causes the configuration information to be removed 10s
+  // after the ReceiveStream is created.

[ivoc, 2015/07/14 12:13:13]

See my comment above.

[terelius, 2015/07/16 12:47:02]

Acknowledged. I'll leave the comment as a reminder.

+  HandleEvent(&event);
+}
+
+void AcmDumpImpl::LogRtpHeader(bool incoming,
+                               MediaType media_type,
+                               const uint8_t* header,
+                               size_t header_length,
+                               size_t total_length) {
   CriticalSectionScoped lock(crit_.get());
   ACMDumpEvent rtp_event;
   const int64_t timestamp = clock_->TimeInMicroseconds();
   rtp_event.set_timestamp_us(timestamp);
   rtp_event.set_type(webrtc::ACMDumpEvent::RTP_EVENT);
-  rtp_event.mutable_packet()->set_direction(
-      incoming ? ACMDumpRTPPacket::INCOMING : ACMDumpRTPPacket::OUTGOING);
-  rtp_event.mutable_packet()->set_rtp_data(packet, length);
+  rtp_event.mutable_rtp_packet()->set_direction(
+      incoming ? ACMDumpRtpPacket::INCOMING : ACMDumpRtpPacket::OUTGOING);
+  if (media_type == MediaType::VIDEO)

[ivoc, 2015/07/14 12:13:13]

I think we should make another small function to convert these enums from one to
the other.

[stefan-webrtc, 2015/07/14 13:28:55]

And I would prefer that function to use a switch instead of if statements.

[terelius, 2015/07/16 12:47:02]

Done.

+    rtp_event.mutable_rtp_packet()->set_type(ACMDumpRtpPacket::VIDEO);
+  else if (media_type == MediaType::AUDIO)
+    rtp_event.mutable_rtp_packet()->set_type(ACMDumpRtpPacket::AUDIO);
+  else
+    rtp_event.mutable_rtp_packet()->set_type(ACMDumpRtpPacket::UNKNOWN_TYPE);
+  rtp_event.mutable_rtp_packet()->set_packet_length(total_length);
+  rtp_event.mutable_rtp_packet()->set_header(header, header_length);
   HandleEvent(&rtp_event);
 }
 
+void AcmDumpImpl::LogRtcpPacket(bool incoming,
+                                MediaType media_type,
+                                const uint8_t* packet,
+                                size_t length) {
+  CriticalSectionScoped lock(crit_.get());
+  ACMDumpEvent rtcp_event;
+  const int64_t timestamp = clock_->TimeInMicroseconds();
+  rtcp_event.set_timestamp_us(timestamp);
+  rtcp_event.set_type(webrtc::ACMDumpEvent::RTCP_EVENT);
+  rtcp_event.mutable_rtcp_packet()->set_direction(

[ivoc, 2015/07/14 12:13:13]

We can reuse the conversion function here.

[terelius, 2015/07/16 12:47:02]

We can't reuse it unless we change the protobuf.
ACMDumpRtpPacket::VIDEO != ACMDumpRtcpPacket::VIDEO

I've made a separate conversion function.

[ivoc, 2015/07/17 12:14:28]

Right, I misread.

+      incoming ? ACMDumpRtcpPacket::INCOMING : ACMDumpRtcpPacket::OUTGOING);
+  if (media_type == MediaType::VIDEO)
+    rtcp_event.mutable_rtcp_packet()->set_type(ACMDumpRtcpPacket::VIDEO);
+  else if (media_type == MediaType::AUDIO)
+    rtcp_event.mutable_rtcp_packet()->set_type(ACMDumpRtcpPacket::AUDIO);
+  else
+    rtcp_event.mutable_rtcp_packet()->set_type(ACMDumpRtcpPacket::UNKNOWN_TYPE);
+  rtcp_event.mutable_rtcp_packet()->set_data(packet, length);
+  HandleEvent(&rtcp_event);
+}
+
 void AcmDumpImpl::LogDebugEvent(DebugEvent event_type,
                                 const std::string& event_message) {
   CriticalSectionScoped lock(crit_.get());
   LogDebugEventLocked(event_type, event_message);
 }
 
 void AcmDumpImpl::LogDebugEvent(DebugEvent event_type) {
   CriticalSectionScoped lock(crit_.get());
   LogDebugEventLocked(event_type, "");
 }
@@ skipping 69 matching lines @@
   return result->ParseFromString(dump_buffer);
 }
 
 #endif  // RTC_AUDIOCODING_DEBUG_DUMP
 
 // AcmDump member functions.
 rtc::scoped_ptr<AcmDump> AcmDump::Create() {
   return rtc::scoped_ptr<AcmDump>(new AcmDumpImpl());
 }
 }  // namespace webrtc