From 4a87e1c21138e80b044c97912f2db5a4924a65c2 Mon Sep 17 00:00:00 2001 From: Elad Alon Date: Tue, 3 Oct 2017 16:11:34 +0200 Subject: [PATCH] Remove encoding code from RtcEventLogImpl and use RtcEventLogEncoder instead MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit RtcEventLogImpl no longer hard-codes the way encoding is done. It now relies on RtcEventEncoder for it. This gives two benefits: 1. We can decide between the current encoding and the new encoding (which is still WIP) without code duplication (no need for RtcEventLogImplNew). 2. Encoding is done only when the event needs to be written to a file. This both avoids unnecessary encoding of events which don't end up getting written to a file, as well as is useful for the new, delta-based encoding, which is stateful. BUG=webrtc:8111 Change-Id: I9517132e5f96b8059002a66fde8d42d3a678c3bb Reviewed-on: https://webrtc-review.googlesource.com/1365 Reviewed-by: Stefan Holmer Reviewed-by: Björn Terelius Commit-Queue: Stefan Holmer Commit-Queue: Elad Alon Cr-Commit-Position: refs/heads/master@{#20118} --- call/call.cc | 31 +- .../rtc_event_log/mock/mock_rtc_event_log.h | 6 + logging/rtc_event_log/rtc_event_log.cc | 489 +++++------------- logging/rtc_event_log/rtc_event_log.h | 85 +-- .../rtc_event_log/rtc_event_log_factory.cc | 5 +- logging/rtc_event_log/rtc_event_log_factory.h | 3 +- .../rtc_event_log_factory_interface.h | 3 +- .../rtc_event_log/rtc_event_log_unittest.cc | 140 +++-- modules/audio_coding/BUILD.gn | 1 + .../audio_network_adaptor_impl_unittest.cc | 13 +- .../audio_network_adaptor/event_log_writer.cc | 7 +- .../event_log_writer_unittest.cc | 125 ++--- .../include/audio_network_adaptor_config.h | 3 - modules/bitrate_controller/BUILD.gn | 1 + .../send_side_bandwidth_estimation.cc | 7 +- ...send_side_bandwidth_estimation_unittest.cc | 22 +- .../congestion_controller/delay_based_bwe.cc | 8 +- .../probe_bitrate_estimator.cc | 20 +- modules/pacing/bitrate_prober.cc | 6 +- modules/rtp_rtcp/BUILD.gn | 1 + modules/rtp_rtcp/source/rtcp_sender.cc | 10 +- modules/rtp_rtcp/source/rtp_sender.cc | 5 +- .../rtp_rtcp/source/rtp_sender_unittest.cc | 37 +- pc/peerconnectionfactory.cc | 6 +- video/video_quality_test.cc | 2 +- voice_engine/BUILD.gn | 1 + voice_engine/channel.cc | 66 ++- 27 files changed, 511 insertions(+), 592 deletions(-) diff --git a/call/call.cc b/call/call.cc index 8bfab8a493..d497760ee5 100644 --- a/call/call.cc +++ b/call/call.cc @@ -27,6 +27,12 @@ #include "call/flexfec_receive_stream_impl.h" #include "call/rtp_stream_receiver_controller.h" #include "call/rtp_transport_controller_send.h" +#include "logging/rtc_event_log/events/rtc_event_audio_receive_stream_config.h" +#include "logging/rtc_event_log/events/rtc_event_audio_send_stream_config.h" +#include "logging/rtc_event_log/events/rtc_event_rtcp_packet_incoming.h" +#include "logging/rtc_event_log/events/rtc_event_rtp_packet_incoming.h" +#include "logging/rtc_event_log/events/rtc_event_video_receive_stream_config.h" +#include "logging/rtc_event_log/events/rtc_event_video_send_stream_config.h" #include "logging/rtc_event_log/rtc_event_log.h" #include "logging/rtc_event_log/rtc_stream_config.h" #include "modules/bitrate_controller/include/bitrate_controller.h" @@ -609,7 +615,8 @@ webrtc::AudioSendStream* Call::CreateAudioSendStream( const webrtc::AudioSendStream::Config& config) { TRACE_EVENT0("webrtc", "Call::CreateAudioSendStream"); RTC_DCHECK_CALLED_SEQUENTIALLY(&configuration_sequence_checker_); - event_log_->LogAudioSendStreamConfig(*CreateRtcLogStreamConfig(config)); + event_log_->Log(rtc::MakeUnique( + CreateRtcLogStreamConfig(config))); rtc::Optional suspended_rtp_state; { @@ -675,7 +682,8 @@ webrtc::AudioReceiveStream* Call::CreateAudioReceiveStream( const webrtc::AudioReceiveStream::Config& config) { TRACE_EVENT0("webrtc", "Call::CreateAudioReceiveStream"); RTC_DCHECK_CALLED_SEQUENTIALLY(&configuration_sequence_checker_); - event_log_->LogAudioReceiveStreamConfig(*CreateRtcLogStreamConfig(config)); + event_log_->Log(rtc::MakeUnique( + CreateRtcLogStreamConfig(config))); AudioReceiveStream* receive_stream = new AudioReceiveStream( &audio_receiver_controller_, transport_send_->packet_router(), config, config_.audio_state, event_log_); @@ -735,8 +743,8 @@ webrtc::VideoSendStream* Call::CreateVideoSendStream( video_send_delay_stats_->AddSsrcs(config); for (size_t ssrc_index = 0; ssrc_index < config.rtp.ssrcs.size(); ++ssrc_index) { - event_log_->LogVideoSendStreamConfig( - *CreateRtcLogStreamConfig(config, ssrc_index)); + event_log_->Log(rtc::MakeUnique( + CreateRtcLogStreamConfig(config, ssrc_index))); } // TODO(mflodman): Base the start bitrate on a current bandwidth estimate, if @@ -826,7 +834,8 @@ webrtc::VideoReceiveStream* Call::CreateVideoReceiveStream( } receive_stream->SignalNetworkState(video_network_state_); UpdateAggregateNetworkState(); - event_log_->LogVideoReceiveStreamConfig(*CreateRtcLogStreamConfig(config)); + event_log_->Log(rtc::MakeUnique( + CreateRtcLogStreamConfig(config))); return receive_stream; } @@ -1302,8 +1311,10 @@ PacketReceiver::DeliveryStatus Call::DeliverRtcp(MediaType media_type, } } - if (rtcp_delivered) - event_log_->LogIncomingRtcpPacket(rtc::MakeArrayView(packet, length)); + if (rtcp_delivered) { + event_log_->Log(rtc::MakeUnique( + rtc::MakeArrayView(packet, length))); + } return rtcp_delivered ? DELIVERY_OK : DELIVERY_PACKET_ERROR; } @@ -1352,7 +1363,8 @@ PacketReceiver::DeliveryStatus Call::DeliverRtp(MediaType media_type, if (audio_receiver_controller_.OnRtpPacket(*parsed_packet)) { received_bytes_per_second_counter_.Add(static_cast(length)); received_audio_bytes_per_second_counter_.Add(static_cast(length)); - event_log_->LogIncomingRtpHeader(*parsed_packet); + event_log_->Log( + rtc::MakeUnique(*parsed_packet)); const int64_t arrival_time_ms = parsed_packet->arrival_time_ms(); if (!first_received_rtp_audio_ms_) { first_received_rtp_audio_ms_.emplace(arrival_time_ms); @@ -1364,7 +1376,8 @@ PacketReceiver::DeliveryStatus Call::DeliverRtp(MediaType media_type, if (video_receiver_controller_.OnRtpPacket(*parsed_packet)) { received_bytes_per_second_counter_.Add(static_cast(length)); received_video_bytes_per_second_counter_.Add(static_cast(length)); - event_log_->LogIncomingRtpHeader(*parsed_packet); + event_log_->Log( + rtc::MakeUnique(*parsed_packet)); const int64_t arrival_time_ms = parsed_packet->arrival_time_ms(); if (!first_received_rtp_video_ms_) { first_received_rtp_video_ms_.emplace(arrival_time_ms); diff --git a/logging/rtc_event_log/mock/mock_rtc_event_log.h b/logging/rtc_event_log/mock/mock_rtc_event_log.h index ea09c5bb23..ef351a25b3 100644 --- a/logging/rtc_event_log/mock/mock_rtc_event_log.h +++ b/logging/rtc_event_log/mock/mock_rtc_event_log.h @@ -11,6 +11,7 @@ #ifndef LOGGING_RTC_EVENT_LOG_MOCK_MOCK_RTC_EVENT_LOG_H_ #define LOGGING_RTC_EVENT_LOG_MOCK_MOCK_RTC_EVENT_LOG_H_ +#include #include #include "logging/rtc_event_log/rtc_event_log.h" @@ -32,6 +33,11 @@ class MockRtcEventLog : public RtcEventLog { MOCK_METHOD0(StopLogging, void()); + virtual void Log(std::unique_ptr event) { + return LogProxy(event.get()); + } + MOCK_METHOD1(LogProxy, void(RtcEvent*)); + MOCK_METHOD1(LogVideoReceiveStreamConfig, void(const rtclog::StreamConfig& config)); diff --git a/logging/rtc_event_log/rtc_event_log.cc b/logging/rtc_event_log/rtc_event_log.cc index bc9f1439ae..a3f7667d00 100644 --- a/logging/rtc_event_log/rtc_event_log.cc +++ b/logging/rtc_event_log/rtc_event_log.cc @@ -18,7 +18,27 @@ #include #include +#include "logging/rtc_event_log/encoder/rtc_event_log_encoder_legacy.h" +// TODO(eladalon): Remove events/* when the deprecated functions are removed. +#include "logging/rtc_event_log/events/rtc_event_audio_network_adaptation.h" +#include "logging/rtc_event_log/events/rtc_event_audio_playout.h" +#include "logging/rtc_event_log/events/rtc_event_audio_receive_stream_config.h" +#include "logging/rtc_event_log/events/rtc_event_audio_send_stream_config.h" +#include "logging/rtc_event_log/events/rtc_event_bwe_update_delay_based.h" +#include "logging/rtc_event_log/events/rtc_event_bwe_update_loss_based.h" +#include "logging/rtc_event_log/events/rtc_event_logging_started.h" +#include "logging/rtc_event_log/events/rtc_event_logging_stopped.h" +#include "logging/rtc_event_log/events/rtc_event_probe_cluster_created.h" +#include "logging/rtc_event_log/events/rtc_event_probe_result_failure.h" +#include "logging/rtc_event_log/events/rtc_event_probe_result_success.h" +#include "logging/rtc_event_log/events/rtc_event_rtcp_packet_incoming.h" +#include "logging/rtc_event_log/events/rtc_event_rtcp_packet_outgoing.h" +#include "logging/rtc_event_log/events/rtc_event_rtp_packet_incoming.h" +#include "logging/rtc_event_log/events/rtc_event_rtp_packet_outgoing.h" +#include "logging/rtc_event_log/events/rtc_event_video_receive_stream_config.h" +#include "logging/rtc_event_log/events/rtc_event_video_send_stream_config.h" #include "logging/rtc_event_log/rtc_stream_config.h" +// TODO(eladalon): Remove these when deprecated functions are removed. #include "modules/audio_coding/audio_network_adaptor/include/audio_network_adaptor.h" #include "modules/remote_bitrate_estimator/include/bwe_defines.h" #include "modules/rtp_rtcp/include/rtp_rtcp_defines.h" @@ -38,7 +58,6 @@ #include "rtc_base/checks.h" #include "rtc_base/constructormagic.h" #include "rtc_base/event.h" -#include "rtc_base/ignore_wundef.h" #include "rtc_base/logging.h" #include "rtc_base/protobuf_utils.h" #include "rtc_base/ptr_util.h" @@ -46,20 +65,10 @@ #include "rtc_base/task_queue.h" #include "rtc_base/thread_annotations.h" #include "rtc_base/timeutils.h" +// TODO(eladalon): Remove this when output is modularized away. #include "system_wrappers/include/file_wrapper.h" #include "typedefs.h" // NOLINT(build/include) -#ifdef ENABLE_RTC_EVENT_LOG -// *.pb.h files are generated at build-time by the protobuf compiler. -RTC_PUSH_IGNORING_WUNDEF() -#ifdef WEBRTC_ANDROID_PLATFORM_BUILD -#include "external/webrtc/webrtc/logging/rtc_event_log/rtc_event_log.pb.h" -#else -#include "logging/rtc_event_log/rtc_event_log.pb.h" -#endif -RTC_POP_IGNORING_WUNDEF() -#endif - namespace webrtc { #ifdef ENABLE_RTC_EVENT_LOG @@ -67,14 +76,6 @@ namespace webrtc { namespace { const int kEventsInHistory = 10000; -bool IsConfigEvent(const rtclog::Event& event) { - rtclog::Event_EventType event_type = event.type(); - return event_type == rtclog::Event::VIDEO_RECEIVER_CONFIG_EVENT || - event_type == rtclog::Event::VIDEO_SENDER_CONFIG_EVENT || - event_type == rtclog::Event::AUDIO_RECEIVER_CONFIG_EVENT || - event_type == rtclog::Event::AUDIO_SENDER_CONFIG_EVENT; -} - // Observe a limit on the number of concurrent logs, so as not to run into // OS-imposed limits on open files and/or threads/task-queues. // TODO(eladalon): Known issue - there's a race over |rtc_event_log_count|. @@ -100,9 +101,21 @@ class ResourceOwningTask final : public rtc::QueuedTask { std::function)> handler_; }; +std::unique_ptr CreateEncoder( + RtcEventLog::EncodingType type) { + switch (type) { + case RtcEventLog::EncodingType::Legacy: + return rtc::MakeUnique(); + default: + LOG(LS_ERROR) << "Unknown RtcEventLog encoder type (" << int(type) << ")"; + RTC_NOTREACHED(); + return std::unique_ptr(nullptr); + } +} + class RtcEventLogImpl final : public RtcEventLog { public: - RtcEventLogImpl(); + explicit RtcEventLogImpl(std::unique_ptr event_encoder); ~RtcEventLogImpl() override; bool StartLogging(const std::string& file_name, @@ -110,6 +123,7 @@ class RtcEventLogImpl final : public RtcEventLog { bool StartLogging(rtc::PlatformFile platform_file, int64_t max_size_bytes) override; void StopLogging() override; + void Log(std::unique_ptr event) override; void LogVideoReceiveStreamConfig(const rtclog::StreamConfig& config) override; void LogVideoSendStreamConfig(const rtclog::StreamConfig& config) override; void LogAudioReceiveStreamConfig(const rtclog::StreamConfig& config) override; @@ -155,21 +169,17 @@ class RtcEventLogImpl final : public RtcEventLog { void StartLoggingInternal(std::unique_ptr file, int64_t max_size_bytes); - void StoreEvent(std::unique_ptr event); - void LogProbeResult(int id, - rtclog::BweProbeResult::ResultType result, - int bitrate_bps); - // Appends an event to the output protobuf string, returning true on success. // Fails and returns false in case the limit on output size prevents the // event from being added; in this case, the output string is left unchanged. - bool AppendEventToString(rtclog::Event* event, + // The event is encoded before being appended. + bool AppendEventToString(const RtcEvent& event, ProtoString* output_string) RTC_WARN_UNUSED_RESULT; - void LogToMemory(std::unique_ptr event); + void LogToMemory(std::unique_ptr event); void StartLogFile(); - void LogToFile(std::unique_ptr event); + void LogToFile(std::unique_ptr event); void StopLogFile(int64_t stop_time); // Make sure that the event log is "managed" - created/destroyed, as well @@ -177,18 +187,19 @@ class RtcEventLogImpl final : public RtcEventLog { rtc::SequencedTaskChecker owner_sequence_checker_; // History containing all past configuration events. - std::vector> config_history_ + std::vector> config_history_ RTC_ACCESS_ON(task_queue_); // History containing the most recent (non-configuration) events (~10s). - std::deque> history_ - RTC_ACCESS_ON(task_queue_); + std::deque> history_ RTC_ACCESS_ON(task_queue_); std::unique_ptr file_ RTC_ACCESS_ON(task_queue_); size_t max_size_bytes_ RTC_ACCESS_ON(task_queue_); size_t written_bytes_ RTC_ACCESS_ON(task_queue_); + std::unique_ptr event_encoder_ RTC_ACCESS_ON(task_queue_); + // Keep this last to ensure it destructs first, or else tasks living on the // queue might access other members after they've been torn down. rtc::TaskQueue task_queue_; @@ -196,56 +207,12 @@ class RtcEventLogImpl final : public RtcEventLog { RTC_DISALLOW_COPY_AND_ASSIGN(RtcEventLogImpl); }; -rtclog::VideoReceiveConfig_RtcpMode ConvertRtcpMode(RtcpMode rtcp_mode) { - switch (rtcp_mode) { - case RtcpMode::kCompound: - return rtclog::VideoReceiveConfig::RTCP_COMPOUND; - case RtcpMode::kReducedSize: - return rtclog::VideoReceiveConfig::RTCP_REDUCEDSIZE; - case RtcpMode::kOff: - RTC_NOTREACHED(); - return rtclog::VideoReceiveConfig::RTCP_COMPOUND; - } - RTC_NOTREACHED(); - return rtclog::VideoReceiveConfig::RTCP_COMPOUND; -} - -rtclog::DelayBasedBweUpdate::DetectorState ConvertDetectorState( - BandwidthUsage state) { - switch (state) { - case BandwidthUsage::kBwNormal: - return rtclog::DelayBasedBweUpdate::BWE_NORMAL; - case BandwidthUsage::kBwUnderusing: - return rtclog::DelayBasedBweUpdate::BWE_UNDERUSING; - case BandwidthUsage::kBwOverusing: - return rtclog::DelayBasedBweUpdate::BWE_OVERUSING; - case BandwidthUsage::kLast: - RTC_NOTREACHED(); - } - RTC_NOTREACHED(); - return rtclog::DelayBasedBweUpdate::BWE_NORMAL; -} - -rtclog::BweProbeResult::ResultType ConvertProbeResultType( - ProbeFailureReason failure_reason) { - switch (failure_reason) { - case ProbeFailureReason::kInvalidSendReceiveInterval: - return rtclog::BweProbeResult::INVALID_SEND_RECEIVE_INTERVAL; - case ProbeFailureReason::kInvalidSendReceiveRatio: - return rtclog::BweProbeResult::INVALID_SEND_RECEIVE_RATIO; - case ProbeFailureReason::kTimeout: - return rtclog::BweProbeResult::TIMEOUT; - case ProbeFailureReason::kLast: - RTC_NOTREACHED(); - } - RTC_NOTREACHED(); - return rtclog::BweProbeResult::SUCCESS; -} - -RtcEventLogImpl::RtcEventLogImpl() +RtcEventLogImpl::RtcEventLogImpl( + std::unique_ptr event_encoder) : file_(FileWrapper::Create()), max_size_bytes_(std::numeric_limits::max()), written_bytes_(0), + event_encoder_(std::move(event_encoder)), task_queue_("rtc_event_log") {} RtcEventLogImpl::~RtcEventLogImpl() { @@ -320,129 +287,53 @@ void RtcEventLogImpl::StopLogging() { LOG(LS_INFO) << "WebRTC event log successfully stopped."; } +void RtcEventLogImpl::Log(std::unique_ptr event) { + RTC_DCHECK(event); + + auto event_handler = [this](std::unique_ptr unencoded_event) { + RTC_DCHECK_RUN_ON(&task_queue_); + if (file_->is_open()) { + LogToFile(std::move(unencoded_event)); + } else { + LogToMemory(std::move(unencoded_event)); + } + }; + + task_queue_.PostTask(rtc::MakeUnique>( + std::move(event), event_handler)); +} + void RtcEventLogImpl::LogVideoReceiveStreamConfig( const rtclog::StreamConfig& config) { - std::unique_ptr event(new rtclog::Event()); - event->set_timestamp_us(rtc::TimeMicros()); - event->set_type(rtclog::Event::VIDEO_RECEIVER_CONFIG_EVENT); - - rtclog::VideoReceiveConfig* receiver_config = - event->mutable_video_receiver_config(); - receiver_config->set_remote_ssrc(config.remote_ssrc); - receiver_config->set_local_ssrc(config.local_ssrc); - - // TODO(perkj): Add field for rsid. - receiver_config->set_rtcp_mode(ConvertRtcpMode(config.rtcp_mode)); - receiver_config->set_remb(config.remb); - - for (const auto& e : config.rtp_extensions) { - rtclog::RtpHeaderExtension* extension = - receiver_config->add_header_extensions(); - extension->set_name(e.uri); - extension->set_id(e.id); - } - - for (const auto& d : config.codecs) { - rtclog::DecoderConfig* decoder = receiver_config->add_decoders(); - decoder->set_name(d.payload_name); - decoder->set_payload_type(d.payload_type); - if (d.rtx_payload_type != 0) { - rtclog::RtxMap* rtx = receiver_config->add_rtx_map(); - rtx->set_payload_type(d.payload_type); - rtx->mutable_config()->set_rtx_ssrc(config.rtx_ssrc); - rtx->mutable_config()->set_rtx_payload_type(d.rtx_payload_type); - } - } - StoreEvent(std::move(event)); + Log(rtc::MakeUnique( + rtc::MakeUnique(config))); } void RtcEventLogImpl::LogVideoSendStreamConfig( const rtclog::StreamConfig& config) { - std::unique_ptr event(new rtclog::Event()); - event->set_timestamp_us(rtc::TimeMicros()); - event->set_type(rtclog::Event::VIDEO_SENDER_CONFIG_EVENT); - - rtclog::VideoSendConfig* sender_config = event->mutable_video_sender_config(); - - // TODO(perkj): rtclog::VideoSendConfig should only contain one SSRC. - sender_config->add_ssrcs(config.local_ssrc); - if (config.rtx_ssrc != 0) { - sender_config->add_rtx_ssrcs(config.rtx_ssrc); - } - - for (const auto& e : config.rtp_extensions) { - rtclog::RtpHeaderExtension* extension = - sender_config->add_header_extensions(); - extension->set_name(e.uri); - extension->set_id(e.id); - } - - // TODO(perkj): rtclog::VideoSendConfig should contain many possible codec - // configurations. - for (const auto& codec : config.codecs) { - sender_config->set_rtx_payload_type(codec.rtx_payload_type); - rtclog::EncoderConfig* encoder = sender_config->mutable_encoder(); - encoder->set_name(codec.payload_name); - encoder->set_payload_type(codec.payload_type); - - if (config.codecs.size() > 1) { - LOG(WARNING) << "LogVideoSendStreamConfig currently only supports one " - << "codec. Logging codec :" << codec.payload_name; - break; - } - } - - StoreEvent(std::move(event)); + Log(rtc::MakeUnique( + rtc::MakeUnique(config))); } void RtcEventLogImpl::LogAudioReceiveStreamConfig( const rtclog::StreamConfig& config) { - std::unique_ptr event(new rtclog::Event()); - event->set_timestamp_us(rtc::TimeMicros()); - event->set_type(rtclog::Event::AUDIO_RECEIVER_CONFIG_EVENT); - - rtclog::AudioReceiveConfig* receiver_config = - event->mutable_audio_receiver_config(); - receiver_config->set_remote_ssrc(config.remote_ssrc); - receiver_config->set_local_ssrc(config.local_ssrc); - - for (const auto& e : config.rtp_extensions) { - rtclog::RtpHeaderExtension* extension = - receiver_config->add_header_extensions(); - extension->set_name(e.uri); - extension->set_id(e.id); - } - StoreEvent(std::move(event)); + Log(rtc::MakeUnique( + rtc::MakeUnique(config))); } void RtcEventLogImpl::LogAudioSendStreamConfig( const rtclog::StreamConfig& config) { - std::unique_ptr event(new rtclog::Event()); - event->set_timestamp_us(rtc::TimeMicros()); - event->set_type(rtclog::Event::AUDIO_SENDER_CONFIG_EVENT); - - rtclog::AudioSendConfig* sender_config = event->mutable_audio_sender_config(); - - sender_config->set_ssrc(config.local_ssrc); - - for (const auto& e : config.rtp_extensions) { - rtclog::RtpHeaderExtension* extension = - sender_config->add_header_extensions(); - extension->set_name(e.uri); - extension->set_id(e.id); - } - - StoreEvent(std::move(event)); + Log(rtc::MakeUnique( + rtc::MakeUnique(config))); } void RtcEventLogImpl::LogIncomingRtpHeader(const RtpPacketReceived& packet) { - LogRtpHeader(kIncomingPacket, packet.data(), packet.size(), - PacedPacketInfo::kNotAProbe); + Log(rtc::MakeUnique(packet)); } void RtcEventLogImpl::LogOutgoingRtpHeader(const RtpPacketToSend& packet, int probe_cluster_id) { - LogRtpHeader(kOutgoingPacket, packet.data(), packet.size(), probe_cluster_id); + Log(rtc::MakeUnique(packet, probe_cluster_id)); } void RtcEventLogImpl::LogRtpHeader(PacketDirection direction, @@ -455,187 +346,79 @@ void RtcEventLogImpl::LogRtpHeader(PacketDirection direction, 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. + // TODO(eladalon): This is highly inefficient. We're only doing this for + // the deprecated interface. We should remove this soon. + if (direction == PacketDirection::kIncomingPacket) { + RtpPacketReceived packet; + packet.Parse(header, packet_length); + Log(rtc::MakeUnique(packet)); + } else { + RTC_CHECK_EQ(direction, PacketDirection::kOutgoingPacket); + RtpPacketToSend packet(nullptr); + packet.Parse(header, packet_length); + Log(rtc::MakeUnique(packet, probe_cluster_id)); } - 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::ReadBigEndian(header + 14 + cc * 4); - header_length += (x_len + 1) * 4; - } - - std::unique_ptr 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_packet_length(packet_length); - rtp_event->mutable_rtp_packet()->set_header(header, header_length); - if (probe_cluster_id != PacedPacketInfo::kNotAProbe) - rtp_event->mutable_rtp_packet()->set_probe_cluster_id(probe_cluster_id); - StoreEvent(std::move(rtp_event)); } void RtcEventLogImpl::LogIncomingRtcpPacket( rtc::ArrayView packet) { - LogRtcpPacket(kIncomingPacket, packet.data(), packet.size()); + Log(rtc::MakeUnique(packet)); } void RtcEventLogImpl::LogOutgoingRtcpPacket( rtc::ArrayView packet) { - LogRtcpPacket(kOutgoingPacket, packet.data(), packet.size()); + Log(rtc::MakeUnique(packet)); } void RtcEventLogImpl::LogRtcpPacket(PacketDirection direction, const uint8_t* packet, size_t length) { - std::unique_ptr rtcp_event(new rtclog::Event()); - rtcp_event->set_timestamp_us(rtc::TimeMicros()); - rtcp_event->set_type(rtclog::Event::RTCP_EVENT); - rtcp_event->mutable_rtcp_packet()->set_incoming(direction == kIncomingPacket); - - rtcp::CommonHeader header; - const uint8_t* block_begin = packet; - const uint8_t* packet_end = packet + length; - RTC_DCHECK(length <= IP_PACKET_SIZE); - uint8_t buffer[IP_PACKET_SIZE]; - uint32_t buffer_length = 0; - while (block_begin < packet_end) { - if (!header.Parse(block_begin, packet_end - block_begin)) { - break; // Incorrect message header. - } - const uint8_t* next_block = header.NextPacket(); - uint32_t block_size = next_block - block_begin; - switch (header.type()) { - case rtcp::SenderReport::kPacketType: - case rtcp::ReceiverReport::kPacketType: - case rtcp::Bye::kPacketType: - case rtcp::ExtendedJitterReport::kPacketType: - case rtcp::Rtpfb::kPacketType: - case rtcp::Psfb::kPacketType: - case rtcp::ExtendedReports::kPacketType: - // We log sender reports, receiver reports, bye messages - // inter-arrival jitter, third-party loss reports, payload-specific - // feedback and extended reports. - memcpy(buffer + buffer_length, block_begin, block_size); - buffer_length += block_size; - break; - case rtcp::Sdes::kPacketType: - case rtcp::App::kPacketType: - default: - // We don't log sender descriptions, application defined messages - // or message blocks of unknown type. - break; - } - - block_begin += block_size; + if (direction == PacketDirection::kIncomingPacket) { + LogIncomingRtcpPacket(rtc::ArrayView(packet, length)); + } else { + RTC_CHECK_EQ(direction, PacketDirection::kOutgoingPacket); + LogOutgoingRtcpPacket(rtc::ArrayView(packet, length)); } - rtcp_event->mutable_rtcp_packet()->set_packet_data(buffer, buffer_length); - StoreEvent(std::move(rtcp_event)); } void RtcEventLogImpl::LogAudioPlayout(uint32_t ssrc) { - std::unique_ptr event(new rtclog::Event()); - event->set_timestamp_us(rtc::TimeMicros()); - event->set_type(rtclog::Event::AUDIO_PLAYOUT_EVENT); - auto playout_event = event->mutable_audio_playout_event(); - playout_event->set_local_ssrc(ssrc); - StoreEvent(std::move(event)); + Log(rtc::MakeUnique(ssrc)); } void RtcEventLogImpl::LogLossBasedBweUpdate(int32_t bitrate_bps, uint8_t fraction_loss, int32_t total_packets) { - std::unique_ptr event(new rtclog::Event()); - event->set_timestamp_us(rtc::TimeMicros()); - event->set_type(rtclog::Event::LOSS_BASED_BWE_UPDATE); - auto bwe_event = event->mutable_loss_based_bwe_update(); - bwe_event->set_bitrate_bps(bitrate_bps); - bwe_event->set_fraction_loss(fraction_loss); - bwe_event->set_total_packets(total_packets); - StoreEvent(std::move(event)); + Log(rtc::MakeUnique(bitrate_bps, fraction_loss, + total_packets)); } void RtcEventLogImpl::LogDelayBasedBweUpdate(int32_t bitrate_bps, BandwidthUsage detector_state) { - std::unique_ptr event(new rtclog::Event()); - event->set_timestamp_us(rtc::TimeMicros()); - event->set_type(rtclog::Event::DELAY_BASED_BWE_UPDATE); - auto bwe_event = event->mutable_delay_based_bwe_update(); - bwe_event->set_bitrate_bps(bitrate_bps); - bwe_event->set_detector_state(ConvertDetectorState(detector_state)); - StoreEvent(std::move(event)); + Log(rtc::MakeUnique(bitrate_bps, + detector_state)); } void RtcEventLogImpl::LogAudioNetworkAdaptation( const AudioEncoderRuntimeConfig& config) { - std::unique_ptr event(new rtclog::Event()); - event->set_timestamp_us(rtc::TimeMicros()); - event->set_type(rtclog::Event::AUDIO_NETWORK_ADAPTATION_EVENT); - auto audio_network_adaptation = event->mutable_audio_network_adaptation(); - if (config.bitrate_bps) - audio_network_adaptation->set_bitrate_bps(*config.bitrate_bps); - if (config.frame_length_ms) - audio_network_adaptation->set_frame_length_ms(*config.frame_length_ms); - if (config.uplink_packet_loss_fraction) { - audio_network_adaptation->set_uplink_packet_loss_fraction( - *config.uplink_packet_loss_fraction); - } - 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(std::move(event)); + Log(rtc::MakeUnique( + rtc::MakeUnique(config))); } void RtcEventLogImpl::LogProbeClusterCreated(int id, int bitrate_bps, int min_probes, int min_bytes) { - std::unique_ptr 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_packets(min_probes); - probe_cluster->set_min_bytes(min_bytes); - StoreEvent(std::move(event)); + Log(rtc::MakeUnique(id, bitrate_bps, min_probes, + min_bytes)); } void RtcEventLogImpl::LogProbeResultSuccess(int id, int bitrate_bps) { - LogProbeResult(id, rtclog::BweProbeResult::SUCCESS, bitrate_bps); + Log(rtc::MakeUnique(id, bitrate_bps)); } void RtcEventLogImpl::LogProbeResultFailure(int id, ProbeFailureReason failure_reason) { - rtclog::BweProbeResult::ResultType result = - ConvertProbeResultType(failure_reason); - LogProbeResult(id, result, -1); -} - -void RtcEventLogImpl::LogProbeResult(int id, - rtclog::BweProbeResult::ResultType result, - int bitrate_bps) { - std::unique_ptr 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(std::move(event)); + Log(rtc::MakeUnique(id, failure_reason)); } void RtcEventLogImpl::StartLoggingInternal(std::unique_ptr file, @@ -661,61 +444,30 @@ void RtcEventLogImpl::StartLoggingInternal(std::unique_ptr file, std::move(file), file_handler)); } -void RtcEventLogImpl::StoreEvent(std::unique_ptr event) { - RTC_DCHECK(event); - - auto event_handler = [this](std::unique_ptr rtclog_event) { - RTC_DCHECK_RUN_ON(&task_queue_); - if (file_->is_open()) { - LogToFile(std::move(rtclog_event)); - } else { - LogToMemory(std::move(rtclog_event)); - } - }; - - task_queue_.PostTask(rtc::MakeUnique>( - std::move(event), event_handler)); -} - -bool RtcEventLogImpl::AppendEventToString(rtclog::Event* event, +bool RtcEventLogImpl::AppendEventToString(const RtcEvent& event, ProtoString* output_string) { RTC_DCHECK_RUN_ON(&task_queue_); - // Even though we're only serializing a single event during this call, what - // we intend to get is a list of events, with a tag and length preceding - // each actual event. To produce that, we serialize a list of a single event. - // If we later serialize additional events, the resulting ProtoString will - // be a proper concatenation of all those events. - - rtclog::EventStream event_stream; - event_stream.add_stream(); - - // As a tweak, we swap the new event into the event-stream, write that to - // file, then swap back. This saves on some copying. - rtclog::Event* output_event = event_stream.mutable_stream(0); - output_event->Swap(event); + std::string encoded_event = event_encoder_->Encode(event); bool appended; size_t potential_new_size = - written_bytes_ + output_string->size() + event_stream.ByteSize(); + written_bytes_ + output_string->size() + encoded_event.length(); if (potential_new_size <= max_size_bytes_) { - event_stream.AppendToString(output_string); + *output_string += encoded_event; appended = true; } else { appended = false; } - // When the function returns, the original Event will be unchanged. - output_event->Swap(event); - return appended; } -void RtcEventLogImpl::LogToMemory(std::unique_ptr event) { +void RtcEventLogImpl::LogToMemory(std::unique_ptr event) { RTC_DCHECK_RUN_ON(&task_queue_); RTC_DCHECK(!file_->is_open()); - if (IsConfigEvent(*event.get())) { + if (event->IsConfigEvent()) { config_history_.push_back(std::move(event)); } else { history_.push_back(std::move(event)); @@ -735,10 +487,7 @@ void RtcEventLogImpl::StartLogFile() { // The timestamp used will correspond to when logging has started. The log // may contain events earlier than the LOG_START event. (In general, the // timestamps in the log are not monotonic.) - rtclog::Event start_event; - start_event.set_timestamp_us(rtc::TimeMicros()); - start_event.set_type(rtclog::Event::LOG_START); - bool appended = AppendEventToString(&start_event, &output_string); + bool appended = AppendEventToString(RtcEventLoggingStarted(), &output_string); // Serialize the config information for all old streams, including streams // which were already logged to previous files. @@ -746,12 +495,12 @@ void RtcEventLogImpl::StartLogFile() { if (!appended) { break; } - appended = AppendEventToString(event.get(), &output_string); + appended = AppendEventToString(*event, &output_string); } // Serialize the events in the event queue. while (appended && !history_.empty()) { - appended = AppendEventToString(history_.front().get(), &output_string); + appended = AppendEventToString(*history_.front(), &output_string); if (appended) { // Known issue - if writing to the file fails, these events will have // been lost. If we try to open a new file, these events will be missing @@ -775,15 +524,15 @@ void RtcEventLogImpl::StartLogFile() { } } -void RtcEventLogImpl::LogToFile(std::unique_ptr event) { +void RtcEventLogImpl::LogToFile(std::unique_ptr event) { RTC_DCHECK_RUN_ON(&task_queue_); RTC_DCHECK(file_->is_open()); ProtoString output_string; - bool appended = AppendEventToString(event.get(), &output_string); + bool appended = AppendEventToString(*event, &output_string); - if (IsConfigEvent(*event.get())) { + if (event->IsConfigEvent()) { config_history_.push_back(std::move(event)); } @@ -810,10 +559,7 @@ void RtcEventLogImpl::StopLogFile(int64_t stop_time) { ProtoString output_string; - rtclog::Event end_event; - end_event.set_timestamp_us(stop_time); - end_event.set_type(rtclog::Event::LOG_END); - bool appended = AppendEventToString(&end_event, &output_string); + bool appended = AppendEventToString(RtcEventLoggingStopped(), &output_string); if (appended) { if (!file_->Write(output_string.data(), output_string.size())) { @@ -836,9 +582,9 @@ void RtcEventLogImpl::StopLogFile(int64_t stop_time) { #endif // ENABLE_RTC_EVENT_LOG // RtcEventLog member functions. -std::unique_ptr RtcEventLog::Create() { +std::unique_ptr RtcEventLog::Create(EncodingType encoding_type) { #ifdef ENABLE_RTC_EVENT_LOG - // TODO(eladalon): Known issue - there's a race over |rtc_event_log_count|. + // TODO(eladalon): Known issue - there's a race over |rtc_event_log_count|. constexpr int kMaxLogCount = 5; int count = 1 + std::atomic_fetch_add(&rtc_event_log_count, 1); if (count > kMaxLogCount) { @@ -847,7 +593,8 @@ std::unique_ptr RtcEventLog::Create() { std::atomic_fetch_sub(&rtc_event_log_count, 1); return CreateNull(); } - return rtc::MakeUnique(); + auto encoder = CreateEncoder(encoding_type); + return rtc::MakeUnique(std::move(encoder)); #else return CreateNull(); #endif // ENABLE_RTC_EVENT_LOG diff --git a/logging/rtc_event_log/rtc_event_log.h b/logging/rtc_event_log/rtc_event_log.h index 076af8d7dc..88ba10e5cc 100644 --- a/logging/rtc_event_log/rtc_event_log.h +++ b/logging/rtc_event_log/rtc_event_log.h @@ -13,7 +13,6 @@ #include #include -#include #include "api/array_view.h" // TODO(eladalon): Get rid of this later in the CL-stack. @@ -22,6 +21,8 @@ // TODO(eladalon): This is here because of ProbeFailureReason; remove this // dependency along with the deprecated LogProbeResultFailure(). #include "logging/rtc_event_log/events/rtc_event_probe_result_failure.h" +// TODO(eladalon): Remove this in an upcoming CL, that will modularize the +// log output into its own class. #include "rtc_base/platform_file.h" namespace webrtc { @@ -33,26 +34,35 @@ struct StreamConfig; } // namespace rtclog class Clock; +// TODO(eladalon): The following may be removed when the deprecated methods +// are removed. struct AudioEncoderRuntimeConfig; class RtpPacketReceived; class RtpPacketToSend; - -enum class MediaType; enum class BandwidthUsage; - enum PacketDirection { kIncomingPacket = 0, kOutgoingPacket }; class RtcEventLog { public: + // TODO(eladalon): Two stages are upcoming. + // 1. Extend this to actually support the new encoding. + // 2. Get rid of the legacy encoding, allowing us to get rid of this enum. + enum class EncodingType { Legacy }; + virtual ~RtcEventLog() {} // Factory method to create an RtcEventLog object. - static std::unique_ptr Create(); + // TODO(eladalon): Get rid of the default value after internal projects fixed. + static std::unique_ptr Create( + EncodingType encoding_type = EncodingType::Legacy); // TODO(nisse): webrtc::Clock is deprecated. Delete this method and // above forward declaration of Clock when - // system_wrappers/include/clock.h is deleted. - static std::unique_ptr Create(const Clock* clock) { - return Create(); + // webrtc/system_wrappers/include/clock.h is deleted. + // TODO(eladalon): Get rid of the default value after internal projects fixed. + static std::unique_ptr Create( + const Clock* clock, + EncodingType encoding_type = EncodingType::Legacy) { + return Create(encoding_type); } // Create an RtcEventLog object that does nothing. @@ -85,19 +95,24 @@ class RtcEventLog { // which it would be permissible to read and/or modify it. virtual void StopLogging() = 0; + // Log an RTC event (the type of event is determined by the subclass). + virtual void Log(std::unique_ptr event) = 0; + // Logs configuration information for a video receive stream. - virtual void LogVideoReceiveStreamConfig( + RTC_DEPRECATED virtual void LogVideoReceiveStreamConfig( const rtclog::StreamConfig& config) = 0; // Logs configuration information for a video send stream. - virtual void LogVideoSendStreamConfig(const rtclog::StreamConfig& config) = 0; + RTC_DEPRECATED virtual void LogVideoSendStreamConfig( + const rtclog::StreamConfig& config) = 0; // Logs configuration information for an audio receive stream. - virtual void LogAudioReceiveStreamConfig( + RTC_DEPRECATED virtual void LogAudioReceiveStreamConfig( const rtclog::StreamConfig& config) = 0; // Logs configuration information for an audio send stream. - virtual void LogAudioSendStreamConfig(const rtclog::StreamConfig& config) = 0; + RTC_DEPRECATED virtual void LogAudioSendStreamConfig( + const rtclog::StreamConfig& config) = 0; RTC_DEPRECATED virtual void LogRtpHeader(PacketDirection direction, const uint8_t* header, @@ -110,51 +125,58 @@ class RtcEventLog { // Logs the header of an incoming RTP packet. |packet_length| // is the total length of the packet, including both header and payload. - virtual void LogIncomingRtpHeader(const RtpPacketReceived& packet) = 0; + RTC_DEPRECATED virtual void LogIncomingRtpHeader( + const RtpPacketReceived& packet) = 0; // Logs the header of an incoming RTP packet. |packet_length| // is the total length of the packet, including both header and payload. - virtual void LogOutgoingRtpHeader(const RtpPacketToSend& packet, - int probe_cluster_id) = 0; + RTC_DEPRECATED virtual void LogOutgoingRtpHeader( + const RtpPacketToSend& packet, + int probe_cluster_id) = 0; RTC_DEPRECATED virtual void LogRtcpPacket(PacketDirection direction, const uint8_t* header, size_t packet_length) {} // Logs an incoming RTCP packet. - virtual void LogIncomingRtcpPacket(rtc::ArrayView packet) = 0; + RTC_DEPRECATED virtual void LogIncomingRtcpPacket( + rtc::ArrayView packet) = 0; // Logs an outgoing RTCP packet. - virtual void LogOutgoingRtcpPacket(rtc::ArrayView packet) = 0; + RTC_DEPRECATED virtual void LogOutgoingRtcpPacket( + rtc::ArrayView packet) = 0; // Logs an audio playout event. - virtual void LogAudioPlayout(uint32_t ssrc) = 0; + RTC_DEPRECATED virtual void LogAudioPlayout(uint32_t ssrc) = 0; // Logs a bitrate update from the bandwidth estimator based on packet loss. - virtual void LogLossBasedBweUpdate(int32_t bitrate_bps, - uint8_t fraction_loss, - int32_t total_packets) = 0; + RTC_DEPRECATED virtual void LogLossBasedBweUpdate(int32_t bitrate_bps, + uint8_t fraction_loss, + int32_t total_packets) = 0; // Logs a bitrate update from the bandwidth estimator based on delay changes. - virtual void LogDelayBasedBweUpdate(int32_t bitrate_bps, - BandwidthUsage detector_state) = 0; + RTC_DEPRECATED virtual void LogDelayBasedBweUpdate( + int32_t bitrate_bps, + BandwidthUsage detector_state) = 0; // Logs audio encoder re-configuration driven by audio network adaptor. - virtual void LogAudioNetworkAdaptation( + RTC_DEPRECATED virtual void LogAudioNetworkAdaptation( const AudioEncoderRuntimeConfig& config) = 0; // Logs when a probe cluster is created. - virtual void LogProbeClusterCreated(int id, - int bitrate_bps, - int min_probes, - int min_bytes) = 0; + RTC_DEPRECATED virtual void LogProbeClusterCreated(int id, + int bitrate_bps, + int min_probes, + int min_bytes) = 0; // Logs the result of a successful probing attempt. - virtual void LogProbeResultSuccess(int id, int bitrate_bps) = 0; + RTC_DEPRECATED virtual void LogProbeResultSuccess(int id, + int bitrate_bps) = 0; // Logs the result of an unsuccessful probing attempt. - virtual void LogProbeResultFailure(int id, - ProbeFailureReason failure_reason) = 0; + RTC_DEPRECATED virtual void LogProbeResultFailure( + int id, + ProbeFailureReason failure_reason) = 0; }; // No-op implementation is used if flag is not set, or in tests. @@ -169,6 +191,7 @@ class RtcEventLogNullImpl : public RtcEventLog { return false; } void StopLogging() override {} + void Log(std::unique_ptr event) override {} void LogVideoReceiveStreamConfig( const rtclog::StreamConfig& config) override {} void LogVideoSendStreamConfig(const rtclog::StreamConfig& config) override {} diff --git a/logging/rtc_event_log/rtc_event_log_factory.cc b/logging/rtc_event_log/rtc_event_log_factory.cc index 80435d9d6f..566736c8b7 100644 --- a/logging/rtc_event_log/rtc_event_log_factory.cc +++ b/logging/rtc_event_log/rtc_event_log_factory.cc @@ -14,8 +14,9 @@ namespace webrtc { -std::unique_ptr RtcEventLogFactory::CreateRtcEventLog() { - return RtcEventLog::Create(); +std::unique_ptr RtcEventLogFactory::CreateRtcEventLog( + RtcEventLog::EncodingType encoding_type) { + return RtcEventLog::Create(encoding_type); } std::unique_ptr CreateRtcEventLogFactory() { diff --git a/logging/rtc_event_log/rtc_event_log_factory.h b/logging/rtc_event_log/rtc_event_log_factory.h index 0a38c66afb..1b75d66c10 100644 --- a/logging/rtc_event_log/rtc_event_log_factory.h +++ b/logging/rtc_event_log/rtc_event_log_factory.h @@ -21,7 +21,8 @@ class RtcEventLogFactory : public RtcEventLogFactoryInterface { public: ~RtcEventLogFactory() override {} - std::unique_ptr CreateRtcEventLog() override; + std::unique_ptr CreateRtcEventLog( + RtcEventLog::EncodingType encoding_type) override; }; std::unique_ptr CreateRtcEventLogFactory(); diff --git a/logging/rtc_event_log/rtc_event_log_factory_interface.h b/logging/rtc_event_log/rtc_event_log_factory_interface.h index ca5cbffec1..a28002d782 100644 --- a/logging/rtc_event_log/rtc_event_log_factory_interface.h +++ b/logging/rtc_event_log/rtc_event_log_factory_interface.h @@ -24,7 +24,8 @@ class RtcEventLogFactoryInterface { public: virtual ~RtcEventLogFactoryInterface() {} - virtual std::unique_ptr CreateRtcEventLog() = 0; + virtual std::unique_ptr CreateRtcEventLog( + RtcEventLog::EncodingType encoding_type) = 0; }; std::unique_ptr CreateRtcEventLogFactory(); diff --git a/logging/rtc_event_log/rtc_event_log_unittest.cc b/logging/rtc_event_log/rtc_event_log_unittest.cc index 629afbccba..d328dffd8e 100644 --- a/logging/rtc_event_log/rtc_event_log_unittest.cc +++ b/logging/rtc_event_log/rtc_event_log_unittest.cc @@ -16,6 +16,23 @@ #include #include "call/call.h" +#include "logging/rtc_event_log/events/rtc_event_audio_network_adaptation.h" +#include "logging/rtc_event_log/events/rtc_event_audio_playout.h" +#include "logging/rtc_event_log/events/rtc_event_audio_receive_stream_config.h" +#include "logging/rtc_event_log/events/rtc_event_audio_send_stream_config.h" +#include "logging/rtc_event_log/events/rtc_event_bwe_update_delay_based.h" +#include "logging/rtc_event_log/events/rtc_event_bwe_update_loss_based.h" +#include "logging/rtc_event_log/events/rtc_event_logging_started.h" +#include "logging/rtc_event_log/events/rtc_event_logging_stopped.h" +#include "logging/rtc_event_log/events/rtc_event_probe_cluster_created.h" +#include "logging/rtc_event_log/events/rtc_event_probe_result_failure.h" +#include "logging/rtc_event_log/events/rtc_event_probe_result_success.h" +#include "logging/rtc_event_log/events/rtc_event_rtcp_packet_incoming.h" +#include "logging/rtc_event_log/events/rtc_event_rtcp_packet_outgoing.h" +#include "logging/rtc_event_log/events/rtc_event_rtp_packet_incoming.h" +#include "logging/rtc_event_log/events/rtc_event_rtp_packet_outgoing.h" +#include "logging/rtc_event_log/events/rtc_event_video_receive_stream_config.h" +#include "logging/rtc_event_log/events/rtc_event_video_send_stream_config.h" #include "logging/rtc_event_log/rtc_event_log.h" #include "logging/rtc_event_log/rtc_event_log_parser.h" #include "logging/rtc_event_log/rtc_event_log_unittest_helper.h" @@ -397,7 +414,8 @@ void RtcEventLogSessionDescription::WriteSession() { // When log_dumper goes out of scope, it causes the log file to be flushed // to disk. - std::unique_ptr log_dumper(RtcEventLog::Create()); + std::unique_ptr log_dumper( + RtcEventLog::Create(RtcEventLog::EncodingType::Legacy)); size_t incoming_rtp_written = 0; size_t outgoing_rtp_written = 0; @@ -416,53 +434,57 @@ void RtcEventLogSessionDescription::WriteSession() { switch (event_types[i]) { case EventType::kIncomingRtp: RTC_CHECK(incoming_rtp_written < incoming_rtp_packets.size()); - log_dumper->LogIncomingRtpHeader( - incoming_rtp_packets[incoming_rtp_written++]); + log_dumper->Log(rtc::MakeUnique( + incoming_rtp_packets[incoming_rtp_written++])); break; - case EventType::kOutgoingRtp: + case EventType::kOutgoingRtp: { RTC_CHECK(outgoing_rtp_written < outgoing_rtp_packets.size()); - log_dumper->LogOutgoingRtpHeader( - outgoing_rtp_packets[outgoing_rtp_written++], - PacedPacketInfo::kNotAProbe); + constexpr int kNotAProbe = PacedPacketInfo::kNotAProbe; // Compiler... + log_dumper->Log(rtc::MakeUnique( + outgoing_rtp_packets[outgoing_rtp_written++], kNotAProbe)); break; + } case EventType::kIncomingRtcp: RTC_CHECK(incoming_rtcp_written < incoming_rtcp_packets.size()); - log_dumper->LogIncomingRtcpPacket( - incoming_rtcp_packets[incoming_rtcp_written++]); + log_dumper->Log(rtc::MakeUnique( + incoming_rtcp_packets[incoming_rtcp_written++])); break; case EventType::kOutgoingRtcp: RTC_CHECK(outgoing_rtcp_written < outgoing_rtcp_packets.size()); - log_dumper->LogOutgoingRtcpPacket( - outgoing_rtcp_packets[outgoing_rtcp_written++]); + log_dumper->Log(rtc::MakeUnique( + outgoing_rtcp_packets[outgoing_rtcp_written++])); break; case EventType::kAudioPlayout: RTC_CHECK(playouts_written < playout_ssrcs.size()); - log_dumper->LogAudioPlayout(playout_ssrcs[playouts_written++]); + log_dumper->Log(rtc::MakeUnique( + playout_ssrcs[playouts_written++])); break; case EventType::kBweLossUpdate: RTC_CHECK(bwe_loss_written < bwe_loss_updates.size()); - log_dumper->LogLossBasedBweUpdate( + log_dumper->Log(rtc::MakeUnique( bwe_loss_updates[bwe_loss_written].bitrate_bps, bwe_loss_updates[bwe_loss_written].fraction_loss, - bwe_loss_updates[bwe_loss_written].total_packets); + bwe_loss_updates[bwe_loss_written].total_packets)); bwe_loss_written++; break; case EventType::kBweDelayUpdate: RTC_CHECK(bwe_delay_written < bwe_delay_updates.size()); - log_dumper->LogDelayBasedBweUpdate( + log_dumper->Log(rtc::MakeUnique( bwe_delay_updates[bwe_delay_written].first, - bwe_delay_updates[bwe_delay_written].second); + bwe_delay_updates[bwe_delay_written].second)); bwe_delay_written++; break; case EventType::kVideoRecvConfig: RTC_CHECK(recv_configs_written < receiver_configs.size()); - log_dumper->LogVideoReceiveStreamConfig( - receiver_configs[recv_configs_written++]); + log_dumper->Log(rtc::MakeUnique( + rtc::MakeUnique( + receiver_configs[recv_configs_written++]))); break; case EventType::kVideoSendConfig: RTC_CHECK(send_configs_written < sender_configs.size()); - log_dumper->LogVideoSendStreamConfig( - sender_configs[send_configs_written++]); + log_dumper->Log(rtc::MakeUnique( + rtc::MakeUnique( + sender_configs[send_configs_written++]))); break; case EventType::kAudioRecvConfig: // Not implemented @@ -711,15 +733,16 @@ TEST(RtcEventLogTest, LogEventAndReadBack) { // Add RTP, start logging, add RTCP and then stop logging rtc::ScopedFakeClock fake_clock; fake_clock.SetTimeMicros(prng.Rand()); - std::unique_ptr log_dumper(RtcEventLog::Create()); + std::unique_ptr log_dumper( + RtcEventLog::Create(RtcEventLog::EncodingType::Legacy)); - log_dumper->LogIncomingRtpHeader(rtp_packet); + log_dumper->Log(rtc::MakeUnique(rtp_packet)); fake_clock.AdvanceTimeMicros(prng.Rand(1, 1000)); log_dumper->StartLogging(temp_filename, 10000000); fake_clock.AdvanceTimeMicros(prng.Rand(1, 1000)); - log_dumper->LogOutgoingRtcpPacket(rtcp_packet); + log_dumper->Log(rtc::MakeUnique(rtcp_packet)); fake_clock.AdvanceTimeMicros(prng.Rand(1, 1000)); log_dumper->StopLogging(); @@ -762,10 +785,12 @@ TEST(RtcEventLogTest, LogLossBasedBweUpdateAndReadBack) { // Start logging, add the packet loss event and then stop logging. rtc::ScopedFakeClock fake_clock; fake_clock.SetTimeMicros(prng.Rand()); - std::unique_ptr log_dumper(RtcEventLog::Create()); + std::unique_ptr log_dumper( + RtcEventLog::Create(RtcEventLog::EncodingType::Legacy)); log_dumper->StartLogging(temp_filename, 10000000); fake_clock.AdvanceTimeMicros(prng.Rand(1, 1000)); - log_dumper->LogLossBasedBweUpdate(bitrate, fraction_lost, total_packets); + log_dumper->Log(rtc::MakeUnique( + bitrate, fraction_lost, total_packets)); fake_clock.AdvanceTimeMicros(prng.Rand(1, 1000)); log_dumper->StopLogging(); @@ -802,14 +827,18 @@ TEST(RtcEventLogTest, LogDelayBasedBweUpdateAndReadBack) { // Start logging, add the packet delay events and then stop logging. rtc::ScopedFakeClock fake_clock; fake_clock.SetTimeMicros(prng.Rand()); - std::unique_ptr log_dumper(RtcEventLog::Create()); + std::unique_ptr log_dumper( + RtcEventLog::Create(RtcEventLog::EncodingType::Legacy)); log_dumper->StartLogging(temp_filename, 10000000); fake_clock.AdvanceTimeMicros(prng.Rand(1, 1000)); - log_dumper->LogDelayBasedBweUpdate(bitrate1, BandwidthUsage::kBwNormal); + log_dumper->Log(rtc::MakeUnique( + bitrate1, BandwidthUsage::kBwNormal)); fake_clock.AdvanceTimeMicros(prng.Rand(1, 1000)); - log_dumper->LogDelayBasedBweUpdate(bitrate2, BandwidthUsage::kBwOverusing); + log_dumper->Log(rtc::MakeUnique( + bitrate2, BandwidthUsage::kBwOverusing)); fake_clock.AdvanceTimeMicros(prng.Rand(1, 1000)); - log_dumper->LogDelayBasedBweUpdate(bitrate3, BandwidthUsage::kBwUnderusing); + log_dumper->Log(rtc::MakeUnique( + bitrate3, BandwidthUsage::kBwUnderusing)); fake_clock.AdvanceTimeMicros(prng.Rand(1, 1000)); log_dumper->StopLogging(); @@ -854,14 +883,18 @@ TEST(RtcEventLogTest, LogProbeClusterCreatedAndReadBack) { rtc::ScopedFakeClock fake_clock; fake_clock.SetTimeMicros(prng.Rand()); - std::unique_ptr log_dumper(RtcEventLog::Create()); + std::unique_ptr log_dumper( + RtcEventLog::Create(RtcEventLog::EncodingType::Legacy)); log_dumper->StartLogging(temp_filename, 10000000); - log_dumper->LogProbeClusterCreated(0, bitrate_bps0, min_probes0, min_bytes0); + log_dumper->Log(rtc::MakeUnique( + 0, bitrate_bps0, min_probes0, min_bytes0)); fake_clock.AdvanceTimeMicros(prng.Rand(1, 1000)); - log_dumper->LogProbeClusterCreated(1, bitrate_bps1, min_probes1, min_bytes1); + log_dumper->Log(rtc::MakeUnique( + 1, bitrate_bps1, min_probes1, min_bytes1)); fake_clock.AdvanceTimeMicros(prng.Rand(1, 1000)); - log_dumper->LogProbeClusterCreated(2, bitrate_bps2, min_probes2, min_bytes2); + log_dumper->Log(rtc::MakeUnique( + 2, bitrate_bps2, min_probes2, min_bytes2)); fake_clock.AdvanceTimeMicros(prng.Rand(1, 1000)); log_dumper->StopLogging(); @@ -900,14 +933,15 @@ TEST(RtcEventLogTest, LogProbeResultSuccessAndReadBack) { rtc::ScopedFakeClock fake_clock; fake_clock.SetTimeMicros(prng.Rand()); - std::unique_ptr log_dumper(RtcEventLog::Create()); + std::unique_ptr log_dumper( + RtcEventLog::Create(RtcEventLog::EncodingType::Legacy)); log_dumper->StartLogging(temp_filename, 10000000); - log_dumper->LogProbeResultSuccess(0, bitrate_bps0); + log_dumper->Log(rtc::MakeUnique(0, bitrate_bps0)); fake_clock.AdvanceTimeMicros(prng.Rand(1, 1000)); - log_dumper->LogProbeResultSuccess(1, bitrate_bps1); + log_dumper->Log(rtc::MakeUnique(1, bitrate_bps1)); fake_clock.AdvanceTimeMicros(prng.Rand(1, 1000)); - log_dumper->LogProbeResultSuccess(2, bitrate_bps2); + log_dumper->Log(rtc::MakeUnique(2, bitrate_bps2)); fake_clock.AdvanceTimeMicros(prng.Rand(1, 1000)); log_dumper->StopLogging(); @@ -942,16 +976,18 @@ TEST(RtcEventLogTest, LogProbeResultFailureAndReadBack) { rtc::ScopedFakeClock fake_clock; fake_clock.SetTimeMicros(prng.Rand()); - std::unique_ptr log_dumper(RtcEventLog::Create()); + std::unique_ptr log_dumper( + RtcEventLog::Create(RtcEventLog::EncodingType::Legacy)); log_dumper->StartLogging(temp_filename, 10000000); - log_dumper->LogProbeResultFailure( - 0, ProbeFailureReason::kInvalidSendReceiveInterval); + log_dumper->Log(rtc::MakeUnique( + 0, ProbeFailureReason::kInvalidSendReceiveInterval)); fake_clock.AdvanceTimeMicros(prng.Rand(1, 1000)); - log_dumper->LogProbeResultFailure( - 1, ProbeFailureReason::kInvalidSendReceiveRatio); + log_dumper->Log(rtc::MakeUnique( + 1, ProbeFailureReason::kInvalidSendReceiveRatio)); fake_clock.AdvanceTimeMicros(prng.Rand(1, 1000)); - log_dumper->LogProbeResultFailure(2, ProbeFailureReason::kTimeout); + log_dumper->Log(rtc::MakeUnique( + 2, ProbeFailureReason::kTimeout)); fake_clock.AdvanceTimeMicros(prng.Rand(1, 1000)); log_dumper->StopLogging(); @@ -1001,7 +1037,8 @@ class ConfigReadWriteTest { // Log a single config event and stop logging. rtc::ScopedFakeClock fake_clock; fake_clock.SetTimeMicros(prng.Rand()); - std::unique_ptr log_dumper(RtcEventLog::Create()); + std::unique_ptr log_dumper( + RtcEventLog::Create(RtcEventLog::EncodingType::Legacy)); log_dumper->StartLogging(temp_filename, 10000000); LogConfig(log_dumper.get()); @@ -1033,7 +1070,8 @@ class AudioReceiveConfigReadWriteTest : public ConfigReadWriteTest { GenerateAudioReceiveConfig(extensions, &config, &prng); } void LogConfig(RtcEventLog* event_log) override { - event_log->LogAudioReceiveStreamConfig(config); + event_log->Log(rtc::MakeUnique( + rtc::MakeUnique(config))); } void VerifyConfig(const ParsedRtcEventLog& parsed_log, size_t index) override { @@ -1050,7 +1088,8 @@ class AudioSendConfigReadWriteTest : public ConfigReadWriteTest { GenerateAudioSendConfig(extensions, &config, &prng); } void LogConfig(RtcEventLog* event_log) override { - event_log->LogAudioSendStreamConfig(config); + event_log->Log(rtc::MakeUnique( + rtc::MakeUnique(config))); } void VerifyConfig(const ParsedRtcEventLog& parsed_log, size_t index) override { @@ -1067,7 +1106,8 @@ class VideoReceiveConfigReadWriteTest : public ConfigReadWriteTest { GenerateVideoReceiveConfig(extensions, &config, &prng); } void LogConfig(RtcEventLog* event_log) override { - event_log->LogVideoReceiveStreamConfig(config); + event_log->Log(rtc::MakeUnique( + rtc::MakeUnique(config))); } void VerifyConfig(const ParsedRtcEventLog& parsed_log, size_t index) override { @@ -1084,7 +1124,8 @@ class VideoSendConfigReadWriteTest : public ConfigReadWriteTest { GenerateVideoSendConfig(extensions, &config, &prng); } void LogConfig(RtcEventLog* event_log) override { - event_log->LogVideoSendStreamConfig(config); + event_log->Log(rtc::MakeUnique( + rtc::MakeUnique(config))); } void VerifyConfig(const ParsedRtcEventLog& parsed_log, size_t index) override { @@ -1100,7 +1141,8 @@ class AudioNetworkAdaptationReadWriteTest : public ConfigReadWriteTest { GenerateAudioNetworkAdaptation(extensions, &config, &prng); } void LogConfig(RtcEventLog* event_log) override { - event_log->LogAudioNetworkAdaptation(config); + event_log->Log(rtc::MakeUnique( + rtc::MakeUnique(config))); } void VerifyConfig(const ParsedRtcEventLog& parsed_log, size_t index) override { diff --git a/modules/audio_coding/BUILD.gn b/modules/audio_coding/BUILD.gn index 0c4ee624cf..da055bb7d2 100644 --- a/modules/audio_coding/BUILD.gn +++ b/modules/audio_coding/BUILD.gn @@ -2178,6 +2178,7 @@ if (rtc_include_tests) { "../../api/audio_codecs:builtin_audio_encoder_factory", "../../common_audio", "../../common_audio:mock_common_audio", + "../../logging:rtc_event_log_api", "../../rtc_base:protobuf_utils", "../../rtc_base:rtc_base", "../../rtc_base:rtc_base_approved", diff --git a/modules/audio_coding/audio_network_adaptor/audio_network_adaptor_impl_unittest.cc b/modules/audio_coding/audio_network_adaptor/audio_network_adaptor_impl_unittest.cc index d297d27c88..1f0f71a543 100644 --- a/modules/audio_coding/audio_network_adaptor/audio_network_adaptor_impl_unittest.cc +++ b/modules/audio_coding/audio_network_adaptor/audio_network_adaptor_impl_unittest.cc @@ -11,6 +11,8 @@ #include #include +#include "logging/rtc_event_log/events/rtc_event.h" +#include "logging/rtc_event_log/events/rtc_event_audio_network_adaptation.h" #include "logging/rtc_event_log/mock/mock_rtc_event_log.h" #include "modules/audio_coding/audio_network_adaptor/audio_network_adaptor_impl.h" #include "modules/audio_coding/audio_network_adaptor/mock/mock_controller.h" @@ -44,6 +46,14 @@ MATCHER_P(NetworkMetricsIs, metric, "") { metric.uplink_recoverable_packet_loss_fraction; } +MATCHER_P(IsRtcEventAnaConfigEqualTo, config, "") { + if (arg->GetType() != RtcEvent::Type::AudioNetworkAdaptation) { + return false; + } + auto ana_event = static_cast(arg); + return *ana_event->config_ == config; +} + MATCHER_P(EncoderRuntimeConfigIs, config, "") { return arg.bitrate_bps == config.bitrate_bps && arg.frame_length_ms == config.frame_length_ms && @@ -271,8 +281,7 @@ TEST(AudioNetworkAdaptorImplTest, LogRuntimeConfigOnGetEncoderRuntimeConfig) { EXPECT_CALL(*states.mock_controllers[0], MakeDecision(_)) .WillOnce(SetArgPointee<0>(config)); - EXPECT_CALL(*states.event_log, - LogAudioNetworkAdaptation(EncoderRuntimeConfigIs(config))) + EXPECT_CALL(*states.event_log, LogProxy(IsRtcEventAnaConfigEqualTo(config))) .Times(1); states.audio_network_adaptor->GetEncoderRuntimeConfig(); } diff --git a/modules/audio_coding/audio_network_adaptor/event_log_writer.cc b/modules/audio_coding/audio_network_adaptor/event_log_writer.cc index a070b77baa..9cdbc54c67 100644 --- a/modules/audio_coding/audio_network_adaptor/event_log_writer.cc +++ b/modules/audio_coding/audio_network_adaptor/event_log_writer.cc @@ -9,10 +9,13 @@ */ #include + #include +#include "logging/rtc_event_log/events/rtc_event_audio_network_adaptation.h" #include "logging/rtc_event_log/rtc_event_log.h" #include "modules/audio_coding/audio_network_adaptor/event_log_writer.h" +#include "rtc_base/ptr_util.h" namespace webrtc { @@ -60,7 +63,9 @@ void EventLogWriter::MaybeLogEncoderConfig( } void EventLogWriter::LogEncoderConfig(const AudioEncoderRuntimeConfig& config) { - event_log_->LogAudioNetworkAdaptation(config); + auto config_copy = rtc::MakeUnique(config); + event_log_->Log( + rtc::MakeUnique(std::move(config_copy))); last_logged_config_ = config; } diff --git a/modules/audio_coding/audio_network_adaptor/event_log_writer_unittest.cc b/modules/audio_coding/audio_network_adaptor/event_log_writer_unittest.cc index 38537054bd..ee8249a1ed 100644 --- a/modules/audio_coding/audio_network_adaptor/event_log_writer_unittest.cc +++ b/modules/audio_coding/audio_network_adaptor/event_log_writer_unittest.cc @@ -10,6 +10,7 @@ #include +#include "logging/rtc_event_log/events/rtc_event_audio_network_adaptation.h" #include "logging/rtc_event_log/mock/mock_rtc_event_log.h" #include "modules/audio_coding/audio_network_adaptor/event_log_writer.h" #include "test/gtest.h" @@ -30,14 +31,12 @@ constexpr bool kEnableDtx = true; constexpr float kPacketLossFraction = 0.05f; constexpr size_t kNumChannels = 1; -MATCHER_P(EncoderRuntimeConfigIs, config, "") { - return arg.bitrate_bps == config.bitrate_bps && - arg.frame_length_ms == config.frame_length_ms && - arg.uplink_packet_loss_fraction == - config.uplink_packet_loss_fraction && - arg.enable_fec == config.enable_fec && - arg.enable_dtx == config.enable_dtx && - arg.num_channels == config.num_channels; +MATCHER_P(IsRtcEventAnaConfigEqualTo, config, "") { + if (arg->GetType() != RtcEvent::Type::AudioNetworkAdaptation) { + return false; + } + auto ana_event = static_cast(arg); + return *ana_event->config_ == config; } struct EventLogWriterStates { @@ -65,18 +64,16 @@ EventLogWriterStates CreateEventLogWriter() { TEST(EventLogWriterTest, FirstConfigIsLogged) { auto state = CreateEventLogWriter(); - EXPECT_CALL( - *state.event_log, - LogAudioNetworkAdaptation(EncoderRuntimeConfigIs(state.runtime_config))) + EXPECT_CALL(*state.event_log, + LogProxy(IsRtcEventAnaConfigEqualTo(state.runtime_config))) .Times(1); state.event_log_writer->MaybeLogEncoderConfig(state.runtime_config); } TEST(EventLogWriterTest, SameConfigIsNotLogged) { auto state = CreateEventLogWriter(); - EXPECT_CALL( - *state.event_log, - LogAudioNetworkAdaptation(EncoderRuntimeConfigIs(state.runtime_config))) + EXPECT_CALL(*state.event_log, + LogProxy(IsRtcEventAnaConfigEqualTo(state.runtime_config))) .Times(1); state.event_log_writer->MaybeLogEncoderConfig(state.runtime_config); state.event_log_writer->MaybeLogEncoderConfig(state.runtime_config); @@ -84,73 +81,64 @@ TEST(EventLogWriterTest, SameConfigIsNotLogged) { TEST(EventLogWriterTest, LogFecStateChange) { auto state = CreateEventLogWriter(); - EXPECT_CALL( - *state.event_log, - LogAudioNetworkAdaptation(EncoderRuntimeConfigIs(state.runtime_config))) + EXPECT_CALL(*state.event_log, + LogProxy(IsRtcEventAnaConfigEqualTo(state.runtime_config))) .Times(1); state.event_log_writer->MaybeLogEncoderConfig(state.runtime_config); state.runtime_config.enable_fec = rtc::Optional(!kEnableFec); - EXPECT_CALL( - *state.event_log, - LogAudioNetworkAdaptation(EncoderRuntimeConfigIs(state.runtime_config))) + EXPECT_CALL(*state.event_log, + LogProxy(IsRtcEventAnaConfigEqualTo(state.runtime_config))) .Times(1); state.event_log_writer->MaybeLogEncoderConfig(state.runtime_config); } TEST(EventLogWriterTest, LogDtxStateChange) { auto state = CreateEventLogWriter(); - EXPECT_CALL( - *state.event_log, - LogAudioNetworkAdaptation(EncoderRuntimeConfigIs(state.runtime_config))) + EXPECT_CALL(*state.event_log, + LogProxy(IsRtcEventAnaConfigEqualTo(state.runtime_config))) .Times(1); state.event_log_writer->MaybeLogEncoderConfig(state.runtime_config); state.runtime_config.enable_dtx = rtc::Optional(!kEnableDtx); - EXPECT_CALL( - *state.event_log, - LogAudioNetworkAdaptation(EncoderRuntimeConfigIs(state.runtime_config))) + EXPECT_CALL(*state.event_log, + LogProxy(IsRtcEventAnaConfigEqualTo(state.runtime_config))) .Times(1); state.event_log_writer->MaybeLogEncoderConfig(state.runtime_config); } TEST(EventLogWriterTest, LogChannelChange) { auto state = CreateEventLogWriter(); - EXPECT_CALL( - *state.event_log, - LogAudioNetworkAdaptation(EncoderRuntimeConfigIs(state.runtime_config))) + EXPECT_CALL(*state.event_log, + LogProxy(IsRtcEventAnaConfigEqualTo(state.runtime_config))) .Times(1); state.event_log_writer->MaybeLogEncoderConfig(state.runtime_config); state.runtime_config.num_channels = rtc::Optional(kNumChannels + 1); - EXPECT_CALL( - *state.event_log, - LogAudioNetworkAdaptation(EncoderRuntimeConfigIs(state.runtime_config))) + EXPECT_CALL(*state.event_log, + LogProxy(IsRtcEventAnaConfigEqualTo(state.runtime_config))) .Times(1); state.event_log_writer->MaybeLogEncoderConfig(state.runtime_config); } TEST(EventLogWriterTest, LogFrameLengthChange) { auto state = CreateEventLogWriter(); - EXPECT_CALL( - *state.event_log, - LogAudioNetworkAdaptation(EncoderRuntimeConfigIs(state.runtime_config))) + EXPECT_CALL(*state.event_log, + LogProxy(IsRtcEventAnaConfigEqualTo(state.runtime_config))) .Times(1); state.event_log_writer->MaybeLogEncoderConfig(state.runtime_config); state.runtime_config.frame_length_ms = rtc::Optional(20); - EXPECT_CALL( - *state.event_log, - LogAudioNetworkAdaptation(EncoderRuntimeConfigIs(state.runtime_config))) + EXPECT_CALL(*state.event_log, + LogProxy(IsRtcEventAnaConfigEqualTo(state.runtime_config))) .Times(1); state.event_log_writer->MaybeLogEncoderConfig(state.runtime_config); } TEST(EventLogWriterTest, DoNotLogSmallBitrateChange) { auto state = CreateEventLogWriter(); - EXPECT_CALL( - *state.event_log, - LogAudioNetworkAdaptation(EncoderRuntimeConfigIs(state.runtime_config))) + EXPECT_CALL(*state.event_log, + LogProxy(IsRtcEventAnaConfigEqualTo(state.runtime_config))) .Times(1); state.event_log_writer->MaybeLogEncoderConfig(state.runtime_config); state.runtime_config.bitrate_bps = @@ -160,9 +148,8 @@ TEST(EventLogWriterTest, DoNotLogSmallBitrateChange) { TEST(EventLogWriterTest, LogLargeBitrateChange) { auto state = CreateEventLogWriter(); - EXPECT_CALL( - *state.event_log, - LogAudioNetworkAdaptation(EncoderRuntimeConfigIs(state.runtime_config))) + EXPECT_CALL(*state.event_log, + LogProxy(IsRtcEventAnaConfigEqualTo(state.runtime_config))) .Times(1); state.event_log_writer->MaybeLogEncoderConfig(state.runtime_config); // At high bitrate, the min fraction rule requires a larger change than the @@ -171,9 +158,8 @@ TEST(EventLogWriterTest, LogLargeBitrateChange) { kMinBitrateChangeBps); state.runtime_config.bitrate_bps = rtc::Optional(kHighBitrateBps + kMinBitrateChangeBps); - EXPECT_CALL( - *state.event_log, - LogAudioNetworkAdaptation(EncoderRuntimeConfigIs(state.runtime_config))) + EXPECT_CALL(*state.event_log, + LogProxy(IsRtcEventAnaConfigEqualTo(state.runtime_config))) .Times(1); state.event_log_writer->MaybeLogEncoderConfig(state.runtime_config); } @@ -181,27 +167,24 @@ TEST(EventLogWriterTest, LogLargeBitrateChange) { TEST(EventLogWriterTest, LogMinBitrateChangeFractionOnLowBitrateChange) { auto state = CreateEventLogWriter(); state.runtime_config.bitrate_bps = rtc::Optional(kLowBitrateBps); - EXPECT_CALL( - *state.event_log, - LogAudioNetworkAdaptation(EncoderRuntimeConfigIs(state.runtime_config))) + EXPECT_CALL(*state.event_log, + LogProxy(IsRtcEventAnaConfigEqualTo(state.runtime_config))) .Times(1); state.event_log_writer->MaybeLogEncoderConfig(state.runtime_config); // At high bitrate, the min change rule requires a larger change than the min // fraction rule. We make sure that the min fraction rule applies. state.runtime_config.bitrate_bps = rtc::Optional( kLowBitrateBps + kLowBitrateBps * kMinBitrateChangeFraction); - EXPECT_CALL( - *state.event_log, - LogAudioNetworkAdaptation(EncoderRuntimeConfigIs(state.runtime_config))) + EXPECT_CALL(*state.event_log, + LogProxy(IsRtcEventAnaConfigEqualTo(state.runtime_config))) .Times(1); state.event_log_writer->MaybeLogEncoderConfig(state.runtime_config); } TEST(EventLogWriterTest, DoNotLogSmallPacketLossFractionChange) { auto state = CreateEventLogWriter(); - EXPECT_CALL( - *state.event_log, - LogAudioNetworkAdaptation(EncoderRuntimeConfigIs(state.runtime_config))) + EXPECT_CALL(*state.event_log, + LogProxy(IsRtcEventAnaConfigEqualTo(state.runtime_config))) .Times(1); state.event_log_writer->MaybeLogEncoderConfig(state.runtime_config); state.runtime_config.uplink_packet_loss_fraction = rtc::Optional( @@ -212,49 +195,43 @@ TEST(EventLogWriterTest, DoNotLogSmallPacketLossFractionChange) { TEST(EventLogWriterTest, LogLargePacketLossFractionChange) { auto state = CreateEventLogWriter(); - EXPECT_CALL( - *state.event_log, - LogAudioNetworkAdaptation(EncoderRuntimeConfigIs(state.runtime_config))) + EXPECT_CALL(*state.event_log, + LogProxy(IsRtcEventAnaConfigEqualTo(state.runtime_config))) .Times(1); state.event_log_writer->MaybeLogEncoderConfig(state.runtime_config); state.runtime_config.uplink_packet_loss_fraction = rtc::Optional( kPacketLossFraction + kMinPacketLossChangeFraction * kPacketLossFraction); - EXPECT_CALL( - *state.event_log, - LogAudioNetworkAdaptation(EncoderRuntimeConfigIs(state.runtime_config))) + EXPECT_CALL(*state.event_log, + LogProxy(IsRtcEventAnaConfigEqualTo(state.runtime_config))) .Times(1); state.event_log_writer->MaybeLogEncoderConfig(state.runtime_config); } TEST(EventLogWriterTest, LogJustOnceOnMultipleChanges) { auto state = CreateEventLogWriter(); - EXPECT_CALL( - *state.event_log, - LogAudioNetworkAdaptation(EncoderRuntimeConfigIs(state.runtime_config))) + EXPECT_CALL(*state.event_log, + LogProxy(IsRtcEventAnaConfigEqualTo(state.runtime_config))) .Times(1); state.event_log_writer->MaybeLogEncoderConfig(state.runtime_config); state.runtime_config.uplink_packet_loss_fraction = rtc::Optional( kPacketLossFraction + kMinPacketLossChangeFraction * kPacketLossFraction); state.runtime_config.frame_length_ms = rtc::Optional(20); - EXPECT_CALL( - *state.event_log, - LogAudioNetworkAdaptation(EncoderRuntimeConfigIs(state.runtime_config))) + EXPECT_CALL(*state.event_log, + LogProxy(IsRtcEventAnaConfigEqualTo(state.runtime_config))) .Times(1); state.event_log_writer->MaybeLogEncoderConfig(state.runtime_config); } TEST(EventLogWriterTest, LogAfterGradualChange) { auto state = CreateEventLogWriter(); - EXPECT_CALL( - *state.event_log, - LogAudioNetworkAdaptation(EncoderRuntimeConfigIs(state.runtime_config))) + EXPECT_CALL(*state.event_log, + LogProxy(IsRtcEventAnaConfigEqualTo(state.runtime_config))) .Times(1); state.event_log_writer->MaybeLogEncoderConfig(state.runtime_config); state.runtime_config.bitrate_bps = rtc::Optional(kHighBitrateBps + kMinBitrateChangeBps); - EXPECT_CALL( - *state.event_log, - LogAudioNetworkAdaptation(EncoderRuntimeConfigIs(state.runtime_config))) + EXPECT_CALL(*state.event_log, + LogProxy(IsRtcEventAnaConfigEqualTo(state.runtime_config))) .Times(1); for (int bitrate_bps = kHighBitrateBps; bitrate_bps <= kHighBitrateBps + kMinBitrateChangeBps; bitrate_bps++) { diff --git a/modules/audio_coding/audio_network_adaptor/include/audio_network_adaptor_config.h b/modules/audio_coding/audio_network_adaptor/include/audio_network_adaptor_config.h index cab8bae2c7..874fc97eb2 100644 --- a/modules/audio_coding/audio_network_adaptor/include/audio_network_adaptor_config.h +++ b/modules/audio_coding/audio_network_adaptor/include/audio_network_adaptor_config.h @@ -19,11 +19,8 @@ struct AudioEncoderRuntimeConfig { AudioEncoderRuntimeConfig(); AudioEncoderRuntimeConfig(const AudioEncoderRuntimeConfig& other); ~AudioEncoderRuntimeConfig(); - AudioEncoderRuntimeConfig& operator=(const AudioEncoderRuntimeConfig& other); - bool operator==(const AudioEncoderRuntimeConfig& other) const; - rtc::Optional bitrate_bps; rtc::Optional frame_length_ms; // Note: This is what we tell the encoder. It doesn't have to reflect diff --git a/modules/bitrate_controller/BUILD.gn b/modules/bitrate_controller/BUILD.gn index 4ebf04c8f6..2f8dd15f22 100644 --- a/modules/bitrate_controller/BUILD.gn +++ b/modules/bitrate_controller/BUILD.gn @@ -59,6 +59,7 @@ if (rtc_include_tests) { ] deps = [ ":bitrate_controller", + "../../logging:rtc_event_log_api", "../../test:field_trial", "../../test:test_support", "../pacing:mock_paced_sender", diff --git a/modules/bitrate_controller/send_side_bandwidth_estimation.cc b/modules/bitrate_controller/send_side_bandwidth_estimation.cc index 5ce7a5ca8a..02d75959a9 100644 --- a/modules/bitrate_controller/send_side_bandwidth_estimation.cc +++ b/modules/bitrate_controller/send_side_bandwidth_estimation.cc @@ -15,10 +15,12 @@ #include #include +#include "logging/rtc_event_log/events/rtc_event_bwe_update_loss_based.h" #include "logging/rtc_event_log/rtc_event_log.h" #include "modules/remote_bitrate_estimator/include/bwe_defines.h" #include "rtc_base/checks.h" #include "rtc_base/logging.h" +#include "rtc_base/ptr_util.h" #include "system_wrappers/include/field_trial.h" #include "system_wrappers/include/metrics.h" @@ -412,8 +414,9 @@ void SendSideBandwidthEstimation::CapBitrateToThresholds(int64_t now_ms, if (bitrate_bps != current_bitrate_bps_ || last_fraction_loss_ != last_logged_fraction_loss_ || now_ms - last_rtc_event_log_ms_ > kRtcEventLogPeriodMs) { - event_log_->LogLossBasedBweUpdate(bitrate_bps, last_fraction_loss_, - expected_packets_since_last_loss_update_); + event_log_->Log(rtc::MakeUnique( + bitrate_bps, last_fraction_loss_, + expected_packets_since_last_loss_update_)); last_logged_fraction_loss_ = last_fraction_loss_; last_rtc_event_log_ms_ = now_ms; } diff --git a/modules/bitrate_controller/send_side_bandwidth_estimation_unittest.cc b/modules/bitrate_controller/send_side_bandwidth_estimation_unittest.cc index e49d861215..f2791cee4f 100644 --- a/modules/bitrate_controller/send_side_bandwidth_estimation_unittest.cc +++ b/modules/bitrate_controller/send_side_bandwidth_estimation_unittest.cc @@ -11,12 +11,29 @@ #include #include +#include "logging/rtc_event_log/events/rtc_event_bwe_update_loss_based.h" #include "logging/rtc_event_log/mock/mock_rtc_event_log.h" #include "modules/bitrate_controller/send_side_bandwidth_estimation.h" #include "test/gtest.h" namespace webrtc { +MATCHER(LossBasedBweUpdateWithBitrateOnly, "") { + if (arg->GetType() != RtcEvent::Type::BweUpdateLossBased) { + return false; + } + auto bwe_event = static_cast(arg); + return bwe_event->bitrate_bps_ > 0 && bwe_event->fraction_loss_ == 0; +} + +MATCHER(LossBasedBweUpdateWithBitrateAndLossFraction, "") { + if (arg->GetType() != RtcEvent::Type::BweUpdateLossBased) { + return false; + } + auto bwe_event = static_cast(arg); + return bwe_event->bitrate_bps_ > 0 && bwe_event->fraction_loss_ > 0; +} + void TestProbing(bool use_delay_based) { MockRtcEventLog event_log; SendSideBandwidthEstimation bwe(&event_log); @@ -65,9 +82,10 @@ TEST(SendSideBweTest, InitialDelayBasedBweWithProbing) { TEST(SendSideBweTest, DoesntReapplyBitrateDecreaseWithoutFollowingRemb) { MockRtcEventLog event_log; - EXPECT_CALL(event_log, LogLossBasedBweUpdate(testing::Gt(0), 0, 0)).Times(1); + EXPECT_CALL(event_log, LogProxy(LossBasedBweUpdateWithBitrateOnly())) + .Times(1); EXPECT_CALL(event_log, - LogLossBasedBweUpdate(testing::Gt(0), testing::Gt(0), 0)) + LogProxy(LossBasedBweUpdateWithBitrateAndLossFraction())) .Times(2); SendSideBandwidthEstimation bwe(&event_log); static const int kMinBitrateBps = 100000; diff --git a/modules/congestion_controller/delay_based_bwe.cc b/modules/congestion_controller/delay_based_bwe.cc index d269be1cae..fbe8dcced3 100644 --- a/modules/congestion_controller/delay_based_bwe.cc +++ b/modules/congestion_controller/delay_based_bwe.cc @@ -14,6 +14,7 @@ #include #include +#include "logging/rtc_event_log/events/rtc_event_bwe_update_delay_based.h" #include "logging/rtc_event_log/rtc_event_log.h" #include "modules/pacing/paced_sender.h" #include "modules/remote_bitrate_estimator/include/remote_bitrate_estimator.h" @@ -21,6 +22,7 @@ #include "rtc_base/checks.h" #include "rtc_base/constructormagic.h" #include "rtc_base/logging.h" +#include "rtc_base/ptr_util.h" #include "rtc_base/thread_annotations.h" #include "system_wrappers/include/field_trial.h" #include "system_wrappers/include/metrics.h" @@ -256,8 +258,10 @@ DelayBasedBwe::Result DelayBasedBwe::MaybeUpdateEstimate( BWE_TEST_LOGGING_PLOT(1, "target_bitrate_bps", now_ms, bitrate_bps); - if (event_log_) - event_log_->LogDelayBasedBweUpdate(bitrate_bps, detector_.State()); + if (event_log_) { + event_log_->Log(rtc::MakeUnique( + bitrate_bps, detector_.State())); + } prev_bitrate_ = bitrate_bps; prev_state_ = detector_.State(); diff --git a/modules/congestion_controller/probe_bitrate_estimator.cc b/modules/congestion_controller/probe_bitrate_estimator.cc index e83d1e08cd..0c1e23f9ee 100644 --- a/modules/congestion_controller/probe_bitrate_estimator.cc +++ b/modules/congestion_controller/probe_bitrate_estimator.cc @@ -12,9 +12,12 @@ #include +#include "logging/rtc_event_log/events/rtc_event_probe_result_failure.h" +#include "logging/rtc_event_log/events/rtc_event_probe_result_success.h" #include "logging/rtc_event_log/rtc_event_log.h" #include "rtc_base/checks.h" #include "rtc_base/logging.h" +#include "rtc_base/ptr_util.h" namespace { // The minumum number of probes we need to receive feedback about in percent @@ -103,8 +106,8 @@ int ProbeBitrateEstimator::HandleProbeAndEstimateBitrate( << "] [send interval: " << send_interval_ms << " ms]" << " [receive interval: " << receive_interval_ms << " ms]"; if (event_log_) { - event_log_->LogProbeResultFailure( - cluster_id, ProbeFailureReason::kInvalidSendReceiveInterval); + event_log_->Log(rtc::MakeUnique( + cluster_id, ProbeFailureReason::kInvalidSendReceiveInterval)); } return -1; } @@ -134,9 +137,10 @@ int ProbeBitrateEstimator::HandleProbeAndEstimateBitrate( << " [ratio: " << receive_bps / 1000 << " / " << send_bps / 1000 << " = " << ratio << " > kMaxValidRatio (" << kMaxValidRatio << ")]"; - if (event_log_) - event_log_->LogProbeResultFailure( - cluster_id, ProbeFailureReason::kInvalidSendReceiveRatio); + if (event_log_) { + event_log_->Log(rtc::MakeUnique( + cluster_id, ProbeFailureReason::kInvalidSendReceiveRatio)); + } return -1; } LOG(LS_INFO) << "Probing successful" @@ -155,8 +159,10 @@ int ProbeBitrateEstimator::HandleProbeAndEstimateBitrate( RTC_DCHECK_GT(send_bps, receive_bps); res = kTargetUtilizationFraction * receive_bps; } - if (event_log_) - event_log_->LogProbeResultSuccess(cluster_id, res); + if (event_log_) { + event_log_->Log( + rtc::MakeUnique(cluster_id, res)); + } estimated_bitrate_bps_ = rtc::Optional(res); return *estimated_bitrate_bps_; } diff --git a/modules/pacing/bitrate_prober.cc b/modules/pacing/bitrate_prober.cc index c25666669c..08c000dfdb 100644 --- a/modules/pacing/bitrate_prober.cc +++ b/modules/pacing/bitrate_prober.cc @@ -12,10 +12,12 @@ #include +#include "logging/rtc_event_log/events/rtc_event_probe_cluster_created.h" #include "logging/rtc_event_log/rtc_event_log.h" #include "modules/pacing/paced_sender.h" #include "rtc_base/checks.h" #include "rtc_base/logging.h" +#include "rtc_base/ptr_util.h" namespace webrtc { @@ -101,10 +103,10 @@ void BitrateProber::CreateProbeCluster(int bitrate_bps, int64_t now_ms) { cluster.pace_info.probe_cluster_id = next_cluster_id_++; clusters_.push(cluster); if (event_log_) - event_log_->LogProbeClusterCreated( + event_log_->Log(rtc::MakeUnique( cluster.pace_info.probe_cluster_id, cluster.pace_info.send_bitrate_bps, cluster.pace_info.probe_cluster_min_probes, - cluster.pace_info.probe_cluster_min_bytes); + cluster.pace_info.probe_cluster_min_bytes)); LOG(LS_INFO) << "Probe cluster (bitrate:min bytes:min packets): (" << cluster.pace_info.send_bitrate_bps << ":" diff --git a/modules/rtp_rtcp/BUILD.gn b/modules/rtp_rtcp/BUILD.gn index 122175a773..cc2361243a 100644 --- a/modules/rtp_rtcp/BUILD.gn +++ b/modules/rtp_rtcp/BUILD.gn @@ -373,6 +373,7 @@ if (rtc_include_tests) { "../../api:transport_api", "../../call:rtp_receiver", "../../common_video:common_video", + "../../logging:rtc_event_log_api", "../../rtc_base:rtc_base_approved", "../../system_wrappers:system_wrappers", "../../test:field_trial", diff --git a/modules/rtp_rtcp/source/rtcp_sender.cc b/modules/rtp_rtcp/source/rtcp_sender.cc index c7e75b67e7..d79e199e8c 100644 --- a/modules/rtp_rtcp/source/rtcp_sender.cc +++ b/modules/rtp_rtcp/source/rtcp_sender.cc @@ -15,6 +15,7 @@ #include #include "common_types.h" // NOLINT(build/include) +#include "logging/rtc_event_log/events/rtc_event_rtcp_packet_outgoing.h" #include "logging/rtc_event_log/rtc_event_log.h" #include "modules/rtp_rtcp/source/rtcp_packet/app.h" #include "modules/rtp_rtcp/source/rtcp_packet/bye.h" @@ -36,6 +37,7 @@ #include "rtc_base/checks.h" #include "rtc_base/constructormagic.h" #include "rtc_base/logging.h" +#include "rtc_base/ptr_util.h" #include "rtc_base/trace_event.h" namespace webrtc { @@ -99,8 +101,8 @@ class PacketContainer : public rtcp::CompoundPacket, if (transport_->SendRtcp(data, length)) { bytes_sent_ += length; if (event_log_) { - event_log_->LogOutgoingRtcpPacket( - rtc::ArrayView(data, length)); + event_log_->Log(rtc::MakeUnique( + rtc::ArrayView(data, length))); } } } @@ -963,8 +965,8 @@ bool RTCPSender::SendFeedbackPacket(const rtcp::TransportFeedback& packet) { void OnPacketReady(uint8_t* data, size_t length) override { if (transport_->SendRtcp(data, length)) { if (event_log_) { - event_log_->LogOutgoingRtcpPacket( - rtc::ArrayView(data, length)); + event_log_->Log(rtc::MakeUnique( + rtc::ArrayView(data, length))); } } else { send_failure_ = true; diff --git a/modules/rtp_rtcp/source/rtp_sender.cc b/modules/rtp_rtcp/source/rtp_sender.cc index 34af1cbcb0..ad9d65118b 100644 --- a/modules/rtp_rtcp/source/rtp_sender.cc +++ b/modules/rtp_rtcp/source/rtp_sender.cc @@ -13,6 +13,7 @@ #include #include +#include "logging/rtc_event_log/events/rtc_event_rtp_packet_outgoing.h" #include "logging/rtc_event_log/rtc_event_log.h" #include "modules/remote_bitrate_estimator/test/bwe_test_logging.h" #include "modules/rtp_rtcp/include/rtp_cvo.h" @@ -26,6 +27,7 @@ #include "rtc_base/arraysize.h" #include "rtc_base/checks.h" #include "rtc_base/logging.h" +#include "rtc_base/ptr_util.h" #include "rtc_base/rate_limiter.h" #include "rtc_base/safe_minmax.h" #include "rtc_base/timeutils.h" @@ -644,7 +646,8 @@ bool RTPSender::SendPacketToNetwork(const RtpPacketToSend& packet, ? static_cast(packet.size()) : -1; if (event_log_ && bytes_sent > 0) { - event_log_->LogOutgoingRtpHeader(packet, pacing_info.probe_cluster_id); + event_log_->Log(rtc::MakeUnique( + packet, pacing_info.probe_cluster_id)); } } TRACE_EVENT_INSTANT2(TRACE_DISABLED_BY_DEFAULT("webrtc_rtp"), diff --git a/modules/rtp_rtcp/source/rtp_sender_unittest.cc b/modules/rtp_rtcp/source/rtp_sender_unittest.cc index e40406cb3b..db760ecf7c 100644 --- a/modules/rtp_rtcp/source/rtp_sender_unittest.cc +++ b/modules/rtp_rtcp/source/rtp_sender_unittest.cc @@ -12,6 +12,7 @@ #include #include "api/video/video_timing.h" +#include "logging/rtc_event_log/events/rtc_event.h" #include "logging/rtc_event_log/mock/mock_rtc_event_log.h" #include "modules/rtp_rtcp/include/rtp_cvo.h" #include "modules/rtp_rtcp/include/rtp_header_extension_map.h" @@ -105,6 +106,10 @@ class LoopbackTransportTest : public webrtc::Transport { RtpHeaderExtensionMap receivers_extensions_; }; +MATCHER_P(SameRtcEventTypeAs, value, "") { + return value == arg->GetType(); +} + } // namespace class MockRtpPacketSender : public RtpPacketSender { @@ -530,7 +535,8 @@ TEST_P(RtpSenderTestWithoutPacer, WritesTimestampToTimingExtension) { TEST_P(RtpSenderTest, TrafficSmoothingWithExtensions) { EXPECT_CALL(mock_paced_sender_, InsertPacket(RtpPacketSender::kNormalPriority, kSsrc, kSeqNum, _, _, _)); - EXPECT_CALL(mock_rtc_event_log_, LogOutgoingRtpHeader(_, _)); + EXPECT_CALL(mock_rtc_event_log_, + LogProxy(SameRtcEventTypeAs(RtcEvent::Type::RtpPacketOutgoing))); rtp_sender_->SetStorePacketsStatus(true, 10); EXPECT_EQ(0, rtp_sender_->RegisterRtpHeaderExtension( @@ -574,7 +580,8 @@ TEST_P(RtpSenderTest, TrafficSmoothingWithExtensions) { TEST_P(RtpSenderTest, TrafficSmoothingRetransmits) { EXPECT_CALL(mock_paced_sender_, InsertPacket(RtpPacketSender::kNormalPriority, kSsrc, kSeqNum, _, _, _)); - EXPECT_CALL(mock_rtc_event_log_, LogOutgoingRtpHeader(_, _)); + EXPECT_CALL(mock_rtc_event_log_, + LogProxy(SameRtcEventTypeAs(RtcEvent::Type::RtpPacketOutgoing))); rtp_sender_->SetStorePacketsStatus(true, 10); EXPECT_EQ(0, rtp_sender_->RegisterRtpHeaderExtension( @@ -627,7 +634,9 @@ TEST_P(RtpSenderTest, SendPadding) { // Make all (non-padding) packets go to send queue. EXPECT_CALL(mock_paced_sender_, InsertPacket(RtpPacketSender::kNormalPriority, kSsrc, kSeqNum, _, _, _)); - EXPECT_CALL(mock_rtc_event_log_, LogOutgoingRtpHeader(_, _)).Times(1 + 4 + 1); + EXPECT_CALL(mock_rtc_event_log_, + LogProxy(SameRtcEventTypeAs(RtcEvent::Type::RtpPacketOutgoing))) + .Times(1 + 4 + 1); uint16_t seq_num = kSeqNum; uint32_t timestamp = kTimestamp; @@ -826,7 +835,8 @@ TEST_P(RtpSenderTest, SendRedundantPayloads) { EXPECT_CALL(mock_paced_sender_, InsertPacket(RtpPacketSender::kNormalPriority, kSsrc, _, _, _, _)) .Times(kNumPayloadSizes); - EXPECT_CALL(mock_rtc_event_log_, LogOutgoingRtpHeader(_, _)) + EXPECT_CALL(mock_rtc_event_log_, + LogProxy(SameRtcEventTypeAs(RtcEvent::Type::RtpPacketOutgoing))) .Times(kNumPayloadSizes); // Send 10 packets of increasing size. @@ -839,7 +849,8 @@ TEST_P(RtpSenderTest, SendRedundantPayloads) { fake_clock_.AdvanceTimeMilliseconds(33); } - EXPECT_CALL(mock_rtc_event_log_, LogOutgoingRtpHeader(_, _)) + EXPECT_CALL(mock_rtc_event_log_, + LogProxy(SameRtcEventTypeAs(RtcEvent::Type::RtpPacketOutgoing))) .Times(::testing::AtLeast(4)); // The amount of padding to send it too small to send a payload packet. @@ -935,7 +946,9 @@ TEST_P(RtpSenderTest, SendFlexfecPackets) { kFlexfecSsrc, _, _, _, false)) .WillOnce(testing::SaveArg<2>(&flexfec_seq_num)); SendGenericPayload(); - EXPECT_CALL(mock_rtc_event_log_, LogOutgoingRtpHeader(_, _)).Times(2); + EXPECT_CALL(mock_rtc_event_log_, + LogProxy(SameRtcEventTypeAs(RtcEvent::Type::RtpPacketOutgoing))) + .Times(2); EXPECT_TRUE(rtp_sender_->TimeToSendPacket(kMediaSsrc, kSeqNum, fake_clock_.TimeInMilliseconds(), false, PacedPacketInfo())); @@ -1010,7 +1023,9 @@ TEST_P(RtpSenderTest, NoFlexfecForTimingFrames) { sizeof(kPayloadData), nullptr, &video_header, nullptr, kDefaultExpectedRetransmissionTimeMs)); - EXPECT_CALL(mock_rtc_event_log_, LogOutgoingRtpHeader(_, _)).Times(1); + EXPECT_CALL(mock_rtc_event_log_, + LogProxy(SameRtcEventTypeAs(RtcEvent::Type::RtpPacketOutgoing))) + .Times(1); EXPECT_TRUE(rtp_sender_->TimeToSendPacket(kMediaSsrc, kSeqNum, fake_clock_.TimeInMilliseconds(), false, PacedPacketInfo())); @@ -1034,7 +1049,9 @@ TEST_P(RtpSenderTest, NoFlexfecForTimingFrames) { kPayloadData, sizeof(kPayloadData), nullptr, &video_header, nullptr, kDefaultExpectedRetransmissionTimeMs)); - EXPECT_CALL(mock_rtc_event_log_, LogOutgoingRtpHeader(_, _)).Times(2); + EXPECT_CALL(mock_rtc_event_log_, + LogProxy(SameRtcEventTypeAs(RtcEvent::Type::RtpPacketOutgoing))) + .Times(2); EXPECT_TRUE(rtp_sender_->TimeToSendPacket(kMediaSsrc, kSeqNum + 1, fake_clock_.TimeInMilliseconds(), false, PacedPacketInfo())); @@ -1080,7 +1097,9 @@ TEST_P(RtpSenderTestWithoutPacer, SendFlexfecPackets) { params.fec_mask_type = kFecMaskRandom; rtp_sender_->SetFecParameters(params, params); - EXPECT_CALL(mock_rtc_event_log_, LogOutgoingRtpHeader(_, _)).Times(2); + EXPECT_CALL(mock_rtc_event_log_, + LogProxy(SameRtcEventTypeAs(RtcEvent::Type::RtpPacketOutgoing))) + .Times(2); SendGenericPayload(); ASSERT_EQ(2, transport_.packets_sent()); const RtpPacketReceived& media_packet = transport_.sent_packets_[0]; diff --git a/pc/peerconnectionfactory.cc b/pc/peerconnectionfactory.cc index 29159aea60..d3c624d1c0 100644 --- a/pc/peerconnectionfactory.cc +++ b/pc/peerconnectionfactory.cc @@ -315,8 +315,10 @@ rtc::Thread* PeerConnectionFactory::network_thread() { std::unique_ptr PeerConnectionFactory::CreateRtcEventLog_w() { RTC_DCHECK_RUN_ON(worker_thread_); - return event_log_factory_ ? event_log_factory_->CreateRtcEventLog() - : rtc::MakeUnique(); + const auto encoding_type = RtcEventLog::EncodingType::Legacy; + return event_log_factory_ + ? event_log_factory_->CreateRtcEventLog(encoding_type) + : rtc::MakeUnique(); } std::unique_ptr PeerConnectionFactory::CreateCall_w( diff --git a/video/video_quality_test.cc b/video/video_quality_test.cc index 2526ac25a6..0008b1f7fa 100644 --- a/video/video_quality_test.cc +++ b/video/video_quality_test.cc @@ -1816,7 +1816,7 @@ void VideoQualityTest::RunWithAnalyzer(const Params& params) { } if (!params.logging.rtc_event_log_name.empty()) { - event_log_ = RtcEventLog::Create(clock_); + event_log_ = RtcEventLog::Create(clock_, RtcEventLog::EncodingType::Legacy); bool event_log_started = event_log_->StartLogging(params.logging.rtc_event_log_name, -1); RTC_DCHECK(event_log_started); diff --git a/voice_engine/BUILD.gn b/voice_engine/BUILD.gn index a7e837fd03..335352b346 100644 --- a/voice_engine/BUILD.gn +++ b/voice_engine/BUILD.gn @@ -68,6 +68,7 @@ rtc_static_library("voice_engine") { "../logging:rtc_event_log_api", "../modules:module_api", "../modules/audio_coding:audio_format_conversion", + "../modules/audio_coding:audio_network_adaptor_config", "../modules/audio_coding:rent_a_codec", "../modules/audio_device", "../modules/audio_processing", diff --git a/voice_engine/channel.cc b/voice_engine/channel.cc index 73da3d14bd..4ac040bee0 100644 --- a/voice_engine/channel.cc +++ b/voice_engine/channel.cc @@ -20,6 +20,25 @@ #include "audio/utility/audio_frame_operations.h" #include "call/rtp_transport_controller_send_interface.h" #include "logging/rtc_event_log/rtc_event_log.h" +// TODO(eladalon): Remove events/* after removing the deprecated functions. +#include "logging/rtc_event_log/events/rtc_event_audio_network_adaptation.h" +#include "logging/rtc_event_log/events/rtc_event_audio_playout.h" +#include "logging/rtc_event_log/events/rtc_event_audio_receive_stream_config.h" +#include "logging/rtc_event_log/events/rtc_event_audio_send_stream_config.h" +#include "logging/rtc_event_log/events/rtc_event_bwe_update_delay_based.h" +#include "logging/rtc_event_log/events/rtc_event_bwe_update_loss_based.h" +#include "logging/rtc_event_log/events/rtc_event_logging_started.h" +#include "logging/rtc_event_log/events/rtc_event_logging_stopped.h" +#include "logging/rtc_event_log/events/rtc_event_probe_cluster_created.h" +#include "logging/rtc_event_log/events/rtc_event_probe_result_failure.h" +#include "logging/rtc_event_log/events/rtc_event_probe_result_success.h" +#include "logging/rtc_event_log/events/rtc_event_rtcp_packet_incoming.h" +#include "logging/rtc_event_log/events/rtc_event_rtcp_packet_outgoing.h" +#include "logging/rtc_event_log/events/rtc_event_rtp_packet_incoming.h" +#include "logging/rtc_event_log/events/rtc_event_rtp_packet_outgoing.h" +#include "logging/rtc_event_log/events/rtc_event_video_receive_stream_config.h" +#include "logging/rtc_event_log/events/rtc_event_video_send_stream_config.h" +#include "modules/audio_coding/audio_network_adaptor/include/audio_network_adaptor_config.h" #include "modules/audio_coding/codecs/audio_format_conversion.h" #include "modules/audio_device/include/audio_device.h" #include "modules/audio_processing/include/audio_processing.h" @@ -36,6 +55,7 @@ #include "rtc_base/format_macros.h" #include "rtc_base/location.h" #include "rtc_base/logging.h" +#include "rtc_base/ptr_util.h" #include "rtc_base/rate_limiter.h" #include "rtc_base/task_queue.h" #include "rtc_base/thread_checker.h" @@ -75,6 +95,13 @@ class RtcEventLogProxy final : public webrtc::RtcEventLog { void StopLogging() override { RTC_NOTREACHED(); } + void Log(std::unique_ptr event) override { + rtc::CritScope lock(&crit_); + if (event_log_) { + event_log_->Log(std::move(event)); + } + } + void LogVideoReceiveStreamConfig( const webrtc::rtclog::StreamConfig&) override { RTC_NOTREACHED(); @@ -88,7 +115,8 @@ class RtcEventLogProxy final : public webrtc::RtcEventLog { const webrtc::rtclog::StreamConfig& config) override { rtc::CritScope lock(&crit_); if (event_log_) { - event_log_->LogAudioReceiveStreamConfig(config); + event_log_->Log(rtc::MakeUnique( + rtc::MakeUnique(config))); } } @@ -96,14 +124,15 @@ class RtcEventLogProxy final : public webrtc::RtcEventLog { const webrtc::rtclog::StreamConfig& config) override { rtc::CritScope lock(&crit_); if (event_log_) { - event_log_->LogAudioSendStreamConfig(config); + event_log_->Log(rtc::MakeUnique( + rtc::MakeUnique(config))); } } void LogIncomingRtpHeader(const RtpPacketReceived& packet) override { rtc::CritScope lock(&crit_); if (event_log_) { - event_log_->LogIncomingRtpHeader(packet); + event_log_->Log(rtc::MakeUnique(packet)); } } @@ -111,28 +140,29 @@ class RtcEventLogProxy final : public webrtc::RtcEventLog { int probe_cluster_id) override { rtc::CritScope lock(&crit_); if (event_log_) { - event_log_->LogOutgoingRtpHeader(packet, probe_cluster_id); + event_log_->Log( + rtc::MakeUnique(packet, probe_cluster_id)); } } void LogIncomingRtcpPacket(rtc::ArrayView packet) override { rtc::CritScope lock(&crit_); if (event_log_) { - event_log_->LogIncomingRtcpPacket(packet); + event_log_->Log(rtc::MakeUnique(packet)); } } void LogOutgoingRtcpPacket(rtc::ArrayView packet) override { rtc::CritScope lock(&crit_); if (event_log_) { - event_log_->LogOutgoingRtcpPacket(packet); + event_log_->Log(rtc::MakeUnique(packet)); } } void LogAudioPlayout(uint32_t ssrc) override { rtc::CritScope lock(&crit_); if (event_log_) { - event_log_->LogAudioPlayout(ssrc); + event_log_->Log(rtc::MakeUnique(ssrc)); } } @@ -141,8 +171,8 @@ class RtcEventLogProxy final : public webrtc::RtcEventLog { int32_t total_packets) override { rtc::CritScope lock(&crit_); if (event_log_) { - event_log_->LogLossBasedBweUpdate(bitrate_bps, fraction_loss, - total_packets); + event_log_->Log(rtc::MakeUnique( + bitrate_bps, fraction_loss, total_packets)); } } @@ -150,7 +180,8 @@ class RtcEventLogProxy final : public webrtc::RtcEventLog { BandwidthUsage detector_state) override { rtc::CritScope lock(&crit_); if (event_log_) { - event_log_->LogDelayBasedBweUpdate(bitrate_bps, detector_state); + event_log_->Log(rtc::MakeUnique( + bitrate_bps, detector_state)); } } @@ -158,7 +189,8 @@ class RtcEventLogProxy final : public webrtc::RtcEventLog { const AudioEncoderRuntimeConfig& config) override { rtc::CritScope lock(&crit_); if (event_log_) { - event_log_->LogAudioNetworkAdaptation(config); + event_log_->Log(rtc::MakeUnique( + rtc::MakeUnique(config))); } } @@ -168,15 +200,16 @@ class RtcEventLogProxy final : public webrtc::RtcEventLog { int min_bytes) override { rtc::CritScope lock(&crit_); if (event_log_) { - event_log_->LogProbeClusterCreated(id, bitrate_bps, min_probes, - min_bytes); + event_log_->Log(rtc::MakeUnique( + id, bitrate_bps, min_probes, min_bytes)); } }; void LogProbeResultSuccess(int id, int bitrate_bps) override { rtc::CritScope lock(&crit_); if (event_log_) { - event_log_->LogProbeResultSuccess(id, bitrate_bps); + event_log_->Log( + rtc::MakeUnique(id, bitrate_bps)); } }; @@ -184,7 +217,8 @@ class RtcEventLogProxy final : public webrtc::RtcEventLog { ProbeFailureReason failure_reason) override { rtc::CritScope lock(&crit_); if (event_log_) { - event_log_->LogProbeResultFailure(id, failure_reason); + event_log_->Log( + rtc::MakeUnique(id, failure_reason)); } }; @@ -584,7 +618,7 @@ AudioMixer::Source::AudioFrameInfo Channel::GetAudioFrameWithInfo( unsigned int ssrc; RTC_CHECK_EQ(GetRemoteSSRC(ssrc), 0); - event_log_proxy_->LogAudioPlayout(ssrc); + event_log_proxy_->Log(rtc::MakeUnique(ssrc)); // Get 10ms raw PCM data from the ACM (mixer limits output frequency) bool muted; if (audio_coding_->PlayoutData10Ms(audio_frame->sample_rate_hz_, audio_frame,