Show why the gateway refused an exec, attached run or log stream

convox.yml

@@ -30,7 +30,7 @@ services:
     # Pinned to an immutable release tag. scripts/bump-version.sh sets it to the new
     # version (:vX.Y.Z); the release workflow publishes that tag when the v* git tag is pushed.
     # :e327add is the v0.1.1 release (identical to :latest when this was pinned).
-    image: docker.io/docspringcom/rack-gateway:v0.1.28
+    image: docker.io/docspringcom/rack-gateway:v0.1.29
     command: ./scripts/start-gateway.sh
     environment:
       - PORT=8080
@@ -54,7 +54,7 @@ services:
 
   admin:
     # Uses same image as gateway service (kept in sync by scripts/bump-version.sh)
-    image: docker.io/docspringcom/rack-gateway:v0.1.28
+    image: docker.io/docspringcom/rack-gateway:v0.1.29
     command: echo "Use this service to run migrations, database admin tasks, etc."
     environment:
       - PORT=8080

docs/src/content/docs/concepts/audit-logging.mdx

@@ -322,7 +322,7 @@ An exec's or a process start's command (`convox run`, `convox exec`) is recorded
 with the credentials a command line commonly carries redacted. The gateway refuses a command longer than 50 KB as
 the audit log records it (redacted, then JSON-encoded) with `400` before it reaches the rack, so nothing runs that
 the log can't show in full, and the refusal is audited as a denial. The rack-gateway CLI checks the length before it
-starts a process, so it can say why; the Convox SDK only shows `websocket: bad handshake` for a refused exec.
+asks for MFA or starts a process.
 
 A command's justification (`--justification`, or the deploy approval's message for a command run under one) is
 recorded with it as `justification` in the details. The gateway can require one for every command, in every app

internal/cli/AGENTS.md

@@ -320,8 +320,10 @@ characters as `\uXXXX`, which `encoding/json` leaves raw, so `-o json` stays val
 - Permission errors: Clear message about which role is required
 - Token expiry: Auto-detect and prompt for re-login
 - Exec and log streams: the Convox SDK (`stdsdk.Client.Websocket`) drops the response to a refused WebSocket
-  handshake, so any gateway refusal of `exec`, `run` (attached) or `logs` (401, 403, 429, 400) prints only
-  `websocket: bad handshake`. The refusal and its reason are in the gateway's audit log and request log. The CLI
-  checks what it can before it connects: `run` and `exec` refuse a command too long for the audit log
+  handshake and returns only `websocket.ErrBadHandshake`. The CLI's websocket dialers (`secureConvoxSDK`) wrap each
+  connection in `handshakeRecordingConn`, which keeps the gateway's response to a refused handshake (and stops
+  recording at an accepted one's headers), and `Execute` turns the error into the status and the gateway's reason
+  (`explainRefusedHandshake`), for example `the gateway refused the connection (403 Forbidden): ...`. The CLI
+  still checks what it can before it connects: `run` and `exec` refuse a command too long for the audit log
   (`audit.CheckCommandLength`), or without a justification the app requires, before any MFA prompt or process
   start.

internal/cli/convox_process_approval.go

@@ -25,8 +25,7 @@ func addJustificationFlag(cmd *cobra.Command) {
 }
 
 // commandJustification returns --justification, checked, or "" without one. A command without one in an app that
