Bug 920123 - Make Start/Stop FrameTimeRecording work with OMTC and remove paint time recording. r=mattwoodrow

This commit is contained in:
Markus Stange 2013-11-27 08:32:19 +01:00
parent c10f43e900
commit 30aeb02de9
16 changed files with 103 additions and 99 deletions

View File

@ -4088,41 +4088,30 @@
return;
}
let paints = {};
let intervals = window.QueryInterface(Ci.nsIInterfaceRequestor)
.getInterface(Ci.nsIDOMWindowUtils)
.stopFrameTimeRecording(aTab._recordingHandle, paints);
.stopFrameTimeRecording(aTab._recordingHandle);
delete aTab._recordingHandle;
paints = paints.value; // The result array itself.
let frameCount = intervals.length;
if (this._tabAnimationLoggingEnabled) {
let msg = "Tab " + (aTab.closing ? "close" : "open") + " (Frame-interval / paint-processing):\n";
let msg = "Tab " + (aTab.closing ? "close" : "open") + " (Frame-interval):\n";
for (let i = 0; i < frameCount; i++) {
msg += Math.round(intervals[i]) + " / " + Math.round(paints[i]) + "\n";
msg += Math.round(intervals[i]) + "\n";
}
Services.console.logStringMessage(msg);
}
// For telemetry, the first frame interval is not useful since it may represent an interval
// to a relatively old frame (prior to recording start). So we'll ignore it for the average.
// But if we recorded only 1 frame (very rare), then the first paint duration is a good
// representative of the first frame interval for our cause (indicates very bad animation).
// First paint duration is always useful for us.
if (frameCount > 0) {
if (frameCount > 1) {
let averageInterval = 0;
let averagePaint = paints[0];
for (let i = 1; i < frameCount; i++) {
averageInterval += intervals[i];
averagePaint += paints[i];
};
averagePaint /= frameCount;
averageInterval = (frameCount == 1)
? averagePaint
: averageInterval / (frameCount - 1);
averageInterval = averageInterval / (frameCount - 1);
Services.telemetry.getHistogramById("FX_TAB_ANIM_ANY_FRAME_INTERVAL_MS").add(averageInterval);
Services.telemetry.getHistogramById("FX_TAB_ANIM_ANY_FRAME_PAINT_MS").add(averagePaint);
if (aTab._recordingTabOpenPlain) {
delete aTab._recordingTabOpenPlain;
@ -4130,7 +4119,6 @@
// easier to overview the data without slicing by it. Hence the additional histograms with _PREVIEW.
let preview = this._browserNewtabpageEnabled ? "_PREVIEW" : "";
Services.telemetry.getHistogramById("FX_TAB_ANIM_OPEN" + preview + "_FRAME_INTERVAL_MS").add(averageInterval);
Services.telemetry.getHistogramById("FX_TAB_ANIM_OPEN" + preview + "_FRAME_PAINT_MS").add(averagePaint);
}
}
]]>

View File

