Hyang-Ah Hana Kim (Gerrit)

unread,

12:12 PM (11 hours ago) 12:12 PM

to goph...@pubsubhelper.golang.org, Hyang-Ah Hana Kim, golang-co...@googlegroups.com

Hyang-Ah Hana Kim has uploaded the change for review

Commit message

sandbox: instrument container wait time (queue delay)

Added container_wait_count and container_wait_latency metrics to the
backend to measure how long requests wait for a ready container.
This helps detect worker starvation which doesn't show up in CPU metrics.
Added TestGetContainerMetrics to verify the instrumentation.

Change-Id: Icf776d18b6db7607a214af59447aeaa2fa0b072c

Change diff

diff --git a/sandbox/metrics.go b/sandbox/metrics.go
index 849bcce..67988b6 100644
--- a/sandbox/metrics.go
+++ b/sandbox/metrics.go
@@ -13,10 +13,12 @@
 
 var (
 	kContainerCreateSuccess = tag.MustNewKey("go-playground/sandbox/container_create_success")
+	kContainerWaitStatus    = tag.MustNewKey("go-playground/sandbox/container_wait_status")
 	mContainers             = stats.Int64("go-playground/sandbox/container_count", "number of sandbox containers", stats.UnitDimensionless)
 	mUnwantedContainers     = stats.Int64("go-playground/sandbox/unwanted_container_count", "number of sandbox containers that are unexpectedly running", stats.UnitDimensionless)
 	mMaxContainers          = stats.Int64("go-playground/sandbox/max_container_count", "target number of sandbox containers", stats.UnitDimensionless)
 	mContainerCreateLatency = stats.Float64("go-playground/sandbox/container_create_latency", "", stats.UnitMilliseconds)
+	mContainerWaitLatency   = stats.Float64("go-playground/sandbox/container_wait_latency", "latency of waiting for a ready container", stats.UnitMilliseconds)
 
 	containerCount = &view.View{
 		Name:        "go-playground/sandbox/container_count",
@@ -52,6 +54,20 @@
 		Measure:     mContainerCreateLatency,
 		Aggregation: ochttp.DefaultLatencyDistribution,
 	}
+	containerWaitCount = &view.View{
+		Name:        "go-playground/sandbox/container_wait_count",
+		Description: "Number of times we waited for a container",
+		Measure:     mContainerWaitLatency,
+		TagKeys:     []tag.Key{kContainerWaitStatus},
+		Aggregation: view.Count(),
+	}
+	containerWaitLatency = &view.View{
+		Name:        "go-playground/sandbox/container_wait_latency",
+		Description: "Latency distribution of waiting for a container",
+		Measure:     mContainerWaitLatency,
+		TagKeys:     []tag.Key{kContainerWaitStatus},
+		Aggregation: ochttp.DefaultLatencyDistribution,
+	}
 )
 
 // Customizations of ochttp views. Views are updated as follows:
@@ -110,6 +126,8 @@
 	maxContainerCount,
 	containerCreateCount,
 	containerCreationLatency,
+	containerWaitCount,
+	containerWaitLatency,
 	ServerRequestCountView,
 	ServerRequestBytesView,
 	ServerResponseBytesView,
diff --git a/sandbox/sandbox.go b/sandbox/sandbox.go
index 69e093c..645aba1 100644
--- a/sandbox/sandbox.go
+++ b/sandbox/sandbox.go
@@ -425,11 +425,29 @@
 }
 
 func getContainer(ctx context.Context) (*Container, error) {
+	start := time.Now()
+	var err error
+	defer func() {
+		status := "success"
+		if err != nil {
+			if errors.Is(err, context.Canceled) {
+				status = "canceled"
+			} else if errors.Is(err, context.DeadlineExceeded) {
+				status = "deadline_exceeded"
+			} else {
+				status = "error"
+			}
+		}
+		_ = stats.RecordWithTags(context.Background(), []tag.Mutator{tag.Upsert(kContainerWaitStatus, status)},
+			mContainerWaitLatency.M(float64(time.Since(start))/float64(time.Millisecond)))
+	}()
+
 	select {
 	case c := <-readyContainer:
 		return c, nil
 	case <-ctx.Done():
-		return nil, ctx.Err()
+		err = ctx.Err()
+		return nil, err
 	}
 }
 
diff --git a/sandbox/sandbox_test.go b/sandbox/sandbox_test.go
index 939a2c2..1bd352e 100644
--- a/sandbox/sandbox_test.go
+++ b/sandbox/sandbox_test.go
@@ -6,6 +6,7 @@
 
 import (
 	"bytes"
+	"context"
 	"io"
 	"os"
 	"os/exec"
@@ -15,6 +16,7 @@
 	"time"
 
 	"github.com/google/go-cmp/cmp"
+	"go.opencensus.io/stats/view"
 )
 
 func TestLimitedWriter(t *testing.T) {
@@ -268,3 +270,92 @@
 	os.Stdin.Read(buf[:])
 	os.Exit(0)
 }
