404-solution / includes / diagnostics / DatabaseQueryFilterTracer.php

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

399 lines 14.2 KB

Raw Download Zip

1	<?php
2
3	if (!defined('ABSPATH')) {
4	exit;
5	}
6
7	/**
8	* Separates WordPress `query` filter time from database-driver time.
9	*
10	* wpdb dispatches `apply_filters('query', $sql)` before `_do_query()`. The
11	* ordinary query probe is intentionally written before wpdb starts, so without
12	* this tracer a foreign callback that never returns looks exactly like a
13	* MariaDB stall. Existing `query` and global `all` callbacks are wrapped for
14	* privacy-safe attribution, then a final PHP_INT_MAX query callback writes the
15	* driver-entry sentinel immediately before wpdb proceeds.
16	*/
17	final class ABJ_404_Solution_DatabaseQueryFilterTracer {
18
19	const MAX_CALLBACK_RECORDS = 64;
20
21	/** @var string */
22	private static $budgetRequestId = '';
23	/** @var int */
24	private static $budgetRecordCount = 0;
25	/** @var bool */
26	private static $budgetCapped = false;
27
28	/** @var string */
29	private $requestId;
30	/** @var int */
31	private $queryOrdinal;
32	/** @var string */
33	private $sqlId;
34	/** @var int */
35	private $operationSequence = 0;
36	/** @var bool */
37	private $recording = false;
38	/** @var string */
39	private $resolvedDirectory;
40	/** @var ABJ_404_Solution_HookCallbackInstrumenter<array{mode:string,fields:array<string,mixed>,started_at?:float\|null}\|null> */
41	private $instrumenter;
42	/** @var ABJ_404_Solution_HookInstrumentationLifecycleTracer */
43	private $lifecycleTracer;
44	/** @var string */
45	private $attemptId;
46	/** @var string */
47	private $recoveryId;
48	/** @var string */
49	private $recoveryBranch;
50
51	/**
52	* @template T
53	* @param array{
54	* q:int,
55	* sql_id:string,
56	* attempt_id?:string,
57	* recovery_id?:string,
58	* recovery_branch?:string
59	* }\|null $queryIdentity
60	* @param callable():T $queryCall
61	* @return T
62	*/
63	public static function trace(?array $queryIdentity, callable $queryCall) {
64	$requestId = ABJ_404_Solution_AjaxQueryTimeline::armedRequestId();
65	if ($requestId === '' \|\| $queryIdentity === null) {
66	return $queryCall();
67	}
68	self::useRequestBudget($requestId);
69	try {
70	$tracer = new self(
71	$requestId,
72	(int)($queryIdentity['q'] ?? 0),
73	is_string($queryIdentity['sql_id'] ?? null)
74	? $queryIdentity['sql_id']
75	: '',
76	is_string($queryIdentity['attempt_id'] ?? null)
77	? $queryIdentity['attempt_id']
78	: '',
79	is_string($queryIdentity['recovery_id'] ?? null)
80	? $queryIdentity['recovery_id']
81	: '',
82	is_string($queryIdentity['recovery_branch'] ?? null)
83	? $queryIdentity['recovery_branch']
84	: ''
85	);
86	} catch (Throwable $e) {
87	self::reportFailure('construction failed: ' . self::throwableSummary($e));
88	return $queryCall();
89	}
90	return $tracer->run($queryCall);
91	}
92
93	private function __construct(
94	string $requestId,
95	int $queryOrdinal,
96	string $sqlId,
97	string $attemptId = '',
98	string $recoveryId = '',
99	string $recoveryBranch = ''
100	) {
101	$this->requestId = $requestId;
102	$this->queryOrdinal = $queryOrdinal;
103	$this->sqlId = $sqlId;
104	$this->attemptId = $attemptId;
105	$this->recoveryId = $recoveryId;
106	$this->recoveryBranch = $recoveryBranch;
107	$this->resolvedDirectory =
108	ABJ_404_Solution_AjaxFrequentCheckpointWriter::resolvedDirectoryForRequest(
109	$requestId
110	);
111	$this->lifecycleTracer = new ABJ_404_Solution_HookInstrumentationLifecycleTracer(
112	$requestId,
113	'database_query_filter',
114	$this->resolvedDirectory
115	);
116	$this->instrumenter = new ABJ_404_Solution_HookCallbackInstrumenter(
117	function (
118	string $registeredHook,
119	string $actualHook,
120	int $priority,
121	array $identity,
122	int $callbackOrdinal
123	) {
124	return $this->beginCallback(
125	$registeredHook,
126	$actualHook,
127	$priority,
128	$callbackOrdinal,
129	$identity
130	);
131	},
132	function ($token): void {
133	$this->endCallback($token);
134	},
135	$this->lifecycleTracer
136	);
137	}
138
139	/**
140	* @template T
141	* @param callable():T $queryCall
142	* @return T
143	*/
144	private function run(callable $queryCall) {
145	$counts = array(
146	'callbacks_wrapped' => 0,
147	'callbacks_marked' => 0,
148	'callbacks_unavailable' => 0,
149	'registry_status' => 'unavailable',
150	);
151	$sentinelRegistered = false;
152	try {
153	foreach (array('all', 'query') as $hook) {
154	$current = $this->instrumenter->instrument($hook);
155	$counts['callbacks_wrapped'] += $current['callbacks_wrapped'];
156	$counts['callbacks_marked'] += $current['callbacks_marked'];
157	$counts['callbacks_unavailable'] += $current['callbacks_unavailable'];
158	if ($current['registry_status'] !== 'unavailable') {
159	$counts['registry_status'] = 'ready';
160	}
161	}
162
163	if (function_exists('add_filter')
164	&& isset($GLOBALS['wp_filter'])
165	&& is_array($GLOBALS['wp_filter'])) {
166	$sentinelRegistered = (bool)$this->lifecycleTracer->traceBoundary(
167	ABJ_404_Solution_HookInstrumentationLifecycleTracer::PHASE_REGISTRATION,
168	'query',
169	function (): bool {
170	return (bool)add_filter(
171	'query',
172	array($this, 'recordDriverEntry'),
173	PHP_INT_MAX,
174	1
175	);
176	}
177	);
178	}
179	} catch (Throwable $e) {
180	self::reportFailure('instrumentation install failed: ' . self::throwableSummary($e));
181	$this->restore(false, $sentinelRegistered);
182	return $queryCall();
183	}
184	$this->write('query_filter_instrumentation', array_merge($this->queryFields(), array(
185	'callbacks_attributed' => $counts['callbacks_wrapped'] + $counts['callbacks_marked'],
186	'callbacks_unavailable' => $counts['callbacks_unavailable'],
187	'registry_status' => $counts['registry_status'],
188	'driver_sentinel' => $sentinelRegistered ? 'registered' : 'unavailable',
189	'max_records' => self::MAX_CALLBACK_RECORDS,
190	)));
191
192	try {
193	$result = $queryCall();
194	} catch (Throwable $e) {
195	$this->write('query_driver_exit', array_merge($this->queryFields(), array(
196	'status' => 'failed',
197	'failure_class' => self::safeClassName(get_class($e)),
198	)));
199	$this->restore(false, $sentinelRegistered);
200	throw $e;
201	}
202	$this->write('query_driver_exit', array_merge($this->queryFields(), array(
203	'status' => 'complete',
204	)));
205	$this->restore(true, $sentinelRegistered);
206	return $result;
207	}
208
209	/**
210	* Final query filter callback: no SQL is stored and the value is returned
211	* byte-for-byte so query behavior cannot change.
212	*
213	* @param mixed $query
214	* @return mixed
215	*/
216	public function recordDriverEntry($query) {
217	$this->write('query_driver_entry', $this->queryFields());
218	return $query;
219	}
220
221	/**
222	* @param array{callback:string,source:string,has_reference:bool} $identity
223	* @return array{mode:string,fields:array<string,mixed>,started_at?:float\|null}\|null
224	*/
225	private function beginCallback(
226	string $registeredHook,
227	string $actualHook,
228	int $priority,
229	int $callbackOrdinal,
230	array $identity
231	): ?array {
232	if ($actualHook !== 'query' \|\| $this->recording \|\| $this->lifecycleTracer->isRecording()) {
233	return null;
234	}
235	$fields = array_merge($this->queryFields(), array(
236	'operation_id' => $this->operationId($registeredHook, $callbackOrdinal),
237	'registered_hook' => ABJ_404_Solution_HookCallbackIdentity::hookName($registeredHook),
238	'hook' => 'query',
239	'callback' => $identity['callback'],
240	'source' => $identity['source'],
241	'priority' => ABJ_404_Solution_HookCallbackIdentity::jsonSafePriority($priority),
242	'callback_ordinal' => $callbackOrdinal,
243	));
244	if (self::$budgetRecordCount + 2 > self::MAX_CALLBACK_RECORDS) {
245	$this->recordCapOnce();
246	ABJ_404_Solution_AjaxCheckpointLogger::recordActiveOperation(
247	$this->requestId,
248	'query_filter_callback',
249	'active',
250	$fields
251	);
252	return array('mode' => 'active', 'fields' => $fields);
253	}
254	$this->write('query_filter_callback_start', $fields);
255	self::$budgetRecordCount++;
256	return array('mode' => 'journal', 'fields' => $fields, 'started_at' => self::nowFloat());
257	}
258
259	/** @param array{mode:string,fields:array<string,mixed>,started_at?:float\|null}\|null $token */
260	private function endCallback($token): void {
261	if (!is_array($token)) {
262	return;
263	}
264	if ($token['mode'] === 'active') {
265	ABJ_404_Solution_AjaxCheckpointLogger::recordActiveOperation(
266	$this->requestId,
267	'query_filter_callback',
268	'complete',
269	$token['fields']
270	);
271	return;
272	}
273	$this->write('query_filter_callback_end', array_merge($token['fields'], array(
274	'status' => 'complete',
275	'elapsed_ms' => self::elapsedMilliseconds($token['started_at'] ?? null),
276	)));
277	self::$budgetRecordCount++;
278	}
279
280	private function recordCapOnce(): void {
281	if (self::$budgetCapped) {
282	return;
283	}
284	self::$budgetCapped = true;
285	$this->write('query_filter_callback_capped', array_merge($this->queryFields(), array(
286	'recorded' => self::$budgetRecordCount,
287	'max_records' => self::MAX_CALLBACK_RECORDS,
288	)));
289	}
290
291	private function restore(bool $completed, bool $sentinelRegistered): void {
292	if ($sentinelRegistered && function_exists('remove_filter')) {
293	try {
294	$this->lifecycleTracer->traceBoundary(
295	ABJ_404_Solution_HookInstrumentationLifecycleTracer::PHASE_REMOVAL,
296	'query',
297	function (): void {
298	remove_filter(
299	'query',
300	array($this, 'recordDriverEntry'),
301	PHP_INT_MAX
302	);
303	}
304	);
305	} catch (Throwable $e) {
306	self::reportFailure(
307	'driver sentinel removal failed: ' . self::throwableSummary($e)
308	);
309	}
310	}
311	try {
312	$this->instrumenter->restore($completed);
313	} catch (Throwable $e) {
314	self::reportFailure('callback restoration failed: ' . self::throwableSummary($e));
315	}
316	}
317
318	/** @return array<string, int\|string> */
319	private function queryFields(): array {
320	$fields = array('q' => $this->queryOrdinal, 'sql_id' => $this->sqlId);
321	if ($this->attemptId !== '') {
322	$fields['attempt_id'] = $this->attemptId;
323	$fields['recovery_id'] = $this->recoveryId;
324	$fields['recovery_branch'] = $this->recoveryBranch;
325	}
326	return $fields;
327	}
328
329	private function operationId(string $registeredHook, int $ordinal): string {
330	$this->operationSequence++;
331	return substr(hash(
332	'sha256',
333	$this->requestId . '\|' . $this->queryOrdinal . '\|' . $this->sqlId
334	. '\|' . $registeredHook . '\|' . $ordinal . '\|' . $this->operationSequence
335	), 0, 12);
336	}
337
338	/** @param array<string,mixed> $fields */
339	private function write(string $event, array $fields): void {
340	if ($this->recording) {
341	return;
342	}
343	$this->recording = true;
344	try {
345	ABJ_404_Solution_AjaxFrequentCheckpointWriter::append(
346	$this->requestId,
347	$event,
348	$fields,
349	$this->resolvedDirectory,
350	true
351	);
352	} catch (Throwable $e) {
353	self::reportFailure($event . ' write failed: ' . $e->getMessage());
354	} finally {
355	$this->recording = false;
356	}
357	}
358
359	private static function nowFloat(): ?float {
360	return function_exists('abj_clock') ? abj_clock()->nowFloat() : null;
361	}
362
363	private static function elapsedMilliseconds(?float $startedAt): ?int {
364	$now = self::nowFloat();
365	return $startedAt === null \|\| $now === null
366	? null
367	: max(0, (int)round(($now - $startedAt) * 1000));
368	}
369
370	private static function reportFailure(string $message): void {
371	abj404_logPhpFallback('database-query-filter-tracer', $message);
372	}
373
374	private static function useRequestBudget(string $requestId): void {
375	if (self::$budgetRequestId === $requestId) {
376	return;
377	}
378	self::$budgetRequestId = $requestId;
379	self::$budgetRecordCount = 0;
380	self::$budgetCapped = false;
381	}
382
383	/** Reset request-local evidence budgets between process-isolated test requests. */
384	public static function resetForTests(): void {
385	self::$budgetRequestId = '';
386	self::$budgetRecordCount = 0;
387	self::$budgetCapped = false;
388	}
389
390	private static function throwableSummary(Throwable $e): string {
391	return get_class($e) . ' code=' . $e->getCode() . ' message=' . $e->getMessage();
392	}
393
394	private static function safeClassName(string $className): string {
395	$safe = preg_replace('/[^A-Za-z0-9_\\\\-]/', '_', $className);
396	return substr(is_string($safe) ? $safe : 'Throwable', 0, 96);
397	}
398	}
399