| 1 |
<?php |
| 2 |
|
| 3 |
if (!defined('ABSPATH')) { |
| 4 |
exit; |
| 5 |
} |
| 6 |
|
| 7 |
/** |
| 8 |
* Per-stage runner / telemetry / shutdown-diagnostics infrastructure for the |
| 9 |
* staged getRedirectsForView build pipeline. |
| 10 |
* |
| 11 |
* Extracted from {@see ABJ_404_Solution_DataAccess_ViewQueriesStagedTrait} |
| 12 |
* so the orchestrator (runStagedBuildOnce) stays under the modularity cap |
| 13 |
* without losing the timing/log/inflight wiring each stage relies on. |
| 14 |
* |
| 15 |
* What lives here: |
| 16 |
* - runTimedViewBuildStage(): the wrapper every stage callback flows |
| 17 |
* through. Times the stage, catches throwables, dispatches them to the |
| 18 |
* HostFailurePolicy classifier, and emits the per-stage log line. |
| 19 |
* - runNonBatchedStageWithKillStreakEscape(): the variant used by the |
| 20 |
* non-batched stages (S3 / S9 / S10) that bumps a kill-streak counter |
| 21 |
* and swaps in an extended per-query timeout on retry. |
| 22 |
* - markViewBuildStageStarted / markViewBuildStageCompleted: persist |
| 23 |
* per-stage entry/exit markers to the progress option registry so a |
| 24 |
* resumable build can pick up where the previous request left off. |
| 25 |
* - registerViewBuildShutdownDiagnostics / logViewBuildShutdownDiagnostics |
| 26 |
* / clearViewBuildOpenStageForShutdown: register_shutdown_function |
| 27 |
* diagnostics that surface a WARN line when PHP dies mid-stage so the |
| 28 |
* post-mortem records which stage was open and the last PHP error. |
| 29 |
* - markBuildStage(): writes the inflight-stage transient that the AJAX |
| 30 |
* progress poller reads, including the "batch X/Y" inner-loop marker |
| 31 |
* captured into $lastBatchProgressDetail so a mid-stage yield doesn't |
| 32 |
* drop back to a bare "yielded in N ms" between ticks. |
| 33 |
* |
| 34 |
* Composed alongside the orchestrator trait into ABJ_404_Solution_DataAccess |
| 35 |
* so the cross-trait calls ($this->readProgressOption, $this->logger, |
| 36 |
* $this->classifyAndHandleStageFailure, $this->resetStageNoProgressStreak, |
| 37 |
* $this->extendedTimeoutForKilledNonBatchedStage, $this->stagedQueryTimeoutSeconds) |
| 38 |
* resolve through the shared composing class. |
| 39 |
*/ |
| 40 |
trait ABJ_404_Solution_DataAccess_ViewBuildStageRunnerTrait { |
| 41 |
|
| 42 |
/** @var bool Process-local guard so shutdown diagnostics register once. */ |
| 43 |
private static $viewBuildShutdownLoggerRegistered = false; |
| 44 |
|
| 45 |
/** @var bool True while a stage has started but has not reached normal logging. */ |
| 46 |
private $viewBuildStageOpenForShutdown = false; |
| 47 |
|
| 48 |
/** @var int Stage currently open for shutdown diagnostics. */ |
| 49 |
private $viewBuildShutdownStageNumber = 0; |
| 50 |
|
| 51 |
/** @var string Stage key currently open for shutdown diagnostics. */ |
| 52 |
private $viewBuildShutdownStageKey = ''; |
| 53 |
|
| 54 |
/** |
| 55 |
* Most recent "batch X/Y" progress detail captured from the inner loops of |
| 56 |
* resumable stages (S2/S4/S5). Preserved across the per-stage yield log so |
| 57 |
* the user-visible status doesn't drop from "batch 1.28M/1.97M (yielded)" |
| 58 |
* back to a bare "yielded in N ms" right before the next tick resumes. |
| 59 |
* |
| 60 |
* Reset to '' at the start of every runTimedViewBuildStage() invocation. |
| 61 |
* |
| 62 |
* @var string |
| 63 |
*/ |
| 64 |
private $lastBatchProgressDetail = ''; |
| 65 |
|
| 66 |
/** |
| 67 |
* Update the inflight stage transient + AJAX-context global so the |
| 68 |
* client-side progress poller can render which sub-stage of the staged |
| 69 |
* build is currently running. |
| 70 |
* |
| 71 |
* Best-effort: when there's no AJAX context (background cron, CLI), this |
| 72 |
* is a no-op. Never let a transient-write failure mask the real query |
| 73 |
* error we're about to raise. |
| 74 |
* |
| 75 |
* @param string $stageKey Sub-stage key, e.g. 'staged_build_s2_insert'. |
| 76 |
* @param string $detail Optional mid-stage progress detail, e.g. 'batch 4/12'. |
| 77 |
* @return void |
| 78 |
*/ |
| 79 |
private function markBuildStage(string $stageKey, string $detail = ''): void { |
| 80 |
if (!class_exists('ABJ_404_Solution_ViewUpdater')) { |
| 81 |
return; |
| 82 |
} |
| 83 |
// Capture inner-loop batch markers ("batch 1282000/1971286", |
| 84 |
// "batch ... (yielded)", "batch killed at size N; shrunk ...") so |
| 85 |
// logTimedViewBuildStage() can preserve them in the per-stage yield |
| 86 |
// marker. Skip strings that already contain ", yielded" so the final |
| 87 |
// yield write does not loop back into the captured detail. |
| 88 |
if ($detail !== '' |
| 89 |
&& strncmp($detail, 'batch ', 6) === 0 |
| 90 |
&& strpos($detail, ', yielded') === false) { |
| 91 |
$this->lastBatchProgressDetail = $detail; |
| 92 |
} |
| 93 |
$label = $detail !== '' ? ($stageKey . ':' . $detail) : $stageKey; |
| 94 |
// The class is autoloaded by Loader.php; markInflightStage is a |
| 95 |
// best-effort no-op when no AJAX context exists. |
| 96 |
\ABJ_404_Solution_ViewUpdater::markInflightStage($label); |
| 97 |
} |
| 98 |
|
| 99 |
/** |
| 100 |
* Run one staged view-build step and write a clear per-stage timing line. |
| 101 |
* |
| 102 |
* The build can span several HTTP requests. For resumable stages that yield |
| 103 |
* mid-stage (S2/S4/S5), this records the time spent in the current tick and |
| 104 |
* marks the status as yielded; the final tick for that stage is logged as |
| 105 |
* completed. |
| 106 |
* |
| 107 |
* @param int $stageNumber 1-based staged build number. |
| 108 |
* @param string $stageKey Stable stage key used by AJAX progress. |
| 109 |
* @param callable $callback Stage work to execute. |
| 110 |
* @return mixed |
| 111 |
*/ |
| 112 |
private function runTimedViewBuildStage(int $stageNumber, string $stageKey, callable $callback) { |
| 113 |
$started = microtime(true); |
| 114 |
// Reset per-stage so a yield marker for this stage cannot accidentally |
| 115 |
// pick up a prior stage's batch detail. Inner loops (S2/S4/S5) |
| 116 |
// populate this via markBuildStage() as they emit "batch X/Y" lines. |
| 117 |
$this->lastBatchProgressDetail = ''; |
| 118 |
try { |
| 119 |
$this->markViewBuildStageStarted($stageNumber, $stageKey); |
| 120 |
// Public extension point. Sites can hook this for telemetry, custom |
| 121 |
// progress dashboards, or chaos-testing the build's resume contract. |
| 122 |
// The do_action call is inside the try so a callback that throws |
| 123 |
// (test injection, host kill simulator) is treated identically to |
| 124 |
// a real SQL error from the stage callback below. |
| 125 |
if (function_exists('do_action')) { |
| 126 |
do_action('abj404_view_build_stage_starting', $stageNumber, $stageKey); |
| 127 |
} |
| 128 |
$result = $callback(); |
| 129 |
} catch (\Throwable $e) { |
| 130 |
// B17 (Bruno 2026-05-13): when the host kills our connection |
| 131 |
// mid-stage (wait_timeout < build duration, MySQL errno 2006 / |
| 132 |
// 2013, "MySQL server has gone away" / "Lost connection during |
| 133 |
// query"), explicitly reconnect BEFORE the classifier and its |
| 134 |
// option-write side effects run. queryAndGetResults() already |
| 135 |
// calls ensureConnection() on its own ingress, so this is |
| 136 |
// belt-and-suspenders for the catch-block path: if a future |
| 137 |
// refactor moved any catch-block option write outside the DAO, |
| 138 |
// a still-broken handle would silently lose the progress / |
| 139 |
// streak / notice updates the classifier depends on. The |
| 140 |
// explicit reconnect also pins the "resume from last completed |
| 141 |
// stage, not S1" contract at the stage runner level rather |
| 142 |
// than at the DAO level. ensureConnection() is idempotent |
| 143 |
// (returns true when already connected) so the cost on the |
| 144 |
// non-connection-drop paths is one mysqli_ping per stage exit. |
| 145 |
if ($this->isTransientConnectionError($e->getMessage())) { |
| 146 |
$this->ensureConnection(); |
| 147 |
} |
| 148 |
// Catch-block classification + side effects (skip / halt / streak) |
| 149 |
// live on the HostFailurePolicy trait so this orchestrator stays |
| 150 |
// focused on stage sequencing. classifyAndHandleStageFailure() |
| 151 |
// returns one of: 'resumable_yield', 'skipped', 'halted', |
| 152 |
// 'completed' (post-S11 reconcile), or 'rethrow'. |
| 153 |
$outcome = $this->classifyAndHandleStageFailure($stageNumber, $stageKey, $e->getMessage(), $started); |
| 154 |
if ($outcome === 'resumable_yield') { |
| 155 |
return false; |
| 156 |
} |
| 157 |
if ($outcome === 'skipped') { |
| 158 |
return 'skipped'; |
| 159 |
} |
| 160 |
if ($outcome === 'halted') { |
| 161 |
return 'halted'; |
| 162 |
} |
| 163 |
if ($outcome === 'completed') { |
| 164 |
return null; |
| 165 |
} |
| 166 |
$this->logTimedViewBuildStage($stageNumber, $stageKey, 'error', $started); |
| 167 |
throw $e; |
| 168 |
} |
| 169 |
|
| 170 |
$status = 'completed'; |
| 171 |
if ($result === false) { |
| 172 |
$status = 'yielded'; |
| 173 |
} else if ($result === 'skipped') { |
| 174 |
$status = 'skipped'; |
| 175 |
} |
| 176 |
// Wall-clock yield (false return) implies the stage's batch loop ran |
| 177 |
// far enough to exhaust the per-stage budget, which is observable |
| 178 |
// forward progress. Reset the no-progress streak so legitimate |
| 179 |
// long-running batched stages do not eventually trip the halt. |
| 180 |
// Completion / skip likewise reset. |
| 181 |
$this->resetStageNoProgressStreak($stageNumber); |
| 182 |
if ($status === 'completed' || $status === 'skipped') { |
| 183 |
$this->markViewBuildStageCompleted($stageNumber); |
| 184 |
} |
| 185 |
$this->logTimedViewBuildStage($stageNumber, $stageKey, $status, $started); |
| 186 |
return $result; |
| 187 |
} |
| 188 |
|
| 189 |
/** |
| 190 |
* Persist stage-start metadata before a stage does work. This survives |
| 191 |
* PHP/request death where the completion marker and catch block never run. |
| 192 |
* |
| 193 |
* @param int $stageNumber |
| 194 |
* @param string $stageKey |
| 195 |
* @return void |
| 196 |
*/ |
| 197 |
private function markViewBuildStageStarted(int $stageNumber, string $stageKey): void { |
| 198 |
$now = time(); |
| 199 |
if ($this->readProgressOption('started_at', 0) === 0) { |
| 200 |
$this->writeProgressOption('started_at', $now); |
| 201 |
} |
| 202 |
$this->writeProgressOption('last_started_stage', $stageNumber); |
| 203 |
$this->writeProgressOption('last_started_at', $now); |
| 204 |
$this->viewBuildStageOpenForShutdown = true; |
| 205 |
$this->viewBuildShutdownStageNumber = $stageNumber; |
| 206 |
$this->viewBuildShutdownStageKey = $stageKey; |
| 207 |
$this->logger->debugMessage(sprintf( |
| 208 |
'[staged] build stage %d/11 %s starting', |
| 209 |
$stageNumber, |
| 210 |
$stageKey |
| 211 |
)); |
| 212 |
} |
| 213 |
|
| 214 |
/** |
| 215 |
* @param int $stageNumber |
| 216 |
* @return void |
| 217 |
*/ |
| 218 |
private function markViewBuildStageCompleted(int $stageNumber): void { |
| 219 |
$this->writeProgressOption('last_completed_stage', $stageNumber); |
| 220 |
$this->writeProgressOption('last_completed_at', time()); |
| 221 |
} |
| 222 |
|
| 223 |
/** @return void */ |
| 224 |
private function clearViewBuildOpenStageForShutdown(): void { |
| 225 |
$this->viewBuildStageOpenForShutdown = false; |
| 226 |
$this->viewBuildShutdownStageNumber = 0; |
| 227 |
$this->viewBuildShutdownStageKey = ''; |
| 228 |
} |
| 229 |
|
| 230 |
/** @return void */ |
| 231 |
private function registerViewBuildShutdownDiagnostics(): void { |
| 232 |
if (self::$viewBuildShutdownLoggerRegistered || !function_exists('register_shutdown_function')) { |
| 233 |
return; |
| 234 |
} |
| 235 |
self::$viewBuildShutdownLoggerRegistered = true; |
| 236 |
register_shutdown_function(function () { |
| 237 |
$this->logViewBuildShutdownDiagnostics(); |
| 238 |
}); |
| 239 |
} |
| 240 |
|
| 241 |
/** @return void */ |
| 242 |
private function logViewBuildShutdownDiagnostics(): void { |
| 243 |
if (!$this->viewBuildStageOpenForShutdown) { |
| 244 |
return; |
| 245 |
} |
| 246 |
$stageNumber = $this->viewBuildShutdownStageNumber > 0 |
| 247 |
? $this->viewBuildShutdownStageNumber |
| 248 |
: $this->readProgressOption('last_started_stage', 0); |
| 249 |
if ($stageNumber <= 0) { |
| 250 |
return; |
| 251 |
} |
| 252 |
$lastCompleted = $this->readProgressOption('last_completed_stage', 0); |
| 253 |
if ($lastCompleted >= $stageNumber) { |
| 254 |
return; |
| 255 |
} |
| 256 |
|
| 257 |
$errorText = 'none'; |
| 258 |
if (function_exists('error_get_last')) { |
| 259 |
$lastError = error_get_last(); |
| 260 |
if (is_array($lastError)) { |
| 261 |
$message = isset($lastError['message']) && is_scalar($lastError['message']) |
| 262 |
? (string)$lastError['message'] : ''; |
| 263 |
$file = isset($lastError['file']) && is_scalar($lastError['file']) |
| 264 |
? (string)$lastError['file'] : ''; |
| 265 |
$line = isset($lastError['line']) && is_scalar($lastError['line']) |
| 266 |
? (string)$lastError['line'] : ''; |
| 267 |
$errorText = trim($message . ($file !== '' ? ' in ' . $file : '') . ($line !== '' ? ':' . $line : '')); |
| 268 |
if ($errorText === '') { |
| 269 |
$errorText = 'error_get_last returned an empty error'; |
| 270 |
} |
| 271 |
} |
| 272 |
} |
| 273 |
|
| 274 |
$this->logger->warn(sprintf( |
| 275 |
'[staged] shutdown while build stage %d/11 %s was still open; ' |
| 276 |
. 'last_completed_stage=%d; fatal_context=%s', |
| 277 |
$stageNumber, |
| 278 |
$this->viewBuildShutdownStageKey, |
| 279 |
$lastCompleted, |
| 280 |
substr($errorText, 0, 240) |
| 281 |
)); |
| 282 |
} |
| 283 |
|
| 284 |
/** |
| 285 |
* Run a non-batched stage (S3 / S9 / S10) with the kill-streak |
| 286 |
* escape valve applied. Behaves like runTimedViewBuildStage() except: |
| 287 |
* |
| 288 |
* - Before invoking the stage, looks up the persisted kill streak |
| 289 |
* for $streakOptKey. If >= 1, swaps in an extended per-query |
| 290 |
* timeout (extendedTimeoutForKilledNonBatchedStage) so the |
| 291 |
* SET STATEMENT max_statement_time hint can exceed the host's |
| 292 |
* session limit on retry. |
| 293 |
* - On `false` return (resumable kill), increments the streak so |
| 294 |
* the next request resumes with the extended timeout already in |
| 295 |
* effect. |
| 296 |
* - On any non-`false` return (completed or 'skipped'), resets the |
| 297 |
* streak to 0 -- the next rebuild starts fresh. |
| 298 |
* |
| 299 |
* The original $stagedQueryTimeoutSeconds is restored before |
| 300 |
* returning so subsequent stages run with their own intelligent |
| 301 |
* timeout, not the extended one (which was only meant for the |
| 302 |
* stuck non-batched stage). |
| 303 |
* |
| 304 |
* @param int $stageNumber 1-based staged build number. |
| 305 |
* @param string $stageKey Stable stage key for AJAX progress. |
| 306 |
* @param string $streakOptKey Progress option key, e.g. 's3_kill_streak'. |
| 307 |
* @param callable $callback |
| 308 |
* @return mixed Forwards runTimedViewBuildStage's return value: |
| 309 |
* typically true|null on completion, false on |
| 310 |
* resumable kill, 'skipped' when the callback |
| 311 |
* self-skips (S9 with no logs_hits table). Callers |
| 312 |
* only check `=== false` so the broader type is fine. |
| 313 |
*/ |
| 314 |
private function runNonBatchedStageWithKillStreakEscape( |
| 315 |
int $stageNumber, |
| 316 |
string $stageKey, |
| 317 |
string $streakOptKey, |
| 318 |
callable $callback |
| 319 |
) { |
| 320 |
$savedTimeout = $this->stagedQueryTimeoutSeconds; |
| 321 |
$this->stagedQueryTimeoutSeconds = $this->extendedTimeoutForKilledNonBatchedStage($streakOptKey); |
| 322 |
try { |
| 323 |
$result = $this->runTimedViewBuildStage($stageNumber, $stageKey, $callback); |
| 324 |
} finally { |
| 325 |
$this->stagedQueryTimeoutSeconds = $savedTimeout; |
| 326 |
} |
| 327 |
if ($result === false) { |
| 328 |
$this->writeProgressOption( |
| 329 |
$streakOptKey, |
| 330 |
$this->readProgressOption($streakOptKey, 0) + 1 |
| 331 |
); |
| 332 |
} else { |
| 333 |
$this->writeProgressOption($streakOptKey, 0); |
| 334 |
} |
| 335 |
return $result; |
| 336 |
} |
| 337 |
|
| 338 |
/** |
| 339 |
* @param int $stageNumber |
| 340 |
* @param string $stageKey |
| 341 |
* @param string $status |
| 342 |
* @param float $started |
| 343 |
* @return void |
| 344 |
*/ |
| 345 |
private function logTimedViewBuildStage(int $stageNumber, string $stageKey, string $status, float $started): void { |
| 346 |
$elapsedMs = (int)round((microtime(true) - $started) * 1000); |
| 347 |
$markerDetail = $status . ' in ' . $elapsedMs . ' ms'; |
| 348 |
// Preserve mid-stage batch progress in the user-visible yield marker |
| 349 |
// so the polled status does not drop from "batch 1282000/1971286 |
| 350 |
// (yielded; tight time)" back to a bare "yielded in N ms" between |
| 351 |
// ticks. Only applied to yield-class statuses; "completed" already |
| 352 |
// reads cleanly without batch context. |
| 353 |
if (($status === 'yielded' || $status === 'killed_resumable') |
| 354 |
&& $this->lastBatchProgressDetail !== '') { |
| 355 |
$markerDetail = $this->lastBatchProgressDetail . ', ' . $markerDetail; |
| 356 |
} |
| 357 |
$this->markBuildStage($stageKey, $markerDetail); |
| 358 |
$this->logger->debugMessage(sprintf( |
| 359 |
'[staged] build stage %d/11 %s %s in %d ms', |
| 360 |
$stageNumber, |
| 361 |
$stageKey, |
| 362 |
$status, |
| 363 |
$elapsedMs |
| 364 |
)); |
| 365 |
$this->clearViewBuildOpenStageForShutdown(); |
| 366 |
} |
| 367 |
} |
| 368 |
|
