Merge "Fix some bugs in duration tracker."
diff --git a/cmds/statsd/src/metrics/DurationMetricProducer.cpp b/cmds/statsd/src/metrics/DurationMetricProducer.cpp
index 0ee7dcd..c8e6cce 100644
--- a/cmds/statsd/src/metrics/DurationMetricProducer.cpp
+++ b/cmds/statsd/src/metrics/DurationMetricProducer.cpp
@@ -130,6 +130,7 @@
 
 void DurationMetricProducer::onSlicedConditionMayChange(const uint64_t eventTime) {
     VLOG("Metric %s onSlicedConditionMayChange", mMetric.name().c_str());
+    flushIfNeeded(eventTime);
     // Now for each of the on-going event, check if the condition has changed for them.
     for (auto& pair : mCurrentSlicedDuration) {
         pair.second->onSlicedConditionMayChange(eventTime);
@@ -139,6 +140,7 @@
 void DurationMetricProducer::onConditionChanged(const bool conditionMet, const uint64_t eventTime) {
     VLOG("Metric %s onConditionChanged", mMetric.name().c_str());
     mCondition = conditionMet;
+    flushIfNeeded(eventTime);
     // TODO: need to populate the condition change time from the event which triggers the condition
     // change, instead of using current time.
     for (auto& pair : mCurrentSlicedDuration) {
diff --git a/cmds/statsd/src/metrics/duration_helper/MaxDurationTracker.cpp b/cmds/statsd/src/metrics/duration_helper/MaxDurationTracker.cpp
index 06e743d..e4b3693 100644
--- a/cmds/statsd/src/metrics/duration_helper/MaxDurationTracker.cpp
+++ b/cmds/statsd/src/metrics/duration_helper/MaxDurationTracker.cpp
@@ -34,7 +34,6 @@
 
 void MaxDurationTracker::noteStart(const HashableDimensionKey& key, bool condition,
                                    const uint64_t eventTime, const ConditionKey& conditionKey) {
-    flushIfNeeded(eventTime);
     // this will construct a new DurationInfo if this key didn't exist.
     DurationInfo& duration = mInfos[key];
     duration.conditionKeys = conditionKey;
@@ -63,7 +62,6 @@
 
 void MaxDurationTracker::noteStop(const HashableDimensionKey& key, const uint64_t eventTime,
                                   bool forceStop) {
-    flushIfNeeded(eventTime);
     declareAnomalyIfAlarmExpired(eventTime);
     VLOG("MaxDuration: key %s stop", key.c_str());
     if (mInfos.find(key) == mInfos.end()) {
@@ -85,7 +83,6 @@
                      (long long)duration.lastStartTime, (long long)eventTime,
                      (long long)durationTime);
                 duration.lastDuration = duration.lastDuration + durationTime;
-                duration.lastStartTime = -1;
                 VLOG("  record duration: %lld ", (long long)duration.lastDuration);
             }
             break;
@@ -223,7 +220,6 @@
 
 void MaxDurationTracker::noteConditionChanged(const HashableDimensionKey& key, bool conditionMet,
                                               const uint64_t timestamp) {
-    flushIfNeeded(timestamp);
     declareAnomalyIfAlarmExpired(timestamp);
     auto it = mInfos.find(key);
     if (it == mInfos.end()) {
diff --git a/cmds/statsd/src/metrics/duration_helper/OringDurationTracker.cpp b/cmds/statsd/src/metrics/duration_helper/OringDurationTracker.cpp
index 29b6c89..76f8514 100644
--- a/cmds/statsd/src/metrics/duration_helper/OringDurationTracker.cpp
+++ b/cmds/statsd/src/metrics/duration_helper/OringDurationTracker.cpp
@@ -38,7 +38,6 @@
 
 void OringDurationTracker::noteStart(const HashableDimensionKey& key, bool condition,
                                      const uint64_t eventTime, const ConditionKey& conditionKey) {
-    flushIfNeeded(eventTime);
     if (condition) {
         if (mStarted.size() == 0) {
             mLastStartTime = eventTime;
@@ -59,7 +58,6 @@
 
 void OringDurationTracker::noteStop(const HashableDimensionKey& key, const uint64_t timestamp,
                                     const bool stopAll) {
-    flushIfNeeded(timestamp);
     declareAnomalyIfAlarmExpired(timestamp);
     VLOG("Oring: %s stop", key.c_str());
     auto it = mStarted.find(key);
@@ -72,7 +70,6 @@
         if (mStarted.empty()) {
             mDuration += (timestamp - mLastStartTime);
             detectAndDeclareAnomaly(timestamp, mCurrentBucketNum, mDuration);
-            mLastStartTime = -1;
             VLOG("record duration %lld, total %lld ", (long long)timestamp - mLastStartTime,
                  (long long)mDuration);
         }
@@ -92,7 +89,6 @@
 }
 
 void OringDurationTracker::noteStopAll(const uint64_t timestamp) {
-    flushIfNeeded(timestamp);
     declareAnomalyIfAlarmExpired(timestamp);
     if (!mStarted.empty()) {
         mDuration += (timestamp - mLastStartTime);
@@ -105,7 +101,6 @@
     mStarted.clear();
     mPaused.clear();
     mConditionKeyMap.clear();
-    mLastStartTime = -1;
 }
 
 bool OringDurationTracker::flushIfNeeded(uint64_t eventTime) {
@@ -122,7 +117,6 @@
     // Process the current bucket.
     if (mStarted.size() > 0) {
         mDuration += (current_info.mBucketEndNs - mLastStartTime);
-        mLastStartTime = current_info.mBucketEndNs;
     }
     if (mDuration > 0) {
         current_info.mDuration = mDuration;
@@ -138,17 +132,15 @@
             info.mBucketEndNs = info.mBucketStartNs + mBucketSizeNs;
             info.mBucketNum = mCurrentBucketNum + i;
             info.mDuration = mBucketSizeNs;
-            mLastStartTime = info.mBucketEndNs;
-            if (info.mDuration > 0) {
                 mBucket.push_back(info);
                 addPastBucketToAnomalyTrackers(info.mDuration, info.mBucketNum);
                 VLOG("  add filling bucket with duration %lld", (long long)info.mDuration);
-            }
         }
     }
     mCurrentBucketStartTimeNs += numBucketsForward * mBucketSizeNs;
     mCurrentBucketNum += numBucketsForward;
 
+    mLastStartTime = mCurrentBucketStartTimeNs;
     mDuration = 0;
 
     // if all stopped, then tell owner it's safe to remove this tracker.
@@ -156,7 +148,6 @@
 }
 
 void OringDurationTracker::onSlicedConditionMayChange(const uint64_t timestamp) {
-    flushIfNeeded(timestamp);
     declareAnomalyIfAlarmExpired(timestamp);
     vector<pair<HashableDimensionKey, int>> startedToPaused;
     vector<pair<HashableDimensionKey, int>> pausedToStarted;
@@ -179,8 +170,7 @@
         }
 
         if (mStarted.empty()) {
-            mDuration = (timestamp - mLastStartTime);
-            mLastStartTime = -1;
+            mDuration += (timestamp - mLastStartTime);
             VLOG("Duration add %lld , to %lld ", (long long)(timestamp - mLastStartTime),
                  (long long)mDuration);
             detectAndDeclareAnomaly(timestamp, mCurrentBucketNum, mDuration);
@@ -222,13 +212,12 @@
 }
 
 void OringDurationTracker::onConditionChanged(bool condition, const uint64_t timestamp) {
-    flushIfNeeded(timestamp);
     declareAnomalyIfAlarmExpired(timestamp);
     if (condition) {
         if (!mPaused.empty()) {
             VLOG("Condition true, all started");
             if (mStarted.empty()) {
-                mLastStartTime = -1;
+                mLastStartTime = timestamp;
             }
             if (mStarted.empty() && !mPaused.empty()) {
                 startAnomalyAlarm(timestamp);
@@ -239,8 +228,7 @@
     } else {
         if (!mStarted.empty()) {
             VLOG("Condition false, all paused");
-            mDuration = (timestamp - mLastStartTime);
-            mLastStartTime = -1;
+            mDuration += (timestamp - mLastStartTime);
             mPaused.insert(mStarted.begin(), mStarted.end());
             mStarted.clear();
             detectAndDeclareAnomaly(timestamp, mCurrentBucketNum, mDuration);
diff --git a/cmds/statsd/tests/metrics/MaxDurationTracker_test.cpp b/cmds/statsd/tests/metrics/MaxDurationTracker_test.cpp
index 9e169bb..d82ccfe 100644
--- a/cmds/statsd/tests/metrics/MaxDurationTracker_test.cpp
+++ b/cmds/statsd/tests/metrics/MaxDurationTracker_test.cpp
@@ -79,6 +79,7 @@
 
     // Another event starts in this bucket.
     tracker.noteStart("2", true, bucketStartTimeNs + 20, key1);
+    tracker.flushIfNeeded(bucketStartTimeNs + bucketSizeNs + 40);
     tracker.noteStopAll(bucketStartTimeNs + bucketSizeNs + 40);
     EXPECT_TRUE(tracker.mInfos.empty());
     EXPECT_EQ(1u, buckets.size());
@@ -108,20 +109,9 @@
     // Starts again. Does not change anything.
     tracker.noteStart("", true, bucketStartTimeNs + bucketSizeNs + 1, key1);
 
-    // Flushes at early 2nd bucket. The event still does not stop yet.
-    tracker.flushIfNeeded(bucketStartTimeNs + bucketSizeNs + 1);
-    EXPECT_EQ(1u, buckets.size());
-    EXPECT_EQ((unsigned long long)(bucketSizeNs - 1), buckets[0].mDuration);
-
-    // Flushes at the end of the 2nd bucket. The event still does not stop yet.
-    tracker.flushIfNeeded(bucketStartTimeNs + (2 * bucketSizeNs));
-    EXPECT_EQ(2u, buckets.size());
-    EXPECT_EQ((unsigned long long)(bucketSizeNs - 1), buckets[0].mDuration);
-    EXPECT_EQ((unsigned long long)bucketSizeNs, buckets[1].mDuration);
-
     // The event stops at early 4th bucket.
+    tracker.flushIfNeeded(bucketStartTimeNs + (3 * bucketSizeNs) + 20);
     tracker.noteStop("", bucketStartTimeNs + (3 * bucketSizeNs) + 20, false /*stop all*/);
-    tracker.flushIfNeeded(bucketStartTimeNs + (3 * bucketSizeNs) + 21);
     EXPECT_EQ(3u, buckets.size());
     EXPECT_EQ((unsigned long long)(bucketSizeNs - 1), buckets[0].mDuration);
     EXPECT_EQ((unsigned long long)bucketSizeNs, buckets[1].mDuration);
@@ -183,28 +173,14 @@
     EXPECT_TRUE(tracker.mAnomalyTrackers.empty());
 
     tracker.noteStart("2:maps", true, eventStartTimeNs, key1);
-    tracker.onSlicedConditionMayChange(eventStartTimeNs + 2 * bucketSizeNs + 5);
-    EXPECT_EQ(2u, buckets.size());
-    EXPECT_EQ(bucketSizeNs - 1, buckets[0].mDuration);
-    EXPECT_EQ(bucketSizeNs, buckets[1].mDuration);
 
-    tracker.noteStop("2:maps", eventStartTimeNs + 2 * bucketSizeNs + durationTimeNs, false);
-    EXPECT_EQ(2u, buckets.size());
-    EXPECT_EQ(bucketSizeNs - 1, buckets[0].mDuration);
-    EXPECT_EQ(bucketSizeNs, buckets[1].mDuration);
-    EXPECT_TRUE(tracker.mInfos.empty());
-    EXPECT_EQ(6LL, tracker.mDuration);
+    tracker.onSlicedConditionMayChange(eventStartTimeNs + 5);
 
-    tracker.noteStart("2:maps", false, eventStartTimeNs + 3 * bucketSizeNs + 10, key1);
-    EXPECT_EQ(1u, tracker.mInfos.size());
-    for (const auto& itr : tracker.mInfos) {
-        EXPECT_EQ(DurationState::kPaused, itr.second.state);
-        EXPECT_EQ(0LL, itr.second.lastDuration);
-    }
-    EXPECT_EQ(3u, buckets.size());
-    EXPECT_EQ(bucketSizeNs - 1, buckets[0].mDuration);
-    EXPECT_EQ(bucketSizeNs, buckets[1].mDuration);
-    EXPECT_EQ(6ULL, buckets[2].mDuration);
+    tracker.noteStop("2:maps", eventStartTimeNs + durationTimeNs, false);
+
+    tracker.flushIfNeeded(bucketStartTimeNs + bucketSizeNs + 1);
+    EXPECT_EQ(1u, buckets.size());
+    EXPECT_EQ(5ULL, buckets[0].mDuration);
 }
 
 TEST(MaxDurationTrackerTest, TestAnomalyDetection) {
@@ -233,6 +209,7 @@
     EXPECT_EQ(10LL, tracker.mDuration);
 
     tracker.noteStart("2", true, eventStartTimeNs + 20, key1);
+    tracker.flushIfNeeded(eventStartTimeNs + 2 * bucketSizeNs + 3 * NS_PER_SEC);
     tracker.noteStop("2", eventStartTimeNs + 2 * bucketSizeNs + 3 * NS_PER_SEC, false);
     EXPECT_EQ((long long)(4 * NS_PER_SEC + 1LL), tracker.mDuration);
     EXPECT_EQ(anomalyTracker->mLastAlarmTimestampNs,
diff --git a/cmds/statsd/tests/metrics/OringDurationTracker_test.cpp b/cmds/statsd/tests/metrics/OringDurationTracker_test.cpp
index f4edffd..54618b5 100644
--- a/cmds/statsd/tests/metrics/OringDurationTracker_test.cpp
+++ b/cmds/statsd/tests/metrics/OringDurationTracker_test.cpp
@@ -130,10 +130,10 @@
 
     tracker.noteStart("2:maps", true, eventStartTimeNs, key1);
     EXPECT_EQ((long long)eventStartTimeNs, tracker.mLastStartTime);
+    tracker.flushIfNeeded(eventStartTimeNs + 2 * bucketSizeNs);
     tracker.noteStart("2:maps", true, eventStartTimeNs + 2 * bucketSizeNs, key1);
     EXPECT_EQ((long long)(bucketStartTimeNs + 2 * bucketSizeNs), tracker.mLastStartTime);
 
-    tracker.flushIfNeeded(eventStartTimeNs + 2 * bucketSizeNs);
     EXPECT_EQ(2u, buckets.size());
     EXPECT_EQ(bucketSizeNs - 1, buckets[0].mDuration);
     EXPECT_EQ(bucketSizeNs, buckets[1].mDuration);
@@ -167,12 +167,47 @@
 
     tracker.noteStart("2:maps", true, eventStartTimeNs, key1);
 
-    tracker.onSlicedConditionMayChange(eventStartTimeNs + 2 * bucketSizeNs + 5);
-    tracker.noteStop("2:maps", eventStartTimeNs + 2 * bucketSizeNs + durationTimeNs, false);
-    tracker.flushIfNeeded(bucketStartTimeNs + 2 * bucketSizeNs + durationTimeNs);
-    EXPECT_EQ(2u, buckets.size());
-    EXPECT_EQ(bucketSizeNs - 1, buckets[0].mDuration);
-    EXPECT_EQ(bucketSizeNs, buckets[1].mDuration);
+    tracker.onSlicedConditionMayChange(eventStartTimeNs + 5);
+
+    tracker.noteStop("2:maps", eventStartTimeNs + durationTimeNs, false);
+
+    tracker.flushIfNeeded(bucketStartTimeNs + bucketSizeNs + 1);
+    EXPECT_EQ(1u, buckets.size());
+    EXPECT_EQ(5ULL, buckets[0].mDuration);
+}
+
+TEST(OringDurationTrackerTest, TestDurationConditionChange2) {
+    sp<MockConditionWizard> wizard = new NaggyMock<MockConditionWizard>();
+
+    ConditionKey key1;
+    key1["APP_BACKGROUND"] = "1:maps|";
+
+    EXPECT_CALL(*wizard, query(_, key1))
+            .Times(2)
+            .WillOnce(Return(ConditionState::kFalse))
+            .WillOnce(Return(ConditionState::kTrue));
+
+    vector<DurationBucket> buckets;
+
+    uint64_t bucketStartTimeNs = 10000000000;
+    uint64_t eventStartTimeNs = bucketStartTimeNs + 1;
+    uint64_t bucketSizeNs = 30 * 1000 * 1000 * 1000LL;
+    uint64_t durationTimeNs = 2 * 1000;
+
+    OringDurationTracker tracker("event", wizard, 1, false, bucketStartTimeNs, bucketSizeNs, {},
+                                 buckets);
+
+    tracker.noteStart("2:maps", true, eventStartTimeNs, key1);
+    // condition to false; record duration 5n
+    tracker.onSlicedConditionMayChange(eventStartTimeNs + 5);
+    // condition to true.
+    tracker.onSlicedConditionMayChange(eventStartTimeNs + 1000);
+    // 2nd duration: 1000ns
+    tracker.noteStop("2:maps", eventStartTimeNs + durationTimeNs, false);
+
+    tracker.flushIfNeeded(bucketStartTimeNs + bucketSizeNs + 1);
+    EXPECT_EQ(1u, buckets.size());
+    EXPECT_EQ(1005ULL, buckets[0].mDuration);
 }
 
 TEST(OringDurationTrackerTest, TestDurationConditionChangeNested) {
@@ -242,6 +277,7 @@
               tracker.predictAnomalyTimestampNs(*anomalyTracker, event1StartTimeNs));
 
     uint64_t event1StopTimeNs = eventStartTimeNs + bucketSizeNs + 10;
+    tracker.flushIfNeeded(event1StopTimeNs);
     tracker.noteStop("1", event1StopTimeNs, false);
     EXPECT_EQ(1u, buckets.size());
     EXPECT_EQ(3ULL + bucketStartTimeNs + bucketSizeNs - eventStartTimeNs - 10,
@@ -290,7 +326,6 @@
     tracker.noteStop("", eventStartTimeNs + 10, false);
     EXPECT_EQ(anomalyTracker->mLastAlarmTimestampNs, -1);
     EXPECT_TRUE(tracker.mStarted.empty());
-    EXPECT_EQ(-1LL, tracker.mLastStartTime);
     EXPECT_EQ(10LL, tracker.mDuration);
 
     EXPECT_EQ(0u, tracker.mStarted.size());
@@ -299,6 +334,7 @@
     EXPECT_EQ(1u, anomalyTracker->mAlarms.size());
     EXPECT_EQ((long long)(51ULL * NS_PER_SEC),
               (long long)(anomalyTracker->mAlarms.begin()->second->timestampSec * NS_PER_SEC));
+    tracker.flushIfNeeded(eventStartTimeNs + 2 * bucketSizeNs + 25);
     tracker.noteStop("", eventStartTimeNs + 2 * bucketSizeNs + 25, false);
     EXPECT_EQ(anomalyTracker->getSumOverPastBuckets("event"), (long long)(bucketSizeNs));
     EXPECT_EQ((long long)(eventStartTimeNs + 2 * bucketSizeNs + 25),