enhanced logging implementation

[Trojan-254]

Logging System Integration for HTeaPot

This pull request introduces a comprehensive logging system for the HTeaPot web server. The system provides structured, component-based logging with performance metrics, millisecond-level precision, and robust concurrency all implemented without any external dependencies.

---

Key Features

• Log Levels
  Five distinct log levels: DEBUG, INFO, WARN, ERROR, and FATAL, with built-in filtering capabilities.

• Component-Based Logging
  Enables creation of multiple loggers for different components, sharing the same output stream but maintaining component-specific labels.

• Millisecond Precision
  Timestamps include millisecond resolution, providing more precise insights into system behavior.

• Performance Metrics
  Logging includes timing data for request handling, cache hits/misses, and proxy operations.

• ISO-8601 Compatible Timestamps
  All timestamps follow the format YYYY-MM-DD HH:MM:SS.mmm for clarity and standardization.

• Thread-Safe Implementation
  Concurrency is handled safely using Arc and channels, ensuring high throughput without locking the main thread.

• Adaptive Buffer Sizing
  Logging buffers scale dynamically based on runtime activity and log volume.

---

Implementation Details

Logger Structure

The logger uses a two-tiered architecture:

• LoggerCore
  Manages the shared channel and the background worker thread, wrapped in an Arc to enable shared ownership.

• Logger
  A lightweight front-end with component context that delegates log writing to LoggerCore.

This modular design allows each subsystem to have a specialized logger, improving log clarity while maintaining resource efficiency and thread safety.

---

Log Message Format

All logs follow this format:

YYYY-MM-DD HH:MM:SS.mmm [LEVEL] [component] Message content

Example:

2025-04-10 07:50:01.135 [INFO] [main] Server started at http://localhost:8081/
2025-04-10 07:50:22.892 [WARN] [http] Path /favicon.ico does not exist

---

Performance Considerations

• Batched Writing
  Log messages are buffered and written in batches to reduce I/O overhead.

• Adaptive Buffer Sizing
  The system dynamically resizes internal buffers depending on log traffic.

• Timeout-Based Flushing
  All logs are flushed at least once per second, ensuring timely delivery.

• Non-Blocking Design
  Logging never blocks the main application thread. Backpressure is handled internally.

---

Usage in HTeaPot

The main application now uses distinct loggers for each core component:

• main: General server lifecycle logs
• http: HTTP server request handling
• proxy: DNS and proxy communication
• cache: Caching system activity

This separation enhances traceability and sets the foundation for future fine-grained log filtering.

---

Performance Metrics

The logger also collects and reports timing data for:

• Full request processing time
• Time spent in cache lookup
• Time taken to proxy DNS requests

These metrics are helpful for profiling server behavior and identifying performance bottlenecks.

---

Migration Notes

All existing logger.msg() calls have been migrated to structured logging methods like logger.info(), logger.warn(), etc. The update preserves compatibility with previous log configurations.

---

Future Improvements

Possible enhancements under consideration:

• File rotation and archival
• Per-component log level configuration
• Customizable log output formats
• Support for structured output (e.g., JSON logs)
• In-memory circular buffer for viewing recent logs via API or UI

---

Sample Output

Finished `dev` profile [unoptimized + debuginfo] target(s) in 2.28s  
Running `target/debug/hteapot ./config.toml`
2025-04-10 09:05:47.445 [INFO] [main] Server started at http://localhost:8081  
2025-04-10 09:07:46.402 [INFO] [http] Request GET /  
2025-04-10 09:07:46.403 [WARN] [http] Path / does not exist  
2025-04-10 09:07:47.294 [INFO] [http] Request GET /  
2025-04-10 09:07:47.294 [WARN] [http] Path / does not exist

[Az107]

LGTM
Great work!

[Az107]

Sorry for reopening this but the logger introduces some latency.
Maybe we could reduce the number of calls to it ?
Also having a config entry to manage the minimum level , or only having debug logs when the build is not release would be great.

[Trojan-254]

No worries at all, really appreciate you bringing it up!

Yeah good call on the logger latency. I was thinking might be worth trying a few things:
Maybe simplifying the timestamp generation, it’s doing some heavy lifting right now.
Adding a config entry to control log level like you said. Could default to INFO in release and DEBUG in debug.
Also wondering if we can optimize the message formatting and buffer re-use to reduce allocations.

[Az107]

That sounds really good!
Let’s do that. Also, I know the design of my logger is probably introducing most of the latency, maybe the calls to SPMC?
If you could check that, it would be great.
Thanks

[Trojan-254]

Great let me work on it, I'll also dig into how much time send() is actually taking in the current setup. If it's a noticeable source of latency, I’ll explore optimizing around the standard library's channel without pulling in any external crates. This project is pretty unique and lean, so I want to keep it tight and dependency-free. I’ll get back to you with what I find!