Skip to content

Logging performance, resilience, and serialization overhaul; TRACE + masking added

Choose a tag to compare

released this 02 Oct 17:18
· 34 commits to working since this release

This release focuses on three primary goals: make high-volume trace/default logging safe to run in production, prevent logging faults from crashing host applications, and simplify serialization and logger internals for cross-platform use. Work in this release addresses long-standing performance problems (including the 60x slowdown when trace-level logging was enabled), closes resource-leak and flood-control correctness issues, and introduces new features for observability and data protection (TRACE as a distinct level and configurable masking). The release also centralizes version management in CI/tooling and updates developer tooling and tests to match the new behavior.

New Features

  • TRACE log level

    • TRACE is now a distinct severity and is wired into the public LogLevel API (adds explicit trace-level handling for extremely verbose logs). (see: implementation notes in src and tests; referenced in milestone issues #48)
  • Configurable masking utilities and middleware

    • Adds masking support for sensitive data (emails, SSNs, JWTs, private keys, base64 blobs) behind a config flag so masking is opt-in.
    • Masking is documented and disabled by default because it can be costly; configuration controlled via masking helpers and middleware. (implements issue #67)
    • Files: new/updated masking tests and referenced documentation in code/tests.

Improvements

  • Async-first logging with safe fallbacks

    • Writes are scheduled asynchronously (setImmediate or setTimeout fallback) to avoid blocking the event loop on synchronous console I/O.
    • If async scheduling fails, code falls back to a synchronous write with guarded error handling.
    • Impact: prevents the event loop blocking observed under heavy trace logging.
    • Files: createLogger changes in src/Logger.ts; examples/performance-test.ts demonstrates behavior.
  • Native-first JSON serialization with robust fallback

    • stringifyJSON now attempts native JSON.stringify first for performance, and only uses a custom recursive implementation when native stringify fails (e.g. circular references).
    • Custom serializer (stringifyJSONCustom) includes defensive per-property handling and safe fallback strings so serialization failures do not throw or crash logging.
    • Impact: typical object serialization is 10–50x faster; circular/edge cases still serialize safely.
    • Files: src/utils.ts (reworked stringifyJSON and stringifyJSONCustom), tests updated in tests/utils.test.ts.
  • Early-exit log level check

    • Log-level filtering is performed before payload formatting, flood-control checks and expensive work.
    • Impact: avoids unnecessary CPU and memory work when logs are filtered out.
    • Files: src/Logger.ts (write early-exit optimization).
  • Trace/default buffering for high-volume debug logs

    • Buffering introduced for high-volume, low-severity messages (TRACE, DEFAULT, DEBUG) with configurable sizes and flush intervals to reduce I/O operations.
    • Files: PERFORMANCE_IMPROVEMENTS.md documents defaults; examples/performance-test.ts exercise buffering.
  • Consolidated error handling and resilience

    • Introduced layered protections and fallbacks so logging errors are isolated and logged with a clear prefix ([Fjell Logging]) rather than propagating to the host application.
    • Resource cleanup (timers, buffers, flood control) guarded with try/catch to avoid leaks or crashes during shutdown.
    • Files: ERROR_HANDLING.md added and createLogger/io functions updated to log internal errors safely.

Bug Fixes

  • FloodControl cleanup / memory-leak fixes (#49)

    • Fixes to FloodControl hashing/cleanup to avoid potential growth/leaks when aggressive suppression is used.
    • Tests adjusted to validate FloodControl behavior and cleanup.
  • Prevent logging from crashing application

    • Multiple defensive changes ensure writer.write calls, scheduled flushes, and serialization do not throw out of band; internal errors are logged to console.error and operations continue.
    • Files: src/Logger.ts, src/utils.ts, tests updated to reflect resilient behavior.
  • JSON and serialization edge-case fixes

    • Fixed cases that previously caused JSON.stringify or the custom serializer to throw; now handled deterministically with safe placeholder output when necessary.
    • Tests added/updated to cover circular references, problematic getters, and large objects in stringifyJSON and safeInspect.

Documentation

  • New performance and error-handling documents

    • PERFORMANCE_IMPROVEMENTS.md: describes the 60x slowdown root causes and the mitigations (async writes, native-first serialization, early exits, buffering). Includes recommended config knobs (TRACE_BUFFER_SIZE, TRACE_FLUSH_INTERVAL) and instructions for running the example performance test.
    • ERROR_HANDLING.md: documents the layered error-protection strategy, error message prefixes ([Fjell Logging]), and testing performed to validate resilience.
  • README.md updated

    • Points to the new performance doc and highlights the core runtime optimizations (async logging, native JSON, trace buffering).

Developer Experience and Tooling Changes

  • Centralized version management

    • Explicit "version" fields have been removed from package.json so release tooling controls package versioning and avoids conflicting entries in the manifest and lockfile.
    • Impact: local package.json no longer contains a hard-coded version; release automation must provide the version at publish time.
    • Files: package.json edits and related lockfile normalization (multiple commits). See commit messages for rationale.
  • ESLint devDependency bump and config normalization

    • Bumped @fjell/eslint-config devDependency to ^1.1.25 and adjusted eslint.config.mjs export shape (normalized to an array). This change aligns local lint setup with the updated devDependency.
  • CI/workflow simplification

    • The npm publish workflow was simplified (build job removed; publish job runs standalone with checkout). Review CI workflows if the previous multi-job expectations are relied upon.

Tests, Examples, and Build

  • Examples/performance-test.ts added

    • A performance test for high-volume trace/default logging demonstrating flush rates and serialization comparisons. Instructions to build/run included in PERFORMANCE_IMPROVEMENTS.md.
  • Tests updated for new API behavior and resilience

    • Tests now pass explicit asyncLogging:false when synchronous behavior is required for deterministic tests.
    • Many tests updated to reflect new stringifyJSON/safeInspect outputs and resilient behavior when serialization or scheduling fails.
    • Files: tests/*, tests/utils.test.ts, tests/Logger.test.ts, tests/masking.test.ts updated accordingly.

Breaking Changes and Compatibility Notes

  • package.json no longer contains a version field

    • Release/publish tooling must supply the package version. This is intentional to centralize version management but requires downstream releases to use the repository's release automation.
  • createLogger signature simplified

    • Constructor/api usage sites were adjusted; tests now pass an explicit asyncLogging flag where synchronous writes are needed for test determinism.
    • If code invoked createLogger with the prior extended signature, update call sites to the simplified signature in src/logging.ts and other consumers.
  • Masking performance

    • Masking is available but disabled by default. Enabling masking may add CPU overhead for high-volume logs; the docs explain trade-offs and recommended usage.

Files and components changed (high-level)

  • New docs/examples

    • PERFORMANCE_IMPROVEMENTS.md (new)
    • ERROR_HANDLING.md (new)
    • examples/performance-test.ts (new)
  • Core code

    • src/utils.ts (major rework: native-first stringifyJSON, stringifyJSONCustom, safeInspect, safeFormat)
    • src/Logger.ts (simplified constructor, early-exit log level check, guarded writer calls)
    • src/logging.ts (entrypoint adjusted to construct loggers consistently; tests control async mode)
  • Config / metadata

    • package.json (version fields removed; devDependency bump)
    • eslint.config.mjs (export shape normalized)
    • package-lock.json and lockfile entries updated to match devDependency updates
  • Tests

    • tests/* updated to match serialization and logger API changes (Logger.test.ts, utils.test.ts, masking.test.ts)

Resolved milestone issues referenced in commits

  • #48 — TRACE level and log-level handling

    • TRACE added as its own level and wired into exports and tests.
  • #49 — FloodControl leak and cleanup

    • FloodControl cleanup behavior corrected to avoid memory growth and to ensure deterministic suppression counts; tests updated accordingly.
  • #67 — Masking feature

    • Masking implemented as configurable middleware with docs and tests; disabled by default and documented performance considerations.

Operational recommendations

  • If tests or consumers relied on synchronous logging behavior, update test harnesses or pass asyncLogging:false when creating loggers.
  • Review release/publish tooling to ensure package versioning is provided at publish time (package.json no longer contains an explicit version). CI/CD processes must continue to populate the release version.
  • If masking is required in production, measure CPU/throughput impact before enabling for very high-volume traces; the performance doc contains benchmarks and suggested buffer/flush values.
  • Monitor these runtime metrics after upgrade: event-loop lag, log processing time, memory usage, and I/O ops/sec (the performance doc lists specific metrics to track).

If any integration or downstream code relies on the previous createLogger signature, or on package.json containing a version, update those areas to match the simplified API and new versioning approach. For serialization and edge-case handling, existing code should see fewer crashes from logging operations and significantly better performance when trace/default logging is enabled.