[issue31732] Add TRACE level to the logging module

[Antoine Pitrou]

Antoine Pitrou  added the comment:

Perhaps a recipe should be published to explain how to add your own levels?

>>> import logging
>>> logging.NOTE = logging.INFO + 5
>>> logging.addLevelName(logging.INFO + 5, 'NOTE')
>>> class MyLogger(logging.getLoggerClass()):
...:def note(self, msg, *args, **kwargs):
...:self.log(logging.NOTE, msg, *args, **kwargs)
...:
>>> logging.setLoggerClass(MyLogger)

>>> logging.basicConfig(level=logging.INFO)
>>> logger.note("hello %s", "Guido")
NOTE:foo:hello Guido

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue31732] Add TRACE level to the logging module

[Antoine Pitrou]

Change by Antoine Pitrou :


--
Removed message: https://bugs.python.org/msg307162

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue31732] Add TRACE level to the logging module

[Antoine Pitrou]

Antoine Pitrou  added the comment:

Perhaps a recipe should be published to explain how to add your own levels?

e.g.:

>>> import logging
>>> logging.NOTE = logging.INFO + 5
>>> logging.addLevelName(logging.INFO + 5, 'NOTE')
>>> class MyLogger(logging.Logger):
...:def note(self, msg, *args, **kwargs):
...:self.log(logging.NOTE, msg, *args, **kwargs)
...:
>>> logging.setLoggerClass(MyLogger)

>>> logging.basicConfig(level=logging.INFO)
>>> logger.note("hello %s", "Guido")
Level 25:foo:hello Guido

--
nosy: +pitrou

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue31732] Add TRACE level to the logging module

[R. David Murray]

R. David Murray  added the comment:

I'm not arguing against the rejection, but I want to mention a point in 
relation to Raymond's statement "five levels have sufficed for a long and that 
the need for finer distinctions almost never arises in practice".  In thinking 
about my own codebase, I have only one project where I added a notice level, 
and none in which I currently have a TRACE level although I think I used it as 
described below in one during development.

If logging had had TRACE built in, I would have used it in almost every project 
I've written.  Instead, I squash everything into the DEBUG level, and that 
results in two things: overly verbose debug logs, and still having to go in and 
add extra temporary debug logging statements to debug hard problems.

I don't think this is a terrible thing.  The "pain" of it only once rose to the 
level where I added a TRACE level to my program. My point is that the lack of 
TRACE (or NOTICE) getting added to projects on a common basis, rather than 
meaning the need for the distinction "almost never arises", means instead that 
the need for them is less pressing than the small pain of adding them.

I will make one argument in favor of adding a TRACE level, but I don't know 
that it is enough to shift the balance.  That argument is that if I had a TRACE 
level built in, instead of adding and deleting extra temporary debug logging 
statements during a debugging cycle, I would add them at the TRACE level and 
*leave them in*, at least until I was ready to ship the code.  Not having to 
add and remove them, and then almost always end up re-adding and re-removing 
them, would speed up my debugging cycle by a non-trivial amount.  Why don't I 
add a TRACE level and do this?  It feels like too much of a pain "just to debug 
this", but then I wind up coming up against that decision again when working on 
the next bug, and the next..and each time it is too much of a pain to add TRACE 
"just for this bug".  

So, having TRACE built in might speed up debugging cycles, because programmers 
are lazy :)

Having made this conscious as a result of thinking about this issue, I may 
start adding TRACE to my projects more often :)

--
nosy: +r.david.murray

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue31732] Add TRACE level to the logging module

[STINNER Victor]

STINNER Victor  added the comment:

Vinay:
> I feel that there is no need for a TRACE level in the stdlib

Ok, that's fine.

I just pushed the idea of someone on IRC. Since I had the same idea once, I 
tried, but I lost :-) I can easily survive without TRACE in the stdlib ;-)


Vinay:
> Victor says "we need to a 6th level since DEBUG might be too verbose" - but 
> as the PR is currently constituted, enabling the TRACE level would output 
> DEBUG messages too, and so be even more verbose than just DEBUG! In this case 
> I feel that, when considering the number of levels, "less is more".

Oh, I'm not sure that I explained my point correctly, since someone else on IRC 
told me that he misunderstood.

My point is that logs have different consumers who have different expectations 
and usages of the logs.

In my case, the customer may want to go to up to the DEBUG level "by default" 
to collect more data on failures. Enabling TRACE would produce too many logs 
and should be restricted to the most tricky bugs where you cannot guess the bug 
only with the DEBUG level.

I tried to explain that if you are putting all debug traces at the DEBUG level, 
you may produce 10 MB of log per minute (arbitrary number for my explanation). 
But producing 10 MB per machine in a large datacenter made of thousands of 
servers can lead to practical storage issues: too many logs would fill the log 
partition too quickly, especially when logs are centralized.

The idea is to reduce debug traces to 10% at the DEBUG level, and put the 
remaings traces at the TRACE level. For example, you can imagine to log an 
exception message at DEBUG, but log the traceback at TRACE level. The traceback 
is likely to produce 10x more logs.

