From 50307d9792feac5b170e0e0536ad6e2a47d5eb27 Mon Sep 17 00:00:00 2001 From: Joe Onorato Date: Wed, 1 May 2019 12:51:05 -0700 Subject: [PATCH] Make am instrument capture logcat during test run, and return it to the host. Also makes bit print that logcat, if available, instead of just the stack trace. This means that when you run a test you don't also have to run logcat in some other window, and then scroll around forever looking for the one test in question. Test: bit -t GtsIncidentManagerTestCases:com.google.android.incident.gts.IncidentManagerTests\#testFail Test: bit -t GtsIncidentManagerTestCases:com.google.android.incident.gts.IncidentManagerTests\#testDoesntExist Bug: 129875642 Change-Id: I8940ff379c919482f4a545cb90d25bdbaa2b4f15 --- cmds/am/proto/instrumentation_data.proto | 1 + .../com/android/commands/am/Instrument.java | 72 +++++++++++++++++-- tools/bit/main.cpp | 10 ++- 3 files changed, 75 insertions(+), 8 deletions(-) diff --git a/cmds/am/proto/instrumentation_data.proto b/cmds/am/proto/instrumentation_data.proto index 8e29f9645568a..23e9519923059 100644 --- a/cmds/am/proto/instrumentation_data.proto +++ b/cmds/am/proto/instrumentation_data.proto @@ -38,6 +38,7 @@ message ResultsBundle { message TestStatus { optional sint32 result_code = 3; optional ResultsBundle results = 4; + optional string logcat = 5; } enum SessionStatusCode { diff --git a/cmds/am/src/com/android/commands/am/Instrument.java b/cmds/am/src/com/android/commands/am/Instrument.java index 70baa8702ba98..4d7b5a79b4f77 100644 --- a/cmds/am/src/com/android/commands/am/Instrument.java +++ b/cmds/am/src/com/android/commands/am/Instrument.java @@ -38,6 +38,7 @@ import android.view.IWindowManager; import java.io.File; import java.io.FileOutputStream; import java.io.IOException; +import java.io.InputStreamReader; import java.io.OutputStream; import java.text.SimpleDateFormat; import java.util.ArrayList; @@ -62,8 +63,15 @@ import java.util.Locale; * other: Failure */ public class Instrument { + private static final String TAG = "am"; + public static final String DEFAULT_LOG_DIR = "instrument-logs"; + private static final int STATUS_TEST_PASSED = 0; + private static final int STATUS_TEST_STARTED = 1; + private static final int STATUS_TEST_FAILED_ASSERTION = -1; + private static final int STATUS_TEST_FAILED_OTHER = -2; + private final IActivityManager mAm; private final IPackageManager mPm; private final IWindowManager mWm; @@ -207,6 +215,8 @@ public class Instrument { private File mLog; + private long mTestStartMs; + ProtoStatusReporter() { if (protoFile) { if (logPath == null) { @@ -241,10 +251,22 @@ public class Instrument { Bundle results) { final ProtoOutputStream proto = new ProtoOutputStream(); - final long token = proto.start(InstrumentationData.Session.TEST_STATUS); + final long testStatusToken = proto.start(InstrumentationData.Session.TEST_STATUS); + proto.write(InstrumentationData.TestStatus.RESULT_CODE, resultCode); writeBundle(proto, InstrumentationData.TestStatus.RESULTS, results); - proto.end(token); + + if (resultCode == STATUS_TEST_STARTED) { + // Logcat -T takes wall clock time (!?) + mTestStartMs = System.currentTimeMillis(); + } else { + if (mTestStartMs > 0) { + proto.write(InstrumentationData.TestStatus.LOGCAT, readLogcat(mTestStartMs)); + } + mTestStartMs = 0; + } + + proto.end(testStatusToken); outputProto(proto); } @@ -254,12 +276,12 @@ public class Instrument { Bundle results) { final ProtoOutputStream proto = new ProtoOutputStream(); - final long token = proto.start(InstrumentationData.Session.SESSION_STATUS); + final long sessionStatusToken = proto.start(InstrumentationData.Session.SESSION_STATUS); proto.write(InstrumentationData.SessionStatus.STATUS_CODE, InstrumentationData.SESSION_FINISHED); proto.write(InstrumentationData.SessionStatus.RESULT_CODE, resultCode); writeBundle(proto, InstrumentationData.SessionStatus.RESULTS, results); - proto.end(token); + proto.end(sessionStatusToken); outputProto(proto); } @@ -268,11 +290,11 @@ public class Instrument { public void onError(String errorText, boolean commandError) { final ProtoOutputStream proto = new ProtoOutputStream(); - final long token = proto.start(InstrumentationData.Session.SESSION_STATUS); + final long sessionStatusToken = proto.start(InstrumentationData.Session.SESSION_STATUS); proto.write(InstrumentationData.SessionStatus.STATUS_CODE, InstrumentationData.SESSION_ABORTED); proto.write(InstrumentationData.SessionStatus.ERROR_TEXT, errorText); - proto.end(token); + proto.end(sessionStatusToken); outputProto(proto); } @@ -514,5 +536,43 @@ public class Instrument { } } } + + private static String readLogcat(long startTimeMs) { + try { + // Figure out the timestamp arg for logcat. + final SimpleDateFormat format = new SimpleDateFormat("yyyy-MM-dd HH:mm:ss.SSS"); + final String timestamp = format.format(new Date(startTimeMs)); + + // Start the process + final Process process = new ProcessBuilder() + .command("logcat", "-d", "-v threadtime,uid", "-T", timestamp) + .start(); + + // Nothing to write. Don't let the command accidentally block. + process.getOutputStream().close(); + + // Read the output + final StringBuilder str = new StringBuilder(); + final InputStreamReader reader = new InputStreamReader(process.getInputStream()); + char[] buffer = new char[4096]; + int amt; + while ((amt = reader.read(buffer, 0, buffer.length)) >= 0) { + if (amt > 0) { + str.append(buffer, 0, amt); + } + } + + try { + process.waitFor(); + } catch (InterruptedException ex) { + // We already have the text, drop the exception. + } + + return str.toString(); + + } catch (IOException ex) { + return "Error reading logcat command:\n" + ex.toString(); + } + } } diff --git a/tools/bit/main.cpp b/tools/bit/main.cpp index 1a91f52bc6cf5..d80c2e742faee 100644 --- a/tools/bit/main.cpp +++ b/tools/bit/main.cpp @@ -290,8 +290,14 @@ TestResults::OnTestStatus(TestStatus& status) m_currentAction->target->name.c_str(), className.c_str(), testName.c_str(), g_escapeEndColor); - string stack = get_bundle_string(results, &found, "stack", NULL); - if (found) { + bool stackFound; + string stack = get_bundle_string(results, &stackFound, "stack", NULL); + if (status.has_logcat()) { + const string logcat = status.logcat(); + if (logcat.length() > 0) { + printf("%s\n", logcat.c_str()); + } + } else if (stackFound) { printf("%s\n", stack.c_str()); } }