Modifies statsd output for start and end times.

We include the start of when the last dump occurred and the current
timestamp. These timestamps are shared across all metrics, so
there's no advantage in duplicating these numbers across all metrics.

Also, we should use elapsed realtime instead of times based on wall
clock, which can jump around and go backwards.

Test: Test that statsd can still build and
adb shell cmd stats dump-report doesn't crash.
Change-Id: I819e5643cee75dfa3e78a58f94c9d61ededa78d7
diff --git a/cmds/statsd/src/StatsLogProcessor.cpp b/cmds/statsd/src/StatsLogProcessor.cpp
index e610fd7..24243af 100644
--- a/cmds/statsd/src/StatsLogProcessor.cpp
+++ b/cmds/statsd/src/StatsLogProcessor.cpp
@@ -32,6 +32,7 @@
 
 #include <log/log_event_list.h>
 #include <utils/Errors.h>
+#include <utils/SystemClock.h>
 
 using namespace android;
 using android::base::StringPrintf;
@@ -60,6 +61,8 @@
 // for ConfigMetricsReport
 const int FIELD_ID_METRICS = 1;
 const int FIELD_ID_UID_MAP = 2;
+const int FIELD_ID_LAST_REPORT_NANOS = 3;
+const int FIELD_ID_CURRENT_REPORT_NANOS = 4;
 
 #define STATS_DATA_DIR "/data/misc/stats-data"
 
@@ -264,6 +267,12 @@
     uidMap.SerializeToArray(&uidMapBuffer[0], uidMapSize);
     proto.write(FIELD_TYPE_MESSAGE | FIELD_ID_UID_MAP, uidMapBuffer, uidMapSize);
 
+    // Fill in the timestamps.
+    proto.write(FIELD_TYPE_INT64 | FIELD_ID_LAST_REPORT_NANOS,
+                (long long)it->second->getLastReportTimeNs());
+    proto.write(FIELD_TYPE_INT64 | FIELD_ID_CURRENT_REPORT_NANOS,
+                (long long)::android::elapsedRealtimeNano());
+
     // End of ConfigMetricsReport (reports).
     proto.end(reportsToken);
 
diff --git a/cmds/statsd/src/metrics/CountMetricProducer.cpp b/cmds/statsd/src/metrics/CountMetricProducer.cpp
index 5b5b57b..5a042b6 100644
--- a/cmds/statsd/src/metrics/CountMetricProducer.cpp
+++ b/cmds/statsd/src/metrics/CountMetricProducer.cpp
@@ -45,8 +45,6 @@
 
 // for StatsLogReport
 const int FIELD_ID_ID = 1;
-const int FIELD_ID_START_REPORT_NANOS = 2;
-const int FIELD_ID_END_REPORT_NANOS = 3;
 const int FIELD_ID_COUNT_METRICS = 5;
 // for CountMetricDataWrapper
 const int FIELD_ID_DATA = 1;
@@ -97,7 +95,6 @@
 void CountMetricProducer::onDumpReportLocked(const uint64_t dumpTimeNs, StatsLogReport* report) {
     flushIfNeededLocked(dumpTimeNs);
     report->set_metric_id(mMetricId);
-    report->set_start_report_nanos(mStartTimeNs);
 
     auto count_metrics = report->mutable_count_metrics();
     for (const auto& counter : mPastBuckets) {
@@ -123,7 +120,6 @@
     }
 
     protoOutput->write(FIELD_TYPE_INT64 | FIELD_ID_ID, (long long)mMetricId);
-    protoOutput->write(FIELD_TYPE_INT64 | FIELD_ID_START_REPORT_NANOS, (long long)mStartTimeNs);
     long long protoToken = protoOutput->start(FIELD_TYPE_MESSAGE | FIELD_ID_COUNT_METRICS);
 
     VLOG("metric %lld dump report now...",(long long)mMetricId);
@@ -167,7 +163,6 @@
     }
 
     protoOutput->end(protoToken);
-    protoOutput->write(FIELD_TYPE_INT64 | FIELD_ID_END_REPORT_NANOS, (long long)dumpTimeNs);
 
     mPastBuckets.clear();
 
diff --git a/cmds/statsd/src/metrics/DurationMetricProducer.cpp b/cmds/statsd/src/metrics/DurationMetricProducer.cpp
index 2400eba1..65cbc4a 100644
--- a/cmds/statsd/src/metrics/DurationMetricProducer.cpp
+++ b/cmds/statsd/src/metrics/DurationMetricProducer.cpp
@@ -44,8 +44,6 @@
 
 // for StatsLogReport
 const int FIELD_ID_ID = 1;
