Interoperability of logging with ignite logger

[sdesrozis]

🐛 Bug description

This bug is related to logger from module logging. Actually, (logging) handlers are attached to loggers created by user.

ignite/ignite/utils.py

Lines 64 to 137 in bef668c

	def setup_logger(
	name: Optional[str] = None,
	level: int = logging.INFO,
	format: str = "%(asctime)s %(name)s %(levelname)s: %(message)s",
	filepath: Optional[str] = None,
	distributed_rank: Optional[int] = None,
	) -> logging.Logger:
	"""Setups logger: name, level, format etc.
	Args:
	name (str, optional): new name for the logger. If None, the standard logger is used.
	level (int): logging level, e.g. CRITICAL, ERROR, WARNING, INFO, DEBUG
	format (str): logging format. By default, `%(asctime)s %(name)s %(levelname)s: %(message)s`
	filepath (str, optional): Optional logging file path. If not None, logs are written to the file.
	distributed_rank (int, optional): Optional, rank in distributed configuration to avoid logger setup for workers.
	If None, distributed_rank is initialized to the rank of process.
	Returns:
	logging.Logger
	For example, to improve logs readability when training with a trainer and evaluator:
	.. code-block:: python
	from ignite.utils import setup_logger
	trainer = ...
	evaluator = ...
	trainer.logger = setup_logger("trainer")
	evaluator.logger = setup_logger("evaluator")
	trainer.run(data, max_epochs=10)
	# Logs will look like
	# 2020-01-21 12:46:07,356 trainer INFO: Engine run starting with max_epochs=5.
	# 2020-01-21 12:46:07,358 trainer INFO: Epoch[1] Complete. Time taken: 00:5:23
	# 2020-01-21 12:46:07,358 evaluator INFO: Engine run starting with max_epochs=1.
	# 2020-01-21 12:46:07,358 evaluator INFO: Epoch[1] Complete. Time taken: 00:01:02
	# ...
	"""
	logger = logging.getLogger(name)
	# Remove previous handlers
	if logger.hasHandlers():
	for h in list(logger.handlers):
	logger.removeHandler(h)
	formatter = logging.Formatter(format)
	if distributed_rank is None:
	if dist.is_available() and dist.is_initialized():
	distributed_rank = dist.get_rank()
	else:
	distributed_rank = 0
	if distributed_rank > 0:
	logger.addHandler(logging.NullHandler())
	else:
	logger.setLevel(level)
	ch = logging.StreamHandler()
	ch.setLevel(level)
	ch.setFormatter(formatter)
	logger.addHandler(ch)
	if filepath is not None:
	fh = logging.FileHandler(filepath)
	fh.setLevel(level)
	fh.setFormatter(formatter)
	logger.addHandler(fh)
	return logger

From logging documentation (https://docs.python.org/3/howto/logging.html#loggers)

Child loggers propagate messages up to the handlers associated with their ancestor loggers. Because of this, it is unnecessary to define and configure handlers for all the loggers an application uses. It is sufficient to configure handlers for a top-level logger and create child loggers as needed. (You can, however, turn off propagation by setting the propagate attribute of a logger to False.)

This code shows the problem of propagation to ancestor

# no ancestor so print is ok
logger = setup_logger("logger")
logger.info("message 1 from test logger") 

# logging creates root ancestor of all loggers including one above 
logging.info("message from default logging, a root logger is defined !")

# root + logger dump...
logger.info("message 2 from test logger")

Result is

> 2020-05-05 09:24:27,583 logger INFO: message 1 from test logger
> 2020-05-05 09:24:27,583 logger INFO: message 2 from test logger
> INFO:logger:message 2 from test logger

Environment

• PyTorch Version (e.g., 1.4): 1.5
• Ignite Version (e.g., 0.3.0): 0.4
• OS (e.g., Linux): Linux
• How you installed Ignite (conda, pip, source): conda
• Python version: 3.7
• Any other relevant information: