pytroll / trollflow2

Next generation Trollflow. Trollflow is for batch-processing satellite data using Satpy
https://trollflow2.readthedocs.org/
GNU General Public License v3.0
10 stars 15 forks source link

Subprocess crash when using custom log config #183

Closed tecnavia-dev closed 9 months ago

tecnavia-dev commented 1 year ago

Describe the bug When I use a custom log config the subprocess crashes, because the handlers are missing.

To Reproduce

satpy_launcher.py -c log_config.yaml

File config:

version: 1

disable_existing_loggers: False
formatters:
  pytroll:
    format: "[%(levelname)s: %(asctime)s: %(name)s] %(message)s"
    datefmt: "%Y-%m-%d %H:%M:%S"

handlers:
  file:
    class: logging.handlers.TimedRotatingFileHandler
    formatter: pytroll
    filename: /path/to/file
    when: midnight
    backupCount: 10  # Does not include the current log file.
    encoding: utf8
  console:
    class: logging.StreamHandler
    level: DEBUG
    formatter: pytroll

root:
  level: DEBUG
  handlers: [console, file]

loggers:
  server:
    level: DEBUG
    handlers: [file]

Expected behavior All message logged

Actual results After a subprocess is created It crashes

Error:

Process SpawnProcess-2:
Traceback (most recent call last):
  File "/usr/lib64/python3.9/logging/config.py", line 770, in add_handlers
    logger.addHandler(self.config['handlers'][h])
  File "/usr/lib64/python3.9/logging/config.py", line 325, in __getitem__
    value = dict.__getitem__(self, key)
KeyError: 'console'
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
  File "/usr/lib64/python3.9/logging/config.py", line 643, in configure
    self.configure_root(root)
  File "/usr/lib64/python3.9/logging/config.py", line 803, in configure_root
    self.common_logger_config(root, config, incremental)
  File "/usr/lib64/python3.9/logging/config.py", line 787, in common_logger_config
    self.add_handlers(logger, handlers)
  File "/usr/lib64/python3.9/logging/config.py", line 772, in add_handlers
    raise ValueError('Unable to add handler %r' % h) from e
ValueError: Unable to add handler 'console'
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
  File "/usr/lib64/python3.9/multiprocessing/process.py", line 315, in _bootstrap
    self.run()
  File "/usr/lib64/python3.9/multiprocessing/process.py", line 108, in run
    self._target(*self._args, **self._kwargs)
  File "/opt/pytroll/venv/pytoch_msg-1-2.1/lib/python3.9/site-packages/trollflow2/logging.py", line 141, in wrapper_decorator
    setup_queued_logging(log_queue, config=log_config)
  File "/opt/pytroll/venv/pytoch_msg-1-2.1/lib/python3.9/site-packages/trollflow2/logging.py", line 122, in setup_queued_logging
    _set_config(config)
  File "/opt/pytroll/venv/pytoch_msg-1-2.1/lib/python3.9/site-packages/trollflow2/logging.py", line 87, in _set_config
    logging.config.dictConfig(config)
  File "/usr/lib64/python3.9/logging/config.py", line 809, in dictConfig
    dictConfigClass(config).configure()
  File "/usr/lib64/python3.9/logging/config.py", line 645, in configure
    raise ValueError('Unable to configure root '
ValueError: Unable to configure root logger

Environment Info:

Solution I found that when the subprocess is created, It removes the handlers in the config.

logging.py

def setup_queued_logging(log_queue, config=None):
    """Set up queued logging in a spawned subprocess."""
    root_logger = getLogger()
    if config:
        remove_handlers_from_config(config)
    _set_config(config)
    queue_handler = QueueHandler(log_queue)
    root_logger.addHandler(queue_handler)

def remove_handlers_from_config(config):
    """Remove handlers from config."""
    config.pop("handlers", None)
    for logger in config["loggers"]:
        config["loggers"][logger].pop("handlers", None)

I removed __remove_handlers_from_config()__ and It fixed my issue.

What is the purpose of this function? Should I expect any problems by removing it?

gerritholl commented 1 year ago

I seem to get this problem when I have both a root and a loggers key in the dictionary. Do you still get this problem if you remove root?

mraspaud commented 1 year ago

The purpose of the removing is so that things are not logged twice when using the queued handler I think.