Swift: rename log package to logging

swift/logging/BUILD.bazel

@@ -0,0 +1,11 @@
+cc_library(
+    name = "logging",
+    srcs = glob(["*.cpp"]),
+    hdrs = glob(["*.h"]),
+    visibility = ["//visibility:public"],
+    deps = [
+        "@absl//absl/strings",
+        "@binlog",
+        "@json",
+    ],
+)

swift/logging/SwiftAssert.h

@@ -0,0 +1,29 @@
+#pragma once
+
+#include <cstdlib>
+
+#include "swift/logging/SwiftLogging.h"
+
+// assert CONDITION, which is always evaluated (once) regardless of the build type. If
+// CONDITION is not satisfied, emit a critical log optionally using provided format and arguments,
+// abort the program
+#define CODEQL_ASSERT(CONDITION, ...) \
+  CODEQL_ASSERT_IMPL(CRITICAL, std::abort(), CONDITION, __VA_ARGS__)
+
+// If CONDITION is not satisfied, emit an error log optionally using provided format and arguments,
+// but continue execution
+#define CODEQL_EXPECT(CONDITION, ...) CODEQL_EXPECT_OR(void(), CONDITION, __VA_ARGS__)
+
+// If CONDITION is not satisfied, emit an error log optionally using provided format and arguments,
+// and execute ACTION (for example return)
+#define CODEQL_EXPECT_OR(ACTION, CONDITION, ...) \
+  CODEQL_ASSERT_IMPL(ERROR, ACTION, CONDITION, __VA_ARGS__)
+
+#define CODEQL_ASSERT_IMPL(LEVEL, ACTION, CONDITION, ...)                           \
+  do {                                                                              \
+    if (!(CONDITION)) {                                                             \
+      [[unlikely]] LOG_##LEVEL("assertion failed on " #CONDITION ". " __VA_ARGS__); \
+      codeql::Log::flush();                                                         \
+      ACTION;                                                                       \
+    }                                                                               \
+  } while (false)

swift/logging/SwiftDiagnostics.cpp

@@ -0,0 +1,55 @@
+#include "swift/logging/SwiftDiagnostics.h"
+
+#include <binlog/Entries.hpp>
+#include <nlohmann/json.hpp>
+#include "absl/strings/str_join.h"
+#include "absl/strings/str_cat.h"
+#include "absl/strings/str_split.h"
+
+namespace codeql {
+void SwiftDiagnosticsSource::emit(std::ostream& out,
+                                  std::string_view timestamp,
+                                  std::string_view message) const {
+  nlohmann::json entry = {
+      {"source",
+       {
+           {"id", sourceId()},
+           {"name", name},
+           {"extractorName", extractorName},
+       }},
+      {"visibility",
+       {
+           {"statusPage", true},
+           {"cliSummaryTable", true},
+           {"telemetry", true},
+       }},
+      {"severity", "error"},
+      {"helpLinks", std::vector<std::string_view>(absl::StrSplit(helpLinks, ' '))},
+      {"plaintextMessage", absl::StrCat(message, ".\n\n", action, ".")},
+      {"timestamp", timestamp},
+  };
+  out << entry << '\n';
+}
+
+std::string SwiftDiagnosticsSource::sourceId() const {
+  auto ret = absl::StrJoin({extractorName, programName, id}, "/");
+  std::replace(ret.begin(), ret.end(), '_', '-');
+  return ret;
+}
+
+void SwiftDiagnosticsDumper::write(const char* buffer, std::size_t bufferSize) {
+  binlog::Range range{buffer, bufferSize};
+  binlog::RangeEntryStream input{range};
+  while (auto event = events.nextEvent(input)) {
+    const auto& source = SwiftDiagnosticsSource::get(event->source->category);
+    std::ostringstream oss;
+    timestampedMessagePrinter.printEvent(oss, *event, events.writerProp(), events.clockSync());
+    // TODO(C++20) use oss.view() directly
+    auto data = oss.str();
+    std::string_view view = data;
+    using ViewPair = std::pair<std::string_view, std::string_view>;
+    auto [timestamp, message] = ViewPair(absl::StrSplit(view, absl::MaxSplits(' ', 1)));
+    source.emit(output, timestamp, message);
+  }
+}
+}  // namespace codeql

