diff --git a/src-async/BitLoggerAsync_test.mbt b/src-async/BitLoggerAsync_test.mbt index 2dde1f7..0a08f7b 100644 --- a/src-async/BitLoggerAsync_test.mbt +++ b/src-async/BitLoggerAsync_test.mbt @@ -91,6 +91,485 @@ async test "shutdown clear closes without worker startup" { inspect(logger.dropped_count(), content="1") } +async test "closed blocking logger does not add pending count on later log attempts" { + let logger = async_logger( + @bitlogger.callback_sink(fn(_) { + + }), + config=AsyncLoggerConfig::new( + max_pending=2, + overflow=AsyncOverflowPolicy::Blocking, + ), + min_level=@bitlogger.Level::Info, + target="async.closed.blocking", + ) + + logger.info("one") + logger.close(clear=true) + inspect(logger.pending_count(), content="0") + inspect(logger.dropped_count(), content="1") + + logger.info("late") + inspect(logger.pending_count(), content="0") + inspect(logger.dropped_count(), content="1") +} + +async test "closed logger runtime determines whether later log reaches patch path" { + let patched : Ref[Int] = Ref(0) + let logger = async_logger( + @bitlogger.callback_sink(fn(_) { + + }), + config=AsyncLoggerConfig::new( + max_pending=2, + overflow=AsyncOverflowPolicy::Blocking, + ), + min_level=@bitlogger.Level::Info, + target="async.closed.patch", + ).with_patch(fn(rec) { + patched.val += 1 + rec + }) + + logger.info("one") + inspect(patched.val, content="1") + logger.close(clear=true) + inspect(logger.pending_count(), content="0") + inspect(logger.dropped_count(), content="1") + + logger.info("late") + inspect( + patched.val, + content=if async_runtime_supports_background_worker() { "2" } else { "1" }, + ) + inspect(logger.pending_count(), content="0") + inspect(logger.dropped_count(), content="1") +} + +async test "async logger with_filter composes and leaves base logger unchanged" { + let written_targets : Ref[Array[String]] = Ref([]) + let written_messages : Ref[Array[String]] = Ref([]) + let base = async_logger( + @bitlogger.callback_sink(fn(rec) { + written_targets.val.push(rec.target) + written_messages.val.push(rec.message) + }), + config=AsyncLoggerConfig::new(max_pending=4), + min_level=@bitlogger.Level::Trace, + target="service", + ) + let filtered = base.with_filter(@bitlogger.all_of([ + @bitlogger.target_has_prefix("service.api"), + @bitlogger.level_at_least(@bitlogger.Level::Info), + @bitlogger.message_contains("visible"), + ])) + + @async.with_task_group(group => { + group.spawn_bg(() => filtered.run()) + filtered.debug("visible debug") + filtered.info("hidden info") + filtered.child("api").info("visible info") + filtered.shutdown() + }) + + inspect(written_messages.val.length(), content="1") + inspect(written_messages.val[0], content="visible info") + inspect(written_targets.val[0], content="service.api") + + let base_written : Ref[Array[String]] = Ref([]) + let untouched = async_logger( + @bitlogger.callback_sink(fn(rec) { + base_written.val.push(rec.message) + }), + config=AsyncLoggerConfig::new(max_pending=4), + min_level=@bitlogger.Level::Info, + target="base", + ) + ignore(untouched.with_filter(fn(_) { false })) + + @async.with_task_group(group => { + group.spawn_bg(() => untouched.run()) + untouched.info("base still writes") + untouched.shutdown() + }) + + inspect(base_written.val.length(), content="1") + inspect(base_written.val[0], content="base still writes") +} + +async test "async logger with_patch composes before filter and does not mutate base logger" { + let captured_target : Ref[String] = Ref("") + let captured_message : Ref[String] = Ref("") + let captured_fields : Ref[Array[@bitlogger.Field]] = Ref([]) + let logger = async_logger( + @bitlogger.callback_sink(fn(rec) { + captured_target.val = rec.target + captured_message.val = rec.message + captured_fields.val = rec.fields + }), + config=AsyncLoggerConfig::new(max_pending=4), + min_level=@bitlogger.Level::Info, + target="auth", + ) + .with_patch(@bitlogger.compose_patches([ + @bitlogger.set_target("audit.auth"), + @bitlogger.prefix_message("[safe] "), + @bitlogger.redact_field("token"), + @bitlogger.append_fields([@bitlogger.field("service", "bitlogger")]), + ])) + .with_filter(@bitlogger.target_is("audit.auth")) + + @async.with_task_group(group => { + group.spawn_bg(() => logger.run()) + logger.info("login", fields=[@bitlogger.field("token", "secret"), @bitlogger.field("user", "alice")]) + logger.shutdown() + }) + + inspect(captured_target.val, content="audit.auth") + inspect(captured_message.val, content="[safe] login") + inspect(captured_fields.val.length(), content="3") + inspect(captured_fields.val[0].key, content="token") + inspect(captured_fields.val[0].value, content="***") + inspect(captured_fields.val[1].key, content="user") + inspect(captured_fields.val[1].value, content="alice") + inspect(captured_fields.val[2].key, content="service") + inspect(captured_fields.val[2].value, content="bitlogger") + + let base_message : Ref[String] = Ref("") + let base_target : Ref[String] = Ref("") + let base_fields : Ref[Array[@bitlogger.Field]] = Ref([]) + let base = async_logger( + @bitlogger.callback_sink(fn(rec) { + base_message.val = rec.message + base_target.val = rec.target + base_fields.val = rec.fields + }), + config=AsyncLoggerConfig::new(max_pending=4), + min_level=@bitlogger.Level::Info, + target="auth", + ) + ignore(base.with_patch(@bitlogger.prefix_message("[safe] "))) + + @async.with_task_group(group => { + group.spawn_bg(() => base.run()) + base.info("plain", fields=[@bitlogger.field("token", "secret")]) + base.shutdown() + }) + + inspect(base_target.val, content="auth") + inspect(base_message.val, content="plain") + inspect(base_fields.val.length(), content="1") + inspect(base_fields.val[0].value, content="secret") +} + +async test "async logger with_min_level only affects derived logger threshold" { + let base_written : Ref[Array[String]] = Ref([]) + let derived_written : Ref[Array[String]] = Ref([]) + let base = async_logger( + @bitlogger.callback_sink(fn(rec) { + base_written.val.push(rec.message) + }), + config=AsyncLoggerConfig::new(max_pending=4), + min_level=@bitlogger.Level::Info, + target="level.base", + ) + let derived = async_logger( + @bitlogger.callback_sink(fn(rec) { + derived_written.val.push(rec.message) + }), + config=AsyncLoggerConfig::new(max_pending=4), + min_level=@bitlogger.Level::Info, + target="level.derived", + ).with_min_level(@bitlogger.Level::Error) + + inspect(base.is_enabled(@bitlogger.Level::Info), content="true") + inspect(derived.is_enabled(@bitlogger.Level::Info), content="false") + inspect(derived.is_enabled(@bitlogger.Level::Error), content="true") + + @async.with_task_group(group => { + group.spawn_bg(() => base.run()) + group.spawn_bg(() => derived.run()) + base.info("base info") + derived.info("derived info skipped") + derived.error("derived error kept") + base.shutdown() + derived.shutdown() + }) + + inspect(base_written.val.length(), content="1") + inspect(base_written.val[0], content="base info") + inspect(derived_written.val.length(), content="1") + inspect(derived_written.val[0], content="derived error kept") +} + +async test "async logger with_target replaces default target without mutating base logger" { + let written_targets : Ref[Array[String]] = Ref([]) + let logger = async_logger( + @bitlogger.callback_sink(fn(rec) { + written_targets.val.push(rec.target) + }), + config=AsyncLoggerConfig::new(max_pending=4), + min_level=@bitlogger.Level::Warn, + target="async.base", + ).with_timestamp() + let retargeted = logger.with_target("async.retarget") + + inspect(logger.target, content="async.base") + inspect(retargeted.target, content="async.retarget") + inspect(logger.timestamp, content="true") + inspect(retargeted.timestamp, content="true") + + @async.with_task_group(group => { + group.spawn_bg(() => retargeted.run()) + retargeted.error("retargeted") + retargeted.shutdown() + }) + + inspect(written_targets.val.length(), content="1") + inspect(written_targets.val[0], content="async.retarget") + + let base_targets : Ref[Array[String]] = Ref([]) + let base = async_logger( + @bitlogger.callback_sink(fn(rec) { + base_targets.val.push(rec.target) + }), + config=AsyncLoggerConfig::new(max_pending=4), + min_level=@bitlogger.Level::Warn, + target="async.base", + ) + ignore(base.with_target("async.retarget")) + + @async.with_task_group(group => { + group.spawn_bg(() => base.run()) + base.error("base") + base.shutdown() + }) + + inspect(base_targets.val.length(), content="1") + inspect(base_targets.val[0], content="async.base") +} + +async test "async logger with_context_fields prepends shared fields without mutating base logger" { + let written_fields : Ref[Array[@bitlogger.Field]] = Ref([]) + let logger = async_logger( + @bitlogger.callback_sink(fn(rec) { + written_fields.val = rec.fields + }), + config=AsyncLoggerConfig::new(max_pending=4), + min_level=@bitlogger.Level::Warn, + target="async.ctx", + ) + let contextual = logger.with_context_fields([ + @bitlogger.field("service", "bitlogger"), + @bitlogger.field("scope", "sdk"), + ]) + + inspect(logger.context_fields.length(), content="0") + inspect(contextual.context_fields.length(), content="2") + + @async.with_task_group(group => { + group.spawn_bg(() => contextual.run()) + contextual.error("ctx", fields=[@bitlogger.field("mode", "test")]) + contextual.shutdown() + }) + + inspect(written_fields.val.length(), content="3") + inspect(written_fields.val[0].key, content="service") + inspect(written_fields.val[0].value, content="bitlogger") + inspect(written_fields.val[1].key, content="scope") + inspect(written_fields.val[1].value, content="sdk") + inspect(written_fields.val[2].key, content="mode") + inspect(written_fields.val[2].value, content="test") +} + +async test "async logger child composes target and preserves other state" { + let written_target : Ref[String] = Ref("") + let written_timestamp : Ref[UInt64] = Ref(0UL) + let logger = async_logger( + @bitlogger.callback_sink(fn(rec) { + written_target.val = rec.target + written_timestamp.val = rec.timestamp_ms + }), + config=AsyncLoggerConfig::new(max_pending=4), + min_level=@bitlogger.Level::Warn, + target="sdk", + ).with_timestamp() + let child = logger.child("worker") + + inspect(logger.target, content="sdk") + inspect(child.target, content="sdk.worker") + inspect(child.timestamp, content="true") + inspect(child.is_enabled(@bitlogger.Level::Error), content="true") + inspect(child.is_enabled(@bitlogger.Level::Info), content="false") + + @async.with_task_group(group => { + group.spawn_bg(() => child.run()) + child.error("child") + child.shutdown() + }) + + inspect(written_target.val, content="sdk.worker") + inspect(written_timestamp.val > 0UL, content="true") + + let root_child = async_logger( + @bitlogger.callback_sink(fn(_) { + + }), + config=AsyncLoggerConfig::new(max_pending=4), + min_level=@bitlogger.Level::Info, + target="", + ).child("worker") + inspect(root_child.target, content="worker") + + let keep_parent = async_logger( + @bitlogger.callback_sink(fn(_) { + + }), + config=AsyncLoggerConfig::new(max_pending=4), + min_level=@bitlogger.Level::Info, + target="sdk", + ).child("") + inspect(keep_parent.target, content="sdk") +} + +async test "async logger with_timestamp only affects derived logger timestamp flag" { + let base_timestamp : Ref[UInt64] = Ref(0UL) + let derived_timestamp : Ref[UInt64] = Ref(0UL) + let base = async_logger( + @bitlogger.callback_sink(fn(rec) { + base_timestamp.val = rec.timestamp_ms + }), + config=AsyncLoggerConfig::new(max_pending=4), + min_level=@bitlogger.Level::Warn, + target="async.ts.base", + ) + let derived = async_logger( + @bitlogger.callback_sink(fn(rec) { + derived_timestamp.val = rec.timestamp_ms + }), + config=AsyncLoggerConfig::new(max_pending=4), + min_level=@bitlogger.Level::Warn, + target="async.ts.derived", + ).with_timestamp() + + inspect(base.timestamp, content="false") + inspect(derived.timestamp, content="true") + + @async.with_task_group(group => { + group.spawn_bg(() => base.run()) + group.spawn_bg(() => derived.run()) + base.error("base") + derived.error("derived") + base.shutdown() + derived.shutdown() + }) + + inspect(base_timestamp.val, content="0") + inspect(derived_timestamp.val > 0UL, content="true") +} + +async test "async logger log supports per-call target override" { + let written_target : Ref[String] = Ref("") + let written_message : Ref[String] = Ref("") + let written_fields : Ref[Array[@bitlogger.Field]] = Ref([]) + let logger = async_logger( + @bitlogger.callback_sink(fn(rec) { + written_target.val = rec.target + written_message.val = rec.message + written_fields.val = rec.fields + }), + config=AsyncLoggerConfig::new(max_pending=4), + min_level=@bitlogger.Level::Warn, + target="async.default", + ).with_context_fields([@bitlogger.field("service", "bitlogger")]) + + @async.with_task_group(group => { + group.spawn_bg(() => logger.run()) + logger.log( + @bitlogger.Level::Error, + "override", + fields=[@bitlogger.field("mode", "test")], + target="async.override", + ) + logger.shutdown() + }) + + inspect(written_target.val, content="async.override") + inspect(written_message.val, content="override") + inspect(written_fields.val.length(), content="2") + inspect(written_fields.val[0].key, content="service") + inspect(written_fields.val[0].value, content="bitlogger") + inspect(written_fields.val[1].key, content="mode") + inspect(written_fields.val[1].value, content="test") + + let second_target : Ref[String] = Ref("") + let second_message : Ref[String] = Ref("") + let second_fields : Ref[Array[@bitlogger.Field]] = Ref([]) + let second = async_logger( + @bitlogger.callback_sink(fn(rec) { + second_target.val = rec.target + second_message.val = rec.message + second_fields.val = rec.fields + }), + config=AsyncLoggerConfig::new(max_pending=4), + min_level=@bitlogger.Level::Warn, + target="async.default", + ).with_context_fields([@bitlogger.field("service", "bitlogger")]) + + @async.with_task_group(group => { + group.spawn_bg(() => second.run()) + second.log(@bitlogger.Level::Error, "default") + second.shutdown() + }) + + inspect(second_target.val, content="async.default") + inspect(second_message.val, content="default") + inspect(second_fields.val.length(), content="1") + inspect(second_fields.val[0].key, content="service") +} + +async test "async logger severity helpers use stored target without override" { + let written_levels : Ref[Array[String]] = Ref([]) + let written_targets : Ref[Array[String]] = Ref([]) + let written_fields : Ref[Array[Array[@bitlogger.Field]]] = Ref([]) + let logger = async_logger( + @bitlogger.callback_sink(fn(rec) { + written_levels.val.push(rec.level.label()) + written_targets.val.push(rec.target) + written_fields.val.push(rec.fields) + }), + config=AsyncLoggerConfig::new(max_pending=4), + min_level=@bitlogger.Level::Info, + target="async.helpers", + ).with_context_fields([@bitlogger.field("service", "bitlogger")]) + + @async.with_task_group(group => { + group.spawn_bg(() => logger.run()) + logger.info("info", fields=[@bitlogger.field("mode", "info")]) + logger.warn("warn", fields=[@bitlogger.field("mode", "warn")]) + logger.error("error", fields=[@bitlogger.field("mode", "error")]) + logger.shutdown() + }) + + inspect(written_levels.val.length(), content="3") + inspect(written_levels.val[0], content="INFO") + inspect(written_levels.val[1], content="WARN") + inspect(written_levels.val[2], content="ERROR") + inspect(written_targets.val.length(), content="3") + inspect(written_targets.val[0], content="async.helpers") + inspect(written_targets.val[1], content="async.helpers") + inspect(written_targets.val[2], content="async.helpers") + inspect(written_fields.val[0].length(), content="2") + inspect(written_fields.val[1].length(), content="2") + inspect(written_fields.val[2].length(), content="2") + inspect(written_fields.val[0][0].key, content="service") + inspect(written_fields.val[0][1].value, content="info") + inspect(written_fields.val[1][0].key, content="service") + inspect(written_fields.val[1][1].value, content="warn") + inspect(written_fields.val[2][0].key, content="service") + inspect(written_fields.val[2][1].value, content="error") +} + test "async logger config stringify roundtrips stable fields" { let text = stringify_async_logger_config( AsyncLoggerConfig::new( @@ -117,6 +596,59 @@ test "async logger config stringify roundtrips stable fields" { }, content="Batch") } +test "async logger config parser accepts compatibility aliases" { + let config = parse_async_logger_config_text( + "{\"overflow\":\"DropLatest\",\"flush\":\"None\",\"max_batch\":0,\"linger_ms\":-2}", + ) + inspect(config.max_batch, content="1") + inspect(config.linger_ms, content="0") + inspect(match config.overflow { + AsyncOverflowPolicy::Blocking => "Blocking" + AsyncOverflowPolicy::DropOldest => "DropOldest" + AsyncOverflowPolicy::DropNewest => "DropNewest" + }, content="DropNewest") + inspect(match config.flush { + AsyncFlushPolicy::Never => "Never" + AsyncFlushPolicy::Batch => "Batch" + AsyncFlushPolicy::Shutdown => "Shutdown" + }, content="Never") +} + +async test "async logger config constructor normalizes batch and linger but preserves pending input" { + let config = AsyncLoggerConfig::new( + max_pending=-3, + overflow=AsyncOverflowPolicy::DropNewest, + max_batch=0, + linger_ms=-5, + flush=AsyncFlushPolicy::Batch, + ) + inspect(config.max_pending, content="-3") + inspect(config.max_batch, content="1") + inspect(config.linger_ms, content="0") + inspect(match config.overflow { + AsyncOverflowPolicy::Blocking => "Blocking" + AsyncOverflowPolicy::DropOldest => "DropOldest" + AsyncOverflowPolicy::DropNewest => "DropNewest" + }, content="DropNewest") + inspect(match config.flush { + AsyncFlushPolicy::Never => "Never" + AsyncFlushPolicy::Batch => "Batch" + AsyncFlushPolicy::Shutdown => "Shutdown" + }, content="Batch") + + let logger = async_logger( + @bitlogger.callback_sink(fn(_) { + + }), + config=config, + min_level=@bitlogger.Level::Info, + target="async.config.normalized", + ) + logger.info("one") + inspect(logger.pending_count(), content="0") + inspect(logger.dropped_count(), content="1") +} + test "async build config stringify roundtrips nested logger and async fields" { let text = stringify_async_logger_build_config( AsyncLoggerBuildConfig::new( @@ -154,6 +686,140 @@ test "async build config stringify roundtrips nested logger and async fields" { }, content="Shutdown") } +test "async build config parser fills omitted sections from defaults" { + let config = parse_async_logger_build_config_text("{}") + inspect(config.logger.min_level.label(), content="INFO") + inspect(config.logger.target, content="") + inspect(config.logger.timestamp, content="false") + inspect(match config.logger.sink.kind { + @bitlogger.SinkKind::Console => "Console" + @bitlogger.SinkKind::JsonConsole => "JsonConsole" + @bitlogger.SinkKind::TextConsole => "TextConsole" + @bitlogger.SinkKind::File => "File" + }, content="Console") + inspect(config.logger.queue is None, content="true") + inspect(config.async_config.max_pending, content="0") + inspect(config.async_config.max_batch, content="1") + inspect(config.async_config.linger_ms, content="0") + inspect(match config.async_config.overflow { + AsyncOverflowPolicy::Blocking => "Blocking" + AsyncOverflowPolicy::DropOldest => "DropOldest" + AsyncOverflowPolicy::DropNewest => "DropNewest" + }, content="Blocking") + inspect(match config.async_config.flush { + AsyncFlushPolicy::Never => "Never" + AsyncFlushPolicy::Batch => "Batch" + AsyncFlushPolicy::Shutdown => "Shutdown" + }, content="Never") +} + +test "async json helpers export stable structured shapes" { + let config_json = async_logger_config_to_json( + AsyncLoggerConfig::new( + max_pending=8, + overflow=AsyncOverflowPolicy::DropOldest, + max_batch=3, + linger_ms=25, + flush=AsyncFlushPolicy::Batch, + ), + ) + let config_obj = config_json.as_object().unwrap() + inspect( + @json_parser.stringify(config_json), + content="{\"max_pending\":8,\"max_batch\":3,\"linger_ms\":25,\"overflow\":\"DropOldest\",\"flush\":\"Batch\"}", + ) + inspect(config_obj.get("max_pending").unwrap().as_number().unwrap().to_int(), content="8") + inspect(config_obj.get("max_batch").unwrap().as_number().unwrap().to_int(), content="3") + inspect(config_obj.get("linger_ms").unwrap().as_number().unwrap().to_int(), content="25") + inspect(config_obj.get("overflow").unwrap().as_string().unwrap(), content="DropOldest") + inspect(config_obj.get("flush").unwrap().as_string().unwrap(), content="Batch") + + let build_json = async_logger_build_config_to_json( + AsyncLoggerBuildConfig::new( + logger=@bitlogger.LoggerConfig::new( + min_level=@bitlogger.Level::Warn, + target="async.roundtrip", + timestamp=true, + sink=@bitlogger.SinkConfig::new(kind=@bitlogger.SinkKind::TextConsole), + ), + async_config=AsyncLoggerConfig::new( + max_pending=2, + overflow=AsyncOverflowPolicy::DropNewest, + max_batch=5, + linger_ms=40, + flush=AsyncFlushPolicy::Shutdown, + ), + ), + ) + let build_obj = build_json.as_object().unwrap() + let logger_obj = build_obj.get("logger").unwrap().as_object().unwrap() + let sink_obj = logger_obj.get("sink").unwrap().as_object().unwrap() + let formatter_obj = sink_obj.get("text_formatter").unwrap().as_object().unwrap() + let async_obj = build_obj.get("async_config").unwrap().as_object().unwrap() + + inspect(logger_obj.get("min_level").unwrap().as_string().unwrap(), content="WARN") + inspect(logger_obj.get("target").unwrap().as_string().unwrap(), content="async.roundtrip") + inspect(logger_obj.get("timestamp").unwrap().as_bool().unwrap(), content="true") + inspect(logger_obj.get("queue") is None, content="true") + inspect(sink_obj.get("kind").unwrap().as_string().unwrap(), content="text_console") + inspect(sink_obj.get("path").unwrap().as_string().unwrap(), content="") + inspect(sink_obj.get("append").unwrap().as_bool().unwrap(), content="true") + inspect(sink_obj.get("auto_flush").unwrap().as_bool().unwrap(), content="true") + inspect(formatter_obj.get("show_timestamp").unwrap().as_bool().unwrap(), content="true") + inspect(formatter_obj.get("separator").unwrap().as_string().unwrap(), content=" ") + inspect(formatter_obj.get("field_separator").unwrap().as_string().unwrap(), content=" ") + inspect(formatter_obj.get("template").unwrap().as_string().unwrap(), content="") + inspect(formatter_obj.get("color_mode").unwrap().as_string().unwrap(), content="never") + inspect(formatter_obj.get("color_support").unwrap().as_string().unwrap(), content="truecolor") + inspect(formatter_obj.get("style_markup").unwrap().as_string().unwrap(), content="full") + inspect(async_obj.get("max_pending").unwrap().as_number().unwrap().to_int(), content="2") + inspect(async_obj.get("max_batch").unwrap().as_number().unwrap().to_int(), content="5") + inspect(async_obj.get("linger_ms").unwrap().as_number().unwrap().to_int(), content="40") + inspect(async_obj.get("overflow").unwrap().as_string().unwrap(), content="DropNewest") + inspect(async_obj.get("flush").unwrap().as_string().unwrap(), content="Shutdown") +} + +test "async build config json export materializes parsed omitted defaults" { + let parsed = parse_async_logger_build_config_text("{}") + let build_json = async_logger_build_config_to_json(parsed) + let build_obj = build_json.as_object().unwrap() + let logger_obj = build_obj.get("logger").unwrap().as_object().unwrap() + let sink_obj = logger_obj.get("sink").unwrap().as_object().unwrap() + let formatter_obj = sink_obj.get("text_formatter").unwrap().as_object().unwrap() + let async_obj = build_obj.get("async_config").unwrap().as_object().unwrap() + + inspect( + @json_parser.stringify(build_json), + content="{\"logger\":{\"min_level\":\"INFO\",\"target\":\"\",\"timestamp\":false,\"sink\":{\"kind\":\"console\",\"path\":\"\",\"append\":true,\"auto_flush\":true,\"text_formatter\":{\"show_timestamp\":true,\"show_level\":true,\"show_target\":true,\"show_fields\":true,\"separator\":\" \",\"field_separator\":\" \",\"template\":\"\",\"color_mode\":\"never\",\"color_support\":\"truecolor\",\"style_markup\":\"full\",\"target_style_markup\":\"disabled\",\"fields_style_markup\":\"disabled\"}}},\"async_config\":{\"max_pending\":0,\"max_batch\":1,\"linger_ms\":0,\"overflow\":\"Blocking\",\"flush\":\"Never\"}}", + ) + inspect(logger_obj.get("min_level").unwrap().as_string().unwrap(), content="INFO") + inspect(logger_obj.get("target").unwrap().as_string().unwrap(), content="") + inspect(logger_obj.get("timestamp").unwrap().as_bool().unwrap(), content="false") + inspect(logger_obj.get("queue") is None, content="true") + inspect(sink_obj.get("kind").unwrap().as_string().unwrap(), content="console") + inspect(sink_obj.get("path").unwrap().as_string().unwrap(), content="") + inspect(sink_obj.get("append").unwrap().as_bool().unwrap(), content="true") + inspect(sink_obj.get("auto_flush").unwrap().as_bool().unwrap(), content="true") + inspect(formatter_obj.get("show_timestamp").unwrap().as_bool().unwrap(), content="true") + inspect(formatter_obj.get("show_level").unwrap().as_bool().unwrap(), content="true") + inspect(formatter_obj.get("show_target").unwrap().as_bool().unwrap(), content="true") + inspect(formatter_obj.get("show_fields").unwrap().as_bool().unwrap(), content="true") + inspect(formatter_obj.get("separator").unwrap().as_string().unwrap(), content=" ") + inspect(formatter_obj.get("field_separator").unwrap().as_string().unwrap(), content=" ") + inspect(formatter_obj.get("template").unwrap().as_string().unwrap(), content="") + inspect(formatter_obj.get("color_mode").unwrap().as_string().unwrap(), content="never") + inspect(formatter_obj.get("color_support").unwrap().as_string().unwrap(), content="truecolor") + inspect(formatter_obj.get("style_markup").unwrap().as_string().unwrap(), content="full") + inspect(formatter_obj.get("target_style_markup").unwrap().as_string().unwrap(), content="disabled") + inspect(formatter_obj.get("fields_style_markup").unwrap().as_string().unwrap(), content="disabled") + inspect(formatter_obj.get("style_tags") is None, content="true") + inspect(async_obj.get("max_pending").unwrap().as_number().unwrap().to_int(), content="0") + inspect(async_obj.get("max_batch").unwrap().as_number().unwrap().to_int(), content="1") + inspect(async_obj.get("linger_ms").unwrap().as_number().unwrap().to_int(), content="0") + inspect(async_obj.get("overflow").unwrap().as_string().unwrap(), content="Blocking") + inspect(async_obj.get("flush").unwrap().as_string().unwrap(), content="Never") +} + test "async config parsers reject malformed input" { let invalid_json_error = (fn() -> String raise { ignore(parse_async_logger_config_text("{")) @@ -210,6 +876,14 @@ test "async runtime capability helpers stay consistent" { inspect(async_runtime_supports_background_worker() == worker_supported, content="true") inspect(async_runtime_mode_label(state.mode) == async_runtime_mode_label(mode), content="true") inspect(state.background_worker == worker_supported, content="true") + inspect( + @json_parser.stringify(async_runtime_state_to_json(state)), + content=if worker_supported { + "{\"mode\":\"native_worker\",\"background_worker\":true}" + } else { + "{\"mode\":\"compatibility\",\"background_worker\":false}" + }, + ) inspect( stringify_async_runtime_state(state), content=if worker_supported { @@ -255,6 +929,14 @@ test "async logger state snapshot reflects current counters and runtime" { AsyncFlushPolicy::Batch => "Batch" AsyncFlushPolicy::Shutdown => "Shutdown" }, content="Shutdown") + inspect( + @json_parser.stringify(async_logger_state_to_json(state)), + content=if async_runtime_supports_background_worker() { + "{\"runtime\":{\"mode\":\"native_worker\",\"background_worker\":true},\"pending_count\":0,\"dropped_count\":0,\"is_closed\":false,\"is_running\":false,\"has_failed\":false,\"last_error\":\"\",\"flush_policy\":\"Shutdown\"}" + } else { + "{\"runtime\":{\"mode\":\"compatibility\",\"background_worker\":false},\"pending_count\":0,\"dropped_count\":0,\"is_closed\":false,\"is_running\":false,\"has_failed\":false,\"last_error\":\"\",\"flush_policy\":\"Shutdown\"}" + }, + ) inspect( stringify_async_logger_state(state), content=if async_runtime_supports_background_worker() { @@ -332,6 +1014,100 @@ async test "async logger records worker failures and wait_idle stops early" { inspect(logger.pending_count(), content="0") } +async test "later started run resets async failure state before draining remaining backlog" { + let writes : Ref[Int] = Ref(0) + let flushes : Ref[Int] = Ref(0) + let logger = async_logger( + @bitlogger.callback_sink(fn(_) { + writes.val += 1 + }), + config=AsyncLoggerConfig::new( + max_pending=4, + overflow=AsyncOverflowPolicy::Blocking, + flush=AsyncFlushPolicy::Batch, + ), + min_level=@bitlogger.Level::Info, + target="async.retry", + flush=fn(_) -> Int raise { + flushes.val += 1 + if flushes.val == 1 { + raise TestFlushError("flush exploded once") + } + 1 + }, + ) + + @async.with_task_group(group => { + group.spawn_bg(allow_failure=true, () => logger.run()) + logger.info("one") + logger.info("two") + logger.wait_idle() + inspect(logger.has_failed(), content="true") + inspect(logger.last_error().contains("TestFlushError"), content="true") + inspect(logger.is_running(), content="false") + inspect(logger.pending_count(), content="1") + + group.spawn_bg(() => logger.run()) + while !logger.is_running() { + @async.pause() + } + inspect(logger.has_failed(), content="false") + inspect(logger.last_error(), content="") + logger.shutdown() + }) + + inspect(writes.val, content="2") + inspect(flushes.val, content="2") + inspect(logger.has_failed(), content="false") + inspect(logger.last_error(), content="") + inspect(logger.is_running(), content="false") + inspect(logger.is_closed(), content="true") + inspect(logger.pending_count(), content="0") +} + +async test "shutdown after worker failure uses runtime-specific pending cleanup" { + let writes : Ref[Int] = Ref(0) + let logger = async_logger( + @bitlogger.callback_sink(fn(_) { + writes.val += 1 + }), + config=AsyncLoggerConfig::new( + max_pending=4, + overflow=AsyncOverflowPolicy::Blocking, + flush=AsyncFlushPolicy::Batch, + ), + min_level=@bitlogger.Level::Info, + target="async.failure.shutdown", + flush=fn(_) -> Int raise { + raise TestFlushError("flush exploded on shutdown path") + }, + ) + + @async.with_task_group(group => { + group.spawn_bg(allow_failure=true, () => logger.run()) + logger.info("one") + logger.info("two") + logger.wait_idle() + inspect(logger.has_failed(), content="true") + inspect(logger.pending_count(), content="1") + logger.shutdown() + }) + + inspect(logger.is_closed(), content="true") + inspect(logger.has_failed(), content="true") + inspect(logger.last_error().contains("TestFlushError"), content="true") + inspect(logger.is_running(), content="false") + inspect(writes.val, content="1") + inspect( + logger.pending_count(), + content=if async_runtime_supports_background_worker() { "0" } else { "1" }, + ) + inspect( + logger.dropped_count(), + content=if async_runtime_supports_background_worker() { "1" } else { "0" }, + ) +} + async test "library async logger keeps a smaller async facade" { let written_targets : Ref[Array[String]] = Ref([]) let written_messages : Ref[Array[String]] = Ref([]) @@ -359,6 +1135,407 @@ async test "library async logger keeps a smaller async facade" { inspect(written_field_counts.val[0], content="2") } +async test "library async new preserves config and flush failure contract" { + let writes : Ref[Int] = Ref(0) + let flushes : Ref[Int] = Ref(0) + let logger = LibraryAsyncLogger::new( + @bitlogger.callback_sink(fn(_) { + writes.val += 1 + }), + config=AsyncLoggerConfig::new( + max_pending=4, + overflow=AsyncOverflowPolicy::Blocking, + max_batch=3, + linger_ms=7, + flush=AsyncFlushPolicy::Batch, + ), + min_level=@bitlogger.Level::Warn, + target="async.lib.new", + flush=fn(_) -> Int raise { + flushes.val += 1 + raise TestFlushError("library new flush exploded") + }, + ) + let full = logger.to_async_logger() + + inspect(logger.is_enabled(@bitlogger.Level::Error), content="true") + inspect(logger.is_enabled(@bitlogger.Level::Info), content="false") + inspect(full.target, content="async.lib.new") + inspect(match full.flush_policy() { + AsyncFlushPolicy::Never => "Never" + AsyncFlushPolicy::Batch => "Batch" + AsyncFlushPolicy::Shutdown => "Shutdown" + }, content="Batch") + inspect(full.pending_count(), content="0") + inspect(full.has_failed(), content="false") + inspect(full.last_error(), content="") + + logger.info("skip") + inspect(full.pending_count(), content="0") + logger.error("one") + logger.error("two") + inspect(full.pending_count(), content="2") + + @async.with_task_group(group => { + group.spawn_bg(allow_failure=true, () => logger.run()) + full.wait_idle() + while !full.has_failed() && full.is_running() { + @async.pause() + } + inspect(full.has_failed(), content="true") + inspect(full.last_error().contains("TestFlushError"), content="true") + inspect(full.is_running(), content="false") + inspect(full.pending_count(), content="0") + logger.shutdown(clear=true) + }) + + inspect(writes.val, content="2") + inspect(flushes.val, content="1") + inspect(full.is_closed(), content="true") +} + +async test "library async context binding replaces stored field set" { + let written_fields : Ref[Array[@bitlogger.Field]] = Ref([]) + let logger = LibraryAsyncLogger::new( + @bitlogger.callback_sink(fn(rec) { + written_fields.val = rec.fields + }), + config=AsyncLoggerConfig::new(max_pending=4), + min_level=@bitlogger.Level::Warn, + target="async.lib.ctx", + ) + .with_context_fields([@bitlogger.field("old", "gone")]) + .with_context_fields([ + @bitlogger.field("service", "bitlogger"), + @bitlogger.field("scope", "sdk"), + ]) + let full = logger.to_async_logger() + + inspect(logger.is_enabled(@bitlogger.Level::Error), content="true") + inspect(logger.is_enabled(@bitlogger.Level::Info), content="false") + inspect(full.target, content="async.lib.ctx") + inspect(full.timestamp, content="false") + inspect(full.context_fields.length(), content="2") + inspect(full.context_fields[0].key, content="service") + inspect(full.context_fields[0].value, content="bitlogger") + inspect(full.context_fields[1].key, content="scope") + inspect(full.context_fields[1].value, content="sdk") + + @async.with_task_group(group => { + group.spawn_bg(() => logger.run()) + logger.error("ctx", fields=[@bitlogger.field("mode", "test")]) + logger.shutdown() + }) + + inspect(written_fields.val.length(), content="3") + inspect(written_fields.val[0].key, content="service") + inspect(written_fields.val[0].value, content="bitlogger") + inspect(written_fields.val[1].key, content="scope") + inspect(written_fields.val[1].value, content="sdk") + inspect(written_fields.val[2].key, content="mode") + inspect(written_fields.val[2].value, content="test") +} + +async test "library async bind matches context facade contract" { + let written_target : Ref[String] = Ref("") + let written_timestamp : Ref[UInt64] = Ref(0UL) + let written_fields : Ref[Array[@bitlogger.Field]] = Ref([]) + let logger = async_logger( + @bitlogger.callback_sink(fn(rec) { + written_target.val = rec.target + written_timestamp.val = rec.timestamp_ms + written_fields.val = rec.fields + }), + config=AsyncLoggerConfig::new(max_pending=4), + min_level=@bitlogger.Level::Warn, + target="async.lib.bind", + ) + .with_timestamp() + .to_library_async_logger() + .bind([@bitlogger.field("service", "bitlogger")]) + let full = logger.to_async_logger() + + inspect(logger.is_enabled(@bitlogger.Level::Error), content="true") + inspect(logger.is_enabled(@bitlogger.Level::Info), content="false") + inspect(full.target, content="async.lib.bind") + inspect(full.timestamp, content="true") + inspect(full.context_fields.length(), content="1") + inspect(full.context_fields[0].key, content="service") + inspect(full.context_fields[0].value, content="bitlogger") + + @async.with_task_group(group => { + group.spawn_bg(() => logger.run()) + logger.error("bound", fields=[@bitlogger.field("mode", "test")]) + logger.shutdown() + }) + + inspect(written_target.val, content="async.lib.bind") + inspect(written_timestamp.val > 0UL, content="true") + inspect(written_fields.val.length(), content="2") + inspect(written_fields.val[0].key, content="service") + inspect(written_fields.val[0].value, content="bitlogger") + inspect(written_fields.val[1].key, content="mode") + inspect(written_fields.val[1].value, content="test") +} + +async test "library async logger with_target preserves facade state while replacing target" { + let written_target : Ref[String] = Ref("") + let written_timestamp : Ref[UInt64] = Ref(0UL) + let logger = async_logger( + @bitlogger.callback_sink(fn(rec) { + written_target.val = rec.target + written_timestamp.val = rec.timestamp_ms + }), + config=AsyncLoggerConfig::new(max_pending=4), + min_level=@bitlogger.Level::Warn, + target="async.lib.base", + ) + .with_timestamp() + .to_library_async_logger() + .with_target("async.lib.retarget") + let full = logger.to_async_logger() + + inspect(logger.is_enabled(@bitlogger.Level::Error), content="true") + inspect(logger.is_enabled(@bitlogger.Level::Info), content="false") + inspect(full.target, content="async.lib.retarget") + inspect(full.timestamp, content="true") + inspect(full.pending_count(), content="0") + inspect(full.dropped_count(), content="0") + inspect(full.is_closed(), content="false") + inspect(full.is_running(), content="false") + inspect(full.has_failed(), content="false") + inspect(full.last_error(), content="") + + @async.with_task_group(group => { + group.spawn_bg(() => logger.run()) + logger.error("retargeted") + logger.shutdown() + }) + + inspect(written_target.val, content="async.lib.retarget") + inspect(written_timestamp.val > 0UL, content="true") +} + +async test "library async logger child composes target through facade" { + let written_target : Ref[String] = Ref("") + let written_timestamp : Ref[UInt64] = Ref(0UL) + let logger = async_logger( + @bitlogger.callback_sink(fn(rec) { + written_target.val = rec.target + written_timestamp.val = rec.timestamp_ms + }), + config=AsyncLoggerConfig::new(max_pending=4), + min_level=@bitlogger.Level::Warn, + target="sdk", + ) + .with_timestamp() + .to_library_async_logger() + .child("worker") + let full = logger.to_async_logger() + + inspect(full.target, content="sdk.worker") + inspect(full.timestamp, content="true") + inspect(logger.is_enabled(@bitlogger.Level::Error), content="true") + inspect(logger.is_enabled(@bitlogger.Level::Info), content="false") + + @async.with_task_group(group => { + group.spawn_bg(() => logger.run()) + logger.error("child") + logger.shutdown() + }) + + inspect(written_target.val, content="sdk.worker") + inspect(written_timestamp.val > 0UL, content="true") + + let root_child = LibraryAsyncLogger::new( + @bitlogger.callback_sink(fn(_) { + + }), + ).child("worker") + inspect(root_child.to_async_logger().target, content="worker") + + let keep_parent = LibraryAsyncLogger::new( + @bitlogger.callback_sink(fn(_) { + + }), + target="sdk", + ).child("") + inspect(keep_parent.to_async_logger().target, content="sdk") +} + +async test "library async logger log supports per-call target override" { + let written_target : Ref[String] = Ref("") + let written_message : Ref[String] = Ref("") + let written_fields : Ref[Array[@bitlogger.Field]] = Ref([]) + let logger = LibraryAsyncLogger::new( + @bitlogger.callback_sink(fn(rec) { + written_target.val = rec.target + written_message.val = rec.message + written_fields.val = rec.fields + }), + config=AsyncLoggerConfig::new(max_pending=4), + min_level=@bitlogger.Level::Warn, + target="async.lib.default", + ) + .with_context_fields([@bitlogger.field("service", "bitlogger")]) + + @async.with_task_group(group => { + group.spawn_bg(() => logger.run()) + logger.log( + @bitlogger.Level::Error, + "override", + fields=[@bitlogger.field("mode", "test")], + target="async.lib.override", + ) + logger.shutdown() + }) + + inspect(written_target.val, content="async.lib.override") + inspect(written_message.val, content="override") + inspect(written_fields.val.length(), content="2") + inspect(written_fields.val[0].key, content="service") + inspect(written_fields.val[0].value, content="bitlogger") + inspect(written_fields.val[1].key, content="mode") + inspect(written_fields.val[1].value, content="test") + + let second_target : Ref[String] = Ref("") + let second_message : Ref[String] = Ref("") + let second_fields : Ref[Array[@bitlogger.Field]] = Ref([]) + let second = LibraryAsyncLogger::new( + @bitlogger.callback_sink(fn(rec) { + second_target.val = rec.target + second_message.val = rec.message + second_fields.val = rec.fields + }), + config=AsyncLoggerConfig::new(max_pending=4), + min_level=@bitlogger.Level::Warn, + target="async.lib.default", + ) + .with_context_fields([@bitlogger.field("service", "bitlogger")]) + + @async.with_task_group(group => { + group.spawn_bg(() => second.run()) + second.log(@bitlogger.Level::Error, "default") + second.shutdown() + }) + + inspect(second_target.val, content="async.lib.default") + inspect(second_message.val, content="default") + inspect(second_fields.val.length(), content="1") + inspect(second_fields.val[0].key, content="service") +} + +async test "library async severity helpers use stored target without override" { + let written_levels : Ref[Array[String]] = Ref([]) + let written_targets : Ref[Array[String]] = Ref([]) + let written_fields : Ref[Array[Array[@bitlogger.Field]]] = Ref([]) + let logger = LibraryAsyncLogger::new( + @bitlogger.callback_sink(fn(rec) { + written_levels.val.push(rec.level.label()) + written_targets.val.push(rec.target) + written_fields.val.push(rec.fields) + }), + config=AsyncLoggerConfig::new(max_pending=4), + min_level=@bitlogger.Level::Info, + target="async.lib.helpers", + ) + .bind([@bitlogger.field("service", "bitlogger")]) + + @async.with_task_group(group => { + group.spawn_bg(() => logger.run()) + logger.info("info", fields=[@bitlogger.field("mode", "info")]) + logger.warn("warn", fields=[@bitlogger.field("mode", "warn")]) + logger.error("error", fields=[@bitlogger.field("mode", "error")]) + logger.shutdown() + }) + + inspect(written_levels.val.length(), content="3") + inspect(written_levels.val[0], content="INFO") + inspect(written_levels.val[1], content="WARN") + inspect(written_levels.val[2], content="ERROR") + inspect(written_targets.val.length(), content="3") + inspect(written_targets.val[0], content="async.lib.helpers") + inspect(written_targets.val[1], content="async.lib.helpers") + inspect(written_targets.val[2], content="async.lib.helpers") + inspect(written_fields.val[0].length(), content="2") + inspect(written_fields.val[1].length(), content="2") + inspect(written_fields.val[2].length(), content="2") + inspect(written_fields.val[0][0].key, content="service") + inspect(written_fields.val[0][1].value, content="info") + inspect(written_fields.val[1][0].key, content="service") + inspect(written_fields.val[1][1].value, content="warn") + inspect(written_fields.val[2][0].key, content="service") + inspect(written_fields.val[2][1].value, content="error") +} + +async test "library async shutdown preserves wrapped failure cleanup semantics" { + let writes : Ref[Int] = Ref(0) + let logger = LibraryAsyncLogger::new( + @bitlogger.callback_sink(fn(_) { + writes.val += 1 + }), + config=AsyncLoggerConfig::new( + max_pending=4, + overflow=AsyncOverflowPolicy::Blocking, + flush=AsyncFlushPolicy::Batch, + ), + min_level=@bitlogger.Level::Info, + target="async.lib.failure", + flush=fn(_) -> Int raise { + raise TestFlushError("library facade flush exploded") + }, + ) + let full = logger.to_async_logger() + + @async.with_task_group(group => { + group.spawn_bg(allow_failure=true, () => logger.run()) + logger.info("one") + logger.info("two") + full.wait_idle() + inspect(full.has_failed(), content="true") + inspect(full.pending_count(), content="1") + logger.shutdown() + }) + + inspect(full.is_closed(), content="true") + inspect(full.has_failed(), content="true") + inspect(full.last_error().contains("TestFlushError"), content="true") + inspect(full.is_running(), content="false") + inspect(writes.val, content="1") + inspect( + full.pending_count(), + content=if async_runtime_supports_background_worker() { "0" } else { "1" }, + ) + inspect( + full.dropped_count(), + content=if async_runtime_supports_background_worker() { "1" } else { "0" }, + ) +} + +async test "library async shutdown clear abandons pending records through facade" { + let logger = LibraryAsyncLogger::new( + @bitlogger.callback_sink(fn(_) { + + }), + config=AsyncLoggerConfig::new( + max_pending=2, + overflow=AsyncOverflowPolicy::Blocking, + ), + min_level=@bitlogger.Level::Info, + target="async.lib.clear", + ) + let full = logger.to_async_logger() + + logger.info("one") + inspect(full.pending_count(), content="1") + inspect(full.dropped_count(), content="0") + logger.shutdown(clear=true) + inspect(full.is_closed(), content="true") + inspect(full.is_running(), content="false") + inspect(full.pending_count(), content="0") + inspect(full.dropped_count(), content="1") +} + async test "library async logger can be built from config" { let logger = parse_and_build_library_async_logger( "{\"logger\":{\"min_level\":\"warn\",\"target\":\"async.lib.config\",\"sink\":{\"kind\":\"console\"}},\"async_config\":{\"max_pending\":2,\"overflow\":\"DropNewest\",\"max_batch\":1,\"linger_ms\":0,\"flush\":\"Never\"}}", @@ -369,6 +1546,508 @@ async test "library async logger can be built from config" { inspect(full.target, content="async.lib.config") } +async test "library async builder unwrap matches direct async builder behavior" { + let config = AsyncLoggerBuildConfig::new( + logger=@bitlogger.LoggerConfig::new( + min_level=@bitlogger.Level::Warn, + target="async.lib.same-build", + timestamp=true, + queue=Some(@bitlogger.QueueConfig::new(3, overflow=@bitlogger.QueueOverflowPolicy::DropNewest)), + sink=@bitlogger.SinkConfig::new(kind=@bitlogger.SinkKind::Console), + ), + async_config=AsyncLoggerConfig::new( + max_pending=2, + overflow=AsyncOverflowPolicy::DropOldest, + flush=AsyncFlushPolicy::Shutdown, + ), + ) + let logger = build_library_async_logger(config) + let full = logger.to_async_logger() + let direct = build_async_logger(config) + let full_state = full.state() + let direct_state = direct.state() + + inspect(full.target, content=direct.target) + inspect(full.timestamp == direct.timestamp, content="true") + inspect(logger.is_enabled(@bitlogger.Level::Error) == direct.is_enabled(@bitlogger.Level::Error), content="true") + inspect(logger.is_enabled(@bitlogger.Level::Info) == direct.is_enabled(@bitlogger.Level::Info), content="true") + inspect( + stringify_async_logger_state(full_state) == stringify_async_logger_state(direct_state), + content="true", + ) + let full_sink_kind = match full.sink { + @bitlogger.RuntimeSink::QueuedConsole(_) => "QueuedConsole" + @bitlogger.RuntimeSink::QueuedJsonConsole(_) => "QueuedJsonConsole" + @bitlogger.RuntimeSink::QueuedTextConsole(_) => "QueuedTextConsole" + @bitlogger.RuntimeSink::QueuedFile(_) => "QueuedFile" + @bitlogger.RuntimeSink::Console(_) => "Console" + @bitlogger.RuntimeSink::JsonConsole(_) => "JsonConsole" + @bitlogger.RuntimeSink::TextConsole(_) => "TextConsole" + @bitlogger.RuntimeSink::File(_) => "File" + } + let direct_sink_kind = match direct.sink { + @bitlogger.RuntimeSink::QueuedConsole(_) => "QueuedConsole" + @bitlogger.RuntimeSink::QueuedJsonConsole(_) => "QueuedJsonConsole" + @bitlogger.RuntimeSink::QueuedTextConsole(_) => "QueuedTextConsole" + @bitlogger.RuntimeSink::QueuedFile(_) => "QueuedFile" + @bitlogger.RuntimeSink::Console(_) => "Console" + @bitlogger.RuntimeSink::JsonConsole(_) => "JsonConsole" + @bitlogger.RuntimeSink::TextConsole(_) => "TextConsole" + @bitlogger.RuntimeSink::File(_) => "File" + } + inspect(full_sink_kind == direct_sink_kind, content="true") + + logger.info("skip") + logger.error("one") + logger.error("two") + logger.error("three") + direct.info("skip") + direct.error("one") + direct.error("two") + direct.error("three") + + inspect(full.pending_count() == direct.pending_count(), content="true") + inspect(full.dropped_count() == direct.dropped_count(), content="true") + inspect(full.is_closed() == direct.is_closed(), content="true") + inspect(full.is_running() == direct.is_running(), content="true") + inspect(full.sink.pending_count() == direct.sink.pending_count(), content="true") + inspect(full.sink.dropped_count() == direct.sink.dropped_count(), content="true") + + @async.with_task_group(group => { + group.spawn_bg(() => logger.run()) + group.spawn_bg(() => direct.run()) + logger.shutdown() + direct.shutdown() + }) + + inspect(full.is_closed() == direct.is_closed(), content="true") + inspect(full.is_running() == direct.is_running(), content="true") + inspect(full.pending_count() == direct.pending_count(), content="true") + inspect(full.dropped_count() == direct.dropped_count(), content="true") + inspect(full.has_failed() == direct.has_failed(), content="true") + inspect(full.last_error() == direct.last_error(), content="true") +} + +async test "library async builder log supports per-call target override through facade" { + let written_target : Ref[String] = Ref("") + + let logger = build_library_async_logger( + AsyncLoggerBuildConfig::new( + logger=@bitlogger.LoggerConfig::new( + min_level=@bitlogger.Level::Warn, + target="async.lib.builder.default", + sink=@bitlogger.SinkConfig::new(kind=@bitlogger.SinkKind::Console), + ), + async_config=AsyncLoggerConfig::new( + max_pending=2, + overflow=AsyncOverflowPolicy::Blocking, + flush=AsyncFlushPolicy::Never, + ), + ), + ) + .to_async_logger() + .with_patch(fn(rec) { + written_target.val = rec.target + rec + }) + .to_library_async_logger() + + @async.with_task_group(group => { + group.spawn_bg(() => logger.run()) + logger.log( + @bitlogger.Level::Error, + "override", + target="async.lib.builder.override", + ) + logger.shutdown() + }) + + inspect(written_target.val, content="async.lib.builder.override") + + let second_target : Ref[String] = Ref("") + + let second = build_library_async_logger( + AsyncLoggerBuildConfig::new( + logger=@bitlogger.LoggerConfig::new( + min_level=@bitlogger.Level::Warn, + target="async.lib.builder.default", + sink=@bitlogger.SinkConfig::new(kind=@bitlogger.SinkKind::Console), + ), + async_config=AsyncLoggerConfig::new( + max_pending=2, + overflow=AsyncOverflowPolicy::Blocking, + flush=AsyncFlushPolicy::Never, + ), + ), + ) + .to_async_logger() + .with_patch(fn(rec) { + second_target.val = rec.target + rec + }) + .to_library_async_logger() + + @async.with_task_group(group => { + group.spawn_bg(() => second.run()) + second.error("default") + second.shutdown() + }) + + inspect(second_target.val, content="async.lib.builder.default") +} + +async test "library async builder severity helpers use stored target without override" { + let written_targets : Ref[Array[String]] = Ref([]) + + let logger = build_library_async_logger( + AsyncLoggerBuildConfig::new( + logger=@bitlogger.LoggerConfig::new( + min_level=@bitlogger.Level::Trace, + target="async.lib.builder.helpers", + sink=@bitlogger.SinkConfig::new(kind=@bitlogger.SinkKind::Console), + ), + async_config=AsyncLoggerConfig::new( + max_pending=4, + overflow=AsyncOverflowPolicy::Blocking, + flush=AsyncFlushPolicy::Never, + ), + ), + ) + .to_async_logger() + .with_patch(fn(rec) { + written_targets.val.push(rec.target) + rec + }) + .to_library_async_logger() + + @async.with_task_group(group => { + group.spawn_bg(() => logger.run()) + logger.info("first") + logger.warn("second") + logger.error("third") + logger.shutdown() + }) + + inspect(written_targets.val.length(), content="3") + inspect(written_targets.val[0], content="async.lib.builder.helpers") + inspect(written_targets.val[1], content="async.lib.builder.helpers") + inspect(written_targets.val[2], content="async.lib.builder.helpers") +} + +async test "library async builder shutdown clear abandons pending records through facade" { + let logger = build_library_async_logger( + AsyncLoggerBuildConfig::new( + logger=@bitlogger.LoggerConfig::new( + min_level=@bitlogger.Level::Info, + target="async.lib.builder.clear", + sink=@bitlogger.SinkConfig::new(kind=@bitlogger.SinkKind::Console), + ), + async_config=AsyncLoggerConfig::new( + max_pending=2, + overflow=AsyncOverflowPolicy::Blocking, + ), + ), + ) + let full = logger.to_async_logger() + + logger.info("one") + inspect(full.pending_count(), content="1") + inspect(full.dropped_count(), content="0") + logger.shutdown(clear=true) + inspect(full.is_closed(), content="true") + inspect(full.is_running(), content="false") + inspect(full.pending_count(), content="0") + inspect(full.dropped_count(), content="1") +} + +async test "parsed library async logger unwrap keeps async helper surface" { + let logger = parse_and_build_library_async_logger( + "{\"logger\":{\"min_level\":\"warn\",\"target\":\"async.lib.config.helpers\",\"sink\":{\"kind\":\"console\"}},\"async_config\":{\"max_pending\":2,\"overflow\":\"DropOldest\",\"max_batch\":1,\"linger_ms\":0,\"flush\":\"Shutdown\"}}", + ) + let full = logger.to_async_logger() + + let state = full.state() + inspect(logger.is_enabled(@bitlogger.Level::Error), content="true") + inspect(logger.is_enabled(@bitlogger.Level::Info), content="false") + inspect(full.target, content="async.lib.config.helpers") + inspect(state.pending_count, content="0") + inspect(state.dropped_count, content="0") + inspect(state.is_closed, content="false") + inspect(state.is_running, content="false") + inspect(state.has_failed, content="false") + inspect(match state.flush_policy { + AsyncFlushPolicy::Never => "Never" + AsyncFlushPolicy::Batch => "Batch" + AsyncFlushPolicy::Shutdown => "Shutdown" + }, content="Shutdown") + + logger.info("skip") + logger.error("one") + logger.error("two") + logger.error("three") + inspect(full.pending_count(), content="2") + inspect(full.dropped_count(), content="1") + inspect(full.is_closed(), content="false") + inspect(full.is_running(), content="false") + + @async.with_task_group(group => { + group.spawn_bg(() => logger.run()) + logger.shutdown() + }) + + inspect(full.is_closed(), content="true") + inspect(full.is_running(), content="false") + inspect(full.pending_count(), content="0") + inspect(full.dropped_count(), content="1") + inspect(full.has_failed(), content="false") + inspect(full.last_error(), content="") +} + +async test "parsed library async logger shutdown clear abandons pending records through facade" { + let logger = parse_and_build_library_async_logger( + "{\"logger\":{\"min_level\":\"info\",\"target\":\"async.lib.json.clear\",\"sink\":{\"kind\":\"console\"}},\"async_config\":{\"max_pending\":2,\"overflow\":\"Blocking\",\"max_batch\":1,\"linger_ms\":0,\"flush\":\"Never\"}}", + ) + let full = logger.to_async_logger() + + logger.info("one") + inspect(full.pending_count(), content="1") + inspect(full.dropped_count(), content="0") + logger.shutdown(clear=true) + inspect(full.is_closed(), content="true") + inspect(full.is_running(), content="false") + inspect(full.pending_count(), content="0") + inspect(full.dropped_count(), content="1") +} + +async test "parsed library async logger log supports per-call target override through facade" { + let written_target : Ref[String] = Ref("") + + let logger = parse_and_build_library_async_logger( + "{\"logger\":{\"min_level\":\"warn\",\"target\":\"async.lib.json.default\",\"sink\":{\"kind\":\"console\"}},\"async_config\":{\"max_pending\":2,\"overflow\":\"Blocking\",\"max_batch\":1,\"linger_ms\":0,\"flush\":\"Never\"}}", + ) + .to_async_logger() + .with_patch(fn(rec) { + written_target.val = rec.target + rec + }) + .to_library_async_logger() + + @async.with_task_group(group => { + group.spawn_bg(() => logger.run()) + logger.log( + @bitlogger.Level::Error, + "override", + target="async.lib.json.override", + ) + logger.shutdown() + }) + + inspect(written_target.val, content="async.lib.json.override") + + let second_target : Ref[String] = Ref("") + + let second = parse_and_build_library_async_logger( + "{\"logger\":{\"min_level\":\"warn\",\"target\":\"async.lib.json.default\",\"sink\":{\"kind\":\"console\"}},\"async_config\":{\"max_pending\":2,\"overflow\":\"Blocking\",\"max_batch\":1,\"linger_ms\":0,\"flush\":\"Never\"}}", + ) + .to_async_logger() + .with_patch(fn(rec) { + second_target.val = rec.target + rec + }) + .to_library_async_logger() + + @async.with_task_group(group => { + group.spawn_bg(() => second.run()) + second.error("default") + second.shutdown() + }) + + inspect(second_target.val, content="async.lib.json.default") +} + +async test "parsed library async severity helpers use stored target without override" { + let written_targets : Ref[Array[String]] = Ref([]) + + let logger = parse_and_build_library_async_logger( + "{\"logger\":{\"min_level\":\"trace\",\"target\":\"async.lib.json.helpers.target\",\"sink\":{\"kind\":\"console\"}},\"async_config\":{\"max_pending\":4,\"overflow\":\"Blocking\",\"max_batch\":1,\"linger_ms\":0,\"flush\":\"Never\"}}", + ) + .to_async_logger() + .with_patch(fn(rec) { + written_targets.val.push(rec.target) + rec + }) + .to_library_async_logger() + + @async.with_task_group(group => { + group.spawn_bg(() => logger.run()) + logger.info("first") + logger.warn("second") + logger.error("third") + logger.shutdown() + }) + + inspect(written_targets.val.length(), content="3") + inspect(written_targets.val[0], content="async.lib.json.helpers.target") + inspect(written_targets.val[1], content="async.lib.json.helpers.target") + inspect(written_targets.val[2], content="async.lib.json.helpers.target") +} + +async test "library async parse-build unwrap matches parsed direct async builder behavior" { + let raw = "{\"logger\":{\"min_level\":\"warn\",\"target\":\"async.lib.json.same-build\",\"timestamp\":true,\"queue\":{\"max_pending\":3,\"overflow\":\"DropNewest\"},\"sink\":{\"kind\":\"console\"}},\"async_config\":{\"max_pending\":2,\"overflow\":\"DropOldest\",\"max_batch\":1,\"linger_ms\":0,\"flush\":\"Shutdown\"}}" + let logger = parse_and_build_library_async_logger(raw) + let full = logger.to_async_logger() + let direct = build_async_logger(parse_async_logger_build_config_text(raw)) + let full_state = full.state() + let direct_state = direct.state() + + inspect(full.target, content=direct.target) + inspect(full.timestamp == direct.timestamp, content="true") + inspect(logger.is_enabled(@bitlogger.Level::Error) == direct.is_enabled(@bitlogger.Level::Error), content="true") + inspect(logger.is_enabled(@bitlogger.Level::Info) == direct.is_enabled(@bitlogger.Level::Info), content="true") + inspect( + stringify_async_logger_state(full_state) == stringify_async_logger_state(direct_state), + content="true", + ) + let full_sink_kind = match full.sink { + @bitlogger.RuntimeSink::QueuedConsole(_) => "QueuedConsole" + @bitlogger.RuntimeSink::QueuedJsonConsole(_) => "QueuedJsonConsole" + @bitlogger.RuntimeSink::QueuedTextConsole(_) => "QueuedTextConsole" + @bitlogger.RuntimeSink::QueuedFile(_) => "QueuedFile" + @bitlogger.RuntimeSink::Console(_) => "Console" + @bitlogger.RuntimeSink::JsonConsole(_) => "JsonConsole" + @bitlogger.RuntimeSink::TextConsole(_) => "TextConsole" + @bitlogger.RuntimeSink::File(_) => "File" + } + let direct_sink_kind = match direct.sink { + @bitlogger.RuntimeSink::QueuedConsole(_) => "QueuedConsole" + @bitlogger.RuntimeSink::QueuedJsonConsole(_) => "QueuedJsonConsole" + @bitlogger.RuntimeSink::QueuedTextConsole(_) => "QueuedTextConsole" + @bitlogger.RuntimeSink::QueuedFile(_) => "QueuedFile" + @bitlogger.RuntimeSink::Console(_) => "Console" + @bitlogger.RuntimeSink::JsonConsole(_) => "JsonConsole" + @bitlogger.RuntimeSink::TextConsole(_) => "TextConsole" + @bitlogger.RuntimeSink::File(_) => "File" + } + inspect(full_sink_kind == direct_sink_kind, content="true") + + logger.info("skip") + logger.error("one") + logger.error("two") + logger.error("three") + direct.info("skip") + direct.error("one") + direct.error("two") + direct.error("three") + + inspect(full.pending_count() == direct.pending_count(), content="true") + inspect(full.dropped_count() == direct.dropped_count(), content="true") + inspect(full.is_closed() == direct.is_closed(), content="true") + inspect(full.is_running() == direct.is_running(), content="true") + inspect(full.sink.pending_count() == direct.sink.pending_count(), content="true") + inspect(full.sink.dropped_count() == direct.sink.dropped_count(), content="true") + + @async.with_task_group(group => { + group.spawn_bg(() => logger.run()) + group.spawn_bg(() => direct.run()) + logger.shutdown() + direct.shutdown() + }) + + inspect(full.is_closed() == direct.is_closed(), content="true") + inspect(full.is_running() == direct.is_running(), content="true") + inspect(full.pending_count() == direct.pending_count(), content="true") + inspect(full.dropped_count() == direct.dropped_count(), content="true") + inspect(full.has_failed() == direct.has_failed(), content="true") + inspect(full.last_error() == direct.last_error(), content="true") +} + +async test "library async parse-build unwrap preserves file-backed runtime helpers" { + let raw = "{\"logger\":{\"min_level\":\"warn\",\"target\":\"async.lib.json.file.same-build\",\"queue\":{\"max_pending\":3,\"overflow\":\"DropOldest\"},\"sink\":{\"kind\":\"file\",\"path\":\"async-lib-json-file-same-build.log\"}},\"async_config\":{\"max_pending\":2,\"overflow\":\"DropOldest\",\"max_batch\":1,\"linger_ms\":0,\"flush\":\"Shutdown\"}}" + let logger = parse_and_build_library_async_logger(raw) + let full = logger.to_async_logger() + let direct = build_async_logger(parse_async_logger_build_config_text(raw)) + + logger.info("skip") + logger.error("one") + logger.error("two") + logger.error("three") + direct.info("skip") + direct.error("one") + direct.error("two") + direct.error("three") + + inspect(full.pending_count() == direct.pending_count(), content="true") + inspect(full.dropped_count() == direct.dropped_count(), content="true") + inspect(full.sink.pending_count() == direct.sink.pending_count(), content="true") + inspect(full.sink.dropped_count() == direct.sink.dropped_count(), content="true") + inspect(full.sink.file_available() == direct.sink.file_available(), content="true") + inspect(full.sink.file_append_mode() == direct.sink.file_append_mode(), content="true") + inspect(full.sink.file_auto_flush() == direct.sink.file_auto_flush(), content="true") + + let full_state = full.sink.file_state() + let direct_state = direct.sink.file_state() + inspect(full_state.path == direct_state.path, content="true") + inspect(full_state.available == direct_state.available, content="true") + inspect(full_state.append == direct_state.append, content="true") + inspect(full_state.auto_flush == direct_state.auto_flush, content="true") + inspect(full_state.open_failures == direct_state.open_failures, content="true") + inspect(full_state.write_failures == direct_state.write_failures, content="true") + inspect(full_state.flush_failures == direct_state.flush_failures, content="true") + inspect(full_state.rotation_failures == direct_state.rotation_failures, content="true") + + match (full.sink.file_runtime_state(), direct.sink.file_runtime_state()) { + (Some(snapshot), Some(other)) => { + inspect(snapshot.file.path == other.file.path, content="true") + inspect(snapshot.file.available == other.file.available, content="true") + inspect(snapshot.queued == other.queued, content="true") + inspect(snapshot.pending_count == other.pending_count, content="true") + inspect(snapshot.dropped_count == other.dropped_count, content="true") + } + _ => inspect(false, content="true") + } + + inspect(full.sink.file_set_append_mode(false) == direct.sink.file_set_append_mode(false), content="true") + inspect(full.sink.file_append_mode() == direct.sink.file_append_mode(), content="true") + inspect(full.sink.file_set_auto_flush(false) == direct.sink.file_set_auto_flush(false), content="true") + inspect(full.sink.file_auto_flush() == direct.sink.file_auto_flush(), content="true") + inspect( + full.sink.file_set_rotation(Some(@bitlogger.file_rotation(36, max_backups=2))) == + direct.sink.file_set_rotation(Some(@bitlogger.file_rotation(36, max_backups=2))), + content="true", + ) + inspect(full.sink.file_rotation_enabled() == direct.sink.file_rotation_enabled(), content="true") + inspect(full.sink.file_reopen_append() == direct.sink.file_reopen_append(), content="true") + inspect(full.sink.file_append_mode() == direct.sink.file_append_mode(), content="true") + inspect(full.sink.file_clear_rotation() == direct.sink.file_clear_rotation(), content="true") + inspect(full.sink.file_reset_policy() == direct.sink.file_reset_policy(), content="true") + inspect(full.sink.file_policy_matches_default() == direct.sink.file_policy_matches_default(), content="true") + inspect( + full.sink.file_reset_failure_counters() == direct.sink.file_reset_failure_counters(), + content="true", + ) + inspect(full.sink.file_flush() == direct.sink.file_flush(), content="true") + inspect(full.pending_count() == direct.pending_count(), content="true") + inspect(full.sink.file_close() == direct.sink.file_close(), content="true") +} + +test "library async logger parse-and-build preserves parsed sync queue layer" { + let logger = parse_and_build_library_async_logger( + "{\"logger\":{\"min_level\":\"warn\",\"target\":\"async.lib.config.queued\",\"queue\":{\"max_pending\":3,\"overflow\":\"DropNewest\"},\"sink\":{\"kind\":\"console\"}},\"async_config\":{\"max_pending\":2,\"overflow\":\"DropNewest\",\"max_batch\":1,\"linger_ms\":0,\"flush\":\"Never\"}}", + ) + let full = logger.to_async_logger() + + inspect(logger.is_enabled(@bitlogger.Level::Error), content="true") + inspect(logger.is_enabled(@bitlogger.Level::Info), content="false") + inspect(full.target, content="async.lib.config.queued") + inspect(match full.sink { + @bitlogger.RuntimeSink::QueuedConsole(_) => "QueuedConsole" + @bitlogger.RuntimeSink::QueuedJsonConsole(_) => "QueuedJsonConsole" + @bitlogger.RuntimeSink::QueuedTextConsole(_) => "QueuedTextConsole" + @bitlogger.RuntimeSink::QueuedFile(_) => "QueuedFile" + _ => "Other" + }, content="QueuedConsole") +} + test "library async text logger can be built from typed config" { let logger = build_library_async_text_logger( AsyncLoggerBuildConfig::new( @@ -386,6 +2065,314 @@ test "library async text logger can be built from typed config" { inspect(full.target, content="async.lib.text") } +async test "library async text builder unwrap matches direct text builder behavior" { + let config = AsyncLoggerBuildConfig::new( + logger=@bitlogger.LoggerConfig::new( + min_level=@bitlogger.Level::Warn, + target="async.lib.text.same-build", + timestamp=true, + queue=Some(@bitlogger.QueueConfig::new(3, overflow=@bitlogger.QueueOverflowPolicy::DropNewest)), + sink=@bitlogger.SinkConfig::new( + kind=@bitlogger.SinkKind::TextConsole, + text_formatter=@bitlogger.TextFormatterConfig::new( + show_timestamp=false, + separator=" | ", + template="TEXT:{target}:{message}", + ), + ), + ), + async_config=AsyncLoggerConfig::new( + max_pending=2, + overflow=AsyncOverflowPolicy::DropOldest, + flush=AsyncFlushPolicy::Shutdown, + ), + ) + let logger = build_library_async_text_logger(config) + let full = logger.to_async_logger() + let direct = build_async_text_logger(config) + let full_state = full.state() + let direct_state = direct.state() + + inspect(full.target, content=direct.target) + inspect(full.timestamp == direct.timestamp, content="true") + inspect(logger.is_enabled(@bitlogger.Level::Error) == direct.is_enabled(@bitlogger.Level::Error), content="true") + inspect(logger.is_enabled(@bitlogger.Level::Info) == direct.is_enabled(@bitlogger.Level::Info), content="true") + inspect( + stringify_async_logger_state(full_state) == stringify_async_logger_state(direct_state), + content="true", + ) + let record = @bitlogger.Record::new(@bitlogger.Level::Error, "boom", target="async.lib.text.same-build") + inspect((full.sink.formatter)(record) == (direct.sink.formatter)(record), content="true") + + logger.info("skip") + logger.error("one") + logger.error("two") + logger.error("three") + direct.info("skip") + direct.error("one") + direct.error("two") + direct.error("three") + + inspect(full.pending_count() == direct.pending_count(), content="true") + inspect(full.dropped_count() == direct.dropped_count(), content="true") + inspect(full.is_closed() == direct.is_closed(), content="true") + inspect(full.is_running() == direct.is_running(), content="true") + + @async.with_task_group(group => { + group.spawn_bg(() => logger.run()) + group.spawn_bg(() => direct.run()) + logger.shutdown() + direct.shutdown() + }) + + inspect(full.is_closed() == direct.is_closed(), content="true") + inspect(full.is_running() == direct.is_running(), content="true") + inspect(full.pending_count() == direct.pending_count(), content="true") + inspect(full.dropped_count() == direct.dropped_count(), content="true") + inspect(full.has_failed() == direct.has_failed(), content="true") + inspect(full.last_error() == direct.last_error(), content="true") +} + +async test "library async text builder log supports per-call target override through facade" { + let written_target : Ref[String] = Ref("") + + let logger = build_library_async_text_logger( + AsyncLoggerBuildConfig::new( + logger=@bitlogger.text_console( + min_level=@bitlogger.Level::Warn, + target="async.lib.text.builder.default", + text_formatter=@bitlogger.TextFormatterConfig::new(show_timestamp=false, separator=" | "), + ), + async_config=AsyncLoggerConfig::new( + max_pending=2, + overflow=AsyncOverflowPolicy::Blocking, + flush=AsyncFlushPolicy::Never, + ), + ), + ) + .to_async_logger() + .with_patch(fn(rec) { + written_target.val = rec.target + rec + }) + .to_library_async_logger() + + @async.with_task_group(group => { + group.spawn_bg(() => logger.run()) + logger.log( + @bitlogger.Level::Error, + "override", + target="async.lib.text.builder.override", + ) + logger.shutdown() + }) + + inspect(written_target.val, content="async.lib.text.builder.override") + + let second_target : Ref[String] = Ref("") + + let second = build_library_async_text_logger( + AsyncLoggerBuildConfig::new( + logger=@bitlogger.text_console( + min_level=@bitlogger.Level::Warn, + target="async.lib.text.builder.default", + text_formatter=@bitlogger.TextFormatterConfig::new(show_timestamp=false, separator=" | "), + ), + async_config=AsyncLoggerConfig::new( + max_pending=2, + overflow=AsyncOverflowPolicy::Blocking, + flush=AsyncFlushPolicy::Never, + ), + ), + ) + .to_async_logger() + .with_patch(fn(rec) { + second_target.val = rec.target + rec + }) + .to_library_async_logger() + + @async.with_task_group(group => { + group.spawn_bg(() => second.run()) + second.error("default") + second.shutdown() + }) + + inspect(second_target.val, content="async.lib.text.builder.default") +} + +async test "library async text builder severity helpers use stored target without override" { + let written_targets : Ref[Array[String]] = Ref([]) + + let logger = build_library_async_text_logger( + AsyncLoggerBuildConfig::new( + logger=@bitlogger.text_console( + min_level=@bitlogger.Level::Info, + target="async.lib.text.builder.helpers", + text_formatter=@bitlogger.TextFormatterConfig::new(show_timestamp=false, separator=" | "), + ), + async_config=AsyncLoggerConfig::new( + max_pending=4, + overflow=AsyncOverflowPolicy::Blocking, + flush=AsyncFlushPolicy::Never, + ), + ), + ) + .to_async_logger() + .with_patch(fn(rec) { + written_targets.val.push(rec.target) + rec + }) + .to_library_async_logger() + + @async.with_task_group(group => { + group.spawn_bg(() => logger.run()) + logger.info("first") + logger.warn("second") + logger.error("third") + logger.shutdown() + }) + + inspect(written_targets.val.length(), content="3") + inspect(written_targets.val[0], content="async.lib.text.builder.helpers") + inspect(written_targets.val[1], content="async.lib.text.builder.helpers") + inspect(written_targets.val[2], content="async.lib.text.builder.helpers") +} + +async test "library async text logger unwrap keeps async helper surface" { + let logger = build_library_async_text_logger( + AsyncLoggerBuildConfig::new( + logger=@bitlogger.text_console( + min_level=@bitlogger.Level::Warn, + target="async.lib.text.helpers", + text_formatter=@bitlogger.TextFormatterConfig::new(show_timestamp=false, separator=" | "), + ), + async_config=AsyncLoggerConfig::new( + max_pending=2, + overflow=AsyncOverflowPolicy::DropOldest, + flush=AsyncFlushPolicy::Shutdown, + ), + ), + ) + let full = logger.to_async_logger() + + let state = full.state() + inspect(logger.is_enabled(@bitlogger.Level::Error), content="true") + inspect(logger.is_enabled(@bitlogger.Level::Info), content="false") + inspect(full.target, content="async.lib.text.helpers") + inspect(state.pending_count, content="0") + inspect(state.dropped_count, content="0") + inspect(state.is_closed, content="false") + inspect(state.is_running, content="false") + inspect(state.has_failed, content="false") + inspect(match state.flush_policy { + AsyncFlushPolicy::Never => "Never" + AsyncFlushPolicy::Batch => "Batch" + AsyncFlushPolicy::Shutdown => "Shutdown" + }, content="Shutdown") + + logger.info("skip") + logger.error("one") + logger.error("two") + logger.error("three") + inspect(full.pending_count(), content="2") + inspect(full.dropped_count(), content="1") + inspect(full.is_closed(), content="false") + inspect(full.is_running(), content="false") + + @async.with_task_group(group => { + group.spawn_bg(() => logger.run()) + logger.shutdown() + }) + + inspect(full.is_closed(), content="true") + inspect(full.is_running(), content="false") + inspect(full.pending_count(), content="0") + inspect(full.dropped_count(), content="1") + inspect(full.has_failed(), content="false") + inspect(full.last_error(), content="") +} + +async test "library async text logger shutdown clear abandons pending records through facade" { + let logger = build_library_async_text_logger( + AsyncLoggerBuildConfig::new( + logger=@bitlogger.text_console( + min_level=@bitlogger.Level::Info, + target="async.lib.text.clear", + text_formatter=@bitlogger.TextFormatterConfig::new(show_timestamp=false, separator=" | "), + ), + async_config=AsyncLoggerConfig::new( + max_pending=2, + overflow=AsyncOverflowPolicy::Blocking, + ), + ), + ) + let full = logger.to_async_logger() + + logger.info("one") + inspect(full.pending_count(), content="1") + inspect(full.dropped_count(), content="0") + logger.shutdown(clear=true) + inspect(full.is_closed(), content="true") + inspect(full.is_running(), content="false") + inspect(full.pending_count(), content="0") + inspect(full.dropped_count(), content="1") +} + +test "library async text logger builder ignores sync queue layer" { + let logger = build_library_async_text_logger( + AsyncLoggerBuildConfig::new( + logger=@bitlogger.LoggerConfig::new( + min_level=@bitlogger.Level::Warn, + target="async.lib.text.queued", + queue=Some(@bitlogger.QueueConfig::new(3, overflow=@bitlogger.QueueOverflowPolicy::DropNewest)), + sink=@bitlogger.SinkConfig::new( + kind=@bitlogger.SinkKind::TextConsole, + text_formatter=@bitlogger.TextFormatterConfig::new(show_timestamp=false, separator=" | "), + ), + ), + async_config=AsyncLoggerConfig::new(max_pending=2), + ), + ) + let full = logger.to_async_logger() + + inspect(logger.is_enabled(@bitlogger.Level::Error), content="true") + inspect(logger.is_enabled(@bitlogger.Level::Info), content="false") + inspect(full.target, content="async.lib.text.queued") + inspect(full.pending_count(), content="0") + inspect(full.dropped_count(), content="0") +} + +test "library async text logger ignores sink kind and still uses text formatter" { + let logger = build_library_async_text_logger( + AsyncLoggerBuildConfig::new( + logger=@bitlogger.LoggerConfig::new( + min_level=@bitlogger.Level::Warn, + target="async.lib.text.kind", + sink=@bitlogger.SinkConfig::new( + kind=@bitlogger.SinkKind::File, + path="ignored.log", + text_formatter=@bitlogger.TextFormatterConfig::new( + show_timestamp=false, + separator=" | ", + template="TEXT:{target}:{message}", + ), + ), + ), + async_config=AsyncLoggerConfig::new(max_pending=2), + ), + ) + let full = logger.to_async_logger() + + inspect(logger.is_enabled(@bitlogger.Level::Error), content="true") + inspect(logger.is_enabled(@bitlogger.Level::Info), content="false") + inspect(full.target, content="async.lib.text.kind") + let rendered = (full.sink.formatter)( + @bitlogger.Record::new(@bitlogger.Level::Error, "boom", target="async.lib.text.kind"), + ) + inspect(rendered, content="TEXT:async.lib.text.kind:boom") +} + async test "async logger can project to library async logger" { let logger = build_async_logger( AsyncLoggerBuildConfig::new( @@ -398,6 +2385,315 @@ async test "async logger can project to library async logger" { inspect(logger.to_async_logger().target, content="async.projected") } +async test "build async logger keeps direct helper surface and runtime sink path" { + let logger = build_async_logger( + AsyncLoggerBuildConfig::new( + logger=@bitlogger.LoggerConfig::new( + min_level=@bitlogger.Level::Warn, + target="async.direct.helpers", + queue=Some(@bitlogger.QueueConfig::new(3, overflow=@bitlogger.QueueOverflowPolicy::DropNewest)), + sink=@bitlogger.SinkConfig::new(kind=@bitlogger.SinkKind::Console), + ), + async_config=AsyncLoggerConfig::new( + max_pending=2, + overflow=AsyncOverflowPolicy::DropOldest, + flush=AsyncFlushPolicy::Shutdown, + ), + ), + ) + + let state = logger.state() + inspect(logger.is_enabled(@bitlogger.Level::Error), content="true") + inspect(logger.is_enabled(@bitlogger.Level::Info), content="false") + inspect(logger.target, content="async.direct.helpers") + inspect(state.pending_count, content="0") + inspect(state.dropped_count, content="0") + inspect(state.is_closed, content="false") + inspect(state.is_running, content="false") + inspect(state.has_failed, content="false") + inspect(match state.flush_policy { + AsyncFlushPolicy::Never => "Never" + AsyncFlushPolicy::Batch => "Batch" + AsyncFlushPolicy::Shutdown => "Shutdown" + }, content="Shutdown") + inspect(match logger.sink { + @bitlogger.RuntimeSink::QueuedConsole(_) => "QueuedConsole" + @bitlogger.RuntimeSink::QueuedJsonConsole(_) => "QueuedJsonConsole" + @bitlogger.RuntimeSink::QueuedTextConsole(_) => "QueuedTextConsole" + @bitlogger.RuntimeSink::QueuedFile(_) => "QueuedFile" + _ => "Other" + }, content="QueuedConsole") + + logger.info("skip") + logger.error("one") + logger.error("two") + logger.error("three") + inspect(logger.pending_count(), content="2") + inspect(logger.dropped_count(), content="1") + inspect(logger.is_closed(), content="false") + inspect(logger.is_running(), content="false") + inspect(logger.sink.pending_count(), content="0") + inspect(logger.sink.dropped_count(), content="0") + + @async.with_task_group(group => { + group.spawn_bg(() => logger.run()) + logger.shutdown() + }) + + inspect(logger.is_closed(), content="true") + inspect(logger.is_running(), content="false") + inspect(logger.pending_count(), content="0") + inspect(logger.dropped_count(), content="1") + inspect(logger.has_failed(), content="false") + inspect(logger.last_error(), content="") +} + +async test "build async logger log supports per-call target override" { + let written_target : Ref[String] = Ref("") + + let logger = build_async_logger( + AsyncLoggerBuildConfig::new( + logger=@bitlogger.LoggerConfig::new( + min_level=@bitlogger.Level::Warn, + target="async.builder.default", + sink=@bitlogger.SinkConfig::new(kind=@bitlogger.SinkKind::Console), + ), + async_config=AsyncLoggerConfig::new( + max_pending=2, + overflow=AsyncOverflowPolicy::Blocking, + flush=AsyncFlushPolicy::Never, + ), + ), + ) + .with_patch(fn(rec) { + written_target.val = rec.target + rec + }) + + @async.with_task_group(group => { + group.spawn_bg(() => logger.run()) + logger.log( + @bitlogger.Level::Error, + "override", + target="async.builder.override", + ) + logger.shutdown() + }) + + inspect(written_target.val, content="async.builder.override") + + let second_target : Ref[String] = Ref("") + + let second = build_async_logger( + AsyncLoggerBuildConfig::new( + logger=@bitlogger.LoggerConfig::new( + min_level=@bitlogger.Level::Warn, + target="async.builder.default", + sink=@bitlogger.SinkConfig::new(kind=@bitlogger.SinkKind::Console), + ), + async_config=AsyncLoggerConfig::new( + max_pending=2, + overflow=AsyncOverflowPolicy::Blocking, + flush=AsyncFlushPolicy::Never, + ), + ), + ) + .with_patch(fn(rec) { + second_target.val = rec.target + rec + }) + + @async.with_task_group(group => { + group.spawn_bg(() => second.run()) + second.error("default") + second.shutdown() + }) + + inspect(second_target.val, content="async.builder.default") +} + +async test "build async logger severity helpers use stored target without override" { + let written_targets : Ref[Array[String]] = Ref([]) + + let logger = build_async_logger( + AsyncLoggerBuildConfig::new( + logger=@bitlogger.LoggerConfig::new( + min_level=@bitlogger.Level::Trace, + target="async.builder.helpers", + sink=@bitlogger.SinkConfig::new(kind=@bitlogger.SinkKind::Console), + ), + async_config=AsyncLoggerConfig::new( + max_pending=4, + overflow=AsyncOverflowPolicy::Blocking, + flush=AsyncFlushPolicy::Never, + ), + ), + ) + .with_patch(fn(rec) { + written_targets.val.push(rec.target) + rec + }) + + @async.with_task_group(group => { + group.spawn_bg(() => logger.run()) + logger.debug("first") + logger.info("second") + logger.error("third") + logger.shutdown() + }) + + inspect(written_targets.val.length(), content="3") + inspect(written_targets.val[0], content="async.builder.helpers") + inspect(written_targets.val[1], content="async.builder.helpers") + inspect(written_targets.val[2], content="async.builder.helpers") +} + +async test "async logger projection preserves async queue and failure state" { + let logger = async_logger( + @bitlogger.callback_sink(fn(_) { + + }), + config=AsyncLoggerConfig::new( + max_pending=4, + overflow=AsyncOverflowPolicy::Blocking, + flush=AsyncFlushPolicy::Batch, + ), + min_level=@bitlogger.Level::Info, + target="async.projected.state", + flush=fn(_) -> Int raise { + raise TestFlushError("projected facade flush exploded") + }, + ).to_library_async_logger() + let full = logger.to_async_logger() + + logger.info("one") + logger.info("two") + inspect(full.target, content="async.projected.state") + inspect(full.pending_count(), content="2") + inspect(full.dropped_count(), content="0") + inspect(full.has_failed(), content="false") + inspect(full.last_error(), content="") + + @async.with_task_group(group => { + group.spawn_bg(allow_failure=true, () => logger.run()) + full.wait_idle() + inspect(full.has_failed(), content="true") + inspect(full.last_error().contains("TestFlushError"), content="true") + inspect(full.is_running(), content="false") + inspect( + full.pending_count(), + content=if async_runtime_supports_background_worker() { "1" } else { "1" }, + ) + inspect( + full.dropped_count(), + content=if async_runtime_supports_background_worker() { "0" } else { "0" }, + ) + logger.shutdown() + }) + + inspect(full.is_closed(), content="true") + inspect(full.has_failed(), content="true") + inspect(full.last_error().contains("TestFlushError"), content="true") +} + +async test "async logger projection preserves file-backed runtime helpers through unwrap" { + let configured = build_async_logger( + AsyncLoggerBuildConfig::new( + logger=@bitlogger.LoggerConfig::new( + min_level=@bitlogger.Level::Warn, + target="async.projected.file", + sink=@bitlogger.SinkConfig::new( + kind=@bitlogger.SinkKind::File, + path="async-projected-file.log", + ), + queue=Some(@bitlogger.QueueConfig::new(2, overflow=@bitlogger.QueueOverflowPolicy::DropOldest)), + ), + async_config=AsyncLoggerConfig::new( + max_pending=2, + overflow=AsyncOverflowPolicy::DropOldest, + flush=AsyncFlushPolicy::Shutdown, + ), + ), + ) + let projected = configured.to_library_async_logger() + let full = projected.to_async_logger() + + inspect(projected.is_enabled(@bitlogger.Level::Error), content="true") + inspect(projected.is_enabled(@bitlogger.Level::Info), content="false") + inspect(full.target, content="async.projected.file") + + full.error("one") + full.error("two") + full.error("three") + inspect(full.pending_count() == configured.pending_count(), content="true") + inspect(full.dropped_count() == configured.dropped_count(), content="true") + inspect(full.sink.pending_count() == configured.sink.pending_count(), content="true") + inspect(full.sink.dropped_count() == configured.sink.dropped_count(), content="true") + inspect(full.sink.file_available() == configured.sink.file_available(), content="true") + inspect(full.sink.file_append_mode() == configured.sink.file_append_mode(), content="true") + inspect(full.sink.file_auto_flush() == configured.sink.file_auto_flush(), content="true") + + let full_state = full.sink.file_state() + let configured_state = configured.sink.file_state() + inspect(full_state.path == configured_state.path, content="true") + inspect(full_state.available == configured_state.available, content="true") + inspect(full_state.append == configured_state.append, content="true") + inspect(full_state.auto_flush == configured_state.auto_flush, content="true") + inspect(full_state.open_failures == configured_state.open_failures, content="true") + inspect(full_state.write_failures == configured_state.write_failures, content="true") + inspect(full_state.flush_failures == configured_state.flush_failures, content="true") + inspect(full_state.rotation_failures == configured_state.rotation_failures, content="true") + + match (full.sink.file_runtime_state(), configured.sink.file_runtime_state()) { + (Some(snapshot), Some(other)) => { + inspect(snapshot.file.path == other.file.path, content="true") + inspect(snapshot.file.available == other.file.available, content="true") + inspect(snapshot.queued == other.queued, content="true") + inspect(snapshot.pending_count == other.pending_count, content="true") + inspect(snapshot.dropped_count == other.dropped_count, content="true") + } + _ => inspect(false, content="true") + } + + inspect(full.sink.file_set_append_mode(false), content="true") + inspect(configured.sink.file_append_mode(), content="false") + inspect(full.sink.file_append_mode() == configured.sink.file_append_mode(), content="true") + + inspect(full.sink.file_set_auto_flush(false), content="true") + inspect(configured.sink.file_auto_flush(), content="false") + inspect(full.sink.file_auto_flush() == configured.sink.file_auto_flush(), content="true") + + inspect(full.sink.file_set_rotation(Some(@bitlogger.file_rotation(36, max_backups=2))), content="true") + inspect(configured.sink.file_rotation_enabled(), content="true") + inspect(full.sink.file_rotation_enabled() == configured.sink.file_rotation_enabled(), content="true") + + let reopen_append_ok = full.sink.file_reopen_append() + inspect(reopen_append_ok == configured.sink.file_reopen_append(), content="true") + inspect(full.sink.file_append_mode() == configured.sink.file_append_mode(), content="true") + + inspect(full.sink.file_clear_rotation(), content="true") + inspect(configured.sink.file_rotation_enabled(), content="false") + inspect(full.sink.file_rotation_enabled() == configured.sink.file_rotation_enabled(), content="true") + + inspect(full.sink.file_reset_policy(), content="true") + inspect(full.sink.file_policy_matches_default() == configured.sink.file_policy_matches_default(), content="true") + + inspect(full.sink.file_reset_failure_counters(), content="true") + let reset_full_state = full.sink.file_state() + let reset_configured_state = configured.sink.file_state() + inspect(reset_full_state.open_failures == reset_configured_state.open_failures, content="true") + inspect(reset_full_state.write_failures == reset_configured_state.write_failures, content="true") + inspect(reset_full_state.flush_failures == reset_configured_state.flush_failures, content="true") + inspect(reset_full_state.rotation_failures == reset_configured_state.rotation_failures, content="true") + + inspect(full.sink.file_flush(), content=if configured.sink.file_available() { "true" } else { "false" }) + inspect(full.pending_count() == configured.pending_count(), content="true") + + let close_expected = configured.sink.file_available() + inspect(full.sink.file_close(), content=if close_expected { "true" } else { "false" }) + inspect(full.sink.file_available() == configured.sink.file_available(), content="true") +} + test "application async logger aliases runtime async entry" { let logger = build_application_async_logger( AsyncLoggerBuildConfig::new( @@ -410,6 +2706,438 @@ test "application async logger aliases runtime async entry" { inspect(logger.target, content="async.app") } +async test "application async logger builder matches direct async builder behavior" { + let config = AsyncLoggerBuildConfig::new( + logger=@bitlogger.LoggerConfig::new( + min_level=@bitlogger.Level::Warn, + target="async.app.same-build", + timestamp=true, + queue=Some(@bitlogger.QueueConfig::new(3, overflow=@bitlogger.QueueOverflowPolicy::DropNewest)), + sink=@bitlogger.SinkConfig::new(kind=@bitlogger.SinkKind::Console), + ), + async_config=AsyncLoggerConfig::new( + max_pending=2, + overflow=AsyncOverflowPolicy::DropOldest, + flush=AsyncFlushPolicy::Shutdown, + ), + ) + let application = build_application_async_logger(config) + let direct = build_async_logger(config) + let application_state = application.state() + let direct_state = direct.state() + + inspect(application.target, content=direct.target) + inspect(application.timestamp == direct.timestamp, content="true") + inspect( + application.is_enabled(@bitlogger.Level::Error) == direct.is_enabled(@bitlogger.Level::Error), + content="true", + ) + inspect( + application.is_enabled(@bitlogger.Level::Info) == direct.is_enabled(@bitlogger.Level::Info), + content="true", + ) + inspect( + stringify_async_logger_state(application_state) == stringify_async_logger_state(direct_state), + content="true", + ) + let application_sink_kind = match application.sink { + @bitlogger.RuntimeSink::QueuedConsole(_) => "QueuedConsole" + @bitlogger.RuntimeSink::QueuedJsonConsole(_) => "QueuedJsonConsole" + @bitlogger.RuntimeSink::QueuedTextConsole(_) => "QueuedTextConsole" + @bitlogger.RuntimeSink::QueuedFile(_) => "QueuedFile" + @bitlogger.RuntimeSink::Console(_) => "Console" + @bitlogger.RuntimeSink::JsonConsole(_) => "JsonConsole" + @bitlogger.RuntimeSink::TextConsole(_) => "TextConsole" + @bitlogger.RuntimeSink::File(_) => "File" + } + let direct_sink_kind = match direct.sink { + @bitlogger.RuntimeSink::QueuedConsole(_) => "QueuedConsole" + @bitlogger.RuntimeSink::QueuedJsonConsole(_) => "QueuedJsonConsole" + @bitlogger.RuntimeSink::QueuedTextConsole(_) => "QueuedTextConsole" + @bitlogger.RuntimeSink::QueuedFile(_) => "QueuedFile" + @bitlogger.RuntimeSink::Console(_) => "Console" + @bitlogger.RuntimeSink::JsonConsole(_) => "JsonConsole" + @bitlogger.RuntimeSink::TextConsole(_) => "TextConsole" + @bitlogger.RuntimeSink::File(_) => "File" + } + inspect(application_sink_kind == direct_sink_kind, content="true") + + application.info("skip") + application.error("one") + application.error("two") + application.error("three") + direct.info("skip") + direct.error("one") + direct.error("two") + direct.error("three") + + inspect(application.pending_count() == direct.pending_count(), content="true") + inspect(application.dropped_count() == direct.dropped_count(), content="true") + inspect(application.is_closed() == direct.is_closed(), content="true") + inspect(application.is_running() == direct.is_running(), content="true") + inspect(application.sink.pending_count() == direct.sink.pending_count(), content="true") + inspect(application.sink.dropped_count() == direct.sink.dropped_count(), content="true") + + @async.with_task_group(group => { + group.spawn_bg(() => application.run()) + group.spawn_bg(() => direct.run()) + application.shutdown() + direct.shutdown() + }) + + inspect(application.is_closed() == direct.is_closed(), content="true") + inspect(application.is_running() == direct.is_running(), content="true") + inspect(application.pending_count() == direct.pending_count(), content="true") + inspect(application.dropped_count() == direct.dropped_count(), content="true") + inspect(application.has_failed() == direct.has_failed(), content="true") + inspect(application.last_error() == direct.last_error(), content="true") +} + +async test "application async builder preserves file-backed runtime helpers" { + let config = AsyncLoggerBuildConfig::new( + logger=@bitlogger.LoggerConfig::new( + min_level=@bitlogger.Level::Warn, + target="async.app.file.same-build", + sink=@bitlogger.SinkConfig::new(kind=@bitlogger.SinkKind::File, path="async-app-file-same-build.log"), + queue=Some(@bitlogger.QueueConfig::new(3, overflow=@bitlogger.QueueOverflowPolicy::DropOldest)), + ), + async_config=AsyncLoggerConfig::new( + max_pending=2, + overflow=AsyncOverflowPolicy::DropOldest, + flush=AsyncFlushPolicy::Shutdown, + ), + ) + let application = build_application_async_logger(config) + let direct = build_async_logger(config) + + application.info("skip") + application.error("one") + application.error("two") + application.error("three") + direct.info("skip") + direct.error("one") + direct.error("two") + direct.error("three") + + inspect(application.pending_count() == direct.pending_count(), content="true") + inspect(application.dropped_count() == direct.dropped_count(), content="true") + inspect(application.sink.pending_count() == direct.sink.pending_count(), content="true") + inspect(application.sink.dropped_count() == direct.sink.dropped_count(), content="true") + inspect(application.sink.file_available() == direct.sink.file_available(), content="true") + inspect(application.sink.file_append_mode() == direct.sink.file_append_mode(), content="true") + inspect(application.sink.file_auto_flush() == direct.sink.file_auto_flush(), content="true") + + let application_state = application.sink.file_state() + let direct_state = direct.sink.file_state() + inspect(application_state.path == direct_state.path, content="true") + inspect(application_state.available == direct_state.available, content="true") + inspect(application_state.append == direct_state.append, content="true") + inspect(application_state.auto_flush == direct_state.auto_flush, content="true") + inspect(application_state.open_failures == direct_state.open_failures, content="true") + inspect(application_state.write_failures == direct_state.write_failures, content="true") + inspect(application_state.flush_failures == direct_state.flush_failures, content="true") + inspect(application_state.rotation_failures == direct_state.rotation_failures, content="true") + + match (application.sink.file_runtime_state(), direct.sink.file_runtime_state()) { + (Some(snapshot), Some(other)) => { + inspect(snapshot.file.path == other.file.path, content="true") + inspect(snapshot.file.available == other.file.available, content="true") + inspect(snapshot.queued == other.queued, content="true") + inspect(snapshot.pending_count == other.pending_count, content="true") + inspect(snapshot.dropped_count == other.dropped_count, content="true") + } + _ => inspect(false, content="true") + } + + inspect(application.sink.file_set_append_mode(false) == direct.sink.file_set_append_mode(false), content="true") + inspect(application.sink.file_append_mode() == direct.sink.file_append_mode(), content="true") + inspect(application.sink.file_set_auto_flush(false) == direct.sink.file_set_auto_flush(false), content="true") + inspect(application.sink.file_auto_flush() == direct.sink.file_auto_flush(), content="true") + inspect( + application.sink.file_set_rotation(Some(@bitlogger.file_rotation(36, max_backups=2))) == + direct.sink.file_set_rotation(Some(@bitlogger.file_rotation(36, max_backups=2))), + content="true", + ) + inspect(application.sink.file_rotation_enabled() == direct.sink.file_rotation_enabled(), content="true") + inspect(application.sink.file_reopen_append() == direct.sink.file_reopen_append(), content="true") + inspect(application.sink.file_append_mode() == direct.sink.file_append_mode(), content="true") + inspect(application.sink.file_clear_rotation() == direct.sink.file_clear_rotation(), content="true") + inspect(application.sink.file_reset_policy() == direct.sink.file_reset_policy(), content="true") + inspect(application.sink.file_policy_matches_default() == direct.sink.file_policy_matches_default(), content="true") + inspect( + application.sink.file_reset_failure_counters() == direct.sink.file_reset_failure_counters(), + content="true", + ) + inspect(application.sink.file_flush() == direct.sink.file_flush(), content="true") + inspect(application.pending_count() == direct.pending_count(), content="true") + inspect(application.sink.file_close() == direct.sink.file_close(), content="true") +} + +async test "application async logger keeps async helper surface" { + let logger : ApplicationAsyncLogger = build_application_async_logger( + AsyncLoggerBuildConfig::new( + logger=@bitlogger.LoggerConfig::new( + min_level=@bitlogger.Level::Warn, + target="async.app.alias", + sink=@bitlogger.SinkConfig::new(kind=@bitlogger.SinkKind::Console), + ), + async_config=AsyncLoggerConfig::new( + max_pending=2, + overflow=AsyncOverflowPolicy::DropOldest, + flush=AsyncFlushPolicy::Shutdown, + ), + ), + ) + + let state = logger.state() + inspect(state.pending_count, content="0") + inspect(state.dropped_count, content="0") + inspect(state.is_closed, content="false") + inspect(state.is_running, content="false") + inspect(state.has_failed, content="false") + inspect(match state.flush_policy { + AsyncFlushPolicy::Never => "Never" + AsyncFlushPolicy::Batch => "Batch" + AsyncFlushPolicy::Shutdown => "Shutdown" + }, content="Shutdown") + + logger.info("skip") + logger.error("one") + logger.error("two") + logger.error("three") + inspect(logger.pending_count(), content="2") + inspect(logger.dropped_count(), content="1") + inspect(logger.is_closed(), content="false") + inspect(logger.is_running(), content="false") + + @async.with_task_group(group => { + group.spawn_bg(() => logger.run()) + logger.shutdown() + }) + + inspect(logger.is_closed(), content="true") + inspect(logger.is_running(), content="false") + inspect(logger.pending_count(), content="0") + inspect(logger.dropped_count(), content="1") + inspect(logger.has_failed(), content="false") + inspect(logger.last_error(), content="") +} + +async test "application async logger shutdown clear abandons pending records" { + let logger : ApplicationAsyncLogger = build_application_async_logger( + AsyncLoggerBuildConfig::new( + logger=@bitlogger.LoggerConfig::new( + min_level=@bitlogger.Level::Info, + target="async.app.clear", + sink=@bitlogger.SinkConfig::new(kind=@bitlogger.SinkKind::Console), + ), + async_config=AsyncLoggerConfig::new( + max_pending=2, + overflow=AsyncOverflowPolicy::Blocking, + ), + ), + ) + + logger.info("one") + inspect(logger.pending_count(), content="1") + inspect(logger.dropped_count(), content="0") + logger.shutdown(clear=true) + inspect(logger.is_closed(), content="true") + inspect(logger.is_running(), content="false") + inspect(logger.pending_count(), content="0") + inspect(logger.dropped_count(), content="1") +} + +async test "application async logger keeps broader async composition surface" { + let logger : ApplicationAsyncLogger = build_application_async_logger( + AsyncLoggerBuildConfig::new( + logger=@bitlogger.LoggerConfig::new( + min_level=@bitlogger.Level::Warn, + target="async.app.compose", + sink=@bitlogger.SinkConfig::new(kind=@bitlogger.SinkKind::Console), + ), + async_config=AsyncLoggerConfig::new( + max_pending=2, + overflow=AsyncOverflowPolicy::DropNewest, + flush=AsyncFlushPolicy::Shutdown, + ), + ), + ) + .with_timestamp() + .with_context_fields([@bitlogger.field("service", "bitlogger")]) + .child("worker") + + inspect(logger.target, content="async.app.compose.worker") + inspect(logger.timestamp, content="true") + inspect(logger.is_enabled(@bitlogger.Level::Error), content="true") + inspect(logger.is_enabled(@bitlogger.Level::Info), content="false") + + logger.error("one") + logger.error("two") + inspect(logger.pending_count(), content="2") + inspect(logger.dropped_count(), content="0") + + @async.with_task_group(group => { + group.spawn_bg(() => logger.run()) + logger.shutdown() + }) + + inspect(logger.is_closed(), content="true") + inspect(logger.pending_count(), content="0") + inspect(logger.dropped_count(), content="0") + inspect(logger.has_failed(), content="false") + inspect(logger.last_error(), content="") +} + +async test "application async logger log supports per-call target override" { + let written_target : Ref[String] = Ref("") + let written_message : Ref[String] = Ref("") + let written_fields : Ref[Array[@bitlogger.Field]] = Ref([]) + let logger : ApplicationAsyncLogger = build_application_async_logger( + AsyncLoggerBuildConfig::new( + logger=@bitlogger.LoggerConfig::new( + min_level=@bitlogger.Level::Warn, + target="async.app.default", + sink=@bitlogger.SinkConfig::new(kind=@bitlogger.SinkKind::Console), + ), + async_config=AsyncLoggerConfig::new(max_pending=4), + ), + ) + .with_context_fields([@bitlogger.field("service", "bitlogger")]) + .with_patch(fn(rec) { + written_target.val = rec.target + written_message.val = rec.message + written_fields.val = rec.fields + rec + }) + + @async.with_task_group(group => { + group.spawn_bg(() => logger.run()) + logger.log( + @bitlogger.Level::Error, + "override", + fields=[@bitlogger.field("mode", "test")], + target="async.app.override", + ) + logger.shutdown() + }) + + inspect(written_target.val, content="async.app.override") + inspect(written_message.val, content="override") + inspect(written_fields.val.length(), content="2") + inspect(written_fields.val[0].key, content="service") + inspect(written_fields.val[0].value, content="bitlogger") + inspect(written_fields.val[1].key, content="mode") + inspect(written_fields.val[1].value, content="test") + + let second_target : Ref[String] = Ref("") + let second_message : Ref[String] = Ref("") + let second_fields : Ref[Array[@bitlogger.Field]] = Ref([]) + let second : ApplicationAsyncLogger = build_application_async_logger( + AsyncLoggerBuildConfig::new( + logger=@bitlogger.LoggerConfig::new( + min_level=@bitlogger.Level::Warn, + target="async.app.default", + sink=@bitlogger.SinkConfig::new(kind=@bitlogger.SinkKind::Console), + ), + async_config=AsyncLoggerConfig::new(max_pending=4), + ), + ) + .with_context_fields([@bitlogger.field("service", "bitlogger")]) + .with_patch(fn(rec) { + second_target.val = rec.target + second_message.val = rec.message + second_fields.val = rec.fields + rec + }) + + @async.with_task_group(group => { + group.spawn_bg(() => second.run()) + second.log(@bitlogger.Level::Error, "default") + second.shutdown() + }) + + inspect(second_target.val, content="async.app.default") + inspect(second_message.val, content="default") + inspect(second_fields.val.length(), content="1") + inspect(second_fields.val[0].key, content="service") +} + +async test "application async logger severity helpers use stored target without override" { + let written_levels : Ref[Array[String]] = Ref([]) + let written_targets : Ref[Array[String]] = Ref([]) + let written_fields : Ref[Array[Array[@bitlogger.Field]]] = Ref([]) + let logger : ApplicationAsyncLogger = build_application_async_logger( + AsyncLoggerBuildConfig::new( + logger=@bitlogger.LoggerConfig::new( + min_level=@bitlogger.Level::Info, + target="async.app.helpers", + sink=@bitlogger.SinkConfig::new(kind=@bitlogger.SinkKind::Console), + ), + async_config=AsyncLoggerConfig::new(max_pending=4), + ), + ) + .with_context_fields([@bitlogger.field("service", "bitlogger")]) + .with_patch(fn(rec) { + written_levels.val.push(rec.level.label()) + written_targets.val.push(rec.target) + written_fields.val.push(rec.fields) + rec + }) + + @async.with_task_group(group => { + group.spawn_bg(() => logger.run()) + logger.info("info", fields=[@bitlogger.field("mode", "info")]) + logger.warn("warn", fields=[@bitlogger.field("mode", "warn")]) + logger.error("error", fields=[@bitlogger.field("mode", "error")]) + logger.shutdown() + }) + + inspect(written_levels.val.length(), content="3") + inspect(written_levels.val[0], content="INFO") + inspect(written_levels.val[1], content="WARN") + inspect(written_levels.val[2], content="ERROR") + inspect(written_targets.val.length(), content="3") + inspect(written_targets.val[0], content="async.app.helpers") + inspect(written_targets.val[1], content="async.app.helpers") + inspect(written_targets.val[2], content="async.app.helpers") + inspect(written_fields.val[0].length(), content="2") + inspect(written_fields.val[1].length(), content="2") + inspect(written_fields.val[2].length(), content="2") + inspect(written_fields.val[0][0].key, content="service") + inspect(written_fields.val[0][1].value, content="info") + inspect(written_fields.val[1][0].key, content="service") + inspect(written_fields.val[1][1].value, content="warn") + inspect(written_fields.val[2][0].key, content="service") + inspect(written_fields.val[2][1].value, content="error") +} + +test "application async logger builder preserves sync queue-backed runtime sink" { + let logger = build_application_async_logger( + AsyncLoggerBuildConfig::new( + logger=@bitlogger.LoggerConfig::new( + min_level=@bitlogger.Level::Warn, + target="async.app.queued", + queue=Some(@bitlogger.QueueConfig::new(3, overflow=@bitlogger.QueueOverflowPolicy::DropNewest)), + ), + async_config=AsyncLoggerConfig::new(max_pending=2), + ), + ) + + inspect(logger.is_enabled(@bitlogger.Level::Error), content="true") + inspect(logger.is_enabled(@bitlogger.Level::Info), content="false") + inspect(logger.target, content="async.app.queued") + inspect(logger.sink.pending_count(), content="0") + inspect(logger.sink.dropped_count(), content="0") + inspect(match logger.sink { + @bitlogger.RuntimeSink::QueuedConsole(_) => "QueuedConsole" + @bitlogger.RuntimeSink::QueuedJsonConsole(_) => "QueuedJsonConsole" + @bitlogger.RuntimeSink::QueuedTextConsole(_) => "QueuedTextConsole" + @bitlogger.RuntimeSink::QueuedFile(_) => "QueuedFile" + _ => "Other" + }, content="QueuedConsole") +} + test "application text async logger uses text facade build path" { let logger = build_application_text_async_logger( AsyncLoggerBuildConfig::new( @@ -426,6 +3154,364 @@ test "application text async logger uses text facade build path" { inspect(logger.target, content="async.app.text") } +async test "application text builder matches direct text builder behavior" { + let config = AsyncLoggerBuildConfig::new( + logger=@bitlogger.LoggerConfig::new( + min_level=@bitlogger.Level::Warn, + target="async.app.text.same-build", + timestamp=true, + queue=Some(@bitlogger.QueueConfig::new(3, overflow=@bitlogger.QueueOverflowPolicy::DropNewest)), + sink=@bitlogger.SinkConfig::new( + kind=@bitlogger.SinkKind::TextConsole, + text_formatter=@bitlogger.TextFormatterConfig::new( + show_timestamp=false, + separator=" | ", + template="TEXT:{target}:{message}", + ), + ), + ), + async_config=AsyncLoggerConfig::new( + max_pending=2, + overflow=AsyncOverflowPolicy::DropOldest, + flush=AsyncFlushPolicy::Shutdown, + ), + ) + let logger = build_application_text_async_logger(config) + let direct = build_async_text_logger(config) + let logger_state = logger.state() + let direct_state = direct.state() + + inspect(logger.target, content=direct.target) + inspect(logger.timestamp == direct.timestamp, content="true") + inspect(logger.is_enabled(@bitlogger.Level::Error) == direct.is_enabled(@bitlogger.Level::Error), content="true") + inspect(logger.is_enabled(@bitlogger.Level::Info) == direct.is_enabled(@bitlogger.Level::Info), content="true") + inspect( + stringify_async_logger_state(logger_state) == stringify_async_logger_state(direct_state), + content="true", + ) + let record = @bitlogger.Record::new(@bitlogger.Level::Error, "boom", target="async.app.text.same-build") + inspect((logger.sink.formatter)(record) == (direct.sink.formatter)(record), content="true") + + logger.info("skip") + logger.error("one") + logger.error("two") + logger.error("three") + direct.info("skip") + direct.error("one") + direct.error("two") + direct.error("three") + + inspect(logger.pending_count() == direct.pending_count(), content="true") + inspect(logger.dropped_count() == direct.dropped_count(), content="true") + inspect(logger.is_closed() == direct.is_closed(), content="true") + inspect(logger.is_running() == direct.is_running(), content="true") + + @async.with_task_group(group => { + group.spawn_bg(() => logger.run()) + group.spawn_bg(() => direct.run()) + logger.shutdown() + direct.shutdown() + }) + + inspect(logger.is_closed() == direct.is_closed(), content="true") + inspect(logger.is_running() == direct.is_running(), content="true") + inspect(logger.pending_count() == direct.pending_count(), content="true") + inspect(logger.dropped_count() == direct.dropped_count(), content="true") + inspect(logger.has_failed() == direct.has_failed(), content="true") + inspect(logger.last_error() == direct.last_error(), content="true") +} + +async test "application text async logger keeps async helper surface" { + let logger : ApplicationTextAsyncLogger = build_application_text_async_logger( + AsyncLoggerBuildConfig::new( + logger=@bitlogger.text_console( + min_level=@bitlogger.Level::Warn, + target="async.app.text.alias", + text_formatter=@bitlogger.TextFormatterConfig::new(show_timestamp=false, separator=" | "), + ), + async_config=AsyncLoggerConfig::new( + max_pending=2, + overflow=AsyncOverflowPolicy::DropOldest, + flush=AsyncFlushPolicy::Shutdown, + ), + ), + ) + + let state = logger.state() + inspect(state.pending_count, content="0") + inspect(state.dropped_count, content="0") + inspect(state.is_closed, content="false") + inspect(state.is_running, content="false") + inspect(state.has_failed, content="false") + inspect(match state.flush_policy { + AsyncFlushPolicy::Never => "Never" + AsyncFlushPolicy::Batch => "Batch" + AsyncFlushPolicy::Shutdown => "Shutdown" + }, content="Shutdown") + + logger.info("skip") + logger.error("one") + logger.error("two") + logger.error("three") + inspect(logger.pending_count(), content="2") + inspect(logger.dropped_count(), content="1") + inspect(logger.is_closed(), content="false") + inspect(logger.is_running(), content="false") + + @async.with_task_group(group => { + group.spawn_bg(() => logger.run()) + logger.shutdown() + }) + + inspect(logger.is_closed(), content="true") + inspect(logger.is_running(), content="false") + inspect(logger.pending_count(), content="0") + inspect(logger.dropped_count(), content="1") + inspect(logger.has_failed(), content="false") + inspect(logger.last_error(), content="") +} + +async test "application text async logger shutdown clear abandons pending records" { + let logger : ApplicationTextAsyncLogger = build_application_text_async_logger( + AsyncLoggerBuildConfig::new( + logger=@bitlogger.text_console( + min_level=@bitlogger.Level::Info, + target="async.app.text.clear", + text_formatter=@bitlogger.TextFormatterConfig::new(show_timestamp=false, separator=" | "), + ), + async_config=AsyncLoggerConfig::new( + max_pending=2, + overflow=AsyncOverflowPolicy::Blocking, + ), + ), + ) + + logger.info("one") + inspect(logger.pending_count(), content="1") + inspect(logger.dropped_count(), content="0") + logger.shutdown(clear=true) + inspect(logger.is_closed(), content="true") + inspect(logger.is_running(), content="false") + inspect(logger.pending_count(), content="0") + inspect(logger.dropped_count(), content="1") +} + +async test "application text async logger keeps broader async composition surface" { + let logger : ApplicationTextAsyncLogger = build_application_text_async_logger( + AsyncLoggerBuildConfig::new( + logger=@bitlogger.text_console( + min_level=@bitlogger.Level::Warn, + target="async.app.text.compose", + text_formatter=@bitlogger.TextFormatterConfig::new(show_timestamp=false, separator=" | "), + ), + async_config=AsyncLoggerConfig::new( + max_pending=2, + overflow=AsyncOverflowPolicy::DropNewest, + flush=AsyncFlushPolicy::Shutdown, + ), + ), + ) + .with_timestamp() + .with_context_fields([@bitlogger.field("service", "bitlogger")]) + .child("worker") + + inspect(logger.target, content="async.app.text.compose.worker") + inspect(logger.timestamp, content="true") + inspect(logger.is_enabled(@bitlogger.Level::Error), content="true") + inspect(logger.is_enabled(@bitlogger.Level::Info), content="false") + + logger.error("one") + logger.error("two") + inspect(logger.pending_count(), content="2") + inspect(logger.dropped_count(), content="0") + + @async.with_task_group(group => { + group.spawn_bg(() => logger.run()) + logger.shutdown() + }) + + inspect(logger.is_closed(), content="true") + inspect(logger.pending_count(), content="0") + inspect(logger.dropped_count(), content="0") + inspect(logger.has_failed(), content="false") + inspect(logger.last_error(), content="") +} + +async test "application text async logger log supports per-call target override" { + let written_target : Ref[String] = Ref("") + let written_message : Ref[String] = Ref("") + let written_fields : Ref[Array[@bitlogger.Field]] = Ref([]) + let logger : ApplicationTextAsyncLogger = build_application_text_async_logger( + AsyncLoggerBuildConfig::new( + logger=@bitlogger.text_console( + min_level=@bitlogger.Level::Warn, + target="async.app.text.default", + text_formatter=@bitlogger.TextFormatterConfig::new(show_timestamp=false, separator=" | "), + ), + async_config=AsyncLoggerConfig::new(max_pending=4), + ), + ) + .with_context_fields([@bitlogger.field("service", "bitlogger")]) + .with_patch(fn(rec) { + written_target.val = rec.target + written_message.val = rec.message + written_fields.val = rec.fields + rec + }) + + @async.with_task_group(group => { + group.spawn_bg(() => logger.run()) + logger.log( + @bitlogger.Level::Error, + "override", + fields=[@bitlogger.field("mode", "test")], + target="async.app.text.override", + ) + logger.shutdown() + }) + + inspect(written_target.val, content="async.app.text.override") + inspect(written_message.val, content="override") + inspect(written_fields.val.length(), content="2") + inspect(written_fields.val[0].key, content="service") + inspect(written_fields.val[0].value, content="bitlogger") + inspect(written_fields.val[1].key, content="mode") + inspect(written_fields.val[1].value, content="test") + + let second_target : Ref[String] = Ref("") + let second_message : Ref[String] = Ref("") + let second_fields : Ref[Array[@bitlogger.Field]] = Ref([]) + let second : ApplicationTextAsyncLogger = build_application_text_async_logger( + AsyncLoggerBuildConfig::new( + logger=@bitlogger.text_console( + min_level=@bitlogger.Level::Warn, + target="async.app.text.default", + text_formatter=@bitlogger.TextFormatterConfig::new(show_timestamp=false, separator=" | "), + ), + async_config=AsyncLoggerConfig::new(max_pending=4), + ), + ) + .with_context_fields([@bitlogger.field("service", "bitlogger")]) + .with_patch(fn(rec) { + second_target.val = rec.target + second_message.val = rec.message + second_fields.val = rec.fields + rec + }) + + @async.with_task_group(group => { + group.spawn_bg(() => second.run()) + second.log(@bitlogger.Level::Error, "default") + second.shutdown() + }) + + inspect(second_target.val, content="async.app.text.default") + inspect(second_message.val, content="default") + inspect(second_fields.val.length(), content="1") + inspect(second_fields.val[0].key, content="service") +} + +async test "application text async logger severity helpers use stored target without override" { + let written_levels : Ref[Array[String]] = Ref([]) + let written_targets : Ref[Array[String]] = Ref([]) + let written_fields : Ref[Array[Array[@bitlogger.Field]]] = Ref([]) + let logger : ApplicationTextAsyncLogger = build_application_text_async_logger( + AsyncLoggerBuildConfig::new( + logger=@bitlogger.text_console( + min_level=@bitlogger.Level::Info, + target="async.app.text.helpers", + text_formatter=@bitlogger.TextFormatterConfig::new(show_timestamp=false, separator=" | "), + ), + async_config=AsyncLoggerConfig::new(max_pending=4), + ), + ) + .with_context_fields([@bitlogger.field("service", "bitlogger")]) + .with_patch(fn(rec) { + written_levels.val.push(rec.level.label()) + written_targets.val.push(rec.target) + written_fields.val.push(rec.fields) + rec + }) + + @async.with_task_group(group => { + group.spawn_bg(() => logger.run()) + logger.info("info", fields=[@bitlogger.field("mode", "info")]) + logger.warn("warn", fields=[@bitlogger.field("mode", "warn")]) + logger.error("error", fields=[@bitlogger.field("mode", "error")]) + logger.shutdown() + }) + + inspect(written_levels.val.length(), content="3") + inspect(written_levels.val[0], content="INFO") + inspect(written_levels.val[1], content="WARN") + inspect(written_levels.val[2], content="ERROR") + inspect(written_targets.val.length(), content="3") + inspect(written_targets.val[0], content="async.app.text.helpers") + inspect(written_targets.val[1], content="async.app.text.helpers") + inspect(written_targets.val[2], content="async.app.text.helpers") + inspect(written_fields.val[0].length(), content="2") + inspect(written_fields.val[1].length(), content="2") + inspect(written_fields.val[2].length(), content="2") + inspect(written_fields.val[0][0].key, content="service") + inspect(written_fields.val[0][1].value, content="info") + inspect(written_fields.val[1][0].key, content="service") + inspect(written_fields.val[1][1].value, content="warn") + inspect(written_fields.val[2][0].key, content="service") + inspect(written_fields.val[2][1].value, content="error") +} + +test "application text async logger builder ignores sync queue layer" { + let logger = build_application_text_async_logger( + AsyncLoggerBuildConfig::new( + logger=@bitlogger.LoggerConfig::new( + min_level=@bitlogger.Level::Warn, + target="async.app.text.queued", + queue=Some(@bitlogger.QueueConfig::new(3, overflow=@bitlogger.QueueOverflowPolicy::DropNewest)), + sink=@bitlogger.SinkConfig::new( + kind=@bitlogger.SinkKind::TextConsole, + text_formatter=@bitlogger.TextFormatterConfig::new(show_timestamp=false, separator=" | "), + ), + ), + async_config=AsyncLoggerConfig::new(max_pending=2), + ), + ) + + inspect(logger.is_enabled(@bitlogger.Level::Error), content="true") + inspect(logger.is_enabled(@bitlogger.Level::Info), content="false") + inspect(logger.target, content="async.app.text.queued") + inspect(logger.pending_count(), content="0") + inspect(logger.dropped_count(), content="0") +} + +test "application text async logger ignores sink kind and still uses text formatter" { + let logger : ApplicationTextAsyncLogger = build_application_text_async_logger( + AsyncLoggerBuildConfig::new( + logger=@bitlogger.LoggerConfig::new( + min_level=@bitlogger.Level::Warn, + target="async.app.text.kind.alias", + sink=@bitlogger.SinkConfig::new( + kind=@bitlogger.SinkKind::File, + path="ignored.log", + text_formatter=@bitlogger.TextFormatterConfig::new( + show_timestamp=false, + separator=" | ", + template="TEXT:{target}:{message}", + ), + ), + ), + async_config=AsyncLoggerConfig::new(max_pending=2), + ), + ) + + inspect(logger.is_enabled(@bitlogger.Level::Error), content="true") + inspect(logger.is_enabled(@bitlogger.Level::Info), content="false") + inspect(logger.target, content="async.app.text.kind.alias") + let rendered = (logger.sink.formatter)( + @bitlogger.Record::new(@bitlogger.Level::Error, "boom", target="async.app.text.kind.alias"), + ) + inspect(rendered, content="TEXT:async.app.text.kind.alias:boom") +} + test "build async text logger keeps text-console config fields" { let logger = build_async_text_logger( AsyncLoggerBuildConfig::new( @@ -450,6 +3536,373 @@ test "build async text logger keeps text-console config fields" { AsyncFlushPolicy::Batch => "Batch" AsyncFlushPolicy::Shutdown => "Shutdown" }, content="Never") + let rendered = (logger.sink.formatter)( + @bitlogger.Record::new(@bitlogger.Level::Error, "boom", target="async.text.direct"), + ) + inspect(rendered, content="[ERROR] | [async.text.direct] | boom") +} + +test "build async text logger ignores sink kind and still uses text formatter" { + let logger = build_async_text_logger( + AsyncLoggerBuildConfig::new( + logger=@bitlogger.LoggerConfig::new( + min_level=@bitlogger.Level::Warn, + target="async.text.kind", + sink=@bitlogger.SinkConfig::new( + kind=@bitlogger.SinkKind::File, + path="ignored.log", + text_formatter=@bitlogger.TextFormatterConfig::new( + show_timestamp=false, + separator=" | ", + template="TEXT:{target}:{message}", + ), + ), + ), + async_config=AsyncLoggerConfig::new(max_pending=2), + ), + ) + + inspect(logger.is_enabled(@bitlogger.Level::Error), content="true") + inspect(logger.is_enabled(@bitlogger.Level::Info), content="false") + inspect(logger.target, content="async.text.kind") + let rendered = (logger.sink.formatter)( + @bitlogger.Record::new(@bitlogger.Level::Error, "boom", target="async.text.kind"), + ) + inspect(rendered, content="TEXT:async.text.kind:boom") +} + +async test "build async text logger keeps direct helper surface" { + let logger = build_async_text_logger( + AsyncLoggerBuildConfig::new( + logger=@bitlogger.LoggerConfig::new( + min_level=@bitlogger.Level::Warn, + target="async.text.helpers", + timestamp=true, + sink=@bitlogger.SinkConfig::new( + kind=@bitlogger.SinkKind::TextConsole, + text_formatter=@bitlogger.TextFormatterConfig::new(show_timestamp=false, separator=" | "), + ), + ), + async_config=AsyncLoggerConfig::new( + max_pending=2, + overflow=AsyncOverflowPolicy::DropOldest, + flush=AsyncFlushPolicy::Shutdown, + ), + ), + ) + + let state = logger.state() + inspect(logger.is_enabled(@bitlogger.Level::Error), content="true") + inspect(logger.is_enabled(@bitlogger.Level::Info), content="false") + inspect(logger.target, content="async.text.helpers") + inspect(logger.timestamp, content="true") + inspect(state.pending_count, content="0") + inspect(state.dropped_count, content="0") + inspect(state.is_closed, content="false") + inspect(state.is_running, content="false") + inspect(state.has_failed, content="false") + inspect(match state.flush_policy { + AsyncFlushPolicy::Never => "Never" + AsyncFlushPolicy::Batch => "Batch" + AsyncFlushPolicy::Shutdown => "Shutdown" + }, content="Shutdown") + + logger.info("skip") + logger.error("one") + logger.error("two") + logger.error("three") + inspect(logger.pending_count(), content="2") + inspect(logger.dropped_count(), content="1") + inspect(logger.is_closed(), content="false") + inspect(logger.is_running(), content="false") + + @async.with_task_group(group => { + group.spawn_bg(() => logger.run()) + logger.shutdown() + }) + + inspect(logger.is_closed(), content="true") + inspect(logger.is_running(), content="false") + inspect(logger.pending_count(), content="0") + inspect(logger.dropped_count(), content="1") + inspect(logger.has_failed(), content="false") + inspect(logger.last_error(), content="") +} + +async test "build async text logger log supports per-call target override" { + let written_target : Ref[String] = Ref("") + + let logger = build_async_text_logger( + AsyncLoggerBuildConfig::new( + logger=@bitlogger.LoggerConfig::new( + min_level=@bitlogger.Level::Warn, + target="async.text.builder.default", + sink=@bitlogger.SinkConfig::new( + kind=@bitlogger.SinkKind::TextConsole, + text_formatter=@bitlogger.TextFormatterConfig::new(show_timestamp=false, separator=" | "), + ), + ), + async_config=AsyncLoggerConfig::new( + max_pending=2, + overflow=AsyncOverflowPolicy::Blocking, + flush=AsyncFlushPolicy::Never, + ), + ), + ) + .with_patch(fn(rec) { + written_target.val = rec.target + rec + }) + + @async.with_task_group(group => { + group.spawn_bg(() => logger.run()) + logger.log( + @bitlogger.Level::Error, + "override", + target="async.text.builder.override", + ) + logger.shutdown() + }) + + inspect(written_target.val, content="async.text.builder.override") + + let second_target : Ref[String] = Ref("") + + let second = build_async_text_logger( + AsyncLoggerBuildConfig::new( + logger=@bitlogger.LoggerConfig::new( + min_level=@bitlogger.Level::Warn, + target="async.text.builder.default", + sink=@bitlogger.SinkConfig::new( + kind=@bitlogger.SinkKind::TextConsole, + text_formatter=@bitlogger.TextFormatterConfig::new(show_timestamp=false, separator=" | "), + ), + ), + async_config=AsyncLoggerConfig::new( + max_pending=2, + overflow=AsyncOverflowPolicy::Blocking, + flush=AsyncFlushPolicy::Never, + ), + ), + ) + .with_patch(fn(rec) { + second_target.val = rec.target + rec + }) + + @async.with_task_group(group => { + group.spawn_bg(() => second.run()) + second.error("default") + second.shutdown() + }) + + inspect(second_target.val, content="async.text.builder.default") +} + +async test "build async text logger severity helpers use stored target without override" { + let written_targets : Ref[Array[String]] = Ref([]) + + let logger = build_async_text_logger( + AsyncLoggerBuildConfig::new( + logger=@bitlogger.LoggerConfig::new( + min_level=@bitlogger.Level::Info, + target="async.text.builder.helpers", + sink=@bitlogger.SinkConfig::new( + kind=@bitlogger.SinkKind::TextConsole, + text_formatter=@bitlogger.TextFormatterConfig::new(show_timestamp=false, separator=" | "), + ), + ), + async_config=AsyncLoggerConfig::new( + max_pending=4, + overflow=AsyncOverflowPolicy::Blocking, + flush=AsyncFlushPolicy::Never, + ), + ), + ) + .with_patch(fn(rec) { + written_targets.val.push(rec.target) + rec + }) + + @async.with_task_group(group => { + group.spawn_bg(() => logger.run()) + logger.info("first") + logger.warn("second") + logger.error("third") + logger.shutdown() + }) + + inspect(written_targets.val.length(), content="3") + inspect(written_targets.val[0], content="async.text.builder.helpers") + inspect(written_targets.val[1], content="async.text.builder.helpers") + inspect(written_targets.val[2], content="async.text.builder.helpers") +} + +async test "build async text logger batch flush policy keeps default no-op flush callback" { + let config = AsyncLoggerBuildConfig::new( + logger=@bitlogger.LoggerConfig::new( + min_level=@bitlogger.Level::Info, + target="async.text.batch.flush", + timestamp=true, + sink=@bitlogger.SinkConfig::new( + kind=@bitlogger.SinkKind::TextConsole, + text_formatter=@bitlogger.TextFormatterConfig::new( + show_timestamp=false, + separator=" | ", + template="TEXT:{target}:{message}", + ), + ), + ), + async_config=AsyncLoggerConfig::new( + max_pending=4, + overflow=AsyncOverflowPolicy::Blocking, + max_batch=2, + flush=AsyncFlushPolicy::Batch, + ), + ) + let configured = build_async_text_logger(config) + let manual = async_logger( + @bitlogger.text_console_sink(config.logger.sink.text_formatter.to_formatter()), + config=config.async_config, + min_level=config.logger.min_level, + target=config.logger.target, + flush=fn(_) -> Int raise { + raise TestFlushError("text batch flush exploded") + }, + ).with_timestamp(enabled=config.logger.timestamp) + + @async.with_task_group(group => { + group.spawn_bg(() => configured.run()) + group.spawn_bg(allow_failure=true, () => manual.run()) + + configured.error("one") + configured.error("two") + manual.error("one") + manual.error("two") + + configured.wait_idle() + manual.wait_idle() + + inspect(match configured.flush_policy() { + AsyncFlushPolicy::Never => "Never" + AsyncFlushPolicy::Batch => "Batch" + AsyncFlushPolicy::Shutdown => "Shutdown" + }, content="Batch") + inspect(match manual.flush_policy() { + AsyncFlushPolicy::Never => "Never" + AsyncFlushPolicy::Batch => "Batch" + AsyncFlushPolicy::Shutdown => "Shutdown" + }, content="Batch") + inspect(configured.has_failed(), content="false") + inspect(configured.last_error(), content="") + inspect(configured.pending_count(), content="0") + inspect(manual.has_failed(), content="true") + inspect(manual.last_error().contains("TestFlushError"), content="true") + + configured.shutdown() + manual.shutdown(clear=true) + }) + + inspect(configured.is_closed(), content="true") + inspect(configured.is_running(), content="false") + inspect(configured.has_failed(), content="false") + inspect(configured.last_error(), content="") + inspect(configured.pending_count(), content="0") + inspect(manual.is_closed(), content="true") + inspect(manual.is_running(), content="false") + inspect(manual.has_failed(), content="true") + inspect(manual.last_error().contains("TestFlushError"), content="true") +} + +async test "build async text logger shutdown flush policy keeps default no-op flush callback" { + let config = AsyncLoggerBuildConfig::new( + logger=@bitlogger.LoggerConfig::new( + min_level=@bitlogger.Level::Info, + target="async.text.shutdown.flush", + timestamp=true, + sink=@bitlogger.SinkConfig::new( + kind=@bitlogger.SinkKind::TextConsole, + text_formatter=@bitlogger.TextFormatterConfig::new( + show_timestamp=false, + separator=" | ", + template="TEXT:{target}:{message}", + ), + ), + ), + async_config=AsyncLoggerConfig::new( + max_pending=4, + overflow=AsyncOverflowPolicy::Blocking, + max_batch=2, + flush=AsyncFlushPolicy::Shutdown, + ), + ) + let configured = build_async_text_logger(config) + let manual = async_logger( + @bitlogger.text_console_sink(config.logger.sink.text_formatter.to_formatter()), + config=config.async_config, + min_level=config.logger.min_level, + target=config.logger.target, + flush=fn(_) -> Int raise { + raise TestFlushError("text shutdown flush exploded") + }, + ).with_timestamp(enabled=config.logger.timestamp) + + @async.with_task_group(group => { + group.spawn_bg(() => configured.run()) + group.spawn_bg(allow_failure=true, () => manual.run()) + + configured.error("one") + configured.error("two") + manual.error("one") + manual.error("two") + + configured.shutdown() + manual.shutdown() + }) + + inspect(match configured.flush_policy() { + AsyncFlushPolicy::Never => "Never" + AsyncFlushPolicy::Batch => "Batch" + AsyncFlushPolicy::Shutdown => "Shutdown" + }, content="Shutdown") + inspect(match manual.flush_policy() { + AsyncFlushPolicy::Never => "Never" + AsyncFlushPolicy::Batch => "Batch" + AsyncFlushPolicy::Shutdown => "Shutdown" + }, content="Shutdown") + inspect(configured.is_closed(), content="true") + inspect(configured.is_running(), content="false") + inspect(configured.has_failed(), content="false") + inspect(configured.last_error(), content="") + inspect(configured.pending_count(), content="0") + inspect(manual.is_closed(), content="true") + inspect(manual.is_running(), content="false") + inspect(manual.has_failed(), content="true") + inspect(manual.last_error().contains("TestFlushError"), content="true") + inspect(manual.pending_count(), content="0") +} + +test "build async text logger ignores sync queue layer" { + let logger = build_async_text_logger( + AsyncLoggerBuildConfig::new( + logger=@bitlogger.LoggerConfig::new( + min_level=@bitlogger.Level::Warn, + target="async.text.queued", + queue=Some(@bitlogger.QueueConfig::new(3, overflow=@bitlogger.QueueOverflowPolicy::DropNewest)), + sink=@bitlogger.SinkConfig::new( + kind=@bitlogger.SinkKind::TextConsole, + text_formatter=@bitlogger.TextFormatterConfig::new(show_timestamp=false, separator=" | "), + ), + ), + async_config=AsyncLoggerConfig::new(max_pending=2), + ), + ) + + inspect(logger.is_enabled(@bitlogger.Level::Error), content="true") + inspect(logger.is_enabled(@bitlogger.Level::Info), content="false") + inspect(logger.target, content="async.text.queued") + inspect(logger.pending_count(), content="0") + inspect(logger.dropped_count(), content="0") } test "application async logger can be built from config text" { @@ -460,3 +3913,333 @@ test "application async logger can be built from config text" { inspect(logger.is_enabled(@bitlogger.Level::Info), content="false") inspect(logger.target, content="async.app.json") } + +async test "application async parse-build matches parsed direct async builder behavior" { + let raw = "{\"logger\":{\"min_level\":\"warn\",\"target\":\"async.app.json.same-build\",\"timestamp\":true,\"queue\":{\"max_pending\":3,\"overflow\":\"DropNewest\"},\"sink\":{\"kind\":\"console\"}},\"async_config\":{\"max_pending\":2,\"overflow\":\"DropOldest\",\"max_batch\":1,\"linger_ms\":0,\"flush\":\"Shutdown\"}}" + let application = parse_and_build_application_async_logger(raw) + let direct = build_async_logger(parse_async_logger_build_config_text(raw)) + let application_state = application.state() + let direct_state = direct.state() + + inspect(application.target, content=direct.target) + inspect(application.timestamp == direct.timestamp, content="true") + inspect( + application.is_enabled(@bitlogger.Level::Error) == direct.is_enabled(@bitlogger.Level::Error), + content="true", + ) + inspect( + application.is_enabled(@bitlogger.Level::Info) == direct.is_enabled(@bitlogger.Level::Info), + content="true", + ) + inspect( + stringify_async_logger_state(application_state) == stringify_async_logger_state(direct_state), + content="true", + ) + let application_sink_kind = match application.sink { + @bitlogger.RuntimeSink::QueuedConsole(_) => "QueuedConsole" + @bitlogger.RuntimeSink::QueuedJsonConsole(_) => "QueuedJsonConsole" + @bitlogger.RuntimeSink::QueuedTextConsole(_) => "QueuedTextConsole" + @bitlogger.RuntimeSink::QueuedFile(_) => "QueuedFile" + @bitlogger.RuntimeSink::Console(_) => "Console" + @bitlogger.RuntimeSink::JsonConsole(_) => "JsonConsole" + @bitlogger.RuntimeSink::TextConsole(_) => "TextConsole" + @bitlogger.RuntimeSink::File(_) => "File" + } + let direct_sink_kind = match direct.sink { + @bitlogger.RuntimeSink::QueuedConsole(_) => "QueuedConsole" + @bitlogger.RuntimeSink::QueuedJsonConsole(_) => "QueuedJsonConsole" + @bitlogger.RuntimeSink::QueuedTextConsole(_) => "QueuedTextConsole" + @bitlogger.RuntimeSink::QueuedFile(_) => "QueuedFile" + @bitlogger.RuntimeSink::Console(_) => "Console" + @bitlogger.RuntimeSink::JsonConsole(_) => "JsonConsole" + @bitlogger.RuntimeSink::TextConsole(_) => "TextConsole" + @bitlogger.RuntimeSink::File(_) => "File" + } + inspect(application_sink_kind == direct_sink_kind, content="true") + + application.info("skip") + application.error("one") + application.error("two") + application.error("three") + direct.info("skip") + direct.error("one") + direct.error("two") + direct.error("three") + + inspect(application.pending_count() == direct.pending_count(), content="true") + inspect(application.dropped_count() == direct.dropped_count(), content="true") + inspect(application.is_closed() == direct.is_closed(), content="true") + inspect(application.is_running() == direct.is_running(), content="true") + inspect(application.sink.pending_count() == direct.sink.pending_count(), content="true") + inspect(application.sink.dropped_count() == direct.sink.dropped_count(), content="true") + + @async.with_task_group(group => { + group.spawn_bg(() => application.run()) + group.spawn_bg(() => direct.run()) + application.shutdown() + direct.shutdown() + }) + + inspect(application.is_closed() == direct.is_closed(), content="true") + inspect(application.is_running() == direct.is_running(), content="true") + inspect(application.pending_count() == direct.pending_count(), content="true") + inspect(application.dropped_count() == direct.dropped_count(), content="true") + inspect(application.has_failed() == direct.has_failed(), content="true") + inspect(application.last_error() == direct.last_error(), content="true") +} + +async test "application async parse-build preserves file-backed runtime helpers" { + let raw = "{\"logger\":{\"min_level\":\"warn\",\"target\":\"async.app.json.file.same-build\",\"queue\":{\"max_pending\":3,\"overflow\":\"DropOldest\"},\"sink\":{\"kind\":\"file\",\"path\":\"async-app-json-file-same-build.log\"}},\"async_config\":{\"max_pending\":2,\"overflow\":\"DropOldest\",\"max_batch\":1,\"linger_ms\":0,\"flush\":\"Shutdown\"}}" + let application = parse_and_build_application_async_logger(raw) + let direct = build_async_logger(parse_async_logger_build_config_text(raw)) + + application.info("skip") + application.error("one") + application.error("two") + application.error("three") + direct.info("skip") + direct.error("one") + direct.error("two") + direct.error("three") + + inspect(application.pending_count() == direct.pending_count(), content="true") + inspect(application.dropped_count() == direct.dropped_count(), content="true") + inspect(application.sink.pending_count() == direct.sink.pending_count(), content="true") + inspect(application.sink.dropped_count() == direct.sink.dropped_count(), content="true") + inspect(application.sink.file_available() == direct.sink.file_available(), content="true") + inspect(application.sink.file_append_mode() == direct.sink.file_append_mode(), content="true") + inspect(application.sink.file_auto_flush() == direct.sink.file_auto_flush(), content="true") + + let application_state = application.sink.file_state() + let direct_state = direct.sink.file_state() + inspect(application_state.path == direct_state.path, content="true") + inspect(application_state.available == direct_state.available, content="true") + inspect(application_state.append == direct_state.append, content="true") + inspect(application_state.auto_flush == direct_state.auto_flush, content="true") + inspect(application_state.open_failures == direct_state.open_failures, content="true") + inspect(application_state.write_failures == direct_state.write_failures, content="true") + inspect(application_state.flush_failures == direct_state.flush_failures, content="true") + inspect(application_state.rotation_failures == direct_state.rotation_failures, content="true") + + match (application.sink.file_runtime_state(), direct.sink.file_runtime_state()) { + (Some(snapshot), Some(other)) => { + inspect(snapshot.file.path == other.file.path, content="true") + inspect(snapshot.file.available == other.file.available, content="true") + inspect(snapshot.queued == other.queued, content="true") + inspect(snapshot.pending_count == other.pending_count, content="true") + inspect(snapshot.dropped_count == other.dropped_count, content="true") + } + _ => inspect(false, content="true") + } + + inspect(application.sink.file_set_append_mode(false) == direct.sink.file_set_append_mode(false), content="true") + inspect(application.sink.file_append_mode() == direct.sink.file_append_mode(), content="true") + inspect(application.sink.file_set_auto_flush(false) == direct.sink.file_set_auto_flush(false), content="true") + inspect(application.sink.file_auto_flush() == direct.sink.file_auto_flush(), content="true") + inspect( + application.sink.file_set_rotation(Some(@bitlogger.file_rotation(36, max_backups=2))) == + direct.sink.file_set_rotation(Some(@bitlogger.file_rotation(36, max_backups=2))), + content="true", + ) + inspect(application.sink.file_rotation_enabled() == direct.sink.file_rotation_enabled(), content="true") + inspect(application.sink.file_reopen_append() == direct.sink.file_reopen_append(), content="true") + inspect(application.sink.file_append_mode() == direct.sink.file_append_mode(), content="true") + inspect(application.sink.file_clear_rotation() == direct.sink.file_clear_rotation(), content="true") + inspect(application.sink.file_reset_policy() == direct.sink.file_reset_policy(), content="true") + inspect(application.sink.file_policy_matches_default() == direct.sink.file_policy_matches_default(), content="true") + inspect( + application.sink.file_reset_failure_counters() == direct.sink.file_reset_failure_counters(), + content="true", + ) + inspect(application.sink.file_flush() == direct.sink.file_flush(), content="true") + inspect(application.pending_count() == direct.pending_count(), content="true") + inspect(application.sink.file_close() == direct.sink.file_close(), content="true") +} + +async test "parsed application async logger keeps async helper surface" { + let logger : ApplicationAsyncLogger = parse_and_build_application_async_logger( + "{\"logger\":{\"min_level\":\"warn\",\"target\":\"async.app.json.helpers\",\"sink\":{\"kind\":\"console\"}},\"async_config\":{\"max_pending\":2,\"overflow\":\"DropOldest\",\"max_batch\":1,\"linger_ms\":0,\"flush\":\"Shutdown\"}}", + ) + + let state = logger.state() + inspect(state.pending_count, content="0") + inspect(state.dropped_count, content="0") + inspect(state.is_closed, content="false") + inspect(state.is_running, content="false") + inspect(state.has_failed, content="false") + inspect(match state.flush_policy { + AsyncFlushPolicy::Never => "Never" + AsyncFlushPolicy::Batch => "Batch" + AsyncFlushPolicy::Shutdown => "Shutdown" + }, content="Shutdown") + + logger.info("skip") + logger.error("one") + logger.error("two") + logger.error("three") + inspect(logger.pending_count(), content="2") + inspect(logger.dropped_count(), content="1") + inspect(logger.is_closed(), content="false") + inspect(logger.is_running(), content="false") + + @async.with_task_group(group => { + group.spawn_bg(() => logger.run()) + logger.shutdown() + }) + + inspect(logger.is_closed(), content="true") + inspect(logger.is_running(), content="false") + inspect(logger.pending_count(), content="0") + inspect(logger.dropped_count(), content="1") + inspect(logger.has_failed(), content="false") + inspect(logger.last_error(), content="") +} + +async test "parsed application async logger shutdown clear abandons pending records" { + let logger : ApplicationAsyncLogger = parse_and_build_application_async_logger( + "{\"logger\":{\"min_level\":\"info\",\"target\":\"async.app.json.clear\",\"sink\":{\"kind\":\"console\"}},\"async_config\":{\"max_pending\":2,\"overflow\":\"Blocking\",\"max_batch\":1,\"linger_ms\":0,\"flush\":\"Never\"}}", + ) + + logger.info("one") + inspect(logger.pending_count(), content="1") + inspect(logger.dropped_count(), content="0") + logger.shutdown(clear=true) + inspect(logger.is_closed(), content="true") + inspect(logger.is_running(), content="false") + inspect(logger.pending_count(), content="0") + inspect(logger.dropped_count(), content="1") +} + +async test "parsed application async logger keeps broader async composition surface" { + let logger : ApplicationAsyncLogger = parse_and_build_application_async_logger( + "{\"logger\":{\"min_level\":\"warn\",\"target\":\"async.app.json.compose\",\"sink\":{\"kind\":\"console\"}},\"async_config\":{\"max_pending\":2,\"overflow\":\"DropNewest\",\"max_batch\":1,\"linger_ms\":0,\"flush\":\"Shutdown\"}}", + ) + .with_timestamp() + .with_context_fields([@bitlogger.field("service", "bitlogger")]) + .child("worker") + + inspect(logger.target, content="async.app.json.compose.worker") + inspect(logger.timestamp, content="true") + inspect(logger.is_enabled(@bitlogger.Level::Error), content="true") + inspect(logger.is_enabled(@bitlogger.Level::Info), content="false") + + logger.error("one") + logger.error("two") + inspect(logger.pending_count(), content="2") + inspect(logger.dropped_count(), content="0") + + @async.with_task_group(group => { + group.spawn_bg(() => logger.run()) + logger.shutdown() + }) + + inspect(logger.is_closed(), content="true") + inspect(logger.pending_count(), content="0") + inspect(logger.dropped_count(), content="0") + inspect(logger.has_failed(), content="false") + inspect(logger.last_error(), content="") +} + +async test "parsed application async logger log supports per-call target override" { + let written_target : Ref[String] = Ref("") + + let logger : ApplicationAsyncLogger = parse_and_build_application_async_logger( + "{\"logger\":{\"min_level\":\"warn\",\"target\":\"async.app.json.default\",\"sink\":{\"kind\":\"console\"}},\"async_config\":{\"max_pending\":2,\"overflow\":\"Blocking\",\"max_batch\":1,\"linger_ms\":0,\"flush\":\"Never\"}}", + ) + .with_patch(fn(rec) { + written_target.val = rec.target + rec + }) + + @async.with_task_group(group => { + group.spawn_bg(() => logger.run()) + logger.log( + @bitlogger.Level::Error, + "override", + target="async.app.json.override", + ) + logger.shutdown() + }) + + inspect(written_target.val, content="async.app.json.override") + + let second_target : Ref[String] = Ref("") + + let second : ApplicationAsyncLogger = parse_and_build_application_async_logger( + "{\"logger\":{\"min_level\":\"warn\",\"target\":\"async.app.json.default\",\"sink\":{\"kind\":\"console\"}},\"async_config\":{\"max_pending\":2,\"overflow\":\"Blocking\",\"max_batch\":1,\"linger_ms\":0,\"flush\":\"Never\"}}", + ) + .with_patch(fn(rec) { + second_target.val = rec.target + rec + }) + + @async.with_task_group(group => { + group.spawn_bg(() => second.run()) + second.error("default") + second.shutdown() + }) + + inspect(second_target.val, content="async.app.json.default") +} + +async test "parsed application async logger severity helpers use stored target without override" { + let written_targets : Ref[Array[String]] = Ref([]) + + let logger : ApplicationAsyncLogger = parse_and_build_application_async_logger( + "{\"logger\":{\"min_level\":\"trace\",\"target\":\"async.app.json.helpers.target\",\"sink\":{\"kind\":\"console\"}},\"async_config\":{\"max_pending\":4,\"overflow\":\"Blocking\",\"max_batch\":1,\"linger_ms\":0,\"flush\":\"Never\"}}", + ) + .with_patch(fn(rec) { + written_targets.val.push(rec.target) + rec + }) + + @async.with_task_group(group => { + group.spawn_bg(() => logger.run()) + logger.debug("first") + logger.info("second") + logger.error("third") + logger.shutdown() + }) + + inspect(written_targets.val.length(), content="3") + inspect(written_targets.val[0], content="async.app.json.helpers.target") + inspect(written_targets.val[1], content="async.app.json.helpers.target") + inspect(written_targets.val[2], content="async.app.json.helpers.target") +} + +test "application async logger parse-and-build preserves parsed sync queue layer" { + let logger = parse_and_build_application_async_logger( + "{\"logger\":{\"min_level\":\"warn\",\"target\":\"async.app.json.queued\",\"queue\":{\"max_pending\":3,\"overflow\":\"DropNewest\"},\"sink\":{\"kind\":\"console\"}},\"async_config\":{\"max_pending\":2,\"overflow\":\"DropNewest\",\"max_batch\":1,\"linger_ms\":0,\"flush\":\"Never\"}}", + ) + + inspect(logger.is_enabled(@bitlogger.Level::Error), content="true") + inspect(logger.is_enabled(@bitlogger.Level::Info), content="false") + inspect(logger.target, content="async.app.json.queued") + inspect(match logger.sink { + @bitlogger.RuntimeSink::QueuedConsole(_) => "QueuedConsole" + @bitlogger.RuntimeSink::QueuedJsonConsole(_) => "QueuedJsonConsole" + @bitlogger.RuntimeSink::QueuedTextConsole(_) => "QueuedTextConsole" + @bitlogger.RuntimeSink::QueuedFile(_) => "QueuedFile" + _ => "Other" + }, content="QueuedConsole") +} + +test "async parse-build facades forward parse failures" { + let raw = "{\"logger\":{\"sink\":{\"kind\":\"file\",\"path\":\"\"}},\"async_config\":{\"max_pending\":2}}" + + let application_error = (fn() -> String raise { + ignore(parse_and_build_application_async_logger(raw)) + "no error" + })() catch { + err => err.to_string() + } + inspect(application_error != "no error", content="true") + + let library_error = (fn() -> String raise { + ignore(parse_and_build_library_async_logger(raw)) + "no error" + })() catch { + err => err.to_string() + } + inspect(library_error != "no error", content="true") +} diff --git a/src/BitLogger_test.mbt b/src/BitLogger_test.mbt index 461e4bd..7417853 100644 --- a/src/BitLogger_test.mbt +++ b/src/BitLogger_test.mbt @@ -116,6 +116,63 @@ test "logger config parser reads file rotation options" { } } +test "logger config parser fills omitted top-level keys from defaults" { + let config = parse_logger_config_text("{}") + inspect(config.min_level.label(), content="INFO") + inspect(config.target, content="") + inspect(config.timestamp, content="false") + inspect(config.queue is None, content="true") + inspect(match config.sink.kind { + SinkKind::Console => "Console" + SinkKind::JsonConsole => "JsonConsole" + SinkKind::TextConsole => "TextConsole" + SinkKind::File => "File" + }, content="Console") + inspect(config.sink.path, content="") + inspect(config.sink.append, content="true") + inspect(config.sink.auto_flush, content="true") + inspect(config.sink.rotation is None, content="true") + inspect(config.sink.text_formatter.show_timestamp, content="true") + inspect(config.sink.text_formatter.separator, content=" ") + inspect(config.sink.text_formatter.field_separator, content=" ") + inspect(config.sink.text_formatter.template, content="") +} + +test "logger config parser fills nested queue and formatter defaults" { + let config = parse_logger_config_text( + "{\"sink\":{\"kind\":\"text_console\",\"text_formatter\":{\"separator\":\" | \"}},\"queue\":{\"max_pending\":4}}", + ) + inspect(match config.sink.kind { + SinkKind::Console => "Console" + SinkKind::JsonConsole => "JsonConsole" + SinkKind::TextConsole => "TextConsole" + SinkKind::File => "File" + }, content="TextConsole") + inspect(config.sink.text_formatter.show_timestamp, content="true") + inspect(config.sink.text_formatter.show_level, content="true") + inspect(config.sink.text_formatter.show_target, content="true") + inspect(config.sink.text_formatter.show_fields, content="true") + inspect(config.sink.text_formatter.separator, content=" | ") + inspect(config.sink.text_formatter.field_separator, content=" ") + inspect(config.sink.text_formatter.template, content="") + inspect(color_mode_label(config.sink.text_formatter.color_mode), content="never") + inspect(color_support_label(config.sink.text_formatter.color_support), content="truecolor") + inspect(style_markup_mode_label(config.sink.text_formatter.style_markup), content="full") + inspect(style_markup_mode_label(config.sink.text_formatter.target_style_markup), content="disabled") + inspect(style_markup_mode_label(config.sink.text_formatter.fields_style_markup), content="disabled") + inspect(config.sink.text_formatter.style_tags.length(), content="0") + match config.queue { + Some(queue) => { + inspect(queue.max_pending, content="4") + inspect(match queue.overflow { + QueueOverflowPolicy::DropNewest => "DropNewest" + QueueOverflowPolicy::DropOldest => "DropOldest" + }, content="DropNewest") + } + None => inspect(false, content="true") + } +} + test "logger config parser rejects malformed sync config input" { let invalid_json_error = (fn() -> String raise ConfigError { ignore(parse_logger_config_text("{")) @@ -268,6 +325,126 @@ test "config subtype json helpers stringify stable shapes" { ) } +test "config json helpers export stable structured shapes" { + let queue_json = queue_config_to_json( + QueueConfig::new(8, overflow=QueueOverflowPolicy::DropOldest), + ) + let queue_obj = queue_json.as_object().unwrap() + inspect(@json_parser.stringify(queue_json), content="{\"max_pending\":8,\"overflow\":\"DropOldest\"}") + inspect(queue_obj.get("max_pending").unwrap().as_number().unwrap().to_int(), content="8") + inspect(queue_obj.get("overflow").unwrap().as_string().unwrap(), content="DropOldest") + + let formatter_json = text_formatter_config_to_json( + TextFormatterConfig::new( + show_timestamp=false, + show_level=true, + show_target=false, + show_fields=true, + separator=" | ", + field_separator=",", + template="[{level}] {message} :: {fields}", + color_mode=ColorMode::Always, + color_support=ColorSupport::Basic, + style_markup=StyleMarkupMode::Builtin, + target_style_markup=StyleMarkupMode::Builtin, + fields_style_markup=StyleMarkupMode::Disabled, + style_tags={ + "accent": text_style(fg=Some("#4cc9f0"), bold=true), + }, + ), + ) + let formatter_obj = formatter_json.as_object().unwrap() + let style_tags_obj = formatter_obj.get("style_tags").unwrap().as_object().unwrap() + let accent_obj = style_tags_obj.get("accent").unwrap().as_object().unwrap() + inspect(formatter_obj.get("show_timestamp").unwrap().as_bool().unwrap(), content="false") + inspect(formatter_obj.get("show_target").unwrap().as_bool().unwrap(), content="false") + inspect(formatter_obj.get("separator").unwrap().as_string().unwrap(), content=" | ") + inspect(formatter_obj.get("field_separator").unwrap().as_string().unwrap(), content=",") + inspect(formatter_obj.get("template").unwrap().as_string().unwrap(), content="[{level}] {message} :: {fields}") + inspect(formatter_obj.get("color_mode").unwrap().as_string().unwrap(), content="always") + inspect(formatter_obj.get("color_support").unwrap().as_string().unwrap(), content="basic") + inspect(formatter_obj.get("style_markup").unwrap().as_string().unwrap(), content="builtin") + inspect(formatter_obj.get("target_style_markup").unwrap().as_string().unwrap(), content="builtin") + inspect(formatter_obj.get("fields_style_markup").unwrap().as_string().unwrap(), content="disabled") + inspect(accent_obj.get("bold").unwrap().as_bool().unwrap(), content="true") + inspect(accent_obj.get("fg").unwrap().as_string().unwrap(), content="#4cc9f0") + + let sink_json = sink_config_to_json( + SinkConfig::new( + kind=SinkKind::File, + path="demo.log", + append=false, + auto_flush=false, + rotation=Some(file_rotation(128, max_backups=2)), + text_formatter=TextFormatterConfig::new(show_timestamp=false, color_mode=ColorMode::Auto), + ), + ) + let sink_obj = sink_json.as_object().unwrap() + let sink_formatter_obj = sink_obj.get("text_formatter").unwrap().as_object().unwrap() + let rotation_obj = sink_obj.get("rotation").unwrap().as_object().unwrap() + inspect(sink_obj.get("kind").unwrap().as_string().unwrap(), content="file") + inspect(sink_obj.get("path").unwrap().as_string().unwrap(), content="demo.log") + inspect(sink_obj.get("append").unwrap().as_bool().unwrap(), content="false") + inspect(sink_obj.get("auto_flush").unwrap().as_bool().unwrap(), content="false") + inspect(sink_formatter_obj.get("show_timestamp").unwrap().as_bool().unwrap(), content="false") + inspect(sink_formatter_obj.get("color_mode").unwrap().as_string().unwrap(), content="auto") + inspect(rotation_obj.get("max_bytes").unwrap().as_number().unwrap().to_int(), content="128") + inspect(rotation_obj.get("max_backups").unwrap().as_number().unwrap().to_int(), content="2") + + let logger_json = logger_config_to_json( + LoggerConfig::new( + min_level=Level::Warn, + target="api", + timestamp=true, + sink=SinkConfig::new(kind=SinkKind::TextConsole), + queue=Some(QueueConfig::new(8, overflow=QueueOverflowPolicy::DropNewest)), + ), + ) + let logger_obj = logger_json.as_object().unwrap() + let logger_sink_obj = logger_obj.get("sink").unwrap().as_object().unwrap() + let logger_queue_obj = logger_obj.get("queue").unwrap().as_object().unwrap() + inspect(logger_obj.get("min_level").unwrap().as_string().unwrap(), content="WARN") + inspect(logger_obj.get("target").unwrap().as_string().unwrap(), content="api") + inspect(logger_obj.get("timestamp").unwrap().as_bool().unwrap(), content="true") + inspect(logger_sink_obj.get("kind").unwrap().as_string().unwrap(), content="text_console") + inspect(logger_queue_obj.get("max_pending").unwrap().as_number().unwrap().to_int(), content="8") + inspect(logger_queue_obj.get("overflow").unwrap().as_string().unwrap(), content="DropNewest") +} + +test "logger config json export materializes parsed omitted defaults" { + let parsed = parse_logger_config_text("{}") + let logger_json = logger_config_to_json(parsed) + let logger_obj = logger_json.as_object().unwrap() + let sink_obj = logger_obj.get("sink").unwrap().as_object().unwrap() + let formatter_obj = sink_obj.get("text_formatter").unwrap().as_object().unwrap() + + inspect( + @json_parser.stringify(logger_json), + content="{\"min_level\":\"INFO\",\"target\":\"\",\"timestamp\":false,\"sink\":{\"kind\":\"console\",\"path\":\"\",\"append\":true,\"auto_flush\":true,\"text_formatter\":{\"show_timestamp\":true,\"show_level\":true,\"show_target\":true,\"show_fields\":true,\"separator\":\" \",\"field_separator\":\" \",\"template\":\"\",\"color_mode\":\"never\",\"color_support\":\"truecolor\",\"style_markup\":\"full\",\"target_style_markup\":\"disabled\",\"fields_style_markup\":\"disabled\"}}}", + ) + inspect(logger_obj.get("min_level").unwrap().as_string().unwrap(), content="INFO") + inspect(logger_obj.get("target").unwrap().as_string().unwrap(), content="") + inspect(logger_obj.get("timestamp").unwrap().as_bool().unwrap(), content="false") + inspect(logger_obj.get("queue") is None, content="true") + inspect(sink_obj.get("kind").unwrap().as_string().unwrap(), content="console") + inspect(sink_obj.get("path").unwrap().as_string().unwrap(), content="") + inspect(sink_obj.get("append").unwrap().as_bool().unwrap(), content="true") + inspect(sink_obj.get("auto_flush").unwrap().as_bool().unwrap(), content="true") + inspect(formatter_obj.get("show_timestamp").unwrap().as_bool().unwrap(), content="true") + inspect(formatter_obj.get("show_level").unwrap().as_bool().unwrap(), content="true") + inspect(formatter_obj.get("show_target").unwrap().as_bool().unwrap(), content="true") + inspect(formatter_obj.get("show_fields").unwrap().as_bool().unwrap(), content="true") + inspect(formatter_obj.get("separator").unwrap().as_string().unwrap(), content=" ") + inspect(formatter_obj.get("field_separator").unwrap().as_string().unwrap(), content=" ") + inspect(formatter_obj.get("template").unwrap().as_string().unwrap(), content="") + inspect(formatter_obj.get("color_mode").unwrap().as_string().unwrap(), content="never") + inspect(formatter_obj.get("color_support").unwrap().as_string().unwrap(), content="truecolor") + inspect(formatter_obj.get("style_markup").unwrap().as_string().unwrap(), content="full") + inspect(formatter_obj.get("target_style_markup").unwrap().as_string().unwrap(), content="disabled") + inspect(formatter_obj.get("fields_style_markup").unwrap().as_string().unwrap(), content="disabled") + inspect(formatter_obj.get("style_tags") is None, content="true") +} + test "default config helpers expose baseline config shapes" { let formatter = default_text_formatter_config() inspect(formatter.show_timestamp, content="true") @@ -437,6 +614,348 @@ test "configured logger reports dropped_count for bounded queue" { inspect(logger.flush(), content="2") } +test "configured logger queue helpers stay aligned with runtime sink helpers" { + let logger = build_logger( + LoggerConfig::new( + min_level=Level::Info, + target="config.delegate", + sink=SinkConfig::new( + kind=SinkKind::TextConsole, + text_formatter=TextFormatterConfig::new(show_timestamp=false, show_target=false), + ), + queue=Some(QueueConfig::new(2, overflow=QueueOverflowPolicy::DropOldest)), + ), + ) + let sink = logger.sink + + logger.info("one") + logger.info("two") + logger.info("three") + + inspect(logger.pending_count() == sink.pending_count(), content="true") + inspect(logger.dropped_count() == sink.dropped_count(), content="true") + inspect(logger.drain(max_items=1) == sink.drain(max_items=1), content="true") + inspect(logger.pending_count() == sink.pending_count(), content="true") + inspect(logger.flush() == sink.flush(), content="true") + inspect(logger.pending_count() == sink.pending_count(), content="true") + inspect(logger.dropped_count() == sink.dropped_count(), content="true") +} + +test "configured logger close stays aligned with runtime sink close" { + 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_logger = build_logger(console_config) + let console_sink = build_logger(console_config).sink + inspect(console_logger.close() == console_sink.close(), content="true") + + let file_config = LoggerConfig::new( + target="config.close.file", + sink=SinkConfig::new(kind=SinkKind::File, path="config-close.log"), + ) + let file_logger = build_logger(file_config) + let file_sink = build_logger(file_config).sink + inspect(file_logger.close() == file_sink.close(), content="true") +} + +test "runtime sink queue helpers forward direct queue state" { + let sink = RuntimeSink::QueuedTextConsole( + queued_sink( + text_console_sink(text_formatter(show_timestamp=false, show_target=false)), + max_pending=2, + overflow=QueueOverflowPolicy::DropOldest, + ), + ) + let logger = Logger::new(sink, min_level=Level::Info, target="runtime.queue") + logger.info("one") + logger.info("two") + logger.info("three") + inspect(sink.pending_count(), content="2") + inspect(sink.dropped_count(), content="1") + inspect(sink.drain(max_items=1), content="1") + inspect(sink.pending_count(), content="1") + inspect(sink.flush(), content="1") + inspect(sink.pending_count(), content="0") +} + +test "runtime sink plain variants use documented fallback counts" { + let console_sink = RuntimeSink::Console(console_sink()) + inspect(console_sink.pending_count(), content="0") + inspect(console_sink.dropped_count(), content="0") + inspect(console_sink.flush(), content="0") + inspect(console_sink.drain(), content="0") + + let file_sink = RuntimeSink::File(file_sink("runtime-direct.log", auto_flush=false)) + inspect(file_sink.pending_count(), content="0") + inspect(file_sink.dropped_count(), content="0") + if file_sink.file_available() { + inspect(file_sink.flush(), content="1") + inspect(file_sink.drain(), content="1") + inspect(file_sink.close(), content="true") + } else { + inspect(file_sink.flush(), content="0") + inspect(file_sink.drain(), content="0") + inspect(file_sink.close(), content="false") + } +} + +test "runtime sink non-file variants expose documented file fallbacks" { + let sink = RuntimeSink::Console(console_sink()) + inspect(sink.file_available(), content="false") + inspect(sink.file_path(), content="") + inspect(sink.file_append_mode(), content="false") + inspect(sink.file_auto_flush(), content="false") + inspect(sink.file_rotation_enabled(), content="false") + inspect(sink.file_rotation_config() is None, content="true") + inspect(sink.file_open_failures(), content="0") + inspect(sink.file_write_failures(), content="0") + inspect(sink.file_flush_failures(), content="0") + inspect(sink.file_rotation_failures(), content="0") + inspect(sink.file_reopen(), content="false") + inspect(sink.file_reopen_with_current_policy(), content="false") + inspect(sink.file_reopen_append(), content="false") + inspect(sink.file_reopen_truncate(), content="false") + inspect(sink.file_set_append_mode(true), content="false") + inspect(sink.file_set_auto_flush(true), content="false") + inspect(sink.file_set_rotation(Some(file_rotation(32, max_backups=2))), content="false") + inspect(sink.file_clear_rotation(), content="false") + inspect(sink.file_set_policy(FileSinkPolicy::new()), content="false") + inspect(sink.file_reset_failure_counters(), content="false") + inspect(sink.file_reset_policy(), content="false") + inspect(sink.file_flush(), content="false") + inspect(sink.file_close(), content="false") + let policy = sink.file_policy() + let defaults = sink.file_default_policy() + let state = sink.file_state() + inspect(policy.append, content="false") + inspect(policy.auto_flush, content="false") + inspect(policy.rotation is None, content="true") + inspect(defaults.append, content="false") + inspect(defaults.auto_flush, content="false") + inspect(defaults.rotation is None, content="true") + inspect(sink.file_policy_matches_default(), content="false") + inspect(state.path, content="") + inspect(state.available, content="false") + inspect(state.append, content="false") + inspect(state.auto_flush, content="false") + inspect(state.rotation is None, content="true") + inspect(state.open_failures, content="0") + inspect(state.write_failures, content="0") + inspect(state.flush_failures, content="0") + inspect(state.rotation_failures, content="0") + inspect(sink.file_runtime_state() is None, content="true") +} + +test "runtime sink plain file helpers expose direct file state and policy" { + let sink = RuntimeSink::File( + file_sink( + "runtime-file-helpers.log", + auto_flush=false, + rotation=Some(file_rotation(40, max_backups=2)), + ), + ) + inspect(sink.file_available() == native_files_supported(), content="true") + inspect(sink.file_path(), content="runtime-file-helpers.log") + inspect(sink.file_append_mode(), content="true") + inspect(sink.file_auto_flush(), content="false") + inspect(sink.file_rotation_enabled(), content="true") + let defaults = sink.file_default_policy() + let policy = sink.file_policy() + inspect(defaults.append, content="true") + inspect(defaults.auto_flush, content="false") + inspect(policy.append, content="true") + inspect(policy.auto_flush, content="false") + inspect(sink.file_policy_matches_default(), content="true") + match sink.file_rotation_config() { + Some(rotation) => { + inspect(rotation.max_bytes, content="40") + inspect(rotation.max_backups, content="2") + } + None => inspect(false, content="true") + } + let state = sink.file_state() + inspect(state.path, content="runtime-file-helpers.log") + inspect(state.available == sink.file_available(), content="true") + inspect(state.append, content="true") + inspect(state.auto_flush, content="false") + match sink.file_runtime_state() { + Some(snapshot) => { + inspect(snapshot.queued, content="false") + inspect(snapshot.pending_count, content="0") + inspect(snapshot.dropped_count, content="0") + inspect(snapshot.file.path, content="runtime-file-helpers.log") + } + None => inspect(false, content="true") + } + inspect(sink.file_set_append_mode(false), content="true") + inspect(sink.file_set_auto_flush(true), content="true") + inspect(sink.file_clear_rotation(), content="true") + inspect(sink.file_policy_matches_default(), content="false") + inspect(sink.file_append_mode(), content="false") + inspect(sink.file_auto_flush(), content="true") + inspect(sink.file_rotation_config() is None, content="true") + inspect(sink.file_reset_policy(), content="true") + inspect(sink.file_policy_matches_default(), content="true") + inspect(sink.file_append_mode(), content="true") + inspect(sink.file_auto_flush(), content="false") + inspect(sink.file_rotation_enabled(), content="true") + if sink.file_available() { + inspect(sink.file_flush(), content="true") + inspect(sink.file_close(), content="true") + } else { + inspect(sink.file_flush(), content="false") + inspect(sink.file_close(), content="false") + } +} + +test "runtime sink queued file helpers preserve queue-aware file runtime state" { + let sink = RuntimeSink::QueuedFile( + queued_sink( + file_sink("runtime-queued-file.log", auto_flush=false), + max_pending=2, + overflow=QueueOverflowPolicy::DropNewest, + ), + ) + let logger = Logger::new(sink, min_level=Level::Info, target="runtime.file.queue") + logger.info("one") + logger.info("two") + logger.info("three") + inspect(sink.file_available() == native_files_supported(), content="true") + inspect(sink.file_path(), content="runtime-queued-file.log") + inspect(sink.pending_count(), content="2") + inspect(sink.dropped_count(), content="1") + match sink.file_runtime_state() { + Some(snapshot) => { + inspect(snapshot.queued, content="true") + inspect(snapshot.pending_count, content="2") + inspect(snapshot.dropped_count, content="1") + inspect(snapshot.file.path, content="runtime-queued-file.log") + } + None => inspect(false, content="true") + } + if sink.file_available() { + inspect(sink.file_flush(), content="true") + inspect(sink.pending_count(), content="0") + match sink.file_runtime_state() { + Some(snapshot) => inspect(snapshot.pending_count, content="0") + None => inspect(false, content="true") + } + inspect(sink.file_close(), content="true") + } else { + inspect(sink.file_flush(), content="false") + inspect(sink.pending_count(), content="0") + match sink.file_runtime_state() { + Some(snapshot) => inspect(snapshot.pending_count, content="0") + None => inspect(false, content="true") + } + inspect(sink.file_close(), content="false") + } +} + +test "runtime sink plain file reopen helpers and failure resets work directly" { + let sink = RuntimeSink::File(file_sink("runtime-reopen-direct.log")) + if sink.file_available() { + inspect(sink.close(), content="true") + inspect(sink.file_reopen_append(), content="true") + inspect(sink.file_available(), content="true") + inspect(sink.file_append_mode(), content="true") + inspect(sink.file_open_failures(), content="0") + Logger::new(sink, min_level=Level::Info, target="runtime.reopen.direct").info("reopened") + inspect(sink.file_write_failures(), content="0") + inspect(sink.file_reopen_truncate(), content="true") + inspect(sink.file_append_mode(), content="false") + inspect(sink.file_reopen(), content="true") + inspect(sink.file_append_mode(), content="false") + inspect(sink.file_reopen_with_current_policy(), content="true") + inspect(sink.file_append_mode(), content="false") + inspect(sink.file_reopen_append(), content="true") + inspect(sink.file_append_mode(), content="true") + inspect(sink.file_reset_failure_counters(), content="true") + inspect(sink.file_open_failures(), content="0") + inspect(sink.file_write_failures(), content="0") + inspect(sink.file_flush_failures(), content="0") + inspect(sink.file_rotation_failures(), content="0") + inspect(sink.close(), content="true") + } else { + inspect(sink.file_append_mode(), content="true") + inspect(sink.file_open_failures(), content="1") + Logger::new(sink, min_level=Level::Info, target="runtime.reopen.direct").info("dropped") + inspect(sink.file_write_failures(), content="1") + inspect(sink.file_reopen_append(), content="false") + inspect(sink.file_open_failures(), content="2") + inspect(sink.file_reopen_truncate(), content="false") + inspect(sink.file_append_mode(), content="false") + inspect(sink.file_reopen_with_current_policy(), content="false") + inspect(sink.file_open_failures(), content="4") + inspect(sink.file_reopen_append(), content="false") + inspect(sink.file_append_mode(), content="true") + inspect(sink.file_open_failures(), content="5") + inspect(sink.file_reset_failure_counters(), content="true") + inspect(sink.file_open_failures(), content="0") + inspect(sink.file_write_failures(), content="0") + inspect(sink.file_flush_failures(), content="0") + inspect(sink.file_rotation_failures(), content="0") + } +} + +test "runtime sink queued file reopen helpers and failure resets work directly" { + let sink = RuntimeSink::QueuedFile( + queued_sink(file_sink("runtime-reopen-queued.log"), max_pending=2), + ) + if sink.file_available() { + inspect(sink.file_close(), content="true") + inspect(sink.file_reopen_append(), content="true") + inspect(sink.file_available(), content="true") + inspect(sink.file_append_mode(), content="true") + inspect(sink.file_open_failures(), content="0") + let logger = Logger::new(sink, min_level=Level::Info, target="runtime.reopen.queued") + logger.info("one") + logger.info("two") + inspect(sink.pending_count(), content="2") + inspect(sink.file_reopen_truncate(), content="true") + inspect(sink.file_append_mode(), content="false") + inspect(sink.file_reopen(), content="true") + inspect(sink.file_append_mode(), content="false") + inspect(sink.file_reopen_with_current_policy(), content="true") + inspect(sink.file_append_mode(), content="false") + inspect(sink.file_reopen_append(), content="true") + inspect(sink.file_append_mode(), content="true") + inspect(sink.file_reset_failure_counters(), content="true") + inspect(sink.file_open_failures(), content="0") + inspect(sink.file_write_failures(), content="0") + inspect(sink.file_flush_failures(), content="0") + inspect(sink.file_rotation_failures(), content="0") + inspect(sink.file_close(), content="true") + } else { + inspect(sink.file_append_mode(), content="true") + inspect(sink.file_open_failures(), content="1") + let logger = Logger::new(sink, min_level=Level::Info, target="runtime.reopen.queued") + logger.info("one") + inspect(sink.pending_count(), content="1") + inspect(sink.file_write_failures(), content="0") + inspect(sink.file_flush(), content="false") + inspect(sink.pending_count(), content="0") + inspect(sink.file_write_failures(), content="1") + inspect(sink.file_reopen_append(), content="false") + inspect(sink.file_open_failures(), content="2") + inspect(sink.file_reopen_truncate(), content="false") + inspect(sink.file_append_mode(), content="false") + inspect(sink.file_reopen_with_current_policy(), content="false") + inspect(sink.file_open_failures(), content="4") + inspect(sink.file_reopen_append(), content="false") + inspect(sink.file_append_mode(), content="true") + inspect(sink.file_open_failures(), content="5") + inspect(sink.file_reset_failure_counters(), content="true") + inspect(sink.file_open_failures(), content="0") + inspect(sink.file_write_failures(), content="0") + inspect(sink.file_flush_failures(), content="0") + inspect(sink.file_rotation_failures(), content="0") + } +} + test "configured logger exposes file sink observability helpers" { let logger = build_logger( LoggerConfig::new( @@ -482,7 +1001,185 @@ test "configured logger exposes file sink observability helpers" { ignore(logger.close()) } +test "configured logger file observation helpers stay aligned with runtime sink helpers" { + let file_logger = build_logger( + LoggerConfig::new( + target="config.file.delegate", + sink=SinkConfig::new(kind=SinkKind::File, path="config-file-delegate.log"), + ), + ) + let file_sink = file_logger.sink + + inspect(file_logger.file_available() == file_sink.file_available(), content="true") + inspect(file_logger.file_path() == file_sink.file_path(), content="true") + inspect(file_logger.file_open_failures() == file_sink.file_open_failures(), content="true") + inspect(file_logger.file_write_failures() == file_sink.file_write_failures(), content="true") + inspect(file_logger.file_flush_failures() == file_sink.file_flush_failures(), content="true") + inspect(file_logger.file_rotation_failures() == file_sink.file_rotation_failures(), content="true") + + let console_logger = build_logger( + LoggerConfig::new( + target="config.file.delegate.console", + sink=SinkConfig::new(kind=SinkKind::Console), + ), + ) + let console_sink = console_logger.sink + + inspect(console_logger.file_available() == console_sink.file_available(), content="true") + inspect(console_logger.file_path() == console_sink.file_path(), content="true") + inspect(console_logger.file_open_failures() == console_sink.file_open_failures(), content="true") + inspect(console_logger.file_write_failures() == console_sink.file_write_failures(), content="true") + inspect(console_logger.file_flush_failures() == console_sink.file_flush_failures(), content="true") + inspect(console_logger.file_rotation_failures() == console_sink.file_rotation_failures(), content="true") + + ignore(file_logger.close()) +} + +test "configured logger file policy helpers stay aligned with runtime sink helpers" { + let file_logger = build_logger( + LoggerConfig::new( + target="config.file.policy.delegate", + sink=SinkConfig::new( + kind=SinkKind::File, + path="config-file-policy-delegate.log", + append=false, + auto_flush=true, + rotation=Some(file_rotation(64, max_backups=2)), + ), + ), + ) + let file_sink = file_logger.sink + let file_policy = file_logger.file_policy() + let file_sink_policy = file_sink.file_policy() + let file_defaults = file_logger.file_default_policy() + let file_sink_defaults = file_sink.file_default_policy() + let file_policy_has_rotation = match file_policy.rotation { + Some(_) => true + None => false + } + let file_sink_policy_has_rotation = match file_sink_policy.rotation { + Some(_) => true + None => false + } + let file_defaults_has_rotation = match file_defaults.rotation { + Some(_) => true + None => false + } + let file_sink_defaults_has_rotation = match file_sink_defaults.rotation { + Some(_) => true + None => false + } + + inspect(file_logger.file_append_mode() == file_sink.file_append_mode(), content="true") + inspect(file_logger.file_auto_flush() == file_sink.file_auto_flush(), content="true") + inspect(file_logger.file_rotation_enabled() == file_sink.file_rotation_enabled(), content="true") + inspect(file_logger.file_policy_matches_default() == file_sink.file_policy_matches_default(), content="true") + inspect(file_policy.append == file_sink_policy.append, content="true") + inspect(file_policy.auto_flush == file_sink_policy.auto_flush, content="true") + inspect(file_policy_has_rotation == file_sink_policy_has_rotation, content="true") + inspect(file_defaults.append == file_sink_defaults.append, content="true") + inspect(file_defaults.auto_flush == file_sink_defaults.auto_flush, content="true") + inspect(file_defaults_has_rotation == file_sink_defaults_has_rotation, content="true") + + let console_logger = build_logger( + LoggerConfig::new( + target="config.file.policy.console", + sink=SinkConfig::new(kind=SinkKind::Console), + ), + ) + let console_sink = console_logger.sink + let console_policy = console_logger.file_policy() + let console_sink_policy = console_sink.file_policy() + let console_defaults = console_logger.file_default_policy() + let console_sink_defaults = console_sink.file_default_policy() + let console_policy_has_rotation = match console_policy.rotation { + Some(_) => true + None => false + } + let console_sink_policy_has_rotation = match console_sink_policy.rotation { + Some(_) => true + None => false + } + let console_defaults_has_rotation = match console_defaults.rotation { + Some(_) => true + None => false + } + let console_sink_defaults_has_rotation = match console_sink_defaults.rotation { + Some(_) => true + None => false + } + + inspect(console_logger.file_append_mode() == console_sink.file_append_mode(), content="true") + inspect(console_logger.file_auto_flush() == console_sink.file_auto_flush(), content="true") + inspect(console_logger.file_rotation_enabled() == console_sink.file_rotation_enabled(), content="true") + inspect(console_logger.file_policy_matches_default() == console_sink.file_policy_matches_default(), content="true") + inspect(console_policy.append == console_sink_policy.append, content="true") + inspect(console_policy.auto_flush == console_sink_policy.auto_flush, content="true") + inspect(console_policy_has_rotation == console_sink_policy_has_rotation, content="true") + inspect(console_defaults.append == console_sink_defaults.append, content="true") + inspect(console_defaults.auto_flush == console_sink_defaults.auto_flush, content="true") + inspect(console_defaults_has_rotation == console_sink_defaults_has_rotation, content="true") + + ignore(file_logger.close()) +} + +test "configured logger file setters stay aligned with runtime sink setters" { + let logger = build_logger( + LoggerConfig::new( + target="config.file.setters.delegate", + sink=SinkConfig::new(kind=SinkKind::File, path="config-file-setters-delegate.log"), + ), + ) + let sink = logger.sink + + inspect(logger.file_set_append_mode(false) == sink.file_set_append_mode(false), content="true") + inspect(logger.file_append_mode() == sink.file_append_mode(), content="true") + + inspect(logger.file_set_auto_flush(false) == sink.file_set_auto_flush(false), content="true") + inspect(logger.file_auto_flush() == sink.file_auto_flush(), content="true") + + let rotation = Some(file_rotation(48, max_backups=3)) + inspect(logger.file_set_rotation(rotation) == sink.file_set_rotation(rotation), content="true") + inspect(logger.file_rotation_enabled() == sink.file_rotation_enabled(), content="true") + + let logger_policy = logger.file_policy() + let sink_policy = sink.file_policy() + inspect(logger_policy.append == sink_policy.append, content="true") + inspect(logger_policy.auto_flush == sink_policy.auto_flush, content="true") + inspect(match logger_policy.rotation { + Some(value) => match sink_policy.rotation { + Some(other) => value.max_bytes == other.max_bytes && value.max_backups == other.max_backups + None => false + } + None => sink_policy.rotation is None + }, content="true") + + inspect(logger.file_clear_rotation() == sink.file_clear_rotation(), content="true") + inspect(logger.file_rotation_enabled() == sink.file_rotation_enabled(), content="true") + inspect(logger.file_policy_matches_default() == sink.file_policy_matches_default(), content="true") + + let console_logger = build_logger( + LoggerConfig::new( + target="config.file.setters.console", + sink=SinkConfig::new(kind=SinkKind::Console), + ), + ) + let console_sink = console_logger.sink + inspect(console_logger.file_set_append_mode(true) == console_sink.file_set_append_mode(true), content="true") + inspect(console_logger.file_set_auto_flush(true) == console_sink.file_set_auto_flush(true), content="true") + inspect(console_logger.file_set_rotation(rotation) == console_sink.file_set_rotation(rotation), content="true") + inspect(console_logger.file_clear_rotation() == console_sink.file_clear_rotation(), content="true") + + ignore(logger.close()) +} + test "file state json helpers stringify stable snapshots" { + let rotation_json = file_rotation_config_to_json(file_rotation(64, max_backups=2)) + let rotation_obj = rotation_json.as_object().unwrap() + inspect(@json_parser.stringify(rotation_json), content="{\"max_bytes\":64,\"max_backups\":2}") + inspect(rotation_obj.get("max_bytes").unwrap().as_number().unwrap().to_int(), content="64") + inspect(rotation_obj.get("max_backups").unwrap().as_number().unwrap().to_int(), content="2") + let plain = file_sink_state_to_json( FileSinkState::new( "demo.log", @@ -496,10 +1193,22 @@ test "file state json helpers stringify stable snapshots" { rotation_failures=4, ), ) + let plain_obj = plain.as_object().unwrap() + let plain_rotation_obj = plain_obj.get("rotation").unwrap().as_object().unwrap() inspect( @json_parser.stringify(plain), content="{\"path\":\"demo.log\",\"available\":true,\"append\":false,\"auto_flush\":true,\"open_failures\":1,\"write_failures\":2,\"flush_failures\":3,\"rotation_failures\":4,\"rotation\":{\"max_bytes\":64,\"max_backups\":2}}", ) + inspect(plain_obj.get("path").unwrap().as_string().unwrap(), content="demo.log") + inspect(plain_obj.get("available").unwrap().as_bool().unwrap(), content="true") + inspect(plain_obj.get("append").unwrap().as_bool().unwrap(), content="false") + inspect(plain_obj.get("auto_flush").unwrap().as_bool().unwrap(), content="true") + inspect(plain_obj.get("open_failures").unwrap().as_number().unwrap().to_int(), content="1") + inspect(plain_obj.get("write_failures").unwrap().as_number().unwrap().to_int(), content="2") + inspect(plain_obj.get("flush_failures").unwrap().as_number().unwrap().to_int(), content="3") + inspect(plain_obj.get("rotation_failures").unwrap().as_number().unwrap().to_int(), content="4") + inspect(plain_rotation_obj.get("max_bytes").unwrap().as_number().unwrap().to_int(), content="64") + inspect(plain_rotation_obj.get("max_backups").unwrap().as_number().unwrap().to_int(), content="2") inspect( stringify_file_sink_state( FileSinkState::new( @@ -519,6 +1228,33 @@ test "file state json helpers stringify stable snapshots" { } test "runtime file state json helpers stringify queue snapshots" { + let runtime_json = runtime_file_state_to_json( + RuntimeFileState::new( + FileSinkState::new( + "queue.log", + available=true, + append=true, + auto_flush=false, + rotation=None, + open_failures=0, + write_failures=1, + flush_failures=2, + rotation_failures=3, + ), + queued=true, + pending_count=7, + dropped_count=5, + ), + ) + let runtime_obj = runtime_json.as_object().unwrap() + let runtime_file_obj = runtime_obj.get("file").unwrap().as_object().unwrap() + inspect(runtime_obj.get("queued").unwrap().as_bool().unwrap(), content="true") + inspect(runtime_obj.get("pending_count").unwrap().as_number().unwrap().to_int(), content="7") + inspect(runtime_obj.get("dropped_count").unwrap().as_number().unwrap().to_int(), content="5") + inspect(runtime_file_obj.get("path").unwrap().as_string().unwrap(), content="queue.log") + inspect(runtime_file_obj.get("available").unwrap().as_bool().unwrap(), content="true") + inspect(runtime_file_obj.get("rotation").unwrap() is @json_parser.JsonValue::Null, content="true") + let json = stringify_runtime_file_state( RuntimeFileState::new( FileSinkState::new( @@ -544,18 +1280,25 @@ test "runtime file state json helpers stringify queue snapshots" { } test "file sink policy json helpers stringify stable policies" { + let policy_json = file_sink_policy_to_json( + FileSinkPolicy::new( + append=false, + auto_flush=true, + rotation=Some(file_rotation(96, max_backups=3)), + ), + ) + let policy_obj = policy_json.as_object().unwrap() + let policy_rotation_obj = policy_obj.get("rotation").unwrap().as_object().unwrap() inspect( @json_parser.stringify( - file_sink_policy_to_json( - FileSinkPolicy::new( - append=false, - auto_flush=true, - rotation=Some(file_rotation(96, max_backups=3)), - ), - ), + policy_json, ), content="{\"append\":false,\"auto_flush\":true,\"rotation\":{\"max_bytes\":96,\"max_backups\":3}}", ) + inspect(policy_obj.get("append").unwrap().as_bool().unwrap(), content="false") + inspect(policy_obj.get("auto_flush").unwrap().as_bool().unwrap(), content="true") + inspect(policy_rotation_obj.get("max_bytes").unwrap().as_number().unwrap().to_int(), content="96") + inspect(policy_rotation_obj.get("max_backups").unwrap().as_number().unwrap().to_int(), content="3") inspect( stringify_file_sink_policy( FileSinkPolicy::new(append=true, auto_flush=false, rotation=None), @@ -653,6 +1396,43 @@ test "configured logger file setters update file sink policy state" { ignore(logger.close()) } +test "configured logger file reopen helpers stay aligned with runtime sink helpers" { + let logger = build_logger( + LoggerConfig::new( + sink=SinkConfig::new(kind=SinkKind::File, path="config-reopen-delegate.log"), + ), + ) + let sink = logger.sink + + inspect(logger.file_set_append_mode(false) == sink.file_set_append_mode(false), content="true") + inspect(logger.file_reopen() == sink.file_reopen(), content="true") + inspect(logger.file_append_mode() == sink.file_append_mode(), content="true") + + inspect(logger.file_reopen_append() == sink.file_reopen_append(), content="true") + inspect(logger.file_append_mode() == sink.file_append_mode(), content="true") + + inspect(logger.file_reopen_truncate() == sink.file_reopen_truncate(), content="true") + inspect(logger.file_append_mode() == sink.file_append_mode(), content="true") + + inspect(logger.file_set_append_mode(true) == sink.file_set_append_mode(true), content="true") + inspect(logger.file_reopen_with_current_policy() == sink.file_reopen_with_current_policy(), content="true") + inspect(logger.file_append_mode() == sink.file_append_mode(), content="true") + + inspect(logger.file_reopen(append=Some(false)) == sink.file_reopen(append=Some(false)), content="true") + inspect(logger.file_append_mode() == sink.file_append_mode(), content="true") + + let console_logger = build_logger( + LoggerConfig::new(sink=SinkConfig::new(kind=SinkKind::Console)), + ) + let console_sink = console_logger.sink + inspect(console_logger.file_reopen() == console_sink.file_reopen(), content="true") + inspect(console_logger.file_reopen_with_current_policy() == console_sink.file_reopen_with_current_policy(), content="true") + inspect(console_logger.file_reopen_append() == console_sink.file_reopen_append(), content="true") + inspect(console_logger.file_reopen_truncate() == console_sink.file_reopen_truncate(), content="true") + + ignore(logger.close()) +} + test "configured logger reset policy restores configured file defaults" { let logger = build_logger( LoggerConfig::new( @@ -784,6 +1564,49 @@ test "configured non-file logger cannot reset file failure counters" { inspect(logger.file_reset_failure_counters(), content="false") } +test "configured logger file reset helpers stay aligned with runtime sink helpers" { + let logger = build_logger( + LoggerConfig::new( + sink=SinkConfig::new( + kind=SinkKind::File, + path="config-reset-delegate.log", + append=false, + auto_flush=false, + rotation=Some(file_rotation(40, max_backups=2)), + ), + ), + ) + let sink = logger.sink + + ignore(logger.file_set_append_mode(true)) + ignore(sink.file_set_append_mode(true)) + ignore(logger.file_set_auto_flush(true)) + ignore(sink.file_set_auto_flush(true)) + ignore(logger.file_set_rotation(None)) + ignore(sink.file_set_rotation(None)) + + inspect(logger.file_reset_policy() == sink.file_reset_policy(), content="true") + inspect(logger.file_policy_matches_default() == sink.file_policy_matches_default(), content="true") + inspect(logger.file_append_mode() == sink.file_append_mode(), content="true") + inspect(logger.file_auto_flush() == sink.file_auto_flush(), content="true") + + inspect(logger.file_reset_failure_counters() == sink.file_reset_failure_counters(), content="true") + inspect(logger.file_open_failures() == sink.file_open_failures(), content="true") + inspect(logger.file_write_failures() == sink.file_write_failures(), content="true") + inspect(logger.file_flush_failures() == sink.file_flush_failures(), content="true") + inspect(logger.file_rotation_failures() == sink.file_rotation_failures(), content="true") + + let console_logger = build_logger(LoggerConfig::new(sink=SinkConfig::new(kind=SinkKind::Console))) + let console_sink = console_logger.sink + inspect(console_logger.file_reset_policy() == console_sink.file_reset_policy(), content="true") + inspect( + console_logger.file_reset_failure_counters() == console_sink.file_reset_failure_counters(), + content="true", + ) + + ignore(logger.close()) +} + test "configured logger exposes file flush and close helpers" { let logger = build_logger( LoggerConfig::new( @@ -802,6 +1625,136 @@ test "configured logger exposes file flush and close helpers" { } } +test "configured logger file flush and close stay aligned with runtime sink helpers" { + let file_config = LoggerConfig::new( + sink=SinkConfig::new(kind=SinkKind::File, path="config-file-helper-delegate.log"), + ) + 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_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") +} + +test "configured logger file state helpers stay aligned with runtime sink helpers" { + let file_logger = build_logger( + LoggerConfig::new( + target="config.file.state.delegate", + sink=SinkConfig::new(kind=SinkKind::File, path="config-file-state-delegate.log"), + ), + ) + let file_sink = file_logger.sink + let file_state = file_logger.file_state() + let file_sink_state = file_sink.file_state() + + inspect(file_state.path == file_sink_state.path, content="true") + inspect(file_state.available == file_sink_state.available, content="true") + inspect(file_state.append == file_sink_state.append, content="true") + inspect(file_state.auto_flush == file_sink_state.auto_flush, content="true") + inspect(file_state.open_failures == file_sink_state.open_failures, content="true") + inspect(file_state.write_failures == file_sink_state.write_failures, content="true") + inspect(file_state.flush_failures == file_sink_state.flush_failures, content="true") + inspect(file_state.rotation_failures == file_sink_state.rotation_failures, content="true") + inspect(match file_state.rotation { + Some(rotation) => match file_sink_state.rotation { + Some(other) => rotation.max_bytes == other.max_bytes && rotation.max_backups == other.max_backups + None => false + } + None => file_sink_state.rotation is None + }, content="true") + inspect( + (file_logger.file_runtime_state() is None) == (file_sink.file_runtime_state() is None), + content="true", + ) + + let queued_logger = build_logger( + LoggerConfig::new( + target="config.file.runtime.delegate", + sink=SinkConfig::new(kind=SinkKind::File, path="config-file-runtime-delegate.log"), + queue=Some(QueueConfig::new(4, overflow=QueueOverflowPolicy::DropNewest)), + ), + ) + let queued_sink = queued_logger.sink + queued_logger.info("one") + queued_logger.info("two") + let queued_state = queued_logger.file_state() + let queued_sink_state = queued_sink.file_state() + + inspect(queued_state.path == queued_sink_state.path, content="true") + inspect(queued_state.available == queued_sink_state.available, content="true") + inspect(queued_state.append == queued_sink_state.append, content="true") + inspect(queued_state.auto_flush == queued_sink_state.auto_flush, content="true") + inspect(queued_state.open_failures == queued_sink_state.open_failures, content="true") + inspect(queued_state.write_failures == queued_sink_state.write_failures, content="true") + inspect(queued_state.flush_failures == queued_sink_state.flush_failures, content="true") + inspect(queued_state.rotation_failures == queued_sink_state.rotation_failures, content="true") + inspect(match queued_state.rotation { + Some(rotation) => match queued_sink_state.rotation { + Some(other) => rotation.max_bytes == other.max_bytes && rotation.max_backups == other.max_backups + None => false + } + None => queued_sink_state.rotation is None + }, content="true") + + match (queued_logger.file_runtime_state(), queued_sink.file_runtime_state()) { + (Some(snapshot), Some(sink_snapshot)) => { + inspect(snapshot.file.path == sink_snapshot.file.path, content="true") + inspect(snapshot.file.available == sink_snapshot.file.available, content="true") + inspect(snapshot.file.append == sink_snapshot.file.append, content="true") + inspect(snapshot.file.auto_flush == sink_snapshot.file.auto_flush, content="true") + inspect(snapshot.file.open_failures == sink_snapshot.file.open_failures, content="true") + inspect(snapshot.file.write_failures == sink_snapshot.file.write_failures, content="true") + inspect(snapshot.file.flush_failures == sink_snapshot.file.flush_failures, content="true") + inspect(snapshot.file.rotation_failures == sink_snapshot.file.rotation_failures, content="true") + inspect(snapshot.queued == sink_snapshot.queued, content="true") + inspect(snapshot.pending_count == sink_snapshot.pending_count, content="true") + inspect(snapshot.dropped_count == sink_snapshot.dropped_count, content="true") + inspect(match snapshot.file.rotation { + Some(rotation) => match sink_snapshot.file.rotation { + Some(other) => rotation.max_bytes == other.max_bytes && rotation.max_backups == other.max_backups + None => false + } + None => sink_snapshot.file.rotation is None + }, content="true") + } + _ => inspect(false, content="true") + } + + let console_logger = build_logger( + LoggerConfig::new( + target="config.file.state.console", + sink=SinkConfig::new(kind=SinkKind::Console), + ), + ) + let console_sink = console_logger.sink + let console_state = console_logger.file_state() + let console_sink_state = console_sink.file_state() + + inspect(console_state.path == console_sink_state.path, content="true") + inspect(console_state.available == console_sink_state.available, content="true") + inspect(console_state.append == console_sink_state.append, content="true") + inspect(console_state.auto_flush == console_sink_state.auto_flush, content="true") + inspect(console_state.open_failures == console_sink_state.open_failures, content="true") + inspect(console_state.write_failures == console_sink_state.write_failures, content="true") + inspect(console_state.flush_failures == console_sink_state.flush_failures, content="true") + inspect(console_state.rotation_failures == console_sink_state.rotation_failures, content="true") + inspect((console_state.rotation is None) == (console_sink_state.rotation is None), content="true") + inspect( + (console_logger.file_runtime_state() is None) == (console_sink.file_runtime_state() is None), + content="true", + ) + + ignore(file_logger.close()) + ignore(queued_logger.close()) +} + test "configured queued file logger flushes queue through file helper" { let logger = build_logger( LoggerConfig::new( @@ -840,6 +1793,90 @@ test "configured queued file logger flushes queue through file helper" { } } +test "logger log supports per-call target override" { + let captured_target : Ref[String] = Ref("") + let captured_message : Ref[String] = Ref("") + let captured_fields : Ref[Array[Field]] = Ref([]) + let logger = Logger::new( + callback_sink(fn(rec) { + captured_target.val = rec.target + captured_message.val = rec.message + captured_fields.val = rec.fields + }), + min_level=Level::Warn, + target="sync.default", + ).with_context_fields([field("service", "bitlogger")]) + + logger.log( + Level::Error, + "override", + fields=[field("mode", "test")], + target="sync.override", + ) + inspect(captured_target.val, content="sync.override") + inspect(captured_message.val, content="override") + inspect(captured_fields.val.length(), content="2") + inspect(captured_fields.val[0].key, content="service") + inspect(captured_fields.val[0].value, content="bitlogger") + inspect(captured_fields.val[1].key, content="mode") + inspect(captured_fields.val[1].value, content="test") + + logger.log(Level::Error, "default") + inspect(captured_target.val, content="sync.default") + inspect(captured_message.val, content="default") + inspect(captured_fields.val.length(), content="1") + inspect(captured_fields.val[0].key, content="service") +} + +test "logger severity helpers use stored target without override" { + let captured_levels : Ref[Array[String]] = Ref([]) + let captured_targets : Ref[Array[String]] = Ref([]) + let captured_fields : Ref[Array[Array[Field]]] = Ref([]) + let logger = Logger::new( + callback_sink(fn(rec) { + captured_levels.val.push(rec.level.label()) + captured_targets.val.push(rec.target) + captured_fields.val.push(rec.fields) + }), + min_level=Level::Trace, + target="sync.helpers", + ).with_context_fields([field("service", "bitlogger")]) + + logger.trace("trace", fields=[field("mode", "trace")]) + logger.debug("debug", fields=[field("mode", "debug")]) + logger.info("info", fields=[field("mode", "info")]) + logger.warn("warn", fields=[field("mode", "warn")]) + logger.error("error", fields=[field("mode", "error")]) + + inspect(captured_levels.val.length(), content="5") + inspect(captured_levels.val[0], content="TRACE") + inspect(captured_levels.val[1], content="DEBUG") + inspect(captured_levels.val[2], content="INFO") + inspect(captured_levels.val[3], content="WARN") + inspect(captured_levels.val[4], content="ERROR") + inspect(captured_targets.val.length(), content="5") + inspect(captured_targets.val[0], content="sync.helpers") + inspect(captured_targets.val[1], content="sync.helpers") + inspect(captured_targets.val[2], content="sync.helpers") + inspect(captured_targets.val[3], content="sync.helpers") + inspect(captured_targets.val[4], content="sync.helpers") + inspect(captured_fields.val[0].length(), content="2") + inspect(captured_fields.val[1].length(), content="2") + inspect(captured_fields.val[2].length(), content="2") + inspect(captured_fields.val[3].length(), content="2") + inspect(captured_fields.val[4].length(), content="2") + inspect(captured_fields.val[0][0].key, content="service") + inspect(captured_fields.val[0][1].value, content="trace") + inspect(captured_fields.val[1][0].key, content="service") + inspect(captured_fields.val[1][1].value, content="debug") + inspect(captured_fields.val[2][0].key, content="service") + inspect(captured_fields.val[2][1].value, content="info") + inspect(captured_fields.val[3][0].key, content="service") + inspect(captured_fields.val[3][1].value, content="warn") + inspect(captured_fields.val[4][0].key, content="service") + inspect(captured_fields.val[4][1].value, content="error") +} + test "library logger keeps a smaller stable facade" { let captured_target : Ref[String] = Ref("") let captured_message : Ref[String] = Ref("") @@ -861,6 +1898,190 @@ test "library logger keeps a smaller stable facade" { inspect(captured_fields.val[1].key, content="mode") } +test "library logger context binding unwraps to context sink shape" { + let logger = LibraryLogger::new(console_sink(), min_level=Level::Warn, target="lib.ctx") + .with_context_fields([field("service", "bitlogger"), field("scope", "sdk")]) + let full = logger.to_logger() + + inspect(full.target, content="lib.ctx") + inspect(full.timestamp, content="false") + inspect(full.is_enabled(Level::Error), content="true") + inspect(full.is_enabled(Level::Info), content="false") + inspect(full.sink.context_fields.length(), content="2") + inspect(full.sink.context_fields[0].key, content="service") + inspect(full.sink.context_fields[0].value, content="bitlogger") + inspect(full.sink.context_fields[1].key, content="scope") + inspect(full.sink.context_fields[1].value, content="sdk") +} + +test "library logger bind matches context facade contract" { + let captured_target : Ref[String] = Ref("") + let captured_timestamp : Ref[UInt64] = Ref(0UL) + let captured_fields : Ref[Array[Field]] = Ref([]) + let logger = Logger::new( + callback_sink(fn(rec) { + captured_target.val = rec.target + captured_timestamp.val = rec.timestamp_ms + captured_fields.val = rec.fields + }), + min_level=Level::Warn, + target="lib.bind", + ) + .with_timestamp() + .to_library_logger() + .bind([field("service", "bitlogger")]) + let full = logger.to_logger() + + inspect(logger.is_enabled(Level::Error), content="true") + inspect(logger.is_enabled(Level::Info), content="false") + inspect(full.target, content="lib.bind") + inspect(full.timestamp, content="true") + inspect(full.sink.context_fields.length(), content="1") + inspect(full.sink.context_fields[0].key, content="service") + inspect(full.sink.context_fields[0].value, content="bitlogger") + + logger.error("bound", fields=[field("mode", "test")]) + inspect(captured_target.val, content="lib.bind") + inspect(captured_timestamp.val > 0UL, content="true") + inspect(captured_fields.val.length(), content="2") + inspect(captured_fields.val[0].key, content="service") + inspect(captured_fields.val[0].value, content="bitlogger") + inspect(captured_fields.val[1].key, content="mode") + inspect(captured_fields.val[1].value, content="test") +} + +test "library logger with_target preserves facade state while replacing target" { + let captured_target : Ref[String] = Ref("") + let captured_timestamp : Ref[UInt64] = Ref(0UL) + let logger = Logger::new( + callback_sink(fn(rec) { + captured_target.val = rec.target + captured_timestamp.val = rec.timestamp_ms + }), + min_level=Level::Warn, + target="lib.base", + ) + .with_timestamp() + .to_library_logger() + .with_target("lib.retarget") + let full = logger.to_logger() + + inspect(logger.is_enabled(Level::Error), content="true") + inspect(logger.is_enabled(Level::Info), content="false") + inspect(full.target, content="lib.retarget") + inspect(full.timestamp, content="true") + + logger.error("retargeted") + inspect(captured_target.val, content="lib.retarget") + inspect(captured_timestamp.val > 0UL, content="true") +} + +test "library logger child composes target through facade" { + let captured_target : Ref[String] = Ref("") + let captured_timestamp : Ref[UInt64] = Ref(0UL) + let logger = Logger::new( + callback_sink(fn(rec) { + captured_target.val = rec.target + captured_timestamp.val = rec.timestamp_ms + }), + min_level=Level::Warn, + target="sdk", + ) + .with_timestamp() + .to_library_logger() + .child("worker") + let full = logger.to_logger() + + inspect(full.target, content="sdk.worker") + inspect(full.timestamp, content="true") + inspect(logger.is_enabled(Level::Error), content="true") + inspect(logger.is_enabled(Level::Info), content="false") + + logger.error("child") + inspect(captured_target.val, content="sdk.worker") + inspect(captured_timestamp.val > 0UL, content="true") + + let root_child = LibraryLogger::new(console_sink()).child("worker") + inspect(root_child.to_logger().target, content="worker") + + let keep_parent = LibraryLogger::new(console_sink(), target="sdk").child("") + inspect(keep_parent.to_logger().target, content="sdk") +} + +test "library logger log supports per-call target override" { + let captured_target : Ref[String] = Ref("") + let captured_message : Ref[String] = Ref("") + let captured_fields : Ref[Array[Field]] = Ref([]) + let logger = LibraryLogger::new( + callback_sink(fn(rec) { + captured_target.val = rec.target + captured_message.val = rec.message + captured_fields.val = rec.fields + }), + min_level=Level::Warn, + target="lib.default", + ) + .with_context_fields([field("service", "bitlogger")]) + + logger.log( + Level::Error, + "override", + fields=[field("mode", "test")], + target="lib.override", + ) + inspect(captured_target.val, content="lib.override") + inspect(captured_message.val, content="override") + inspect(captured_fields.val.length(), content="2") + inspect(captured_fields.val[0].key, content="service") + inspect(captured_fields.val[0].value, content="bitlogger") + inspect(captured_fields.val[1].key, content="mode") + inspect(captured_fields.val[1].value, content="test") + + logger.log(Level::Error, "default") + inspect(captured_target.val, content="lib.default") + inspect(captured_message.val, content="default") + inspect(captured_fields.val.length(), content="1") + inspect(captured_fields.val[0].key, content="service") +} + +test "library logger severity helpers use stored target without override" { + let captured_levels : Ref[Array[String]] = Ref([]) + let captured_targets : Ref[Array[String]] = Ref([]) + let captured_fields : Ref[Array[Array[Field]]] = Ref([]) + let logger = LibraryLogger::new( + callback_sink(fn(rec) { + captured_levels.val.push(rec.level.label()) + captured_targets.val.push(rec.target) + captured_fields.val.push(rec.fields) + }), + min_level=Level::Info, + target="lib.helpers", + ) + .bind([field("service", "bitlogger")]) + + logger.info("info", fields=[field("mode", "info")]) + logger.warn("warn", fields=[field("mode", "warn")]) + logger.error("error", fields=[field("mode", "error")]) + + inspect(captured_levels.val.length(), content="3") + inspect(captured_levels.val[0], content="INFO") + inspect(captured_levels.val[1], content="WARN") + inspect(captured_levels.val[2], content="ERROR") + inspect(captured_targets.val.length(), content="3") + inspect(captured_targets.val[0], content="lib.helpers") + inspect(captured_targets.val[1], content="lib.helpers") + inspect(captured_targets.val[2], content="lib.helpers") + inspect(captured_fields.val[0].length(), content="2") + inspect(captured_fields.val[1].length(), content="2") + inspect(captured_fields.val[2].length(), content="2") + inspect(captured_fields.val[0][0].key, content="service") + inspect(captured_fields.val[0][1].value, content="info") + inspect(captured_fields.val[1][0].key, content="service") + inspect(captured_fields.val[1][1].value, content="warn") + inspect(captured_fields.val[2][0].key, content="service") + inspect(captured_fields.val[2][1].value, content="error") +} + test "library logger can unwrap to full logger when needed" { let base = LibraryLogger::new(console_sink(), min_level=Level::Warn, target="lib") let full = base.to_logger().with_timestamp() @@ -884,6 +2105,241 @@ test "library logger can be built from configured runtime path" { inspect(full.target, content="lib.config") } +test "library logger builder log supports per-call target override through facade" { + let captured_target : Ref[String] = Ref("") + let captured_message : Ref[String] = Ref("") + let captured_fields : Ref[Array[Field]] = Ref([]) + let logger = build_library_logger( + LoggerConfig::new( + min_level=Level::Warn, + target="lib.config.default", + sink=SinkConfig::new(kind=SinkKind::Console), + ), + ) + .to_logger() + .with_patch(fn(rec) { + captured_target.val = rec.target + captured_message.val = rec.message + captured_fields.val = rec.fields + rec + }) + .to_library_logger() + .bind([field("service", "bitlogger")]) + + logger.log( + Level::Error, + "override", + fields=[field("mode", "test")], + target="lib.config.override", + ) + inspect(captured_target.val, content="lib.config.override") + inspect(captured_message.val, content="override") + inspect(captured_fields.val.length(), content="2") + inspect(captured_fields.val[0].key, content="service") + inspect(captured_fields.val[0].value, content="bitlogger") + inspect(captured_fields.val[1].key, content="mode") + inspect(captured_fields.val[1].value, content="test") + + logger.log(Level::Error, "default") + inspect(captured_target.val, content="lib.config.default") + inspect(captured_message.val, content="default") + inspect(captured_fields.val.length(), content="1") + inspect(captured_fields.val[0].key, content="service") +} + +test "library logger builder severity helpers use stored target without override" { + let captured_levels : Ref[Array[String]] = Ref([]) + let captured_targets : Ref[Array[String]] = Ref([]) + let captured_fields : Ref[Array[Array[Field]]] = Ref([]) + let logger = build_library_logger( + LoggerConfig::new( + min_level=Level::Info, + target="lib.config.helpers", + sink=SinkConfig::new(kind=SinkKind::Console), + ), + ) + .to_logger() + .with_patch(fn(rec) { + captured_levels.val.push(rec.level.label()) + captured_targets.val.push(rec.target) + captured_fields.val.push(rec.fields) + rec + }) + .to_library_logger() + .bind([field("service", "bitlogger")]) + + logger.info("info", fields=[field("mode", "info")]) + logger.warn("warn", fields=[field("mode", "warn")]) + logger.error("error", fields=[field("mode", "error")]) + + inspect(captured_levels.val.length(), content="3") + inspect(captured_levels.val[0], content="INFO") + inspect(captured_levels.val[1], content="WARN") + inspect(captured_levels.val[2], content="ERROR") + inspect(captured_targets.val.length(), content="3") + inspect(captured_targets.val[0], content="lib.config.helpers") + inspect(captured_targets.val[1], content="lib.config.helpers") + inspect(captured_targets.val[2], content="lib.config.helpers") + inspect(captured_fields.val[0].length(), content="2") + inspect(captured_fields.val[1].length(), content="2") + inspect(captured_fields.val[2].length(), content="2") + inspect(captured_fields.val[0][0].key, content="service") + inspect(captured_fields.val[0][1].value, content="info") + inspect(captured_fields.val[1][0].key, content="service") + inspect(captured_fields.val[1][1].value, content="warn") + inspect(captured_fields.val[2][0].key, content="service") + inspect(captured_fields.val[2][1].value, content="error") +} + +test "library logger builder unwrap matches direct configured builder behavior" { + let config = LoggerConfig::new( + min_level=Level::Warn, + target="lib.config.same-build", + timestamp=true, + queue=Some(QueueConfig::new(2, overflow=QueueOverflowPolicy::DropNewest)), + sink=SinkConfig::new(kind=SinkKind::Console), + ) + let logger = build_library_logger(config) + let full = logger.to_logger() + let configured = build_logger(config) + + inspect(full.target, content=configured.target) + inspect(full.timestamp == configured.timestamp, content="true") + inspect(logger.is_enabled(Level::Error) == configured.is_enabled(Level::Error), content="true") + inspect(logger.is_enabled(Level::Info) == configured.is_enabled(Level::Info), content="true") + let full_sink_kind = match full.sink { + RuntimeSink::QueuedConsole(_) => "QueuedConsole" + RuntimeSink::QueuedJsonConsole(_) => "QueuedJsonConsole" + RuntimeSink::QueuedTextConsole(_) => "QueuedTextConsole" + RuntimeSink::QueuedFile(_) => "QueuedFile" + RuntimeSink::Console(_) => "Console" + RuntimeSink::JsonConsole(_) => "JsonConsole" + RuntimeSink::TextConsole(_) => "TextConsole" + RuntimeSink::File(_) => "File" + } + let configured_sink_kind = match configured.sink { + RuntimeSink::QueuedConsole(_) => "QueuedConsole" + RuntimeSink::QueuedJsonConsole(_) => "QueuedJsonConsole" + RuntimeSink::QueuedTextConsole(_) => "QueuedTextConsole" + RuntimeSink::QueuedFile(_) => "QueuedFile" + RuntimeSink::Console(_) => "Console" + RuntimeSink::JsonConsole(_) => "JsonConsole" + RuntimeSink::TextConsole(_) => "TextConsole" + RuntimeSink::File(_) => "File" + } + inspect(full_sink_kind == configured_sink_kind, content="true") + + full.error("one") + full.error("two") + full.error("three") + configured.error("one") + configured.error("two") + configured.error("three") + + inspect(full.pending_count() == configured.pending_count(), content="true") + inspect(full.dropped_count() == configured.dropped_count(), content="true") + inspect(full.flush() == configured.flush(), content="true") + inspect(full.pending_count() == configured.pending_count(), content="true") +} + +test "library logger builder unwrap preserves file runtime helpers" { + let config = LoggerConfig::new( + min_level=Level::Warn, + target="lib.file.same-build", + sink=SinkConfig::new(kind=SinkKind::File, path="lib-file-same-build.log"), + queue=Some(QueueConfig::new(2, overflow=QueueOverflowPolicy::DropOldest)), + ) + let logger = build_library_logger(config) + let full = logger.to_logger() + let configured = build_logger(config) + + full.error("one") + full.error("two") + full.error("three") + configured.error("one") + configured.error("two") + configured.error("three") + + inspect(full.pending_count() == configured.pending_count(), content="true") + inspect(full.dropped_count() == configured.dropped_count(), content="true") + inspect(full.file_available() == configured.file_available(), content="true") + inspect(full.file_append_mode() == configured.file_append_mode(), content="true") + inspect(full.file_auto_flush() == configured.file_auto_flush(), content="true") + + let full_state = full.file_state() + let configured_state = configured.file_state() + inspect(full_state.path == configured_state.path, content="true") + inspect(full_state.available == configured_state.available, content="true") + inspect(full_state.append == configured_state.append, content="true") + inspect(full_state.auto_flush == configured_state.auto_flush, content="true") + inspect(full_state.open_failures == configured_state.open_failures, content="true") + inspect(full_state.write_failures == configured_state.write_failures, content="true") + inspect(full_state.flush_failures == configured_state.flush_failures, content="true") + inspect(full_state.rotation_failures == configured_state.rotation_failures, content="true") + + match (full.file_runtime_state(), configured.file_runtime_state()) { + (Some(snapshot), Some(other)) => { + inspect(snapshot.file.path == other.file.path, content="true") + inspect(snapshot.file.available == other.file.available, content="true") + inspect(snapshot.queued == other.queued, content="true") + inspect(snapshot.pending_count == other.pending_count, content="true") + inspect(snapshot.dropped_count == other.dropped_count, content="true") + } + _ => inspect(false, 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") +} + +test "library logger builder unwrap preserves file controls" { + let config = LoggerConfig::new( + min_level=Level::Warn, + target="lib.file.controls.same-build", + sink=SinkConfig::new(kind=SinkKind::File, path="lib-file-controls-same-build.log"), + ) + let logger = build_library_logger(config) + let full = logger.to_logger() + let configured = build_logger(config) + + inspect(full.file_set_append_mode(false) == configured.file_set_append_mode(false), content="true") + inspect(full.file_append_mode() == configured.file_append_mode(), content="true") + inspect(full.file_set_auto_flush(false) == configured.file_set_auto_flush(false), content="true") + inspect(full.file_auto_flush() == configured.file_auto_flush(), content="true") + + let rotation = Some(file_rotation(48, max_backups=3)) + inspect(full.file_set_rotation(rotation) == configured.file_set_rotation(rotation), content="true") + inspect(full.file_rotation_enabled() == configured.file_rotation_enabled(), content="true") + + let full_policy = full.file_policy() + let configured_policy = configured.file_policy() + inspect(full_policy.append == configured_policy.append, content="true") + inspect(full_policy.auto_flush == configured_policy.auto_flush, content="true") + inspect(match full_policy.rotation { + Some(value) => match configured_policy.rotation { + Some(other) => value.max_bytes == other.max_bytes && value.max_backups == other.max_backups + None => false + } + None => configured_policy.rotation is None + }, content="true") + + inspect(full.file_reopen_append() == configured.file_reopen_append(), content="true") + inspect(full.file_append_mode() == configured.file_append_mode(), content="true") + inspect(full.file_reopen_truncate() == configured.file_reopen_truncate(), content="true") + inspect(full.file_append_mode() == configured.file_append_mode(), content="true") + inspect(full.file_reopen_with_current_policy() == configured.file_reopen_with_current_policy(), content="true") + + inspect(full.file_clear_rotation() == configured.file_clear_rotation(), content="true") + inspect(full.file_rotation_enabled() == configured.file_rotation_enabled(), content="true") + inspect(full.file_policy_matches_default() == configured.file_policy_matches_default(), content="true") + inspect(full.file_reset_policy() == configured.file_reset_policy(), content="true") + inspect(full.file_policy_matches_default() == configured.file_policy_matches_default(), content="true") + inspect(full.file_reset_failure_counters() == configured.file_reset_failure_counters(), content="true") + + inspect(full.file_close() == configured.file_close(), content="true") +} + test "library logger can be parsed and built from config text" { let logger = parse_and_build_library_logger( "{\"min_level\":\"warn\",\"target\":\"lib.json\",\"sink\":{\"kind\":\"console\"}}", @@ -894,6 +2350,230 @@ test "library logger can be parsed and built from config text" { inspect(full.target, content="lib.json") } +test "parsed library logger log supports per-call target override through facade" { + let captured_target : Ref[String] = Ref("") + let captured_message : Ref[String] = Ref("") + let captured_fields : Ref[Array[Field]] = Ref([]) + let logger = parse_and_build_library_logger( + "{\"min_level\":\"warn\",\"target\":\"lib.json.default\",\"sink\":{\"kind\":\"console\"}}", + ) + .to_logger() + .with_patch(fn(rec) { + captured_target.val = rec.target + captured_message.val = rec.message + captured_fields.val = rec.fields + rec + }) + .to_library_logger() + .bind([field("service", "bitlogger")]) + + logger.log( + Level::Error, + "override", + fields=[field("mode", "test")], + target="lib.json.override", + ) + inspect(captured_target.val, content="lib.json.override") + inspect(captured_message.val, content="override") + inspect(captured_fields.val.length(), content="2") + inspect(captured_fields.val[0].key, content="service") + inspect(captured_fields.val[0].value, content="bitlogger") + inspect(captured_fields.val[1].key, content="mode") + inspect(captured_fields.val[1].value, content="test") + + logger.log(Level::Error, "default") + inspect(captured_target.val, content="lib.json.default") + inspect(captured_message.val, content="default") + inspect(captured_fields.val.length(), content="1") + inspect(captured_fields.val[0].key, content="service") +} + +test "parsed library logger severity helpers use stored target without override" { + let captured_levels : Ref[Array[String]] = Ref([]) + let captured_targets : Ref[Array[String]] = Ref([]) + let captured_fields : Ref[Array[Array[Field]]] = Ref([]) + let logger = parse_and_build_library_logger( + "{\"min_level\":\"info\",\"target\":\"lib.json.helpers\",\"sink\":{\"kind\":\"console\"}}", + ) + .to_logger() + .with_patch(fn(rec) { + captured_levels.val.push(rec.level.label()) + captured_targets.val.push(rec.target) + captured_fields.val.push(rec.fields) + rec + }) + .to_library_logger() + .bind([field("service", "bitlogger")]) + + logger.info("info", fields=[field("mode", "info")]) + logger.warn("warn", fields=[field("mode", "warn")]) + logger.error("error", fields=[field("mode", "error")]) + + inspect(captured_levels.val.length(), content="3") + inspect(captured_levels.val[0], content="INFO") + inspect(captured_levels.val[1], content="WARN") + inspect(captured_levels.val[2], content="ERROR") + inspect(captured_targets.val.length(), content="3") + inspect(captured_targets.val[0], content="lib.json.helpers") + inspect(captured_targets.val[1], content="lib.json.helpers") + inspect(captured_targets.val[2], content="lib.json.helpers") + inspect(captured_fields.val[0].length(), content="2") + inspect(captured_fields.val[1].length(), content="2") + inspect(captured_fields.val[2].length(), content="2") + inspect(captured_fields.val[0][0].key, content="service") + inspect(captured_fields.val[0][1].value, content="info") + inspect(captured_fields.val[1][0].key, content="service") + inspect(captured_fields.val[1][1].value, content="warn") + inspect(captured_fields.val[2][0].key, content="service") + inspect(captured_fields.val[2][1].value, content="error") +} + +test "library logger parse-build unwrap matches parsed direct builder behavior" { + let raw = "{\"min_level\":\"warn\",\"target\":\"lib.json.same-build\",\"timestamp\":true,\"queue\":{\"max_pending\":2,\"overflow\":\"DropNewest\"},\"sink\":{\"kind\":\"console\"}}" + let logger = parse_and_build_library_logger(raw) + let full = logger.to_logger() + let configured = parse_and_build_logger(raw) + + inspect(full.target, content=configured.target) + inspect(full.timestamp == configured.timestamp, content="true") + inspect(logger.is_enabled(Level::Error) == configured.is_enabled(Level::Error), content="true") + inspect(logger.is_enabled(Level::Info) == configured.is_enabled(Level::Info), content="true") + let full_sink_kind = match full.sink { + RuntimeSink::QueuedConsole(_) => "QueuedConsole" + RuntimeSink::QueuedJsonConsole(_) => "QueuedJsonConsole" + RuntimeSink::QueuedTextConsole(_) => "QueuedTextConsole" + RuntimeSink::QueuedFile(_) => "QueuedFile" + RuntimeSink::Console(_) => "Console" + RuntimeSink::JsonConsole(_) => "JsonConsole" + RuntimeSink::TextConsole(_) => "TextConsole" + RuntimeSink::File(_) => "File" + } + let configured_sink_kind = match configured.sink { + RuntimeSink::QueuedConsole(_) => "QueuedConsole" + RuntimeSink::QueuedJsonConsole(_) => "QueuedJsonConsole" + RuntimeSink::QueuedTextConsole(_) => "QueuedTextConsole" + RuntimeSink::QueuedFile(_) => "QueuedFile" + RuntimeSink::Console(_) => "Console" + RuntimeSink::JsonConsole(_) => "JsonConsole" + RuntimeSink::TextConsole(_) => "TextConsole" + RuntimeSink::File(_) => "File" + } + inspect(full_sink_kind == configured_sink_kind, content="true") + + full.error("one") + full.error("two") + full.error("three") + configured.error("one") + configured.error("two") + configured.error("three") + + inspect(full.pending_count() == configured.pending_count(), content="true") + inspect(full.dropped_count() == configured.dropped_count(), content="true") + inspect(full.flush() == configured.flush(), content="true") + inspect(full.pending_count() == configured.pending_count(), content="true") +} + +test "library logger parse-build unwrap preserves file runtime helpers" { + let raw = "{\"min_level\":\"warn\",\"target\":\"lib.json.file.same-build\",\"queue\":{\"max_pending\":2,\"overflow\":\"DropOldest\"},\"sink\":{\"kind\":\"file\",\"path\":\"lib-json-file-same-build.log\"}}" + let logger = parse_and_build_library_logger(raw) + let full = logger.to_logger() + let configured = parse_and_build_logger(raw) + + full.error("one") + full.error("two") + full.error("three") + configured.error("one") + configured.error("two") + configured.error("three") + + inspect(full.pending_count() == configured.pending_count(), content="true") + inspect(full.dropped_count() == configured.dropped_count(), content="true") + inspect(full.file_available() == configured.file_available(), content="true") + inspect(full.file_append_mode() == configured.file_append_mode(), content="true") + inspect(full.file_auto_flush() == configured.file_auto_flush(), content="true") + + let full_state = full.file_state() + let configured_state = configured.file_state() + inspect(full_state.path == configured_state.path, content="true") + inspect(full_state.available == configured_state.available, content="true") + inspect(full_state.append == configured_state.append, content="true") + inspect(full_state.auto_flush == configured_state.auto_flush, content="true") + inspect(full_state.open_failures == configured_state.open_failures, content="true") + inspect(full_state.write_failures == configured_state.write_failures, content="true") + inspect(full_state.flush_failures == configured_state.flush_failures, content="true") + inspect(full_state.rotation_failures == configured_state.rotation_failures, content="true") + + match (full.file_runtime_state(), configured.file_runtime_state()) { + (Some(snapshot), Some(other)) => { + inspect(snapshot.file.path == other.file.path, content="true") + inspect(snapshot.file.available == other.file.available, content="true") + inspect(snapshot.queued == other.queued, content="true") + inspect(snapshot.pending_count == other.pending_count, content="true") + inspect(snapshot.dropped_count == other.dropped_count, content="true") + } + _ => inspect(false, 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") +} + +test "library logger parse-build unwrap preserves file controls" { + let raw = "{\"min_level\":\"warn\",\"target\":\"lib.json.file.controls.same-build\",\"sink\":{\"kind\":\"file\",\"path\":\"lib-json-file-controls-same-build.log\"}}" + let logger = parse_and_build_library_logger(raw) + let full = logger.to_logger() + let configured = parse_and_build_logger(raw) + + inspect(full.file_set_append_mode(false) == configured.file_set_append_mode(false), content="true") + inspect(full.file_append_mode() == configured.file_append_mode(), content="true") + inspect(full.file_set_auto_flush(false) == configured.file_set_auto_flush(false), content="true") + inspect(full.file_auto_flush() == configured.file_auto_flush(), content="true") + + let rotation = Some(file_rotation(40, max_backups=2)) + inspect(full.file_set_rotation(rotation) == configured.file_set_rotation(rotation), content="true") + inspect(full.file_rotation_enabled() == configured.file_rotation_enabled(), content="true") + inspect(full.file_reopen(append=Some(false)) == configured.file_reopen(append=Some(false)), content="true") + inspect(full.file_append_mode() == configured.file_append_mode(), content="true") + inspect(full.file_reopen_append() == configured.file_reopen_append(), content="true") + inspect(full.file_append_mode() == configured.file_append_mode(), content="true") + inspect(full.file_clear_rotation() == configured.file_clear_rotation(), content="true") + inspect(full.file_rotation_enabled() == configured.file_rotation_enabled(), content="true") + inspect(full.file_reset_policy() == configured.file_reset_policy(), content="true") + inspect(full.file_policy_matches_default() == configured.file_policy_matches_default(), content="true") + inspect(full.file_reset_failure_counters() == configured.file_reset_failure_counters(), content="true") + + inspect(full.file_close() == configured.file_close(), content="true") +} + +test "parsed library logger unwrap preserves configured runtime path" { + let logger = parse_and_build_library_logger( + "{\"min_level\":\"warn\",\"target\":\"lib.json.runtime\",\"timestamp\":true,\"queue\":{\"max_pending\":3,\"overflow\":\"DropNewest\"},\"sink\":{\"kind\":\"console\"}}", + ) + let full = logger.to_logger() + + inspect(logger.is_enabled(Level::Error), content="true") + inspect(logger.is_enabled(Level::Info), content="false") + inspect(full.target, content="lib.json.runtime") + inspect(full.timestamp, content="true") + + full.error("one") + full.error("two") + inspect(match full.sink { + RuntimeSink::QueuedConsole(_) => "QueuedConsole" + RuntimeSink::QueuedJsonConsole(_) => "QueuedJsonConsole" + RuntimeSink::QueuedTextConsole(_) => "QueuedTextConsole" + RuntimeSink::QueuedFile(_) => "QueuedFile" + _ => "Other" + }, content="QueuedConsole") + inspect(full.sink.pending_count(), content="2") + inspect(full.sink.dropped_count(), content="0") + inspect(full.sink.drain(max_items=1), content="1") + inspect(full.sink.pending_count(), content="1") + inspect(full.sink.flush(), content="1") + inspect(full.sink.pending_count(), content="0") +} + test "configured logger can project to library logger" { let configured = build_logger( LoggerConfig::new(min_level=Level::Warn, target="lib.projected"), @@ -904,6 +2584,141 @@ test "configured logger can project to library logger" { inspect(logger.to_logger().target, content="lib.projected") } +test "logger projection preserves sync composition state through library facade" { + let captured_target : Ref[String] = Ref("") + let captured_timestamp : Ref[UInt64] = Ref(0UL) + let captured_fields : Ref[Array[Field]] = Ref([]) + let base = Logger::new( + callback_sink(fn(rec) { + captured_target.val = rec.target + captured_timestamp.val = rec.timestamp_ms + captured_fields.val = rec.fields + }), + min_level=Level::Warn, + target="lib.projected.state", + ) + .with_timestamp() + .with_context_fields([field("service", "bitlogger")]) + let projected = base.to_library_logger() + let full = projected.to_logger() + + inspect(projected.is_enabled(Level::Error), content="true") + inspect(projected.is_enabled(Level::Info), content="false") + inspect(full.target, content="lib.projected.state") + inspect(full.timestamp, content="true") + full.error("boom", fields=[field("mode", "test")]) + inspect(captured_target.val, content="lib.projected.state") + inspect(captured_timestamp.val > 0UL, content="true") + inspect(captured_fields.val.length(), content="2") + inspect(captured_fields.val[0].key, content="service") + inspect(captured_fields.val[0].value, content="bitlogger") + inspect(captured_fields.val[1].key, content="mode") +} + +test "configured logger projection preserves runtime helpers through unwrap" { + let projected = build_logger( + LoggerConfig::new( + min_level=Level::Warn, + target="lib.projected.runtime", + sink=SinkConfig::new(kind=SinkKind::Console), + queue=Some(QueueConfig::new(3, overflow=QueueOverflowPolicy::DropNewest)), + ), + ).to_library_logger() + let full = projected.to_logger() + + inspect(projected.is_enabled(Level::Error), content="true") + inspect(projected.is_enabled(Level::Info), content="false") + inspect(full.target, content="lib.projected.runtime") + full.error("one") + full.error("two") + inspect(match full.sink { + RuntimeSink::QueuedConsole(_) => "QueuedConsole" + RuntimeSink::QueuedJsonConsole(_) => "QueuedJsonConsole" + RuntimeSink::QueuedTextConsole(_) => "QueuedTextConsole" + RuntimeSink::QueuedFile(_) => "QueuedFile" + _ => "Other" + }, content="QueuedConsole") + inspect(full.sink.pending_count(), content="2") + inspect(full.sink.dropped_count(), content="0") + inspect(full.sink.drain(max_items=1), content="1") + inspect(full.sink.pending_count(), content="1") + inspect(full.sink.flush(), content="1") + inspect(full.sink.pending_count(), content="0") +} + +test "configured logger projection preserves file runtime helpers through unwrap" { + let configured = build_logger( + LoggerConfig::new( + min_level=Level::Warn, + target="lib.projected.file", + sink=SinkConfig::new(kind=SinkKind::File, path="lib-projected-file.log"), + queue=Some(QueueConfig::new(2, overflow=QueueOverflowPolicy::DropOldest)), + ), + ) + let projected = configured.to_library_logger() + let full = projected.to_logger() + + inspect(projected.is_enabled(Level::Error), content="true") + inspect(projected.is_enabled(Level::Info), content="false") + inspect(full.target, content="lib.projected.file") + + full.error("one") + full.error("two") + full.error("three") + inspect(full.pending_count() == configured.pending_count(), content="true") + inspect(full.dropped_count() == configured.dropped_count(), content="true") + inspect(full.file_available() == configured.file_available(), content="true") + inspect(full.file_append_mode() == configured.file_append_mode(), content="true") + inspect(full.file_auto_flush() == configured.file_auto_flush(), content="true") + + let full_state = full.file_state() + let configured_state = configured.file_state() + inspect(full_state.path == configured_state.path, content="true") + inspect(full_state.available == configured_state.available, content="true") + inspect(full_state.append == configured_state.append, content="true") + inspect(full_state.auto_flush == configured_state.auto_flush, content="true") + inspect(full_state.open_failures == configured_state.open_failures, content="true") + inspect(full_state.write_failures == configured_state.write_failures, content="true") + inspect(full_state.flush_failures == configured_state.flush_failures, content="true") + inspect(full_state.rotation_failures == configured_state.rotation_failures, content="true") + + match (full.file_runtime_state(), configured.file_runtime_state()) { + (Some(snapshot), Some(other)) => { + inspect(snapshot.file.path == other.file.path, content="true") + inspect(snapshot.file.available == other.file.available, content="true") + inspect(snapshot.queued == other.queued, content="true") + inspect(snapshot.pending_count == other.pending_count, content="true") + inspect(snapshot.dropped_count == other.dropped_count, content="true") + } + _ => inspect(false, content="true") + } + + inspect(full.file_set_append_mode(false) == configured.file_set_append_mode(false), content="true") + inspect(full.file_append_mode() == configured.file_append_mode(), content="true") + inspect(full.file_set_auto_flush(false) == configured.file_set_auto_flush(false), content="true") + inspect(full.file_auto_flush() == configured.file_auto_flush(), content="true") + inspect( + full.file_set_rotation(Some(file_rotation(36, max_backups=2))) == + configured.file_set_rotation(Some(file_rotation(36, max_backups=2))), + content="true", + ) + inspect(full.file_rotation_enabled() == configured.file_rotation_enabled(), content="true") + inspect(full.file_reopen_append() == configured.file_reopen_append(), content="true") + inspect(full.file_append_mode() == configured.file_append_mode(), content="true") + inspect(full.file_clear_rotation() == configured.file_clear_rotation(), content="true") + inspect(full.file_reset_policy() == configured.file_reset_policy(), content="true") + inspect(full.file_policy_matches_default() == configured.file_policy_matches_default(), content="true") + 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") + + 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" { set_default_min_level(Level::Warn) set_default_target("lib.default") @@ -913,6 +2728,24 @@ test "default library logger mirrors shared sync defaults" { inspect(logger.to_logger().target, content="lib.default") } +test "default library logger snapshots shared defaults at creation time" { + set_default_min_level(Level::Warn) + set_default_target("lib.before") + let before = default_library_logger() + + set_default_min_level(Level::Debug) + set_default_target("lib.after") + let after = default_library_logger() + + inspect(before.is_enabled(Level::Error), content="true") + inspect(before.is_enabled(Level::Info), content="false") + inspect(before.to_logger().target, content="lib.before") + + inspect(after.is_enabled(Level::Error), content="true") + inspect(after.is_enabled(Level::Info), content="true") + inspect(after.to_logger().target, content="lib.after") +} + test "application logger aliases configured runtime entry" { let logger = build_application_logger( LoggerConfig::new(min_level=Level::Warn, target="app.runtime"), @@ -922,6 +2755,311 @@ test "application logger aliases configured runtime entry" { inspect(logger.target, content="app.runtime") } +test "application logger builder matches direct configured builder behavior" { + let config = LoggerConfig::new( + min_level=Level::Warn, + target="app.runtime.same-build", + timestamp=true, + queue=Some(QueueConfig::new(2, overflow=QueueOverflowPolicy::DropNewest)), + sink=SinkConfig::new(kind=SinkKind::Console), + ) + let application = build_application_logger(config) + let configured = build_logger(config) + + inspect(application.target, content=configured.target) + inspect(application.timestamp, content="true") + inspect(configured.timestamp, content="true") + inspect(application.is_enabled(Level::Error) == configured.is_enabled(Level::Error), content="true") + inspect(application.is_enabled(Level::Info) == configured.is_enabled(Level::Info), content="true") + let application_sink_kind = match application.sink { + RuntimeSink::QueuedConsole(_) => "QueuedConsole" + RuntimeSink::QueuedJsonConsole(_) => "QueuedJsonConsole" + RuntimeSink::QueuedTextConsole(_) => "QueuedTextConsole" + RuntimeSink::QueuedFile(_) => "QueuedFile" + RuntimeSink::Console(_) => "Console" + RuntimeSink::JsonConsole(_) => "JsonConsole" + RuntimeSink::TextConsole(_) => "TextConsole" + RuntimeSink::File(_) => "File" + } + let configured_sink_kind = match configured.sink { + RuntimeSink::QueuedConsole(_) => "QueuedConsole" + RuntimeSink::QueuedJsonConsole(_) => "QueuedJsonConsole" + RuntimeSink::QueuedTextConsole(_) => "QueuedTextConsole" + RuntimeSink::QueuedFile(_) => "QueuedFile" + RuntimeSink::Console(_) => "Console" + RuntimeSink::JsonConsole(_) => "JsonConsole" + RuntimeSink::TextConsole(_) => "TextConsole" + RuntimeSink::File(_) => "File" + } + inspect(application_sink_kind == configured_sink_kind, content="true") + + application.error("one") + application.error("two") + application.error("three") + configured.error("one") + configured.error("two") + configured.error("three") + + inspect(application.pending_count() == configured.pending_count(), content="true") + inspect(application.dropped_count() == configured.dropped_count(), content="true") + inspect(application.flush() == configured.flush(), content="true") + inspect(application.pending_count() == configured.pending_count(), content="true") +} + +test "configured logger keeps broader logger composition surface" { + let logger : ConfiguredLogger = build_logger( + LoggerConfig::new( + min_level=Level::Warn, + target="configured.compose", + queue=Some(QueueConfig::new(2, overflow=QueueOverflowPolicy::DropNewest)), + sink=SinkConfig::new(kind=SinkKind::Console), + ), + ) + let derived = logger.with_timestamp().child("worker") + + inspect(derived.target, content="configured.compose.worker") + inspect(derived.timestamp, content="true") + inspect(derived.is_enabled(Level::Error), content="true") + inspect(derived.is_enabled(Level::Info), content="false") + inspect(match derived.sink { + RuntimeSink::QueuedConsole(_) => "QueuedConsole" + RuntimeSink::QueuedJsonConsole(_) => "QueuedJsonConsole" + RuntimeSink::QueuedTextConsole(_) => "QueuedTextConsole" + RuntimeSink::QueuedFile(_) => "QueuedFile" + _ => "Other" + }, content="QueuedConsole") + + derived.error("one") + derived.error("two") + inspect(derived.pending_count(), content="2") + inspect(derived.dropped_count(), content="0") + inspect(derived.flush(), content="2") +} + +test "configured logger build supports per-call target override" { + let captured_target : Ref[String] = Ref("") + let captured_message : Ref[String] = Ref("") + let captured_fields : Ref[Array[Field]] = Ref([]) + let logger = build_logger( + LoggerConfig::new( + min_level=Level::Warn, + target="configured.default", + sink=SinkConfig::new(kind=SinkKind::Console), + ), + ) + .with_patch(fn(rec) { + captured_target.val = rec.target + captured_message.val = rec.message + captured_fields.val = rec.fields + rec + }) + .with_context_fields([field("service", "bitlogger")]) + + logger.log( + Level::Error, + "override", + fields=[field("mode", "test")], + target="configured.override", + ) + inspect(captured_target.val, content="configured.override") + inspect(captured_message.val, content="override") + inspect(captured_fields.val.length(), content="2") + inspect(captured_fields.val[0].key, content="service") + inspect(captured_fields.val[0].value, content="bitlogger") + inspect(captured_fields.val[1].key, content="mode") + inspect(captured_fields.val[1].value, content="test") + + logger.log(Level::Error, "default") + inspect(captured_target.val, content="configured.default") + inspect(captured_message.val, content="default") + inspect(captured_fields.val.length(), content="1") + inspect(captured_fields.val[0].key, content="service") +} + +test "configured logger build severity helpers use stored target without override" { + let captured_levels : Ref[Array[String]] = Ref([]) + let captured_targets : Ref[Array[String]] = Ref([]) + let captured_fields : Ref[Array[Array[Field]]] = Ref([]) + let logger = build_logger( + LoggerConfig::new( + min_level=Level::Info, + target="configured.helpers", + sink=SinkConfig::new(kind=SinkKind::Console), + ), + ) + .with_patch(fn(rec) { + captured_levels.val.push(rec.level.label()) + captured_targets.val.push(rec.target) + captured_fields.val.push(rec.fields) + rec + }) + .with_context_fields([field("service", "bitlogger")]) + + logger.info("info", fields=[field("mode", "info")]) + logger.warn("warn", fields=[field("mode", "warn")]) + logger.error("error", fields=[field("mode", "error")]) + + inspect(captured_levels.val.length(), content="3") + inspect(captured_levels.val[0], content="INFO") + inspect(captured_levels.val[1], content="WARN") + inspect(captured_levels.val[2], content="ERROR") + inspect(captured_targets.val.length(), content="3") + inspect(captured_targets.val[0], content="configured.helpers") + inspect(captured_targets.val[1], content="configured.helpers") + inspect(captured_targets.val[2], content="configured.helpers") + inspect(captured_fields.val[0].length(), content="2") + inspect(captured_fields.val[1].length(), content="2") + inspect(captured_fields.val[2].length(), content="2") + inspect(captured_fields.val[0][0].key, content="service") + inspect(captured_fields.val[0][1].value, content="info") + inspect(captured_fields.val[1][0].key, content="service") + inspect(captured_fields.val[1][1].value, content="warn") + inspect(captured_fields.val[2][0].key, content="service") + inspect(captured_fields.val[2][1].value, content="error") +} + +test "application logger keeps configured runtime helper surface" { + let logger : ApplicationLogger = build_application_logger( + LoggerConfig::new( + min_level=Level::Warn, + target="app.alias.helpers", + sink=SinkConfig::new(kind=SinkKind::File, path="app-alias.log"), + queue=Some(QueueConfig::new(2, overflow=QueueOverflowPolicy::DropOldest)), + ), + ) + + logger.error("one") + logger.error("two") + logger.error("three") + inspect(logger.pending_count(), content="2") + inspect(logger.dropped_count(), content="1") + inspect(logger.file_policy().append, content="true") + inspect(logger.file_runtime_state() is None, content="false") + inspect(logger.flush(), content="2") + inspect(logger.pending_count(), content="0") + + if logger.file_available() { + inspect(logger.file_flush(), content="true") + inspect(logger.file_close(), content="true") + } else { + inspect(logger.file_flush(), content="false") + inspect(logger.file_close(), content="false") + } +} + +test "application logger build supports per-call target override" { + let captured_target : Ref[String] = Ref("") + let captured_message : Ref[String] = Ref("") + let captured_fields : Ref[Array[Field]] = Ref([]) + let logger = build_application_logger( + LoggerConfig::new( + min_level=Level::Warn, + target="app.config.default", + sink=SinkConfig::new(kind=SinkKind::Console), + ), + ) + .with_patch(fn(rec) { + captured_target.val = rec.target + captured_message.val = rec.message + captured_fields.val = rec.fields + rec + }) + .with_context_fields([field("service", "bitlogger")]) + + logger.log( + Level::Error, + "override", + fields=[field("mode", "test")], + target="app.config.override", + ) + inspect(captured_target.val, content="app.config.override") + inspect(captured_message.val, content="override") + inspect(captured_fields.val.length(), content="2") + inspect(captured_fields.val[0].key, content="service") + inspect(captured_fields.val[0].value, content="bitlogger") + inspect(captured_fields.val[1].key, content="mode") + inspect(captured_fields.val[1].value, content="test") + + logger.log(Level::Error, "default") + inspect(captured_target.val, content="app.config.default") + inspect(captured_message.val, content="default") + inspect(captured_fields.val.length(), content="1") + inspect(captured_fields.val[0].key, content="service") +} + +test "application logger build severity helpers use stored target without override" { + let captured_levels : Ref[Array[String]] = Ref([]) + let captured_targets : Ref[Array[String]] = Ref([]) + let captured_fields : Ref[Array[Array[Field]]] = Ref([]) + let logger = build_application_logger( + LoggerConfig::new( + min_level=Level::Info, + target="app.config.helpers", + sink=SinkConfig::new(kind=SinkKind::Console), + ), + ) + .with_patch(fn(rec) { + captured_levels.val.push(rec.level.label()) + captured_targets.val.push(rec.target) + captured_fields.val.push(rec.fields) + rec + }) + .with_context_fields([field("service", "bitlogger")]) + + logger.info("info", fields=[field("mode", "info")]) + logger.warn("warn", fields=[field("mode", "warn")]) + logger.error("error", fields=[field("mode", "error")]) + + inspect(captured_levels.val.length(), content="3") + inspect(captured_levels.val[0], content="INFO") + inspect(captured_levels.val[1], content="WARN") + inspect(captured_levels.val[2], content="ERROR") + inspect(captured_targets.val.length(), content="3") + inspect(captured_targets.val[0], content="app.config.helpers") + inspect(captured_targets.val[1], content="app.config.helpers") + inspect(captured_targets.val[2], content="app.config.helpers") + inspect(captured_fields.val[0].length(), content="2") + inspect(captured_fields.val[1].length(), content="2") + inspect(captured_fields.val[2].length(), content="2") + inspect(captured_fields.val[0][0].key, content="service") + inspect(captured_fields.val[0][1].value, content="info") + inspect(captured_fields.val[1][0].key, content="service") + inspect(captured_fields.val[1][1].value, content="warn") + inspect(captured_fields.val[2][0].key, content="service") + inspect(captured_fields.val[2][1].value, content="error") +} + +test "application logger keeps broader logger composition surface" { + let logger : ApplicationLogger = build_application_logger( + LoggerConfig::new( + min_level=Level::Warn, + target="app.compose", + queue=Some(QueueConfig::new(2, overflow=QueueOverflowPolicy::DropNewest)), + sink=SinkConfig::new(kind=SinkKind::Console), + ), + ) + let derived = logger.with_timestamp().child("worker") + + inspect(derived.target, content="app.compose.worker") + inspect(derived.timestamp, content="true") + inspect(derived.is_enabled(Level::Error), content="true") + inspect(derived.is_enabled(Level::Info), content="false") + inspect(match derived.sink { + RuntimeSink::QueuedConsole(_) => "QueuedConsole" + RuntimeSink::QueuedJsonConsole(_) => "QueuedJsonConsole" + RuntimeSink::QueuedTextConsole(_) => "QueuedTextConsole" + RuntimeSink::QueuedFile(_) => "QueuedFile" + _ => "Other" + }, content="QueuedConsole") + + derived.error("one") + derived.error("two") + inspect(derived.pending_count(), content="2") + inspect(derived.dropped_count(), content="0") + inspect(derived.flush(), content="2") + inspect(derived.pending_count(), content="0") +} + test "application logger can be built from config text" { let logger = parse_and_build_application_logger( "{\"min_level\":\"warn\",\"target\":\"app.json\",\"sink\":{\"kind\":\"console\"}}", @@ -930,3 +3068,483 @@ test "application logger can be built from config text" { inspect(logger.is_enabled(Level::Info), content="false") inspect(logger.target, content="app.json") } + +test "parsed application logger log supports per-call target override" { + let captured_target : Ref[String] = Ref("") + let captured_message : Ref[String] = Ref("") + let captured_fields : Ref[Array[Field]] = Ref([]) + let logger = parse_and_build_application_logger( + "{\"min_level\":\"warn\",\"target\":\"app.json.default\",\"sink\":{\"kind\":\"console\"}}", + ) + .with_patch(fn(rec) { + captured_target.val = rec.target + captured_message.val = rec.message + captured_fields.val = rec.fields + rec + }) + .with_context_fields([field("service", "bitlogger")]) + + logger.log( + Level::Error, + "override", + fields=[field("mode", "test")], + target="app.json.override", + ) + inspect(captured_target.val, content="app.json.override") + inspect(captured_message.val, content="override") + inspect(captured_fields.val.length(), content="2") + inspect(captured_fields.val[0].key, content="service") + inspect(captured_fields.val[0].value, content="bitlogger") + inspect(captured_fields.val[1].key, content="mode") + inspect(captured_fields.val[1].value, content="test") + + logger.log(Level::Error, "default") + inspect(captured_target.val, content="app.json.default") + inspect(captured_message.val, content="default") + inspect(captured_fields.val.length(), content="1") + inspect(captured_fields.val[0].key, content="service") +} + +test "parsed application logger severity helpers use stored target without override" { + let captured_levels : Ref[Array[String]] = Ref([]) + let captured_targets : Ref[Array[String]] = Ref([]) + let captured_fields : Ref[Array[Array[Field]]] = Ref([]) + let logger = parse_and_build_application_logger( + "{\"min_level\":\"info\",\"target\":\"app.json.helpers\",\"sink\":{\"kind\":\"console\"}}", + ) + .with_patch(fn(rec) { + captured_levels.val.push(rec.level.label()) + captured_targets.val.push(rec.target) + captured_fields.val.push(rec.fields) + rec + }) + .with_context_fields([field("service", "bitlogger")]) + + logger.info("info", fields=[field("mode", "info")]) + logger.warn("warn", fields=[field("mode", "warn")]) + logger.error("error", fields=[field("mode", "error")]) + + inspect(captured_levels.val.length(), content="3") + inspect(captured_levels.val[0], content="INFO") + inspect(captured_levels.val[1], content="WARN") + inspect(captured_levels.val[2], content="ERROR") + inspect(captured_targets.val.length(), content="3") + inspect(captured_targets.val[0], content="app.json.helpers") + inspect(captured_targets.val[1], content="app.json.helpers") + inspect(captured_targets.val[2], content="app.json.helpers") + inspect(captured_fields.val[0].length(), content="2") + inspect(captured_fields.val[1].length(), content="2") + inspect(captured_fields.val[2].length(), content="2") + inspect(captured_fields.val[0][0].key, content="service") + inspect(captured_fields.val[0][1].value, content="info") + inspect(captured_fields.val[1][0].key, content="service") + inspect(captured_fields.val[1][1].value, content="warn") + inspect(captured_fields.val[2][0].key, content="service") + inspect(captured_fields.val[2][1].value, content="error") +} + +test "application logger parse-build matches parsed direct builder behavior" { + let raw = "{\"min_level\":\"warn\",\"target\":\"app.json.same-build\",\"timestamp\":true,\"queue\":{\"max_pending\":2,\"overflow\":\"DropNewest\"},\"sink\":{\"kind\":\"console\"}}" + let application = parse_and_build_application_logger(raw) + let configured = build_logger(parse_logger_config_text(raw)) + + inspect(application.target, content=configured.target) + inspect(application.timestamp == configured.timestamp, content="true") + inspect(application.is_enabled(Level::Error) == configured.is_enabled(Level::Error), content="true") + inspect(application.is_enabled(Level::Info) == configured.is_enabled(Level::Info), content="true") + let application_sink_kind = match application.sink { + RuntimeSink::QueuedConsole(_) => "QueuedConsole" + RuntimeSink::QueuedJsonConsole(_) => "QueuedJsonConsole" + RuntimeSink::QueuedTextConsole(_) => "QueuedTextConsole" + RuntimeSink::QueuedFile(_) => "QueuedFile" + RuntimeSink::Console(_) => "Console" + RuntimeSink::JsonConsole(_) => "JsonConsole" + RuntimeSink::TextConsole(_) => "TextConsole" + RuntimeSink::File(_) => "File" + } + let configured_sink_kind = match configured.sink { + RuntimeSink::QueuedConsole(_) => "QueuedConsole" + RuntimeSink::QueuedJsonConsole(_) => "QueuedJsonConsole" + RuntimeSink::QueuedTextConsole(_) => "QueuedTextConsole" + RuntimeSink::QueuedFile(_) => "QueuedFile" + RuntimeSink::Console(_) => "Console" + RuntimeSink::JsonConsole(_) => "JsonConsole" + RuntimeSink::TextConsole(_) => "TextConsole" + RuntimeSink::File(_) => "File" + } + inspect(application_sink_kind == configured_sink_kind, content="true") + + application.error("one") + application.error("two") + application.error("three") + configured.error("one") + configured.error("two") + configured.error("three") + + inspect(application.pending_count() == configured.pending_count(), content="true") + inspect(application.dropped_count() == configured.dropped_count(), content="true") + inspect(application.flush() == configured.flush(), content="true") + inspect(application.pending_count() == configured.pending_count(), content="true") +} + +test "application logger file helpers match direct configured builder behavior" { + let config = LoggerConfig::new( + min_level=Level::Warn, + target="app.file.same-build", + sink=SinkConfig::new(kind=SinkKind::File, path="app-file-same-build.log"), + queue=Some(QueueConfig::new(2, overflow=QueueOverflowPolicy::DropOldest)), + ) + let application = build_application_logger(config) + let configured = build_logger(config) + + application.error("one") + application.error("two") + application.error("three") + configured.error("one") + configured.error("two") + configured.error("three") + + inspect(application.pending_count() == configured.pending_count(), content="true") + inspect(application.dropped_count() == configured.dropped_count(), content="true") + inspect(application.file_available() == configured.file_available(), content="true") + inspect(application.file_append_mode() == configured.file_append_mode(), content="true") + inspect(application.file_auto_flush() == configured.file_auto_flush(), content="true") + inspect(application.file_policy_matches_default() == configured.file_policy_matches_default(), content="true") + + let application_policy = application.file_policy() + let configured_policy = configured.file_policy() + inspect(application_policy.append == configured_policy.append, content="true") + inspect(application_policy.auto_flush == configured_policy.auto_flush, content="true") + inspect(match application_policy.rotation { + Some(rotation) => match configured_policy.rotation { + Some(other) => rotation.max_bytes == other.max_bytes && rotation.max_backups == other.max_backups + None => false + } + None => configured_policy.rotation is None + }, content="true") + + let application_state = application.file_state() + let configured_state = configured.file_state() + inspect(application_state.path == configured_state.path, content="true") + inspect(application_state.available == configured_state.available, content="true") + inspect(application_state.append == configured_state.append, content="true") + inspect(application_state.auto_flush == configured_state.auto_flush, content="true") + inspect(application_state.open_failures == configured_state.open_failures, content="true") + inspect(application_state.write_failures == configured_state.write_failures, content="true") + inspect(application_state.flush_failures == configured_state.flush_failures, content="true") + inspect(application_state.rotation_failures == configured_state.rotation_failures, content="true") + + match (application.file_runtime_state(), configured.file_runtime_state()) { + (Some(snapshot), Some(other)) => { + inspect(snapshot.file.path == other.file.path, content="true") + inspect(snapshot.file.available == other.file.available, content="true") + inspect(snapshot.queued == other.queued, content="true") + inspect(snapshot.pending_count == other.pending_count, content="true") + inspect(snapshot.dropped_count == other.dropped_count, content="true") + } + _ => inspect(false, content="true") + } + + inspect(application.file_flush() == configured.file_flush(), content="true") + inspect(application.pending_count() == configured.pending_count(), content="true") + inspect(application.file_close() == configured.file_close(), content="true") +} + +test "application logger file controls match direct configured builder behavior" { + let config = LoggerConfig::new( + min_level=Level::Warn, + target="app.file.controls.same-build", + sink=SinkConfig::new(kind=SinkKind::File, path="app-file-controls-same-build.log"), + ) + let application = build_application_logger(config) + let configured = build_logger(config) + + inspect(application.file_set_append_mode(false) == configured.file_set_append_mode(false), content="true") + inspect(application.file_append_mode() == configured.file_append_mode(), content="true") + + inspect(application.file_set_auto_flush(false) == configured.file_set_auto_flush(false), content="true") + inspect(application.file_auto_flush() == configured.file_auto_flush(), content="true") + + let rotation = Some(file_rotation(48, max_backups=3)) + inspect(application.file_set_rotation(rotation) == configured.file_set_rotation(rotation), content="true") + inspect(application.file_rotation_enabled() == configured.file_rotation_enabled(), content="true") + + let application_policy = application.file_policy() + let configured_policy = configured.file_policy() + inspect(application_policy.append == configured_policy.append, content="true") + inspect(application_policy.auto_flush == configured_policy.auto_flush, content="true") + inspect(match application_policy.rotation { + Some(value) => match configured_policy.rotation { + Some(other) => value.max_bytes == other.max_bytes && value.max_backups == other.max_backups + None => false + } + None => configured_policy.rotation is None + }, content="true") + + inspect(application.file_reopen_append() == configured.file_reopen_append(), content="true") + inspect(application.file_append_mode() == configured.file_append_mode(), content="true") + inspect(application.file_reopen_truncate() == configured.file_reopen_truncate(), content="true") + inspect(application.file_append_mode() == configured.file_append_mode(), content="true") + inspect( + application.file_reopen_with_current_policy() == configured.file_reopen_with_current_policy(), + content="true", + ) + + inspect(application.file_clear_rotation() == configured.file_clear_rotation(), content="true") + inspect(application.file_rotation_enabled() == configured.file_rotation_enabled(), content="true") + inspect(application.file_policy_matches_default() == configured.file_policy_matches_default(), content="true") + inspect(application.file_reset_policy() == configured.file_reset_policy(), content="true") + inspect(application.file_policy_matches_default() == configured.file_policy_matches_default(), content="true") + inspect(application.file_reset_failure_counters() == configured.file_reset_failure_counters(), content="true") + + inspect(application.file_close() == configured.file_close(), content="true") +} + +test "parsed application logger keeps direct runtime helper surface" { + let logger : ApplicationLogger = parse_and_build_application_logger( + "{\"min_level\":\"warn\",\"target\":\"app.json.helpers\",\"queue\":{\"max_pending\":2,\"overflow\":\"DropOldest\"},\"sink\":{\"kind\":\"file\",\"path\":\"app-json-helpers.log\"}}", + ) + + logger.error("one") + logger.error("two") + logger.error("three") + inspect(logger.pending_count(), content="2") + inspect(logger.dropped_count(), content="1") + inspect(logger.file_policy().append, content="true") + inspect(logger.file_runtime_state() is None, content="false") + inspect(logger.flush(), content="2") + inspect(logger.pending_count(), content="0") + + if logger.file_available() { + inspect(logger.file_flush(), content="true") + inspect(logger.file_close(), content="true") + } else { + inspect(logger.file_flush(), content="false") + inspect(logger.file_close(), content="false") + } +} + +test "parsed application logger file helpers match parsed configured builder behavior" { + let raw = "{\"min_level\":\"warn\",\"target\":\"app.json.file.same-build\",\"queue\":{\"max_pending\":2,\"overflow\":\"DropOldest\"},\"sink\":{\"kind\":\"file\",\"path\":\"app-json-file-same-build.log\"}}" + let application = parse_and_build_application_logger(raw) + let configured = parse_and_build_logger(raw) + + application.error("one") + application.error("two") + application.error("three") + configured.error("one") + configured.error("two") + configured.error("three") + + inspect(application.pending_count() == configured.pending_count(), content="true") + inspect(application.dropped_count() == configured.dropped_count(), content="true") + inspect(application.file_available() == configured.file_available(), content="true") + inspect(application.file_append_mode() == configured.file_append_mode(), content="true") + inspect(application.file_auto_flush() == configured.file_auto_flush(), content="true") + inspect(application.file_policy_matches_default() == configured.file_policy_matches_default(), content="true") + + let application_state = application.file_state() + let configured_state = configured.file_state() + inspect(application_state.path == configured_state.path, content="true") + inspect(application_state.available == configured_state.available, content="true") + inspect(application_state.append == configured_state.append, content="true") + inspect(application_state.auto_flush == configured_state.auto_flush, content="true") + inspect(application_state.open_failures == configured_state.open_failures, content="true") + inspect(application_state.write_failures == configured_state.write_failures, content="true") + inspect(application_state.flush_failures == configured_state.flush_failures, content="true") + inspect(application_state.rotation_failures == configured_state.rotation_failures, content="true") + + match (application.file_runtime_state(), configured.file_runtime_state()) { + (Some(snapshot), Some(other)) => { + inspect(snapshot.file.path == other.file.path, content="true") + inspect(snapshot.file.available == other.file.available, content="true") + inspect(snapshot.queued == other.queued, content="true") + inspect(snapshot.pending_count == other.pending_count, content="true") + inspect(snapshot.dropped_count == other.dropped_count, content="true") + } + _ => inspect(false, content="true") + } + + inspect(application.file_flush() == configured.file_flush(), content="true") + inspect(application.pending_count() == configured.pending_count(), content="true") + inspect(application.file_close() == configured.file_close(), content="true") +} + +test "parsed application logger file controls match parsed configured builder behavior" { + let raw = "{\"min_level\":\"warn\",\"target\":\"app.json.file.controls.same-build\",\"sink\":{\"kind\":\"file\",\"path\":\"app-json-file-controls-same-build.log\"}}" + let application = parse_and_build_application_logger(raw) + let configured = parse_and_build_logger(raw) + + inspect(application.file_set_append_mode(false) == configured.file_set_append_mode(false), content="true") + inspect(application.file_append_mode() == configured.file_append_mode(), content="true") + inspect(application.file_set_auto_flush(false) == configured.file_set_auto_flush(false), content="true") + inspect(application.file_auto_flush() == configured.file_auto_flush(), content="true") + + let rotation = Some(file_rotation(40, max_backups=2)) + inspect(application.file_set_rotation(rotation) == configured.file_set_rotation(rotation), content="true") + inspect(application.file_rotation_enabled() == configured.file_rotation_enabled(), content="true") + inspect(application.file_reopen(append=Some(false)) == configured.file_reopen(append=Some(false)), content="true") + inspect(application.file_append_mode() == configured.file_append_mode(), content="true") + inspect(application.file_reopen_append() == configured.file_reopen_append(), content="true") + inspect(application.file_append_mode() == configured.file_append_mode(), content="true") + inspect(application.file_clear_rotation() == configured.file_clear_rotation(), content="true") + inspect(application.file_rotation_enabled() == configured.file_rotation_enabled(), content="true") + inspect(application.file_reset_policy() == configured.file_reset_policy(), content="true") + inspect(application.file_policy_matches_default() == configured.file_policy_matches_default(), content="true") + inspect(application.file_reset_failure_counters() == configured.file_reset_failure_counters(), content="true") + + inspect(application.file_close() == configured.file_close(), content="true") +} + +test "parsed configured logger keeps composition and runtime helper surface" { + let logger : ConfiguredLogger = parse_and_build_logger( + "{\"min_level\":\"warn\",\"target\":\"parsed.compose\",\"timestamp\":true,\"queue\":{\"max_pending\":2,\"overflow\":\"DropNewest\"},\"sink\":{\"kind\":\"console\"}}", + ) + let derived = logger.child("worker") + + inspect(derived.target, content="parsed.compose.worker") + inspect(derived.timestamp, content="true") + inspect(derived.is_enabled(Level::Error), content="true") + inspect(derived.is_enabled(Level::Info), content="false") + inspect(match derived.sink { + RuntimeSink::QueuedConsole(_) => "QueuedConsole" + RuntimeSink::QueuedJsonConsole(_) => "QueuedJsonConsole" + RuntimeSink::QueuedTextConsole(_) => "QueuedTextConsole" + RuntimeSink::QueuedFile(_) => "QueuedFile" + _ => "Other" + }, content="QueuedConsole") + + derived.error("one") + derived.error("two") + inspect(derived.pending_count(), content="2") + inspect(derived.dropped_count(), content="0") + inspect(derived.flush(), content="2") + inspect(derived.pending_count(), content="0") +} + +test "parsed configured logger log supports per-call target override" { + let captured_target : Ref[String] = Ref("") + let captured_message : Ref[String] = Ref("") + let captured_fields : Ref[Array[Field]] = Ref([]) + let logger = parse_and_build_logger( + "{\"min_level\":\"warn\",\"target\":\"parsed.default\",\"sink\":{\"kind\":\"console\"}}", + ) + .with_patch(fn(rec) { + captured_target.val = rec.target + captured_message.val = rec.message + captured_fields.val = rec.fields + rec + }) + .with_context_fields([field("service", "bitlogger")]) + + logger.log( + Level::Error, + "override", + fields=[field("mode", "test")], + target="parsed.override", + ) + inspect(captured_target.val, content="parsed.override") + inspect(captured_message.val, content="override") + inspect(captured_fields.val.length(), content="2") + inspect(captured_fields.val[0].key, content="service") + inspect(captured_fields.val[0].value, content="bitlogger") + inspect(captured_fields.val[1].key, content="mode") + inspect(captured_fields.val[1].value, content="test") + + logger.log(Level::Error, "default") + inspect(captured_target.val, content="parsed.default") + inspect(captured_message.val, content="default") + inspect(captured_fields.val.length(), content="1") + inspect(captured_fields.val[0].key, content="service") +} + +test "parsed configured logger severity helpers use stored target without override" { + let captured_levels : Ref[Array[String]] = Ref([]) + let captured_targets : Ref[Array[String]] = Ref([]) + let captured_fields : Ref[Array[Array[Field]]] = Ref([]) + let logger = parse_and_build_logger( + "{\"min_level\":\"info\",\"target\":\"parsed.helpers\",\"sink\":{\"kind\":\"console\"}}", + ) + .with_patch(fn(rec) { + captured_levels.val.push(rec.level.label()) + captured_targets.val.push(rec.target) + captured_fields.val.push(rec.fields) + rec + }) + .with_context_fields([field("service", "bitlogger")]) + + logger.info("info", fields=[field("mode", "info")]) + logger.warn("warn", fields=[field("mode", "warn")]) + logger.error("error", fields=[field("mode", "error")]) + + inspect(captured_levels.val.length(), content="3") + inspect(captured_levels.val[0], content="INFO") + inspect(captured_levels.val[1], content="WARN") + inspect(captured_levels.val[2], content="ERROR") + inspect(captured_targets.val.length(), content="3") + inspect(captured_targets.val[0], content="parsed.helpers") + inspect(captured_targets.val[1], content="parsed.helpers") + inspect(captured_targets.val[2], content="parsed.helpers") + inspect(captured_fields.val[0].length(), content="2") + inspect(captured_fields.val[1].length(), content="2") + inspect(captured_fields.val[2].length(), content="2") + inspect(captured_fields.val[0][0].key, content="service") + inspect(captured_fields.val[0][1].value, content="info") + inspect(captured_fields.val[1][0].key, content="service") + inspect(captured_fields.val[1][1].value, content="warn") + inspect(captured_fields.val[2][0].key, content="service") + inspect(captured_fields.val[2][1].value, content="error") +} + +test "sync parse-build facades forward config errors" { + let raw = "{\"sink\":{\"kind\":\"file\",\"path\":\"\"}}" + let malformed = "{" + + let configured_error = (fn() -> String raise ConfigError { + ignore(parse_and_build_logger(raw)) + "no error" + })() catch { + ConfigError::InvalidConfig(message) => message + } + inspect(configured_error, content="File sink requires non-empty path") + + let application_error = (fn() -> String raise ConfigError { + ignore(parse_and_build_application_logger(raw)) + "no error" + })() catch { + ConfigError::InvalidConfig(message) => message + } + inspect(application_error, content="File sink requires non-empty path") + + let library_error = (fn() -> String raise ConfigError { + ignore(parse_and_build_library_logger(raw)) + "no error" + })() catch { + ConfigError::InvalidConfig(message) => message + } + inspect(library_error, content="File sink requires non-empty path") + + let configured_invalid_json = (fn() -> String raise ConfigError { + ignore(parse_and_build_logger(malformed)) + "no error" + })() catch { + ConfigError::InvalidConfig(message) => message + } + inspect(configured_invalid_json.contains("Invalid JSON:"), content="true") + + let application_invalid_json = (fn() -> String raise ConfigError { + ignore(parse_and_build_application_logger(malformed)) + "no error" + })() catch { + ConfigError::InvalidConfig(message) => message + } + inspect(application_invalid_json.contains("Invalid JSON:"), content="true") + + let library_invalid_json = (fn() -> String raise ConfigError { + ignore(parse_and_build_library_logger(malformed)) + "no error" + })() catch { + ConfigError::InvalidConfig(message) => message + } + inspect(library_invalid_json.contains("Invalid JSON:"), content="true") +} diff --git a/src/BitLogger_wbtest.mbt b/src/BitLogger_wbtest.mbt index 9296aeb..275d4ea 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() @@ -544,12 +562,17 @@ test "file sink set policy applies bundled runtime policy" { } test "file sink tracks rotation failures on unavailable backend" { - let sink = file_sink("bitlogger-rotate.log", rotation=Some(file_rotation(1, max_backups=1))) + let path = "bitlogger-rotate.log" + ignore(remove_file_internal(path)) + ignore(remove_file_internal(path + ".1")) + let sink = file_sink(path, rotation=Some(file_rotation(1, max_backups=1))) sink.write(record(Level::Info, "a")) if sink.is_available() { inspect(sink.rotation_failures(), content="0") inspect(sink.write_failures(), content="0") ignore(sink.close()) + ignore(remove_file_internal(path)) + ignore(remove_file_internal(path + ".1")) } else { inspect(sink.rotation_failures(), content="0") inspect(sink.write_failures(), content="1")