Skip to content

Commit 0942681

Browse files
kamcheungting-dbkamcheungting-db
committed
feat(logging): add LOG_* logging macros (4/6)
Fourth block: the application-facing macros, the only part most callers touch. - ICEBERG_LOG_{TRACE,DEBUG,INFO,WARN,ERROR,CRITICAL,FATAL} plus the generic ICEBERG_LOG(level, ...), ICEBERG_LOG_TO(logger, level, ...) for an explicit logger, and ICEBERG_LOG_RUNTIME_FMT for a runtime (non-literal) format string. - ICEBERG_LOG_ACTIVE_LEVEL is a compile-time severity floor: statements below it are removed entirely via `if constexpr` (no format call site, no source location emitted). ICEBERG_LOG_FATAL is never gated by the floor -- its abort is always compiled in; it emits, best-effort Flush()es the same logger it emitted to, then std::abort(). - Filtering is decided solely by Logger::ShouldLog(); formatting is wrapped in try/catch so logging never throws (a format failure routes to EmitFormatError). - Bare Java-style aliases (LOG_INFO, ...) are opt-in via ICEBERG_LOG_SHORT_MACROS to avoid polluting consumers / colliding with glog/abseil. Header-only addition to logger.h. macros_test covers injection, the guard-before-format short-circuit, never-throws, and FATAL aborts; macros_active_level_test verifies compile-time stripping in a kOff translation unit. Co-authored-by: Isaac
1 parent d3237ab commit 0942681

6 files changed

Lines changed: 388 additions & 5 deletions

File tree

‎meson.build‎

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -31,7 +31,9 @@ project(
3131
)
3232

3333
cpp = meson.get_compiler('cpp')
34-
args = cpp.get_supported_arguments(['/bigobj'])
34+
# /Zc:preprocessor: MSVC's conforming preprocessor, required for the __VA_OPT__
35+
# used by the logging macros. get_supported_arguments drops it on non-MSVC.
36+
args = cpp.get_supported_arguments(['/bigobj', '/Zc:preprocessor'])
3537
add_project_arguments(args, language: 'cpp')
3638

3739
subdir('src')

‎src/iceberg/logging/logger.h‎

