diff --git a/cmds/statsd/.clang-format b/cmds/statsd/.clang-format index 3d64beeecda62..cead3a0794352 100644 --- a/cmds/statsd/.clang-format +++ b/cmds/statsd/.clang-format @@ -12,3 +12,6 @@ IndentWidth: 4 PointerAlignment: Left TabWidth: 4 AccessModifierOffset: -4 +IncludeCategories: + - Regex: '^"Log\.h"' + Priority: -1 diff --git a/cmds/statsd/Android.mk b/cmds/statsd/Android.mk index 1c88a249f75af..58ba42fb35196 100644 --- a/cmds/statsd/Android.mk +++ b/cmds/statsd/Android.mk @@ -42,6 +42,8 @@ statsd_common_src := \ src/metrics/EventMetricProducer.cpp \ src/metrics/CountMetricProducer.cpp \ src/metrics/DurationMetricProducer.cpp \ + src/metrics/duration_helper/OringDurationTracker.cpp \ + src/metrics/duration_helper/MaxDurationTracker.cpp \ src/metrics/MetricsManager.cpp \ src/metrics/metrics_manager_util.cpp \ src/packages/UidMap.cpp \ @@ -143,7 +145,9 @@ LOCAL_SRC_FILES := \ tests/LogEntryMatcher_test.cpp \ tests/LogReader_test.cpp \ tests/MetricsManager_test.cpp \ - tests/UidMap_test.cpp + tests/UidMap_test.cpp \ + tests/OringDurationTracker_test.cpp \ + tests/MaxDurationTracker_test.cpp LOCAL_STATIC_LIBRARIES := \ diff --git a/cmds/statsd/src/StatsService.cpp b/cmds/statsd/src/StatsService.cpp index 604753ef54a00..a856a271df4f1 100644 --- a/cmds/statsd/src/StatsService.cpp +++ b/cmds/statsd/src/StatsService.cpp @@ -231,6 +231,14 @@ void StatsService::print_cmd_help(FILE* out) { fprintf(out, " parameter on eng builds. If UID is omitted the calling\n"); fprintf(out, " uid is used.\n"); fprintf(out, " NAME The per-uid name to use\n"); + fprintf(out, "\n"); + fprintf(out, "\n"); + fprintf(out, "usage: adb shell cmd stats dump-report [UID] NAME\n"); + fprintf(out, " Dump all metric data for a configuration.\n"); + fprintf(out, " UID The uid of the configuration. It is only possible to pass\n"); + fprintf(out, " the UID parameter on eng builds. If UID is omitted the\n"); + fprintf(out, " calling uid is used.\n"); + fprintf(out, " NAME The name of the configuration\n"); } status_t StatsService::cmd_config(FILE* in, FILE* out, FILE* err, Vector& args) { @@ -312,7 +320,7 @@ status_t StatsService::cmd_dump_report(FILE* out, FILE* err, const VectorgetCallingUid(); // TODO: What if this isn't a binder call? Should we fail? - name.assign(args[2].c_str(), args[2].size()); + name.assign(args[1].c_str(), args[1].size()); good = true; } else if (argCount == 3) { // If it's a userdebug or eng build, then the shell user can diff --git a/cmds/statsd/src/condition/CombinationConditionTracker.cpp b/cmds/statsd/src/condition/CombinationConditionTracker.cpp index f56c15a370869..953bcb3d67a4f 100644 --- a/cmds/statsd/src/condition/CombinationConditionTracker.cpp +++ b/cmds/statsd/src/condition/CombinationConditionTracker.cpp @@ -16,7 +16,6 @@ #define DEBUG true // STOPSHIP if true #include "Log.h" - #include "CombinationConditionTracker.h" #include diff --git a/cmds/statsd/src/condition/CombinationConditionTracker.h b/cmds/statsd/src/condition/CombinationConditionTracker.h index fc88a88f4d63c..dbdb3b7d31d77 100644 --- a/cmds/statsd/src/condition/CombinationConditionTracker.h +++ b/cmds/statsd/src/condition/CombinationConditionTracker.h @@ -46,8 +46,6 @@ public: const std::vector>& allConditions, std::vector& conditionCache) override; - void addDimensions(const std::vector& keyMatchers) override{}; - private: LogicalOperation mLogicalOperation; // Store index of the children Conditions. diff --git a/cmds/statsd/src/condition/ConditionTracker.h b/cmds/statsd/src/condition/ConditionTracker.h index 055b4784f72c4..bb5ddeb4ec2b3 100644 --- a/cmds/statsd/src/condition/ConditionTracker.h +++ b/cmds/statsd/src/condition/ConditionTracker.h @@ -16,8 +16,6 @@ #pragma once -#include "Log.h" - #include "condition/condition_util.h" #include "frameworks/base/cmds/statsd/src/statsd_config.pb.h" #include "matchers/LogMatchingTracker.h" @@ -103,8 +101,6 @@ public: mSliced = mSliced | sliced; } - virtual void addDimensions(const std::vector& keyMatchers) = 0; - protected: // We don't really need the string name, but having a name here makes log messages // easy to debug. diff --git a/cmds/statsd/src/condition/ConditionWizard.h b/cmds/statsd/src/condition/ConditionWizard.h index 4889b64de2ed5..1a01afa7fbdcf 100644 --- a/cmds/statsd/src/condition/ConditionWizard.h +++ b/cmds/statsd/src/condition/ConditionWizard.h @@ -27,19 +27,23 @@ namespace statsd { // Held by MetricProducer, to query a condition state with input defined in EventConditionLink. class ConditionWizard : public virtual android::RefBase { public: + ConditionWizard(){}; // for testing ConditionWizard(std::vector>& conditionTrackers) : mAllConditions(conditionTrackers){}; + virtual ~ConditionWizard(){}; + // Query condition state, for a ConditionTracker at [conditionIndex], with [conditionParameters] // [conditionParameters] mapping from condition name to the HashableDimensionKey to query the // condition. // The ConditionTracker at [conditionIndex] can be a CombinationConditionTracker. In this case, // the conditionParameters contains the parameters for it's children SimpleConditionTrackers. - ConditionState query(const int conditionIndex, - const std::map& conditionParameters); + virtual ConditionState query( + const int conditionIndex, + const std::map& conditionParameters); private: - std::vector>& mAllConditions; + std::vector> mAllConditions; }; } // namespace statsd diff --git a/cmds/statsd/src/condition/SimpleConditionTracker.cpp b/cmds/statsd/src/condition/SimpleConditionTracker.cpp index aff476814c943..b691faea205d6 100644 --- a/cmds/statsd/src/condition/SimpleConditionTracker.cpp +++ b/cmds/statsd/src/condition/SimpleConditionTracker.cpp @@ -74,6 +74,13 @@ SimpleConditionTracker::SimpleConditionTracker( mStopAllLogMatcherIndex = -1; } + mDimension.insert(mDimension.begin(), simpleCondition.dimension().begin(), + simpleCondition.dimension().end()); + + if (mDimension.size() > 0) { + mSliced = true; + } + mInitialized = true; } @@ -98,12 +105,6 @@ void print(unordered_map& conditions, cons } } -void SimpleConditionTracker::addDimensions(const std::vector& keyMatchers) { - VLOG("Added dimensions size %lu", (unsigned long)keyMatchers.size()); - mDimensionsList.push_back(keyMatchers); - mSliced = true; -} - bool SimpleConditionTracker::evaluateCondition(const LogEvent& event, const vector& eventMatcherValues, const vector>& mAllConditions, @@ -157,18 +158,15 @@ bool SimpleConditionTracker::evaluateCondition(const LogEvent& event, // TODO: handle stop all; all dimension should be cleared. } - if (mDimensionsList.size() > 0) { - for (size_t i = 0; i < mDimensionsList.size(); i++) { - const auto& dim = mDimensionsList[i]; - vector key = getDimensionKey(event, dim); - HashableDimensionKey hashableKey = getHashableKey(key); - if (mSlicedConditionState.find(hashableKey) == mSlicedConditionState.end() || - mSlicedConditionState[hashableKey] != newCondition) { - slicedChanged = true; - mSlicedConditionState[hashableKey] = newCondition; - } - VLOG("key: %s %d", hashableKey.c_str(), newCondition); + + if (mDimension.size() > 0) { + HashableDimensionKey hashableKey = getHashableKey(getDimensionKey(event, mDimension)); + if (mSlicedConditionState.find(hashableKey) == mSlicedConditionState.end() || + mSlicedConditionState[hashableKey] != newCondition) { + slicedChanged = true; + mSlicedConditionState[hashableKey] = newCondition; } + VLOG("key: %s %d", hashableKey.c_str(), newCondition); // dump all dimensions for debugging if (DEBUG) { print(mSlicedConditionState, mName); diff --git a/cmds/statsd/src/condition/SimpleConditionTracker.h b/cmds/statsd/src/condition/SimpleConditionTracker.h index 1f357f059aabc..b72157baf1e25 100644 --- a/cmds/statsd/src/condition/SimpleConditionTracker.h +++ b/cmds/statsd/src/condition/SimpleConditionTracker.h @@ -27,8 +27,6 @@ namespace statsd { class SimpleConditionTracker : public virtual ConditionTracker { public: - // dimensions is a vector of vector because for one single condition, different metrics may be - // interested in slicing in different ways. one vector defines one type of slicing. SimpleConditionTracker(const std::string& name, const int index, const SimpleCondition& simpleCondition, const std::unordered_map& trackerNameIndexMap); @@ -51,8 +49,6 @@ public: const std::vector>& allConditions, std::vector& conditionCache) override; - void addDimensions(const std::vector& keyMatchers) override; - private: // The index of the LogEventMatcher which defines the start. int mStartLogMatcherIndex; @@ -66,8 +62,11 @@ private: // The index of the LogEventMatcher which defines the stop all. int mStopAllLogMatcherIndex; - // Different metrics may subscribe to different types of slicings. So it's a vector of vector. - std::vector> mDimensionsList; + // The dimension defines at the atom level, how start and stop should match. + // e.g., APP_IN_FOREGROUND, the dimension should be the uid field. Each "start" and + // "stop" tells you the state change of a particular app. Without this dimension, this + // condition does not make sense. + std::vector mDimension; // Keep the map from the internal HashableDimensionKey to std::vector // that StatsLogReport wants. diff --git a/cmds/statsd/src/config/ConfigManager.cpp b/cmds/statsd/src/config/ConfigManager.cpp index c16971aeb8a85..e3ccb0635bab4 100644 --- a/cmds/statsd/src/config/ConfigManager.cpp +++ b/cmds/statsd/src/config/ConfigManager.cpp @@ -118,9 +118,10 @@ static StatsdConfig build_fake_config() { StatsdConfig config; config.set_config_id(12345L); - int WAKE_LOCK_TAG_ID = 11; + int WAKE_LOCK_TAG_ID = 1111; // put a fake id here to make testing easier. int WAKE_LOCK_UID_KEY_ID = 1; - int WAKE_LOCK_STATE_KEY = 3; + int WAKE_LOCK_NAME_KEY = 3; + int WAKE_LOCK_STATE_KEY = 4; int WAKE_LOCK_ACQUIRE_VALUE = 1; int WAKE_LOCK_RELEASE_VALUE = 0; @@ -180,24 +181,56 @@ static StatsdConfig build_fake_config() { link->add_key_in_main()->set_key(WAKE_LOCK_UID_KEY_ID); link->add_key_in_condition()->set_key(APP_USAGE_UID_KEY_ID); - // Duration of an app holding wl, while screen on and app in background + // Duration of an app holding any wl, while screen on and app in background, slice by uid DurationMetric* durationMetric = config.add_duration_metric(); durationMetric->set_metric_id(5); - durationMetric->set_start("APP_GET_WL"); - durationMetric->set_stop("APP_RELEASE_WL"); durationMetric->mutable_bucket()->set_bucket_size_millis(30 * 1000L); durationMetric->set_type(DurationMetric_AggregationType_DURATION_SUM); keyMatcher = durationMetric->add_dimension(); keyMatcher->set_key(WAKE_LOCK_UID_KEY_ID); + durationMetric->set_what("WL_STATE_PER_APP_PER_NAME"); durationMetric->set_predicate("APP_IS_BACKGROUND_AND_SCREEN_ON"); link = durationMetric->add_links(); link->set_condition("APP_IS_BACKGROUND"); link->add_key_in_main()->set_key(WAKE_LOCK_UID_KEY_ID); link->add_key_in_condition()->set_key(APP_USAGE_UID_KEY_ID); + // max Duration of an app holding any wl, while screen on and app in background, slice by uid + durationMetric = config.add_duration_metric(); + durationMetric->set_metric_id(6); + durationMetric->mutable_bucket()->set_bucket_size_millis(30 * 1000L); + durationMetric->set_type(DurationMetric_AggregationType_DURATION_MAX_SPARSE); + keyMatcher = durationMetric->add_dimension(); + keyMatcher->set_key(WAKE_LOCK_UID_KEY_ID); + durationMetric->set_what("WL_STATE_PER_APP_PER_NAME"); + durationMetric->set_predicate("APP_IS_BACKGROUND_AND_SCREEN_ON"); + link = durationMetric->add_links(); + link->set_condition("APP_IS_BACKGROUND"); + link->add_key_in_main()->set_key(WAKE_LOCK_UID_KEY_ID); + link->add_key_in_condition()->set_key(APP_USAGE_UID_KEY_ID); + + // Duration of an app holding any wl, while screen on and app in background + durationMetric = config.add_duration_metric(); + durationMetric->set_metric_id(7); + durationMetric->mutable_bucket()->set_bucket_size_millis(30 * 1000L); + durationMetric->set_type(DurationMetric_AggregationType_DURATION_MAX_SPARSE); + durationMetric->set_what("WL_STATE_PER_APP_PER_NAME"); + durationMetric->set_predicate("APP_IS_BACKGROUND_AND_SCREEN_ON"); + link = durationMetric->add_links(); + link->set_condition("APP_IS_BACKGROUND"); + link->add_key_in_main()->set_key(WAKE_LOCK_UID_KEY_ID); + link->add_key_in_condition()->set_key(APP_USAGE_UID_KEY_ID); + + // Duration of screen on time. + durationMetric = config.add_duration_metric(); + durationMetric->set_metric_id(8); + durationMetric->mutable_bucket()->set_bucket_size_millis(30 * 1000L); + durationMetric->set_type(DurationMetric_AggregationType_DURATION_SUM); + durationMetric->set_what("SCREEN_IS_ON"); + // Add an EventMetric to log process state change events. EventMetric* eventMetric = config.add_event_metric(); - eventMetric->set_metric_id(6); + eventMetric->set_metric_id(9); eventMetric->set_what("SCREEN_TURNED_ON"); // Event matchers............ @@ -272,6 +305,8 @@ static StatsdConfig build_fake_config() { simpleCondition = condition->mutable_simple_condition(); simpleCondition->set_start("APP_GOES_BACKGROUND"); simpleCondition->set_stop("APP_GOES_FOREGROUND"); + KeyMatcher* condition_dimension1 = simpleCondition->add_dimension(); + condition_dimension1->set_key(APP_USAGE_UID_KEY_ID); condition = config.add_condition(); condition->set_name("APP_IS_BACKGROUND_AND_SCREEN_ON"); @@ -280,6 +315,16 @@ static StatsdConfig build_fake_config() { combination_condition->add_condition("APP_IS_BACKGROUND"); combination_condition->add_condition("SCREEN_IS_ON"); + condition = config.add_condition(); + condition->set_name("WL_STATE_PER_APP_PER_NAME"); + simpleCondition = condition->mutable_simple_condition(); + simpleCondition->set_start("APP_GET_WL"); + simpleCondition->set_stop("APP_RELEASE_WL"); + KeyMatcher* condition_dimension = simpleCondition->add_dimension(); + condition_dimension->set_key(WAKE_LOCK_UID_KEY_ID); + condition_dimension = simpleCondition->add_dimension(); + condition_dimension->set_key(WAKE_LOCK_NAME_KEY); + return config; } diff --git a/cmds/statsd/src/metrics/CountMetricProducer.cpp b/cmds/statsd/src/metrics/CountMetricProducer.cpp index 69f336f420fcc..10816f6206aa8 100644 --- a/cmds/statsd/src/metrics/CountMetricProducer.cpp +++ b/cmds/statsd/src/metrics/CountMetricProducer.cpp @@ -21,7 +21,6 @@ #include "CountMetricProducer.h" #include "stats_util.h" -#include #include #include @@ -94,7 +93,7 @@ static void addSlicedCounterToReport(StatsLogReport_CountMetricDataWrapper& wrap } } -void CountMetricProducer::onSlicedConditionMayChange() { +void CountMetricProducer::onSlicedConditionMayChange(const uint64_t eventTime) { VLOG("Metric %lld onSlicedConditionMayChange", mMetric.metric_id()); } @@ -128,7 +127,7 @@ StatsLogReport CountMetricProducer::onDumpReport() { // TODO: Clear mPastBuckets, mDimensionKeyMap once the report is dumped. } -void CountMetricProducer::onConditionChanged(const bool conditionMet) { +void CountMetricProducer::onConditionChanged(const bool conditionMet, const uint64_t eventTime) { VLOG("Metric %lld onConditionChanged", mMetric.metric_id()); mCondition = conditionMet; } diff --git a/cmds/statsd/src/metrics/CountMetricProducer.h b/cmds/statsd/src/metrics/CountMetricProducer.h index 8ed2234ceed45..5d1889a9b18f8 100644 --- a/cmds/statsd/src/metrics/CountMetricProducer.h +++ b/cmds/statsd/src/metrics/CountMetricProducer.h @@ -41,13 +41,13 @@ public: virtual ~CountMetricProducer(); - void onConditionChanged(const bool conditionMet) override; + void onConditionChanged(const bool conditionMet, const uint64_t eventTime) override; void finish() override; StatsLogReport onDumpReport() override; - void onSlicedConditionMayChange() override; + void onSlicedConditionMayChange(const uint64_t eventTime) override; size_t byteSize() override; diff --git a/cmds/statsd/src/metrics/DurationMetricProducer.cpp b/cmds/statsd/src/metrics/DurationMetricProducer.cpp index a590bc8569666..dfed27576165d 100644 --- a/cmds/statsd/src/metrics/DurationMetricProducer.cpp +++ b/cmds/statsd/src/metrics/DurationMetricProducer.cpp @@ -15,11 +15,11 @@ */ #define DEBUG true -#include "DurationMetricProducer.h" + #include "Log.h" +#include "DurationMetricProducer.h" #include "stats_util.h" -#include #include #include @@ -34,13 +34,15 @@ namespace statsd { DurationMetricProducer::DurationMetricProducer(const DurationMetric& metric, const int conditionIndex, const size_t startIndex, const size_t stopIndex, const size_t stopAllIndex, - const sp& wizard) + const sp& wizard, + const vector& internalDimension) // TODO: Pass in the start time from MetricsManager, instead of calling time() here. : MetricProducer(time(nullptr) * NANO_SECONDS_IN_A_SECOND, conditionIndex, wizard), mMetric(metric), mStartIndex(startIndex), mStopIndex(stopIndex), - mStopAllIndex(stopAllIndex) { + mStopAllIndex(stopAllIndex), + mInternalDimension(internalDimension) { // TODO: The following boiler plate code appears in all MetricProducers, but we can't abstract // them in the base class, because the proto generated CountMetric, and DurationMetric are // not related. Maybe we should add a template in the future?? @@ -67,34 +69,43 @@ DurationMetricProducer::~DurationMetricProducer() { VLOG("~DurationMetric() called"); } +unique_ptr DurationMetricProducer::createDurationTracker( + vector& bucket) { + switch (mMetric.type()) { + case DurationMetric_AggregationType_DURATION_SUM: + return make_unique(mWizard, mConditionTrackerIndex, + mCurrentBucketStartTimeNs, mBucketSizeNs, + bucket); + case DurationMetric_AggregationType_DURATION_MAX_SPARSE: + return make_unique(mWizard, mConditionTrackerIndex, + mCurrentBucketStartTimeNs, mBucketSizeNs, + bucket); + } +} + void DurationMetricProducer::finish() { // TODO: write the StatsLogReport to dropbox using // DropboxWriter. } -void DurationMetricProducer::onSlicedConditionMayChange() { +void DurationMetricProducer::onSlicedConditionMayChange(const uint64_t eventTime) { VLOG("Metric %lld onSlicedConditionMayChange", mMetric.metric_id()); // Now for each of the on-going event, check if the condition has changed for them. + flushIfNeeded(eventTime); for (auto& pair : mCurrentSlicedDuration) { - VLOG("Metric %lld current %s state: %d", mMetric.metric_id(), pair.first.c_str(), - pair.second.state); - if (pair.second.state == kStopped) { - continue; - } - bool conditionMet = mWizard->query(mConditionTrackerIndex, pair.second.conditionKeys) == - ConditionState::kTrue; - VLOG("key: %s, condition: %d", pair.first.c_str(), conditionMet); - noteConditionChanged(pair.first, conditionMet, time(nullptr) * 1000000000); + pair.second->onSlicedConditionMayChange(eventTime); } } -void DurationMetricProducer::onConditionChanged(const bool conditionMet) { +void DurationMetricProducer::onConditionChanged(const bool conditionMet, const uint64_t eventTime) { VLOG("Metric %lld onConditionChanged", mMetric.metric_id()); mCondition = conditionMet; // TODO: need to populate the condition change time from the event which triggers the condition // change, instead of using current time. + + flushIfNeeded(eventTime); for (auto& pair : mCurrentSlicedDuration) { - noteConditionChanged(pair.first, conditionMet, time(nullptr) * 1000000000); + pair.second->onConditionChanged(conditionMet, eventTime); } } @@ -107,7 +118,7 @@ static void addDurationBucketsToReport(StatsLogReport_DurationMetricDataWrapper& } for (const auto& bucket : buckets) { data->add_bucket_info()->CopyFrom(bucket); - VLOG("\t bucket [%lld - %lld] count: %lld", bucket.start_bucket_nanos(), + VLOG("\t bucket [%lld - %lld] duration(ns): %lld", bucket.start_bucket_nanos(), bucket.end_bucket_nanos(), bucket.duration_nanos()); } } @@ -120,7 +131,7 @@ StatsLogReport DurationMetricProducer::onDumpReport() { // Dump current bucket if it's stale. // If current bucket is still on-going, don't force dump current bucket. // In finish(), We can force dump current bucket. - flushDurationIfNeeded(time(nullptr) * NANO_SECONDS_IN_A_SECOND); + flushIfNeeded(time(nullptr) * NANO_SECONDS_IN_A_SECOND); report.set_end_report_nanos(mCurrentBucketStartTimeNs); StatsLogReport_DurationMetricDataWrapper* wrapper = report.mutable_duration_metrics(); @@ -137,216 +148,50 @@ StatsLogReport DurationMetricProducer::onDumpReport() { return report; }; -void DurationMetricProducer::onMatchedLogEventInternal( - const size_t matcherIndex, const HashableDimensionKey& eventKey, - const map& conditionKeys, bool condition, - const LogEvent& event) { - flushDurationIfNeeded(event.GetTimestampNs()); - - if (matcherIndex == mStopAllIndex) { - noteStopAll(event.GetTimestampNs()); - return; - } - - if (mCurrentSlicedDuration.find(eventKey) == mCurrentSlicedDuration.end() && mConditionSliced) { - // add the durationInfo for the current bucket. - auto& durationInfo = mCurrentSlicedDuration[eventKey]; - durationInfo.conditionKeys = conditionKeys; - } - - if (matcherIndex == mStartIndex) { - VLOG("Metric %lld Key: %s Start, Condition %d", mMetric.metric_id(), eventKey.c_str(), - condition); - noteStart(eventKey, condition, event.GetTimestampNs()); - } else if (matcherIndex == mStopIndex) { - VLOG("Metric %lld Key: %s Stop, Condition %d", mMetric.metric_id(), eventKey.c_str(), - condition); - noteStop(eventKey, event.GetTimestampNs()); - } -} - -void DurationMetricProducer::noteConditionChanged(const HashableDimensionKey& key, - const bool conditionMet, - const uint64_t eventTime) { - flushDurationIfNeeded(eventTime); - - auto it = mCurrentSlicedDuration.find(key); - if (it == mCurrentSlicedDuration.end()) { - return; - } - - switch (it->second.state) { - case kStarted: - // if condition becomes false, kStarted -> kPaused. Record the current duration. - if (!conditionMet) { - it->second.state = DurationState::kPaused; - it->second.lastDuration = - updateDuration(it->second.lastDuration, - eventTime - it->second.lastStartTime, mMetric.type()); - VLOG("Metric %lld Key: %s Paused because condition is false ", mMetric.metric_id(), - key.c_str()); - } - break; - case kStopped: - // nothing to do if it's stopped. - break; - case kPaused: - // if condition becomes true, kPaused -> kStarted. and the start time is the condition - // change time. - if (conditionMet) { - it->second.state = DurationState::kStarted; - it->second.lastStartTime = eventTime; - VLOG("Metric %lld Key: %s Paused->Started", mMetric.metric_id(), key.c_str()); - } - break; - } -} - -void DurationMetricProducer::noteStart(const HashableDimensionKey& key, const bool conditionMet, - const uint64_t eventTime) { - // this will add an empty bucket for this key if it didn't exist before. - DurationInfo& duration = mCurrentSlicedDuration[key]; - - switch (duration.state) { - case kStarted: - // It's safe to do nothing here. even if condition is not true, it means we are about - // to receive the condition change event. - break; - case kPaused: - // Safe to do nothing here. kPaused is waiting for the condition change. - break; - case kStopped: - if (!conditionMet) { - // event started, but we need to wait for the condition to become true. - duration.state = DurationState::kPaused; - break; - } - duration.state = DurationState::kStarted; - duration.lastStartTime = eventTime; - break; - } -} - -void DurationMetricProducer::noteStop(const HashableDimensionKey& key, const uint64_t eventTime) { - if (mCurrentSlicedDuration.find(key) == mCurrentSlicedDuration.end()) { - // we didn't see a start event before. do nothing. - return; - } - DurationInfo& duration = mCurrentSlicedDuration[key]; - - switch (duration.state) { - case DurationState::kStopped: - // already stopped, do nothing. - break; - case DurationState::kStarted: { - duration.state = DurationState::kStopped; - int64_t durationTime = eventTime - duration.lastStartTime; - VLOG("Metric %lld, key %s, Stop %lld %lld %lld", mMetric.metric_id(), key.c_str(), - (long long)duration.lastStartTime, (long long)eventTime, (long long)durationTime); - duration.lastDuration = - updateDuration(duration.lastDuration, durationTime, mMetric.type()); - VLOG(" record duration: %lld ", (long long)duration.lastDuration); - break; - } - case DurationState::kPaused: { - duration.state = DurationState::kStopped; - break; - } - } -} - -int64_t DurationMetricProducer::updateDuration(const int64_t lastDuration, - const int64_t durationTime, - const DurationMetric_AggregationType type) { - int64_t result = lastDuration; - switch (type) { - case DurationMetric_AggregationType_DURATION_SUM: - result += durationTime; - break; - case DurationMetric_AggregationType_DURATION_MAX_SPARSE: - if (lastDuration < durationTime) { - result = durationTime; - } - break; - case DurationMetric_AggregationType_DURATION_MIN_SPARSE: - if (lastDuration > durationTime) { - result = durationTime; - } - break; - } - return result; -} - -void DurationMetricProducer::noteStopAll(const uint64_t eventTime) { - for (auto& duration : mCurrentSlicedDuration) { - noteStop(duration.first, eventTime); - } -} - -// When a new matched event comes in, we check if event falls into the current -// bucket. If not, flush the old counter to past buckets and initialize the current buckt. -void DurationMetricProducer::flushDurationIfNeeded(const uint64_t eventTime) { +void DurationMetricProducer::flushIfNeeded(uint64_t eventTime) { if (mCurrentBucketStartTimeNs + mBucketSizeNs > eventTime) { return; } - // adjust the bucket start time - int numBucketsForward = (eventTime - mCurrentBucketStartTimeNs) / mBucketSizeNs; - - DurationBucketInfo info; - uint64_t endTime = mCurrentBucketStartTimeNs + mBucketSizeNs; - info.set_start_bucket_nanos(mCurrentBucketStartTimeNs); - info.set_end_bucket_nanos(endTime); - - uint64_t oldBucketStartTimeNs = mCurrentBucketStartTimeNs; - mCurrentBucketStartTimeNs += (numBucketsForward)*mBucketSizeNs; - VLOG("Metric %lld: new bucket start time: %lld", mMetric.metric_id(), - (long long)mCurrentBucketStartTimeNs); - + VLOG("flushing..........."); for (auto it = mCurrentSlicedDuration.begin(); it != mCurrentSlicedDuration.end(); ++it) { - int64_t finalDuration = it->second.lastDuration; - if (it->second.state == kStarted) { - // the event is still on-going, duration needs to be updated. - int64_t durationTime = endTime - it->second.lastStartTime; - finalDuration = updateDuration(it->second.lastDuration, durationTime, mMetric.type()); - } - - VLOG(" final duration for last bucket: %lld", (long long)finalDuration); - - // Don't record empty bucket. - if (finalDuration != 0) { - info.set_duration_nanos(finalDuration); - // it will auto create new vector of CountbucketInfo if the key is not found. - auto& bucketList = mPastBuckets[it->first]; - bucketList.push_back(info); - } - - // if the event is still on-going, add the buckets between previous bucket and now. Because - // the event has been going on across all the buckets in between. - // |prev_bucket|...|..|...|now_bucket| - if (it->second.state == kStarted) { - for (int i = 1; i < numBucketsForward; i++) { - DurationBucketInfo info; - info.set_start_bucket_nanos(oldBucketStartTimeNs + mBucketSizeNs * i); - info.set_end_bucket_nanos(endTime + mBucketSizeNs * i); - info.set_duration_nanos(mBucketSizeNs); - auto& bucketList = mPastBuckets[it->first]; - bucketList.push_back(info); - VLOG(" add filling bucket with duration %lld", (long long)mBucketSizeNs); - } - } - - if (it->second.state == DurationState::kStopped) { - // No need to keep buckets for events that were stopped before. If the event starts - // again, we will add it back. + if (it->second->flushIfNeeded(eventTime)) { + VLOG("erase bucket for key %s", it->first.c_str()); mCurrentSlicedDuration.erase(it); - } else { - // for kPaused, and kStarted event, we will keep the buckets, and reset the start time - // and duration. - it->second.lastStartTime = mCurrentBucketStartTimeNs; - it->second.lastDuration = 0; } } + + int numBucketsForward = (eventTime - mCurrentBucketStartTimeNs) / mBucketSizeNs; + mCurrentBucketStartTimeNs += numBucketsForward * mBucketSizeNs; +} + +void DurationMetricProducer::onMatchedLogEventInternal( + const size_t matcherIndex, const HashableDimensionKey& eventKey, + const map& conditionKeys, bool condition, + const LogEvent& event) { + flushIfNeeded(event.GetTimestampNs()); + + if (matcherIndex == mStopAllIndex) { + for (auto& pair : mCurrentSlicedDuration) { + pair.second->noteStopAll(event.GetTimestampNs()); + } + return; + } + + HashableDimensionKey atomKey = getHashableKey(getDimensionKey(event, mInternalDimension)); + + if (mCurrentSlicedDuration.find(eventKey) == mCurrentSlicedDuration.end()) { + mCurrentSlicedDuration[eventKey] = createDurationTracker(mPastBuckets[eventKey]); + } + + auto it = mCurrentSlicedDuration.find(eventKey); + + if (matcherIndex == mStartIndex) { + it->second->noteStart(atomKey, condition, event.GetTimestampNs(), conditionKeys); + + } else if (matcherIndex == mStopIndex) { + it->second->noteStop(atomKey, event.GetTimestampNs()); + } } size_t DurationMetricProducer::byteSize() { diff --git a/cmds/statsd/src/metrics/DurationMetricProducer.h b/cmds/statsd/src/metrics/DurationMetricProducer.h index 29fc82852621e..5b302b45dd0a5 100644 --- a/cmds/statsd/src/metrics/DurationMetricProducer.h +++ b/cmds/statsd/src/metrics/DurationMetricProducer.h @@ -22,6 +22,9 @@ #include "../condition/ConditionTracker.h" #include "../matchers/matcher_util.h" #include "MetricProducer.h" +#include "duration_helper/DurationTracker.h" +#include "duration_helper/MaxDurationTracker.h" +#include "duration_helper/OringDurationTracker.h" #include "frameworks/base/cmds/statsd/src/stats_log.pb.h" #include "frameworks/base/cmds/statsd/src/statsd_config.pb.h" #include "stats_util.h" @@ -32,42 +35,22 @@ namespace android { namespace os { namespace statsd { -enum DurationState { - kStopped = 0, // The event is stopped. - kStarted = 1, // The event is on going. - kPaused = 2, // The event is started, but condition is false, clock is paused. When condition - // turns to true, kPaused will become kStarted. -}; - -// Hold duration information for current on-going bucket. -struct DurationInfo { - DurationState state; - // most recent start time. - int64_t lastStartTime; - // existing duration in current bucket. Eventually, the duration will be aggregated in - // the way specified in AggregateType (Sum, Max, or Min). - int64_t lastDuration; - // cache the HashableDimensionKeys we need to query the condition for this duration event. - std::map conditionKeys; - - DurationInfo() : state(kStopped), lastStartTime(0), lastDuration(0){}; -}; - class DurationMetricProducer : public MetricProducer { public: DurationMetricProducer(const DurationMetric& durationMetric, const int conditionIndex, const size_t startIndex, const size_t stopIndex, - const size_t stopAllIndex, const sp& wizard); + const size_t stopAllIndex, const sp& wizard, + const vector& internalDimension); virtual ~DurationMetricProducer(); - void onConditionChanged(const bool conditionMet) override; + void onConditionChanged(const bool conditionMet, const uint64_t eventTime) override; void finish() override; StatsLogReport onDumpReport() override; - void onSlicedConditionMayChange() override; + void onSlicedConditionMayChange(const uint64_t eventTime) override; size_t byteSize() override; @@ -93,26 +76,21 @@ private: // Index of the SimpleLogEntryMatcher which defines the stop all for all dimensions. const size_t mStopAllIndex; + // The dimension from the atom predicate. e.g., uid, wakelock name. + const vector mInternalDimension; + // Save the past buckets and we can clear when the StatsLogReport is dumped. std::unordered_map> mPastBuckets; // The current bucket. - std::unordered_map mCurrentSlicedDuration; + std::unordered_map> + mCurrentSlicedDuration; void flushDurationIfNeeded(const uint64_t newEventTime); - void noteStart(const HashableDimensionKey& key, const bool conditionMet, - const uint64_t eventTime); + std::unique_ptr createDurationTracker(std::vector& bucket); - void noteStop(const HashableDimensionKey& key, const uint64_t eventTime); - - void noteStopAll(const uint64_t eventTime); - - static int64_t updateDuration(const int64_t lastDuration, const int64_t durationTime, - const DurationMetric_AggregationType type); - - void noteConditionChanged(const HashableDimensionKey& key, const bool conditionMet, - const uint64_t eventTime); + void flushIfNeeded(uint64_t timestamp); }; } // namespace statsd diff --git a/cmds/statsd/src/metrics/EventMetricProducer.cpp b/cmds/statsd/src/metrics/EventMetricProducer.cpp index 7e06105146799..dd23d66da7cc9 100644 --- a/cmds/statsd/src/metrics/EventMetricProducer.cpp +++ b/cmds/statsd/src/metrics/EventMetricProducer.cpp @@ -20,7 +20,6 @@ #include "EventMetricProducer.h" #include "stats_util.h" -#include #include #include @@ -78,7 +77,7 @@ void EventMetricProducer::startNewProtoOutputStream(long long startTime) { void EventMetricProducer::finish() { } -void EventMetricProducer::onSlicedConditionMayChange() { +void EventMetricProducer::onSlicedConditionMayChange(const uint64_t eventTime) { } StatsLogReport EventMetricProducer::onDumpReport() { @@ -105,7 +104,7 @@ StatsLogReport EventMetricProducer::onDumpReport() { return StatsLogReport(); } -void EventMetricProducer::onConditionChanged(const bool conditionMet) { +void EventMetricProducer::onConditionChanged(const bool conditionMet, const uint64_t eventTime) { VLOG("Metric %lld onConditionChanged", mMetric.metric_id()); mCondition = conditionMet; } diff --git a/cmds/statsd/src/metrics/EventMetricProducer.h b/cmds/statsd/src/metrics/EventMetricProducer.h index de1102b0c735c..72df0a77101b7 100644 --- a/cmds/statsd/src/metrics/EventMetricProducer.h +++ b/cmds/statsd/src/metrics/EventMetricProducer.h @@ -43,13 +43,13 @@ public: const std::map& conditionKey, bool condition, const LogEvent& event) override; - void onConditionChanged(const bool conditionMet) override; + void onConditionChanged(const bool conditionMet, const uint64_t eventTime) override; void finish() override; StatsLogReport onDumpReport() override; - void onSlicedConditionMayChange() override; + void onSlicedConditionMayChange(const uint64_t eventTime) override; size_t byteSize() override; diff --git a/cmds/statsd/src/metrics/MetricProducer.h b/cmds/statsd/src/metrics/MetricProducer.h index 80eb527f3bdf6..2083695e72380 100644 --- a/cmds/statsd/src/metrics/MetricProducer.h +++ b/cmds/statsd/src/metrics/MetricProducer.h @@ -50,9 +50,9 @@ public: // Consume the parsed stats log entry that already matched the "what" of the metric. void onMatchedLogEvent(const size_t matcherIndex, const LogEvent& event); - virtual void onConditionChanged(const bool condition) = 0; + virtual void onConditionChanged(const bool condition, const uint64_t eventTime) = 0; - virtual void onSlicedConditionMayChange() = 0; + virtual void onSlicedConditionMayChange(const uint64_t eventTime) = 0; // This is called when the metric collecting is done, e.g., when there is a new configuration // coming. MetricProducer should do the clean up, and dump existing data to dropbox. diff --git a/cmds/statsd/src/metrics/MetricsManager.cpp b/cmds/statsd/src/metrics/MetricsManager.cpp index 4fa3965a9dd28..d1df8aa751773 100644 --- a/cmds/statsd/src/metrics/MetricsManager.cpp +++ b/cmds/statsd/src/metrics/MetricsManager.cpp @@ -74,6 +74,7 @@ void MetricsManager::onLogEvent(const LogEvent& event) { } int tagId = event.GetTagId(); + uint64_t eventTime = event.GetTimestampNs(); if (mTagIds.find(tagId) == mTagIds.end()) { // not interesting... return; @@ -124,13 +125,14 @@ void MetricsManager::onLogEvent(const LogEvent& event) { // metric cares about non sliced condition, and it's changed. // Push the new condition to it directly. if (!mAllMetricProducers[metricIndex]->isConditionSliced() && changedCache[i]) { - mAllMetricProducers[metricIndex]->onConditionChanged(conditionCache[i]); + mAllMetricProducers[metricIndex]->onConditionChanged(conditionCache[i], + eventTime); // metric cares about sliced conditions, and it may have changed. Send // notification, and the metric can query the sliced conditions that are // interesting to it. } else if (mAllMetricProducers[metricIndex]->isConditionSliced() && slicedChangedCache[i]) { - mAllMetricProducers[metricIndex]->onSlicedConditionMayChange(); + mAllMetricProducers[metricIndex]->onSlicedConditionMayChange(eventTime); } } } diff --git a/cmds/statsd/src/metrics/duration_helper/DurationTracker.h b/cmds/statsd/src/metrics/duration_helper/DurationTracker.h new file mode 100644 index 0000000000000..0d0d9a4e26475 --- /dev/null +++ b/cmds/statsd/src/metrics/duration_helper/DurationTracker.h @@ -0,0 +1,89 @@ +/* + * Copyright (C) 2017 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. + */ + +#ifndef DURATION_TRACKER_H +#define DURATION_TRACKER_H + +#include "condition/ConditionWizard.h" +#include "stats_util.h" + +#include "frameworks/base/cmds/statsd/src/stats_log.pb.h" + +namespace android { +namespace os { +namespace statsd { + +enum DurationState { + kStopped = 0, // The event is stopped. + kStarted = 1, // The event is on going. + kPaused = 2, // The event is started, but condition is false, clock is paused. When condition + // turns to true, kPaused will become kStarted. +}; + +// Hold duration information for one atom level duration in current on-going bucket. +struct DurationInfo { + DurationState state; + // most recent start time. + int64_t lastStartTime; + // existing duration in current bucket. + int64_t lastDuration; + // TODO: Optimize the way we track sliced condition in duration metrics. + // cache the HashableDimensionKeys we need to query the condition for this duration event. + ConditionKey conditionKeys; + + DurationInfo() : state(kStopped), lastStartTime(0), lastDuration(0){}; +}; + +class DurationTracker { +public: + DurationTracker(sp wizard, int conditionIndex, uint64_t currentBucketStartNs, + uint64_t bucketSizeNs, std::vector& bucket) + : mWizard(wizard), + mConditionTrackerIndex(conditionIndex), + mCurrentBucketStartTimeNs(currentBucketStartNs), + mBucketSizeNs(bucketSizeNs), + mBucket(bucket), + mDuration(0){}; + virtual ~DurationTracker(){}; + virtual void noteStart(const HashableDimensionKey& key, bool condition, + const uint64_t eventTime, const ConditionKey& conditionKey) = 0; + virtual void noteStop(const HashableDimensionKey& key, const uint64_t eventTime) = 0; + virtual void noteStopAll(const uint64_t eventTime) = 0; + virtual void onSlicedConditionMayChange(const uint64_t timestamp) = 0; + virtual void onConditionChanged(bool condition, const uint64_t timestamp) = 0; + // Flush stale buckets if needed, and return true if the tracker has no on-going duration + // events, so that the owner can safely remove the tracker. + virtual bool flushIfNeeded(uint64_t timestampNs) = 0; + +protected: + sp mWizard; + + int mConditionTrackerIndex; + + uint64_t mCurrentBucketStartTimeNs; + + int64_t mBucketSizeNs; + + std::vector& mBucket; // where to write output + + int64_t mDuration; // current recorded duration result +}; + +} // namespace statsd +} // namespace os +} // namespace android + +#endif // DURATION_TRACKER_H \ No newline at end of file diff --git a/cmds/statsd/src/metrics/duration_helper/MaxDurationTracker.cpp b/cmds/statsd/src/metrics/duration_helper/MaxDurationTracker.cpp new file mode 100644 index 0000000000000..856ca9d979f55 --- /dev/null +++ b/cmds/statsd/src/metrics/duration_helper/MaxDurationTracker.cpp @@ -0,0 +1,227 @@ +/* + * Copyright (C) 2017 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. + */ + +#define DEBUG true + +#include "Log.h" +#include "MaxDurationTracker.h" + +namespace android { +namespace os { +namespace statsd { + +MaxDurationTracker::MaxDurationTracker(sp wizard, int conditionIndex, + uint64_t currentBucketStartNs, uint64_t bucketSizeNs, + std::vector& bucket) + : DurationTracker(wizard, conditionIndex, currentBucketStartNs, bucketSizeNs, bucket) { +} + +void MaxDurationTracker::noteStart(const HashableDimensionKey& key, bool condition, + const uint64_t eventTime, const ConditionKey& conditionKey) { + // this will construct a new DurationInfo if this key didn't exist. + DurationInfo& duration = mInfos[key]; + duration.conditionKeys = conditionKey; + VLOG("MaxDuration: key %s start condition %d", key.c_str(), condition); + + switch (duration.state) { + case kStarted: + // The same event is already started. Because we are not counting nesting, so ignore. + break; + case kPaused: + // Safe to do nothing here. Paused means started but condition is false. + break; + case kStopped: + if (!condition) { + // event started, but we need to wait for the condition to become true. + duration.state = DurationState::kPaused; + } else { + duration.state = DurationState::kStarted; + duration.lastStartTime = eventTime; + } + break; + } +} + +void MaxDurationTracker::noteStop(const HashableDimensionKey& key, const uint64_t eventTime) { + VLOG("MaxDuration: key %s stop", key.c_str()); + if (mInfos.find(key) == mInfos.end()) { + // we didn't see a start event before. do nothing. + return; + } + DurationInfo& duration = mInfos[key]; + + switch (duration.state) { + case DurationState::kStopped: + // already stopped, do nothing. + break; + case DurationState::kStarted: { + duration.state = DurationState::kStopped; + int64_t durationTime = eventTime - duration.lastStartTime; + VLOG("Max, key %s, Stop %lld %lld %lld", key.c_str(), (long long)duration.lastStartTime, + (long long)eventTime, (long long)durationTime); + duration.lastDuration = duration.lastDuration + durationTime; + VLOG(" record duration: %lld ", (long long)duration.lastDuration); + break; + } + case DurationState::kPaused: { + duration.state = DurationState::kStopped; + break; + } + } + + if (duration.lastDuration > mDuration) { + mDuration = duration.lastDuration; + VLOG("Max: new max duration: %lld", (long long)mDuration); + } + // Once an atom duration ends, we erase it. Next time, if we see another atom event with the + // same name, they are still considered as different atom durations. + mInfos.erase(key); +} +void MaxDurationTracker::noteStopAll(const uint64_t eventTime) { + for (auto& pair : mInfos) { + noteStop(pair.first, eventTime); + } +} + +bool MaxDurationTracker::flushIfNeeded(uint64_t eventTime) { + if (mCurrentBucketStartTimeNs + mBucketSizeNs > eventTime) { + return false; + } + + VLOG("MaxDurationTracker flushing....."); + + // adjust the bucket start time + int numBucketsForward = (eventTime - mCurrentBucketStartTimeNs) / mBucketSizeNs; + + DurationBucketInfo info; + uint64_t endTime = mCurrentBucketStartTimeNs + mBucketSizeNs; + info.set_start_bucket_nanos(mCurrentBucketStartTimeNs); + info.set_end_bucket_nanos(endTime); + + uint64_t oldBucketStartTimeNs = mCurrentBucketStartTimeNs; + mCurrentBucketStartTimeNs += (numBucketsForward)*mBucketSizeNs; + + bool hasOnGoingStartedEvent = false; // a kStarted event last across bucket boundaries. + bool hasPendingEvent = + false; // has either a kStarted or kPaused event across bucket boundaries + // meaning we need to carry them over to the new bucket. + for (auto it = mInfos.begin(); it != mInfos.end(); ++it) { + int64_t finalDuration = it->second.lastDuration; + if (it->second.state == kStarted) { + // the event is still on-going, duration needs to be updated. + // |..lastDurationTime_recorded...last_start -----|bucket_end. We need to record the + // duration between lastStartTime and bucketEnd. + int64_t durationTime = endTime - it->second.lastStartTime; + + finalDuration += durationTime; + VLOG(" unrecorded %lld -> %lld", (long long)(durationTime), (long long)finalDuration); + // if the event is still on-going, we need to fill the buckets between prev_bucket and + // now_bucket. |prev_bucket|...|..|...|now_bucket| + hasOnGoingStartedEvent = true; + } + + if (finalDuration > mDuration) { + mDuration = finalDuration; + } + + if (it->second.state == DurationState::kStopped) { + // No need to keep buckets for events that were stopped before. + mInfos.erase(it); + } else { + hasPendingEvent = true; + // for kPaused, and kStarted event, we will keep track of them, and reset the start time + // and duration. + it->second.lastStartTime = mCurrentBucketStartTimeNs; + it->second.lastDuration = 0; + } + } + + if (mDuration != 0) { + info.set_duration_nanos(mDuration); + mBucket.push_back(info); + VLOG(" final duration for last bucket: %lld", (long long)mDuration); + } + + mDuration = 0; + if (hasOnGoingStartedEvent) { + for (int i = 1; i < numBucketsForward; i++) { + DurationBucketInfo info; + info.set_start_bucket_nanos(oldBucketStartTimeNs + mBucketSizeNs * i); + info.set_end_bucket_nanos(endTime + mBucketSizeNs * i); + info.set_duration_nanos(mBucketSizeNs); + mBucket.push_back(info); + VLOG(" filling gap bucket with duration %lld", (long long)mBucketSizeNs); + } + } + // If this tracker has no pending events, tell owner to remove. + return !hasPendingEvent; +} + +void MaxDurationTracker::onSlicedConditionMayChange(const uint64_t timestamp) { + // VLOG("Metric %lld onSlicedConditionMayChange", mMetric.metric_id()); + // Now for each of the on-going event, check if the condition has changed for them. + for (auto& pair : mInfos) { + if (pair.second.state == kStopped) { + continue; + } + bool conditionMet = mWizard->query(mConditionTrackerIndex, pair.second.conditionKeys) == + ConditionState::kTrue; + VLOG("key: %s, condition: %d", pair.first.c_str(), conditionMet); + noteConditionChanged(pair.first, conditionMet, timestamp); + } +} + +void MaxDurationTracker::onConditionChanged(bool condition, const uint64_t timestamp) { + for (auto& pair : mInfos) { + noteConditionChanged(pair.first, condition, timestamp); + } +} + +void MaxDurationTracker::noteConditionChanged(const HashableDimensionKey& key, bool conditionMet, + const uint64_t timestamp) { + auto it = mInfos.find(key); + if (it == mInfos.end()) { + return; + } + + switch (it->second.state) { + case kStarted: + // if condition becomes false, kStarted -> kPaused. Record the current duration. + if (!conditionMet) { + it->second.state = DurationState::kPaused; + it->second.lastDuration += (timestamp - it->second.lastStartTime); + + VLOG("MaxDurationTracker Key: %s Started->Paused ", key.c_str()); + } + break; + case kStopped: + // nothing to do if it's stopped. + break; + case kPaused: + // if condition becomes true, kPaused -> kStarted. and the start time is the condition + // change time. + if (conditionMet) { + it->second.state = DurationState::kStarted; + it->second.lastStartTime = timestamp; + VLOG("MaxDurationTracker Key: %s Paused->Started", key.c_str()); + } + break; + } +} + +} // namespace statsd +} // namespace os +} // namespace android \ No newline at end of file diff --git a/cmds/statsd/src/metrics/duration_helper/MaxDurationTracker.h b/cmds/statsd/src/metrics/duration_helper/MaxDurationTracker.h new file mode 100644 index 0000000000000..c74d070a32975 --- /dev/null +++ b/cmds/statsd/src/metrics/duration_helper/MaxDurationTracker.h @@ -0,0 +1,55 @@ +/* + * Copyright (C) 2017 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. + */ + +#ifndef MAX_DURATION_TRACKER_H +#define MAX_DURATION_TRACKER_H + +#include "DurationTracker.h" + +#include "frameworks/base/cmds/statsd/src/stats_log.pb.h" + +namespace android { +namespace os { +namespace statsd { + +// Tracks a pool of atom durations, and output the max duration for each bucket. +// To get max duration, we need to keep track of each individual durations, and compare them when +// they stop or bucket expires. +class MaxDurationTracker : public DurationTracker { +public: + MaxDurationTracker(sp wizard, int conditionIndex, + uint64_t currentBucketStartNs, uint64_t bucketSizeNs, + std::vector& bucket); + void noteStart(const HashableDimensionKey& key, bool condition, const uint64_t eventTime, + const ConditionKey& conditionKey) override; + void noteStop(const HashableDimensionKey& key, const uint64_t eventTime) override; + void noteStopAll(const uint64_t eventTime) override; + bool flushIfNeeded(uint64_t timestampNs) override; + void onSlicedConditionMayChange(const uint64_t timestamp) override; + void onConditionChanged(bool condition, const uint64_t timestamp) override; + +private: + std::map mInfos; + + void noteConditionChanged(const HashableDimensionKey& key, bool conditionMet, + const uint64_t timestamp); +}; + +} // namespace statsd +} // namespace os +} // namespace android + +#endif // MAX_DURATION_TRACKER_H diff --git a/cmds/statsd/src/metrics/duration_helper/OringDurationTracker.cpp b/cmds/statsd/src/metrics/duration_helper/OringDurationTracker.cpp new file mode 100644 index 0000000000000..e045fb4fb0122 --- /dev/null +++ b/cmds/statsd/src/metrics/duration_helper/OringDurationTracker.cpp @@ -0,0 +1,195 @@ +/* + * Copyright (C) 2017 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. + */ +#define DEBUG true +#include "Log.h" +#include "OringDurationTracker.h" + +namespace android { +namespace os { +namespace statsd { +OringDurationTracker::OringDurationTracker(sp wizard, int conditionIndex, + uint64_t currentBucketStartNs, uint64_t bucketSizeNs, + std::vector& bucket) + : DurationTracker(wizard, conditionIndex, currentBucketStartNs, bucketSizeNs, bucket), + mStarted(), + mPaused() { + mLastStartTime = 0; +} + +void OringDurationTracker::noteStart(const HashableDimensionKey& key, bool condition, + const uint64_t eventTime, const ConditionKey& conditionKey) { + if (condition) { + if (mStarted.size() == 0) { + mLastStartTime = eventTime; + VLOG("record first start...."); + } + mStarted.insert(key); + } else { + mPaused.insert(key); + } + + if (mConditionKeyMap.find(key) == mConditionKeyMap.end()) { + mConditionKeyMap[key] = conditionKey; + } + + VLOG("Oring: %s start, condition %d", key.c_str(), condition); +} + +void OringDurationTracker::noteStop(const HashableDimensionKey& key, const uint64_t timestamp) { + VLOG("Oring: %s stop", key.c_str()); + auto it = mStarted.find(key); + if (it != mStarted.end()) { + mStarted.erase(it); + if (mStarted.empty()) { + mDuration += (timestamp - mLastStartTime); + VLOG("record duration %lld, total %lld ", (long long)timestamp - mLastStartTime, + (long long)mDuration); + } + } + + mPaused.erase(key); + mConditionKeyMap.erase(key); +} +void OringDurationTracker::noteStopAll(const uint64_t timestamp) { + if (!mStarted.empty()) { + mDuration += (timestamp - mLastStartTime); + VLOG("Oring Stop all: record duration %lld %lld ", (long long)timestamp - mLastStartTime, + (long long)mDuration); + } + + mStarted.clear(); + mPaused.clear(); + mConditionKeyMap.clear(); +} + +bool OringDurationTracker::flushIfNeeded(uint64_t eventTime) { + if (mCurrentBucketStartTimeNs + mBucketSizeNs > eventTime) { + return false; + } + VLOG("OringDurationTracker Flushing............."); + // adjust the bucket start time + int numBucketsForward = (eventTime - mCurrentBucketStartTimeNs) / mBucketSizeNs; + DurationBucketInfo info; + uint64_t endTime = mCurrentBucketStartTimeNs + mBucketSizeNs; + info.set_start_bucket_nanos(mCurrentBucketStartTimeNs); + info.set_end_bucket_nanos(endTime); + + uint64_t oldBucketStartTimeNs = mCurrentBucketStartTimeNs; + mCurrentBucketStartTimeNs += (numBucketsForward)*mBucketSizeNs; + + if (mStarted.size() > 0) { + mDuration += (endTime - mLastStartTime); + } + if (mDuration != 0) { + info.set_duration_nanos(mDuration); + // it will auto create new vector of CountbucketInfo if the key is not found. + mBucket.push_back(info); + VLOG(" duration: %lld", (long long)mDuration); + } + + if (mStarted.size() > 0) { + for (int i = 1; i < numBucketsForward; i++) { + DurationBucketInfo info; + info.set_start_bucket_nanos(oldBucketStartTimeNs + mBucketSizeNs * i); + info.set_end_bucket_nanos(endTime + mBucketSizeNs * i); + info.set_duration_nanos(mBucketSizeNs); + mBucket.push_back(info); + VLOG(" add filling bucket with duration %lld", (long long)mBucketSizeNs); + } + } + mLastStartTime = mCurrentBucketStartTimeNs; + mDuration = 0; + + // if all stopped, then tell owner it's safe to remove this tracker. + return mStarted.empty() && mPaused.empty(); +} + +void OringDurationTracker::onSlicedConditionMayChange(const uint64_t timestamp) { + vector startedToPaused; + vector pausedToStarted; + if (!mStarted.empty()) { + for (auto it = mStarted.begin(); it != mStarted.end();) { + auto key = *it; + if (mConditionKeyMap.find(key) == mConditionKeyMap.end()) { + VLOG("Key %s dont have condition key", key.c_str()); + ++it; + continue; + } + if (mWizard->query(mConditionTrackerIndex, mConditionKeyMap[key]) != + ConditionState::kTrue) { + it = mStarted.erase(it); + startedToPaused.push_back(key); + VLOG("Key %s started -> paused", key.c_str()); + } else { + ++it; + } + } + + if (mStarted.empty()) { + mDuration += (timestamp - mLastStartTime); + VLOG("Duration add %lld , to %lld ", (long long)(timestamp - mLastStartTime), + (long long)mDuration); + } + } + + if (!mPaused.empty()) { + for (auto it = mPaused.begin(); it != mPaused.end();) { + auto key = *it; + if (mConditionKeyMap.find(key) == mConditionKeyMap.end()) { + VLOG("Key %s dont have condition key", key.c_str()); + ++it; + continue; + } + if (mWizard->query(mConditionTrackerIndex, mConditionKeyMap[key]) == + ConditionState::kTrue) { + it = mPaused.erase(it); + pausedToStarted.push_back(key); + VLOG("Key %s paused -> started", key.c_str()); + } else { + ++it; + } + } + + if (mStarted.empty() && pausedToStarted.size() > 0) { + mLastStartTime = timestamp; + } + } + + mStarted.insert(pausedToStarted.begin(), pausedToStarted.end()); + mPaused.insert(startedToPaused.begin(), startedToPaused.end()); +} + +void OringDurationTracker::onConditionChanged(bool condition, const uint64_t timestamp) { + if (condition) { + if (!mPaused.empty()) { + VLOG("Condition true, all started"); + if (mStarted.empty()) { + mLastStartTime = timestamp; + } + mStarted.insert(mPaused.begin(), mPaused.end()); + } + } else { + if (!mStarted.empty()) { + VLOG("Condition false, all paused"); + mDuration += (timestamp - mLastStartTime); + mPaused.insert(mStarted.begin(), mStarted.end()); + } + } +} + +} // namespace statsd +} // namespace os +} // namespace android diff --git a/cmds/statsd/src/metrics/duration_helper/OringDurationTracker.h b/cmds/statsd/src/metrics/duration_helper/OringDurationTracker.h new file mode 100644 index 0000000000000..542525153fb01 --- /dev/null +++ b/cmds/statsd/src/metrics/duration_helper/OringDurationTracker.h @@ -0,0 +1,57 @@ +/* + * Copyright (C) 2017 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. + */ + +#ifndef ORING_DURATION_TRACKER_H +#define ORING_DURATION_TRACKER_H + +#include "DurationTracker.h" + +#include +namespace android { +namespace os { +namespace statsd { + +// Tracks the "Or'd" duration -- if 2 durations are overlapping, they won't be double counted. +class OringDurationTracker : public DurationTracker { +public: + OringDurationTracker(sp wizard, int conditionIndex, + uint64_t currentBucketStartNs, uint64_t bucketSizeNs, + std::vector& bucket); + void noteStart(const HashableDimensionKey& key, bool condition, const uint64_t eventTime, + const ConditionKey& conditionKey) override; + void noteStop(const HashableDimensionKey& key, const uint64_t eventTime) override; + void noteStopAll(const uint64_t eventTime) override; + void onSlicedConditionMayChange(const uint64_t timestamp) override; + void onConditionChanged(bool condition, const uint64_t timestamp) override; + bool flushIfNeeded(uint64_t timestampNs) override; + +private: + // We don't need to keep track of individual durations. The information that's needed is: + // 1) which keys are started. We record the first start time. + // 2) which keys are paused (started but condition was false) + // 3) whenever a key stops, we remove it from the started set. And if the set becomes empty, + // it means everything has stopped, we then record the end time. + std::set mStarted; + std::set mPaused; + int64_t mLastStartTime; + std::map mConditionKeyMap; +}; + +} // namespace statsd +} // namespace os +} // namespace android + +#endif // ORING_DURATION_TRACKER_H \ No newline at end of file diff --git a/cmds/statsd/src/metrics/metrics_manager_util.cpp b/cmds/statsd/src/metrics/metrics_manager_util.cpp index e90f998a71790..3b3ffb7aad6a6 100644 --- a/cmds/statsd/src/metrics/metrics_manager_util.cpp +++ b/cmds/statsd/src/metrics/metrics_manager_util.cpp @@ -33,6 +33,8 @@ namespace os { namespace statsd { bool handleMetricWithLogTrackers(const string what, const int metricIndex, + const bool usedForDimension, + const vector>& allLogEntryMatchers, const unordered_map& logTrackerMap, unordered_map>& trackerToMetricMap, int& logTrackerIndex) { @@ -41,6 +43,12 @@ bool handleMetricWithLogTrackers(const string what, const int metricIndex, ALOGW("cannot find the LogEntryMatcher %s in config", what.c_str()); return false; } + if (usedForDimension && allLogEntryMatchers[logTrackerIt->second]->getTagIds().size() > 1) { + ALOGE("LogEntryMatcher %s has more than one tag ids. When a metric has dimension, the " + "\"what\" can only about one atom type.", + what.c_str()); + return false; + } logTrackerIndex = logTrackerIt->second; auto& metric_list = trackerToMetricMap[logTrackerIndex]; metric_list.push_back(metricIndex); @@ -68,8 +76,7 @@ bool handleMetricWithConditions( } allConditionTrackers[condition_it->second]->setSliced(true); allConditionTrackers[it->second]->setSliced(true); - allConditionTrackers[it->second]->addDimensions( - vector(link.key_in_condition().begin(), link.key_in_condition().end())); + // TODO: We need to verify the link is valid. } conditionIndex = condition_it->second; @@ -176,6 +183,7 @@ bool initConditions(const StatsdConfig& config, const unordered_map bool initMetrics(const StatsdConfig& config, const unordered_map& logTrackerMap, const unordered_map& conditionTrackerMap, + const vector>& allLogEntryMatchers, vector>& allConditionTrackers, vector>& allMetricProducers, unordered_map>& conditionToMetricMap, @@ -196,8 +204,9 @@ bool initMetrics(const StatsdConfig& config, const unordered_map& l int metricIndex = allMetricProducers.size(); int trackerIndex; - if (!handleMetricWithLogTrackers(metric.what(), metricIndex, logTrackerMap, - trackerToMetricMap, trackerIndex)) { + if (!handleMetricWithLogTrackers(metric.what(), metricIndex, metric.dimension_size() > 0, + allLogEntryMatchers, logTrackerMap, trackerToMetricMap, + trackerIndex)) { return false; } @@ -215,26 +224,49 @@ bool initMetrics(const StatsdConfig& config, const unordered_map& l for (int i = 0; i < config.duration_metric_size(); i++) { int metricIndex = allMetricProducers.size(); const DurationMetric& metric = config.duration_metric(i); + + auto what_it = conditionTrackerMap.find(metric.what()); + if (what_it == conditionTrackerMap.end()) { + ALOGE("DurationMetric's \"what\" is invalid"); + return false; + } + + const Condition& durationWhat = config.condition(what_it->second); + + if (durationWhat.contents_case() != Condition::ContentsCase::kSimpleCondition) { + ALOGE("DurationMetric's \"what\" must be a simple condition"); + return false; + } + + const auto& simpleCondition = durationWhat.simple_condition(); + int trackerIndices[3] = {-1, -1, -1}; - if (!metric.has_start() || - !handleMetricWithLogTrackers(metric.start(), metricIndex, logTrackerMap, - trackerToMetricMap, trackerIndices[0])) { + if (!simpleCondition.has_start() || + !handleMetricWithLogTrackers(simpleCondition.start(), metricIndex, + metric.dimension_size() > 0, allLogEntryMatchers, + logTrackerMap, trackerToMetricMap, trackerIndices[0])) { ALOGE("Duration metrics must specify a valid the start event matcher"); return false; } - if (metric.has_stop() && - !handleMetricWithLogTrackers(metric.stop(), metricIndex, logTrackerMap, - trackerToMetricMap, trackerIndices[1])) { + if (simpleCondition.has_stop() && + !handleMetricWithLogTrackers(simpleCondition.stop(), metricIndex, + metric.dimension_size() > 0, allLogEntryMatchers, + logTrackerMap, trackerToMetricMap, trackerIndices[1])) { return false; } - if (metric.has_stop_all() && - !handleMetricWithLogTrackers(metric.stop_all(), metricIndex, logTrackerMap, - trackerToMetricMap, trackerIndices[2])) { + if (simpleCondition.has_stop_all() && + !handleMetricWithLogTrackers(simpleCondition.stop_all(), metricIndex, + metric.dimension_size() > 0, allLogEntryMatchers, + logTrackerMap, trackerToMetricMap, trackerIndices[2])) { return false; } + vector internalDimension; + internalDimension.insert(internalDimension.begin(), simpleCondition.dimension().begin(), + simpleCondition.dimension().end()); + int conditionIndex = -1; if (metric.has_predicate()) { @@ -243,9 +275,9 @@ bool initMetrics(const StatsdConfig& config, const unordered_map& l conditionToMetricMap); } - sp durationMetric = - new DurationMetricProducer(metric, conditionIndex, trackerIndices[0], - trackerIndices[1], trackerIndices[2], wizard); + sp durationMetric = new DurationMetricProducer( + metric, conditionIndex, trackerIndices[0], trackerIndices[1], trackerIndices[2], + wizard, internalDimension); allMetricProducers.push_back(durationMetric); } @@ -258,8 +290,8 @@ bool initMetrics(const StatsdConfig& config, const unordered_map& l return false; } int trackerIndex; - if (!handleMetricWithLogTrackers(metric.what(), metricIndex, logTrackerMap, - trackerToMetricMap, trackerIndex)) { + if (!handleMetricWithLogTrackers(metric.what(), metricIndex, false, allLogEntryMatchers, + logTrackerMap, trackerToMetricMap, trackerIndex)) { return false; } @@ -299,8 +331,9 @@ bool initStatsdConfig(const StatsdConfig& config, set& allTagIds, return false; } - if (!initMetrics(config, logTrackerMap, conditionTrackerMap, allConditionTrackers, - allMetricProducers, conditionToMetricMap, trackerToMetricMap)) { + if (!initMetrics(config, logTrackerMap, conditionTrackerMap, allLogEntryMatchers, + allConditionTrackers, allMetricProducers, conditionToMetricMap, + trackerToMetricMap)) { ALOGE("initMetricProducers failed"); return false; } diff --git a/cmds/statsd/src/metrics/metrics_manager_util.h b/cmds/statsd/src/metrics/metrics_manager_util.h index 6722eb3cfe72e..c91b7fc32a85a 100644 --- a/cmds/statsd/src/metrics/metrics_manager_util.h +++ b/cmds/statsd/src/metrics/metrics_manager_util.h @@ -75,6 +75,7 @@ bool initMetrics( const StatsdConfig& config, const std::unordered_map& logTrackerMap, const std::unordered_map& conditionTrackerMap, const std::unordered_map>& eventConditionLinks, + const vector>& allLogEntryMatchers, vector>& allConditionTrackers, std::vector>& allMetricProducers, std::unordered_map>& conditionToMetricMap, diff --git a/cmds/statsd/src/stats_util.h b/cmds/statsd/src/stats_util.h index 39c1d59c88b7e..a428752ba6346 100644 --- a/cmds/statsd/src/stats_util.h +++ b/cmds/statsd/src/stats_util.h @@ -40,6 +40,8 @@ const uint64_t TYPE_STRING = 9ULL << FIELD_TYPE_SHIFT; typedef std::string HashableDimensionKey; +typedef std::map ConditionKey; + EventMetricData parse(log_msg msg); int getTagId(log_msg msg); diff --git a/cmds/statsd/src/statsd_config.proto b/cmds/statsd/src/statsd_config.proto index 72bde1f7c748c..87884b33cef04 100644 --- a/cmds/statsd/src/statsd_config.proto +++ b/cmds/statsd/src/statsd_config.proto @@ -82,6 +82,8 @@ message SimpleCondition { optional bool count_nesting = 3 [default = true]; optional string stop_all = 4; + + repeated KeyMatcher dimension = 5; } message Condition { @@ -148,29 +150,24 @@ message CountMetric { message DurationMetric { optional int64 metric_id = 1; - optional string start = 2; - - optional string stop = 3; - - optional string stop_all = 4; + optional string what = 2; enum AggregationType { DURATION_SUM = 1; DURATION_MAX_SPARSE = 2; - DURATION_MIN_SPARSE = 3; } - optional AggregationType type = 5; + optional AggregationType type = 3; - optional string predicate = 6; + optional string predicate = 4; - repeated KeyMatcher dimension = 7; + repeated KeyMatcher dimension = 5; - optional Bucket bucket = 8; + optional Bucket bucket = 6; - repeated Alert alerts = 9; + repeated Alert alerts = 7; - repeated EventConditionLink links = 10; + repeated EventConditionLink links = 8; } diff --git a/cmds/statsd/tests/MaxDurationTracker_test.cpp b/cmds/statsd/tests/MaxDurationTracker_test.cpp new file mode 100644 index 0000000000000..ae8bf42652355 --- /dev/null +++ b/cmds/statsd/tests/MaxDurationTracker_test.cpp @@ -0,0 +1,115 @@ +// Copyright (C) 2017 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 + +#include "src/condition/ConditionWizard.h" +#include "src/metrics/duration_helper/MaxDurationTracker.h" + +#include +#include +#include +#include + +using namespace android::os::statsd; +using namespace testing; +using android::sp; +using std::set; +using std::unordered_map; +using std::vector; + +#ifdef __ANDROID__ + +class MockConditionWizard : public ConditionWizard { +public: + MOCK_METHOD2( + query, + ConditionState(const int conditionIndex, + const std::map& conditionParameters)); +}; + +TEST(MaxDurationTrackerTest, TestSimpleMaxDuration) { + sp wizard = new NaggyMock(); + + vector buckets; + ConditionKey key1; + + uint64_t bucketStartTimeNs = 10000000000; + uint64_t bucketSizeNs = 30 * 1000 * 1000 * 1000LL; + + MaxDurationTracker tracker(wizard, -1, bucketStartTimeNs, bucketSizeNs, buckets); + + tracker.noteStart("", true, bucketStartTimeNs, key1); + tracker.noteStop("", bucketStartTimeNs + 10); + + tracker.noteStart("", true, bucketStartTimeNs + 20, key1); + tracker.noteStop("", bucketStartTimeNs + 40); + + tracker.flushIfNeeded(bucketStartTimeNs + bucketSizeNs + 1); + EXPECT_EQ(1u, buckets.size()); + EXPECT_EQ(20, buckets[0].duration_nanos()); +} + +TEST(MaxDurationTrackerTest, TestCrossBucketBoundary) { + sp wizard = new NaggyMock(); + + vector buckets; + ConditionKey key1; + + uint64_t bucketStartTimeNs = 10000000000; + uint64_t bucketSizeNs = 30 * 1000 * 1000 * 1000LL; + + MaxDurationTracker tracker(wizard, -1, bucketStartTimeNs, bucketSizeNs, buckets); + + tracker.noteStart("", true, bucketStartTimeNs + 1, key1); + tracker.flushIfNeeded(bucketStartTimeNs + (2 * bucketSizeNs) + 1); + + EXPECT_EQ(2u, buckets.size()); + EXPECT_EQ((long long)(bucketSizeNs - 1), buckets[0].duration_nanos()); + EXPECT_EQ((long long)bucketSizeNs, buckets[1].duration_nanos()); +} + +TEST(MaxDurationTrackerTest, TestMaxDurationWithCondition) { + sp wizard = new NaggyMock(); + + ConditionKey key1; + key1["APP_BACKGROUND"] = "1:maps|"; + + EXPECT_CALL(*wizard, query(_, key1)) // #4 + .WillOnce(Return(ConditionState::kFalse)); + + vector buckets; + + uint64_t bucketStartTimeNs = 10000000000; + uint64_t eventStartTimeNs = bucketStartTimeNs + 1; + uint64_t bucketSizeNs = 30 * 1000 * 1000 * 1000LL; + int64_t durationTimeNs = 2 * 1000; + + MaxDurationTracker tracker(wizard, 1, bucketStartTimeNs, bucketSizeNs, buckets); + + tracker.noteStart("2:maps", true, eventStartTimeNs, key1); + + tracker.onSlicedConditionMayChange(eventStartTimeNs + 5); + + tracker.noteStop("2:maps", eventStartTimeNs + durationTimeNs); + + tracker.flushIfNeeded(bucketStartTimeNs + bucketSizeNs + 1); + EXPECT_EQ(1u, buckets.size()); + EXPECT_EQ(5, buckets[0].duration_nanos()); +} + +#else +GTEST_LOG_(INFO) << "This test does nothing.\n"; +#endif diff --git a/cmds/statsd/tests/MetricsManager_test.cpp b/cmds/statsd/tests/MetricsManager_test.cpp index b000e13886329..2af17c2d33c08 100644 --- a/cmds/statsd/tests/MetricsManager_test.cpp +++ b/cmds/statsd/tests/MetricsManager_test.cpp @@ -124,6 +124,39 @@ StatsdConfig buildMissingMatchers() { return config; } +StatsdConfig buildDimensionMetricsWithMultiTags() { + StatsdConfig config; + config.set_config_id(12345L); + + LogEntryMatcher* eventMatcher = config.add_log_entry_matcher(); + eventMatcher->set_name("BATTERY_VERY_LOW"); + SimpleLogEntryMatcher* simpleLogEntryMatcher = eventMatcher->mutable_simple_log_entry_matcher(); + simpleLogEntryMatcher->set_tag(2); + + eventMatcher = config.add_log_entry_matcher(); + eventMatcher->set_name("BATTERY_VERY_VERY_LOW"); + simpleLogEntryMatcher = eventMatcher->mutable_simple_log_entry_matcher(); + simpleLogEntryMatcher->set_tag(3); + + eventMatcher = config.add_log_entry_matcher(); + eventMatcher->set_name("BATTERY_LOW"); + + LogEntryMatcher_Combination* combination = eventMatcher->mutable_combination(); + combination->set_operation(LogicalOperation::OR); + combination->add_matcher("BATTERY_VERY_LOW"); + combination->add_matcher("BATTERY_VERY_VERY_LOW"); + + // Count process state changes, slice by uid, while SCREEN_IS_OFF + CountMetric* metric = config.add_count_metric(); + metric->set_metric_id(3); + metric->set_what("BATTERY_LOW"); + metric->mutable_bucket()->set_bucket_size_millis(30 * 1000L); + KeyMatcher* keyMatcher = metric->add_dimension(); + keyMatcher->set_key(1); + + return config; +} + StatsdConfig buildCircleConditions() { StatsdConfig config; config.set_config_id(12345L); @@ -180,6 +213,21 @@ TEST(MetricsManagerTest, TestGoodConfig) { trackerToConditionMap)); } +TEST(MetricsManagerTest, TestDimensionMetricsWithMultiTags) { + StatsdConfig config = buildDimensionMetricsWithMultiTags(); + set allTagIds; + vector> allLogEntryMatchers; + vector> allConditionTrackers; + vector> allMetricProducers; + unordered_map> conditionToMetricMap; + unordered_map> trackerToMetricMap; + unordered_map> trackerToConditionMap; + + EXPECT_FALSE(initStatsdConfig(config, allTagIds, allLogEntryMatchers, allConditionTrackers, + allMetricProducers, conditionToMetricMap, trackerToMetricMap, + trackerToConditionMap)); +} + TEST(MetricsManagerTest, TestCircleLogMatcherDependency) { StatsdConfig config = buildCircleMatchers(); set allTagIds; diff --git a/cmds/statsd/tests/OringDurationTracker_test.cpp b/cmds/statsd/tests/OringDurationTracker_test.cpp new file mode 100644 index 0000000000000..0b7981935ab1e --- /dev/null +++ b/cmds/statsd/tests/OringDurationTracker_test.cpp @@ -0,0 +1,99 @@ +// Copyright (C) 2017 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 + +#include "src/condition/ConditionWizard.h" +#include "src/metrics/duration_helper/OringDurationTracker.h" + +#include +#include +#include +#include + +using namespace android::os::statsd; +using namespace testing; +using android::sp; +using std::set; +using std::unordered_map; +using std::vector; + +#ifdef __ANDROID__ + +class MockConditionWizard : public ConditionWizard { +public: + MOCK_METHOD2( + query, + ConditionState(const int conditionIndex, + const std::map& conditionParameters)); +}; + +TEST(OringDurationTrackerTest, TestDurationOverlap) { + sp wizard = new NaggyMock(); + + ConditionKey key1; + key1["APP_BACKGROUND"] = "1:maps|"; + + vector buckets; + + uint64_t bucketStartTimeNs = 10000000000; + uint64_t eventStartTimeNs = bucketStartTimeNs + 1; + uint64_t bucketSizeNs = 30 * 1000 * 1000 * 1000LL; + int64_t durationTimeNs = 2 * 1000; + + OringDurationTracker tracker(wizard, 1, bucketStartTimeNs, bucketSizeNs, buckets); + + tracker.noteStart("2:maps", true, eventStartTimeNs, key1); + tracker.noteStart("2:maps", true, eventStartTimeNs + 10, key1); // overlapping wl + + tracker.noteStop("2:maps", eventStartTimeNs + durationTimeNs); + + tracker.flushIfNeeded(bucketStartTimeNs + bucketSizeNs + 1); + EXPECT_EQ(1u, buckets.size()); + EXPECT_EQ(durationTimeNs, buckets[0].duration_nanos()); +} + +TEST(OringDurationTrackerTest, TestDurationConditionChange) { + sp wizard = new NaggyMock(); + + ConditionKey key1; + key1["APP_BACKGROUND"] = "1:maps|"; + + EXPECT_CALL(*wizard, query(_, key1)) // #4 + .WillOnce(Return(ConditionState::kFalse)); + + vector buckets; + + uint64_t bucketStartTimeNs = 10000000000; + uint64_t eventStartTimeNs = bucketStartTimeNs + 1; + uint64_t bucketSizeNs = 30 * 1000 * 1000 * 1000LL; + int64_t durationTimeNs = 2 * 1000; + + OringDurationTracker tracker(wizard, 1, bucketStartTimeNs, bucketSizeNs, buckets); + + tracker.noteStart("2:maps", true, eventStartTimeNs, key1); + + tracker.onSlicedConditionMayChange(eventStartTimeNs + 5); + + tracker.noteStop("2:maps", eventStartTimeNs + durationTimeNs); + + tracker.flushIfNeeded(bucketStartTimeNs + bucketSizeNs + 1); + EXPECT_EQ(1u, buckets.size()); + EXPECT_EQ(5, buckets[0].duration_nanos()); +} + +#else +GTEST_LOG_(INFO) << "This test does nothing.\n"; +#endif