diff --git a/docsite/docs/reference/troubleshooting.md b/docsite/docs/reference/troubleshooting.md index d37119d..c7a012b 100644 --- a/docsite/docs/reference/troubleshooting.md +++ b/docsite/docs/reference/troubleshooting.md @@ -86,7 +86,7 @@ instantaneous. | Connects, then closes at once | guacd unreachable. Check `GUACD_ADDR` and that the container is running | | SSH rejects the key | The stored key has no private half, or is not on the target | | RDP fails on retry | Credentials are single-use and consumed at tunnel open enter them again | -| Hangs at connecting | The agent is offline, or nothing is listening on the protocol port on the target's own loopback address. Check the audit log for `console.proxy_failed` — its reason names which | +| Hangs, then disconnects | The agent never claimed the relay, nothing is listening on the protocol port on the target's own loopback address, or guacd never dialled in time. Check the audit log for `console.proxy_failed` — its reason (`agent_timeout`, `dial_refused`, `guacd_timeout`, `rejected`) names which | | Fails only in production | The reverse proxy is not forwarding WebSocket upgrade headers | ## Monitors report down when the service is up diff --git a/docsite/docs/vantage/browser-console.md b/docsite/docs/vantage/browser-console.md index f35afa1..796d59c 100644 --- a/docsite/docs/vantage/browser-console.md +++ b/docsite/docs/vantage/browser-console.md @@ -70,4 +70,4 @@ keystroke log. If you need that, it has to come from the target machine. | Connects then closes immediately | guacd unreachable check `GUACD_ADDR` and that the container is up | | SSH refuses the key | The stored key has no private half, or is not in the target's `authorized_keys` | | RDP fails on a fresh credential | Credentials are consumed on open; a retry needs them entered again | -| Hangs at connecting | The agent is offline, or nothing is listening on the protocol port on the target's own loopback address. Check the audit log for `console.proxy_failed` — its reason names which | +| Hangs, then disconnects | The agent never claimed the relay, nothing is listening on the protocol port on the target's own loopback address, or guacd never dialled in time. Check the audit log for `console.proxy_failed` — its reason (`agent_timeout`, `dial_refused`, `guacd_timeout`, `rejected`) names which | diff --git a/server/internal/api/console.go b/server/internal/api/console.go index 3fad53b..a714156 100644 --- a/server/internal/api/console.go +++ b/server/internal/api/console.go @@ -150,7 +150,22 @@ func consoleTunnel(c *gin.Context) { c.JSON(http.StatusInternalServerError, gin.H{"error": "could not open relay"}) return } - defer relay.Close() + // guac.WebsocketServer.ServeHTTP returns before installing its + // OnDisconnect handler when the connect callback errors, which is exactly + // the path every relay failure this proxy introduces takes (the agent + // never claims it, dial_refused, guacd never dials, rejected). Emitting + // console.proxy_failed and ending the session here, unconditionally on + // teardown, is what makes those failures reach the audit log at all; + // OnDisconnect below only sees the rarer case of a session that was fully + // established and then failed. + defer func() { + relay.Close() + if reason := relay.Reason(); reason != "" { + services.LogEvent(instanceID, "console.proxy_failed", actorFromCtx(c), srv.ServerID, "", + fmt.Sprintf("console relay failed: %s (proxy_id=%s, port=%d)", reason, relay.ProxyID, relay.Port)) + } + _ = services.EndConsoleSession(instanceID, sessionID) + }() services.LogEvent(instanceID, "console.proxy_opened", actorFromCtx(c), srv.ServerID, "", fmt.Sprintf("console relay opened (proxy_id=%s, port=%d)", relay.ProxyID, relay.Port)) @@ -192,14 +207,9 @@ func consoleTunnel(c *gin.Context) { return guac.NewSimpleTunnel(stream), nil } + // Teardown (proxy_failed audit + EndConsoleSession) lives in the deferred + // func above, not here: this only fires once a tunnel was actually + // established, and letting both paths log would double the audit event. wsServer := guac.NewWebsocketServer(connect) - wsServer.OnDisconnect = func(id string, r *http.Request, t guac.Tunnel) { - if reason := relay.Reason(); reason != "" { - services.LogEvent(instanceID, "console.proxy_failed", actorFromCtx(c), srv.ServerID, "", - fmt.Sprintf("console relay failed: %s (proxy_id=%s, port=%d)", reason, relay.ProxyID, relay.Port)) - } - relay.Close() - _ = services.EndConsoleSession(instanceID, sessionID) - } wsServer.ServeHTTP(c.Writer, c.Request) } diff --git a/server/internal/proxy/session.go b/server/internal/proxy/session.go index 9217f21..d76b932 100644 --- a/server/internal/proxy/session.go +++ b/server/internal/proxy/session.go @@ -35,17 +35,29 @@ type Session struct { once sync.Once mu sync.Mutex reason string + conn net.Conn + + rendezvous *time.Timer } // NewSession binds an ephemeral port on listenHost. allowed is the set of IPs // permitted to connect; an empty set allows any, which is the degraded case // when guacd's host could not be resolved. +// +// A watchdog is armed immediately: if the agent never opens its ProxyStream +// and calls Serve, nothing else would ever bound how long the listener (and +// the registry entry that references it) stays open. Serve cancels it once +// entered and re-arms the same deadline for the accept wait. func NewSession(listenHost string, allowed []string) (*Session, error) { ln, err := net.Listen("tcp", net.JoinHostPort(listenHost, "0")) if err != nil { return nil, fmt.Errorf("bind relay listener: %w", err) } - return &Session{listener: ln, allowed: allowed, timeout: rendezvousTimeout}, nil + s := &Session{listener: ln, allowed: allowed, timeout: rendezvousTimeout} + s.rendezvous = time.AfterFunc(rendezvousTimeout, func() { + s.Close("agent_timeout") + }) + return s, nil } func (s *Session) Port() int { @@ -68,21 +80,45 @@ func (s *Session) setReason(r string) { } // Close tears the session down once. A non-empty reason is recorded only if no -// reason has been recorded already. +// reason has been recorded already. It closes both the listener and, if a +// connection has already been accepted, that connection too — an unconditional +// kill for the whole relay chain regardless of which stage it is in. func (s *Session) Close(reason string) { if reason != "" { s.setReason(reason) } s.once.Do(func() { + if s.rendezvous != nil { + s.rendezvous.Stop() + } _ = s.listener.Close() + s.mu.Lock() + conn := s.conn + s.mu.Unlock() + if conn != nil { + _ = conn.Close() + } }) } +func (s *Session) setConn(conn net.Conn) { + s.mu.Lock() + s.conn = conn + s.mu.Unlock() +} + // Serve accepts exactly one connection, verifies its source, and relays until // either side ends. It always closes the listener before returning. func (s *Session) Serve(stream AgentStream) error { defer s.Close("") + // The agent has claimed the session and opened its stream, so the + // unclaimed-rendezvous watchdog no longer applies; the accept deadline set + // just below takes over for the claimed case. + if s.rendezvous != nil { + s.rendezvous.Stop() + } + if l, ok := s.listener.(*net.TCPListener); ok { _ = l.SetDeadline(time.Now().Add(s.timeout)) } @@ -109,9 +145,15 @@ func (s *Session) Serve(stream AgentStream) error { continue } - // One connection only: nothing else may claim this port. - s.Close("") - defer conn.Close() + // One connection only: nothing else may claim this port. Store the + // conn first so a concurrent external Close (e.g. the browser tab + // closing) can reach it via the sync.Once teardown; then close just + // the listener directly (not through Close, which would also close + // the conn we are about to relay). The deferred s.Close("") above + // performs the real one-shot teardown, including this conn, once + // relay returns. + s.setConn(conn) + _ = s.listener.Close() return s.relay(conn, stream) }