fix logger behavior so that it is initialized after command line parsed (#3509)

In some cases the command-line was getting parsed before the logger was
initialized, causing the logger not to pick up custom logging
instructions from `--log_handlers`. This PR fixes the issue.

invokeai/app/api_app.py

@@ -4,7 +4,6 @@ from inspect import signature
 
 import uvicorn
 
-from invokeai.backend.util.logging import InvokeAILogger
 from fastapi import FastAPI
 from fastapi.middleware.cors import CORSMiddleware
 from fastapi.openapi.docs import get_redoc_html, get_swagger_ui_html
@@ -15,15 +14,19 @@ from fastapi_events.middleware import EventHandlerASGIMiddleware
 from pathlib import Path
 from pydantic.schema import schema
 
+#This should come early so that modules can log their initialization properly
+from .services.config import InvokeAIAppConfig
+from ..backend.util.logging import InvokeAILogger
+app_config = InvokeAIAppConfig.get_config()
+app_config.parse_args()
+logger = InvokeAILogger.getLogger(config=app_config)
+
 import invokeai.frontend.web as web_dir
 
 from .api.dependencies import ApiDependencies
 from .api.routers import sessions, models, images
 from .api.sockets import SocketIO
 from .invocations.baseinvocation import BaseInvocation
-from .services.config import InvokeAIAppConfig
-
-logger = InvokeAILogger.getLogger()
 
 # Create the app
 # TODO: create this all in a method so configuration/etc. can be passed in?
@@ -41,11 +44,6 @@ app.add_middleware(
 
 socket_io = SocketIO(app)
 
-# initialize config
-# this is a module global
-app_config = InvokeAIAppConfig.get_config()
-app_config.parse_args()
-
 # Add startup event to load dependencies
 @app.on_event("startup")
 async def startup_event():

invokeai/app/cli_app.py

@@ -13,14 +13,20 @@ from typing import (
 
 from pydantic import BaseModel, ValidationError
 from pydantic.fields import Field
+
+# This should come early so that the logger can pick up its configuration options
+from .services.config import InvokeAIAppConfig
+from invokeai.backend.util.logging import InvokeAILogger
+config = InvokeAIAppConfig.get_config()
+config.parse_args()
+logger = InvokeAILogger().getLogger(config=config)
+
 from invokeai.app.services.image_record_storage import SqliteImageRecordStorage
 from invokeai.app.services.images import ImageService
 from invokeai.app.services.metadata import CoreMetadataService
 from invokeai.app.services.resource_name import SimpleNameService
 from invokeai.app.services.urls import LocalUrlService
 
-
-import invokeai.backend.util.logging as logger
 from .services.default_graphs import create_system_graphs
 from .services.latent_storage import DiskLatentsStorage, ForwardCacheLatentsStorage
 
@@ -38,7 +44,7 @@ from .services.invocation_services import InvocationServices
 from .services.invoker import Invoker
 from .services.processor import DefaultInvocationProcessor
 from .services.sqlite import SqliteItemStorage
-from .services.config import InvokeAIAppConfig
+
 
 class CliCommand(BaseModel):
     command: Union[BaseCommand.get_commands() + BaseInvocation.get_invocations()] = Field(discriminator="type")  # type: ignore
@@ -47,7 +53,6 @@ class CliCommand(BaseModel):
 class InvalidArgs(Exception):
     pass
 
-
 def add_invocation_args(command_parser):
     # Add linking capability
     command_parser.add_argument(
@@ -191,14 +196,7 @@ def invoke_all(context: CliContext):
         
         raise SessionError()
 
-
-logger = logger.InvokeAILogger.getLogger()
-
-
 def invoke_cli():
-    # this gets the basic configuration
-    config = InvokeAIAppConfig.get_config()
-    config.parse_args()
     
     # get the optional list of invocations to execute on the command line
     parser = config.get_parser()

invokeai/backend/install/invokeai_configure.py

@@ -40,6 +40,7 @@ import invokeai.configs as configs
 from invokeai.app.services.config import (
     InvokeAIAppConfig,
 )
+from invokeai.backend.util.logging import InvokeAILogger
 from invokeai.frontend.install.model_install import addModelsForm, process_and_execute
 from invokeai.frontend.install.widgets import (
     CenteredButtonPress,
@@ -80,6 +81,7 @@ INIT_FILE_PREAMBLE = """# InvokeAI initialization file
 # or renaming it and then running invokeai-configure again.
 """
 
+logger=None
 
 # --------------------------------------------
 def postscript(errors: None):
@@ -824,6 +826,7 @@ def main():
     if opt.full_precision:
         invoke_args.extend(['--precision','float32'])
     config.parse_args(invoke_args)
+    logger = InvokeAILogger().getLogger(config=config)
 
     errors = set()
 

invokeai/backend/model_management/model_manager.py

@@ -784,7 +784,7 @@ class ModelManager(object):
 
         self.logger.info(f"Probing {thing} for import")
 
-        if thing.startswith(("http:", "https:", "ftp:")):
+        if str(thing).startswith(("http:", "https:", "ftp:")):
             self.logger.info(f"{thing} appears to be a URL")
             model_path = self._resolve_path(
                 thing, "models/ldm/stable-diffusion-v1"

invokeai/backend/util/logging.py

@@ -1,6 +1,7 @@
 # Copyright (c) 2023 Lincoln D. Stein and The InvokeAI Development Team
 
-"""invokeai.util.logging
+"""
+invokeai.util.logging
 
 Logging class for InvokeAI that produces console messages
 
@@ -11,6 +12,7 @@ from invokeai.backend.util.logging import InvokeAILogger
 logger = InvokeAILogger.getLogger(name='InvokeAI') // Initialization
 (or)
 logger = InvokeAILogger.getLogger(__name__) // To use the filename
+logger.configure()
 
 logger.critical('this is critical') // Critical Message
 logger.error('this is an error') // Error Message
@@ -28,6 +30,149 @@ Console messages:
 Alternate Method (in this case the logger name will be set to InvokeAI):
 import invokeai.backend.util.logging as IAILogger
 IAILogger.debug('this is a debugging message')
+
+## Configuration
+
+The default configuration will print to stderr on the console. To add
+additional logging handlers, call getLogger with an initialized InvokeAIAppConfig
+object:
+
+
+ config = InvokeAIAppConfig.get_config()
+ config.parse_args()
+ logger = InvokeAILogger.getLogger(config=config)
+
+### Three command-line options control logging:
+
+`--log_handlers <handler1> <handler2> ...`
+
+This option activates one or more log handlers. Options are "console", "file", "syslog" and "http". To specify more than one, separate them by spaces:
+
+```
+invokeai-web --log_handlers console syslog=/dev/log file=C:\\Users\\fred\\invokeai.log
+```
+
+The format of these options is described below.
+
+### `--log_format {plain|color|legacy|syslog}`
+
+This controls the format of log messages written to the console. Only the "console" log handler is currently affected by this setting.
+
+* "plain" provides formatted messages like this:
+
+```bash
+
+[2023-05-24 23:18:2[2023-05-24 23:18:50,352]::[InvokeAI]::DEBUG --> this is a debug message
+[2023-05-24 23:18:50,352]::[InvokeAI]::INFO --> this is an informational messages
+[2023-05-24 23:18:50,352]::[InvokeAI]::WARNING --> this is a warning
+[2023-05-24 23:18:50,352]::[InvokeAI]::ERROR --> this is an error
+[2023-05-24 23:18:50,352]::[InvokeAI]::CRITICAL --> this is a critical error
+```
+
+* "color" produces similar output, but the text will be color coded to indicate the severity of the message.
+
+* "legacy" produces output similar to InvokeAI versions 2.3 and earlier:
+
+```
+### this is a critical error
+*** this is an error
+** this is a warning
+>> this is an informational messages
+   | this is a debug message
+```
+
+* "syslog" produces messages suitable for syslog entries:
+
+```bash
+InvokeAI [2691178] <CRITICAL> this is a critical error
+InvokeAI [2691178] <ERROR> this is an error
+InvokeAI [2691178] <WARNING> this is a warning
+InvokeAI [2691178] <INFO> this is an informational messages
+InvokeAI [2691178] <DEBUG> this is a debug message
+```
+
+(note that the date, time and hostname will be added by the syslog system)
+
+### `--log_level {debug|info|warning|error|critical}`
+
+Providing this command-line option will cause only messages at the specified level or above to be emitted.
+
+## Console logging
+
+When "console" is provided to `--log_handlers`, messages will be written to the command line window in which InvokeAI was launched. By default, the color formatter will be used unless overridden by `--log_format`.
+
+## File logging
+
+When "file" is provided to `--log_handlers`, entries will be written to the file indicated in the path argument. By default, the "plain" format will be used:
+
+```bash
+invokeai-web --log_handlers file=/var/log/invokeai.log
+```
+
+## Syslog logging
+
+When "syslog" is requested, entries will be sent to the syslog system. There are a variety of ways to control where the log message is sent:
+
+* Send to the local machine using the `/dev/log` socket:
+
+```
+invokeai-web --log_handlers syslog=/dev/log
+```
+
+* Send to the local machine using a UDP message:
+
+```
+invokeai-web --log_handlers syslog=localhost
+```
+
+* Send to the local machine using a UDP message on a nonstandard port:
+
+```
+invokeai-web --log_handlers syslog=localhost:512
+```
+
+* Send to a remote machine named "loghost" on the local LAN using  facility LOG_USER and UDP packets:
+
+```
+invokeai-web --log_handlers syslog=loghost,facility=LOG_USER,socktype=SOCK_DGRAM
+```
+
+This can be abbreviated `syslog=loghost`, as LOG_USER and SOCK_DGRAM are defaults.
+
+* Send to a remote machine named "loghost" using the facility LOCAL0  and using a TCP socket:
+
+```
+invokeai-web --log_handlers syslog=loghost,facility=LOG_LOCAL0,socktype=SOCK_STREAM
+```
+
+If no arguments are specified (just a bare "syslog"), then the logging system will look for a UNIX socket named `/dev/log`, and if not found try to send a UDP message to `localhost`. The Macintosh OS used to support logging to a socket named `/var/run/syslog`, but this feature has since been disabled.
+
+## Web logging
+
+If you have access to a web server that is configured to log messages when a particular URL is requested, you can log using the "http" method:
+
+```
+invokeai-web --log_handlers http=http://my.server/path/to/logger,method=POST
+```
+
+The optional [,method=] part can be used to specify whether the URL accepts GET (default) or POST messages.
+
+Currently password authentication and SSL are not supported.
+
+## Using the configuration file
+
+You can set and forget logging options by adding a "Logging" section to `invokeai.yaml`:
+
+```
+InvokeAI:
+  [... other settings...]
+  Logging:
+    log_handlers:
+       - console
+       - syslog=/dev/log
+    log_level: info
+    log_format: color
+```
 """
 
 import logging.handlers
@@ -180,10 +325,13 @@ class InvokeAILogger(object):
     loggers = dict()
 
     @classmethod
-    def getLogger(cls, name: str = 'InvokeAI') -> logging.Logger:
+    def getLogger(cls,
-        config = get_invokeai_config()
+                  name: str = 'InvokeAI',
-        
+                  config: InvokeAIAppConfig=InvokeAIAppConfig.get_config())->logging.Logger:
-        if name not in cls.loggers:
+        if name in cls.loggers:
+            logger = cls.loggers[name]
+            logger.handlers.clear()
+        else:
             logger = logging.getLogger(name)
         logger.setLevel(config.log_level.upper()) # yes, strings work here
         for ch in cls.getLoggers(config):
@@ -199,9 +347,11 @@ class InvokeAILogger(object):
             handler_name,*args = handler.split('=',2)
             args = args[0] if len(args) > 0 else None
 
-            # console is the only handler that gets a custom formatter
+            # console and file get the fancy formatter.
-            if handler_name=='console':
+            # syslog gets a simple one
+            # http gets no custom formatter
             formatter = LOG_FORMATTERS[config.log_format]
+            if handler_name=='console':
                 ch = logging.StreamHandler()
                 ch.setFormatter(formatter())
                 handlers.append(ch)
@@ -212,7 +362,9 @@ class InvokeAILogger(object):
                 handlers.append(ch)
                 
             elif handler_name=='file':
-                handlers.append(cls._parse_file_args(args))
+                ch = cls._parse_file_args(args)
+                ch.setFormatter(formatter())
+                handlers.append(ch)
                 
             elif handler_name=='http':
                 handlers.append(cls._parse_http_args(args))

invokeai/frontend/install/model_install.py

@@ -28,7 +28,7 @@ import torch
 from npyscreen import widget
 from omegaconf import OmegaConf
 
-import invokeai.backend.util.logging as logger
+from invokeai.backend.util.logging import InvokeAILogger
 
 from invokeai.backend.install.model_install_backend import (
     Dataset_path,
@@ -939,6 +939,7 @@ def main():
     if opt.full_precision:
         invoke_args.extend(['--precision','float32'])
     config.parse_args(invoke_args)
+    logger = InvokeAILogger().getLogger(config=config)
 
     if not (config.root_dir / config.conf_path.parent).exists():
         logger.info(