swift/logging/SwiftDiagnostics.h

@@ -0,0 +1,87 @@
+#pragma once
+
+#include <binlog/EventStream.hpp>
+#include <binlog/PrettyPrinter.hpp>
+#include <string>
+#include <vector>
+#include <unordered_map>
+#include <cassert>
+#include <fstream>
+#include <filesystem>
+#include <sstream>
+#include <mutex>
+
+namespace codeql {
+
+extern const std::string_view programName;
+
+// Models a diagnostic source for Swift, holding static information that goes out into a diagnostic
+// These are internally stored into a map on id's. A specific error log can use binlog's category
+// as id, which will then be used to recover the diagnostic source while dumping.
+struct SwiftDiagnosticsSource {
+  std::string_view id;
+  std::string_view name;
+  static constexpr std::string_view extractorName = "swift";
+  std::string_view action;
+  std::string_view helpLinks;  // space separated if more than 1. Not a vector to allow constexpr
+
+  // for the moment, we only output errors, so no need to store the severity
+
+  // registers a diagnostics source for later retrieval with get, if not done yet
+  template <const SwiftDiagnosticsSource* Spec>
+  static void inscribe() {
+    static std::once_flag once;
+    std::call_once(once, [] {
+      auto [it, inserted] = map().emplace(Spec->id, Spec);
+      assert(inserted);
+    });
+  }
+
+  // gets a previously inscribed SwiftDiagnosticsSource for the given id. Will abort if none exists
+  static const SwiftDiagnosticsSource& get(const std::string& id) { return *map().at(id); }
+
+  // emit a JSON diagnostics for this source with the given timestamp and message to out
+  // A plaintextMessage is used that includes both the message and the action to take. Dots are
+  // appended to both. The id is used to construct the source id in the form
+  // `swift/<prog name>/<id with '-' replacing '_'>`
+  void emit(std::ostream& out, std::string_view timestamp, std::string_view message) const;
+
+ private:
+  std::string sourceId() const;
+  using Map = std::unordered_map<std::string, const SwiftDiagnosticsSource*>;
+
+  static Map& map() {
+    static Map ret;
+    return ret;
+  }
+};
+
+// An output modeling binlog's output stream concept that intercepts binlog entries and translates
+// them to appropriate diagnostics JSON entries
+class SwiftDiagnosticsDumper {
+ public:
+  // opens path for writing out JSON entries. Returns whether the operation was successful.
+  bool open(const std::filesystem::path& path) {
+    output.open(path);
+    return output.good();
+  }
+
+  // write out binlog entries as corresponding JSON diagnostics entries. Expects all entries to have
+  // a category equal to an id of a previously created SwiftDiagnosticSource.
+  void write(const char* buffer, std::size_t bufferSize);
+
+ private:
+  binlog::EventStream events;
+  std::ofstream output;
+  binlog::PrettyPrinter timestampedMessagePrinter{"%u %m", "%Y-%m-%dT%H:%M:%S.%NZ"};
+};
+
+}  // namespace codeql
+
+namespace codeql_diagnostics {
+constexpr codeql::SwiftDiagnosticsSource internal_error{
+    "internal_error",
+    "Internal error",
+    "Contact us about this issue",
+};
+}  // namespace codeql_diagnostics

swift/logging/SwiftLogging.cpp

