Symfony messenger:consume not working (no exception)

Question

Symfony 5.1

I'm trying to setup an async email handler for my project. Emails are sended into Doctrine messenger_messages table but when I use the command php bin/console messenger:consume -vv, I have the [OK] Consuming messages from transports "async". message in console, but no message in the table is delivered.

Edit : It worked yesterday and it didn't worked when I tried again today. I restarted my server while the consumer was running and in the error message :

An exception occurred while executing 'SELECT m.* FROM messenger_messages m WHERE (m.delivered_at is null
  OR m.delivered_at < ?) AND (m.available_at <= ?) AND (m.queue_name = ?) ORDER BY available_at ASC LIMIT 1
  FOR UPDATE' with params ["2020-07-16 07:20:55", "2020-07-16 08:20:55", "default"]:

  SQLSTATE[HY000]: General error: 2006 MySQL server has gone away

I saw that the consumer check 'available_at <= 2020-07-16 08:20:55' while the older message in my table is available_at 2020-07-16 09:33:30. I don't know how to change that.

Edit2 : It looks like I have a timezone problem : My timezone is UTC+2 and it's 10:36 right now, but in the dev.log, the consumer is doing request for 08:36 :

[2020-07-16T08:36:44.241767+00:00] doctrine.DEBUG: "COMMIT" [] []
[2020-07-16T08:36:45.242051+00:00] doctrine.DEBUG: "START TRANSACTION" [] []
[2020-07-16T08:36:45.242341+00:00] doctrine.DEBUG: SELECT m.* FROM messenger_messages m WHERE (m.delivered_at is null OR m.delivered_at < ?) AND (m.available_at <= ?) AND (m.queue_name = ?) ORDER BY available_at ASC LIMIT 1 FOR UPDATE ["2020-07-16T07:36:45+00:00","2020-07-16T08:36:45+00:00","default"] []

Edit3 : My problem was in the php.ini used by the CLI. I had defined my timezone in the php.ini used by Symfony but not in the CLI one, so since the consumer is ran from the console, it was at UTC and not UTC+2.

My EmailHandler :

class EmailHandler implements MessageHandlerInterface
{
    private $address;
    private $mailer;

    public function __construct($address, MailerInterface $mailer)
    {
        $this->mailer = $mailer;
        $this->address = $address;
    }
    public function __invoke(Email $email)
    {
        $user =  $email->getTask()->getIdUser();
        $token = $user->getToken();
        $email = (new TemplatedEmail())
            ->from($this->address)
            ->to($user->getEmail())
            ->subject('Activation de compte Classe Virtuelle')
            ->htmlTemplate('emails/activate.html.twig')
            ->context([
                'address' => $user->getEmail(),
                'nom' => $email->getTask()->getNom(),
                'prenom' => $email->getTask()->getPrenom(),
                'token' => $token
            ]);
            $this->mailer->send($email);
    }

My Email:

class Email
{
    private $task;

    /**
     * @return mixed
     */
    public function getTask()
    {
        return $this->task;
    }

    /**
     * @param mixed $task
     */
    public function setTask($task): void
    {
        $this->task = $task;
    }
}

messenger.yaml

    framework:
    messenger:
        # Uncomment this (and the failed transport below) to send failed messages to this transport for later handling.
        # failure_transport: failed

        transports:
            # https://symfony.com/doc/current/messenger.html#transport-configuration
            async: '%env(MESSENGER_TRANSPORT_DSN)%'
            # failed: 'doctrine://default?queue_name=failed'
            # sync: 'sync://'

        routing:
            # Route your messages to the transports
            'App\Controller\Message\Email': async

.env

MESSENGER_TRANSPORT_DSN=doctrine://default

my controller

