From 35a21b944170ac4caad306d662ccec7941f746b2 Mon Sep 17 00:00:00 2001 From: Avi Halachmi Date: Thu, 3 Jan 2013 21:53:15 -0500 Subject: [PATCH] Bug 820167 - Tab open/close animation prints performance data to error console when enabled. r=jmuizelaar,dao --- browser/base/content/tabbrowser.xml | 28 +++++++++++++++++++ dom/base/nsDOMWindowUtils.cpp | 33 ++++++++++++++++------- dom/interfaces/base/nsIDOMWindowUtils.idl | 7 ++--- gfx/layers/Layers.cpp | 20 +++++++++++--- gfx/layers/Layers.h | 7 +++-- layout/base/nsRefreshDriver.cpp | 8 ++++++ 6 files changed, 84 insertions(+), 19 deletions(-) diff --git a/browser/base/content/tabbrowser.xml b/browser/base/content/tabbrowser.xml index 201df07ab2d..f1527d859ad 100644 --- a/browser/base/content/tabbrowser.xml +++ b/browser/base/content/tabbrowser.xml @@ -1274,6 +1274,11 @@ if (t.pinned) tabContainer._handleNewTab(t); else { + if (tabContainer._tabAnimationLoggingEnabled) { + window.QueryInterface(Ci.nsIInterfaceRequestor) + .getInterface(Ci.nsIDOMWindowUtils) + .startFrameTimeRecording(); + } t._animStartTime = Date.now(); t.setAttribute("fadein", "true"); @@ -1574,6 +1579,11 @@ return; } + if (this.tabContainer._tabAnimationLoggingEnabled) { + window.QueryInterface(Ci.nsIInterfaceRequestor) + .getInterface(Ci.nsIDOMWindowUtils) + .startFrameTimeRecording(); + } aTab._animStartTime = Date.now(); this._blurTab(aTab); @@ -2880,6 +2890,12 @@ Services.prefs.addObserver("browser.tabs.", this._prefObserver, false); window.addEventListener("resize", this, false); window.addEventListener("load", this, false); + + try { + this._tabAnimationLoggingEnabled = Services.prefs.getBoolPref("browser.tabs.animationLogging.enabled"); + } catch (ex) { + this._tabAnimationLoggingEnabled = false; + } ]]> @@ -3512,6 +3528,18 @@ "FX_TAB_ANIM_OPEN_MS") .add(Date.now() - tab._animStartTime); tab._animStartTime = 0; + + if (this._tabAnimationLoggingEnabled) { + let paints = {}; + let intervals = window.QueryInterface(Ci.nsIInterfaceRequestor) + .getInterface(Ci.nsIDOMWindowUtils) + .stopFrameTimeRecording(paints); + let msg = "Tab " + (tab.closing ? "close" : "open") + " (Frame-interval / paint-processing):\n"; + for (let i = 0; i < intervals.length; i++) { + msg += Math.round(intervals[i]) + " / " + Math.round(paints.value[i]) + "\n"; + } + Services.console.logStringMessage(msg); + } } if (tab.getAttribute("fadein") == "true") { diff --git a/dom/base/nsDOMWindowUtils.cpp b/dom/base/nsDOMWindowUtils.cpp index 8f787b220da..77a94372207 100644 --- a/dom/base/nsDOMWindowUtils.cpp +++ b/dom/base/nsDOMWindowUtils.cpp @@ -2156,14 +2156,15 @@ nsDOMWindowUtils::StartFrameTimeRecording() } NS_IMETHODIMP -nsDOMWindowUtils::StopFrameTimeRecording(uint32_t *frameCount, float **frames) +nsDOMWindowUtils::StopFrameTimeRecording(float** paintTimes, uint32_t *frameCount, float **frameIntervals) { if (!nsContentUtils::IsCallerChrome()) { return NS_ERROR_DOM_SECURITY_ERR; } NS_ENSURE_ARG_POINTER(frameCount); - NS_ENSURE_ARG_POINTER(frames); + NS_ENSURE_ARG_POINTER(frameIntervals); + NS_ENSURE_ARG_POINTER(paintTimes); nsCOMPtr widget = GetWidget(); if (!widget) @@ -2173,20 +2174,32 @@ nsDOMWindowUtils::StopFrameTimeRecording(uint32_t *frameCount, float **frames) if (!mgr) return NS_ERROR_FAILURE; - nsTArray frameTimes; - mgr->StopFrameTimeRecording(frameTimes); + nsTArray tmpFrameIntervals; + nsTArray tmpPaintTimes; + mgr->StopFrameTimeRecording(tmpFrameIntervals, tmpPaintTimes); - *frames = nullptr; - *frameCount = frameTimes.Length(); + *frameIntervals = nullptr; + *paintTimes = nullptr; + *frameCount = tmpFrameIntervals.Length(); if (*frameCount != 0) { - *frames = (float*)nsMemory::Alloc(*frameCount * sizeof(float*)); - if (!*frames) + *frameIntervals = (float*)nsMemory::Alloc(*frameCount * sizeof(float*)); + if (!*frameIntervals) return NS_ERROR_OUT_OF_MEMORY; - /* copy over the frame times into the array we just allocated */ + *paintTimes = (float*)nsMemory::Alloc(*frameCount * sizeof(float*)); + if (!*paintTimes) + return NS_ERROR_OUT_OF_MEMORY; + + /* copy over the frame intervals and paint times into the arrays we just allocated */ for (uint32_t i = 0; i < *frameCount; i++) { - (*frames)[i] = frameTimes[i]; + (*frameIntervals)[i] = tmpFrameIntervals[i]; +#ifndef ANDROID + (*paintTimes)[i] = tmpPaintTimes[i]; +#else + // Waiting for bug 785597 to work on android. + (*paintTimes)[i] = 0; +#endif } } diff --git a/dom/interfaces/base/nsIDOMWindowUtils.idl b/dom/interfaces/base/nsIDOMWindowUtils.idl index 2ea03cb3105..77045d8064a 100644 --- a/dom/interfaces/base/nsIDOMWindowUtils.idl +++ b/dom/interfaces/base/nsIDOMWindowUtils.idl @@ -40,7 +40,7 @@ interface nsIDOMTouch; interface nsIDOMClientRect; interface nsIURI; -[scriptable, uuid(2196a216-ed3c-46dd-aa24-9f5b3ac17539)] +[scriptable, uuid(c98249a5-d38a-4ec6-b6e0-6866ea87d6bb)] interface nsIDOMWindowUtils : nsISupports { /** @@ -1044,8 +1044,9 @@ interface nsIDOMWindowUtils : nsISupports { readonly attribute AString layerManagerType; void startFrameTimeRecording(); - void stopFrameTimeRecording([optional] out unsigned long frameCount, - [retval, array, size_is(frameCount)] out float frameTime); + void stopFrameTimeRecording([optional, array, size_is(frameCount)] out float paintTimes, + [optional] out unsigned long frameCount, + [retval, array, size_is(frameCount)] out float frameIntervals); /** * Signals that we're begining to tab switch. This is used by painting code to * determine total tab switch time. diff --git a/gfx/layers/Layers.cpp b/gfx/layers/Layers.cpp index 10e3e6ceede..968b0abc0c6 100644 --- a/gfx/layers/Layers.cpp +++ b/gfx/layers/Layers.cpp @@ -913,6 +913,15 @@ void LayerManager::StartFrameTimeRecording() { mLastFrameTime = TimeStamp::Now(); + mPaintStartTime = mLastFrameTime; +} + +void +LayerManager::SetPaintStartTime(TimeStamp& aTime) +{ + if (!mLastFrameTime.IsNull()) { + mPaintStartTime = aTime; + } } void @@ -920,7 +929,8 @@ LayerManager::PostPresent() { if (!mLastFrameTime.IsNull()) { TimeStamp now = TimeStamp::Now(); - mFrameTimes.AppendElement((now - mLastFrameTime).ToMilliseconds()); + mFrameIntervals.AppendElement((now - mLastFrameTime).ToMilliseconds()); + mPaintTimes.AppendElement((now - mPaintStartTime).ToMilliseconds()); mLastFrameTime = now; } if (!mTabSwitchStart.IsNull()) { @@ -931,11 +941,13 @@ LayerManager::PostPresent() } void -LayerManager::StopFrameTimeRecording(nsTArray& aTimes) +LayerManager::StopFrameTimeRecording(nsTArray& aFrameIntervals, nsTArray& aPaintTimes) { mLastFrameTime = TimeStamp(); - aTimes.SwapElements(mFrameTimes); - mFrameTimes.Clear(); + aFrameIntervals.SwapElements(mFrameIntervals); + aPaintTimes.SwapElements(mPaintTimes); + mFrameIntervals.Clear(); + mPaintTimes.Clear(); } void diff --git a/gfx/layers/Layers.h b/gfx/layers/Layers.h index 855f0b1500a..4f17ab1008d 100644 --- a/gfx/layers/Layers.h +++ b/gfx/layers/Layers.h @@ -484,7 +484,8 @@ public: void LogSelf(const char* aPrefix=""); void StartFrameTimeRecording(); - void StopFrameTimeRecording(nsTArray& aTimes); + void SetPaintStartTime(TimeStamp& aTime); + void StopFrameTimeRecording(nsTArray& aFrameTimes, nsTArray& aProcessingTimes); void PostPresent(); @@ -516,7 +517,9 @@ protected: bool mInTransaction; private: TimeStamp mLastFrameTime; - nsTArray mFrameTimes; + TimeStamp mPaintStartTime; + nsTArray mFrameIntervals; + nsTArray mPaintTimes; TimeStamp mTabSwitchStart; }; diff --git a/layout/base/nsRefreshDriver.cpp b/layout/base/nsRefreshDriver.cpp index e9c41f3d0fc..2b3993a3a75 100644 --- a/layout/base/nsRefreshDriver.cpp +++ b/layout/base/nsRefreshDriver.cpp @@ -942,6 +942,14 @@ nsRefreshDriver::Tick(int64_t aNowEpoch, TimeStamp aNowTime) #ifdef DEBUG_INVALIDATIONS printf("Starting ProcessPendingUpdates\n"); #endif +#ifndef ANDROID + // Waiting for bug 785597 to work on android. + nsRefPtr mgr = mPresContext->GetPresShell()->GetLayerManager(); + if (mgr) { + mgr->SetPaintStartTime(mMostRecentRefresh); + } +#endif + mViewManagerFlushIsPending = false; nsCOMPtr vm = mPresContext->GetPresShell()->GetViewManager(); vm->ProcessPendingUpdates();