outposts/ldap: add tracing for LDAP bind and search

Signed-off-by: Jens Langhammer <jens.langhammer@beryju.org>

internal/outpost/ak/global.go

@@ -35,15 +35,17 @@ func doGlobalSetup(config map[string]interface{}) {
 	}
 	log.WithField("buildHash", constants.BUILD()).WithField("version", constants.VERSION).Info("Starting authentik outpost")
 
+	env := config[ConfigErrorReportingEnvironment].(string)
 	var dsn string
 	if config[ConfigErrorReportingEnabled].(bool) {
 		dsn = "https://a579bb09306d4f8b8d8847c052d3a1d3@sentry.beryju.org/8"
-		log.Debug("Error reporting enabled")
+		log.WithField("env", env).Debug("Error reporting enabled")
 	}
 
 	err := sentry.Init(sentry.ClientOptions{
 		Dsn:              dsn,
-		Environment: config[ConfigErrorReportingEnvironment].(string),
+		Environment:      env,
+		TracesSampleRate: 1,
 	})
 	if err != nil {
 		log.Fatalf("sentry.Init: %s", err)

internal/outpost/flow.go

@@ -11,6 +11,7 @@ import (
 	"strconv"
 	"strings"
 
+	"github.com/getsentry/sentry-go"
 	log "github.com/sirupsen/logrus"
 	"goauthentik.io/api"
 	"goauthentik.io/internal/constants"
@@ -34,14 +35,19 @@ const (
 type FlowExecutor struct {
 	Params  url.Values
 	Answers map[StageComponent]string
+	Context context.Context
 
 	api      *api.APIClient
 	flowSlug string
 	log      *log.Entry
 	token    string
+
+	sp *sentry.Span
 }
 
-func NewFlowExecutor(flowSlug string, refConfig *api.Configuration, logFields log.Fields) *FlowExecutor {
+func NewFlowExecutor(ctx context.Context, flowSlug string, refConfig *api.Configuration, logFields log.Fields) *FlowExecutor {
+	rsp := sentry.StartSpan(ctx, "authentik.outposts.flow_executor")
+
 	l := log.WithField("flow", flowSlug).WithFields(logFields)
 	jar, err := cookiejar.New(nil)
 	if err != nil {
@@ -61,10 +67,12 @@ func NewFlowExecutor(flowSlug string, refConfig *api.Configuration, logFields lo
 	return &FlowExecutor{
 		Params:   url.Values{},
 		Answers:  make(map[StageComponent]string),
+		Context:  rsp.Context(),
 		api:      apiClient,
 		flowSlug: flowSlug,
 		log:      l,
 		token:    strings.Split(refConfig.DefaultHeader["Authorization"], " ")[1],
+		sp:       rsp,
 	}
 }
 
@@ -89,6 +97,8 @@ func (fe *FlowExecutor) DelegateClientIP(a net.Addr) {
 }
 
 func (fe *FlowExecutor) CheckApplicationAccess(appSlug string) (bool, error) {
+	acsp := sentry.StartSpan(fe.Context, "authentik.outposts.flow_executor.check_access")
+	defer acsp.Finish()
 	p, _, err := fe.api.CoreApi.CoreApplicationsCheckAccessRetrieve(context.Background(), appSlug).Execute()
 	if !p.Passing {
 		fe.log.Info("Access denied for user")
@@ -113,6 +123,9 @@ func (fe *FlowExecutor) Execute() (bool, error) {
 }
 
 func (fe *FlowExecutor) solveFlowChallenge(depth int) (bool, error) {
+	defer fe.sp.Finish()
+
+	gcsp := sentry.StartSpan(fe.Context, "authentik.outposts.flow_executor.get_challenge")
 	req := fe.api.FlowsApi.FlowsExecutorGet(context.Background(), fe.flowSlug).Query(fe.Params.Encode())
 	challenge, _, err := req.Execute()
 	if err != nil {
@@ -120,6 +133,10 @@ func (fe *FlowExecutor) solveFlowChallenge(depth int) (bool, error) {
 	}
 	ch := challenge.GetActualInstance().(ChallengeInt)
 	fe.log.WithField("component", ch.GetComponent()).WithField("type", ch.GetType()).Debug("Got challenge")
+	gcsp.SetTag("ak_challenge", string(ch.GetType()))
+	gcsp.SetTag("ak_component", ch.GetComponent())
+	gcsp.Finish()
+
 	responseReq := fe.api.FlowsApi.FlowsExecutorSolve(context.Background(), fe.flowSlug).Query(fe.Params.Encode())
 	switch ch.GetComponent() {
 	case string(StageIdentification):
@@ -150,9 +167,15 @@ func (fe *FlowExecutor) solveFlowChallenge(depth int) (bool, error) {
 	default:
 		return false, fmt.Errorf("unsupported challenge type %s", ch.GetComponent())
 	}
+
+	scsp := sentry.StartSpan(fe.Context, "authentik.outposts.flow_executor.solve_challenge")
 	response, _, err := responseReq.Execute()
 	ch = response.GetActualInstance().(ChallengeInt)
 	fe.log.WithField("component", ch.GetComponent()).WithField("type", ch.GetType()).Debug("Got response")
+	scsp.SetTag("ak_challenge", string(ch.GetType()))
+	scsp.SetTag("ak_component", ch.GetComponent())
+	scsp.Finish()
+
 	switch ch.GetComponent() {
 	case string(StageAccessDenied):
 		return false, errors.New("got ak-stage-access-denied")

internal/outpost/ldap/bind.go

@@ -1,9 +1,11 @@
 package ldap
 
 import (
+	"context"
 	"net"
 	"strings"
 
+	"github.com/getsentry/sentry-go"
 	"github.com/google/uuid"
 	"github.com/nmcclain/ldap"
 	log "github.com/sirupsen/logrus"
@@ -15,9 +17,15 @@ type BindRequest struct {
 	id     string
 	conn   net.Conn
 	log    *log.Entry
+	ctx    context.Context
 }
 
 func (ls *LDAPServer) Bind(bindDN string, bindPW string, conn net.Conn) (ldap.LDAPResultCode, error) {
+	span := sentry.StartSpan(context.TODO(), "authentik.providers.ldap.bind",
+		sentry.TransactionName("authentik.providers.ldap.bind"))
+	span.SetTag("user", bindDN)
+	defer span.Finish()
+
 	bindDN = strings.ToLower(bindDN)
 	rid := uuid.New().String()
 	req := BindRequest{
@@ -26,6 +34,7 @@ func (ls *LDAPServer) Bind(bindDN string, bindPW string, conn net.Conn) (ldap.LD
 		conn:   conn,
 		log:    ls.log.WithField("bindDN", bindDN).WithField("requestId", rid).WithField("client", conn.RemoteAddr().String()),
 		id:     rid,
+		ctx:    span.Context(),
 	}
 	req.log.Info("Bind request")
 	for _, instance := range ls.providers {

internal/outpost/ldap/instance_bind.go

@@ -6,6 +6,7 @@ import (
 	"strings"
 	"time"
 
+	"github.com/getsentry/sentry-go"
 	goldap "github.com/go-ldap/ldap/v3"
 	"github.com/nmcclain/ldap"
 	log "github.com/sirupsen/logrus"
@@ -34,7 +35,7 @@ func (pi *ProviderInstance) getUsername(dn string) (string, error) {
 }
 
 func (pi *ProviderInstance) Bind(username string, req BindRequest) (ldap.LDAPResultCode, error) {
-	fe := outpost.NewFlowExecutor(pi.flowSlug, pi.s.ac.Client.GetConfig(), log.Fields{
+	fe := outpost.NewFlowExecutor(req.ctx, pi.flowSlug, pi.s.ac.Client.GetConfig(), log.Fields{
 		"bindDN":    req.BindDN,
 		"client":    req.conn.RemoteAddr().String(),
 		"requestId": req.id,
@@ -53,6 +54,7 @@ func (pi *ProviderInstance) Bind(username string, req BindRequest) (ldap.LDAPRes
 		req.log.WithError(err).Warning("failed to execute flow")
 		return ldap.LDAPResultOperationsError, nil
 	}
+
 	access, err := fe.CheckApplicationAccess(pi.appSlug)
 	if !access {
 		req.log.Info("Access denied for user")
@@ -63,6 +65,7 @@ func (pi *ProviderInstance) Bind(username string, req BindRequest) (ldap.LDAPRes
 		return ldap.LDAPResultOperationsError, nil
 	}
 	req.log.Info("User has access")
+	uisp := sentry.StartSpan(req.ctx, "authentik.providers.ldap.bind.user_info")
 	// Get user info to store in context
 	userInfo, _, err := fe.ApiClient().CoreApi.CoreUsersMeRetrieve(context.Background()).Execute()
 	if err != nil {
@@ -78,7 +81,7 @@ func (pi *ProviderInstance) Bind(username string, req BindRequest) (ldap.LDAPRes
 	if pi.boundUsers[req.BindDN].CanSearch {
 		req.log.WithField("group", cs).Info("Allowed access to search")
 	}
-
+	uisp.Finish()
 	defer pi.boundUsersMutex.Unlock()
 	pi.delayDeleteUserInfo(username)
 	return ldap.LDAPResultSuccess, nil

internal/outpost/ldap/instance_search.go

@@ -6,6 +6,7 @@ import (
 	"fmt"
 	"strings"
 
+	"github.com/getsentry/sentry-go"
 	"github.com/nmcclain/ldap"
 	"goauthentik.io/api"
 )
@@ -17,6 +18,7 @@ func (pi *ProviderInstance) SearchMe(user api.User) (ldap.ServerSearchResult, er
 }
 
 func (pi *ProviderInstance) Search(req SearchRequest) (ldap.ServerSearchResult, error) {
+	accsp := sentry.StartSpan(req.ctx, "authentik.providers.ldap.search.check_access")
 	baseDN := strings.ToLower("," + pi.BaseDN)
 
 	entries := []*ldap.Entry{}
@@ -42,12 +44,15 @@ func (pi *ProviderInstance) Search(req SearchRequest) (ldap.ServerSearchResult,
 		pi.log.Debug("User can't search, showing info about user")
 		return pi.SearchMe(flags.UserInfo)
 	}
+	accsp.Finish()
 
 	switch filterEntity {
 	default:
 		return ldap.ServerSearchResult{ResultCode: ldap.LDAPResultOperationsError}, fmt.Errorf("Search Error: unhandled filter type: %s [%s]", filterEntity, req.Filter)
 	case GroupObjectClass:
+		gapisp := sentry.StartSpan(req.ctx, "authentik.providers.ldap.search.api_group")
 		groups, _, err := pi.s.ac.Client.CoreApi.CoreGroupsList(context.Background()).Execute()
+		gapisp.Finish()
 		if err != nil {
 			return ldap.ServerSearchResult{ResultCode: ldap.LDAPResultOperationsError}, fmt.Errorf("API Error: %s", err)
 		}
@@ -66,7 +71,10 @@ func (pi *ProviderInstance) Search(req SearchRequest) (ldap.ServerSearchResult,
 			entries = append(entries, pi.GroupEntry(pi.APIUserToLDAPGroup(u)))
 		}
 	case UserObjectClass, "":
+		uapisp := sentry.StartSpan(req.ctx, "authentik.providers.ldap.search.api_user")
 		users, _, err := pi.s.ac.Client.CoreApi.CoreUsersList(context.Background()).Execute()
+		uapisp.Finish()
+
 		if err != nil {
 			return ldap.ServerSearchResult{ResultCode: ldap.LDAPResultOperationsError}, fmt.Errorf("API Error: %s", err)
 		}

internal/outpost/ldap/search.go

@@ -1,10 +1,12 @@
 package ldap
 
 import (
+	"context"
 	"errors"
 	"net"
 	"strings"
 
+	"github.com/getsentry/sentry-go"
 	goldap "github.com/go-ldap/ldap/v3"
 	"github.com/google/uuid"
 	"github.com/nmcclain/ldap"
@@ -17,9 +19,15 @@ type SearchRequest struct {
 	id     string
 	conn   net.Conn
 	log    *log.Entry
+	ctx    context.Context
 }
 
 func (ls *LDAPServer) Search(bindDN string, searchReq ldap.SearchRequest, conn net.Conn) (ldap.ServerSearchResult, error) {
+	span := sentry.StartSpan(context.TODO(), "authentik.providers.ldap.search", sentry.TransactionName("authentik.providers.ldap.search"))
+	span.SetTag("user", bindDN)
+
+	defer span.Finish()
+
 	bindDN = strings.ToLower(bindDN)
 	rid := uuid.New().String()
 	req := SearchRequest{
@@ -28,9 +36,19 @@ func (ls *LDAPServer) Search(bindDN string, searchReq ldap.SearchRequest, conn n
 		conn:          conn,
 		log:           ls.log.WithField("bindDN", bindDN).WithField("requestId", rid).WithField("client", conn.RemoteAddr().String()).WithField("filter", searchReq.Filter).WithField("baseDN", searchReq.BaseDN),
 		id:            rid,
+		ctx:           span.Context(),
 	}
 	req.log.Info("Search request")
 
+	defer func() {
+		err := recover()
+		if err == nil {
+			return
+		}
+		log.WithError(err.(error)).Error("recover in serach request")
+		sentry.CaptureException(err.(error))
+	}()
+
 	if searchReq.BaseDN == "" {
 		return ldap.ServerSearchResult{ResultCode: ldap.LDAPResultSuccess}, nil
 	}