404-solution / includes / services / CronWriteOutcome.php

CronWriteOutcome.php in 404 Solution trunk, at includes/services/CronWriteOutcome.php

392 lines 15.8 KB

Raw Download Zip

1	<?php
2
3	if (!defined('ABSPATH')) {
4	exit;
5	}
6
7	/**
8	* Decides what a WordPress cron write's reported result actually means, and
9	* says so.
10	*
11	* The write-side twin of {@see ABJ_404_Solution_ScheduledEventInspector}, and
12	* it exists for the same reason: WordPress's cron primitives report failure for
13	* outcomes that are not failures. Three of them have reached production:
14	*
15	* - `duplicate_event`, which wp_schedule_single_event() returns only after
16	* finding an event it considers equivalent to the requested one, i.e. only
17	* when the hook IS scheduled (report 284, signature b2c064ec15425cf2);
18	* - `could_not_set` from a write that changed nothing because a concurrent
19	* request stored the identical event first (report 276, signature
20	* 87a00a2680c1bc07);
21	* - the same `could_not_set` from wp_unschedule_event() for an event another
22	* request had already removed.
23	*
24	* Believing any of them costs the plugin author an emailed ERROR report about
25	* work that was already done, so every refusal is settled here before anything
26	* is logged: benign ones leave a debug breadcrumb and report success, and only
27	* a genuinely unmet request produces the diagnostic line.
28	*
29	* This class owns no cron writes and no scheduling policy; it is given what a
30	* primitive returned and answers for it.
31	*/
32	class ABJ_404_Solution_CronWriteOutcome {
33
34	/**
35	* WordPress's code for "I did not write this because I already hold an
36	* equivalent event" (wp_schedule_single_event(), wp-includes/cron.php).
37	*/
38	const WP_ERROR_DUPLICATE_EVENT = 'duplicate_event';
39
40	/** Shared reason text for a write another request had already performed. */
41	const SATISFIED_BY_CONCURRENT_WRITE =
42	'the cron store already holds the requested state (a concurrent request wrote it first)';
43
44	/** @var ABJ_404_Solution_Logging\|null */
45	private $logger;
46
47	/** @var ABJ_404_Solution_ScheduledEventInspector Read side of the cron store. */
48	private $inspector;
49
50	/** @var string */
51	private $lastFailureDetail = '';
52
53	/**
54	* @param ABJ_404_Solution_Logging\|null $logger
55	* @param ABJ_404_Solution_ScheduledEventInspector $inspector
56	*/
57	public function __construct($logger, ABJ_404_Solution_ScheduledEventInspector $inspector) {
58	$this->logger = $logger;
59	$this->inspector = $inspector;
60	}
61
62	/** @return string */
63	public function lastFailureDetail(): string {
64	return $this->lastFailureDetail;
65	}
66
67	/**
68	* Whether a cron primitive's return value is WordPress claiming failure.
69	* Whether that claim is true is what the resolve* methods below decide.
70	*
71	* @param mixed $result
72	*/
73	public function reportsFailure($result): bool {
74	return $result === false \|\| $this->isWpError($result);
75	}
76
77	/**
78	* Settle a refused wp_schedule_single_event() write: true when the caller's
79	* request holds regardless, false (reported) when it genuinely does not.
80	*
81	* WordPress answers this itself whenever it can. `duplicate_event` is not a
82	* failure report at all -- core returns it only after scanning its own cron
83	* store and finding an equivalent event, so the hook is scheduled and core
84	* has already done the check. Re-deriving that verdict from a second read
85	* is what produced report 284: the plugin's copy of the duplicate window
86	* disagreed with the one core had just applied.
87	*
88	* Builds older than WordPress 5.7 ignore the $wp_error argument and return
89	* a bare false with no code to read, so the store inspection stays as the
90	* fallback for them (and for the no-op option write of report 276).
91	*
92	* @param array{writeResult: mixed, hook: string, args: array<int, mixed>, timestamp: int, now: int} $request
93	*/
94	public function resolveSingleWrite(array $request): bool {
95	$writeResult = $request['writeResult'];
96	$hook = $request['hook'];
97	$args = $request['args'];
98	$timestamp = $request['timestamp'];
99	$now = $request['now'];
100
101	if ($this->wpErrorCode($writeResult) === self::WP_ERROR_DUPLICATE_EVENT) {
102	return $this->reportAlreadySatisfied(array(
103	'type' => 'single',
104	'hook' => $hook,
105	'timestamp' => $timestamp,
106	'reason' => 'WordPress refused it as a duplicate, which means its cron store already holds an '
107	. 'equivalent event for the hook',
108	));
109	}
110	$inspectionFailure = '';
111	try {
112	$this->inspector->refreshCronStoreReads();
113	$stored = $this->inspector->requestedEventIsStored(array(
114	'hook' => $hook,
115	'args' => $args,
116	'timestamp' => $timestamp,
117	'recurrence' => null,
118	'now' => $now,
119	));
120	} catch (Throwable $e) {
121	$stored = false;
122	$inspectionFailure = $this->inspectionFailureDetail($e);
123	}
124	if ($stored) {
125	return $this->reportAlreadySatisfied(array(
126	'type' => 'single',
127	'hook' => $hook,
128	'timestamp' => $timestamp,
129	'reason' => self::SATISFIED_BY_CONCURRENT_WRITE,
130	));
131	}
132	$this->reportScheduleFailure(array(
133	'type' => 'single',
134	'hook' => $hook,
135	'recurrence' => null,
136	'timestamp' => $timestamp,
137	'args' => $args,
138	'errorCode' => $this->wpErrorCode($writeResult) ?: 'cron_write_returned_false',
139	'detail' => $this->writeFailureDetail($writeResult, 'wp_schedule_single_event') . $inspectionFailure,
140	'now' => $now,
141	));
142	return false;
143	}
144
145	/**
146	* Settle a refused wp_schedule_event() write. wp_schedule_event() has no
147	* duplicate check of its own, so only the store can answer here.
148	*
149	* @param array{writeResult: mixed, hook: string, recurrence: string, args: array<int, mixed>, timestamp: int, now: int} $request
150	*/
151	public function resolveRecurringWrite(array $request): bool {
152	$writeResult = $request['writeResult'];
153	$hook = $request['hook'];
154	$recurrence = $request['recurrence'];
155	$args = $request['args'];
156	$timestamp = $request['timestamp'];
157	$now = $request['now'];
158
159	$inspectionFailure = '';
160	try {
161	$this->inspector->refreshCronStoreReads();
162	$stored = $this->inspector->requestedEventIsStored(array(
163	'hook' => $hook,
164	'args' => $args,
165	'timestamp' => $timestamp,
166	'recurrence' => $recurrence,
167	'now' => $now,
168	));
169	} catch (Throwable $e) {
170	$stored = false;
171	$inspectionFailure = $this->inspectionFailureDetail($e);
172	}
173	if ($stored) {
174	return $this->reportAlreadySatisfied(array(
175	'type' => 'recurring',
176	'hook' => $hook,
177	'timestamp' => $timestamp,
178	'reason' => self::SATISFIED_BY_CONCURRENT_WRITE,
179	));
180	}
181	$this->reportScheduleFailure(array(
182	'type' => 'recurring',
183	'hook' => $hook,
184	'recurrence' => $recurrence,
185	'timestamp' => $timestamp,
186	'args' => $args,
187	'errorCode' => $this->wpErrorCode($writeResult) ?: 'cron_write_returned_false',
188	'detail' => $this->writeFailureDetail($writeResult, 'wp_schedule_event') . $inspectionFailure,
189	'now' => $now,
190	));
191	return false;
192	}
193
194	/**
195	* Settle a refused wp_unschedule_event() write. Removal is reported at
196	* warning level rather than error: the plugin keeps working with a stale
197	* event scheduled, so this is not something to mail anyone about.
198	*
199	* @param array{writeResult: mixed, hook: string, args: array<int, mixed>, timestamp: int} $request
200	*/
201	public function resolveRemoval(array $request): bool {
202	$writeResult = $request['writeResult'];
203	$hook = $request['hook'];
204	$args = $request['args'];
205	$timestamp = $request['timestamp'];
206
207	$inspectionFailure = '';
208	try {
209	$this->inspector->refreshCronStoreReads();
210	$absent = $this->inspector->requestedEventIsAbsent(array(
211	'hook' => $hook,
212	'args' => $args,
213	'timestamp' => $timestamp,
214	));
215	} catch (Throwable $e) {
216	$absent = false;
217	$inspectionFailure = $this->inspectionFailureDetail($e);
218	}
219	if ($absent) {
220	return $this->reportAlreadySatisfied(array(
221	'type' => 'removal of',
222	'hook' => $hook,
223	'timestamp' => $timestamp,
224	'reason' => 'the event is already gone (a concurrent request removed it first)',
225	));
226	}
227	$errorCode = $this->wpErrorCode($writeResult) ?: 'cron_removal_returned_false';
228	$this->lastFailureDetail = $this->writeFailureDetail($writeResult, 'wp_unschedule_event')
229	. $inspectionFailure;
230	$this->warn('Failed to unschedule cron hook ' . $hook . ' at timestamp ' . $timestamp
231	. '. Error code: ' . $errorCode . '. Detail: ' . $this->lastFailureDetail
232	. '. Recovery: inspect filters on wp_unschedule_event and the WordPress cron option, then retry.');
233	return false;
234	}
235
236	/**
237	* Report a removal that a WordPress build reported no status for and that
238	* the cron store shows still scheduled afterwards.
239	*/
240	public function reportRemovalNotVerified(string $hook, int $timestamp): bool {
241	$this->lastFailureDetail = 'event remained scheduled after wp_unschedule_event returned no status';
242	$this->warn('Failed to verify cron hook removal for ' . $hook . ' at timestamp ' . $timestamp
243	. '. Detail: ' . $this->lastFailureDetail
244	. '. Recovery: inspect filters on wp_unschedule_event and the WordPress cron option, then retry.');
245	return false;
246	}
247
248	/**
249	* Report a cron primitive that this WordPress build does not provide, which
250	* is the one failure mode no amount of re-reading the store can excuse.
251	*
252	* @param array{verb: string, hook: string, primitive: string} $failure
253	*/
254	public function reportUnavailablePrimitive(array $failure): void {
255	$verb = $failure['verb'];
256	$hook = $failure['hook'];
257	$primitive = $failure['primitive'];
258	$this->lastFailureDetail = $primitive . ' unavailable';
259	$this->warn('Cannot ' . $verb . ' cron hook ' . $hook . ': ' . $primitive
260	. ' unavailable. Error code: cron_primitive_unavailable. Recovery: verify the WordPress core '
261	. 'cron files are complete and the function is available, then retry.');
262	}
263
264	/** Preserve a cron-read exception as part of the write failure evidence. */
265	private function inspectionFailureDetail(Throwable $error): string {
266	return '; cron store verification failed (' . get_class($error) . ', code '
267	. $error->getCode() . '): ' . $error->getMessage();
268	}
269
270	/**
271	* Report a scheduling request that was genuinely not met, with everything
272	* needed to tell a hosting problem from a plugin one: what was asked for,
273	* when, against which clock, whether WP-Cron is even enabled on this site,
274	* and whether the database said anything.
275	*
276	* @param array{type: string, hook: string, recurrence: string\|null, timestamp: int, args: array<int, mixed>, errorCode: string, detail: string, now: int} $failure
277	* @return void
278	*/
279	public function reportScheduleFailure(array $failure): void {
280	$type = $failure['type'];
281	$hook = $failure['hook'];
282	$recurrence = $failure['recurrence'];
283	$timestamp = $failure['timestamp'];
284	$args = $failure['args'];
285	$errorCode = $failure['errorCode'];
286	$detail = trim($failure['detail']);
287	$now = $failure['now'];
288	if ($detail === '') {
289	$detail = 'cron primitive returned false without a WP_Error message';
290	}
291	$this->lastFailureDetail = $detail;
292	global $wpdb;
293	$dbError = isset($wpdb) && isset($wpdb->last_error) && is_string($wpdb->last_error) && $wpdb->last_error !== ''
294	? $wpdb->last_error
295	: 'none';
296	$argsJson = json_encode($args);
297	$argsText = is_string($argsJson) ? $argsJson : 'unencodable';
298	$this->error(sprintf(
299	'Failed to schedule %s cron hook %s. Recurrence: %s, timestamp: %d, current: %d, args: %s, '
300	. 'WP-Cron disabled: %s, DB error: %s, error code: %s, detail: %s. '
301	. 'Recovery: inspect the named WP-Cron and database errors, then retry the schedule.',
302	$type,
303	$hook,
304	$recurrence ?? 'single',
305	$timestamp,
306	$now,
307	$argsText,
308	(defined('DISABLE_WP_CRON') && DISABLE_WP_CRON) ? 'yes' : 'no',
309	$dbError,
310	$errorCode,
311	$detail
312	));
313	}
314
315	/**
316	* Record that a write WordPress reported as failed had in fact already been
317	* satisfied, and report success. Debug level on purpose: nothing is wrong,
318	* nothing needs doing, and the line exists only so the race stays traceable
319	* in a debug log.
320	*
321	* @param array{type: string, hook: string, timestamp: int, reason: string} $outcome
322	*/
323	private function reportAlreadySatisfied(array $outcome): bool {
324	$this->lastFailureDetail = '';
325	$this->debug(sprintf(
326	'WordPress reported the %s cron write for %s at timestamp %d as failed, but %s. '
327	. 'Treating as scheduled.',
328	$outcome['type'],
329	$outcome['hook'],
330	$outcome['timestamp'],
331	$outcome['reason']
332	));
333	return true;
334	}
335
336	/** @param mixed $value */
337	private function isWpError($value): bool {
338	return function_exists('is_wp_error') && is_wp_error($value);
339	}
340
341	/**
342	* The WP_Error code a cron primitive refused with, or '' when it gave none
343	* (a bare false, or a WordPress older than 5.7 ignoring $wp_error).
344	*
345	* @param mixed $value
346	*/
347	private function wpErrorCode($value): string {
348	if ($this->isWpError($value) && is_object($value) && method_exists($value, 'get_error_code')) {
349	$code = $value->get_error_code();
350	return is_scalar($code) ? (string)$code : '';
351	}
352	return '';
353	}
354
355	/** @param mixed $value */
356	private function wpErrorMessage($value): string {
357	if ($this->isWpError($value) && is_object($value) && method_exists($value, 'get_error_message')) {
358	$message = $value->get_error_message();
359	return is_string($message) ? $message : '';
360	}
361	return '';
362	}
363
364	/** @param mixed $writeResult */
365	private function writeFailureDetail($writeResult, string $primitive): string {
366	$message = $this->wpErrorMessage($writeResult);
367	return $message !== '' ? $message : $primitive . ' returned false without a WP_Error message';
368	}
369
370	private function error(string $message): void {
371	if ($this->logger !== null && method_exists($this->logger, 'errorMessage')) {
372	$this->logger->errorMessage($message);
373	return;
374	}
375	abj404_logPhpFallback('service-resolution-fallback', $message);
376	}
377
378	private function debug(string $message): void {
379	if ($this->logger !== null && method_exists($this->logger, 'debugMessage')) {
380	$this->logger->debugMessage($message);
381	}
382	}
383
384	private function warn(string $message): void {
385	if ($this->logger !== null && method_exists($this->logger, 'warn')) {
386	$this->logger->warn($message);
387	return;
388	}
389	abj404_logPhpFallback('service-resolution-fallback', $message);
390	}
391	}
392