[fix][test]fix flaky KeySharedSubscriptionBrokerCacheTest.testReplayQueueReadsGettingCached #24955

3pacccccc · 2025-11-06T15:29:00Z

Motivation

the test log is: https://gist.github.com/3pacccccc/7050810fa187f17046d826e7971c174a
From the error logs, we can see the exact failure:

java.util.ConcurrentModificationException: null
	at java.base/java.util.ArrayList$Itr.checkForComodification(ArrayList.java:1013) ~[?:?]
	at java.base/java.util.ArrayList$Itr.next(ArrayList.java:967) ~[?:?]
	at org.apache.bookkeeper.client.PulsarMockLedgerHandle.getLength(PulsarMockLedgerHandle.java:235) ~[testmocks-4.2.0-SNAPSHOT.jar:4.17.2]
	at org.apache.bookkeeper.mledger.impl.cache.RangeEntryCacheImpl.getEstimatedEntrySize(RangeEntryCacheImpl.java:503) ~[managed-ledger-4.2.0-SNAPSHOT.jar:4.2.0-SNAPSHOT]
	at org.apache.bookkeeper.mledger.impl.cache.RangeEntryCacheImpl.asyncReadEntriesByPosition(RangeEntryCacheImpl.java:310) ~[managed-ledger-4.2.0-SNAPSHOT.jar:4.2.0-SNAPSHOT]
	at org.apache.bookkeeper.mledger.impl.cache.RangeEntryCacheImpl.asyncReadEntry0(RangeEntryCacheImpl.java:286) ~[managed-ledger-4.2.0-SNAPSHOT.jar:4.2.0-SNAPSHOT]
	at org.apache.bookkeeper.mledger.impl.cache.RangeEntryCacheImpl.asyncReadEntry(RangeEntryCacheImpl.java:268) ~[managed-ledger-4.2.0-SNAPSHOT.jar:4.2.0-SNAPSHOT]
	at org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl.asyncReadEntry(ManagedLedgerImpl.java:2438) ~[managed-ledger-4.2.0-SNAPSHOT.jar:?]
	at org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl.internalReadFromLedger(ManagedLedgerImpl.java:2408) ~[managed-ledger-4.2.0-SNAPSHOT.jar:?]
	at org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl.asyncReadEntries(ManagedLedgerImpl.java:2089) ~[managed-ledger-4.2.0-SNAPSHOT.jar:?]
	at org.apache.bookkeeper.mledger.impl.ManagedCursorImpl.asyncReadEntriesWithSkip(ManagedCursorImpl.java:918) ~[managed-ledger-4.2.0-SNAPSHOT.jar:?]
	at org.apache.bookkeeper.mledger.impl.ManagedCursorImpl.asyncReadEntriesWithSkipOrWait(ManagedCursorImpl.java:1071) ~[managed-ledger-4.2.0-SNAPSHOT.jar:?]
	at org.apache.pulsar.broker.service.persistent.PersistentDispatcherMultipleConsumers.readMoreEntries(PersistentDispatcherMultipleConsumers.java:430) ~[classes/:?]
	at org.apache.pulsar.broker.service.persistent.PersistentDispatcherMultipleConsumers.lambda$readMoreEntriesAsync$4(PersistentDispatcherMultipleConsumers.java:324) ~[classes/:?]

The root cause analysis shows:

Thread safety issue: The entries list in PulsarMockLedgerHandle was implemented as an ArrayList, which is not thread-safe
Concurrent access: Multiple threads were concurrently reading from and potentially modifying the entries list during test execution
Cache invalidation: When the ConcurrentModificationException occurred, it caused all caches to be removed, making all subsequent read operations fail1
Complete read failure: With the cache cleared and the test's interceptor configured to fail all BookKeeper reads (to enforce cache-only behavior), all subsequent read operations failed with NonRecoverableLedgerException: Should not read from BK since cache should be used2

Modifications

Replace ArrayList with CopyOnWriteArrayList for the entries field in PulsarMockLedgerHandle

Verifying this change

Documentation

doc
doc-required
doc-not-needed
doc-complete

Matching PR in forked repository

PR in forked repository: 3pacccccc#30

lhotari · 2025-11-06T19:31:15Z

