I wrote down why the audit screen was slow, fixed it, measured it, and was wrong

The Starting Point

Yesterday's walkthrough turned up something with a very specific tell. The permission core.audit.view was declared and granted to Admin by default, and gating nothing — because there was no audit screen anywhere. No controller, no route, no view, no navigation item.

The audit logger has been called by every module since core was written and nothing could read what it wrote.

Found by noticing the permission rather than by clicking, which is new for this failure shape.

What Actually Happened

First: a permission bug that had been silently live for weeks

Before the audit work, the walkthrough's first item: Notification rules was missing from the Administration menu. Not stale dev data. The platform.

The permission registry's sync reports only what it created, and that report is the sole trigger for granting a declared default. Its own docblock warns that creating a permission anywhere else spends its newness and it is "granted to nobody, ever" — and the documented deploy command walked straight into it. The vendor-admin step syncs on its way to granting itself everything, so the role catalogue found nothing new and cascaded nothing.

Core is a required module, so the enable path never runs for it. That command is the only path a new core permission has into a running deployment.

The effect: any permission core has added since a deployment's roles were created never reached Admin, Editor or Reader. Invisible until a new permission gates something somebody looks for — which is exactly what just happened.

The fix is one line moved: cascade before the vendor admin, so creation and granting happen together.

I have now hit this same bug twice, three weeks apart, from two different entry points. The first time it was modules enabled after roles existed.

Then: a rule that told nobody

A rule on a case's assignee, notifying the assignee, sent nothing.

Reading a person field. The contract is explicit and I didn't follow my own design. A person field's own key is the name column — it holds "Chris Cooper" — and the identifier columns are declared per kind on the definition. My resolver guessed at conventional column names, found neither, then fell back to the field itself and found a person's name where it wanted an identifier.

The rule fired and reported told 0, skipped 0 — which is how it was found. Those counters I added yesterday earned their place inside a day.

And the permission check it then failed. With resolution fixed, the recipient was found and immediately dropped — because whether somebody may see a record is only answerable inside a business unit. Roles are granted per unit, so the check consults the acting one, and with none acting it answers false for everybody, an administrator with every permission included.

A web request always has a unit, so this was invisible from the interface. But a case reassigned by a queue job, a console command or an API call without a unit header would have dropped every recipient on a check that was never really asked.

The audit trail, and my wrong diagnosis

I built the screen, then moved the trail onto its own database, then made it record field-level diffs. Then came performance.

I wrote a decision record saying the OR IS NULL predicate in the unit scoping was why reads were linear, and that removing it would take a filtered read from ~200ms to single digits.

At 300,000 rows: 192ms before. 199ms after. The first page went from 31ms to 37ms.

The OR was not the thing.

Measuring where the time actually went found it in one line:

fetching the fifty rows a page shows:   4.7ms
the COUNT(*) beside them:              25.4ms

Pagination's total cost five times what the data cost. And no index removes it, because counting what matches means visiting what matches.

The same governs the filters. An event matching one row in seven costs 51ms; the same filter matching six in seven costs 146ms. The cost is proportional to how much matches, not to how well it's indexed.

So the remaining fix isn't an index or a predicate — it's to stop counting the whole table to draw a page. A bounded count that says "1,000+". Which is a visible change to what the screen says, so it's a decision rather than an optimisation.

With that: first page 37ms → 0.9ms. Filtered by event 199ms → 6.5ms. The number itself 25.4ms → 0.8ms.

And the row that didn't move is the one worth keeping, because it's the general rule underneath all of it: a bounded count stops early when there's a lot to find and cannot stop at all when there's little. Proving a substring matches one row in three hundred thousand means looking at all of them. The bound helps exactly where the old count hurt most, and not at all where the query was always going to scan.

The sentinel change stays — correct, simpler than the OR, modestly better on two paths. It simply wasn't the thing. The decision record is amended to say so rather than left claiming a cause that measurement disproved.

The relation that doesn't cross databases

I wrote in a model that the causer and subject relations would still resolve across connections.

They do not. Laravel's morph resolution puts the related model on the parent's connection whenever the related model names none of its own — and no application model does. So looking up the person who did something searches the audit database, which has no users table, and throws.

Not silently wrong. It takes the page down.

Only a test against a real second in-memory database could have said so, and the test now pins the failure so the relation cannot be put back.

The same trap had already been written once: the controller listed people using a subquery across the trail's table. It would have failed the moment anybody moved the trail. That's what a second connection does — the code keeps working right up until the setting changes.

Recording what changed, and the constraint that shaped it

finishSave() calls syncOriginal() as its last act. So once a save finishes, the old value is gone from the model — and all thirty-six audit calls in the platform happen after their save. Reading the diff there returns the new value as both halves.

So an Eloquent listener takes it during the event, holds it for the request keyed by record, and the logger collects it. No caller changed.

Also wrong on the first pass and caught the same way: wasRecentlyCreated stays true for the rest of the request, so a record created and then updated reported its update as a creation.

Redaction is four rules in order, and they're deliberately arranged so none depends on memory:

