log handlers: rotate and ring buffer

.gitignore

@@ -19,6 +19,7 @@ venv
 
 # all models and temp files
 *.log
+*.log.*
 *.bak
 *.ckpt
 *.safetensors

CHANGELOG.md

@@ -1,12 +1,22 @@
 # Change Log for SD.Next
 
+## Update for 06/17/2023
+
+- minor improvements to extra networks ui  
+- more hints/tooltips integrated into ui  
+- decidated api server  
+  - still in developent, but highly promising for high throughput server  
+- improve server logging with  
+  - log file rotation  
+  - ring buffer with api endpoint `/sdapi/v1/log`  
+
 ## Update for 06/14/2023
 
 Second stage of a jumbo merge from upstream plus few minor changes...
 
 - simplify token merging  
 - reorganize some settings  
-- all updates from upstream: A1111 v1.3.2 [df004be] (latest release)  
+- all updates from upstream: **A1111** v1.3.2 [df004be] *(latest release)*  
   pretty much nothing major that i haven't released in previous versions, but its still a long list of tiny changes  
   - skipped/did-not-port:  
     add separate hires prompt: unnecessarily complicated and spread over large number of commits due to many regressions  

cli/sdapi.py

@@ -167,6 +167,13 @@ def progresssync():
     return res
 
 
+def get_log():
+    res = getsync('/sdapi/v1/log')
+    for l in res:
+        log.debug(l)
+    return res
+
+
 def options():
     opts = getsync('/sdapi/v1/options')
     flags = getsync('/sdapi/v1/cmd-flags')
@@ -223,6 +230,8 @@ async def close():
         print(json.dumps(opt['options'], indent = 2))
         log.debug({ 'cmd-flags' })
         print(json.dumps(opt['flags'], indent = 2))
+    if 'log' in sys.argv:
+        get_log()
     if 'shutdown' in sys.argv:
         shutdown()
     asyncio.run(close(), debug=True)

cli/train.py

@@ -6,7 +6,6 @@
 import gc
 import sys
 import json
-import time
 import shutil
 import pathlib
 import asyncio
@@ -39,13 +38,7 @@
 
 # methods
 
-def setup_logging(clean=False):
-    try:
-        if clean and os.path.isfile(log_file):
-            os.remove(log_file)
-        time.sleep(0.1) # prevent race condition
-    except Exception:
-        pass
+def setup_logging():
     from rich.theme import Theme
     from rich.logging import RichHandler
     from rich.console import Console

installer.py

@@ -48,36 +48,63 @@ class Dot(dict): # dot notation access to dictionary attributes
 
 
 # setup console and file logging
-def setup_logging(clean=False):
-    try:
-        if clean and os.path.isfile(log_file):
-            os.remove(log_file)
-        time.sleep(0.1) # prevent race condition
-    except Exception:
-        pass
+def setup_logging():
+
+    class RingBuffer(logging.StreamHandler):
+        def __init__(self, capacity):
+            super().__init__()
+            self.capacity = capacity
+            self.buffer = []
+            self.formatter = logging.Formatter('{ "asctime":"%(asctime)s", "created":%(created)f, "facility":"%(name)s", "pid":%(process)d, "tid":%(thread)d, "level":"%(levelname)s", "module":"%(module)s", "func":"%(funcName)s", "msg":"%(message)s" }')
+
+        def emit(self, record):
+            msg = self.format(record)
+            self.buffer.append(json.loads(msg))
+            if len(self.buffer) > self.capacity:
+                self.buffer.pop(0)
+
+        def get(self):
+            return self.buffer
+
+    from logging.handlers import RotatingFileHandler
     from rich.theme import Theme
     from rich.logging import RichHandler
     from rich.console import Console
     from rich.pretty import install as pretty_install
     from rich.traceback import install as traceback_install
+
+    level = logging.DEBUG if args.debug else logging.INFO
+    log.setLevel(logging.DEBUG) # log to file is always at level debug for facility `sd`
     console = Console(log_time=True, log_time_format='%H:%M:%S-%f', theme=Theme({
         "traceback.border": "black",
         "traceback.border.syntax_error": "black",
         "inspect.value.border": "black",
     }))
-    level = logging.DEBUG if args.debug else logging.INFO
     try:
         logging.basicConfig(level=logging.ERROR, format='%(asctime)s | %(name)s | %(levelname)s | %(module)s | %(message)s', filename=log_file, filemode='a', encoding='utf-8', force=True)
     except Exception:
         logging.basicConfig(level=logging.ERROR, format='%(asctime)s | %(name)s | %(levelname)s | %(module)s | %(message)s') # to be able to report unsupported python version
