From a353b287e38bff9139f0d5f157131c19d436773c Mon Sep 17 00:00:00 2001 From: Nicholas Ambur Date: Thu, 15 Dec 2022 06:17:18 +0000 Subject: [PATCH] add LatencyTracter per action device properties Each action LatencyTracker can log is controlled by gobal enable, tracing threshold, and sampling rate DeviceConfig properties. This change adds the ability to control properties per action. By setting an action specific parameter, it will override the associated global parameter. New parameters added: - _enable - _sample_interval - _trace_threshold Bug: 260609037 Test: atest LatencyTrackerTest Change-Id: I258a078074ca82a8837246c7b16407ab21ba1edf --- .../android/internal/util/LatencyTracker.java | 119 +++++++++++++++-- .../internal/util/LatencyTrackerTest.java | 126 ++++++++++++++++-- 2 files changed, 222 insertions(+), 23 deletions(-) diff --git a/core/java/com/android/internal/util/LatencyTracker.java b/core/java/com/android/internal/util/LatencyTracker.java index 4b7b91c74f94e..afb526aeea6fb 100644 --- a/core/java/com/android/internal/util/LatencyTracker.java +++ b/core/java/com/android/internal/util/LatencyTracker.java @@ -37,12 +37,17 @@ import static com.android.internal.util.FrameworkStatsLog.UIACTION_LATENCY_REPOR import static com.android.internal.util.FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_UDFPS_ILLUMINATE; import static com.android.internal.util.FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_USER_SWITCH; import static com.android.internal.util.FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__UNKNOWN_ACTION; +import static com.android.internal.util.LatencyTracker.ActionProperties.ENABLE_SUFFIX; +import static com.android.internal.util.LatencyTracker.ActionProperties.LEGACY_TRACE_THRESHOLD_SUFFIX; +import static com.android.internal.util.LatencyTracker.ActionProperties.SAMPLE_INTERVAL_SUFFIX; +import static com.android.internal.util.LatencyTracker.ActionProperties.TRACE_THRESHOLD_SUFFIX; import android.annotation.IntDef; import android.annotation.NonNull; import android.annotation.Nullable; import android.content.Context; import android.os.Build; +import android.os.ConditionVariable; import android.os.SystemClock; import android.os.Trace; import android.provider.DeviceConfig; @@ -58,6 +63,7 @@ import com.android.internal.os.BackgroundThread; import java.lang.annotation.Retention; import java.lang.annotation.RetentionPolicy; +import java.util.Locale; import java.util.concurrent.ThreadLocalRandom; import java.util.concurrent.TimeUnit; @@ -261,11 +267,11 @@ public class LatencyTracker { @GuardedBy("mLock") private final SparseArray mSessions = new SparseArray<>(); @GuardedBy("mLock") - private final int[] mTraceThresholdPerAction = new int[ACTIONS_ALL.length]; - @GuardedBy("mLock") - private int mSamplingInterval; + private final SparseArray mActionPropertiesMap = new SparseArray<>(); @GuardedBy("mLock") private boolean mEnabled; + @VisibleForTesting + public final ConditionVariable mDeviceConfigPropertiesUpdated = new ConditionVariable(); public static LatencyTracker getInstance(Context context) { if (sLatencyTracker == null) { @@ -278,9 +284,9 @@ public class LatencyTracker { return sLatencyTracker; } - private LatencyTracker() { + @VisibleForTesting + public LatencyTracker() { mEnabled = DEFAULT_ENABLED; - mSamplingInterval = DEFAULT_SAMPLING_INTERVAL; // Post initialization to the background in case we're running on the main thread. BackgroundThread.getHandler().post(() -> this.updateProperties( @@ -291,14 +297,24 @@ public class LatencyTracker { private void updateProperties(DeviceConfig.Properties properties) { synchronized (mLock) { - mSamplingInterval = properties.getInt(SETTINGS_SAMPLING_INTERVAL_KEY, + int samplingInterval = properties.getInt(SETTINGS_SAMPLING_INTERVAL_KEY, DEFAULT_SAMPLING_INTERVAL); mEnabled = properties.getBoolean(SETTINGS_ENABLED_KEY, DEFAULT_ENABLED); for (int action : ACTIONS_ALL) { - mTraceThresholdPerAction[action] = - properties.getInt(getNameOfAction(STATSD_ACTION[action]), -1); + String actionName = getNameOfAction(STATSD_ACTION[action]).toLowerCase(Locale.ROOT); + int legacyActionTraceThreshold = properties.getInt( + actionName + LEGACY_TRACE_THRESHOLD_SUFFIX, -1); + mActionPropertiesMap.put(action, new ActionProperties(action, + properties.getBoolean(actionName + ENABLE_SUFFIX, mEnabled), + properties.getInt(actionName + SAMPLE_INTERVAL_SUFFIX, samplingInterval), + properties.getInt(actionName + TRACE_THRESHOLD_SUFFIX, + legacyActionTraceThreshold))); + } + if (DEBUG) { + Log.d(TAG, "updated action properties: " + mActionPropertiesMap); } } + mDeviceConfigPropertiesUpdated.open(); } /** @@ -369,16 +385,38 @@ public class LatencyTracker { return "com.android.telemetry.latency-tracker-" + getNameOfAction(STATSD_ACTION[action]); } + /** + * @deprecated Use {@link #isEnabled(Context, int)} + */ + @Deprecated public static boolean isEnabled(Context ctx) { return getInstance(ctx).isEnabled(); } + /** + * @deprecated Used {@link #isEnabled(int)} + */ + @Deprecated public boolean isEnabled() { synchronized (mLock) { return mEnabled; } } + public static boolean isEnabled(Context ctx, int action) { + return getInstance(ctx).isEnabled(action); + } + + public boolean isEnabled(int action) { + synchronized (mLock) { + ActionProperties actionProperties = mActionPropertiesMap.get(action); + if (actionProperties != null) { + return actionProperties.isEnabled(); + } + return false; + } + } + /** * Notifies that an action is starting. This needs to be called from the main thread. * @@ -468,8 +506,14 @@ public class LatencyTracker { boolean shouldSample; int traceThreshold; synchronized (mLock) { - shouldSample = ThreadLocalRandom.current().nextInt(mSamplingInterval) == 0; - traceThreshold = mTraceThresholdPerAction[action]; + ActionProperties actionProperties = mActionPropertiesMap.get(action); + if (actionProperties == null) { + return; + } + int nextRandNum = ThreadLocalRandom.current().nextInt( + actionProperties.getSamplingInterval()); + shouldSample = nextRandNum == 0; + traceThreshold = actionProperties.getTraceThreshold(); } if (traceThreshold > 0 && duration >= traceThreshold) { @@ -549,4 +593,59 @@ public class LatencyTracker { return (int) (mEndRtc - mStartRtc); } } + + @VisibleForTesting + static class ActionProperties { + static final String ENABLE_SUFFIX = "_enable"; + static final String SAMPLE_INTERVAL_SUFFIX = "_sample_interval"; + // TODO: migrate all usages of the legacy trace theshold property + static final String LEGACY_TRACE_THRESHOLD_SUFFIX = ""; + static final String TRACE_THRESHOLD_SUFFIX = "_trace_threshold"; + + @Action + private final int mAction; + private final boolean mEnabled; + private final int mSamplingInterval; + private final int mTraceThreshold; + + ActionProperties( + @Action int action, + boolean enabled, + int samplingInterval, + int traceThreshold) { + this.mAction = action; + com.android.internal.util.AnnotationValidations.validate( + Action.class, null, mAction); + this.mEnabled = enabled; + this.mSamplingInterval = samplingInterval; + this.mTraceThreshold = traceThreshold; + } + + @Action + int getAction() { + return mAction; + } + + boolean isEnabled() { + return mEnabled; + } + + int getSamplingInterval() { + return mSamplingInterval; + } + + int getTraceThreshold() { + return mTraceThreshold; + } + + @Override + public String toString() { + return "ActionProperties{" + + " mAction=" + mAction + + ", mEnabled=" + mEnabled + + ", mSamplingInterval=" + mSamplingInterval + + ", mTraceThreshold=" + mTraceThreshold + + "}"; + } + } } diff --git a/core/tests/coretests/src/com/android/internal/util/LatencyTrackerTest.java b/core/tests/coretests/src/com/android/internal/util/LatencyTrackerTest.java index e384e699333b9..d1f0b5e1dd304 100644 --- a/core/tests/coretests/src/com/android/internal/util/LatencyTrackerTest.java +++ b/core/tests/coretests/src/com/android/internal/util/LatencyTrackerTest.java @@ -23,36 +23,53 @@ import static com.android.internal.util.LatencyTracker.STATSD_ACTION; import static com.google.common.truth.Truth.assertThat; import static com.google.common.truth.Truth.assertWithMessage; +import android.provider.DeviceConfig; +import android.util.Log; + +import androidx.test.ext.junit.runners.AndroidJUnit4; import androidx.test.filters.SmallTest; import com.google.common.truth.Expect; +import org.junit.Before; import org.junit.Rule; import org.junit.Test; +import org.junit.runner.RunWith; import java.lang.reflect.Field; import java.lang.reflect.Modifier; +import java.time.Duration; import java.util.Arrays; +import java.util.HashMap; import java.util.HashSet; import java.util.List; import java.util.Map; import java.util.stream.Collectors; @SmallTest +@RunWith(AndroidJUnit4.class) public class LatencyTrackerTest { + private static final String TAG = LatencyTrackerTest.class.getSimpleName(); private static final String ENUM_NAME_PREFIX = "UIACTION_LATENCY_REPORTED__ACTION__"; + private static final String ACTION_ENABLE_SUFFIX = "_enable"; + private static final Duration TEST_TIMEOUT = Duration.ofMillis(500); @Rule public final Expect mExpect = Expect.create(); + @Before + public void setUp() { + DeviceConfig.deleteProperty(DeviceConfig.NAMESPACE_LATENCY_TRACKER, + LatencyTracker.SETTINGS_ENABLED_KEY); + getAllActions().forEach(action -> { + DeviceConfig.deleteProperty(DeviceConfig.NAMESPACE_LATENCY_TRACKER, + action.getName().toLowerCase() + ACTION_ENABLE_SUFFIX); + }); + } + @Test public void testCujsMapToEnumsCorrectly() { - List actions = Arrays.stream(LatencyTracker.class.getDeclaredFields()) - .filter(f -> f.getName().startsWith("ACTION_") - && Modifier.isStatic(f.getModifiers()) - && f.getType() == int.class) - .collect(Collectors.toList()); - + List actions = getAllActions(); Map enumsMap = Arrays.stream(FrameworkStatsLog.class.getDeclaredFields()) .filter(f -> f.getName().startsWith(ENUM_NAME_PREFIX) && Modifier.isStatic(f.getModifiers()) @@ -84,13 +101,7 @@ public class LatencyTrackerTest { @Test public void testCujTypeEnumCorrectlyDefined() throws Exception { - List cujEnumFields = - Arrays.stream(LatencyTracker.class.getDeclaredFields()) - .filter(field -> field.getName().startsWith("ACTION_") - && Modifier.isStatic(field.getModifiers()) - && field.getType() == int.class) - .collect(Collectors.toList()); - + List cujEnumFields = getAllActions(); HashSet allValues = new HashSet<>(); for (Field field : cujEnumFields) { int fieldValue = field.getInt(null); @@ -106,6 +117,95 @@ public class LatencyTrackerTest { } } + @Test + public void testIsEnabled_globalEnabled() { + DeviceConfig.setProperty(DeviceConfig.NAMESPACE_LATENCY_TRACKER, + LatencyTracker.SETTINGS_ENABLED_KEY, "true", false); + LatencyTracker latencyTracker = new LatencyTracker(); + waitForLatencyTrackerToUpdateProperties(latencyTracker); + assertThat(latencyTracker.isEnabled()).isTrue(); + } + + @Test + public void testIsEnabled_globalDisabled() { + DeviceConfig.setProperty(DeviceConfig.NAMESPACE_LATENCY_TRACKER, + LatencyTracker.SETTINGS_ENABLED_KEY, "false", false); + LatencyTracker latencyTracker = new LatencyTracker(); + waitForLatencyTrackerToUpdateProperties(latencyTracker); + assertThat(latencyTracker.isEnabled()).isFalse(); + } + + @Test + public void testIsEnabledAction_useGlobalValueWhenActionEnableIsNotSet() { + LatencyTracker latencyTracker = new LatencyTracker(); + // using a single test action, but this applies to all actions + int action = LatencyTracker.ACTION_SHOW_VOICE_INTERACTION; + Log.i(TAG, "setting property=" + LatencyTracker.SETTINGS_ENABLED_KEY + ", value=true"); + latencyTracker.mDeviceConfigPropertiesUpdated.close(); + DeviceConfig.setProperty(DeviceConfig.NAMESPACE_LATENCY_TRACKER, + LatencyTracker.SETTINGS_ENABLED_KEY, "true", false); + waitForLatencyTrackerToUpdateProperties(latencyTracker); + assertThat( + latencyTracker.isEnabled(action)).isTrue(); + + Log.i(TAG, "setting property=" + LatencyTracker.SETTINGS_ENABLED_KEY + + ", value=false"); + latencyTracker.mDeviceConfigPropertiesUpdated.close(); + DeviceConfig.setProperty(DeviceConfig.NAMESPACE_LATENCY_TRACKER, + LatencyTracker.SETTINGS_ENABLED_KEY, "false", false); + waitForLatencyTrackerToUpdateProperties(latencyTracker); + assertThat(latencyTracker.isEnabled(action)).isFalse(); + } + + @Test + public void testIsEnabledAction_actionPropertyOverridesGlobalProperty() + throws DeviceConfig.BadConfigException { + LatencyTracker latencyTracker = new LatencyTracker(); + // using a single test action, but this applies to all actions + int action = LatencyTracker.ACTION_SHOW_VOICE_INTERACTION; + String actionEnableProperty = "action_show_voice_interaction" + ACTION_ENABLE_SUFFIX; + Log.i(TAG, "setting property=" + actionEnableProperty + ", value=true"); + + latencyTracker.mDeviceConfigPropertiesUpdated.close(); + Map properties = new HashMap() {{ + put(LatencyTracker.SETTINGS_ENABLED_KEY, "false"); + put(actionEnableProperty, "true"); + }}; + DeviceConfig.setProperties( + new DeviceConfig.Properties(DeviceConfig.NAMESPACE_LATENCY_TRACKER, + properties)); + waitForLatencyTrackerToUpdateProperties(latencyTracker); + assertThat(latencyTracker.isEnabled(action)).isTrue(); + + latencyTracker.mDeviceConfigPropertiesUpdated.close(); + Log.i(TAG, "setting property=" + actionEnableProperty + ", value=false"); + properties.put(LatencyTracker.SETTINGS_ENABLED_KEY, "true"); + properties.put(actionEnableProperty, "false"); + DeviceConfig.setProperties( + new DeviceConfig.Properties(DeviceConfig.NAMESPACE_LATENCY_TRACKER, + properties)); + waitForLatencyTrackerToUpdateProperties(latencyTracker); + assertThat(latencyTracker.isEnabled(action)).isFalse(); + } + + private void waitForLatencyTrackerToUpdateProperties(LatencyTracker latencyTracker) { + try { + Thread.sleep(TEST_TIMEOUT.toMillis()); + } catch (InterruptedException e) { + e.printStackTrace(); + } + assertThat(latencyTracker.mDeviceConfigPropertiesUpdated.block( + TEST_TIMEOUT.toMillis())).isTrue(); + } + + private List getAllActions() { + return Arrays.stream(LatencyTracker.class.getDeclaredFields()) + .filter(field -> field.getName().startsWith("ACTION_") + && Modifier.isStatic(field.getModifiers()) + && field.getType() == int.class) + .collect(Collectors.toList()); + } + private int getIntFieldChecked(Field field) { try { return field.getInt(null);