The TRACE level is only enabled on-demand for a short period of time on a few 
selected servers.

Technically, you can already do that INFO and DEBUG levels. But in OpenStack, 
these levels are already "busy" with enough messages and we needed a 6th level 
:-)

(I don't want to reopen the discssion, just to make sure that I was correctly 
understood ;-))

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue31732] Add TRACE level to the logging module

[Vinay Sajip]

Vinay Sajip  added the comment:

As Raymond has said: though it might appear reasonable to add a TRACE level 
from the numerous examples that Victor has given, in practice it is hard enough 
to know when a particular level should be applied. Victor says "we need to a 
6th level since DEBUG might be too verbose" - but as the PR is currently 
constituted, enabling the TRACE level would output DEBUG messages too, and so 
be even more verbose than just DEBUG! In this case I feel that, when 
considering the number of levels, "less is more".

For specific applications different levels might be desirable, and the logging 
system makes this possible, though not at the level of convenience of having a 
trace() method on loggers. However, it's easy enough to provide your own 
subclass with that method, if you really need it that badly. Of course you can 
currently also do logger.log(TRACE, ...) without the need for any subclass or 
need to "patch the stdlib" (as per Victor's comment).

This is one of those areas where tastes differ - and it is IMO really just a 
matter of taste. The five levels we have presently are based on what was 
considered best practice when the logging module was added to Python, and it 
specifically eschewed adopting prior art where more levels were available (e.g. 
syslog). The documentation gives a clear rationale for when to use what level:

https://docs.python.org/2/howto/logging.html#when-to-use-logging

and this seems of reasonably universal applicability across projects.

Given that individual projects *can* provide additional levels according to 
their need, I feel that there is no need for a TRACE level in the stdlib; as 
Raymond has pointed out in msg304304, the current levels are easy to understand 
when to apply, and finer levels invariably lead to different opinions on when 
to use them, due to essentially being matters of taste.

--
resolution:  -> wont fix
stage: patch review -> resolved
status: open -> closed
type:  -> enhancement

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue31732] Add TRACE level to the logging module

[pmpp]

pmpp  added the comment:

Sorry, i didn't mean to be rude. Just wanted to pick your attention because i 
think you miss the point:  logging as is it with its levels is perfect for *log 
messages*.
Review the typical usage shown and you'll see that tracing level is for logging 
tracebacks : the debug message is separate. Traces just don't fit on standard 
log output, they clutter and obviously have a format of their own. 
As a user i see TRACE as context for logging.exception when it has nothing to 
do with errors or verbosity.

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue31732] Add TRACE level to the logging module

[Raymond Hettinger]

Raymond Hettinger  added the comment:

No need to be brusque with me.  Vinay is the decision maker on this.

Overall, this seems rehash and second guess the discussions and decisions made 
15 years ago when PEP 282 was accepted.  At that time, it was decided that five 
levels had advantages for learnability and usability, but that the levels 
should be extendable to cover more specialized uses:

>>> import logging
>>> SEMI_IMPORTANT = 35
>>> logging.addLevelName(SEMI_IMPORTANT, 'SEMI_IMPORTANT')
>>> logging.log(SEMI_IMPORTANT, 'request backlog getting high')
SEMI_IMPORTANT:root:request backlog getting high

This effortless extendability let us avoid adding the whole zoo of names 
sometimes used in other projects (FATAL, TRACE, NOTICE, FINE, FINER, FINEST).  
As far as I can tell, this module has a 15 year track record of success and was 
well thought-out from the outset.  So there is no reason to suddenly be so 
insistent that the module must change to accommodate your world view of how 
everyone else should prioritize their log entries.

As a teacher, project leader, and coach, one thing I really like about Vinay's 
design is that people seem to easily and naturally assign the correct rank 
order to the existing five levels.  Today, I asked some engineers where TRACE 
or NOTICE would fit in and they were unsure.  This indicates that adding new 
levels will impact usability and make users worse off.

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue31732] Add TRACE level to the logging module

[pmpp]

pmpp  added the comment:

As a dumb user I vote in favor of this on the ground that five levels is not 
sufficient for a long and that the need for finer distinctions already arose 
for me in practice.  Till i overcame the mental cost to think, learn and *find 
time* on how to make a finer level of distinction to work.

line tracing logging is a level on its own and doesn't fit with provided ones 
which are *too simple*.

--

If python is "battery included". It's time to provide a multiplatform charger 
...

--
nosy: +pmpp

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue31732] Add TRACE level to the logging module

[STINNER Victor]

STINNER Victor  added the comment:

Raymond Hettinger: "... the need for finer distinctions almost never arises in 
practice"

I gave a list of 10 projects which are alreading using widely the 6th TRACE 
level.

In this list, I consider that OpenStack and SaltStack are two big and serious 
projects which justify to add the TRACE level in the stdlib. It will avoid 
these projects to have to "patch" the stdlib for their need.

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue31732] Add TRACE level to the logging module

