You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@tomcat.apache.org by bu...@apache.org on 2019/10/24 14:42:36 UTC
[Bug 63879] New: Unessesary log noise under DEBUG
https://bz.apache.org/bugzilla/show_bug.cgi?id=63879
Bug ID: 63879
Summary: Unessesary log noise under DEBUG
Product: Tomcat 9
Version: 9.0.21
Hardware: Macintosh
Status: NEW
Severity: trivial
Priority: P2
Component: Util
Assignee: dev@tomcat.apache.org
Reporter: michael.bazos@priceline.com
Target Milestone: -----
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.
--
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org
[Bug 63879] Unessesary log noise under DEBUG
Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=63879
--- Comment #4 from Remy Maucherat <re...@apache.org> ---
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.
--
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org
[Bug 63879] Unessesary log noise under DEBUG
Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=63879
--- Comment #6 from Michael Bazos <mi...@priceline.com> ---
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.
--- Comment #7 from Michael Bazos <mi...@priceline.com> ---
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.
--
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org
[Bug 63879] Unessesary log noise under DEBUG
Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=63879
--- Comment #5 from Christopher Schultz <ch...@christopherschultz.net> ---
I think switching the log message to TRACE is the best solution.
--
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org
[Bug 63879] Unessesary log noise under DEBUG
Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=63879
--- Comment #8 from Christopher Schultz <ch...@christopherschultz.net> ---
(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")
--
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org
Re: [Bug 63879] Unessesary log noise under DEBUG
Posted by Steve Sanders <st...@gmail.com>.
I like this idea. I have found in past situations that it's handy to know
when closeSocket is called. The exception seems overkill since there is
nothing really wrong.
On Thu, Oct 24, 2019, 10:19 AM <bu...@apache.org> wrote:
> https://bz.apache.org/bugzilla/show_bug.cgi?id=63879
>
> --- Comment #2 from Michael Bazos <mi...@priceline.com> ---
> 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?
>
> --
> You are receiving this mail because:
> You are the assignee for the bug.
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
> For additional commands, e-mail: dev-help@tomcat.apache.org
>
>
[Bug 63879] Unessesary log noise under DEBUG
Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=63879
--- Comment #2 from Michael Bazos <mi...@priceline.com> ---
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?
--
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org
[Bug 63879] Unessesary log noise under DEBUG
Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=63879
--- Comment #6 from Michael Bazos <mi...@priceline.com> ---
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.
--
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org
[Bug 63879] Unessesary log noise under DEBUG
Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=63879
Remy Maucherat <re...@apache.org> changed:
What |Removed |Added
----------------------------------------------------------------------------
Status|NEW |RESOLVED
Resolution|--- |FIXED
--- Comment #10 from Remy Maucherat <re...@apache.org> ---
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.
--
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org
[Bug 63879] Unessesary log noise under DEBUG
Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=63879
--- Comment #9 from Steve Sanders <st...@gmail.com> ---
(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.
--
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org
[Bug 63879] Unessesary log noise under DEBUG
Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=63879
Christopher Schultz <ch...@christopherschultz.net> changed:
What |Removed |Added
----------------------------------------------------------------------------
CC| |remm@apache.org
OS| |All
--- Comment #1 from Christopher Schultz <ch...@christopherschultz.net> ---
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?
--
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org
[Bug 63879] Unessesary log noise under DEBUG
Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=63879
--- Comment #3 from Steve Sanders <st...@gmail.com> ---
Ive submitted a patch for this: https://github.com/apache/tomcat/pull/220
--
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org