Some checks failed
check / check (push) Failing after 2m49s
Expanding a delivery on the event log page now shows each recorded attempt: attempt number, outcome, status code, duration, error and response body. Previously a failure rendered as "target: failed" and diagnosing it meant opening the per-webhook SQLite file by hand. The response body is cut by SQLite via substr over a blob cast, the same projection the event body uses, so an oversized stored response never becomes a Go string. The page reports the cut with a marker. Response bodies and errors are remote content, so both go through a new delivery.Redactor that strips the target's own destination URL, path, query and userinfo, plus the values of credential-shaped request headers, before rendering. Target configuration keeps reaching the template only as a TargetView. A body that reaches the cap is treated as cut whether or not SQLite is what cut it. The delivery engine stops reading a response at its own cap, which is the same number of bytes this page renders, and the row it writes records that cut length as the whole length, so nothing in the row separates a response that ended at the cap from one severed there. Such a body goes through RedactCut, which drops any tail that is a proper prefix of a secret: the remote chooses the padding in front of a credential it echoes, so it chooses where the cut falls inside that credential. Its marker says the response reached the recording limit rather than quoting a total the row does not know. Redactors are built from an unscoped target load. Deleting a target only soft deletes the row while its deliveries survive, and a scoped load would leave exactly those deliveries rendering unredacted. The views the page lists stay scoped. Attempt loading is chunked so the IN clause cannot exceed SQLite's bound-parameter limit, and a chunk that fails fails the page rather than rendering the deliveries it covered as never having run. The page renders at most 20 attempts per delivery, counting what it leaves out. static/css/tailwind.css is regenerated with tailwindcss for the utility classes the new markup uses.
510 lines
13 KiB
Go
510 lines
13 KiB
Go
package handlers_test
|
|
|
|
import (
|
|
"net/http"
|
|
"net/http/httptest"
|
|
"strconv"
|
|
"strings"
|
|
"testing"
|
|
|
|
"github.com/stretchr/testify/assert"
|
|
"github.com/stretchr/testify/require"
|
|
"gorm.io/gorm/clause"
|
|
"sneak.berlin/go/webhooker/internal/database"
|
|
"sneak.berlin/go/webhooker/internal/delivery"
|
|
"sneak.berlin/go/webhooker/internal/handlers"
|
|
"sneak.berlin/go/webhooker/internal/session"
|
|
)
|
|
|
|
// responseCap is the number of response bytes the event log
|
|
// page is allowed to render for one delivery attempt.
|
|
const responseCap = handlers.MaxRenderedResponseBytesForTest
|
|
|
|
// failedAttempt describes the failed delivery every test in
|
|
// this file seeds. The values are distinctive so that finding
|
|
// them in the rendered page cannot be a coincidence.
|
|
const (
|
|
attemptStatusCode = 502
|
|
attemptDurationMS = 1234
|
|
attemptNumber = 3
|
|
attemptError = "upstream returned 502 Bad Gateway"
|
|
)
|
|
|
|
// seedFailedDelivery records an event, a failed delivery
|
|
// against targetID, and one delivery result carrying the
|
|
// given response body. It returns the delivery.
|
|
func seedFailedDelivery(
|
|
t *testing.T,
|
|
dbMgr *database.WebhookDBManager,
|
|
webhookID, targetID, responseBody string,
|
|
) *database.Delivery {
|
|
t.Helper()
|
|
|
|
webhookDB, err := dbMgr.GetDB(webhookID)
|
|
require.NoError(t, err)
|
|
|
|
event := &database.Event{
|
|
WebhookID: webhookID,
|
|
Method: http.MethodPost,
|
|
Body: `{"test":true}`,
|
|
ContentType: "application/json",
|
|
}
|
|
|
|
require.NoError(t, webhookDB.Omit(
|
|
clause.Associations,
|
|
).Create(event).Error)
|
|
|
|
dlv := &database.Delivery{
|
|
EventID: event.ID,
|
|
TargetID: targetID,
|
|
Status: database.DeliveryStatusFailed,
|
|
}
|
|
|
|
require.NoError(t, webhookDB.Omit(
|
|
clause.Associations,
|
|
).Create(dlv).Error)
|
|
|
|
result := &database.DeliveryResult{
|
|
DeliveryID: dlv.ID,
|
|
AttemptNum: attemptNumber,
|
|
Success: false,
|
|
StatusCode: attemptStatusCode,
|
|
ResponseBody: responseBody,
|
|
Error: attemptError,
|
|
Duration: attemptDurationMS,
|
|
}
|
|
|
|
require.NoError(t, webhookDB.Omit(
|
|
clause.Associations,
|
|
).Create(result).Error)
|
|
|
|
return dlv
|
|
}
|
|
|
|
// seedFailureAndRender seeds a failed delivery against a
|
|
// target of the given type and config, and returns the
|
|
// rendered event log page.
|
|
func seedFailureAndRender(
|
|
t *testing.T,
|
|
targetType database.TargetType,
|
|
config, responseBody string,
|
|
) string {
|
|
t.Helper()
|
|
|
|
var (
|
|
h *handlers.Handlers
|
|
sess *session.Session
|
|
db *database.Database
|
|
dbMgr *database.WebhookDBManager
|
|
)
|
|
|
|
app := newTestApp(t, &h, &sess, &db, &dbMgr)
|
|
app.RequireStart()
|
|
|
|
t.Cleanup(app.RequireStop)
|
|
|
|
wh := seedWebhook(t, db)
|
|
tgt := seedConfiguredTarget(
|
|
t, db, wh.ID, targetType, config,
|
|
)
|
|
|
|
seedFailedDelivery(t, dbMgr, wh.ID, tgt.ID, responseBody)
|
|
|
|
return renderSourceLogsPage(t, h, sess, wh.ID)
|
|
}
|
|
|
|
// TestHandleSourceLogs_RendersFailedAttempt is the regression
|
|
// test for the reported gap: a failed delivery used to render
|
|
// as the status word alone, so diagnosing it meant opening the
|
|
// per-webhook SQLite file by hand.
|
|
func TestHandleSourceLogs_RendersFailedAttempt(t *testing.T) {
|
|
t.Parallel()
|
|
|
|
body := seedFailureAndRender(
|
|
t,
|
|
database.TargetTypeHTTP,
|
|
`{"url":"https://example.com/hook/abc"}`,
|
|
"upstream exploded",
|
|
)
|
|
|
|
assert.Contains(
|
|
t, body, strconv.Itoa(attemptStatusCode),
|
|
"the attempt's status code must reach the page",
|
|
)
|
|
assert.Contains(
|
|
t, body, attemptError,
|
|
"the attempt's error must reach the page",
|
|
)
|
|
assert.Contains(
|
|
t, body, strconv.Itoa(attemptDurationMS),
|
|
"the attempt's duration must reach the page",
|
|
)
|
|
assert.Contains(
|
|
t, body, "Attempt "+strconv.Itoa(attemptNumber),
|
|
"the attempt number must reach the page",
|
|
)
|
|
assert.Contains(
|
|
t, body, "upstream exploded",
|
|
"the attempt's response body must reach the page",
|
|
)
|
|
}
|
|
|
|
// TestHandleSourceLogs_EscapesResponseBody proves the
|
|
// response body is treated as the untrusted remote content it
|
|
// is. The remote chooses these bytes and the page is rendered
|
|
// inside the operator's authenticated origin, where the
|
|
// application's own CSP allows inline script from 'self'.
|
|
func TestHandleSourceLogs_EscapesResponseBody(t *testing.T) {
|
|
t.Parallel()
|
|
|
|
const payload = `<script>alert("xss")</script>`
|
|
|
|
body := seedFailureAndRender(
|
|
t,
|
|
database.TargetTypeHTTP,
|
|
`{"url":"https://example.com/hook/abc"}`,
|
|
payload,
|
|
)
|
|
|
|
assert.NotContains(t, body, payload)
|
|
assert.NotContains(t, body, "<script>alert")
|
|
assert.Contains(t, body, "alert")
|
|
}
|
|
|
|
// TestHandleSourceLogs_RedactsCredentialEchoedInResponse
|
|
// covers the case that makes rendering a response body a
|
|
// disclosure question at all: the remote echoes back the
|
|
// credential the request carried, and the page would then put
|
|
// it on the operator's screen.
|
|
func TestHandleSourceLogs_RedactsCredentialEchoedInResponse(
|
|
t *testing.T,
|
|
) {
|
|
t.Parallel()
|
|
|
|
body := seedFailureAndRender(
|
|
t,
|
|
database.TargetTypeSlack,
|
|
`{"webhookUrl":"`+slackWebhookURL+`"}`,
|
|
"no_service: "+slackWebhookURL,
|
|
)
|
|
|
|
assert.NotContains(t, body, slackSecretPath)
|
|
assert.NotContains(t, body, "T00000000")
|
|
assert.NotContains(t, body, "B00000000")
|
|
assert.Contains(t, body, delivery.RedactionMarker)
|
|
|
|
// The rest of the response is still shown, or the
|
|
// redaction would have cost the operator the diagnosis.
|
|
assert.Contains(t, body, "no_service")
|
|
}
|
|
|
|
// TestHandleSourceLogs_RedactsCredentialEchoedInError covers
|
|
// the same disclosure through the error field. The delivery
|
|
// engine masks the URL out of the errors it stores, so this
|
|
// holds the read path to the rows written before it did.
|
|
func TestHandleSourceLogs_RedactsCredentialEchoedInError(
|
|
t *testing.T,
|
|
) {
|
|
t.Parallel()
|
|
|
|
var (
|
|
h *handlers.Handlers
|
|
sess *session.Session
|
|
db *database.Database
|
|
dbMgr *database.WebhookDBManager
|
|
)
|
|
|
|
app := newTestApp(t, &h, &sess, &db, &dbMgr)
|
|
app.RequireStart()
|
|
|
|
t.Cleanup(app.RequireStop)
|
|
|
|
wh := seedWebhook(t, db)
|
|
tgt := seedConfiguredTarget(
|
|
t, db, wh.ID,
|
|
database.TargetTypeSlack,
|
|
`{"webhookUrl":"`+slackWebhookURL+`"}`,
|
|
)
|
|
|
|
dlv := seedFailedDelivery(t, dbMgr, wh.ID, tgt.ID, "")
|
|
|
|
webhookDB, err := dbMgr.GetDB(wh.ID)
|
|
require.NoError(t, err)
|
|
|
|
// An unmasked transport error, exactly as Go's HTTP
|
|
// client renders one.
|
|
require.NoError(t, webhookDB.Model(
|
|
&database.DeliveryResult{},
|
|
).Where(
|
|
"delivery_id = ?", dlv.ID,
|
|
).Update(
|
|
"error",
|
|
`Post "`+slackWebhookURL+`": dial tcp: i/o timeout`,
|
|
).Error)
|
|
|
|
body := renderSourceLogsPage(t, h, sess, wh.ID)
|
|
|
|
assert.NotContains(t, body, slackSecretPath)
|
|
assert.Contains(t, body, delivery.RedactionMarker)
|
|
assert.Contains(t, body, "i/o timeout")
|
|
}
|
|
|
|
// severedPadding is the filler that puts the end of an echoed
|
|
// webhook URL five bytes past a cut at the response cap, so
|
|
// the cut leaves the workspace ID, the bot ID and all but the
|
|
// last few token characters behind.
|
|
func severedPadding() string {
|
|
const severedTail = 5
|
|
|
|
return strings.Repeat(
|
|
"A", responseCap-len(slackWebhookURL)+severedTail,
|
|
)
|
|
}
|
|
|
|
// TestHandleSourceLogs_RedactsCredentialSeveredByTheEngineCut
|
|
// is the regression test for a redactor gated on the SQL cut
|
|
// alone. The delivery engine stops reading a response at its
|
|
// own cap, which is the same number of bytes this page
|
|
// renders, so a row the engine cut is byte-for-byte
|
|
// indistinguishable from a complete response and that gate
|
|
// never opened on anything the engine writes.
|
|
//
|
|
// The seeded body is what the engine stores for any remote
|
|
// that sends at least that much: exactly responseCap bytes,
|
|
// ending in a severed webhook URL.
|
|
// TestDeliverHTTP_CutsStoredResponseAtMaxBodyLog in
|
|
// internal/delivery pins that this is the size it produces.
|
|
func TestHandleSourceLogs_RedactsCredentialSeveredByTheEngineCut(
|
|
t *testing.T,
|
|
) {
|
|
t.Parallel()
|
|
|
|
sent := severedPadding() + slackWebhookURL +
|
|
strings.Repeat("Z", 128)
|
|
stored := sent[:responseCap]
|
|
|
|
require.Len(
|
|
t, stored, responseCap,
|
|
"the engine stores exactly the cap, never more",
|
|
)
|
|
require.Contains(
|
|
t, stored, "T00000000",
|
|
"the severed credential must be in what is seeded",
|
|
)
|
|
|
|
body := seedFailureAndRender(
|
|
t,
|
|
database.TargetTypeSlack,
|
|
`{"webhookUrl":"`+slackWebhookURL+`"}`,
|
|
stored,
|
|
)
|
|
|
|
assert.NotContains(t, body, "T00000000")
|
|
assert.NotContains(t, body, "B00000000")
|
|
assert.Contains(t, body, delivery.RedactionMarker)
|
|
assert.Contains(
|
|
t, body, "reached the recording limit",
|
|
"a body the engine cut must not be shown as complete",
|
|
)
|
|
}
|
|
|
|
// TestHandleSourceLogs_RedactsCredentialSeveredBySQLCut covers
|
|
// the same severing for a row larger than the cap, which is
|
|
// SQLite's cut rather than the engine's. The current engine
|
|
// writes no such row; rows predating its cap or restored from
|
|
// an archive are not bounded by it, which is why the page cuts
|
|
// again in SQL and has to redact that cut too.
|
|
func TestHandleSourceLogs_RedactsCredentialSeveredBySQLCut(
|
|
t *testing.T,
|
|
) {
|
|
t.Parallel()
|
|
|
|
stored := severedPadding() + slackWebhookURL +
|
|
strings.Repeat("Z", 128)
|
|
|
|
require.Greater(
|
|
t, len(stored), responseCap,
|
|
"the stored body must exceed the cap or nothing is cut",
|
|
)
|
|
|
|
body := seedFailureAndRender(
|
|
t,
|
|
database.TargetTypeSlack,
|
|
`{"webhookUrl":"`+slackWebhookURL+`"}`,
|
|
stored,
|
|
)
|
|
|
|
assert.NotContains(t, body, "T00000000")
|
|
assert.NotContains(t, body, "B00000000")
|
|
assert.NotContains(
|
|
t, body, slackWebhookURL[:len(slackWebhookURL)-10],
|
|
)
|
|
assert.Contains(t, body, delivery.RedactionMarker)
|
|
}
|
|
|
|
// TestHandleSourceLogs_RedactsForSoftDeletedTarget covers a
|
|
// target an operator has deleted. The row is only soft deleted
|
|
// and its deliveries survive in the per-webhook database, so
|
|
// its redactor has to survive with it or every response body
|
|
// it ever recorded renders unredacted.
|
|
func TestHandleSourceLogs_RedactsForSoftDeletedTarget(
|
|
t *testing.T,
|
|
) {
|
|
t.Parallel()
|
|
|
|
var (
|
|
h *handlers.Handlers
|
|
sess *session.Session
|
|
db *database.Database
|
|
dbMgr *database.WebhookDBManager
|
|
)
|
|
|
|
app := newTestApp(t, &h, &sess, &db, &dbMgr)
|
|
app.RequireStart()
|
|
|
|
t.Cleanup(app.RequireStop)
|
|
|
|
wh := seedWebhook(t, db)
|
|
tgt := seedConfiguredTarget(
|
|
t, db, wh.ID,
|
|
database.TargetTypeSlack,
|
|
`{"webhookUrl":"`+slackWebhookURL+`"}`,
|
|
)
|
|
|
|
seedFailedDelivery(
|
|
t, dbMgr, wh.ID, tgt.ID,
|
|
"no_service: "+slackWebhookURL,
|
|
)
|
|
|
|
require.NoError(t, db.DB().Delete(tgt).Error)
|
|
|
|
body := renderSourceLogsPage(t, h, sess, wh.ID)
|
|
|
|
assert.NotContains(t, body, slackSecretPath)
|
|
assert.NotContains(t, body, "T00000000")
|
|
assert.Contains(t, body, delivery.RedactionMarker)
|
|
assert.Contains(t, body, "no_service")
|
|
}
|
|
|
|
// TestHandleSourceLogs_BoundsRenderedAttempts pins the ceiling
|
|
// on how many of one delivery's attempts reach the page, and
|
|
// that what it drops is counted rather than hidden.
|
|
func TestHandleSourceLogs_BoundsRenderedAttempts(t *testing.T) {
|
|
t.Parallel()
|
|
|
|
const extraAttempts = 7
|
|
|
|
var (
|
|
h *handlers.Handlers
|
|
sess *session.Session
|
|
db *database.Database
|
|
dbMgr *database.WebhookDBManager
|
|
)
|
|
|
|
app := newTestApp(t, &h, &sess, &db, &dbMgr)
|
|
app.RequireStart()
|
|
|
|
t.Cleanup(app.RequireStop)
|
|
|
|
wh := seedWebhook(t, db)
|
|
tgt := seedConfiguredTarget(
|
|
t, db, wh.ID, database.TargetTypeLog, "",
|
|
)
|
|
|
|
dlv := seedFailedDelivery(t, dbMgr, wh.ID, tgt.ID, "")
|
|
|
|
webhookDB, err := dbMgr.GetDB(wh.ID)
|
|
require.NoError(t, err)
|
|
|
|
total := handlers.MaxRenderedAttemptsForTest + extraAttempts
|
|
|
|
// seedFailedDelivery already recorded one attempt.
|
|
for i := range total - 1 {
|
|
require.NoError(t, webhookDB.Omit(
|
|
clause.Associations,
|
|
).Create(&database.DeliveryResult{
|
|
DeliveryID: dlv.ID,
|
|
AttemptNum: attemptNumber + 1 + i,
|
|
Error: attemptError,
|
|
}).Error)
|
|
}
|
|
|
|
views := h.LoadEventLogViewsForTest(
|
|
httptest.NewRecorder(), *wh, 1,
|
|
)
|
|
require.Len(t, views, 1)
|
|
require.Len(t, views[0].Deliveries, 1)
|
|
|
|
dv := views[0].Deliveries[0]
|
|
|
|
assert.Equal(t, total, dv.AttemptCount)
|
|
assert.Len(
|
|
t, dv.Results, handlers.MaxRenderedAttemptsForTest,
|
|
)
|
|
assert.Equal(t, extraAttempts, dv.AttemptsOmitted)
|
|
|
|
page := renderSourceLogsPage(t, h, sess, wh.ID)
|
|
|
|
assert.Contains(t, page, "attempts omitted")
|
|
assert.Contains(
|
|
t, page, strconv.Itoa(total)+" attempts",
|
|
"the header must count every recorded attempt",
|
|
)
|
|
}
|
|
|
|
// TestHandleSourceLogs_BoundsOversizeResponse proves the
|
|
// rendered page is bounded by the response cap rather than by
|
|
// the stored response size. The cut happens in SQLite, so the
|
|
// oversized value never becomes a Go string; this asserts the
|
|
// observable consequence, that neither the page nor the
|
|
// projection carries the tail.
|
|
func TestHandleSourceLogs_BoundsOversizeResponse(t *testing.T) {
|
|
t.Parallel()
|
|
|
|
const tail = "QQRESPONSETAILQQ"
|
|
|
|
var (
|
|
h *handlers.Handlers
|
|
sess *session.Session
|
|
db *database.Database
|
|
dbMgr *database.WebhookDBManager
|
|
)
|
|
|
|
app := newTestApp(t, &h, &sess, &db, &dbMgr)
|
|
app.RequireStart()
|
|
|
|
t.Cleanup(app.RequireStop)
|
|
|
|
wh := seedWebhook(t, db)
|
|
tgt := seedConfiguredTarget(
|
|
t, db, wh.ID, database.TargetTypeLog, "",
|
|
)
|
|
|
|
stored := strings.Repeat("A", responseCap*4) + tail
|
|
seedFailedDelivery(t, dbMgr, wh.ID, tgt.ID, stored)
|
|
|
|
views := h.LoadEventLogViewsForTest(
|
|
httptest.NewRecorder(), *wh, 1,
|
|
)
|
|
require.Len(t, views, 1)
|
|
require.Len(t, views[0].Deliveries, 1)
|
|
require.Len(t, views[0].Deliveries[0].Results, 1)
|
|
|
|
attempt := views[0].Deliveries[0].Results[0]
|
|
|
|
assert.LessOrEqual(
|
|
t, len(attempt.ResponseBody), responseCap,
|
|
)
|
|
assert.Equal(
|
|
t, int64(len(stored)), attempt.ResponseBytes,
|
|
)
|
|
assert.True(t, attempt.ResponseTruncated)
|
|
|
|
page := renderSourceLogsPage(t, h, sess, wh.ID)
|
|
|
|
assert.NotContains(t, page, tail)
|
|
assert.Contains(
|
|
t, page, "Response truncated for display",
|
|
)
|
|
}
|