From 39cefdb3c5fb5b93f2681188871544a38a0c9efe Mon Sep 17 00:00:00 2001 From: Fredrik Solenberg Date: Wed, 4 Oct 2017 08:49:37 +0000 Subject: [PATCH] Revert "Reland "Remove WEBRTC_TRACE."" MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit This reverts commit 68007e97ec9399125e4be9964af8b0338766cd91. Reason for revert: More downstream breakages. Original change's description: > Reland "Remove WEBRTC_TRACE." > > This is a reland of 2209b90449473e1df3e0797b6271c7624b41907d > Original change's description: > > Remove WEBRTC_TRACE. > > > > Bug: webrtc:5118 > > Change-Id: I0af0f8845ee016fa61d7cecc526e2a672ec8732d > > Reviewed-on: https://webrtc-review.googlesource.com/5382 > > Reviewed-by: Niels Moller > > Reviewed-by: Sami Kalliomäki > > Reviewed-by: Karl Wiberg > > Commit-Queue: Fredrik Solenberg > > Cr-Commit-Position: refs/heads/master@{#20114} > > Bug: webrtc:5118 > Change-Id: I2d93fd40fcaa251c363bdcfb1c04b834a3a7f0e9 > Reviewed-on: https://webrtc-review.googlesource.com/6000 > Reviewed-by: Karl Wiberg > Reviewed-by: Niels Moller > Commit-Queue: Fredrik Solenberg > Cr-Commit-Position: refs/heads/master@{#20132} TBR=solenberg@webrtc.org,sakal@webrtc.org,kwiberg@webrtc.org,nisse@webrtc.org Change-Id: I093ee8c5c997c0dd46b3a3ca0e6271e3ea083d82 No-Presubmit: true No-Tree-Checks: true No-Try: true Bug: webrtc:5118 Reviewed-on: https://webrtc-review.googlesource.com/6320 Reviewed-by: Fredrik Solenberg Commit-Queue: Fredrik Solenberg Cr-Commit-Position: refs/heads/master@{#20133} --- call/call.cc | 4 + common_types.h | 58 ++ .../appspot/apprtc/PeerConnectionClient.java | 3 +- media/engine/webrtcvoiceengine.cc | 36 ++ media/engine/webrtcvoiceengine.h | 7 +- modules/audio_coding/test/APITest.cc | 8 + modules/audio_coding/test/EncodeDecodeTest.cc | 17 + modules/audio_coding/test/Tester.cc | 59 ++ .../agc/agc_manager_direct_unittest.cc | 3 + .../audio_processing_unittest.cc | 3 + .../test/aec_dump_based_simulator.cc | 12 + .../test/wav_based_simulator.cc | 13 + rtc_base/java/src/org/webrtc/Logging.java | 22 +- .../src/org/webrtc/PeerConnectionTest.java | 6 + sdk/android/src/jni/pc/logging_jni.cc | 22 + .../src/jni/pc/peerconnectionfactory_jni.cc | 3 + system_wrappers/BUILD.gn | 12 + .../include/logcat_trace_context.h | 35 ++ system_wrappers/include/trace.h | 89 +++ .../source/logcat_trace_context.cc | 63 ++ system_wrappers/source/trace_impl.cc | 583 ++++++++++++++++++ system_wrappers/source/trace_impl.h | 105 ++++ system_wrappers/source/trace_posix.cc | 85 +++ system_wrappers/source/trace_posix.h | 39 ++ system_wrappers/source/trace_win.cc | 97 +++ system_wrappers/source/trace_win.h | 36 ++ test/BUILD.gn | 2 + test/test_main.cc | 4 + test/testsupport/trace_to_stderr.cc | 63 ++ test/testsupport/trace_to_stderr.h | 52 ++ video/video_quality_test.cc | 3 + video/video_quality_test.h | 2 + voice_engine/shared_data.cc | 5 +- voice_engine/transmit_mixer.cc | 32 +- voice_engine/transmit_mixer.h | 5 +- voice_engine/voice_engine_impl.cc | 16 +- 36 files changed, 1589 insertions(+), 15 deletions(-) create mode 100644 system_wrappers/include/logcat_trace_context.h create mode 100644 system_wrappers/include/trace.h create mode 100644 system_wrappers/source/logcat_trace_context.cc create mode 100644 system_wrappers/source/trace_impl.cc create mode 100644 system_wrappers/source/trace_impl.h create mode 100644 system_wrappers/source/trace_posix.cc create mode 100644 system_wrappers/source/trace_posix.h create mode 100644 system_wrappers/source/trace_win.cc create mode 100644 system_wrappers/source/trace_win.h create mode 100644 test/testsupport/trace_to_stderr.cc create mode 100644 test/testsupport/trace_to_stderr.h diff --git a/call/call.cc b/call/call.cc index 08e9dc2553..d497760ee5 100644 --- a/call/call.cc +++ b/call/call.cc @@ -57,6 +57,7 @@ #include "system_wrappers/include/cpu_info.h" #include "system_wrappers/include/metrics.h" #include "system_wrappers/include/rw_lock_wrapper.h" +#include "system_wrappers/include/trace.h" #include "video/call_stats.h" #include "video/send_delay_stats.h" #include "video/stats_counter.h" @@ -439,6 +440,7 @@ Call::Call(const Call::Config& config, RTC_DCHECK_GE(config.bitrate_config.max_bitrate_bps, config.bitrate_config.start_bitrate_bps); } + Trace::CreateTrace(); transport_send->send_side_cc()->RegisterNetworkObserver(this); transport_send_ = std::move(transport_send); transport_send_->send_side_cc()->SignalNetworkState(kNetworkDown); @@ -498,6 +500,8 @@ Call::~Call() { } UpdateReceiveHistograms(); UpdateHistograms(); + + Trace::ReturnTrace(); } rtc::Optional Call::ParseRtpPacket( diff --git a/common_types.h b/common_types.h index e7d912c90d..207c81e114 100644 --- a/common_types.h +++ b/common_types.h @@ -78,6 +78,64 @@ class OutStream : public RewindableStream { virtual bool Write(const void* buf, size_t len) = 0; }; +enum TraceModule { + kTraceUndefined = 0, + // not a module, triggered from the engine code + kTraceVoice = 0x0001, + // not a module, triggered from the engine code + kTraceVideo = 0x0002, + // not a module, triggered from the utility code + kTraceUtility = 0x0003, + kTraceRtpRtcp = 0x0004, + kTraceTransport = 0x0005, + kTraceSrtp = 0x0006, + kTraceAudioCoding = 0x0007, + kTraceAudioMixerServer = 0x0008, + kTraceAudioMixerClient = 0x0009, + kTraceFile = 0x000a, + kTraceAudioProcessing = 0x000b, + kTraceVideoCoding = 0x0010, + kTraceVideoMixer = 0x0011, + kTraceAudioDevice = 0x0012, + kTraceVideoRenderer = 0x0014, + kTraceVideoCapture = 0x0015, + kTraceRemoteBitrateEstimator = 0x0017, +}; + +enum TraceLevel { + kTraceNone = 0x0000, // no trace + kTraceStateInfo = 0x0001, + kTraceWarning = 0x0002, + kTraceError = 0x0004, + kTraceCritical = 0x0008, + kTraceApiCall = 0x0010, + kTraceDefault = 0x00ff, + + kTraceModuleCall = 0x0020, + kTraceMemory = 0x0100, // memory info + kTraceTimer = 0x0200, // timing info + kTraceStream = 0x0400, // "continuous" stream of data + + // used for debug purposes + kTraceDebug = 0x0800, // debug + kTraceInfo = 0x1000, // debug info + + // Non-verbose level used by LS_INFO of logging.h. Do not use directly. + kTraceTerseInfo = 0x2000, + + kTraceAll = 0xffff +}; + +// External Trace API +class TraceCallback { + public: + virtual void Print(TraceLevel level, const char* message, int length) = 0; + + protected: + virtual ~TraceCallback() {} + TraceCallback() {} +}; + enum FileFormats { kFileFormatWavFile = 1, kFileFormatCompressedFile = 2, diff --git a/examples/androidapp/src/org/appspot/apprtc/PeerConnectionClient.java b/examples/androidapp/src/org/appspot/apprtc/PeerConnectionClient.java index 9d6822b12e..caad17125b 100644 --- a/examples/androidapp/src/org/appspot/apprtc/PeerConnectionClient.java +++ b/examples/androidapp/src/org/appspot/apprtc/PeerConnectionClient.java @@ -624,8 +624,9 @@ public class PeerConnectionClient { } isInitiator = false; - // Set INFO libjingle logging. + // Set default WebRTC tracing and INFO libjingle logging. // NOTE: this _must_ happen while |factory| is alive! + Logging.enableTracing("logcat:", EnumSet.of(Logging.TraceLevel.TRACE_DEFAULT)); Logging.enableLogToDebugOutput(Logging.Severity.LS_INFO); mediaStream = factory.createLocalMediaStream("ARDAMS"); diff --git a/media/engine/webrtcvoiceengine.cc b/media/engine/webrtcvoiceengine.cc index a6875f8198..467e38dcc4 100644 --- a/media/engine/webrtcvoiceengine.cc +++ b/media/engine/webrtcvoiceengine.cc @@ -42,6 +42,7 @@ #include "rtc_base/trace_event.h" #include "system_wrappers/include/field_trial.h" #include "system_wrappers/include/metrics.h" +#include "system_wrappers/include/trace.h" #include "voice_engine/transmit_mixer.h" namespace cricket { @@ -49,6 +50,12 @@ namespace { constexpr size_t kMaxUnsignaledRecvStreams = 4; +const int kDefaultTraceFilter = webrtc::kTraceNone | webrtc::kTraceTerseInfo | + webrtc::kTraceWarning | webrtc::kTraceError | + webrtc::kTraceCritical; +const int kElevatedTraceFilter = kDefaultTraceFilter | webrtc::kTraceStateInfo | + webrtc::kTraceInfo; + constexpr int kNackRtpHistoryMs = 5000; // Check to verify that the define for the intelligibility enhancer is properly @@ -247,6 +254,7 @@ WebRtcVoiceEngine::~WebRtcVoiceEngine() { if (initialized_) { StopAecDump(); voe_wrapper_->base()->Terminate(); + webrtc::Trace::SetTraceCallback(nullptr); } } @@ -279,8 +287,12 @@ void WebRtcVoiceEngine::Init() { channel_config_.enable_voice_pacing = true; + // Temporarily turn logging level up for the Init() call. + webrtc::Trace::SetTraceCallback(this); + webrtc::Trace::set_level_filter(kElevatedTraceFilter); RTC_CHECK_EQ(0, voe_wrapper_->base()->Init(adm_.get(), apm(), decoder_factory_)); + webrtc::Trace::set_level_filter(kDefaultTraceFilter); // No ADM supplied? Get the default one from VoE. if (!adm_) { @@ -664,6 +676,30 @@ RtpCapabilities WebRtcVoiceEngine::GetCapabilities() const { return capabilities; } +void WebRtcVoiceEngine::Print(webrtc::TraceLevel level, const char* trace, + int length) { + // Note: This callback can happen on any thread! + rtc::LoggingSeverity sev = rtc::LS_VERBOSE; + if (level == webrtc::kTraceError || level == webrtc::kTraceCritical) + sev = rtc::LS_ERROR; + else if (level == webrtc::kTraceWarning) + sev = rtc::LS_WARNING; + else if (level == webrtc::kTraceStateInfo || level == webrtc::kTraceInfo) + sev = rtc::LS_INFO; + else if (level == webrtc::kTraceTerseInfo) + sev = rtc::LS_INFO; + + // Skip past boilerplate prefix text. + if (length < 72) { + std::string msg(trace, length); + LOG(LS_ERROR) << "Malformed webrtc log message: "; + LOG_V(sev) << msg; + } else { + std::string msg(trace + 71, length - 72); + LOG_V(sev) << "webrtc: " << msg; + } +} + void WebRtcVoiceEngine::RegisterChannel(WebRtcVoiceMediaChannel* channel) { RTC_DCHECK(worker_thread_checker_.CalledOnValidThread()); RTC_DCHECK(channel); diff --git a/media/engine/webrtcvoiceengine.h b/media/engine/webrtcvoiceengine.h index 3bd8fa86e5..87b7a94727 100644 --- a/media/engine/webrtcvoiceengine.h +++ b/media/engine/webrtcvoiceengine.h @@ -48,7 +48,7 @@ class WebRtcVoiceMediaChannel; // WebRtcVoiceEngine is a class to be used with CompositeMediaEngine. // It uses the WebRtc VoiceEngine library for audio handling. -class WebRtcVoiceEngine final { +class WebRtcVoiceEngine final : public webrtc::TraceCallback { friend class WebRtcVoiceMediaChannel; public: WebRtcVoiceEngine( @@ -65,7 +65,7 @@ class WebRtcVoiceEngine final { rtc::scoped_refptr audio_mixer, rtc::scoped_refptr audio_processing, VoEWrapper* voe_wrapper); - ~WebRtcVoiceEngine(); + ~WebRtcVoiceEngine() override; // Does initialization that needs to occur on the worker thread. void Init(); @@ -108,6 +108,9 @@ class WebRtcVoiceEngine final { // easily at any time. bool ApplyOptions(const AudioOptions& options); + // webrtc::TraceCallback: + void Print(webrtc::TraceLevel level, const char* trace, int length) override; + void StartAecDump(const std::string& filename); int CreateVoEChannel(); diff --git a/modules/audio_coding/test/APITest.cc b/modules/audio_coding/test/APITest.cc index 363eb6b304..b29e84e106 100644 --- a/modules/audio_coding/test/APITest.cc +++ b/modules/audio_coding/test/APITest.cc @@ -25,6 +25,7 @@ #include "rtc_base/platform_thread.h" #include "rtc_base/timeutils.h" #include "system_wrappers/include/event_wrapper.h" +#include "system_wrappers/include/trace.h" #include "test/gtest.h" #include "test/testsupport/fileutils.h" #include "typedefs.h" // NOLINT(build/include) @@ -258,8 +259,15 @@ int16_t APITest::SetUp() { // B _outFreqHzB = _outFileB.SamplingFrequency(); + //Trace::SetEncryptedTraceFile("ACMAPITestEncrypted.txt"); + char print[11]; + // Create a trace file. + Trace::CreateTrace(); + Trace::SetTraceFile( + (webrtc::test::OutputPath() + "acm_api_trace.txt").c_str()); + printf("\nRandom Test (y/n)?"); EXPECT_TRUE(fgets(print, 10, stdin) != NULL); print[10] = '\0'; diff --git a/modules/audio_coding/test/EncodeDecodeTest.cc b/modules/audio_coding/test/EncodeDecodeTest.cc index c765f68502..2b6b4acfd0 100644 --- a/modules/audio_coding/test/EncodeDecodeTest.cc +++ b/modules/audio_coding/test/EncodeDecodeTest.cc @@ -19,6 +19,7 @@ #include "modules/audio_coding/codecs/audio_format_conversion.h" #include "modules/audio_coding/include/audio_coding_module.h" #include "modules/audio_coding/test/utility.h" +#include "system_wrappers/include/trace.h" #include "test/gtest.h" #include "test/testsupport/fileutils.h" @@ -175,6 +176,9 @@ void Receiver::Setup(AudioCodingModule *acm, RTPStream *rtpStream, void Receiver::Teardown() { delete[] _playoutBuffer; _pcmFile.Close(); + if (testMode > 1) { + Trace::ReturnTrace(); + } } bool Receiver::IncomingPacket() { @@ -250,6 +254,9 @@ void Receiver::Run() { EncodeDecodeTest::EncodeDecodeTest() { _testMode = 2; + Trace::CreateTrace(); + Trace::SetTraceFile( + (webrtc::test::OutputPath() + "acm_encdec_trace.txt").c_str()); } EncodeDecodeTest::EncodeDecodeTest(int testMode) { @@ -257,6 +264,11 @@ EncodeDecodeTest::EncodeDecodeTest(int testMode) { //testMode == 1 for testing all codecs/parameters //testMode > 1 for specific user-input test (as it was used before) _testMode = testMode; + if (_testMode != 0) { + Trace::CreateTrace(); + Trace::SetTraceFile( + (webrtc::test::OutputPath() + "acm_encdec_trace.txt").c_str()); + } } void EncodeDecodeTest::Perform() { @@ -314,6 +326,11 @@ void EncodeDecodeTest::Perform() { rtpFile.Close(); } } + + // End tracing. + if (_testMode == 1) { + Trace::ReturnTrace(); + } } std::string EncodeDecodeTest::EncodeToFile(int fileType, diff --git a/modules/audio_coding/test/Tester.cc b/modules/audio_coding/test/Tester.cc index 73625f1708..7d58b6ded3 100644 --- a/modules/audio_coding/test/Tester.cc +++ b/modules/audio_coding/test/Tester.cc @@ -23,15 +23,22 @@ #include "modules/audio_coding/test/TwoWayCommunication.h" #include "modules/audio_coding/test/iSACTest.h" #include "modules/audio_coding/test/opus_test.h" +#include "system_wrappers/include/trace.h" #include "test/gtest.h" #include "test/testsupport/fileutils.h" +using webrtc::Trace; + // This parameter is used to describe how to run the tests. It is normally // set to 0, and all tests are run in quite mode. #define ACM_TEST_MODE 0 TEST(AudioCodingModuleTest, TestAllCodecs) { + Trace::CreateTrace(); + Trace::SetTraceFile((webrtc::test::OutputPath() + + "acm_allcodecs_trace.txt").c_str()); webrtc::TestAllCodecs(ACM_TEST_MODE).Perform(); + Trace::ReturnTrace(); } #if defined(WEBRTC_ANDROID) @@ -39,7 +46,11 @@ TEST(AudioCodingModuleTest, DISABLED_TestEncodeDecode) { #else TEST(AudioCodingModuleTest, TestEncodeDecode) { #endif + Trace::CreateTrace(); + Trace::SetTraceFile((webrtc::test::OutputPath() + + "acm_encodedecode_trace.txt").c_str()); webrtc::EncodeDecodeTest(ACM_TEST_MODE).Perform(); + Trace::ReturnTrace(); } #if defined(WEBRTC_CODEC_RED) @@ -48,7 +59,11 @@ TEST(AudioCodingModuleTest, DISABLED_TestRedFec) { #else TEST(AudioCodingModuleTest, TestRedFec) { #endif + Trace::CreateTrace(); + Trace::SetTraceFile((webrtc::test::OutputPath() + + "acm_fec_trace.txt").c_str()); webrtc::TestRedFec().Perform(); + Trace::ReturnTrace(); } #endif @@ -58,7 +73,11 @@ TEST(AudioCodingModuleTest, DISABLED_TestIsac) { #else TEST(AudioCodingModuleTest, TestIsac) { #endif + Trace::CreateTrace(); + Trace::SetTraceFile((webrtc::test::OutputPath() + + "acm_isac_trace.txt").c_str()); webrtc::ISACTest(ACM_TEST_MODE).Perform(); + Trace::ReturnTrace(); } #endif @@ -69,7 +88,11 @@ TEST(AudioCodingModuleTest, DISABLED_TwoWayCommunication) { #else TEST(AudioCodingModuleTest, TwoWayCommunication) { #endif + Trace::CreateTrace(); + Trace::SetTraceFile((webrtc::test::OutputPath() + + "acm_twowaycom_trace.txt").c_str()); webrtc::TwoWayCommunication(ACM_TEST_MODE).Perform(); + Trace::ReturnTrace(); } #endif @@ -79,7 +102,11 @@ TEST(AudioCodingModuleTest, DISABLED_TestStereo) { #else TEST(AudioCodingModuleTest, TestStereo) { #endif + Trace::CreateTrace(); + Trace::SetTraceFile((webrtc::test::OutputPath() + + "acm_stereo_trace.txt").c_str()); webrtc::TestStereo(ACM_TEST_MODE).Perform(); + Trace::ReturnTrace(); } // Disabled on ios as flaky, see https://crbug.com/webrtc/7057 @@ -88,11 +115,19 @@ TEST(AudioCodingModuleTest, DISABLED_TestWebRtcVadDtx) { #else TEST(AudioCodingModuleTest, TestWebRtcVadDtx) { #endif + Trace::CreateTrace(); + Trace::SetTraceFile((webrtc::test::OutputPath() + + "acm_vaddtx_trace.txt").c_str()); webrtc::TestWebRtcVadDtx().Perform(); + Trace::ReturnTrace(); } TEST(AudioCodingModuleTest, TestOpusDtx) { + Trace::CreateTrace(); + Trace::SetTraceFile((webrtc::test::OutputPath() + + "acm_opusdtx_trace.txt").c_str()); webrtc::TestOpusDtx().Perform(); + Trace::ReturnTrace(); } // Disabled on ios as flaky, see https://crbug.com/webrtc/7057 @@ -101,15 +136,27 @@ TEST(AudioCodingModuleTest, DISABLED_TestOpus) { #else TEST(AudioCodingModuleTest, TestOpus) { #endif + Trace::CreateTrace(); + Trace::SetTraceFile((webrtc::test::OutputPath() + + "acm_opus_trace.txt").c_str()); webrtc::OpusTest().Perform(); + Trace::ReturnTrace(); } TEST(AudioCodingModuleTest, TestPacketLoss) { + Trace::CreateTrace(); + Trace::SetTraceFile((webrtc::test::OutputPath() + + "acm_packetloss_trace.txt").c_str()); webrtc::PacketLossTest(1, 10, 10, 1).Perform(); + Trace::ReturnTrace(); } TEST(AudioCodingModuleTest, TestPacketLossBurst) { + Trace::CreateTrace(); + Trace::SetTraceFile((webrtc::test::OutputPath() + + "acm_packetloss_burst_trace.txt").c_str()); webrtc::PacketLossTest(1, 10, 10, 2).Perform(); + Trace::ReturnTrace(); } // Disabled on ios as flake, see https://crbug.com/webrtc/7057 @@ -118,7 +165,11 @@ TEST(AudioCodingModuleTest, DISABLED_TestPacketLossStereo) { #else TEST(AudioCodingModuleTest, TestPacketLossStereo) { #endif + Trace::CreateTrace(); + Trace::SetTraceFile((webrtc::test::OutputPath() + + "acm_packetloss_trace.txt").c_str()); webrtc::PacketLossTest(2, 10, 10, 1).Perform(); + Trace::ReturnTrace(); } // Disabled on ios as flake, see https://crbug.com/webrtc/7057 @@ -127,13 +178,21 @@ TEST(AudioCodingModuleTest, DISABLED_TestPacketLossStereoBurst) { #else TEST(AudioCodingModuleTest, TestPacketLossStereoBurst) { #endif + Trace::CreateTrace(); + Trace::SetTraceFile((webrtc::test::OutputPath() + + "acm_packetloss_burst_trace.txt").c_str()); webrtc::PacketLossTest(2, 10, 10, 2).Perform(); + Trace::ReturnTrace(); } // The full API test is too long to run automatically on bots, but can be used // for offline testing. User interaction is needed. #ifdef ACM_TEST_FULL_API TEST(AudioCodingModuleTest, TestAPI) { + Trace::CreateTrace(); + Trace::SetTraceFile((webrtc::test::OutputPath() + + "acm_apitest_trace.txt").c_str()); webrtc::APITest().Perform(); + Trace::ReturnTrace(); } #endif diff --git a/modules/audio_processing/agc/agc_manager_direct_unittest.cc b/modules/audio_processing/agc/agc_manager_direct_unittest.cc index 6a8af6aa71..a7a296bd05 100644 --- a/modules/audio_processing/agc/agc_manager_direct_unittest.cc +++ b/modules/audio_processing/agc/agc_manager_direct_unittest.cc @@ -13,8 +13,10 @@ #include "common_types.h" // NOLINT(build/include) #include "modules/audio_processing/agc/mock_agc.h" #include "modules/audio_processing/include/mock_audio_processing.h" +#include "system_wrappers/include/trace.h" #include "test/gmock.h" #include "test/gtest.h" +#include "test/testsupport/trace_to_stderr.h" using ::testing::_; using ::testing::DoAll; @@ -92,6 +94,7 @@ class AgcManagerDirectTest : public ::testing::Test { test::MockGainControl gctrl_; TestVolumeCallbacks volume_; AgcManagerDirect manager_; + test::TraceToStderr trace_to_stderr; }; TEST_F(AgcManagerDirectTest, StartupMinVolumeConfigurationIsRespected) { diff --git a/modules/audio_processing/audio_processing_unittest.cc b/modules/audio_processing/audio_processing_unittest.cc index 6893159dad..7cd2c95e01 100644 --- a/modules/audio_processing/audio_processing_unittest.cc +++ b/modules/audio_processing/audio_processing_unittest.cc @@ -38,6 +38,7 @@ #include "rtc_base/task_queue.h" #include "rtc_base/thread.h" #include "system_wrappers/include/event_wrapper.h" +#include "system_wrappers/include/trace.h" #include "test/gtest.h" #include "test/testsupport/fileutils.h" @@ -350,9 +351,11 @@ class ApmTest : public ::testing::Test { virtual void TearDown(); static void SetUpTestCase() { + Trace::CreateTrace(); } static void TearDownTestCase() { + Trace::ReturnTrace(); ClearTempFiles(); } diff --git a/modules/audio_processing/test/aec_dump_based_simulator.cc b/modules/audio_processing/test/aec_dump_based_simulator.cc index 23b7afb453..0e32978f73 100644 --- a/modules/audio_processing/test/aec_dump_based_simulator.cc +++ b/modules/audio_processing/test/aec_dump_based_simulator.cc @@ -14,6 +14,7 @@ #include "modules/audio_processing/test/protobuf_utils.h" #include "rtc_base/checks.h" +#include "test/testsupport/trace_to_stderr.h" namespace webrtc { namespace test { @@ -209,6 +210,11 @@ void AecDumpBasedSimulator::PrepareReverseProcessStreamCall( } void AecDumpBasedSimulator::Process() { + std::unique_ptr trace_to_stderr; + if (settings_.use_verbose_logging) { + trace_to_stderr.reset(new test::TraceToStderr(true)); + } + CreateAudioProcessor(); dump_input_file_ = OpenFile(settings_.aec_dump_input_filename->c_str(), "rb"); @@ -229,6 +235,8 @@ void AecDumpBasedSimulator::Process() { webrtc::audioproc::Event event_msg; int num_forward_chunks_processed = 0; + const float kOneBykChunksPerSecond = + 1.f / AudioProcessingSimulator::kChunksPerSecond; while (ReadMessageFromFile(dump_input_file_, &event_msg)) { switch (event_msg.type()) { case webrtc::audioproc::Event::INIT: @@ -251,6 +259,10 @@ void AecDumpBasedSimulator::Process() { default: RTC_CHECK(false); } + if (trace_to_stderr) { + trace_to_stderr->SetTimeSeconds(num_forward_chunks_processed * + kOneBykChunksPerSecond); + } } fclose(dump_input_file_); diff --git a/modules/audio_processing/test/wav_based_simulator.cc b/modules/audio_processing/test/wav_based_simulator.cc index f53d1e5d8d..599242969a 100644 --- a/modules/audio_processing/test/wav_based_simulator.cc +++ b/modules/audio_processing/test/wav_based_simulator.cc @@ -15,6 +15,7 @@ #include "modules/audio_processing/test/test_utils.h" #include "rtc_base/checks.h" +#include "test/testsupport/trace_to_stderr.h" namespace webrtc { namespace test { @@ -87,6 +88,11 @@ void WavBasedSimulator::PrepareReverseProcessStreamCall() { } void WavBasedSimulator::Process() { + std::unique_ptr trace_to_stderr; + if (settings_.use_verbose_logging) { + trace_to_stderr.reset(new test::TraceToStderr(true)); + } + if (settings_.custom_call_order_filename) { call_chain_ = WavBasedSimulator::GetCustomEventChain( *settings_.custom_call_order_filename); @@ -100,6 +106,8 @@ void WavBasedSimulator::Process() { bool samples_left_to_process = true; int call_chain_index = 0; int num_forward_chunks_processed = 0; + const int kOneBykChunksPerSecond = + 1.f / AudioProcessingSimulator::kChunksPerSecond; while (samples_left_to_process) { switch (call_chain_[call_chain_index]) { case SimulationEventType::kProcessStream: @@ -116,6 +124,11 @@ void WavBasedSimulator::Process() { } call_chain_index = (call_chain_index + 1) % call_chain_.size(); + + if (trace_to_stderr) { + trace_to_stderr->SetTimeSeconds(num_forward_chunks_processed * + kOneBykChunksPerSecond); + } } DestroyAudioProcessor(); diff --git a/rtc_base/java/src/org/webrtc/Logging.java b/rtc_base/java/src/org/webrtc/Logging.java index 3fd6ffc880..1afb687605 100644 --- a/rtc_base/java/src/org/webrtc/Logging.java +++ b/rtc_base/java/src/org/webrtc/Logging.java @@ -22,6 +22,7 @@ import java.util.logging.Logger; * app: * - Logging.enableLogThreads * - Logging.enableLogTimeStamps + * - Logging.enableTracing * - Logging.enableLogToDebugOutput * * Using these APIs requires that the native library is loaded. For example: @@ -33,6 +34,7 @@ import java.util.logging.Logger; */ public class Logging { private static final Logger fallbackLogger = createFallbackLogger(); + private static volatile boolean tracingEnabled; private static volatile boolean loggingEnabled; private static Logger createFallbackLogger() { @@ -41,8 +43,7 @@ public class Logging { return fallbackLogger; } - // TODO(solenberg): Remove once dependent projects updated. - @Deprecated + // Keep in sync with webrtc/common_types.h:TraceLevel. public enum TraceLevel { TRACE_NONE(0x0000), TRACE_STATEINFO(0x0001), @@ -77,9 +78,19 @@ public class Logging { nativeEnableLogTimeStamps(); } - // TODO(solenberg): Remove once dependent projects updated. - @Deprecated - public static void enableTracing(String path, EnumSet levels) { + // Enable tracing to |path| of messages of |levels|. + // On Android, use "logcat:" for |path| to send output there. + // Note: this function controls the output of the WEBRTC_TRACE() macros. + public static synchronized void enableTracing(String path, EnumSet levels) { + if (tracingEnabled) { + return; + } + int nativeLevel = 0; + for (TraceLevel level : levels) { + nativeLevel |= level.level; + } + nativeEnableTracing(path, nativeLevel); + tracingEnabled = true; } // Enable diagnostic logging for messages of |severity| to the platform debug @@ -154,6 +165,7 @@ public class Logging { return sw.toString(); } + private static native void nativeEnableTracing(String path, int nativeLevels); private static native void nativeEnableLogToDebugOutput(int nativeSeverity); private static native void nativeEnableLogThreads(); private static native void nativeEnableLogTimeStamps(); diff --git a/sdk/android/instrumentationtests/src/org/webrtc/PeerConnectionTest.java b/sdk/android/instrumentationtests/src/org/webrtc/PeerConnectionTest.java index eff28eccb2..699c7de205 100644 --- a/sdk/android/instrumentationtests/src/org/webrtc/PeerConnectionTest.java +++ b/sdk/android/instrumentationtests/src/org/webrtc/PeerConnectionTest.java @@ -597,6 +597,12 @@ public class PeerConnectionTest { PeerConnectionFactory.Options options = new PeerConnectionFactory.Options(); options.networkIgnoreMask = 0; PeerConnectionFactory factory = new PeerConnectionFactory(options); + // Uncomment to get ALL WebRTC tracing and SENSITIVE libjingle logging. + // NOTE: this _must_ happen while |factory| is alive! + // Logging.enableTracing( + // "/tmp/PeerConnectionTest-log.txt", + // EnumSet.of(Logging.TraceLevel.TRACE_ALL), + // Logging.Severity.LS_SENSITIVE); MediaConstraints pcConstraints = new MediaConstraints(); pcConstraints.mandatory.add(new MediaConstraints.KeyValuePair("DtlsSrtpKeyAgreement", "true")); diff --git a/sdk/android/src/jni/pc/logging_jni.cc b/sdk/android/src/jni/pc/logging_jni.cc index 7e3e1d3213..2b3d9d62c9 100644 --- a/sdk/android/src/jni/pc/logging_jni.cc +++ b/sdk/android/src/jni/pc/logging_jni.cc @@ -12,10 +12,32 @@ #include "rtc_base/logging.h" #include "sdk/android/src/jni/jni_helpers.h" +#include "system_wrappers/include/logcat_trace_context.h" +#include "system_wrappers/include/trace.h" namespace webrtc { namespace jni { +JNI_FUNCTION_DECLARATION(void, + Logging_nativeEnableTracing, + JNIEnv* jni, + jclass, + jstring j_path, + jint nativeLevels) { + std::string path = JavaToStdString(jni, j_path); + if (nativeLevels != kTraceNone) { + Trace::set_level_filter(nativeLevels); + if (path != "logcat:") { + RTC_CHECK_EQ(0, Trace::SetTraceFile(path.c_str(), false)) + << "SetTraceFile failed"; + } else { + // Intentionally leak this to avoid needing to reason about its lifecycle. + // It keeps no state and functions only as a dispatch point. + static LogcatTraceContext* g_trace_callback = new LogcatTraceContext(); + } + } +} + JNI_FUNCTION_DECLARATION(void, Logging_nativeEnableLogToDebugOutput, JNIEnv* jni, diff --git a/sdk/android/src/jni/pc/peerconnectionfactory_jni.cc b/sdk/android/src/jni/pc/peerconnectionfactory_jni.cc index 466bf84854..bf35b80949 100644 --- a/sdk/android/src/jni/pc/peerconnectionfactory_jni.cc +++ b/sdk/android/src/jni/pc/peerconnectionfactory_jni.cc @@ -30,6 +30,7 @@ // We don't want to depend on 'system_wrappers:field_trial_default' because // clients should be able to provide their own implementation. #include "system_wrappers/include/field_trial_default.h" // nogncheck +#include "system_wrappers/include/trace.h" namespace webrtc { namespace jni { @@ -146,6 +147,7 @@ JNI_FUNCTION_DECLARATION( // webrtc/rtc_base/ are convoluted, we simply wrap here to avoid having to // think about ramifications of auto-wrapping there. rtc::ThreadManager::Instance()->WrapCurrentThread(); + Trace::CreateTrace(); std::unique_ptr network_thread = rtc::Thread::CreateWithSocketServer(); @@ -223,6 +225,7 @@ JNI_FUNCTION_DECLARATION(void, delete field_trials_init_string; field_trials_init_string = NULL; } + Trace::ReturnTrace(); } JNI_FUNCTION_DECLARATION(void, diff --git a/system_wrappers/BUILD.gn b/system_wrappers/BUILD.gn index 30ebc4742b..29ee8b87de 100644 --- a/system_wrappers/BUILD.gn +++ b/system_wrappers/BUILD.gn @@ -28,6 +28,7 @@ rtc_static_library("system_wrappers") { "include/sleep.h", "include/static_instance.h", "include/timestamp_extrapolator.h", + "include/trace.h", "source/aligned_malloc.cc", "source/atomic32_win.cc", "source/clock.cc", @@ -47,6 +48,12 @@ rtc_static_library("system_wrappers") { "source/rw_lock_win.h", "source/sleep.cc", "source/timestamp_extrapolator.cc", + "source/trace_impl.cc", + "source/trace_impl.h", + "source/trace_posix.cc", + "source/trace_posix.h", + "source/trace_win.cc", + "source/trace_win.h", ] defines = [] @@ -61,6 +68,11 @@ rtc_static_library("system_wrappers") { ] if (is_android) { + sources += [ + "include/logcat_trace_context.h", + "source/logcat_trace_context.cc", + ] + defines += [ "WEBRTC_THREAD_RR" ] deps += [ ":cpu_features_android" ] diff --git a/system_wrappers/include/logcat_trace_context.h b/system_wrappers/include/logcat_trace_context.h new file mode 100644 index 0000000000..8eb688dc8b --- /dev/null +++ b/system_wrappers/include/logcat_trace_context.h @@ -0,0 +1,35 @@ +/* + * Copyright (c) 2013 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 SYSTEM_WRAPPERS_INCLUDE_LOGCAT_TRACE_CONTEXT_H_ +#define SYSTEM_WRAPPERS_INCLUDE_LOGCAT_TRACE_CONTEXT_H_ + +#include "system_wrappers/include/trace.h" + +#ifndef ANDROID +#error This file only makes sense to include on Android! +#endif + +namespace webrtc { + +// Scoped helper class for directing Traces to Android's logcat facility. While +// this object lives, Trace output will be sent to logcat. +class LogcatTraceContext : public webrtc::TraceCallback { + public: + LogcatTraceContext(); + ~LogcatTraceContext() override; + + // TraceCallback impl. + void Print(TraceLevel level, const char* message, int length) override; +}; + +} // namespace webrtc + +#endif // SYSTEM_WRAPPERS_INCLUDE_LOGCAT_TRACE_CONTEXT_H_ diff --git a/system_wrappers/include/trace.h b/system_wrappers/include/trace.h new file mode 100644 index 0000000000..e498a52537 --- /dev/null +++ b/system_wrappers/include/trace.h @@ -0,0 +1,89 @@ +/* + * Copyright (c) 2012 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. + * + * System independent wrapper for logging runtime information to file. + * Note: All log messages will be written to the same trace file. + * Note: If too many messages are written to file there will be a build up of + * messages. Apply filtering to avoid that. + */ + +#ifndef SYSTEM_WRAPPERS_INCLUDE_TRACE_H_ +#define SYSTEM_WRAPPERS_INCLUDE_TRACE_H_ + +#include "common_types.h" // NOLINT(build/include) +#include "typedefs.h" // NOLINT(build/include) + +namespace webrtc { + +#if defined(WEBRTC_RESTRICT_LOGGING) +// Disable all TRACE macros. The LOG macro is still functional. +#define WEBRTC_TRACE true ? (void) 0 : Trace::Add +#else +#define WEBRTC_TRACE Trace::Add +#endif + +class Trace { + public: + // The length of the trace text preceeding the log message. + static const int kBoilerplateLength; + // The position of the timestamp text within a trace. + static const int kTimestampPosition; + // The length of the timestamp (without "delta" field). + static const int kTimestampLength; + + // Increments the reference count to the trace. + static void CreateTrace(); + // Decrements the reference count to the trace. + static void ReturnTrace(); + // Note: any instance that writes to the trace file should increment and + // decrement the reference count on construction and destruction, + // respectively. + + // Specifies what type of messages should be written to the trace file. The + // filter parameter is a bitmask where each message type is enumerated by the + // TraceLevel enumerator. TODO(hellner): why is the TraceLevel enumerator not + // defined in this file? + static void set_level_filter(int filter); + + // Returns what type of messages are written to the trace file. + static int level_filter(); + + // Sets the file name. If add_file_counter is false the same file will be + // reused when it fills up. If it's true a new file with incremented name + // will be used. + static int32_t SetTraceFile(const char* file_name, + const bool add_file_counter = false); + + // Registers callback to receive trace messages. + // TODO(hellner): Why not use OutStream instead? Why is TraceCallback not + // defined in this file? + static int32_t SetTraceCallback(TraceCallback* callback); + + // Adds a trace message for writing to file. The message is put in a queue + // for writing to file whenever possible for performance reasons. I.e. there + // is a crash it is possible that the last, vital logs are not logged yet. + // level is the type of message to log. If that type of messages is + // filtered it will not be written to file. module is an identifier for what + // part of the code the message is coming. + // id is an identifier that should be unique for that set of classes that + // are associated (e.g. all instances owned by an engine). + // msg and the ellipsis are the same as e.g. sprintf. + // TODO(hellner) Why is TraceModule not defined in this file? + static void Add(const TraceLevel level, + const TraceModule module, + const int32_t id, + const char* msg, ...); + + private: + static volatile int level_filter_; +}; + +} // namespace webrtc + +#endif // SYSTEM_WRAPPERS_INCLUDE_TRACE_H_ diff --git a/system_wrappers/source/logcat_trace_context.cc b/system_wrappers/source/logcat_trace_context.cc new file mode 100644 index 0000000000..cb43dddd5b --- /dev/null +++ b/system_wrappers/source/logcat_trace_context.cc @@ -0,0 +1,63 @@ +/* + * Copyright (c) 2013 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 "system_wrappers/include/logcat_trace_context.h" + +#include +#include + +#include "rtc_base/logging.h" + +namespace webrtc { + +static android_LogPriority AndroidLogPriorityFromWebRtcLogLevel( + TraceLevel webrtc_level) { + // NOTE: this mapping is somewhat arbitrary. StateInfo and Info are mapped + // to DEBUG because they are highly verbose in webrtc code (which is + // unfortunate). + switch (webrtc_level) { + case webrtc::kTraceStateInfo: return ANDROID_LOG_DEBUG; + case webrtc::kTraceWarning: return ANDROID_LOG_WARN; + case webrtc::kTraceError: return ANDROID_LOG_ERROR; + case webrtc::kTraceCritical: return ANDROID_LOG_FATAL; + case webrtc::kTraceApiCall: return ANDROID_LOG_VERBOSE; + case webrtc::kTraceModuleCall: return ANDROID_LOG_VERBOSE; + case webrtc::kTraceMemory: return ANDROID_LOG_VERBOSE; + case webrtc::kTraceTimer: return ANDROID_LOG_VERBOSE; + case webrtc::kTraceStream: return ANDROID_LOG_VERBOSE; + case webrtc::kTraceDebug: return ANDROID_LOG_DEBUG; + case webrtc::kTraceInfo: return ANDROID_LOG_DEBUG; + case webrtc::kTraceTerseInfo: return ANDROID_LOG_INFO; + default: + LOG(LS_ERROR) << "Unexpected log level" << webrtc_level; + return ANDROID_LOG_FATAL; + } +} + +LogcatTraceContext::LogcatTraceContext() { + webrtc::Trace::CreateTrace(); + if (webrtc::Trace::SetTraceCallback(this) != 0) + assert(false); +} + +LogcatTraceContext::~LogcatTraceContext() { + if (webrtc::Trace::SetTraceCallback(NULL) != 0) + assert(false); + webrtc::Trace::ReturnTrace(); +} + +void LogcatTraceContext::Print(TraceLevel level, + const char* message, + int length) { + __android_log_print(AndroidLogPriorityFromWebRtcLogLevel(level), + "WEBRTC", "%.*s", length, message); +} + +} // namespace webrtc diff --git a/system_wrappers/source/trace_impl.cc b/system_wrappers/source/trace_impl.cc new file mode 100644 index 0000000000..c1ec984f6d --- /dev/null +++ b/system_wrappers/source/trace_impl.cc @@ -0,0 +1,583 @@ +/* + * Copyright (c) 2012 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 "system_wrappers/source/trace_impl.h" + +#include +#include +#include +#include + +#include "rtc_base/atomicops.h" +#include "rtc_base/platform_thread.h" +#ifdef _WIN32 +#include "system_wrappers/source/trace_win.h" +#else +#include "system_wrappers/source/trace_posix.h" +#endif // _WIN32 + +#define KEY_LEN_CHARS 31 + +#ifdef _WIN32 +#pragma warning(disable:4355) +#endif // _WIN32 + +namespace webrtc { + +const int Trace::kBoilerplateLength = 71; +const int Trace::kTimestampPosition = 13; +const int Trace::kTimestampLength = 12; +volatile int Trace::level_filter_ = kTraceDefault; + +// Construct On First Use idiom. Avoids "static initialization order fiasco". +TraceImpl* TraceImpl::StaticInstance(CountOperation count_operation, + const TraceLevel level) { + // Sanities to avoid taking lock unless absolutely necessary (for + // performance reasons). count_operation == kAddRefNoCreate implies that a + // message will be written to file. + if ((level != kTraceAll) && (count_operation == kAddRefNoCreate)) { + if (!(level & level_filter())) { + return NULL; + } + } + TraceImpl* impl = + GetStaticInstance(count_operation); + return impl; +} + +TraceImpl* TraceImpl::GetTrace(const TraceLevel level) { + return StaticInstance(kAddRefNoCreate, level); +} + +TraceImpl* TraceImpl::CreateInstance() { +#if defined(_WIN32) + return new TraceWindows(); +#else + return new TracePosix(); +#endif +} + +TraceImpl::TraceImpl() + : callback_(NULL), + row_count_text_(0), + file_count_text_(0), + trace_file_(FileWrapper::Create()) { +} + +TraceImpl::~TraceImpl() { + trace_file_->CloseFile(); +} + +int32_t TraceImpl::AddThreadId(char* trace_message) const { + uint32_t thread_id = rtc::CurrentThreadId(); + // Messages is 12 characters. + return sprintf(trace_message, "%10u; ", thread_id); +} + +int32_t TraceImpl::AddLevel(char* sz_message, const TraceLevel level) const { + const int kMessageLength = 12; + switch (level) { + case kTraceTerseInfo: + // Add the appropriate amount of whitespace. + memset(sz_message, ' ', kMessageLength); + sz_message[kMessageLength] = '\0'; + break; + case kTraceStateInfo: + sprintf(sz_message, "STATEINFO ; "); + break; + case kTraceWarning: + sprintf(sz_message, "WARNING ; "); + break; + case kTraceError: + sprintf(sz_message, "ERROR ; "); + break; + case kTraceCritical: + sprintf(sz_message, "CRITICAL ; "); + break; + case kTraceInfo: + sprintf(sz_message, "DEBUGINFO ; "); + break; + case kTraceModuleCall: + sprintf(sz_message, "MODULECALL; "); + break; + case kTraceMemory: + sprintf(sz_message, "MEMORY ; "); + break; + case kTraceTimer: + sprintf(sz_message, "TIMER ; "); + break; + case kTraceStream: + sprintf(sz_message, "STREAM ; "); + break; + case kTraceApiCall: + sprintf(sz_message, "APICALL ; "); + break; + case kTraceDebug: + sprintf(sz_message, "DEBUG ; "); + break; + default: + assert(false); + return 0; + } + // All messages are 12 characters. + return kMessageLength; +} + +int32_t TraceImpl::AddModuleAndId(char* trace_message, + const TraceModule module, + const int32_t id) const { + // Use long int to prevent problems with different definitions of + // int32_t. + // TODO(hellner): is this actually a problem? If so, it should be better to + // clean up int32_t + const long int idl = id; + const int kMessageLength = 25; + if (idl != -1) { + const unsigned long int id_engine = id >> 16; + const unsigned long int id_channel = id & 0xffff; + + switch (module) { + case kTraceUndefined: + // Add the appropriate amount of whitespace. + memset(trace_message, ' ', kMessageLength); + trace_message[kMessageLength] = '\0'; + break; + case kTraceVoice: + sprintf(trace_message, " VOICE:%5ld %5ld;", id_engine, + id_channel); + break; + case kTraceVideo: + sprintf(trace_message, " VIDEO:%5ld %5ld;", id_engine, + id_channel); + break; + case kTraceUtility: + sprintf(trace_message, " UTILITY:%5ld %5ld;", id_engine, + id_channel); + break; + case kTraceRtpRtcp: + sprintf(trace_message, " RTP/RTCP:%5ld %5ld;", id_engine, + id_channel); + break; + case kTraceTransport: + sprintf(trace_message, " TRANSPORT:%5ld %5ld;", id_engine, + id_channel); + break; + case kTraceAudioCoding: + sprintf(trace_message, "AUDIO CODING:%5ld %5ld;", id_engine, + id_channel); + break; + case kTraceSrtp: + sprintf(trace_message, " SRTP:%5ld %5ld;", id_engine, + id_channel); + break; + case kTraceAudioMixerServer: + sprintf(trace_message, " AUDIO MIX/S:%5ld %5ld;", id_engine, + id_channel); + break; + case kTraceAudioMixerClient: + sprintf(trace_message, " AUDIO MIX/C:%5ld %5ld;", id_engine, + id_channel); + break; + case kTraceVideoCoding: + sprintf(trace_message, "VIDEO CODING:%5ld %5ld;", id_engine, + id_channel); + break; + case kTraceVideoMixer: + // Print sleep time and API call + sprintf(trace_message, " VIDEO MIX:%5ld %5ld;", id_engine, + id_channel); + break; + case kTraceFile: + sprintf(trace_message, " FILE:%5ld %5ld;", id_engine, + id_channel); + break; + case kTraceAudioProcessing: + sprintf(trace_message, " AUDIO PROC:%5ld %5ld;", id_engine, + id_channel); + break; + case kTraceAudioDevice: + sprintf(trace_message, "AUDIO DEVICE:%5ld %5ld;", id_engine, + id_channel); + break; + case kTraceVideoRenderer: + sprintf(trace_message, "VIDEO RENDER:%5ld %5ld;", id_engine, + id_channel); + break; + case kTraceVideoCapture: + sprintf(trace_message, "VIDEO CAPTUR:%5ld %5ld;", id_engine, + id_channel); + break; + case kTraceRemoteBitrateEstimator: + sprintf(trace_message, " BWE RBE:%5ld %5ld;", id_engine, + id_channel); + break; + } + } else { + switch (module) { + case kTraceUndefined: + // Add the appropriate amount of whitespace. + memset(trace_message, ' ', kMessageLength); + trace_message[kMessageLength] = '\0'; + break; + case kTraceVoice: + sprintf(trace_message, " VOICE:%11ld;", idl); + break; + case kTraceVideo: + sprintf(trace_message, " VIDEO:%11ld;", idl); + break; + case kTraceUtility: + sprintf(trace_message, " UTILITY:%11ld;", idl); + break; + case kTraceRtpRtcp: + sprintf(trace_message, " RTP/RTCP:%11ld;", idl); + break; + case kTraceTransport: + sprintf(trace_message, " TRANSPORT:%11ld;", idl); + break; + case kTraceAudioCoding: + sprintf(trace_message, "AUDIO CODING:%11ld;", idl); + break; + case kTraceSrtp: + sprintf(trace_message, " SRTP:%11ld;", idl); + break; + case kTraceAudioMixerServer: + sprintf(trace_message, " AUDIO MIX/S:%11ld;", idl); + break; + case kTraceAudioMixerClient: + sprintf(trace_message, " AUDIO MIX/C:%11ld;", idl); + break; + case kTraceVideoCoding: + sprintf(trace_message, "VIDEO CODING:%11ld;", idl); + break; + case kTraceVideoMixer: + sprintf(trace_message, " VIDEO MIX:%11ld;", idl); + break; + case kTraceFile: + sprintf(trace_message, " FILE:%11ld;", idl); + break; + case kTraceAudioProcessing: + sprintf(trace_message, " AUDIO PROC:%11ld;", idl); + break; + case kTraceAudioDevice: + sprintf(trace_message, "AUDIO DEVICE:%11ld;", idl); + break; + case kTraceVideoRenderer: + sprintf(trace_message, "VIDEO RENDER:%11ld;", idl); + break; + case kTraceVideoCapture: + sprintf(trace_message, "VIDEO CAPTUR:%11ld;", idl); + break; + case kTraceRemoteBitrateEstimator: + sprintf(trace_message, " BWE RBE:%11ld;", idl); + break; + } + } + return kMessageLength; +} + +int32_t TraceImpl::SetTraceFileImpl(const char* file_name_utf8, + const bool add_file_counter) { + rtc::CritScope lock(&crit_); + + trace_file_->CloseFile(); + trace_file_path_.clear(); + + if (file_name_utf8) { + if (add_file_counter) { + file_count_text_ = 1; + + char file_name_with_counter_utf8[FileWrapper::kMaxFileNameSize]; + CreateFileName(file_name_utf8, file_name_with_counter_utf8, + file_count_text_); + if (!trace_file_->OpenFile(file_name_with_counter_utf8, false)) { + return -1; + } + trace_file_path_ = file_name_with_counter_utf8; + } else { + file_count_text_ = 0; + if (!trace_file_->OpenFile(file_name_utf8, false)) { + return -1; + } + trace_file_path_ = file_name_utf8; + } + } + row_count_text_ = 0; + return 0; +} + +int32_t TraceImpl::SetTraceCallbackImpl(TraceCallback* callback) { + rtc::CritScope lock(&crit_); + callback_ = callback; + return 0; +} + +int32_t TraceImpl::AddMessage( + char* trace_message, + const char msg[WEBRTC_TRACE_MAX_MESSAGE_SIZE], + const uint16_t written_so_far) const { + int length = 0; + if (written_so_far >= WEBRTC_TRACE_MAX_MESSAGE_SIZE) { + return -1; + } + // - 2 to leave room for newline and NULL termination. +#ifdef _WIN32 + length = _snprintf(trace_message, + WEBRTC_TRACE_MAX_MESSAGE_SIZE - written_so_far - 2, + "%s", msg); + if (length < 0) { + length = WEBRTC_TRACE_MAX_MESSAGE_SIZE - written_so_far - 2; + trace_message[length] = 0; + } +#else + length = snprintf(trace_message, + WEBRTC_TRACE_MAX_MESSAGE_SIZE - written_so_far - 2, + "%s", msg); + if (length < 0 || + length > WEBRTC_TRACE_MAX_MESSAGE_SIZE - written_so_far - 2) { + length = WEBRTC_TRACE_MAX_MESSAGE_SIZE - written_so_far - 2; + trace_message[length] = 0; + } +#endif + // Length with NULL termination. + return length + 1; +} + +void TraceImpl::AddMessageToList( + const char trace_message[WEBRTC_TRACE_MAX_MESSAGE_SIZE], + const uint16_t length, + const TraceLevel level) { + rtc::CritScope lock(&crit_); + if (callback_) + callback_->Print(level, trace_message, length); + WriteToFile(trace_message, length); +} + +void TraceImpl::WriteToFile(const char* msg, uint16_t length) { + if (!trace_file_->is_open()) + return; + + if (row_count_text_ > WEBRTC_TRACE_MAX_FILE_SIZE) { + // wrap file + row_count_text_ = 0; + trace_file_->Flush(); + + if (file_count_text_ == 0) { + trace_file_->Rewind(); + } else { + char new_file_name[FileWrapper::kMaxFileNameSize]; + + // get current name + file_count_text_++; + UpdateFileName(new_file_name, file_count_text_); + + trace_file_->CloseFile(); + trace_file_path_.clear(); + + if (!trace_file_->OpenFile(new_file_name, false)) { + return; + } + trace_file_path_ = new_file_name; + } + } + if (row_count_text_ == 0) { + char message[WEBRTC_TRACE_MAX_MESSAGE_SIZE + 1]; + int32_t length = AddDateTimeInfo(message); + if (length != -1) { + message[length] = 0; + message[length - 1] = '\n'; + trace_file_->Write(message, length); + row_count_text_++; + } + } + + char trace_message[WEBRTC_TRACE_MAX_MESSAGE_SIZE]; + memcpy(trace_message, msg, length); + trace_message[length] = 0; + trace_message[length - 1] = '\n'; + trace_file_->Write(trace_message, length); + row_count_text_++; +} + +void TraceImpl::AddImpl(const TraceLevel level, + const TraceModule module, + const int32_t id, + const char msg[WEBRTC_TRACE_MAX_MESSAGE_SIZE]) { + if (!TraceCheck(level)) + return; + + char trace_message[WEBRTC_TRACE_MAX_MESSAGE_SIZE]; + char* message_ptr = &trace_message[0]; + int32_t len = AddLevel(message_ptr, level); + if (len == -1) + return; + + message_ptr += len; + int32_t ack_len = len; + + len = AddTime(message_ptr, level); + if (len == -1) + return; + + message_ptr += len; + ack_len += len; + + len = AddModuleAndId(message_ptr, module, id); + if (len == -1) + return; + + message_ptr += len; + ack_len += len; + + len = AddThreadId(message_ptr); + if (len < 0) + return; + + message_ptr += len; + ack_len += len; + + len = AddMessage(message_ptr, msg, static_cast(ack_len)); + if (len == -1) + return; + + ack_len += len; + AddMessageToList(trace_message, static_cast(ack_len), level); +} + +bool TraceImpl::TraceCheck(const TraceLevel level) const { + return (level & level_filter()) ? true : false; +} + +bool TraceImpl::UpdateFileName( + char file_name_with_counter_utf8[FileWrapper::kMaxFileNameSize], + const uint32_t new_count) const { + int32_t length = static_cast(trace_file_path_.length()); + + int32_t length_without_file_ending = length - 1; + while (length_without_file_ending > 0) { + if (trace_file_path_[length_without_file_ending] == '.') { + break; + } else { + length_without_file_ending--; + } + } + if (length_without_file_ending == 0) { + length_without_file_ending = length; + } + int32_t length_to_ = length_without_file_ending - 1; + while (length_to_ > 0) { + if (trace_file_path_[length_to_] == '_') { + break; + } else { + length_to_--; + } + } + + memcpy(file_name_with_counter_utf8, &trace_file_path_[0], length_to_); + sprintf(file_name_with_counter_utf8 + length_to_, "_%lu%s", + static_cast(new_count), + &trace_file_path_[length_without_file_ending]); + return true; +} + +bool TraceImpl::CreateFileName( + const char file_name_utf8[FileWrapper::kMaxFileNameSize], + char file_name_with_counter_utf8[FileWrapper::kMaxFileNameSize], + const uint32_t new_count) const { + int32_t length = (int32_t)strlen(file_name_utf8); + if (length < 0) { + return false; + } + + int32_t length_without_file_ending = length - 1; + while (length_without_file_ending > 0) { + if (file_name_utf8[length_without_file_ending] == '.') { + break; + } else { + length_without_file_ending--; + } + } + if (length_without_file_ending == 0) { + length_without_file_ending = length; + } + memcpy(file_name_with_counter_utf8, file_name_utf8, + length_without_file_ending); + sprintf(file_name_with_counter_utf8 + length_without_file_ending, "_%lu%s", + static_cast(new_count), + file_name_utf8 + length_without_file_ending); + return true; +} + +// static +void Trace::CreateTrace() { + TraceImpl::StaticInstance(kAddRef); +} + +// static +void Trace::ReturnTrace() { + TraceImpl::StaticInstance(kRelease); +} + +// static +void Trace::set_level_filter(int filter) { + rtc::AtomicOps::ReleaseStore(&level_filter_, filter); +} + +// static +int Trace::level_filter() { + return rtc::AtomicOps::AcquireLoad(&level_filter_); +} + +// static +int32_t Trace::SetTraceFile(const char* file_name, + const bool add_file_counter) { + TraceImpl* trace = TraceImpl::GetTrace(); + if (trace) { + int ret_val = trace->SetTraceFileImpl(file_name, add_file_counter); + ReturnTrace(); + return ret_val; + } + return -1; +} + +int32_t Trace::SetTraceCallback(TraceCallback* callback) { + TraceImpl* trace = TraceImpl::GetTrace(); + if (trace) { + int ret_val = trace->SetTraceCallbackImpl(callback); + ReturnTrace(); + return ret_val; + } + return -1; +} + +void Trace::Add(const TraceLevel level, const TraceModule module, + const int32_t id, const char* msg, ...) { + TraceImpl* trace = TraceImpl::GetTrace(level); + if (trace) { + if (trace->TraceCheck(level)) { + char temp_buff[WEBRTC_TRACE_MAX_MESSAGE_SIZE]; + char* buff = 0; + if (msg) { + va_list args; + va_start(args, msg); +#ifdef _WIN32 + _vsnprintf(temp_buff, WEBRTC_TRACE_MAX_MESSAGE_SIZE - 1, msg, args); +#else + vsnprintf(temp_buff, WEBRTC_TRACE_MAX_MESSAGE_SIZE - 1, msg, args); +#endif + va_end(args); + buff = temp_buff; + } + trace->AddImpl(level, module, id, buff); + } + ReturnTrace(); + } +} + +} // namespace webrtc diff --git a/system_wrappers/source/trace_impl.h b/system_wrappers/source/trace_impl.h new file mode 100644 index 0000000000..3e730f6818 --- /dev/null +++ b/system_wrappers/source/trace_impl.h @@ -0,0 +1,105 @@ +/* + * Copyright (c) 2012 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 SYSTEM_WRAPPERS_SOURCE_TRACE_IMPL_H_ +#define SYSTEM_WRAPPERS_SOURCE_TRACE_IMPL_H_ + +#include + +#include "rtc_base/criticalsection.h" +#include "rtc_base/platform_thread.h" +#include "system_wrappers/include/event_wrapper.h" +#include "system_wrappers/include/file_wrapper.h" +#include "system_wrappers/include/static_instance.h" +#include "system_wrappers/include/trace.h" + +namespace webrtc { + +#define WEBRTC_TRACE_MAX_MESSAGE_SIZE 1024 +// Total buffer size is WEBRTC_TRACE_NUM_ARRAY (number of buffer partitions) * +// WEBRTC_TRACE_MAX_QUEUE (number of lines per buffer partition) * +// WEBRTC_TRACE_MAX_MESSAGE_SIZE (number of 1 byte charachters per line) = +// 1 or 4 Mbyte. + +#define WEBRTC_TRACE_MAX_FILE_SIZE 100*1000 +// Number of rows that may be written to file. On average 110 bytes per row (max +// 256 bytes per row). So on average 110*100*1000 = 11 Mbyte, max 256*100*1000 = +// 25.6 Mbyte + +class TraceImpl : public Trace { + public: + virtual ~TraceImpl(); + + static TraceImpl* CreateInstance(); + static TraceImpl* GetTrace(const TraceLevel level = kTraceAll); + + int32_t SetTraceFileImpl(const char* file_name, const bool add_file_counter); + int32_t SetTraceCallbackImpl(TraceCallback* callback); + + void AddImpl(const TraceLevel level, const TraceModule module, + const int32_t id, const char* msg); + + bool TraceCheck(const TraceLevel level) const; + + protected: + TraceImpl(); + + static TraceImpl* StaticInstance(CountOperation count_operation, + const TraceLevel level = kTraceAll); + + int32_t AddThreadId(char* trace_message) const; + + // OS specific implementations. + virtual int32_t AddTime(char* trace_message, + const TraceLevel level) const = 0; + + virtual int32_t AddDateTimeInfo(char* trace_message) const = 0; + + private: + friend class Trace; + + int32_t AddLevel(char* sz_message, const TraceLevel level) const; + + int32_t AddModuleAndId(char* trace_message, const TraceModule module, + const int32_t id) const; + + int32_t AddMessage(char* trace_message, + const char msg[WEBRTC_TRACE_MAX_MESSAGE_SIZE], + const uint16_t written_so_far) const; + + void AddMessageToList( + const char trace_message[WEBRTC_TRACE_MAX_MESSAGE_SIZE], + const uint16_t length, + const TraceLevel level); + + bool UpdateFileName( + char file_name_with_counter_utf8[FileWrapper::kMaxFileNameSize], + const uint32_t new_count) const RTC_EXCLUSIVE_LOCKS_REQUIRED(crit_); + + bool CreateFileName( + const char file_name_utf8[FileWrapper::kMaxFileNameSize], + char file_name_with_counter_utf8[FileWrapper::kMaxFileNameSize], + const uint32_t new_count) const; + + void WriteToFile(const char* msg, uint16_t length) + RTC_EXCLUSIVE_LOCKS_REQUIRED(crit_); + + TraceCallback* callback_ RTC_GUARDED_BY(crit_); + uint32_t row_count_text_ RTC_GUARDED_BY(crit_); + uint32_t file_count_text_ RTC_GUARDED_BY(crit_); + + const std::unique_ptr trace_file_ RTC_GUARDED_BY(crit_); + std::string trace_file_path_ RTC_GUARDED_BY(crit_); + rtc::CriticalSection crit_; +}; + +} // namespace webrtc + +#endif // SYSTEM_WRAPPERS_SOURCE_TRACE_IMPL_H_ diff --git a/system_wrappers/source/trace_posix.cc b/system_wrappers/source/trace_posix.cc new file mode 100644 index 0000000000..a01733325e --- /dev/null +++ b/system_wrappers/source/trace_posix.cc @@ -0,0 +1,85 @@ +/* + * Copyright (c) 2012 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 "system_wrappers/source/trace_posix.h" + +#include +#include +#include +#include +#include +#include + +namespace webrtc { + +TracePosix::TracePosix() { + struct timeval system_time_high_res; + gettimeofday(&system_time_high_res, 0); + prev_api_tick_count_ = prev_tick_count_ = system_time_high_res.tv_sec; +} + +int32_t TracePosix::AddTime(char* trace_message, const TraceLevel level) const { + struct timeval system_time_high_res; + if (gettimeofday(&system_time_high_res, 0) == -1) { + return -1; + } + struct tm buffer; + const struct tm* system_time = + localtime_r(&system_time_high_res.tv_sec, &buffer); + + const uint32_t ms_time = system_time_high_res.tv_usec / 1000; + uint32_t prev_tickCount = 0; + { + rtc::CritScope lock(&crit_sect_); + if (level == kTraceApiCall) { + prev_tickCount = prev_tick_count_; + prev_tick_count_ = ms_time; + } else { + prev_tickCount = prev_api_tick_count_; + prev_api_tick_count_ = ms_time; + } + } + + uint32_t dw_delta_time = ms_time - prev_tickCount; + if (prev_tickCount == 0) { + dw_delta_time = 0; + } + if (dw_delta_time > 0x0fffffff) { + // Either wraparound or data race. + dw_delta_time = 0; + } + if (dw_delta_time > 99999) { + dw_delta_time = 99999; + } + + sprintf(trace_message, "(%2u:%2u:%2u:%3u |%5lu) ", system_time->tm_hour, + system_time->tm_min, system_time->tm_sec, ms_time, + static_cast(dw_delta_time)); + // Messages are 22 characters. + return 22; +} + +int32_t TracePosix::AddDateTimeInfo(char* trace_message) const { + time_t t; + time(&t); + char buffer[26]; // man ctime says buffer should have room for >=26 bytes. + sprintf(trace_message, "Local Date: %s", ctime_r(&t, buffer)); + int32_t len = static_cast(strlen(trace_message)); + + if ('\n' == trace_message[len - 1]) { + trace_message[len - 1] = '\0'; + --len; + } + + // Messages is 12 characters. + return len + 1; +} + +} // namespace webrtc diff --git a/system_wrappers/source/trace_posix.h b/system_wrappers/source/trace_posix.h new file mode 100644 index 0000000000..357d226a3c --- /dev/null +++ b/system_wrappers/source/trace_posix.h @@ -0,0 +1,39 @@ +/* + * Copyright (c) 2011 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 SYSTEM_WRAPPERS_SOURCE_TRACE_POSIX_H_ +#define SYSTEM_WRAPPERS_SOURCE_TRACE_POSIX_H_ + +#include "rtc_base/criticalsection.h" +#include "system_wrappers/source/trace_impl.h" + +namespace webrtc { + +class TracePosix : public TraceImpl { + public: + TracePosix(); + ~TracePosix() override = default; + + // This method can be called on several different threads different from + // the creating thread. + int32_t AddTime(char* trace_message, const TraceLevel level) const override; + + int32_t AddDateTimeInfo(char* trace_message) const override; + + private: + volatile mutable uint32_t prev_api_tick_count_; + volatile mutable uint32_t prev_tick_count_; + + rtc::CriticalSection crit_sect_; +}; + +} // namespace webrtc + +#endif // SYSTEM_WRAPPERS_SOURCE_TRACE_POSIX_H_ diff --git a/system_wrappers/source/trace_win.cc b/system_wrappers/source/trace_win.cc new file mode 100644 index 0000000000..2becb78291 --- /dev/null +++ b/system_wrappers/source/trace_win.cc @@ -0,0 +1,97 @@ +/* + * Copyright (c) 2012 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 "system_wrappers/source/trace_win.h" + +#include +#include + +#include "Mmsystem.h" + +namespace webrtc { +TraceWindows::TraceWindows() + : prev_api_tick_count_(0), + prev_tick_count_(0) { +} + +TraceWindows::~TraceWindows() { +} + +int32_t TraceWindows::AddTime(char* trace_message, + const TraceLevel level) const { + uint32_t dw_current_time = timeGetTime(); + SYSTEMTIME system_time; + GetSystemTime(&system_time); + + if (level == kTraceApiCall) { + uint32_t dw_delta_time = dw_current_time - prev_tick_count_; + prev_tick_count_ = dw_current_time; + + if (prev_tick_count_ == 0) { + dw_delta_time = 0; + } + if (dw_delta_time > 0x0fffffff) { + // Either wrap-around or data race. + dw_delta_time = 0; + } + if (dw_delta_time > 99999) { + dw_delta_time = 99999; + } + + sprintf(trace_message, "(%2u:%2u:%2u:%3u |%5u) ", system_time.wHour, + system_time.wMinute, system_time.wSecond, + system_time.wMilliseconds, dw_delta_time); + } else { + uint32_t dw_delta_time = dw_current_time - prev_api_tick_count_; + prev_api_tick_count_ = dw_current_time; + + if (prev_api_tick_count_ == 0) { + dw_delta_time = 0; + } + if (dw_delta_time > 0x0fffffff) { + // Either wraparound or data race. + dw_delta_time = 0; + } + if (dw_delta_time > 99999) { + dw_delta_time = 99999; + } + sprintf(trace_message, "(%2u:%2u:%2u:%3u |%5u) ", system_time.wHour, + system_time.wMinute, system_time.wSecond, + system_time.wMilliseconds, dw_delta_time); + } + return 22; +} + +int32_t TraceWindows::AddDateTimeInfo(char* trace_message) const { + prev_api_tick_count_ = timeGetTime(); + prev_tick_count_ = prev_api_tick_count_; + + SYSTEMTIME sys_time; + GetLocalTime(&sys_time); + + TCHAR sz_date_str[20]; + TCHAR sz_time_str[20]; + + // Create date string (e.g. Apr 04 2002) + GetDateFormat(LOCALE_SYSTEM_DEFAULT, 0, &sys_time, TEXT("MMM dd yyyy"), + sz_date_str, 20); + + // Create time string (e.g. 15:32:08) + GetTimeFormat(LOCALE_SYSTEM_DEFAULT, 0, &sys_time, TEXT("HH':'mm':'ss"), + sz_time_str, 20); + + sprintf(trace_message, "Local Date: %ls Local Time: %ls", sz_date_str, + sz_time_str); + + // Include NULL termination (hence + 1). + return static_cast(strlen(trace_message) + 1); +} + +} // namespace webrtc diff --git a/system_wrappers/source/trace_win.h b/system_wrappers/source/trace_win.h new file mode 100644 index 0000000000..b1a41f296b --- /dev/null +++ b/system_wrappers/source/trace_win.h @@ -0,0 +1,36 @@ +/* + * Copyright (c) 2011 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 SYSTEM_WRAPPERS_SOURCE_TRACE_WIN_H_ +#define SYSTEM_WRAPPERS_SOURCE_TRACE_WIN_H_ + +#include +#include + +#include "system_wrappers/source/trace_impl.h" + +namespace webrtc { + +class TraceWindows : public TraceImpl { + public: + TraceWindows(); + virtual ~TraceWindows(); + + virtual int32_t AddTime(char* trace_message, const TraceLevel level) const; + + virtual int32_t AddDateTimeInfo(char* trace_message) const; + private: + volatile mutable uint32_t prev_api_tick_count_; + volatile mutable uint32_t prev_tick_count_; +}; + +} // namespace webrtc + +#endif // SYSTEM_WRAPPERS_SOURCE_TRACE_WIN_H_ diff --git a/test/BUILD.gn b/test/BUILD.gn index 78a734d98a..adb2dbf654 100644 --- a/test/BUILD.gn +++ b/test/BUILD.gn @@ -135,6 +135,8 @@ rtc_source_set("test_support") { "testsupport/packet_reader.h", "testsupport/perf_test.cc", "testsupport/perf_test.h", + "testsupport/trace_to_stderr.cc", + "testsupport/trace_to_stderr.h", "testsupport/unittest_utils.h", ] diff --git a/test/test_main.cc b/test/test_main.cc index 8bd2ed2244..8a6f26653b 100644 --- a/test/test_main.cc +++ b/test/test_main.cc @@ -15,6 +15,7 @@ #include "test/gmock.h" #include "test/gtest.h" #include "test/testsupport/fileutils.h" +#include "test/testsupport/trace_to_stderr.h" #if defined(WEBRTC_IOS) #include "test/ios/test_support.h" @@ -56,6 +57,9 @@ int main(int argc, char* argv[]) { webrtc::metrics::Enable(); rtc::LogMessage::SetLogToStderr(FLAG_logs); + std::unique_ptr trace_to_stderr; + if (FLAG_logs) + trace_to_stderr.reset(new webrtc::test::TraceToStderr); #if defined(WEBRTC_IOS) rtc::test::InitTestSuite(RUN_ALL_TESTS, argc, argv); rtc::test::RunTestsFromIOSApp(); diff --git a/test/testsupport/trace_to_stderr.cc b/test/testsupport/trace_to_stderr.cc new file mode 100644 index 0000000000..5b75d1bf8e --- /dev/null +++ b/test/testsupport/trace_to_stderr.cc @@ -0,0 +1,63 @@ +/* + * Copyright (c) 2013 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 "test/testsupport/trace_to_stderr.h" + +#include +#include + +#include + +namespace webrtc { +namespace test { + +static const int kLevelFilter = kTraceError | kTraceWarning | kTraceTerseInfo; + +TraceToStderr::TraceToStderr() + : override_time_(false), + time_seconds_(0) { + Trace::set_level_filter(kLevelFilter); + Trace::CreateTrace(); + Trace::SetTraceCallback(this); +} + +TraceToStderr::TraceToStderr(bool override_time) + : override_time_(override_time), + time_seconds_(0) { + Trace::set_level_filter(kLevelFilter); + Trace::CreateTrace(); + Trace::SetTraceCallback(this); +} + +TraceToStderr::~TraceToStderr() { + Trace::SetTraceCallback(NULL); + Trace::ReturnTrace(); +} + +void TraceToStderr::SetTimeSeconds(float time) { time_seconds_ = time; } + +void TraceToStderr::Print(TraceLevel level, const char* msg_array, int length) { + if (level & kLevelFilter) { + assert(length > Trace::kBoilerplateLength); + std::string msg = msg_array; + std::string msg_log = msg.substr(Trace::kBoilerplateLength); + if (override_time_) { + fprintf(stderr, "%.2fs %s\n", time_seconds_, msg_log.c_str()); + } else { + std::string msg_time = msg.substr(Trace::kTimestampPosition, + Trace::kTimestampLength); + fprintf(stderr, "%s %s\n", msg_time.c_str(), msg_log.c_str()); + } + fflush(stderr); + } +} + +} // namespace test +} // namespace webrtc diff --git a/test/testsupport/trace_to_stderr.h b/test/testsupport/trace_to_stderr.h new file mode 100644 index 0000000000..bb8a53ab8f --- /dev/null +++ b/test/testsupport/trace_to_stderr.h @@ -0,0 +1,52 @@ +/* + * Copyright (c) 2013 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 TEST_TEST_SUPPORT_TRACE_TO_STDERR_H_ +#define TEST_TEST_SUPPORT_TRACE_TO_STDERR_H_ + +#include "system_wrappers/include/trace.h" + +namespace webrtc { +namespace test { + +// Upon constructing an instance of this class, all traces will be redirected +// to stderr. At destruction, redirection is halted. +class TraceToStderr : public TraceCallback { + public: + TraceToStderr(); + // Set |override_time| to true to control the time printed with each trace + // through SetTimeSeconds(). Otherwise, the trace's usual wallclock time is + // used. + // + // This is useful for offline test tools, where the file time is much more + // informative than the real time. + explicit TraceToStderr(bool override_time); + ~TraceToStderr() override; + + // Every subsequent trace printout will use |time|. Has no effect if + // |override_time| in the constructor was set to false. + // + // No attempt is made to ensure thread-safety between the trace writing and + // time updating. In tests, since traces will normally be triggered by the + // main thread doing the time updating, this should be of no concern. + virtual void SetTimeSeconds(float time); + + // Implements TraceCallback. + void Print(TraceLevel level, const char* msg_array, int length) override; + + private: + bool override_time_; + float time_seconds_; +}; + +} // namespace test +} // namespace webrtc + +#endif // TEST_TEST_SUPPORT_TRACE_TO_STDERR_H_ diff --git a/video/video_quality_test.cc b/video/video_quality_test.cc index 7a548ef5a3..0008b1f7fa 100644 --- a/video/video_quality_test.cc +++ b/video/video_quality_test.cc @@ -1406,6 +1406,9 @@ void VideoQualityTest::FillScalabilitySettings( void VideoQualityTest::SetupVideo(Transport* send_transport, Transport* recv_transport) { + if (params_.logging.logs) + trace_to_stderr_.reset(new test::TraceToStderr); + size_t num_video_streams = params_.ss.streams.size(); size_t num_flexfec_streams = params_.video.flexfec ? 1 : 0; CreateSendConfig(num_video_streams, 0, num_flexfec_streams, send_transport); diff --git a/video/video_quality_test.h b/video/video_quality_test.h index e0b3deae60..c16105c3cb 100644 --- a/video/video_quality_test.h +++ b/video/video_quality_test.h @@ -18,6 +18,7 @@ #include "media/engine/simulcast_encoder_adapter.h" #include "test/call_test.h" #include "test/frame_generator.h" +#include "test/testsupport/trace_to_stderr.h" namespace webrtc { @@ -139,6 +140,7 @@ class VideoQualityTest : public test::CallTest { // We need a more general capturer than the FrameGeneratorCapturer. std::unique_ptr video_capturer_; std::vector> thumbnail_capturers_; + std::unique_ptr trace_to_stderr_; std::unique_ptr frame_generator_; std::unique_ptr video_encoder_; std::unique_ptr vp8_encoder_factory_; diff --git a/voice_engine/shared_data.cc b/voice_engine/shared_data.cc index 01e163b394..ac830c7163 100644 --- a/voice_engine/shared_data.cc +++ b/voice_engine/shared_data.cc @@ -11,6 +11,7 @@ #include "voice_engine/shared_data.h" #include "modules/audio_processing/include/audio_processing.h" +#include "system_wrappers/include/trace.h" #include "voice_engine/channel.h" #include "voice_engine/transmit_mixer.h" @@ -26,7 +27,8 @@ SharedData::SharedData() _audioDevicePtr(NULL), _moduleProcessThreadPtr(ProcessThread::Create("VoiceProcessThread")), encoder_queue_("AudioEncoderQueue") { - if (TransmitMixer::Create(_transmitMixerPtr) == 0) { + Trace::CreateTrace(); + if (TransmitMixer::Create(_transmitMixerPtr, _gInstanceCounter) == 0) { _transmitMixerPtr->SetEngineInformation(&_channelManager); } } @@ -38,6 +40,7 @@ SharedData::~SharedData() _audioDevicePtr->Release(); } _moduleProcessThreadPtr->Stop(); + Trace::ReturnTrace(); } rtc::TaskQueue* SharedData::encoder_queue() { diff --git a/voice_engine/transmit_mixer.cc b/voice_engine/transmit_mixer.cc index c8e8200206..8fe1d2584a 100644 --- a/voice_engine/transmit_mixer.cc +++ b/voice_engine/transmit_mixer.cc @@ -17,6 +17,7 @@ #include "rtc_base/location.h" #include "rtc_base/logging.h" #include "system_wrappers/include/event_wrapper.h" +#include "system_wrappers/include/trace.h" #include "voice_engine/channel.h" #include "voice_engine/channel_manager.h" #include "voice_engine/utility.h" @@ -27,13 +28,16 @@ namespace voe { // TODO(solenberg): The thread safety in this class is dubious. int32_t -TransmitMixer::Create(TransmitMixer*& mixer) +TransmitMixer::Create(TransmitMixer*& mixer, uint32_t instanceId) { - mixer = new TransmitMixer(); + WEBRTC_TRACE(kTraceMemory, kTraceVoice, VoEId(instanceId, -1), + "TransmitMixer::Create(instanceId=%d)", instanceId); + mixer = new TransmitMixer(instanceId); if (mixer == NULL) { - LOG(LS_ERROR) << "TransmitMixer::Create() unable to allocate memory " - "for mixer"; + WEBRTC_TRACE(kTraceMemory, kTraceVoice, VoEId(instanceId, -1), + "TransmitMixer::Create() unable to allocate memory" + "for mixer"); return -1; } return 0; @@ -49,6 +53,13 @@ TransmitMixer::Destroy(TransmitMixer*& mixer) } } +TransmitMixer::TransmitMixer(uint32_t instanceId) : + _instanceId(instanceId) +{ + WEBRTC_TRACE(kTraceMemory, kTraceVoice, VoEId(_instanceId, -1), + "TransmitMixer::TransmitMixer() - ctor"); +} + TransmitMixer::~TransmitMixer() = default; void TransmitMixer::SetEngineInformation(ChannelManager* channelManager) { @@ -58,6 +69,10 @@ void TransmitMixer::SetEngineInformation(ChannelManager* channelManager) { int32_t TransmitMixer::SetAudioProcessingModule(AudioProcessing* audioProcessingModule) { + WEBRTC_TRACE(kTraceInfo, kTraceVoice, VoEId(_instanceId, -1), + "TransmitMixer::SetAudioProcessingModule(" + "audioProcessingModule=0x%x)", + audioProcessingModule); audioproc_ = audioProcessingModule; return 0; } @@ -94,6 +109,13 @@ TransmitMixer::PrepareDemux(const void* audioSamples, uint16_t currentMicLevel, bool keyPressed) { + WEBRTC_TRACE(kTraceStream, kTraceVoice, VoEId(_instanceId, -1), + "TransmitMixer::PrepareDemux(nSamples=%" PRIuS ", " + "nChannels=%" PRIuS ", samplesPerSec=%u, totalDelayMS=%u, " + "clockDrift=%d, currentMicLevel=%u)", + nSamples, nChannels, samplesPerSec, totalDelayMS, clockDrift, + currentMicLevel); + // --- Resample input audio and create/store the initial audio frame GenerateAudioFrame(static_cast(audioSamples), nSamples, @@ -138,6 +160,8 @@ uint32_t TransmitMixer::CaptureLevel() const int32_t TransmitMixer::StopSend() { + WEBRTC_TRACE(kTraceInfo, kTraceVoice, VoEId(_instanceId, -1), + "TransmitMixer::StopSend()"); _audioLevel.Clear(); return 0; } diff --git a/voice_engine/transmit_mixer.h b/voice_engine/transmit_mixer.h index 6cfe0704d3..a983c3f275 100644 --- a/voice_engine/transmit_mixer.h +++ b/voice_engine/transmit_mixer.h @@ -39,7 +39,7 @@ class MixedAudio; class TransmitMixer { public: - static int32_t Create(TransmitMixer*& mixer); + static int32_t Create(TransmitMixer*& mixer, uint32_t instanceId); static void Destroy(TransmitMixer*& mixer); @@ -90,6 +90,8 @@ protected: TransmitMixer() = default; private: + TransmitMixer(uint32_t instanceId); + // Gets the maximum sample rate and number of channels over all currently // sending codecs. void GetSendCodecInfo(int* max_sample_rate, size_t* max_channels); @@ -122,6 +124,7 @@ private: rtc::CriticalSection lock_; bool typing_noise_detected_ RTC_GUARDED_BY(lock_) = false; + int _instanceId = 0; uint32_t _captureLevel = 0; bool stereo_codec_ = false; bool swap_stereo_channels_ = false; diff --git a/voice_engine/voice_engine_impl.cc b/voice_engine/voice_engine_impl.cc index b0ff0849ba..681f00ed0b 100644 --- a/voice_engine/voice_engine_impl.cc +++ b/voice_engine/voice_engine_impl.cc @@ -16,6 +16,7 @@ #include "modules/audio_coding/include/audio_coding_module.h" #include "rtc_base/checks.h" +#include "system_wrappers/include/trace.h" #include "voice_engine/channel_proxy.h" #include "voice_engine/voice_engine_impl.h" @@ -45,6 +46,9 @@ int VoiceEngineImpl::Release() { int new_ref = --_ref_count; assert(new_ref >= 0); if (new_ref == 0) { + WEBRTC_TRACE(kTraceApiCall, kTraceVoice, -1, + "VoiceEngineImpl self deleting (voiceEngine=0x%p)", this); + // Clear any pointers before starting destruction. Otherwise worker- // threads will still have pointers to a partially destructed object. // Example: AudioDeviceBuffer::RequestPlayoutData() can access a @@ -74,8 +78,18 @@ bool VoiceEngine::Delete(VoiceEngine*& voiceEngine) { return false; VoiceEngineImpl* s = static_cast(voiceEngine); - s->Release(); + // Release the reference that was added in GetVoiceEngine. + int ref = s->Release(); voiceEngine = NULL; + + if (ref != 0) { + WEBRTC_TRACE( + kTraceWarning, kTraceVoice, -1, + "VoiceEngine::Delete did not release the very last reference. " + "%d references remain.", + ref); + } + return true; } } // namespace webrtc