← Writing

Debugging Edge Workers: Why the Cron Ran Without Cleaning the Catalogue

Subrequest bottleneck investigation in Cloudflare Workers: how a loop limit silently halted the cleanup of 100 orphaned variants in a live e-commerce store.

Cloudflare WorkersDebuggingSubrequestsE-commerce
Debugging Edge Workers: Why the Cron Ran Without Cleaning the Catalogue

A store selling made-to-measure blinds creates a product variant for every configuration a customer puts together. Width, height, fabric, colour, control type: each combination becomes a real item in the catalogue, otherwise it cannot go into the cart. That means the catalogue fills up with junk by design, and that there is a scheduled Worker whose only job is to delete the variants nobody bought.

The suspicion recorded two weeks earlier was straightforward: the variant IDs were spread across too wide a range for a 24-hour window, so the cron probably was not running.

The suspicion got the symptom right and the cause entirely wrong. The cron was running. It had been running for months, without a single failed execution. And even so there were 100 expired variants, the oldest created 101 days earlier.

The pattern that gave the case away

Before touching a single line, I ran a read-only script against the store to count what was actually there. The result did not look random, and that is what matters:

  • 109 live configurator variants, 100 of them already expired.
  • All 100 expired ones were in products from position 79 onwards in the list.
  • The only configurator product within the first 47 positions had zero expired variants.

Where the cron reached, it worked perfectly. The problem was not execution, it was reach. And “reach” is not a category of bug that occurs to you when your starting hypothesis is “it is not running”.

Three causes stacked

None of the three alone explained the buildup.

The window was never 24 hours. The constant in the code said 72, with a comment explaining why: giving the customer three days to come back to an abandoned cart. The README, the documentation and my own notes said 24. The original suspicion had been measured against the wrong window, and with 72 hours the expected spread of IDs is three times larger. Which means the data that raised the suspicion was not even evidence of a problem.

The name filter caught the whole store. The list of configurator products was identified by name, looking for terms like “blackout” and “solar screen”. Except the store sells blinds: those terms matched 111 of the 113 products. Listing the variants of 111 products costs 111 subrequests, and the Cloudflare Workers free plan caps you at 50. The loop blew the budget around product 47 and hit break. Always the same first 47. The products that were actually piling up junk lived in positions 79 to 111.

The schedule was weekly. The dashboard showed 0 3 * * 0, Sunday at 3 a.m. The comment in the code, the README and the documentation said 0 3 * * *, daily. It was never daily.

The corollary that explains why nobody had fixed it by hand

There was a manual cleanup route, meant to force the sweep without waiting for the schedule. It called exactly the same function, which always starts from the top of the list.

Running the manual cleanup, however many times, spent the whole budget walking through products that were already clean and stopped before reaching the dirty ones. The escape valve had the same defect as the system it was supposed to rescue, which made it perfectly useless in a silent way.

The fix was not raising the budget

The obvious way out would be to paginate, keep a cursor between runs and work through it in chunks. I did consider it. Reading the API documentation is what made that unnecessary: the products endpoint already returns the variants embedded in each product, creation date and all.

The 113 products come back in one subrequest. Not 111.

With that, the sweep moved to building a global queue of expired variants, ordered from oldest to newest, and spending the remaining ~47 calls on deletions only. Since every run sees the whole store, any buildup drains itself run after run, with no need to keep state anywhere.

The rotation between runs that I had been considering only existed as an idea because listing variants was expensive. When the cost dropped from 111 to 1, the problem the rotation solved stopped existing. It holds as a general rule: a good share of the complexity we design exists to work around a constraint that was never verified.

The side finding that nearly became an incident

Two things turned up by accident in the middle of the diagnosis, and both were more dangerous than the original bug.

The first: the manual cleanup route called the function with the parameter that ignores the time window. The name and the intended use were “run the cron early”, but the actual behaviour was to delete every variant, including those in carts open at that very moment. Anyone clicking it thinking they were just bringing the sweep forward would have destroyed purchases in progress. The default now respects the window, same as the schedule, and the destructive mode now requires an explicit parameter in the URL.

The second: after draining the 100 variants, one of the products was left with a single variant, the one I had been treating for weeks as cosmetic junk. It is what keeps the product’s variation property alive. Deleting it would leave the product with no variants at all, and the platform removes the attribute in that case, which would break the creation of future variants. The configurator on that page would simply stop working.

An earlier decision not to touch it had been made for another reason, and by luck. It was not cosmetic, it was structural.

What was left

The drain deleted 100 variants, with 0 errors and no product left empty. Nine remained, all within the 72-hour window, the oldest at 47 hours: legitimate carts, which is exactly what should be left.

Before shipping, I validated the new logic in simulation against the real store, without deleting anything: 1 sweep call against the 112 from before, 47 left over for deletions, and in the worst simulated case the queue came out correctly ordered, with the structural variant kept out of it.

What I take from this, and it is not about cron:

A scheduled job that runs without an error is not a scheduled job that works. The log said “success” every time, because running out of budget and exiting is a success path. Only measuring the effect in the world, rather than the status of the run, revealed the problem.

Three documents said the same wrong thing. The README, the documentation and my notes agreed with each other about the window and about the frequency. Agreement between documents is not verification: they had been copied from one another. The code and the dashboard disagreed with all three, and they were right.

The initial hypothesis cost two weeks. “The cron is not running” was plausible, it was consistent with the symptom, and it sent me looking in the wrong place. What broke it open was stopping testing the hypothesis and going to count what was actually in the store.