artin/sourcegraph
1
0
Fork 0
mirror of https://github.com/sourcegraph/sourcegraph.git synced 2026-02-06 19:21:50 +00:00
Code Issues Packages Projects Releases Wiki Activity

Add webhook logging to new webhooks handler (#43446)

Browse Source 
* add webhook logging middleware to webhooks handler to log webhooks and ensure webhook ID is set on log

* separate setting webhook/ext svc ids into separate setters

* move webhook logging middleware to top level
This commit is contained in:
Molly Weitzel 2022-10-27 09:58:37 -06:00 committed by GitHub
parent 9e46677e6d
commit 74ec39b1c9
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
8 changed files with 102 additions and 21 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

2
cmd/frontend/internal/httpapi/httpapi.go
View File

@ -101,7 +101,7 @@ func NewHandler(
// TODO: Integrate with webhookMiddleware.Logger
webhookHandler := webhooks.NewHandler(logger, db, &gh)
m.Get(apirouter.Webhooks).Handler(trace.Route(webhookHandler))
m.Get(apirouter.Webhooks).Handler(trace.Route(webhookMiddleware.Logger(webhookHandler)))
m.Get(apirouter.GitHubWebhooks).Handler(trace.Route(webhookMiddleware.Logger(&gh)))
m.Get(apirouter.GitLabWebhooks).Handler(trace.Route(webhookMiddleware.Logger(handlers.GitLabWebhook)))
m.Get(apirouter.BitbucketServerWebhooks).Handler(trace.Route(webhookMiddleware.Logger(handlers.BitbucketServerWebhook)))

36
cmd/frontend/webhooks/middleware.go
View File

@ -19,7 +19,17 @@ import (
func SetExternalServiceID(ctx context.Context, id int64) {
// There's no else case here because it is expected that there's no setter
// if logging is disabled.
if setter, ok := ctx.Value(setterContextKey).(contextFunc); ok {
if setter, ok := ctx.Value(extSvcIDSetterContextKey).(contextFuncInt64); ok {
setter(id)
}
}
// SetWebhookID attaches a specific webhook ID to the current
// webhook request for logging purposes.
func SetWebhookID(ctx context.Context, id int32) {
// There's no else case here because it is expected that there's no setter
// if logging is disabled.
if setter, ok := ctx.Value(webhookIDSetterContextKey).(contextFuncInt32); ok {
setter(id)
}
}
@ -63,17 +73,22 @@ func (mw *LogMiddleware) Logger(next http.Handler) http.Handler {
statusCode: 200,
}
// The external service ID is looked up within the webhook handler, but
// The external service ID and webhook id is looked up within the webhook handler, but
// we need access to it to be able to store the webhook log with the
// appropriate external service ID. To handle this, we'll put a setter
// appropriate external service/webhook ID. To handle this, we'll put a setter
// closure into the context that can then be used by
// SetExternalServiceID to receive the external service ID from the
// handler.
var externalServiceID *int64
var setter contextFunc = func(id int64) {
externalServiceID = &id
var extSvcIDSetter contextFuncInt64 = func(extSvcID int64) {
externalServiceID = &extSvcID
}
ctx := context.WithValue(r.Context(), setterContextKey, setter)
ctx := context.WithValue(r.Context(), extSvcIDSetterContextKey, extSvcIDSetter)
var webhookID *int32
var webhookIDSetter contextFuncInt32 = func(whID int32) {
webhookID = &whID
}
ctx = context.WithValue(ctx, webhookIDSetterContextKey, webhookIDSetter)
// Delegate to the next handler.
next.ServeHTTP(writer, r.WithContext(ctx))
@ -87,6 +102,7 @@ func (mw *LogMiddleware) Logger(next http.Handler) http.Handler {
// Write the payload.
if err := mw.store.Create(r.Context(), &types.WebhookLog{
ExternalServiceID: externalServiceID,
WebhookID: webhookID,
StatusCode: writer.statusCode,
Request: types.NewUnencryptedWebhookLogMessage(types.WebhookLogMessage{
Header: r.Header,
@ -156,6 +172,10 @@ func LoggingEnabled(c *conf.Unified) bool {
type contextKey string
var setterContextKey = contextKey("webhook setter")
var extSvcIDSetterContextKey = contextKey("webhook external service ID setter")
type contextFunc func(int64)
type contextFuncInt64 func(int64)
var webhookIDSetterContextKey = contextKey("webhook ID setter")
type contextFuncInt32 func(int32)

4
cmd/frontend/webhooks/middleware_test.go
View File

@ -24,13 +24,13 @@ func TestSetExternalServiceID(t *testing.T) {
SetExternalServiceID(ctx, 1)
// Make sure it can handle an invalid setter.
invalidCtx := context.WithValue(ctx, setterContextKey, func() {
invalidCtx := context.WithValue(ctx, extSvcIDSetterContextKey, func() {
panic("if we get as far as calling this, that's a bug")
})
SetExternalServiceID(invalidCtx, 1)
// Now the real case: a valid setter.
validCtx := context.WithValue(ctx, setterContextKey, func(id int64) {
validCtx := context.WithValue(ctx, extSvcIDSetterContextKey, func(id int64) {
assert.EqualValues(t, 42, id)
})
SetExternalServiceID(validCtx, 42)

1
cmd/frontend/webhooks/webhooks.go
View File

@ -44,6 +44,7 @@ func NewHandler(logger log.Logger, db database.DB, gh *GitHubWebhook) http.Handl
http.Error(w, "Could not find webhook with provided UUID.", http.StatusNotFound)
return
}
SetWebhookID(r.Context(), webhook.ID)
var secret string
if webhook.Secret != nil {

15
cmd/frontend/webhooks/webhooks_test.go
View File

@ -64,8 +64,12 @@ func TestWebhooksHandler(t *testing.T) {
DB: db,
}
webhookMiddleware := NewLogMiddleware(
db.WebhookLogs(keyring.Default().WebhookLogKey),
)
base := mux.NewRouter()
base.Path("/.api/webhooks/{webhook_uuid}").Methods("POST").Handler(NewHandler(logger, db, &gh))
base.Path("/.api/webhooks/{webhook_uuid}").Methods("POST").Handler(webhookMiddleware.Logger(NewHandler(logger, db, &gh)))
srv := httptest.NewServer(base)
t.Run("found GitLab webhook with correct secret returns unimplemented", func(t *testing.T) {
@ -128,6 +132,15 @@ func TestWebhooksHandler(t *testing.T) {
require.NoError(t, err)
assert.Equal(t, http.StatusOK, resp.StatusCode)
logs, _, err := db.WebhookLogs(keyring.Default().WebhookLogKey).List(context.Background(), database.WebhookLogListOpts{
WebhookID: &gitHubWH.ID,
})
assert.NoError(t, err)
assert.Len(t, logs, 1)
for _, log := range logs {
assert.Equal(t, gitHubWH.ID, *log.WebhookID)
}
})
t.Run("GitHub with no secret returns 200", func(t *testing.T) {

22
internal/database/webhook_logs.go
View File

@ -59,6 +59,7 @@ func (s *webhookLogStore) Create(ctx context.Context, log *types.WebhookLog) err
webhookLogCreateQueryFmtstr,
receivedAt,
dbutil.NullInt64{N: log.ExternalServiceID},
dbutil.NullInt32{N: log.WebhookID},
log.StatusCode,
[]byte(rawRequest),
[]byte(rawResponse),
@ -104,6 +105,12 @@ type WebhookLogListOpts struct {
// logs will be returned.
ExternalServiceID *int64
// If set and non-zero, this limits the webhook logs to those matched to
// that configured webhook. If set and zero, this limits the webhook logs to
// those that did not match any webhook. If nil, then all webhook
// logs will be returned.
WebhookID *int32
// If set, only webhook logs that resulted in errors will be returned.
OnlyErrors bool
@ -120,6 +127,13 @@ func (opts *WebhookLogListOpts) predicates() []*sqlf.Query {
preds = append(preds, sqlf.Sprintf("external_service_id = %s", *id))
}
}
if id := opts.WebhookID; id != nil {
if *id == 0 {
preds = append(preds, sqlf.Sprintf("webhook_id IS NULL"))
} else {
preds = append(preds, sqlf.Sprintf("webhook_id = %s", *id))
}
}
if opts.OnlyErrors {
preds = append(preds, sqlf.Sprintf("status_code NOT BETWEEN 100 AND 399"))
}
@ -207,6 +221,7 @@ var webhookLogColumns = []*sqlf.Query{
sqlf.Sprintf("id"),
sqlf.Sprintf("received_at"),
sqlf.Sprintf("external_service_id"),
sqlf.Sprintf("webhook_id"),
sqlf.Sprintf("status_code"),
sqlf.Sprintf("request"),
sqlf.Sprintf("response"),
@ -218,6 +233,7 @@ INSERT INTO
webhook_logs (
received_at,
external_service_id,
webhook_id,
status_code,
request,
response,
@ -229,6 +245,7 @@ INSERT INTO
%s,
%s,
%s,
%s,
%s
)
RETURNING %s
@ -274,6 +291,7 @@ WHERE
func (s *webhookLogStore) scanWebhookLog(log *types.WebhookLog, sc dbutil.Scanner) error {
var (
externalServiceID int64 = -1
webhookID int32 = -1
request, response []byte
keyID string
)
@ -282,6 +300,7 @@ func (s *webhookLogStore) scanWebhookLog(log *types.WebhookLog, sc dbutil.Scanne
&log.ID,
&log.ReceivedAt,
&dbutil.NullInt64{N: &externalServiceID},
&dbutil.NullInt32{N: &webhookID},
&log.StatusCode,
&request,
&response,
@ -293,6 +312,9 @@ func (s *webhookLogStore) scanWebhookLog(log *types.WebhookLog, sc dbutil.Scanne
if externalServiceID != -1 {
log.ExternalServiceID = &externalServiceID
}
if webhookID != -1 {
log.WebhookID = &webhookID
}
log.Request = types.NewEncryptedWebhookLogMessage(string(request), keyID, s.key)
log.Response = types.NewEncryptedWebhookLogMessage(string(response), keyID, s.key)

42
internal/database/webhook_logs_test.go
View File

@ -8,10 +8,12 @@ import (
"time"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
"github.com/sourcegraph/log/logtest"
"github.com/sourcegraph/sourcegraph/internal/database/dbtest"
"github.com/sourcegraph/sourcegraph/internal/encryption/keyring"
et "github.com/sourcegraph/sourcegraph/internal/encryption/testing"
"github.com/sourcegraph/sourcegraph/internal/extsvc"
"github.com/sourcegraph/sourcegraph/internal/types"
@ -37,7 +39,7 @@ func TestWebhookLogStore(t *testing.T) {
store := tx.WebhookLogs(nil)
log := createWebhookLog(0, http.StatusCreated, time.Now())
log := createWebhookLog(0, 0, http.StatusCreated, time.Now())
err = store.Create(ctx, log)
assert.Nil(t, err)
@ -74,7 +76,7 @@ func TestWebhookLogStore(t *testing.T) {
store := tx.WebhookLogs(et.ByteaTestKey{})
// Weirdly, Go doesn't have a HTTP constant for "418 I'm a Teapot".
log := createWebhookLog(0, 418, time.Now())
log := createWebhookLog(0, 0, 418, time.Now())
err = store.Create(ctx, log)
assert.Nil(t, err)
@ -110,7 +112,7 @@ func TestWebhookLogStore(t *testing.T) {
store := tx.WebhookLogs(&et.BadKey{Err: errors.New("uh-oh")})
log := createWebhookLog(0, http.StatusExpectationFailed, time.Now())
log := createWebhookLog(0, 0, http.StatusExpectationFailed, time.Now())
err = store.Create(ctx, log)
assert.NotNil(t, err)
})
@ -125,7 +127,7 @@ func TestWebhookLogStore(t *testing.T) {
store := tx.WebhookLogs(et.TestKey{})
log := createWebhookLog(0, http.StatusInternalServerError, time.Now())
log := createWebhookLog(0, 0, http.StatusInternalServerError, time.Now())
err = store.Create(ctx, log)
assert.Nil(t, err)
@ -166,16 +168,20 @@ func TestWebhookLogStore(t *testing.T) {
}
assert.Nil(t, esStore.Upsert(ctx, es))
whStore := tx.Webhooks(keyring.Default().WebhookKey)
wh, err := whStore.Create(ctx, extsvc.KindGitHub, "http://github.com", 0, nil)
require.NoError(t, err)
store := tx.WebhookLogs(et.TestKey{})
okTime := time.Date(2021, 10, 29, 18, 46, 0, 0, time.UTC)
okLog := createWebhookLog(es.ID, http.StatusOK, okTime)
okLog := createWebhookLog(es.ID, wh.ID, http.StatusOK, okTime)
if err := store.Create(ctx, okLog); err != nil {
t.Fatal(err)
}
errTime := time.Date(2021, 10, 29, 18, 47, 0, 0, time.UTC)
errLog := createWebhookLog(0, http.StatusInternalServerError, errTime)
errLog := createWebhookLog(0, 0, http.StatusInternalServerError, errTime)
if err := store.Create(ctx, errLog); err != nil {
t.Fatal(err)
}
@ -205,6 +211,18 @@ func TestWebhookLogStore(t *testing.T) {
opts: WebhookLogListOpts{ExternalServiceID: int64Ptr(es.ID + 1)},
want: []*types.WebhookLog{},
},
"specific webhook id": {
opts: WebhookLogListOpts{WebhookID: int32Ptr(wh.ID)},
want: []*types.WebhookLog{okLog},
},
"no webhook id": {
opts: WebhookLogListOpts{WebhookID: int32Ptr(0)},
want: []*types.WebhookLog{errLog},
},
"webhook id without results": {
opts: WebhookLogListOpts{WebhookID: int32Ptr(wh.ID + 1)},
want: []*types.WebhookLog{},
},
"both within time range": {
opts: WebhookLogListOpts{
Since: timePtr(okTime.Add(-1 * time.Minute)),
@ -290,10 +308,10 @@ func TestWebhookLogStore(t *testing.T) {
retention, err := time.ParseDuration("24h")
assert.Nil(t, err)
stale := createWebhookLog(es.ID, http.StatusOK, time.Now().Add(-(2 * retention)))
stale := createWebhookLog(es.ID, 0, http.StatusOK, time.Now().Add(-(2 * retention)))
store.Create(ctx, stale)
fresh := createWebhookLog(0, http.StatusInternalServerError, time.Now())
fresh := createWebhookLog(0, 0, http.StatusInternalServerError, time.Now())
store.Create(ctx, fresh)
err = store.DeleteStale(ctx, retention)
@ -305,11 +323,15 @@ func TestWebhookLogStore(t *testing.T) {
})
}
func createWebhookLog(externalServiceID int64, statusCode int, receivedAt time.Time) *types.WebhookLog {
func createWebhookLog(externalServiceID int64, webhookID int32, statusCode int, receivedAt time.Time) *types.WebhookLog {
var id *int64
if externalServiceID != 0 {
id = &externalServiceID
}
var whID *int32
if webhookID != 0 {
whID = &webhookID
}
requestHeader := http.Header{}
requestHeader.Add("type", "request")
@ -320,6 +342,7 @@ func createWebhookLog(externalServiceID int64, statusCode int, receivedAt time.T
return &types.WebhookLog{
ReceivedAt: receivedAt,
ExternalServiceID: id,
WebhookID: whID,
StatusCode: statusCode,
Request: types.NewUnencryptedWebhookLogMessage(types.WebhookLogMessage{
Header: requestHeader,
@ -333,4 +356,5 @@ func createWebhookLog(externalServiceID int64, statusCode int, receivedAt time.T
}
func int64Ptr(v int64) *int64 { return &v }
func int32Ptr(v int32) *int32 { return &v }
func timePtr(v time.Time) *time.Time { return &v }

1
internal/types/webhook_logs.go
View File

@ -11,6 +11,7 @@ type WebhookLog struct {
ID int64
ReceivedAt time.Time
ExternalServiceID *int64
WebhookID *int32
StatusCode int
Request *EncryptableWebhookLogMessage
Response *EncryptableWebhookLogMessage