Bug 1377619 - Add EndTransaction to on screen timing log for WebRender r=nical

This commit is contained in:
sotaro 2017-07-28 08:05:56 +09:00
parent 54d72f81ac
commit eaf00c953c
10 changed files with 107 additions and 21 deletions

View File

@ -1957,7 +1957,7 @@ CompositorBridgeParent::NotifyDidCompositeToPipeline(const wr::PipelineId& aPipe
}
if (mWrBridge->PipelineId() == aPipelineId) {
uint64_t transactionId = mWrBridge->FlushTransactionIdsForEpoch(aEpoch);
uint64_t transactionId = mWrBridge->FlushTransactionIdsForEpoch(aEpoch, aCompositeEnd);
Unused << SendDidComposite(0, transactionId, aCompositeStart, aCompositeEnd);
nsTArray<ImageCompositeNotificationInfo> notifications;
@ -1974,7 +1974,7 @@ CompositorBridgeParent::NotifyDidCompositeToPipeline(const wr::PipelineId& aPipe
lts->mWrBridge &&
lts->mWrBridge->PipelineId() == aPipelineId) {
CrossProcessCompositorBridgeParent* cpcp = lts->mCrossProcessParent;
uint64_t transactionId = lts->mWrBridge->FlushTransactionIdsForEpoch(aEpoch);
uint64_t transactionId = lts->mWrBridge->FlushTransactionIdsForEpoch(aEpoch, aCompositeEnd);
Unused << cpcp->SendDidComposite(aLayersId, transactionId, aCompositeStart, aCompositeEnd);
}
});

View File

@ -56,10 +56,10 @@ parent:
async DPBegin(IntSize aSize);
async DPEnd(IntSize aSize, WebRenderParentCommand[] commands, OpDestroy[] toDestroy, uint64_t fwdTransactionId, uint64_t transactionId,
LayoutSize aContentSize, ByteBuffer aDL, BuiltDisplayListDescriptor aDLDesc,
WebRenderScrollData aScrollData, uint32_t idNameSpace);
WebRenderScrollData aScrollData, uint32_t idNameSpace, TimeStamp fwdTime);
sync DPSyncEnd(IntSize aSize, WebRenderParentCommand[] commands, OpDestroy[] toDestroy, uint64_t fwdTransactionId, uint64_t transactionId,
LayoutSize aContentSize, ByteBuffer aDL, BuiltDisplayListDescriptor aDLDesc,
WebRenderScrollData aScrollData, uint32_t idNameSpace);
WebRenderScrollData aScrollData, uint32_t idNameSpace, TimeStamp fwdTime);
async ParentCommands(WebRenderParentCommand[] commands);
sync DPGetSnapshot(PTexture texture);
async AddPipelineIdForAsyncCompositable(PipelineId aImageId, CompositableHandle aHandle);

View File

@ -112,12 +112,17 @@ WebRenderBridgeChild::DPEnd(wr::DisplayListBuilder &aBuilder,
aBuilder.Finalize(contentSize, dl);
ByteBuffer dlData(Move(dl.dl));
TimeStamp fwdTime;
#if defined(ENABLE_FRAME_LATENCY_LOG)
fwdTime = TimeStamp::Now();
#endif
if (aIsSync) {
this->SendDPSyncEnd(aSize, mParentCommands, mDestroyedActors, GetFwdTransactionId(), aTransactionId,
contentSize, dlData, dl.dl_desc, aScrollData, mIdNamespace);
contentSize, dlData, dl.dl_desc, aScrollData, mIdNamespace,fwdTime);
} else {
this->SendDPEnd(aSize, mParentCommands, mDestroyedActors, GetFwdTransactionId(), aTransactionId,
contentSize, dlData, dl.dl_desc, aScrollData, mIdNamespace);
contentSize, dlData, dl.dl_desc, aScrollData, mIdNamespace, fwdTime);
}
mParentCommands.Clear();