-const int FIELD_ID_START_REPORT_NANOS = 2;
-const int FIELD_ID_END_REPORT_NANOS = 3;
 const int FIELD_ID_DURATION_METRICS = 6;
 // for DurationMetricDataWrapper
 const int FIELD_ID_DATA = 1;
@@ -179,7 +177,6 @@
 void DurationMetricProducer::onDumpReportLocked(const uint64_t dumpTimeNs, StatsLogReport* report) {
     flushIfNeededLocked(dumpTimeNs);
     report->set_metric_id(mMetricId);
-    report->set_start_report_nanos(mStartTimeNs);
 
     auto duration_metrics = report->mutable_duration_metrics();
     for (const auto& pair : mPastBuckets) {
@@ -205,7 +202,6 @@
     }
 
     protoOutput->write(FIELD_TYPE_INT64 | FIELD_ID_ID, (long long)mMetricId);
-    protoOutput->write(FIELD_TYPE_INT64 | FIELD_ID_START_REPORT_NANOS, (long long)mStartTimeNs);
     long long protoToken = protoOutput->start(FIELD_TYPE_MESSAGE | FIELD_ID_DURATION_METRICS);
 
     VLOG("metric %lld dump report now...", (long long)mMetricId);
@@ -250,7 +246,6 @@
     }
 
     protoOutput->end(protoToken);
-    protoOutput->write(FIELD_TYPE_INT64 | FIELD_ID_END_REPORT_NANOS, (long long)dumpTimeNs);
     mPastBuckets.clear();
 }
 
diff --git a/cmds/statsd/src/metrics/EventMetricProducer.cpp b/cmds/statsd/src/metrics/EventMetricProducer.cpp
index a021e0a..0578e06 100644
--- a/cmds/statsd/src/metrics/EventMetricProducer.cpp
+++ b/cmds/statsd/src/metrics/EventMetricProducer.cpp
@@ -42,8 +42,6 @@
 
 // for StatsLogReport
 const int FIELD_ID_ID = 1;
-const int FIELD_ID_START_REPORT_NANOS = 2;
-const int FIELD_ID_END_REPORT_NANOS = 3;
 const int FIELD_ID_EVENT_METRICS = 4;
 // for EventMetricDataWrapper
 const int FIELD_ID_DATA = 1;
@@ -106,8 +104,6 @@
         return;
     }
     protoOutput->write(FIELD_TYPE_INT64 | FIELD_ID_ID, (long long)mMetricId);
-    protoOutput->write(FIELD_TYPE_INT64 | FIELD_ID_START_REPORT_NANOS, (long long)mStartTimeNs);
-    protoOutput->write(FIELD_TYPE_INT64 | FIELD_ID_END_REPORT_NANOS, (long long)dumpTimeNs);
 
     size_t bufferSize = mProto->size();
     VLOG("metric %lld dump report now... proto size: %zu ",
diff --git a/cmds/statsd/src/metrics/GaugeMetricProducer.cpp b/cmds/statsd/src/metrics/GaugeMetricProducer.cpp
index 4190f00..62ee6ef 100644
--- a/cmds/statsd/src/metrics/GaugeMetricProducer.cpp
+++ b/cmds/statsd/src/metrics/GaugeMetricProducer.cpp
@@ -45,8 +45,6 @@
 
 // for StatsLogReport
 const int FIELD_ID_ID = 1;
-const int FIELD_ID_START_REPORT_NANOS = 2;
-const int FIELD_ID_END_REPORT_NANOS = 3;
 const int FIELD_ID_GAUGE_METRICS = 8;
 // for GaugeMetricDataWrapper
 const int FIELD_ID_DATA = 1;
@@ -134,7 +132,6 @@
     }
 
     protoOutput->write(FIELD_TYPE_INT64 | FIELD_ID_ID, (long long)mMetricId);
-    protoOutput->write(FIELD_TYPE_INT64 | FIELD_ID_START_REPORT_NANOS, (long long)mStartTimeNs);
     long long protoToken = protoOutput->start(FIELD_TYPE_MESSAGE | FIELD_ID_GAUGE_METRICS);
 
     for (const auto& pair : mPastBuckets) {
@@ -188,7 +185,6 @@
         protoOutput->end(wrapperToken);
     }
     protoOutput->end(protoToken);
