Closed bug report

kicad_show_symbol is ~56s on every call: full cold start (relaunch + library scan) even when the Symbol Editor is already open on that symbol

Colby Knox · ·closed by John Lauer

kicad_show_symbol takes ~56s on EVERY call: full cold start (relaunch + library scan) even when the Symbol Editor is already open on that exact symbol

Live, Colby-ROG2, 2026-08-19 (kicad-bridge 0.9.181, KiCad 10.0, ab relay). kicad_show_symbol {symbolName:"IN-S42ATR", libraryName:"Adom"} succeeds but takes ~57-58s, and it costs the same every time because it is treated as a cold start on every call.

Measurements (two back-to-back calls)

  • Call 1: success:true, durationMs: 57107, output "Symbol 'IN-S42ATR' loaded (background win32 path): Adom:IN-S42ATR — Symbol Editor"
  • Call 2 (immediately after): success:true, durationMs: 58607, progress.measured: {phase:"kicad.show_symbol", seconds:56.14, startKind:"cold"}

Between the two calls, kicad_window_info shows the editor was ALREADY open on the target symbol, and there is exactly one (no leak):

editors: [{ hwnd: 1837708, title: "Adom:IN-S42ATR — Symbol Editor" }]
projectManager: { hwnd: 1114720, title: "KiCad 10.0" }

So on call 2 the Symbol Editor is already up and already displaying Adom:IN-S42ATR — the desired end state — yet the verb still runs the full ~56s startKind:"cold" flow instead of returning immediately.

What seems to be happening

The show path does not check for an already-open Symbol Editor (which kicad_window_info clearly sees) before doing its work. Every call re-runs the cold sequence: launch/raise KiCad, open the Symbol Editor, and win32-navigate to the symbol. The dominant cost is very likely KiCad itself rescanning ALL symbol libraries when the editor is opened/refreshed (KiCad does a full library index on Symbol Editor open, which is tens of seconds), compounded by the bridge paying it on every call rather than once.

For a wiki Quick Actions "Open in Symbol Editor" button this is a 57s spinner every click, even to re-show a symbol that is already on screen.

Asks

  1. Before the cold path, check kicad_window_info / the reverse bridge for an already-open Symbol Editor:

    • already open AND already showing the target library:symbol -> return fast (just foreground/report), no relaunch, no rescan.
    • open but on a different symbol -> navigate the existing editor (win32/plugin) instead of relaunching, so KiCad's library scan is not repeated.
    • reserve the ~56s cold flow for a genuine cold start (no KiCad running).
  2. Break the 56s into sub-phase timings in progress/output (launch vs library-scan vs navigate) so it is clear where it goes and whether KiCad's library index is the bottleneck. If it is, a warm-editor reuse fixes the common case entirely.

  3. Replace the fixed time.sleep() settle delays in the open/navigate flow with a poll-until-ready wait on the actual condition. open_symbol_editor.py sleeps a fixed 0.5s / 1.5s / 2.0s after launching KiCad and after each navigation step, plus a 10s cap waiting for the project manager. Fixed sleeps both over-wait in the common case and under-wait on a slow box; the sync equivalent of "await the condition" is a tight poll loop (WaitForInputIdle, or poll EnumWindows for the target window / poll the plugin's editor inventory until the frame is present) with a short interval and a timeout. That trims the settle overhead and is more robust than guessing a delay.

Note on the split: the fixed sleeps are only part of the budget (roughly 5-10s of the 56s). The bulk is almost certainly KiCad's own synchronous symbol-library index when the Symbol Editor opens, which the bridge cannot make async (it is KiCad's blocking work) - the only way to avoid it is not to reopen/rescan when an editor is already up (ask 1). So: warm-editor reuse removes the big cost, poll-until-ready removes the sleep overhead, and sub-phase timings confirm the split.

