Added support for logging the SSRC corresponding to AudioPlayout events.

To do this, the logging of this event was moved from the ACM to
VoiceEngine Channel. A new LogAudioPlayoutEvent function was added on
the RtcEventLog interface, and the LogDebugEvent function was removed
since it is no longer being used.

BUG=webrtc:4741
R=henrik.lundin@webrtc.org, henrikg@webrtc.org, kwiberg@webrtc.org, stefan@webrtc.org, terelius@webrtc.org

Review URL: https://codereview.webrtc.org/1340283002 .

Cr-Commit-Position: refs/heads/master@{#9972}

webrtc/modules/audio_coding/main/acm2/audio_coding_module_impl.cc

@@ -27,7 +27,6 @@
 #include "webrtc/system_wrappers/interface/rw_lock_wrapper.h"
 #include "webrtc/system_wrappers/interface/trace.h"
 #include "webrtc/typedefs.h"
-#include "webrtc/video/rtc_event_log.h"
 
 namespace webrtc {
 
@@ -147,8 +146,7 @@ AudioCodingModuleImpl::AudioCodingModuleImpl(
       first_frame_(true),
       callback_crit_sect_(CriticalSectionWrapper::CreateCriticalSection()),
       packetization_callback_(NULL),
-      vad_callback_(NULL),
+      vad_callback_(NULL) {
-      event_log_(config.event_log) {
   if (InitializeReceiverSafe() < 0) {
     WEBRTC_TRACE(webrtc::kTraceError, webrtc::kTraceAudioCoding, id_,
                  "Cannot initialize receiver");
@@ -682,11 +680,6 @@ int AudioCodingModuleImpl::PlayoutData10Ms(int desired_freq_hz,
                  "PlayoutData failed, RecOut Failed");
     return -1;
   }
-  {
-    if (event_log_)
-      event_log_->LogDebugEvent(RtcEventLog::DebugEvent::kAudioPlayout);
-  }
-
   audio_frame->id_ = id_;
   return 0;
 }

webrtc/modules/audio_coding/main/acm2/audio_coding_module_impl.h

@@ -295,8 +295,6 @@ class AudioCodingModuleImpl final : public AudioCodingModule {
   AudioPacketizationCallback* packetization_callback_
       GUARDED_BY(callback_crit_sect_);
   ACMVADCallback* vad_callback_ GUARDED_BY(callback_crit_sect_);
-
-  RtcEventLog* const event_log_;
 };
 
 }  // namespace acm2

webrtc/modules/audio_coding/main/interface/audio_coding_module.h

@@ -29,7 +29,6 @@ struct WebRtcRTPHeader;
 class AudioDecoder;
 class AudioEncoder;
 class AudioFrame;
-class RtcEventLog;
 class RTPFragmentationHeader;
 
 #define WEBRTC_10MS_PCM_AUDIO 960  // 16 bits super wideband 48 kHz
@@ -83,16 +82,11 @@ class AudioCodingModule {
 
  public:
   struct Config {
-    Config()
+    Config() : id(0), neteq_config(), clock(Clock::GetRealTimeClock()) {}
-        : id(0),
-          neteq_config(),
-          clock(Clock::GetRealTimeClock()),
-          event_log(nullptr) {}
 
     int id;
     NetEq::Config neteq_config;
     Clock* clock;
-    RtcEventLog* event_log;
   };
 
   ///////////////////////////////////////////////////////////////////////////

webrtc/video/rtc_event_log.cc

@@ -50,7 +50,7 @@ class RtcEventLogImpl final : public RtcEventLog {
                      MediaType media_type,
                      const uint8_t* packet,
                      size_t length) override {}
-  void LogDebugEvent(DebugEvent event_type) override {}
+  void LogAudioPlayout(uint32_t ssrc) override {}
 };
 
 #else  // ENABLE_RTC_EVENT_LOG is defined
@@ -72,7 +72,7 @@ class RtcEventLogImpl final : public RtcEventLog {
                      MediaType media_type,
                      const uint8_t* packet,
                      size_t length) override;
-  void LogDebugEvent(DebugEvent event_type) override;
+  void LogAudioPlayout(uint32_t ssrc) override;
 
  private:
   // Stops logging and clears the stored data and buffers.
@@ -111,20 +111,6 @@ namespace {
 // unnamed namespace. The intention is to make the compiler warn if anyone
 // adds unhandled new events/modes/etc.
 
-rtclog::DebugEvent_EventType ConvertDebugEvent(
-    RtcEventLog::DebugEvent event_type) {
-  switch (event_type) {
-    case RtcEventLog::DebugEvent::kLogStart:
-      return rtclog::DebugEvent::LOG_START;
-    case RtcEventLog::DebugEvent::kLogEnd:
-      return rtclog::DebugEvent::LOG_END;
-    case RtcEventLog::DebugEvent::kAudioPlayout:
-      return rtclog::DebugEvent::AUDIO_PLAYOUT;
-  }
-  RTC_NOTREACHED();
-  return rtclog::DebugEvent::UNKNOWN_EVENT;
-}
-
 rtclog::VideoReceiveConfig_RtcpMode ConvertRtcpMode(
     newapi::RtcpMode rtcp_mode) {
   switch (rtcp_mode) {
@@ -188,7 +174,7 @@ void RtcEventLogImpl::StartLogging(const std::string& file_name,
   start_event.set_timestamp_us(start_time_us_);
   start_event.set_type(rtclog::Event::DEBUG_EVENT);
   auto debug_event = start_event.mutable_debug_event();
-  debug_event->set_type(ConvertDebugEvent(DebugEvent::kLogStart));
+  debug_event->set_type(rtclog::DebugEvent_EventType_LOG_START);
   StoreToFile(&start_event);
 }
 
@@ -330,14 +316,15 @@ void RtcEventLogImpl::LogRtcpPacket(bool incoming,
   HandleEvent(&rtcp_event);
 }
 
-void RtcEventLogImpl::LogDebugEvent(DebugEvent event_type) {
+void RtcEventLogImpl::LogAudioPlayout(uint32_t ssrc) {
   rtc::CritScope lock(&crit_);
   rtclog::Event event;
   const int64_t timestamp = clock_->TimeInMicroseconds();
   event.set_timestamp_us(timestamp);
   event.set_type(rtclog::Event::DEBUG_EVENT);
   auto debug_event = event.mutable_debug_event();
-  debug_event->set_type(ConvertDebugEvent(event_type));
+  debug_event->set_type(rtclog::DebugEvent_EventType_AUDIO_PLAYOUT);
+  debug_event->set_local_ssrc(ssrc);
   HandleEvent(&event);
 }
 
@@ -350,7 +337,7 @@ void RtcEventLogImpl::StopLoggingLocked() {
     event.set_timestamp_us(timestamp);
     event.set_type(rtclog::Event::DEBUG_EVENT);
     auto debug_event = event.mutable_debug_event();
-    debug_event->set_type(ConvertDebugEvent(DebugEvent::kLogEnd));
+    debug_event->set_type(rtclog::DebugEvent_EventType_LOG_END);
     // Store the event and close the file
     RTC_DCHECK(file_->Open());
     StoreToFile(&event);

webrtc/video/rtc_event_log.h

@@ -31,9 +31,6 @@ enum class MediaType;
 
 class RtcEventLog {
  public:
-  // The types of debug events that are currently supported for logging.
-  enum class DebugEvent { kLogStart, kLogEnd, kAudioPlayout };
-
   virtual ~RtcEventLog() {}
 
   static rtc::scoped_ptr<RtcEventLog> Create();
@@ -67,8 +64,8 @@ class RtcEventLog {
                              const uint8_t* packet,
                              size_t length) = 0;
 
-  // Logs a debug event.
+  // Logs an audio playout event
-  virtual void LogDebugEvent(DebugEvent event_type) = 0;
+  virtual void LogAudioPlayout(uint32_t ssrc) = 0;
 
   // Reads an RtcEventLog file and returns true when reading was successful.
   // The result is stored in the given EventStream object.

webrtc/video/rtc_event_log.proto

@@ -106,6 +106,9 @@ message DebugEvent {
 
   // required
   optional EventType type = 1;
+
+  // required if type == AUDIO_PLAYOUT
+  optional uint32 local_ssrc = 2;
 }
 
 

webrtc/video/rtc_event_log_unittest.cc

@@ -265,12 +265,14 @@ void VerifyRtcpEvent(const rtclog::Event& event,
   }
 }
 
-void VerifyPlayoutEvent(const rtclog::Event& event) {
+void VerifyPlayoutEvent(const rtclog::Event& event, uint32_t ssrc) {
   ASSERT_TRUE(IsValidBasicEvent(event));
   ASSERT_EQ(rtclog::Event::DEBUG_EVENT, event.type());
   const rtclog::DebugEvent& debug_event = event.debug_event();
   ASSERT_TRUE(debug_event.has_type());
   EXPECT_EQ(rtclog::DebugEvent::AUDIO_PLAYOUT, debug_event.type());
+  ASSERT_TRUE(debug_event.has_local_ssrc());
+  EXPECT_EQ(ssrc, debug_event.local_ssrc());
 }
 
 void VerifyLogStartEvent(const rtclog::Event& event) {
@@ -407,6 +409,7 @@ void LogSessionAndReadBack(size_t rtp_count,
   std::vector<rtc::Buffer> rtp_packets;
   std::vector<rtc::Buffer> rtcp_packets;
   std::vector<size_t> rtp_header_sizes;
+  std::vector<uint32_t> playout_ssrcs;
 
   VideoReceiveStream::Config receiver_config(nullptr);
   VideoSendStream::Config sender_config(nullptr);
@@ -427,6 +430,10 @@ void LogSessionAndReadBack(size_t rtp_count,
     rtcp_packets.push_back(rtc::Buffer(packet_size));
     GenerateRtcpPacket(rtcp_packets[i].data(), packet_size);
   }
+  // Create debug_count random SSRCs to use when logging AudioPlayout events.
+  for (size_t i = 0; i < debug_count; i++) {
+    playout_ssrcs.push_back(static_cast<uint32_t>(rand()));
+  }
   // Create configurations for the video streams.
   GenerateVideoReceiveConfig(extensions_bitvector, &receiver_config);
   GenerateVideoSendConfig(extensions_bitvector, &sender_config);
@@ -459,7 +466,7 @@ void LogSessionAndReadBack(size_t rtp_count,
         rtcp_index++;
       }
       if (i * debug_count >= debug_index * rtp_count) {
-        log_dumper->LogDebugEvent(RtcEventLog::DebugEvent::kAudioPlayout);
+        log_dumper->LogAudioPlayout(playout_ssrcs[debug_index - 1]);
         debug_index++;
       }
       if (i == rtp_count / 2) {
@@ -497,7 +504,8 @@ void LogSessionAndReadBack(size_t rtp_count,
       rtcp_index++;
     }
     if (i * debug_count >= debug_index * rtp_count) {
-      VerifyPlayoutEvent(parsed_stream.stream(event_index));
+      VerifyPlayoutEvent(parsed_stream.stream(event_index),
+                         playout_ssrcs[debug_index - 1]);
       event_index++;
       debug_index++;
     }

webrtc/voice_engine/channel.cc

@@ -12,6 +12,7 @@
 
 #include <algorithm>
 
+#include "webrtc/base/checks.h"
 #include "webrtc/base/format_macros.h"
 #include "webrtc/base/timeutils.h"
 #include "webrtc/common.h"
@@ -450,6 +451,11 @@ int32_t Channel::GetAudioFrame(int32_t id, AudioFrame* audioFrame)
     WEBRTC_TRACE(kTraceStream, kTraceVoice, VoEId(_instanceId,_channelId),
                  "Channel::GetAudioFrame(id=%d)", id);
 
+    if (event_log_) {
+      unsigned int ssrc;
+      RTC_CHECK_EQ(GetLocalSSRC(ssrc), 0);
+      event_log_->LogAudioPlayout(ssrc);
+    }
     // Get 10ms raw PCM data from the ACM (mixer limits output frequency)
     if (audio_coding_->PlayoutData10Ms(audioFrame->sample_rate_hz_,
                                        audioFrame) == -1)
@@ -719,6 +725,7 @@ Channel::Channel(int32_t channelId,
     volume_settings_critsect_(*CriticalSectionWrapper::CreateCriticalSection()),
     _instanceId(instanceId),
     _channelId(channelId),
+    event_log_(event_log),
     rtp_header_parser_(RtpHeaderParser::Create()),
     rtp_payload_registry_(
         new RTPPayloadRegistry(RTPPayloadStrategy::CreateStrategy(true))),
@@ -809,7 +816,6 @@ Channel::Channel(int32_t channelId,
     }
     acm_config.neteq_config.enable_fast_accelerate =
         config.Get<NetEqFastAccelerate>().enabled;
-    acm_config.event_log = event_log;
     audio_coding_.reset(AudioCodingModule::Create(acm_config));
 
     _inbandDtmfQueue.ResetDtmf();

webrtc/voice_engine/channel.h

@@ -488,6 +488,8 @@ private:
 
     ChannelState channel_state_;
 
+    RtcEventLog* const event_log_;
+
     rtc::scoped_ptr<RtpHeaderParser> rtp_header_parser_;
     rtc::scoped_ptr<RTPPayloadRegistry> rtp_payload_registry_;
     rtc::scoped_ptr<ReceiveStatistics> rtp_receive_statistics_;