toolkit/xre/EventTracer.cpp

Sat, 03 Jan 2015 20:18:00 +0100

author
Michael Schloh von Bennewitz <michael@schloh.com>
date
Sat, 03 Jan 2015 20:18:00 +0100
branch
TOR_BUG_3246
changeset 7
129ffea94266
permissions
-rw-r--r--

Conditionally enable double key logic according to:
private browsing mode or privacy.thirdparty.isolate preference and
implement in GetCookieStringCommon and FindCookie where it counts...
With some reservations of how to convince FindCookie users to test
condition and pass a nullptr when disabling double key logic.

michael@0 1 /* This Source Code Form is subject to the terms of the Mozilla Public
michael@0 2 * License, v. 2.0. If a copy of the MPL was not distributed with this
michael@0 3 * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
michael@0 4
michael@0 5 /*
michael@0 6 * Event loop instrumentation. This code attempts to measure the
michael@0 7 * latency of the UI-thread event loop by firing native events at it from
michael@0 8 * a background thread, and measuring how long it takes for them
michael@0 9 * to be serviced. The measurement interval (kMeasureInterval, below)
michael@0 10 * is also used as the upper bound of acceptable response time.
michael@0 11 * When an event takes longer than that interval to be serviced,
michael@0 12 * a sample will be written to the log.
michael@0 13 *
michael@0 14 * Usage:
michael@0 15 *
michael@0 16 * Set MOZ_INSTRUMENT_EVENT_LOOP=1 in the environment to enable
michael@0 17 * this instrumentation. Currently only the UI process is instrumented.
michael@0 18 *
michael@0 19 * Set MOZ_INSTRUMENT_EVENT_LOOP_OUTPUT in the environment to a
michael@0 20 * file path to contain the log output, the default is to log to stdout.
michael@0 21 *
michael@0 22 * Set MOZ_INSTRUMENT_EVENT_LOOP_THRESHOLD in the environment to an
michael@0 23 * integer number of milliseconds to change the threshold for reporting.
michael@0 24 * The default is 20 milliseconds. Unresponsive periods shorter than this
michael@0 25 * threshold will not be reported.
michael@0 26 *
michael@0 27 * Set MOZ_INSTRUMENT_EVENT_LOOP_INTERVAL in the environment to an
michael@0 28 * integer number of milliseconds to change the maximum sampling frequency.
michael@0 29 * This variable controls how often events will be sent to the main
michael@0 30 * thread's event loop to sample responsiveness. The sampler will not
michael@0 31 * send events twice within LOOP_INTERVAL milliseconds.
michael@0 32 * The default is 10 milliseconds.
michael@0 33 *
michael@0 34 * All logged output lines start with MOZ_EVENT_TRACE. All timestamps
michael@0 35 * output are milliseconds since the epoch (PRTime / 1000).
michael@0 36 *
michael@0 37 * On startup, a line of the form:
michael@0 38 * MOZ_EVENT_TRACE start <timestamp>
michael@0 39 * will be output.
michael@0 40 *
michael@0 41 * On shutdown, a line of the form:
michael@0 42 * MOZ_EVENT_TRACE stop <timestamp>
michael@0 43 * will be output.
michael@0 44 *
michael@0 45 * When an event servicing time exceeds the threshold, a line of the form:
michael@0 46 * MOZ_EVENT_TRACE sample <timestamp> <duration>
michael@0 47 * will be output, where <duration> is the number of milliseconds that
michael@0 48 * it took for the event to be serviced. Duration may contain a fractional
michael@0 49 * component.
michael@0 50 */
michael@0 51
michael@0 52 #include "GeckoProfiler.h"
michael@0 53
michael@0 54 #include "EventTracer.h"
michael@0 55
michael@0 56 #include <stdio.h>
michael@0 57
michael@0 58 #include "mozilla/Preferences.h"
michael@0 59 #include "mozilla/TimeStamp.h"
michael@0 60 #include "mozilla/WidgetTraceEvent.h"
michael@0 61 #include "nsDebug.h"
michael@0 62 #include <limits.h>
michael@0 63 #include <prenv.h>
michael@0 64 #include <prinrval.h>
michael@0 65 #include <prthread.h>
michael@0 66 #include <prtime.h>
michael@0 67
michael@0 68 #ifdef MOZ_WIDGET_GONK
michael@0 69 #include "nsThreadUtils.h"
michael@0 70 #include "nsIObserverService.h"
michael@0 71 #include "mozilla/Services.h"
michael@0 72 #endif
michael@0 73
michael@0 74 using mozilla::TimeDuration;
michael@0 75 using mozilla::TimeStamp;
michael@0 76 using mozilla::FireAndWaitForTracerEvent;
michael@0 77
michael@0 78 namespace {
michael@0 79
michael@0 80 PRThread* sTracerThread = nullptr;
michael@0 81 bool sExit = false;
michael@0 82
michael@0 83 struct TracerStartClosure {
michael@0 84 bool mLogTracing;
michael@0 85 int32_t mThresholdInterval;
michael@0 86 };
michael@0 87
michael@0 88 #ifdef MOZ_WIDGET_GONK
michael@0 89 class EventLoopLagDispatcher : public nsRunnable
michael@0 90 {
michael@0 91 public:
michael@0 92 explicit EventLoopLagDispatcher(int aLag)
michael@0 93 : mLag(aLag) {}
michael@0 94
michael@0 95 NS_IMETHODIMP Run()
michael@0 96 {
michael@0 97 nsCOMPtr<nsIObserverService> obsService =
michael@0 98 mozilla::services::GetObserverService();
michael@0 99 if (!obsService) {
michael@0 100 return NS_ERROR_FAILURE;
michael@0 101 }
michael@0 102
michael@0 103 nsAutoString value;
michael@0 104 value.AppendInt(mLag);
michael@0 105 return obsService->NotifyObservers(nullptr, "event-loop-lag", value.get());
michael@0 106 }
michael@0 107
michael@0 108 private:
michael@0 109 int mLag;
michael@0 110 };
michael@0 111 #endif
michael@0 112
michael@0 113 /*
michael@0 114 * The tracer thread fires events at the native event loop roughly
michael@0 115 * every kMeasureInterval. It will sleep to attempt not to send them
michael@0 116 * more quickly, but if the response time is longer than kMeasureInterval
michael@0 117 * it will not send another event until the previous response is received.
michael@0 118 *
michael@0 119 * The output defaults to stdout, but can be redirected to a file by
michael@0 120 * settting the environment variable MOZ_INSTRUMENT_EVENT_LOOP_OUTPUT
michael@0 121 * to the name of a file to use.
michael@0 122 */
michael@0 123 void TracerThread(void *arg)
michael@0 124 {
michael@0 125 PR_SetCurrentThreadName("Event Tracer");
michael@0 126
michael@0 127 TracerStartClosure* threadArgs = static_cast<TracerStartClosure*>(arg);
michael@0 128
michael@0 129 // These are the defaults. They can be overridden by environment vars.
michael@0 130 // This should be set to the maximum latency we'd like to allow
michael@0 131 // for responsiveness.
michael@0 132 int32_t thresholdInterval = threadArgs->mThresholdInterval;
michael@0 133 PRIntervalTime threshold = PR_MillisecondsToInterval(thresholdInterval);
michael@0 134 // This is the sampling interval.
michael@0 135 PRIntervalTime interval = PR_MillisecondsToInterval(thresholdInterval / 2);
michael@0 136
michael@0 137 sExit = false;
michael@0 138 FILE* log = nullptr;
michael@0 139 char* envfile = PR_GetEnv("MOZ_INSTRUMENT_EVENT_LOOP_OUTPUT");
michael@0 140 if (envfile) {
michael@0 141 log = fopen(envfile, "w");
michael@0 142 }
michael@0 143 if (log == nullptr)
michael@0 144 log = stdout;
michael@0 145
michael@0 146 char* thresholdenv = PR_GetEnv("MOZ_INSTRUMENT_EVENT_LOOP_THRESHOLD");
michael@0 147 if (thresholdenv && *thresholdenv) {
michael@0 148 int val = atoi(thresholdenv);
michael@0 149 if (val != 0 && val != INT_MAX && val != INT_MIN) {
michael@0 150 threshold = PR_MillisecondsToInterval(val);
michael@0 151 }
michael@0 152 }
michael@0 153
michael@0 154 char* intervalenv = PR_GetEnv("MOZ_INSTRUMENT_EVENT_LOOP_INTERVAL");
michael@0 155 if (intervalenv && *intervalenv) {
michael@0 156 int val = atoi(intervalenv);
michael@0 157 if (val != 0 && val != INT_MAX && val != INT_MIN) {
michael@0 158 interval = PR_MillisecondsToInterval(val);
michael@0 159 }
michael@0 160 }
michael@0 161
michael@0 162 if (threadArgs->mLogTracing) {
michael@0 163 long long now = PR_Now() / PR_USEC_PER_MSEC;
michael@0 164 fprintf(log, "MOZ_EVENT_TRACE start %llu\n", now);
michael@0 165 }
michael@0 166
michael@0 167 while (!sExit) {
michael@0 168 TimeStamp start(TimeStamp::Now());
michael@0 169 profiler_responsiveness(start);
michael@0 170 PRIntervalTime next_sleep = interval;
michael@0 171
michael@0 172 //TODO: only wait up to a maximum of interval; return
michael@0 173 // early if that threshold is exceeded and dump a stack trace
michael@0 174 // or do something else useful.
michael@0 175 if (FireAndWaitForTracerEvent()) {
michael@0 176 TimeDuration duration = TimeStamp::Now() - start;
michael@0 177 // Only report samples that exceed our measurement threshold.
michael@0 178 long long now = PR_Now() / PR_USEC_PER_MSEC;
michael@0 179 if (threadArgs->mLogTracing && duration.ToMilliseconds() > threshold) {
michael@0 180 fprintf(log, "MOZ_EVENT_TRACE sample %llu %lf\n",
michael@0 181 now,
michael@0 182 duration.ToMilliseconds());
michael@0 183 #ifdef MOZ_WIDGET_GONK
michael@0 184 NS_DispatchToMainThread(
michael@0 185 new EventLoopLagDispatcher(int(duration.ToSecondsSigDigits() * 1000)));
michael@0 186 #endif
michael@0 187 }
michael@0 188
michael@0 189 if (next_sleep > duration.ToMilliseconds()) {
michael@0 190 next_sleep -= int(duration.ToMilliseconds());
michael@0 191 }
michael@0 192 else {
michael@0 193 // Don't sleep at all if this event took longer than the measure
michael@0 194 // interval to deliver.
michael@0 195 next_sleep = 0;
michael@0 196 }
michael@0 197 }
michael@0 198
michael@0 199 if (next_sleep != 0 && !sExit) {
michael@0 200 PR_Sleep(next_sleep);
michael@0 201 }
michael@0 202 }
michael@0 203
michael@0 204 if (threadArgs->mLogTracing) {
michael@0 205 long long now = PR_Now() / PR_USEC_PER_MSEC;
michael@0 206 fprintf(log, "MOZ_EVENT_TRACE stop %llu\n", now);
michael@0 207 }
michael@0 208
michael@0 209 if (log != stdout)
michael@0 210 fclose(log);
michael@0 211
michael@0 212 delete threadArgs;
michael@0 213 }
michael@0 214
michael@0 215 } // namespace
michael@0 216
michael@0 217 namespace mozilla {
michael@0 218
michael@0 219 bool InitEventTracing(bool aLog)
michael@0 220 {
michael@0 221 if (sTracerThread)
michael@0 222 return true;
michael@0 223
michael@0 224 // Initialize the widget backend.
michael@0 225 if (!InitWidgetTracing())
michael@0 226 return false;
michael@0 227
michael@0 228 // The tracer thread owns the object and will delete it.
michael@0 229 TracerStartClosure* args = new TracerStartClosure();
michael@0 230 args->mLogTracing = aLog;
michael@0 231
michael@0 232 // Pass the default threshold interval.
michael@0 233 int32_t thresholdInterval = 20;
michael@0 234 Preferences::GetInt("devtools.eventlooplag.threshold", &thresholdInterval);
michael@0 235 args->mThresholdInterval = thresholdInterval;
michael@0 236
michael@0 237 // Create a thread that will fire events back at the
michael@0 238 // main thread to measure responsiveness.
michael@0 239 NS_ABORT_IF_FALSE(!sTracerThread, "Event tracing already initialized!");
michael@0 240 sTracerThread = PR_CreateThread(PR_USER_THREAD,
michael@0 241 TracerThread,
michael@0 242 args,
michael@0 243 PR_PRIORITY_NORMAL,
michael@0 244 PR_GLOBAL_THREAD,
michael@0 245 PR_JOINABLE_THREAD,
michael@0 246 0);
michael@0 247 return sTracerThread != nullptr;
michael@0 248 }
michael@0 249
michael@0 250 void ShutdownEventTracing()
michael@0 251 {
michael@0 252 if (!sTracerThread)
michael@0 253 return;
michael@0 254
michael@0 255 sExit = true;
michael@0 256 // Ensure that the tracer thread doesn't hang.
michael@0 257 SignalTracerThread();
michael@0 258
michael@0 259 if (sTracerThread)
michael@0 260 PR_JoinThread(sTracerThread);
michael@0 261 sTracerThread = nullptr;
michael@0 262
michael@0 263 // Allow the widget backend to clean up.
michael@0 264 CleanUpWidgetTracing();
michael@0 265 }
michael@0 266
michael@0 267 } // namespace mozilla

mercurial