Lines changed: 174 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -127,8 +127,8 @@ class ICEBERG_EXPORT LogMessage::Builder {
127127
/// \brief Well-known Logger::Initialize() property keys.
128128
///
129129
/// `level` is honored by the base Logger::Initialize (parsed via
130-
/// LogLevelFromString). `pattern` is honored by the formatting sinks
131-
/// (CerrLogger, SpdLogger).
130+
/// LogLevelFromString) on every backend. `pattern` is honored only by the
131+
/// spdlog backend; CerrLogger uses a fixed layout and ignores it.
132132
inline constexpr std::string_view kLevelProperty = "level";
133133
inline constexpr std::string_view kPatternProperty = "pattern";
134134

@@ -371,3 +371,175 @@ void Log(Logger& logger, LogLevel level,
371371
}
372372

373373
} // namespace iceberg
374+
375+
// ---------------------------------------------------------------------------
376+
// Logging macros.
377+
//
378+
// Every macro takes a std::format string followed by its arguments. The
379+
// rendered line depends on the active backend (see cerr_logger.h for the
380+
// std::cerr layout, or the spdlog pattern); the examples below show the call
381+
// site and, for the default CerrLogger, the line it produces.
382+
//
383+
// ICEBERG_LOG_TRACE("entering scan for {}", table);
384+
// 2026-06-16T10:59:41.186Z trace [12345] table_scan.cc:88] entering scan for db.t
385+
// ICEBERG_LOG_DEBUG("cache miss key={}", key);
386+
// 2026-06-16T10:59:41.186Z debug [12345] cache.cc:42] cache miss key=manifest-7
387+
// ICEBERG_LOG_INFO("loaded {} manifests in {} ms", n, ms);
388+
// 2026-06-16T10:59:41.186Z info [12345] table_scan.cc:91] loaded 5 manifests in 12 ms
389+
// ICEBERG_LOG_WARN("retry {} after {}", attempt, err);
390+
// 2026-06-16T10:59:41.186Z warn [12345] io.cc:51] retry 2 after timeout
391+
// ICEBERG_LOG_ERROR("commit failed: {}", status);
392+
// 2026-06-16T10:59:41.186Z error [12345] txn.cc:77] commit failed: conflict
393+
// ICEBERG_LOG_CRITICAL("metadata unreadable at {}", path);
394+
// 2026-06-16T10:59:41.186Z critical [12345] meta.cc:30] metadata unreadable at s3://b/m.json
395+
// ICEBERG_LOG_FATAL("unrecoverable: {}", reason); // emits, flushes, then std::abort()
396+
// 2026-06-16T10:59:41.186Z fatal [12345] boot.cc:19] unrecoverable: bad config
397+
//
398+
// Less common forms:
399+
// ICEBERG_LOG(level, "level chosen at runtime: {}", x); // runtime severity
400+
// ICEBERG_LOG_TO(logger, level, "to an explicit logger {}", y);
401+
// ICEBERG_LOG_RUNTIME_FMT(level, fmt_string, args...); // non-literal format
402+
//
403+
// With ICEBERG_LOG_SHORT_MACROS defined, bare aliases (LOG_INFO, ...) are also
404+
// available. A format string is mandatory; zero extra args is fine
405+
// (ICEBERG_LOG_INFO("done")).
406+
// ---------------------------------------------------------------------------
407+
408+
/// \brief Compile-time severity floor: statements below this level are removed
409+
/// entirely from the build (their format call sites and source_location literals
410+
/// are never emitted). Defaults to keeping everything. ICEBERG_LOG_FATAL is never
411+
/// gated by this floor -- its abort is always compiled in.
412+
#ifndef ICEBERG_LOG_ACTIVE_LEVEL
413+
# define ICEBERG_LOG_ACTIVE_LEVEL ::iceberg::LogLevel::kTrace
414+
#endif
415+
416+
// Internal: fixed-severity emit with compile-time floor then the authoritative
417+
// Logger::ShouldLog (the single source of truth for runtime filtering), with
418+
// formatting only on the taken path, never throwing.
419+
#define ICEBERG_INTERNAL_LOG(level_, FMT_, ...) \
420+
do { \
421+
if constexpr ((level_) >= ICEBERG_LOG_ACTIVE_LEVEL) { \
422+
const auto& _ib_logger = ::iceberg::internal::CurrentLogger(); \
423+
if (_ib_logger && _ib_logger->ShouldLog(level_)) { \
424+
try { \
425+
::iceberg::internal::Emit(*_ib_logger, (level_), \
426+
::std::source_location::current(), \
427+
::std::format(FMT_ __VA_OPT__(, ) __VA_ARGS__)); \
428+
} catch (...) { \
429+
::iceberg::internal::EmitFormatError(*_ib_logger, (level_), \
430+
::std::source_location::current()); \
431+
} \
432+
} \
433+
} \
434+
} while (0)
435+
436+
#define ICEBERG_LOG_TRACE(...) \
437+
ICEBERG_INTERNAL_LOG(::iceberg::LogLevel::kTrace, __VA_ARGS__)
438+
#define ICEBERG_LOG_DEBUG(...) \
439+
ICEBERG_INTERNAL_LOG(::iceberg::LogLevel::kDebug, __VA_ARGS__)
440+
#define ICEBERG_LOG_INFO(...) \
441+
ICEBERG_INTERNAL_LOG(::iceberg::LogLevel::kInfo, __VA_ARGS__)
442+
#define ICEBERG_LOG_WARN(...) \
443+
ICEBERG_INTERNAL_LOG(::iceberg::LogLevel::kWarn, __VA_ARGS__)
444+
#define ICEBERG_LOG_ERROR(...) \
445+
ICEBERG_INTERNAL_LOG(::iceberg::LogLevel::kError, __VA_ARGS__)
446+
#define ICEBERG_LOG_CRITICAL(...) \
447+
ICEBERG_INTERNAL_LOG(::iceberg::LogLevel::kCritical, __VA_ARGS__)
448+
449+
// FATAL: emit if enabled (never compile-stripped), then ALWAYS flush + abort.
450+
// Acquires the default logger ONCE and uses the same instance for emit and flush
451+
// so a concurrent SetDefaultLogger cannot flush a different logger than it emitted to.
452+
#define ICEBERG_LOG_FATAL(FMT_, ...) \
453+
do { \
454+
auto _ib_logger = ::iceberg::GetDefaultLogger(); \
455+
if (_ib_logger && _ib_logger->ShouldLog(::iceberg::LogLevel::kFatal)) { \
456+
try { \
457+
::iceberg::internal::Emit(*_ib_logger, ::iceberg::LogLevel::kFatal, \
458+
::std::source_location::current(), \
459+
::std::format(FMT_ __VA_OPT__(, ) __VA_ARGS__)); \
460+
} catch (...) { \
461+
::iceberg::internal::EmitFormatError(*_ib_logger, ::iceberg::LogLevel::kFatal, \
462+
::std::source_location::current()); \
463+
} \
464+
} \
465+
if (_ib_logger) _ib_logger->Flush(); \
466+
::std::abort(); \
467+
} while (0)
468+
469+
// Generic, runtime-level form against the default logger. No compile-time floor
470+
// (the level is not a constant). Acquires the logger once; aborts when level == kFatal
471+
// (flushing that same logger first).
472+
#define ICEBERG_LOG(level_, FMT_, ...) \
473+
do { \
474+
const ::iceberg::LogLevel _ib_lvl = (level_); \
475+
const auto& _ib_logger = ::iceberg::internal::CurrentLogger(); \
476+
if (_ib_logger && _ib_logger->ShouldLog(_ib_lvl)) { \
477+
try { \
478+
::iceberg::internal::Emit(*_ib_logger, _ib_lvl, ::std::source_location::current(), \
479+
::std::format(FMT_ __VA_OPT__(, ) __VA_ARGS__)); \
480+
} catch (...) { \
481+
::iceberg::internal::EmitFormatError(*_ib_logger, _ib_lvl, \
482+
::std::source_location::current()); \
483+
} \
484+
} \
485+
if (_ib_lvl == ::iceberg::LogLevel::kFatal) { \
486+
if (_ib_logger) _ib_logger->Flush(); \
487+
::std::abort(); \
488+
} \
489+
} while (0)
490+
491+
// Generic form targeting an EXPLICIT logger (must be an lvalue Logger&). Honors
492+
// only that logger's ShouldLog. Aborts when level == kFatal.
493+
#define ICEBERG_LOG_TO(logger_, level_, FMT_, ...) \
494+
do { \
495+
::iceberg::Logger& _ib_logger = (logger_); \
496+
const ::iceberg::LogLevel _ib_lvl = (level_); \
497+
if (_ib_logger.ShouldLog(_ib_lvl)) { \
498+
try { \
499+
::iceberg::internal::Emit(_ib_logger, _ib_lvl, ::std::source_location::current(), \
500+
::std::format(FMT_ __VA_OPT__(, ) __VA_ARGS__)); \
501+
} catch (...) { \
502+
::iceberg::internal::EmitFormatError(_ib_logger, _ib_lvl, \
503+
::std::source_location::current()); \
504+
} \
505+
} \
506+
if (_ib_lvl == ::iceberg::LogLevel::kFatal) { \
507+
_ib_logger.Flush(); \
508+
::std::abort(); \
509+
} \
510+
} while (0)
511+
512+
// Runtime (non-literal) format string against the default logger. Acquires the
513+
// logger once; aborts when level == kFatal (flushing that same logger first).
514+
#define ICEBERG_LOG_RUNTIME_FMT(level_, FMT_, ...) \
515+
do { \
516+
const ::iceberg::LogLevel _ib_lvl = (level_); \
517+
const auto& _ib_logger = ::iceberg::internal::CurrentLogger(); \
518+
if (_ib_logger && _ib_logger->ShouldLog(_ib_lvl)) { \
519+
try { \
520+
::iceberg::internal::Emit( \
521+
*_ib_logger, _ib_lvl, ::std::source_location::current(), \
522+
::iceberg::internal::VFormat((FMT_)__VA_OPT__(, ) __VA_ARGS__)); \
523+
} catch (...) { \
524+
::iceberg::internal::EmitFormatError(*_ib_logger, _ib_lvl, \
525+
::std::source_location::current()); \
526+
} \
527+
} \
528+
if (_ib_lvl == ::iceberg::LogLevel::kFatal) { \
529+
if (_ib_logger) _ib_logger->Flush(); \
530+
::std::abort(); \
531+
} \
532+
} while (0)
533+
534+
// Bare, Java-style aliases. Opt-IN only (define ICEBERG_LOG_SHORT_MACROS before
535+
// including this header) to avoid colliding with glog/abseil/windows.h in
536+
// consumer translation units. No bare LOG(level) is provided.
537+
#ifdef ICEBERG_LOG_SHORT_MACROS
538+
# define LOG_TRACE(...) ICEBERG_LOG_TRACE(__VA_ARGS__)
539+
# define LOG_DEBUG(...) ICEBERG_LOG_DEBUG(__VA_ARGS__)
540+
# define LOG_INFO(...) ICEBERG_LOG_INFO(__VA_ARGS__)
541+
# define LOG_WARN(...) ICEBERG_LOG_WARN(__VA_ARGS__)
542+
# define LOG_ERROR(...) ICEBERG_LOG_ERROR(__VA_ARGS__)
543+
# define LOG_CRITICAL(...) ICEBERG_LOG_CRITICAL(__VA_ARGS__)
544+
# define LOG_FATAL(...) ICEBERG_LOG_FATAL(__VA_ARGS__)
545+
#endif // ICEBERG_LOG_SHORT_MACROS