+
+func TestGetContainerMetrics(t *testing.T) {
+	// Initialize readyContainer channel if not already done (it is usually done in main)
+	if readyContainer == nil {
+		readyContainer = make(chan *Container)
+	}
+
+	// Register views
+	if err := view.Register(views...); err != nil {
+		if !strings.Contains(err.Error(), "already registered") {
+			t.Fatalf("view.Register: %v", err)
+		}
+	}
+
+	// Test case 1: Canceled context
+	ctx, cancel := context.WithCancel(t.Context())
+	cancel() // Cancel immediately
+
+	_, err := getContainer(ctx)
+	if err == nil {
+		t.Fatal("expected error from getContainer with canceled context")
+	}
+
+	rows, err := view.RetrieveData("go-playground/sandbox/container_wait_count")
+	if err != nil {
+		t.Fatalf("RetrieveData failed: %v", err)
+	}
+
+	found := false
+	for _, row := range rows {
+		for _, tg := range row.Tags {
+			if tg.Key == kContainerWaitStatus && tg.Value == "canceled" {
+				found = true
+				countData, ok := row.Data.(*view.CountData)
+				if !ok {
+					t.Fatalf("unexpected data type: %T", row.Data)
+				}
+				if countData.Value < 1 {
+					t.Errorf("expected count >= 1, got %v", countData.Value)
+				}
+			}
+		}
+	}
+	if !found {
+		t.Errorf("metric container_wait_count with tag status=canceled was not recorded. Rows: %v", rows)
+	}
+
+	// Test case 2: Success (container available)
+	c := &Container{
+		name:      "test-container",
+		cancelCmd: func() {},
+	}
+	ctx2 := context.Background()
+	go func() {
+		readyContainer <- c
+	}()
+
+	gotC, err := getContainer(ctx2)
+	if err != nil {
+		t.Fatalf("getContainer failed: %v", err)
+	}
+	if gotC != c {
+		t.Errorf("got container %v, want %v", gotC, c)
+	}
+
+	rows, err = view.RetrieveData("go-playground/sandbox/container_wait_count")
+	if err != nil {
+		t.Fatalf("RetrieveData failed: %v", err)
+	}
+
+	found = false
+	for _, row := range rows {
+		for _, tg := range row.Tags {
+			if tg.Key == kContainerWaitStatus && tg.Value == "success" {
+				found = true
+				countData, ok := row.Data.(*view.CountData)
+				if !ok {
+					t.Fatalf("unexpected data type: %T", row.Data)
+				}
+				if countData.Value < 1 {
+					t.Errorf("expected count >= 1, got %v", countData.Value)
+				}
+			}
+		}
+	}
+	if !found {
+		t.Errorf("metric container_wait_count with tag status=success was not recorded. Rows: %v", rows)
+	}
+}

Change information

Files:

M sandbox/metrics.go
M sandbox/sandbox.go
M sandbox/sandbox_test.go

Change size: M

Delta: 3 files changed, 128 insertions(+), 1 deletion(-)

Open in Gerrit

Related details

Attention set is empty

Submit Requirements:

Code-Review
No-Unresolved-Comments
Review-Enforcement
TryBots-Pass

Inspect html for hidden footers to help with email filtering. To unsubscribe visit settings.

Gerrit

unsatisfied_requirement

satisfied_requirement

open

diffy

Dmitri Shuralyov (Gerrit)

unread,

5:31 PM (6 hours ago) 5:31 PM

to Hyang-Ah Hana Kim, goph...@pubsubhelper.golang.org, Dmitri Shuralyov, Nicholas Husin, golang...@luci-project-accounts.iam.gserviceaccount.com, golang-co...@googlegroups.com

Attention needed from Hyang-Ah Hana Kim and Nicholas Husin

Dmitri Shuralyov voted and added 2 comments

Votes added by Dmitri Shuralyov

Code-Review

+2

2 comments

Patchset-level comments

File-level comment, Patchset 1 (Latest):

Dmitri Shuralyov . resolved

Thanks.

File sandbox/sandbox.go

Line 427, Patchset 1 (Latest):

func getContainer(ctx context.Context) (*Container, error) {
	start := time.Now()
	var err error

Dmitri Shuralyov . unresolved

```suggestion
func getContainer(ctx context.Context) (_ *Container, err error) {
	start := time.Now()
```

Open in Gerrit

Related details

Attention is currently required from:

Hyang-Ah Hana Kim
Nicholas Husin

Submit Requirements:

Code-Review
No-Unresolved-Comments

Review-Enforcement

TryBots-Pass

Inspect html for hidden footers to help with email filtering. To unsubscribe visit settings.

Gerrit

satisfied_requirement

unsatisfied_requirement

open

diffy

Dmitri Shuralyov (Gerrit)

unread,

5:33 PM (6 hours ago) 5:33 PM

to Hyang-Ah Hana Kim, goph...@pubsubhelper.golang.org, Dmitri Shuralyov, Nicholas Husin, golang...@luci-project-accounts.iam.gserviceaccount.com, golang-co...@googlegroups.com

Attention needed from Hyang-Ah Hana Kim and Nicholas Husin

Dmitri Shuralyov voted Code-Review+1

Code-Review

+1

Open in Gerrit

Related details

Attention is currently required from:

Hyang-Ah Hana Kim
Nicholas Husin

Submit Requirements:

Code-Review
No-Unresolved-Comments

Review-Enforcement
TryBots-Pass

Inspect html for hidden footers to help with email filtering. To unsubscribe visit settings.

Gerrit

satisfied_requirement

unsatisfied_requirement

open

diffy

Reply all

Reply to author

Forward

[playground] sandbox: instrument container wait time (queue delay)

Hyang-Ah Hana Kim (Gerrit)

Hyang-Ah Hana Kim has uploaded the change for review

Commit message

Change diff

Change information

Related details

Dmitri Shuralyov (Gerrit)

Dmitri Shuralyov voted and added 2 comments

Votes added by Dmitri Shuralyov

2 comments

Related details

Dmitri Shuralyov (Gerrit)

Dmitri Shuralyov voted Code-Review+1

Related details