From 2db46b0fb7f9444c138ba5ee6276b5bb40981d67 Mon Sep 17 00:00:00 2001 From: Ivo Creusen Date: Fri, 14 Dec 2018 16:49:12 +0100 Subject: [PATCH] Added new feature to print a text log to neteq_rtpplay MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit This will print out the major events during a NetEq simulation. Bug: b/116685514 Change-Id: Iab172e9a9115695b42c67628d5523c727359bb89 Reviewed-on: https://webrtc-review.googlesource.com/c/114320 Commit-Queue: Ivo Creusen Reviewed-by: Björn Terelius Reviewed-by: Henrik Lundin Cr-Commit-Position: refs/heads/master@{#26019} --- modules/audio_coding/BUILD.gn | 1 + modules/audio_coding/neteq/include/neteq.h | 2 + .../neteq/neteq_decoder_plc_unittest.cc | 2 +- modules/audio_coding/neteq/neteq_unittest.cc | 4 +- .../neteq/statistics_calculator.cc | 2 +- .../audio_coding/neteq/tools/neteq_test.cc | 67 ++++++++++++++++++- modules/audio_coding/neteq/tools/neteq_test.h | 5 ++ .../neteq/tools/neteq_test_factory.cc | 16 ++++- rtc_tools/event_log_visualizer/analyzer.cc | 2 +- test/fuzzers/neteq_rtp_fuzzer.cc | 2 +- test/fuzzers/neteq_signal_fuzzer.cc | 2 +- 11 files changed, 95 insertions(+), 10 deletions(-) diff --git a/modules/audio_coding/BUILD.gn b/modules/audio_coding/BUILD.gn index 34df39f492..6657495303 100644 --- a/modules/audio_coding/BUILD.gn +++ b/modules/audio_coding/BUILD.gn @@ -1096,6 +1096,7 @@ rtc_source_set("neteq_tools_minimal") { "../../rtc_base:checks", "../../rtc_base:rtc_base_approved", "../rtp_rtcp", + "../rtp_rtcp:rtp_rtcp_format", "//third_party/abseil-cpp/absl/types:optional", ] defines = audio_codec_defines diff --git a/modules/audio_coding/neteq/include/neteq.h b/modules/audio_coding/neteq/include/neteq.h index 2820fd8478..242ff64705 100644 --- a/modules/audio_coding/neteq/include/neteq.h +++ b/modules/audio_coding/neteq/include/neteq.h @@ -85,6 +85,8 @@ struct NetEqOperationsAndState { uint64_t accelerate_samples = 0; // Count of the number of buffer flushes. uint64_t packet_buffer_flushes = 0; + // The number of primary packets that were discarded. + uint64_t discarded_primary_packets = 0; // The statistics below are not cumulative. // The waiting time of the last decoded packet. uint64_t last_waiting_time_ms = 0; diff --git a/modules/audio_coding/neteq/neteq_decoder_plc_unittest.cc b/modules/audio_coding/neteq/neteq_decoder_plc_unittest.cc index 8d0972cb54..acc25b7efc 100644 --- a/modules/audio_coding/neteq/neteq_decoder_plc_unittest.cc +++ b/modules/audio_coding/neteq/neteq_decoder_plc_unittest.cc @@ -185,7 +185,7 @@ NetEqNetworkStatistics RunTest(int loss_cadence, std::string* checksum) { // No callback objects. NetEqTest::Callbacks callbacks; - NetEqTest neteq_test(config, decoders, external_decoders, + NetEqTest neteq_test(config, decoders, external_decoders, nullptr, std::move(lossy_input), std::move(output), callbacks); EXPECT_LE(kRunTimeMs, neteq_test.Run()); diff --git a/modules/audio_coding/neteq/neteq_unittest.cc b/modules/audio_coding/neteq/neteq_unittest.cc index 3acb865cee..922f9fcfb9 100644 --- a/modules/audio_coding/neteq/neteq_unittest.cc +++ b/modules/audio_coding/neteq/neteq_unittest.cc @@ -1726,8 +1726,8 @@ TEST(NetEqNoTimeStretchingMode, RunTest) { new TimeLimitedNetEqInput(std::move(input), 20000)); std::unique_ptr output(new VoidAudioSink); NetEqTest::Callbacks callbacks; - NetEqTest test(config, codecs, ext_codecs, std::move(input_time_limit), - std::move(output), callbacks); + NetEqTest test(config, codecs, ext_codecs, nullptr, + std::move(input_time_limit), std::move(output), callbacks); test.Run(); const auto stats = test.SimulationStats(); EXPECT_EQ(0, stats.accelerate_rate); diff --git a/modules/audio_coding/neteq/statistics_calculator.cc b/modules/audio_coding/neteq/statistics_calculator.cc index 50521fb03d..5d94abd8b8 100644 --- a/modules/audio_coding/neteq/statistics_calculator.cc +++ b/modules/audio_coding/neteq/statistics_calculator.cc @@ -216,7 +216,7 @@ void StatisticsCalculator::AddZeros(size_t num_samples) { } void StatisticsCalculator::PacketsDiscarded(size_t num_packets) { - discarded_packets_ += num_packets; + operations_and_state_.discarded_primary_packets += num_packets; } void StatisticsCalculator::SecondaryPacketsDiscarded(size_t num_packets) { diff --git a/modules/audio_coding/neteq/tools/neteq_test.cc b/modules/audio_coding/neteq/tools/neteq_test.cc index 421f380a7a..a3c3ffa32b 100644 --- a/modules/audio_coding/neteq/tools/neteq_test.cc +++ b/modules/audio_coding/neteq/tools/neteq_test.cc @@ -10,9 +10,11 @@ #include "modules/audio_coding/neteq/tools/neteq_test.h" +#include #include #include "api/audio_codecs/builtin_audio_decoder_factory.h" +#include "modules/rtp_rtcp/source/byte_io.h" namespace webrtc { namespace test { @@ -52,6 +54,7 @@ void DefaultNetEqTestErrorCallback::OnGetAudioError() { NetEqTest::NetEqTest(const NetEq::Config& config, const DecoderMap& codecs, const ExtDecoderMap& ext_codecs, + std::unique_ptr text_log, std::unique_ptr input, std::unique_ptr output, Callbacks callbacks) @@ -59,7 +62,8 @@ NetEqTest::NetEqTest(const NetEq::Config& config, input_(std::move(input)), output_(std::move(output)), callbacks_(callbacks), - sample_rate_hz_(config.sample_rate_hz) { + sample_rate_hz_(config.sample_rate_hz), + text_log_(std::move(text_log)) { RTC_CHECK(!config.enable_muted_state) << "The code does not handle enable_muted_state"; RegisterDecoders(codecs); @@ -117,7 +121,35 @@ NetEqTest::SimulationStepResult NetEqTest::RunToNextGetAudio() { current_state_.packet_iat_ms.push_back(time_now_ms - *last_packet_time_ms_); } + if (text_log_) { + const auto ops_state = neteq_->GetOperationsAndState(); + const auto delta_wallclock = + last_packet_time_ms_ ? (time_now_ms - *last_packet_time_ms_) : -1; + const auto delta_timestamp = + last_packet_timestamp_ + ? (static_cast(packet_data->header.timestamp) - + *last_packet_timestamp_) * + 1000 / sample_rate_hz_ + : -1; + const auto packet_size_bytes = + packet_data->payload.size() == 12 + ? ByteReader::ReadLittleEndian( + &packet_data->payload[8]) + : -1; + *text_log_ << "Packet - wallclock: " << std::setw(5) << time_now_ms + << ", delta wc: " << std::setw(4) << delta_wallclock + << ", timestamp: " << std::setw(10) + << packet_data->header.timestamp + << ", delta ts: " << std::setw(4) << delta_timestamp + << ", size: " << std::setw(5) << packet_size_bytes + << ", frame size: " << std::setw(3) + << ops_state.current_frame_size_ms + << ", buffer size: " << std::setw(4) + << ops_state.current_buffer_size_ms << std::endl; + } last_packet_time_ms_ = absl::make_optional(time_now_ms); + last_packet_timestamp_ = + absl::make_optional(packet_data->header.timestamp); } // Check if it is time to get output audio. @@ -186,6 +218,39 @@ NetEqTest::SimulationStepResult NetEqTest::RunToNextGetAudio() { // Consider the whole frame to be the result of normal playout. result.action_times_ms[Action::kNormal] = 10; } + auto lifetime_stats = LifetimeStats(); + if (text_log_) { + const bool plc = + (out_frame.speech_type_ == AudioFrame::SpeechType::kPLC) || + (out_frame.speech_type_ == AudioFrame::SpeechType::kPLCCNG); + const bool cng = out_frame.speech_type_ == AudioFrame::SpeechType::kCNG; + const bool voice_concealed = + lifetime_stats.voice_concealed_samples > + prev_lifetime_stats_.voice_concealed_samples; + *text_log_ << "GetAudio - wallclock: " << std::setw(5) << time_now_ms + << ", delta wc: " << std::setw(4) + << (input_->NextEventTime().value_or(time_now_ms) - + start_time_ms) + << ", CNG: " << cng << ", PLC: " << plc + << ", voice concealed: " << voice_concealed + << ", buffer size: " << std::setw(4) + << current_state_.current_delay_ms << std::endl; + if (operations_state.discarded_primary_packets > + prev_ops_state_.discarded_primary_packets) { + *text_log_ << "Discarded " + << (operations_state.discarded_primary_packets - + prev_ops_state_.discarded_primary_packets) + << " primary packets." << std::endl; + } + if (operations_state.packet_buffer_flushes > + prev_ops_state_.packet_buffer_flushes) { + *text_log_ << "Flushed packet buffer " + << (operations_state.packet_buffer_flushes - + prev_ops_state_.packet_buffer_flushes) + << " times." << std::endl; + } + } + prev_lifetime_stats_ = lifetime_stats; result.is_simulation_finished = input_->ended(); prev_ops_state_ = operations_state; return result; diff --git a/modules/audio_coding/neteq/tools/neteq_test.h b/modules/audio_coding/neteq/tools/neteq_test.h index 23d7c22aaa..edbb620831 100644 --- a/modules/audio_coding/neteq/tools/neteq_test.h +++ b/modules/audio_coding/neteq/tools/neteq_test.h @@ -11,6 +11,7 @@ #ifndef MODULES_AUDIO_CODING_NETEQ_TOOLS_NETEQ_TEST_H_ #define MODULES_AUDIO_CODING_NETEQ_TOOLS_NETEQ_TEST_H_ +#include #include #include #include @@ -87,6 +88,7 @@ class NetEqTest : public NetEqSimulator { NetEqTest(const NetEq::Config& config, const DecoderMap& codecs, const ExtDecoderMap& ext_codecs, + std::unique_ptr text_log, std::unique_ptr input, std::unique_ptr output, Callbacks callbacks); @@ -121,6 +123,9 @@ class NetEqTest : public NetEqSimulator { int sample_rate_hz_; NetEqState current_state_; NetEqOperationsAndState prev_ops_state_; + NetEqLifetimeStatistics prev_lifetime_stats_; + absl::optional last_packet_timestamp_; + std::unique_ptr text_log_; }; } // namespace test diff --git a/modules/audio_coding/neteq/tools/neteq_test_factory.cc b/modules/audio_coding/neteq/tools/neteq_test_factory.cc index aa956ce8ab..b462776a2f 100644 --- a/modules/audio_coding/neteq/tools/neteq_test_factory.cc +++ b/modules/audio_coding/neteq/tools/neteq_test_factory.cc @@ -14,6 +14,7 @@ #include // For ULONG_MAX returned by strtoul. #include #include // For strtoul. +#include #include #include #include @@ -138,6 +139,10 @@ WEBRTC_DEFINE_bool(matlabplot, WEBRTC_DEFINE_bool(pythonplot, false, "Generates a python script for plotting the delay profile"); +WEBRTC_DEFINE_bool(textlog, + false, + "Generates a text log describing the simulation on a " + "step-by-step basis."); WEBRTC_DEFINE_bool(concealment_events, false, "Prints concealment events"); WEBRTC_DEFINE_int(max_nr_packets_in_buffer, 50, @@ -460,6 +465,13 @@ std::unique_ptr NetEqTestFactory::InitializeTest( ext_codecs_[replacement_pt] = ext_dec_info; } + // Create a text log file if needed. + std::unique_ptr text_log; + if (FLAG_textlog) { + text_log = + absl::make_unique(output_file_name + ".text_log.txt"); + } + NetEqTest::Callbacks callbacks; stats_plotter_.reset(new NetEqStatsPlotter(FLAG_matlabplot, FLAG_pythonplot, FLAG_concealment_events, @@ -475,8 +487,8 @@ std::unique_ptr NetEqTestFactory::InitializeTest( config.max_packets_in_buffer = FLAG_max_nr_packets_in_buffer; config.enable_fast_accelerate = FLAG_enable_fast_accelerate; return absl::make_unique(config, codecs, ext_codecs_, - std::move(input), std::move(output), - callbacks); + std::move(text_log), std::move(input), + std::move(output), callbacks); } } // namespace test diff --git a/rtc_tools/event_log_visualizer/analyzer.cc b/rtc_tools/event_log_visualizer/analyzer.cc index 89f239171f..7cf003991b 100644 --- a/rtc_tools/event_log_visualizer/analyzer.cc +++ b/rtc_tools/event_log_visualizer/analyzer.cc @@ -1735,7 +1735,7 @@ std::unique_ptr CreateNetEqTestAndRun( callbacks.post_insert_packet = neteq_stats_getter->delay_analyzer(); callbacks.get_audio_callback = neteq_stats_getter.get(); - test::NetEqTest test(config, codecs, ext_codecs, std::move(input), + test::NetEqTest test(config, codecs, ext_codecs, nullptr, std::move(input), std::move(output), callbacks); test.Run(); return neteq_stats_getter; diff --git a/test/fuzzers/neteq_rtp_fuzzer.cc b/test/fuzzers/neteq_rtp_fuzzer.cc index 94dbef39eb..1582507c6e 100644 --- a/test/fuzzers/neteq_rtp_fuzzer.cc +++ b/test/fuzzers/neteq_rtp_fuzzer.cc @@ -138,7 +138,7 @@ void FuzzOneInputTest(const uint8_t* data, size_t size) { NetEqTest::ExtDecoderMap ext_codecs; - NetEqTest test(config, codecs, ext_codecs, std::move(input), + NetEqTest test(config, codecs, ext_codecs, nullptr, std::move(input), std::move(output), callbacks); test.Run(); } diff --git a/test/fuzzers/neteq_signal_fuzzer.cc b/test/fuzzers/neteq_signal_fuzzer.cc index 25302c31a8..1bdc43a81a 100644 --- a/test/fuzzers/neteq_signal_fuzzer.cc +++ b/test/fuzzers/neteq_signal_fuzzer.cc @@ -183,7 +183,7 @@ void FuzzOneInputTest(const uint8_t* data, size_t size) { NetEqTest::ExtDecoderMap ext_codecs; - NetEqTest test(config, codecs, ext_codecs, std::move(input), + NetEqTest test(config, codecs, ext_codecs, nullptr, std::move(input), std::move(output), callbacks); test.Run(); }