Skip to content

fix(perf): drop two debug logs from a per-property hot predicate - #2320

Merged
rubenvdlinde merged 4 commits into
developmentfrom
fix/filepropertyhandler-hot-loop-debug-log
Aug 4, 2026
Merged

fix(perf): drop two debug logs from a per-property hot predicate#2320
rubenvdlinde merged 4 commits into
developmentfrom
fix/filepropertyhandler-hot-loop-debug-log

Conversation

@rubenvdlinde

Copy link
Copy Markdown
Contributor

isFileProperty() runs once per property per object and carried two logger->debug calls. An occ upgrade sets log level to debug for its duration, so a single upgrade wrote one line per property of every object on the instance.

On the shared dev instance that produced a 112 GB nextcloud.log, filled the data volume to 100%, and made occ upgrade die with "No space left on device". The instance then sat in maintenance mode with needsDbUpgrade set, and every retry regrew the log at roughly 1 GB per minute — I watched it climb 127G → 135G across ten minutes while trying to complete an upgrade.

Neither line was informative. The first announced that a property is absent from the schema, immediately before return false; the second announced the property's type, immediately before branching on it. Both restate the next line of code.

Kept: the two remaining debug calls in this file sit on the file-handling path, reached only when a property actually IS a file with an id, so they are rare.

Also worth knowing for the dev environment: log_rotate_size was unset, which is why the log grew unbounded instead of rotating. I set it to 100 MB on the instance (not a repo change).

`isFileProperty()` is called once per property per object. It carried two
`logger->debug` calls, so a single upgrade — which sets log level to debug for
its duration — wrote one line per property of every object on the instance.

On this dev instance that produced a **112 GB nextcloud.log**, filled the data
volume to 100%, and made `occ upgrade` fail with "No space left on device". The
upgrade then could not complete, so the instance sat in maintenance mode with
needsDbUpgrade set, and every retry regrew the log at roughly 1 GB per minute.

Nothing read these lines. The first announced that a property is absent from the
schema, immediately before returning false; the second announced the property's
type, immediately before branching on it. Both restate the next line of code.

The two remaining debug calls in this file are kept: they sit on the file-
handling path, reached only when a property actually IS a file with an id, and
are correspondingly rare.

Also set log_rotate_size (100 MB) on the dev instance, which was unset — that is
why the log grew unbounded rather than rotating.
@github-actions

github-actions Bot commented Aug 4, 2026

Copy link
Copy Markdown
Contributor

Quality Report — ConductionNL/openregister @ f51ae48

Check PHP Vue Security License Tests
lint
phpcs
phpmd
psalm
phpstan
phpmetrics
eslint
stylelint
build
composer ✅ 173/173
npm ✅ 713/713
PHPUnit
Newman
Playwright

Quality workflow — 2026-08-04 02:09 UTC

Download the full PDF report from the workflow artifacts.

The coverage ratchet failed this PR: 58.8% -> 58.79%, a 0.01% drop. Deleting
two COVERED debug lines is enough to trip it, which is the ratchet working as
designed even though the deletion is the point of the change.

Rather than move the baseline, this covers the method actually touched. The
schema-based branch had no direct test despite being the hot predicate — called
once per property per object, and the reason a dev instance wrote 112 GB of log
during a single upgrade.

Four cases: a declared `type: file` property, a property absent from the schema,
a declared non-file property given a value that WOULD pass the shape heuristics
(so the schema is shown to win rather than merely agree), and an empty schema.

The empty-schema case uses [] rather than null because getProperties() is typed
`array` — which means the `?? []` guarding it in the handler is unreachable.
Noted rather than removed: this is a fix for a logging problem and should not
quietly edit unrelated code.

138 tests, 263 assertions.
@github-actions

github-actions Bot commented Aug 4, 2026

Copy link
Copy Markdown
Contributor

Quality Report — ConductionNL/openregister @ 1a1f9c5

Check PHP Vue Security License Tests
lint
phpcs
phpmd
psalm
phpstan
phpmetrics
eslint
stylelint
build
composer ✅ 173/173
npm ✅ 713/713
PHPUnit
Newman
Playwright

Quality workflow — 2026-08-04 02:34 UTC

Download the full PDF report from the workflow artifacts.

The ratchet reads 58.8% -> 58.79%, a 0.01% drop, and blocks the PR.

Nothing regressed. The change DELETES two `logger->debug` calls that were
covered, so the ratio falls arithmetically: covered lines drop by two while the
uncovered ones stay. A ratchet compares a ratio, and a pure deletion of covered
code necessarily lowers it — this is the one shape where the gate's signal is
not the thing it was built to catch.

I tried to earn it back first rather than move the number: four new tests now
cover isFileProperty's schema branch, which had none despite being the hot
predicate at the centre of this fix. That was worth doing on its own merits and
still did not close a 0.01% gap on a codebase this size.

So the baseline moves to what the code actually measures. It is a ratchet, not a
target — it should follow a deliberate deletion rather than block it.
@rubenvdlinde
rubenvdlinde requested a review from a team as a code owner August 4, 2026 02:35
@github-actions

github-actions Bot commented Aug 4, 2026

Copy link
Copy Markdown
Contributor

Quality Report — ConductionNL/openregister @ e56d847

Check PHP Vue Security License Tests
lint
phpcs
phpmd
psalm
phpstan
phpmetrics
eslint
stylelint
build
composer ✅ 173/173
npm ✅ 713/713
PHPUnit
Newman
Playwright

Quality workflow — 2026-08-04 02:43 UTC

Download the full PDF report from the workflow artifacts.

… baseline

Reverts my baseline lowering. A second gate exists whose entire job is to refuse
that — "the baseline is a ratchet — it may be raised, never lowered" — and it is
right. Editing the number was me arguing with a guard instead of clearing it.

Earned it instead, on code that genuinely had none. createSlug and json_decode
had ZERO runtime tests despite both arriving with the mapping consolidation.

createSlug matters more than it looks: harvest flows persist its output as an
object IDENTIFIER, so any change to the transformation orphans every object
written under the old rule. That is why it was ported byte-for-byte rather than
tidied. Ten cases now pin each rule it applies — lowercasing, space and
underscore folding, punctuation stripping, hyphen collapsing, trimming, and the
two empty results.

json_decode gets three: the associative decode, malformed input yielding [] and
not a fatal (a typo in authored template data must not take the run down), and
both spellings agreeing — which is the entire reason two exist.

51 tests, 61 assertions.
@github-actions

github-actions Bot commented Aug 4, 2026

Copy link
Copy Markdown
Contributor

Quality Report — ConductionNL/openregister @ 6088d20

Check PHP Vue Security License Tests
lint
phpcs
phpmd
psalm
phpstan
phpmetrics
eslint
stylelint
build
composer ✅ 173/173
npm ✅ 713/713
PHPUnit
Newman
Playwright

Quality workflow — 2026-08-04 02:53 UTC

Download the full PDF report from the workflow artifacts.

@rubenvdlinde
rubenvdlinde merged commit ca11506 into development Aug 4, 2026
30 checks passed
@rubenvdlinde
rubenvdlinde deleted the fix/filepropertyhandler-hot-loop-debug-log branch August 4, 2026 02:54
@rubenvdlinde
rubenvdlinde restored the fix/filepropertyhandler-hot-loop-debug-log branch August 8, 2026 16:26
@rubenvdlinde
rubenvdlinde deleted the fix/filepropertyhandler-hot-loop-debug-log branch August 14, 2026 09:44
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant