Skip to content
Closed
Show file tree
Hide file tree
Changes from all commits
Commits
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
Original file line number Diff line number Diff line change
Expand Up @@ -143,6 +143,7 @@ public class DefaultMavenPluginManager
private PluginVersionResolver pluginVersionResolver;
private PluginArtifactsCache pluginArtifactsCache;
private MavenPluginValidator pluginValidator;
private MojoLogFactory logFactory;

private final ExtensionDescriptorBuilder extensionDescriptorBuilder = new ExtensionDescriptorBuilder();
private final PluginDescriptorBuilder builder = new PluginDescriptorBuilder();
Expand All @@ -158,7 +159,8 @@ public DefaultMavenPluginManager(
ExtensionRealmCache extensionRealmCache,
PluginVersionResolver pluginVersionResolver,
PluginArtifactsCache pluginArtifactsCache,
MavenPluginValidator pluginValidator )
MavenPluginValidator pluginValidator,
MojoLogFactory logFactory )
{
this.container = container;
this.classRealmManager = classRealmManager;
Expand All @@ -170,6 +172,7 @@ public DefaultMavenPluginManager(
this.pluginVersionResolver = pluginVersionResolver;
this.pluginArtifactsCache = pluginArtifactsCache;
this.pluginValidator = pluginValidator;
this.logFactory = logFactory;
}

public synchronized PluginDescriptor getPluginDescriptor( Plugin plugin, List<RemoteRepository> repositories,
Expand Down Expand Up @@ -569,8 +572,7 @@ else if ( cause instanceof LinkageError )

if ( mojo instanceof Mojo )
{
Logger mojoLogger = LoggerFactory.getLogger( mojoDescriptor.getImplementation() );
( (Mojo) mojo ).setLog( new MojoLogWrapper( mojoLogger ) );
( ( Mojo ) mojo ).setLog( logFactory.getLog( mojoDescriptor.getImplementation() ) );
}

Xpp3Dom dom = mojoExecution.getConfiguration();
Expand Down
206 changes: 206 additions & 0 deletions maven-core/src/main/java/org/apache/maven/plugin/internal/MojoLog.java
Original file line number Diff line number Diff line change
@@ -0,0 +1,206 @@
package org.apache.maven.plugin.internal;

/*
* 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.
*/

import org.apache.maven.plugin.logging.Log;
import org.slf4j.Logger;

import javax.inject.Provider;

import static java.util.Objects.requireNonNull;

/**
* Mojo {@link Log} implementation that lazily creates {@link Logger} instances. To achieve "lazyness" it uses
* {@link Provider} for logger, but guarantees that {@link Provider#get()} is invoked only once, and once got
* Logger instance is reused.
*
* @since TBD
*/
public class MojoLog
implements Log
{
private final Provider<Logger> loggerProvider;

public MojoLog( Provider<Logger> loggerProvider )
{
this.loggerProvider = memoize( loggerProvider );
}

private Logger getLogger()
{
return loggerProvider.get();
}

private String toString( CharSequence content )
{
if ( content == null )
{
return "";
}
else
{
return content.toString();
}
}

@Override
public void debug( CharSequence content )
{
if ( getLogger().isDebugEnabled() )
{
getLogger().debug( toString( content ) );
}
}

@Override
public void debug( CharSequence format, Object... arguments )
{
if ( getLogger().isDebugEnabled() )
Comment thread
cstamas marked this conversation as resolved.
{
getLogger().debug( toString( format ), arguments );
}
}

@Override
public void debug( CharSequence content, Throwable error )
{
if ( getLogger().isDebugEnabled() )
{
getLogger().debug( toString( content ), error );
}
}

@Override
public void debug( Throwable error )
{
getLogger().debug( "", error );
}

@Override
public void info( CharSequence content )
{
getLogger().info( toString( content ) );
}

@Override
public void info( CharSequence content, Throwable error )
{
getLogger().info( toString( content ), error );
}

@Override
public void info( Throwable error )
{
getLogger().info( "", error );
}

@Override
public void warn( CharSequence content )
{
getLogger().warn( toString( content ) );
}

@Override
public void warn( CharSequence content, Throwable error )
{
getLogger().warn( toString( content ), error );
}

@Override
public void warn( Throwable error )
{
getLogger().warn( "", error );
}

@Override
public void error( CharSequence content )
{
getLogger().error( toString( content ) );
}

@Override
public void error( CharSequence content, Throwable error )
{
getLogger().error( toString( content ), error );
}

@Override
public void error( Throwable error )
{
getLogger().error( "", error );
}

@Override
public boolean isDebugEnabled()
{
return getLogger().isDebugEnabled();
}

@Override
public boolean isInfoEnabled()
{
return getLogger().isInfoEnabled();
}

@Override
public boolean isWarnEnabled()
{
return getLogger().isWarnEnabled();
}

@Override
public boolean isErrorEnabled()
{
return getLogger().isErrorEnabled();
}

/**
* A helper bit to make users of this class easier: it wraps {@link Provider} into "memoizing" provider: the
* wrapped (delegate) provider will be invoked only once, and the returned value will be stored for subsequent
* invocations of {@link Provider#get()} on wrapper.
*/
private static <T> Provider<T> memoize( Provider<T> provider )
{
requireNonNull( provider );
return new Provider<T>()
{
Provider<T> delegate = this::memoize;

volatile boolean memoized = false;

@Override
public T get()
{
return delegate.get();
}

private synchronized T memoize()
{
if ( !memoized )
{
T value = provider.get();
delegate = () -> value;
memoized = true;
}
return delegate.get();
}
};
}
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,46 @@
package org.apache.maven.plugin.internal;

/*
* 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.
*/

import javax.inject.Named;
import javax.inject.Singleton;

import org.apache.maven.plugin.logging.Log;
import org.slf4j.LoggerFactory;

/**
* Implementation of Mojo {@link Log} factory backed by Maven internal logging (slf4j).
*
* @since TBD
*/
@Singleton
@Named
public class MojoLogFactory
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

One of the issues we now have is that we can only specify a global loglevel. In case something with my-verify-maven-plugin went wrong and I want to see its debug logging, I now can only use mvn -X verify and wait until the end, getting debug logging for everything.

The changes that are proposed must be prepared to be able to log for 1 specific plugin or goal.
I think this might be a critical class.
I don't have the solution yet, but I want to be sure that what is introduced is also prepared for future implementations.

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

IMO, for plugin you'd want to just set logging level of given logger (but how to map plugin name -> class name)? As this class just wraps Slfj4 LoggerFactory...

To achieve that, IMHO you'd want:

  • be able to map plugin -> class
  • configure logger level to DEBUG for given logger (the FQCN)

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

i think it is a bit more complex. It is not just the mojo, but all other classes of the plugin, both inside the jar and the other used classes. What is the plugin calls maven-core code? I would expect that to be logged at the mojo-loglevel too. We need to dive into the possibilities with classworlds to achieve this.

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It may be easier to set a MDC flag on the logger before executing a plugin. At least, this would allow to easily filter all log statements related to a given invocation.

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Think a threadlocal solution does not work since a lot of mojo are multithreaded so, until we replace through the ClassRealm the new Thread with a new MavenThread which can propagate a context and rely on some MDC I think we have to fallback on a class realm anyway. Only limitation is to log a particular execution - and I think it is fine - so long story short, I would align log factory on classloaders (maybe with the exception of extensions which would inherit from maven core config but it is by design).

Copy link
Copy Markdown
Member Author

@cstamas cstamas Oct 19, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@rfscholte so you want even core calls as DEBUG? That would mean (re)loading SLF4J in plugin realm, and is something we do not do (we do not expose it even to plugins). Could you elaborate a bit more about this?

Copy link
Copy Markdown
Contributor

@gnodet gnodet Oct 19, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Think a threadlocal solution does not work since a lot of mojo are multithreaded so, until we replace through the ClassRealm the new Thread with a new MavenThread which can propagate a context and rely on some MDC I think we have to fallback on a class realm anyway. Only limitation is to log a particular execution - and I think it is fine - so long story short, I would align log factory on classloaders (maybe with the exception of extensions which would inherit from maven core config but it is by design).

Fwiw, in mvnd, log statements are already associated to a given project execution. It's not perfect, as it will certainly miss some associations, but it works in most cases. The overall goal in mvnd was to be able to separate the log statements between project being built concurrently. The initial work was done in https://github.com/takari/concurrent-build-logger and adapted. Overall, it works quite well now !
https://github.com/mvndaemon/mvnd/tree/master/daemon/src/main/java/org/mvndaemon/mvnd/logging

Copy link
Copy Markdown
Contributor

@gnodet gnodet Oct 19, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Here is a trivial example but it does NOT do what @rfscholte proposes #600
@gnodet does SimpleLogger, used by support MDC?

No, you're right. But there's no reason to stay on SimpleLogger if there's a need to change. Anyway, in mvnd, the MDC is set, but not actually used. Turning on debug logging for certain mojos executions can be done with a custom filtering provided by maven somehow. The MDC is only a way to convey the information that can be used in a more standard way, and a simple ThreadLocal could be sufficient.

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Fwiw, in mvnd, log statements are already associated to a given project execution. It's not perfect, as it will certainly miss some associations, but it works in most cases.

This is why I'm saying a thread local solution can be a quick impl but not a final solution, several mojos are not properly logged. While just in the window of mvnd it is okish but if we speak about configuring loggers it will not be the same tolerance at all IMHO.

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@rfscholte so you want even core calls as DEBUG? Could you elaborate a bit more about this?

What I would expect is a behavior similar to: at start of Mojo reset the loggers and change the root logger to debug, at end of the Mojo restore the loggers. Reason is that the issue might not be in the plugin code itself, but in one of its dependencies and if that uses logging it might be very very helpful.
Remember this is just a thought, and I just want everybody to be aware of it that it must be possible to improve the logging experience in the future, one way or another.

{
public Log getLog( final Class<?> clazz )
{
return new MojoLog( () -> LoggerFactory.getLogger( clazz ) );
}

public Log getLog( final String name )
Copy link
Copy Markdown
Contributor

@rfscholte rfscholte Oct 19, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Is this still used? And do we really want to support this?

{
return new MojoLog( () -> LoggerFactory.getLogger( name ) );
}
}
Loading