Skip to content

test_in_tail: fix flaky throttling test by allowing one extra watcher tick - #5489

Merged
kenhys merged 1 commit into
fluent:masterfrom
Watson1978:test_in_tail-throttling-upper-bound
Sep 7, 2026
Merged

kenhys merged 1 commit into
fluent:masterfrom
Watson1978:test_in_tail-throttling-upper-bound

Conversation

@Watson1978

@Watson1978 Watson1978 commented Sep 6, 2026

Copy link
Copy Markdown
Contributor

Which issue(s) this PR fixes:
Fixes #

What this PR does / why we need it:

The lines collected with throttling test still fails intermittently after #5381 and #5418, this time on the upper bound: Ruby 3.3 on macOS CI measured 3.329s against a 3.32s limit.

4) Failure: test: lines collected with throttling(TailInputTest::throttling logs at in_tail level):
  elapsed_seconds 3.329012749999947 is out of allowed range:
    lower: 0.6799999999999999 [sec]
    upper: 3.3200000000000003 [sec].

Once the file has been written, retries depend mainly on the 1s watcher timer. A tick near the 2s rate-period boundary can arrive slightly too early, delaying the next read until the following tick. Local tracing confirmed read-start intervals of both approximately 2s and 3s.

The existing 1.32s allowance covers both timer scheduling and read/observation latency. When an extra tick consumes 1s, only 0.32s remains for other delays—slightly less than this CI run needed.

This PR adds one watcher interval to the upper bound, increasing it from 3.32s to 4.32s. The lower bound and record-count assertions remain unchanged.

Docs Changes:
N/A

Release Note:
N/A

… tick

The `test "lines collected with throttling"` still fails intermittently
on CI, this time on the upper bound:

    elapsed_seconds 3.329012749999947 is out of allowed range:
      lower: 0.6799999999999999 [sec]
      upper: 3.3200000000000003 [sec].

The throttling state is re-checked only when the tail watcher is
notified. Once the file has been fully written, retries depend mainly on
the 1s timer tick. Whether the tick that lands exactly rate_period after
the previous read start already satisfies `time_spent >= rate_period`
depends on sub-millisecond scheduling differences, so the next read can
start one tick later, i.e. rate_period + 1s after the previous one.

The existing jitter (1.32s) already contains one watcher interval, but
that allowance is shared with the read/observation latency: when the
extra tick and a slow batch coincide, only 0.32s is left for the
read-time skew and the 0.1s polling of the test thread, which is not
enough on a slow runner.

Add the watcher interval to the upper bound explicitly, so the upper
bound tolerates the same read/observation latency as the lower bound on
top of the extra tick. The per-cycle line-count assertion is kept, so a
regression that actually breaks throttling is still detected.

Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
Signed-off-by: Shizuo Fujita <fujita@clear-code.com>
@Watson1978 Watson1978 added CI Test/CI issues backport to v1.19 We will backport this fix to the LTS branch labels Sep 6, 2026
@Watson1978 Watson1978 added this to the v1.20.0 milestone Sep 6, 2026
@Watson1978
Watson1978 requested a review from kenhys September 7, 2026 05:36
@kenhys
kenhys merged commit 77517f4 into fluent:master Sep 7, 2026
20 checks passed
@Watson1978
Watson1978 deleted the test_in_tail-throttling-upper-bound branch September 7, 2026 06:29
@Watson1978 Watson1978 added the backported "backport to LTS" is done label Sep 13, 2026
Watson1978 added a commit that referenced this pull request Sep 14, 2026
…one extra watcher tick (#5489) (#5495)

**Which issue(s) this PR fixes**: 
Backport #5489
Fixes #

**What this PR does / why we need it**: 

The `lines collected with throttling` test still fails intermittently
after #5381 and #5418, this time on the upper bound: [Ruby 3.3 on macOS
CI](https://github.com/fluent/fluentd/actions/runs/34003950778/job/101426224818)
measured 3.329s against a 3.32s limit.

```
4) Failure: test: lines collected with throttling(TailInputTest::throttling logs at in_tail level):
  elapsed_seconds 3.329012749999947 is out of allowed range:
    lower: 0.6799999999999999 [sec]
    upper: 3.3200000000000003 [sec].
```

Once the file has been written, retries depend mainly on the 1s watcher
timer. A tick near the 2s rate-period boundary can arrive slightly too
early, delaying the next read until the following tick. Local tracing
confirmed read-start intervals of both approximately 2s and 3s.

The existing 1.32s allowance covers both timer scheduling and
read/observation latency. When an extra tick consumes 1s, only 0.32s
remains for other delays—slightly less than this CI run needed.

This PR adds one watcher interval to the upper bound, increasing it from
3.32s to 4.32s. The lower bound and record-count assertions remain
unchanged.

**Docs Changes**:
N/A

**Release Note**:
N/A

Signed-off-by: Shizuo Fujita <fujita@clear-code.com>
Signed-off-by: github-actions[bot] <github-actions[bot]@users.noreply.github.com>
Co-authored-by: Shizuo Fujita <fujita@clear-code.com>
Co-authored-by: Claude Fable 5.1 <noreply@anthropic.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

backport to v1.19 We will backport this fix to the LTS branch backported "backport to LTS" is done CI Test/CI issues

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants