404-solution / includes / diagnostics / RoutineLogTracer.php

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

149 lines 5.0 KB

Raw Download Zip

1	<?php
2
3	if (!defined('ABSPATH')) {
4	exit;
5	}
6
7	/**
8	* Durable, privacy-safe attribution for ordinary logging reached during an
9	* instrumented table request outside the authorization and failure scopes.
10	*/
11	final class ABJ_404_Solution_RoutineLogTracer {
12
13	/** @var array<int,string> */
14	private static $operationStack = array();
15	/** @var int */
16	private static $operationSequence = 0;
17	/** @var bool */
18	private static $recording = false;
19
20	/**
21	* @template T
22	* @param array<string,mixed> $fields
23	* @param callable():T $work
24	* @return T
25	*/
26	public static function trace(string $operation, array $fields, callable $work) {
27	if (self::$recording
28	\|\| ABJ_404_Solution_AuthorizationLogTracer::isActive()
29	\|\| ABJ_404_Solution_PostAuthorizationFailureTracer::isActive()) {
30	return $work();
31	}
32	$requestId = self::requestId();
33	if ($requestId === '') {
34	return $work();
35	}
36
37	$safeOperation = self::safeToken($operation, 'operation');
38	$operationId = self::operationId($requestId, $safeOperation);
39	$identity = array(
40	'operation_id' => $operationId,
41	'operation' => $safeOperation,
42	);
43	$parent = end(self::$operationStack);
44	if (is_string($parent) && $parent !== '') {
45	$identity['parent_operation_id'] = $parent;
46	}
47	if (isset($fields['level']) && is_string($fields['level'])) {
48	$identity['level'] = self::safeToken($fields['level'], 'level');
49	}
50
51	self::recordStart($requestId, $identity);
52	self::$operationStack[] = $operationId;
53	$startedAt = self::nowFloat();
54	try {
55	$result = $work();
56	} catch (Throwable $error) {
57	array_pop(self::$operationStack);
58	self::recordEnd($requestId, array_merge($identity, array(
59	'status' => 'error',
60	'elapsed_ms' => self::elapsedMilliseconds($startedAt),
61	'result' => 'error',
62	'error' => self::errorSummary($error),
63	)));
64	throw $error;
65	}
66	array_pop(self::$operationStack);
67	self::recordEnd($requestId, array_merge($identity, array(
68	'status' => 'complete',
69	'elapsed_ms' => self::elapsedMilliseconds($startedAt),
70	'result' => self::resultSummary($result),
71	)));
72	return $result;
73	}
74
75	/** @param array<string,mixed> $fields */
76	private static function recordStart(string $requestId, array $fields): void {
77	self::$recording = true;
78	try {
79	ABJ_404_Solution_AjaxCheckpointLogger::recordFrequent(
80	$requestId,
81	'routine_log_operation_start',
82	$fields
83	);
84	} finally {
85	self::$recording = false;
86	}
87	}
88
89	/** @param array<string,mixed> $fields */
90	private static function recordEnd(string $requestId, array $fields): void {
91	self::$recording = true;
92	try {
93	ABJ_404_Solution_AjaxCheckpointLogger::recordFrequent(
94	$requestId,
95	'routine_log_operation_end',
96	$fields
97	);
98	} finally {
99	self::$recording = false;
100	}
101	}
102
103	private static function requestId(): string {
104	return class_exists('ABJ_404_Solution_AjaxDiagnosticRequestPolicy')
105	? ABJ_404_Solution_AjaxDiagnosticRequestPolicy::instrumentedRequestIdFromGlobalContext()
106	: '';
107	}
108
109	private static function operationId(string $requestId, string $operation): string {
110	self::$operationSequence++;
111	return substr(hash('sha256', $requestId . '\|' . $operation . '\|' . self::$operationSequence), 0, 12);
112	}
113
114	private static function safeToken(string $value, string $fallback): string {
115	return preg_match('/^[a-z][a-z0-9_]{0,63}$/', $value) === 1
116	? $value
117	: $fallback . '#' . substr(hash('sha256', $value), 0, 12);
118	}
119
120	/** @param mixed $result */
121	private static function resultSummary($result): string {
122	if (is_bool($result)) {
123	return $result ? 'true' : 'false';
124	}
125	return gettype($result);
126	}
127
128	/** @return array{class:string,code:int,message:string} */
129	private static function errorSummary(Throwable $error): array {
130	return array(
131	'class' => get_class($error),
132	'code' => is_int($error->getCode()) ? $error->getCode() : 0,
133	'message' => 'message#' . substr(hash('sha256', $error->getMessage()), 0, 12),
134	);
135	}
136
137	private static function nowFloat(): ?float {
138	return function_exists('abj_clock') ? abj_clock()->nowFloat() : null;
139	}
140
141	private static function elapsedMilliseconds(?float $startedAt): ?int {
142	if ($startedAt === null) {
143	return null;
144	}
145	$finishedAt = self::nowFloat();
146	return $finishedAt === null ? null : max(0, (int)round(($finishedAt - $startedAt) * 1000));
147	}
148	}
149