[ws-manager-mk2] Enable tracing, add debug logs

Author: WVerlaek

components/ws-manager-mk2/controllers/status.go

@@ -179,7 +179,7 @@ func updateWorkspaceStatus(ctx context.Context, workspace *workspacev1.Workspace
 		workspace.Status.Phase = workspacev1.WorkspacePhaseUnknown
 
 	default:
-		log.Info("cannot determine workspace phase")
+		log.Error("cannot determine workspace phase", "podStatus", pod.Status)
 		workspace.Status.Phase = workspacev1.WorkspacePhaseUnknown
 
 	}

components/ws-manager-mk2/controllers/workspace_controller.go

@@ -108,6 +108,7 @@ func (r *WorkspaceReconciler) Reconcile(ctx context.Context, req ctrl.Request) (
 
 	r.updateMetrics(ctx, &workspace)
 
+	log.V(1).Info("updated workspace status", "status", workspace.Status)
 	err = r.Status().Update(ctx, &workspace)
 	if err != nil {
 		// log.WithValues("status", workspace).Error(err, "unable to update workspace status")

components/ws-manager-mk2/main.go

@@ -20,6 +20,7 @@ import (
 	_ "k8s.io/client-go/plugin/pkg/client/auth"
 
 	grpc_prometheus "github.com/grpc-ecosystem/go-grpc-prometheus"
+	"github.com/prometheus/client_golang/prometheus"
 	"k8s.io/apimachinery/pkg/runtime"
 	utilruntime "k8s.io/apimachinery/pkg/util/runtime"
 	clientgoscheme "k8s.io/client-go/kubernetes/scheme"
@@ -32,6 +33,7 @@ import (
 	common_grpc "github.com/gitpod-io/gitpod/common-go/grpc"
 	"github.com/gitpod-io/gitpod/common-go/log"
 	"github.com/gitpod-io/gitpod/common-go/pprof"
+	"github.com/gitpod-io/gitpod/common-go/tracing"
 	imgbldr "github.com/gitpod-io/gitpod/image-builder/api"
 	regapi "github.com/gitpod-io/gitpod/registry-facade/api"
 	wsmanapi "github.com/gitpod-io/gitpod/ws-manager/api"
@@ -71,6 +73,19 @@ func main() {
 	flag.Parse()
 
 	ctrl.SetLogger(zap.New(zap.UseFlagOptions(&opts)))
+	promrep := &tracing.PromReporter{
+		Operations: map[string]tracing.SpanMetricMapping{
+			"StartWorkspace": {
+				Name:    "wsman_start_workspace",
+				Help:    "time it takes to service a StartWorkspace request",
+				Buckets: prometheus.LinearBuckets(0, 500, 10), // 10 buckets, each 500ms wide
+			},
+		},
+	}
+	closer := tracing.Init("ws-manager-mk2", tracing.WithPrometheusReporter(promrep))
+	if closer != nil {
+		defer closer.Close()
+	}
 
 	cfg, err := getConfig(configFN)
 	if err != nil {

dev/loadgen/pkg/loadgen/executor.go

@@ -211,7 +211,7 @@ func (w *WsmanExecutor) StopAll(ctx context.Context) error {
 
 		_, err := w.C.StopWorkspace(ctx, &stopReq)
 		if err != nil {
-			log.Warnf("failed to stop %s", id)
+			log.Warnf("failed to stop %s: %v", id, err)
 		}
 	}
 

dev/loadgen/pkg/observer/success.go

@@ -73,16 +73,26 @@ func (o *SuccessObserver) Wait(ctx context.Context, expected int) error {
 		case <-ticker.C:
 			o.m.Lock()
 			running := 0
+			stopped := 0
 			for _, ws := range o.workspaces {
-				if ws.Phase == api.WorkspacePhase_RUNNING {
+				switch ws.Phase {
+				case api.WorkspacePhase_RUNNING:
 					running += 1
+				case api.WorkspacePhase_STOPPED:
+					stopped += 1
 				}
 			}
 
 			if float32(running) >= float32(len(o.workspaces))*o.successRate {
 				return nil
 			}
 
+			// Quit early if too many workspaces have stopped already. They'll never become ready.
+			maxRunning := len(o.workspaces) - stopped
+			if float32(maxRunning) < float32(len(o.workspaces))*o.successRate {
+				return fmt.Errorf("too many workspaces in stopped state (%d), will never get enough ready workspaces", stopped)
+			}
+
 			o.m.Unlock()
 		case <-ctx.Done():
 			o.m.Lock()