|
| 1 | +# Log Service |
| 2 | + |
| 3 | +## Description |
| 4 | + |
| 5 | +The log service is a **singleton** that provides structured logging to the rest of the system. It has two modes of operation: |
| 6 | + |
| 7 | +- **Pre-connection** — log calls write to the console (via `rxilog`) only, with no bus activity. |
| 8 | +- **Post-connection** — once `log_service.start()` has wired up a bus connection, every log call also publishes a structured message to `{'logs', <level>}` on the bus so that other services (e.g. a log checker or an uploader) can subscribe to them. |
| 9 | + |
| 10 | +Because it is a singleton registered in `package.loaded`, any module that calls `require 'services.log'` gets the same instance regardless of load order or scope boundaries. |
| 11 | + |
| 12 | +## Levels |
| 13 | + |
| 14 | +The service exposes one method per log level, matching the levels defined in `rxilog`: |
| 15 | + |
| 16 | +| Method | Bus topic | Severity | |
| 17 | +|--------|-----------|----------| |
| 18 | +| `log.trace(...)` | `{'logs', 'trace'}` | lowest | |
| 19 | +| `log.debug(...)` | `{'logs', 'debug'}` | | |
| 20 | +| `log.info(...)` | `{'logs', 'info'}` | | |
| 21 | +| `log.warn(...)` | `{'logs', 'warn'}` | | |
| 22 | +| `log.error(...)` | `{'logs', 'error'}` | | |
| 23 | +| `log.fatal(...)` | `{'logs', 'fatal'}` | highest | |
| 24 | + |
| 25 | +Each method always writes to the console. Publishing to the bus only happens when `log_service._conn` is set (i.e. after `start()` has run). |
| 26 | + |
| 27 | +## Bus Messages |
| 28 | + |
| 29 | +### Log entry (non-retained) |
| 30 | + |
| 31 | +Topic: `{'logs', <level>}` |
| 32 | + |
| 33 | +Published for every log call made while the service is running. |
| 34 | + |
| 35 | +```lua |
| 36 | +{ |
| 37 | + message = "[LEVEL HH:MM:SS] file.lua:line message text", |
| 38 | + timestamp = <number>, -- realtime clock (seconds since epoch) |
| 39 | +} |
| 40 | +``` |
| 41 | + |
| 42 | +- `message` is the pre-formatted string produced by `rxilog.format_log_message`, including level, timestamp, source location, and message text. |
| 43 | +- `timestamp` is the wall-clock time from `fibers.utils.time.realtime()`. |
| 44 | + |
| 45 | +### Service status (retained) |
| 46 | + |
| 47 | +Topic: `{'svc', <name>, 'status'}` |
| 48 | + |
| 49 | +```lua |
| 50 | +{ state = 'starting' | 'running' | 'stopped', ts = <monotonic number> } |
| 51 | +``` |
| 52 | + |
| 53 | +Published at each lifecycle transition. `name` defaults to `'log'` but can be overridden via `opts.name`. |
| 54 | + |
| 55 | +## Initialisation |
| 56 | + |
| 57 | +`log_service.start(conn, opts)` follows the standard service lifecycle: |
| 58 | + |
| 59 | +1. Retains `state = 'starting'` on `{'svc', name, 'status'}`. |
| 60 | +2. Registers a `finally` block that clears `_conn` and retains `state = 'stopped'` when the scope exits. |
| 61 | +3. Sets `log_service._conn = conn` so subsequent log calls publish to the bus. |
| 62 | +4. Retains `state = 'running'`. |
| 63 | +5. Emits its own first log entry: `log.trace("Log service started")`. |
| 64 | +6. Blocks in a `sleep(math.huge)` loop — the service runs until its scope is cancelled. |
| 65 | + |
| 66 | +## Service Flow |
| 67 | + |
| 68 | +```mermaid |
| 69 | +flowchart TD |
| 70 | + St[Start] --> A(Retain status: starting) |
| 71 | + A --> B(Register finally block) |
| 72 | + B --> C(Set _conn = conn) |
| 73 | + C --> D(Retain status: running) |
| 74 | + D --> E(log.trace: Log service started) |
| 75 | + E --> F{sleep forever} |
| 76 | + F -->|scope cancelled| G(finally: clear _conn) |
| 77 | + G --> H(Retain status: stopped) |
| 78 | + H --> I[End] |
| 79 | +``` |
| 80 | + |
| 81 | +## Architecture |
| 82 | + |
| 83 | +- The service owns a single long-lived sleep and relies entirely on scope cancellation for shutdown — there is no explicit shutdown message. |
| 84 | +- The singleton pattern (`package.loaded["services.log"] = log_service`) means the connection state is global. Only one instance of `start()` should be running at a time. |
| 85 | +- Log calls are synchronous: `_conn:publish` is called inline before returning to the caller. There is no batching or queue. |
| 86 | +- Source location is captured at call time via `debug.getinfo(2, "Sl")`, so the `message` field always reflects the actual call site, not an internal log helper. |
| 87 | +- The `finally` block guarantees `_conn` is cleared even if the scope fails rather than being cancelled cleanly. |
| 88 | + |
| 89 | +## Tests |
| 90 | + |
| 91 | +Tests live in `tests/test_log.lua` and are run with: |
| 92 | + |
| 93 | +```sh |
| 94 | +cd tests && luajit test_log.lua |
| 95 | +``` |
| 96 | + |
| 97 | +The entry point wraps `luaunit.LuaUnit.run()` inside `fibers.run()` so every test method can call `perform()` directly. |
| 98 | + |
| 99 | +### TestLogSingleton |
| 100 | + |
| 101 | +Unit tests that do not require the scheduler. |
| 102 | + |
| 103 | +| Test | What it checks | |
| 104 | +|------|----------------| |
| 105 | +| `test_has_all_log_level_methods` | Singleton exposes a callable method for every `rxilog` level | |
| 106 | +| `test_log_without_conn_does_not_error` | Calling log methods with `_conn = nil` does not raise | |
| 107 | +| `test_singleton_identity` | `require 'services.log'` twice returns the exact same table | |
| 108 | + |
| 109 | +### TestLogBusPublish |
| 110 | + |
| 111 | +Integration tests that wire `_conn` directly without running the full service. Each test operates inside the fiber scheduler and calls `perform()` to receive from the bus. |
| 112 | + |
| 113 | +| Test | What it checks | |
| 114 | +|------|----------------| |
| 115 | +| `test_info_publishes_to_bus` | A single `log.info()` produces exactly one `{'logs','info'}` message | |
| 116 | +| `test_all_levels_publish_correct_topic` | Each level method publishes on its matching `{'logs', <level>}` topic | |
| 117 | +| `test_message_payload_fields` | Payload contains a formatted `message` string and a positive `timestamp` number | |
| 118 | +| `test_no_publish_without_connection` | No bus messages are produced when `_conn` is `nil` | |
| 119 | + |
| 120 | +### TestLogServiceLifecycle |
| 121 | + |
| 122 | +Full-service tests that start the log service in a child scope via `start_log()` and observe its behaviour over its lifetime. |
| 123 | + |
| 124 | +| Test | What it checks | |
| 125 | +|------|----------------| |
| 126 | +| `test_publishes_starting_running_stopped` | Service retains `'starting'`, `'running'`, and `'stopped'` states in order | |
| 127 | +| `test_service_publishes_log_entries` | Log calls made after the service reaches `'running'` are delivered to the bus | |
| 128 | +| `test_conn_cleared_after_stop` | `log._conn` is `nil` after the service scope is cancelled | |
0 commit comments