Bug 1429764 - Do not call ReduceTimerPrecision twice for DOM Navigation timers. r=bkelly, r=timhuang, a=jcristau
authorTom Ritter <tom@mozilla.com>
Fri, 12 Jan 2018 13:36:04 -0600
changeset 445688 ff6f39465890eabd327328f5c7d80fb1f9917649
parent 445687 86ba26a98381e474145f646b54ba2a84321a6233
child 445689 d304791fc530e1350e81b719c17f167f3ab0384b
push id1629
push userryanvm@gmail.com
push dateThu, 18 Jan 2018 14:27:59 +0000
treeherdermozilla-release@ff6f39465890 [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersbkelly, timhuang, jcristau
bugs1429764
milestone58.0
Bug 1429764 - Do not call ReduceTimerPrecision twice for DOM Navigation timers. r=bkelly, r=timhuang, a=jcristau 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);