Improve header isolation and parse time of logger.h (#4445)

As we prepare to surface qpu headers in user code, `cudaq.h` is become
significantly slower to parse in a prototyping sandbox. This PR
addresses a slowdown introduced by logger.h as can be seen in the
profile below.


The compiled code is:
```cpp
#include <cudaq.h>

int main() {
return 0;
}
```
The compile time is 3.6s.
```
time clang++ cudaq_inc.cpp -std=c++20  -I ~/cudaq/cq2/install/cudaq/include
real    0m3.603s
```

The profile shows logger.h takes 441ms of parse time.

<img width="689" height="519" alt="logger-profile-1"
src="https://github.com/user-attachments/assets/2a677887-0ef9-432c-a07a-6b5f3c8aabed"
/>

With this patch, the compilation time becomes 2.9s
```
time clang++ cudaq_inc.cpp -std=c++20  -I ~/cudaq/cq2/install/cudaq/include
real    0m2.936s
```

The profile show logger.h only taking 7ms.


<img width="676" height="465" alt="logger-profile-2"
src="https://github.com/user-attachments/assets/9034acc9-829e-4960-97a8-f433c41107de"
/>


This is achieved by replacing the `std::variant` with a `FormatArgument`
which only stores a pointer and an out-of-line appending callback. The
callback is instantiated in logger.cpp.

---------

Signed-off-by: Renaud Kauffmann <rkauffmann@nvidia.com>

Author: Renaud-K

runtime/common/CodeGenConfig.cpp

@@ -10,6 +10,8 @@
 #include "FmtCore.h"
 #include "cudaq/runtime/logger/logger.h"
 #include <stdexcept>
+#include <tuple>
+#include <vector>
 
 namespace {
 

runtime/cudaq/platform/fermioniq/FermioniqQPU.cpp

@@ -7,6 +7,7 @@
  ******************************************************************************/
 
 #include "FermioniqQPU.h"
+#include "cudaq/runtime/logger/cudaq_fmt.h"
 #include "nlohmann/json.hpp"
 #include <memory>
 

runtime/include/cudaq/runtime/logger/cudaq_fmt.h

@@ -8,120 +8,75 @@
 
 #pragma once
 
-#include <chrono>
-#include <complex>
+#include <array>
 #include <cstddef>
-#include <cstdint>
-#include <functional>
-#include <map>
+#include <memory>
 #include <span>
 #include <string>
+#include <string_view>
 #include <type_traits>
-#include <variant>
-#include <vector>
+#include <utility>
 
 //
-// This header provides a wrapper around some of the fmtlib functions, so that
-// fmtlib headers, which are not distributed, do not bleed into user code.
+// This header provides a wrapper around some of the `fmtlib` functions, so that
+// `fmtlib` headers, which are not distributed, do not propagate into user code.
 //
 // It introduces a cudaq_fmt namespace to make it easy to distinguish between
-// what would otherwise be fmt::format and cudaq::fmt::format.
+// what would otherwise be `fmt::format` and `cudaq::format`.
 //
 
 namespace cudaq_fmt {
-struct fmt_arg;
-namespace details {
-//
-// Concepts to check if T is in the variant
-//
-template <typename T, typename... Types>
-concept one_of = ((std::same_as<T, Types> ||
-                   std::same_as<std::reference_wrapper<const T>, Types>) ||
-                  ...);
-
-template <typename T, typename Variant>
-struct is_variant_member;
-
-template <typename T, typename... Types>
-struct is_variant_member<T, std::variant<Types...>>
-    : std::bool_constant<one_of<T, Types...>> {};
-
-template <typename T, typename Variant>
-concept variant_alternative =
-    is_variant_member<std::decay_t<T>, Variant>::value;
-
-//
-// Packed versions of format and print, implemented in logger.cpp
-//
-std::string format_packed(const std::string_view message,
-                          const std::span<fmt_arg> &arr);
-
-void print_packed(const std::string_view message,
-                  const std::span<fmt_arg> &arr);
-} // namespace details
 
-//
-// Packed parameter type passing arguments to fmt
-// Built-in types need to be passed by value.
-// Please store large types (like vectors, strings) as reference_wrappers
-//
-struct fmt_arg {
-  using storage_t = std::variant<
-      bool, char, uint32_t, int32_t, uint64_t, int64_t, float, double,
-      std::complex<float>, std::complex<double>, std::string_view, const char *,
-      char *, void *, std::chrono::milliseconds,
-      std::chrono::system_clock::time_point,
-      std::reference_wrapper<const std::vector<int32_t>>,
-      std::reference_wrapper<const std::string>,
-      std::reference_wrapper<const std::vector<uint32_t>>,
-      std::reference_wrapper<const std::vector<uint64_t>>,
-      std::reference_wrapper<const std::vector<float>>,
-      std::reference_wrapper<const std::vector<double>>,
-      std::reference_wrapper<const std::vector<std::string>>,
-      std::reference_wrapper<const std::map<std::string, std::string>>,
-      std::reference_wrapper<const std::vector<std::complex<float>>>,
-      std::reference_wrapper<const std::vector<std::complex<double>>>>;
-  storage_t value;
+/// Type-erased reference to a format argument.
+///
+/// This intentionally stores only a pointer and an out-of-line appending
+/// callback. The callback is instantiated in logger.cpp, where heavier headers
+/// such as `fmtlib` and `chrono` can be included without forcing
+/// every formatting caller to parse them.
+struct FormatArgument {
+  using Appender = void (*)(void *store, const void *value);
 
   template <typename T>
-    requires details::variant_alternative<T, storage_t>
-  fmt_arg(const T &v) : value(std::cref(v)) {}
+  FormatArgument(const T &value)
+      : value(std::addressof(value)), append(&appendArgument<std::decay_t<T>>) {
+  }
 
-  // On macOS, unsigned long and long are distinct types from uint64_t/int64_t
-  // (both 64-bit but different type identities). These constructors convert
-  // to canonical fixed-width types. Constraints ensure they only exist when
-  // the types are actually distinct (disabled on Linux where they're aliases).
+  FormatArgument(const char *value) : value(value), append(&appendCString) {}
+  FormatArgument(char *value) : value(value), append(&appendCString) {}
 
-  template <typename T>
-    requires(std::same_as<T, unsigned long> && !std::same_as<T, uint64_t>)
-  fmt_arg(T v) : value(static_cast<uint64_t>(v)) {}
-
-  template <typename T>
-    requires(std::same_as<T, long> && !std::same_as<T, int64_t>)
-  fmt_arg(T v) : value(static_cast<int64_t>(v)) {}
+  const void *value = nullptr;
+  Appender append = nullptr;
 
   template <typename T>
-    requires(std::same_as<T, std::vector<unsigned long>> &&
-             !std::same_as<unsigned long, uint64_t>)
-  fmt_arg(const T &v)
-      : value(std::cref(reinterpret_cast<const std::vector<uint64_t> &>(v))) {}
+  static void appendArgument(void *store, const void *value);
+  static void appendCString(void *store, const void *value);
 };
 
+namespace details {
+std::string format_packed(const std::string_view message,
+                          const std::span<const FormatArgument> &arr);
+
+void print_packed(const std::string_view message,
+                  const std::span<const FormatArgument> &arr);
+} // namespace details
+
 //
 // Functions substitutes for fmt::format and fmt::print
 //
 template <typename... Args>
 std::string format(const std::string_view message, Args &&...args) {
-  auto array = std::array<fmt_arg, sizeof...(Args)>{
-      fmt_arg(std::forward<Args>(args))...};
-  return details::format_packed(message, array);
+  auto array = std::array<FormatArgument, sizeof...(Args)>{
+      FormatArgument(std::forward<Args>(args))...};
+  return details::format_packed(
+      message, std::span<const FormatArgument>(array.data(), array.size()));
 }
 
 template <typename... Args>
 void print(const std::string_view message, Args &&...args) {
-  auto array = std::array<fmt_arg, sizeof...(Args)>{
-      fmt_arg(std::forward<Args>(args))...};
-  return details::print_packed(message, array);
+  auto array = std::array<FormatArgument, sizeof...(Args)>{
+      FormatArgument(std::forward<Args>(args))...};
+  return details::print_packed(
+      message, std::span<const FormatArgument>(array.data(), array.size()));
 }
 
 //

runtime/include/cudaq/runtime/logger/logger.h

@@ -10,14 +10,21 @@
 
 #include "cudaq/runtime/logger/cudaq_fmt.h"
 #include "cudaq/runtime/logger/tracer.h"
+#include <array>
+#include <cstddef>
+#include <span>
+#include <stdexcept>
+#include <string>
+#include <string_view>
+#include <utility>
 
 namespace cudaq {
 
 /// @brief Returns true if `tag` is enabled. Tags are only enabled/disabled at
 /// program startup.
 bool isTimingTagEnabled(int tag);
 
-// Keep all spdlog headers hidden in the implementation file
+// Keep all spdlog headers hidden in the implementation file.
 namespace details {
 // This enum must match spdlog::level enums. This is checked via static_assert
 // in logger.cpp.
@@ -29,34 +36,54 @@ void debug(const std::string_view msg);
 void warn(const std::string_view msg);
 void error(const std::string_view msg);
 std::string pathToFileName(const std::string_view fullFilePath);
+
+// Test/debug helpers. Production callers configure the level via the
+// CUDAQ_LOG_LEVEL environment variable.
+void setLogLevel(LogLevel level);
+LogLevel getLogLevel();
+
+// Flushes any buffered log output. Useful in tests that need to inspect
+// captured stdout immediately after emitting an info/debug message
+// (initializeLogger only enables flush_on(warn)).
+void flushLogs();
+
+void logMessagePacked(LogLevel logLevel, const std::string_view message,
+                      const std::span<const cudaq_fmt::FormatArgument> &args,
+                      const char *fileName, int lineNo);
+
+void logWithTimestampPacked(
+    const std::string_view message,
+    const std::span<const cudaq_fmt::FormatArgument> &args);
+
+template <typename... Args>
+std::string formatMessage(const std::string_view message, Args &&...args) {
+  return cudaq_fmt::format(message, std::forward<Args>(args)...);
+}
+
+template <typename... Args>
+void logMessage(LogLevel logLevel, const std::string_view message,
+                const char *fileName, int lineNo, Args &&...args) {
+  std::array<cudaq_fmt::FormatArgument, sizeof...(Args)> packedArgs{
+      cudaq_fmt::FormatArgument(std::forward<Args>(args))...};
+  logMessagePacked(logLevel, message,
+                   std::span<const cudaq_fmt::FormatArgument>(
+                       packedArgs.data(), packedArgs.size()),
+                   fileName, lineNo);
+}
 } // namespace details
 
-/// This type seeks to enable automated injection of the
-/// source location of the `cudaq::info()` or `debug()` call.
-/// We do this via a struct of the same name (info), which
-/// takes the message and variadic arguments for the message, and
-/// finishes with arguments with defaults providing the file name
-/// and the source location. We could also add the function name
-/// if we want it in the future.
-///
-/// We then use a template deduction guide to map calls of the
-/// templated `cudaq::info()` function to this type.
+/// These types seek to enable automated injection of the source location of the
+/// `cudaq::info()` or `debug()` call. The actual formatting is out-of-line in
+/// logger.cpp so callers do not need to parse `fmt` or `chrono` headers.
 #define CUDAQ_LOGGER_DEDUCTION_STRUCT(NAME)                                    \
   template <typename... Args>                                                  \
   struct NAME {                                                                \
     NAME(const std::string_view message, Args &&...args,                       \
-         const char *funcName = __builtin_FUNCTION(),                          \
          const char *fileName = __builtin_FILE(),                              \
          int lineNo = __builtin_LINE()) {                                      \
-      if (details::should_log(details::LogLevel::NAME)) {                      \
-        auto msg = cudaq_fmt::format(message, args...);                        \
-        std::string name = funcName;                                           \
-        auto start = name.find_first_of(" ");                                  \
-        name = name.substr(start + 1, name.find_first_of("(") - start - 1);    \
-        msg = "[" + details::pathToFileName(fileName) + ":" +                  \
-              std::to_string(lineNo) + "] " + msg;                             \
-        details::NAME(msg);                                                    \
-      }                                                                        \
+      if (details::should_log(details::LogLevel::NAME))                        \
+        details::logMessage(details::LogLevel::NAME, message, fileName,        \
+                            lineNo, std::forward<Args>(args)...);              \
     }                                                                          \
   };                                                                           \
   template <typename... Args>                                                  \
@@ -69,7 +96,7 @@ CUDAQ_LOGGER_DEDUCTION_STRUCT(error);
 #ifdef CUDAQ_DEBUG
 CUDAQ_LOGGER_DEDUCTION_STRUCT(debug);
 #else
-// Remove cudaq::debug log messages from Release binaries
+// Remove cudaq::debug log messages from Release binaries.
 template <typename... Args>
 void debug(const std::string_view, Args &&...) {}
 #endif
@@ -79,43 +106,17 @@ void debug(const std::string_view, Args &&...) {}
 // Note 2: File and line info is not included in the log line.
 template <typename... Args>
 void log(const std::string_view message, Args &&...args) {
-  const auto timestamp = std::chrono::system_clock::now();
-  const auto now_c = std::chrono::system_clock::to_time_t(timestamp);
-  std::tm now_tm = *std::localtime(&now_c);
-  cudaq_fmt::print("[{:04}-{:02}-{:02} {:02}:{:02}:{:%S}] {}\n",
-                   now_tm.tm_year + 1900, now_tm.tm_mon + 1, now_tm.tm_mday,
-                   now_tm.tm_hour, now_tm.tm_min,
-                   std::chrono::round<std::chrono::milliseconds>(
-                       timestamp.time_since_epoch()),
-                   cudaq_fmt::format(message, args...));
+  std::array<cudaq_fmt::FormatArgument, sizeof...(Args)> packedArgs{
+      cudaq_fmt::FormatArgument(std::forward<Args>(args))...};
+  details::logWithTimestampPacked(
+      message, std::span<const cudaq_fmt::FormatArgument>(packedArgs.data(),
+                                                          packedArgs.size()));
 }
 
-/// @brief This type is meant to provided quick tracing
-/// of function calls. Instantiate at the beginning
-/// of a function and when it goes out of scope at function
-/// end, it will call to the trace function and report
-/// the function name and the execution time in ms.
-//
-// Since this traces upon destruction, tracing in tandem
-// with ScopeTrace instances within functions called from
-// the current one will stack and can be read in reverse order.
-// This type keeps track of an integer that prints and indentation
-// before the message to demonstrate the call stack.
-//
-// e.g. for
-// void bar() {
-//   ScopedTrace trace("bar");
-//   foobar() // <-- also creates a ScopedTrace
-// }
-// void foo() {
-//  ScopedTrace trace("foo");
-//  bar()
-// }
-//
-// will print
-// [2022-12-15 18:54:39.346] [trace] -- foobar() executed in 0.026 ms.
-// [2022-12-15 18:54:39.347] [trace] - bar executed in 0.604 ms.
-// [2022-12-15 18:54:39.347] [trace] foo executed in 2.572 ms.
+/// @brief This type is meant to provided quick tracing of function calls.
+/// Instantiate at the beginning of a function and when it goes out of scope at
+/// function end, it will call to the trace function and report the function
+/// name and execution time.
 class ScopedTrace {
 private:
   SpanHandle handle;
@@ -140,7 +141,7 @@ class ScopedTrace {
         for (std::size_t i = 0; i < nArgs; i++)
           argsMsg += (i != nArgs - 1) ? "{}, " : "{}}})";
       }
-      return cudaq_fmt::format(argsMsg, args...);
+      return details::formatMessage(argsMsg, std::forward<Args>(args)...);
     }
   }