Skip to content

logging.handlers.MemoryHandler seems to be unconditionally flushed on process exit #95804

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

Closed
rascalking opened this issue Aug 8, 2022 · 7 comments
Assignees
Labels
stdlib Python modules in the Lib dir type-bug An unexpected behavior, bug, or error

Comments

@rascalking
Copy link
Contributor

Bug report

The documentation for MemoryHandler claims: If flushOnClose is specified as False, then the buffer is not flushed when the handler is closed.

However, as this minimal test shows, it's not always respected. Running this snippet does print "this should not print to the console" to the console.

import logging, logging.handlers
logging.root.addHandler(
    logging.handlers.MemoryHandler(
        capacity=10,
        flushLevel=logging.ERROR,
        target=logging.StreamHandler(),
        flushOnClose=False))
logging.warning('this should not print to the console')

It looks like it's the shutdown handler in Lib/logging/__init__.py that's doing the flushing.

If you explicitly close the handler before the process exits, you get the expected behavior...the log message isn't printed to the console. Which is why the unit test passes, that's what it's testing.

Your environment

I initially noticed this in python 3.8.13 on MacOS 12.5 (21G72). I can repro in the other python versions I have installed on that same macbook, 3.9.2 and 3.10.4.

@rascalking rascalking added the type-bug An unexpected behavior, bug, or error label Aug 8, 2022
@AlexWaygood AlexWaygood added the stdlib Python modules in the Lib dir label Aug 8, 2022
@rascalking
Copy link
Contributor Author

I'm happy to work on a fix for this, BTW.

@vsajip
Copy link
Member

vsajip commented Aug 8, 2022

Sure, please do.

@rascalking
Copy link
Contributor Author

I think ideally, I'd remove the h.flush() call from the shutdown handler, and ensure the handler classes that have a flush method call it from their close method. But that's a bigger change than is maybe strictly necessary.

The other approach I see is similar to what was done in the solution to #70746. We can add a MemoryHandler.shouldFlushBeforeClose() method, which just returns self.flushOnClose. But then we need to either add it as an always-return-true method on the base Handler class, or the shutdown handler has to define something like:

def should_flush_before_close(handler):
    if callable(getattr(handler, 'shouldFlushBeforeClose', None)):
        return handler.shouldFlushBeforeClose()
    return True

and then call that on each handler in order to decide whether or not to call flush(). It doesn't change any existing behavior that might be relied on, but it's messier and less readable. And it feels like we're adding a bunch of cruft to unrelated classes purely to solve the problem that MemoryHandler is having.

Do you see any approaches I'm missing? Or have a preference of the two options I've found so far?

@vsajip
Copy link
Member

vsajip commented Aug 10, 2022

This seems the simplest change to correct what is just a simple oversight in the shutdown() code:

                    h.acquire()
                    h.flush()
                    h.close()

to

                    h.acquire()
                    if not isinstance(h, MemoryHandler) or h.flushOnClose:
                        h.flush()
                    h.close()

Any reason that shouldn't work?

@rascalking
Copy link
Contributor Author

Nope, I'd just been trying to find something behavior based, that didn't rely on inheritance hierarchy.

Since flushOnClose is checked inside the close() call anyway, I think this can simplify to

h.aqcuire()
if not isinstance(h, MemoryHandler):
    h.flush()
h.close()

I'll go with that approach and knock out some tests. Thanks!

@rascalking
Copy link
Contributor Author

Ended up needing to check for h.flushOnClose directly to avoid an import loop.

@vsajip
Copy link
Member

vsajip commented Aug 11, 2022

Should be closed by #95857.

@vsajip vsajip closed this as completed Aug 11, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
stdlib Python modules in the Lib dir type-bug An unexpected behavior, bug, or error
Projects
None yet
Development

No branches or pull requests

3 participants