Bug 793735 - Add functionality to create TimeStamp instances representing the process creation time, r=froydnj
authorGabriele Svelto <gsvelto@mozilla.com>
Thu, 28 Mar 2013 11:28:09 +0100
changeset 138889 8c5aa269c3cd94c773b5e95a0f886293ddbb637e
parent 138888 b0d84238095938e638497cd1b02bc7005f1abdfb
child 138890 77014412cd4a112a68a6f30d4e840033710a561d
push id2579
push userakeybl@mozilla.com
push dateMon, 24 Jun 2013 18:52:47 +0000
treeherdermozilla-beta@b69b7de8a05a [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersfroydnj
bugs793735
milestone23.0a1
first release with
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
last release without
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
Bug 793735 - Add functionality to create TimeStamp instances representing the process creation time, r=froydnj
xpcom/ds/TimeStamp.h
xpcom/ds/TimeStamp_darwin.cpp
xpcom/ds/TimeStamp_posix.cpp
xpcom/ds/TimeStamp_windows.cpp
--- a/xpcom/ds/TimeStamp.h
+++ b/xpcom/ds/TimeStamp.h
@@ -224,16 +224,38 @@ public:
    *
    * NowLoRes() has been introduced to workaround performance problems of
    * QueryPerformanceCounter on the Windows platform.  NowLoRes() is giving
    * lower precision, usually 15.6 ms, but with very good performance benefit.
    * Use it for measurements of longer times, like >200ms timeouts.
    */
   static TimeStamp Now() { return Now(true); }
   static TimeStamp NowLoRes() { return Now(false); }
+
+  /**
+   * Return a timestamp representing the time when the current process was
+   * created which will be comparable with other timestamps taken with this
+   * class. If the actual process creation time is detected to be inconsistent
+   * the @a aIsInconsistent parameter will be set to true, the returned
+   * timestamp however will still be valid though inaccurate.
+   *
+   * @param aIsInconsistent Set to true if an inconsistency was detected in the
+   * process creation time
+   * @returns A timestamp representing the time when the process was created,
+   * this timestamp is always valid even when errors are reported
+   */
+  static TimeStamp ProcessCreation(bool& aIsInconsistent);
+
+  /**
+   * Records a process restart. After this call ProcessCreation() will return
+   * the time when the browser was restarted instead of the actual time when
+   * the process was created.
+   */
+  static void RecordProcessRestart();
+
   /**
    * Compute the difference between two timestamps. Both must be non-null.
    */
   TimeDuration operator-(const TimeStamp& aOther) const {
     MOZ_ASSERT(!IsNull(), "Cannot compute with a null value");
     MOZ_ASSERT(!aOther.IsNull(), "Cannot compute with aOther null value");
     PR_STATIC_ASSERT(-INT64_MAX > INT64_MIN);
     int64_t ticks = int64_t(mValue - aOther.mValue);
@@ -325,13 +347,26 @@ private:
    * 
    * PR_INTERVAL_MAX is set at 100,000 ticks per second. So the minimum
    * time to wrap around is about 2^64/100000 seconds, i.e. about
    * 5,849,424 years.
    *
    * When using a system clock, a value is system dependent.
    */
   TimeStampValue mValue;
+
+  /**
+   * First timestamp taken when the class static initializers are run. This
+   * timestamp is used to sanitize timestamps coming from different sources.
+   */
+  static TimeStamp sFirstTimeStamp;
+
+  /**
+   * Timestamp representing the time when the process was created. This field
+   * is populated lazily the first time this information is required and is
+   * replaced every time the process is restarted.
+   */
+  static TimeStamp sProcessCreation;
 };
 
 }
 
 #endif /* mozilla_TimeStamp_h */
--- a/xpcom/ds/TimeStamp_darwin.cpp
+++ b/xpcom/ds/TimeStamp_darwin.cpp
@@ -12,26 +12,32 @@
 //
 // This code is inspired by Chromium's time_mac.cc. The biggest
 // differences are that we explicitly initialize using
 // TimeStamp::Initialize() instead of lazily in Now() and that
 // we store the time value in ticks and convert when needed instead
 // of storing the time value in nanoseconds.
 
 #include <mach/mach_time.h>
+#include <sys/param.h>
+#include <sys/time.h>
+#include <sys/sysctl.h>
 #include <time.h>
 
 #include "mozilla/TimeStamp.h"
+#include "nsCRT.h"
+#include "prenv.h"
+#include "prprf.h"
 
 // Estimate of the smallest duration of time we can measure.
 static uint64_t sResolution;
 static uint64_t sResolutionSigDigs;
 