View File

@ -404,7 +404,8 @@ WebRenderBridgeParent::HandleDPEnd(const gfx::IntSize& aSize,
const wr::ByteBuffer& dl,
const wr::BuiltDisplayListDescriptor& dlDesc,
const WebRenderScrollData& aScrollData,
const uint32_t& aIdNameSpace)
const uint32_t& aIdNameSpace,
const TimeStamp& aFwdTime)
{
AutoProfilerTracing tracing("Paint", "DPTransaction");
UpdateFwdTransactionId(aFwdTransactionId);
@ -423,7 +424,7 @@ WebRenderBridgeParent::HandleDPEnd(const gfx::IntSize& aSize,
uint32_t wrEpoch = GetNextWrEpoch();
ProcessWebRenderCommands(aSize, aCommands, wr::NewEpoch(wrEpoch),
aContentSize, dl, dlDesc, aIdNameSpace);
HoldPendingTransactionId(wrEpoch, aTransactionId);
HoldPendingTransactionId(wrEpoch, aTransactionId, aFwdTime);
mScrollData = aScrollData;
UpdateAPZ();
@ -517,13 +518,14 @@ WebRenderBridgeParent::RecvDPEnd(const gfx::IntSize& aSize,
const wr::ByteBuffer& dl,
const wr::BuiltDisplayListDescriptor& dlDesc,
const WebRenderScrollData& aScrollData,
const uint32_t& aIdNameSpace)
const uint32_t& aIdNameSpace,
const TimeStamp& aFwdTime)
{
if (mDestroyed) {
return IPC_OK();
}
HandleDPEnd(aSize, Move(aCommands), Move(aToDestroy), aFwdTransactionId, aTransactionId,
aContentSize, dl, dlDesc, aScrollData, aIdNameSpace);
aContentSize, dl, dlDesc, aScrollData, aIdNameSpace, aFwdTime);
return IPC_OK();
}
@ -537,13 +539,14 @@ WebRenderBridgeParent::RecvDPSyncEnd(const gfx::IntSize &aSize,
const wr::ByteBuffer& dl,
const wr::BuiltDisplayListDescriptor& dlDesc,
const WebRenderScrollData& aScrollData,
const uint32_t& aIdNameSpace)
const uint32_t& aIdNameSpace,
const TimeStamp& aFwdTime)
{
if (mDestroyed) {
return IPC_OK();
}
HandleDPEnd(aSize, Move(aCommands), Move(aToDestroy), aFwdTransactionId, aTransactionId,
aContentSize, dl, dlDesc, aScrollData, aIdNameSpace);
aContentSize, dl, dlDesc, aScrollData, aIdNameSpace, aFwdTime);
return IPC_OK();
}
@ -1124,6 +1127,11 @@ WebRenderBridgeParent::CompositeToTarget(gfx::DrawTarget* aTarget, const gfx::In
wr::RenderThread::Get()->IncPendingFrameCount(mApi->GetId());
#if defined(ENABLE_FRAME_LATENCY_LOG)
auto startTime = TimeStamp::Now();
mApi->SetFrameStartTime(startTime);
#endif
if (!transformArray.IsEmpty() || !opacityArray.IsEmpty()) {
mApi->GenerateFrame(opacityArray, transformArray);
} else {
@ -1140,7 +1148,7 @@ WebRenderBridgeParent::CompositeToTarget(gfx::DrawTarget* aTarget, const gfx::In
}
void
WebRenderBridgeParent::HoldPendingTransactionId(uint32_t aWrEpoch, uint64_t aTransactionId)
WebRenderBridgeParent::HoldPendingTransactionId(uint32_t aWrEpoch, uint64_t aTransactionId, const TimeStamp& aFwdTime)
{
// The transaction ID might get reset to 1 if the page gets reloaded, see
// https://bugzilla.mozilla.org/show_bug.cgi?id=1145295#c41
@ -1150,7 +1158,7 @@ WebRenderBridgeParent::HoldPendingTransactionId(uint32_t aWrEpoch, uint64_t aTra
if (aTransactionId == 1) {
FlushPendingTransactionIds();
}
mPendingTransactionIds.push(PendingTransactionId(wr::NewEpoch(aWrEpoch), aTransactionId));
mPendingTransactionIds.push(PendingTransactionId(wr::NewEpoch(aWrEpoch), aTransactionId, aFwdTime));
}
uint64_t
@ -1175,7 +1183,7 @@ WebRenderBridgeParent::FlushPendingTransactionIds()
}
uint64_t
WebRenderBridgeParent::FlushTransactionIdsForEpoch(const wr::Epoch& aEpoch)
WebRenderBridgeParent::FlushTransactionIdsForEpoch(const wr::Epoch& aEpoch, const TimeStamp& aEndTime)
{
uint64_t id = 0;
while (!mPendingTransactionIds.empty()) {
@ -1184,6 +1192,13 @@ WebRenderBridgeParent::FlushTransactionIdsForEpoch(const wr::Epoch& aEpoch)
if (diff < 0) {
break;
}
#if defined(ENABLE_FRAME_LATENCY_LOG)
if (mPendingTransactionIds.front().mFwdTime) {
uint32_t latencyMs = round((aEndTime - mPendingTransactionIds.front().mFwdTime).ToMilliseconds());
printf_stderr("From EndTransaction to end of generate frame latencyMs %d this %p\n", latencyMs, this);
}
#endif
id = mPendingTransactionIds.front().mId;
mPendingTransactionIds.pop();
if (diff == 0) {

View File

@ -102,7 +102,8 @@ public:
const wr::ByteBuffer& dl,
const wr::BuiltDisplayListDescriptor& dlDesc,
const WebRenderScrollData& aScrollData,
const uint32_t& aIdNameSpace) override;
const uint32_t& aIdNameSpace,
const TimeStamp& aFwdTime) override;
mozilla::ipc::IPCResult RecvDPSyncEnd(const gfx::IntSize& aSize,
InfallibleTArray<WebRenderParentCommand>&& aCommands,
InfallibleTArray<OpDestroy>&& aToDestroy,
@ -112,7 +113,8 @@ public:
const wr::ByteBuffer& dl,
const wr::BuiltDisplayListDescriptor& dlDesc,
const WebRenderScrollData& aScrollData,
const uint32_t& aIdNameSpace) override;
const uint32_t& aIdNameSpace,
const TimeStamp& aFwdTime) override;
mozilla::ipc::IPCResult RecvParentCommands(nsTArray<WebRenderParentCommand>&& commands) override;
mozilla::ipc::IPCResult RecvDPGetSnapshot(PTextureParent* aTexture) override;
@ -167,10 +169,10 @@ public:
void SendPendingAsyncMessages() override;
void SetAboutToSendAsyncMessages() override;
void HoldPendingTransactionId(uint32_t aWrEpoch, uint64_t aTransactionId);
void HoldPendingTransactionId(uint32_t aWrEpoch, uint64_t aTransactionId, const TimeStamp& aFwdTime);
uint64_t LastPendingTransactionId();
uint64_t FlushPendingTransactionIds();
uint64_t FlushTransactionIdsForEpoch(const wr::Epoch& aEpoch);
uint64_t FlushTransactionIdsForEpoch(const wr::Epoch& aEpoch, const TimeStamp& aEndTime);
TextureFactoryIdentifier GetTextureFactoryIdentifier();
@ -233,7 +235,8 @@ private:
const wr::ByteBuffer& dl,
const wr::BuiltDisplayListDescriptor& dlDesc,
const WebRenderScrollData& aScrollData,
const uint32_t& aIdNameSpace);
const uint32_t& aIdNameSpace,
const TimeStamp& aFwdTime);
mozilla::ipc::IPCResult HandleShutdown();
void AdvanceAnimations();
@ -256,12 +259,14 @@ private:
private:
struct PendingTransactionId {
PendingTransactionId(wr::Epoch aEpoch, uint64_t aId)
PendingTransactionId(wr::Epoch aEpoch, uint64_t aId, const TimeStamp& aFwdTime)
: mEpoch(aEpoch)
, mId(aId)
, mFwdTime(aFwdTime)
{}
wr::Epoch mEpoch;
uint64_t mId;
TimeStamp mFwdTime;
};
CompositorBridgeParentBase* MOZ_NON_OWNING_REF mCompositorBridge;

