Error when initializing queue listener from config file

[djsaroka]

I'm loading a logger from a yaml config file.
I noticed that a custom handler that I named "sql" was not initializing.
It is a number of handlers that I have connected to a queue listener that I named "queue_listener" also loading from the file.
I noticed that it left the sql handler as <class 'logging.config.ConvertingDict'> when it added it to the listener instead of resolving it.
So then it would error later with:
process = record.levelno >= handler.level
AttributeError: 'ConvertingDict' object has no attribute 'level'

I tried a multitude of things that did not work so I looked at the logging config.py to see what I was doing wrong with the values I was sending in.
I noticed that in line 563 that it imported the handlers sorted from the config file, ascending alphabetical order.
I tested naming my queue listener, "z_queue_listener" and then everything worked fine.
I think it would probably be best to pull the handlers in order that they are in the config file to avoid this error.
I also tested and reproduced this error with the built in logging handler types as well.

[JelleZijlstra]

Could you give a code sample that demonstrates the problem you are seeing? You say something about "line 563", but I have no idea what file you are talking about.

I don't think the standard library supports YAML config files anywhere, so your problem may be with a third-party library, not with CPython itself.

[djsaroka]

Could you give a code sample that demonstrates the problem you are seeing? You say something about "line 563", but I have no idea what file you are talking about.

I don't think the standard library supports YAML config files anywhere, so your problem may be with a third-party library, not with CPython itself.

@JelleZijlstra I apologize for not being explicit enough.
I get the configuration information from the yaml file, which uses a 3rd party library to get a dictionary.
Then I use the logging dict config method to load the configuration.

with open(config_file_path.absolute(), 'r') as f:
    config_dict = yaml.safe_load(f.read())
    logging.config.dictConfig(config_dict)

So if you were to look at the config_dict, it is in the same order in which they appear in the file.
When I mention line 563 I am talking about the python built in logging config module, i.e. config.py:

# Next, do handlers - they refer to formatters and filters
# As handlers can refer to other handlers, sort the keys
# to allow a deterministic order of configuration
handlers = config.get('handlers', EMPTY_DICT)
deferred = []
for name in sorted(handlers): <- RIGHT HERE
    try:
        handler = self.configure_handler(handlers[name])
        handler.name = name
        handlers[name] = handler
    except Exception as e:
        if 'target not configured yet' in str(e.__cause__):
            deferred.append(name)
        else:
            raise ValueError('Unable to configure handler '
                             '%r' % name) from e

I should also mention that in order to get the queue listener to work from a config file I made a custom class.
I found an example and modified it to:

class QueueListenerHandler(QueueHandler):

    def __init__(
        self, 
        handlers, 
        respect_handler_level=False, 
        auto_run=True, 
        queue=Queue(-1)
    ):

        super().__init__(queue)
        self._listener = QueueListener(
            self.queue,
            *handlers,
            respect_handler_level=respect_handler_level)

        self._listener.handlers = list(self._resolve_handlers(handlers))

        if auto_run:
            self.start()
            atexit.register(self.stop)

    def _resolve_handlers(self, l):

        if not isinstance(l, ConvertingList):
            return l

        # Indexing the list performs the evaluation.
        return [l[i] for i in range(len(l))]

    def add_handler(self, handler):

        if not handler in self._listener.handlers:
            self._listener.handlers.append(handler)

    def remove_handler(self, handler):

        if handler in self._listener.handlers:
            handler.close()
            self._listener.handlers.remove(handler)

    def start(self):
        self._listener.start()

    def stop(self):
        self._listener.stop()

    def emit(self, record):
        return super().emit(record)

So my config file would look like:

version: 1
formatters:
  simple:
    format: "%(asctime)s | %(levelname)-8s | %(name)-12s | %(message)s"
    datefmt: "%Y-%m-%d %H:%M:%S"
  detailed:
    format: "%(asctime)s | %(levelname)-8s | %(name)-12s | %(processName)s-%(module)s-%(funcName)-25s | %(message)s"
    datefmt: "%Y-%m-%d %H:%M:%S"
handlers:
  console:
    class: logging.StreamHandler
    level: DEBUG
    formatter: simple
    stream: ext://sys.stdout
  file:
    class: logging.FileHandler
    level: DEBUG
    formatter: detailed
    filename: Logs/log-file.log
    mode: w
  queue_listener:
    class: Support.QueueListenerHandler
    handlers: 
      - cfg://handlers.console
      - cfg://handlers.file
    respect_handler_level: True
loggers:
  process_logger:
    level: DEBUG
    handlers: 
      - queue_listener
    propagate: False
root:
  level: DEBUG
  handlers:
    - console

Here's how I'm testing it:

with open('Files/config copy.yaml', 'r') as f:
        config_dict = yaml.safe_load(f.read())
        logging.config.dictConfig(config_dict)

logger = logging.getLogger("process_logger")
logger.debug('This is a debug message')

The output is:
2022-05-18 14:51:01 | DEBUG | process_logger | This is a debug message
But if I modified the file handler to z_file:

version: 1
formatters:
  simple:
    format: "%(asctime)s | %(levelname)-8s | %(name)-12s | %(message)s"
    datefmt: "%Y-%m-%d %H:%M:%S"
  detailed:
    format: "%(asctime)s | %(levelname)-8s | %(name)-12s | %(processName)s-%(module)s-%(funcName)-25s | %(message)s"
    datefmt: "%Y-%m-%d %H:%M:%S"
handlers:
  console:
    class: logging.StreamHandler
    level: DEBUG
    formatter: simple
    stream: ext://sys.stdout
  z_file:
    class: logging.FileHandler
    level: DEBUG
    formatter: detailed
    filename: Logs/log-file.log
    mode: w
  queue_listener:
    class: Support.QueueListenerHandler
    handlers: 
      - cfg://handlers.console
      - cfg://handlers.z_file
    respect_handler_level: True
loggers:
  process_logger:
    level: DEBUG
    handlers: 
      - queue_listener
    propagate: False
root:
  level: DEBUG
  handlers:
    - console

The output is an error message:
process = record.levelno >= handler.level
AttributeError: 'ConvertingDict' object has no attribute 'level'

That's what I was explaining before where it is not evaluating the handler if it is alphabetically after the queue listener

[akulakov]

Note that the line in question,

for name in sorted(handlers):

is from 2010 and so predates the change that made dicts keep their defined order, so the sorting was probably done for consistency of order.

[akulakov]

The comment above the line I referenced, indicates it's indeed sorted for consistency and to allow references between handlers.

I don't think it can be changed as @djsaroka requested because it would be break existing code, but a doc note may be added (as I haven't been able to find any such note); -- possibly in this section: https://docs.python.org/3.12/library/logging.config.html#dictionary-schema-details

[vsajip]

I think this issue is now out of date as there is now a mechanism for configuring QueueListener / QueueHandler together in #93269.