From e8b92c18bd6a801a8f0ab0d42159a5535eceb953 Mon Sep 17 00:00:00 2001 From: Patrik Date: Tue, 10 Oct 2023 12:08:20 +0200 Subject: [PATCH] chore: add more tracing to post-flow hooks (#3566) --- selfservice/flow/login/hook.go | 16 +++++- selfservice/flow/registration/hook.go | 30 +++++++++-- x/http_secure_redirect.go | 2 +- x/http_secure_redirect_test.go | 78 +++++++++++++++------------ 4 files changed, 88 insertions(+), 38 deletions(-) diff --git a/selfservice/flow/login/hook.go b/selfservice/flow/login/hook.go index b8ce1d15d3b0..69a00232b992 100644 --- a/selfservice/flow/login/hook.go +++ b/selfservice/flow/login/hook.go @@ -9,6 +9,7 @@ import ( "net/http" "time" + "go.opentelemetry.io/otel/attribute" "go.opentelemetry.io/otel/trace" "github.com/ory/kratos/x/events" @@ -145,6 +146,11 @@ func (e *HookExecutor) PostLoginHook( if err != nil { return err } + span.SetAttributes(otelx.StringAttrs(map[string]string{ + "return_to": returnTo.String(), + "flow_type": string(flow.TypeBrowser), + "redirect_reason": "login successful", + })...) classified := s s = s.Declassified() @@ -165,6 +171,9 @@ func (e *HookExecutor) PostLoginHook( WithField("identity_id", i.ID). WithField("flow_method", a.Active). Debug("A ExecuteLoginPostHook hook aborted early.") + + span.SetAttributes(attribute.String("redirect_reason", "aborted by hook"), attribute.String("executor", fmt.Sprintf("%T", executor))) + return nil } return e.handleLoginError(w, r, g, a, i, err) @@ -181,6 +190,7 @@ func (e *HookExecutor) PostLoginHook( } if a.Type == flow.TypeAPI { + span.SetAttributes(attribute.String("flow_type", string(flow.TypeAPI))) if err := e.d.SessionPersister().UpsertSession(r.Context(), s); err != nil { return errors.WithStack(err) } @@ -190,7 +200,7 @@ func (e *HookExecutor) PostLoginHook( WithField("identity_id", i.ID). Info("Identity authenticated successfully and was issued an Ory Kratos Session Token.") - trace.SpanFromContext(r.Context()).AddEvent(events.NewLoginSucceeded(r.Context(), &events.LoginSucceededOpts{ + span.AddEvent(events.NewLoginSucceeded(r.Context(), &events.LoginSucceededOpts{ SessionID: s.ID, IdentityID: i.ID, FlowType: string(a.Type), @@ -235,6 +245,8 @@ func (e *HookExecutor) PostLoginHook( })) if x.IsJSONRequest(r) { + span.SetAttributes(attribute.String("flow_type", "spa")) + // Browser flows rely on cookies. Adding tokens in the mix will confuse consumers. s.Token = "" @@ -251,6 +263,7 @@ func (e *HookExecutor) PostLoginHook( if err != nil { return err } + span.SetAttributes(attribute.String("return_to", postChallengeURL), attribute.String("redirect_reason", "oauth2 login challenge")) e.d.Writer().WriteError(w, r, flow.NewBrowserLocationChangeRequiredError(postChallengeURL)) return nil } @@ -286,6 +299,7 @@ func (e *HookExecutor) PostLoginHook( return err } finalReturnTo = rt + span.SetAttributes(attribute.String("return_to", rt), attribute.String("redirect_reason", "oauth2 login challenge")) } x.ContentNegotiationRedirection(w, r, s, e.d.Writer(), finalReturnTo) diff --git a/selfservice/flow/registration/hook.go b/selfservice/flow/registration/hook.go index 20538ccfe1e6..f7a7fed1d99f 100644 --- a/selfservice/flow/registration/hook.go +++ b/selfservice/flow/registration/hook.go @@ -9,8 +9,11 @@ import ( "net/http" "time" + "go.opentelemetry.io/otel/attribute" + + "github.com/ory/x/otelx" + "github.com/julienschmidt/httprouter" - "go.opentelemetry.io/otel/trace" "github.com/ory/kratos/selfservice/sessiontokenexchange" "github.com/ory/kratos/x/events" @@ -81,6 +84,7 @@ type ( x.HTTPClientProvider x.LoggingProvider x.WriterProvider + x.TracingProvider sessiontokenexchange.PersistenceProvider } HookExecutor struct { @@ -95,7 +99,12 @@ func NewHookExecutor(d executorDependencies) *HookExecutor { return &HookExecutor{d: d} } -func (e *HookExecutor) PostRegistrationHook(w http.ResponseWriter, r *http.Request, ct identity.CredentialsType, provider string, a *Flow, i *identity.Identity) error { +func (e *HookExecutor) PostRegistrationHook(w http.ResponseWriter, r *http.Request, ct identity.CredentialsType, provider string, a *Flow, i *identity.Identity) (err error) { + ctx := r.Context() + ctx, span := e.d.Tracer(ctx).Tracer().Start(ctx, "HookExecutor.PostRegistrationHook") + r = r.WithContext(ctx) + defer otelx.End(span, &err) + e.d.Logger(). WithRequest(r). WithField("identity_id", i.ID). @@ -159,13 +168,18 @@ func (e *HookExecutor) PostRegistrationHook(w http.ResponseWriter, r *http.Reque if err != nil { return err } + span.SetAttributes(otelx.StringAttrs(map[string]string{ + "return_to": returnTo.String(), + "flow_type": string(flow.TypeBrowser), + "redirect_reason": "registration successful", + })...) e.d.Audit(). WithRequest(r). WithField("identity_id", i.ID). Info("A new identity has registered using self-service registration.") - trace.SpanFromContext(r.Context()).AddEvent(events.NewRegistrationSucceeded(r.Context(), i.ID, string(a.Type), a.Active.String(), provider)) + span.AddEvent(events.NewRegistrationSucceeded(r.Context(), i.ID, string(a.Type), a.Active.String(), provider)) s := session.NewInactiveSession() @@ -197,6 +211,9 @@ func (e *HookExecutor) PostRegistrationHook(w http.ResponseWriter, r *http.Reque WithField("identity_id", i.ID). WithField("flow_method", ct). Debug("A ExecutePostRegistrationPostPersistHook hook aborted early.") + + span.SetAttributes(attribute.String("redirect_reason", "aborted by hook"), attribute.String("executor", fmt.Sprintf("%T", executor))) + return nil } @@ -210,6 +227,8 @@ func (e *HookExecutor) PostRegistrationHook(w http.ResponseWriter, r *http.Reque WithError(err). Error("ExecutePostRegistrationPostPersistHook hook failed with an error.") + span.SetAttributes(attribute.String("redirect_reason", "hook error"), attribute.String("executor", fmt.Sprintf("%T", executor))) + traits := i.Traits return flow.HandleHookError(w, r, a, traits, ct.ToUiNodeGroup(), err, e.d, e.d) } @@ -230,6 +249,8 @@ func (e *HookExecutor) PostRegistrationHook(w http.ResponseWriter, r *http.Reque Debug("Post registration execution hooks completed successfully.") if a.Type == flow.TypeAPI || x.IsJSONRequest(r) { + span.SetAttributes(attribute.String("flow_type", string(flow.TypeAPI))) + if a.IDToken != "" { // We don't want to redirect with the code, if the flow was submitted with an ID token. // This is the case for Sign in with native Apple SDK or Google SDK. @@ -265,9 +286,12 @@ func (e *HookExecutor) PostRegistrationHook(w http.ResponseWriter, r *http.Reque } finalReturnTo = callbackURL } + span.SetAttributes(attribute.String("redirect_reason", "oauth2 login challenge")) } else if a.ReturnToVerification != "" { finalReturnTo = a.ReturnToVerification + span.SetAttributes(attribute.String("redirect_reason", "verification requested")) } + span.SetAttributes(attribute.String("return_to", finalReturnTo)) x.ContentNegotiationRedirection(w, r, s.Declassified(), e.d.Writer(), finalReturnTo) return nil diff --git a/x/http_secure_redirect.go b/x/http_secure_redirect.go index d4d4ebbd29d7..cccbba6db2ec 100644 --- a/x/http_secure_redirect.go +++ b/x/http_secure_redirect.go @@ -143,7 +143,7 @@ func SecureRedirectTo(r *http.Request, defaultReturnTo *url.URL, opts ...SecureR return nil, errors.WithStack(herodot.ErrBadRequest. WithID(text.ErrIDRedirectURLNotAllowed). - WithReasonf("Requested return_to URL \"%s\" is not allowed.", returnTo). + WithReasonf("Requested return_to URL %q is not allowed.", returnTo). WithDebugf("Allowed domains are: %v", o.allowlist)) } diff --git a/x/http_secure_redirect_test.go b/x/http_secure_redirect_test.go index f94c474e2440..0afedc3f9e89 100644 --- a/x/http_secure_redirect_test.go +++ b/x/http_secure_redirect_test.go @@ -128,7 +128,7 @@ func TestTakeOverReturnToParameter(t *testing.T) { func TestSecureRedirectTo(t *testing.T) { newServer := func(t *testing.T, isTLS bool, isRelative bool, expectErr bool, opts func(ts *httptest.Server) []x.SecureRedirectOption) *httptest.Server { var ts *httptest.Server - f := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + handler := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { if opts == nil { opts = func(ts *httptest.Server) []x.SecureRedirectOption { return nil @@ -138,7 +138,7 @@ func TestSecureRedirectTo(t *testing.T) { if !isRelative { defaultReturnTo = ts.URL + defaultReturnTo } - ru, err := x.SecureRedirectTo(r, urlx.ParseOrPanic(defaultReturnTo), opts(ts)...) + returnTo, err := x.SecureRedirectTo(r, urlx.ParseOrPanic(defaultReturnTo), opts(ts)...) if expectErr { require.Error(t, err) _, _ = w.Write([]byte("error")) @@ -146,13 +146,13 @@ func TestSecureRedirectTo(t *testing.T) { } require.NoError(t, err) - _, _ = w.Write([]byte(ru.String())) + _, _ = w.Write([]byte(returnTo.String())) }) if isTLS { - ts = httptest.NewTLSServer(f) + ts = httptest.NewTLSServer(handler) } else { - ts = httptest.NewServer(f) + ts = httptest.NewServer(handler) } t.Cleanup(ts.Close) @@ -170,49 +170,61 @@ func TestSecureRedirectTo(t *testing.T) { } t.Run("case=return to a relative path with anchor works", func(t *testing.T) { - s := newServer(t, false, true, false, func(ts *httptest.Server) []x.SecureRedirectOption { - return []x.SecureRedirectOption{x.SecureRedirectAllowURLs([]url.URL{*urlx.ParseOrPanic("/foo")})} - }) - _, body := makeRequest(t, s, "?return_to=/foo/kratos%23abcd") - assert.Equal(t, body, "/foo/kratos#abcd") + returnTo, err := x.SecureRedirectTo( + httptest.NewRequest("GET", "/?return_to=/foo/kratos%23abcd", nil), + urlx.ParseOrPanic("/default-return-to"), + x.SecureRedirectAllowURLs([]url.URL{*urlx.ParseOrPanic("/foo")}), + ) + require.NoError(t, err) + assert.Equal(t, returnTo.String(), "/foo/kratos#abcd") }) t.Run("case=return to default URL if nothing is allowed", func(t *testing.T) { - s := newServer(t, false, false, false, nil) - _, body := makeRequest(t, s, "?return_to=/foo") - assert.EqualValues(t, body, s.URL+"/default-return-to") + returnTo, err := x.SecureRedirectTo( + httptest.NewRequest("GET", "/?return_to=/foo", nil), + urlx.ParseOrPanic("https://www.ory.sh/default-return-to"), + ) + require.NoError(t, err) + assert.Equal(t, returnTo.String(), "https://www.ory.sh/default-return-to") }) t.Run("case=return to foo with server baseURL if allowed", func(t *testing.T) { - s := newServer(t, false, false, false, func(ts *httptest.Server) []x.SecureRedirectOption { - return []x.SecureRedirectOption{x.SecureRedirectAllowURLs([]url.URL{*urlx.ParseOrPanic(ts.URL)})} - }) - _, body := makeRequest(t, s, "?return_to=/foo") - assert.Equal(t, body, s.URL+"/foo") + returnTo, err := x.SecureRedirectTo( + httptest.NewRequest("GET", "/?return_to=/foo", nil), + urlx.ParseOrPanic("https://www.ory.sh/default-return-to"), + x.SecureRedirectAllowURLs([]url.URL{*urlx.ParseOrPanic("https://www.ory.sh")}), + ) + require.NoError(t, err) + assert.Equal(t, returnTo.String(), "https://www.ory.sh/foo") }) t.Run("case=return to a relative path works", func(t *testing.T) { - s := newServer(t, false, true, false, func(ts *httptest.Server) []x.SecureRedirectOption { - return []x.SecureRedirectOption{x.SecureRedirectAllowURLs([]url.URL{*urlx.ParseOrPanic("/foo")})} - }) - _, body := makeRequest(t, s, "?return_to=/foo/kratos") - assert.Equal(t, body, "/foo/kratos") + returnTo, err := x.SecureRedirectTo( + httptest.NewRequest("GET", "/?return_to=/foo/kratos", nil), + urlx.ParseOrPanic("/default-return-to"), + x.SecureRedirectAllowURLs([]url.URL{*urlx.ParseOrPanic("/foo")}), + ) + require.NoError(t, err) + assert.Equal(t, returnTo.String(), "/foo/kratos") }) t.Run("case=return to a fully qualified domain is forbidden if allowlist is relative", func(t *testing.T) { - s := newServer(t, false, true, true, func(ts *httptest.Server) []x.SecureRedirectOption { - return []x.SecureRedirectOption{x.SecureRedirectAllowURLs([]url.URL{*urlx.ParseOrPanic("/foo")})} - }) - _, body := makeRequest(t, s, "?return_to=https://www.ory.sh/foo/kratos") - assert.Equal(t, body, "error") + _, err := x.SecureRedirectTo( + httptest.NewRequest("GET", "/?return_to=https://www.ory.sh/foo/kratos", nil), + urlx.ParseOrPanic("/default-return-to"), + x.SecureRedirectAllowURLs([]url.URL{*urlx.ParseOrPanic("/foo")}), + ) + require.Error(t, err) }) t.Run("case=return to another domain works", func(t *testing.T) { - s := newServer(t, false, false, false, func(ts *httptest.Server) []x.SecureRedirectOption { - return []x.SecureRedirectOption{x.SecureRedirectAllowURLs([]url.URL{*urlx.ParseOrPanic("https://www.ory.sh/foo")})} - }) - _, body := makeRequest(t, s, "?return_to=https://www.ory.sh/foo/kratos") - assert.Equal(t, body, "https://www.ory.sh/foo/kratos") + returnTo, err := x.SecureRedirectTo( + httptest.NewRequest("GET", "https://example.com/?return_to=https://www.ory.sh/foo/kratos", nil), + urlx.ParseOrPanic("https://www.ory.sh/default-return-to"), + x.SecureRedirectAllowURLs([]url.URL{*urlx.ParseOrPanic("https://www.ory.sh/foo")}), + ) + require.NoError(t, err) + assert.Equal(t, returnTo.String(), "https://www.ory.sh/foo/kratos") }) t.Run("case=return to another domain fails if host mismatches", func(t *testing.T) {