This change causes a test to fail:

  Error:  Tests run: 21, Failures: 1, Errors: 0, Skipped: 6, Time elapsed: 1189 s <<< FAILURE! -- in org.apache.bookkeeper.mledger.offload.jcloud.impl.BlobStoreManagedLedgerOffloaderTest
  Error:  org.apache.bookkeeper.mledger.offload.jcloud.impl.BlobStoreManagedLedgerOffloaderTest.testReadHandlerState -- Time elapsed: 60.01 s <<< FAILURE!
  org.testng.internal.thread.ThreadTimeoutException: Method org.apache.bookkeeper.mledger.offload.jcloud.impl.BlobStoreManagedLedgerOffloaderTest.testReadHandlerState() didn't finish within the time-out 60000
  	at java.base/java.util.Arrays.copyOf(Arrays.java:3482)
  	at java.base/java.util.concurrent.CopyOnWriteArrayList.add(CopyOnWriteArrayList.java:465)
  	at org.apache.bookkeeper.client.PulsarMockLedgerHandle.addEntry(PulsarMockLedgerHandle.java:162)
  	at org.apache.bookkeeper.mledger.offload.jcloud.impl.BlobStoreManagedLedgerOffloaderBase.buildReadHandle(BlobStoreManagedLedgerOffloaderBase.java:160)
  	at org.apache.bookkeeper.mledger.offload.jcloud.impl.BlobStoreManagedLedgerOffloaderTest.testReadHandlerState(BlobStoreManagedLedgerOffloaderTest.java:179)
  	at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
  	at java.base/java.lang.reflect.Method.invoke(Method.java:580)
  	at org.testng.internal.invokers.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:139)
  	at org.testng.internal.invokers.InvokeMethodRunnable.runOne(InvokeMethodRunnable.java:47)
  	at org.testng.internal.invokers.InvokeMethodRunnable.call(InvokeMethodRunnable.java:76)
  	at org.testng.internal.invokers.InvokeMethodRunnable.call(InvokeMethodRunnable.java:11)
  	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317)
  	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
  	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
  	at java.base/java.lang.Thread.run(Thread.java:1583)

perhaps it adds too much overhead for that test.

lhotari · 2025-11-06T19:36:45Z

I think we should simply use Collections.synchronizedList(new ArrayList<>()) instead, however it's possible that it introduces deadlocks.

Another optimization would be to add a counter to replace the iteration:

pulsar/testmocks/src/main/java/org/apache/bookkeeper/client/PulsarMockLedgerHandle.java

Lines 232 to 240 in 186b503

    
           @Override 
        
           public long getLength() { 
        
               long length = 0; 
        
               for (LedgerEntryImpl entry : entries) { 
        
                   length += entry.getLength(); 
        
               } 
        
               return length; 
        
           }

3pacccccc · 2025-11-07T06:14:20Z

I think we should simply use Collections.synchronizedList(new ArrayList<>()) instead, however it's possible that it introduces deadlocks.

Another optimization would be to add a counter to replace the iteration:

pulsar/testmocks/src/main/java/org/apache/bookkeeper/client/PulsarMockLedgerHandle.java

Lines 232 to 240 in 186b503

@Override

public long getLength() {

long length = 0;

for (LedgerEntryImpl entry : entries) {

length += entry.getLength();

}

return length;

}

@lhotari changed to Collections.synchronizedList(new ArrayList<>()), please take a look

lhotari · 2025-11-07T07:45:18Z

@lhotari changed to Collections.synchronizedList(new ArrayList<>()), please take a look

It's necessary to implement

pulsar/testmocks/src/main/java/org/apache/bookkeeper/client/PulsarMockLedgerHandle.java

Lines 232 to 240 in 186b503

    
           @Override 
        
           public long getLength() { 
        
               long length = 0; 
        
               for (LedgerEntryImpl entry : entries) { 
        
                   length += entry.getLength(); 
        
               } 
        
               return length; 
        
           }

using a counter. The ConcurrentModificationException won't get fixed with synchronized list. It's not a large change to do so.

PulsarMockLedgerHandle.getLength would need to be implemented using a counter where the counter value is incremented when entries are added.

3pacccccc · 2025-11-07T08:00:16Z

@lhotari changed to Collections.synchronizedList(new ArrayList<>()), please take a look

It's necessary to implement

pulsar/testmocks/src/main/java/org/apache/bookkeeper/client/PulsarMockLedgerHandle.java

Lines 232 to 240 in 186b503

@Override

public long getLength() {

long length = 0;

for (LedgerEntryImpl entry : entries) {

length += entry.getLength();

}

return length;

}

