[cobalt][system_metrics] Log uptime once per hour
Adds a method which logs for the fuchsia_uptime metric
once per hour.
TEST= cobalt_system_metrics_unittests
Change-Id: Ic7888fd6d77af30f1a5e64f5974953732a9ee2fb
diff --git a/src/cobalt/bin/system-metrics/system_metrics_daemon.cc b/src/cobalt/bin/system-metrics/system_metrics_daemon.cc
index bcc0e8d..6ade346 100644
--- a/src/cobalt/bin/system-metrics/system_metrics_daemon.cc
+++ b/src/cobalt/bin/system-metrics/system_metrics_daemon.cc
@@ -43,8 +43,17 @@
using fuchsia_system_metrics::
FuchsiaMemoryExperimentalMetricDimensionMemoryBreakdown;
using fuchsia_system_metrics::FuchsiaUpPingMetricDimensionUptime;
+using fuchsia_system_metrics::FuchsiaUptimeMetricDimensionUptimeRange;
using std::chrono::steady_clock;
+namespace {
+// Given a number of seconds, return the number of seconds before the next
+// multiple of 1 hour.
+std::chrono::seconds SecondsBeforeNextHour(std::chrono::seconds uptime) {
+ return std::chrono::seconds(3600 - (uptime.count() % 3600));
+}
+} // namespace
+
SystemMetricsDaemon::SystemMetricsDaemon(async_dispatcher_t* dispatcher,
sys::ComponentContext* context)
: SystemMetricsDaemon(
@@ -74,19 +83,28 @@
void SystemMetricsDaemon::StartLogging() {
TRACE_DURATION("system_metrics", "SystemMetricsDaemon::StartLogging");
// We keep gathering metrics until this process is terminated.
- RepeatedlyLogUpTimeAndLifeTimeEvents();
+ RepeatedlyLogUpPingAndLifeTimeEvents();
+ RepeatedlyLogUptime();
RepeatedlyLogCpuUsage();
RepeatedlyLogMemoryUsage();
}
-void SystemMetricsDaemon::RepeatedlyLogUpTimeAndLifeTimeEvents() {
- std::chrono::seconds seconds_to_sleep = LogUpTimeAndLifeTimeEvents();
+void SystemMetricsDaemon::RepeatedlyLogUpPingAndLifeTimeEvents() {
+ std::chrono::seconds seconds_to_sleep = LogUpPingAndLifeTimeEvents();
async::PostDelayedTask(
- dispatcher_, [this]() { RepeatedlyLogUpTimeAndLifeTimeEvents(); },
+ dispatcher_, [this]() { RepeatedlyLogUpPingAndLifeTimeEvents(); },
zx::sec(seconds_to_sleep.count() + 5));
return;
}
+void SystemMetricsDaemon::RepeatedlyLogUptime() {
+ std::chrono::seconds seconds_to_sleep = LogFuchsiaUptime();
+ async::PostDelayedTask(
+ dispatcher_, [this]() { RepeatedlyLogUptime(); },
+ zx::sec(seconds_to_sleep.count()));
+ return;
+}
+
void SystemMetricsDaemon::RepeatedlyLogCpuUsage() {
std::chrono::seconds seconds_to_sleep = LogCpuUsage();
async::PostDelayedTask(
@@ -112,7 +130,7 @@
return std::chrono::duration_cast<std::chrono::seconds>(now - start_time_);
}
-std::chrono::seconds SystemMetricsDaemon::LogUpTimeAndLifeTimeEvents() {
+std::chrono::seconds SystemMetricsDaemon::LogUpPingAndLifeTimeEvents() {
std::chrono::seconds uptime = GetUpTime();
return std::min(LogFuchsiaUpPing(uptime), LogFuchsiaLifetimeEvents());
}
@@ -247,6 +265,35 @@
return std::chrono::hours(1);
}
+std::chrono::seconds SystemMetricsDaemon::LogFuchsiaUptime() {
+ std::chrono::seconds uptime = GetUpTime();
+ if (!logger_) {
+ FX_LOGS(ERROR)
+ << "Cobalt SystemMetricsDaemon: No logger present. Reconnecting...";
+ InitializeLogger();
+ // Something went wrong. Pause for 5 minutes.
+ return std::chrono::minutes(5);
+ }
+ auto up_hours =
+ std::chrono::duration_cast<std::chrono::hours>(uptime).count();
+ uint32_t event_code =
+ (up_hours < 336)
+ ? FuchsiaUptimeMetricDimensionUptimeRange::LessThanTwoWeeks
+ : event_code =
+ FuchsiaUptimeMetricDimensionUptimeRange::TwoWeeksOrMore;
+
+ fuchsia::cobalt::Status status;
+ logger_->LogElapsedTime(fuchsia_system_metrics::kFuchsiaUptimeMetricId,
+ event_code, "", up_hours, &status);
+ if (status != fuchsia::cobalt::Status::OK) {
+ FX_LOGS(ERROR)
+ << "Cobalt SystemMetricsDaemon: LogCobaltEvent() returned status="
+ << StatusToString(status);
+ }
+ // Schedule a call of this function for the next multiple of an hour.
+ return SecondsBeforeNextHour(uptime);
+}
+
std::chrono::seconds SystemMetricsDaemon::LogFuchsiaLifetimeEvents() {
TRACE_DURATION("system_metrics",
"SystemMetricsDaemon::LogFuchsiaLifetimeEvents");
diff --git a/src/cobalt/bin/system-metrics/system_metrics_daemon.h b/src/cobalt/bin/system-metrics/system_metrics_daemon.h
index 5e9eca9..88eff9e 100644
--- a/src/cobalt/bin/system-metrics/system_metrics_daemon.h
+++ b/src/cobalt/bin/system-metrics/system_metrics_daemon.h
@@ -62,10 +62,14 @@
void InitializeRootResourceHandle();
- // Calls LogUpTimeAndLifeTimeEvents,
+ // Calls LogUpPingAndLifeTimeEvents,
// and then uses the |dispatcher| passed to the constructor to
// schedule the next round.
- void RepeatedlyLogUpTimeAndLifeTimeEvents();
+ void RepeatedlyLogUpPingAndLifeTimeEvents();
+
+ // Calls LogFuchsiaUptime and then uses the |dispatcher| passed to the
+ // constructor to schedule the next round.
+ void RepeatedlyLogUptime();
// Calls LogMemoryUsage,
// then uses the |dispatcher| passed to the constructor to schedule
@@ -83,7 +87,7 @@
// Calls LogFuchsiaUpPing and LogFuchsiaLifetimeEvents.
//
// Returns the amount of time before this method needs to be invoked again.
- std::chrono::seconds LogUpTimeAndLifeTimeEvents();
+ std::chrono::seconds LogUpPingAndLifeTimeEvents();
// Logs one or more UpPing events depending on how long the device has been
// up.
@@ -108,6 +112,13 @@
// Currently returns std::chrono::seconds::max().
std::chrono::seconds LogFuchsiaLifetimeEvents();
+ // Once per hour, rounds the current uptime down to the nearest number of
+ // hours and logs an event for the fuchsia_uptime metric.
+ //
+ // Returns the amount of time before this method needs to be invoked again.
+ // This is the number of seconds until the uptime reaches the next full hour.
+ std::chrono::seconds LogFuchsiaUptime();
+
// Logs several different measurements of system-wide memory usage.
//
// Returns the amount of time before this method needs to be invoked again.
diff --git a/src/cobalt/bin/system-metrics/system_metrics_daemon_test.cc b/src/cobalt/bin/system-metrics/system_metrics_daemon_test.cc
index e2a7e56..287312b 100644
--- a/src/cobalt/bin/system-metrics/system_metrics_daemon_test.cc
+++ b/src/cobalt/bin/system-metrics/system_metrics_daemon_test.cc
@@ -26,10 +26,18 @@
using fuchsia_system_metrics::
FuchsiaMemoryExperimental2MetricDimensionTimeSinceBoot;
using fuchsia_system_metrics::FuchsiaUpPingMetricDimensionUptime;
+using fuchsia_system_metrics::FuchsiaUptimeMetricDimensionUptimeRange;
using std::chrono::hours;
using std::chrono::minutes;
using std::chrono::seconds;
+namespace {
+typedef FuchsiaUptimeMetricDimensionUptimeRange UptimeRange;
+static constexpr int kHour = 3600;
+static constexpr int kDay = 24 * kHour;
+static constexpr int kWeek = 7 * kDay;
+} // namespace
+
class SystemMetricsDaemonTest : public gtest::TestLoopFixture {
public:
// Note that we first save an unprotected pointer in fake_clock_ and then
@@ -52,14 +60,18 @@
return daemon_->LogFuchsiaLifetimeEvents();
}
- seconds LogUpTimeAndLifeTimeEvents() {
- return daemon_->LogUpTimeAndLifeTimeEvents();
+ seconds LogUpPingAndLifeTimeEvents() {
+ return daemon_->LogUpPingAndLifeTimeEvents();
}
- void RepeatedlyLogUpTimeAndLifeTimeEvents() {
- return daemon_->RepeatedlyLogUpTimeAndLifeTimeEvents();
+ seconds LogFuchsiaUptime() { return daemon_->LogFuchsiaUptime(); }
+
+ void RepeatedlyLogUpPingAndLifeTimeEvents() {
+ return daemon_->RepeatedlyLogUpPingAndLifeTimeEvents();
}
+ void RepeatedlyLogUptime() { return daemon_->RepeatedlyLogUptime(); }
+
seconds LogMemoryUsage() { return daemon_->LogMemoryUsage(); }
seconds LogCpuUsage() {
@@ -86,6 +98,16 @@
EXPECT_EQ(expected_event_count, fake_logger_.event_count());
}
+ void CheckUptimeValues(size_t expected_call_count,
+ uint32_t expected_last_event_code,
+ int64_t expected_last_up_hours) {
+ EXPECT_EQ(expected_call_count, fake_logger_.call_count());
+ EXPECT_EQ(fuchsia_system_metrics::kFuchsiaUptimeMetricId,
+ fake_logger_.last_metric_id());
+ EXPECT_EQ(expected_last_event_code, fake_logger_.last_event_code());
+ EXPECT_EQ(expected_last_up_hours, fake_logger_.last_elapsed_time());
+ }
+
void DoFuchsiaUpPingTest(seconds now_seconds, seconds expected_sleep_seconds,
size_t expected_call_count,
uint32_t expected_last_event_code) {
@@ -97,7 +119,7 @@
expected_last_event_code);
}
- void DoLogUpTimeAndLifeTimeEventsTest(seconds increment_seconds,
+ void DoLogUpPingAndLifeTimeEventsTest(seconds increment_seconds,
seconds expected_sleep_seconds,
size_t expected_call_count,
uint32_t expected_last_metric_id,
@@ -105,16 +127,26 @@
fake_logger_.reset();
fake_clock_->Increment(increment_seconds);
EXPECT_EQ(expected_sleep_seconds.count(),
- LogUpTimeAndLifeTimeEvents().count());
+ LogUpPingAndLifeTimeEvents().count());
CheckValues(cobalt::kLogEvent, expected_call_count, expected_last_metric_id,
expected_last_event_code);
}
+ void DoFuchsiaUptimeTest(seconds now_seconds, seconds expected_sleep_seconds,
+ uint32_t expected_event_code,
+ int64_t expected_up_hours) {
+ fake_logger_.reset();
+ SetClockToDaemonStartTime();
+ fake_clock_->Increment(now_seconds);
+ EXPECT_EQ(expected_sleep_seconds.count(), LogFuchsiaUptime().count());
+ CheckUptimeValues(1u, expected_event_code, expected_up_hours);
+ }
+
// This method is used by the test of the method
- // RepeatedlyLogUpTimeAndLifeTimeEvents(). It advances our two fake clocks
+ // RepeatedlyLogUpPingAndLifeTimeEvents(). It advances our two fake clocks
// (one used by the SystemMetricDaemon, one used by the MessageLoop) by the
// specified amount, and then checks to make sure that
- // RepeatedlyLogUpTimeAndLifeTimeEvents() was executed and did the expected
+ // RepeatedlyLogUpPingAndLifeTimeEvents() was executed and did the expected
// thing.
void AdvanceTimeAndCheck(seconds advance_time_seconds,
size_t expected_call_count,
@@ -131,12 +163,59 @@
fake_logger_.reset();
}
+ // This method is used by the test of the method RepeatedlyLogUptime(). It
+ // advances our two fake clocks by the specified amount, and then checks to
+ // make sure that RepeatedlyLogUptime() made the expected logging calls in the
+ // meantime.
+ void AdvanceAndCheckUptime(seconds advance_time_seconds,
+ size_t expected_call_count,
+ uint32_t expected_last_event_code,
+ int64_t expected_last_up_hours) {
+ bool expected_activity = (expected_call_count != 0);
+ fake_clock_->Increment(advance_time_seconds);
+ EXPECT_EQ(expected_activity,
+ RunLoopFor(zx::sec(advance_time_seconds.count())));
+ if (expected_activity) {
+ CheckUptimeValues(expected_call_count, expected_last_event_code,
+ expected_last_up_hours);
+ }
+ fake_logger_.reset();
+ }
+
+ // Rewinds the SystemMetricsDaemon's clock back to the daemon's startup time.
+ void SetClockToDaemonStartTime() {
+ fake_clock_->set_time(daemon_->start_time_);
+ }
+
protected:
FakeSteadyClock* fake_clock_;
FakeLogger_Sync fake_logger_;
std::unique_ptr<SystemMetricsDaemon> daemon_;
};
+// Tests the method LogFuchsiaUptime(). Uses a local FakeLogger_Sync and
+// does not use FIDL. Does not use the message loop.
+TEST_F(SystemMetricsDaemonTest, LogFuchsiaUptime) {
+ DoFuchsiaUptimeTest(seconds(0), seconds(kHour), UptimeRange::LessThanTwoWeeks,
+ 0);
+ DoFuchsiaUptimeTest(seconds(kHour - 1), seconds(1),
+ UptimeRange::LessThanTwoWeeks, 0);
+ DoFuchsiaUptimeTest(seconds(5), seconds(kHour - 5),
+ UptimeRange::LessThanTwoWeeks, 0);
+ DoFuchsiaUptimeTest(seconds(kDay), seconds(kHour),
+ UptimeRange::LessThanTwoWeeks, 24);
+ DoFuchsiaUptimeTest(seconds(kDay + 6 * kHour + 10), seconds(kHour - 10),
+ UptimeRange::LessThanTwoWeeks, 30);
+ DoFuchsiaUptimeTest(seconds(kWeek), seconds(kHour),
+ UptimeRange::LessThanTwoWeeks, 168);
+ DoFuchsiaUptimeTest(seconds(kWeek), seconds(kHour),
+ UptimeRange::LessThanTwoWeeks, 168);
+ DoFuchsiaUptimeTest(seconds(2 * kWeek), seconds(kHour),
+ UptimeRange::TwoWeeksOrMore, 336);
+ DoFuchsiaUptimeTest(seconds(2 * kWeek + 6 * kDay + 10), seconds(kHour - 10),
+ UptimeRange::TwoWeeksOrMore, 480);
+}
+
// Tests the method LogFuchsiaUpPing(). Uses a local FakeLogger_Sync and
// does not use FIDL. Does not use the message loop.
TEST_F(SystemMetricsDaemonTest, LogFuchsiaUpPing) {
@@ -161,7 +240,8 @@
FuchsiaUpPingMetricDimensionUptime::UpOneMinute);
// If we've been up for 61 seconds, expect 2 log events, the second one
- // being of type UpOneMinute, and a return value of 9 minutes minus 1 second.
+ // being of type UpOneMinute, and a return value of 9 minutes minus 1
+ // second.
DoFuchsiaUpPingTest(seconds(61), minutes(9) - seconds(1), 2,
FuchsiaUpPingMetricDimensionUptime::UpOneMinute);
@@ -176,8 +256,8 @@
FuchsiaUpPingMetricDimensionUptime::UpTenMinutes);
// If we've been up for 10 minutes plus 1 second, expect 3 log events, the
- // last one being of type UpTenMinutes, and a return value of 50 minutes minus
- // one second.
+ // last one being of type UpTenMinutes, and a return value of 50 minutes
+ // minus one second.
DoFuchsiaUpPingTest(minutes(10) + seconds(1), minutes(50) - seconds(1), 3,
FuchsiaUpPingMetricDimensionUptime::UpTenMinutes);
@@ -237,46 +317,46 @@
FuchsiaUpPingMetricDimensionUptime::UpSixDays);
}
-// Tests the method LogFuchsiaLifetimeEvents(). Uses a local FakeLogger_Sync and
-// does not use FIDL. Does not use the message loop.
+// Tests the method LogFuchsiaLifetimeEvents(). Uses a local FakeLogger_Sync
+// and does not use FIDL. Does not use the message loop.
TEST_F(SystemMetricsDaemonTest, LogFuchsiaLifetimeEvents) {
fake_logger_.reset();
- // The first time LogFuchsiaLifetimeEvents() is invoked it should log 1 event
- // of type "Boot" and return seconds::max().
+ // The first time LogFuchsiaLifetimeEvents() is invoked it should log 1
+ // event of type "Boot" and return seconds::max().
EXPECT_EQ(seconds::max(), LogFuchsiaLifetimeEvents());
CheckValues(cobalt::kLogEvent, 1,
fuchsia_system_metrics::kFuchsiaLifetimeEventsMetricId,
FuchsiaLifetimeEventsMetricDimensionEvents::Boot);
fake_logger_.reset();
- // The second time LogFuchsiaLifetimeEvents() is invoked it should do nothing
- // and return seconds::max().
+ // The second time LogFuchsiaLifetimeEvents() is invoked it should do
+ // nothing and return seconds::max().
EXPECT_EQ(seconds::max(), LogFuchsiaLifetimeEvents());
CheckValues(cobalt::kOther, 0, -1, -1);
}
-// Tests the method LogUpTimeAndLifeTimeEvents(). Uses a local FakeLogger_Sync
+// Tests the method LogUpPingAndLifeTimeEvents(). Uses a local FakeLogger_Sync
// and does not use FIDL. Does not use the message loop.
-TEST_F(SystemMetricsDaemonTest, LogUpTimeAndLifeTimeEvents) {
+TEST_F(SystemMetricsDaemonTest, LogUpPingAndLifeTimeEvents) {
// If we have been up for 1 second, expect 2 log events. First there is an
// "Up" event and then there is "Boot" event. Expect a return value of
// 59 seconds.
- DoLogUpTimeAndLifeTimeEventsTest(
+ DoLogUpPingAndLifeTimeEventsTest(
seconds(1), seconds(59), 2,
fuchsia_system_metrics::kFuchsiaLifetimeEventsMetricId,
FuchsiaLifetimeEventsMetricDimensionEvents::Boot);
// 59 Seconds later, expect 2 log events. First there is an "Up" event and
// then there is an "UpOneMinute" event. Expect a return value of 9 minutes.
- DoLogUpTimeAndLifeTimeEventsTest(
+ DoLogUpPingAndLifeTimeEventsTest(
seconds(59), minutes(9), 2,
fuchsia_system_metrics::kFuchsiaUpPingMetricId,
FuchsiaUpPingMetricDimensionUptime::UpOneMinute);
// 9 Minutes minus 1 second later, expect 2 log events. First there is an
- // "Up" event and then there is an "UpOneMinute" event. Expect a return value
- // of 1 second.
- DoLogUpTimeAndLifeTimeEventsTest(
+ // "Up" event and then there is an "UpOneMinute" event. Expect a return
+ // value of 1 second.
+ DoLogUpPingAndLifeTimeEventsTest(
minutes(9) - seconds(1), seconds(1), 2,
fuchsia_system_metrics::kFuchsiaUpPingMetricId,
FuchsiaUpPingMetricDimensionUptime::UpOneMinute);
@@ -284,7 +364,7 @@
// 2 seconds later, expect 3 log events. First there is an
// "Up" event and then there is an "UpOneMinute" event and then there is an
// "UpTenMinutes" event. Expect a return value of 50 minutes - 1 second.
- DoLogUpTimeAndLifeTimeEventsTest(
+ DoLogUpPingAndLifeTimeEventsTest(
seconds(2), minutes(50) - seconds(1), 3,
fuchsia_system_metrics::kFuchsiaUpPingMetricId,
FuchsiaUpPingMetricDimensionUptime::UpTenMinutes);
@@ -292,7 +372,7 @@
// 50 minutes - 1 second later, the device has been up for one hour.
// Expect 4 log events: "Up", "UpOneMinute", "UpTenMinutes", "UpOneHour".
// Expect a return value of one hour.
- DoLogUpTimeAndLifeTimeEventsTest(
+ DoLogUpPingAndLifeTimeEventsTest(
minutes(50) - seconds(1), hours(1), 4,
fuchsia_system_metrics::kFuchsiaUpPingMetricId,
FuchsiaUpPingMetricDimensionUptime::UpOneHour);
@@ -300,85 +380,128 @@
// One hour later, the device has been up for two hours.
// Expect 4 log events: "Up", "UpOneMinute", "UpTenMinutes", "UpOneHour".
// Expect a return value of one hour.
- DoLogUpTimeAndLifeTimeEventsTest(
+ DoLogUpPingAndLifeTimeEventsTest(
hours(1), hours(1), 4, fuchsia_system_metrics::kFuchsiaUpPingMetricId,
FuchsiaUpPingMetricDimensionUptime::UpOneHour);
// One hour later, the device has been up for three hours.
// Expect 4 log events: "Up", "UpOneMinute", "UpTenMinutes", "UpOneHour".
// Expect a return value of one hour.
- DoLogUpTimeAndLifeTimeEventsTest(
+ DoLogUpPingAndLifeTimeEventsTest(
hours(1), hours(1), 4, fuchsia_system_metrics::kFuchsiaUpPingMetricId,
FuchsiaUpPingMetricDimensionUptime::UpOneHour);
// One hour later, the device has been up for four hours.
// Expect 4 log events: "Up", "UpOneMinute", "UpTenMinutes", "UpOneHour".
// Expect a return value of one hour.
- DoLogUpTimeAndLifeTimeEventsTest(
+ DoLogUpPingAndLifeTimeEventsTest(
hours(1), hours(1), 4, fuchsia_system_metrics::kFuchsiaUpPingMetricId,
FuchsiaUpPingMetricDimensionUptime::UpOneHour);
// One hour later, the device has been up for five hours.
// Expect 4 log events: "Up", "UpOneMinute", "UpTenMinutes", "UpOneHour".
// Expect a return value of one hour.
- DoLogUpTimeAndLifeTimeEventsTest(
+ DoLogUpPingAndLifeTimeEventsTest(
hours(1), hours(1), 4, fuchsia_system_metrics::kFuchsiaUpPingMetricId,
FuchsiaUpPingMetricDimensionUptime::UpOneHour);
// One hour later, the device has been up for six hours.
// Expect 4 log events: "Up", "UpOneMinute", "UpTenMinutes", "UpOneHour".
// Expect a return value of one hour.
- DoLogUpTimeAndLifeTimeEventsTest(
+ DoLogUpPingAndLifeTimeEventsTest(
hours(1), hours(1), 4, fuchsia_system_metrics::kFuchsiaUpPingMetricId,
FuchsiaUpPingMetricDimensionUptime::UpOneHour);
// Six hours later, the device has been up for twelve hours.
// Expect 5 log events: "Up", "UpOneMinute", "UpTenMinutes", "UpOneHour",
// "UpTwelveHours". Expect a return value of one hour.
- DoLogUpTimeAndLifeTimeEventsTest(
+ DoLogUpPingAndLifeTimeEventsTest(
hours(6), hours(1), 5, fuchsia_system_metrics::kFuchsiaUpPingMetricId,
FuchsiaUpPingMetricDimensionUptime::UpTwelveHours);
// One hour later, the device has been up for 13 hours.
// Expect 5 log events: "Up", "UpOneMinute", "UpTenMinutes", "UpOneHour",
// "UpTwelveHours". Expect a return value of one hour.
- DoLogUpTimeAndLifeTimeEventsTest(
+ DoLogUpPingAndLifeTimeEventsTest(
hours(1), hours(1), 5, fuchsia_system_metrics::kFuchsiaUpPingMetricId,
FuchsiaUpPingMetricDimensionUptime::UpTwelveHours);
// One hour later, the device has been up for 14 hours.
// Expect 5 log events: "Up", "UpOneMinute", "UpTenMinutes", "UpOneHour",
// "UpTwelveHours". Expect a return value of one hour.
- DoLogUpTimeAndLifeTimeEventsTest(
+ DoLogUpPingAndLifeTimeEventsTest(
hours(1), hours(1), 5, fuchsia_system_metrics::kFuchsiaUpPingMetricId,
FuchsiaUpPingMetricDimensionUptime::UpTwelveHours);
// Ten hours later, the device has been up for 24 hours.
// Expect 6 log events: "Up", "UpOneMinute", "UpTenMinutes", "UpOneHour",
// "UpTwelveHours", "UpOneDay". Expect a return value of one hour.
- DoLogUpTimeAndLifeTimeEventsTest(
+ DoLogUpPingAndLifeTimeEventsTest(
hours(10), hours(1), 6, fuchsia_system_metrics::kFuchsiaUpPingMetricId,
FuchsiaUpPingMetricDimensionUptime::UpOneDay);
// One later, the device has been up for 25 hours.
// Expect 6 log events: "Up", "UpOneMinute", "UpTenMinutes", "UpOneHour",
// "UpTwelveHours", "UpOneDay". Expect a return value of one hour.
- DoLogUpTimeAndLifeTimeEventsTest(
+ DoLogUpPingAndLifeTimeEventsTest(
hours(1), hours(1), 6, fuchsia_system_metrics::kFuchsiaUpPingMetricId,
FuchsiaUpPingMetricDimensionUptime::UpOneDay);
}
-// Tests the method RepeatedlyLogUpTimeAndLifeTimeEvents(). This test differs
+// Tests the method RepeatedlyLogUptime(). This test uses the message loop to
+// schedule future runs of work. Uses a local FakeLogger_Sync and does not use
+// FIDL.
+TEST_F(SystemMetricsDaemonTest, RepeatedlyLogUptime) {
+ RunLoopUntilIdle();
+
+ // Invoke the method under test. This should cause the uptime to be logged
+ // once, and schedules the next run for approximately 1 hour in the future.
+ // (More precisely, the next run should occur in 1 hour minus the amount of
+ // time after the daemon's start time which this method is invoked.)
+ RepeatedlyLogUptime();
+
+ // The first event should have been logged, with an uptime of 0 hours.
+ CheckUptimeValues(1u, UptimeRange::LessThanTwoWeeks, 0);
+ fake_logger_.reset();
+
+ // Advance the clock by 30 seconds. Nothing should have happened.
+ AdvanceAndCheckUptime(seconds(30), 0, -1, -1);
+
+ // Advance the clock to the next hour. The system metrics daemon has been up
+ // for 1 hour by now, so the second event should have been logged.
+ AdvanceAndCheckUptime(seconds(kHour - 30), 1, UptimeRange::LessThanTwoWeeks,
+ 1);
+
+ // Advance the clock by 1 day. At this point, the daemon has been up for 25
+ // hours. Since the last time we checked |fake_logger_|, the daemon should
+ // have logged the uptime 24 times, with the most recent value equal to 25.
+ AdvanceAndCheckUptime(seconds(kDay), 24, UptimeRange::LessThanTwoWeeks, 25);
+
+ // Advance the clock by 1 week. At this point, the daemon has been up for 8
+ // days + 1 hour. Since the last time we checked |fake_logger_|, the daemon
+ // should have logged the uptime 168 times, with the most recent value equal
+ // to 193.
+ AdvanceAndCheckUptime(seconds(kWeek), 168, UptimeRange::LessThanTwoWeeks,
+ 193);
+
+ // Advance the clock 1 more week. At this point, the daemon has been up for
+ // 15 days + 1 hour. Since the last time we checked |fake_logger_|, the daemon
+ // should have logged the uptime 168 times, with the most recent value equal
+ // to 361.
+ AdvanceAndCheckUptime(seconds(kWeek), 168, UptimeRange::TwoWeeksOrMore, 361);
+}
+
+// Tests the method RepeatedlyLogUpPingAndLifeTimeEvents(). This test differs
// from the previous ones because it makes use of the message loop in order to
// schedule future runs of work. Uses a local FakeLogger_Sync and does not use
// FIDL.
-TEST_F(SystemMetricsDaemonTest, RepeatedlyLogUpTimeAndLifeTimeEvents) {
+TEST_F(SystemMetricsDaemonTest, RepeatedlyLogUpPingAndLifeTimeEvents) {
// Make sure the loop has no initial pending work.
RunLoopUntilIdle();
// Invoke the method under test. This kicks of the first run and schedules
// the second run for 1 minute plus 5 seconds in the future.
- RepeatedlyLogUpTimeAndLifeTimeEvents();
+ RepeatedlyLogUpPingAndLifeTimeEvents();
// The initial two events should have been logged, the second of which is
// |Boot|.
@@ -390,7 +513,7 @@
// Advance the clock by 30 seconds. Nothing should have happened.
AdvanceTimeAndCheck(seconds(30), 0, -1, -1);
// Advance the clock by 30 seconds again. Nothing should have happened
- // because the first run of RepeatedlyLogUpTimeAndLifeTimeEvents() added a 5
+ // because the first run of RepeatedlyLogUpPingAndLifeTimeEvents() added a 5
// second buffer to the next scheduled run time.
AdvanceTimeAndCheck(seconds(30), 0, -1, -1);
@@ -419,7 +542,8 @@
AdvanceTimeAndCheck(minutes(60) - (minutes(10) + seconds(5)), 0, -1, -1);
// Advance the clock 5 s to t=1h + 5s. Now expect the fourth batch of
- // work to occur. This consists of 4 events the last of which is |UpOneHour|.
+ // work to occur. This consists of 4 events the last of which is
+ // |UpOneHour|.
AdvanceTimeAndCheck(seconds(5), 4,
fuchsia_system_metrics::kFuchsiaUpPingMetricId,
FuchsiaUpPingMetricDimensionUptime::UpOneHour);
diff --git a/src/cobalt/bin/testing/fake_clock.h b/src/cobalt/bin/testing/fake_clock.h
index 2192571..d437a28 100644
--- a/src/cobalt/bin/testing/fake_clock.h
+++ b/src/cobalt/bin/testing/fake_clock.h
@@ -22,6 +22,8 @@
now_ += increment_seconds;
}
+ void set_time(std::chrono::steady_clock::time_point t) { now_ = t; }
+
private:
std::chrono::steady_clock::time_point now_ = std::chrono::steady_clock::now();
};
diff --git a/src/cobalt/bin/testing/fake_logger.cc b/src/cobalt/bin/testing/fake_logger.cc
index 9f188e9..9e6b1a0 100644
--- a/src/cobalt/bin/testing/fake_logger.cc
+++ b/src/cobalt/bin/testing/fake_logger.cc
@@ -43,6 +43,7 @@
last_log_method_invoked_ = kLogElapsedTime;
last_metric_id_ = metric_id;
last_event_code_ = event_code;
+ last_elapsed_time_ = elapsed_micros;
*out_status = Status::OK;
return ZX_OK;
}
diff --git a/src/cobalt/bin/testing/fake_logger.h b/src/cobalt/bin/testing/fake_logger.h
index 3ebe3c3..07f01e6 100644
--- a/src/cobalt/bin/testing/fake_logger.h
+++ b/src/cobalt/bin/testing/fake_logger.h
@@ -69,6 +69,10 @@
void reset_last_event_code() { last_event_code_ = -1; }
+ int64_t last_elapsed_time() { return last_elapsed_time_; }
+
+ void reset_last_elapsed_time() { last_elapsed_time_ = -1; }
+
LogMethod last_log_method_invoked() { return last_log_method_invoked_; }
void reset_last_log_method_invoked() { last_log_method_invoked_ = kOther; }
@@ -84,6 +88,7 @@
void reset() {
reset_last_metric_id();
reset_last_event_code();
+ reset_last_elapsed_time();
reset_last_log_method_invoked();
reset_call_count();
reset_event_count();
@@ -92,6 +97,7 @@
private:
uint32_t last_metric_id_ = -1;
uint32_t last_event_code_ = -1;
+ int64_t last_elapsed_time_ = -1;
LogMethod last_log_method_invoked_ = kOther;
size_t call_count_ = 0;
size_t event_count_ = 0; // for LogCobaltEvents only