-static const uint16_t kNsPerUs   =       1000;
 static const uint64_t kNsPerMs   =    1000000;
+static const uint64_t kUsPerSec  =    1000000;
 static const uint64_t kNsPerSec  = 1000000000;
 static const double kNsPerMsd    =    1000000.0;
 static const double kNsPerSecd   = 1000000000.0;
 
 static bool gInitialized = false;
 static double sNsPerTick;
 
 static uint64_t
@@ -72,16 +78,19 @@ ClockResolutionNs()
     minres = 1 * kNsPerMs;
   }
 
   return minres;
 }
 
 namespace mozilla {
 
+TimeStamp TimeStamp::sFirstTimeStamp;
+TimeStamp TimeStamp::sProcessCreation;
+
 double
 TimeDuration::ToSeconds() const
 {
   NS_ABORT_IF_FALSE(gInitialized, "calling TimeDuration too early");
   return (mValue * sNsPerTick) / kNsPerSecd;
 }
 
 double
@@ -142,23 +151,103 @@ TimeStamp::Startup()
   // find the number of significant digits in sResolution, for the
   // sake of ToSecondsSigDigits()
   for (sResolutionSigDigs = 1;
        !(sResolutionSigDigs == sResolution
          || 10*sResolutionSigDigs > sResolution);
        sResolutionSigDigs *= 10);
 
   gInitialized = true;
+  sFirstTimeStamp = TimeStamp::Now();
+  sProcessCreation = TimeStamp();
+
   return NS_OK;
 }
 
 void
 TimeStamp::Shutdown()
 {
 }
 
 TimeStamp
 TimeStamp::Now(bool aHighResolution)
 {
   return TimeStamp(ClockTime());
 }
 
+// Computes and returns the process uptime in microseconds.
+// Returns 0 if an error was encountered.
+
+static uint64_t
+ComputeProcessUptime()
+{
+  struct timeval tv;
+  int rv = gettimeofday(&tv, NULL);
+
+  if (rv == -1) {
+    return 0;
+  }
+
+  int mib[] = {
+    CTL_KERN,
+    KERN_PROC,
+    KERN_PROC_PID,
+    getpid(),
+  };
+  u_int mibLen = sizeof(mib) / sizeof(mib[0]);
+
+  struct kinfo_proc proc;
+  size_t bufferSize = sizeof(proc);
+  rv = sysctl(mib, mibLen, &proc, &bufferSize, NULL, 0);
+
+  if (rv == -1)
+    return 0;
+
+  uint64_t startTime =
+    ((uint64_t)proc.kp_proc.p_un.__p_starttime.tv_sec * kUsPerSec) +
+    proc.kp_proc.p_un.__p_starttime.tv_usec;
+  uint64_t now = (tv.tv_sec * kUsPerSec) + tv.tv_usec;
+
+  if (startTime > now)
+    return 0;
+
+  return now - startTime;
 }
+
+TimeStamp
+TimeStamp::ProcessCreation(bool& aIsInconsistent)
+{
+  aIsInconsistent = false;
+
+  if (sProcessCreation.IsNull()) {
+    char *mozAppRestart = PR_GetEnv("MOZ_APP_RESTART");
+    TimeStamp ts;
+
+    if (mozAppRestart) {
+      ts = TimeStamp(nsCRT::atoll(mozAppRestart));
+    } else {
+      TimeStamp now = TimeStamp::Now();
+      uint64_t uptime = ComputeProcessUptime();
+
+      ts = now - TimeDuration::FromMicroseconds(uptime);
+
+      if ((ts > sFirstTimeStamp) || (uptime == 0)) {
+        // If the process creation timestamp was inconsistent replace it with the
+        // first one instead and notify that a telemetry error was detected.
+        aIsInconsistent = true;
+        ts = sFirstTimeStamp;
+      }
+    }
+
+    sProcessCreation = ts;
+  }
+
+  return sProcessCreation;
+}
+
+void
+TimeStamp::RecordProcessRestart()
+{
+  PR_SetEnv(PR_smprintf("MOZ_APP_RESTART=%lld", ClockTime()));
+  sProcessCreation = TimeStamp();
+}
+
+}
--- a/xpcom/ds/TimeStamp_posix.cpp
+++ b/xpcom/ds/TimeStamp_posix.cpp
@@ -8,19 +8,54 @@
 // Implement TimeStamp::Now() with POSIX clocks.
 //
 // The "tick" unit for POSIX clocks is simply a nanosecond, as this is
 // the smallest unit of time representable by struct timespec.  That
 // doesn't mean that a nanosecond is the resolution of TimeDurations
 // obtained with this API; see TimeDuration::Resolution;
 //
 
