fix: improve webhook resilience (#3200)

* fix: improve webhook logging * chore: bump x * feat: decouple context in PostRegistrationPostPersist hook
ory · Apr 5, 2023 · 0a05d99 · 0a05d99
1 parent 21576be
commit 0a05d99
Show file tree

Hide file tree

Showing 2 changed files with 40 additions and 14 deletions.
diff --git a/selfservice/flow/registration/hook.go b/selfservice/flow/registration/hook.go
@@ -48,7 +48,7 @@ type (
 	}
 )
 
-func PostHookPostPersistExecutorNames(e []PostHookPostPersistExecutor) []string {
+func ExecutorNames[T any](e []T) []string {
 	names := make([]string, len(e))
 	for k, ee := range e {
 		names[k] = fmt.Sprintf("%T", ee)
@@ -107,24 +107,31 @@ func (e *HookExecutor) PostRegistrationHook(w http.ResponseWriter, r *http.Reque
 					WithRequest(r).
 					WithField("executor", fmt.Sprintf("%T", executor)).
 					WithField("executor_position", k).
-					WithField("executors", PostHookPostPersistExecutorNames(e.d.PostRegistrationPostPersistHooks(r.Context(), ct))).
+					WithField("executors", ExecutorNames(e.d.PostRegistrationPrePersistHooks(r.Context(), ct))).
 					WithField("identity_id", i.ID).
 					WithField("flow_method", ct).
 					Debug("A ExecutePostRegistrationPrePersistHook hook aborted early.")
 				return nil
 			}
 
-			var traits identity.Traits
-			if i != nil {
-				traits = i.Traits
-			}
+			e.d.Logger().
+				WithRequest(r).
+				WithField("executor", fmt.Sprintf("%T", executor)).
+				WithField("executor_position", k).
+				WithField("executors", ExecutorNames(e.d.PostRegistrationPrePersistHooks(r.Context(), ct))).
+				WithField("identity_id", i.ID).
+				WithField("flow_method", ct).
+				WithError(err).
+				Error("ExecutePostRegistrationPostPersistHook hook failed with an error.")
+
+			traits := i.Traits
 			return flow.HandleHookError(w, r, a, traits, ct.ToUiNodeGroup(), err, e.d, e.d)
 		}
 
 		e.d.Logger().WithRequest(r).
 			WithField("executor", fmt.Sprintf("%T", executor)).
 			WithField("executor_position", k).
-			WithField("executors", PostHookPostPersistExecutorNames(e.d.PostRegistrationPostPersistHooks(r.Context(), ct))).
+			WithField("executors", ExecutorNames(e.d.PostRegistrationPrePersistHooks(r.Context(), ct))).
 			WithField("identity_id", i.ID).
 			WithField("flow_method", ct).
 			Debug("ExecutePostRegistrationPrePersistHook completed successfully.")
@@ -189,24 +196,31 @@ func (e *HookExecutor) PostRegistrationHook(w http.ResponseWriter, r *http.Reque
 					WithRequest(r).
 					WithField("executor", fmt.Sprintf("%T", executor)).
 					WithField("executor_position", k).
-					WithField("executors", PostHookPostPersistExecutorNames(e.d.PostRegistrationPostPersistHooks(r.Context(), ct))).
+					WithField("executors", ExecutorNames(e.d.PostRegistrationPostPersistHooks(r.Context(), ct))).
 					WithField("identity_id", i.ID).
 					WithField("flow_method", ct).
 					Debug("A ExecutePostRegistrationPostPersistHook hook aborted early.")
 				return nil
 			}
 
-			var traits identity.Traits
-			if i != nil {
-				traits = i.Traits
-			}
+			e.d.Logger().
+				WithRequest(r).
+				WithField("executor", fmt.Sprintf("%T", executor)).
+				WithField("executor_position", k).
+				WithField("executors", ExecutorNames(e.d.PostRegistrationPostPersistHooks(r.Context(), ct))).
+				WithField("identity_id", i.ID).
+				WithField("flow_method", ct).
+				WithError(err).
+				Error("ExecutePostRegistrationPostPersistHook hook failed with an error.")
+
+			traits := i.Traits
 			return flow.HandleHookError(w, r, a, traits, ct.ToUiNodeGroup(), err, e.d, e.d)
 		}
 
 		e.d.Logger().WithRequest(r).
 			WithField("executor", fmt.Sprintf("%T", executor)).
 			WithField("executor_position", k).
-			WithField("executors", PostHookPostPersistExecutorNames(e.d.PostRegistrationPostPersistHooks(r.Context(), ct))).
+			WithField("executors", ExecutorNames(e.d.PostRegistrationPostPersistHooks(r.Context(), ct))).
 			WithField("identity_id", i.ID).
 			WithField("flow_method", ct).
 			Debug("ExecutePostRegistrationPostPersistHook completed successfully.")

diff --git a/selfservice/hook/web_hook.go b/selfservice/hook/web_hook.go
@@ -193,6 +193,7 @@ func (e *WebHook) ExecutePostRegistrationPrePersistHook(_ http.ResponseWriter, r
 	if !(gjson.GetBytes(e.conf, "can_interrupt").Bool() || gjson.GetBytes(e.conf, "response.parse").Bool()) {
 		return nil
 	}
+
 	return otelx.WithSpan(req.Context(), "selfservice.hook.WebHook.ExecutePostRegistrationPrePersistHook", func(ctx context.Context) error {
 		return e.execute(ctx, &templateContext{
 			Flow:           flow,
@@ -209,7 +210,15 @@ func (e *WebHook) ExecutePostRegistrationPostPersistHook(_ http.ResponseWriter,
 	if gjson.GetBytes(e.conf, "can_interrupt").Bool() || gjson.GetBytes(e.conf, "response.parse").Bool() {
 		return nil
 	}
-	return otelx.WithSpan(req.Context(), "selfservice.hook.WebHook.ExecutePostRegistrationPostPersistHook", func(ctx context.Context) error {
+
+	// We want to decouple the request from the hook execution, so that the hooks still execute even
+	// if the request is canceled.
+	var cancel context.CancelFunc
+	ctx := trace.ContextWithSpan(context.Background(), trace.SpanFromContext(req.Context()))
+	ctx, cancel = context.WithTimeout(ctx, 5*time.Minute)
+	defer cancel()
+
+	return otelx.WithSpan(ctx, "selfservice.hook.WebHook.ExecutePostRegistrationPostPersistHook", func(ctx context.Context) error {
 		return e.execute(ctx, &templateContext{
 			Flow:           flow,
 			RequestHeaders: req.Header,
@@ -284,7 +293,10 @@ func (e *WebHook) execute(ctx context.Context, data *templateContext) error {
 			// incoming request context is cancelled.
 			//
 			// The webhook will still cancel after 30 seconds as that is the configured timeout for the HTTP client.
+			var cancel context.CancelFunc
 			ctx = trace.ContextWithSpan(context.Background(), trace.SpanFromContext(ctx))
+			ctx, cancel = context.WithTimeout(ctx, 5*time.Minute)
+			defer cancel()
 		}
 		ctx, span := tracer.Start(ctx, "selfservice.webhook")
 		defer otelx.End(span, &finalErr)