feat: Structured logging

Core/include/Acts/TrackFitting/detail/GainMatrixUpdaterImpl.hpp

@@ -32,8 +32,8 @@ std::tuple<double, std::error_code> GainMatrixUpdater::visitMeasurementImpl(
       calibratedCovariance{trackState.calibratedCovariance};
 
   ACTS_VERBOSE("Measurement dimension: " << kMeasurementSize);
-  ACTS_VERBOSE("Calibrated measurement: " << calibrated.transpose());
-  ACTS_VERBOSE("Calibrated measurement covariance:\n" << calibratedCovariance);
+  ACTS_STRUCTURED("Calibrated measurement", calibrated.transpose());
+  ACTS_STRUCTURED("Calibrated measurement covariance", calibratedCovariance);
 
   std::span<const std::uint8_t, kMeasurementSize> validSubspaceIndices(
       trackState.projector.begin(),
@@ -52,7 +52,7 @@ std::tuple<double, std::error_code> GainMatrixUpdater::visitMeasurementImpl(
                       .inverse())
                      .eval();
 
-  ACTS_VERBOSE("Gain Matrix K:\n" << K);
+  ACTS_STRUCTURED("Gain Matrix K", K);
 
   if (K.hasNaN()) {
     // set to error abort execution
@@ -65,8 +65,8 @@ std::tuple<double, std::error_code> GainMatrixUpdater::visitMeasurementImpl(
   trackState.filtered = normalizeBoundParameters(trackState.filtered);
   trackState.filteredCovariance =
       (BoundSquareMatrix::Identity() - K * H) * trackState.predictedCovariance;
-  ACTS_VERBOSE("Filtered parameters: " << trackState.filtered.transpose());
-  ACTS_VERBOSE("Filtered covariance:\n" << trackState.filteredCovariance);
+  ACTS_STRUCTURED("Filtered parameters", trackState.filtered.transpose());
+  ACTS_STRUCTURED("Filtered covariance", trackState.filteredCovariance);
 
   ParametersVector residual;
   residual = calibrated - H * trackState.filtered;

Core/include/Acts/Utilities/Logger.hpp

@@ -10,19 +10,43 @@
 // STL include(s)
 #include <cassert>
 #include <ctime>
-#include <exception>
-#include <functional>
 #include <iomanip>
 #include <iostream>
 #include <memory>
 #include <optional>
+#include <span>
 #include <sstream>
 #include <stdexcept>
 #include <string>
 #include <string_view>
 #include <thread>
 #include <utility>
 
+#include <Eigen/Core>
+
+namespace Acts {
+
+class Logger;
+
+class StructuredLoggerBase {
+ public:
+  virtual ~StructuredLoggerBase() {}
+  virtual void log(const Logger& logger, std::string_view msg) = 0;
+  virtual void log(std::string_view tag, std::string_view name,
+                   const Eigen::MatrixXd& m) = 0;
+  virtual void log(std::string_view tag, std::string_view name,
+                   const std::span<double>& s) = 0;
+};
+
+/// TODO this is not meant to be the final version
+/// Ultimately the structured logger should be somehow part of Acts::Logger
+/// instance but was to lazy for now to do the wireing
+void setStructuredLogger(
+    std::unique_ptr<StructuredLoggerBase>&& structuredLogger);
+StructuredLoggerBase* getStructuredLogger();
+
+}  // namespace Acts
+
 /// @defgroup Logging Logging
 
 // clang-format off
@@ -71,6 +95,9 @@
       std::ostringstream os;                                                   \
       os << x;                                                                 \
       logger().log(level, os.str());                                           \
+      if( auto slog = Acts::getStructuredLogger(); slog != nullptr ) { \
+        slog->log(logger(), os.str()); \
+      } \
     }                                                                          \
   }                                                                            \
   while(0)
@@ -146,6 +173,18 @@
 /// The debug message is printed if the current Acts::Logging::Level <=
 /// Acts::Logging::FATAL.
 #define ACTS_FATAL(x)  ACTS_LOG(Acts::Logging::FATAL, x)
+
+/// @brief macro for structured logging
+/// TODO This will not break the line before matrices unfortunately...
+/// maybe we can wire this in somehow
+#define ACTS_STRUCTURED(key, val) \
+    do { \
+        ACTS_VERBOSE("structured | " << key << ":" << val); \
+        if( auto slog = Acts::getStructuredLogger(); slog != nullptr ) { \
+           slog->log(logger().name(), key, val); \
+        } \
+    } while(0)
+
 // clang-format on
 
 namespace Acts {

Core/src/Utilities/Logger.cpp

@@ -144,4 +144,16 @@ const Logger& getDummyLogger() {
 
   return *logger;
 }
+
+static std::unique_ptr<Acts::StructuredLoggerBase> s_structuredLogger;
+
+void setStructuredLogger(
+    std::unique_ptr<StructuredLoggerBase>&& structuredLogger) {
+  s_structuredLogger = std::move(structuredLogger);
+}
+
+Acts::StructuredLoggerBase* getStructuredLogger() {
+  return s_structuredLogger.get();
+}
+
 }  // namespace Acts

Examples/Python/src/Json.cpp

@@ -14,6 +14,7 @@
 #include "Acts/Plugins/Json/JsonSurfacesReader.hpp"
 #include "Acts/Plugins/Json/MaterialMapJsonConverter.hpp"
 #include "Acts/Plugins/Json/ProtoDetectorJsonConverter.hpp"
+#include "Acts/Plugins/Json/StructuredLoggerJson.hpp"
 #include "Acts/Plugins/Python/Utilities.hpp"
 #include "Acts/Utilities/Logger.hpp"
 #include "ActsExamples/Framework/ProcessCode.hpp"
@@ -294,5 +295,15 @@ void addJson(Context& ctx) {
               return Acts::DetectorJsonConverter::fromJson(gctx, jDetectorIn);
             });
   }
