update error logging for tests, highlight test failure (#7162)

Author: r2k1

e2e/config/config.go

@@ -44,8 +44,8 @@ type Configuration struct {
 	BlobStorageAccountPrefix               string        `env:"BLOB_STORAGE_ACCOUNT_PREFIX" envDefault:"abe2e"`
 	BuildID                                string        `env:"BUILD_ID" envDefault:"local"`
 	DefaultLocation                        string        `env:"E2E_LOCATION" envDefault:"westus3"`
-	DefaultSubnetName                      string        `env:"DEFAULT_SUBNET_NAME" envDefault:"aks-subnet"`
 	DefaultPollInterval                    time.Duration `env:"DEFAULT_POLL_INTERVAL" envDefault:"1s"`
+	DefaultSubnetName                      string        `env:"DEFAULT_SUBNET_NAME" envDefault:"aks-subnet"`
 	DefaultVMSKU                           string        `env:"DEFAULT_VM_SKU" envDefault:"Standard_D2ds_v5"`
 	DisableScriptLessCompilation           bool          `env:"DISABLE_SCRIPTLESS_COMPILATION"`
 	E2ELoggingDir                          string        `env:"LOGGING_DIR" envDefault:"scenario-logs"`

e2e/go.mod

@@ -17,6 +17,7 @@ require (
 	github.com/Azure/azure-sdk-for-go/sdk/resourcemanager/resources/armresources v1.2.0
 	github.com/Azure/azure-sdk-for-go/sdk/resourcemanager/storage/armstorage v1.8.1
 	github.com/Azure/azure-sdk-for-go/sdk/storage/azblob v1.6.2
+	github.com/blang/semver v3.5.1+incompatible
 	github.com/caarlos0/env/v11 v11.3.1
 	github.com/joho/godotenv v1.5.1
 	github.com/sanity-io/litter v1.5.5
@@ -34,7 +35,6 @@ require (
 	github.com/Azure/go-autorest/autorest/to v0.4.1 // indirect
 	github.com/Masterminds/semver/v3 v3.4.0 // indirect
 	github.com/aws/aws-sdk-go-v2 v1.38.2 // indirect
-	github.com/blang/semver v3.5.1+incompatible // indirect
 	github.com/clarketm/json v1.17.1 // indirect
 	github.com/coreos/butane v0.25.1 // indirect
 	github.com/coreos/go-json v0.0.0-20230131223807-18775e0fb4fb // indirect

e2e/kube.go

@@ -190,7 +190,7 @@ func (k *Kubeclient) WaitUntilNodeReady(ctx context.Context, t testing.TB, vmssN
 	}
 
 	if node == nil {
-		t.Fatalf("ERROR: %q haven't appeared in k8s API server", vmssName)
+		t.Fatalf("%q haven't appeared in k8s API server", vmssName)
 		return ""
 	}
 

e2e/log.go

@@ -8,11 +8,11 @@ import (
 	"github.com/Azure/agentbaker/e2e/config"
 )
 
-func testDir(t *testing.T) string {
+func testDir(t testing.TB) string {
 	return filepath.Join(config.Config.E2ELoggingDir, t.Name())
 }
 
-func writeToFile(t *testing.T, fileName, content string) error {
+func writeToFile(t testing.TB, fileName, content string) error {
 	dirPath := testDir(t)
 	// Create the directory if it doesn't exist
 	if err := os.MkdirAll(dirPath, 0755); err != nil {
@@ -23,7 +23,7 @@ func writeToFile(t *testing.T, fileName, content string) error {
 	return os.WriteFile(fullPath, []byte(content), 0644)
 }
 
-func dumpFileMapToDir(t *testing.T, files map[string]string) error {
+func dumpFileMapToDir(t testing.TB, files map[string]string) error {
 	for fileName, contents := range files {
 		fileName = filepath.Base(fileName)
 		if err := writeToFile(t, fileName, contents); err != nil {

e2e/node_config.go

@@ -97,7 +97,7 @@ var baseKubeletConfig = &aksnodeconfigv1.KubeletConfig{
 	},
 }
 
-func getBaseNBC(t *testing.T, cluster *Cluster, vhd *config.Image) *datamodel.NodeBootstrappingConfiguration {
+func getBaseNBC(t testing.TB, cluster *Cluster, vhd *config.Image) *datamodel.NodeBootstrappingConfiguration {
 	var nbc *datamodel.NodeBootstrappingConfiguration
 
 	if vhd.Distro.IsWindowsDistro() {
@@ -266,7 +266,7 @@ func nbcToAKSNodeConfigV1(nbc *datamodel.NodeBootstrappingConfiguration) *aksnod
 // TODO(ace): minimize the actual required defaults.
 // this is what we previously used for bash e2e from e2e/nodebootstrapping_template.json.
 // which itself was extracted from baker_test.go logic, which was inherited from aks-engine.
-func baseTemplateLinux(t *testing.T, location string, k8sVersion string, arch string) *datamodel.NodeBootstrappingConfiguration {
+func baseTemplateLinux(t testing.TB, location string, k8sVersion string, arch string) *datamodel.NodeBootstrappingConfiguration {
 	config := &datamodel.NodeBootstrappingConfiguration{
 		ContainerService: &datamodel.ContainerService{
 			ID:       "",
@@ -741,7 +741,7 @@ func baseTemplateLinux(t *testing.T, location string, k8sVersion string, arch st
 // this been crafted with a lot of trial and pain, some values are not needed, but it takes a lot of time to figure out which ones.
 // and we hope to move on to a different config, so I don't want to invest any more time in this-
 // please keep the kubernetesVersion in sync with componets.json so that during e2e no extra binaries are required.
-func baseTemplateWindows(t *testing.T, location string) *datamodel.NodeBootstrappingConfiguration {
+func baseTemplateWindows(t testing.TB, location string) *datamodel.NodeBootstrappingConfiguration {
 	kubernetesVersion := "1.30.12"
 	// kubernetesVersion := "1.31.9"
 	// kubernetesVersion := "v1.32.5"

e2e/test_helpers.go

@@ -66,7 +66,7 @@ func constructErrorMessage(subscriptionID, location string) string {
 	return fmt.Sprintf("Received second cancellation signal, forcing exit.\nPlease check https://ms.portal.azure.com/#@microsoft.onmicrosoft.com/resource/subscriptions/%s/resourceGroups/%s/overview and delete any resources created by the test suite", subscriptionID, config.ResourceGroupName(location))
 }
 
-func newTestCtx(t *testing.T) context.Context {
+func newTestCtx(t testing.TB) context.Context {
 	if testCtx.Err() != nil {
 		t.Skip("test suite is shutting down")
 	}
@@ -178,7 +178,8 @@ func copyScenario(s *Scenario) *Scenario {
 	return &copied
 }
 
-func runScenario(t *testing.T, s *Scenario) {
+func runScenario(t testing.TB, s *Scenario) {
+	t = toolkit.WithTestLogger(t)
 	if s.Location == "" {
 		s.Location = config.Config.DefaultLocation
 	}
@@ -276,7 +277,7 @@ func prepareAKSNode(ctx context.Context, s *Scenario) {
 	require.NoError(s.T, err, "failed to get VM private IP address")
 }
 
-func maybeSkipScenario(ctx context.Context, t *testing.T, s *Scenario) {
+func maybeSkipScenario(ctx context.Context, t testing.TB, s *Scenario) {
 	s.Tags.Name = t.Name()
 	s.Tags.OS = string(s.VHD.OS)
 	s.Tags.Arch = s.VHD.Arch

e2e/toolkit/log.go

@@ -2,14 +2,15 @@ package toolkit
 
 import (
 	"context"
+	"fmt"
 	"log"
 	"testing"
 )
 
 // testLoggerKey is a private key to prevent *testing.T from being easily accessed
 type testLoggerKey struct{}
 
-func ContextWithT(ctx context.Context, t *testing.T) context.Context {
+func ContextWithT(ctx context.Context, t testing.TB) context.Context {
 	if t == nil {
 		log.Println("WARNING: No *testing.T provided, this function should only be called from a test")
 		return ctx
@@ -18,7 +19,7 @@ func ContextWithT(ctx context.Context, t *testing.T) context.Context {
 }
 
 func Logf(ctx context.Context, format string, args ...any) {
-	t, ok := ctx.Value(testLoggerKey{}).(*testing.T)
+	t, ok := ctx.Value(testLoggerKey{}).(testing.TB)
 	if !ok || t == nil {
 		log.Printf(format+"WARNING: No *testing.T in Context, this function should only be called from ", args...)
 	}
@@ -27,11 +28,68 @@ func Logf(ctx context.Context, format string, args ...any) {
 }
 
 func Log(ctx context.Context, args ...any) {
-	t, ok := ctx.Value(testLoggerKey{}).(*testing.T)
+	t, ok := ctx.Value(testLoggerKey{}).(testing.TB)
 	if !ok || t == nil {
 		log.Println("WARNING: No *testing.T in Context, this function should only be called from a test")
 		return
 	}
 	t.Helper()
 	t.Log(args...)
 }
+
+type testLogger struct {
+	testing.TB
+}
+
+// formatError formats the ERROR prefix with emoji
+func (t *testLogger) formatError() string {
+	return "🔴 FAIL:"
+}
+
+func (t *testLogger) Fatal(args ...any) {
+	t.Helper()
+	// Prepend "ERROR: " to the first argument
+	if len(args) > 0 {
+		args[0] = fmt.Sprintf("%s %v", t.formatError(), args[0])
+	} else {
+		args = []any{t.formatError() + " "}
+	}
+	t.TB.Fatal(args...)
+}
+
+func (t *testLogger) Fatalf(format string, args ...any) {
+	t.Helper()
+	t.TB.Fatalf(t.formatError()+" "+format, args...)
+}
+
+func (t *testLogger) Error(args ...any) {
+	t.Helper()
+	// Prepend "ERROR: " to the first argument
+	if len(args) > 0 {
+		args[0] = fmt.Sprintf("%s %v", t.formatError(), args[0])
+	} else {
+		args = []any{t.formatError() + " "}
+	}
+	t.TB.Error(args...)
+}
+
+func (t *testLogger) Errorf(format string, args ...any) {
+	t.Helper()
+	t.TB.Errorf(t.formatError()+" "+format, args...)
+}
+
+func (t *testLogger) FailNow() {
+	t.Helper()
+	t.Log(t.formatError())
+	t.TB.FailNow()
+}
+
+func (t *testLogger) Fail() {
+	t.Helper()
+	t.Log(t.formatError())
+	t.TB.Fail()
+}
+
+func WithTestLogger(t testing.TB) testing.TB {
+	return &testLogger{TB: t}
+}

e2e/types.go

@@ -31,6 +31,7 @@ type Tags struct {
 	ServerTLSBootstrapping bool
 	KubeletCustomConfig    bool
 	Scriptless             bool
+	VHDCaching             bool
 }
 
 // MatchesFilters checks if the Tags struct matches all given filters.
@@ -125,7 +126,7 @@ type Scenario struct {
 
 	// Runtime contains the runtime state of the scenario. It's populated in the beginning of the test run
 	Runtime *ScenarioRuntime
-	T       *testing.T
+	T       testing.TB
 }
 
 type ScenarioRuntime struct {
@@ -172,7 +173,7 @@ func (s *Scenario) PrepareAKSNodeConfig() {
 
 // PrepareVMSSModel mutates the input VirtualMachineScaleSet based on the scenario's VMConfigMutator, if configured.
 // This method will also use the scenario's configured VHD selector to modify the input VMSS to reference the correct VHD resource.
-func (s *Scenario) PrepareVMSSModel(ctx context.Context, t *testing.T, vmss *armcompute.VirtualMachineScaleSet) {
+func (s *Scenario) PrepareVMSSModel(ctx context.Context, t testing.TB, vmss *armcompute.VirtualMachineScaleSet) {
 	resourceID, err := CachedPrepareVHD(ctx, GetVHDRequest{
 		Image:    *s.VHD,
 		Location: s.Location,

e2e/validation.go

@@ -48,7 +48,7 @@ func ValidatePodRunning(ctx context.Context, s *Scenario, pod *corev1.Pod) {
 	s.T.Logf("node health validation: test pod %q is running on node %q", pod.Name, s.Runtime.KubeNodeName)
 }
 
-func truncatePodName(t *testing.T, pod *corev1.Pod) {
+func truncatePodName(t testing.TB, pod *corev1.Pod) {
 	name := pod.Name
 	if len(pod.Name) < 63 {
 		return

e2e/vmss.go

@@ -317,7 +317,7 @@ func waitForVMPrivateIP(ctx context.Context, s *Scenario) (string, error) {
 	}
 }
 
-func skipTestIfSKUNotAvailableErr(t *testing.T, err error) {
+func skipTestIfSKUNotAvailableErr(t testing.TB, err error) {
 	// sometimes the SKU is not available and we can't do anything. Skip the test in this case.
 	var respErr *azcore.ResponseError
 	if config.Config.SkipTestsWithSKUCapacityIssue &&
@@ -741,7 +741,7 @@ func getNewRSAKeyPair() (privatePEMBytes []byte, publicKeyBytes []byte, e error)
 	return
 }
 
-func generateVMSSNameLinux(t *testing.T) string {
+func generateVMSSNameLinux(t testing.TB) string {
 	name := fmt.Sprintf("%s-%s-%s", randomLowercaseString(4), time.Now().Format(time.DateOnly), t.Name())
 	name = strings.ReplaceAll(name, "_", "")
 	name = strings.ReplaceAll(name, "/", "")