diff --git a/api/rtc_event_log/rtc_event.h b/api/rtc_event_log/rtc_event.h index 101f78f255..51db8f0b4d 100644 --- a/api/rtc_event_log/rtc_event.h +++ b/api/rtc_event_log/rtc_event.h @@ -52,7 +52,8 @@ class RtcEvent { VideoSendStreamConfig, GenericPacketSent, GenericPacketReceived, - GenericAckReceived + GenericAckReceived, + FrameDecoded }; RtcEvent(); diff --git a/logging/BUILD.gn b/logging/BUILD.gn index c1edd69680..7a8922d4a2 100644 --- a/logging/BUILD.gn +++ b/logging/BUILD.gn @@ -108,6 +108,22 @@ rtc_library("rtc_event_bwe") { ] } +rtc_library("rtc_event_frame_events") { + sources = [ + "rtc_event_log/events/rtc_event_frame_decoded.cc", + "rtc_event_log/events/rtc_event_frame_decoded.h", + ] + deps = [ + "../api/rtc_event_log", + "../api/video:video_frame", + "../rtc_base:timeutils", + ] + absl_deps = [ + "//third_party/abseil-cpp/absl/memory", + "//third_party/abseil-cpp/absl/types:optional", + ] +} + rtc_library("rtc_event_generic_packet_events") { visibility = [ "*" ] sources = [ @@ -203,6 +219,7 @@ rtc_library("rtc_event_log_impl_encoder") { ":ice_log", ":rtc_event_audio", ":rtc_event_bwe", + ":rtc_event_frame_events", ":rtc_event_generic_packet_events", ":rtc_event_log2_proto", ":rtc_event_log_api", @@ -311,6 +328,7 @@ if (rtc_enable_protobuf) { "../api/units:data_rate", "../api/units:time_delta", "../api/units:timestamp", + "../api/video:video_frame", "../call:video_stream_api", "../modules:module_api", "../modules:module_api_public", @@ -349,6 +367,7 @@ if (rtc_enable_protobuf) { ":ice_log", ":rtc_event_audio", ":rtc_event_bwe", + ":rtc_event_frame_events", ":rtc_event_generic_packet_events", ":rtc_event_log2_proto", ":rtc_event_log_impl_encoder", diff --git a/logging/rtc_event_log/encoder/rtc_event_log_encoder_legacy.cc b/logging/rtc_event_log/encoder/rtc_event_log_encoder_legacy.cc index 2f1c5a4533..d16badaade 100644 --- a/logging/rtc_event_log/encoder/rtc_event_log_encoder_legacy.cc +++ b/logging/rtc_event_log/encoder/rtc_event_log_encoder_legacy.cc @@ -367,6 +367,7 @@ std::string RtcEventLogEncoderLegacy::Encode(const RtcEvent& event) { case RtcEvent::Type::GenericPacketReceived: case RtcEvent::Type::GenericPacketSent: case RtcEvent::Type::GenericAckReceived: + case RtcEvent::Type::FrameDecoded: // These are unsupported in the old format, but shouldn't crash. return ""; } diff --git a/logging/rtc_event_log/encoder/rtc_event_log_encoder_new_format.cc b/logging/rtc_event_log/encoder/rtc_event_log_encoder_new_format.cc index 70c7f37356..3cfd7a0a88 100644 --- a/logging/rtc_event_log/encoder/rtc_event_log_encoder_new_format.cc +++ b/logging/rtc_event_log/encoder/rtc_event_log_encoder_new_format.cc @@ -24,6 +24,7 @@ #include "logging/rtc_event_log/events/rtc_event_bwe_update_loss_based.h" #include "logging/rtc_event_log/events/rtc_event_dtls_transport_state.h" #include "logging/rtc_event_log/events/rtc_event_dtls_writable_state.h" +#include "logging/rtc_event_log/events/rtc_event_frame_decoded.h" #include "logging/rtc_event_log/events/rtc_event_generic_ack_received.h" #include "logging/rtc_event_log/events/rtc_event_generic_packet_received.h" #include "logging/rtc_event_log/events/rtc_event_generic_packet_sent.h" @@ -91,6 +92,26 @@ rtclog2::DelayBasedBweUpdates::DetectorState ConvertToProtoFormat( return rtclog2::DelayBasedBweUpdates::BWE_UNKNOWN_STATE; } +rtclog2::FrameDecodedEvents::Codec ConvertToProtoFormat(VideoCodecType codec) { + switch (codec) { + case VideoCodecType::kVideoCodecGeneric: + return rtclog2::FrameDecodedEvents::CODEC_GENERIC; + case VideoCodecType::kVideoCodecVP8: + return rtclog2::FrameDecodedEvents::CODEC_VP8; + case VideoCodecType::kVideoCodecVP9: + return rtclog2::FrameDecodedEvents::CODEC_VP9; + case VideoCodecType::kVideoCodecAV1: + return rtclog2::FrameDecodedEvents::CODEC_AV1; + case VideoCodecType::kVideoCodecH264: + return rtclog2::FrameDecodedEvents::CODEC_H264; + case VideoCodecType::kVideoCodecMultiplex: + // This codec type is afaik not used. + return rtclog2::FrameDecodedEvents::CODEC_UNKNOWN; + } + RTC_NOTREACHED(); + return rtclog2::FrameDecodedEvents::CODEC_UNKNOWN; +} + rtclog2::BweProbeResultFailure::FailureReason ConvertToProtoFormat( ProbeFailureReason failure_reason) { switch (failure_reason) { @@ -677,6 +698,7 @@ std::string RtcEventLogEncoderNewFormat::EncodeBatch( std::vector bwe_loss_based_updates; std::vector dtls_transport_states; std::vector dtls_writable_states; + std::vector frames_decoded; std::vector generic_acks_received; std::vector generic_packets_received; std::vector generic_packets_sent; @@ -859,6 +881,13 @@ std::string RtcEventLogEncoderNewFormat::EncodeBatch( generic_acks_received.push_back(rtc_event); break; } + case RtcEvent::Type::FrameDecoded: { + auto* rtc_event = + static_cast(it->get()); + // TODO(terelius): Group by SSRC + frames_decoded.push_back(rtc_event); + break; + } } } @@ -872,6 +901,7 @@ std::string RtcEventLogEncoderNewFormat::EncodeBatch( EncodeBweUpdateLossBased(bwe_loss_based_updates, &event_stream); EncodeDtlsTransportState(dtls_transport_states, &event_stream); EncodeDtlsWritableState(dtls_writable_states, &event_stream); + EncodeFramesDecoded(frames_decoded, &event_stream); EncodeGenericAcksReceived(generic_acks_received, &event_stream); EncodeGenericPacketsReceived(generic_packets_received, &event_stream); EncodeGenericPacketsSent(generic_packets_sent, &event_stream); @@ -1431,6 +1461,105 @@ void RtcEventLogEncoderNewFormat::EncodeRtpPacketIncoming( } } +void RtcEventLogEncoderNewFormat::EncodeFramesDecoded( + rtc::ArrayView batch, + rtclog2::EventStream* event_stream) { + if (batch.empty()) { + return; + } + const RtcEventFrameDecoded* const base_event = batch[0]; + rtclog2::FrameDecodedEvents* proto_batch = + event_stream->add_frame_decoded_events(); + proto_batch->set_timestamp_ms(base_event->timestamp_ms()); + proto_batch->set_ssrc(base_event->ssrc()); + proto_batch->set_render_time_ms(base_event->render_time_ms()); + proto_batch->set_width(base_event->width()); + proto_batch->set_height(base_event->height()); + proto_batch->set_codec(ConvertToProtoFormat(base_event->codec())); + proto_batch->set_qp(base_event->qp()); + + if (batch.size() == 1) { + return; + } + + // Delta encoding + proto_batch->set_number_of_deltas(batch.size() - 1); + std::vector> values(batch.size() - 1); + std::string encoded_deltas; + + // timestamp_ms + for (size_t i = 0; i < values.size(); ++i) { + const RtcEventFrameDecoded* event = batch[i + 1]; + values[i] = ToUnsigned(event->timestamp_ms()); + } + encoded_deltas = EncodeDeltas(ToUnsigned(base_event->timestamp_ms()), values); + if (!encoded_deltas.empty()) { + proto_batch->set_timestamp_ms_deltas(encoded_deltas); + } + + // SSRC + for (size_t i = 0; i < values.size(); ++i) { + const RtcEventFrameDecoded* event = batch[i + 1]; + values[i] = event->ssrc(); + } + encoded_deltas = EncodeDeltas(base_event->ssrc(), values); + if (!encoded_deltas.empty()) { + proto_batch->set_ssrc_deltas(encoded_deltas); + } + + // render_time_ms + for (size_t i = 0; i < values.size(); ++i) { + const RtcEventFrameDecoded* event = batch[i + 1]; + values[i] = ToUnsigned(event->render_time_ms()); + } + encoded_deltas = + EncodeDeltas(ToUnsigned(base_event->render_time_ms()), values); + if (!encoded_deltas.empty()) { + proto_batch->set_render_time_ms_deltas(encoded_deltas); + } + + // width + for (size_t i = 0; i < values.size(); ++i) { + const RtcEventFrameDecoded* event = batch[i + 1]; + values[i] = ToUnsigned(event->width()); + } + encoded_deltas = EncodeDeltas(ToUnsigned(base_event->width()), values); + if (!encoded_deltas.empty()) { + proto_batch->set_width_deltas(encoded_deltas); + } + + // height + for (size_t i = 0; i < values.size(); ++i) { + const RtcEventFrameDecoded* event = batch[i + 1]; + values[i] = ToUnsigned(event->height()); + } + encoded_deltas = EncodeDeltas(ToUnsigned(base_event->height()), values); + if (!encoded_deltas.empty()) { + proto_batch->set_height_deltas(encoded_deltas); + } + + // codec + for (size_t i = 0; i < values.size(); ++i) { + const RtcEventFrameDecoded* event = batch[i + 1]; + values[i] = static_cast(ConvertToProtoFormat(event->codec())); + } + encoded_deltas = EncodeDeltas( + static_cast(ConvertToProtoFormat(base_event->codec())), values); + if (!encoded_deltas.empty()) { + proto_batch->set_codec_deltas(encoded_deltas); + } + + // qp + for (size_t i = 0; i < values.size(); ++i) { + const RtcEventFrameDecoded* event = batch[i + 1]; + values[i] = event->qp(); + } + encoded_deltas = EncodeDeltas(base_event->qp(), values); + if (!encoded_deltas.empty()) { + proto_batch->set_qp_deltas(encoded_deltas); + } +} + void RtcEventLogEncoderNewFormat::EncodeGenericPacketsSent( rtc::ArrayView batch, rtclog2::EventStream* event_stream) { diff --git a/logging/rtc_event_log/encoder/rtc_event_log_encoder_new_format.h b/logging/rtc_event_log/encoder/rtc_event_log_encoder_new_format.h index d25184ec4a..fdbe8fe854 100644 --- a/logging/rtc_event_log/encoder/rtc_event_log_encoder_new_format.h +++ b/logging/rtc_event_log/encoder/rtc_event_log_encoder_new_format.h @@ -51,6 +51,7 @@ class RtcEventVideoSendStreamConfig; class RtcEventIceCandidatePairConfig; class RtcEventIceCandidatePair; class RtpPacket; +class RtcEventFrameDecoded; class RtcEventGenericAckReceived; class RtcEventGenericPacketReceived; class RtcEventGenericPacketSent; @@ -94,6 +95,8 @@ class RtcEventLogEncoderNewFormat final : public RtcEventLogEncoder { void EncodeDtlsWritableState( rtc::ArrayView batch, rtclog2::EventStream* event_stream); + void EncodeFramesDecoded(rtc::ArrayView batch, + rtclog2::EventStream* event_stream); void EncodeGenericAcksReceived( rtc::ArrayView batch, rtclog2::EventStream* event_stream); diff --git a/logging/rtc_event_log/encoder/rtc_event_log_encoder_unittest.cc b/logging/rtc_event_log/encoder/rtc_event_log_encoder_unittest.cc index cf85775f52..c7b348e54a 100644 --- a/logging/rtc_event_log/encoder/rtc_event_log_encoder_unittest.cc +++ b/logging/rtc_event_log/encoder/rtc_event_log_encoder_unittest.cc @@ -630,6 +630,35 @@ TEST_P(RtcEventLogEncoderTest, RtcEventDtlsWritableState) { } } +TEST_P(RtcEventLogEncoderTest, RtcEventFrameDecoded) { + std::vector> events(event_count_); + for (size_t i = 0; i < event_count_; ++i) { + events[i] = (i == 0 || !force_repeated_fields_) + ? gen_.NewFrameDecodedEvent() + : events[0]->Copy(); + history_.push_back(events[i]->Copy()); + } + + const std::string encoded = + encoder_->EncodeBatch(history_.begin(), history_.end()); + auto status = parsed_log_.ParseString(encoded); + if (!status.ok()) + RTC_LOG(LS_ERROR) << status.message(); + ASSERT_TRUE(status.ok()); + + const auto& decoded_frames = parsed_log_.decoded_frames(); + if (!new_encoding_) { + ASSERT_EQ(decoded_frames.size(), 0u); + return; + } + + ASSERT_EQ(decoded_frames.size(), event_count_); + + for (size_t i = 0; i < event_count_; ++i) { + verifier_.VerifyLoggedFrameDecoded(*events[i], decoded_frames[i]); + } +} + // TODO(eladalon/terelius): Test with multiple events in the batch. TEST_P(RtcEventLogEncoderTest, RtcEventIceCandidatePairConfig) { std::unique_ptr event = diff --git a/logging/rtc_event_log/events/rtc_event_frame_decoded.cc b/logging/rtc_event_log/events/rtc_event_frame_decoded.cc new file mode 100644 index 0000000000..19929e77fb --- /dev/null +++ b/logging/rtc_event_log/events/rtc_event_frame_decoded.cc @@ -0,0 +1,52 @@ +/* + * Copyright (c) 2019 The WebRTC project authors. All Rights Reserved. + * + * Use of this source code is governed by a BSD-style license + * that can be found in the LICENSE file in the root of the source + * tree. An additional intellectual property rights grant can be found + * in the file PATENTS. All contributing project authors may + * be found in the AUTHORS file in the root of the source tree. + */ + +#include "logging/rtc_event_log/events/rtc_event_frame_decoded.h" + +#include "absl/memory/memory.h" + +namespace webrtc { + +RtcEventFrameDecoded::RtcEventFrameDecoded(int64_t render_time_ms, + uint32_t ssrc, + int width, + int height, + VideoCodecType codec, + uint8_t qp) + : render_time_ms_(render_time_ms), + ssrc_(ssrc), + width_(width), + height_(height), + codec_(codec), + qp_(qp) {} + +RtcEventFrameDecoded::RtcEventFrameDecoded(const RtcEventFrameDecoded& other) + : RtcEvent(other.timestamp_us_), + render_time_ms_(other.render_time_ms_), + ssrc_(other.ssrc_), + width_(other.width_), + height_(other.height_), + codec_(other.codec_), + qp_(other.qp_) {} + +RtcEvent::Type RtcEventFrameDecoded::GetType() const { + return RtcEvent::Type::FrameDecoded; +} + +bool RtcEventFrameDecoded::IsConfigEvent() const { + return false; +} + +std::unique_ptr RtcEventFrameDecoded::Copy() const { + return absl::WrapUnique( + new RtcEventFrameDecoded(*this)); +} + +} // namespace webrtc diff --git a/logging/rtc_event_log/events/rtc_event_frame_decoded.h b/logging/rtc_event_log/events/rtc_event_frame_decoded.h new file mode 100644 index 0000000000..ebc0522c98 --- /dev/null +++ b/logging/rtc_event_log/events/rtc_event_frame_decoded.h @@ -0,0 +1,59 @@ +/* + * Copyright (c) 2019 The WebRTC project authors. All Rights Reserved. + * + * Use of this source code is governed by a BSD-style license + * that can be found in the LICENSE file in the root of the source + * tree. An additional intellectual property rights grant can be found + * in the file PATENTS. All contributing project authors may + * be found in the AUTHORS file in the root of the source tree. + */ + +#ifndef LOGGING_RTC_EVENT_LOG_EVENTS_RTC_EVENT_FRAME_DECODED_H_ +#define LOGGING_RTC_EVENT_LOG_EVENTS_RTC_EVENT_FRAME_DECODED_H_ + +#include + +#include + +#include "api/rtc_event_log/rtc_event.h" +#include "api/video/video_codec_type.h" + +namespace webrtc { + +class RtcEventFrameDecoded final : public RtcEvent { + public: + RtcEventFrameDecoded(int64_t render_time_ms, + uint32_t ssrc, + int width, + int height, + VideoCodecType codec, + uint8_t qp); + ~RtcEventFrameDecoded() override = default; + + Type GetType() const override; + + bool IsConfigEvent() const override; + + std::unique_ptr Copy() const; + + int64_t render_time_ms() const { return render_time_ms_; } + uint32_t ssrc() const { return ssrc_; } + int width() const { return width_; } + int height() const { return height_; } + VideoCodecType codec() const { return codec_; } + uint8_t qp() const { return qp_; } + + private: + RtcEventFrameDecoded(const RtcEventFrameDecoded& other); + + const int64_t render_time_ms_; + const uint32_t ssrc_; + const int width_; + const int height_; + const VideoCodecType codec_; + const uint8_t qp_; +}; + +} // namespace webrtc + +#endif // LOGGING_RTC_EVENT_LOG_EVENTS_RTC_EVENT_FRAME_DECODED_H_ diff --git a/logging/rtc_event_log/logged_events.h b/logging/rtc_event_log/logged_events.h index e13bba0c43..4bd33f62bd 100644 --- a/logging/rtc_event_log/logged_events.h +++ b/logging/rtc_event_log/logged_events.h @@ -18,6 +18,7 @@ #include "api/units/data_rate.h" #include "api/units/time_delta.h" #include "api/units/timestamp.h" +#include "api/video/video_codec_type.h" #include "logging/rtc_event_log/events/rtc_event_dtls_transport_state.h" #include "logging/rtc_event_log/events/rtc_event_ice_candidate_pair.h" #include "logging/rtc_event_log/events/rtc_event_ice_candidate_pair_config.h" @@ -188,6 +189,19 @@ struct LoggedBweProbeFailureEvent { ProbeFailureReason failure_reason; }; +struct LoggedFrameDecoded { + int64_t log_time_us() const { return timestamp_us; } + int64_t log_time_ms() const { return timestamp_us / 1000; } + + int64_t timestamp_us; + int64_t render_time_ms; + uint32_t ssrc; + int width; + int height; + VideoCodecType codec; + uint8_t qp; +}; + struct LoggedIceCandidatePairConfig { int64_t log_time_us() const { return timestamp_us; } int64_t log_time_ms() const { return timestamp_us / 1000; } diff --git a/logging/rtc_event_log/rtc_event_log2.proto b/logging/rtc_event_log/rtc_event_log2.proto index 0cdb2a43c7..4ff3206439 100644 --- a/logging/rtc_event_log/rtc_event_log2.proto +++ b/logging/rtc_event_log/rtc_event_log2.proto @@ -20,7 +20,8 @@ message EventStream { repeated IncomingRtcpPackets incoming_rtcp_packets = 4; repeated OutgoingRtcpPackets outgoing_rtcp_packets = 5; repeated AudioPlayoutEvents audio_playout_events = 6; - // The field tags 7-15 are reserved for the most common events. + repeated FrameDecodedEvents frame_decoded_events = 7; + // The field tags 8-15 are reserved for the most common events. repeated BeginLogEvent begin_log_events = 16; repeated EndLogEvent end_log_events = 17; repeated LossBasedBweUpdates loss_based_bwe_updates = 18; @@ -284,6 +285,50 @@ message AudioPlayoutEvents { optional bytes local_ssrc_deltas = 102; } +message FrameDecodedEvents { + enum Codec { + CODEC_UNKNOWN = 0; + CODEC_GENERIC = 1; + CODEC_VP8 = 2; + CODEC_VP9 = 3; + CODEC_AV1 = 4; + CODEC_H264 = 5; + } + + // required + optional int64 timestamp_ms = 1; + + // required - The SSRC of the video stream that the frame belongs to. + optional fixed32 ssrc = 2; + + // required - The predicted render time of the frame. + optional int64 render_time_ms = 3; + + // required - The width (in pixels) of the frame. + optional int32 width = 4; + + // required - The height (in pixels) of the frame. + optional int32 height = 5; + + // required - The codec type of the frame. + optional Codec codec = 6; + + // required - The QP (quantization parameter) of the frame. Range [0,255]. + optional uint32 qp = 7; + + // optional - required if the batch contains delta encoded events. + optional uint32 number_of_deltas = 15; + + // Delta encodings. + optional bytes timestamp_ms_deltas = 101; + optional bytes ssrc_deltas = 102; + optional bytes render_time_ms_deltas = 103; + optional bytes width_deltas = 104; + optional bytes height_deltas = 105; + optional bytes codec_deltas = 106; + optional bytes qp_deltas = 107; +} + message BeginLogEvent { // required optional int64 timestamp_ms = 1; diff --git a/logging/rtc_event_log/rtc_event_log_parser.cc b/logging/rtc_event_log/rtc_event_log_parser.cc index c88207607c..4ab4332843 100644 --- a/logging/rtc_event_log/rtc_event_log_parser.cc +++ b/logging/rtc_event_log/rtc_event_log_parser.cc @@ -293,6 +293,27 @@ IceCandidatePairEventType GetRuntimeIceCandidatePairEventType( return IceCandidatePairEventType::kCheckSent; } +VideoCodecType GetRuntimeCodecType(rtclog2::FrameDecodedEvents::Codec codec) { + switch (codec) { + case rtclog2::FrameDecodedEvents::CODEC_GENERIC: + return VideoCodecType::kVideoCodecGeneric; + case rtclog2::FrameDecodedEvents::CODEC_VP8: + return VideoCodecType::kVideoCodecVP8; + case rtclog2::FrameDecodedEvents::CODEC_VP9: + return VideoCodecType::kVideoCodecVP9; + case rtclog2::FrameDecodedEvents::CODEC_AV1: + return VideoCodecType::kVideoCodecAV1; + case rtclog2::FrameDecodedEvents::CODEC_H264: + return VideoCodecType::kVideoCodecH264; + case rtclog2::FrameDecodedEvents::CODEC_UNKNOWN: + RTC_LOG(LS_ERROR) << "Unknown codec type. Assuming " + "VideoCodecType::kVideoCodecMultiplex"; + return VideoCodecType::kVideoCodecMultiplex; + } + RTC_NOTREACHED(); + return VideoCodecType::kVideoCodecMultiplex; +} + // Reads a VarInt from |stream| and returns it. Also writes the read bytes to // |buffer| starting |bytes_written| bytes into the buffer. |bytes_written| is // incremented for each written byte. @@ -528,7 +549,7 @@ ParsedRtcEventLog::ParseStatus StoreRtpPackets( number_of_deltas); } - // Delta decoding + // Populate events from decoded deltas for (size_t i = 0; i < number_of_deltas; ++i) { RTC_PARSE_CHECK_OR_RETURN(timestamp_ms_values[i].has_value()); RTC_PARSE_CHECK_OR_RETURN(marker_values[i].has_value()); @@ -641,7 +662,7 @@ ParsedRtcEventLog::ParseStatus StoreRtcpPackets( DecodeBlobs(proto.raw_packet_blobs(), number_of_deltas); RTC_PARSE_CHECK_OR_RETURN_EQ(raw_packet_values.size(), number_of_deltas); - // Delta decoding + // Populate events from decoded deltas for (size_t i = 0; i < number_of_deltas; ++i) { RTC_PARSE_CHECK_OR_RETURN(timestamp_ms_values[i].has_value()); int64_t timestamp_ms; @@ -1063,6 +1084,7 @@ void ParsedRtcEventLog::Clear() { bwe_loss_updates_.clear(); dtls_transport_states_.clear(); dtls_writable_states_.clear(); + decoded_frames_.clear(); alr_state_events_.clear(); ice_candidate_pair_configs_.clear(); ice_candidate_pair_events_.clear(); @@ -1200,6 +1222,7 @@ ParsedRtcEventLog::ParseStatus ParsedRtcEventLog::ParseStream( StoreFirstAndLastTimestamp(bwe_probe_success_events()); StoreFirstAndLastTimestamp(bwe_delay_updates()); StoreFirstAndLastTimestamp(bwe_loss_updates()); + StoreFirstAndLastTimestamp(decoded_frames()); StoreFirstAndLastTimestamp(dtls_transport_states()); StoreFirstAndLastTimestamp(dtls_writable_states()); StoreFirstAndLastTimestamp(ice_candidate_pair_configs()); @@ -2337,7 +2360,8 @@ ParsedRtcEventLog::ParseStatus ParsedRtcEventLog::StoreParsedNewFormatEvent( stream.video_send_stream_configs_size() + stream.generic_packets_sent_size() + stream.generic_packets_received_size() + - stream.generic_acks_received_size(), + stream.generic_acks_received_size() + + stream.frame_decoded_events_size(), 1u); if (stream.incoming_rtp_packets_size() == 1) { @@ -2395,6 +2419,8 @@ ParsedRtcEventLog::ParseStatus ParsedRtcEventLog::StoreParsedNewFormatEvent( return StoreGenericPacketSentEvent(stream.generic_packets_sent(0)); } else if (stream.generic_acks_received_size() == 1) { return StoreGenericAckReceivedEvent(stream.generic_acks_received(0)); + } else if (stream.frame_decoded_events_size() == 1) { + return StoreFrameDecodedEvents(stream.frame_decoded_events(0)); } else { RTC_NOTREACHED(); return ParseStatus::Success(); @@ -2478,7 +2504,7 @@ ParsedRtcEventLog::ParseStatus ParsedRtcEventLog::StoreRemoteEstimateEvent( RTC_PARSE_CHECK_OR_RETURN_EQ(link_capacity_upper_kbps_values.size(), number_of_deltas); - // Delta decoding + // Populate events from decoded deltas for (size_t i = 0; i < number_of_deltas; ++i) { LoggedRemoteEstimateEvent event; RTC_PARSE_CHECK_OR_RETURN(timestamp_ms_values[i].has_value()); @@ -2500,7 +2526,6 @@ ParsedRtcEventLog::ParseStatus ParsedRtcEventLog::StoreAudioPlayoutEvent( RTC_PARSE_CHECK_OR_RETURN(proto.has_local_ssrc()); // Base event - auto map_it = audio_playout_events_[proto.local_ssrc()]; audio_playout_events_[proto.local_ssrc()].emplace_back( 1000 * proto.timestamp_ms(), proto.local_ssrc()); @@ -2521,7 +2546,7 @@ ParsedRtcEventLog::ParseStatus ParsedRtcEventLog::StoreAudioPlayoutEvent( proto.local_ssrc_deltas(), proto.local_ssrc(), number_of_deltas); RTC_PARSE_CHECK_OR_RETURN_EQ(local_ssrc_values.size(), number_of_deltas); - // Delta decoding + // Populate events from decoded deltas for (size_t i = 0; i < number_of_deltas; ++i) { RTC_PARSE_CHECK_OR_RETURN(timestamp_ms_values[i].has_value()); RTC_PARSE_CHECK_OR_RETURN(local_ssrc_values[i].has_value()); @@ -2623,7 +2648,7 @@ ParsedRtcEventLog::ParseStatus ParsedRtcEventLog::StoreBweLossBasedUpdate( proto.total_packets_deltas(), proto.total_packets(), number_of_deltas); RTC_PARSE_CHECK_OR_RETURN_EQ(total_packets_values.size(), number_of_deltas); - // Delta decoding + // Populate events from decoded deltas for (size_t i = 0; i < number_of_deltas; ++i) { RTC_PARSE_CHECK_OR_RETURN(timestamp_ms_values[i].has_value()); int64_t timestamp_ms; @@ -2689,7 +2714,7 @@ ParsedRtcEventLog::ParseStatus ParsedRtcEventLog::StoreBweDelayBasedUpdate( static_cast(proto.detector_state()), number_of_deltas); RTC_PARSE_CHECK_OR_RETURN_EQ(detector_state_values.size(), number_of_deltas); - // Delta decoding + // Populate events from decoded deltas for (size_t i = 0; i < number_of_deltas; ++i) { RTC_PARSE_CHECK_OR_RETURN(timestamp_ms_values[i].has_value()); int64_t timestamp_ms; @@ -2765,6 +2790,113 @@ ParsedRtcEventLog::ParseStatus ParsedRtcEventLog::StoreBweProbeFailureEvent( return ParseStatus::Success(); } +ParsedRtcEventLog::ParseStatus ParsedRtcEventLog::StoreFrameDecodedEvents( + const rtclog2::FrameDecodedEvents& proto) { + RTC_PARSE_CHECK_OR_RETURN(proto.has_timestamp_ms()); + RTC_PARSE_CHECK_OR_RETURN(proto.has_ssrc()); + RTC_PARSE_CHECK_OR_RETURN(proto.has_render_time_ms()); + RTC_PARSE_CHECK_OR_RETURN(proto.has_width()); + RTC_PARSE_CHECK_OR_RETURN(proto.has_height()); + RTC_PARSE_CHECK_OR_RETURN(proto.has_codec()); + RTC_PARSE_CHECK_OR_RETURN(proto.has_qp()); + + LoggedFrameDecoded base_frame; + base_frame.timestamp_us = 1000 * proto.timestamp_ms(); + base_frame.ssrc = proto.ssrc(); + base_frame.render_time_ms = proto.render_time_ms(); + base_frame.width = proto.width(); + base_frame.height = proto.height(); + base_frame.codec = GetRuntimeCodecType(proto.codec()); + RTC_PARSE_CHECK_OR_RETURN_GE(proto.qp(), 0); + RTC_PARSE_CHECK_OR_RETURN_LE(proto.qp(), 255); + base_frame.qp = static_cast(proto.qp()); + + decoded_frames_.push_back(base_frame); + + const size_t number_of_deltas = + proto.has_number_of_deltas() ? proto.number_of_deltas() : 0u; + if (number_of_deltas == 0) { + return ParseStatus::Success(); + } + + // timestamp_ms + std::vector> timestamp_ms_values = + DecodeDeltas(proto.timestamp_ms_deltas(), + ToUnsigned(proto.timestamp_ms()), number_of_deltas); + RTC_PARSE_CHECK_OR_RETURN_EQ(timestamp_ms_values.size(), number_of_deltas); + + // SSRC + std::vector> ssrc_values = + DecodeDeltas(proto.ssrc_deltas(), proto.ssrc(), number_of_deltas); + RTC_PARSE_CHECK_OR_RETURN_EQ(ssrc_values.size(), number_of_deltas); + + // render_time_ms + std::vector> render_time_ms_values = + DecodeDeltas(proto.render_time_ms_deltas(), + ToUnsigned(proto.render_time_ms()), number_of_deltas); + RTC_PARSE_CHECK_OR_RETURN_EQ(render_time_ms_values.size(), number_of_deltas); + + // width + std::vector> width_values = DecodeDeltas( + proto.width_deltas(), ToUnsigned(proto.width()), number_of_deltas); + RTC_PARSE_CHECK_OR_RETURN_EQ(width_values.size(), number_of_deltas); + + // height + std::vector> height_values = DecodeDeltas( + proto.height_deltas(), ToUnsigned(proto.height()), number_of_deltas); + RTC_PARSE_CHECK_OR_RETURN_EQ(height_values.size(), number_of_deltas); + + // codec + std::vector> codec_values = + DecodeDeltas(proto.codec_deltas(), static_cast(proto.codec()), + number_of_deltas); + RTC_PARSE_CHECK_OR_RETURN_EQ(codec_values.size(), number_of_deltas); + + // qp + std::vector> qp_values = + DecodeDeltas(proto.qp_deltas(), proto.qp(), number_of_deltas); + RTC_PARSE_CHECK_OR_RETURN_EQ(qp_values.size(), number_of_deltas); + + // Populate events from decoded deltas + for (size_t i = 0; i < number_of_deltas; ++i) { + LoggedFrameDecoded frame; + int64_t timestamp_ms; + RTC_PARSE_CHECK_OR_RETURN(timestamp_ms_values[i].has_value()); + RTC_PARSE_CHECK_OR_RETURN( + ToSigned(timestamp_ms_values[i].value(), ×tamp_ms)); + frame.timestamp_us = 1000 * timestamp_ms; + + RTC_PARSE_CHECK_OR_RETURN(ssrc_values[i].has_value()); + RTC_PARSE_CHECK_OR_RETURN_LE(ssrc_values[i].value(), + std::numeric_limits::max()); + frame.ssrc = static_cast(ssrc_values[i].value()); + + RTC_PARSE_CHECK_OR_RETURN(render_time_ms_values[i].has_value()); + RTC_PARSE_CHECK_OR_RETURN( + ToSigned(render_time_ms_values[i].value(), &frame.render_time_ms)); + + RTC_PARSE_CHECK_OR_RETURN(width_values[i].has_value()); + RTC_PARSE_CHECK_OR_RETURN(ToSigned(width_values[i].value(), &frame.width)); + + RTC_PARSE_CHECK_OR_RETURN(height_values[i].has_value()); + RTC_PARSE_CHECK_OR_RETURN( + ToSigned(height_values[i].value(), &frame.height)); + + RTC_PARSE_CHECK_OR_RETURN(codec_values[i].has_value()); + frame.codec = + GetRuntimeCodecType(static_cast( + codec_values[i].value())); + + RTC_PARSE_CHECK_OR_RETURN(qp_values[i].has_value()); + RTC_PARSE_CHECK_OR_RETURN_LE(qp_values[i].value(), + std::numeric_limits::max()); + frame.qp = static_cast(qp_values[i].value()); + + decoded_frames_.push_back(frame); + } + return ParseStatus::Success(); +} + ParsedRtcEventLog::ParseStatus ParsedRtcEventLog::StoreGenericAckReceivedEvent( const rtclog2::GenericAckReceived& proto) { RTC_PARSE_CHECK_OR_RETURN(proto.has_timestamp_ms()); @@ -2882,14 +3014,14 @@ ParsedRtcEventLog::ParseStatus ParsedRtcEventLog::StoreGenericPacketSentEvent( number_of_deltas); RTC_PARSE_CHECK_OR_RETURN_EQ(overhead_length_values.size(), number_of_deltas); - std::vector> payload_length_values = - DecodeDeltas(proto.payload_length_deltas(), - ToUnsigned(proto.payload_length()), number_of_deltas); + std::vector> payload_length_values = DecodeDeltas( + proto.payload_length_deltas(), ToUnsigned(proto.payload_length()), + number_of_deltas); // TODO(terelius): Remove ToUnsigned RTC_PARSE_CHECK_OR_RETURN_EQ(payload_length_values.size(), number_of_deltas); - std::vector> padding_length_values = - DecodeDeltas(proto.padding_length_deltas(), - ToUnsigned(proto.padding_length()), number_of_deltas); + std::vector> padding_length_values = DecodeDeltas( + proto.padding_length_deltas(), ToUnsigned(proto.padding_length()), + number_of_deltas); // TODO(terelius): Remove ToUnsigned RTC_PARSE_CHECK_OR_RETURN_EQ(padding_length_values.size(), number_of_deltas); for (size_t i = 0; i < number_of_deltas; i++) { @@ -2955,7 +3087,8 @@ ParsedRtcEventLog::StoreGenericPacketReceivedEvent( ToSigned(packet_number_values[i].value(), &packet_number)); int32_t packet_length; RTC_PARSE_CHECK_OR_RETURN( - ToSigned(packet_length_values[i].value(), &packet_length)); + ToSigned(packet_length_values[i].value(), + &packet_length)); // TODO(terelius): Remove ToSigned generic_packets_received_.push_back( {timestamp_ms * 1000, packet_number, packet_length}); } @@ -3074,7 +3207,7 @@ ParsedRtcEventLog::StoreAudioNetworkAdaptationEvent( } RTC_PARSE_CHECK_OR_RETURN_EQ(num_channels_values.size(), number_of_deltas); - // Delta decoding + // Populate events from decoded deltas for (size_t i = 0; i < number_of_deltas; ++i) { RTC_PARSE_CHECK_OR_RETURN(timestamp_ms_values[i].has_value()); int64_t timestamp_ms; diff --git a/logging/rtc_event_log/rtc_event_log_parser.h b/logging/rtc_event_log/rtc_event_log_parser.h index 8d3351e815..542f1cc6e7 100644 --- a/logging/rtc_event_log/rtc_event_log_parser.h +++ b/logging/rtc_event_log/rtc_event_log_parser.h @@ -611,6 +611,11 @@ class ParsedRtcEventLog { return generic_acks_received_; } + // Media + const std::vector& decoded_frames() const { + return decoded_frames_; + } + int64_t first_timestamp() const { return first_timestamp_; } int64_t last_timestamp() const { return last_timestamp_; } @@ -726,6 +731,8 @@ class ParsedRtcEventLog { ParseStatus StoreDtlsTransportState( const rtclog2::DtlsTransportStateEvent& proto); ParseStatus StoreDtlsWritableState(const rtclog2::DtlsWritableState& proto); + ParsedRtcEventLog::ParseStatus StoreFrameDecodedEvents( + const rtclog2::FrameDecodedEvents& proto); ParseStatus StoreGenericAckReceivedEvent( const rtclog2::GenericAckReceived& proto); ParseStatus StoreGenericPacketReceivedEvent( @@ -848,6 +855,8 @@ class ParsedRtcEventLog { std::vector dtls_transport_states_; std::vector dtls_writable_states_; + std::vector decoded_frames_; + std::vector ice_candidate_pair_configs_; std::vector ice_candidate_pair_events_; diff --git a/logging/rtc_event_log/rtc_event_log_unittest.cc b/logging/rtc_event_log/rtc_event_log_unittest.cc index e785d6160a..848d3b0faa 100644 --- a/logging/rtc_event_log/rtc_event_log_unittest.cc +++ b/logging/rtc_event_log/rtc_event_log_unittest.cc @@ -69,6 +69,7 @@ struct EventCounts { size_t bwe_delay_events = 0; size_t dtls_transport_states = 0; size_t dtls_writable_states = 0; + size_t frame_decoded_events = 0; size_t probe_creations = 0; size_t probe_successes = 0; size_t probe_failures = 0; @@ -85,9 +86,9 @@ struct EventCounts { size_t total_nonconfig_events() const { return alr_states + route_changes + audio_playouts + ana_configs + bwe_loss_events + bwe_delay_events + dtls_transport_states + - dtls_writable_states + probe_creations + probe_successes + - probe_failures + ice_configs + ice_events + incoming_rtp_packets + - outgoing_rtp_packets + incoming_rtcp_packets + + dtls_writable_states + frame_decoded_events + probe_creations + + probe_successes + probe_failures + ice_configs + ice_events + + incoming_rtp_packets + outgoing_rtp_packets + incoming_rtcp_packets + outgoing_rtcp_packets + generic_packets_sent + generic_packets_received + generic_acks_received; } @@ -165,6 +166,7 @@ class RtcEventLogSession dtls_transport_state_list_; std::vector> dtls_writable_state_list_; + std::vector> frame_decoded_event_list_; std::vector> generic_acks_received_; std::vector> @@ -444,6 +446,15 @@ void RtcEventLogSession::WriteLog(EventCounts count, } selection -= count.dtls_writable_states; + if (selection < count.frame_decoded_events) { + auto event = gen_.NewFrameDecodedEvent(); + event_log->Log(event->Copy()); + frame_decoded_event_list_.push_back(std::move(event)); + count.frame_decoded_events--; + continue; + } + selection -= count.frame_decoded_events; + if (selection < count.ice_configs) { auto event = gen_.NewIceCandidatePairConfig(); event_log->Log(event->Copy()); @@ -629,6 +640,14 @@ void RtcEventLogSession::ReadAndVerifyLog() { *probe_success_list_[i], parsed_bwe_probe_success_events[i]); } + auto& parsed_frame_decoded_events = parsed_log.decoded_frames(); + ASSERT_EQ(parsed_frame_decoded_events.size(), + frame_decoded_event_list_.size()); + for (size_t i = 0; i < parsed_frame_decoded_events.size(); i++) { + verifier_.VerifyLoggedFrameDecoded(*frame_decoded_event_list_[i], + parsed_frame_decoded_events[i]); + } + auto& parsed_ice_candidate_pair_configs = parsed_log.ice_candidate_pair_configs(); ASSERT_EQ(parsed_ice_candidate_pair_configs.size(), ice_config_list_.size()); @@ -761,8 +780,6 @@ TEST_P(RtcEventLogSession, StartLoggingFromBeginning) { count.ana_configs = 3; count.bwe_loss_events = 20; count.bwe_delay_events = 20; - count.dtls_transport_states = 4; - count.dtls_writable_states = 2; count.probe_creations = 4; count.probe_successes = 2; count.probe_failures = 2; @@ -773,10 +790,13 @@ TEST_P(RtcEventLogSession, StartLoggingFromBeginning) { count.incoming_rtcp_packets = 20; count.outgoing_rtcp_packets = 20; if (IsNewFormat()) { - count.route_changes = 4; + count.dtls_transport_states = 4; + count.dtls_writable_states = 2; + count.frame_decoded_events = 50; count.generic_packets_sent = 100; count.generic_packets_received = 100; count.generic_acks_received = 20; + count.route_changes = 4; } WriteLog(count, 0); @@ -794,8 +814,6 @@ TEST_P(RtcEventLogSession, StartLoggingInTheMiddle) { count.ana_configs = 10; count.bwe_loss_events = 50; count.bwe_delay_events = 50; - count.dtls_transport_states = 4; - count.dtls_writable_states = 5; count.probe_creations = 10; count.probe_successes = 5; count.probe_failures = 5; @@ -806,10 +824,13 @@ TEST_P(RtcEventLogSession, StartLoggingInTheMiddle) { count.incoming_rtcp_packets = 50; count.outgoing_rtcp_packets = 50; if (IsNewFormat()) { - count.route_changes = 10; + count.dtls_transport_states = 4; + count.dtls_writable_states = 5; + count.frame_decoded_events = 250; count.generic_packets_sent = 500; count.generic_packets_received = 500; count.generic_acks_received = 50; + count.route_changes = 10; } WriteLog(count, 500); diff --git a/logging/rtc_event_log/rtc_event_log_unittest_helper.cc b/logging/rtc_event_log/rtc_event_log_unittest_helper.cc index 2a41f6d25b..905ac449f8 100644 --- a/logging/rtc_event_log/rtc_event_log_unittest_helper.cc +++ b/logging/rtc_event_log/rtc_event_log_unittest_helper.cc @@ -37,6 +37,7 @@ #include "modules/rtp_rtcp/source/rtp_packet_to_send.h" #include "rtc_base/buffer.h" #include "rtc_base/checks.h" +#include "rtc_base/time_utils.h" #include "system_wrappers/include/ntp_time.h" #include "test/gtest.h" @@ -147,6 +148,29 @@ EventGenerator::NewDtlsWritableState() { return std::make_unique(writable); } +std::unique_ptr EventGenerator::NewFrameDecodedEvent() { + constexpr int kMinRenderDelayMs = 1; + constexpr int kMaxRenderDelayMs = 2000000; + constexpr int kMaxWidth = 15360; + constexpr int kMaxHeight = 8640; + constexpr int kMinWidth = 16; + constexpr int kMinHeight = 16; + constexpr int kNumCodecTypes = 5; + + constexpr VideoCodecType kCodecList[kNumCodecTypes] = { + kVideoCodecGeneric, kVideoCodecVP8, kVideoCodecVP9, kVideoCodecAV1, + kVideoCodecH264}; + const int64_t render_time_ms = + rtc::TimeMillis() + prng_.Rand(kMinRenderDelayMs, kMaxRenderDelayMs); + const uint32_t ssrc = prng_.Rand(); + const int width = prng_.Rand(kMinWidth, kMaxWidth); + const int height = prng_.Rand(kMinHeight, kMaxHeight); + const VideoCodecType codec = kCodecList[prng_.Rand(0, kNumCodecTypes - 1)]; + const uint8_t qp = prng_.Rand(); + return std::make_unique(render_time_ms, ssrc, width, + height, codec, qp); +} + std::unique_ptr EventGenerator::NewProbeClusterCreated() { constexpr int kMaxBweBps = 20000000; @@ -835,6 +859,18 @@ void EventVerifier::VerifyLoggedDtlsWritableState( EXPECT_EQ(original_event.writable(), logged_event.writable); } +void EventVerifier::VerifyLoggedFrameDecoded( + const RtcEventFrameDecoded& original_event, + const LoggedFrameDecoded& logged_event) const { + EXPECT_EQ(original_event.timestamp_ms(), logged_event.log_time_ms()); + EXPECT_EQ(original_event.ssrc(), logged_event.ssrc); + EXPECT_EQ(original_event.render_time_ms(), logged_event.render_time_ms); + EXPECT_EQ(original_event.width(), logged_event.width); + EXPECT_EQ(original_event.height(), logged_event.height); + EXPECT_EQ(original_event.codec(), logged_event.codec); + EXPECT_EQ(original_event.qp(), logged_event.qp); +} + void EventVerifier::VerifyLoggedIceCandidatePairConfig( const RtcEventIceCandidatePairConfig& original_event, const LoggedIceCandidatePairConfig& logged_event) const { diff --git a/logging/rtc_event_log/rtc_event_log_unittest_helper.h b/logging/rtc_event_log/rtc_event_log_unittest_helper.h index 6f0a9c9afe..b289737ddb 100644 --- a/logging/rtc_event_log/rtc_event_log_unittest_helper.h +++ b/logging/rtc_event_log/rtc_event_log_unittest_helper.h @@ -25,6 +25,7 @@ #include "logging/rtc_event_log/events/rtc_event_bwe_update_loss_based.h" #include "logging/rtc_event_log/events/rtc_event_dtls_transport_state.h" #include "logging/rtc_event_log/events/rtc_event_dtls_writable_state.h" +#include "logging/rtc_event_log/events/rtc_event_frame_decoded.h" #include "logging/rtc_event_log/events/rtc_event_generic_ack_received.h" #include "logging/rtc_event_log/events/rtc_event_generic_packet_received.h" #include "logging/rtc_event_log/events/rtc_event_generic_packet_sent.h" @@ -71,6 +72,7 @@ class EventGenerator { std::unique_ptr NewBweUpdateLossBased(); std::unique_ptr NewDtlsTransportState(); std::unique_ptr NewDtlsWritableState(); + std::unique_ptr NewFrameDecodedEvent(); std::unique_ptr NewGenericAckReceived(); std::unique_ptr NewGenericPacketReceived(); std::unique_ptr NewGenericPacketSent(); @@ -189,6 +191,9 @@ class EventVerifier { const RtcEventDtlsWritableState& original_event, const LoggedDtlsWritableState& logged_event) const; + void VerifyLoggedFrameDecoded(const RtcEventFrameDecoded& original_event, + const LoggedFrameDecoded& logged_event) const; + void VerifyLoggedIceCandidatePairConfig( const RtcEventIceCandidatePairConfig& original_event, const LoggedIceCandidatePairConfig& logged_event) const;