bug #39598 [Messenger] Fix stopwach usage if it has been reset (lyrixx)

This PR was merged into the 4.4 branch.

Discussion
----------

[Messenger] Fix stopwach usage if it has been reset

| Q             | A
| ------------- | ---
| Branch?       | 4.4
| Bug fix?      | yes
| New feature?  | no
| Deprecations? | no
| Tickets       |
| License       | MIT
| Doc PR        |

I'm slowly migrating an application to messenger (from swarrot) and I
hit a strange bug. My message was well processeed **BUT** retry!

It comes from two things

* I manually reset the application (via the service resetter, to keep a
low memory usage)
* symfony/messenger try to collect some information, but since the
stopwatch has been reset, an exception occurs and the message has been
retried

So this patch avoid throwing an exception when everything works well

<details>

<summary>the trace:</summary>

```

18:45:41 INFO      [messenger] Message AppBundle\Crawler\Messenger\Message\CrawlSitemapMessage handled by AppBundle\Crawler\Messenger\MessageHandler\CrawlSitemapMessageHa
ndler::__invoke
[
  "message" => AppBundle\Crawler\Messenger\Message\CrawlSitemapMessage^ {
    -crawlId: "885d23a7-8ad5-4935-a2b3-1c114ac76ded"
  },
  "class" => "AppBundle\Crawler\Messenger\Message\CrawlSitemapMessage",
  "handler" => "AppBundle\Crawler\Messenger\MessageHandler\CrawlSitemapMessageHandler::__invoke"
]
18:45:41 ERROR     [messenger] Error thrown while handling message AppBundle\Crawler\Messenger\Message\CrawlSitemapMessage. Sending for retry #1 using 1000 ms delay. Erro
r: "Event ""Symfony\Component\Messenger\Middleware\HandleMessageMiddleware" on "messenger.bus.default"" is not started."
[
  "message" => AppBundle\Crawler\Messenger\Message\CrawlSitemapMessage^ {
    -crawlId: "885d23a7-8ad5-4935-a2b3-1c114ac76ded"
  },
  "class" => "AppBundle\Crawler\Messenger\Message\CrawlSitemapMessage",
  "retryCount" => 1,
  "delay" => 1000,
  "error" => "Event ""Symfony\Component\Messenger\Middleware\HandleMessageMiddleware" on "messenger.bus.default"" is not started.",
  "exception" => LogicException {
    #message: "Event ""Symfony\Component\Messenger\Middleware\HandleMessageMiddleware" on "messenger.bus.default"" is not started."
    #code: 0
    #file: "./vendor/symfony/symfony/src/Symfony/Component/Stopwatch/Section.php"
    #line: 142
    trace: {
      ./vendor/symfony/symfony/src/Symfony/Component/Stopwatch/Section.php:142 { …}
      ./vendor/symfony/symfony/src/Symfony/Component/Stopwatch/Stopwatch.php:126 { …}
      ./vendor/symfony/symfony/src/Symfony/Component/Messenger/Middleware/TraceableMiddleware.php:75 { …}
      ./vendor/symfony/symfony/src/Symfony/Component/Messenger/Middleware/HandleMessageMiddleware.php:83 { …}
      ./vendor/symfony/symfony/src/Symfony/Component/Messenger/Middleware/SendMessageMiddleware.php:74 { …}
      ./src/Middleware/ResetApplicationMiddlerwareMiddleware.php:14 {
        AppBundle\Middleware\ResetApplicationMiddlerwareMiddleware->handle(Envelope $envelope, StackInterface $stack): Envelope^
        ›     echo "couocu";
        ›     return $stack->next()->handle($envelope, $stack);
        › }
      }
      ./vendor/symfony/symfony/src/Symfony/Bridge/Doctrine/Messenger/DoctrinePingConnectionMiddleware.php:34 { …}
      ./vendor/symfony/symfony/src/Symfony/Bridge/Doctrine/Messenger/AbstractDoctrineMiddleware.php:45 { …}
      ./vendor/symfony/symfony/src/Symfony/Component/Messenger/Middleware/FailedMessageProcessingMiddleware.php:34 { …}
      ./vendor/symfony/symfony/src/Symfony/Component/Messenger/Middleware/DispatchAfterCurrentBusMiddleware.php:68 { …}
      ./vendor/symfony/symfony/src/Symfony/Component/Messenger/Middleware/RejectRedeliveredMessageMiddleware.php:48 { …}
      ./vendor/symfony/symfony/src/Symfony/Component/Messenger/Middleware/AddBusNameStampMiddleware.php:37 { …}
      ./vendor/symfony/symfony/src/Symfony/Component/Messenger/Middleware/TraceableMiddleware.php:43 { …}
      ./vendor/symfony/symfony/src/Symfony/Component/Messenger/MessageBus.php:80 { …}
      ./vendor/symfony/symfony/src/Symfony/Component/Messenger/TraceableMessageBus.php:41 { …}
      ./vendor/symfony/symfony/src/Symfony/Component/Messenger/RoutableMessageBus.php:54 { …}
      ./vendor/symfony/symfony/src/Symfony/Component/Messenger/Worker.php:114 { …}
      ./vendor/symfony/symfony/src/Symfony/Component/Messenger/Worker.php:77 { …}
      ./vendor/symfony/symfony/src/Symfony/Component/Messenger/Command/ConsumeMessagesCommand.php:198 { …}
      ./vendor/symfony/symfony/src/Symfony/Component/Console/Command/Command.php:255 { …}
      ./vendor/symfony/symfony/src/Symfony/Component/Console/Application.php:989 { …}
      ./vendor/symfony/symfony/src/Symfony/Bundle/FrameworkBundle/Console/Application.php:96 { …}
      ./vendor/symfony/symfony/src/Symfony/Component/Console/Application.php:290 { …}
      ./vendor/symfony/symfony/src/Symfony/Bundle/FrameworkBundle/Console/Application.php:82 { …}
      ./vendor/symfony/symfony/src/Symfony/Component/Console/Application.php:166 { …}
      ./bin/console:29 { …}
    }
  }
]

```

