1 /* 2 * Copyright (C) 2015 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.media.tests; 18 19 import com.android.ddmlib.CollectingOutputReceiver; 20 import com.android.tradefed.config.IConfiguration; 21 import com.android.tradefed.config.IConfigurationReceiver; 22 import com.android.tradefed.config.Option; 23 import com.android.tradefed.device.DeviceNotAvailableException; 24 import com.android.tradefed.device.ITestDevice; 25 import com.android.tradefed.log.LogUtil.CLog; 26 import com.android.tradefed.metrics.proto.MetricMeasurement.Metric; 27 import com.android.tradefed.result.ByteArrayInputStreamSource; 28 import com.android.tradefed.result.CollectingTestListener; 29 import com.android.tradefed.result.FileInputStreamSource; 30 import com.android.tradefed.result.ITestInvocationListener; 31 import com.android.tradefed.result.InputStreamSource; 32 import com.android.tradefed.result.LogDataType; 33 import com.android.tradefed.result.TestDescription; 34 import com.android.tradefed.testtype.IDeviceTest; 35 import com.android.tradefed.testtype.IRemoteTest; 36 import com.android.tradefed.testtype.InstrumentationTest; 37 import com.android.tradefed.util.FileUtil; 38 import com.android.tradefed.util.IRunUtil; 39 import com.android.tradefed.util.RunUtil; 40 import com.android.tradefed.util.StreamUtil; 41 import com.android.tradefed.util.proto.TfMetricProtoUtil; 42 43 import org.junit.Assert; 44 45 import java.io.BufferedReader; 46 import java.io.BufferedWriter; 47 import java.io.File; 48 import java.io.FileWriter; 49 import java.io.IOException; 50 import java.io.StringReader; 51 import java.util.ArrayList; 52 import java.util.Collection; 53 import java.util.HashMap; 54 import java.util.Map; 55 import java.util.Timer; 56 import java.util.TimerTask; 57 import java.util.concurrent.TimeUnit; 58 59 /** 60 * Camera test base class 61 * 62 * Camera2StressTest, CameraStartupTest, Camera2LatencyTest and CameraPerformanceTest use this base 63 * class for Camera ivvavik and later. 64 */ 65 public class CameraTestBase implements IDeviceTest, IRemoteTest, IConfigurationReceiver { 66 67 private static final long SHELL_TIMEOUT_MS = 60 * 1000; // 1 min 68 private static final int SHELL_MAX_ATTEMPTS = 3; 69 protected static final String PROCESS_CAMERA_DAEMON = "mm-qcamera-daemon"; 70 protected static final String PROCESS_MEDIASERVER = "mediaserver"; 71 protected static final String PROCESS_CAMERA_APP = "com.google.android.GoogleCamera"; 72 protected static final String DUMP_ION_HEAPS_COMMAND = "cat /d/ion/heaps/system"; 73 protected static final String ARGUMENT_TEST_ITERATIONS = "iterations"; 74 75 @Option(name = "test-package", description = "Test package to run.") 76 private String mTestPackage = "com.google.android.camera"; 77 78 @Option(name = "test-class", description = "Test class to run.") 79 private String mTestClass = null; 80 81 @Option(name = "test-methods", description = "Test method to run. May be repeated.") 82 private Collection<String> mTestMethods = new ArrayList<>(); 83 84 @Option(name = "test-runner", description = "Test runner for test instrumentation.") 85 private String mTestRunner = "android.test.InstrumentationTestRunner"; 86 87 @Option(name = "test-timeout", description = "Max time allowed in ms for a test run.") 88 private int mTestTimeoutMs = 60 * 60 * 1000; // 1 hour 89 90 @Option(name = "shell-timeout", 91 description="The defined timeout (in milliseconds) is used as a maximum waiting time " 92 + "when expecting the command output from the device. At any time, if the " 93 + "shell command does not output anything for a period longer than defined " 94 + "timeout the TF run terminates. For no timeout, set to 0.") 95 private long mShellTimeoutMs = 60 * 60 * 1000; // default to 1 hour 96 97 @Option(name = "ru-key", description = "Result key to use when posting to the dashboard.") 98 private String mRuKey = null; 99 100 @Option(name = "logcat-on-failure", description = 101 "take a logcat snapshot on every test failure.") 102 private boolean mLogcatOnFailure = false; 103 104 @Option( 105 name = "instrumentation-arg", 106 description = "Additional instrumentation arguments to provide." 107 ) 108 private Map<String, String> mInstrArgMap = new HashMap<>(); 109 110 @Option(name = "dump-meminfo", description = 111 "take a dumpsys meminfo at a given interval time.") 112 private boolean mDumpMeminfo = false; 113 114 @Option(name="dump-meminfo-interval-ms", 115 description="Interval of calling dumpsys meminfo in milliseconds.") 116 private int mMeminfoIntervalMs = 5 * 60 * 1000; // 5 minutes 117 118 @Option(name = "dump-ion-heap", description = 119 "dump ION allocations at the end of test.") 120 private boolean mDumpIonHeap = false; 121 122 @Option(name = "dump-thread-count", description = 123 "Count the number of threads in Camera process at a given interval time.") 124 private boolean mDumpThreadCount = false; 125 126 @Option(name="dump-thread-count-interval-ms", 127 description="Interval of calling ps to count the number of threads in milliseconds.") 128 private int mThreadCountIntervalMs = 5 * 60 * 1000; // 5 minutes 129 130 @Option(name="iterations", description="The number of iterations to run. Default to 1. " 131 + "This takes effect only when Camera2InstrumentationTestRunner is used to execute " 132 + "framework stress tests.") 133 private int mIterations = 1; 134 135 private ITestDevice mDevice = null; 136 137 // A base listener to collect the results from each test run. Test results will be forwarded 138 // to other listeners. 139 private AbstractCollectingListener mCollectingListener = null; 140 141 private long mStartTimeMs = 0; 142 143 private MeminfoTimer mMeminfoTimer = null; 144 private ThreadTrackerTimer mThreadTrackerTimer = null; 145 146 protected IConfiguration mConfiguration; 147 148 /** 149 * {@inheritDoc} 150 */ 151 @Override run(ITestInvocationListener listener)152 public void run(ITestInvocationListener listener) throws DeviceNotAvailableException { 153 // ignore 154 } 155 156 /** 157 * Run Camera instrumentation test with a default listener. 158 * 159 * @param listener the ITestInvocationListener of test results 160 * @throws DeviceNotAvailableException 161 */ runInstrumentationTest(ITestInvocationListener listener)162 protected void runInstrumentationTest(ITestInvocationListener listener) 163 throws DeviceNotAvailableException { 164 if (mCollectingListener == null) { 165 mCollectingListener = new DefaultCollectingListener(listener); 166 } 167 runInstrumentationTest(listener, mCollectingListener); 168 } 169 170 /** 171 * Run Camera instrumentation test with a listener to gather the metrics from the individual 172 * test runs. 173 * 174 * @param listener the ITestInvocationListener of test results 175 * @param collectingListener the {@link CollectingTestListener} to collect the metrics from 176 * test runs 177 * @throws DeviceNotAvailableException 178 */ runInstrumentationTest(ITestInvocationListener listener, AbstractCollectingListener collectingListener)179 protected void runInstrumentationTest(ITestInvocationListener listener, 180 AbstractCollectingListener collectingListener) 181 throws DeviceNotAvailableException { 182 Assert.assertNotNull(collectingListener); 183 mCollectingListener = collectingListener; 184 185 InstrumentationTest instr = new InstrumentationTest(); 186 instr.setDevice(getDevice()); 187 instr.setPackageName(getTestPackage()); 188 instr.setRunnerName(getTestRunner()); 189 instr.setClassName(getTestClass()); 190 instr.setTestTimeout(getTestTimeoutMs()); 191 instr.setShellTimeout(getShellTimeoutMs()); 192 instr.setLogcatOnFailure(mLogcatOnFailure); 193 instr.setRunName(getRuKey()); 194 instr.setRerunMode(false); 195 196 // Set test iteration. 197 if (getIterationCount() > 1) { 198 CLog.v("Setting test iterations: %d", getIterationCount()); 199 Map<String, String> instrArgMap = getInstrumentationArgMap(); 200 instrArgMap.put(ARGUMENT_TEST_ITERATIONS, String.valueOf(getIterationCount())); 201 } 202 203 for (Map.Entry<String, String> entry : getInstrumentationArgMap().entrySet()) { 204 instr.addInstrumentationArg(entry.getKey(), entry.getValue()); 205 } 206 207 // Check if dumpheap needs to be taken for native processes before test runs. 208 if (shouldDumpMeminfo()) { 209 mMeminfoTimer = new MeminfoTimer(0, mMeminfoIntervalMs); 210 } 211 if (shouldDumpThreadCount()) { 212 long delayMs = mThreadCountIntervalMs / 2; // Not to run all dump at the same interval. 213 mThreadTrackerTimer = new ThreadTrackerTimer(delayMs, mThreadCountIntervalMs); 214 } 215 216 // Run tests. 217 mStartTimeMs = System.currentTimeMillis(); 218 if (mTestMethods.size() > 0) { 219 CLog.d(String.format("The number of test methods is: %d", mTestMethods.size())); 220 for (String testName : mTestMethods) { 221 instr.setMethodName(testName); 222 instr.run(mCollectingListener); 223 } 224 } else { 225 instr.run(mCollectingListener); 226 } 227 228 dumpIonHeaps(mCollectingListener, getTestClass()); 229 } 230 231 /** 232 * A base listener to collect all test results and metrics from Camera instrumentation test run. 233 * Abstract methods can be overridden to handle test metrics or inform of test run ended. 234 */ 235 protected abstract class AbstractCollectingListener extends CollectingTestListener { 236 237 private ITestInvocationListener mListener = null; 238 private Map<String, String> mMetrics = new HashMap<>(); 239 private Map<String, String> mFatalErrors = new HashMap<>(); 240 241 private static final String INCOMPLETE_TEST_ERR_MSG_PREFIX = 242 "Test failed to run to completion. Reason: 'Instrumentation run failed"; 243 AbstractCollectingListener(ITestInvocationListener listener)244 public AbstractCollectingListener(ITestInvocationListener listener) { 245 mListener = listener; 246 } 247 248 /** 249 * Override only when subclasses need to get the test metrics from an individual 250 * instrumentation test. To aggregate the metrics from each test, update the 251 * getAggregatedMetrics and post them at the end of test run. 252 * 253 * @param test identifies the test 254 * @param testMetrics a {@link Map} of the metrics emitted 255 */ handleMetricsOnTestEnded(TestDescription test, Map<String, String> testMetrics)256 abstract public void handleMetricsOnTestEnded(TestDescription test, 257 Map<String, String> testMetrics); 258 259 /** 260 * Override only when it needs to inform subclasses of instrumentation test run ended, 261 * so that subclasses have a chance to peek the aggregated results at the end of test run 262 * and to decide what metrics to be posted. 263 * Either {@link ITestInvocationListener#testRunEnded} or 264 * {@link ITestInvocationListener#testRunFailed} should be called in this function to 265 * report the test run status. 266 * 267 * @param listener - the ITestInvocationListener of test results 268 * @param elapsedTime - device reported elapsed time, in milliseconds 269 * @param runMetrics - key-value pairs reported at the end of an instrumentation test run. 270 * Use getAggregatedMetrics to retrieve the metrics aggregated 271 * from an individual test, instead. 272 */ handleTestRunEnded(ITestInvocationListener listener, long elapsedTime, Map<String, String> runMetrics)273 abstract public void handleTestRunEnded(ITestInvocationListener listener, 274 long elapsedTime, Map<String, String> runMetrics); 275 276 /** 277 * Report the end of an individual camera test and delegate handling the collected metrics 278 * to subclasses. Do not override testEnded to manipulate the test metrics after each test. 279 * Instead, use handleMetricsOnTestEnded. 280 * 281 * @param test identifies the test 282 * @param testMetrics a {@link Map} of the metrics emitted 283 */ 284 @Override testEnded( TestDescription test, long endTime, HashMap<String, Metric> testMetrics)285 public void testEnded( 286 TestDescription test, long endTime, HashMap<String, Metric> testMetrics) { 287 super.testEnded(test, endTime, testMetrics); 288 handleMetricsOnTestEnded(test, TfMetricProtoUtil.compatibleConvert(testMetrics)); 289 stopDumping(test); 290 mListener.testEnded(test, endTime, testMetrics); 291 } 292 293 @Override testStarted(TestDescription test, long startTime)294 public void testStarted(TestDescription test, long startTime) { 295 super.testStarted(test, startTime); 296 startDumping(test); 297 mListener.testStarted(test, startTime); 298 } 299 300 @Override testFailed(TestDescription test, String trace)301 public void testFailed(TestDescription test, String trace) { 302 super.testFailed(test, trace); 303 // If the test failed to run to complete, this is an exceptional case. 304 // Let this test run fail so that it can rerun. 305 if (trace.startsWith(INCOMPLETE_TEST_ERR_MSG_PREFIX)) { 306 mFatalErrors.put(test.getTestName(), trace); 307 CLog.d("Test (%s) failed due to fatal error : %s", test.getTestName(), trace); 308 } 309 mListener.testFailed(test, trace); 310 } 311 312 @Override testRunFailed(String errorMessage)313 public void testRunFailed(String errorMessage) { 314 super.testRunFailed(errorMessage); 315 mFatalErrors.put(getRuKey(), errorMessage); 316 } 317 318 @Override testRunEnded(long elapsedTime, HashMap<String, Metric> runMetrics)319 public void testRunEnded(long elapsedTime, HashMap<String, Metric> runMetrics) { 320 super.testRunEnded(elapsedTime, runMetrics); 321 handleTestRunEnded(mListener, elapsedTime, 322 TfMetricProtoUtil.compatibleConvert(runMetrics)); 323 // never be called since handleTestRunEnded will handle it if needed. 324 //mListener.testRunEnded(elapsedTime, runMetrics); 325 } 326 327 @Override testRunStarted(String runName, int testCount)328 public void testRunStarted(String runName, int testCount) { 329 super.testRunStarted(runName, testCount); 330 mListener.testRunStarted(runName, testCount); 331 } 332 333 @Override testRunStopped(long elapsedTime)334 public void testRunStopped(long elapsedTime) { 335 super.testRunStopped(elapsedTime); 336 mListener.testRunStopped(elapsedTime); 337 } 338 339 @Override testLog(String dataName, LogDataType dataType, InputStreamSource dataStream)340 public void testLog(String dataName, LogDataType dataType, InputStreamSource dataStream) { 341 super.testLog(dataName, dataType, dataStream); 342 mListener.testLog(dataName, dataType, dataStream); 343 } 344 startDumping(TestDescription test)345 protected void startDumping(TestDescription test) { 346 if (shouldDumpMeminfo()) { 347 mMeminfoTimer.start(test); 348 } 349 if (shouldDumpThreadCount()) { 350 mThreadTrackerTimer.start(test); 351 } 352 } 353 stopDumping(TestDescription test)354 protected void stopDumping(TestDescription test) { 355 InputStreamSource outputSource = null; 356 File outputFile = null; 357 if (shouldDumpMeminfo()) { 358 mMeminfoTimer.stop(); 359 // Grab a snapshot of meminfo file and post it to dashboard. 360 try { 361 outputFile = mMeminfoTimer.getOutputFile(); 362 outputSource = new FileInputStreamSource(outputFile, true /* delete */); 363 String logName = String.format("meminfo_%s", test.getTestName()); 364 mListener.testLog(logName, LogDataType.TEXT, outputSource); 365 } finally { 366 StreamUtil.cancel(outputSource); 367 } 368 } 369 if (shouldDumpThreadCount()) { 370 mThreadTrackerTimer.stop(); 371 try { 372 outputFile = mThreadTrackerTimer.getOutputFile(); 373 outputSource = new FileInputStreamSource(outputFile, true /* delete */); 374 String logName = String.format("ps_%s", test.getTestName()); 375 mListener.testLog(logName, LogDataType.TEXT, outputSource); 376 } finally { 377 StreamUtil.cancel(outputSource); 378 } 379 } 380 } 381 getAggregatedMetrics()382 public Map<String, String> getAggregatedMetrics() { 383 return mMetrics; 384 } 385 getListeners()386 public ITestInvocationListener getListeners() { 387 return mListener; 388 } 389 390 /** 391 * Determine that the test run failed with fatal errors. 392 * 393 * @return True if test run has a failure due to fatal error. 394 */ hasTestRunFatalError()395 public boolean hasTestRunFatalError() { 396 return (getNumTotalTests() > 0 && mFatalErrors.size() > 0); 397 } 398 getFatalErrors()399 public Map<String, String> getFatalErrors() { 400 return mFatalErrors; 401 } 402 getErrorMessage()403 public String getErrorMessage() { 404 StringBuilder sb = new StringBuilder(); 405 for (Map.Entry<String, String> error : mFatalErrors.entrySet()) { 406 sb.append(error.getKey()); 407 sb.append(" : "); 408 sb.append(error.getValue()); 409 sb.append("\n"); 410 } 411 return sb.toString(); 412 } 413 } 414 415 protected class DefaultCollectingListener extends AbstractCollectingListener { 416 DefaultCollectingListener(ITestInvocationListener listener)417 public DefaultCollectingListener(ITestInvocationListener listener) { 418 super(listener); 419 } 420 421 @Override handleMetricsOnTestEnded(TestDescription test, Map<String, String> testMetrics)422 public void handleMetricsOnTestEnded(TestDescription test, Map<String, String> testMetrics) { 423 if (testMetrics == null) { 424 return; // No-op if there is nothing to post. 425 } 426 getAggregatedMetrics().putAll(testMetrics); 427 } 428 429 @Override handleTestRunEnded(ITestInvocationListener listener, long elapsedTime, Map<String, String> runMetrics)430 public void handleTestRunEnded(ITestInvocationListener listener, long elapsedTime, 431 Map<String, String> runMetrics) { 432 // Post aggregated metrics at the end of test run. 433 listener.testRunEnded(getTestDurationMs(), TfMetricProtoUtil.upgradeConvert(getAggregatedMetrics())); 434 } 435 } 436 437 // TODO: Leverage AUPT to collect system logs (meminfo, ION allocations and processes/threads) 438 private class MeminfoTimer { 439 440 private static final String LOG_HEADER = 441 "uptime,pssCameraDaemon,pssCameraApp,ramTotal,ramFree,ramUsed"; 442 private static final String DUMPSYS_MEMINFO_COMMAND = 443 "dumpsys meminfo -c | grep -w -e " + "^ram -e ^time"; 444 private String[] mDumpsysMemInfoProc = { 445 PROCESS_CAMERA_DAEMON, PROCESS_CAMERA_APP, PROCESS_MEDIASERVER 446 }; 447 private static final int STATE_STOPPED = 0; 448 private static final int STATE_SCHEDULED = 1; 449 private static final int STATE_RUNNING = 2; 450 451 private int mState = STATE_STOPPED; 452 private Timer mTimer = new Timer(true); // run as a daemon thread 453 private long mDelayMs = 0; 454 private long mPeriodMs = 60 * 1000; // 60 sec 455 private File mOutputFile = null; 456 private String mCommand; 457 MeminfoTimer(long delayMs, long periodMs)458 public MeminfoTimer(long delayMs, long periodMs) { 459 mDelayMs = delayMs; 460 mPeriodMs = periodMs; 461 mCommand = DUMPSYS_MEMINFO_COMMAND; 462 for (String process : mDumpsysMemInfoProc) { 463 mCommand += " -e " + process; 464 } 465 } 466 start(TestDescription test)467 synchronized void start(TestDescription test) { 468 if (isRunning()) { 469 stop(); 470 } 471 // Create an output file. 472 if (createOutputFile(test) == null) { 473 CLog.w("Stop collecting meminfo since meminfo log file not found."); 474 mState = STATE_STOPPED; 475 return; // No-op 476 } 477 mTimer.scheduleAtFixedRate(new TimerTask() { 478 @Override 479 public void run() { 480 mState = STATE_RUNNING; 481 dumpMeminfo(mCommand, mOutputFile); 482 } 483 }, mDelayMs, mPeriodMs); 484 mState = STATE_SCHEDULED; 485 } 486 stop()487 synchronized void stop() { 488 mState = STATE_STOPPED; 489 mTimer.cancel(); 490 } 491 isRunning()492 synchronized boolean isRunning() { 493 return (mState == STATE_RUNNING); 494 } 495 getOutputFile()496 public File getOutputFile() { 497 return mOutputFile; 498 } 499 createOutputFile(TestDescription test)500 private File createOutputFile(TestDescription test) { 501 try { 502 mOutputFile = FileUtil.createTempFile( 503 String.format("meminfo_%s", test.getTestName()), "csv"); 504 BufferedWriter writer = new BufferedWriter(new FileWriter(mOutputFile, false)); 505 writer.write(LOG_HEADER); 506 writer.newLine(); 507 writer.flush(); 508 writer.close(); 509 } catch (IOException e) { 510 CLog.w("Failed to create meminfo log file %s:", mOutputFile.getAbsolutePath()); 511 CLog.e(e); 512 return null; 513 } 514 return mOutputFile; 515 } 516 } 517 dumpMeminfo(String command, File outputFile)518 void dumpMeminfo(String command, File outputFile) { 519 try { 520 CollectingOutputReceiver receiver = new CollectingOutputReceiver(); 521 // Dump meminfo in a compact form. 522 getDevice().executeShellCommand(command, receiver, 523 SHELL_TIMEOUT_MS, TimeUnit.MILLISECONDS, SHELL_MAX_ATTEMPTS); 524 printMeminfo(outputFile, receiver.getOutput()); 525 } catch (DeviceNotAvailableException e) { 526 CLog.w("Failed to dump meminfo:"); 527 CLog.e(e); 528 } 529 } 530 printMeminfo(File outputFile, String meminfo)531 void printMeminfo(File outputFile, String meminfo) { 532 // Parse meminfo and print each iteration in a line in a .csv format. The meminfo output 533 // are separated into three different formats: 534 // 535 // Format: time,<uptime>,<realtime> 536 // eg. "time,59459911,63354673" 537 // 538 // Format: proc,<oom_label>,<process_name>,<pid>,<pss>,<hasActivities> 539 // eg. "proc,native,mm-qcamera-daemon,522,12881,e" 540 // "proc,fore,com.google.android.GoogleCamera,26560,70880,a" 541 // 542 // Format: ram,<total>,<free>,<used> 543 // eg. "ram,1857364,810189,541516" 544 BufferedWriter writer = null; 545 BufferedReader reader = null; 546 try { 547 final String DELIMITER = ","; 548 writer = new BufferedWriter(new FileWriter(outputFile, true)); 549 reader = new BufferedReader(new StringReader(meminfo)); 550 String line; 551 String uptime = null; 552 String pssCameraNative = null; 553 String pssCameraApp = null; 554 String ramTotal = null; 555 String ramFree = null; 556 String ramUsed = null; 557 while ((line = reader.readLine()) != null) { 558 if (line.startsWith("time")) { 559 uptime = line.split(DELIMITER)[1]; 560 } else if (line.startsWith("ram")) { 561 String[] ram = line.split(DELIMITER); 562 ramTotal = ram[1]; 563 ramFree = ram[2]; 564 ramUsed = ram[3]; 565 } else if (line.contains(PROCESS_CAMERA_DAEMON)) { 566 pssCameraNative = line.split(DELIMITER)[4]; 567 } else if (line.contains(PROCESS_CAMERA_APP)) { 568 pssCameraApp = line.split(DELIMITER)[4]; 569 } 570 } 571 String printMsg = String.format( 572 "%s,%s,%s,%s,%s,%s", uptime, pssCameraNative, pssCameraApp, 573 ramTotal, ramFree, ramUsed); 574 writer.write(printMsg); 575 writer.newLine(); 576 writer.flush(); 577 } catch (IOException e) { 578 CLog.w("Failed to print meminfo to %s:", outputFile.getAbsolutePath()); 579 CLog.e(e); 580 } finally { 581 StreamUtil.close(writer); 582 } 583 } 584 585 // TODO: Leverage AUPT to collect system logs (meminfo, ION allocations and processes/threads) 586 private class ThreadTrackerTimer { 587 588 // list all threads in a given process, remove the first header line, squeeze whitespaces, 589 // select thread name (in 14th column), then sort and group by its name. 590 // Examples: 591 // 3 SoundPoolThread 592 // 3 SoundPool 593 // 2 Camera Job Disp 594 // 1 pool-7-thread-1 595 // 1 pool-6-thread-1 596 // FIXME: Resolve the error "sh: syntax error: '|' unexpected" using the command below 597 // $ /system/bin/ps -t -p %s | tr -s ' ' | cut -d' ' -f13- | sort | uniq -c | sort -nr" 598 private static final String PS_COMMAND_FORMAT = "/system/bin/ps -t -p %s"; 599 private static final String PGREP_COMMAND_FORMAT = "pgrep %s"; 600 private static final int STATE_STOPPED = 0; 601 private static final int STATE_SCHEDULED = 1; 602 private static final int STATE_RUNNING = 2; 603 604 private int mState = STATE_STOPPED; 605 private Timer mTimer = new Timer(true); // run as a daemon thread 606 private long mDelayMs = 0; 607 private long mPeriodMs = 60 * 1000; // 60 sec 608 private File mOutputFile = null; 609 ThreadTrackerTimer(long delayMs, long periodMs)610 public ThreadTrackerTimer(long delayMs, long periodMs) { 611 mDelayMs = delayMs; 612 mPeriodMs = periodMs; 613 } 614 start(TestDescription test)615 synchronized void start(TestDescription test) { 616 if (isRunning()) { 617 stop(); 618 } 619 // Create an output file. 620 if (createOutputFile(test) == null) { 621 CLog.w("Stop collecting thread counts since log file not found."); 622 mState = STATE_STOPPED; 623 return; // No-op 624 } 625 mTimer.scheduleAtFixedRate(new TimerTask() { 626 @Override 627 public void run() { 628 mState = STATE_RUNNING; 629 dumpThreadCount(PS_COMMAND_FORMAT, getPid(PROCESS_CAMERA_APP), mOutputFile); 630 } 631 }, mDelayMs, mPeriodMs); 632 mState = STATE_SCHEDULED; 633 } 634 stop()635 synchronized void stop() { 636 mState = STATE_STOPPED; 637 mTimer.cancel(); 638 } 639 isRunning()640 synchronized boolean isRunning() { 641 return (mState == STATE_RUNNING); 642 } 643 getOutputFile()644 public File getOutputFile() { 645 return mOutputFile; 646 } 647 createOutputFile(TestDescription test)648 File createOutputFile(TestDescription test) { 649 try { 650 mOutputFile = FileUtil.createTempFile( 651 String.format("ps_%s", test.getTestName()), "txt"); 652 new BufferedWriter(new FileWriter(mOutputFile, false)).close(); 653 } catch (IOException e) { 654 CLog.w("Failed to create processes and threads file %s:", 655 mOutputFile.getAbsolutePath()); 656 CLog.e(e); 657 return null; 658 } 659 return mOutputFile; 660 } 661 getPid(String processName)662 String getPid(String processName) { 663 String result = null; 664 try { 665 result = getDevice().executeShellCommand(String.format(PGREP_COMMAND_FORMAT, 666 processName)); 667 } catch (DeviceNotAvailableException e) { 668 CLog.w("Failed to get pid %s:", processName); 669 CLog.e(e); 670 } 671 return result; 672 } 673 getUptime()674 String getUptime() { 675 String uptime = null; 676 try { 677 // uptime will typically have a format like "5278.73 1866.80". Use the first one 678 // (which is wall-time) 679 uptime = getDevice().executeShellCommand("cat /proc/uptime").split(" ")[0]; 680 Float.parseFloat(uptime); 681 } catch (NumberFormatException e) { 682 CLog.w("Failed to get valid uptime %s: %s", uptime, e); 683 } catch (DeviceNotAvailableException e) { 684 CLog.w("Failed to get valid uptime: %s", e); 685 } 686 return uptime; 687 } 688 dumpThreadCount(String commandFormat, String pid, File outputFile)689 void dumpThreadCount(String commandFormat, String pid, File outputFile) { 690 try { 691 if ("".equals(pid)) { 692 return; 693 } 694 String result = getDevice().executeShellCommand(String.format(commandFormat, pid)); 695 String header = String.format("UPTIME: %s", getUptime()); 696 BufferedWriter writer = new BufferedWriter(new FileWriter(outputFile, true)); 697 writer.write(header); 698 writer.newLine(); 699 writer.write(result); 700 writer.newLine(); 701 writer.flush(); 702 writer.close(); 703 } catch (DeviceNotAvailableException | IOException e) { 704 CLog.w("Failed to dump thread count:"); 705 CLog.e(e); 706 } 707 } 708 } 709 710 // TODO: Leverage AUPT to collect system logs (meminfo, ION allocations and 711 // processes/threads) dumpIonHeaps(ITestInvocationListener listener, String testClass)712 protected void dumpIonHeaps(ITestInvocationListener listener, String testClass) { 713 if (!shouldDumpIonHeap()) { 714 return; // No-op if option is not set. 715 } 716 try { 717 String result = getDevice().executeShellCommand(DUMP_ION_HEAPS_COMMAND); 718 if (!"".equals(result)) { 719 String fileName = String.format("ionheaps_%s_onEnd", testClass); 720 listener.testLog(fileName, LogDataType.TEXT, 721 new ByteArrayInputStreamSource(result.getBytes())); 722 } 723 } catch (DeviceNotAvailableException e) { 724 CLog.w("Failed to dump ION heaps:"); 725 CLog.e(e); 726 } 727 } 728 729 /** 730 * {@inheritDoc} 731 */ 732 @Override setDevice(ITestDevice device)733 public void setDevice(ITestDevice device) { 734 mDevice = device; 735 } 736 737 /** 738 * {@inheritDoc} 739 */ 740 @Override getDevice()741 public ITestDevice getDevice() { 742 return mDevice; 743 } 744 745 /** 746 * {@inheritDoc} 747 */ 748 @Override setConfiguration(IConfiguration configuration)749 public void setConfiguration(IConfiguration configuration) { 750 mConfiguration = configuration; 751 } 752 753 /** 754 * Get the {@link IRunUtil} instance to use. 755 * <p/> 756 * Exposed so unit tests can mock. 757 */ getRunUtil()758 IRunUtil getRunUtil() { 759 return RunUtil.getDefault(); 760 } 761 762 /** 763 * Get the duration of Camera test instrumentation in milliseconds. 764 * 765 * @return the duration of Camera instrumentation test until it is called. 766 */ getTestDurationMs()767 public long getTestDurationMs() { 768 return System.currentTimeMillis() - mStartTimeMs; 769 } 770 getTestPackage()771 public String getTestPackage() { 772 return mTestPackage; 773 } 774 setTestPackage(String testPackage)775 public void setTestPackage(String testPackage) { 776 mTestPackage = testPackage; 777 } 778 getTestClass()779 public String getTestClass() { 780 return mTestClass; 781 } 782 setTestClass(String testClass)783 public void setTestClass(String testClass) { 784 mTestClass = testClass; 785 } 786 getTestRunner()787 public String getTestRunner() { 788 return mTestRunner; 789 } 790 setTestRunner(String testRunner)791 public void setTestRunner(String testRunner) { 792 mTestRunner = testRunner; 793 } 794 getTestTimeoutMs()795 public int getTestTimeoutMs() { 796 return mTestTimeoutMs; 797 } 798 setTestTimeoutMs(int testTimeoutMs)799 public void setTestTimeoutMs(int testTimeoutMs) { 800 mTestTimeoutMs = testTimeoutMs; 801 } 802 getShellTimeoutMs()803 public long getShellTimeoutMs() { 804 return mShellTimeoutMs; 805 } 806 setShellTimeoutMs(long shellTimeoutMs)807 public void setShellTimeoutMs(long shellTimeoutMs) { 808 mShellTimeoutMs = shellTimeoutMs; 809 } 810 getRuKey()811 public String getRuKey() { 812 return mRuKey; 813 } 814 setRuKey(String ruKey)815 public void setRuKey(String ruKey) { 816 mRuKey = ruKey; 817 } 818 shouldDumpMeminfo()819 public boolean shouldDumpMeminfo() { 820 return mDumpMeminfo; 821 } 822 shouldDumpIonHeap()823 public boolean shouldDumpIonHeap() { 824 return mDumpIonHeap; 825 } 826 shouldDumpThreadCount()827 public boolean shouldDumpThreadCount() { 828 return mDumpThreadCount; 829 } 830 getCollectingListener()831 public AbstractCollectingListener getCollectingListener() { 832 return mCollectingListener; 833 } 834 setLogcatOnFailure(boolean logcatOnFailure)835 public void setLogcatOnFailure(boolean logcatOnFailure) { 836 mLogcatOnFailure = logcatOnFailure; 837 } 838 getIterationCount()839 public int getIterationCount() { 840 return mIterations; 841 } 842 getInstrumentationArgMap()843 public Map<String, String> getInstrumentationArgMap() { return mInstrArgMap; } 844 } 845