Mojo API update proposal

[cstamas]

This is a DRAFT that started as booster for discussion about Mojo
logging.

Re logging: I believe Maven should not get in a way to
Maven Plugin developers, but we still can offer
some "convenience" helpers and make things right
(like for example logging in ctor of Mojo).

IMHO, I distinguish 2 log-related situations:

• trivial to simple Maven Plugins (from one mojo plugin to more mojos + several "own"
  components): here developer can easily choose (and usually choose Mojo Log)
  to do the job. Maven is helping here.
• complex Maven plugins: plugins pulling in "foreign" frameworks/components/whatever,
  here logging is usually "given", but as Mojo class loader is "self first", it is really
  easy for developer to decide (and implement) which logging it wants (or must) to
  use, Maven should not interfere.

One thing IMHO remains, to make Mojo Log interface more "slf4j Logger"-lookalike.
This is just a "quick draft" adjusted to make ITs pass, but I am sure there are some (binary)
incompatibilities remaining we'd need to investigate and fix.

Other changes: MavenSession (compatible) update, to make clear Mojo contexts are
ConcurrentMaps. And a bit of Mojo context cleanup, mostly regarding Javadoc
mentioning how should it be used.

Changes in this PR:

• un-deprecate Log and Log related methods on Mojo, AbstractMojo
• introduce LogFactory component for those seeking for simple logging solution from Mojos and own components
• loggers are lazily looked up and "memoized" (thanks Romain)
• classes Mojo, AbstractMojo are mostly unchanged (Log injection here happens "manually" in DefMvnPluginMgr as before)
• MavenSession plugin context change (is ConcurrentMap)
• Javadoc around Mojo Context

Issues:

• https://issues.apache.org/jira/browse/MNG-7084 -- indirectly fixes (does not adds injection of Log instances due simplicity, it ads a component that may be used for same thing, for example with using ctor injection)
• https://issues.apache.org/jira/browse/MNG-7083 -- TBD, make Log SLF4J Logger "alike"
• https://issues.apache.org/jira/browse/MNG-7082 -- fixes

[cstamas]

ping @McFoggy

[rmannibucau]

A few early comments on common log factory pitfalls (multiple init, cleanup depending on classrealm etc) + a question on the compat we want for mojo to avoid everyone to be forced to rewrite to support maven.next. Hope it will help a bit.

[mthmulders]

A few small remarks from my side, mainly documentation related.

[slawekjaranowski]

will other methods (warn, info, error) have also such signature?
What if last argument will be of Throwable type?

[cstamas]

Yes, as commit message says, the DEBUG level changes are just showcasing what I meant by"make Logger slf4j Logger-look-alike" 1683b45

[cstamas]

Re last argument of Throwable, same thing applies as here http://slf4j.org/faq.html#paramException

[cstamas]

Moved unrelated (to Mojo API) session changes to it's own PR #575

[McFoggy]

Hi, as you ping me there for the replacement of #437 and #438 here is what I can tell you.

When I created the PRs, I was looking for a standardized way to use & inject "Logger" (whatever the interface/impl) in different maven places.
Standard plugins used to inherit from Mojo and thus access a Log interface from Mojo/AbstractMojo but for core extensions (what I was more interested of) it was not clear what to use and how. Looking at this PR it looks like the answer is now inject and use LogFactory.

Then more specifically for #438 the introduction of the functional providers of message was more to allow new syntax of writing logs. This PR provides new Log methods but not functional ones allowing to use lambda or method references.
For me #438 it is still valid or could be merged here with the other enhancements to Log interface.

[cstamas]

Hi, as you ping me there for the replacement of #437 and #438 here is what I can tell you.

Thanks for reaching out!

When I created the PRs, I was looking for a standardized way to use & inject "Logger" (whatever the interface/impl) in different maven places. Standard plugins used to inherit from Mojo and thus access a Log interface from Mojo/AbstractMojo but for core extensions (what I was more interested of) it was not clear what to use and how. Looking at this PR it looks like the answer is now inject and use LogFactory.

Correct. I know it would be simpler to inject logger, but that would complicate things for Mojos and Components. Now, mojos and components can get same breed of loggers (even with ctor injection as you point out), as my issue here was that while Mojos get loggers injected, components cannot even get to them even if they want to.

Then more specifically for #438 the introduction of the functional providers of message was more to allow new syntax of writing logs. This PR provides new Log methods but not functional ones allowing to use lambda or method references. For me #438 it is still valid or could be merged here with the other enhancements to Log interface.

Am unsure do we want to invent things here. Am sure that logging API can be quite "non conventional" even smart, but my choice to be slf4j-like is intentional, as after all, core and almost everything else around Mojos/plugins that's the API we use. IMO, it is much simpler for a developer to just follow one API. After all, as slf4j is lazy, you can still provide some bits that has toString() implementation (so evaluates to String when slf4j asks for):

