Eliminate mutable global state in AbstractLoggingSpy

This commit is contained in:
Peter Palaga
2021-01-06 13:14:15 +01:00
parent 97f3c50503
commit 945ad3ef2a
6 changed files with 149 additions and 188 deletions

View File

@@ -154,6 +154,9 @@ public class DaemonMavenCli {
private final Map<String, ConfigurationProcessor> configurationProcessors;
/** Non-volatile, assuming that it is accessed only from the main thread */
private AbstractLoggingSpy loggingSpy = AbstractLoggingSpy.dummy();
public DaemonMavenCli() throws Exception {
slf4jLoggerFactory = LoggerFactory.getILoggerFactory();
slf4jLogger = slf4jLoggerFactory.getLogger(this.getClass().getName());
@@ -177,12 +180,18 @@ public class DaemonMavenCli {
public int main(List<String> arguments,
String workingDirectory,
String projectDirectory,
Map<String, String> clientEnv) throws Exception {
CliRequest req = new CliRequest(null, null);
req.args = arguments.toArray(new String[0]);
req.workingDirectory = workingDirectory;
req.multiModuleProjectDirectory = new File(projectDirectory);
return doMain(req, clientEnv);
Map<String, String> clientEnv,
AbstractLoggingSpy loggingSpy) throws Exception {
this.loggingSpy = loggingSpy;
try {
CliRequest req = new CliRequest(null, null);
req.args = arguments.toArray(new String[0]);
req.workingDirectory = workingDirectory;
req.multiModuleProjectDirectory = new File(projectDirectory);
return doMain(req, clientEnv);
} finally {
this.loggingSpy = AbstractLoggingSpy.dummy();
}
}
public int doMain(CliRequest cliRequest, Map<String, String> clientEnv) throws Exception {
@@ -261,7 +270,7 @@ public class DaemonMavenCli {
}
} catch (ParseException e) {
System.err.println("Unable to parse maven.config: " + e.getMessage());
AbstractLoggingSpy.instance().append(MvndHelpFormatter.displayHelp(cliManager));
loggingSpy.log(MvndHelpFormatter.displayHelp(cliManager));
throw e;
}
@@ -273,14 +282,14 @@ public class DaemonMavenCli {
}
} catch (ParseException e) {
System.err.println("Unable to parse command line options: " + e.getMessage());
AbstractLoggingSpy.instance().append(MvndHelpFormatter.displayHelp(cliManager));
loggingSpy.log(MvndHelpFormatter.displayHelp(cliManager));
throw e;
}
}
private void help(CliRequest cliRequest) throws Exception {
if (cliRequest.commandLine.hasOption(CLIManager.HELP)) {
AbstractLoggingSpy.instance().append(MvndHelpFormatter.displayHelp(new CLIManager()));
loggingSpy.log(MvndHelpFormatter.displayHelp(new CLIManager()));
throw new ExitException(0);
}
@@ -378,7 +387,7 @@ public class DaemonMavenCli {
private void version(CliRequest cliRequest) throws ExitException {
if (cliRequest.debug || cliRequest.commandLine.hasOption(CLIManager.VERSION)) {
AbstractLoggingSpy.instance().append(CLIReportingUtils.showVersion());
loggingSpy.log(CLIReportingUtils.showVersion());
if (cliRequest.commandLine.hasOption(CLIManager.VERSION)) {
throw new ExitException(0);
}
@@ -534,7 +543,7 @@ public class DaemonMavenCli {
final EventSpyDispatcher eventSpyDispatcher = container.lookup(EventSpyDispatcher.class);
configure(cliRequest, eventSpyDispatcher, configurationProcessors);
populateRequest(cliRequest, cliRequest.request, slf4jLogger, eventSpyDispatcher,
container.lookup(ModelProcessor.class), createTransferListener(cliRequest));
container.lookup(ModelProcessor.class), createTransferListener(cliRequest), loggingSpy);
executionRequestPopulator.populateDefaults(cliRequest.request);
BootstrapCoreExtensionManager resolver = container.lookup(BootstrapCoreExtensionManager.class);
return Collections
@@ -941,7 +950,7 @@ public class DaemonMavenCli {
private void populateRequest(CliRequest cliRequest) {
populateRequest(cliRequest, cliRequest.request, slf4jLogger, eventSpyDispatcher, modelProcessor,
createTransferListener(cliRequest));
createTransferListener(cliRequest), loggingSpy);
}
private static void populateRequest(
@@ -950,7 +959,8 @@ public class DaemonMavenCli {
Logger slf4jLogger,
EventSpyDispatcher eventSpyDispatcher,
ModelProcessor modelProcessor,
TransferListener transferListener) {
TransferListener transferListener,
AbstractLoggingSpy loggingSpy) {
CommandLine commandLine = cliRequest.commandLine;
String workingDirectory = cliRequest.workingDirectory;
boolean showErrors = cliRequest.showErrors;
@@ -1051,7 +1061,9 @@ public class DaemonMavenCli {
ExecutionListener executionListener = new ExecutionEventLogger();
if (eventSpyDispatcher != null) {
executionListener = new LoggingExecutionListener(eventSpyDispatcher.chainListener(executionListener));
executionListener = new LoggingExecutionListener(
eventSpyDispatcher.chainListener(executionListener),
loggingSpy);
}
String alternatePomFile = null;

View File

@@ -41,9 +41,6 @@ import java.util.concurrent.locks.ReentrantLock;
import java.util.function.Predicate;
import java.util.stream.Collectors;
import org.apache.maven.cli.DaemonMavenCli;
import org.apache.maven.execution.MavenSession;
import org.apache.maven.project.MavenProject;
import org.mvndaemon.mvnd.builder.DependencyGraph;
import org.mvndaemon.mvnd.builder.SmartBuilder;
import org.mvndaemon.mvnd.common.DaemonConnection;
import org.mvndaemon.mvnd.common.DaemonException;
@@ -54,9 +51,7 @@ import org.mvndaemon.mvnd.common.DaemonState;
import org.mvndaemon.mvnd.common.DaemonStopEvent;
import org.mvndaemon.mvnd.common.Environment;
import org.mvndaemon.mvnd.common.Message;
import org.mvndaemon.mvnd.common.Message.BuildException;
import org.mvndaemon.mvnd.common.Message.BuildRequest;
import org.mvndaemon.mvnd.common.Message.BuildStarted;
import org.mvndaemon.mvnd.common.Os;
import org.mvndaemon.mvnd.daemon.DaemonExpiration.DaemonExpirationResult;
import org.mvndaemon.mvnd.daemon.DaemonExpiration.DaemonExpirationStrategy;
@@ -429,16 +424,14 @@ public class Server implements AutoCloseable, Runnable {
private void handle(DaemonConnection connection, BuildRequest buildRequest) {
updateState(Busy);
try {
final BlockingQueue<Message> sendQueue = new PriorityBlockingQueue<>(64,
Comparator.comparingInt(this::getClassOrder).thenComparingLong(Message::timestamp));
final BlockingQueue<Message> recvQueue = new LinkedBlockingDeque<>();
final AbstractLoggingSpy loggingSpy = new AbstractLoggingSpy(sendQueue);
try (ProjectBuildLogAppender logAppender = new ProjectBuildLogAppender(loggingSpy)) {
LOGGER.info("Executing request");
BlockingQueue<Message> sendQueue = new PriorityBlockingQueue<>(64,
Comparator.comparingInt(this::getClassOrder).thenComparingLong(Message::timestamp));
BlockingQueue<Message> recvQueue = new LinkedBlockingDeque<>();
DaemonLoggingSpy loggingSpy = new DaemonLoggingSpy(sendQueue);
AbstractLoggingSpy.instance(loggingSpy);
Thread sender = new Thread(() -> {
try {
boolean flushed = true;
@@ -538,7 +531,8 @@ public class Server implements AutoCloseable, Runnable {
buildRequest.getArgs(),
buildRequest.getWorkingDir(),
buildRequest.getProjectDir(),
buildRequest.getEnv());
buildRequest.getEnv(),
loggingSpy);
LOGGER.info("Build finished, finishing message dispatch");
loggingSpy.finish(exitCode);
} catch (Throwable t) {
@@ -633,68 +627,4 @@ public class Server implements AutoCloseable, Runnable {
public String toString() {
return info.toString();
}
private static class DaemonLoggingSpy extends AbstractLoggingSpy {
private final BlockingQueue<Message> queue;
public DaemonLoggingSpy(BlockingQueue<Message> queue) {
this.queue = queue;
}
@Override
public void finish(int exitCode) throws Exception {
queue.add(new Message.BuildFinished(exitCode));
queue.add(Message.STOP_SINGLETON);
}
@Override
public void fail(Throwable t) throws Exception {
queue.add(new BuildException(t));
queue.add(Message.STOP_SINGLETON);
}
@Override
protected void onStartSession(MavenSession session) {
final int degreeOfConcurrency = session.getRequest().getDegreeOfConcurrency();
final DependencyGraph<MavenProject> dependencyGraph = DependencyGraph.fromMaven(session);
session.getRequest().getData().put(DependencyGraph.class.getName(), dependencyGraph);
final int maxThreads = degreeOfConcurrency == 1 ? 1 : dependencyGraph.computeMaxWidth(degreeOfConcurrency, 1000);
queue.add(new BuildStarted(getCurrentProject(session).getName(), session.getProjects().size(), maxThreads));
}
private MavenProject getCurrentProject(MavenSession mavenSession) {
// Workaround for https://issues.apache.org/jira/browse/MNG-6979
// MavenSession.getCurrentProject() does not return the correct value in some cases
String executionRootDirectory = mavenSession.getExecutionRootDirectory();
if (executionRootDirectory == null) {
return mavenSession.getCurrentProject();
}
return mavenSession.getProjects().stream()
.filter(p -> (p.getFile() != null && executionRootDirectory.equals(p.getFile().getParent())))
.findFirst()
.orElse(mavenSession.getCurrentProject());
}
@Override
protected void onStartProject(String projectId, String display) {
queue.add(Message.projectStarted(projectId, display));
}
@Override
protected void onStopProject(String projectId, String display) {
queue.add(Message.projectStopped(projectId, display));
}
@Override
protected void onStartMojo(String projectId, String display) {
queue.add(Message.mojoStarted(projectId, display));
}
@Override
protected void onProjectLog(String projectId, String message) {
queue.add(projectId == null ? Message.log(message) : Message.log(projectId, message));
}
}
}

View File

@@ -15,83 +15,91 @@
*/
package org.mvndaemon.mvnd.logging.smart;
import java.util.Collection;
import java.util.function.Consumer;
import org.apache.maven.execution.ExecutionEvent;
import org.apache.maven.execution.MavenSession;
import org.apache.maven.project.MavenProject;
import org.mvndaemon.mvnd.builder.DependencyGraph;
import org.mvndaemon.mvnd.common.Message;
import org.mvndaemon.mvnd.common.Message.BuildException;
import org.mvndaemon.mvnd.common.Message.BuildStarted;
public abstract class AbstractLoggingSpy {
/**
* Sends events back to the client.
*/
public class AbstractLoggingSpy {
private static final AbstractLoggingSpy DUMMY = new AbstractLoggingSpy(m -> {
});
private final Consumer<Message> queue;
private static AbstractLoggingSpy instance;
public static AbstractLoggingSpy instance() {
if (instance == null) {
instance = new AbstractLoggingSpy() {
};
}
return instance;
/**
* @return a dummy {@link AbstractLoggingSpy} that just swallows the messages and does not send them anywhere
*/
public static AbstractLoggingSpy dummy() {
return DUMMY;
}
public static void instance(AbstractLoggingSpy instance) {
AbstractLoggingSpy.instance = instance;
public AbstractLoggingSpy(Collection<Message> queue) {
this(queue::add);
}
public void append(String event) {
append(null, event);
public AbstractLoggingSpy(Consumer<Message> queue) {
this.queue = queue;
}
public void append(String projectId, String event) {
public void sessionStarted(ExecutionEvent event) {
final MavenSession session = event.getSession();
final int degreeOfConcurrency = session.getRequest().getDegreeOfConcurrency();
final DependencyGraph<MavenProject> dependencyGraph = DependencyGraph.fromMaven(session);
session.getRequest().getData().put(DependencyGraph.class.getName(), dependencyGraph);
final int maxThreads = degreeOfConcurrency == 1 ? 1 : dependencyGraph.computeMaxWidth(degreeOfConcurrency, 1000);
queue.accept(new BuildStarted(getCurrentProject(session).getName(), session.getProjects().size(), maxThreads));
}
public void projectStarted(ExecutionEvent event) {
queue.accept(Message.projectStarted(getProjectId(event), getProjectDisplay(event)));
}
public void projectLogMessage(String projectId, String event) {
String msg = event.endsWith("\n") ? event.substring(0, event.length() - 1) : event;
onProjectLog(projectId, msg);
queue.accept(projectId == null ? Message.log(msg) : Message.log(projectId, msg));
}
public void projectFinished(ExecutionEvent event) {
queue.accept(Message.projectStopped(getProjectId(event), getProjectDisplay(event)));
}
public void mojoStarted(ExecutionEvent event) {
queue.accept(Message.mojoStarted(getProjectId(event), getProjectDisplay(event)));
}
public void finish(int exitCode) throws Exception {
queue.accept(new Message.BuildFinished(exitCode));
queue.accept(Message.STOP_SINGLETON);
}
public void fail(Throwable t) throws Exception {
queue.accept(new BuildException(t));
queue.accept(Message.STOP_SINGLETON);
}
protected void notifySessionStart(ExecutionEvent event) {
onStartSession(event.getSession());
public void log(String msg) {
queue.accept(Message.log(msg));
}
protected void notifySessionFinish(ExecutionEvent event) {
onFinishSession();
}
protected void notifyProjectBuildStart(ExecutionEvent event) {
onStartProject(getProjectId(event), getProjectDisplay(event));
}
protected void notifyProjectBuildFinish(ExecutionEvent event) {
onStopProject(getProjectId(event), getProjectDisplay(event));
}
protected void notifyMojoExecutionStart(ExecutionEvent event) {
onStartMojo(getProjectId(event), getProjectDisplay(event));
}
protected void notifyMojoExecutionFinish(ExecutionEvent event) {
onStopMojo(getProjectId(event), getProjectDisplay(event));
}
protected void onStartSession(MavenSession session) {
}
protected void onFinishSession() {
}
protected void onStartProject(String projectId, String display) {
}
protected void onStopProject(String projectId, String display) {
}
protected void onStartMojo(String projectId, String display) {
}
protected void onStopMojo(String projectId, String display) {
}
protected void onProjectLog(String projectId, String message) {
private MavenProject getCurrentProject(MavenSession mavenSession) {
// Workaround for https://issues.apache.org/jira/browse/MNG-6979
// MavenSession.getCurrentProject() does not return the correct value in some cases
String executionRootDirectory = mavenSession.getExecutionRootDirectory();
if (executionRootDirectory == null) {
return mavenSession.getCurrentProject();
}
return mavenSession.getProjects().stream()
.filter(p -> (p.getFile() != null && executionRootDirectory.equals(p.getFile().getParent())))
.findFirst()
.orElse(mavenSession.getCurrentProject());
}
private String getProjectId(ExecutionEvent event) {

View File

@@ -21,9 +21,11 @@ import org.apache.maven.execution.ExecutionListener;
public class LoggingExecutionListener implements ExecutionListener {
private final ExecutionListener delegate;
private final AbstractLoggingSpy loggingSpy;
public LoggingExecutionListener(ExecutionListener delegate) {
public LoggingExecutionListener(ExecutionListener delegate, AbstractLoggingSpy loggingSpy) {
this.delegate = delegate;
this.loggingSpy = loggingSpy;
}
@Override
@@ -35,7 +37,7 @@ public class LoggingExecutionListener implements ExecutionListener {
@Override
public void sessionStarted(ExecutionEvent event) {
setMdc(event);
AbstractLoggingSpy.instance().notifySessionStart(event);
loggingSpy.sessionStarted(event);
delegate.sessionStarted(event);
}
@@ -43,13 +45,12 @@ public class LoggingExecutionListener implements ExecutionListener {
public void sessionEnded(ExecutionEvent event) {
setMdc(event);
delegate.sessionEnded(event);
AbstractLoggingSpy.instance().notifySessionFinish(event);
}
@Override
public void projectStarted(ExecutionEvent event) {
setMdc(event);
AbstractLoggingSpy.instance().notifyProjectBuildStart(event);
loggingSpy.projectStarted(event);
delegate.projectStarted(event);
}
@@ -57,27 +58,27 @@ public class LoggingExecutionListener implements ExecutionListener {
public void projectSucceeded(ExecutionEvent event) {
setMdc(event);
delegate.projectSucceeded(event);
AbstractLoggingSpy.instance().notifyProjectBuildFinish(event);
loggingSpy.projectFinished(event);
}
@Override
public void projectFailed(ExecutionEvent event) {
setMdc(event);
delegate.projectFailed(event);
AbstractLoggingSpy.instance().notifyProjectBuildFinish(event);
loggingSpy.projectFinished(event);
}
@Override
public void projectSkipped(ExecutionEvent event) {
setMdc(event);
delegate.projectSkipped(event);
AbstractLoggingSpy.instance().notifyProjectBuildFinish(event);
loggingSpy.projectFinished(event);
}
@Override
public void mojoStarted(ExecutionEvent event) {
setMdc(event);
AbstractLoggingSpy.instance().notifyMojoExecutionStart(event);
loggingSpy.mojoStarted(event);
delegate.mojoStarted(event);
}
@@ -85,21 +86,18 @@ public class LoggingExecutionListener implements ExecutionListener {
public void mojoSucceeded(ExecutionEvent event) {
setMdc(event);
delegate.mojoSucceeded(event);
AbstractLoggingSpy.instance().notifyMojoExecutionFinish(event);
}
@Override
public void mojoFailed(ExecutionEvent event) {
setMdc(event);
delegate.mojoFailed(event);
AbstractLoggingSpy.instance().notifyMojoExecutionFinish(event);
}
@Override
public void mojoSkipped(ExecutionEvent event) {
setMdc(event);
delegate.mojoSkipped(event);
AbstractLoggingSpy.instance().notifyMojoExecutionFinish(event);
}
@Override

View File

@@ -16,20 +16,22 @@
package org.mvndaemon.mvnd.logging.smart;
import ch.qos.logback.classic.Level;
import ch.qos.logback.classic.Logger;
import ch.qos.logback.classic.PatternLayout;
import ch.qos.logback.classic.pattern.ClassicConverter;
import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.core.AppenderBase;
import ch.qos.logback.core.Context;
import java.util.Map;
import org.apache.maven.shared.utils.logging.LoggerLevelRenderer;
import org.apache.maven.shared.utils.logging.MessageUtils;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
/**
* This Maven-specific appender outputs project build log messages
* to the smart logging system.
* Forwards log messages to the client.
*/
public class ProjectBuildLogAppender extends AppenderBase<ILoggingEvent> {
public class ProjectBuildLogAppender extends AppenderBase<ILoggingEvent> implements AutoCloseable {
private static final String KEY_PROJECT_ID = "maven.project.id";
private static final ThreadLocal<String> PROJECT_ID = new InheritableThreadLocal<>();
@@ -57,21 +59,33 @@ public class ProjectBuildLogAppender extends AppenderBase<ILoggingEvent> {
}
}
private String pattern;
private PatternLayout layout;
private static final String pattern = "[%level] %msg%n";
private final PatternLayout layout;
private final AbstractLoggingSpy loggingSpy;
public ProjectBuildLogAppender(AbstractLoggingSpy loggingSpy) {
this.loggingSpy = loggingSpy;
this.name = ProjectBuildLogAppender.class.getName();
this.context = (Context) LoggerFactory.getILoggerFactory();
final PatternLayout l = new PatternLayout();
l.setContext(context);
l.setPattern(pattern);
final Map<String, String> instanceConverterMap = l.getInstanceConverterMap();
final String levelConverterClassName = LevelConverter.class.getName();
instanceConverterMap.put("level", levelConverterClassName);
instanceConverterMap.put("le", levelConverterClassName);
instanceConverterMap.put("p", levelConverterClassName);
this.layout = l;
final Logger root = (Logger) LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME);
root.addAppender(this);
start();
}
@Override
public void start() {
if (pattern == null) {
addError("\"Pattern\" property not set for appender named [" + name + "].");
return;
}
layout = new PatternLayout();
layout.setContext(context);
layout.setPattern(pattern);
layout.getInstanceConverterMap().put("level", LevelConverter.class.getName());
layout.getInstanceConverterMap().put("le", LevelConverter.class.getName());
layout.getInstanceConverterMap().put("p", LevelConverter.class.getName());
layout.start();
super.start();
}
@@ -80,11 +94,7 @@ public class ProjectBuildLogAppender extends AppenderBase<ILoggingEvent> {
protected void append(ILoggingEvent event) {
Map<String, String> mdc = event.getMDCPropertyMap();
String projectId = mdc != null ? mdc.get(KEY_PROJECT_ID) : null;
AbstractLoggingSpy.instance().append(projectId, layout.doLayout(event));
}
public void setPattern(String pattern) {
this.pattern = pattern;
loggingSpy.projectLogMessage(projectId, layout.doLayout(event));
}
public static class LevelConverter extends ClassicConverter {
@@ -104,4 +114,17 @@ public class ProjectBuildLogAppender extends AppenderBase<ILoggingEvent> {
}
}
}
@Override
public void close() {
stop();
final Logger root = (Logger) LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME);
root.detachAppender(this);
}
@Override
public void stop() {
layout.stop();
super.stop();
}
}

View File

@@ -25,13 +25,6 @@
<configuration>
<contextListener class="ch.qos.logback.classic.jul.LevelChangePropagator" />
<!--
| write project-specific build log messages to ${project.build.directory}/build.log files
-->
<appender name="MEM" class="org.mvndaemon.mvnd.logging.smart.ProjectBuildLogAppender">
<pattern>[%level] %msg%n</pattern>
</appender>
<appender name="DAEMON" class="ch.qos.logback.core.FileAppender">
<file>${mvnd.daemonStorage}/daemon-${mvnd.uid}.log</file>
<encoder>
@@ -49,7 +42,4 @@
<logger name="org.apache.maven.lifecycle.internal.builder.BuilderCommon" level="ERROR" />
<logger name="org.eclipse.aether.internal.impl.WarnChecksumPolicy" level="ERROR" />
<root level="${consoleLevel:-info}">
<appender-ref ref="MEM" />
</root>
</configuration>