Capture systrace buffers.
When tracing is enabled (/sys/kernel/debug/tracing/tracing_on = 1),
dumpstate will run 'atrace --async_dump' and redirect its output to a
systrace.txt entry in the zip file.
BUG: 27419521
Change-Id: Ia6de46a691b25febac31331fe0aa8701c9a84ebb
diff --git a/cmds/dumpstate/bugreport-format.md b/cmds/dumpstate/bugreport-format.md
index fc43250..484f97f 100644
--- a/cmds/dumpstate/bugreport-format.md
+++ b/cmds/dumpstate/bugreport-format.md
@@ -41,6 +41,8 @@
under the `FS` folder. For example, a `/dirA/dirB/fileC` file in the device
would generate a `FS/dirA/dirB/fileC` entry in the zip file.
+When systrace is enabled, the zip file will contain a `systrace.txt` file as well.
+
The flat file also has some minor changes:
- Tombstone files were removed and added to the zip file.
diff --git a/cmds/dumpstate/dumpstate.cpp b/cmds/dumpstate/dumpstate.cpp
index 5898b41..ee0df52 100644
--- a/cmds/dumpstate/dumpstate.cpp
+++ b/cmds/dumpstate/dumpstate.cpp
@@ -63,6 +63,7 @@
static std::set<std::string> mount_points;
void add_mountinfo();
static bool add_zip_entry(const std::string& entry_name, const std::string& entry_path);
+static bool add_zip_entry_from_fd(const std::string& entry_name, int fd);
#define PSTORE_LAST_KMSG "/sys/fs/pstore/console-ramoops"
@@ -90,7 +91,7 @@
* See bugreport-format.txt for more info.
*/
// TODO: change to "v1" before final N build
-static std::string VERSION_DEFAULT = "v1-dev2";
+static std::string VERSION_DEFAULT = "v1-dev3";
/* gets the tombstone data, according to the bugreport type: if zipped gets all tombstones,
* otherwise gets just those modified in the last half an hour. */
@@ -168,6 +169,42 @@
closedir(d);
}
+static void dump_systrace() {
+ if (!zip_writer) {
+ MYLOGD("Not dumping systrace because zip_writer is not set\n");
+ return;
+ }
+ const char* path = "/sys/kernel/debug/tracing/tracing_on";
+ long int is_tracing;
+ if (read_file_as_long(path, &is_tracing)) {
+ return; // error already logged
+ }
+ if (is_tracing <= 0) {
+ MYLOGD("Skipping systrace because '%s' content is '%ld'\n", path, is_tracing);
+ return;
+ }
+
+ DurationReporter duration_reporter("SYSTRACE", nullptr);
+ // systrace output can be many MBs, so we need to redirect its stdout straigh to the zip file by
+ // forking and using a pipe.
+ int pipefd[2];
+ pipe(pipefd);
+ if (fork() == 0) {
+ close(pipefd[0]); // close reading end in the child
+ dup2(pipefd[1], STDOUT_FILENO); // send stdout to the pipe
+ dup2(pipefd[1], STDERR_FILENO); // send stderr to the pipe
+ close(pipefd[1]); // this descriptor is no longer needed
+
+ // TODO: ideally it should use run_command, but it doesn't work well with pipes.
+ // The drawback of calling execl directly is that we're not timing out if it hangs.
+ MYLOGD("Running '/system/bin/atrace --async_dump', which can take several seconds");
+ execl("/system/bin/atrace", "/system/bin/atrace", "--async_dump", nullptr);
+ } else {
+ close(pipefd[1]); // close the write end of the pipe in the parent
+ add_zip_entry_from_fd("systrace.txt", pipefd[0]); // write output to zip file
+ }
+}
+
static bool skip_not_stat(const char *path) {
static const char stat[] = "/stat";
size_t len = strlen(path);
@@ -1252,11 +1289,15 @@
// duration is logged into MYLOG instead.
print_header(version);
+ // Dumps systrace right away, otherwise it will be filled with unnecessary events.
+ dump_systrace();
+
// Invoking the following dumpsys calls before dump_traces() to try and
// keep the system stats as close to its initial state as possible.
run_command("DUMPSYS MEMINFO", 30, SU_PATH, "shell", "dumpsys", "meminfo", "-a", NULL);
run_command("DUMPSYS CPUINFO", 30, SU_PATH, "shell", "dumpsys", "cpuinfo", "-a", NULL);
+
/* collect stack traces from Dalvik and native processes (needs root) */
dump_traces_path = dump_traces();
diff --git a/cmds/dumpstate/dumpstate.h b/cmds/dumpstate/dumpstate.h
index 288fe39..cdb2502 100644
--- a/cmds/dumpstate/dumpstate.h
+++ b/cmds/dumpstate/dumpstate.h
@@ -85,6 +85,9 @@
/* prints the contents of a file */
int dump_file(const char *title, const char *path);
+/* saves the the contents of a file as a long */
+int read_file_as_long(const char *path, long int *output);
+
/* prints the contents of the fd
* fd must have been opened with the flag O_NONBLOCK.
*/
diff --git a/cmds/dumpstate/utils.cpp b/cmds/dumpstate/utils.cpp
index d21ef7b..7ed51ab 100644
--- a/cmds/dumpstate/utils.cpp
+++ b/cmds/dumpstate/utils.cpp
@@ -474,6 +474,27 @@
return _dump_file_from_fd(title, path, fd);
}
+int read_file_as_long(const char *path, long int *output) {
+ int fd = TEMP_FAILURE_RETRY(open(path, O_RDONLY | O_NONBLOCK | O_CLOEXEC));
+ if (fd < 0) {
+ int err = errno;
+ MYLOGE("Error opening file descriptor for %s: %s\n", path, strerror(err));
+ return -1;
+ }
+ char buffer[50];
+ ssize_t bytes_read = TEMP_FAILURE_RETRY(read(fd, buffer, sizeof(buffer)));
+ if (bytes_read == -1) {
+ MYLOGE("Error reading file %s: %s\n", path, strerror(errno));
+ return -2;
+ }
+ if (bytes_read == 0) {
+ MYLOGE("File %s is empty\n", path);
+ return -3;
+ }
+ *output = atoi(buffer);
+ return 0;
+}
+
/* calls skip to gate calling dump_from_fd recursively
* in the specified directory. dump_from_fd defaults to
* dump_file_from_fd above when set to NULL. skip defaults
@@ -676,7 +697,6 @@
execvp(command, (char**) args);
// execvp's result will be handled after waitpid_with_timeout() below...
- _exit(-1); // ...but it doesn't hurt to force exit, just in case
}
/* handle parent case */