Sentry Logging Time Issue

[Vladelis]

Since Laravel 5.6 there is an logging config file thus making it easier to get the application logs onto sentry. The issue I kept running into is that the log displays its time with the default formatter and each log with the same message creates a new issue in sentry.
I made a solution by creating a CustomFormatter class and tapped it into the sentry channel to change the formatter into one that truncates the time from the message.
Is there a cleaner and better way of solving this? Seems like a lot of ugly code for some basic functionality.

<?php

namespace Certificates\Logging;

use Monolog\Formatter\LineFormatter;

class CustomFormatter
{
    /**
     * @param  \Illuminate\Log\Logger  $logger
     * @return void
     */
    public function __invoke($logger)
    {
        foreach ($logger->getHandlers() as $handler) {
            $handler->setFormatter(new LineFormatter("%channel%.%level_name%: %message% %context% %extra%\n",null, false,true));
        }
    }
}

        'sentry' => [
            'driver' => 'sentry',
            'tap' => [Certificates\Logging\CustomFormatter::class],
        ],

[stayallive]

This is not so nice, but I am not sure... probably Laravel is overwriting the line formatter since the format in the RavenHandler does not have any of that info.

See: https://github.com/Seldaek/monolog/blob/master/src/Monolog/Handler/RavenHandler.php

Open to suggestions on how to improve because dates in this format is not so good.

Maybe we should set the RavenHandler format explicitly when registering the log channel.

[Vladelis]

Yeah I think setting the default handler's formatter upon registration to one that does not display a different message for the same error (with time excluded), so that all of the same errors would fall under the same issue in Sentry would be a great solution.
Also I think the solution that the monolog driver has for logging without the use of the tap array is quite good. So maybe leave the option of changing the formatter or the handler log on the sentry driver in a similar way.
Copied an example from the Laravel's documentation.

'browser' => [
    'driver' => 'monolog',
    'handler' => Monolog\Handler\BrowserConsoleHandler::class,
    'formatter' => Monolog\Formatter\HtmlFormatter::class,
    'formatter_with' => [
        'dateFormat' => 'Y-m-d',
    ],
],

Thanks a lot for the effort

[dmyers]

@Vladelis Did you all get this figured out by chance? I'm having an issue where none of my events are getting grouped properly and I think it is due to the formatting as well. The production.ERROR part and the context seem unnecessary, but I don't know why they are being added to the log message, in a previous integration of Sentry I never had them formatted like this.

Any help would be greatly appreciated, I'm getting a lot of notifications for this even though I would like to silence the issue for this particular one for all events.

[dmyers]

I did a bit more research and it seems like the readme should be updated to recommend using a new SentryFormatter for the logs and possibly to add that formatter to this repo to make a good sensible default for people... I found this in the Monolog repo that is probably outdated at this point as it's named RavenHandler, but all it does is use the Monoglog\LineFormatter and change the format.

https://github.com/Seldaek/monolog/blob/master/src/Monolog/Handler/RavenHandler.php#L209

[dmyers]

I was able to get this to work now in my sentry config, but it might be beneficial to use this by default for others to have a good out-of-box setup.

<?php
'sentry' => [
    'driver' => 'sentry',
    'level'  => 'error',
    'formatter' => Monolog\Formatter\LineFormatter::class,
    'formatter_with' => [
        'format' => '%message%',
    ],
],

[Vladelis]

@dmyers Yeah I think they patched it not long ago so your solution is what it should look like. I had to use a custom formatter beforehand which still worked, but was very unclean in my eyes.

[stayallive]

Happy to accept a PR to make this the default 👍

[gregory-claeyssens]

Thank you for the fix @dmyers it helped bring down the duplicates quite a lot.
Yet, I see a lot of duplicates still, mostly initiated from Guzzle, I think it's because the error message is including the URL, so it is always a different message that is logged.
I found this article explaining that grouping is done on message as a fallback. Would it be reasonably possible to add the stacktrace so grouping might become more robust? Or maybe I'm missing something obviously simple

[dmyers]

@sweet-greg Glad I could help. Yeah I have that same issue with Guzzle still I think I have fixed by creating a custom Exception inside app/Exceptions/HttpClientException that extends \Exception and I catch Guzzle's RequestException and rethrow it with my custom exception like this:

try {
	// ...
}
catch (\GuzzleHttp\Exception\RequestException $e) {
	if ($e->hasResponse()) {
	    $response = $e->getResponse();
		throw new HttpClientException(sprintf('Error with API call (%s)', $response->getReasonPhrase()), $response->getStatusCode());
	}
	else {
		throw $e;
	}
}

Yeah I think stacktrace deduping would be really nice too, maybe someone from Sentry could comment on that idea or maybe a new issue.

[stayallive]

So this took a bit... but while working on some other log channel improvements I think we finally fixed this by default: #142.

We now just report the %message% without all the date, time and log level cruft once that PR is merged and released.