Clone Sentry Hubs

to make error-trace-mapping concurrency-proof.

internal/api/environments.go

@@ -8,6 +8,7 @@ import (
 	"net/http"
 	"strconv"
 
+	"github.com/getsentry/sentry-go"
 	"github.com/gorilla/mux"
 	"github.com/openHPI/poseidon/internal/environment"
 	"github.com/openHPI/poseidon/internal/runner"
@@ -122,7 +123,7 @@ func (e *EnvironmentController) createOrUpdate(writer http.ResponseWriter, reque
 	}
 
 	var created bool
-	logging.StartSpan(request.Context(), "api.env.update", "Create Environment", func(ctx context.Context) {
+	logging.StartSpan(request.Context(), "api.env.update", "Create Environment", func(ctx context.Context, _ *sentry.Span) {
 		created, err = e.manager.CreateOrUpdate(ctx, environmentID, *req)
 	})
 	if err != nil {

internal/api/runners.go

@@ -10,6 +10,7 @@ import (
 	"strconv"
 	"strings"
 
+	"github.com/getsentry/sentry-go"
 	"github.com/google/uuid"
 	"github.com/gorilla/mux"
 	nomadApi "github.com/hashicorp/nomad/api"
@@ -73,7 +74,7 @@ func (r *RunnerController) provide(writer http.ResponseWriter, request *http.Req
 		nextRunner runner.Runner
 		err        error
 	)
-	logging.StartSpan(request.Context(), "api.runner.claim", "Claim Runner", func(_ context.Context) {
+	logging.StartSpan(request.Context(), "api.runner.claim", "Claim Runner", func(_ context.Context, _ *sentry.Span) {
 		nextRunner, err = r.manager.Claim(environmentID, runnerRequest.InactivityTimeout)
 	})
 	if err != nil {
@@ -111,7 +112,7 @@ func (r *RunnerController) listFileSystem(writer http.ResponseWriter, request *h
 	}
 
 	writer.Header().Set("Content-Type", "application/json")
-	logging.StartSpan(request.Context(), "api.fs.list", "List File System", func(ctx context.Context) {
+	logging.StartSpan(request.Context(), "api.fs.list", "List File System", func(ctx context.Context, _ *sentry.Span) {
 		err = targetRunner.ListFileSystem(ctx, path, recursive, writer, privilegedExecution)
 	})
 	if errors.Is(err, runner.ErrFileNotFound) {
@@ -136,7 +137,7 @@ func (r *RunnerController) updateFileSystem(writer http.ResponseWriter, request
 	targetRunner, _ := runner.FromContext(request.Context())
 
 	var err error
-	logging.StartSpan(request.Context(), "api.fs.update", "Update File System", func(ctx context.Context) {
+	logging.StartSpan(request.Context(), "api.fs.update", "Update File System", func(ctx context.Context, _ *sentry.Span) {
 		err = targetRunner.UpdateFileSystem(ctx, fileCopyRequest)
 	})
 
@@ -168,7 +169,7 @@ func (r *RunnerController) fileContent(writer http.ResponseWriter, request *http
 	}
 
 	writer.Header().Set("Content-Disposition", "attachment; filename=\""+path+"\"")
-	logging.StartSpan(request.Context(), "api.fs.read", "File Content", func(ctx context.Context) {
+	logging.StartSpan(request.Context(), "api.fs.read", "File Content", func(ctx context.Context, _ *sentry.Span) {
 		err = targetRunner.GetFileContent(ctx, path, writer, privilegedExecution)
 	})
 	if errors.Is(err, runner.ErrFileNotFound) {
@@ -220,7 +221,7 @@ func (r *RunnerController) execute(writer http.ResponseWriter, request *http.Req
 	}
 	executionID := newUUID.String()
 
-	logging.StartSpan(request.Context(), "api.runner.exec", "Store Execution", func(_ context.Context) {
+	logging.StartSpan(request.Context(), "api.runner.exec", "Store Execution", func(_ context.Context, _ *sentry.Span) {
 		targetRunner.StoreExecution(executionID, executionRequest)
 	})
 	webSocketURL := url.URL{
@@ -265,7 +266,7 @@ func (r *RunnerController) delete(writer http.ResponseWriter, request *http.Requ
 	targetRunner, _ := runner.FromContext(request.Context())
 
 	var err error
-	logging.StartSpan(request.Context(), "api.runner.delete", "Return Runner", func(_ context.Context) {
+	logging.StartSpan(request.Context(), "api.runner.delete", "Return Runner", func(_ context.Context, _ *sentry.Span) {
 		err = r.manager.Return(targetRunner)
 	})
 	if err != nil {

internal/api/websocket.go

@@ -6,6 +6,7 @@ import (
 	"fmt"
 	"net/http"
 
+	"github.com/getsentry/sentry-go"
 	"github.com/gorilla/websocket"
 	"github.com/openHPI/poseidon/internal/api/ws"
 	"github.com/openHPI/poseidon/internal/runner"
@@ -103,7 +104,7 @@ func (r *RunnerController) connectToRunner(writer http.ResponseWriter, request *
 	log.WithContext(proxyCtx).
 		WithField("executionID", logging.RemoveNewlineSymbol(executionID)).
 		Info("Running execution")
-	logging.StartSpan(request.Context(), "api.runner.connect", "Execute Interactively", func(ctx context.Context) {
+	logging.StartSpan(request.Context(), "api.runner.connect", "Execute Interactively", func(ctx context.Context, _ *sentry.Span) {
 		exit, cancel, err := targetRunner.ExecuteInteractively(ctx, executionID,
 			proxy.Input, proxy.Output.StdOut(), proxy.Output.StdErr())
 		if err != nil {

internal/environment/nomad_manager.go

@@ -8,6 +8,7 @@ import (
 	"os"
 	"time"
 
+	"github.com/getsentry/sentry-go"
 	nomadApi "github.com/hashicorp/nomad/api"
 	"github.com/hashicorp/nomad/nomad/structs"
 	"github.com/openHPI/poseidon/internal/nomad"
@@ -158,15 +159,15 @@ func (m *NomadEnvironmentManager) CreateOrUpdate(
 	m.runnerManager.StoreEnvironment(environment)
 
 	// Register template Job with Nomad.
-	logging.StartSpan(ctx, "env.update.register", "Register Environment", func(_ context.Context) {
+	logging.StartSpan(ctx, "env.update.register", "Register Environment", func(_ context.Context, _ *sentry.Span) {
 		err = environment.Register()
 	})
 	if err != nil {
 		return false, fmt.Errorf("error registering template job in API: %w", err)
 	}
 
 	// Launch idle runners based on the template job.
-	logging.StartSpan(ctx, "env.update.poolsize", "Apply Prewarming Pool Size", func(_ context.Context) {
+	logging.StartSpan(ctx, "env.update.poolsize", "Apply Prewarming Pool Size", func(_ context.Context, _ *sentry.Span) {
 		err = environment.ApplyPrewarmingPoolSize()
 	})
 	if err != nil {

internal/nomad/api_querier.go

@@ -98,7 +98,7 @@ func (nc *nomadAPIClient) Execute(ctx context.Context, runnerID string, cmd stri
 	log.WithContext(ctx).WithField("command", strings.ReplaceAll(cmd, "\n", "")).Trace("Requesting Nomad Exec")
 	var allocations []*nomadApi.AllocationListStub
 	var err error
-	logging.StartSpan(ctx, "nomad.execute.list", "List Allocations for id", func(_ context.Context) {
+	logging.StartSpan(ctx, "nomad.execute.list", "List Allocations for id", func(_ context.Context, _ *sentry.Span) {
 		allocations, _, err = nc.client.Jobs().Allocations(runnerID, false, nil)
 	})
 	if err != nil {
@@ -109,39 +109,45 @@ func (nc *nomadAPIClient) Execute(ctx context.Context, runnerID string, cmd stri
 	}
 
 	var allocation *nomadApi.Allocation
-	logging.StartSpan(ctx, "nomad.execute.info", "List Data of Allocation", func(_ context.Context) {
+	logging.StartSpan(ctx, "nomad.execute.info", "List Data of Allocation", func(_ context.Context, _ *sentry.Span) {
 		allocation, _, err = nc.client.Allocations().Info(allocations[0].ID, nil)
 	})
 	if err != nil {
 		return 1, fmt.Errorf("error retrieving allocation info: %w", err)
 	}
 
 	var exitCode int
-	span := sentry.StartSpan(ctx, "nomad.execute.exec")
-	defer span.Finish()
-	span.Description = "Execute Command in Allocation"
-	span.SetData("command", cmd)
+	logging.StartSpan(ctx, "nomad.execute.exec", "Execute Command in Allocation", func(ctx context.Context, span *sentry.Span) {
+		span.SetData("command", cmd)
+		exitCode, err = nc.executeInAllocation(ctx, cmd, allocation, tty, stdin, stdout, stderr)
+	})
+
+	return exitCode, err
+}
 
-	debugWriter := NewSentryDebugWriter(span.Context(), stdout)
+func (nc *nomadAPIClient) executeInAllocation(ctx context.Context, cmd string, allocation *nomadApi.Allocation, tty bool,
+	stdin io.Reader, stdout io.Writer, stderr io.Writer,
+) (int, error) {
+	debugWriter := NewSentryDebugWriter(ctx, stdout)
 	commands := []string{"/bin/bash", "-c", cmd}
-	exitCode, err = nc.client.Allocations().
-		Exec(span.Context(), allocation, TaskName, tty, commands, stdin, debugWriter, stderr, nil, nil)
+	exitCode, err := nc.client.Allocations().
+		Exec(ctx, allocation, TaskName, tty, commands, stdin, debugWriter, stderr, nil, nil)
 	debugWriter.Close(exitCode)
 
 	switch {
 	case err == nil:
 		return exitCode, nil
 	case websocket.IsCloseError(errors.Unwrap(err), websocket.CloseNormalClosure):
-		log.WithContext(span.Context()).WithError(err).Info("The exit code could not be received.")
+		log.WithContext(ctx).WithError(err).Info("The exit code could not be received.")
 		return 0, nil
 	case errors.Is(err, context.Canceled):
-		log.WithContext(span.Context()).Debug("Execution canceled by context")
+		log.WithContext(ctx).Debug("Execution canceled by context")
 		return 0, nil
 	case errors.Is(err, io.ErrUnexpectedEOF), strings.Contains(err.Error(), io.ErrUnexpectedEOF.Error()):
 		// The unexpected EOF is a generic Nomad error. However, our investigations have shown that all the current
 		// events of this error are caused by fsouza/go-dockerclient#1076. Because this error happens at the very end,
 		// it does not affect the functionality. Therefore, we don't propagate the error.
-		log.WithContext(span.Context()).WithError(err).
+		log.WithContext(ctx).WithError(err).
 			WithField(logging.SentryFingerprintFieldKey, []string{"nomad-unexpected-eof"}).Warn("Unexpected EOF for Execute")
 		return 0, nil
 	case strings.Contains(err.Error(), "Unknown allocation"):

internal/nomad/nomad.go

@@ -9,6 +9,7 @@ import (
 	"strings"
 	"time"
 
+	"github.com/getsentry/sentry-go"
 	nomadApi "github.com/hashicorp/nomad/api"
 	"github.com/hashicorp/nomad/nomad/structs"
 	influxdb2 "github.com/influxdata/influxdb-client-go/v2"
@@ -641,7 +642,7 @@ func (a *APIClient) executeCommandInteractivelyWithStderr(ctx context.Context, a
 		defer cancel()
 
 		// Catch stderr in separate execution.
-		logging.StartSpan(ctx, "nomad.execute.stderr", "Execution for separate StdErr", func(ctx context.Context) {
+		logging.StartSpan(ctx, "nomad.execute.stderr", "Execution for separate StdErr", func(ctx context.Context, _ *sentry.Span) {
 			exit, err := a.Execute(ctx, allocationID, prepareCommandTTYStdErr(currentNanoTime, privilegedExecution), true,
 				nullio.Reader{Ctx: readingContext}, stderr, io.Discard)
 			if err != nil {
@@ -654,7 +655,7 @@ func (a *APIClient) executeCommandInteractivelyWithStderr(ctx context.Context, a
 	command = prepareCommandTTY(command, currentNanoTime, privilegedExecution)
 	var exit int
 	var err error
-	logging.StartSpan(ctx, "nomad.execute.tty", "Interactive Execution", func(ctx context.Context) {
+	logging.StartSpan(ctx, "nomad.execute.tty", "Interactive Execution", func(ctx context.Context, _ *sentry.Span) {
 		exit, err = a.Execute(ctx, allocationID, command, true, stdin, stdout, io.Discard)
 	})
 

internal/nomad/sentry_debug_writer.go

@@ -9,6 +9,7 @@ import (
 	"time"
 
 	"github.com/getsentry/sentry-go"
+	"github.com/openHPI/poseidon/pkg/logging"
 )
 
 var (
@@ -35,6 +36,7 @@ type SentryDebugWriter struct {
 }
 
 func NewSentryDebugWriter(ctx context.Context, target io.Writer) *SentryDebugWriter {
+	ctx = logging.CloneSentryHub(ctx)
 	span := sentry.StartSpan(ctx, "nomad.execute.connect")
 	span.Description = "/bin/bash -c"
 	return &SentryDebugWriter{

pkg/logging/sentry_hook.go

@@ -80,9 +80,19 @@ func (hook *SentryHook) Levels() []logrus.Level {
 	}
 }
 
-func StartSpan(ctx context.Context, op, description string, callback func(context.Context)) {
-	span := sentry.StartSpan(ctx, op)
+func StartSpan(ctx context.Context, op, description string, callback func(context.Context, *sentry.Span)) {
+	innerCtx := CloneSentryHub(ctx)
+	span := sentry.StartSpan(innerCtx, op)
 	span.Description = description
 	defer span.Finish()
-	callback(span.Context())
+	callback(span.Context(), span)
+}
+
+func CloneSentryHub(ctx context.Context) context.Context {
+	hub := sentry.GetHubFromContext(ctx)
+	if hub == nil {
+		hub = sentry.CurrentHub()
+	}
+	innerHub := hub.Clone()
+	return sentry.SetHubOnContext(ctx, innerHub)
 }

pkg/nullio/ls2json.go

@@ -93,7 +93,8 @@ func (w *Ls2JsonWriter) initializeJSONObject() (count int, err error) {
 			err = fmt.Errorf("could not write to target: %w", err)
 		} else {
 			w.jsonStartSent = true
-			w.sentrySpan = sentry.StartSpan(w.Ctx, "nullio.init")
+			ctx := logging.CloneSentryHub(w.Ctx)
+			w.sentrySpan = sentry.StartSpan(ctx, "nullio.init")
 			w.sentrySpan.Description = "Forwarding"
 		}
 	}