Symbol currently WORKS (unlike footprint, adom/kicad-bridge#34) - this is purely about the ~56s-per-call latency. Happy to re-run with any extra instrumentation against this machine.

8 Replies

John Lauer ·

Fixed in 0.9.185. Measured on a live box just now: 2.5s, down from your 56-58s.

kicad_show_symbol {symbolName:"IN-S42ATR", libraryName:"Adom"} -> success: true, reused: true, 2.5s "Symbol Editor is already showing Adom:IN-S42ATR - reused it (no relaunch, no library rescan)."

Your diagnosis was right on both counts: the show path never checked for an already-open editor, and the dominant cost is KiCad re-indexing every symbol library when the Symbol Editor opens - which the bridge was paying on every single call. Ask 1 is implemented: if an editor is already displaying the requested library:part, the verb returns it immediately instead of running the cold sequence. The same fast path is in kicad_show_footprint.

Not yet done, and I would rather say so than let you assume: your ask 2 (sub-phase timings splitting launch vs library-scan vs navigate inside the progress block) and ask 3 (replacing the fixed time.sleep settles with poll-until-ready). The measured-progress contract from #32 landed in 0.9.176-0.9.178 so the verb reports one phase end to end with real elapsed time and per-machine history, but it does not yet break that phase into sub-steps. Both are on my list; the reuse fast path was the one that removes the pain today.

Worth noting for the case that still hits the cold path: with the editor closed, the ~56s is largely KiCad's own library index, not bridge overhead. Sub-phase timings will make that visible rather than assumed, which is exactly why you asked for them.

Colby Knox ·

The 0.9.185 fast path is confirmed for the same-part re-show. The remaining gap is ask 1's SECOND sub-case ("open but on a different symbol -> navigate"), and on a live Quick Actions click it produces BOTH symptoms of this issue at once.

Repro (live, real user, KiCad already running): Symbol Editor already open on Adom:ADS1015IDGS. Click "Open in Symbol Editor" for a DIFFERENT part, 2N7000, same Adom library. Result:

  • ~53s again. The full cold sequence (relaunch / library rescan) runs even though KiCad and the Symbol Editor were already up, because the fast path only short-circuits when the editor is already showing the REQUESTED part. A different part still pays the whole ~53s.
  • The editor stays on ADS1015IDGS; 2N7000 never loads. The window title is unchanged after the call (Adom:ADS1015IDGS — Symbol Editor).

So for a different part the show verb neither fast-paths nor navigates: it runs cold and fails to switch. For Quick Actions this is the COMMON path, not an edge case. The "Open in Symbol/Footprint Editor" buttons are per-part, so a user browsing parts almost always has the editor open on a previous part when they click the next one, which is exactly the "one editor at a time, and it will not switch" behavior the user hit.

Desired: editor open but on a different part -> navigate the OPEN editor to the requested library:part (LIB_TREE select/load) and surface it per the window-etiquette rules, with no relaunch and no full library rescan. Same for kicad_show_footprint.

The "does not load a different part into an already-open editor" half may be the same background LIB_TREE navigation degraded in #31 on KiCad 10.0.5. If so, link them. I can confirm the exact KiCad build on the box and grab the sub-phase breakdown (which progress step eats the 53s, plus durationMs / progress.measured) on the next click to target it precisely.

John Lauer ·

I could not reproduce your switch failure, but chasing it found a worse bug in the same code path, and I would rather show you the negative result than a fix I cannot justify.

WHAT I TRIED. I set up your exact conditions on a second box (ConfRoomROG), including the part I thought mattered most: KiCad launched by a HUMAN, not by the bridge, so nothing in the process is bridge-owned.

editor open on Adom:IN-S42ATR, ask for Adom:AdomDemo_IC -> success, 9.1s, title Adom:AdomDemo_IC editor open on Adom:AdomDemo_IC, ask for Adom:VLMB1500 -> success, 9.2s, title Adom:VLMB1500

No relaunch, no library rescan, correct part, on both boxes. So "editor open on a different part -> navigate" DOES work here, in 9 seconds, on a user-launched KiCad. Your ~53s cold sequence is not something I can currently make happen, which means I do not yet understand it and should not claim a fix.

THE BUG I FOUND INSTEAD, and it is mine. My first repro attempt asked for symbol RP2040 in library Adom on a box where that symbol does not exist in Adom. It should have failed. It returned:

success: true, 57s "Symbol 'RP2040' loaded (background win32 path): AdomRP2040:ADOM_MECHANICAL_PIN - Symbol Editor"

The filter text "Adom RP2040" matched a DIFFERENT library that happens to be named AdomRP2040, KiCad selected that library's first symbol, and the load check was requested.lower() in title.lower() - a substring test. "rp2040" is a substring of "adomrp2040", so the bridge certified a part it never loaded, from a library nobody asked for. A caller then screenshots that as evidence.

Fixed in 0.9.194: the title is parsed into library:symbol and both are compared exactly, so the check is proof rather than a coincidence. Same call now:

success: false, "Symbol Editor open but 'RP2040' didn't load in the background after two attempts (title: AdomRP2040:ADOM_MECHANICAL_PIN - Symbol Editor)"

and the three legitimate loads above still pass at 9s, so this is not over-correction.

WHY THIS MATTERS FOR YOUR REPORT. Your symptom is "the editor stays on ADS1015IDGS and 2N7000 never loads". With the old substring check, whether that call reported success or failure depended on an accident of naming. If any part of "2N7000" appeared in the old title you would have gotten a FALSE success; you got a failure, so it did not - but the verdict was never trustworthy either way, and neither of us could have told a genuine navigation failure from a bad check. That had to go first.

ALSO SHIPPED, 0.9.192-0.9.193, both possibly relevant to you:

  • errorCode library_cache_stale. A Symbol Editor indexes its libraries ONCE, at open. A symbol installed AFTER that is on disk and invisible to that editor, and no retry will ever find it. Verified live: a part present at open loads first try; a part installed minutes later fails forever. If your Quick Actions flow installs the part and then clicks "Open in Symbol Editor", this is very likely your actual cause. The verb now names it and rescan:true fixes it by closing and reopening the editor (costs the cold index, ~60s, and it says so).
  • The verb retries the background navigation itself instead of telling you to retry.
  • kicad_install_symbol flags staleEditorOpen at install time, when the staleness is created.

WHAT I NEED FROM YOUR BOX, and it is now two cheap calls rather than a file hunt. On 0.9.194, at the moment of a failing Quick Actions click:

  1. kicad_show_symbol {...} - send the WHOLE response. attempts, errorCode, and the title in the error text now distinguish the three causes: stale index, genuine navigation failure, or the editor not being found at all.
  2. kicad_plugin_diagnose {} - read-only. (0.9.194 also stops this verb from judging a box where KiCad is not running: it was reporting "IMPORTED BUT DID NOT START" off log lines written by the bridge's own python.exe probes, which is a confident answer to a question nobody could answer yet. It now separates GUI lines from probe lines and says KICAD NOT RUNNING when that is the truth.)

The specific thing I want to know: does your failing call take ~53s, or ~9s? 53s means the Symbol Editor was NOT found and the cold path ran, which is a different bug from navigation failing, and it is the half I cannot reproduce. 9s means it found the editor and the navigation itself failed, which points at the stale index.

Still not done from your original asks: sub-phase timings (launch vs library-scan vs navigate) and replacing the fixed settle sleeps with poll-until-ready. Your ask for the sub-phase breakdown is exactly what would answer the 53s question without another round of this, so it moves up.

John Lauer ·

Retracting a lead I gave you, before you spend time on it.

I said the blank editor canvas I was seeing was "very likely the same defect as your 2N7000 never loads". It is not. Withdraw that.

Every blank canvas I had came from one machine (a conference-room box). On a normal workstation the canvas renders correctly every time - I verified four opens this morning on 0.9.201 and looked at each one: three symbols and a footprint, all fully drawn. The mechanism is almost certainly the host, not the navigation: KiCad draws into a wxGLCanvas, an OpenGL surface, which produces no picture on a box with no usable GPU or no active console session, while the window frame captures fine. Nothing to do with loading a part.

So your issue is still exactly what your evidence said it was, and my detour did not touch it: the editor is open, and asking for a different part neither fast-paths nor navigates. I still cannot reproduce that. On both my boxes, including one where a human launched KiCad rather than the bridge, switching an open editor to a different part takes ~9s, no relaunch, no rescan, correct title, correct canvas.

The one number that would split it in two, when you next hit it on 0.9.201:

  • ~53s means the Symbol Editor was NOT found and the whole cold path ran. That is a detection bug, and it is the half I have never reproduced.
  • ~9s means the editor was found and the navigation itself failed, which points at the stale library index (errorCode: library_cache_stale, remedy rescan:true) shipped in 0.9.193.

0.9.201 also returns evidence.canvasRendered on every show_*, so if a part ever DOES load without drawing on your box, the response will now say so outright instead of leaving you to squint at a screenshot.

Sorry for the noise - better to pull the wrong lead than let you chase it.

Colby Knox ·

Reproduced and split it. It is neither of your two branches cleanly: detection works, the failure is the stale library index, and the wiki recipe is what walks straight into it.

Colby-ROG2, kicad-bridge 0.9.210 (auto-synced past 0.9.201), KiCad 10.0, all driven over the relay in the background.

step result
cold open A (show_symbol ADS1220IRVAR) success, 60.5s, canvasRendered:true
re-show A, same part success, 2.7s, reused:true ("no relaunch, no library rescan")
install B (LM1117DT-3.3) while A's editor is open success, staleEditorOpen: true ("a Symbol Editor was already open when these symbols were added, so it cannot see them until it reopens")
show B (different part, installed AFTER open) fail, library_cache_stale, attempts:2, ~30s
show B with rescan:true success, 56.8s, canvasRendered:true (screenshot below)

So:

  • Detection is fine on this box. Re-showing the open part fast-paths in 2.7s, reused:true. The editor is found. That rules out your ~53s "editor not found" branch.
  • The failure is library_cache_stale. The ~30s Colby read as "53s" is the 2-attempt retry against a stale index, not a cold relaunch (a real cold open here is ~60s). "2N7000 never loaded" is exactly this error surfacing.
  • Why you got 9s and could not reproduce it: your repro showed a part that was already installed before the editor opened, so it was in the index and navigation succeeded. The wiki Quick Actions recipe installs the part and THEN shows it, so whenever an editor is already open from a previous click, the new part is installed-after-open every time. That is the stale trigger you never hit, and it is the common path for us because the buttons are per-part.
  • rescan:true is the confirmed remedy: it reopens the editor, pays the ~57s reindex, and the new part renders (screenshot: Adom:LM1117DT-3.3 — Symbol Editor, canvas drawn).

Nothing further needed from you here, 0.9.193's staleEditorOpen flag + library_cache_stale + rescan:true are exactly the right primitives. The remaining work is wiki-side: on staleEditorOpen (or a library_cache_stale from show), the recipe should go straight to rescan:true and tell the user it is refreshing the library (~1 min). I am implementing that now.

Two thank-yous: canvasRendered plus the auto-pulled screenshot made this a clean, evidence-backed measurement instead of squinting at a window, and the staleEditorOpen flag at install time is what let me localize it in one pass.

kicad-editor-adomlm1117dt-33-symbol-editor-1787238174316

Colby Knox ·

Wiki fix shipped to prod. The recipe now reads staleEditorOpen from the install response and goes straight to show {rescan:true} (skipping the doomed ~30s first show), and falls back to a rescan if a normal show still returns library_cache_stale. So a freshly-installed part renders in an already-open editor instead of silently not loading.

The residual is pure KiCad cost, not a bug: switching an already-open editor to a newly-installed part now pays the ~1 min reindex every time, because rescan reopens the editor. We surface it as "refreshing the library (about a minute)..." so it is not a mystery spinner. If the reindex could ever be made cheaper on the bridge side (a warm index, or a targeted add rather than a full reopen), that is the one thing between this and instant part-switching. Your call whether that is worth a separate perf issue or just the nature of KiCad's index-at-open.

Thanks again for the fast primitives here. staleEditorOpen at install time is what let the client skip straight to the remedy instead of eating the failed attempt first.

John Lauer ·

Root cause confirmed - and 0.9.211 now does the remedy itself, no argument needed

Your split is right and your explanation of why I could not reproduce it is exactly correct. My repro installed the part BEFORE opening the editor, so it was in the index and navigation succeeded in 9s. The Quick Actions recipe installs and THEN shows, so with an editor already open the symbol is installed-after-open every time. I was testing the one ordering that cannot fail.

So I have stopped making you ask for the fix. rescan:true was the right primitive but the wrong contract: the bridge already knows the index is stale (it says so), and it already knows the remedy, so requiring the caller to pass an argument is the bridge passing its own retry loop out through the API. That was the same mistake 0.9.192 fixed for the navigate retry, and I repeated it.

0.9.211: a stale index re-indexes itself. Reproduced your exact sequence on an idle box:

1. show A (IN-S42ATR)              -> success, 24.1s   [editor now open]
2. install B WHILE A is open       -> staleEditorOpen: true      <- your trigger
3. show B, NO rescan argument      -> success, autoRescanned: true
                                      window: Adom:AUTORESCAN-TEST — Symbol Editor
                                      canvasRendered: true
                                      85s total (the cold re-index, as expected)

Step 3 is the call that failed for you with library_cache_stale. It now succeeds on its own.

The one guard that matters: it only closes an editor the BRIDGE owns. The ownership ledger already tracks which KiCad windows we spawned, so an editor a HUMAN opened is never closed automatically - that case still returns library_cache_stale and asks, because silently closing a window someone is working in is worse than any stale index. The response carries autoRescanned: true and a hint explaining why the call took about a minute, so the extra time is never mysterious.

What this means for your wiki-side work: the branch you are implementing still has a job, but a smaller one. You no longer need to detect library_cache_stale and re-issue with rescan:true for the ordinary case - just tell the user it may take about a minute when autoRescanned comes back true. Keep the explicit path for an editor the user opened themselves, since the bridge deliberately will not touch that one.

Thank you for the measurement discipline on this. The table you posted - fast path 2.7s, cold 60.5s, stale failure ~30s at 2 attempts - is what made it unambiguous that this was never the "editor not found" branch, and I would have kept chasing the wrong half without it. Noting for my own process: I could not reproduce it because my repro was constructed rather than taken from the real caller's sequence. The wiki recipe's ordering was the whole bug, and it was never in any test I wrote.

John Lauer ·

Closing - re-verified on 0.9.217 just now, with a brand new symbol

Your root cause was right and the remedy is now automatic. Re-ran your exact sequence on an idle box, using a symbol created for this test so nothing could already be in the index:

1. show IN-S42ATR                     -> editor open: Adom:IN-S42ATR — Symbol Editor
2. install CLOSEVERIFY-183536 while that editor is open
                                      -> staleEditorOpen: true
3. show CLOSEVERIFY-183536, NO rescan argument
                                      -> success: true
                                         autoRescanned: true
                                         window: Adom:CLOSEVERIFY-183536 — Symbol Editor
                                         canvasRendered: true
                                         85s (the cold re-index)

Step 3 is the call that failed for you with library_cache_stale. It succeeds unaided now.

Worth noting how easily this test could have lied: my first run reported autoRescanned: null and looked like a pass, because the symbol I used had been installed BEFORE the editor opened in an earlier run, so it was already indexed and loaded normally. Same trap as my original repro, which is exactly why I could not reproduce your bug for two days. A new symbol per run is the only version of this test that means anything.

Guard unchanged: only an editor the BRIDGE owns is closed automatically. One a human opened still returns library_cache_stale and asks, because closing a window someone is working in is worse than a stale index.

Reopen if the Quick Actions path still hits it.

John Lauer closed this ·

Log in to reply.