[Messenger] improve logs #32036
Merged
[Messenger] improve logs #32036
Conversation
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Tobion
commented
Jun 14, 2019
| @@ -75,7 +75,7 @@ public function handle(Envelope $envelope, StackInterface $stack): Envelope | |||
| throw new NoHandlerForMessageException(sprintf('No handler for message "%s".', $context['class'])); | |||
| } | |||
|
|
|||
| $this->logger->info('No handler for message "{class}"', $context); | |||
| $this->logger->info('No handler for message {class}', $context); | |||
There was a problem hiding this comment.
Removed quotes for consistency. They are not useful in logs because in cli they are colored due to the context and the class is a very fixed string anyway without whitespace.
Tobion
commented
Jun 14, 2019
| } | ||
| } catch (\Throwable $e) { | ||
| $context['exception'] = $e; | ||
| $this->logger->warning('An exception occurred while handling message "{class}": '.$e->getMessage(), $context); |
There was a problem hiding this comment.
Just removing the try catch. It's usually not a good idea to both log and re-throw because it created duplicate logs.
Tobion
commented
Jun 14, 2019
| @@ -157,7 +159,7 @@ private function handleMessage(Envelope $envelope, ReceiverInterface $receiver, | |||
| $receiver->ack($envelope); | |||
| } else { | |||
| if (null !== $this->logger) { | |||
| $this->logger->critical('Rejecting {class} (removing from transport).', $context + ['error' => $throwable]); | |||
| $this->logger->critical('Error thrown while handling message {class}. Removing from transport after {retryCount} retries. Error: "{error}"', $context + ['retryCount' => $retryCount, 'error' => $throwable->getMessage(), 'exception' => $throwable]); | |||
There was a problem hiding this comment.
including the exception message makes sure you can see it without having to run in -vvv mode. the context otherwise only shows the exception class but not the message.
fabpot
approved these changes
Jun 14, 2019
|
Thank you @Tobion. |
fabpot
added a commit
that referenced
this pull request
Jun 14, 2019
This PR was merged into the 4.3 branch. Discussion ---------- [Messenger] improve logs | Q | A | ------------- | --- | Branch? | 4.3 | Bug fix? | no | New feature? | no <!-- please update src/**/CHANGELOG.md files --> | BC breaks? | no <!-- see https://symfony.com/bc --> | Deprecations? | no <!-- please update UPGRADE-*.md and src/**/CHANGELOG.md files --> | Tests pass? | yes <!-- please add some, will be required by reviewers --> | Fixed tickets | | License | MIT | Doc PR | The logs are currently very confusing and duplicated: - When handled sync the uncaught error it logged and displayed by the console / http error handler anyway. Currently it the warning is duplicated and useless: ``` 14:26:11 WARNING [messenger] An exception occurred while handling message "{class}": OUCH, THAT HURTS! GO TO MOM! 14:26:11 ERROR [console] Error thrown while running command "{class}". Message: "OUCH, THAT HURTS! GO TO MOM!" In HandleMessageMiddleware.php line 82: [Symfony\Component\Messenger\Exception\HandlerFailedException] OUCH, THAT HURTS! GO TO MOM! ``` - When handling async is was even confusing because the actual error was logged as warning and the retry (which is a good thing) was the error. ``` 13:48:15 WARNING [messenger] An exception occurred while handling message "{class}": OUCH, THAT HURTS! GO TO MOM! 13:48:15 ERROR [messenger] Retrying {class} - retry #1. ``` Now it's must clearer and adds even context like the delay: ``` 16:20:11 ERROR [messenger] Error thrown while handling message {class}. Dispatching for retry #3 using 4000 ms delay. Error: "OUCH, THAT HURTS! GO TO MOM!" ... 16:20:15 CRITICAL [messenger] Error thrown while handling message {class}. Removing from transport after 3 retries. Error: "OUCH, THAT HURTS! GO TO MOM!" ``` Commits ------- 2ac7027 [Messenger] improve logs
Merged
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
The logs are currently very confusing and duplicated:
Now it's must clearer and adds even context like the delay: