Bug 1221674 - Add telemetry probe in the content process to measure t…

…he time between refresh driver ticks. r=kats

gfx/thebes/SoftwareVsyncSource.cpp

@@ -112,6 +112,12 @@ SoftwareDisplay::NotifyVsync(mozilla::TimeStamp aVsyncTimestamp)
   ScheduleNextVsync(aVsyncTimestamp);
 }
 
+mozilla::TimeDuration
+SoftwareDisplay::GetVsyncRate()
+{
+  return mVsyncRate;
+}
+
 void
 SoftwareDisplay::ScheduleNextVsync(mozilla::TimeStamp aVsyncTimestamp)
 {

gfx/thebes/SoftwareVsyncSource.h

@@ -27,6 +27,7 @@ class SoftwareDisplay final : public mozilla::gfx::VsyncSource::Display
   virtual bool IsVsyncEnabled() override;
   bool IsInSoftwareVsyncThread();
   virtual void NotifyVsync(mozilla::TimeStamp aVsyncTimestamp) override;
+  virtual mozilla::TimeDuration GetVsyncRate() override;
   void ScheduleNextVsync(mozilla::TimeStamp aVsyncTimestamp);
   void Shutdown();
 

gfx/thebes/VsyncSource.cpp

@@ -68,6 +68,13 @@ VsyncSource::Display::NotifyVsync(TimeStamp aVsyncTimestamp)
   mRefreshTimerVsyncDispatcher->NotifyVsync(aVsyncTimestamp);
 }
 
+TimeDuration
+VsyncSource::Display::GetVsyncRate()
+{
+  // If hardware queries fail / are unsupported, we have to just guess.
+  return TimeDuration::FromMilliseconds(1000.0 / 60.0);
+}
+
 void
 VsyncSource::Display::AddCompositorVsyncDispatcher(CompositorVsyncDispatcher* aCompositorVsyncDispatcher)
 {

gfx/thebes/VsyncSource.h

@@ -39,7 +39,7 @@ class VsyncSource
       // However, different platforms give different vsync notification times.
       // b2g - The vsync timestamp of the previous frame that was just displayed
       // OSX - The vsync timestamp of the upcoming frame, in the future
-      // TODO: Windows / Linux. DOCUMENT THIS WHEN IMPLEMENTING ON THOSE PLATFORMS
+      // Windows: It's messy, see gfxWindowsPlatform.
       // Android: TODO
       // All platforms should normalize to the vsync that just occured.
       // Large parts of Gecko assume TimeStamps should not be in the future such as animations
@@ -50,6 +50,7 @@ class VsyncSource
       void AddCompositorVsyncDispatcher(CompositorVsyncDispatcher* aCompositorVsyncDispatcher);
       void RemoveCompositorVsyncDispatcher(CompositorVsyncDispatcher* aCompositorVsyncDispatcher);
       void NotifyRefreshTimerVsyncStatus(bool aEnable);
+      virtual TimeDuration GetVsyncRate();
 
       // These should all only be called on the main thread
       virtual void EnableVsync() = 0;

gfx/thebes/gfxPlatformMac.cpp

@@ -542,6 +542,18 @@ class OSXVsyncSource final : public VsyncSource
         CVDisplayLinkRelease(mDisplayLink);
         mDisplayLink = nullptr;
       }
+
+      CVTime vsyncRate = CVDisplayLinkGetNominalOutputVideoRefreshPeriod(mDisplayLink);
+      if (vsyncRate.flags & kCVTimeIsIndefinite) {
+        NS_WARNING("Could not get vsync rate, setting to 60.");
+        mVsyncRate = TimeDuration::FromMilliseconds(1000.0 / 60.0);
+      } else {
+        int64_t timeValue = vsyncRate.timeValue;
+        int64_t timeScale = vsyncRate.timeScale;
+        const int milliseconds = 1000;
+        float rateInMs = ((double) timeValue / (double) timeScale) * milliseconds;
+        mVsyncRate = TimeDuration::FromMilliseconds(rateInMs);
+      }
     }
 
     virtual void DisableVsync() override
