/* * 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 STATSD_DEBUG false #include "Log.h" #include "MaxDurationTracker.h" #include "guardrail/StatsdStats.h" namespace android { namespace os { namespace statsd { MaxDurationTracker::MaxDurationTracker(const ConfigKey& key, const int64_t id, const MetricDimensionKey& eventKey, const sp& wizard, int conditionIndex, bool nesting, int64_t currentBucketStartNs, int64_t currentBucketNum, int64_t startTimeNs, int64_t bucketSizeNs, bool conditionSliced, bool fullLink, const vector>& anomalyTrackers) : DurationTracker(key, id, eventKey, wizard, conditionIndex, nesting, currentBucketStartNs, currentBucketNum, startTimeNs, bucketSizeNs, conditionSliced, fullLink, anomalyTrackers) { mDuration = 0; } bool MaxDurationTracker::hitGuardRail(const HashableDimensionKey& newKey, size_t dimensionHardLimit) const { // ===========GuardRail============== if (mInfos.find(newKey) != mInfos.end()) { // if the key existed, we are good! return false; } // 1. Report the tuple count if the tuple count > soft limit if (mInfos.size() >= StatsdStats::kDimensionKeySizeSoftLimit) { size_t newTupleCount = mInfos.size() + 1; StatsdStats::getInstance().noteMetricDimensionSize(mConfigKey, mTrackerId, newTupleCount); // 2. Don't add more tuples, we are above the allowed threshold. Drop the data. if (newTupleCount > dimensionHardLimit) { if (!mHasHitGuardrail) { ALOGE("MaxDurTracker %lld dropping data for dimension key %s", (long long)mTrackerId, newKey.toString().c_str()); mHasHitGuardrail = true; } StatsdStats::getInstance().noteHardDimensionLimitReached(mTrackerId); return true; } } return false; } void MaxDurationTracker::noteStart(const HashableDimensionKey& key, bool condition, const int64_t eventTime, const ConditionKey& conditionKey, size_t dimensionHardLimit) { // this will construct a new DurationInfo if this key didn't exist. if (hitGuardRail(key, dimensionHardLimit)) { return; } DurationInfo& duration = mInfos[key]; if (mConditionSliced) { duration.conditionKeys = conditionKey; } VLOG("MaxDuration: key %s start condition %d", key.toString().c_str(), condition); switch (duration.state) { case kStarted: duration.startCount++; break; case kPaused: duration.startCount++; 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; startAnomalyAlarm(eventTime); } duration.startCount = 1; break; } } void MaxDurationTracker::noteStop(const HashableDimensionKey& key, const int64_t eventTime, bool forceStop) { VLOG("MaxDuration: key %s stop", key.toString().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.startCount--; if (forceStop || !mNested || duration.startCount <= 0) { stopAnomalyAlarm(eventTime); duration.state = DurationState::kStopped; int64_t durationTime = eventTime - duration.lastStartTime; VLOG("Max, key %s, Stop %lld %lld %lld", key.toString().c_str(), (long long)duration.lastStartTime, (long long)eventTime, (long long)durationTime); duration.lastDuration += durationTime; if (hasStartedDuration()) { // In case any other dimensions are still started, we need to keep the alarm // set. startAnomalyAlarm(eventTime); } VLOG(" record duration: %lld ", (long long)duration.lastDuration); } break; } case DurationState::kPaused: { duration.startCount--; if (forceStop || !mNested || duration.startCount <= 0) { 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. if (duration.state == DurationState::kStopped) { mInfos.erase(key); } } bool MaxDurationTracker::hasStartedDuration() const { for (auto& pair : mInfos) { if (pair.second.state == kStarted) { return true; } } return false; } bool MaxDurationTracker::hasAccumulatedDuration() const { // When DurationState is changed to kStopped, we remove its entry from mInfos. Thus, mInfos // will be empty when all entries are stopped. return !mInfos.empty() || mDuration != 0; } void MaxDurationTracker::noteStopAll(const int64_t eventTime) { std::set keys; for (const auto& pair : mInfos) { keys.insert(pair.first); } for (auto& key : keys) { noteStop(key, eventTime, true); } } bool MaxDurationTracker::flushCurrentBucket( const int64_t eventTimeNs, const optional& uploadThreshold, const int64_t globalConditionTrueNs, std::unordered_map>* output) { VLOG("MaxDurationTracker flushing....."); // adjust the bucket start time int numBucketsForward = 0; int64_t fullBucketEnd = getCurrentBucketEndTimeNs(); int64_t currentBucketEndTimeNs; if (eventTimeNs >= fullBucketEnd) { numBucketsForward = 1 + (eventTimeNs - fullBucketEnd) / mBucketSizeNs; currentBucketEndTimeNs = fullBucketEnd; } else { // This must be a partial bucket. currentBucketEndTimeNs = eventTimeNs; } 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();) { if (it->second.state == DurationState::kStopped) { // No need to keep buckets for events that were stopped before. it = mInfos.erase(it); } else { ++it; hasPendingEvent = true; } } // mDuration is updated in noteStop to the maximum duration that ended in the current bucket. if (durationPassesThreshold(uploadThreshold, mDuration)) { DurationBucket info; info.mBucketStartNs = mCurrentBucketStartTimeNs; info.mBucketEndNs = currentBucketEndTimeNs; info.mDuration = mDuration; info.mConditionTrueNs = globalConditionTrueNs; (*output)[mEventKey].push_back(info); VLOG(" final duration for last bucket: %lld", (long long)mDuration); } else { VLOG(" duration: %lld does not pass set threshold", (long long)mDuration); } if (numBucketsForward > 0) { mCurrentBucketStartTimeNs = fullBucketEnd + (numBucketsForward - 1) * mBucketSizeNs; mCurrentBucketNum += numBucketsForward; } else { // We must be forming a partial bucket. mCurrentBucketStartTimeNs = eventTimeNs; } mDuration = 0; // Reset mHasHitGuardrail boolean since bucket was reset mHasHitGuardrail = false; // If this tracker has no pending events, tell owner to remove. return !hasPendingEvent; } bool MaxDurationTracker::flushIfNeeded( int64_t eventTimeNs, const optional& uploadThreshold, unordered_map>* output) { if (eventTimeNs < getCurrentBucketEndTimeNs()) { return false; } return flushCurrentBucket(eventTimeNs, uploadThreshold, /*globalConditionTrueNs*/ 0, output); } void MaxDurationTracker::onSlicedConditionMayChange(const int64_t timestamp) { // 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; } ConditionState conditionState = mWizard->query( mConditionTrackerIndex, pair.second.conditionKeys, !mHasLinksToAllConditionDimensionsInTracker); bool conditionMet = (conditionState == ConditionState::kTrue); VLOG("key: %s, condition: %d", pair.first.toString().c_str(), conditionMet); noteConditionChanged(pair.first, conditionMet, timestamp); } } void MaxDurationTracker::onStateChanged(const int64_t timestamp, const int32_t atomId, const FieldValue& newState) { ALOGE("MaxDurationTracker does not handle sliced state changes."); } void MaxDurationTracker::onConditionChanged(bool condition, const int64_t timestamp) { for (auto& pair : mInfos) { noteConditionChanged(pair.first, condition, timestamp); } } void MaxDurationTracker::noteConditionChanged(const HashableDimensionKey& key, bool conditionMet, const int64_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 and // stop anomaly alarm. if (!conditionMet) { stopAnomalyAlarm(timestamp); it->second.state = DurationState::kPaused; it->second.lastDuration += (timestamp - it->second.lastStartTime); if (hasStartedDuration()) { // In case any other dimensions are still started, we need to set the alarm. startAnomalyAlarm(timestamp); } VLOG("MaxDurationTracker Key: %s Started->Paused ", key.toString().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; startAnomalyAlarm(timestamp); VLOG("MaxDurationTracker Key: %s Paused->Started", key.toString().c_str()); } break; } // Note that we don't update mDuration here since it's only updated during noteStop. } int64_t MaxDurationTracker::predictAnomalyTimestampNs(const AnomalyTracker& anomalyTracker, const int64_t currentTimestamp) const { // The allowed time we can continue in the current state is the // (anomaly threshold) - max(elapsed time of the started mInfos). int64_t maxElapsed = 0; for (auto it = mInfos.begin(); it != mInfos.end(); ++it) { if (it->second.state == DurationState::kStarted) { int64_t duration = it->second.lastDuration + (currentTimestamp - it->second.lastStartTime); if (duration > maxElapsed) { maxElapsed = duration; } } } int64_t anomalyTimeNs = currentTimestamp + anomalyTracker.getAnomalyThreshold() - maxElapsed; int64_t refractoryEndNs = anomalyTracker.getRefractoryPeriodEndsSec(mEventKey) * NS_PER_SEC; return std::max(anomalyTimeNs, refractoryEndNs); } void MaxDurationTracker::dumpStates(int out, bool verbose) const { dprintf(out, "\t\t sub-durations %lu\n", (unsigned long)mInfos.size()); dprintf(out, "\t\t current duration %lld\n", (long long)mDuration); } int64_t MaxDurationTracker::getCurrentStateKeyDuration() const { ALOGE("MaxDurationTracker does not handle sliced state changes."); return -1; } int64_t MaxDurationTracker::getCurrentStateKeyFullBucketDuration() const { ALOGE("MaxDurationTracker does not handle sliced state changes."); return -1; } void MaxDurationTracker::updateCurrentStateKey(const int32_t atomId, const FieldValue& newState) { ALOGE("MaxDurationTracker does not handle sliced state changes."); } } // namespace statsd } // namespace os } // namespace android