orangeInk
orangeInk

Reputation: 1400

Python logging calls showing on console even when redirecting stdout

I'm on a Windows 7 machine with Python 3.6

I'm wondering why the following code prints the logger message to the console even though the logger (or rather its parent's handler) is configured to emit to stdout and stdout is redirected to io.StringIO().

import sys
import logging
from io import StringIO

logging.basicConfig(format='%(message)s', level=logging.DEBUG, stream=sys.stdout)

logger = logging.getLogger(__name__)

old_stdout = sys.stdout
sys.stdout = tmp = StringIO()
print('*** FIRST IN CODE : print')
logger.debug('*** SECOND IN CODE : logger')
sys.stdout = old_stdout
print(tmp.getvalue())

If you comment out the last line in this code (print(tmp.getvalue())) you'll see that *** FIRST IN CODE : print no longer shows up on the console while *** SECOND IN CODE : logger still does.

I've tried removing stream=sys.stdout from the basicConfig() call (in which case the StreamHandler that gets created will default to stderr) and redirected stderr instead but the result is the exact same as with stdout.

I've also looked at the StreamHandler's code but that didn't explain anything either.

I've read that there are a few quirks with stdout/-err redirection on Windows. Is that what's happening here or am I missing something?

Upvotes: 0

Views: 281

Answers (1)

Rob Kennedy
Rob Kennedy

Reputation: 163257

When you use stream=sys.stdout to configure the logger, the logger gets a reference to the original sys.stdout value, just like old_stdout does in the line afterward.

When you change sys.stdout, you don't expect the value of old_stdout to change, right? So why should the value of logger.stream (or whatever it's really named) change?

The logger doesn't notice that you've since changed the value of the variable you used to assign the stream parameter. To do that, it would need to compare the received stream parameter to all possible sources, including sys.stdout, and then check that source later to see whether it still matches the stream parameter. That's way too much work, and doesn't follow general expectations of assigning values to variables or parameters.

If you want to redirect output, do so before telling other parts of your program (such as your logger) where to send their output.

For all the logger knows, you intended to keep logging going to the console while other output got sent elsewhere.

Upvotes: 3

Related Questions