Skip to content

12188 add logging handler context managers#12207

Merged
glyph merged 12 commits intotrunkfrom
12188-redux
Jun 20, 2024
Merged

12188 add logging handler context managers#12207
glyph merged 12 commits intotrunkfrom
12188-redux

Conversation

@glyph
Copy link
Member

@glyph glyph commented Jun 9, 2024

This is a retread of #12196 with a simpler commit history. Its description:

Scope and purpose

Fixes #12188

Fixes #12195

This includes all the changes from #12189 , but attempts to demonstrate their utility. In so doing, I discovered a performance regression due to the additional allocation from creating a new context manager, so this also adds Logger.failureHandler, which allows for pre-allocating a context manager with a fixed error message, suitable for use within hot loops.

It also includes a ton of examples of the usages of both decorators, as well as a huge amount of refactoring, because:

  • many of the places that I wanted to use this are very old Twisted code
    • ThreadedSelectReactor was, in particular, a buggy mess with no test coverage that basically didn't work
  • using this new API requires migrating from old-logger to new-logger, so I had to go do that too
  • as I migrated I wanted type checking, and touching type checking in some places caused knock-on changes to be needed
  • in addressing the coverage gaps, I fixed a few bugs, in particular in half-close support, which previously just … did not work at all, with StandardIO just never calling writeConnectionLost at all.

There are no particularly interesting bugs fixed here, or major new subsystems with full type coverage, so not much for the release notes, but i think it's worth dealing with a slightly larger and more diffuse PR for getting all these minor improvements.

@codspeed-hq
Copy link

codspeed-hq bot commented Jun 9, 2024

CodSpeed Performance Report

Merging #12207 will not alter performance

Comparing 12188-redux (8f0643c) with trunk (c99802c)

Summary

✅ 2 untouched benchmarks

@glyph glyph marked this pull request as ready for review June 9, 2024 00:56
@chevah-robot chevah-robot requested a review from a team June 9, 2024 00:57
@glyph glyph requested a review from twm June 9, 2024 00:57
@glyph
Copy link
Member Author

glyph commented Jun 9, 2024

@twm fyi this is your fault for making me actually consider the design

(Thank you, the code is much better for it, but still, there's like 1000 lines now)

@glyph
Copy link
Member Author

glyph commented Jun 9, 2024

Sigh, trying one more force push to get rid of spurious codecov statuses that seem to have gotten stuck to the win32 stdio changes.

@adiroiban
Copy link
Member

Sigh, trying one more force push to get rid of spurious codecov statuses that seem to have gotten stuck to the win32 stdio changes.

Not sure if you are aware of the "Re-run failed jobs" feature.

Maybe a force push is easier for your, so that's also an option.

image

~~~~~~~~~~~~~~~~~

:py:class:`Logger <twisted.logger.Logger>` provides a :py:meth:`failure <twisted.logger.Logger.failure>` method, which allows one to capture a :py:class:`Failure <twisted.python.failure.Failure>` object conveniently:
:py:class:`Logger <twisted.logger.Logger>` provides a :py:meth:`failure <twisted.logger.Logger.handlingFailures>` method, which allows one to run some application code, then capture a :py:class:`Failure <twisted.python.failure.Failure>` in the log stream if that code raises an exception:
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Maybe we should also have an example demonstrating the usage of the "Operation" ... or at least a few words about the fact that the context manager returns an "operation" that can be used to check the result and contains a reference to the raised Failure

Copy link
Member

@adiroiban adiroiban left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for the update.

I did a quick review and left a few comments.

I haven't looked into the details of win32 and threadselect changes

I think that this is a big improvement.

I have approved it, but I am leaving this for review for Tom or other team members.

If a further review is delayed, I think that this can be merged.

Thanks again!

@adiroiban adiroiban requested a review from a team June 10, 2024 09:55
@glyph
Copy link
Member Author

glyph commented Jun 10, 2024

Thanks @adiroiban, I really appreciate that! I think this is one that might benefit from some post-hoc review, so after reviewing and addressing your comments I might land pretty quickly, but will be interested in feedback from others later.

@glyph
Copy link
Member Author

glyph commented Jun 10, 2024

Not sure if you are aware of the "Re-run failed jobs" feature.

Maybe a force push is easier for your, so that's also an option.

The problem in this case is that the job did not fail, but that codecov reported annotations

Not sure if you are aware of the "Re-run failed jobs" feature.

Maybe a force push is easier for your, so that's also an option.

I use it all the time :)

