[MateoLostanlen]

Replaces #392, closed by mistake (GitHub cannot reopen a PR once its branch was deleted).

What changes

• Unify logging setup across pyroengine, pyro_camera_api and pyro-predictor: only the two entrypoints configure logging, both with the same format, and verbosity is driven by a new LOG_LEVEL env var wired through docker-compose. Library modules no longer call logging.basicConfig(force=True) at import. Uvicorn lines are routed through the same formatter too, so every line in both containers shares one format.
• Cut steady state noise: a quiet inference round and a quiet patrol cycle are each one INFO summary line. Per pose and per frame detail is available at DEBUG. Detections, alerts and failures stay at INFO.
• Fix log levels: startup retries are warnings instead of errors, unexpected failures keep their traceback via logger.exception, a known down camera is reported once instead of every 30s, and every camera scoped line carries a [cam_id] prefix.
• Redact credentials from RTSP URLs and ffmpeg commands, which were logged in cleartext at INFO. Redaction happens at the logging handler, so a URL that slips through a new call site is still scrubbed.
• Replace the log grep engine healthcheck with a heartbeat file, so container liveness no longer depends on log level or message wording. The heartbeat is written on every loop pass, so offline cameras do not cause restarts. When it is older than 10 min the healthcheck kills the engine (init: true makes tini PID 1) and restart: always brings it back. This supersedes fix(compose): restart the engine when its log goes stale #419.
• Also in here: the standalone scripts in src/ get their logging output back (they relied on the basicConfig that libraries no longer call), a frame dropped during the patrol settle window is no longer counted as a capture failure, and the pyro_camera_api test suite now runs in CI.

Examples

Output below was captured by running the same script on develop and on this branch.

One quiet round, 4 poses, nothing detected (every 30s)

Before, 18 lines:

2026-07-29 22:31:58,897 | INFO: Captured image for 192.168.1.10, pose 0
2026-07-29 22:31:58,897 | INFO: Model original pred : [[0.00942827 0.5561888 0.02951318 0.6073602 0.70792276]]
2026-07-29 22:31:58,897 | INFO: pred for 192.168.1.10_0 : [[0.00942827 0.5561888 0.02951318 0.6073602 0.70792276]]
2026-07-29 22:31:58,897 | INFO: Camera '192.168.1.10_0' - No wildfire (confidence: 2.00%)
   ... same 4 lines for poses 1, 2, 3 ...
2026-07-29 22:31:58,898 | INFO: Run focus finder
2026-07-29 22:31:58,898 | INFO: Loop run under 2.34 seconds, sleeping for 27.66 seconds

After, 1 line:

2026-07-29 22:32:06,237 [INFO] pyroengine.core: Inference round: analyzed=4 failed=0 positive=0 max_confidence=0.02 duration=0.0s

The prediction array was printed twice per pose, once by vision.py and once by engine.py. Run focus finder printed on every round even though focus_finder() only acts once an hour.

A real detection stays visible

before: 2026-07-29 22:31:59,919 | INFO: Model original pred : [[0.00942827 0.5561888 0.02951318 0.6073602 0.70792276]]
        2026-07-29 22:31:59,919 | INFO: pred for 192.168.1.10_0 : [[0.00942827 ...]]
        2026-07-29 22:31:59,919 | INFO: Camera '192.168.1.10_0' - Wildfire detected (confidence: 35.40%)

after:  2026-07-29 22:32:06,434 [INFO] pyro_predictor.predictor: [192.168.1.10_0] Wildfire detected (confidence: 35.40%)

Format now carries the logger name

before: 2026-07-29 22:31:58,896 | INFO: Waiting for Pyro Camera API
after:  2026-07-29 22:32:06,236 [INFO] pyroengine.core: Waiting for Pyro Camera API at http://fake

The camera API used a different format in the same deployment. Both now share one format, and engine logs go to stdout explicitly instead of stderr.

Uvicorn kept its own handlers with propagate=False, so its lines had no timestamp at all:

before: INFO:     Started server process [18204]
        INFO:     Application startup complete.
        INFO:     127.0.0.1:65188 - "GET /ping HTTP/1.1" 200 OK

after:  2026-07-30 06:44:39,485 [INFO] uvicorn.error: Started server process [19498]
        2026-07-30 06:44:39,486 [INFO] uvicorn.error: Application startup complete.

The per request access line is now DEBUG only, since the engine polls the capture endpoints every few seconds. At LOG_LEVEL=DEBUG it comes back, in the shared format:

2026-07-30 06:44:48,464 [INFO] uvicorn.access: 127.0.0.1:65251 - "GET /ping HTTP/1.1" 200

Levels

before: | ERROR: API not ready: Connection refused          (normal boot path, every 10s)
after:  [WARNING] pyroengine.core: Camera API not ready yet, retrying in 10s: Connection refused

