Advanced Python logging system

Question 1

I've been writing Python for years, but I've only just started using it in bigger programs than just simple server scripts. This means I now also want to use a more advanced logging system. To make things simple I created the following logger:

import logging
from inspect import getframeinfo, stack
logger = logging.getLogger()
formatter = logging.Formatter('%(asctime)s %(name)-7s %(levelname)-8s %(message)s')
file_handler = logging.FileHandler('mm.log')
file_handler.setFormatter(formatter)
stream_handler = logging.StreamHandler()
stream_handler.setFormatter(formatter)
logger.addHandler(file_handler)
logger.addHandler(stream_handler)
logger.setLevel(logging.INFO)
def l(*args, **kwargs):
 level = kwargs.get('level', 'info').lower()
 assert level in ('debug', 'info', 'warning', 'error', 'critical')
 caller = getframeinfo(stack()[1][0])
 file_line = "%s:%d - " % (caller.filename, caller.lineno)
 logger_input = file_line + ' '.join([str(a) for a in args])
 getattr(logger, level)(logger_input)

This logs to stdout and to a logfile and also logs the filename and the line number from which the log is made. It can be used as follows:

from tools import l
l('Log message') # logs in INFO by default
l('Log message one', 'log message two') # log multiple messages
l('Log message', level='critical') # log in critical level

which creates something like this:

2017年10月10日 20:47:16,170 root INFO test.py:5 - Log message
2017年10月10日 20:47:16,171 root INFO test.py:14 - Log message one log message two
2017年10月10日 20:47:16,171 root CRITICAL test.py:116 - Log message

I import this in all the other files of my program and it seems to work quite ok. It enables to me to run the program from the command line and see the output, as well as running it as a daemon and seeing the output in the log files later. Furthermore, it's easy for debugging because it also logs the filename and line number, and I can easily change the default logging level with one line. Lastly, the use of a single l shortens the way of logging things. All in all, I'm quite happy with it.

I'm unsure if this is for some reason stupid though. Maybe there are situations which I can't oversee right now which would make this mess up things. Maybe the default conversion to strings is not smart for some reason?

Could anybody enlighten me as to what could be wrong with this or how it could be made better/more robust? All tips are welcome!

Question 2

Are you sure about your example? Not l('Log message one','log message two')?

Question 3

@Zeta - You're right. Although this also works it doesn't show the thing I was trying to show.. :-)

Question 4

PEP-8 Conventions

Top-level functions should be separated (preceded and followed) by two blank lines:
```
logger.setLevel(logging.INFO)
def l(*args, **kwargs):
 <body>
```
Don't mix single quotes ' and double quotes " in a single file (or project). You may you use either of them, but

Pick a rule and stick to it.
Lines should not exceed 79 characters (or 73 characters for documentation).

General concerns

l is a bad name for a function. Always try to pick a name that describes what the function does, like log.
You haven't added any docstrings to your function. If anyone else wants to use your code, they have no way to know what parameters to pass (or what the function actually does). According to PEP-257,

All modules should normally have docstrings, and all functions and classes exported by a module should also have docstrings.

A good docstring describes what your function does, what parameters it expects, what it returns and if applicable, what Exception it raises if something goes wrong.
assert should really only be used for debugging purposes, not in the 'stable' release. I propose raising a ValueError instead.
Since you're only retrieving the level argument from **kwargs, you may as well make it a keyword argument.

Improved code

Taking into account all of the above, here's my rewritten version of your code:

