8000 [Debug] PHP 7 Error Exceptions logged twice · Issue #16980 · symfony/symfony · GitHub
[go: up one dir, main page]
Skip to content

[Debug] PHP 7 Error Exceptions logged twice #16980

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom
Closed
Tobion opened this issue Dec 11, 2015 · 11 comments
Closed

[Debug] PHP 7 Error Exceptions logged twice #16980

Tobion opened this issue Dec 11, 2015 · 11 comments
Assignees
@nicolas-grekas
Labels
Debug

Comments

@Tobion
Copy link
Contributor
Tobion commented Dec 11, 2015 •
edited
Loading

With PHP 7, \Error exceptions are logged two times as critical.
Here an example of the TypeEror.

  • CRITICAL - Type error: Argument 1 passed to Symfony\Component\HttpFoundation\Request::getPreferredLanguage() must be of the type array, string given, called in src\AppBundle\Controller\DefaultController.php on line 17
  • CRITICAL - Uncaught PHP Exception Symfony\Component\Debug\Exception\FatalThrowableError: "Type error: Argument 1 passed to Symfony\Component\HttpFoundation\Request::getPreferredLanguage() must be of the type array, string given, called in src\AppBundle\Controller\DefaultController.php on line 17" at src\Symfony\Component\HttpFoundation\Request.php line 1535

The reason for this is that the ErrorHandler::handleException logs the PHP error exception. It than wraps the Throwable in a FatalThrowableError to let the Kernel exception listeners do their work (which are typehinted against \Exception, see GetResponseForExceptionEvent). Then the ExceptionListener kicks in, which logs the FatalThrowableError again.

One error should not cause multiple error logs. Also the second error log with Uncaught PHP Exception Symfony\Component\Debug\Exception\FatalThrowableError is kinda wrong/irritating because you cannot actually catch the FatalThrowableError. You have to catch the \Error or \Throwable instead.

This double logging is in dev environment. In prod env only the second wrong error "Uncaught PHP Exception Symfony\Component\Debug\Exception\FatalThrowableError" is logged.
@xabbuh xabbuh added the Debug label Dec 12, 2015
@nicolas-grekas
Copy link
Member

So, when an exception/error is re-injected to the kernel via terminateWithException, we should display it but not log it, knowing that the error handler already had a chance to lg it (and thus did so). Right?

@Tobion
Copy link
Contributor Author
Tobion commented Dec 21, 2015

That would be the first step yes.

@nicolas-grekas
Copy link
Member

Exceptions Fatal errors are logged on two different channels (php and request). Do you think it matters? We should log them only on the php one then?

@jakzal jakzal mentioned this issue Dec 30, 2015
Closed
@yapro
Copy link
Contributor
yapro commented Dec 31, 2015

@nicolas-grekas Yes, you should writing Fatal error only once. I don't want to see the same error 2 times, it only clogs up the logs. Thank you.

@nicolas-grekas nicolas-grekas mentioned this issue Dec 31, 2015
Merged
@nicolas-grekas
Copy link
Mem 8000 ber

Should be fixed by #17202, could you please confirm?

@Tobion Tobion mentioned this issue Jan 4, 2016
Closed
nicolas-grekas added a commit that referenced this issue Jan 13, 2016
@nicolas-grekas
bug #17202 [FrameworkBundle] Don't log twice with the error handler (…
c60053e 
…nicolas-grekas)

This PR was merged into the 2.8 branch.

Discussion
----------

[FrameworkBundle] Don't log twice with the error handler

| Q             | A
| ------------- | ---
| Bug fix?      | yes
| New feature?  | no
| BC breaks?    | no
| Deprecations? | no
| Tests pass?   | yes
| Fixed tickets | #16980
| License       | MIT
| Doc PR        | -

ping @Tobion @yapro does it work as expected with this patch?

Commits
-------

