From b0d2a39a5bcb10cd9aa519d5dbfc1cd173df61cb Mon Sep 17 00:00:00 2001 From: hatayama Date: Wed, 7 Oct 2026 00:28:29 +0900 Subject: [PATCH 1/5] Add failing tests for a dispatched failure hidden behind an earlier busy answer After a busy answer, the retry that reached Unity can still end in a dropped connection or a timeout. Today the retry loop reports the earlier busy answer instead, so compile never asks Unity for its status even though the compile is running. These tests pin the attempt's own error and outcome, keep the busy answer for an attempt that never reached Unity, and keep a caller's cancellation winning in both cases. --- .../connection_retry_flow_test.go | 55 +++++- .../projectrunner/connection_retry_test.go | 183 ++++++++++++++++++ 2 files changed, 234 insertions(+), 4 deletions(-) diff --git a/cli/project-runner/internal/projectrunner/connection_retry_flow_test.go b/cli/project-runner/internal/projectrunner/connection_retry_flow_test.go index 9f7b7fa13e..3ee9242f58 100644 --- a/cli/project-runner/internal/projectrunner/connection_retry_flow_test.go +++ b/cli/project-runner/internal/projectrunner/connection_retry_flow_test.go @@ -6,6 +6,7 @@ import ( "io" "os" "path/filepath" + "reflect" "strings" "testing" "time" @@ -211,11 +212,11 @@ func TestFinishBusyRetryStopsWithTheRightError(t *testing.T) { } } -// Verifies a transport error right after a busy answer reports the busy answer, unless the caller -// cancelled, in which case the cancellation wins. -func TestFinishNonRetryableConnectionAttemptPrefersBusyOverTransportError(t *testing.T) { +// Verifies a transport error from an attempt that never reached Unity reports the earlier busy +// answer, unless the caller cancelled, in which case the cancellation wins. +func TestFinishNonRetryableConnectionAttemptPrefersBusyOverAnUndispatchedTransportError(t *testing.T) { busy := serverBusyRPCError(t) - current := sendAttempt{outcome: unityipc.UnitySendOutcome{RequestDispatched: true}, err: io.ErrUnexpectedEOF} + current := sendAttempt{err: io.ErrUnexpectedEOF} last := sendAttempt{err: busy} _, err := finishNonRetryableConnectionAttempt(context.Background(), current, last, 0, nil) @@ -229,6 +230,52 @@ func TestFinishNonRetryableConnectionAttemptPrefersBusyOverTransportError(t *tes } } +// Verifies a dropped connection or a timeout from an attempt that reached Unity after a busy answer +// comes back as that attempt's own error and outcome, so the caller can recover from what really +// happened, and that a caller's cancellation still wins over it. +func TestFinishNonRetryableConnectionAttemptKeepsADispatchedFailureAfterBusy(t *testing.T) { + busy := serverBusyRPCError(t) + last := sendAttempt{outcome: unityipc.UnitySendOutcome{RequestDispatched: true, RequestAccepted: true}, err: busy} + cases := []struct { + name string + current sendAttempt + }{ + { + name: "dropped after the accept", + current: sendAttempt{outcome: unityipc.UnitySendOutcome{RequestDispatched: true, RequestAccepted: true}, err: io.ErrUnexpectedEOF}, + }, + { + name: "dropped before the accept", + current: sendAttempt{outcome: unityipc.UnitySendOutcome{RequestDispatched: true}, err: io.EOF}, + }, + { + name: "final response timed out after the accept", + current: sendAttempt{outcome: unityipc.UnitySendOutcome{RequestDispatched: true, RequestAccepted: true}, err: os.ErrDeadlineExceeded}, + }, + } + for _, testCase := range cases { + t.Run(testCase.name, func(t *testing.T) { + t.Run("reports the dispatched failure", func(t *testing.T) { + // A positive response timeout keeps the accepted timeout out of the focus handling, + // which needs a focus controller this test does not build. + outcome, err := finishNonRetryableConnectionAttempt(context.Background(), testCase.current, last, time.Second, nil) + if !errors.Is(err, testCase.current.err) || isUnityServerBusyRPCError(err) { + t.Fatalf("err = %v, want the dispatched attempt's own error %v", err, testCase.current.err) + } + if !reflect.DeepEqual(outcome, testCase.current.outcome) { + t.Fatalf("outcome = %+v, want the dispatched attempt's outcome %+v", outcome, testCase.current.outcome) + } + }) + t.Run("reports the cancellation", func(t *testing.T) { + _, err := finishNonRetryableConnectionAttempt(cancelledContext(), testCase.current, last, time.Second, nil) + if !errors.Is(err, context.Canceled) { + t.Fatalf("err = %v, want context.Canceled", err) + } + }) + }) + } +} + // Verifies the unity-alive retry reports the caller's cancellation when its retry context ends // because the caller cancelled, and Unity-not-responding otherwise. func TestFinishUnityAliveRetryWaitWhenRetryContextEnds(t *testing.T) { diff --git a/cli/project-runner/internal/projectrunner/connection_retry_test.go b/cli/project-runner/internal/projectrunner/connection_retry_test.go index 93defc4123..e84f4d343e 100644 --- a/cli/project-runner/internal/projectrunner/connection_retry_test.go +++ b/cli/project-runner/internal/projectrunner/connection_retry_test.go @@ -1469,3 +1469,186 @@ func TestSendWithTransientConnectionRetrySurfacesDispatchedFailureAfterBusy(t *t t.Fatalf("dispatched failure must surface as the original RPC error, got: %v", err) } } + +// busyFirstServerConnection starts a TCP stand-in for Unity that answers the first connection with +// a busy error and hands every later connection, once its request has been read, to +// handleDispatched. The returned connection points at the stand-in. +func busyFirstServerConnection(t *testing.T, handleDispatched func(conn net.Conn)) unityipc.Connection { + t.Helper() + listener, err := net.Listen("tcp", "127.0.0.1:0") + if err != nil { + t.Fatalf("failed to listen: %v", err) + } + t.Cleanup(func() { + _ = listener.Close() + }) + + busy := `{"jsonrpc":"2.0","id":1,"error":{"code":-32603,"message":"Unity is busy running 'execute-dynamic-code'.","data":{"type":"server_busy","runningToolName":"execute-dynamic-code","requestedToolName":"compile","message":"busy"}}}` + go func() { + first := true + for { + conn, acceptErr := listener.Accept() + if acceptErr != nil { + return + } + sendBusy := first + first = false + go func(conn net.Conn, sendBusy bool) { + defer func() { + _ = conn.Close() + }() + if _, readErr := unityipc.Read(bufio.NewReader(conn)); readErr != nil { + return + } + if sendBusy { + _ = unityipc.Write(conn, []byte(busy)) + return + } + handleDispatched(conn) + }(conn, sendBusy) + } + }() + + return unityipc.Connection{ + Endpoint: unityipc.Endpoint{ + Network: "tcp", + Address: listener.Addr().String(), + }, + ProjectRoot: t.TempDir(), + } +} + +// Verifies a connection that drops after Unity accepted the retried request comes back as that +// disconnect, not as the busy answer from the attempt before it, so compile can go on to ask Unity +// for its compile status. +func TestSendWithTransientConnectionRetrySurfacesADroppedConnectionAfterBusy(t *testing.T) { + if runtime.GOOS == "windows" { + t.Skip("TCP endpoint injection is only used by this non-Windows client test") + } + + deps := defaultConnectionRetryDeps() + deps.retryTimeout = 150 * time.Millisecond + deps.retryPoll = 5 * time.Millisecond + deps.findRunningUnityProcess = func(context.Context, string) (*clicore.UnityProcess, error) { + return nil, nil + } + connection := busyFirstServerConnection(t, func(conn net.Conn) { + accepted := `{"jsonrpc":"2.0","result":{"accepted":true},"uloop":{"phase":"accepted"},"id":1}` + _ = unityipc.Write(conn, []byte(accepted)) + }) + + outcome, err := sendWithTransientConnectionRetryWithDeps( + context.Background(), + connection, + "compile", + map[string]any{}, + nil, + 0, + deps) + if err == nil { + t.Fatal("expected the dropped connection to surface") + } + if isUnityServerBusyRPCError(err) { + t.Fatalf("a request that reached Unity must not be reported as the earlier busy answer, got: %v", err) + } + if !clierrors.IsTransportDisconnectError(err) { + t.Fatalf("err = %v, want a transport disconnect", err) + } + if !outcome.RequestDispatched || !outcome.RequestAccepted { + t.Fatalf("outcome = %+v, want a dispatched and accepted request", outcome) + } + if !shouldWaitForCompileStatus(err, outcome) { + t.Fatalf("compile must be able to wait for its status after err = %v, outcome = %+v", err, outcome) + } +} + +// Verifies a final response wait that times out after Unity accepted the retried request, which is +// how a compile longer than its response timeout ends, comes back as that timeout and not as the +// busy answer from the attempt before it, so compile can go on to ask Unity for its compile status. +func TestSendWithTransientConnectionRetrySurfacesAFinalResponseTimeoutAfterBusy(t *testing.T) { + if runtime.GOOS == "windows" { + t.Skip("TCP endpoint injection is only used by this non-Windows client test") + } + + deps := defaultConnectionRetryDeps() + deps.retryTimeout = 150 * time.Millisecond + deps.retryPoll = 5 * time.Millisecond + deps.findRunningUnityProcess = func(context.Context, string) (*clicore.UnityProcess, error) { + return nil, nil + } + connection := busyFirstServerConnection(t, func(conn net.Conn) { + accepted := `{"jsonrpc":"2.0","result":{"accepted":true},"uloop":{"phase":"accepted"},"id":1}` + if writeErr := unityipc.Write(conn, []byte(accepted)); writeErr != nil { + return + } + // Staying silent past the response timeout makes the client's own deadline end the wait, + // rather than the close that follows. + time.Sleep(200 * time.Millisecond) + }) + + outcome, err := sendWithTransientConnectionRetryWithDeps( + context.Background(), + connection, + "compile", + map[string]any{}, + nil, + 50*time.Millisecond, + deps) + if err == nil { + t.Fatal("expected the final response timeout to surface") + } + if isUnityServerBusyRPCError(err) { + t.Fatalf("a request that reached Unity must not be reported as the earlier busy answer, got: %v", err) + } + if !clierrors.IsFinalResponseTimeoutError(err) { + t.Fatalf("err = %v, want a final response timeout", err) + } + if !outcome.RequestAccepted { + t.Fatalf("outcome = %+v, want an accepted request", outcome) + } + if !shouldWaitForCompileStatus(err, outcome) { + t.Fatalf("compile must be able to wait for its status after err = %v, outcome = %+v", err, outcome) + } +} + +// Verifies a retried request that Unity read but never acknowledged times out as an unanswered +// request, not as the busy answer from the attempt before it. +func TestSendWithTransientConnectionRetrySurfacesAnUnansweredRequestAfterBusy(t *testing.T) { + if runtime.GOOS == "windows" { + t.Skip("TCP endpoint injection is only used by this non-Windows client test") + } + + deps := defaultConnectionRetryDeps() + retryWindow := 150 * time.Millisecond + deps.retryTimeout = retryWindow + deps.retryPoll = 5 * time.Millisecond + deps.findRunningUnityProcess = func(context.Context, string) (*clicore.UnityProcess, error) { + return nil, nil + } + connection := busyFirstServerConnection(t, func(net.Conn) { + // Twice the window keeps the request unacknowledged until the attempt's own accept + // deadline has ended it. + time.Sleep(retryWindow * 2) + }) + + outcome, err := sendWithTransientConnectionRetryWithDeps( + context.Background(), + connection, + "compile", + map[string]any{}, + nil, + 0, + deps) + if err == nil { + t.Fatal("expected the unanswered request to surface") + } + if isUnityServerBusyRPCError(err) { + t.Fatalf("a request that reached Unity must not be reported as the earlier busy answer, got: %v", err) + } + if !clierrors.IsFinalResponseTimeoutError(err) { + t.Fatalf("err = %v, want a response timeout", err) + } + if !outcome.RequestDispatched || outcome.RequestAccepted { + t.Fatalf("outcome = %+v, want a dispatched request that was never accepted", outcome) + } +} From 2454ad787a0bb9bc67803fdbc4eab973fc81f493 Mon Sep 17 00:00:00 2001 From: hatayama Date: Wed, 7 Oct 2026 00:29:14 +0900 Subject: [PATCH 2/5] Report a dispatched failure after a busy answer instead of the busy answer A busy answer means Unity ran nothing, so it was a fair diagnosis for any later transport error back when the retry window and the connection deadline ended together. Each attempt now has its own deadline, and a retry that reached Unity may already be running: replacing its dropped connection or timeout with the busy answer stopped compile from asking Unity for its status and reported a running command as not executed. The busy answer now wins only over an attempt that never reached Unity, and a caller's cancellation still wins over both. --- .../projectrunner/connection_retry_flow.go | 17 ++++++++++------- 1 file changed, 10 insertions(+), 7 deletions(-) diff --git a/cli/project-runner/internal/projectrunner/connection_retry_flow.go b/cli/project-runner/internal/projectrunner/connection_retry_flow.go index cfdeb61dcb..856512656f 100644 --- a/cli/project-runner/internal/projectrunner/connection_retry_flow.go +++ b/cli/project-runner/internal/projectrunner/connection_retry_flow.go @@ -70,17 +70,20 @@ func finishNonRetryableConnectionAttempt( responseTimeout time.Duration, focusController *connectionRetryFocusController, ) (unityipc.UnitySendOutcome, error) { - // A transport error after a busy response in this window must not mask the - // busy; the server answered moments ago, so busy is the truer diagnosis. - // An RPC error is a real Unity answer, not a transport artifact, and must - // surface as-is. The transport error is not compared against the window - // deadline because the connection deadline can fire microseconds before - // the context reports expiry. + // A busy answer earlier in this window wins only over an attempt whose request never reached + // Unity, such as a failed connect or write: nothing ran, so busy is the truer diagnosis. A + // request that reached Unity may already be running, so that attempt's own error and outcome + // take the same path as a first attempt's, and the caller recovers from them (compile, for + // one, asks Unity for its compile status). An RPC error is a real Unity answer, not a + // transport artifact, and must surface as-is. if currentAttempt.err != nil && !isRPCError(currentAttempt.err) && isUnityServerBusyRPCError(lastAttempt.err) { + // A caller that cancelled gets the cancellation back, whichever attempt failed. if ctx.Err() != nil { return currentAttempt.outcome, ctx.Err() } - return lastAttempt.outcome, lastAttempt.err + if !currentAttempt.outcome.RequestDispatched { + return lastAttempt.outcome, lastAttempt.err + } } if reason, ok := connectionRetryFocusReasonForError(currentAttempt.err, currentAttempt.outcome, responseTimeout); ok { focusController.tryFocus(ctx, reason, currentAttempt.err) From a0d86d89c1dbe0ad771eb82791f25da6eef005ec Mon Sep 17 00:00:00 2001 From: hatayama Date: Wed, 7 Oct 2026 01:06:27 +0900 Subject: [PATCH 3/5] Keep the fake Unity silent until the client hangs up in the busy retry tests The final response timeout and unanswered request tests let the stand-in close the connection 150 ms after the client's deadline. On a slow runner the client can fall that far behind, and the close then arrives first as a disconnect. Reading until the client hangs up makes the client's own deadline the only thing that can end the wait. --- .../projectrunner/connection_retry_test.go | 18 +++++++++--------- 1 file changed, 9 insertions(+), 9 deletions(-) diff --git a/cli/project-runner/internal/projectrunner/connection_retry_test.go b/cli/project-runner/internal/projectrunner/connection_retry_test.go index e84f4d343e..fa120a499d 100644 --- a/cli/project-runner/internal/projectrunner/connection_retry_test.go +++ b/cli/project-runner/internal/projectrunner/connection_retry_test.go @@ -6,6 +6,7 @@ import ( "encoding/json" "errors" "fmt" + "io" "net" "os" "path/filepath" @@ -1581,9 +1582,9 @@ func TestSendWithTransientConnectionRetrySurfacesAFinalResponseTimeoutAfterBusy( if writeErr := unityipc.Write(conn, []byte(accepted)); writeErr != nil { return } - // Staying silent past the response timeout makes the client's own deadline end the wait, - // rather than the close that follows. - time.Sleep(200 * time.Millisecond) + // Staying silent until the client hangs up means the client's own deadline is always what + // ends the wait, never a close from this side. + _, _ = io.Copy(io.Discard, conn) }) outcome, err := sendWithTransientConnectionRetryWithDeps( @@ -1619,16 +1620,15 @@ func TestSendWithTransientConnectionRetrySurfacesAnUnansweredRequestAfterBusy(t } deps := defaultConnectionRetryDeps() - retryWindow := 150 * time.Millisecond - deps.retryTimeout = retryWindow + deps.retryTimeout = 150 * time.Millisecond deps.retryPoll = 5 * time.Millisecond deps.findRunningUnityProcess = func(context.Context, string) (*clicore.UnityProcess, error) { return nil, nil } - connection := busyFirstServerConnection(t, func(net.Conn) { - // Twice the window keeps the request unacknowledged until the attempt's own accept - // deadline has ended it. - time.Sleep(retryWindow * 2) + connection := busyFirstServerConnection(t, func(conn net.Conn) { + // Staying silent until the client hangs up means the client's own accept deadline is always + // what ends the wait, never a close from this side. + _, _ = io.Copy(io.Discard, conn) }) outcome, err := sendWithTransientConnectionRetryWithDeps( From c1d1256b0442797b2bacfdd9608869cf86950df9 Mon Sep 17 00:00:00 2001 From: hatayama Date: Wed, 7 Oct 2026 01:06:28 +0900 Subject: [PATCH 4/5] Pin an editor-unresponsive error after a busy answer An accepted request can also end with the heartbeat reporting a stalled main thread. That error is not an RPC answer either, so it used to be replaced by the earlier busy answer too. The new test pins its own error and outcome and the main-thread-stall focus handling a first attempt gets. The busy attempt in these tests now carries a distinct timing, so returning its outcome instead of the current one fails in every case. --- .../connection_retry_flow_test.go | 48 ++++++++++++++++++- 1 file changed, 47 insertions(+), 1 deletion(-) diff --git a/cli/project-runner/internal/projectrunner/connection_retry_flow_test.go b/cli/project-runner/internal/projectrunner/connection_retry_flow_test.go index 3ee9242f58..03eb818520 100644 --- a/cli/project-runner/internal/projectrunner/connection_retry_flow_test.go +++ b/cli/project-runner/internal/projectrunner/connection_retry_flow_test.go @@ -235,7 +235,7 @@ func TestFinishNonRetryableConnectionAttemptPrefersBusyOverAnUndispatchedTranspo // happened, and that a caller's cancellation still wins over it. func TestFinishNonRetryableConnectionAttemptKeepsADispatchedFailureAfterBusy(t *testing.T) { busy := serverBusyRPCError(t) - last := sendAttempt{outcome: unityipc.UnitySendOutcome{RequestDispatched: true, RequestAccepted: true}, err: busy} + last := busyAttemptAfterAccept(busy) cases := []struct { name string current sendAttempt @@ -276,6 +276,52 @@ func TestFinishNonRetryableConnectionAttemptKeepsADispatchedFailureAfterBusy(t * } } +// busyAttemptAfterAccept returns a busy answer to an accepted request. Its distinct timing tells its +// outcome apart from a current attempt whose flags are the same, so a test can see which outcome +// came back. +func busyAttemptAfterAccept(busy error) sendAttempt { + return sendAttempt{ + outcome: unityipc.UnitySendOutcome{ + RequestDispatched: true, + RequestAccepted: true, + Timing: unityipc.UnitySendTiming{Total: time.Millisecond}, + }, + err: busy, + } +} + +// Verifies an editor-unresponsive error from an attempt that Unity accepted after a busy answer comes +// back as that attempt's own error and outcome, and goes through the main-thread-stall focus handling +// a first attempt would get, instead of being reported as the busy answer. +func TestFinishNonRetryableConnectionAttemptKeepsAnEditorUnresponsiveErrorAfterBusy(t *testing.T) { + busy := serverBusyRPCError(t) + last := busyAttemptAfterAccept(busy) + current := sendAttempt{ + outcome: unityipc.UnitySendOutcome{RequestDispatched: true, RequestAccepted: true}, + err: &unityipc.EditorUnresponsiveError{StallSeconds: 30}, + } + processLookups := 0 + deps := defaultConnectionRetryDeps() + deps.findRunningUnityProcess = func(context.Context, string) (*clicore.UnityProcess, error) { + processLookups++ + return nil, nil + } + // This error enters the focus handling whatever the response timeout is, so it needs a real focus + // controller. Finding no Unity process keeps the focus itself from running. + focusController := newConnectionRetryFocusController(unityipc.Connection{ProjectRoot: t.TempDir()}, "get-logs", deps) + + outcome, err := finishNonRetryableConnectionAttempt(context.Background(), current, last, 0, focusController) + if !errors.Is(err, current.err) || isUnityServerBusyRPCError(err) { + t.Errorf("err = %v, want the accepted attempt's own error %v", err, current.err) + } + if !reflect.DeepEqual(outcome, current.outcome) { + t.Errorf("outcome = %+v, want the accepted attempt's outcome %+v", outcome, current.outcome) + } + if processLookups != 1 { + t.Errorf("Unity process lookups = %d, want 1 from the main-thread-stall focus handling", processLookups) + } +} + // Verifies the unity-alive retry reports the caller's cancellation when its retry context ends // because the caller cancelled, and Unity-not-responding otherwise. func TestFinishUnityAliveRetryWaitWhenRetryContextEnds(t *testing.T) { From 38f86fa62ef191cbc2c987713afbcd2d17716662 Mon Sep 17 00:00:00 2001 From: hatayama Date: Wed, 7 Oct 2026 01:42:06 +0900 Subject: [PATCH 5/5] Pin any other error from an accepted attempt after a busy answer The rule keeps the error of an attempt that reached Unity whatever its kind, not only disconnects, timeouts, and the editor-unresponsive error. A final response that fails to decode, for one, reaches the same branch. A table case with a plain error pins that the rule does not depend on the kind of error, and that a cancelled caller still gets the cancellation. --- .../projectrunner/connection_retry_flow_test.go | 12 +++++++++--- 1 file changed, 9 insertions(+), 3 deletions(-) diff --git a/cli/project-runner/internal/projectrunner/connection_retry_flow_test.go b/cli/project-runner/internal/projectrunner/connection_retry_flow_test.go index 03eb818520..fa4e5aa890 100644 --- a/cli/project-runner/internal/projectrunner/connection_retry_flow_test.go +++ b/cli/project-runner/internal/projectrunner/connection_retry_flow_test.go @@ -230,9 +230,9 @@ func TestFinishNonRetryableConnectionAttemptPrefersBusyOverAnUndispatchedTranspo } } -// Verifies a dropped connection or a timeout from an attempt that reached Unity after a busy answer -// comes back as that attempt's own error and outcome, so the caller can recover from what really -// happened, and that a caller's cancellation still wins over it. +// Verifies a dropped connection, a timeout, or any other non-RPC error from an attempt that reached +// Unity after a busy answer comes back as that attempt's own error and outcome, so the caller can +// recover from what really happened, and that a caller's cancellation still wins over it. func TestFinishNonRetryableConnectionAttemptKeepsADispatchedFailureAfterBusy(t *testing.T) { busy := serverBusyRPCError(t) last := busyAttemptAfterAccept(busy) @@ -252,6 +252,12 @@ func TestFinishNonRetryableConnectionAttemptKeepsADispatchedFailureAfterBusy(t * name: "final response timed out after the accept", current: sendAttempt{outcome: unityipc.UnitySendOutcome{RequestDispatched: true, RequestAccepted: true}, err: os.ErrDeadlineExceeded}, }, + { + // Stands for an error that is neither a disconnect nor a timeout, such as a final response + // that fails to decode: the rule does not depend on the kind of error. + name: "failed another way after the accept", + current: sendAttempt{outcome: unityipc.UnitySendOutcome{RequestDispatched: true, RequestAccepted: true}, err: errors.New("final response could not be decoded")}, + }, } for _, testCase := range cases { t.Run(testCase.name, func(t *testing.T) {