Add startup timing diagnostics for issue 273

- Log backend route timings for startup-related API calls
- Log frontend extension setup and node creation timings
- Create a focused debug branch for reporter-side diagnosis

__init__.py

@@ -12,9 +12,10 @@ Unified architecture supporting ChatterBox, F5-TTS, and future engines like RVC:
 # Setting it here causes "allocator mismatch" errors because ComfyUI already imported torch
 
 # Import from the main nodes.py file which handles the new unified architecture
-import importlib.util
-import os
-import sys
+import importlib.util
+import os
+import sys
+import time
 
 # Note: PyTorch inductor patches removed - not needed for PyTorch 2.10+ with triton-windows 3.6+
 # Qwen3-TTS torch.compile optimizations require:
@@ -309,57 +310,71 @@ __description__ = "Universal multi-engine TTS extension for ComfyUI with unified
 __all__ = ["NODE_CLASS_MAPPINGS", "NODE_DISPLAY_NAME_MAPPINGS"]
 
 # Define web directory for JavaScript files (settings UI)
-WEB_DIRECTORY = "./web"
-
-# Register API endpoint for widget data
-def setup_api_routes():
+WEB_DIRECTORY = "./web"
+
+
+def _debug_timing_log(label: str, start_time: float, extra: str = ""):
+    """Print consistent startup timing diagnostics for debug branches."""
+    elapsed = time.perf_counter() - start_time
+    suffix = f" | {extra}" if extra else ""
+    print(f"⏱️ [startup-debug] {label}: {elapsed:.3f}s{suffix}")
+
+# Register API endpoint for widget data
+def setup_api_routes():
     """Setup API routes for widget communication"""
     try:
         import json
         from server import PromptServer
         from aiohttp import web
 
-        @PromptServer.instance.routes.get("/api/tts-audio-suite/available-characters")
-        async def get_available_characters_endpoint(request):
-            """API endpoint to get available TTS character voices including aliases"""
-            try:
-                # Load voice discovery directly by file path to avoid package import issues
-                voice_discovery_path = os.path.join(os.path.dirname(__file__), "utils", "voice", "discovery.py")
+        @PromptServer.instance.routes.get("/api/tts-audio-suite/available-characters")
+        async def get_available_characters_endpoint(request):
+            """API endpoint to get available TTS character voices including aliases"""
+            start_time = time.perf_counter()
+            try:
+                # Load voice discovery directly by file path to avoid package import issues
+                voice_discovery_path = os.path.join(os.path.dirname(__file__), "utils", "voice", "discovery.py")
                 spec = importlib.util.spec_from_file_location("voice_discovery_module", voice_discovery_path)
                 voice_discovery_module = importlib.util.module_from_spec(spec)
                 spec.loader.exec_module(voice_discovery_module)
 
                 characters = list(voice_discovery_module.get_available_characters())
                 # Also get character aliases
-                aliases = list(voice_discovery_module.voice_discovery._character_aliases.keys()) if hasattr(voice_discovery_module.voice_discovery, '_character_aliases') else []
-                # Combine and deduplicate
-                all_chars = sorted(set(characters + aliases))
-                return web.json_response({"characters": all_chars})
-            except Exception as e:
-                print(f"⚠️ Error retrieving available characters: {e}")
-                return web.json_response({"characters": [], "error": str(e)})
-
+                aliases = list(voice_discovery_module.voice_discovery._character_aliases.keys()) if hasattr(voice_discovery_module.voice_discovery, '_character_aliases') else []
+                # Combine and deduplicate
+                all_chars = sorted(set(characters + aliases))
+                _debug_timing_log("/available-characters", start_time, f"count={len(all_chars)}")
+                return web.json_response({"characters": all_chars})
+            except Exception as e:
+                print(f"⚠️ Error retrieving available characters: {e}")
+                _debug_timing_log("/available-characters", start_time, f"error={type(e).__name__}")
+                return web.json_response({"characters": [], "error": str(e)})
+
         @PromptServer.instance.routes.get("/api/tts-audio-suite/available-languages")
         async def get_available_languages_endpoint(request):
             """API endpoint to get available language codes from the canonical language mapper"""
