src/logger/logger.cc

// 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/logger.h"

#include <memory>
#include <string>

#include "src/logger/event_loggers.h"
#include "src/logger/event_record.h"
#include "src/public/lib/statusor/status_macros.h"
#include "src/registry/metric_definition.pb.h"
#include "src/registry/report_definition.pb.h"

namespace cobalt::logger {

using LoggerMethod = LoggerCallsMadeMigratedMetricDimensionLoggerMethod;

namespace {
template <class EventType>
void CopyEventCodesAndComponent(const std::vector<uint32_t>& event_codes,
                                const std::string& component, EventType* event) {
  for (auto event_code : event_codes) {
    event->add_event_code(event_code);
  }
  event->set_component(component);
}

template <class EventType>
void CopyEventCodes(const std::vector<uint32_t>& event_codes, EventType* event) {
  for (auto event_code : event_codes) {
    event->add_event_code(event_code);
  }
}

}  // namespace

Logger::Logger(std::unique_ptr<ProjectContext> project_context,
               local_aggregation::LocalAggregation& local_aggregation,
               ObservationWriter& observation_writer, system_data::SystemDataInterface& system_data,
               util::CivilTimeConverterInterface& civil_time_converter,
               std::vector<uint32_t> experiment_ids, InternalMetrics* internal_metrics)
    : Logger(std::move(project_context), local_aggregation, observation_writer, system_data,
             nullptr, civil_time_converter, std::weak_ptr<UndatedEventManager>(),
             std::move(experiment_ids), internal_metrics) {}

Logger::Logger(std::unique_ptr<ProjectContext> project_context,
               local_aggregation::LocalAggregation& local_aggregation,
               ObservationWriter& observation_writer, system_data::SystemDataInterface& system_data,
               util::ValidatedClockInterface* validated_clock,
               util::CivilTimeConverterInterface& civil_time_converter,
               std::weak_ptr<UndatedEventManager> undated_event_manager,
               std::vector<uint32_t> experiment_ids, InternalMetrics* internal_metrics)
    : project_context_(std::move(project_context)),
      local_aggregation_(local_aggregation),
      observation_writer_(observation_writer),
      system_data_(system_data),
      validated_clock_(validated_clock),
      civil_time_converter_(civil_time_converter),
      undated_event_manager_(std::move(undated_event_manager)),
      experiment_ids_(std::move(experiment_ids)),
      internal_metrics_(internal_metrics) {
  CHECK(project_context_);
  if (!validated_clock_) {
    local_validated_clock_ =
        std::make_unique<util::AlwaysAccurateClock>(std::make_unique<util::SystemClock>());
    validated_clock_ = local_validated_clock_.get();
  }
  // If we were passed an internal Logger then we are not an internal Logger.
  is_internal_logger_ = !internal_metrics;
}

// TODO(fxbug.dev/85571): NOLINTNEXTLINE(bugprone-easily-swappable-parameters)
Status Logger::LogOccurrence(uint32_t metric_id, uint64_t count,
                             const std::vector<uint32_t>& event_codes) {
  InternalMetrics::InternalMetricsFlusher flusher = internal_metrics_.Flusher();
  internal_metrics_.LoggerCalled(LoggerMethod::LogOccurrence, project_context_->project());
  CB_ASSIGN_OR_RETURN(auto event_record, EventRecord::MakeEventRecord(project_context_, metric_id));
  OccurrenceEvent* occurrence_event = event_record->event()->mutable_occurrence_event();
  CopyEventCodes(event_codes, occurrence_event);
  occurrence_event->set_count(count);
  return Log(metric_id, MetricDefinition::OCCURRENCE, std::move(event_record));
}

// TODO(fxbug.dev/85571): NOLINTNEXTLINE(bugprone-easily-swappable-parameters)
Status Logger::LogInteger(uint32_t metric_id, int64_t value,
                          const std::vector<uint32_t>& event_codes) {
  InternalMetrics::InternalMetricsFlusher flusher = internal_metrics_.Flusher();
  internal_metrics_.LoggerCalled(LoggerMethod::LogInteger, project_context_->project());
  CB_ASSIGN_OR_RETURN(auto event_record, EventRecord::MakeEventRecord(project_context_, metric_id));
  IntegerEvent* integer_event = event_record->event()->mutable_integer_event();
  CopyEventCodes(event_codes, integer_event);
  integer_event->set_value(value);
  return Log(metric_id, MetricDefinition::INTEGER, std::move(event_record));
}

Status Logger::LogIntegerHistogram(uint32_t metric_id, HistogramPtr histogram,
                                   const std::vector<uint32_t>& event_codes) {
  InternalMetrics::InternalMetricsFlusher flusher = internal_metrics_.Flusher();
  internal_metrics_.LoggerCalled(LoggerMethod::LogIntegerHistogram, project_context_->project());
  CB_ASSIGN_OR_RETURN(auto event_record, EventRecord::MakeEventRecord(project_context_, metric_id));
  IntegerHistogramEvent* integer_histogram_event =
      event_record->event()->mutable_integer_histogram_event();
  CopyEventCodes(event_codes, integer_histogram_event);
  integer_histogram_event->mutable_buckets()->Swap(histogram.get());
  return Log(metric_id, MetricDefinition::INTEGER_HISTOGRAM, std::move(event_record));
}

Status Logger::LogString(uint32_t metric_id, const std::string& string_value,
                         const std::vector<uint32_t>& event_codes) {
  InternalMetrics::InternalMetricsFlusher flusher = internal_metrics_.Flusher();
  internal_metrics_.LoggerCalled(LoggerMethod::LogString, project_context_->project());
  CB_ASSIGN_OR_RETURN(auto event_record, EventRecord::MakeEventRecord(project_context_, metric_id));
  StringEvent* string_event = event_record->event()->mutable_string_event();
  CopyEventCodes(event_codes, string_event);
  string_event->set_string_value(string_value);
  return Log(metric_id, MetricDefinition::STRING, std::move(event_record));
}

Status Logger::Log(uint32_t metric_id, MetricDefinition::MetricType metric_type,
                   std::unique_ptr<EventRecord> event_record) {
  // For Cobalt 1.1 Local Aggregation, the SystemProfile must be included with the event.
  if (metric_type == MetricDefinition::OCCURRENCE || metric_type == MetricDefinition::INTEGER ||
      metric_type == MetricDefinition::INTEGER_HISTOGRAM ||
      metric_type == MetricDefinition::STRING) {
    // Get the current unfiltered global system profile to log with this event.
    event_record->system_profile()->CopyFrom(system_data_.system_profile());

    // Add any non-global system profile data to the event's system profile.
    for (const uint32_t& id : experiment_ids_) {
      event_record->system_profile()->add_experiment_ids(id);
    }
  }

  const int kVerboseLoggingLevel = (is_internal_logger_ ? 9 : 7);
  VLOG(kVerboseLoggingLevel) << "Received logged event for " << event_record->FullMetricName();
  auto event_logger = internal::EventLogger::Create(
      metric_type, local_aggregation_, observation_writer_, system_data_, civil_time_converter_);
  Status validation_result =
      event_logger->PrepareAndValidateEvent(metric_id, metric_type, event_record.get());
  if (!validation_result.ok()) {
    return validation_result;
  }

  auto now = validated_clock_->now();
  if (!now) {
    VLOG(kVerboseLoggingLevel)
        << "Buffering logged event because we don't yet have an accurate clock. ";
    // Missing system time means that the clock is not valid, so save the event until it is.
    auto undated_event_manager = undated_event_manager_.lock();
    if (undated_event_manager) {
      return undated_event_manager->Save(std::move(event_record));
    }
    // A missing UndatedEventManager is handled by retrying the clock, which should now be valid.

    // If we fall through to here, then a race condition has occurred in which the clock that we
    // thought was not validated, has become validated. Retrying the clock should succeed.
    now = validated_clock_->now();
    if (!now) {
      // This should never happen, if it does then it's a bug.
      return util::StatusBuilder(
                 StatusCode::FAILED_PRECONDITION,
                 "Clock is invalid but there is no UndatedEventManager that will save the "
                 "event, dropping event for metric: ")
          .AppendMsg(metric_id)
          .LogError()
          .Build();
    }
  }

  Status result = event_logger->Log(std::move(event_record), *now);

  return result;
}

void Logger::PauseInternalLogging() { internal_metrics_.PauseLogging(); }
void Logger::ResumeInternalLogging() { internal_metrics_.ResumeLogging(); }

}  // namespace cobalt::logger