adding efficient polling to waitForStepsToFinish

The current waitForStepsToFinish implementation is a classic busy-wait.
It checks for file existence without any sleep, resulting in a high
CPU usage. Adding a profile with a unit test to show that almost all
time is spent in system calls with a high total sample count. This led to
execssive CPU usage by the sidecar even when just waiting.

The function now sleeps 100ms between checks, drastically reducing the
frequency. The sidecar now uses minimal CPU while waiting.

Signed-off-by: Priti Desai <pdesai@us.ibm.com>

Author: pritidesai

config/config-defaults.yaml

@@ -149,3 +149,11 @@ data:
     #     limits:
     #       memory: "256Mi"
     #       cpu: "500m"
+
+    # default-sidecar-log-polling-interval specifies the polling interval for the Tekton sidecar log results container.
+    # This controls how frequently the sidecar checks for step completion files written by steps in a TaskRun.
+    # Lower values (e.g., "10ms") make the sidecar more responsive but may increase CPU usage; higher values (e.g., "1s")
+    # reduce resource usage but may delay result collection.
+    # This value is used by the sidecar-tekton-log-results container and can be tuned for performance or test scenarios.
+    # Example values: "100ms", "500ms", "1s"
+    default-sidecar-log-polling-interval: "100ms"

docs/additional-configs.md

@@ -243,6 +243,7 @@ The example below customizes the following:
 - the default maximum combinations of `Parameters` in a `Matrix` that can be used to fan out a `PipelineTask`. For
 more information, see [`Matrix`](matrix.md).
 - the default resolver type to `git`.
+- the default polling interval for the sidecar log results container via `default-sidecar-log-polling-interval`.
 
 ```yaml
 apiVersion: v1
@@ -260,8 +261,26 @@ data:
     emptyDir: {}
   default-max-matrix-combinations-count: "1024"
   default-resolver-type: "git"
+  default-sidecar-log-polling-interval: "100ms"
 ```
 
