1 // Copyright 2022 The Chromium Authors
2 // Use of this source code is governed by a BSD-style license that can be
3 // found in the LICENSE file.
4
5 #include "components/metrics/metrics_service_observer.h"
6
7 #include "base/base64.h"
8 #include "base/callback_list.h"
9 #include "base/json/json_string_value_serializer.h"
10 #include "base/task/single_thread_task_runner.h"
11 #include "base/test/bind.h"
12 #include "base/test/task_environment.h"
13 #include "components/metrics/log_decoder.h"
14 #include "components/metrics/metrics_log.h"
15 #include "components/metrics/metrics_logs_event_manager.h"
16 #include "components/metrics/metrics_pref_names.h"
17 #include "components/metrics/metrics_scheduler.h"
18 #include "components/metrics/metrics_service.h"
19 #include "components/metrics/metrics_state_manager.h"
20 #include "components/metrics/metrics_upload_scheduler.h"
21 #include "components/metrics/test/test_enabled_state_provider.h"
22 #include "components/metrics/test/test_metrics_service_client.h"
23 #include "components/metrics/unsent_log_store_metrics_impl.h"
24 #include "components/prefs/testing_pref_service.h"
25 #include "testing/gtest/include/gtest/gtest.h"
26 #include "third_party/metrics_proto/chrome_user_metrics_extension.pb.h"
27
28 namespace metrics {
29 namespace {
30
31 class MetricsServiceObserverTest : public testing::Test {
32 public:
MetricsServiceObserverTest()33 MetricsServiceObserverTest()
34 : enabled_state_provider_(/*consent=*/true, /*enabled=*/true) {}
35 ~MetricsServiceObserverTest() override = default;
36
SetUp()37 void SetUp() override {
38 // The following call is needed for calling MetricsService::Start(), which
39 // sets up callbacks for user actions (which in turn verifies that a task
40 // runner is provided).
41 base::SetRecordActionTaskRunner(
42 task_environment_.GetMainThreadTaskRunner());
43 // The following call is needed for instantiating an instance of
44 // MetricsStateManager, which reads various prefs in its constructor.
45 MetricsService::RegisterPrefs(local_state_.registry());
46 }
47
GetMetricsStateManager()48 MetricsStateManager* GetMetricsStateManager() {
49 // Lazy-initialize |metrics_state_manager_| so that it correctly reads the
50 // stability state from prefs after tests have a chance to initialize it.
51 if (!metrics_state_manager_) {
52 metrics_state_manager_ = MetricsStateManager::Create(
53 local_state(), enabled_state_provider(),
54 /*backup_registry_key=*/std::wstring(),
55 /*user_data_dir=*/base::FilePath(), StartupVisibility::kUnknown);
56 metrics_state_manager_->InstantiateFieldTrialList();
57 }
58 return metrics_state_manager_.get();
59 }
60
enabled_state_provider()61 EnabledStateProvider* enabled_state_provider() {
62 return &enabled_state_provider_;
63 }
64
local_state()65 PrefService* local_state() { return &local_state_; }
66
67 protected:
68 base::test::TaskEnvironment task_environment_{
69 base::test::TaskEnvironment::TimeSource::MOCK_TIME};
70
71 private:
72 TestEnabledStateProvider enabled_state_provider_;
73 TestingPrefServiceSimple local_state_;
74 std::unique_ptr<MetricsStateManager> metrics_state_manager_;
75 };
76
77 class MetricsServiceObserverExportTest
78 : public MetricsServiceObserverTest,
79 public testing::WithParamInterface<bool> {
80 public:
81 MetricsServiceObserverExportTest() = default;
82 ~MetricsServiceObserverExportTest() override = default;
83
ShouldIncludeLogProtoData()84 bool ShouldIncludeLogProtoData() { return GetParam(); }
85 };
86
87 } // namespace
88
89 // Verifies that MetricsServiceObserver is notified when a log is created,
90 // staged, uploading, uploaded, and finally discarded.
TEST_F(MetricsServiceObserverTest,SuccessfulLogUpload)91 TEST_F(MetricsServiceObserverTest, SuccessfulLogUpload) {
92 TestMetricsServiceClient client;
93 MetricsService service(GetMetricsStateManager(), &client, local_state());
94
95 // Create a MetricsServiceObserver that will observe logs from |service|.
96 MetricsServiceObserver logs_observer(
97 MetricsServiceObserver::MetricsServiceType::UMA);
98 service.AddLogsObserver(&logs_observer);
99
100 // Start the metrics service.
101 service.InitializeMetricsRecordingState();
102 service.Start();
103
104 // Fast forward the time until the the first ongoing log is completed.
105 task_environment_.FastForwardBy(
106 base::Seconds(MetricsScheduler::GetInitialIntervalSeconds()));
107
108 // Verify that |logs_observer| is aware of the log.
109 std::vector<std::unique_ptr<MetricsServiceObserver::Log>>* observed_logs =
110 logs_observer.logs_for_testing();
111 ASSERT_EQ(observed_logs->size(), 1U);
112 MetricsServiceObserver::Log* log_info = observed_logs->front().get();
113
114 // Stage the log.
115 MetricsLogStore* test_log_store = service.LogStoreForTest();
116 test_log_store->StageNextLog();
117 ASSERT_TRUE(test_log_store->has_staged_log());
118
119 // Verify that |logs_observer| is aware that the log was staged.
120 ASSERT_EQ(log_info->events.size(), 2U);
121 EXPECT_EQ(log_info->events[0].event,
122 MetricsLogsEventManager::LogEvent::kLogCreated);
123 EXPECT_EQ(log_info->events[1].event,
124 MetricsLogsEventManager::LogEvent::kLogStaged);
125
126 // Fast forward the time to trigger the uploading of the log.
127 task_environment_.FastForwardBy(
128 MetricsUploadScheduler::GetUnsentLogsInterval());
129
130 // Verify that |logs_observer| observed the log being sent.
131 ASSERT_EQ(log_info->events.size(), 3U);
132 EXPECT_EQ(log_info->events[2].event,
133 MetricsLogsEventManager::LogEvent::kLogUploading);
134
135 // Simulate the upload being completed successfully.
136 client.uploader()->CompleteUpload(200);
137
138 // Verify that |logs_observer| observed the log being uploaded and then
139 // finally discarded.
140 ASSERT_EQ(log_info->events.size(), 5U);
141 EXPECT_EQ(log_info->events[3].event,
142 MetricsLogsEventManager::LogEvent::kLogUploaded);
143 EXPECT_EQ(log_info->events[4].event,
144 MetricsLogsEventManager::LogEvent::kLogDiscarded);
145
146 service.RemoveLogsObserver(&logs_observer);
147 }
148
149 // Verifies that MetricsServiceObserver is notified when 1) a log is re-staged
150 // to be re-transmitted after failing to be uploaded, and 2) a log is discarded
151 // after failing to be uploaded because of a bad request.
TEST_F(MetricsServiceObserverTest,UnsuccessfulLogUpload)152 TEST_F(MetricsServiceObserverTest, UnsuccessfulLogUpload) {
153 TestMetricsServiceClient client;
154 MetricsService service(GetMetricsStateManager(), &client, local_state());
155
156 // Create a MetricsServiceObserver that will observe logs from |service|.
157 MetricsServiceObserver logs_observer(
158 MetricsServiceObserver::MetricsServiceType::UMA);
159 service.AddLogsObserver(&logs_observer);
160
161 // Start the metrics service.
162 service.InitializeMetricsRecordingState();
163 service.Start();
164
165 // Fast forward the time until the the first ongoing log is completed.
166 task_environment_.FastForwardBy(
167 base::Seconds(MetricsScheduler::GetInitialIntervalSeconds()));
168
169 // Verify that |logs_observer| is aware of the log.
170 std::vector<std::unique_ptr<MetricsServiceObserver::Log>>* observed_logs =
171 logs_observer.logs_for_testing();
172 ASSERT_EQ(observed_logs->size(), 1U);
173 MetricsServiceObserver::Log* log_info = observed_logs->front().get();
174
175 // Stage the log, and verify that |logs_observer| observed this event.
176 MetricsLogStore* test_log_store = service.LogStoreForTest();
177 test_log_store->StageNextLog();
178 ASSERT_TRUE(test_log_store->has_staged_log());
179 ASSERT_EQ(log_info->events.size(), 2U);
180 EXPECT_EQ(log_info->events[0].event,
181 MetricsLogsEventManager::LogEvent::kLogCreated);
182 EXPECT_EQ(log_info->events[1].event,
183 MetricsLogsEventManager::LogEvent::kLogStaged);
184
185 // Fast forward the time to trigger the uploading of the log, and verify that
186 // |logs_observer| observed this event.
187 task_environment_.FastForwardBy(
188 MetricsUploadScheduler::GetUnsentLogsInterval());
189 EXPECT_EQ(log_info->events.size(), 3U);
190 EXPECT_EQ(log_info->events.back().event,
191 MetricsLogsEventManager::LogEvent::kLogUploading);
192
193 // Simulate the upload failing due to a timeout.
194 client.uploader()->CompleteUpload(408);
195
196 // Verify that |logs_observer| observed the log being re-staged for
197 // re-transmission.
198 EXPECT_EQ(log_info->events.size(), 4U);
199 EXPECT_EQ(log_info->events.back().event,
200 MetricsLogsEventManager::LogEvent::kLogStaged);
201
202 // Fast forward the time to trigger the re-upload of the log, and verify that
203 // |logs_observer| observed this event. Since the last upload failed, the time
204 // before the next upload is triggered is different (longer).
205 task_environment_.FastForwardBy(
206 MetricsUploadScheduler::GetInitialBackoffInterval());
207 EXPECT_EQ(log_info->events.size(), 5U);
208 EXPECT_EQ(log_info->events.back().event,
209 MetricsLogsEventManager::LogEvent::kLogUploading);
210
211 // Simulate the upload failing due to bad syntax.
212 client.uploader()->CompleteUpload(400);
213
214 // Verify that |logs_observer| observed the log being discarded because it was
215 // failed to be uploaded due to a bad request, and should not be
216 // re-transmitted.
217 EXPECT_EQ(log_info->events.size(), 6U);
218 EXPECT_EQ(log_info->events.back().event,
219 MetricsLogsEventManager::LogEvent::kLogDiscarded);
220
221 service.RemoveLogsObserver(&logs_observer);
222 }
223
224 // Verifies that MetricsServiceObserver is notified when a log that is too
225 // large gets trimmed.
TEST_F(MetricsServiceObserverTest,TrimLargeLog)226 TEST_F(MetricsServiceObserverTest, TrimLargeLog) {
227 TestMetricsServiceClient client;
228
229 // Set the max log size to be 1 byte so that pretty much all logs will be
230 // trimmed. We don't set it to 0 bytes because that is a special value that
231 // represents no max size.
232 client.set_max_ongoing_log_size_bytes(1);
233
234 MetricsService service(GetMetricsStateManager(), &client, local_state());
235
236 // Create a MetricsServiceObserver that will observe logs from |service|.
237 MetricsServiceObserver logs_observer(
238 MetricsServiceObserver::MetricsServiceType::UMA);
239 service.AddLogsObserver(&logs_observer);
240
241 // Initialize the metrics service.
242 service.InitializeMetricsRecordingState();
243
244 // Store some arbitrary log.
245 MetricsLogStore* test_log_store = service.LogStoreForTest();
246 LogMetadata metadata;
247 test_log_store->StoreLog(
248 /*log_data=*/".", MetricsLog::LogType::ONGOING_LOG, metadata,
249 MetricsLogsEventManager::CreateReason::kUnknown);
250
251 // Verify that |logs_observer| is aware of the log.
252 std::vector<std::unique_ptr<MetricsServiceObserver::Log>>* observed_logs =
253 logs_observer.logs_for_testing();
254 ASSERT_EQ(observed_logs->size(), 1U);
255 MetricsServiceObserver::Log* log_info = observed_logs->front().get();
256 ASSERT_EQ(log_info->events.size(), 1U);
257 EXPECT_EQ(log_info->events[0].event,
258 MetricsLogsEventManager::LogEvent::kLogCreated);
259
260 // Trim logs and verify that |logs_observer| is aware that the log was
261 // trimmed.
262 test_log_store->TrimAndPersistUnsentLogs(/*overwrite_in_memory_store=*/true);
263 ASSERT_EQ(log_info->events.size(), 2U);
264 EXPECT_EQ(log_info->events[1].event,
265 MetricsLogsEventManager::LogEvent::kLogTrimmed);
266
267 service.RemoveLogsObserver(&logs_observer);
268 }
269
270 // Verifies that MetricsServiceObserver is notified when logs are trimmed due to
271 // enough logs being stored.
TEST_F(MetricsServiceObserverTest,TrimLongLogList)272 TEST_F(MetricsServiceObserverTest, TrimLongLogList) {
273 TestMetricsServiceClient client;
274
275 // Set the minimum log count to 1 and minimum log size to 1 byte. This
276 // essentially means that the log store, when trimming logs, will only keep
277 // the most recent one. I.e., after storing one log, it will trim the rest
278 // due to having stored enough logs.
279 client.set_min_ongoing_log_queue_size_bytes(1);
280 client.set_min_ongoing_log_queue_count(1);
281
282 MetricsService service(GetMetricsStateManager(), &client, local_state());
283
284 // Create a MetricsServiceObserver that will observe logs from |service|.
285 MetricsServiceObserver logs_observer(
286 MetricsServiceObserver::MetricsServiceType::UMA);
287 service.AddLogsObserver(&logs_observer);
288
289 // Initialize the metrics service.
290 service.InitializeMetricsRecordingState();
291
292 // Store 3 arbitrary logs.
293 MetricsLogStore* test_log_store = service.LogStoreForTest();
294 LogMetadata metadata;
295 for (int i = 0; i < 3; i++) {
296 test_log_store->StoreLog(
297 /*log_data=*/base::NumberToString(i), MetricsLog::LogType::ONGOING_LOG,
298 metadata, MetricsLogsEventManager::CreateReason::kUnknown);
299 }
300
301 // Verify that |logs_observer| is aware of the 3 logs.
302 std::vector<std::unique_ptr<MetricsServiceObserver::Log>>* observed_logs =
303 logs_observer.logs_for_testing();
304 ASSERT_EQ(observed_logs->size(), 3U);
305
306 // Trim logs.
307 test_log_store->TrimAndPersistUnsentLogs(/*overwrite_in_memory_store=*/true);
308
309 // Verify that all logs except the last one (the most recent one) have been
310 // trimmed.
311 ASSERT_EQ(observed_logs->size(), 3U);
312 ASSERT_EQ(observed_logs->at(0)->events.size(), 2U);
313 EXPECT_EQ(observed_logs->at(0)->events[1].event,
314 MetricsLogsEventManager::LogEvent::kLogTrimmed);
315
316 ASSERT_EQ(observed_logs->at(1)->events.size(), 2U);
317 EXPECT_EQ(observed_logs->at(1)->events[1].event,
318 MetricsLogsEventManager::LogEvent::kLogTrimmed);
319
320 ASSERT_EQ(observed_logs->at(2)->events.size(), 1U);
321
322 service.RemoveLogsObserver(&logs_observer);
323 }
324
325 // Verifies that logs created through MetricsLogStore, which is used by UMA, are
326 // annotated with a type (ongoing, independent, or stability).
TEST_F(MetricsServiceObserverTest,UmaLogType)327 TEST_F(MetricsServiceObserverTest, UmaLogType) {
328 // Verify that logs created through MetricsLogStore::StoreLog() will be
329 // annotated with a type.
330 {
331 MetricsLogsEventManager logs_event_manager;
332 TestMetricsServiceClient client;
333 MetricsLogStore test_log_store(local_state(), client.GetStorageLimits(),
334 client.GetUploadSigningKey(),
335 &logs_event_manager);
336
337 // Create a MetricsServiceObserver that will observe UMA logs from
338 // |test_log_store|, which notifies through |logs_event_manager|.
339 MetricsServiceObserver logs_observer(
340 MetricsServiceObserver::MetricsServiceType::UMA);
341 logs_event_manager.AddObserver(&logs_observer);
342
343 // Load logs from persistent storage, which is needed to internally
344 // initialize |test_log_store|. There should be no logs loaded.
345 test_log_store.LoadPersistedUnsentLogs();
346 std::vector<std::unique_ptr<MetricsServiceObserver::Log>>* logs =
347 logs_observer.logs_for_testing();
348 EXPECT_EQ(logs->size(), 0U);
349
350 test_log_store.StoreLog("Ongoing Log", MetricsLog::LogType::ONGOING_LOG,
351 LogMetadata(),
352 MetricsLogsEventManager::CreateReason::kUnknown);
353 ASSERT_EQ(logs->size(), 1U);
354 ASSERT_TRUE(logs->back()->type.has_value());
355 EXPECT_EQ(logs->back()->type.value(), MetricsLog::LogType::ONGOING_LOG);
356 test_log_store.StoreLog("Independent Log",
357 MetricsLog::LogType::INDEPENDENT_LOG, LogMetadata(),
358 MetricsLogsEventManager::CreateReason::kUnknown);
359 ASSERT_EQ(logs->size(), 2U);
360 ASSERT_TRUE(logs->back()->type.has_value());
361 EXPECT_EQ(logs->back()->type.value(), MetricsLog::LogType::INDEPENDENT_LOG);
362 test_log_store.StoreLog(
363 "Stability Log", MetricsLog::LogType::INITIAL_STABILITY_LOG,
364 LogMetadata(), MetricsLogsEventManager::CreateReason::kUnknown);
365 ASSERT_EQ(logs->size(), 3U);
366 ASSERT_TRUE(logs->back()->type.has_value());
367 EXPECT_EQ(logs->back()->type.value(),
368 MetricsLog::LogType::INITIAL_STABILITY_LOG);
369
370 // Store logs in persistent storage, in preparation for the next assertions.
371 test_log_store.TrimAndPersistUnsentLogs(/*overwrite_in_memory_store=*/true);
372
373 logs_event_manager.RemoveObserver(&logs_observer);
374 }
375
376 // Verify that logs loaded from persistent storage are annotated with a type.
377 {
378 MetricsLogsEventManager logs_event_manager;
379 TestMetricsServiceClient client;
380 MetricsLogStore test_log_store(local_state(), client.GetStorageLimits(),
381 client.GetUploadSigningKey(),
382 &logs_event_manager);
383
384 // Create a MetricsServiceObserver that will observe UMA logs from
385 // |test_log_store|, which notifies through |logs_event_manager|.
386 MetricsServiceObserver logs_observer(
387 MetricsServiceObserver::MetricsServiceType::UMA);
388 logs_event_manager.AddObserver(&logs_observer);
389
390 // Load logs from persistent storage, which were created previously.
391 std::vector<std::unique_ptr<MetricsServiceObserver::Log>>* logs =
392 logs_observer.logs_for_testing();
393 EXPECT_EQ(logs->size(), 0U);
394 test_log_store.LoadPersistedUnsentLogs();
395
396 // Verify that logs were observed by |logs_observer|, and that they were
397 // annotated with a type. There should be 3 logs. Note that the order in
398 // which the logs are loaded (stability first, then ongoing) is hardcoded in
399 // MetricsLogStore. Further, the "independent" log should have become an
400 // "ongoing" log (due to limitations on how logs are stored in persistent
401 // storage).
402 ASSERT_EQ(logs->size(), 3U);
403 ASSERT_TRUE(logs->at(0)->type.has_value());
404 EXPECT_EQ(logs->at(0)->type.value(),
405 MetricsLog::LogType::INITIAL_STABILITY_LOG);
406 ASSERT_TRUE(logs->at(1)->type.has_value());
407 EXPECT_EQ(logs->at(1)->type.value(), MetricsLog::LogType::ONGOING_LOG);
408 ASSERT_TRUE(logs->at(2)->type.has_value());
409 EXPECT_EQ(logs->at(2)->type.value(), MetricsLog::LogType::ONGOING_LOG);
410
411 logs_event_manager.RemoveObserver(&logs_observer);
412 }
413
414 // Verify that when loading logs from persistent storage after setting an
415 // "alternate ongoing log store", the logs are annotated with a type.
416 {
417 MetricsLogsEventManager logs_event_manager;
418 TestMetricsServiceClient client;
419 MetricsLogStore::StorageLimits storage_limits = client.GetStorageLimits();
420 MetricsLogStore test_log_store(local_state(), storage_limits,
421 client.GetUploadSigningKey(),
422 &logs_event_manager);
423
424 // Load logs from persistent storage, which is needed to internally
425 // initialize |test_log_store|. There should be 3 logs loaded (however, we
426 // do not care about them).
427 test_log_store.LoadPersistedUnsentLogs();
428
429 // Create a MetricsServiceObserver that will observe UMA logs from
430 // |test_log_store|, which notifies through |logs_event_manager|.
431 MetricsServiceObserver logs_observer(
432 MetricsServiceObserver::MetricsServiceType::UMA);
433 logs_event_manager.AddObserver(&logs_observer);
434
435 // Verify that |logs_observer| is not aware of any logs (since we started
436 // observing *after* logs from persistent storage were loaded).
437 std::vector<std::unique_ptr<MetricsServiceObserver::Log>>* logs =
438 logs_observer.logs_for_testing();
439 EXPECT_EQ(logs->size(), 0U);
440
441 // Create an UnsentLogStore, which will be used as the "alternate ongoing
442 // log store". This log store will read from the same persistent storage as
443 // a "normal" ongoing log queue.
444 auto alternate_ongoing_log_store = std::make_unique<UnsentLogStore>(
445 std::make_unique<UnsentLogStoreMetricsImpl>(), local_state(),
446 prefs::kMetricsOngoingLogs, prefs::kMetricsOngoingLogsMetadata,
447 storage_limits.ongoing_log_queue_limits, client.GetUploadSigningKey(),
448 // |logs_event_manager| will be set by |test_log_store| directly in
449 // MetricsLogStore::SetAlternateOngoingLogStore().
450 /*logs_event_manager=*/nullptr);
451
452 // Set the alternate ongoing log store of |test_log_store|. This should load
453 // logs from persistent storage.
454 test_log_store.SetAlternateOngoingLogStore(
455 std::move(alternate_ongoing_log_store));
456
457 // Verify that logs were observed by |logs_observer|, and that they were
458 // annotated with a type. There should be 2 logs. The "independent" log
459 // should have become an "ongoing" log (due to limitations on how logs are
460 // stored in persistent storage).
461 ASSERT_EQ(logs->size(), 2U);
462 ASSERT_TRUE(logs->at(0)->type.has_value());
463 EXPECT_EQ(logs->at(0)->type.value(), MetricsLog::LogType::ONGOING_LOG);
464 ASSERT_TRUE(logs->at(1)->type.has_value());
465 EXPECT_EQ(logs->at(1)->type.value(), MetricsLog::LogType::ONGOING_LOG);
466
467 logs_event_manager.RemoveObserver(&logs_observer);
468 }
469 }
470
471 INSTANTIATE_TEST_SUITE_P(MetricsServiceObserverExportTests,
472 MetricsServiceObserverExportTest,
473 testing::Bool());
474
475 // Verifies that MetricsServiceObserver::ExportLogsAsJson() returns a valid
476 // JSON string that represents the logs that the observer is aware of.
477 // This test is parameterized (bool parameter). When the parameter is true,
478 // we should include log proto data when exporting. When false, log proto data
479 // should not be included.
TEST_P(MetricsServiceObserverExportTest,ExportLogsAsJson)480 TEST_P(MetricsServiceObserverExportTest, ExportLogsAsJson) {
481 TestMetricsServiceClient client;
482 MetricsService service(GetMetricsStateManager(), &client, local_state());
483
484 // Create a MetricsServiceObserver that will observe logs from |service|.
485 MetricsServiceObserver logs_observer(
486 MetricsServiceObserver::MetricsServiceType::UMA);
487 service.AddLogsObserver(&logs_observer);
488
489 // Start the metrics service.
490 service.InitializeMetricsRecordingState();
491 service.Start();
492
493 // Fast forward the time until the the first ongoing log is completed.
494 task_environment_.FastForwardBy(
495 base::Seconds(MetricsScheduler::GetInitialIntervalSeconds()));
496
497 // Stage the log.
498 MetricsLogStore* test_log_store = service.LogStoreForTest();
499 test_log_store->StageNextLog();
500 ASSERT_TRUE(test_log_store->has_staged_log());
501
502 // Fast forward the time to trigger the uploading of the log.
503 task_environment_.FastForwardBy(
504 MetricsUploadScheduler::GetUnsentLogsInterval());
505
506 // Export logs as a JSON string.
507 std::string json;
508 bool include_log_proto_data = ShouldIncludeLogProtoData();
509 ASSERT_TRUE(logs_observer.ExportLogsAsJson(include_log_proto_data, &json));
510
511 // Parse the JSON string and convert it to a base::Value.
512 JSONStringValueDeserializer deserializer(json);
513 std::unique_ptr<base::Value> logs_value = deserializer.Deserialize(
514 /*error_code=*/nullptr, /*error_message=*/nullptr);
515 ASSERT_TRUE(logs_value);
516
517 // Verify that the base::Value created from the JSON reflects what we expect:
518 // |logs_observer| should be aware of a single log, which has been staged and
519 // is being uploaded.
520 ASSERT_TRUE(logs_value->is_dict());
521 base::Value::Dict& logs_dict = logs_value->GetDict();
522
523 base::Value* log_type = logs_dict.Find("logType");
524 ASSERT_TRUE(log_type);
525 ASSERT_TRUE(log_type->is_string());
526 EXPECT_EQ(log_type->GetString(), "UMA");
527
528 base::Value* logs_list_value = logs_dict.Find("logs");
529 ASSERT_TRUE(logs_list_value);
530 ASSERT_TRUE(logs_list_value->is_list());
531 base::Value::List& logs_list = logs_list_value->GetList();
532 ASSERT_EQ(logs_list.size(), 1U);
533
534 base::Value& log_value = logs_list.front();
535 ASSERT_TRUE(log_value.is_dict());
536 base::Value::Dict& log_dict = log_value.GetDict();
537
538 base::Value* uma_log_type = log_dict.Find("type");
539 ASSERT_TRUE(uma_log_type);
540 ASSERT_TRUE(uma_log_type->is_string());
541 EXPECT_EQ(uma_log_type->GetString(), "Ongoing");
542
543 base::Value* log_hash = log_dict.Find("hash");
544 ASSERT_TRUE(log_hash);
545 ASSERT_TRUE(log_hash->is_string());
546 EXPECT_FALSE(log_hash->GetString().empty());
547
548 base::Value* log_timestamp = log_dict.Find("timestamp");
549 ASSERT_TRUE(log_timestamp);
550 ASSERT_TRUE(log_timestamp->is_string());
551 EXPECT_FALSE(log_timestamp->GetString().empty());
552
553 base::Value* log_data = log_dict.Find("data");
554 if (include_log_proto_data) {
555 ASSERT_TRUE(log_data);
556 ASSERT_TRUE(log_data->is_string());
557 EXPECT_FALSE(log_data->GetString().empty());
558
559 // Verify that the proto data can be parsed.
560 std::string gzipped_log_data;
561 ASSERT_TRUE(base::Base64Decode(log_data->GetString(), &gzipped_log_data));
562 ChromeUserMetricsExtension uma_proto;
563 ASSERT_TRUE(DecodeLogDataToProto(gzipped_log_data, &uma_proto));
564 EXPECT_TRUE(uma_proto.has_client_id());
565 EXPECT_TRUE(uma_proto.has_session_id());
566 EXPECT_TRUE(uma_proto.has_system_profile());
567 } else {
568 EXPECT_FALSE(log_data);
569 }
570
571 base::Value* log_size = log_dict.Find("size");
572 ASSERT_TRUE(log_size);
573 ASSERT_TRUE(log_size->is_int());
574
575 base::Value* log_events = log_dict.Find("events");
576 ASSERT_TRUE(log_events);
577 ASSERT_TRUE(log_events->is_list());
578 base::Value::List& log_events_list = log_events->GetList();
579 ASSERT_EQ(log_events_list.size(), 3U);
580
581 base::Value& first_log_event = log_events_list[0];
582 ASSERT_TRUE(first_log_event.is_dict());
583 base::Value::Dict& first_log_event_dict = first_log_event.GetDict();
584 base::Value* first_log_event_string = first_log_event_dict.Find("event");
585 ASSERT_TRUE(first_log_event_string);
586 ASSERT_TRUE(first_log_event_string->is_string());
587 EXPECT_EQ(first_log_event_string->GetString(), "Created");
588 base::Value* first_log_event_timestamp =
589 first_log_event_dict.Find("timestampMs");
590 ASSERT_TRUE(first_log_event_timestamp);
591 ASSERT_TRUE(first_log_event_timestamp->is_double());
592
593 base::Value& second_log_event = log_events_list[1];
594 ASSERT_TRUE(second_log_event.is_dict());
595 base::Value::Dict& second_log_event_dict = second_log_event.GetDict();
596 base::Value* second_log_event_string = second_log_event_dict.Find("event");
597 ASSERT_TRUE(second_log_event_string);
598 ASSERT_TRUE(second_log_event_string->is_string());
599 EXPECT_EQ(second_log_event_string->GetString(), "Staged");
600 base::Value* second_log_event_timestamp =
601 second_log_event_dict.Find("timestampMs");
602 ASSERT_TRUE(second_log_event_timestamp);
603 ASSERT_TRUE(second_log_event_timestamp->is_double());
604
605 base::Value& third_log_event = log_events_list[2];
606 ASSERT_TRUE(third_log_event.is_dict());
607 base::Value::Dict& third_log_event_dict = third_log_event.GetDict();
608 base::Value* third_log_event_string = third_log_event_dict.Find("event");
609 ASSERT_TRUE(third_log_event_string);
610 ASSERT_TRUE(third_log_event_string->is_string());
611 EXPECT_EQ(third_log_event_string->GetString(), "Uploading");
612 base::Value* third_log_event_timestamp =
613 third_log_event_dict.Find("timestampMs");
614 ASSERT_TRUE(third_log_event_timestamp);
615 ASSERT_TRUE(third_log_event_timestamp->is_double());
616
617 service.RemoveLogsObserver(&logs_observer);
618 }
619
620 // Verifies that callbacks registered to a MetricsServiceObserver instance are
621 // run every time it is notified.
TEST_F(MetricsServiceObserverTest,NotifiedCallbacks)622 TEST_F(MetricsServiceObserverTest, NotifiedCallbacks) {
623 // Create a MetricsServiceObserver.
624 MetricsServiceObserver logs_observer(
625 MetricsServiceObserver::MetricsServiceType::UMA);
626
627 int num_callback_executed = 0;
628
629 {
630 // Add a callback to |logs_observer| that increments |num_callback_executed|
631 // every time it is run.
632 base::CallbackListSubscription callback_subscription =
633 logs_observer.AddNotifiedCallback(base::BindLambdaForTesting(
634 [&num_callback_executed]() { num_callback_executed++; }));
635 EXPECT_EQ(num_callback_executed, 0);
636
637 // Verify that OnLogCreated() triggers the callback.
638 const std::string kLogHash = "test";
639 logs_observer.OnLogCreated(kLogHash, /*log_data=*/"", /*log_timestamp=*/"",
640 MetricsLogsEventManager::CreateReason::kUnknown);
641 EXPECT_EQ(num_callback_executed, 1);
642
643 // Verify that OnLogEvent() triggers the callback.
644 logs_observer.OnLogEvent(MetricsLogsEventManager::LogEvent::kLogStaged,
645 kLogHash, /*message=*/"");
646 EXPECT_EQ(num_callback_executed, 2);
647 }
648
649 // Verify that after the callback list subscription |callback_subscription| is
650 // destroyed, it is automatically de-registered from |logs_observer|.
651 const std::string kLogHash2 = "test2";
652 num_callback_executed = 0;
653 logs_observer.OnLogCreated(kLogHash2, /*log_data=*/"", /*log_timestamp=*/"",
654 MetricsLogsEventManager::CreateReason::kUnknown);
655 logs_observer.OnLogEvent(MetricsLogsEventManager::LogEvent::kLogStaged,
656 kLogHash2, /*message=*/"");
657 EXPECT_EQ(num_callback_executed, 0);
658 }
659
660 } // namespace metrics
661