the jvm DEBUG flag is not working org.eclipse.jetty.LEVEL=DEBUG

[4devwithgit]

Jetty version - 9.4.36

Java version - ./jdk/bin/java -version
java version "1.8.0_271"
Java(TM) SE Runtime Environment (build 8.0.6.20 - pxa6480sr6fp20-20201120_02(SR6 FP20))
IBM J9 VM (build 2.9, JRE 1.8.0 Linux amd64-64-Bit Compressed References 20201102_458768 (JIT enabled, AOT enabled)
OpenJ9 - 5b31a42
OMR - 6ad3a34
IBM - b7e48f4)
JCL - 20201119_01 based on Oracle jdk8u271-b09

OS type/version - Linux XXXX 3.10.0-1062.4.1.el7.x86_64 #1 SMP Wed Sep 25 09:42:57 EDT 2019 x86_64 x86_64 x86_64 GNU/Linux

** Red Hat Enterprise Linux Server release 7.7 (Maipo) **

Description - In order to enable jetty http server logs, we used to do following steps

1. Enable jetty debug log in GUI
2. Add the below code to PSHttpAdapterImpl in asset clump

import org.eclipse.jetty.util.log.Log;
import org.eclipse.jetty.util.log.StdErrLog;

Logger jettyLog = LogService.getLogger("jettylogger");
jettyLog.logDebug("Enabling Jetty Debug Logs:"+jettyLog.isDebug());
if(jettyLog.isDebug()) {
StdErrLog errLog = new StdErrLog();
errLog.setDebugEnabled(true);
Log.setLog(errLog);
}

3. Build asset clump
4. Add -Dorg.eclipse.jetty.util.log.class=org.eclipse.jetty.util.log.StdErrLog -Dorg.eclipse.jetty.LEVEL=DEBUG
   to SI_INSTALL/noapp/bin/startNoApp.sh
5. Restart application

But, though it used to work in 9.4.26, its not working in 9.4.36. And, we are seeing below errors, in jetty logs, when set as DEBUG during server startup,

[2021-03-03 18:38:10.655] ALL 000000000000 GLOBAL_SCOPE 2021-03-03 18:38:10.655:DBUG:oejs.SecurityHandler:Thread-11:
java.lang.Throwable
at org.eclipse.jetty.security.ConstraintSecurityHandler.checkPathsWithUncoveredHttpMethods(ConstraintSecurityHandler.java:762) at org.eclipse.jetty.security.ConstraintSecurityHandler.doStart(ConstraintSecurityHandler.java:415)
at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:73)
at org.eclipse.jetty.util.component.ContainerLifeCycle.start(ContainerLifeCycle.java:169)
at org.eclipse.jetty.util.component.ContainerLifeCycle.doStart(ContainerLifeCycle.java:110)
at org.eclipse.jetty.server.handler.AbstractHandler.doStart(AbstractHandler.java:97)
at org.eclipse.jetty.server.handler.ScopedHandler.doStart(ScopedHandler.java:120)
at org.eclipse.jetty.server.session.SessionHandler.doStart(SessionHandler.java:505)
at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:73)
at org.eclipse.jetty.util.component.ContainerLifeCycle.start(ContainerLifeCycle.java:169)
at org.eclipse.jetty.util.component.ContainerLifeCycle.doStart(ContainerLifeCycle.java:110)
at org.eclipse.jetty.server.handler.AbstractHandler.doStart(AbstractHandler.java:97)
at org.eclipse.jetty.server.handler.ScopedHandler.doStart(ScopedHandler.java:120)
at org.eclipse.jetty.server.handler.ContextHandler.startContext(ContextHandler.java:970)
at org.eclipse.jetty.servlet.ServletContextHandler.startContext(ServletContextHandler.java:375)
at org.eclipse.jetty.webapp.WebAppContext.startWebapp(WebAppContext.java:1457)
at org.eclipse.jetty.webapp.WebAppContext.startContext(WebAppContext.java:1422)
at org.eclipse.jetty.server.handler.ContextHandler.doStart(ContextHandler.java:911)
at org.eclipse.jetty.servlet.ServletContextHandler.doStart(ServletContextHandler.java:288)
at org.eclipse.jetty.webapp.WebAppContext.doStart(WebAppContext.java:524)
at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:73)
at org.eclipse.jetty.util.component.ContainerLifeCycle.start(ContainerLifeCycle.java:169)
at org.eclipse.jetty.util.component.ContainerLifeCycle.doStart(ContainerLifeCycle.java:117)
at org.eclipse.jetty.server.handler.AbstractHandler.doStart(AbstractHandler.java:97)
at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:73)
at org.eclipse.jetty.util.component.ContainerLifeCycle.start(ContainerLifeCycle.java:169)
at org.eclipse.jetty.util.component.ContainerLifeCycle.doStart(ContainerLifeCycle.java:117)
at org.eclipse.jetty.server.handler.AbstractHandler.doStart(AbstractHandler.java:97)
at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:73)
at org.eclipse.jetty.util.component.ContainerLifeCycle.start(ContainerLifeCycle.java:169)
at org.eclipse.jetty.server.Server.start(Server.java:423)
at org.eclipse.jetty.util.component.ContainerLifeCycle.doStart(ContainerLifeCycle.java:110)
at org.eclipse.jetty.server.handler.AbstractHandler.doStart(AbstractHandler.java:97)
at org.eclipse.jetty.server.Server.doStart(Server.java:387)
at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:73)
at com.sterlingcommerce.woodstock.noapp*.WebServerStartThread.run(WebServerStartThread.java:64)*
at java.lang.Thread.run(Thread.java:822)

[sbordet]

@4devwithgit I don't understand your report.

If you enable the ALL logging level, you will get all internal exceptions that Jetty logs that are not errors, they are just exceptions logged at IGNORE or DEBUG level and can be ignored.

[janbartel]

I'm confused: you seem to be saying that you can't set DEBUG mode, and yet the stacktrace shows DEBUG logging?

For the stacktrace, this appears in DEBUG mode only, and is related to a WARN log line that should appear just above it, of the following format:
{} has uncovered http methods for path: {}

Where the first {} is the context and the second {} is the path with uncovered http methods. This warning is a requirement of the servlet specification section 13.8.4 Uncovered HTTP Protocol Methods.

[joakime]

Do we really need that LOG.debug?

https://github.com/eclipse/jetty.project/blob/23c1ef3ae98d53c12c245ac6139e6ad4b3a0ea5a/jetty-security/src/main/java/org/eclipse/jetty/security/ConstraintSecurityHandler.java#L746-L751

Isn't the LOG.warn sufficient?
Is there something about the stacktrace that gives us something useful?
The commit that added that Throwable -> b186d3e

[4devwithgit]

the application server, gets stuck with the given error. It fails to bring up the application which is deployed using this jetty.

[joakime]

This logging wouldn't cause the server to get stuck.
The behavior here is just to log.
In fact, the code that calls this method, doesn't even look at the return value.

If you have a stuck app server, something else is going on.