Bug 1425462 Add logging to ReduceTimePrecision to output what we hope will be strictly increasing timestamps and print the callers draft
authorTom Ritter <tom@mozilla.com>
Thu, 18 Jan 2018 15:08:11 -0600
changeset 724410 5485dd5e8844723985bf9f48b3e9390d1c57e3ab
parent 724409 c190e87f29df18b6158ae87f0bac1e91e4298c0c
child 724411 a6c0992dbcef536c31e65c4b01711d5b889cdfdd
push id96741
push userbmo:tom@mozilla.com
push dateWed, 24 Jan 2018 22:45:52 +0000
bugs1425462
milestone59.0a1
Bug 1425462 Add logging to ReduceTimePrecision to output what we hope will be strictly increasing timestamps and print the callers MozReview-Commit-ID: GiEYzAn5xLQ
toolkit/components/resistfingerprinting/nsRFPService.cpp
toolkit/components/resistfingerprinting/nsRFPService.h
--- a/toolkit/components/resistfingerprinting/nsRFPService.cpp
+++ b/toolkit/components/resistfingerprinting/nsRFPService.cpp
@@ -1,16 +1,17 @@
 /* -*- Mode: C++; tab-width: 2; indent-tabs-mode: nil; c-basic-offset: 2 -*- */
 /* 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/. */
 
 #include "nsRFPService.h"
 
 #include <algorithm>
+#include <execinfo.h>
 #include <time.h>
 
 #include "mozilla/ClearOnShutdown.h"
 #include "mozilla/Logging.h"
 #include "mozilla/Preferences.h"
 #include "mozilla/Services.h"
 #include "mozilla/StaticPtr.h"
 #include "mozilla/TextEvents.h"
@@ -141,20 +142,46 @@ nsRFPService::IsResistFingerprintingEnab
 /* static */
 bool
 nsRFPService::IsTimerPrecisionReductionEnabled()
 {
   return (sPrivacyTimerPrecisionReduction || IsResistFingerprintingEnabled()) &&
          TimerResolution() != 0;
 }
 
+#define INIT_STACKTRACE() \
+  void* callstack[4]; \
+  int frames = backtrace(callstack, 4); \
+  char** strs = backtrace_symbols(callstack, frames);
+
+#define CALLER() \
+  ((strstr(strs[1], "Performance3Now") != NULL) ? "performance.now()" : \
+  ((strstr(strs[1], "dom5Event13TimeStampImplEv") != NULL) ? "Event.timeStamp" : \
+  ((strstr(strs[2], "AnimationTimeline22GetCurrentTimeAsDouble") != NULL) ? "AnimationTimeline::GetCurrentTimeAsDouble" : \
+  "")))
+
+#define PRINT_STACKTRACE() \
+  if (strcmp(CALLER(), "") == 0) { \
+    for (int i = 0; i < frames; ++i) { \
+      MOZ_LOG(gResistFingerprintingLog, LogLevel::Debug, ("  %s\n", strs[i])); \
+    } \
+  } \
+  free(strs);
+
 /* static */
 double
