[Mailer] Memory leaking when sending many emails

[alexkingdom]

Symfony version(s) affected

5.3, 5.4

Description

This problem I had before (https://stackoverflow.com/questions/67248353/symfony-5-memory-leaking-when-send-multiple-emails-through-mailer) but it fixed after upgrading Symfony.

Now I started to have again problems related mailer when sending many emails through command.

Code inside execute method of command:

    // Total Users
    $totalRecords = $this->getUserRepository()->count(['newsletter' => true]);

    if ($totalRecords === 0) {
        $output->writeln('No records found');

        return Command::SUCCESS;
    }

    $offers = $this->fetchOffersByType($type);
    $totalOffers = count($offers);

    // Check if we have popular offers
    if ($totalOffers === 0) {
        $output->writeln('No Offers was found');

        return Command::SUCCESS;
    }

    $totalPages = ceil($totalRecords / self::BUFFER_SIZE);

    // Initializing one time and assign to users
    $newsletter = (new Newsletter())
        ->setSentAt(new DateTime())
        ->setType(NewsletterType::MAP[$type]);

    $totalSuccessSent = 0;
    $total = 0;
    for ($page = 1; $page <= $totalPages; $page++) {
        // Get users to who we will send newsletters
        $users = $this->getUserRepository()
            ->findBy(['newsletter' => true], null, self::BUFFER_SIZE, self::BUFFER_SIZE * ($page - 1));

        foreach ($users as $user) {
            $total++;
            if (empty($user->getEmail())) {
                continue;
            }

            if ($this->emailService->sendNewsletter($user, $type, $offers)) {
                $user->addNewsletter($newsletter);

                $this->em->persist($user);
                $totalSuccessSent++;
            }
        }

        $this->em->flush();

        // Make clean up after specific number of users
        if ($total % self::CLEAN_UP_AFTER === 0) {
            $output->writeln('Clean Up');
            $this->em->clear();
            gc_collect_cycles();
        }
    }

And here is the piece of method sendNewsletter:

     try {
        $email = (new TemplatedEmail())
            ->from(new Address($this->parameterBag->get('noReplayEmail'), $this->parameterBag->get('noReplayEmailName')))
            ->to($user->getEmail())
            ->priority(Email::PRIORITY_NORMAL)
            ->subject($subject)
            ->htmlTemplate($template)
            ->context([
                'offers' => $offers,
            ]);

        $this->mailer->send($email);

        return true;
    } catch (TransportExceptionInterface | RfcComplianceException | JsonException $e) {
        return false;
    }

If to comment $this->mailer->send($email) no problem at all. For testing I'm using dsn: null://null

Upgrading / downgrading of symfony not helped me.
I'm using right now Symfony 5.4 and php 7.4

Note: Memory limit that is used for command is 512 MB.

How to reproduce

Just create a command send many emails and on each sent email track the memory peak and you will see how it's increasing.

Possible Solution

After investigation and debugging I found that so called MessageLoggerListener (vendor/symfony/mailer/EventListener/MessageLoggerListener.php) is collecting logs but don't reset the logs.

So I decorated this listener and just reset after ever 50 events. I don't like this solution so for this reason I wrote here, maybe there is better solution.

Here is the code:

<?php

declare(strict_types=1);

namespace App\EventSubscriber;

use Symfony\Component\EventDispatcher\EventSubscriberInterface;
use Symfony\Component\Mailer\Event\MessageEvent;
use Symfony\Component\Mailer\EventListener\MessageLoggerListener;

/**
 * Decorating the listener that save logs related to message events but it not reset the data
 * and this creates memory leaking.
 *
 * Temporary solution.
 */
class MessageLoggerListenerDecorator implements EventSubscriberInterface
{
    private const BUFFER_LOG = 50;

    private MessageLoggerListener $messageLoggerListener;

    public function __construct(MessageLoggerListener $messageLoggerListener)
    {
        $this->messageLoggerListener = $messageLoggerListener;
    }

    /**
     * @inheritDoc
     */
    public static function getSubscribedEvents(): array
    {
        return [
            MessageEvent::class => ['onMessage', -255],
        ];
    }

    public function onMessage(MessageEvent $event): void
    {
        if (count($this->messageLoggerListener->getEvents()->getEvents()) >= self::BUFFER_LOG) {
            $this->messageLoggerListener->reset();
        }

        $this->messageLoggerListener->onMessage($event);
    }
}

And service.yml:

    App\EventSubscriber\MessageLoggerListenerDecorator:
        decorates: mailer.message_logger_listener
        arguments: ['@.inner']

Additional Context

No response

[alexkingdom]

Here is something similar related to Message Logger listener: #37712

[stof]

The I'm wondering why MessageLoggerListener is registered in prod. It is a debugging tool

[alexkingdom]

@stof good point.

[xabbuh]

@alexkingdom Did you manage to find out why the service is registered in the prod environment?

[alexkingdom]

@xabbuh actually no. I just use my fix.
I didn't had a chance to investigate more.

[xabbuh]

Let's close here for now then until we are able to reproduce.

[jonathantullett]

I am seeing the same problem. My logs (each mail sending iteration), with memory usage:

Without calling $mailer->send():

Environment: prod
sendEmails memory usage (new high): 36,928,944
sendEmails memory usage (enter): 36,547,136
sendEmails memory usage (enter): 36,581,336
execute memory usage (top): 36,592,808

After running all the code except for $mailer->send() for 3 emails (to hundreds of addresses), I see a peak memory usage of 38,132,568, which after some GC drops to: 36,592,808 which is fairly consistent across all the mailings.

When calling $mailer->send(), we get (for each iteration):

Environment: prod
execute memory usage (top): 13,655,512
sendEmails memory usage (new high): 40,009,544
sendEmails memory usage (new high): 48,189,048
sendEmails memory usage (new high): 55,340,568
execute memory usage (top): 54,181,304

We have a peak usage of 55,340,568 and that keeps going up, each email, until it hits the memory limit and is killed.

When I call $this->getApplication()->reset(), things look a bit better:

sendEmails memory usage (enter): 25,662,392
sendEmails memory usage (enter): 30,796,416
sendEmails memory usage (enter): 31,921,288
sendEmails memory usage (enter): 27,018,552
sendEmails memory usage (enter): 28,158,896
sendEmails memory usage (enter): 29,246,744
sendEmails memory usage (enter): 33,652,864

However there's still some creep; I'll run with this in production and see how it fares under proper loads.

This is my monolog config, should it be relevant:

monolog:
    handlers:
        main:
            type:         fingers_crossed
            action_level: critical
            handler:      grouped
        grouped:
            type:    group
            members: [streamed, deduplicated]
        streamed:
            type:  stream
            path:  'php://stdout'
            level: debug
        deduplicated:
            type:    deduplication
            handler: symfony_mailer
        symfony_mailer:
            type:         symfony_mailer
            from_email:   'prod-error@xxx'
            to_email:     ['jonathan@xxx', 'xxx@uk.teams.ms']
            subject:      'An error occurred in Production: %%message%%'
            level:        debug
            formatter:    monolog.formatter.html
            content_type: text/html

[jonathantullett]

After 18 hours since deploying the code with $this->getApplication()->reset(), memory usage remains stable (around ~32Mb) after sending many thousands of emails, so this looks to have worked around the issue for me. However, I think there's something wrong under the hood which should be addressed as I wouldn't expect it to be necessary in the prod environment. @xabbuh - I think this should be re-opened. I hope there's enough info here now for someone to be able to find the root cause.

[stof]

Well, if you use a fingers_crossed handler in a long running process, it will indeed leak memory (as it collects logs). Resetting stateful services between the processing of each message in a worker is the expected usage.

[jonathantullett]

@stof - thanks for the response.

Looks like fingers_crossed is the default recommendation from the monolog recipe, which is why I would have it configured:
https://github.com/symfony/recipes/blob/master/symfony/monolog-bundle/3.7/config/packages/monolog.yaml#L44=

Should something be updated there then?

[stof]

Well, for the webserver, this is the sane default. And for workers, this can be a good config as well if you reset stateful services properly between messages.
I'm not sure whether this resetting is enabled by default in the config of the messenger component. If not, it might make sense to update the messenger recipe.