Shopware 6 Cronjob Debugging / Messenger & Scheduled Tasks

Zielsetzung

Shopware 6 Cronjob zu Debuggen und auch ein Debugging bereitzustellen ist in Shopware 6 nicht so schwierig, wenn man ein paar Feinheiten beachtet. Es sollen sowohl Fehlerausgabe und Logging im Betrieb möglich sein um die Anwendung zu Debuggen und um zu verhindern, dass Cronjobs sich in der Datenbank selbst als failed registrieren und nicht mehr ausgeführt werden. Weiterhin soll ein CLI Command zur Verfügung gestellt werden um das Debugging weiter zu vereinfachen.

Problemstellung

Shopware 6 bricht bei jedem Fehler im Cronjob so ab, dass ein Eintrag in der Datenbank festgeschrieben wird der verhindert, dass der Cronjob erneut ausgeführt wird. Im Betrieb möchte man das nicht wenn man zum Beispiel Fehler loggen oder Ausnahmen behandeln will ohne, dass gleich der ganze Cronjob ausgesetzt wird. Ein Logging vereinfacht uns das Debugging der Cronjobs und mit Hilfe eines CLI Command können wir die Kommandos bequem auf der Console debuggen.

Lösungsweg

Es soll eine abstrakte Klasse für alle Cronjobs angelegt werden, die das betreffende Loggingverhalten für Cronjobs implementiert, Fehler abfängt und speichert. Außerdem möchte ich einen Consolen-Command zur Verfügung stellen in dem ich den Cronjobs vereinfacht auf der Console debuggen kann.

Umsetzung

Als ich das Erste mal mit den Cronjobs von Shopware 6 zu tun hatte sind mir viele Probleme und merkwürdige Fehler aufgetreten.

Keine Fehlermeldungen
Bleibt in Status „queue“ stecken oder „failed“ ohne Hinweis
Debugging mit XDebug teilweise ohne Funktion

Nach ein paar Stunden mit dem Cronjob System versteht man dann aber letztendlich den Sinn hinter den Funktionen und Daten die dort durchlaufen.

Der Cronjob kann auf zwei verschiedene Wege getriggert werden:

Über den Administrationsbereich als Asynchroner Request
Über die Console, respektive über einen Cronjob aus dem System

Eine Besonderheit hierbei ist, dass man nicht einzelne Cronjobs antriggert sondern einen Prozess startet der die Cronjobs für eine gegebene Zeitspanne abarbeitet.

Den Asynchronen Request über das Backend kann deaktivieren in folgender Datei: /config/packages/shopware.yaml

shopware:
  admin_worker:
    enable_admin_worker: false

Alternativ kann man die Message Queue leeren und den Cronprozess starten mit

bin/console messenger:consume --time-limit=360
bin/console scheduled-task:run --time-limit=360

Hier ist auch schon die erste Falle versteckt. Denn wenn der Prozess läuft, dann werden alle Klassen geladen und bleiben für die 360 Sekunden für den Prozess erhalten. Deshalb scheint XDebug mit z.B. PHPStorm manchmal einfach nicht zu funktionieren oder die Anwendung reagiert nicht auf Änderungen die man macht.

Der Messenger muss Mitlaufen um die Queue abzuarbeiten.

In der Dokumentation steht, dass der Messenger eigentlich auch var_dump ausgeben müsste aber bei mir blieb er sogar bei Fehlern völlig Stumm. Diese unerklärlichen Stati-Änderungen mussten erst mal als Fehler erkannt werden. Denn auch das Steckenbleiben im Status „queue“ sowie „failed“ weißt auf einen Fehler im Script hin. Bleibt die Anwendung in „running“ hängen, dann wurde der Cronjob vermutlich abgebrochen.

Aus diesem Grund habe ich mir eine Abstrakte Klasse für meinen Cronhandler erstellt, der nicht nur die Fehler loggt, sondern dazu auch noch verhindert, dass ungewollte Stati für den Cronjob gespeichert werden.

<?php declare(strict_types=1);

namespace MyNamespace;

use Psr\Log\LoggerInterface;
use Shopware\Core\Framework\DataAbstractionLayer\EntityRepositoryInterface;
use Shopware\Core\Framework\MessageQueue\ScheduledTask\ScheduledTaskHandler;

