Skip to content

Commit a655149

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 db7df76 commit a655149

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
@@ -68,8 +68,8 @@ struct LogMessage {
6868
/// \brief Well-known Logger::Initialize() property keys.
6969
///
7070
/// `level` is honored by the base Logger::Initialize (parsed via
71-
/// LogLevelFromString). `pattern` is honored by the formatting sinks
72-
/// (CerrLogger, SpdLogger).
71+
/// LogLevelFromString) on every backend. `pattern` is honored only by the
72+
/// spdlog backend; CerrLogger uses a fixed layout and ignores it.
7373
inline constexpr std::string_view kLevelProperty = "level";
7474
inline constexpr std::string_view kPatternProperty = "pattern";
7575

@@ -211,3 +211,175 @@ std::string VFormat(std::string_view fmt, Args&&... args) {
211211
} // namespace detail
212212

213213
} // namespace iceberg
214+
215+
// ---------------------------------------------------------------------------
216+
// Logging macros.
217+
//
218+
// Every macro takes a std::format string followed by its arguments. The
219+
// rendered line depends on the active backend (see cerr_logger.h for the
220+
// std::cerr layout, or the spdlog pattern); the examples below show the call
221+
// site and, for the default CerrLogger, the line it produces.
222+
//
223+
// ICEBERG_LOG_TRACE("entering scan for {}", table);
224+
// 2026-06-16T10:59:41.186Z trace [12345] table_scan.cc:88] entering scan for db.t
225+
// ICEBERG_LOG_DEBUG("cache miss key={}", key);
226+
// 2026-06-16T10:59:41.186Z debug [12345] cache.cc:42] cache miss key=manifest-7
227+
// ICEBERG_LOG_INFO("loaded {} manifests in {} ms", n, ms);
228+
// 2026-06-16T10:59:41.186Z info [12345] table_scan.cc:91] loaded 5 manifests in 12 ms
229+
// ICEBERG_LOG_WARN("retry {} after {}", attempt, err);
230+
// 2026-06-16T10:59:41.186Z warn [12345] io.cc:51] retry 2 after timeout
231+
// ICEBERG_LOG_ERROR("commit failed: {}", status);
232+
// 2026-06-16T10:59:41.186Z error [12345] txn.cc:77] commit failed: conflict
233+
// ICEBERG_LOG_CRITICAL("metadata unreadable at {}", path);
234+
// 2026-06-16T10:59:41.186Z critical [12345] meta.cc:30] metadata unreadable at s3://b/m.json
235+
// ICEBERG_LOG_FATAL("unrecoverable: {}", reason); // emits, flushes, then std::abort()
236+
// 2026-06-16T10:59:41.186Z fatal [12345] boot.cc:19] unrecoverable: bad config
237+
//
238+
// Less common forms:
239+
// ICEBERG_LOG(level, "level chosen at runtime: {}", x); // runtime severity
240+
// ICEBERG_LOG_TO(logger, level, "to an explicit logger {}", y);
241+
// ICEBERG_LOG_RUNTIME_FMT(level, fmt_string, args...); // non-literal format
242+
//
243+
// With ICEBERG_LOG_SHORT_MACROS defined, bare aliases (LOG_INFO, ...) are also
244+
// available. A format string is mandatory; zero extra args is fine
245+
// (ICEBERG_LOG_INFO("done")).
246+
// ---------------------------------------------------------------------------
247+
248+
/// \brief Compile-time severity floor: statements below this level are removed
249+
/// entirely from the build (their format call sites and source_location literals
250+
/// are never emitted). Defaults to keeping everything. ICEBERG_LOG_FATAL is never
251+
/// gated by this floor -- its abort is always compiled in.
252+
#ifndef ICEBERG_LOG_ACTIVE_LEVEL
253+
# define ICEBERG_LOG_ACTIVE_LEVEL ::iceberg::LogLevel::kTrace
254+
#endif
255+
256+
// Internal: fixed-severity emit with compile-time floor then the authoritative
257+
// Logger::ShouldLog (the single source of truth for runtime filtering), with
258+
// formatting only on the taken path, never throwing.
259+
#define ICEBERG_INTERNAL_LOG(level_, FMT_, ...) \
260+
do { \
261+
if constexpr ((level_) >= ICEBERG_LOG_ACTIVE_LEVEL) { \
262+
const auto& _ib_logger = ::iceberg::detail::CurrentLogger(); \
263+
if (_ib_logger && _ib_logger->ShouldLog(level_)) { \
264+
try { \
265+
::iceberg::detail::Emit(*_ib_logger, (level_), \
266+
::std::source_location::current(), \
267+
::std::format(FMT_ __VA_OPT__(, ) __VA_ARGS__)); \
268+
} catch (...) { \
269+
::iceberg::detail::EmitFormatError(*_ib_logger, (level_), \
270+
::std::source_location::current()); \
271+
} \
272+
} \
273+
} \
274+
} while (0)
275+
276+
#define ICEBERG_LOG_TRACE(...) \
277+
ICEBERG_INTERNAL_LOG(::iceberg::LogLevel::kTrace, __VA_ARGS__)
278+
#define ICEBERG_LOG_DEBUG(...) \
279+
ICEBERG_INTERNAL_LOG(::iceberg::LogLevel::kDebug, __VA_ARGS__)
280+
#define ICEBERG_LOG_INFO(...) \
281+
ICEBERG_INTERNAL_LOG(::iceberg::LogLevel::kInfo, __VA_ARGS__)
282+
#define ICEBERG_LOG_WARN(...) \
283+
ICEBERG_INTERNAL_LOG(::iceberg::LogLevel::kWarn, __VA_ARGS__)
284+
#define ICEBERG_LOG_ERROR(...) \
285+
ICEBERG_INTERNAL_LOG(::iceberg::LogLevel::kError, __VA_ARGS__)
286+
#define ICEBERG_LOG_CRITICAL(...) \
287+
ICEBERG_INTERNAL_LOG(::iceberg::LogLevel::kCritical, __VA_ARGS__)
288+
289+
// FATAL: emit if enabled (never compile-stripped), then ALWAYS flush + abort.
290+
// Acquires the default logger ONCE and uses the same instance for emit and flush
291+
// so a concurrent SetDefaultLogger cannot flush a different logger than it emitted to.
292+
#define ICEBERG_LOG_FATAL(FMT_, ...) \
293+
do { \
294+
auto _ib_logger = ::iceberg::GetDefaultLogger(); \
295+
if (_ib_logger && _ib_logger->ShouldLog(::iceberg::LogLevel::kFatal)) { \
296+
try { \
297+
::iceberg::detail::Emit(*_ib_logger, ::iceberg::LogLevel::kFatal, \
298+
::std::source_location::current(), \
299+
::std::format(FMT_ __VA_OPT__(, ) __VA_ARGS__)); \
300+
} catch (...) { \
301+
::iceberg::detail::EmitFormatError(*_ib_logger, ::iceberg::LogLevel::kFatal, \
302+
::std::source_location::current()); \
303+
} \
304+
} \
305+
if (_ib_logger) _ib_logger->Flush(); \
306+
::std::abort(); \
307+
} while (0)
308+
309+
// Generic, runtime-level form against the default logger. No compile-time floor
310+
// (the level is not a constant). Acquires the logger once; aborts when level == kFatal
311+
// (flushing that same logger first).
312+
#define ICEBERG_LOG(level_, FMT_, ...) \
313+
do { \
314+
const ::iceberg::LogLevel _ib_lvl = (level_); \
315+
const auto& _ib_logger = ::iceberg::detail::CurrentLogger(); \
316+
if (_ib_logger && _ib_logger->ShouldLog(_ib_lvl)) { \
317+
try { \
318+
::iceberg::detail::Emit(*_ib_logger, _ib_lvl, ::std::source_location::current(), \
319+
::std::format(FMT_ __VA_OPT__(, ) __VA_ARGS__)); \
320+
} catch (...) { \
321+
::iceberg::detail::EmitFormatError(*_ib_logger, _ib_lvl, \
322+
::std::source_location::current()); \
323+
} \
324+
} \
325+
if (_ib_lvl == ::iceberg::LogLevel::kFatal) { \
326+
if (_ib_logger) _ib_logger->Flush(); \
327+
::std::abort(); \
328+
} \
329+
} while (0)
330+
331+
// Generic form targeting an EXPLICIT logger (must be an lvalue Logger&). Honors
332+
// only that logger's ShouldLog. Aborts when level == kFatal.
333+
#define ICEBERG_LOG_TO(logger_, level_, FMT_, ...) \
334+
do { \
335+
::iceberg::Logger& _ib_logger = (logger_); \
336+
const ::iceberg::LogLevel _ib_lvl = (level_); \
337+
if (_ib_logger.ShouldLog(_ib_lvl)) { \
338+
try { \
339+
::iceberg::detail::Emit(_ib_logger, _ib_lvl, ::std::source_location::current(), \
340+
::std::format(FMT_ __VA_OPT__(, ) __VA_ARGS__)); \
341+
} catch (...) { \
342+
::iceberg::detail::EmitFormatError(_ib_logger, _ib_lvl, \
343+
::std::source_location::current()); \
344+
} \
345+
} \
346+
if (_ib_lvl == ::iceberg::LogLevel::kFatal) { \
347+
_ib_logger.Flush(); \
348+
::std::abort(); \
349+
} \
350+
} while (0)
351+
352+
// Runtime (non-literal) format string against the default logger. Acquires the
353+
// logger once; aborts when level == kFatal (flushing that same logger first).
354+
#define ICEBERG_LOG_RUNTIME_FMT(level_, FMT_, ...) \
355+
do { \
356+
const ::iceberg::LogLevel _ib_lvl = (level_); \
357+
const auto& _ib_logger = ::iceberg::detail::CurrentLogger(); \
358+
if (_ib_logger && _ib_logger->ShouldLog(_ib_lvl)) { \
359+
try { \
360+
::iceberg::detail::Emit( \
361+
*_ib_logger, _ib_lvl, ::std::source_location::current(), \
362+
::iceberg::detail::VFormat((FMT_)__VA_OPT__(, ) __VA_ARGS__)); \
363+
} catch (...) { \
364+
::iceberg::detail::EmitFormatError(*_ib_logger, _ib_lvl, \
365+
::std::source_location::current()); \
366+
} \
367+
} \
368+
if (_ib_lvl == ::iceberg::LogLevel::kFatal) { \
369+
if (_ib_logger) _ib_logger->Flush(); \
370+
::std::abort(); \
371+
} \
372+
} while (0)
373+
374+
// Bare, Java-style aliases. Opt-IN only (define ICEBERG_LOG_SHORT_MACROS before
375+
// including this header) to avoid colliding with glog/abseil/windows.h in
376+
// consumer translation units. No bare LOG(level) is provided.
377+
#ifdef ICEBERG_LOG_SHORT_MACROS
378+
# define LOG_TRACE(...) ICEBERG_LOG_TRACE(__VA_ARGS__)
379+
# define LOG_DEBUG(...) ICEBERG_LOG_DEBUG(__VA_ARGS__)
380+
# define LOG_INFO(...) ICEBERG_LOG_INFO(__VA_ARGS__)
381+
# define LOG_WARN(...) ICEBERG_LOG_WARN(__VA_ARGS__)
382+
# define LOG_ERROR(...) ICEBERG_LOG_ERROR(__VA_ARGS__)
383+
# define LOG_CRITICAL(...) ICEBERG_LOG_CRITICAL(__VA_ARGS__)
384+
# define LOG_FATAL(...) ICEBERG_LOG_FATAL(__VA_ARGS__)
385+
#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)