In this particular case, the issue is that the job did not actually fail. Codecov ran, it emitted some annotations, failed the check, then withdrew the failure once the Windows coverage arrived, but didn't withdraw the annotations. You can see them on the current files changed tab like this:

image

which of course makes no sense given that the patch is 100% covered and these are patch lines. I was hoping that the bug was intermittent and might be addressed by a full rebuild, but no, it looks like a flaw in codecov.

@glyph
Copy link
Member Author

glyph commented Jun 10, 2024

I have approved it

huh, why did the robot not notice this and add needs-merge ?

@adiroiban
Copy link
Member

It might be due to this

glyph requested a review from twm 2 weeks ago

I think that as long as there are requested reviewers, it is not yet considered ready for merge.

@glyph glyph removed the request for review from twm June 20, 2024 21:59
@glyph
Copy link
Member Author

glyph commented Jun 20, 2024

I think that as long as there are requested reviewers, it is not yet considered ready for merge.

OK, I can remove twm then

@glyph
Copy link
Member Author

glyph commented Jun 20, 2024

Oh… but that doesn't help, because… somehow you reviewed as you, and not "on behalf of twisted-contributors"? Hmmm. I guess I should just mention people and never use the review-request mechanism.

@glyph
Copy link
Member Author

glyph commented Jun 20, 2024

@glyph glyph merged commit 8487b2b into trunk Jun 20, 2024
@glyph glyph deleted the 12188-redux branch June 20, 2024 22:42
@glyph
Copy link
Member Author

glyph commented Jun 20, 2024

Not going to wait for Docker to resolve their incident here, but if there's a problem we can revert.

@adiroiban
Copy link
Member

Oh… but that doesn't help, because… somehow you reviewed as you, and not "on behalf of twisted-contributors"? Hmmm. I guess I should just mention people and never use the review-request mechanism.

The review robot is not AI.
It has a fixed set of rules, defined at https://github.com/chevah/github-hooks-server/blob/main/chevah/github_hooks_server/handler.py

The main use case for the robot is to allow non Twisted Org members to manage add the review label

@glyph
Copy link
Member Author

glyph commented Jun 21, 2024

The main use case for the robot is to allow non Twisted Org members to manage add the review label

Yeah, I should contribute back to it a bit more :). But I really want in-org members to use it as much as possible, so we have a common workflow.

@adiroiban
Copy link
Member

Yeah, I should contribute back to it a bit more :)

You can start by submitting bug reports and defining the rules/requirements/specifications for the robot.


I think that the robot works.

For this PR, you have explicitly requested a review from Tom and Tom has not reviewed the PR yet.
So I think that the PR should not be considered ready to merge.


For example see #12213

The PR was started as draft. As soon as the PR was no longer a draft the review label was added and a review was requested for the whole team.

I have reviewed the change and the PR was marked for merge.

Another example is #12216 ... I have expliclty requested the review, the label was autoatically applied and the Twisted team was automatically added to review.

As soon as someone from the team has reviewd and approved the PR, it was marked for merge.

Another example is #12202 ... marked as no longer a draft, the review was automatically request, I have requested changes and the label was automatically updated.

arkamar added a commit to arkamar/testtools that referenced this pull request Jul 1, 2024
Twisted recently changed behavior of logger on failures [1]. It newly
logs the `Main loop terminated.` even on exceptions, which breaks two
test in twistedsupport test suite. This hack attempts to address the
upcoming issue.

