ENH: Migrate logs to `logging`

Summary

Proposal to migrate logs done with print() to logging

Rationale

Python logging module offers a better control over verbosity levels or channels to report events.

For instance, it would permit to trace every events (including DEBUG ones) into a file, while more severe/important ones are traced into the console. WARNINGs and ERRORs could be sent by email.

While a template could be provided by default, end-users would be able to adapt the logging configuration to their needs.

Consequences

If the evolution is conducted, there would be a few things that'll require attention

1. print() should be reserved to "Display console output for ordinary usage of a command line script or program", and yet traced to files (INFO level?)

2. Call to external tools (OTB or GDAL applications) should be redirected. But with which severity level?

3. When producing log files, shall we really generate a file for non-errors, and a file for errors like how it's done at this moment? Wouldn't it be better to have a log file with errors and warnings only, and a file with everything else? This way, we'd have the list of events that require attention on its own, and a complete and consistent list in another file. IOW, no need to struggle to reorder the things sent to stdout and sterr because they have been separated.

4. We'll need to assign the right level to all the current messages in S1Tiling.

Example

A simple python program

As we can see, we dan override the settings in the configuration file through options like --verbose=2 for instance.

#!/usr/bin/env python3
# -*- coding: utf-8 -*-

import logging
import logging.config
import yaml
from contextlib import redirect_stdout

with open('logging.conf.yaml', 'r') as stream:
    # FullLoader requires yaml 5.1
    config = yaml.load(stream, Loader=yaml.FullLoader)
    # config = yaml.load(stream)

# print(config)
verbose = True
# verbose = False
if verbose:
    # Control the maximum global verbosity level
    config["root"]["level"] = "DEBUG"

    # Control the local console verbosity level
    config["handlers"]["console"]["level"] = "DEBUG"

# print(config)

# Here, we can change things like add 'debug' to the console
# Or the current global level
logging.config.dictConfig(config)

# create logger
# logger = logging.getLogger('simpleExample')
logger = logging.getLogger('root')
logger.write = lambda msg: logger.info(msg) if msg != '\n' else None

# 'application' code
logger.debug('debug message')
logger.info('info message')
with redirect_stdout(logger):
    print("test")
logger.warning('warn message')
logger.error('error message')
logger.critical('critical message')

The YAML configuration file

The configuration file, in YAML format

version: 1
disable_existing_loggers: true
formatters:
    brief:
        format: '%(message)s'
    simple:
        format: '%(levelname)s - %(message)s'
    full:
        format: '%(asctime)s - %(name)-15s - %(levelname)-8s - %(message)s'

handlers:
    console:
        class: logging.StreamHandler
        level: INFO
        formatter: simple
        stream: ext://sys.stdout
    file:
        class: logging.FileHandler
        level: DEBUG
        formatter: full
        filename: logging-test.log
        mode: w # 'w' disable 'a'ppend
    important:
        class: logging.FileHandler
        level: WARNING
        formatter: full
        filename: logging-test-IMPORTANT.log
        mode: w # 'w' disable 'a'ppend
    # email:
    #     class: logging.handlers.SMTPHandler
    #     mailhost: localhost
    #     fromaddr: my_app@domain.tld
    #     toaddrs:
    #         - support_team@domain.tld
    #         - dev_team@domain.tld
    #     subject: Houston, we have a problem.

loggers:
    simpleExample:
        level: DEBUG
        handlers: [console]
        propagate: no
root:
    level: INFO
    handlers: [console,file, important]

Results

Console

DEBUG - debug message
INFO - info message
INFO - test
WARNING - warn message
ERROR - error message
CRITICAL - critical message

logging-test.log

2020-03-18 15:42:12,283 - root            - DEBUG    - debug message
2020-03-18 15:42:12,283 - root            - INFO     - info message
2020-03-18 15:42:12,283 - root            - INFO     - test
2020-03-18 15:42:12,283 - root            - WARNING  - warn message
2020-03-18 15:42:12,283 - root            - ERROR    - error message
2020-03-18 15:42:12,283 - root            - CRITICAL - critical message

logging-test-IMPORTANT.log

2020-03-18 15:42:12,283 - root            - WARNING  - warn message
2020-03-18 15:42:12,283 - root            - ERROR    - error message
2020-03-18 15:42:12,283 - root            - CRITICAL - critical message