1 /* 2 * Copyright (C) 2017 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 package com.android.media.tests; 17 18 import static java.nio.file.StandardCopyOption.REPLACE_EXISTING; 19 20 import com.android.ddmlib.NullOutputReceiver; 21 import com.android.media.tests.AudioLoopbackImageAnalyzer.Result; 22 import com.android.media.tests.AudioLoopbackTestHelper.LogFileType; 23 import com.android.media.tests.AudioLoopbackTestHelper.ResultData; 24 import com.android.tradefed.config.Option; 25 import com.android.tradefed.device.DeviceNotAvailableException; 26 import com.android.tradefed.device.ITestDevice; 27 import com.android.tradefed.log.LogUtil.CLog; 28 import com.android.tradefed.result.FileInputStreamSource; 29 import com.android.tradefed.result.ITestInvocationListener; 30 import com.android.tradefed.result.InputStreamSource; 31 import com.android.tradefed.result.LogDataType; 32 import com.android.tradefed.result.TestDescription; 33 import com.android.tradefed.testtype.IDeviceTest; 34 import com.android.tradefed.testtype.IRemoteTest; 35 import com.android.tradefed.util.FileUtil; 36 import com.android.tradefed.util.RunUtil; 37 38 import java.io.File; 39 import java.io.IOException; 40 import java.nio.file.Files; 41 import java.util.Arrays; 42 import java.util.Collections; 43 import java.util.Date; 44 import java.util.HashMap; 45 import java.util.List; 46 import java.util.Map; 47 import java.util.concurrent.TimeUnit; 48 49 /** 50 * Runs Audio Latency and Audio Glitch test and reports result. 51 * 52 * <p>Strategy for Audio Latency Stress test: RUN test 1000 times. In each iteration, collect result 53 * files from device, parse and collect data in a ResultData object that also keeps track of 54 * location to test files for a particular iteration. 55 * 56 * <p>ANALYZE test results to produce statistics for 1. Latency and Confidence (Min, Max, Mean, 57 * Median) 2. Create CSV file with test run data 3. Print bad test data to host log file 4. Get 58 * number of test runs with valid data to send to dashboard 5. Produce histogram in host log file; 59 * count number of test results that fall into 1 ms wide buckets. 60 * 61 * <p>UPLOAD test results + log files from “bad” runs; i.e. runs that is missing some or all result 62 * data. 63 */ 64 public class AudioLoopbackTest implements IDeviceTest, IRemoteTest { 65 66 //=================================================================== 67 // TEST OPTIONS 68 //=================================================================== 69 @Option(name = "run-key", description = "Run key for the test") 70 private String mRunKey = "AudioLoopback"; 71 72 @Option(name = "sampling-freq", description = "Sampling Frequency for Loopback app") 73 private String mSamplingFreq = "48000"; 74 75 @Option(name = "mic-source", description = "Mic Source for Loopback app") 76 private String mMicSource = "3"; 77 78 @Option(name = "audio-thread", description = "Audio Thread for Loopback app") 79 private String mAudioThread = "1"; 80 81 @Option( 82 name = "audio-level", 83 description = 84 "Audio Level for Loopback app. A device specific" 85 + "param which makes waveform in loopback test hit 60% to 80% range" 86 ) 87 private String mAudioLevel = "-1"; 88 89 @Option(name = "test-type", description = "Test type to be executed") 90 private String mTestType = TESTTYPE_LATENCY_STR; 91 92 @Option(name = "buffer-test-duration", description = "Buffer test duration in seconds") 93 private String mBufferTestDuration = "10"; 94 95 @Option(name = "key-prefix", description = "Key Prefix for reporting") 96 private String mKeyPrefix = "48000_Mic3_"; 97 98 @Option(name = "iterations", description = "Number of test iterations") 99 private int mIterations = 1; 100 101 @Option(name = "baseline_latency", description = "") 102 private float mBaselineLatency = 0f; 103 104 //=================================================================== 105 // CLASS VARIABLES 106 //=================================================================== 107 private static final Map<String, String> METRICS_KEY_MAP = createMetricsKeyMap(); 108 private Map<LogFileType, LogFileData> mFileDataKeyMap; 109 private ITestDevice mDevice; 110 private TestRunHelper mTestRunHelper; 111 private AudioLoopbackTestHelper mLoopbackTestHelper; 112 113 //=================================================================== 114 // CONSTANTS 115 //=================================================================== 116 private static final String TESTTYPE_LATENCY_STR = "222"; 117 private static final String TESTTYPE_GLITCH_STR = "223"; 118 private static final long TIMEOUT_MS = 5 * 60 * 1000; // 5 min 119 private static final long DEVICE_SYNC_MS = 5 * 60 * 1000; // 5 min 120 private static final long POLLING_INTERVAL_MS = 5 * 1000; 121 private static final int MAX_ATTEMPTS = 3; 122 private static final int MAX_NR_OF_LOG_UPLOADS = 100; 123 124 private static final int LATENCY_ITERATIONS_LOWER_BOUND = 1; 125 private static final int LATENCY_ITERATIONS_UPPER_BOUND = 10000; 126 private static final int GLITCH_ITERATIONS_LOWER_BOUND = 1; 127 private static final int GLITCH_ITERATIONS_UPPER_BOUND = 1; 128 129 private static final String DEVICE_TEMP_DIR_PATH = "/sdcard/"; 130 private static final String FMT_OUTPUT_PREFIX = "output_%1$d_" + System.currentTimeMillis(); 131 private static final String FMT_DEVICE_FILENAME = FMT_OUTPUT_PREFIX + "%2$s"; 132 private static final String FMT_DEVICE_PATH = DEVICE_TEMP_DIR_PATH + FMT_DEVICE_FILENAME; 133 134 private static final String AM_CMD = 135 "am start -n org.drrickorang.loopback/.LoopbackActivity" 136 + " --ei SF %s --es FileName %s --ei MicSource %s --ei AudioThread %s" 137 + " --ei AudioLevel %s --ei TestType %s --ei BufferTestDuration %s"; 138 139 private static final String ERR_PARAMETER_OUT_OF_BOUNDS = 140 "Test parameter '%1$s' is out of bounds. Lower limit = %2$d, upper limit = %3$d"; 141 142 private static final String KEY_RESULT_LATENCY_MS = "latency_ms"; 143 private static final String KEY_RESULT_LATENCY_CONFIDENCE = "latency_confidence"; 144 private static final String KEY_RESULT_RECORDER_BENCHMARK = "recorder_benchmark"; 145 private static final String KEY_RESULT_RECORDER_OUTLIER = "recorder_outliers"; 146 private static final String KEY_RESULT_PLAYER_BENCHMARK = "player_benchmark"; 147 private static final String KEY_RESULT_PLAYER_OUTLIER = "player_outliers"; 148 private static final String KEY_RESULT_NUMBER_OF_GLITCHES = "number_of_glitches"; 149 private static final String KEY_RESULT_RECORDER_BUFFER_CALLBACK = "late_recorder_callbacks"; 150 private static final String KEY_RESULT_PLAYER_BUFFER_CALLBACK = "late_player_callbacks"; 151 private static final String KEY_RESULT_GLITCHES_PER_HOUR = "glitches_per_hour"; 152 private static final String KEY_RESULT_TEST_STATUS = "test_status"; 153 private static final String KEY_RESULT_AUDIO_LEVEL = "audio_level"; 154 private static final String KEY_RESULT_RMS = "rms"; 155 private static final String KEY_RESULT_RMS_AVERAGE = "rms_average"; 156 private static final String KEY_RESULT_SAMPLING_FREQUENCY_CONFIDENCE = "sampling_frequency"; 157 private static final String KEY_RESULT_PERIOD_CONFIDENCE = "period_confidence"; 158 private static final String KEY_RESULT_SAMPLING_BLOCK_SIZE = "block_size"; 159 160 private static final String REDUCED_GLITCHES_TEST_DURATION = "600"; // 10 min 161 162 private static final LogFileType[] LATENCY_TEST_LOGS = { 163 LogFileType.RESULT, 164 LogFileType.GRAPH, 165 LogFileType.WAVE, 166 LogFileType.PLAYER_BUFFER, 167 LogFileType.PLAYER_BUFFER_HISTOGRAM, 168 LogFileType.PLAYER_BUFFER_PERIOD_TIMES, 169 LogFileType.RECORDER_BUFFER, 170 LogFileType.RECORDER_BUFFER_HISTOGRAM, 171 LogFileType.RECORDER_BUFFER_PERIOD_TIMES, 172 LogFileType.LOGCAT 173 }; 174 175 private static final LogFileType[] GLITCH_TEST_LOGS = { 176 LogFileType.RESULT, 177 LogFileType.GRAPH, 178 LogFileType.WAVE, 179 LogFileType.PLAYER_BUFFER, 180 LogFileType.PLAYER_BUFFER_HISTOGRAM, 181 LogFileType.PLAYER_BUFFER_PERIOD_TIMES, 182 LogFileType.RECORDER_BUFFER, 183 LogFileType.RECORDER_BUFFER_HISTOGRAM, 184 LogFileType.RECORDER_BUFFER_PERIOD_TIMES, 185 LogFileType.GLITCHES_MILLIS, 186 LogFileType.HEAT_MAP, 187 LogFileType.LOGCAT 188 }; 189 190 /** 191 * The Audio Latency and Audio Glitch test deals with many various types of log files. To be 192 * able to generate log files in a generic manner, this map is provided to get access to log 193 * file properties like log name prefix, log name file extension and log type (leveraging 194 * tradefed class LogDataType, used when uploading log). 195 */ getLogFileDataKeyMap()196 private final synchronized Map<LogFileType, LogFileData> getLogFileDataKeyMap() { 197 if (mFileDataKeyMap != null) { 198 return mFileDataKeyMap; 199 } 200 201 final Map<LogFileType, LogFileData> result = new HashMap<LogFileType, LogFileData>(); 202 203 // Populate dictionary with info about various types of logfiles 204 LogFileData l = new LogFileData(".txt", "result", LogDataType.TEXT); 205 result.put(LogFileType.RESULT, l); 206 207 l = new LogFileData(".png", "graph", LogDataType.PNG); 208 result.put(LogFileType.GRAPH, l); 209 210 l = new LogFileData(".wav", "wave", LogDataType.UNKNOWN); 211 result.put(LogFileType.WAVE, l); 212 213 l = new LogFileData("_playerBufferPeriod.txt", "player_buffer", LogDataType.TEXT); 214 result.put(LogFileType.PLAYER_BUFFER, l); 215 216 l = new LogFileData("_playerBufferPeriod.png", "player_buffer_histogram", LogDataType.PNG); 217 result.put(LogFileType.PLAYER_BUFFER_HISTOGRAM, l); 218 219 String fileExtension = "_playerBufferPeriodTimes.txt"; 220 String uploadName = "player_buffer_period_times"; 221 l = new LogFileData(fileExtension, uploadName, LogDataType.TEXT); 222 result.put(LogFileType.PLAYER_BUFFER_PERIOD_TIMES, l); 223 224 l = new LogFileData("_recorderBufferPeriod.txt", "recorder_buffer", LogDataType.TEXT); 225 result.put(LogFileType.RECORDER_BUFFER, l); 226 227 fileExtension = "_recorderBufferPeriod.png"; 228 uploadName = "recorder_buffer_histogram"; 229 l = new LogFileData(fileExtension, uploadName, LogDataType.PNG); 230 result.put(LogFileType.RECORDER_BUFFER_HISTOGRAM, l); 231 232 fileExtension = "_recorderBufferPeriodTimes.txt"; 233 uploadName = "recorder_buffer_period_times"; 234 l = new LogFileData(fileExtension, uploadName, LogDataType.TEXT); 235 result.put(LogFileType.RECORDER_BUFFER_PERIOD_TIMES, l); 236 237 l = new LogFileData("_glitchMillis.txt", "glitches_millis", LogDataType.TEXT); 238 result.put(LogFileType.GLITCHES_MILLIS, l); 239 240 241 l = new LogFileData("_heatMap.png", "heat_map", LogDataType.PNG); 242 result.put(LogFileType.HEAT_MAP, l); 243 244 l = new LogFileData(".txt", "logcat", LogDataType.TEXT); 245 result.put(LogFileType.LOGCAT, l); 246 247 mFileDataKeyMap = Collections.unmodifiableMap(result); 248 return mFileDataKeyMap; 249 } 250 createMetricsKeyMap()251 private static final Map<String, String> createMetricsKeyMap() { 252 final Map<String, String> result = new HashMap<String, String>(); 253 254 result.put("LatencyMs", KEY_RESULT_LATENCY_MS); 255 result.put("LatencyConfidence", KEY_RESULT_LATENCY_CONFIDENCE); 256 result.put("SF", KEY_RESULT_SAMPLING_FREQUENCY_CONFIDENCE); 257 result.put("Recorder Benchmark", KEY_RESULT_RECORDER_BENCHMARK); 258 result.put("Recorder Number of Outliers", KEY_RESULT_RECORDER_OUTLIER); 259 result.put("Player Benchmark", KEY_RESULT_PLAYER_BENCHMARK); 260 result.put("Player Number of Outliers", KEY_RESULT_PLAYER_OUTLIER); 261 result.put("Total Number of Glitches", KEY_RESULT_NUMBER_OF_GLITCHES); 262 result.put("kth% Late Recorder Buffer Callbacks", KEY_RESULT_RECORDER_BUFFER_CALLBACK); 263 result.put("kth% Late Player Buffer Callbacks", KEY_RESULT_PLAYER_BUFFER_CALLBACK); 264 result.put("Glitches Per Hour", KEY_RESULT_GLITCHES_PER_HOUR); 265 result.put("Test Status", KEY_RESULT_TEST_STATUS); 266 result.put("AudioLevel", KEY_RESULT_AUDIO_LEVEL); 267 result.put("RMS", KEY_RESULT_RMS); 268 result.put("Average", KEY_RESULT_RMS_AVERAGE); 269 result.put("PeriodConfidence", KEY_RESULT_PERIOD_CONFIDENCE); 270 result.put("BS", KEY_RESULT_SAMPLING_BLOCK_SIZE); 271 272 return Collections.unmodifiableMap(result); 273 } 274 275 //=================================================================== 276 // ENUMS 277 //=================================================================== 278 public enum TestType { 279 GLITCH, 280 LATENCY, 281 LATENCY_STRESS, 282 NONE 283 } 284 285 //=================================================================== 286 // INNER CLASSES 287 //=================================================================== 288 public final class LogFileData { 289 private String fileExtension; 290 private String filePrefix; 291 private LogDataType logDataType; 292 LogFileData(String fileExtension, String filePrefix, LogDataType logDataType)293 private LogFileData(String fileExtension, String filePrefix, LogDataType logDataType) { 294 this.fileExtension = fileExtension; 295 this.filePrefix = filePrefix; 296 this.logDataType = logDataType; 297 } 298 } 299 300 //=================================================================== 301 // FUNCTIONS 302 //=================================================================== 303 304 /** {@inheritDoc} */ 305 @Override setDevice(ITestDevice device)306 public void setDevice(ITestDevice device) { 307 mDevice = device; 308 } 309 310 /** {@inheritDoc} */ 311 @Override getDevice()312 public ITestDevice getDevice() { 313 return mDevice; 314 } 315 316 /** 317 * Test Entry Point 318 * 319 * <p>{@inheritDoc} 320 */ 321 @Override run(ITestInvocationListener listener)322 public void run(ITestInvocationListener listener) throws DeviceNotAvailableException { 323 324 initializeTest(listener); 325 326 mTestRunHelper.startTest(1); 327 328 Map<String, String> metrics = null; 329 try { 330 if (!verifyTestParameters()) { 331 return; 332 } 333 334 // Stop logcat logging so we can record one logcat log per iteration 335 getDevice().stopLogcat(); 336 337 switch (getTestType()) { 338 case GLITCH: 339 runGlitchesTest(mTestRunHelper, mLoopbackTestHelper); 340 break; 341 case LATENCY: 342 case LATENCY_STRESS: 343 // Run test iterations 344 runLatencyTest(mLoopbackTestHelper, mIterations); 345 break; 346 default: 347 break; 348 } 349 350 mLoopbackTestHelper.processTestData(); 351 metrics = uploadLogsReturnMetrics(listener); 352 CLog.i("Uploading metrics values:\n" + Arrays.toString(metrics.entrySet().toArray())); 353 mTestRunHelper.endTest(metrics); 354 } catch (TestFailureException e) { 355 CLog.i("TestRunHelper.reportFailure triggered"); 356 } finally { 357 CLog.i("Test ended - cleanup"); 358 deleteAllTempFiles(); 359 getDevice().startLogcat(); 360 } 361 } 362 runLatencyTest(AudioLoopbackTestHelper loopbackTestHelper, int iterations)363 private void runLatencyTest(AudioLoopbackTestHelper loopbackTestHelper, int iterations) 364 throws DeviceNotAvailableException, TestFailureException { 365 for (int i = 0; i < iterations; i++) { 366 CLog.i("---- Iteration " + i + " of " + (iterations - 1) + " -----"); 367 368 final ResultData d = new ResultData(); 369 d.setIteration(i); 370 Map<String, String> resultsDictionary = null; 371 resultsDictionary = runTest(d, getSingleTestTimeoutValue()); 372 loopbackTestHelper.addTestData(d, resultsDictionary, true); 373 } 374 } 375 376 /** 377 * Glitches test, strategy: 378 * <p> 379 * 380 * <ul> 381 * <li>1. Calibrate Audio level 382 * <li>2. Run Audio Latency test until seeing good waveform 383 * <li>3. Run small Glitches test, 5-10 seconds 384 * <li>4. If numbers look good, run long Glitches test, else run reduced Glitches test 385 * </ul> 386 * 387 * @param testRunHelper 388 * @param loopbackTestHelper 389 * @throws DeviceNotAvailableException 390 * @throws TestFailureException 391 */ runGlitchesTest(TestRunHelper testRunHelper, AudioLoopbackTestHelper loopbackTestHelper)392 private void runGlitchesTest(TestRunHelper testRunHelper, 393 AudioLoopbackTestHelper loopbackTestHelper) 394 throws DeviceNotAvailableException, TestFailureException { 395 final int MAX_RETRIES = 3; 396 int nrOfSuccessfulTests; 397 int counter = 0; 398 AudioLoopbackTestHelper tempTestHelper = null; 399 boolean runningReducedGlitchesTest = false; 400 401 // Step 1: Calibrate Audio level 402 // Step 2: Run Audio Latency test until seeing good waveform 403 final int LOOPBACK_ITERATIONS = 4; 404 final String originalTestType = mTestType; 405 final String originalBufferTestDuration = mBufferTestDuration; 406 mTestType = TESTTYPE_LATENCY_STR; 407 do { 408 nrOfSuccessfulTests = 0; 409 tempTestHelper = new AudioLoopbackTestHelper(LOOPBACK_ITERATIONS); 410 runLatencyTest(tempTestHelper, LOOPBACK_ITERATIONS); 411 nrOfSuccessfulTests = tempTestHelper.processTestData(); 412 counter++; 413 } while (nrOfSuccessfulTests <= 0 && counter <= MAX_RETRIES); 414 415 if (nrOfSuccessfulTests <= 0) { 416 testRunHelper.reportFailure("Glitch Setup failed: Latency test"); 417 } 418 419 // Retrieve audio level from successful test 420 int audioLevel = -1; 421 List<ResultData> results = tempTestHelper.getAllTestData(); 422 for (ResultData rd : results) { 423 // Check if test passed 424 if (rd.getImageAnalyzerResult() == Result.PASS && rd.getConfidence() == 1.0) { 425 audioLevel = rd.getAudioLevel(); 426 break; 427 } 428 } 429 430 if (audioLevel < 6) { 431 testRunHelper.reportFailure("Glitch Setup failed: Audio level not valid"); 432 } 433 434 CLog.i("Audio Glitch: Audio level is " + audioLevel); 435 436 // Step 3: Run small Glitches test, 5-10 seconds 437 mTestType = originalTestType; 438 mBufferTestDuration = "10"; 439 mAudioLevel = Integer.toString(audioLevel); 440 441 counter = 0; 442 int glitches = -1; 443 do { 444 tempTestHelper = new AudioLoopbackTestHelper(1); 445 runLatencyTest(tempTestHelper, 1); 446 Map<String, String> resultsDictionary = 447 tempTestHelper.getResultDictionaryForIteration(0); 448 final String nrOfGlitches = 449 resultsDictionary.get(getMetricsKey(KEY_RESULT_NUMBER_OF_GLITCHES)); 450 glitches = Integer.parseInt(nrOfGlitches); 451 CLog.i("10 s glitch test produced " + glitches + " glitches"); 452 counter++; 453 } while (glitches > 10 || glitches < 0 && counter <= MAX_RETRIES); 454 455 // Step 4: If numbers look good, run long Glitches test 456 if (glitches > 10 || glitches < 0) { 457 // Reduce test time and set some values to 0 once test completes 458 runningReducedGlitchesTest = true; 459 mBufferTestDuration = REDUCED_GLITCHES_TEST_DURATION; 460 } else { 461 mBufferTestDuration = originalBufferTestDuration; 462 } 463 464 final ResultData d = new ResultData(); 465 d.setIteration(0); 466 Map<String, String> resultsDictionary = null; 467 resultsDictionary = runTest(d, getSingleTestTimeoutValue()); 468 if (runningReducedGlitchesTest) { 469 // Special treatment, we want to upload values, but also indicate that pre-test 470 // conditions failed. We will set the glitches count and zero out the rest. 471 String[] testValuesToChangeArray = new String[] { 472 KEY_RESULT_RECORDER_BENCHMARK, 473 KEY_RESULT_RECORDER_OUTLIER, 474 KEY_RESULT_PLAYER_BENCHMARK, 475 KEY_RESULT_PLAYER_OUTLIER, 476 KEY_RESULT_RECORDER_BUFFER_CALLBACK, 477 KEY_RESULT_PLAYER_BUFFER_CALLBACK 478 }; 479 480 for (String key : testValuesToChangeArray) { 481 final String metricsKey = getMetricsKey(key); 482 if (resultsDictionary.containsKey(metricsKey)) { 483 resultsDictionary.put(metricsKey, "0"); 484 } 485 } 486 } 487 488 loopbackTestHelper.addTestData(d, resultsDictionary, false); 489 } 490 initializeTest(ITestInvocationListener listener)491 private void initializeTest(ITestInvocationListener listener) 492 throws UnsupportedOperationException, DeviceNotAvailableException { 493 494 mFileDataKeyMap = getLogFileDataKeyMap(); 495 TestDescription testId = new TestDescription(getClass().getCanonicalName(), mRunKey); 496 497 // Allocate helpers 498 mTestRunHelper = new TestRunHelper(listener, testId); 499 mLoopbackTestHelper = new AudioLoopbackTestHelper(mIterations); 500 501 getDevice().disableKeyguard(); 502 getDevice().waitForDeviceAvailable(DEVICE_SYNC_MS); 503 504 getDevice().setDate(new Date()); 505 CLog.i("syncing device time to host time"); 506 } 507 runTest(ResultData data, final long timeout)508 private Map<String, String> runTest(ResultData data, final long timeout) 509 throws DeviceNotAvailableException, TestFailureException { 510 511 // start measurement and wait for result file 512 final NullOutputReceiver receiver = new NullOutputReceiver(); 513 514 final String loopbackCmd = getTestCommand(data.getIteration()); 515 CLog.i("Loopback cmd: " + loopbackCmd); 516 517 // Clear logcat 518 // Seems like getDevice().clearLogcat(); doesn't do anything? 519 // Do it through ADB 520 getDevice().executeAdbCommand("logcat", "-c"); 521 final long deviceTestStartTime = getDevice().getDeviceDate(); 522 523 getDevice() 524 .executeShellCommand( 525 loopbackCmd, receiver, TIMEOUT_MS, TimeUnit.MILLISECONDS, MAX_ATTEMPTS); 526 527 final long loopbackStartTime = System.currentTimeMillis(); 528 File loopbackReport = null; 529 530 data.setDeviceTestStartTime(deviceTestStartTime); 531 532 // Try to retrieve result file from device. 533 final String resultFilename = getDeviceFilename(LogFileType.RESULT, data.getIteration()); 534 do { 535 RunUtil.getDefault().sleep(POLLING_INTERVAL_MS); 536 if (getDevice().doesFileExist(resultFilename)) { 537 // Store device log files in tmp directory on Host and add to ResultData object 538 storeDeviceFilesOnHost(data); 539 final String reportFilename = data.getLogFile(LogFileType.RESULT); 540 if (reportFilename != null && !reportFilename.isEmpty()) { 541 loopbackReport = new File(reportFilename); 542 if (loopbackReport.length() > 0) { 543 break; 544 } 545 } 546 } 547 548 data.setIsTimedOut(System.currentTimeMillis() - loopbackStartTime >= timeout); 549 } while (!data.hasLogFile(LogFileType.RESULT) && !data.isTimedOut()); 550 551 // Grab logcat for iteration 552 try (final InputStreamSource lc = getDevice().getLogcatSince(deviceTestStartTime)) { 553 saveLogcatForIteration(data, lc, data.getIteration()); 554 } 555 556 // Check if test timed out. If so, don't fail the test, but return to upper logic. 557 // We accept certain number of individual test timeouts. 558 if (data.isTimedOut()) { 559 // No device result files retrieved, so no need to parse 560 return null; 561 } 562 563 // parse result 564 Map<String, String> loopbackResult = null; 565 566 try { 567 loopbackResult = 568 AudioLoopbackTestHelper.parseKeyValuePairFromFile( 569 loopbackReport, METRICS_KEY_MAP, mKeyPrefix, "=", "%s: %s"); 570 populateResultData(loopbackResult, data); 571 572 // Trust but verify, so get Audio Level from ADB and compare to value from app 573 final int adbAudioLevel = 574 AudioLevelUtility.extractDeviceHeadsetLevelFromAdbShell(getDevice()); 575 if (adbAudioLevel > -1 && data.getAudioLevel() != adbAudioLevel) { 576 final String errMsg = 577 String.format( 578 "App Audio Level (%1$d) differs from ADB level (%2$d)", 579 data.getAudioLevel(), adbAudioLevel); 580 mTestRunHelper.reportFailure(errMsg); 581 } 582 } catch (final IOException ioe) { 583 CLog.e(ioe); 584 mTestRunHelper.reportFailure("I/O error while parsing Loopback result."); 585 } catch (final NumberFormatException ne) { 586 CLog.e(ne); 587 mTestRunHelper.reportFailure("Number format error parsing Loopback result."); 588 } 589 590 return loopbackResult; 591 } 592 getMetricsKey(final String key)593 private String getMetricsKey(final String key) { 594 return mKeyPrefix + key; 595 } getSingleTestTimeoutValue()596 private final long getSingleTestTimeoutValue() { 597 return Long.parseLong(mBufferTestDuration) * 1000 + TIMEOUT_MS; 598 } 599 uploadLogsReturnMetrics(ITestInvocationListener listener)600 private Map<String, String> uploadLogsReturnMetrics(ITestInvocationListener listener) 601 throws DeviceNotAvailableException, TestFailureException { 602 603 // "resultDictionary" is used to post results to dashboards like BlackBox 604 // "results" contains test logs to be uploaded; i.e. to Sponge 605 606 List<ResultData> results = null; 607 Map<String, String> resultDictionary = new HashMap<String, String>(); 608 609 switch (getTestType()) { 610 case GLITCH: 611 resultDictionary = mLoopbackTestHelper.getResultDictionaryForIteration(0); 612 // Upload all test files to be backward compatible with old test 613 results = mLoopbackTestHelper.getAllTestData(); 614 break; 615 case LATENCY: 616 { 617 final int nrOfValidResults = mLoopbackTestHelper.processTestData(); 618 if (nrOfValidResults == 0) { 619 mTestRunHelper.reportFailure("No good data was collected"); 620 } else { 621 // use dictionary collected from single test run 622 resultDictionary = mLoopbackTestHelper.getResultDictionaryForIteration(0); 623 } 624 625 // Upload all test files to be backward compatible with old test 626 results = mLoopbackTestHelper.getAllTestData(); 627 } 628 break; 629 case LATENCY_STRESS: 630 { 631 final int nrOfValidResults = mLoopbackTestHelper.processTestData(); 632 if (nrOfValidResults == 0) { 633 mTestRunHelper.reportFailure("No good data was collected"); 634 } else { 635 mLoopbackTestHelper.populateStressTestMetrics(resultDictionary, mKeyPrefix); 636 } 637 638 results = mLoopbackTestHelper.getWorstResults(MAX_NR_OF_LOG_UPLOADS); 639 640 // Save all test data in a spreadsheet style csv file for post test analysis 641 try { 642 saveResultsAsCSVFile(listener); 643 } catch (final IOException e) { 644 CLog.e(e); 645 } 646 } 647 break; 648 default: 649 break; 650 } 651 652 // Upload relevant logs 653 for (final ResultData d : results) { 654 final LogFileType[] logFileTypes = getLogFileTypesForCurrentTest(); 655 for (final LogFileType logType : logFileTypes) { 656 uploadLog(listener, logType, d); 657 } 658 } 659 660 return resultDictionary; 661 } 662 getTestType()663 private TestType getTestType() { 664 if (mTestType.equals(TESTTYPE_GLITCH_STR)) { 665 if (GLITCH_ITERATIONS_LOWER_BOUND <= mIterations 666 && mIterations <= GLITCH_ITERATIONS_UPPER_BOUND) { 667 return TestType.GLITCH; 668 } 669 } 670 671 if (mTestType.equals(TESTTYPE_LATENCY_STR)) { 672 if (mIterations == 1) { 673 return TestType.LATENCY; 674 } 675 676 if (LATENCY_ITERATIONS_LOWER_BOUND <= mIterations 677 && mIterations <= LATENCY_ITERATIONS_UPPER_BOUND) { 678 return TestType.LATENCY_STRESS; 679 } 680 } 681 682 return TestType.NONE; 683 } 684 verifyTestParameters()685 private boolean verifyTestParameters() throws TestFailureException { 686 if (getTestType() != TestType.NONE) { 687 return true; 688 } 689 690 if (mTestType.equals(TESTTYPE_GLITCH_STR) 691 && (mIterations < GLITCH_ITERATIONS_LOWER_BOUND 692 || mIterations > GLITCH_ITERATIONS_UPPER_BOUND)) { 693 final String error = 694 String.format( 695 ERR_PARAMETER_OUT_OF_BOUNDS, 696 "iterations", 697 GLITCH_ITERATIONS_LOWER_BOUND, 698 GLITCH_ITERATIONS_UPPER_BOUND); 699 mTestRunHelper.reportFailure(error); 700 return false; 701 } 702 703 if (mTestType.equals(TESTTYPE_LATENCY_STR) 704 && (mIterations < LATENCY_ITERATIONS_LOWER_BOUND 705 || mIterations > LATENCY_ITERATIONS_UPPER_BOUND)) { 706 final String error = 707 String.format( 708 ERR_PARAMETER_OUT_OF_BOUNDS, 709 "iterations", 710 LATENCY_ITERATIONS_LOWER_BOUND, 711 LATENCY_ITERATIONS_UPPER_BOUND); 712 mTestRunHelper.reportFailure(error); 713 return false; 714 } 715 716 return true; 717 } 718 populateResultData(final Map<String, String> results, ResultData data)719 private void populateResultData(final Map<String, String> results, ResultData data) { 720 if (results == null || results.isEmpty()) { 721 return; 722 } 723 724 String key = getMetricsKey(KEY_RESULT_LATENCY_MS); 725 if (results.containsKey(key)) { 726 data.setLatency(Float.parseFloat(results.get(key))); 727 } 728 729 key = getMetricsKey(KEY_RESULT_LATENCY_CONFIDENCE); 730 if (results.containsKey(key)) { 731 data.setConfidence(Float.parseFloat(results.get(key))); 732 } 733 734 key = getMetricsKey(KEY_RESULT_AUDIO_LEVEL); 735 if (results.containsKey(key)) { 736 data.setAudioLevel(Integer.parseInt(results.get(key))); 737 } 738 739 key = getMetricsKey(KEY_RESULT_RMS); 740 if (results.containsKey(key)) { 741 data.setRMS(Float.parseFloat(results.get(key))); 742 } 743 744 key = getMetricsKey(KEY_RESULT_RMS_AVERAGE); 745 if (results.containsKey(key)) { 746 data.setRMSAverage(Float.parseFloat(results.get(key))); 747 } 748 749 key = getMetricsKey(KEY_RESULT_PERIOD_CONFIDENCE); 750 if (results.containsKey(key)) { 751 data.setPeriodConfidence(Float.parseFloat(results.get(key))); 752 } 753 754 key = getMetricsKey(KEY_RESULT_SAMPLING_BLOCK_SIZE); 755 if (results.containsKey(key)) { 756 data.setBlockSize(Integer.parseInt(results.get(key))); 757 } 758 } 759 storeDeviceFilesOnHost(ResultData data)760 private void storeDeviceFilesOnHost(ResultData data) throws DeviceNotAvailableException { 761 final int iteration = data.getIteration(); 762 for (final LogFileType log : getLogFileTypesForCurrentTest()) { 763 if (getDevice().doesFileExist(getDeviceFilename(log, iteration))) { 764 final String deviceFileName = getDeviceFilename(log, iteration); 765 final File logFile = getDevice().pullFile(deviceFileName); 766 data.setLogFile(log, logFile.getAbsolutePath()); 767 CLog.i("Delete file from device: " + deviceFileName); 768 deleteFileFromDevice(deviceFileName); 769 } 770 } 771 } 772 deleteAllTempFiles()773 private void deleteAllTempFiles() { 774 for (final ResultData d : mLoopbackTestHelper.getAllTestData()) { 775 final LogFileType[] logFileTypes = getLogFileTypesForCurrentTest(); 776 for (final LogFileType logType : logFileTypes) { 777 final String logFilename = d.getLogFile(logType); 778 if (logFilename == null || logFilename.isEmpty()) { 779 CLog.e("Logfile not found for LogFileType=" + logType.name()); 780 } else { 781 FileUtil.deleteFile(new File(logFilename)); 782 } 783 } 784 } 785 } 786 deleteFileFromDevice(String deviceFileName)787 private void deleteFileFromDevice(String deviceFileName) throws DeviceNotAvailableException { 788 getDevice().executeShellCommand("rm -f " + deviceFileName); 789 } 790 getLogFileTypesForCurrentTest()791 private final LogFileType[] getLogFileTypesForCurrentTest() { 792 switch (getTestType()) { 793 case GLITCH: 794 return GLITCH_TEST_LOGS; 795 case LATENCY: 796 case LATENCY_STRESS: 797 return LATENCY_TEST_LOGS; 798 default: 799 return null; 800 } 801 } 802 getKeyPrefixForIteration(int iteration)803 private String getKeyPrefixForIteration(int iteration) { 804 if (mIterations == 1) { 805 // If only one run, skip the iteration number 806 return mKeyPrefix; 807 } 808 return mKeyPrefix + iteration + "_"; 809 } 810 getDeviceFilename(LogFileType key, int iteration)811 private String getDeviceFilename(LogFileType key, int iteration) { 812 final Map<LogFileType, LogFileData> map = getLogFileDataKeyMap(); 813 if (map.containsKey(key)) { 814 final LogFileData data = map.get(key); 815 return String.format(FMT_DEVICE_PATH, iteration, data.fileExtension); 816 } 817 return null; 818 } 819 uploadLog(ITestInvocationListener listener, LogFileType key, ResultData data)820 private void uploadLog(ITestInvocationListener listener, LogFileType key, ResultData data) { 821 final Map<LogFileType, LogFileData> map = getLogFileDataKeyMap(); 822 if (!map.containsKey(key)) { 823 return; 824 } 825 826 final LogFileData logInfo = map.get(key); 827 final String prefix = getKeyPrefixForIteration(data.getIteration()) + logInfo.filePrefix; 828 final LogDataType logDataType = logInfo.logDataType; 829 final String logFilename = data.getLogFile(key); 830 if (logFilename == null || logFilename.isEmpty()) { 831 CLog.e("Logfile not found for LogFileType=" + key.name()); 832 } else { 833 File logFile = new File(logFilename); 834 try (InputStreamSource iss = new FileInputStreamSource(logFile)) { 835 listener.testLog(prefix, logDataType, iss); 836 } 837 } 838 } 839 saveLogcatForIteration(ResultData data, InputStreamSource logcat, int iteration)840 private void saveLogcatForIteration(ResultData data, InputStreamSource logcat, int iteration) { 841 if (logcat == null) { 842 CLog.i("Logcat could not be saved for iteration " + iteration); 843 return; 844 } 845 846 //create a temp file 847 File temp; 848 try { 849 temp = FileUtil.createTempFile("logcat_" + iteration + "_", ".txt"); 850 data.setLogFile(LogFileType.LOGCAT, temp.getAbsolutePath()); 851 852 // Copy logcat data into temp file 853 Files.copy(logcat.createInputStream(), temp.toPath(), REPLACE_EXISTING); 854 logcat.close(); 855 } catch (final IOException e) { 856 CLog.i("Error when saving logcat for iteration=" + iteration); 857 CLog.e(e); 858 } 859 } 860 saveResultsAsCSVFile(ITestInvocationListener listener)861 private void saveResultsAsCSVFile(ITestInvocationListener listener) 862 throws DeviceNotAvailableException, IOException { 863 final File csvTmpFile = File.createTempFile("audio_test_data", "csv"); 864 mLoopbackTestHelper.writeAllResultsToCSVFile(csvTmpFile, getDevice()); 865 try (InputStreamSource iss = new FileInputStreamSource(csvTmpFile)) { 866 listener.testLog("audio_test_data", LogDataType.JACOCO_CSV, iss); 867 } 868 // cleanup 869 csvTmpFile.delete(); 870 } 871 getTestCommand(int currentIteration)872 private String getTestCommand(int currentIteration) { 873 return String.format( 874 AM_CMD, 875 mSamplingFreq, 876 String.format(FMT_OUTPUT_PREFIX, currentIteration), 877 mMicSource, 878 mAudioThread, 879 mAudioLevel, 880 mTestType, 881 mBufferTestDuration); 882 } 883 } 884