add --log-startup option to print detailed startup progress

modules/cmd_args.py

@@ -13,6 +13,7 @@ parser.add_argument("--reinstall-xformers", action='store_true', help="launch.py
 parser.add_argument("--reinstall-torch", action='store_true', help="launch.py argument: install the appropriate version of torch even if you have some version already installed")
 parser.add_argument("--update-check", action='store_true', help="launch.py argument: check for updates at startup")
 parser.add_argument("--test-server", action='store_true', help="launch.py argument: configure server for testing")
+parser.add_argument("--log-startup", action='store_true', help="launch.py argument: print a detailed log of what's happening at startup")
 parser.add_argument("--skip-prepare-environment", action='store_true', help="launch.py argument: skip all environment preparation")
 parser.add_argument("--skip-install", action='store_true', help="launch.py argument: skip installation of packages")
 parser.add_argument("--do-not-download-clip", action='store_true', help="do not download CLIP model even if it's not included in the checkpoint")

modules/launch_utils.py

@@ -226,8 +226,11 @@ def run_extensions_installers(settings_file):
 
     with startup_timer.subcategory("run extensions installers"):
         for dirname_extension in list_extensions(settings_file):
-            run_extension_installer(os.path.join(extensions_dir, dirname_extension))
+            path = os.path.join(extensions_dir, dirname_extension)
-            startup_timer.record(dirname_extension)
+
+            if os.path.isdir(path):
+                run_extension_installer(path)
+                startup_timer.record(dirname_extension)
 
 
 re_requirement = re.compile(r"\s*([-_a-zA-Z0-9]+)\s*(?:==\s*([-+_.a-zA-Z0-9]+))?\s*")

modules/timer.py

@@ -1,4 +1,5 @@
 import time
+import argparse
 
 
 class TimerSubcategory:
@@ -11,20 +12,27 @@ class TimerSubcategory:
     def __enter__(self):
         self.start = time.time()
         self.timer.base_category = self.original_base_category + self.category + "/"
+        self.timer.subcategory_level += 1
+
+        if self.timer.print_log:
+            print(f"{'  ' * self.timer.subcategory_level}{self.category}:")
 
     def __exit__(self, exc_type, exc_val, exc_tb):
         elapsed_for_subcategroy = time.time() - self.start
         self.timer.base_category = self.original_base_category
         self.timer.add_time_to_record(self.original_base_category + self.category, elapsed_for_subcategroy)
-        self.timer.record(self.category)
+        self.timer.subcategory_level -= 1
+        self.timer.record(self.category, disable_log=True)
 
 
 class Timer:
-    def __init__(self):
+    def __init__(self, print_log=False):
         self.start = time.time()
         self.records = {}
         self.total = 0
         self.base_category = ''
+        self.print_log = print_log
+        self.subcategory_level = 0
 
     def elapsed(self):
         end = time.time()
@@ -38,13 +46,16 @@ class Timer:
 
         self.records[category] += amount
 
-    def record(self, category, extra_time=0):
+    def record(self, category, extra_time=0, disable_log=False):
         e = self.elapsed()
 
         self.add_time_to_record(self.base_category + category, e + extra_time)
 
         self.total += e + extra_time
 
+        if self.print_log and not disable_log:
+            print(f"{'  ' * self.subcategory_level}{category}: done in {e + extra_time:.3f}s")
+
     def subcategory(self, name):
         self.elapsed()
 
@@ -71,6 +82,10 @@ class Timer:
         self.__init__()
 
 
-startup_timer = Timer()
+parser = argparse.ArgumentParser(add_help=False)
+parser.add_argument("--log-startup", action='store_true', help="print a detailed log of what's happening at startup")
+args = parser.parse_known_args()[0]
+
+startup_timer = Timer(print_log=args.log_startup)
 
 startup_record = None