Repository navigation
fix(tunnel): report an opentunnel that cannot connect as a failed command - #597
Jisung Chae (jisung-02) wants to merge 10 commits into
Conversation
There was a problem hiding this comment.
🟡 Changes recommended
Unresolved lifecycle and cancellation issues include potential command-worker starvation and reporting success after cancellation or closure.
2 open issues
What changed in this PR
This pull request makes opentunnel report connection and relay-start failures synchronously instead of returning premature success.
Changes:
- Split tunnel startup into synchronous
Openand asynchronousServephases. - Added context-aware dialing, handshake error reporting, lifecycle synchronization, and cleanup safeguards.
- Added tests covering failed opens, cancellation, relay failures, resource refusals, and stale tunnel cleanup.
| File | Description |
|---|---|
pkg/runner/ws_url_test.go |
Updates tunnel connection tests to pass a context. |
pkg/runner/tunnel_client.go |
Implements synchronous opening, cancellation, relay startup, synchronized lifecycle handling, and cleanup. |
pkg/runner/tunnel_client_test.go |
Tests successful and failed opens, cancellation, relay startup, serving, and tunnel replacement behavior. |
pkg/executor/handlers/tunnel/tunnel.go |
Opens tunnels before returning command results and injects resource checks. |
pkg/executor/handlers/tunnel/tunnel_test.go |
Tests refused connections, editor setup failures, and resource-limit refusals. |
Review effort: Lite
![alpacax-wall-d[bot]](https://avatars.githubusercontent.com/in/4826009?s=60&v=4){kind=small}
There was a problem hiding this comment.
WALL-D review: Approval withheld · head 21c807d
Code review result: Comments only (1 P1/P2) · head 21c807d
Review summary
- Found 1 P1/P2 defect.
A maintainer will review this PR.
Product review result: Nothing flagged · head 21c807d
Re-review requests and limits
WALL-D reviews a PR opened ready after this rule took effect once on its own. After that it reviews only on request: comment @alpacax-wall-d review or mark a draft ready for review, up to 5 times per PR including the first review. A re-review reads only the lines changed since the last review, and from the second re-review on only P1 findings block approval. Answering the product review's questions reviews only the product side again.
alpacax-wall-d
Bot
added
the
needs-author-fix
|
@alpacax-wall-d review |
alpacax-wall-d
Bot
removed
the
needs-author-fix
|
@alpacax-wall-d review |
|
A review is already queued. |
|
Reviewed 30584f9: #597 (review) |
Geunwoo Noh (geunwoonoh)
left a comment
Geunwoo Noh (geunwoonoh)
left a comment
There was a problem hiding this comment.
Summary
The design is solid and the tests cover the boundary cases well. I found nothing that should block the merge. The three earlier Copilot and WALL-D findings (command context cancellation, t.Error in the seam, the gap between unregistering and setting closed) are all addressed in the code and covered by tests.
Critical issues (0)
Warnings (1)
pkg/executor/handlers/tunnel/tunnel.go:166Performance: one open now holds a shared pool worker for up to about 35 seconds (30-second handshake plus 5-second daemon wait), where it used to hold it for close to zero. A burst of opens against a blackholed tunnel server can fill all 20 workers, delaying shell commands andclosetunnelby up to 35 seconds; once the 200-slot queue fills, commands are refused withjob queue is full. The Copilot thread already explains the upper bound and the reasoning holds, so this does not block the merge, but a follow-up issue for a semaphore on concurrent opens or a separate path for control commands is worth filing.
Suggestions (7)
pkg/runner/tunnel_client.go:169,tunnel_client_test.go:426-435An already closed tunnel can still dial.context.AfterFunc(tc.ctx, cancel)runscancelin its own goroutine even when the context is already done, so a localhost dial can finish and send the upgrade request first. The result is stillerrTunnelClosedWhileOpening, so there is no production impact, but the test name (DialsNothing...) states a contract the code does not guarantee, andassert.Empty(t, hits)reads a channel the server handler fills asynchronously, so it can miss a late hit. An early check inopen()makes the contract deterministic.pkg/runner/tunnel_client.go:206,:617isRegisteredduplicatesGetActiveTunnel, which had no production caller on main and only test callers after this PR. HaveisRegisteredreuse it, or merge the two.pkg/executor/handlers/tunnel/tunnel_test.go:317ThissetServerURLshares its name with the one inpkg/runnerbut takes*httptest.Serverinstead ofstring. The packages cannot share it, but matching the signature avoids confusion.pkg/runner/tunnel_client_test.go:419require.Erroralone passes on an unrelated error such as a refused URL. Narrow it to the two cases the comment names:errors.Is(err, context.DeadlineExceeded) || errors.Is(err, os.ErrDeadlineExceeded)(check first thatsanitizeURLErrorkeeps the wrapping).pkg/executor/handlers/tunnel/tunnel.go:167A user closing a tunnel right after opening it (errTunnelClosedWhileOpening) is logged withlog.Error. Picking that case out witherrors.Isand logging it at Info or Warn cuts alert noise.pkg/runner/tunnel_client.go:233mgr.cancel()reaches into another type's unexported field. Nothing has started yet, somgr.Stop()does the same thing (with a nil cmd it only cancels) and keeps teardown on one API.pkg/runner/tunnel_client.go:332Thectxparameter of theNetDialContextclosure shadows thectxofconnect(ctx), which is easy to confuse with the outerctx.Err()just below. A name likedctxreads more clearly.
Further notes
Go conventions: lowercase error strings, %w wrapping, a sentinel error, the Open/open split, require versus assert, and t.Context() all follow convention. The startRelay and checkResources seams match the existing demote and terminateFn pattern. Network-backed tests staying on the real clock matches the CLAUDE.md guidance.
Duplicate or unused code
GetActiveTunnel/isRegistered: see suggestion 2.- Wrapping in
handshakeError{StatusCode: resp.StatusCode, ...}appears here and atauth_backoff.go:108. Two sites do not justify a helper yet. - The
closedflag looks redundant withtc.ctx.Err()but is needed: whileClosestops code-server (the grace wait), the context is not canceled yet, and a sessionconnectinstalls in that window would missClose's snapshot and leak. Settingclosedunder the lock closes that window. - In
!unwatch() || dialCtx.Err() != nilthe first condition implies the second, butunwatch()must run for its side effect of removing the AfterFunc. Intended.
Performance
- Cost: warning 1. A successful reply also waits for the dial RTT, TLS, and the daemon start (up to 5 seconds on Unix), which is the point of the fix.
- Gains: a
closetunnelduring the handshake frees the socket and worker at once instead of after the 30-second timeout; a failed open no longer stays registered or deletes a newer tunnel with the same ID; the data race oncodeServerMgr = nilinCloseis gone. - Overhead: one
WithCancel, twoAfterFuncs and oneRLockon the global map per open. Negligible.
Concurrency (no issues found)
- Locks are taken only in the order
connMuthenactiveTunnelsMu(read).CloseTunnel,CloseAllActiveTunnelsandunregisterAndCloseall releaseactiveTunnelsMubefore callingClose, so there is no reverse path and no deadlock. - In gorilla v1.5.3, the wss and HTTP proxy paths also go through
NetDialContext, so cancellation closes the proxy TCP connection too. - A health check that arrives after
Closeand callsStartAsynccannot start code-server, because the manager's context is already canceled.
Highlights
- The failure cause now reaches the command result, and reusing
handshakeErrorcarries a reason such as(HTTP 403)through to the client. unregisterAndClosedeletes only its own entry, which cleanly closes the session ID reuse race.- The held-handshake test waits on the server receiving the request rather than on a sleep, and the regression test was confirmed to fail before the fix.
Verdict: APPROVED, with warning 1 left to a follow-up issue.
Checklist
- Code follows stack conventions
- Tests included and passing (CI green)
- No security vulnerabilities
- Documentation updated if needed (not applicable)
|
|
||
| go tunnelClient.RunTunnelBackground() | ||
| // Open before replying so a tunnel that cannot open fails the command. | ||
| if err := tunnelClient.Open(ctx); err != nil { |
There was a problem hiding this comment.
Warning: performance. Open now runs on the shared pool worker for up to about 35 seconds (30-second handshake plus 5-second daemon wait), where the old go RunTunnelBackground() returned at once. A burst of opens against a blackholed tunnel server can fill all 20 workers and delay shell commands and closetunnel by up to 35 seconds; once the 200-slot queue fills, commands are refused with job queue is full. The bound explained in the Copilot thread holds, so this does not block the merge, but a follow-up issue for a semaphore on concurrent opens or a separate path for control commands is worth filing.
There was a problem hiding this comment.
Agreed on the cost, and not changed in this PR: a semaphore taken inside the pool job would still hold the worker while it waits, so the fix needs either control commands off the shared pool or a cap checked before submitting. Filed as #598 with both directions.
| return nil | ||
| } | ||
|
|
||
| func (tc *TunnelClient) open(ctx context.Context) error { |
There was a problem hiding this comment.
Suggestion: an already closed tunnel can still dial. context.AfterFunc(tc.ctx, cancel) in connect runs cancel in its own goroutine even when tc.ctx is already done, so a localhost dial can finish and send the upgrade request first. The result is still errTunnelClosedWhileOpening, so there is no production impact, but TestTunnelOpen_DialsNothingAfterTheTunnelWasClosed states a contract the code does not guarantee. An early check makes it deterministic:
| func (tc *TunnelClient) open(ctx context.Context) error { | |
| func (tc *TunnelClient) open(ctx context.Context) error { | |
| if tc.ctx.Err() != nil { | |
| return errTunnelClosedWhileOpening | |
| } |
There was a problem hiding this comment.
Fixed in 5cbd26f. You were right that context.AfterFunc runs cancel in its own goroutine even on a context that is already done, so a closed tunnel could start the dial. open now reads closed under connMu before doing anything; Close sets it before it cancels tc.ctx, so it also catches a close that is still stopping code-server.
| err := tc.Open(t.Context()) | ||
|
|
||
| require.ErrorIs(t, err, errTunnelClosedWhileOpening) | ||
| assert.Empty(t, hits) |
There was a problem hiding this comment.
Suggestion: assert.Empty(t, hits) reads a channel the server handler fills asynchronously, so it can pass even when a request arrives slightly later. With the early tc.ctx.Err() check in open() suggested above, the dial cannot start at all and this assertion becomes reliable.
There was a problem hiding this comment.
Fixed in 5cbd26f, differently from the suggestion alone. The early check made the dial impossible, but the old assertion still could not prove it: with the check removed it passed 300 of 300 runs. The test now listens on a raw TCP socket and accepts after Open returns, since a loopback connect is queued before the dial returns. Without the check it fails 6 of 100 runs under GOMAXPROCS=1, with it 0 of 350; the race is rare, so no run can force it.
| func (tc *TunnelClient) isRegistered() bool { | ||
| activeTunnelsMu.RLock() | ||
| defer activeTunnelsMu.RUnlock() | ||
| return activeTunnels[tc.sessionID] == tc | ||
| } |
There was a problem hiding this comment.
Suggestion: this duplicates GetActiveTunnel, which had no production caller on main and has only test callers after this PR. Reusing it keeps one lookup:
| func (tc *TunnelClient) isRegistered() bool { | |
| activeTunnelsMu.RLock() | |
| defer activeTunnelsMu.RUnlock() | |
| return activeTunnels[tc.sessionID] == tc | |
| } | |
| func (tc *TunnelClient) isRegistered() bool { | |
| got, _ := GetActiveTunnel(tc.sessionID) | |
| return got == tc | |
| } |
There was a problem hiding this comment.
Applied as suggested in 241aa5c: isRegistered now calls GetActiveTunnel instead of repeating its lookup.
|
|
||
| // setServerURL makes srv the configured Alpacon server, which is the only | ||
| // host a tunnel URL may name. | ||
| func setServerURL(t *testing.T, srv *httptest.Server) { |
There was a problem hiding this comment.
Suggestion: pkg/runner has a test helper with the same name, setServerURL(t, serverURL string). The packages cannot share it, but matching that signature (taking srv.URL) avoids two helpers with one name and different arguments.
There was a problem hiding this comment.
Applied in 241aa5c: the handler tests' setServerURL now takes the URL string, matching the runner helper of the same name.
|
|
||
| err := tc.Open(ctx) | ||
|
|
||
| require.Error(t, err) // gorilla's own deadline may report it first as an i/o timeout |
There was a problem hiding this comment.
Suggestion: require.Error alone also passes on an unrelated error, such as a refused URL. Narrowing it to the two cases the comment names, errors.Is(err, context.DeadlineExceeded) || errors.Is(err, os.ErrDeadlineExceeded), makes the test prove the deadline stopped the dial (check first that sanitizeURLError keeps the wrapping).
There was a problem hiding this comment.
Applied in e03b258. sanitizeURLError wraps with %w, so both cases match through errors.Is. With the server URL pointed at an unresolvable host, the old assertion passed on lookup console.invalid: no such host and the new one fails.
| go tunnelClient.RunTunnelBackground() | ||
| // Open before replying so a tunnel that cannot open fails the command. | ||
| if err := tunnelClient.Open(ctx); err != nil { | ||
| log.Error().Err(err).Str("sessionID", args.SessionID).Msg("Tunnel open failed.") |
There was a problem hiding this comment.
Suggestion: a user closing a tunnel right after opening it returns errTunnelClosedWhileOpening and is logged here at Error level. Picking that case out with errors.Is and logging it at Info or Warn keeps it out of error alerts.
There was a problem hiding this comment.
Applied in 9054216: the sentinel is exported as ErrTunnelClosedWhileOpening and the handler logs it at Info. Checking that path turned up one more case, fixed in bcb52e2: a close during the daemon wait made the real startTunnelRelay return the canceled tc.ctx error, which open wrapped as a relay failure, so it still reached Error. open now returns the sentinel when tc.ctx is done after the relay start fails, with a test that failed before. An open cut short by shutdown mostly ends on the canceled command context instead, since shutdown cancels the root context before CloseAllActiveTunnels, so it stays at Error; b19a560 makes the sentinel's doc say so.
| tc.connMu.Lock() | ||
| defer tc.connMu.Unlock() | ||
| if tc.closed { | ||
| mgr.cancel() |
There was a problem hiding this comment.
Suggestion: mgr.cancel() reaches into an unexported field of CodeServerManager. Nothing has started yet, so mgr.Stop() does the same thing (with a nil cmd it only cancels) and keeps teardown on one API.
| mgr.cancel() | |
| _ = mgr.Stop() |
There was a problem hiding this comment.
Applied as suggested in 241aa5c. With a nil cmd, Stop() only cancels, so the behavior is the same.
| dialer.NetDialContext = func(ctx context.Context, network, addr string) (net.Conn, error) { | ||
| c, err := (&net.Dialer{}).DialContext(ctx, network, addr) |
There was a problem hiding this comment.
Suggestion: this ctx parameter shadows the ctx of connect(ctx), and the outer one is read a few lines below in fmt.Errorf("tunnel dial stopped: %w", ctx.Err()). A distinct name reads more clearly.
| dialer.NetDialContext = func(ctx context.Context, network, addr string) (net.Conn, error) { | |
| c, err := (&net.Dialer{}).DialContext(ctx, network, addr) | |
| dialer.NetDialContext = func(dctx context.Context, network, addr string) (net.Conn, error) { | |
| c, err := (&net.Dialer{}).DialContext(dctx, network, addr) |
c4a4492
c4a4492 to
b19a560
Compare
|
Thanks for the review. Every item was checked against the code and held. The branch is rebased onto
Two more commits came out of a full review of the branch: 33ea8be drops Verification on b19a560:
|
…mand opentunnel started the tunnel in a goroutine and replied with exit code 0 before the dial, so a tunnel server refusal, a code-server manager that could not be created or a relay that did not start reached Alpacon as an opened tunnel and only the host log said why. The handler now runs Open first: it prepares code-server, dials the tunnel server and starts the relay, and on failure unregisters the tunnel and returns exit code 1 with the reason. Serve keeps relaying streams in the background. The dial follows the command context and the tunnel's own. gorilla does not watch the context while it reads the handshake response, so the dial socket is closed on cancellation, and a closetunnel during the open now fails it instead of waiting out the handshake timeout. A refused handshake reports its HTTP status. Cleanup unregisters a tunnel only while it is still the registered entry, so it no longer removes a newer tunnel under the same session ID. Fixes #596
- fail Open when the command context ends during the relay start - return an error from the test relay seam instead of calling t.Error
- fail Open when CloseTunnel has unregistered the tunnel but not yet closed it
connect cancels its dial through context.AfterFunc(tc.ctx, cancel), and AfterFunc runs cancel in its own goroutine even when tc.ctx is already done. Open on a tunnel that was already closed could therefore connect and send the upgrade request before the cancel landed, although it still returned errTunnelClosedWhileOpening. open now reads tc.closed under connMu before doing anything. Close sets closed before it cancels tc.ctx, so the check also catches a close that is still stopping code-server. The test counted hits on an HTTP handler, which records them asynchronously and could miss a late request. It now listens on a raw TCP socket and accepts after Open returns: a loopback connect is queued before the dial returns, so any dial Open made is already there. Without the check, it fails 6 of 100 runs under GOMAXPROCS=1; with it, 0 of 350.
A user who closes a tunnel right after opening it makes Open return the closed-while-opening error, and the handler logged it with log.Error like any other open failure. That is a close the user asked for, not a fault, so it no longer belongs in error alerts. Export the sentinel as ErrTunnelClosedWhileOpening so the handler can pick it out with errors.Is and log it at Info. The command result is unchanged: it still fails with the same message.
The test for a command context ending mid-handshake only required some error, so a dial that failed for an unrelated reason passed it too. With the server URL pointed at an unresolvable host, the old assertion passed on "lookup console.invalid: no such host". Require the error to be context.DeadlineExceeded or, when gorilla's own conn deadline reports first, os.ErrDeadlineExceeded. sanitizeURLError wraps with %w, so both still match through errors.Is. The same mutation now fails the test.
- isRegistered repeated GetActiveTunnel's lookup under the same lock; it now calls GetActiveTunnel. - initCodeServerManager called mgr.cancel(), an unexported field of CodeServerManager. Nothing has started yet, so Stop() only cancels and keeps teardown on one API. - The NetDialContext closure's ctx shadowed connect's ctx, which is read a few lines below in the "tunnel dial stopped" error; it is now dctx. - The handler tests' setServerURL took *httptest.Server while the runner tests' helper of the same name takes a string; it now takes the URL string too.
relayMustNotStart returned a package-level errRelayMustNotStart so one test could assert it was not the error. That assertion became the deadline check, leaving the sentinel unread; the stub now builds its error inline.
startTunnelRelay checks tc.ctx before spawning the daemon and while it waits for the daemon socket, and returns tc.ctx's error when the tunnel closes. open wrapped that as "failed to start tunnel relay", so a closetunnel or shutdown during the up-to-5-second daemon wait reached the console as a relay failure and the handler logged it at Error instead of recognizing ErrTunnelClosedWhileOpening. open now returns ErrTunnelClosedWhileOpening when tc.ctx is done after the relay start fails, as connect already does for its dial. The new test closes the tunnel inside the relay stub and returns the error the way startTunnelRelay does; it failed before this change with "failed to start tunnel relay: tunnel session closed while waiting for daemon socket: context canceled".
The sentinel's doc said it reports a close "by closetunnel or shutdown", but shutdown cancels the root context before CloseAllActiveTunnels runs, so an open interrupted by shutdown mostly ends with the canceled command context instead. The doc now names the mechanism, Close, rather than the callers. The handler's Info branch said "a close the user asked for", which left out the shutdown case that does reach it when CloseAllActiveTunnels wins the race.
b19a560 to
d8a4d57
Compare
|
If this PR is ready, ask for a review by commenting WALL-D: no review was requested in the 24 hours since the last push to |
Fixes #596
Summary
opentunnelstarted the tunnel in a goroutine and replied with exit code 0 before it dialed, so a tunnel that never connected reached Alpacon as an opened tunnel and only the host log said why. The handler now opens the tunnel before it replies: a refused dial, a code-server manager that cannot be created, or a relay that does not start returns exit code 1 withopentunnel: <reason>. Clients that read the command result, such asalpacon tunnelsince alpacax/alpacon-cli#636, can then show that reason instead of waiting on a tunnel that is not there.Changes
RunTunnelBackgroundis split intoOpen(ctx)andServe().OpenrunsinitCodeServerManager,connectand the relay start insidehandleOpenTunnel; on failure it unregisters and closes the tunnel.Servekeeps relaying streams in a goroutine and cleans up when the session ends.connectinstalls aNetDialContextthat closes the dial socket on cancellation. Aclosetunnelduring the open now fails it at once instead of waiting out the 30-secondHandshakeTimeout.ErrTunnelClosedWhileOpening, so a closed or abandoned tunnel is never reported as opened.openchecksclosedbefore it dials, becauseconnectcancels the dial throughcontext.AfterFunc, which runs in its own goroutine even on a context that is already done. A close that lands during the relay start is reported the same way, whether the relay stub returns orstartTunnelRelayfails on the canceledtc.ctx. The last check also requires the tunnel to still be registered, becauseCloseTunnelandCloseAllActiveTunnelsunregister it beforeClosesetsclosed. A command context that ends before the relay start returns fails the open as well.ErrTunnelClosedWhileOpeningat Info and every other open failure at Error. An open interrupted by shutdown mostly ends with the canceled command context instead, since shutdown cancels the root context beforeCloseAllActiveTunnelsruns, and is still logged at Error.handshakeError, for exampleopentunnel: failed to connect to tunnel server: websocket: bad handshake (HTTP 403).connMuand aclosedflag handwsConn,sessionandcodeServerMgrfromOpentoClosewithout a race.Closekeeps its order: stop code-server, then cancel. It no longer setscodeServerMgrto nil, which a concurrent health check could read between its nil check and its use.closetunnel.CheckSystemResourcesis a handler field (checkResources) and the relay start aTunnelClientfield (startRelay), so tests do not depend on the host's CPU load or spawn the daemon.Things to note
opentunnelnow replies after the dial and relay start rather than before them. The dial still starts as soon as the command arrives, so the moment the agent reaches the tunnel server does not move. One pool worker is held for the open, at most about 35 seconds (30-second handshake timeout plus the 5-second daemon wait). Aclosetunnelqueued behind busy workers therefore waits at most that long; shell commands already hold the same workers for up to 30 minutes. Keeping control commands off the shared pool, or capping concurrent opens, is tracked in Tunnel opens can hold every shared pool worker for up to 35 seconds #598.RegisterTunnel,Open,Serveorder in the type, and moving the tunnel dial ontopkg/wsclient.handleHealthCheckstill readscodeServerMgrwithout the lock, as before; this PR only removes the write that made that read able to panic.Testing
go test -race -count=1 -p 1 ./...passes on the pushed head, rebased ontomainat d04c244.pkg/runner/tunnel_client_test.go: a successful open, a relay that cannot start, a refused handshake with its status, aclosetunnelwhile the handshake is held (waits on the server receiving the request, not on a sleep), the command context ending, an open after close that makes no TCP connection, a close during the relay start, a close that fails the relay start, the command context ending during the relay start, a tunnel unregistered but not yet closed,Serveunregistering when the server ends the session, and cleanup leaving a newer tunnel under the same ID. The held-handshake test failed before theNetDialContextchange. The relay-start test failed before thetc.ctxcheck withfailed to start tunnel relay: tunnel session closed while waiting for daemon socket: context canceled. The open-after-close test fails 6 of 100 runs underGOMAXPROCS=1without the earlyclosedcheck and 0 of 350 with it; the race is rare, so it cannot fail every run. The command-deadline test now requirescontext.DeadlineExceededoros.ErrDeadlineExceeded, and fails when the server URL points at an unresolvable host.pkg/executor/handlers/tunnel/tunnel_test.go: a refused dial returns exit code 1 with the exact result and leaves nothing registered (this test reproduced the bug first), an editor whose code-server manager cannot be created (Linux only, since macOS uses the current user), and the resource-limit refusal.go vetfor linux, darwin and windows passes.golangci-lintreports only the two existingunusedfindings incmd/alpamon/command/register/register.goandpkg/runner/commit_types.go.Korean: none