Skip to content

feat(logging): add Logger interface and default logger (2/6)#723

Open
kamcheungting-db wants to merge 9 commits into
apache:mainfrom
kamcheungting-db:logging-block2-interface
Open

feat(logging): add Logger interface and default logger (2/6)#723
kamcheungting-db wants to merge 9 commits into
apache:mainfrom
kamcheungting-db:logging-block2-interface

Conversation

@kamcheungting-db

@kamcheungting-db kamcheungting-db commented Jun 10, 2026

Copy link
Copy Markdown
Contributor

Part 2 of the logging stack (builds on #722). Adds the logging API and a swappable default logger — the foundation the backends and macros plug into.

What's here

  • Logger: the pluggable sink interface (ShouldLog / Log / SetLevel / Flush / Initialize). ShouldLog() is the single source of truth for runtime filtering.
  • LogMessage owns its formatted text so a sink can safely keep a record; reserves an attributes field for future structured logging.
  • Process-global default logger: GetDefaultLogger / SetDefaultLogger / SetDefaultLevel, with a lock-free thread-local fast path so logging stays cheap.
  • Initialize applies the level property, so config-driven levels actually work. CurrentLogger() is safe to call even from a thread_local destructor during thread shutdown.
  • logger.h stays backend-agnostic (never includes the build config header), so consumers see one stable API regardless of backend.

Examples — using the API directly (the LOG_* macros that wrap it arrive in #725):

// A custom sink, installed as the process default.
class MySink : public Logger {
 public:
  bool ShouldLog(LogLevel level) const override { return level >= level_; }
  void Log(LogMessage&& m) noexcept override { write_line(m.message); }
  void SetLevel(LogLevel level) override { level_ = level; }
  LogLevel level() const override { return level_; }
 private:
  std::atomic<LogLevel> level_{LogLevel::kInfo};
};

SetDefaultLogger(std::make_shared<MySink>());   // install process-wide
SetDefaultLevel(LogLevel::kDebug);              // adjust the threshold

auto logger = GetDefaultLogger();               // borrow the current default
if (logger->ShouldLog(LogLevel::kInfo)) {
  logger->Log(LogMessage{.level = LogLevel::kInfo, .message = "scan ready"});
}

// Or configure from catalog-style properties (applies the "level" key):
auto sink = std::make_shared<MySink>();
auto status = sink->Initialize({{std::string(kLevelProperty), "warn"}});  // -> kWarn

The same example is documented inline in logger.h.

Testslogger_test: default-logger API, level-from-property, invalid level rejected, concurrent swap/read, and logging during thread teardown. Built and run with clang/libc++ (spdlog ON and OFF).

This pull request and its description were written by Isaac.

@kamcheungting-db kamcheungting-db changed the title [Iceberg Logger] [Part-2] Logger Interface feat: [Iceberg Logger] [Part-2] Logger Interface Jun 10, 2026
@kamcheungting-db kamcheungting-db changed the title feat: [Iceberg Logger] [Part-2] Logger Interface feat(logging): add Logger interface and default logger Jun 11, 2026
@kamcheungting-db kamcheungting-db changed the title feat(logging): add Logger interface and default logger feat(logging): add Logger interface and default logger (2/6) Jun 11, 2026
@kamcheungting-db kamcheungting-db force-pushed the logging-block2-interface branch 7 times, most recently from fd8c3b4 to c2b6a92 Compare June 16, 2026 03:27
@kamcheungting-db kamcheungting-db force-pushed the logging-block2-interface branch from c2b6a92 to cf09b69 Compare June 16, 2026 03:40
Second block: the backend-agnostic logging API and the swappable default logger.

- Logger: pure-virtual sink (ShouldLog/Log/SetLevel/level/Flush/IsNoop), with
  ShouldLog() as the single authority for runtime filtering and a documented
  no-reentrancy / thread-safety / noexcept contract. Mirrors MetricsReporter.
- LogMessage owns its formatted text (moved in) so a sink may retain records;
  reserves an owning attributes vector for future structured logging without an
  ABI break. logger.h is backend-agnostic -- it never includes the build config
  header nor references the spdlog feature macro, so consumers see one stable API.
- Process-global default logger: GetDefaultLogger / SetDefaultLogger /
  SetDefaultLevel, plus a lock-free thread-local generation cache on the hot path
  (no lock or refcount churn in steady state; slot mutex only on swap/refresh).
  NoopLogger is the placeholder default here; CerrLogger and the spdlog backend
  arrive in the following blocks.

Builds the source into both CMake and Meson and installs logger.h alongside
log_level.h; logger_test covers the default-logger API, level lowering taking
effect immediately, and concurrent swap/read safety.

Co-authored-by: Isaac
@kamcheungting-db kamcheungting-db force-pushed the logging-block2-interface branch from cf09b69 to 246cab6 Compare June 16, 2026 03:58
Comment thread src/iceberg/test/logger_test.cc Outdated
Comment on lines +103 to +104
(void)l->ShouldLog(LogLevel::kError);
(void)GetDefaultLogger();

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
(void)l->ShouldLog(LogLevel::kError);
(void)GetDefaultLogger();
std::ignore = l->ShouldLog(LogLevel::kError);
std::ignore = GetDefaultLogger();

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done

Comment thread src/iceberg/test/logger_test.cc Outdated
auto status =
logger.Initialize({{std::string(kLevelProperty), std::string("not-a-level")}});
ASSERT_FALSE(status.has_value());
EXPECT_EQ(status.error().kind, ErrorKind::kInvalidArgument);

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Let's use IsError matcher.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done

Comment thread src/iceberg/logging/logger.h Outdated
/// Both key and value are owned so a sink may retain the record safely.
/// Unused in v1; reserved so structured logging can be added without an ABI
/// break to LogMessage.
struct LogAttribute {

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Do we need to add ICEBERG_EXPORT to this and below?

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done


namespace detail {

const std::shared_ptr<Logger>& CurrentLogger() noexcept {

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think this is still not safe for thread_local teardown.

One case: a thread creates another thread_local object first. Then it calls CurrentLogger() in normal code. At thread exit, alive is destroyed before that earlier object. If that earlier object logs in its destructor, we read alive.value after alive is already destroyed. This is UB.

The test only checks first use from a TLS destructor. Maybe we need a design without destructible TLS state, or leak the per-thread cache.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done.
The new thread local is implemented and guaranteed teardown logic safe.
The tear down logic is protected by a thread local Guard.

ThreadCache* AccessThreadCache(bool create) noexcept {
  static thread_local bool dead = false;
  static thread_local ThreadCache* cache = nullptr;
  static thread_local struct Guard {
    ~Guard() {
      dead = true;  // mark BEFORE freeing, so a re-entrant log hits the fallback
      delete cache;
      cache = nullptr;
    }
  } guard;
  std::ignore = guard;  // mark the thread_local as intentionally used (its dtor is
                        // registered by reaching the declaration above)

  if (dead) return nullptr;
  if (cache == nullptr && create) cache = new ThreadCache();
  return cache;
}

Comment thread src/iceberg/logging/logger.h Outdated
}

/// \brief Cheap check whether a record at \p level would be emitted.
virtual bool ShouldLog(LogLevel level) const = 0;

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The doc says logger implementations must not throw. ShouldLog() is also in the hot path.

But the virtual method is not noexcept. A custom engine logger may throw here by mistake. Then logging can throw from the filter path. Adding noexcept later is also an API/ABI change.

Can we mark ShouldLog() noexcept now? Maybe SetLevel() and level() too, if we want the same rule for all logger methods.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

done

Comment thread src/iceberg/logging/logger.h Outdated
#pragma once

/// \file iceberg/logging/logger.h
/// \brief Pluggable logging interface, the process-global default logger, and

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Small doc issue. This header says it has logging macros, but this PR does not add them.

The PR text says macros are in a later block. Users who read the installed header may be confused.

Maybe say this header has the logger API and macro helper hooks. Or move this sentence to the later PR.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

done.

///
/// Off the hot path -- acquires the slot lock and returns an owning copy. The
/// logging macros use the cheaper internal hot-path accessor instead.
ICEBERG_EXPORT std::shared_ptr<Logger> GetDefaultLogger();

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think only having a process-global default logger may be hard for engine integration.

In engines, users may want different loggers for different catalog, session, query, or task. If all code only reads one global logger, it is hard to route logs to the engine logging context.

Can we consider a way to pass or bind a logger from a higher level context? The global logger can still be the fallback.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done

///
/// Declared ICEBERG_EXPORT because the logging macros expand into this call in
/// consumer translation units.
ICEBERG_EXPORT void Emit(Logger& logger, LogLevel level,

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think we should keep a lazy format-style API here.

Now Emit takes an already formatted std::string. This means the string must be built before calling the sink. It is OK after ShouldLog(), but it still makes the API string-based. Some engine loggers may want to keep format string + args, or format only inside their own backend.

Can we provide an API closer to std::format style, like log(level, fmt, args...), and only build the string after the level check? This also makes normal use easier for callers.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

we now support:
iceberg::Log(LogLevel::kInfo, "loaded {} files", n);
and
iceberg::Log(logger, LogLevel::kWarn, "retry {}", attempt);

LogLevel level = LogLevel::kOff;
std::string message;
std::source_location location = std::source_location::current();
std::vector<LogAttribute> attributes;

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think the attributes field is useful, but now there is no easy API to fill it.

For engine loggers, structured fields are often important. For example query id, task id, table name, snapshot id, file path, etc. If the first public API only supports message text in practice, it may be harder to add good structured logging later.

Can we add a small helper or builder path for attributes, or at least define how future macros will pass them?

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done, we now support

auto record = LogMessage::Builder(LogLevel::kInfo)
                  .Message("scan finished")
                  .Attribute("table", table_name)
                  .Attribute("snapshot_id", std::to_string(id))
                  .Build();
logger->Log(std::move(record));

Resolves @wgtmac's review comments on PR apache#723:

- Mark ShouldLog()/SetLevel()/level() noexcept so a custom logger cannot throw
  from the hot filter path; propagated to NoopLogger and CapturingLogger.
- Make CurrentLogger() safe during thread teardown without UB: the per-thread
  cache is reached via a trivially-destructible thread_local pointer to a
  never-freed heap slot (kept LSan-reachable by a registry), so logging from a
  thread_local destructor in any order is safe. Replaces the AliveFlag guard.
- Add ICEBERG_EXPORT to LogAttribute/LogMessage, matching Error/ScanReport.
- Trim the logger.h \file brief (the macros it referenced arrive in PR apache#725).
- Tests: use the IsError matcher and std::ignore; strengthen the teardown test
  to log from a thread_local destroyed after the cache.

Co-authored-by: Isaac
Addresses @wgtmac's review comment on PR apache#723 asking for a std::format-style API
that builds the string only after the level check.

- A single overloaded iceberg::Log():
    Log(level, "fmt {}", args...)           -> process-default logger
    Log(logger, level, "fmt {}", args...)   -> explicit logger
  disambiguated by the first argument.
- Formats only after ShouldLog() (no wasted work when disabled) and never throws
  -- a formatting failure routes to EmitFormatError, matching the macros.
- The call-site source_location is captured via a small consteval FmtWithLoc
  wrapper (the std::print technique), preserving compile-time format-string
  checking without a macro.

The sink interface (Logger::Log(LogMessage&&)) intentionally stays
pre-formatted: passing std::format_args across the virtual boundary is
lifetime-unsafe and would break safe record retention. The format-style win is
delivered at the call layer instead.

Co-authored-by: Isaac
Addresses @wgtmac's review comment on PR apache#723 that LogMessage::attributes had no
easy fill path.

Adds a fluent LogMessage::Builder so engine loggers can attach structured fields
(query id, task id, table name, snapshot id, file path, ...):

  auto record = LogMessage::Builder(LogLevel::kInfo)
                    .Message("scan finished")
                    .Attribute("table", table_name)
                    .Attribute("snapshot_id", std::to_string(id))
                    .Build();
  logger->Log(std::move(record));

- Message() sets the formatted text; Attribute() appends an owned key/value;
  Location() overrides the source location (defaults to the build site).
- Build() moves the accumulated state into a LogMessage.

This defines how attributes get populated, so structured logging can grow
without an ABI break.

Co-authored-by: Isaac
Replaces the intentional permanent per-thread leak with a cache that is freed at
thread exit, while staying safe to call CurrentLogger() from any thread_local
destructor during teardown.

The per-thread state is split by lifetime:
- `dead` (bool) and `cache` (pointer) are trivially destructible, so their
  storage stays valid for the whole thread and is readable from any other
  thread_local's destructor, in any destruction order.
- A `guard` (the only piece with a destructor) frees the cache and sets `dead`
  at thread exit. A thread_local destroyed after it reads `dead == true` and
  falls back to an immortal no-op; one destroyed before it still sees a live
  cache. Either order is safe.

This is the correct version of the earlier AliveFlag attempt, which was UB
because the flag object itself had a destructor (reading it after that
destructor ran was the very use-after-lifetime it tried to prevent). Drops the
LSan-reachability registry, which is no longer needed now that nothing leaks.

Validated with a dedicated stress harness under ThreadSanitizer and
AddressSanitizer (no leaks): logging from a thread_local destroyed after the
cache; logging interleaved with concurrent SetDefaultLogger swaps and thread
teardown; and a thread whose only logging happens in a thread_local destructor.
Adds ConcurrentTeardownAndSwapIsSafe to cover the combined path in CI.

Co-authored-by: Isaac
Bind a logger for the current thread + scope so the default path
(CurrentLogger/Log(level,...)/LOG_* macros) routes to it, with the global
default as fallback. Engines can route Iceberg's own internal logs into a
per catalog/session/query/task context without touching call sites.
@kamcheungting-db kamcheungting-db requested a review from wgtmac June 21, 2026 10:16
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants