Skip to content

Fix moodle:sync stacking by cutting per-user Moodle HTTP call volume - #112

Merged
Celeo merged 1 commit into
masterfrom
celeo/moodle-sync-bug
Jul 21, 2026
Merged

Fix moodle:sync stacking by cutting per-user Moodle HTTP call volume#112
Celeo merged 1 commit into
masterfrom
celeo/moodle-sync-bug

Conversation

@Celeo

@Celeo Celeo commented Jul 21, 2026

Copy link
Copy Markdown
Contributor

Summary

moodle:sync runs on a 3-hour schedule in the current namespace api-worker pod. A single run was taking 17+ hours, so new runs kept stacking on top of unfinished ones — 6 concurrent instances observed live on the pod, each ~55-63MB RSS, driving CPU to the pod's limit and climbing day over day. Left alone this was on track to eventually OOM the pod.

Why #111 didn't fix it

#111 (merged/deployed 2026-07-19) memoized VATUSAMoodle::getCategories() and added a 30s per-call HTTP timeout, on the theory that a category-fetch N+1 was what pushed a run past the 120-minute withoutOverlapping() lock. Two days after that deploy, the pod still had 6 stacked moodle:sync processes with elapsed times 17h47m → 2h47m — one per missed 3-hour tick, none ever completing. So the N+1 fix was real but not the dominant cost.

Actual root cause: MoodleSync::handle() walks the entire VATUSA user table and fires one core_user_get_users HTTP call per user just to check "is this CID in Moodle?" The large majority of users aren't, so this alone is tens of thousands of sequential round-trips per run. Every user who is in Moodle then triggers several more one-item-at-a-time write calls (cohorts, roles, enrolments) — staff users trigger dozens via a nested category/course enrolment loop. Runtime > the 120-minute lock window, so the lock auto-expires mid-run and the next scheduler tick starts a fresh overlapping instance.

Per api/CLAUDE.md, that 120-minute window on moodle:sync was deliberately shortened (commit a324474) so an orphaned lock (left behind by a pod restart/OOM) self-heals in ~1-2h instead of Laravel's 24h default — so widening it isn't an option. This PR instead cuts real runtime back under the existing window.

What's changing — using Moodle's bulk endpoints

Moodle's Web Service functions are bulk-capable almost everywhere (they accept arrays), but our wrappers only ever called them with single-element arrays, paying one HTTP round-trip per item. This PR:

  1. Kills the whole-table existence-check HTTP storm. Adds VATUSAMoodle::getAllUserIdMap(), which builds a full CID -> Moodle user id map with one query against the Moodle DB connection this class already uses elsewhere (clearUserCohorts, getContext, etc. all use DB::connection('moodle')). MoodleSync::handle() now does an in-memory lookup against that map instead of an HTTP call per VATUSA user, and passes the known id into sync() so its own redundant second getUserId() call is skipped too. This removes ~all of the dominant cost.
  2. Batches the per-user write calls. Adds assignCohortsBulk(), assignRolesBulk(), enrolUsersBulk() to VATUSAMoodle (the existing single-item methods are untouched — other callers depend on them: ULSHelper, AcademyController, MoodleCompetency). sync() now collects each user's cohort/role/enrolment items and flushes each as one bulk call, turning ~5-30 calls/user into ~3-4.

Explicitly unchanged: Kernel.php scheduling, the withoutOverlapping() values, and every existing VATUSAMoodle method signature. The single-user moodle:sync {cid} CLI path still does its original create-or-update getUserId() lookup — only the whole-table bulk path changed.

Behavior preservation

The bulk sync path only ever iterated users that passed if ($this->moodle->getUserId($user->cid)) — i.e. users already confirmed to exist in Moodle; it never created new users from that path. Iterating $moodleIds->has($user->cid) against the new map is equivalent, so no user that was previously synced is now skipped, and no user is newly synced that wasn't before. Per-user batching doesn't change ordering relative to other users, and each user's own clear-then-assign sequence (clearUserCohorts/clearUserRoles happen before the corresponding bulk assign, same as before) is preserved.

Testing

  • Local: ./vendor/bin/phpunit — 5/5 passing, including a new tests/Unit/MoodleUserIdMapTest.php covering the one non-obvious assumption the swap relies on (an int CID lookup matching a map keyed from the Moodle DB's string idnumber column values, via PHP's numeric-string array key coercion).
  • The existing suite is smoke-only (in-memory SQLite, no real Moodle), so the bulk Moodle calls themselves can't be integration-tested locally.

Recommended before merging to prod traffic

  • Deploy this branch to a dev/staging overlay first.
  • Run php artisan moodle:sync manually and time it — expect minutes, not hours.
  • Spot-check a few users' cohorts/roles/enrolments in Moodle match what the old per-item path produced (no behavioral drift from batching).
  • After deploying to prod, confirm via kubectl -n current exec <api-worker-pod> -- ps -o pid,etime,rss,args that at most one moodle:sync process is ever live, and that it completes well within the 3-hour interval. Cross-check logs for matching Starting/Finished scheduled task: moodle:sync pairs (the after hook never fired while the job was stuck) and watch pod CPU/memory flatten instead of climbing.

Risks

  • Bulk-call atomicity is unverified. Moodle's bulk Web Service functions accept an array of items in one call; if one item in the array is invalid (e.g. a category lookup returned null for a context id), it's not confirmed whether Moodle rejects the whole batch or processes valid items and reports per-item errors. Worth watching for on the staging run and after prod rollout — if it does hard-fail whole batches, a bad category mapping for one facility could now block cohort/role assignment for other facilities in the same call, where before it would only have failed that one item.
  • getAllUserIdMap() reads idnumber/deleted directly from the Moodle DB, same access pattern as existing methods in this class, but it's a new query shape — if Moodle's schema differs from what's assumed (idnumber as the CID, deleted = 0 for active users), the map could be built incorrectly. Worth a spot-check against real data in staging.
  • Scope is intentionally narrow: no changes to MoodleCompetency.php, the scheduler config, or the timeout PR Fix moodle:sync piling up overlapping instances via category-fetch N+1 #111 already added.

🤖 Generated with Claude Code

PR #111 memoized getCategories() and added a 30s per-call HTTP timeout,
on the theory that a category-fetch N+1 was what pushed a single
moodle:sync run past its 120-minute withoutOverlapping() lock. Deployed
2026-07-19T21:29Z; two days later the api-worker pod still had 6
concurrent moodle:sync processes stacked ~3h apart (elapsed 17h47m down
to 2h47m), so that fix did not address the dominant cost.

Root cause: MoodleSync::handle() walks the *entire* VATUSA user table
and makes one core_user_get_users HTTP call per user just to check "is
this CID in Moodle?" - the large majority return "not found", so this
existence check alone is tens of thousands of sequential round-trips
per run. Every user who *is* found in Moodle then triggers several more
one-item-at-a-time write calls (cohorts, roles, enrolments), with staff
users triggering dozens via a nested category/course enrolment loop.

Per api/CLAUDE.md, the 120-minute withoutOverlapping() window on
moodle:sync is deliberately short (commit a324474) so an orphaned lock
self-heals in ~1-2h instead of Laravel's 24h default - widening it would
undo that, so this fix instead cuts real runtime back under the window
using Moodle's existing bulk Web Service endpoints.

- VATUSAMoodle::getAllUserIdMap() replaces the per-user getUserId() HTTP
  existence check with a single query against the Moodle DB connection
  this class already uses elsewhere, building a full CID -> Moodle-id
  map up front. MoodleSync::handle() now does an in-memory lookup
  against that map instead of an HTTP call per VATUSA user, and passes
  the known id into sync() so its own redundant second getUserId() call
  is skipped too. The single-user `moodle:sync {cid}` CLI path is
  unchanged (still create-or-update via getUserId()).
- VATUSAMoodle gains assignCohortsBulk()/assignRolesBulk()/
  enrolUsersBulk(), thin wrappers that send the same
  core_cohort_add_cohort_members/core_role_assign_roles/
  enrol_manual_enrol_users calls with a full array of items instead of
  a single-element array. The existing single-item methods are left
  untouched (other callers depend on them). MoodleSync::sync() now
  collects each user's cohort/role/enrolment items and flushes each as
  one bulk call at the end, instead of one HTTP round-trip per item.

No changes to Kernel.php scheduling, withoutOverlapping() values, or any
existing VATUSAMoodle method signature.

Co-authored-by: Claude Sonnet 5 <noreply@anthropic.com>
@Celeo
Celeo merged commit e8b0f33 into master Jul 21, 2026
3 checks passed
Celeo added a commit that referenced this pull request Jul 21, 2026
…113)

PR #112 removed the per-user Moodle existence-check HTTP storm, but live
prod evidence showed runs still stack: the 25,152-user matched set still
drives one core_user_update_users, one core_cohort_add_cohort_members, one
core_role_assign_roles, and (for staff) one enrol_manual_enrol_users call
per user, ~75-100k HTTP round-trips total. Scheduled runs since #112's
deploy never completed (no "Finished scheduled task" log line across four
consecutive 3-hour ticks), and a manual foreground run ran 36+ minutes
without finishing before being backgrounded.

