Introduced in tomcat 9.0.21 there was a log DEBUG message introduced in org.apache.tomcat.util.net.NioEndpoint.NioSocketWrapper#doClose ``` @Override protected void doClose() { if (log.isDebugEnabled()) { log.debug("Calling [" + getEndpoint() + "].closeSocket([" + this + "])", new Exception()); } ``` Adding log message with the exception like this causes noise to clients and could be alarming here is a sample output from the clients perspective: [10-24-19 10:29:44.066] [http-nio-8080-exec-8] DEBUG o.a.tomcat.util.net.NioEndpoint - Calling [org.apache.tomcat.util.net.NioEndpoint@7073a1db].closeSocket([org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@5e5a7392:org.apache.tomcat.util.net.NioChannel@5fa6a12b:java.nio.channels.SocketChannel[connected local=/0:0:0:0:0:0:0:1:8080 remote=/0:0:0:0:0:0:0:1:57802]]) java.lang.Exception: null at org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper.doClose(NioEndpoint.java:1163) ~[tomcat-embed-core-9.0.27.jar:9.0.27] at org.apache.tomcat.util.net.SocketWrapperBase.close(SocketWrapperBase.java:402) ~[tomcat-embed-core-9.0.27.jar:9.0.27] at org.apache.tomcat.util.net.NioEndpoint$Poller.cancelledKey(NioEndpoint.java:665) ~[tomcat-embed-core-9.0.27.jar:9.0.27] at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1582) ~[tomcat-embed-core-9.0.27.jar:9.0.27] at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) ~[tomcat-embed-core-9.0.27.jar:9.0.27] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) ~[na:na] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) ~[na:na] at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) ~[tomcat-embed-core-9.0.27.jar:9.0.27] at java.base/java.lang.Thread.run(Thread.java:834) ~[na:na] I think it would be best to remove the Exception from the debug statement or if the stack trace is needed to output this in a better manner.
Looks like leftover debugging code. Should be changed to TRACE at the very least. Rémy, do you think this log message even needs to stay in there?
TRACE would be okay as I feel most people wouldn't need that but I think it could be left at DEBUG probably just want to not add the Exception?
Ive submitted a patch for this: https://github.com/apache/tomcat/pull/220
The stack trace is used to know what called close (obviously). This is the same in the NIO 2 connector. This might be a little bit too much (= not that useful) and I will likely remove them, but I don't see why you are enabling debug logging and complain about it as this logging level is very verbose on the endpoints. HTTP/2 has similar verbosity on debug logging BTW.
I think switching the log message to TRACE is the best solution.
I agree switching to TRACE is the best option. Also it might be helpful to not throw new Exception(); as this produces this message "java.lang.Exception: null" If you are going to have this it might be best to provide a message to let people know this is intended and testing. This issue came up as it was forwarded to me by another team at my company and my response was it's fine it's `DEBUG` but I also feel seeing a stack trace like this can clue to some potential issue happening or maybe something not being done in an optimal way. Either way I think checking the rest of the code base in NIO and NIO2 for this pattern and switching the statements to TRACE at a minimum should be fine.
(In reply to Michael Bazos from comment #6) > I agree switching to TRACE is the best option. Also it might be helpful to > not throw new Exception() Note that the exception is not thrown, only constructed. Yes, this requires the runtime to walk the the stack to produce the stack trace (Which is precisely why it's being done at all) but we don't incur the penalty of actually throwing the exception. > this produces this message > "java.lang.Exception: null" If you are going to have this it might be best > to provide a message to let people know this is intended and testing. +1 to adding a message e.g. new Exception("Intentional stack trace")
(In reply to Christopher Schultz from comment #8) > (In reply to Michael Bazos from comment #6) > > I agree switching to TRACE is the best option. Also it might be helpful to > > not throw new Exception() > > Note that the exception is not thrown, only constructed. Yes, this requires > the runtime to walk the the stack to produce the stack trace (Which is > precisely why it's being done at all) but we don't incur the penalty of > actually throwing the exception. > > > this produces this message > > "java.lang.Exception: null" If you are going to have this it might be best > > to provide a message to let people know this is intended and testing. > > +1 to adding a message e.g. new Exception("Intentional stack trace") Good idea! I've updated my patch to use isTraceEnabled, and added the exception message.
I removed the stack trace but kept the debug log, as I didn't see much use to the stack trace. This was added in NIO2 when I was looking at how close was called (NIO2 being mostly async), and it's not generally useful but it was added when I did the doClose refactoring. This will be in 9.0.28.