+            start_time = time.perf_counter()
             try:
-                # Load language_mapper directly by file path to avoid package import issues
-                language_mapper_path = os.path.join(os.path.dirname(__file__), "utils", "models", "language_mapper.py")
+                # Load language_mapper directly by file path to avoid package import issues
+                language_mapper_path = os.path.join(os.path.dirname(__file__), "utils", "models", "language_mapper.py")
                 spec = importlib.util.spec_from_file_location("language_mapper_module", language_mapper_path)
                 language_mapper_module = importlib.util.module_from_spec(spec)
                 spec.loader.exec_module(language_mapper_module)
-
-                # Get all unique canonical language codes (the values in LANGUAGE_ALIASES)
-                languages = sorted(set(language_mapper_module.LANGUAGE_ALIASES.values()))
-                return web.json_response({"languages": languages})
-            except Exception as e:
+
+                # Get all unique canonical language codes (the values in LANGUAGE_ALIASES)
+                languages = sorted(set(language_mapper_module.LANGUAGE_ALIASES.values()))
+                _debug_timing_log("/available-languages", start_time, f"count={len(languages)}")
+                return web.json_response({"languages": languages})
+            except Exception as e:
                 print(f"⚠️ Error retrieving available languages: {e}")
+                _debug_timing_log("/available-languages", start_time, f"error={type(e).__name__}")
                 # Fallback list
                 return web.json_response({"languages": ["en", "de", "fr", "ja", "es", "it", "pt", "th", "no"], "error": str(e)})
 
         @PromptServer.instance.routes.get("/api/tts-audio-suite/voice-input-devices")
         async def get_voice_input_devices_endpoint(request):
             """Return input devices without risking a main-process PortAudio hang."""
+            start_time = time.perf_counter()
             try:
                 import json
                 import subprocess
@@ -407,22 +422,26 @@ print(json.dumps({"devices": devices}))
                 if not isinstance(devices, list):
                     devices = []
 
+                _debug_timing_log("/voice-input-devices", start_time, f"count={len(devices)}")
                 return web.json_response({"devices": devices})
             except subprocess.TimeoutExpired:
+                _debug_timing_log("/voice-input-devices", start_time, "timeout")
                 return web.json_response(
                     {"devices": [], "error": "Timed out while probing audio input devices. Leaving the dropdown on system default avoids startup hangs."},
                     status=504,
                 )
             except Exception as e:
                 print(f"⚠️ Error retrieving voice input devices: {e}")
+                _debug_timing_log("/voice-input-devices", start_time, f"error={type(e).__name__}")
                 return web.json_response({"devices": [], "error": str(e)}, status=500)
 
         @PromptServer.instance.routes.post("/api/tts-audio-suite/settings")
         async def set_inline_tag_settings_endpoint(request):
             """API endpoint to receive settings from frontend for inline edit tags and restore VC"""
-            print("🔧 Settings endpoint called")  # Immediate print to verify endpoint is reached
-            try:
-                data = await request.json()
+            start_time = time.perf_counter()
+            print("🔧 Settings endpoint called")  # Immediate print to verify endpoint is reached
+            try:
+                data = await request.json()
                 precision = data.get("precision", "auto")
                 device = data.get("device", "auto")
                 vc_engine = data.get("vc_engine", "chatterbox_23lang")
@@ -433,23 +452,29 @@ print(json.dumps({"devices": devices}))
                 # Import edit_post_processor using normal import to ensure we get the same module instance
                 # that will be used during workflow execution
                 # CRITICAL: Must use the same module instance, not create a new one via importlib!