‎src/iceberg/test/CMakeLists.txt‎

Lines changed: 6 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -64,7 +64,9 @@ function(add_iceberg_test test_name)
6464
endif()
6565

6666
if(MSVC_TOOLCHAIN)
67-
target_compile_options(${test_name} PRIVATE /bigobj)
67+
# /Zc:preprocessor: conforming preprocessor for the __VA_OPT__ in the logging
68+
# macros (MSVC's traditional preprocessor rejects it).
69+
target_compile_options(${test_name} PRIVATE /bigobj /Zc:preprocessor)
6870
endif()
6971

7072
add_test(NAME ${test_name} COMMAND ${test_name})
@@ -106,7 +108,9 @@ add_iceberg_test(logging_test
106108
SOURCES
107109
cerr_logger_test.cc
108110
log_level_test.cc
109-
logger_test.cc)
111+
logger_test.cc
112+
macros_active_level_test.cc
113+
macros_test.cc)
110114

111115
add_iceberg_test(expression_test
112116
SOURCES

‎src/iceberg/test/macros_active_level_test.cc‎

Lines changed: 57 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,57 @@
1+
/*
2+
* Licensed to the Apache Software Foundation (ASF) under one
3+
* or more contributor license agreements. See the NOTICE file
4+
* distributed with this work for additional information
5+
* regarding copyright ownership. The ASF licenses this file
6+
* to you under the Apache License, Version 2.0 (the
7+
* "License"); you may not use this file except in compliance
8+
* with the License. You may obtain a copy of the License at
9+
*
10+
* http://www.apache.org/licenses/LICENSE-2.0
11+
*
12+
* Unless required by applicable law or agreed to in writing,
13+
* software distributed under the License is distributed on an
14+
* "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
15+
* KIND, either express or implied. See the License for the
16+
* specific language governing permissions and limitations
17+
* under the License.
18+
*/
19+
20+
// Compile-time floor set to kOff for this translation unit: every fixed-severity
21+
// macro below kFatal must be stripped to nothing, while ICEBERG_LOG_FATAL must
22+
// still abort (its abort is never gated by the compile-time floor).
23+
#define ICEBERG_LOG_ACTIVE_LEVEL ::iceberg::LogLevel::kOff
24+
25+
#include <memory>
26+
27+
#include <gtest/gtest.h>
28+
29+
#include "iceberg/logging/log_level.h"
30+
#include "iceberg/logging/logger.h"
31+
#include "iceberg/test/logging_test_helpers.h"
32+
33+
namespace iceberg {
34+
35+
TEST(MacrosActiveLevelTest, BelowFloorStatementsAreCompiledOut) {
36+
auto logger = std::make_shared<CapturingLogger>();
37+
logger->SetLevel(LogLevel::kTrace);
38+
ScopedDefaultLogger guard(logger);
39+
40+
int calls = 0;
41+
auto counted = [&calls]() {
42+
++calls;
43+
return 1;
44+
};
45+
// Stripped at compile time -> arguments never evaluated, nothing emitted,
46+
// even though the runtime logger would accept these levels.
47+
ICEBERG_LOG_INFO("{}", counted());
48+
ICEBERG_LOG_CRITICAL("{}", counted());
49+
EXPECT_EQ(calls, 0);
50+
EXPECT_EQ(logger->count(), 0u);
51+
}
52+
53+
TEST(MacrosActiveLevelDeathTest, FatalStillAbortsWhenEverythingElseStripped) {
54+
EXPECT_DEATH({ ICEBERG_LOG_FATAL("still fatal"); }, "");
55+
}
56+
57+
} // namespace iceberg

0 commit comments

Comments
 (0)