Logging

ghchronicle logs to standard error, and the log block sets the level, the format and an optional rotating file.

log:
  level: info # debug, info, warn, error
  format: text # text or json
  file: /var/log/ghchronicle/ghchronicle.log
  max_bytes: 67108864
  keep: 5

The keys

Key	Default	Meaning
`level`	`info`	`debug`, `info`, `warn` or `error`; anything else behaves as `info`
`format`	`text`	`text` for a human, `json` for a shipper; anything else is `text`
`file`	none	A rotating file as well as standard error
`max_bytes`	`67108864`	Rotate at 64 MiB. Anything not positive falls back to the default
`keep`	`5`	How many rotated files to keep. Anything not positive falls back to the default

Both, never instead

A configured file does not replace standard error, it is written in addition to it. Under systemd the journal is where anyone looks first, and a log file that silently took the journal’s place would be a trap: journalctl -u ghchronicle would go quiet and the obvious conclusion would be that the service had stopped.

Rotation is by size with numbered suffixes, so retention is a count rather than a date and two rotations in the same second cannot collide. The size counter is read from the file at start-up, so a restart does not reset it and let the file grow without bound.

What the log says on a good day

Taken from the author’s service on 2026-09-27, a start and the lines of its sweeps:

level=INFO msg="ghchronicle running" tick=15m0s tick_from="shortest cadence"
level=INFO msg="cache file read" file=/var/lib/ghchronicle/state-cache.bin written=2026-09-27T15:27:41+02:00 answers=1170 runs=672 refusals=100 page_sizes=54 age=1s
level=INFO msg="repositories discovered" count=37 archived_aside=17
level=INFO msg="slow families due together take turns" starting=planning waiting=settings,traffic
level=INFO msg=written sink=influxdb family=repo points=934 unchanged=1955
level=INFO msg="nothing moved since the window, repositories left unread" family=commits repos=34
level=INFO msg=written sink=influxdb family=commits points=17 unchanged=0
level=INFO msg="rate budget" bucket=core remaining=4477 limit=5000
level=INFO msg="points already written and not sent again" sink=influxdb skipped=54511
level=INFO msg="sweep finished"

The first two come once, when the process starts: the tick the loop wakes at, and what the cache beside the state file gave back. The list of repositories is rebuilt once an hour, and archived_aside counts the archived ones set aside, which still get their two rows. In written, points is what reached the store and unchanged what the write ledger left out because the store already holds it; see what the written line counts. A family of six hours or more that is due behind another one is named under waiting, see the slow families take turns, and commits, issues and issueevents say how many repositories they left unread because nothing moved in them, see asking first what moved.

A family that is not due yet simply does not appear. That is normal, and it is the first thing to check when a measurement seems to be missing: with a twelve-hour cadence, half a day of logs can legitimately never mention stats.

The two lines worth an alert

rate limit reserve reached means a family was skipped to protect the budget.

level=WARN msg="rate limit reserve reached, family skipped" family=artifacts

Once is fine. Every sweep means the cadences are too fast for the number of repositories.

family failed everywhere, not marking it as run means every repository failed for one family.

level=WARN msg="family failed everywhere, not marking it as run" family=security

The family is deliberately not marked as done, so it is retried at the next cadence rather than being treated as complete. That is the line that separates “a feature is off on one repository” from “the token lost a scope”.

Debugging

log:
  level: debug

Debug adds these lines, and no more:

loaded the written-points ledger, with how many points it came back with, when the service starts;
no cache file yet, the first pass of each family pays in full, at the first start with a state file;
not every store keeps a write ledger, when the runs the cache file remembers are listed again because a store keeps no ledger or the run ends with its sweep;
no targets.user, account-wide families skipped;
sink dropped old entries, with how many a sink left out for being older than its horizon, the only way to see that a push was trimmed rather than rejected;
card-only sweep, the state file is left as it was;
cache file saved, with how many answers and runs it holds and how long it took;
migration not needed and migration applied before, at every start, for each change a store never needed or has had applied already;
migration noted: nothing is changed and migration frozen, at every start after the first, which says each at INFO;
set-aside copy forgotten, when a copy a migration set aside falls due and the state file stops naming it: the store purges it itself for one InfluxDB 3 purges on its own schedule, and the store keeps it for good, and -migrate asks the store for it for one it keeps for good.

There is no per-request log: the client in internal/ghapi carries no logger, so which endpoint was called and which answer came back 304 are not visible at any level. That includes its one retry: a REST request answered 500, 502, 503 or 504 is asked again two seconds later, silently, and so is a job log’s download from storage, so a collector failed naming one of those four has already failed twice.

Not to be confused with the job log collector

log is the tool’s own diary. every.families.joblogs is a collector: it fetches the last forty lines of every failed GitHub Actions job and turns them into points. They are unrelated settings, and the second one belongs in a log store rather than in a metrics database. See Loki.

Written and maintained by José Manuel Requena Plens

MIT licenceRelease history