From 1400008041e0c9505dff3846fbd4e5face63c824 Mon Sep 17 00:00:00 2001 From: Silvestre Zabala Date: Thu, 28 Mar 2024 12:15:42 +0100 Subject: [PATCH 1/4] fix(go_app): fix CPU usage by test app --- .../assets/app/go_app/internal/app/c_clock.go | 10 +++++ .../assets/app/go_app/internal/app/cpu.go | 16 +++++--- .../assets/app/go_app/internal/app/cpuInfo.go | 15 ------- .../app/go_app/internal/app/cpu_test.go | 41 +++++++++++++------ 4 files changed, 49 insertions(+), 33 deletions(-) create mode 100644 src/acceptance/assets/app/go_app/internal/app/c_clock.go delete mode 100644 src/acceptance/assets/app/go_app/internal/app/cpuInfo.go diff --git a/src/acceptance/assets/app/go_app/internal/app/c_clock.go b/src/acceptance/assets/app/go_app/internal/app/c_clock.go new file mode 100644 index 0000000000..472d5ec030 --- /dev/null +++ b/src/acceptance/assets/app/go_app/internal/app/c_clock.go @@ -0,0 +1,10 @@ +package app + +//#include +import "C" + +const ClocksPerSec = C.CLOCKS_PER_SEC + +func GetClock() float64 { + return float64(C.clock()) +} diff --git a/src/acceptance/assets/app/go_app/internal/app/cpu.go b/src/acceptance/assets/app/go_app/internal/app/cpu.go index 0de5f6d565..b4bd33d77a 100644 --- a/src/acceptance/assets/app/go_app/internal/app/cpu.go +++ b/src/acceptance/assets/app/go_app/internal/app/cpu.go @@ -64,17 +64,15 @@ func CPUTests(logger logr.Logger, r *gin.RouterGroup, cpuTest CPUWaster) *gin.Ro } func (m *ConcurrentBusyLoopCPUWaster) UseCPU(utilisation uint64, duration time.Duration) { - m.mu.Lock() - defer m.mu.Unlock() - m.isRunning = true + m.StartTest() for utilisation > 0 { perGoRoutineUtilisation := min(utilisation, 100) utilisation = utilisation - perGoRoutineUtilisation go func(util uint64) { - run := time.Duration(util) * time.Microsecond / 10 - sleep := time.Duration(100-util) * time.Microsecond / 10 + run := time.Duration(util) * time.Second / 100 + sleep := time.Duration(100-util) * time.Second / 100 runtime.LockOSThread() for m.IsRunning() { begin := time.Now() @@ -83,8 +81,10 @@ func (m *ConcurrentBusyLoopCPUWaster) UseCPU(utilisation uint64, duration time.D } time.Sleep(sleep) } + runtime.UnlockOSThread() }(perGoRoutineUtilisation) } + // how long go func() { time.Sleep(duration) @@ -104,6 +104,12 @@ func (m *ConcurrentBusyLoopCPUWaster) StopTest() { m.isRunning = false } +func (m *ConcurrentBusyLoopCPUWaster) StartTest() { + m.mu.Lock() + defer m.mu.Unlock() + m.isRunning = true +} + func min[T constraints.Ordered](a, b T) T { if a < b { return a diff --git a/src/acceptance/assets/app/go_app/internal/app/cpuInfo.go b/src/acceptance/assets/app/go_app/internal/app/cpuInfo.go deleted file mode 100644 index b2e2af654c..0000000000 --- a/src/acceptance/assets/app/go_app/internal/app/cpuInfo.go +++ /dev/null @@ -1,15 +0,0 @@ -package app - -//#include -import "C" -import "time" - -var startTime = time.Now() -var startTicks = C.clock() - -// CpuTotalUsageTime https://stackoverflow.com/questions/11356330/how-to-get-cpu-usage/31030753#31030753 -func CpuTotalUsageTime() float64 { - clockSeconds := float64(C.clock()-startTicks) / float64(C.CLOCKS_PER_SEC) - realSeconds := time.Since(startTime).Seconds() - return clockSeconds + realSeconds -} diff --git a/src/acceptance/assets/app/go_app/internal/app/cpu_test.go b/src/acceptance/assets/app/go_app/internal/app/cpu_test.go index 3119454388..8bd7e917b9 100644 --- a/src/acceptance/assets/app/go_app/internal/app/cpu_test.go +++ b/src/acceptance/assets/app/go_app/internal/app/cpu_test.go @@ -53,29 +53,44 @@ var _ = Describe("CPU tests", func() { Expect(utilization).Should(Equal(uint64(5))) }) }) - Context("UseCPU", func() { - It("should use cpu and release when stopped", func() { - oldCpu := getTotalCPUUsage("before cpuTest info test") + // This test is timing sensitive and may fail on GitHub workers, which is why it is marked as flaky + Context("UseCPU", FlakeAttempts(3), func() { + DescribeTable("should use cpu", + func(utilisation uint64, duration time.Duration) { + oldCpu := getTotalCPUUsage("before cpuTest info test") - By("allocating cpu") - cpuInfo := &app.ConcurrentBusyLoopCPUWaster{} - cpuInfo.UseCPU(100, time.Second) - Expect(cpuInfo.IsRunning()).To(Equal(true)) - Eventually(cpuInfo.IsRunning, "2s").Should(Equal(false)) - newCpu := getTotalCPUUsage("after cpuTest info test") - Expect(newCpu - oldCpu).To(BeNumerically(">=", 500*time.Millisecond)) - }) + By("allocating cpu") + cpuInfo := &app.ConcurrentBusyLoopCPUWaster{} + cpuInfo.UseCPU(utilisation, duration) + Expect(cpuInfo.IsRunning()).To(Equal(true)) + Eventually(cpuInfo.IsRunning).WithTimeout(duration + time.Second).WithPolling(time.Second).Should(Equal(false)) + newCpu := getTotalCPUUsage("after cpuTest info test") + expectedCPUUsage := multiplyDurationByPercentage(duration, utilisation) + // Give 10% tolerance - but at least 1 second, as this is the internal resolution of the CPU waster + tolerance := max(multiplyDurationByPercentage(expectedCPUUsage, 10), time.Second) + Expect(newCpu - oldCpu).To(BeNumerically("~", expectedCPUUsage, tolerance)) + }, + Entry("25% for 10 seconds", uint64(25), time.Second*10), + Entry("50% for 10 seconds", uint64(50), time.Second*10), + Entry("100% for 10 seconds", uint64(100), time.Second*10), + Entry("200% for 10 seconds", uint64(200), time.Second*10), + Entry("400% for 10 seconds", uint64(400), time.Second*10), + ) }) }) func getTotalCPUUsage(action string) time.Duration { GinkgoHelper() - cpuTotalUsage := app.CpuTotalUsageTime() - cpuTotalDuration := time.Duration(cpuTotalUsage * float64(time.Second)) + cpuTotalUsage := app.GetClock() + cpuTotalDuration := time.Duration(float64(time.Second) * cpuTotalUsage / app.ClocksPerSec) GinkgoWriter.Printf("total cpu time %s: %s\n", action, cpuTotalDuration.String()) return cpuTotalDuration } + +func multiplyDurationByPercentage(duration time.Duration, percentage uint64) time.Duration { + return time.Duration(float64(duration) * float64(percentage) / 100) +} From f85fed3c96baa810132baec87f7e2d85ccca14d7 Mon Sep 17 00:00:00 2001 From: Silvestre Zabala Date: Tue, 2 Apr 2024 12:27:30 +0200 Subject: [PATCH 2/4] add some docs --- src/acceptance/assets/app/go_app/internal/app/cpu.go | 9 +++++++-- 1 file changed, 7 insertions(+), 2 deletions(-) diff --git a/src/acceptance/assets/app/go_app/internal/app/cpu.go b/src/acceptance/assets/app/go_app/internal/app/cpu.go index b4bd33d77a..ef33342f83 100644 --- a/src/acceptance/assets/app/go_app/internal/app/cpu.go +++ b/src/acceptance/assets/app/go_app/internal/app/cpu.go @@ -64,13 +64,18 @@ func CPUTests(logger logr.Logger, r *gin.RouterGroup, cpuTest CPUWaster) *gin.Ro } func (m *ConcurrentBusyLoopCPUWaster) UseCPU(utilisation uint64, duration time.Duration) { - m.StartTest() + m.startTest() for utilisation > 0 { + // to allow to use more than one CPU, we distribute the utilisation to multiple goroutines perGoRoutineUtilisation := min(utilisation, 100) utilisation = utilisation - perGoRoutineUtilisation + // the core cpu wasting goroutine go func(util uint64) { + // to achieve a desired utilisation, we run a busy loop for a certain percentage of time and then wait for the remainder + // concretely, we split a second into two parts: one busy loop and one sleep + // we repeat this "second" until the test is stopped run := time.Duration(util) * time.Second / 100 sleep := time.Duration(100-util) * time.Second / 100 runtime.LockOSThread() @@ -104,7 +109,7 @@ func (m *ConcurrentBusyLoopCPUWaster) StopTest() { m.isRunning = false } -func (m *ConcurrentBusyLoopCPUWaster) StartTest() { +func (m *ConcurrentBusyLoopCPUWaster) startTest() { m.mu.Lock() defer m.mu.Unlock() m.isRunning = true From b5838e0a2536f799a03b7d18203e07dcd8ac2cab Mon Sep 17 00:00:00 2001 From: geigerj0 <112163019+geigerj0@users.noreply.github.com> Date: Tue, 2 Apr 2024 14:09:45 +0200 Subject: [PATCH 3/4] new context for ConcurrentBusyLoopCPUWaster and a little renaming --- .../app/go_app/internal/app/cpu_test.go | 44 ++++++++++--------- 1 file changed, 23 insertions(+), 21 deletions(-) diff --git a/src/acceptance/assets/app/go_app/internal/app/cpu_test.go b/src/acceptance/assets/app/go_app/internal/app/cpu_test.go index 8bd7e917b9..73af7ca7af 100644 --- a/src/acceptance/assets/app/go_app/internal/app/cpu_test.go +++ b/src/acceptance/assets/app/go_app/internal/app/cpu_test.go @@ -55,28 +55,30 @@ var _ = Describe("CPU tests", func() { }) // This test is timing sensitive and may fail on GitHub workers, which is why it is marked as flaky - Context("UseCPU", FlakeAttempts(3), func() { - DescribeTable("should use cpu", - func(utilisation uint64, duration time.Duration) { - oldCpu := getTotalCPUUsage("before cpuTest info test") + Context("ConcurrentBusyLoopCPUWaster", func() { + Context("UseCPU", FlakeAttempts(3), func() { + DescribeTable("should use cpu", + func(utilisation uint64, duration time.Duration) { + oldCpu := getTotalCPUUsage("before cpuTest info test") - By("allocating cpu") - cpuInfo := &app.ConcurrentBusyLoopCPUWaster{} - cpuInfo.UseCPU(utilisation, duration) - Expect(cpuInfo.IsRunning()).To(Equal(true)) - Eventually(cpuInfo.IsRunning).WithTimeout(duration + time.Second).WithPolling(time.Second).Should(Equal(false)) - newCpu := getTotalCPUUsage("after cpuTest info test") - expectedCPUUsage := multiplyDurationByPercentage(duration, utilisation) - // Give 10% tolerance - but at least 1 second, as this is the internal resolution of the CPU waster - tolerance := max(multiplyDurationByPercentage(expectedCPUUsage, 10), time.Second) - Expect(newCpu - oldCpu).To(BeNumerically("~", expectedCPUUsage, tolerance)) - }, - Entry("25% for 10 seconds", uint64(25), time.Second*10), - Entry("50% for 10 seconds", uint64(50), time.Second*10), - Entry("100% for 10 seconds", uint64(100), time.Second*10), - Entry("200% for 10 seconds", uint64(200), time.Second*10), - Entry("400% for 10 seconds", uint64(400), time.Second*10), - ) + By("allocating cpu") + cpuWaster := &app.ConcurrentBusyLoopCPUWaster{} + cpuWaster.UseCPU(utilisation, duration) + Expect(cpuWaster.IsRunning()).To(Equal(true)) + Eventually(cpuWaster.IsRunning).WithTimeout(duration + time.Second).WithPolling(time.Second).Should(Equal(false)) + newCpu := getTotalCPUUsage("after cpuTest info test") + expectedCPUUsage := multiplyDurationByPercentage(duration, utilisation) + // Give 10% tolerance - but at least 1 second, as this is the internal resolution of the CPU waster + tolerance := max(multiplyDurationByPercentage(expectedCPUUsage, 10), time.Second) + Expect(newCpu - oldCpu).To(BeNumerically("~", expectedCPUUsage, tolerance)) + }, + Entry("25% for 10 seconds", uint64(25), time.Second*10), + Entry("50% for 10 seconds", uint64(50), time.Second*10), + Entry("100% for 10 seconds", uint64(100), time.Second*10), + Entry("200% for 10 seconds", uint64(200), time.Second*10), + Entry("400% for 10 seconds", uint64(400), time.Second*10), + ) + }) }) }) From 9f7bf824d73045b258e9ed8a515e3fd6d56f1488 Mon Sep 17 00:00:00 2001 From: Silvestre Zabala Date: Tue, 2 Apr 2024 15:22:40 +0200 Subject: [PATCH 4/4] misc cleanups - `min` is now builtin - `RWMutex` captures intent better --- src/acceptance/assets/app/go_app/go.mod | 2 +- .../assets/app/go_app/internal/app/cpu.go | 14 +++----------- .../assets/app/go_app/internal/app/cpu_test.go | 6 +++--- 3 files changed, 7 insertions(+), 15 deletions(-) diff --git a/src/acceptance/assets/app/go_app/go.mod b/src/acceptance/assets/app/go_app/go.mod index 443f0200f3..443bd29177 100644 --- a/src/acceptance/assets/app/go_app/go.mod +++ b/src/acceptance/assets/app/go_app/go.mod @@ -25,7 +25,6 @@ require ( go.opentelemetry.io/otel/sdk v1.24.0 go.opentelemetry.io/otel/trace v1.24.0 go.uber.org/zap v1.27.0 - golang.org/x/exp v0.0.0-20240325151524-a685a6edb6d8 ) require ( @@ -62,6 +61,7 @@ require ( go.uber.org/multierr v1.11.0 // indirect golang.org/x/arch v0.7.0 // indirect golang.org/x/crypto v0.21.0 // indirect + golang.org/x/exp v0.0.0-20240325151524-a685a6edb6d8 // indirect golang.org/x/mod v0.16.0 // indirect golang.org/x/net v0.22.0 // indirect golang.org/x/sync v0.6.0 // indirect diff --git a/src/acceptance/assets/app/go_app/internal/app/cpu.go b/src/acceptance/assets/app/go_app/internal/app/cpu.go index ef33342f83..35733cb307 100644 --- a/src/acceptance/assets/app/go_app/internal/app/cpu.go +++ b/src/acceptance/assets/app/go_app/internal/app/cpu.go @@ -9,7 +9,6 @@ import ( "github.com/gin-gonic/gin" "github.com/go-logr/logr" - "golang.org/x/exp/constraints" ) //counterfeiter:generate . CPUWaster @@ -20,7 +19,7 @@ type CPUWaster interface { } type ConcurrentBusyLoopCPUWaster struct { - mu sync.Mutex + mu sync.RWMutex isRunning bool } @@ -98,8 +97,8 @@ func (m *ConcurrentBusyLoopCPUWaster) UseCPU(utilisation uint64, duration time.D } func (m *ConcurrentBusyLoopCPUWaster) IsRunning() bool { - m.mu.Lock() - defer m.mu.Unlock() + m.mu.RLock() + defer m.mu.RUnlock() return m.isRunning } @@ -114,10 +113,3 @@ func (m *ConcurrentBusyLoopCPUWaster) startTest() { defer m.mu.Unlock() m.isRunning = true } - -func min[T constraints.Ordered](a, b T) T { - if a < b { - return a - } - return b -} diff --git a/src/acceptance/assets/app/go_app/internal/app/cpu_test.go b/src/acceptance/assets/app/go_app/internal/app/cpu_test.go index 73af7ca7af..0d8d3c7fdd 100644 --- a/src/acceptance/assets/app/go_app/internal/app/cpu_test.go +++ b/src/acceptance/assets/app/go_app/internal/app/cpu_test.go @@ -59,14 +59,14 @@ var _ = Describe("CPU tests", func() { Context("UseCPU", FlakeAttempts(3), func() { DescribeTable("should use cpu", func(utilisation uint64, duration time.Duration) { - oldCpu := getTotalCPUUsage("before cpuTest info test") + oldCpu := getTotalCPUUsage("before test") - By("allocating cpu") + By("wasting cpu time") cpuWaster := &app.ConcurrentBusyLoopCPUWaster{} cpuWaster.UseCPU(utilisation, duration) Expect(cpuWaster.IsRunning()).To(Equal(true)) Eventually(cpuWaster.IsRunning).WithTimeout(duration + time.Second).WithPolling(time.Second).Should(Equal(false)) - newCpu := getTotalCPUUsage("after cpuTest info test") + newCpu := getTotalCPUUsage("after test") expectedCPUUsage := multiplyDurationByPercentage(duration, utilisation) // Give 10% tolerance - but at least 1 second, as this is the internal resolution of the CPU waster tolerance := max(multiplyDurationByPercentage(expectedCPUUsage, 10), time.Second)