@@ -0,0 +1,191 @@
+#include "swift/logging/SwiftLogging.h"
+
+#include <filesystem>
+#include <stdlib.h>
+#include <optional>
+
+#define LEVEL_REGEX_PATTERN "trace|debug|info|warning|error|critical|no_logs"
+
+BINLOG_ADAPT_ENUM(codeql::Log::Level, trace, debug, info, warning, error, critical, no_logs)
+
+namespace codeql {
+
+namespace {
+using LevelRule = std::pair<std::regex, Log::Level>;
+using LevelRules = std::vector<LevelRule>;
+
+Log::Level getLevelFor(std::string_view name, const LevelRules& rules, Log::Level dflt) {
+  for (auto it = rules.rbegin(); it != rules.rend(); ++it) {
+    if (std::regex_match(std::begin(name), std::end(name), it->first)) {
+      return it->second;
+    }
+  }
+  return dflt;
+}
+
+const char* getEnvOr(const char* var, const char* dflt) {
+  if (const char* ret = getenv(var)) {
+    return ret;
+  }
+  return dflt;
+}
+
+std::string_view matchToView(std::csub_match m) {
+  return {m.first, static_cast<size_t>(m.length())};
+}
+
+Log::Level stringToLevel(std::string_view v) {
+  if (v == "trace") return Log::Level::trace;
+  if (v == "debug") return Log::Level::debug;
+  if (v == "info") return Log::Level::info;
+  if (v == "warning") return Log::Level::warning;
+  if (v == "error") return Log::Level::error;
+  if (v == "critical") return Log::Level::critical;
+  return Log::Level::no_logs;
+}
+
+Log::Level matchToLevel(std::csub_match m) {
+  return stringToLevel(matchToView(m));
+}
+
+}  // namespace
+
+std::vector<std::string> Log::collectLevelRulesAndReturnProblems(const char* envVar) {
+  std::vector<std::string> problems;
+  if (auto levels = getEnvOr(envVar, nullptr)) {
+    // expect comma-separated <glob pattern>:<log severity>
+    std::regex comma{","};
+    std::regex levelAssignment{R"((?:([*./\w]+)|(?:out:(bin|text|console))):()" LEVEL_REGEX_PATTERN
+                               ")"};
+    std::cregex_token_iterator begin{levels, levels + strlen(levels), comma, -1};
+    std::cregex_token_iterator end{};
+    for (auto it = begin; it != end; ++it) {
+      std::cmatch match;
+      if (std::regex_match(it->first, it->second, match, levelAssignment)) {
+        auto level = matchToLevel(match[3]);
+        if (match[1].matched) {
+          auto pattern = match[1].str();
+          // replace all "*" with ".*" and all "." with "\.", turning the glob pattern into a regex
+          std::string::size_type pos = 0;
+          while ((pos = pattern.find_first_of("*.", pos)) != std::string::npos) {
+            pattern.insert(pos, (pattern[pos] == '*') ? "." : "\\");
+            pos += 2;
+          }
+          sourceRules.emplace_back(pattern, level);
+        } else {
+          auto out = matchToView(match[2]);
+          if (out == "bin") {
+            binary.level = level;
+          } else if (out == "text") {
+            text.level = level;
+          } else if (out == "console") {
+            console.level = level;
+          }
+        }
+      } else {
+        problems.emplace_back("Malformed log level rule: " + it->str());
+      }
+    }
+  }
+  return problems;
+}
+
+void Log::configure() {
+  // as we are configuring logging right now, we collect problems and log them at the end
+  auto problems = collectLevelRulesAndReturnProblems("CODEQL_EXTRACTOR_SWIFT_LOG_LEVELS");
+  auto now = std::to_string(std::chrono::system_clock::now().time_since_epoch().count());
+  if (text || binary) {
+    std::filesystem::path logFile = getEnvOr("CODEQL_EXTRACTOR_SWIFT_LOG_DIR", "extractor-out/log");
+    logFile /= "swift";
+    logFile /= programName;
+    logFile /= now;
+    std::error_code ec;
+    std::filesystem::create_directories(logFile.parent_path(), ec);
+    if (!ec) {
+      if (text) {
+        logFile.replace_extension(".log");
+        textFile.open(logFile);
+        if (!textFile) {
+          problems.emplace_back("Unable to open text log file " + logFile.string());
+          text.level = Level::no_logs;
+        }
+      }
+      if (binary) {
+        logFile.replace_extension(".blog");
+        binary.output.open(logFile, std::fstream::out | std::fstream::binary);
+        if (!binary.output) {
+          problems.emplace_back("Unable to open binary log file " + logFile.string());
+          binary.level = Level::no_logs;
+        }
+      }
+    } else {
+      problems.emplace_back("Unable to create log directory " + logFile.parent_path().string() +
+                            ": " + ec.message());
+      binary.level = Level::no_logs;
+      text.level = Level::no_logs;
+    }
+    if (diagnostics) {
+      std::filesystem::path diagFile =
+          getEnvOr("CODEQL_EXTRACTOR_SWIFT_DIAGNOSTIC_DIR", "extractor-out/diagnostics");
+      diagFile /= programName;
+      diagFile /= now;
+      diagFile.replace_extension(".jsonl");
+      std::error_code ec;
+      std::filesystem::create_directories(diagFile.parent_path(), ec);
+      if (!ec) {
+        if (!diagnostics.output.open(diagFile)) {
+          problems.emplace_back("Unable to open diagnostics json file " + diagFile.string());
+          diagnostics.level = Level::no_logs;
+        }
+      } else {
+        problems.emplace_back("Unable to create diagnostics directory " +
+                              diagFile.parent_path().string() + ": " + ec.message());
+        diagnostics.level = Level::no_logs;
+      }
+    }
+  }
+  for (const auto& problem : problems) {
+    LOG_ERROR("{}", problem);
+  }
+  LOG_INFO("Logging configured (binary: {}, text: {}, console: {})", binary.level, text.level,
+           console.level);
+  flushImpl();
+}
+
+void Log::flushImpl() {
+  session.consume(*this);
+  if (text) {
+    textFile.flush();
+  }
+  if (binary) {
+    binary.output.flush();
+  }
+}
+
+Log::LoggerConfiguration Log::getLoggerConfigurationImpl(std::string_view name) {
+  LoggerConfiguration ret{session, std::string{programName}};
+  ret.fullyQualifiedName += '/';
+  ret.fullyQualifiedName += name;
+  ret.level = std::min({binary.level, text.level, console.level});
+  ret.level = getLevelFor(ret.fullyQualifiedName, sourceRules, ret.level);
+  // avoid Logger constructor loop
+  if (name != "logging") {
+    LOG_DEBUG("Configuring logger {} with level {}", ret.fullyQualifiedName, ret.level);
+  }
+  return ret;
+}
+
+Log& Log::write(const char* buffer, std::streamsize size) {
+  if (text) text.write(buffer, size);
+  if (binary) binary.write(buffer, size);
+  if (console) console.write(buffer, size);
+  if (diagnostics) diagnostics.write(buffer, size);
+  return *this;
+}
+
+Logger& Log::logger() {
+  static Logger ret{getLoggerConfigurationImpl("logging")};
+  return ret;
+}
+
+}  // namespace codeql

