Issue 34107: root.warning('msg') output format modified by logging.warning('msg')

Issue34107

Created on 2018-07-13 00:25 by Michael Kearney, last changed 2022-04-11 14:59 by admin. This issue is now closed.

Files
File name Uploaded Description Edit
logTest.py Michael Kearney, 2018-07-13 00:25 unittest
Messages (3)
msg321582 - (view) Author: Michael Kearney (Michael Kearney) Date: 2018-07-13 00:25
0 >>> import logging
1 >>> root=logging.getLogger(name='root')
2 >>> root.warning('msg')
3 msg                                   <----- Compare this line
4 >>> logging.warning('msg')
5 WARNING:root:msg
6 >>> root.warning('msg')
7 WARNING:root:msg                      <------ with this line

Specifically, I was surprised to see
   line 7 response to line 6
given
   line 3 response to line 2

logger methods log(),critical(),error(),info() act the same way.

A workaround from issue 33897 fixes things
   logging.basicConfig(level=logging.DEBUG, force=True)

I discovered this when exploring "logging" module defaults, It is the sort of thing someone new to the module might encounter. I did.

Slightly more comprehensive unittest example attached.

This may be my first real submission. Feedback appreciated
msg321583 - (view) Author: Vinay Sajip (vinay.sajip) * (Python committer) Date: 2018-07-13 09:09
This behaviour is as expected. If no handlers are configured for logging, an internal "handler of last resort" is used, with just the message output. See:

https://docs.python.org/3/howto/logging.html#what-happens-if-no-configuration-is-provided

If you call logging.warning(...), and if no handlers are configured, then basicConfig() is internally called to set up a handler with a basic format string. See:

https://docs.python.org/3/library/logging.html#logging.log

So, what you've described is as it should be.
msg321632 - (view) Author: Michael Kearney (Michael Kearney) Date: 2018-07-13 20:03
Thanks for the clarification and doc pointers. I saw "lastResort" attribute in the code 
but had not fully understood what was going on. I am not certain I really do now, but that's ok. That's why we read docs, read and write
code. Eventually it starts making sense.
It appears that there is history to contend with or complications provoked by threads. 

I had not yet read the lastResort discussion in the documentation. That's deep in the 
advanced tutorial, I was getting tripped up by simple examples that I concocted from 
very simple cases, which can be on the fringes of actual usage. I wonder why "lastResort" differs from the built-in default. 

I was playing with basicConfig because I wanted to experiment with formatting and level,
and I managed to generate messages that seemed unrelated to formating I had specified.


For now it appears that after
    import logging

I can add 
    logging.warning('')

and achieve what I want. I get the default format where I expect rather than lastResort format.

I prefer the default format that I get from the internal call to basicConfig.
I can imagine the there will be a situation where I want the even simpler
"last resort format".
History
Date User Action Args
2022-04-11 14:59:03adminsetgithub: 78288
2018-07-13 20:03:39Michael Kearneysetmessages: + msg321632
2018-07-13 09:09:50vinay.sajipsetstatus: open -> closed
resolution: not a bug
messages: + msg321583

stage: resolved

2018-07-13 09:02:11xtreaksetnosy: + xtreak
2018-07-13 04:02:11ned.deilysetnosy: + vinay.sajip
2018-07-13 00:25:05Michael Kearneycreate