@ -83,6 +83,7 @@
#include "nsIDocShellTreeOwner.h"
#include "nsIInterfaceRequestorUtils.h"
#include "GeckoProfiler.h"
#include "mozilla/Preferences.h"
#ifdef XP_WIN
#undef GetClassName
@ -2242,14 +2243,18 @@ nsDOMWindowUtils::StartFrameTimeRecording(uint32_t *startIndex)
if (!mgr)
return NS_ERROR_FAILURE;
*startIndex = mgr->StartFrameTimeRecording();
const uint32_t kRecordingMinSize = 60 * 10; // 10 seconds @60 fps.
const uint32_t kRecordingMaxSize = 60 * 60 * 60; // One hour
uint32_t bufferSize = Preferences::GetUint("toolkit.framesRecording.bufferSize", uint32_t(0));
bufferSize = std::min(bufferSize, kRecordingMaxSize);
bufferSize = std::max(bufferSize, kRecordingMinSize);
*startIndex = mgr->StartFrameTimeRecording(bufferSize);
return NS_OK;
}
NS_IMETHODIMP
nsDOMWindowUtils::StopFrameTimeRecording(uint32_t startIndex,
float **paintTimes,
uint32_t *frameCount,
float **frameIntervals)
{
@ -2259,7 +2264,6 @@ nsDOMWindowUtils::StopFrameTimeRecording(uint32_t startIndex,
NS_ENSURE_ARG_POINTER(frameCount);
NS_ENSURE_ARG_POINTER(frameIntervals);
NS_ENSURE_ARG_POINTER(paintTimes);
nsCOMPtr<nsIWidget> widget = GetWidget();
if (!widget)
@ -2270,22 +2274,14 @@ nsDOMWindowUtils::StopFrameTimeRecording(uint32_t startIndex,
return NS_ERROR_FAILURE;
nsTArray<float> tmpFrameIntervals;
nsTArray<float> tmpPaintTimes;
mgr->StopFrameTimeRecording(startIndex, tmpFrameIntervals, tmpPaintTimes);
mgr->StopFrameTimeRecording(startIndex, tmpFrameIntervals);
*frameCount = tmpFrameIntervals.Length();
*frameIntervals = (float*)nsMemory::Alloc(*frameCount * sizeof(float*));
*paintTimes = (float*)nsMemory::Alloc(*frameCount * sizeof(float*));
/* copy over the frame intervals and paint times into the arrays we just allocated */
for (uint32_t i = 0; i < *frameCount; i++) {
(*frameIntervals)[i] = tmpFrameIntervals[i];
#ifndef MOZ_WIDGET_GONK
(*paintTimes)[i] = tmpPaintTimes[i];
#else
// Waiting for bug 830475 to work on B2G.
(*paintTimes)[i] = 0;
#endif
}
return NS_OK;

View File

@ -43,7 +43,7 @@ interface nsIDOMEventTarget;
interface nsIRunnable;
interface nsICompositionStringSynthesizer;
[scriptable, uuid(928356ff-26b2-434e-a7ce-c1a660162d81)]
[scriptable, uuid(e12df416-e3e0-4177-b936-fa106f62ae3f)]
interface nsIDOMWindowUtils : nsISupports {
/**
@ -1044,7 +1044,7 @@ interface nsIDOMWindowUtils : nsISupports {
readonly attribute boolean layerManagerRemote;
/**
* Record (and return) frame-intervals and paint-times for frames which were presented
* Record (and return) frame-intervals for frames which were presented
* between calling StartFrameTimeRecording and StopFrameTimeRecording.
*
* - Uses a cyclic buffer and serves concurrent consumers, so if Stop is called too late
@ -1066,7 +1066,6 @@ interface nsIDOMWindowUtils : nsISupports {
* - Allocation is infallible. Should be released even if size is 0.
*/
void stopFrameTimeRecording(in unsigned long startIndex,
[optional, array, size_is(frameCount)] out float paintTimes,
[optional] out unsigned long frameCount,
[retval, array, size_is(frameCount)] out float frameIntervals);

View File

@ -17,7 +17,6 @@
#include "gfxPlatform.h" // for gfxPlatform
#include "gfxUtils.h" // for gfxUtils, etc
#include "mozilla/DebugOnly.h" // for DebugOnly
#include "mozilla/Preferences.h" // for Preferences
#include "mozilla/Telemetry.h" // for Accumulate
#include "mozilla/TelemetryHistogramEnums.h"
#include "mozilla/gfx/2D.h" // for DrawTarget
@ -997,16 +996,14 @@ RefLayer::FillSpecificAttributes(SpecificLayerAttributes& aAttrs)
/**
* StartFrameTimeRecording, together with StopFrameTimeRecording
* enable recording of frame intrvals and paint times.
* (Paint start time is set from the refresh driver right before starting
* flush/paint and ends at PostPresent. Intervals are measured at PostPresent).
* enable recording of frame intervals.
*
* To allow concurrent consumers, 2 cyclic arrays are used (for intervals, paints)
* which serve all consumers, practically stateless with regard to consumers.
* To allow concurrent consumers, a cyclic array is used which serves all
* consumers, practically stateless with regard to consumers.
*
* To save resources, the buffers are allocated on first call to StartFrameTimeRecording
* To save resources, the buffer is allocated on first call to StartFrameTimeRecording
* and recording is paused if no consumer which called StartFrameTimeRecording is able
* to get valid results (because the cyclic buffers were overwritten since that call).
* to get valid results (because the cyclic buffer was overwritten since that call).
*
* To determine availability of the data upon StopFrameTimeRecording:
* - mRecording.mNextIndex increases on each PostPresent, and never resets.
@ -1024,29 +1021,20 @@ RefLayer::FillSpecificAttributes(SpecificLayerAttributes& aAttrs)
* older than this, it means that some frames were not recorded, so data is invalid.
*/
uint32_t
LayerManager::StartFrameTimeRecording()
LayerManager::StartFrameTimeRecording(int32_t aBufferSize)
{
if (mRecording.mIsPaused) {
mRecording.mIsPaused = false;
if (!mRecording.mIntervals.Length()) { // Initialize recording buffers
const uint32_t kRecordingMinSize = 60 * 10; // 10 seconds @60 fps.
const uint32_t kRecordingMaxSize = 60 * 60 * 60; // One hour
uint32_t bufferSize = Preferences::GetUint("toolkit.framesRecording.bufferSize",
kRecordingMinSize);
bufferSize = std::min(bufferSize, kRecordingMaxSize);
bufferSize = std::max(bufferSize, kRecordingMinSize);
if (!mRecording.mIntervals.SetLength(bufferSize) || !mRecording.mPaints.SetLength(bufferSize)) {
if (!mRecording.mIntervals.SetLength(aBufferSize)) {
mRecording.mIsPaused = true; // OOM
mRecording.mIntervals.Clear();
mRecording.mPaints.Clear();
}
}
// After being paused, recent values got invalid. Update them to now.
mRecording.mLastFrameTime = TimeStamp::Now();
mRecording.mPaintStartTime = mRecording.mLastFrameTime;
// Any recording which started before this is invalid, since we were paused.
mRecording.mCurrentRunStartIndex = mRecording.mNextIndex;
@ -1059,23 +1047,13 @@ LayerManager::StartFrameTimeRecording()
}
void
LayerManager::SetPaintStartTime(TimeStamp& aTime)
{
if (!mRecording.mIsPaused) {
mRecording.mPaintStartTime = aTime;
}
}
void
LayerManager::PostPresent()
LayerManager::RecordFrame()
{
if (!mRecording.mIsPaused) {
TimeStamp now = TimeStamp::Now();
uint32_t i = mRecording.mNextIndex % mRecording.mIntervals.Length();
mRecording.mIntervals[i] = static_cast<float>((now - mRecording.mLastFrameTime)
.ToMilliseconds());
mRecording.mPaints[i] = static_cast<float>((now - mRecording.mPaintStartTime)
.ToMilliseconds());
mRecording.mNextIndex++;
mRecording.mLastFrameTime = now;
@ -1084,6 +1062,11 @@ LayerManager::PostPresent()
mRecording.mIsPaused = true;
}
}
}
void
LayerManager::PostPresent()
{
if (!mTabSwitchStart.IsNull()) {
Telemetry::Accumulate(Telemetry::FX_TAB_SWITCH_TOTAL_MS,
uint32_t((TimeStamp::Now() - mTabSwitchStart).ToMilliseconds()));
@ -1093,8 +1076,7 @@ LayerManager::PostPresent()
void
LayerManager::StopFrameTimeRecording(uint32_t aStartIndex,
nsTArray<float>& aFrameIntervals,
nsTArray<float>& aPaintTimes)
nsTArray<float>& aFrameIntervals)
{
uint32_t bufferSize = mRecording.mIntervals.Length();
uint32_t length = mRecording.mNextIndex - aStartIndex;
@ -1105,9 +1087,8 @@ LayerManager::StopFrameTimeRecording(uint32_t aStartIndex,
}
// Set length in advance to avoid possibly repeated reallocations (and OOM checks).
if (!length || !aFrameIntervals.SetLength(length) || !aPaintTimes.SetLength(length)) {
if (!length || !aFrameIntervals.SetLength(length)) {
aFrameIntervals.Clear();
aPaintTimes.Clear();
return; // empty recording or OOM, return empty arrays.
}
@ -1117,7 +1098,6 @@ LayerManager::StopFrameTimeRecording(uint32_t aStartIndex,
cyclicPos = 0;
}
aFrameIntervals[i] = mRecording.mIntervals[cyclicPos];
aPaintTimes[i] = mRecording.mPaints[cyclicPos];
}
}

View File

@ -544,18 +544,17 @@ public:
/**
* Returns a handle which represents current recording start position.
*/
uint32_t StartFrameTimeRecording();
virtual uint32_t StartFrameTimeRecording(int32_t aBufferSize);
/**
* Clears, then populates 2 arraye with the recorded frames timing data.
* The arrays will be empty if data was overwritten since aStartIndex was obtained.
* Clears, then populates aFrameIntervals with the recorded frame timing
* data. The array will be empty if data was overwritten since
* aStartIndex was obtained.
*/
void StopFrameTimeRecording(uint32_t aStartIndex,
nsTArray<float>& aFrameIntervals,
nsTArray<float>& aPaintTimes);
void SetPaintStartTime(TimeStamp& aTime);
virtual void StopFrameTimeRecording(uint32_t aStartIndex,
nsTArray<float>& aFrameIntervals);
void RecordFrame();
void PostPresent();
void BeginTabSwitch();
@ -600,9 +599,7 @@ private:
bool mIsPaused;
uint32_t mNextIndex;
TimeStamp mLastFrameTime;
TimeStamp mPaintStartTime;
nsTArray<float> mIntervals;
nsTArray<float> mPaints;
uint32_t mLatestStartIndex;
uint32_t mCurrentRunStartIndex;
};

View File

@ -629,7 +629,8 @@ BasicLayerManager::EndTransactionInternal(DrawThebesLayerCallback aCallback,
FlashWidgetUpdateArea(mTarget);
}
RenderDebugOverlay();
LayerManager::PostPresent();
RecordFrame();
PostPresent();
if (!mTransactionIncomplete) {
// Clear out target if we have a complete transaction.

View File

@ -304,6 +304,28 @@ ClientLayerManager::SendInvalidRegion(const nsIntRegion& aRegion)
}
}
uint32_t
ClientLayerManager::StartFrameTimeRecording(int32_t aBufferSize)
{
CompositorChild* renderer = GetRemoteRenderer();
if (renderer) {
uint32_t startIndex;
renderer->SendStartFrameTimeRecording(aBufferSize, &startIndex);
return startIndex;
}
return -1;
}
void
ClientLayerManager::StopFrameTimeRecording(uint32_t aStartIndex,
nsTArray<float>& aFrameIntervals)
{
CompositorChild* renderer = GetRemoteRenderer();
if (renderer) {
renderer->SendStopFrameTimeRecording(aStartIndex, &aFrameIntervals);
}
}
void
ClientLayerManager::ForwardTransaction()
{

View File

@ -81,6 +81,11 @@ public:
virtual void FlushRendering() MOZ_OVERRIDE;
void SendInvalidRegion(const nsIntRegion& aRegion);
virtual uint32_t StartFrameTimeRecording(int32_t aBufferSize) MOZ_OVERRIDE;
virtual void StopFrameTimeRecording(uint32_t aStartIndex,
nsTArray<float>& aFrameIntervals) MOZ_OVERRIDE;
virtual bool NeedsWidgetInvalidation() MOZ_OVERRIDE { return false; }
ShadowableLayer* Hold(Layer* aLayer);

View File

@ -418,6 +418,8 @@ LayerManagerComposite::Render()
}
mCompositor->GetWidget()->PostRender(this);
RecordFrame();
}
void

View File

@ -733,7 +733,8 @@ LayerManagerD3D10::Render(EndTransactionFlags aFlags)
mSwapChain->Present(0, mDisableSequenceForNextFrame ? DXGI_PRESENT_DO_NOT_SEQUENCE : 0);
mDisableSequenceForNextFrame = false;
}
LayerManager::PostPresent();
RecordFrame();
PostPresent();
}
void

View File

@ -277,7 +277,8 @@ LayerManagerD3D9::Render()
(r = iter.Next()) != nullptr;) {
mSwapChain->Present(*r);
}
LayerManager::PostPresent();
RecordFrame();
PostPresent();
} else {
PaintToTarget();
}

