Render delivery attempt detail in the event log (closes #202)
All checks were successful
check / check (push) Successful in 4m16s
All checks were successful
check / check (push) Successful in 4m16s
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. A cut body goes through RedactCut as well, 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. Target configuration keeps reaching the template only as a TargetView. 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, its error is reported rather than discarded, and the page renders at most 20 attempts per delivery, counting what it leaves out. static/css/tailwind.css is regenerated with the repo's pinned tailwindcss for the utility classes the new markup uses.
This commit is contained in:
458
internal/handlers/delivery_result_view_test.go
Normal file
458
internal/handlers/delivery_result_view_test.go
Normal file
@@ -0,0 +1,458 @@
|
||||
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")
|
||||
}
|
||||
|
||||
// TestHandleSourceLogs_RedactsCredentialSeveredByTheCut is the
|
||||
// regression test for a redactor that ran after the cut. The
|
||||
// remote chooses the padding in front of the credential it
|
||||
// echoes, so it chooses where the 4096-byte cut lands inside
|
||||
// that credential; the severed prefix matches no secret whole
|
||||
// and used to render verbatim.
|
||||
func TestHandleSourceLogs_RedactsCredentialSeveredByTheCut(
|
||||
t *testing.T,
|
||||
) {
|
||||
t.Parallel()
|
||||
|
||||
// Padding sized so the cut falls five bytes before the end
|
||||
// of the webhook URL, leaving the workspace ID, the bot ID
|
||||
// and all but the last few token characters in the cut
|
||||
// body.
|
||||
const severedTail = 5
|
||||
|
||||
pad := strings.Repeat(
|
||||
"A", responseCap-len(slackWebhookURL)+severedTail,
|
||||
)
|
||||
stored := pad + 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 the
|
||||
// target most likely to have a bad destination URL in its
|
||||
// history: deleting and recreating is how an operator fixes a
|
||||
// mistyped one. The row is only soft deleted and its
|
||||
// deliveries survive, so its redactor has to survive with it.
|
||||
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",
|
||||
)
|
||||
}
|
||||
Reference in New Issue
Block a user