/* * Copyright (C) 2015 The Android Open Source Project * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. * You may obtain a copy of the License at * * http://www.apache.org/licenses/LICENSE-2.0 * * Unless required by applicable law or agreed to in writing, software * distributed under the License is distributed on an "AS IS" BASIS, * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. * See the License for the specific language governing permissions and * limitations under the License. */ package com.android.media.tests; import com.android.ddmlib.CollectingOutputReceiver; import com.android.tradefed.config.IConfiguration; import com.android.tradefed.config.IConfigurationReceiver; import com.android.tradefed.config.Option; import com.android.tradefed.device.DeviceNotAvailableException; import com.android.tradefed.device.ITestDevice; import com.android.tradefed.invoker.TestInformation; import com.android.tradefed.log.LogUtil.CLog; import com.android.tradefed.result.ByteArrayInputStreamSource; import com.android.tradefed.result.CollectingTestListener; import com.android.tradefed.result.ITestInvocationListener; import com.android.tradefed.result.LogDataType; import com.android.tradefed.result.TestDescription; import com.android.tradefed.testtype.IDeviceTest; import com.android.tradefed.testtype.IRemoteTest; import com.android.tradefed.testtype.InstrumentationTest; import com.android.tradefed.util.FileUtil; import com.android.tradefed.util.IRunUtil; import com.android.tradefed.util.RunUtil; import com.android.tradefed.util.StreamUtil; import org.junit.Assert; import java.io.BufferedReader; import java.io.BufferedWriter; import java.io.File; import java.io.FileWriter; import java.io.IOException; import java.io.StringReader; import java.util.ArrayList; import java.util.Collection; import java.util.HashMap; import java.util.Map; import java.util.Timer; import java.util.TimerTask; import java.util.concurrent.TimeUnit; /** * Camera test base class * * Camera2StressTest, CameraStartupTest, Camera2LatencyTest and CameraPerformanceTest use this base * class for Camera ivvavik and later. */ public class CameraTestBase implements IDeviceTest, IRemoteTest, IConfigurationReceiver { private static final long SHELL_TIMEOUT_MS = 60 * 1000; // 1 min private static final int SHELL_MAX_ATTEMPTS = 3; protected static final String PROCESS_CAMERA_DAEMON = "mm-qcamera-daemon"; protected static final String PROCESS_MEDIASERVER = "mediaserver"; protected static final String PROCESS_CAMERA_APP = "com.google.android.GoogleCamera"; protected static final String DUMP_ION_HEAPS_COMMAND = "cat /d/ion/heaps/system"; protected static final String ARGUMENT_TEST_ITERATIONS = "iterations"; @Option(name = "test-package", description = "Test package to run.") private String mTestPackage = "com.google.android.camera"; @Option(name = "test-class", description = "Test class to run.") private String mTestClass = null; @Option(name = "test-methods", description = "Test method to run. May be repeated.") private Collection mTestMethods = new ArrayList<>(); @Option(name = "test-runner", description = "Test runner for test instrumentation.") private String mTestRunner = "android.test.InstrumentationTestRunner"; @Option(name = "test-timeout", description = "Max time allowed in ms for a test run.") private int mTestTimeoutMs = 60 * 60 * 1000; // 1 hour @Option(name = "shell-timeout", description="The defined timeout (in milliseconds) is used as a maximum waiting time " + "when expecting the command output from the device. At any time, if the " + "shell command does not output anything for a period longer than defined " + "timeout the TF run terminates. For no timeout, set to 0.") private long mShellTimeoutMs = 60 * 60 * 1000; // default to 1 hour @Option(name = "ru-key", description = "Result key to use when posting to the dashboard.") private String mRuKey = null; /** Rely on invocation level logcat capture rather than this. */ @Deprecated @Option( name = "logcat-on-failure", description = "take a logcat snapshot on every test failure." ) private boolean mLogcatOnFailure = false; @Option( name = "instrumentation-arg", description = "Additional instrumentation arguments to provide." ) private Map mInstrArgMap = new HashMap<>(); @Option(name = "dump-meminfo", description = "take a dumpsys meminfo at a given interval time.") private boolean mDumpMeminfo = false; @Option(name="dump-meminfo-interval-ms", description="Interval of calling dumpsys meminfo in milliseconds.") private int mMeminfoIntervalMs = 5 * 60 * 1000; // 5 minutes @Option(name = "dump-ion-heap", description = "dump ION allocations at the end of test.") private boolean mDumpIonHeap = false; @Option(name = "dump-thread-count", description = "Count the number of threads in Camera process at a given interval time.") private boolean mDumpThreadCount = false; @Option(name="dump-thread-count-interval-ms", description="Interval of calling ps to count the number of threads in milliseconds.") private int mThreadCountIntervalMs = 5 * 60 * 1000; // 5 minutes @Option(name="iterations", description="The number of iterations to run. Default to 1. " + "This takes effect only when Camera2InstrumentationTestRunner is used to execute " + "framework stress tests.") private int mIterations = 1; private ITestDevice mDevice = null; // A base listener to collect the results from each test run. Test results will be forwarded // to other listeners. private CollectingTestListener mCollectingListener = null; private ITestInvocationListener mListener = null; private long mStartTimeMs = 0; public MeminfoTimer mMeminfoTimer = null; public ThreadTrackerTimer mThreadTrackerTimer = null; protected IConfiguration mConfiguration; /** {@inheritDoc} */ @Override public void run(TestInformation testInfo, ITestInvocationListener listener) throws DeviceNotAvailableException { // ignore } /** * Run Camera instrumentation test with a listener to gather the metrics from the individual * test runs. * * @param listener the ITestInvocationListener of test results * @param collectingListener the {@link CollectingTestListener} to collect the metrics from test * runs * @throws DeviceNotAvailableException */ protected void runInstrumentationTest( TestInformation testInfo, ITestInvocationListener listener, CameraTestMetricsCollectionListener.DefaultCollectingListener collectingListener) throws DeviceNotAvailableException { Assert.assertNotNull(collectingListener); mCollectingListener = collectingListener; mListener = listener; InstrumentationTest instr = new InstrumentationTest(); instr.setDevice(getDevice()); instr.setConfiguration(mConfiguration); instr.setPackageName(getTestPackage()); instr.setRunnerName(getTestRunner()); instr.setClassName(getTestClass()); instr.setTestTimeout(getTestTimeoutMs()); instr.setShellTimeout(getShellTimeoutMs()); instr.setRunName(getRuKey()); instr.setRerunMode(false); if (!getIsolatedStorageFlag()) { instr.setIsolatedStorage(false); } // Set test iteration. if (getIterationCount() > 1) { CLog.v("Setting test iterations: %d", getIterationCount()); Map instrArgMap = getInstrumentationArgMap(); instrArgMap.put(ARGUMENT_TEST_ITERATIONS, String.valueOf(getIterationCount())); } for (Map.Entry entry : getInstrumentationArgMap().entrySet()) { instr.addInstrumentationArg(entry.getKey(), entry.getValue()); } // Check if dumpheap needs to be taken for native processes before test runs. if (shouldDumpMeminfo()) { mMeminfoTimer = new MeminfoTimer(0, mMeminfoIntervalMs); } if (shouldDumpThreadCount()) { long delayMs = mThreadCountIntervalMs / 2; // Not to run all dump at the same interval. mThreadTrackerTimer = new ThreadTrackerTimer(delayMs, mThreadCountIntervalMs); } // Run tests. mStartTimeMs = System.currentTimeMillis(); if (mTestMethods.size() > 0) { CLog.d(String.format("The number of test methods is: %d", mTestMethods.size())); for (String testName : mTestMethods) { instr.setMethodName(testName); instr.run(testInfo, mCollectingListener); } } else { instr.run(testInfo, mCollectingListener); } dumpIonHeaps(mCollectingListener, getTestClass()); } private Map mMetrics = new HashMap<>(); private Map mFatalErrors = new HashMap<>(); private static final String INCOMPLETE_TEST_ERR_MSG_PREFIX = "Test failed to run to completion. Reason: 'Instrumentation run failed"; public Map getAggregatedMetrics() { return mMetrics; } public ITestInvocationListener getListeners() { return mListener; } // TODO: Leverage AUPT to collect system logs (meminfo, ION allocations and processes/threads) public class MeminfoTimer { private static final String LOG_HEADER = "uptime,pssCameraDaemon,pssCameraApp,ramTotal,ramFree,ramUsed"; private static final String DUMPSYS_MEMINFO_COMMAND = "dumpsys meminfo -c | grep -w -e " + "^ram -e ^time"; private String[] mDumpsysMemInfoProc = { PROCESS_CAMERA_DAEMON, PROCESS_CAMERA_APP, PROCESS_MEDIASERVER }; private static final int STATE_STOPPED = 0; private static final int STATE_SCHEDULED = 1; private static final int STATE_RUNNING = 2; private int mState = STATE_STOPPED; private Timer mTimer = new Timer(true); // run as a daemon thread private long mDelayMs = 0; private long mPeriodMs = 60 * 1000; // 60 sec private File mOutputFile = null; private String mCommand; public MeminfoTimer(long delayMs, long periodMs) { mDelayMs = delayMs; mPeriodMs = periodMs; mCommand = DUMPSYS_MEMINFO_COMMAND; for (String process : mDumpsysMemInfoProc) { mCommand += " -e " + process; } } synchronized void start(TestDescription test) { if (isRunning()) { stop(); } // Create an output file. if (createOutputFile(test) == null) { CLog.w("Stop collecting meminfo since meminfo log file not found."); mState = STATE_STOPPED; return; // No-op } mTimer.scheduleAtFixedRate(new TimerTask() { @Override public void run() { mState = STATE_RUNNING; dumpMeminfo(mCommand, mOutputFile); } }, mDelayMs, mPeriodMs); mState = STATE_SCHEDULED; } synchronized void stop() { mState = STATE_STOPPED; mTimer.cancel(); } synchronized boolean isRunning() { return (mState == STATE_RUNNING); } public File getOutputFile() { return mOutputFile; } private File createOutputFile(TestDescription test) { try { mOutputFile = FileUtil.createTempFile( String.format("meminfo_%s", test.getTestName()), "csv"); BufferedWriter writer = new BufferedWriter(new FileWriter(mOutputFile, false)); writer.write(LOG_HEADER); writer.newLine(); writer.flush(); writer.close(); } catch (IOException e) { CLog.w("Failed to create meminfo log file %s:", mOutputFile.getAbsolutePath()); CLog.e(e); return null; } return mOutputFile; } } void dumpMeminfo(String command, File outputFile) { try { CollectingOutputReceiver receiver = new CollectingOutputReceiver(); // Dump meminfo in a compact form. getDevice().executeShellCommand(command, receiver, SHELL_TIMEOUT_MS, TimeUnit.MILLISECONDS, SHELL_MAX_ATTEMPTS); printMeminfo(outputFile, receiver.getOutput()); } catch (DeviceNotAvailableException e) { CLog.w("Failed to dump meminfo:"); CLog.e(e); } } void printMeminfo(File outputFile, String meminfo) { // Parse meminfo and print each iteration in a line in a .csv format. The meminfo output // are separated into three different formats: // // Format: time,, // eg. "time,59459911,63354673" // // Format: proc,,,,, // eg. "proc,native,mm-qcamera-daemon,522,12881,e" // "proc,fore,com.google.android.GoogleCamera,26560,70880,a" // // Format: ram,,, // eg. "ram,1857364,810189,541516" BufferedWriter writer = null; BufferedReader reader = null; try { final String DELIMITER = ","; writer = new BufferedWriter(new FileWriter(outputFile, true)); reader = new BufferedReader(new StringReader(meminfo)); String line; String uptime = null; String pssCameraNative = null; String pssCameraApp = null; String ramTotal = null; String ramFree = null; String ramUsed = null; while ((line = reader.readLine()) != null) { if (line.startsWith("time")) { uptime = line.split(DELIMITER)[1]; } else if (line.startsWith("ram")) { String[] ram = line.split(DELIMITER); ramTotal = ram[1]; ramFree = ram[2]; ramUsed = ram[3]; } else if (line.contains(PROCESS_CAMERA_DAEMON)) { pssCameraNative = line.split(DELIMITER)[4]; } else if (line.contains(PROCESS_CAMERA_APP)) { pssCameraApp = line.split(DELIMITER)[4]; } } String printMsg = String.format( "%s,%s,%s,%s,%s,%s", uptime, pssCameraNative, pssCameraApp, ramTotal, ramFree, ramUsed); writer.write(printMsg); writer.newLine(); writer.flush(); } catch (IOException e) { CLog.w("Failed to print meminfo to %s:", outputFile.getAbsolutePath()); CLog.e(e); } finally { StreamUtil.close(writer); } } // TODO: Leverage AUPT to collect system logs (meminfo, ION allocations and processes/threads) public class ThreadTrackerTimer { // list all threads in a given process, remove the first header line, squeeze whitespaces, // select thread name (in 14th column), then sort and group by its name. // Examples: // 3 SoundPoolThread // 3 SoundPool // 2 Camera Job Disp // 1 pool-7-thread-1 // 1 pool-6-thread-1 // FIXME: Resolve the error "sh: syntax error: '|' unexpected" using the command below // $ /system/bin/ps -t -p %s | tr -s ' ' | cut -d' ' -f13- | sort | uniq -c | sort -nr" private static final String PS_COMMAND_FORMAT = "/system/bin/ps -t -p %s"; private static final String PGREP_COMMAND_FORMAT = "pgrep %s"; private static final int STATE_STOPPED = 0; private static final int STATE_SCHEDULED = 1; private static final int STATE_RUNNING = 2; private int mState = STATE_STOPPED; private Timer mTimer = new Timer(true); // run as a daemon thread private long mDelayMs = 0; private long mPeriodMs = 60 * 1000; // 60 sec private File mOutputFile = null; public ThreadTrackerTimer(long delayMs, long periodMs) { mDelayMs = delayMs; mPeriodMs = periodMs; } synchronized void start(TestDescription test) { if (isRunning()) { stop(); } // Create an output file. if (createOutputFile(test) == null) { CLog.w("Stop collecting thread counts since log file not found."); mState = STATE_STOPPED; return; // No-op } mTimer.scheduleAtFixedRate(new TimerTask() { @Override public void run() { mState = STATE_RUNNING; dumpThreadCount(PS_COMMAND_FORMAT, getPid(PROCESS_CAMERA_APP), mOutputFile); } }, mDelayMs, mPeriodMs); mState = STATE_SCHEDULED; } synchronized void stop() { mState = STATE_STOPPED; mTimer.cancel(); } synchronized boolean isRunning() { return (mState == STATE_RUNNING); } public File getOutputFile() { return mOutputFile; } File createOutputFile(TestDescription test) { try { mOutputFile = FileUtil.createTempFile( String.format("ps_%s", test.getTestName()), "txt"); new BufferedWriter(new FileWriter(mOutputFile, false)).close(); } catch (IOException e) { CLog.w("Failed to create processes and threads file %s:", mOutputFile.getAbsolutePath()); CLog.e(e); return null; } return mOutputFile; } String getPid(String processName) { String result = null; try { result = getDevice().executeShellCommand(String.format(PGREP_COMMAND_FORMAT, processName)); } catch (DeviceNotAvailableException e) { CLog.w("Failed to get pid %s:", processName); CLog.e(e); } return result; } String getUptime() { String uptime = null; try { // uptime will typically have a format like "5278.73 1866.80". Use the first one // (which is wall-time) uptime = getDevice().executeShellCommand("cat /proc/uptime").split(" ")[0]; Float.parseFloat(uptime); } catch (NumberFormatException e) { CLog.w("Failed to get valid uptime %s: %s", uptime, e); } catch (DeviceNotAvailableException e) { CLog.w("Failed to get valid uptime: %s", e); } return uptime; } void dumpThreadCount(String commandFormat, String pid, File outputFile) { try { if ("".equals(pid)) { return; } String result = getDevice().executeShellCommand(String.format(commandFormat, pid)); String header = String.format("UPTIME: %s", getUptime()); BufferedWriter writer = new BufferedWriter(new FileWriter(outputFile, true)); writer.write(header); writer.newLine(); writer.write(result); writer.newLine(); writer.flush(); writer.close(); } catch (DeviceNotAvailableException | IOException e) { CLog.w("Failed to dump thread count:"); CLog.e(e); } } } // TODO: Leverage AUPT to collect system logs (meminfo, ION allocations and // processes/threads) protected void dumpIonHeaps(ITestInvocationListener listener, String testClass) { if (!shouldDumpIonHeap()) { return; // No-op if option is not set. } try { String result = getDevice().executeShellCommand(DUMP_ION_HEAPS_COMMAND); if (!"".equals(result)) { String fileName = String.format("ionheaps_%s_onEnd", testClass); listener.testLog(fileName, LogDataType.TEXT, new ByteArrayInputStreamSource(result.getBytes())); } } catch (DeviceNotAvailableException e) { CLog.w("Failed to dump ION heaps:"); CLog.e(e); } } /** * {@inheritDoc} */ @Override public void setDevice(ITestDevice device) { mDevice = device; } /** * {@inheritDoc} */ @Override public ITestDevice getDevice() { return mDevice; } /** * {@inheritDoc} */ @Override public void setConfiguration(IConfiguration configuration) { mConfiguration = configuration; } /** * Get the {@link IRunUtil} instance to use. *

* Exposed so unit tests can mock. */ IRunUtil getRunUtil() { return RunUtil.getDefault(); } /** * Get the duration of Camera test instrumentation in milliseconds. * * @return the duration of Camera instrumentation test until it is called. */ public long getTestDurationMs() { return System.currentTimeMillis() - mStartTimeMs; } public String getTestPackage() { return mTestPackage; } public void setTestPackage(String testPackage) { mTestPackage = testPackage; } public String getTestClass() { return mTestClass; } public void setTestClass(String testClass) { mTestClass = testClass; } public String getTestRunner() { return mTestRunner; } public void setTestRunner(String testRunner) { mTestRunner = testRunner; } public int getTestTimeoutMs() { return mTestTimeoutMs; } public void setTestTimeoutMs(int testTimeoutMs) { mTestTimeoutMs = testTimeoutMs; } public long getShellTimeoutMs() { return mShellTimeoutMs; } public void setShellTimeoutMs(long shellTimeoutMs) { mShellTimeoutMs = shellTimeoutMs; } public String getRuKey() { return mRuKey; } public void setRuKey(String ruKey) { mRuKey = ruKey; } public boolean shouldDumpMeminfo() { return mDumpMeminfo; } public boolean shouldDumpIonHeap() { return mDumpIonHeap; } public boolean shouldDumpThreadCount() { return mDumpThreadCount; } public ITestInvocationListener getCollectingListener() { return mCollectingListener; } public void setLogcatOnFailure(boolean logcatOnFailure) { mLogcatOnFailure = logcatOnFailure; } public int getIterationCount() { return mIterations; } public boolean getIsolatedStorageFlag() { return mIsolatedStorageFlag; } public void setIsolatedStorageFlag(boolean isolatedStorage) { mIsolatedStorageFlag = isolatedStorage; } boolean mIsolatedStorageFlag = true; public Map getInstrumentationArgMap() { return mInstrArgMap; } }