From 0bc00b14510acbfb1ded4f7b500c5f210aabc3b7 Mon Sep 17 00:00:00 2001 From: William Viana Date: Fri, 3 Apr 2026 11:24:42 -0700 Subject: [PATCH] fix: prevent pcbnew stdout noise from causing sync_schematic_to_board timeouts The TS<->Python communication channel uses stdout for JSON responses. pcbnew's C++ SWIG layer can write warnings and diagnostics directly to C-level stdout (fd 1), corrupting the JSON framing. The TS parser then never sees valid JSON and the command times out after 30 seconds. Three changes fix this: 1. Python stdout redirect: In main(), save the original stdout fd for exclusive JSON response use, then redirect fd 1 to stderr so all pcbnew C++ output goes to logs instead of the response pipe. 2. Robust TS JSON parser: tryParseResponse() now uses newline-delimited parsing as a fallback. The Python side writes single-line JSON terminated by \n; the parser uses this as the completion signal instead of brace-matching, which prevents premature resolution of truncated chunked responses. Non-JSON preamble lines are logged and stripped. 3. Fix stray print() calls: Converted print() to logger in component_schematic.py and library_schematic.py so they don't leak to stdout during normal operations. Also adds sync_schematic_to_board to the longRunningCommands list for an appropriate timeout value. --- python/commands/component_schematic.py | 21 +++-- python/commands/library_schematic.py | 19 ++-- python/kicad_interface.py | 29 ++++-- src/server.ts | 118 +++++++++++++++++++------ 4 files changed, 137 insertions(+), 50 deletions(-) diff --git a/python/commands/component_schematic.py b/python/commands/component_schematic.py index 2592820..597709d 100644 --- a/python/commands/component_schematic.py +++ b/python/commands/component_schematic.py @@ -278,13 +278,13 @@ class ComponentManager: if symbol_to_remove: schematic.symbol._elements.remove(symbol_to_remove) - print(f"Removed component {component_ref} from schematic.") + logger.info(f"Removed component {component_ref} from schematic.") return True else: - print(f"Component with reference {component_ref} not found.") + logger.warning(f"Component with reference {component_ref} not found.") return False except Exception as e: - print(f"Error removing component {component_ref}: {e}") + logger.error(f"Error removing component {component_ref}: {e}") return False @staticmethod @@ -302,15 +302,14 @@ class ComponentManager: if key in symbol_to_update.property: symbol_to_update.property[key].value = value else: - # Add as a new property if it doesn't exist symbol_to_update.property.append(key, value) - print(f"Updated properties for component {component_ref}.") + logger.info(f"Updated properties for component {component_ref}.") return True else: - print(f"Component with reference {component_ref} not found.") + logger.warning(f"Component with reference {component_ref} not found.") return False except Exception as e: - print(f"Error updating component {component_ref}: {e}") + logger.error(f"Error updating component {component_ref}: {e}") return False @staticmethod @@ -318,9 +317,9 @@ class ComponentManager: """Get a component by reference designator""" for symbol in schematic.symbol: if symbol.reference == component_ref: - print(f"Found component with reference {component_ref}.") + logger.debug(f"Found component with reference {component_ref}.") return symbol - print(f"Component with reference {component_ref} not found.") + logger.warning(f"Component with reference {component_ref} not found.") return None @staticmethod @@ -339,13 +338,13 @@ class ComponentManager: ) ): matching_components.append(symbol) - print(f"Found {len(matching_components)} components matching query '{query}'.") + logger.debug(f"Found {len(matching_components)} components matching query '{query}'.") return matching_components @staticmethod def get_all_components(schematic: Schematic): """Get all components in schematic""" - print(f"Retrieving all {len(schematic.symbol)} components.") + logger.debug(f"Retrieving all {len(schematic.symbol)} components.") return list(schematic.symbol) diff --git a/python/commands/library_schematic.py b/python/commands/library_schematic.py index 6ddf7b4..8d683d5 100644 --- a/python/commands/library_schematic.py +++ b/python/commands/library_schematic.py @@ -1,10 +1,13 @@ import glob +import logging # Symbol class might not be directly importable in the current version import os from skip import Schematic +logger = logging.getLogger(__name__) + class LibraryManager: """Manage symbol libraries""" @@ -31,11 +34,11 @@ class LibraryManager: matching_libs = glob.glob(path_pattern, recursive=True) libraries.extend(matching_libs) except Exception as e: - print(f"Error searching for libraries at {path_pattern}: {e}") + logger.error(f"Error searching for libraries at {path_pattern}: {e}") # Extract library names from paths library_names = [os.path.splitext(os.path.basename(lib))[0] for lib in libraries] - print( + logger.info( f"Found {len(library_names)} libraries: {', '.join(library_names[:10])}{'...' if len(library_names) > 10 else ''}" ) @@ -54,12 +57,12 @@ class LibraryManager: # A potential approach would be to load the library file using KiCAD's Python API # or by parsing the library file format. # KiCAD symbol libraries are .kicad_sym files which are S-expression format - print( + logger.warning( f"Attempted to list symbols in library {library_path}. This requires advanced implementation." ) return [] except Exception as e: - print(f"Error listing symbols in library {library_path}: {e}") + logger.error(f"Error listing symbols in library {library_path}: {e}") return [] @staticmethod @@ -68,12 +71,12 @@ class LibraryManager: try: # Similar to list_library_symbols, this might require a more direct approach # using KiCAD's Python API or by parsing the symbol library. - print( + logger.warning( f"Attempted to get details for symbol {symbol_name} in library {library_path}. This requires advanced implementation." ) return {} except Exception as e: - print(f"Error getting symbol details for {symbol_name} in {library_path}: {e}") + logger.error(f"Error getting symbol details for {symbol_name} in {library_path}: {e}") return {} @staticmethod @@ -89,12 +92,12 @@ class LibraryManager: libraries = LibraryManager.list_available_libraries(search_paths) results = [] - print( + logger.warning( f"Searched for symbols matching '{query}'. This requires advanced implementation." ) return results except Exception as e: - print(f"Error searching for symbols matching '{query}': {e}") + logger.error(f"Error searching for symbols matching '{query}': {e}") return [] @staticmethod diff --git a/python/kicad_interface.py b/python/kicad_interface.py index 1c14710..68db19d 100644 --- a/python/kicad_interface.py +++ b/python/kicad_interface.py @@ -4024,8 +4024,29 @@ print("ok") } +def _write_response(response_fd, response): + """Write a JSON response to the original stdout fd. + + All response output goes through this function so that stray C-level + writes from pcbnew (warnings, diagnostics) never corrupt the JSON + framing seen by the TypeScript host. + """ + payload = json.dumps(response) + "\n" + os.write(response_fd, payload.encode("utf-8")) + + def main(): """Main entry point""" + # --- Redirect stdout so pcbnew C++ noise never reaches the TS host --- + # Save the real stdout fd for our exclusive JSON response channel. + _response_fd = os.dup(1) + # Point fd 1 (C-level stdout) at stderr so that any printf / std::cout + # output from pcbnew or other C extensions is visible in logs but does + # NOT corrupt the JSON stream the TypeScript side is parsing. + os.dup2(2, 1) + # Also redirect Python-level stdout to stderr for the same reason. + sys.stdout = sys.stderr + logger.info("Starting KiCAD interface...") interface = KiCADInterface() @@ -4167,10 +4188,9 @@ def main(): # Handle command response = interface.handle_command(command, params) - # Send response + # Send response via the clean fd (immune to pcbnew stdout noise) logger.debug(f"Sending response: {response}") - print(json.dumps(response)) - sys.stdout.flush() + _write_response(_response_fd, response) except json.JSONDecodeError as e: logger.error(f"Invalid JSON input: {str(e)}") @@ -4179,8 +4199,7 @@ def main(): "message": "Invalid JSON input", "errorDetails": str(e), } - print(json.dumps(response)) - sys.stdout.flush() + _write_response(_response_fd, response) except KeyboardInterrupt: logger.info("KiCAD interface stopped") diff --git a/src/server.ts b/src/server.ts index 6abd742..708e607 100644 --- a/src/server.ts +++ b/src/server.ts @@ -516,7 +516,13 @@ export class KiCADMcpServer { // Determine timeout based on command type // DRC and export operations need longer timeouts for large boards let commandTimeout = 30000; // Default 30 seconds - const longRunningCommands = ["run_drc", "export_gerber", "export_pdf", "export_3d"]; + const longRunningCommands = [ + "run_drc", + "export_gerber", + "export_pdf", + "export_3d", + "sync_schematic_to_board", + ]; if (longRunningCommands.includes(command)) { commandTimeout = 600000; // 10 minutes for long operations logger.info(`Using extended timeout (${commandTimeout / 1000}s) for command: ${command}`); @@ -550,7 +556,21 @@ export class KiCADMcpServer { } /** - * Try to parse a complete JSON response from the buffer + * Try to parse a complete JSON response from the buffer. + * + * Responses from the Python side are single-line JSON terminated by '\n' + * (written via _write_response). The buffer may also contain non-JSON + * preamble lines (e.g. C-level warnings from pcbnew that leaked to the + * response fd before the redirect took effect). + * + * Strategy: + * 1. Fast path: JSON.parse(buffer) — works for clean, complete responses + * (JSON.parse tolerates trailing whitespace/newlines). + * 2. If that fails and the buffer has no '\n' yet, the response line is + * still arriving in chunks — keep collecting. + * 3. If the buffer has '\n', split into lines and search from the END for + * a parseable JSON line. This avoids prematurely resolving with a + * truncated JSON object when a large response is still chunking in. */ private tryParseResponse(): void { if (!this.currentRequestHandler) { @@ -564,37 +584,83 @@ export class KiCADMcpServer { return; } + let result: any; + + // Fast path: try to parse the response as JSON. Handles the common + // case of a clean, complete JSON response (possibly with trailing \n). try { - // Try to parse the response as JSON - const result = JSON.parse(this.responseBuffer); - - // If we get here, we have a valid JSON response - logger.debug( - `Completed KiCAD command with result: ${result.success ? "success" : "failure"}`, - ); - - // Clear the timeout since we got a response - if (this.currentRequestHandler.timeoutHandle) { - clearTimeout(this.currentRequestHandler.timeoutHandle); + result = JSON.parse(this.responseBuffer); + } catch { + // Direct parse failed. Either the response is still arriving in + // chunks, or the buffer has non-JSON preamble from pcbnew. + // + // The Python side writes each response as a single line of JSON + // terminated by \n. We use the newline as the completion signal: + // if there is no \n in the buffer yet, the JSON line is still + // being assembled from chunks — keep collecting. + if (!this.responseBuffer.includes("\n")) { + return; } - // Get the handler before clearing - const handler = this.currentRequestHandler; + // Buffer contains newline(s). Split into lines and look for a + // complete JSON object, searching from the END so that preamble + // lines (which may themselves contain '{') are skipped. + const lines = this.responseBuffer.split("\n"); + let jsonLineIndex = -1; - // Clear state - this.responseBuffer = ""; - this.currentRequestHandler = null; - this.processingRequest = false; + for (let i = lines.length - 1; i >= 0; i--) { + const line = lines[i].trim(); + if (line.length === 0) continue; + if (!line.startsWith("{")) continue; - // Resolve the promise with the result - handler.resolve(result); + try { + result = JSON.parse(line); + jsonLineIndex = i; + break; + } catch { + // Looks like JSON but doesn't parse — could be an incomplete + // final line still being chunked. Keep collecting. + continue; + } + } - // Process next request if any - setTimeout(() => this.processNextRequest(), 0); - } catch (e) { - // Not a complete JSON yet, keep collecting data - // This is normal for large responses that come in chunks + if (jsonLineIndex < 0) { + // No parseable JSON line found yet. Either only preamble has + // arrived, or the JSON line is split across the last \n boundary + // and is still incomplete. Keep collecting. + return; + } + + // Log any preceding non-JSON lines as preamble + const preambleLines = lines.slice(0, jsonLineIndex).filter((l) => l.trim().length > 0); + if (preambleLines.length > 0) { + logger.warn( + `Stripped non-JSON preamble from Python response: ${preambleLines.join(" | ")}`, + ); + } } + + // If we get here, we have a valid JSON response + logger.debug(`Completed KiCAD command with result: ${result.success ? "success" : "failure"}`); + + // Clear the timeout since we got a response + if (this.currentRequestHandler.timeoutHandle) { + clearTimeout(this.currentRequestHandler.timeoutHandle); + } + + // Get the handler before clearing + const handler = this.currentRequestHandler; + + // Clear state + this.responseBuffer = ""; + this.currentRequestHandler = null; + this.processingRequest = false; + + // Resolve the promise with the result + handler.resolve(result); + + // Process next request if any + setTimeout(() => this.processNextRequest(), 0); } /**