Support dumpsys timeouts in milliseconds
- add new dumpsys argument to specify timeouts in milliseconds
- use milliseconds to define timeouts in dumpstate
- minor dumpsys output format changes:
"SERVICE '<service_name>' DUMP TIMEOUT (1s) EXPIRED" ->
"SERVICE '<service_name>' DUMP TIMEOUT (1000ms) EXPIRED"
Bug: 27429130
Test: mmm -j32 frameworks/native/cmds/dumpsys && \
mmm -j32 frameworks/native/cmds/dumpstate && \
adb sync data && adb shell /data/nativetest/dumpsys_test/dumpsys_test && \
adb shell /data/nativetest64/dumpsys_test/dumpsys_test && \
adb shell /data/nativetest/dumpstate_test/dumpstate_test && \
adb shell /data/nativetest64/dumpstate_test/dumpstate_test && \
printf "\n\n#### ALL TESTS PASSED ####\n"
Change-Id: Ibc96ad030bb2c6d880b8201c9b6241fce20b284f
Change-Id: I6ef2ff19787f2b6d940d56e453a1a7462a8c854a
diff --git a/cmds/dumpstate/DumpstateUtil.cpp b/cmds/dumpstate/DumpstateUtil.cpp
index ede4254..85eb464 100644
--- a/cmds/dumpstate/DumpstateUtil.cpp
+++ b/cmds/dumpstate/DumpstateUtil.cpp
@@ -43,7 +43,7 @@
static constexpr const char* kSuPath = "/system/xbin/su";
-static bool waitpid_with_timeout(pid_t pid, int timeout_seconds, int* status) {
+static bool waitpid_with_timeout(pid_t pid, int timeout_ms, int* status) {
sigset_t child_mask, old_mask;
sigemptyset(&child_mask);
sigaddset(&child_mask, SIGCHLD);
@@ -54,10 +54,11 @@
}
timespec ts;
- ts.tv_sec = timeout_seconds;
- ts.tv_nsec = 0;
+ ts.tv_sec = MSEC_TO_SEC(timeout_ms);
+ ts.tv_nsec = (timeout_ms % 1000) * 1000000;
int ret = TEMP_FAILURE_RETRY(sigtimedwait(&child_mask, NULL, &ts));
int saved_errno = errno;
+
// Set the signals back the way they were.
if (sigprocmask(SIG_SETMASK, &old_mask, NULL) == -1) {
printf("*** sigprocmask failed: %s\n", strerror(errno));
@@ -91,7 +92,7 @@
CommandOptions CommandOptions::DEFAULT = CommandOptions::WithTimeout(10).Build();
CommandOptions CommandOptions::AS_ROOT = CommandOptions::WithTimeout(10).AsRoot().Build();
-CommandOptions::CommandOptionsBuilder::CommandOptionsBuilder(int64_t timeout) : values(timeout) {
+CommandOptions::CommandOptionsBuilder::CommandOptionsBuilder(int64_t timeout_ms) : values(timeout_ms) {
}
CommandOptions::CommandOptionsBuilder& CommandOptions::CommandOptionsBuilder::Always() {
@@ -130,8 +131,8 @@
return CommandOptions(values);
}
-CommandOptions::CommandOptionsValues::CommandOptionsValues(int64_t timeout)
- : timeout_(timeout),
+CommandOptions::CommandOptionsValues::CommandOptionsValues(int64_t timeout_ms)
+ : timeout_ms_(timeout_ms),
always_(false),
account_mode_(DONT_DROP_ROOT),
output_mode_(NORMAL_OUTPUT),
@@ -142,7 +143,11 @@
}
int64_t CommandOptions::Timeout() const {
- return values.timeout_;
+ return MSEC_TO_SEC(values.timeout_ms_);
+}
+
+int64_t CommandOptions::TimeoutInMs() const {
+ return values.timeout_ms_;
}
bool CommandOptions::Always() const {
@@ -161,8 +166,12 @@
return values.logging_message_;
}
-CommandOptions::CommandOptionsBuilder CommandOptions::WithTimeout(int64_t timeout) {
- return CommandOptions::CommandOptionsBuilder(timeout);
+CommandOptions::CommandOptionsBuilder CommandOptions::WithTimeout(int64_t timeout_sec) {
+ return CommandOptions::CommandOptionsBuilder(SEC_TO_MSEC(timeout_sec));
+}
+
+CommandOptions::CommandOptionsBuilder CommandOptions::WithTimeoutInMs(int64_t timeout_ms) {
+ return CommandOptions::CommandOptionsBuilder(timeout_ms);
}
std::string PropertiesHelper::build_type_ = "";
@@ -314,7 +323,7 @@
/* handle parent case */
int status;
- bool ret = waitpid_with_timeout(pid, options.Timeout(), &status);
+ bool ret = waitpid_with_timeout(pid, options.TimeoutInMs(), &status);
fsync(fd);
uint64_t elapsed = Nanotime() - start;
@@ -333,9 +342,9 @@
static_cast<float>(elapsed) / NANOS_PER_SEC, pid);
}
kill(pid, SIGTERM);
- if (!waitpid_with_timeout(pid, 5, nullptr)) {
+ if (!waitpid_with_timeout(pid, 5000, nullptr)) {
kill(pid, SIGKILL);
- if (!waitpid_with_timeout(pid, 5, nullptr)) {
+ if (!waitpid_with_timeout(pid, 5000, nullptr)) {
if (!silent)
dprintf(fd, "could not kill command '%s' (pid %d) even with SIGKILL.\n",
command, pid);
diff --git a/cmds/dumpstate/DumpstateUtil.h b/cmds/dumpstate/DumpstateUtil.h
index 698ceff..8342099 100644
--- a/cmds/dumpstate/DumpstateUtil.h
+++ b/cmds/dumpstate/DumpstateUtil.h
@@ -19,6 +19,16 @@
#include <cstdint>
#include <string>
+/*
+ * Converts seconds to milliseconds.
+ */
+#define SEC_TO_MSEC(second) (second * 1000)
+
+/*
+ * Converts milliseconds to seconds.
+ */
+#define MSEC_TO_SEC(millisecond) (millisecond / 1000)
+
namespace android {
namespace os {
namespace dumpstate {
@@ -66,9 +76,9 @@
private:
class CommandOptionsValues {
private:
- CommandOptionsValues(int64_t timeout);
+ CommandOptionsValues(int64_t timeout_ms);
- int64_t timeout_;
+ int64_t timeout_ms_;
bool always_;
PrivilegeMode account_mode_;
OutputMode output_mode_;
@@ -102,13 +112,15 @@
CommandOptions Build();
private:
- CommandOptionsBuilder(int64_t timeout);
+ CommandOptionsBuilder(int64_t timeout_ms);
CommandOptionsValues values;
friend class CommandOptions;
};
- /** Gets the command timeout, in seconds. */
+ /** Gets the command timeout in seconds. */
int64_t Timeout() const;
+ /** Gets the command timeout in milliseconds. */
+ int64_t TimeoutInMs() const;
/* Checks whether the command should always be run, even on dry-run mode. */
bool Always() const;
/** Gets the PrivilegeMode of the command. */
@@ -118,8 +130,11 @@
/** Gets the logging message header, it any. */
std::string LoggingMessage() const;
- /** Creates a builder with the requied timeout. */
- static CommandOptionsBuilder WithTimeout(int64_t timeout);
+ /** Creates a builder with the requied timeout in seconds. */
+ static CommandOptionsBuilder WithTimeout(int64_t timeout_sec);
+
+ /** Creates a builder with the requied timeout in milliseconds. */
+ static CommandOptionsBuilder WithTimeoutInMs(int64_t timeout_ms);
// Common options.
static CommandOptions DEFAULT;
diff --git a/cmds/dumpstate/dumpstate.cpp b/cmds/dumpstate/dumpstate.cpp
index 364ead0..aba08d9 100644
--- a/cmds/dumpstate/dumpstate.cpp
+++ b/cmds/dumpstate/dumpstate.cpp
@@ -113,8 +113,8 @@
}
static void RunDumpsys(const std::string& title, const std::vector<std::string>& dumpsysArgs,
const CommandOptions& options = Dumpstate::DEFAULT_DUMPSYS,
- long dumpsysTimeout = 0) {
- return ds.RunDumpsys(title, dumpsysArgs, options, dumpsysTimeout);
+ long dumpsysTimeoutMs = 0) {
+ return ds.RunDumpsys(title, dumpsysArgs, options, dumpsysTimeoutMs);
}
static int DumpFile(const std::string& title, const std::string& path) {
return ds.DumpFile(title, path);
@@ -830,33 +830,32 @@
}
static void DoLogcat() {
- unsigned long timeout;
+ unsigned long timeout_ms;
// DumpFile("EVENT LOG TAGS", "/etc/event-log-tags");
// calculate timeout
- timeout = logcat_timeout("main") + logcat_timeout("system") + logcat_timeout("crash");
- if (timeout < 20000) {
- timeout = 20000;
+ timeout_ms = logcat_timeout("main") + logcat_timeout("system") + logcat_timeout("crash");
+ if (timeout_ms < 20000) {
+ timeout_ms = 20000;
}
RunCommand("SYSTEM LOG",
- {"logcat", "-v", "threadtime", "-v", "printable", "-v", "uid",
- "-d", "*:v"},
- CommandOptions::WithTimeout(timeout / 1000).Build());
- timeout = logcat_timeout("events");
- if (timeout < 20000) {
- timeout = 20000;
+ {"logcat", "-v", "threadtime", "-v", "printable", "-v", "uid", "-d", "*:v"},
+ CommandOptions::WithTimeoutInMs(timeout_ms).Build());
+ timeout_ms = logcat_timeout("events");
+ if (timeout_ms < 20000) {
+ timeout_ms = 20000;
}
RunCommand("EVENT LOG",
{"logcat", "-b", "events", "-v", "threadtime", "-v", "printable", "-v", "uid",
"-d", "*:v"},
- CommandOptions::WithTimeout(timeout / 1000).Build());
- timeout = logcat_timeout("radio");
- if (timeout < 20000) {
- timeout = 20000;
+ CommandOptions::WithTimeoutInMs(timeout_ms).Build());
+ timeout_ms = logcat_timeout("radio");
+ if (timeout_ms < 20000) {
+ timeout_ms = 20000;
}
RunCommand("RADIO LOG",
{"logcat", "-b", "radio", "-v", "threadtime", "-v", "printable", "-v", "uid",
"-d", "*:v"},
- CommandOptions::WithTimeout(timeout / 1000).Build());
+ CommandOptions::WithTimeoutInMs(timeout_ms).Build());
RunCommand("LOG STATISTICS", {"logcat", "-b", "all", "-S"});
diff --git a/cmds/dumpstate/dumpstate.h b/cmds/dumpstate/dumpstate.h
index 1bfafba..8db23a9 100644
--- a/cmds/dumpstate/dumpstate.h
+++ b/cmds/dumpstate/dumpstate.h
@@ -196,19 +196,19 @@
/*
* Runs `dumpsys` with the given arguments, automatically setting its timeout
- * (`-t` argument)
+ * (`-T` argument)
* according to the command options.
*
* |title| description of the command printed on `stdout` (or empty to skip
* description).
* |dumpsys_args| `dumpsys` arguments (except `-t`).
* |options| optional argument defining the command's behavior.
- * |dumpsys_timeout| when > 0, defines the value passed to `dumpsys -t` (otherwise it uses the
+ * |dumpsys_timeout| when > 0, defines the value passed to `dumpsys -T` (otherwise it uses the
* timeout from `options`)
*/
void RunDumpsys(const std::string& title, const std::vector<std::string>& dumpsys_args,
const android::os::dumpstate::CommandOptions& options = DEFAULT_DUMPSYS,
- long dumpsys_timeout = 0);
+ long dumpsys_timeout_ms = 0);
/*
* Prints the contents of a file.
diff --git a/cmds/dumpstate/tests/dumpstate_test.cpp b/cmds/dumpstate/tests/dumpstate_test.cpp
index 92b0c0d..a2e9453 100644
--- a/cmds/dumpstate/tests/dumpstate_test.cpp
+++ b/cmds/dumpstate/tests/dumpstate_test.cpp
@@ -1001,7 +1001,7 @@
err, StartsWith("stderr\n*** command '" + kSimpleCommand + " --crash' failed: exit code"));
}
-TEST_F(DumpstateUtilTest, RunCommandTimesout) {
+TEST_F(DumpstateUtilTest, RunCommandTimesoutWithSec) {
CreateFd("RunCommandTimesout.txt");
EXPECT_EQ(-1, RunCommand("", {kSimpleCommand, "--sleep", "2"},
CommandOptions::WithTimeout(1).Build()));
@@ -1011,6 +1011,17 @@
" --sleep 2' timed out after 1"));
}
+TEST_F(DumpstateUtilTest, RunCommandTimesoutWithMsec) {
+ CreateFd("RunCommandTimesout.txt");
+ EXPECT_EQ(-1, RunCommand("", {kSimpleCommand, "--sleep", "2"},
+ CommandOptions::WithTimeoutInMs(1000).Build()));
+ EXPECT_THAT(out, StartsWith("stdout line1\n*** command '" + kSimpleCommand +
+ " --sleep 2' timed out after 1"));
+ EXPECT_THAT(err, StartsWith("sleeping for 2s\n*** command '" + kSimpleCommand +
+ " --sleep 2' timed out after 1"));
+}
+
+
TEST_F(DumpstateUtilTest, RunCommandIsKilled) {
CreateFd("RunCommandIsKilled.txt");
CaptureStderr();
diff --git a/cmds/dumpstate/utils.cpp b/cmds/dumpstate/utils.cpp
index 6ff0dae..ac48041 100644
--- a/cmds/dumpstate/utils.cpp
+++ b/cmds/dumpstate/utils.cpp
@@ -215,10 +215,10 @@
return progress_;
}
-bool Progress::Inc(int32_t delta) {
+bool Progress::Inc(int32_t delta_sec) {
bool changed = false;
- if (delta >= 0) {
- progress_ += delta;
+ if (delta_sec >= 0) {
+ progress_ += delta_sec;
if (progress_ > max_) {
int32_t old_max = max_;
max_ = floor((float)progress_ * growth_factor_);
@@ -723,9 +723,9 @@
}
void Dumpstate::RunDumpsys(const std::string& title, const std::vector<std::string>& dumpsys_args,
- const CommandOptions& options, long dumpsysTimeout) {
- long timeout = dumpsysTimeout > 0 ? dumpsysTimeout : options.Timeout();
- std::vector<std::string> dumpsys = {"/system/bin/dumpsys", "-t", std::to_string(timeout)};
+ const CommandOptions& options, long dumpsysTimeoutMs) {
+ long timeout_ms = dumpsysTimeoutMs > 0 ? dumpsysTimeoutMs : options.TimeoutInMs();
+ std::vector<std::string> dumpsys = {"/system/bin/dumpsys", "-T", std::to_string(timeout_ms)};
dumpsys.insert(dumpsys.end(), dumpsys_args.begin(), dumpsys_args.end());
RunCommand(title, dumpsys, options);
}
@@ -1165,14 +1165,14 @@
}
// TODO: make this function thread safe if sections are generated in parallel.
-void Dumpstate::UpdateProgress(int32_t delta) {
+void Dumpstate::UpdateProgress(int32_t delta_sec) {
if (progress_ == nullptr) {
MYLOGE("UpdateProgress: progress_ not set\n");
return;
}
// Always update progess so stats can be tuned...
- bool max_changed = progress_->Inc(delta);
+ bool max_changed = progress_->Inc(delta_sec);
// ...but only notifiy listeners when necessary.
if (!update_progress_) return;
diff --git a/cmds/dumpsys/dumpsys.cpp b/cmds/dumpsys/dumpsys.cpp
index c36ab08..0862a40 100644
--- a/cmds/dumpsys/dumpsys.cpp
+++ b/cmds/dumpsys/dumpsys.cpp
@@ -61,7 +61,8 @@
"SERVICE [ARGS]]\n"
" --help: shows this help\n"
" -l: only list services, do not dump them\n"
- " -t TIMEOUT: TIMEOUT to use in seconds instead of default 10 seconds\n"
+ " -t TIMEOUT_SEC: TIMEOUT to use in seconds instead of default 10 seconds\n"
+ " -T TIMEOUT_MS: TIMEOUT to use in milliseconds instead of default 10 seconds\n"
" --proto: filter services that support dumping data in proto format. Dumps"
" will be in proto format.\n"
" --priority LEVEL: filter services based on specified priority\n"
@@ -104,7 +105,7 @@
bool showListOnly = false;
bool skipServices = false;
bool filterByProto = false;
- int timeoutArg = 10;
+ int timeoutArgMs = 10000;
int dumpPriorityFlags = IServiceManager::DUMP_FLAG_PRIORITY_ALL;
static struct option longOptions[] = {{"priority", required_argument, 0, 0},
{"proto", no_argument, 0, 0},
@@ -119,7 +120,7 @@
int c;
int optionIndex = 0;
- c = getopt_long(argc, argv, "+t:l", longOptions, &optionIndex);
+ c = getopt_long(argc, argv, "+t:T:l", longOptions, &optionIndex);
if (c == -1) {
break;
@@ -146,10 +147,22 @@
case 't':
{
- char *endptr;
- timeoutArg = strtol(optarg, &endptr, 10);
- if (*endptr != '\0' || timeoutArg <= 0) {
- fprintf(stderr, "Error: invalid timeout number: '%s'\n", optarg);
+ char* endptr;
+ timeoutArgMs = strtol(optarg, &endptr, 10);
+ timeoutArgMs = timeoutArgMs * 1000;
+ if (*endptr != '\0' || timeoutArgMs <= 0) {
+ fprintf(stderr, "Error: invalid timeout(seconds) number: '%s'\n", optarg);
+ return -1;
+ }
+ }
+ break;
+
+ case 'T':
+ {
+ char* endptr;
+ timeoutArgMs = strtol(optarg, &endptr, 10);
+ if (*endptr != '\0' || timeoutArgMs <= 0) {
+ fprintf(stderr, "Error: invalid timeout(milliseconds) number: '%s'\n", optarg);
return -1;
}
}
@@ -269,7 +282,7 @@
}
});
- auto timeout = std::chrono::seconds(timeoutArg);
+ auto timeout = std::chrono::milliseconds(timeoutArgMs);
auto start = std::chrono::steady_clock::now();
auto end = start + timeout;
@@ -321,8 +334,8 @@
if (timed_out) {
aout << endl
- << "*** SERVICE '" << service_name << "' DUMP TIMEOUT (" << timeoutArg
- << "s) EXPIRED ***" << endl
+ << "*** SERVICE '" << service_name << "' DUMP TIMEOUT (" << timeoutArgMs
+ << "ms) EXPIRED ***" << endl
<< endl;
}
diff --git a/cmds/dumpsys/tests/dumpsys_test.cpp b/cmds/dumpsys/tests/dumpsys_test.cpp
index 18a4da9..bdb0a9a 100644
--- a/cmds/dumpsys/tests/dumpsys_test.cpp
+++ b/cmds/dumpsys/tests/dumpsys_test.cpp
@@ -299,12 +299,25 @@
}
// Tests 'dumpsys -t 1 service_name' on a service that times out after 2s
-TEST_F(DumpsysTest, DumpRunningServiceTimeout) {
+TEST_F(DumpsysTest, DumpRunningServiceTimeoutInSec) {
sp<BinderMock> binder_mock = ExpectDumpAndHang("Valet", 2, "Here's your car");
CallMain({"-t", "1", "Valet"});
- AssertOutputContains("SERVICE 'Valet' DUMP TIMEOUT (1s) EXPIRED");
+ AssertOutputContains("SERVICE 'Valet' DUMP TIMEOUT (1000ms) EXPIRED");
+ AssertNotDumped("Here's your car");
+
+ // TODO(b/65056227): BinderMock is not destructed because thread is detached on dumpsys.cpp
+ Mock::AllowLeak(binder_mock.get());
+}
+
+// Tests 'dumpsys -T 500 service_name' on a service that times out after 2s
+TEST_F(DumpsysTest, DumpRunningServiceTimeoutInMs) {
+ sp<BinderMock> binder_mock = ExpectDumpAndHang("Valet", 2, "Here's your car");
+
+ CallMain({"-T", "500", "Valet"});
+
+ AssertOutputContains("SERVICE 'Valet' DUMP TIMEOUT (500ms) EXPIRED");
AssertNotDumped("Here's your car");
// TODO(b/65056227): BinderMock is not destructed because thread is detached on dumpsys.cpp