Bug 1429764 Do not call ReduceTimerPrecision twice for DOM Navigation timers r=bkelly,timhuang
authorTom Ritter <tom@mozilla.com>
Fri, 12 Jan 2018 13:36:04 -0600
changeset 399590 17bf5819b42fa3b656f2d3c565bc4fb0ca050066
parent 399589 947d9e8d3265bd15e4c324624d141c3af71eb04f
child 399591 7be74a94e7667f417a92098953f0c2adfa4bb65d
push id98981
push usercsabou@mozilla.com
push dateWed, 17 Jan 2018 09:51:16 +0000
treeherdermozilla-inbound@7eaf34a4efa6 [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersbkelly, timhuang
bugs1429764
milestone59.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 1429764 Do not call ReduceTimerPrecision twice for DOM Navigation timers r=bkelly,timhuang Bug 1429764 details a test failure that was asserting that the performance navigation timers were strictly increasing (or equal). fetchStart should have a timestamp before domainLookupStart. But it didn't. The problem is two-fold. This corrects the test and the issue by addressing one part of the problem, the second part of the problem needs to be written up in a new bug and addressed there. (That bug is not yet filed at writing, but see dependencies of 1429764 in the future to find it.) The second, and underlying, problem is that calling ReduceTimerPrecision with the same value multiple times may continually reduce it. Meaning that the first you call it with, say, .75, (and a precision of .20), it will be reduced to .6. The second time you call it (with .6), instead of staying at .6 it will be reduced to .4. This is because floats are fuzzy. Inside ReduceTimerPrecision we are multiplying a decimal by a decimal, so while floor(.6 / .20) should equal 3, sometimes it's actually 2.999... which gets floors to 2, gets multiplied again by .2, and which results in .4 If that's the underlying problem, the first, and surface, problem is - why are we calling ReduceTimerPrecision multiple times? We shouldn't be. That's what this patch fixes. TimeStampToDOMHighResOrFetchStart will return either TimeStampToDOMHighRes() or FetchStartHighRes(). FetchStartHighRes() internally calls TimeStampToDOMHighRes and then ReduceTimerPrecision - this is where (some of) the two reduction calls happen - because TimeStampToDOMHighRes itself calls ReduceTimerPrecision also. I remove the ReduceTimerPrecision from TimeStampToDOMHighRes. FetchStartHighRes will now only call ReduceTimerPrecision once, at the end of the return. But we have to fix places we call TimeStampToDOMHighResOrFetchStart, because the callers of that function also call ReduceTimerPrecision. So if TimeStampToDOMHighResOrFetchStart returned FetchStartHighRes, we'd be calling ReduceTimerPrecision twice for those callers. So inside first off, we remove the outer call to ReduceTimerPrecision. that surrounds the 5 or so callsites of TimeStampToDOMHighResOrFetchStart. Then inside of TimeStampToDOMHighResOrFetchStart we return either FetchStartHighRes (which is has already called ReduceTimerPrecision) or we call ReduceTimerPrecision with the value. Now. TimeStampToDOMHighRes was used in more places than just FetchStartHighRes - there were several other places where we were doing double rounding, and this fixed those as well. AsyncOpenHighRes, WorkerStartHighRes, DomainLookupEndHighRes, ConnectStartHighRes, SecureConnectionStartHighRes, ConnectEndHighRes, and ResponseEndHighRes. MozReview-Commit-ID: K5nHql135rb
dom/performance/PerformanceTiming.cpp
dom/performance/PerformanceTiming.h
toolkit/components/resistfingerprinting/nsRFPService.cpp
--- a/dom/performance/PerformanceTiming.cpp
+++ b/dom/performance/PerformanceTiming.cpp
@@ -273,18 +273,17 @@ PerformanceTiming::WorkerStartHighRes()
  */
 DOMHighResTimeStamp
 PerformanceTiming::RedirectStartHighRes()
 {
   if (!nsContentUtils::IsPerformanceTimingEnabled() || !IsInitialized() ||
       nsContentUtils::ShouldResistFingerprinting()) {
     return mZeroTime;
   }
-  return nsRFPService::ReduceTimePrecisionAsMSecs(
-    TimeStampToDOMHighResOrFetchStart(mRedirectStart));
+  return TimeStampToReducedDOMHighResOrFetchStart(mRedirectStart);
 }
 
 DOMTimeMilliSec
 PerformanceTiming::RedirectStart()
 {
   if (!IsInitialized()) {
     return 0;
   }
@@ -308,18 +307,17 @@ PerformanceTiming::RedirectStart()
  */
 DOMHighResTimeStamp
 PerformanceTiming::RedirectEndHighRes()
 {
   if (!nsContentUtils::IsPerformanceTimingEnabled() || !IsInitialized() ||
       nsContentUtils::ShouldResistFingerprinting()) {
     return mZeroTime;
   }
-  return nsRFPService::ReduceTimePrecisionAsMSecs(
-    TimeStampToDOMHighResOrFetchStart(mRedirectEnd));
+  return TimeStampToReducedDOMHighResOrFetchStart(mRedirectEnd);
 }
 
 DOMTimeMilliSec
 PerformanceTiming::RedirectEnd()
 {
   if (!IsInitialized()) {
     return 0;
   }
@@ -333,18 +331,17 @@ PerformanceTiming::RedirectEnd()
 
 DOMHighResTimeStamp
 PerformanceTiming::DomainLookupStartHighRes()
 {
   if (!nsContentUtils::IsPerformanceTimingEnabled() || !IsInitialized() ||
       nsContentUtils::ShouldResistFingerprinting()) {
     return mZeroTime;
   }
-  return nsRFPService::ReduceTimePrecisionAsMSecs(
-    TimeStampToDOMHighResOrFetchStart(mDomainLookupStart));
+  return TimeStampToReducedDOMHighResOrFetchStart(mDomainLookupStart);
 }
 
 DOMTimeMilliSec
 PerformanceTiming::DomainLookupStart()
 {
   return static_cast<int64_t>(DomainLookupStartHighRes());
 }
 
@@ -432,18 +429,17 @@ PerformanceTiming::RequestStartHighRes()
       nsContentUtils::ShouldResistFingerprinting()) {
     return mZeroTime;
   }
 
   if (mRequestStart.IsNull()) {
     mRequestStart = mWorkerRequestStart;
   }
 
-  return nsRFPService::ReduceTimePrecisionAsMSecs(
-    TimeStampToDOMHighResOrFetchStart(mRequestStart));
+  return TimeStampToReducedDOMHighResOrFetchStart(mRequestStart);
 }
 
 DOMTimeMilliSec
 PerformanceTiming::RequestStart()
 {
   return static_cast<int64_t>(RequestStartHighRes());
 }
 
@@ -458,18 +454,17 @@ PerformanceTiming::ResponseStartHighRes(
      (!mCacheReadStart.IsNull() && mCacheReadStart < mResponseStart)) {
     mResponseStart = mCacheReadStart;
   }
 
   if (mResponseStart.IsNull() ||
       (!mRequestStart.IsNull() && mResponseStart < mRequestStart)) {
     mResponseStart = mRequestStart;
   }
-  return nsRFPService::ReduceTimePrecisionAsMSecs(
-    TimeStampToDOMHighResOrFetchStart(mResponseStart));
+  return TimeStampToReducedDOMHighResOrFetchStart(mResponseStart);
 }
 
 DOMTimeMilliSec
 PerformanceTiming::ResponseStart()
 {
   return static_cast<int64_t>(ResponseStartHighRes());
 }
 
