blob: c945acbfd475e52145908256f29808b352a45926 [file] [log] [blame]
// Copyright 2018 The Fuchsia Authors. All rights reserved.
// Use of this source code is governed by a BSD-style license that can be
// found in the LICENSE file.
#include "src/logger/undated_event_manager.h"
#include <memory>
#include <string>
#include <google/protobuf/text_format.h>
#include <google/protobuf/util/message_differencer.h>
#include <gtest/gtest.h>
#include "src/lib/util/clock.h"
#include "src/lib/util/encrypted_message_util.h"
#include "src/lib/util/testing/test_with_files.h"
#include "src/local_aggregation/testing/test_local_aggregation.h"
#include "src/logger/fake_logger.h"
#include "src/logger/internal_metrics.h"
#include "src/logger/internal_metrics_config.cb.h"
#include "src/logger/logger_interface.h"
#include "src/logger/logger_test_utils.h"
#include "src/logger/project_context.h"
#include "src/pb/metadata_builder.h"
#include "src/pb/observation.pb.h"
#include "src/system_data/client_secret.h"
#include "src/system_data/fake_system_data.h"
// Generated from all_reports_test_registry.yaml
// Namespace: cobalt::logger::testing::all_report_types
#include "src/logger/test_registries/all_report_types_test_registry.cb.h"
namespace cobalt::logger {
using local_aggregation::TestLocalAggregation;
using testing::FakeObservationStore;
using testing::GetTestProject;
using testing::GetTestProjectContextFactory;
using testing::TestUpdateRecipient;
using util::EncryptedMessageMaker;
using util::IncrementingSteadyClock;
using util::IncrementingSystemClock;
namespace {
std::tm kSystemTime = {
.tm_sec = 30,
.tm_min = 20,
.tm_hour = 10,
.tm_mday = 2, // 2nd
.tm_mon = 7, // August
.tm_year = 119, // 2019
};
const auto kSystemTimePoint = std::chrono::system_clock::from_time_t(std::mktime(&kSystemTime));
// Use a smaller max saved size for testing.
constexpr size_t kMaxSavedEvents = 10;
} // namespace
class UndatedEventManagerTest : public util::testing::TestWithFiles {
protected:
void SetUp() override {
MakeTestFolder();
mock_system_clock_ =
std::make_unique<IncrementingSystemClock>(std::chrono::system_clock::duration(0));
mock_system_clock_->set_time(kSystemTimePoint);
mock_steady_clock_ = new IncrementingSteadyClock();
validated_clock_ = std::make_unique<util::FakeValidatedClock>(mock_system_clock_.get());
validated_clock_->SetAccurate(true);
civil_time_converter_ = std::make_unique<util::UtcTimeConverter>();
observation_store_ = std::make_unique<FakeObservationStore>();
update_recipient_ = std::make_unique<TestUpdateRecipient>();
observation_encrypter_ = EncryptedMessageMaker::MakeUnencrypted().Unwrap();
observation_writer_ = std::make_unique<ObservationWriter>(
*observation_store_, update_recipient_.get(), observation_encrypter_.get());
metadata_builder_ = std::make_unique<MetadataBuilder>(system_data_, validated_clock_.get(),
system_data_cache_path(), fs());
metadata_builder_->SnapshotSystemData();
CobaltConfig cfg = {.client_secret = system_data::ClientSecret::GenerateNewSecret()};
cfg.local_aggregation_backfill_days = 0;
cfg.local_aggregate_store_dir = local_aggregation_store_path();
project_context_factory_ =
GetTestProjectContextFactory(testing::all_report_types::kCobaltRegistryBase64);
local_aggregation_ = std::make_unique<TestLocalAggregation>(
cfg, *project_context_factory_, system_data_, *metadata_builder_, fs(),
*observation_writer_, *civil_time_converter_);
internal_logger_ = std::make_unique<testing::FakeLogger>();
internal_metrics_ =
logger::InternalMetrics::NewWithLogger(internal_logger_.get(), nullptr).Unwrap();
undated_event_manager_ = std::make_unique<UndatedEventManager>(
*local_aggregation_, *observation_writer_, system_data_, *civil_time_converter_,
kMaxSavedEvents);
undated_event_manager_->SetSteadyClock(mock_steady_clock_);
}
void TearDown() override { undated_event_manager_.reset(); }
std::unique_ptr<UndatedEventManager> undated_event_manager_;
std::unique_ptr<testing::FakeLogger> internal_logger_;
std::unique_ptr<logger::InternalMetrics> internal_metrics_;
std::unique_ptr<ObservationWriter> observation_writer_;
std::unique_ptr<TestUpdateRecipient> update_recipient_;
std::unique_ptr<IncrementingSystemClock> mock_system_clock_;
IncrementingSteadyClock* mock_steady_clock_;
std::unique_ptr<util::FakeValidatedClock> validated_clock_;
std::unique_ptr<TestLocalAggregation> local_aggregation_;
private:
std::unique_ptr<FakeObservationStore> observation_store_;
std::unique_ptr<util::UtcTimeConverter> civil_time_converter_;
std::unique_ptr<MetadataBuilder> metadata_builder_;
std::unique_ptr<ProjectContextFactory> project_context_factory_;
std::unique_ptr<EncryptedMessageMaker> observation_encrypter_;
system_data::FakeSystemData system_data_;
};
// Test that the UndatedEventManager can outlive the source of the ProjectContext.
TEST_F(UndatedEventManagerTest, DeletedProjectContext) {
std::shared_ptr<ProjectContext> project_context =
GetTestProject(testing::all_report_types::kCobaltRegistryBase64);
// Create an event and save it.
auto event_record = EventRecord::MakeEventRecord(
project_context, testing::all_report_types::kNewReadCacheHitsMetricId)
.value();
event_record->event()->mutable_occurrence_event()->add_event_code(42);
ASSERT_NE(nullptr, event_record->metric());
// Drop the ProjectContext. If no one else has retained a copy, it will be deleted.
project_context.reset();
ASSERT_EQ(StatusCode::OK, undated_event_manager_->Save(std::move(event_record)).error_code());
// Check that no immediate Observations were generated.
ASSERT_EQ(0, local_aggregation_->num_events_added());
EXPECT_EQ(1, undated_event_manager_->NumSavedEvents());
// Flush the saved events, this will generate immediate observations.
ASSERT_EQ(StatusCode::OK,
undated_event_manager_->Flush(mock_system_clock_.get(), internal_metrics_.get())
.error_code());
EXPECT_EQ(0, undated_event_manager_->NumSavedEvents());
// Now there should be an observation.
ASSERT_EQ(1, local_aggregation_->num_events_added());
// Monotonic clock was not advanced, so the day index is the current one.
ASSERT_EQ(kSystemTimePoint, local_aggregation_->last_timestamp());
// One internal metric call for the number of cached events.
EXPECT_EQ(1, internal_logger_->call_count());
EXPECT_EQ(internal_logger_->last_event_logged().metric_id(),
kInaccurateClockEventsCachedMigratedMetricId);
}
TEST_F(UndatedEventManagerTest, OneImmediatelyFlushedEvent) {
std::shared_ptr<ProjectContext> project_context =
GetTestProject(testing::all_report_types::kCobaltRegistryBase64);
// Create an event and save it.
auto event_record = EventRecord::MakeEventRecord(
project_context, testing::all_report_types::kNewReadCacheHitsMetricId)
.value();
event_record->event()->mutable_occurrence_event()->add_event_code(42);
ASSERT_NE(nullptr, event_record->metric());
ASSERT_EQ(StatusCode::OK, undated_event_manager_->Save(std::move(event_record)).error_code());
// Check that no events were added.
EXPECT_EQ(0, local_aggregation_->num_events_added());
EXPECT_EQ(1, undated_event_manager_->NumSavedEvents());
// Flush the saved events, this will generate immediate observations.
ASSERT_EQ(StatusCode::OK,
undated_event_manager_->Flush(mock_system_clock_.get(), internal_metrics_.get())
.error_code());
EXPECT_EQ(0, undated_event_manager_->NumSavedEvents());
// Now there should be an observation.
ASSERT_EQ(1, local_aggregation_->num_events_added());
// Monotonic clock was not advanced, so the day index is the current one.
ASSERT_EQ(kSystemTimePoint, local_aggregation_->last_timestamp());
// One internal metric call for the number of cached events.
EXPECT_EQ(1, internal_logger_->call_count());
EXPECT_EQ(internal_logger_->last_event_logged().metric_id(),
kInaccurateClockEventsCachedMigratedMetricId);
}
TEST_F(UndatedEventManagerTest, OneDayDelayInSystemClockAccuracy) {
std::shared_ptr<ProjectContext> project_context =
GetTestProject(testing::all_report_types::kCobaltRegistryBase64);
// Create an event and save it.
auto event_record = EventRecord::MakeEventRecord(
project_context, testing::all_report_types::kNewReadCacheHitsMetricId)
.value();
event_record->event()->mutable_occurrence_event()->add_event_code(42);
ASSERT_NE(nullptr, event_record->metric());
ASSERT_EQ(StatusCode::OK, undated_event_manager_->Save(std::move(event_record)).error_code());
// Check that no immediate Observations were generated.
EXPECT_EQ(0, local_aggregation_->num_events_added());
EXPECT_EQ(1, undated_event_manager_->NumSavedEvents());
// One day later, the clock is finally accurate, flush the saved events, this will generate
// observations.
mock_steady_clock_->increment_by(std::chrono::hours(24));
ASSERT_EQ(StatusCode::OK,
undated_event_manager_->Flush(mock_system_clock_.get(), internal_metrics_.get())
.error_code());
EXPECT_EQ(0, undated_event_manager_->NumSavedEvents());
// Now there should be an observation.
ASSERT_EQ(1, local_aggregation_->num_events_added());
// Day index is from the previous day, due to the monotonic time advancing one day.
ASSERT_EQ(kSystemTimePoint - std::chrono::hours(24), local_aggregation_->last_timestamp());
// One internal metric call for the number of cached events.
EXPECT_EQ(1, internal_logger_->call_count());
EXPECT_EQ(internal_logger_->last_event_logged().metric_id(),
kInaccurateClockEventsCachedMigratedMetricId);
}
TEST_F(UndatedEventManagerTest, TooManyEventsToStore) {
std::shared_ptr<ProjectContext> project_context =
GetTestProject(testing::all_report_types::kCobaltRegistryBase64);
// Create some events and save them. These will be dropped
auto event_record =
EventRecord::MakeEventRecord(project_context, testing::all_report_types::kDeviceBootsMetricId)
.value();
event_record->event()->mutable_occurrence_event()->add_event_code(1);
ASSERT_NE(nullptr, event_record->metric());
ASSERT_EQ(StatusCode::OK, undated_event_manager_->Save(std::move(event_record)).error_code());
event_record = EventRecord::MakeEventRecord(project_context,
testing::all_report_types::kNewReadCacheHitsMetricId)
.value();
event_record->event()->mutable_occurrence_event()->add_event_code(99);
ASSERT_NE(nullptr, event_record->metric());
ASSERT_EQ(StatusCode::OK, undated_event_manager_->Save(std::move(event_record)).error_code());
event_record = EventRecord::MakeEventRecord(project_context,
testing::all_report_types::kFeaturesActiveMetricId)
.value();
event_record->event()->mutable_occurrence_event()->add_event_code(98);
ASSERT_NE(nullptr, event_record->metric());
ASSERT_EQ(StatusCode::OK, undated_event_manager_->Save(std::move(event_record)).error_code());
event_record = EventRecord::MakeEventRecord(project_context,
testing::all_report_types::kNewReadCacheHitsMetricId)
.value();
event_record->event()->mutable_occurrence_event()->add_event_code(97);
ASSERT_NE(nullptr, event_record->metric());
ASSERT_EQ(StatusCode::OK, undated_event_manager_->Save(std::move(event_record)).error_code());
// Save events beyond the max size of the cache. Only 10 events should fit in memory.
// Each event is on a different day.
for (int i = kMaxSavedEvents; i > 0; i--) {
mock_steady_clock_->increment_by(std::chrono::hours(24));
event_record = EventRecord::MakeEventRecord(
project_context, testing::all_report_types::kNewReadCacheHitsMetricId)
.value();
event_record->event()->mutable_occurrence_event()->add_event_code(i);
ASSERT_NE(nullptr, event_record->metric());
ASSERT_EQ(StatusCode::OK, undated_event_manager_->Save(std::move(event_record)).error_code());
}
// Check that no immediate Observations were generated and only the max were saved.
ASSERT_EQ(0, local_aggregation_->num_events_added());
EXPECT_EQ(kMaxSavedEvents, undated_event_manager_->NumSavedEvents());
// Flush the saved events, this will generate immediate observations.
ASSERT_EQ(StatusCode::OK,
undated_event_manager_->Flush(mock_system_clock_.get(), internal_metrics_.get())
.error_code());
EXPECT_EQ(0, undated_event_manager_->NumSavedEvents());
// Now there should be the maximum cache size of observation.
ASSERT_EQ(kMaxSavedEvents, local_aggregation_->num_events_added());
// Day index starts from 9 days ago and ends at today.
std::chrono::system_clock::time_point start_time =
kSystemTimePoint - std::chrono::hours(24 * (kMaxSavedEvents - 1));
for (int i = 0; i < kMaxSavedEvents; i++) {
EXPECT_EQ(testing::all_report_types::kNewReadCacheHitsMetricId,
local_aggregation_->metric_id(i));
EXPECT_EQ(start_time + std::chrono::hours(24 * i), local_aggregation_->timestamp(i));
}
// Two internal metric calls for the number of cached and dropped events.
EXPECT_EQ(2, internal_logger_->call_count());
EXPECT_EQ(internal_logger_->last_event_logged().metric_id(),
kInaccurateClockEventsDroppedMigratedMetricId);
}
TEST_F(UndatedEventManagerTest, SaveAfterFlush) {
std::shared_ptr<ProjectContext> project_context =
GetTestProject(testing::all_report_types::kCobaltRegistryBase64);
// Flush the empty manager, this will not generate any observations.
ASSERT_EQ(StatusCode::OK,
undated_event_manager_->Flush(mock_system_clock_.get(), internal_metrics_.get())
.error_code());
EXPECT_EQ(0, local_aggregation_->num_events_added());
EXPECT_EQ(0, undated_event_manager_->NumSavedEvents());
// Create an event and try to save it.
auto event_record = EventRecord::MakeEventRecord(
project_context, testing::all_report_types::kNewReadCacheHitsMetricId)
.value();
event_record->event()->mutable_occurrence_event()->add_event_code(42);
ASSERT_NE(nullptr, event_record->metric());
// One day later, the clock is finally accurate, try to save an event, this will generate
// observations. (This scenario is not very likely, as the clock should report accurate around
// the same time as the flush, but this allows us to verify the steady clock time being after
// the flush time results in a correct date setting.)
mock_steady_clock_->increment_by(std::chrono::hours(24));
ASSERT_EQ(StatusCode::OK, undated_event_manager_->Save(std::move(event_record)).error_code());
EXPECT_EQ(0, undated_event_manager_->NumSavedEvents());
// Now there should be an observation.
ASSERT_EQ(1, local_aggregation_->num_events_added());
// Day index is from the previous day, due to the monotonic time advancing one day.
ASSERT_EQ(kSystemTimePoint + std::chrono::hours(24), local_aggregation_->last_timestamp());
// No internal metric calls for the number of cached events.
EXPECT_EQ(0, internal_logger_->call_count());
}
} // namespace cobalt::logger