before: | ERROR: Camera 'x' - unable to upload cache
        | ERROR: ConnectionError(...)                       (two lines, no traceback)
after:  [ERROR] pyroengine.engine: [x] Unable to upload cache: ConnectionError(...)

Patrol cycle, 4 poses every 30s

before: [192.168.1.10] Moving to pose 0         (x4)
        [192.168.1.10] Stored image for pose 0  (x4)
        [192.168.1.10] Returned to pose 0
        [192.168.1.10] Restored manual focus to 520

after:  [192.168.1.10] Patrol cycle: captured=4/4 failed=0 duration=12.3s

Credentials

before: [INFO] start pipeline, rtsp rtsp://admin:S3cret!@192.168.1.10:554/h264, srt ...
after:  [INFO] Start pipeline, rtsp rtsp://***:***@192.168.1.10:554/h264, srt ...

Nothing is lost at LOG_LEVEL=DEBUG

[DEBUG] pyroengine.core: [192.168.1.10_0] Captured image from cam1
[DEBUG] pyroengine.core: [192.168.1.10_1] Captured image from cam1
[DEBUG] pyroengine.core: [192.168.1.10_2] Captured image from cam1
[DEBUG] pyroengine.core: [192.168.1.10_3] Captured image from cam1
[INFO]  pyroengine.core: Inference round: analyzed=4 failed=0 positive=0 max_confidence=0.02 duration=0.0s

Deployment note

The engine healthcheck no longer greps engine.log. It now checks that the heartbeat file (option --heartbeat-file, default data/heartbeat) was touched in the last 10 minutes. The file is refreshed on every loop pass, through the night sleep and during autofocus on a responsive camera. When it is older than 10 min the healthcheck kills every process but PID 1 (tini, via init: true) so restart: always brings the engine back. No file yet means the engine is still starting, which never triggers a kill. start_period moves from 20s to 300s to cover the model download and the first loop.

[codecov]

Codecov Report

❌ Patch coverage is 58.94737% with 39 lines in your changes missing coverage. Please review.
✅ Project coverage is 81.05%. Comparing base (a2604d4) to head (e6a40c5).

Files with missing lines	Patch %	Lines
pyroengine/core.py	60.00%	26 Missing ⚠️
pyroengine/logs.py	0.00%	11 Missing ⚠️
pyroengine/engine.py	89.47%	2 Missing ⚠️

Additional details and impacted files

@@             Coverage Diff             @@
##           develop     #417      +/-   ##
===========================================
+ Coverage    80.51%   81.05%   +0.53%     
===========================================
  Files            6        7       +1     
  Lines          847      871      +24     
===========================================
+ Hits           682      706      +24     
  Misses         165      165              

Flag	Coverage Δ
unittests	81.05% <58.94%> (+0.53%)	⬆️

Flags with carried forward coverage won't be shown. Click here to find out more.

☔ View full report in Codecov by Harness.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:

• ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.
• 📦 JS Bundle Analysis: Save yourself from yourself by tracking and limiting bundle sizes in JS merges.

[fe51]

Reviewed — LGTM overall. The logging refactor is clean, well tested, and easy to roll back (revert the merge commit).

One thing worth fixing before or right after merge:

• Healthcheck vs. active streams (pyroengine/core.py:194): inference_loop returns early while a stream is active, and the heartbeat is only touched on a successful capture (or during the night sleep). Previously the healthcheck was a grep on engine.log, which never went stale. With the new 10 min freshness check, a stream longer than 10 min makes the engine report unhealthy even though it is intentionally paused. This only matters if something restarts unhealthy containers (e.g. autoheal), but a one-line self._write_heartbeat() before that early return would avoid it.

Minor, non-blocking:

• The secrets redaction filter doesn't cover exception tracebacks (exc_text), so a URL with credentials inside a requests error could still be logged by the new logger.exception calls.
• The _SENSITIVE_KV regex is broad (u=, p=, user=, auth=), so values like p=0.35 get masked in unrelated log lines.
• getMessage() in the filter is unguarded; a malformed logger.info("x %s %s", a) from any logger would raise instead of being swallowed by logging.

[MateoLostanlen]

Hi @fe51 Thanks for the review!

Rebased on develop and addressed your points:

• Healthcheck vs. active streams: the heartbeat is now written before the early return when a stream is active, so a long stream no longer marks the engine unhealthy (0bd0218).
• Redaction filter (93e0395):
  • tracebacks are scrubbed too, so a URL with credentials inside a requests error is masked
  • u= / p= are only masked in the MediaMTX streamid form (after : or ,), so p=0.35 stays readable. I kept user= and auth= broad on purpose, masking a username by mistake is harmless
  • a malformed record no longer raises in the filter, logging reports it as usual

Each case has a test.