using a counter. The ConcurrentModificationException won't get fixed with synchronized list. It's not a large change to do so.

@lhotari sure, I'll add a counter for this

codecov-commenter · 2025-11-07T08:53:17Z

Codecov Report

✅ All modified and coverable lines are covered by tests.
✅ Project coverage is 74.23%. Comparing base (7c343d0) to head (62ff04c).
⚠️ Report is 6 commits behind head on master.

Additional details and impacted files

@@             Coverage Diff              @@
##             master   #24955      +/-   ##
============================================
- Coverage     74.24%   74.23%   -0.01%     
+ Complexity    33911    33604     -307     
============================================
  Files          1913     1920       +7     
  Lines        149510   150062     +552     
  Branches      17373    17404      +31     
============================================
+ Hits         110997   111405     +408     
- Misses        29685    29772      +87     
- Partials       8828     8885      +57

Flag	Coverage Δ
inttests	`26.25% <ø> (-0.04%)`	⬇️
systests	`22.83% <ø> (+0.11%)`	⬆️
unittests	`73.77% <ø> (-0.01%)`	⬇️

Flags with carried forward coverage won't be shown. Click here to find out more.
see 108 files with indirect coverage changes

🚀 New features to boost your workflow:

❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.
📦 JS Bundle Analysis: Save yourself from yourself by tracking and limiting bundle sizes in JS merges.

Copilot

Pull Request Overview

This PR optimizes the getLength() method in mock BookKeeper classes by maintaining a running counter instead of iterating through entries on each call. The changes also add thread-safety by wrapping the entries list in a synchronized collection.

Key changes:

Introduced AtomicLong totalLengthCounter to track cumulative entry lengths
Replaced ArrayList with Collections.synchronizedList for thread-safe entry storage
Updated getLength() implementations to return the counter value directly

Reviewed Changes

Copilot reviewed 3 out of 3 changed files in this pull request and generated 3 comments.

File	Description
PulsarMockReadHandle.java	Added `totalLengthCounter` parameter and updated `getLength()` to use the counter
PulsarMockLedgerHandle.java	Introduced counter field, made entries list thread-safe, and updated entry addition logic to maintain the counter
PulsarMockBookKeeper.java	Updated read handle creation to pass counter reference and added counter reset in shutdown

💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.

testmocks/src/main/java/org/apache/bookkeeper/client/PulsarMockLedgerHandle.java