interface SupplierWithToString extends Supplier<String> {
  String toString();
}
  private static Supplier<String> toStringSupplier(final Supplier<String> stringSupplier) {
    return new SupplierWithToString<String>() {
      @Override
      public String get() {
        return stringSupplier.get();
      }
      
      public String toString() {
        return get();
      }
    };
  }

and use it as

      log.info("this is a {} about {}", toStringSupplier(() -> "message"), toStringSupplier(() -> "logging"));

Note: untested, just drafted
Isn't this same semantics?

[rmannibucau]

Maybe off topic: but why not using JUL API? it is lazy, standard, dep free and built-in. Can also be made working and wired to whatever maven picked as logger impl out of the box for any classrealm so sounds like a win-win versus a custom API.

[cstamas]

@rmannibucau please stop with "why not...". We had this (long) discussion, it was resolved, and this is where we are with it. All the enumerated things stand for slf4j as well, sans the "dep free". But please, don't reboot this discussion, it stole too many precious dev hours already.

[rmannibucau]

@cstamas the only agreement was for @apache/maven project. For the API there is no slf4j agreement but the agreement to get a logging API. Since JUL is the built-in and well known java logging API and from maven standpoint we can completely control it properly for all plugins and components it makes sense to not reinvent the wheel and just reuse this API (we don't have to use the impl and should likely stay on slf4j until we rediscuss it). So don't read it as a "why not" but more a "the API we should use is already there".

[michael-o]

@cstamas the only agreement was for @apache/maven project. For the API there is no slf4j agreement but the agreement to get a logging API. Since JUL is the built-in and well known java logging API and from maven standpoint we can completely control it properly for all plugins and components it makes sense to not reinvent the wheel and just reuse this API (we don't have to use the impl and should likely stay on slf4j until we rediscuss it). So don't read it as a "why not" but more a "the API we should use is already there".

No JULI please, it is horrible. A pain in the ass in Tomcat.

[rmannibucau]

@michael-o if you mean JULi I will not dig but if you mean JUL I think it is wrong. Technically JUL is 1-1 with slf4j without drawbacks SLF4J brings for a plugin system like mojos. The only drawback of JULI is the fact it is global and configured on the JVM, two trivial points to solve at maven level, even without tomcat hacks IMHO.

[michael-o]

@michael-o if you mean JULi I will not dig but if you mean JUL I think it is wrong. Technically JUL is 1-1 with slf4j without drawbacks SLF4J brings for a plugin system like mojos. The only drawback of JULI is the fact it is global and configured on the JVM, two trivial points to solve at maven level, even without tomcat hacks IMHO.

You are right. I need to distinguish between JUL and JULI. Thank you for making me aware. JUL lacks placeholders like SLF4J has, though.

[rmannibucau]

@michael-o yes and no, since the API has suppliers it is faster and more fluent to not use placeholders these days:

logger.info(() -> "I did " + that);

[cstamas]

Am sorry, but this PR is NOT about changing logging API to some other API anywhere in maven (so not even in Mojos). It is about Mojo API, and as part of it, Mojo Log is about to stay. Most we can do is improve it (in backward compat way). Those who are mentioning other loggers are simply missing the point, and that is not a big problem, but derailing discussion is. Whenever logging is mentioned, this happens. Sigh,

[rmannibucau]

@cstamas guess it comes from the factory which is likely considered as not needed and duplicating logger abstractions. Dropping it and 100% relying on Log is fine for me while you can inject a Log instance in a component and maybe solves this topic?

[cstamas]

When I created the PRs, I was looking for a standardized way to use & inject "Logger" (whatever the interface/impl) in different maven places. Standard plugins used to inherit from Mojo and thus access a Log interface from Mojo/AbstractMojo but for core extensions (what I was more interested of) it was not clear what to use and how. Looking at this PR it looks like the answer is now inject and use LogFactory.

@McFoggy sorry, I just reread the bits that I also highlighted, as seems I missed those at first read and response. Well, for "core extensions" is same what stands in maven core itself: slf4j. Given core extension is loaded like this: http://takari.io/book/91-maven-classloading.html

[rmannibucau]

will remains external extensions which must not depend on slf4j so Log can likely become the abstraction to use for external code at least, no?

[rfscholte]

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.

[cstamas]

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)

[rfscholte]

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.

[gnodet]

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.

[rmannibucau]

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).

[cstamas]

@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?

[gnodet]

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

[gnodet]

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.

[rmannibucau]

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.

[rfscholte]

@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.

[rfscholte]

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