Stop reporting frame stats from frames completed before observer was attached

Test: Run app from bug report
Fixes: 195699687
Change-Id: If80825dfb41467917b7b9b1e8c9ead1a0dcbffae
This commit is contained in:
Pablo Gamito
2021-08-09 14:37:56 +00:00
parent ab1d302c75
commit 88660d77da
9 changed files with 165 additions and 64 deletions

View File

@@ -587,6 +587,7 @@ cc_defaults {
"HardwareBitmapUploader.cpp",
"HWUIProperties.sysprop",
"JankTracker.cpp",
"FrameMetricsReporter.cpp",
"Layer.cpp",
"LayerUpdateQueue.cpp",
"ProfileData.cpp",

View File

@@ -26,6 +26,13 @@ public:
virtual void notify(const int64_t* buffer) = 0;
bool waitForPresentTime() const { return mWaitForPresentTime; };
void reportMetricsFrom(int64_t frameNumber, int32_t surfaceControlId) {
mAttachedFrameNumber = frameNumber;
mSurfaceControlId = surfaceControlId;
};
int64_t attachedFrameNumber() const { return mAttachedFrameNumber; };
int32_t attachedSurfaceControlId() const { return mSurfaceControlId; };
/**
* Create a new metrics observer. An observer that watches present time gets notified at a
* different time than the observer that doesn't.
@@ -42,6 +49,22 @@ public:
private:
const bool mWaitForPresentTime;
// The id of the surface control (mSurfaceControlGenerationId in CanvasContext)
// for which the mAttachedFrameNumber applies to. We rely on this value being
// an increasing counter. We will report metrics:
// - for all frames if the frame comes from a surface with a surfaceControlId
// that is strictly greater than mSurfaceControlId.
// - for all frames with a frame number greater than or equal to mAttachedFrameNumber
// if the frame comes from a surface with a surfaceControlId that is equal to the
// mSurfaceControlId.
// We will never report metrics if the frame comes from a surface with a surfaceControlId
// that is strictly smaller than mSurfaceControlId.
int32_t mSurfaceControlId;
// The frame number the metrics observer was attached on. Metrics will be sent from this frame
// number (inclusive) onwards in the case that the surface id is equal to mSurfaceControlId.
int64_t mAttachedFrameNumber;
};
} // namespace uirenderer

View File

@@ -0,0 +1,56 @@
/*
* Copyright (C) 2021 The Android Open Source Project
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
#include "FrameMetricsReporter.h"
namespace android {
namespace uirenderer {
void FrameMetricsReporter::reportFrameMetrics(const int64_t* stats, bool hasPresentTime,
int64_t frameNumber, int32_t surfaceControlId) {
FatVector<sp<FrameMetricsObserver>, 10> copy;
{
std::lock_guard lock(mObserversLock);
copy.reserve(mObservers.size());
for (size_t i = 0; i < mObservers.size(); i++) {
auto observer = mObservers[i];
if (CC_UNLIKELY(surfaceControlId < observer->attachedSurfaceControlId())) {
// Don't notify if the metrics are from a frame that was run on an old
// surface (one from before the observer was attached).
ALOGV("skipped reporting metrics from old surface %d", surfaceControlId);
continue;
} else if (CC_UNLIKELY(surfaceControlId == observer->attachedSurfaceControlId() &&
frameNumber < observer->attachedFrameNumber())) {
// Don't notify if the metrics are from a frame that was queued by the
// BufferQueueProducer on the render thread before the observer was attached.
ALOGV("skipped reporting metrics from old frame %ld", (long)frameNumber);
continue;
}
const bool wantsPresentTime = observer->waitForPresentTime();
if (hasPresentTime == wantsPresentTime) {
copy.push_back(observer);
}
}
}
for (size_t i = 0; i < copy.size(); i++) {
copy[i]->notify(stats);
}
}
} // namespace uirenderer
} // namespace android

View File

@@ -63,23 +63,14 @@ public:
* If an observer does not want present time, only notify when 'hasPresentTime' is false.
* Never notify both types of observers from the same callback, because the callback with
* 'hasPresentTime' is sent at a different time than the one without.
*
* The 'frameNumber' and 'surfaceControlId' associated to the frame whose's stats are being
* reported are used to determine whether or not the stats should be reported. We won't report
* stats of frames that are from "old" surfaces (i.e. with surfaceControlIds older than the one
* the observer was attached on) nor those that are from "old" frame numbers.
*/
void reportFrameMetrics(const int64_t* stats, bool hasPresentTime) {
FatVector<sp<FrameMetricsObserver>, 10> copy;
{
std::lock_guard lock(mObserversLock);
copy.reserve(mObservers.size());
for (size_t i = 0; i < mObservers.size(); i++) {
const bool wantsPresentTime = mObservers[i]->waitForPresentTime();
if (hasPresentTime == wantsPresentTime) {
copy.push_back(mObservers[i]);
}
}
}
for (size_t i = 0; i < copy.size(); i++) {
copy[i]->notify(stats);
}
}
void reportFrameMetrics(const int64_t* stats, bool hasPresentTime, int64_t frameNumber,
int32_t surfaceControlId);
private:
FatVector<sp<FrameMetricsObserver>, 10> mObservers GUARDED_BY(mObserversLock);

View File

@@ -164,7 +164,8 @@ void JankTracker::calculateLegacyJank(FrameInfo& frame) REQUIRES(mDataMutex) {
- lastFrameOffset + mFrameIntervalLegacy;
}
void JankTracker::finishFrame(FrameInfo& frame, std::unique_ptr<FrameMetricsReporter>& reporter) {
void JankTracker::finishFrame(FrameInfo& frame, std::unique_ptr<FrameMetricsReporter>& reporter,
int64_t frameNumber, int32_t surfaceControlId) {
std::lock_guard lock(mDataMutex);
calculateLegacyJank(frame);
@@ -253,7 +254,8 @@ void JankTracker::finishFrame(FrameInfo& frame, std::unique_ptr<FrameMetricsRepo
}
if (CC_UNLIKELY(reporter.get() != nullptr)) {
reporter->reportFrameMetrics(frame.data(), false /* hasPresentTime */);
reporter->reportFrameMetrics(frame.data(), false /* hasPresentTime */, frameNumber,
surfaceControlId);
}
}

View File

@@ -57,7 +57,8 @@ public:
}
FrameInfo* startFrame() { return &mFrames.next(); }
void finishFrame(FrameInfo& frame, std::unique_ptr<FrameMetricsReporter>& reporter);
void finishFrame(FrameInfo& frame, std::unique_ptr<FrameMetricsReporter>& reporter,
int64_t frameNumber, int32_t surfaceId);
// Calculates the 'legacy' jank information, i.e. with outdated refresh rate information and
// without GPU completion or deadlined information.

View File

@@ -613,16 +613,18 @@ nsecs_t CanvasContext::draw() {
if (requireSwap) {
if (mExpectSurfaceStats) {
reportMetricsWithPresentTime();
std::lock_guard lock(mLast4FrameInfosMutex);
std::pair<FrameInfo*, int64_t>& next = mLast4FrameInfos.next();
next.first = mCurrentFrameInfo;
next.second = frameCompleteNr;
std::lock_guard lock(mLast4FrameMetricsInfosMutex);
FrameMetricsInfo& next = mLast4FrameMetricsInfos.next();
next.frameInfo = mCurrentFrameInfo;
next.frameNumber = frameCompleteNr;
next.surfaceId = mSurfaceControlGenerationId;
} else {
mCurrentFrameInfo->markFrameCompleted();
mCurrentFrameInfo->set(FrameInfoIndex::GpuCompleted)
= mCurrentFrameInfo->get(FrameInfoIndex::FrameCompleted);
std::scoped_lock lock(mFrameMetricsReporterMutex);
mJankTracker.finishFrame(*mCurrentFrameInfo, mFrameMetricsReporter);
mJankTracker.finishFrame(*mCurrentFrameInfo, mFrameMetricsReporter, frameCompleteNr,
mSurfaceControlGenerationId);
}
}
@@ -658,14 +660,18 @@ void CanvasContext::reportMetricsWithPresentTime() {
ATRACE_CALL();
FrameInfo* forthBehind;
int64_t frameNumber;
int32_t surfaceControlId;
{ // acquire lock
std::scoped_lock lock(mLast4FrameInfosMutex);
if (mLast4FrameInfos.size() != mLast4FrameInfos.capacity()) {
std::scoped_lock lock(mLast4FrameMetricsInfosMutex);
if (mLast4FrameMetricsInfos.size() != mLast4FrameMetricsInfos.capacity()) {
// Not enough frames yet
return;
}
// Surface object keeps stats for the last 8 frames.
std::tie(forthBehind, frameNumber) = mLast4FrameInfos.front();
auto frameMetricsInfo = mLast4FrameMetricsInfos.front();
forthBehind = frameMetricsInfo.frameInfo;
frameNumber = frameMetricsInfo.frameNumber;
surfaceControlId = frameMetricsInfo.surfaceId;
} // release lock
nsecs_t presentTime = 0;
@@ -680,25 +686,50 @@ void CanvasContext::reportMetricsWithPresentTime() {
{ // acquire lock
std::scoped_lock lock(mFrameMetricsReporterMutex);
if (mFrameMetricsReporter != nullptr) {
mFrameMetricsReporter->reportFrameMetrics(forthBehind->data(), true /*hasPresentTime*/);
mFrameMetricsReporter->reportFrameMetrics(forthBehind->data(), true /*hasPresentTime*/,
frameNumber, surfaceControlId);
}
} // release lock
}
FrameInfo* CanvasContext::getFrameInfoFromLast4(uint64_t frameNumber) {
std::scoped_lock lock(mLast4FrameInfosMutex);
for (size_t i = 0; i < mLast4FrameInfos.size(); i++) {
if (mLast4FrameInfos[i].second == frameNumber) {
return mLast4FrameInfos[i].first;
void CanvasContext::addFrameMetricsObserver(FrameMetricsObserver* observer) {
std::scoped_lock lock(mFrameMetricsReporterMutex);
if (mFrameMetricsReporter.get() == nullptr) {
mFrameMetricsReporter.reset(new FrameMetricsReporter());
}
// We want to make sure we aren't reporting frames that have already been queued by the
// BufferQueueProducer on the rendner thread but are still pending the callback to report their
// their frame metrics.
int64_t nextFrameNumber = getFrameNumber();
observer->reportMetricsFrom(nextFrameNumber, mSurfaceControlGenerationId);
mFrameMetricsReporter->addObserver(observer);
}
void CanvasContext::removeFrameMetricsObserver(FrameMetricsObserver* observer) {
std::scoped_lock lock(mFrameMetricsReporterMutex);
if (mFrameMetricsReporter.get() != nullptr) {
mFrameMetricsReporter->removeObserver(observer);
if (!mFrameMetricsReporter->hasObservers()) {
mFrameMetricsReporter.reset(nullptr);
}
}
return nullptr;
}
CanvasContext::FrameMetricsInfo CanvasContext::getFrameMetricsInfoFromLast4(uint64_t frameNumber) {
std::scoped_lock lock(mLast4FrameMetricsInfosMutex);
for (size_t i = 0; i < mLast4FrameMetricsInfos.size(); i++) {
if (mLast4FrameMetricsInfos[i].frameNumber == frameNumber) {
return mLast4FrameMetricsInfos[i];
}
}
return {};
}
void CanvasContext::onSurfaceStatsAvailable(void* context, ASurfaceControl* control,
ASurfaceControlStats* stats) {
CanvasContext* instance = static_cast<CanvasContext*>(context);
auto* instance = static_cast<CanvasContext*>(context);
const ASurfaceControlFunctions& functions =
instance->mRenderThread.getASurfaceControlFunctions();
@@ -706,14 +737,17 @@ void CanvasContext::onSurfaceStatsAvailable(void* context, ASurfaceControl* cont
nsecs_t gpuCompleteTime = functions.getAcquireTimeFunc(stats);
uint64_t frameNumber = functions.getFrameNumberFunc(stats);
FrameInfo* frameInfo = instance->getFrameInfoFromLast4(frameNumber);
FrameMetricsInfo frameMetricsInfo = instance->getFrameMetricsInfoFromLast4(frameNumber);
FrameInfo* frameInfo = frameMetricsInfo.frameInfo;
if (frameInfo != nullptr) {
frameInfo->set(FrameInfoIndex::FrameCompleted) = std::max(gpuCompleteTime,
frameInfo->get(FrameInfoIndex::SwapBuffersCompleted));
frameInfo->set(FrameInfoIndex::GpuCompleted) = gpuCompleteTime;
std::scoped_lock lock(instance->mFrameMetricsReporterMutex);
instance->mJankTracker.finishFrame(*frameInfo, instance->mFrameMetricsReporter);
instance->mJankTracker.finishFrame(*frameInfo, instance->mFrameMetricsReporter,
frameMetricsInfo.frameNumber,
frameMetricsInfo.surfaceId);
}
}

View File

@@ -167,24 +167,8 @@ public:
void setContentDrawBounds(const Rect& bounds) { mContentDrawBounds = bounds; }
void addFrameMetricsObserver(FrameMetricsObserver* observer) {
std::scoped_lock lock(mFrameMetricsReporterMutex);
if (mFrameMetricsReporter.get() == nullptr) {
mFrameMetricsReporter.reset(new FrameMetricsReporter());
}
mFrameMetricsReporter->addObserver(observer);
}
void removeFrameMetricsObserver(FrameMetricsObserver* observer) {
std::scoped_lock lock(mFrameMetricsReporterMutex);
if (mFrameMetricsReporter.get() != nullptr) {
mFrameMetricsReporter->removeObserver(observer);
if (!mFrameMetricsReporter->hasObservers()) {
mFrameMetricsReporter.reset(nullptr);
}
}
}
void addFrameMetricsObserver(FrameMetricsObserver* observer);
void removeFrameMetricsObserver(FrameMetricsObserver* observer);
// Used to queue up work that needs to be completed before this frame completes
void enqueueFrameWork(std::function<void()>&& func);
@@ -254,7 +238,13 @@ private:
*/
void reportMetricsWithPresentTime();
FrameInfo* getFrameInfoFromLast4(uint64_t frameNumber);
struct FrameMetricsInfo {
FrameInfo* frameInfo;
int64_t frameNumber;
int32_t surfaceId;
};
CanvasContext::FrameMetricsInfo getFrameMetricsInfoFromLast4(uint64_t frameNumber);
// The same type as Frame.mWidth and Frame.mHeight
int32_t mLastFrameWidth = 0;
@@ -266,7 +256,9 @@ private:
// NULL to remove the reference
ASurfaceControl* mSurfaceControl = nullptr;
// id to track surface control changes and WebViewFunctor uses it to determine
// whether reparenting is needed
// whether reparenting is needed also used by FrameMetricsReporter to determine
// if a frame is from an "old" surface (i.e. one that existed before the
// observer was attched) and therefore shouldn't be reported.
int32_t mSurfaceControlGenerationId = 0;
// stopped indicates the CanvasContext will reject actual redraw operations,
// and defer repaint until it is un-stopped
@@ -308,10 +300,11 @@ private:
FrameInfo* mCurrentFrameInfo = nullptr;
// List of frames that are awaiting GPU completion reporting
RingBuffer<std::pair<FrameInfo*, int64_t>, 4> mLast4FrameInfos
GUARDED_BY(mLast4FrameInfosMutex);
std::mutex mLast4FrameInfosMutex;
// List of data of frames that are awaiting GPU completion reporting. Used to compute frame
// metrics and determine whether or not to report the metrics.
RingBuffer<FrameMetricsInfo, 4> mLast4FrameMetricsInfos
GUARDED_BY(mLast4FrameMetricsInfosMutex);
std::mutex mLast4FrameMetricsInfosMutex;
std::string mName;
JankTracker mJankTracker;

View File

@@ -662,4 +662,4 @@ void ASurfaceTransaction_setOnCommit(ASurfaceTransaction* aSurfaceTransaction, v
Transaction* transaction = ASurfaceTransaction_to_Transaction(aSurfaceTransaction);
transaction->addTransactionCommittedCallback(callback, context);
}
}