</details>

Commits
-------

bf4b0cc022 [Messenger] Fix stopwach usage if it has been reset
This commit is contained in:
Fabien Potencier 2020-12-28 11:10:10 +01:00
commit bbe1bb77ef
2 changed files with 34 additions and 2 deletions

View File

@ -71,7 +71,7 @@ class TraceableStack implements StackInterface
*/
public function next(): MiddlewareInterface
{
if (null !== $this->currentEvent) {
if (null !== $this->currentEvent && $this->stopwatch->isStarted($this->currentEvent)) {
$this->stopwatch->stop($this->currentEvent);
}

View File

@ -42,7 +42,7 @@ class TraceableMiddlewareTest extends MiddlewareTestCase
};
$stopwatch = $this->createMock(Stopwatch::class);
$stopwatch->expects($this->once())->method('isStarted')->willReturn(true);
$stopwatch->expects($this->exactly(2))->method('isStarted')->willReturn(true);
$stopwatch->expects($this->exactly(2))
->method('start')
->withConsecutive(
@ -91,4 +91,36 @@ class TraceableMiddlewareTest extends MiddlewareTestCase
$traced = new TraceableMiddleware($stopwatch, $busId);
$traced->handle(new Envelope(new DummyMessage('Hello')), new StackMiddleware(new \ArrayIterator([null, $middleware])));
}
public function testHandleWhenStopwatchHasBeenReset()
{
$busId = 'command_bus';
$envelope = new Envelope(new DummyMessage('Hello'));
$stopwatch = new Stopwatch();
$middleware = new class($stopwatch) implements MiddlewareInterface {
public $calls = 0;
private $stopwatch;
public function __construct(Stopwatch $stopwatch)
{
$this->stopwatch = $stopwatch;
}
public function handle(Envelope $envelope, StackInterface $stack): Envelope
{
$this->stopwatch->reset();
++$this->calls;
return $stack->next()->handle($envelope, $stack);
}
};
$traced = new TraceableMiddleware($stopwatch, $busId);
$traced->handle($envelope, new StackMiddleware(new \ArrayIterator([null, $middleware])));
$this->assertSame(1, $middleware->calls);
}
}