Add logging of decoded video frames.

This CL adds the possibility to log metainformation about
decoded frames in RTC event log, including encoding parsing
and tests. It will be wired up in a followup CL.


Bug: webrtc:8802
Change-Id: Ied598b266513d0f63fce0484d741af1782607e74
Reviewed-on: https://webrtc-review.googlesource.com/c/src/+/181061
Reviewed-by: Christoffer Rodbro <crodbro@webrtc.org>
Reviewed-by: Artem Titov <titovartem@webrtc.org>
Commit-Queue: Björn Terelius <terelius@webrtc.org>
Cr-Commit-Position: refs/heads/master@{#31873}
This commit is contained in:
Björn Terelius
2020-08-06 12:37:08 +02:00
committed by Commit Bot
parent 82eb3cf4b5
commit 00c12f6779
15 changed files with 583 additions and 27 deletions

View File

@ -52,7 +52,8 @@ class RtcEvent {
VideoSendStreamConfig,
GenericPacketSent,
GenericPacketReceived,
GenericAckReceived
GenericAckReceived,
FrameDecoded
};
RtcEvent();

View File

@ -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",

View File

@ -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 "";
}

View File

@ -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<const RtcEventBweUpdateLossBased*> bwe_loss_based_updates;
std::vector<const RtcEventDtlsTransportState*> dtls_transport_states;
std::vector<const RtcEventDtlsWritableState*> dtls_writable_states;
std::vector<const RtcEventFrameDecoded*> frames_decoded;
std::vector<const RtcEventGenericAckReceived*> generic_acks_received;
std::vector<const RtcEventGenericPacketReceived*> generic_packets_received;
std::vector<const RtcEventGenericPacketSent*> 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<const RtcEventFrameDecoded* const>(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<const RtcEventFrameDecoded*> 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<absl::optional<uint64_t>> 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<uint64_t>(ConvertToProtoFormat(event->codec()));
}
encoded_deltas = EncodeDeltas(
static_cast<uint64_t>(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<const RtcEventGenericPacketSent*> batch,
rtclog2::EventStream* event_stream) {

View File

@ -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<const RtcEventDtlsWritableState*> batch,
rtclog2::EventStream* event_stream);
void EncodeFramesDecoded(rtc::ArrayView<const RtcEventFrameDecoded*> batch,
rtclog2::EventStream* event_stream);
void EncodeGenericAcksReceived(
rtc::ArrayView<const RtcEventGenericAckReceived*> batch,
rtclog2::EventStream* event_stream);

View File

@ -630,6 +630,35 @@ TEST_P(RtcEventLogEncoderTest, RtcEventDtlsWritableState) {
}
}
TEST_P(RtcEventLogEncoderTest, RtcEventFrameDecoded) {
std::vector<std::unique_ptr<RtcEventFrameDecoded>> 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<RtcEventIceCandidatePairConfig> event =

View File

@ -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> RtcEventFrameDecoded::Copy() const {
return absl::WrapUnique<RtcEventFrameDecoded>(
new RtcEventFrameDecoded(*this));
}
} // namespace webrtc

View File

@ -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 <stdint.h>
#include <memory>
#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<RtcEventFrameDecoded> 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_

View File

@ -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; }

View File

@ -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;

View File

@ -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<uint64_t>(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<uint8_t>(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<absl::optional<uint64_t>> 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<absl::optional<uint64_t>> 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<absl::optional<uint64_t>> 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<absl::optional<uint64_t>> 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<absl::optional<uint64_t>> 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<absl::optional<uint64_t>> codec_values =
DecodeDeltas(proto.codec_deltas(), static_cast<uint64_t>(proto.codec()),
number_of_deltas);
RTC_PARSE_CHECK_OR_RETURN_EQ(codec_values.size(), number_of_deltas);
// qp
std::vector<absl::optional<uint64_t>> 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(), &timestamp_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<uint32_t>::max());
frame.ssrc = static_cast<uint32_t>(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<rtclog2::FrameDecodedEvents::Codec>(
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<uint8_t>::max());
frame.qp = static_cast<uint8_t>(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<absl::optional<uint64_t>> payload_length_values =
DecodeDeltas(proto.payload_length_deltas(),
ToUnsigned(proto.payload_length()), number_of_deltas);
std::vector<absl::optional<uint64_t>> 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<absl::optional<uint64_t>> padding_length_values =
DecodeDeltas(proto.padding_length_deltas(),
ToUnsigned(proto.padding_length()), number_of_deltas);
std::vector<absl::optional<uint64_t>> 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;

View File

@ -611,6 +611,11 @@ class ParsedRtcEventLog {
return generic_acks_received_;
}
// Media
const std::vector<LoggedFrameDecoded>& 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<LoggedDtlsTransportState> dtls_transport_states_;
std::vector<LoggedDtlsWritableState> dtls_writable_states_;
std::vector<LoggedFrameDecoded> decoded_frames_;
std::vector<LoggedIceCandidatePairConfig> ice_candidate_pair_configs_;
std::vector<LoggedIceCandidatePairEvent> ice_candidate_pair_events_;

View File

@ -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<std::unique_ptr<RtcEventDtlsWritableState>>
dtls_writable_state_list_;
std::vector<std::unique_ptr<RtcEventFrameDecoded>> frame_decoded_event_list_;
std::vector<std::unique_ptr<RtcEventGenericAckReceived>>
generic_acks_received_;
std::vector<std::unique_ptr<RtcEventGenericPacketReceived>>
@ -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);

View File

@ -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<RtcEventDtlsWritableState>(writable);
}
std::unique_ptr<RtcEventFrameDecoded> 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<uint32_t>();
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<uint8_t>();
return std::make_unique<RtcEventFrameDecoded>(render_time_ms, ssrc, width,
height, codec, qp);
}
std::unique_ptr<RtcEventProbeClusterCreated>
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 {

View File

@ -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<RtcEventBweUpdateLossBased> NewBweUpdateLossBased();
std::unique_ptr<RtcEventDtlsTransportState> NewDtlsTransportState();
std::unique_ptr<RtcEventDtlsWritableState> NewDtlsWritableState();
std::unique_ptr<RtcEventFrameDecoded> NewFrameDecodedEvent();
std::unique_ptr<RtcEventGenericAckReceived> NewGenericAckReceived();
std::unique_ptr<RtcEventGenericPacketReceived> NewGenericPacketReceived();
std::unique_ptr<RtcEventGenericPacketSent> 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;