abstract class AbstractCronHandler extends ScheduledTaskHandler
{
    protected $logger;

    public function __construct(LoggerInterface $logger, EntityRepositoryInterface $scheduledTaskRepository)
    {
        parent::__construct($scheduledTaskRepository);
        $this->logger = $logger;
    }

    public function handle($task): void
    {
        set_error_handler([$this, 'handleError');

        try {
            parent::handle($task);
        } catch(\Throwable $e) {
            $this->logException($e);
        } finally {
            restore_error_handler();
        }
    }

    public function handleError($code, $message, $file, $line)
    {
        $exception = new \ErrorException($message, $code, E_ERROR, $file, $line);
        $this->logException($exception);
        return true;
    }

    public function logException(\Throwable $e): void
    {
        $message =
            $e->getMessage() . "\n in " .
            $e->getFile() . "\n line " .
            $e->getLine() . "\n" . $e->getTraceAsString();
        $this->logger->error($message);
    }
}

Diese Klasse wird von jedem CronHandler vererbt, der dieses Verhalten aufweisen soll. Den Logger kann man über die /Resources/services.xml konfigurieren:

<?xml version="1.0" ?>

<container xmlns="http://symfony.com/schema/dic/services"
           xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
           xsi:schemaLocation="http://symfony.com/schema/dic/services http://symfony.com/schema/dic/services/services-1.0.xsd">
<service id="MyNamespace\Logger" class="Monolog\Logger">
            <factory service="Shopware\Core\Framework\Log\LoggerFactory" method="createRotating"/>
            <argument type="string">myNamespace_cron</argument>
        </service>

        <service id="MyNamespace\Cron">
            <tag name="shopware.scheduled.task" />
        </service>

        <service id="MyNamespace\CronHandler">
            <argument type="service" id="MyNamespace\Logger" />
            <tag name="messenger.message_handler" />
        </service>

</container>

Der Cronjob sieht wie folgt aus:

<?php declare(strict_types=1);

namespace Sumedia\Wbo\Cron;

use Shopware\Core\Framework\MessageQueue\ScheduledTask\ScheduledTask;

class ExportOrders extends ScheduledTask
{
    public static function getTaskName(): string
    {
        return 'myNamespace.myAction';
    }

    public static function getDefaultInterval(): int
    {
        return 360;
    }
}

Der Handler mit meiner abstrakten Klasse:

<?php declare(strict_types=1);

namespace MyNamesoace;

use Psr\Log\LoggerInterface;
use Shopware\Core\Framework\DataAbstractionLayer\EntityRepositoryInterface;
use Symfony\Component\DependencyInjection\Container;

class CronHandler extends AbstractCronHandler
{
    public function __construct(LoggerInterface $logger)
    {
        parent::__construct($logger, $scheduledTaskRepository);
    }

    public static function getHandledMessages(): iterable
    {
        return [ Cron::class ];
    }

    public function run(): void
    {
        /** do fancy stuff **/
    }
}

Damit wir aber die Anwendung nicht über die Logdateien debuggen müssen legen wir uns einen CLI Command an, der uns Fehler direkt auf der Console meldet.

<?php

/**
 * @copyright Sven Ullmann <kontakt@sumedia-webdesign.de>
 */

declare(strict_types=1);

namespace Sumedia\Wbo\Service\Wbo\Command\Cli;

use Psr\Log\LoggerInterface;
use Symfony\Component\Console\Command\Command;
use Symfony\Component\Console\Input\InputInterface;
use Symfony\Component\Console\Output\OutputInterface;
use Symfony\Component\DependencyInjection\ContainerInterface;

class ExportOrders extends Command
{
    protected static $defaultName = 'my:export-orders';

    /** @var YourInterface */
    protected $command;

    // $command is any command that implements ::execute()
    public function __construct(YourInterface $command)
    {
        $this->command = $command;
        parent::__construct();
    }

    protected function configure(): void
    {
        $this->setDescription('Exports orders');
    }

    protected function execute(InputInterface $input, OutputInterface $output): int
    {
        $this->command->execute();
        
        return 0;
    }
}

Nach dem man nun seinen Prozess mit der CLI verbunden hat kann man bequem per Console debuggen:

bin/console my:export-orders