This splits sync() into a pure compute step (computeSyncItems()) that
returns per-user update/cohort/role/enrolment items instead of flushing
them immediately, and has handle()'s chunk(1000) loop accumulate those
across the whole chunk before flushing 4 bulk HTTP calls per chunk instead
of per user (~104 calls total for the full table instead of ~75-100k).

Also:
- Add VATUSAMoodle::updateUsersBulk(), mirroring the existing
  assignCohortsBulk/assignRolesBulk/enrolUsersBulk bulk helpers -
  core_user_update_users was the one per-user HTTP call #112 left
  unbatched.
- Memoize getCoursesInCategory() the same way getCategories() already is,
  since staff/instructor users were re-fetching the same category's course
  list by HTTP on every occurrence.
- Add logger() calls around the bulk pass (matched-user count at start,
  per-chunk item counts, a final run summary, and a log-and-rethrow around
  each bulk call) so a run's progress and any mid-run failure are visible
  in logs instead of requiring a live kubectl/ps/DB investigation like
  tonight's.

Single-user CLI path (moodle:sync {cid}) and all existing single-item
VATUSAMoodle methods (getUserId, assignCohort, assignRole, enrolUser,
createUser, updateUser) are unchanged - only new additive bulk/memoized
methods were introduced. Kernel.php scheduling and withoutOverlapping(120)
are untouched.

Co-authored-by: Claude Sonnet 5 <noreply@anthropic.com>
@Celeo
Celeo deleted the celeo/moodle-sync-bug branch July 21, 2026 16:05
Celeo added a commit that referenced this pull request Jul 21, 2026
assignCohortsBulk(), assignRolesBulk(), and enrolUsersBulk() (added in
#112) didn't pass self::METHOD_POST to request(), so they defaulted to
METHOD_GET. VATUSAMoodle::request() builds GET requests by http_build_query()-ing
the whole parameters array into the URL query string. That was invisible
in #112 because each call only ever carried one user's handful of
cohorts/roles. #113's cross-user chunk batching (up to ~1000 users per
call) pushed the query string past the server's URL length limit: the
first manual production run after #113 deployed failed immediately with
"HTTP/1.1 414 URI Too Long" on chunk 1's cohort assignment call.

Fix: pass self::METHOD_POST on all three, matching the pattern already
used by createUser(), updateUser(), and updateUsersBulk() (the one #113
bulk helper that already had this right).

Co-authored-by: Claude Sonnet 5 <noreply@anthropic.com>
Celeo added a commit that referenced this pull request Jul 22, 2026
…ng every run (#114)

moodle:sync was clearing and re-inserting every matched user's cohort
memberships on every run (~28k writes/pass), regardless of whether anything
had changed since the last run three hours earlier. Each cohort write triggers
Moodle's enrol_cohort sync, which bumps mdl_course.cacherev. The rating cohorts
(OBS, S1-C1, ZZN, ...) all enrol into one course ("Trainee Orientation",
id 8), so essentially every cohort insert funnels a cacherev UPDATE onto that
single row. Those UPDATEs serialize on the row lock: observed live with 16
concurrent `UPDATE mdl_course ... WHERE id=8` stuck 20-110s and 15 transactions
waiting on row locks, with sync throughput collapsing ~28x over a run (20,675
cohort writes in the first hour down to 728 in the fourth). Batching (#112/#113)
and a pacing sleep cut the HTTP call count but not the per-write cacherev storm,
so runs still degraded and overflowed the withoutOverlapping(120) window.

Organic (non-sync) cohort changes run at single digits per hour, so ~99.9% of
that churn was rewriting identical data. This diffs each user's desired cohorts
against their current membership (read in bulk per chunk via one query against
the moodle DB) and only issues the actual adds/removes. The end state is
identical to clear-then-reassign — the user ends up in exactly the desired
cohorts and no others — but a steady-state run writes almost nothing, so the
cacherev row-lock pileup goes away at the source. Indexing on the affected
tables is stock-Moodle-correct; the cacherev UPDATE is a primary-key point
update, so there was nothing to fix at the index layer.

Also stop retrying a failed sub-batch. A write that timed out on our side
usually keeps running server-side holding locks; a retry just adds a second
writer to the same contended rows and makes the pileup worse. moodle:sync
recomputes full desired state every run, so a skipped sub-batch self-heals on
the next pass.

Roles are still cleared-and-reassigned per user for now (a follow-up can apply
the same diff there); this change targets the cohort path, which is the dominant
source of the cacherev contention.

Co-authored-by: Claude Opus 4.8 <noreply@anthropic.com>
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