+#include <sys/syscall.h>
 #include <time.h>
+#include <unistd.h>
+
+#if defined(__DragonFly__) || defined(__FreeBSD__) \
+    || defined(__NetBSD__) || defined(__OpenBSD__)
+#include <sys/param.h>
+#include <sys/sysctl.h>
+#endif
+
+#if defined(__DragonFly__) || defined(__FreeBSD__)
+#include <sys/user.h>
+#endif
+
+#if defined(__NetBSD__)
+#undef KERN_PROC
+#define KERN_PROC KERN_PROC2
+#define KINFO_PROC struct kinfo_proc2
+#else
+#define KINFO_PROC struct kinfo_proc
+#endif
+
+#if defined(__DragonFly__)
+#define KP_START_SEC kp_start.tv_sec
+#define KP_START_USEC kp_start.tv_usec
+#elif defined(__FreeBSD__)
+#define KP_START_SEC ki_start.tv_sec
+#define KP_START_USEC ki_start.tv_usec
+#else
+#define KP_START_SEC p_ustart_sec
+#define KP_START_USEC p_ustart_usec
+#endif
 
 #include "mozilla/TimeStamp.h"
+#include "nsCRT.h"
+#include "prenv.h"
+#include "prprf.h"
+#include "prthread.h"
 
 // Estimate of the smallest duration of time we can measure.
 static uint64_t sResolution;
 static uint64_t sResolutionSigDigs;
 
 static const uint16_t kNsPerUs   =       1000;
 static const uint64_t kNsPerMs   =    1000000;
 static const uint64_t kNsPerSec  = 1000000000; 
@@ -90,18 +125,20 @@ ClockResolutionNs()
     // clock_getres probably failed.  fall back on NSPR's resolution
     // assumption
     minres = 1 * kNsPerMs;
   }
 
   return minres;
 }
 
