From 18e469298e73aa8fd9d28196457990e37a394b04 Mon Sep 17 00:00:00 2001 From: Muhammad Qureshi Date: Fri, 24 May 2019 16:38:49 -0700 Subject: [PATCH] Handle condition changes when metric is not active. Treat metric activation like conditions as much as possible. Keep track of condition changes even when metric is not active. Right now, we ignore all condition changes if metric is not active. This is a band-aid fix. Ideally, we should re-think how metric activation is implemented and consider implementing it as a condition with a timebomb. Bug: 130838341 Test: statsd_test Test: cts-tradefed run cts-dev -m CtsStatsdHostTestCases -t android.cts.statsd.metric Change-Id: I96bb7a7c6ee88359f310065e166f858be945eaff --- cmds/statsd/Android.bp | 1 + cmds/statsd/src/StatsLogProcessor.h | 7 + .../src/metrics/DurationMetricProducer.cpp | 86 ++- .../src/metrics/DurationMetricProducer.h | 6 + .../src/metrics/GaugeMetricProducer.cpp | 24 +- cmds/statsd/src/metrics/GaugeMetricProducer.h | 3 + cmds/statsd/src/metrics/MetricProducer.cpp | 6 +- cmds/statsd/src/metrics/MetricProducer.h | 29 +- cmds/statsd/src/metrics/MetricsManager.h | 7 + .../src/metrics/ValueMetricProducer.cpp | 132 ++-- cmds/statsd/src/metrics/ValueMetricProducer.h | 3 + .../tests/e2e/DurationMetric_e2e_test.cpp | 717 ++++++++++++++++++ .../tests/e2e/GaugeMetric_e2e_pull_test.cpp | 61 +- .../tests/e2e/ValueMetric_pull_e2e_test.cpp | 31 +- 14 files changed, 999 insertions(+), 114 deletions(-) create mode 100644 cmds/statsd/tests/e2e/DurationMetric_e2e_test.cpp diff --git a/cmds/statsd/Android.bp b/cmds/statsd/Android.bp index 15d248f06c7ca..15c88c00646c0 100644 --- a/cmds/statsd/Android.bp +++ b/cmds/statsd/Android.bp @@ -262,6 +262,7 @@ cc_test { "tests/e2e/Anomaly_duration_sum_e2e_test.cpp", "tests/e2e/ConfigTtl_e2e_test.cpp", "tests/e2e/PartialBucket_e2e_test.cpp", + "tests/e2e/DurationMetric_e2e_test.cpp", "tests/shell/ShellSubscriber_test.cpp", ], diff --git a/cmds/statsd/src/StatsLogProcessor.h b/cmds/statsd/src/StatsLogProcessor.h index 92aa425a731d9..ce75f78c04ea4 100644 --- a/cmds/statsd/src/StatsLogProcessor.h +++ b/cmds/statsd/src/StatsLogProcessor.h @@ -273,6 +273,13 @@ private: FRIEND_TEST(MetricActivationE2eTest, TestCountMetricWithOneDeactivation); FRIEND_TEST(MetricActivationE2eTest, TestCountMetricWithTwoDeactivations); FRIEND_TEST(MetricActivationE2eTest, TestCountMetricWithTwoMetricsTwoDeactivations); + + FRIEND_TEST(DurationMetricE2eTest, TestOneBucket); + FRIEND_TEST(DurationMetricE2eTest, TestTwoBuckets); + FRIEND_TEST(DurationMetricE2eTest, TestWithActivation); + FRIEND_TEST(DurationMetricE2eTest, TestWithCondition); + FRIEND_TEST(DurationMetricE2eTest, TestWithSlicedCondition); + FRIEND_TEST(DurationMetricE2eTest, TestWithActivationAndSlicedCondition); }; } // namespace statsd diff --git a/cmds/statsd/src/metrics/DurationMetricProducer.cpp b/cmds/statsd/src/metrics/DurationMetricProducer.cpp index 615c7f2959c08..96fbf7fb5ebe9 100644 --- a/cmds/statsd/src/metrics/DurationMetricProducer.cpp +++ b/cmds/statsd/src/metrics/DurationMetricProducer.cpp @@ -220,7 +220,7 @@ void DurationMetricProducer::onSlicedConditionMayChangeLocked_opt1(bool conditio trueConditionDimensions.end()) { for (auto& condIt : whatIt.second) { condIt.second->onConditionChanged( - currentUnSlicedPartCondition, eventTime); + currentUnSlicedPartCondition, eventTime); } } } @@ -314,7 +314,7 @@ void DurationMetricProducer::onSlicedConditionMayChangeLocked_opt2(bool conditio auto condIt = whatIt.second.find(trueDim); if (condIt != whatIt.second.end()) { condIt->second->onConditionChanged( - currentUnSlicedPartCondition, eventTime); + currentUnSlicedPartCondition, eventTime); } else { if (mMetric2ConditionLinks.size() == 0 || trueDim.contains(linkedConditionDimensionKey)) { @@ -338,32 +338,25 @@ void DurationMetricProducer::onSlicedConditionMayChangeLocked_opt2(bool conditio } } -void DurationMetricProducer::onSlicedConditionMayChangeLocked(bool overallCondition, - const int64_t eventTime) { - VLOG("Metric %lld onSlicedConditionMayChange", (long long)mMetricId); - flushIfNeededLocked(eventTime); - - if (!mConditionSliced) { - return; - } - +void DurationMetricProducer::onSlicedConditionMayChangeInternalLocked(bool overallCondition, + const int64_t eventTimeNs) { bool changeDimTrackable = mWizard->IsChangedDimensionTrackable(mConditionTrackerIndex); if (changeDimTrackable && mHasLinksToAllConditionDimensionsInTracker && mDimensionsInCondition.empty()) { - onSlicedConditionMayChangeLocked_opt1(overallCondition, eventTime); + onSlicedConditionMayChangeLocked_opt1(overallCondition, eventTimeNs); return; } if (changeDimTrackable && mSameConditionDimensionsInTracker && mMetric2ConditionLinks.size() <= 1) { - onSlicedConditionMayChangeLocked_opt2(overallCondition, eventTime); + onSlicedConditionMayChangeLocked_opt2(overallCondition, eventTimeNs); return; } // Now for each of the on-going event, check if the condition has changed for them. for (auto& whatIt : mCurrentSlicedDurationTrackerMap) { for (auto& pair : whatIt.second) { - pair.second->onSlicedConditionMayChange(overallCondition, eventTime); + pair.second->onSlicedConditionMayChange(overallCondition, eventTimeNs); } } @@ -389,10 +382,10 @@ void DurationMetricProducer::onSlicedConditionMayChangeLocked(bool overallCondit continue; } unique_ptr newTracker = - whatIt.second.begin()->second->clone(eventTime); + whatIt.second.begin()->second->clone(eventTimeNs); if (newTracker != nullptr) { newTracker->setEventKey(MetricDimensionKey(newEventKey)); - newTracker->onSlicedConditionMayChange(overallCondition, eventTime); + newTracker->onSlicedConditionMayChange(overallCondition, eventTimeNs); whatIt.second[conditionDimension] = std::move(newTracker); } } @@ -418,10 +411,10 @@ void DurationMetricProducer::onSlicedConditionMayChangeLocked(bool overallCondit if (hitGuardRailLocked(newEventKey)) { continue; } - auto newTracker = whatIt.second.begin()->second->clone(eventTime); + auto newTracker = whatIt.second.begin()->second->clone(eventTimeNs); if (newTracker != nullptr) { newTracker->setEventKey(newEventKey); - newTracker->onSlicedConditionMayChange(overallCondition, eventTime); + newTracker->onSlicedConditionMayChange(overallCondition, eventTimeNs); whatIt.second[conditionDimension] = std::move(newTracker); } } @@ -430,10 +423,61 @@ void DurationMetricProducer::onSlicedConditionMayChangeLocked(bool overallCondit } } +void DurationMetricProducer::onSlicedConditionMayChangeLocked(bool overallCondition, + const int64_t eventTime) { + VLOG("Metric %lld onSlicedConditionMayChange", (long long)mMetricId); + + if (!mIsActive) { + return; + } + + flushIfNeededLocked(eventTime); + + if (!mConditionSliced) { + return; + } + + onSlicedConditionMayChangeInternalLocked(overallCondition, eventTime); +} + +void DurationMetricProducer::onActiveStateChangedLocked(const int64_t& eventTimeNs) { + MetricProducer::onActiveStateChangedLocked(eventTimeNs); + + if (!mConditionSliced) { + if (ConditionState::kTrue != mCondition) { + return; + } + + if (mIsActive) { + flushIfNeededLocked(eventTimeNs); + } + + for (auto& whatIt : mCurrentSlicedDurationTrackerMap) { + for (auto& pair : whatIt.second) { + pair.second->onConditionChanged(mIsActive, eventTimeNs); + } + } + } else if (mIsActive) { + flushIfNeededLocked(eventTimeNs); + onSlicedConditionMayChangeInternalLocked(mIsActive, eventTimeNs); + } else { // mConditionSliced == true && !mIsActive + for (auto& whatIt : mCurrentSlicedDurationTrackerMap) { + for (auto& pair : whatIt.second) { + pair.second->onConditionChanged(mIsActive, eventTimeNs); + } + } + } +} + void DurationMetricProducer::onConditionChangedLocked(const bool conditionMet, const int64_t eventTime) { VLOG("Metric %lld onConditionChanged", (long long)mMetricId); mCondition = conditionMet ? ConditionState::kTrue : ConditionState::kFalse; + + if (!mIsActive) { + return; + } + flushIfNeededLocked(eventTime); for (auto& whatIt : mCurrentSlicedDurationTrackerMap) { for (auto& pair : whatIt.second) { @@ -696,7 +740,9 @@ void DurationMetricProducer::onMatchedLogEventLocked(const size_t matcherIndex, return; } - flushIfNeededLocked(event.GetElapsedTimestampNs()); + if (mIsActive) { + flushIfNeededLocked(event.GetElapsedTimestampNs()); + } // Handles Stopall events. if (matcherIndex == mStopAllIndex) { @@ -767,6 +813,8 @@ void DurationMetricProducer::onMatchedLogEventLocked(const size_t matcherIndex, } } + condition = condition && mIsActive; + if (dimensionKeysInCondition.empty()) { handleStartEvent(MetricDimensionKey(dimensionInWhat, DEFAULT_DIMENSION_KEY), conditionKey, condition, event); diff --git a/cmds/statsd/src/metrics/DurationMetricProducer.h b/cmds/statsd/src/metrics/DurationMetricProducer.h index f711df240f5e8..56c9fd68eac54 100644 --- a/cmds/statsd/src/metrics/DurationMetricProducer.h +++ b/cmds/statsd/src/metrics/DurationMetricProducer.h @@ -73,9 +73,15 @@ private: // Internal interface to handle condition change. void onConditionChangedLocked(const bool conditionMet, const int64_t eventTime) override; + // Internal interface to handle active state change. + void onActiveStateChangedLocked(const int64_t& eventTimeNs) override; + // Internal interface to handle sliced condition change. void onSlicedConditionMayChangeLocked(bool overallCondition, const int64_t eventTime) override; + void onSlicedConditionMayChangeInternalLocked(bool overallCondition, + const int64_t eventTimeNs); + void onSlicedConditionMayChangeLocked_opt1(bool overallCondition, const int64_t eventTime); void onSlicedConditionMayChangeLocked_opt2(bool overallCondition, const int64_t eventTime); diff --git a/cmds/statsd/src/metrics/GaugeMetricProducer.cpp b/cmds/statsd/src/metrics/GaugeMetricProducer.cpp index 41000dae14624..7a87f0381676b 100644 --- a/cmds/statsd/src/metrics/GaugeMetricProducer.cpp +++ b/cmds/statsd/src/metrics/GaugeMetricProducer.cpp @@ -364,11 +364,27 @@ void GaugeMetricProducer::pullAndMatchEventsLocked(const int64_t timestampNs) { } } +void GaugeMetricProducer::onActiveStateChangedLocked(const int64_t& eventTimeNs) { + MetricProducer::onActiveStateChangedLocked(eventTimeNs); + if (ConditionState::kTrue != mCondition || !mIsPulled) { + return; + } + if (mTriggerAtomId == -1 || (mIsActive && mSamplingType == GaugeMetric::RANDOM_ONE_SAMPLE)) { + pullAndMatchEventsLocked(eventTimeNs); + } + +} + void GaugeMetricProducer::onConditionChangedLocked(const bool conditionMet, const int64_t eventTimeNs) { VLOG("GaugeMetric %lld onConditionChanged", (long long)mMetricId); - flushIfNeededLocked(eventTimeNs); + mCondition = conditionMet ? ConditionState::kTrue : ConditionState::kFalse; + if (!mIsActive) { + return; + } + + flushIfNeededLocked(eventTimeNs); if (mIsPulled && mTriggerAtomId == -1) { pullAndMatchEventsLocked(eventTimeNs); } // else: Push mode. No need to proactively pull the gauge data. @@ -378,10 +394,14 @@ void GaugeMetricProducer::onSlicedConditionMayChangeLocked(bool overallCondition const int64_t eventTimeNs) { VLOG("GaugeMetric %lld onSlicedConditionMayChange overall condition %d", (long long)mMetricId, overallCondition); + mCondition = overallCondition ? ConditionState::kTrue : ConditionState::kFalse; + if (!mIsActive) { + return; + } + flushIfNeededLocked(eventTimeNs); // If the condition is sliced, mCondition is true if any of the dimensions is true. And we will // pull for every dimension. - mCondition = overallCondition ? ConditionState::kTrue : ConditionState::kFalse; if (mIsPulled && mTriggerAtomId == -1) { pullAndMatchEventsLocked(eventTimeNs); } // else: Push mode. No need to proactively pull the gauge data. diff --git a/cmds/statsd/src/metrics/GaugeMetricProducer.h b/cmds/statsd/src/metrics/GaugeMetricProducer.h index 1b43d4386e6c8..a612adf8a38b5 100644 --- a/cmds/statsd/src/metrics/GaugeMetricProducer.h +++ b/cmds/statsd/src/metrics/GaugeMetricProducer.h @@ -106,6 +106,9 @@ private: // Internal interface to handle condition change. void onConditionChangedLocked(const bool conditionMet, const int64_t eventTime) override; + // Internal interface to handle active state change. + void onActiveStateChangedLocked(const int64_t& eventTimeNs) override; + // Internal interface to handle sliced condition change. void onSlicedConditionMayChangeLocked(bool overallCondition, const int64_t eventTime) override; diff --git a/cmds/statsd/src/metrics/MetricProducer.cpp b/cmds/statsd/src/metrics/MetricProducer.cpp index d913427a05dcc..8cbc9c45ca279 100644 --- a/cmds/statsd/src/metrics/MetricProducer.cpp +++ b/cmds/statsd/src/metrics/MetricProducer.cpp @@ -107,7 +107,7 @@ void MetricProducer::flushIfExpire(int64_t elapsedTimestampNs) { } mIsActive = evaluateActiveStateLocked(elapsedTimestampNs); if (!mIsActive) { - flushLocked(elapsedTimestampNs); + onActiveStateChangedLocked(elapsedTimestampNs); } } @@ -143,7 +143,11 @@ void MetricProducer::activateLocked(int activationTrackerIndex, int64_t elapsedT } activation->start_ns = elapsedTimestampNs; activation->state = ActivationState::kActive; + bool oldActiveState = mIsActive; mIsActive = true; + if (!oldActiveState) { // Metric went from not active to active. + onActiveStateChangedLocked(elapsedTimestampNs); + } } void MetricProducer::cancelEventActivationLocked(int deactivationTrackerIndex) { diff --git a/cmds/statsd/src/metrics/MetricProducer.h b/cmds/statsd/src/metrics/MetricProducer.h index 3ddbef44718da..aa757618435c5 100644 --- a/cmds/statsd/src/metrics/MetricProducer.h +++ b/cmds/statsd/src/metrics/MetricProducer.h @@ -132,23 +132,17 @@ public: // Consume the parsed stats log entry that already matched the "what" of the metric. void onMatchedLogEvent(const size_t matcherIndex, const LogEvent& event) { std::lock_guard lock(mMutex); - if (mIsActive) { - onMatchedLogEventLocked(matcherIndex, event); - } + onMatchedLogEventLocked(matcherIndex, event); } void onConditionChanged(const bool condition, const int64_t eventTime) { std::lock_guard lock(mMutex); - if (mIsActive) { - onConditionChangedLocked(condition, eventTime); - } + onConditionChangedLocked(condition, eventTime); } void onSlicedConditionMayChange(bool overallCondition, const int64_t eventTime) { std::lock_guard lock(mMutex); - if (mIsActive) { - onSlicedConditionMayChangeLocked(overallCondition, eventTime); - } + onSlicedConditionMayChangeLocked(overallCondition, eventTime); } bool isConditionSliced() const { @@ -304,12 +298,18 @@ protected: * bucket's end timestamp, than we flush up to the end of the latest full bucket; otherwise, * we assume that we want to flush a partial bucket. The bucket start timestamp and bucket * number are not changed by this function. This method should only be called by - * flushIfNeededLocked or the app upgrade handler; the caller MUST update the bucket timestamp - * and bucket number as needed. + * flushIfNeededLocked or flushLocked or the app upgrade handler; the caller MUST update the + * bucket timestamp and bucket number as needed. */ virtual void flushCurrentBucketLocked(const int64_t& eventTimeNs, const int64_t& nextBucketStartTimeNs) {}; + virtual void onActiveStateChangedLocked(const int64_t& eventTimeNs) { + if (!mIsActive) { + flushLocked(eventTimeNs); + } + } + // Convenience to compute the current bucket's end time, which is always aligned with the // start time of the metric. int64_t getCurrentBucketEndTimeNs() const { @@ -412,6 +412,13 @@ protected: bool mIsActive; + FRIEND_TEST(DurationMetricE2eTest, TestOneBucket); + FRIEND_TEST(DurationMetricE2eTest, TestTwoBuckets); + FRIEND_TEST(DurationMetricE2eTest, TestWithActivation); + FRIEND_TEST(DurationMetricE2eTest, TestWithCondition); + FRIEND_TEST(DurationMetricE2eTest, TestWithSlicedCondition); + FRIEND_TEST(DurationMetricE2eTest, TestWithActivationAndSlicedCondition); + FRIEND_TEST(MetricActivationE2eTest, TestCountMetric); FRIEND_TEST(MetricActivationE2eTest, TestCountMetricWithOneDeactivation); FRIEND_TEST(MetricActivationE2eTest, TestCountMetricWithTwoDeactivations); diff --git a/cmds/statsd/src/metrics/MetricsManager.h b/cmds/statsd/src/metrics/MetricsManager.h index da3be061cb57e..6fc2c1379645c 100644 --- a/cmds/statsd/src/metrics/MetricsManager.h +++ b/cmds/statsd/src/metrics/MetricsManager.h @@ -291,6 +291,13 @@ private: FRIEND_TEST(StatsLogProcessorTest, TestActivationOnBootMultipleActivationsDifferentActivationTypes); FRIEND_TEST(StatsLogProcessorTest, TestActivationsPersistAcrossSystemServerRestart); + + FRIEND_TEST(DurationMetricE2eTest, TestOneBucket); + FRIEND_TEST(DurationMetricE2eTest, TestTwoBuckets); + FRIEND_TEST(DurationMetricE2eTest, TestWithActivation); + FRIEND_TEST(DurationMetricE2eTest, TestWithCondition); + FRIEND_TEST(DurationMetricE2eTest, TestWithSlicedCondition); + FRIEND_TEST(DurationMetricE2eTest, TestWithActivationAndSlicedCondition); }; } // namespace statsd diff --git a/cmds/statsd/src/metrics/ValueMetricProducer.cpp b/cmds/statsd/src/metrics/ValueMetricProducer.cpp index 17f2994cca310..01362b6b4fedf 100644 --- a/cmds/statsd/src/metrics/ValueMetricProducer.cpp +++ b/cmds/statsd/src/metrics/ValueMetricProducer.cpp @@ -109,7 +109,7 @@ ValueMetricProducer::ValueMetricProducer( mMaxPullDelayNs(metric.max_pull_delay_sec() > 0 ? metric.max_pull_delay_sec() * NS_PER_SEC : StatsdStats::kPullMaxDelayNs), mSplitBucketForAppUpgrade(metric.split_bucket_for_app_upgrade()), - mConditionTimer(mCondition == ConditionState::kTrue, timeBaseNs) { + mConditionTimer(mIsActive && mCondition == ConditionState::kTrue, timeBaseNs) { int64_t bucketSizeMills = 0; if (metric.has_bucket()) { bucketSizeMills = TimeUnitToBucketSizeInMillisGuardrailed(key.GetUid(), metric.bucket()); @@ -364,58 +364,98 @@ void ValueMetricProducer::resetBase() { mHasGlobalBase = false; } -void ValueMetricProducer::onConditionChangedLocked(const bool condition, - const int64_t eventTimeNs) { +// Handle active state change. Active state change is treated like a condition change: +// - drop bucket if active state change event arrives too late +// - if condition is true, pull data on active state changes +// - ConditionTimer tracks changes based on AND of condition and active state. +void ValueMetricProducer::onActiveStateChangedLocked(const int64_t& eventTimeNs) { bool isEventTooLate = eventTimeNs < mCurrentBucketStartTimeNs; - if (!isEventTooLate) { - if (mCondition == ConditionState::kUnknown) { - // If the condition was unknown, we mark the bucket as invalid since the bucket will - // contain partial data. For instance, the condition change might happen close to the - // end of the bucket and we might miss lots of data. - // - // We still want to pull to set the base. - invalidateCurrentBucket(); - } - - // Pull on condition changes. - ConditionState newCondition = condition ? ConditionState::kTrue : ConditionState::kFalse; - bool conditionChanged = - (mCondition == ConditionState::kTrue && newCondition == ConditionState::kFalse) - || (mCondition == ConditionState::kFalse && newCondition == ConditionState::kTrue); - // We do not need to pull when we go from unknown to false. - // - // We also pull if the condition was already true in order to be able to flush the bucket at - // the end if needed. - // - // onConditionChangedLocked might happen on bucket boundaries if this is called before - // #onDataPulled. - if (mIsPulled && (conditionChanged || condition)) { - pullAndMatchEventsLocked(eventTimeNs, newCondition); - } - - // When condition change from true to false, clear diff base but don't - // reset other counters as we may accumulate more value in the bucket. - if (mUseDiff && mCondition == ConditionState::kTrue - && newCondition == ConditionState::kFalse) { - resetBase(); - } - mCondition = newCondition; - } else { - VLOG("Skip event due to late arrival: %lld vs %lld", (long long)eventTimeNs, - (long long)mCurrentBucketStartTimeNs); - StatsdStats::getInstance().noteConditionChangeInNextBucket(mMetricId); + if (ConditionState::kTrue == mCondition && isEventTooLate) { + // Drop bucket because event arrived too late, ie. we are missing data for this bucket. invalidateCurrentBucket(); - // Something weird happened. If we received another event in the future, the condition might - // be wrong. - mCondition = initialCondition(mConditionTrackerIndex); } - // This part should alway be called. + // Call parent method once we've verified the validity of current bucket. + MetricProducer::onActiveStateChangedLocked(eventTimeNs); + + if (ConditionState::kTrue != mCondition) { + return; + } + + // Pull on active state changes. + if (!isEventTooLate) { + if (mIsPulled) { + pullAndMatchEventsLocked(eventTimeNs, mCondition); + } + // When active state changes from true to false, clear diff base but don't + // reset other counters as we may accumulate more value in the bucket. + if (mUseDiff && !mIsActive) { + resetBase(); + } + } + flushIfNeededLocked(eventTimeNs); - mConditionTimer.onConditionChanged(mCondition, eventTimeNs); + + // Let condition timer know of new active state. + mConditionTimer.onConditionChanged(mIsActive, eventTimeNs); } -void ValueMetricProducer::pullAndMatchEventsLocked(const int64_t timestampNs, ConditionState condition) { +void ValueMetricProducer::onConditionChangedLocked(const bool condition, + const int64_t eventTimeNs) { + ConditionState newCondition = condition ? ConditionState::kTrue : ConditionState::kFalse; + bool isEventTooLate = eventTimeNs < mCurrentBucketStartTimeNs; + + if (mIsActive) { + if (isEventTooLate) { + VLOG("Skip event due to late arrival: %lld vs %lld", (long long)eventTimeNs, + (long long)mCurrentBucketStartTimeNs); + StatsdStats::getInstance().noteConditionChangeInNextBucket(mMetricId); + invalidateCurrentBucket(); + } else { + if (mCondition == ConditionState::kUnknown) { + // If the condition was unknown, we mark the bucket as invalid since the bucket will + // contain partial data. For instance, the condition change might happen close to + // the end of the bucket and we might miss lots of data. + // + // We still want to pull to set the base. + invalidateCurrentBucket(); + } + + // Pull on condition changes. + bool conditionChanged = + (mCondition == ConditionState::kTrue && newCondition == ConditionState::kFalse) + || (mCondition == ConditionState::kFalse && + newCondition == ConditionState::kTrue); + // We do not need to pull when we go from unknown to false. + // + // We also pull if the condition was already true in order to be able to flush the + // bucket at the end if needed. + // + // onConditionChangedLocked might happen on bucket boundaries if this is called before + // #onDataPulled. + if (mIsPulled && (conditionChanged || condition)) { + pullAndMatchEventsLocked(eventTimeNs, newCondition); + } + + // When condition change from true to false, clear diff base but don't + // reset other counters as we may accumulate more value in the bucket. + if (mUseDiff && mCondition == ConditionState::kTrue + && newCondition == ConditionState::kFalse) { + resetBase(); + } + } + } + + mCondition = isEventTooLate ? initialCondition(mConditionTrackerIndex) : newCondition; + + if (mIsActive) { + flushIfNeededLocked(eventTimeNs); + mConditionTimer.onConditionChanged(mCondition, eventTimeNs); + } +} + +void ValueMetricProducer::pullAndMatchEventsLocked(const int64_t timestampNs, + ConditionState condition) { vector> allData; if (!mPullerManager->Pull(mPullTagId, &allData)) { ALOGE("Stats puller failed for tag: %d at %lld", mPullTagId, (long long)timestampNs); diff --git a/cmds/statsd/src/metrics/ValueMetricProducer.h b/cmds/statsd/src/metrics/ValueMetricProducer.h index de01e7221ad0d..739f6ef07cc45 100644 --- a/cmds/statsd/src/metrics/ValueMetricProducer.h +++ b/cmds/statsd/src/metrics/ValueMetricProducer.h @@ -93,6 +93,9 @@ private: android::util::ProtoOutputStream* protoOutput) override; void clearPastBucketsLocked(const int64_t dumpTimeNs) override; + // Internal interface to handle active state change. + void onActiveStateChangedLocked(const int64_t& eventTimeNs) override; + // Internal interface to handle condition change. void onConditionChangedLocked(const bool conditionMet, const int64_t eventTime) override; diff --git a/cmds/statsd/tests/e2e/DurationMetric_e2e_test.cpp b/cmds/statsd/tests/e2e/DurationMetric_e2e_test.cpp new file mode 100644 index 0000000000000..5da0fca2f3ede --- /dev/null +++ b/cmds/statsd/tests/e2e/DurationMetric_e2e_test.cpp @@ -0,0 +1,717 @@ +// Copyright (C) 2019 The Android Open Source Project +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +#include + +#include "src/StatsLogProcessor.h" +#include "src/stats_log_util.h" +#include "tests/statsd_test_util.h" + +#include + +namespace android { +namespace os { +namespace statsd { + +#ifdef __ANDROID__ + +TEST(DurationMetricE2eTest, TestOneBucket) { + StatsdConfig config; + config.add_allowed_log_source("AID_ROOT"); // LogEvent defaults to UID of root. + + auto screenOnMatcher = CreateScreenTurnedOnAtomMatcher(); + auto screenOffMatcher = CreateScreenTurnedOffAtomMatcher(); + *config.add_atom_matcher() = screenOnMatcher; + *config.add_atom_matcher() = screenOffMatcher; + + auto durationPredicate = CreateScreenIsOnPredicate(); + *config.add_predicate() = durationPredicate; + + int64_t metricId = 123456; + auto durationMetric = config.add_duration_metric(); + durationMetric->set_id(metricId); + durationMetric->set_what(durationPredicate.id()); + durationMetric->set_bucket(FIVE_MINUTES); + durationMetric->set_aggregation_type(DurationMetric_AggregationType_SUM); + + + const int64_t baseTimeNs = 0; // 0:00 + const int64_t configAddedTimeNs = baseTimeNs + 1 * NS_PER_SEC; // 0:01 + const int64_t bucketSizeNs = + TimeUnitToBucketSizeInMillis(config.duration_metric(0).bucket()) * 1000LL * 1000LL; + + int uid = 12345; + int64_t cfgId = 98765; + ConfigKey cfgKey(uid, cfgId); + + auto processor = CreateStatsLogProcessor(baseTimeNs, configAddedTimeNs, config, cfgKey); + + EXPECT_EQ(processor->mMetricsManagers.size(), 1u); + sp metricsManager = processor->mMetricsManagers.begin()->second; + EXPECT_TRUE(metricsManager->isConfigValid()); + EXPECT_EQ(metricsManager->mAllMetricProducers.size(), 1); + sp metricProducer = metricsManager->mAllMetricProducers[0]; + EXPECT_TRUE(metricsManager->isActive()); + EXPECT_TRUE(metricProducer->mIsActive); + + std::unique_ptr event; + + // Screen is off at start of bucket. + event = CreateScreenStateChangedEvent( + android::view::DISPLAY_STATE_OFF, configAddedTimeNs); // 0:01 + processor->OnLogEvent(event.get()); + + // Turn screen on. + const int64_t durationStartNs = configAddedTimeNs + 10 * NS_PER_SEC; // 0:11 + event = CreateScreenStateChangedEvent(android::view::DISPLAY_STATE_ON, durationStartNs); + processor->OnLogEvent(event.get()); + + // Turn off screen 30 seconds after turning on. + const int64_t durationEndNs = durationStartNs + 30 * NS_PER_SEC; // 0:41 + event = CreateScreenStateChangedEvent(android::view::DISPLAY_STATE_OFF, durationEndNs); + processor->OnLogEvent(event.get()); + + event = CreateScreenBrightnessChangedEvent(64, durationEndNs + 1 * NS_PER_SEC); // 0:42 + processor->OnLogEvent(event.get()); + + ConfigMetricsReportList reports; + vector buffer; + processor->onDumpReport(cfgKey, configAddedTimeNs + bucketSizeNs + 1 * NS_PER_SEC, false, true, + ADB_DUMP, FAST, &buffer); // 5:01 + EXPECT_TRUE(buffer.size() > 0); + EXPECT_TRUE(reports.ParseFromArray(&buffer[0], buffer.size())); + backfillDimensionPath(&reports); + backfillStartEndTimestamp(&reports); + EXPECT_EQ(1, reports.reports_size()); + EXPECT_EQ(1, reports.reports(0).metrics_size()); + EXPECT_EQ(metricId, reports.reports(0).metrics(0).metric_id()); + EXPECT_TRUE(reports.reports(0).metrics(0).has_duration_metrics()); + + const StatsLogReport::DurationMetricDataWrapper& durationMetrics = + reports.reports(0).metrics(0).duration_metrics(); + EXPECT_EQ(1, durationMetrics.data_size()); + + auto data = durationMetrics.data(0); + EXPECT_EQ(1, data.bucket_info_size()); + EXPECT_EQ(durationEndNs - durationStartNs, data.bucket_info(0).duration_nanos()); + EXPECT_EQ(configAddedTimeNs, data.bucket_info(0).start_bucket_elapsed_nanos()); + EXPECT_EQ(baseTimeNs + bucketSizeNs, data.bucket_info(0).end_bucket_elapsed_nanos()); +} + +TEST(DurationMetricE2eTest, TestTwoBuckets) { + StatsdConfig config; + config.add_allowed_log_source("AID_ROOT"); // LogEvent defaults to UID of root. + + auto screenOnMatcher = CreateScreenTurnedOnAtomMatcher(); + auto screenOffMatcher = CreateScreenTurnedOffAtomMatcher(); + *config.add_atom_matcher() = screenOnMatcher; + *config.add_atom_matcher() = screenOffMatcher; + + auto durationPredicate = CreateScreenIsOnPredicate(); + *config.add_predicate() = durationPredicate; + + int64_t metricId = 123456; + auto durationMetric = config.add_duration_metric(); + durationMetric->set_id(metricId); + durationMetric->set_what(durationPredicate.id()); + durationMetric->set_bucket(FIVE_MINUTES); + durationMetric->set_aggregation_type(DurationMetric_AggregationType_SUM); + + + const int64_t baseTimeNs = 0; // 0:00 + const int64_t configAddedTimeNs = baseTimeNs + 1 * NS_PER_SEC; // 0:01 + const int64_t bucketSizeNs = + TimeUnitToBucketSizeInMillis(config.duration_metric(0).bucket()) * 1000LL * 1000LL; + + int uid = 12345; + int64_t cfgId = 98765; + ConfigKey cfgKey(uid, cfgId); + + auto processor = CreateStatsLogProcessor(baseTimeNs, configAddedTimeNs, config, cfgKey); + + EXPECT_EQ(processor->mMetricsManagers.size(), 1u); + sp metricsManager = processor->mMetricsManagers.begin()->second; + EXPECT_TRUE(metricsManager->isConfigValid()); + EXPECT_EQ(metricsManager->mAllMetricProducers.size(), 1); + sp metricProducer = metricsManager->mAllMetricProducers[0]; + EXPECT_TRUE(metricsManager->isActive()); + EXPECT_TRUE(metricProducer->mIsActive); + + std::unique_ptr event; + + // Screen is off at start of bucket. + event = CreateScreenStateChangedEvent( + android::view::DISPLAY_STATE_OFF, configAddedTimeNs); // 0:01 + processor->OnLogEvent(event.get()); + + // Turn screen on. + const int64_t durationStartNs = configAddedTimeNs + 10 * NS_PER_SEC; // 0:11 + event = CreateScreenStateChangedEvent(android::view::DISPLAY_STATE_ON, durationStartNs); + processor->OnLogEvent(event.get()); + + // Turn off screen 30 seconds after turning on. + const int64_t durationEndNs = durationStartNs + 30 * NS_PER_SEC; // 0:41 + event = CreateScreenStateChangedEvent(android::view::DISPLAY_STATE_OFF, durationEndNs); + processor->OnLogEvent(event.get()); + + event = CreateScreenBrightnessChangedEvent(64, durationEndNs + 1 * NS_PER_SEC); // 0:42 + processor->OnLogEvent(event.get()); + + ConfigMetricsReportList reports; + vector buffer; + processor->onDumpReport(cfgKey, configAddedTimeNs + 2 * bucketSizeNs + 1 * NS_PER_SEC, false, true, + ADB_DUMP, FAST, &buffer); // 10:01 + EXPECT_TRUE(buffer.size() > 0); + EXPECT_TRUE(reports.ParseFromArray(&buffer[0], buffer.size())); + backfillDimensionPath(&reports); + backfillStartEndTimestamp(&reports); + EXPECT_EQ(1, reports.reports_size()); + EXPECT_EQ(1, reports.reports(0).metrics_size()); + EXPECT_EQ(metricId, reports.reports(0).metrics(0).metric_id()); + EXPECT_TRUE(reports.reports(0).metrics(0).has_duration_metrics()); + + const StatsLogReport::DurationMetricDataWrapper& durationMetrics = + reports.reports(0).metrics(0).duration_metrics(); + EXPECT_EQ(1, durationMetrics.data_size()); + + auto data = durationMetrics.data(0); + EXPECT_EQ(1, data.bucket_info_size()); + + auto bucketInfo = data.bucket_info(0); + EXPECT_EQ(0, bucketInfo.bucket_num()); + EXPECT_EQ(durationEndNs - durationStartNs, bucketInfo.duration_nanos()); + EXPECT_EQ(configAddedTimeNs, bucketInfo.start_bucket_elapsed_nanos()); + EXPECT_EQ(baseTimeNs + bucketSizeNs, bucketInfo.end_bucket_elapsed_nanos()); +} + +TEST(DurationMetricE2eTest, TestWithActivation) { + StatsdConfig config; + config.add_allowed_log_source("AID_ROOT"); // LogEvent defaults to UID of root. + + auto screenOnMatcher = CreateScreenTurnedOnAtomMatcher(); + auto screenOffMatcher = CreateScreenTurnedOffAtomMatcher(); + auto crashMatcher = CreateProcessCrashAtomMatcher(); + *config.add_atom_matcher() = screenOnMatcher; + *config.add_atom_matcher() = screenOffMatcher; + *config.add_atom_matcher() = crashMatcher; + + auto durationPredicate = CreateScreenIsOnPredicate(); + *config.add_predicate() = durationPredicate; + + int64_t metricId = 123456; + auto durationMetric = config.add_duration_metric(); + durationMetric->set_id(metricId); + durationMetric->set_what(durationPredicate.id()); + durationMetric->set_bucket(FIVE_MINUTES); + durationMetric->set_aggregation_type(DurationMetric_AggregationType_SUM); + + auto metric_activation1 = config.add_metric_activation(); + metric_activation1->set_metric_id(metricId); + auto event_activation1 = metric_activation1->add_event_activation(); + event_activation1->set_atom_matcher_id(crashMatcher.id()); + event_activation1->set_ttl_seconds(30); // 30 secs. + + const int64_t bucketStartTimeNs = 10000000000; + const int64_t bucketSizeNs = + TimeUnitToBucketSizeInMillis(config.duration_metric(0).bucket()) * 1000LL * 1000LL; + + int uid = 12345; + int64_t cfgId = 98765; + ConfigKey cfgKey(uid, cfgId); + + sp m = new UidMap(); + sp pullerManager = new StatsPullerManager(); + sp anomalyAlarmMonitor; + sp subscriberAlarmMonitor; + vector activeConfigsBroadcast; + + int broadcastCount = 0; + StatsLogProcessor processor(m, pullerManager, anomalyAlarmMonitor, subscriberAlarmMonitor, + bucketStartTimeNs, [](const ConfigKey& key) { return true; }, + [&uid, &broadcastCount, &activeConfigsBroadcast](const int& broadcastUid, + const vector& activeConfigs) { + broadcastCount++; + EXPECT_EQ(broadcastUid, uid); + activeConfigsBroadcast.clear(); + activeConfigsBroadcast.insert(activeConfigsBroadcast.end(), + activeConfigs.begin(), activeConfigs.end()); + return true; + }); + + processor.OnConfigUpdated(bucketStartTimeNs, cfgKey, config); // 0:00 + + EXPECT_EQ(processor.mMetricsManagers.size(), 1u); + sp metricsManager = processor.mMetricsManagers.begin()->second; + EXPECT_TRUE(metricsManager->isConfigValid()); + EXPECT_EQ(metricsManager->mAllMetricProducers.size(), 1); + sp metricProducer = metricsManager->mAllMetricProducers[0]; + auto& eventActivationMap = metricProducer->mEventActivationMap; + + EXPECT_FALSE(metricsManager->isActive()); + EXPECT_FALSE(metricProducer->mIsActive); + EXPECT_EQ(eventActivationMap.size(), 1u); + EXPECT_TRUE(eventActivationMap.find(2) != eventActivationMap.end()); + EXPECT_EQ(eventActivationMap[2]->state, ActivationState::kNotActive); + EXPECT_EQ(eventActivationMap[2]->start_ns, 0); + EXPECT_EQ(eventActivationMap[2]->ttl_ns, event_activation1->ttl_seconds() * NS_PER_SEC); + + std::unique_ptr event; + + // Turn screen off. + event = CreateScreenStateChangedEvent( + android::view::DISPLAY_STATE_OFF, bucketStartTimeNs + 2 * NS_PER_SEC); // 0:02 + processor.OnLogEvent(event.get()); + + // Turn screen on. + const int64_t durationStartNs = bucketStartTimeNs + 5 * NS_PER_SEC; // 0:05 + event = CreateScreenStateChangedEvent(android::view::DISPLAY_STATE_ON, durationStartNs); + processor.OnLogEvent(event.get()); + + // Activate metric. + const int64_t activationStartNs = bucketStartTimeNs + 5 * NS_PER_SEC; // 0:10 + const int64_t activationEndNs = + activationStartNs + event_activation1->ttl_seconds() * NS_PER_SEC; // 0:40 + event = CreateAppCrashEvent(111, activationStartNs); + processor.OnLogEvent(event.get()); + EXPECT_TRUE(metricsManager->isActive()); + EXPECT_TRUE(metricProducer->mIsActive); + EXPECT_EQ(broadcastCount, 1); + EXPECT_EQ(activeConfigsBroadcast.size(), 1); + EXPECT_EQ(activeConfigsBroadcast[0], cfgId); + EXPECT_EQ(eventActivationMap[2]->state, ActivationState::kActive); + EXPECT_EQ(eventActivationMap[2]->start_ns, activationStartNs); + EXPECT_EQ(eventActivationMap[2]->ttl_ns, event_activation1->ttl_seconds() * NS_PER_SEC); + + // Expire activation. + const int64_t expirationNs = activationEndNs + 7 * NS_PER_SEC; + event = CreateScreenBrightnessChangedEvent(64, expirationNs); // 0:47 + processor.OnLogEvent(event.get()); + EXPECT_FALSE(metricsManager->isActive()); + EXPECT_FALSE(metricProducer->mIsActive); + EXPECT_EQ(broadcastCount, 2); + EXPECT_EQ(activeConfigsBroadcast.size(), 0); + EXPECT_EQ(eventActivationMap.size(), 1u); + EXPECT_TRUE(eventActivationMap.find(2) != eventActivationMap.end()); + EXPECT_EQ(eventActivationMap[2]->state, ActivationState::kNotActive); + EXPECT_EQ(eventActivationMap[2]->start_ns, activationStartNs); + EXPECT_EQ(eventActivationMap[2]->ttl_ns, event_activation1->ttl_seconds() * NS_PER_SEC); + + // Turn off screen 10 seconds after activation expiration. + const int64_t durationEndNs = activationEndNs + 10 * NS_PER_SEC; // 0:50 + event = CreateScreenStateChangedEvent(android::view::DISPLAY_STATE_OFF, durationEndNs); + processor.OnLogEvent(event.get()); + + // Turn screen on. + const int64_t duration2StartNs = durationEndNs + 5 * NS_PER_SEC; // 0:55 + event = CreateScreenStateChangedEvent(android::view::DISPLAY_STATE_ON, duration2StartNs); + processor.OnLogEvent(event.get()); + + // Turn off screen. + const int64_t duration2EndNs = duration2StartNs + 10 * NS_PER_SEC; // 1:05 + event = CreateScreenStateChangedEvent(android::view::DISPLAY_STATE_OFF, duration2EndNs); + processor.OnLogEvent(event.get()); + + // Activate metric. + const int64_t activation2StartNs = duration2EndNs + 5 * NS_PER_SEC; // 1:10 + const int64_t activation2EndNs = + activation2StartNs + event_activation1->ttl_seconds() * NS_PER_SEC; // 1:40 + event = CreateAppCrashEvent(211, activation2StartNs); + processor.OnLogEvent(event.get()); + EXPECT_TRUE(metricsManager->isActive()); + EXPECT_TRUE(metricProducer->mIsActive); + EXPECT_EQ(broadcastCount, 3); + EXPECT_EQ(activeConfigsBroadcast.size(), 1); + EXPECT_EQ(activeConfigsBroadcast[0], cfgId); + EXPECT_EQ(eventActivationMap[2]->state, ActivationState::kActive); + EXPECT_EQ(eventActivationMap[2]->start_ns, activation2StartNs); + EXPECT_EQ(eventActivationMap[2]->ttl_ns, event_activation1->ttl_seconds() * NS_PER_SEC); + + ConfigMetricsReportList reports; + vector buffer; + processor.onDumpReport(cfgKey, bucketStartTimeNs + bucketSizeNs + 1 * NS_PER_SEC, false, true, + ADB_DUMP, FAST, &buffer); // 5:01 + EXPECT_TRUE(buffer.size() > 0); + EXPECT_TRUE(reports.ParseFromArray(&buffer[0], buffer.size())); + backfillDimensionPath(&reports); + backfillStartEndTimestamp(&reports); + EXPECT_EQ(1, reports.reports_size()); + EXPECT_EQ(1, reports.reports(0).metrics_size()); + EXPECT_EQ(metricId, reports.reports(0).metrics(0).metric_id()); + EXPECT_TRUE(reports.reports(0).metrics(0).has_duration_metrics()); + + const StatsLogReport::DurationMetricDataWrapper& durationMetrics = + reports.reports(0).metrics(0).duration_metrics(); + EXPECT_EQ(1, durationMetrics.data_size()); + + auto data = durationMetrics.data(0); + EXPECT_EQ(1, data.bucket_info_size()); + + auto bucketInfo = data.bucket_info(0); + EXPECT_EQ(0, bucketInfo.bucket_num()); + EXPECT_EQ(bucketStartTimeNs, bucketInfo.start_bucket_elapsed_nanos()); + EXPECT_EQ(expirationNs, bucketInfo.end_bucket_elapsed_nanos()); + EXPECT_EQ(expirationNs - durationStartNs, bucketInfo.duration_nanos()); +} + +TEST(DurationMetricE2eTest, TestWithCondition) { + StatsdConfig config; + config.add_allowed_log_source("AID_ROOT"); // LogEvent defaults to UID of root. + *config.add_atom_matcher() = CreateAcquireWakelockAtomMatcher(); + *config.add_atom_matcher() = CreateReleaseWakelockAtomMatcher(); + *config.add_atom_matcher() = CreateMoveToBackgroundAtomMatcher(); + *config.add_atom_matcher() = CreateMoveToForegroundAtomMatcher(); + + auto holdingWakelockPredicate = CreateHoldingWakelockPredicate(); + *config.add_predicate() = holdingWakelockPredicate; + + auto isInBackgroundPredicate = CreateIsInBackgroundPredicate(); + *config.add_predicate() = isInBackgroundPredicate; + + auto durationMetric = config.add_duration_metric(); + durationMetric->set_id(StringToId("WakelockDuration")); + durationMetric->set_what(holdingWakelockPredicate.id()); + durationMetric->set_condition(isInBackgroundPredicate.id()); + durationMetric->set_aggregation_type(DurationMetric::SUM); + durationMetric->set_bucket(FIVE_MINUTES); + + ConfigKey cfgKey; + uint64_t bucketStartTimeNs = 10000000000; + uint64_t bucketSizeNs = + TimeUnitToBucketSizeInMillis(config.duration_metric(0).bucket()) * 1000000LL; + auto processor = CreateStatsLogProcessor(bucketStartTimeNs, bucketStartTimeNs, config, cfgKey); + EXPECT_EQ(processor->mMetricsManagers.size(), 1u); + sp metricsManager = processor->mMetricsManagers.begin()->second; + EXPECT_TRUE(metricsManager->isConfigValid()); + EXPECT_EQ(metricsManager->mAllMetricProducers.size(), 1); + sp metricProducer = metricsManager->mAllMetricProducers[0]; + auto& eventActivationMap = metricProducer->mEventActivationMap; + EXPECT_TRUE(metricsManager->isActive()); + EXPECT_TRUE(metricProducer->mIsActive); + EXPECT_TRUE(eventActivationMap.empty()); + + int appUid = 123; + std::vector attributions1 = {CreateAttribution(appUid, "App1")}; + + auto event = CreateAcquireWakelockEvent( + attributions1, "wl1", bucketStartTimeNs + 10 * NS_PER_SEC); // 0:10 + processor->OnLogEvent(event.get()); + + event = CreateMoveToBackgroundEvent(appUid, bucketStartTimeNs + 22 * NS_PER_SEC); // 0:22 + processor->OnLogEvent(event.get()); + + event = CreateMoveToForegroundEvent( + appUid, bucketStartTimeNs + (3 * 60 + 15) * NS_PER_SEC); // 3:15 + processor->OnLogEvent(event.get()); + + event = CreateReleaseWakelockEvent( + attributions1, "wl1", bucketStartTimeNs + 4 * 60 * NS_PER_SEC); // 4:00 + processor->OnLogEvent(event.get()); + + vector buffer; + ConfigMetricsReportList reports; + processor->onDumpReport(cfgKey, bucketStartTimeNs + bucketSizeNs + 1, false, true, + ADB_DUMP, FAST, &buffer); + EXPECT_GT(buffer.size(), 0); + EXPECT_TRUE(reports.ParseFromArray(&buffer[0], buffer.size())); + backfillDimensionPath(&reports); + backfillStringInReport(&reports); + backfillStartEndTimestamp(&reports); + + EXPECT_EQ(1, reports.reports_size()); + EXPECT_EQ(1, reports.reports(0).metrics_size()); + EXPECT_EQ(1, reports.reports(0).metrics(0).duration_metrics().data_size()); + + auto data = reports.reports(0).metrics(0).duration_metrics().data(0); + + // Validate bucket info. + EXPECT_EQ(1, data.bucket_info_size()); + + auto bucketInfo = data.bucket_info(0); + EXPECT_EQ(bucketStartTimeNs, bucketInfo.start_bucket_elapsed_nanos()); + EXPECT_EQ(bucketStartTimeNs + bucketSizeNs, bucketInfo.end_bucket_elapsed_nanos()); + EXPECT_EQ((2 * 60 + 53) * NS_PER_SEC, bucketInfo.duration_nanos()); +} + +TEST(DurationMetricE2eTest, TestWithSlicedCondition) { + StatsdConfig config; + config.add_allowed_log_source("AID_ROOT"); // LogEvent defaults to UID of root. + auto screenOnMatcher = CreateScreenTurnedOnAtomMatcher(); + *config.add_atom_matcher() = CreateAcquireWakelockAtomMatcher(); + *config.add_atom_matcher() = CreateReleaseWakelockAtomMatcher(); + *config.add_atom_matcher() = CreateMoveToBackgroundAtomMatcher(); + *config.add_atom_matcher() = CreateMoveToForegroundAtomMatcher(); + + auto holdingWakelockPredicate = CreateHoldingWakelockPredicate(); + // The predicate is dimensioning by first attribution node by uid. + FieldMatcher dimensions = CreateAttributionUidDimensions( + android::util::WAKELOCK_STATE_CHANGED, {Position::FIRST}); + *holdingWakelockPredicate.mutable_simple_predicate()->mutable_dimensions() = dimensions; + *config.add_predicate() = holdingWakelockPredicate; + + auto isInBackgroundPredicate = CreateIsInBackgroundPredicate(); + *isInBackgroundPredicate.mutable_simple_predicate()->mutable_dimensions() = + CreateDimensions(android::util::ACTIVITY_FOREGROUND_STATE_CHANGED, {Position::FIRST}); + *config.add_predicate() = isInBackgroundPredicate; + + auto durationMetric = config.add_duration_metric(); + durationMetric->set_id(StringToId("WakelockDuration")); + durationMetric->set_what(holdingWakelockPredicate.id()); + durationMetric->set_condition(isInBackgroundPredicate.id()); + durationMetric->set_aggregation_type(DurationMetric::SUM); + // The metric is dimensioning by first attribution node and only by uid. + *durationMetric->mutable_dimensions_in_what() = + CreateAttributionUidDimensions( + android::util::WAKELOCK_STATE_CHANGED, {Position::FIRST}); + durationMetric->set_bucket(FIVE_MINUTES); + + // Links between wakelock state atom and condition of app is in background. + auto links = durationMetric->add_links(); + links->set_condition(isInBackgroundPredicate.id()); + auto dimensionWhat = links->mutable_fields_in_what(); + dimensionWhat->set_field(android::util::WAKELOCK_STATE_CHANGED); + dimensionWhat->add_child()->set_field(1); // uid field. + *links->mutable_fields_in_condition() = CreateAttributionUidDimensions( + android::util::ACTIVITY_FOREGROUND_STATE_CHANGED, { Position::FIRST }); + + ConfigKey cfgKey; + uint64_t bucketStartTimeNs = 10000000000; + uint64_t bucketSizeNs = + TimeUnitToBucketSizeInMillis(config.duration_metric(0).bucket()) * 1000000LL; + auto processor = CreateStatsLogProcessor(bucketStartTimeNs, bucketStartTimeNs, config, cfgKey); + EXPECT_EQ(processor->mMetricsManagers.size(), 1u); + sp metricsManager = processor->mMetricsManagers.begin()->second; + EXPECT_TRUE(metricsManager->isConfigValid()); + EXPECT_EQ(metricsManager->mAllMetricProducers.size(), 1); + sp metricProducer = metricsManager->mAllMetricProducers[0]; + auto& eventActivationMap = metricProducer->mEventActivationMap; + EXPECT_TRUE(metricsManager->isActive()); + EXPECT_TRUE(metricProducer->mIsActive); + EXPECT_TRUE(eventActivationMap.empty()); + + int appUid = 123; + std::vector attributions1 = {CreateAttribution(appUid, "App1")}; + + auto event = CreateAcquireWakelockEvent( + attributions1, "wl1", bucketStartTimeNs + 10 * NS_PER_SEC); // 0:10 + processor->OnLogEvent(event.get()); + + event = CreateMoveToBackgroundEvent(appUid, bucketStartTimeNs + 22 * NS_PER_SEC); // 0:22 + processor->OnLogEvent(event.get()); + + event = CreateReleaseWakelockEvent( + attributions1, "wl1", bucketStartTimeNs + 60 * NS_PER_SEC); // 1:00 + processor->OnLogEvent(event.get()); + + + event = CreateMoveToForegroundEvent( + appUid, bucketStartTimeNs + (3 * 60 + 15) * NS_PER_SEC); // 3:15 + processor->OnLogEvent(event.get()); + + vector buffer; + ConfigMetricsReportList reports; + processor->onDumpReport(cfgKey, bucketStartTimeNs + bucketSizeNs + 1, false, true, + ADB_DUMP, FAST, &buffer); + EXPECT_GT(buffer.size(), 0); + EXPECT_TRUE(reports.ParseFromArray(&buffer[0], buffer.size())); + backfillDimensionPath(&reports); + backfillStringInReport(&reports); + backfillStartEndTimestamp(&reports); + + EXPECT_EQ(1, reports.reports_size()); + EXPECT_EQ(1, reports.reports(0).metrics_size()); + EXPECT_EQ(1, reports.reports(0).metrics(0).duration_metrics().data_size()); + + auto data = reports.reports(0).metrics(0).duration_metrics().data(0); + // Validate dimension value. + ValidateAttributionUidDimension(data.dimensions_in_what(), + android::util::WAKELOCK_STATE_CHANGED, appUid); + // Validate bucket info. + EXPECT_EQ(1, data.bucket_info_size()); + + auto bucketInfo = data.bucket_info(0); + EXPECT_EQ(bucketStartTimeNs, bucketInfo.start_bucket_elapsed_nanos()); + EXPECT_EQ(bucketStartTimeNs + bucketSizeNs, bucketInfo.end_bucket_elapsed_nanos()); + EXPECT_EQ(38 * NS_PER_SEC, bucketInfo.duration_nanos()); +} + +TEST(DurationMetricE2eTest, TestWithActivationAndSlicedCondition) { + StatsdConfig config; + config.add_allowed_log_source("AID_ROOT"); // LogEvent defaults to UID of root. + auto screenOnMatcher = CreateScreenTurnedOnAtomMatcher(); + *config.add_atom_matcher() = CreateAcquireWakelockAtomMatcher(); + *config.add_atom_matcher() = CreateReleaseWakelockAtomMatcher(); + *config.add_atom_matcher() = CreateMoveToBackgroundAtomMatcher(); + *config.add_atom_matcher() = CreateMoveToForegroundAtomMatcher(); + *config.add_atom_matcher() = screenOnMatcher; + + auto holdingWakelockPredicate = CreateHoldingWakelockPredicate(); + // The predicate is dimensioning by first attribution node by uid. + FieldMatcher dimensions = CreateAttributionUidDimensions( + android::util::WAKELOCK_STATE_CHANGED, {Position::FIRST}); + *holdingWakelockPredicate.mutable_simple_predicate()->mutable_dimensions() = dimensions; + *config.add_predicate() = holdingWakelockPredicate; + + auto isInBackgroundPredicate = CreateIsInBackgroundPredicate(); + *isInBackgroundPredicate.mutable_simple_predicate()->mutable_dimensions() = + CreateDimensions(android::util::ACTIVITY_FOREGROUND_STATE_CHANGED, {Position::FIRST}); + *config.add_predicate() = isInBackgroundPredicate; + + auto durationMetric = config.add_duration_metric(); + durationMetric->set_id(StringToId("WakelockDuration")); + durationMetric->set_what(holdingWakelockPredicate.id()); + durationMetric->set_condition(isInBackgroundPredicate.id()); + durationMetric->set_aggregation_type(DurationMetric::SUM); + // The metric is dimensioning by first attribution node and only by uid. + *durationMetric->mutable_dimensions_in_what() = + CreateAttributionUidDimensions( + android::util::WAKELOCK_STATE_CHANGED, {Position::FIRST}); + durationMetric->set_bucket(FIVE_MINUTES); + + // Links between wakelock state atom and condition of app is in background. + auto links = durationMetric->add_links(); + links->set_condition(isInBackgroundPredicate.id()); + auto dimensionWhat = links->mutable_fields_in_what(); + dimensionWhat->set_field(android::util::WAKELOCK_STATE_CHANGED); + dimensionWhat->add_child()->set_field(1); // uid field. + *links->mutable_fields_in_condition() = CreateAttributionUidDimensions( + android::util::ACTIVITY_FOREGROUND_STATE_CHANGED, { Position::FIRST }); + + auto metric_activation1 = config.add_metric_activation(); + metric_activation1->set_metric_id(durationMetric->id()); + auto event_activation1 = metric_activation1->add_event_activation(); + event_activation1->set_atom_matcher_id(screenOnMatcher.id()); + event_activation1->set_ttl_seconds(60 * 2); // 2 minutes. + + ConfigKey cfgKey; + uint64_t bucketStartTimeNs = 10000000000; + uint64_t bucketSizeNs = + TimeUnitToBucketSizeInMillis(config.duration_metric(0).bucket()) * 1000000LL; + auto processor = CreateStatsLogProcessor(bucketStartTimeNs, bucketStartTimeNs, config, cfgKey); + EXPECT_EQ(processor->mMetricsManagers.size(), 1u); + sp metricsManager = processor->mMetricsManagers.begin()->second; + EXPECT_TRUE(metricsManager->isConfigValid()); + EXPECT_EQ(metricsManager->mAllMetricProducers.size(), 1); + sp metricProducer = metricsManager->mAllMetricProducers[0]; + auto& eventActivationMap = metricProducer->mEventActivationMap; + EXPECT_FALSE(metricsManager->isActive()); + EXPECT_FALSE(metricProducer->mIsActive); + EXPECT_EQ(eventActivationMap.size(), 1u); + EXPECT_TRUE(eventActivationMap.find(4) != eventActivationMap.end()); + EXPECT_EQ(eventActivationMap[4]->state, ActivationState::kNotActive); + EXPECT_EQ(eventActivationMap[4]->start_ns, 0); + EXPECT_EQ(eventActivationMap[4]->ttl_ns, event_activation1->ttl_seconds() * NS_PER_SEC); + + int appUid = 123; + std::vector attributions1 = {CreateAttribution(appUid, "App1")}; + + auto event = CreateAcquireWakelockEvent( + attributions1, "wl1", bucketStartTimeNs + 10 * NS_PER_SEC); // 0:10 + processor->OnLogEvent(event.get()); + EXPECT_FALSE(metricsManager->isActive()); + EXPECT_FALSE(metricProducer->mIsActive); + EXPECT_EQ(eventActivationMap[4]->state, ActivationState::kNotActive); + EXPECT_EQ(eventActivationMap[4]->start_ns, 0); + EXPECT_EQ(eventActivationMap[4]->ttl_ns, event_activation1->ttl_seconds() * NS_PER_SEC); + + event = CreateMoveToBackgroundEvent(appUid, bucketStartTimeNs + 22 * NS_PER_SEC); // 0:22 + processor->OnLogEvent(event.get()); + EXPECT_FALSE(metricsManager->isActive()); + EXPECT_FALSE(metricProducer->mIsActive); + EXPECT_EQ(eventActivationMap[4]->state, ActivationState::kNotActive); + EXPECT_EQ(eventActivationMap[4]->start_ns, 0); + EXPECT_EQ(eventActivationMap[4]->ttl_ns, event_activation1->ttl_seconds() * NS_PER_SEC); + + const int64_t durationStartNs = bucketStartTimeNs + 30 * NS_PER_SEC; // 0:30 + event = CreateScreenStateChangedEvent(android::view::DISPLAY_STATE_ON, durationStartNs); + processor->OnLogEvent(event.get()); + EXPECT_TRUE(metricsManager->isActive()); + EXPECT_TRUE(metricProducer->mIsActive); + EXPECT_EQ(eventActivationMap[4]->state, ActivationState::kActive); + EXPECT_EQ(eventActivationMap[4]->start_ns, durationStartNs); + EXPECT_EQ(eventActivationMap[4]->ttl_ns, event_activation1->ttl_seconds() * NS_PER_SEC); + + const int64_t durationEndNs = + durationStartNs + (event_activation1->ttl_seconds() + 30) * NS_PER_SEC; // 3:00 + event = CreateAppCrashEvent(333, durationEndNs); + processor->OnLogEvent(event.get()); + EXPECT_FALSE(metricsManager->isActive()); + EXPECT_FALSE(metricProducer->mIsActive); + EXPECT_EQ(eventActivationMap[4]->state, ActivationState::kNotActive); + EXPECT_EQ(eventActivationMap[4]->start_ns, durationStartNs); + EXPECT_EQ(eventActivationMap[4]->ttl_ns, event_activation1->ttl_seconds() * NS_PER_SEC); + + event = CreateMoveToForegroundEvent( + appUid, bucketStartTimeNs + (3 * 60 + 15) * NS_PER_SEC); // 3:15 + processor->OnLogEvent(event.get()); + + event = CreateReleaseWakelockEvent( + attributions1, "wl1", bucketStartTimeNs + (4 * 60 + 17) * NS_PER_SEC); // 4:17 + processor->OnLogEvent(event.get()); + + event = CreateMoveToBackgroundEvent( + appUid, bucketStartTimeNs + (4 * 60 + 20) * NS_PER_SEC); // 4:20 + processor->OnLogEvent(event.get()); + + event = CreateAcquireWakelockEvent( + attributions1, "wl1", bucketStartTimeNs + (4 * 60 + 25) * NS_PER_SEC); // 4:25 + processor->OnLogEvent(event.get()); + + const int64_t duration2StartNs = bucketStartTimeNs + (4 * 60 + 30) * NS_PER_SEC; // 4:30 + event = CreateScreenStateChangedEvent(android::view::DISPLAY_STATE_ON, duration2StartNs); + processor->OnLogEvent(event.get()); + EXPECT_TRUE(metricsManager->isActive()); + EXPECT_TRUE(metricProducer->mIsActive); + EXPECT_EQ(eventActivationMap[4]->state, ActivationState::kActive); + EXPECT_EQ(eventActivationMap[4]->start_ns, duration2StartNs); + EXPECT_EQ(eventActivationMap[4]->ttl_ns, event_activation1->ttl_seconds() * NS_PER_SEC); + + vector buffer; + ConfigMetricsReportList reports; + processor->onDumpReport(cfgKey, bucketStartTimeNs + bucketSizeNs + 1, false, true, + ADB_DUMP, FAST, &buffer); + EXPECT_GT(buffer.size(), 0); + EXPECT_TRUE(reports.ParseFromArray(&buffer[0], buffer.size())); + backfillDimensionPath(&reports); + backfillStringInReport(&reports); + backfillStartEndTimestamp(&reports); + + EXPECT_EQ(1, reports.reports_size()); + EXPECT_EQ(1, reports.reports(0).metrics_size()); + EXPECT_EQ(1, reports.reports(0).metrics(0).duration_metrics().data_size()); + + auto data = reports.reports(0).metrics(0).duration_metrics().data(0); + // Validate dimension value. + ValidateAttributionUidDimension(data.dimensions_in_what(), + android::util::WAKELOCK_STATE_CHANGED, appUid); + // Validate bucket info. + EXPECT_EQ(2, data.bucket_info_size()); + + auto bucketInfo = data.bucket_info(0); + EXPECT_EQ(bucketStartTimeNs, bucketInfo.start_bucket_elapsed_nanos()); + EXPECT_EQ(durationEndNs, bucketInfo.end_bucket_elapsed_nanos()); + EXPECT_EQ(durationEndNs - durationStartNs, bucketInfo.duration_nanos()); + + bucketInfo = data.bucket_info(1); + EXPECT_EQ(durationEndNs, bucketInfo.start_bucket_elapsed_nanos()); + EXPECT_EQ(bucketStartTimeNs + bucketSizeNs, bucketInfo.end_bucket_elapsed_nanos()); + EXPECT_EQ(bucketStartTimeNs + bucketSizeNs - duration2StartNs, bucketInfo.duration_nanos()); +} + +#else +GTEST_LOG_(INFO) << "This test does nothing.\n"; +#endif + +} // namespace statsd +} // namespace os +} // namespace android diff --git a/cmds/statsd/tests/e2e/GaugeMetric_e2e_pull_test.cpp b/cmds/statsd/tests/e2e/GaugeMetric_e2e_pull_test.cpp index 6ec0a114b3ed6..c7ba9be3ca5a6 100644 --- a/cmds/statsd/tests/e2e/GaugeMetric_e2e_pull_test.cpp +++ b/cmds/statsd/tests/e2e/GaugeMetric_e2e_pull_test.cpp @@ -446,22 +446,23 @@ TEST(GaugeMetricE2eTest, TestRandomSamplePulledEventsWithActivation) { // Pulling alarm arrives on time and reset the sequential pulling alarm. // Event should not be kept. - processor->informPullAlarmFired(nextPullTimeNs + 1); + processor->informPullAlarmFired(nextPullTimeNs + 1); // 15 mins + 1 ns. EXPECT_EQ(baseTimeNs + startBucketNum * bucketSizeNs + 2 * bucketSizeNs, nextPullTimeNs); EXPECT_FALSE(processor->mMetricsManagers.begin()->second->mAllMetricProducers[0]->isActive()); + // Activate the metric. A pull occurs upon activation. const int64_t activationNs = configAddedTimeNs + bucketSizeNs + (2 * 1000 * 1000); // 2 millis. auto batterySaverOnEvent = CreateBatterySaverOnEvent(activationNs); - processor->OnLogEvent(batterySaverOnEvent.get()); + processor->OnLogEvent(batterySaverOnEvent.get()); // 15 mins + 2 ms. EXPECT_TRUE(processor->mMetricsManagers.begin()->second->mAllMetricProducers[0]->isActive()); - // This event should be kept. 1 total. - processor->informPullAlarmFired(nextPullTimeNs + 1); + // This event should be kept. 2 total. + processor->informPullAlarmFired(nextPullTimeNs + 1); // 20 mins + 1 ns. EXPECT_EQ(baseTimeNs + startBucketNum * bucketSizeNs + 3 * bucketSizeNs, nextPullTimeNs); - // This event should be kept. 2 total. - processor->informPullAlarmFired(nextPullTimeNs + 2); + // This event should be kept. 3 total. + processor->informPullAlarmFired(nextPullTimeNs + 2); // 25 mins + 2 ns. EXPECT_EQ(baseTimeNs + startBucketNum * bucketSizeNs + 4 * bucketSizeNs, nextPullTimeNs); // Create random event to deactivate metric. @@ -469,7 +470,7 @@ TEST(GaugeMetricE2eTest, TestRandomSamplePulledEventsWithActivation) { processor->OnLogEvent(deactivationEvent.get()); EXPECT_FALSE(processor->mMetricsManagers.begin()->second->mAllMetricProducers[0]->isActive()); - // Event should not be kept. 2 total. + // Event should not be kept. 3 total. processor->informPullAlarmFired(nextPullTimeNs + 3); EXPECT_EQ(baseTimeNs + startBucketNum * bucketSizeNs + 5 * bucketSizeNs, nextPullTimeNs); @@ -497,27 +498,39 @@ TEST(GaugeMetricE2eTest, TestRandomSamplePulledEventsWithActivation) { EXPECT_EQ(1 /* subsystem name field */, data.dimensions_in_what().value_tuple().dimensions_value(0).field()); EXPECT_FALSE(data.dimensions_in_what().value_tuple().dimensions_value(0).value_str().empty()); - EXPECT_EQ(2, data.bucket_info_size()); + EXPECT_EQ(3, data.bucket_info_size()); - EXPECT_EQ(1, data.bucket_info(0).atom_size()); - EXPECT_EQ(1, data.bucket_info(0).elapsed_timestamp_nanos_size()); - EXPECT_EQ(baseTimeNs + 4 * bucketSizeNs + 1, data.bucket_info(0).elapsed_timestamp_nanos(0)); - EXPECT_EQ(0, data.bucket_info(0).wall_clock_timestamp_nanos_size()); - EXPECT_EQ(baseTimeNs + 4 * bucketSizeNs, data.bucket_info(0).start_bucket_elapsed_nanos()); - EXPECT_EQ(baseTimeNs + 5 * bucketSizeNs, data.bucket_info(0).end_bucket_elapsed_nanos()); - EXPECT_TRUE(data.bucket_info(0).atom(0).subsystem_sleep_state().subsystem_name().empty()); - EXPECT_GT(data.bucket_info(0).atom(0).subsystem_sleep_state().time_millis(), 0); + auto bucketInfo = data.bucket_info(0); + EXPECT_EQ(1, bucketInfo.atom_size()); + EXPECT_EQ(1, bucketInfo.elapsed_timestamp_nanos_size()); + EXPECT_EQ(activationNs, bucketInfo.elapsed_timestamp_nanos(0)); + EXPECT_EQ(0, bucketInfo.wall_clock_timestamp_nanos_size()); + EXPECT_EQ(baseTimeNs + 3 * bucketSizeNs, bucketInfo.start_bucket_elapsed_nanos()); + EXPECT_EQ(baseTimeNs + 4 * bucketSizeNs, bucketInfo.end_bucket_elapsed_nanos()); + EXPECT_TRUE(bucketInfo.atom(0).subsystem_sleep_state().subsystem_name().empty()); + EXPECT_GT(bucketInfo.atom(0).subsystem_sleep_state().time_millis(), 0); - EXPECT_EQ(1, data.bucket_info(1).atom_size()); - EXPECT_EQ(1, data.bucket_info(1).elapsed_timestamp_nanos_size()); - EXPECT_EQ(baseTimeNs + 5 * bucketSizeNs + 2, data.bucket_info(1).elapsed_timestamp_nanos(0)); - EXPECT_EQ(0, data.bucket_info(1).wall_clock_timestamp_nanos_size()); + bucketInfo = data.bucket_info(1); + EXPECT_EQ(1, bucketInfo.atom_size()); + EXPECT_EQ(1, bucketInfo.elapsed_timestamp_nanos_size()); + EXPECT_EQ(baseTimeNs + 4 * bucketSizeNs + 1, bucketInfo.elapsed_timestamp_nanos(0)); + EXPECT_EQ(0, bucketInfo.wall_clock_timestamp_nanos_size()); + EXPECT_EQ(baseTimeNs + 4 * bucketSizeNs, bucketInfo.start_bucket_elapsed_nanos()); + EXPECT_EQ(baseTimeNs + 5 * bucketSizeNs, bucketInfo.end_bucket_elapsed_nanos()); + EXPECT_TRUE(bucketInfo.atom(0).subsystem_sleep_state().subsystem_name().empty()); + EXPECT_GT(bucketInfo.atom(0).subsystem_sleep_state().time_millis(), 0); + + bucketInfo = data.bucket_info(2); + EXPECT_EQ(1, bucketInfo.atom_size()); + EXPECT_EQ(1, bucketInfo.elapsed_timestamp_nanos_size()); + EXPECT_EQ(baseTimeNs + 5 * bucketSizeNs + 2, bucketInfo.elapsed_timestamp_nanos(0)); + EXPECT_EQ(0, bucketInfo.wall_clock_timestamp_nanos_size()); EXPECT_EQ(MillisToNano(NanoToMillis(baseTimeNs + 5 * bucketSizeNs)), - data.bucket_info(1).start_bucket_elapsed_nanos()); + bucketInfo.start_bucket_elapsed_nanos()); EXPECT_EQ(MillisToNano(NanoToMillis(activationNs + ttlNs + 1)), - data.bucket_info(1).end_bucket_elapsed_nanos()); - EXPECT_TRUE(data.bucket_info(1).atom(0).subsystem_sleep_state().subsystem_name().empty()); - EXPECT_GT(data.bucket_info(1).atom(0).subsystem_sleep_state().time_millis(), 0); + bucketInfo.end_bucket_elapsed_nanos()); + EXPECT_TRUE(bucketInfo.atom(0).subsystem_sleep_state().subsystem_name().empty()); + EXPECT_GT(bucketInfo.atom(0).subsystem_sleep_state().time_millis(), 0); } TEST(GaugeMetricE2eTest, TestRandomSamplePulledEventsNoCondition) { diff --git a/cmds/statsd/tests/e2e/ValueMetric_pull_e2e_test.cpp b/cmds/statsd/tests/e2e/ValueMetric_pull_e2e_test.cpp index ff6af38bd351a..fb878dc7efed1 100644 --- a/cmds/statsd/tests/e2e/ValueMetric_pull_e2e_test.cpp +++ b/cmds/statsd/tests/e2e/ValueMetric_pull_e2e_test.cpp @@ -306,18 +306,20 @@ TEST(ValueMetricE2eTest, TestPulledEvents_WithActivation) { EXPECT_EQ(baseTimeNs + startBucketNum * bucketSizeNs + bucketSizeNs, expectedPullTimeNs); // Pulling alarm arrives on time and reset the sequential pulling alarm. - processor->informPullAlarmFired(expectedPullTimeNs + 1); + processor->informPullAlarmFired(expectedPullTimeNs + 1); // 15 mins + 1 ns. EXPECT_EQ(baseTimeNs + startBucketNum * bucketSizeNs + 2 * bucketSizeNs, expectedPullTimeNs); + EXPECT_FALSE(processor->mMetricsManagers.begin()->second->mAllMetricProducers[0]->isActive()); + // Activate the metric. A pull occurs here const int64_t activationNs = configAddedTimeNs + bucketSizeNs + (2 * 1000 * 1000); // 2 millis. auto batterySaverOnEvent = CreateBatterySaverOnEvent(activationNs); - processor->OnLogEvent(batterySaverOnEvent.get()); + processor->OnLogEvent(batterySaverOnEvent.get()); // 15 mins + 2 ms. EXPECT_TRUE(processor->mMetricsManagers.begin()->second->mAllMetricProducers[0]->isActive()); - processor->informPullAlarmFired(expectedPullTimeNs + 1); + processor->informPullAlarmFired(expectedPullTimeNs + 1); // 20 mins + 1 ns. EXPECT_EQ(baseTimeNs + startBucketNum * bucketSizeNs + 3 * bucketSizeNs, expectedPullTimeNs); - processor->informPullAlarmFired(expectedPullTimeNs + 1); + processor->informPullAlarmFired(expectedPullTimeNs + 2); // 25 mins + 2 ns. EXPECT_EQ(baseTimeNs + startBucketNum * bucketSizeNs + 4 * bucketSizeNs, expectedPullTimeNs); // Create random event to deactivate metric. @@ -325,10 +327,11 @@ TEST(ValueMetricE2eTest, TestPulledEvents_WithActivation) { processor->OnLogEvent(deactivationEvent.get()); EXPECT_FALSE(processor->mMetricsManagers.begin()->second->mAllMetricProducers[0]->isActive()); - processor->informPullAlarmFired(expectedPullTimeNs + 1); + processor->informPullAlarmFired(expectedPullTimeNs + 3); EXPECT_EQ(baseTimeNs + startBucketNum * bucketSizeNs + 5 * bucketSizeNs, expectedPullTimeNs); - processor->informPullAlarmFired(expectedPullTimeNs + 1); + processor->informPullAlarmFired(expectedPullTimeNs + 4); + EXPECT_EQ(baseTimeNs + startBucketNum * bucketSizeNs + 6 * bucketSizeNs, expectedPullTimeNs); ConfigMetricsReportList reports; vector buffer; @@ -352,12 +355,18 @@ TEST(ValueMetricE2eTest, TestPulledEvents_WithActivation) { EXPECT_EQ(1 /* subsystem name field */, data.dimensions_in_what().value_tuple().dimensions_value(0).field()); EXPECT_FALSE(data.dimensions_in_what().value_tuple().dimensions_value(0).value_str().empty()); - // We have 1 full bucket, the two surrounding the activation are dropped. - EXPECT_EQ(1, data.bucket_info_size()); + // We have 2 full buckets, the two surrounding the activation are dropped. + EXPECT_EQ(2, data.bucket_info_size()); - EXPECT_EQ(baseTimeNs + 4 * bucketSizeNs, data.bucket_info(0).start_bucket_elapsed_nanos()); - EXPECT_EQ(baseTimeNs + 5 * bucketSizeNs, data.bucket_info(0).end_bucket_elapsed_nanos()); - EXPECT_EQ(1, data.bucket_info(0).values_size()); + auto bucketInfo = data.bucket_info(0); + EXPECT_EQ(baseTimeNs + 3 * bucketSizeNs, bucketInfo.start_bucket_elapsed_nanos()); + EXPECT_EQ(baseTimeNs + 4 * bucketSizeNs, bucketInfo.end_bucket_elapsed_nanos()); + EXPECT_EQ(1, bucketInfo.values_size()); + + bucketInfo = data.bucket_info(1); + EXPECT_EQ(baseTimeNs + 4 * bucketSizeNs, bucketInfo.start_bucket_elapsed_nanos()); + EXPECT_EQ(baseTimeNs + 5 * bucketSizeNs, bucketInfo.end_bucket_elapsed_nanos()); + EXPECT_EQ(1, bucketInfo.values_size()); } #else