Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Unexpected results on CI with higher loop iterations #117

Open
ubiuser opened this issue Nov 23, 2023 · 0 comments
Open

Unexpected results on CI with higher loop iterations #117

ubiuser opened this issue Nov 23, 2023 · 0 comments

Comments

@ubiuser
Copy link

ubiuser commented Nov 23, 2023

Hi, I added a modified version of the example tests into my project to see what results we get on our GitLab runners and they are not what I expected when the iteration runs some extra loops.

Results:

=== RUN   TestRateLimit_Example_default
    ratelimit_test.go:20: 1 0s
    ratelimit_test.go:20: 2 0s
    ratelimit_test.go:20: 3 0s
    ratelimit_test.go:20: 4 4ms
    ratelimit_test.go:20: 5 10ms
    ratelimit_test.go:20: 6 10ms
    ratelimit_test.go:20: 7 10ms
    ratelimit_test.go:20: 8 10ms
    ratelimit_test.go:20: 9 10ms
    ratelimit_test.go:20: 10 10ms
    ratelimit_test.go:20: 11 10ms
    ratelimit_test.go:20: 12 10ms
    ratelimit_test.go:20: 13 10ms
    ratelimit_test.go:20: 14 10ms
    ratelimit_test.go:20: 15 10ms
    ratelimit_test.go:20: 16 10ms
    ratelimit_test.go:20: 17 10ms
    ratelimit_test.go:20: 18 10ms
    ratelimit_test.go:20: 19 10ms
    ratelimit_test.go:20: 20 10ms
    ratelimit_test.go:20: 21 10ms
    ratelimit_test.go:20: 22 10ms
    ratelimit_test.go:20: 23 10ms
    ratelimit_test.go:20: 24 10ms
    ratelimit_test.go:20: 25 10ms
    ratelimit_test.go:20: 26 10ms
    ratelimit_test.go:20: 27 10ms
    ratelimit_test.go:20: 28 10ms
    ratelimit_test.go:20: 29 10ms
    ratelimit_test.go:20: 30 10ms
    ratelimit_test.go:20: 31 10ms
    ratelimit_test.go:20: 32 10ms
    ratelimit_test.go:20: 33 58ms
    ratelimit_test.go:20: 34 0s
    ratelimit_test.go:20: 35 0s
    ratelimit_test.go:20: 36 0s
    ratelimit_test.go:20: 37 0s
    ratelimit_test.go:20: 38 2ms
    ratelimit_test.go:20: 39 10ms
    ratelimit_test.go:20: 40 10ms
    ratelimit_test.go:20: 41 10ms
    ratelimit_test.go:20: 42 68ms
    ratelimit_test.go:20: 43 0s
    ratelimit_test.go:20: 44 0s
    ratelimit_test.go:20: 45 0s
    ratelimit_test.go:20: 46 0s
    ratelimit_test.go:20: 47 0s
    ratelimit_test.go:20: 48 2ms
    ratelimit_test.go:20: 49 10ms
--- FAIL: TestRateLimit_Example_default (0.50s)

and

=== RUN   TestRateLimit_Example_withoutSlack
    ratelimit_test.go:46: 1 10ms
    ratelimit_test.go:46: 2 10ms
    ratelimit_test.go:46: 3 10ms
    ratelimit_test.go:46: 4 55.767826ms
    ratelimit_test.go:46: 5 10ms
    ratelimit_test.go:46: 6 10ms
    ratelimit_test.go:46: 7 10ms
    ratelimit_test.go:46: 8 70.044275ms
    ratelimit_test.go:46: 9 10ms
    ratelimit_test.go:46: 10 10ms
    ratelimit_test.go:46: 11 10ms
    ratelimit_test.go:46: 12 10ms
    ratelimit_test.go:46: 13 10ms
    ratelimit_test.go:46: 14 10ms
    ratelimit_test.go:46: 15 10ms
    ratelimit_test.go:46: 16 10ms
    ratelimit_test.go:46: 17 10ms
    ratelimit_test.go:46: 18 10ms
    ratelimit_test.go:46: 19 10ms
    ratelimit_test.go:46: 20 10ms
    ratelimit_test.go:46: 21 10ms
    ratelimit_test.go:46: 22 10ms
    ratelimit_test.go:46: 23 10ms
    ratelimit_test.go:46: 24 10ms
    ratelimit_test.go:46: 25 10ms
    ratelimit_test.go:46: 26 29.903942ms
    ratelimit_test.go:46: 27 10ms
    ratelimit_test.go:46: 28 10ms
    ratelimit_test.go:46: 29 10ms
    ratelimit_test.go:46: 30 10ms
    ratelimit_test.go:46: 31 60.066856ms
    ratelimit_test.go:46: 32 10ms
    ratelimit_test.go:46: 33 10ms
    ratelimit_test.go:46: 34 10ms
    ratelimit_test.go:46: 35 10ms
    ratelimit_test.go:46: 36 59.972692ms
    ratelimit_test.go:46: 37 10ms
    ratelimit_test.go:46: 38 10ms
    ratelimit_test.go:46: 39 10ms
    ratelimit_test.go:46: 40 70.053405ms
    ratelimit_test.go:46: 41 10ms
    ratelimit_test.go:46: 42 10ms
    ratelimit_test.go:46: 43 10ms
    ratelimit_test.go:46: 44 69.93269ms
    ratelimit_test.go:46: 45 10ms
    ratelimit_test.go:46: 46 10ms
    ratelimit_test.go:46: 47 10ms
    ratelimit_test.go:46: 48 70.018764ms
    ratelimit_test.go:46: 49 10ms
--- FAIL: TestRateLimit_Example_withoutSlack (0.90s)

The modified tests are very plain, essentially I just replaced the print statement with t.Log and the loop runs more iterations.

func TestRateLimit_Example_default(t *testing.T) {
	rl := ratelimit.New(100) // per second, some slack.

	rl.Take()                         // Initialize.
	time.Sleep(time.Millisecond * 45) // Let some time pass.

	prev := time.Now()
	for i := 0; i < 50; i++ {
		now := rl.Take()
		if i > 0 {
			t.Log(i, now.Sub(prev).Round(time.Millisecond*2))
		}
		prev = now
	}

	t.Fail() // just to see the output

	// Output:
	// 1 0s
	// 2 0s
	// 3 0s
	// 4 4ms
	// 5 10ms
	// 6 10ms
	// 7 10ms
	// 8 10ms
	// 9 10ms
}

and

func TestRateLimit_Example_withoutSlack(t *testing.T) {
	rl := ratelimit.New(100, ratelimit.WithoutSlack) // per second, no slack.

	prev := time.Now()
	for i := 0; i < 50; i++ {
		now := rl.Take()
		if i > 0 {
			t.Log(i, now.Sub(prev))
		}
		prev = now
	}

	t.Fail() // just to see the output

	// Output:
	// 1 10ms
	// 2 10ms
	// 3 10ms
	// 4 10ms
	// 5 10ms
}

The project is based on Go 1.21 and is built with

ENV CGO_ENABLED=0 \
  GOOS=linux \
  GOARCH=amd64
RUN --mount=target=. \
  --mount=type=cache,target=/root/.cache/go-build \
  go build -a -tags netgo -ldflags "-w -s" -o "/bin/" ./cmd/...
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

1 participant