--- a/dom/performance/PerformanceTiming.h
+++ b/dom/performance/PerformanceTiming.h
@@ -64,20 +64,20 @@ public:
    * @param   aStamp
    *          The TimeStamp recorded for a specific event. This TimeStamp can
    *          be null.
    * @return  the duration of an event with a given TimeStamp, relative to the
    *          navigationStart TimeStamp (the moment the user landed on the
    *          page), if the given TimeStamp is valid. Otherwise, it will return
    *          the FetchStart timing value.
    */
-  inline DOMHighResTimeStamp TimeStampToDOMHighResOrFetchStart(TimeStamp aStamp)
+  inline DOMHighResTimeStamp TimeStampToReducedDOMHighResOrFetchStart(TimeStamp aStamp)
   {
     return (!aStamp.IsNull())
-        ? TimeStampToDOMHighRes(aStamp)
+        ? nsRFPService::ReduceTimePrecisionAsMSecs(TimeStampToDOMHighRes(aStamp))
         : FetchStartHighRes();
   }
 
   /**
    * The nsITimedChannel records an absolute timestamp for each event.
    * The nsDOMNavigationTiming will record the moment when the user landed on
    * the page. This is a window.performance unique timestamp, so it can be used
    * for all the events (navigation timing and resource timing events).
@@ -103,18 +103,17 @@ public:
    * page
    * - an absolute wall clock time since the unix epoch
    */
   inline DOMHighResTimeStamp TimeStampToDOMHighRes(TimeStamp aStamp) const
   {
     MOZ_ASSERT(!aStamp.IsNull());
     TimeDuration duration =
         aStamp - GetDOMTiming()->GetNavigationStartTimeStamp();
-    return nsRFPService::ReduceTimePrecisionAsMSecs(
-      duration.ToMilliseconds() + mZeroTime);
+    return duration.ToMilliseconds() + mZeroTime;
   }
 
   virtual JSObject* WrapObject(JSContext *cx,
                                JS::Handle<JSObject*> aGivenProto) override;
 
   // PerformanceNavigation WebIDL methods
   DOMTimeMilliSec NavigationStart() const
   {
--- a/toolkit/components/resistfingerprinting/nsRFPService.cpp
+++ b/toolkit/components/resistfingerprinting/nsRFPService.cpp
@@ -4,16 +4,17 @@
  * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
 
 #include "nsRFPService.h"
 
 #include <algorithm>
 #include <time.h>
 
 #include "mozilla/ClearOnShutdown.h"
+#include "mozilla/Logging.h"
 #include "mozilla/Preferences.h"
 #include "mozilla/Services.h"
 #include "mozilla/StaticPtr.h"
 
 #include "nsCOMPtr.h"
 #include "nsCoord.h"
 #include "nsServiceManagerUtils.h"
 #include "nsString.h"
@@ -29,16 +30,20 @@
 
 #include "prenv.h"
 
 #include "js/Date.h"
 
 using namespace mozilla;
 using namespace std;
 
+#ifdef DEBUG
+static mozilla::LazyLogModule gResistFingerprintingLog("nsResistFingerprinting");
+#endif
+
 #define RESIST_FINGERPRINTING_PREF "privacy.resistFingerprinting"
 #define RFP_TIMER_PREF "privacy.reduceTimerPrecision"
 #define RFP_TIMER_VALUE_PREF "privacy.resistFingerprinting.reduceTimerPrecision.microseconds"
 #define RFP_TIMER_VALUE_DEFAULT 20
 #define RFP_SPOOFED_FRAMES_PER_SEC_PREF "privacy.resistFingerprinting.video_frames_per_sec"
 #define RFP_SPOOFED_DROPPED_RATIO_PREF  "privacy.resistFingerprinting.video_dropped_ratio"
 #define RFP_TARGET_VIDEO_RES_PREF "privacy.resistFingerprinting.target_video_res"
 #define RFP_SPOOFED_FRAMES_PER_SEC_DEFAULT 30
@@ -95,27 +100,40 @@ nsRFPService::IsTimerPrecisionReductionE
 /* static */
 double
 nsRFPService::ReduceTimePrecisionAsMSecs(double aTime)
 {
   if (!IsTimerPrecisionReductionEnabled()) {
     return aTime;
   }
   const double resolutionMSec = sResolutionUSec / 1000.0;
-  return floor(aTime / resolutionMSec) * resolutionMSec;
+  double ret = floor(aTime / resolutionMSec) * resolutionMSec;
+#if defined(DEBUG)
+  MOZ_LOG(gResistFingerprintingLog, LogLevel::Verbose,
+    ("Given: %.*f, Rounding with %.*f, Intermediate: %.*f, Got: %.*f",
+      DBL_DIG-1, aTime, DBL_DIG-1, resolutionMSec, DBL_DIG-1, floor(aTime / resolutionMSec), DBL_DIG-1, ret));
+#endif
+  return ret;
 }
 
 /* static */
 double
 nsRFPService::ReduceTimePrecisionAsUSecs(double aTime)
 {
   if (!IsTimerPrecisionReductionEnabled()) {
     return aTime;
   }
-  return floor(aTime / sResolutionUSec) * sResolutionUSec;
+  double ret = floor(aTime / sResolutionUSec) * sResolutionUSec;
+#if defined(DEBUG)
+  double tmp_sResolutionUSec = sResolutionUSec;
+  MOZ_LOG(gResistFingerprintingLog, LogLevel::Verbose,
+    ("Given: %.*f, Rounding with %.*f, Intermediate: %.*f, Got: %.*f",
+      DBL_DIG-1, aTime, DBL_DIG-1, tmp_sResolutionUSec, DBL_DIG-1, floor(aTime / tmp_sResolutionUSec), DBL_DIG-1, ret));
+#endif
+  return ret;
 }
 
 /* static */
 uint32_t
 nsRFPService::CalculateTargetVideoResolution(uint32_t aVideoQuality)
 {
   return aVideoQuality * NSToIntCeil(aVideoQuality * 16 / 9.0);
 }
@@ -126,20 +144,32 @@ nsRFPService::ReduceTimePrecisionAsSecs(
 {
   if (!IsTimerPrecisionReductionEnabled()) {
     return aTime;
   }
   if (sResolutionUSec < 1000000) {
     // The resolution is smaller than one sec.  Use the reciprocal to avoid
     // floating point error.
     const double resolutionSecReciprocal = 1000000.0 / sResolutionUSec;
-    return floor(aTime * resolutionSecReciprocal) / resolutionSecReciprocal;
+    double ret = floor(aTime * resolutionSecReciprocal) / resolutionSecReciprocal;
+#if defined(DEBUG)
+  MOZ_LOG(gResistFingerprintingLog, LogLevel::Verbose,
+    ("Given: %.*f, Reciprocal Rounding with %.*f, Intermediate: %.*f, Got: %.*f",
+      DBL_DIG-1, aTime, DBL_DIG-1, resolutionSecReciprocal, DBL_DIG-1, floor(aTime * resolutionSecReciprocal), DBL_DIG-1, ret));
+#endif
+    return ret;
   }
   const double resolutionSec = sResolutionUSec / 1000000.0;
-  return floor(aTime / resolutionSec) * resolutionSec;
+  double ret = floor(aTime / resolutionSec) * resolutionSec;
+#if defined(DEBUG)
+  MOZ_LOG(gResistFingerprintingLog, LogLevel::Verbose,
+    ("Given: %.*f, Rounding with %.*f, Intermediate: %.*f, Got: %.*f",
+      DBL_DIG-1, aTime, DBL_DIG-1, resolutionSec, DBL_DIG-1, floor(aTime / resolutionSec), DBL_DIG-1, ret));
+#endif
+  return ret;
 }
 
 /* static */
 uint32_t
 nsRFPService::GetSpoofedTotalFrames(double aTime)
 {
   double time = ReduceTimePrecisionAsSecs(aTime);