commit 8d945c02da15d12e714db0b6be39589636f51ca9
author Nandana Dutt <nandana@google.com> Wed Aug 14 13:30:07 2019 +0100
committer Nandana Dutt <nandana@google.com> Thu Aug 15 11:33:07 2019 +0100
tree d38cdb20c99416e173ddbaa3a411bbad6f2ca4e9
parent e75ab2a74185a6c3d7008fd96a048118b3eb5956

Allow duration of some commands to be logged.

BUG: 137580007
Test: bugreport contains duration for (EVENT LOG, STATS LOG, RADIO LOG).
      But does not contain duration for other quick running commands.
Change-Id: I771a79052f4a6522ad98b22d4a49331d7ac59584

cmds/dumpstate/dumpstate.cpp

diff --git a/cmds/dumpstate/dumpstate.cpp b/cmds/dumpstate/dumpstate.cpp
index 957dfa1..0b9dada 100644
--- a/cmds/dumpstate/dumpstate.cpp
+++ b/cmds/dumpstate/dumpstate.cpp
@@ -115,8 +115,9 @@
 // TODO: temporary variables and functions used during C++ refactoring
 static Dumpstate& ds = Dumpstate::GetInstance();
 static int RunCommand(const std::string& title, const std::vector<std::string>& full_command,
-                      const CommandOptions& options = CommandOptions::DEFAULT) {
-    return ds.RunCommand(title, full_command, options);
+                      const CommandOptions& options = CommandOptions::DEFAULT,
+                      bool verbose_duration = false) {
+    return ds.RunCommand(title, full_command, options, verbose_duration);
 }
 
 // Reasonable value for max stats.
@@ -867,17 +868,17 @@
     RunCommand(
         "EVENT LOG",
         {"logcat", "-b", "events", "-v", "threadtime", "-v", "printable", "-v", "uid", "-d", "*:v"},
-        CommandOptions::WithTimeoutInMs(timeout_ms).Build());
+        CommandOptions::WithTimeoutInMs(timeout_ms).Build(), true /* verbose_duration */);
     timeout_ms = logcat_timeout({"stats"});
     RunCommand(
         "STATS LOG",
         {"logcat", "-b", "stats", "-v", "threadtime", "-v", "printable", "-v", "uid", "-d", "*:v"},
-        CommandOptions::WithTimeoutInMs(timeout_ms).Build());
+        CommandOptions::WithTimeoutInMs(timeout_ms).Build(), true /* verbose_duration */);
     timeout_ms = logcat_timeout({"radio"});
     RunCommand(
         "RADIO LOG",
         {"logcat", "-b", "radio", "-v", "threadtime", "-v", "printable", "-v", "uid", "-d", "*:v"},
-        CommandOptions::WithTimeoutInMs(timeout_ms).Build());
+        CommandOptions::WithTimeoutInMs(timeout_ms).Build(), true /* verbose_duration */);
 
     RunCommand("LOG STATISTICS", {"logcat", "-b", "all", "-S"});
 
@@ -2814,8 +2815,8 @@
     return singleton_;
 }
 
-DurationReporter::DurationReporter(const std::string& title, bool logcat_only)
-    : title_(title), logcat_only_(logcat_only) {
+DurationReporter::DurationReporter(const std::string& title, bool logcat_only, bool verbose)
+    : title_(title), logcat_only_(logcat_only), verbose_(verbose) {
     if (!title_.empty()) {
         started_ = Nanotime();
     }
@@ -2824,7 +2825,7 @@
 DurationReporter::~DurationReporter() {
     if (!title_.empty()) {
         float elapsed = (float)(Nanotime() - started_) / NANOS_PER_SEC;
-        if (elapsed < .5f) {
+        if (elapsed < .5f && !verbose_) {
             return;
         }
         MYLOGD("Duration of '%s': %.2fs\n", title_.c_str(), elapsed);
@@ -3417,8 +3418,8 @@
 }
 
 int Dumpstate::RunCommand(const std::string& title, const std::vector<std::string>& full_command,
-                          const CommandOptions& options) {
-    DurationReporter duration_reporter(title);
+                          const CommandOptions& options, bool verbose_duration) {
+    DurationReporter duration_reporter(title, false /* logcat_only */, verbose_duration);
 
     int status = RunCommandToFd(STDOUT_FILENO, title, full_command, options);