| // 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/event_loggers.h" |
| |
| #include <memory> |
| #include <string> |
| |
| #include <google/protobuf/repeated_field.h> |
| |
| #include "src/lib/util/datetime_util.h" |
| #include "src/lib/util/status_builder.h" |
| #include "src/logger/event_record.h" |
| #include "src/pb/event.pb.h" |
| #include "src/pb/observation.pb.h" |
| #include "src/public/lib/status.h" |
| #include "src/public/lib/statusor/status_macros.h" |
| #include "src/registry/metric_definition.pb.h" |
| #include "src/registry/report_definition.pb.h" |
| #include "src/tracing.h" |
| |
| namespace cobalt::logger::internal { |
| |
| using ::google::protobuf::RepeatedField; |
| |
| constexpr char TRACE_PREFIX[] = "[COBALT_EVENT_TRACE] "; |
| |
| std::unique_ptr<EventLogger> EventLogger::Create( |
| MetricDefinition::MetricType metric_type, |
| local_aggregation::LocalAggregation& local_aggregation, |
| const ObservationWriter& observation_writer, |
| const system_data::SystemDataInterface& system_data, |
| util::CivilTimeConverterInterface& civil_time_converter) { |
| switch (metric_type) { |
| case MetricDefinition::OCCURRENCE: { |
| return std::make_unique<internal::OccurrenceEventLogger>( |
| local_aggregation, observation_writer, system_data, civil_time_converter); |
| } |
| case MetricDefinition::INTEGER: { |
| return std::make_unique<internal::IntegerEventLogger>(local_aggregation, observation_writer, |
| system_data, civil_time_converter); |
| } |
| case MetricDefinition::INTEGER_HISTOGRAM: { |
| return std::make_unique<internal::IntegerHistogramEventLogger>( |
| local_aggregation, observation_writer, system_data, civil_time_converter); |
| } |
| case MetricDefinition::STRING: { |
| return std::make_unique<internal::StringEventLogger>(local_aggregation, observation_writer, |
| system_data, civil_time_converter); |
| } |
| default: { |
| LOG(ERROR) << "Failed to process a metric type of " << metric_type; |
| return nullptr; |
| } |
| } |
| } |
| |
| std::string EventLogger::TraceEvent(const EventRecord& event_record) { |
| if (!event_record.metric()->meta_data().also_log_locally()) { |
| return ""; |
| } |
| |
| Event* event = event_record.event(); |
| |
| std::stringstream ss; |
| ss << "Day index: " << event->day_index() << std::endl; |
| if (event->has_occurrence_event()) { |
| const OccurrenceEvent& e = event->occurrence_event(); |
| ss << "OccurrenceEvent:" << std::endl; |
| ss << "EventCodes:"; |
| for (uint32_t code : e.event_code()) { |
| ss << " " << code; |
| } |
| ss << ", Count: " << e.count() << std::endl; |
| } else if (event->has_integer_event()) { |
| const IntegerEvent& e = event->integer_event(); |
| ss << "IntegerEvent:" << std::endl; |
| ss << "EventCodes:"; |
| for (uint32_t code : e.event_code()) { |
| ss << " " << code; |
| } |
| ss << ", Value: " << e.value() << std::endl; |
| } else if (event->has_integer_histogram_event()) { |
| const IntegerHistogramEvent& e = event->integer_histogram_event(); |
| ss << "IntegerHistogramEvent:" << std::endl; |
| ss << "EventCodes:"; |
| for (uint32_t code : e.event_code()) { |
| ss << " " << code; |
| } |
| for (const HistogramBucket& bucket : e.buckets()) { |
| ss << "| " << bucket.index() << " = " << bucket.count() << std::endl; |
| } |
| } else if (event->has_string_event()) { |
| const StringEvent& e = event->string_event(); |
| ss << "StringEvent:" << std::endl; |
| ss << "EventCodes:"; |
| for (uint32_t code : e.event_code()) { |
| ss << " " << code; |
| } |
| ss << ", String: " << e.string_value() << std::endl; |
| } |
| |
| return ss.str(); |
| } |
| |
| void EventLogger::TraceLogFailure(const Status& status, const EventRecord& event_record, |
| const std::string& trace, const ReportDefinition& report) { |
| if (!event_record.metric()->meta_data().also_log_locally()) { |
| return; |
| } |
| |
| LOG(INFO) << TRACE_PREFIX << "(" |
| << event_record.project_context()->RefMetric(event_record.metric()).FullyQualifiedName() |
| << "): Error (" << status << ")" << std::endl |
| << trace << "While trying to send report: " << report.report_name() << std::endl; |
| } |
| |
| void EventLogger::TraceLogSuccess(const EventRecord& event_record, const std::string& trace) { |
| if (!event_record.metric()->meta_data().also_log_locally()) { |
| return; |
| } |
| |
| LOG(INFO) << TRACE_PREFIX << "(" |
| << event_record.project_context()->RefMetric(event_record.metric()).FullyQualifiedName() |
| << "):" << std::endl |
| << trace; |
| } |
| |
| Status EventLogger::Log(std::unique_ptr<EventRecord> event_record, |
| const std::chrono::system_clock::time_point& event_timestamp) { |
| TRACE_DURATION("cobalt_core", "EventLogger::Log", "metric_id", event_record->metric()->id()); |
| |
| CB_RETURN_IF_ERROR(FinalizeEvent(event_record.get(), event_timestamp)); |
| |
| if (system_data_.release_stage() > event_record->metric()->meta_data().max_release_stage()) { |
| // Quietly ignore this metric. |
| LOG_FIRST_N(INFO, 10) << "Not logging metric `" |
| << event_record->project_context()->FullMetricName( |
| *event_record->metric()) |
| << "` because its max_release_stage (" |
| << event_record->metric()->meta_data().max_release_stage() |
| << ") is lower than the device's current release_stage: " |
| << system_data_.release_stage(); |
| return Status::OkStatus(); |
| } |
| |
| if (event_record->metric()->reports_size() == 0) { |
| VLOG(1) << "Warning: An event was logged for a metric with no reports " |
| "defined: " |
| << event_record->project_context()->FullMetricName(*event_record->metric()); |
| } |
| |
| // Store the trace before attempting to log the event. This way, if parts of |
| // the event are moved out of the object, the resulting trace will still have |
| // useful information. |
| auto trace = TraceEvent(*event_record); |
| |
| Status status = local_aggregation().AddEvent(*event_record, event_timestamp); |
| if (!status.ok()) { |
| TraceLogFailure(status, *event_record, trace, event_record->metric()->reports(0)); |
| return status; |
| } |
| TraceLogSuccess(*event_record, trace); |
| return Status::OkStatus(); |
| } |
| |
| Status EventLogger::PrepareAndValidateEvent(uint32_t metric_id, |
| MetricDefinition::MetricType expected_type, |
| EventRecord* event_record) { |
| if (event_record->metric() == nullptr) { |
| return util::StatusBuilder(StatusCode::INVALID_ARGUMENT, "Metric with ID `") |
| .AppendMsg(metric_id) |
| .AppendMsg("` was not found in the project.") |
| .WithContexts(*event_record) |
| .LogError() |
| .Build(); |
| } |
| if (event_record->metric()->metric_type() != expected_type) { |
| return util::StatusBuilder(StatusCode::INVALID_ARGUMENT, "Metric is of incorrect type") |
| .WithContexts(*event_record) |
| .WithContext("expected_type", expected_type) |
| .WithContext("found_type", event_record->metric()->metric_type()) |
| .LogError() |
| .Build(); |
| } |
| return ValidateEvent(*event_record); |
| } |
| |
| Status EventLogger::FinalizeEvent(EventRecord* event_record, |
| const std::chrono::system_clock::time_point& event_timestamp) { |
| // Compute the day_index and hour ID in the appropriate time zone for the metric's TimeZonePolicy. |
| CB_ASSIGN_OR_RETURN(util::TimeInfo event_time, |
| util::TimeInfo::FromTimePoint(event_timestamp, civil_time_converter_, |
| *event_record->metric())); |
| event_record->event()->set_day_index(event_time.day_index); |
| event_record->event()->set_hour_id(event_time.hour_id); |
| return Status::OkStatus(); |
| } |
| |
| Status EventLogger::ValidateEvent(const EventRecord& /*event_record*/) { |
| return Status::OkStatus(); |
| } |
| |
| Status EventLogger::ValidateEventCodes(const MetricDefinition& metric, |
| const RepeatedField<uint32_t>& event_codes, |
| const std::string& full_metric_name) { |
| // When new dimensions are added to a metric, they can only be appended, not deleted or inserted. |
| // Because of this, and because metric definitions may change before the matching code does, we |
| // want to accept events where fewer than the expected number of event_codes have been provided. |
| if (event_codes.size() > metric.metric_dimensions_size()) { |
| return util::StatusBuilder( |
| StatusCode::INVALID_ARGUMENT, |
| "The number of event codes given is more than the number of metric dimensions") |
| .WithContext("event_codes.size()", event_codes.size()) |
| .WithContext("metric_dimensions", metric.metric_dimensions_size()) |
| .WithContext("Metric", full_metric_name) |
| .LogError() |
| .Build(); |
| } |
| for (int i = 0; i < event_codes.size(); i++) { |
| const auto& dim = metric.metric_dimensions(i); |
| auto code = event_codes.Get(i); |
| |
| // This verifies the two possible validation modes for a metric_dimension. |
| // |
| // 1. If it has a max_event_code, then all we do is verify that the supplied |
| // code is <= that value |
| // |
| // 2. If no max_event_code is specified, we verify that the supplied code |
| // maps to one of the values in the event_code map. |
| if (dim.max_event_code() > 0) { |
| if (code > dim.max_event_code()) { |
| return util::StatusBuilder( |
| StatusCode::INVALID_ARGUMENT, |
| "The given event_code exceeds the max_event_code for that dimension") |
| .WithContext("Dimension", i) |
| .WithContext("given event_code", code) |
| .WithContext("max_event_code", dim.max_event_code()) |
| .WithContext("Metric", full_metric_name) |
| .LogError() |
| .Build(); |
| } |
| } else { |
| bool valid = false; |
| for (const auto& event_code : dim.event_codes()) { |
| if (event_code.first == code) { |
| valid = true; |
| break; |
| } |
| } |
| |
| if (!valid) { |
| return util::StatusBuilder(StatusCode::INVALID_ARGUMENT) |
| .AppendMsg( |
| "The given event_code is not a valid event code for that dimension. You " |
| "must either define this event code in the metric_dimension, or set the " |
| "max_event_code >= ") |
| .AppendMsg(code) |
| .WithContext("Dimension", i) |
| .WithContext("given event_code", code) |
| .WithContext("max_event_code", dim.max_event_code()) |
| .WithContext("Metric", full_metric_name) |
| .LogError() |
| .Build(); |
| } |
| } |
| } |
| return Status::OkStatus(); |
| } |
| |
| ///////////// OccurrenceEventLogger method implementations ////////////////////////// |
| |
| Status OccurrenceEventLogger::ValidateEvent(const EventRecord& event_record) { |
| if (!event_record.event()->has_occurrence_event()) { |
| return util::StatusBuilder(StatusCode::INVALID_ARGUMENT, |
| "The provided event is invalid, expected it to contain an event " |
| "type of OccurredEvent") |
| .WithContexts(event_record, event_record.event()->type_case()) |
| .LogError() |
| .Build(); |
| } |
| if (event_record.metric() == nullptr) { |
| return util::StatusBuilder(StatusCode::INVALID_ARGUMENT, |
| "The provided event is missing a metric") |
| .LogError() |
| .Build(); |
| } |
| const MetricDefinition& metric = *(event_record.metric()); |
| return ValidateEventCodes(metric, event_record.event()->occurrence_event().event_code(), |
| event_record.project_context()->FullMetricName(metric)); |
| } |
| |
| ///////////// IntegerEventLogger method implementations ////////////////////////// |
| |
| Status IntegerEventLogger::ValidateEvent(const EventRecord& event_record) { |
| if (!event_record.event()->has_integer_event()) { |
| return util::StatusBuilder(StatusCode::INVALID_ARGUMENT, |
| "The provided event is invalid, expected it to contain an event " |
| "type of IntegerEvent") |
| .WithContexts(event_record.event()->type_case(), event_record) |
| .LogError() |
| .Build(); |
| } |
| if (event_record.metric() == nullptr) { |
| return util::StatusBuilder(StatusCode::INVALID_ARGUMENT, |
| "The provided event is missing a metric") |
| .LogError() |
| .Build(); |
| } |
| const MetricDefinition& metric = *(event_record.metric()); |
| return ValidateEventCodes(metric, event_record.event()->integer_event().event_code(), |
| event_record.project_context()->FullMetricName(metric)); |
| } |
| |
| ///////////// IntegerHistogramEventLogger method implementations ////////////////////////// |
| |
| Status IntegerHistogramEventLogger::ValidateEvent(const EventRecord& event_record) { |
| if (!event_record.event()->has_integer_histogram_event()) { |
| return util::StatusBuilder( |
| StatusCode::INVALID_ARGUMENT, |
| "The provided event is invalid, expected it to contain an event type of " |
| "IntegerHistogramEvent") |
| .WithContexts(event_record.event()->type_case(), event_record) |
| .LogError() |
| .Build(); |
| } |
| const IntegerHistogramEvent& integer_histogram_event = |
| event_record.event()->integer_histogram_event(); |
| if (event_record.metric() == nullptr) { |
| return util::StatusBuilder(StatusCode::INVALID_ARGUMENT, |
| "The provided event is missing a metric") |
| .LogError() |
| .Build(); |
| } |
| const MetricDefinition& metric = *(event_record.metric()); |
| |
| auto status = ValidateEventCodes(metric, integer_histogram_event.event_code(), |
| event_record.project_context()->FullMetricName(metric)); |
| if (!status.ok()) { |
| return status; |
| } |
| |
| if (!metric.has_int_buckets()) { |
| return util::StatusBuilder( |
| StatusCode::FAILED_PRECONDITION, |
| "Invalid Cobalt config: Metric does not have an |int_buckets| field set.") |
| .WithContext("Metric", event_record.project_context()->FullMetricName(metric)) |
| .LogError() |
| .Build(); |
| } |
| const IntegerBuckets& int_buckets = metric.int_buckets(); |
| uint32_t num_valid_buckets; |
| switch (int_buckets.buckets_case()) { |
| case IntegerBuckets::kExponential: |
| num_valid_buckets = int_buckets.exponential().num_buckets(); |
| break; |
| case IntegerBuckets::kLinear: |
| num_valid_buckets = int_buckets.linear().num_buckets(); |
| break; |
| case IntegerBuckets::BUCKETS_NOT_SET: { |
| return util::StatusBuilder( |
| StatusCode::FAILED_PRECONDITION, |
| "Invalid Cobalt config: Metric has an invalid |int_buckets| field. Either " |
| "exponential or linear buckets must be specified.") |
| .WithContext("Metric", event_record.project_context()->FullMetricName(metric)) |
| .LogError() |
| .Build(); |
| } |
| } |
| |
| // In addition to the specified num_buckets, there are the underflow and |
| // overflow buckets. |
| num_valid_buckets += 2; |
| |
| int num_provided_buckets = integer_histogram_event.buckets_size(); |
| for (int i = 0; i < num_provided_buckets; ++i) { |
| if (integer_histogram_event.buckets(i).index() >= num_valid_buckets) { |
| return util::StatusBuilder(StatusCode::INVALID_ARGUMENT, |
| "The provided histogram is invalid. The index value is out of " |
| "bounds for the Metric") |
| .WithContext("Metric", event_record.project_context()->FullMetricName(metric)) |
| .WithContext("index_value", integer_histogram_event.buckets(i).index()) |
| .WithContext("position", i) |
| .LogError() |
| .Build(); |
| } |
| } |
| |
| return Status::OkStatus(); |
| } |
| |
| ///////////// StringEventLogger method implementations ////////////////////////// |
| |
| Status StringEventLogger::ValidateEvent(const EventRecord& event_record) { |
| if (!event_record.event()->has_string_event()) { |
| return util::StatusBuilder( |
| StatusCode::INVALID_ARGUMENT, |
| "The provided event is invalid, expected it to contain an event type of StringEvent") |
| .WithContexts(event_record.event()->type_case(), event_record) |
| .LogError() |
| .Build(); |
| } |
| if (event_record.metric() == nullptr) { |
| return util::StatusBuilder(StatusCode::INVALID_ARGUMENT, |
| "The provided event is missing a metric") |
| .LogError() |
| .Build(); |
| } |
| const MetricDefinition& metric = *(event_record.metric()); |
| return ValidateEventCodes(metric, event_record.event()->string_event().event_code(), |
| event_record.project_context()->FullMetricName(metric)); |
| } |
| |
| } // namespace cobalt::logger::internal |