+namespace mozilla {
 
-namespace mozilla {
+TimeStamp TimeStamp::sFirstTimeStamp;
+TimeStamp TimeStamp::sProcessCreation;
 
 double
 TimeDuration::ToSeconds() const
 {
   return double(mValue) / kNsPerSecd;
 }
 
 double
@@ -154,23 +191,209 @@ TimeStamp::Startup()
   // find the number of significant digits in sResolution, for the
   // sake of ToSecondsSigDigits()
   for (sResolutionSigDigs = 1;
        !(sResolutionSigDigs == sResolution
          || 10*sResolutionSigDigs > sResolution);
        sResolutionSigDigs *= 10);
 
   gInitialized = true;
+  sFirstTimeStamp = TimeStamp::Now();
+  sProcessCreation = TimeStamp();
+
   return NS_OK;
 }
 
 void
 TimeStamp::Shutdown()
 {
 }
 
 TimeStamp
 TimeStamp::Now(bool aHighResolution)
 {
   return TimeStamp(ClockTimeNs());
 }
 
+#if defined(LINUX) || defined(ANDROID)
+
+// Calculates the amount of jiffies that have elapsed since boot and up to the
+// starttime value of a specific process as found in its /proc/*/stat file.
+// Returns 0 if an error occurred.
+
+static uint64_t
+JiffiesSinceBoot(const char *aFile)
+{
+  char stat[512];
+
+  FILE *f = fopen(aFile, "r");
+  if (!f)
+    return 0;
+
+  int n = fread(&stat, 1, sizeof(stat) - 1, f);
+
+  fclose(f);
+
+  if (n <= 0)
+    return 0;
+
+  stat[n] = 0;
+
+  long long unsigned startTime = 0; // instead of uint64_t to keep GCC quiet
+  char *s = strrchr(stat, ')');
+
+  if (!s)
+    return 0;
+
+  int rv = sscanf(s + 2,
+                  "%*c %*d %*d %*d %*d %*d %*u %*u %*u %*u "
+                  "%*u %*u %*u %*d %*d %*d %*d %*d %*d %llu",
+                  &startTime);
+
+  if (rv != 1 || !startTime)
+    return 0;
+
+  return startTime;
 }
+
+// Computes the interval that has elapsed between the thread creation and the
+// process creation by comparing the starttime fields in the respective
+// /proc/*/stat files. The resulting value will be a good approximation of the
+// process uptime. This value will be stored at the address pointed by aTime;
+// if an error occurred 0 will be stored instead.
+
+static void
+ComputeProcessUptimeThread(void *aTime)
+{
+  uint64_t *uptime = static_cast<uint64_t *>(aTime);
+  long hz = sysconf(_SC_CLK_TCK);
+
+  *uptime = 0;
+
+  if (!hz)
+    return;
+
+  char threadStat[40];
+  sprintf(threadStat, "/proc/self/task/%d/stat", (pid_t) syscall(__NR_gettid));
+
+  uint64_t threadJiffies = JiffiesSinceBoot(threadStat);
+  uint64_t selfJiffies = JiffiesSinceBoot("/proc/self/stat");
+
+  if (!threadJiffies || !selfJiffies)
+    return;
+
+  *uptime = ((threadJiffies - selfJiffies) * kNsPerSec) / hz;
+}
+
+// Computes and returns the process uptime in ns on Linux & its derivatives.
+// Returns 0 if an error was encountered.
+
+static uint64_t
+ComputeProcessUptime()
+{
+  uint64_t uptime = 0;
+  PRThread *thread = PR_CreateThread(PR_USER_THREAD,
+                                     ComputeProcessUptimeThread,
+                                     &uptime,
+                                     PR_PRIORITY_NORMAL,
+                                     PR_LOCAL_THREAD,
+                                     PR_JOINABLE_THREAD,
+                                     0);
+
+  PR_JoinThread(thread);
+
+  return uptime;
+}
+
+#elif defined(__DragonFly__) || defined(__FreeBSD__) \
+      || defined(__NetBSD__) || defined(__OpenBSD__)
+
+// Computes and returns the process uptime in ns on various BSD flavors.
+// Returns 0 if an error was encountered.
+
+static uint64_t
+ComputeProcessUptime()
+{
+  struct timespec ts;
+  int rv = clock_gettime(CLOCK_REALTIME, &ts);
+
+  if (rv == -1) {
+    return 0;
+  }
+
+  int mib[] = {
+    CTL_KERN,
+    KERN_PROC,
+    KERN_PROC_PID,
+    getpid(),
+#if defined(__NetBSD__) || defined(__OpenBSD__)
+    sizeof(KINFO_PROC),
+    1,
+#endif
+  };
+  u_int mibLen = sizeof(mib) / sizeof(mib[0]);
+
+  KINFO_PROC proc;
+  size_t bufferSize = sizeof(proc);
+  rv = sysctl(mib, mibLen, &proc, &bufferSize, NULL, 0);
+
+  if (rv == -1)
+    return 0;
+
+  uint64_t startTime = ((uint64_t)proc.KP_START_SEC * kNsPerSec)
+    + (proc.KP_START_USEC * kNsPerUs);
+  uint64_t now = ((uint64_t)ts.tv_sec * kNsPerSec) + ts.tv_nsec;
+
+  if (startTime > now)
+    return 0;
+
+  return (now - startTime);
+}
+
+#else
+
+static uint64_t
+ComputeProcessUptime()
+{
+  return 0;
+}
+
+#endif
+
+TimeStamp
+TimeStamp::ProcessCreation(bool& aIsInconsistent)
+{
+  aIsInconsistent = false;
+
+  if (sProcessCreation.IsNull()) {
+    char *mozAppRestart = PR_GetEnv("MOZ_APP_RESTART");
+    TimeStamp ts;
+
+    if (mozAppRestart) {
+      ts = TimeStamp(nsCRT::atoll(mozAppRestart));
+    } else {
+      TimeStamp now = TimeStamp::Now();
+      uint64_t uptime = ComputeProcessUptime();
+
+      ts = now - TimeDuration::FromMicroseconds(uptime / 1000);
+
+      if ((ts > sFirstTimeStamp) || (uptime == 0)) {
+        // If the process creation timestamp was inconsistent replace it with the
+        // first one instead and notify that a telemetry error was detected.
+        aIsInconsistent = true;
+        ts = sFirstTimeStamp;
+      }
+    }
+
+    sProcessCreation = ts;
+  }
+
+  return sProcessCreation;
+}
+
+void
+TimeStamp::RecordProcessRestart()
+{
+  PR_SetEnv(PR_smprintf("MOZ_APP_RESTART=%lld", ClockTimeNs()));
+  sProcessCreation = TimeStamp();
+}
+
+}
--- a/xpcom/ds/TimeStamp_windows.cpp
+++ b/xpcom/ds/TimeStamp_windows.cpp
@@ -11,17 +11,20 @@
 // before this reaches the Release or even Beta channel.
 #define FORCE_PR_LOG
 
 #include "mozilla/MathAlgorithms.h"
 #include "mozilla/Mutex.h"
 #include "mozilla/TimeStamp.h"
 #include <windows.h>
 