$hidden on the model — strongest, because it's maintained for a stronger reason than auditing: an unhidden sensitive column leaks through every JSON response anyway.
The cast — anything hashed or encrypted was deliberately made unreadable at rest, and writing the plaintext into a table nothing deletes from would undo exactly that.
The name, as a deliberately broad backstop.
The deployment's own list.

A redacted field is still named as having changed, with the reason instead of the value. Omitting it would make a password change look like nothing happened.

Two menu bugs, and two tests that passed against them

The menu had two "Commercial" headings. Three modules declare a group explicitly; three others inherit their category from package metadata. Two strings, two headings, both rendering the same word, because every renderer already passes the key through a headline formatter. Fixed at the registry — a heading is normalised before anything groups by it.

The first fix used Str::snake(), which turns "COMMERCIAL" into c_o_m_m_e_r_c_i_a_l. The test caught that and the real data would not have, because the two spellings in use happened to differ only in the first letter.

And three list pages were reachable from nowhere. In the horizontal menu's section bar, an item with children rendered its label as a heading and only its children as links — silently dropping the parent's own route. Three modules declare both a list route and children, so the bar showed the children and the lists were unreachable. The vertical menu never had the fault, which is why it survived the design-layer walkthrough — and horizontal is the default skin.

Two tests failed to catch it:

The existing one asserted every entry appears in both menus. The label did appear — as a heading. A label is not a link.
The replacement asserted every target the menu names is linked somewhere on the page — and passed against the broken version, because the menu drawn below 1024px renders parents as links and sits in the markup whichever layout is chosen.

So the assertion moved to the component where the decision is made, and was checked by breaking it again and watching it fail.

What Worked

Keeping the trail, and proving it's deliberate. Nothing prunes the audit trail. Nothing is scheduled to. No retention period ships.

But nothing pruned it before either — only because nobody had built pruning, which from outside is indistinguishable from an oversight. Two guards make it a decision:

the trail table carries no foreign keys at all, so deleting a person, a record or a whole business unit leaves it exactly as it was
a test reads every package's source and fails on anything that deletes from it, with an empty allow-list a future pruner would have to argue its way onto

Checked by writing a pruner and watching the test fail.

(The first version of that test walked into every package's vendor directory and threw the results away, adding twenty-four seconds to every suite run. Pruned before descending: 0.43s.)

And the tension it doesn't resolve is named rather than buried: keeping everything and erasing a person are in direct conflict, and the trail now holds field values.

Forms as a narrowed view of a record type. Two properties make one link safe to print on a sheet, both tested directly:

The record comes from what somebody typed, never from the browser. A test posts four different id-ish parameters naming somebody else's account and asserts that account is untouched.
Only the form's own fields are written. The payload isn't filtered — the fields are rebuilt from the form's definition, so a field named in both the request and the form's field list is never looked at.

And a refusal that says why. A form narrowed to a role answered 404 to a signed-in administrator who could see it in a list, on the argument that 403 confirms a form exists. That argument is right for a stranger with a URL and wrong for somebody who is already looking at the thing. It protects nothing from them.

Plus: the button was offered anyway. visibleWhen checked only whether the form was active. A link to a page that refuses is worse than no link — a rule this platform applies to unconfigured disks and dead record types, and hadn't applied here.

What I Learned

Measure before you write down the cause. I put a diagnosis in a decision record, implemented it, and it changed nothing. The record is amended rather than quietly corrected.
COUNT(*) for pagination can cost more than the page. Five times more, here. And no index fixes it.
A bounded count helps where scanning hurts and not at all where you were always going to scan. That asymmetry is the whole rule.
Eloquent morph relations resolve on the parent's connection. Cross-database relations throw rather than returning nothing.
syncOriginal() runs at the end of finishSave() — after a save, the old value is gone. Capture diffs in the model event.
wasRecentlyCreated stays true for the whole request.
A test that passes against the bug is not a test. Two of mine did yesterday. Break the code and watch the test fail, every time.
A permission created outside the registry's sync is granted to nobody, ever — and I've now hit that from two directions three weeks apart.
A permission check with no business unit in context answers false for everybody, including an administrator holding everything.
"Nobody built it yet" and "we decided not to" look identical from outside. If the absence is deliberate, guard it.

Tech Notes

Stack: PHP 8.4, Laravel, MySQL (Docker), SQLite suites, PHPStan level 6
Audit trail: own connection selectable at runtime (so the table is created on demand rather than by migration), unit as an indexed column with a 0 sentinel instead of NULL, simplePaginate + a bounded count of 1,001
Diffs captured in an Eloquent listener during the event; 200 tracked records per request, values cut at 500 chars
Redaction: model $hidden → cast → name backstop → deployment list; redacted fields still reported as changed
Forms write through the same writer the generic form uses — never a second write path
bin/check green at 1,382 assertions across fourteen packages

# measured at 300,000 rows, medians of five runs
first page       37ms → 0.9ms
filtered         199ms → 6.5ms
the count        25.4ms → 0.8ms
text search      unchanged — LIKE with a leading wildcard, and that's honest