fix(logrotate): bound retention by age, and drop the dead cron.hourly move - #165
Conversation
…hourly runs
cubesys.log.default.retention is a published tuning whose help text reads "Set
log file retention policy in days", default 14, and it is the only retention
control there is: all ~40 LogRotateConf declarations in hex and cubecos pass
retention 0, WriteLogRotateConf only emits `rotate` when that is non-zero, so
every generated config inherits the global this function writes. Measured on
accept-3cc: 1 of 62 files in /etc/logrotate.d sets its own rotate.
logrotate's `rotate` is a count of GENERATIONS, not days. The two coincide only
while every log rotates exactly once a day, which stopped being true when the
logrotate timer moved to hourly: each generated config pairs `daily` with
`maxsize 128M` and rotates on whichever comes first, so a log that passes the cap
every hour kept `rotate` hours of history instead of `rotate` days. That is the
audit window, and it silently shrank by 24x for exactly the busiest logs.
So bound the window by age and leave the count as a safety net rather than the
policy: maxage carries the days promise, and rotate is sized for the worst case
the hourly timer allows -- 24 rotations a day -- so it cannot bind first. A log
that rotates once a day is unaffected; maxage removes its 15th day exactly as
rotate 14 used to.
Verified on accept-3cc against logrotate 3.18.0, as a steady-state simulation
rather than a pre-seeded directory -- logrotate never revisits generations beyond
`rotate`, so seeding more than that measures nothing. Scaled 7x (maxage 2 days,
rotate 48), starting empty and ageing every generation by one interval between
rotations:
rotating once a day rotate 2 kept 2 gens, oldest 1.0 days
rotate 48+maxage2 kept 3 gens, oldest 2.0 days
tripping maxsize hourly rotate 2 kept 2 gens, oldest 0.0 days <-- 2 hours
rotate 48+maxage2 kept 48 gens, oldest 1.9 days
Applied to the live global config on jim-1cc it renders as `rotate 336` +
`maxage 14`, logrotate parses it, and a real pass over 184 considered files exits
0 with no output. Clean CXX logrotate.o and AR libhex_sdk.a in the build jail,
with the emitted directive list in the object now daily / su root syslog /
rotate %d / maxage %d / create / include.
Reported by traviswu-bigstack in review on bigstack-oss/cubecos#1433.
Refs bigstack-oss/cubecos#1433
Signed-off-by: Jim Lin <jim.lin@bigstack.co>
Co-authored-by: Eandalf <clinah@connect.ust.hk>
Co-authored-by: Claude Opus 5 (1M context) <noreply@anthropic.com>
…stemd timer
full_rootfs_install ran
chroot $(ROOTDIR) mv /etc/cron.daily/logrotate /etc/cron.hourly/ || true
to make logrotate run hourly. RHEL and CentOS stopped shipping that cron job when
logrotate moved to a systemd timer, so on a stream9 rootfs the source path does
not exist, the mv fails, and `|| true` swallows it. Verified on a running node:
the logrotate rpm owns only
/usr/lib/systemd/system/logrotate.service
/usr/lib/systemd/system/logrotate.timer
/etc/cron.daily/logrotate is absent and /etc/cron.hourly holds nothing but
0anacron. The line above it disables crond as well, so even a successful move
would have needed something to re-enable cron before it could fire.
The intent was right and has simply been unreachable: the effective schedule on
every image built since the switch has been the packaged timer's
OnCalendar=daily, which is what made the maxsize 128M cap in every generated
config unenforceable. cubecos ships a logrotate.timer drop-in to set the hourly
schedule where it now belongs; this removes the line that looked like it was
already doing that job, so the next person reading either repo is not told two
different things.
No behaviour change on any built image -- the command has never had an effect.
Refs bigstack-oss/cubecos#1433
Signed-off-by: Jim Lin <jim.lin@bigstack.co>
Co-authored-by: Eandalf <clinah@connect.ust.hk>
Co-authored-by: Claude Opus 5 (1M context) <noreply@anthropic.com>
Picks up hex 5cfb997, the other half of the review response on this PR: - fix(logrotate): bound retention by age, so the days promise survives hourly runs -- WriteDefLogRotateConf now emits `maxage <days>` with `rotate` sized so it cannot bind first. Without it, making the timer hourly shrinks the audit window from cubesys.log.default.retention days to that many *hours* for any log that trips the maxsize cap within the hour, which is exactly the busiest ones. - build(rootfs): drop the cron.hourly logrotate move -- dead since logrotate moved to a systemd timer, and the reason the hourly schedule this PR sets was believed to already be in place. Also carries 5740f8e, a dependabot harden-runner bump already on hex develop. Pending as bigstack-oss/hex#165; both repos fast-forward merge, so this SHA stays valid once that lands. Refs #1192 Refs #1433 Signed-off-by: Jim Lin <jim.lin@bigstack.co> Co-authored-by: Eandalf <clinah@connect.ust.hk> Co-authored-by: Claude Opus 5 (1M context) <noreply@anthropic.com>
SekiXu
left a comment
There was a problem hiding this comment.
rotate retention * 24 + maxage retention is the right shape, and the steady-state
simulation is the right way to have measured it — seeding beyond rotate would have proved
nothing. One thing to fold in while this is open, because it is in the lines this PR moves.
hex_trim_syslog cannot remove anything
Two separate mismatches, one of them from this PR.
.gz is never matched. The loop tests [ -e /var/log/messages.$I ]. At postrotate time
— before compression, as the comment added in cb13101 says — the directory holds
messages, an uncompressed messages.1, and messages.2.gz onward: the global conf has no
dateext, and WriteLogRotateConf always emits compress. So the only unsuffixed
generation that ever exists is messages.1, which cb13101 correctly stops it from
touching. That fix is right; what it leaves is a loop with nothing it can match.
Ran both revisions straight out of git with only /var/log rewritten to a scratch dir, so
after the substitution the sole difference between the files is the loop bound. Directory
seeded to the postrotate state above, LIMIT set six times under total:
removed total (512B blocks)
d500f450 messages.1 6000 -> 5600 still 5.6x over budget
5cfb9978 nothing 6000 -> 6000 rc=0
fea23e1 made this reachable by shipping the script for the first time, and
config_syslogd.cpp:117 makes it the only enforcement SYSLOG_DISK_PERC has.
This is where my own #163 measurement landed and I did not follow it through: "the matchable
set is byte-for-byte identical with and without delaycompress" was already this fact — both
cases leave exactly messages.1 matchable — one step short of the conclusion. Mine to have
caught before approving #163.
I=14 no longer matches the retention. It mirrors the old global rotate 14; b5ba5d8
raises that to retention * 24, rendering as rotate 336. Even with .gz matching fixed
the scan would cover generations 2..14 of up to 336 — and a log that reaches 336 generations
is exactly the busy log the budget exists for.
Both want the same edit: remove messages.$I and messages.$I.gz, and take the upper bound
from the retention value WriteDefLogRotateConf already has rather than a literal.
Picks up hex 5cfb997, the other half of the review response on this PR: - fix(logrotate): bound retention by age, so the days promise survives hourly runs -- WriteDefLogRotateConf now emits `maxage <days>` with `rotate` sized so it cannot bind first. Without it, making the timer hourly shrinks the audit window from cubesys.log.default.retention days to that many *hours* for any log that trips the maxsize cap within the hour, which is exactly the busiest ones. - build(rootfs): drop the cron.hourly logrotate move -- dead since logrotate moved to a systemd timer, and the reason the hourly schedule this PR sets was believed to already be in place. Also carries 5740f8e, a dependabot harden-runner bump already on hex develop. Pending as bigstack-oss/hex#165; both repos fast-forward merge, so this SHA stays valid once that lands. Refs #1192 Refs #1433 Signed-off-by: Jim Lin <jim.lin@bigstack.co> Co-authored-by: Eandalf <clinah@connect.ust.hk> Co-authored-by: Claude Opus 5 (1M context) <noreply@anthropic.com>
…ove something hex_trim_syslog has never been able to remove a compressed generation, and since cb13101 it has not been able to remove anything at all. Two mismatches with the directory it runs against, one of them mine: - It tested `-e /var/log/messages.$I` only. WriteLogRotateConf always emits `compress` and the global conf sets no `dateext`, so at postrotate time the directory holds `messages`, a still-uncompressed `messages.1`, and `messages.2.gz` onward. The only unsuffixed generation that ever exists is .1 -- which cb13101 correctly stopped it from touching, leaving a loop with nothing it could match. - `I=14` mirrored the old global `rotate 14`. b5ba5d8 raises that to `retention * 24`, rendering as 336, so even with .gz matching the scan would have covered generations 2..14 of up to 336 -- and a log that reaches 336 generations is exactly the busy log the budget exists for. Take the generation list from the filesystem instead of counting down from a literal. That removes the coupling that has now drifted twice, and it is immune to whatever `rotate` becomes next. messages.1 stays excluded for cb13101's reason: postrotate runs before compression, so .1 is the file logrotate is about to open. Reported by SekiXu in review on #165, who also traced it back to his own #163 measurement -- "the matchable set is byte-for-byte identical with and without delaycompress" was already this fact, one step short of the conclusion. Verified on jim-1cc, both revisions run out of git with only /var/log rewritten to a scratch dir, seeded to the real postrotate shape observed on that node (messages, plain messages.1, messages.2.gz..messages.14.gz) and LIMIT set to a sixth of the total: shipped total 3236 -> 3236 removed nothing fixed total 3236 -> 688 messages.1 survived Inert at the real budget: with the messages set at 168816K against a 5% budget of 4592725K on accept-3cc, a run changes nothing. And seeded to 336 generations with a large one at .300, it trims oldest-first down to .299 -- generations the old bound could never reach. Refs bigstack-oss/cubecos#1433 Signed-off-by: Jim Lin <jim.lin@bigstack.co> Co-authored-by: Eandalf <clinah@connect.ust.hk> Co-authored-by: Claude Opus 5 (1M context) <noreply@anthropic.com>
Picks up hex e2a4060, which makes hex_trim_syslog able to remove a generation again. It matched only unsuffixed `messages.$I` while every rotated generation is compressed, and counted down from a literal 14 that no longer tracks the global `rotate` now that it is `retention * 24`. Since cb13101 stopped it touching messages.1 -- correctly, because postrotate runs before compression -- the two together left a loop with nothing it could match at all, so the SYSLOG_DISK_PERC budget had no enforcement behind it. The generation list now comes from the filesystem rather than a counter, which also removes the coupling that has drifted twice. Pending as bigstack-oss/hex#165; both repos fast-forward merge, so this SHA stays valid once that lands. Refs #1192 Refs #1433 Signed-off-by: Jim Lin <jim.lin@bigstack.co> Co-authored-by: Eandalf <clinah@connect.ust.hk> Co-authored-by: Claude Opus 5 (1M context) <noreply@anthropic.com>
|
@SekiXu thank you for checking this — and for not stopping at the shape of the change. You found that the script this PR touches could not remove anything at all, and you were right on both counts. Fixed in e2a4060.
Because of that I went one step past your suggestion. Rather than taking the bound from the retention value, the generation list now comes from the filesystem: sort whatever Reproduced your A/B before and after, both revisions run out of git with only Still inert when it should be — on accept-3cc the messages set is 168816K against a 5% budget of 4592725K, and a run changes nothing. And seeded to 336 generations with a large one at On your note that this is where your own #163 measurement landed — "the matchable set is byte-for-byte identical with and without The rest of this PR is unchanged: 🤖 Generated with Claude Code |
SekiXu
left a comment
There was a problem hiding this comment.
Approving. Taking the generation list from the filesystem is better than the bound I suggested — it needs no retention value plumbed from cubecos's config_syslogd into hex, and it cannot drift again whatever rotate becomes. That is the more durable answer to a literal that has now drifted twice.
Reproduced the A/B independently rather than taking the numbers, both revisions run straight out of git with only /var/log rewritten to a scratch dir. Seeded to the postrotate shape — messages 2000K, an uncompressed messages.1 800K, .2–.14.gz at 100K each — with LIMIT at a sixth of the total:
total survivors
shipped 8200 -> 8200 everything removed nothing
this head 8200 -> 5600 messages, messages.1
And seeded to 336 generations with a large one at .300, LIMIT just under the total: it trims oldest-first and stops at .299, having removed 37 files, with messages.1 intact. Generations the old bound could never have reached, and the exclusion holding.
One nit, in the lines this rewrites. logger fires once per removed file, so the 336-generation case writes ~335 lines into the log it is trimming; the old bound capped that at 13. It is small against a log that has busted a 5% partition budget, but a single line before the loop says the same thing and does not scale with the damage.
The other half is unchanged and still right: maxage retention with rotate retention * 24 so the count cannot bind first, and the cron.hourly move removed as dead since the systemd timer.
…ge is for
Two changes, both following cubecos reverting the logrotate timer to daily on
the product owner's call.
`rotate` goes back to the retention value. It was raised to retention * 24 for
the worst case an hourly timer allowed -- 24 rotations a day -- and on the daily
schedule that is 336 generations for a log that can produce at most 14. Nothing
kept the extra files, but the number described a schedule we no longer ship.
The comment went with it. It had justified maxage entirely by the hourly timer
("they stopped coinciding when the logrotate timer moved to hourly"), which
would have left the code explained by something that no longer exists -- and
worse, it claimed rotate was sized so it could not bind first, which stops being
true the moment rotate is the day count again.
So state what the two bounds actually do, since they are not redundant:
rotate caps how many files a busy log leaves behind; on a daily schedule
that is also its age, one generation per day.
maxage caps their age directly, and is the only one of the two that says
anything about a log that rotates *rarely* -- with notifempty and a
quiet service, generations sit for months while staying well inside a
count of 14, and without maxage they are kept indefinitely.
Measured on accept-3cc, scaled 7x (retention 2), logrotate 3.18.0:
daily rotation, 20 cycles rotate 2 2 gens, oldest 1.0 days
rotate 2+maxage 2 2 gens, oldest 1.0 days
a log that rotates rarely rotate 2 2 gens, oldest 40 days
(generations already 40d old) rotate 2+maxage 2 1 gen, oldest 0 days
Identical on the shipped schedule, which is why the change is safe; the second
row is the case maxage exists for.
The residual is recorded in the comment rather than papered over: if something
rotates a log more than once in a day -- an operator's `logrotate -f`, a fixpack
driving a rotation -- rotate spends a generation without spending a day and the
window shrinks below the advertised days. That is long-standing behaviour, and
sizing rotate past the daily count is what this commit is undoing.
Clean CXX logrotate.o and AR libhex_sdk.a, emitted directive list unchanged.
Refs bigstack-oss/cubecos#1192
Signed-off-by: Jim Lin <jim.lin@bigstack.co>
Co-authored-by: Eandalf <clinah@connect.ust.hk>
Co-authored-by: Claude Opus 5 (1M context) <noreply@anthropic.com>
Picks up hex 1d8bd9b, the hex-side follow-through on reverting this PR's logrotate timer to daily. `rotate` goes back to the retention value. It had been raised to retention * 24 to cover the worst case an hourly timer allowed, which on the daily schedule means 336 generations for a log that can produce at most 14 -- a number describing a schedule this PR no longer ships. The comment went with it: it had justified `maxage` entirely by the hourly timer, and claimed `rotate` was sized so it could not bind first, which stops being true once `rotate` is the day count again. `maxage` stays, and the commit records why it is not redundant at the same value: on a daily schedule the two agree exactly, but only `maxage` bounds a log that rotates *rarely* -- with notifempty and a quiet service, generations sit for months while staying well inside a count of 14. Pending as bigstack-oss/hex#165; both repos fast-forward merge, so this SHA stays valid once that lands. Refs #1192 Signed-off-by: Jim Lin <jim.lin@bigstack.co> Co-authored-by: Eandalf <clinah@connect.ust.hk> Co-authored-by: Claude Opus 5 (1M context) <noreply@anthropic.com>
Picks up hex 5cfb997, the other half of the review response on this PR: - fix(logrotate): bound retention by age, so the days promise survives hourly runs -- WriteDefLogRotateConf now emits `maxage <days>` with `rotate` sized so it cannot bind first. Without it, making the timer hourly shrinks the audit window from cubesys.log.default.retention days to that many *hours* for any log that trips the maxsize cap within the hour, which is exactly the busiest ones. - build(rootfs): drop the cron.hourly logrotate move -- dead since logrotate moved to a systemd timer, and the reason the hourly schedule this PR sets was believed to already be in place. Also carries 5740f8e, a dependabot harden-runner bump already on hex develop. Pending as bigstack-oss/hex#165; both repos fast-forward merge, so this SHA stays valid once that lands. Refs #1192 Refs #1433 Signed-off-by: Jim Lin <jim.lin@bigstack.co> Co-authored-by: Eandalf <clinah@connect.ust.hk> Co-authored-by: Claude Opus 5 (1M context) <noreply@anthropic.com>
Picks up hex e2a4060, which makes hex_trim_syslog able to remove a generation again. It matched only unsuffixed `messages.$I` while every rotated generation is compressed, and counted down from a literal 14 that no longer tracks the global `rotate` now that it is `retention * 24`. Since cb13101 stopped it touching messages.1 -- correctly, because postrotate runs before compression -- the two together left a loop with nothing it could match at all, so the SYSLOG_DISK_PERC budget had no enforcement behind it. The generation list now comes from the filesystem rather than a counter, which also removes the coupling that has drifted twice. Pending as bigstack-oss/hex#165; both repos fast-forward merge, so this SHA stays valid once that lands. Refs #1192 Refs #1433 Signed-off-by: Jim Lin <jim.lin@bigstack.co> Co-authored-by: Eandalf <clinah@connect.ust.hk> Co-authored-by: Claude Opus 5 (1M context) <noreply@anthropic.com>
Picks up hex 1d8bd9b, the hex-side follow-through on reverting this PR's logrotate timer to daily. `rotate` goes back to the retention value. It had been raised to retention * 24 to cover the worst case an hourly timer allowed, which on the daily schedule means 336 generations for a log that can produce at most 14 -- a number describing a schedule this PR no longer ships. The comment went with it: it had justified `maxage` entirely by the hourly timer, and claimed `rotate` was sized so it could not bind first, which stops being true once `rotate` is the day count again. `maxage` stays, and the commit records why it is not redundant at the same value: on a daily schedule the two agree exactly, but only `maxage` bounds a log that rotates *rarely* -- with notifempty and a quiet service, generations sit for months while staying well inside a count of 14. Pending as bigstack-oss/hex#165; both repos fast-forward merge, so this SHA stays valid once that lands. Refs #1192 Signed-off-by: Jim Lin <jim.lin@bigstack.co> Co-authored-by: Eandalf <clinah@connect.ust.hk> Co-authored-by: Claude Opus 5 (1M context) <noreply@anthropic.com>
What type of PR is this?
What this PR does / why we need it
Both halves came out of review on bigstack-oss/cubecos#1433, which moves the logrotate timer to hourly so the
maxsize 128Mcap in every generated config is actually evaluated.cubesys.log.default.retentionis a published tuning whose help text reads "Set log file retention policy in days", default 14 — and it is the only retention control there is. All ~40LogRotateConfdeclarations in hex and cubecos passretention 0, andWriteLogRotateConfonly emitsrotatewhen that is non-zero, so every generated config inherits the globalWriteDefLogRotateConfwrites. Measured on a live 3-node cluster: 1 of 62 files in/etc/logrotate.dsets its ownrotate. But logrotate'srotatecounts generations, which equals days only while a log rotates exactly once a day. With the timer hourly, each config pairsdailywithmaxsize 128Mand rotates on whichever comes first — so a log passing the cap every hour keptrotatehours of history.maxagenow carries the days promise androtateis sized for the worst case the hourly timer allows (24/day) so it cannot bind first.cron.hourlymove is removed, having never once taken effect.full_rootfs_installmoved/etc/cron.daily/logrotateinto/etc/cron.hourly/, guarded with|| true. RHEL/CentOS stopped shipping that cron job when logrotate moved to a systemd timer, so the source path does not exist on a stream9 rootfs, themvfails and the guard swallows it.Which issue(s) this PR fixes
Refs bigstack-oss/cubecos#672
Special notes for your reviewer
Why
rotatehad to change too, and not justmaxage.maxageprunes by age but does not extend anything —rotate 14still deletes the 15th generation regardless of its age, so on an hourly-rotating log it would have bound first at 14 hours andmaxage 14would never have been reached.rotate retention * 24is the count that cannot bind before 14 days at the fastest rate the timer permits. A log rotating once a day is unaffected either way:maxageremoves its 15th day exactly asrotate 14used to.On the removed line, "no behaviour change" is meant literally. The command has never had an effect on any image built since the systemd-timer switch. Verified on a running node — the logrotate rpm owns only
/usr/lib/systemd/system/logrotate.{service,timer},/etc/cron.daily/logrotateis absent, and/etc/cron.hourlyholds nothing but0anacron. The line immediately above it disablescrond, so even a successful move would have needed cron re-enabled before it could fire. It is removed so the two repos stop describing two different schedules.Additional documentation