implement a logger we can reuse everywhere #133
Labels
No labels
prio_critical
prio_low
type_bug
type_contact
type_issue
type_lead
type_question
type_story
type_task
No milestone
No project
No assignees
1 participant
Notifications
Due date
No due date set.
Dependencies
No dependencies set.
Reference
lhumina_code/hero_lib#133
Loading…
Add table
Add a link
Reference in a new issue
No description provided.
Delete branch "%!s()"
Deleting a branch is permanent. Although the deleted branch may continue to exist for a short time before it actually gets removed, it CANNOT be undone in most cases. Continue?
in /Volumes/T7/code0/hero_lib/crates/core/src/logger
Hero Logs — Fast Append-Only Logging Spec
Goal
Create a very fast, simple, human-readable logging system.
No database.
No Tantivy.
No indexer for now.
Just reliable local log capture.
Log directory
Each source has maximum 3 dotted parts:
Mapped to:
Examples:
If source has more than 3 parts, give error
Log entry
Line format
One log entry is one line.
Use tab-separated fields:
Example:
srcis not written inside the line because it is represented by the file path.Field rules
epochUnix timestamp in seconds.
Example:
contextidContext identifier.
job_idJob identifier.
loglevelSingle
u8value.Suggested mapping:
tagsComma-separated list.
Rules:
Example:
Empty tags:
contentHuman-readable message.
Rules:
Sanitizing:
Writer architecture
Do not write directly from the caller thread.
Use:
Performance setting
Recommended defaults:
For higher safety:
For maximum speed:
File handling
Maintain an LRU cache of open writers:
Open files with:
Create parent directories automatically.
Rotation
Simple size-based rotation.
Default:
Rotation format:
On rotation:
Overflow behavior
Default: never block critical app logic forever.
Recommended modes:
Default:
Meaning:
At minimum, maintain counters:
Shutdown
On graceful shutdown:
Minimal API
Final recommended setting
Hero Logs — Implementation Spec for Issue #133
Objective
Implement an append-only file logger at
crates/core/src/logger/exposing aLogSinktrait whose default implementation maps a dotted source path (e.g.router.http.proxy) to a path under~/hero/var/logs/and writes one TSV-formatted line per entry. The writer runs on a dedicatedstd::thread, owns a bounded MPSC channel, an LRU cache ofBufWriter<File>handles, and performs size-based rotation, periodic flushing, and graceful shutdown. The module must build cleanly insideherolib_corewith no new optional features and no tokio dependency.Requirements
~/hero/var/logs/withsrcdotted-path mapping to file path. Max 3 dotted parts:router->~/hero/var/logs/router.logrouter.http->~/hero/var/logs/router/http.logrouter.http.proxy->~/hero/var/logs/router/http/proxy.logLogEntryfields:contextid: u32,job_id: u32,src: String,tags: Vec<String>,epoch: u32,loglevel: u8,content: String.epoch\tcontextid\tjob_id\tloglevel\ttags\tcontent\n.srcis NOT in the line.epochis u32 unix seconds.contextid == 0means default/admin/system.job_id == 0means not job-related.loglevelmapping:0=debug, 10=info, 20=notice, 30=warning, 40=critical, 254=error, 255=reserved.key:valuepairs, no spaces/tabs/newlines, emptyVecserializes as-.\n->[BR],\rremoved or[BR].LogEntry, sanitizes + formats, sends pre-rendered record to a bounded channel; a single writer thread groups by path, writes through aBufWriter<File>(append + create), flushes periodically.channel_size=100_000,writer_buffer_per_file=256 KiB,flush_interval=100 ms,max_open_files=128,fsync=false.OpenOptions { create: true, append: true }; auto-create parent directories.max_file_size=256 MiB,max_rotated_files=8. On rotation: flush, close, rename chain, reopen.DropNewest,Block,DropDebugFirst(defaultDropDebugFirst). Counters:dropped_debug,dropped_info,dropped_error.LoggerConfig { root, channel_size, flush_interval_ms, writer_buffer_size, max_open_files, max_file_size, max_rotated_files }LogEntry { contextid, job_id, src, tags, epoch, loglevel, content }trait LogSink { fn log(&self, entry: LogEntry); fn flush(&self); fn shutdown(&self); }Files to Modify / Create
crates/core/src/logger/mod.rscrates/core/src/logger/errors.rsLoggerErrorenum (thiserror) andResult<T>alias.crates/core/src/logger/level.rsLogLevelenum +as_u8/from_u8with the 0/10/20/30/40/254/255 mapping.crates/core/src/logger/config.rsLoggerConfig+ defaults; helper to resolve~/hero/var/logs/;OverflowModeenum.crates/core/src/logger/entry.rsLogEntry,epoch_now(), sanitization,format_line,src_to_path.crates/core/src/logger/writer.rscrates/core/src/logger/sink.rsLogSinktrait +Logger(default file-backed implementation).crates/core/src/lib.rspub mod logger;and a one-line rustdoc bullet.crates/core/tests/logger.rsNo new mandatory Cargo deps required.
Implementation Plan
Step 1 - Module skeleton and public surface stubs
Files:
errors.rs,level.rs,config.rs,mod.rs,lib.rs.Adds
LoggerError,Result,LogLevel,OverflowMode,LoggerConfigwith documented defaults; declares submodules;pub mod logger;inlib.rs.Dependencies: none.
Step 2 -
LogEntry, sanitization, formatting, src->path mappingFiles:
entry.rs,mod.rs.Adds
LogEntry,epoch_now(),sanitize_content,sanitize_tag,format_tags,format_line,src_to_path. Inline unit tests for all.Dependencies: Step 1.
Step 3 - Writer thread (LRU cache, rotation, flush)
Files:
writer.rs.Adds
WriterMsgenum andWriterStatewith the LRU cache, rotation chain, periodic flush viarecv_timeout, optional fsync on shutdown, shutdown ack. Errors are logged viaeprintln!but never panic the thread. Inline unit tests usingtempfile::TempDir.Dependencies: Steps 1-2.
Step 4 -
LogSinktrait +LoggerimplementationFiles:
sink.rs,mod.rs.Adds
LogSinktrait (Send + Sync),Loggerstruct holding boundedSyncSender,JoinHandle, atomic counters, shutdown flag. Implements three overflow modes; constructorsLogger::new(cfg)andLogger::with_overflow(cfg, mode)returningArc<Self>.Dropcallsshutdown().Dependencies: Steps 1-3.
Step 5 - Integration tests
Files:
crates/core/tests/logger.rs.Tests: 1-part / 2-part / 3-part path routing, >3 parts -> dropped_error counter, rotation chain limit, content sanitization, idempotent shutdown, tag formatting and
-empty case.Dependencies: Steps 1-4.
Step 6 - Module documentation
Files:
mod.rs,lib.rs.Module-level rustdoc with defaults table, mapping rules, and a
no_runexample. Bullet for the logger in the crate-level doc.Dependencies: Steps 1-4.
Acceptance Criteria
pub mod logger;incrates/core/src/lib.rs.LogSink,Logger,LogEntry,LoggerConfig,LoggerError,Result,LogLevel,OverflowMode.LogEntryhas the seven specified fields with the exact types.LoggerConfigdefaults match the issue:channel_size=100_000,flush_interval_ms=100,writer_buffer_size=256*1024,max_open_files=128,max_file_size=256*1024*1024,max_rotated_files=8,fsync=false, defaultroot=~/hero/var/logs.srcmapping: 1/2/3 parts produce the documented paths; >3 parts is rejected.epoch\tcontextid\tjob_id\tloglevel\ttags\tcontent\n;srcdoes not appear in the line.tagsrenders as-; non-empty tags joined with,.\nand lone\r->[BR].std::threadnamedhero-logger; no tokio dependency added.max_open_files; evicted writers are flushed before drop.create(true).append(true); parent dirs auto-created.name.log.1...name.log.{max_rotated_files}; oldest dropped.DropDebugFirst.dropped_debug,dropped_info,dropped_errorcounters readable fromLogger.shutdown()is idempotent, drains pending, flushes, optionally fsyncs, joins.cargo build -p herolib_coreandcargo test -p herolib_coresucceed.Notes
std::threadover tokio: the issue says "writer thread" andherolib_coredoes not depend on tokio in default features. Usingstd::threadplusstd::sync::mpsc::sync_channelavoids forcing an async runtime on every caller.mpsc::sync_channel(N)provides the back-pressure semantics required byBlockandDropNewest.DropDebugFirst: with a single queue, we cannot reorder already-queued items. Chosen semantics: when the channel is full, drop incoming debug records (incrementingdropped_debug); block on incoming non-debug records. Biases the queue toward higher severity over time.epochauto-fill: ifentry.epoch == 0, substituteepoch_now()at format time.0is unambiguous as a sentinel.key:valuevalidation.max_open_files=128.std::fs::renameis best-effort. A crash mid-rotation can leave a gap. Acceptable for a non-critical log.dirs::home_dir().join("hero").join("var").join("logs").Hero Logs - Implementation Spec for Issue #133 (Revised)
Objective
Implement an append-only file logger at
crates/core/src/logger/exposing aLogSinktrait whose default implementation maps a dotted source path (e.g.router.http.proxy) to a path under~/hero/var/logs/and writes one TSV-formatted line per entry. The writer runs on a dedicatedstd::thread, owns a bounded MPSC channel, an LRU cache ofBufWriter<File>handles, and performs size-based rotation, periodic flushing, and graceful shutdown. The module must build cleanly insideherolib_corewith no new optional features and no tokio dependency.Requirements
~/hero/var/logs/withsrcdotted-path mapping to file path. Max 3 dotted parts:router->~/hero/var/logs/router.logrouter.http->~/hero/var/logs/router/http.logrouter.http.proxy->~/hero/var/logs/router/http/proxy.logLogEntryfields:contextid: u32,src: String,tags: Vec<String>,epoch: u32,loglevel: u8,content: String. (Nojob_id- callers put it insrcif they want it.)epoch\tcontextid\tloglevel\ttags\tcontent\n.srcis NOT in the line;job_idno longer exists.epochis u32 unix seconds.contextid == 0means default/admin/system.loglevelmapping:0=debug, 10=info, 20=notice, 30=warning, 40=critical, 254=error, 255=reserved.key:valuepairs, no spaces/tabs/newlines, emptyVecserializes as-.\n->[BR],\rremoved or[BR].LogEntry, sanitizes + formats, sends pre-rendered record to a bounded channel; a single writer thread groups by path, writes through aBufWriter<File>(append + create), flushes periodically.channel_size=100_000,writer_buffer_per_file=256 KiB,flush_interval=100 ms,max_open_files=128,fsync=false.OpenOptions { create: true, append: true }; auto-create parent directories.max_file_size=256 MiB,max_rotated_files=8. On rotation: flush, close, rename chain, reopen.DropNewest,Block,DropDebugFirst(defaultDropDebugFirst). Counters:dropped_debug,dropped_info,dropped_error.LoggerConfig { root, channel_size, flush_interval_ms, writer_buffer_size, max_open_files, max_file_size, max_rotated_files }(plusfsync: bool)LogEntry { contextid, src, tags, epoch, loglevel, content }trait LogSink { fn log(&self, entry: LogEntry); fn flush(&self); fn shutdown(&self); }Files to Modify / Create
crates/core/src/logger/mod.rscrates/core/src/logger/errors.rsLoggerErrorenum (thiserror) andResult<T>alias.crates/core/src/logger/level.rsLogLevelenum +as_u8/from_u8for the 0/10/20/30/40/254/255 mapping.crates/core/src/logger/config.rsLoggerConfig+ defaults; default-root resolver;OverflowModeenum.crates/core/src/logger/entry.rsLogEntry,epoch_now(), sanitization,format_line(5 columns),src_to_path.crates/core/src/logger/writer.rscrates/core/src/logger/sink.rsLogSinktrait +Logger(default file-backed implementation).crates/core/src/lib.rspub mod logger;and a one-line rustdoc bullet.crates/core/tests/logger.rsNo new mandatory Cargo deps.
Implementation Plan
Step 1 - Module skeleton and public surface stubs
Files:
errors.rs,level.rs,config.rs,mod.rs,lib.rs.Adds
LoggerError,Result,LogLevel,OverflowMode,LoggerConfigwith documented defaults; declares submodules;pub mod logger;inlib.rs.Dependencies: none.
Step 2 -
LogEntry, sanitization, formatting, src->path mappingFiles:
entry.rs,mod.rs.Adds
LogEntry(six fields, no job_id),epoch_now(),sanitize_content,sanitize_tag,format_tags,format_lineproducing exactly five tab-separated columns + newline,src_to_path. Inline unit tests for all.Dependencies: Step 1.
Step 3 - Writer thread (LRU cache, rotation, flush)
Files:
writer.rs.Adds
WriterMsgandWriterStatewith the LRU cache, rotation chain, periodic flush viarecv_timeout, optional fsync on shutdown, shutdown ack. Errors logged viaeprintln!, never panic. Inline unit tests usingtempfile::TempDir.Dependencies: Steps 1-2.
Step 4 -
LogSinktrait +LoggerimplementationFiles:
sink.rs,mod.rs.Adds
LogSink: Send + Synctrait,Loggerstruct with boundedSyncSender,JoinHandle, atomic counters, shutdown flag. Three overflow modes;Logger::new(cfg)/Logger::with_overflow(cfg, mode)returningArc<Self>.Dropcallsshutdown().Dependencies: Steps 1-3.
Step 5 - Integration tests
Files:
crates/core/tests/logger.rs.Tests: 1/2/3-part path routing, >3 parts -> dropped_error, rotation chain limit, content sanitization, idempotent shutdown, tag formatting and
-empty case, exact 5-column TSV line.Dependencies: Steps 1-4.
Step 6 - Module documentation
Files:
mod.rs,lib.rs.Module-level rustdoc with defaults table, mapping rules, and a
no_runexample. Bullet for the logger in the crate-level doc.Dependencies: Steps 1-4.
Acceptance Criteria
pub mod logger;incrates/core/src/lib.rs.LogSink,Logger,LogEntry,LoggerConfig,LoggerError,Result,LogLevel,OverflowMode.LogEntryhas exactly:contextid: u32,src: String,tags: Vec<String>,epoch: u32,loglevel: u8,content: String. Nojob_id.LoggerConfigdefaults match the issue:channel_size=100_000,flush_interval_ms=100,writer_buffer_size=256*1024,max_open_files=128,max_file_size=256*1024*1024,max_rotated_files=8,fsync=false, defaultroot=~/hero/var/logs.srcmapping: 1/2/3 parts produce the documented paths; >3 parts is rejected.epoch\tcontextid\tloglevel\ttags\tcontent\n(five columns);srcdoes not appear in the line.tagsrenders as-; non-empty tags joined with,.\nand lone\r->[BR].std::threadnamedhero-logger; no tokio dependency added.max_open_files; evicted writers are flushed before drop.create(true).append(true); parent dirs auto-created.name.log.1...name.log.{max_rotated_files}; oldest dropped.DropDebugFirst.dropped_debug,dropped_info,dropped_errorcounters readable fromLogger.shutdown()is idempotent, drains pending, flushes, optionally fsyncs, joins.cargo build -p herolib_coreandcargo test -p herolib_coresucceed.Notes
job_idremoved:srcis freeform (still 1-3 dotted parts). Callers may encodeservice.job.<id>themselves; the logger does not interpret it.std::threadover tokio: the issue says "writer thread" andherolib_coredoes not depend on tokio in default features.mpsc::sync_channel(N)provides back-pressure forBlockandDropNewest.DropDebugFirst: when the channel is full, drop incoming debug records (incrementingdropped_debug); block on incoming non-debug records. Biases the queue toward higher severity over time.epochauto-fill: ifentry.epoch == 0, substituteepoch_now()at format time.0is unambiguous as a sentinel.key:valuestructural validation.std::fs::renameis best-effort; a crash mid-rotation can leave a gap. Acceptable.dirs::home_dir().join("hero").join("var").join("logs").Test Results
cargo test -p herolib_coretests/logger.rsintegrationNew logger unit tests (15 in
crates/core/src/logger/)level::round_trip_known_valueslevel::unknown_maps_to_reservedentry::src_one_partentry::src_two_partsentry::src_three_partsentry::src_too_deepentry::src_empty_or_dottedentry::src_rejects_path_separatorsentry::sanitize_content_replaces_tabs_and_newlinesentry::empty_tags_render_dashentry::multi_tags_join_with_commaentry::tags_are_sanitizedentry::format_line_shape_five_columnsentry::format_line_autofills_epochwriter::opens_and_appendswriter::lru_evictionwriter::rotation_chainwriter::shutdown_flushes_and_acksIntegration tests (
crates/core/tests/logger.rs)one_part_src_writes_root_log- exact TSV output verified byte-for-bytethree_part_src_creates_nested_dirs- parent directory auto-creationtoo_deep_src_increments_dropped_error- >3 dotted parts rejected, counter incrementedrotation_chain_caps_at_max_rotated_files-.log.1/.log.2/.log.3exist,.log.4does notcontent_sanitization_produces_single_line- tabs/CRLF/LF/CR all collapsed correctlyshutdown_is_idempotent_and_blocks_new_logs- second shutdown is a no-op; post-shutdown log bumpsdropped_errortag_formatting_and_empty_dash- empty tags render-, internal whitespace and commas sanitizeddrop_newest_drops_under_pressure- bounded channel under burst correctly incrementsdropped_debugImplementation Summary
Append-only file logger landed at
crates/core/src/logger/. Public surface re-exported fromherolib_core::logger.Files created
crates/core/src/logger/mod.rs- module root, public re-exports, module-level docs with mapping table and TSV format spec.crates/core/src/logger/errors.rs-LoggerError(thiserror) +Result<T>alias. Variants:InvalidSrc,SrcTooDeep { src, parts },Io,ChannelClosed,AlreadyShutdown.crates/core/src/logger/level.rs-LogLevelenum andLOG_LEVEL_*constants for 0/10/20/30/40/254/255.crates/core/src/logger/config.rs-LoggerConfigwith documented defaults (channel_size=100_000, flush_interval_ms=100, writer_buffer_size=256 KiB, max_open_files=128, max_file_size=256 MiB, max_rotated_files=8, fsync=false),default_root()resolving to~/hero/var/logs, andOverflowMode(DropNewest,Block,DropDebugFirst; defaultDropDebugFirst).crates/core/src/logger/entry.rs-LogEntry(six fields:contextid,src,tags,epoch,loglevel,content),epoch_now(),sanitize_content,sanitize_tag,format_tags,format_line(5-column TSV),src_to_pathenforcing the 1/2/3-part rule.crates/core/src/logger/writer.rs- dedicatedstd::threadwriter. LRU cache (HashMap<PathBuf, BufWriter<File>>+VecDeque<PathBuf>), per-file size tracking, periodic flush viarecv_timeout, size-based rotation chain, drain-on-shutdown, optional fsync.crates/core/src/logger/sink.rs-LogSink: Send + Synctrait and theLoggerstruct. Boundedmpsc::sync_channelfor back-pressure, atomic counters (dropped_debug,dropped_info,dropped_error), CAS-guarded idempotentshutdown(),Dropcallsshutdown().File modified
crates/core/src/lib.rs-pub mod logger;+ a one-line entry in the crate-level doc.Public API
Wire format
Five tab-separated columns, ending with
\n:srcis encoded by the file path and is never inside the line.job_idis not part of the model - callers encode it insidesrcif they want it.Acceptance criteria
pub mod logger;incrates/core/src/lib.rs.LogSink,Logger,LogEntry,LoggerConfig,LoggerError,Result,LogLevel,OverflowMode.LogEntryhas exactly the six specified fields with the exact types.LoggerConfigdefaults match the issue.srcmapping: 1/2/3 parts produce the documented paths; >3 parts is rejected.epoch\tcontextid\tloglevel\ttags\tcontent\n;srcdoes not appear in the line.tagsrenders as-; non-empty tags joined with,.\n,\r, and\r\n->[BR].std::threadnamedhero-logger; no tokio dependency added.max_open_files; evicted writers are flushed.create(true).append(true); parent dirs auto-created.name.log.1...name.log.{max_rotated_files}; oldest dropped.DropDebugFirst.dropped_debug,dropped_info,dropped_errorcounters readable fromLogger.shutdown()is idempotent, drains pending records, flushes, optionally fsyncs, joins.cargo build -p herolib_coreandcargo test -p herolib_coresucceed.Notes / decisions
job_idremoved per follow-up clarification on this issue.srcremains 1-3 dotted parts; callers encode any job identifier they want there.thiserror,serde,dirs(target-gated), andstdcover everything;tempfile(already a dev-dep) is used in the writer's inline tests and the integration test.DropDebugFirstsemantics with a single bounded queue: when the channel is full, drop incomingloglevel == 0records and bumpdropped_debug; non-debug records fall back toBlockso they are never silently lost.epoch == 0is treated as a sentinel and replaced withepoch_now()at format time. Real Unix timestamps in the system are always far above zero.std::fs::renameper slot - a crash mid-rotation can leave a numbering gap, which is acceptable for non-critical logs.dirs::home_dir().join("hero/var/logs")on native targets and/tmp/hero/var/logsonwasm32.