-    protoOutput->write(FIELD_TYPE_INT64 | FIELD_ID_END_REPORT_NANOS, (long long)dumpTimeNs);
 
     mPastBuckets.clear();
     // TODO: Clear mDimensionKeyMap once the report is dumped.
diff --git a/cmds/statsd/src/metrics/MetricsManager.cpp b/cmds/statsd/src/metrics/MetricsManager.cpp
index 6573a89..eb6f0cb 100644
--- a/cmds/statsd/src/metrics/MetricsManager.cpp
+++ b/cmds/statsd/src/metrics/MetricsManager.cpp
@@ -29,6 +29,7 @@
 
 #include <log/logprint.h>
 #include <private/android_filesystem_config.h>
+#include <utils/SystemClock.h>
 
 using android::util::FIELD_COUNT_REPEATED;
 using android::util::FIELD_TYPE_MESSAGE;
@@ -48,7 +49,7 @@
 
 MetricsManager::MetricsManager(const ConfigKey& key, const StatsdConfig& config,
                                const long timeBaseSec, sp<UidMap> uidMap)
-    : mConfigKey(key), mUidMap(uidMap) {
+    : mConfigKey(key), mUidMap(uidMap), mLastReportTimeNs(0) {
     mConfigValid =
             initStatsdConfig(key, config, *uidMap, timeBaseSec, mTagIds, mAllAtomMatchers, mAllConditionTrackers,
                              mAllMetricProducers, mAllAnomalyTrackers, mConditionToMetricMap,
@@ -184,6 +185,7 @@
             protoOutput->end(token);
         }
     }
+    mLastReportTimeNs = ::android::elapsedRealtimeNano();
     VLOG("=========================Metric Reports End==========================");
 }
 
diff --git a/cmds/statsd/src/metrics/MetricsManager.h b/cmds/statsd/src/metrics/MetricsManager.h
index 9cae70a..2b30f44 100644
--- a/cmds/statsd/src/metrics/MetricsManager.h
+++ b/cmds/statsd/src/metrics/MetricsManager.h
@@ -64,6 +64,11 @@
 
     void dumpStates(FILE* out, bool verbose);
 
+    // Returns the elapsed realtime when this metric manager last reported metrics.
+    uint64_t getLastReportTimeNs() {
+        return mLastReportTimeNs;
+    };
+
     // Config source owner can call onDumpReport() to get all the metrics collected.
     virtual void onDumpReport(android::util::ProtoOutputStream* protoOutput);
     virtual void onDumpReport(const uint64_t& dumpTimeStampNs, ConfigMetricsReport* report);
@@ -78,6 +83,8 @@
 
     bool mConfigValid = false;
 
+    uint64_t mLastReportTimeNs;
+
     // The uid log sources from StatsdConfig.
     std::vector<int32_t> mAllowedUid;
 
diff --git a/cmds/statsd/src/metrics/ValueMetricProducer.cpp b/cmds/statsd/src/metrics/ValueMetricProducer.cpp
index 31d9ff8..7b1944c 100644
--- a/cmds/statsd/src/metrics/ValueMetricProducer.cpp
+++ b/cmds/statsd/src/metrics/ValueMetricProducer.cpp
@@ -48,8 +48,6 @@
 
 // for StatsLogReport
 const int FIELD_ID_ID = 1;
-const int FIELD_ID_START_REPORT_NANOS = 2;
-const int FIELD_ID_END_REPORT_NANOS = 3;
 const int FIELD_ID_VALUE_METRICS = 7;
 // for ValueMetricDataWrapper
 const int FIELD_ID_DATA = 1;