            $email = new Email();
            $email->setTask($addUser);
            $messageBus->dispatch($email);

a line added in my table when I dispatch an email in my controller

100,
"O:36:\""Symfony\\Component\\Messenger\\Envelope\"":2:{s:44:\""\0Symfony\\Component\\Messenger\\Envelope\0stamps\"";a:1:{s:46:\""Symfony\\Component\\Messenger\\Stamp\\BusNameStamp\"";a:1:{i:0;O:46:\""Symfony\\Component\\Messenger\\Stamp\\BusNameStamp\"":1:{s:55:\""\0Symfony\\Component\\Messenger\\Stamp\\BusNameStamp\0busName\"";s:21:\""messenger.bus.default\"";}}}s:45:\""\0Symfony\\Component\\Messenger\\Envelope\0message\"";O:28:\""App\\Controller\\Message\\Email\"":1:{s:34:\""\0App\\Controller\\Message\\Email\0task\"";O:17:\""App\\Entity\\Eleves\"":7:{s:21:\""\0App\\Entity\\Eleves\0id\"";N;s:26:\""\0App\\Entity\\Eleves\0id_user\"";O:16:\""App\\Entity\\Users\"":12:{s:20:\""\0App\\Entity\\Users\0id\"";N;s:29:\""\0App\\Entity\\Users\0identifiant\"";s:40:\""200c6d84e5eeeec42b1c7ea1ff2945340013f5db\"";s:21:\""\0App\\Entity\\Users\0mdp\"";s:40:\""f0f1b73b43acb236eb1388bd781189209361b8b2\"";s:23:\""\0App\\Entity\\Users\0email\"";s:20:\""[email protected]\"";s:25:\""\0App\\Entity\\Users\0id_role\"";O:16:\""App\\Entity\\Roles\"":3:{s:20:\""\0App\\Entity\\Roles\0id\"";i:1;s:26:\""\0App\\Entity\\Roles\0nom_role\"";s:10:\""ROLE_ELEVE\"";s:23:\""\0App\\Entity\\Roles\0users\"";O:33:\""Doctrine\\ORM\\PersistentCollection\"":2:{s:13:\""\0*\0collection\"";O:43:\""Doctrine\\Common\\Collections\\ArrayCollection\"":1:{s:53:\""\0Doctrine\\Common\\Collections\\ArrayCollection\0elements\"";a:0:{}}s:14:\""\0*\0initialized\"";b:0;}}s:40:\""\0App\\Entity\\Users\0commentaires_concernes\"";O:43:\""Doctrine\\Common\\Collections\\ArrayCollection\"":1:{s:53:\""\0Doctrine\\Common\\Collections\\ArrayCollection\0elements\"";a:0:{}}s:37:\""\0App\\Entity\\Users\0commentaires_ecrits\"";O:43:\""Doctrine\\Common\\Collections\\ArrayCollection\"":1:{s:53:\""\0Doctrine\\Common\\Collections\\ArrayCollection\0elements\"";a:0:{}}s:29:\""\0App\\Entity\\Users\0sousgroupes\"";O:43:\""Doctrine\\Common\\Collections\\ArrayCollection\"":1:{s:53:\""\0Doctrine\\Common\\Collections\\ArrayCollection\0elements\"";a:0:{}}s:23:\""\0App\\Entity\\Users\0actif\"";i:0;s:24:\""\0App\\Entity\\Users\0admins\"";N;s:38:\""\0App\\Entity\\Users\0sousgroupes_visibles\"";O:43:\""Doctrine\\Common\\Collections\\ArrayCollection\"":1:{s:53:\""\0Doctrine\\Common\\Collections\\ArrayCollection\0elements\"";a:0:{}}s:23:\""\0App\\Entity\\Users\0token\"";s:40:\""f3ab58732b9bf1029f3105f65d2469fd955e61b6\"";}s:22:\""\0App\\Entity\\Eleves\0nom\"";s:7:\""aezdzed\"";s:25:\""\0App\\Entity\\Eleves\0prenom\"";s:9:\""zedzdezed\"";s:28:\""\0App\\Entity\\Eleves\0id_classe\"";O:18:\""App\\Entity\\Classes\"":6:{s:22:\""\0App\\Entity\\Classes\0id\"";i:1;s:30:\""\0App\\Entity\\Classes\0nom_classe\"";s:5:\""2nde1\"";s:26:\""\0App\\Entity\\Classes\0eleves\"";O:33:\""Doctrine\\ORM\\PersistentCollection\"":2:{s:13:\""\0*\0collection\"";O:43:\""Doctrine\\Common\\Collections\\ArrayCollection\"":1:{s:53:\""\0Doctrine\\Common\\Collections\\ArrayCollection\0elements\"";a:0:{}}s:14:\""\0*\0initialized\"";b:0;}s:25:\""\0App\\Entity\\Classes\0cours\"";O:33:\""Doctrine\\ORM\\PersistentCollection\"":2:{s:13:\""\0*\0collection\"";O:43:\""Doctrine\\Common\\Collections\\ArrayCollection\"":1:{s:53:\""\0Doctrine\\Common\\Collections\\ArrayCollection\0elements\"";a:0:{}}s:14:\""\0*\0initialized\"";b:0;}s:28:\""\0App\\Entity\\Classes\0archives\"";O:33:\""Doctrine\\ORM\\PersistentCollection\"":2:{s:13:\""\0*\0collection\"";O:43:\""Doctrine\\Common\\Collections\\ArrayCollection\"":1:{s:53:\""\0Doctrine\\Common\\Collections\\ArrayCollection\0elements\"";a:0:{}}s:14:\""\0*\0initialized\"";b:0;}s:25:\""\0App\\Entity\\Classes\0profs\"";O:33:\""Doctrine\\ORM\\PersistentCollection\"":2:{s:13:\""\0*\0collection\"";O:43:\""Doctrine\\Common\\Collections\\ArrayCollection\"":1:{s:53:\""\0Doctrine\\Common\\Collections\\ArrayCollection\0elements\"";a:0:{}}s:14:\""\0*\0initialized\"";b:0;}}s:32:\""\0App\\Entity\\Eleves\0id_sousgroupe\"";O:43:\""Doctrine\\Common\\Collections\\ArrayCollection\"":1:{s:53:\""\0Doctrine\\Common\\Collections\\ArrayCollection\0elements\"";a:0:{}}s:23:\""\0App\\Entity\\Eleves\0type\"";s:6:\""Eleves\"";}}}",
[],
default,
2020-07-15 16:05:25,
2020-07-15 16:05:25,

Answer 1

Check if you configured the right timezone in php.ini. Worker pick and execute queued tasks by created_at and available_at db columns. As I see in your provided log data your PHP timezone set to UTC which is probably not intended.

log:

[2020-07-16T08:36:45.242341+00:00] doctrine.DEBUG: SELECT m.* FROM messenger_messages m WHERE (m.delivered_at is null OR m.delivered_at < ?) AND (m.available_at <= ?) AND (m.queue_name = ?) ORDER BY available_at ASC LIMIT 1 FOR UPDATE ["2020-07-16T07:36:45+00:00","2020-07-16T08:36:45+00:00","default"] []

db:

2020-07-15 16:05:25,
2020-07-15 16:05:25,

As you see message queued for 7:30 hours later.

Set proper timezone in php.ini from https://www.php.net/manual/en/timezones.php and restart the service.

if you have no idea where the php.ini located run this command:

php -i | grep php.ini