View File

@ -132,6 +132,15 @@ RendererOGL::Render()
mGL->SwapBuffers();
mWidget->PostRender(&widgetContext);
#if defined(ENABLE_FRAME_LATENCY_LOG)
if (mFrameStartTime) {
uint32_t latencyMs = round((TimeStamp::Now() - mFrameStartTime).ToMilliseconds());
printf_stderr("generate frame latencyMs latencyMs %d\n", latencyMs);
}
// Clear frame start time
mFrameStartTime = TimeStamp();
#endif
// TODO: Flush pending actions such as texture deletions/unlocks and
// textureHosts recycling.
@ -170,6 +179,17 @@ RendererOGL::SetProfilerEnabled(bool aEnabled)
wr_renderer_set_profiler_enabled(mRenderer, aEnabled);
}
void
RendererOGL::SetFrameStartTime(const TimeStamp& aTime)
{
if (mFrameStartTime) {
// frame start time is already set. This could happen when multiple
// generate frame requests are merged by webrender.
return;
}
mFrameStartTime = aTime;
}
wr::WrRenderedEpochs*
RendererOGL::FlushRenderedEpochs()
{

View File

@ -58,6 +58,9 @@ public:
/// This can be called on the render thread only.
void SetProfilerEnabled(bool aEnabled);
/// This can be called on the render thread only.
void SetFrameStartTime(const TimeStamp& aTime);
/// This can be called on the render thread only.
~RendererOGL();
@ -91,6 +94,7 @@ protected:
wr::Renderer* mRenderer;
layers::CompositorBridgeParentBase* mBridge;
wr::WindowId mWindowId;
TimeStamp mFrameStartTime;
};
} // namespace wr

