Refactor span log helpers

components/common-go/tracing/tracing.go

@@ -135,16 +135,6 @@ func FromTraceID(traceID string) opentracing.SpanContext {
 	return spanCtx
 }
 
-// LogEvent logs an event in the trace.
-func LogEvent(span opentracing.Span, name string) {
-	span.LogFields(tracelog.String("event", name))
-}
-
-// LogKV is a convenience method which logs a single key-value pair to a span
-func LogKV(span opentracing.Span, key, value string) {
-	span.LogFields(tracelog.String(key, value))
-}
-
 // LogError logs an error and marks the span as errornous
 func LogError(span opentracing.Span, err error) {
 	span.LogFields(tracelog.Error(err))
@@ -168,5 +158,5 @@ func LogMessageSafe(span opentracing.Span, name string, req proto.Message) {
 		msg = string(safeReqs)
 	}
 
-	LogKV(span, name, msg)
+	span.LogKV(name, msg)
 }

components/image-builder/pkg/resolve/resolve.go

@@ -60,7 +60,7 @@ func (dr *DockerRegistryResolver) Resolve(ctx context.Context, ref string, opts
 
 	options := getOptions(opts)
 
-	tracing.LogKV(span, "original-ref", ref)
+	span.LogKV("original-ref", ref)
 
 	// The ref may be what Docker calls a "familiar" name, e.g. ubuntu:latest instead of docker.io/library/ubuntu:latest.
 	// To make this a valid digested form we first need to normalize that familiar name.
@@ -71,27 +71,27 @@ func (dr *DockerRegistryResolver) Resolve(ctx context.Context, ref string, opts
 
 	// The reference is already in digest form we don't have to do anything
 	if _, ok := pref.(reference.Canonical); ok {
-		tracing.LogKV(span, "result", ref)
+		span.LogKV("result", ref)
 		return ref, nil
 	}
 
 	nref := pref.String()
-	tracing.LogKV(span, "normalized-ref", nref)
+	span.LogKV("normalized-ref", nref)
 
 	manifest, err := dr.Client.DistributionInspect(ctx, nref, options.Auth)
 	// do not wrap this error so that others can check if this IsErrNotFound (Docker SDK doesn't use Go2 error values)
 	if err != nil {
 		return "", err
 	}
-	tracing.LogEvent(span, "got manifest")
+	span.LogKV("event", "got manifest")
 
 	cres, err := reference.WithDigest(pref, manifest.Descriptor.Digest)
 	if err != nil {
 		return "", err
 	}
 	res = cres.String()
 
-	tracing.LogKV(span, "result", res)
+	span.LogKV("result", res)
 
 	return res, nil
 }

components/ws-manager/pkg/manager/manager.go

@@ -152,26 +152,26 @@ func (m *Manager) StartWorkspace(ctx context.Context, req *api.StartWorkspaceReq
 	if exists {
 		return nil, xerrors.Errorf("workspace %s exists already", req.Id)
 	}
-	tracing.LogEvent(span, "workspace does not exist")
+	span.LogKV("event", "workspace does not exist")
 	err = validateStartWorkspaceRequest(req)
 	if err != nil {
 		return nil, xerrors.Errorf("cannot start workspace: %w", err)
 	}
-	tracing.LogEvent(span, "validated workspace start request")
+	span.LogKV("event", "validated workspace start request")
 	// create the objects required to start the workspace pod/service
 	startContext, err := m.newStartWorkspaceContext(ctx, req)
 	if err != nil {
 		return nil, xerrors.Errorf("cannot create context: %w", err)
 	}
-	tracing.LogEvent(span, "created start workspace context")
+	span.LogKV("event", "created start workspace context")
 	clog.Info("starting new workspace")
 	// we must create the workspace pod first to make sure we don't clean up the services or configmap we're about to create
 	// because they're "dangling".
 	pod, err := m.createWorkspacePod(startContext)
 	if err != nil {
 		return nil, xerrors.Errorf("cannot create workspace pod: %w", err)
 	}
-	tracing.LogEvent(span, "pod description created")
+	span.LogKV("event", "pod description created")
 	err = m.Clientset.Create(ctx, pod)
 	if err != nil {
 		m, _ := json.Marshal(pod)
@@ -180,7 +180,7 @@ func (m *Manager) StartWorkspace(ctx context.Context, req *api.StartWorkspaceReq
 		clog.WithError(err).WithField("req", req).WithField("pod", safePod).Error("was unable to start workspace")
 		return nil, err
 	}
-	tracing.LogEvent(span, "pod created")
+	span.LogKV("event", "pod created")
 
 	// only regular workspaces get a service, the others are fine with just pod
 	okResponse := &api.StartWorkspaceResponse{Url: startContext.WorkspaceURL}
@@ -224,7 +224,7 @@ func (m *Manager) StartWorkspace(ctx context.Context, req *api.StartWorkspaceReq
 		// could not create Theia service
 		return nil, xerrors.Errorf("cannot create workspace's Theia service: %w", err)
 	}
-	tracing.LogEvent(span, "theia service created")
+	span.LogKV("event", "theia service created")
 
 	// if we have ports configured already, create the ports service
 	if len(req.Spec.Ports) > 0 {
@@ -239,7 +239,7 @@ func (m *Manager) StartWorkspace(ctx context.Context, req *api.StartWorkspaceReq
 			// could not create ports service
 			return nil, xerrors.Errorf("cannot create workspace's public service: %w", err)
 		}
-		tracing.LogEvent(span, "ports service created")
+		span.LogKV("event", "ports service created")
 	}
 
 	m.metrics.OnWorkspaceStarted(req.Type)
@@ -397,7 +397,7 @@ func (m *Manager) stopWorkspace(ctx context.Context, workspaceID string, gracePe
 			PropagationPolicy:  &propagationPolicy,
 		},
 	)
-	tracing.LogEvent(span, "theia service deleted")
+	span.LogKV("event", "theia service deleted")
 
 	portsServiceErr := m.Clientset.Delete(ctx, &corev1.Service{
 		ObjectMeta: metav1.ObjectMeta{
@@ -410,7 +410,7 @@ func (m *Manager) stopWorkspace(ctx context.Context, workspaceID string, gracePe
 			PropagationPolicy:  &propagationPolicy,
 		},
 	)
-	tracing.LogEvent(span, "ports service deleted")
+	span.LogKV("event", "ports service deleted")
 
 	podErr := m.Clientset.Delete(ctx,
 		&corev1.Pod{
@@ -424,7 +424,7 @@ func (m *Manager) stopWorkspace(ctx context.Context, workspaceID string, gracePe
 			PropagationPolicy:  &propagationPolicy,
 		},
 	)
-	tracing.LogEvent(span, "pod deleted")
+	span.LogKV("event", "pod deleted")
 
 	if podErr != nil {
 		return xerrors.Errorf("stopWorkspace: %w", podErr)
@@ -621,7 +621,7 @@ func (m *Manager) ControlPort(ctx context.Context, req *api.ControlPortRequest)
 		if err != nil {
 			return nil, xerrors.Errorf("cannot create service: %w", err)
 		}
-		tracing.LogEvent(span, "port service created")
+		span.LogKV("event", "port service created")
 
 		service = *newService
 
@@ -647,7 +647,7 @@ func (m *Manager) ControlPort(ctx context.Context, req *api.ControlPortRequest)
 				return nil, err
 			}
 		}
-		tracing.LogEvent(span, "host available")
+		span.LogKV("event", "host available")
 
 		// we've successfully exposed the port by creating the service
 		err = notifyStatusChange()
@@ -699,7 +699,7 @@ func (m *Manager) ControlPort(ctx context.Context, req *api.ControlPortRequest)
 			PropagationPolicy: &propagationPolicy,
 		})
 
-		tracing.LogEvent(span, "port service deleted")
+		span.LogKV("event", "port service deleted")
 	} else {
 		// we've made it here which means we need to actually patch the service
 		service.Spec = *spec
@@ -725,7 +725,7 @@ func (m *Manager) ControlPort(ctx context.Context, req *api.ControlPortRequest)
 		if err != nil {
 			return nil, xerrors.Errorf("cannot update service: %w", err)
 		}
-		tracing.LogEvent(span, "port service updated")
+		span.LogKV("event", "port service updated")
 	}
 	if err != nil {
 		return nil, xerrors.Errorf("cannot control port: %w", err)
@@ -781,7 +781,7 @@ func (m *Manager) DescribeWorkspace(ctx context.Context, req *api.DescribeWorksp
 		return nil, status.Errorf(codes.Internal, "cannot get workspace status: %q", err)
 	}
 	tracing.ApplyOWI(span, wsk8s.GetOWIFromObject(&pod.ObjectMeta))
-	tracing.LogEvent(span, "get pod")
+	span.LogKV("event", "get pod")
 
 	wso, err := m.getWorkspaceObjects(ctx, pod)
 	if err != nil {

components/ws-manager/pkg/manager/manager_ee.go

@@ -36,7 +36,7 @@ func (m *Manager) TakeSnapshot(ctx context.Context, req *api.TakeSnapshotRequest
 		return nil, status.Errorf(codes.Internal, "cannot get workspace status: %q", err)
 	}
 	tracing.ApplyOWI(span, wsk8s.GetOWIFromObject(&pod.ObjectMeta))
-	tracing.LogEvent(span, "get pod")
+	span.LogKV("event", "get pod")
 
 	wso, err := m.getWorkspaceObjects(ctx, pod)
 	if err != nil {
@@ -82,7 +82,7 @@ func (m *Manager) ControlAdmission(ctx context.Context, req *api.ControlAdmissio
 		return nil, status.Errorf(codes.Internal, "cannot get workspace status: %q", err)
 	}
 	tracing.ApplyOWI(span, wsk8s.GetOWIFromObject(&pod.ObjectMeta))
-	tracing.LogEvent(span, "get pod")
+	span.LogKV("event", "get pod")
 
 	wso, err := m.getWorkspaceObjects(ctx, pod)
 	if err != nil {

components/ws-manager/pkg/manager/monitor.go

@@ -327,7 +327,7 @@ func (m *Monitor) actOnPodEvent(ctx context.Context, status *api.WorkspaceStatus
 		}
 
 		if !wso.IsWorkspaceHeadless() {
-			tracing.LogEvent(span, "removeTraceAnnotation")
+			span.LogKV("event", "removeTraceAnnotation")
 			// once a regular workspace is up and running, we'll remove the traceID information so that the parent span
 			// ends once the workspace has started
 			err := m.manager.markWorkspace(ctx, workspaceID, deleteMark(wsk8s.TraceIDAnnotation))
@@ -556,7 +556,7 @@ func (m *Monitor) traceWorkspace(occasion string, wso *workspaceObjects) opentra
 	if wso.Pod != nil {
 		tracing.ApplyOWI(span, wsk8s.GetOWIFromObject(&wso.Pod.ObjectMeta))
 	}
-	tracing.LogKV(span, "occasion", occasion)
+	span.LogKV("occasion", occasion)
 
 	// OpenTracing does not support creating a span from a SpanContext https://github.com/opentracing/specification/issues/81.
 	// Until that changes we just finish the span immediately after calling on-change.
@@ -584,7 +584,7 @@ func (m *Monitor) waitForWorkspaceReady(ctx context.Context, pod *corev1.Pod) (e
 		return
 	}
 
-	tracing.LogEvent(span, "probeDone")
+	span.LogKV("event", "probeDone")
 	probeResult := *r
 	if probeResult == WorkspaceProbeStopped {
 		// Workspace probe was stopped most likely because the workspace itself was stopped.
@@ -629,7 +629,7 @@ func (m *Monitor) waitForWorkspaceReady(ctx context.Context, pod *corev1.Pod) (e
 	m.initializerMapLock.Lock()
 	delete(m.initializerMap, pod.Name)
 	m.initializerMapLock.Unlock()
-	tracing.LogEvent(span, "contentInitDone")
+	span.LogKV("event", "contentInitDone")
 
 	// workspace is ready - mark it as such
 	err = m.manager.markWorkspace(ctx, workspaceID, deleteMark(workspaceNeverReadyAnnotation))
@@ -918,7 +918,7 @@ func (m *Monitor) finalizeWorkspaceContent(ctx context.Context, wso *workspaceOb
 		gitStatus   *csapi.GitStatus
 	)
 	for i := 0; i < wsdaemonMaxAttempts; i++ {
-		tracing.LogKV(span, "attempt", strconv.Itoa(i))
+		span.LogKV("attempt", strconv.Itoa(i))
 		didSometing, gs, err := doFinalize()
 		if !didSometing {
 			// someone else is managing finalization process ... we don't have to bother

components/ws-manager/pkg/manager/probe.go

@@ -79,25 +79,25 @@ func (p *WorkspaceReadyProbe) Run(ctx context.Context) WorkspaceProbeResult {
 			return WorkspaceProbeStopped
 		}
 
-		tracing.LogEvent(span, "probe start")
+		span.LogKV("event", "probe start")
 		resp, err := client.Get(p.readyURL)
 
 		if err != nil {
 			urlerr, ok := err.(*url.Error)
 			if !ok || !urlerr.Timeout() {
-				tracing.LogKV(span, "response", "error")
+				span.LogKV("response", "error")
 				log.WithError(err).Debug("got a non-timeout error during workspace probe")
 				time.Sleep(p.RetryDelay)
 				continue
 			}
 
 			// we've timed out - do not log this as it would spam the logs for no good reason
-			tracing.LogKV(span, "response", "timeout")
+			span.LogKV("response", "timeout")
 			continue
 		}
 
 		if resp.StatusCode != http.StatusOK {
-			tracing.LogKV(span, "response", fmt.Sprintf("%v", resp.StatusCode))
+			span.LogKV("response", fmt.Sprintf("%v", resp.StatusCode))
 			log.WithField("url", p.readyURL).WithField("status", resp.StatusCode).Debug("workspace did not respond to ready probe with OK status")
 			time.Sleep(p.RetryDelay)
 			continue