feat(logging): add Logger interface and default logger (2/6)#723
feat(logging): add Logger interface and default logger (2/6)#723kamcheungting-db wants to merge 9 commits into
Conversation
fd8c3b4 to
c2b6a92
Compare
c2b6a92 to
cf09b69
Compare
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
cf09b69 to
246cab6
Compare
| (void)l->ShouldLog(LogLevel::kError); | ||
| (void)GetDefaultLogger(); |
There was a problem hiding this comment.
| (void)l->ShouldLog(LogLevel::kError); | |
| (void)GetDefaultLogger(); | |
| std::ignore = l->ShouldLog(LogLevel::kError); | |
| std::ignore = GetDefaultLogger(); |
| auto status = | ||
| logger.Initialize({{std::string(kLevelProperty), std::string("not-a-level")}}); | ||
| ASSERT_FALSE(status.has_value()); | ||
| EXPECT_EQ(status.error().kind, ErrorKind::kInvalidArgument); |
| /// 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 { |
There was a problem hiding this comment.
Do we need to add ICEBERG_EXPORT to this and below?
|
|
||
| namespace detail { | ||
|
|
||
| const std::shared_ptr<Logger>& CurrentLogger() noexcept { |
There was a problem hiding this comment.
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.
There was a problem hiding this comment.
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;
}
| } | ||
|
|
||
| /// \brief Cheap check whether a record at \p level would be emitted. | ||
| virtual bool ShouldLog(LogLevel level) const = 0; |
There was a problem hiding this comment.
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.
| #pragma once | ||
|
|
||
| /// \file iceberg/logging/logger.h | ||
| /// \brief Pluggable logging interface, the process-global default logger, and |
There was a problem hiding this comment.
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.
| /// | ||
| /// 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(); |
There was a problem hiding this comment.
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.
| /// | ||
| /// Declared ICEBERG_EXPORT because the logging macros expand into this call in | ||
| /// consumer translation units. | ||
| ICEBERG_EXPORT void Emit(Logger& logger, LogLevel level, |
There was a problem hiding this comment.
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.
There was a problem hiding this comment.
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; |
There was a problem hiding this comment.
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?
There was a problem hiding this comment.
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.
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.LogMessageowns its formatted text so a sink can safely keep a record; reserves an attributes field for future structured logging.GetDefaultLogger/SetDefaultLogger/SetDefaultLevel, with a lock-free thread-local fast path so logging stays cheap.Initializeapplies thelevelproperty, so config-driven levels actually work.CurrentLogger()is safe to call even from athread_localdestructor during thread shutdown.logger.hstays 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):The same example is documented inline in
logger.h.Tests —
logger_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.