Merge changes I6b499f53,If821ed21

* changes:
  dumpstate: report process times
  Add option to #define _DUMPSTATE_DRY_RUN_ to skip the actual dumps.

4 files changed, 192 insertions, 29 deletions

diff --git a/cmds/dumpstate/Android.mk b/cmds/dumpstate/Android.mk
index 6442701..b0cecdd 100644
--- a/cmds/dumpstate/Android.mk
+++ b/cmds/dumpstate/Android.mk
@@ -16,7 +16,7 @@ LOCAL_MODULE := dumpstate
 
 LOCAL_SHARED_LIBRARIES := libcutils liblog libselinux
 LOCAL_HAL_STATIC_LIBRARIES := libdumpstate
-LOCAL_CFLAGS += -Wall -Wno-unused-parameter -std=gnu99
+LOCAL_CFLAGS += -Wall -Werror -Wno-unused-parameter -std=gnu99
 LOCAL_INIT_RC := dumpstate.rc
 
 include $(BUILD_EXECUTABLE)
diff --git a/cmds/dumpstate/dumpstate.cpp b/cmds/dumpstate/dumpstate.cpp
index db12bf2..792d7e8 100644
--- a/cmds/dumpstate/dumpstate.cpp
+++ b/cmds/dumpstate/dumpstate.cpp
@@ -437,6 +437,7 @@ static void dumpstate() {
     run_command("LIST OF OPEN FILES", 10, SU_PATH, "root", "lsof", NULL);
     for_each_pid(do_showmap, "SMAPS OF ALL PROCESSES");
     for_each_tid(show_wchan, "BLOCKED PROCESS WAIT-CHANNELS");
+    for_each_pid(show_showtime, "PROCESS TIMES (pid cmd user system iowait+percentage)");
 
     if (screenshot_path[0]) {
         ALOGI("taking screenshot\n");
@@ -885,11 +886,12 @@ int main(int argc, char *argv[]) {
 
     /* tell activity manager we're done */
     if (do_broadcast && use_outfile && do_fb) {
-        run_command(NULL, 5, "/system/bin/am", "broadcast", "--user", "0",
+        const char *args[] = { "/system/bin/am", "broadcast", "--user", "0",
                 "-a", "android.intent.action.BUGREPORT_FINISHED",
                 "--es", "android.intent.extra.BUGREPORT", path,
                 "--es", "android.intent.extra.SCREENSHOT", screenshot_path,
-                "--receiver-permission", "android.permission.DUMP", NULL);
+                "--receiver-permission", "android.permission.DUMP", NULL };
+        run_command_always(NULL, 5, args);
     }
 
     ALOGI("done\n");
diff --git a/cmds/dumpstate/dumpstate.h b/cmds/dumpstate/dumpstate.h
index 3b6abc1..3063ec2 100644
--- a/cmds/dumpstate/dumpstate.h
+++ b/cmds/dumpstate/dumpstate.h
@@ -17,6 +17,18 @@
 #ifndef _DUMPSTATE_H_
 #define _DUMPSTATE_H_
 
+/* When defined, skips the real dumps and just print the section headers.
+   Useful when debugging dumpstate itself. */
+//#define _DUMPSTATE_DRY_RUN_
+
+#ifdef _DUMPSTATE_DRY_RUN_
+#define ON_DRY_RUN_RETURN(X) return X
+#endif
+#ifndef _DUMPSTATE_DRY_RUN_
+#define ON_DRY_RUN_RETURN(X)
+#endif
+
+
 #include <time.h>
 #include <unistd.h>
 #include <stdbool.h>
@@ -52,6 +64,11 @@ int dump_files(const char *title, const char *dir,
 /* forks a command and waits for it to finish -- terminate args with NULL */
 int run_command(const char *title, int timeout_seconds, const char *command, ...);
 
+/* forks a command and waits for it to finish
+   first element of args is the command, and last must be NULL.
+   command is always ran, even when _DUMPSTATE_DRY_RUN_ is defined. */
+int run_command_always(const char *title, int timeout_seconds, const char *args[]);
+
 /* prints all the system properties */
 void print_properties();
 
@@ -73,6 +90,9 @@ void for_each_tid(for_each_tid_func func, const char *header);
 /* Displays a blocked processes in-kernel wait channel */
 void show_wchan(int pid, int tid, const char *name);
 
+/* Displays a processes times */
+void show_showtime(int pid, const char *name);
+
 /* Runs "showmap" for a process */
 void do_showmap(int pid, const char *name);
 
diff --git a/cmds/dumpstate/utils.cpp b/cmds/dumpstate/utils.cpp
index c3e0262..0b1fa43 100644
--- a/cmds/dumpstate/utils.cpp
+++ b/cmds/dumpstate/utils.cpp
@@ -26,6 +26,7 @@
 #include <string.h>
 #include <sys/inotify.h>
 #include <sys/stat.h>
+#include <sys/sysconf.h>
 #include <sys/time.h>
 #include <sys/wait.h>
 #include <sys/klog.h>
@@ -60,6 +61,7 @@ static uint64_t nanotime() {
 }
 
 void for_each_userid(void (*func)(int), const char *header) {
+    ON_DRY_RUN_RETURN();
     DIR *d;
     struct dirent *de;
 
@@ -102,13 +104,32 @@ static void __for_each_pid(void (*helper)(int, const char *, void *), const char
             continue;
         }
 
-        sprintf(cmdpath,"/proc/%d/cmdline", pid);
         memset(cmdline, 0, sizeof(cmdline));
-        if ((fd = TEMP_FAILURE_RETRY(open(cmdpath, O_RDONLY | O_CLOEXEC))) < 0) {
-            strcpy(cmdline, "N/A");
-        } else {
-            read(fd, cmdline, sizeof(cmdline) - 1);
+
+        snprintf(cmdpath, sizeof(cmdpath), "/proc/%d/cmdline", pid);
+        if ((fd = TEMP_FAILURE_RETRY(open(cmdpath, O_RDONLY | O_CLOEXEC))) >= 0) {
+            TEMP_FAILURE_RETRY(read(fd, cmdline, sizeof(cmdline) - 2));
             close(fd);
+            if (cmdline[0]) {
+                helper(pid, cmdline, arg);
+                continue;
+            }
+        }
+
+        // if no cmdline, a kernel thread has comm
+        snprintf(cmdpath, sizeof(cmdpath), "/proc/%d/comm", pid);
+        if ((fd = TEMP_FAILURE_RETRY(open(cmdpath, O_RDONLY | O_CLOEXEC))) >= 0) {
+            TEMP_FAILURE_RETRY(read(fd, cmdline + 1, sizeof(cmdline) - 4));
+            close(fd);
+            if (cmdline[1]) {
+                cmdline[0] = '[';
+                size_t len = strcspn(cmdline, "\f\b\r\n");
+                cmdline[len] = ']';
+                cmdline[len+1] = '\0';
+            }
+        }
+        if (!cmdline[0]) {
+            strcpy(cmdline, "N/A");
         }
         helper(pid, cmdline, arg);
     }
@@ -122,6 +143,7 @@ static void for_each_pid_helper(int pid, const char *cmdline, void *arg) {
 }
 
 void for_each_pid(for_each_pid_func func, const char *header) {
+    ON_DRY_RUN_RETURN();
     __for_each_pid(for_each_pid_helper, header, (void *) func);
 }
 
@@ -159,7 +181,7 @@ static void for_each_tid_helper(int pid, const char *cmdline, void *arg) {
             strcpy(comm, "N/A");
         } else {
             char *c;
-            read(fd, comm, sizeof(comm) - 1);
+            TEMP_FAILURE_RETRY(read(fd, comm, sizeof(comm) - 2));
             close(fd);
 
             c = strrchr(comm, '\n');
@@ -174,13 +196,15 @@ static void for_each_tid_helper(int pid, const char *cmdline, void *arg) {
 }
 
 void for_each_tid(for_each_tid_func func, const char *header) {
+    ON_DRY_RUN_RETURN();
     __for_each_pid(for_each_tid_helper, header, (void *) func);
 }
 
 void show_wchan(int pid, int tid, const char *name) {
+    ON_DRY_RUN_RETURN();
     char path[255];
     char buffer[255];
-    int fd;
+    int fd, ret, save_errno;
     char name_buffer[255];
 
     memset(buffer, 0, sizeof(buffer));
@@ -191,9 +215,13 @@ void show_wchan(int pid, int tid, const char *name) {
         return;
     }
 
-    if (read(fd, buffer, sizeof(buffer)) < 0) {
-        printf("Failed to read '%s' (%s)\n", path, strerror(errno));
-        goto out_close;
+    ret = TEMP_FAILURE_RETRY(read(fd, buffer, sizeof(buffer)));
+    save_errno = errno;
+    close(fd);
+
+    if (ret < 0) {
+        printf("Failed to read '%s' (%s)\n", path, strerror(save_errno));
+        return;
     }
 
     snprintf(name_buffer, sizeof(name_buffer), "%*s%s",
@@ -201,13 +229,109 @@ void show_wchan(int pid, int tid, const char *name) {
 
     printf("%-7d %-32s %s\n", tid, name_buffer, buffer);
 
-out_close:
+    return;
+}
+
+// print time in centiseconds
+static void snprcent(char *buffer, size_t len, size_t spc,
+                     unsigned long long time) {
+    static long hz; // cache discovered hz
+
+    if (hz <= 0) {
+        hz = sysconf(_SC_CLK_TCK);
+        if (hz <= 0) {
+            hz = 1000;
+        }
+    }
+
+    // convert to centiseconds
+    time = (time * 100 + (hz / 2)) / hz;
+
+    char str[16];
+
+    snprintf(str, sizeof(str), " %llu.%02u",
+             time / 100, (unsigned)(time % 100));
+    size_t offset = strlen(buffer);
+    snprintf(buffer + offset, (len > offset) ? len - offset : 0,
+             "%*s", (spc > offset) ? (int)(spc - offset) : 0, str);
+}
+
+// print permille as a percent
+static void snprdec(char *buffer, size_t len, size_t spc, unsigned permille) {
+    char str[16];
+
+    snprintf(str, sizeof(str), " %u.%u%%", permille / 10, permille % 10);
+    size_t offset = strlen(buffer);
+    snprintf(buffer + offset, (len > offset) ? len - offset : 0,
+             "%*s", (spc > offset) ? (int)(spc - offset) : 0, str);
+}
+
+void show_showtime(int pid, const char *name) {
+    ON_DRY_RUN_RETURN();
+    char path[255];
+    char buffer[1023];
+    int fd, ret, save_errno;
+
+    memset(buffer, 0, sizeof(buffer));
+
+    sprintf(path, "/proc/%d/stat", pid);
+    if ((fd = TEMP_FAILURE_RETRY(open(path, O_RDONLY | O_CLOEXEC))) < 0) {
+        printf("Failed to open '%s' (%s)\n", path, strerror(errno));
+        return;
+    }
+
+    ret = TEMP_FAILURE_RETRY(read(fd, buffer, sizeof(buffer)));
+    save_errno = errno;
     close(fd);
+
+    if (ret < 0) {
+        printf("Failed to read '%s' (%s)\n", path, strerror(save_errno));
+        return;
+    }
+
+    // field 14 is utime
+    // field 15 is stime
+    // field 42 is iotime
+    unsigned long long utime = 0, stime = 0, iotime = 0;
+    if (sscanf(buffer,
+               "%*llu %*s %*s %*lld %*lld %*lld %*lld %*lld %*lld %*lld %*lld "
+               "%*lld %*lld %llu %llu %*lld %*lld %*lld %*lld %*lld %*lld "
+               "%*lld %*lld %*lld %*lld %*lld %*lld %*lld %*lld %*lld %*lld "
+               "%*lld %*lld %*lld %*lld %*lld %*lld %*lld %*lld %*lld %llu ",
+               &utime, &stime, &iotime) != 3) {
+        return;
+    }
+
+    unsigned long long total = utime + stime;
+    if (!total) {
+        return;
+    }
+
+    unsigned permille = (iotime * 1000 + (total / 2)) / total;
+    if (permille > 1000) {
+        permille = 1000;
+    }
+
+    // try to beautify and stabilize columns at <80 characters
+    snprintf(buffer, sizeof(buffer), "%-6d%s", pid, name);
+    if ((name[0] != '[') || utime) {
+        snprcent(buffer, sizeof(buffer), 57, utime);
+    }
+    snprcent(buffer, sizeof(buffer), 65, stime);
+    if ((name[0] != '[') || iotime) {
+        snprcent(buffer, sizeof(buffer), 73, iotime);
+    }
+    if (iotime) {
+        snprdec(buffer, sizeof(buffer), 79, permille);
+    }
+    puts(buffer); // adds a trailing newline
+
     return;
 }
 
 void do_dmesg() {
     printf("------ KERNEL LOG (dmesg) ------\n");
+    ON_DRY_RUN_RETURN();
     /* Get size of kernel buffer */
     int size = klogctl(KLOG_SIZE_BUFFER, NULL, 0);
     if (size <= 0) {
@@ -299,10 +423,12 @@ static int _dump_file_from_fd(const char *title, const char *path, int fd) {
 
 /* prints the contents of a file */
 int dump_file(const char *title, const char *path) {
+    if (title) printf("------ %s (%s) ------\n", title, path);
+    ON_DRY_RUN_RETURN(0);
+
     int fd = TEMP_FAILURE_RETRY(open(path, O_RDONLY | O_NONBLOCK | O_CLOEXEC));
     if (fd < 0) {
         int err = errno;
-        if (title) printf("------ %s (%s) ------\n", title, path);
         printf("*** %s: %s\n", path, strerror(err));
         if (title) printf("\n");
         return -1;
@@ -328,6 +454,7 @@ int dump_files(const char *title, const char *dir,
     if (title) {
         printf("------ %s (%s) ------\n", title, dir);
     }
+    ON_DRY_RUN_RETURN(0);
 
     if (dir[strlen(dir) - 1] == '/') {
         ++slash;
@@ -384,6 +511,7 @@ int dump_files(const char *title, const char *dir,
  * stuck.
  */
 int dump_file_from_fd(const char *title, const char *path, int fd) {
+    ON_DRY_RUN_RETURN(0);
     int flags = fcntl(fd, F_GETFL);
     if (flags == -1) {
         printf("*** %s: failed to get flags on fd %d: %s\n", path, fd, strerror(errno));
@@ -442,6 +570,29 @@ bool waitpid_with_timeout(pid_t pid, int timeout_seconds, int* status) {
 /* forks a command and waits for it to finish */
 int run_command(const char *title, int timeout_seconds, const char *command, ...) {
     fflush(stdout);
+
+    const char *args[1024] = {command};
+    size_t arg;
+    va_list ap;
+    va_start(ap, command);
+    if (title) printf("------ %s (%s", title, command);
+    for (arg = 1; arg < sizeof(args) / sizeof(args[0]); ++arg) {
+        args[arg] = va_arg(ap, const char *);
+        if (args[arg] == NULL) break;
+        if (title) printf(" %s", args[arg]);
+    }
+    if (title) printf(") ------\n");
+    fflush(stdout);
+
+    ON_DRY_RUN_RETURN(0);
+
+    return run_command_always(title, timeout_seconds, args);
+}
+
+/* forks a command and waits for it to finish */
+int run_command_always(const char *title, int timeout_seconds, const char *args[]) {
+    const char *command = args[0];
+
     uint64_t start = nanotime();
     pid_t pid = fork();
 
@@ -453,8 +604,6 @@ int run_command(const char *title, int timeout_seconds, const char *command, ...
 
     /* handle child case */
     if (pid == 0) {
-        const char *args[1024] = {command};
-        size_t arg;
 
         /* make sure the child dies when dumpstate dies */
         prctl(PR_SET_PDEATHSIG, SIGKILL);
@@ -465,17 +614,6 @@ int run_command(const char *title, int timeout_seconds, const char *command, ...
         sigact.sa_handler = SIG_IGN;
         sigaction(SIGPIPE, &sigact, NULL);
 
-        va_list ap;
-        va_start(ap, command);
-        if (title) printf("------ %s (%s", title, command);
-        for (arg = 1; arg < sizeof(args) / sizeof(args[0]); ++arg) {
-            args[arg] = va_arg(ap, const char *);
-            if (args[arg] == NULL) break;
-            if (title) printf(" %s", args[arg]);
-        }
-        if (title) printf(") ------\n");
-        fflush(stdout);
-
         execvp(command, (char**) args);
         printf("*** exec(%s): %s\n", command, strerror(errno));
         fflush(stdout);
@@ -532,12 +670,13 @@ static int compare_prop(const void *a, const void *b) {
 
 /* prints all the system properties */
 void print_properties() {
+    printf("------ SYSTEM PROPERTIES ------\n");
+    ON_DRY_RUN_RETURN();
     size_t i;
     num_props = 0;
     property_list(print_prop, NULL);
     qsort(&props, num_props, sizeof(props[0]), compare_prop);
 
-    printf("------ SYSTEM PROPERTIES ------\n");
     for (i = 0; i < num_props; ++i) {
         fputs(props[i], stdout);
         free(props[i]);
@@ -611,6 +750,7 @@ static bool should_dump_native_traces(const char* path) {
 
 /* dump Dalvik and native stack traces, return the trace file location (NULL if none) */
 const char *dump_traces() {
+    ON_DRY_RUN_RETURN(NULL);
     const char* result = NULL;
 
     char traces_path[PROPERTY_VALUE_MAX] = "";
@@ -764,6 +904,7 @@ error_close_fd:
 }
 
 void dump_route_tables() {
+    ON_DRY_RUN_RETURN();
     const char* const RT_TABLES_PATH = "/data/misc/net/rt_tables";
     dump_file("RT_TABLES", RT_TABLES_PATH);
     FILE* fp = fopen(RT_TABLES_PATH, "re");