package handlers_test import ( "bytes" "context" "encoding/json" "log/slog" "net/http" "net/http/httptest" "net/netip" "strings" "testing" "github.com/go-chi/chi" "github.com/google/uuid" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" "gorm.io/gorm/clause" "sneak.berlin/go/webhooker/internal/config" "sneak.berlin/go/webhooker/internal/database" "sneak.berlin/go/webhooker/internal/handlers" "sneak.berlin/go/webhooker/internal/middleware" "sneak.berlin/go/webhooker/internal/middleware/middlewaretest" ) // TestHandleWebhook_LogsClientNextToThePeer checks that the // receiver's "webhook request received" line carries both addresses: // remoteIP, the connecting peer, and clientIP, the client the access // log attributes the request to. func TestHandleWebhook_LogsClientNextToThePeer(t *testing.T) { t.Parallel() // untrustedPeer is outside the trusted 10.0.0.0/8, so its // X-Forwarded-For is ignored and it is the client. const untrustedPeer = "192.0.2.10" cases := map[string]struct { peer string wantRemote string wantClient string }{ "trusted proxy with a forwarded chain": { peer: "10.0.0.1:44444", wantRemote: "10.0.0.1", wantClient: "198.51.100.7", }, "untrusted peer": { peer: untrustedPeer + ":5555", wantRemote: untrustedPeer, wantClient: untrustedPeer, }, } for name, tc := range cases { t.Run(name, func(t *testing.T) { t.Parallel() var ( h *handlers.Handlers mw *middleware.Middleware db *database.Database ) app := newTestAppWithConfig(t, &config.Config{ DataDir: t.TempDir(), TrustedProxies: []netip.Prefix{ netip.MustParsePrefix("10.0.0.0/8"), }, }, &h, &mw, &db) app.RequireStart() t.Cleanup(app.RequireStop) buf := new(bytes.Buffer) h.SetLogForTest(slog.New(slog.NewJSONHandler(buf, nil))) webhook := seedWebhook(t, db) seedEntrypoint(t, db, webhook.ID) // Logging is what works the client address out, so the // request goes through it as it does in production. router := chi.NewRouter() router.Use(mw.Logging()) router.Post("/h/{uuid}", h.HandleWebhook()) req := httptest.NewRequestWithContext( context.Background(), http.MethodPost, "/h/ep-"+webhook.ID, strings.NewReader("{}"), ) req.RemoteAddr = tc.peer req.Header.Set("X-Forwarded-For", "198.51.100.7, 10.0.0.2") w := httptest.NewRecorder() router.ServeHTTP(w, req) require.Equal(t, http.StatusOK, w.Code) line := receivedLine(t, buf) assert.Equal(t, tc.wantRemote, line["remoteIP"]) assert.Equal(t, tc.wantClient, line["clientIP"]) }) } } // TestHandleWebhook_LogsNoEntrypointUUID sends an accepted event, a // request over the receiver rate limit and a request for an unknown // UUID through the receiver as routes.go mounts it, and checks that // nothing logged, at any level, carries either UUID. func TestHandleWebhook_LogsNoEntrypointUUID(t *testing.T) { t.Parallel() var ( h *handlers.Handlers db *database.Database ) cfg := &config.Config{DataDir: t.TempDir(), ReceiverRateLimit: 1} app := newTestAppWithConfig(t, cfg, &h, &db) app.RequireStart() t.Cleanup(app.RequireStop) buf := new(bytes.Buffer) log := slog.New(slog.NewJSONHandler( buf, &slog.HandlerOptions{Level: slog.LevelDebug}, )) h.SetLogForTest(log) mw := middlewaretest.New(t, log, cfg, nil) webhook := seedWebhook(t, db) entrypoint := &database.Entrypoint{ WebhookID: webhook.ID, Path: uuid.New().String(), Active: true, } require.NoError(t, db.DB().Omit(clause.Associations). Create(entrypoint).Error) unknownUUID := uuid.New().String() router := chi.NewRouter() router.Use(mw.Logging()) router.With(mw.ReceiverRateLimit()).HandleFunc( middleware.ReceiverRoute, h.HandleWebhook(), ) // In order: the limit is one request per minute per path, so the // second request for the known UUID is the rejected one. for _, step := range []struct { entrypointUUID string wantStatus int }{ {entrypoint.Path, http.StatusOK}, {entrypoint.Path, http.StatusTooManyRequests}, {unknownUUID, http.StatusNotFound}, } { req := httptest.NewRequestWithContext( context.Background(), http.MethodPost, "/h/"+step.entrypointUUID, strings.NewReader("{}"), ) w := httptest.NewRecorder() router.ServeHTTP(w, req) require.Equal(t, step.wantStatus, w.Code) } // The lines this test is about were all written, so the checks // below are not passing on an empty log. for _, msg := range []string{ "webhook request received", "webhook receiver rate limit exceeded", "entrypoint not found", } { assert.Contains(t, buf.String(), `"msg":"`+msg+`"`) } assert.NotContains(t, buf.String(), entrypoint.Path) assert.NotContains(t, buf.String(), unknownUUID) line := receivedLine(t, buf) assert.Equal(t, entrypoint.ID, line["entrypoint_id"]) assert.Equal(t, webhook.ID, line["webhook_id"]) } // receivedLine returns the one "webhook request received" line in the // captured JSON log. func receivedLine(t *testing.T, buf *bytes.Buffer) map[string]any { t.Helper() var found []map[string]any for line := range strings.SplitSeq( strings.TrimSpace(buf.String()), "\n", ) { var entry map[string]any require.NoError(t, json.Unmarshal([]byte(line), &entry)) if entry["msg"] == "webhook request received" { found = append(found, entry) } } require.Len(t, found, 1) return found[0] } // TestHandleWebhook_StoresTheEvent proves an accepted request is // answered with the receiver's 200 and body, and that the event is // stored with a pending delivery to the webhook's active target. func TestHandleWebhook_StoresTheEvent(t *testing.T) { t.Parallel() var ( h *handlers.Handlers db *database.Database dbMgr *database.WebhookDBManager ) app := newTestApp(t, &h, &db, &dbMgr) app.RequireStart() t.Cleanup(app.RequireStop) webhook := seedWebhook(t, db) entrypoint := seedEntrypoint(t, db, webhook.ID) target := seedConfiguredTarget( t, db, webhook.ID, database.TargetTypeHTTP, database.Target{URL: replayTargetURL}, ) w := httptest.NewRecorder() h.HandleWebhook().ServeHTTP(w, postRequest( "/h/"+entrypoint.Path, nil, map[string]string{"uuid": entrypoint.Path}, )) require.Equal(t, http.StatusOK, w.Code) assert.JSONEq(t, `{"status":"ok"}`, w.Body.String()) webhookDB, err := dbMgr.GetDB(webhook.ID) require.NoError(t, err) events := listEvents(t, webhookDB) require.Len(t, events, 1) assert.Equal(t, entrypoint.ID, events[0].EntrypointID) deliveries := listDeliveries(t, webhookDB, events[0].ID) require.Len(t, deliveries, 1) assert.Equal(t, target.ID, deliveries[0].TargetID) assert.Equal(t, database.DeliveryStatusPending, deliveries[0].Status) } // TestHandleWebhook_FailedStoreAnswersPlainError proves that an event // the engine cannot store is answered with the receiver's plain-text // 500, and that nothing of it is left stored. func TestHandleWebhook_FailedStoreAnswersPlainError(t *testing.T) { t.Parallel() var ( h *handlers.Handlers db *database.Database dbMgr *database.WebhookDBManager ) app := newTestApp(t, &h, &db, &dbMgr) app.RequireStart() t.Cleanup(app.RequireStop) webhook := seedWebhook(t, db) entrypoint := seedEntrypoint(t, db, webhook.ID) // Without its event totals table the webhook's database refuses // the totals write, which comes after the event row. webhookDB, err := dbMgr.GetDB(webhook.ID) require.NoError(t, err) require.NoError(t, webhookDB.Migrator().DropTable(&database.EventTotals{})) w := httptest.NewRecorder() h.HandleWebhook().ServeHTTP(w, postRequest( "/h/"+entrypoint.Path, nil, map[string]string{"uuid": entrypoint.Path}, )) assert.Equal(t, http.StatusInternalServerError, w.Code) assert.Equal(t, "Internal server error\n", w.Body.String()) assert.Empty(t, listEvents(t, webhookDB)) }