diff --git a/dom/media/AsyncLogger.h b/dom/media/AsyncLogger.h index 85cc6b465986..1eccacf043b9 100644 --- a/dom/media/AsyncLogger.h +++ b/dom/media/AsyncLogger.h @@ -12,13 +12,12 @@ #include #include "mozilla/ArrayUtils.h" #include "mozilla/Attributes.h" -#include "mozilla/Logging.h" +#include "mozilla/BaseProfilerMarkerTypes.h" #include "mozilla/MathAlgorithms.h" #include "mozilla/Sprintf.h" #include "mozilla/TimeStamp.h" #include "GeckoProfiler.h" #include "MPSCQueue.h" -#include "mozilla/BaseProfilerMarkerTypes.h" #if defined(_WIN32) # include @@ -71,21 +70,19 @@ class MOZ_STACK_CLASS StringWriter { const size_t PAYLOAD_TOTAL_SIZE = 2 << 9; -// This class implements a lock-free asynchronous logger, that outputs to -// MOZ_LOG or adds profiler markers (the default). +// This class implements a lock-free asynchronous logger, that +// adds profiler markers. // Any thread can use this logger without external synchronization and without // being blocked. This log is suitable for use in real-time audio threads. // This class uses a thread internally, and must be started and stopped // manually. -// If logging/profiling is disabled, all the calls are no-op and cheap. +// If profiling is disabled, all the calls are no-op and cheap. class AsyncLogger { public: enum class TracingPhase : uint8_t { BEGIN, END, COMPLETE }; const char TRACING_PHASE_STRINGS[3] = {'B', 'E', 'X'}; - enum AsyncLoggerOutputMode { MOZLOG, PROFILER }; - struct TextPayload { char mPayload[PAYLOAD_TOTAL_SIZE - MPSC_MSG_RESERVED]; }; @@ -137,21 +134,11 @@ class AsyncLogger { static_assert(sizeof(MPSCQueue::Message) == PAYLOAD_TOTAL_SIZE, "MPSCQueue internal allocations has an unexpected size."); - // aLogModuleName is the name of the MOZ_LOG module. - explicit AsyncLogger(const char* aLogModuleName, - AsyncLogger::AsyncLoggerOutputMode aMode = - AsyncLogger::AsyncLoggerOutputMode::PROFILER) - : mThread(nullptr), - mLogModule(aLogModuleName), - mRunning(false), - mMode(aMode) {} + explicit AsyncLogger() : mThread(nullptr), mRunning(false) {} void Start() { MOZ_ASSERT(!mRunning, "Double calls to AsyncLogger::Start"); mRunning = true; - if (mMode == AsyncLogger::AsyncLoggerOutputMode::MOZLOG) { - LogMozLog("["); - } Run(); } @@ -164,97 +151,57 @@ class AsyncLogger { // Log something that has a beginning and an end void Log(const char* aName, const char* aCategory, const char* aComment, TracingPhase aPhase) { - if (Enabled()) { - if (mMode == AsyncLogger::AsyncLoggerOutputMode::MOZLOG) { - LogMozLog( - "{\"name\": \"%s\", \"cat\": \"%s\", \"ph\": \"%c\"," - "\"ts\": %" PRIu64 - ", \"pid\": %d, \"tid\":" - " %zu, \"args\": { \"comment\": \"%s\"}},", - aName, aCategory, TRACING_PHASE_STRINGS[static_cast(aPhase)], - NowInUs(), getpid(), - std::hash{}(std::this_thread::get_id()), aComment); - } else { - auto* msg = new MPSCQueue::Message(); - - msg->data.mTID = profiler_current_thread_id(); - msg->data.mPhase = aPhase; - msg->data.mTimestamp = TimeStamp::Now(); - msg->data.mDurationUs = 0; // unused, duration is end - begin - - StringWriter writer(msg->data.mName, ArrayLength(msg->data.mName)); - - size_t commentIndex; - DebugOnly truncated = writer.AppendCString(aName, &commentIndex); - MOZ_ASSERT(!truncated, "Tracing payload truncated: name"); - - if (aComment) { - truncated = writer.AppendCString(aComment, &commentIndex); - MOZ_ASSERT(!truncated, "Tracing payload truncated: comment"); - msg->data.mCommentStart = commentIndex; - } else { - msg->data.mCommentStart = 0; - } - mMessageQueueProfiler.Push(msg); - } + if (!Enabled()) { + return; } + + auto* msg = new MPSCQueue::Message(); + + msg->data.mTID = profiler_current_thread_id(); + msg->data.mPhase = aPhase; + msg->data.mTimestamp = TimeStamp::Now(); + msg->data.mDurationUs = 0; // unused, duration is end - begin + + StringWriter writer(msg->data.mName, ArrayLength(msg->data.mName)); + + size_t commentIndex; + DebugOnly truncated = writer.AppendCString(aName, &commentIndex); + MOZ_ASSERT(!truncated, "Tracing payload truncated: name"); + + if (aComment) { + truncated = writer.AppendCString(aComment, &commentIndex); + MOZ_ASSERT(!truncated, "Tracing payload truncated: comment"); + msg->data.mCommentStart = commentIndex; + } else { + msg->data.mCommentStart = 0; + } + mMessageQueueProfiler.Push(msg); } // Log something that has a beginning and a duration void LogDuration(const char* aName, const char* aCategory, uint64_t aDuration, uint64_t aFrames, uint64_t aSampleRate) { if (Enabled()) { - if (mMode == AsyncLogger::AsyncLoggerOutputMode::MOZLOG) { - LogMozLog( - "{\"name\": \"%s\", \"cat\": \"%s\", \"ph\": \"X\"," - "\"ts\": %" PRIu64 ", \"dur\": %" PRIu64 - ", \"pid\": %d," - "\"tid\": %zu, \"args\": { \"comment\": \"%" PRIu64 "/%" PRIu64 - "\"}},", - aName, aCategory, NowInUs(), aDuration, getpid(), - std::hash{}(std::this_thread::get_id()), aFrames, - aSampleRate); - } else { - auto* msg = new MPSCQueue::Message(); - msg->data.mTID = profiler_current_thread_id(); - msg->data.mPhase = TracingPhase::COMPLETE; - msg->data.mTimestamp = TimeStamp::Now(); - msg->data.mDurationUs = - (static_cast(aFrames) / aSampleRate) * 1e6; - size_t len = std::min(strlen(aName), ArrayLength(msg->data.mName)); - memcpy(msg->data.mName, aName, len); - msg->data.mName[len] = 0; - mMessageQueueProfiler.Push(msg); - } + auto* msg = new MPSCQueue::Message(); + msg->data.mTID = profiler_current_thread_id(); + msg->data.mPhase = TracingPhase::COMPLETE; + msg->data.mTimestamp = TimeStamp::Now(); + msg->data.mDurationUs = + (static_cast(aFrames) / aSampleRate) * 1e6; + size_t len = std::min(strlen(aName), ArrayLength(msg->data.mName)); + memcpy(msg->data.mName, aName, len); + msg->data.mName[len] = 0; + mMessageQueueProfiler.Push(msg); } } - void LogMozLog(const char* format, ...) MOZ_FORMAT_PRINTF(2, 3) { - auto* msg = new MPSCQueue::Message(); - va_list args; - va_start(args, format); - VsprintfLiteral(msg->data.mPayload, format, args); - va_end(args); - mMessageQueueLog.Push(msg); - } - bool Enabled() { - return (mMode == AsyncLoggerOutputMode::MOZLOG && - MOZ_LOG_TEST(mLogModule, mozilla::LogLevel::Verbose)) || - (mMode == AsyncLoggerOutputMode::PROFILER && profiler_is_active()); - } + bool Enabled() { return profiler_is_active(); } private: void Run() { mThread.reset(new std::thread([this]() { AUTO_PROFILER_REGISTER_THREAD("AsyncLogger"); while (mRunning) { - { - TextPayload message; - while (mMessageQueueLog.Pop(&message) && mRunning) { - MOZ_LOG(mLogModule, mozilla::LogLevel::Verbose, - ("%s", message.mPayload)); - } - } { struct TracingMarkerWithComment { static constexpr Span MarkerTypeName() { @@ -344,11 +291,8 @@ class AsyncLogger { void Sleep() { std::this_thread::sleep_for(std::chrono::milliseconds(10)); } std::unique_ptr mThread; - mozilla::LazyLogModule mLogModule; - MPSCQueue mMessageQueueLog; MPSCQueue mMessageQueueProfiler; std::atomic mRunning; - std::atomic mMode; }; } // end namespace mozilla diff --git a/dom/media/Tracing.cpp b/dom/media/Tracing.cpp index 4250f132bbbb..eaa472b8c50e 100644 --- a/dom/media/Tracing.cpp +++ b/dom/media/Tracing.cpp @@ -12,7 +12,7 @@ using namespace mozilla; using TracingPhase = mozilla::AsyncLogger::TracingPhase; -mozilla::AsyncLogger gAudioCallbackTraceLogger("AudioCallbackTracing"); +mozilla::AsyncLogger gAudioCallbackTraceLogger; static std::atomic gTracingStarted(0); void StartAudioCallbackTracing() {