The Tor Browser: comparison toolkit/xre/EventTracer.cpp

--1:000000000000
+:dfe83a993846
+/* 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/. */
+/*
+* Event loop instrumentation. This code attempts to measure the
+* latency of the UI-thread event loop by firing native events at it from
+* a background thread, and measuring how long it takes for them
+* to be serviced. The measurement interval (kMeasureInterval, below)
+* is also used as the upper bound of acceptable response time.
+* When an event takes longer than that interval to be serviced,
+* a sample will be written to the log.
+*
+* Usage:
+*
+* Set MOZ_INSTRUMENT_EVENT_LOOP=1 in the environment to enable
+* this instrumentation. Currently only the UI process is instrumented.
+*
+* Set MOZ_INSTRUMENT_EVENT_LOOP_OUTPUT in the environment to a
+* file path to contain the log output, the default is to log to stdout.
+*
+* Set MOZ_INSTRUMENT_EVENT_LOOP_THRESHOLD in the environment to an
+* integer number of milliseconds to change the threshold for reporting.
+* The default is 20 milliseconds. Unresponsive periods shorter than this
+* threshold will not be reported.
+*
+* Set MOZ_INSTRUMENT_EVENT_LOOP_INTERVAL in the environment to an
+* integer number of milliseconds to change the maximum sampling frequency.
+* This variable controls how often events will be sent to the main
+* thread's event loop to sample responsiveness. The sampler will not
+* send events twice within LOOP_INTERVAL milliseconds.
+* The default is 10 milliseconds.
+*
+* All logged output lines start with MOZ_EVENT_TRACE. All timestamps
+* output are milliseconds since the epoch (PRTime / 1000).
+*
+* On startup, a line of the form:
+*   MOZ_EVENT_TRACE start <timestamp>
+* will be output.
+*
+* On shutdown, a line of the form:
+*   MOZ_EVENT_TRACE stop <timestamp>
+* will be output.
+*
+* When an event servicing time exceeds the threshold, a line of the form:
+*   MOZ_EVENT_TRACE sample <timestamp> <duration>
+* will be output, where <duration> is the number of milliseconds that
+* it took for the event to be serviced. Duration may contain a fractional
+* component.
+*/
+#include "GeckoProfiler.h"
+#include "EventTracer.h"
+#include <stdio.h>
+#include "mozilla/Preferences.h"
+#include "mozilla/TimeStamp.h"
+#include "mozilla/WidgetTraceEvent.h"
+#include "nsDebug.h"
+#include <limits.h>
+#include <prenv.h>
+#include <prinrval.h>
+#include <prthread.h>
+#include <prtime.h>
+#ifdef MOZ_WIDGET_GONK
+#include "nsThreadUtils.h"
+#include "nsIObserverService.h"
+#include "mozilla/Services.h"
+#endif
+using mozilla::TimeDuration;
+using mozilla::TimeStamp;
+using mozilla::FireAndWaitForTracerEvent;
+namespace {
+PRThread* sTracerThread = nullptr;
+bool sExit = false;
+struct TracerStartClosure {
+bool mLogTracing;
+int32_t mThresholdInterval;
+};
+#ifdef MOZ_WIDGET_GONK
+class EventLoopLagDispatcher : public nsRunnable
+{
+public:
+explicit EventLoopLagDispatcher(int aLag)
+: mLag(aLag) {}
+NS_IMETHODIMP Run()
+{
+nsCOMPtr<nsIObserverService> obsService =
+mozilla::services::GetObserverService();
+if (!obsService) {
+return NS_ERROR_FAILURE;
+}
+nsAutoString value;
+value.AppendInt(mLag);
+return obsService->NotifyObservers(nullptr, "event-loop-lag", value.get());
+}
+private:
+int mLag;
+};
+#endif
+/*
+* The tracer thread fires events at the native event loop roughly
+* every kMeasureInterval. It will sleep to attempt not to send them
+* more quickly, but if the response time is longer than kMeasureInterval
+* it will not send another event until the previous response is received.
+*
+* The output defaults to stdout, but can be redirected to a file by
+* settting the environment variable MOZ_INSTRUMENT_EVENT_LOOP_OUTPUT
+* to the name of a file to use.
+*/
+void TracerThread(void *arg)
+{
+PR_SetCurrentThreadName("Event Tracer");
+TracerStartClosure* threadArgs = static_cast<TracerStartClosure*>(arg);
+// These are the defaults. They can be overridden by environment vars.
+// This should be set to the maximum latency we'd like to allow
+// for responsiveness.
+int32_t thresholdInterval = threadArgs->mThresholdInterval;
+PRIntervalTime threshold = PR_MillisecondsToInterval(thresholdInterval);
+// This is the sampling interval.
+PRIntervalTime interval = PR_MillisecondsToInterval(thresholdInterval / 2);
+sExit = false;
+FILE* log = nullptr;
+char* envfile = PR_GetEnv("MOZ_INSTRUMENT_EVENT_LOOP_OUTPUT");
+if (envfile) {
+log = fopen(envfile, "w");
+}
+if (log == nullptr)
+log = stdout;
+char* thresholdenv = PR_GetEnv("MOZ_INSTRUMENT_EVENT_LOOP_THRESHOLD");
+if (thresholdenv && *thresholdenv) {
+int val = atoi(thresholdenv);
+if (val != 0 && val != INT_MAX && val != INT_MIN) {
+threshold = PR_MillisecondsToInterval(val);
+}
+}
+char* intervalenv = PR_GetEnv("MOZ_INSTRUMENT_EVENT_LOOP_INTERVAL");
+if (intervalenv && *intervalenv) {
+int val = atoi(intervalenv);
+if (val != 0 && val != INT_MAX && val != INT_MIN) {
+interval = PR_MillisecondsToInterval(val);
+}
+}
+if (threadArgs->mLogTracing) {
+long long now = PR_Now() / PR_USEC_PER_MSEC;
+fprintf(log, "MOZ_EVENT_TRACE start %llu\n", now);
+}
+while (!sExit) {
+TimeStamp start(TimeStamp::Now());
+profiler_responsiveness(start);
+PRIntervalTime next_sleep = interval;
+//TODO: only wait up to a maximum of interval; return
+// early if that threshold is exceeded and dump a stack trace
+// or do something else useful.
+if (FireAndWaitForTracerEvent()) {
+TimeDuration duration = TimeStamp::Now() - start;
+// Only report samples that exceed our measurement threshold.
+long long now = PR_Now() / PR_USEC_PER_MSEC;
+if (threadArgs->mLogTracing && duration.ToMilliseconds() > threshold) {
+fprintf(log, "MOZ_EVENT_TRACE sample %llu %lf\n",
+now,
+duration.ToMilliseconds());
+#ifdef MOZ_WIDGET_GONK
+NS_DispatchToMainThread(
+new EventLoopLagDispatcher(int(duration.ToSecondsSigDigits() * 1000)));
+#endif
+}
+if (next_sleep > duration.ToMilliseconds()) {
+next_sleep -= int(duration.ToMilliseconds());
+}
+else {
+// Don't sleep at all if this event took longer than the measure
+// interval to deliver.
+next_sleep = 0;
+}
+}
+if (next_sleep != 0 && !sExit) {
+PR_Sleep(next_sleep);
+}
+}
+if (threadArgs->mLogTracing) {
+long long now = PR_Now() / PR_USEC_PER_MSEC;
+fprintf(log, "MOZ_EVENT_TRACE stop %llu\n", now);
+}
+if (log != stdout)
+fclose(log);
+delete threadArgs;
+}
+} // namespace
+namespace mozilla {
+bool InitEventTracing(bool aLog)
+{
+if (sTracerThread)
+return true;
+// Initialize the widget backend.
+if (!InitWidgetTracing())
+return false;
+// The tracer thread owns the object and will delete it.
+TracerStartClosure* args = new TracerStartClosure();
+args->mLogTracing = aLog;
+// Pass the default threshold interval.
+int32_t thresholdInterval = 20;
+Preferences::GetInt("devtools.eventlooplag.threshold", &thresholdInterval);
+args->mThresholdInterval = thresholdInterval;
+// Create a thread that will fire events back at the
+// main thread to measure responsiveness.
+NS_ABORT_IF_FALSE(!sTracerThread, "Event tracing already initialized!");
+sTracerThread = PR_CreateThread(PR_USER_THREAD,
+TracerThread,
+args,
+PR_PRIORITY_NORMAL,
+PR_GLOBAL_THREAD,
+PR_JOINABLE_THREAD,
+0);
+return sTracerThread != nullptr;
+}
+void ShutdownEventTracing()
+{
+if (!sTracerThread)
+return;
+sExit = true;
+// Ensure that the tracer thread doesn't hang.
+SignalTracerThread();
+if (sTracerThread)
+PR_JoinThread(sTracerThread);
+sTracerThread = nullptr;
+// Allow the widget backend to clean up.
+CleanUpWidgetTracing();
+}
+}  // namespace mozilla

The Tor Browser / file comparison

comparison: toolkit/xre/EventTracer.cpp

toolkit/xre/EventTracer.cpp