diff options
author | Android Build Coastguard Worker <android-build-coastguard-worker@google.com> | 2024-04-23 23:18:55 +0000 |
---|---|---|
committer | Android Build Coastguard Worker <android-build-coastguard-worker@google.com> | 2024-04-23 23:18:55 +0000 |
commit | d3da8dce50f4e618b5e66ef90fbe2208b4472141 (patch) | |
tree | 8e0d49059ae08ff6adf8b1303f71059471e5a542 | |
parent | 7fc48af77353b9d2b802d857b7adea2c0a08e0f8 (diff) | |
parent | 64110d4397222b0182070b4a1537befc26102df0 (diff) | |
download | StatsD-sdk-release.tar.gz |
Snap for 11754915 from 64110d4397222b0182070b4a1537befc26102df0 to sdk-releasesdk-release
Change-Id: I0d76707d2a20cc11580894ece6c354220d517619
24 files changed, 471 insertions, 35 deletions
diff --git a/perfetto/README.md b/perfetto/README.md new file mode 100644 index 00000000..765b743f --- /dev/null +++ b/perfetto/README.md @@ -0,0 +1,16 @@ +To push config to be used at device boot automatically + +``` +adb push perfetto/atrace.pbtxt /data/misc/perfetto-configs/boottrace.pbtxt +adb shell setprop persist.debug.perfetto.boottrace 1 +``` + +The output trace will be written at /data/misc/perfetto-traces/boottrace.perfetto-trace. +The file will be removed before a new trace is started. + +``` +adb pull /data/misc/perfetto-traces/boottrace.perfetto-trace +``` + +# Links +- https://perfetto.dev/docs/case-studies/android-boot-tracing diff --git a/perfetto/atrace.pbtxt b/perfetto/atrace.pbtxt new file mode 100644 index 00000000..e5c512c5 --- /dev/null +++ b/perfetto/atrace.pbtxt @@ -0,0 +1,30 @@ +buffers: { + size_kb: 522240 + fill_policy: DISCARD +} +buffers: { + size_kb: 8192 + fill_policy: RING_BUFFER +} +data_sources: { + config { + name: "linux.process_stats" + target_buffer: 1 + process_stats_config { + scan_all_processes_on_start: true + } + } +} +data_sources: { + config { + name: "linux.ftrace" + ftrace_config { + atrace_categories: "binder_driver" + atrace_categories: "binder_lock" + atrace_categories: "sm" + atrace_categories: "ss" + atrace_apps: "*" + } + } +} +duration_ms: 180000 diff --git a/service/java/com/android/server/stats/StatsCompanionService.java b/service/java/com/android/server/stats/StatsCompanionService.java index 16e66fe4..6e920c52 100644 --- a/service/java/com/android/server/stats/StatsCompanionService.java +++ b/service/java/com/android/server/stats/StatsCompanionService.java @@ -755,7 +755,8 @@ public class StatsCompanionService extends IStatsCompanionService.Stub { // Setup receiver for device reboots or shutdowns. filter = new IntentFilter(Intent.ACTION_REBOOT); filter.addAction(Intent.ACTION_SHUTDOWN); - mContext.registerReceiverForAllUsers(shutdownEventReceiver, filter, null, null); + mContext.registerReceiverForAllUsers(shutdownEventReceiver, filter, null, + /* scheduler= */ mHandler); // Register listener for statsd_java properties updates. DeviceConfig.addOnPropertiesChangedListener(NAMESPACE_STATSD_JAVA, diff --git a/statsd/src/StatsLogProcessor.cpp b/statsd/src/StatsLogProcessor.cpp index 27426087..9fe282a3 100644 --- a/statsd/src/StatsLogProcessor.cpp +++ b/statsd/src/StatsLogProcessor.cpp @@ -36,6 +36,7 @@ #include "stats_util.h" #include "statslog_statsd.h" #include "storage/StorageManager.h" +#include "utils/api_tracing.h" using namespace android; using android::base::StringPrintf; @@ -389,6 +390,7 @@ void StatsLogProcessor::resetConfigsLocked(const int64_t timestampNs) { } void StatsLogProcessor::OnLogEvent(LogEvent* event) { + ATRACE_CALL(); OnLogEvent(event, getElapsedRealtimeNs()); } @@ -806,7 +808,9 @@ void StatsLogProcessor::onConfigMetricsReportLocked( } // Data corrupted reason - writeDataCorruptedReasons(tempProto); + writeDataCorruptedReasons(tempProto, FIELD_ID_DATA_CORRUPTED_REASON, + StatsdStats::getInstance().hasEventQueueOverflow(), + StatsdStats::getInstance().hasSocketLoss()); // Estimated memory bytes tempProto.write(FIELD_TYPE_INT64 | FIELD_ID_ESTIMATED_DATA_BYTES, totalSize); @@ -1455,6 +1459,7 @@ void StatsLogProcessor::onUidMapReceived(const int64_t eventTimeNs) { } void StatsLogProcessor::onStatsdInitCompleted(const int64_t elapsedTimeNs) { + ATRACE_CALL(); std::lock_guard<std::mutex> lock(mMetricsMutex); VLOG("Received boot completed signal"); for (const auto& it : mMetricsManagers) { @@ -1511,17 +1516,6 @@ void StatsLogProcessor::updateLogEventFilterLocked() const { mLogEventFilter->setAtomIds(std::move(allAtomIds), this); } -void StatsLogProcessor::writeDataCorruptedReasons(ProtoOutputStream& proto) { - if (StatsdStats::getInstance().hasEventQueueOverflow()) { - proto.write(FIELD_TYPE_INT32 | FIELD_COUNT_REPEATED | FIELD_ID_DATA_CORRUPTED_REASON, - DATA_CORRUPTED_EVENT_QUEUE_OVERFLOW); - } - if (StatsdStats::getInstance().hasSocketLoss()) { - proto.write(FIELD_TYPE_INT32 | FIELD_COUNT_REPEATED | FIELD_ID_DATA_CORRUPTED_REASON, - DATA_CORRUPTED_SOCKET_LOSS); - } -} - bool StatsLogProcessor::validateAppBreadcrumbEvent(const LogEvent& event) const { if (event.GetTagId() == util::APP_BREADCRUMB_REPORTED) { // Check that app breadcrumb reported fields are valid. diff --git a/statsd/src/StatsLogProcessor.h b/statsd/src/StatsLogProcessor.h index b6d66af9..c5faaf25 100644 --- a/statsd/src/StatsLogProcessor.h +++ b/statsd/src/StatsLogProcessor.h @@ -327,8 +327,6 @@ private: /* Tells LogEventFilter about atom ids to parse */ void updateLogEventFilterLocked() const; - void writeDataCorruptedReasons(ProtoOutputStream& proto); - bool validateAppBreadcrumbEvent(const LogEvent& event) const; // Function used to send a broadcast so that receiver for the config key can call getData diff --git a/statsd/src/StatsService.cpp b/statsd/src/StatsService.cpp index b5d3d75b..9cbd7b12 100644 --- a/statsd/src/StatsService.cpp +++ b/statsd/src/StatsService.cpp @@ -43,6 +43,7 @@ #include "storage/StorageManager.h" #include "subscriber/SubscriberReporter.h" #include "utils/DbUtils.h" +#include "utils/api_tracing.h" using namespace android; @@ -237,6 +238,7 @@ StatsService::StatsService(const sp<UidMap>& uidMap, shared_ptr<LogEventQueue> q } StatsService::~StatsService() { + ATRACE_CALL(); if (mEventQueue != nullptr) { stopReadingLogs(); mLogsReaderThread->join(); @@ -987,6 +989,7 @@ bool StatsService::getUidFromString(const char* s, int32_t& uid) { } Status StatsService::informAllUidData(const ScopedFileDescriptor& fd) { + ATRACE_CALL(); ENFORCE_UID(AID_SYSTEM); // Parse fd into proto. @@ -1004,6 +1007,7 @@ Status StatsService::informAllUidData(const ScopedFileDescriptor& fd) { Status StatsService::informOnePackage(const string& app, int32_t uid, int64_t version, const string& versionString, const string& installer, const vector<uint8_t>& certificateHash) { + ATRACE_CALL(); ENFORCE_UID(AID_SYSTEM); VLOG("StatsService::informOnePackage was called"); @@ -1014,6 +1018,7 @@ Status StatsService::informOnePackage(const string& app, int32_t uid, int64_t ve } Status StatsService::informOnePackageRemoved(const string& app, int32_t uid) { + ATRACE_CALL(); ENFORCE_UID(AID_SYSTEM); VLOG("StatsService::informOnePackageRemoved was called"); @@ -1029,6 +1034,7 @@ Status StatsService::informAnomalyAlarmFired() { } Status StatsService::informAlarmForSubscriberTriggeringFired() { + ATRACE_CALL(); ENFORCE_UID(AID_SYSTEM); VLOG("StatsService::informAlarmForSubscriberTriggeringFired was called"); @@ -1045,6 +1051,7 @@ Status StatsService::informAlarmForSubscriberTriggeringFired() { } Status StatsService::informPollAlarmFired() { + ATRACE_CALL(); ENFORCE_UID(AID_SYSTEM); VLOG("StatsService::informPollAlarmFired was called"); @@ -1054,6 +1061,7 @@ Status StatsService::informPollAlarmFired() { } Status StatsService::systemRunning() { + ATRACE_CALL(); ENFORCE_UID(AID_SYSTEM); // When system_server is up and running, schedule the dropbox task to run. @@ -1063,6 +1071,7 @@ Status StatsService::systemRunning() { } Status StatsService::informDeviceShutdown() { + ATRACE_CALL(); ENFORCE_UID(AID_SYSTEM); VLOG("StatsService::informDeviceShutdown"); int64_t elapsedRealtimeNs = getElapsedRealtimeNs(); @@ -1084,6 +1093,7 @@ void StatsService::sayHiToStatsCompanion() { } Status StatsService::statsCompanionReady() { + ATRACE_CALL(); ENFORCE_UID(AID_SYSTEM); VLOG("StatsService::statsCompanionReady was called"); @@ -1102,6 +1112,7 @@ Status StatsService::statsCompanionReady() { } Status StatsService::bootCompleted() { + ATRACE_CALL(); ENFORCE_UID(AID_SYSTEM); VLOG("StatsService::bootCompleted was called"); @@ -1125,6 +1136,7 @@ void StatsService::onStatsdInitCompleted() { } void StatsService::Startup() { + ATRACE_CALL(); mConfigManager->Startup(); int64_t wallClockNs = getWallClockNs(); int64_t elapsedRealtimeNs = getElapsedRealtimeNs(); @@ -1134,6 +1146,7 @@ void StatsService::Startup() { } void StatsService::Terminate() { + ATRACE_CALL(); ALOGI("StatsService::Terminating"); if (mProcessor != nullptr) { int64_t elapsedRealtimeNs = getElapsedRealtimeNs(); @@ -1154,6 +1167,7 @@ void StatsService::OnLogEvent(LogEvent* event) { } Status StatsService::getData(int64_t key, const int32_t callingUid, vector<uint8_t>* output) { + ATRACE_CALL(); ENFORCE_UID(AID_SYSTEM); getDataChecked(key, callingUid, output); return Status::ok(); @@ -1161,6 +1175,7 @@ Status StatsService::getData(int64_t key, const int32_t callingUid, vector<uint8 Status StatsService::getDataFd(int64_t key, const int32_t callingUid, const ScopedFileDescriptor& fd) { + ATRACE_CALL(); ENFORCE_UID(AID_SYSTEM); vector<uint8_t> reportData; getDataChecked(key, callingUid, &reportData); @@ -1197,6 +1212,7 @@ void StatsService::getDataChecked(int64_t key, const int32_t callingUid, vector< } Status StatsService::getMetadata(vector<uint8_t>* output) { + ATRACE_CALL(); ENFORCE_UID(AID_SYSTEM); StatsdStats::getInstance().dumpStats(output, false); // Don't reset the counters. @@ -1205,6 +1221,7 @@ Status StatsService::getMetadata(vector<uint8_t>* output) { Status StatsService::addConfiguration(int64_t key, const vector <uint8_t>& config, const int32_t callingUid) { + ATRACE_CALL(); ENFORCE_UID(AID_SYSTEM); if (addConfigurationChecked(callingUid, key, config)) { @@ -1228,6 +1245,7 @@ bool StatsService::addConfigurationChecked(int uid, int64_t key, const vector<ui Status StatsService::removeDataFetchOperation(int64_t key, const int32_t callingUid) { + ATRACE_CALL(); ENFORCE_UID(AID_SYSTEM); ConfigKey configKey(callingUid, key); mConfigManager->RemoveConfigReceiver(configKey); @@ -1237,6 +1255,7 @@ Status StatsService::removeDataFetchOperation(int64_t key, Status StatsService::setDataFetchOperation(int64_t key, const shared_ptr<IPendingIntentRef>& pir, const int32_t callingUid) { + ATRACE_CALL(); ENFORCE_UID(AID_SYSTEM); ConfigKey configKey(callingUid, key); @@ -1252,6 +1271,7 @@ Status StatsService::setDataFetchOperation(int64_t key, Status StatsService::setActiveConfigsChangedOperation(const shared_ptr<IPendingIntentRef>& pir, const int32_t callingUid, vector<int64_t>* output) { + ATRACE_CALL(); ENFORCE_UID(AID_SYSTEM); mConfigManager->SetActiveConfigsChangedReceiver(callingUid, pir); @@ -1264,6 +1284,7 @@ Status StatsService::setActiveConfigsChangedOperation(const shared_ptr<IPendingI } Status StatsService::removeActiveConfigsChangedOperation(const int32_t callingUid) { + ATRACE_CALL(); ENFORCE_UID(AID_SYSTEM); mConfigManager->RemoveActiveConfigsChangedReceiver(callingUid); @@ -1271,6 +1292,7 @@ Status StatsService::removeActiveConfigsChangedOperation(const int32_t callingUi } Status StatsService::removeConfiguration(int64_t key, const int32_t callingUid) { + ATRACE_CALL(); ENFORCE_UID(AID_SYSTEM); ConfigKey configKey(callingUid, key); @@ -1282,6 +1304,7 @@ Status StatsService::setBroadcastSubscriber(int64_t configId, int64_t subscriberId, const shared_ptr<IPendingIntentRef>& pir, const int32_t callingUid) { + ATRACE_CALL(); VLOG("StatsService::setBroadcastSubscriber called."); ENFORCE_UID(AID_SYSTEM); @@ -1299,6 +1322,7 @@ Status StatsService::setBroadcastSubscriber(int64_t configId, Status StatsService::unsetBroadcastSubscriber(int64_t configId, int64_t subscriberId, const int32_t callingUid) { + ATRACE_CALL(); ENFORCE_UID(AID_SYSTEM); VLOG("StatsService::unsetBroadcastSubscriber called."); @@ -1309,6 +1333,7 @@ Status StatsService::unsetBroadcastSubscriber(int64_t configId, } Status StatsService::allPullersFromBootRegistered() { + ATRACE_CALL(); ENFORCE_UID(AID_SYSTEM); VLOG("StatsService::allPullersFromBootRegistered was called"); @@ -1320,6 +1345,7 @@ Status StatsService::registerPullAtomCallback(int32_t uid, int32_t atomTag, int6 int64_t timeoutMillis, const std::vector<int32_t>& additiveFields, const shared_ptr<IPullAtomCallback>& pullerCallback) { + ATRACE_CALL(); ENFORCE_UID(AID_SYSTEM); VLOG("StatsService::registerPullAtomCallback called."); mPullerManager->RegisterPullAtomCallback(uid, atomTag, MillisToNano(coolDownMillis), @@ -1332,6 +1358,7 @@ Status StatsService::registerNativePullAtomCallback( int32_t atomTag, int64_t coolDownMillis, int64_t timeoutMillis, const std::vector<int32_t>& additiveFields, const shared_ptr<IPullAtomCallback>& pullerCallback) { + ATRACE_CALL(); if (!checkPermission(kPermissionRegisterPullAtom)) { return exception( EX_SECURITY, @@ -1347,6 +1374,7 @@ Status StatsService::registerNativePullAtomCallback( } Status StatsService::unregisterPullAtomCallback(int32_t uid, int32_t atomTag) { + ATRACE_CALL(); ENFORCE_UID(AID_SYSTEM); VLOG("StatsService::unregisterPullAtomCallback called."); mPullerManager->UnregisterPullAtomCallback(uid, atomTag); @@ -1354,6 +1382,7 @@ Status StatsService::unregisterPullAtomCallback(int32_t uid, int32_t atomTag) { } Status StatsService::unregisterNativePullAtomCallback(int32_t atomTag) { + ATRACE_CALL(); if (!checkPermission(kPermissionRegisterPullAtom)) { return exception( EX_SECURITY, @@ -1367,6 +1396,7 @@ Status StatsService::unregisterNativePullAtomCallback(int32_t atomTag) { } Status StatsService::getRegisteredExperimentIds(std::vector<int64_t>* experimentIdsOut) { + ATRACE_CALL(); ENFORCE_UID(AID_SYSTEM); // TODO: add verifier permission @@ -1396,6 +1426,7 @@ Status StatsService::updateProperties(const vector<PropertyParcel>& properties) } void StatsService::statsCompanionServiceDied(void* cookie) { + ATRACE_CALL(); auto thiz = static_cast<StatsService*>(cookie); thiz->statsCompanionServiceDiedImpl(); } @@ -1434,6 +1465,7 @@ Status StatsService::setRestrictedMetricsChangedOperation(const int64_t configId const shared_ptr<IPendingIntentRef>& pir, const int32_t callingUid, vector<int64_t>* output) { + ATRACE_CALL(); ENFORCE_UID(AID_SYSTEM); if (!isAtLeastU()) { ALOGW("setRestrictedMetricsChangedOperation invoked on U- device"); @@ -1451,6 +1483,7 @@ Status StatsService::setRestrictedMetricsChangedOperation(const int64_t configId Status StatsService::removeRestrictedMetricsChangedOperation(const int64_t configId, const string& configPackage, const int32_t callingUid) { + ATRACE_CALL(); ENFORCE_UID(AID_SYSTEM); if (!isAtLeastU()) { ALOGW("removeRestrictedMetricsChangedOperation invoked on U- device"); @@ -1465,6 +1498,7 @@ Status StatsService::querySql(const string& sqlQuery, const int32_t minSqlClient const shared_ptr<IStatsQueryCallback>& callback, const int64_t configKey, const string& configPackage, const int32_t callingUid) { + ATRACE_CALL(); ENFORCE_UID(AID_SYSTEM); if (callback == nullptr) { ALOGW("querySql called with null callback."); @@ -1480,6 +1514,7 @@ Status StatsService::querySql(const string& sqlQuery, const int32_t minSqlClient Status StatsService::addSubscription(const vector<uint8_t>& subscriptionConfig, const shared_ptr<IStatsSubscriptionCallback>& callback) { + ATRACE_CALL(); ENFORCE_SID(kTracedProbesSid); initShellSubscriber(); @@ -1489,6 +1524,7 @@ Status StatsService::addSubscription(const vector<uint8_t>& subscriptionConfig, } Status StatsService::removeSubscription(const shared_ptr<IStatsSubscriptionCallback>& callback) { + ATRACE_CALL(); ENFORCE_SID(kTracedProbesSid); if (mShellSubscriber != nullptr) { @@ -1498,6 +1534,7 @@ Status StatsService::removeSubscription(const shared_ptr<IStatsSubscriptionCallb } Status StatsService::flushSubscription(const shared_ptr<IStatsSubscriptionCallback>& callback) { + ATRACE_CALL(); ENFORCE_SID(kTracedProbesSid); if (mShellSubscriber != nullptr) { diff --git a/statsd/src/external/StatsPuller.cpp b/statsd/src/external/StatsPuller.cpp index 0051b0c3..e0fce5e2 100644 --- a/statsd/src/external/StatsPuller.cpp +++ b/statsd/src/external/StatsPuller.cpp @@ -18,10 +18,12 @@ #include "Log.h" #include "StatsPuller.h" + #include "StatsPullerManager.h" #include "guardrail/StatsdStats.h" #include "puller_util.h" #include "stats_log_util.h" +#include "utils/api_tracing.h" namespace android { namespace os { @@ -44,6 +46,7 @@ StatsPuller::StatsPuller(const int tagId, const int64_t coolDownNs, const int64_ PullErrorCode StatsPuller::Pull(const int64_t eventTimeNs, std::vector<std::shared_ptr<LogEvent>>* data) { + ATRACE_CALL(); lock_guard<std::mutex> lock(mLock); const int64_t elapsedTimeNs = getElapsedRealtimeNs(); const int64_t systemUptimeMillis = getSystemUptimeMillis(); diff --git a/statsd/src/external/StatsPullerManager.cpp b/statsd/src/external/StatsPullerManager.cpp index df36d832..bba32b99 100644 --- a/statsd/src/external/StatsPullerManager.cpp +++ b/statsd/src/external/StatsPullerManager.cpp @@ -54,12 +54,14 @@ StatsPullerManager::StatsPullerManager() bool StatsPullerManager::Pull(int tagId, const ConfigKey& configKey, const int64_t eventTimeNs, vector<shared_ptr<LogEvent>>* data) { + ATRACE_CALL(); std::lock_guard<std::mutex> _l(mLock); return PullLocked(tagId, configKey, eventTimeNs, data); } bool StatsPullerManager::Pull(int tagId, const vector<int32_t>& uids, const int64_t eventTimeNs, vector<std::shared_ptr<LogEvent>>* data) { + ATRACE_CALL(); std::lock_guard<std::mutex> _l(mLock); return PullLocked(tagId, uids, eventTimeNs, data); } @@ -217,6 +219,7 @@ void StatsPullerManager::UnregisterPullUidProvider(const ConfigKey& configKey, } void StatsPullerManager::OnAlarmFired(int64_t elapsedTimeNs) { + ATRACE_CALL(); std::lock_guard<std::mutex> _l(mLock); int64_t wallClockNs = getWallClockNs(); @@ -294,6 +297,7 @@ void StatsPullerManager::OnAlarmFired(int64_t elapsedTimeNs) { } int StatsPullerManager::ForceClearPullerCache() { + ATRACE_CALL(); std::lock_guard<std::mutex> _l(mLock); int totalCleared = 0; for (const auto& pulledAtom : kAllPullAtomInfo) { @@ -303,6 +307,7 @@ int StatsPullerManager::ForceClearPullerCache() { } int StatsPullerManager::ClearPullerCacheIfNecessary(int64_t timestampNs) { + ATRACE_CALL(); std::lock_guard<std::mutex> _l(mLock); int totalCleared = 0; for (const auto& pulledAtom : kAllPullAtomInfo) { @@ -315,6 +320,7 @@ void StatsPullerManager::RegisterPullAtomCallback(const int uid, const int32_t a const int64_t coolDownNs, const int64_t timeoutNs, const vector<int32_t>& additiveFields, const shared_ptr<IPullAtomCallback>& callback) { + ATRACE_CALL(); std::lock_guard<std::mutex> _l(mLock); VLOG("RegisterPullerCallback: adding puller for tag %d", atomTag); @@ -339,6 +345,7 @@ void StatsPullerManager::RegisterPullAtomCallback(const int uid, const int32_t a } void StatsPullerManager::UnregisterPullAtomCallback(const int uid, const int32_t atomTag) { + ATRACE_CALL(); std::lock_guard<std::mutex> _l(mLock); PullerKey key = {.uid = uid, .atomTag = atomTag}; if (kAllPullAtomInfo.find(key) != kAllPullAtomInfo.end()) { diff --git a/statsd/src/guardrail/StatsdStats.cpp b/statsd/src/guardrail/StatsdStats.cpp index 191ea3fa..2d9586f4 100644 --- a/statsd/src/guardrail/StatsdStats.cpp +++ b/statsd/src/guardrail/StatsdStats.cpp @@ -1206,7 +1206,8 @@ void StatsdStats::dumpStats(int out) const { auto dropBytesPtr = configStats->data_drop_bytes.begin(); for (int i = 0; i < (int)configStats->data_drop_time_sec.size(); i++, dropTimePtr++, dropBytesPtr++) { - dprintf(out, "\tdata drop time: %d with size %lld", *dropTimePtr, + dprintf(out, "\tdata drop time: %s(%lld) with %lld bytes\n", + buildTimeString(*dropTimePtr).c_str(), (long long)*dropTimePtr, (long long)*dropBytesPtr); } diff --git a/statsd/src/metrics/EventMetricProducer.cpp b/statsd/src/metrics/EventMetricProducer.cpp index a8f45391..648e21c9 100644 --- a/statsd/src/metrics/EventMetricProducer.cpp +++ b/statsd/src/metrics/EventMetricProducer.cpp @@ -49,6 +49,8 @@ const int FIELD_ID_ID = 1; const int FIELD_ID_EVENT_METRICS = 4; const int FIELD_ID_IS_ACTIVE = 14; const int FIELD_ID_ESTIMATED_MEMORY_BYTES = 18; +const int FIELD_ID_DATA_CORRUPTED_REASON = 19; + // for EventMetricDataWrapper const int FIELD_ID_DATA = 1; // for EventMetricData @@ -138,6 +140,8 @@ optional<InvalidConfigReason> EventMetricProducer::onConfigUpdatedLocked( void EventMetricProducer::dropDataLocked(const int64_t dropTimeNs) { mAggregatedAtoms.clear(); mTotalSize = 0; + mDataCorruptedDueToSocketLoss = false; + mDataCorruptedDueToQueueOverflow = false; StatsdStats::getInstance().noteBucketDropped(mMetricId); } @@ -165,6 +169,8 @@ std::unique_ptr<std::vector<uint8_t>> serializeProtoLocked(ProtoOutputStream& pr void EventMetricProducer::clearPastBucketsLocked(const int64_t dumpTimeNs) { mAggregatedAtoms.clear(); mTotalSize = 0; + mDataCorruptedDueToSocketLoss = false; + mDataCorruptedDueToQueueOverflow = false; } void EventMetricProducer::onDumpReportLocked(const int64_t dumpTimeNs, @@ -177,6 +183,9 @@ void EventMetricProducer::onDumpReportLocked(const int64_t dumpTimeNs, protoOutput->write(FIELD_TYPE_BOOL | FIELD_ID_IS_ACTIVE, isActiveLocked()); protoOutput->write(FIELD_TYPE_INT64 | FIELD_ID_ESTIMATED_MEMORY_BYTES, (long long)byteSizeLocked()); + // Data corrupted reason + writeDataCorruptedReasons(*protoOutput, FIELD_ID_DATA_CORRUPTED_REASON, + mDataCorruptedDueToQueueOverflow, mDataCorruptedDueToSocketLoss); uint64_t protoToken = protoOutput->start(FIELD_TYPE_MESSAGE | FIELD_ID_EVENT_METRICS); for (const auto& [atomDimensionKey, elapsedTimestampsNs] : mAggregatedAtoms) { @@ -197,10 +206,13 @@ void EventMetricProducer::onDumpReportLocked(const int64_t dumpTimeNs, protoOutput->end(aggregatedToken); protoOutput->end(wrapperToken); } + protoOutput->end(protoToken); if (erase_data) { mAggregatedAtoms.clear(); mTotalSize = 0; + mDataCorruptedDueToSocketLoss = false; + mDataCorruptedDueToQueueOverflow = false; } } diff --git a/statsd/src/metrics/GaugeMetricProducer.h b/statsd/src/metrics/GaugeMetricProducer.h index fbcab81f..18e0b43c 100644 --- a/statsd/src/metrics/GaugeMetricProducer.h +++ b/statsd/src/metrics/GaugeMetricProducer.h @@ -96,8 +96,8 @@ public: // GaugeMetric needs to immediately trigger another pull when we create the partial bucket. void onStatsdInitCompleted(int64_t eventTimeNs) override { + ATRACE_CALL(); std::lock_guard<std::mutex> lock(mMutex); - flushLocked(eventTimeNs); if (mIsPulled && mSamplingType == GaugeMetric::RANDOM_ONE_SAMPLE && mIsActive) { pullAndMatchEventsLocked(eventTimeNs); diff --git a/statsd/src/metrics/MetricProducer.cpp b/statsd/src/metrics/MetricProducer.cpp index 14c07a8a..ad2c8ccc 100644 --- a/statsd/src/metrics/MetricProducer.cpp +++ b/statsd/src/metrics/MetricProducer.cpp @@ -34,7 +34,6 @@ namespace android { namespace os { namespace statsd { - // for ActiveMetric const int FIELD_ID_ACTIVE_METRIC_ID = 1; const int FIELD_ID_ACTIVE_METRIC_ACTIVATION = 2; @@ -187,6 +186,11 @@ void MetricProducer::onMatchedLogEventLocked(const size_t matcherIndex, const Lo statePrimaryKeys); } +void MetricProducer::onMatchedLogEventLostLocked(int32_t /*atomId*/, DataCorruptedReason reason) { + mDataCorruptedDueToSocketLoss |= reason == DATA_CORRUPTED_SOCKET_LOSS; + mDataCorruptedDueToQueueOverflow |= reason == DATA_CORRUPTED_EVENT_QUEUE_OVERFLOW; +} + bool MetricProducer::evaluateActiveStateLocked(int64_t elapsedTimestampNs) { bool isActive = mEventActivationMap.empty(); for (auto& it : mEventActivationMap) { diff --git a/statsd/src/metrics/MetricProducer.h b/statsd/src/metrics/MetricProducer.h index eee20064..d134425e 100644 --- a/statsd/src/metrics/MetricProducer.h +++ b/statsd/src/metrics/MetricProducer.h @@ -18,6 +18,7 @@ #define METRIC_PRODUCER_H #include <src/active_config_list.pb.h> +#include <src/guardrail/stats_log_enums.pb.h> #include <utils/RefBase.h> #include <unordered_map> @@ -37,6 +38,7 @@ #include "state/StateManager.h" #include "utils/DbUtils.h" #include "utils/ShardOffsetProvider.h" +#include "utils/api_tracing.h" namespace android { namespace os { @@ -197,15 +199,22 @@ public: * Force a partial bucket split on boot complete. */ virtual void onStatsdInitCompleted(int64_t eventTimeNs) { + ATRACE_CALL(); std::lock_guard<std::mutex> lock(mMutex); flushLocked(eventTimeNs); } + // Consume the parsed stats log entry that already matched the "what" of the metric. void onMatchedLogEvent(const size_t matcherIndex, const LogEvent& event) { std::lock_guard<std::mutex> lock(mMutex); onMatchedLogEventLocked(matcherIndex, event); } + void onMatchedLogEventLost(int32_t atomId, DataCorruptedReason reason) { + std::lock_guard<std::mutex> lock(mMutex); + onMatchedLogEventLostLocked(atomId, reason); + } + void onConditionChanged(const bool condition, int64_t eventTime) { std::lock_guard<std::mutex> lock(mMutex); onConditionChangedLocked(condition, eventTime); @@ -234,8 +243,8 @@ public: std::set<string> *str_set, android::util::ProtoOutputStream* protoOutput) { std::lock_guard<std::mutex> lock(mMutex); - return onDumpReportLocked(dumpTimeNs, include_current_partial_bucket, erase_data, - dumpLatency, str_set, protoOutput); + onDumpReportLocked(dumpTimeNs, include_current_partial_bucket, erase_data, dumpLatency, + str_set, protoOutput); } virtual optional<InvalidConfigReason> onConfigUpdatedLocked( @@ -256,7 +265,7 @@ public: void clearPastBuckets(const int64_t dumpTimeNs) { std::lock_guard<std::mutex> lock(mMutex); - return clearPastBucketsLocked(dumpTimeNs); + clearPastBucketsLocked(dumpTimeNs); } void prepareFirstBucket() { @@ -430,14 +439,14 @@ protected: // Consume the parsed stats log entry that already matched the "what" of the metric. virtual void onMatchedLogEventLocked(const size_t matcherIndex, const LogEvent& event); + virtual void onMatchedLogEventLostLocked(int32_t atomId, DataCorruptedReason reason); virtual void onConditionChangedLocked(const bool condition, int64_t eventTime) = 0; virtual void onSlicedConditionMayChangeLocked(bool overallCondition, const int64_t eventTime) = 0; virtual void onDumpReportLocked(const int64_t dumpTimeNs, const bool include_current_partial_bucket, - const bool erase_data, - const DumpLatency dumpLatency, - std::set<string> *str_set, + const bool erase_data, const DumpLatency dumpLatency, + std::set<string>* str_set, android::util::ProtoOutputStream* protoOutput) = 0; virtual void clearPastBucketsLocked(const int64_t dumpTimeNs) = 0; virtual void prepareFirstBucketLocked(){}; @@ -584,6 +593,8 @@ protected: } wp<ConfigMetadataProvider> mConfigMetadataProvider; + bool mDataCorruptedDueToSocketLoss = false; + bool mDataCorruptedDueToQueueOverflow = false; FRIEND_TEST(CountMetricE2eTest, TestSlicedState); FRIEND_TEST(CountMetricE2eTest, TestSlicedStateWithMap); @@ -622,6 +633,9 @@ protected: FRIEND_TEST(ValueMetricE2eTest, TestInitWithSlicedState_WithIncorrectDimensions); FRIEND_TEST(ValueMetricE2eTest, TestInitialConditionChanges); + FRIEND_TEST(MetricsManagerTest, TestOnLogEventLossForAllowedFromAnyUidAtom); + FRIEND_TEST(MetricsManagerTest, TestOnLogEventLossForNotAllowedAtom); + FRIEND_TEST(MetricsManagerUtilTest, TestInitialConditions); FRIEND_TEST(MetricsManagerUtilTest, TestSampledMetrics); @@ -632,6 +646,10 @@ protected: FRIEND_TEST(ConfigUpdateTest, TestUpdateDurationMetrics); FRIEND_TEST(ConfigUpdateTest, TestUpdateMetricsMultipleTypes); FRIEND_TEST(ConfigUpdateTest, TestUpdateAlerts); + + FRIEND_TEST(EventMetricProducerTest, TestCorruptedDataReasonSocketLoss_OnDumpReport); + FRIEND_TEST(EventMetricProducerTest, TestCorruptedDataReasonSocketLoss_OnDropData); + FRIEND_TEST(EventMetricProducerTest, TestCorruptedDataReasonSocketLoss_OnClearPastBuckets); }; } // namespace statsd diff --git a/statsd/src/metrics/MetricsManager.cpp b/statsd/src/metrics/MetricsManager.cpp index 12a3f27b..1ab1e382 100644 --- a/statsd/src/metrics/MetricsManager.cpp +++ b/statsd/src/metrics/MetricsManager.cpp @@ -34,6 +34,7 @@ #include "stats_util.h" #include "statslog_statsd.h" #include "utils/DbUtils.h" +#include "utils/api_tracing.h" using android::util::FIELD_COUNT_REPEATED; using android::util::FIELD_TYPE_INT32; @@ -421,6 +422,7 @@ void MetricsManager::onUidMapReceived(const int64_t eventTimeNs) { } void MetricsManager::onStatsdInitCompleted(const int64_t eventTimeNs) { + ATRACE_CALL(); // Inform all metric producers. for (const auto& it : mAllMetricProducers) { it->onStatsdInitCompleted(eventTimeNs); @@ -513,20 +515,19 @@ void MetricsManager::onDumpReport(const int64_t dumpTimeStampNs, const int64_t w VLOG("=========================Metric Reports End=========================="); } -bool MetricsManager::checkLogCredentials(const LogEvent& event) { - if (mWhitelistedAtomIds.find(event.GetTagId()) != mWhitelistedAtomIds.end()) { +bool MetricsManager::checkLogCredentials(const int32_t uid, const int32_t atomId) const { + if (mWhitelistedAtomIds.find(atomId) != mWhitelistedAtomIds.end()) { return true; } - if (event.GetUid() == AID_ROOT || - (event.GetUid() >= AID_SYSTEM && event.GetUid() < AID_SHELL)) { + if (uid == AID_ROOT || (uid >= AID_SYSTEM && uid < AID_SHELL)) { // enable atoms logged from pre-installed Android system services return true; } std::lock_guard<std::mutex> lock(mAllowedLogSourcesMutex); - if (mAllowedLogSources.find(event.GetUid()) == mAllowedLogSources.end()) { - VLOG("log source %d not on the whitelist", event.GetUid()); + if (mAllowedLogSources.find(uid) == mAllowedLogSources.end()) { + VLOG("log source %d not on the whitelist", uid); return false; } return true; @@ -538,11 +539,24 @@ void MetricsManager::onLogEvent(const LogEvent& event) { return; } + const int tagId = event.GetTagId(); + + if (tagId == util::STATS_SOCKET_LOSS_REPORTED) { + // Hard coded logic to handle socket loss info to highlight metric corruption reason + // STATS_SOCKET_LOSS_REPORTED might not be part of atoms allow list - but some of lost + // atoms can be always allowed - that is the reason to evaluate SocketLossInfo content prior + // the checkLogCredentials below + const std::optional<SocketLossInfo>& lossInfo = toSocketLossInfo(event); + if (lossInfo) { + onLogEventLost(*lossInfo); + } + // next, atom is going to be propagated to be consumed by metrics if any + } + if (!checkLogCredentials(event)) { return; } - const int tagId = event.GetTagId(); const int64_t eventTimeNs = event.GetElapsedTimestampNs(); bool isActive = mIsAlwaysActive; @@ -701,6 +715,48 @@ void MetricsManager::onLogEvent(const LogEvent& event) { } } +void MetricsManager::onLogEventLost(const SocketLossInfo& socketLossInfo) { + // socketLossInfo stores atomId per UID - to eliminate duplicates using set + const set<int> uniqueLostAtomIds(socketLossInfo.atomIds.begin(), socketLossInfo.atomIds.end()); + + // pass lost atom id to all relevant metrics + for (const auto lostAtomId : uniqueLostAtomIds) { + /** + * Socket loss atom: + * - comes from a specific uid (originUid) + * - specifies the uid in the atom payload (socketLossInfo.uid) + * - provides a list of atom ids that are lost + * + * For atom id that is lost (lostAtomId below): + * - if that atom id is allowed from any uid, then always count this atom as lost + * - else, if the originUid (from ucred) (socketLossInfo.uid below - is the same for all + * uniqueLostAtomIds) is in the allowed log sources - count this atom as lost + */ + + if (!checkLogCredentials(socketLossInfo.uid, lostAtomId)) { + continue; + } + + const auto matchersIt = mTagIdsToMatchersMap.find(lostAtomId); + if (matchersIt == mTagIdsToMatchersMap.end()) { + // atom is lost - but no metrics in config reference it + continue; + } + const auto& matchersIndexesListForLostAtom = matchersIt->second; + for (const auto matcherIndex : matchersIndexesListForLostAtom) { + auto it = mTrackerToMetricMap.find(matcherIndex); + if (it == mTrackerToMetricMap.end()) { + continue; + } + auto& metricsList = it->second; + for (const int metricIndex : metricsList) { + mAllMetricProducers[metricIndex]->onMatchedLogEventLost(lostAtomId, + DATA_CORRUPTED_SOCKET_LOSS); + } + } + } +} + void MetricsManager::onAnomalyAlarmFired( const int64_t timestampNs, unordered_set<sp<const InternalAlarm>, SpHash<InternalAlarm>>& alarmSet) { diff --git a/statsd/src/metrics/MetricsManager.h b/statsd/src/metrics/MetricsManager.h index 3b28b6a3..22d5ecf1 100644 --- a/statsd/src/metrics/MetricsManager.h +++ b/statsd/src/metrics/MetricsManager.h @@ -57,8 +57,6 @@ public: // Return whether the configuration is valid. bool isConfigValid() const; - bool checkLogCredentials(const LogEvent& event); - virtual void onLogEvent(const LogEvent& event); void onAnomalyAlarmFired( @@ -325,6 +323,12 @@ private: std::vector<int> mMetricIndexesWithActivation; + inline bool checkLogCredentials(const LogEvent& event) const { + return checkLogCredentials(event.GetUid(), event.GetTagId()); + } + + bool checkLogCredentials(int32_t uid, int32_t atomId) const; + void initAllowedLogSources(); void initPullAtomSources(); @@ -365,6 +369,8 @@ private: // metrics. void setTriggerGetDataBytesFromConfig(const StatsdConfig& config); + void onLogEventLost(const SocketLossInfo& socketLossInfo); + // The memory limit in bytes for storing metrics size_t mMaxMetricsBytes; @@ -406,7 +412,10 @@ private: FRIEND_TEST(MetricActivationE2eTest, TestCountMetricWithTwoMetricsTwoDeactivations); FRIEND_TEST(MetricsManagerTest, TestLogSources); + FRIEND_TEST(MetricsManagerTest, TestCheckLogCredentialsWhitelistedAtom); FRIEND_TEST(MetricsManagerTest, TestLogSourcesOnConfigUpdate); + FRIEND_TEST(MetricsManagerTest, TestOnLogEventLossForAllowedFromAnyUidAtom); + FRIEND_TEST(MetricsManagerTest, TestOnLogEventLossForNotAllowedAtom); FRIEND_TEST(MetricsManagerTest_SPlus, TestRestrictedMetricsConfig); FRIEND_TEST(MetricsManagerTest_SPlus, TestRestrictedMetricsConfigUpdate); FRIEND_TEST(MetricsManagerUtilTest, TestSampledMetrics); diff --git a/statsd/src/metrics/ValueMetricProducer.cpp b/statsd/src/metrics/ValueMetricProducer.cpp index 7937c69d..f4620ddb 100644 --- a/statsd/src/metrics/ValueMetricProducer.cpp +++ b/statsd/src/metrics/ValueMetricProducer.cpp @@ -158,6 +158,7 @@ ValueMetricProducer<AggregatedValue, DimExtras>::~ValueMetricProducer() { template <typename AggregatedValue, typename DimExtras> void ValueMetricProducer<AggregatedValue, DimExtras>::onStatsdInitCompleted( const int64_t eventTimeNs) { + ATRACE_CALL(); lock_guard<mutex> lock(mMutex); if (isPulled() && mCondition == ConditionState::kTrue && mIsActive) { diff --git a/statsd/src/shell/ShellSubscriber.cpp b/statsd/src/shell/ShellSubscriber.cpp index 90ade1c7..56c3ccd8 100644 --- a/statsd/src/shell/ShellSubscriber.cpp +++ b/statsd/src/shell/ShellSubscriber.cpp @@ -24,6 +24,7 @@ #include "guardrail/StatsdStats.h" #include "stats_log_util.h" +#include "utils/api_tracing.h" using aidl::android::os::IStatsSubscriptionCallback; @@ -126,6 +127,7 @@ void ShellSubscriber::pullAndSendHeartbeats() { } void ShellSubscriber::onLogEvent(const LogEvent& event) { + ATRACE_CALL(); // Skip if event is skipped if (event.isParsedHeaderOnly()) { return; diff --git a/statsd/src/socket/StatsSocketListener.cpp b/statsd/src/socket/StatsSocketListener.cpp index da1a2a88..7f0eb436 100644 --- a/statsd/src/socket/StatsSocketListener.cpp +++ b/statsd/src/socket/StatsSocketListener.cpp @@ -33,6 +33,7 @@ #include "logd/logevent_util.h" #include "stats_log_util.h" #include "statslog_statsd.h" +#include "utils/api_tracing.h" namespace android { namespace os { @@ -46,6 +47,7 @@ StatsSocketListener::StatsSocketListener(const std::shared_ptr<LogEventQueue>& q } bool StatsSocketListener::onDataAvailable(SocketClient* cli) { + ATRACE_CALL(); static bool name_set; if (!name_set) { prctl(PR_SET_NAME, "statsd.writer"); @@ -103,6 +105,7 @@ bool StatsSocketListener::onDataAvailable(SocketClient* cli) { void StatsSocketListener::processSocketMessage(const char* buffer, const uint32_t len, uint32_t uid, uint32_t pid, LogEventQueue& queue, const LogEventFilter& filter) { + ATRACE_CALL(); static const uint32_t kStatsEventTag = 1937006964; if (len <= (ssize_t)(sizeof(android_log_header_t)) + sizeof(uint32_t)) { @@ -154,6 +157,7 @@ void StatsSocketListener::processSocketMessage(const char* buffer, const uint32_ void StatsSocketListener::processStatsEventBuffer(const uint8_t* msg, const uint32_t len, uint32_t uid, uint32_t pid, LogEventQueue& queue, const LogEventFilter& filter) { + ATRACE_CALL(); std::unique_ptr<LogEvent> logEvent = std::make_unique<LogEvent>(uid, pid); if (filter.getFilteringEnabled()) { diff --git a/statsd/src/stats_log.proto b/statsd/src/stats_log.proto index 09ba6a87..ff219519 100644 --- a/statsd/src/stats_log.proto +++ b/statsd/src/stats_log.proto @@ -320,6 +320,8 @@ message StatsLogReport { optional int64 estimated_data_bytes = 18; + repeated DataCorruptedReason data_corrupted_reason = 19; + // Do not use. reserved 13, 15; } diff --git a/statsd/src/stats_log_util.cpp b/statsd/src/stats_log_util.cpp index 6d473447..f7c9996b 100644 --- a/statsd/src/stats_log_util.cpp +++ b/statsd/src/stats_log_util.cpp @@ -554,6 +554,18 @@ void writeAtomMetricStatsToStream(const std::pair<int64_t, StatsdStats::AtomMetr protoOutput->end(token); } +void writeDataCorruptedReasons(ProtoOutputStream& proto, int fieldIdDataCorruptedReason, + bool hasQueueOverflow, bool hasSocketLoss) { + if (hasQueueOverflow) { + proto.write(FIELD_TYPE_INT32 | FIELD_COUNT_REPEATED | fieldIdDataCorruptedReason, + DATA_CORRUPTED_EVENT_QUEUE_OVERFLOW); + } + if (hasSocketLoss) { + proto.write(FIELD_TYPE_INT32 | FIELD_COUNT_REPEATED | fieldIdDataCorruptedReason, + DATA_CORRUPTED_SOCKET_LOSS); + } +} + int64_t getElapsedRealtimeNs() { return ::android::elapsedRealtimeNano(); } diff --git a/statsd/src/stats_log_util.h b/statsd/src/stats_log_util.h index 16cdb35c..5aa4c0b5 100644 --- a/statsd/src/stats_log_util.h +++ b/statsd/src/stats_log_util.h @@ -92,6 +92,9 @@ void writePullerStatsToStream(const std::pair<int, StatsdStats::PulledAtomStats> void writeAtomMetricStatsToStream(const std::pair<int64_t, StatsdStats::AtomMetricStats> &pair, ProtoOutputStream *protoOutput); +void writeDataCorruptedReasons(ProtoOutputStream& proto, int fieldIdDataCorruptedReason, + bool hasQueueOverflow, bool hasSocketLoss); + template<class T> bool parseProtoOutputStream(ProtoOutputStream& protoOutput, T* message) { std::string pbBytes; diff --git a/statsd/src/utils/api_tracing.h b/statsd/src/utils/api_tracing.h new file mode 100644 index 00000000..69edeae8 --- /dev/null +++ b/statsd/src/utils/api_tracing.h @@ -0,0 +1,21 @@ +/* + * Copyright (C) 2024 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. + */ + +#pragma once + +#define ATRACE_TAG ATRACE_TAG_APP + +#include <utils/Trace.h> diff --git a/statsd/tests/MetricsManager_test.cpp b/statsd/tests/MetricsManager_test.cpp index d86e9757..a45fa247 100644 --- a/statsd/tests/MetricsManager_test.cpp +++ b/statsd/tests/MetricsManager_test.cpp @@ -32,6 +32,7 @@ #include "src/state/StateManager.h" #include "src/statsd_config.pb.h" #include "statsd_test_util.h" +#include "statslog_statsdtest.h" using namespace testing; using android::sp; @@ -53,10 +54,12 @@ const ConfigKey kConfigKey(0, kConfigId); const long timeBaseSec = 1000; -StatsdConfig buildGoodRestrictedConfig() { +StatsdConfig buildEventConfig(bool isRestricted) { StatsdConfig config; config.set_id(kConfigId); - config.set_restricted_metrics_delegate_package_name("delegate"); + if (isRestricted) { + config.set_restricted_metrics_delegate_package_name("delegate"); + } AtomMatcher* eventMatcher = config.add_atom_matcher(); eventMatcher->set_id(StringToId("SCREEN_IS_ON")); @@ -69,6 +72,14 @@ StatsdConfig buildGoodRestrictedConfig() { return config; } +StatsdConfig buildGoodRestrictedConfig() { + return buildEventConfig(/*isRestricted*/ true); +} + +StatsdConfig buildGoodEventConfig() { + return buildEventConfig(/*isRestricted*/ false); +} + set<int32_t> unionSet(const vector<set<int32_t>> sets) { set<int32_t> toRet; for (const set<int32_t>& s : sets) { @@ -76,6 +87,36 @@ set<int32_t> unionSet(const vector<set<int32_t>> sets) { } return toRet; } + +SocketLossInfo createSocketLossInfo(int32_t uid, int32_t atomId) { + SocketLossInfo lossInfo; + lossInfo.uid = uid; + lossInfo.errors.push_back(-11); + lossInfo.atomIds.push_back(atomId); + lossInfo.counts.push_back(1); + return lossInfo; +} + +// helper API to create STATS_SOCKET_LOSS_REPORTED LogEvent +LogEvent createSocketLossInfoLogEvent(int32_t uid, int32_t lossAtomId) { + const SocketLossInfo lossInfo = createSocketLossInfo(uid, lossAtomId); + + AStatsEvent* statsEvent = AStatsEvent_obtain(); + AStatsEvent_setAtomId(statsEvent, util::STATS_SOCKET_LOSS_REPORTED); + AStatsEvent_writeInt32(statsEvent, lossInfo.uid); + AStatsEvent_addBoolAnnotation(statsEvent, ASTATSLOG_ANNOTATION_ID_IS_UID, true); + AStatsEvent_writeInt64(statsEvent, lossInfo.firstLossTsNanos); + AStatsEvent_writeInt64(statsEvent, lossInfo.lastLossTsNanos); + AStatsEvent_writeInt32(statsEvent, lossInfo.overflowCounter); + AStatsEvent_writeInt32Array(statsEvent, lossInfo.errors.data(), lossInfo.errors.size()); + AStatsEvent_writeInt32Array(statsEvent, lossInfo.atomIds.data(), lossInfo.atomIds.size()); + AStatsEvent_writeInt32Array(statsEvent, lossInfo.counts.data(), lossInfo.counts.size()); + + LogEvent event(uid /* uid */, 0 /* pid */); + parseStatsEventToLogEvent(statsEvent, &event); + return event; +} + } // anonymous namespace TEST(MetricsManagerTest, TestLogSources) { @@ -299,6 +340,69 @@ TEST(MetricsManagerTest, TestCheckLogCredentialsWhitelistedAtom) { EXPECT_TRUE(metricsManager.checkLogCredentials(event)); } +TEST(MetricsManagerTest, TestOnLogEventLossForAllowedFromAnyUidAtom) { + sp<UidMap> uidMap; + sp<StatsPullerManager> pullerManager = new StatsPullerManager(); + sp<AlarmMonitor> anomalyAlarmMonitor; + sp<AlarmMonitor> periodicAlarmMonitor; + + StatsdConfig config = buildGoodEventConfig(); + config.add_whitelisted_atom_ids(2); + + MetricsManager metricsManager(kConfigKey, config, timeBaseSec, timeBaseSec, uidMap, + pullerManager, anomalyAlarmMonitor, periodicAlarmMonitor); + + const int32_t customAppUid = AID_APP_START + 1; + LogEvent eventOfInterest(customAppUid /* uid */, 0 /* pid */); + CreateNoValuesLogEvent(&eventOfInterest, 2 /* atom id */, 0 /* timestamp */); + EXPECT_TRUE(metricsManager.checkLogCredentials(eventOfInterest)); + EXPECT_FALSE(metricsManager.mAllMetricProducers[0]->mDataCorruptedDueToSocketLoss); + + LogEvent eventSocketLossReported = createSocketLossInfoLogEvent(customAppUid, 2); + + // the STATS_SOCKET_LOSS_REPORTED on its own will not be propagated/consumed by any metric + EXPECT_FALSE(metricsManager.checkLogCredentials(eventSocketLossReported)); + + // the loss info for an atom of interest (2) will be evaluated even when + // STATS_SOCKET_LOSS_REPORTED atom is not explicitly in allowed list + metricsManager.onLogEvent(eventSocketLossReported); + + // check that corresponding event metric was updated with loss info + // the invariant is there is only one metric in the config + EXPECT_TRUE(metricsManager.mAllMetricProducers[0]->mDataCorruptedDueToSocketLoss); +} + +TEST(MetricsManagerTest, TestOnLogEventLossForNotAllowedAtom) { + sp<UidMap> uidMap; + sp<StatsPullerManager> pullerManager = new StatsPullerManager(); + sp<AlarmMonitor> anomalyAlarmMonitor; + sp<AlarmMonitor> periodicAlarmMonitor; + + StatsdConfig config = buildGoodEventConfig(); + + MetricsManager metricsManager(kConfigKey, config, timeBaseSec, timeBaseSec, uidMap, + pullerManager, anomalyAlarmMonitor, periodicAlarmMonitor); + + const int32_t customAppUid = AID_APP_START + 1; + LogEvent eventOfInterest(customAppUid /* uid */, 0 /* pid */); + CreateNoValuesLogEvent(&eventOfInterest, 2 /* atom id */, 0 /* timestamp */); + EXPECT_FALSE(metricsManager.checkLogCredentials(eventOfInterest)); + EXPECT_FALSE(metricsManager.mAllMetricProducers[0]->mDataCorruptedDueToSocketLoss); + + LogEvent eventSocketLossReported = createSocketLossInfoLogEvent(customAppUid, 2); + + // the STATS_SOCKET_LOSS_REPORTED on its own will not be propagated/consumed by any metric + EXPECT_FALSE(metricsManager.checkLogCredentials(eventSocketLossReported)); + + // the loss info for an atom of interest (2) will not be evaluated since atom of interest does + // not pass credential check + metricsManager.onLogEvent(eventSocketLossReported); + + // check that corresponding event metric was not updated with loss info + // the invariant is there is only one metric in the config + EXPECT_FALSE(metricsManager.mAllMetricProducers[0]->mDataCorruptedDueToSocketLoss); +} + TEST(MetricsManagerTest, TestWhitelistedAtomStateTracker) { sp<UidMap> uidMap; sp<StatsPullerManager> pullerManager = new StatsPullerManager(); diff --git a/statsd/tests/metrics/EventMetricProducer_test.cpp b/statsd/tests/metrics/EventMetricProducer_test.cpp index 6e25f791..a789f3ba 100644 --- a/statsd/tests/metrics/EventMetricProducer_test.cpp +++ b/statsd/tests/metrics/EventMetricProducer_test.cpp @@ -53,6 +53,7 @@ void makeLogEvent(LogEvent* logEvent, int32_t atomId, int64_t timestampNs, strin parseStatsEventToLogEvent(statsEvent, logEvent); } + } // anonymous namespace class EventMetricProducerTest : public ::testing::Test { @@ -350,6 +351,106 @@ TEST_F(EventMetricProducerTest, TestTwoAtomTagAggregatedEvents) { } } +TEST_F(EventMetricProducerTest, TestCorruptedDataReasonSocketLoss_OnDumpReport) { + int64_t bucketStartTimeNs = 10000000000; + int tagId = 1; + + EventMetric metric; + metric.set_id(1); + + LogEvent event1(/*uid=*/0, /*pid=*/0); + makeLogEvent(&event1, tagId, bucketStartTimeNs + 10, "111"); + + sp<MockConditionWizard> wizard = new NaggyMock<MockConditionWizard>(); + sp<MockConfigMetadataProvider> provider = makeMockConfigMetadataProvider(/*enabled=*/false); + EventMetricProducer eventProducer(kConfigKey, metric, -1 /*-1 meaning no condition*/, {}, + wizard, protoHash, bucketStartTimeNs, provider); + eventProducer.onMatchedLogEvent(1 /*matcher index*/, event1); + + EXPECT_FALSE(eventProducer.mDataCorruptedDueToSocketLoss); + EXPECT_FALSE(eventProducer.mDataCorruptedDueToQueueOverflow); + + eventProducer.onMatchedLogEventLost(tagId, DATA_CORRUPTED_SOCKET_LOSS); + + EXPECT_TRUE(eventProducer.mDataCorruptedDueToSocketLoss); + EXPECT_FALSE(eventProducer.mDataCorruptedDueToQueueOverflow); + + // Check dump report content. + ProtoOutputStream output; + std::set<string> strSet; + eventProducer.onDumpReport(bucketStartTimeNs + 50, true /*include current partial bucket*/, + true /*erase data*/, FAST, &strSet, &output); + + StatsLogReport report = outputStreamToProto(&output); + EXPECT_TRUE(report.has_event_metrics()); + ASSERT_EQ(1, report.event_metrics().data_size()); + ASSERT_EQ(1, report.data_corrupted_reason_size()); + ASSERT_EQ(DATA_CORRUPTED_SOCKET_LOSS, report.data_corrupted_reason()[0]); + + EXPECT_FALSE(eventProducer.mDataCorruptedDueToSocketLoss); + EXPECT_FALSE(eventProducer.mDataCorruptedDueToQueueOverflow); +} + +TEST_F(EventMetricProducerTest, TestCorruptedDataReasonSocketLoss_OnDropData) { + int64_t bucketStartTimeNs = 10000000000; + int tagId = 1; + + EventMetric metric; + metric.set_id(1); + + LogEvent event1(/*uid=*/0, /*pid=*/0); + makeLogEvent(&event1, tagId, bucketStartTimeNs + 10, "111"); + + sp<MockConditionWizard> wizard = new NaggyMock<MockConditionWizard>(); + sp<MockConfigMetadataProvider> provider = makeMockConfigMetadataProvider(/*enabled=*/false); + EventMetricProducer eventProducer(kConfigKey, metric, -1 /*-1 meaning no condition*/, {}, + wizard, protoHash, bucketStartTimeNs, provider); + eventProducer.onMatchedLogEvent(1 /*matcher index*/, event1); + + EXPECT_FALSE(eventProducer.mDataCorruptedDueToSocketLoss); + EXPECT_FALSE(eventProducer.mDataCorruptedDueToQueueOverflow); + + eventProducer.onMatchedLogEventLost(tagId, DATA_CORRUPTED_SOCKET_LOSS); + + EXPECT_TRUE(eventProducer.mDataCorruptedDueToSocketLoss); + EXPECT_FALSE(eventProducer.mDataCorruptedDueToQueueOverflow); + + eventProducer.dropData(bucketStartTimeNs + 100); + + EXPECT_FALSE(eventProducer.mDataCorruptedDueToSocketLoss); + EXPECT_FALSE(eventProducer.mDataCorruptedDueToQueueOverflow); +} + +TEST_F(EventMetricProducerTest, TestCorruptedDataReasonSocketLoss_OnClearPastBuckets) { + int64_t bucketStartTimeNs = 10000000000; + int tagId = 1; + + EventMetric metric; + metric.set_id(1); + + LogEvent event1(/*uid=*/0, /*pid=*/0); + makeLogEvent(&event1, tagId, bucketStartTimeNs + 10, "111"); + + sp<MockConditionWizard> wizard = new NaggyMock<MockConditionWizard>(); + sp<MockConfigMetadataProvider> provider = makeMockConfigMetadataProvider(/*enabled=*/false); + EventMetricProducer eventProducer(kConfigKey, metric, -1 /*-1 meaning no condition*/, {}, + wizard, protoHash, bucketStartTimeNs, provider); + eventProducer.onMatchedLogEvent(1 /*matcher index*/, event1); + + EXPECT_FALSE(eventProducer.mDataCorruptedDueToSocketLoss); + EXPECT_FALSE(eventProducer.mDataCorruptedDueToQueueOverflow); + + eventProducer.onMatchedLogEventLost(tagId, DATA_CORRUPTED_SOCKET_LOSS); + + EXPECT_TRUE(eventProducer.mDataCorruptedDueToSocketLoss); + EXPECT_FALSE(eventProducer.mDataCorruptedDueToQueueOverflow); + + eventProducer.clearPastBuckets(bucketStartTimeNs + 100); + + EXPECT_FALSE(eventProducer.mDataCorruptedDueToSocketLoss); + EXPECT_FALSE(eventProducer.mDataCorruptedDueToQueueOverflow); +} + } // namespace statsd } // namespace os } // namespace android |