View File

@ -510,6 +510,39 @@ WebRenderAPI::SetProfilerEnabled(bool aEnabled)
RunOnRenderThread(Move(event));
}
class FrameStartTime : public RendererEvent
{
public:
explicit FrameStartTime(const TimeStamp& aTime)
: mTime(aTime)
{
MOZ_COUNT_CTOR(FrameStartTime);
}
~FrameStartTime()
{
MOZ_COUNT_DTOR(FrameStartTime);
}
virtual void Run(RenderThread& aRenderThread, WindowId aWindowId) override
{
auto renderer = aRenderThread.GetRenderer(aWindowId);
if (renderer) {
renderer->SetFrameStartTime(mTime);
}
}
private:
TimeStamp mTime;
};
void
WebRenderAPI::SetFrameStartTime(const TimeStamp& aTime)
{
auto event = MakeUnique<FrameStartTime>(aTime);
RunOnRenderThread(Move(event));
}
void
WebRenderAPI::RunOnRenderThread(UniquePtr<RendererEvent> aEvent)
{

View File

@ -101,6 +101,8 @@ public:
void SetProfilerEnabled(bool aEnabled);
void SetFrameStartTime(const TimeStamp& aTime);
void RunOnRenderThread(UniquePtr<RendererEvent> aEvent);
void Readback(gfx::IntSize aSize, uint8_t *aBuffer, uint32_t aBufferSize);

View File

@ -17,6 +17,8 @@
#include "RoundedRect.h"
#include "nsStyleConsts.h"
//#define ENABLE_FRAME_LATENCY_LOG
namespace mozilla {
namespace wr {