-    log.setLevel(logging.DEBUG) # log to file is always at level debug for facility `sd`
     pretty_install(console=console)
     traceback_install(console=console, extra_lines=1, width=console.width, word_wrap=False, indent_guides=False, suppress=[])
-    rh = RichHandler(show_time=True, omit_repeated_times=False, show_level=True, show_path=False, markup=False, rich_tracebacks=True, log_time_format='%H:%M:%S-%f', level=level, console=console)
-    rh.set_name(level)
     while log.hasHandlers() and len(log.handlers) > 0:
         log.removeHandler(log.handlers[0])
+
+    # handlers
+    rh = RichHandler(show_time=True, omit_repeated_times=False, show_level=True, show_path=False, markup=False, rich_tracebacks=True, log_time_format='%H:%M:%S-%f', level=level, console=console)
+    rh.setLevel(level)
     log.addHandler(rh)
+
+    fh = RotatingFileHandler(log_file, maxBytes=10*1024*1024, backupCount=5, encoding='utf-8', delay=True) # 10MB default for log rotation
+    fh.formatter = logging.Formatter('%(asctime)s | %(name)s | %(levelname)s | %(module)s | %(message)s')
+    fh.setLevel(logging.DEBUG)
+    log.addHandler(fh)
+
+    rb = RingBuffer(100) # 100 entries default in log ring buffer
+    rb.setLevel(level)
+    log.addHandler(rb)
+    log.buffer = rb.buffer
+
+    # overrides
     logging.getLogger("urllib3").setLevel(logging.ERROR)
     logging.getLogger("httpx").setLevel(logging.ERROR)
     logging.getLogger("ControlNet").handlers = log.handlers

launch.py

@@ -151,7 +151,7 @@ def start_server(immediate=True, server=None):
     installer.ensure_base_requirements()
     init_modules() # setup argparser and default folders
     installer.args = args
-    installer.setup_logging(False)
+    installer.setup_logging()
     installer.log.info('Starting SD.Next')
     installer.read_options()
     installer.check_python()
@@ -186,7 +186,6 @@ def start_server(immediate=True, server=None):
     # installer.log.debug(f"Args: {vars(args)}")
     logging.disable(logging.NOTSET if args.debug else logging.DEBUG)
 
-
     instance = start_server(immediate=True, server=None)
     while True:
         try:

modules/api/api.py

@@ -142,6 +142,7 @@ def __init__(self, app: FastAPI, queue_lock: Lock):
         self.add_api_route("/sdapi/v1/reload-checkpoint", self.reloadapi, methods=["POST"])
         self.add_api_route("/sdapi/v1/scripts", self.get_scripts_list, methods=["GET"], response_model=models.ScriptsList)
         self.add_api_route("/sdapi/v1/script-info", self.get_script_info, methods=["GET"], response_model=List[models.ScriptInfo])
+        self.add_api_route("/sdapi/v1/log", self.get_log_buffer, methods=["GET"], response_model=List)
         self.default_script_arg_txt2img = []
         self.default_script_arg_img2img = []
 
@@ -156,6 +157,9 @@ def auth(self, credentials: HTTPBasicCredentials = Depends(HTTPBasic())):
                 return True
         raise HTTPException(status_code=401, detail="Unauthorized", headers={"WWW-Authenticate": "Basic"})
 
+    def get_log_buffer(self):
+        return shared.log.buffer
+
     def get_selectable_script(self, script_name, script_runner):
         if script_name is None or script_name == "":
             return None, None

modules/errors.py

@@ -23,7 +23,7 @@ def install(suppress=[]): # noqa: B006
     warnings.filterwarnings("ignore", category=UserWarning)
     pretty_install(console=console)
     traceback_install(console=console, extra_lines=1, width=console.width, word_wrap=False, indent_guides=False, suppress=suppress)
-    logging.basicConfig(level=logging.INFO, format='%(asctime)s | %(levelname)s | %(pathname)s | %(message)s')
+    logging.basicConfig(level=logging.ERROR, format='%(asctime)s | %(levelname)s | %(pathname)s | %(message)s')
     # for handler in logging.getLogger().handlers:
     #    handler.setLevel(logging.INFO)