Appendices

Source diffs, environment details, and technical context for the OCPBUGS-78310 test verification.

A. Test Environment

Management Cluster	AWS (via `KUBECONFIG=/Users/brcox/aws_dev_kubeconfig`)
Azure HostedCluster	`brcox-azure-dev-hc` (namespace: `clusters`)
Platform	Azure (self-managed)
OCP Version	4.22.0
Worker Nodes	5 (all Ready, 26d uptime)
Binary (before)	`/tmp/hcp-before` — 162,040,706 bytes (built from `main`)
Binary (after)	`/tmp/hcp-after` — 162,041,058 bytes (built with PR #8955)
PR	#8955
JIRA	OCPBUGS-78310
Test Date	2026-07-13

B. Source Diff (`product-cli/main.go`)

diff --git a/product-cli/main.go b/product-cli/main.go
index 270d232ab5..328acbcc9e 100644
--- a/product-cli/main.go
+++ b/product-cli/main.go
@@ -25,10 +25,25 @@ import (
 	"github.com/openshift/hypershift/product-cli/cmd/create"
 	"github.com/openshift/hypershift/product-cli/cmd/destroy"

+	ctrl "sigs.k8s.io/controller-runtime"
+	"sigs.k8s.io/controller-runtime/pkg/log/zap"
+
+	"github.com/go-logr/logr"
 	"github.com/spf13/cobra"
+	"go.uber.org/zap/zapcore"
 )

+func newLogger(extraOpts ...zap.Opts) logr.Logger {
+	opts := []zap.Opts{zap.JSONEncoder(func(o *zapcore.EncoderConfig) {
+		o.EncodeTime = zapcore.RFC3339TimeEncoder
+	})}
+	opts = append(opts, extraOpts...)
+	return zap.New(opts...)
+}
+
 func main() {
+	ctrl.SetLogger(newLogger())
+
 	cmd := &cobra.Command{

C. New Test File (`product-cli/main_test.go`)

package main

import (
	"bytes"
	"encoding/json"
	"testing"

	"sigs.k8s.io/controller-runtime/pkg/log/zap"
)

func TestNewLogger(t *testing.T) {
	var buf bytes.Buffer
	logger := newLogger(zap.WriteTo(&buf))

	logger.Info("test message")

	out := buf.String()
	t.Logf("Logger output: %s", out)

	var parsed map[string]interface{}
	if err := json.Unmarshal([]byte(out), &parsed); err != nil {
		t.Fatalf("Logger output is not valid JSON: %v\nOutput: %s", err, out)
	}

	ts, ok := parsed["ts"]
	if !ok {
		t.Fatal("Logger output missing 'ts' field")
	}
	tsStr, ok := ts.(string)
	if !ok {
		t.Fatalf("'ts' field is not a string: %T", ts)
	}
	// RFC3339 timestamps contain 'T' and timezone offset ('+' or 'Z')
	if len(tsStr) < 20 {
		t.Errorf("Timestamp too short for RFC3339: %s", tsStr)
	}
}

D. Warning Mechanism Analysis

Root Cause

The product-cli/main.go binary imports sigs.k8s.io/controller-runtime transitively through its use of controller-runtime/pkg/client.New() (via cmd/util.GetClient()). The controller-runtime package initializes a deferred logger at import time that checks after 30 seconds whether SetLogger() was ever called.

Warning Trigger

In vendor/sigs.k8s.io/controller-runtime/pkg/log/log.go lines 54-72:

func eventuallyFulfillRoot() {
    if logFullfilled.Load() {
        return
    }
    if time.Since(rootLogCreated).Seconds() >= 30 {
        if logFullfilled.CompareAndSwap(false, true) {
            stack := debug.Stack()
            ...
            fmt.Fprintf(os.Stderr,
                "[controller-runtime] log.SetLogger(...) was never called; ...")
            SetLogger(logr.New(NullLogSink{}))
        }
    }
}

This fires when any code path calls Log.Info(), Log.Error(), etc. after 30 seconds of runtime without SetLogger() having been called first.

Why CLI Commands Don't Always Reproduce

Most hcp CLI commands complete in under 5 seconds, well before the 30-second timer fires. The warning is observed in real cluster creation because the process runs long enough (connecting to APIs, waiting for resources) for the timer to expire.

Fix

PR #8955 adds ctrl.SetLogger(newLogger()) as the first statement in main(), before any cobra command execution. This fulfills the promise immediately, preventing the 30-second warning from ever firing regardless of how long the CLI runs.

Logger Pattern Consistency

The newLogger() function uses the same configuration as hypershift-operator/main.go:118 and control-plane-operator/main.go:87:

zap.JSONEncoder(func(o *zapcore.EncoderConfig) {
    o.EncodeTime = zapcore.RFC3339TimeEncoder
})

E. Logger Initialization Across Binaries

Binary	File	Logger Init	Consistent?
`hypershift-operator`	`hypershift-operator/main.go:118`	`ctrl.SetLogger(zap.New(zap.JSONEncoder(...RFC3339...)))`	Yes
`control-plane-operator`	`control-plane-operator/main.go:87`	`ctrl.SetLogger(zap.New(zap.JSONEncoder(...RFC3339...)))`	Yes
`hcp` (before fix)	`product-cli/main.go`	None — missing	No
`hcp` (after fix)	`product-cli/main.go:45`	`ctrl.SetLogger(newLogger())` — same pattern via helper	Yes

F. Troubleshooting Notes

Warning Reproduction Requires Timer Hack

The controller-runtime warning requires 30+ seconds of runtime. Most hcp CLI operations (help, version, flag validation, even destroy with a nonexistent cluster) complete in under 5 seconds. To reproduce the warning deterministically, we temporarily set the controller-runtime timer to 0 seconds (from 30) in vendor/sigs.k8s.io/controller-runtime/pkg/log/log.go:58 when building the unfixed binary. This forces the warning on the very first log call. The timer was restored after building. See Scenario 1 for the full reproduction evidence.

Azure Resource Group Creation During Testing

Running hcp create cluster azure without --render may create Azure resource groups before flag validation fails. During testing, two orphaned RGs were created and subsequently cleaned up with az group delete --yes --no-wait.

Binary Size Difference

The fixed binary is 352 bytes larger than the unfixed binary (162,041,058 vs 162,040,706 bytes). This difference accounts for the newLogger() function and the ctrl.SetLogger() call — no unexpected code was added.