A single character, three years of incidents

A few months ago, going over with the client the history of a corporate website that we maintain at APG, we came across three years of incidents that nobody had been able to explain, because every so often and with no apparent pattern the blog content would disappear.

Three years of incidents

We are talking about a WordPress multisite installation with close to eight hundred published articles and with a blog that is an important part of the client’s international presence, so every episode was noticed.

The content was not being deleted, it was disappearing: the articles stopped showing on the website and also in the WordPress Dashboard, as if they had never existed.

Other times they turned up in the Trash, always twenty at a time, and days later somebody would notice, whatever could be restored was restored and life went on.

It had been happening like that for about three years, sometimes with whole months of silence between one episode and the next, with no fixed time, no day of the week and no relation at all to the publishing or to the updates.

And with an aggravating factor that made the diagnosis especially difficult, because the activity log attributed every episode to a real user account, usually that of somebody who was working on the site at that moment and who, logically, denied having done anything. Suspicion kept rotating between agencies, collaborators and ourselves.

The dead ends

We started with the obvious, which was to look for a process capable of deleting content, and we went through the scheduled tasks of the network’s two sites one by one. All of them were identifiable and legitimate, and none of them could touch the status of an article.

We then suspected a recently activated plugin, because the most recent episode had coincided with that activation, and the time correlation was perfect, but false, since an earlier episode had happened without anyone touching that plugin.

We suspected the agency that appeared in the logs, and this was the important part, because two of the episodes happened in the small hours, with no session open, so nobody could have caused them.

Lastly we suspected a direct write against the database, bypassing WordPress, and we ruled that out with evidence, because when content is sent to the Trash WordPress leaves some characteristic metadata and it was all there, so everything had gone through its normal functions.

Important: along the way something collateral and not minor turned up, which is that a maintenance tool configured on one of the network’s sites was emptying, obviously, the Trash of every site every night, so that whatever fell into it was destroyed before anyone saw it.

Fixing that did not solve the fault, but it completely changed how serious it was, because until that moment every episode was irreversible.

How did we do it?

When the hypotheses run out you have to stop reasoning and start measuring.

We wrote a small observer plugin that prevented nothing, it only watched, and that every time something tried to alter the status of an article in an anomalous way saved the complete execution trace —which file, which line, which function and which plugin— along with the exact context of the request.

Three days later it fired, and with the trace in front of us what until then had been a ghost turned into four lines of code.

The culprit was a plugin installed years earlier, with no updates for six years, whose function is legitimate, since it restricts which private articles each user can see by modifying the queries that WordPress sends to the database.

The problem is in how it modifies them, because instead of adding its condition to the clause that already came in with .=, it replaces the whole thing with =.

Specifically the filter did something very close to this small piece of PHP code, with the faulty line commented out above the good one:

Thanks to that dot in front of the equals sign the condition is added to what the query was already asking, whereas without it any query that runs with the filter active ends up asking something completely different.

And that is where everything else fits, because a routine WordPress task, the one in charge of marking expired personal data requests as failed, was asking for "expired privacy requests" and getting "published blog articles", and was doing its job with them. It marked them, and the content disappeared from the website.

Another task, the one that moves form spam messages to the Trash, was asking for "spam messages" and also getting blog articles, and it sent them to the trash in batches of twenty, which was the batch size it had been configured with.

Fine, but why was it so odd?

The faulty filter has checks so as not to act in the Dashboard and only activates if there is a user with a session started, two conditions that look incompatible and that only coincide in one very specific scenario.

That scenario is that WordPress’s task scheduler, WP-Cron, fires at the request of the browser of somebody who has the dashboard open, something that happens more than it seems because several common tools call it that way so that tasks do not get stuck.

Since the call comes out of the browser, the session cookies travel with it, so the scheduled task runs with the identity of whoever has the tab open, and that is where the intermittence of the fault comes from and that is also why the logs systematically blamed people who had done nothing.

It was fixed in two layers at once, in the plugin itself and in a separate module that removes that filter during scheduled tasks, in case the plugin ever gets updated again.

What do we take away from this?

Four things, and none of them is exclusive to this client:

• Inherited plugins: every plugin that is installed is third-party code running with full permissions over the website, and one abandoned six years ago carries on working with all its bugs intact.
• Logs: an activity log tells you under which session something happened, not what code caused it, and confusing the two costs professional relationships.
• Instrumentation: we got it wrong several times before getting it right, and what finally closed the case was setting a trap in the right place and waiting three days.
• Backups: all the affected content was recovered, more than a hundred articles, because there were enough copies and because somebody took the trouble to compare them one by one so as to restore only what was missing, without trampling the work done afterwards.

Thanks to that execution trace we found an abandoned plugin that had spent three years breaking other people’s queries, and since then not a single episode has happened again.

At APG we have spent years taking care of the maintenance of corporate WordPress websites, so if yours has behaviours that nobody can explain all you have to do is get in touch with us, tell us what is happening and ask us for a quote.

We hope you find this case useful if you ever come across a fault that there is no way to reproduce, and we look forward to your comments and contributions.