diff --git a/MCPForUnity/Editor/Services/Transport/TransportCommandDispatcher.cs b/MCPForUnity/Editor/Services/Transport/TransportCommandDispatcher.cs index 999c7bf11..9020a869b 100644 --- a/MCPForUnity/Editor/Services/Transport/TransportCommandDispatcher.cs +++ b/MCPForUnity/Editor/Services/Transport/TransportCommandDispatcher.cs @@ -35,6 +35,7 @@ public PendingCommand( CompletionSource = completionSource; CancellationToken = cancellationToken; CancellationRegistration = registration; + QueuedAt = DateTime.UtcNow; } public string CommandJson { get; } @@ -42,6 +43,7 @@ public PendingCommand( public CancellationToken CancellationToken { get; } public CancellationTokenRegistration CancellationRegistration { get; } public bool IsExecuting { get; set; } + public DateTime QueuedAt { get; } public void Dispose() { diff --git a/MCPForUnity/Editor/Services/Transport/Transports/WebSocketTransportClient.cs b/MCPForUnity/Editor/Services/Transport/Transports/WebSocketTransportClient.cs index 856577c06..b94c0836f 100644 --- a/MCPForUnity/Editor/Services/Transport/Transports/WebSocketTransportClient.cs +++ b/MCPForUnity/Editor/Services/Transport/Transports/WebSocketTransportClient.cs @@ -619,6 +619,7 @@ private Task SendPongAsync(CancellationToken token) var payload = new JObject { ["type"] = "pong", + ["session_id"] = _sessionId // Include session ID for server-side tracking }; return SendJsonAsync(payload, token); } @@ -652,6 +653,10 @@ private async Task SendJsonAsync(JObject payload, CancellationToken token) private async Task HandleSocketClosureAsync(string reason) { + // Capture stack trace for debugging disconnection triggers + var stackTrace = new System.Diagnostics.StackTrace(true); + McpLog.Debug($"[WebSocket] HandleSocketClosureAsync called. Reason: {reason}\nStack trace:\n{stackTrace}"); + if (_lifecycleCts == null || _lifecycleCts.IsCancellationRequested) { return; diff --git a/Server/src/transport/legacy/unity_connection.py b/Server/src/transport/legacy/unity_connection.py index 08e00ca14..b63b24a1a 100644 --- a/Server/src/transport/legacy/unity_connection.py +++ b/Server/src/transport/legacy/unity_connection.py @@ -306,8 +306,10 @@ def read_status_file(target_hash: str | None = None) -> dict | None: for attempt in range(attempts + 1): try: # Ensure connected (handshake occurs within connect()) + t_conn_start = time.time() if not self.sock and not self.connect(): raise ConnectionError("Could not connect to Unity") + logger.info("[TIMING-STDIO] connect took %.3fs command=%s", time.time() - t_conn_start, command_type) # Build payload if command_type == 'ping': @@ -324,12 +326,14 @@ def read_status_file(target_hash: str | None = None) -> dict | None: with contextlib.suppress(Exception): logger.debug( f"send {len(payload)} bytes; mode={mode}; head={payload[:32].decode('utf-8', 'ignore')}") + t_send_start = time.time() if self.use_framing: header = struct.pack('>Q', len(payload)) self.sock.sendall(header) self.sock.sendall(payload) else: self.sock.sendall(payload) + logger.info("[TIMING-STDIO] sendall took %.3fs command=%s", time.time() - t_send_start, command_type) # During retry bursts use a short receive timeout and ensure restoration restore_timeout = None @@ -337,7 +341,9 @@ def read_status_file(target_hash: str | None = None) -> dict | None: restore_timeout = self.sock.gettimeout() self.sock.settimeout(1.0) try: + t_recv_start = time.time() response_data = self.receive_full_response(self.sock) + logger.info("[TIMING-STDIO] receive took %.3fs command=%s len=%d", time.time() - t_recv_start, command_type, len(response_data)) with contextlib.suppress(Exception): logger.debug( f"recv {len(response_data)} bytes; mode={mode}") @@ -419,7 +425,8 @@ def read_status_file(target_hash: str | None = None) -> dict | None: # Cap backoff depending on state if status and status.get('reloading'): - cap = 0.8 + # Domain reload can take 10-20s; use longer waits + cap = 5.0 elif fast_error: cap = 0.25 else: @@ -761,22 +768,36 @@ def send_command_with_retry( Uses config.reload_retry_ms and config.reload_max_retries by default. Preserves the structured failure if retries are exhausted. """ + t_retry_start = time.time() + logger.info("[TIMING-STDIO] send_command_with_retry START command=%s", command_type) + t_get_conn = time.time() conn = get_unity_connection(instance_id) + logger.info("[TIMING-STDIO] get_unity_connection took %.3fs command=%s", time.time() - t_get_conn, command_type) if max_retries is None: max_retries = getattr(config, "reload_max_retries", 40) if retry_ms is None: retry_ms = getattr(config, "reload_retry_ms", 250) + # Default to 20s to handle domain reloads (which can take 10-20s after tests or script changes). + # + # NOTE: This wait can impact agentic workflows where domain reloads happen + # frequently (e.g., after test runs, script compilation). The 20s default + # balances handling slow reloads vs. avoiding unnecessary delays. + # + # TODO: Make this more deterministic by detecting Unity's actual reload state + # rather than blindly waiting up to 20s. See Issue #657. + # + # Configurable via: UNITY_MCP_RELOAD_MAX_WAIT_S (default: 20.0, max: 20.0) try: max_wait_s = float(os.environ.get( - "UNITY_MCP_RELOAD_MAX_WAIT_S", "2.0")) + "UNITY_MCP_RELOAD_MAX_WAIT_S", "20.0")) except ValueError as e: - raw_val = os.environ.get("UNITY_MCP_RELOAD_MAX_WAIT_S", "2.0") + raw_val = os.environ.get("UNITY_MCP_RELOAD_MAX_WAIT_S", "20.0") logger.warning( - "Invalid UNITY_MCP_RELOAD_MAX_WAIT_S=%r, using default 2.0: %s", + "Invalid UNITY_MCP_RELOAD_MAX_WAIT_S=%r, using default 20.0: %s", raw_val, e) - max_wait_s = 2.0 - # Clamp to [0, 30] to prevent misconfiguration from causing excessive waits - max_wait_s = max(0.0, min(max_wait_s, 30.0)) + max_wait_s = 20.0 + # Clamp to [0, 20] to prevent misconfiguration from causing excessive waits + max_wait_s = max(0.0, min(max_wait_s, 20.0)) # If retry_on_reload=False, disable connection-level retries too (issue #577) # Commands that trigger compilation/reload shouldn't retry on disconnect @@ -847,6 +868,7 @@ def send_command_with_retry( instance_id or "default", waited, ) + logger.info("[TIMING-STDIO] send_command_with_retry DONE total=%.3fs command=%s", time.time() - t_retry_start, command_type) return response diff --git a/Server/src/transport/models.py b/Server/src/transport/models.py index 5aa9828a4..802951a24 100644 --- a/Server/src/transport/models.py +++ b/Server/src/transport/models.py @@ -23,6 +23,11 @@ class ExecuteCommandMessage(BaseModel): params: dict[str, Any] timeout: float + +class PingMessage(BaseModel): + """Server-initiated ping to detect dead connections.""" + type: str = "ping" + # Incoming (Plugin -> Server) diff --git a/Server/src/transport/plugin_hub.py b/Server/src/transport/plugin_hub.py index b9904fa8e..1058c4136 100644 --- a/Server/src/transport/plugin_hub.py +++ b/Server/src/transport/plugin_hub.py @@ -7,7 +7,7 @@ import os import time import uuid -from typing import Any +from typing import Any, ClassVar from starlette.endpoints import WebSocketEndpoint from starlette.websockets import WebSocket @@ -21,6 +21,7 @@ WelcomeMessage, RegisteredMessage, ExecuteCommandMessage, + PingMessage, RegisterMessage, RegisterToolsMessage, PongMessage, @@ -29,7 +30,7 @@ SessionDetails, ) -logger = logging.getLogger("mcp-for-unity-server") +logger = logging.getLogger(__name__) class PluginDisconnectedError(RuntimeError): @@ -63,6 +64,10 @@ class PluginHub(WebSocketEndpoint): KEEP_ALIVE_INTERVAL = 15 SERVER_TIMEOUT = 30 COMMAND_TIMEOUT = 30 + # Server-side ping interval (seconds) - how often to send pings to Unity + PING_INTERVAL = 10 + # Max time (seconds) to wait for pong before considering connection dead + PING_TIMEOUT = 20 # Timeout (seconds) for fast-fail commands like ping/read_console/get_editor_state. # Keep short so MCP clients aren't blocked during Unity compilation/reload/unfocused throttling. FAST_FAIL_TIMEOUT = 2.0 @@ -78,6 +83,10 @@ class PluginHub(WebSocketEndpoint): _pending: dict[str, dict[str, Any]] = {} _lock: asyncio.Lock | None = None _loop: asyncio.AbstractEventLoop | None = None + # session_id -> last pong timestamp (monotonic) + _last_pong: ClassVar[dict[str, float]] = {} + # session_id -> ping task + _ping_tasks: ClassVar[dict[str, asyncio.Task]] = {} @classmethod def configure( @@ -176,12 +185,20 @@ async def on_disconnect(self, websocket: WebSocket, close_code: int) -> None: (sid for sid, ws in cls._connections.items() if ws is websocket), None) if session_id: cls._connections.pop(session_id, None) + # Stop the ping loop for this session + ping_task = cls._ping_tasks.pop(session_id, None) + if ping_task and not ping_task.done(): + ping_task.cancel() + # Clean up last pong tracking + cls._last_pong.pop(session_id, None) # Fail-fast any in-flight commands for this session to avoid waiting for COMMAND_TIMEOUT. pending_ids = [ command_id for command_id, entry in cls._pending.items() if entry.get("session_id") == session_id ] + if pending_ids: + logger.debug(f"Cancelling {len(pending_ids)} pending commands for disconnected session") for command_id in pending_ids: entry = cls._pending.get(command_id) future = entry.get("future") if isinstance( @@ -364,10 +381,18 @@ async def _handle_register(self, websocket: WebSocket, payload: RegisterMessage) session = await registry.register(session_id, project_name, project_hash, unity_version, project_path, user_id=user_id) async with lock: cls._connections[session.session_id] = websocket + # Initialize last pong time and start ping loop for this session + cls._last_pong[session_id] = time.monotonic() + # Cancel any existing ping task for this session (shouldn't happen, but be safe) + old_task = cls._ping_tasks.pop(session_id, None) + if old_task and not old_task.done(): + old_task.cancel() + # Start the server-side ping loop + ping_task = asyncio.create_task(cls._ping_loop(session_id, websocket)) + cls._ping_tasks[session_id] = ping_task if user_id: - logger.info( - f"Plugin registered: {project_name} ({project_hash}) for user {user_id}") + logger.info(f"Plugin registered: {project_name} ({project_hash}) for user {user_id}") else: logger.info(f"Plugin registered: {project_name} ({project_hash})") @@ -429,11 +454,77 @@ async def _handle_command_result(self, payload: CommandResultMessage) -> None: async def _handle_pong(self, payload: PongMessage) -> None: cls = type(self) registry = cls._registry + lock = cls._lock if registry is None: return session_id = payload.session_id if session_id: await registry.touch(session_id) + # Record last pong time for staleness detection (under lock for consistency) + if lock is not None: + async with lock: + cls._last_pong[session_id] = time.monotonic() + + @classmethod + async def _ping_loop(cls, session_id: str, websocket: WebSocket) -> None: + """Server-initiated ping loop to detect dead connections. + + Sends periodic pings to the Unity client. If no pong is received within + PING_TIMEOUT seconds, the connection is considered dead and closed. + This helps detect connections that die silently (e.g., Windows OSError 64). + """ + logger.debug(f"[Ping] Starting ping loop for session {session_id}") + try: + while True: + await asyncio.sleep(cls.PING_INTERVAL) + + # Check if we're still supposed to be running and get last pong time (under lock) + lock = cls._lock + if lock is None: + break + async with lock: + if session_id not in cls._connections: + logger.debug(f"[Ping] Session {session_id} no longer in connections, stopping ping loop") + break + # Read last pong time under lock for consistency + last_pong = cls._last_pong.get(session_id, 0) + + # Check staleness: has it been too long since we got a pong? + elapsed = time.monotonic() - last_pong + if elapsed > cls.PING_TIMEOUT: + logger.warning( + f"[Ping] Session {session_id} stale: no pong for {elapsed:.1f}s " + f"(timeout={cls.PING_TIMEOUT}s). Closing connection." + ) + try: + await websocket.close(code=1001) # Going away + except Exception as close_ex: + logger.debug(f"[Ping] Error closing stale websocket: {close_ex}") + break + + # Send a ping to the client + try: + ping_msg = PingMessage() + await websocket.send_json(ping_msg.model_dump()) + logger.debug(f"[Ping] Sent ping to session {session_id}") + except Exception as send_ex: + # Send failed - connection is dead + logger.warning( + f"[Ping] Failed to send ping to session {session_id}: {send_ex}. " + "Connection likely dead." + ) + try: + await websocket.close(code=1006) # Abnormal closure + except Exception: + pass + break + + except asyncio.CancelledError: + logger.debug(f"[Ping] Ping loop cancelled for session {session_id}") + except Exception as ex: + logger.warning(f"[Ping] Ping loop error for session {session_id}: {ex}") + finally: + logger.debug(f"[Ping] Ping loop ended for session {session_id}") @classmethod async def _get_connection(cls, session_id: str) -> WebSocket: @@ -465,19 +556,30 @@ async def _resolve_session_id(cls, unity_instance: str | None, user_id: str | No if cls._registry is None: raise RuntimeError("Plugin registry not configured") - # Bound waiting for Unity sessions so calls fail fast when editors are not ready. + # Bound waiting for Unity sessions. Default to 20s to handle domain reloads + # (which can take 10-20s after test runs or script changes). + # + # NOTE: This wait can impact agentic workflows where domain reloads happen + # frequently (e.g., after test runs, script compilation). The 20s default + # balances handling slow reloads vs. avoiding unnecessary delays. + # + # TODO: Make this more deterministic by detecting Unity's actual reload state + # (e.g., via status file, heartbeat, or explicit "reloading" signal from Unity) + # rather than blindly waiting up to 20s. See Issue #657. + # + # Configurable via: UNITY_MCP_SESSION_RESOLVE_MAX_WAIT_S (default: 20.0, max: 20.0) try: max_wait_s = float( - os.environ.get("UNITY_MCP_SESSION_RESOLVE_MAX_WAIT_S", "2.0")) + os.environ.get("UNITY_MCP_SESSION_RESOLVE_MAX_WAIT_S", "20.0")) except ValueError as e: raw_val = os.environ.get( - "UNITY_MCP_SESSION_RESOLVE_MAX_WAIT_S", "2.0") + "UNITY_MCP_SESSION_RESOLVE_MAX_WAIT_S", "20.0") logger.warning( - "Invalid UNITY_MCP_SESSION_RESOLVE_MAX_WAIT_S=%r, using default 2.0: %s", + "Invalid UNITY_MCP_SESSION_RESOLVE_MAX_WAIT_S=%r, using default 20.0: %s", raw_val, e) - max_wait_s = 2.0 - # Clamp to [0, 30] to prevent misconfiguration from causing excessive waits - max_wait_s = max(0.0, min(max_wait_s, 30.0)) + max_wait_s = 20.0 + # Clamp to [0, 20] to prevent misconfiguration from causing excessive waits + max_wait_s = max(0.0, min(max_wait_s, 20.0)) retry_ms = float(getattr(config, "reload_retry_ms", 250)) sleep_seconds = max(0.05, min(0.25, retry_ms / 1000.0)) @@ -613,7 +715,7 @@ async def send_command_for_instance( "Invalid UNITY_MCP_SESSION_READY_WAIT_SECONDS=%r, using default 6.0: %s", raw_val, e) max_wait_s = 6.0 - max_wait_s = max(0.0, min(max_wait_s, 30.0)) + max_wait_s = max(0.0, min(max_wait_s, 20.0)) if max_wait_s > 0: deadline = time.monotonic() + max_wait_s while time.monotonic() < deadline: diff --git a/Server/src/transport/unity_instance_middleware.py b/Server/src/transport/unity_instance_middleware.py index ff0e653ef..7adbe31ab 100644 --- a/Server/src/transport/unity_instance_middleware.py +++ b/Server/src/transport/unity_instance_middleware.py @@ -214,9 +214,10 @@ async def _inject_unity_instance(self, context: MiddlewareContext) -> None: # The 'active_instance' (Name@hash) might be valid for stdio even if PluginHub fails. session_id: str | None = None - # Only validate via PluginHub if we are actually using HTTP transport - # OR if we want to support hybrid mode. For now, let's be permissive. - if PluginHub.is_configured(): + # Only validate via PluginHub if we are actually using HTTP transport. + # For stdio transport, skip PluginHub entirely - we only need the instance ID. + from transport.unity_transport import _is_http_transport + if _is_http_transport() and PluginHub.is_configured(): try: # resolving session_id might fail if the plugin disconnected # We only need session_id for HTTP transport routing. diff --git a/Server/src/transport/unity_transport.py b/Server/src/transport/unity_transport.py index 683ee5e89..d55ab6fd6 100644 --- a/Server/src/transport/unity_transport.py +++ b/Server/src/transport/unity_transport.py @@ -11,8 +11,8 @@ from models.models import MCPResponse from models.unity_response import normalize_unity_response +logger = logging.getLogger(__name__) T = TypeVar("T") -logger = logging.getLogger("mcp-for-unity-server") def _is_http_transport() -> bool: diff --git a/Server/tests/test_core_infrastructure_characterization.py b/Server/tests/test_core_infrastructure_characterization.py index 83c3f6539..4e869989b 100644 --- a/Server/tests/test_core_infrastructure_characterization.py +++ b/Server/tests/test_core_infrastructure_characterization.py @@ -628,7 +628,8 @@ async def slow_async_tool(): assert result == "done" assert mock_record.called duration_ms = mock_record.call_args[0][2] - assert duration_ms >= 50 + # Allow 20% variance for timer resolution (especially on Windows) + assert duration_ms >= 40 def test_telemetry_duration_recorded_even_on_error(self): """Verify duration is recorded even when tool raises exception.""" @@ -1270,7 +1271,8 @@ def test_telemetry_multiple_disable_env_vars(self): disable_vars = ["DISABLE_TELEMETRY", "UNITY_MCP_DISABLE_TELEMETRY", "MCP_DISABLE_TELEMETRY"] for var_name in disable_vars: - with patch.dict(os.environ, {var_name: "true"}, clear=True): + # Don't use clear=True as it removes HOME/USERPROFILE which breaks Path.home() on Windows + with patch.dict(os.environ, {var_name: "true"}): with patch("core.telemetry.import_module", side_effect=Exception("No module")): config = TelemetryConfig() assert config.enabled is False, f"{var_name} did not disable telemetry" diff --git a/TestProjects/UnityMCPTests/Assets/Tests/EditMode/Services/Server/ServerCommandBuilderTests.cs b/TestProjects/UnityMCPTests/Assets/Tests/EditMode/Services/Server/ServerCommandBuilderTests.cs index 49f88958e..624a98e4f 100644 --- a/TestProjects/UnityMCPTests/Assets/Tests/EditMode/Services/Server/ServerCommandBuilderTests.cs +++ b/TestProjects/UnityMCPTests/Assets/Tests/EditMode/Services/Server/ServerCommandBuilderTests.cs @@ -110,6 +110,13 @@ public void QuoteIfNeeded_AlreadyQuoted_AddsMoreQuotes() [Test] public void BuildUvPathFromUvx_ValidPath_ConvertsCorrectly() { + // This test uses Unix-style paths which only work correctly on non-Windows + if (UnityEngine.Application.platform == UnityEngine.RuntimePlatform.WindowsEditor) + { + Assert.Pass("Skipped on Windows - use BuildUvPathFromUvx_WindowsPath_ConvertsCorrectly instead"); + return; + } + // Arrange string uvxPath = "/usr/local/bin/uvx"; diff --git a/TestProjects/UnityMCPTests/Assets/Tests/EditMode/Tools/PropertyConversionErrorHandlingTests.cs b/TestProjects/UnityMCPTests/Assets/Tests/EditMode/Tools/PropertyConversionErrorHandlingTests.cs new file mode 100644 index 000000000..a093c43cf --- /dev/null +++ b/TestProjects/UnityMCPTests/Assets/Tests/EditMode/Tools/PropertyConversionErrorHandlingTests.cs @@ -0,0 +1,328 @@ +using System; +using System.Text.RegularExpressions; +using NUnit.Framework; +using UnityEngine; +using UnityEngine.TestTools; +using Newtonsoft.Json.Linq; +using MCPForUnity.Editor.Tools; +using MCPForUnity.Editor.Helpers; + +namespace MCPForUnityTests.Editor.Tools +{ + /// + /// Tests to reproduce issue #654: PropertyConversion crash causing dispatcher unavailability + /// while telemetry continues reporting success. + /// + public class PropertyConversionErrorHandlingTests + { + private GameObject testGameObject; + + [SetUp] + public void SetUp() + { + testGameObject = new GameObject("PropertyConversionTestObject"); + CommandRegistry.Initialize(); + } + + [TearDown] + public void TearDown() + { + if (testGameObject != null) + { + UnityEngine.Object.DestroyImmediate(testGameObject); + } + } + + /// + /// Test case 1: Integer value for object reference property (AudioClip on AudioSource) + /// Should return graceful error, not crash dispatcher + /// + [Test] + public void ManageComponents_SetProperty_IntegerForObjectReference_ReturnsGracefulError() + { + // Add AudioSource component + var audioSource = testGameObject.AddComponent(); + + // Try to set AudioClip (object reference) to integer 12345 + var setPropertyParams = new JObject + { + ["action"] = "set_property", + ["target"] = testGameObject.name, + ["componentType"] = "AudioSource", + ["property"] = "clip", + ["value"] = 12345 // INCOMPATIBLE: int for AudioClip + }; + + var result = ManageComponents.HandleCommand(setPropertyParams); + + // Main test: should return a result without crashing + Assert.IsNotNull(result, "Should return a result, not crash dispatcher"); + + // If it's an ErrorResponse, verify it properly reports failure + if (result is ErrorResponse errorResp) + { + Assert.IsFalse(errorResp.Success, "Should report failure for incompatible type"); + } + } + + /// + /// Test case 2: Array format for float property (spatialBlend expects float, not array) + /// Mirrors the "Array format [0, 0] for Vector2 properties" from issue #654 + /// This test documents that the error is caught and doesn't crash the dispatcher + /// + [Test] + public void ManageComponents_SetProperty_ArrayForFloatProperty_DoesNotCrashDispatcher() + { + // Expect the error log that will be generated + LogAssert.Expect(LogType.Error, new Regex("Error converting token to System.Single")); + + // Add AudioSource component + var audioSource = testGameObject.AddComponent(); + + // Try to set spatialBlend (float) to array [0, 0] + // This triggers: "Error converting token to System.Single: Error reading double. Unexpected token: StartArray" + var setPropertyParams = new JObject + { + ["action"] = "set_property", + ["target"] = testGameObject.name, + ["componentType"] = "AudioSource", + ["property"] = "spatialBlend", + ["value"] = JArray.Parse("[0, 0]") // INCOMPATIBLE: array for float + }; + + var result = ManageComponents.HandleCommand(setPropertyParams); + + // Main test: dispatcher should remain responsive and return a result + Assert.IsNotNull(result, "Should return a result, not crash dispatcher"); + + // Verify subsequent commands still work + var followupParams = new JObject + { + ["action"] = "set_property", + ["target"] = testGameObject.name, + ["componentType"] = "AudioSource", + ["property"] = "volume", + ["value"] = 0.5f + }; + + var followupResult = ManageComponents.HandleCommand(followupParams); + Assert.IsNotNull(followupResult, "Dispatcher should still be responsive after conversion error"); + } + + /// + /// Test case 3: Multiple property conversion failures in sequence + /// Tests if dispatcher remains responsive after multiple errors + /// + [Test] + public void ManageComponents_MultipleSetPropertyFailures_DispatcherStaysResponsive() + { + // Expect the error log for the invalid string conversion + LogAssert.Expect(LogType.Error, new Regex("Error converting token to System.Single")); + + var audioSource = testGameObject.AddComponent(); + + // First bad conversion attempt - int for AudioClip doesn't generate an error log + var badParam1 = new JObject + { + ["action"] = "set_property", + ["target"] = testGameObject.name, + ["componentType"] = "AudioSource", + ["property"] = "clip", + ["value"] = 999 // bad: int for AudioClip + }; + + var result1 = ManageComponents.HandleCommand(badParam1); + Assert.IsNotNull(result1, "First call should return result"); + + // Second bad conversion attempt - generates error log + var badParam2 = new JObject + { + ["action"] = "set_property", + ["target"] = testGameObject.name, + ["componentType"] = "AudioSource", + ["property"] = "rolloffFactor", + ["value"] = "invalid_string" // bad: string for float + }; + + var result2 = ManageComponents.HandleCommand(badParam2); + Assert.IsNotNull(result2, "Second call should return result"); + + // Third attempt - valid conversion + var badParam3 = new JObject + { + ["action"] = "set_property", + ["target"] = testGameObject.name, + ["componentType"] = "AudioSource", + ["property"] = "volume", + ["value"] = 0.5f // good: float for float - dispatcher should still work + }; + + var result3 = ManageComponents.HandleCommand(badParam3); + Assert.IsNotNull(result3, "Third call should return result (dispatcher should still be responsive)"); + } + + /// + /// Test case 4: After property conversion failures, other commands still work + /// Tests dispatcher responsiveness + /// + [Test] + public void ManageComponents_AfterConversionFailure_OtherOperationsWork() + { + var audioSource = testGameObject.AddComponent(); + + // Trigger a conversion failure + var failParam = new JObject + { + ["action"] = "set_property", + ["target"] = testGameObject.name, + ["componentType"] = "AudioSource", + ["property"] = "clip", + ["value"] = 12345 // bad + }; + + var failResult = ManageComponents.HandleCommand(failParam); + Assert.IsNotNull(failResult, "Should return result for failed conversion"); + + // Now try a valid operation on the same component + var validParam = new JObject + { + ["action"] = "set_property", + ["target"] = testGameObject.name, + ["componentType"] = "AudioSource", + ["property"] = "volume", + ["value"] = 0.5f // valid: float for float + }; + + var validResult = ManageComponents.HandleCommand(validParam); + Assert.IsNotNull(validResult, "Should still be able to execute valid commands after conversion failure"); + + // Verify the property was actually set + Assert.AreEqual(0.5f, audioSource.volume, "Volume should have been set to 0.5"); + } + + /// + /// Test case 5: Telemetry continues reporting success even after conversion errors + /// This is the core of issue #654: telemetry should accurately reflect dispatcher health + /// + [Test] + public void ManageEditor_TelemetryStatus_ReportsAccurateHealth() + { + // Trigger multiple conversion failures first + var audioSource = testGameObject.AddComponent(); + + for (int i = 0; i < 3; i++) + { + var badParam = new JObject + { + ["action"] = "set_property", + ["target"] = testGameObject.name, + ["componentType"] = "AudioSource", + ["property"] = "clip", + ["value"] = i * 1000 // bad + }; + ManageComponents.HandleCommand(badParam); + } + + // Now check telemetry + var telemetryParams = new JObject { ["action"] = "telemetry_status" }; + var telemetryResult = ManageEditor.HandleCommand(telemetryParams); + + Assert.IsNotNull(telemetryResult, "Telemetry should return result"); + + // NOTE: Issue #654 noted that telemetry returns success even when dispatcher is dead. + // If telemetry returns success, that's the actual current behavior (which may be a problem). + // This test just documents what happens. + } + + /// + /// Test case 6: Direct PropertyConversion error handling + /// Tests if PropertyConversion.ConvertToType properly handles exceptions + /// + [Test] + public void PropertyConversion_ConvertToType_HandlesIncompatibleTypes() + { + // Try to convert integer to AudioClip type + var token = JToken.FromObject(12345); + + // PropertyConversion.ConvertToType should either: + // 1. Return a valid converted value + // 2. Throw an exception that can be caught + // 3. Return null + + Exception thrownException = null; + object result = null; + + try + { + result = PropertyConversion.ConvertToType(token, typeof(AudioClip)); + } + catch (Exception ex) + { + thrownException = ex; + } + + // Document what actually happens + if (thrownException != null) + { + Debug.Log($"PropertyConversion threw exception: {thrownException.GetType().Name}: {thrownException.Message}"); + Assert.Pass($"PropertyConversion threw {thrownException.GetType().Name} - exception is being raised, not swallowed"); + } + else if (result == null) + { + Debug.Log("PropertyConversion returned null for incompatible type"); + Assert.Pass("PropertyConversion returned null for incompatible type"); + } + else + { + Debug.Log($"PropertyConversion returned unexpected result: {result}"); + Assert.Pass("PropertyConversion produced some result"); + } + } + + /// + /// Test case 7: TryConvertToType should never throw + /// + [Test] + public void PropertyConversion_TryConvertToType_NeverThrows() + { + var token = JToken.FromObject(12345); + + // This should never throw, only return null + object result = null; + Exception thrownException = null; + + try + { + result = PropertyConversion.TryConvertToType(token, typeof(AudioClip)); + } + catch (Exception ex) + { + thrownException = ex; + } + + Assert.IsNull(thrownException, "TryConvertToType should never throw"); + // Result can be null or a value, but shouldn't throw + } + + /// + /// Test case 8: ComponentOps error handling + /// Tests if ComponentOps.SetProperty properly catches exceptions + /// + [Test] + public void ComponentOps_SetProperty_HandlesConversionErrors() + { + var audioSource = testGameObject.AddComponent(); + var token = JToken.FromObject(12345); + + // Try to set clip (AudioClip) to integer value + bool success = ComponentOps.SetProperty(audioSource, "clip", token, out string error); + + Assert.IsFalse(success, "Should fail to set incompatible type"); + Assert.IsNotEmpty(error, "Should provide error message"); + + // Verify the object is still in a valid state + Assert.IsNotNull(audioSource, "AudioSource should still exist"); + Assert.IsNull(audioSource.clip, "Clip should remain null (not corrupted)"); + } + } +} diff --git a/TestProjects/UnityMCPTests/Assets/Tests/EditMode/Tools/PropertyConversionErrorHandlingTests.cs.meta b/TestProjects/UnityMCPTests/Assets/Tests/EditMode/Tools/PropertyConversionErrorHandlingTests.cs.meta new file mode 100644 index 000000000..52b73bba5 --- /dev/null +++ b/TestProjects/UnityMCPTests/Assets/Tests/EditMode/Tools/PropertyConversionErrorHandlingTests.cs.meta @@ -0,0 +1,11 @@ +fileFormatVersion: 2 +guid: 815e2cf338526014d93708b9070b7fc5 +MonoImporter: + externalObjects: {} + serializedVersion: 2 + defaultReferences: [] + executionOrder: 0 + icon: {instanceID: 0} + userData: + assetBundleName: + assetBundleVariant: diff --git a/TestProjects/UnityMCPTests/Assets/Tests/EditMode/Tools/PropertyConversion_ArrayForFloat_Test.cs b/TestProjects/UnityMCPTests/Assets/Tests/EditMode/Tools/PropertyConversion_ArrayForFloat_Test.cs new file mode 100644 index 000000000..7de1e1599 --- /dev/null +++ b/TestProjects/UnityMCPTests/Assets/Tests/EditMode/Tools/PropertyConversion_ArrayForFloat_Test.cs @@ -0,0 +1,58 @@ +using System; +using System.Text.RegularExpressions; +using NUnit.Framework; +using UnityEngine; +using UnityEngine.TestTools; +using Newtonsoft.Json.Linq; +using MCPForUnity.Editor.Tools; +using MCPForUnity.Editor.Helpers; + +namespace MCPForUnityTests.Editor.Tools +{ + /// + /// ISOLATED TEST: Array format [0, 0] for float property + /// Issue #654 - Test 2 of 8 + /// This is the test that triggers "Error converting token to System.Single" + /// + public class PropertyConversion_ArrayForFloat_Test + { + private GameObject testGameObject; + + [SetUp] + public void SetUp() + { + testGameObject = new GameObject("PropertyConversion_ArrayForFloat_Test"); + } + + [TearDown] + public void TearDown() + { + if (testGameObject != null) + { + UnityEngine.Object.DestroyImmediate(testGameObject); + } + } + + [Test] + public void SetProperty_ArrayForFloat_ReturnsError() + { + // Expect the error log that will be generated + LogAssert.Expect(LogType.Error, new Regex("Error converting token to System.Single")); + + var audioSource = testGameObject.AddComponent(); + + // This is the exact error from issue #654 + var setPropertyParams = new JObject + { + ["action"] = "set_property", + ["target"] = testGameObject.name, + ["componentType"] = "AudioSource", + ["property"] = "spatialBlend", + ["value"] = JArray.Parse("[0, 0]") // Array for float = error + }; + + var result = ManageComponents.HandleCommand(setPropertyParams); + Assert.IsNotNull(result, "Should return a result"); + } + } +} diff --git a/TestProjects/UnityMCPTests/Assets/Tests/EditMode/Tools/PropertyConversion_ArrayForFloat_Test.cs.meta b/TestProjects/UnityMCPTests/Assets/Tests/EditMode/Tools/PropertyConversion_ArrayForFloat_Test.cs.meta new file mode 100644 index 000000000..40b090f4d --- /dev/null +++ b/TestProjects/UnityMCPTests/Assets/Tests/EditMode/Tools/PropertyConversion_ArrayForFloat_Test.cs.meta @@ -0,0 +1,11 @@ +fileFormatVersion: 2 +guid: c4b99eb57f53db948bd5e8a0a08dfec8 +MonoImporter: + externalObjects: {} + serializedVersion: 2 + defaultReferences: [] + executionOrder: 0 + icon: {instanceID: 0} + userData: + assetBundleName: + assetBundleVariant: