From 646c3935f29cb5da8b5a358946f3fbe30e47153e Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?G=C3=BCnther=20Noack?= <gnoack@google.com>
Date: Wed, 17 Jan 2024 07:26:04 -0800
Subject: [PATCH] Litter system service test with debug printf statements

Sorry, this is not a real pull request :) This seems like the easiest way to
reproduce it under the exact same conditions as we have previously been seeing
the test.

PiperOrigin-RevId: 599166456
---
 .../internal/monitoring/resource_usage_monitor.go    | 12 +++++++++++-
 fleetspeak/src/client/system_service_test.go         |  8 +++++++-
 2 files changed, 18 insertions(+), 2 deletions(-)

diff --git a/fleetspeak/src/client/internal/monitoring/resource_usage_monitor.go b/fleetspeak/src/client/internal/monitoring/resource_usage_monitor.go
index 15cb1737..a434a5c3 100644
--- a/fleetspeak/src/client/internal/monitoring/resource_usage_monitor.go
+++ b/fleetspeak/src/client/internal/monitoring/resource_usage_monitor.go
@@ -277,6 +277,8 @@ func (m *ResourceUsageMonitor) Run(ctx context.Context) {
 	ctx, cancel := context.WithCancel(ctx)
 	defer cancel()
 
+	log.Errorf("XYZ Resource Usage Monitor Run()")
+	defer log.Errorf("XYZ Resource Usage Monitor Run() exit")
 	// 1s, 2s, 4s, 8s, 16s, ..., m.maxSamplePeriod, m.maxSamplePeriod, m.maxSamplePeriod, ...
 	backoffPeriod := min(time.Second, m.maxSamplePeriod)
 	backoff := time.NewTimer(backoffPeriod)
@@ -297,6 +299,7 @@ func (m *ResourceUsageMonitor) Run(ctx context.Context) {
 	for {
 		select {
 		case <-ctx.Done():
+			log.Errorf("XYZ Resource Usage Monitor ctx done: %v (cause %v)", ctx.Err(), context.Cause(ctx))
 			return
 		case <-backoff.C:
 			backoffPeriod = min(backoffPeriod*2, m.maxSamplePeriod)
@@ -323,6 +326,7 @@ func (m *ResourceUsageMonitor) Run(ctx context.Context) {
 
 			err = AggregateResourceUsage(prevRU, currRU, ss, &aggRU, false)
 			if err != nil {
+				log.Errorf("XYZ Resource Usage Monitor: agg error: %v", err)
 				m.errorf("aggregation error: %v", err)
 				resetSamples()
 				continue
@@ -333,8 +337,10 @@ func (m *ResourceUsageMonitor) Run(ctx context.Context) {
 
 			// Sample size reached.
 			if numSamplesCollected == ss {
+				log.Errorf("XYZ Resource Usage Monitor: %v samples collected!", numSamplesCollected)
 				debugStatus, err := m.ruf.DebugStatusForPID(m.pid)
 				if err != nil {
+					log.Errorf("XYZ Resource Usage Monitor: fail to get debug status")
 					m.errorf("failed to get debug status for process[%d]: %v", m.pid, err)
 				}
 				rud := &mpb.ResourceUsageData{
@@ -393,13 +399,17 @@ func (m *ResourceUsageMonitor) errorf(format string, a ...any) {
 }
 
 // SendProtoToServer wraps a proto in a fspb.Message and sends it to the server.
-func SendProtoToServer(ctx context.Context, pb proto.Message, msgType string, sc service.Context) error {
+func SendProtoToServer(ctx context.Context, pb proto.Message, msgType string, sc service.Context) (sErr error) {
 	d, err := anypb.New(pb)
 	if err != nil {
 		return err
 	}
+	log.Errorf("XYZ SendProtoToServer()")
+	defer func() { log.Errorf("XYZ SendProtoToServer(): exit: %v", sErr) }()
+
 	ctx, cancel := context.WithTimeout(ctx, 30*time.Second)
 	defer cancel()
+
 	return sc.Send(ctx, service.AckMessage{
 		M: &fspb.Message{
 			Destination: &fspb.Address{ServiceName: "system"},
diff --git a/fleetspeak/src/client/system_service_test.go b/fleetspeak/src/client/system_service_test.go
index 9cf849fa..ccb0ee66 100644
--- a/fleetspeak/src/client/system_service_test.go
+++ b/fleetspeak/src/client/system_service_test.go
@@ -42,10 +42,13 @@ type fakeServiceContext struct {
 }
 
 func (sc fakeServiceContext) Send(ctx context.Context, m service.AckMessage) error {
+	log.Errorf("XYZ fake service context: Send(m) of %+v", m.M)
 	select {
 	case <-ctx.Done():
+		log.Errorf("XYZ fake service context: Send(m) context canceled: %v cause: %v", ctx.Err(), context.Cause(ctx))
 		return ctx.Err()
 	case sc.out <- m.M:
+		log.Errorf("XYZ fake service context: Send(m) OK")
 		return nil
 	}
 }
@@ -98,7 +101,9 @@ func setUpTestEnv(t *testing.T) *testEnv {
 		wg.Add(1)
 		go func() {
 			defer wg.Done()
-			for range out {
+			log.Errorf("XYZ srv.Stop draining out chan")
+			for m := range out {
+				log.Errorf("XYZ Discarded message after stop: %+v", m)
 			}
 		}()
 
@@ -175,6 +180,7 @@ func TestStatsMsg(t *testing.T) {
 	for {
 		select {
 		case res := <-env.ctx.out:
+			log.Errorf("XYZ test res := <-env.ctx.out with res.MessageType=%q", res.MessageType)
 			if res.MessageType != "ResourceUsage" {
 				t.Errorf("Received message of unexpected type '%s'", res.MessageType)
 				continue