libs/hwui/JankTracker.cpp - platform_frameworks_base - Gitiles

 /*
  * Copyright (C) 2015 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 "JankTracker.h"

 #include <errno.h>
 #include <inttypes.h>
 #include <sys/mman.h>

 #include <algorithm>
 #include <cmath>
 #include <cstdio>
 #include <limits>

 #include <cutils/ashmem.h>
 #include <log/log.h>

 #include "Properties.h"
 #include "utils/TimeUtils.h"

 namespace android {
 namespace uirenderer {

 struct Comparison {
     FrameInfoIndex start;
     FrameInfoIndex end;
 };

 static const Comparison COMPARISONS[] = {
         {FrameInfoIndex::IntendedVsync, FrameInfoIndex::Vsync},
         {FrameInfoIndex::OldestInputEvent, FrameInfoIndex::Vsync},
         {FrameInfoIndex::Vsync, FrameInfoIndex::SyncStart},
         {FrameInfoIndex::SyncStart, FrameInfoIndex::IssueDrawCommandsStart},
         {FrameInfoIndex::IssueDrawCommandsStart, FrameInfoIndex::FrameCompleted},
 };

 // If the event exceeds 10 seconds throw it away, this isn't a jank event
 // it's an ANR and will be handled as such
 static const int64_t IGNORE_EXCEEDING = seconds_to_nanoseconds(10);

 /*
  * We don't track direct-drawing via Surface:lockHardwareCanvas()
  * for now
  *
  * TODO: kSurfaceCanvas can negatively impact other drawing by using up
  * time on the RenderThread, figure out how to attribute that as a jank-causer
  */
 static const int64_t EXEMPT_FRAMES_FLAGS = FrameInfoFlags::SurfaceCanvas;

 // For testing purposes to try and eliminate test infra overhead we will
 // consider any unknown delay of frame start as part of the test infrastructure
 // and filter it out of the frame profile data
 static FrameInfoIndex sFrameStart = FrameInfoIndex::IntendedVsync;

 JankTracker::JankTracker(const DisplayInfo& displayInfo) {
     // By default this will use malloc memory. It may be moved later to ashmem
     // if there is shared space for it and a request comes in to do that.
     mData = new ProfileData;
     reset();
     nsecs_t frameIntervalNanos = static_cast<nsecs_t>(1_s / displayInfo.fps);
 #if USE_HWC2
     nsecs_t sfOffset = frameIntervalNanos - (displayInfo.presentationDeadline - 1_ms);
     nsecs_t offsetDelta = sfOffset - displayInfo.appVsyncOffset;
     // There are two different offset cases. If the offsetDelta is positive
     // and small, then the intention is to give apps extra time by leveraging
     // pipelining between the UI & RT threads. If the offsetDelta is large or
     // negative, the intention is to subtract time from the total duration
     // in which case we can't afford to wait for dequeueBuffer blockage.
     if (offsetDelta <= 4_ms && offsetDelta >= 0) {
         // SF will begin composition at VSYNC-app + offsetDelta. If we are triple
         // buffered, this is the expected time at which dequeueBuffer will
         // return due to the staggering of VSYNC-app & VSYNC-sf.
         mDequeueTimeForgiveness = offsetDelta + 4_ms;
     }
 #endif
     setFrameInterval(frameIntervalNanos);
 }

 JankTracker::~JankTracker() {
     freeData();
 }

 void JankTracker::freeData() {
     if (mIsMapped) {
         munmap(mData, sizeof(ProfileData));
     } else {
         delete mData;
     }
     mIsMapped = false;
     mData = nullptr;
 }

 void JankTracker::rotateStorage() {
     // If we are mapped we want to stop using the ashmem backend and switch to malloc
     // We are expecting a switchStorageToAshmem call to follow this, but it's not guaranteed
     // If we aren't sitting on top of ashmem then just do a reset() as it's functionally
     // equivalent do a free, malloc, reset.
     if (mIsMapped) {
         freeData();
         mData = new ProfileData;
     }
     reset();
 }

 void JankTracker::switchStorageToAshmem(int ashmemfd) {
     int regionSize = ashmem_get_size_region(ashmemfd);
     if (regionSize < 0) {
         int err = errno;
         ALOGW("Failed to get ashmem region size from fd %d, err %d %s", ashmemfd, err, strerror(err));
         return;
     }
     if (regionSize < static_cast<int>(sizeof(ProfileData))) {
         ALOGW("Ashmem region is too small! Received %d, required %u",
                 regionSize, static_cast<unsigned int>(sizeof(ProfileData)));
         return;
     }
     ProfileData* newData = reinterpret_cast<ProfileData*>(
             mmap(NULL, sizeof(ProfileData), PROT_READ | PROT_WRITE,
             MAP_SHARED, ashmemfd, 0));
     if (newData == MAP_FAILED) {
         int err = errno;
         ALOGW("Failed to move profile data to ashmem fd %d, error = %d",
                 ashmemfd, err);
         return;
     }

     newData->mergeWith(*mData);
     freeData();
     mData = newData;
     mIsMapped = true;
 }

 void JankTracker::setFrameInterval(nsecs_t frameInterval) {
     mFrameInterval = frameInterval;
     mThresholds[kMissedVsync] = 1;
     /*
      * Due to interpolation and sample rate differences between the touch
      * panel and the display (example, 85hz touch panel driving a 60hz display)
      * we call high latency 1.5 * frameinterval
      *
      * NOTE: Be careful when tuning this! A theoretical 1,000hz touch panel
      * on a 60hz display will show kOldestInputEvent - kIntendedVsync of being 15ms
      * Thus this must always be larger than frameInterval, or it will fail
      */
     mThresholds[kHighInputLatency] = static_cast<int64_t>(1.5 * frameInterval);

     // Note that these do not add up to 1. This is intentional. It's to deal
     // with variance in values, and should be sort of an upper-bound on what
     // is reasonable to expect.
     mThresholds[kSlowUI] = static_cast<int64_t>(.5 * frameInterval);
     mThresholds[kSlowSync] = static_cast<int64_t>(.2 * frameInterval);
     mThresholds[kSlowRT] = static_cast<int64_t>(.75 * frameInterval);

 }

 void JankTracker::addFrame(const FrameInfo& frame) {
     // Fast-path for jank-free frames
     int64_t totalDuration = frame.duration(sFrameStart, FrameInfoIndex::FrameCompleted);
     if (mDequeueTimeForgiveness
             && frame[FrameInfoIndex::DequeueBufferDuration] > 500_us) {
         nsecs_t expectedDequeueDuration =
                 mDequeueTimeForgiveness + frame[FrameInfoIndex::Vsync]
                 - frame[FrameInfoIndex::IssueDrawCommandsStart];
         if (expectedDequeueDuration > 0) {
             // Forgive only up to the expected amount, but not more than
             // the actual time spent blocked.
             nsecs_t forgiveAmount = std::min(expectedDequeueDuration,
                     frame[FrameInfoIndex::DequeueBufferDuration]);
             LOG_ALWAYS_FATAL_IF(forgiveAmount >= totalDuration,
                     "Impossible dequeue duration! dequeue duration reported %" PRId64
                     ", total duration %" PRId64, forgiveAmount, totalDuration);
             totalDuration -= forgiveAmount;
         }
     }
     LOG_ALWAYS_FATAL_IF(totalDuration <= 0, "Impossible totalDuration %" PRId64, totalDuration);
     mData->reportFrame(totalDuration);

     // Keep the fast path as fast as possible.
     if (CC_LIKELY(totalDuration < mFrameInterval)) {
         return;
     }

     // Only things like Surface.lockHardwareCanvas() are exempt from tracking
     if (frame[FrameInfoIndex::Flags] & EXEMPT_FRAMES_FLAGS) {
         return;
     }

     mData->reportJank();

     for (int i = 0; i < NUM_BUCKETS; i++) {
         int64_t delta = frame.duration(COMPARISONS[i].start, COMPARISONS[i].end);
         if (delta >= mThresholds[i] && delta < IGNORE_EXCEEDING) {
             mData->reportJankType((JankType) i);
         }
     }
 }

 void JankTracker::dumpData(int fd, const ProfileDataDescription* description, const ProfileData* data) {
     if (description) {
         switch (description->type) {
             case JankTrackerType::Generic:
                 break;
             case JankTrackerType::Package:
                 dprintf(fd, "\nPackage: %s", description->name.c_str());
                 break;
             case JankTrackerType::Window:
                 dprintf(fd, "\nWindow: %s", description->name.c_str());
                 break;
         }
     }
     if (sFrameStart != FrameInfoIndex::IntendedVsync) {
         dprintf(fd, "\nNote: Data has been filtered!");
     }
     data->dump(fd);
     dprintf(fd, "\n");
 }

 void JankTracker::reset() {
     mData->reset();
     sFrameStart = Properties::filterOutTestOverhead
             ? FrameInfoIndex::HandleInputStart
             : FrameInfoIndex::IntendedVsync;
 }

 } /* namespace uirenderer */
 } /* namespace android */
	/*
	* Copyright (C) 2015 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 "JankTracker.h"

	#include <errno.h>
	#include <inttypes.h>
	#include <sys/mman.h>

	#include <algorithm>
	#include <cmath>
	#include <cstdio>
	#include <limits>

	#include <cutils/ashmem.h>
	#include <log/log.h>

	#include "Properties.h"
	#include "utils/TimeUtils.h"

	namespace android {
	namespace uirenderer {

	struct Comparison {
	FrameInfoIndex start;
	FrameInfoIndex end;
	};

	static const Comparison COMPARISONS[] = {
	{FrameInfoIndex::IntendedVsync, FrameInfoIndex::Vsync},
	{FrameInfoIndex::OldestInputEvent, FrameInfoIndex::Vsync},
	{FrameInfoIndex::Vsync, FrameInfoIndex::SyncStart},
	{FrameInfoIndex::SyncStart, FrameInfoIndex::IssueDrawCommandsStart},
	{FrameInfoIndex::IssueDrawCommandsStart, FrameInfoIndex::FrameCompleted},
	};

	// If the event exceeds 10 seconds throw it away, this isn't a jank event
	// it's an ANR and will be handled as such
	static const int64_t IGNORE_EXCEEDING = seconds_to_nanoseconds(10);

	/*
	* We don't track direct-drawing via Surface:lockHardwareCanvas()
	* for now
	*
	* TODO: kSurfaceCanvas can negatively impact other drawing by using up
	* time on the RenderThread, figure out how to attribute that as a jank-causer
	*/
	static const int64_t EXEMPT_FRAMES_FLAGS = FrameInfoFlags::SurfaceCanvas;

	// For testing purposes to try and eliminate test infra overhead we will
	// consider any unknown delay of frame start as part of the test infrastructure
	// and filter it out of the frame profile data
	static FrameInfoIndex sFrameStart = FrameInfoIndex::IntendedVsync;

	JankTracker::JankTracker(const DisplayInfo& displayInfo) {
	// By default this will use malloc memory. It may be moved later to ashmem
	// if there is shared space for it and a request comes in to do that.
	mData = new ProfileData;
	reset();
	nsecs_t frameIntervalNanos = static_cast<nsecs_t>(1_s / displayInfo.fps);
	#if USE_HWC2
	nsecs_t sfOffset = frameIntervalNanos - (displayInfo.presentationDeadline - 1_ms);
	nsecs_t offsetDelta = sfOffset - displayInfo.appVsyncOffset;
	// There are two different offset cases. If the offsetDelta is positive
	// and small, then the intention is to give apps extra time by leveraging
	// pipelining between the UI & RT threads. If the offsetDelta is large or
	// negative, the intention is to subtract time from the total duration
	// in which case we can't afford to wait for dequeueBuffer blockage.
	if (offsetDelta <= 4_ms && offsetDelta >= 0) {
	// SF will begin composition at VSYNC-app + offsetDelta. If we are triple
	// buffered, this is the expected time at which dequeueBuffer will
	// return due to the staggering of VSYNC-app & VSYNC-sf.
	mDequeueTimeForgiveness = offsetDelta + 4_ms;
	}
	#endif
	setFrameInterval(frameIntervalNanos);
	}

	JankTracker::~JankTracker() {
	freeData();
	}

	void JankTracker::freeData() {
	if (mIsMapped) {
	munmap(mData, sizeof(ProfileData));
	} else {
	delete mData;
	}
	mIsMapped = false;
	mData = nullptr;
	}

	void JankTracker::rotateStorage() {
	// If we are mapped we want to stop using the ashmem backend and switch to malloc
	// We are expecting a switchStorageToAshmem call to follow this, but it's not guaranteed
	// If we aren't sitting on top of ashmem then just do a reset() as it's functionally
	// equivalent do a free, malloc, reset.
	if (mIsMapped) {
	freeData();
	mData = new ProfileData;
	}
	reset();
	}

	void JankTracker::switchStorageToAshmem(int ashmemfd) {
	int regionSize = ashmem_get_size_region(ashmemfd);
	if (regionSize < 0) {
	int err = errno;
	ALOGW("Failed to get ashmem region size from fd %d, err %d %s", ashmemfd, err, strerror(err));
	return;
	}
	if (regionSize < static_cast<int>(sizeof(ProfileData))) {
	ALOGW("Ashmem region is too small! Received %d, required %u",
	regionSize, static_cast<unsigned int>(sizeof(ProfileData)));
	return;
	}
	ProfileData* newData = reinterpret_cast<ProfileData*>(
	mmap(NULL, sizeof(ProfileData), PROT_READ \| PROT_WRITE,
	MAP_SHARED, ashmemfd, 0));
	if (newData == MAP_FAILED) {
	int err = errno;
	ALOGW("Failed to move profile data to ashmem fd %d, error = %d",
	ashmemfd, err);
	return;
	}

	newData->mergeWith(*mData);
	freeData();
	mData = newData;
	mIsMapped = true;
	}

	void JankTracker::setFrameInterval(nsecs_t frameInterval) {
	mFrameInterval = frameInterval;
	mThresholds[kMissedVsync] = 1;
	/*
	* Due to interpolation and sample rate differences between the touch
	* panel and the display (example, 85hz touch panel driving a 60hz display)
	* we call high latency 1.5 * frameinterval
	*
	* NOTE: Be careful when tuning this! A theoretical 1,000hz touch panel
	* on a 60hz display will show kOldestInputEvent - kIntendedVsync of being 15ms
	* Thus this must always be larger than frameInterval, or it will fail
	*/
	mThresholds[kHighInputLatency] = static_cast<int64_t>(1.5 * frameInterval);

	// Note that these do not add up to 1. This is intentional. It's to deal
	// with variance in values, and should be sort of an upper-bound on what
	// is reasonable to expect.
	mThresholds[kSlowUI] = static_cast<int64_t>(.5 * frameInterval);
	mThresholds[kSlowSync] = static_cast<int64_t>(.2 * frameInterval);
	mThresholds[kSlowRT] = static_cast<int64_t>(.75 * frameInterval);

	}

	void JankTracker::addFrame(const FrameInfo& frame) {
	// Fast-path for jank-free frames
	int64_t totalDuration = frame.duration(sFrameStart, FrameInfoIndex::FrameCompleted);
	if (mDequeueTimeForgiveness
	&& frame[FrameInfoIndex::DequeueBufferDuration] > 500_us) {
	nsecs_t expectedDequeueDuration =
	mDequeueTimeForgiveness + frame[FrameInfoIndex::Vsync]
	- frame[FrameInfoIndex::IssueDrawCommandsStart];
	if (expectedDequeueDuration > 0) {
	// Forgive only up to the expected amount, but not more than
	// the actual time spent blocked.
	nsecs_t forgiveAmount = std::min(expectedDequeueDuration,
	frame[FrameInfoIndex::DequeueBufferDuration]);
	LOG_ALWAYS_FATAL_IF(forgiveAmount >= totalDuration,
	"Impossible dequeue duration! dequeue duration reported %" PRId64
	", total duration %" PRId64, forgiveAmount, totalDuration);
	totalDuration -= forgiveAmount;
	}
	}
	LOG_ALWAYS_FATAL_IF(totalDuration <= 0, "Impossible totalDuration %" PRId64, totalDuration);
	mData->reportFrame(totalDuration);

	// Keep the fast path as fast as possible.
	if (CC_LIKELY(totalDuration < mFrameInterval)) {
	return;
	}

	// Only things like Surface.lockHardwareCanvas() are exempt from tracking
	if (frame[FrameInfoIndex::Flags] & EXEMPT_FRAMES_FLAGS) {
	return;
	}

	mData->reportJank();

	for (int i = 0; i < NUM_BUCKETS; i++) {
	int64_t delta = frame.duration(COMPARISONS[i].start, COMPARISONS[i].end);
	if (delta >= mThresholds[i] && delta < IGNORE_EXCEEDING) {
	mData->reportJankType((JankType) i);
	}
	}
	}

	void JankTracker::dumpData(int fd, const ProfileDataDescription* description, const ProfileData* data) {
	if (description) {
	switch (description->type) {
	case JankTrackerType::Generic:
	break;
	case JankTrackerType::Package:
	dprintf(fd, "\nPackage: %s", description->name.c_str());
	break;
	case JankTrackerType::Window:
	dprintf(fd, "\nWindow: %s", description->name.c_str());
	break;
	}
	}
	if (sFrameStart != FrameInfoIndex::IntendedVsync) {
	dprintf(fd, "\nNote: Data has been filtered!");
	}
	data->dump(fd);
	dprintf(fd, "\n");
	}

	void JankTracker::reset() {
	mData->reset();
	sFrameStart = Properties::filterOutTestOverhead
	? FrameInfoIndex::HandleInputStart
	: FrameInfoIndex::IntendedVsync;
	}

	} /* namespace uirenderer */
	} /* namespace android */