…QueueReadsGettingCached (#24955) (cherry picked from commit aeb1bd1)

…QueueReadsGettingCached (apache#24955) (cherry picked from commit aeb1bd1)

…QueueReadsGettingCached (apache#24955) (cherry picked from commit aeb1bd1) (cherry picked from commit 6d07787)

…QueueReadsGettingCached (apache#24955) (cherry picked from commit aeb1bd1) (cherry picked from commit 421d646)

fix flaky test

378623c

github-actions bot added the doc-not-needed Your PR changes do not impact docs label Nov 6, 2025

lhotari previously approved these changes Nov 6, 2025

View reviewed changes

lhotari assigned 3pacccccc Nov 6, 2025

lhotari added this to the 4.2.0 milestone Nov 6, 2025

lhotari added release/4.1.2 release/3.3.10 release/4.0.8 release/3.0.15 labels Nov 6, 2025

replace CopyOnWriteArrayList with Collections.synchronizedList

8e824a6

add totalLengthCounter for PulsarMockLedgerHandle

504ca9a

3pacccccc requested a review from lhotari November 9, 2025 14:35

lhotari approved these changes Nov 9, 2025

View reviewed changes

lhotari requested a review from Copilot November 9, 2025 17:02

Copilot AI reviewed Nov 9, 2025

View reviewed changes

applied copilot's comments

62ff04c

Technoboy- approved these changes Nov 11, 2025

View reviewed changes

Technoboy- merged commit aeb1bd1 into apache:master Nov 11, 2025
96 of 100 checks passed

3pacccccc deleted the fix-flaky-test branch November 11, 2025 07:23

lhotari pushed a commit that referenced this pull request Nov 11, 2025

[fix][test] Fix flaky KeySharedSubscriptionBrokerCacheTest.testReplay…

fb8a0e8

…QueueReadsGettingCached (#24955) (cherry picked from commit aeb1bd1)

lhotari pushed a commit that referenced this pull request Nov 11, 2025

[fix][test] Fix flaky KeySharedSubscriptionBrokerCacheTest.testReplay…

abd3246

…QueueReadsGettingCached (#24955) (cherry picked from commit aeb1bd1)

lhotari added cherry-picked/branch-3.3 cherry-picked/branch-4.1 labels Nov 11, 2025

lhotari pushed a commit that referenced this pull request Nov 11, 2025

[fix][test] Fix flaky KeySharedSubscriptionBrokerCacheTest.testReplay…

6d07787

…QueueReadsGettingCached (#24955) (cherry picked from commit aeb1bd1)

lhotari added the cherry-picked/branch-3.0 label Nov 11, 2025

lhotari pushed a commit that referenced this pull request Nov 11, 2025

[fix][test] Fix flaky KeySharedSubscriptionBrokerCacheTest.testReplay…

421d646

…QueueReadsGettingCached (#24955) (cherry picked from commit aeb1bd1)

lhotari added the cherry-picked/branch-4.0 label Nov 11, 2025

nodece pushed a commit to nodece/pulsar that referenced this pull request Nov 12, 2025

[fix][test] Fix flaky KeySharedSubscriptionBrokerCacheTest.testReplay…

87beedc

…QueueReadsGettingCached (apache#24955) (cherry picked from commit aeb1bd1)

manas-ctds pushed a commit to datastax/pulsar that referenced this pull request Nov 13, 2025

[fix][test] Fix flaky KeySharedSubscriptionBrokerCacheTest.testReplay…

37ce8de

…QueueReadsGettingCached (apache#24955) (cherry picked from commit aeb1bd1) (cherry picked from commit 6d07787)

srinath-ctds pushed a commit to datastax/pulsar that referenced this pull request Nov 13, 2025

[fix][test] Fix flaky KeySharedSubscriptionBrokerCacheTest.testReplay…

c74e273

…QueueReadsGettingCached (apache#24955) (cherry picked from commit aeb1bd1) (cherry picked from commit 6d07787)

manas-ctds pushed a commit to datastax/pulsar that referenced this pull request Nov 13, 2025

[fix][test] Fix flaky KeySharedSubscriptionBrokerCacheTest.testReplay…

0307f24

…QueueReadsGettingCached (apache#24955) (cherry picked from commit aeb1bd1) (cherry picked from commit 421d646)

srinath-ctds pushed a commit to datastax/pulsar that referenced this pull request Nov 14, 2025

[fix][test] Fix flaky KeySharedSubscriptionBrokerCacheTest.testReplay…

9ab8c19

…QueueReadsGettingCached (apache#24955) (cherry picked from commit aeb1bd1) (cherry picked from commit 421d646)

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

[fix][test]fix flaky KeySharedSubscriptionBrokerCacheTest.testReplayQueueReadsGettingCached #24955

[fix][test]fix flaky KeySharedSubscriptionBrokerCacheTest.testReplayQueueReadsGettingCached #24955

3pacccccc commented Nov 6, 2025

Uh oh!

lhotari commented Nov 6, 2025

Uh oh!

lhotari commented Nov 6, 2025

Uh oh!

3pacccccc commented Nov 7, 2025

Uh oh!

lhotari commented Nov 7, 2025

Uh oh!

3pacccccc commented Nov 7, 2025

Uh oh!

codecov-commenter commented Nov 7, 2025 •

edited

Loading

Uh oh!

Copilot AI left a comment

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

4 participants

[fix][test]fix flaky KeySharedSubscriptionBrokerCacheTest.testReplayQueueReadsGettingCached #24955

[fix][test]fix flaky KeySharedSubscriptionBrokerCacheTest.testReplayQueueReadsGettingCached #24955

Conversation

3pacccccc commented Nov 6, 2025

Motivation

Modifications

Verifying this change

Documentation

Matching PR in forked repository

Uh oh!

lhotari commented Nov 6, 2025

Uh oh!

lhotari commented Nov 6, 2025

Uh oh!

3pacccccc commented Nov 7, 2025

Uh oh!

lhotari commented Nov 7, 2025

Uh oh!

3pacccccc commented Nov 7, 2025

Uh oh!

codecov-commenter commented Nov 7, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Codecov Report

Uh oh!

Copilot AI left a comment

Choose a reason for hiding this comment

Pull Request Overview

Reviewed Changes

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

4 participants

codecov-commenter commented Nov 7, 2025 •

edited

Loading