-                try:
-                    from utils.audio import edit_post_processor as edit_post_processor_module
-                except ImportError:
-                    # Fallback: Load directly by file path if normal import fails
-                    edit_post_processor_path = os.path.join(os.path.dirname(__file__), "utils", "audio", "edit_post_processor.py")
-                    spec = importlib.util.spec_from_file_location("utils.audio.edit_post_processor", edit_post_processor_path)
-                    edit_post_processor_module = importlib.util.module_from_spec(spec)
-                    sys.modules["utils.audio.edit_post_processor"] = edit_post_processor_module  # Register in sys.modules!
-                    spec.loader.exec_module(edit_post_processor_module)
-
-                # Store in global settings that edit_post_processor can access
-                edit_post_processor_module.set_inline_tag_settings(precision=precision, device=device, vc_engine=vc_engine, cosyvoice_variant=cosyvoice_variant)
-
-                return web.json_response({"status": "success", "precision": precision, "device": device, "vc_engine": vc_engine, "cosyvoice_variant": cosyvoice_variant})
-            except Exception as e:
-                print(f"⚠️ Error setting inline tag settings: {e}")
-                return web.json_response({"status": "error", "error": str(e)})
+                try:
+                    import_start = time.perf_counter()
+                    from utils.audio import edit_post_processor as edit_post_processor_module
+                    _debug_timing_log("/settings import edit_post_processor", import_start, "import_mode=normal")
+                except ImportError:
+                    # Fallback: Load directly by file path if normal import fails
+                    edit_post_processor_path = os.path.join(os.path.dirname(__file__), "utils", "audio", "edit_post_processor.py")
+                    spec = importlib.util.spec_from_file_location("utils.audio.edit_post_processor", edit_post_processor_path)
+                    edit_post_processor_module = importlib.util.module_from_spec(spec)
+                    sys.modules["utils.audio.edit_post_processor"] = edit_post_processor_module  # Register in sys.modules!
+                    import_start = time.perf_counter()
+                    spec.loader.exec_module(edit_post_processor_module)
+                    _debug_timing_log("/settings import edit_post_processor", import_start, "import_mode=fallback")
+
+                # Store in global settings that edit_post_processor can access
+                edit_post_processor_module.set_inline_tag_settings(precision=precision, device=device, vc_engine=vc_engine, cosyvoice_variant=cosyvoice_variant)
+
+                _debug_timing_log("/settings", start_time, "status=success")
+                return web.json_response({"status": "success", "precision": precision, "device": device, "vc_engine": vc_engine, "cosyvoice_variant": cosyvoice_variant})
+            except Exception as e:
+                print(f"⚠️ Error setting inline tag settings: {e}")
+                _debug_timing_log("/settings", start_time, f"error={type(e).__name__}")
+                return web.json_response({"status": "error", "error": str(e)})
 
         @PromptServer.instance.routes.get("/api/tts-audio-suite/voice-preview")
         async def get_voice_preview_endpoint(request):

web/audio_analyzer_interface.js

