Technical debt, part 3: I refactored a 1,000-line view… and underneath was a query scanning the whole log table
ContenidoContents
Third and final part of the technical-debt series on my Jitsi-for-Moodle plugin. In part 1 I broke apart two “god files”; in part 2 I took apart the 924-line video-call function. One monster remained: view.php, the page the student or teacher sees when entering the activity. 971 lines mixing everything.
I refactored it with the usual recipe. But this time the refactor itself is the least of it —it’s the same pattern as the previous parts—. What was interesting was what showed up when I lifted the rugs: a query scanning the whole site’s log table, a cache hiding it, an N+1, a bug that let you record and stream at once, and a couple of “time capsules” buried in the code.
The refactor, in four phases (the quick bit)
view.php was the classic fat controller. I split it in four steps, validating each in a real Moodle:
- V1 — Cleanup: parameterized SQL, dead code out, and unifying
$context(it was being reassigned mid-file, evaluating a permission in the wrong context). - V2 — JavaScript to modules: the ~500 lines of JS embedded in PHP → four ES6 modules with their linter. (I covered the pattern in part 2: PHP stops manufacturing behaviour and starts handing over data.)
- V3 — HTML to templates: the scattered HTML → three Mustache templates. PHP decides, the template paints.
- V4 — CRUD out of the view: the logic mutating the database moved to a testable class, leaving thin controllers.
Result: from 971 to 455 lines (−53%) and zero embedded JavaScript. So far, the expected. Now the good part.
The cache that was hiding an expensive query
There was a counter —“user’s total minutes”— shown statically: it only changed on reload. I wanted to refresh it every 15 seconds, and when I opened the function that computes it I found a 2-minute cache. Why cache something like that?
A commit from September 2024 added it, “Add caching to getminutes functions”. Not a whim: the query counted rows in logstore_standard_log —the log table for the whole Moodle— and was called in a loop. The cache was there covering the problem, not fixing it. And that’s the golden clue: a cache almost always hides an expensive query. Before removing it, understand what it hides.
21× faster with one column in the WHERE
I ran EXPLAIN ANALYZE and there it was, in black and white:
1BEFORE — SELECT * ... WHERE userid AND contextinstanceid AND action
2Seq Scan on mdl_logstore_standard_log
3 Rows Removed by Filter: 14803 ← scans the WHOLE table
4 Buffers: shared hit=444
5Execution Time: 5.913 ms
Two changes: COUNT(*) instead of fetching all rows, and —the key— adding contextlevel to the WHERE. With that column, the query uses a composite index that already existed and wasn’t being used:
1AFTER — SELECT COUNT(*) ... WHERE userid AND contextlevel AND contextinstanceid AND action
2Index Scan using mdl_logsstanlog_useconconcr_ix
3 Buffers: shared hit=31
4Execution Time: 0.274 ms
5.913 ms → 0.274 ms (~21× faster), 444 → 31 buffers. And that’s with only ~15,000 log rows locally; the Seq Scan scales with the total table size (millions in production), while the Index Scan only with that user’s rows. The index was already there; the query just needed to give it the contextlevel.
With the query now cheap, the live counter actually refreshes every 15 seconds without a cache and with no penalty.
The N+1 that multiplied with the previous one
Along the way, the attendance report called that minutes function twice per connected user. With 30 students, 60 queries. The classic N+1. I replaced it with two aggregate queries using GROUP BY:
1BEFORE 60 queries · 36.55 ms
2AFTER 2 queries · 5.02 ms → 30× fewer queries, 7.3× faster
And note: the real factor in production is bigger, because each of those 60 queries was also the Seq Scan from before. The two fixes multiply.
The two-buttons bug
A gift I wasn’t looking for. Testing live: when pressing Record, during the seconds Jitsi takes to confirm, the Go live button stayed clickable —and vice versa—. You could launch both at once. The cause: each handler disabled only itself.
1// BEFORE: only disables its own button
2btn.disabled = true;
3api.startRecording({mode: 'file'}); // streamBtn still clickable
4
5// AFTER: disable BOTH until confirmed, with a safety net
6setControlsDisabled(true);
7armControlsWatchdog(); // re-enables after 20s if nothing starts
8api.startRecording({mode: 'file'});
It had been there for a while; it surfaced when I looked closely. And I fixed a pre-existing case where the stream button got stuck after an error.
Time capsules
What I enjoyed most about refactoring such an old view is the archaeology. You find code that’s a message from the past:
- The phantom
$state. There’s a parameter,$state, thatview.phpparses… but that no plugin file generates. It comes from outside: the Moodle mobile app builds it. A years-old commit introduced it, titled literally “ionic 5 compatibility”. Part of what it unpacks is dead code that’s never used. I decided not to touch it: breaking it would break app users. A time capsule you keep respecting because you don’t fully know who depends on it. - The Moodle 3.11 branches. The plugin requires Moodle 4.5+, but there were
if ($CFG->branch <= 311)that never run. Gone. (The Bootstrap 4 vs 5 toggle stays: that still distinguishes 4.5 from 5.x.)
And the environment scares
It’s not all plugin code; the terrain bites too:
- ESLint rejected my push three times. The pre-push hook runs ESLint with
--max-warnings 0, stricter than the day-to-day one.camelcase(a web service argument that’ssnake_caseby definition),promise/no-nesting(toasync/await),no-alert… Moral: reproduce the CI lint locally before pushing, or you pile up failed push cycles. - I almost declared a bug that didn’t exist. Validating live, I saw the presence table empty and thought “it’s broken”. No: that table self-cleans after 150 seconds, and on top of that I was looking at a different activity than the one the user was testing. Don’t mistake a transient state for a fault —and make sure you’re looking at the same object—.
What I take from this part
Parts 1 and 2 were about structure. This one was about what the structure was hiding:
- Measure before touching performance.
EXPLAIN ANALYZEturned a “this looks heavy” into a concrete change: one column in theWHERE, 21× faster. - A cache almost always covers an expensive query. Understand what it hides before removing it; sometimes, once you understand it, you no longer need it.
- Refactoring old code is archaeology. It uncovers bugs (the buttons), time capsules (the ionic
$state) and forgotten decisions. Read it with respect: not everything odd is a mistake, sometimes it’s someone solving a problem you no longer see.
With this, the plugin’s big refactor —external.php, lib.php, the video call and view.php— is done. All on dev, validated in a real Moodle at every step, ready to go to master once I’ve tested it thoroughly. Three god files fewer, a handful of bugs and bottlenecks fixed, and a plugin finally ready for the Moodle that’s coming.
Epilogue in part 4: I thought I was done… and the last CRUD still reloaded the whole page.