5926ff2 [FrameworkBundle] Don't log twice with the error handler
@xabbuh xabbuh mentioned this issue Jan 18, 2016
Merged
fabpot added a commit that referenced this issue Jan 19, 2016
@fabpot
bug #17433 [FrameworkBundle] Don't log twice with the error handler (…
63cb9a9 
…nicolas-grekas)

This PR was merged into the 2.7 branch.

Discussion
----------

[FrameworkBundle] Don't log twice with the error handler

| Q             | A
| ------------- | ---
| Bug fix?      | no
| New feature?  | no
| BC breaks?    | no
| Deprecations? | no
| Tests pass?   | yes
| Fixed tickets | #16980, #17202
| License       | MIT
| Doc PR        |

Commits
-------

90d493e [FrameworkBundle] Don't log twice with the error handler
@fabpot fabpot closed this as completed Jan 19, 2016
@Tobion
Copy link
Contributor Author
Tobion commented May 26, 2017

This problem seems to be back again using Symfony 3.3. I get two critical error logs for the same thing.

CRITICAL php Type error: ...
CRITICAL request Uncaught PHP Exception Symfony\Component\Debug\Exception\FatalThrowableError: "Type error: ...

@Tobion Tobion reopened this May 26, 2017
@nicolas-grekas nicolas-grekas self-assigned this Jul 28, 2017
@Tobion
Copy link
Contributor Author
Tobion commented Nov 27, 2017

@nicolas-grekas the problem is still there with SE 3.4 rc2

@nicolas-grekas nicolas-grekas mentioned this issue Dec 9, 2017
Merged
@nicolas-grekas
Copy link
Member

Fixed in #25408

fabpot added a commit that referenced this issue Dec 11, 2017
@fabpot
bug #25408 [Debug] Fix catching fatal errors in case of nested error …
891b321 
…handlers (nicolas-grekas)

This PR was merged into the 2.7 branch.

Discussion
----------

[Debug] Fix catching fatal errors in case of nested error handlers

| Q             | A
| ------------- | ---
| Branch?       | 2.7
| Bug fix?      | yes
| New feature?  | no
| BC breaks?    | no
| Deprecations? | no
| Tests pass?   | yes
| Fixed tickets | #8703, #16980
| License       | MIT
| Doc PR        | -

Fixing a bug from 2013 :)

Commits
-------

27dc9a6 [Debug] Fix catching fatal errors in case of nested error handlers
@fabpot fabpot closed this as completed Dec 11, 2017
@gigi
Copy link
gigi commented Apr 27, 2018

Can You please check current status?
Seems problem came back again...
Symfony 4.0.8

[2018-04-27 12:41:55] app.CRITICAL: Unhandled exception...
[2018-04-27 12:41:55] request.CRITICAL: Uncaught PHP Exception InvalidArgumentException...

@hanwoods
Copy link
hanwoods commented Oct 16, 2018 •
edited
Loading

It seems I'm still experiencing this problem too, but with 3 copies of each log. I can't seem to reproduce the issue locally, but its happening in our production environments.

config.yml

monolog:
    channels: ['etl']
    handlers:
        etl:
            level:    info
            type:     stream
            buffer_size: 20
            path:     '%kernel.logs_dir%/etl.log'
            channels: [etl]

composer.json

"symfony/monolog-bundle": "^3.1.0",
"symfony/polyfill-apcu": "^1.0",
"symfony/swiftmailer-bundle": "^2.3.10",
"symfony/symfony": "3.3.*",

etl.log

[2018-10-16 13:55:34] etl.INFO: Job id: 8
[2018-10-16 13:55:34] etl.INFO: Job id: 8
[2018-10-16 13:55:34] etl.INFO: Job id: 8

@diditoumoro
Copy link

was this issue being solved? as we are facing the same issue with monolog logging message 3 times

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@nicolas-grekas nicolas-grekas

Labels
Debug
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
8 participants
@fabpot @nicolas-grekas @yapro @Tobion @xabbuh @hanwoods @gigi @diditoumoro
0