Move some info logged by the WebApp CL as INFO to DEBUG/FINE level to reduce noise #24944
Conversation
Jersey 3.1.6 depends on it but GF had an older version. Admin Console failed to load. Signed-off-by:Ondro Mihalyi <mihalyi@omnifish.ee>
Signed-off-by:Ondro Mihalyi <mihalyi@omnifish.ee>
| @@ -267,7 +269,12 @@ public final class WebappClassLoader extends GlassfishUrlClassLoader | |||
| * but no defined repositories. | |||
| */ | |||
| public WebappClassLoader(ClassLoader parent) { | |||
| this(parent, "unknown"); | |||
There was a problem hiding this comment.
I am against this change, it is confusing and doesn't bring a value.
There was a problem hiding this comment.
You mean it doesn't bring any value that the log message says which application is related to the web app classloader? I thought it's very important, otherwise the new INFO message just says that some web app classloader was closed.
There was a problem hiding this comment.
Alternatively, I can just change the log level of the original message rom INFO to DEBUG. I don't think it's important to log an INFO message when classloader is closed, what do you think?
There was a problem hiding this comment.
I mean that it logs the value just in one case of five possible creations of the classloader. If it should know the name of the application, it should know it always, without any "unknown" value.
| @@ -1131,7 +1138,9 @@ public void close() throws IOException { | |||
| if (status == LifeCycleStatus.CLOSED) { | |||
| return; | |||
| } | |||
| LOG.log(INFO, "close(), this:\n{0}", this); | |||
| LOG.log(INFO, () -> "close(), " + this.getClass().getSimpleName() | |||
There was a problem hiding this comment.
The original state was very useful for quite regular issues of users who used incompatible dependencies packed directly to war. And it doesn't log too often, just on CL close.
There was a problem hiding this comment.
It logs one every app deployment. To me, the big INFO message with urls is just noise. INFO messages to me are short statements about what's going on, with a few simple values. Not something that takes the whole screen to show the whole message. That's either CONFIG (which isn't supported by System.Logger), or DEBUG, because it's only relevant in case of issues. In the end, the urls list only shows what's inside WEB-INF/lib in the WAR, people can unpack the WAR and see.
There was a problem hiding this comment.
Knowing simple name of the closed classloader class is worthless. Currently it reports some statistics and also the list of managed libraries, which is very useful in many use cases (missing/duplicit/harmful dependencies, etc). I use it nearly everyday, with some issues detected which were not resolved yet.
We can discuss that with others - if I am the only one who uses it or not.
Btw it logs also the context which is also used for the name of the classloader - and has the same issue with "unknown" value - I would like rather to clear it and make it final rather than increasing number of ways to make it "weird".
There was a problem hiding this comment.
I admit I was just too lazy to look at other places that use the constructor. It's better it all places pass the app name so that it can be in the log.
But I would still turn this log into the DEBUG level. If you think it's essential for development, then we can make the default log configuration set the log level of the org.glassfish.web.loader.WebappClassLoader logger to FINE. But for production, it makes more sense to disable this log with the NORMAL level. Of course, FINE level enables some more log messages, but if they are less important, we can move them to TRACE/FINER level. Would you agree with that?
There was a problem hiding this comment.
just on CL close.
Maybe we need to look a bit at the wording of the log message too.
I mean, it now sounds like a command.
"Close this: [list]"
Which may make the user wonder if they need to close something explicitly, but they have no idea how to do it.
There was a problem hiding this comment.
Basically the important information should be always logged:
- Name and all endpoints of the application
- Classpaths
- When components changed their state, are usable or when they were disabled and why
This reports the classpath of the application. Maybe it would be better to report it on start rather than on close, but because the start is bit more complicated, this is now better.
|
I'll close this PR. I see there's no consensus and this change is not important enough to seek for an agreement. I'm OK with logging the full classpath, although I still think it's more a debugging info and it's a noise in normal usage. |
|
At least you forced me to thing about some future state. @avpinchuk now works on more serious issues with reliable closing applibs (which was never considered on GF and causes IOExceptions on Windows), then I will try to analyze how to move the app name/context name out of the classloader and use the app name as the classloader name instead; and it should be ALWAYS set, so no "unknown" value should be set any more. And the classpath or cl.toString should be written to logs on startup, not on close. That is still an issue, because of the "lifecycle" which I had to add to force the CL to keep at least some rules. Now we are still expanding the "zone of reliability", so finally it should converge to something more simple. |
With this, the following is logged in INFO during app deployment:
The following is not logged as INFO anymore, rather as DEBUG/FINE. As INFO is the default log level, it's a noise in logs which is mostly for troubleshooting and it's better to have it in DEBUG level, only if requested: