diff options
Diffstat (limited to '')
-rw-r--r-- | dom/media/AsyncLogger.h | 305 |
1 files changed, 305 insertions, 0 deletions
diff --git a/dom/media/AsyncLogger.h b/dom/media/AsyncLogger.h new file mode 100644 index 0000000000..adc4101382 --- /dev/null +++ b/dom/media/AsyncLogger.h @@ -0,0 +1,305 @@ +/* This Source Code Form is subject to the terms of the Mozilla Public + * License, v. 2.0. If a copy of the MPL was not distributed with this + * file, You can obtain one at http://mozilla.org/MPL/2.0/. */ + +/* Implementation of an asynchronous lock-free logging system. */ + +#ifndef mozilla_dom_AsyncLogger_h +#define mozilla_dom_AsyncLogger_h + +#include <atomic> +#include <thread> +#include <cinttypes> +#include "mozilla/ArrayUtils.h" +#include "mozilla/Attributes.h" +#include "mozilla/BaseProfilerMarkerTypes.h" +#include "mozilla/MathAlgorithms.h" +#include "mozilla/Sprintf.h" +#include "mozilla/TimeStamp.h" +#include "GeckoProfiler.h" +#include "MPSCQueue.h" + +#if defined(_WIN32) +# include <process.h> +# define getpid() _getpid() +#else +# include <unistd.h> +#endif + +namespace mozilla { + +// Allows writing 0-terminated C-strings in a buffer, and returns the start +// index of the string that's been appended. Automatically truncates the strings +// as needed if the storage is too small, returning true when that's the case. +class MOZ_STACK_CLASS StringWriter { + public: + StringWriter(char* aMemory, size_t aLength) + : mMemory(aMemory), mWriteIndex(0), mLength(aLength) {} + + bool AppendCString(const char* aString, size_t* aIndexStart) { + *aIndexStart = mWriteIndex; + if (!aString) { + return false; + } + size_t toCopy = strlen(aString); + bool truncated = false; + + if (toCopy > Available()) { + truncated = true; + toCopy = Available() - 1; + } + + memcpy(&(mMemory[mWriteIndex]), aString, toCopy); + mWriteIndex += toCopy; + mMemory[mWriteIndex] = 0; + mWriteIndex++; + + return truncated; + } + + private: + size_t Available() { + MOZ_ASSERT(mLength > mWriteIndex); + return mLength - mWriteIndex; + } + + char* mMemory; + size_t mWriteIndex; + size_t mLength; +}; + +const size_t PAYLOAD_TOTAL_SIZE = 2 << 9; + +// 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 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'}; + + struct TextPayload { + char mPayload[PAYLOAD_TOTAL_SIZE - MPSC_MSG_RESERVED]; + }; + + // The order of the fields is important here to minimize padding. + struct TracePayload { +#define MEMBERS_EXCEPT_NAME \ + /* If this marker is of phase B or E (begin or end), this is the time at \ + * which it was captured. */ \ + TimeStamp mTimestamp; \ + /* The thread on which this tracepoint was gathered. */ \ + ProfilerThreadId mTID; \ + /* If this marker is of phase X (COMPLETE), this holds the duration of the \ + * event in microseconds. Else, the value is not used. */ \ + uint32_t mDurationUs; \ + /* A trace payload can be either: \ + * - Begin - this marks the beginning of a temporal region \ + * - End - this marks the end of a temporal region \ + * - Complete - this is a timestamp and a length, forming complete a \ + * temporal region */ \ + TracingPhase mPhase; \ + /* Offset at which the comment part of the string starts, in mName */ \ + uint8_t mCommentStart; + + MEMBERS_EXCEPT_NAME; + + private: + // Mock structure, to know where the first character of the name will be. + struct MembersWithChar { + MEMBERS_EXCEPT_NAME; + char c; + }; + static constexpr size_t scRemainingSpaceForName = + PAYLOAD_TOTAL_SIZE - offsetof(MembersWithChar, c) - + ((MPSC_MSG_RESERVED + alignof(MembersWithChar) - 1) & + ~(alignof(MembersWithChar) - 1)); +#undef MEMBERS_EXCEPT_NAME + + public: + // An arbitrary string, usually containing a function signature or a + // recognizable tag of some sort, to be displayed when analyzing the + // profile. + char mName[scRemainingSpaceForName]; + }; + + // The goal here is to make it easy on the allocator. We pack a pointer in the + // message struct, and we still want to do power of two allocations to + // minimize allocator slop. + static_assert(sizeof(MPSCQueue<TracePayload>::Message) == PAYLOAD_TOTAL_SIZE, + "MPSCQueue internal allocations has an unexpected size."); + + explicit AsyncLogger() : mThread(nullptr), mRunning(false) {} + + void Start() { + MOZ_ASSERT(!mRunning, "Double calls to AsyncLogger::Start"); + mRunning = true; + Run(); + } + + void Stop() { + if (mRunning) { + mRunning = false; + } + } + + // Log something that has a beginning and an end + void Log(const char* aName, const char* aCategory, const char* aComment, + TracingPhase aPhase) { + if (!Enabled()) { + return; + } + + auto* msg = new MPSCQueue<TracePayload>::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<bool> 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()) { + auto* msg = new MPSCQueue<TracePayload>::Message(); + msg->data.mTID = profiler_current_thread_id(); + msg->data.mPhase = TracingPhase::COMPLETE; + msg->data.mTimestamp = TimeStamp::Now(); + msg->data.mDurationUs = + (static_cast<double>(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); + } + } + + bool Enabled() { return mRunning; } + + private: + void Run() { + mThread.reset(new std::thread([this]() { + AUTO_PROFILER_REGISTER_THREAD("AsyncLogger"); + while (mRunning) { + { + struct TracingMarkerWithComment { + static constexpr Span<const char> MarkerTypeName() { + return MakeStringSpan("Real-Time"); + } + static void StreamJSONMarkerData( + baseprofiler::SpliceableJSONWriter& aWriter, + const ProfilerString8View& aText) { + aWriter.StringProperty("name", aText); + } + static MarkerSchema MarkerTypeDisplay() { + using MS = MarkerSchema; + MS schema{MS::Location::MarkerChart, MS::Location::MarkerTable}; + schema.SetChartLabel("{marker.data.name}"); + schema.SetTableLabel("{marker.name} - {marker.data.name}"); + schema.AddKeyLabelFormatSearchable("name", "Comment", + MS::Format::String, + MS::Searchable::Searchable); + return schema; + } + }; + + struct TracingMarker { + static constexpr Span<const char> MarkerTypeName() { + return MakeStringSpan("Real-time"); + } + static void StreamJSONMarkerData( + baseprofiler::SpliceableJSONWriter& aWriter) {} + static MarkerSchema MarkerTypeDisplay() { + using MS = MarkerSchema; + MS schema{MS::Location::MarkerChart, MS::Location::MarkerTable}; + // Nothing outside the defaults. + return schema; + } + }; + + TracePayload message; + while (mMessageQueueProfiler.Pop(&message) && mRunning) { + if (message.mPhase != TracingPhase::COMPLETE) { + if (!message.mCommentStart) { + profiler_add_marker( + ProfilerString8View::WrapNullTerminatedString( + message.mName), + geckoprofiler::category::MEDIA_RT, + {MarkerThreadId(message.mTID), + (message.mPhase == TracingPhase::BEGIN) + ? MarkerTiming::IntervalStart(message.mTimestamp) + : MarkerTiming::IntervalEnd(message.mTimestamp)}, + TracingMarker{}); + } else { + profiler_add_marker( + ProfilerString8View::WrapNullTerminatedString( + message.mName), + geckoprofiler::category::MEDIA_RT, + {MarkerThreadId(message.mTID), + (message.mPhase == TracingPhase::BEGIN) + ? MarkerTiming::IntervalStart(message.mTimestamp) + : MarkerTiming::IntervalEnd(message.mTimestamp)}, + TracingMarkerWithComment{}, + ProfilerString8View::WrapNullTerminatedString( + &(message.mName[message.mCommentStart]))); + } + } else { + profiler_add_marker( + ProfilerString8View::WrapNullTerminatedString(message.mName), + geckoprofiler::category::MEDIA_RT, + {MarkerThreadId(message.mTID), + MarkerTiming::Interval( + message.mTimestamp, + message.mTimestamp + TimeDuration::FromMicroseconds( + message.mDurationUs))}, + TracingMarker{}); + } + } + } + Sleep(); + } + })); + // cleanup is done via mRunning + mThread->detach(); + } + + uint64_t NowInUs() { + static TimeStamp base = TimeStamp::Now(); + return (TimeStamp::Now() - base).ToMicroseconds(); + } + + void Sleep() { std::this_thread::sleep_for(std::chrono::milliseconds(10)); } + + std::unique_ptr<std::thread> mThread; + MPSCQueue<TracePayload> mMessageQueueProfiler; + std::atomic<bool> mRunning; +}; + +} // end namespace mozilla + +#if defined(_WIN32) +# undef getpid +#endif + +#endif // mozilla_dom_AsyncLogger_h |