@@ -564,6 +576,11 @@ class OSXVsyncSource final : public VsyncSource
       return mDisplayLink != nullptr;
     }
 
+    virtual TimeDuration GetVsyncRate() override
+    {
+      return mVsyncRate;
+    }
+
     // The vsync timestamps given by the CVDisplayLinkCallback are
     // in the future for the NEXT frame. Large parts of Gecko, such
     // as animations assume a timestamp at either now or in the past.
@@ -575,6 +592,7 @@ class OSXVsyncSource final : public VsyncSource
     // Manages the display link render thread
     CVDisplayLinkRef   mDisplayLink;
     RefPtr<nsITimer> mTimer;
+    TimeDuration mVsyncRate;
   }; // OSXDisplay
 
 private:

gfx/thebes/gfxWindowsPlatform.cpp

@@ -2664,6 +2664,29 @@ class D3DVsyncSource final : public VsyncSource
         const double rate = 1000 / 60.0;
         mSoftwareVsyncRate = TimeDuration::FromMilliseconds(rate);
         MOZ_RELEASE_ASSERT(mVsyncThread->Start(), "Could not start Windows vsync thread");
+        SetVsyncRate();
+      }
+
+      void SetVsyncRate()
+      {
+        if (!DwmCompositionEnabled()) {
+          mVsyncRate = TimeDuration::FromMilliseconds(1000.0 / 60.0);
+          return;
+        }
+
+        DWM_TIMING_INFO vblankTime;
+        // Make sure to init the cbSize, otherwise GetCompositionTiming will fail
+        vblankTime.cbSize = sizeof(DWM_TIMING_INFO);
+        HRESULT hr = WinUtils::dwmGetCompositionTimingInfoPtr(0, &vblankTime);
+        if (SUCCEEDED(hr)) {
+          UNSIGNED_RATIO refreshRate = vblankTime.rateRefresh;
+          // We get the rate in hertz / time, but we want the rate in ms.
+          float rate = ((float) refreshRate.uiDenominator
+                       / (float) refreshRate.uiNumerator) * 1000;
+          mVsyncRate = TimeDuration::FromMilliseconds(rate);
+        } else {
+          mVsyncRate = TimeDuration::FromMilliseconds(1000.0 / 60.0);
+        }
       }
 
       virtual void EnableVsync() override
@@ -2701,6 +2724,11 @@ class D3DVsyncSource final : public VsyncSource
         return mVsyncEnabled;
       }
 
+      virtual TimeDuration GetVsyncRate() override
+      {
+        return mVsyncRate;
+      }
+
       void ScheduleSoftwareVsync(TimeStamp aVsyncTimestamp)
       {
         MOZ_ASSERT(IsInVsyncThread());
@@ -2826,6 +2854,7 @@ class D3DVsyncSource final : public VsyncSource
       TimeStamp mPrevVsync; // Only used on Windows 10
       Monitor mVsyncEnabledLock;
       base::Thread* mVsyncThread;
+      TimeDuration mVsyncRate;
       bool mVsyncEnabled;
   }; // end d3dvsyncdisplay
 

layout/base/nsRefreshDriver.cpp

@@ -313,6 +313,9 @@ class VsyncRefreshDriverTimer : public RefreshDriverTimer
     explicit RefreshDriverVsyncObserver(VsyncRefreshDriverTimer* aVsyncRefreshDriverTimer)
       : mVsyncRefreshDriverTimer(aVsyncRefreshDriverTimer)
       , mRefreshTickLock("RefreshTickLock")
