# Logging timps writes to stderr and, with `general.syslog = 1`, to syslog. Two knobs decide what you see: a global level, and a per-module debug switch. ## The two knobs ``` general.loglevel = 2 # 0=err 1=warn 2=info 3=debug general.debug_modules = # comma-separated module names, case-insensitive ``` The filter is one line (`src/log.c`, `log_printf`): ```c if (level > g_level && !mod_is_debug(module)) return; ``` A message passes if its level is at or below `loglevel`, **or** if its module is named in `debug_modules` — a listed module is raised to DEBUG outright, so *all* of its levels pass regardless of the global level. So `debug_modules` opens one module's full output without making every other module verbose — which is the point: `loglevel = 3` on a camera that also runs the ISP layer produces far more than anyone wants to read. (Until 2026-08-20 only the listed module's DEBUG lines passed the filter, so `loglevel = 1` plus `debug_modules = daynight` showed DAYNIGHT's DEBUG lines while hiding its INFO lines — nobody expected that.) `debug_modules` takes at most 8 names — a 9th name, or one too long to be a module tag, is rejected with a WARN rather than silently dropped — and is live-applicable over `POST /control` — no restart, no config file edit: ``` curl -s -X POST http://:8880/control -H "X-Timps-Token: $T" \ -d '{"general":{"debug_modules":"daynight"}}' ``` ## What each level is for | level | contains | example | |---|---|---| | 0 `err` | the subsystem cannot do its job and stops trying: a socket that cannot bind, an encoder channel that never comes up | `bind/listen on 9000 failed` | | 1 `warn` | something is wrong or degraded, and a human may need to act | `IMP_AI_EnableAec failed - continuing without echo cancellation` | | 2 `info` | **events**: state changed, a decision was taken, a subsystem came up | `switching to day (probe confirmed)`, `ISP up, sensor=sc4336p fps=30` | | 3 `debug` | **measurements**: per-tick values, per-probe detail, per-frame notes | `probe: r=1.05 lit=3350 dark=3520 hr=199 verdict=day` | The dividing line between 2 and 3 is *event versus measurement*. An end user wants to know that the camera switched to day mode and why; they do not want the exposure index of every probe that decided not to switch. Level 2 is the shipped default and is meant to stay readable on a camera that runs for months. ## Modules Names as they appear in the log and as `debug_modules` accepts them. The four numeric columns are the count of distinct `LOGE`/`LOGW`/`LOGI`/`LOGD` call sites in that module's source file — **how many different messages that module can produce at each level**, not how often they fire at runtime. A module with `warn=29` has 29 different situations it can WARN about, not 29 warnings a minute; a chatty module like `DAYNIGHT` (15 debug call sites) can still be perfectly quiet if none of its probes are unusual. Read the column as "surface area", and read `err=0` as "this module never gives up on its own — whatever it reports at worst degrades or falls back". The counts are per-module-tag, i.e. per `MOD` `#define` in that source file, not per file — `log.c` here is the logger's own module (its rejected-`debug_modules`-name diagnostics), not a count of every `LOG*(` call in the codebase. Recounted against `main` on every `CHANGELOG.md` release; if you're reading this next to a checkout, `grep -oE 'LOG[EWID]\(' src/ | sort | uniq -c` reproduces a row. | module | source | err | warn | info | debug | what its debug output adds | |---|---|---:|---:|---:|---:|---| | `DAYNIGHT` | `daynight.c` | — | — | — | — | **since v1.10.1** (the counts are of the earlier engine): every look, `look (): lit … dark … bar … -> check\|night`; since v1.11.0 `why` can be `color`, and `-> locked (N s)` when a lockout after failed checks holds the check back, with `colour moved N %` / `colour back to the scene before the look` | | `HAL_ING` | `hal/hal_ingenic.c` | 44 | 77 | 48 | 10 | encoder/framesource internals, polling and teardown detail, the sensor-fps requested-vs-held readback (`sensor fps: requested N, driver holds n/d, set rc=R`) | | `CTRL` | `control.c` | 0 | 4 | 3 | 5 | request/field handling on `/control` | | `OSD` | `hal/imp_osd.c` | 4 | 8 | 6 | 3 | overlay placement and region updates | | `RTSP` | `rtsp/rtsp.c` | 4 | 8 | 5 | 1 | per-drop queue-overflow detail, dropped P-frames, IDR re-requests (the *first* keyframe drop of a session is a WARN) | | `HTTP` | `mp4/httpd.c` | 3 | 13 | 10 | 5 | same for the fMP4/MJPEG side, including adaptive freeze (first keyframe drop per client is a WARN) | | `HUB` | `hub.c` | 0 | 1 | 0 | 2 | fan-out subscribe/unsubscribe at debug, plus the one always-on line: a per-(consumer kind, stream) queue-overflow summary, at most once per 60 s — the counter behind it is `/control` `queue_drops` | | `CLIENT` | `clients.c` | 0 | 1 | 2 | 0 | — (one line per streaming client: `+ : chn=N agent=""` on connect, `- : after Ns, N bytes` on disconnect. Since v1.9.28 control bytes and non-ASCII in the User-Agent are logged as `?`, so a client cannot put terminal escapes into a log viewer. The WebUI's own `/events` connections use the same two lines at DEBUG, so `debug_modules = client` shows them too; a full client table is the WARN) | | `REC` | `record.c` | 11 | 9 | 6 | 2 | segment and writer detail, plus the overflow re-gate (which keyframe the segment resumed on, and whether the eviction was video or audio-only); the *first* queue drop per subscription is a WARN | | `TLS` | `tls.c` | 5 | 3 | 1 | 3 | handshakes that are ordinary peer noise (EOF, close_notify, reset); the interesting ones are WARN | | `CONFIG` | `config.c` | 1 | 29 | 4 | 0 | — | | `SRT` | `srt.c` | 7 | 10 | 3 | 2 | the 10-second key=value `stats:` line (RTT, loss, retransmits, send rate) while a receiver is connected, plus queue-overflow detail and IDR re-requests (the *first* keyframe drop of a session is a WARN) | | `spk` | `rtsp/speaker.c` | 0 | 8 | 7 | 0 | — | | `MAIN` | `main.c` | 8 | 5 | 8 | 0 | — | | `LIBIMP` | `hal/libimp_check.c` | 2 | 2 | 0 | 0 | — (start-up only: the libimp does not fit the build, exit 78/79; see [Building](Building.md#which-libimp-a-binary-needs---check-libs)) | | `MOTION` | `hal/imp_motion.c` | 9 | 8 | 5 | 0 | — | | `TL` | `timelapse.c` | 4 | 1 | 5 | 0 | — | | `HAL_SIM` | `hal/hal_sim.c` | 4 | 2 | 4 | 0 | — | | `TRACE` | `trace.c` | 0 | 4 | 0 | 0 | — (deliberately WARN-only: its output is gated by its own `general.trace*` switch) | | `bc` | `rtsp/backchannel.c` | 0 | 1 | 3 | 0 | — | | `AAC` | `codec/aac.c` | 0 | 1 | 0 | 0 | — | | `LOG` | `log.c` | 0 | 2 | 0 | 0 | — (the logger itself: rejected `debug_modules` names) | Names are matched case-insensitively, so `daynight` and `DAYNIGHT` are the same; they are written above exactly as they appear in the log. Note `CTRL` and `REC` — not `CONTROL` or `RECORD`. A name too long to be a module tag, or a 9th name, is rejected with a WARN. A *well-formed* name that matches nothing (a typo of the right length) is still accepted silently and does nothing — it looks identical to a module that simply has no debug output. Modules with no debug lines are listed so that `debug_modules=motion` visibly does nothing rather than looking broken. ## Collecting day/night data The day/night measurement series lives at DEBUG. A camera that feeds a central collector therefore needs ``` general.debug_modules = daynight ``` in its `/etc/timps.conf`. Without it the automaton still works and still logs its decisions at INFO — you get the switches and the reference changes, but not the per-probe numbers the analysis scripts read. This is deliberate, but the point is *readability*, not bandwidth: at the default cadence (a look every 45 min, `heartbeat_max_s = 43200`) the demoted lines amount to a few dozen a day, and a camera that sets `debug_modules` ships exactly as many bytes as before the change. On a collector, the bulk of the day/night-related traffic is elsewhere entirely — `crond`'s once-a-minute job lines and, where `dnlog.isp_syslog` is on, the per-minute `dnisp` CSV row from `timps-dn-isp-log` — neither of which this change touches. What the change buys is a level 2 that stays readable on installations that never asked for per-probe measurements. The same convention applies to SRT's 10-second `stats:` line: it is a measurement and lives at DEBUG — a dashboard that wants the series sets `debug_modules = srt` (or `daynight,srt`). The replay harness (`scripts/dn-replay.py`) sets `debug_modules=daynight` for every scenario: several `expect_log` patterns match lines that are now DEBUG, and the `forbid_log` checks would otherwise pass vacuously against lines the filter had already removed.