swift/logging/SwiftLogging.h

@@ -0,0 +1,223 @@
+#pragma once
+
+#include <fstream>
+#include <iostream>
+#include <regex>
+#include <vector>
+
+#include <binlog/binlog.hpp>
+#include <binlog/TextOutputStream.hpp>
+#include <binlog/EventFilter.hpp>
+#include <binlog/adapt_stdfilesystem.hpp>
+#include <binlog/adapt_stderrorcode.hpp>
+#include <binlog/adapt_stdoptional.hpp>
+#include <binlog/adapt_stdvariant.hpp>
+
+#include "swift/logging/SwiftDiagnostics.h"
+
+// Logging macros. These will call `logger()` to get a Logger instance, picking up any `logger`
+// defined in the current scope. Domain-specific loggers can be added or used by either:
+// * providing a class field called `logger` (as `Logger::operator()()` returns itself)
+// * declaring a local `logger` variable (to be used for one-time execution like code in `main`)
+// * declaring a `Logger& logger()` function returning a reference to a static local variable
+// * passing a logger around using a `Logger& logger` function parameter
+// They are created with a name that appears in the logs and can be used to filter debug levels (see
+// `Logger`).
+#define LOG_CRITICAL(...) LOG_WITH_LEVEL(critical, __VA_ARGS__)
+#define LOG_ERROR(...) LOG_WITH_LEVEL(error, __VA_ARGS__)
+#define LOG_WARNING(...) LOG_WITH_LEVEL(warning, __VA_ARGS__)
+#define LOG_INFO(...) LOG_WITH_LEVEL(info, __VA_ARGS__)
+#define LOG_DEBUG(...) LOG_WITH_LEVEL(debug, __VA_ARGS__)
+#define LOG_TRACE(...) LOG_WITH_LEVEL(trace, __VA_ARGS__)
+
+// only do the actual logging if the picked up `Logger` instance is configured to handle the
+// provided log level. `LEVEL` must be a compile-time constant. `logger()` is evaluated once
+#define LOG_WITH_LEVEL_AND_CATEGORY(LEVEL, CATEGORY, ...)                                    \
+  do {                                                                                       \
+    constexpr codeql::Log::Level _level = codeql::Log::Level::LEVEL;                         \
+    codeql::Logger& _logger = logger();                                                      \
+    if (_level >= _logger.level()) {                                                         \
+      BINLOG_CREATE_SOURCE_AND_EVENT(_logger.writer(), _level, CATEGORY, binlog::clockNow(), \
+                                     __VA_ARGS__);                                           \
+    }                                                                                        \
+  } while (false)
+
+#define LOG_WITH_LEVEL(LEVEL, ...) LOG_WITH_LEVEL_AND_CATEGORY(LEVEL, , __VA_ARGS__)
+
+// Emit errors with a specified diagnostics ID. This must be the name of a `SwiftDiagnosticsSource`
+// defined in the `codeql_diagnostics` namespace, which must have `id` equal to its name.
+#define DIAGNOSE_CRITICAL(ID, ...) DIAGNOSE_WITH_LEVEL(critical, ID, __VA_ARGS__)
+#define DIAGNOSE_ERROR(ID, ...) DIAGNOSE_WITH_LEVEL(error, ID, __VA_ARGS__)
+
+#define DIAGNOSE_WITH_LEVEL(LEVEL, ID, ...)                              \
+  do {                                                                   \
+    codeql::SwiftDiagnosticsSource::inscribe<&codeql_diagnostics::ID>(); \
+    LOG_WITH_LEVEL_AND_CATEGORY(LEVEL, ID, __VA_ARGS__);                 \
+  } while (false)
+
+// avoid calling into binlog's original macros
+#undef BINLOG_CRITICAL
+#undef BINLOG_CRITICAL_W
+#undef BINLOG_CRITICAL_C
+#undef BINLOG_CRITICAL_WC
+#undef BINLOG_ERROR
+#undef BINLOG_ERROR_W
+#undef BINLOG_ERROR_C
+#undef BINLOG_ERROR_WC
+#undef BINLOG_WARNING
+#undef BINLOG_WARNING_W
+#undef BINLOG_WARNING_C
+#undef BINLOG_WARNING_WC
+#undef BINLOG_INFO
+#undef BINLOG_INFO_W
+#undef BINLOG_INFO_C
+#undef BINLOG_INFO_WC
+#undef BINLOG_DEBUG
+#undef BINLOG_DEBUG_W
+#undef BINLOG_DEBUG_C
+#undef BINLOG_DEBUG_WC
+#undef BINLOG_TRACE
+#undef BINLOG_TRACE_W
+#undef BINLOG_TRACE_C
+#undef BINLOG_TRACE_WC
+
+namespace codeql {
+
+// tools should define this to tweak the root name of all loggers
+extern const std::string_view programName;
+
+// This class is responsible for the global log state (outputs, log level rules, flushing)
+// State is stored in the singleton `Log::instance()`.
+// Before using logging, `Log::configure("<name>")` should be used (e.g.
+// `Log::configure("extractor")`). Then, `Log::flush()` should be regularly called.
+// Logging is configured upon first usage.  This consists in
+//  * using environment variable `CODEQL_EXTRACTOR_SWIFT_LOG_DIR` to choose where to dump the log
+//    file(s). Log files will go to a subdirectory thereof named after `programName`
+//  * using environment variable `CODEQL_EXTRACTOR_SWIFT_LOG_LEVELS` to configure levels for
+//    loggers and outputs. This must have the form of a comma separated `spec:level` list, where
+//    `spec` is either a glob pattern (made up of alphanumeric, `/`, `*` and `.` characters) for
+//    matching logger names or one of `out:bin`, `out:text` or `out:console`.
+//    Output default levels can be seen in the corresponding initializers below. By default, all
+//    loggers are configured with the lowest output level
+class Log {
+ public:
+  using Level = binlog::Severity;
+
+  // Internal data required to build `Logger` instances
+  struct LoggerConfiguration {
+    binlog::Session& session;
+    std::string fullyQualifiedName;
+    Level level;
+  };
+
+  // Flush logs to the designated outputs
+  static void flush() { instance().flushImpl(); }
+
+  // create `Logger` configuration, used internally by `Logger`'s constructor
+  static LoggerConfiguration getLoggerConfiguration(std::string_view name) {
+    return instance().getLoggerConfigurationImpl(name);
+  }
+
+ private:
+  static constexpr const char* format = "%u %S [%n] %m (%G:%L)\n";
+
+  Log() { configure(); }
+
+  static Log& instance() {
+    static Log ret;
+    return ret;
+  }
+
+  class Logger& logger();
+
+  void configure();
+  void flushImpl();
+  LoggerConfiguration getLoggerConfigurationImpl(std::string_view name);
+
+  // make `session.consume(*this)` work, which requires access to `write`
+  friend binlog::Session;
+  Log& write(const char* buffer, std::streamsize size);
+
+  struct OnlyWithCategory {};
+
+  // Output filtered according to a configured log level
+  template <typename Output>
+  struct FilteredOutput {
+    binlog::Severity level;
+    Output output;
+    binlog::EventFilter filter;
+
+    template <typename... Args>
+    FilteredOutput(Level level, Args&&... args)
+        : level{level}, output{std::forward<Args>(args)...}, filter{filterOnLevel()} {}
+
+    template <typename... Args>
+    FilteredOutput(OnlyWithCategory, Level level, Args&&... args)
+        : level{level},
+          output{std::forward<Args>(args)...},
+          filter{filterOnLevelAndNonEmptyCategory()} {}
+
+    FilteredOutput& write(const char* buffer, std::streamsize size) {
+      filter.writeAllowed(buffer, size, output);
+      return *this;
+    }
+
+    binlog::EventFilter::Predicate filterOnLevel() const {
+      return [this](const binlog::EventSource& src) { return src.severity >= level; };
+    }
+
+    binlog::EventFilter::Predicate filterOnLevelAndNonEmptyCategory() const {
+      return [this](const binlog::EventSource& src) {
+        return !src.category.empty() && src.severity >= level;
+      };
+    }
+
+    // if configured as `no_logs`, the output is effectively disabled
+    explicit operator bool() const { return level < Level::no_logs; }
+  };
+
+  using LevelRule = std::pair<std::regex, Level>;
+  using LevelRules = std::vector<LevelRule>;
+
+  binlog::Session session;
+  std::ofstream textFile;
+  FilteredOutput<std::ofstream> binary{Level::no_logs};
+  FilteredOutput<binlog::TextOutputStream> text{Level::info, textFile, format};
+  FilteredOutput<binlog::TextOutputStream> console{Level::warning, std::cerr, format};
+  FilteredOutput<SwiftDiagnosticsDumper> diagnostics{OnlyWithCategory{}, Level::error};
+  LevelRules sourceRules;
+  std::vector<std::string> collectLevelRulesAndReturnProblems(const char* envVar);
+};
+
+// This class represent a named domain-specific logger, responsible for pushing logs using the
+// underlying `binlog::SessionWriter` class. This has a configured log level, so that logs on this
+// `Logger` with a level lower than the configured one are no-ops. The level is configured based
+// on rules matching `<programName>/<name>` in `CODEQL_EXTRACTOR_SWIFT_LOG_LEVELS` (see above).
+// `<name>` is provided in the constructor. If no rule matches the name, the log level defaults to
+// the minimum level of all outputs.
+class Logger {
+ public:
+  // configured logger based on name, as explained above
+  explicit Logger(std::string_view name) : Logger(Log::getLoggerConfiguration(name)) {}
+
+  // used internally, public to be accessible to Log for its own logger
+  explicit Logger(Log::LoggerConfiguration&& configuration)
+      : w{configuration.session, queueSize, /* id */ 0,
+          std::move(configuration.fullyQualifiedName)},
+        level_{configuration.level} {}
+
+  binlog::SessionWriter& writer() { return w; }
+  Log::Level level() const { return level_; }
+
+  // make defining a `Logger logger` field be equivalent to providing a `Logger& logger()` function
+  // in order to be picked up by logging macros
+  Logger& operator()() { return *this; }
+
+ private:
+  static constexpr size_t queueSize = 1 << 20;  // default taken from binlog
+
+  binlog::SessionWriter w;
+  Log::Level level_;
+};
+
+}  // namespace codeql