Use elapsed realtime instead of times based on wall clock, which can jump around and go backwards.
Test: statsd unit test passed
Change-Id: Ib541df99231e171b3be2a24f75632693e36da90e
diff --git a/cmds/statsd/src/StatsLogProcessor.cpp b/cmds/statsd/src/StatsLogProcessor.cpp
index 3a20b12..afb2c47 100644
--- a/cmds/statsd/src/StatsLogProcessor.cpp
+++ b/cmds/statsd/src/StatsLogProcessor.cpp
@@ -21,6 +21,7 @@
#include <android-base/file.h>
#include <dirent.h>
#include "StatsLogProcessor.h"
+#include "stats_log_util.h"
#include "android-base/stringprintf.h"
#include "guardrail/StatsdStats.h"
#include "metrics/CountMetricProducer.h"
@@ -59,8 +60,8 @@
// for ConfigMetricsReport
const int FIELD_ID_METRICS = 1;
const int FIELD_ID_UID_MAP = 2;
-const int FIELD_ID_LAST_REPORT_NANOS = 3;
-const int FIELD_ID_CURRENT_REPORT_NANOS = 4;
+const int FIELD_ID_LAST_REPORT_ELAPSED_NANOS = 3;
+const int FIELD_ID_CURRENT_REPORT_ELAPSED_NANOS = 4;
#define STATS_DATA_DIR "/data/misc/stats-data"
@@ -136,7 +137,7 @@
void StatsLogProcessor::OnLogEvent(LogEvent* event) {
std::lock_guard<std::mutex> lock(mMetricsMutex);
StatsdStats::getInstance().noteAtomLogged(
- event->GetTagId(), event->GetTimestampNs() / NS_PER_SEC);
+ event->GetTagId(), event->GetElapsedTimestampNs() / NS_PER_SEC);
// Hard-coded logic to update the isolated uid's in the uid-map.
// The field numbers need to be currently updated by hand with atoms.proto
@@ -148,10 +149,10 @@
return;
}
- long curTime = time(nullptr);
- if (curTime - mLastPullerCacheClearTimeSec > StatsdStats::kPullerCacheClearIntervalSec) {
- mStatsPullerManager.ClearPullerCacheIfNecessary(curTime);
- mLastPullerCacheClearTimeSec = curTime;
+ uint64_t curTimeSec = getElapsedRealtimeSec();
+ if (curTimeSec - mLastPullerCacheClearTimeSec > StatsdStats::kPullerCacheClearIntervalSec) {
+ mStatsPullerManager.ClearPullerCacheIfNecessary(curTimeSec);
+ mLastPullerCacheClearTimeSec = curTimeSec;
}
if (event->GetTagId() != android::util::ISOLATED_UID_CHANGED) {
@@ -162,7 +163,7 @@
// pass the event to metrics managers.
for (auto& pair : mMetricsManagers) {
pair.second->onLogEvent(*event);
- flushIfNecessaryLocked(event->GetTimestampNs(), pair.first, *(pair.second));
+ flushIfNecessaryLocked(event->GetElapsedTimestampNs(), pair.first, *(pair.second));
}
}
@@ -242,6 +243,7 @@
long long reportsToken =
proto.start(FIELD_TYPE_MESSAGE | FIELD_COUNT_REPEATED | FIELD_ID_REPORTS);
+ int64_t lastReportTimeNs = it->second->getLastReportTimeNs();
// First, fill in ConfigMetricsReport using current data on memory, which
// starts from filling in StatsLogReport's.
it->second->onDumpReport(dumpTimeStampNs, &proto);
@@ -254,10 +256,10 @@
proto.write(FIELD_TYPE_MESSAGE | FIELD_ID_UID_MAP, uidMapBuffer, uidMapSize);
// Fill in the timestamps.
- proto.write(FIELD_TYPE_INT64 | FIELD_ID_LAST_REPORT_NANOS,
- (long long)it->second->getLastReportTimeNs());
- proto.write(FIELD_TYPE_INT64 | FIELD_ID_CURRENT_REPORT_NANOS,
- (long long)::android::elapsedRealtimeNano());
+ proto.write(FIELD_TYPE_INT64 | FIELD_ID_LAST_REPORT_ELAPSED_NANOS,
+ (long long)lastReportTimeNs);
+ proto.write(FIELD_TYPE_INT64 | FIELD_ID_CURRENT_REPORT_ELAPSED_NANOS,
+ (long long)dumpTimeStampNs);
// End of ConfigMetricsReport (reports).
proto.end(reportsToken);
@@ -340,8 +342,8 @@
vector<uint8_t> data;
onDumpReportLocked(key, time(nullptr) * NS_PER_SEC, &data);
// TODO: Add a guardrail to prevent accumulation of file on disk.
- string file_name = StringPrintf("%s/%ld_%d_%lld", STATS_DATA_DIR, time(nullptr),
- key.GetUid(), (long long)key.GetId());
+ string file_name = StringPrintf("%s/%ld_%d_%lld", STATS_DATA_DIR,
+ (long)getWallClockSec(), key.GetUid(), (long long)key.GetId());
StorageManager::writeFile(file_name.c_str(), &data[0], data.size());
}
}
diff --git a/cmds/statsd/src/StatsService.cpp b/cmds/statsd/src/StatsService.cpp
index ee38667..bb47653 100644
--- a/cmds/statsd/src/StatsService.cpp
+++ b/cmds/statsd/src/StatsService.cpp
@@ -18,6 +18,7 @@
#include "Log.h"
#include "StatsService.h"
+#include "stats_log_util.h"
#include "android-base/stringprintf.h"
#include "config/ConfigKey.h"
#include "config/ConfigManager.h"
@@ -79,18 +80,20 @@
mUidMap = new UidMap();
StatsPuller::SetUidMap(mUidMap);
mConfigManager = new ConfigManager();
- mProcessor = new StatsLogProcessor(mUidMap, mAnomalyMonitor, time(nullptr), [this](const ConfigKey& key) {
- sp<IStatsCompanionService> sc = getStatsCompanionService();
- auto receiver = mConfigManager->GetConfigReceiver(key);
- if (sc == nullptr) {
- VLOG("Could not find StatsCompanionService");
- } else if (receiver == nullptr) {
- VLOG("Statscompanion could not find a broadcast receiver for %s",
- key.ToString().c_str());
- } else {
- sc->sendDataBroadcast(receiver);
+ mProcessor = new StatsLogProcessor(mUidMap, mAnomalyMonitor, getElapsedRealtimeSec(),
+ [this](const ConfigKey& key) {
+ sp<IStatsCompanionService> sc = getStatsCompanionService();
+ auto receiver = mConfigManager->GetConfigReceiver(key);
+ if (sc == nullptr) {
+ VLOG("Could not find StatsCompanionService");
+ } else if (receiver == nullptr) {
+ VLOG("Statscompanion could not find a broadcast receiver for %s",
+ key.ToString().c_str());
+ } else {
+ sc->sendDataBroadcast(receiver);
+ }
}
- });
+ );
mConfigManager->AddListener(mProcessor);
@@ -668,11 +671,7 @@
return Status::fromExceptionCode(Status::EX_SECURITY,
"Only system uid can call informAnomalyAlarmFired");
}
-
- // TODO: This may be a bug. time(nullptr) can be off (wrt AlarmManager's time) and cause us to
- // miss the alarm! Eventually we will switch to using elapsedRealTime everywhere,
- // which may hopefully fix the problem, so we'll leave this alone for now.
- uint64_t currentTimeSec = time(nullptr);
+ uint64_t currentTimeSec = getElapsedRealtimeSec();
std::unordered_set<sp<const AnomalyAlarm>, SpHash<AnomalyAlarm>> anomalySet =
mAnomalyMonitor->popSoonerThan(static_cast<uint32_t>(currentTimeSec));
if (anomalySet.size() > 0) {
diff --git a/cmds/statsd/src/external/CpuTimePerUidFreqPuller.cpp b/cmds/statsd/src/external/CpuTimePerUidFreqPuller.cpp
index d0d2f93..d1d9d37 100644
--- a/cmds/statsd/src/external/CpuTimePerUidFreqPuller.cpp
+++ b/cmds/statsd/src/external/CpuTimePerUidFreqPuller.cpp
@@ -25,6 +25,7 @@
#include "guardrail/StatsdStats.h"
#include "logd/LogEvent.h"
#include "statslog.h"
+#include "stats_log_util.h"
using std::make_shared;
using std::shared_ptr;
@@ -62,7 +63,9 @@
return false;
}
- uint64_t timestamp = time(nullptr) * NS_PER_SEC;
+ int64_t wallClockTimestampNs = getWallClockNs();
+ int64_t elapsedTimestampNs = getElapsedRealtimeNs();
+
char buf[kLineBufferSize];
// first line prints the format and frequencies
fin.getline(buf, kLineBufferSize);
@@ -77,7 +80,8 @@
int idx = 0;
do {
timeMs = std::stoull(pch);
- auto ptr = make_shared<LogEvent>(android::util::CPU_TIME_PER_UID_FREQ, timestamp);
+ auto ptr = make_shared<LogEvent>(android::util::CPU_TIME_PER_UID_FREQ,
+ wallClockTimestampNs, elapsedTimestampNs);
ptr->write(uid);
ptr->write(idx);
ptr->write(timeMs);
diff --git a/cmds/statsd/src/external/CpuTimePerUidPuller.cpp b/cmds/statsd/src/external/CpuTimePerUidPuller.cpp
index d9aeb46..568b8f0 100644
--- a/cmds/statsd/src/external/CpuTimePerUidPuller.cpp
+++ b/cmds/statsd/src/external/CpuTimePerUidPuller.cpp
@@ -24,6 +24,7 @@
#include "guardrail/StatsdStats.h"
#include "logd/LogEvent.h"
#include "statslog.h"
+#include "stats_log_util.h"
using std::make_shared;
using std::shared_ptr;
@@ -57,7 +58,8 @@
return false;
}
- uint64_t timestamp = time(nullptr) * NS_PER_SEC;
+ int64_t wallClockTimestampNs = getWallClockNs();
+ int64_t elapsedTimestampNs = getElapsedRealtimeNs();
char buf[kLineBufferSize];
char* pch;
while (!fin.eof()) {
@@ -70,7 +72,8 @@
pch = strtok(buf, " ");
uint64_t sysTimeMs = std::stoull(pch);
- auto ptr = make_shared<LogEvent>(android::util::CPU_TIME_PER_UID, timestamp);
+ auto ptr = make_shared<LogEvent>(android::util::CPU_TIME_PER_UID,
+ wallClockTimestampNs, elapsedTimestampNs);
ptr->write(uid);
ptr->write(userTimeMs);
ptr->write(sysTimeMs);
diff --git a/cmds/statsd/src/external/KernelUidCpuActiveTimeReader.cpp b/cmds/statsd/src/external/KernelUidCpuActiveTimeReader.cpp
index 0e126e7..0b545cc 100644
--- a/cmds/statsd/src/external/KernelUidCpuActiveTimeReader.cpp
+++ b/cmds/statsd/src/external/KernelUidCpuActiveTimeReader.cpp
@@ -23,6 +23,7 @@
#include "guardrail/StatsdStats.h"
#include "logd/LogEvent.h"
#include "statslog.h"
+#include "stats_log_util.h"
using std::make_shared;
using std::shared_ptr;
@@ -57,7 +58,9 @@
return false;
}
- uint64_t timestamp = time(nullptr) * NS_PER_SEC;
+ int64_t wallClockTimestampNs = getWallClockNs();
+ int64_t elapsedTimestampNs = getElapsedRealtimeNs();
+
char buf[kLineBufferSize];
char* pch;
while (!fin.eof()) {
@@ -70,7 +73,7 @@
int idx = 0;
do {
timeMs = std::stoull(pch);
- auto ptr = make_shared<LogEvent>(mTagId, timestamp);
+ auto ptr = make_shared<LogEvent>(mTagId, wallClockTimestampNs, elapsedTimestampNs);
ptr->write(uid);
ptr->write(idx);
ptr->write(timeMs);
diff --git a/cmds/statsd/src/external/KernelUidCpuClusterTimeReader.cpp b/cmds/statsd/src/external/KernelUidCpuClusterTimeReader.cpp
index 7684ed4..cc80204 100644
--- a/cmds/statsd/src/external/KernelUidCpuClusterTimeReader.cpp
+++ b/cmds/statsd/src/external/KernelUidCpuClusterTimeReader.cpp
@@ -22,6 +22,7 @@
#include "guardrail/StatsdStats.h"
#include "logd/LogEvent.h"
#include "statslog.h"
+#include "stats_log_util.h"
using std::make_shared;
using std::shared_ptr;
@@ -56,7 +57,8 @@
return false;
}
- uint64_t timestamp = time(nullptr) * NS_PER_SEC;
+ int64_t wallClockTimestampNs = getWallClockNs();
+ int64_t elapsedTimestampNs = getElapsedRealtimeNs();
char buf[kLineBufferSize];
char* pch;
while (!fin.eof()) {
@@ -69,7 +71,7 @@
int idx = 0;
do {
timeMs = std::stoull(pch);
- auto ptr = make_shared<LogEvent>(mTagId, timestamp);
+ auto ptr = make_shared<LogEvent>(mTagId, wallClockTimestampNs, elapsedTimestampNs);
ptr->write(uid);
ptr->write(idx);
ptr->write(timeMs);
diff --git a/cmds/statsd/src/external/ResourceHealthManagerPuller.cpp b/cmds/statsd/src/external/ResourceHealthManagerPuller.cpp
index 72fb5ff..261cb43 100644
--- a/cmds/statsd/src/external/ResourceHealthManagerPuller.cpp
+++ b/cmds/statsd/src/external/ResourceHealthManagerPuller.cpp
@@ -25,6 +25,7 @@
#include "ResourceHealthManagerPuller.h"
#include "logd/LogEvent.h"
#include "statslog.h"
+#include "stats_log_util.h"
using android::hardware::hidl_vec;
using android::hardware::health::V2_0::get_health_service;
@@ -61,7 +62,8 @@
return false;
}
- uint64_t timestamp = time(nullptr) * NS_PER_SEC;
+ int64_t wallClockTimestampNs = getWallClockNs();
+ int64_t elapsedTimestampNs = getElapsedRealtimeNs();
data->clear();
bool result_success = true;
@@ -72,12 +74,14 @@
return;
}
if (mTagId == android::util::REMAINING_BATTERY_CAPACITY) {
- auto ptr = make_shared<LogEvent>(android::util::REMAINING_BATTERY_CAPACITY, timestamp);
+ auto ptr = make_shared<LogEvent>(android::util::REMAINING_BATTERY_CAPACITY,
+ wallClockTimestampNs, elapsedTimestampNs);
ptr->write(v.legacy.batteryChargeCounter);
ptr->init();
data->push_back(ptr);
} else if (mTagId == android::util::FULL_BATTERY_CAPACITY) {
- auto ptr = make_shared<LogEvent>(android::util::FULL_BATTERY_CAPACITY, timestamp);
+ auto ptr = make_shared<LogEvent>(android::util::FULL_BATTERY_CAPACITY,
+ wallClockTimestampNs, elapsedTimestampNs);
ptr->write(v.legacy.batteryFullCharge);
ptr->init();
data->push_back(ptr);
diff --git a/cmds/statsd/src/external/StatsCompanionServicePuller.cpp b/cmds/statsd/src/external/StatsCompanionServicePuller.cpp
index 8210c8d..bd859fd 100644
--- a/cmds/statsd/src/external/StatsCompanionServicePuller.cpp
+++ b/cmds/statsd/src/external/StatsCompanionServicePuller.cpp
@@ -22,6 +22,7 @@
#include <private/android_filesystem_config.h>
#include "StatsCompanionServicePuller.h"
#include "StatsService.h"
+#include "stats_log_util.h"
#include "guardrail/StatsdStats.h"
using namespace android;
@@ -53,13 +54,13 @@
return false;
}
data->clear();
- int timestamp = time(nullptr);
+ int32_t timestampSec = getWallClockSec();
for (const StatsLogEventWrapper& it : returned_value) {
log_msg tmp;
tmp.entry_v1.len = it.bytes.size();
// Manually set the header size to 28 bytes to match the pushed log events.
tmp.entry.hdr_size = kLogMsgHeaderSize;
- tmp.entry_v1.sec = timestamp;
+ tmp.entry_v1.sec = timestampSec;
// And set the received bytes starting after the 28 bytes reserved for header.
std::copy(it.bytes.begin(), it.bytes.end(), tmp.buf + kLogMsgHeaderSize);
data->push_back(make_shared<LogEvent>(tmp));
diff --git a/cmds/statsd/src/external/StatsPuller.cpp b/cmds/statsd/src/external/StatsPuller.cpp
index fc0ad7c..9513cc5 100644
--- a/cmds/statsd/src/external/StatsPuller.cpp
+++ b/cmds/statsd/src/external/StatsPuller.cpp
@@ -20,6 +20,7 @@
#include "StatsPuller.h"
#include "guardrail/StatsdStats.h"
#include "puller_util.h"
+#include "stats_log_util.h"
namespace android {
namespace os {
@@ -44,7 +45,7 @@
bool StatsPuller::Pull(std::vector<std::shared_ptr<LogEvent>>* data) {
lock_guard<std::mutex> lock(mLock);
StatsdStats::getInstance().notePull(mTagId);
- long curTime = time(nullptr);
+ long curTime = getElapsedRealtimeSec();
if (curTime - mLastPullTimeSec < mCoolDownSec) {
(*data) = mCachedData;
StatsdStats::getInstance().notePullFromCache(mTagId);
diff --git a/cmds/statsd/src/external/StatsPullerManagerImpl.cpp b/cmds/statsd/src/external/StatsPullerManagerImpl.cpp
index 4c676a7..08c59cf 100644
--- a/cmds/statsd/src/external/StatsPullerManagerImpl.cpp
+++ b/cmds/statsd/src/external/StatsPullerManagerImpl.cpp
@@ -33,6 +33,7 @@
#include "SubsystemSleepStatePuller.h"
#include "logd/LogEvent.h"
#include "statslog.h"
+#include "stats_log_util.h"
#include <iostream>
@@ -165,8 +166,9 @@
if (roundedIntervalMs < mCurrentPullingInterval) {
VLOG("Updating pulling interval %ld", intervalMs);
mCurrentPullingInterval = roundedIntervalMs;
- long currentTimeMs = time(nullptr) * 1000;
- long nextAlarmTimeMs = currentTimeMs + mCurrentPullingInterval - (currentTimeMs - mTimeBaseSec * 1000) % mCurrentPullingInterval;
+ long currentTimeMs = getElapsedRealtimeMillis();
+ long nextAlarmTimeMs = currentTimeMs + mCurrentPullingInterval -
+ (currentTimeMs - mTimeBaseSec * 1000) % mCurrentPullingInterval;
if (mStatsCompanionService != nullptr) {
mStatsCompanionService->setPullingAlarms(nextAlarmTimeMs, mCurrentPullingInterval);
} else {
@@ -195,7 +197,7 @@
void StatsPullerManagerImpl::OnAlarmFired() {
AutoMutex _l(mReceiversLock);
- uint64_t currentTimeMs = time(nullptr) /60 * 60 * 1000;
+ uint64_t currentTimeMs = getElapsedRealtimeMillis();
vector<pair<int, vector<ReceiverInfo*>>> needToPull =
vector<pair<int, vector<ReceiverInfo*>>>();
diff --git a/cmds/statsd/src/external/SubsystemSleepStatePuller.cpp b/cmds/statsd/src/external/SubsystemSleepStatePuller.cpp
index 65a1df0e..4501b64 100644
--- a/cmds/statsd/src/external/SubsystemSleepStatePuller.cpp
+++ b/cmds/statsd/src/external/SubsystemSleepStatePuller.cpp
@@ -36,6 +36,7 @@
#include "SubsystemSleepStatePuller.h"
#include "logd/LogEvent.h"
#include "statslog.h"
+#include "stats_log_util.h"
using android::hardware::hidl_vec;
using android::hardware::power::V1_0::IPower;
@@ -84,20 +85,22 @@
return false;
}
- uint64_t timestamp = time(nullptr) * NS_PER_SEC;
+ int64_t wallClockTimestampNs = getWallClockNs();
+ int64_t elapsedTimestampNs = getElapsedRealtimeNs();
data->clear();
Return<void> ret;
ret = gPowerHalV1_0->getPlatformLowPowerStats(
- [&data, timestamp](hidl_vec<PowerStatePlatformSleepState> states, Status status) {
+ [&data, wallClockTimestampNs, elapsedTimestampNs](hidl_vec<PowerStatePlatformSleepState> states, Status status) {
if (status != Status::SUCCESS) return;
for (size_t i = 0; i < states.size(); i++) {
const PowerStatePlatformSleepState& state = states[i];
- auto statePtr = make_shared<LogEvent>(android::util::SUBSYSTEM_SLEEP_STATE,
- timestamp);
+ auto statePtr = make_shared<LogEvent>(
+ android::util::SUBSYSTEM_SLEEP_STATE,
+ wallClockTimestampNs, elapsedTimestampNs);
statePtr->write(state.name);
statePtr->write("");
statePtr->write(state.totalTransitions);
@@ -109,8 +112,9 @@
(long long)state.totalTransitions,
state.supportedOnlyInSuspend ? 1 : 0);
for (auto voter : state.voters) {
- auto voterPtr = make_shared<LogEvent>(android::util::SUBSYSTEM_SLEEP_STATE,
- timestamp);
+ auto voterPtr = make_shared<LogEvent>(
+ android::util::SUBSYSTEM_SLEEP_STATE,
+ wallClockTimestampNs, elapsedTimestampNs);
voterPtr->write(state.name);
voterPtr->write(voter.name);
voterPtr->write(voter.totalNumberOfTimesVotedSinceBoot);
@@ -135,7 +139,7 @@
android::hardware::power::V1_1::IPower::castFrom(gPowerHalV1_0);
if (gPowerHal_1_1 != nullptr) {
ret = gPowerHal_1_1->getSubsystemLowPowerStats(
- [&data, timestamp](hidl_vec<PowerStateSubsystem> subsystems, Status status) {
+ [&data, wallClockTimestampNs, elapsedTimestampNs](hidl_vec<PowerStateSubsystem> subsystems, Status status) {
if (status != Status::SUCCESS) return;
if (subsystems.size() > 0) {
@@ -145,7 +149,8 @@
const PowerStateSubsystemSleepState& state =
subsystem.states[j];
auto subsystemStatePtr = make_shared<LogEvent>(
- android::util::SUBSYSTEM_SLEEP_STATE, timestamp);
+ android::util::SUBSYSTEM_SLEEP_STATE,
+ wallClockTimestampNs, elapsedTimestampNs);
subsystemStatePtr->write(subsystem.name);
subsystemStatePtr->write(state.name);
subsystemStatePtr->write(state.totalTransitions);
diff --git a/cmds/statsd/src/guardrail/StatsdStats.cpp b/cmds/statsd/src/guardrail/StatsdStats.cpp
index 06c5b00..e2e9426 100644
--- a/cmds/statsd/src/guardrail/StatsdStats.cpp
+++ b/cmds/statsd/src/guardrail/StatsdStats.cpp
@@ -80,7 +80,7 @@
// TODO: add stats for pulled atoms.
StatsdStats::StatsdStats() {
mPushedAtomStats.resize(android::util::kMaxPushedAtomId + 1);
- mStartTimeSec = time(nullptr);
+ mStartTimeSec = getWallClockSec();
}
StatsdStats& StatsdStats::getInstance() {
@@ -99,7 +99,7 @@
void StatsdStats::noteConfigReceived(const ConfigKey& key, int metricsCount, int conditionsCount,
int matchersCount, int alertsCount, bool isValid) {
lock_guard<std::mutex> lock(mLock);
- int32_t nowTimeSec = time(nullptr);
+ int32_t nowTimeSec = getWallClockSec();
// If there is an existing config for the same key, icebox the old config.
noteConfigRemovedInternalLocked(key);
@@ -125,7 +125,7 @@
void StatsdStats::noteConfigRemovedInternalLocked(const ConfigKey& key) {
auto it = mConfigStats.find(key);
if (it != mConfigStats.end()) {
- int32_t nowTimeSec = time(nullptr);
+ int32_t nowTimeSec = getWallClockSec();
it->second.set_deletion_time_sec(nowTimeSec);
// Add condition stats, metrics stats, matcher stats, alert stats
addSubStatsToConfigLocked(key, it->second);
@@ -145,7 +145,7 @@
}
void StatsdStats::noteBroadcastSent(const ConfigKey& key) {
- noteBroadcastSent(key, time(nullptr));
+ noteBroadcastSent(key, getWallClockSec());
}
void StatsdStats::noteBroadcastSent(const ConfigKey& key, int32_t timeSec) {
@@ -164,7 +164,7 @@
}
void StatsdStats::noteDataDropped(const ConfigKey& key) {
- noteDataDropped(key, time(nullptr));
+ noteDataDropped(key, getWallClockSec());
}
void StatsdStats::noteDataDropped(const ConfigKey& key, int32_t timeSec) {
@@ -183,7 +183,7 @@
}
void StatsdStats::noteMetricsReportSent(const ConfigKey& key) {
- noteMetricsReportSent(key, time(nullptr));
+ noteMetricsReportSent(key, getWallClockSec());
}
void StatsdStats::noteMetricsReportSent(const ConfigKey& key, int32_t timeSec) {
@@ -275,10 +275,6 @@
void StatsdStats::noteAtomLogged(int atomId, int32_t timeSec) {
lock_guard<std::mutex> lock(mLock);
- if (timeSec < mStartTimeSec) {
- return;
- }
-
if (atomId > android::util::kMaxPushedAtomId) {
ALOGW("not interested in atom %d", atomId);
return;
@@ -293,7 +289,7 @@
if (mLoggerErrors.size() == kMaxLoggerErrors) {
mLoggerErrors.pop_front();
}
- mLoggerErrors.push_back(std::make_pair(time(nullptr), error));
+ mLoggerErrors.push_back(std::make_pair(getWallClockSec(), error));
}
void StatsdStats::reset() {
@@ -303,7 +299,7 @@
void StatsdStats::resetInternalLocked() {
// Reset the historical data, but keep the active ConfigStats
- mStartTimeSec = time(nullptr);
+ mStartTimeSec = getWallClockSec();
mIceBox.clear();
mConditionStats.clear();
mMetricsStats.clear();
@@ -495,7 +491,7 @@
ProtoOutputStream proto;
proto.write(FIELD_TYPE_INT32 | FIELD_ID_BEGIN_TIME, mStartTimeSec);
- proto.write(FIELD_TYPE_INT32 | FIELD_ID_END_TIME, (int32_t)time(nullptr));
+ proto.write(FIELD_TYPE_INT32 | FIELD_ID_END_TIME, (int32_t)getWallClockSec());
for (const auto& configStats : mIceBox) {
const int numBytes = configStats.ByteSize();
diff --git a/cmds/statsd/src/logd/LogEvent.cpp b/cmds/statsd/src/logd/LogEvent.cpp
index 45fb5da..7489d9b 100644
--- a/cmds/statsd/src/logd/LogEvent.cpp
+++ b/cmds/statsd/src/logd/LogEvent.cpp
@@ -33,7 +33,7 @@
LogEvent::LogEvent(log_msg& msg) {
mContext =
create_android_log_parser(msg.msg() + sizeof(uint32_t), msg.len() - sizeof(uint32_t));
- mTimestampNs = msg.entry_v1.sec * NS_PER_SEC + msg.entry_v1.nsec;
+ mLogdTimestampNs = msg.entry_v1.sec * NS_PER_SEC + msg.entry_v1.nsec;
mLogUid = msg.entry_v4.uid;
init(mContext);
if (mContext) {
@@ -42,12 +42,24 @@
}
}
-LogEvent::LogEvent(int32_t tagId, uint64_t timestampNs) {
- mTimestampNs = timestampNs;
+LogEvent::LogEvent(int32_t tagId, int64_t wallClockTimestampNs, int64_t elapsedTimestampNs) {
+ mLogdTimestampNs = wallClockTimestampNs;
mTagId = tagId;
mLogUid = 0;
mContext = create_android_logger(1937006964); // the event tag shared by all stats logs
if (mContext) {
+ android_log_write_int64(mContext, elapsedTimestampNs);
+ android_log_write_int32(mContext, tagId);
+ }
+}
+
+LogEvent::LogEvent(int32_t tagId, int64_t timestampNs) {
+ mLogdTimestampNs = timestampNs;
+ mTagId = tagId;
+ mLogUid = 0;
+ mContext = create_android_logger(1937006964); // the event tag shared by all stats logs
+ if (mContext) {
+ android_log_write_int64(mContext, timestampNs);
android_log_write_int32(mContext, tagId);
}
}
@@ -176,8 +188,8 @@
elem = android_log_read_next(context);
switch ((int)elem.type) {
case EVENT_TYPE_INT:
- // elem at [0] is EVENT_TYPE_LIST, [1] is the tag id.
- if (i == 1) {
+ // elem at [0] is EVENT_TYPE_LIST, [1] is the timestamp, [2] is tag id.
+ if (i == 2) {
mTagId = elem.data.int32;
} else {
if (depth < 0 || depth > 2) {
@@ -214,15 +226,18 @@
} break;
case EVENT_TYPE_LONG: {
- if (depth < 0 || depth > 2) {
- ALOGE("Depth > 2. Not supported!");
- return;
+ if (i == 1) {
+ mElapsedTimestampNs = elem.data.int64;
+ } else {
+ if (depth < 0 || depth > 2) {
+ ALOGE("Depth > 2. Not supported!");
+ return;
+ }
+ mValues.push_back(
+ FieldValue(Field(mTagId, pos, depth), Value((int64_t)elem.data.int64)));
+
+ pos[depth]++;
}
- mValues.push_back(
- FieldValue(Field(mTagId, pos, depth), Value((int64_t)elem.data.int64)));
-
- pos[depth]++;
-
} break;
case EVENT_TYPE_LIST:
depth++;
@@ -370,7 +385,7 @@
string LogEvent::ToString() const {
ostringstream result;
- result << "{ " << mTimestampNs << " (" << mTagId << ")";
+ result << "{ " << mLogdTimestampNs << " " << mElapsedTimestampNs << " (" << mTagId << ")";
for (const auto& value : mValues) {
result << StringPrintf("%#x", value.mField.getField());
result << "->";
diff --git a/cmds/statsd/src/logd/LogEvent.h b/cmds/statsd/src/logd/LogEvent.h
index 0895daa..b3084d5 100644
--- a/cmds/statsd/src/logd/LogEvent.h
+++ b/cmds/statsd/src/logd/LogEvent.h
@@ -47,14 +47,18 @@
/**
* Constructs a LogEvent with synthetic data for testing. Must call init() before reading.
*/
- explicit LogEvent(int32_t tagId, uint64_t timestampNs);
+ explicit LogEvent(int32_t tagId, int64_t wallClockTimestampNs, int64_t elapsedTimestampNs);
+
+ // For testing. The timestamp is used as both elapsed real time and logd timestamp.
+ explicit LogEvent(int32_t tagId, int64_t timestampNs);
~LogEvent();
/**
* Get the timestamp associated with this event.
*/
- inline uint64_t GetTimestampNs() const { return mTimestampNs; }
+ inline int64_t GetLogdTimestampNs() const { return mLogdTimestampNs; }
+ inline int64_t GetElapsedTimestampNs() const { return mElapsedTimestampNs; }
/**
* Get the tag for this event.
@@ -107,9 +111,18 @@
void init();
/**
- * Set timestamp if the original timestamp is missing.
+ * Set elapsed timestamp if the original timestamp is missing.
*/
- void setTimestampNs(uint64_t timestampNs) {mTimestampNs = timestampNs;}
+ void setElapsedTimestampNs(int64_t timestampNs) {
+ mElapsedTimestampNs = timestampNs;
+ }
+
+ /**
+ * Set the timestamp if the original logd timestamp is missing.
+ */
+ void setLogdWallClockTimestampNs(int64_t timestampNs) {
+ mLogdTimestampNs = timestampNs;
+ }
inline int size() const {
return mValues.size();
@@ -144,7 +157,11 @@
// When the log event is created from log msg, this field is never initiated.
android_log_context mContext = NULL;
- uint64_t mTimestampNs;
+ // The timestamp set by the logd.
+ int64_t mLogdTimestampNs;
+
+ // The elapsed timestamp set by statsd log writer.
+ int64_t mElapsedTimestampNs;
int mTagId;
diff --git a/cmds/statsd/src/metrics/CountMetricProducer.cpp b/cmds/statsd/src/metrics/CountMetricProducer.cpp
index bd2674b..178db1a 100644
--- a/cmds/statsd/src/metrics/CountMetricProducer.cpp
+++ b/cmds/statsd/src/metrics/CountMetricProducer.cpp
@@ -52,8 +52,8 @@
const int FIELD_ID_DIMENSION_IN_CONDITION = 2;
const int FIELD_ID_BUCKET_INFO = 3;
// for CountBucketInfo
-const int FIELD_ID_START_BUCKET_NANOS = 1;
-const int FIELD_ID_END_BUCKET_NANOS = 2;
+const int FIELD_ID_START_BUCKET_ELAPSED_NANOS = 1;
+const int FIELD_ID_END_BUCKET_ELAPSED_NANOS = 2;
const int FIELD_ID_COUNT = 3;
CountMetricProducer::CountMetricProducer(const ConfigKey& key, const CountMetric& metric,
@@ -107,7 +107,6 @@
if (mPastBuckets.empty()) {
return;
}
-
protoOutput->write(FIELD_TYPE_INT64 | FIELD_ID_ID, (long long)mMetricId);
long long protoToken = protoOutput->start(FIELD_TYPE_MESSAGE | FIELD_ID_COUNT_METRICS);
@@ -132,12 +131,13 @@
}
// Then fill bucket_info (CountBucketInfo).
+
for (const auto& bucket : counter.second) {
long long bucketInfoToken = protoOutput->start(
FIELD_TYPE_MESSAGE | FIELD_COUNT_REPEATED | FIELD_ID_BUCKET_INFO);
- protoOutput->write(FIELD_TYPE_INT64 | FIELD_ID_START_BUCKET_NANOS,
+ protoOutput->write(FIELD_TYPE_INT64 | FIELD_ID_START_BUCKET_ELAPSED_NANOS,
(long long)bucket.mBucketStartNs);
- protoOutput->write(FIELD_TYPE_INT64 | FIELD_ID_END_BUCKET_NANOS,
+ protoOutput->write(FIELD_TYPE_INT64 | FIELD_ID_END_BUCKET_ELAPSED_NANOS,
(long long)bucket.mBucketEndNs);
protoOutput->write(FIELD_TYPE_INT64 | FIELD_ID_COUNT, (long long)bucket.mCount);
protoOutput->end(bucketInfoToken);
@@ -184,7 +184,7 @@
const size_t matcherIndex, const MetricDimensionKey& eventKey,
const ConditionKey& conditionKey, bool condition,
const LogEvent& event) {
- uint64_t eventTimeNs = event.GetTimestampNs();
+ uint64_t eventTimeNs = event.GetElapsedTimestampNs();
flushIfNeededLocked(eventTimeNs);
if (condition == false) {
diff --git a/cmds/statsd/src/metrics/DurationMetricProducer.cpp b/cmds/statsd/src/metrics/DurationMetricProducer.cpp
index 6b321e1..af22578c 100644
--- a/cmds/statsd/src/metrics/DurationMetricProducer.cpp
+++ b/cmds/statsd/src/metrics/DurationMetricProducer.cpp
@@ -51,8 +51,8 @@
const int FIELD_ID_DIMENSION_IN_CONDITION = 2;
const int FIELD_ID_BUCKET_INFO = 3;
// for DurationBucketInfo
-const int FIELD_ID_START_BUCKET_NANOS = 1;
-const int FIELD_ID_END_BUCKET_NANOS = 2;
+const int FIELD_ID_START_BUCKET_ELAPSED_NANOS = 1;
+const int FIELD_ID_END_BUCKET_ELAPSED_NANOS = 2;
const int FIELD_ID_DURATION = 3;
DurationMetricProducer::DurationMetricProducer(const ConfigKey& key, const DurationMetric& metric,
@@ -221,9 +221,9 @@
for (const auto& bucket : pair.second) {
long long bucketInfoToken = protoOutput->start(
FIELD_TYPE_MESSAGE | FIELD_COUNT_REPEATED | FIELD_ID_BUCKET_INFO);
- protoOutput->write(FIELD_TYPE_INT64 | FIELD_ID_START_BUCKET_NANOS,
+ protoOutput->write(FIELD_TYPE_INT64 | FIELD_ID_START_BUCKET_ELAPSED_NANOS,
(long long)bucket.mBucketStartNs);
- protoOutput->write(FIELD_TYPE_INT64 | FIELD_ID_END_BUCKET_NANOS,
+ protoOutput->write(FIELD_TYPE_INT64 | FIELD_ID_END_BUCKET_ELAPSED_NANOS,
(long long)bucket.mBucketEndNs);
protoOutput->write(FIELD_TYPE_INT64 | FIELD_ID_DURATION, (long long)bucket.mDuration);
protoOutput->end(bucketInfoToken);
@@ -310,11 +310,11 @@
const size_t matcherIndex, const MetricDimensionKey& eventKey,
const ConditionKey& conditionKeys, bool condition,
const LogEvent& event) {
- flushIfNeededLocked(event.GetTimestampNs());
+ flushIfNeededLocked(event.GetElapsedTimestampNs());
if (matcherIndex == mStopAllIndex) {
for (auto& pair : mCurrentSlicedDurationTrackerMap) {
- pair.second->noteStopAll(event.GetTimestampNs());
+ pair.second->noteStopAll(event.GetElapsedTimestampNs());
}
return;
}
@@ -333,16 +333,16 @@
if (values.empty()) {
if (matcherIndex == mStartIndex) {
it->second->noteStart(DEFAULT_DIMENSION_KEY, condition,
- event.GetTimestampNs(), conditionKeys);
+ event.GetElapsedTimestampNs(), conditionKeys);
} else if (matcherIndex == mStopIndex) {
- it->second->noteStop(DEFAULT_DIMENSION_KEY, event.GetTimestampNs(), false);
+ it->second->noteStop(DEFAULT_DIMENSION_KEY, event.GetElapsedTimestampNs(), false);
}
} else {
for (const auto& value : values) {
if (matcherIndex == mStartIndex) {
- it->second->noteStart(value, condition, event.GetTimestampNs(), conditionKeys);
+ it->second->noteStart(value, condition, event.GetElapsedTimestampNs(), conditionKeys);
} else if (matcherIndex == mStopIndex) {
- it->second->noteStop(value, event.GetTimestampNs(), false);
+ it->second->noteStop(value, event.GetElapsedTimestampNs(), false);
}
}
}
diff --git a/cmds/statsd/src/metrics/EventMetricProducer.cpp b/cmds/statsd/src/metrics/EventMetricProducer.cpp
index ed7e44d..2585aa3 100644
--- a/cmds/statsd/src/metrics/EventMetricProducer.cpp
+++ b/cmds/statsd/src/metrics/EventMetricProducer.cpp
@@ -19,6 +19,7 @@
#include "EventMetricProducer.h"
#include "stats_util.h"
+#include "stats_log_util.h"
#include <limits.h>
#include <stdlib.h>
@@ -46,8 +47,9 @@
// for EventMetricDataWrapper
const int FIELD_ID_DATA = 1;
// for EventMetricData
-const int FIELD_ID_TIMESTAMP_NANOS = 1;
+const int FIELD_ID_ELAPSED_TIMESTAMP_NANOS = 1;
const int FIELD_ID_ATOMS = 2;
+const int FIELD_ID_WALL_CLOCK_TIMESTAMP_NANOS = 3;
EventMetricProducer::EventMetricProducer(const ConfigKey& key, const EventMetric& metric,
const int conditionIndex,
@@ -127,9 +129,12 @@
long long wrapperToken =
mProto->start(FIELD_TYPE_MESSAGE | FIELD_COUNT_REPEATED | FIELD_ID_DATA);
- mProto->write(FIELD_TYPE_INT64 | FIELD_ID_TIMESTAMP_NANOS, (long long)event.GetTimestampNs());
+ mProto->write(FIELD_TYPE_INT64 | FIELD_ID_ELAPSED_TIMESTAMP_NANOS,
+ (long long)event.GetElapsedTimestampNs());
long long eventToken = mProto->start(FIELD_TYPE_MESSAGE | FIELD_ID_ATOMS);
event.ToProto(*mProto);
+ mProto->write(FIELD_TYPE_INT64 | FIELD_ID_WALL_CLOCK_TIMESTAMP_NANOS,
+ (long long)getWallClockNs());
mProto->end(eventToken);
mProto->end(wrapperToken);
}
diff --git a/cmds/statsd/src/metrics/GaugeMetricProducer.cpp b/cmds/statsd/src/metrics/GaugeMetricProducer.cpp
index da0cafe..af3b4c5 100644
--- a/cmds/statsd/src/metrics/GaugeMetricProducer.cpp
+++ b/cmds/statsd/src/metrics/GaugeMetricProducer.cpp
@@ -52,10 +52,10 @@
const int FIELD_ID_DIMENSION_IN_CONDITION = 2;
const int FIELD_ID_BUCKET_INFO = 3;
// for GaugeBucketInfo
-const int FIELD_ID_START_BUCKET_NANOS = 1;
-const int FIELD_ID_END_BUCKET_NANOS = 2;
+const int FIELD_ID_START_BUCKET_ELAPSED_NANOS = 1;
+const int FIELD_ID_END_BUCKET_ELAPSED_NANOS = 2;
const int FIELD_ID_ATOM = 3;
-const int FIELD_ID_TIMESTAMP = 4;
+const int FIELD_ID_ELAPSED_ATOM_TIMESTAMP = 4;
GaugeMetricProducer::GaugeMetricProducer(const ConfigKey& key, const GaugeMetric& metric,
const int conditionIndex,
@@ -161,9 +161,9 @@
for (const auto& bucket : pair.second) {
long long bucketInfoToken = protoOutput->start(
FIELD_TYPE_MESSAGE | FIELD_COUNT_REPEATED | FIELD_ID_BUCKET_INFO);
- protoOutput->write(FIELD_TYPE_INT64 | FIELD_ID_START_BUCKET_NANOS,
+ protoOutput->write(FIELD_TYPE_INT64 | FIELD_ID_START_BUCKET_ELAPSED_NANOS,
(long long)bucket.mBucketStartNs);
- protoOutput->write(FIELD_TYPE_INT64 | FIELD_ID_END_BUCKET_NANOS,
+ protoOutput->write(FIELD_TYPE_INT64 | FIELD_ID_END_BUCKET_ELAPSED_NANOS,
(long long)bucket.mBucketEndNs);
if (!bucket.mGaugeAtoms.empty()) {
@@ -175,8 +175,9 @@
protoOutput->end(atomsToken);
for (const auto& atom : bucket.mGaugeAtoms) {
- protoOutput->write(FIELD_TYPE_INT64 | FIELD_COUNT_REPEATED | FIELD_ID_TIMESTAMP,
- (long long)atom.mTimestamps);
+ protoOutput->write(
+ FIELD_TYPE_INT64 | FIELD_COUNT_REPEATED | FIELD_ID_ELAPSED_ATOM_TIMESTAMP,
+ (long long)atom.mTimestamps);
}
}
protoOutput->end(bucketInfoToken);
@@ -293,7 +294,7 @@
if (condition == false) {
return;
}
- uint64_t eventTimeNs = event.GetTimestampNs();
+ uint64_t eventTimeNs = event.GetElapsedTimestampNs();
mTagId = event.GetTagId();
if (eventTimeNs < mCurrentBucketStartTimeNs) {
VLOG("Skip event due to late arrival: %lld vs %lld", (long long)eventTimeNs,
diff --git a/cmds/statsd/src/metrics/MetricProducer.cpp b/cmds/statsd/src/metrics/MetricProducer.cpp
index beb9015..f3307dc 100644
--- a/cmds/statsd/src/metrics/MetricProducer.cpp
+++ b/cmds/statsd/src/metrics/MetricProducer.cpp
@@ -25,7 +25,7 @@
using std::map;
void MetricProducer::onMatchedLogEventLocked(const size_t matcherIndex, const LogEvent& event) {
- uint64_t eventTimeNs = event.GetTimestampNs();
+ uint64_t eventTimeNs = event.GetElapsedTimestampNs();
// this is old event, maybe statsd restarted?
if (eventTimeNs < mStartTimeNs) {
return;
diff --git a/cmds/statsd/src/metrics/MetricsManager.cpp b/cmds/statsd/src/metrics/MetricsManager.cpp
index dd6735b..ae48c52 100644
--- a/cmds/statsd/src/metrics/MetricsManager.cpp
+++ b/cmds/statsd/src/metrics/MetricsManager.cpp
@@ -26,6 +26,7 @@
#include "matchers/SimpleLogMatchingTracker.h"
#include "metrics_manager_util.h"
#include "stats_util.h"
+#include "stats_log_util.h"
#include <log/logprint.h>
#include <private/android_filesystem_config.h>
@@ -49,9 +50,10 @@
MetricsManager::MetricsManager(const ConfigKey& key, const StatsdConfig& config,
const long timeBaseSec, sp<UidMap> uidMap)
- : mConfigKey(key), mUidMap(uidMap), mLastReportTimeNs(0) {
+ : mConfigKey(key), mUidMap(uidMap), mLastReportTimeNs(timeBaseSec * NS_PER_SEC) {
mConfigValid =
- initStatsdConfig(key, config, *uidMap, timeBaseSec, mTagIds, mAllAtomMatchers, mAllConditionTrackers,
+ initStatsdConfig(key, config, *uidMap, timeBaseSec, mTagIds, mAllAtomMatchers,
+ mAllConditionTrackers,
mAllMetricProducers, mAllAnomalyTrackers, mConditionToMetricMap,
mTrackerToMetricMap, mTrackerToConditionMap, mNoReportMetricIds);
@@ -176,7 +178,7 @@
protoOutput->end(token);
}
}
- mLastReportTimeNs = ::android::elapsedRealtimeNano();
+ mLastReportTimeNs = dumpTimeStampNs;
VLOG("=========================Metric Reports End==========================");
}
@@ -230,7 +232,7 @@
}
int tagId = event.GetTagId();
- uint64_t eventTime = event.GetTimestampNs();
+ uint64_t eventTime = event.GetElapsedTimestampNs();
if (mTagIds.find(tagId) == mTagIds.end()) {
// not interesting...
return;
diff --git a/cmds/statsd/src/metrics/ValueMetricProducer.cpp b/cmds/statsd/src/metrics/ValueMetricProducer.cpp
index 45b4ac0..cbca884 100644
--- a/cmds/statsd/src/metrics/ValueMetricProducer.cpp
+++ b/cmds/statsd/src/metrics/ValueMetricProducer.cpp
@@ -219,19 +219,19 @@
}
// For scheduled pulled data, the effective event time is snap to the nearest
// bucket boundary to make bucket finalize.
- uint64_t realEventTime = allData.at(0)->GetTimestampNs();
+ uint64_t realEventTime = allData.at(0)->GetElapsedTimestampNs();
uint64_t eventTime = mStartTimeNs +
- ((realEventTime - mStartTimeNs)/mBucketSizeNs) * mBucketSizeNs;
+ ((realEventTime - mStartTimeNs) / mBucketSizeNs) * mBucketSizeNs;
mCondition = false;
for (const auto& data : allData) {
- data->setTimestampNs(eventTime-1);
+ data->setElapsedTimestampNs(eventTime - 1);
onMatchedLogEventLocked(0, *data);
}
mCondition = true;
for (const auto& data : allData) {
- data->setTimestampNs(eventTime);
+ data->setElapsedTimestampNs(eventTime);
onMatchedLogEventLocked(0, *data);
}
}
@@ -261,7 +261,7 @@
const size_t matcherIndex, const MetricDimensionKey& eventKey,
const ConditionKey& conditionKey, bool condition,
const LogEvent& event) {
- uint64_t eventTimeNs = event.GetTimestampNs();
+ uint64_t eventTimeNs = event.GetElapsedTimestampNs();
if (eventTimeNs < mCurrentBucketStartTimeNs) {
VLOG("Skip event due to late arrival: %lld vs %lld", (long long)eventTimeNs,
(long long)mCurrentBucketStartTimeNs);
diff --git a/cmds/statsd/src/metrics/ValueMetricProducer.h b/cmds/statsd/src/metrics/ValueMetricProducer.h
index 6701a46..b518f2f 100644
--- a/cmds/statsd/src/metrics/ValueMetricProducer.h
+++ b/cmds/statsd/src/metrics/ValueMetricProducer.h
@@ -62,7 +62,7 @@
// Pretend the pulled data occurs right before the app upgrade event.
mCondition = false;
for (const auto& data : allData) {
- data->setTimestampNs(eventTimeNs - 1);
+ data->setElapsedTimestampNs(eventTimeNs - 1);
onMatchedLogEventLocked(0, *data);
}
@@ -71,7 +71,7 @@
mCondition = true;
for (const auto& data : allData) {
- data->setTimestampNs(eventTimeNs);
+ data->setElapsedTimestampNs(eventTimeNs);
onMatchedLogEventLocked(0, *data);
}
} else { // For pushed value metric, we simply flush and reset the current bucket start.
diff --git a/cmds/statsd/src/packages/UidMap.cpp b/cmds/statsd/src/packages/UidMap.cpp
index 691423e..e322ca4 100644
--- a/cmds/statsd/src/packages/UidMap.cpp
+++ b/cmds/statsd/src/packages/UidMap.cpp
@@ -16,6 +16,7 @@
#define DEBUG true // STOPSHIP if true
#include "Log.h"
+#include "stats_log_util.h"
#include "guardrail/StatsdStats.h"
#include "packages/UidMap.h"
@@ -82,7 +83,7 @@
void UidMap::updateMap(const vector<int32_t>& uid, const vector<int64_t>& versionCode,
const vector<String16>& packageName) {
- updateMap(time(nullptr) * NS_PER_SEC, uid, versionCode, packageName);
+ updateMap(getElapsedRealtimeNs(), uid, versionCode, packageName);
}
void UidMap::updateMap(const int64_t& timestamp, const vector<int32_t>& uid,
@@ -98,7 +99,7 @@
}
auto snapshot = mOutput.add_snapshots();
- snapshot->set_timestamp_nanos(timestamp);
+ snapshot->set_elapsed_timestamp_nanos(timestamp);
for (size_t j = 0; j < uid.size(); j++) {
auto t = snapshot->add_package_info();
t->set_name(string(String8(packageName[j]).string()));
@@ -125,7 +126,7 @@
}
void UidMap::updateApp(const String16& app_16, const int32_t& uid, const int64_t& versionCode) {
- updateApp(time(nullptr) * NS_PER_SEC, app_16, uid, versionCode);
+ updateApp(getElapsedRealtimeNs(), app_16, uid, versionCode);
}
void UidMap::updateApp(const int64_t& timestamp, const String16& app_16, const int32_t& uid,
@@ -137,7 +138,7 @@
auto log = mOutput.add_changes();
log->set_deletion(false);
- log->set_timestamp_nanos(timestamp);
+ log->set_elapsed_timestamp_nanos(timestamp);
log->set_app(appName);
log->set_uid(uid);
log->set_version(versionCode);
@@ -194,7 +195,7 @@
}
void UidMap::removeApp(const String16& app_16, const int32_t& uid) {
- removeApp(time(nullptr) * NS_PER_SEC, app_16, uid);
+ removeApp(getElapsedRealtimeNs(), app_16, uid);
}
void UidMap::getListenerListCopyLocked(vector<wp<PackageInfoListener>>* output) {
@@ -218,7 +219,7 @@
auto log = mOutput.add_changes();
log->set_deletion(true);
- log->set_timestamp_nanos(timestamp);
+ log->set_elapsed_timestamp_nanos(timestamp);
log->set_app(app);
log->set_uid(uid);
mBytesUsed += log->ByteSize();
@@ -305,7 +306,7 @@
}
UidMapping UidMap::getOutput(const ConfigKey& key) {
- return getOutput(time(nullptr) * NS_PER_SEC, key);
+ return getOutput(getElapsedRealtimeNs(), key);
}
UidMapping UidMap::getOutput(const int64_t& timestamp, const ConfigKey& key) {
@@ -321,7 +322,7 @@
auto snapshots = mOutput.mutable_snapshots();
auto it_snapshots = snapshots->cbegin();
while (it_snapshots != snapshots->cend()) {
- if (it_snapshots->timestamp_nanos() < cutoff_nanos) {
+ if (it_snapshots->elapsed_timestamp_nanos() < cutoff_nanos) {
// it_snapshots points to the following element after erasing.
it_snapshots = snapshots->erase(it_snapshots);
} else {
@@ -331,7 +332,7 @@
auto deltas = mOutput.mutable_changes();
auto it_deltas = deltas->cbegin();
while (it_deltas != deltas->cend()) {
- if (it_deltas->timestamp_nanos() < cutoff_nanos) {
+ if (it_deltas->elapsed_timestamp_nanos() < cutoff_nanos) {
// it_snapshots points to the following element after erasing.
it_deltas = deltas->erase(it_deltas);
} else {
@@ -343,7 +344,7 @@
// Produce another snapshot. This results in extra data being uploaded but helps
// ensure we can re-construct the UID->app name, versionCode mapping in server.
auto snapshot = mOutput.add_snapshots();
- snapshot->set_timestamp_nanos(timestamp);
+ snapshot->set_elapsed_timestamp_nanos(timestamp);
for (auto it : mMap) {
auto t = snapshot->add_package_info();
t->set_name(it.second.packageName);
diff --git a/cmds/statsd/src/stats_log.proto b/cmds/statsd/src/stats_log.proto
index b56cffb..b427485 100644
--- a/cmds/statsd/src/stats_log.proto
+++ b/cmds/statsd/src/stats_log.proto
@@ -42,15 +42,17 @@
}
message EventMetricData {
- optional int64 timestamp_nanos = 1;
+ optional int64 elapsed_timestamp_nanos = 1;
optional Atom atom = 2;
+
+ optional int64 wall_clock_timestamp_sec = 3;
}
message CountBucketInfo {
- optional int64 start_bucket_nanos = 1;
+ optional int64 start_bucket_elapsed_nanos = 1;
- optional int64 end_bucket_nanos = 2;
+ optional int64 end_bucket_elapsed_nanos = 2;
optional int64 count = 3;
}
@@ -64,9 +66,9 @@
}
message DurationBucketInfo {
- optional int64 start_bucket_nanos = 1;
+ optional int64 start_bucket_elapsed_nanos = 1;
- optional int64 end_bucket_nanos = 2;
+ optional int64 end_bucket_elapsed_nanos = 2;
optional int64 duration_nanos = 3;
}
@@ -80,9 +82,9 @@
}
message ValueBucketInfo {
- optional int64 start_bucket_nanos = 1;
+ optional int64 start_bucket_elapsed_nanos = 1;
- optional int64 end_bucket_nanos = 2;
+ optional int64 end_bucket_elapsed_nanos = 2;
optional int64 value = 3;
}
@@ -102,7 +104,7 @@
repeated Atom atom = 3;
- repeated int64 timestamp_nanos = 4;
+ repeated int64 elapsed_timestamp_nanos = 4;
}
message GaugeMetricData {
@@ -122,7 +124,7 @@
optional int32 uid = 3;
}
- optional int64 timestamp_nanos = 1;
+ optional int64 elapsed_timestamp_nanos = 1;
repeated PackageInfo package_info = 2;
}
@@ -131,7 +133,7 @@
message Change {
optional bool deletion = 1;
- optional int64 timestamp_nanos = 2;
+ optional int64 elapsed_timestamp_nanos = 2;
optional string app = 3;
optional int32 uid = 4;
@@ -176,9 +178,9 @@
optional UidMapping uid_map = 2;
- optional int64 last_report_nanos = 3;
+ optional int64 last_report_elapsed_nanos = 3;
- optional int64 current_report_nanos = 4;
+ optional int64 current_report_elapsed_nanos = 4;
}
message ConfigMetricsReportList {
diff --git a/cmds/statsd/src/stats_log_util.cpp b/cmds/statsd/src/stats_log_util.cpp
index 86c258b..e735770 100644
--- a/cmds/statsd/src/stats_log_util.cpp
+++ b/cmds/statsd/src/stats_log_util.cpp
@@ -20,6 +20,8 @@
#include <utils/Log.h>
#include <set>
#include <stack>
+#include <utils/Log.h>
+#include <utils/SystemClock.h>
using android::util::FIELD_COUNT_REPEATED;
using android::util::FIELD_TYPE_BOOL;
@@ -263,6 +265,30 @@
protoOutput->end(token);
}
+int64_t getElapsedRealtimeNs() {
+ return ::android::elapsedRealtimeNano();
+}
+
+int64_t getElapsedRealtimeSec() {
+ return ::android::elapsedRealtimeNano() / NS_PER_SEC;
+}
+
+int64_t getElapsedRealtimeMillis() {
+ return ::android::elapsedRealtime();
+}
+
+int64_t getWallClockNs() {
+ return time(nullptr) * NS_PER_SEC;
+}
+
+int64_t getWallClockSec() {
+ return time(nullptr);
+}
+
+int64_t getWallClockMillis() {
+ return time(nullptr) * MS_PER_SEC;
+}
+
} // namespace statsd
} // namespace os
} // namespace android
\ No newline at end of file
diff --git a/cmds/statsd/src/stats_log_util.h b/cmds/statsd/src/stats_log_util.h
index 6583f57..32fe0b8 100644
--- a/cmds/statsd/src/stats_log_util.h
+++ b/cmds/statsd/src/stats_log_util.h
@@ -35,6 +35,24 @@
// Convert the TimeUnit enum to the bucket size in millis.
int64_t TimeUnitToBucketSizeInMillis(TimeUnit unit);
+// Gets the elapsed timestamp in ns.
+int64_t getElapsedRealtimeNs();
+
+// Gets the elapsed timestamp in millis.
+int64_t getElapsedRealtimeMillis();
+
+// Gets the elapsed timestamp in seconds.
+int64_t getElapsedRealtimeSec();
+
+// Gets the wall clock timestamp in ns.
+int64_t getWallClockNs();
+
+// Gets the wall clock timestamp in millis.
+int64_t getWallClockMillis();
+
+// Gets the wall clock timestamp in seconds.
+int64_t getWallClockSec();
+
// Helper function to write PulledAtomStats to ProtoOutputStream
void writePullerStatsToStream(const std::pair<int, StatsdStats::PulledAtomStats>& pair,
util::ProtoOutputStream* protoOutput);
diff --git a/cmds/statsd/src/storage/StorageManager.cpp b/cmds/statsd/src/storage/StorageManager.cpp
index 23bd5561..6a1db72 100644
--- a/cmds/statsd/src/storage/StorageManager.cpp
+++ b/cmds/statsd/src/storage/StorageManager.cpp
@@ -20,6 +20,7 @@
#include "android-base/stringprintf.h"
#include "guardrail/StatsdStats.h"
#include "storage/StorageManager.h"
+#include "stats_log_util.h"
#include <android-base/file.h>
#include <dirent.h>
@@ -252,7 +253,7 @@
string file_name = getFilePath(path, timestamp, uid, configID);
// Check for timestamp and delete if it's too old.
- long fileAge = time(nullptr) - timestamp;
+ long fileAge = getWallClockSec() - timestamp;
if (fileAge > StatsdStats::kMaxAgeSecond) {
deleteFile(file_name.c_str());
}