diff options
| -rw-r--r-- | core/java/android/content/res/ResourceTimer.java | 289 | ||||
| -rw-r--r-- | core/jni/Android.bp | 1 | ||||
| -rw-r--r-- | core/jni/AndroidRuntime.cpp | 2 | ||||
| -rw-r--r-- | core/jni/android_content_res_ResourceTimer.cpp | 129 | ||||
| -rw-r--r-- | libs/androidfw/Android.bp | 2 | ||||
| -rw-r--r-- | libs/androidfw/ResourceTimer.cpp | 271 | ||||
| -rw-r--r-- | libs/androidfw/include/androidfw/ResourceTimer.h | 221 | ||||
| -rw-r--r-- | libs/androidfw/tests/ResourceTimer_test.cpp | 245 |
8 files changed, 1160 insertions, 0 deletions
diff --git a/core/java/android/content/res/ResourceTimer.java b/core/java/android/content/res/ResourceTimer.java new file mode 100644 index 000000000000..13f0b72b8875 --- /dev/null +++ b/core/java/android/content/res/ResourceTimer.java @@ -0,0 +1,289 @@ +/* + * Copyright (C) 2022 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. + */ + +package android.content.res; + +import android.annotation.NonNull; +import android.annotation.Nullable; + +import android.os.Handler; +import android.os.Looper; +import android.os.Message; +import android.os.ParcelFileDescriptor; +import android.os.Process; +import android.os.SystemClock; +import android.text.TextUtils; +import android.util.Log; + +import com.android.internal.annotations.GuardedBy; +import com.android.internal.util.FastPrintWriter; + +import java.io.FileOutputStream; +import java.io.PrintWriter; +import java.util.Arrays; + +/** + * Provides access to the resource timers without intruding on other classes. + * @hide + */ +public final class ResourceTimer { + private static final String TAG = "ResourceTimer"; + + // Enable metrics in this process. The flag may be set false in some processes. The flag is + // never set true at runtime, so setting it false here disables the feature entirely. + private static boolean sEnabled = true; + + // Set true for incremental metrics (the counters are reset after every fetch). Set false for + // cumulative metrics (the counters are never reset and accumulate values for the lifetime of + // the process). + private static boolean sIncrementalMetrics = true; + + // Set true to enable some debug behavior. + private static boolean ENABLE_DEBUG = false; + + // The global lock. + private static final Object sLock = new Object(); + + // The singleton cache manager + private static ResourceTimer sManager; + + // The handler for the timeouts. + private static Handler mHandler; + + // The time at which the process started. + private final static long sProcessStart = SystemClock.uptimeMillis(); + + // Metrics are published at offsets from the process start. Processes publish at five minutes + // and one hour. Thereafter, metrics are published every 12 hours. The values in this array + // are in units of minutes. + private static final long[] sPublicationPoints = new long[]{ 5, 60, 60 * 12 }; + + // The index of the latest publication point. + private static int sCurrentPoint; + + /** + * The runtime timer configuration. + */ + private static class Config { + // The number of timers in the runtime + int maxTimer; + // The number of histogram buckets per timer. + int maxBuckets; + // The number of "largest" values per timer. + int maxLargest; + // A string label for each timer. This array has maxTimer elements. + String[] timers; + } + + /** + * The timer information that is pulled from the native runtime. All times have units of ns. + */ + private static class Timer { + int count; + long total; + int mintime; + int maxtime; + int[] largest; + int[] percentile; + @Override + public String toString() { + return TextUtils.formatSimple("%d:%d:%d:%d", count, total, mintime, maxtime); + } + } + + /** + * A singleton Config. This is initialized when the timers are started. + */ + @GuardedBy("sLock") + private static Config sConfig; + + /** + * A singleton Summary object that is refilled from the native side. The length of the array + * is the number of timers that can be fetched. nativeGetTimers() will fill the array to the + * smaller of the length of the array or the actual number of timers in the runtime. The + * actual number of timers in the run time is returned by the function. + */ + @GuardedBy("sLock") + private static Timer[] sTimers; + + /** + * The time at which the local timer array was last updated. This has the same units as + * sProcessStart; the difference is the process run time. + */ + @GuardedBy("sLock") + private static long sLastUpdated = 0; + + // The constructor is private. Use the factory to get a hold of the manager. + private ResourceTimer() { + throw new RuntimeException("ResourceTimer constructor"); + } + + /** + * Start the manager. This runs a periodic job that collects and publishes timer values. + * This is not part of the constructor only because the looper failicities might not be + * available at the beginning of time. + */ + public static void start() { + synchronized (sLock) { + if (!sEnabled) { + return; + } + if (mHandler != null) { + // Nothing to be done. The job has already been started. + return; + } + if (Looper.getMainLooper() == null) { + throw new RuntimeException("ResourceTimer started too early"); + } + mHandler = new Handler(Looper.getMainLooper()) { + @Override + public void handleMessage(Message msg) { + ResourceTimer.handleMessage(msg); + } + }; + + // Initialize the container that holds information from the native runtime. The + // container is built according to the dimensions returned by the native layer. + sConfig = new Config(); + nativeEnableTimers(sConfig); + sTimers = new Timer[sConfig.maxTimer]; + for (int i = 0; i < sTimers.length; i++) { + sTimers[i] = new Timer(); + sTimers[i].percentile = new int[sConfig.maxBuckets]; + sTimers[i].largest = new int[sConfig.maxLargest]; + } + + sCurrentPoint = 0; + startTimer(); + } + } + + /** + * Handle a refresh message. Publish the metrics and start a timer for the next publication. + * The message parameter is unused. + */ + private static void handleMessage(Message msg) { + synchronized (sLock) { + publish(); + startTimer(); + } + } + + /** + * Start a timer to the next publication point. Publication points are referenced from + * process start. + */ + @GuardedBy("sLock") + private static void startTimer() { + // The delay is in minutes. + long delay; + if (sCurrentPoint < sPublicationPoints.length) { + delay = sPublicationPoints[sCurrentPoint]; + } else { + // Repeat with the final publication point. + delay = sCurrentPoint * sPublicationPoints[sPublicationPoints.length - 1]; + } + // Convert minutes to milliseconds. + delay *= 60 * 1000; + // If debug is enabled, convert hours down to minutes. + if (ENABLE_DEBUG) { + delay /= 60; + } + mHandler.sendEmptyMessageAtTime(0, sProcessStart + delay); + } + + /** + * Update the local copy of the timers. The current time is saved as well. + */ + @GuardedBy("sLock") + private static void update(boolean reset) { + nativeGetTimers(sTimers, reset); + sLastUpdated = SystemClock.uptimeMillis(); + } + + /** + * Retrieve the accumulated timer information, reset the native counters, and advance the + * publication point. + */ + @GuardedBy("sLock") + private static void publish() { + update(true); + // Log the number of records read. This happens a few times a day. + for (int i = 0; i < sTimers.length; i++) { + if (sTimers[i].count > 0) { + Log.i(TAG, TextUtils.formatSimple("%s count=%d pvalues=%s", + sConfig.timers[i], sTimers[i].count, + packedString(sTimers[i].percentile))); + } + } + sCurrentPoint++; + } + + /** + * Given an int[], return a string that is formatted as "a,b,c" with no spaces. + */ + private static String packedString(int[] a) { + return Arrays.toString(a).replaceAll("[\\]\\[ ]", ""); + } + + /** + * Update the metrics information and dump it. + * @hide + */ + public static void dumpTimers(@NonNull ParcelFileDescriptor pfd, @Nullable String[] args) { + FileOutputStream fout = new FileOutputStream(pfd.getFileDescriptor()); + PrintWriter pw = new FastPrintWriter(fout); + synchronized (sLock) { + if (!sEnabled || (sConfig == null)) { + pw.println(" Timers are not enabled in this process"); + pw.flush(); + return; + } + } + + // Look for the --refresh switch. If the switch is present, then sTimers is updated. + // Otherwise, the current value of sTimers is displayed. + boolean refresh = Arrays.asList(args).contains("-refresh"); + + synchronized (sLock) { + update(refresh); + long runtime = sLastUpdated - sProcessStart; + pw.format(" config runtime=%d proc=%s\n", runtime, Process.myProcessName()); + for (int i = 0; i < sTimers.length; i++) { + Timer t = sTimers[i]; + if (t.count != 0) { + String name = sConfig.timers[i]; + pw.format(" stats timer=%s cnt=%d avg=%d min=%d max=%d pval=%s " + + "largest=%s\n", + name, t.count, t.total / t.count, t.mintime, t.maxtime, + packedString(t.percentile), + packedString(t.largest)); + } + } + } + pw.flush(); + } + + // Enable (or disabled) the runtime timers. Note that timers are disabled by default. This + // retrieves the runtime timer configuration that are taking effect + private static native int nativeEnableTimers(@NonNull Config config); + + // Retrieve the timers from the native layer. If reset is true, the timers are reset after + // being fetched. The method returns the number of timers that are defined in the runtime + // layer. The stats array is filled out to the smaller of its actual size and the number of + // runtime timers; it never overflows. + private static native int nativeGetTimers(@NonNull Timer[] stats, boolean reset); +} diff --git a/core/jni/Android.bp b/core/jni/Android.bp index 26d0be139b64..d59a51ab9174 100644 --- a/core/jni/Android.bp +++ b/core/jni/Android.bp @@ -209,6 +209,7 @@ cc_library_shared { "android_content_res_ApkAssets.cpp", "android_content_res_ObbScanner.cpp", "android_content_res_Configuration.cpp", + "android_content_res_ResourceTimer.cpp", "android_security_Scrypt.cpp", "com_android_internal_content_om_OverlayConfig.cpp", "com_android_internal_net_NetworkUtilsInternal.cpp", diff --git a/core/jni/AndroidRuntime.cpp b/core/jni/AndroidRuntime.cpp index 11cb64cdf81a..68db603c3671 100644 --- a/core/jni/AndroidRuntime.cpp +++ b/core/jni/AndroidRuntime.cpp @@ -117,6 +117,7 @@ extern int register_android_util_MemoryIntArray(JNIEnv* env); extern int register_android_content_StringBlock(JNIEnv* env); extern int register_android_content_XmlBlock(JNIEnv* env); extern int register_android_content_res_ApkAssets(JNIEnv* env); +extern int register_android_content_res_ResourceTimer(JNIEnv* env); extern int register_android_graphics_BLASTBufferQueue(JNIEnv* env); extern int register_android_graphics_SurfaceTexture(JNIEnv* env); extern int register_android_view_DisplayEventReceiver(JNIEnv* env); @@ -1506,6 +1507,7 @@ static const RegJNIRec gRegJNI[] = { REG_JNI(register_android_content_StringBlock), REG_JNI(register_android_content_XmlBlock), REG_JNI(register_android_content_res_ApkAssets), + REG_JNI(register_android_content_res_ResourceTimer), REG_JNI(register_android_text_AndroidCharacter), REG_JNI(register_android_text_Hyphenator), REG_JNI(register_android_view_InputDevice), diff --git a/core/jni/android_content_res_ResourceTimer.cpp b/core/jni/android_content_res_ResourceTimer.cpp new file mode 100644 index 000000000000..91e3c921afe6 --- /dev/null +++ b/core/jni/android_content_res_ResourceTimer.cpp @@ -0,0 +1,129 @@ +/* + * Copyright 2022, 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 <jni.h> +#include <core_jni_helpers.h> +#include <utils/misc.h> +#include <androidfw/ResourceTimer.h> + +namespace android { + +// ---------------------------------------------------------------------------- + +static struct { + jfieldID maxTimer; + jfieldID maxBuckets; + jfieldID maxLargest; + jfieldID timers; +} gConfigOffsets; + +static struct { + jfieldID count; + jfieldID total; + jfieldID mintime; + jfieldID maxtime; + jfieldID largest; + jfieldID percentile; +} gTimerOffsets; + +// ---------------------------------------------------------------------------- + + +static int NativeGetTimers(JNIEnv* env, jobject /*clazz*/, jobjectArray timer, jboolean reset) { + size_t size = ResourceTimer::counterSize; + if (jsize st = env->GetArrayLength(timer); st < size) { + // Shrink the size to the minimum of the available counters and the available space. + size = st; + } + for (size_t i = 0; i < size; i++) { + ResourceTimer::Timer src; + ResourceTimer::copy(i, src, reset); + jobject dst = env->GetObjectArrayElement(timer, i); + env->SetIntField(dst, gTimerOffsets.count, src.count); + if (src.count == 0) { + continue; + } + + src.compute(); + env->SetIntField(dst, gTimerOffsets.count, src.count); + env->SetLongField(dst, gTimerOffsets.total, src.total); + env->SetIntField(dst, gTimerOffsets.mintime, src.mintime); + env->SetIntField(dst, gTimerOffsets.maxtime, src.maxtime); + jintArray percentile = + reinterpret_cast<jintArray>(env->GetObjectField(dst, gTimerOffsets.percentile)); + env->SetIntArrayRegion(percentile, 0, 1, &src.pvalues.p50.nominal); + env->SetIntArrayRegion(percentile, 1, 1, &src.pvalues.p90.nominal); + env->SetIntArrayRegion(percentile, 2, 1, &src.pvalues.p95.nominal); + env->SetIntArrayRegion(percentile, 3, 1, &src.pvalues.p99.nominal); + jintArray largest = + reinterpret_cast<jintArray>(env->GetObjectField(dst, gTimerOffsets.largest)); + env->SetIntArrayRegion(largest, 0, ResourceTimer::Timer::MaxLargest, src.largest); + } + return size; +} + +static jstring counterName(JNIEnv *env, int counter) { + char const *s = ResourceTimer::toString(static_cast<ResourceTimer::Counter>(counter)); + return env->NewStringUTF(s); +} + +static int NativeEnableTimers(JNIEnv* env, jobject /*clazz*/, jobject config) { + ResourceTimer::enable(); + + env->SetIntField(config, gConfigOffsets.maxTimer, ResourceTimer::counterSize); + env->SetIntField(config, gConfigOffsets.maxBuckets, 4); // Number of ints in PValues + env->SetIntField(config, gConfigOffsets.maxLargest, ResourceTimer::Timer::MaxLargest); + + jclass str = env->FindClass("java/lang/String"); + jstring empty = counterName(env, 0); + jobjectArray timers = env->NewObjectArray(ResourceTimer::counterSize, str, empty); + for (int i = 0; i < ResourceTimer::counterSize; i++) { + env->SetObjectArrayElement(timers, i, counterName(env, i)); + } + env->SetObjectField(config, gConfigOffsets.timers, timers); + return 0; +} + +// ---------------------------------------------------------------------------- + +// JNI registration. +static const JNINativeMethod gResourceTimerMethods[] = { + {"nativeEnableTimers", "(Landroid/content/res/ResourceTimer$Config;)I", + (void *) NativeEnableTimers}, + {"nativeGetTimers", "([Landroid/content/res/ResourceTimer$Timer;Z)I", + (void *) NativeGetTimers}, +}; + +int register_android_content_res_ResourceTimer(JNIEnv* env) { + jclass config = FindClassOrDie(env, "android/content/res/ResourceTimer$Config"); + gConfigOffsets.maxTimer = GetFieldIDOrDie(env, config, "maxTimer", "I"); + gConfigOffsets.maxBuckets = GetFieldIDOrDie(env, config, "maxBuckets", "I"); + gConfigOffsets.maxLargest = GetFieldIDOrDie(env, config, "maxLargest", "I"); + gConfigOffsets.timers = GetFieldIDOrDie(env, config, "timers", "[Ljava/lang/String;"); + + jclass timers = FindClassOrDie(env, "android/content/res/ResourceTimer$Timer"); + gTimerOffsets.count = GetFieldIDOrDie(env, timers, "count", "I"); + gTimerOffsets.total = GetFieldIDOrDie(env, timers, "total", "J"); + gTimerOffsets.mintime = GetFieldIDOrDie(env, timers, "mintime", "I"); + gTimerOffsets.maxtime = GetFieldIDOrDie(env, timers, "maxtime", "I"); + gTimerOffsets.largest = GetFieldIDOrDie(env, timers, "largest", "[I"); + gTimerOffsets.percentile = GetFieldIDOrDie(env, timers, "percentile", "[I"); + + return RegisterMethodsOrDie(env, "android/content/res/ResourceTimer", gResourceTimerMethods, + NELEM(gResourceTimerMethods)); +} + +}; // namespace android diff --git a/libs/androidfw/Android.bp b/libs/androidfw/Android.bp index 779c4b75efc4..eb8d26adc7d7 100644 --- a/libs/androidfw/Android.bp +++ b/libs/androidfw/Android.bp @@ -71,6 +71,7 @@ cc_library { "misc.cpp", "ObbFile.cpp", "PosixUtils.cpp", + "ResourceTimer.cpp", "ResourceTypes.cpp", "ResourceUtils.cpp", "StreamingZipInflater.cpp", @@ -173,6 +174,7 @@ cc_test { "tests/Idmap_test.cpp", "tests/LoadedArsc_test.cpp", "tests/Locale_test.cpp", + "tests/ResourceTimer_test.cpp", "tests/ResourceUtils_test.cpp", "tests/ResTable_test.cpp", "tests/Split_test.cpp", diff --git a/libs/androidfw/ResourceTimer.cpp b/libs/androidfw/ResourceTimer.cpp new file mode 100644 index 000000000000..44128d9e4e3d --- /dev/null +++ b/libs/androidfw/ResourceTimer.cpp @@ -0,0 +1,271 @@ +/* + * Copyright (C) 2022 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 <unistd.h> +#include <string.h> + +#include <map> +#include <atomic> + +#include <utils/Log.h> +#include <androidfw/ResourceTimer.h> + +// The following block allows compilation on windows, which does not have getuid(). +#ifdef _WIN32 +#ifdef ERROR +#undef ERROR +#endif +#define getuid() (getUidWindows_) +#endif + +namespace android { + +namespace { + +#ifdef _WIN32 +// A temporary to confuse lint into thinking that getuid() on windows might return something other +// than zero. +int getUidWindows_ = 0; +#endif + +// The number of nanoseconds in a microsecond. +static const unsigned int US = 1000; +// The number of nanoseconds in a second. +static const unsigned int S = 1000 * 1000 * 1000; + +// Return the difference between two timespec values. The difference is in nanoseconds. If the +// return value would exceed 2s (2^31 nanoseconds) then UINT_MAX is returned. +unsigned int diffInNs(timespec const &a, timespec const &b) { + timespec r = { 0, 0 }; + r.tv_nsec = a.tv_nsec - b.tv_nsec; + if (r.tv_nsec < 0) { + r.tv_sec = -1; + r.tv_nsec += S; + } + r.tv_sec = r.tv_sec + (a.tv_sec - b.tv_sec); + if (r.tv_sec > 2) return UINT_MAX; + unsigned int result = (r.tv_sec * S) + r.tv_nsec; + if (result > 2 * S) return UINT_MAX; + return result; +} + +} + +ResourceTimer::ResourceTimer(Counter api) + : active_(enabled_.load()), + api_(api) { + if (active_) { + clock_gettime(CLOCK_MONOTONIC, &start_); + } +} + +ResourceTimer::~ResourceTimer() { + record(); +} + +void ResourceTimer::enable() { + if (!enabled_.load()) counter_ = new GuardedTimer[ResourceTimer::counterSize]; + enabled_.store(true); +} + +void ResourceTimer::cancel() { + active_ = false; +} + +void ResourceTimer::record() { + if (!active_) return; + + struct timespec end; + clock_gettime(CLOCK_MONOTONIC, &end); + // Get the difference in microseconds. + const unsigned int ticks = diffInNs(end, start_); + ScopedTimer t(counter_[toIndex(api_)]); + t->record(ticks); + active_ = false; +} + +bool ResourceTimer::copy(int counter, Timer &dst, bool reset) { + ScopedTimer t(counter_[counter]); + if (t->count == 0) { + dst.reset(); + if (reset) t->reset(); + return false; + } + Timer::copy(dst, *t, reset); + return true; +} + +void ResourceTimer::reset() { + for (int i = 0; i < counterSize; i++) { + ScopedTimer t(counter_[i]); + t->reset(); + } +} + +ResourceTimer::Timer::Timer() { + // Ensure newly-created objects are zeroed. + memset(buckets, 0, sizeof(buckets)); + reset(); +} + +ResourceTimer::Timer::~Timer() { + for (int d = 0; d < MaxDimension; d++) { + delete[] buckets[d]; + } +} + +void ResourceTimer::Timer::freeBuckets() { + for (int d = 0; d < MaxDimension; d++) { + delete[] buckets[d]; + buckets[d] = 0; + } +} + +void ResourceTimer::Timer::reset() { + count = total = mintime = maxtime = 0; + memset(largest, 0, sizeof(largest)); + memset(&pvalues, 0, sizeof(pvalues)); + // Zero the histogram, keeping any allocated dimensions. + for (int d = 0; d < MaxDimension; d++) { + if (buckets[d] != 0) memset(buckets[d], 0, sizeof(int) * MaxBuckets); + } +} + +void ResourceTimer::Timer::copy(Timer &dst, Timer &src, bool reset) { + dst.freeBuckets(); + dst = src; + // Clean up the histograms. + if (reset) { + // Do NOT free the src buckets because they being used by dst. + memset(src.buckets, 0, sizeof(src.buckets)); + src.reset(); + } else { + for (int d = 0; d < MaxDimension; d++) { + if (src.buckets[d] != nullptr) { + dst.buckets[d] = new int[MaxBuckets]; + memcpy(dst.buckets[d], src.buckets[d], sizeof(int) * MaxBuckets); + } + } + } +} + +void ResourceTimer::Timer::record(int ticks) { + // Record that the event happened. + count++; + + total += ticks; + if (mintime == 0 || ticks < mintime) mintime = ticks; + if (ticks > maxtime) maxtime = ticks; + + // Do not add oversized events to the histogram. + if (ticks != UINT_MAX) { + for (int d = 0; d < MaxDimension; d++) { + if (ticks < range[d]) { + if (buckets[d] == 0) { + buckets[d] = new int[MaxBuckets]; + memset(buckets[d], 0, sizeof(int) * MaxBuckets); + } + if (ticks < width[d]) { + // Special case: never write to bucket 0 because it complicates the percentile logic. + // However, this is always the smallest possible value to it is very unlikely to ever + // affect any of the percentile results. + buckets[d][1]++; + } else { + buckets[d][ticks / width[d]]++; + } + break; + } + } + } + + // The list of largest times is sorted with the biggest value at index 0 and the smallest at + // index MaxLargest-1. The incoming tick count should be added to the array only if it is + // larger than the current value at MaxLargest-1. + if (ticks > largest[Timer::MaxLargest-1]) { + for (size_t i = 0; i < Timer::MaxLargest; i++) { + if (ticks > largest[i]) { + if (i < Timer::MaxLargest-1) { + for (size_t j = Timer::MaxLargest - 1; j > i; j--) { + largest[j] = largest[j-1]; + } + } + largest[i] = ticks; + break; + } + } + } +} + +void ResourceTimer::Timer::Percentile::compute( + int cumulative, int current, int count, int width, int time) { + nominal = time; + nominal_actual = (cumulative * 100) / count; + floor = nominal - width; + floor_actual = ((cumulative - current) * 100) / count; +} + +void ResourceTimer::Timer::compute() { + memset(&pvalues, 0, sizeof(pvalues)); + + float l50 = count / 2.0; + float l90 = (count * 9.0) / 10.0; + float l95 = (count * 95.0) / 100.0; + float l99 = (count * 99.0) / 100.0; + + int sum = 0; + for (int d = 0; d < MaxDimension; d++) { + if (buckets[d] == 0) continue; + for (int j = 0; j < MaxBuckets && sum < count; j++) { + // Empty buckets don't contribute to the answers. Skip them. + if (buckets[d][j] == 0) continue; + sum += buckets[d][j]; + // A word on indexing. j is never zero in the following lines. buckets[0][0] corresponds + // to a delay of 0us, which cannot happen. buckets[n][0], for n > 0 overlaps a value in + // buckets[n-1], and the code would have stopped there. + if (sum >= l50 && pvalues.p50.nominal == 0) { + pvalues.p50.compute(sum, buckets[d][j], count, width[d], j * width[d]); + } + if (sum >= l90 && pvalues.p90.nominal == 0) { + pvalues.p90.compute(sum, buckets[d][j], count, width[d], j * width[d]); + } + if (sum >= l95 && pvalues.p95.nominal == 0) { + pvalues.p95.compute(sum, buckets[d][j], count, width[d], j * width[d]); + } + if (sum >= l99 && pvalues.p99.nominal == 0) { + pvalues.p99.compute(sum, buckets[d][j], count, width[d], j * width[d]); + } + } + } +} + +char const *ResourceTimer::toString(ResourceTimer::Counter counter) { + switch (counter) { + case Counter::GetResourceValue: + return "GetResourceValue"; + case Counter::RetrieveAttributes: + return "RetrieveAttributes"; + }; + return "Unknown"; +} + +std::atomic<bool> ResourceTimer::enabled_(false); +std::atomic<ResourceTimer::GuardedTimer *> ResourceTimer::counter_(nullptr); + +const int ResourceTimer::Timer::range[] = { 100 * US, 1000 * US, 10*1000 * US, 100*1000 * US }; +const int ResourceTimer::Timer::width[] = { 1 * US, 10 * US, 100 * US, 1000 * US }; + + +} // namespace android diff --git a/libs/androidfw/include/androidfw/ResourceTimer.h b/libs/androidfw/include/androidfw/ResourceTimer.h new file mode 100644 index 000000000000..74613519a920 --- /dev/null +++ b/libs/androidfw/include/androidfw/ResourceTimer.h @@ -0,0 +1,221 @@ +/* + * Copyright (C) 2022 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. + */ + +#ifndef ANDROIDFW_RESOURCETIMER_H_ +#define ANDROIDFW_RESOURCETIMER_H_ + +#include <time.h> +#include <atomic> +#include <vector> + +#include <utils/Mutex.h> +#include <android-base/macros.h> +#include <androidfw/Util.h> + +namespace android { + +// ResourceTimer captures the duration of short functions. Durations are accumulated in registers +// and statistics are pulled back to the Java layer as needed. +// To monitor an API, first add it to the Counter enumeration. Then, inside the API, create an +// instance of ResourceTimer with the appropriate enumeral. The corresponding counter will be +// updated when the ResourceTimer destructor is called, normally at the end of the enclosing block. +class ResourceTimer { + public: + enum class Counter { + GetResourceValue, + RetrieveAttributes, + + LastCounter = RetrieveAttributes, + }; + static const int counterSize = static_cast<int>(Counter::LastCounter) + 1; + static char const *toString(Counter); + + // Start a timer for the specified counter. + ResourceTimer(Counter); + // The block is exiting. If the timer is active, record it. + ~ResourceTimer(); + // This records the elapsed time and disables further recording. Use this if the containing + // block includes extra processing that should not be included in the timer. The method is + // destructive in that the timer is no longer valid and further calls to record() will be + // ignored. + void record(); + // This cancels a timer. Elapsed time will neither be computed nor recorded. + void cancel(); + + // A single timer contains the count of events and the cumulative time spent handling the + // events. It also includes the smallest value seen and 10 largest values seen. Finally, it + // includes a histogram of values that approximates a semi-log. + + // The timer can compute percentiles of recorded events. For example, the p50 value is a time + // such that 50% of the readings are below the value and 50% are above the value. The + // granularity in the readings means that a percentile cannot always be computed. In this case, + // the percentile is reported as zero. (The simplest example is when there is a single + // reading.) Even if the value can be computed, it will not be exact. Therefore, a percentile + // is actually reported as two values: the lowest time at which it might be valid and the + // highest time at which it might be valid. + struct Timer { + static const size_t MaxLargest = 5; + + // The construct zeros all the fields. The destructor releases memory allocated to the + // buckets. + Timer(); + ~Timer(); + + // The following summary values are set to zero on a reset. All times are in ns. + + // The total number of events recorded. + int count; + // The total duration of events. + int64_t total; + // The smallest event duration seen. This is guaranteed to be non-zero if count is greater + // than 0. + int mintime; + // The largest event duration seen. + int maxtime; + + // The largest values seen. Element 0 is the largest value seen (and is the same as maxtime, + // above). Element 1 is the next largest, and so on. If count is less than MaxLargest, + // unused elements will be zero. + int largest[MaxLargest]; + + // The p50 value is a time such that 50% of the readings are below that time and 50% of the + // readings. + + // A single percentile is defined by the lowest value supported by the readings and the + // highest value supported by the readings. + struct Percentile { + // The nominal time (in ns) of the percentile. The true percentile is guaranteed to be less + // than or equal to this time. + int nominal; + // The actual percentile of the nominal time. + int nominal_actual; + // The time of the next lower bin. The true percentile is guaranteed to be greater than + // this time. + int floor; + // The actual percentile of the floor time. + int floor_actual; + + // Fill in a percentile given the cumulative to the bin, the count in the current bin, the + // total count, the width of the bin, and the time of the bin. + void compute(int cumulative, int current, int count, int width, int time); + }; + + // The structure that holds the percentiles. + struct { + Percentile p50; + Percentile p90; + Percentile p95; + Percentile p99; + } pvalues; + + // Set all counters to zero. + void reset(); + // Record an event. The input time is in ns. + void record(int); + // Compute the percentiles. Percentiles are computed on demand, as the computation is too + // expensive to be done inline. + void compute(); + + // Copy one timer to another. If reset is true then the src is reset immediately after the + // copy. The reset flag is exploited to make the copy faster. Any data in dst is lost. + static void copy(Timer &dst, Timer &src, bool reset); + + private: + // Free any buckets. + void freeBuckets(); + + // Readings are placed in bins, which are orgzanized into decades. The decade 0 covers + // [0,100) in steps of 1us. Decade 1 covers [0,1000) in steps of 10us. Decade 2 covers + // [0,10000) in steps of 100us. And so on. + + // An event is placed in the first bin that can hold it. This means that events in the range + // of [0,100) are placed in the first decade, events in the range of [0,1000) are placed in + // the second decade, and so on. This also means that the first 10% of the bins are unused + // in each decade after the first. + + // The design provides at least two significant digits across the range of [0,10000). + + static const size_t MaxDimension = 4; + static const size_t MaxBuckets = 100; + + // The range of each dimension. The lower value is always zero. + static const int range[MaxDimension]; + // The width of each bin, by dimension + static const int width[MaxDimension]; + + // A histogram of the values seen. Centuries are allocated as needed, to minimize the memory + // impact. + int *buckets[MaxDimension]; + }; + + // Fetch one Timer. The function has a short-circuit behavior: if the count is zero then + // destination count is set to zero and the function returns false. Otherwise, the destination + // is a copy of the source and the function returns true. This behavior lowers the cost of + // handling unused timers. + static bool copy(int src, Timer &dst, bool reset); + + // Enable the timers. Timers are initially disabled. Enabling timers allocates memory for the + // counters. Timers cannot be disabled. + static void enable(); + + private: + // An internal reset method. This does not take a lock. + static void reset(); + + // Helper method to convert a counter into an enum. Presumably, this will be inlined into zero + // actual cpu instructions. + static inline std::vector<unsigned int>::size_type toIndex(Counter c) { + return static_cast<std::vector<unsigned int>::size_type>(c); + } + + // Every counter has an associated lock. The lock has been factored into a separate class to + // keep the Timer class a POD. + struct GuardedTimer { + Mutex lock_; + Timer timer_; + }; + + // Scoped timer + struct ScopedTimer { + AutoMutex _l; + Timer &t; + ScopedTimer(GuardedTimer &g) : + _l(g.lock_), t(g.timer_) { + } + Timer *operator->() { + return &t; + } + Timer& operator*() { + return t; + } + }; + + // An individual timer is active (or not), is tracking a specific API, and has a start time. + // The api and the start time are undefined if the timer is not active. + bool active_; + Counter api_; + struct timespec start_; + + // The global enable flag. This is initially false and may be set true by the java runtime. + static std::atomic<bool> enabled_; + + // The global timers. The memory for the timers is not allocated until the timers are enabled. + static std::atomic<GuardedTimer *> counter_; +}; + +} // namespace android + +#endif /* ANDROIDFW_RESOURCETIMER_H_ */ diff --git a/libs/androidfw/tests/ResourceTimer_test.cpp b/libs/androidfw/tests/ResourceTimer_test.cpp new file mode 100644 index 000000000000..4a1e9735de7a --- /dev/null +++ b/libs/androidfw/tests/ResourceTimer_test.cpp @@ -0,0 +1,245 @@ +/* + * Copyright (C) 2022 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 <android-base/file.h> +#include <android-base/test_utils.h> +#include <androidfw/Util.h> + +#include "TestHelpers.h" + +#include <androidfw/ResourceTimer.h> + +namespace android { + +namespace { + +// Create a reading in us. This is a convenience function to avoid multiplying by 1000 +// everywhere. +unsigned int US(int us) { + return us * 1000; +} + +} + +TEST(ResourceTimerTest, TimerBasic) { + ResourceTimer::Timer timer; + ASSERT_THAT(timer.count, 0); + ASSERT_THAT(timer.total, 0); + + for (int i = 1; i <= 100; i++) { + timer.record(US(i)); + } + ASSERT_THAT(timer.count, 100); + ASSERT_THAT(timer.total, US((101 * 100)/2)); + ASSERT_THAT(timer.mintime, US(1)); + ASSERT_THAT(timer.maxtime, US(100)); + ASSERT_THAT(timer.pvalues.p50.floor, 0); + ASSERT_THAT(timer.pvalues.p50.nominal, 0); + ASSERT_THAT(timer.largest[0], US(100)); + ASSERT_THAT(timer.largest[1], US(99)); + ASSERT_THAT(timer.largest[2], US(98)); + ASSERT_THAT(timer.largest[3], US(97)); + ASSERT_THAT(timer.largest[4], US(96)); + timer.compute(); + ASSERT_THAT(timer.pvalues.p50.floor, US(49)); + ASSERT_THAT(timer.pvalues.p50.nominal, US(50)); + ASSERT_THAT(timer.pvalues.p90.floor, US(89)); + ASSERT_THAT(timer.pvalues.p90.nominal, US(90)); + ASSERT_THAT(timer.pvalues.p95.floor, US(94)); + ASSERT_THAT(timer.pvalues.p95.nominal, US(95)); + ASSERT_THAT(timer.pvalues.p99.floor, US(98)); + ASSERT_THAT(timer.pvalues.p99.nominal, US(99)); + + // Test reset functionality. All values should be zero after the reset. Computing pvalues + // after the result should also yield zeros. + timer.reset(); + ASSERT_THAT(timer.count, 0); + ASSERT_THAT(timer.total, 0); + ASSERT_THAT(timer.mintime, US(0)); + ASSERT_THAT(timer.maxtime, US(0)); + ASSERT_THAT(timer.pvalues.p50.floor, US(0)); + ASSERT_THAT(timer.pvalues.p50.nominal, US(0)); + ASSERT_THAT(timer.largest[0], US(0)); + ASSERT_THAT(timer.largest[1], US(0)); + ASSERT_THAT(timer.largest[2], US(0)); + ASSERT_THAT(timer.largest[3], US(0)); + ASSERT_THAT(timer.largest[4], US(0)); + timer.compute(); + ASSERT_THAT(timer.pvalues.p50.floor, US(0)); + ASSERT_THAT(timer.pvalues.p50.nominal, US(0)); + ASSERT_THAT(timer.pvalues.p90.floor, US(0)); + ASSERT_THAT(timer.pvalues.p90.nominal, US(0)); + ASSERT_THAT(timer.pvalues.p95.floor, US(0)); + ASSERT_THAT(timer.pvalues.p95.nominal, US(0)); + ASSERT_THAT(timer.pvalues.p99.floor, US(0)); + ASSERT_THAT(timer.pvalues.p99.nominal, US(0)); + + // Test again, adding elements in reverse. + for (int i = 100; i >= 1; i--) { + timer.record(US(i)); + } + ASSERT_THAT(timer.count, 100); + ASSERT_THAT(timer.total, US((101 * 100)/2)); + ASSERT_THAT(timer.mintime, US(1)); + ASSERT_THAT(timer.maxtime, US(100)); + ASSERT_THAT(timer.pvalues.p50.floor, 0); + ASSERT_THAT(timer.pvalues.p50.nominal, 0); + timer.compute(); + ASSERT_THAT(timer.pvalues.p50.floor, US(49)); + ASSERT_THAT(timer.pvalues.p50.nominal, US(50)); + ASSERT_THAT(timer.pvalues.p90.floor, US(89)); + ASSERT_THAT(timer.pvalues.p90.nominal, US(90)); + ASSERT_THAT(timer.pvalues.p95.floor, US(94)); + ASSERT_THAT(timer.pvalues.p95.nominal, US(95)); + ASSERT_THAT(timer.pvalues.p99.floor, US(98)); + ASSERT_THAT(timer.pvalues.p99.nominal, US(99)); + ASSERT_THAT(timer.largest[0], US(100)); + ASSERT_THAT(timer.largest[1], US(99)); + ASSERT_THAT(timer.largest[2], US(98)); + ASSERT_THAT(timer.largest[3], US(97)); + ASSERT_THAT(timer.largest[4], US(96)); +} + +TEST(ResourceTimerTest, TimerLimit) { + ResourceTimer::Timer timer; + + // Event truncation means that a time of 1050us will be stored in the 1000us + // bucket. Since there is a single event, all p-values lie in the same range. + timer.record(US(1050)); + timer.compute(); + ASSERT_THAT(timer.pvalues.p50.floor, US(900)); + ASSERT_THAT(timer.pvalues.p50.nominal, US(1000)); + ASSERT_THAT(timer.pvalues.p90.floor, US(900)); + ASSERT_THAT(timer.pvalues.p90.nominal, US(1000)); + ASSERT_THAT(timer.pvalues.p95.floor, US(900)); + ASSERT_THAT(timer.pvalues.p95.nominal, US(1000)); + ASSERT_THAT(timer.pvalues.p99.floor, US(900)); + ASSERT_THAT(timer.pvalues.p99.nominal, US(1000)); +} + +TEST(ResourceTimerTest, TimerCopy) { + ResourceTimer::Timer source; + for (int i = 1; i <= 100; i++) { + source.record(US(i)); + } + ResourceTimer::Timer timer; + ResourceTimer::Timer::copy(timer, source, true); + ASSERT_THAT(source.count, 0); + ASSERT_THAT(source.total, 0); + // compute() is not normally be called on a reset timer, but it should work and it should return + // all zeros. + source.compute(); + ASSERT_THAT(source.pvalues.p50.floor, US(0)); + ASSERT_THAT(source.pvalues.p50.nominal, US(0)); + ASSERT_THAT(source.pvalues.p90.floor, US(0)); + ASSERT_THAT(source.pvalues.p90.nominal, US(0)); + ASSERT_THAT(source.pvalues.p95.floor, US(0)); + ASSERT_THAT(source.pvalues.p95.nominal, US(0)); + ASSERT_THAT(source.pvalues.p99.floor, US(0)); + ASSERT_THAT(source.pvalues.p99.nominal, US(0)); + ASSERT_THAT(source.largest[0], US(0)); + ASSERT_THAT(source.largest[1], US(0)); + ASSERT_THAT(source.largest[2], US(0)); + ASSERT_THAT(source.largest[3], US(0)); + ASSERT_THAT(source.largest[4], US(0)); + + timer.compute(); + ASSERT_THAT(timer.pvalues.p50.floor, US(49)); + ASSERT_THAT(timer.pvalues.p50.nominal, US(50)); + ASSERT_THAT(timer.pvalues.p90.floor, US(89)); + ASSERT_THAT(timer.pvalues.p90.nominal, US(90)); + ASSERT_THAT(timer.pvalues.p95.floor, US(94)); + ASSERT_THAT(timer.pvalues.p95.nominal, US(95)); + ASSERT_THAT(timer.pvalues.p99.floor, US(98)); + ASSERT_THAT(timer.pvalues.p99.nominal, US(99)); + ASSERT_THAT(timer.largest[0], US(100)); + ASSERT_THAT(timer.largest[1], US(99)); + ASSERT_THAT(timer.largest[2], US(98)); + ASSERT_THAT(timer.largest[3], US(97)); + ASSERT_THAT(timer.largest[4], US(96)); + + // Call compute a second time. The values must be the same. + timer.compute(); + ASSERT_THAT(timer.pvalues.p50.floor, US(49)); + ASSERT_THAT(timer.pvalues.p50.nominal, US(50)); + ASSERT_THAT(timer.pvalues.p90.floor, US(89)); + ASSERT_THAT(timer.pvalues.p90.nominal, US(90)); + ASSERT_THAT(timer.pvalues.p95.floor, US(94)); + ASSERT_THAT(timer.pvalues.p95.nominal, US(95)); + ASSERT_THAT(timer.pvalues.p99.floor, US(98)); + ASSERT_THAT(timer.pvalues.p99.nominal, US(99)); + ASSERT_THAT(timer.largest[0], US(100)); + ASSERT_THAT(timer.largest[1], US(99)); + ASSERT_THAT(timer.largest[2], US(98)); + ASSERT_THAT(timer.largest[3], US(97)); + ASSERT_THAT(timer.largest[4], US(96)); + + // Modify the source. If timer and source share histogram arrays, this will introduce an + // error. + for (int i = 1; i <= 100; i++) { + source.record(US(i)); + } + // Call compute a third time. The values must be the same. + timer.compute(); + ASSERT_THAT(timer.pvalues.p50.floor, US(49)); + ASSERT_THAT(timer.pvalues.p50.nominal, US(50)); + ASSERT_THAT(timer.pvalues.p90.floor, US(89)); + ASSERT_THAT(timer.pvalues.p90.nominal, US(90)); + ASSERT_THAT(timer.pvalues.p95.floor, US(94)); + ASSERT_THAT(timer.pvalues.p95.nominal, US(95)); + ASSERT_THAT(timer.pvalues.p99.floor, US(98)); + ASSERT_THAT(timer.pvalues.p99.nominal, US(99)); + ASSERT_THAT(timer.largest[0], US(100)); + ASSERT_THAT(timer.largest[1], US(99)); + ASSERT_THAT(timer.largest[2], US(98)); + ASSERT_THAT(timer.largest[3], US(97)); + ASSERT_THAT(timer.largest[4], US(96)); +} + +// Verify that if too many oversize entries are reported, the percentile values cannot be computed +// and are set to zero. +TEST(ResourceTimerTest, TimerOversize) { + static const int oversize = US(2 * 1000 * 1000); + + ResourceTimer::Timer timer; + for (int i = 1; i <= 100; i++) { + timer.record(US(i)); + } + + // Insert enough oversize values to invalidate the p90, p95, and p99 percentiles. The p50 is + // still computable. + for (int i = 1; i <= 50; i++) { + timer.record(oversize); + } + ASSERT_THAT(timer.largest[0], oversize); + ASSERT_THAT(timer.largest[1], oversize); + ASSERT_THAT(timer.largest[2], oversize); + ASSERT_THAT(timer.largest[3], oversize); + ASSERT_THAT(timer.largest[4], oversize); + timer.compute(); + ASSERT_THAT(timer.pvalues.p50.floor, US(74)); + ASSERT_THAT(timer.pvalues.p50.nominal, US(75)); + ASSERT_THAT(timer.pvalues.p90.floor, 0); + ASSERT_THAT(timer.pvalues.p90.nominal, 0); + ASSERT_THAT(timer.pvalues.p95.floor, 0); + ASSERT_THAT(timer.pvalues.p95.nominal, 0); + ASSERT_THAT(timer.pvalues.p99.floor, 0); + ASSERT_THAT(timer.pvalues.p99.nominal, 0); +} + + +} // namespace android |