diff options
author | Stefan Holmer <stefan@webrtc.org> | 2015-04-10 10:35:30 +0200 |
---|---|---|
committer | Stefan Holmer <stefan@webrtc.org> | 2015-04-10 08:35:33 +0000 |
commit | dcbd3acbef881b0e6a5d459c6f6b7c7080eb1a20 (patch) | |
tree | 696d9772fda4bbcf3771170eb93f1c61332343aa | |
parent | f2822edf611ff187eab61abccd9edb2edac4ba64 (diff) | |
download | webrtc-dcbd3acbef881b0e6a5d459c6f6b7c7080eb1a20.tar.gz |
Improve BWE plotting and logging to make it possible to use multiple windows/figures.
Also adds plotting of the BWE threshold and offset.
R=solenberg@webrtc.org
Review URL: https://webrtc-codereview.appspot.com/43119004
Cr-Commit-Position: refs/heads/master@{#8968}
15 files changed, 102 insertions, 82 deletions
diff --git a/webrtc/modules/remote_bitrate_estimator/aimd_rate_control.cc b/webrtc/modules/remote_bitrate_estimator/aimd_rate_control.cc index bed5d99cab..a1a9baf352 100644 --- a/webrtc/modules/remote_bitrate_estimator/aimd_rate_control.cc +++ b/webrtc/modules/remote_bitrate_estimator/aimd_rate_control.cc @@ -137,8 +137,6 @@ void AimdRateControl::SetEstimate(int bitrate_bps, int64_t now_ms) { uint32_t AimdRateControl::ChangeBitrate(uint32_t current_bitrate_bps, uint32_t incoming_bitrate_bps, int64_t now_ms) { - BWE_TEST_LOGGING_PLOT("estimated_incoming#1", -1, - incoming_bitrate_bps / 1000); if (!updated_) { return current_bitrate_bps_; } @@ -172,15 +170,11 @@ uint32_t AimdRateControl::ChangeBitrate(uint32_t current_bitrate_bps, const int64_t response_time = rtt_ + 100; uint32_t additive_increase_bps = AdditiveRateIncrease( now_ms, time_last_bitrate_change_, response_time); - BWE_TEST_LOGGING_PLOT("add_increase#1", -1, - additive_increase_bps / 1000); current_bitrate_bps += additive_increase_bps; } else { uint32_t multiplicative_increase_bps = MultiplicativeRateIncrease( now_ms, time_last_bitrate_change_, current_bitrate_bps); - BWE_TEST_LOGGING_PLOT("mult_increase#1", -1, - multiplicative_increase_bps / 1000); current_bitrate_bps += multiplicative_increase_bps; } diff --git a/webrtc/modules/remote_bitrate_estimator/overuse_detector.cc b/webrtc/modules/remote_bitrate_estimator/overuse_detector.cc index fa5b8f71d7..33b234c1f3 100644 --- a/webrtc/modules/remote_bitrate_estimator/overuse_detector.cc +++ b/webrtc/modules/remote_bitrate_estimator/overuse_detector.cc @@ -15,6 +15,7 @@ #include <stdlib.h> #include "webrtc/modules/remote_bitrate_estimator/include/bwe_defines.h" +#include "webrtc/modules/remote_bitrate_estimator/test/bwe_test_logging.h" #include "webrtc/modules/rtp_rtcp/source/rtp_utility.h" #include "webrtc/system_wrappers/interface/trace.h" @@ -51,14 +52,19 @@ void OveruseDetector::SetRateControlRegion(RateControlRegion region) { } } -BandwidthUsage OveruseDetector::Detect(double offset, double ts_delta, - int num_of_deltas) { +BandwidthUsage OveruseDetector::Detect(double offset, + double ts_delta, + int num_of_deltas, + int64_t now_ms) { if (num_of_deltas < 2) { return kBwNormal; } const double prev_offset = prev_offset_; prev_offset_ = offset; const double T = std::min(num_of_deltas, 60) * offset; + BWE_TEST_LOGGING_PLOT(1, "offset", now_ms, T); + BWE_TEST_LOGGING_PLOT(1, "threshold", now_ms, threshold_); + if (T > threshold_) { if (time_over_using_ == -1) { // Initialize the timer. Assume that we've been diff --git a/webrtc/modules/remote_bitrate_estimator/overuse_detector.h b/webrtc/modules/remote_bitrate_estimator/overuse_detector.h index 2a6cdd764f..8269368ae0 100644 --- a/webrtc/modules/remote_bitrate_estimator/overuse_detector.h +++ b/webrtc/modules/remote_bitrate_estimator/overuse_detector.h @@ -31,8 +31,10 @@ class OveruseDetector { // offset was based on, representing the time between detector updates. // |num_of_deltas| is the number of deltas the offset estimate is based on. // Returns the state after the detection update. - BandwidthUsage Detect(double offset, double timestamp_delta, - int num_of_deltas); + BandwidthUsage Detect(double offset, + double timestamp_delta, + int num_of_deltas, + int64_t now_ms); // Returns the current detector state. BandwidthUsage State() const; diff --git a/webrtc/modules/remote_bitrate_estimator/overuse_detector_unittest.cc b/webrtc/modules/remote_bitrate_estimator/overuse_detector_unittest.cc index 59a3056a3b..7c975cbe5f 100644 --- a/webrtc/modules/remote_bitrate_estimator/overuse_detector_unittest.cc +++ b/webrtc/modules/remote_bitrate_estimator/overuse_detector_unittest.cc @@ -104,7 +104,7 @@ class OveruseDetectorTest : public ::testing::Test { overuse_detector_->State()); overuse_detector_->Detect(overuse_estimator_->offset(), timestamp_delta_ms, - overuse_estimator_->num_of_deltas()); + overuse_estimator_->num_of_deltas(), 0); } } diff --git a/webrtc/modules/remote_bitrate_estimator/remote_bitrate_estimator.gypi b/webrtc/modules/remote_bitrate_estimator/remote_bitrate_estimator.gypi index 84e8324674..21d3bd584f 100644 --- a/webrtc/modules/remote_bitrate_estimator/remote_bitrate_estimator.gypi +++ b/webrtc/modules/remote_bitrate_estimator/remote_bitrate_estimator.gypi @@ -40,6 +40,16 @@ 'test/bwe_test_logging.cc', 'test/bwe_test_logging.h', ], # source + 'conditions': [ + ['enable_bwe_test_logging==1', { + 'defines': [ 'BWE_TEST_LOGGING_COMPILE_TIME_ENABLE=1' ], + }, { + 'defines': [ 'BWE_TEST_LOGGING_COMPILE_TIME_ENABLE=0' ], + 'sources!': [ + 'remote_bitrate_estimator/test/bwe_test_logging.cc' + ], + }], + ], }, ], # targets 'conditions': [ diff --git a/webrtc/modules/remote_bitrate_estimator/remote_bitrate_estimator_abs_send_time.cc b/webrtc/modules/remote_bitrate_estimator/remote_bitrate_estimator_abs_send_time.cc index 65e5401494..5b34cbbd23 100644 --- a/webrtc/modules/remote_bitrate_estimator/remote_bitrate_estimator_abs_send_time.cc +++ b/webrtc/modules/remote_bitrate_estimator/remote_bitrate_estimator_abs_send_time.cc @@ -409,7 +409,7 @@ void RemoteBitrateEstimatorAbsSendTimeImpl::IncomingPacketInfo( double ts_delta_ms = (1000.0 * ts_delta) / (1 << kInterArrivalShift); estimator_.Update(t_delta, ts_delta_ms, size_delta, detector_.State()); detector_.Detect(estimator_.offset(), ts_delta_ms, - estimator_.num_of_deltas()); + estimator_.num_of_deltas(), now_ms); UpdateStats(static_cast<int>(t_delta - ts_delta_ms), now_ms); } if (detector_.State() == kBwOverusing) { diff --git a/webrtc/modules/remote_bitrate_estimator/remote_bitrate_estimator_single_stream.cc b/webrtc/modules/remote_bitrate_estimator/remote_bitrate_estimator_single_stream.cc index 72c476d202..dc7742808f 100644 --- a/webrtc/modules/remote_bitrate_estimator/remote_bitrate_estimator_single_stream.cc +++ b/webrtc/modules/remote_bitrate_estimator/remote_bitrate_estimator_single_stream.cc @@ -146,7 +146,7 @@ void RemoteBitrateEstimatorImpl::IncomingPacket( estimator->detector.State()); estimator->detector.Detect(estimator->estimator.offset(), timestamp_delta_ms, - estimator->estimator.num_of_deltas()); + estimator->estimator.num_of_deltas(), now_ms); } if (estimator->detector.State() == kBwOverusing) { uint32_t incoming_bitrate = incoming_bitrate_.Rate(now_ms); diff --git a/webrtc/modules/remote_bitrate_estimator/test/bwe_plot.sh b/webrtc/modules/remote_bitrate_estimator/test/bwe_plot.sh index 4695af45cd..66b7417e46 100755 --- a/webrtc/modules/remote_bitrate_estimator/test/bwe_plot.sh +++ b/webrtc/modules/remote_bitrate_estimator/test/bwe_plot.sh @@ -16,48 +16,58 @@ # --gtest_filter=*BweTest* | [trunk_path]/webrtc/modules/ # remote_bitrate_estimator/bwe_plot. -# bwe_plot.sh has a single y axis and a dual y axis mode. If any line specifies -# a an axis by ending with "#<axis number (1 or 2)>" two y axis will be used, -# the first will be assumed to represent bitrate (in kbps) and the second will -# be assumed to represent time deltas (in ms). +# bwe_plot.sh supports multiple figures (windows), the figure is specified as an +# identifier at the first argument after the PLOT command. Each figure has a +# single y axis and a dual y axis mode. If any line specifies an axis by ending +# with "#<axis number (1 or 2)>" two y axis will be used, the first will be +# assumed to represent bitrate (in kbps) and the second will be assumed to +# represent time deltas (in ms). log=$(</dev/stdin) function gen_gnuplot_input { colors=(a7001f 0a60c2 b2582b 21a66c d6604d 4393c3 f4a582 92c5de edcbb7 b1c5d0) - data_sets=$(echo "$log" | grep "^PLOT" | cut -f 2 | sort | uniq) - linetypes=($(echo "$data_sets" | cut -d '#' -f 2 | cut -d ' ' -f 1)) - echo -n "reset; " - echo -n "set terminal wxt size 1440,900 font \"Arial,9\"; " - echo -n "set xlabel \"Seconds\"; " - if [ -n $linetypes ]; then - echo -n "set ylabel 'bitrate (kbps)';" - echo -n "set ytics nomirror;" - echo -n "set y2label 'time delta (ms)';" - echo -n "set y2tics nomirror;" - fi - echo -n "plot " - i=0 - for set in $data_sets ; do - (( i++ )) && echo -n "," - echo -n "'-' with " - echo -n "linespoints " - echo -n "ps 0.5 " - echo -n "lc rgbcolor \"#${colors[$(($i % 10))]}\" " - if [ -n ${linetypes[$i - 1]} ]; then - echo -n "axes x1y${linetypes[$i - 1]} " - elif [ -n $linestypes ]; then - # If no line type is specified, but line types are used, we will default - # to the bitrate axis. - echo -n "axes x1y1 " + plots=$(echo "$log" | grep "^PLOT") + figures=($(echo "$plots" | cut -f 2 | sort | uniq)) + + for figure in "${figures[@]}" ; do + data_sets=$(echo "$plots" | grep "^PLOT.$figure" | cut -f 3 | sort | uniq) + linetypes=($(echo "$data_sets" | grep "#" | cut -d '#' -f 2 | \ + cut -d ' ' -f 1)) + echo -n "reset; " + echo -n "set terminal wxt $figure size 1440,900 font \"Arial,9\"; " + echo -n "set xlabel \"Seconds\"; " + if (( "${#linetypes[@]}" > "0" )); then + echo -n "set ylabel 'bitrate (kbps)';" + echo -n "set ytics nomirror;" + echo -n "set y2label 'time delta (ms)';" + echo -n "set y2tics nomirror;" fi - echo -n "title \"$set\" " - done - echo - for set in $data_sets ; do - echo "$log" | grep "^PLOT.$set" | cut -f 3,4 - echo "e" + echo -n "plot " + i=0 + for set in $data_sets ; do + (( i++ )) && echo -n "," + echo -n "'-' with " + echo -n "linespoints " + echo -n "ps 0.5 " + echo -n "lc rgbcolor \"#${colors[$(($i % 10))]}\" " + if (( "${#linetypes[@]}" > "0" )); then + if (( "$i" <= "${#linetypes[@]}" )); then + echo -n "axes x1y${linetypes[$i - 1]} " + else + # If no line type is specified, but line types are used, we will + # default to the bitrate axis. + echo -n "axes x1y1 " + fi + fi + echo -n "title \"$set\" " + done + echo + for set in $data_sets ; do + echo "$log" | grep "^PLOT.$figure.$set" | cut -f 4,5 + echo "e" + done done } -gen_gnuplot_input "$log" | gnuplot -persist +gen_gnuplot_input | gnuplot -persist diff --git a/webrtc/modules/remote_bitrate_estimator/test/bwe_test_framework.cc b/webrtc/modules/remote_bitrate_estimator/test/bwe_test_framework.cc index d5a95066c5..d179e8e6ea 100644 --- a/webrtc/modules/remote_bitrate_estimator/test/bwe_test_framework.cc +++ b/webrtc/modules/remote_bitrate_estimator/test/bwe_test_framework.cc @@ -198,8 +198,7 @@ bool IsTimeSorted(const Packets& packets) { PacketProcessor::PacketProcessor(PacketProcessorListener* listener, int flow_id, ProcessorType type) - : listener_(listener) { - flow_ids_.insert(flow_id); + : listener_(listener), flow_ids_(&flow_id, &flow_id + 1) { if (listener_) { listener_->AddPacketProcessor(this, type); } @@ -270,7 +269,7 @@ Stats<double> RateCounterFilter::GetBitrateStats() const { void RateCounterFilter::Plot(int64_t timestamp_ms) { BWE_TEST_LOGGING_CONTEXT(name_.c_str()); - BWE_TEST_LOGGING_PLOT("Throughput_#1", timestamp_ms, + BWE_TEST_LOGGING_PLOT(0, "Throughput_#1", timestamp_ms, rate_counter_->bits_per_second() / 1000.0); } @@ -549,7 +548,7 @@ void TraceBasedDeliveryFilter::Plot(int64_t timestamp_ms) { BWE_TEST_LOGGING_CONTEXT(name_.c_str()); // This plots the max possible throughput of the trace-based delivery filter, // which will be reached if a packet sent on every packet slot of the trace. - BWE_TEST_LOGGING_PLOT("MaxThroughput_#1", timestamp_ms, + BWE_TEST_LOGGING_PLOT(0, "MaxThroughput_#1", timestamp_ms, rate_counter_->bits_per_second() / 1000.0); } diff --git a/webrtc/modules/remote_bitrate_estimator/test/bwe_test_framework.h b/webrtc/modules/remote_bitrate_estimator/test/bwe_test_framework.h index 9e893de511..69dc8e111b 100644 --- a/webrtc/modules/remote_bitrate_estimator/test/bwe_test_framework.h +++ b/webrtc/modules/remote_bitrate_estimator/test/bwe_test_framework.h @@ -191,7 +191,7 @@ class PacketProcessor { // internal data. virtual void Plot(int64_t timestamp_ms) {} - // Run simulation for |time_ms| micro seconds, consuming packets from, and + // Run simulation for |time_ms| milliseconds, consuming packets from, and // producing packets into in_out. The outgoing packet list must be sorted on // |send_time_us_|. The simulation time |time_ms| is optional to use. virtual void RunFor(int64_t time_ms, Packets* in_out) = 0; @@ -200,7 +200,7 @@ class PacketProcessor { private: PacketProcessorListener* listener_; - FlowIds flow_ids_; + const FlowIds flow_ids_; DISALLOW_COPY_AND_ASSIGN(PacketProcessor); }; diff --git a/webrtc/modules/remote_bitrate_estimator/test/bwe_test_logging.cc b/webrtc/modules/remote_bitrate_estimator/test/bwe_test_logging.cc index 65369fde36..319a97bfca 100644 --- a/webrtc/modules/remote_bitrate_estimator/test/bwe_test_logging.cc +++ b/webrtc/modules/remote_bitrate_estimator/test/bwe_test_logging.cc @@ -16,6 +16,7 @@ #include <stdio.h> #include <algorithm> +#include <sstream> #include "webrtc/system_wrappers/interface/critical_section_wrapper.h" #include "webrtc/system_wrappers/interface/thread_wrapper.h" @@ -27,14 +28,9 @@ namespace bwe { Logging Logging::g_Logging; static std::string ToString(uint32_t v) { - const size_t kBufferSize = 16; - char string_buffer[kBufferSize] = {0}; -#if defined(_MSC_VER) && defined(_WIN32) - _snprintf(string_buffer, kBufferSize - 1, "%08x", v); -#else - snprintf(string_buffer, kBufferSize, "%08x", v); -#endif - return string_buffer; + std::stringstream ss; + ss << v; + return ss.str(); } Logging::Context::Context(uint32_t name, int64_t timestamp_ms, bool enabled) { @@ -94,14 +90,14 @@ void Logging::Log(const char format[], ...) { } } -void Logging::Plot(double value) { +void Logging::Plot(int figure, double value) { CriticalSectionScoped cs(crit_sect_.get()); ThreadMap::iterator it = thread_map_.find(ThreadWrapper::GetThreadId()); assert(it != thread_map_.end()); const State& state = it->second.stack.top(); if (state.enabled) { - printf("PLOT\t%s\t%f\t%f\n", state.tag.c_str(), state.timestamp_ms * 0.001, - value); + printf("PLOT\t%d\t%s\t%f\t%f\n", figure, state.tag.c_str(), + state.timestamp_ms * 0.001, value); } } diff --git a/webrtc/modules/remote_bitrate_estimator/test/bwe_test_logging.h b/webrtc/modules/remote_bitrate_estimator/test/bwe_test_logging.h index 728e98e629..c214d70c27 100644 --- a/webrtc/modules/remote_bitrate_estimator/test/bwe_test_logging.h +++ b/webrtc/modules/remote_bitrate_estimator/test/bwe_test_logging.h @@ -28,7 +28,7 @@ // BWE_TEST_LOGGING_CONTEXT(i); // BWE_TEST_LOGGING_LOG1("weight", "%f tonnes", weights_[i]); // for (float j=0.0f; j<1.0; j+=0.4f) { -// BWE_TEST_LOGGING_PLOT("bps", -1, j); +// BWE_TEST_LOGGING_PLOT(0, "bps", -1, j); // } // } // } @@ -86,11 +86,12 @@ #define BWE_TEST_LOGGING_LOG5(name, format, _1, _2, _3, _4, _5) // Print to stdout in tab-separated format suitable for plotting, e.g.: -// PLOT Context1_Context2_Name time value +// PLOT figure Context1_Context2_Name time value +// |figure| is a figure id. Different figures are plotted in different windows. // |name| is a char*, std::string or uint32_t to name the plotted value. // |time| is an int64_t time in ms, or -1 to inherit time from previous context. // |value| is a double precision float to be plotted. -#define BWE_TEST_LOGGING_PLOT(name, time, value) +#define BWE_TEST_LOGGING_PLOT(figure, name, time, value) #else // BWE_TEST_LOGGING_COMPILE_TIME_ENABLE @@ -154,12 +155,12 @@ _4, _5); \ } while (0); -#define BWE_TEST_LOGGING_PLOT(name, time, value)\ - do { \ - __BWE_TEST_LOGGING_CONTEXT_DECLARE(__bwe_log_, __LINE__, name, \ - static_cast<int64_t>(time), true); \ - webrtc::testing::bwe::Logging::GetInstance()->Plot(value); \ - } while (0); +#define BWE_TEST_LOGGING_PLOT(figure, name, time, value) \ + do { \ + __BWE_TEST_LOGGING_CONTEXT_DECLARE(__bwe_log_, __LINE__, name, \ + static_cast<int64_t>(time), true); \ + webrtc::testing::bwe::Logging::GetInstance()->Plot(figure, value); \ + } while (0); namespace webrtc { @@ -188,7 +189,7 @@ class Logging { void SetGlobalEnable(bool enabled); void Log(const char format[], ...); - void Plot(double value); + void Plot(int figure, double value); private: struct State { diff --git a/webrtc/modules/remote_bitrate_estimator/test/estimators/remb.cc b/webrtc/modules/remote_bitrate_estimator/test/estimators/remb.cc index 18c63e3bb8..a61b5239d5 100644 --- a/webrtc/modules/remote_bitrate_estimator/test/estimators/remb.cc +++ b/webrtc/modules/remote_bitrate_estimator/test/estimators/remb.cc @@ -117,8 +117,8 @@ FeedbackPacket* RembReceiver::GetFeedback(int64_t now_ms) { double estimated_kbps = static_cast<double>(estimated_bps) / 1000.0; RTC_UNUSED(estimated_kbps); if (plot_estimate_) { - BWE_TEST_LOGGING_PLOT(estimate_log_prefix_, clock_.TimeInMilliseconds(), - estimated_kbps); + BWE_TEST_LOGGING_PLOT(0, estimate_log_prefix_, + clock_.TimeInMilliseconds(), estimated_kbps); } } return feedback; diff --git a/webrtc/modules/remote_bitrate_estimator/test/packet_receiver.cc b/webrtc/modules/remote_bitrate_estimator/test/packet_receiver.cc index 0f85d7f22c..1640137a6a 100644 --- a/webrtc/modules/remote_bitrate_estimator/test/packet_receiver.cc +++ b/webrtc/modules/remote_bitrate_estimator/test/packet_receiver.cc @@ -50,14 +50,14 @@ void PacketReceiver::RunFor(int64_t time_ms, Packets* in_out) { // should only process a single flow id. // TODO(holmer): Break this out into a Demuxer which implements both // PacketProcessorListener and PacketProcessor. + BWE_TEST_LOGGING_CONTEXT("Receiver"); if ((*it)->GetPacketType() == Packet::kMedia && (*it)->flow_id() == *flow_ids().begin()) { - BWE_TEST_LOGGING_CONTEXT("Receiver"); + BWE_TEST_LOGGING_CONTEXT(*flow_ids().begin()); const MediaPacket* media_packet = static_cast<const MediaPacket*>(*it); // We're treating the send time (from previous filter) as the arrival // time once packet reaches the estimator. int64_t arrival_time_ms = (media_packet->send_time_us() + 500) / 1000; - BWE_TEST_LOGGING_TIME(arrival_time_ms); PlotDelay(arrival_time_ms, (media_packet->creation_time_us() + 500) / 1000); @@ -80,7 +80,7 @@ void PacketReceiver::PlotDelay(int64_t arrival_time_ms, int64_t send_time_ms) { if (!plot_delay_) return; if (arrival_time_ms - last_delay_plot_ms_ > kDelayPlotIntervalMs) { - BWE_TEST_LOGGING_PLOT(delay_log_prefix_, arrival_time_ms, + BWE_TEST_LOGGING_PLOT(0, delay_log_prefix_, arrival_time_ms, arrival_time_ms - send_time_ms); last_delay_plot_ms_ = arrival_time_ms; } diff --git a/webrtc/modules/remote_bitrate_estimator/test/packet_sender.cc b/webrtc/modules/remote_bitrate_estimator/test/packet_sender.cc index 2a34d22c63..5908f26748 100644 --- a/webrtc/modules/remote_bitrate_estimator/test/packet_sender.cc +++ b/webrtc/modules/remote_bitrate_estimator/test/packet_sender.cc @@ -104,7 +104,7 @@ void PacketSender::OnNetworkChanged(uint32_t target_bitrate_bps, source_->SetBitrateBps(target_bitrate_bps); std::stringstream ss; ss << "SendEstimate_" << source_->flow_id() << "#1"; - BWE_TEST_LOGGING_PLOT(ss.str(), clock_.TimeInMilliseconds(), + BWE_TEST_LOGGING_PLOT(0, ss.str(), clock_.TimeInMilliseconds(), target_bitrate_bps / 1000); } @@ -134,6 +134,8 @@ void PacedVideoSender::RunFor(int64_t time_ms, Packets* in_out) { std::list<FeedbackPacket*> feedbacks = GetFeedbackPackets(in_out, end_time_ms); int64_t last_run_time_ms = -1; + BWE_TEST_LOGGING_CONTEXT("Sender"); + BWE_TEST_LOGGING_CONTEXT(source_->flow_id()); do { int64_t time_until_process_ms = TimeUntilNextProcess(modules_); int64_t time_until_feedback_ms = time_ms; |