[release-4.21] OCPBUGS-112011: BUG-FIX Latency Test

docs/performanceprofile/performance_controller.md

@@ -117,6 +117,7 @@ You can run the container with different ENV variables, but the bare minimum is
 
 - `LATENCY_TEST_DELAY` indicates an (optional) delay in seconds to be used between the container is created and the tests actually start. Default is zero (start immediately).
 - `LATENCY_TEST_RUNTIME` the amount of time in seconds that the latency test should run.
+- `LATENCY_TEST_TIMEOUT_BUFFER` overhead seconds (not per-tool runtime) for in-pod CPU setup/init and for the pod to reach Succeeded after the tool finishes.
 - `LATENCY_TEST_IMAGE` the image that used under the latency test.
 - `LATECNY_TEST_CPUS` the amount of CPUs the pod which run the latency test should request
 - `OSLAT_MAXIMUM_LATENCY` the expected maximum latency for all buckets in us in the oslat test.

test/e2e/performanceprofile/functests/4_latency/latency.go

@@ -42,12 +42,12 @@ const (
 	hwlatdetectTestName = "hwlatdetect"
 
 	//default values
-	defaultTestDelay   = 0
-	defaultTestRuntime = "300"
-	defaultMaxLatency  = -1
-	defaultTestCpus    = -1
-	defaultTestMemory  = "1Gi"
-
+	defaultTestDelay         = 0
+	defaultTestRuntime       = "300"
+	defaultMaxLatency        = -1
+	defaultTestCpus          = -1
+	defaultTestMemory        = "1Gi"
+	defaultTestTimeoutBuffer = 150
 	//dynamic memory mode values
 	// 32Mi per requested CPU should be reasonable for the test
 	perCpuMemoryFactor = 32
@@ -57,15 +57,17 @@ const (
 )
 
 var (
-	latencyTestDelay   = defaultTestDelay
-	latencyTestRuntime = defaultTestRuntime
-	maximumLatency     = defaultMaxLatency
-	latencyTestCpus    = defaultTestCpus
-	latencyTestMemory  = defaultTestMemory
+	latencyTestDelay         = defaultTestDelay
+	latencyTestRuntime       = defaultTestRuntime
+	latencyTestTimeoutBuffer = defaultTestTimeoutBuffer
+	maximumLatency           = defaultMaxLatency
+	latencyTestCpus          = defaultTestCpus
+	latencyTestMemory        = defaultTestMemory
 )
 
 // LATENCY_TEST_DELAY delay the run of the binary, can be useful to give time to the CPU manager reconcile loop
 // to update the default CPU pool
+// LATENCY_TEST_TIMEOUT_BUFFER: extra seconds for pod CPU setup and Succeeded wait (not per-tool runtime)
 // LATENCY_TEST_RUNTIME: the amount of time in seconds that the latency test should run
 // LATENCY_TEST_CPUS: the amount of CPUs the pod which run the latency test should request
 // LATENCY_TEST_MEMORY: the amount of memory the pod which run the latency test should request
@@ -79,6 +81,9 @@ var _ = Describe("[performance] Latency Test", Ordered, func() {
 		latencyTestDelay, err = getLatencyTestDelay()
 		Expect(err).ToNot(HaveOccurred())
 
+		latencyTestTimeoutBuffer, err = getLatencyTestTimeoutBuffer()
+		Expect(err).ToNot(HaveOccurred())
+
 		latencyTestCpus, err = getLatencyTestCpus()
 		Expect(err).ToNot(HaveOccurred())
 
@@ -275,6 +280,23 @@ func getLatencyTestDelay() (int, error) {
 	return defaultTestDelay, nil
 }
 
+func getLatencyTestTimeoutBuffer() (int, error) {
+	if latencyTestTimeoutBufferEnv, ok := os.LookupEnv("LATENCY_TEST_TIMEOUT_BUFFER"); ok {
+		val, err := strconv.Atoi(latencyTestTimeoutBufferEnv)
+		if err != nil {
+			return val, fmt.Errorf("the environment variable LATENCY_TEST_TIMEOUT_BUFFER has incorrect value %q, it must be a non-negative integer with maximum value of %d: %w", latencyTestTimeoutBufferEnv, math.MaxInt32, err)
+		}
+		if val < 0 || val > math.MaxInt32 {
+			return val, fmt.Errorf("the environment variable LATENCY_TEST_TIMEOUT_BUFFER has an invalid number %q, it must be a non-negative integer with maximum value of %d", latencyTestTimeoutBufferEnv, math.MaxInt32)
+		}
+		if val < defaultTestTimeoutBuffer {
+			testlog.Warningf("LATENCY_TEST_TIMEOUT_BUFFER=%d is below %d; for safe execution set it to %d or higher, as a lower value may cause timeouts", val, defaultTestTimeoutBuffer, defaultTestTimeoutBuffer)
+		}
+		return val, nil
+	}
+	return defaultTestTimeoutBuffer, nil
+}
+
 func getLatencyTestCpus() (int, error) {
 	if latencyTestCpusEnv, ok := os.LookupEnv("LATENCY_TEST_CPUS"); ok {
 		val, err := strconv.Atoi(latencyTestCpusEnv)
@@ -489,13 +511,14 @@ func createLatencyTestPod(testPod *corev1.Pod) {
 		Expect(isEqual(RequestsCpusQuantity, latencyTestCpus)).To(BeTrue(), fmt.Sprintf("actual requests of cpus number used for the latency pod is not as set in LATENCY_TEST_CPUS, actual number is: %s", RequestsCpusQuantity))
 	}
 
-	By("Waiting another two minutes to give enough time for the cluster to move the pod to Succeeded phase")
-	podTimeout := time.Duration(timeout + latencyTestDelay + 120)
+	podTimeout := time.Duration(timeout + latencyTestDelay + latencyTestTimeoutBuffer)
+	By(fmt.Sprintf("Waiting up to %d seconds (runtime=%d, delay=%d, timeoutBuffer=%d) for the pod to reach Succeeded phase", int(podTimeout), timeout, latencyTestDelay, latencyTestTimeoutBuffer))
+
 	testPod, err = pods.WaitForPhase(context.TODO(), client.ObjectKeyFromObject(testPod), corev1.PodSucceeded, podTimeout*time.Second)
 	if err != nil {
 		logEventsForPod(testPod)
 	}
-	Expect(err).ToNot(HaveOccurred(), "pod %q did not reach %q phase; error: %v", podKey, corev1.PodSucceeded, err)
+	Expect(err).ToNot(HaveOccurred(), "pod %q did not reach %q phase; error: %v. Please Increase LATENCY_TEST_TIMEOUT_BUFFER to allow the cluster to move the pod to Succeeded phase and run again.", podKey, corev1.PodSucceeded, err)
 }
 
 func extractLatencyValues(exp string, pod *corev1.Pod) []int {

test/e2e/performanceprofile/functests/5_latency_testing/latency_testing.go

@@ -23,13 +23,14 @@ const (
 	cyclictest  = "cyclictest"
 	hwlatdetect = "hwlatdetect"
 	//Environment variables names
-	latencyTestDelay     = "LATENCY_TEST_DELAY"
-	latencyTestRuntime   = "LATENCY_TEST_RUNTIME"
-	maximumLatency       = "MAXIMUM_LATENCY"
-	oslatMaxLatency      = "OSLAT_MAXIMUM_LATENCY"
-	hwlatdetecMaxLatency = "HWLATDETECT_MAXIMUM_LATENCY"
-	cyclictestMaxLatency = "CYCLICTEST_MAXIMUM_LATENCY"
-	latencyTestCpus      = "LATENCY_TEST_CPUS"
+	latencyTestDelay         = "LATENCY_TEST_DELAY"
+	latencyTestRuntime       = "LATENCY_TEST_RUNTIME"
+	latencyTestTimeoutBuffer = "LATENCY_TEST_TIMEOUT_BUFFER"
+	maximumLatency           = "MAXIMUM_LATENCY"
+	oslatMaxLatency          = "OSLAT_MAXIMUM_LATENCY"
+	hwlatdetecMaxLatency     = "HWLATDETECT_MAXIMUM_LATENCY"
+	cyclictestMaxLatency     = "CYCLICTEST_MAXIMUM_LATENCY"
+	latencyTestCpus          = "LATENCY_TEST_CPUS"
 	//invalid values error messages
 	unexpectedError = "Unexpected error"
 	//incorrect values error messages
@@ -44,6 +45,8 @@ const (
 	invalidCpuNumber                   = incorrectMsgPart1 + latencyTestCpus + invalidNumber + mustBePositiveInt
 	incorrectDelay                     = incorrectMsgPart1 + latencyTestDelay + incorrectMsgPart2 + mustBeNonNegativeInt
 	invalidNumberDelay                 = incorrectMsgPart1 + latencyTestDelay + invalidNumber + mustBeNonNegativeInt
+	incorrectTimeoutBuffer             = incorrectMsgPart1 + latencyTestTimeoutBuffer + incorrectMsgPart2 + mustBeNonNegativeInt
+	invalidNumberTimeoutBuffer         = incorrectMsgPart1 + latencyTestTimeoutBuffer + invalidNumber + mustBeNonNegativeInt
 	incorrectMaxLatency                = incorrectMsgPart1 + maximumLatency + incorrectMsgPart2 + mustBeNonNegativeInt
 	invalidNumberMaxLatency            = incorrectMsgPart1 + maximumLatency + invalidNumber + mustBeNonNegativeInt
 	incorrectOslatMaxLatency           = incorrectMsgPart1 + "\"" + oslatMaxLatency + "\"" + incorrectMsgPart2 + mustBeNonNegativeInt
@@ -82,6 +85,7 @@ const (
 type latencyTest struct {
 	testDelay             string
 	testRuntime           string
+	testTimeoutBuffer     string
 	testMaxLatency        string
 	oslatMaxLatency       string
 	cyclictestMaxLatency  string
@@ -178,6 +182,9 @@ func setEnvAndGetDescription(tst latencyTest) string {
 	if tst.testDelay != "" {
 		setEnvWriteDescription(latencyTestDelay, tst.testDelay, sb, &nonDefaultValues)
 	}
+	if tst.testTimeoutBuffer != "" {
+		setEnvWriteDescription(latencyTestTimeoutBuffer, tst.testTimeoutBuffer, sb, &nonDefaultValues)
+	}
 	if tst.testRuntime != "" {
 		setEnvWriteDescription(latencyTestRuntime, tst.testRuntime, sb, &nonDefaultValues)
 	}
@@ -211,6 +218,7 @@ func setEnvWriteDescription(envVar string, val string, sb *bytes.Buffer, flag *b
 
 func clearEnv() {
 	os.Unsetenv(latencyTestDelay)
+	os.Unsetenv(latencyTestTimeoutBuffer)
 	os.Unsetenv(latencyTestRuntime)
 	os.Unsetenv(maximumLatency)
 	os.Unsetenv(oslatMaxLatency)
@@ -237,6 +245,7 @@ func getValidValuesTests(toolToTest string) []latencyTest {
 	testSet = append(testSet, latencyTest{testDelay: "1", testRuntime: successRuntime, testMaxLatency: untunedLatencyThreshold, outputMsgs: []string{success}, toolToTest: toolToTest, ginkgoTimeout: successGinkgoTimeout})
 	testSet = append(testSet, latencyTest{testDelay: "60", testRuntime: successRuntime, testMaxLatency: untunedLatencyThreshold, outputMsgs: []string{success}, toolToTest: toolToTest, ginkgoTimeout: successGinkgoTimeout})
 	testSet = append(testSet, latencyTest{testRuntime: "2", testCpus: "5", testMaxLatency: untunedLatencyThreshold, outputMsgs: []string{skip, skipOddCpuNumber}, toolToTest: toolToTest, ginkgoTimeout: successGinkgoTimeout})
+	testSet = append(testSet, latencyTest{testTimeoutBuffer: "155", testRuntime: successRuntime, testMaxLatency: untunedLatencyThreshold, testCpus: "4", outputMsgs: []string{success}, toolToTest: toolToTest, ginkgoTimeout: successGinkgoTimeout})
 
 	if toolToTest != hwlatdetect {
 		testSet = append(testSet, latencyTest{testRuntime: "1", outputMsgs: []string{skip, skipMaxLatency}, toolToTest: toolToTest, ginkgoTimeout: successGinkgoTimeout})
@@ -279,6 +288,11 @@ func getNegativeTests(toolToTest string) []latencyTest {
 	testSet = append(testSet, latencyTest{testRuntime: "2", testCpus: "-1", outputMsgs: []string{invalidCpuNumber, fail}, toolToTest: toolToTest})
 	testSet = append(testSet, latencyTest{testRuntime: "2", testCpus: "0", outputMsgs: []string{invalidCpuNumber, fail}, toolToTest: toolToTest})
 
+	// LATENCY_TEST_TIMEOUT_BUFFER must be a valid integer, reject non-numeric, and negative values.
+	testSet = append(testSet, latencyTest{testTimeoutBuffer: "J", outputMsgs: []string{incorrectTimeoutBuffer, fail}, toolToTest: toolToTest})
+	testSet = append(testSet, latencyTest{testTimeoutBuffer: fmt.Sprint(math.MaxInt32 + 1), outputMsgs: []string{invalidNumberTimeoutBuffer, fail}, toolToTest: toolToTest})
+	testSet = append(testSet, latencyTest{testTimeoutBuffer: "-5", outputMsgs: []string{invalidNumberTimeoutBuffer, fail}, toolToTest: toolToTest})
+
 	if toolToTest == oslat {
 		testSet = append(testSet, latencyTest{testRuntime: "2", oslatMaxLatency: "&", outputMsgs: []string{incorrectOslatMaxLatency, fail}, toolToTest: toolToTest})
 		testSet = append(testSet, latencyTest{testRuntime: "2", oslatMaxLatency: fmt.Sprint(math.MaxInt32 + 1), outputMsgs: []string{invalidNumberOslatMaxLatency, fail}, toolToTest: toolToTest})