[1] twisted/twisted#12207
arkamar added a commit to arkamar/testtools that referenced this pull request Jul 1, 2024
Twisted recently changed behavior of logger on failures [1]. It newly
logs the `Main loop terminated.` even on exceptions, which breaks two
test in twistedsupport test suite. This hack attempts to address the
upcoming issue.

[1] twisted/twisted#12207
arkamar added a commit to arkamar/testtools that referenced this pull request Jul 1, 2024
Twisted recently changed behavior of logger on failures [1]. It newly
logs the `Main loop terminated.` even on exceptions, which breaks two
test in twistedsupport test suite. This hack attempts to address the
upcoming issue.

[1] twisted/twisted#12207
@rnixx
Copy link

rnixx commented Jan 18, 2025

kivy (https://github.com/kivy/kivy) supports the use of twisted reactor. Therefor it uses the ThreadedSelectReactor. It gets installed without signal handling. When shutting down the reactor, reactor._mainLoopShutdown() is called before reactor.stop(), otherwise the process gets stuck in threading._shutdown (https://github.com/kivy/kivy/blob/master/kivy/support.py#L230).

This changeset removes _mainLoopShutdown(). While the use of this private function in kivy was probably never a clean solution it's hard to find out how to properly shutdown the reactor now.

@glyph can you point me in the right direction please?

@adiroiban
Copy link
Member

Will _uninstallHandler() work for you?

@rnixx
Copy link

rnixx commented Jan 21, 2025

@adiroiban Thank you. That fixes the problem.

Just one question. Why is this not done in ThreadedSelectReactor.stop()?

@adiroiban
Copy link
Member

I think that the thread is stopped via the event system ... the reason... reduce the reliance on inheritance ... I don't know. I have not designed this component.

self.threadpoolShutdownID = self.addSystemEventTrigger(
"during", "shutdown", self._stopThreadPool
)

@rnixx
Copy link

rnixx commented Jan 21, 2025

As pointed out in my initial comment, it's possible to install the reactor without signal handling, which seems to be the cause of the issue. It might make sense to handle this case in ThreadedSelectReactor?

@adiroiban
Copy link
Member

it's possible to install the reactor without signal handling,

I think that "signal handling" means Unix signals.

The shutdown used Twisted events notification.

From what I can see, the thread pool is lazy initialized by Twisted.
That is, if your code never uses threads, you will not have the threading reactor part active.

It looks like you want to run Twisted in the non-main thread.

I am using this code to support some end to end tests for my Twisted application ... maybe it helps

https://github.com/chevah/compat/blob/master/src/chevah_compat/testing/threaded_reactor.py

@glyph
Copy link
Member Author

glyph commented Jan 21, 2025

@glyph can you point me in the right direction please?

I think that the next thing to do here is to file a bug, describing the problem that you're facing in specific details. It sounds like maybe you've got more of a feature request than a bug report, but I'm not sure why you're installing without signal handlers in the first place, so perhaps it's just a bug in the way that works.

(In the future, I plan to make a more concerted effort to remove or scramble private APIs like this on a more regular basis so that downstream users take our compatibility contract more seriously, so if you notice issues like this, reach out and try to get the features you need supported :))

@glyph
Copy link
Member Author

glyph commented Jan 22, 2025

@rnixx To be clear I think your next step here is to get us to fix the bug, which is that the reactor should not break like this when you start and stop it normally. We may need to push some work off to the application, but hopefully we can just figure out a way to do it without signals. If we do need to push work onto the application it should be part of the contract of starting without signals, something obvious that comes from that API like an object that gets returned to you with the relevant hook, rather than providing a public version of an API which can arbitrarily mangle internal process state to work around bugs that we have shipped.

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

Projects

None yet

Development

Successfully merging this pull request may close these issues.

demonstrate the utility of / migrate to Logger.handlingFailures Add a context manager for calling log.failure when code fails

4 participants