diff --git a/docs/file.md b/docs/file.md new file mode 100644 index 0000000..5e2d0bd --- /dev/null +++ b/docs/file.md @@ -0,0 +1,41 @@ +# File subscriber + +`brickfrog/moontrace/file` is a native-only buffered file subscriber. The +subscriber returned by `FileSubscriber::subscriber()` is synchronous: it formats +the event as one JSON line and attempts a non-blocking enqueue. When the queue +is full or shut down, the event is dropped and counted. + +The application owns the async worker. Start `run()` inside the app's async +context, then call `flush()` at durability boundaries and `shutdown()` before +leaving the task group. + +```moonbit +let files = @file.file_subscriber( + "logs/moontrace.jsonl", + max_size_bytes=10 * 1024 * 1024, + max_files=5, + gzip=true, + max_batch=128, + queue_capacity=1024, +) + +@moontrace.set_subscriber(files.subscriber()) + +@async.with_task_group(group => { + group.spawn_bg(() => files.run()) + + @moontrace.info("service started") + files.flush() + + files.shutdown() +}) +``` + +Rotation is size-based. When the active file crosses `max_size_bytes`, it is +renamed to `path.1`, older rotated files are shifted up, and files beyond +`max_files` are removed. With `gzip=true`, rotated files are written as +`path.N.gz` and the temporary uncompressed rotation is removed. + +The file subscriber uses `moonbitlang/async/fs` and is only supported on the +native target. Constructing it on other targets aborts immediately with a clear +unsupported-target error instead of returning a subscriber that drops events. diff --git a/src/file/file_subscriber.mbt b/src/file/file_subscriber.mbt new file mode 100644 index 0000000..2712a75 --- /dev/null +++ b/src/file/file_subscriber.mbt @@ -0,0 +1,506 @@ +///| +const DEFAULT_MAX_SIZE_BYTES : Int = 10 * 1024 * 1024 + +///| +const DEFAULT_MAX_FILES : Int = 5 + +///| +const DEFAULT_MAX_BATCH : Int = 128 + +///| +const DEFAULT_QUEUE_CAPACITY : Int = 1024 + +///| +pub(all) struct FileSubscriberConfig { + path : String + max_size_bytes : Int + max_files : Int + gzip : Bool + max_batch : Int + queue_capacity : Int +} derive(Eq, Compare, Debug) + +///| +pub fn FileSubscriberConfig::new( + path : String, + max_size_bytes? : Int = DEFAULT_MAX_SIZE_BYTES, + max_files? : Int = DEFAULT_MAX_FILES, + gzip? : Bool = false, + max_batch? : Int = DEFAULT_MAX_BATCH, + queue_capacity? : Int = DEFAULT_QUEUE_CAPACITY, +) -> FileSubscriberConfig { + { + path, + max_size_bytes: clamp_positive(max_size_bytes), + max_files: clamp_non_negative(max_files), + gzip, + max_batch: clamp_positive(max_batch), + queue_capacity: clamp_positive(queue_capacity), + } +} + +///| +#cfg(target="native") +struct FileSubscriber { + config : FileSubscriberConfig + queue : @aqueue.Queue[String] + write_lock : @aqueue.Queue[Unit] + mut initialized : Bool + mut current_size : Int + mut enqueued_count : Int + mut written_count : Int + mut dropped_count : Int + mut is_shut_down : Bool + mut worker_running : Bool +} + +///| +#cfg(not(target="native")) +struct FileSubscriber { + marker : Unit +} + +///| +#cfg(not(target="native")) +let _non_native_file_subscriber_marker : FileSubscriber = FileSubscriber::{ + marker: (), +} + +///| +pub fn file_subscriber( + path : String, + max_size_bytes? : Int = DEFAULT_MAX_SIZE_BYTES, + max_files? : Int = DEFAULT_MAX_FILES, + gzip? : Bool = false, + max_batch? : Int = DEFAULT_MAX_BATCH, + queue_capacity? : Int = DEFAULT_QUEUE_CAPACITY, +) -> FileSubscriber { + FileSubscriber::new( + FileSubscriberConfig::new( + path, + max_size_bytes~, + max_files~, + gzip~, + max_batch~, + queue_capacity~, + ), + ) +} + +///| +#cfg(target="native") +pub fn FileSubscriber::new(config : FileSubscriberConfig) -> FileSubscriber { + let queue : @aqueue.Queue[String] = @aqueue.Queue( + kind=@aqueue.Kind::Blocking(config.queue_capacity), + ) + let write_lock : @aqueue.Queue[Unit] = @aqueue.Queue( + kind=@aqueue.Kind::Blocking(1), + ) + let _ = write_lock.try_put(()) catch { _ => false } + { + config, + queue, + write_lock, + initialized: false, + current_size: 0, + enqueued_count: 0, + written_count: 0, + dropped_count: 0, + is_shut_down: false, + worker_running: false, + } +} + +///| +#cfg(not(target="native")) +pub fn FileSubscriber::new(_config : FileSubscriberConfig) -> FileSubscriber { + abort(unsupported_target_message()) +} + +///| +#cfg(target="native") +pub fn FileSubscriber::subscriber( + self : FileSubscriber, +) -> (@moontrace.Event) -> Unit { + fn(event) { + if self.is_shut_down { + self.dropped_count += 1 + return + } + let line = event.to_json().stringify() + "\n" + let accepted = self.queue.try_put(line) catch { _ => false } + if accepted { + self.enqueued_count += 1 + } else { + self.dropped_count += 1 + } + } +} + +///| +#cfg(not(target="native")) +pub fn FileSubscriber::subscriber( + self : FileSubscriber, +) -> (@moontrace.Event) -> Unit { + ignore(self.marker) + fn(_event) { abort(unsupported_target_message()) } +} + +///| +pub fn FileSubscriber::dropped(self : FileSubscriber) -> Int { + self.dropped_count_impl() +} + +///| +#cfg(target="native") +pub fn FileSubscriber::written(self : FileSubscriber) -> Int { + self.written_count +} + +///| +#cfg(not(target="native")) +pub fn FileSubscriber::written(_self : FileSubscriber) -> Int { + 0 +} + +///| +#cfg(target="native") +fn FileSubscriber::dropped_count_impl(self : FileSubscriber) -> Int { + self.dropped_count +} + +///| +#cfg(not(target="native")) +fn FileSubscriber::dropped_count_impl(_self : FileSubscriber) -> Int { + ignore(_self.marker) + 0 +} + +///| +#cfg(target="native") +pub async fn FileSubscriber::run(self : FileSubscriber) -> Unit { + if self.worker_running { + raise Failure::Failure( + "moontrace file subscriber worker is already running", + ) + } + self.worker_running = true + defer { + self.worker_running = false + } + while true { + let first = self.queue.get() catch { + @aqueue.QueueAlreadyClosed => return + err => raise err + } + let batch = self.batch_with_first(first) + self.write_batch(batch) + @async.sleep(0) + } +} + +///| +#cfg(not(target="native")) +pub async fn FileSubscriber::run(self : FileSubscriber) -> Unit { + ignore(self.marker) + @async.sleep(0) + raise Failure::Failure(unsupported_target_message()) +} + +///| +#cfg(target="native") +pub async fn FileSubscriber::flush(self : FileSubscriber) -> Unit { + let target = self.enqueued_count + if self.worker_running { + while self.worker_running && self.written_count < target { + @async.sleep(0) + } + } + if self.written_count < target { + self.drain_without_worker() + } + if self.written_count < target { + raise Failure::Failure( + "moontrace file subscriber flush could not write all accepted events", + ) + } +} + +///| +#cfg(not(target="native")) +pub async fn FileSubscriber::flush(self : FileSubscriber) -> Unit { + ignore(self.marker) + @async.sleep(0) + raise Failure::Failure(unsupported_target_message()) +} + +///| +#cfg(target="native") +pub async fn FileSubscriber::shutdown(self : FileSubscriber) -> Unit { + if !self.is_shut_down { + self.is_shut_down = true + } + self.flush() + self.queue.close() + while self.worker_running { + @async.sleep(0) + } +} + +///| +#cfg(not(target="native")) +pub async fn FileSubscriber::shutdown(self : FileSubscriber) -> Unit { + ignore(self.marker) + @async.sleep(0) + raise Failure::Failure(unsupported_target_message()) +} + +///| +fn clamp_positive(value : Int) -> Int { + if value < 1 { + 1 + } else { + value + } +} + +///| +fn clamp_non_negative(value : Int) -> Int { + if value < 0 { + 0 + } else { + value + } +} + +///| +#cfg(not(target="native")) +fn unsupported_target_message() -> String { + "moontrace file subscriber is only supported on the native target" +} + +///| +#cfg(target="native") +fn byte_len(data : String) -> Int { + let payload : &@io.Data = data + payload.binary().length() +} + +///| +#cfg(target="native") +fn FileSubscriber::try_take(self : FileSubscriber) -> String? { + self.queue.try_get() catch { + _ => None + } +} + +///| +#cfg(target="native") +fn FileSubscriber::batch_with_first( + self : FileSubscriber, + first : String, +) -> Array[String] { + let batch = [first] + while batch.length() < self.config.max_batch { + match self.try_take() { + Some(line) => batch.push(line) + None => break + } + } + batch +} + +///| +#cfg(target="native") +async fn FileSubscriber::drain_without_worker(self : FileSubscriber) -> Unit { + while true { + match self.try_take() { + Some(first) => { + self.write_batch(self.batch_with_first(first)) + @async.sleep(0) + } + None => return + } + } +} + +///| +#cfg(target="native") +async fn FileSubscriber::write_batch( + self : FileSubscriber, + lines : Array[String], +) -> Unit { + if lines.is_empty() { + return + } + ignore(self.write_lock.get()) + defer self.release_write_lock() + self.initialize_file() + let builder = StringBuilder::new() + let mut payload_bytes = 0 + lines.each(fn(line) { + payload_bytes += byte_len(line) + builder.write_string(line) + }) + if self.current_size > 0 && + self.current_size + payload_bytes > self.config.max_size_bytes { + self.rotate() + } + let payload = builder.to_string() + @fs.write_file( + self.config.path, + payload, + create_mode=@fs.CreateMode::OpenOrCreate, + append=true, + ) + self.current_size += payload_bytes + self.written_count += lines.length() + if self.current_size >= self.config.max_size_bytes { + self.rotate() + } +} + +///| +#cfg(target="native") +fn FileSubscriber::release_write_lock(self : FileSubscriber) -> Unit { + let _ = self.write_lock.try_put(()) catch { _ => false } +} + +///| +#cfg(target="native") +async fn FileSubscriber::initialize_file(self : FileSubscriber) -> Unit { + if self.initialized { + return + } + if @fs.exists(self.config.path) { + let file = @fs.open( + self.config.path, + mode=@fs.Mode::ReadOnly, + create_mode=@fs.CreateMode::OpenExisting, + ) + self.current_size = file.size().to_int() + file.close() + if self.current_size >= self.config.max_size_bytes { + self.rotate() + } + } else { + self.ensure_active_file() + } + self.initialized = true +} + +///| +#cfg(target="native") +async fn FileSubscriber::ensure_active_file(self : FileSubscriber) -> Unit { + @fs.write_file( + self.config.path, + "", + create_mode=@fs.CreateMode::OpenOrCreate, + append=true, + ) +} + +///| +#cfg(target="native") +async fn FileSubscriber::rotate(self : FileSubscriber) -> Unit { + if !@fs.exists(self.config.path) { + self.current_size = 0 + self.ensure_active_file() + return + } + if self.config.max_files == 0 { + @fs.remove(self.config.path) + self.current_size = 0 + self.ensure_active_file() + @async.sleep(0) + return + } + self.shift_rotated_files() + let raw_path = self.raw_rotated_path(1) + self.remove_if_exists(raw_path) + if self.config.gzip { + self.remove_if_exists(self.rotated_path(1)) + } + @fs.rename(self.config.path, raw_path, replace=true) + if self.config.gzip { + self.gzip_file(raw_path, self.rotated_path(1)) + self.remove_if_exists(raw_path) + } + self.current_size = 0 + self.ensure_active_file() + @async.sleep(0) +} + +///| +#cfg(target="native") +async fn FileSubscriber::shift_rotated_files(self : FileSubscriber) -> Unit { + self.remove_if_exists(self.rotated_path(self.config.max_files)) + if self.config.gzip { + self.remove_if_exists(self.raw_rotated_path(self.config.max_files)) + } + let mut index = self.config.max_files - 1 + while index >= 1 { + let from = self.rotated_path(index) + if @fs.exists(from) { + @fs.rename(from, self.rotated_path(index + 1), replace=true) + } + index -= 1 + } +} + +///| +#cfg(target="native") +fn FileSubscriber::raw_rotated_path( + self : FileSubscriber, + index : Int, +) -> String { + self.config.path + "." + index.to_string() +} + +///| +#cfg(target="native") +fn FileSubscriber::rotated_path(self : FileSubscriber, index : Int) -> String { + let path = self.raw_rotated_path(index) + if self.config.gzip { + path + ".gz" + } else { + path + } +} + +///| +#cfg(target="native") +async fn FileSubscriber::remove_if_exists( + _self : FileSubscriber, + path : String, +) -> Unit { + if @fs.exists(path) { + @fs.remove(path) + } +} + +///| +#cfg(target="native") +async fn FileSubscriber::gzip_file( + _self : FileSubscriber, + source : String, + destination : String, +) -> Unit { + let reader = @fs.open( + source, + mode=@fs.Mode::ReadOnly, + create_mode=@fs.CreateMode::OpenExisting, + ) + defer reader.close() + let writer = @fs.open( + destination, + mode=@fs.Mode::WriteOnly, + create_mode=@fs.CreateMode::CreateOrTruncate, + permission=0o600, + ) + defer writer.close() + let encoder = @gzip.Encoder(writer) + encoder.write(reader.read_all()) + encoder.end() + @async.sleep(0) +} diff --git a/src/file/file_subscriber_test.mbt b/src/file/file_subscriber_test.mbt new file mode 100644 index 0000000..7ec9804 --- /dev/null +++ b/src/file/file_subscriber_test.mbt @@ -0,0 +1,283 @@ +///| +#cfg(target="native") +fn test_event(message : String) -> @moontrace.Event { + @moontrace.Event::{ + level: @moontrace.Info, + message, + fields: [], + timestamp: (123 : UInt64), + source: "brickfrog/moontrace/file/test", + } +} + +///| +#cfg(target="native") +fn event_line(message : String) -> String { + test_event(message).to_json().stringify() + "\n" +} + +///| +#cfg(target="native") +fn lines(messages : Array[String]) -> String { + let builder = StringBuilder::new() + messages.each(fn(message) { builder.write_string(event_line(message)) }) + builder.to_string() +} + +///| +#cfg(target="native") +fn string_bytes(data : String) -> Int { + let payload : &@io.Data = data + payload.binary().length() +} + +///| +#cfg(target="native") +async fn with_temp_log(f : async (String) -> Unit) -> Unit { + @async.with_task_group(group => { + let dir = @fs.tmpdir(prefix="moontrace-file") + group.add_defer(() => { + @async.protect_from_cancel(() => @fs.rmdir(dir, recursive=true)) + }) + f(dir + "/events.log") + }) +} + +///| +#cfg(target="native") +async test "append writes json lines in order after flush" { + @async.with_timeout(1000, () => { + with_temp_log(path => { + let subscriber = @file.file_subscriber(path, max_batch=16) + let sink = subscriber.subscriber() + sink(test_event("one")) + sink(test_event("two")) + subscriber.flush() + assert_eq(@fs.read_file(path).text(), lines(["one", "two"])) + assert_eq(subscriber.written(), 2) + assert_eq(subscriber.dropped(), 0) + }) + }) +} + +///| +#cfg(target="native") +async test "flush without worker drains queued lines" { + @async.with_timeout(1000, () => { + with_temp_log(path => { + let subscriber = @file.file_subscriber(path, max_batch=1) + let sink = subscriber.subscriber() + sink(test_event("no-worker-one")) + sink(test_event("no-worker-two")) + subscriber.flush() + assert_eq( + @fs.read_file(path).text(), + lines(["no-worker-one", "no-worker-two"]), + ) + assert_eq(subscriber.written(), 2) + }) + }) +} + +///| +#cfg(target="native") +async test "rotation creates rotated file and fresh active file" { + @async.with_timeout(1000, () => { + with_temp_log(path => { + let expected = lines(["before", "after"]) + let subscriber = @file.file_subscriber( + path, + max_size_bytes=string_bytes(expected) - 1, + max_files=3, + max_batch=16, + ) + let sink = subscriber.subscriber() + sink(test_event("before")) + sink(test_event("after")) + subscriber.flush() + assert_eq(@fs.read_file(path + ".1").text(), expected) + assert_true(@fs.exists(path)) + assert_eq(@fs.read_file(path).text(), "") + }) + }) +} + +///| +#cfg(target="native") +async test "retention deletes rotated files beyond max_files" { + @async.with_timeout(1000, () => { + with_temp_log(path => { + let subscriber = @file.file_subscriber( + path, + max_size_bytes=1, + max_files=2, + max_batch=1, + ) + let sink = subscriber.subscriber() + sink(test_event("one")) + sink(test_event("two")) + sink(test_event("three")) + sink(test_event("four")) + subscriber.flush() + assert_eq(@fs.read_file(path + ".1").text(), event_line("four")) + assert_eq(@fs.read_file(path + ".2").text(), event_line("three")) + assert_true(!@fs.exists(path + ".3")) + }) + }) +} + +///| +#cfg(target="native") +async test "gzip compresses rotated files" { + @async.with_timeout(1000, () => { + with_temp_log(path => { + let expected = event_line("compressed") + let subscriber = @file.file_subscriber( + path, + max_size_bytes=1, + max_files=1, + gzip=true, + max_batch=1, + ) + let sink = subscriber.subscriber() + sink(test_event("compressed")) + subscriber.flush() + assert_true(@fs.exists(path + ".1.gz")) + assert_true(!@fs.exists(path + ".1")) + let compressed = @fs.open( + path + ".1.gz", + mode=@fs.Mode::ReadOnly, + create_mode=@fs.CreateMode::OpenExisting, + ) + defer compressed.close() + assert_eq(@gzip.Decoder(compressed).read_all().text(), expected) + }) + }) +} + +///| +#cfg(target="native") +async test "bounded batches drain bursts and overflow counts drops" { + @async.with_timeout(1000, () => { + @async.with_task_group(group => { + let dir = @fs.tmpdir(prefix="moontrace-file") + group.add_defer(() => { + @async.protect_from_cancel(() => @fs.rmdir(dir, recursive=true)) + }) + let path = dir + "/events.log" + let subscriber = @file.file_subscriber( + path, + max_size_bytes=100000, + max_files=1, + max_batch=3, + queue_capacity=16, + ) + group.spawn_bg(() => subscriber.run()) + @async.sleep(0) + let sink = subscriber.subscriber() + let messages = ["m0", "m1", "m2", "m3", "m4", "m5", "m6"] + messages.each(fn(message) { sink(test_event(message)) }) + subscriber.flush() + assert_eq(@fs.read_file(path).text(), lines(messages)) + assert_eq(subscriber.written(), 7) + assert_eq(subscriber.dropped(), 0) + subscriber.shutdown() + + let overflow_path = dir + "/overflow.log" + let overflow = @file.file_subscriber( + overflow_path, + max_size_bytes=100000, + max_files=1, + max_batch=8, + queue_capacity=2, + ) + let overflow_sink = overflow.subscriber() + overflow_sink(test_event("keep-one")) + overflow_sink(test_event("keep-two")) + overflow_sink(test_event("drop-one")) + overflow_sink(test_event("drop-two")) + overflow.flush() + assert_eq(overflow.dropped(), 2) + assert_eq(overflow.written(), 2) + assert_eq( + @fs.read_file(overflow_path).text(), + lines(["keep-one", "keep-two"]), + ) + }) + }) +} + +///| +#cfg(target="native") +async test "shutdown without worker drains queued lines and returns" { + @async.with_timeout(1000, () => { + with_temp_log(path => { + let subscriber = @file.file_subscriber(path, max_batch=2) + let sink = subscriber.subscriber() + sink(test_event("shutdown-no-worker")) + subscriber.shutdown() + assert_eq(@fs.read_file(path).text(), lines(["shutdown-no-worker"])) + assert_eq(subscriber.written(), 1) + }) + }) +} + +///| +#cfg(target="native") +async test "flush after stopped worker returns without spinning" { + @async.with_timeout(1000, () => { + @async.with_task_group(group => { + let dir = @fs.tmpdir(prefix="moontrace-file") + group.add_defer(() => { + @async.protect_from_cancel(() => @fs.rmdir(dir, recursive=true)) + }) + let subscriber = @file.file_subscriber(dir, max_batch=1) + let sink = subscriber.subscriber() + sink(test_event("lost-to-failed-worker")) + let worker = group.spawn(allow_failure=true, () => subscriber.run()) + try { + worker.wait() + assert_true(false) + } catch { + _ => () + } + try @async.with_timeout(200, () => subscriber.flush()) catch { + @async.TimeoutError => assert_true(false) + _ => () + } noraise { + _ => assert_true(false) + } + }) + }) +} + +///| +#cfg(target="native") +async test "shutdown flushes queued lines and drops future events" { + @async.with_timeout(1000, () => { + @async.with_task_group(group => { + let dir = @fs.tmpdir(prefix="moontrace-file") + group.add_defer(() => { + @async.protect_from_cancel(() => @fs.rmdir(dir, recursive=true)) + }) + let path = dir + "/events.log" + let subscriber = @file.file_subscriber( + path, + max_batch=2, + queue_capacity=8, + ) + group.spawn_bg(() => subscriber.run()) + @async.sleep(0) + let sink = subscriber.subscriber() + sink(test_event("queued-one")) + sink(test_event("queued-two")) + subscriber.shutdown() + assert_eq(@fs.read_file(path).text(), lines(["queued-one", "queued-two"])) + let dropped_before = subscriber.dropped() + sink(test_event("after-shutdown")) + assert_eq(subscriber.dropped(), dropped_before + 1) + assert_eq(subscriber.written(), 2) + assert_eq(@fs.read_file(path).text(), lines(["queued-one", "queued-two"])) + }) + }) +} diff --git a/src/file/moon.pkg b/src/file/moon.pkg new file mode 100644 index 0000000..3105a7a --- /dev/null +++ b/src/file/moon.pkg @@ -0,0 +1,10 @@ +import { + "brickfrog/moontrace", + "moonbitlang/async", + "moonbitlang/async/aqueue", + "moonbitlang/async/fs", + "moonbitlang/async/gzip", + "moonbitlang/async/io", +} + +warnings = "-unused_package" diff --git a/src/file/pkg.generated.mbti b/src/file/pkg.generated.mbti new file mode 100644 index 0000000..5321d48 --- /dev/null +++ b/src/file/pkg.generated.mbti @@ -0,0 +1,37 @@ +// Generated using `moon info`, DON'T EDIT IT +package "brickfrog/moontrace/file" + +import { + "brickfrog/moontrace", + "moonbitlang/core/debug", +} + +// Values +pub fn file_subscriber(String, max_size_bytes? : Int, max_files? : Int, gzip? : Bool, max_batch? : Int, queue_capacity? : Int) -> FileSubscriber + +// Errors + +// Types and methods +type FileSubscriber +pub fn FileSubscriber::dropped(Self) -> Int +pub async fn FileSubscriber::flush(Self) -> Unit +pub fn FileSubscriber::new(FileSubscriberConfig) -> Self +pub async fn FileSubscriber::run(Self) -> Unit +pub async fn FileSubscriber::shutdown(Self) -> Unit +pub fn FileSubscriber::subscriber(Self) -> (@moontrace.Event) -> Unit +pub fn FileSubscriber::written(Self) -> Int + +pub(all) struct FileSubscriberConfig { + path : String + max_size_bytes : Int + max_files : Int + gzip : Bool + max_batch : Int + queue_capacity : Int +} derive(Compare, Eq, @debug.Debug) +pub fn FileSubscriberConfig::new(String, max_size_bytes? : Int, max_files? : Int, gzip? : Bool, max_batch? : Int, queue_capacity? : Int) -> Self + +// Type aliases + +// Traits +