+### `default-sidecar-log-polling-interval`
+
+The `default-sidecar-log-polling-interval` key in the `config-defaults` ConfigMap specifies how frequently the Tekton
+sidecar log results container polls for step completion files written by steps in a TaskRun. Lower values (e.g., `10ms`)
+make the sidecar more responsive but may increase CPU usage; higher values (e.g., `1s`) reduce resource usage but may
+delay result collection. This value is used by the `sidecar-tekton-log-results` container and can be tuned for performance
+or test scenarios.
+
+**Example values:**
+- `100ms` (default)
+- `500ms`
+- `1s`
+- `10ms` (for fast polling in tests)
+
+**Note:** The `default-sidecar-log-polling-interval` setting is only applicable when results are created using the
+[sidecar approach](#enabling-larger-results-using-sidecar-logs).
+
 **Note:** The `_example` key in the provided [config-defaults.yaml](./../config/config-defaults.yaml)
 file lists the keys you can customize along with their default values.
 

internal/sidecarlogresults/sidecarlogresults.go

@@ -26,6 +26,7 @@ import (
 	"os"
 	"path/filepath"
 	"strings"
+	"time"
 
 	"github.com/tektoncd/pipeline/pkg/apis/config"
 	"github.com/tektoncd/pipeline/pkg/apis/pipeline"
@@ -74,7 +75,7 @@ func encode(w io.Writer, v any) error {
 	return json.NewEncoder(w).Encode(v)
 }
 
-func waitForStepsToFinish(runDir string) error {
+func waitForStepsToFinish(runDir string, sleepInterval time.Duration) error {
 	steps := make(map[string]bool)
 	files, err := os.ReadDir(runDir)
 	if err != nil {
@@ -103,6 +104,9 @@ func waitForStepsToFinish(runDir string) error {
 				return err
 			}
 		}
+		if sleepInterval > 0 {
+			time.Sleep(sleepInterval)
+		}
 	}
 	return nil
 }
@@ -143,7 +147,15 @@ func readResults(resultsDir, resultFile, stepName string, resultType SidecarLogR
 // in their results path and prints them in a structured way to its
 // stdout so that the reconciler can parse those logs.
 func LookForResults(w io.Writer, runDir string, resultsDir string, resultNames []string, stepResultsDir string, stepResults map[string][]string) error {
-	if err := waitForStepsToFinish(runDir); err != nil {
+	intervalStr := os.Getenv("SIDECAR_LOG_POLLING_INTERVAL")
+	if intervalStr == "" {
+		intervalStr = "100ms"
+	}
+	interval, err := time.ParseDuration(intervalStr)
+	if err != nil {
+		interval = 100 * time.Millisecond
+	}
+	if err := waitForStepsToFinish(runDir, interval); err != nil {
 		return fmt.Errorf("error while waiting for the steps to finish  %w", err)
 	}
 	results := make(chan SidecarLogResult)
@@ -205,7 +217,15 @@ func LookForResults(w io.Writer, runDir string, resultsDir string, resultNames [
 // If the provenance file exists, the function extracts artifact information, formats it into a
 // JSON string, and encodes it for output alongside relevant metadata (step name, artifact type).
 func LookForArtifacts(w io.Writer, names []string, runDir string) error {
-	if err := waitForStepsToFinish(runDir); err != nil {
+	intervalStr := os.Getenv("SIDECAR_LOG_POLLING_INTERVAL")
+	if intervalStr == "" {
+		intervalStr = "100ms"
+	}
+	interval, err := time.ParseDuration(intervalStr)
+	if err != nil {
+		interval = 100 * time.Millisecond
+	}
+	if err := waitForStepsToFinish(runDir, interval); err != nil {
 		return err
 	}
 

internal/sidecarlogresults/sidecarlogresults_test.go

@@ -23,9 +23,11 @@ import (
 	"fmt"
 	"os"
 	"path/filepath"
+	"runtime/pprof"
 	"sort"
 	"strings"
 	"testing"
+	"time"
 
 	"github.com/google/go-cmp/cmp"
 	v1 "github.com/tektoncd/pipeline/pkg/apis/pipeline/v1"
@@ -608,6 +610,66 @@ func TestExtractStepAndResultFromSidecarResultName_Error(t *testing.T) {
 	}
 }
 
+// TestWaitForStepsToFinish_Profile ensures that waitForStepsToFinish correctly waits for all step output files to appear before returning
+// The test creates a file called cpu.prof and starts Go's CPU profiler
+// A temporary directory is created to simulate the Tekton step run directory.
+// The test creates a large number of subdirectories e.g. step0, step1, ..., each representing a step in a TaskRun
+// A goroutine is started that, one by one, writes an out file in each step directory, with a small delay between each
+// The test calls the function and waits for it to complete and the profile is saved for later analysis
+// This is helpful to compare the impact of code changes, provides a reproducible way to profile and optimize the function waitForStepsToFinish
+func TestWaitForStepsToFinish_Profile(t *testing.T) {
+	f, err := os.Create("cpu.prof")
+	if err != nil {
+		t.Fatalf("could not create CPU profile: %v", err)
+	}
+	defer func(f *os.File) {
+		err := f.Close()
+		if err != nil {
+			return
+		}
+	}(f)
+	err = pprof.StartCPUProfile(f)
+	if err != nil {
+		return
+	}
+	defer pprof.StopCPUProfile()
+
+	// Setup: create a temp runDir with many fake step files
+	runDir := t.TempDir()
+	stepCount := 100
+	for i := range stepCount {
+		dir := filepath.Join(runDir, fmt.Sprintf("step%d", i))
+		err := os.MkdirAll(dir, 0755)
+		if err != nil {
+			return
+		}
+	}
+
+	// Simulate steps finishing one by one with a delay
+	go func() {
+		for i := range stepCount {
+			file := filepath.Join(runDir, fmt.Sprintf("step%d", i), "out")
+			err := os.WriteFile(file, []byte("done"), 0644)
+			if err != nil {
+				return
+			}
+			time.Sleep(10 * time.Millisecond)
+		}
+	}()
+
+	intervalStr := os.Getenv("SIDECAR_LOG_POLLING_INTERVAL")
+	if intervalStr == "" {
+		intervalStr = "100ms"
+	}
+	interval, err := time.ParseDuration(intervalStr)
+	if err != nil {
+		interval = 100 * time.Millisecond
+	}
+	if err := waitForStepsToFinish(runDir, interval); err != nil {
+		t.Fatalf("waitForStepsToFinish failed: %v", err)
+	}
+}
+
 func TestLookForArtifacts(t *testing.T) {
 	base := basicArtifacts()
 	modified := base.DeepCopy()

pkg/apis/config/default.go

@@ -54,6 +54,8 @@ const (
 	// Default maximum resolution timeout used by the resolution controller before timing out when exceeded
 	DefaultMaximumResolutionTimeout = 1 * time.Minute
 
+	DefaultSidecarLogPollingInterval = 100 * time.Millisecond
+
 	defaultTimeoutMinutesKey                = "default-timeout-minutes"
 	defaultServiceAccountKey                = "default-service-account"
 	defaultManagedByLabelValueKey           = "default-managed-by-label-value"
@@ -67,6 +69,7 @@ const (
 	defaultContainerResourceRequirementsKey = "default-container-resource-requirements"
 	defaultImagePullBackOffTimeout          = "default-imagepullbackoff-timeout"
 	defaultMaximumResolutionTimeout         = "default-maximum-resolution-timeout"
+	defaultSidecarLogPollingIntervalKey     = "default-sidecar-log-polling-interval"
 )
 
 // DefaultConfig holds all the default configurations for the config.
@@ -88,6 +91,10 @@ type Defaults struct {
 	DefaultContainerResourceRequirements map[string]corev1.ResourceRequirements
 	DefaultImagePullBackOffTimeout       time.Duration
 	DefaultMaximumResolutionTimeout      time.Duration
+	// DefaultSidecarLogPollingInterval specifies how frequently (as a time.Duration) the Tekton sidecar log results container polls for step completion files.
+	// This value is loaded from the 'sidecar-log-polling-interval' key in the config-defaults ConfigMap.
+	// It is used to control the responsiveness and resource usage of the sidecar in both production and test environments.
+	DefaultSidecarLogPollingInterval time.Duration
 }
 
 // GetDefaultsConfigName returns the name of the configmap containing all
@@ -120,6 +127,7 @@ func (cfg *Defaults) Equals(other *Defaults) bool {
 		other.DefaultResolverType == cfg.DefaultResolverType &&
 		other.DefaultImagePullBackOffTimeout == cfg.DefaultImagePullBackOffTimeout &&
 		other.DefaultMaximumResolutionTimeout == cfg.DefaultMaximumResolutionTimeout &&
+		other.DefaultSidecarLogPollingInterval == cfg.DefaultSidecarLogPollingInterval &&
 		reflect.DeepEqual(other.DefaultForbiddenEnv, cfg.DefaultForbiddenEnv)
 }
 
@@ -134,6 +142,7 @@ func NewDefaultsFromMap(cfgMap map[string]string) (*Defaults, error) {
 		DefaultResolverType:               DefaultResolverTypeValue,
 		DefaultImagePullBackOffTimeout:    DefaultImagePullBackOffTimeout,
 		DefaultMaximumResolutionTimeout:   DefaultMaximumResolutionTimeout,
+		DefaultSidecarLogPollingInterval:  DefaultSidecarLogPollingInterval,
 	}
 
 	if defaultTimeoutMin, ok := cfgMap[defaultTimeoutMinutesKey]; ok {
@@ -220,6 +229,14 @@ func NewDefaultsFromMap(cfgMap map[string]string) (*Defaults, error) {
 		tc.DefaultMaximumResolutionTimeout = timeout
 	}
 
+	if defaultSidecarPollingInterval, ok := cfgMap[defaultSidecarLogPollingIntervalKey]; ok {
+		interval, err := time.ParseDuration(defaultSidecarPollingInterval)
+		if err != nil {
+			return nil, fmt.Errorf("failed parsing default config %q", defaultSidecarPollingInterval)
+		}
+		tc.DefaultSidecarLogPollingInterval = interval
+	}
+
 	return &tc, nil
 }
 

pkg/apis/config/default_test.go

@@ -46,6 +46,7 @@ func TestNewDefaultsFromConfigMap(t *testing.T) {
 				DefaultResolverType:               "git",
 				DefaultImagePullBackOffTimeout:    time.Duration(5) * time.Second,
 				DefaultMaximumResolutionTimeout:   1 * time.Minute,
+				DefaultSidecarLogPollingInterval:  100 * time.Millisecond,
 			},
 			fileName: config.GetDefaultsConfigName(),
 		},
@@ -67,6 +68,7 @@ func TestNewDefaultsFromConfigMap(t *testing.T) {
 				DefaultMaxMatrixCombinationsCount: 256,
 				DefaultImagePullBackOffTimeout:    0,
 				DefaultMaximumResolutionTimeout:   1 * time.Minute,
+				DefaultSidecarLogPollingInterval:  100 * time.Millisecond,
 			},
 			fileName: "config-defaults-with-pod-template",
 		},
@@ -91,6 +93,7 @@ func TestNewDefaultsFromConfigMap(t *testing.T) {
 				DefaultMaxMatrixCombinationsCount: 256,
 				DefaultImagePullBackOffTimeout:    0,
 				DefaultMaximumResolutionTimeout:   1 * time.Minute,
+				DefaultSidecarLogPollingInterval:  100 * time.Millisecond,
 			},
 		},
 		{
@@ -104,6 +107,7 @@ func TestNewDefaultsFromConfigMap(t *testing.T) {
 				DefaultMaxMatrixCombinationsCount: 256,
 				DefaultImagePullBackOffTimeout:    0,
 				DefaultMaximumResolutionTimeout:   1 * time.Minute,
+				DefaultSidecarLogPollingInterval:  100 * time.Millisecond,
 			},
 		},
 		{
@@ -120,6 +124,7 @@ func TestNewDefaultsFromConfigMap(t *testing.T) {
 				DefaultManagedByLabelValue:        config.DefaultManagedByLabelValue,
 				DefaultImagePullBackOffTimeout:    0,
 				DefaultMaximumResolutionTimeout:   1 * time.Minute,
+				DefaultSidecarLogPollingInterval:  100 * time.Millisecond,
 			},
 		},
 		{
@@ -133,6 +138,7 @@ func TestNewDefaultsFromConfigMap(t *testing.T) {
 				DefaultForbiddenEnv:               []string{"TEKTON_POWER_MODE", "TEST_ENV", "TEST_TEKTON"},
 				DefaultImagePullBackOffTimeout:    time.Duration(15) * time.Second,
 				DefaultMaximumResolutionTimeout:   1 * time.Minute,
+				DefaultSidecarLogPollingInterval:  100 * time.Millisecond,
 			},
 		},
 		{
@@ -146,6 +152,7 @@ func TestNewDefaultsFromConfigMap(t *testing.T) {
 				DefaultContainerResourceRequirements: map[string]corev1.ResourceRequirements{},
 				DefaultImagePullBackOffTimeout:       0,
 				DefaultMaximumResolutionTimeout:      1 * time.Minute,
+				DefaultSidecarLogPollingInterval:     100 * time.Millisecond,
 			},
 		},
 		{
@@ -162,6 +169,7 @@ func TestNewDefaultsFromConfigMap(t *testing.T) {
 				DefaultMaxMatrixCombinationsCount: 256,
 				DefaultImagePullBackOffTimeout:    0,
 				DefaultMaximumResolutionTimeout:   1 * time.Minute,
+				DefaultSidecarLogPollingInterval:  100 * time.Millisecond,
 				DefaultContainerResourceRequirements: map[string]corev1.ResourceRequirements{
 					config.ResourceRequirementDefaultContainerKey: {
 						Requests: corev1.ResourceList{
@@ -219,6 +227,7 @@ func TestNewDefaultsFromEmptyConfigMap(t *testing.T) {
 		DefaultMaxMatrixCombinationsCount: 256,
 		DefaultImagePullBackOffTimeout:    0,
 		DefaultMaximumResolutionTimeout:   1 * time.Minute,
+		DefaultSidecarLogPollingInterval:  100 * time.Millisecond,
 	}
 	verifyConfigFileWithExpectedConfig(t, DefaultsConfigEmptyName, expectedConfig)
 }
@@ -417,6 +426,51 @@ func TestEquals(t *testing.T) {
 	}
 }
 
+func TestSidecarLogPollingIntervalParsing(t *testing.T) {
+	cases := []struct {
+		name     string
+		data     map[string]string
+		expected time.Duration
+		wantErr  bool
+	}{
+		{
+			name:     "valid interval",
+			data:     map[string]string{"default-sidecar-log-polling-interval": "42ms"},
+			expected: 42 * time.Millisecond,
+			wantErr:  false,
+		},
+		{
+			name:     "invalid interval",
+			data:     map[string]string{"default-sidecar-log-polling-interval": "notaduration"},
+			expected: 0,
+			wantErr:  true,
+		},
+		{
+			name:     "not set (default)",
+			data:     map[string]string{},
+			expected: 100 * time.Millisecond,
+			wantErr:  false,
+		},
+	}
+	for _, tc := range cases {
+		t.Run(tc.name, func(t *testing.T) {
+			cfg, err := config.NewDefaultsFromMap(tc.data)
+			if tc.wantErr {
+				if err == nil {
+					t.Errorf("expected error, got nil")
+				}
+				return
+			}
+			if err != nil {
+				t.Fatalf("unexpected error: %v", err)
+			}
+			if cfg.DefaultSidecarLogPollingInterval != tc.expected {
+				t.Errorf("got %v, want %v", cfg.DefaultSidecarLogPollingInterval, tc.expected)
+			}
+		})
+	}
+}
+
 func verifyConfigFileWithExpectedConfig(t *testing.T, fileName string, expectedConfig *config.Defaults) {
 	t.Helper()
 	cm := test.ConfigMapFromTestFile(t, fileName)