Expected response code "354" but got code "250", with message "250 2.1.5 Ok"

Symfony version(s) affected

6.0.19

Description

Sending Emails within the same process shortly after each other to the same recipient address randomly produces this error:

Expected response code "354" but got code "250", with message "250 2.1.5 Ok"

Resending the email later produces no error any more.

The operator of the SMTP Server says: "It has to do with pipelining. Your SMTP client is probably mashing up messages from SMTP server with different emails being sent."

Is there any chance that he is right?

How to reproduce

The event is random, approximatively once every 1000 emails - I have not found a possibility to intentionally reproduce it.

Possible Solution

No response

Additional Context

A worker process (continuously running) looks for emails to be sent. Each email is sent serial, synchroneous.

I have the same problem

We also get these; we run a single messenger process that uses a redis stream. Every few hours or so, we get this error (using google workspaces smtp server). I cannot figure out how to debug why this is happening though.

Relevant stacktrace:

Caused By: Symfony\Component\Mailer\Exception\UnexpectedResponseException · Expected response code "354" but got code "250", with message "250 2.1.5 OK z10-20020a2e8e8a000000b002e132776df4sm207562ljk.59 - gsmtp".
vendor/symfony/mailer/Transport/Smtp/SmtpTransport.php:333 Symfony\Component\Mailer\Transport\Smtp\SmtpTransport::assertResponseCode
            $codeStr = $code ? sprintf('code "%s"', $code) : 'empty code';
            $responseStr = $response ? sprintf(', with message "%s"', trim($response)) : '';
            throw new UnexpectedResponseException(sprintf('Expected response code "%s" but got ', implode('/', $codes)).$codeStr.$responseStr.'.', $code ?: 0);
        }
    }
vendor/symfony/mailer/Transport/Smtp/SmtpTransport.php:197 Symfony\Component\Mailer\Transport\Smtp\SmtpTransport::executeCommand
vendor/symfony/mailer/Transport/Smtp/EsmtpTransport.php:118 Symfony\Component\Mailer\Transport\Smtp\EsmtpTransport::executeCommand
vendor/symfony/mailer/Transport/Smtp/SmtpTransport.php:219 Symfony\Component\Mailer\Transport\Smtp\SmtpTransport::doSend
vendor/symfony/mailer/Transport/AbstractTransport.php:90 Symfony\Component\Mailer\Transport\AbstractTransport::send
vendor/symfony/mailer/Transport/Smtp/SmtpTransport.php:137 Symfony\Component\Mailer\Transport\Smtp\SmtpTransport::send
vendor/symfony/mailer/Transport/Transports.php:51 Symfony\Component\Mailer\Transport\Transports::send
vendor/symfony/mailer/Messenger/MessageHandler.php:31 Symfony\Component\Mailer\Messenger\MessageHandler::__invoke
vendor/symfony/messenger/Middleware/HandleMessageMiddleware.php:152 Symfony\Component\Messenger\Middleware\HandleMessageMiddleware::callHandler
vendor/symfony/messenger/Middleware/HandleMessageMiddleware.php:91 Symfony\Component\Messenger\Middleware\HandleMessageMiddleware::handle
vendor/symfony/messenger/Middleware/SendMessageMiddleware.php:71 Symfony\Component\Messenger\Middleware\SendMessageMiddleware::handle
vendor/symfony/messenger/Middleware/FailedMessageProcessingMiddleware.php:34 Symfony\Component\Messenger\Middleware\FailedMessageProcessingMiddleware::handle
vendor/symfony/messenger/Middleware/DispatchAfterCurrentBusMiddleware.php:68 Symfony\Component\Messenger\Middleware\DispatchAfterCurrentBusMiddleware::handle
vendor/symfony/messenger/Middleware/RejectRedeliveredMessageMiddleware.php:41 Symfony\Component\Messenger\Middleware\RejectRedeliveredMessageMiddleware::handle
vendor/symfony/messenger/Middleware/AddBusNameStampMiddleware.php:37 Symfony\Component\Messenger\Middleware\AddBusNameStampMiddleware::handle
vendor/symfony/messenger/MessageBus.php:70 Symfony\Component\Messenger\MessageBus::dispatch
vendor/symfony/messenger/RoutableMessageBus.php:54 Symfony\Component\Messenger\RoutableMessageBus::dispatch
vendor/symfony/messenger/Worker.php:162 Symfony\Component\Messenger\Worker::handleMessage
vendor/symfony/messenger/Worker.php:109 Symfony\Component\Messenger\Worker::run
vendor/symfony/messenger/Command/ConsumeMessagesCommand.php:235 Symfony\Component\Messenger\Command\ConsumeMessagesCommand::execute
vendor/symfony/console/Command/Command.php:326 Symfony\Component\Console\Command\Command::run
vendor/symfony/console/Application.php:1096 Symfony\Component\Console\Application::doRunCommand
vendor/symfony/framework-bundle/Console/Application.php:126 Symfony\Bundle\FrameworkBundle\Console\Application::doRunCommand
vendor/symfony/console/Application.php:324 Symfony\Component\Console\Application::doRun
vendor/symfony/framework-bundle/Console/Application.php:80 Symfony\Bundle\FrameworkBundle\Console\Application::doRun
vendor/symfony/console/Application.php:175 Symfony\Component\Console\Application::run
vendor/symfony/runtime/Runner/Symfony/ConsoleApplicationRunner.php:49 Symfony\Component\Runtime\Runner\Symfony\ConsoleApplicationRunner::run
vendor/autoload_runtime.php:29 require_once
app/console:13 [main]

@alcohol try set your config smtp config ping_threshold=9

https://symfony.com/doc/current/mailer.html#other-options

smtp://USERNAME:PASSWORD@default?ping_threshold=9

Can you elaborate why?

I am experiencing the same problem, although my setup differs slightly as my worker is frequently restarted.
I've observed that the issue consistently occurs immediately after a timeout error from the previous message.

For instance:

Message N: Connection to "xxx:587" timed out.
Message N+1: Expected response code "354" but got code "250", with message "250 2.1.5 Recipient OK".

Typically, this happens approximately every 1000 messages, though occasionally it works for up to 10,000 messages. Note that I send between 4 and 10 messages per process.
Since my setup allows for it, I've implemented the following workaround: whenever I encounter a timeout error, I restart the process.
I will continue to monitor the messages to see if the issue persists.

Nice catch @HexDestroyer , it happens after timeouts for us too:

In our setup, we run two parallel processes with supervisor with the following params:

messenger:consume mailer --limit 100 --time-limit=600 --sleep=10

The problem is that the message handler will run further (and exit normally due to other consumer settings), but it probably should just fail out after the timeout error, because it currently loses the correct state in the SMTP protocol.

Now that you mention it, I too am seeing that these response code failures are coinciding with timeout failures.

Looks like adding --failure-limit=1 to our systemd managed process does the job for now.