[Raymond Hettinger]

Raymond Hettinger  added the comment:

I vote against this on the ground that five levels have sufficed for a long and 
that the need for finer distinctions almost never arises in practice.  There 
would be an ongoing mental cost to making users learn and think about finer 
levels of distinction.

--
assignee:  -> vinay.sajip
nosy: +rhettinger

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue31732] Add TRACE level to the logging module

[STINNER Victor]

STINNER Victor  added the comment:

More references to TRACE logging level:

* "CUSTOM_TRACE = 5 # Mapping for zLOG.TRACE" in Zope zLOG
  https://github.com/zopefoundation/zLOG/blob/master/src/zLOG/EventLogger.py#L29

* Runlevel = stem.util.enum.UppercaseEnum('TRACE', 'DEBUG', 'INFO', 'NOTICE', 
'WARN', 'ERROR')
  TRACE, DEBUG, INFO, NOTICE, WARN, ERR = list(Runlevel)
  https://stem.torproject.org/_modules/stem/util/log.html

* "TRACE = 5 # Trace log level."
  "An extension of Python's option parser."
  
https://github.com/mikeorr/WebHelpers2/blob/master/unfinished/logging_optparse.py#L14

* "TRACE = 5"
  http://www.taurus-scada.org/en/latest/_modules/taurus/core/util/log.html

* "TRACE = 9"
  "bokeh: Interactive plots and applications in the browser from Python"
  https://pypkg.com/pypi/bokeh/f/bokeh/util/logconfig.py

* "With custom log levels: (...) TRACE = 5" (an example in the doc)
  https://pypi.python.org/pypi/colorlog

Note: Zope zLOG also has a "CUSTOM_BLATHER = 15 # Mapping for zLOG.BLATHER" 
level.

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue31732] Add TRACE level to the logging module

[STINNER Victor]

STINNER Victor  added the comment:

Other references to a TRACE logging level:

* SaltStack: trace = 5
  https://docs.saltstack.com/en/latest/ref/configuration/logging/#log-levels

* autologging.TRACE = 1: "A custom tracing log level, lower in severity than 
logging.DEBUG."
  autologging: "Autologging eliminates boilerplate logging setup code and 
tracing code, and provides a means to separate application logging from program 
flow and data tracing."
  http://pythonhosted.org/Autologging/autologging.html#autologging.TRACE

* robot.logger.TRACE and robot.logger.trace()
  https://robot-framework.readthedocs.io/en/2.9.2/_modules/robot/api/logger.html
  
https://robot-framework.readthedocs.io/en/2.9.2/autodoc/robot.api.html#log-levels

* "I'd like to have loglevel TRACE (5) for my application (...)"
  
https://stackoverflow.com/questions/2183233/how-to-add-a-custom-loglevel-to-pythons-logging-facility

--


FYI while searching users of "TRACE" log level, I also found the other log 
levels:

* "NOTE" < DEBUG
* "FATAL" = CRITICAL
* "profile" = 15 < INFO, but 15 > DEBUG
* "garbage" = 1 < DEBUG

Again, I don't think that these ones are interesting.

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue31732] Add TRACE level to the logging module

[STINNER Victor]

STINNER Victor  added the comment:

Attached PR 3930 adds logging.TRACE, logging.trace() and logging.Logger.trace().

--
nosy: +vinay.sajip

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue31732] Add TRACE level to the logging module

[STINNER Victor]

Change by STINNER Victor :


--
keywords: +patch
pull_requests: +3905
stage:  -> patch review

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue31732] Add TRACE level to the logging module

[STINNER Victor]

New submission from STINNER Victor :

The logging module has already 5 log levels: CRITICAL, ERROR, WARNING, INFO, 
DEBUG.
https://docs.python.org/dev/library/logging.html#logging-levels
(I don't count NOTSET, I don't consider it to be "usable", at least not in an 
application or a library.)

For a large application, sometimes we need to a 6th level since DEBUG might be 
too verbose for some customers (random value: 1 MiB of log per minute). The 
OpenStack project has 2 additional logging levels: TRACE and AUDIT. See the 
Oslo Log project used by all OpenStack projects:

https://github.com/openstack/oslo.log/blob/master/oslo_log/handlers.py#L39

The typical usage for TRACE is to log a Python traceback when an exception is 
logged:

logger.debug("Oops: something bad happened! %s", exc)
for line in my_exception_formatter(exc):
   logger.trace(line)

In software development, "trace" term is commonly associated to "debug traces", 
as in "How to get debug traces?". Or more commonly in Python: "traceback" or 
"stack trace".

An additional level helps to filter logs, but also to colorize logs differently.

--

I don't propose to add a new AUDIT level since it's not well defined and it's 
less popular in OpenStack. For example, the Oslo Log module adds a new 
logger.trace() method, but no logger.audit().

--
components: Library (Lib)
messages: 303945
nosy: haypo
priority: normal
severity: normal
status: open
title: Add TRACE level to the logging module
versions: Python 3.7

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com