-// requires one (required) is refused here, before anything starts: the gateway refuses it too, but the CLI can't
-// show why the gateway refused an exec's WebSocket handshake.
+// requires one (required) is refused here, before any MFA prompt or process start: the gateway refuses it too.
 func commandJustification(cmd *cobra.Command, app string, required bool) (string, error) {
 	text, err := cmd.Flags().GetString(justificationFlag)
 	if err != nil {

internal/cli/convox_process_command.go

@@ -103,9 +103,8 @@ func runProcessCommand(
 }
 
 // prepareProcessCommand checks an exec or run command and reviews its script. The gateway refuses a command too
-// long for its audit log, or without a justification in an app that requires one, but the Convox SDK drops the
-// answer to a refused WebSocket handshake, so an exec it refused would only show "websocket: bad handshake".
-// Checking the command here explains the refusal, before any MFA prompt or process start.
+// long for its audit log, or without a justification in an app that requires one; checking the command here
+// refuses it before any MFA prompt or process start.
 func prepareProcessCommand(cobraCmd *cobra.Command, args []string, action string) (processCommand, error) {
 	if err := resolveAppFlag(cobraCmd); err != nil {
 		return processCommand{}, err

internal/cli/convox_process_command_test.go

@@ -52,8 +52,7 @@ func processCobraCommand(t *testing.T, cmd *cobra.Command, flags map[string]stri
 }
 
 // Without --justification, a command in an app that requires one (its own setting, or the gateway-wide one) is
-// refused before anything is sent to the rack (the gateway's refusal of an exec would only show as
-// "websocket: bad handshake").
+// refused before anything is sent to the rack.
 func TestProcessCommandRefusedWithoutAJustificationTheAppRequires(t *testing.T) {
 	const required = `{"require_command_justification":{"value":true}}`
 	for name, set := range map[string]func(*envChangeGateway){

internal/cli/convox_processes_test.go

@@ -100,8 +100,7 @@ func assertFlag(t *testing.T, flag *stdcli.Flag, name string, value interface{})
 	}
 }
 
-// A command too long for the gateway's audit log is refused with the reason before any MFA prompt or process start:
-// the gateway's own refusal of an exec only shows as "websocket: bad handshake".
+// A command too long for the gateway's audit log is refused with the reason before any MFA prompt or process start.
 func TestProcessCommandsRefuseCommandsTooLongToAudit(t *testing.T) {
 	long := strings.Repeat("x", audit.MaxRecordedCommandBytes)
 	for _, cmd := range []*cobra.Command{ExecCommand(), RunCommand()} {

internal/cli/root.go

@@ -93,5 +93,5 @@ Rack management:
 		InstancesCommand(),
 	)
 
-	return rootCmd.Execute()
+	return explainRefusedHandshake(rootCmd.Execute())
 }

internal/cli/sdk_tls.go

@@ -30,9 +30,12 @@ var sdkRootCAs *x509.CertPool
 // Gateway connections ignore HTTP(S)_PROXY / ALL_PROXY, as stdsdk's own HTTP client always did. gorilla
 // would otherwise use the TLS hook to dial the proxy itself (and skip TLS to the gateway), which breaks
 // logs, exec and run behind a proxy.
+//
+// Both websocket dialers record the gateway's answer to a refused handshake (see explainRefusedHandshake).
 func secureConvoxSDK() {
 	stdsdk.DefaultClient = newVerifyingSDKClient()
 	websocket.DefaultDialer.NetDialTLSContext = dialVerifiedTLS
+	websocket.DefaultDialer.NetDialContext = dialRecordingHandshake
 	websocket.DefaultDialer.Proxy = nil
 }
 
@@ -64,7 +67,11 @@ func dialVerifiedTLS(ctx context.Context, network, addr string) (net.Conn, error
 		NetDialer: &net.Dialer{Timeout: 30 * time.Second, KeepAlive: 10 * time.Second},
 		Config:    verifyingTLSConfig(host),
 	}
-	return dialer.DialContext(ctx, network, addr)
+	conn, err := dialer.DialContext(ctx, network, addr)
+	if err != nil {
+		return nil, err
+	}
+	return recordHandshake(conn), nil
 }
 
 // parseGatewayURL parses a gateway base URL and refuses ones the CLI must not send credentials to: plain HTTP

internal/cli/websocket_refusal.go

@@ -0,0 +1,137 @@
+package cli
+
+import (
+	"bufio"
+	"bytes"
+	"context"
+	"errors"
+	"fmt"
+	"io"
+	"net"
+	"net/http"
+	"sync"
+
+	"github.com/gorilla/websocket"
+)
+
+// maxRecordedRefusalBytes caps how much of the gateway's answer to a refused WebSocket handshake the CLI keeps.
+// gorilla reads 1 KB of a refused handshake's body, so a recording rarely gets that far.
+const maxRecordedRefusalBytes = 4 << 10
+
+// The Convox SDK (stdsdk.Client.Websocket) drops the response gorilla returns with websocket.ErrBadHandshake, so
+// a refused exec, attached run or log stream would only say "websocket: bad handshake". The CLI's WebSocket
+// connections record what the gateway sends until the handshake is over, and keep the response to a refused one
+// here for explainRefusedHandshake.
+var lastRefusedHandshake struct {
+	mu       sync.Mutex
+	response []byte
+}
+
+func setRefusedHandshake(response []byte) {
+	lastRefusedHandshake.mu.Lock()
+	defer lastRefusedHandshake.mu.Unlock()
+	lastRefusedHandshake.response = append([]byte(nil), response...)
+}
+
+func takeRefusedHandshake() []byte {
+	lastRefusedHandshake.mu.Lock()
+	defer lastRefusedHandshake.mu.Unlock()
+	response := lastRefusedHandshake.response
+	lastRefusedHandshake.response = nil
+	return response
+}
+
+// handshakeRecordingConn records what the server sends until the end of its handshake response. It stops at the
+// headers of an accepted handshake (101 Switching Protocols), so none of the stream itself is kept, and keeps a
+// refused one's response, body included, up to maxRecordedRefusalBytes.
+type handshakeRecordingConn struct {
+	net.Conn
+	recording bool
+	received  []byte
+}
+
+func recordHandshake(conn net.Conn) net.Conn {
+	return &handshakeRecordingConn{Conn: conn, recording: true}
+}
+
+func (c *handshakeRecordingConn) Read(p []byte) (int, error) {
+	n, err := c.Conn.Read(p)
+	if c.recording && n > 0 {
+		c.record(p[:n])
+	}
+	return n, err
+}
+
+func (c *handshakeRecordingConn) record(data []byte) {
+	if room := maxRecordedRefusalBytes - len(c.received); len(data) > room {
+		data = data[:room]
+	}
+	c.received = append(c.received, data...)
+	full := len(c.received) >= maxRecordedRefusalBytes
+	if !full && !bytes.Contains(c.received, []byte("\r\n\r\n")) {
+		return
+	}
+	if isSwitchingProtocols(c.received) {
+		c.recording, c.received = false, nil
+		return
+	}
+	setRefusedHandshake(c.received)
+	if full {
+		c.recording, c.received = false, nil
+	}
+}
+
+func isSwitchingProtocols(response []byte) bool {
+	return bytes.HasPrefix(response, []byte("HTTP/1.1 101 ")) || bytes.HasPrefix(response, []byte("HTTP/1.0 101 "))
+}
+
+// dialRecordingHandshake is the dialer for plain WebSocket connections (ws://, to a gateway on this machine).
+func dialRecordingHandshake(ctx context.Context, network, addr string) (net.Conn, error) {
+	conn, err := (&net.Dialer{}).DialContext(ctx, network, addr)
+	if err != nil {
+		return nil, err
+	}
+	return recordHandshake(conn), nil
+}
+
+// handshakeRefusedError is a WebSocket handshake the gateway refused, with its reason.
+type handshakeRefusedError struct {
+	status int
+	reason string
+}
+
+func (e *handshakeRefusedError) Error() string {
+	msg := fmt.Sprintf("the gateway refused the connection (%d %s)", e.status, http.StatusText(e.status))
+	if e.reason == "" {
+		return msg
+	}
+	return msg + ": " + e.reason
+}
+
+func (*handshakeRefusedError) Unwrap() error {
+	return websocket.ErrBadHandshake
+}
+
+// explainRefusedHandshake replaces websocket.ErrBadHandshake with the gateway's status and reason, when the
+// connection recorded its response.
+func explainRefusedHandshake(err error) error {
+	if !errors.Is(err, websocket.ErrBadHandshake) {
+		return err
+	}
+	response := takeRefusedHandshake()
+	if response == nil {
+		return err
+	}
+	resp, parseErr := http.ReadResponse(bufio.NewReader(bytes.NewReader(response)), nil)
+	if parseErr != nil {
+		return err
+	}
+	defer func() { _ = resp.Body.Close() }()
+	// A body cut off at maxRecordedRefusalBytes still has its start.
+	body, _ := io.ReadAll(resp.Body)
+	refusal := &handshakeRefusedError{status: resp.StatusCode}
+	if len(bytes.TrimSpace(body)) > 0 {
+		refusal.reason = RenderGatewayError(body)
+	}
+	return refusal
+}