Audio stack traces

Bug: webrtc:0
Change-Id: I90ea6301f02c2ebe72711ddbeda0bf000a6873aa
Reviewed-on: https://webrtc-review.googlesource.com/c/src/+/276940
Auto-Submit: Olga Sharonova <olka@webrtc.org>
Commit-Queue: Henrik Andreassson <henrika@webrtc.org>
Reviewed-by: Henrik Andreassson <henrika@webrtc.org>
Cr-Commit-Position: refs/heads/main@{#38223}

audio/BUILD.gn

@@ -87,6 +87,7 @@ rtc_library("audio") {
     "../rtc_base:audio_format_to_string",
     "../rtc_base:buffer",
     "../rtc_base:checks",
+    "../rtc_base:event_tracer",
     "../rtc_base:logging",
     "../rtc_base:macromagic",
     "../rtc_base:race_checker",

audio/audio_send_stream.cc

@@ -39,6 +39,7 @@
 #include "rtc_base/logging.h"
 #include "rtc_base/strings/audio_format_to_string.h"
 #include "rtc_base/task_queue.h"
+#include "rtc_base/trace_event.h"
 
 namespace webrtc {
 namespace {
@@ -392,6 +393,7 @@ void AudioSendStream::Stop() {
 void AudioSendStream::SendAudioData(std::unique_ptr<AudioFrame> audio_frame) {
   RTC_CHECK_RUNS_SERIALIZED(&audio_capture_race_checker_);
   RTC_DCHECK_GT(audio_frame->sample_rate_hz_, 0);
+  TRACE_EVENT0("webrtc", "AudioSendStream::SendAudioData");
   double duration = static_cast<double>(audio_frame->samples_per_channel_) /
                     audio_frame->sample_rate_hz_;
   {

audio/audio_transport_impl.cc

@@ -20,6 +20,7 @@
 #include "modules/async_audio_processing/async_audio_processing.h"
 #include "modules/audio_processing/include/audio_frame_proxies.h"
 #include "rtc_base/checks.h"
+#include "rtc_base/trace_event.h"
 
 namespace webrtc {
 
@@ -177,6 +178,7 @@ int32_t AudioTransportImpl::RecordedDataIsAvailable(
 
 void AudioTransportImpl::SendProcessedData(
     std::unique_ptr<AudioFrame> audio_frame) {
+  TRACE_EVENT0("webrtc", "AudioTransportImpl::SendProcessedData");
   RTC_DCHECK_GT(audio_frame->samples_per_channel_, 0);
   MutexLock lock(&capture_lock_);
   if (audio_senders_.empty())
@@ -202,6 +204,7 @@ int32_t AudioTransportImpl::NeedMorePlayData(const size_t nSamples,
                                              size_t& nSamplesOut,
                                              int64_t* elapsed_time_ms,
                                              int64_t* ntp_time_ms) {
+  TRACE_EVENT0("webrtc", "AudioTransportImpl::SendProcessedData");
   RTC_DCHECK_EQ(sizeof(int16_t) * nChannels, nBytesPerSample);
   RTC_DCHECK_GE(nChannels, 1);
   RTC_DCHECK_LE(nChannels, 2);
@@ -239,6 +242,8 @@ void AudioTransportImpl::PullRenderData(int bits_per_sample,
                                         void* audio_data,
                                         int64_t* elapsed_time_ms,
                                         int64_t* ntp_time_ms) {
+  TRACE_EVENT2("webrtc", "AudioTransportImpl::PullRenderData", "sample_rate",
+               sample_rate, "number_of_frames", number_of_frames);
   RTC_DCHECK_EQ(bits_per_sample, 16);
   RTC_DCHECK_GE(number_of_channels, 1);
   RTC_DCHECK_GE(sample_rate, AudioProcessing::NativeRate::kSampleRate8kHz);

audio/channel_receive.cc

@@ -48,6 +48,7 @@
 #include "rtc_base/synchronization/mutex.h"
 #include "rtc_base/system/no_unique_address.h"
 #include "rtc_base/time_utils.h"
+#include "rtc_base/trace_event.h"
 #include "system_wrappers/include/metrics.h"
 #include "system_wrappers/include/ntp_time.h"
 
@@ -375,6 +376,8 @@ void ChannelReceive::InitFrameTransformerDelegate(
 AudioMixer::Source::AudioFrameInfo ChannelReceive::GetAudioFrameWithInfo(
     int sample_rate_hz,
     AudioFrame* audio_frame) {
+  TRACE_EVENT1("webrtc", "ChannelReceive::GetAudioFrameWithInfo",
+               "sample_rate_hz", sample_rate_hz);
   RTC_DCHECK_RUNS_SERIALIZED(&audio_thread_race_checker_);
   audio_frame->sample_rate_hz_ = sample_rate_hz;
 
@@ -440,7 +443,6 @@ AudioMixer::Source::AudioFrameInfo ChannelReceive::GetAudioFrameWithInfo(
 
   if (capture_start_rtp_time_stamp_ >= 0) {
     // audio_frame.timestamp_ should be valid from now on.
-
     // Compute elapsed time.
     int64_t unwrap_timestamp =
         rtp_ts_wraparound_handler_->Unwrap(audio_frame->timestamp_);

audio/channel_send.cc

@@ -40,6 +40,7 @@
 #include "rtc_base/synchronization/mutex.h"
 #include "rtc_base/task_queue.h"
 #include "rtc_base/time_utils.h"
+#include "rtc_base/trace_event.h"
 #include "system_wrappers/include/clock.h"
 #include "system_wrappers/include/metrics.h"
 
@@ -801,6 +802,8 @@ void ChannelSend::RtcpPacketTypesCounterUpdated(
 
 void ChannelSend::ProcessAndEncodeAudio(
     std::unique_ptr<AudioFrame> audio_frame) {
+  TRACE_EVENT0("webrtc", "ChannelSend::ProcessAndEncodeAudio");
+
   RTC_DCHECK_RUNS_SERIALIZED(&audio_thread_race_checker_);
   RTC_DCHECK_GT(audio_frame->samples_per_channel_, 0);
   RTC_DCHECK_LE(audio_frame->num_channels_, 8);

media/engine/webrtc_voice_engine.cc

@@ -923,6 +923,8 @@ class WebRtcVoiceMediaChannel::WebRtcAudioSendStream
               size_t number_of_channels,
               size_t number_of_frames,
               absl::optional<int64_t> absolute_capture_timestamp_ms) override {
+    TRACE_EVENT_BEGIN2("webrtc", "WebRtcAudioSendStream::OnData", "sample_rate",
+                       sample_rate, "number_of_frames", number_of_frames);
     RTC_DCHECK_EQ(16, bits_per_sample);
     RTC_CHECK_RUNS_SERIALIZED(&audio_capture_race_checker_);
     RTC_DCHECK(stream_);
@@ -938,6 +940,8 @@ class WebRtcVoiceMediaChannel::WebRtcAudioSendStream
           *absolute_capture_timestamp_ms);
     }
     stream_->SendAudioData(std::move(audio_frame));
+    TRACE_EVENT_END1("webrtc", "WebRtcAudioSendStream::OnData",
+                     "number_of_channels", number_of_channels);
   }
 
   // Callback from the `source_` when it is going away. In case Start() has

modules/audio_device/BUILD.gn

@@ -72,6 +72,7 @@ rtc_library("audio_device_buffer") {
     "../../common_audio:common_audio_c",
     "../../rtc_base:buffer",
     "../../rtc_base:checks",
+    "../../rtc_base:event_tracer",
     "../../rtc_base:logging",
     "../../rtc_base:macromagic",
     "../../rtc_base:rtc_task_queue",

modules/audio_device/audio_device_buffer.cc

@@ -20,6 +20,7 @@
 #include "rtc_base/checks.h"
 #include "rtc_base/logging.h"
 #include "rtc_base/time_utils.h"
+#include "rtc_base/trace_event.h"
 #include "system_wrappers/include/metrics.h"
 
 namespace webrtc {
@@ -297,6 +298,9 @@ int32_t AudioDeviceBuffer::DeliverRecordedData() {
 }
 
 int32_t AudioDeviceBuffer::RequestPlayoutData(size_t samples_per_channel) {
+  TRACE_EVENT1("webrtc", "AudioDeviceBuffer::RequestPlayoutData",
+               "samples_per_channel", samples_per_channel);
+
   // The consumer can change the requested size on the fly and we therefore
   // resize the buffer accordingly. Also takes place at the first call to this
   // method.

modules/audio_mixer/BUILD.gn

@@ -46,6 +46,7 @@ rtc_library("audio_mixer_impl") {
     "../../audio/utility:audio_frame_operations",
     "../../common_audio",
     "../../rtc_base:checks",
+    "../../rtc_base:event_tracer",
     "../../rtc_base:logging",
     "../../rtc_base:macromagic",
     "../../rtc_base:race_checker",

modules/audio_mixer/audio_mixer_impl.cc

@@ -21,6 +21,7 @@
 #include "modules/audio_mixer/default_output_rate_calculator.h"
 #include "rtc_base/checks.h"
 #include "rtc_base/logging.h"
+#include "rtc_base/trace_event.h"
 
 namespace webrtc {
 
@@ -156,6 +157,7 @@ rtc::scoped_refptr<AudioMixerImpl> AudioMixerImpl::Create(
 
 void AudioMixerImpl::Mix(size_t number_of_channels,
                          AudioFrame* audio_frame_for_mixing) {
+  TRACE_EVENT0("webrtc", "AudioMixerImpl::Mix");
   RTC_DCHECK(number_of_channels >= 1);
   MutexLock lock(&mutex_);
 

modules/rtp_rtcp/source/source_tracker.cc

@@ -13,6 +13,8 @@
 #include <algorithm>
 #include <utility>
 
+#include "rtc_base/trace_event.h"
+
 namespace webrtc {
 
 constexpr int64_t SourceTracker::kTimeoutMs;
@@ -24,6 +26,8 @@ void SourceTracker::OnFrameDelivered(const RtpPacketInfos& packet_infos) {
     return;
   }
 
+  TRACE_EVENT0("webrtc", "SourceTracker::OnFrameDelivered");
+
   int64_t now_ms = clock_->TimeInMilliseconds();
   MutexLock lock_scope(&lock_);
 

pc/BUILD.gn

@@ -1828,6 +1828,7 @@ rtc_library("remote_audio_source") {
     "../media:rtc_media_base",
     "../rtc_base",
     "../rtc_base:checks",
+    "../rtc_base:event_tracer",
     "../rtc_base:logging",
     "../rtc_base:safe_conversions",
     "../rtc_base:stringutils",

pc/remote_audio_source.cc

@@ -23,6 +23,7 @@
 #include "rtc_base/checks.h"
 #include "rtc_base/logging.h"
 #include "rtc_base/strings/string_format.h"
+#include "rtc_base/trace_event.h"
 
 namespace webrtc {
 
@@ -149,6 +150,7 @@ void RemoteAudioSource::RemoveSink(AudioTrackSinkInterface* sink) {
 
 void RemoteAudioSource::OnData(const AudioSinkInterface::Data& audio) {
   // Called on the externally-owned audio callback thread, via/from webrtc.
+  TRACE_EVENT0("webrtc", "RemoteAudioSource::OnData");
   MutexLock lock(&sink_lock_);
   for (auto* sink : sinks_) {
     // When peerconnection acts as an audio source, it should not provide

pc/rtp_sender.cc

@@ -474,6 +474,8 @@ void LocalAudioSinkAdapter::OnData(
     size_t number_of_channels,
     size_t number_of_frames,
     absl::optional<int64_t> absolute_capture_timestamp_ms) {
+  TRACE_EVENT2("webrtc", "LocalAudioSinkAdapter::OnData", "sample_rate",
+               sample_rate, "number_of_frames", number_of_frames);
   MutexLock lock(&lock_);
   if (sink_) {
     sink_->OnData(audio_data, bits_per_sample, sample_rate, number_of_channels,