-nsRFPService::ReduceTimePrecisionAsMSecs(double aTime)
+nsRFPService::ReduceTimePrecisionAsMSecs(double aTime, double timeOrigin /* = 0 */)
 {
+#if defined(DEBUG)
+  INIT_STACKTRACE();
+  MOZ_LOG(gResistFingerprintingLog, LogLevel::Debug,
+    ("Parent: %d Timestamp: %f Caller: %s", XRE_IsParentProcess(), (aTime + timeOrigin), CALLER()));
+  PRINT_STACKTRACE();
+#endif
+
   if (!IsTimerPrecisionReductionEnabled()) {
     return aTime;
   }
   const double resolutionMSec = TimerResolution() / 1000.0;
   double clamped = floor(aTime / resolutionMSec) * resolutionMSec;
 #if defined(DEBUG)
   MOZ_LOG(gResistFingerprintingLog, LogLevel::Verbose,
     ("Given: %.*f, Rounding with %.*f, Intermediate: %.*f, Got: %.*f",
@@ -171,18 +198,25 @@ nsRFPService::ReduceTimePrecisionAsMSecs
     clamped += r1 * 2 * jitterResolutionMSec - jitterResolutionMSec;
   }
 
   return clamped;
 }
 
 /* static */
 double
-nsRFPService::ReduceTimePrecisionAsUSecs(double aTime)
+nsRFPService::ReduceTimePrecisionAsUSecs(double aTime, double timeOrigin /* = 0 */)
 {
+#if defined(DEBUG)
+  INIT_STACKTRACE();
+  MOZ_LOG(gResistFingerprintingLog, LogLevel::Debug,
+    ("Parent: %d Timestamp: %f Caller: %s", XRE_IsParentProcess(), (aTime + timeOrigin), CALLER()));
+  PRINT_STACKTRACE();
+#endif
+
   if (!IsTimerPrecisionReductionEnabled()) {
     return aTime;
   }
   double resolutionUSec = TimerResolution();
   double clamped = floor(aTime / resolutionUSec) * resolutionUSec;
 #if defined(DEBUG)
   double tmp_sResolutionUSec = resolutionUSec;
   MOZ_LOG(gResistFingerprintingLog, LogLevel::Verbose,
@@ -206,18 +240,25 @@ nsRFPService::ReduceTimePrecisionAsUSecs
 uint32_t
 nsRFPService::CalculateTargetVideoResolution(uint32_t aVideoQuality)
 {
   return aVideoQuality * NSToIntCeil(aVideoQuality * 16 / 9.0);
 }
 
 /* static */
 double
-nsRFPService::ReduceTimePrecisionAsSecs(double aTime)
+nsRFPService::ReduceTimePrecisionAsSecs(double aTime, double timeOrigin /* = 0 */)
 {
+#if defined(DEBUG)
+  INIT_STACKTRACE();
+  MOZ_LOG(gResistFingerprintingLog, LogLevel::Debug,
+    ("Parent: %d Timestamp: %f Caller: %s", XRE_IsParentProcess(), (aTime + timeOrigin), CALLER()));
+  PRINT_STACKTRACE();
+#endif
+
   if (!IsTimerPrecisionReductionEnabled()) {
     return aTime;
   }
   double clamped;
   double resolutionUSec = TimerResolution();
   if (TimerResolution() < 1000000) {
     // The resolution is smaller than one sec.  Use the reciprocal to avoid
     // floating point error.
--- a/toolkit/components/resistfingerprinting/nsRFPService.h
+++ b/toolkit/components/resistfingerprinting/nsRFPService.h
@@ -156,19 +156,19 @@ public:
   NS_DECL_ISUPPORTS
   NS_DECL_NSIOBSERVER
 
   static nsRFPService* GetOrCreate();
   static bool IsResistFingerprintingEnabled();
   static bool IsTimerPrecisionReductionEnabled();
 
   // The following Reduce methods can be called off main thread.
-  static double ReduceTimePrecisionAsMSecs(double aTime);
-  static double ReduceTimePrecisionAsUSecs(double aTime);
-  static double ReduceTimePrecisionAsSecs(double aTime);
+  static double ReduceTimePrecisionAsMSecs(double aTime, double timeOrigin = 0);
+  static double ReduceTimePrecisionAsUSecs(double aTime, double timeOrigin = 0);
+  static double ReduceTimePrecisionAsSecs(double aTime, double timeOrigin = 0);
 
   // This method calculates the video resolution (i.e. height x width) based
   // on the video quality (480p, 720p, etc).
   static uint32_t CalculateTargetVideoResolution(uint32_t aVideoQuality);
 
   // Methods for getting spoofed media statistics and the return value will
   // depend on the video resolution.
   static uint32_t GetSpoofedTotalFrames(double aTime);