Moar tests for RunCommand:

- Command not found.
- Command returns non-0 status (and fixed return of RunCommand).
- Command times out.
- Command is killed.
- Command crashes.
- Command logs initial message.

BUG: 31807540
Test:  mmm -j32 frameworks/native/cmds/dumpstate/ && adb push ${ANDROID_PRODUCT_OUT}/data/nativetest/dumpstate_test* /data/nativetest && adb shell /data/nativetest/dumpstate_test/dumpstate_test
Change-Id: I6459846791e45f4ebc4433b83feec81be4050167
diff --git a/cmds/dumpstate/dumpstate.h b/cmds/dumpstate/dumpstate.h
index 1c570b0..eef3ac7 100644
--- a/cmds/dumpstate/dumpstate.h
+++ b/cmds/dumpstate/dumpstate.h
@@ -37,9 +37,6 @@
 #include <string>
 #include <vector>
 
-// TODO: remove once dumpstate_board() devices use CommandOptions
-#define SU_PATH "/system/xbin/su"
-
 // Workaround for const char *args[MAX_ARGS_ARRAY_SIZE] variables until they're converted to
 // std::vector<std::string>
 // TODO: remove once not used
diff --git a/cmds/dumpstate/tests/dumpstate_test.cpp b/cmds/dumpstate/tests/dumpstate_test.cpp
index 9e59080..27826a1 100644
--- a/cmds/dumpstate/tests/dumpstate_test.cpp
+++ b/cmds/dumpstate/tests/dumpstate_test.cpp
@@ -20,9 +20,13 @@
 #include <gtest/gtest.h>
 
 #include <libgen.h>
+#include <signal.h>
+#include <sys/types.h>
 #include <unistd.h>
+#include <thread>
 
 #include <android-base/file.h>
+#include <android-base/strings.h>
 
 using ::testing::EndsWith;
 using ::testing::IsEmpty;
@@ -49,7 +53,7 @@
                    const CommandOptions& options = CommandOptions::DEFAULT) {
         CaptureStdout();
         CaptureStderr();
-        int status = ds_.RunCommand(title, fullCommand, options);
+        int status = ds.RunCommand(title, fullCommand, options);
         out = GetCapturedStdout();
         err = GetCapturedStderr();
         return status;
@@ -59,14 +63,14 @@
     std::string out, err;
 
     std::string testPath = dirname(android::base::GetExecutablePath().c_str());
-    std::string simpleBin = testPath + "/../dumpstate_test_fixture/dumpstate_test_fixture";
+    std::string simpleCommand = testPath + "/../dumpstate_test_fixture/dumpstate_test_fixture";
+    std::string echoCommand = "/system/bin/echo";
+
+    Dumpstate& ds = Dumpstate::GetInstance();
 
     void SetDryRun(bool dryRun) {
-        ds_.dryRun_ = dryRun;
+        ds.dryRun_ = dryRun;
     }
-
-  private:
-    Dumpstate& ds_ = Dumpstate::GetInstance();
 };
 
 TEST_F(DumpstateTest, RunCommandNoArgs) {
@@ -74,43 +78,52 @@
 }
 
 TEST_F(DumpstateTest, RunCommandNoTitle) {
-    EXPECT_EQ(0, RunCommand("", {simpleBin}));
+    EXPECT_EQ(0, RunCommand("", {simpleCommand}));
     EXPECT_THAT(out, StrEq("stdout\n"));
     EXPECT_THAT(err, StrEq("stderr\n"));
 }
 
 TEST_F(DumpstateTest, RunCommandWithTitle) {
-    EXPECT_EQ(0, RunCommand("I AM GROOT", {simpleBin}));
+    EXPECT_EQ(0, RunCommand("I AM GROOT", {simpleCommand}));
     EXPECT_THAT(err, StrEq("stderr\n"));
     // We don't know the exact duration, so we check the prefix and suffix
-    EXPECT_THAT(out, StartsWith("------ I AM GROOT (" + simpleBin + ") ------\nstdout\n------"));
+    EXPECT_THAT(out,
+                StartsWith("------ I AM GROOT (" + simpleCommand + ") ------\nstdout\n------"));
     EXPECT_THAT(out, EndsWith("s was the duration of 'I AM GROOT' ------\n"));
 }
 
