From 31f06f57248d98f1bd1a267d319e85bb8be9f04a Mon Sep 17 00:00:00 2001 From: Nanaloveyuki Date: Sun, 14 Jun 2026 12:55:29 +0800 Subject: [PATCH] :bug: fix native file sink lifecycle behavior --- docs/README-en.md | 6 ++- docs/api/configured-logger-close.md | 8 +++- docs/api/configured-logger-file-close.md | 7 +++- docs/api/configured-logger-file-flush.md | 8 +++- docs/api/file-sink-flush.md | 1 + docs/api/global-debug.md | 12 ++++-- docs/api/global-trace.md | 12 ++++-- docs/api/runtime-sink-close.md | 8 +++- docs/api/runtime-sink-file-close.md | 5 ++- docs/api/runtime-sink-file-flush.md | 7 +++- src/BitLogger_test.mbt | 49 ++++++++++++------------ src/BitLogger_wbtest.mbt | 18 +++++++++ src/utils/file_backend_native.mbt | 2 +- src/utils/moon.pkg | 1 + src/utils/stub.c | 5 +++ 15 files changed, 110 insertions(+), 39 deletions(-) create mode 100644 src/utils/stub.c diff --git a/docs/README-en.md b/docs/README-en.md index 791d3fe..615a59c 100644 --- a/docs/README-en.md +++ b/docs/README-en.md @@ -57,7 +57,9 @@ Use `Logger::new(...)` when you want to assemble custom sink graphs directly. ## Documentation -- [API index](./api/index.md) -- [src package README](../src/README.mbt.md) +- [API index](./api/index.md): canonical API reference, organized as one public API per file +- [src package README](../src/README.mbt.md): package-level usage notes and target reminders +- [`docs/changes/`](./changes/): versioned release notes and publish-facing change summaries +- [`docs/dev/`](./dev/): developer reference material, investigations, and temporary implementation notes Common entry points: `text_console(...)`, `file(...)`, `with_queue(...)`, `build_logger(...)`, `build_async_logger(...)` diff --git a/docs/api/configured-logger-close.md b/docs/api/configured-logger-close.md index c2cf7fb..325ef66 100644 --- a/docs/api/configured-logger-close.md +++ b/docs/api/configured-logger-close.md @@ -36,7 +36,9 @@ Detailed rules explaining key parameters and behaviors - This helper delegates directly to `self.sink.close()`. - Plain file sinks forward to `FileSink::close()` through `RuntimeSink`. - Queue-backed file sinks close the wrapped file sink instead of only the queue wrapper. +- Generic `close()` on queued file sinks does not drain pending queue entries first; it closes the wrapped file sink directly. - Console-style sinks and queue-wrapped console-style sinks return `true` as a no-op success because they do not expose a meaningful close step here. +- For file-backed configured loggers, later `close()` calls return `false` after the wrapped file handle has already been cleared. ### How to Use @@ -65,10 +67,14 @@ In this example, callers can branch on the reported close result. e.g.: - If the configured runtime sink shape has no real close action, the helper may still return `true` as a no-op success. +- If the configured logger shares the same wrapped runtime sink state with another facade and one path already closed that file-backed sink, a later close attempt returns `false`. + - If callers need a file-specific close path with queue flush nuances, `file_close()` may be the better API. ### Notes 1. This is the generic configured runtime close helper. -2. Prefer file-specific helpers when the configured sink shape is known to be file-backed. +2. Prefer `file_close()` when the configured sink shape is file-backed and queued records should be flushed before teardown. + +3. Converting the same configured logger through wrapper paths such as library projection still shares the wrapped runtime sink state, so close effects are visible across those facades. diff --git a/docs/api/configured-logger-file-close.md b/docs/api/configured-logger-file-close.md index 92c8584..9749780 100644 --- a/docs/api/configured-logger-file-close.md +++ b/docs/api/configured-logger-file-close.md @@ -37,6 +37,7 @@ Detailed rules explaining key parameters and behaviors - Queued file sinks flush queue work before closing the wrapped inner file sink. - Non-file sinks return `false`. - This helper is narrower than generic `close()` because it specifically targets file sink shutdown. +- After a file-backed configured logger has already cleared its file handle, later `file_close()` calls return `false`. ### How to Use @@ -65,10 +66,14 @@ In this example, the result describes file close behavior rather than generic si e.g.: - If the configured sink is not file-backed, the method returns `false`. +- If the file handle was already closed earlier through this logger or another facade sharing the same wrapped runtime sink state, the method returns `false`. + - If callers only need generic sink teardown, `close()` is the broader API. ### Notes 1. Prefer this helper when file-backed runtime behavior matters specifically. -2. Queued file sinks may flush pending records before closing the file. +2. Queued file sinks flush pending records before closing the file, unlike generic `close()`. + +3. Library or application facades derived from the same configured runtime logger still observe the same underlying file-close state. diff --git a/docs/api/configured-logger-file-flush.md b/docs/api/configured-logger-file-flush.md index dadbd5f..6da4461 100644 --- a/docs/api/configured-logger-file-flush.md +++ b/docs/api/configured-logger-file-flush.md @@ -2,7 +2,7 @@ name: configured-logger-file-flush group: api category: runtime -update-time: 20260512 +update-time: 20260614 description: Flush the file sink behind a configured runtime logger when one is present. key-word: - logger @@ -35,9 +35,11 @@ Detailed rules explaining key parameters and behaviors - Plain file sinks forward directly to file flush behavior through the wrapped `RuntimeSink`. - Queued file sinks first flush queued records, then flush the wrapped inner file sink. +- For queued file sinks, the returned `Bool` comes from the inner file flush rather than the queue flush step. - For queued file sinks, this step may also be the point where queued records finally hit the inner file sink, so write-failure counters can change here even if earlier log calls only queued records. - Non-file sinks return `false`. - This helper is narrower than generic `flush()` because it targets file sink behavior specifically. +- After a file-backed configured logger has already cleared its file handle, later `file_flush()` calls return `false`. ### How to Use @@ -66,6 +68,8 @@ In this example, callers can distinguish file flush success from a non-file sink e.g.: - If the configured sink is not file-backed, the method returns `false`. +- If the file handle was already closed earlier through this logger or another facade sharing the same wrapped runtime sink state, the method returns `false`. + - If callers want generic queue or sink advancement instead of file-specific behavior, `flush()` is the broader API. ### Notes @@ -73,3 +77,5 @@ e.g.: 1. Prefer this helper when the configured sink is known to be file-backed. 2. Queued file sinks may perform both queue flush and file flush work here, including surfacing delayed write failures from previously queued records. + +3. Library or application facades derived from the same configured runtime logger still observe the same underlying file-flush availability state. diff --git a/docs/api/file-sink-flush.md b/docs/api/file-sink-flush.md index c259f94..7618a65 100644 --- a/docs/api/file-sink-flush.md +++ b/docs/api/file-sink-flush.md @@ -37,6 +37,7 @@ Detailed rules explaining key parameters and behaviors - On flush failure, `flush_failures` is incremented. - On success, failure counters are left unchanged. - This helper does not reopen the sink automatically. +- If another alias already closed the same underlying sink handle, this method also returns `false`. ### How to Use diff --git a/docs/api/global-debug.md b/docs/api/global-debug.md index aa64c50..7200fcb 100644 --- a/docs/api/global-debug.md +++ b/docs/api/global-debug.md @@ -35,7 +35,8 @@ pub fn debug(message : String, fields~ : Array[Field] = []) -> Unit {} Detailed rules explaining key parameters and behaviors - This helper delegates to `default_logger().debug(...)`. -- The record uses the current shared minimum level and target configuration. +- Each call therefore reads the current shared default threshold and target at write time instead of holding one long-lived logger value internally. +- It uses the shared console sink and current default target. - Debug output is typically intended for development and troubleshooting. - This helper is best suited to small apps or code paths that intentionally rely on the shared logger. @@ -48,10 +49,13 @@ Here are some specific examples provided. When code wants quick diagnostics without wiring a logger variable: ```moonbit set_default_min_level(Level::Debug) +set_default_target("cache") debug("cache refreshed") ``` -In this example, the shared global path starts accepting debug records. +In this example, the shared global path starts accepting debug records under the `cache` target. + +If `set_default_target(...)` or `set_default_min_level(...)` changes later, future `debug(...)` calls will observe those updated shared defaults automatically. #### When Attach Structured Debug Context @@ -73,5 +77,7 @@ e.g.: 1. Prefer explicit loggers once application logging becomes subsystem-specific. -2. Use `set_default_min_level(...)` before expecting global debug output to appear. +2. Future calls pick up later shared-default changes because the helper forwards through a fresh `default_logger()` each time. + +3. Use `set_default_min_level(...)` before expecting global debug output to appear. diff --git a/docs/api/global-trace.md b/docs/api/global-trace.md index bda8bc5..5db47b1 100644 --- a/docs/api/global-trace.md +++ b/docs/api/global-trace.md @@ -35,8 +35,9 @@ pub fn trace(message : String, fields~ : Array[Field] = []) -> Unit {} Detailed rules explaining key parameters and behaviors - This helper delegates to `default_logger().trace(...)`. +- Each call therefore reads the current shared default threshold and target at write time instead of holding one long-lived logger value internally. - Trace is the lowest built-in severity and is commonly disabled unless the shared minimum level is lowered. -- The shared default target and console sink are used. +- It uses the shared console sink and current default target. - This helper favors convenience over explicit per-component logger ownership. ### How to Use @@ -48,10 +49,13 @@ Here are some specific examples provided. When a script or small app wants temporary low-level diagnostics: ```moonbit set_default_min_level(Level::Trace) +set_default_target("loop") trace("entered sync loop") ``` -In this example, the shared global path begins accepting trace records. +In this example, the shared global path begins accepting trace records under the `loop` target. + +If `set_default_target(...)` or `set_default_min_level(...)` changes later, future `trace(...)` calls will observe those updated shared defaults automatically. #### When Attach Structured Trace Context @@ -73,5 +77,7 @@ e.g.: 1. Global trace logging is convenient for scripts but easy to overuse in larger systems. -2. This helper always goes through the shared default logger path. +2. Future calls pick up later shared-default changes because the helper forwards through a fresh `default_logger()` each time. + +3. This helper always goes through the shared default logger path. diff --git a/docs/api/runtime-sink-close.md b/docs/api/runtime-sink-close.md index 1308175..9c18423 100644 --- a/docs/api/runtime-sink-close.md +++ b/docs/api/runtime-sink-close.md @@ -36,8 +36,10 @@ Detailed rules explaining key parameters and behaviors - Plain console-style runtime sinks return `true` because they do not have a meaningful close step here. - Plain file runtime sinks forward directly to `FileSink::close()`. - Queued file runtime sinks close the wrapped file sink rather than only the queue wrapper. +- Generic `close()` on `QueuedFile` does not drain or flush queued records first; it closes the inner file sink directly. - Queue-wrapped console-style runtime sinks return `true` as a no-op success. - This method is the direct sink-level API used by `ConfiguredLogger::close(...)`. +- For file-backed runtime sinks, later `close()` calls return `false` after the handle has already been cleared. ### How to Use @@ -66,10 +68,14 @@ In this example, callers can branch on the reported close result. e.g.: - If the runtime sink shape has no real close action, the method may still return `true` as a no-op success. +- If a file-backed runtime sink was already closed earlier through this sink or another facade sharing the same underlying state, a later close attempt returns `false`. + - If callers know they are working with a direct `FileSink`, `FileSink::close()` is the narrower API. ### Notes 1. Use this helper when code is managing a `RuntimeSink` value directly. -2. `ConfiguredLogger::close(...)` is the higher-level wrapper for config-built loggers. +2. Use `file_close()` instead of generic `close()` when queued file sinks should flush pending records before file teardown. + +3. `ConfiguredLogger::close(...)` is the higher-level wrapper for config-built loggers. diff --git a/docs/api/runtime-sink-file-close.md b/docs/api/runtime-sink-file-close.md index c67e751..f4a5529 100644 --- a/docs/api/runtime-sink-file-close.md +++ b/docs/api/runtime-sink-file-close.md @@ -37,6 +37,7 @@ Detailed rules explaining key parameters and behaviors - `QueuedFile` runtime variants first attempt `sink.flush()` on the queue wrapper, then call `sink.sink.close()` on the wrapped file sink. - For `QueuedFile`, the queue flush result is ignored and the returned `Bool` comes from the inner file close. - Non-file runtime variants return `false`. +- After a file-backed runtime sink has already cleared its handle, later `file_close()` calls return `false`. ### How to Use @@ -65,10 +66,12 @@ In this example, the result describes file close behavior rather than generic si e.g.: - If the runtime sink is not file-backed, the method returns `false`. +- If the file handle was already closed earlier through this runtime sink or another facade sharing the same underlying file-backed state, the method returns `false`. + - If callers only need generic sink teardown, `close()` is the broader API. ### Notes 1. Prefer this helper when direct runtime code specifically cares about file-backed shutdown. -2. Queued file sinks may flush pending records before closing the file. +2. Queued file sinks flush pending records before closing the file, unlike generic `close()`. diff --git a/docs/api/runtime-sink-file-flush.md b/docs/api/runtime-sink-file-flush.md index 1e81469..3950727 100644 --- a/docs/api/runtime-sink-file-flush.md +++ b/docs/api/runtime-sink-file-flush.md @@ -2,7 +2,7 @@ name: runtime-sink-file-flush group: api category: runtime -update-time: 20260613 +update-time: 20260614 description: Flush the file sink behind a RuntimeSink when one is present. key-word: - runtime @@ -38,6 +38,7 @@ Detailed rules explaining key parameters and behaviors - For `QueuedFile`, the queue flush result is ignored and the returned `Bool` comes from the inner file flush. - For `QueuedFile`, this step may also be the point where queued records finally reach the inner file sink, so write-failure counters can change here even if earlier `log(...)` calls only enqueued records. - Non-file runtime variants return `false`. +- After a file-backed runtime sink has already cleared its handle, later `file_flush()` calls return `false`. ### How to Use @@ -66,6 +67,8 @@ In this example, callers can distinguish file flush success from a non-file sink e.g.: - If the runtime sink is not file-backed, the method returns `false`. +- If the file handle was already closed earlier through this runtime sink or another facade sharing the same underlying file-backed state, the method returns `false`. + - If callers want generic queue or sink advancement instead of file-specific behavior, `flush()` is the broader API. ### Notes @@ -73,3 +76,5 @@ e.g.: 1. Prefer this helper when direct runtime code specifically cares about file flush behavior. 2. Queued file sinks may perform both queue flush work and file flush work here, including surfacing delayed write failures from previously queued records. + +3. Library or application facades that share the same wrapped file-backed runtime sink still observe the same flush availability state. diff --git a/src/BitLogger_test.mbt b/src/BitLogger_test.mbt index b49b551..7417853 100644 --- a/src/BitLogger_test.mbt +++ b/src/BitLogger_test.mbt @@ -642,24 +642,22 @@ test "configured logger queue helpers stay aligned with runtime sink helpers" { } test "configured logger close stays aligned with runtime sink close" { - let console_logger = build_logger( - LoggerConfig::new( - min_level=Level::Info, - target="config.close.console", - sink=SinkConfig::new(kind=SinkKind::Console), - queue=Some(QueueConfig::new(2, overflow=QueueOverflowPolicy::DropNewest)), - ), + let console_config = LoggerConfig::new( + min_level=Level::Info, + target="config.close.console", + sink=SinkConfig::new(kind=SinkKind::Console), + queue=Some(QueueConfig::new(2, overflow=QueueOverflowPolicy::DropNewest)), ) - let console_sink = console_logger.sink + let console_logger = build_logger(console_config) + let console_sink = build_logger(console_config).sink inspect(console_logger.close() == console_sink.close(), content="true") - let file_logger = build_logger( - LoggerConfig::new( - target="config.close.file", - sink=SinkConfig::new(kind=SinkKind::File, path="config-close.log"), - ), + let file_config = LoggerConfig::new( + target="config.close.file", + sink=SinkConfig::new(kind=SinkKind::File, path="config-close.log"), ) - let file_sink = file_logger.sink + let file_logger = build_logger(file_config) + let file_sink = build_logger(file_config).sink inspect(file_logger.close() == file_sink.close(), content="true") } @@ -1628,20 +1626,18 @@ test "configured logger exposes file flush and close helpers" { } test "configured logger file flush and close stay aligned with runtime sink helpers" { - let file_logger = build_logger( - LoggerConfig::new( - sink=SinkConfig::new(kind=SinkKind::File, path="config-file-helper-delegate.log"), - ), + let file_config = LoggerConfig::new( + sink=SinkConfig::new(kind=SinkKind::File, path="config-file-helper-delegate.log"), ) - let file_sink = file_logger.sink + let file_logger = build_logger(file_config) + let file_sink = build_logger(file_config).sink inspect(file_logger.file_flush() == file_sink.file_flush(), content="true") inspect(file_logger.file_close() == file_sink.file_close(), content="true") - let console_logger = build_logger( - LoggerConfig::new(sink=SinkConfig::new(kind=SinkKind::Console)), - ) - let console_sink = console_logger.sink + let console_config = LoggerConfig::new(sink=SinkConfig::new(kind=SinkKind::Console)) + let console_logger = build_logger(console_config) + let console_sink = build_logger(console_config).sink inspect(console_logger.file_flush() == console_sink.file_flush(), content="true") inspect(console_logger.file_close() == console_sink.file_close(), content="true") @@ -2715,7 +2711,12 @@ test "configured logger projection preserves file runtime helpers through unwrap inspect(full.file_reset_failure_counters() == configured.file_reset_failure_counters(), content="true") inspect(full.file_flush() == configured.file_flush(), content="true") inspect(full.pending_count() == configured.pending_count(), content="true") - inspect(full.file_close() == configured.file_close(), content="true") + + let was_available = configured.file_available() + inspect(configured.file_close() == was_available, content="true") + inspect(full.file_available(), content="false") + inspect(configured.file_available(), content="false") + inspect(full.file_close(), content="false") } test "default library logger mirrors shared sync defaults" { diff --git a/src/BitLogger_wbtest.mbt b/src/BitLogger_wbtest.mbt index 9296aeb..e1dc21a 100644 --- a/src/BitLogger_wbtest.mbt +++ b/src/BitLogger_wbtest.mbt @@ -6,6 +6,24 @@ test "default logger can be reconfigured" { inspect(logger.target, content="global") } +test "default logger snapshots shared defaults at creation time" { + set_default_min_level(Level::Warn) + set_default_target("before") + let before = default_logger() + + set_default_min_level(Level::Debug) + set_default_target("after") + let after = default_logger() + + inspect(before.is_enabled(Level::Error), content="true") + inspect(before.is_enabled(Level::Info), content="false") + inspect(before.target, content="before") + + inspect(after.is_enabled(Level::Error), content="true") + inspect(after.is_enabled(Level::Info), content="true") + inspect(after.target, content="after") +} + test "logger can enable timestamps" { let logger = Logger::new(console_sink(), min_level=Level::Info, target="time") .with_timestamp() diff --git a/src/utils/file_backend_native.mbt b/src/utils/file_backend_native.mbt index dde4854..1a04c10 100644 --- a/src/utils/file_backend_native.mbt +++ b/src/utils/file_backend_native.mbt @@ -37,7 +37,7 @@ type NativeFileHandle #borrow(path, mode) extern "C" fn file_open_ffi(path : Bytes, mode : Bytes) -> NativeFileHandle = "fopen" -extern "C" fn file_is_null_ffi(handle : NativeFileHandle) -> Bool = "moonbitlang_async_pointer_is_null" +extern "C" fn file_is_null_ffi(handle : NativeFileHandle) -> Bool = "bitlogger_pointer_is_null" #borrow(buffer) extern "C" fn file_write_ffi( diff --git a/src/utils/moon.pkg b/src/utils/moon.pkg index 6cda0a0..0ebc5b8 100644 --- a/src/utils/moon.pkg +++ b/src/utils/moon.pkg @@ -7,6 +7,7 @@ import { } options( + "native-stub": [ "stub.c" ], targets: { "file_backend_native.mbt": [ "native", "llvm" ], "file_backend_stub.mbt": [ "js", "wasm", "wasm-gc" ], diff --git a/src/utils/stub.c b/src/utils/stub.c new file mode 100644 index 0000000..eeb17c5 --- /dev/null +++ b/src/utils/stub.c @@ -0,0 +1,5 @@ +#include + +int32_t bitlogger_pointer_is_null(void *ptr) { + return ptr == 0; +}