Fix to ensure that asyncio uses SaltLoggingClass

[barneysowood]

What does this PR do?

Adds a check in to salt._logging.impl to ensure that the logger for asyncio is using SaltLoggingClass. If asyncio has been imported before salt._logging then the class is already set to logging.Logger. That can't handle additional fields such as %(jid)s and will throw an exception if that is set in the fmt string.

I considered just changing the order of imports in salt/__init__.py, which works when running salt normally, however it was impossible to test as the test suite always imports asyncio well before any salt modules are imported.

What issues does this PR fix or reference?

Fixes #68400

Previous Behavior

When using a log_fmt_console with %(jid)s and a log_level of debug, there would be exceptions like this:

--- Logging error ---
Traceback (most recent call last):
  File "/opt/saltstack/salt/lib/python3.10/logging/__init__.py", line 440, in format
    return self._format(record)
  File "/opt/saltstack/salt/lib/python3.10/logging/__init__.py", line 436, in _format
    return self._fmt % values
KeyError: 'jid'

New Behavior

No exceptions are thrown

Merge requirements satisfied?

[NOTICE] Bug fixes or features added to Salt require tests.

• Changelog - https://docs.saltproject.io/en/master/topics/development/changelog.html
• Tests written/updated

Commits signed with SSH?

Yes

[bdrx312]

Is this really the correct/ideal way to do this? Shouldn't a the logger be created/instantiated as a SaltLoggingClass and assigned to the logger instead of mucking with the internal attributes?

[barneysowood]

The logger for asyncio isn't being created in salt - it's created within asyncio and happens as soon as you import it:

>>> import logging
>>> logging.root.getChildren()
set()
>>> import asyncio
>>> logging.root.getChildren()
{<Logger asyncio (WARNING)>}
>>>

As I noted above, the other option is to try to make sure that asyncio is imported after salt._logging, but that is somewhat fragile and it also doesn't work in the test suite where asyncio gets imported by pytest (or maybe one of the pytest extensions..)

I don't love it as a solution, but I can't see a better way to do it - open to suggestions if you can.

[bdrx312]

Would something like this quick untested rough draft (with the help from llm) work?

import logging

def ensure_asyncio_uses_salt_logger(SaltLoggingClass):
    name = "asyncio"
    mgr = logging.root.manager
    # Preserve any existing logger settings
    existing = mgr.loggerDict.get(name)
    handlers = getattr(existing, "handlers", []) if isinstance(existing, logging.Logger) else []
    level = getattr(existing, "level", logging.NOTSET) if isinstance(existing, logging.Logger) else logging.NOTSET
    propagate = getattr(existing, "propagate", True) if isinstance(existing, logging.Logger) else True

    # Create SaltLoggingClass logger instance
    salt_logger = SaltLoggingClass(name)
    # Copy preserved state
    salt_logger.handlers[:] = handlers[:]    # shallow copy handlers list
    salt_logger.setLevel(level)
    salt_logger.propagate = propagate

    # Replace manager entry so logging.getLogger(name) returns salt_logger
    mgr.loggerDict[name] = salt_logger

[barneysowood]

Thanks for the suggestion, although that won't entirely solve the problem. Whilst that will replace the logger for asyncio in the logging manager and any new calls to logging.getLogger("asyncio") will return the new logger, the logger used by the asyncio module has already been assigned, so it will continue to use the old logger object.

We could do something like this and then update asyncio.logger I guess. That said, I'm wondering if it makes more sense to move the code that enriches the log records (ie adding jid) out of the SaltLoggerClass and into a filter that can be applied to existing logging classes. Will have a play about with that to see how much effort that'd be.