import logging
from inspect import getframeinfo, stack
logger = logging.getLogger()
formatter = logging.Formatter('
 %(asctime)s %(name)-7s %(levelname)-8s %(message)s
')
file_handler = logging.FileHandler('mm.log')
file_handler.setFormatter(formatter)
stream_handler = logging.StreamHandler()
stream_handler.setFormatter(formatter)
logger.addHandler(file_handler)
logger.addHandler(stream_handler)
logger.setLevel(logging.INFO)
def log(*args, level='info'):
 """Log a message to stdout and a log file.
 Arguments:
 - *args: All messages to be logged (as strings).
 - level: The level for debugging. Any of 'debug', 'info', 'warning',
 'error', 'critical'. Defaults to 'info'.
 Raises:
 - ValueError if an invalid `level` argument is passed.
 """
 LEVELS = ('debug', 'info', 'warning', 'error', 'critical')
 level = level.lower()
 if level not in LEVELS:
 raise ValueError('`level` argument must be any of {}'.format(
 str(LEVELS)[1:-1]
 )
 caller = getframeinfo(stack()[1][0])
 file_line = '%s:%d - ' % (caller.filename, caller.lineno)
 logger_input = file_line + ' '.join([str(a) for a in args])
 getattr(logger, level)(logger_input)

The use of *args in the above snippet breaks backward compatibility!

Question 5

Thanks for your feedback. The things you mention are all valid points. But I guess it means that once I use your adjusted version, the general working of the logging code is pretty good? I mean, this wouldn't create problems when using concurrency?

Question 6

Unfortunately you can't put a keyword argument after the *args argument. That is why I used the **kwargs for it.

Question 7

@kramer65 You can in Python 3.x. (And you did not specify which Python version you are using, as far as I can see). However it might make sense to at least mention that this breaks backwards compatibility.

Question 8

@kramer65 I'm not confident I'm qualified to answer your questions regarding concurrency, as I don't have a lot of experience with it. Perhaps you can open an updated question (or edit this one) to specifically express your concerns on that part.

Daniel Daniel 4,6222 gold badges18 silver badges40 bronze badges · Answer 1 · 2017-10-11 09:21:48Z

PEP-8 Conventions

Top-level functions should be separated (preceded and followed) by two blank lines:
```
logger.setLevel(logging.INFO)
def l(*args, **kwargs):
 <body>
```
Don't mix single quotes ' and double quotes " in a single file (or project). You may you use either of them, but

Pick a rule and stick to it.
Lines should not exceed 79 characters (or 73 characters for documentation).

General concerns

l is a bad name for a function. Always try to pick a name that describes what the function does, like log.
You haven't added any docstrings to your function. If anyone else wants to use your code, they have no way to know what parameters to pass (or what the function actually does). According to PEP-257,

All modules should normally have docstrings, and all functions and classes exported by a module should also have docstrings.

A good docstring describes what your function does, what parameters it expects, what it returns and if applicable, what Exception it raises if something goes wrong.
assert should really only be used for debugging purposes, not in the 'stable' release. I propose raising a ValueError instead.
Since you're only retrieving the level argument from **kwargs, you may as well make it a keyword argument.

Improved code

Taking into account all of the above, here's my rewritten version of your code:

import logging
from inspect import getframeinfo, stack
logger = logging.getLogger()
formatter = logging.Formatter('
 %(asctime)s %(name)-7s %(levelname)-8s %(message)s
')
file_handler = logging.FileHandler('mm.log')
file_handler.setFormatter(formatter)
stream_handler = logging.StreamHandler()
stream_handler.setFormatter(formatter)
logger.addHandler(file_handler)
logger.addHandler(stream_handler)
logger.setLevel(logging.INFO)
def log(*args, level='info'):
 """Log a message to stdout and a log file.
 Arguments:
 - *args: All messages to be logged (as strings).
 - level: The level for debugging. Any of 'debug', 'info', 'warning',
 'error', 'critical'. Defaults to 'info'.
 Raises:
 - ValueError if an invalid `level` argument is passed.
 """
 LEVELS = ('debug', 'info', 'warning', 'error', 'critical')
 level = level.lower()
 if level not in LEVELS:
 raise ValueError('`level` argument must be any of {}'.format(
 str(LEVELS)[1:-1]
 )
 caller = getframeinfo(stack()[1][0])
 file_line = '%s:%d - ' % (caller.filename, caller.lineno)
 logger_input = file_line + ' '.join([str(a) for a in args])
 getattr(logger, level)(logger_input)

The use of *args in the above snippet breaks backward compatibility!

Thanks for your feedback. The things you mention are all valid points. But I guess it means that once I use your adjusted version, the general working of the logging code is pretty good? I mean, this wouldn't create problems when using concurrency?
Unfortunately you can't put a keyword argument after the *args argument. That is why I used the **kwargs for it.
@kramer65 You can in Python 3.x. (And you did not specify which Python version you are using, as far as I can see). However it might make sense to at least mention that this breaks backwards compatibility.
@kramer65 I'm not confident I'm qualified to answer your questions regarding concurrency, as I don't have a lot of experience with it. Perhaps you can open an updated question (or edit this one) to specifically express your concerns on that part.

Stack Exchange Network

Advanced Python logging system

1 Answer 1

PEP-8 Conventions

General concerns

Improved code

Your Answer

Sign up or log in

Post as a guest

Post as a guest

Hot Network Questions

Advanced Python logging system

1 Answer 1

PEP-8 Conventions

General concerns

Improved code

Your Answer

Sign up or log in

Post as a guest

Post as a guest

Related

Hot Network Questions