Skip to content

OAK-11606 - indexing-job: throttle messages warning about enqueuing delays in IndexWriterPool #2189

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.

Sign up for GitHub

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

Merged
nfsantos merged 1 commit into from
Mar 19, 2025
Merged

OAK-11606 - indexing-job: throttle messages warning about enqueuing delays in IndexWriterPool #2189

Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
18 changes: 12 additions & 6 deletions .../src/main/java/org/apache/jackrabbit/oak/plugins/index/lucene/writer/IndexWriterPool.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -84,6 +84,7 @@ public class IndexWriterPool {
private long updateCount = 0;
private long deleteCount = 0;
private long totalEnqueueTimeNanos = 0;
private long enqueuingDelayMessageLastLoggedMillis = 0;

private static class OperationBatch {
final long sequenceNumber;
Expand Down Expand Up @@ -379,14 +380,19 @@ private long flushBatch() {
if (seqNumber % 1000 == 0) {
LOG.info("Enqueuing batch {}, size: {}", seqNumber, batch.size());
}
long start = System.nanoTime();
long enqueuingStartNanos = System.nanoTime();
queue.put(new OperationBatch(seqNumber, batch.toArray(new Operation[0])));
long durationNanos = System.nanoTime() - start;
long durationMillis = durationNanos / 1_000_000;
long enqueuingEndNanos = System.nanoTime();
long durationNanos = enqueuingEndNanos - enqueuingStartNanos;
totalEnqueueTimeNanos += durationNanos;
if (durationMillis > 1) {
LOG.info("Enqueuing batch delayed. Seq number: {}, size: {}. Delay: {} ms",
seqNumber, batch.size(), durationMillis);
long durationMillis = durationNanos / 1_000_000;
if (durationMillis > 10) {
long currentTimeMillis = enqueuingEndNanos / 1_000_000;
if (currentTimeMillis - enqueuingDelayMessageLastLoggedMillis > TimeUnit.SECONDS.toMillis(10)) {
LOG.info("Enqueuing batch delayed. Seq number: {}, size: {}. Delay: {} ms (These messages are logged every 10 seconds)",
seqNumber, batch.size(), durationMillis);
enqueuingDelayMessageLastLoggedMillis = currentTimeMillis;
}
}
batch.clear();
return seqNumber;
Expand Down
Loading