+      , mRecentVsync(TimeStamp::Now())
+      , mLastChildTick(TimeStamp::Now())
+      , mVsyncRate(TimeDuration::Forever())
       , mProcessedVsync(true)
     {
       MOZ_ASSERT(NS_IsMainThread());
@@ -352,22 +355,47 @@ class VsyncRefreshDriverTimer : public RefreshDriverTimer
       mVsyncRefreshDriverTimer = nullptr;
     }
 
+    void OnTimerStart()
+    {
+      if (!XRE_IsParentProcess()) {
+        mLastChildTick = TimeStamp::Now();
+      }
+    }
+
   private:
     virtual ~RefreshDriverVsyncObserver() {}
 
+    void RecordTelemetryProbes(TimeStamp aVsyncTimestamp)
+    {
+      MOZ_ASSERT(NS_IsMainThread());
+    #ifndef ANDROID  /* bug 1142079 */
+      if (XRE_IsParentProcess()) {
+        TimeDuration vsyncLatency = TimeStamp::Now() - aVsyncTimestamp;
+        Telemetry::Accumulate(Telemetry::FX_REFRESH_DRIVER_CHROME_FRAME_DELAY_MS,
+                              vsyncLatency.ToMilliseconds());
+      } else if (mVsyncRate != TimeDuration::Forever()) {
+        TimeDuration contentDelay = (TimeStamp::Now() - mLastChildTick) - mVsyncRate;
+        Telemetry::Accumulate(Telemetry::FX_REFRESH_DRIVER_CONTENT_FRAME_DELAY_MS,
+                              contentDelay.ToMilliseconds());
+      } else {
+        // Request the vsync rate from the parent process. Might be a few vsyncs
+        // until the parent responds.
+        mVsyncRate = mVsyncRefreshDriverTimer->mVsyncChild->GetVsyncRate();
+      }
+    #endif
+    }
+
     void TickRefreshDriver(TimeStamp aVsyncTimestamp)
     {
       MOZ_ASSERT(NS_IsMainThread());
 
+      RecordTelemetryProbes(aVsyncTimestamp);
       if (XRE_IsParentProcess()) {
         MonitorAutoLock lock(mRefreshTickLock);
-        #ifndef ANDROID  /* bug 1142079 */
-          TimeDuration vsyncLatency = TimeStamp::Now() - aVsyncTimestamp;
-          Telemetry::Accumulate(Telemetry::FX_REFRESH_DRIVER_CHROME_FRAME_DELAY_MS,
-                                vsyncLatency.ToMilliseconds());
-        #endif
         aVsyncTimestamp = mRecentVsync;
         mProcessedVsync = true;
+      } else {
+        mLastChildTick = TimeStamp::Now();
       }
       MOZ_ASSERT(aVsyncTimestamp <= TimeStamp::Now());
 
@@ -385,6 +413,8 @@ class VsyncRefreshDriverTimer : public RefreshDriverTimer
     VsyncRefreshDriverTimer* mVsyncRefreshDriverTimer;
     Monitor mRefreshTickLock;
     TimeStamp mRecentVsync;
+    TimeStamp mLastChildTick;
+    TimeDuration mVsyncRate;
     bool mProcessedVsync;
   }; // RefreshDriverVsyncObserver
 
@@ -418,6 +448,7 @@ class VsyncRefreshDriverTimer : public RefreshDriverTimer
       mVsyncDispatcher->SetParentRefreshTimer(mVsyncObserver);
     } else {
       Unused << mVsyncChild->SendObserve();
+      mVsyncObserver->OnTimerStart();
     }
   }
 

layout/ipc/PVsync.ipdl

@@ -23,10 +23,14 @@ child:
   // Send vsync event from chrome to content process.
   async Notify(TimeStamp aVsyncTimestamp) compress;
 
+  // Send the vsync rate to the content process.
+  async VsyncRate(float aVsyncRate);
+
 parent:
   // Content process use these messages to acquire the vsync event.
   async Observe();
   async Unobserve();
