Watcher emits no audit trail; 24 releases silently skipped 2026-08-19/20

[oalders]

Olaf apologizes in advance for using a bot to do the research. Caveat Emptor.

Summary

MetaCPAN::Script::Watcher emits no record of what it observed or acted on. When it skips a release, there is no way to determine why. On 2026-08-20, 24 consecutive releases were skipped and the logs contain nothing about them.

Logging state

Line references against master @ a4fd17a (the commit deployed on bm-mc-02).

Watcher log calls:

Line	Level	Message
L52	log_debug	Loading RECENT-$segment.json
L80	log_debug	Includes latest release
L99	log_debug	Archive $archive does not yet exist
L114	log_debug	Running @run
L104	log_error	Aborting, archive ... not available after 15 seconds

log4perl_prod.conf line 1:

log4perl.rootLogger=WARN, OUTPUT, SYSLOG

Every log_debug above is discarded. The only surviving statements are the two log_error calls (L31, L104).

Observed result on bm-mc-02:

• journalctl -u metacpan-watcher --since "2026-08-19 12:00" --until "2026-08-20 13:00" returns only systemd start/stop lines — no application output.
• metacpan-api/var/log/metacpan.log is 0 bytes; the seven rotated copies are 14 bytes each (empty bzip2).
• No metacpan_api syslog entries originate from the watcher during the window.

There is therefore no record of which RECENT segments were read, what high-water mark was used, which releases were considered, or which were enqueued.

Incident, 2026-08-19/20 (bm-mc-02)

rsync to the mirror was broken from 2026-08-19 until 03:27:46 BST on 2026-08-20, when the backlog landed in a single backfill (tarball ctimes).

The watcher indexes via --queue (L110-113), so every release it acts on leaves a minion_jobs row. index_release rows are retained back to 2024-11-04 on this host, so absence is meaningful.

minion_jobs rows created 2026-08-20 03:00–05:00 BST:

5455337 | 2026-08-20 03:28:01 | ["/home/metacpan/CPAN/authors/id/I/IN/INGY/Alien-YAMLScript-0.2.30.tar.gz"]
5455342 | 2026-08-20 03:28:33 | ["/home/metacpan/CPAN/authors/id/I/IN/INGY/YAMLScript-0.2.30.tar.gz"]
5455347 | 2026-08-20 03:28:56 | ["/home/metacpan/CPAN/authors/id/I/IN/INGY/YAMLScript-0.2.30.tar.gz"]
5455352 | 2026-08-20 03:29:31 | ["/home/metacpan/CPAN/authors/id/I/IN/INGY/YAMLScript-0.2.30.tar.gz"]

No other release was enqueued. select count(*) from minion_jobs where args::text like '%/URI-%' returns 0.

Releases from that backfill, ordered by upload date (release.date in ES):

2026-08-19T12:03:04  Feersum-1.506_55                             missed
2026-08-19T12:55:08  Google-Ads-GoogleAds-Client-34.0.0           missed
2026-08-19T13:11:36  HTTP-API-Client-1.25                         missed
2026-08-19T14:19:41  Util-H2O-More-0.4.4                          missed
2026-08-19T15:12:48  Util-H2O-More-0.4.5                          missed
2026-08-19T15:20:38  BarefootJS-0.31.9                            missed
2026-08-19T15:20:49  BarefootJS-Backend-Xslate-0.31.9             missed
2026-08-19T15:21:00  Mojolicious-Plugin-BarefootJS-0.31.9         missed
2026-08-19T16:20:18  HTTP-API-Client-1.26                         missed
2026-08-19T17:03:16  Dist-Zilla-Plugin-LicenseFile-0.001          missed
2026-08-19T17:08:33  Punk-OpenTelemetry-0.02                      missed
2026-08-19T17:32:51  Dist-Zilla-PluginBundle-Author-GETTY-0.320   missed
2026-08-19T19:38:45  URI-5.36                                     missed
2026-08-19T20:13:00  MojoX-MojoDbWrap-0.005001-TRIAL              missed
2026-08-19T20:27:03  PDL-IO-Matlab-0.007                          missed
2026-08-19T20:31:06  PDL-DSP-Fir-0.008                            missed
2026-08-19T20:33:59  WebService-GarminConnect-1.1.3               missed
2026-08-19T21:20:47  Device-Chip-From-Sensirion-0.03              missed
2026-08-19T22:46:34  X11-GUITest-0.29                             missed
2026-08-19T22:50:34  Crypt-Age-0.002                              missed
2026-08-19T23:31:05  PDL-Complex-2.012                            missed
2026-08-19T23:35:07  Archive-Extract-0.90                         missed
2026-08-20T00:05:38  Filename-KeyValue-0.005                      missed
2026-08-20T00:43:57  Lingua-Text-0.09                             missed
------------------------------------------------------------------ cutoff
2026-08-20T01:44:31  Alien-YAMLScript-0.2.30                      enqueued 03:28:01
2026-08-20T01:44:42  YAMLScript-0.2.30                            enqueued 03:28:33

24 consecutive releases skipped, no inversions, sharp cutoff between 00:43:57 and 01:44:31. All 26 tarballs were on disk at 03:27:46, before the first enqueue at 03:28:01.

The 24 missed releases were indexed manually on 2026-08-20. Before that, 19 distributions had no release at status: latest (#1496).

Why the cause is not stated here

The cutoff correlates with upload time, not with disk arrival time, which is consistent with the high-water mark in changes(): latest_release() (L87-92) takes the newest indexed release date, and the segment scan terminates once an entry predates it (L75, L79). That mechanism is code-verifiable; that it fired here is not, because nothing was logged.

Hand-tracing changes() against the RECENT segment layout does not unambiguously reproduce the observed cutoff, so this is not asserted as the root cause.

Requested change

Log at a level that survives rootLogger=WARN, or lower the watcher's threshold, so that a future occurrence is diagnosable:

1. The high-water mark returned by latest_release() on each poll.
2. Each RECENT segment loaded, and the segment at which the scan terminated.
3. Each candidate release, and whether it was enqueued or skipped — with the reason.

Environment

• bm-mc-02, metacpan-api @ a4fd17a
• metacpan-watcher.service is stopped and started every hour at :55 throughout the window (systemd journal). Noted for interpreting the journal; not claimed as a contributing factor.

---

_{Filed by Claude (model claude-opus-5, Anthropic) via Claude Code, at the request of @oalders. Code references, log state, Minion rows and timestamps above were verified against metacpan-api a4fd17a and the running host.}