Ben Chuanlong Du's Blog

It is never too late to learn.

Hands on the logging Module in Python

In [1]:
import logging
In [2]:
logging.basicConfig(
    format="%(asctime)s | %(module)s.%(funcName)s: %(lineno)s | %(levelname)s: %(message)s",
    level=logging.INFO,
)
In [3]:
logging.info("a testing mesage")
2020-08-16 12:48:34,347 | <ipython-input-3-91855f049bb2>.<module>: 1 | INFO: a testing mesage

General Tips

  1. Do NOT use %, str.format or f-string to format strings when you log messages. Instead, passing parameters to logging methods so that lazy string evaluation can be leveraged.

     :::python
     # for the logging module
     logger.info("%s is copied to %s", src_file, des_file)
    
     # for the loguru module
     logger.info("{} is copied to {}", src_file, des_file)

The Confusing style Option

The style option of the method logging.basicConfig is for the format option of the method only. It is NOT the style of strings when you actually log messages (using method logging.info, logging.debug, etc.). Those logging methods always use the % style no matter what value you set the style option (of the logging.basicConfig) to.

Traps in Using the logging Module Directly

There are 2 ways to use the logging module. First, you can create a logger object which is the recommended way. Howerver, another even simpler way is to use the logging module directly. Be aware that if you use the logging module directly, the default logging level is WARNING (30), which means that logging.info will not print anything. You can set the default level of the root logger using the following command.

logging.basicConfig(level=logging.INFO)

But again be aware that

  1. You have to call the method logging.basicConfig before any logging method (logging.info, logging.debug, etc.).
  2. If you call logging.basicConfig multiple times, only the first call is in effect.

Notice that the below code (default behavior) does not log anything.

In [10]:
%%writefile python_logging_1.py
#!/usr/bin/env python3
import logging
logging.info("a testing message")
Overwriting python_logging_1.py
In [13]:
!chmod +x python_logging_1.py
!./python_logging_1.py

Notice that the below code (after setting logging level to INFO) does make logging.info in effect.

In [17]:
%%writefile python_logging_2.py
#!/usr/bin/env python3
import logging
logging.basicConfig(level=logging.INFO)
logging.info("a testing message")
Overwriting python_logging_2.py
In [18]:
!chmod +x python_logging_2.py
!./python_logging_2.py
INFO:root:a testing message

Notice th below code

In [4]:
%%writefile python_logging_3.py
#!/usr/bin/env python3
import logging
logging.basicConfig(level=logging.INFO)
logging.basicConfig(level=logging.CRITICAL)
logging.info("a testing message")
Writing python_logging_3.py
In [22]:
!chmod +x python_logging_3.py
!./python_logging_3.py
INFO:root:a testing message

Control Logging Level from Command-line

It is often desirable to control the logging level using a command-line option. Let's say that you use the option --level to accept names (warning, debug, info, etc) of logging levels (rather than the corresponding integer values so that you do not have to remember the integer values of levels), and the corresponding variable is args.level. You can retrive the corresponding logging level using getattr(logging, args.level.upper()). And thus you can easily set the logging level with the following code.

:::python
level = getattr(logging, args.level.upper())
logging.setLevel(level)
In [ ]:
 

Comments