Demystifying Python Logging

One of the most important aspects, and at the same time weakest I found in python: Handling logs. It seemed strange to me to see how the programs were full of prints that essentially served two purposes: debugging and as the exit of the process or program in execution. In a project came the issue of how to handle the logs in an orderly and standard manner and of course, after some research I found a way to achieve just what I wanted: Output by the console and at the same time write to disk, in a file of my preference of the output of the program: Using only the Python logging library is enough to achieve a decent output of our code result.

We are using only 2 python’s standard library modules.

import time
import logging

Basic Config

We define the basic configuration, which is the one that will be used to write to disk, notice we use asctime, levelname (log level), and the message itself. We also configure the default “level” and the name of the output file (can have a relative or absolute path)

logging.basicConfig(format='%(asctime)s %(levelname)-8s %    (message)s',datefmt='%m/%d/%Y %I:%M:%S',
                  filename='output.log',
                  level=logging.DEBUG)

Console

Now comes the configuration of the console: instead of basicConfig we use StreamHandler () and the default level to INFO. Use exactly the same output format, maybe you want to use a different one for each. You can see better how logging works in the documentation.

Then we add the handler to the logging so that both happen at the same time. That is, write to disk and display in the console.

console = logging.StreamHandler()
console.setLevel(logging.INFO)formatter = logging.Formatter(
    '%(asctime)s %(levelname)-8s: %(message)s')console.setFormatter(formatter)logging.getLogger('').addHandler(console)

Example

I’ll show some examples of use, note that we must manually set the level of log we want to show, that is, the library itself can not determine when it is an error or info or whatever. We must do it by ourselves depending on the possible behavior of a block of code, notice:

a = 'a string'
try:
    b = a + 1
except TypeError as e:
    logging.error('OH! There has been an error: {}'.format(e))

Ah! and the output?

Finally, this is what the output of our newly configured log looks like.

05/17/2018 10:41:44 INFO     Inicio de mi programa
05/17/2018 10:41:46 WARNING  Una advertencia
05/17/2018 10:41:46 ERROR    OH! Ha ocurrido un error: Can't convert 'int' object to str implicitly
05/17/2018 10:41:46 CRITICAL Huston tenemos un problema! No podemos sumar strings y enteros
05/17/2018 10:41:46 INFO     Fin de la diversion (por ahora)
05/17/2018 10:42:56 INFO     Inicio de mi programa
05/17/2018 10:42:58 WARNING  Una advertencia
05/17/2018 10:42:58 ERROR    OH! Ha ocurrido un error: Can't convert 'int' object to str implicitly
05/17/2018 10:42:58 CRITICAL Huston tenemos un problema! No podemos sumar strings y enteros
05/17/2018 10:43:00 INFO     Fin de la diversion (por ahora)

The Code

Here the complete piece of code:

# Don't forget to import your modules
import time
import logging
# log basic conf
logging.basicConfig(format='%(asctime)s %(levelname)-8s %(message)s',
                    datefmt='%m/%d/%Y %I:%M:%S',
                    filename='output.log',
                    level=logging.DEBUG)
# Handler which writes INFO messages or higher to the sys.stderr
console = logging.StreamHandler()
console.setLevel(logging.INFO)
# set a format which is simpler for console use
formatter = logging.Formatter(
    '%(asctime)s %(levelname)-8s: %(message)s')
# tell the handler to use this format
console.setFormatter(formatter)
# add the handler to the root logger
logging.getLogger('').addHandler(console)
# lets play
logging.info('Starting the program')
# time delay to see better how time logging works
time.sleep(2)
# lets test a warning
# Notice: we get to handle the severity of the logs
logging.warn('Showing a warning')
a = 'a string'
try:
    b = a + 1
except TypeError as e:
    # we can combine our own text with the system output
    logging.error('OH! There has been an error: {}'.format(e))
# keep testing this
if isinstance(a, str):
    logging.fatal(
        'Huston we\'ve got a problem cannot sum strings to integers')
time.sleep(2)
# end of the fun
logging.info('End of the fun (by now)')

Conclusion

As I’ve shown above the python’s logging library or module, few lines of codes, and some discipline in its usage can way improve your scripts or programs. It is super easy giving your code output a professional look sending data to the screen or to a file at the same time just like every decent software does “out there”. From now stop using the print statement for this task as it is not its main purpose and leverage the power of Logging!