diff --git a/src/Commands/core/DrupalCommands.php b/src/Commands/core/DrupalCommands.php index ed19c5e24b..215de40c32 100644 --- a/src/Commands/core/DrupalCommands.php +++ b/src/Commands/core/DrupalCommands.php @@ -6,10 +6,12 @@ use Consolidation\OutputFormatters\StructuredData\RowsOfFields; use Drupal\Core\CronInterface; +use Drupal\Core\Database\Connection; use Drupal\Core\Extension\ModuleHandlerInterface; use Drupal\Core\Routing\RouteProviderInterface; use Drupal\Core\Url; use Drush\Attributes as CLI; +use Drush\Boot\DrupalBootLevels; use Drush\Commands\AutowireTrait; use Drush\Commands\DrushCommands; use Drush\Drupal\DrupalUtil; @@ -39,6 +41,7 @@ public function getRouteProvider(): RouteProviderInterface } public function __construct( + protected Connection $connection, protected CronInterface $cron, protected ModuleHandlerInterface $moduleHandler, protected RouteProviderInterface $routeProvider @@ -50,12 +53,168 @@ public function __construct( * Run all cron hooks in all active modules for specified site. * * Consider using `drush maint:status && drush core:cron` to avoid cache poisoning during maintenance mode. + * + * @command core:cron + * @aliases cron,core-cron + * @topics docs:cron + * @option show-drupal-logs Display Drupal watchdog logs generated during cron execution. + * @option log-severity Minimum severity level for displayed logs (emergency=0, alert=1, critical=2, error=3, warning=4, notice=5, info=6, debug=7). Defaults to 6 (info). + * @option log-type Filter logs by type (e.g., 'cron', 'php', 'system'). + * @usage drush core:cron + * Run cron normally. + * @usage drush core:cron --show-drupal-logs + * Run cron and display Drupal logs generated during execution. + * @usage drush core:cron --show-drupal-logs --log-severity=4 + * Run cron and show only warnings and higher severity logs. + * @usage drush core:cron --show-drupal-logs --log-type=cron + * Run cron and show only cron-related logs. */ #[CLI\Command(name: self::CRON, aliases: ['cron', 'core-cron'])] - #[CLI\Topics(topics: [DocsCommands::CRON])] - public function cron(): bool + #[CLI\Option(name: 'show-drupal-logs', description: 'Display Drupal watchdog logs generated during cron execution.')] + #[CLI\Option(name: 'log-severity', description: 'Minimum severity level for displayed logs (0-7). Defaults to 6 (info).')] + #[CLI\Option(name: 'log-type', description: 'Filter logs by type.')] + #[CLI\Topics(topics: ['docs:cron'])] + #[CLI\Bootstrap(level: DrupalBootLevels::FULL)] + public function cron($options = [ + 'show-drupal-logs' => false, + 'log-severity' => 6, + 'log-type' => self::REQ, + ]): void + { + // Get the last watchdog ID before running cron + $lastWid = null; + if ($options['show-drupal-logs']) { + // Only check if dblog module is enabled + if (!$this->moduleHandler->moduleExists('dblog')) { + throw new \Exception(dt('The dblog module must be enabled to use --show-drupal-logs option.')); + } + $lastWid = $this->getLastWatchdogId(); + } + + // Run cron + $this->getCron()->run(); + + // Display Drupal logs if requested + if ($options['show-drupal-logs'] && $lastWid !== null) { + $this->displayCronLogs($lastWid, (int) $options['log-severity'], $options['log-type']); + } + } + + /** + * Get the last watchdog entry ID. + * + * @return int|null + */ + protected function getLastWatchdogId(): ?int { - return $this->getCron()->run(); + try { + $result = $this->connection->select('watchdog', 'w') + ->fields('w', ['wid']) + ->orderBy('wid', 'DESC') + ->range(0, 1) + ->execute() + ->fetchField(); + + return $result ? (int) $result : 0; + } catch (\Exception $e) { + $this->logger()->warning('Could not retrieve last watchdog ID: ' . $e->getMessage()); + return null; + } + } + + /** + * Display watchdog logs generated since the given ID. + * + * @param int $last_wid The last watchdog ID before cron ran + * @param int $min_severity Minimum severity level to display + * @param string|null $log_type Optional type filter + */ + protected function displayCronLogs(int $last_wid, int $min_severity, ?string $log_type): void + { + $query = $this->connection->select('watchdog', 'w') + ->fields('w', ['wid', 'timestamp', 'type', 'severity', 'message', 'variables']) + ->condition('wid', $last_wid, '>') + ->orderBy('wid', 'ASC'); + + if ($min_severity < 7) { + $query->condition('severity', $min_severity, '<='); + } + + if ($log_type) { + $query->condition('type', $log_type); + } + + $logs = $query->execute()->fetchAll(); + + if (!empty($logs)) { + $this->logger()->notice(dt('Drupal logs generated during cron execution:')); + $this->logger()->notice(str_repeat('-', 80)); + + foreach ($logs as $log) { + $timestamp = date('Y-m-d H:i:s', (int) $log->timestamp); + + $severity_labels = [ + 0 => 'EMERGENCY', + 1 => 'ALERT', + 2 => 'CRITICAL', + 3 => 'ERROR', + 4 => 'WARNING', + 5 => 'NOTICE', + 6 => 'INFO', + 7 => 'DEBUG', + ]; + + $severity_label = $severity_labels[$log->severity] ?? 'UNKNOWN'; + + // Format message + $message = $this->formatLogMessage($log->message, $log->variables); + + // Output using logger based on severity + if ($log->severity <= 2) { + $this->logger()->error(dt("[$timestamp] [$severity_label] [{$log->type}] $message")); + } elseif ($log->severity <= 4) { + $this->logger()->warning(dt("[$timestamp] [$severity_label] [{$log->type}] $message")); + } else { + $this->logger()->notice(dt("[$timestamp] [$severity_label] [{$log->type}] $message")); + } + } + + $this->logger()->notice(str_repeat('-', 80)); + $this->logger()->success(dt('Total logs displayed: @count', ['@count' => count($logs)])); + } else { + $this->logger()->notice(dt('No Drupal logs generated during cron execution.')); + } + } + + /** + * Format a log message by replacing placeholders and sanitizing content. + * + * @param string $message + * The log message with placeholders (e.g., 'User @name logged in'). + * @param string|null $variables + * Serialized array of placeholder replacements. + * + * @return string + * The formatted message with HTML stripped and truncated if needed. + */ + protected function formatLogMessage(string $message, ?string $variables): string + { + if (!empty($variables)) { + $variables_array = @unserialize($variables); + if (is_array($variables_array)) { + $message = strtr($message, $variables_array); + } + } + + // Strip HTML tags + $message = strip_tags($message); + + // Truncate long messages + if (strlen($message) > 200) { + $message = substr($message, 0, 197) . '...'; + } + + return $message; } /** diff --git a/tests/integration/CronShowLogsTest.php b/tests/integration/CronShowLogsTest.php new file mode 100644 index 0000000000..ae2d9c4227 --- /dev/null +++ b/tests/integration/CronShowLogsTest.php @@ -0,0 +1,121 @@ +drush('core:cron'); + $output = $this->getErrorOutput(); + + // Should not contain log output header + $this->assertStringNotContainsString('Drupal logs generated during cron execution:', $output); + } + + /** + * Test cron with --show-drupal-logs when dblog is enabled. + */ + public function testCronShowLogsWithDblog(): void + { + // Enable dblog module + $this->drush('pm:enable', ['dblog']); + + // Run cron with --show-drupal-logs + $this->drush('core:cron', [], ['show-drupal-logs' => null]); + $output = $this->getErrorOutput(); + + // Should contain log output header or "No Drupal logs" message + $this->assertTrue( + str_contains($output, 'Drupal logs generated during cron execution:') || + str_contains($output, 'No Drupal logs generated during cron execution.') + ); + } + + /** + * Test cron with --show-drupal-logs and actual log generation. + */ + public function testCronShowLogsGeneratesOutput(): void + { + // Enable dblog + $this->drush('pm:enable', ['dblog']); + + // Clear existing logs + $this->drush('watchdog:delete', ['all'], ['yes' => true]); + + // Create a log entry + $eval = "\\Drupal::logger('test')->info('Test cron log message');"; + $this->drush('php:eval', [$eval]); + + // Run cron with --show-drupal-logs + $this->drush('core:cron', [], ['show-drupal-logs' => null]); + $output = $this->getErrorOutput(); + + // Should show logs section + $this->assertStringContainsString('Drupal logs generated during cron execution:', $output); + } + + /** + * Test cron with --show-drupal-logs and --log-severity filter. + */ + public function testCronShowLogsWithSeverityFilter(): void + { + // Enable dblog + $this->drush('pm:enable', ['dblog']); + + // Clear logs + $this->drush('watchdog:delete', ['all'], ['yes' => true]); + + // Create logs with different severities + $eval1 = "\\Drupal::logger('test')->info('Test info message');"; + $eval2 = "\\Drupal::logger('test')->warning('Test warning message');"; + $this->drush('php:eval', [$eval1]); + $this->drush('php:eval', [$eval2]); + + // Run cron with severity filter (only warnings and above, level 4) + $this->drush('core:cron', [], ['show-drupal-logs' => null, 'log-severity' => 4]); + $output = $this->getErrorOutput(); + + // Should contain WARNING but not INFO + if (str_contains($output, 'Drupal logs generated during cron execution:')) { + $this->assertStringContainsString('WARNING', $output); + } + } + + /** + * Test cron with --show-drupal-logs and --log-type filter. + */ + public function testCronShowLogsWithTypeFilter(): void + { + // Enable dblog + $this->drush('pm:enable', ['dblog']); + + // Clear logs + $this->drush('watchdog:delete', ['all'], ['yes' => true]); + + // Create logs with different types + $eval1 = "\\Drupal::logger('test_type')->info('Test message');"; + $eval2 = "\\Drupal::logger('other_type')->info('Other message');"; + $this->drush('php:eval', [$eval1]); + $this->drush('php:eval', [$eval2]); + + // Run cron with type filter + $this->drush('core:cron', [], ['show-drupal-logs' => null, 'log-type' => 'test_type']); + $output = $this->getErrorOutput(); + + // Should only show logs of filtered type + if (str_contains($output, 'Drupal logs generated during cron execution:')) { + $this->assertStringContainsString('[test_type]', $output); + } + } +}