+#include "nsCRT.h"
 #include "prlog.h"
+#include "prenv.h"
+#include "prprf.h"
 #include <stdio.h>
 
 #include <intrin.h>
 
 #if defined(PR_LOGGING)
 // Log module for mozilla::TimeStamp for Windows logging...
 //
 // To enable logging (see prlog.h for full details):
@@ -157,16 +160,19 @@ static CRITICAL_SECTION sTimeStampLock;
 static DWORD sLastGTCResult = 0;
 
 // Higher part of the 64-bit value of MozGetTickCount64,
 // incremented atomically.
 static DWORD sLastGTCRollover = 0;
 
 namespace mozilla {
 
+TimeStamp TimeStamp::sFirstTimeStamp;
+TimeStamp TimeStamp::sProcessCreation;
+
 typedef ULONGLONG (WINAPI* GetTickCount64_t)();
 static GetTickCount64_t sGetTickCount64 = nullptr;
 
 // ----------------------------------------------------------------------------
 // Critical Section helper class
 // ----------------------------------------------------------------------------
 
 class AutoCriticalSection
@@ -522,16 +528,18 @@ TimeStamp::Startup()
     return NS_OK;
   }
 
   sFrequencyPerSec = freq.QuadPart;
   LOG(("TimeStamp: QPC frequency=%llu", sFrequencyPerSec));
 
   InitThresholds();
   InitResolution();
+  sFirstTimeStamp = TimeStamp::Now();
+  sProcessCreation = TimeStamp();
 
   return NS_OK;
 }
 
 void
 TimeStamp::Shutdown()
 {
   DeleteCriticalSection(&sTimeStampLock);
@@ -544,9 +552,79 @@ TimeStamp::Now(bool aHighResolution)
   bool useQPC = (aHighResolution && sUseQPC);
 
   // Both values are in [mt] units.
   ULONGLONG QPC = useQPC ? PerformanceCounter() : uint64_t(0);
   ULONGLONG GTC = ms2mt(sGetTickCount64());
   return TimeStamp(TimeStampValue(GTC, QPC, useQPC));
 }
 
+// Computes and returns the current process uptime in microseconds.
+// Returns 0 if an error was encountered while computing the uptime.
+
+static uint64_t
+ComputeProcessUptime()
+{
+  SYSTEMTIME nowSys;
+  GetSystemTime(&nowSys);
+
+  FILETIME now;
+  bool success = SystemTimeToFileTime(&nowSys, &now);
+
+  if (!success)
+    return 0;
+
+  FILETIME start, foo, bar, baz;
+  success = GetProcessTimes(GetCurrentProcess(), &start, &foo, &bar, &baz);
+
+  if (!success)
+    return 0;
+
+  ULARGE_INTEGER startUsec = {
+    start.dwLowDateTime,
+    start.dwHighDateTime
+  };
+  ULARGE_INTEGER nowUsec = {
+    now.dwLowDateTime,
+    now.dwHighDateTime
+  };
+
+  return (nowUsec.QuadPart - startUsec.QuadPart) / 10ULL;
+}
+
+TimeStamp
+TimeStamp::ProcessCreation(bool& aIsInconsistent)
+{
+  aIsInconsistent = false;
+
+  if (sProcessCreation.IsNull()) {
+    char *mozAppRestart = PR_GetEnv("MOZ_APP_RESTART");
+    TimeStamp ts;
+
+    if (mozAppRestart) {
+      ts = TimeStamp(TimeStampValue(nsCRT::atoll(mozAppRestart), 0, false));
+    } else {
+      TimeStamp now = TimeStamp::Now();
+      uint64_t uptime = ComputeProcessUptime();
+      ts = now - TimeDuration::FromMicroseconds(static_cast<double>(uptime));
+
+      if ((ts > sFirstTimeStamp) || (uptime == 0)) {
+        // If the process creation timestamp was inconsistent replace it with the
+        // first one instead and notify that a telemetry error was detected.
+        aIsInconsistent = true;
+        ts = sFirstTimeStamp;
+      }
+    }
+
+    sProcessCreation = ts;
+  }
+
+  return sProcessCreation;
+}
+
+void
+TimeStamp::RecordProcessRestart()
+{
+  PR_SetEnv(PR_smprintf("MOZ_APP_RESTART=%lld", ms2mt(sGetTickCount64())));
+  sProcessCreation = TimeStamp();
+}
+
 } // namespace mozilla