Move logging from root logger

[pee-po]

Logging to root logger is a bad practice - in order to allow customisation, a uniquely named logger should be used.
Normally, logs are sent to a logger named the same way as the module (i.e. entsoe, entsoe.decorators), or equivalently the logger name is set to __name__. The latter is what this PR introduces.

See here and here.

This topic is hard to test automatically, so manual tests were performed.

Here's a reproducible setup:

main.py:

import mymod
import pandas as pd
import logging

mymod.logger.info('Log Info 1')

# Guarantee empty data and therefore a log from entsoe
start = pd.Timestamp('2014-01-01 00:00:00', tz='Europe/Warsaw')
mymod.get_net_position('PL', start=start, end=start + pd.Timedelta(days=1))

mymod.logger.info('Log Info 2')

entsoe_logger = logging.getLogger('entsoe')
entsoe_logger.setLevel(logging.DEBUG)
entsoe_logger.addHandler(mymod.log_handler_std)
mymod.get_net_position('PL', start=start, end=start + pd.Timedelta(days=1))

mymod.logger.info('Log Info 3')

mymod/funs.py:

from entsoe import EntsoePandasClient
from entsoe.exceptions import NoMatchingDataError
from settings import api_key

def get_net_position(country, start, end):
    client = EntsoePandasClient(api_key)
    try:
        df = client.query_net_position(country, start=start, end=end)
    except NoMatchingDataError:
        df = None
    return df

mymod/__init__.py:

from .funs import get_net_position
import logging
import sys

log_handler_std = logging.StreamHandler(sys.stdout)
formatter = logging.Formatter(
    '%(asctime)s - %(name)s - %(levelname)s - %(message)s'
)
log_handler_std.setFormatter(formatter)

logger = logging.getLogger(__name__)
logger.setLevel(logging.DEBUG)
logger.addHandler(log_handler_std)

__all__ = [
    'get_net_position',
    'logger',
    'log_handler_std'
]

After this PR the result of main.py is:

2023-09-15 23:54:56,531 - mymod - INFO - Log Info 1
2023-09-15 23:54:57,062 - mymod - INFO - Log Info 2
2023-09-15 23:54:57,065 - entsoe.entsoe - DEBUG - Performing request to https://web-api.tp.entsoe.eu/api with params {'documentType': 'A25', 'businessType': 'B09', 'Contract_MarketAgreement.Type': 'A01', 'in_Domain': '10YPL-AREA-----S', 'out_Domain': '10YPL-AREA-----S', 'securityToken': '6284c86a-839c-4da2-86fa-19f9c4833ba8', 'periodStart': '201312312300', 'periodEnd': '201401012300'}
2023-09-15 23:54:57,318 - entsoe.decorators - DEBUG - NoMatchingDataError: between 2014-01-01 00:00:00+01:00 and 2014-01-02 00:00:00+01:00
2023-09-15 23:54:57,320 - mymod - INFO - Log Info 3

which is very much expected - normal logs are intact and entsoe-py logs are logged only when explicitly required to do so.

Conversely, before this PR the result of main.py is:

2023-09-15 23:58:00,981 - mymod - INFO - Log Info 1
2023-09-15 23:58:01,184 - mymod - INFO - Log Info 2
INFO:mymod:Log Info 2
2023-09-15 23:58:01,392 - mymod - INFO - Log Info 3
INFO:mymod:Log Info 3

which is a mess. entsoe-py logs are hard to parse and normal logs are distorted since the first entsoe log.

I realize that the propagate=False trick was proposed in #86 but this is a half-measure. I also checked whether this approach still produces expected results.

main2.py:

import mymod
import pandas as pd
import logging

logger = mymod.logger
logger.propagate = False
logger.info('Log Info 1')

start = pd.Timestamp('2014-01-01 00:00:00', tz='Europe/Warsaw')
mymod.get_net_position('PL', start=start, end=start + pd.Timedelta(days=1))

logger.info('Log Info 2')

gives same result for old and new approach, hence this is not a breaking change (as far as the recommended approach goes).

Fixes: #86

[fboerman]

hi! sorry for the late response, this indeed seems like a good idea!