-TEST_F(DumpstateTest, RunCommandRedirectStderr) {
+TEST_F(DumpstateTest, RunCommandWithLoggingMessage) {
     EXPECT_EQ(
-        0, RunCommand("", {simpleBin}, CommandOptions::WithTimeout(10).RedirectStderr().Build()));
+        0, RunCommand("", {simpleCommand},
+                      CommandOptions::WithTimeout(10).Log("COMMAND, Y U NO LOG FIRST?").Build()));
+    EXPECT_THAT(out, StrEq("stdout\n"));
+    EXPECT_THAT(err, StrEq("COMMAND, Y U NO LOG FIRST?stderr\n"));
+}
+
+TEST_F(DumpstateTest, RunCommandRedirectStderr) {
+    EXPECT_EQ(0, RunCommand("", {simpleCommand},
+                            CommandOptions::WithTimeout(10).RedirectStderr().Build()));
     EXPECT_THAT(out, IsEmpty());
-    EXPECT_THAT(err, StrEq("stderr\nstdout\n"));
+    EXPECT_THAT(err, StrEq("stdout\nstderr\n"));
 }
 
 TEST_F(DumpstateTest, RunCommandWithOneArg) {
-    EXPECT_EQ(0, RunCommand("", {simpleBin, "one"}));
+    EXPECT_EQ(0, RunCommand("", {echoCommand, "one"}));
     EXPECT_THAT(err, IsEmpty());
     EXPECT_THAT(out, StrEq("one\n"));
 }
 
