xref: /frameworks/base/core/java/android/content/res/ResourceTimer.java

/*
 * 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.app.AppProtoEnums;
import android.os.Handler;
import android.os.Looper;
import android.os.Message;
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 com.android.internal.util.FrameworkStatsLog;

import java.io.FileDescriptor;
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;

    /**
     * This array contains the statsd enum associated with each timer entry.  A value of NONE (0)
     * means that the entry should not be logged to statsd.  (This would be the case for timers
     * that are created for temporary debugging.)
     */
    @GuardedBy("sLock")
    private static int[] sApiMap;

    /**
     * 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];
            }
            // Map the values returned from the runtime to statsd enumerals  The runtime may
            // return timers that are not meant to be logged via statsd.  Such timers are mapped
            // to RESOURCE_API_NONE.
            sApiMap = new int[sConfig.maxTimer];
            for (int i = 0; i < sApiMap.length; i++) {
                if (sConfig.timers[i].equals("GetResourceValue")) {
                    sApiMap[i] = AppProtoEnums.RESOURCE_API_GET_VALUE;
                } else if (sConfig.timers[i].equals("RetrieveAttributes")) {
                    sApiMap[i] = AppProtoEnums.RESOURCE_API_RETRIEVE_ATTRIBUTES;
                } else {
                    sApiMap[i] = AppProtoEnums.RESOURCE_API_NONE;
                }
            }

            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.
            final long repeated = sPublicationPoints[sPublicationPoints.length - 1];
            final int prelude = sPublicationPoints.length - 1;
            delay = (sCurrentPoint - prelude) * repeated;
        }
        // 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++) {
            var timer = sTimers[i];
            if (timer.count > 0) {
                Log.i(TAG, TextUtils.formatSimple("%s count=%d pvalues=%s",
                                sConfig.timers[i], timer.count, packedString(timer.percentile)));
                if (sApiMap[i] != AppProtoEnums.RESOURCE_API_NONE) {
                    FrameworkStatsLog.write(FrameworkStatsLog.RESOURCE_API_INFO,
                            sApiMap[i],
                            timer.count, timer.total,
                            timer.percentile[0], timer.percentile[1],
                            timer.percentile[2], timer.percentile[3],
                            timer.largest[0], timer.largest[1], timer.largest[2],
                            timer.largest[3], timer.largest[4]);
                }
            }
        }
        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 FileDescriptor fd, String... args) {
        try (PrintWriter pw = new FastPrintWriter(new FileOutputStream(fd))) {
            pw.println("\nDumping ResourceTimers");

            final boolean enabled;
            synchronized (sLock) {
                enabled = sEnabled && sConfig != null;
            }
            if (!enabled) {
                pw.println("  Timers are not enabled in this process");
                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));
                    }
                }
            }
        }
    }

    // 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);
}