diff --git a/CHANGELOG.md b/CHANGELOG.md index 45522809..0b4ddd1b 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -11,6 +11,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - Asynchronous actions in the framework (pollora/hook 1.4): `Action::add(...)->async()` can queue handlers as Laravel jobs. The `queue` driver dispatches a `RunAsyncAction` job on `hooks.async.queue.connection` (the default connection when null) and on the action's `onQueue()` or `hooks.async.queue.queue`. `auto`, the default, tries the Laravel queue first once `HOOKS_ASYNC_CONNECTION` names the connection a worker runs (without a worker, jobs would never run, so the queue is opt-in), then Action Scheduler, then WP-Cron; a `sync` or `null` connection is always skipped. `via('queue')` and `HOOKS_ASYNC_DRIVER=queue` use the default connection. The job is tried once: retries are new jobs queued after the backoff, and the last failure lands in the failed jobs table. It also clears WordPress's in-memory cache before each handler, since a worker lives across jobs - `config/hooks.php`, published with `php artisan vendor:publish --tag=pollora-hooks`: default driver (`HOOKS_ASYNC_DRIVER`, `sync` in a developer's `.env` runs every handler at once), attempts, backoff, `as_user`, queue connection and name - `#[Async]`, next to `#[Action]`, makes a method asynchronous with the options of `->async()` as named parameters: `delay`, `via`, `onQueue`, `unique` (`true` or the lock duration), `tries`, `backoff`, `asUser`, `capture` and `when` (public methods of the class), `keepMissing`, `except`. On a class it applies to every `#[Action]` method, and a method's own `#[Async]` replaces it. A declaration that cannot be honoured (a hook in `except` the method does not declare, a missing or non-public `capture`/`when` method, invalid attempts, backoff or lock) is logged and the action runs synchronously; `#[Async]` on a `#[Filter]` or without `#[Action]` is logged +- `pollora:doctor` and Site Health check asynchronous actions (`async-actions`): an ignored `#[Async]` (now kept, not only logged), an unavailable default driver (every handler then runs in the request) or `via()` driver, a `HOOKS_ASYNC_CONNECTION` that is undefined or `sync`/`null`, WP-Cron events overdue for an hour while WP-Cron or Action Scheduler is in use (Pollora sets `DISABLE_WP_CRON`: a system cron must request `wp-cron.php`), jobs of a database queue waiting 15 minutes for a worker, and payloads or unique locks the daily recovery task left behind - Async handlers in the framework: debug mode follows `app.debug`, incidents go to the Laravel log, closures are signed with the application key, Eloquent models travel by class and key and are reloaded at execution, and parameters typed with a service are resolved from the container ### Fixed diff --git a/src/Attributes/Action.php b/src/Attributes/Action.php index 0e1eae4b..fad73f62 100755 --- a/src/Attributes/Action.php +++ b/src/Attributes/Action.php @@ -5,6 +5,7 @@ namespace Pollora\Attributes; use Attribute; +use Pollora\Hook\Application\Services\AsyncDeclarationFailures; use Pollora\Hook\Domain\Contract\Action as ActionService; use Pollora\Hook\Infrastructure\Services\AsyncAttributeRegistrar; use Psr\Log\LoggerInterface; @@ -46,7 +47,10 @@ public function handle( } // Asynchronously when the method or its class carries #[Async] - (new AsyncAttributeRegistrar($actionService, $this->logger($serviceLocator)))->register( + $logger = $this->optional($serviceLocator, LoggerInterface::class); + $failures = $this->optional($serviceLocator, AsyncDeclarationFailures::class); + + (new AsyncAttributeRegistrar($actionService, $logger, $failures))->register( $attribute->hook, $instance, $context, @@ -56,16 +60,21 @@ public function handle( } /** - * The application logger, when the service locator provides one. + * A service the service locator may not provide: the logger, the record of ignored #[Async]. + * + * @template T of object + * + * @param class-string $class + * @return T|null */ - private function logger(object $serviceLocator): ?LoggerInterface + private function optional(object $serviceLocator, string $class): ?object { try { - $logger = $serviceLocator->get(LoggerInterface::class); + $service = $serviceLocator->get($class); } catch (\Throwable) { return null; } - return $logger instanceof LoggerInterface ? $logger : null; + return $service instanceof $class ? $service : null; } } diff --git a/src/Hook/Application/Services/AsyncDeclarationFailures.php b/src/Hook/Application/Services/AsyncDeclarationFailures.php new file mode 100644 index 00000000..c92f7ad7 --- /dev/null +++ b/src/Hook/Application/Services/AsyncDeclarationFailures.php @@ -0,0 +1,33 @@ + Reason, by method ("Class::method()") + */ + private array $failures = []; + + public function fail(string $class, string $method, string $reason): void + { + $this->failures[sprintf('%s::%s()', ltrim($class, '\\'), $method)] = $reason; + } + + /** + * @return array Reason, by method ("Class::method()") + */ + public function all(): array + { + return $this->failures; + } +} diff --git a/src/Hook/Infrastructure/Checks/AsyncActionsCheck.php b/src/Hook/Infrastructure/Checks/AsyncActionsCheck.php new file mode 100644 index 00000000..1ce6440f --- /dev/null +++ b/src/Hook/Infrastructure/Checks/AsyncActionsCheck.php @@ -0,0 +1,238 @@ +failures->all(); + $registrations = $this->inspector->registrations(); + + if ($failures === [] && $registrations === []) { + return CheckResult::ok('No asynchronous action registered.'); + } + + /** @var list $errors Line and fix */ + $errors = []; + /** @var list $warnings Line and fix */ + $warnings = []; + + foreach ($failures as $method => $reason) { + $errors[] = [sprintf('%s: #[Async] is ignored, the action runs synchronously — %s', $method, $reason), 'Fix the #[Async] declaration named in each line, then run php artisan discovery:clear']; + } + + $default = Async::defaultDriver(); + $defaultProblem = $this->unavailable($default); + + if ($defaultProblem !== null) { + $errors[] = [sprintf('The default driver "%s" is unavailable, so every asynchronous action runs inside the request that fires it: %s', $default, $defaultProblem), 'Set HOOKS_ASYNC_DRIVER (config/hooks.php async.default) to a driver this site has, or to auto']; + } + + $used = $defaultProblem === null ? [$default] : []; + + foreach ($this->requestedDrivers($registrations) as $driver => $hooks) { + $problem = $this->unavailable($driver); + + if ($problem === null) { + $used[] = $driver; + + continue; + } + + $warnings[] = [sprintf('%s ask(s) for the driver "%s", unavailable, and go(es) through "%s" instead: %s', implode(', ', $hooks), $driver, $default, $problem), sprintf('Make the driver "%s" available, or remove via()', $driver)]; + } + + $warnings = [...$warnings, ...$this->connectionProblems(), ...$this->unprocessed(array_values(array_unique($used)))]; + + $lines = static fn (array $problems): array => array_map(static fn (array $problem): string => $problem[0], $problems); + + if ($errors !== []) { + return CheckResult::error(sprintf('%d asynchronous action problem(s) that change how handlers run.', count($errors)), [...$lines($errors), ...$lines($warnings)], $errors[0][1]); + } + + if ($warnings !== []) { + return CheckResult::warning(sprintf('%d problem(s) with asynchronous actions.', count($warnings)), $lines($warnings), $warnings[0][1]); + } + + return CheckResult::ok(sprintf('%d asynchronous action(s), default driver "%s".', count($registrations), $default)); + } + + /** + * Why a driver cannot queue in this request, or null. + */ + private function unavailable(string $driver): ?string + { + try { + Async::driver($driver); + } catch (DriverUnavailable $driverUnavailable) { + return $driverUnavailable->getMessage(); + } + + return null; + } + + /** + * Hooks of the registrations that name their driver, by driver. + * + * @param list $registrations + * @return array> + */ + private function requestedDrivers(array $registrations): array + { + $drivers = []; + + foreach ($registrations as $registration) { + $driver = $registration->options->driver(); + + if ($driver !== null) { + $drivers[$driver][] = $registration->hook; + } + } + + return array_map(static fn (array $hooks): array => array_values(array_unique($hooks)), $drivers); + } + + /** + * HOOKS_ASYNC_CONNECTION names a connection the queue driver cannot use. + * + * @return list + */ + private function connectionProblems(): array + { + $connection = $this->config->get('hooks.async.queue.connection'); + + if ($connection === null) { + return []; + } + + $driver = $this->config->get(sprintf('queue.connections.%s.driver', $connection)); + + if (! is_string($driver)) { + return [[sprintf('HOOKS_ASYNC_CONNECTION names the connection "%s", which config/queue.php does not define: auto leaves the queue out', $connection), 'Set HOOKS_ASYNC_CONNECTION to a connection of config/queue.php that a worker runs']]; + } + + if (in_array($driver, ['sync', 'null'], true)) { + return [[sprintf('HOOKS_ASYNC_CONNECTION names the "%s" connection, whose %s driver %s: auto leaves the queue out', $connection, $driver, $driver === 'sync' ? 'runs jobs inside the request' : 'discards jobs'), 'Set HOOKS_ASYNC_CONNECTION to the connection a worker runs (database, redis…)']]; + } + + return []; + } + + /** + * What runs WP-Cron on this site, and so what to add when nothing does. + */ + private function cronFix(): string + { + if ($this->config->get('wordpress.use_laravel_scheduler')) { + return 'WP-Cron events are Laravel jobs here (wordpress.use_laravel_scheduler): run a queue worker, php artisan queue:work'; + } + + return $this->inspector->cronRunsOnPageLoad() + ? 'The site gets too few visits to run WP-Cron: add a system cron that requests wp-cron.php every minute' + : 'DISABLE_WP_CRON is set (Pollora sets it): add a system cron, e.g. * * * * * curl -s https://example.com/cms/wp-cron.php, or wp cron event run --due-now'; + } + + /** + * What the drivers in use queued and nothing ran. + * + * @param list $drivers + * @return list + */ + private function unprocessed(array $drivers): array + { + $problems = []; + + if (array_intersect($drivers, ['wp-cron', 'action-scheduler']) !== []) { + $overdue = $this->inspector->overdueCronEvents(self::CRON_GRACE); + + if ($overdue['count'] > 0) { + $problems[] = [ + sprintf('%d WP-Cron event(s) overdue, the oldest since %s: WP-Cron and Action Scheduler run nothing until wp-cron.php is requested', $overdue['count'], gmdate('Y-m-d H:i', (int) $overdue['oldest']).' UTC'), + $this->cronFix(), + ]; + } + } + + if (in_array('queue', $drivers, true)) { + $connection = (string) ($this->config->get('hooks.async.queue.connection') ?? $this->config->get('queue.default')); + $waiting = $this->inspector->waitingJobs($connection, self::QUEUE_GRACE); + + if ($waiting !== null && $waiting['count'] > 0) { + $problems[] = [ + sprintf('%d job(s) of the "%s" queue connection waiting since %s: no worker picks them up', $waiting['count'], $connection, gmdate('Y-m-d H:i', (int) $waiting['oldest']).' UTC'), + sprintf('Run a worker, kept alive by Supervisor or systemd: php artisan queue:work %s', $connection), + ]; + } + } + + $stranded = $this->inspector->strandedPayloads(self::MAINTENANCE_GRACE); + + if ($stranded > 0) { + $problems[] = [sprintf('%d stored payload(s) older than a day with no event to run them: the daily recovery task (%s) does not run', $stranded, 'pollora/async/recover'), 'Make sure WP-Cron runs: wp cron event run pollora/async/recover schedules them again']; + } + + $locks = $this->inspector->expiredLocks(self::MAINTENANCE_GRACE); + + if ($locks > 0) { + $problems[] = [sprintf('%d unique lock(s) expired for more than a day: the daily maintenance task (%s) does not run', $locks, 'pollora/async/recover'), 'Make sure WP-Cron runs: wp cron event run pollora/async/recover deletes them']; + } + + return $problems; + } +} diff --git a/src/Hook/Infrastructure/Providers/AsyncServiceProvider.php b/src/Hook/Infrastructure/Providers/AsyncServiceProvider.php index c8b9f7b9..03a61093 100644 --- a/src/Hook/Infrastructure/Providers/AsyncServiceProvider.php +++ b/src/Hook/Infrastructure/Providers/AsyncServiceProvider.php @@ -8,10 +8,12 @@ use Illuminate\Contracts\Config\Repository; use Illuminate\Contracts\Container\Container; use Illuminate\Support\ServiceProvider; +use Pollora\Doctor\Infrastructure\Providers\DoctorServiceProvider; use Pollora\Hook\Async\Async; use Pollora\Hook\Async\Contracts\AsyncDriver; use Pollora\Hook\Infrastructure\Async\EloquentModelReference; use Pollora\Hook\Infrastructure\Async\QueueDriver; +use Pollora\Hook\Infrastructure\Checks\AsyncActionsCheck; use Psr\Log\LoggerInterface; /** @@ -23,6 +25,7 @@ * - closures signed with the application key * - Eloquent models carried by reference * - handler parameters that are not hook arguments resolved from the container + * - the async-actions check of pollora:doctor and Site Health */ class AsyncServiceProvider extends ServiceProvider { @@ -37,6 +40,9 @@ public function boot(): void __DIR__.'/../../../../config/hooks.php' => config_path('hooks.php'), ], 'pollora-hooks'); + // A check of pollora:doctor and Site Health; tagged on boot, so it comes after the framework's own + $this->app->tag([AsyncActionsCheck::class], DoctorServiceProvider::CHECKS_TAG); + $this->configureAsync($this->app->make(Repository::class)); } diff --git a/src/Hook/Infrastructure/Providers/HookServiceProvider.php b/src/Hook/Infrastructure/Providers/HookServiceProvider.php index 61a64ce6..cf22814d 100755 --- a/src/Hook/Infrastructure/Providers/HookServiceProvider.php +++ b/src/Hook/Infrastructure/Providers/HookServiceProvider.php @@ -9,6 +9,7 @@ use Pollora\Application\Application\Services\ConsoleDetectionService; use Pollora\Hook\Adapter\Out\WordPress\Action; use Pollora\Hook\Adapter\Out\WordPress\Filter; +use Pollora\Hook\Application\Services\AsyncDeclarationFailures; use Pollora\Hook\Domain\Contract\Action as ActionContract; use Pollora\Hook\Domain\Contract\CallbackResolverInterface; use Pollora\Hook\Domain\Contract\Filter as FilterContract; @@ -74,11 +75,15 @@ public function register(): void $this->app->alias(Action::class, ActionContract::class); $this->app->alias(Filter::class, FilterContract::class); + // #[Async] declarations discovery refuses, listed by pollora:doctor + $this->app->singleton(AsyncDeclarationFailures::class); + // Register Hook Discovery $this->app->singleton(HookDiscovery::class, fn (Application $app): HookDiscovery => new HookDiscovery( $app->make(ActionContract::class), $app->make(FilterContract::class), - $app->bound(LoggerInterface::class) ? $app->make(LoggerInterface::class) : null + $app->bound(LoggerInterface::class) ? $app->make(LoggerInterface::class) : null, + $app->make(AsyncDeclarationFailures::class), )); if ($this->consoleDetectionService->isConsole()) { diff --git a/src/Hook/Infrastructure/Services/AsyncAttributeRegistrar.php b/src/Hook/Infrastructure/Services/AsyncAttributeRegistrar.php index 4cc6e430..21829005 100644 --- a/src/Hook/Infrastructure/Services/AsyncAttributeRegistrar.php +++ b/src/Hook/Infrastructure/Services/AsyncAttributeRegistrar.php @@ -6,6 +6,7 @@ use Pollora\Attributes\Action; use Pollora\Attributes\Async; +use Pollora\Hook\Application\Services\AsyncDeclarationFailures; use Pollora\Hook\Async\PendingAsync; use Pollora\Hook\Domain\Contract\Action as ActionContract; use Psr\Log\LoggerInterface; @@ -16,14 +17,15 @@ * * A declaration that cannot be honoured (an unknown hook in except, a capture * or when method that is not a public method of the class, invalid attempts, - * backoff or lock duration) is logged and the action is registered - * synchronously: the work still happens. + * backoff or lock duration) is logged, kept for pollora:doctor, and the + * action is registered synchronously: the work still happens. */ final readonly class AsyncAttributeRegistrar { public function __construct( private ActionContract $actions, private ?LoggerInterface $logger = null, + private ?AsyncDeclarationFailures $failures = null, ) {} /** @@ -63,6 +65,7 @@ public function register(string $hook, object $instance, ReflectionMethod $metho if ($problem !== null) { $this->logger?->error(sprintf('#[Async] on %s::%s() is ignored, the action runs synchronously: %s', $method->getDeclaringClass()->getName(), $method->getName(), $problem)); + $this->failures?->fail($method->getDeclaringClass()->getName(), $method->getName(), $problem); return; } diff --git a/src/Hook/Infrastructure/Services/AsyncInspector.php b/src/Hook/Infrastructure/Services/AsyncInspector.php new file mode 100644 index 00000000..da55592e --- /dev/null +++ b/src/Hook/Infrastructure/Services/AsyncInspector.php @@ -0,0 +1,188 @@ +async() or #[Async]. + * + * @return list + */ + public function registrations(): array + { + global $wp_filter; + + $registrations = []; + + foreach ((array) $wp_filter as $hook) { + foreach (is_object($hook) && isset($hook->callbacks) ? (array) $hook->callbacks : [] as $callbacks) { + foreach ((array) $callbacks as $callback) { + if (($callback['function'] ?? null) instanceof QueuedHandler) { + $registrations[] = $callback['function']; + } + } + } + } + + return $registrations; + } + + /** + * Whether WordPress runs WP-Cron on page loads. Pollora turns it off: a system cron must request wp-cron.php. + */ + public function cronRunsOnPageLoad(): bool + { + return ! defined('DISABLE_WP_CRON') || ! constant('DISABLE_WP_CRON'); + } + + /** + * WP-Cron events due for longer than that: nothing runs wp-cron.php. + * + * @return array{count: int, oldest: int|null} Count, and the timestamp of the oldest one + */ + public function overdueCronEvents(int $seconds): array + { + if (! function_exists('_get_cron_array')) { + return ['count' => 0, 'oldest' => null]; + } + + $threshold = time() - $seconds; + $count = 0; + $oldest = null; + + foreach ((array) _get_cron_array() as $timestamp => $hooks) { + if (! is_int($timestamp) || $timestamp >= $threshold) { + continue; + } + + foreach ((array) $hooks as $events) { + $count += count((array) $events); + } + + $oldest = $oldest === null ? $timestamp : min($oldest, $timestamp); + } + + return ['count' => $count, 'oldest' => $oldest]; + } + + /** + * Stored payloads dispatched longer ago than that, that no event will run: + * the daily recovery task did not schedule them again. + */ + public function strandedPayloads(int $seconds): int + { + $threshold = time() - $seconds; + $stranded = 0; + + foreach ($this->options(PayloadStore::OPTION_PREFIX) as $name => $value) { + $id = substr($name, strlen(PayloadStore::OPTION_PREFIX)); + + try { + $dispatchedAt = (new \DateTimeImmutable(AsyncPayload::fromJson($value)->origin['dispatchedAt']))->getTimestamp(); + } catch (\Throwable) { + $stranded++; + + continue; + } + + if ($dispatchedAt < $threshold && ! $this->isPending($id)) { + $stranded++; + } + } + + return $stranded; + } + + /** + * Unique locks expired longer ago than that: the daily maintenance task does not run. + */ + public function expiredLocks(int $seconds): int + { + $threshold = time() - $seconds; + + return count(array_filter($this->options(UniqueLock::OPTION_PREFIX), static fn (string $expiresAt): bool => (int) $expiresAt < $threshold)); + } + + /** + * Jobs of a database queue connection available for longer than that and never picked up: no worker runs. + * + * @return array{count: int, oldest: int|null}|null Null when the connection does not keep its jobs in a table + */ + public function waitingJobs(string $connection, int $seconds): ?array + { + $settings = $this->config->get('queue.connections.'.$connection); + + if (! is_array($settings) || ($settings['driver'] ?? null) !== 'database') { + return null; + } + + $jobs = $this->databases->connection($settings['connection'] ?? null) + ->table($settings['table'] ?? 'jobs') + ->whereNull('reserved_at') + ->where('available_at', '<', time() - $seconds); + + $count = (clone $jobs)->count(); + + return ['count' => $count, 'oldest' => $count > 0 ? (int) $jobs->min('available_at') : null]; + } + + /** + * @return array Option values, by name + */ + private function options(string $prefix): array + { + global $wpdb; + + if (! is_object($wpdb)) { + return []; + } + + $rows = $wpdb->get_results($wpdb->prepare( + "SELECT option_name, option_value FROM {$wpdb->options} WHERE option_name LIKE %s LIMIT %d", + $wpdb->esc_like($prefix).'%', + self::BATCH, + ), 'ARRAY_A'); + + $options = []; + foreach ((array) $rows as $row) { + $options[(string) $row['option_name']] = (string) $row['option_value']; + } + + return $options; + } + + private function isPending(string $id): bool + { + if (function_exists('wp_next_scheduled') && wp_next_scheduled(Async::HOOK, [$id]) !== false) { + return true; + } + + return function_exists('as_has_scheduled_action') && as_has_scheduled_action(Async::HOOK, [$id]); + } +} diff --git a/src/Hook/Infrastructure/Services/HookDiscovery.php b/src/Hook/Infrastructure/Services/HookDiscovery.php index d765cd17..3c4a3903 100644 --- a/src/Hook/Infrastructure/Services/HookDiscovery.php +++ b/src/Hook/Infrastructure/Services/HookDiscovery.php @@ -12,6 +12,7 @@ use Pollora\Discovery\Domain\Contracts\ReflectionCacheInterface; use Pollora\Discovery\Domain\Services\HasInstancePool; use Pollora\Discovery\Domain\Services\IsDiscovery; +use Pollora\Hook\Application\Services\AsyncDeclarationFailures; use Pollora\Hook\Domain\Contract\Action as ActionContract; use Pollora\Hook\Domain\Contract\Filter as FilterContract; use Psr\Log\LoggerInterface; @@ -40,7 +41,8 @@ final class HookDiscovery implements DiscoveryInterface public function __construct( private readonly ActionContract $actionService, private readonly FilterContract $filterService, - private readonly ?LoggerInterface $logger = null + private readonly ?LoggerInterface $logger = null, + private readonly ?AsyncDeclarationFailures $asyncFailures = null, ) {} /** @@ -133,7 +135,7 @@ public function apply(): void // Create instance and call method directly; asynchronously when #[Async] says so $instance = $this->getInstanceFromPool($className); - (new AsyncAttributeRegistrar($this->actionService, $this->logger))->register( + (new AsyncAttributeRegistrar($this->actionService, $this->logger, $this->asyncFailures))->register( hook: $action->hook, instance: $instance, method: $reflectionMethod, @@ -141,12 +143,14 @@ public function apply(): void ); } elseif ($hookType === 'async') { $this->logger?->error(sprintf('#[Async] on %s::%s() is ignored: the method has no #[Action] to make asynchronous.', ltrim($className, '\\'), $methodName)); + $this->asyncFailures?->fail($className, $methodName, 'the method has no #[Action] to make asynchronous'); } elseif ($hookType === 'filter') { /** @var Filter $filter */ $filter = $hookAttribute->newInstance(); if (AsyncAttributeRegistrar::isDeclaredOn($reflectionMethod)) { $this->logger?->error(sprintf('#[Async] on %s::%s() is ignored: a filter returns a value to its caller and cannot be deferred.', ltrim($className, '\\'), $methodName)); + $this->asyncFailures?->fail($className, $methodName, 'a filter returns a value to its caller and cannot be deferred'); } // Create instance and call method directly diff --git a/tests/Feature/Hook/Async/AsyncActionsCheckTest.php b/tests/Feature/Hook/Async/AsyncActionsCheckTest.php new file mode 100644 index 00000000..ed96ee04 --- /dev/null +++ b/tests/Feature/Hook/Async/AsyncActionsCheckTest.php @@ -0,0 +1,223 @@ + */ + public array $registered = []; + + public bool $cronOnPageLoad = false; + + /** @var array{count: int, oldest: int|null} */ + public array $overdue = ['count' => 0, 'oldest' => null]; + + /** @var array{count: int, oldest: int|null}|null */ + public ?array $waiting = null; + + public int $stranded = 0; + + public int $locks = 0; + + public function registrations(): array + { + return $this->registered; + } + + public function cronRunsOnPageLoad(): bool + { + return $this->cronOnPageLoad; + } + + public function overdueCronEvents(int $seconds): array + { + return $this->overdue; + } + + public function strandedPayloads(int $seconds): int + { + return $this->stranded; + } + + public function expiredLocks(int $seconds): int + { + return $this->locks; + } + + public function waitingJobs(string $connection, int $seconds): ?array + { + return $this->waiting; + } +} + +function asyncCheckDriver(bool $available): AsyncDriver +{ + return new readonly class($available) implements AsyncDriver + { + public function __construct(private bool $available) {} + + public function available(): bool + { + return $this->available; + } + + public function dispatch(AsyncPayload $payload, int $delay = 0): void {} + }; +} + +beforeEach(function (): void { + Async::flush(); + Functions\when('did_action')->justReturn(1); + Async::extend('wp-cron', fn (): AsyncDriver => asyncCheckDriver(true)); + Async::setDefaultDriver('wp-cron'); + + $this->failures = new AsyncDeclarationFailures; + $this->inspector = new AsyncCheckInspector(resolve('config'), resolve('db')); + $this->check = new AsyncActionsCheck($this->failures, $this->inspector, resolve('config')); + + $this->actions = new Action; + $this->register = function (string $hook, ?string $via = null): void { + $pending = $this->actions->add($hook, [new AsyncCheckHandler, 'handle'])->async(); + if ($via !== null) { + $pending->via($via); + } + + $this->inspector->registered[] = $this->actions->callbacks($hook)[0]['callback']; + }; +}); + +afterEach(function (): void { + Async::flush(); +}); + +it('waits for WordPress', function (): void { + Functions\when('did_action')->justReturn(0); + + expect($this->check->run(RunContext::Console)->status)->toBe(CheckStatus::Skipped); +}); + +it('passes when nothing is asynchronous', function (): void { + expect($this->check->run(RunContext::Console)->summary)->toBe('No asynchronous action registered.'); +}); + +it('passes with the registrations and the default driver', function (): void { + ($this->register)('save_post'); + + $result = $this->check->run(RunContext::Http); + + expect($result->status)->toBe(CheckStatus::Ok) + ->and($result->summary)->toBe('1 asynchronous action(s), default driver "wp-cron".'); +}); + +it('lists the #[Async] declarations discovery ignored', function (): void { + $this->failures->fail('\\App\\Hooks\\Crm', 'sync', "except names 'save_post_page', which is not a hook of its #[Action] (save_post)"); + + $result = $this->check->run(RunContext::Console); + + expect($result->status)->toBe(CheckStatus::Error) + ->and($result->details)->toBe(["App\\Hooks\\Crm::sync(): #[Async] is ignored, the action runs synchronously — except names 'save_post_page', which is not a hook of its #[Action] (save_post)"]) + ->and($result->fix)->toContain('discovery:clear'); +}); + +it('fails when the default driver is unavailable, since every handler then runs in the request', function (): void { + Async::extend('queue', fn (): AsyncDriver => asyncCheckDriver(false)); + Async::setDefaultDriver('queue'); + ($this->register)('save_post'); + + $result = $this->check->run(RunContext::Console); + + expect($result->status)->toBe(CheckStatus::Error) + ->and($result->details[0])->toStartWith('The default driver "queue" is unavailable'); +}); + +it('warns about a registration whose driver is unavailable', function (): void { + ($this->register)('save_post', 'action-scheduler'); + + $result = $this->check->run(RunContext::Console); + + expect($result->status)->toBe(CheckStatus::Warning) + ->and($result->details[0])->toStartWith('save_post ask(s) for the driver "action-scheduler", unavailable, and go(es) through "wp-cron" instead'); +}); + +it('warns when HOOKS_ASYNC_CONNECTION names a connection the queue driver cannot use', function (array $connections, string $expected): void { + config(['hooks.async.queue.connection' => 'jobs', 'queue.connections' => $connections]); + ($this->register)('save_post'); + + $result = $this->check->run(RunContext::Console); + + expect($result->status)->toBe(CheckStatus::Warning) + ->and($result->details[0])->toContain($expected); +})->with([ + 'undefined' => [[], 'which config/queue.php does not define'], + 'sync' => [['jobs' => ['driver' => 'sync']], 'runs jobs inside the request'], + 'null' => [['jobs' => ['driver' => 'null']], 'discards jobs'], +]); + +it('warns when WP-Cron events are overdue, with the fix for what runs WP-Cron', function (bool $onPageLoad, bool $laravelScheduler, string $fix): void { + config(['wordpress.use_laravel_scheduler' => $laravelScheduler]); + ($this->register)('save_post'); + $this->inspector->cronOnPageLoad = $onPageLoad; + $this->inspector->overdue = ['count' => 3, 'oldest' => 1_800_000_000]; + + $result = $this->check->run(RunContext::Console); + + expect($result->status)->toBe(CheckStatus::Warning) + ->and($result->details[0])->toBe('3 WP-Cron event(s) overdue, the oldest since 2027-01-15 08:00 UTC: WP-Cron and Action Scheduler run nothing until wp-cron.php is requested') + ->and($result->fix)->toContain($fix); +})->with([ + 'disabled' => [false, false, 'DISABLE_WP_CRON is set'], + 'on page load' => [true, false, 'too few visits'], + 'Laravel scheduler' => [false, true, 'run a queue worker'], +]); + +it('leaves overdue WP-Cron events alone when no driver in use relies on WP-Cron', function (): void { + Async::extend('queue', fn (): AsyncDriver => asyncCheckDriver(true)); + Async::setDefaultDriver('queue'); + ($this->register)('save_post'); + $this->inspector->overdue = ['count' => 3, 'oldest' => 1_800_000_000]; + + expect($this->check->run(RunContext::Console)->status)->toBe(CheckStatus::Ok); +}); + +it('warns when queued jobs wait for a worker', function (): void { + Async::extend('queue', fn (): AsyncDriver => asyncCheckDriver(true)); + config(['queue.default' => 'database']); + ($this->register)('save_post', 'queue'); + $this->inspector->waiting = ['count' => 2, 'oldest' => 1_800_000_000]; + + $result = $this->check->run(RunContext::Console); + + expect($result->status)->toBe(CheckStatus::Warning) + ->and($result->details[0])->toStartWith('2 job(s) of the "database" queue connection waiting since') + ->and($result->fix)->toContain('php artisan queue:work database'); +}); + +it('warns about payloads and locks the daily task left behind', function (): void { + ($this->register)('save_post'); + $this->inspector->stranded = 4; + $this->inspector->locks = 2; + + $result = $this->check->run(RunContext::Console); + + expect($result->status)->toBe(CheckStatus::Warning) + ->and($result->details)->toHaveCount(2) + ->and($result->details[0])->toStartWith('4 stored payload(s) older than a day') + ->and($result->details[1])->toStartWith('2 unique lock(s) expired'); +}); diff --git a/tests/Feature/Hook/Async/AsyncAttributeTest.php b/tests/Feature/Hook/Async/AsyncAttributeTest.php index a1c2a448..8506b5bb 100644 --- a/tests/Feature/Hook/Async/AsyncAttributeTest.php +++ b/tests/Feature/Hook/Async/AsyncAttributeTest.php @@ -7,6 +7,7 @@ use Pollora\Discovery\Infrastructure\Services\ReflectionCache; use Pollora\Hook\Adapter\Out\WordPress\Action; use Pollora\Hook\Adapter\Out\WordPress\Filter; +use Pollora\Hook\Application\Services\AsyncDeclarationFailures; use Pollora\Hook\Async\Async; use Pollora\Hook\Async\AsyncPayload; use Pollora\Hook\Async\QueuedHandler; @@ -32,7 +33,8 @@ public function log($level, string|Stringable $message, array $context = []): vo $this->errors[] = (string) $message; } }; - $this->registrar = new AsyncAttributeRegistrar($this->actions, $this->logger); + $this->failures = new AsyncDeclarationFailures; + $this->registrar = new AsyncAttributeRegistrar($this->actions, $this->logger, $this->failures); $this->register = function (string $class, string $method, ?string $hook = null): void { $reflection = new ReflectionMethod($class, $method); foreach ($reflection->getAttributes(ActionAttribute::class) as $action) { @@ -111,10 +113,12 @@ function registeredCallback(Action $actions, string $hook): mixed Async::assertDispatched(AsyncAttributeClassHooks::class.'@audit', fn (AsyncPayload $payload): bool => $payload->tries === 5); }); -it('registers synchronously, and logs why, a declaration it cannot honour', function (string $method, string $reason): void { +it('registers synchronously, and logs and records why, a declaration it cannot honour', function (string $method, string $reason): void { ($this->register)(AsyncAttributeInvalidHooks::class, $method); expect(registeredCallback($this->actions, 'save_post'))->toBeArray() + ->and($this->failures->all())->toHaveKey(AsyncAttributeInvalidHooks::class.'::'.$method.'()') + ->and($this->failures->all()[AsyncAttributeInvalidHooks::class.'::'.$method.'()'])->toContain($reason) ->and($this->logger->errors)->toHaveCount(1) ->and($this->logger->errors[0])->toContain(sprintf('#[Async] on %s::%s() is ignored, the action runs synchronously', AsyncAttributeInvalidHooks::class, $method)) ->and($this->logger->errors[0])->toContain($reason); @@ -129,7 +133,7 @@ function registeredCallback(Action $actions, string $hook): mixed describe('Discovery', function (): void { beforeEach(function (): void { - $this->discovery = new HookDiscovery($this->actions, new Filter, $this->logger); + $this->discovery = new HookDiscovery($this->actions, new Filter, $this->logger, $this->failures); $this->discovery->discover(new DiscoveryLocation('', __DIR__), DiscoveredClass::fromReflection(new ReflectionClass(AsyncAttributeHooks::class)), new ReflectionCache); $this->discovery->apply(); }); @@ -139,8 +143,9 @@ function registeredCallback(Action $actions, string $hook): mixed ->and(registeredCallback($this->actions, 'wp_loaded'))->toBeArray(); }); - it('logs an #[Async] on a filter, which still registers, and an #[Async] without #[Action]', function (): void { - expect($this->logger->errors)->toContain(sprintf('#[Async] on %s::filterContent() is ignored: a filter returns a value to its caller and cannot be deferred.', AsyncAttributeHooks::class)) + it('logs and records an #[Async] on a filter, which still registers, and an #[Async] without #[Action]', function (): void { + expect(array_keys($this->failures->all()))->toContain(AsyncAttributeHooks::class.'::filterContent()', AsyncAttributeHooks::class.'::orphan()') + ->and($this->logger->errors)->toContain(sprintf('#[Async] on %s::filterContent() is ignored: a filter returns a value to its caller and cannot be deferred.', AsyncAttributeHooks::class)) ->and($this->logger->errors)->toContain(sprintf('#[Async] on %s::orphan() is ignored: the method has no #[Action] to make asynchronous.', AsyncAttributeHooks::class)); }); }); diff --git a/tests/Feature/Hook/Async/AsyncInspectorTest.php b/tests/Feature/Hook/Async/AsyncInspectorTest.php new file mode 100644 index 00000000..1ed06cca --- /dev/null +++ b/tests/Feature/Hook/Async/AsyncInspectorTest.php @@ -0,0 +1,163 @@ + 0, 'blogId' => 1, 'locale' => 'en_US', 'dispatchedAt' => gmdate(DATE_ATOM, $dispatchedAt)], + ))->toJson(); +} + +/** + * Stands in for $wpdb: the options rows whose name starts with the prefix asked for. + * + * @param array $options + */ +function asyncInspectorWpdb(array $options): object +{ + return new class($options) + { + public string $options = 'wp_options'; + + private string $prefix = ''; + + public function __construct(private readonly array $rows) {} + + public function esc_like(string $text): string + { + return $text; + } + + public function prepare(string $query, string $like, int $limit): string + { + $this->prefix = rtrim($like, '%'); + + return $query; + } + + public function get_results(string $query, string $output): array + { + $rows = []; + foreach ($this->rows as $name => $value) { + if (str_starts_with($name, $this->prefix)) { + $rows[] = ['option_name' => $name, 'option_value' => $value]; + } + } + + return $rows; + } + }; +} + +beforeEach(function (): void { + Async::flush(); + $this->inspector = new AsyncInspector(resolve('config'), resolve('db')); + $this->previousWpdb = $GLOBALS['wpdb'] ?? null; +}); + +afterEach(function (): void { + Async::flush(); + $GLOBALS['wpdb'] = $this->previousWpdb; + unset($GLOBALS['wp_filter']); +}); + +it('finds the asynchronous registrations among the WordPress hooks', function (): void { + $actions = new Action; + $actions->add('save_post', [new AsyncInspectorHandler, 'handle'])->async(); + $queued = $actions->callbacks('save_post')[0]['callback']; + + $GLOBALS['wp_filter'] = [ + 'save_post' => (object) ['callbacks' => [10 => ['a' => ['function' => $queued], 'b' => ['function' => 'strlen']]]], + 'init' => (object) ['callbacks' => [10 => ['c' => ['function' => 'strlen']]]], + ]; + + expect($this->inspector->registrations())->toBe([$queued]) + ->and($queued)->toBeInstanceOf(QueuedHandler::class); +}); + +it('counts the WP-Cron events overdue for longer than the grace period', function (): void { + $now = time(); + Functions\when('_get_cron_array')->justReturn([ + $now - 7200 => ['wp_version_check' => ['k1' => []], 'pollora/async/run' => ['k2' => [], 'k3' => []]], + $now - 4000 => ['wp_update_plugins' => ['k4' => []]], + $now - 60 => ['recent' => ['k5' => []]], + $now + 600 => ['future' => ['k6' => []]], + ]); + + expect($this->inspector->overdueCronEvents(3600))->toBe(['count' => 4, 'oldest' => $now - 7200]); +}); + +it('counts stored payloads no event will run, and unreadable ones', function (): void { + $old = '11111111-1111-4111-8111-111111111111'; + $scheduled = '22222222-2222-4222-8222-222222222222'; + $recent = '33333333-3333-4333-8333-333333333333'; + Functions\when('wp_next_scheduled')->alias(fn (string $hook, array $args): int|false => $args === [$scheduled] ? time() + 3600 : false); + + $GLOBALS['wpdb'] = asyncInspectorWpdb([ + 'pollora_async_'.$old => asyncInspectorPayload($old, time() - 200_000), + 'pollora_async_'.$scheduled => asyncInspectorPayload($scheduled, time() - 200_000), + 'pollora_async_'.$recent => asyncInspectorPayload($recent, time() - 60), + 'pollora_async_44444444-4444-4444-8444-444444444444' => 'not a payload', + ]); + + expect($this->inspector->strandedPayloads(86400))->toBe(2); +}); + +it('counts the unique locks expired for longer than the grace period', function (): void { + $GLOBALS['wpdb'] = asyncInspectorWpdb([ + 'pollora_unique_a' => (string) (time() - 200_000), + 'pollora_unique_b' => (string) (time() - 60), + 'pollora_unique_c' => (string) (time() + 600), + 'pollora_async_x' => (string) (time() - 200_000), + ]); + + expect($this->inspector->expiredLocks(86400))->toBe(1); +}); + +it('counts the jobs of a database queue that no worker picked up', function (): void { + config([ + 'database.connections.testing' => ['driver' => 'sqlite', 'database' => ':memory:', 'prefix' => ''], + 'queue.connections.database' => ['driver' => 'database', 'connection' => 'testing', 'table' => 'jobs'], + ]); + Schema::connection('testing')->create('jobs', function (Blueprint $table): void { + $table->id(); + $table->string('queue'); + $table->longText('payload'); + $table->unsignedInteger('reserved_at')->nullable(); + $table->unsignedInteger('available_at'); + }); + $old = time() - 3600; + DB::connection('testing')->table('jobs')->insert([ + ['queue' => 'default', 'payload' => '{}', 'reserved_at' => null, 'available_at' => $old], + ['queue' => 'default', 'payload' => '{}', 'reserved_at' => null, 'available_at' => $old + 60], + ['queue' => 'default', 'payload' => '{}', 'reserved_at' => time(), 'available_at' => $old], + ['queue' => 'default', 'payload' => '{}', 'reserved_at' => null, 'available_at' => time()], + ]); + + expect($this->inspector->waitingJobs('database', 900))->toBe(['count' => 2, 'oldest' => $old]); +}); + +it('cannot count the jobs of a queue that keeps them elsewhere', function (): void { + config(['queue.connections.redis' => ['driver' => 'redis']]); + + expect($this->inspector->waitingJobs('redis', 900))->toBeNull() + ->and($this->inspector->waitingJobs('missing', 900))->toBeNull(); +}); diff --git a/tests/e2e/specs/doctor.spec.ts b/tests/e2e/specs/doctor.spec.ts index f970acb1..3d86b2cd 100644 --- a/tests/e2e/specs/doctor.spec.ts +++ b/tests/e2e/specs/doctor.spec.ts @@ -16,7 +16,7 @@ test('Site Health lists the Pollora checks, the web-only block check and the che // Passed tests sit in a collapsed list: read the triggers, visible or not. const results = page.locator('.health-check-accordion-trigger'); - for (const label of ['WordPress core patch', 'Composer patches lock', 'Theme, plugin and module builds', 'Blocks registered', 'Typed meta', 'Roles', 'Block bindings']) { + for (const label of ['WordPress core patch', 'Composer patches lock', 'Theme, plugin and module builds', 'Blocks registered', 'Typed meta', 'Roles', 'Block bindings', 'Asynchronous actions']) { await expect(results.filter({ hasText: label }).filter({ hasText: 'Pollora' }), label).toHaveCount(1); }