1 // Copyright (C) 2020 The Android Open Source Project
2 //
3 // Licensed under the Apache License, Version 2.0 (the "License");
4 // you may not use this file except in compliance with the License.
5 // You may obtain a copy of the License at
6 //
7 // http://www.apache.org/licenses/LICENSE-2.0
8 //
9 // Unless required by applicable law or agreed to in writing, software
10 // distributed under the License is distributed on an "AS IS" BASIS,
11 // WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
12 // See the License for the specific language governing permissions and
13 // limitations under the License.
14
15 #include <aidl/android/os/StatsDimensionsValueParcel.h>
16 #include <android-base/properties.h>
17 #include <android-base/stringprintf.h>
18 #include <android/binder_interface_utils.h>
19 #include <gtest/gtest.h>
20
21 #include <thread>
22
23 #include "src/StatsLogProcessor.h"
24 #include "src/StatsService.h"
25 #include "src/storage/StorageManager.h"
26 #include "src/subscriber/SubscriberReporter.h"
27 #include "tests/statsd_test_util.h"
28
29 namespace android {
30 namespace os {
31 namespace statsd {
32
33 #ifdef __ANDROID__
34
35 using aidl::android::os::StatsDimensionsValueParcel;
36 using android::base::SetProperty;
37 using android::base::StringPrintf;
38 using ::ndk::SharedRefBase;
39 using namespace std;
40
41 // Tests that only run with the partial config update feature turned on.
42 namespace {
ValidateSubsystemSleepDimension(const DimensionsValue & value,string name)43 void ValidateSubsystemSleepDimension(const DimensionsValue& value, string name) {
44 EXPECT_EQ(value.field(), util::SUBSYSTEM_SLEEP_STATE);
45 ASSERT_EQ(value.value_tuple().dimensions_value_size(), 1);
46 EXPECT_EQ(value.value_tuple().dimensions_value(0).field(), 1 /* subsystem name field */);
47 EXPECT_EQ(value.value_tuple().dimensions_value(0).value_str(), name);
48 }
49
CreateStatsLogProcessor(const int64_t timeBaseNs,const int64_t currentTimeNs,const StatsdConfig & config,const ConfigKey & key,const shared_ptr<MockLogEventFilter> & logEventFilter)50 sp<StatsLogProcessor> CreateStatsLogProcessor(
51 const int64_t timeBaseNs, const int64_t currentTimeNs, const StatsdConfig& config,
52 const ConfigKey& key, const shared_ptr<MockLogEventFilter>& logEventFilter) {
53 if (logEventFilter) {
54 // call from StatsLogProcessor constructor
55 Expectation initCall = EXPECT_CALL(*logEventFilter,
56 setAtomIds(StatsLogProcessor::getDefaultAtomIdSet(), _))
57 .Times(1);
58 EXPECT_CALL(*logEventFilter, setAtomIds(CreateAtomIdSetFromConfig(config), _))
59 .Times(1)
60 .After(initCall);
61 }
62
63 return CreateStatsLogProcessor(timeBaseNs, currentTimeNs, config, key, nullptr, 0, new UidMap(),
64 logEventFilter);
65 }
66
67 } // Anonymous namespace.
68
69 // Setup for test fixture.
70 class ConfigUpdateE2eTest : public testing::TestWithParam<bool> {
71 protected:
72 std::shared_ptr<MockLogEventFilter> mLogEventFilter;
73
SetUp()74 void SetUp() override {
75 mLogEventFilter = GetParam() ? std::make_shared<MockLogEventFilter>() : nullptr;
76 }
77
78 public:
ToString(testing::TestParamInfo<bool> info)79 static std::string ToString(testing::TestParamInfo<bool> info) {
80 return info.param ? "WithLogEventFilter" : "NoLogEventFilter";
81 }
82 };
83
84 INSTANTIATE_TEST_SUITE_P(ConfigUpdateE2eTest, ConfigUpdateE2eTest, testing::Bool(),
85 ConfigUpdateE2eTest::ToString);
86
TEST_P(ConfigUpdateE2eTest,TestEventMetric)87 TEST_P(ConfigUpdateE2eTest, TestEventMetric) {
88 StatsdConfig config;
89 config.add_allowed_log_source("AID_ROOT");
90
91 AtomMatcher syncStartMatcher = CreateSyncStartAtomMatcher();
92 *config.add_atom_matcher() = syncStartMatcher;
93 AtomMatcher wakelockAcquireMatcher = CreateAcquireWakelockAtomMatcher();
94 *config.add_atom_matcher() = wakelockAcquireMatcher;
95 AtomMatcher screenOnMatcher = CreateScreenTurnedOnAtomMatcher();
96 *config.add_atom_matcher() = screenOnMatcher;
97 AtomMatcher screenOffMatcher = CreateScreenTurnedOffAtomMatcher();
98 *config.add_atom_matcher() = screenOffMatcher;
99 AtomMatcher batteryPluggedUsbMatcher = CreateBatteryStateUsbMatcher();
100 *config.add_atom_matcher() = batteryPluggedUsbMatcher;
101 AtomMatcher unpluggedMatcher = CreateBatteryStateNoneMatcher();
102 *config.add_atom_matcher() = unpluggedMatcher;
103
104 AtomMatcher* combinationMatcher = config.add_atom_matcher();
105 combinationMatcher->set_id(StringToId("SyncOrWakelockMatcher"));
106 combinationMatcher->mutable_combination()->set_operation(LogicalOperation::OR);
107 addMatcherToMatcherCombination(syncStartMatcher, combinationMatcher);
108 addMatcherToMatcherCombination(wakelockAcquireMatcher, combinationMatcher);
109
110 Predicate screenOnPredicate = CreateScreenIsOnPredicate();
111 *config.add_predicate() = screenOnPredicate;
112 Predicate unpluggedPredicate = CreateDeviceUnpluggedPredicate();
113 *config.add_predicate() = unpluggedPredicate;
114
115 Predicate* combinationPredicate = config.add_predicate();
116 combinationPredicate->set_id(StringToId("ScreenOnOrUnpluggedPred)"));
117 combinationPredicate->mutable_combination()->set_operation(LogicalOperation::OR);
118 addPredicateToPredicateCombination(screenOnPredicate, combinationPredicate);
119 addPredicateToPredicateCombination(unpluggedPredicate, combinationPredicate);
120
121 EventMetric eventPersist =
122 createEventMetric("SyncOrWlWhileScreenOnOrUnplugged", combinationMatcher->id(),
123 combinationPredicate->id());
124 EventMetric eventChange = createEventMetric(
125 "WakelockWhileScreenOn", wakelockAcquireMatcher.id(), screenOnPredicate.id());
126 EventMetric eventRemove = createEventMetric("Syncs", syncStartMatcher.id(), nullopt);
127
128 *config.add_event_metric() = eventRemove;
129 *config.add_event_metric() = eventPersist;
130 *config.add_event_metric() = eventChange;
131
132 ConfigKey key(123, 987);
133 uint64_t bucketStartTimeNs = 10000000000; // 0:10
134 sp<StatsLogProcessor> processor = CreateStatsLogProcessor(bucketStartTimeNs, bucketStartTimeNs,
135 config, key, mLogEventFilter);
136
137 int app1Uid = 123;
138 vector<int> attributionUids1 = {app1Uid};
139 vector<string> attributionTags1 = {"App1"};
140
141 // Initialize log events before update.
142 std::vector<std::unique_ptr<LogEvent>> events;
143 events.push_back(CreateAcquireWakelockEvent(bucketStartTimeNs + 5 * NS_PER_SEC,
144 attributionUids1, attributionTags1,
145 "wl1")); // Not kept.
146 events.push_back(CreateScreenStateChangedEvent(
147 bucketStartTimeNs + 10 * NS_PER_SEC,
148 android::view::DISPLAY_STATE_ON)); // Condition true for change.
149 events.push_back(CreateSyncStartEvent(bucketStartTimeNs + 15 * NS_PER_SEC, attributionUids1,
150 attributionTags1,
151 "sync1")); // Kept for persist & remove.
152 events.push_back(CreateBatteryStateChangedEvent(
153 bucketStartTimeNs + 20 * NS_PER_SEC,
154 BatteryPluggedStateEnum::BATTERY_PLUGGED_NONE)); // Condition true for preserve.
155 events.push_back(CreateAcquireWakelockEvent(bucketStartTimeNs + 25 * NS_PER_SEC,
156 attributionUids1, attributionTags1,
157 "wl2")); // Kept by persist and change.
158 events.push_back(CreateScreenStateChangedEvent(
159 bucketStartTimeNs + 30 * NS_PER_SEC,
160 android::view::DISPLAY_STATE_OFF)); // Condition false for change.
161 events.push_back(CreateSyncStartEvent(bucketStartTimeNs + 35 * NS_PER_SEC, attributionUids1,
162 attributionTags1,
163 "sync2")); // Kept for persist & remove.
164 events.push_back(CreateAcquireWakelockEvent(bucketStartTimeNs + 40 * NS_PER_SEC,
165 attributionUids1, attributionTags1,
166 "wl3")); // Kept by persist.
167
168 // Send log events to StatsLogProcessor.
169 for (auto& event : events) {
170 processor->OnLogEvent(event.get());
171 }
172
173 // Do update. Add matchers/conditions in different order to force indices to change.
174 StatsdConfig newConfig;
175 newConfig.add_allowed_log_source("AID_ROOT");
176
177 *newConfig.add_atom_matcher() = screenOnMatcher;
178 *newConfig.add_atom_matcher() = batteryPluggedUsbMatcher;
179 *newConfig.add_atom_matcher() = syncStartMatcher;
180 *newConfig.add_atom_matcher() = *combinationMatcher;
181 *newConfig.add_atom_matcher() = wakelockAcquireMatcher;
182 *newConfig.add_atom_matcher() = screenOffMatcher;
183 *newConfig.add_atom_matcher() = unpluggedMatcher;
184 *newConfig.add_predicate() = *combinationPredicate;
185 *newConfig.add_predicate() = unpluggedPredicate;
186 *newConfig.add_predicate() = screenOnPredicate;
187
188 // Add metrics. Note that the condition of eventChange will go from false to true.
189 eventChange.set_condition(unpluggedPredicate.id());
190 *newConfig.add_event_metric() = eventChange;
191 EventMetric eventNew = createEventMetric("ScreenOn", screenOnMatcher.id(), nullopt);
192 *newConfig.add_event_metric() = eventNew;
193 *newConfig.add_event_metric() = eventPersist;
194
195 int64_t updateTimeNs = bucketStartTimeNs + 60 * NS_PER_SEC;
196 if (GetParam()) {
197 EXPECT_CALL(*mLogEventFilter,
198 setAtomIds(CreateAtomIdSetFromConfig(newConfig), processor.get()))
199 .Times(1);
200 }
201 processor->OnConfigUpdated(updateTimeNs, key, newConfig);
202
203 // Send events after the update.
204 events.clear();
205 events.push_back(CreateAcquireWakelockEvent(bucketStartTimeNs + 65 * NS_PER_SEC,
206 attributionUids1, attributionTags1,
207 "wl4")); // Kept by preserve & change.
208 events.push_back(CreateBatteryStateChangedEvent(
209 bucketStartTimeNs + 70 * NS_PER_SEC,
210 BatteryPluggedStateEnum::BATTERY_PLUGGED_USB)); // All conditions are false.
211 events.push_back(CreateAcquireWakelockEvent(bucketStartTimeNs + 75 * NS_PER_SEC,
212 attributionUids1, attributionTags1,
213 "wl5")); // Not kept.
214 events.push_back(CreateScreenStateChangedEvent(
215 bucketStartTimeNs + 80 * NS_PER_SEC,
216 android::view::DISPLAY_STATE_ON)); // Condition true for preserve, event kept by new.
217 events.push_back(CreateAcquireWakelockEvent(bucketStartTimeNs + 85 * NS_PER_SEC,
218 attributionUids1, attributionTags1,
219 "wl6")); // Kept by preserve.
220 events.push_back(CreateSyncStartEvent(bucketStartTimeNs + 90 * NS_PER_SEC, attributionUids1,
221 attributionTags1, "sync3")); // Kept by preserve.
222
223 // Send log events to StatsLogProcessor.
224 for (auto& event : events) {
225 processor->OnLogEvent(event.get());
226 }
227 uint64_t dumpTimeNs = bucketStartTimeNs + 100 * NS_PER_SEC;
228 ConfigMetricsReportList reports;
229 vector<uint8_t> buffer;
230 processor->onDumpReport(key, dumpTimeNs, true, true, ADB_DUMP, FAST, &buffer);
231 EXPECT_TRUE(reports.ParseFromArray(&buffer[0], buffer.size()));
232 backfillDimensionPath(&reports);
233 backfillStringInReport(&reports);
234 backfillStartEndTimestamp(&reports);
235 backfillAggregatedAtoms(&reports);
236 ASSERT_EQ(reports.reports_size(), 2);
237
238 // Report from before update.
239 ConfigMetricsReport report = reports.reports(0);
240 ASSERT_EQ(report.metrics_size(), 3);
241 // Event remove. Captured sync events. There were 2 syncs before the update.
242 StatsLogReport eventRemoveBefore = report.metrics(0);
243 EXPECT_EQ(eventRemoveBefore.metric_id(), eventRemove.id());
244 EXPECT_TRUE(eventRemoveBefore.has_event_metrics());
245 ASSERT_EQ(eventRemoveBefore.event_metrics().data_size(), 2);
246 auto data = eventRemoveBefore.event_metrics().data(0);
247 EXPECT_EQ(data.elapsed_timestamp_nanos(), bucketStartTimeNs + 15 * NS_PER_SEC);
248 EXPECT_EQ(data.atom().sync_state_changed().sync_name(), "sync1");
249 data = eventRemoveBefore.event_metrics().data(1);
250 EXPECT_EQ(data.elapsed_timestamp_nanos(), bucketStartTimeNs + 35 * NS_PER_SEC);
251 EXPECT_EQ(data.atom().sync_state_changed().sync_name(), "sync2");
252
253 // Captured wakelocks & syncs while screen on or unplugged. There were 2 wakelocks and 2 syncs.
254 StatsLogReport eventPersistBefore = report.metrics(1);
255 EXPECT_EQ(eventPersistBefore.metric_id(), eventPersist.id());
256 EXPECT_TRUE(eventPersistBefore.has_event_metrics());
257 ASSERT_EQ(eventPersistBefore.event_metrics().data_size(), 3);
258 data = eventPersistBefore.event_metrics().data(0);
259 EXPECT_EQ(data.elapsed_timestamp_nanos(), bucketStartTimeNs + 25 * NS_PER_SEC);
260 EXPECT_EQ(data.atom().wakelock_state_changed().tag(), "wl2");
261 data = eventPersistBefore.event_metrics().data(1);
262 EXPECT_EQ(data.elapsed_timestamp_nanos(), bucketStartTimeNs + 35 * NS_PER_SEC);
263 EXPECT_EQ(data.atom().sync_state_changed().sync_name(), "sync2");
264 data = eventPersistBefore.event_metrics().data(2);
265 EXPECT_EQ(data.elapsed_timestamp_nanos(), bucketStartTimeNs + 40 * NS_PER_SEC);
266 EXPECT_EQ(data.atom().wakelock_state_changed().tag(), "wl3");
267
268 // Captured wakelock events while screen on. There was 1 before the update.
269 StatsLogReport eventChangeBefore = report.metrics(2);
270 EXPECT_EQ(eventChangeBefore.metric_id(), eventChange.id());
271 EXPECT_TRUE(eventChangeBefore.has_event_metrics());
272 ASSERT_EQ(eventChangeBefore.event_metrics().data_size(), 1);
273 data = eventChangeBefore.event_metrics().data(0);
274 EXPECT_EQ(data.elapsed_timestamp_nanos(), bucketStartTimeNs + 25 * NS_PER_SEC);
275 EXPECT_EQ(data.atom().wakelock_state_changed().tag(), "wl2");
276
277 // Report from after update.
278 report = reports.reports(1);
279 ASSERT_EQ(report.metrics_size(), 3);
280 // Captured wakelocks while unplugged. There was 1 after the update.
281 StatsLogReport eventChangeAfter = report.metrics(0);
282 EXPECT_EQ(eventChangeAfter.metric_id(), eventChange.id());
283 EXPECT_TRUE(eventChangeAfter.has_event_metrics());
284 ASSERT_EQ(eventChangeAfter.event_metrics().data_size(), 1);
285 data = eventChangeAfter.event_metrics().data(0);
286 EXPECT_EQ(data.elapsed_timestamp_nanos(), bucketStartTimeNs + 65 * NS_PER_SEC);
287 EXPECT_EQ(data.atom().wakelock_state_changed().tag(), "wl4");
288
289 // Captured screen on events. There was 1 after the update.
290 StatsLogReport eventNewAfter = report.metrics(1);
291 EXPECT_EQ(eventNewAfter.metric_id(), eventNew.id());
292 EXPECT_TRUE(eventNewAfter.has_event_metrics());
293 ASSERT_EQ(eventNewAfter.event_metrics().data_size(), 1);
294 data = eventNewAfter.event_metrics().data(0);
295 EXPECT_EQ(data.elapsed_timestamp_nanos(), bucketStartTimeNs + 80 * NS_PER_SEC);
296 EXPECT_EQ(data.atom().screen_state_changed().state(), android::view::DISPLAY_STATE_ON);
297
298 // There were 2 wakelocks and 1 sync after the update while the condition was true.
299 StatsLogReport eventPersistAfter = report.metrics(2);
300 EXPECT_EQ(eventPersistAfter.metric_id(), eventPersist.id());
301 EXPECT_TRUE(eventPersistAfter.has_event_metrics());
302 ASSERT_EQ(eventPersistAfter.event_metrics().data_size(), 3);
303 data = eventPersistAfter.event_metrics().data(0);
304 EXPECT_EQ(data.elapsed_timestamp_nanos(), bucketStartTimeNs + 65 * NS_PER_SEC);
305 EXPECT_EQ(data.atom().wakelock_state_changed().tag(), "wl4");
306 data = eventPersistAfter.event_metrics().data(1);
307 EXPECT_EQ(data.elapsed_timestamp_nanos(), bucketStartTimeNs + 85 * NS_PER_SEC);
308 EXPECT_EQ(data.atom().wakelock_state_changed().tag(), "wl6");
309 data = eventPersistAfter.event_metrics().data(2);
310 EXPECT_EQ(data.elapsed_timestamp_nanos(), bucketStartTimeNs + 90 * NS_PER_SEC);
311 EXPECT_EQ(data.atom().sync_state_changed().sync_name(), "sync3");
312 }
313
TEST_P(ConfigUpdateE2eTest,TestCountMetric)314 TEST_P(ConfigUpdateE2eTest, TestCountMetric) {
315 StatsdConfig config;
316 config.add_allowed_log_source("AID_ROOT");
317
318 AtomMatcher syncStartMatcher = CreateSyncStartAtomMatcher();
319 *config.add_atom_matcher() = syncStartMatcher;
320 AtomMatcher wakelockAcquireMatcher = CreateAcquireWakelockAtomMatcher();
321 *config.add_atom_matcher() = wakelockAcquireMatcher;
322 AtomMatcher wakelockReleaseMatcher = CreateReleaseWakelockAtomMatcher();
323 *config.add_atom_matcher() = wakelockReleaseMatcher;
324 AtomMatcher screenOnMatcher = CreateScreenTurnedOnAtomMatcher();
325 *config.add_atom_matcher() = screenOnMatcher;
326 AtomMatcher screenOffMatcher = CreateScreenTurnedOffAtomMatcher();
327 *config.add_atom_matcher() = screenOffMatcher;
328
329 Predicate holdingWakelockPredicate = CreateHoldingWakelockPredicate();
330 // The predicate is dimensioning by first attribution node by uid.
331 *holdingWakelockPredicate.mutable_simple_predicate()->mutable_dimensions() =
332 CreateAttributionUidDimensions(util::WAKELOCK_STATE_CHANGED, {Position::FIRST});
333 *config.add_predicate() = holdingWakelockPredicate;
334
335 Predicate screenOnPredicate = CreateScreenIsOnPredicate();
336 *config.add_predicate() = screenOnPredicate;
337
338 Predicate* combination = config.add_predicate();
339 combination->set_id(StringToId("ScreenOnAndHoldingWL)"));
340 combination->mutable_combination()->set_operation(LogicalOperation::AND);
341 addPredicateToPredicateCombination(screenOnPredicate, combination);
342 addPredicateToPredicateCombination(holdingWakelockPredicate, combination);
343
344 State uidProcessState = CreateUidProcessState();
345 *config.add_state() = uidProcessState;
346
347 CountMetric countPersist =
348 createCountMetric("CountSyncPerUidWhileScreenOnHoldingWLSliceProcessState",
349 syncStartMatcher.id(), combination->id(), {uidProcessState.id()});
350 *countPersist.mutable_dimensions_in_what() =
351 CreateAttributionUidDimensions(util::SYNC_STATE_CHANGED, {Position::FIRST});
352 // Links between sync state atom and condition of uid is holding wakelock.
353 MetricConditionLink* links = countPersist.add_links();
354 links->set_condition(holdingWakelockPredicate.id());
355 *links->mutable_fields_in_what() =
356 CreateAttributionUidDimensions(util::SYNC_STATE_CHANGED, {Position::FIRST});
357 *links->mutable_fields_in_condition() =
358 CreateAttributionUidDimensions(util::WAKELOCK_STATE_CHANGED, {Position::FIRST});
359 MetricStateLink* stateLink = countPersist.add_state_link();
360 stateLink->set_state_atom_id(util::UID_PROCESS_STATE_CHANGED);
361 *stateLink->mutable_fields_in_what() =
362 CreateAttributionUidDimensions(util::SYNC_STATE_CHANGED, {Position::FIRST});
363 *stateLink->mutable_fields_in_state() =
364 CreateDimensions(util::UID_PROCESS_STATE_CHANGED, {1 /*uid*/});
365
366 CountMetric countChange = createCountMetric("Count*WhileScreenOn", syncStartMatcher.id(),
367 screenOnPredicate.id(), {});
368 CountMetric countRemove = createCountMetric("CountSync", syncStartMatcher.id(), nullopt, {});
369 *config.add_count_metric() = countRemove;
370 *config.add_count_metric() = countPersist;
371 *config.add_count_metric() = countChange;
372
373 ConfigKey key(123, 987);
374 uint64_t bucketStartTimeNs = 10000000000; // 0:10
375 uint64_t bucketSizeNs = TimeUnitToBucketSizeInMillis(TEN_MINUTES) * 1000000LL;
376 sp<StatsLogProcessor> processor = CreateStatsLogProcessor(bucketStartTimeNs, bucketStartTimeNs,
377 config, key, mLogEventFilter);
378
379 int app1Uid = 123, app2Uid = 456;
380 vector<int> attributionUids1 = {app1Uid};
381 vector<string> attributionTags1 = {"App1"};
382 vector<int> attributionUids2 = {app2Uid};
383 vector<string> attributionTags2 = {"App2"};
384
385 // Initialize log events before update. Counts are for countPersist since others are simpler.
386 std::vector<std::unique_ptr<LogEvent>> events;
387 events.push_back(CreateUidProcessStateChangedEvent(
388 bucketStartTimeNs + 2 * NS_PER_SEC, app1Uid,
389 android::app::ProcessStateEnum::PROCESS_STATE_IMPORTANT_BACKGROUND));
390 events.push_back(CreateUidProcessStateChangedEvent(
391 bucketStartTimeNs + 3 * NS_PER_SEC, app2Uid,
392 android::app::ProcessStateEnum::PROCESS_STATE_IMPORTANT_FOREGROUND));
393 events.push_back(CreateSyncStartEvent(bucketStartTimeNs + 5 * NS_PER_SEC, attributionUids1,
394 attributionTags1, "sync_name")); // Not counted.
395 events.push_back(
396 CreateScreenStateChangedEvent(bucketStartTimeNs + 10 * NS_PER_SEC,
397 android::view::DisplayStateEnum::DISPLAY_STATE_ON));
398 events.push_back(CreateAcquireWakelockEvent(bucketStartTimeNs + 15 * NS_PER_SEC,
399 attributionUids1, attributionTags1, "wl1"));
400 events.push_back(CreateSyncStartEvent(bucketStartTimeNs + 20 * NS_PER_SEC, attributionUids1,
401 attributionTags1, "sync_name")); // Counted. uid1 = 1.
402 events.push_back(CreateSyncStartEvent(bucketStartTimeNs + 21 * NS_PER_SEC, attributionUids2,
403 attributionTags2, "sync_name")); // Not counted.
404 events.push_back(CreateAcquireWakelockEvent(bucketStartTimeNs + 25 * NS_PER_SEC,
405 attributionUids2, attributionTags2, "wl2"));
406 events.push_back(CreateSyncStartEvent(bucketStartTimeNs + 30 * NS_PER_SEC, attributionUids1,
407 attributionTags1, "sync_name")); // Counted. uid1 = 2.
408 events.push_back(CreateSyncStartEvent(bucketStartTimeNs + 31 * NS_PER_SEC, attributionUids2,
409 attributionTags2, "sync_name")); // Counted. uid2 = 1
410 events.push_back(CreateReleaseWakelockEvent(bucketStartTimeNs + 35 * NS_PER_SEC,
411 attributionUids1, attributionTags1, "wl1"));
412 // Send log events to StatsLogProcessor.
413 for (auto& event : events) {
414 processor->OnLogEvent(event.get());
415 }
416
417 // Do update. Add matchers/conditions in different order to force indices to change.
418 StatsdConfig newConfig;
419 newConfig.add_allowed_log_source("AID_ROOT");
420
421 *newConfig.add_atom_matcher() = screenOnMatcher;
422 *newConfig.add_atom_matcher() = screenOffMatcher;
423 *newConfig.add_atom_matcher() = syncStartMatcher;
424 *newConfig.add_atom_matcher() = wakelockAcquireMatcher;
425 *newConfig.add_atom_matcher() = wakelockReleaseMatcher;
426 *newConfig.add_predicate() = *combination;
427 *newConfig.add_predicate() = holdingWakelockPredicate;
428 *newConfig.add_predicate() = screenOnPredicate;
429 *newConfig.add_state() = uidProcessState;
430
431 countChange.set_what(screenOnMatcher.id());
432 *newConfig.add_count_metric() = countChange;
433 CountMetric countNew = createCountMetric("CountWlWhileScreenOn", wakelockAcquireMatcher.id(),
434 screenOnPredicate.id(), {});
435 *newConfig.add_count_metric() = countNew;
436 *newConfig.add_count_metric() = countPersist;
437
438 int64_t updateTimeNs = bucketStartTimeNs + 60 * NS_PER_SEC;
439 if (GetParam()) {
440 EXPECT_CALL(*mLogEventFilter,
441 setAtomIds(CreateAtomIdSetFromConfig(newConfig), processor.get()))
442 .Times(1);
443 }
444 processor->OnConfigUpdated(updateTimeNs, key, newConfig);
445
446 // Send events after the update. Counts reset to 0 since this is a new bucket.
447 events.clear();
448 events.push_back(CreateSyncStartEvent(bucketStartTimeNs + 65 * NS_PER_SEC, attributionUids1,
449 attributionTags1, "sync_name")); // Not counted.
450 events.push_back(CreateSyncStartEvent(bucketStartTimeNs + 66 * NS_PER_SEC, attributionUids2,
451 attributionTags2, "sync_name")); // Counted. uid2 = 1.
452 events.push_back(CreateAcquireWakelockEvent(bucketStartTimeNs + 70 * NS_PER_SEC,
453 attributionUids1, attributionTags1, "wl1"));
454 events.push_back(
455 CreateScreenStateChangedEvent(bucketStartTimeNs + 75 * NS_PER_SEC,
456 android::view::DisplayStateEnum::DISPLAY_STATE_OFF));
457 events.push_back(CreateSyncStartEvent(bucketStartTimeNs + 80 * NS_PER_SEC, attributionUids2,
458 attributionTags2, "sync_name")); // Not counted.
459 events.push_back(
460 CreateScreenStateChangedEvent(bucketStartTimeNs + 85 * NS_PER_SEC,
461 android::view::DisplayStateEnum::DISPLAY_STATE_ON));
462 events.push_back(CreateSyncStartEvent(bucketStartTimeNs + 90 * NS_PER_SEC, attributionUids1,
463 attributionTags1, "sync_name")); // Counted. uid1 = 1.
464 events.push_back(CreateSyncStartEvent(bucketStartTimeNs + 11 * NS_PER_SEC, attributionUids2,
465 attributionTags2, "sync_name")); // Counted. uid2 = 2.
466 // Flushes bucket.
467 events.push_back(CreateAcquireWakelockEvent(bucketStartTimeNs + bucketSizeNs + NS_PER_SEC,
468 attributionUids1, attributionTags1, "wl2"));
469 // Send log events to StatsLogProcessor.
470 for (auto& event : events) {
471 processor->OnLogEvent(event.get());
472 }
473 uint64_t dumpTimeNs = bucketStartTimeNs + bucketSizeNs + 10 * NS_PER_SEC;
474 ConfigMetricsReportList reports;
475 vector<uint8_t> buffer;
476 processor->onDumpReport(key, dumpTimeNs, true, true, ADB_DUMP, FAST, &buffer);
477 EXPECT_TRUE(reports.ParseFromArray(&buffer[0], buffer.size()));
478 backfillDimensionPath(&reports);
479 backfillStringInReport(&reports);
480 backfillStartEndTimestamp(&reports);
481 ASSERT_EQ(reports.reports_size(), 2);
482
483 // Report from before update.
484 ConfigMetricsReport report = reports.reports(0);
485 ASSERT_EQ(report.metrics_size(), 3);
486 // Count syncs. There were 5 syncs before the update.
487 StatsLogReport countRemoveBefore = report.metrics(0);
488 EXPECT_EQ(countRemoveBefore.metric_id(), countRemove.id());
489 EXPECT_TRUE(countRemoveBefore.has_count_metrics());
490 ASSERT_EQ(countRemoveBefore.count_metrics().data_size(), 1);
491 auto data = countRemoveBefore.count_metrics().data(0);
492 ASSERT_EQ(data.bucket_info_size(), 1);
493 ValidateCountBucket(data.bucket_info(0), bucketStartTimeNs, updateTimeNs, 5);
494
495 // Uid 1 had 2 syncs, uid 2 had 1 sync.
496 StatsLogReport countPersistBefore = report.metrics(1);
497 EXPECT_EQ(countPersistBefore.metric_id(), countPersist.id());
498 EXPECT_TRUE(countPersistBefore.has_count_metrics());
499 StatsLogReport::CountMetricDataWrapper countMetrics;
500 sortMetricDataByDimensionsValue(countPersistBefore.count_metrics(), &countMetrics);
501 ASSERT_EQ(countMetrics.data_size(), 2);
502 data = countMetrics.data(0);
503 ValidateAttributionUidDimension(data.dimensions_in_what(), util::SYNC_STATE_CHANGED, app1Uid);
504 ValidateStateValue(data.slice_by_state(), util::UID_PROCESS_STATE_CHANGED,
505 android::app::ProcessStateEnum::PROCESS_STATE_IMPORTANT_BACKGROUND);
506 ASSERT_EQ(data.bucket_info_size(), 1);
507 ValidateCountBucket(data.bucket_info(0), bucketStartTimeNs, updateTimeNs, 2);
508
509 data = countMetrics.data(1);
510 ValidateAttributionUidDimension(data.dimensions_in_what(), util::SYNC_STATE_CHANGED, app2Uid);
511 ValidateStateValue(data.slice_by_state(), util::UID_PROCESS_STATE_CHANGED,
512 android::app::ProcessStateEnum::PROCESS_STATE_IMPORTANT_FOREGROUND);
513 ASSERT_EQ(data.bucket_info_size(), 1);
514 ValidateCountBucket(data.bucket_info(0), bucketStartTimeNs, updateTimeNs, 1);
515
516 // Counts syncs while screen on. There were 4 before the update.
517 StatsLogReport countChangeBefore = report.metrics(2);
518 EXPECT_EQ(countChangeBefore.metric_id(), countChange.id());
519 EXPECT_TRUE(countChangeBefore.has_count_metrics());
520 ASSERT_EQ(countChangeBefore.count_metrics().data_size(), 1);
521 data = countChangeBefore.count_metrics().data(0);
522 ASSERT_EQ(data.bucket_info_size(), 1);
523 ValidateCountBucket(data.bucket_info(0), bucketStartTimeNs, updateTimeNs, 4, 50 * NS_PER_SEC);
524
525 // Report from after update.
526 report = reports.reports(1);
527 ASSERT_EQ(report.metrics_size(), 3);
528 // Count screen on while screen is on. There was 1 after the update.
529 StatsLogReport countChangeAfter = report.metrics(0);
530 EXPECT_EQ(countChangeAfter.metric_id(), countChange.id());
531 EXPECT_TRUE(countChangeAfter.has_count_metrics());
532 ASSERT_EQ(countChangeAfter.count_metrics().data_size(), 1);
533 data = countChangeAfter.count_metrics().data(0);
534 ASSERT_EQ(data.bucket_info_size(), 1);
535 ValidateCountBucket(data.bucket_info(0), updateTimeNs, bucketStartTimeNs + bucketSizeNs, 1,
536 530 * NS_PER_SEC);
537
538 // Count wl acquires while screen on. There were 2, one in each bucket.
539 StatsLogReport countNewAfter = report.metrics(1);
540 EXPECT_EQ(countNewAfter.metric_id(), countNew.id());
541 EXPECT_TRUE(countNewAfter.has_count_metrics());
542 ASSERT_EQ(countNewAfter.count_metrics().data_size(), 1);
543 data = countNewAfter.count_metrics().data(0);
544 ASSERT_EQ(data.bucket_info_size(), 2);
545 ValidateCountBucket(data.bucket_info(0), updateTimeNs, bucketStartTimeNs + bucketSizeNs, 1,
546 530 * NS_PER_SEC);
547 ValidateCountBucket(data.bucket_info(1), bucketStartTimeNs + bucketSizeNs, dumpTimeNs, 1,
548 10 * NS_PER_SEC);
549
550 // Uid 1 had 1 sync, uid 2 had 2 syncs.
551 StatsLogReport countPersistAfter = report.metrics(2);
552 EXPECT_EQ(countPersistAfter.metric_id(), countPersist.id());
553 EXPECT_TRUE(countPersistAfter.has_count_metrics());
554 countMetrics.Clear();
555 sortMetricDataByDimensionsValue(countPersistAfter.count_metrics(), &countMetrics);
556 ASSERT_EQ(countMetrics.data_size(), 2);
557 data = countMetrics.data(0);
558 ValidateAttributionUidDimension(data.dimensions_in_what(), util::SYNC_STATE_CHANGED, app1Uid);
559 ValidateStateValue(data.slice_by_state(), util::UID_PROCESS_STATE_CHANGED,
560 android::app::ProcessStateEnum::PROCESS_STATE_IMPORTANT_BACKGROUND);
561 ASSERT_EQ(data.bucket_info_size(), 1);
562 ValidateCountBucket(data.bucket_info(0), updateTimeNs, bucketStartTimeNs + bucketSizeNs, 1);
563
564 data = countMetrics.data(1);
565 ValidateAttributionUidDimension(data.dimensions_in_what(), util::SYNC_STATE_CHANGED, app2Uid);
566 ValidateStateValue(data.slice_by_state(), util::UID_PROCESS_STATE_CHANGED,
567 android::app::ProcessStateEnum::PROCESS_STATE_IMPORTANT_FOREGROUND);
568 ASSERT_EQ(data.bucket_info_size(), 1);
569 ValidateCountBucket(data.bucket_info(0), updateTimeNs, bucketStartTimeNs + bucketSizeNs, 2);
570 }
571
TEST_P(ConfigUpdateE2eTest,TestDurationMetric)572 TEST_P(ConfigUpdateE2eTest, TestDurationMetric) {
573 StatsdConfig config;
574 config.add_allowed_log_source("AID_ROOT");
575
576 AtomMatcher syncStartMatcher = CreateSyncStartAtomMatcher();
577 *config.add_atom_matcher() = syncStartMatcher;
578 AtomMatcher syncStopMatcher = CreateSyncEndAtomMatcher();
579 *config.add_atom_matcher() = syncStopMatcher;
580 AtomMatcher wakelockAcquireMatcher = CreateAcquireWakelockAtomMatcher();
581 *config.add_atom_matcher() = wakelockAcquireMatcher;
582 AtomMatcher wakelockReleaseMatcher = CreateReleaseWakelockAtomMatcher();
583 *config.add_atom_matcher() = wakelockReleaseMatcher;
584 AtomMatcher screenOnMatcher = CreateScreenTurnedOnAtomMatcher();
585 *config.add_atom_matcher() = screenOnMatcher;
586 AtomMatcher screenOffMatcher = CreateScreenTurnedOffAtomMatcher();
587 *config.add_atom_matcher() = screenOffMatcher;
588
589 Predicate holdingWakelockPredicate = CreateHoldingWakelockPredicate();
590 // The predicate is dimensioning by first attribution node by uid.
591 *holdingWakelockPredicate.mutable_simple_predicate()->mutable_dimensions() =
592 CreateAttributionUidDimensions(util::WAKELOCK_STATE_CHANGED, {Position::FIRST});
593 *config.add_predicate() = holdingWakelockPredicate;
594
595 Predicate screenOnPredicate = CreateScreenIsOnPredicate();
596 *config.add_predicate() = screenOnPredicate;
597
598 Predicate syncPredicate = CreateIsSyncingPredicate();
599 // The predicate is dimensioning by first attribution node by uid.
600 *syncPredicate.mutable_simple_predicate()->mutable_dimensions() =
601 CreateAttributionUidDimensions(util::SYNC_STATE_CHANGED, {Position::FIRST});
602 *config.add_predicate() = syncPredicate;
603
604 State uidProcessState = CreateUidProcessState();
605 *config.add_state() = uidProcessState;
606
607 DurationMetric durationSumPersist =
608 createDurationMetric("DurSyncPerUidWhileHoldingWLSliceProcessState", syncPredicate.id(),
609 holdingWakelockPredicate.id(), {uidProcessState.id()});
610 *durationSumPersist.mutable_dimensions_in_what() =
611 CreateAttributionUidDimensions(util::SYNC_STATE_CHANGED, {Position::FIRST});
612 // Links between sync state atom and condition of uid is holding wakelock.
613 MetricConditionLink* links = durationSumPersist.add_links();
614 links->set_condition(holdingWakelockPredicate.id());
615 *links->mutable_fields_in_what() =
616 CreateAttributionUidDimensions(util::SYNC_STATE_CHANGED, {Position::FIRST});
617 *links->mutable_fields_in_condition() =
618 CreateAttributionUidDimensions(util::WAKELOCK_STATE_CHANGED, {Position::FIRST});
619 MetricStateLink* stateLink = durationSumPersist.add_state_link();
620 stateLink->set_state_atom_id(util::UID_PROCESS_STATE_CHANGED);
621 *stateLink->mutable_fields_in_what() =
622 CreateAttributionUidDimensions(util::SYNC_STATE_CHANGED, {Position::FIRST});
623 *stateLink->mutable_fields_in_state() =
624 CreateDimensions(util::UID_PROCESS_STATE_CHANGED, {1 /*uid*/});
625
626 DurationMetric durationMaxPersist =
627 createDurationMetric("DurMaxSyncPerUidWhileHoldingWL", syncPredicate.id(),
628 holdingWakelockPredicate.id(), {});
629 durationMaxPersist.set_aggregation_type(DurationMetric::MAX_SPARSE);
630 *durationMaxPersist.mutable_dimensions_in_what() =
631 CreateAttributionUidDimensions(util::SYNC_STATE_CHANGED, {Position::FIRST});
632 // Links between sync state atom and condition of uid is holding wakelock.
633 links = durationMaxPersist.add_links();
634 links->set_condition(holdingWakelockPredicate.id());
635 *links->mutable_fields_in_what() =
636 CreateAttributionUidDimensions(util::SYNC_STATE_CHANGED, {Position::FIRST});
637 *links->mutable_fields_in_condition() =
638 CreateAttributionUidDimensions(util::WAKELOCK_STATE_CHANGED, {Position::FIRST});
639
640 DurationMetric durationChange = createDurationMetric("Dur*WhileScreenOn", syncPredicate.id(),
641 screenOnPredicate.id(), {});
642 DurationMetric durationRemove =
643 createDurationMetric("DurScreenOn", screenOnPredicate.id(), nullopt, {});
644 *config.add_duration_metric() = durationMaxPersist;
645 *config.add_duration_metric() = durationRemove;
646 *config.add_duration_metric() = durationSumPersist;
647 *config.add_duration_metric() = durationChange;
648
649 ConfigKey key(123, 987);
650 uint64_t bucketStartTimeNs = 10000000000; // 0:10
651 uint64_t bucketSizeNs = TimeUnitToBucketSizeInMillis(TEN_MINUTES) * 1000000LL;
652 sp<StatsLogProcessor> processor = CreateStatsLogProcessor(bucketStartTimeNs, bucketStartTimeNs,
653 config, key, mLogEventFilter);
654
655 int app1Uid = 123, app2Uid = 456, app3Uid = 789;
656 vector<int> attributionUids1 = {app1Uid};
657 vector<string> attributionTags1 = {"App1"};
658 vector<int> attributionUids2 = {app2Uid};
659 vector<string> attributionTags2 = {"App2"};
660 vector<int> attributionUids3 = {app3Uid};
661 vector<string> attributionTags3 = {"App3"};
662
663 // Initialize log events before update. Comments provided for durations of persisted metrics.
664 std::vector<std::unique_ptr<LogEvent>> events;
665 events.push_back(CreateUidProcessStateChangedEvent(
666 bucketStartTimeNs + 2 * NS_PER_SEC, app1Uid,
667 android::app::ProcessStateEnum::PROCESS_STATE_IMPORTANT_BACKGROUND));
668 events.push_back(CreateUidProcessStateChangedEvent(
669 bucketStartTimeNs + 3 * NS_PER_SEC, app2Uid,
670 android::app::ProcessStateEnum::PROCESS_STATE_IMPORTANT_FOREGROUND));
671 events.push_back(CreateScreenStateChangedEvent(
672 bucketStartTimeNs + 5 * NS_PER_SEC, android::view::DisplayStateEnum::DISPLAY_STATE_ON));
673 events.push_back(CreateUidProcessStateChangedEvent(
674 bucketStartTimeNs + 6 * NS_PER_SEC, app3Uid,
675 android::app::ProcessStateEnum::PROCESS_STATE_IMPORTANT_BACKGROUND));
676 events.push_back(CreateSyncStartEvent(bucketStartTimeNs + 10 * NS_PER_SEC, attributionUids1,
677 attributionTags1, "sync_name")); // uid1 paused.
678 events.push_back(CreateAcquireWakelockEvent(bucketStartTimeNs + 15 * NS_PER_SEC,
679 attributionUids2, attributionTags2,
680 "wl2")); // uid2 cond true.
681 events.push_back(
682 CreateScreenStateChangedEvent(bucketStartTimeNs + 20 * NS_PER_SEC,
683 android::view::DisplayStateEnum::DISPLAY_STATE_OFF));
684 events.push_back(CreateSyncStartEvent(bucketStartTimeNs + 25 * NS_PER_SEC, attributionUids2,
685 attributionTags2, "sync_name")); // Uid 2 start t=25.
686 events.push_back(CreateAcquireWakelockEvent(bucketStartTimeNs + 27 * NS_PER_SEC,
687 attributionUids1, attributionTags1,
688 "wl1")); // Uid 1 start t=27.
689 events.push_back(CreateSyncStartEvent(bucketStartTimeNs + 35 * NS_PER_SEC, attributionUids3,
690 attributionTags3, "sync_name")); // Uid 3 paused.
691 events.push_back(
692 CreateScreenStateChangedEvent(bucketStartTimeNs + 40 * NS_PER_SEC,
693 android::view::DisplayStateEnum::DISPLAY_STATE_ON));
694 events.push_back(CreateSyncEndEvent(bucketStartTimeNs + 45 * NS_PER_SEC, attributionUids2,
695 attributionTags2,
696 "sync_name")); // Uid 2 stop. sum/max = 20.
697 // Send log events to StatsLogProcessor.
698 for (auto& event : events) {
699 processor->OnLogEvent(event.get());
700 }
701
702 // Do update. Add matchers/conditions in different order to force indices to change.
703 StatsdConfig newConfig;
704 newConfig.add_allowed_log_source("AID_ROOT");
705
706 *newConfig.add_atom_matcher() = wakelockReleaseMatcher;
707 *newConfig.add_atom_matcher() = syncStopMatcher;
708 *newConfig.add_atom_matcher() = screenOnMatcher;
709 *newConfig.add_atom_matcher() = screenOffMatcher;
710 *newConfig.add_atom_matcher() = syncStartMatcher;
711 *newConfig.add_atom_matcher() = wakelockAcquireMatcher;
712 *newConfig.add_predicate() = syncPredicate;
713 *newConfig.add_predicate() = screenOnPredicate;
714 *newConfig.add_predicate() = holdingWakelockPredicate;
715 *newConfig.add_state() = uidProcessState;
716
717 durationChange.set_what(holdingWakelockPredicate.id());
718 *newConfig.add_duration_metric() = durationChange;
719 DurationMetric durationNew =
720 createDurationMetric("DurationSync", syncPredicate.id(), nullopt, {});
721 *newConfig.add_duration_metric() = durationNew;
722 *newConfig.add_duration_metric() = durationMaxPersist;
723 *newConfig.add_duration_metric() = durationSumPersist;
724
725 // At update, only uid 1 is syncing & holding a wakelock, duration=33. Max is paused for uid3.
726 // Before the update, only uid2 will report a duration for max, since others are started/paused.
727 int64_t updateTimeNs = bucketStartTimeNs + 60 * NS_PER_SEC;
728 if (GetParam()) {
729 EXPECT_CALL(*mLogEventFilter,
730 setAtomIds(CreateAtomIdSetFromConfig(newConfig), processor.get()))
731 .Times(1);
732 }
733 processor->OnConfigUpdated(updateTimeNs, key, newConfig);
734
735 // Send events after the update.
736 events.clear();
737 events.push_back(CreateAcquireWakelockEvent(bucketStartTimeNs + 65 * NS_PER_SEC,
738 attributionUids3, attributionTags3,
739 "wl3")); // Uid3 start t=65.
740 events.push_back(CreateSyncStartEvent(bucketStartTimeNs + 70 * NS_PER_SEC, attributionUids2,
741 attributionTags2, "sync_name")); // Uid2 start t=70.
742 events.push_back(CreateReleaseWakelockEvent(bucketStartTimeNs + 75 * NS_PER_SEC,
743 attributionUids1, attributionTags1,
744 "wl1")); // Uid1 Pause. Dur = 15.
745 events.push_back(
746 CreateScreenStateChangedEvent(bucketStartTimeNs + 81 * NS_PER_SEC,
747 android::view::DisplayStateEnum::DISPLAY_STATE_OFF));
748 events.push_back(CreateUidProcessStateChangedEvent(
749 bucketStartTimeNs + 85 * NS_PER_SEC, app3Uid,
750 android::app::ProcessStateEnum::
751 PROCESS_STATE_IMPORTANT_FOREGROUND)); // Uid3 Sum in BG: 20. FG starts. Max is
752 // unchanged.
753 events.push_back(CreateSyncEndEvent(bucketStartTimeNs + 90 * NS_PER_SEC, attributionUids3,
754 attributionTags3,
755 "sync_name")); // Uid3 stop. Sum in FG: 5. MAX: 25.
756
757 // Flushes bucket. Sum: uid1=15, uid2=bucketSize - 70, uid3 = 20 in FG, 5 in BG. Max: uid3=25,
758 // others don't report.
759 events.push_back(CreateSyncEndEvent(bucketStartTimeNs + bucketSizeNs + NS_PER_SEC,
760 attributionUids1, attributionTags1,
761 "sync_name")); // Uid1 stop. Max=15+33=48, Sum is 0.
762
763 // Send log events to StatsLogProcessor.
764 for (auto& event : events) {
765 processor->OnLogEvent(event.get());
766 }
767 uint64_t bucketEndTimeNs = bucketStartTimeNs + bucketSizeNs;
768 uint64_t dumpTimeNs = bucketStartTimeNs + bucketSizeNs + 10 * NS_PER_SEC;
769 ConfigMetricsReportList reports;
770 vector<uint8_t> buffer;
771 // In the partial bucket, Sum for uid2 = 10, Max for Uid1 = 48. Rest are unreported.
772 processor->onDumpReport(key, dumpTimeNs, true, true, ADB_DUMP, FAST, &buffer);
773 EXPECT_TRUE(reports.ParseFromArray(&buffer[0], buffer.size()));
774 backfillDimensionPath(&reports);
775 backfillStringInReport(&reports);
776 backfillStartEndTimestamp(&reports);
777 ASSERT_EQ(reports.reports_size(), 2);
778
779 // Report from before update.
780 ConfigMetricsReport report = reports.reports(0);
781 ASSERT_EQ(report.metrics_size(), 4);
782 // Max duration of syncs per uid while uid holding WL. Only uid2 should have data.
783 StatsLogReport durationMaxPersistBefore = report.metrics(0);
784 EXPECT_EQ(durationMaxPersistBefore.metric_id(), durationMaxPersist.id());
785 EXPECT_TRUE(durationMaxPersistBefore.has_duration_metrics());
786 StatsLogReport::DurationMetricDataWrapper durationMetrics;
787 sortMetricDataByDimensionsValue(durationMaxPersistBefore.duration_metrics(), &durationMetrics);
788 ASSERT_EQ(durationMetrics.data_size(), 1);
789 auto data = durationMetrics.data(0);
790 ValidateAttributionUidDimension(data.dimensions_in_what(), util::SYNC_STATE_CHANGED, app2Uid);
791 ASSERT_EQ(data.bucket_info_size(), 1);
792 ValidateDurationBucket(data.bucket_info(0), bucketStartTimeNs, updateTimeNs, 20 * NS_PER_SEC);
793
794 // Screen on time. ON: 5, OFF: 20, ON: 40. Update: 60. Result: 35
795 StatsLogReport durationRemoveBefore = report.metrics(1);
796 EXPECT_EQ(durationRemoveBefore.metric_id(), durationRemove.id());
797 EXPECT_TRUE(durationRemoveBefore.has_duration_metrics());
798 durationMetrics.Clear();
799 sortMetricDataByDimensionsValue(durationRemoveBefore.duration_metrics(), &durationMetrics);
800 ASSERT_EQ(durationMetrics.data_size(), 1);
801 data = durationMetrics.data(0);
802 ASSERT_EQ(data.bucket_info_size(), 1);
803 ValidateDurationBucket(data.bucket_info(0), bucketStartTimeNs, updateTimeNs, 35 * NS_PER_SEC);
804
805 // Duration of syncs per uid while uid holding WL, slice screen. Uid1=33, uid2=20.
806 StatsLogReport durationSumPersistBefore = report.metrics(2);
807 EXPECT_EQ(durationSumPersistBefore.metric_id(), durationSumPersist.id());
808 EXPECT_TRUE(durationSumPersistBefore.has_duration_metrics());
809 durationMetrics.Clear();
810 sortMetricDataByDimensionsValue(durationSumPersistBefore.duration_metrics(), &durationMetrics);
811 ASSERT_EQ(durationMetrics.data_size(), 2);
812 data = durationMetrics.data(0);
813 ValidateAttributionUidDimension(data.dimensions_in_what(), util::SYNC_STATE_CHANGED, app1Uid);
814 ValidateStateValue(data.slice_by_state(), util::UID_PROCESS_STATE_CHANGED,
815 android::app::ProcessStateEnum::PROCESS_STATE_IMPORTANT_BACKGROUND);
816 ASSERT_EQ(data.bucket_info_size(), 1);
817 ValidateDurationBucket(data.bucket_info(0), bucketStartTimeNs, updateTimeNs, 33 * NS_PER_SEC);
818
819 data = durationMetrics.data(1);
820 ValidateAttributionUidDimension(data.dimensions_in_what(), util::SYNC_STATE_CHANGED, app2Uid);
821 ValidateStateValue(data.slice_by_state(), util::UID_PROCESS_STATE_CHANGED,
822 android::app::ProcessStateEnum::PROCESS_STATE_IMPORTANT_FOREGROUND);
823 ASSERT_EQ(data.bucket_info_size(), 1);
824 ValidateDurationBucket(data.bucket_info(0), bucketStartTimeNs, updateTimeNs, 20 * NS_PER_SEC);
825
826 // Duration of syncs while screen on. Start: 10, pause: 20, start: 40 Update: 60. Total: 30.
827 StatsLogReport durationChangeBefore = report.metrics(3);
828 EXPECT_EQ(durationChangeBefore.metric_id(), durationChange.id());
829 EXPECT_TRUE(durationChangeBefore.has_duration_metrics());
830 durationMetrics.Clear();
831 sortMetricDataByDimensionsValue(durationChangeBefore.duration_metrics(), &durationMetrics);
832 ASSERT_EQ(durationMetrics.data_size(), 1);
833 data = durationMetrics.data(0);
834 ASSERT_EQ(data.bucket_info_size(), 1);
835 ValidateDurationBucket(data.bucket_info(0), bucketStartTimeNs, updateTimeNs, 30 * NS_PER_SEC,
836 35000000000);
837
838 // Report from after update.
839 report = reports.reports(1);
840 ASSERT_EQ(report.metrics_size(), 4);
841 // Duration of WL while screen on. Update: 60, pause: 81. Total: 21.
842 StatsLogReport durationChangeAfter = report.metrics(0);
843 EXPECT_EQ(durationChangeAfter.metric_id(), durationChange.id());
844 EXPECT_TRUE(durationChangeAfter.has_duration_metrics());
845 durationMetrics.Clear();
846 sortMetricDataByDimensionsValue(durationChangeAfter.duration_metrics(), &durationMetrics);
847 ASSERT_EQ(durationMetrics.data_size(), 1);
848 data = durationMetrics.data(0);
849 ASSERT_EQ(data.bucket_info_size(), 1);
850 ValidateDurationBucket(data.bucket_info(0), updateTimeNs, bucketEndTimeNs, 21 * NS_PER_SEC,
851 21000000000);
852
853 // Duration of syncs. Always true since at least 1 uid is always syncing.
854 StatsLogReport durationNewAfter = report.metrics(1);
855 EXPECT_EQ(durationNewAfter.metric_id(), durationNew.id());
856 EXPECT_TRUE(durationNewAfter.has_duration_metrics());
857 durationMetrics.Clear();
858 sortMetricDataByDimensionsValue(durationNewAfter.duration_metrics(), &durationMetrics);
859 ASSERT_EQ(durationMetrics.data_size(), 1);
860 data = durationMetrics.data(0);
861 ASSERT_EQ(data.bucket_info_size(), 2);
862 ValidateDurationBucket(data.bucket_info(0), updateTimeNs, bucketEndTimeNs,
863 bucketEndTimeNs - updateTimeNs);
864 ValidateDurationBucket(data.bucket_info(1), bucketEndTimeNs, dumpTimeNs,
865 dumpTimeNs - bucketEndTimeNs);
866
867 // Max duration of syncs per uid while uid holding WL.
868 StatsLogReport durationMaxPersistAfter = report.metrics(2);
869 EXPECT_EQ(durationMaxPersistAfter.metric_id(), durationMaxPersist.id());
870 EXPECT_TRUE(durationMaxPersistAfter.has_duration_metrics());
871 durationMetrics.Clear();
872 sortMetricDataByDimensionsValue(durationMaxPersistAfter.duration_metrics(), &durationMetrics);
873 ASSERT_EQ(durationMetrics.data_size(), 2);
874
875 // Uid 1. Duration = 48 in the later bucket.
876 data = durationMetrics.data(0);
877 ValidateAttributionUidDimension(data.dimensions_in_what(), util::SYNC_STATE_CHANGED, app1Uid);
878 ASSERT_EQ(data.bucket_info_size(), 1);
879 ValidateDurationBucket(data.bucket_info(0), bucketEndTimeNs, dumpTimeNs, 48 * NS_PER_SEC);
880
881 // Uid 3. Duration = 25.
882 data = durationMetrics.data(1);
883 ValidateAttributionUidDimension(data.dimensions_in_what(), util::SYNC_STATE_CHANGED, app3Uid);
884 ASSERT_EQ(data.bucket_info_size(), 1);
885 ValidateDurationBucket(data.bucket_info(0), updateTimeNs, bucketEndTimeNs, 25 * NS_PER_SEC);
886
887 // Duration of syncs per uid while uid holding WL, slice screen.
888 StatsLogReport durationSumPersistAfter = report.metrics(3);
889 EXPECT_EQ(durationSumPersistAfter.metric_id(), durationSumPersist.id());
890 EXPECT_TRUE(durationSumPersistAfter.has_duration_metrics());
891 durationMetrics.Clear();
892 sortMetricDataByDimensionsValue(durationSumPersistAfter.duration_metrics(), &durationMetrics);
893 ASSERT_EQ(durationMetrics.data_size(), 4);
894
895 // Uid 1 in BG. Duration = 15.
896 data = durationMetrics.data(0);
897 ValidateAttributionUidDimension(data.dimensions_in_what(), util::SYNC_STATE_CHANGED, app1Uid);
898 ValidateStateValue(data.slice_by_state(), util::UID_PROCESS_STATE_CHANGED,
899 android::app::ProcessStateEnum::PROCESS_STATE_IMPORTANT_BACKGROUND);
900 ASSERT_EQ(data.bucket_info_size(), 1);
901 ValidateDurationBucket(data.bucket_info(0), updateTimeNs, bucketEndTimeNs, 15 * NS_PER_SEC);
902
903 // Uid 2 in FG. Duration = bucketSize - 70 in first bucket, 10 in second bucket.
904 data = durationMetrics.data(1);
905 ValidateAttributionUidDimension(data.dimensions_in_what(), util::SYNC_STATE_CHANGED, app2Uid);
906 ValidateStateValue(data.slice_by_state(), util::UID_PROCESS_STATE_CHANGED,
907 android::app::ProcessStateEnum::PROCESS_STATE_IMPORTANT_FOREGROUND);
908 ASSERT_EQ(data.bucket_info_size(), 2);
909 ValidateDurationBucket(data.bucket_info(0), updateTimeNs, bucketEndTimeNs,
910 bucketSizeNs - 70 * NS_PER_SEC);
911 ValidateDurationBucket(data.bucket_info(1), bucketEndTimeNs, dumpTimeNs, 10 * NS_PER_SEC);
912
913 // Uid 3 in FG. Duration = 5.
914 data = durationMetrics.data(2);
915 ValidateAttributionUidDimension(data.dimensions_in_what(), util::SYNC_STATE_CHANGED, app3Uid);
916 ValidateStateValue(data.slice_by_state(), util::UID_PROCESS_STATE_CHANGED,
917 android::app::ProcessStateEnum::PROCESS_STATE_IMPORTANT_FOREGROUND);
918 ASSERT_EQ(data.bucket_info_size(), 1);
919 ValidateDurationBucket(data.bucket_info(0), updateTimeNs, bucketEndTimeNs, 5 * NS_PER_SEC);
920
921 // Uid 3 in BG. Duration = 20.
922 data = durationMetrics.data(3);
923 ValidateAttributionUidDimension(data.dimensions_in_what(), util::SYNC_STATE_CHANGED, app3Uid);
924 ValidateStateValue(data.slice_by_state(), util::UID_PROCESS_STATE_CHANGED,
925 android::app::ProcessStateEnum::PROCESS_STATE_IMPORTANT_BACKGROUND);
926 ASSERT_EQ(data.bucket_info_size(), 1);
927 ValidateDurationBucket(data.bucket_info(0), updateTimeNs, bucketEndTimeNs, 20 * NS_PER_SEC);
928 }
929
TEST_P(ConfigUpdateE2eTest,TestGaugeMetric)930 TEST_P(ConfigUpdateE2eTest, TestGaugeMetric) {
931 StatsdConfig config;
932 config.add_allowed_log_source("AID_ROOT");
933 config.add_default_pull_packages("AID_ROOT"); // Fake puller is registered with root.
934
935 AtomMatcher appStartMatcher = CreateSimpleAtomMatcher("AppStart", util::APP_START_OCCURRED);
936 *config.add_atom_matcher() = appStartMatcher;
937 AtomMatcher backgroundMatcher = CreateMoveToBackgroundAtomMatcher();
938 *config.add_atom_matcher() = backgroundMatcher;
939 AtomMatcher foregroundMatcher = CreateMoveToForegroundAtomMatcher();
940 *config.add_atom_matcher() = foregroundMatcher;
941 AtomMatcher screenOnMatcher = CreateScreenTurnedOnAtomMatcher();
942 *config.add_atom_matcher() = screenOnMatcher;
943 AtomMatcher screenOffMatcher = CreateScreenTurnedOffAtomMatcher();
944 *config.add_atom_matcher() = screenOffMatcher;
945 AtomMatcher subsystemSleepMatcher =
946 CreateSimpleAtomMatcher("SubsystemSleep", util::SUBSYSTEM_SLEEP_STATE);
947 *config.add_atom_matcher() = subsystemSleepMatcher;
948
949 Predicate isInBackgroundPredicate = CreateIsInBackgroundPredicate();
950 *isInBackgroundPredicate.mutable_simple_predicate()->mutable_dimensions() =
951 CreateDimensions(util::ACTIVITY_FOREGROUND_STATE_CHANGED, {1 /*uid field*/});
952 *config.add_predicate() = isInBackgroundPredicate;
953
954 Predicate screenOnPredicate = CreateScreenIsOnPredicate();
955 *config.add_predicate() = screenOnPredicate;
956
957 GaugeMetric gaugePullPersist =
958 createGaugeMetric("SubsystemSleepWhileScreenOn", subsystemSleepMatcher.id(),
959 GaugeMetric::RANDOM_ONE_SAMPLE, screenOnPredicate.id(), {});
960 *gaugePullPersist.mutable_dimensions_in_what() =
961 CreateDimensions(util::SUBSYSTEM_SLEEP_STATE, {1 /* subsystem name */});
962
963 GaugeMetric gaugePushPersist =
964 createGaugeMetric("AppStartWhileInBg", appStartMatcher.id(),
965 GaugeMetric::FIRST_N_SAMPLES, isInBackgroundPredicate.id(), nullopt);
966 *gaugePushPersist.mutable_dimensions_in_what() =
967 CreateDimensions(util::APP_START_OCCURRED, {1 /*uid field*/});
968 // Links between sync state atom and condition of uid is holding wakelock.
969 MetricConditionLink* links = gaugePushPersist.add_links();
970 links->set_condition(isInBackgroundPredicate.id());
971 *links->mutable_fields_in_what() =
972 CreateDimensions(util::APP_START_OCCURRED, {1 /*uid field*/});
973 *links->mutable_fields_in_condition() =
974 CreateDimensions(util::ACTIVITY_FOREGROUND_STATE_CHANGED, {1 /*uid field*/});
975
976 GaugeMetric gaugeChange = createGaugeMetric("GaugeScrOn", screenOnMatcher.id(),
977 GaugeMetric::RANDOM_ONE_SAMPLE, nullopt, nullopt);
978 GaugeMetric gaugeRemove =
979 createGaugeMetric("GaugeSubsysTriggerScr", subsystemSleepMatcher.id(),
980 GaugeMetric::FIRST_N_SAMPLES, nullopt, screenOnMatcher.id());
981 *gaugeRemove.mutable_dimensions_in_what() =
982 CreateDimensions(util::SUBSYSTEM_SLEEP_STATE, {1 /* subsystem name */});
983 *config.add_gauge_metric() = gaugeRemove;
984 *config.add_gauge_metric() = gaugePullPersist;
985 *config.add_gauge_metric() = gaugeChange;
986 *config.add_gauge_metric() = gaugePushPersist;
987
988 ConfigKey key(123, 987);
989 uint64_t bucketStartTimeNs = getElapsedRealtimeNs(); // 0:10
990 uint64_t bucketSizeNs = TimeUnitToBucketSizeInMillis(TEN_MINUTES) * 1000000LL;
991 if (GetParam()) {
992 // call from StatsLogProcessor constructor
993 Expectation initCall = EXPECT_CALL(*mLogEventFilter,
994 setAtomIds(StatsLogProcessor::getDefaultAtomIdSet(), _))
995 .Times(1);
996 EXPECT_CALL(*mLogEventFilter, setAtomIds(CreateAtomIdSetFromConfig(config), _))
997 .Times(1)
998 .After(initCall);
999 }
1000 sp<StatsLogProcessor> processor =
1001 CreateStatsLogProcessor(bucketStartTimeNs, bucketStartTimeNs, config, key,
1002 SharedRefBase::make<FakeSubsystemSleepCallback>(),
1003 util::SUBSYSTEM_SLEEP_STATE, new UidMap(), mLogEventFilter);
1004
1005 int app1Uid = 123, app2Uid = 456;
1006
1007 // Initialize log events before update.
1008 std::vector<std::unique_ptr<LogEvent>> events;
1009 events.push_back(CreateMoveToBackgroundEvent(bucketStartTimeNs + 5 * NS_PER_SEC, app1Uid));
1010 events.push_back(CreateAppStartOccurredEvent(bucketStartTimeNs + 10 * NS_PER_SEC, app1Uid,
1011 "app1", AppStartOccurred::WARM, "", "", true,
1012 /*start_msec*/ 101)); // Kept by gaugePushPersist.
1013 events.push_back(
1014 CreateAppStartOccurredEvent(bucketStartTimeNs + 15 * NS_PER_SEC, app2Uid, "app2",
1015 AppStartOccurred::WARM, "", "", true,
1016 /*start_msec*/ 201)); // Not kept by gaugePushPersist.
1017 events.push_back(CreateScreenStateChangedEvent(
1018 bucketStartTimeNs + 20 * NS_PER_SEC,
1019 android::view::DISPLAY_STATE_ON)); // Pulls gaugePullPersist and gaugeRemove.
1020 events.push_back(CreateMoveToBackgroundEvent(bucketStartTimeNs + 25 * NS_PER_SEC, app2Uid));
1021 events.push_back(
1022 CreateScreenStateChangedEvent(bucketStartTimeNs + 30 * NS_PER_SEC,
1023 android::view::DisplayStateEnum::DISPLAY_STATE_OFF));
1024 events.push_back(CreateAppStartOccurredEvent(bucketStartTimeNs + 35 * NS_PER_SEC, app1Uid,
1025 "app1", AppStartOccurred::WARM, "", "", true,
1026 /*start_msec*/ 102)); // Kept by gaugePushPersist.
1027 events.push_back(CreateAppStartOccurredEvent(bucketStartTimeNs + 40 * NS_PER_SEC, app2Uid,
1028 "app2", AppStartOccurred::WARM, "", "", true,
1029 /*start_msec*/ 202)); // Kept by gaugePushPersist.
1030 events.push_back(CreateScreenStateChangedEvent(
1031 bucketStartTimeNs + 45 * NS_PER_SEC,
1032 android::view::DisplayStateEnum::DISPLAY_STATE_ON)); // Pulls gaugeRemove only.
1033 events.push_back(CreateMoveToForegroundEvent(bucketStartTimeNs + 50 * NS_PER_SEC, app1Uid));
1034
1035 // Send log events to StatsLogProcessor.
1036 for (auto& event : events) {
1037 processor->mPullerManager->ForceClearPullerCache();
1038 processor->OnLogEvent(event.get());
1039 }
1040 processor->mPullerManager->ForceClearPullerCache();
1041
1042 // Do the update. Add matchers/conditions in different order to force indices to change.
1043 StatsdConfig newConfig;
1044 newConfig.add_allowed_log_source("AID_ROOT");
1045 newConfig.add_default_pull_packages("AID_ROOT"); // Fake puller is registered with root.
1046
1047 *newConfig.add_atom_matcher() = screenOffMatcher;
1048 *newConfig.add_atom_matcher() = foregroundMatcher;
1049 *newConfig.add_atom_matcher() = appStartMatcher;
1050 *newConfig.add_atom_matcher() = subsystemSleepMatcher;
1051 *newConfig.add_atom_matcher() = backgroundMatcher;
1052 *newConfig.add_atom_matcher() = screenOnMatcher;
1053
1054 *newConfig.add_predicate() = isInBackgroundPredicate;
1055 *newConfig.add_predicate() = screenOnPredicate;
1056
1057 gaugeChange.set_sampling_type(GaugeMetric::FIRST_N_SAMPLES);
1058 *newConfig.add_gauge_metric() = gaugeChange;
1059 GaugeMetric gaugeNew = createGaugeMetric("GaugeSubsys", subsystemSleepMatcher.id(),
1060 GaugeMetric::RANDOM_ONE_SAMPLE, {}, {});
1061 *gaugeNew.mutable_dimensions_in_what() =
1062 CreateDimensions(util::SUBSYSTEM_SLEEP_STATE, {1 /* subsystem name */});
1063 *newConfig.add_gauge_metric() = gaugeNew;
1064 *newConfig.add_gauge_metric() = gaugePushPersist;
1065 *newConfig.add_gauge_metric() = gaugePullPersist;
1066
1067 int64_t updateTimeNs = bucketStartTimeNs + 60 * NS_PER_SEC;
1068 // Update pulls gaugePullPersist and gaugeNew.
1069 if (GetParam()) {
1070 EXPECT_CALL(*mLogEventFilter, setAtomIds(CreateAtomIdSetFromConfig(newConfig), _)).Times(1);
1071 }
1072 processor->OnConfigUpdated(updateTimeNs, key, newConfig);
1073
1074 // Verify puller manager is properly set.
1075 sp<StatsPullerManager> pullerManager = processor->mPullerManager;
1076 EXPECT_EQ(pullerManager->mNextPullTimeNs, bucketStartTimeNs + bucketSizeNs);
1077 ASSERT_EQ(pullerManager->mReceivers.size(), 1);
1078 ASSERT_EQ(pullerManager->mReceivers.begin()->second.size(), 2);
1079
1080 // Send events after the update. Counts reset to 0 since this is a new bucket.
1081 events.clear();
1082 events.push_back(
1083 CreateAppStartOccurredEvent(bucketStartTimeNs + 65 * NS_PER_SEC, app1Uid, "app1",
1084 AppStartOccurred::WARM, "", "", true,
1085 /*start_msec*/ 103)); // Not kept by gaugePushPersist.
1086 events.push_back(CreateAppStartOccurredEvent(bucketStartTimeNs + 70 * NS_PER_SEC, app2Uid,
1087 "app2", AppStartOccurred::WARM, "", "", true,
1088 /*start_msec*/ 203)); // Kept by gaugePushPersist.
1089 events.push_back(
1090 CreateScreenStateChangedEvent(bucketStartTimeNs + 75 * NS_PER_SEC,
1091 android::view::DisplayStateEnum::DISPLAY_STATE_OFF));
1092 events.push_back(
1093 CreateScreenStateChangedEvent(bucketStartTimeNs + 80 * NS_PER_SEC,
1094 android::view::DisplayStateEnum::DISPLAY_STATE_ON));
1095 events.push_back(CreateMoveToBackgroundEvent(bucketStartTimeNs + 85 * NS_PER_SEC, app1Uid));
1096 events.push_back(
1097 CreateScreenStateChangedEvent(bucketStartTimeNs + 90 * NS_PER_SEC,
1098 android::view::DisplayStateEnum::DISPLAY_STATE_OFF));
1099 events.push_back(CreateAppStartOccurredEvent(bucketStartTimeNs + 95 * NS_PER_SEC, app1Uid,
1100 "app1", AppStartOccurred::WARM, "", "", true,
1101 /*start_msec*/ 104)); // Kept by gaugePushPersist.
1102 events.push_back(CreateAppStartOccurredEvent(bucketStartTimeNs + 100 * NS_PER_SEC, app2Uid,
1103 "app2", AppStartOccurred::WARM, "", "", true,
1104 /*start_msec*/ 204)); // Kept by gaugePushPersist.
1105 events.push_back(
1106 CreateScreenStateChangedEvent(bucketStartTimeNs + 105 * NS_PER_SEC,
1107 android::view::DisplayStateEnum::DISPLAY_STATE_ON));
1108 events.push_back(
1109 CreateScreenStateChangedEvent(bucketStartTimeNs + 110 * NS_PER_SEC,
1110 android::view::DisplayStateEnum::DISPLAY_STATE_OFF));
1111 // Send log events to StatsLogProcessor.
1112 for (auto& event : events) {
1113 processor->mPullerManager->ForceClearPullerCache();
1114 processor->OnLogEvent(event.get());
1115 }
1116 processor->mPullerManager->ForceClearPullerCache();
1117 // Pulling alarm arrive, triggering a bucket split. Only gaugeNew keeps the data since the
1118 // condition is false for gaugeNew.
1119 processor->informPullAlarmFired(bucketStartTimeNs + bucketSizeNs);
1120
1121 uint64_t dumpTimeNs = bucketStartTimeNs + bucketSizeNs + 10 * NS_PER_SEC;
1122 ConfigMetricsReportList reports;
1123 vector<uint8_t> buffer;
1124 processor->onDumpReport(key, dumpTimeNs, true, true, ADB_DUMP, FAST, &buffer);
1125 EXPECT_TRUE(reports.ParseFromArray(&buffer[0], buffer.size()));
1126 backfillDimensionPath(&reports);
1127 backfillStringInReport(&reports);
1128 backfillStartEndTimestamp(&reports);
1129 backfillAggregatedAtoms(&reports);
1130 ASSERT_EQ(reports.reports_size(), 2);
1131
1132 int64_t roundedBucketStartNs = MillisToNano(NanoToMillis(bucketStartTimeNs));
1133 int64_t roundedUpdateTimeNs = MillisToNano(NanoToMillis(updateTimeNs));
1134 int64_t roundedBucketEndNs = MillisToNano(NanoToMillis(bucketStartTimeNs + bucketSizeNs));
1135 int64_t roundedDumpTimeNs = MillisToNano(NanoToMillis(dumpTimeNs));
1136
1137 // Report from before update.
1138 ConfigMetricsReport report = reports.reports(0);
1139 ASSERT_EQ(report.metrics_size(), 4);
1140 // Gauge subsystem sleep state trigger screen on. 2 pulls occurred.
1141 StatsLogReport gaugeRemoveBefore = report.metrics(0);
1142 EXPECT_EQ(gaugeRemoveBefore.metric_id(), gaugeRemove.id());
1143 EXPECT_TRUE(gaugeRemoveBefore.has_gauge_metrics());
1144 StatsLogReport::GaugeMetricDataWrapper gaugeMetrics;
1145 sortMetricDataByDimensionsValue(gaugeRemoveBefore.gauge_metrics(), &gaugeMetrics);
1146 ASSERT_EQ(gaugeMetrics.data_size(), 2);
1147 auto data = gaugeMetrics.data(0);
1148 ValidateSubsystemSleepDimension(data.dimensions_in_what(), "subsystem_name_1");
1149 ASSERT_EQ(data.bucket_info_size(), 1);
1150 ValidateGaugeBucketTimes(data.bucket_info(0), roundedBucketStartNs, roundedUpdateTimeNs,
1151 {(int64_t)(bucketStartTimeNs + 20 * NS_PER_SEC),
1152 (int64_t)(bucketStartTimeNs + 45 * NS_PER_SEC)});
1153 ASSERT_EQ(data.bucket_info(0).atom_size(), 2);
1154 EXPECT_EQ(data.bucket_info(0).atom(0).subsystem_sleep_state().time_millis(), 101);
1155 EXPECT_EQ(data.bucket_info(0).atom(1).subsystem_sleep_state().time_millis(), 401);
1156
1157 data = gaugeMetrics.data(1);
1158 ValidateSubsystemSleepDimension(data.dimensions_in_what(), "subsystem_name_2");
1159 ASSERT_EQ(data.bucket_info_size(), 1);
1160 ValidateGaugeBucketTimes(data.bucket_info(0), roundedBucketStartNs, roundedUpdateTimeNs,
1161 {(int64_t)(bucketStartTimeNs + 20 * NS_PER_SEC),
1162 (int64_t)(bucketStartTimeNs + 45 * NS_PER_SEC)});
1163 ASSERT_EQ(data.bucket_info(0).atom_size(), 2);
1164 EXPECT_EQ(data.bucket_info(0).atom(0).subsystem_sleep_state().time_millis(), 102);
1165 EXPECT_EQ(data.bucket_info(0).atom(1).subsystem_sleep_state().time_millis(), 402);
1166
1167 // Gauge subsystem sleep state when screen is on. One pull when the screen turned on
1168 StatsLogReport gaugePullPersistBefore = report.metrics(1);
1169 EXPECT_EQ(gaugePullPersistBefore.metric_id(), gaugePullPersist.id());
1170 EXPECT_TRUE(gaugePullPersistBefore.has_gauge_metrics());
1171 gaugeMetrics.Clear();
1172 sortMetricDataByDimensionsValue(gaugePullPersistBefore.gauge_metrics(), &gaugeMetrics);
1173 ASSERT_EQ(gaugeMetrics.data_size(), 2);
1174 data = gaugeMetrics.data(0);
1175 ValidateSubsystemSleepDimension(data.dimensions_in_what(), "subsystem_name_1");
1176 ASSERT_EQ(data.bucket_info_size(), 1);
1177 ValidateGaugeBucketTimes(data.bucket_info(0), roundedBucketStartNs, roundedUpdateTimeNs,
1178 {(int64_t)(bucketStartTimeNs + 20 * NS_PER_SEC)});
1179 ASSERT_EQ(data.bucket_info(0).atom_size(), 1);
1180 EXPECT_EQ(data.bucket_info(0).atom(0).subsystem_sleep_state().time_millis(), 101);
1181
1182 data = gaugeMetrics.data(1);
1183 ValidateSubsystemSleepDimension(data.dimensions_in_what(), "subsystem_name_2");
1184 ASSERT_EQ(data.bucket_info_size(), 1);
1185 ValidateGaugeBucketTimes(data.bucket_info(0), roundedBucketStartNs, roundedUpdateTimeNs,
1186 {(int64_t)(bucketStartTimeNs + 20 * NS_PER_SEC)});
1187 ASSERT_EQ(data.bucket_info(0).atom_size(), 1);
1188 EXPECT_EQ(data.bucket_info(0).atom(0).subsystem_sleep_state().time_millis(), 102);
1189
1190 // Gauge screen on events, one per bucket.
1191 StatsLogReport gaugeChangeBefore = report.metrics(2);
1192 EXPECT_EQ(gaugeChangeBefore.metric_id(), gaugeChange.id());
1193 EXPECT_TRUE(gaugeChangeBefore.has_gauge_metrics());
1194 gaugeMetrics.Clear();
1195 sortMetricDataByDimensionsValue(gaugeChangeBefore.gauge_metrics(), &gaugeMetrics);
1196 ASSERT_EQ(gaugeMetrics.data_size(), 1);
1197 data = gaugeMetrics.data(0);
1198 ASSERT_EQ(data.bucket_info_size(), 1);
1199 ValidateGaugeBucketTimes(data.bucket_info(0), roundedBucketStartNs, roundedUpdateTimeNs,
1200 {(int64_t)(bucketStartTimeNs + 20 * NS_PER_SEC)});
1201 ASSERT_EQ(data.bucket_info(0).atom_size(), 1);
1202 EXPECT_EQ(data.bucket_info(0).atom(0).screen_state_changed().state(),
1203 android::view::DISPLAY_STATE_ON);
1204
1205 // Gauge app start while app is in the background. App 1 started twice, app 2 started once.
1206 StatsLogReport gaugePushPersistBefore = report.metrics(3);
1207 EXPECT_EQ(gaugePushPersistBefore.metric_id(), gaugePushPersist.id());
1208 EXPECT_TRUE(gaugePushPersistBefore.has_gauge_metrics());
1209 gaugeMetrics.Clear();
1210 sortMetricDataByDimensionsValue(gaugePushPersistBefore.gauge_metrics(), &gaugeMetrics);
1211 ASSERT_EQ(gaugeMetrics.data_size(), 2);
1212 data = gaugeMetrics.data(0);
1213 ValidateUidDimension(data.dimensions_in_what(), util::APP_START_OCCURRED, app1Uid);
1214 ASSERT_EQ(data.bucket_info_size(), 1);
1215 ValidateGaugeBucketTimes(data.bucket_info(0), roundedBucketStartNs, roundedUpdateTimeNs,
1216 {(int64_t)(bucketStartTimeNs + 10 * NS_PER_SEC),
1217 (int64_t)(bucketStartTimeNs + 35 * NS_PER_SEC)});
1218 ASSERT_EQ(data.bucket_info(0).atom_size(), 2);
1219 EXPECT_EQ(data.bucket_info(0).atom(0).app_start_occurred().pkg_name(), "app1");
1220 EXPECT_EQ(data.bucket_info(0).atom(0).app_start_occurred().activity_start_millis(), 101);
1221 EXPECT_EQ(data.bucket_info(0).atom(1).app_start_occurred().pkg_name(), "app1");
1222 EXPECT_EQ(data.bucket_info(0).atom(1).app_start_occurred().activity_start_millis(), 102);
1223
1224 data = gaugeMetrics.data(1);
1225 ValidateUidDimension(data.dimensions_in_what(), util::APP_START_OCCURRED, app2Uid);
1226 ASSERT_EQ(data.bucket_info_size(), 1);
1227 ValidateGaugeBucketTimes(data.bucket_info(0), roundedBucketStartNs, roundedUpdateTimeNs,
1228 {(int64_t)(bucketStartTimeNs + 40 * NS_PER_SEC)});
1229 ASSERT_EQ(data.bucket_info(0).atom_size(), 1);
1230 EXPECT_EQ(data.bucket_info(0).atom(0).app_start_occurred().pkg_name(), "app2");
1231 EXPECT_EQ(data.bucket_info(0).atom(0).app_start_occurred().activity_start_millis(), 202);
1232
1233 // Report from after update.
1234 report = reports.reports(1);
1235 ASSERT_EQ(report.metrics_size(), 4);
1236 // Gauge screen on events FIRST_N_SAMPLES. There were 2.
1237 StatsLogReport gaugeChangeAfter = report.metrics(0);
1238 EXPECT_EQ(gaugeChangeAfter.metric_id(), gaugeChange.id());
1239 EXPECT_TRUE(gaugeChangeAfter.has_gauge_metrics());
1240 gaugeMetrics.Clear();
1241 sortMetricDataByDimensionsValue(gaugeChangeAfter.gauge_metrics(), &gaugeMetrics);
1242 ASSERT_EQ(gaugeMetrics.data_size(), 1);
1243 data = gaugeMetrics.data(0);
1244 ASSERT_EQ(data.bucket_info_size(), 1);
1245 ValidateGaugeBucketTimes(data.bucket_info(0), roundedUpdateTimeNs, roundedBucketEndNs,
1246 {(int64_t)(bucketStartTimeNs + 80 * NS_PER_SEC),
1247 (int64_t)(bucketStartTimeNs + 105 * NS_PER_SEC)});
1248 ASSERT_EQ(data.bucket_info(0).atom_size(), 2);
1249 EXPECT_EQ(data.bucket_info(0).atom(0).screen_state_changed().state(),
1250 android::view::DISPLAY_STATE_ON);
1251 EXPECT_EQ(data.bucket_info(0).atom(1).screen_state_changed().state(),
1252 android::view::DISPLAY_STATE_ON);
1253
1254 // Gauge subsystem sleep state, random one sample, no condition.
1255 // Pulled at update time and after the normal bucket end.
1256 StatsLogReport gaugeNewAfter = report.metrics(1);
1257 EXPECT_EQ(gaugeNewAfter.metric_id(), gaugeNew.id());
1258 EXPECT_TRUE(gaugeNewAfter.has_gauge_metrics());
1259 gaugeMetrics.Clear();
1260 sortMetricDataByDimensionsValue(gaugeNewAfter.gauge_metrics(), &gaugeMetrics);
1261 ASSERT_EQ(gaugeMetrics.data_size(), 2);
1262 data = gaugeMetrics.data(0);
1263 ValidateSubsystemSleepDimension(data.dimensions_in_what(), "subsystem_name_1");
1264 ASSERT_EQ(data.bucket_info_size(), 2);
1265 ValidateGaugeBucketTimes(data.bucket_info(0), roundedUpdateTimeNs, roundedBucketEndNs,
1266 {updateTimeNs});
1267 ASSERT_EQ(data.bucket_info(0).atom_size(), 1);
1268 EXPECT_EQ(data.bucket_info(0).atom(0).subsystem_sleep_state().time_millis(), 901);
1269 ValidateGaugeBucketTimes(data.bucket_info(1), roundedBucketEndNs, roundedDumpTimeNs,
1270 {(int64_t)(bucketStartTimeNs + bucketSizeNs)});
1271 ASSERT_EQ(data.bucket_info(1).atom_size(), 1);
1272 EXPECT_EQ(data.bucket_info(1).atom(0).subsystem_sleep_state().time_millis(), 1601);
1273
1274 data = gaugeMetrics.data(1);
1275 ValidateSubsystemSleepDimension(data.dimensions_in_what(), "subsystem_name_2");
1276 ASSERT_EQ(data.bucket_info_size(), 2);
1277 ValidateGaugeBucketTimes(data.bucket_info(0), roundedUpdateTimeNs, roundedBucketEndNs,
1278 {updateTimeNs});
1279 ASSERT_EQ(data.bucket_info(0).atom_size(), 1);
1280 EXPECT_EQ(data.bucket_info(0).atom(0).subsystem_sleep_state().time_millis(), 902);
1281 ValidateGaugeBucketTimes(data.bucket_info(1), roundedBucketEndNs, roundedDumpTimeNs,
1282 {(int64_t)(bucketStartTimeNs + bucketSizeNs)});
1283 ASSERT_EQ(data.bucket_info(1).atom_size(), 1);
1284 EXPECT_EQ(data.bucket_info(1).atom(0).subsystem_sleep_state().time_millis(), 1602);
1285
1286 // Gauge app start while app is in the background. App 1 started once, app 2 started twice.
1287 StatsLogReport gaugePushPersistAfter = report.metrics(2);
1288 EXPECT_EQ(gaugePushPersistAfter.metric_id(), gaugePushPersist.id());
1289 EXPECT_TRUE(gaugePushPersistAfter.has_gauge_metrics());
1290 gaugeMetrics.Clear();
1291 sortMetricDataByDimensionsValue(gaugePushPersistAfter.gauge_metrics(), &gaugeMetrics);
1292 ASSERT_EQ(gaugeMetrics.data_size(), 2);
1293 data = gaugeMetrics.data(0);
1294 ValidateUidDimension(data.dimensions_in_what(), util::APP_START_OCCURRED, app1Uid);
1295 ASSERT_EQ(data.bucket_info_size(), 1);
1296 ValidateGaugeBucketTimes(data.bucket_info(0), roundedUpdateTimeNs, roundedBucketEndNs,
1297 {(int64_t)(bucketStartTimeNs + 95 * NS_PER_SEC)});
1298 ASSERT_EQ(data.bucket_info(0).atom_size(), 1);
1299 EXPECT_EQ(data.bucket_info(0).atom(0).app_start_occurred().pkg_name(), "app1");
1300 EXPECT_EQ(data.bucket_info(0).atom(0).app_start_occurred().activity_start_millis(), 104);
1301
1302 data = gaugeMetrics.data(1);
1303 ValidateUidDimension(data.dimensions_in_what(), util::APP_START_OCCURRED, app2Uid);
1304 ASSERT_EQ(data.bucket_info_size(), 1);
1305 ValidateGaugeBucketTimes(data.bucket_info(0), roundedUpdateTimeNs, roundedBucketEndNs,
1306 {(int64_t)(bucketStartTimeNs + 70 * NS_PER_SEC),
1307 (int64_t)(bucketStartTimeNs + 100 * NS_PER_SEC)});
1308 ASSERT_EQ(data.bucket_info(0).atom_size(), 2);
1309 EXPECT_EQ(data.bucket_info(0).atom(0).app_start_occurred().pkg_name(), "app2");
1310 EXPECT_EQ(data.bucket_info(0).atom(0).app_start_occurred().activity_start_millis(), 203);
1311 EXPECT_EQ(data.bucket_info(0).atom(1).app_start_occurred().pkg_name(), "app2");
1312 EXPECT_EQ(data.bucket_info(0).atom(1).app_start_occurred().activity_start_millis(), 204);
1313
1314 // Gauge subsystem sleep state when screen is on. One pull at update since screen is on then.
1315 StatsLogReport gaugePullPersistAfter = report.metrics(3);
1316 EXPECT_EQ(gaugePullPersistAfter.metric_id(), gaugePullPersist.id());
1317 EXPECT_TRUE(gaugePullPersistAfter.has_gauge_metrics());
1318 gaugeMetrics.Clear();
1319 sortMetricDataByDimensionsValue(gaugePullPersistAfter.gauge_metrics(), &gaugeMetrics);
1320 ASSERT_EQ(gaugeMetrics.data_size(), 2);
1321 data = gaugeMetrics.data(0);
1322 ValidateSubsystemSleepDimension(data.dimensions_in_what(), "subsystem_name_1");
1323 ASSERT_EQ(data.bucket_info_size(), 1);
1324 ValidateGaugeBucketTimes(data.bucket_info(0), roundedUpdateTimeNs, roundedBucketEndNs,
1325 {updateTimeNs});
1326 ASSERT_EQ(data.bucket_info(0).atom_size(), 1);
1327 EXPECT_EQ(data.bucket_info(0).atom(0).subsystem_sleep_state().time_millis(), 901);
1328
1329 data = gaugeMetrics.data(1);
1330 ValidateSubsystemSleepDimension(data.dimensions_in_what(), "subsystem_name_2");
1331 ASSERT_EQ(data.bucket_info_size(), 1);
1332 ValidateGaugeBucketTimes(data.bucket_info(0), roundedUpdateTimeNs, roundedBucketEndNs,
1333 {updateTimeNs});
1334 ASSERT_EQ(data.bucket_info(0).atom_size(), 1);
1335 EXPECT_EQ(data.bucket_info(0).atom(0).subsystem_sleep_state().time_millis(), 902);
1336 }
1337
TEST_P(ConfigUpdateE2eTest,TestValueMetric)1338 TEST_P(ConfigUpdateE2eTest, TestValueMetric) {
1339 StatsdConfig config;
1340 config.add_allowed_log_source("AID_ROOT");
1341 config.add_default_pull_packages("AID_ROOT"); // Fake puller is registered with root.
1342
1343 AtomMatcher brightnessMatcher = CreateScreenBrightnessChangedAtomMatcher();
1344 *config.add_atom_matcher() = brightnessMatcher;
1345 AtomMatcher screenOnMatcher = CreateScreenTurnedOnAtomMatcher();
1346 *config.add_atom_matcher() = screenOnMatcher;
1347 AtomMatcher screenOffMatcher = CreateScreenTurnedOffAtomMatcher();
1348 *config.add_atom_matcher() = screenOffMatcher;
1349 AtomMatcher batteryPluggedUsbMatcher = CreateBatteryStateUsbMatcher();
1350 *config.add_atom_matcher() = batteryPluggedUsbMatcher;
1351 AtomMatcher unpluggedMatcher = CreateBatteryStateNoneMatcher();
1352 *config.add_atom_matcher() = unpluggedMatcher;
1353 AtomMatcher subsystemSleepMatcher =
1354 CreateSimpleAtomMatcher("SubsystemSleep", util::SUBSYSTEM_SLEEP_STATE);
1355 *config.add_atom_matcher() = subsystemSleepMatcher;
1356
1357 Predicate screenOnPredicate = CreateScreenIsOnPredicate();
1358 *config.add_predicate() = screenOnPredicate;
1359 Predicate unpluggedPredicate = CreateDeviceUnpluggedPredicate();
1360 *config.add_predicate() = unpluggedPredicate;
1361
1362 State screenState = CreateScreenState();
1363 *config.add_state() = screenState;
1364
1365 ValueMetric valuePullPersist =
1366 createValueMetric("SubsystemSleepWhileUnpluggedSliceScreen", subsystemSleepMatcher, 4,
1367 unpluggedPredicate.id(), {screenState.id()});
1368 *valuePullPersist.mutable_dimensions_in_what() =
1369 CreateDimensions(util::SUBSYSTEM_SLEEP_STATE, {1 /* subsystem name */});
1370
1371 ValueMetric valuePushPersist = createValueMetric(
1372 "MinScreenBrightnessWhileScreenOn", brightnessMatcher, 1, screenOnPredicate.id(), {});
1373 valuePushPersist.set_aggregation_type(ValueMetric::MIN);
1374
1375 ValueMetric valueChange =
1376 createValueMetric("SubsystemSleep", subsystemSleepMatcher, 4, nullopt, {});
1377 *valueChange.mutable_dimensions_in_what() =
1378 CreateDimensions(util::SUBSYSTEM_SLEEP_STATE, {1 /* subsystem name */});
1379
1380 ValueMetric valueRemove =
1381 createValueMetric("AvgScreenBrightness", brightnessMatcher, 1, nullopt, {});
1382 valueRemove.set_aggregation_type(ValueMetric::AVG);
1383
1384 *config.add_value_metric() = valuePullPersist;
1385 *config.add_value_metric() = valueRemove;
1386 *config.add_value_metric() = valuePushPersist;
1387 *config.add_value_metric() = valueChange;
1388
1389 ConfigKey key(123, 987);
1390 uint64_t bucketStartTimeNs = getElapsedRealtimeNs();
1391 uint64_t bucketSizeNs = TimeUnitToBucketSizeInMillis(TEN_MINUTES) * 1000000LL;
1392 if (GetParam()) {
1393 // call from StatsLogProcessor constructor
1394 Expectation initCall = EXPECT_CALL(*mLogEventFilter,
1395 setAtomIds(StatsLogProcessor::getDefaultAtomIdSet(), _))
1396 .Times(1);
1397 EXPECT_CALL(*mLogEventFilter, setAtomIds(CreateAtomIdSetFromConfig(config), _))
1398 .Times(1)
1399 .After(initCall);
1400 }
1401 // Config creation triggers pull #1.
1402 sp<StatsLogProcessor> processor =
1403 CreateStatsLogProcessor(bucketStartTimeNs, bucketStartTimeNs, config, key,
1404 SharedRefBase::make<FakeSubsystemSleepCallback>(),
1405 util::SUBSYSTEM_SLEEP_STATE, new UidMap(), mLogEventFilter);
1406
1407 // Initialize log events before update.
1408 // ValuePushPersist and ValuePullPersist will skip the bucket due to condition unknown.
1409 std::vector<std::unique_ptr<LogEvent>> events;
1410 events.push_back(CreateScreenBrightnessChangedEvent(bucketStartTimeNs + 5 * NS_PER_SEC, 5));
1411 events.push_back(CreateScreenStateChangedEvent(bucketStartTimeNs + 10 * NS_PER_SEC,
1412 android::view::DISPLAY_STATE_ON));
1413 events.push_back(CreateScreenBrightnessChangedEvent(bucketStartTimeNs + 15 * NS_PER_SEC, 15));
1414 events.push_back(CreateBatteryStateChangedEvent(
1415 bucketStartTimeNs + 20 * NS_PER_SEC,
1416 BatteryPluggedStateEnum::BATTERY_PLUGGED_NONE)); // Pull #2.
1417 events.push_back(CreateScreenBrightnessChangedEvent(bucketStartTimeNs + 25 * NS_PER_SEC, 40));
1418
1419 // Send log events to StatsLogProcessor.
1420 for (auto& event : events) {
1421 processor->mPullerManager->ForceClearPullerCache();
1422 processor->OnLogEvent(event.get());
1423 }
1424 processor->mPullerManager->ForceClearPullerCache();
1425
1426 // Do the update. Add matchers/conditions in different order to force indices to change.
1427 StatsdConfig newConfig;
1428 newConfig.add_allowed_log_source("AID_ROOT");
1429 newConfig.add_default_pull_packages("AID_ROOT"); // Fake puller is registered with root.
1430
1431 *newConfig.add_atom_matcher() = screenOffMatcher;
1432 *newConfig.add_atom_matcher() = unpluggedMatcher;
1433 *newConfig.add_atom_matcher() = batteryPluggedUsbMatcher;
1434 *newConfig.add_atom_matcher() = subsystemSleepMatcher;
1435 *newConfig.add_atom_matcher() = brightnessMatcher;
1436 *newConfig.add_atom_matcher() = screenOnMatcher;
1437
1438 *newConfig.add_predicate() = unpluggedPredicate;
1439 *newConfig.add_predicate() = screenOnPredicate;
1440
1441 *config.add_state() = screenState;
1442
1443 valueChange.set_condition(screenOnPredicate.id());
1444 *newConfig.add_value_metric() = valueChange;
1445 ValueMetric valueNew = createValueMetric("MaxScrBrightness", brightnessMatcher, 1, nullopt, {});
1446 valueNew.set_aggregation_type(ValueMetric::MAX);
1447 *newConfig.add_value_metric() = valueNew;
1448 *newConfig.add_value_metric() = valuePushPersist;
1449 *newConfig.add_value_metric() = valuePullPersist;
1450
1451 int64_t updateTimeNs = bucketStartTimeNs + 30 * NS_PER_SEC;
1452 // Update pulls valuePullPersist and valueNew. Pull #3.
1453 if (GetParam()) {
1454 EXPECT_CALL(*mLogEventFilter, setAtomIds(CreateAtomIdSetFromConfig(newConfig), _)).Times(1);
1455 }
1456 processor->OnConfigUpdated(updateTimeNs, key, newConfig);
1457
1458 // Verify puller manager is properly set.
1459 sp<StatsPullerManager> pullerManager = processor->mPullerManager;
1460 EXPECT_EQ(pullerManager->mNextPullTimeNs, bucketStartTimeNs + bucketSizeNs);
1461 ASSERT_EQ(pullerManager->mReceivers.size(), 1);
1462 ASSERT_EQ(pullerManager->mReceivers.begin()->second.size(), 2);
1463
1464 // Send events after the update. Values reset since this is a new bucket.
1465 events.clear();
1466 events.push_back(CreateScreenBrightnessChangedEvent(bucketStartTimeNs + 35 * NS_PER_SEC, 30));
1467 events.push_back(CreateScreenStateChangedEvent(bucketStartTimeNs + 40 * NS_PER_SEC,
1468 android::view::DISPLAY_STATE_OFF)); // Pull #4.
1469 events.push_back(CreateScreenBrightnessChangedEvent(bucketStartTimeNs + 45 * NS_PER_SEC, 20));
1470 events.push_back(CreateBatteryStateChangedEvent(
1471 bucketStartTimeNs + 50 * NS_PER_SEC,
1472 BatteryPluggedStateEnum::BATTERY_PLUGGED_USB)); // Pull #5.
1473 events.push_back(CreateScreenBrightnessChangedEvent(bucketStartTimeNs + 55 * NS_PER_SEC, 25));
1474 events.push_back(CreateScreenStateChangedEvent(bucketStartTimeNs + 60 * NS_PER_SEC,
1475 android::view::DISPLAY_STATE_ON)); // Pull #6.
1476 events.push_back(CreateBatteryStateChangedEvent(
1477 bucketStartTimeNs + 65 * NS_PER_SEC,
1478 BatteryPluggedStateEnum::BATTERY_PLUGGED_NONE)); // Pull #7.
1479 events.push_back(CreateScreenBrightnessChangedEvent(bucketStartTimeNs + 70 * NS_PER_SEC, 40));
1480
1481 // Send log events to StatsLogProcessor.
1482 for (auto& event : events) {
1483 processor->mPullerManager->ForceClearPullerCache();
1484 processor->OnLogEvent(event.get());
1485 }
1486 processor->mPullerManager->ForceClearPullerCache();
1487
1488 // Pulling alarm arrive, triggering a bucket split.
1489 // Both valuePullPersist and valueChange use the value since both conditions are true. Pull #8.
1490 processor->informPullAlarmFired(bucketStartTimeNs + bucketSizeNs);
1491 processor->OnLogEvent(CreateScreenBrightnessChangedEvent(
1492 bucketStartTimeNs + bucketSizeNs + 5 * NS_PER_SEC, 50)
1493 .get());
1494
1495 uint64_t dumpTimeNs = bucketStartTimeNs + bucketSizeNs + 10 * NS_PER_SEC;
1496 ConfigMetricsReportList reports;
1497 vector<uint8_t> buffer;
1498 processor->onDumpReport(key, dumpTimeNs, true, true, ADB_DUMP, FAST, &buffer);
1499 EXPECT_TRUE(reports.ParseFromArray(&buffer[0], buffer.size()));
1500 backfillDimensionPath(&reports);
1501 backfillStringInReport(&reports);
1502 backfillStartEndTimestamp(&reports);
1503 ASSERT_EQ(reports.reports_size(), 2);
1504
1505 int64_t roundedBucketStartNs = MillisToNano(NanoToMillis(bucketStartTimeNs));
1506 int64_t roundedUpdateTimeNs = MillisToNano(NanoToMillis(updateTimeNs));
1507 int64_t roundedBucketEndNs = MillisToNano(NanoToMillis(bucketStartTimeNs + bucketSizeNs));
1508 int64_t roundedDumpTimeNs = MillisToNano(NanoToMillis(dumpTimeNs));
1509
1510 // Report from before update.
1511 ConfigMetricsReport report = reports.reports(0);
1512 ASSERT_EQ(report.metrics_size(), 4);
1513 // Pull subsystem sleep while unplugged slice screen. Bucket skipped due to condition unknown.
1514 StatsLogReport valuePullPersistBefore = report.metrics(0);
1515 EXPECT_EQ(valuePullPersistBefore.metric_id(), valuePullPersist.id());
1516 EXPECT_TRUE(valuePullPersistBefore.has_value_metrics());
1517 ASSERT_EQ(valuePullPersistBefore.value_metrics().data_size(), 0);
1518 ASSERT_EQ(valuePullPersistBefore.value_metrics().skipped_size(), 1);
1519 StatsLogReport::SkippedBuckets skipBucket = valuePullPersistBefore.value_metrics().skipped(0);
1520 EXPECT_EQ(skipBucket.start_bucket_elapsed_nanos(), roundedBucketStartNs);
1521 EXPECT_EQ(skipBucket.end_bucket_elapsed_nanos(), roundedUpdateTimeNs);
1522 ASSERT_EQ(skipBucket.drop_event_size(), 1);
1523 EXPECT_EQ(skipBucket.drop_event(0).drop_reason(), BucketDropReason::CONDITION_UNKNOWN);
1524
1525 // Average screen brightness. Values were 5, 15, 40. Avg: 20.
1526 StatsLogReport valueRemoveBefore = report.metrics(1);
1527 EXPECT_EQ(valueRemoveBefore.metric_id(), valueRemove.id());
1528 EXPECT_TRUE(valueRemoveBefore.has_value_metrics());
1529 StatsLogReport::ValueMetricDataWrapper valueMetrics;
1530 sortMetricDataByDimensionsValue(valueRemoveBefore.value_metrics(), &valueMetrics);
1531 ASSERT_EQ(valueMetrics.data_size(), 1);
1532 ValueMetricData data = valueMetrics.data(0);
1533 EXPECT_FALSE(data.has_dimensions_in_what());
1534 EXPECT_EQ(data.slice_by_state_size(), 0);
1535 ASSERT_EQ(data.bucket_info_size(), 1);
1536 EXPECT_EQ(3, data.bucket_info(0).values(0).sample_size());
1537 ValidateValueBucket(data.bucket_info(0), roundedBucketStartNs, roundedUpdateTimeNs, {20}, 0, 0);
1538
1539 // Min screen brightness while screen on. Bucket skipped due to condition unknown.
1540 StatsLogReport valuePushPersistBefore = report.metrics(2);
1541 EXPECT_EQ(valuePushPersistBefore.metric_id(), valuePushPersist.id());
1542 EXPECT_TRUE(valuePushPersistBefore.has_value_metrics());
1543 ASSERT_EQ(valuePushPersistBefore.value_metrics().data_size(), 0);
1544 ASSERT_EQ(valuePushPersistBefore.value_metrics().skipped_size(), 1);
1545 skipBucket = valuePushPersistBefore.value_metrics().skipped(0);
1546 EXPECT_EQ(skipBucket.start_bucket_elapsed_nanos(), roundedBucketStartNs);
1547 EXPECT_EQ(skipBucket.end_bucket_elapsed_nanos(), roundedUpdateTimeNs);
1548 ASSERT_EQ(skipBucket.drop_event_size(), 1);
1549 EXPECT_EQ(skipBucket.drop_event(0).drop_reason(), BucketDropReason::CONDITION_UNKNOWN);
1550
1551 // Pull Subsystem sleep state. Value is Pull #3 (900) - Pull#1 (100).
1552 StatsLogReport valueChangeBefore = report.metrics(3);
1553 EXPECT_EQ(valueChangeBefore.metric_id(), valueChange.id());
1554 EXPECT_TRUE(valueChangeBefore.has_value_metrics());
1555 valueMetrics.Clear();
1556 sortMetricDataByDimensionsValue(valueChangeBefore.value_metrics(), &valueMetrics);
1557 ASSERT_EQ(valueMetrics.data_size(), 2);
1558 data = valueMetrics.data(0);
1559 ValidateSubsystemSleepDimension(data.dimensions_in_what(), "subsystem_name_1");
1560 ASSERT_EQ(data.bucket_info_size(), 1);
1561 ValidateValueBucket(data.bucket_info(0), roundedBucketStartNs, roundedUpdateTimeNs, {800}, 0,
1562 0);
1563 data = valueMetrics.data(1);
1564 ValidateSubsystemSleepDimension(data.dimensions_in_what(), "subsystem_name_2");
1565 ASSERT_EQ(data.bucket_info_size(), 1);
1566 ValidateValueBucket(data.bucket_info(0), roundedBucketStartNs, roundedUpdateTimeNs, {800}, 0,
1567 0);
1568
1569 // Report from after update.
1570 report = reports.reports(1);
1571 ASSERT_EQ(report.metrics_size(), 4);
1572 // Pull subsystem sleep while screen on.
1573 // Pull#4 (1600) - pull#3 (900) + pull#8 (6400) - pull#6 (3600)
1574 StatsLogReport valueChangeAfter = report.metrics(0);
1575 EXPECT_EQ(valueChangeAfter.metric_id(), valueChange.id());
1576 EXPECT_TRUE(valueChangeAfter.has_value_metrics());
1577 valueMetrics.Clear();
1578 sortMetricDataByDimensionsValue(valueChangeAfter.value_metrics(), &valueMetrics);
1579 int64_t conditionTrueNs = bucketSizeNs - 60 * NS_PER_SEC + 10 * NS_PER_SEC;
1580 ASSERT_EQ(valueMetrics.data_size(), 2);
1581 data = valueMetrics.data(0);
1582 ValidateSubsystemSleepDimension(data.dimensions_in_what(), "subsystem_name_1");
1583 ASSERT_EQ(data.bucket_info_size(), 1);
1584 ValidateValueBucket(data.bucket_info(0), roundedUpdateTimeNs, roundedBucketEndNs, {3500},
1585 conditionTrueNs, 0);
1586 ASSERT_EQ(valueMetrics.data_size(), 2);
1587 data = valueMetrics.data(1);
1588 ValidateSubsystemSleepDimension(data.dimensions_in_what(), "subsystem_name_2");
1589 ASSERT_EQ(data.bucket_info_size(), 1);
1590 ValidateValueBucket(data.bucket_info(0), roundedUpdateTimeNs, roundedBucketEndNs, {3500},
1591 conditionTrueNs, 0);
1592
1593 ASSERT_EQ(valueChangeAfter.value_metrics().skipped_size(), 1);
1594 skipBucket = valueChangeAfter.value_metrics().skipped(0);
1595 EXPECT_EQ(skipBucket.start_bucket_elapsed_nanos(), roundedBucketEndNs);
1596 EXPECT_EQ(skipBucket.end_bucket_elapsed_nanos(), roundedDumpTimeNs);
1597 ASSERT_EQ(skipBucket.drop_event_size(), 1);
1598 EXPECT_EQ(skipBucket.drop_event(0).drop_reason(), BucketDropReason::DUMP_REPORT_REQUESTED);
1599
1600 // Max screen brightness, no condition. Val is 40 in first bucket, 50 in second.
1601 StatsLogReport valueNewAfter = report.metrics(1);
1602 EXPECT_EQ(valueNewAfter.metric_id(), valueNew.id());
1603 EXPECT_TRUE(valueNewAfter.has_value_metrics());
1604 valueMetrics.Clear();
1605 sortMetricDataByDimensionsValue(valueNewAfter.value_metrics(), &valueMetrics);
1606 ASSERT_EQ(valueMetrics.data_size(), 1);
1607 data = valueMetrics.data(0);
1608 ASSERT_EQ(data.bucket_info_size(), 2);
1609 ValidateValueBucket(data.bucket_info(0), roundedUpdateTimeNs, roundedBucketEndNs, {40}, 0, 0);
1610 ValidateValueBucket(data.bucket_info(1), roundedBucketEndNs, roundedDumpTimeNs, {50}, 0, 0);
1611
1612 // Min screen brightness when screen on. Val is 30 in first bucket, 50 in second.
1613 StatsLogReport valuePushPersistAfter = report.metrics(2);
1614 EXPECT_EQ(valuePushPersistAfter.metric_id(), valuePushPersist.id());
1615 EXPECT_TRUE(valuePushPersistAfter.has_value_metrics());
1616 valueMetrics.Clear();
1617 sortMetricDataByDimensionsValue(valuePushPersistAfter.value_metrics(), &valueMetrics);
1618 ASSERT_EQ(valueMetrics.data_size(), 1);
1619 data = valueMetrics.data(0);
1620 ASSERT_EQ(data.bucket_info_size(), 2);
1621 conditionTrueNs = bucketSizeNs - 60 * NS_PER_SEC + 10 * NS_PER_SEC;
1622 ValidateValueBucket(data.bucket_info(0), roundedUpdateTimeNs, roundedBucketEndNs, {30},
1623 conditionTrueNs, 0);
1624 ValidateValueBucket(data.bucket_info(1), roundedBucketEndNs, roundedDumpTimeNs, {50},
1625 10 * NS_PER_SEC, 0);
1626
1627 // TODO(b/179725160): fix assertions.
1628 // Subsystem sleep state while unplugged slice screen.
1629 StatsLogReport valuePullPersistAfter = report.metrics(3);
1630 EXPECT_EQ(valuePullPersistAfter.metric_id(), valuePullPersist.id());
1631 EXPECT_TRUE(valuePullPersistAfter.has_value_metrics());
1632 valueMetrics.Clear();
1633 sortMetricDataByDimensionsValue(valuePullPersistAfter.value_metrics(), &valueMetrics);
1634 ASSERT_EQ(valueMetrics.data_size(), 4);
1635 // Name 1, screen OFF. Pull#5 (2500) - pull#4 (1600).
1636 data = valueMetrics.data(0);
1637 conditionTrueNs = 10 * NS_PER_SEC;
1638 ValidateSubsystemSleepDimension(data.dimensions_in_what(), "subsystem_name_1");
1639 ValidateStateValue(data.slice_by_state(), util::SCREEN_STATE_CHANGED,
1640 android::view::DisplayStateEnum::DISPLAY_STATE_OFF);
1641 ASSERT_EQ(data.bucket_info_size(), 1);
1642 ValidateValueBucket(data.bucket_info(0), roundedUpdateTimeNs, roundedBucketEndNs, {900}, -1, 0);
1643 // Name 1, screen ON. Pull#4 (1600) - pull#3 (900) + pull#8 (6400) - pull#7 (4900).
1644 data = valueMetrics.data(1);
1645 conditionTrueNs = 10 * NS_PER_SEC + bucketSizeNs - 65 * NS_PER_SEC;
1646 ValidateSubsystemSleepDimension(data.dimensions_in_what(), "subsystem_name_1");
1647 ValidateStateValue(data.slice_by_state(), util::SCREEN_STATE_CHANGED,
1648 android::view::DisplayStateEnum::DISPLAY_STATE_ON);
1649 ASSERT_EQ(data.bucket_info_size(), 1);
1650 ValidateValueBucket(data.bucket_info(0), roundedUpdateTimeNs, roundedBucketEndNs, {2200}, -1,
1651 0);
1652 // Name 2, screen OFF. Pull#5 (2500) - pull#4 (1600).
1653 data = valueMetrics.data(2);
1654 conditionTrueNs = 10 * NS_PER_SEC;
1655 ValidateSubsystemSleepDimension(data.dimensions_in_what(), "subsystem_name_2");
1656 ValidateStateValue(data.slice_by_state(), util::SCREEN_STATE_CHANGED,
1657 android::view::DisplayStateEnum::DISPLAY_STATE_OFF);
1658 ASSERT_EQ(data.bucket_info_size(), 1);
1659 ValidateValueBucket(data.bucket_info(0), roundedUpdateTimeNs, roundedBucketEndNs, {900}, -1, 0);
1660 // Name 2, screen ON. Pull#4 (1600) - pull#3 (900) + pull#8 (6400) - pull#7 (4900).
1661 data = valueMetrics.data(3);
1662 conditionTrueNs = 10 * NS_PER_SEC + bucketSizeNs - 65 * NS_PER_SEC;
1663 ValidateSubsystemSleepDimension(data.dimensions_in_what(), "subsystem_name_2");
1664 ValidateStateValue(data.slice_by_state(), util::SCREEN_STATE_CHANGED,
1665 android::view::DisplayStateEnum::DISPLAY_STATE_ON);
1666 ASSERT_EQ(data.bucket_info_size(), 1);
1667 ValidateValueBucket(data.bucket_info(0), roundedUpdateTimeNs, roundedBucketEndNs, {2200}, -1,
1668 0);
1669
1670 ASSERT_EQ(valuePullPersistAfter.value_metrics().skipped_size(), 1);
1671 skipBucket = valuePullPersistAfter.value_metrics().skipped(0);
1672 EXPECT_EQ(skipBucket.start_bucket_elapsed_nanos(), roundedBucketEndNs);
1673 EXPECT_EQ(skipBucket.end_bucket_elapsed_nanos(), roundedDumpTimeNs);
1674 ASSERT_EQ(skipBucket.drop_event_size(), 1);
1675 EXPECT_EQ(skipBucket.drop_event(0).drop_reason(), BucketDropReason::DUMP_REPORT_REQUESTED);
1676 }
1677
TEST_P(ConfigUpdateE2eTest,TestKllMetric)1678 TEST_P(ConfigUpdateE2eTest, TestKllMetric) {
1679 StatsdConfig config;
1680 config.add_allowed_log_source("AID_ROOT");
1681
1682 AtomMatcher brightnessMatcher = CreateScreenBrightnessChangedAtomMatcher();
1683 *config.add_atom_matcher() = brightnessMatcher;
1684 AtomMatcher screenOnMatcher = CreateScreenTurnedOnAtomMatcher();
1685 *config.add_atom_matcher() = screenOnMatcher;
1686 AtomMatcher screenOffMatcher = CreateScreenTurnedOffAtomMatcher();
1687 *config.add_atom_matcher() = screenOffMatcher;
1688 AtomMatcher batteryPluggedUsbMatcher = CreateBatteryStateUsbMatcher();
1689 *config.add_atom_matcher() = batteryPluggedUsbMatcher;
1690 AtomMatcher unpluggedMatcher = CreateBatteryStateNoneMatcher();
1691 *config.add_atom_matcher() = unpluggedMatcher;
1692
1693 Predicate screenOnPredicate = CreateScreenIsOnPredicate();
1694 *config.add_predicate() = screenOnPredicate;
1695 Predicate unpluggedPredicate = CreateDeviceUnpluggedPredicate();
1696 *config.add_predicate() = unpluggedPredicate;
1697
1698 KllMetric kllPersist = createKllMetric("ScreenBrightnessWhileScreenOn", brightnessMatcher, 1,
1699 screenOnPredicate.id());
1700
1701 KllMetric kllChange = createKllMetric("ScreenBrightness", brightnessMatcher, 1, nullopt);
1702
1703 KllMetric kllRemove = createKllMetric("ScreenBrightnessWhileUnplugged", brightnessMatcher, 1,
1704 unpluggedPredicate.id());
1705
1706 *config.add_kll_metric() = kllRemove;
1707 *config.add_kll_metric() = kllPersist;
1708 *config.add_kll_metric() = kllChange;
1709
1710 ConfigKey key(123, 987);
1711 const uint64_t bucketStartTimeNs = 10000000000; // 0:10
1712 uint64_t bucketSizeNs = TimeUnitToBucketSizeInMillis(TEN_MINUTES) * 1000000LL;
1713 sp<StatsLogProcessor> processor = CreateStatsLogProcessor(bucketStartTimeNs, bucketStartTimeNs,
1714 config, key, mLogEventFilter);
1715
1716 // Initialize log events before update.
1717 // kllPersist and kllRemove will skip the bucket due to condition unknown.
1718 std::vector<std::unique_ptr<LogEvent>> events;
1719 events.push_back(CreateScreenBrightnessChangedEvent(bucketStartTimeNs + 5 * NS_PER_SEC, 5));
1720 events.push_back(CreateScreenBrightnessChangedEvent(bucketStartTimeNs + 15 * NS_PER_SEC, 15));
1721 events.push_back(CreateBatteryStateChangedEvent(bucketStartTimeNs + 20 * NS_PER_SEC,
1722 BatteryPluggedStateEnum::BATTERY_PLUGGED_NONE));
1723 events.push_back(CreateScreenBrightnessChangedEvent(bucketStartTimeNs + 25 * NS_PER_SEC, 40));
1724 events.push_back(CreateScreenStateChangedEvent(bucketStartTimeNs + 27 * NS_PER_SEC,
1725 android::view::DISPLAY_STATE_ON));
1726
1727 // Send log events to StatsLogProcessor.
1728 for (auto& event : events) {
1729 processor->OnLogEvent(event.get());
1730 }
1731
1732 // Do the update. Add matchers/conditions in different order to force indices to change.
1733 StatsdConfig newConfig;
1734 newConfig.add_allowed_log_source("AID_ROOT");
1735
1736 *newConfig.add_atom_matcher() = screenOffMatcher;
1737 *newConfig.add_atom_matcher() = unpluggedMatcher;
1738 *newConfig.add_atom_matcher() = batteryPluggedUsbMatcher;
1739 *newConfig.add_atom_matcher() = brightnessMatcher;
1740 *newConfig.add_atom_matcher() = screenOnMatcher;
1741 AtomMatcher batterySaverStartMatcher = CreateBatterySaverModeStartAtomMatcher();
1742 *newConfig.add_atom_matcher() = batterySaverStartMatcher;
1743 AtomMatcher batterySaverStopMatcher = CreateBatterySaverModeStopAtomMatcher();
1744 *newConfig.add_atom_matcher() = batterySaverStopMatcher;
1745
1746 *newConfig.add_predicate() = screenOnPredicate;
1747 Predicate batterySaverPredicate = CreateBatterySaverModePredicate();
1748 *newConfig.add_predicate() = batterySaverPredicate;
1749 Predicate screenOffPredicate = CreateScreenIsOffPredicate();
1750 *newConfig.add_predicate() = screenOffPredicate;
1751
1752 kllChange.set_condition(batterySaverPredicate.id());
1753 *newConfig.add_kll_metric() = kllChange;
1754 KllMetric kllNew = createKllMetric("ScreenBrightnessWhileScreenOff", brightnessMatcher, 1,
1755 screenOffPredicate.id());
1756 *newConfig.add_kll_metric() = kllNew;
1757 *newConfig.add_kll_metric() = kllPersist;
1758
1759 int64_t updateTimeNs = bucketStartTimeNs + 30 * NS_PER_SEC;
1760 if (GetParam()) {
1761 EXPECT_CALL(*mLogEventFilter,
1762 setAtomIds(CreateAtomIdSetFromConfig(newConfig), processor.get()))
1763 .Times(1);
1764 }
1765 processor->OnConfigUpdated(updateTimeNs, key, newConfig);
1766
1767 // Send events after the update. This is a new bucket.
1768 events.clear();
1769 events.push_back(CreateScreenBrightnessChangedEvent(updateTimeNs + 5 * NS_PER_SEC, 30));
1770 events.push_back(CreateScreenStateChangedEvent(updateTimeNs + 10 * NS_PER_SEC,
1771 android::view::DISPLAY_STATE_OFF));
1772 events.push_back(CreateScreenBrightnessChangedEvent(updateTimeNs + 15 * NS_PER_SEC, 20));
1773 events.push_back(CreateBatteryStateChangedEvent(updateTimeNs + 20 * NS_PER_SEC,
1774 BatteryPluggedStateEnum::BATTERY_PLUGGED_USB));
1775 events.push_back(CreateScreenBrightnessChangedEvent(updateTimeNs + 25 * NS_PER_SEC, 25));
1776 events.push_back(CreateScreenStateChangedEvent(updateTimeNs + 30 * NS_PER_SEC,
1777 android::view::DISPLAY_STATE_ON));
1778 events.push_back(CreateBatteryStateChangedEvent(updateTimeNs + 35 * NS_PER_SEC,
1779 BatteryPluggedStateEnum::BATTERY_PLUGGED_NONE));
1780 events.push_back(CreateScreenBrightnessChangedEvent(updateTimeNs + 40 * NS_PER_SEC, 40));
1781
1782 // End current bucket and start new bucket.
1783 events.push_back(CreateScreenBrightnessChangedEvent(
1784 bucketStartTimeNs + bucketSizeNs + 5 * NS_PER_SEC, 50));
1785
1786 // Send log events to StatsLogProcessor.
1787 for (auto& event : events) {
1788 processor->OnLogEvent(event.get());
1789 }
1790
1791 uint64_t dumpTimeNs = bucketStartTimeNs + bucketSizeNs + 10 * NS_PER_SEC;
1792 ConfigMetricsReportList reports;
1793 vector<uint8_t> buffer;
1794 processor->onDumpReport(key, dumpTimeNs, true, true, ADB_DUMP, FAST, &buffer);
1795 EXPECT_TRUE(reports.ParseFromArray(&buffer[0], buffer.size()));
1796 backfillDimensionPath(&reports);
1797 backfillStringInReport(&reports);
1798 backfillStartEndTimestamp(&reports);
1799 ASSERT_EQ(reports.reports_size(), 2);
1800
1801 // Report from before update.
1802 ConfigMetricsReport report = reports.reports(0);
1803 ASSERT_EQ(report.metrics_size(), 3);
1804
1805 // kllRemove: Screen brightness while unplugged. Bucket skipped due to condition unknown.
1806 StatsLogReport kllRemoveBefore = report.metrics(0);
1807 EXPECT_EQ(kllRemoveBefore.metric_id(), kllRemove.id());
1808 EXPECT_TRUE(kllRemoveBefore.has_kll_metrics());
1809 ASSERT_EQ(kllRemoveBefore.kll_metrics().data_size(), 0);
1810 ASSERT_EQ(kllRemoveBefore.kll_metrics().skipped_size(), 1);
1811 StatsLogReport::SkippedBuckets skipBucket = kllRemoveBefore.kll_metrics().skipped(0);
1812 EXPECT_EQ(skipBucket.start_bucket_elapsed_nanos(), bucketStartTimeNs);
1813 EXPECT_EQ(skipBucket.end_bucket_elapsed_nanos(), updateTimeNs);
1814 ASSERT_EQ(skipBucket.drop_event_size(), 1);
1815 EXPECT_EQ(skipBucket.drop_event(0).drop_reason(), BucketDropReason::CONDITION_UNKNOWN);
1816
1817 // kllPersist: Screen brightness while screen on.
1818 StatsLogReport kllPersistBefore = report.metrics(1);
1819 EXPECT_EQ(kllPersistBefore.metric_id(), kllPersist.id());
1820 EXPECT_TRUE(kllPersistBefore.has_kll_metrics());
1821 EXPECT_EQ(kllPersistBefore.kll_metrics().data_size(), 0);
1822 ASSERT_EQ(kllPersistBefore.kll_metrics().skipped_size(), 1);
1823 skipBucket = kllPersistBefore.kll_metrics().skipped(0);
1824 EXPECT_EQ(skipBucket.start_bucket_elapsed_nanos(), bucketStartTimeNs);
1825 EXPECT_EQ(skipBucket.end_bucket_elapsed_nanos(), updateTimeNs);
1826 ASSERT_EQ(skipBucket.drop_event_size(), 1);
1827 EXPECT_EQ(skipBucket.drop_event(0).drop_reason(), BucketDropReason::CONDITION_UNKNOWN);
1828
1829 // kllChange: Screen brightness.
1830 StatsLogReport kllChangeBefore = report.metrics(2);
1831 EXPECT_EQ(kllChangeBefore.metric_id(), kllChange.id());
1832 EXPECT_TRUE(kllChangeBefore.has_kll_metrics());
1833 ASSERT_EQ(kllChangeBefore.kll_metrics().data_size(), 1);
1834 KllMetricData data = kllChangeBefore.kll_metrics().data(0);
1835 ASSERT_EQ(data.bucket_info_size(), 1);
1836 TRACE_CALL(ValidateKllBucket, data.bucket_info(0), bucketStartTimeNs, updateTimeNs,
1837 /*sketchSizes=*/{3}, /*conditionTrueNs=*/0);
1838 EXPECT_EQ(kllChangeBefore.kll_metrics().skipped_size(), 0);
1839
1840 // Report from after update.
1841 report = reports.reports(1);
1842 ASSERT_EQ(report.metrics_size(), 3);
1843
1844 // kllChange: Screen brightness while on battery saver.
1845 StatsLogReport kllChangeAfter = report.metrics(0);
1846 EXPECT_EQ(kllChangeAfter.metric_id(), kllChange.id());
1847 EXPECT_TRUE(kllChangeAfter.has_kll_metrics());
1848 EXPECT_EQ(kllChangeAfter.kll_metrics().data_size(), 0);
1849 ASSERT_EQ(kllChangeAfter.kll_metrics().skipped_size(), 2);
1850 skipBucket = kllChangeAfter.kll_metrics().skipped(0);
1851 EXPECT_EQ(skipBucket.start_bucket_elapsed_nanos(), updateTimeNs);
1852 EXPECT_EQ(skipBucket.end_bucket_elapsed_nanos(), bucketStartTimeNs + bucketSizeNs);
1853 ASSERT_EQ(skipBucket.drop_event_size(), 1);
1854 EXPECT_EQ(skipBucket.drop_event(0).drop_reason(), BucketDropReason::CONDITION_UNKNOWN);
1855 skipBucket = kllChangeAfter.kll_metrics().skipped(1);
1856 EXPECT_EQ(skipBucket.start_bucket_elapsed_nanos(), bucketStartTimeNs + bucketSizeNs);
1857 EXPECT_EQ(skipBucket.end_bucket_elapsed_nanos(), dumpTimeNs);
1858 ASSERT_EQ(skipBucket.drop_event_size(), 1);
1859 EXPECT_EQ(skipBucket.drop_event(0).drop_reason(), BucketDropReason::CONDITION_UNKNOWN);
1860
1861 // kllNew: Screen brightness while screen off.
1862 StatsLogReport kllNewAfter = report.metrics(1);
1863 EXPECT_EQ(kllNewAfter.metric_id(), kllNew.id());
1864 EXPECT_TRUE(kllNewAfter.has_kll_metrics());
1865 EXPECT_EQ(kllNewAfter.kll_metrics().data_size(), 0);
1866 ASSERT_EQ(kllNewAfter.kll_metrics().skipped_size(), 2);
1867 skipBucket = kllNewAfter.kll_metrics().skipped(0);
1868 EXPECT_EQ(skipBucket.start_bucket_elapsed_nanos(), updateTimeNs);
1869 EXPECT_EQ(skipBucket.end_bucket_elapsed_nanos(), bucketStartTimeNs + bucketSizeNs);
1870 ASSERT_EQ(skipBucket.drop_event_size(), 1);
1871 EXPECT_EQ(skipBucket.drop_event(0).drop_reason(), BucketDropReason::CONDITION_UNKNOWN);
1872 skipBucket = kllNewAfter.kll_metrics().skipped(1);
1873 EXPECT_EQ(skipBucket.start_bucket_elapsed_nanos(), bucketStartTimeNs + bucketSizeNs);
1874 EXPECT_EQ(skipBucket.end_bucket_elapsed_nanos(), dumpTimeNs);
1875 ASSERT_EQ(skipBucket.drop_event_size(), 1);
1876 EXPECT_EQ(skipBucket.drop_event(0).drop_reason(), BucketDropReason::NO_DATA);
1877
1878 // kllPersist: Screen brightness while screen on.
1879 StatsLogReport kllPersistAfter = report.metrics(2);
1880 EXPECT_EQ(kllPersistAfter.metric_id(), kllPersist.id());
1881 EXPECT_TRUE(kllPersistAfter.has_kll_metrics());
1882 ASSERT_EQ(kllPersistAfter.kll_metrics().data_size(), 1);
1883 data = kllPersistAfter.kll_metrics().data(0);
1884 ASSERT_EQ(data.bucket_info_size(), 2);
1885 int64_t conditionTrueNs =
1886 bucketStartTimeNs + 40 * NS_PER_SEC - updateTimeNs + bucketSizeNs - 60 * NS_PER_SEC;
1887 TRACE_CALL(ValidateKllBucket, data.bucket_info(0), updateTimeNs,
1888 bucketStartTimeNs + bucketSizeNs,
1889 /*sketchSizes=*/{2}, conditionTrueNs);
1890 conditionTrueNs = dumpTimeNs - bucketStartTimeNs - bucketSizeNs;
1891 TRACE_CALL(ValidateKllBucket, data.bucket_info(1), bucketStartTimeNs + bucketSizeNs, dumpTimeNs,
1892 /*sketchSizes=*/{1}, conditionTrueNs);
1893 EXPECT_EQ(kllPersistAfter.kll_metrics().skipped_size(), 0);
1894 }
1895
TEST_P(ConfigUpdateE2eTest,TestMetricActivation)1896 TEST_P(ConfigUpdateE2eTest, TestMetricActivation) {
1897 ALOGE("Start ConfigUpdateE2eTest#TestMetricActivation");
1898 StatsdConfig config;
1899 config.add_allowed_log_source("AID_ROOT");
1900
1901 string immediateTag = "immediate", bootTag = "boot", childTag = "child";
1902
1903 AtomMatcher syncStartMatcher = CreateSyncStartAtomMatcher();
1904 *config.add_atom_matcher() = syncStartMatcher;
1905
1906 AtomMatcher immediateMatcher =
1907 CreateSimpleAtomMatcher("immediateMatcher", util::WAKELOCK_STATE_CHANGED);
1908 FieldValueMatcher* fvm =
1909 immediateMatcher.mutable_simple_atom_matcher()->add_field_value_matcher();
1910 fvm->set_field(3); // Tag.
1911 fvm->set_eq_string(immediateTag);
1912 *config.add_atom_matcher() = immediateMatcher;
1913
1914 AtomMatcher bootMatcher = CreateSimpleAtomMatcher("bootMatcher", util::WAKELOCK_STATE_CHANGED);
1915 fvm = bootMatcher.mutable_simple_atom_matcher()->add_field_value_matcher();
1916 fvm->set_field(3); // Tag.
1917 fvm->set_eq_string(bootTag);
1918 *config.add_atom_matcher() = bootMatcher;
1919
1920 AtomMatcher childMatcher =
1921 CreateSimpleAtomMatcher("childMatcher", util::WAKELOCK_STATE_CHANGED);
1922 fvm = childMatcher.mutable_simple_atom_matcher()->add_field_value_matcher();
1923 fvm->set_field(3); // Tag.
1924 fvm->set_eq_string(childTag);
1925 *config.add_atom_matcher() = childMatcher;
1926
1927 AtomMatcher acquireMatcher = CreateAcquireWakelockAtomMatcher();
1928 *config.add_atom_matcher() = acquireMatcher;
1929
1930 AtomMatcher combinationMatcher;
1931 combinationMatcher.set_id(StringToId("combination"));
1932 AtomMatcher_Combination* combination = combinationMatcher.mutable_combination();
1933 combination->set_operation(LogicalOperation::OR);
1934 combination->add_matcher(acquireMatcher.id());
1935 combination->add_matcher(childMatcher.id());
1936 *config.add_atom_matcher() = combinationMatcher;
1937
1938 CountMetric immediateMetric =
1939 createCountMetric("ImmediateMetric", syncStartMatcher.id(), nullopt, {});
1940 CountMetric bootMetric = createCountMetric("BootMetric", syncStartMatcher.id(), nullopt, {});
1941 CountMetric combinationMetric =
1942 createCountMetric("CombinationMetric", syncStartMatcher.id(), nullopt, {});
1943 *config.add_count_metric() = immediateMetric;
1944 *config.add_count_metric() = bootMetric;
1945 *config.add_count_metric() = combinationMetric;
1946
1947 MetricActivation immediateMetricActivation;
1948 immediateMetricActivation.set_metric_id(immediateMetric.id());
1949 auto eventActivation = immediateMetricActivation.add_event_activation();
1950 eventActivation->set_activation_type(ActivationType::ACTIVATE_IMMEDIATELY);
1951 eventActivation->set_atom_matcher_id(immediateMatcher.id());
1952 eventActivation->set_ttl_seconds(60); // One minute.
1953 *config.add_metric_activation() = immediateMetricActivation;
1954
1955 MetricActivation bootMetricActivation;
1956 bootMetricActivation.set_metric_id(bootMetric.id());
1957 eventActivation = bootMetricActivation.add_event_activation();
1958 eventActivation->set_activation_type(ActivationType::ACTIVATE_ON_BOOT);
1959 eventActivation->set_atom_matcher_id(bootMatcher.id());
1960 eventActivation->set_ttl_seconds(60); // One minute.
1961 *config.add_metric_activation() = bootMetricActivation;
1962
1963 MetricActivation combinationMetricActivation;
1964 combinationMetricActivation.set_metric_id(combinationMetric.id());
1965 eventActivation = combinationMetricActivation.add_event_activation();
1966 eventActivation->set_activation_type(ActivationType::ACTIVATE_IMMEDIATELY);
1967 eventActivation->set_atom_matcher_id(combinationMatcher.id());
1968 eventActivation->set_ttl_seconds(60); // One minute.
1969 *config.add_metric_activation() = combinationMetricActivation;
1970
1971 ConfigKey key(123, 987);
1972 uint64_t bucketStartTimeNs = 10000000000; // 0:10
1973 uint64_t bucketSizeNs = TimeUnitToBucketSizeInMillis(TEN_MINUTES) * 1000000LL;
1974 sp<StatsLogProcessor> processor = CreateStatsLogProcessor(bucketStartTimeNs, bucketStartTimeNs,
1975 config, key, mLogEventFilter);
1976 int uid1 = 55555;
1977
1978 // Initialize log events before update.
1979 // Counts provided in order of immediate, boot, and combination metric.
1980 std::vector<std::unique_ptr<LogEvent>> events;
1981
1982 events.push_back(CreateSyncStartEvent(bucketStartTimeNs + 5 * NS_PER_SEC, {uid1}, {""},
1983 "")); // Count: 0, 0, 0.
1984 events.push_back(CreateReleaseWakelockEvent(bucketStartTimeNs + 10 * NS_PER_SEC, {uid1}, {""},
1985 immediateTag)); // Activate immediate metric.
1986 events.push_back(CreateSyncStartEvent(bucketStartTimeNs + 15 * NS_PER_SEC, {uid1}, {""},
1987 "")); // Count: 1, 0, 0.
1988 events.push_back(CreateAcquireWakelockEvent(bucketStartTimeNs + 20 * NS_PER_SEC, {uid1}, {""},
1989 "foo")); // Activate combination metric.
1990 events.push_back(CreateSyncStartEvent(bucketStartTimeNs + 25 * NS_PER_SEC, {uid1}, {""},
1991 "")); // Count: 2, 0, 1.
1992 events.push_back(CreateReleaseWakelockEvent(bucketStartTimeNs + 30 * NS_PER_SEC, {uid1}, {""},
1993 bootTag)); // Boot metric pending activation.
1994 events.push_back(CreateSyncStartEvent(bucketStartTimeNs + 35 * NS_PER_SEC, {uid1}, {""},
1995 "")); // Count: 3, 0, 2.
1996 // Send log events to StatsLogProcessor.
1997 for (auto& event : events) {
1998 processor->OnLogEvent(event.get());
1999 }
2000
2001 // Do update. Add matchers/conditions in different order to force indices to change.
2002 StatsdConfig newConfig;
2003 newConfig.add_allowed_log_source("AID_ROOT");
2004 newConfig.set_hash_strings_in_metric_report(false); // Modify metadata for fun.
2005
2006 // Change combination matcher, will mean combination metric isn't active after update.
2007 combinationMatcher.mutable_combination()->set_operation(LogicalOperation::AND);
2008 *newConfig.add_atom_matcher() = acquireMatcher;
2009 *newConfig.add_atom_matcher() = bootMatcher;
2010 *newConfig.add_atom_matcher() = combinationMatcher;
2011 *newConfig.add_atom_matcher() = childMatcher;
2012 *newConfig.add_atom_matcher() = syncStartMatcher;
2013 *newConfig.add_atom_matcher() = immediateMatcher;
2014
2015 *newConfig.add_count_metric() = bootMetric;
2016 *newConfig.add_count_metric() = combinationMetric;
2017 *newConfig.add_count_metric() = immediateMetric;
2018
2019 *newConfig.add_metric_activation() = bootMetricActivation;
2020 *newConfig.add_metric_activation() = combinationMetricActivation;
2021 *newConfig.add_metric_activation() = immediateMetricActivation;
2022
2023 int64_t updateTimeNs = bucketStartTimeNs + 40 * NS_PER_SEC;
2024 if (GetParam()) {
2025 EXPECT_CALL(*mLogEventFilter,
2026 setAtomIds(CreateAtomIdSetFromConfig(newConfig), processor.get()))
2027 .Times(1);
2028 }
2029 processor->OnConfigUpdated(updateTimeNs, key, newConfig);
2030
2031 // The reboot will write to disk again, so sleep for 1 second to avoid this.
2032 // TODO(b/178887128): clean this up.
2033 std::this_thread::sleep_for(1000ms);
2034 // Send event after the update. Counts reset to 0 since this is a new bucket.
2035 processor->OnLogEvent(
2036 CreateSyncStartEvent(bucketStartTimeNs + 45 * NS_PER_SEC, {uid1}, {""}, "")
2037 .get()); // Count: 1, 0, 0.
2038
2039 // Fake a reboot. Code is from StatsService::informDeviceShutdown.
2040 int64_t shutDownTimeNs = bucketStartTimeNs + 50 * NS_PER_SEC;
2041 processor->WriteDataToDisk(DEVICE_SHUTDOWN, FAST, shutDownTimeNs, getWallClockNs());
2042 processor->SaveActiveConfigsToDisk(shutDownTimeNs);
2043 processor->SaveMetadataToDisk(getWallClockNs(), shutDownTimeNs);
2044
2045 // On boot, use StartUp. However, skip config manager for simplicity.
2046 int64_t bootTimeNs = bucketStartTimeNs + 55 * NS_PER_SEC;
2047 processor = CreateStatsLogProcessor(bootTimeNs, bootTimeNs, newConfig, key, mLogEventFilter);
2048 processor->LoadActiveConfigsFromDisk();
2049 processor->LoadMetadataFromDisk(getWallClockNs(), bootTimeNs);
2050
2051 // Send events after boot. Counts reset to 0 since this is a new bucket. Boot metric now active.
2052 events.clear();
2053 events.push_back(CreateSyncStartEvent(bucketStartTimeNs + 60 * NS_PER_SEC, {uid1}, {""},
2054 "")); // Count: 1, 1, 0.
2055 int64_t deactivationTimeNs = bucketStartTimeNs + 76 * NS_PER_SEC;
2056 events.push_back(CreateScreenStateChangedEvent(
2057 deactivationTimeNs,
2058 android::view::DisplayStateEnum::DISPLAY_STATE_OFF)); // TTLs immediate metric.
2059 events.push_back(CreateSyncStartEvent(bucketStartTimeNs + 80 * NS_PER_SEC, {uid1}, {""},
2060 "")); // Count: 1, 2, 0.
2061 events.push_back(CreateAcquireWakelockEvent(bucketStartTimeNs + 85 * NS_PER_SEC, {uid1}, {""},
2062 childTag)); // Activate combination metric.
2063 events.push_back(CreateSyncStartEvent(bucketStartTimeNs + 90 * NS_PER_SEC, {uid1}, {""},
2064 "")); // Count: 1, 3, 1.
2065
2066 // Send log events to StatsLogProcessor.
2067 for (auto& event : events) {
2068 processor->OnLogEvent(event.get());
2069 }
2070 uint64_t dumpTimeNs = bucketStartTimeNs + 90 * NS_PER_SEC;
2071 ConfigMetricsReportList reports;
2072 vector<uint8_t> buffer;
2073 processor->onDumpReport(key, dumpTimeNs, true, true, ADB_DUMP, FAST, &buffer);
2074 EXPECT_TRUE(reports.ParseFromArray(&buffer[0], buffer.size()));
2075 sortReportsByElapsedTime(&reports);
2076 backfillDimensionPath(&reports);
2077 backfillStringInReport(&reports);
2078 backfillStartEndTimestamp(&reports);
2079 ASSERT_EQ(reports.reports_size(), 3);
2080
2081 // Report from before update.
2082 ConfigMetricsReport report = reports.reports(0);
2083 EXPECT_EQ(report.last_report_elapsed_nanos(), bucketStartTimeNs);
2084 EXPECT_EQ(report.current_report_elapsed_nanos(), updateTimeNs);
2085 ASSERT_EQ(report.metrics_size(), 3);
2086 // Immediate metric. Count = 3.
2087 StatsLogReport metricReport = report.metrics(0);
2088 EXPECT_EQ(metricReport.metric_id(), immediateMetric.id());
2089 EXPECT_TRUE(metricReport.is_active());
2090 EXPECT_TRUE(metricReport.has_count_metrics());
2091
2092 // Boot metric. Count = 0.
2093 metricReport = report.metrics(1);
2094 EXPECT_EQ(metricReport.metric_id(), bootMetric.id());
2095 EXPECT_FALSE(metricReport.is_active());
2096 EXPECT_FALSE(metricReport.has_count_metrics());
2097
2098 // Combination metric. Count = 2.
2099 metricReport = report.metrics(2);
2100 EXPECT_EQ(metricReport.metric_id(), combinationMetric.id());
2101 EXPECT_TRUE(metricReport.is_active());
2102 EXPECT_TRUE(metricReport.has_count_metrics());
2103
2104 // Report from after update, before boot.
2105 report = reports.reports(1);
2106 EXPECT_EQ(report.last_report_elapsed_nanos(), updateTimeNs);
2107 EXPECT_EQ(report.current_report_elapsed_nanos(), shutDownTimeNs);
2108 ASSERT_EQ(report.metrics_size(), 3);
2109 // Boot metric. Count = 0.
2110 metricReport = report.metrics(0);
2111 EXPECT_EQ(metricReport.metric_id(), bootMetric.id());
2112 EXPECT_FALSE(metricReport.is_active());
2113 EXPECT_FALSE(metricReport.has_count_metrics());
2114
2115 // Combination metric. Count = 0.
2116 metricReport = report.metrics(1);
2117 EXPECT_EQ(metricReport.metric_id(), combinationMetric.id());
2118 EXPECT_FALSE(metricReport.is_active());
2119 EXPECT_FALSE(metricReport.has_count_metrics());
2120
2121 // Immediate metric. Count = 1.
2122 metricReport = report.metrics(2);
2123 EXPECT_EQ(metricReport.metric_id(), immediateMetric.id());
2124 EXPECT_TRUE(metricReport.is_active());
2125 EXPECT_TRUE(metricReport.has_count_metrics());
2126
2127 // Report from after reboot.
2128 report = reports.reports(2);
2129 EXPECT_EQ(report.last_report_elapsed_nanos(), bootTimeNs);
2130 EXPECT_EQ(report.current_report_elapsed_nanos(), dumpTimeNs);
2131 ASSERT_EQ(report.metrics_size(), 3);
2132 // Boot metric. Count = 3.
2133 metricReport = report.metrics(0);
2134 EXPECT_EQ(metricReport.metric_id(), bootMetric.id());
2135 EXPECT_TRUE(metricReport.is_active());
2136 EXPECT_TRUE(metricReport.has_count_metrics());
2137
2138 // Combination metric. Count = 1.
2139 metricReport = report.metrics(1);
2140 EXPECT_EQ(metricReport.metric_id(), combinationMetric.id());
2141 EXPECT_TRUE(metricReport.is_active());
2142 EXPECT_TRUE(metricReport.has_count_metrics());
2143
2144 // Immediate metric. Count = 1.
2145 metricReport = report.metrics(2);
2146 EXPECT_EQ(metricReport.metric_id(), immediateMetric.id());
2147 EXPECT_FALSE(metricReport.is_active());
2148 EXPECT_TRUE(metricReport.has_count_metrics());
2149 ALOGE("End ConfigUpdateE2eTest#TestMetricActivation");
2150 }
2151
TEST_P(ConfigUpdateE2eTest,TestAnomalyCountMetric)2152 TEST_P(ConfigUpdateE2eTest, TestAnomalyCountMetric) {
2153 StatsdConfig config;
2154 config.add_allowed_log_source("AID_ROOT");
2155
2156 AtomMatcher syncStartMatcher = CreateSyncStartAtomMatcher();
2157 *config.add_atom_matcher() = syncStartMatcher;
2158 AtomMatcher wakelockAcquireMatcher = CreateAcquireWakelockAtomMatcher();
2159 *config.add_atom_matcher() = wakelockAcquireMatcher;
2160
2161 CountMetric countWakelock =
2162 createCountMetric("CountWakelock", wakelockAcquireMatcher.id(), nullopt, {});
2163 *countWakelock.mutable_dimensions_in_what() =
2164 CreateAttributionUidDimensions(util::WAKELOCK_STATE_CHANGED, {Position::FIRST});
2165
2166 CountMetric countSync = createCountMetric("CountSync", syncStartMatcher.id(), nullopt, {});
2167 *countSync.mutable_dimensions_in_what() =
2168 CreateAttributionUidDimensions(util::SYNC_STATE_CHANGED, {Position::FIRST});
2169
2170 *config.add_count_metric() = countWakelock;
2171 *config.add_count_metric() = countSync;
2172
2173 Alert alertPreserve =
2174 createAlert("AlertPreserve", countWakelock.id(), /*buckets=*/2, /*triggerSumGt=*/1);
2175 alertPreserve.set_refractory_period_secs(20);
2176 Alert alertReplace = createAlert("AlertReplace", countSync.id(), 1, 1);
2177 alertReplace.set_refractory_period_secs(1);
2178 Alert alertRemove = createAlert("AlertRemove", countWakelock.id(), 1, 0);
2179 alertRemove.set_refractory_period_secs(1);
2180 *config.add_alert() = alertReplace;
2181 *config.add_alert() = alertPreserve;
2182 *config.add_alert() = alertRemove;
2183
2184 int preserveSubId = 1, replaceSubId = 2, removeSubId = 3;
2185 Subscription preserveSub = createSubscription("S1", Subscription::ALERT, alertPreserve.id());
2186 preserveSub.mutable_broadcast_subscriber_details()->set_subscriber_id(preserveSubId);
2187 Subscription replaceSub = createSubscription("S2", Subscription::ALERT, alertReplace.id());
2188 replaceSub.mutable_broadcast_subscriber_details()->set_subscriber_id(replaceSubId);
2189 Subscription removeSub = createSubscription("S3", Subscription::ALERT, alertRemove.id());
2190 removeSub.mutable_broadcast_subscriber_details()->set_subscriber_id(removeSubId);
2191 *config.add_subscription() = preserveSub;
2192 *config.add_subscription() = removeSub;
2193 *config.add_subscription() = replaceSub;
2194
2195 int app1Uid = 123, app2Uid = 456;
2196 vector<int> attributionUids1 = {app1Uid};
2197 vector<string> attributionTags1 = {"App1"};
2198 vector<int> attributionUids2 = {app2Uid};
2199 vector<string> attributionTags2 = {"App2"};
2200 int64_t configUid = 123, configId = 987;
2201 ConfigKey key(configUid, configId);
2202
2203 int alertPreserveCount = 0, alertRemoveCount = 0;
2204 StatsDimensionsValueParcel alertPreserveDims;
2205 StatsDimensionsValueParcel alertRemoveDims;
2206
2207 // The binder calls here will happen synchronously because they are in-process.
2208 shared_ptr<MockPendingIntentRef> preserveBroadcast =
2209 SharedRefBase::make<StrictMock<MockPendingIntentRef>>();
2210 EXPECT_CALL(*preserveBroadcast, sendSubscriberBroadcast(configUid, configId, preserveSub.id(),
2211 alertPreserve.id(), _, _))
2212 .Times(2)
2213 .WillRepeatedly(
2214 Invoke([&alertPreserveCount, &alertPreserveDims](
2215 int64_t, int64_t, int64_t, int64_t, const vector<string>&,
2216 const StatsDimensionsValueParcel& dimensionsValueParcel) {
2217 alertPreserveCount++;
2218 alertPreserveDims = dimensionsValueParcel;
2219 return Status::ok();
2220 }));
2221
2222 shared_ptr<MockPendingIntentRef> replaceBroadcast =
2223 SharedRefBase::make<StrictMock<MockPendingIntentRef>>();
2224 EXPECT_CALL(*replaceBroadcast, sendSubscriberBroadcast(configUid, configId, replaceSub.id(),
2225 alertReplace.id(), _, _))
2226 .Times(0);
2227
2228 shared_ptr<MockPendingIntentRef> removeBroadcast =
2229 SharedRefBase::make<StrictMock<MockPendingIntentRef>>();
2230 EXPECT_CALL(*removeBroadcast, sendSubscriberBroadcast(configUid, configId, removeSub.id(),
2231 alertRemove.id(), _, _))
2232 .Times(3)
2233 .WillRepeatedly(
2234 Invoke([&alertRemoveCount, &alertRemoveDims](
2235 int64_t, int64_t, int64_t, int64_t, const vector<string>&,
2236 const StatsDimensionsValueParcel& dimensionsValueParcel) {
2237 alertRemoveCount++;
2238 alertRemoveDims = dimensionsValueParcel;
2239 return Status::ok();
2240 }));
2241
2242 SubscriberReporter::getInstance().setBroadcastSubscriber(key, preserveSubId, preserveBroadcast);
2243 SubscriberReporter::getInstance().setBroadcastSubscriber(key, replaceSubId, replaceBroadcast);
2244 SubscriberReporter::getInstance().setBroadcastSubscriber(key, removeSubId, removeBroadcast);
2245
2246 uint64_t bucketSizeNs = TimeUnitToBucketSizeInMillis(TEN_MINUTES) * 1000000LL;
2247 uint64_t bucketStartTimeNs = 10000000000; // 0:10
2248 uint64_t bucket2StartTimeNs = bucketStartTimeNs + bucketSizeNs;
2249 sp<StatsLogProcessor> processor = CreateStatsLogProcessor(bucketStartTimeNs, bucketStartTimeNs,
2250 config, key, mLogEventFilter);
2251
2252 StatsDimensionsValueParcel wlUid1 =
2253 CreateAttributionUidDimensionsValueParcel(util::WAKELOCK_STATE_CHANGED, app1Uid);
2254 StatsDimensionsValueParcel wlUid2 =
2255 CreateAttributionUidDimensionsValueParcel(util::WAKELOCK_STATE_CHANGED, app2Uid);
2256
2257 processor->OnLogEvent(CreateAcquireWakelockEvent(bucketStartTimeNs + 15 * NS_PER_SEC,
2258 attributionUids1, attributionTags1, "wl1")
2259 .get());
2260 EXPECT_EQ(alertPreserveCount, 0);
2261 EXPECT_EQ(alertRemoveCount, 1);
2262 EXPECT_EQ(alertRemoveDims, wlUid1);
2263
2264 processor->OnLogEvent(CreateAcquireWakelockEvent(bucketStartTimeNs + 20 * NS_PER_SEC,
2265 attributionUids2, attributionTags2, "wl2")
2266 .get());
2267 EXPECT_EQ(alertPreserveCount, 0);
2268 EXPECT_EQ(alertRemoveCount, 2);
2269 EXPECT_EQ(alertRemoveDims, wlUid2);
2270
2271 processor->OnLogEvent(CreateSyncStartEvent(bucket2StartTimeNs + 5 * NS_PER_SEC,
2272 attributionUids1, attributionTags1, "sync1")
2273 .get());
2274 EXPECT_EQ(alertPreserveCount, 0);
2275 EXPECT_EQ(alertRemoveCount, 2);
2276
2277 // AlertPreserve enters 30 sec refractory period for uid2.
2278 processor->OnLogEvent(CreateAcquireWakelockEvent(bucket2StartTimeNs + 10 * NS_PER_SEC,
2279 attributionUids2, attributionTags2, "wl2")
2280 .get());
2281 EXPECT_EQ(alertPreserveCount, 1);
2282 EXPECT_EQ(alertPreserveDims, wlUid2);
2283 EXPECT_EQ(alertRemoveCount, 3);
2284 EXPECT_EQ(alertRemoveDims, wlUid2);
2285
2286 // Do config update.
2287 StatsdConfig newConfig;
2288 newConfig.add_allowed_log_source("AID_ROOT");
2289 *newConfig.add_atom_matcher() = wakelockAcquireMatcher;
2290 *newConfig.add_atom_matcher() = syncStartMatcher;
2291
2292 // Clear dims of sync metric, will result in alertReplace getting replaced.
2293 countSync.clear_dimensions_in_what();
2294 *newConfig.add_count_metric() = countSync;
2295 *newConfig.add_count_metric() = countWakelock;
2296
2297 // New alert on existing metric. Should get current full bucket, but not history of 1st bucket.
2298 Alert alertNew = createAlert("AlertNew", countWakelock.id(), /*buckets=*/1, /*triggerSumGt=*/1);
2299 *newConfig.add_alert() = alertPreserve;
2300 *newConfig.add_alert() = alertNew;
2301 *newConfig.add_alert() = alertReplace;
2302
2303 int newSubId = 4;
2304 Subscription newSub = createSubscription("S4", Subscription::ALERT, alertNew.id());
2305 newSub.mutable_broadcast_subscriber_details()->set_subscriber_id(newSubId);
2306 *newConfig.add_subscription() = newSub;
2307 *newConfig.add_subscription() = replaceSub;
2308 *newConfig.add_subscription() = preserveSub;
2309
2310 int alertNewCount = 0;
2311 StatsDimensionsValueParcel alertNewDims;
2312 shared_ptr<MockPendingIntentRef> newBroadcast =
2313 SharedRefBase::make<StrictMock<MockPendingIntentRef>>();
2314 EXPECT_CALL(*newBroadcast,
2315 sendSubscriberBroadcast(configUid, configId, newSub.id(), alertNew.id(), _, _))
2316 .Times(1)
2317 .WillRepeatedly(
2318 Invoke([&alertNewCount, &alertNewDims](
2319 int64_t, int64_t, int64_t, int64_t, const vector<string>&,
2320 const StatsDimensionsValueParcel& dimensionsValueParcel) {
2321 alertNewCount++;
2322 alertNewDims = dimensionsValueParcel;
2323 return Status::ok();
2324 }));
2325 SubscriberReporter::getInstance().setBroadcastSubscriber(key, newSubId, newBroadcast);
2326
2327 int64_t updateTimeNs = bucket2StartTimeNs + 15 * NS_PER_SEC;
2328 if (GetParam()) {
2329 EXPECT_CALL(*mLogEventFilter,
2330 setAtomIds(CreateAtomIdSetFromConfig(newConfig), processor.get()))
2331 .Times(1);
2332 }
2333 processor->OnConfigUpdated(updateTimeNs, key, newConfig);
2334
2335 // Within refractory of AlertPreserve, but AlertNew should fire since the full bucket has 2.
2336 processor->OnLogEvent(CreateAcquireWakelockEvent(bucket2StartTimeNs + 20 * NS_PER_SEC,
2337 attributionUids2, attributionTags2, "wl2")
2338 .get());
2339 EXPECT_EQ(alertPreserveCount, 1);
2340 EXPECT_EQ(alertNewCount, 1);
2341 EXPECT_EQ(alertNewDims, wlUid2);
2342
2343 // Wakelock for uid1 fired in first bucket, alert preserve should keep the history and fire.
2344 processor->OnLogEvent(CreateAcquireWakelockEvent(bucket2StartTimeNs + 25 * NS_PER_SEC,
2345 attributionUids1, attributionTags1, "wl1")
2346 .get());
2347 EXPECT_EQ(alertPreserveCount, 2);
2348 EXPECT_EQ(alertPreserveDims, wlUid1);
2349 EXPECT_EQ(alertNewCount, 1);
2350
2351 processor->OnLogEvent(CreateSyncStartEvent(bucket2StartTimeNs + 30 * NS_PER_SEC,
2352 attributionUids1, attributionTags1, "sync1")
2353 .get());
2354 EXPECT_EQ(alertPreserveCount, 2);
2355 EXPECT_EQ(alertNewCount, 1);
2356 EXPECT_EQ(alertRemoveCount, 3);
2357
2358 // Clear data so it doesn't stay on disk.
2359 vector<uint8_t> buffer;
2360 processor->onDumpReport(key, bucket2StartTimeNs + 100 * NS_PER_SEC, true, true, ADB_DUMP, FAST,
2361 &buffer);
2362 SubscriberReporter::getInstance().unsetBroadcastSubscriber(key, preserveSubId);
2363 SubscriberReporter::getInstance().unsetBroadcastSubscriber(key, replaceSubId);
2364 SubscriberReporter::getInstance().unsetBroadcastSubscriber(key, removeSubId);
2365 SubscriberReporter::getInstance().unsetBroadcastSubscriber(key, newSubId);
2366 }
2367
TEST_P(ConfigUpdateE2eTest,TestAnomalyDurationMetric)2368 TEST_P(ConfigUpdateE2eTest, TestAnomalyDurationMetric) {
2369 StatsdConfig config;
2370 config.add_allowed_log_source("AID_ROOT");
2371
2372 AtomMatcher wakelockAcquireMatcher = CreateAcquireWakelockAtomMatcher();
2373 *config.add_atom_matcher() = wakelockAcquireMatcher;
2374 AtomMatcher wakelockReleaseMatcher = CreateReleaseWakelockAtomMatcher();
2375 *config.add_atom_matcher() = wakelockReleaseMatcher;
2376 AtomMatcher screenOnMatcher = CreateScreenTurnedOnAtomMatcher();
2377 *config.add_atom_matcher() = screenOnMatcher;
2378 AtomMatcher screenOffMatcher = CreateScreenTurnedOffAtomMatcher();
2379 *config.add_atom_matcher() = screenOffMatcher;
2380
2381 Predicate holdingWakelockPredicate = CreateHoldingWakelockPredicate();
2382 *holdingWakelockPredicate.mutable_simple_predicate()->mutable_dimensions() =
2383 CreateAttributionUidDimensions(util::WAKELOCK_STATE_CHANGED, {Position::FIRST});
2384 *config.add_predicate() = holdingWakelockPredicate;
2385 Predicate screenOnPredicate = CreateScreenIsOnPredicate();
2386 *config.add_predicate() = screenOnPredicate;
2387
2388 DurationMetric durationWakelock =
2389 createDurationMetric("DurWakelock", holdingWakelockPredicate.id(), nullopt, {});
2390 *durationWakelock.mutable_dimensions_in_what() =
2391 CreateAttributionUidDimensions(util::WAKELOCK_STATE_CHANGED, {Position::FIRST});
2392 DurationMetric durationScreen =
2393 createDurationMetric("DurScreen", screenOnPredicate.id(), nullopt, {});
2394 *config.add_duration_metric() = durationScreen;
2395 *config.add_duration_metric() = durationWakelock;
2396
2397 Alert alertPreserve = createAlert("AlertPreserve", durationWakelock.id(), /*buckets=*/2,
2398 /*triggerSumGt=*/30 * NS_PER_SEC);
2399 alertPreserve.set_refractory_period_secs(300);
2400 Alert alertReplace = createAlert("AlertReplace", durationScreen.id(), 2, 30 * NS_PER_SEC);
2401 alertReplace.set_refractory_period_secs(1);
2402 Alert alertRemove = createAlert("AlertRemove", durationWakelock.id(), 5, 10 * NS_PER_SEC);
2403 alertRemove.set_refractory_period_secs(1);
2404 *config.add_alert() = alertReplace;
2405 *config.add_alert() = alertPreserve;
2406 *config.add_alert() = alertRemove;
2407
2408 int preserveSubId = 1, replaceSubId = 2, removeSubId = 3;
2409 Subscription preserveSub = createSubscription("S1", Subscription::ALERT, alertPreserve.id());
2410 preserveSub.mutable_broadcast_subscriber_details()->set_subscriber_id(preserveSubId);
2411 Subscription replaceSub = createSubscription("S2", Subscription::ALERT, alertReplace.id());
2412 replaceSub.mutable_broadcast_subscriber_details()->set_subscriber_id(replaceSubId);
2413 Subscription removeSub = createSubscription("S3", Subscription::ALERT, alertRemove.id());
2414 removeSub.mutable_broadcast_subscriber_details()->set_subscriber_id(removeSubId);
2415 *config.add_subscription() = preserveSub;
2416 *config.add_subscription() = removeSub;
2417 *config.add_subscription() = replaceSub;
2418
2419 int app1Uid = 123, app2Uid = 456, app3Uid = 789, app4Uid = 111;
2420 vector<int> attributionUids1 = {app1Uid}, attributionUids2 = {app2Uid},
2421 attributionUids3 = {app3Uid}, attributionUids4 = {app4Uid};
2422 vector<string> attributionTags1 = {"App1"}, attributionTags2 = {"App2"},
2423 attributionTags3 = {"App3"}, attributionTags4 = {"App4"};
2424
2425 int64_t configUid = 123, configId = 987;
2426 ConfigKey key(configUid, configId);
2427
2428 int alertPreserveCount = 0, alertRemoveCount = 0;
2429 StatsDimensionsValueParcel alertPreserveDims;
2430 StatsDimensionsValueParcel alertRemoveDims;
2431
2432 // The binder calls here will happen synchronously because they are in-process.
2433 shared_ptr<MockPendingIntentRef> preserveBroadcast =
2434 SharedRefBase::make<StrictMock<MockPendingIntentRef>>();
2435 EXPECT_CALL(*preserveBroadcast, sendSubscriberBroadcast(configUid, configId, preserveSub.id(),
2436 alertPreserve.id(), _, _))
2437 .Times(4)
2438 .WillRepeatedly(
2439 Invoke([&alertPreserveCount, &alertPreserveDims](
2440 int64_t, int64_t, int64_t, int64_t, const vector<string>&,
2441 const StatsDimensionsValueParcel& dimensionsValueParcel) {
2442 alertPreserveCount++;
2443 alertPreserveDims = dimensionsValueParcel;
2444 return Status::ok();
2445 }));
2446
2447 shared_ptr<MockPendingIntentRef> replaceBroadcast =
2448 SharedRefBase::make<StrictMock<MockPendingIntentRef>>();
2449 EXPECT_CALL(*replaceBroadcast, sendSubscriberBroadcast(configUid, configId, replaceSub.id(),
2450 alertReplace.id(), _, _))
2451 .Times(0);
2452
2453 shared_ptr<MockPendingIntentRef> removeBroadcast =
2454 SharedRefBase::make<StrictMock<MockPendingIntentRef>>();
2455 EXPECT_CALL(*removeBroadcast, sendSubscriberBroadcast(configUid, configId, removeSub.id(),
2456 alertRemove.id(), _, _))
2457 .Times(6)
2458 .WillRepeatedly(
2459 Invoke([&alertRemoveCount, &alertRemoveDims](
2460 int64_t, int64_t, int64_t, int64_t, const vector<string>&,
2461 const StatsDimensionsValueParcel& dimensionsValueParcel) {
2462 alertRemoveCount++;
2463 alertRemoveDims = dimensionsValueParcel;
2464 return Status::ok();
2465 }));
2466
2467 SubscriberReporter::getInstance().setBroadcastSubscriber(key, preserveSubId, preserveBroadcast);
2468 SubscriberReporter::getInstance().setBroadcastSubscriber(key, replaceSubId, replaceBroadcast);
2469 SubscriberReporter::getInstance().setBroadcastSubscriber(key, removeSubId, removeBroadcast);
2470
2471 const sp<UidMap> uidMap = new UidMap();
2472 if (GetParam()) {
2473 // call from StatsLogProcessor constructor
2474 Expectation initCall = EXPECT_CALL(*mLogEventFilter,
2475 setAtomIds(StatsLogProcessor::getDefaultAtomIdSet(), _))
2476 .Times(1);
2477 EXPECT_CALL(*mLogEventFilter, setAtomIds(CreateAtomIdSetFromConfig(config), _))
2478 .Times(1)
2479 .After(initCall);
2480 }
2481 const shared_ptr<StatsService> service = SharedRefBase::make<StatsService>(
2482 uidMap, /* queue */ nullptr, /* LogEventFilter */ mLogEventFilter);
2483 sp<StatsLogProcessor> processor = service->mProcessor;
2484 uint64_t bucketSizeNs = TimeUnitToBucketSizeInMillis(TEN_MINUTES) * 1000000LL;
2485 int64_t bucketStartTimeNs = processor->mTimeBaseNs;
2486 int64_t roundedBucketStartTimeNs = bucketStartTimeNs / NS_PER_SEC * NS_PER_SEC;
2487 uint64_t bucket2StartTimeNs = bucketStartTimeNs + bucketSizeNs;
2488 processor->OnConfigUpdated(bucketStartTimeNs, key, config);
2489
2490 StatsDimensionsValueParcel wlUid1 =
2491 CreateAttributionUidDimensionsValueParcel(util::WAKELOCK_STATE_CHANGED, app1Uid);
2492 StatsDimensionsValueParcel wlUid2 =
2493 CreateAttributionUidDimensionsValueParcel(util::WAKELOCK_STATE_CHANGED, app2Uid);
2494 StatsDimensionsValueParcel wlUid3 =
2495 CreateAttributionUidDimensionsValueParcel(util::WAKELOCK_STATE_CHANGED, app3Uid);
2496 StatsDimensionsValueParcel wlUid4 =
2497 CreateAttributionUidDimensionsValueParcel(util::WAKELOCK_STATE_CHANGED, app4Uid);
2498
2499 int64_t eventTimeNs = bucketStartTimeNs + 15 * NS_PER_SEC;
2500 processor->OnLogEvent(
2501 CreateAcquireWakelockEvent(eventTimeNs, attributionUids1, attributionTags1, "wl1")
2502 .get(),
2503 eventTimeNs);
2504 EXPECT_EQ(alertPreserveCount, 0);
2505 EXPECT_EQ(alertRemoveCount, 0);
2506
2507 eventTimeNs = bucketStartTimeNs + 20 * NS_PER_SEC;
2508 processor->OnLogEvent(CreateScreenStateChangedEvent(
2509 eventTimeNs, android::view::DisplayStateEnum::DISPLAY_STATE_ON)
2510 .get(),
2511 eventTimeNs);
2512 EXPECT_EQ(alertPreserveCount, 0);
2513 EXPECT_EQ(alertRemoveCount, 0);
2514
2515 // Uid 1 accumulates 15 seconds in bucket #1.
2516 eventTimeNs = bucketStartTimeNs + 30 * NS_PER_SEC;
2517 processor->OnLogEvent(
2518 CreateReleaseWakelockEvent(eventTimeNs, attributionUids1, attributionTags1, "wl1")
2519 .get(),
2520 eventTimeNs);
2521 EXPECT_EQ(alertPreserveCount, 0);
2522 EXPECT_EQ(alertRemoveCount, 1);
2523 EXPECT_EQ(alertRemoveDims, wlUid1);
2524
2525 // 20 seconds accumulated in bucket #1.
2526 eventTimeNs = bucketStartTimeNs + 40 * NS_PER_SEC;
2527 processor->OnLogEvent(CreateScreenStateChangedEvent(
2528 eventTimeNs, android::view::DisplayStateEnum::DISPLAY_STATE_OFF)
2529 .get(),
2530 eventTimeNs);
2531 EXPECT_EQ(alertPreserveCount, 0);
2532 EXPECT_EQ(alertRemoveCount, 1);
2533
2534 eventTimeNs = bucket2StartTimeNs + 2 * NS_PER_SEC;
2535 processor->OnLogEvent(
2536 CreateAcquireWakelockEvent(eventTimeNs, attributionUids4, attributionTags4, "wl4")
2537 .get(),
2538 eventTimeNs);
2539 EXPECT_EQ(alertPreserveCount, 0);
2540 EXPECT_EQ(alertRemoveCount, 1);
2541
2542 eventTimeNs = bucket2StartTimeNs + 5 * NS_PER_SEC;
2543 processor->OnLogEvent(
2544 CreateAcquireWakelockEvent(eventTimeNs, attributionUids2, attributionTags2, "wl2")
2545 .get(),
2546 eventTimeNs);
2547 EXPECT_EQ(alertPreserveCount, 0);
2548 EXPECT_EQ(alertRemoveCount, 1);
2549
2550 // Alarm for alert remove for uid 4.
2551 eventTimeNs = bucket2StartTimeNs + 13 * NS_PER_SEC;
2552 processor->OnLogEvent(CreateBatteryStateChangedEvent(
2553 eventTimeNs, BatteryPluggedStateEnum::BATTERY_PLUGGED_USB)
2554 .get(),
2555 eventTimeNs);
2556 EXPECT_EQ(alertPreserveCount, 0);
2557 EXPECT_EQ(alertRemoveCount, 2);
2558 EXPECT_EQ(alertRemoveDims, wlUid4);
2559
2560 // Uid3 will be pending at the update.
2561 // Also acts as the alarm for alert remove for uid 2.
2562 eventTimeNs = bucket2StartTimeNs + 30 * NS_PER_SEC;
2563 processor->OnLogEvent(
2564 CreateAcquireWakelockEvent(eventTimeNs, attributionUids3, attributionTags3, "wl3")
2565 .get(),
2566 eventTimeNs);
2567 EXPECT_EQ(alertPreserveCount, 0);
2568 EXPECT_EQ(alertRemoveCount, 3);
2569 EXPECT_EQ(alertRemoveDims, wlUid2);
2570
2571 // Alarm for alert preserve for uid 4, enters 5 min refractory period.
2572 eventTimeNs = bucket2StartTimeNs + 33 * NS_PER_SEC;
2573 processor->OnLogEvent(CreateBatteryStateChangedEvent(
2574 eventTimeNs, BatteryPluggedStateEnum::BATTERY_PLUGGED_USB)
2575 .get(),
2576 eventTimeNs);
2577 EXPECT_EQ(alertPreserveCount, 1);
2578 EXPECT_EQ(alertPreserveDims, wlUid4);
2579 EXPECT_EQ(alertRemoveCount, 3);
2580
2581 // Uid 2 accumulates 32 seconds in partial bucket before the update. Alert preserve fires.
2582 // Preserve enters 5 min refractory for uid 2.
2583 // Alert remove fires again for uid 2 since the refractory has expired.
2584 eventTimeNs = bucket2StartTimeNs + 37 * NS_PER_SEC;
2585 processor->OnLogEvent(
2586 CreateReleaseWakelockEvent(eventTimeNs, attributionUids2, attributionTags2, "wl2")
2587 .get(),
2588 eventTimeNs);
2589 EXPECT_EQ(alertPreserveCount, 2);
2590 EXPECT_EQ(alertPreserveDims, wlUid2);
2591 EXPECT_EQ(alertRemoveCount, 4);
2592 EXPECT_EQ(alertRemoveDims, wlUid2);
2593
2594 // Alarm for alert remove for uid 3.
2595 eventTimeNs = bucket2StartTimeNs + 41 * NS_PER_SEC;
2596 processor->OnLogEvent(CreateBatteryStateChangedEvent(
2597 eventTimeNs, BatteryPluggedStateEnum::BATTERY_PLUGGED_USB)
2598 .get(),
2599 eventTimeNs);
2600 EXPECT_EQ(alertPreserveCount, 2);
2601 EXPECT_EQ(alertRemoveCount, 5);
2602 EXPECT_EQ(alertRemoveDims, wlUid3);
2603
2604 // Release wl for uid 4, has accumulated 41 seconds in partial bucket before update.
2605 // Acts as alarm for uid3 of alert remove.
2606 eventTimeNs = bucket2StartTimeNs + 43 * NS_PER_SEC;
2607 processor->OnLogEvent(
2608 CreateReleaseWakelockEvent(eventTimeNs, attributionUids4, attributionTags4, "wl4")
2609 .get(),
2610 eventTimeNs);
2611 EXPECT_EQ(alertPreserveCount, 2);
2612 EXPECT_EQ(alertRemoveCount, 6);
2613 EXPECT_EQ(alertRemoveDims, wlUid4);
2614
2615 // Starts the timer for screen on.
2616 eventTimeNs = bucket2StartTimeNs + 46 * NS_PER_SEC;
2617 processor->OnLogEvent(CreateScreenStateChangedEvent(
2618 eventTimeNs, android::view::DisplayStateEnum::DISPLAY_STATE_ON)
2619 .get(),
2620 eventTimeNs);
2621 EXPECT_EQ(alertPreserveCount, 2);
2622 EXPECT_EQ(alertRemoveCount, 6);
2623
2624 // Do config update.
2625 StatsdConfig newConfig;
2626 newConfig.add_allowed_log_source("AID_ROOT");
2627 *newConfig.add_atom_matcher() = wakelockAcquireMatcher;
2628 *newConfig.add_atom_matcher() = screenOffMatcher;
2629 *newConfig.add_atom_matcher() = wakelockReleaseMatcher;
2630 *newConfig.add_atom_matcher() = screenOnMatcher;
2631 *newConfig.add_predicate() = screenOnPredicate;
2632 *newConfig.add_predicate() = holdingWakelockPredicate;
2633 *newConfig.add_duration_metric() = durationWakelock;
2634 *newConfig.add_duration_metric() = durationScreen;
2635
2636 alertReplace.set_refractory_period_secs(2); // Causes replacement.
2637 // New alert on existing metric. Should get current full bucket, but not history of 1st bucket.
2638 Alert alertNew = createAlert("AlertNew", durationWakelock.id(), /*buckets=*/2,
2639 /*triggerSumGt=*/40 * NS_PER_SEC);
2640 *newConfig.add_alert() = alertPreserve;
2641 *newConfig.add_alert() = alertNew;
2642 *newConfig.add_alert() = alertReplace;
2643
2644 int newSubId = 4;
2645 Subscription newSub = createSubscription("S4", Subscription::ALERT, alertNew.id());
2646 newSub.mutable_broadcast_subscriber_details()->set_subscriber_id(newSubId);
2647 *newConfig.add_subscription() = newSub;
2648 *newConfig.add_subscription() = replaceSub;
2649 *newConfig.add_subscription() = preserveSub;
2650
2651 int alertNewCount = 0;
2652 StatsDimensionsValueParcel alertNewDims;
2653 shared_ptr<MockPendingIntentRef> newBroadcast =
2654 SharedRefBase::make<StrictMock<MockPendingIntentRef>>();
2655 EXPECT_CALL(*newBroadcast,
2656 sendSubscriberBroadcast(configUid, configId, newSub.id(), alertNew.id(), _, _))
2657 .Times(3)
2658 .WillRepeatedly(
2659 Invoke([&alertNewCount, &alertNewDims](
2660 int64_t, int64_t, int64_t, int64_t, const vector<string>&,
2661 const StatsDimensionsValueParcel& dimensionsValueParcel) {
2662 alertNewCount++;
2663 alertNewDims = dimensionsValueParcel;
2664 return Status::ok();
2665 }));
2666 SubscriberReporter::getInstance().setBroadcastSubscriber(key, newSubId, newBroadcast);
2667
2668 int64_t updateTimeNs = bucket2StartTimeNs + 50 * NS_PER_SEC;
2669 if (GetParam()) {
2670 EXPECT_CALL(*mLogEventFilter, setAtomIds(CreateAtomIdSetFromConfig(newConfig), _)).Times(1);
2671 }
2672 processor->OnConfigUpdated(updateTimeNs, key, newConfig);
2673
2674 // Alert preserve will set alarm after the refractory period, but alert new will set it for
2675 // 8 seconds after this event.
2676 // Alert new should fire for uid 4, since it has already accumulated 41s and should fire on the
2677 // first event after the update.
2678 eventTimeNs = bucket2StartTimeNs + 55 * NS_PER_SEC;
2679 processor->OnLogEvent(
2680 CreateAcquireWakelockEvent(eventTimeNs, attributionUids2, attributionTags2, "wl2")
2681 .get(),
2682 eventTimeNs);
2683 EXPECT_EQ(alertPreserveCount, 2);
2684 EXPECT_EQ(alertNewCount, 1);
2685 EXPECT_EQ(alertNewDims, wlUid4);
2686
2687 eventTimeNs = bucket2StartTimeNs + 60 * NS_PER_SEC;
2688 // Alert replace doesn't fire because it has lost history.
2689 processor->OnLogEvent(CreateScreenStateChangedEvent(
2690 eventTimeNs, android::view::DisplayStateEnum::DISPLAY_STATE_OFF)
2691 .get(),
2692 eventTimeNs);
2693 EXPECT_EQ(alertPreserveCount, 2);
2694 EXPECT_EQ(alertNewCount, 1);
2695
2696 // Alert preserve has 15 seconds from 1st bucket, so alert should fire at bucket2Start + 80.
2697 // Serves as alarm for alert new for uid2.
2698 // Also serves as alarm for alert preserve for uid 3, which began at bucket2Start + 30.
2699 eventTimeNs = bucket2StartTimeNs + 65 * NS_PER_SEC;
2700 processor->OnLogEvent(
2701 CreateAcquireWakelockEvent(eventTimeNs, attributionUids1, attributionTags1, "wl1")
2702 .get(),
2703 eventTimeNs);
2704 EXPECT_EQ(alertPreserveCount, 3);
2705 EXPECT_EQ(alertPreserveDims, wlUid3);
2706 EXPECT_EQ(alertNewCount, 2);
2707 EXPECT_EQ(alertNewDims, wlUid2);
2708
2709 // Release wakelock for uid1, causing alert preserve to fire for uid1.
2710 // Also serves as alarm for alert new for uid3.
2711 eventTimeNs = bucket2StartTimeNs + 81 * NS_PER_SEC;
2712 processor->OnLogEvent(
2713 CreateReleaseWakelockEvent(eventTimeNs, attributionUids1, attributionTags1, "wl1")
2714 .get(),
2715 eventTimeNs);
2716 EXPECT_EQ(alertPreserveCount, 4);
2717 EXPECT_EQ(alertPreserveDims, wlUid1);
2718 EXPECT_EQ(alertNewCount, 3);
2719 EXPECT_EQ(alertNewDims, wlUid3);
2720
2721 // Clear data so it doesn't stay on disk.
2722 vector<uint8_t> buffer;
2723 processor->onDumpReport(key, bucket2StartTimeNs + 100 * NS_PER_SEC, true, true, ADB_DUMP, FAST,
2724 &buffer);
2725 SubscriberReporter::getInstance().unsetBroadcastSubscriber(key, preserveSubId);
2726 SubscriberReporter::getInstance().unsetBroadcastSubscriber(key, replaceSubId);
2727 SubscriberReporter::getInstance().unsetBroadcastSubscriber(key, removeSubId);
2728 SubscriberReporter::getInstance().unsetBroadcastSubscriber(key, newSubId);
2729 }
2730
TEST_P(ConfigUpdateE2eTest,TestAlarms)2731 TEST_P(ConfigUpdateE2eTest, TestAlarms) {
2732 StatsdConfig config;
2733 config.add_allowed_log_source("AID_ROOT");
2734 Alarm alarmPreserve = createAlarm("AlarmPreserve", /*offset*/ 5 * MS_PER_SEC,
2735 /*period*/ TimeUnitToBucketSizeInMillis(ONE_MINUTE));
2736 Alarm alarmReplace = createAlarm("AlarmReplace", /*offset*/ 1,
2737 /*period*/ TimeUnitToBucketSizeInMillis(FIVE_MINUTES));
2738 Alarm alarmRemove = createAlarm("AlarmRemove", /*offset*/ 1,
2739 /*period*/ TimeUnitToBucketSizeInMillis(ONE_MINUTE));
2740 *config.add_alarm() = alarmReplace;
2741 *config.add_alarm() = alarmPreserve;
2742 *config.add_alarm() = alarmRemove;
2743
2744 int preserveSubId = 1, replaceSubId = 2, removeSubId = 3;
2745 Subscription preserveSub = createSubscription("S1", Subscription::ALARM, alarmPreserve.id());
2746 preserveSub.mutable_broadcast_subscriber_details()->set_subscriber_id(preserveSubId);
2747 Subscription replaceSub = createSubscription("S2", Subscription::ALARM, alarmReplace.id());
2748 replaceSub.mutable_broadcast_subscriber_details()->set_subscriber_id(replaceSubId);
2749 Subscription removeSub = createSubscription("S3", Subscription::ALARM, alarmRemove.id());
2750 removeSub.mutable_broadcast_subscriber_details()->set_subscriber_id(removeSubId);
2751 *config.add_subscription() = preserveSub;
2752 *config.add_subscription() = removeSub;
2753 *config.add_subscription() = replaceSub;
2754
2755 int64_t configUid = 123, configId = 987;
2756 ConfigKey key(configUid, configId);
2757
2758 int alarmPreserveCount = 0, alarmReplaceCount = 0, alarmRemoveCount = 0;
2759
2760 // The binder calls here will happen synchronously because they are in-process.
2761 shared_ptr<MockPendingIntentRef> preserveBroadcast =
2762 SharedRefBase::make<StrictMock<MockPendingIntentRef>>();
2763 EXPECT_CALL(*preserveBroadcast, sendSubscriberBroadcast(configUid, configId, preserveSub.id(),
2764 alarmPreserve.id(), _, _))
2765 .Times(4)
2766 .WillRepeatedly([&alarmPreserveCount](int64_t, int64_t, int64_t, int64_t,
2767 const vector<string>&,
2768 const StatsDimensionsValueParcel&) {
2769 alarmPreserveCount++;
2770 return Status::ok();
2771 });
2772
2773 shared_ptr<MockPendingIntentRef> replaceBroadcast =
2774 SharedRefBase::make<StrictMock<MockPendingIntentRef>>();
2775 EXPECT_CALL(*replaceBroadcast, sendSubscriberBroadcast(configUid, configId, replaceSub.id(),
2776 alarmReplace.id(), _, _))
2777 .Times(2)
2778 .WillRepeatedly([&alarmReplaceCount](int64_t, int64_t, int64_t, int64_t,
2779 const vector<string>&,
2780 const StatsDimensionsValueParcel&) {
2781 alarmReplaceCount++;
2782 return Status::ok();
2783 });
2784
2785 shared_ptr<MockPendingIntentRef> removeBroadcast =
2786 SharedRefBase::make<StrictMock<MockPendingIntentRef>>();
2787 EXPECT_CALL(*removeBroadcast, sendSubscriberBroadcast(configUid, configId, removeSub.id(),
2788 alarmRemove.id(), _, _))
2789 .Times(1)
2790 .WillRepeatedly([&alarmRemoveCount](int64_t, int64_t, int64_t, int64_t,
2791 const vector<string>&,
2792 const StatsDimensionsValueParcel&) {
2793 alarmRemoveCount++;
2794 return Status::ok();
2795 });
2796
2797 SubscriberReporter::getInstance().setBroadcastSubscriber(key, preserveSubId, preserveBroadcast);
2798 SubscriberReporter::getInstance().setBroadcastSubscriber(key, replaceSubId, replaceBroadcast);
2799 SubscriberReporter::getInstance().setBroadcastSubscriber(key, removeSubId, removeBroadcast);
2800
2801 int64_t startTimeSec = 10;
2802 sp<StatsLogProcessor> processor = CreateStatsLogProcessor(
2803 startTimeSec * NS_PER_SEC, startTimeSec * NS_PER_SEC, config, key, mLogEventFilter);
2804
2805 sp<AlarmMonitor> alarmMonitor = processor->getPeriodicAlarmMonitor();
2806 // First alarm is for alarm preserve's offset of 5 seconds.
2807 EXPECT_EQ(alarmMonitor->getRegisteredAlarmTimeSec(), startTimeSec + 5);
2808
2809 // Alarm fired at 5. AlarmPreserve should fire.
2810 int32_t alarmFiredTimestampSec = startTimeSec + 5;
2811 auto alarmSet = alarmMonitor->popSoonerThan(static_cast<uint32_t>(alarmFiredTimestampSec));
2812 processor->onPeriodicAlarmFired(alarmFiredTimestampSec * NS_PER_SEC, alarmSet);
2813 EXPECT_EQ(alarmPreserveCount, 1);
2814 EXPECT_EQ(alarmReplaceCount, 0);
2815 EXPECT_EQ(alarmRemoveCount, 0);
2816 EXPECT_EQ(alarmMonitor->getRegisteredAlarmTimeSec(), startTimeSec + 60);
2817
2818 // Alarm fired at 75. AlarmPreserve and AlarmRemove should fire.
2819 alarmFiredTimestampSec = startTimeSec + 75;
2820 alarmSet = alarmMonitor->popSoonerThan(static_cast<uint32_t>(alarmFiredTimestampSec));
2821 processor->onPeriodicAlarmFired(alarmFiredTimestampSec * NS_PER_SEC, alarmSet);
2822 EXPECT_EQ(alarmPreserveCount, 2);
2823 EXPECT_EQ(alarmReplaceCount, 0);
2824 EXPECT_EQ(alarmRemoveCount, 1);
2825 EXPECT_EQ(alarmMonitor->getRegisteredAlarmTimeSec(), startTimeSec + 120);
2826
2827 // Do config update.
2828 StatsdConfig newConfig;
2829 newConfig.add_allowed_log_source("AID_ROOT");
2830
2831 // Change alarm replace's definition.
2832 alarmReplace.set_period_millis(TimeUnitToBucketSizeInMillis(ONE_MINUTE));
2833 Alarm alarmNew = createAlarm("AlarmNew", /*offset*/ 1,
2834 /*period*/ TimeUnitToBucketSizeInMillis(FIVE_MINUTES));
2835 *newConfig.add_alarm() = alarmNew;
2836 *newConfig.add_alarm() = alarmPreserve;
2837 *newConfig.add_alarm() = alarmReplace;
2838
2839 int newSubId = 4;
2840 Subscription newSub = createSubscription("S4", Subscription::ALARM, alarmNew.id());
2841 newSub.mutable_broadcast_subscriber_details()->set_subscriber_id(newSubId);
2842 *newConfig.add_subscription() = newSub;
2843 *newConfig.add_subscription() = replaceSub;
2844 *newConfig.add_subscription() = preserveSub;
2845
2846 int alarmNewCount = 0;
2847 shared_ptr<MockPendingIntentRef> newBroadcast =
2848 SharedRefBase::make<StrictMock<MockPendingIntentRef>>();
2849 EXPECT_CALL(*newBroadcast,
2850 sendSubscriberBroadcast(configUid, configId, newSub.id(), alarmNew.id(), _, _))
2851 .Times(1)
2852 .WillRepeatedly([&alarmNewCount](int64_t, int64_t, int64_t, int64_t,
2853 const vector<string>&,
2854 const StatsDimensionsValueParcel&) {
2855 alarmNewCount++;
2856 return Status::ok();
2857 });
2858 SubscriberReporter::getInstance().setBroadcastSubscriber(key, newSubId, newBroadcast);
2859 if (GetParam()) {
2860 EXPECT_CALL(*mLogEventFilter, setAtomIds(CreateAtomIdSetFromConfig(newConfig), _)).Times(1);
2861 }
2862 processor->OnConfigUpdated((startTimeSec + 90) * NS_PER_SEC, key, newConfig);
2863 // After the update, the alarm time should remain unchanged since alarm replace now fires every
2864 // minute with no offset.
2865 EXPECT_EQ(alarmMonitor->getRegisteredAlarmTimeSec(), startTimeSec + 120);
2866
2867 // Alarm fired at 120. AlermReplace should fire.
2868 alarmFiredTimestampSec = startTimeSec + 120;
2869 alarmSet = alarmMonitor->popSoonerThan(static_cast<uint32_t>(alarmFiredTimestampSec));
2870 processor->onPeriodicAlarmFired(alarmFiredTimestampSec * NS_PER_SEC, alarmSet);
2871 EXPECT_EQ(alarmPreserveCount, 2);
2872 EXPECT_EQ(alarmReplaceCount, 1);
2873 EXPECT_EQ(alarmNewCount, 0);
2874 EXPECT_EQ(alarmMonitor->getRegisteredAlarmTimeSec(), startTimeSec + 125);
2875
2876 // Alarm fired at 130. AlarmPreserve should fire.
2877 alarmFiredTimestampSec = startTimeSec + 130;
2878 alarmSet = alarmMonitor->popSoonerThan(static_cast<uint32_t>(alarmFiredTimestampSec));
2879 processor->onPeriodicAlarmFired(alarmFiredTimestampSec * NS_PER_SEC, alarmSet);
2880 EXPECT_EQ(alarmPreserveCount, 3);
2881 EXPECT_EQ(alarmReplaceCount, 1);
2882 EXPECT_EQ(alarmNewCount, 0);
2883 EXPECT_EQ(alarmMonitor->getRegisteredAlarmTimeSec(), startTimeSec + 180);
2884
2885 // Alarm fired late at 310. All alerms should fire.
2886 alarmFiredTimestampSec = startTimeSec + 310;
2887 alarmSet = alarmMonitor->popSoonerThan(static_cast<uint32_t>(alarmFiredTimestampSec));
2888 processor->onPeriodicAlarmFired(alarmFiredTimestampSec * NS_PER_SEC, alarmSet);
2889 EXPECT_EQ(alarmPreserveCount, 4);
2890 EXPECT_EQ(alarmReplaceCount, 2);
2891 EXPECT_EQ(alarmNewCount, 1);
2892 EXPECT_EQ(alarmMonitor->getRegisteredAlarmTimeSec(), startTimeSec + 360);
2893
2894 // Clear subscribers
2895 SubscriberReporter::getInstance().unsetBroadcastSubscriber(key, preserveSubId);
2896 SubscriberReporter::getInstance().unsetBroadcastSubscriber(key, replaceSubId);
2897 SubscriberReporter::getInstance().unsetBroadcastSubscriber(key, removeSubId);
2898 SubscriberReporter::getInstance().unsetBroadcastSubscriber(key, newSubId);
2899 }
2900
TEST_P(ConfigUpdateE2eTest,TestNewDurationExistingWhat)2901 TEST_P(ConfigUpdateE2eTest, TestNewDurationExistingWhat) {
2902 StatsdConfig config;
2903 config.add_allowed_log_source("AID_ROOT");
2904 *config.add_atom_matcher() = CreateAcquireWakelockAtomMatcher();
2905 *config.add_atom_matcher() = CreateReleaseWakelockAtomMatcher();
2906
2907 Predicate holdingWakelockPredicate = CreateHoldingWakelockPredicate();
2908 *config.add_predicate() = holdingWakelockPredicate;
2909
2910 ConfigKey key(123, 987);
2911 uint64_t bucketStartTimeNs = 10000000000; // 0:10
2912 uint64_t bucketSizeNs = TimeUnitToBucketSizeInMillis(FIVE_MINUTES) * 1000000LL;
2913 sp<StatsLogProcessor> processor = CreateStatsLogProcessor(bucketStartTimeNs, bucketStartTimeNs,
2914 config, key, mLogEventFilter);
2915
2916 int app1Uid = 123;
2917 vector<int> attributionUids1 = {app1Uid};
2918 vector<string> attributionTags1 = {"App1"};
2919 // Create a wakelock acquire, causing the condition to be true.
2920 unique_ptr<LogEvent> event = CreateAcquireWakelockEvent(bucketStartTimeNs + 10 * NS_PER_SEC,
2921 attributionUids1, attributionTags1,
2922 "wl1"); // 0:10
2923 processor->OnLogEvent(event.get());
2924
2925 // Add metric.
2926 DurationMetric* durationMetric = config.add_duration_metric();
2927 durationMetric->set_id(StringToId("WakelockDuration"));
2928 durationMetric->set_what(holdingWakelockPredicate.id());
2929 durationMetric->set_aggregation_type(DurationMetric::SUM);
2930 durationMetric->set_bucket(FIVE_MINUTES);
2931
2932 uint64_t updateTimeNs = bucketStartTimeNs + 60 * NS_PER_SEC; // 1:00
2933 if (GetParam()) {
2934 EXPECT_CALL(*mLogEventFilter,
2935 setAtomIds(CreateAtomIdSetFromConfig(config), processor.get()))
2936 .Times(1);
2937 }
2938 processor->OnConfigUpdated(updateTimeNs, key, config);
2939
2940 event = CreateReleaseWakelockEvent(bucketStartTimeNs + 80 * NS_PER_SEC, attributionUids1,
2941 attributionTags1,
2942 "wl1"); // 1:20
2943 processor->OnLogEvent(event.get());
2944 uint64_t dumpTimeNs = bucketStartTimeNs + 90 * NS_PER_SEC; // 1:30
2945 ConfigMetricsReportList reports;
2946 vector<uint8_t> buffer;
2947 processor->onDumpReport(key, dumpTimeNs, true, true, ADB_DUMP, FAST, &buffer);
2948 EXPECT_TRUE(reports.ParseFromArray(&buffer[0], buffer.size()));
2949 backfillDimensionPath(&reports);
2950 backfillStringInReport(&reports);
2951 backfillStartEndTimestamp(&reports);
2952 ASSERT_EQ(reports.reports_size(), 1);
2953 ASSERT_EQ(reports.reports(0).metrics_size(), 1);
2954 EXPECT_TRUE(reports.reports(0).metrics(0).has_duration_metrics());
2955
2956 StatsLogReport::DurationMetricDataWrapper metricData;
2957 sortMetricDataByDimensionsValue(reports.reports(0).metrics(0).duration_metrics(), &metricData);
2958 ASSERT_EQ(metricData.data_size(), 1);
2959 DurationMetricData data = metricData.data(0);
2960 ASSERT_EQ(data.bucket_info_size(), 1);
2961
2962 DurationBucketInfo bucketInfo = data.bucket_info(0);
2963 EXPECT_EQ(bucketInfo.start_bucket_elapsed_nanos(), updateTimeNs);
2964 EXPECT_EQ(bucketInfo.end_bucket_elapsed_nanos(), dumpTimeNs);
2965 EXPECT_EQ(bucketInfo.duration_nanos(), 20 * NS_PER_SEC);
2966 }
2967
TEST_P(ConfigUpdateE2eTest,TestNewDurationExistingWhatSlicedCondition)2968 TEST_P(ConfigUpdateE2eTest, TestNewDurationExistingWhatSlicedCondition) {
2969 StatsdConfig config;
2970 config.add_allowed_log_source("AID_ROOT");
2971 *config.add_atom_matcher() = CreateAcquireWakelockAtomMatcher();
2972 *config.add_atom_matcher() = CreateReleaseWakelockAtomMatcher();
2973 *config.add_atom_matcher() = CreateMoveToBackgroundAtomMatcher();
2974 *config.add_atom_matcher() = CreateMoveToForegroundAtomMatcher();
2975
2976 Predicate holdingWakelockPredicate = CreateHoldingWakelockPredicate();
2977 // The predicate is dimensioning by first attribution node by uid.
2978 *holdingWakelockPredicate.mutable_simple_predicate()->mutable_dimensions() =
2979 CreateAttributionUidDimensions(util::WAKELOCK_STATE_CHANGED, {Position::FIRST});
2980 *config.add_predicate() = holdingWakelockPredicate;
2981
2982 Predicate isInBackgroundPredicate = CreateIsInBackgroundPredicate();
2983 *isInBackgroundPredicate.mutable_simple_predicate()->mutable_dimensions() =
2984 CreateDimensions(util::ACTIVITY_FOREGROUND_STATE_CHANGED, {1 /*uid*/});
2985 *config.add_predicate() = isInBackgroundPredicate;
2986
2987 ConfigKey key(123, 987);
2988 uint64_t bucketStartTimeNs = 10000000000; // 0:10
2989 uint64_t bucketSizeNs = TimeUnitToBucketSizeInMillis(FIVE_MINUTES) * 1000000LL;
2990 sp<StatsLogProcessor> processor = CreateStatsLogProcessor(bucketStartTimeNs, bucketStartTimeNs,
2991 config, key, mLogEventFilter);
2992
2993 int app1Uid = 123, app2Uid = 456;
2994 vector<int> attributionUids1 = {app1Uid};
2995 vector<string> attributionTags1 = {"App1"};
2996 vector<int> attributionUids2 = {app2Uid};
2997 vector<string> attributionTags2 = {"App2"};
2998 unique_ptr<LogEvent> event = CreateAcquireWakelockEvent(bucketStartTimeNs + 10 * NS_PER_SEC,
2999 attributionUids1, attributionTags1,
3000 "wl1"); // 0:10
3001 processor->OnLogEvent(event.get());
3002 event = CreateMoveToBackgroundEvent(bucketStartTimeNs + 22 * NS_PER_SEC, app1Uid); // 0:22
3003 processor->OnLogEvent(event.get());
3004 event = CreateAcquireWakelockEvent(bucketStartTimeNs + 35 * NS_PER_SEC, attributionUids2,
3005 attributionTags2,
3006 "wl1"); // 0:35
3007 processor->OnLogEvent(event.get());
3008
3009 // Add metric.
3010 DurationMetric* durationMetric = config.add_duration_metric();
3011 durationMetric->set_id(StringToId("WakelockDuration"));
3012 durationMetric->set_what(holdingWakelockPredicate.id());
3013 durationMetric->set_condition(isInBackgroundPredicate.id());
3014 durationMetric->set_aggregation_type(DurationMetric::SUM);
3015 // The metric is dimensioning by first attribution node and only by uid.
3016 *durationMetric->mutable_dimensions_in_what() =
3017 CreateAttributionUidDimensions(util::WAKELOCK_STATE_CHANGED, {Position::FIRST});
3018 durationMetric->set_bucket(FIVE_MINUTES);
3019 // Links between wakelock state atom and condition of app is in background.
3020 auto links = durationMetric->add_links();
3021 links->set_condition(isInBackgroundPredicate.id());
3022 *links->mutable_fields_in_what() =
3023 CreateAttributionUidDimensions(util::WAKELOCK_STATE_CHANGED, {Position::FIRST});
3024 *links->mutable_fields_in_condition() =
3025 CreateDimensions(util::ACTIVITY_FOREGROUND_STATE_CHANGED, {1 /*uid*/});
3026
3027 uint64_t updateTimeNs = bucketStartTimeNs + 60 * NS_PER_SEC; // 1:00
3028 if (GetParam()) {
3029 EXPECT_CALL(*mLogEventFilter,
3030 setAtomIds(CreateAtomIdSetFromConfig(config), processor.get()))
3031 .Times(1);
3032 }
3033 processor->OnConfigUpdated(updateTimeNs, key, config);
3034
3035 event = CreateMoveToBackgroundEvent(bucketStartTimeNs + 73 * NS_PER_SEC, app2Uid); // 1:13
3036 processor->OnLogEvent(event.get());
3037 event = CreateReleaseWakelockEvent(bucketStartTimeNs + 84 * NS_PER_SEC, attributionUids1,
3038 attributionTags1, "wl1"); // 1:24
3039 processor->OnLogEvent(event.get());
3040
3041 uint64_t dumpTimeNs = bucketStartTimeNs + 90 * NS_PER_SEC; // 1:30
3042 ConfigMetricsReportList reports;
3043 vector<uint8_t> buffer;
3044 processor->onDumpReport(key, dumpTimeNs, true, true, ADB_DUMP, FAST, &buffer);
3045 EXPECT_TRUE(reports.ParseFromArray(&buffer[0], buffer.size()));
3046 backfillDimensionPath(&reports);
3047 backfillStringInReport(&reports);
3048 backfillStartEndTimestamp(&reports);
3049 ASSERT_EQ(reports.reports_size(), 1);
3050 ASSERT_EQ(reports.reports(0).metrics_size(), 1);
3051 EXPECT_TRUE(reports.reports(0).metrics(0).has_duration_metrics());
3052
3053 StatsLogReport::DurationMetricDataWrapper metricData;
3054 sortMetricDataByDimensionsValue(reports.reports(0).metrics(0).duration_metrics(), &metricData);
3055 ASSERT_EQ(metricData.data_size(), 2);
3056
3057 DurationMetricData data = metricData.data(0);
3058 ValidateAttributionUidDimension(data.dimensions_in_what(), util::WAKELOCK_STATE_CHANGED,
3059 app1Uid);
3060 ASSERT_EQ(data.bucket_info_size(), 1);
3061 DurationBucketInfo bucketInfo = data.bucket_info(0);
3062 EXPECT_EQ(bucketInfo.duration_nanos(), 24 * NS_PER_SEC);
3063
3064 data = metricData.data(1);
3065 ValidateAttributionUidDimension(data.dimensions_in_what(), util::WAKELOCK_STATE_CHANGED,
3066 app2Uid);
3067 ASSERT_EQ(data.bucket_info_size(), 1);
3068 bucketInfo = data.bucket_info(0);
3069 EXPECT_EQ(bucketInfo.duration_nanos(), 17 * NS_PER_SEC);
3070 }
3071
TEST_P(ConfigUpdateE2eTest,TestNewDurationExistingWhatSlicedState)3072 TEST_P(ConfigUpdateE2eTest, TestNewDurationExistingWhatSlicedState) {
3073 StatsdConfig config;
3074 config.add_allowed_log_source("AID_ROOT");
3075 *config.add_atom_matcher() = CreateAcquireWakelockAtomMatcher();
3076 *config.add_atom_matcher() = CreateReleaseWakelockAtomMatcher();
3077
3078 Predicate holdingWakelockPredicate = CreateHoldingWakelockPredicate();
3079 // The predicate is dimensioning by first attribution node by uid.
3080 *holdingWakelockPredicate.mutable_simple_predicate()->mutable_dimensions() =
3081 CreateAttributionUidDimensions(util::WAKELOCK_STATE_CHANGED, {Position::FIRST});
3082 *config.add_predicate() = holdingWakelockPredicate;
3083
3084 auto uidProcessState = CreateUidProcessState();
3085 *config.add_state() = uidProcessState;
3086
3087 // Count metric. We don't care about this one. Only use it so the StateTracker gets persisted.
3088 CountMetric* countMetric = config.add_count_metric();
3089 countMetric->set_id(StringToId("Tmp"));
3090 countMetric->set_what(config.atom_matcher(0).id());
3091 countMetric->add_slice_by_state(uidProcessState.id());
3092 // The metric is dimensioning by first attribution node and only by uid.
3093 *countMetric->mutable_dimensions_in_what() =
3094 CreateAttributionUidDimensions(util::WAKELOCK_STATE_CHANGED, {Position::FIRST});
3095 countMetric->set_bucket(FIVE_MINUTES);
3096 auto stateLink = countMetric->add_state_link();
3097 stateLink->set_state_atom_id(util::UID_PROCESS_STATE_CHANGED);
3098 *stateLink->mutable_fields_in_what() =
3099 CreateAttributionUidDimensions(util::WAKELOCK_STATE_CHANGED, {Position::FIRST});
3100 *stateLink->mutable_fields_in_state() =
3101 CreateDimensions(util::UID_PROCESS_STATE_CHANGED, {1 /*uid*/});
3102 config.add_no_report_metric(countMetric->id());
3103
3104 ConfigKey key(123, 987);
3105 uint64_t bucketStartTimeNs = 10000000000; // 0:10
3106 uint64_t bucketSizeNs = TimeUnitToBucketSizeInMillis(FIVE_MINUTES) * 1000000LL;
3107 sp<StatsLogProcessor> processor = CreateStatsLogProcessor(bucketStartTimeNs, bucketStartTimeNs,
3108 config, key, mLogEventFilter);
3109
3110 int app1Uid = 123, app2Uid = 456;
3111 vector<int> attributionUids1 = {app1Uid};
3112 vector<string> attributionTags1 = {"App1"};
3113 vector<int> attributionUids2 = {app2Uid};
3114 vector<string> attributionTags2 = {"App2"};
3115 unique_ptr<LogEvent> event = CreateUidProcessStateChangedEvent(
3116 bucketStartTimeNs + 10 * NS_PER_SEC, app1Uid,
3117 android::app::ProcessStateEnum::PROCESS_STATE_IMPORTANT_FOREGROUND); // 0:10
3118 processor->OnLogEvent(event.get());
3119 event = CreateAcquireWakelockEvent(bucketStartTimeNs + 22 * NS_PER_SEC, attributionUids1,
3120 attributionTags1,
3121 "wl1"); // 0:22
3122 processor->OnLogEvent(event.get());
3123 event = CreateUidProcessStateChangedEvent(
3124 bucketStartTimeNs + 30 * NS_PER_SEC, app2Uid,
3125 android::app::ProcessStateEnum::PROCESS_STATE_IMPORTANT_FOREGROUND); // 0:30
3126 processor->OnLogEvent(event.get());
3127
3128 // Add metric.
3129 DurationMetric* durationMetric = config.add_duration_metric();
3130 durationMetric->set_id(StringToId("WakelockDuration"));
3131 durationMetric->set_what(holdingWakelockPredicate.id());
3132 durationMetric->add_slice_by_state(uidProcessState.id());
3133 durationMetric->set_aggregation_type(DurationMetric::SUM);
3134 // The metric is dimensioning by first attribution node and only by uid.
3135 *durationMetric->mutable_dimensions_in_what() =
3136 CreateAttributionUidDimensions(util::WAKELOCK_STATE_CHANGED, {Position::FIRST});
3137 durationMetric->set_bucket(FIVE_MINUTES);
3138 // Links between wakelock state atom and condition of app is in background.
3139 stateLink = durationMetric->add_state_link();
3140 stateLink->set_state_atom_id(util::UID_PROCESS_STATE_CHANGED);
3141 *stateLink->mutable_fields_in_what() =
3142 CreateAttributionUidDimensions(util::WAKELOCK_STATE_CHANGED, {Position::FIRST});
3143 *stateLink->mutable_fields_in_state() =
3144 CreateDimensions(util::UID_PROCESS_STATE_CHANGED, {1 /*uid*/});
3145
3146 uint64_t updateTimeNs = bucketStartTimeNs + 60 * NS_PER_SEC; // 1:00
3147 if (GetParam()) {
3148 EXPECT_CALL(*mLogEventFilter,
3149 setAtomIds(CreateAtomIdSetFromConfig(config), processor.get()))
3150 .Times(1);
3151 }
3152 processor->OnConfigUpdated(updateTimeNs, key, config);
3153
3154 event = CreateAcquireWakelockEvent(bucketStartTimeNs + 72 * NS_PER_SEC, attributionUids2,
3155 attributionTags2,
3156 "wl1"); // 1:13
3157 processor->OnLogEvent(event.get());
3158 event = CreateUidProcessStateChangedEvent(
3159 bucketStartTimeNs + 75 * NS_PER_SEC, app1Uid,
3160 android::app::ProcessStateEnum::PROCESS_STATE_IMPORTANT_BACKGROUND); // 1:15
3161 processor->OnLogEvent(event.get());
3162 event = CreateReleaseWakelockEvent(bucketStartTimeNs + 84 * NS_PER_SEC, attributionUids1,
3163 attributionTags1, "wl1"); // 1:24
3164 processor->OnLogEvent(event.get());
3165
3166 uint64_t dumpTimeNs = bucketStartTimeNs + 90 * NS_PER_SEC; // 1:30
3167 ConfigMetricsReportList reports;
3168 vector<uint8_t> buffer;
3169 processor->onDumpReport(key, dumpTimeNs, true, true, ADB_DUMP, FAST, &buffer);
3170 EXPECT_TRUE(reports.ParseFromArray(&buffer[0], buffer.size()));
3171 backfillDimensionPath(&reports);
3172 backfillStringInReport(&reports);
3173 backfillStartEndTimestamp(&reports);
3174 ASSERT_EQ(reports.reports_size(), 1);
3175 ASSERT_EQ(reports.reports(0).metrics_size(), 1);
3176 EXPECT_TRUE(reports.reports(0).metrics(0).has_duration_metrics());
3177
3178 StatsLogReport::DurationMetricDataWrapper metricData;
3179 sortMetricDataByDimensionsValue(reports.reports(0).metrics(0).duration_metrics(), &metricData);
3180 ASSERT_EQ(metricData.data_size(), 3);
3181
3182 DurationMetricData data = metricData.data(0);
3183 ValidateAttributionUidDimension(data.dimensions_in_what(), util::WAKELOCK_STATE_CHANGED,
3184 app1Uid);
3185 ValidateStateValue(data.slice_by_state(), util::UID_PROCESS_STATE_CHANGED,
3186 android::app::ProcessStateEnum::PROCESS_STATE_IMPORTANT_FOREGROUND);
3187 ASSERT_EQ(data.bucket_info_size(), 1);
3188 DurationBucketInfo bucketInfo = data.bucket_info(0);
3189 EXPECT_EQ(bucketInfo.duration_nanos(), 15 * NS_PER_SEC);
3190
3191 data = metricData.data(1);
3192 ValidateAttributionUidDimension(data.dimensions_in_what(), util::WAKELOCK_STATE_CHANGED,
3193 app1Uid);
3194 ValidateStateValue(data.slice_by_state(), util::UID_PROCESS_STATE_CHANGED,
3195 android::app::ProcessStateEnum::PROCESS_STATE_IMPORTANT_BACKGROUND);
3196 ASSERT_EQ(data.bucket_info_size(), 1);
3197 bucketInfo = data.bucket_info(0);
3198 EXPECT_EQ(bucketInfo.duration_nanos(), 9 * NS_PER_SEC);
3199
3200 data = metricData.data(2);
3201 ValidateAttributionUidDimension(data.dimensions_in_what(), util::WAKELOCK_STATE_CHANGED,
3202 app2Uid);
3203 ValidateStateValue(data.slice_by_state(), util::UID_PROCESS_STATE_CHANGED,
3204 android::app::ProcessStateEnum::PROCESS_STATE_IMPORTANT_FOREGROUND);
3205 ASSERT_EQ(data.bucket_info_size(), 1);
3206 bucketInfo = data.bucket_info(0);
3207 EXPECT_EQ(bucketInfo.duration_nanos(), 18 * NS_PER_SEC);
3208 }
3209
3210 #else
3211 GTEST_LOG_(INFO) << "This test does nothing.\n";
3212 #endif
3213
3214 } // namespace statsd
3215 } // namespace os
3216 } // namespace android
3217