Skip to content
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.

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

Flush loggers on kernel.reset #279

Merged
merged 1 commit into from
May 16, 2019
Merged

Conversation

dnna
Copy link
Contributor

@dnna dnna commented Sep 9, 2018

Fixes php-pm/php-pm-httpkernel#134 and php-pm/php-pm-httpkernel#62

When using PHP-PM the worker does not die at the end of the request, so the shutdown functions registered by monolog are never triggered (so for example BufferHandler never flushes). This PR partially fixes the problem by flushing the loggers containing a flush function at the end of each request.

I did not use the close function (mentioned in Seldaek/monolog#1053) because some loggers use sockets or other connections that would be closed in this case and not be reusable in the next request.

I'm not sure if this is the best solution to this problem, happy to discuss alternatives if there is a better way.

@nicolas-grekas
Copy link
Member

Shouldn't we use the kernel.reset tag instead?
See symfony/symfony#24155

@dnna
Copy link
Contributor Author

dnna commented Sep 9, 2018

Actually I tried kernel.reset, but it didn't seem to trigger the flush when an exception occurred.

@dnna
Copy link
Contributor Author

dnna commented Sep 9, 2018

Never mind, I see the issue now. kernel.reset triggers on the next request, not the current one, so I actually needed to perform a second request for the logs of the first request to flush.

Its not ideal, but it still solves the problem adequately and kernel.reset was designed specifically for PHP-PM cases, so I will adapt the code to use that instead.

@dnna dnna changed the title Flush loggers on kernel.terminate Flush loggers on kernel.reset Sep 13, 2018
@lyrixx
Copy link
Member

lyrixx commented Sep 21, 2018

I would use Seldaek/monolog#997 instead of using flush

@dnna
Copy link
Contributor Author

dnna commented Sep 21, 2018

Yeap, that solution looks better. Hope it gets merged soon, and I'll change this PR to use that one :)

@lyrixx
Copy link
Member

lyrixx commented Sep 21, 2018

I hope too :)

@Seldaek
Copy link
Member

Seldaek commented Dec 26, 2018

reset is now part of Monolog 1.24.0 and above.. Would be good to update this PR. You can test for ResettableInterface being present.

@Seldaek Seldaek added this to the 3.4 milestone Dec 26, 2018
@dnna
Copy link
Contributor Author

dnna commented Dec 26, 2018

Perfect, will update it in the next few days.

@dnna
Copy link
Contributor Author

dnna commented Jan 1, 2019

@Seldaek @lyrixx @nicolas-grekas I have updated this PR to use the ResettableInterface.

There is a deprecation notice in the PHP 7.1 tests, but I don't think its related with this PR, could you guys have a look?

@Seldaek
Copy link
Member

Seldaek commented Jan 13, 2019

Sorry for the delay. This looks better already but I am afraid attaching kernel.reset to all handlers means that some of them will end up being reset multiple times. For example a GroupHandler or BufferHandler when it gets reset it resets the handlers it contains. This is so you can simply call Logger::reset and then it trickles down to all handlers from there even tho the Logger doesn't know about all of them.

I think it would be preferrable to set the tag on the Logger instances to avoid these multi-resets.

@dnna
Copy link
Contributor Author

dnna commented Jan 14, 2019

Hmm is it a good idea to explicitly set the tag on specific loggers? Won't this be something we'll have to keep track of whenever a new logger is added?

If reset is designed to trickle down to all handlers, maybe it would be better to just trigger reset on the main handler (if it has ResettableInterface) and let it trickle down to the rest?

@Seldaek
Copy link
Member

Seldaek commented Jan 14, 2019

Yes.. this is kinda complicated by the fact that some handlers can be only in some loggers, and not in all. But I guess resetting only the main logger would probably make sense, otherwise we end up with duplicate resets again. Channel-specific handlers might be needing a manual reset from the user in that case.. that's a trade-off we may have to live with unless someone feels like figuring out which handlers are not in the default logger chain and then tagging those for reset too.. I'm not sure what's worse between maybe double resets and maybe no reset at all.

@dnna
Copy link
Contributor Author

dnna commented Jan 14, 2019

I think just resetting the main logger and having it trickle down the chain would resolve most of the use cases requiring a logger reset anyway.

It will certainly improve the situation compared to what it is currently, so maybe we should proceed with that?

@Seldaek
Copy link
Member

Seldaek commented Jan 14, 2019

Yes that sounds good to me :)

@lyrixx
Copy link
Member

lyrixx commented Jan 14, 2019

We could leverage the autoconfiguration, isn't ?

@stof
Copy link
Member

stof commented Jan 14, 2019

I think the DI extension already knows which handlers are nested ones. So it could manage the tagging of non-nested ones.

@dnna
Copy link
Contributor Author

dnna commented Jan 15, 2019

OK, so we'll leverage the the DI extension to find all the top-level handlers (like main) and reset them, given that they implement ResettableInterface. I'll try to work on that in the next few days and update the PR.

@dnna
Copy link
Contributor Author

dnna commented Jan 16, 2019

I have changed the logic to apply the reset tag only to non-nested handlers. @Seldaek @stof please have a look again.

@acasademont
Copy link
Contributor

Is there something left to be done here? Can we help in some way? We're really interested in this PR

@Seldaek
Copy link
Member

Seldaek commented Apr 5, 2019

I think it looks good to me now. Would be happy to get a second opinion from someone else, but for me it looks mergeable.

@acasademont
Copy link
Contributor

@lyrixx @stof any comments on this one? Thanks!

@acasademont
Copy link
Contributor

@dnna the only thing i'd probably suggest is a squash of all the commits.

@dnna
Copy link
Contributor Author

dnna commented May 8, 2019

@acasademont there is an option to do this automatically during the merge, no? If not I'm happy to squash them

@lyrixx lyrixx force-pushed the flushonterminate branch from 4ddc924 to 366f692 Compare May 16, 2019 10:21
@lyrixx
Copy link
Member

lyrixx commented May 16, 2019

It took time, but here we go, this is in now. Thank you very much @dnna.

@lyrixx lyrixx merged commit 366f692 into symfony:master May 16, 2019
lyrixx added a commit that referenced this pull request May 16, 2019
This PR was squashed before being merged into the 3.x-dev branch (closes #279).

Discussion
----------

Flush loggers on kernel.reset

Fixes php-pm/php-pm-httpkernel#134 and php-pm/php-pm-httpkernel#62

When using [PHP-PM](https://github.com/php-pm/php-pm) the worker does not die at the end of the request, so the shutdown functions registered by monolog are never triggered (so for example `BufferHandler` never flushes). This PR partially fixes the problem by flushing the loggers containing a `flush` function at the end of each request.

I did not use the `close` function (mentioned in Seldaek/monolog#1053) because some loggers use sockets or other connections that would be closed in this case and not be reusable in the next request.

I'm not sure if this is the best solution to this problem, happy to discuss alternatives if there is a better way.

Commits
-------

366f692 Flush loggers on kernel.reset
@dnna dnna deleted the flushonterminate branch May 16, 2019 10:26
@acasademont
Copy link
Contributor

awesome thanks! hope we can have a new release of the bundle soon :D

@lyrixx
Copy link
Member

lyrixx commented May 22, 2019

I made some triage recently. I will wait a bit to get some feedback and we will release it ASAP.
Thanks

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Monolog BufferHandler does not flush at the end of the request
6 participants