Fix log spam from http: response.WriteHeader on hijacked connection for WebSocket errors

This commit is contained in:
binwiederhier
2026-02-04 06:05:54 -08:00
parent fe386e31dd
commit 08eaafa77b
8 changed files with 356 additions and 269 deletions

View File

@@ -78,6 +78,21 @@ func (e errHTTP) clone() errHTTP {
}
}
// errWebSocketPostUpgrade is a wrapper error indicating an error occurred after the WebSocket
// upgrade completed (i.e., the connection was hijacked). This is used to avoid calling
// WriteHeader on hijacked connections, which causes log spam.
type errWebSocketPostUpgrade struct {
err error
}
func (e *errWebSocketPostUpgrade) Error() string {
return e.err.Error()
}
func (e *errWebSocketPostUpgrade) Unwrap() error {
return e.err
}
var (
errHTTPBadRequest = &errHTTP{40000, http.StatusBadRequest, "invalid request", "", nil}
errHTTPBadRequestEmailDisabled = &errHTTP{40001, http.StatusBadRequest, "e-mail notifications are not enabled", "https://ntfy.sh/docs/config/#e-mail-notifications", nil}

View File

@@ -1,14 +1,16 @@
package server
import (
"errors"
"fmt"
"net/http"
"strings"
"unicode/utf8"
"github.com/emersion/go-smtp"
"github.com/gorilla/websocket"
"heckel.io/ntfy/v2/log"
"heckel.io/ntfy/v2/util"
"net/http"
"strings"
"unicode/utf8"
)
// Log tags
@@ -83,7 +85,8 @@ func httpContext(r *http.Request) log.Context {
}
func websocketErrorContext(err error) log.Context {
if c, ok := err.(*websocket.CloseError); ok {
var c *websocket.CloseError
if errors.As(err, &c) {
return log.Context{
"error": c.Error(),
"error_code": c.Code,

View File

@@ -434,8 +434,14 @@ func (s *Server) handleError(w http.ResponseWriter, r *http.Request, v *visitor,
} else {
ev.Info("WebSocket error: %s", err.Error())
}
w.WriteHeader(httpErr.HTTPCode)
return // Do not attempt to write any body to upgraded connection
// Write error response only if the connection was not hijacked yet. Bytes written to hijacked
// connections are WebSocket frames, not HTTP, and will cause "http: response.WriteHeader on hijacked
// connection" log spam.
var postUpgradeErr *errWebSocketPostUpgrade
if !errors.As(err, &postUpgradeErr) {
w.WriteHeader(httpErr.HTTPCode)
}
return
}
if isNormalError {
ev.Debug("Connection closed with HTTP %d (ntfy error %d)", httpErr.HTTPCode, httpErr.Code)
@@ -1637,7 +1643,10 @@ func (s *Server) handleSubscribeWS(w http.ResponseWriter, r *http.Request, v *vi
logvr(v, r).Tag(tagWebsocket).Err(err).Fields(websocketErrorContext(err)).Trace("WebSocket connection closed")
return nil // Normal closures are not errors; note: "1006 (abnormal closure)" is treated as normal, because people disconnect a lot
}
return err
if err != nil {
return &errWebSocketPostUpgrade{err}
}
return nil
}
func parseSubscribeParams(r *http.Request) (poll bool, since sinceMarker, scheduled bool, filters *queryFilter, err error) {

View File

@@ -7,6 +7,7 @@ import (
_ "embed"
"encoding/base64"
"encoding/json"
"errors"
"fmt"
"io"
"net/http"
@@ -3760,3 +3761,61 @@ func waitForWithMaxWait(t *testing.T, maxWait time.Duration, f func() bool) {
}
t.Fatalf("Function f did not succeed after %v: %v", maxWait, string(debug.Stack()))
}
// mockResponseWriter is a mock ResponseWriter for testing
type mockResponseWriter struct {
header http.Header
statusCode int
body []byte
writeHeaderHit bool
}
func newMockResponseWriter() *mockResponseWriter {
return &mockResponseWriter{
header: make(http.Header),
}
}
func (m *mockResponseWriter) Header() http.Header {
return m.header
}
func (m *mockResponseWriter) Write(b []byte) (int, error) {
m.body = append(m.body, b...)
return len(b), nil
}
func (m *mockResponseWriter) WriteHeader(statusCode int) {
m.statusCode = statusCode
m.writeHeaderHit = true
}
func TestServer_HandleError_SkipsWriteHeaderOnHijackedConnection(t *testing.T) {
// Test that handleError does not call WriteHeader for WebSocket errors wrapped
// with errWebSocketPostUpgrade (indicating the connection was hijacked)
s := newTestServer(t, newTestConfig(t))
// Create a WebSocket upgrade request
r, _ := http.NewRequest("GET", "/mytopic/ws", nil)
r.Header.Set("Upgrade", "websocket")
r.Header.Set("Connection", "Upgrade")
v := newVisitor(s.config, s.messageCache, s.userManager, netip.MustParseAddr("1.2.3.4"), nil)
// Test post-upgrade errors wrapped with errWebSocketPostUpgrade (should NOT call WriteHeader)
postUpgradeErr := &errWebSocketPostUpgrade{errors.New("websocket: close 1000 (normal)")}
mock := newMockResponseWriter()
s.handleError(mock, r, v, postUpgradeErr)
require.False(t, mock.writeHeaderHit, "WriteHeader should not be called for post-upgrade errors")
// Test pre-upgrade errors (should call WriteHeader)
preUpgradeErrors := []error{
errHTTPBadRequestWebSocketsUpgradeHeaderMissing,
errHTTPTooManyRequestsLimitSubscriptions,
errHTTPInternalError,
}
for _, err := range preUpgradeErrors {
mock := newMockResponseWriter()
s.handleError(mock, r, v, err)
require.True(t, mock.writeHeaderHit, "WriteHeader should be called for error: %s", err.Error())
}
}