@@ -1,8 +1,14 @@
-import { app } from "../../scripts/app.js";
-import { AudioAnalyzerInterface } from "./audio_analyzer_core.js";
-
-// Simple execution tracking
-let audioAnalyzerNodes = new Map();
+import { app } from "../../scripts/app.js";
+import { AudioAnalyzerInterface } from "./audio_analyzer_core.js";
+
+// Simple execution tracking
+let audioAnalyzerNodes = new Map();
+
+function logTiming(label, start, extra = "") {
+    const elapsed = (performance.now() - start).toFixed(1);
+    const suffix = extra ? ` | ${extra}` : "";
+    console.log(`⏱️ [startup-debug] ${label}: ${elapsed}ms${suffix}`);
+}
 
 // Hook into ComfyUI's global execution completion
 if (window.app && window.app.ui && window.app.ui.queue) {
@@ -69,10 +75,11 @@ function handleNodeExecution(message) {
 app.registerExtension({
     name: "chatterbox.audio_analyzer",
 
-    async setup() {
-        // Patch graphToPrompt to inject node ID right before prompt is sent to backend
-        const onGraphToPrompt = app.graphToPrompt;
-        app.graphToPrompt = async function() {
+    async setup() {
+        const start = performance.now();
+        // Patch graphToPrompt to inject node ID right before prompt is sent to backend
+        const onGraphToPrompt = app.graphToPrompt;
+        app.graphToPrompt = async function() {
             // Get the original prompt
             const prompt = await onGraphToPrompt.apply(this, arguments);
 
@@ -87,15 +94,16 @@ app.registerExtension({
                 }
             }
             return prompt;
-        };
-        // console.log("🌊 Audio Wave Analyzer: Patched graphToPrompt to inject node IDs.");  // Debug: patch confirmation
-    },
+        };
+        logTiming("web/audio-analyzer setup", start);
+    },
     
     async beforeRegisterNodeDef(nodeType, nodeData) {
-        if (nodeData.name === "ChatterBoxAudioAnalyzer") {
-            const onNodeCreated = nodeType.prototype.onNodeCreated;
-            nodeType.prototype.onNodeCreated = function() {
-                const result = onNodeCreated ? onNodeCreated.apply(this, arguments) : undefined;
+        if (nodeData.name === "ChatterBoxAudioAnalyzer") {
+            const onNodeCreated = nodeType.prototype.onNodeCreated;
+            nodeType.prototype.onNodeCreated = function() {
+                const start = performance.now();
+                const result = onNodeCreated ? onNodeCreated.apply(this, arguments) : undefined;
                 
                 this.setSize([800, 600]);
                 
@@ -106,12 +114,14 @@ app.registerExtension({
                     
                     // No need for hidden widget - node_id is now injected via graphToPrompt patch
                     
-                } catch (error) {
-                    console.error('❌ Audio Wave Analyzer: Failed to create interface:', error);
-                }
-                
-                return result;
-            };
+                } catch (error) {
+                    console.error('❌ Audio Wave Analyzer: Failed to create interface:', error);
+                }
+
+                logTiming("web/audio-analyzer onNodeCreated", start, `node=${this.id}`);
+                
+                return result;
+            };
 
             // Add widget value persistence fix for ComfyUI reloads
             const onConfigure = nodeType.prototype.onConfigure;
@@ -561,4 +571,4 @@ app.registerExtension({
             };
         }
     }
-});
+});

web/chatterbox_voice_capture.js

@@ -6,6 +6,12 @@ const VOICE_CAPTURE_CLASSES = new Set(["ChatterBoxVoiceCaptureDiogod", "ChatterB
 const DEFAULT_DEVICE_LABEL = "System Default Input Device";
 const LOADING_DEVICE_LABEL = "Loading input devices...";
 
+function logTiming(label, start, extra = "") {
+    const elapsed = (performance.now() - start).toFixed(1);
+    const suffix = extra ? ` | ${extra}` : "";
+    console.log(`⏱️ [startup-debug] ${label}: ${elapsed}ms${suffix}`);
+}
+
 function isVoiceCaptureNode(nodeOrData) {
     const comfyClass = nodeOrData?.comfyClass || nodeOrData?.name;
     return VOICE_CAPTURE_CLASSES.has(comfyClass);
@@ -111,6 +117,7 @@ function applyDeviceList(node, devices, errorMessage = "") {
 }
 
 async function refreshInputDevices(node, { auto = false } = {}) {
+    const start = performance.now();
     const comboWidget = node.__ttsVoiceDeviceComboWidget;
     const refreshWidget = node.__ttsVoiceDeviceRefreshWidget;
     if (!comboWidget || !refreshWidget) {
@@ -136,11 +143,13 @@ async function refreshInputDevices(node, { auto = false } = {}) {
             throw new Error(result.error || `HTTP ${response.status}`);
         }
         applyDeviceList(node, devices);
+        logTiming("web/voice-capture refreshInputDevices", start, `status=${response.status} count=${devices.length}`);
     } catch (error) {
         comboWidget.options.values = [previousLabel || DEFAULT_DEVICE_LABEL];
         comboWidget.value = previousLabel || DEFAULT_DEVICE_LABEL;
         refreshWidget.name = "Refresh Input Devices (retry)";
         console.warn("ChatterBox Voice Capture: unable to load input devices.", error);
+        logTiming("web/voice-capture refreshInputDevices", start, `error=${error?.name || "unknown"}`);
         app.graph.setDirtyCanvas(true);
     } finally {
         node.__ttsVoiceDeviceRefreshInFlight = false;
@@ -156,6 +165,7 @@ app.registerExtension({
 
         const onNodeCreated = nodeType.prototype.onNodeCreated;
         nodeType.prototype.onNodeCreated = function() {
+            const start = performance.now();
             const result = onNodeCreated ? onNodeCreated.apply(this, arguments) : undefined;
 
             this.setSize([420, 340]);
@@ -168,6 +178,8 @@ app.registerExtension({
                 app.graph.setDirtyCanvas(true);
             }, 100);
 
+            logTiming("web/voice-capture onNodeCreated", start, `node=${this.id}`);
+
             return result;
         };
 

web/string_multiline_tag_editor.js

@@ -22,6 +22,12 @@ let widgetCounter = 0;
 
 const CHANGE_TRACKER_PATCH_FLAG = "__ttsTagEditorUndoRedoPatched";
 
+function logTiming(label, start, extra = "") {
+    const elapsed = (performance.now() - start).toFixed(1);
+    const suffix = extra ? ` | ${extra}` : "";
+    console.log(`⏱️ [startup-debug] ${label}: ${elapsed}ms${suffix}`);
+}
+
 const isTagEditorFocused = () => {
     const activeElement = document.activeElement;
     return activeElement instanceof HTMLElement &&
@@ -56,6 +62,7 @@ patchChangeTrackerUndoRedo();
 
 // Create the widget
 function addStringMultilineTagEditorWidget(node) {
+    const start = performance.now();
     // Use widget counter as fallback when node.id is -1 (not yet assigned)
     const uniqueId = node.id !== -1 ? node.id : `widget_${widgetCounter++}`;
     const storageKey = `string_multiline_tag_editor_${uniqueId}`;
@@ -724,6 +731,8 @@ function addStringMultilineTagEditorWidget(node) {
     // Initialize history display
     historyStatus.textContent = state.getHistoryStatus();
 
+    logTiming("web/tag-editor addWidget", start, `node=${node.id}`);
+
     return widget;
 }
 
@@ -735,6 +744,7 @@ app.registerExtension({
             // Override onNodeCreated to create our custom widget
             const originalOnNodeCreated = nodeType.prototype.onNodeCreated;
             nodeType.prototype.onNodeCreated = function () {
+                const start = performance.now();
                 // Call original to set up the node
                 if (originalOnNodeCreated) {
                     originalOnNodeCreated.call(this);
@@ -745,6 +755,7 @@ app.registerExtension({
 
                 // Create our custom widget (becomes the FIRST widget now)
                 addStringMultilineTagEditorWidget(this);
+                logTiming("web/tag-editor onNodeCreated", start, `node=${this.id}`);
             };
         }
     }

web/tts_audio_suite_settings.js

@@ -1,14 +1,21 @@
-import { app } from '../../scripts/app.js'
-
-const SETTING_CATEGORY = "TTS Audio Suite";
-const SETTING_SECTION_STEP_EDITX = "Step Audio EditX (Inline Tags)";
-const SETTING_SECTION_RESTORE_VC = "Voice Restoration (<restore> Tags)";
-
-// Shared function to send settings to backend
-async function sendSettingsToBackend() {
-    try {
-        const precision = app.ui.settings.getSettingValue("TTSAudioSuite.InlineEditTags.Precision", "auto");
-        const device = app.ui.settings.getSettingValue("TTSAudioSuite.InlineEditTags.Device", "auto");
+import { app } from '../../scripts/app.js'
+
+const SETTING_CATEGORY = "TTS Audio Suite";
+const SETTING_SECTION_STEP_EDITX = "Step Audio EditX (Inline Tags)";
+const SETTING_SECTION_RESTORE_VC = "Voice Restoration (<restore> Tags)";
+
+function logTiming(label, start, extra = "") {
+    const elapsed = (performance.now() - start).toFixed(1);
+    const suffix = extra ? ` | ${extra}` : "";
+    console.log(`⏱️ [startup-debug] ${label}: ${elapsed}ms${suffix}`);
+}
+
+// Shared function to send settings to backend
+async function sendSettingsToBackend() {
+    const start = performance.now();
+    try {
+        const precision = app.ui.settings.getSettingValue("TTSAudioSuite.InlineEditTags.Precision", "auto");
+        const device = app.ui.settings.getSettingValue("TTSAudioSuite.InlineEditTags.Device", "auto");
         const vcEngine = app.ui.settings.getSettingValue("TTSAudioSuite.RestoreTags.VCEngine", "chatterbox_23lang");
         const cosyvoiceVariant = app.ui.settings.getSettingValue("TTSAudioSuite.RestoreTags.CosyVoiceVariant", "RL");
 
@@ -27,16 +34,18 @@ async function sendSettingsToBackend() {
             })
         });
 
-        if (!response.ok) {
-            console.error(`TTS Audio Suite: Failed to send settings to backend (status ${response.status})`);
-        } else {
-            const result = await response.json();
-            console.log("TTS Audio Suite: Backend confirmed settings:", result);
-        }
-    } catch (error) {
-        console.error("TTS Audio Suite: Error sending settings to backend:", error);
-    }
-}
+        if (!response.ok) {
+            console.error(`TTS Audio Suite: Failed to send settings to backend (status ${response.status})`);
+        } else {
+            const result = await response.json();
+            console.log("TTS Audio Suite: Backend confirmed settings:", result);
+        }
+        logTiming("web/settings sendSettingsToBackend", start, `status=${response.status}`);
+    } catch (error) {
+        console.error("TTS Audio Suite: Error sending settings to backend:", error);
+        logTiming("web/settings sendSettingsToBackend", start, `error=${error?.name || "unknown"}`);
+    }
+}
 
 app.registerExtension({
     name: "TTS_Audio_Suite.Settings",
@@ -95,13 +104,14 @@ app.registerExtension({
                 "💡 Tip: Match this to the variant you use for TTS to avoid model unload/reload during restore.\n\n" +
                 "⚠️ IMPORTANT: Refresh browser (F5) after changing settings for them to take effect."
         }
-    ],
-    async setup() {
-        // Send settings on initial load (with delay to ensure settings are loaded)
-        setTimeout(() => {
-            sendSettingsToBackend();
-            console.log("TTS Audio Suite: Initial settings sent to backend");
-        }, 1000);
+    ],
+    async setup() {
+        const setupStart = performance.now();
+        // Send settings on initial load (with delay to ensure settings are loaded)
+        setTimeout(() => {
+            sendSettingsToBackend();
+            console.log("TTS Audio Suite: Initial settings sent to backend");
+        }, 1000);
 
         // Listen for setting changes and send to backend
         const originalChangeSettings = app.ui.settings.setSettingValue;
@@ -112,11 +122,12 @@ app.registerExtension({
             if (id.startsWith("TTSAudioSuite.InlineEditTags.") || id.startsWith("TTSAudioSuite.RestoreTags.")) {
                 sendSettingsToBackend();
             }
-        };
-
-        console.log("TTS Audio Suite: Settings registered and synced with backend");
-    }
-})
+        };
+
+        console.log("TTS Audio Suite: Settings registered and synced with backend");
+        logTiming("web/settings setup", setupStart);
+    }
+})
 
 // Register separate extension for beforeQueuing hook (must be at top level)
 app.registerExtension({