1 /* 2 * Copyright (C) 2022 The Android Open Source Project 3 * 4 * Licensed under the Apache License, Version 2.0 (the "License"); 5 * you may not use this file except in compliance with the License. 6 * You may obtain a copy of the License at 7 * 8 * http://www.apache.org/licenses/LICENSE-2.0 9 * 10 * Unless required by applicable law or agreed to in writing, software 11 * distributed under the License is distributed on an "AS IS" BASIS, 12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. 13 * See the License for the specific language governing permissions and 14 * limitations under the License. 15 */ 16 17 package com.android.internal.util; 18 19 import static android.provider.DeviceConfig.NAMESPACE_LATENCY_TRACKER; 20 import static android.text.TextUtils.formatSimple; 21 22 import static com.android.internal.util.FrameworkStatsLog.UI_ACTION_LATENCY_REPORTED; 23 import static com.android.internal.util.LatencyTracker.STATSD_ACTION; 24 25 import static com.google.common.truth.Truth.assertThat; 26 import static com.google.common.truth.Truth.assertWithMessage; 27 28 import android.platform.test.annotations.IgnoreUnderRavenwood; 29 import android.platform.test.ravenwood.RavenwoodRule; 30 import android.provider.DeviceConfig; 31 32 import androidx.test.runner.AndroidJUnit4; 33 34 import com.android.internal.util.LatencyTracker.ActionProperties; 35 36 import com.google.common.truth.Expect; 37 38 import org.junit.After; 39 import org.junit.Before; 40 import org.junit.Rule; 41 import org.junit.Test; 42 import org.junit.runner.RunWith; 43 44 import java.lang.reflect.Field; 45 import java.lang.reflect.Modifier; 46 import java.util.Arrays; 47 import java.util.HashMap; 48 import java.util.HashSet; 49 import java.util.List; 50 import java.util.Map; 51 import java.util.stream.Collectors; 52 53 @RunWith(AndroidJUnit4.class) 54 @IgnoreUnderRavenwood(blockedBy = DeviceConfig.class) 55 public class LatencyTrackerTest { 56 @Rule 57 public final RavenwoodRule mRavenwood = new RavenwoodRule(); 58 59 private static final String ENUM_NAME_PREFIX = "UIACTION_LATENCY_REPORTED__ACTION__"; 60 61 @Rule 62 public final Expect mExpect = Expect.create(); 63 64 // Fake is used because it tests the real logic of LatencyTracker, and it only fakes the 65 // outcomes (PerfettoTrigger and FrameworkStatsLog). 66 private FakeLatencyTracker mLatencyTracker; 67 private int mInitialSyncDisabledMode; 68 69 @Before setUp()70 public void setUp() throws Exception { 71 mInitialSyncDisabledMode = DeviceConfig.getSyncDisabledMode(); 72 DeviceConfig.setSyncDisabledMode(DeviceConfig.SYNC_DISABLED_MODE_NONE); 73 mLatencyTracker = FakeLatencyTracker.create(); 74 } 75 76 @After tearDown()77 public void tearDown() throws Exception { 78 mLatencyTracker.stopListeningForLatencyTrackerConfigChanges(); 79 DeviceConfig.setProperties( 80 new DeviceConfig.Properties.Builder(NAMESPACE_LATENCY_TRACKER).build()); 81 DeviceConfig.setSyncDisabledMode(mInitialSyncDisabledMode); 82 } 83 84 @Test testCujsMapToEnumsCorrectly()85 public void testCujsMapToEnumsCorrectly() { 86 List<Field> actions = getAllActionFields(); 87 Map<Integer, String> enumsMap = Arrays.stream(FrameworkStatsLog.class.getDeclaredFields()) 88 .filter(f -> f.getName().startsWith(ENUM_NAME_PREFIX) 89 && Modifier.isStatic(f.getModifiers()) 90 && f.getType() == int.class) 91 .collect(Collectors.toMap(this::getIntFieldChecked, Field::getName)); 92 93 assertThat(enumsMap.size() - 1).isEqualTo(actions.size()); 94 95 actions.forEach(f -> { 96 final int action = getIntFieldChecked(f); 97 final String actionName = f.getName(); 98 final String expectedEnumName = formatSimple("%s%s", ENUM_NAME_PREFIX, actionName); 99 final int enumKey = STATSD_ACTION[action]; 100 final String enumName = enumsMap.get(enumKey); 101 final String expectedActionName = LatencyTracker.getNameOfAction(enumKey); 102 mExpect 103 .withMessage(formatSimple( 104 "%s (%d) not matches %s (%d)", actionName, action, enumName, enumKey)) 105 .that(expectedEnumName.equals(enumName)) 106 .isTrue(); 107 mExpect 108 .withMessage( 109 formatSimple("getNameOfAction(%d) not matches: %s, expected=%s", 110 enumKey, actionName, expectedActionName)) 111 .that(actionName.equals(expectedActionName)) 112 .isTrue(); 113 }); 114 } 115 116 @Test testCujTypeEnumCorrectlyDefined()117 public void testCujTypeEnumCorrectlyDefined() throws Exception { 118 List<Field> cujEnumFields = getAllActionFields(); 119 HashSet<Integer> allValues = new HashSet<>(); 120 for (Field field : cujEnumFields) { 121 int fieldValue = field.getInt(null); 122 assertWithMessage( 123 "Field %s must have a mapping to a value in STATSD_ACTION", 124 field.getName()) 125 .that(fieldValue < STATSD_ACTION.length) 126 .isTrue(); 127 assertWithMessage("All CujType values must be unique. Field %s repeats existing value.", 128 field.getName()) 129 .that(allValues.add(fieldValue)) 130 .isTrue(); 131 } 132 } 133 134 @Test 135 public void testIsEnabled_trueWhenGlobalEnabled() throws Exception { 136 DeviceConfig.setProperty(NAMESPACE_LATENCY_TRACKER, 137 LatencyTracker.SETTINGS_ENABLED_KEY, "true", false); 138 mLatencyTracker.waitForGlobalEnabledState(true); 139 mLatencyTracker.waitForAllPropertiesEnableState(true); 140 141 //noinspection deprecation 142 assertThat(mLatencyTracker.isEnabled()).isTrue(); 143 } 144 145 @Test 146 public void testIsEnabled_falseWhenGlobalDisabled() throws Exception { 147 DeviceConfig.setProperty(NAMESPACE_LATENCY_TRACKER, 148 LatencyTracker.SETTINGS_ENABLED_KEY, "false", false); 149 mLatencyTracker.waitForGlobalEnabledState(false); 150 mLatencyTracker.waitForAllPropertiesEnableState(false); 151 152 //noinspection deprecation 153 assertThat(mLatencyTracker.isEnabled()).isFalse(); 154 } 155 156 @Test 157 public void testIsEnabledAction_useGlobalValueWhenActionEnableIsNotSet() 158 throws Exception { 159 // using a single test action, but this applies to all actions 160 int action = LatencyTracker.ACTION_SHOW_VOICE_INTERACTION; 161 DeviceConfig.deleteProperty(NAMESPACE_LATENCY_TRACKER, 162 "action_show_voice_interaction_enable"); 163 mLatencyTracker.waitForAllPropertiesEnableState(false); 164 DeviceConfig.setProperty(NAMESPACE_LATENCY_TRACKER, 165 LatencyTracker.SETTINGS_ENABLED_KEY, "true", false); 166 mLatencyTracker.waitForGlobalEnabledState(true); 167 mLatencyTracker.waitForAllPropertiesEnableState(true); 168 169 assertThat(mLatencyTracker.isEnabled(action)).isTrue(); 170 } 171 172 @Test 173 public void testIsEnabledAction_actionPropertyOverridesGlobalProperty() 174 throws Exception { 175 // using a single test action, but this applies to all actions 176 int action = LatencyTracker.ACTION_SHOW_VOICE_INTERACTION; 177 DeviceConfig.setProperty(NAMESPACE_LATENCY_TRACKER, 178 LatencyTracker.SETTINGS_ENABLED_KEY, "false", false); 179 mLatencyTracker.waitForGlobalEnabledState(false); 180 181 Map<String, String> deviceConfigProperties = new HashMap<>(); 182 deviceConfigProperties.put("action_show_voice_interaction_enable", "true"); 183 deviceConfigProperties.put("action_show_voice_interaction_sample_interval", "1"); 184 deviceConfigProperties.put("action_show_voice_interaction_trace_threshold", "-1"); 185 DeviceConfig.setProperties( 186 new DeviceConfig.Properties(NAMESPACE_LATENCY_TRACKER, 187 deviceConfigProperties)); 188 189 mLatencyTracker.waitForMatchingActionProperties( 190 new ActionProperties(action, true /* enabled */, 1 /* samplingInterval */, 191 -1 /* traceThreshold */)); 192 193 assertThat(mLatencyTracker.isEnabled(action)).isTrue(); 194 } 195 196 @Test 197 public void testLogsWhenEnabled() throws Exception { 198 // using a single test action, but this applies to all actions 199 int action = LatencyTracker.ACTION_SHOW_VOICE_INTERACTION; 200 Map<String, String> deviceConfigProperties = new HashMap<>(); 201 deviceConfigProperties.put("action_show_voice_interaction_enable", "true"); 202 deviceConfigProperties.put("action_show_voice_interaction_sample_interval", "1"); 203 deviceConfigProperties.put("action_show_voice_interaction_trace_threshold", "-1"); 204 DeviceConfig.setProperties( 205 new DeviceConfig.Properties(NAMESPACE_LATENCY_TRACKER, 206 deviceConfigProperties)); 207 mLatencyTracker.waitForMatchingActionProperties( 208 new ActionProperties(action, true /* enabled */, 1 /* samplingInterval */, 209 -1 /* traceThreshold */)); 210 211 mLatencyTracker.logAction(action, 1234); 212 assertThat(mLatencyTracker.getEventsWrittenToFrameworkStats(action)).hasSize(1); 213 LatencyTracker.FrameworkStatsLogEvent frameworkStatsLog = 214 mLatencyTracker.getEventsWrittenToFrameworkStats(action).get(0); 215 assertThat(frameworkStatsLog.logCode).isEqualTo(UI_ACTION_LATENCY_REPORTED); 216 assertThat(frameworkStatsLog.statsdAction).isEqualTo(STATSD_ACTION[action]); 217 assertThat(frameworkStatsLog.durationMillis).isEqualTo(1234); 218 219 mLatencyTracker.clearEvents(); 220 221 mLatencyTracker.onActionStart(action); 222 mLatencyTracker.onActionEnd(action); 223 // assert that action was logged, but we cannot confirm duration logged 224 assertThat(mLatencyTracker.getEventsWrittenToFrameworkStats(action)).hasSize(1); 225 frameworkStatsLog = mLatencyTracker.getEventsWrittenToFrameworkStats(action).get(0); 226 assertThat(frameworkStatsLog.logCode).isEqualTo(UI_ACTION_LATENCY_REPORTED); 227 assertThat(frameworkStatsLog.statsdAction).isEqualTo(STATSD_ACTION[action]); 228 } 229 230 @Test 231 public void testDoesNotLogWhenDisabled() throws Exception { 232 // using a single test action, but this applies to all actions 233 int action = LatencyTracker.ACTION_SHOW_VOICE_INTERACTION; 234 DeviceConfig.setProperty(NAMESPACE_LATENCY_TRACKER, "action_show_voice_interaction_enable", 235 "false", false); 236 mLatencyTracker.waitForActionEnabledState(action, false); 237 assertThat(mLatencyTracker.isEnabled(action)).isFalse(); 238 239 mLatencyTracker.logAction(action, 1234); 240 assertThat(mLatencyTracker.getEventsWrittenToFrameworkStats(action)).isEmpty(); 241 242 mLatencyTracker.onActionStart(action); 243 mLatencyTracker.onActionEnd(action); 244 assertThat(mLatencyTracker.getEventsWrittenToFrameworkStats(action)).isEmpty(); 245 } 246 247 @Test 248 public void testOnActionEndDoesNotLogWithoutOnActionStart() 249 throws Exception { 250 // using a single test action, but this applies to all actions 251 int action = LatencyTracker.ACTION_SHOW_VOICE_INTERACTION; 252 DeviceConfig.setProperty(NAMESPACE_LATENCY_TRACKER, "action_show_voice_interaction_enable", 253 "true", false); 254 mLatencyTracker.waitForActionEnabledState(action, true); 255 assertThat(mLatencyTracker.isEnabled(action)).isTrue(); 256 257 mLatencyTracker.onActionEnd(action); 258 assertThat(mLatencyTracker.getEventsWrittenToFrameworkStats(action)).isEmpty(); 259 } 260 261 @Test 262 public void testOnActionEndDoesNotLogWhenCanceled() 263 throws Exception { 264 // using a single test action, but this applies to all actions 265 int action = LatencyTracker.ACTION_SHOW_VOICE_INTERACTION; 266 DeviceConfig.setProperty(NAMESPACE_LATENCY_TRACKER, "action_show_voice_interaction_enable", 267 "true", false); 268 mLatencyTracker.waitForActionEnabledState(action, true); 269 assertThat(mLatencyTracker.isEnabled(action)).isTrue(); 270 271 mLatencyTracker.onActionStart(action); 272 mLatencyTracker.onActionCancel(action); 273 mLatencyTracker.onActionEnd(action); 274 assertThat(mLatencyTracker.getEventsWrittenToFrameworkStats(action)).isEmpty(); 275 } 276 277 @Test 278 public void testNeverTriggersPerfettoWhenThresholdNegative() 279 throws Exception { 280 // using a single test action, but this applies to all actions 281 int action = LatencyTracker.ACTION_SHOW_VOICE_INTERACTION; 282 Map<String, String> deviceConfigProperties = new HashMap<>(); 283 deviceConfigProperties.put("action_show_voice_interaction_enable", "true"); 284 deviceConfigProperties.put("action_show_voice_interaction_sample_interval", "1"); 285 deviceConfigProperties.put("action_show_voice_interaction_trace_threshold", "-1"); 286 DeviceConfig.setProperties( 287 new DeviceConfig.Properties(NAMESPACE_LATENCY_TRACKER, 288 deviceConfigProperties)); 289 mLatencyTracker.waitForMatchingActionProperties( 290 new ActionProperties(action, true /* enabled */, 1 /* samplingInterval */, 291 -1 /* traceThreshold */)); 292 293 mLatencyTracker.onActionStart(action); 294 mLatencyTracker.onActionEnd(action); 295 assertThat(mLatencyTracker.getTriggeredPerfettoTraceNames()).isEmpty(); 296 } 297 298 @Test 299 public void testNeverTriggersPerfettoWhenDisabled() 300 throws Exception { 301 // using a single test action, but this applies to all actions 302 int action = LatencyTracker.ACTION_SHOW_VOICE_INTERACTION; 303 Map<String, String> deviceConfigProperties = new HashMap<>(); 304 deviceConfigProperties.put("action_show_voice_interaction_enable", "false"); 305 deviceConfigProperties.put("action_show_voice_interaction_sample_interval", "1"); 306 deviceConfigProperties.put("action_show_voice_interaction_trace_threshold", "1"); 307 DeviceConfig.setProperties( 308 new DeviceConfig.Properties(NAMESPACE_LATENCY_TRACKER, 309 deviceConfigProperties)); 310 mLatencyTracker.waitForMatchingActionProperties( 311 new ActionProperties(action, false /* enabled */, 1 /* samplingInterval */, 312 1 /* traceThreshold */)); 313 314 mLatencyTracker.onActionStart(action); 315 mLatencyTracker.onActionEnd(action); 316 assertThat(mLatencyTracker.getTriggeredPerfettoTraceNames()).isEmpty(); 317 } 318 319 @Test 320 public void testTriggersPerfettoWhenAboveThreshold() 321 throws Exception { 322 // using a single test action, but this applies to all actions 323 int action = LatencyTracker.ACTION_SHOW_VOICE_INTERACTION; 324 Map<String, String> deviceConfigProperties = new HashMap<>(); 325 deviceConfigProperties.put("action_show_voice_interaction_enable", "true"); 326 deviceConfigProperties.put("action_show_voice_interaction_sample_interval", "1"); 327 deviceConfigProperties.put("action_show_voice_interaction_trace_threshold", "1"); 328 DeviceConfig.setProperties( 329 new DeviceConfig.Properties(NAMESPACE_LATENCY_TRACKER, 330 deviceConfigProperties)); 331 mLatencyTracker.waitForMatchingActionProperties( 332 new ActionProperties(action, true /* enabled */, 1 /* samplingInterval */, 333 1 /* traceThreshold */)); 334 335 mLatencyTracker.onActionStart(action); 336 // We need to sleep here to ensure that the end call is past the set trace threshold (1ms) 337 Thread.sleep(5 /* millis */); 338 mLatencyTracker.onActionEnd(action); 339 assertThat(mLatencyTracker.getTriggeredPerfettoTraceNames()).hasSize(1); 340 assertThat(mLatencyTracker.getTriggeredPerfettoTraceNames().get(0)).isEqualTo( 341 "com.android.telemetry.latency-tracker-ACTION_SHOW_VOICE_INTERACTION"); 342 } 343 344 @Test 345 public void testNeverTriggersPerfettoWhenBelowThreshold() 346 throws Exception { 347 // using a single test action, but this applies to all actions 348 int action = LatencyTracker.ACTION_SHOW_VOICE_INTERACTION; 349 Map<String, String> deviceConfigProperties = new HashMap<>(); 350 deviceConfigProperties.put("action_show_voice_interaction_enable", "true"); 351 deviceConfigProperties.put("action_show_voice_interaction_sample_interval", "1"); 352 deviceConfigProperties.put("action_show_voice_interaction_trace_threshold", "1000"); 353 DeviceConfig.setProperties( 354 new DeviceConfig.Properties(NAMESPACE_LATENCY_TRACKER, 355 deviceConfigProperties)); 356 mLatencyTracker.waitForMatchingActionProperties( 357 new ActionProperties(action, true /* enabled */, 1 /* samplingInterval */, 358 1000 /* traceThreshold */)); 359 360 mLatencyTracker.onActionStart(action); 361 // No sleep here to ensure that end call comes before 1000ms threshold 362 mLatencyTracker.onActionEnd(action); 363 assertThat(mLatencyTracker.getTriggeredPerfettoTraceNames()).isEmpty(); 364 } 365 366 private List<Field> getAllActionFields() { 367 return Arrays.stream(LatencyTracker.class.getDeclaredFields()).filter( 368 field -> field.getName().startsWith("ACTION_") && Modifier.isStatic( 369 field.getModifiers()) && field.getType() == int.class).collect( 370 Collectors.toList()); 371 } 372 getIntFieldChecked(Field field)373 private int getIntFieldChecked(Field field) { 374 try { 375 return field.getInt(null); 376 } catch (IllegalAccessException ex) { 377 throw new RuntimeException(ex); 378 } 379 } 380 } 381