Add new event type to RtcEventLog

Alr state is now logged by the pacer. To avoid confusion,
loopback tools will now create two separate rtc event
logs for sender and receiver calls.

Bug: webrtc:8287, webrtc:8588
Change-Id: Ib3e47d109c3a65a7ed069b9a613e6a08fe6a2f30
Reviewed-on: https://webrtc-review.googlesource.com/26880
Reviewed-by: Erik Språng <sprang@webrtc.org>
Reviewed-by: Björn Terelius <terelius@webrtc.org>
Reviewed-by: Philip Eliasson <philipel@webrtc.org>
Commit-Queue: Ilya Nikolaevskiy <ilnik@webrtc.org>
Cr-Commit-Position: refs/heads/master@{#21084}
This commit is contained in:
Ilya Nikolaevskiy
2017-12-05 13:19:45 +01:00
committed by Commit Bot
parent 095c25d05a
commit a4259f6b66
22 changed files with 236 additions and 26 deletions

View File

@ -25,6 +25,8 @@ group("logging") {
rtc_source_set("rtc_event_log_api") {
sources = [
"rtc_event_log/events/rtc_event.h",
"rtc_event_log/events/rtc_event_alr_state.cc",
"rtc_event_log/events/rtc_event_alr_state.h",
"rtc_event_log/events/rtc_event_audio_network_adaptation.cc",
"rtc_event_log/events/rtc_event_audio_network_adaptation.h",
"rtc_event_log/events/rtc_event_audio_playout.cc",

View File

@ -10,6 +10,7 @@
#include "logging/rtc_event_log/encoder/rtc_event_log_encoder_legacy.h"
#include "logging/rtc_event_log/events/rtc_event_alr_state.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"
@ -114,6 +115,11 @@ std::string RtcEventLogEncoderLegacy::Encode(const RtcEvent& event) {
return EncodeAudioNetworkAdaptation(rtc_event);
}
case RtcEvent::Type::AlrStateEvent: {
auto& rtc_event = static_cast<const RtcEventAlrState&>(event);
return EncodeAlrState(rtc_event);
}
case RtcEvent::Type::AudioPlayout: {
auto& rtc_event = static_cast<const RtcEventAudioPlayout&>(event);
return EncodeAudioPlayout(rtc_event);
@ -204,6 +210,17 @@ std::string RtcEventLogEncoderLegacy::Encode(const RtcEvent& event) {
return "";
}
std::string RtcEventLogEncoderLegacy::EncodeAlrState(
const RtcEventAlrState& event) {
rtclog::Event rtclog_event;
rtclog_event.set_timestamp_us(event.timestamp_us_);
rtclog_event.set_type(rtclog::Event::ALR_STATE_EVENT);
auto alr_state = rtclog_event.mutable_alr_state();
alr_state->set_in_alr(event.in_alr_);
return Serialize(&rtclog_event);
}
std::string RtcEventLogEncoderLegacy::EncodeAudioNetworkAdaptation(
const RtcEventAudioNetworkAdaptation& event) {
rtclog::Event rtclog_event;

View File

@ -42,6 +42,7 @@ class RtcEventRtpPacketIncoming;
class RtcEventRtpPacketOutgoing;
class RtcEventVideoReceiveStreamConfig;
class RtcEventVideoSendStreamConfig;
class RtcEventAlrState;
class RtpPacket;
class RtcEventLogEncoderLegacy final : public RtcEventLogEncoder {
@ -52,6 +53,7 @@ class RtcEventLogEncoderLegacy final : public RtcEventLogEncoder {
private:
// Encoding entry-point for the various RtcEvent subclasses.
std::string EncodeAlrState(const RtcEventAlrState& event);
std::string EncodeAudioNetworkAdaptation(
const RtcEventAudioNetworkAdaptation& event);
std::string EncodeAudioPlayout(const RtcEventAudioPlayout& event);

View File

@ -30,6 +30,7 @@ class RtcEvent {
// superclass, but the *actual* information - rtclog::StreamConfig, etc. -
// is kept separate.
enum class Type {
AlrStateEvent,
AudioNetworkAdaptation,
AudioPlayout,
AudioReceiveStreamConfig,

View File

@ -0,0 +1,27 @@
/*
* Copyright (c) 2017 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_alr_state.h"
namespace webrtc {
RtcEventAlrState::RtcEventAlrState(bool in_alr) : in_alr_(in_alr) {}
RtcEventAlrState::~RtcEventAlrState() = default;
RtcEvent::Type RtcEventAlrState::GetType() const {
return RtcEvent::Type::AlrStateEvent;
}
bool RtcEventAlrState::IsConfigEvent() const {
return false;
}
} // namespace webrtc

View File

@ -0,0 +1,33 @@
/*
* Copyright (c) 2017 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_ALR_STATE_H_
#define LOGGING_RTC_EVENT_LOG_EVENTS_RTC_EVENT_ALR_STATE_H_
#include "logging/rtc_event_log/events/rtc_event.h"
#include "typedefs.h" // NOLINT(build/include)
namespace webrtc {
class RtcEventAlrState final : public RtcEvent {
public:
explicit RtcEventAlrState(bool in_alr);
~RtcEventAlrState() override;
Type GetType() const override;
bool IsConfigEvent() const override;
const bool in_alr_;
};
} // namespace webrtc
#endif // LOGGING_RTC_EVENT_LOG_EVENTS_RTC_EVENT_ALR_STATE_H_

View File

@ -40,6 +40,7 @@ message Event {
AUDIO_NETWORK_ADAPTATION_EVENT = 16;
BWE_PROBE_CLUSTER_CREATED_EVENT = 17;
BWE_PROBE_RESULT_EVENT = 18;
ALR_STATE_EVENT = 19;
}
// required - Indicates the type of this event
@ -81,6 +82,9 @@ message Event {
// required if type == BWE_PROBE_RESULT_EVENT
BweProbeResult probe_result = 18;
// required if type == ALR_STATE_EVENT
AlrState alr_state = 19;
}
}
@ -314,3 +318,8 @@ message BweProbeResult {
// optional - but required if result == SUCCESS. The resulting bitrate in bps.
optional uint64 bitrate_bps = 3;
}
message AlrState {
// required - If we are in ALR or not.
optional bool in_alr = 1;
}

View File

@ -164,6 +164,8 @@ std::string EventTypeToString(webrtc::rtclog::Event::EventType event_type) {
return "BWE_PROBE_CREATED";
case webrtc::rtclog::Event::BWE_PROBE_RESULT_EVENT:
return "BWE_PROBE_RESULT";
case webrtc::rtclog::Event::ALR_STATE_EVENT:
return "ALR_STATE_EVENT";
}
RTC_NOTREACHED();
return "UNKNOWN_EVENT";

View File

@ -785,6 +785,17 @@ int main(int argc, char* argv[]) {
event_recognized = true;
break;
}
case webrtc::ParsedRtcEventLog::ALR_STATE_EVENT: {
if (FLAG_bwe) {
webrtc::ParsedRtcEventLog::AlrStateEvent alr_state =
parsed_stream.GetAlrState(i);
std::cout << parsed_stream.GetTimestamp(i) << "\tALR_STATE"
<< "\tin_alr=" << alr_state.in_alr << std::endl;
}
event_recognized = true;
break;
}
}
if (!event_recognized) {

View File

@ -74,6 +74,8 @@ ParsedRtcEventLog::EventType GetRuntimeEventType(
return ParsedRtcEventLog::EventType::BWE_PROBE_CLUSTER_CREATED_EVENT;
case rtclog::Event::BWE_PROBE_RESULT_EVENT:
return ParsedRtcEventLog::EventType::BWE_PROBE_RESULT_EVENT;
case rtclog::Event::ALR_STATE_EVENT:
return ParsedRtcEventLog::EventType::ALR_STATE_EVENT;
}
return ParsedRtcEventLog::EventType::UNKNOWN_EVENT;
}
@ -652,6 +654,22 @@ ParsedRtcEventLog::BweProbeResultEvent ParsedRtcEventLog::GetBweProbeResult(
return res;
}
ParsedRtcEventLog::AlrStateEvent ParsedRtcEventLog::GetAlrState(
size_t index) const {
RTC_CHECK_LT(index, GetNumberOfEvents());
const rtclog::Event& event = events_[index];
RTC_CHECK(event.has_type());
RTC_CHECK_EQ(event.type(), rtclog::Event::ALR_STATE_EVENT);
RTC_CHECK(event.has_alr_state());
const rtclog::AlrState& alr_event = event.alr_state();
AlrStateEvent res;
res.timestamp = GetTimestamp(index);
RTC_CHECK(alr_event.has_in_alr());
res.in_alr = alr_event.in_alr();
return res;
}
// Returns the MediaType for registered SSRCs. Search from the end to use last
// registered types first.
ParsedRtcEventLog::MediaType ParsedRtcEventLog::GetMediaType(

View File

@ -65,6 +65,11 @@ class ParsedRtcEventLog {
BandwidthUsage detector_state;
};
struct AlrStateEvent {
uint64_t timestamp;
bool in_alr;
};
enum EventType {
UNKNOWN_EVENT = 0,
LOG_START = 1,
@ -80,7 +85,8 @@ class ParsedRtcEventLog {
AUDIO_SENDER_CONFIG_EVENT = 11,
AUDIO_NETWORK_ADAPTATION_EVENT = 16,
BWE_PROBE_CLUSTER_CREATED_EVENT = 17,
BWE_PROBE_RESULT_EVENT = 18
BWE_PROBE_RESULT_EVENT = 18,
ALR_STATE_EVENT = 19
};
enum class MediaType { ANY, AUDIO, VIDEO, DATA };
@ -180,6 +186,8 @@ class ParsedRtcEventLog {
MediaType GetMediaType(uint32_t ssrc, PacketDirection direction) const;
AlrStateEvent GetAlrState(size_t index) const;
private:
rtclog::StreamConfig GetVideoReceiveConfig(const rtclog::Event& event) const;
std::vector<rtclog::StreamConfig> GetVideoSendConfig(

View File

@ -12,9 +12,12 @@
#include <string>
#include "logging/rtc_event_log/events/rtc_event_alr_state.h"
#include "logging/rtc_event_log/rtc_event_log.h"
#include "rtc_base/checks.h"
#include "rtc_base/format_macros.h"
#include "rtc_base/logging.h"
#include "rtc_base/ptr_util.h"
#include "rtc_base/timeutils.h"
#include "system_wrappers/include/field_trial.h"
@ -26,11 +29,14 @@ const char AlrDetector::kStrictPacingAndProbingExperimentName[] =
"WebRTC-StrictPacingAndProbing";
const char kDefaultProbingScreenshareBweSettings[] = "1.0,2875,80,40,-60,3";
AlrDetector::AlrDetector()
AlrDetector::AlrDetector() : AlrDetector(nullptr) {}
AlrDetector::AlrDetector(RtcEventLog* event_log)
: bandwidth_usage_percent_(kDefaultAlrBandwidthUsagePercent),
alr_start_budget_level_percent_(kDefaultAlrStartBudgetLevelPercent),
alr_stop_budget_level_percent_(kDefaultAlrStopBudgetLevelPercent),
alr_budget_(0, true) {
alr_budget_(0, true),
event_log_(event_log) {
RTC_CHECK(
field_trial::FindFullName(kStrictPacingAndProbingExperimentName)
.empty() ||
@ -55,15 +61,21 @@ AlrDetector::~AlrDetector() {}
void AlrDetector::OnBytesSent(size_t bytes_sent, int64_t delta_time_ms) {
alr_budget_.UseBudget(bytes_sent);
alr_budget_.IncreaseBudget(delta_time_ms);
bool state_changed = false;
if (alr_budget_.budget_level_percent() > alr_start_budget_level_percent_ &&
!alr_started_time_ms_) {
alr_started_time_ms_.emplace(rtc::TimeMillis());
state_changed = true;
} else if (alr_budget_.budget_level_percent() <
alr_stop_budget_level_percent_ &&
alr_started_time_ms_) {
state_changed = true;
alr_started_time_ms_.reset();
}
if (event_log_ && state_changed) {
event_log_->Log(
rtc::MakeUnique<RtcEventAlrState>(alr_started_time_ms_.has_value()));
}
}
void AlrDetector::SetEstimatedBitrate(int bitrate_bps) {

View File

@ -20,6 +20,8 @@
namespace webrtc {
class RtcEventLog;
// Application limited region detector is a class that utilizes signals of
// elapsed time and bytes sent to estimate whether network traffic is
// currently limited by the application's ability to generate traffic.
@ -30,6 +32,7 @@ namespace webrtc {
class AlrDetector {
public:
AlrDetector();
explicit AlrDetector(RtcEventLog* event_log);
~AlrDetector();
void OnBytesSent(size_t bytes_sent, int64_t delta_time_ms);
@ -76,6 +79,8 @@ class AlrDetector {
IntervalBudget alr_budget_;
rtc::Optional<int64_t> alr_started_time_ms_;
RtcEventLog* event_log_;
};
} // namespace webrtc

View File

@ -58,7 +58,7 @@ PacedSender::PacedSender(const Clock* clock,
std::unique_ptr<PacketQueue> packets)
: clock_(clock),
packet_sender_(packet_sender),
alr_detector_(rtc::MakeUnique<AlrDetector>()),
alr_detector_(rtc::MakeUnique<AlrDetector>(event_log)),
paused_(false),
media_budget_(rtc::MakeUnique<IntervalBudget>(0)),
padding_budget_(rtc::MakeUnique<IntervalBudget>(0)),

View File

@ -522,6 +522,10 @@ EventLogAnalyzer::EventLogAnalyzer(const ParsedRtcEventLog& log)
bwe_probe_result_events_.push_back(parsed_log_.GetBweProbeResult(i));
break;
}
case ParsedRtcEventLog::ALR_STATE_EVENT: {
alr_state_events_.push_back(parsed_log_.GetAlrState(i));
break;
}
case ParsedRtcEventLog::UNKNOWN_EVENT: {
break;
}
@ -968,7 +972,8 @@ void EventLogAnalyzer::CreateFractionLossGraph(Plot* plot) {
void EventLogAnalyzer::CreateTotalBitrateGraph(
PacketDirection desired_direction,
Plot* plot,
bool show_detector_state) {
bool show_detector_state,
bool show_alr_state) {
struct TimestampSize {
TimestampSize(uint64_t t, size_t s) : timestamp(t), size(s) {}
uint64_t timestamp;
@ -1089,12 +1094,36 @@ void EventLogAnalyzer::CreateTotalBitrateGraph(
}
}
IntervalSeries alr_state("ALR", "#555555", IntervalSeries::kHorizontal);
bool previously_in_alr = false;
int64_t alr_start = 0;
for (auto& alr : alr_state_events_) {
float y = ToCallTime(alr.timestamp);
if (!previously_in_alr && alr.in_alr) {
alr_start = alr.timestamp;
previously_in_alr = true;
} else if (previously_in_alr && !alr.in_alr) {
float x = ToCallTime(alr_start);
alr_state.intervals.emplace_back(x, y);
previously_in_alr = false;
}
}
if (previously_in_alr) {
float x = ToCallTime(alr_start);
float y = ToCallTime(end_time_);
alr_state.intervals.emplace_back(x, y);
}
if (show_detector_state) {
plot->AppendIntervalSeries(std::move(overusing_series));
plot->AppendIntervalSeries(std::move(underusing_series));
plot->AppendIntervalSeries(std::move(normal_series));
}
if (show_alr_state) {
plot->AppendIntervalSeries(std::move(alr_state));
}
plot->AppendTimeSeries(std::move(loss_series));
plot->AppendTimeSeries(std::move(delay_series));
plot->AppendTimeSeries(std::move(created_series));

View File

@ -87,7 +87,8 @@ class EventLogAnalyzer {
void CreateTotalBitrateGraph(PacketDirection desired_direction,
Plot* plot,
bool show_detector_state = false);
bool show_detector_state = false,
bool show_alr_state = false);
void CreateStreamBitrateGraph(PacketDirection desired_direction, Plot* plot);
@ -201,6 +202,8 @@ class EventLogAnalyzer {
std::vector<std::unique_ptr<TriageNotification>> notifications_;
std::vector<ParsedRtcEventLog::AlrStateEvent> alr_state_events_;
// Window and step size used for calculating moving averages, e.g. bitrate.
// The generated data points will be |step_| microseconds apart.
// Only events occuring at most |window_duration_| microseconds before the

View File

@ -132,6 +132,10 @@ DEFINE_bool(show_detector_state,
"Show the state of the delay based BWE detector on the total "
"bitrate graph");
DEFINE_bool(show_alr_state,
false,
"Show the state ALR state on the total bitrate graph");
DEFINE_bool(
print_triage_notifications,
false,
@ -245,12 +249,14 @@ int main(int argc, char* argv[]) {
if (FLAG_plot_incoming_bitrate) {
analyzer.CreateTotalBitrateGraph(webrtc::PacketDirection::kIncomingPacket,
collection->AppendNewPlot(),
FLAG_show_detector_state);
FLAG_show_detector_state,
FLAG_show_alr_state);
}
if (FLAG_plot_outgoing_bitrate) {
analyzer.CreateTotalBitrateGraph(webrtc::PacketDirection::kOutgoingPacket,
collection->AppendNewPlot(),
FLAG_show_detector_state);
FLAG_show_detector_state,
FLAG_show_alr_state);
}
if (FLAG_plot_incoming_stream_bitrate) {
analyzer.CreateStreamBitrateGraph(webrtc::PacketDirection::kIncomingPacket,

View File

@ -103,8 +103,8 @@ void PythonPlot::Draw() {
}
// IntervalSeries
printf("interval_colors = ['#ff8e82','#5092fc','#c4ffc4']\n");
RTC_CHECK_LE(interval_list_.size(), 3);
printf("interval_colors = ['#ff8e82','#5092fc','#c4ffc4','#aaaaaa']\n");
RTC_CHECK_LE(interval_list_.size(), 4);
// To get the intervals to show up in the legend we have to create patches
// for them.
printf("legend_patches = []\n");

View File

@ -69,7 +69,10 @@ std::string Codec() {
return static_cast<std::string>(FLAG_codec);
}
DEFINE_string(rtc_event_log_name, "", "Filename for rtc event log.");
DEFINE_string(rtc_event_log_name,
"",
"Filename for rtc event log. Two files "
"with \"_send\" and \"_recv\" suffixes will be created.");
std::string RtcEventLogName() {
return static_cast<std::string>(FLAG_rtc_event_log_name);
}

View File

@ -133,7 +133,10 @@ int AvgPropagationDelayMs() {
return static_cast<int>(FLAG_avg_propagation_delay_ms);
}
DEFINE_string(rtc_event_log_name, "", "Filename for rtc event log.");
DEFINE_string(rtc_event_log_name,
"",
"Filename for rtc event log. Two files "
"with \"_send\" and \"_recv\" suffixes will be created.");
std::string RtcEventLogName() {
return static_cast<std::string>(FLAG_rtc_event_log_name);
}

View File

@ -1801,24 +1801,40 @@ void VideoQualityTest::RunWithAnalyzer(const Params& params) {
}
if (!params.logging.rtc_event_log_name.empty()) {
event_log_ = RtcEventLog::Create(clock_, RtcEventLog::EncodingType::Legacy);
std::unique_ptr<RtcEventLogOutputFile> output(
send_event_log_ =
RtcEventLog::Create(clock_, RtcEventLog::EncodingType::Legacy);
recv_event_log_ =
RtcEventLog::Create(clock_, RtcEventLog::EncodingType::Legacy);
std::unique_ptr<RtcEventLogOutputFile> send_output(
rtc::MakeUnique<RtcEventLogOutputFile>(
params.logging.rtc_event_log_name, RtcEventLog::kUnlimitedOutput));
bool event_log_started = event_log_->StartLogging(
std::move(output), RtcEventLog::kImmediateOutput);
params.logging.rtc_event_log_name + "_send",
RtcEventLog::kUnlimitedOutput));
std::unique_ptr<RtcEventLogOutputFile> recv_output(
rtc::MakeUnique<RtcEventLogOutputFile>(
params.logging.rtc_event_log_name + "_recv",
RtcEventLog::kUnlimitedOutput));
bool event_log_started =
send_event_log_->StartLogging(std::move(send_output),
RtcEventLog::kImmediateOutput) &&
recv_event_log_->StartLogging(std::move(recv_output),
RtcEventLog::kImmediateOutput);
RTC_DCHECK(event_log_started);
} else {
send_event_log_ = RtcEventLog::CreateNull();
recv_event_log_ = RtcEventLog::CreateNull();
}
Call::Config call_config(event_log_.get());
call_config.bitrate_config = params.call.call_bitrate_config;
Call::Config send_call_config(send_event_log_.get());
Call::Config recv_call_config(recv_event_log_.get());
send_call_config.bitrate_config = params.call.call_bitrate_config;
recv_call_config.bitrate_config = params.call.call_bitrate_config;
task_queue_.SendTask(
[this, &call_config, &send_transport, &recv_transport]() {
CreateCalls(call_config, call_config);
send_transport = CreateSendTransport();
recv_transport = CreateReceiveTransport();
});
task_queue_.SendTask([this, &send_call_config, &recv_call_config,
&send_transport, &recv_transport]() {
CreateCalls(send_call_config, recv_call_config);
send_transport = CreateSendTransport();
recv_transport = CreateReceiveTransport();
});
std::string graph_title = params_.analyzer.graph_title;
if (graph_title.empty())

View File

@ -161,6 +161,9 @@ class VideoQualityTest : public test::CallTest {
VideoSendStream::DegradationPreference degradation_preference_ =
VideoSendStream::DegradationPreference::kMaintainFramerate;
Params params_;
std::unique_ptr<webrtc::RtcEventLog> recv_event_log_;
std::unique_ptr<webrtc::RtcEventLog> send_event_log_;
};
} // namespace webrtc