404-solution / includes / diagnostics / ResponseControlFilterTracer.php

ResponseControlFilterTracer.php in 404 Solution trunk, at includes/diagnostics/ResponseControlFilterTracer.php

292 lines 12.0 KB

Raw Download Zip

1	<?php
2
3	if (!defined('ABSPATH')) {
4	exit;
5	}
6
7	/**
8	* Durable attribution for the response-control filter dispatches on the
9	* instrumented table AJAX response tail (Bruno timeout cause matrix, gap-hunt
10	* iterations 8 and 9, Codex response-control-filter gaps).
11	*
12	* Four production filters run foreign WordPress callbacks at response-critical
13	* boundaries that no other tracer covers:
14	*
15	* - AjaxAdminEndpointSupport::getAndClearAjaxBufferedOutput() dispatches
16	* `abj404_should_manage_output_buffer` before the output buffer is read or
17	* drained.
18	* - AjaxResponseEmitter::sendJsonResponseAndExit() dispatches
19	* `abj404_should_exit` after the echo boundary and before the first flush
20	* checkpoint.
21	* - DetachAbExperiment::assignNextAttempt() dispatches
22	* `abj404_should_run_detach_ab_diagnostic` after the response flush and
23	* before the connection-detach call.
24	* - WordPress status_header() dispatches `status_header` before core header
25	* emission while AjaxResponseEmitter is sending the table response.
26	*
27	* A callback registered on either named filter, or on WordPress's global `all`
28	* hook (which fires on every apply_filters), can conditionally block only for
29	* `ajaxUpdatePaginationLinks`, so a successful canary request cannot eliminate
30	* it: the canary carries no instrumented request id and never reaches this
31	* tracer, while the real table request does. Without per-callback identity a
32	* failing session says only "between echo and flush" or "before ob_read", not
33	* which callback ran there.
34	*
35	* The tracer is active only inside an instrumented table AJAX request
36	* (AjaxDiagnosticRequestPolicy::instrumentedRequestIdFromGlobalContext() !== ''); every
37	* other request -- the canary ladder, the hot front-end 404 path, any other
38	* AJAX action -- is a pure pass-through with no record, no registry access, and
39	* behavior byte-identical to a bare apply_filters(). For an instrumented
40	* request each dispatch is durably bracketed BEFORE any registry access, then
41	* the named filter's callbacks AND the `all` hook's callbacks are wrapped with
42	* the shared reference-safe callback-identity machinery
43	* (ABJ_404_Solution_HookCallbackInstrumenter). A callback that does not return
44	* leaves its start unmatched, and the dispatch bracket start is itself reserved,
45	* so a worker killed inside a foreign callback still names the boundary it died
46	* on through bounded support extraction. Callback arguments, filter values, and
47	* source paths never enter these records.
48	*
49	* allow-no-test-found: exercised through the real ajaxUpdatePaginationLinks
50	* response entry point in tests/ResponseControlFilterTracerTest.php.
51	*/
52	final class ABJ_404_Solution_ResponseControlFilterTracer {
53
54	/** WordPress's global hook plus the named response-control filter. */
55	const ALL_HOOK = 'all';
56
57	/**
58	* Monotonic across every dispatch in the process, so two dispatches of the
59	* same filter within one request (the happy-path exit and the error-path
60	* exit both dispatch abj404_should_exit) never collide on an operation id --
61	* a collision would let one dispatch's end close the other's reserved start.
62	*
63	* @var int
64	*/
65	private static $dispatchSequence = 0;
66
67	/** @var string */
68	private $requestId;
69	/** @var string The raw filter hook name passed to apply_filters(). */
70	private $rawFilterHook;
71	/** @var string Redacted hook identity stamped onto records. */
72	private $filterHook;
73	/** @var int This dispatch's unique ordinal, seeding every operation id. */
74	private $dispatchOrdinal;
75	/** @var int */
76	private $operationSequence = 0;
77	/** @var bool */
78	private $recording = false;
79	/** @var ABJ_404_Solution_HookCallbackInstrumenter<array{fields: array<string, mixed>, started_at: float\|null}\|null> */
80	private $hookInstrumenter;
81	/** @var ABJ_404_Solution_HookInstrumentationLifecycleTracer */
82	private $lifecycleTracer;
83
84	/**
85	* Bracket one response-control filter dispatch and attribute every foreign
86	* callback it runs. Returns the dispatch result unchanged so the caller's
87	* gate keeps behaving exactly as it did with a bare apply_filters().
88	*
89	* @template T
90	* @param string $filterHook The named filter dispatched inside $dispatch.
91	* @param callable():T $dispatch Invokes apply_filters($filterHook, ...).
92	* @return T
93	*/
94	public static function traceDispatch(string $filterHook, callable $dispatch) {
95	$requestId = class_exists('ABJ_404_Solution_AjaxDiagnosticRequestPolicy')
96	? ABJ_404_Solution_AjaxDiagnosticRequestPolicy::instrumentedRequestIdFromGlobalContext()
97	: '';
98	if ($requestId === '') {
99	// Not the instrumented endpoint (canary ladder, front-end 404, any
100	// other AJAX action): no bracket, no registry access, byte-identical.
101	return $dispatch();
102	}
103	return (new self($requestId, $filterHook))->run($dispatch);
104	}
105
106	private function __construct(string $requestId, string $filterHook) {
107	$this->requestId = $requestId;
108	$this->rawFilterHook = $filterHook;
109	$this->filterHook = ABJ_404_Solution_HookCallbackIdentity::hookName($filterHook);
110	$this->dispatchOrdinal = ++self::$dispatchSequence;
111	$this->lifecycleTracer = new ABJ_404_Solution_HookInstrumentationLifecycleTracer(
112	$requestId,
113	'response_control_filter'
114	);
115	$this->hookInstrumenter = new ABJ_404_Solution_HookCallbackInstrumenter(
116	function (
117	string $registeredHook,
118	string $actualHook,
119	int $priority,
120	array $identity,
121	int $callbackOrdinal
122	) {
123	return $this->beginHookCallback(
124	$registeredHook,
125	$actualHook,
126	$priority,
127	$callbackOrdinal,
128	$identity
129	);
130	},
131	function ($token): void {
132	$this->finishHookCallback($token);
133	},
134	$this->lifecycleTracer
135	);
136	}
137
138	/**
139	* @template T
140	* @param callable():T $dispatch
141	* @return T
142	*/
143	private function run(callable $dispatch) {
144	// The durable dispatch start lands BEFORE any registry access or foreign
145	// dispatch. A worker killed inside a callback still leaves this reserved
146	// start naming the boundary it died on.
147	$operationId = $this->operationId('response_control_filter_dispatch');
148	$this->write('response_control_filter_dispatch_start', array(
149	'operation_id' => $operationId,
150	'filter_hook' => $this->filterHook,
151	));
152	$status = $this->installHookCallbacks();
153	$startedAt = self::nowFloat();
154	try {
155	$result = $dispatch();
156	} catch (Throwable $e) {
157	// Leave the dispatch start and any in-flight callback start unmatched
158	// (both reserved), restore the registry without ending pending
159	// markers, and rethrow so the caller's recovery is unchanged.
160	$this->restoreHookCallbacks(false);
161	throw $e;
162	}
163	$this->restoreHookCallbacks(true);
164	$this->write('response_control_filter_dispatch_end', array_merge($status, array(
165	'operation_id' => $operationId,
166	'filter_hook' => $this->filterHook,
167	'status' => 'complete',
168	'elapsed_ms' => self::elapsedMilliseconds($startedAt),
169	)));
170	return $result;
171	}
172
173	/**
174	* Wrap every callback on the named filter and on the `all` hook. The named
175	* hook is instrumented last so its callbacks sit closest to the dispatch,
176	* mirroring WordPress's `all`-then-named invocation order.
177	*
178	* @return array{callbacks_attributed: int, callbacks_unavailable: int, registry_status: string}
179	*/
180	private function installHookCallbacks(): array {
181	$attributed = 0;
182	$unavailable = 0;
183	$registryUnavailable = false;
184	foreach (array(self::ALL_HOOK, $this->rawFilterHook) as $hookName) {
185	$counts = $this->hookInstrumenter->instrument($hookName);
186	$attributed += $counts['callbacks_wrapped'] + $counts['callbacks_marked'];
187	$unavailable += $counts['callbacks_unavailable'];
188	if ($counts['registry_status'] === 'unavailable') {
189	$registryUnavailable = true;
190	}
191	}
192	return array(
193	'callbacks_attributed' => $attributed,
194	'callbacks_unavailable' => $unavailable,
195	'registry_status' => $registryUnavailable
196	? 'unavailable'
197	: ($unavailable === 0 ? 'ready' : 'partial'),
198	);
199	}
200
201	/**
202	* @param array{callback: string, source: string, has_reference: bool} $identity
203	* @return array{fields: array<string, mixed>, started_at: float\|null}\|null
204	*/
205	private function beginHookCallback(
206	string $registeredHook,
207	string $actualHook,
208	int $priority,
209	int $callbackOrdinal,
210	array $identity
211	): ?array {
212	if ($this->recording \|\| $this->lifecycleTracer->isRecording()) {
213	return null;
214	}
215	$fields = array(
216	'filter_hook' => $this->filterHook,
217	'registered_hook' => ABJ_404_Solution_HookCallbackIdentity::hookName($registeredHook),
218	'hook' => ABJ_404_Solution_HookCallbackIdentity::hookName($actualHook),
219	'callback' => $identity['callback'],
220	'source' => $identity['source'],
221	'priority' => ABJ_404_Solution_HookCallbackIdentity::jsonSafePriority($priority),
222	'callback_ordinal' => $callbackOrdinal,
223	);
224	$fields['operation_id'] = $this->operationId('response_control_filter_callback');
225	$this->write('response_control_filter_callback_start', $fields);
226	return array('fields' => $fields, 'started_at' => self::nowFloat());
227	}
228
229	/** @param array{fields: array<string, mixed>, started_at: float\|null}\|null $token */
230	private function finishHookCallback($token): void {
231	if (!is_array($token)) {
232	return;
233	}
234	$this->write('response_control_filter_callback_end', array_merge($token['fields'], array(
235	'status' => 'complete',
236	'elapsed_ms' => self::elapsedMilliseconds($token['started_at']),
237	)));
238	}
239
240	private function restoreHookCallbacks(bool $scopeCompleted): void {
241	$this->hookInstrumenter->restore($scopeCompleted);
242	}
243
244	private function operationId(string $eventPrefix): string {
245	$this->operationSequence++;
246	return substr(hash(
247	'sha256',
248	$this->requestId . '\|' . $this->rawFilterHook . '\|' . $this->dispatchOrdinal
249	. '\|' . $this->operationSequence . '\|' . $eventPrefix
250	), 0, 12);
251	}
252
253	/** @param array<string, mixed> $fields */
254	private function write(string $event, array $fields): void {
255	if ($this->recording) {
256	return;
257	}
258	$this->recording = true;
259	try {
260	ABJ_404_Solution_AjaxCheckpointLogger::recordFrequent(
261	$this->requestId,
262	$event,
263	$fields
264	);
265	} catch (Throwable $e) {
266	self::reportFailure('checkpoint write failed: ' . $e->getMessage());
267	} finally {
268	$this->recording = false;
269	}
270	}
271
272	private static function nowFloat(): ?float {
273	if (function_exists('abj_clock')) {
274	return abj_clock()->nowFloat();
275	}
276	if (class_exists('ABJ_404_Solution_SystemClock')) {
277	return (new ABJ_404_Solution_SystemClock())->nowFloat();
278	}
279	return null;
280	}
281
282	private static function elapsedMilliseconds(?float $startedAt): ?int {
283	return $startedAt === null
284	? null
285	: max(0, (int)round((self::nowFloat() - $startedAt) * 1000));
286	}
287
288	private static function reportFailure(string $message): void {
289	abj404_logPhpFallback('response-control-filter-tracer', $message);
290	}
291	}
292