diff --git a/pkg/service/handlers/handlers_proxy.go b/pkg/service/handlers/handlers_proxy.go index 95f6771..f74910f 100644 --- a/pkg/service/handlers/handlers_proxy.go +++ b/pkg/service/handlers/handlers_proxy.go @@ -104,7 +104,25 @@ func (s *Server) ServeProxy(target *url.URL) http.HandlerFunc { } // HandleNotFound handles requests that don't match any route. +// It always logs [UNHANDLED] so unimplemented endpoints are visible in plain output. +// When proxyLogBody is enabled it also logs the request body (truncated to 512 bytes). func (s *Server) HandleNotFound(w http.ResponseWriter, r *http.Request) { + if s.proxyLogBody && r.Body != nil { + body, _ := io.ReadAll(r.Body) + r.Body = io.NopCloser(bytes.NewBuffer(body)) + + preview := body + truncated := "" + if len(preview) > 512 { + preview = preview[:512] + truncated = "…" + } + + log.Printf("[UNHANDLED] %s %s body(%d bytes): %s%s", r.Method, r.URL.Path, len(body), preview, truncated) + } else { + log.Printf("[UNHANDLED] %s %s", r.Method, r.URL.Path) + } + s.HandleBoseProxy(w, r) } diff --git a/pkg/service/handlers/handlers_proxy_test.go b/pkg/service/handlers/handlers_proxy_test.go index cea3035..00f94ac 100644 --- a/pkg/service/handlers/handlers_proxy_test.go +++ b/pkg/service/handlers/handlers_proxy_test.go @@ -3,6 +3,7 @@ package handlers import ( "bytes" "io" + "log" "net/http" "net/http/httptest" "os" @@ -14,6 +15,102 @@ import ( "github.com/gesellix/bose-soundtouch/pkg/service/proxy" ) +func TestHandleNotFound_UnhandledLogging(t *testing.T) { + // backend absorbs proxied requests so the test doesn't hit the real Bose upstream + backend := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) { + w.WriteHeader(http.StatusOK) + })) + defer backend.Close() + + backendHost := strings.TrimPrefix(backend.URL, "http://") + + captureLog := func(fn func()) string { + var buf bytes.Buffer + log.SetOutput(&buf) + defer log.SetOutput(os.Stderr) + fn() + return buf.String() + } + + t.Run("always logs [UNHANDLED] with method and path", func(t *testing.T) { + ds := datastore.NewDataStore(t.TempDir()) + server := NewServer(ds, nil, "http://localhost", false, false, false) + + req := httptest.NewRequest("GET", "/some/unknown/path", nil) + req.Host = backendHost + + logged := captureLog(func() { + server.HandleNotFound(httptest.NewRecorder(), req) + }) + + if !strings.Contains(logged, "[UNHANDLED]") { + t.Errorf("expected [UNHANDLED] in log, got: %s", logged) + } + if !strings.Contains(logged, "GET") || !strings.Contains(logged, "/some/unknown/path") { + t.Errorf("expected method and path in log, got: %s", logged) + } + }) + + t.Run("includes body in log when proxyLogBody is true", func(t *testing.T) { + ds := datastore.NewDataStore(t.TempDir()) + server := NewServer(ds, nil, "http://localhost", false, true, false) + + req := httptest.NewRequest("POST", "/marge/unknown", bytes.NewBufferString("")) + req.Host = backendHost + + logged := captureLog(func() { + server.HandleNotFound(httptest.NewRecorder(), req) + }) + + if !strings.Contains(logged, "") { + t.Errorf("expected body in log when proxyLogBody=true, got: %s", logged) + } + }) + + t.Run("omits body from log when proxyLogBody is false", func(t *testing.T) { + ds := datastore.NewDataStore(t.TempDir()) + server := NewServer(ds, nil, "http://localhost", false, false, false) + + req := httptest.NewRequest("POST", "/marge/unknown", bytes.NewBufferString("")) + req.Host = backendHost + + logged := captureLog(func() { + server.HandleNotFound(httptest.NewRecorder(), req) + }) + + if strings.Contains(logged, "") { + t.Errorf("expected body omitted when proxyLogBody=false, got: %s", logged) + } + if !strings.Contains(logged, "[UNHANDLED]") { + t.Errorf("expected [UNHANDLED] even without body, got: %s", logged) + } + }) + + t.Run("body is still forwarded to proxy after being read for logging", func(t *testing.T) { + var receivedBody string + forwardCheck := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + b, _ := io.ReadAll(r.Body) + receivedBody = string(b) + w.WriteHeader(http.StatusOK) + })) + defer forwardCheck.Close() + + ds := datastore.NewDataStore(t.TempDir()) + server := NewServer(ds, nil, "http://localhost", false, true, false) + + req := httptest.NewRequest("POST", "/marge/unknown", bytes.NewBufferString("")) + req.Host = strings.TrimPrefix(forwardCheck.URL, "http://") + + captureLog(func() { + server.HandleNotFound(httptest.NewRecorder(), req) + }) + + if receivedBody != "" { + t.Errorf("expected body forwarded to proxy, got: %q", receivedBody) + } + }) +} + func TestHandleProxyRequest_RequestBodyRecording(t *testing.T) { t.Setenv("RECORDER_ASYNC", "false") tmpDir, err := os.MkdirTemp("", "proxy-request-body-test")