Ensure that fetching a logger doesn't reset its loglevel to default (#5222)

## What type of PR is this? (check all applicable)

- [ ] Refactor
- [ ] Feature
- [x] Bug Fix
- [ ] Optimization
- [ ] Documentation Update
- [ ] Community Node Submission


## Have you discussed this change with the InvokeAI team?
- [ ] Yes
- [X] No, because: minor bug

      
## Have you updated all relevant documentation?
- [X] Yes
- [ ] No


## Description

While writing regression tests for the queued downloader I discovered
that when using `InvokeAILogger.get_logger()` to fetch a
previously-created logger it resets that logger's log level to the
default specified in the global config. In other words, this didn't work
as expected:

```
import logging
from invokeai.backend.util.logging import InvokeAILogger
logger1 = InvokeAILogger.get_logger('TestLogger')
logger1.setLevel(logging.DEBUG)
logger2 = InvokeAILogger.get_logger('TestLogger')
assert logger1.level == logging.DEBUG
assert logger2.level == logging.DEBUG
```

This PR fixes the problem and adds a corresponding pytest.

## Related Tickets & Documents

<!--
For pull requests that relate or close an issue, please include them
below. 

For example having the text: "closes #1234" would connect the current
pull
request to issue 1234.  And when we merge the pull request, Github will
automatically close the issue.
-->

- Related Issue #
- Closes #

## QA Instructions, Screenshots, Recordings

<!-- 
Please provide steps on how to test changes, any hardware or 
software specifications as well as any other pertinent information. 
-->

## Added/updated tests?

- [X] Yes
- [ ] No

## [optional] Are there any post deployment tasks we need to perform?
This commit is contained in:
Lincoln Stein 2023-12-04 22:50:59 -05:00 committed by GitHub
commit 1ca0901cbe
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
3 changed files with 66 additions and 10 deletions

View File

@ -141,7 +141,7 @@ async def del_model_record(
status_code=201,
)
async def add_model_record(
config: Annotated[AnyModelConfig, Body(description="Model config", discriminator="type")]
config: Annotated[AnyModelConfig, Body(description="Model config", discriminator="type")],
) -> AnyModelConfig:
"""
Add a model using the configuration information appropriate for its type.

View File

@ -342,14 +342,13 @@ class InvokeAILogger(object): # noqa D102
cls, name: str = "InvokeAI", config: InvokeAIAppConfig = InvokeAIAppConfig.get_config()
) -> logging.Logger: # noqa D102
if name in cls.loggers:
logger = cls.loggers[name]
logger.handlers.clear()
else:
logger = logging.getLogger(name)
return cls.loggers[name]
logger = logging.getLogger(name)
logger.setLevel(config.log_level.upper()) # yes, strings work here
for ch in cls.get_loggers(config):
logger.addHandler(ch)
cls.loggers[name] = logger
cls.loggers[name] = logger
return cls.loggers[name]
@classmethod
@ -358,7 +357,7 @@ class InvokeAILogger(object): # noqa D102
handlers = []
for handler in handler_strs:
handler_name, *args = handler.split("=", 2)
args = args[0] if len(args) > 0 else None
arg = args[0] if len(args) > 0 else None
# console and file get the fancy formatter.
# syslog gets a simple one
@ -370,16 +369,16 @@ class InvokeAILogger(object): # noqa D102
handlers.append(ch)
elif handler_name == "syslog":
ch = cls._parse_syslog_args(args)
ch = cls._parse_syslog_args(arg)
handlers.append(ch)
elif handler_name == "file":
ch = cls._parse_file_args(args)
ch = cls._parse_file_args(arg)
ch.setFormatter(formatter())
handlers.append(ch)
elif handler_name == "http":
ch = cls._parse_http_args(args)
ch = cls._parse_http_args(arg)
handlers.append(ch)
return handlers

View File

@ -0,0 +1,57 @@
"""
Test interaction of logging with configuration system.
"""
import io
import logging
import re
from invokeai.app.services.config import InvokeAIAppConfig
from invokeai.backend.util.logging import LOG_FORMATTERS, InvokeAILogger
# test formatting
# Would prefer to use the capfd/capsys fixture here, but it is broken
# when used with the logging module: https://github.com/pytest-dev/pytest/issue
def test_formatting():
logger = InvokeAILogger.get_logger()
stream = io.StringIO()
handler = logging.StreamHandler(stream)
handler.setFormatter(LOG_FORMATTERS["plain"]())
logger.addHandler(handler)
logger.info("test1")
output = stream.getvalue()
assert re.search(r"\[InvokeAI\]::INFO --> test1$", output)
handler.setFormatter(LOG_FORMATTERS["legacy"]())
logger.info("test2")
output = stream.getvalue()
assert re.search(r">> test2$", output)
# test independence of two loggers with different names
def test_independence():
logger1 = InvokeAILogger.get_logger()
logger2 = InvokeAILogger.get_logger("Test")
assert logger1.name == "InvokeAI"
assert logger2.name == "Test"
assert logger1.level == logging.INFO
assert logger2.level == logging.INFO
logger2.setLevel(logging.DEBUG)
assert logger1.level == logging.INFO
assert logger2.level == logging.DEBUG
# test that the logger is returned from two similar get_logger() calls
def test_retrieval():
logger1 = InvokeAILogger.get_logger()
logger2 = InvokeAILogger.get_logger()
logger3 = InvokeAILogger.get_logger("Test")
assert logger1 == logger2
assert logger1 != logger3
# test that the configuration is used to set the initial logging level
def test_config():
config = InvokeAIAppConfig(log_level="debug")
logger1 = InvokeAILogger.get_logger("DebugTest", config=config)
assert logger1.level == logging.DEBUG