[
https://issues.apache.org/jira/browse/SSHD-838?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16565685#comment-16565685
]
Bryan Turner edited comment on SSHD-838 at 8/1/18 5:35 PM:
-----------------------------------------------------------
{quote}
If anything, I am considering replacing all code that passes the exception
directly to the logging framework with this call.
{quote}
That's _extremely_ concerning to me.
{quote}
The reason for it is that when passing the exception directly to the logging
framework it logs the entire stack trace - which is often very long and
tedious. Usually, logging the top (or bottom - depending how you look at it)
6-8 frames provides enough "hints" as to the call flow to let the user know
what went wrong.
{quote}
That doesn't feel like a decision a _library_ should make. The few frames being
logged may be "enough hints" for an SSHD developer, but they completely
eliminate most, if not all, frames related to the _application_. That means I
have to reproduce the failure myself (which isn't always possible), or
otherwise guess my way through to how the SSHD code relates to _my_ code. What
call in _my_ application led to the calls in SSHD that failed?
By using SLF4J "normally", the decisions are left to the application developer.
If the _application_ doesn't want the full trace, they can eliminate some or
all of it by configuring Logback/Log4J accordingly\-\-something Bitbucket
Server, for example, _does_. We trim our own stack frames\-\-we don't need (or
want) the libraries we use to do it for us, because our goals aren't always the
same. For the _library_, the goal is to facilitate its maintainers' ability to
get useful (_to them_) details when failures are reported, while avoiding "long
and tedious" extra information that makes resolution slower. For the
_application_, the goal is to facilitate troubleshooting _customer-raised
issues_, which requires more complete context. Is the problem in the library?
Or is the problem in how we _set up or use_ the library? When SSH-related
issues come through our support, _very, very few_ of them get forwarded to the
wider SSHD community. Instead, we debug them ourselves and we
[often|https://github.com/apache/mina-sshd/pull/1]
[provide|https://github.com/apache/mina-sshd/pull/2]
[fixes|https://github.com/apache/mina-sshd/pull/3] ([and more
examples|https://issues.apache.org/jira/browse/SSHD-163?jql=project%20%3D%20SSHD%20AND%20reporter%20%3D%20pepoirot%20]).
Further, there are shortcomings with the _structure_ of
{{logExceptionStackTrace}}'s output:
* You're dropping the cause(s), which are often more useful for debugging a
failure than the various exceptions that wrap them
* All of the frames are separate log messages, which means:
** They each are prefixed with logger details, making the frames themselves
significantly harder to scan
** Systems that are connected to a LaaS (logging-as-a-service) framework end up
with all of the frames in separate events. Searching for a message and then
seeing the trace becomes more complicated
I humbly ask...please don't move your logging in this direction. As a system
which uses Mina SSHD heavily, it's a very undesirable change for Bitbucket
Server. If you do make this change, though, please, please add a way to turn it
off and log exceptions normally again.
Best regards,
Bryan Turner
was (Author: bturner):
{quote}
If anything, I am considering replacing all code that passes the exception
directly to the logging framework with this call.
{quote}
That's _extremely_ concerning to me.
{quote}
The reason for it is that when passing the exception directly to the logging
framework it logs the entire stack trace - which is often very long and
tedious. Usually, logging the top (or bottom - depending how you look at it)
6-8 frames provides enough "hints" as to the call flow to let the user know
what went wrong.
{quote}
That doesn't feel like a decision a _library_ should make. The few frames being
logged may be "enough hints" for an SSHD developer, but they completely
eliminate most, if not all, frames related to the _application_. That means I
have to reproduce the failure myself (which isn't always possible), or
otherwise guess my way through to how the SSHD code relates to _my_ code. What
call in _my_ application led to the calls in SSHD that failed?
By using SLF4J "normally", the decisions are left to the application developer.
If the _application_ doesn't want the full trace, they can eliminate some or
all of it by configuring Logback/Log4J accordingly--something Bitbucket Server,
for example, _does_. We trim our own stack frames--we don't need (or want) the
libraries we use to do it for us, because our goals aren't always the same. For
the _library_, the goal is to facilitate its maintainers' ability to get useful
(_to them_) details when failures are reported, while avoiding "long and
tedious" extra information that makes resolution slower. For the _application_,
the goal is to facilitate troubleshooting _customer-raised issues_, which
requires more complete context. Is the problem in the library? Or is the
problem in how we _set up or use_ the library? When SSH-related issues come
through our support, _very, very few_ of them get forwarded to the wider SSHD
community. Instead, we debug them ourselves and we
[often|https://github.com/apache/mina-sshd/pull/1]
[provide|https://github.com/apache/mina-sshd/pull/2]
[fixes|https://github.com/apache/mina-sshd/pull/3] ([and more
examples|https://issues.apache.org/jira/browse/SSHD-163?jql=project%20%3D%20SSHD%20AND%20reporter%20%3D%20pepoirot%20]).
Further, there are shortcomings with the _structure_ of
{{logExceptionStackTrace}}'s output:
* You're dropping the cause(s), which are often more useful for debugging a
failure than the various exceptions that wrap them
* All of the frames are separate log messages, which means:
** They each are prefixed with logger details, making the frames themselves
significantly harder to scan
** Systems that are connected to a LaaS (logging-as-a-service) framework end up
with all of the frames in separate events. Searching for a message and then
seeing the trace becomes more complicated
I humbly ask...please don't move your logging in this direction. As a system
which uses Mina SSHD heavily, it's a very undesirable change for Bitbucket
Server. If you do make this change, though, please, please add a way to turn it
off and log exceptions normally again.
Best regards,
Bryan Turner
> Lower the log level in Nio2Acceptor.AcceptCompletionHandler#okToReaccept
> ------------------------------------------------------------------------
>
> Key: SSHD-838
> URL: https://issues.apache.org/jira/browse/SSHD-838
> Project: MINA SSHD
> Issue Type: Improvement
> Affects Versions: 2.0.0
> Reporter: jpalacios
> Priority: Minor
> Attachments: sshd-nio-acceptor-logging.patch
>
>
> As discussed in [SSHD-833|https://issues.apache.org/jira/browse/SSHD-833], it
> appears that when a client disconnects before the handshake completes there's
> some pretty loud logging coming from the
> {{Nio2Acceptor.AcceptCompletionHandler#okToReaccept}}.
> The entire message is logged at {{WARN}} level. Also, several lines from the
> stack trace are logged individually at the same level.
> We feel this much logging at {{WARN}} level will be too much noise for system
> administrators who might think there's something wrong with the system. We
> propose:
> # Changing the log level to {{DEBUG}} / {{FINE}}
> # Logging the stacktrace in a single message
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
