Hooked up RtcEventLog. It lives in Voice Engine and pointers are propagated to ACM and Call.

An option was added to voe_cmd_test to make a RtcEventLog dump.

BUG=webrtc:4741

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

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

talk/media/webrtc/fakewebrtcvoiceengine.h

@@ -536,6 +536,7 @@ class FakeWebRtcVoiceEngine
     channels_[channel]->associate_send_channel = accociate_send_channel;
     return 0;
   }
+  webrtc::RtcEventLog* GetEventLog() { return nullptr; }
 
   // webrtc::VoECodec
   WEBRTC_FUNC(NumOfCodecs, ()) {

webrtc/modules/audio_coding/BUILD.gn

@@ -58,6 +58,12 @@ source_set("audio_coding") {
     ]
   }
 
+  if (is_clang) {
+    # Suppress warnings from Chrome's Clang plugins.
+    # See http://code.google.com/p/webrtc/issues/detail?id=163 for details.
+    configs -= [ "//build/config/clang:find_bad_constructs" ]
+  }
+
   deps = [
     ":cng",
     ":g711",
@@ -68,6 +74,7 @@ source_set("audio_coding") {
     ":neteq",
     ":pcm16b",
     ":red",
+    "../..:rtc_event_log",
     "../..:webrtc_common",
     "../../common_audio",
     "../../system_wrappers",

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

@@ -27,6 +27,7 @@
 #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 {
 
@@ -146,7 +147,8 @@ 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");
@@ -680,6 +682,10 @@ 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

@@ -299,6 +299,8 @@ 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/audio_coding_module.gypi

@@ -39,6 +39,7 @@
       'dependencies': [
         '<@(audio_coding_dependencies)',
         '<(webrtc_root)/common.gyp:webrtc_common',
+        '<(webrtc_root)/webrtc.gyp:rtc_event_log',
         'neteq',
       ],
       'include_dirs': [

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

@@ -26,10 +26,11 @@ namespace webrtc {
 // forward declarations
 struct CodecInst;
 struct WebRtcRTPHeader;
-class AudioFrame;
-class RTPFragmentationHeader;
-class AudioEncoder;
 class AudioDecoder;
+class AudioEncoder;
+class AudioFrame;
+class RtcEventLog;
+class RTPFragmentationHeader;
 
 #define WEBRTC_10MS_PCM_AUDIO 960  // 16 bits super wideband 48 kHz
 
@@ -85,11 +86,13 @@ class AudioCodingModule {
     Config()
         : id(0),
           neteq_config(),
-          clock(Clock::GetRealTimeClock()) {}
+          clock(Clock::GetRealTimeClock()),
+          event_log(nullptr) {}
 
     int id;
     NetEq::Config neteq_config;
     Clock* clock;
+    RtcEventLog* event_log;
   };
 
   ///////////////////////////////////////////////////////////////////////////

webrtc/video/call.cc

@@ -32,8 +32,10 @@
 #include "webrtc/system_wrappers/interface/trace.h"
 #include "webrtc/system_wrappers/interface/trace_event.h"
 #include "webrtc/video/audio_receive_stream.h"
+#include "webrtc/video/rtc_event_log.h"
 #include "webrtc/video/video_receive_stream.h"
 #include "webrtc/video/video_send_stream.h"
+#include "webrtc/voice_engine/include/voe_codec.h"
 
 namespace webrtc {
 
@@ -120,6 +122,8 @@ class Call : public webrtc::Call, public PacketReceiver {
 
   VideoSendStream::RtpStateMap suspended_video_send_ssrcs_;
 
+  RtcEventLog* event_log_;
+
   DISALLOW_COPY_AND_ASSIGN(Call);
 };
 }  // namespace internal
@@ -138,7 +142,8 @@ Call::Call(const Call::Config& config)
       config_(config),
       network_enabled_(true),
       receive_crit_(RWLockWrapper::CreateRWLock()),
-      send_crit_(RWLockWrapper::CreateRWLock()) {
+      send_crit_(RWLockWrapper::CreateRWLock()),
+      event_log_(nullptr) {
   DCHECK_GE(config.bitrate_config.min_bitrate_bps, 0);
   DCHECK_GE(config.bitrate_config.start_bitrate_bps,
             config.bitrate_config.min_bitrate_bps);
@@ -146,6 +151,13 @@ Call::Call(const Call::Config& config)
     DCHECK_GE(config.bitrate_config.max_bitrate_bps,
               config.bitrate_config.start_bitrate_bps);
   }
+  if (config.voice_engine) {
+    VoECodec* voe_codec = VoECodec::GetInterface(config.voice_engine);
+    if (voe_codec) {
+      event_log_ = voe_codec->GetEventLog();
+      voe_codec->Release();
+    }
+  }
 
   Trace::CreateTrace();
   module_process_thread_->Start();
@@ -236,6 +248,9 @@ webrtc::VideoSendStream* Call::CreateVideoSendStream(
   }
   video_send_streams_.insert(send_stream);
 
+  if (event_log_)
+    event_log_->LogVideoSendStreamConfig(config);
+
   if (!network_enabled_)
     send_stream->SignalNetworkState(kNetworkDown);
   return send_stream;
@@ -302,6 +317,9 @@ webrtc::VideoReceiveStream* Call::CreateVideoReceiveStream(
   if (!network_enabled_)
     receive_stream->SignalNetworkState(kNetworkDown);
 
+  if (event_log_)
+    event_log_->LogVideoReceiveStreamConfig(config);
+
   return receive_stream;
 }
 
@@ -463,15 +481,21 @@ PacketReceiver::DeliveryStatus Call::DeliverRtcp(MediaType media_type,
   if (media_type == MediaType::ANY || media_type == MediaType::VIDEO) {
     ReadLockScoped read_lock(*receive_crit_);
     for (VideoReceiveStream* stream : video_receive_streams_) {
-      if (stream->DeliverRtcp(packet, length))
+      if (stream->DeliverRtcp(packet, length)) {
         rtcp_delivered = true;
+        if (event_log_)
+          event_log_->LogRtcpPacket(true, media_type, packet, length);
+      }
     }
   }
   if (media_type == MediaType::ANY || media_type == MediaType::VIDEO) {
     ReadLockScoped read_lock(*send_crit_);
     for (VideoSendStream* stream : video_send_streams_) {
-      if (stream->DeliverRtcp(packet, length))
+      if (stream->DeliverRtcp(packet, length)) {
         rtcp_delivered = true;
+        if (event_log_)
+          event_log_->LogRtcpPacket(false, media_type, packet, length);
+      }
     }
   }
   return rtcp_delivered ? DELIVERY_OK : DELIVERY_PACKET_ERROR;
@@ -491,17 +515,23 @@ PacketReceiver::DeliveryStatus Call::DeliverRtp(MediaType media_type,
   if (media_type == MediaType::ANY || media_type == MediaType::AUDIO) {
     auto it = audio_receive_ssrcs_.find(ssrc);
     if (it != audio_receive_ssrcs_.end()) {
-      return it->second->DeliverRtp(packet, length, packet_time)
+      auto status = it->second->DeliverRtp(packet, length, packet_time)
                         ? DELIVERY_OK
                         : DELIVERY_PACKET_ERROR;
+      if (status == DELIVERY_OK && event_log_)
+        event_log_->LogRtpHeader(true, media_type, packet, length);
+      return status;
     }
   }
   if (media_type == MediaType::ANY || media_type == MediaType::VIDEO) {
     auto it = video_receive_ssrcs_.find(ssrc);
     if (it != video_receive_ssrcs_.end()) {
-      return it->second->DeliverRtp(packet, length, packet_time)
+      auto status = it->second->DeliverRtp(packet, length, packet_time)
                         ? DELIVERY_OK
                         : DELIVERY_PACKET_ERROR;
+      if (status == DELIVERY_OK && event_log_)
+        event_log_->LogRtpHeader(true, media_type, packet, length);
+      return status;
     }
   }
   return DELIVERY_UNKNOWN_SSRC;

webrtc/video/webrtc_video.gypi

@@ -20,6 +20,7 @@
       '<(webrtc_root)/modules/modules.gyp:webrtc_video_coding',
       '<(webrtc_root)/system_wrappers/system_wrappers.gyp:system_wrappers',
       '<(webrtc_root)/voice_engine/voice_engine.gyp:voice_engine',
+      '<(webrtc_root)/webrtc.gyp:rtc_event_log',
     ],
     'webrtc_video_sources': [
       'video/audio_receive_stream.cc',

webrtc/voice_engine/BUILD.gn

@@ -95,6 +95,7 @@ source_set("voice_engine") {
   }
 
   deps = [
+    "..:rtc_event_log",
     "..:webrtc_common",
     "../common_audio",
     "../modules/audio_coding",

webrtc/voice_engine/channel.cc

@@ -628,17 +628,16 @@ Channel::NeededFrequency(int32_t id) const
     return(highestNeeded);
 }
 
-int32_t
+int32_t Channel::CreateChannel(Channel*& channel,
-Channel::CreateChannel(Channel*& channel,
                                int32_t channelId,
                                uint32_t instanceId,
-                       const Config& config)
+                               RtcEventLog* const event_log,
-{
+                               const Config& config) {
     WEBRTC_TRACE(kTraceMemory, kTraceVoice, VoEId(instanceId,channelId),
                  "Channel::CreateChannel(channelId=%d, instanceId=%d)",
         channelId, instanceId);
 
-    channel = new Channel(channelId, instanceId, config);
+    channel = new Channel(channelId, instanceId, event_log, config);
     if (channel == NULL)
     {
         WEBRTC_TRACE(kTraceMemory, kTraceVoice,
@@ -713,8 +712,9 @@ Channel::RecordFileEnded(int32_t id)
 
 Channel::Channel(int32_t channelId,
                  uint32_t instanceId,
-                 const Config& config) :
+                 RtcEventLog* const event_log,
-    _fileCritSect(*CriticalSectionWrapper::CreateCriticalSection()),
+                 const Config& config)
+  : _fileCritSect(*CriticalSectionWrapper::CreateCriticalSection()),
     _callbackCritSect(*CriticalSectionWrapper::CreateCriticalSection()),
     volume_settings_critsect_(*CriticalSectionWrapper::CreateCriticalSection()),
     _instanceId(instanceId),
@@ -722,11 +722,15 @@ Channel::Channel(int32_t channelId,
     rtp_header_parser_(RtpHeaderParser::Create()),
     rtp_payload_registry_(
         new RTPPayloadRegistry(RTPPayloadStrategy::CreateStrategy(true))),
-    rtp_receive_statistics_(ReceiveStatistics::Create(
+    rtp_receive_statistics_(
-        Clock::GetRealTimeClock())),
+        ReceiveStatistics::Create(Clock::GetRealTimeClock())),
-    rtp_receiver_(RtpReceiver::CreateAudioReceiver(
+    rtp_receiver_(
-        VoEModuleId(instanceId, channelId), Clock::GetRealTimeClock(), this,
+        RtpReceiver::CreateAudioReceiver(VoEModuleId(instanceId, channelId),
-        this, this, rtp_payload_registry_.get())),
+                                         Clock::GetRealTimeClock(),
+                                         this,
+                                         this,
+                                         this,
+                                         rtp_payload_registry_.get())),
     telephone_event_handler_(rtp_receiver_->GetTelephoneEventHandler()),
     _outputAudioLevel(),
     _externalTransport(false),
@@ -744,7 +748,8 @@ Channel::Channel(int32_t channelId,
     _outputExternalMedia(false),
     _inputExternalMediaCallbackPtr(NULL),
     _outputExternalMediaCallbackPtr(NULL),
-    _timeStamp(0), // This is just an offset, RTP module will add it's own random offset
+    _timeStamp(0),  // This is just an offset, RTP module will add it's own
+                    // random offset
     _sendTelephoneEventPayloadType(106),
     ntp_estimator_(Clock::GetRealTimeClock()),
     jitter_buffer_playout_timestamp_(0),
@@ -791,8 +796,7 @@ Channel::Channel(int32_t channelId,
     rtcp_observer_(new VoERtcpObserver(this)),
     network_predictor_(new NetworkPredictor(Clock::GetRealTimeClock())),
     assoc_send_channel_lock_(CriticalSectionWrapper::CreateCriticalSection()),
-    associate_send_channel_(ChannelOwner(nullptr))
+    associate_send_channel_(ChannelOwner(nullptr)) {
-{
     WEBRTC_TRACE(kTraceMemory, kTraceVoice, VoEId(_instanceId,_channelId),
                  "Channel::Channel() - ctor");
     AudioCodingModule::Config acm_config;
@@ -805,6 +809,7 @@ 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

@@ -51,6 +51,7 @@ class FileWrapper;
 class ProcessThread;
 class ReceiveStatistics;
 class RemoteNtpTimeEstimator;
+class RtcEventLog;
 class RTPPayloadRegistry;
 class RtpReceiver;
 class RTPReceiverAudio;
@@ -170,8 +171,12 @@ public:
     static int32_t CreateChannel(Channel*& channel,
                                  int32_t channelId,
                                  uint32_t instanceId,
+                                 RtcEventLog* const event_log,
+                                 const Config& config);
+    Channel(int32_t channelId,
+            uint32_t instanceId,
+            RtcEventLog* const event_log,
             const Config& config);
-    Channel(int32_t channelId, uint32_t instanceId, const Config& config);
     int32_t Init();
     int32_t SetEngineInformation(
         Statistics& engineStatistics,

webrtc/voice_engine/channel_manager.cc

@@ -49,7 +49,8 @@ ChannelManager::ChannelManager(uint32_t instance_id, const Config& config)
     : instance_id_(instance_id),
       last_channel_id_(-1),
       lock_(CriticalSectionWrapper::CreateCriticalSection()),
-      config_(config) {}
+      config_(config),
+      event_log_(RtcEventLog::Create()) {}
 
 ChannelOwner ChannelManager::CreateChannel() {
   return CreateChannelInternal(config_);
@@ -61,7 +62,8 @@ ChannelOwner ChannelManager::CreateChannel(const Config& external_config) {
 
 ChannelOwner ChannelManager::CreateChannelInternal(const Config& config) {
   Channel* channel;
-  Channel::CreateChannel(channel, ++last_channel_id_, instance_id_, config);
+  Channel::CreateChannel(channel, ++last_channel_id_, instance_id_,
+                         event_log_.get(), config);
   ChannelOwner channel_owner(channel);
 
   CriticalSectionScoped crit(lock_.get());
@@ -128,6 +130,10 @@ size_t ChannelManager::NumOfChannels() const {
   return channels_.size();
 }
 
+RtcEventLog* ChannelManager::GetEventLog() const {
+  return event_log_.get();
+}
+
 ChannelManager::Iterator::Iterator(ChannelManager* channel_manager)
     : iterator_pos_(0) {
   channel_manager->GetAllChannels(&channels_);

webrtc/voice_engine/channel_manager.h

@@ -18,6 +18,7 @@
 #include "webrtc/system_wrappers/interface/atomic32.h"
 #include "webrtc/system_wrappers/interface/critical_section_wrapper.h"
 #include "webrtc/typedefs.h"
+#include "webrtc/video/rtc_event_log.h"
 
 namespace webrtc {
 
@@ -111,6 +112,9 @@ class ChannelManager {
 
   size_t NumOfChannels() const;
 
+  // Returns a pointer to the event log object stored within the ChannelManager.
+  RtcEventLog* GetEventLog() const;
+
  private:
   // Create a channel given a configuration, |config|.
   ChannelOwner CreateChannelInternal(const Config& config);
@@ -123,6 +127,7 @@ class ChannelManager {
   std::vector<ChannelOwner> channels_;
 
   const Config& config_;
+  rtc::scoped_ptr<RtcEventLog> event_log_;
 
   DISALLOW_COPY_AND_ASSIGN(ChannelManager);
 };

webrtc/voice_engine/include/voe_codec.h

@@ -35,6 +35,7 @@
 
 namespace webrtc {
 
+class RtcEventLog;
 class VoiceEngine;
 
 class WEBRTC_DLLEXPORT VoECodec {
@@ -131,6 +132,10 @@ class WEBRTC_DLLEXPORT VoECodec {
   // success, and -1 if failed.
   virtual int SetOpusDtx(int channel, bool enable_dtx) = 0;
 
+  // Get a pointer to the event logging object associated with this Voice
+  // Engine. This pointer will remain valid until VoiceEngine is destroyed.
+  virtual RtcEventLog* GetEventLog() = 0;
+
  protected:
   VoECodec() {}
   virtual ~VoECodec() {}

webrtc/voice_engine/test/auto_test/standard/codec_test.cc

@@ -8,8 +8,14 @@
  *  be found in the AUTHORS file in the root of the source tree.
  */
 
+#include <stdio.h>
+#include <string>
+
+#include "webrtc/test/test_suite.h"
+#include "webrtc/test/testsupport/fileutils.h"
 #include "webrtc/voice_engine/test/auto_test/fixtures/after_streaming_fixture.h"
 #include "webrtc/voice_engine/voice_engine_defines.h"
+#include "webrtc/video/rtc_event_log.h"
 
 class CodecTest : public AfterStreamingFixture {
  protected:
@@ -182,6 +188,30 @@ TEST_F(CodecTest, OpusDtxCannotBeSetForNonOpus) {
   }
 }
 
+#ifdef ENABLE_RTC_EVENT_LOG
+TEST_F(CodecTest, RtcEventLogIntegrationTest) {
+  webrtc::RtcEventLog* event_log = voe_codec_->GetEventLog();
+  ASSERT_TRUE(event_log);
+
+  // Find the name of the current test, in order to use it as a temporary
+  // filename.
+  auto test_info = ::testing::UnitTest::GetInstance()->current_test_info();
+  const std::string temp_filename = webrtc::test::OutputPath() +
+                                    test_info->test_case_name() +
+                                    test_info->name();
+  // Create a log file.
+  event_log->StartLogging(temp_filename, 1000);
+  event_log->StopLogging();
+
+  // Check if the file has been created.
+  FILE* event_file = fopen(temp_filename.c_str(), "r");
+  ASSERT_TRUE(event_file);
+  fclose(event_file);
+  // Remove the temporary file.
+  remove(temp_filename.c_str());
+}
+#endif  // ENABLE_RTC_EVENT_LOG
+
 // TODO(xians, phoglund): Re-enable when issue 372 is resolved.
 TEST_F(CodecTest, DISABLED_ManualVerifySendCodecsForAllPacketSizes) {
   for (int i = 0; i < voe_codec_->NumOfCodecs(); ++i) {

webrtc/voice_engine/test/cmd_test/voe_cmd_test.cc

@@ -25,6 +25,7 @@
 #include "webrtc/test/channel_transport/include/channel_transport.h"
 #include "webrtc/test/testsupport/fileutils.h"
 #include "webrtc/test/testsupport/trace_to_stderr.h"
+#include "webrtc/video/rtc_event_log.h"
 #include "webrtc/voice_engine/include/voe_audio_processing.h"
 #include "webrtc/voice_engine/include/voe_base.h"
 #include "webrtc/voice_engine/include/voe_codec.h"
@@ -451,7 +452,8 @@ void RunTest(std::string out_path) {
       printf("%i. Toggle Opus DTX \n", option_index++);
       printf("%i. Set bit rate (only take effect on codecs that allow the "
              "change) \n", option_index++);
-      printf("%i. Toggle debug recording \n", option_index++);
+      printf("%i. Toggle AECdump recording \n", option_index++);
+      printf("%i. Record RtcEventLog file of 30 seconds \n", option_index++);
 
       printf("Select action or %i to stop the call: ", option_index);
       int option_selection;
@@ -798,6 +800,9 @@ void RunTest(std::string out_path) {
           printf("Debug recording named %s started\n", kDebugFileName);
         }
         debug_recording_started = !debug_recording_started;
+      } else if (option_selection == option_index++) {
+        const char* kDebugFileName = "eventlog.rel";
+        codec->GetEventLog()->StartLogging(kDebugFileName, 30000);
       } else {
         break;
       }

webrtc/voice_engine/voe_base_impl.cc

@@ -424,7 +424,6 @@ int VoEBaseImpl::InitializeChannel(voe::ChannelOwner* channel_owner) {
         channel_owner->channel()->ChannelId());
     return -1;
   }
-
   return channel_owner->channel()->ChannelId();
 }
 

webrtc/voice_engine/voe_codec_impl.cc

@@ -473,6 +473,10 @@ void VoECodecImpl::ExternalToACMCodecRepresentation(CodecInst& toInst,
   }
 }
 
+RtcEventLog* VoECodecImpl::GetEventLog() {
+  return _shared->channel_manager().GetEventLog();
+}
+
 #endif  // WEBRTC_VOICE_ENGINE_CODEC_API
 
 }  // namespace webrtc

webrtc/voice_engine/voe_codec_impl.h

@@ -58,6 +58,8 @@ class VoECodecImpl : public VoECodec {
 
   int SetOpusDtx(int channel, bool enable_dtx) override;
 
+  RtcEventLog* GetEventLog() override;
+
  protected:
   VoECodecImpl(voe::SharedData* shared);
   ~VoECodecImpl() override;

webrtc/voice_engine/voice_engine.gyp

@@ -26,6 +26,7 @@
         '<(webrtc_root)/modules/modules.gyp:rtp_rtcp',
         '<(webrtc_root)/modules/modules.gyp:webrtc_utility',
         '<(webrtc_root)/system_wrappers/system_wrappers.gyp:system_wrappers',
+        '<(webrtc_root)/webrtc.gyp:rtc_event_log',
       ],
       'sources': [
         'include/voe_audio_processing.h',
@@ -153,6 +154,7 @@
             '<(webrtc_root)/system_wrappers/system_wrappers.gyp:system_wrappers_default',
             '<(webrtc_root)/test/test.gyp:channel_transport',
             '<(webrtc_root)/test/test.gyp:test_support',
+            '<(webrtc_root)/webrtc.gyp:rtc_event_log',
            ],
           'sources': [
             'test/auto_test/automated_mode.cc',
@@ -208,6 +210,11 @@
                 'test/auto_test/standard/hardware_before_streaming_test.cc',
               ],
             }],
+            ['enable_protobuf==1', {
+              'defines': [
+                'ENABLE_RTC_EVENT_LOG',
+              ],
+            }],
           ],
           # Disable warnings to enable Win64 build, issue 1323.
           'msvs_disabled_warnings': [
@@ -226,6 +233,7 @@
             '<(webrtc_root)/system_wrappers/system_wrappers.gyp:system_wrappers_default',
             '<(webrtc_root)/test/test.gyp:channel_transport',
             '<(webrtc_root)/test/test.gyp:test_support',
+            '<(webrtc_root)/webrtc.gyp:rtc_event_log',
           ],
           'sources': [
             'test/cmd_test/voe_cmd_test.cc',