@@ -122,7 +120,6 @@
 void ValueMetricProducer::onDumpReportLocked(const uint64_t dumpTimeNs, StatsLogReport* report) {
     flushIfNeededLocked(dumpTimeNs);
     report->set_metric_id(mMetricId);
-    report->set_start_report_nanos(mStartTimeNs);
     auto value_metrics = report->mutable_value_metrics();
     for (const auto& pair : mPastBuckets) {
         ValueMetricData* metricData = value_metrics->add_data();
@@ -147,7 +144,6 @@
         return;
     }
     protoOutput->write(FIELD_TYPE_INT64 | FIELD_ID_ID, (long long)mMetricId);
-    protoOutput->write(FIELD_TYPE_INT64 | FIELD_ID_START_REPORT_NANOS, (long long)mStartTimeNs);
     long long protoToken = protoOutput->start(FIELD_TYPE_MESSAGE | FIELD_ID_VALUE_METRICS);
 
     for (const auto& pair : mPastBuckets) {
@@ -186,7 +182,6 @@
         protoOutput->end(wrapperToken);
     }
     protoOutput->end(protoToken);
-    protoOutput->write(FIELD_TYPE_INT64 | FIELD_ID_END_REPORT_NANOS, (long long)dumpTimeNs);
 
     VLOG("metric %lld dump report now...", (long long)mMetricId);
     mPastBuckets.clear();
diff --git a/cmds/statsd/src/stats_log.proto b/cmds/statsd/src/stats_log.proto
index af21ca4..b56cffb 100644
--- a/cmds/statsd/src/stats_log.proto
+++ b/cmds/statsd/src/stats_log.proto
@@ -143,9 +143,7 @@
 message StatsLogReport {
   optional int64 metric_id = 1;
 
-  optional int64 start_report_nanos = 2;
-
-  optional int64 end_report_nanos = 3;
+  // Fields 2 and 3 are reserved.
 
   message EventMetricDataWrapper {
     repeated EventMetricData data = 1;
@@ -177,6 +175,10 @@
   repeated StatsLogReport metrics = 1;
 
   optional UidMapping uid_map = 2;
+
+  optional int64 last_report_nanos = 3;
+
+  optional int64 current_report_nanos = 4;
 }
 
 message ConfigMetricsReportList {
diff --git a/cmds/statsd/tools/dogfood/src/com/android/statsd/dogfood/DisplayProtoUtils.java b/cmds/statsd/tools/dogfood/src/com/android/statsd/dogfood/DisplayProtoUtils.java
index 33c8abf..03e5fef 100644
--- a/cmds/statsd/tools/dogfood/src/com/android/statsd/dogfood/DisplayProtoUtils.java
+++ b/cmds/statsd/tools/dogfood/src/com/android/statsd/dogfood/DisplayProtoUtils.java
@@ -32,11 +32,13 @@
 
         for (StatsLog.ConfigMetricsReport report : reports.getReportsList()) {
             sb.append("StatsLogReport size: ").append(report.getMetricsCount()).append("\n");
+            sb.append("Last report time:").append(getDateStr(report.getLastReportNanos())).
+                    append("\n");
+            sb.append("Current report time:").append(getDateStr(report.getCurrentReportNanos())).
+                    append("\n");
             for (StatsLog.StatsLogReport log : report.getMetricsList()) {
                 sb.append("\n\n");
                 sb.append("metric id: ").append(log.getMetricId()).append("\n");
-                sb.append("start time:").append(getDateStr(log.getStartReportNanos())).append("\n");
-                sb.append("end time:").append(getDateStr(log.getEndReportNanos())).append("\n");
 
                 switch (log.getDataCase()) {
                     case DURATION_METRICS:
diff --git a/cmds/statsd/tools/loadtest/src/com/android/statsd/loadtest/DisplayProtoUtils.java b/cmds/statsd/tools/loadtest/src/com/android/statsd/loadtest/DisplayProtoUtils.java
index 75489ad..87b82c2 100644
--- a/cmds/statsd/tools/loadtest/src/com/android/statsd/loadtest/DisplayProtoUtils.java
+++ b/cmds/statsd/tools/loadtest/src/com/android/statsd/loadtest/DisplayProtoUtils.java
@@ -36,6 +36,10 @@
         int numMetrics = 0;
         for (StatsLog.ConfigMetricsReport report : reports.getReportsList()) {
             sb.append("StatsLogReport size: ").append(report.getMetricsCount()).append("\n");
+            sb.append("Last report time:").append(getDateStr(report.getLastReportNanos())).
+                    append("\n");
+            sb.append("Current report time:").append(getDateStr(report.getCurrentReportNanos())).
+                    append("\n");
             for (StatsLog.StatsLogReport log : report.getMetricsList()) {
                 numMetrics++;
                 if (numMetrics > MAX_NUM_METRICS_TO_DISPLAY) {
@@ -45,8 +49,6 @@
                 }
                 sb.append("\n");
                 sb.append("metric id: ").append(log.getMetricId()).append("\n");
-                sb.append("start time:").append(getDateStr(log.getStartReportNanos())).append("\n");
-                sb.append("end time:").append(getDateStr(log.getEndReportNanos())).append("\n");
 
                 switch (log.getDataCase()) {
                     case DURATION_METRICS: