MINOR: Less restrictive assertion in flaky BufferPool test by colinhicks · Pull Request #5799 · apache/kafka

colinhicks · 2018-10-15T14:33:29Z

We are routinely seeing CI failures from an assertion in testBlockTimeout(), which relies on the interaction between (de)allocations against a producer BufferPool, across multiple threads. I reproduced the failed assertion in my local build at a rate of 2% (N=100):

assertTrue("available memory" + pool.availableMemory(), 
    pool.availableMemory() >= 9 && pool.availableMemory() <= 10);

Here's a summary of the test history:

(KAFKA-3648; maxTimeToBlock in BufferPool.allocate should be enforced #1304) KAFKA-3648; maxTimeToBlock in BufferPool.allocate should be enforced
- Ensured timeout was properly checked and iterated during a blocked allocation.
- Added the test's deferred deallocations.
(KAFKA-4840 : BufferPool errors can cause buffer pool to go into a bad state #2659) KAFKA-4840 : BufferPool errors can cause buffer pool to go into a bad state
- Ensured proper cleanup of blocked allocation requests given an exception.
- Added assertion in question.

This patch decreases the lower bound for expected available memory, as thread scheduling entails that a variable amount of deallocation happens by the point of assertion.

The patch also makes minor clarifications to test logic and comments. On my machine, it has a 100% passing rate (N=500).

Committer Checklist (excluded from commit message)

Verify design and implementation
Verify test coverage and CI build status
Verify documentation (including upgrade notes)

ijuma · 2018-10-16T14:06:17Z

@smccauliff @lindong28 @becketqin can one of you review this?

ijuma · 2018-10-16T14:08:02Z

Thanks for the PR @colinhicks. What is the actual value of availableMemory when the test fails?

colinhicks · 2018-10-16T14:09:08Z

When the test fails, the value of availableMemory is 8.

ijuma

Thanks for the PR, left a couple of comments.

ijuma · 2018-10-20T18:10:28Z

-        assertTrue("Allocation should finish not much later than maxBlockTimeMs", endTimeMs - beginTimeMs < maxBlockTimeMs + 1000);
+        long durationMs = Time.SYSTEM.milliseconds() - beginTimeMs;
+        assertTrue("TimeoutException should not throw before maxBlockTimeMs", durationMs >= maxBlockTimeMs);
+        assertTrue("TimeoutException should throw soon after maxBlockTimeMs", durationMs < maxBlockTimeMs + 100);


You made this stricter (+100 instead of +1000), I'd not do that given Jenkins variability.

ijuma · 2018-10-20T18:18:17Z

        } catch (TimeoutException e) {
            // this is good
        }
-        assertTrue("available memory" + pool.availableMemory(), pool.availableMemory() >= 9 && pool.availableMemory() <= 10);


Instead of removing this, we should probably just say assert that it can be from 8 to 10 with a comment saying that thread scheduling sometimes means that no deallocation happens by the time we get here.

ijuma · 2018-10-20T18:30:21Z

-        assertTrue("available memory" + pool.availableMemory(), pool.availableMemory() >= 9 && pool.availableMemory() <= 10);
-        long endTimeMs = Time.SYSTEM.milliseconds();
-        assertTrue("Allocation should finish not much later than maxBlockTimeMs", endTimeMs - beginTimeMs < maxBlockTimeMs + 1000);
+        // Thread scheduling sometimes means that no deallocation happens by this point


Sorry, my bad, but we should probably say that deallocation varies instead of "no deallocation". 8 implies that at least one of them happened.

ijuma

LGTM, thanks!

colinhicks · 2018-10-20T18:34:07Z

Thanks for the review and comments @ijuma. I also updated the PR title and description to match the changes you suggested.

ijuma · 2018-10-20T18:35:55Z

Perfect, thanks.

lindong28 · 2018-10-20T20:19:02Z

@ijuma Sorry, I didn't notice your message previously.

Decrease the lower bound for expected available memory, as thread scheduling entails that a variable amount of deallocation happens by the point of assertion. Also make minor clarifications to test logic and comments. The passing rate improved from 98% to 100% locally after these changes (100+ runs). Reviewers: Ismael Juma <ismael@juma.me.uk> ### Committer Checklist (excluded from commit message) - [ ] Verify design and implementation - [ ] Verify test coverage and CI build status - [ ] Verify documentation (including upgrade notes)

ijuma · 2018-10-21T00:42:24Z

Merged to trunk, 2.1 and 2.0 branches.

Decrease the lower bound for expected available memory, as thread scheduling entails that a variable amount of deallocation happens by the point of assertion. Also make minor clarifications to test logic and comments. The passing rate improved from 98% to 100% locally after these changes (100+ runs). Reviewers: Ismael Juma <ismael@juma.me.uk> ### Committer Checklist (excluded from commit message) - [ ] Verify design and implementation - [ ] Verify test coverage and CI build status - [ ] Verify documentation (including upgrade notes)

MINOR: remove non-deterministic assertion in flaky BufferPool test.

5a60313

ijuma reviewed Oct 20, 2018

View reviewed changes

colinhicks added 2 commits October 20, 2018 14:24

Address code review feedback.

4847884

Correct spacing in assertion message.

7bb618d

colinhicks changed the title ~~MINOR: remove non-deterministic assertion in flaky BufferPool test.~~ MINOR: Less restrictive assertion in flaky BufferPool test. Oct 20, 2018

ijuma reviewed Oct 20, 2018

View reviewed changes

Clarify deallocation timing comment.

cc55247

ijuma approved these changes Oct 20, 2018

View reviewed changes

ijuma changed the title ~~MINOR: Less restrictive assertion in flaky BufferPool test.~~ MINOR: Less restrictive assertion in flaky BufferPool test Oct 21, 2018

ijuma merged commit 74f686d into apache:trunk Oct 21, 2018

colinhicks deleted the fix-buffer-pool-test-flakiness branch October 21, 2018 21:04

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

MINOR: Less restrictive assertion in flaky BufferPool test - #5799

MINOR: Less restrictive assertion in flaky BufferPool test#5799
ijuma merged 4 commits into
apache:trunkfrom
colinhicks:fix-buffer-pool-test-flakiness

colinhicks commented Oct 15, 2018 •

edited

Loading

Uh oh!

ijuma commented Oct 16, 2018

Uh oh!

ijuma commented Oct 16, 2018

Uh oh!

colinhicks commented Oct 16, 2018

Uh oh!

ijuma left a comment

Uh oh!

ijuma Oct 20, 2018

Uh oh!

ijuma Oct 20, 2018 •

edited

Loading

Uh oh!

ijuma Oct 20, 2018

Uh oh!

ijuma left a comment

Uh oh!

colinhicks commented Oct 20, 2018

Uh oh!

ijuma commented Oct 20, 2018

Uh oh!

lindong28 commented Oct 20, 2018

Uh oh!

ijuma commented Oct 21, 2018

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants

Uh oh!

Conversation

colinhicks commented Oct 15, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Committer Checklist (excluded from commit message)

Uh oh!

ijuma commented Oct 16, 2018

Uh oh!

ijuma commented Oct 16, 2018

Uh oh!

colinhicks commented Oct 16, 2018

Uh oh!

ijuma left a comment

Choose a reason for hiding this comment

Uh oh!

ijuma Oct 20, 2018

Choose a reason for hiding this comment

Uh oh!

ijuma Oct 20, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

ijuma Oct 20, 2018

Choose a reason for hiding this comment

Uh oh!

ijuma left a comment

Choose a reason for hiding this comment

Uh oh!

colinhicks commented Oct 20, 2018

Uh oh!

ijuma commented Oct 20, 2018

Uh oh!

lindong28 commented Oct 20, 2018

Uh oh!

ijuma commented Oct 21, 2018

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants

colinhicks commented Oct 15, 2018 •

edited

Loading

ijuma Oct 20, 2018 •

edited

Loading