From 1b0ac6a09466421cf05f282b8a4b854bd10d54ad Mon Sep 17 00:00:00 2001 From: Taras Glek Date: Thu, 14 Jul 2011 13:02:20 -0400 Subject: [PATCH] Bug 670008. Fix measurement of the startup telemetry numbers. r=glandium --- toolkit/components/startup/nsAppStartup.cpp | 55 +++++++++++++++---- .../telemetry/TelemetryHistograms.h | 1 + toolkit/components/telemetry/TelemetryPing.js | 10 ++-- 3 files changed, 52 insertions(+), 14 deletions(-) diff --git a/toolkit/components/startup/nsAppStartup.cpp b/toolkit/components/startup/nsAppStartup.cpp index cf3d7fb1955..abf4a747e2e 100644 --- a/toolkit/components/startup/nsAppStartup.cpp +++ b/toolkit/components/startup/nsAppStartup.cpp @@ -96,7 +96,11 @@ #include #endif +#include "mozilla/Telemetry.h" + static NS_DEFINE_CID(kAppShellCID, NS_APPSHELL_CID); + +using namespace mozilla; extern PRTime gXRE_mainTimestamp; extern PRTime gFirstPaintTimestamp; // mfinklesessionstore-browser-state-restored might be a better choice than the one below @@ -574,11 +578,11 @@ JiffiesSinceBoot(const char *file) char *s = strrchr(stat, ')'); if (!s) return 0; - sscanf(s + 2, - "%*c %*d %*d %*d %*d %*d %*u %*u %*u %*u " - "%*u %*u %*u %*u %*u %*d %*d %*d %*d %llu", - &starttime); - if (!starttime) + int ret = sscanf(s + 2, + "%*c %*d %*d %*d %*d %*d %*u %*u %*u %*u " + "%*u %*u %*u %*u %*u %*d %*d %*d %*d %llu", + &starttime); + if (ret != 1 || !starttime) return 0; return starttime; } @@ -595,7 +599,13 @@ ThreadedCalculateProcessCreationTimestamp(void *aClosure) char thread_stat[40]; sprintf(thread_stat, "/proc/self/task/%d/stat", (pid_t) syscall(__NR_gettid)); - PRTime interval = (JiffiesSinceBoot(thread_stat) - JiffiesSinceBoot("/proc/self/stat")) * PR_USEC_PER_SEC / hz;; + PRUint64 thread_jiffies = JiffiesSinceBoot(thread_stat); + PRUint64 self_jiffies = JiffiesSinceBoot("/proc/self/stat"); + + if (!thread_jiffies || !self_jiffies) + return; + + PRTime interval = (thread_jiffies - self_jiffies) * PR_USEC_PER_SEC / hz; gProcessCreationTimestamp = now - interval; } @@ -628,7 +638,7 @@ CalculateProcessCreationTimestamp() timestamp = (timestamp - 116444736000000000LL) / 10LL; #else timestamp = (timestamp - 116444736000000000i64) / 10i64; -#endif +#endif return timestamp; } #elif defined(XP_MACOSX) @@ -686,6 +696,13 @@ MaybeDefineProperty(JSContext *cx, JSObject *obj, const char *name, PRTime times JS_DefineProperty(cx, obj, name, OBJECT_TO_JSVAL(date), NULL, NULL, JSPROP_ENUMERATE); } +enum { + INVALID_PROCESS_CREATION = 0, + INVALID_MAIN, + INVALID_FIRST_PAINT, + INVALID_SESSION_RESTORED +}; + NS_IMETHODIMP nsAppStartup::GetStartupInfo() { @@ -720,10 +737,28 @@ nsAppStartup::GetStartupInfo() } else if (!gProcessCreationTimestamp) { gProcessCreationTimestamp = CalculateProcessCreationTimestamp(); } + // Bug 670008: Avoid obviously invalid process creation times + if (PR_Now() <= gProcessCreationTimestamp) { + gProcessCreationTimestamp = 0; + Telemetry::Accumulate(Telemetry::STARTUP_MEASUREMENT_ERRORS, INVALID_PROCESS_CREATION); + } MaybeDefineProperty(cx, obj, "process", gProcessCreationTimestamp); - MaybeDefineProperty(cx, obj, "main", gXRE_mainTimestamp); - MaybeDefineProperty(cx, obj, "firstPaint", gFirstPaintTimestamp); - MaybeDefineProperty(cx, obj, "sessionRestored", gRestoredTimestamp); + + if (gXRE_mainTimestamp >= gProcessCreationTimestamp) + MaybeDefineProperty(cx, obj, "main", gXRE_mainTimestamp); + else + Telemetry::Accumulate(Telemetry::STARTUP_MEASUREMENT_ERRORS, INVALID_MAIN); + + if (gFirstPaintTimestamp >= gXRE_mainTimestamp) + MaybeDefineProperty(cx, obj, "firstPaint", gFirstPaintTimestamp); + else + Telemetry::Accumulate(Telemetry::STARTUP_MEASUREMENT_ERRORS, INVALID_FIRST_PAINT); + + if (gRestoredTimestamp >= gXRE_mainTimestamp) + MaybeDefineProperty(cx, obj, "sessionRestored", gRestoredTimestamp); + else + Telemetry::Accumulate(Telemetry::STARTUP_MEASUREMENT_ERRORS, INVALID_SESSION_RESTORED); + return NS_OK; } diff --git a/toolkit/components/telemetry/TelemetryHistograms.h b/toolkit/components/telemetry/TelemetryHistograms.h index 77c675fc478..7de5bab2d3e 100644 --- a/toolkit/components/telemetry/TelemetryHistograms.h +++ b/toolkit/components/telemetry/TelemetryHistograms.h @@ -102,3 +102,4 @@ HTTP_HISTOGRAMS(SUB, "subitem: ") #undef HTTP_HISTOGRAMS HISTOGRAM(FIND_PLUGINS, 1, 3000, 10, EXPONENTIAL, "Time spent scanning filesystem for plugins (ms)") HISTOGRAM(CHECK_JAVA_ENABLED, 1, 3000, 10, EXPONENTIAL, "Time spent checking if Java is enabled (ms)") +HISTOGRAM(STARTUP_MEASUREMENT_ERRORS, 1, 3, 4, LINEAR, "Flags errors in startup calculation()") diff --git a/toolkit/components/telemetry/TelemetryPing.js b/toolkit/components/telemetry/TelemetryPing.js index c0f0a4db3ad..1e88fb345f9 100644 --- a/toolkit/components/telemetry/TelemetryPing.js +++ b/toolkit/components/telemetry/TelemetryPing.js @@ -186,10 +186,12 @@ function getSimpleMeasurements() { // uptime in minutes uptime: Math.round((new Date() - si.process) / 60000) } - for each (let field in ["main", "firstPaint", "sessionRestored"]) { - if (!(field in si)) - continue; - ret[field] = si[field] - si.process + if (si.process) { + for each (let field in ["main", "firstPaint", "sessionRestored"]) { + if (!(field in si)) + continue; + ret[field] = si[field] - si.process + } } return ret; }