Merge "Data/activation broadcasts use elapsed realtime" (20c14c40) · Commits · e / os / android_frameworks_base

cmds/statsd/src/StatsLogProcessor.cpp

+23 −16

Original line number	Diff line number	Diff line
		@@ -200,6 +200,10 @@ void StatsLogProcessor::resetConfigsLocked(const int64_t timestampNs) {
		}

		void StatsLogProcessor::OnLogEvent(LogEvent* event) {
		OnLogEvent(event, getElapsedRealtimeNs());
		}

		void StatsLogProcessor::OnLogEvent(LogEvent* event, int64_t elapsedRealtimeNs) {
		std::lock_guard<std::mutex> lock(mMetricsMutex);

		#ifdef VERY_VERBOSE_PRINTING
		@@ -207,9 +211,9 @@ void StatsLogProcessor::OnLogEvent(LogEvent* event) {
		ALOGI("%s", event->ToString().c_str());
		}
		#endif
		const int64_t currentTimestampNs = event->GetElapsedTimestampNs();
		const int64_t eventElapsedTimeNs = event->GetElapsedTimestampNs();

		resetIfConfigTtlExpiredLocked(currentTimestampNs);
		resetIfConfigTtlExpiredLocked(eventElapsedTimeNs);

		StatsdStats::getInstance().noteAtomLogged(
		event->GetTagId(), event->GetElapsedTimestampNs() / NS_PER_SEC);
		@@ -264,14 +268,15 @@ void StatsLogProcessor::OnLogEvent(LogEvent* event) {
		uidsWithActiveConfigsChanged.insert(uid);
		StatsdStats::getInstance().noteActiveStatusChanged(pair.first, isCurActive);
		}
		flushIfNecessaryLocked(event->GetElapsedTimestampNs(), pair.first, *(pair.second));
		flushIfNecessaryLocked(pair.first, *(pair.second));
		}

		// Don't use the event timestamp for the guardrail.
		for (int uid : uidsWithActiveConfigsChanged) {
		// Send broadcast so that receivers can pull data.
		auto lastBroadcastTime = mLastActivationBroadcastTimes.find(uid);
		if (lastBroadcastTime != mLastActivationBroadcastTimes.end()) {
		if (currentTimestampNs - lastBroadcastTime->second <
		if (elapsedRealtimeNs - lastBroadcastTime->second <
		StatsdStats::kMinActivationBroadcastPeriodNs) {
		StatsdStats::getInstance().noteActivationBroadcastGuardrailHit(uid);
		VLOG("StatsD would've sent an activation broadcast but the rate limit stopped us.");
		@@ -282,13 +287,13 @@ void StatsLogProcessor::OnLogEvent(LogEvent* event) {
		if (activeConfigs != activeConfigsPerUid.end()) {
		if (mSendActivationBroadcast(uid, activeConfigs->second)) {
		VLOG("StatsD sent activation notice for uid %d", uid);
		mLastActivationBroadcastTimes[uid] = currentTimestampNs;
		mLastActivationBroadcastTimes[uid] = elapsedRealtimeNs;
		}
		} else {
		std::vector<int64_t> emptyActiveConfigs;
		if (mSendActivationBroadcast(uid, emptyActiveConfigs)) {
		VLOG("StatsD sent EMPTY activation notice for uid %d", uid);
		mLastActivationBroadcastTimes[uid] = currentTimestampNs;
		mLastActivationBroadcastTimes[uid] = elapsedRealtimeNs;
		}
		}
		}
		@@ -550,22 +555,23 @@ void StatsLogProcessor::OnConfigRemoved(const ConfigKey& key) {
		}
		}

		void StatsLogProcessor::flushIfNecessaryLocked(
		int64_t timestampNs, const ConfigKey& key, MetricsManager& metricsManager) {
		void StatsLogProcessor::flushIfNecessaryLocked(const ConfigKey& key,
		MetricsManager& metricsManager) {
		int64_t elapsedRealtimeNs = getElapsedRealtimeNs();
		auto lastCheckTime = mLastByteSizeTimes.find(key);
		if (lastCheckTime != mLastByteSizeTimes.end()) {
		if (timestampNs - lastCheckTime->second < StatsdStats::kMinByteSizeCheckPeriodNs) {
		if (elapsedRealtimeNs - lastCheckTime->second < StatsdStats::kMinByteSizeCheckPeriodNs) {
		return;
		}
		}

		// We suspect that the byteSize() computation is expensive, so we set a rate limit.
		size_t totalBytes = metricsManager.byteSize();
		mLastByteSizeTimes[key] = timestampNs;
		mLastByteSizeTimes[key] = elapsedRealtimeNs;
		bool requestDump = false;
		if (totalBytes >
		StatsdStats::kMaxMetricsBytesPerConfig) { // Too late. We need to start clearing data.
		metricsManager.dropData(timestampNs);
		if (totalBytes > StatsdStats::kMaxMetricsBytesPerConfig) {
		// Too late. We need to start clearing data.
		metricsManager.dropData(elapsedRealtimeNs);
		StatsdStats::getInstance().noteDataDropped(key, totalBytes);
		VLOG("StatsD had to toss out metrics for %s", key.ToString().c_str());
		} else if ((totalBytes > StatsdStats::kBytesPerConfigTriggerGetData) \|\|
		@@ -580,7 +586,8 @@ void StatsLogProcessor::flushIfNecessaryLocked(
		// Send broadcast so that receivers can pull data.
		auto lastBroadcastTime = mLastBroadcastTimes.find(key);
		if (lastBroadcastTime != mLastBroadcastTimes.end()) {
		if (timestampNs - lastBroadcastTime->second < StatsdStats::kMinBroadcastPeriodNs) {
		if (elapsedRealtimeNs - lastBroadcastTime->second <
		StatsdStats::kMinBroadcastPeriodNs) {
		VLOG("StatsD would've sent a broadcast but the rate limit stopped us.");
		return;
		}
		@@ -588,7 +595,7 @@ void StatsLogProcessor::flushIfNecessaryLocked(
		if (mSendBroadcast(key)) {
		mOnDiskDataConfigs.erase(key);
		VLOG("StatsD triggered data fetch for %s", key.ToString().c_str());
		mLastBroadcastTimes[key] = timestampNs;
		mLastBroadcastTimes[key] = elapsedRealtimeNs;
		StatsdStats::getInstance().noteBroadcastSent(key);
		}
		}

cmds/statsd/src/StatsLogProcessor.h

+3 −2

Original line number	Diff line number	Diff line
		@@ -147,6 +147,8 @@ private:

		sp<AlarmMonitor> mPeriodicAlarmMonitor;

		void OnLogEvent(LogEvent* event, int64_t elapsedRealtimeNs);

		void resetIfConfigTtlExpiredLocked(const int64_t timestampNs);

		void OnConfigUpdatedLocked(
		@@ -176,8 +178,7 @@ private:

		/* Check if we should send a broadcast if approaching memory limits and if we're over, we
		* actually delete the data. */
		void flushIfNecessaryLocked(int64_t timestampNs, const ConfigKey& key,
		MetricsManager& metricsManager);
		void flushIfNecessaryLocked(const ConfigKey& key, MetricsManager& metricsManager);

		// Maps the isolated uid in the log event to host uid if the log event contains uid fields.
		void mapIsolatedUidToHostUidIfNecessaryLocked(LogEvent* event) const;

cmds/statsd/tests/StatsLogProcessor_test.cpp

+5 −5

Original line number	Diff line number	Diff line
		@@ -76,9 +76,9 @@ TEST(StatsLogProcessorTest, TestRateLimitByteSize) {
		// Expect only the first flush to trigger a check for byte size since the last two are
		// rate-limited.
		EXPECT_CALL(mockMetricsManager, byteSize()).Times(1);
		p.flushIfNecessaryLocked(99, key, mockMetricsManager);
		p.flushIfNecessaryLocked(100, key, mockMetricsManager);
		p.flushIfNecessaryLocked(101, key, mockMetricsManager);
		p.flushIfNecessaryLocked(key, mockMetricsManager);
		p.flushIfNecessaryLocked(key, mockMetricsManager);
		p.flushIfNecessaryLocked(key, mockMetricsManager);
		}

		TEST(StatsLogProcessorTest, TestRateLimitBroadcast) {
		@@ -103,7 +103,7 @@ TEST(StatsLogProcessorTest, TestRateLimitBroadcast) {
		StatsdStats::kMaxMetricsBytesPerConfig * .95)));

		// Expect only one broadcast despite always returning a size that should trigger broadcast.
		p.flushIfNecessaryLocked(1, key, mockMetricsManager);
		p.flushIfNecessaryLocked(key, mockMetricsManager);
		EXPECT_EQ(1, broadcastCount);

		// b/73089712
		@@ -136,7 +136,7 @@ TEST(StatsLogProcessorTest, TestDropWhenByteSizeTooLarge) {
		EXPECT_CALL(mockMetricsManager, dropData(_)).Times(1);

		// Expect to call the onDumpReport and skip the broadcast.
		p.flushIfNecessaryLocked(1, key, mockMetricsManager);
		p.flushIfNecessaryLocked(key, mockMetricsManager);
		EXPECT_EQ(0, broadcastCount);
		}

cmds/statsd/tests/e2e/DurationMetric_e2e_test.cpp

+8 −8

Original line number	Diff line number	Diff line
		@@ -271,19 +271,19 @@ TEST(DurationMetricE2eTest, TestWithActivation) {
		// Turn screen off.
		event = CreateScreenStateChangedEvent(
		android::view::DISPLAY_STATE_OFF, bucketStartTimeNs + 2 * NS_PER_SEC); // 0:02
		processor.OnLogEvent(event.get());
		processor.OnLogEvent(event.get(), bucketStartTimeNs + 2 * NS_PER_SEC);

		// Turn screen on.
		const int64_t durationStartNs = bucketStartTimeNs + 5 * NS_PER_SEC; // 0:05
		event = CreateScreenStateChangedEvent(android::view::DISPLAY_STATE_ON, durationStartNs);
		processor.OnLogEvent(event.get());
		processor.OnLogEvent(event.get(), durationStartNs);

		// Activate metric.
		const int64_t activationStartNs = bucketStartTimeNs + 5 * NS_PER_SEC; // 0:10
		const int64_t activationEndNs =
		activationStartNs + event_activation1->ttl_seconds() * NS_PER_SEC; // 0:40
		event = CreateAppCrashEvent(111, activationStartNs);
		processor.OnLogEvent(event.get());
		processor.OnLogEvent(event.get(), activationStartNs);
		EXPECT_TRUE(metricsManager->isActive());
		EXPECT_TRUE(metricProducer->mIsActive);
		EXPECT_EQ(broadcastCount, 1);
		@@ -296,7 +296,7 @@ TEST(DurationMetricE2eTest, TestWithActivation) {
		// Expire activation.
		const int64_t expirationNs = activationEndNs + 7 * NS_PER_SEC;
		event = CreateScreenBrightnessChangedEvent(64, expirationNs); // 0:47
		processor.OnLogEvent(event.get());
		processor.OnLogEvent(event.get(), expirationNs);
		EXPECT_FALSE(metricsManager->isActive());
		EXPECT_FALSE(metricProducer->mIsActive);
		EXPECT_EQ(broadcastCount, 2);
		@@ -310,24 +310,24 @@ TEST(DurationMetricE2eTest, TestWithActivation) {
		// Turn off screen 10 seconds after activation expiration.
		const int64_t durationEndNs = activationEndNs + 10 * NS_PER_SEC; // 0:50
		event = CreateScreenStateChangedEvent(android::view::DISPLAY_STATE_OFF, durationEndNs);
		processor.OnLogEvent(event.get());
		processor.OnLogEvent(event.get(),durationEndNs);

		// Turn screen on.
		const int64_t duration2StartNs = durationEndNs + 5 * NS_PER_SEC; // 0:55
		event = CreateScreenStateChangedEvent(android::view::DISPLAY_STATE_ON, duration2StartNs);
		processor.OnLogEvent(event.get());
		processor.OnLogEvent(event.get(), duration2StartNs);

		// Turn off screen.
		const int64_t duration2EndNs = duration2StartNs + 10 * NS_PER_SEC; // 1:05
		event = CreateScreenStateChangedEvent(android::view::DISPLAY_STATE_OFF, duration2EndNs);
		processor.OnLogEvent(event.get());
		processor.OnLogEvent(event.get(), duration2EndNs);

		// Activate metric.
		const int64_t activation2StartNs = duration2EndNs + 5 * NS_PER_SEC; // 1:10
		const int64_t activation2EndNs =
		activation2StartNs + event_activation1->ttl_seconds() * NS_PER_SEC; // 1:40
		event = CreateAppCrashEvent(211, activation2StartNs);
		processor.OnLogEvent(event.get());
		processor.OnLogEvent(event.get(), activation2StartNs);
		EXPECT_TRUE(metricsManager->isActive());
		EXPECT_TRUE(metricProducer->mIsActive);
		EXPECT_EQ(broadcastCount, 3);

cmds/statsd/tests/e2e/MetricActivation_e2e_test.cpp

+77 −77

File changed.

Preview size limit exceeded, changes collapsed.