+
+  {
+    mex.def(
+        "enableJsonStructuredLogging",
+        [](std::string jsonPath) {
+          auto sLogger = std::make_unique<Acts::StructuredLoggerJson>(jsonPath);
+          Acts::setStructuredLogger(std::move(sLogger));
+        },
+        "jsonPath"_a);
+  }
 }
 }  // namespace Acts::Python

Examples/Scripts/Python/truth_tracking_kalman.py

@@ -191,6 +191,8 @@ def runTruthTrackingKalman(
     #     / "Examples/Algorithms/Digitization/share/default-smearing-config-generic.json"
     # )
 
+    acts.examples.enableJsonStructuredLogging("log.json")
+
     field = acts.ConstantBField(acts.Vector3(0, 0, 2 * u.T))
 
     runTruthTrackingKalman(

Plugins/Json/CMakeLists.txt

@@ -24,6 +24,7 @@ add_library(
     src/DetrayJsonHelper.cpp
     src/JsonDetectorElement.cpp
     src/JsonSurfacesReader.cpp
+    src/StructuredLoggerJson.cpp
 )
 target_include_directories(
     ActsPluginJson

Plugins/Json/include/Acts/Plugins/Json/StructuredLoggerJson.hpp

@@ -0,0 +1,37 @@
+// This file is part of the ACTS project.
+//
+// Copyright (C) 2016 CERN for the benefit of the ACTS project
+//
+// This Source Code Form is subject to the terms of the Mozilla Public
+// License, v. 2.0. If a copy of the MPL was not distributed with this
+// file, You can obtain one at https://mozilla.org/MPL/2.0/.
+
+#pragma once
+
+#include "Acts/Utilities/Logger.hpp"
+
+#include <filesystem>
+#include <mutex>
+
+#include <nlohmann/json.hpp>
+
+namespace Acts {
+
+class StructuredLoggerJson : public StructuredLoggerBase {
+ public:
+  StructuredLoggerJson(std::filesystem::path outputFile);
+  ~StructuredLoggerJson();
+
+  void log(const Logger &logger, std::string_view msg) override;
+  void log(std::string_view tag, std::string_view name,
+           const Eigen::MatrixXd &m) override;
+  void log(std::string_view tag, std::string_view name,
+           const std::span<double> &s) override;
+
+ private:
+  std::mutex m_mutex;
+  nlohmann::json m_json;
+  std::filesystem::path m_path;
+};
+
+}  // namespace Acts

Plugins/Json/src/StructuredLoggerJson.cpp

@@ -0,0 +1,74 @@
+// This file is part of the ACTS project.
+//
+// Copyright (C) 2016 CERN for the benefit of the ACTS project
+//
+// This Source Code Form is subject to the terms of the Mozilla Public
+// License, v. 2.0. If a copy of the MPL was not distributed with this
+// file, You can obtain one at https://mozilla.org/MPL/2.0/.
+
+#include <Acts/Plugins/Json/StructuredLoggerJson.hpp>
+
+#include <fstream>
+
+namespace Acts {
+
+StructuredLoggerJson::StructuredLoggerJson(std::filesystem::path outputFile)
+    : m_path(outputFile) {
+  m_json = nlohmann::json::array();
+}
+
+StructuredLoggerJson::~StructuredLoggerJson() {
+  std::cout << "Dump json to " << m_path << std::endl;
+  std::ofstream os(m_path);
+  os << m_json.dump(2);
+}
+
+void StructuredLoggerJson::log(const Logger &logger, std::string_view msg) {
+  nlohmann::json j;
+  j["tag"] = logger.name();
+  j["level"] = static_cast<int>(logger.level());
+  j["type"] = "message";
+  j["key"] = "";
+  j["val"] = msg;
+
+  std::lock_guard<std::mutex> guard(m_mutex);
+  m_json.push_back(j);
+  std::cout << "log msg to json" << std::endl;
+}
+
+void StructuredLoggerJson::log(std::string_view tag, std::string_view name,
+                               const Eigen::MatrixXd &m) {
+  nlohmann::json j;
+  j["tag"] = tag;
+  j["level"] = "STRUCTURED";
+  j["key"] = name;
+
+  if (m.rows() == 1) {
+    j["type"] = "vector";
+    j["val"] = m.row(0);
+  } else {
+    j["type"] = "matrix";
+    j["val"] = nlohmann::json::array();
+    for (const auto &row : m.rowwise()) {
+      j["val"].push_back(row);
+    }
+  }
+
+  std::lock_guard<std::mutex> guard(m_mutex);
+  m_json.push_back(j);
+}
+
+void StructuredLoggerJson::log(std::string_view tag, std::string_view name,
+                               const std::span<double> &s) {
+  nlohmann::json j;
+  j["tag"] = tag;
+  j["level"] = "STRUCTURED";
+  j["type"] = "vector";
+  j["key"] = name;
+  j["val"] = s;
+
+  std::lock_guard<std::mutex> guard(m_mutex);
+  m_json.push_back(j);
+}
+
+}  // namespace Acts