/* ***** BEGIN LICENSE BLOCK ***** * Version: MPL 1.1/GPL 2.0/LGPL 2.1 * * The contents of this file are subject to the Mozilla Public License Version * 1.1 (the "License"); you may not use this file except in compliance with * the License. You may obtain a copy of the License at * http://www.mozilla.org/MPL/ * * Software distributed under the License is distributed on an "AS IS" basis, * WITHOUT WARRANTY OF ANY KIND, either express or implied. See the License * for the specific language governing rights and limitations under the * License. * * The Original Code is mozilla.org code. * * The Initial Developer of the Original Code is * The Mozilla Foundation. * Portions created by the Initial Developer are Copyright (C) 2011 * the Initial Developer. All Rights Reserved. * * Contributor(s): * Ted Mielczarek * * Alternatively, the contents of this file may be used under the terms of * either the GNU General Public License Version 2 or later (the "GPL"), or * the GNU Lesser General Public License Version 2.1 or later (the "LGPL"), * in which case the provisions of the GPL or the LGPL are applicable instead * of those above. If you wish to allow use of your version of this file only * under the terms of either the GPL or the LGPL, and not to allow others to * use your version of this file under the terms of the MPL, indicate your * decision by deleting the provisions above and replace them with the notice * and other provisions required by the GPL or the LGPL. If you do not delete * the provisions above, a recipient may use your version of this file under * the terms of any one of the MPL, the GPL or the LGPL. * * ***** END LICENSE BLOCK ***** */ /* * 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 * will be output. * * On shutdown, a line of the form: * MOZ_EVENT_TRACE stop * will be output. * * When an event servicing time exceeds the threshold, a line of the form: * MOZ_EVENT_TRACE sample * will be output, where is the number of milliseconds that * it took for the event to be serviced. */ #include "sampler.h" #include "EventTracer.h" #include #include "mozilla/TimeStamp.h" #include "mozilla/WidgetTraceEvent.h" #include #include #include #include #include using mozilla::TimeDuration; using mozilla::TimeStamp; using mozilla::FireAndWaitForTracerEvent; namespace { PRThread* sTracerThread = NULL; bool sExit = false; /* * 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) { // 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. PRIntervalTime threshold = PR_MillisecondsToInterval(20); // This is the sampling interval. PRIntervalTime interval = PR_MillisecondsToInterval(10); sExit = false; FILE* log = NULL; char* envfile = PR_GetEnv("MOZ_INSTRUMENT_EVENT_LOOP_OUTPUT"); if (envfile) { log = fopen(envfile, "w"); } if (log == NULL) 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); } } fprintf(log, "MOZ_EVENT_TRACE start %llu\n", PR_Now() / PR_USEC_PER_MSEC); while (!sExit) { TimeStamp start(TimeStamp::Now()); SAMPLER_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. if (duration.ToMilliseconds() > threshold) { fprintf(log, "MOZ_EVENT_TRACE sample %llu %d\n", PR_Now() / PR_USEC_PER_MSEC, int(duration.ToSecondsSigDigits() * 1000)); } 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); } } fprintf(log, "MOZ_EVENT_TRACE stop %llu\n", PR_Now() / PR_USEC_PER_MSEC); if (log != stdout) fclose(log); } } // namespace namespace mozilla { bool InitEventTracing() { if (sTracerThread) return true; // Initialize the widget backend. if (!InitWidgetTracing()) return false; // 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, NULL, PR_PRIORITY_NORMAL, PR_GLOBAL_THREAD, PR_JOINABLE_THREAD, 0); return sTracerThread != NULL; } void ShutdownEventTracing() { if (!sTracerThread) return; sExit = true; // Ensure that the tracer thread doesn't hang. SignalTracerThread(); if (sTracerThread) PR_JoinThread(sTracerThread); sTracerThread = NULL; // Allow the widget backend to clean up. CleanUpWidgetTracing(); } } // namespace mozilla