Improved usage of stderr for logging.

Dumpstate have some macros that write logs to both ALOG and stderr,
which is useful when the latter is redirected to a file.

But prior to this change, only the log statements from dumpstate.cpp
were using it, and utils.cpp was logging to stderr directly.

This change not only uses MYLOGE for all error messages, but also closes
stderr at the very end (so it doesn't miss statements like the
parameters sent to send_broadcast) and uses MYLOGD for the overall progress.

BUG: 27437378
Change-Id: I373a523e20c98d8f445822103784fa9900c6c684
diff --git a/cmds/dumpstate/utils.cpp b/cmds/dumpstate/utils.cpp
index f0ae325..884f250 100644
--- a/cmds/dumpstate/utils.cpp
+++ b/cmds/dumpstate/utils.cpp
@@ -501,7 +501,7 @@
     dirp = opendir(dir);
     if (dirp == NULL) {
         retval = -errno;
-        fprintf(stderr, "%s: %s\n", dir, strerror(errno));
+        MYLOGE("%s: %s\n", dir, strerror(errno));
         return retval;
     }
 
@@ -702,7 +702,7 @@
 
 void send_broadcast(const std::string& action, const std::vector<std::string>& args) {
     if (args.size() > 1000) {
-        fprintf(stderr, "send_broadcast: too many arguments (%d)\n", (int) args.size());
+        MYLOGE("send_broadcast: too many arguments (%d)\n", (int) args.size());
         return;
     }
     const char *am_args[1024] = { SU_PATH, "shell", "/system/bin/am", "broadcast",
@@ -755,12 +755,12 @@
 void redirect_to_socket(FILE *redirect, const char *service) {
     int s = android_get_control_socket(service);
     if (s < 0) {
-        fprintf(stderr, "android_get_control_socket(%s): %s\n", service, strerror(errno));
+        MYLOGE("android_get_control_socket(%s): %s\n", service, strerror(errno));
         exit(1);
     }
     fcntl(s, F_SETFD, FD_CLOEXEC);
     if (listen(s, 4) < 0) {
-        fprintf(stderr, "listen(control socket): %s\n", strerror(errno));
+        MYLOGE("listen(control socket): %s\n", strerror(errno));
         exit(1);
     }
 
@@ -768,7 +768,7 @@
     socklen_t alen = sizeof(addr);
     int fd = accept(s, &addr, &alen);
     if (fd < 0) {
-        fprintf(stderr, "accept(control socket): %s\n", strerror(errno));
+        MYLOGE("accept(control socket): %s\n", strerror(errno));
         exit(1);
     }
 
@@ -810,7 +810,7 @@
     int fd = TEMP_FAILURE_RETRY(open(path, O_WRONLY | O_CREAT | O_TRUNC | O_CLOEXEC | O_NOFOLLOW,
                                      S_IRUSR | S_IWUSR | S_IRGRP | S_IROTH));
     if (fd < 0) {
-        fprintf(stderr, "%s: %s\n", path, strerror(errno));
+        MYLOGE("%s: %s\n", path, strerror(errno));
         exit(1);
     }
 
@@ -842,7 +842,7 @@
     strlcpy(anr_traces_path, traces_path, sizeof(anr_traces_path));
     strlcat(anr_traces_path, ".anr", sizeof(anr_traces_path));
     if (rename(traces_path, anr_traces_path) && errno != ENOENT) {
-        fprintf(stderr, "rename(%s, %s): %s\n", traces_path, anr_traces_path, strerror(errno));
+        MYLOGE("rename(%s, %s): %s\n", traces_path, anr_traces_path, strerror(errno));
         return NULL;  // Can't rename old traces.txt -- no permission? -- leave it alone instead
     }
 
@@ -850,12 +850,12 @@
     int fd = TEMP_FAILURE_RETRY(open(traces_path, O_CREAT | O_WRONLY | O_TRUNC | O_NOFOLLOW | O_CLOEXEC,
                                      0666));  /* -rw-rw-rw- */
     if (fd < 0) {
-        fprintf(stderr, "%s: %s\n", traces_path, strerror(errno));
+        MYLOGE("%s: %s\n", traces_path, strerror(errno));
         return NULL;
     }
     int chmod_ret = fchmod(fd, 0666);
     if (chmod_ret < 0) {
-        fprintf(stderr, "fchmod on %s failed: %s\n", traces_path, strerror(errno));
+        MYLOGE("fchmod on %s failed: %s\n", traces_path, strerror(errno));
         close(fd);
         return NULL;
     }
@@ -867,20 +867,20 @@
     /* walk /proc and kill -QUIT all Dalvik processes */
     DIR *proc = opendir("/proc");
     if (proc == NULL) {
-        fprintf(stderr, "/proc: %s\n", strerror(errno));
+        MYLOGE("/proc: %s\n", strerror(errno));
         goto error_close_fd;
     }
 
     /* use inotify to find when processes are done dumping */
     ifd = inotify_init();
     if (ifd < 0) {
-        fprintf(stderr, "inotify_init: %s\n", strerror(errno));
+        MYLOGE("inotify_init: %s\n", strerror(errno));
         goto error_close_fd;
     }
 
     wfd = inotify_add_watch(ifd, traces_path, IN_CLOSE_WRITE);
     if (wfd < 0) {
-        fprintf(stderr, "inotify_add_watch(%s): %s\n", traces_path, strerror(errno));
+        MYLOGE("inotify_add_watch(%s): %s\n", traces_path, strerror(errno));
         goto error_close_ifd;
     }
 
@@ -915,7 +915,7 @@
             ++dalvik_found;
             uint64_t start = DurationReporter::nanotime();
             if (kill(pid, SIGQUIT)) {
-                fprintf(stderr, "kill(%d, SIGQUIT): %s\n", pid, strerror(errno));
+                MYLOGE("kill(%d, SIGQUIT): %s\n", pid, strerror(errno));
                 continue;
             }
 
@@ -923,16 +923,16 @@
             struct pollfd pfd = { ifd, POLLIN, 0 };
             int ret = poll(&pfd, 1, 5000);  /* 5 sec timeout */
             if (ret < 0) {
-                fprintf(stderr, "poll: %s\n", strerror(errno));
+                MYLOGE("poll: %s\n", strerror(errno));
             } else if (ret == 0) {
-                fprintf(stderr, "warning: timed out dumping pid %d\n", pid);
+                MYLOGE("warning: timed out dumping pid %d\n", pid);
             } else {
                 struct inotify_event ie;
                 read(ifd, &ie, sizeof(ie));
             }
 
             if (lseek(fd, 0, SEEK_END) < 0) {
-                fprintf(stderr, "lseek: %s\n", strerror(errno));
+                MYLOGE("lseek: %s\n", strerror(errno));
             } else {
                 dprintf(fd, "[dump dalvik stack %d: %.3fs elapsed]\n",
                         pid, (float)(DurationReporter::nanotime() - start) / NANOS_PER_SEC);
@@ -940,7 +940,7 @@
         } else if (should_dump_native_traces(data)) {
             /* dump native process if appropriate */
             if (lseek(fd, 0, SEEK_END) < 0) {
-                fprintf(stderr, "lseek: %s\n", strerror(errno));
+                MYLOGE("lseek: %s\n", strerror(errno));
             } else {
                 static uint16_t timeout_failures = 0;
                 uint64_t start = DurationReporter::nanotime();
@@ -961,14 +961,14 @@
     }
 
     if (dalvik_found == 0) {
-        fprintf(stderr, "Warning: no Dalvik processes found to dump stacks\n");
+        MYLOGE("Warning: no Dalvik processes found to dump stacks\n");
     }
 
     static char dump_traces_path[PATH_MAX];
     strlcpy(dump_traces_path, traces_path, sizeof(dump_traces_path));
     strlcat(dump_traces_path, ".bugreport", sizeof(dump_traces_path));
     if (rename(traces_path, dump_traces_path)) {
-        fprintf(stderr, "rename(%s, %s): %s\n", traces_path, dump_traces_path, strerror(errno));
+        MYLOGE("rename(%s, %s): %s\n", traces_path, dump_traces_path, strerror(errno));
         goto error_close_ifd;
     }
     result = dump_traces_path;
@@ -1021,7 +1021,7 @@
     // adjusts max on the fly
     if (progress > weight_total) {
         int new_total = weight_total * 1.2;
-        fprintf(stderr, "Adjusting total weight from %d to %d\n", weight_total, new_total);
+        MYLOGD("Adjusting total weight from %d to %d\n", weight_total, new_total);
         weight_total = new_total;
         sprintf(key, "dumpstate.%d.max", getpid());
         sprintf(value, "%d", weight_total);
@@ -1035,9 +1035,14 @@
     sprintf(key, "dumpstate.%d.progress", getpid());
     sprintf(value, "%d", progress);
 
-    // stderr is ignored on normal invocations, but useful when calling /system/bin/dumpstate
-    // directly for debuggging.
-    fprintf(stderr, "Setting progress (%s): %s/%d\n", key, value, weight_total);
+    if (progress % 100 == 0) {
+        // We don't want to spam logcat, so only log multiples of 100.
+        MYLOGD("Setting progress (%s): %s/%d\n", key, value, weight_total);
+    } else {
+        // stderr is ignored on normal invocations, but useful when calling /system/bin/dumpstate
+        // directly for debuggging.
+        fprintf(stderr, "Setting progress (%s): %s/%d\n", key, value, weight_total);
+    }
 
     int status = property_set(key, value);
     if (status) {
@@ -1195,5 +1200,5 @@
         args.append(argv[i]);
         args.append(" ");
     }
-    MYLOGI("%s: %s\n", message.c_str(), args.c_str());
+    MYLOGD("%s: %s\n", message.c_str(), args.c_str());
 }