+  async RequestVsyncRate();
 
   // This message is never sent. Each PVsync actor will stay alive as long as
   // its PBackground manager.

layout/ipc/VsyncChild.cpp

@@ -14,6 +14,7 @@ namespace layout {
 VsyncChild::VsyncChild()
   : mObservingVsync(false)
   , mIsShutdown(false)
+  , mVsyncRate(TimeDuration::Forever())
 {
   MOZ_ASSERT(NS_IsMainThread());
 }
@@ -72,5 +73,22 @@ VsyncChild::SetVsyncObserver(VsyncObserver* aVsyncObserver)
   mObserver = aVsyncObserver;
 }
 
+TimeDuration
+VsyncChild::GetVsyncRate()
+{
+  if (mVsyncRate == TimeDuration::Forever()) {
+    PVsyncChild::SendRequestVsyncRate();
+  }
+
+  return mVsyncRate;
+}
+
+bool
+VsyncChild::RecvVsyncRate(const float& aVsyncRate)
+{
+  mVsyncRate = TimeDuration::FromMilliseconds(aVsyncRate);
+  return true;
+}
+
 } // namespace layout
 } // namespace mozilla

layout/ipc/VsyncChild.h

@@ -38,19 +38,22 @@ class VsyncChild final : public PVsyncChild
 
   // Bind a VsyncObserver into VsyncChild after ipc channel connected.
   void SetVsyncObserver(VsyncObserver* aVsyncObserver);
+  TimeDuration GetVsyncRate();
 
 private:
   VsyncChild();
   virtual ~VsyncChild();
 
   virtual bool RecvNotify(const TimeStamp& aVsyncTimestamp) override;
+  virtual bool RecvVsyncRate(const float& aVsyncRate) override;
   virtual void ActorDestroy(ActorDestroyReason aActorDestroyReason) override;
 
   bool mObservingVsync;
   bool mIsShutdown;
 
   // The content side vsync observer.
   RefPtr<VsyncObserver> mObserver;
+  TimeDuration mVsyncRate;
 };
 
 } // namespace layout

layout/ipc/VsyncParent.cpp

@@ -72,6 +72,15 @@ VsyncParent::DispatchVsyncEvent(TimeStamp aTimeStamp)
   }
 }
 
+bool
+VsyncParent::RecvRequestVsyncRate()
+{
+  AssertIsOnBackgroundThread();
+  TimeDuration vsyncRate = gfxPlatform::GetPlatform()->GetHardwareVsync()->GetGlobalDisplay().GetVsyncRate();
+  Unused << SendVsyncRate(vsyncRate.ToMilliseconds());
+  return true;
+}
+
 bool
 VsyncParent::RecvObserve()
 {

layout/ipc/VsyncParent.h

@@ -36,6 +36,7 @@ class VsyncParent final : public PVsyncParent,
   virtual ~VsyncParent();
 
   virtual bool NotifyVsync(TimeStamp aTimeStamp) override;
+  virtual bool RecvRequestVsyncRate() override;
 
   virtual bool RecvObserve() override;
   virtual bool RecvUnobserve() override;

toolkit/components/telemetry/Histograms.json

@@ -4090,7 +4090,14 @@
     "kind": "exponential",
     "high": "10000",
     "n_buckets": 50,
-    "description": "Delay in ms between the target and the actual handling time of the frame at refresh driver in chrome process."
+    "description": "Delay in ms between the target and the actual handling time of the frame at refresh driver in the chrome process."
+  },
+  "FX_REFRESH_DRIVER_CONTENT_FRAME_DELAY_MS": {
+    "expires_in_version": "default",
+    "kind": "exponential",
+    "high": "10000",
+    "n_buckets": 50,
+    "description": "Delay in ms between the target and the actual handling time of the frame at refresh driver in the content process."
   },
   "FX_TAB_SWITCH_UPDATE_MS": {
     "alert_emails": ["perf-telemetry-alerts@mozilla.com"],