-TEST_F(DumpstateTest, RunCommandWithNoArgs) {
-    EXPECT_EQ(0, RunCommand("", {simpleBin, "one", "is", "the", "loniest", "number"}));
+TEST_F(DumpstateTest, RunCommandWithMultipleArgs) {
+    EXPECT_EQ(0, RunCommand("", {echoCommand, "one", "is", "the", "loniest", "number"}));
     EXPECT_THAT(err, IsEmpty());
     EXPECT_THAT(out, StrEq("one is the loniest number\n"));
 }
 
 TEST_F(DumpstateTest, RunCommandDryRun) {
     SetDryRun(true);
-    EXPECT_EQ(0, RunCommand("I AM GROOT", {simpleBin}));
+    EXPECT_EQ(0, RunCommand("I AM GROOT", {simpleCommand}));
     // We don't know the exact duration, so we check the prefix and suffix
-    EXPECT_THAT(out, StartsWith("------ I AM GROOT (" + simpleBin +
+    EXPECT_THAT(out, StartsWith("------ I AM GROOT (" + simpleCommand +
                                 ") ------\n\t(skipped on dry run)\n------"));
     EXPECT_THAT(out, EndsWith("s was the duration of 'I AM GROOT' ------\n"));
     EXPECT_THAT(err, IsEmpty());
@@ -118,26 +131,91 @@
 
 TEST_F(DumpstateTest, RunCommandDryRunNoTitle) {
     SetDryRun(true);
-    EXPECT_EQ(0, RunCommand("", {simpleBin}));
+    EXPECT_EQ(0, RunCommand("", {simpleCommand}));
     EXPECT_THAT(out, IsEmpty());
     EXPECT_THAT(err, IsEmpty());
 }
 
 TEST_F(DumpstateTest, RunCommandDryRunAlways) {
     SetDryRun(true);
-    EXPECT_EQ(0, RunCommand("", {simpleBin}, CommandOptions::WithTimeout(10).Always().Build()));
+    EXPECT_EQ(0, RunCommand("", {simpleCommand}, CommandOptions::WithTimeout(10).Always().Build()));
     EXPECT_THAT(out, StrEq("stdout\n"));
     EXPECT_THAT(err, StrEq("stderr\n"));
 }
 
+TEST_F(DumpstateTest, RunCommandNotFound) {
+    EXPECT_NE(0, RunCommand("", {"/there/cannot/be/such/command"}));
+    EXPECT_THAT(out, StartsWith("*** command '/there/cannot/be/such/command' failed: exit code"));
+    EXPECT_THAT(err, StartsWith("execvp on command '/there/cannot/be/such/command' failed"));
+}
+
+TEST_F(DumpstateTest, RunCommandFails) {
+    EXPECT_EQ(42, RunCommand("", {simpleCommand, "--exit", "42"}));
+    EXPECT_THAT(
+        out, StrEq("stdout\n*** command '" + simpleCommand + " --exit 42' failed: exit code 42\n"));
+    EXPECT_THAT(
+        err, StrEq("stderr\n*** command '" + simpleCommand + " --exit 42' failed: exit code 42\n"));
+}
+
+TEST_F(DumpstateTest, RunCommandCrashes) {
+    EXPECT_NE(0, RunCommand("", {simpleCommand, "--crash"}));
+    // We don't know the exit code, so check just the prefix.
+    EXPECT_THAT(
+        out, StartsWith("stdout\n*** command '" + simpleCommand + " --crash' failed: exit code"));
+    EXPECT_THAT(
+        err, StartsWith("stderr\n*** command '" + simpleCommand + " --crash' failed: exit code"));
+}
+
+TEST_F(DumpstateTest, RunCommandTimesout) {
+    EXPECT_EQ(-1, RunCommand("", {simpleCommand, "--sleep", "2"},
+                             CommandOptions::WithTimeout(1).Build()));
+    EXPECT_THAT(out, StartsWith("stdout line1\n*** command '" + simpleCommand +
+                                " --sleep 2' timed out after 1"));
+    EXPECT_THAT(err, StartsWith("sleeping for 2s\n*** command '" + simpleCommand +
+                                " --sleep 2' timed out after 1"));
+}
+
+TEST_F(DumpstateTest, RunCommandIsKilled) {
+    CaptureStdout();
+    CaptureStderr();
+
+    std::thread t([=]() {
+        EXPECT_EQ(SIGTERM, ds.RunCommand("", {simpleCommand, "--pid", "--sleep", "20"},
+                                         CommandOptions::WithTimeout(100).Always().Build()));
+    });
+
+    // Capture pid and pre-sleep output.
+    sleep(1);  // Wait a little bit to make sure pid and 1st line were printed.
+    std::string err = GetCapturedStderr();
+    EXPECT_THAT(err, StrEq("sleeping for 20s\n"));
+
+    std::string out = GetCapturedStdout();
+    std::vector<std::string> lines = android::base::Split(out, "\n");
+    ASSERT_EQ(3, (int)lines.size()) << "Invalid lines before sleep: " << out;
+
+    int pid = atoi(lines[0].c_str());
+    EXPECT_THAT(lines[1], StrEq("stdout line1"));
+    EXPECT_THAT(lines[2], IsEmpty());  // \n
+
+    // Then kill the process.
+    CaptureStdout();
+    CaptureStderr();
+    ASSERT_EQ(0, kill(pid, SIGTERM)) << "failed to kill pid " << pid;
+    t.join();
+
+    // Finally, check output after murder.
+    out = GetCapturedStdout();
+    err = GetCapturedStderr();
+
+    EXPECT_THAT(out, StrEq("*** command '" + simpleCommand +
+                           " --pid --sleep 20' failed: killed by signal 15\n"));
+    EXPECT_THAT(err, StrEq("*** command '" + simpleCommand +
+                           " --pid --sleep 20' failed: killed by signal 15\n"));
+}
+
 // TODO: add test for other scenarios:
 // - AsRoot()
 // - DropRoot
-// - WithLoggingMessage()
-// - command does not exist (invalid path)
-// - command times out
-// - command exits with a different value
-// - command is killed before timed out
 // - test progress
 
 // TODO: test DumpFile()
diff --git a/cmds/dumpstate/tests/dumpstate_test_fixture.cpp b/cmds/dumpstate/tests/dumpstate_test_fixture.cpp
index 5ac4cc7..9af2246 100644
--- a/cmds/dumpstate/tests/dumpstate_test_fixture.cpp
+++ b/cmds/dumpstate/tests/dumpstate_test_fixture.cpp
@@ -15,30 +15,86 @@
  */
 
 #include <stdio.h>
+#include <stdlib.h>
+#include <string.h>
+#include <unistd.h>
+
+#define LOG_TAG "dumpstate"
+#include <cutils/log.h>
+
+void PrintDefaultOutput() {
+    fprintf(stdout, "stdout\n");
+    fflush(stdout);
+    fprintf(stderr, "stderr\n");
+    fflush(stderr);
+}
 
 /*
  * Binary used to on RunCommand tests.
  *
  * Usage:
  *
- * - It returns 0 unless documented otherwise.
- * - Without any arguments, prints `stdout\n` on `stdout` and `stderr\n` on `stderr`.
- * - With arguments, prints all arguments on `stdout` separated by ` `.
+ * - Unless stated otherwise this command:
+ *
+ *   1.Prints `stdout\n` on `stdout` and flushes it.
+ *   2.Prints `stderr\n` on `stderr` and flushes it.
+ *   3.Exit with status 0.
+ *
+ * - If 1st argument is '--pid', it first prints its pid on `stdout`.
+ *
+ * - If 1st argument is '--crash', it uses ALOGF to crash and returns 666.
+ *
+ * - With argument '--exit' 'CODE', returns CODE;
+ *
+ * - With argument '--sleep 'TIME':
+ *
+ *   1.Prints `stdout line1\n` on `stdout` and `sleeping TIME s\n` on `stderr`
+ *   2.Sleeps for TIME s
+ *   3.Prints `stdout line2\n` on `stdout` and `woke up\n` on `stderr`
  */
 int main(int argc, char* const argv[]) {
+    if (argc == 2) {
+        if (strcmp(argv[1], "--crash") == 0) {
+            PrintDefaultOutput();
+            LOG_FATAL("D'OH\n");
+            return 666;
+        }
+    }
+    if (argc == 3) {
+        if (strcmp(argv[1], "--exit") == 0) {
+            PrintDefaultOutput();
+            return atoi(argv[2]);
+        }
+    }
+
     if (argc > 1) {
-        for (int i = 1; i < argc; i++) {
-            fprintf(stdout, "%s", argv[i]);
-            if (i == argc - 1) {
-                fprintf(stdout, "\n");
-            } else {
-                fprintf(stdout, " ");
+        int index = 1;
+
+        // First check arguments that can shift the index.
+        if (strcmp(argv[1], "--pid") == 0) {
+            index++;
+            fprintf(stdout, "%d\n", getpid());
+            fflush(stdout);
+        }
+
+        if (argc > index + 1) {
+            // Then the "common" arguments.
+            if (strcmp(argv[index], "--sleep") == 0) {
+                int napTime = atoi(argv[index + 1]);
+                fprintf(stdout, "stdout line1\n");
+                fflush(stdout);
+                fprintf(stderr, "sleeping for %ds\n", napTime);
+                fflush(stderr);
+                sleep(napTime);
+                fprintf(stdout, "stdout line2\n");
+                fflush(stdout);
+                fprintf(stderr, "woke up\n");
+                fflush(stderr);
+                return 0;
             }
         }
-        return 0;
     }
-    fprintf(stdout, "stdout\n");
-    fprintf(stderr, "stderr\n");
 
+    PrintDefaultOutput();
     return 0;
 }
diff --git a/cmds/dumpstate/utils.cpp b/cmds/dumpstate/utils.cpp
index 55316c5..b347ce8 100644
--- a/cmds/dumpstate/utils.cpp
+++ b/cmds/dumpstate/utils.cpp
@@ -50,6 +50,8 @@
 
 #include "dumpstate.h"
 
+#define SU_PATH "/system/xbin/su"
+
 static const int64_t NANOS_PER_SEC = 1000000000;
 
 static const int TRACE_DUMP_TIMEOUT_MS = 10000; // 10 seconds
@@ -870,7 +872,7 @@
             if (!silent)
                 printf("*** command '%s' timed out after %.3fs (killing pid %d)\n", command,
                        (float)elapsed / NANOS_PER_SEC, pid);
-            MYLOGE("command '%s' timed out after %.3fs (killing pid %d)\n", command,
+            MYLOGE("*** command '%s' timed out after %.3fs (killing pid %d)\n", command,
                    (float)elapsed / NANOS_PER_SEC, pid);
         } else {
             if (!silent)
@@ -880,9 +882,9 @@
                    (float)elapsed / NANOS_PER_SEC, pid);
         }
         kill(pid, SIGTERM);
-        if (!waitpid_with_timeout(pid, 5, NULL)) {
+        if (!waitpid_with_timeout(pid, 5, nullptr)) {
             kill(pid, SIGKILL);
-            if (!waitpid_with_timeout(pid, 5, NULL)) {
+            if (!waitpid_with_timeout(pid, 5, nullptr)) {
                 if (!silent)
                     printf("could not kill command '%s' (pid %d) even with SIGKILL.\n", command,
                            pid);
@@ -893,11 +895,13 @@
     }
 
     if (WIFSIGNALED(status)) {
-        if (!silent) printf("*** %s: Killed by signal %d\n", command, WTERMSIG(status));
-        MYLOGE("*** %s: Killed by signal %d\n", command, WTERMSIG(status));
+        if (!silent)
+            printf("*** command '%s' failed: killed by signal %d\n", command, WTERMSIG(status));
+        MYLOGE("*** command '%s' failed: killed by signal %d\n", command, WTERMSIG(status));
     } else if (WIFEXITED(status) && WEXITSTATUS(status) > 0) {
-        if (!silent) printf("*** %s: Exit code %d\n", command, WEXITSTATUS(status));
-        MYLOGE("*** %s: Exit code %d\n", command, WEXITSTATUS(status));
+        status = WEXITSTATUS(status);
+        if (!silent) printf("*** command '%s' failed: exit code %d\n", command, status);
+        MYLOGE("*** command '%s' failed: exit code %d\n", command, status);
     }
 
     if (weight > 0) {