From b9c541fca3f8ef1f125163d5d39b5970644931cb Mon Sep 17 00:00:00 2001 From: Guillaume Nodet Date: Sat, 1 Aug 2026 19:31:09 +0200 Subject: [PATCH] Add AsyncDrainWriter to eliminate PrintWriter lock contention MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit During parallel model building, multiple PhasingExecutor threads log concurrently via SLF4J → ProjectBuildLogAppender → SimpleBuildEventListener → PrintWriter.println(). Since PrintWriter.println() is synchronized, this creates significant contention (1,470ms blocked time on a 4383-module project with -T1C). AsyncDrainWriter wraps the writer Consumer with a lock-free ConcurrentLinkedQueue and a non-blocking tryLock() drain pattern: - Producers enqueue messages (CAS, no blocking) - At most one thread drains the queue to the underlying PrintWriter - Other threads return immediately after enqueue - close() performs a final blocking drain to ensure no messages are lost JFR results on 4383-module diamond project (validate -T1C): - PrintWriter contention: 1,470ms → 0ms (eliminated) - PhasingExecutor contention: 546ms → 49ms (side effect) - Median wall time: -485ms (-3.3%) - Run-to-run variance halved (range 2.70s → 1.33s) Co-Authored-By: Claude Opus 4.6 --- .../maven/cling/invoker/LookupInvoker.java | 11 +- .../maven/logging/AsyncDrainWriter.java | 106 ++++++++++++++++++ 2 files changed, 115 insertions(+), 2 deletions(-) create mode 100644 impl/maven-core/src/main/java/org/apache/maven/logging/AsyncDrainWriter.java diff --git a/impl/maven-cli/src/main/java/org/apache/maven/cling/invoker/LookupInvoker.java b/impl/maven-cli/src/main/java/org/apache/maven/cling/invoker/LookupInvoker.java index 40d3bb4926a4..02f2f1d4bcdc 100644 --- a/impl/maven-cli/src/main/java/org/apache/maven/cling/invoker/LookupInvoker.java +++ b/impl/maven-cli/src/main/java/org/apache/maven/cling/invoker/LookupInvoker.java @@ -78,6 +78,7 @@ import org.apache.maven.impl.SettingsUtilsV4; import org.apache.maven.jline.FastTerminal; import org.apache.maven.jline.MessageUtils; +import org.apache.maven.logging.AsyncDrainWriter; import org.apache.maven.logging.BuildEventListener; import org.apache.maven.logging.LoggingOutputStream; import org.apache.maven.logging.ProjectBuildLogAppender; @@ -415,24 +416,30 @@ protected Consumer determineWriter(C context) { } protected Consumer doDetermineWriter(C context) { + Consumer raw; if (context.options().logFile().isPresent()) { Path logFile = context.cwd.resolve(context.options().logFile().get()); try { PrintWriter printWriter = new PrintWriter(Files.newBufferedWriter(logFile), true); context.closeables.add(printWriter); - return printWriter::println; + raw = printWriter::println; } catch (IOException e) { throw new MavenException("Unable to redirect logging to " + logFile, e); } } else { // Given the terminal creation has been offloaded to a different thread, // do not pass directly the terminal writer - return msg -> { + raw = msg -> { PrintWriter pw = context.terminal.writer(); pw.println(msg); pw.flush(); }; } + // Wrap with lock-free async drain to eliminate PrintWriter synchronized contention + // when multiple PhasingExecutor threads log concurrently during parallel model building. + AsyncDrainWriter asyncWriter = new AsyncDrainWriter(raw); + context.closeables.add(asyncWriter); + return asyncWriter; } protected void activateLogging(C context) throws Exception { diff --git a/impl/maven-core/src/main/java/org/apache/maven/logging/AsyncDrainWriter.java b/impl/maven-core/src/main/java/org/apache/maven/logging/AsyncDrainWriter.java new file mode 100644 index 000000000000..73ee815a3178 --- /dev/null +++ b/impl/maven-core/src/main/java/org/apache/maven/logging/AsyncDrainWriter.java @@ -0,0 +1,106 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, + * software distributed under the License is distributed on an + * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY + * KIND, either express or implied. See the License for the + * specific language governing permissions and limitations + * under the License. + */ +package org.apache.maven.logging; + +import java.util.concurrent.ConcurrentLinkedQueue; +import java.util.concurrent.locks.ReentrantLock; +import java.util.function.Consumer; + +/** + * A lock-free buffering wrapper around a {@link Consumer Consumer<String>} that + * eliminates contention when multiple threads log concurrently. + *

+ * Callers enqueue messages into a {@link ConcurrentLinkedQueue} (lock-free), + * then attempt a non-blocking drain via {@link ReentrantLock#tryLock()}. + * If another thread is already draining, the caller returns immediately — + * its message will be picked up by the ongoing or next drain cycle. + * This ensures that at most one thread writes to the underlying consumer + * at any time, without blocking producers. + *

+ * The pattern eliminates the {@code synchronized} contention in + * {@link java.io.PrintWriter#println(String)} that occurs when multiple + * {@link org.apache.maven.impl.util.PhasingExecutor} threads log during + * parallel model building. + * + * @since 4.0.0 + */ +public class AsyncDrainWriter implements Consumer, AutoCloseable { + + private final Consumer delegate; + private final ConcurrentLinkedQueue queue = new ConcurrentLinkedQueue<>(); + private final ReentrantLock drainLock = new ReentrantLock(); + + public AsyncDrainWriter(Consumer delegate) { + this.delegate = delegate; + } + + @Override + public void accept(String msg) { + queue.add(msg); + tryDrain(); + } + + /** + * Attempts a non-blocking drain of all queued messages. + * Only one thread drains at a time; others return immediately. + * After releasing the lock, a re-check ensures no message is + * stranded by a race between enqueue and the last poll. + */ + private void tryDrain() { + if (drainLock.tryLock()) { + try { + drain(); + } finally { + drainLock.unlock(); + } + // Re-check: a message may have been enqueued after our last poll() + // but before unlock(). The enqueuer's tryLock() would have failed, + // so we need to pick it up here. + if (!queue.isEmpty() && drainLock.tryLock()) { + try { + drain(); + } finally { + drainLock.unlock(); + } + } + } + } + + private void drain() { + String m; + while ((m = queue.poll()) != null) { + delegate.accept(m); + } + } + + /** + * Flushes all remaining buffered messages to the delegate. + * Blocks until the drain is complete — call this before shutdown + * to ensure no messages are lost. + */ + @Override + public void close() { + drainLock.lock(); + try { + drain(); + } finally { + drainLock.unlock(); + } + } +}