View File

@ -331,6 +331,27 @@ CompositorParent::RecvNotifyRegionInvalidated(const nsIntRegion& aRegion)
return true;
}
bool
CompositorParent::RecvStartFrameTimeRecording(const int32_t& aBufferSize, uint32_t* aOutStartIndex)
{
if (mLayerManager) {
*aOutStartIndex = mLayerManager->StartFrameTimeRecording(aBufferSize);
} else {
*aOutStartIndex = 0;
}
return true;
}
bool
CompositorParent::RecvStopFrameTimeRecording(const uint32_t& aStartIndex,
InfallibleTArray<float>* intervals)
{
if (mLayerManager) {
mLayerManager->StopFrameTimeRecording(aStartIndex, *intervals);
}
return true;
}
void
CompositorParent::ActorDestroy(ActorDestroyReason why)
{
@ -906,6 +927,8 @@ public:
{ return true; }
virtual bool RecvFlushRendering() MOZ_OVERRIDE { return true; }
virtual bool RecvNotifyRegionInvalidated(const nsIntRegion& aRegion) { return true; }
virtual bool RecvStartFrameTimeRecording(const int32_t& aBufferSize, uint32_t* aOutStartIndex) MOZ_OVERRIDE { return true; }
virtual bool RecvStopFrameTimeRecording(const uint32_t& aStartIndex, InfallibleTArray<float>* intervals) MOZ_OVERRIDE { return true; }
virtual PLayerTransactionParent*
AllocPLayerTransactionParent(const nsTArray<LayersBackend>& aBackendHints,

View File

@ -89,6 +89,8 @@ public:
virtual bool RecvFlushRendering() MOZ_OVERRIDE;
virtual bool RecvNotifyRegionInvalidated(const nsIntRegion& aRegion) MOZ_OVERRIDE;
virtual bool RecvStartFrameTimeRecording(const int32_t& aBufferSize, uint32_t* aOutStartIndex) MOZ_OVERRIDE;
virtual bool RecvStopFrameTimeRecording(const uint32_t& aStartIndex, InfallibleTArray<float>* intervals) MOZ_OVERRIDE;
virtual void ActorDestroy(ActorDestroyReason why) MOZ_OVERRIDE;

View File

@ -64,6 +64,12 @@ parent:
// block until they are completed.
sync FlushRendering();
sync StartFrameTimeRecording(int32_t bufferSize)
returns (uint32_t startIndex);
sync StopFrameTimeRecording(uint32_t startIndex)
returns (float[] intervals);
// layersBackendHints is an ordered list of preffered backends where
// layersBackendHints[0] is the best backend. If any hints are LAYERS_NONE
// that hint is ignored.

View File

@ -1202,13 +1202,6 @@ nsRefreshDriver::Tick(int64_t aNowEpoch, TimeStamp aNowTime)
printf_stderr("Starting ProcessPendingUpdates\n");
}
#endif
#ifndef MOZ_WIDGET_GONK
// Waiting for bug 830475 to work on B2G.
nsRefPtr<layers::LayerManager> mgr = mPresContext->GetPresShell()->GetLayerManager();
if (mgr) {
mgr->SetPaintStartTime(mMostRecentRefresh);
}
#endif
mViewManagerFlushIsPending = false;
nsRefPtr<nsViewManager> vm = mPresContext->GetPresShell()->GetViewManager();

View File

@ -2677,12 +2677,6 @@
"n_buckets": 50,
"description": "Average frame interval during tab open animation of about:newtab (preview=on), when other tabs are unaffected"
},
"FX_TAB_ANIM_OPEN_PREVIEW_FRAME_PAINT_MS": {
"kind": "exponential",
"high": "500",
"n_buckets": 30,
"description": "Average paint duration during tab open animation of about:newtab (preview=on), when other tabs are unaffected"
},
"FX_TAB_ANIM_OPEN_FRAME_INTERVAL_MS": {
"kind": "exponential",
"low" : 7,
@ -2690,12 +2684,6 @@
"n_buckets": 50,
"description": "Average frame interval during tab open animation of about:newtab (preview=off), when other tabs are unaffected"
},
"FX_TAB_ANIM_OPEN_FRAME_PAINT_MS": {
"kind": "exponential",
"high": "500",
"n_buckets": 30,
"description": "Average paint duration during tab open animation of about:newtab (preview=off), when other tabs are unaffected"
},
"FX_TAB_ANIM_ANY_FRAME_INTERVAL_MS": {
"kind": "exponential",
"low" : 7,