diff --git a/webrtc/BUILD.gn b/webrtc/BUILD.gn index f31eae11f6..48fbebbe36 100644 --- a/webrtc/BUILD.gn +++ b/webrtc/BUILD.gn @@ -358,7 +358,7 @@ if (rtc_enable_protobuf) { configs += [ ":common_config" ] public_configs = [ ":common_inherited_config" ] - deps = [ + public_deps = [ ":rtc_event_log_proto", ":webrtc_common", ] diff --git a/webrtc/tools/BUILD.gn b/webrtc/tools/BUILD.gn index 2d095636df..abf0ca0482 100644 --- a/webrtc/tools/BUILD.gn +++ b/webrtc/tools/BUILD.gn @@ -171,6 +171,36 @@ source_set("agc_test_utils") { # Exclude tools depending on gflags since that's not available in Chromium. if (rtc_include_tests) { + if (rtc_enable_protobuf) { + executable("event_log_visualizer") { + sources = [ + "event_log_visualizer/analyzer.cc", + "event_log_visualizer/analyzer.h", + "event_log_visualizer/generate_timeseries.cc", + "event_log_visualizer/plot_base.h", + "event_log_visualizer/plot_python.cc", + "event_log_visualizer/plot_python.h", + ] + + configs += [ "..:common_config" ] + public_configs = [ "..:common_inherited_config" ] + + if (is_clang && !is_nacl) { + # Suppress warnings from the Chromium Clang plugin. + # See http://code.google.com/p/webrtc/issues/detail?id=163 for details. + configs -= [ "//build/config/clang:find_bad_constructs" ] + } + + defines = [ "ENABLE_RTC_EVENT_LOG" ] + deps = [ + "../:rtc_event_log_parser", + "../modules/rtp_rtcp:rtp_rtcp", + "../system_wrappers:system_wrappers_default", + "//third_party/gflags", + ] + } + } + executable("agc_harness") { testonly = true sources = [ diff --git a/webrtc/tools/DEPS b/webrtc/tools/DEPS index 73073f02f4..33df89fe2d 100644 --- a/webrtc/tools/DEPS +++ b/webrtc/tools/DEPS @@ -1,7 +1,9 @@ include_rules = [ "+webrtc/base", + "+webrtc/call", "+webrtc/common_video", "+webrtc/modules/audio_processing", + "+webrtc/modules/rtp_rtcp", "+webrtc/system_wrappers", "+webrtc/voice_engine", ] diff --git a/webrtc/tools/event_log_visualizer/analyzer.cc b/webrtc/tools/event_log_visualizer/analyzer.cc new file mode 100644 index 0000000000..05d94ee063 --- /dev/null +++ b/webrtc/tools/event_log_visualizer/analyzer.cc @@ -0,0 +1,710 @@ +/* + * Copyright (c) 2016 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 "webrtc/tools/event_log_visualizer/analyzer.h" + +#include +#include +#include +#include +#include +#include + +#include "webrtc/audio_receive_stream.h" +#include "webrtc/audio_send_stream.h" +#include "webrtc/base/checks.h" +#include "webrtc/call.h" +#include "webrtc/common_types.h" +#include "webrtc/modules/rtp_rtcp/include/rtp_rtcp.h" +#include "webrtc/modules/rtp_rtcp/include/rtp_rtcp_defines.h" +#include "webrtc/modules/rtp_rtcp/source/rtp_utility.h" +#include "webrtc/video_receive_stream.h" +#include "webrtc/video_send_stream.h" + +namespace { + +std::string SsrcToString(uint32_t ssrc) { + std::stringstream ss; + ss << "SSRC " << ssrc; + return ss.str(); +} + +// Checks whether an SSRC is contained in the list of desired SSRCs. +// Note that an empty SSRC list matches every SSRC. +bool MatchingSsrc(uint32_t ssrc, const std::vector& desired_ssrc) { + if (desired_ssrc.size() == 0) + return true; + return std::find(desired_ssrc.begin(), desired_ssrc.end(), ssrc) != + desired_ssrc.end(); +} + +double AbsSendTimeToMicroseconds(int64_t abs_send_time) { + // The timestamp is a fixed point representation with 6 bits for seconds + // and 18 bits for fractions of a second. Thus, we divide by 2^18 to get the + // time in seconds and then multiply by 1000000 to convert to microseconds. + static constexpr double kTimestampToMicroSec = + 1000000.0 / static_cast(1 << 18); + return abs_send_time * kTimestampToMicroSec; +} + +// Computes the difference |later| - |earlier| where |later| and |earlier| +// are counters that wrap at |modulus|. The difference is chosen to have the +// least absolute value. For example if |modulus| is 8, then the difference will +// be chosen in the range [-3, 4]. If |modulus| is 9, then the difference will +// be in [-4, 4]. +int64_t WrappingDifference(uint32_t later, uint32_t earlier, int64_t modulus) { + RTC_DCHECK_LE(1, modulus); + RTC_DCHECK_LT(later, modulus); + RTC_DCHECK_LT(earlier, modulus); + int64_t difference = + static_cast(later) - static_cast(earlier); + int64_t max_difference = modulus / 2; + int64_t min_difference = max_difference - modulus + 1; + if (difference > max_difference) { + difference -= modulus; + } + if (difference < min_difference) { + difference += modulus; + } + return difference; +} + +class StreamId { + public: + StreamId(uint32_t ssrc, + webrtc::PacketDirection direction, + webrtc::MediaType media_type) + : ssrc_(ssrc), direction_(direction), media_type_(media_type) {} + + bool operator<(const StreamId& other) const { + if (ssrc_ < other.ssrc_) { + return true; + } + if (ssrc_ == other.ssrc_) { + if (media_type_ < other.media_type_) { + return true; + } + if (media_type_ == other.media_type_) { + if (direction_ < other.direction_) { + return true; + } + } + } + return false; + } + + bool operator==(const StreamId& other) const { + return ssrc_ == other.ssrc_ && direction_ == other.direction_ && + media_type_ == other.media_type_; + } + + uint32_t GetSsrc() const { return ssrc_; } + + private: + uint32_t ssrc_; + webrtc::PacketDirection direction_; + webrtc::MediaType media_type_; +}; + +const double kXMargin = 1.02; +const double kYMargin = 1.1; +const double kDefaultXMin = -1; +const double kDefaultYMin = -1; + +} // namespace + +namespace webrtc { +namespace plotting { + +EventLogAnalyzer::EventLogAnalyzer(const ParsedRtcEventLog& log) + : parsed_log_(log), window_duration_(250000), step_(10000) { + uint64_t first_timestamp = std::numeric_limits::max(); + uint64_t last_timestamp = std::numeric_limits::min(); + for (size_t i = 0; i < parsed_log_.GetNumberOfEvents(); i++) { + ParsedRtcEventLog::EventType event_type = parsed_log_.GetEventType(i); + if (event_type == ParsedRtcEventLog::EventType::VIDEO_RECEIVER_CONFIG_EVENT) + continue; + if (event_type == ParsedRtcEventLog::EventType::VIDEO_SENDER_CONFIG_EVENT) + continue; + if (event_type == ParsedRtcEventLog::EventType::AUDIO_RECEIVER_CONFIG_EVENT) + continue; + if (event_type == ParsedRtcEventLog::EventType::AUDIO_SENDER_CONFIG_EVENT) + continue; + uint64_t timestamp = parsed_log_.GetTimestamp(i); + first_timestamp = std::min(first_timestamp, timestamp); + last_timestamp = std::max(last_timestamp, timestamp); + } + if (last_timestamp < first_timestamp) { + // No useful events in the log. + first_timestamp = last_timestamp = 0; + } + begin_time_ = first_timestamp; + end_time_ = last_timestamp; +} + +void EventLogAnalyzer::CreatePacketGraph(PacketDirection desired_direction, + Plot* plot) { + std::map time_series; + + PacketDirection direction; + MediaType media_type; + uint8_t header[IP_PACKET_SIZE]; + size_t header_length, total_length; + float max_y = 0; + + for (size_t i = 0; i < parsed_log_.GetNumberOfEvents(); i++) { + ParsedRtcEventLog::EventType event_type = parsed_log_.GetEventType(i); + if (event_type == ParsedRtcEventLog::RTP_EVENT) { + parsed_log_.GetRtpHeader(i, &direction, &media_type, header, + &header_length, &total_length); + if (direction == desired_direction) { + // Parse header to get SSRC. + RtpUtility::RtpHeaderParser rtp_parser(header, header_length); + RTPHeader parsed_header; + rtp_parser.Parse(&parsed_header); + // Filter on SSRC. + if (MatchingSsrc(parsed_header.ssrc, desired_ssrc_)) { + uint64_t timestamp = parsed_log_.GetTimestamp(i); + float x = static_cast(timestamp - begin_time_) / 1000000; + float y = total_length; + max_y = std::max(max_y, y); + time_series[parsed_header.ssrc].points.push_back( + TimeSeriesPoint(x, y)); + } + } + } + } + + // Set labels and put in graph. + for (auto& kv : time_series) { + kv.second.label = SsrcToString(kv.first); + kv.second.style = BAR_GRAPH; + plot->series.push_back(std::move(kv.second)); + } + + plot->xaxis_min = kDefaultXMin; + plot->xaxis_max = (end_time_ - begin_time_) / 1000000 * kXMargin; + plot->xaxis_label = "Time (s)"; + plot->yaxis_min = kDefaultYMin; + plot->yaxis_max = max_y * kYMargin; + plot->yaxis_label = "Packet size (bytes)"; + if (desired_direction == webrtc::PacketDirection::kIncomingPacket) { + plot->title = "Incoming RTP packets"; + } else if (desired_direction == webrtc::PacketDirection::kOutgoingPacket) { + plot->title = "Outgoing RTP packets"; + } +} + +// For each SSRC, plot the time between the consecutive playouts. +void EventLogAnalyzer::CreatePlayoutGraph(Plot* plot) { + std::map time_series; + std::map last_playout; + + uint32_t ssrc; + float max_y = 0; + + for (size_t i = 0; i < parsed_log_.GetNumberOfEvents(); i++) { + ParsedRtcEventLog::EventType event_type = parsed_log_.GetEventType(i); + if (event_type == ParsedRtcEventLog::AUDIO_PLAYOUT_EVENT) { + parsed_log_.GetAudioPlayout(i, &ssrc); + uint64_t timestamp = parsed_log_.GetTimestamp(i); + if (MatchingSsrc(ssrc, desired_ssrc_)) { + float x = static_cast(timestamp - begin_time_) / 1000000; + float y = static_cast(timestamp - last_playout[ssrc]) / 1000; + if (time_series[ssrc].points.size() == 0) { + // There were no previusly logged playout for this SSRC. + // Generate a point, but place it on the x-axis. + y = 0; + } + max_y = std::max(max_y, y); + time_series[ssrc].points.push_back(TimeSeriesPoint(x, y)); + last_playout[ssrc] = timestamp; + } + } + } + + // Set labels and put in graph. + for (auto& kv : time_series) { + kv.second.label = SsrcToString(kv.first); + kv.second.style = BAR_GRAPH; + plot->series.push_back(std::move(kv.second)); + } + + plot->xaxis_min = kDefaultXMin; + plot->xaxis_max = (end_time_ - begin_time_) / 1000000 * kXMargin; + plot->xaxis_label = "Time (s)"; + plot->yaxis_min = kDefaultYMin; + plot->yaxis_max = max_y * kYMargin; + plot->yaxis_label = "Time since last playout (ms)"; + plot->title = "Audio playout"; +} + +// For each SSRC, plot the time between the consecutive playouts. +void EventLogAnalyzer::CreateSequenceNumberGraph(Plot* plot) { + std::map time_series; + std::map last_seqno; + + PacketDirection direction; + MediaType media_type; + uint8_t header[IP_PACKET_SIZE]; + size_t header_length, total_length; + + int max_y = 1; + int min_y = 0; + + for (size_t i = 0; i < parsed_log_.GetNumberOfEvents(); i++) { + ParsedRtcEventLog::EventType event_type = parsed_log_.GetEventType(i); + if (event_type == ParsedRtcEventLog::RTP_EVENT) { + parsed_log_.GetRtpHeader(i, &direction, &media_type, header, + &header_length, &total_length); + uint64_t timestamp = parsed_log_.GetTimestamp(i); + if (direction == PacketDirection::kIncomingPacket) { + // Parse header to get SSRC. + RtpUtility::RtpHeaderParser rtp_parser(header, header_length); + RTPHeader parsed_header; + rtp_parser.Parse(&parsed_header); + // Filter on SSRC. + if (MatchingSsrc(parsed_header.ssrc, desired_ssrc_)) { + float x = static_cast(timestamp - begin_time_) / 1000000; + int y = WrappingDifference(parsed_header.sequenceNumber, + last_seqno[parsed_header.ssrc], 1ul << 16); + if (time_series[parsed_header.ssrc].points.size() == 0) { + // There were no previusly logged playout for this SSRC. + // Generate a point, but place it on the x-axis. + y = 0; + } + max_y = std::max(max_y, y); + min_y = std::min(min_y, y); + time_series[parsed_header.ssrc].points.push_back( + TimeSeriesPoint(x, y)); + last_seqno[parsed_header.ssrc] = parsed_header.sequenceNumber; + } + } + } + } + + // Set labels and put in graph. + for (auto& kv : time_series) { + kv.second.label = SsrcToString(kv.first); + kv.second.style = BAR_GRAPH; + plot->series.push_back(std::move(kv.second)); + } + + plot->xaxis_min = kDefaultXMin; + plot->xaxis_max = (end_time_ - begin_time_) / 1000000 * kXMargin; + plot->xaxis_label = "Time (s)"; + plot->yaxis_min = min_y - (kYMargin - 1) / 2 * (max_y - min_y); + plot->yaxis_max = max_y + (kYMargin - 1) / 2 * (max_y - min_y); + plot->yaxis_label = "Difference since last packet"; + plot->title = "Sequence number"; +} + +void EventLogAnalyzer::CreateDelayChangeGraph(Plot* plot) { + // Maps a stream identifier consisting of ssrc, direction and MediaType + // to the header extensions used by that stream, + std::map extension_maps; + + struct SendReceiveTime { + SendReceiveTime() = default; + SendReceiveTime(uint32_t send_time, uint64_t recv_time) + : absolute_send_time(send_time), receive_timestamp(recv_time) {} + uint32_t absolute_send_time; // 24-bit value in units of 2^-18 seconds. + uint64_t receive_timestamp; // In microseconds. + }; + std::map last_packet; + std::map time_series; + + PacketDirection direction; + MediaType media_type; + uint8_t header[IP_PACKET_SIZE]; + size_t header_length, total_length; + + double max_y = 10; + double min_y = 0; + + for (size_t i = 0; i < parsed_log_.GetNumberOfEvents(); i++) { + ParsedRtcEventLog::EventType event_type = parsed_log_.GetEventType(i); + if (event_type == ParsedRtcEventLog::VIDEO_RECEIVER_CONFIG_EVENT) { + VideoReceiveStream::Config config(nullptr); + parsed_log_.GetVideoReceiveConfig(i, &config); + StreamId stream(config.rtp.remote_ssrc, kIncomingPacket, + MediaType::VIDEO); + extension_maps[stream].Erase(); + for (size_t j = 0; j < config.rtp.extensions.size(); ++j) { + const std::string& extension = config.rtp.extensions[j].uri; + int id = config.rtp.extensions[j].id; + extension_maps[stream].Register(StringToRtpExtensionType(extension), + id); + } + } else if (event_type == ParsedRtcEventLog::VIDEO_SENDER_CONFIG_EVENT) { + VideoSendStream::Config config(nullptr); + parsed_log_.GetVideoSendConfig(i, &config); + for (auto ssrc : config.rtp.ssrcs) { + StreamId stream(ssrc, kIncomingPacket, MediaType::VIDEO); + extension_maps[stream].Erase(); + for (size_t j = 0; j < config.rtp.extensions.size(); ++j) { + const std::string& extension = config.rtp.extensions[j].uri; + int id = config.rtp.extensions[j].id; + extension_maps[stream].Register(StringToRtpExtensionType(extension), + id); + } + } + } else if (event_type == ParsedRtcEventLog::AUDIO_RECEIVER_CONFIG_EVENT) { + AudioReceiveStream::Config config; + // TODO(terelius): Parse the audio configs once we have them + } else if (event_type == ParsedRtcEventLog::AUDIO_SENDER_CONFIG_EVENT) { + AudioSendStream::Config config(nullptr); + // TODO(terelius): Parse the audio configs once we have them + } else if (event_type == ParsedRtcEventLog::RTP_EVENT) { + parsed_log_.GetRtpHeader(i, &direction, &media_type, header, + &header_length, &total_length); + if (direction == kIncomingPacket) { + // Parse header to get SSRC. + RtpUtility::RtpHeaderParser rtp_parser(header, header_length); + RTPHeader parsed_header; + rtp_parser.Parse(&parsed_header); + // Filter on SSRC. + if (MatchingSsrc(parsed_header.ssrc, desired_ssrc_)) { + StreamId stream(parsed_header.ssrc, direction, media_type); + // Look up the extension_map and parse it again to get the extensions. + if (extension_maps.count(stream) == 1) { + RtpHeaderExtensionMap* extension_map = &extension_maps[stream]; + rtp_parser.Parse(&parsed_header, extension_map); + if (parsed_header.extension.hasAbsoluteSendTime) { + uint64_t timestamp = parsed_log_.GetTimestamp(i); + int64_t send_time_diff = WrappingDifference( + parsed_header.extension.absoluteSendTime, + last_packet[stream].absolute_send_time, 1ul << 24); + int64_t recv_time_diff = + timestamp - last_packet[stream].receive_timestamp; + + float x = static_cast(timestamp - begin_time_) / 1000000; + double y = static_cast( + recv_time_diff - + AbsSendTimeToMicroseconds(send_time_diff)) / + 1000; + if (time_series[stream].points.size() == 0) { + // There were no previusly logged playout for this SSRC. + // Generate a point, but place it on the x-axis. + y = 0; + } + max_y = std::max(max_y, y); + min_y = std::min(min_y, y); + time_series[stream].points.push_back(TimeSeriesPoint(x, y)); + last_packet[stream] = SendReceiveTime( + parsed_header.extension.absoluteSendTime, timestamp); + } + } + } + } + } + } + + // Set labels and put in graph. + for (auto& kv : time_series) { + kv.second.label = SsrcToString(kv.first.GetSsrc()); + kv.second.style = BAR_GRAPH; + plot->series.push_back(std::move(kv.second)); + } + + plot->xaxis_min = kDefaultXMin; + plot->xaxis_max = (end_time_ - begin_time_) / 1000000 * kXMargin; + plot->xaxis_label = "Time (s)"; + plot->yaxis_min = min_y - (kYMargin - 1) / 2 * (max_y - min_y); + plot->yaxis_max = max_y + (kYMargin - 1) / 2 * (max_y - min_y); + plot->yaxis_label = "Latency change (ms)"; + plot->title = "Network latency change between consecutive packets"; +} + +void EventLogAnalyzer::CreateAccumulatedDelayChangeGraph(Plot* plot) { + // TODO(terelius): Refactor + + // Maps a stream identifier consisting of ssrc, direction and MediaType + // to the header extensions used by that stream. + std::map extension_maps; + + struct SendReceiveTime { + SendReceiveTime() = default; + SendReceiveTime(uint32_t send_time, uint64_t recv_time, double accumulated) + : absolute_send_time(send_time), + receive_timestamp(recv_time), + accumulated_delay(accumulated) {} + uint32_t absolute_send_time; // 24-bit value in units of 2^-18 seconds. + uint64_t receive_timestamp; // In microseconds. + double accumulated_delay; // In milliseconds. + }; + std::map last_packet; + std::map time_series; + + PacketDirection direction; + MediaType media_type; + uint8_t header[IP_PACKET_SIZE]; + size_t header_length, total_length; + + double max_y = 10; + double min_y = 0; + + for (size_t i = 0; i < parsed_log_.GetNumberOfEvents(); i++) { + ParsedRtcEventLog::EventType event_type = parsed_log_.GetEventType(i); + if (event_type == ParsedRtcEventLog::VIDEO_RECEIVER_CONFIG_EVENT) { + VideoReceiveStream::Config config(nullptr); + parsed_log_.GetVideoReceiveConfig(i, &config); + StreamId stream(config.rtp.remote_ssrc, kIncomingPacket, + MediaType::VIDEO); + extension_maps[stream].Erase(); + for (size_t j = 0; j < config.rtp.extensions.size(); ++j) { + const std::string& extension = config.rtp.extensions[j].uri; + int id = config.rtp.extensions[j].id; + extension_maps[stream].Register(StringToRtpExtensionType(extension), + id); + } + } else if (event_type == ParsedRtcEventLog::VIDEO_SENDER_CONFIG_EVENT) { + VideoSendStream::Config config(nullptr); + parsed_log_.GetVideoSendConfig(i, &config); + for (auto ssrc : config.rtp.ssrcs) { + StreamId stream(ssrc, kIncomingPacket, MediaType::VIDEO); + extension_maps[stream].Erase(); + for (size_t j = 0; j < config.rtp.extensions.size(); ++j) { + const std::string& extension = config.rtp.extensions[j].uri; + int id = config.rtp.extensions[j].id; + extension_maps[stream].Register(StringToRtpExtensionType(extension), + id); + } + } + } else if (event_type == ParsedRtcEventLog::AUDIO_RECEIVER_CONFIG_EVENT) { + AudioReceiveStream::Config config; + // TODO(terelius): Parse the audio configs once we have them + } else if (event_type == ParsedRtcEventLog::AUDIO_SENDER_CONFIG_EVENT) { + AudioSendStream::Config config(nullptr); + // TODO(terelius): Parse the audio configs once we have them + } else if (event_type == ParsedRtcEventLog::RTP_EVENT) { + parsed_log_.GetRtpHeader(i, &direction, &media_type, header, + &header_length, &total_length); + if (direction == kIncomingPacket) { + // Parse header to get SSRC. + RtpUtility::RtpHeaderParser rtp_parser(header, header_length); + RTPHeader parsed_header; + rtp_parser.Parse(&parsed_header); + // Filter on SSRC. + if (MatchingSsrc(parsed_header.ssrc, desired_ssrc_)) { + StreamId stream(parsed_header.ssrc, direction, media_type); + // Look up the extension_map and parse it again to get the extensions. + if (extension_maps.count(stream) == 1) { + RtpHeaderExtensionMap* extension_map = &extension_maps[stream]; + rtp_parser.Parse(&parsed_header, extension_map); + if (parsed_header.extension.hasAbsoluteSendTime) { + uint64_t timestamp = parsed_log_.GetTimestamp(i); + int64_t send_time_diff = WrappingDifference( + parsed_header.extension.absoluteSendTime, + last_packet[stream].absolute_send_time, 1ul << 24); + int64_t recv_time_diff = + timestamp - last_packet[stream].receive_timestamp; + + float x = static_cast(timestamp - begin_time_) / 1000000; + double y = last_packet[stream].accumulated_delay + + static_cast( + recv_time_diff - + AbsSendTimeToMicroseconds(send_time_diff)) / + 1000; + if (time_series[stream].points.size() == 0) { + // There were no previusly logged playout for this SSRC. + // Generate a point, but place it on the x-axis. + y = 0; + } + max_y = std::max(max_y, y); + min_y = std::min(min_y, y); + time_series[stream].points.push_back(TimeSeriesPoint(x, y)); + last_packet[stream] = SendReceiveTime( + parsed_header.extension.absoluteSendTime, timestamp, y); + } + } + } + } + } + } + + // Set labels and put in graph. + for (auto& kv : time_series) { + kv.second.label = SsrcToString(kv.first.GetSsrc()); + kv.second.style = LINE_GRAPH; + plot->series.push_back(std::move(kv.second)); + } + + plot->xaxis_min = kDefaultXMin; + plot->xaxis_max = (end_time_ - begin_time_) / 1000000 * kXMargin; + plot->xaxis_label = "Time (s)"; + plot->yaxis_min = min_y - (kYMargin - 1) / 2 * (max_y - min_y); + plot->yaxis_max = max_y + (kYMargin - 1) / 2 * (max_y - min_y); + plot->yaxis_label = "Latency change (ms)"; + plot->title = "Accumulated network latency change"; +} + +// Plot the total bandwidth used by all RTP streams. +void EventLogAnalyzer::CreateTotalBitrateGraph( + PacketDirection desired_direction, + Plot* plot) { + struct TimestampSize { + TimestampSize(uint64_t t, size_t s) : timestamp(t), size(s) {} + uint64_t timestamp; + size_t size; + }; + std::vector packets; + + PacketDirection direction; + size_t total_length; + + // Extract timestamps and sizes for the relevant packets. + for (size_t i = 0; i < parsed_log_.GetNumberOfEvents(); i++) { + ParsedRtcEventLog::EventType event_type = parsed_log_.GetEventType(i); + if (event_type == ParsedRtcEventLog::RTP_EVENT) { + parsed_log_.GetRtpHeader(i, &direction, nullptr, nullptr, nullptr, + &total_length); + if (direction == desired_direction) { + uint64_t timestamp = parsed_log_.GetTimestamp(i); + packets.push_back(TimestampSize(timestamp, total_length)); + } + } + } + + size_t window_index_begin = 0; + size_t window_index_end = 0; + size_t bytes_in_window = 0; + float max_y = 0; + + // Calculate a moving average of the bitrate and store in a TimeSeries. + plot->series.push_back(TimeSeries()); + for (uint64_t time = begin_time_; time < end_time_ + step_; time += step_) { + while (window_index_end < packets.size() && + packets[window_index_end].timestamp < time) { + bytes_in_window += packets[window_index_end].size; + window_index_end++; + } + while (window_index_begin < packets.size() && + packets[window_index_begin].timestamp < time - window_duration_) { + RTC_DCHECK_LE(packets[window_index_begin].size, bytes_in_window); + bytes_in_window -= packets[window_index_begin].size; + window_index_begin++; + } + float window_duration_in_seconds = + static_cast(window_duration_) / 1000000; + float x = static_cast(time - begin_time_) / 1000000; + float y = bytes_in_window * 8 / window_duration_in_seconds / 1000; + max_y = std::max(max_y, y); + plot->series.back().points.push_back(TimeSeriesPoint(x, y)); + } + + // Set labels. + if (desired_direction == webrtc::PacketDirection::kIncomingPacket) { + plot->series.back().label = "Incoming bitrate"; + } else if (desired_direction == webrtc::PacketDirection::kOutgoingPacket) { + plot->series.back().label = "Outgoing bitrate"; + } + plot->series.back().style = LINE_GRAPH; + + plot->xaxis_min = kDefaultXMin; + plot->xaxis_max = (end_time_ - begin_time_) / 1000000 * kXMargin; + plot->xaxis_label = "Time (s)"; + plot->yaxis_min = kDefaultYMin; + plot->yaxis_max = max_y * kYMargin; + plot->yaxis_label = "Bitrate (kbps)"; + if (desired_direction == webrtc::PacketDirection::kIncomingPacket) { + plot->title = "Incoming RTP bitrate"; + } else if (desired_direction == webrtc::PacketDirection::kOutgoingPacket) { + plot->title = "Outgoing RTP bitrate"; + } +} + +// For each SSRC, plot the bandwidth used by that stream. +void EventLogAnalyzer::CreateStreamBitrateGraph( + PacketDirection desired_direction, + Plot* plot) { + struct TimestampSize { + TimestampSize(uint64_t t, size_t s) : timestamp(t), size(s) {} + uint64_t timestamp; + size_t size; + }; + std::map > packets; + + PacketDirection direction; + MediaType media_type; + uint8_t header[IP_PACKET_SIZE]; + size_t header_length, total_length; + + // Extract timestamps and sizes for the relevant packets. + for (size_t i = 0; i < parsed_log_.GetNumberOfEvents(); i++) { + ParsedRtcEventLog::EventType event_type = parsed_log_.GetEventType(i); + if (event_type == ParsedRtcEventLog::RTP_EVENT) { + parsed_log_.GetRtpHeader(i, &direction, &media_type, header, + &header_length, &total_length); + if (direction == desired_direction) { + // Parse header to get SSRC. + RtpUtility::RtpHeaderParser rtp_parser(header, header_length); + RTPHeader parsed_header; + rtp_parser.Parse(&parsed_header); + // Filter on SSRC. + if (MatchingSsrc(parsed_header.ssrc, desired_ssrc_)) { + uint64_t timestamp = parsed_log_.GetTimestamp(i); + packets[parsed_header.ssrc].push_back( + TimestampSize(timestamp, total_length)); + } + } + } + } + + float max_y = 0; + + for (auto& kv : packets) { + size_t window_index_begin = 0; + size_t window_index_end = 0; + size_t bytes_in_window = 0; + + // Calculate a moving average of the bitrate and store in a TimeSeries. + plot->series.push_back(TimeSeries()); + for (uint64_t time = begin_time_; time < end_time_ + step_; time += step_) { + while (window_index_end < kv.second.size() && + kv.second[window_index_end].timestamp < time) { + bytes_in_window += kv.second[window_index_end].size; + window_index_end++; + } + while (window_index_begin < kv.second.size() && + kv.second[window_index_begin].timestamp < + time - window_duration_) { + RTC_DCHECK_LE(kv.second[window_index_begin].size, bytes_in_window); + bytes_in_window -= kv.second[window_index_begin].size; + window_index_begin++; + } + float window_duration_in_seconds = + static_cast(window_duration_) / 1000000; + float x = static_cast(time - begin_time_) / 1000000; + float y = bytes_in_window * 8 / window_duration_in_seconds / 1000; + max_y = std::max(max_y, y); + plot->series.back().points.push_back(TimeSeriesPoint(x, y)); + } + + // Set labels. + plot->series.back().label = SsrcToString(kv.first); + plot->series.back().style = LINE_GRAPH; + } + + plot->xaxis_min = kDefaultXMin; + plot->xaxis_max = (end_time_ - begin_time_) / 1000000 * kXMargin; + plot->xaxis_label = "Time (s)"; + plot->yaxis_min = kDefaultYMin; + plot->yaxis_max = max_y * kYMargin; + plot->yaxis_label = "Bitrate (kbps)"; + if (desired_direction == webrtc::PacketDirection::kIncomingPacket) { + plot->title = "Incoming bitrate per stream"; + } else if (desired_direction == webrtc::PacketDirection::kOutgoingPacket) { + plot->title = "Outgoing bitrate per stream"; + } +} + +} // namespace plotting +} // namespace webrtc diff --git a/webrtc/tools/event_log_visualizer/analyzer.h b/webrtc/tools/event_log_visualizer/analyzer.h new file mode 100644 index 0000000000..08fcd5c99f --- /dev/null +++ b/webrtc/tools/event_log_visualizer/analyzer.h @@ -0,0 +1,65 @@ +/* + * Copyright (c) 2016 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 WEBRTC_TOOLS_EVENT_LOG_VISUALIZER_ANALYZER_H_ +#define WEBRTC_TOOLS_EVENT_LOG_VISUALIZER_ANALYZER_H_ + +#include + +#include "webrtc/call/rtc_event_log_parser.h" +#include "webrtc/tools/event_log_visualizer/plot_base.h" + +namespace webrtc { +namespace plotting { + +class EventLogAnalyzer { + public: + // The EventLogAnalyzer keeps a reference to the ParsedRtcEventLog for the + // duration of its lifetime. The ParsedRtcEventLog must not be destroyed or + // modified while the EventLogAnalyzer is being used. + explicit EventLogAnalyzer(const ParsedRtcEventLog& log); + + void CreatePacketGraph(PacketDirection desired_direction, Plot* plot); + + void CreatePlayoutGraph(Plot* plot); + + void CreateSequenceNumberGraph(Plot* plot); + + void CreateDelayChangeGraph(Plot* plot); + + void CreateAccumulatedDelayChangeGraph(Plot* plot); + + void CreateTotalBitrateGraph(PacketDirection desired_direction, Plot* plot); + + void CreateStreamBitrateGraph(PacketDirection desired_direction, Plot* plot); + + private: + const ParsedRtcEventLog& parsed_log_; + + // A list of SSRCs we are interested in analysing. + // If left empty, all SSRCs will be considered relevant. + std::vector desired_ssrc_; + + // 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 + // current data point will be part of the average. + uint64_t window_duration_; + uint64_t step_; + + // First and last events of the log. + uint64_t begin_time_; + uint64_t end_time_; +}; + +} // namespace plotting +} // namespace webrtc + +#endif // WEBRTC_TOOLS_EVENT_LOG_VISUALIZER_ANALYZER_H_ diff --git a/webrtc/tools/event_log_visualizer/generate_timeseries.cc b/webrtc/tools/event_log_visualizer/generate_timeseries.cc new file mode 100644 index 0000000000..d2139475fa --- /dev/null +++ b/webrtc/tools/event_log_visualizer/generate_timeseries.cc @@ -0,0 +1,138 @@ +/* + * Copyright (c) 2016 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 + +#include "gflags/gflags.h" +#include "webrtc/call/rtc_event_log_parser.h" +#include "webrtc/tools/event_log_visualizer/analyzer.h" +#include "webrtc/tools/event_log_visualizer/plot_base.h" +#include "webrtc/tools/event_log_visualizer/plot_python.h" + +DEFINE_bool(incoming, true, "Plot statistics for incoming packets."); +DEFINE_bool(outgoing, true, "Plot statistics for outgoing packets."); +DEFINE_bool(plot_all, true, "Plot all different data types."); +DEFINE_bool(plot_packets, + false, + "Plot bar graph showing the size of each packet."); +DEFINE_bool(plot_audio_playout, + false, + "Plot bar graph showing the time between each audio playout."); +DEFINE_bool( + plot_sequence_number, + false, + "Plot the difference in sequence number between consecutive packets."); +DEFINE_bool( + plot_delay_change, + false, + "Plot the difference in 1-way path delay between consecutive packets."); +DEFINE_bool(plot_accumulated_delay_change, + false, + "Plot the accumulated 1-way path delay change, or the path delay " + "change compared to the first packet."); +DEFINE_bool(plot_total_bitrate, + false, + "Plot the total bitrate used by all streams."); +DEFINE_bool(plot_stream_bitrate, + false, + "Plot the bitrate used by each stream."); + +int main(int argc, char* argv[]) { + std::string program_name = argv[0]; + std::string usage = + "A tool for visualizing WebRTC event logs.\n" + "Example usage:\n" + + program_name + " | python\n" + "Run " + program_name + + " --help for a list of command line options\n"; + google::SetUsageMessage(usage); + google::ParseCommandLineFlags(&argc, &argv, true); + + if (argc != 2) { + // Print usage information. + std::cout << google::ProgramUsage(); + return 0; + } + + std::string filename = argv[1]; + + webrtc::ParsedRtcEventLog parsed_log; + + if (!parsed_log.ParseFile(filename)) { + std::cerr << "Could not parse the entire log file." << std::endl; + std::cerr << "Proceeding to analyze the first " + << parsed_log.GetNumberOfEvents() << " events in the file." + << std::endl; + } + + webrtc::plotting::EventLogAnalyzer analyzer(parsed_log); + std::unique_ptr collection( + new webrtc::plotting::PythonPlotCollection()); + + if (FLAGS_plot_all || FLAGS_plot_packets) { + if (FLAGS_incoming) { + analyzer.CreatePacketGraph(webrtc::PacketDirection::kIncomingPacket, + collection->append_new_plot()); + } + if (FLAGS_outgoing) { + analyzer.CreatePacketGraph(webrtc::PacketDirection::kOutgoingPacket, + collection->append_new_plot()); + } + } + + if (FLAGS_plot_all || FLAGS_plot_audio_playout) { + analyzer.CreatePlayoutGraph(collection->append_new_plot()); + } + + if (FLAGS_plot_all || FLAGS_plot_sequence_number) { + if (FLAGS_incoming) { + analyzer.CreateSequenceNumberGraph(collection->append_new_plot()); + } + } + + if (FLAGS_plot_all || FLAGS_plot_delay_change) { + if (FLAGS_incoming) { + analyzer.CreateDelayChangeGraph(collection->append_new_plot()); + } + } + + if (FLAGS_plot_all || FLAGS_plot_accumulated_delay_change) { + if (FLAGS_incoming) { + analyzer.CreateAccumulatedDelayChangeGraph(collection->append_new_plot()); + } + } + + if (FLAGS_plot_all || FLAGS_plot_total_bitrate) { + if (FLAGS_incoming) { + analyzer.CreateTotalBitrateGraph(webrtc::PacketDirection::kIncomingPacket, + collection->append_new_plot()); + } + if (FLAGS_outgoing) { + analyzer.CreateTotalBitrateGraph(webrtc::PacketDirection::kOutgoingPacket, + collection->append_new_plot()); + } + } + + if (FLAGS_plot_all || FLAGS_plot_stream_bitrate) { + if (FLAGS_incoming) { + analyzer.CreateStreamBitrateGraph( + webrtc::PacketDirection::kIncomingPacket, + collection->append_new_plot()); + } + if (FLAGS_outgoing) { + analyzer.CreateStreamBitrateGraph( + webrtc::PacketDirection::kOutgoingPacket, + collection->append_new_plot()); + } + } + + collection->draw(); + + return 0; +} diff --git a/webrtc/tools/event_log_visualizer/plot_base.h b/webrtc/tools/event_log_visualizer/plot_base.h new file mode 100644 index 0000000000..925dcecf3d --- /dev/null +++ b/webrtc/tools/event_log_visualizer/plot_base.h @@ -0,0 +1,78 @@ +/* + * Copyright (c) 2016 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 WEBRTC_TOOLS_EVENT_LOG_VISUALIZER_PLOT_BASE_H_ +#define WEBRTC_TOOLS_EVENT_LOG_VISUALIZER_PLOT_BASE_H_ + +#include +#include +#include +#include + +namespace webrtc { +namespace plotting { + +enum PlotStyle { LINE_GRAPH, BAR_GRAPH }; + +struct TimeSeriesPoint { + TimeSeriesPoint(float x, float y) : x(x), y(y) {} + float x; + float y; +}; + +struct TimeSeries { + TimeSeries() = default; + TimeSeries(TimeSeries&& other) + : label(std::move(other.label)), + style(other.style), + points(std::move(other.points)) {} + TimeSeries& operator=(TimeSeries&& other) { + label = std::move(other.label); + style = other.style; + points = std::move(other.points); + return *this; + } + + std::string label; + PlotStyle style; + std::vector points; +}; + +// This is basically a struct that represents of a general graph, with axes, +// title and one or more data series. We make it a class only to document that +// it also specifies an interface for the draw()ing objects. +class Plot { + public: + virtual ~Plot() {} + virtual void draw() = 0; + + float xaxis_min; + float xaxis_max; + std::string xaxis_label; + float yaxis_min; + float yaxis_max; + std::string yaxis_label; + std::vector series; + std::string title; +}; + +class PlotCollection { + public: + virtual ~PlotCollection() {} + virtual void draw() = 0; + virtual Plot* append_new_plot() = 0; + + protected: + std::vector > plots; +}; + +} // namespace plotting +} // namespace webrtc + +#endif // WEBRTC_TOOLS_EVENT_LOG_VISUALIZER_PLOT_BASE_H_ diff --git a/webrtc/tools/event_log_visualizer/plot_python.cc b/webrtc/tools/event_log_visualizer/plot_python.cc new file mode 100644 index 0000000000..916bc2e6a6 --- /dev/null +++ b/webrtc/tools/event_log_visualizer/plot_python.cc @@ -0,0 +1,98 @@ +/* + * Copyright (c) 2016 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 "webrtc/tools/event_log_visualizer/plot_python.h" + +#include + +namespace webrtc { +namespace plotting { + +PythonPlot::PythonPlot() {} + +PythonPlot::~PythonPlot() {} + +void PythonPlot::draw() { + // Write python commands to stdout. Intended program usage is + // ./event_log_visualizer event_log160330.dump | python + + if (!series.empty()) { + printf("color_count = %zu\n", series.size()); + printf( + "hls_colors = [(i*1.0/color_count, 0.25+i*0.5/color_count, 0.8) for i " + "in range(color_count)]\n"); + printf("rgb_colors = [colorsys.hls_to_rgb(*hls) for hls in hls_colors]\n"); + + for (size_t i = 0; i < series.size(); i++) { + // List x coordinates + printf("x%zu = [", i); + if (series[i].points.size() > 0) + printf("%G", series[i].points[0].x); + for (size_t j = 1; j < series[i].points.size(); j++) + printf(", %G", series[i].points[j].x); + printf("]\n"); + + // List y coordinates + printf("y%zu = [", i); + if (series[i].points.size() > 0) + printf("%G", series[i].points[0].y); + for (size_t j = 1; j < series[i].points.size(); j++) + printf(", %G", series[i].points[j].y); + printf("]\n"); + + if (series[i].style == BAR_GRAPH) { + // There is a plt.bar function that draws bar plots, + // but it is *way* too slow to be useful. + printf( + "plt.vlines(x%zu, map(lambda t: min(t,0), y%zu), map(lambda t: " + "max(t,0), y%zu), color=rgb_colors[%zu], " + "label=\'%s\')\n", + i, i, i, i, series[i].label.c_str()); + } else if (series[i].style == LINE_GRAPH) { + printf("plt.plot(x%zu, y%zu, color=rgb_colors[%zu], label=\'%s\')\n", i, + i, i, series[i].label.c_str()); + } else { + printf("raise Exception(\"Unknown graph type\")\n"); + } + } + } + + printf("plt.xlim(%f, %f)\n", xaxis_min, xaxis_max); + printf("plt.ylim(%f, %f)\n", yaxis_min, yaxis_max); + printf("plt.xlabel(\'%s\')\n", xaxis_label.c_str()); + printf("plt.ylabel(\'%s\')\n", yaxis_label.c_str()); + printf("plt.title(\'%s\')\n", title.c_str()); + if (!series.empty()) { + printf("plt.legend(loc=\'best\', fontsize=\'small\')\n"); + } +} + +PythonPlotCollection::PythonPlotCollection() {} + +PythonPlotCollection::~PythonPlotCollection() {} + +void PythonPlotCollection::draw() { + printf("import matplotlib.pyplot as plt\n"); + printf("import colorsys\n"); + for (size_t i = 0; i < plots.size(); i++) { + printf("plt.figure(%zu)\n", i); + plots[i]->draw(); + } + printf("plt.show()\n"); +} + +Plot* PythonPlotCollection::append_new_plot() { + Plot* plot = new PythonPlot(); + plots.push_back(std::unique_ptr(plot)); + return plot; +} + +} // namespace plotting +} // namespace webrtc diff --git a/webrtc/tools/event_log_visualizer/plot_python.h b/webrtc/tools/event_log_visualizer/plot_python.h new file mode 100644 index 0000000000..8d63f952eb --- /dev/null +++ b/webrtc/tools/event_log_visualizer/plot_python.h @@ -0,0 +1,36 @@ +/* + * Copyright (c) 2016 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 WEBRTC_TOOLS_EVENT_LOG_VISUALIZER_PLOT_PYTHON_H_ +#define WEBRTC_TOOLS_EVENT_LOG_VISUALIZER_PLOT_PYTHON_H_ + +#include "webrtc/tools/event_log_visualizer/plot_base.h" + +namespace webrtc { +namespace plotting { + +class PythonPlot final : public Plot { + public: + PythonPlot(); + ~PythonPlot() override; + void draw() override; +}; + +class PythonPlotCollection final : public PlotCollection { + public: + PythonPlotCollection(); + ~PythonPlotCollection() override; + void draw() override; + Plot* append_new_plot() override; +}; + +} // namespace plotting +} // namespace webrtc + +#endif // WEBRTC_TOOLS_EVENT_LOG_VISUALIZER_PLOT_PYTHON_H_ diff --git a/webrtc/tools/tools.gyp b/webrtc/tools/tools.gyp index 998319e31f..5c11370a20 100644 --- a/webrtc/tools/tools.gyp +++ b/webrtc/tools/tools.gyp @@ -99,6 +99,32 @@ }, # force_mic_volume_max ], 'conditions': [ + ['enable_protobuf==1 and include_tests==1', { + # TODO(terelius): This tool requires the include_test condition to + # prevent build errors when gflags isn't found in downstream projects. + # There should be a cleaner way to do this. The tool is not test related. + 'targets': [ + { + # This target should only be built if enable_protobuf is set + 'target_name': 'event_log_visualizer', + 'type': 'executable', + 'dependencies': [ + '<(webrtc_root)/webrtc.gyp:rtc_event_log_parser', + '<(webrtc_root)/modules/modules.gyp:rtp_rtcp', + '<(webrtc_root)/system_wrappers/system_wrappers.gyp:metrics_default', + '<(DEPTH)/third_party/gflags/gflags.gyp:gflags', + ], + 'sources': [ + 'event_log_visualizer/analyzer.cc', + 'event_log_visualizer/analyzer.h', + 'event_log_visualizer/generate_timeseries.cc', + 'event_log_visualizer/plot_base.h', + 'event_log_visualizer/plot_python.cc', + 'event_log_visualizer/plot_python.h', + ], + }, + ], + }], ['include_tests==1', { 'targets' : [ {