[
https://issues.apache.org/jira/browse/SSHD-152?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13280076#comment-13280076
]
Gunnar Wagenknecht edited comment on SSHD-152 at 5/21/12 10:52 AM:
-------------------------------------------------------------------
I share your point about best practices. However, I'm really concerned that an
administrator runs into the issue. Administrative folks can't be aware of any
side effects that may or may not exist in any combination of log-level
settings. They tend to enable higher output when analyzing issues without
knowing such side-effects.
I think that SSHD should be very careful and add a protection especially when
it interacts with streams like System.out/System.err that may be used by many
other libs in a system.
Also, I'm not sure if the issue is really a concurrency issue or may be cause
be recursive invocation of ChannelOutputStream.flush() line: 119. Does SSHD
wrap/replace System.out?
was (Author: gunnar):
I share your point about best practices. However, I'm really concerned that
an administrator runs into the issue. Administrative folks can't be aware of
any side effects that may or may not exist in any combination of log-level
settings. They tend to enable higher output when analyzing issues without
knowing such side-effects.
I think that SSHD should be very careful and add a protection especially when
it interacts with streams like System.out/System.err that may be used by many
other libs in a system.
Also, I'm not sure if the issue is really a concurrency issue or may be cause
be recursive invocation of {{ChannelOutputStream.flush() line: 119}}. Does SSHD
wrap/replace {{System.out}}?
> Logging may cause deadlock.
> ---------------------------
>
> Key: SSHD-152
> URL: https://issues.apache.org/jira/browse/SSHD-152
> Project: MINA SSHD
> Issue Type: Bug
> Affects Versions: 0.5.0
> Reporter: Gunnar Wagenknecht
> Assignee: Guillaume Nodet
>
> I'm not really sure what I did but I think I somehow managed to deadlock my
> system using SSHD in combination with Logback console appender.
> Thread 1
> {noformat}
> Thread [Thread-21] (Suspended)
> owns: ChannelOutputStream (id=481)
> owns: ConsoleOutputStream (id=482)
> owns: PrintStream (id=483)
> owns: Object (id=202)
> waited by: Thread [...] (Suspended)
> waited by: Thread [...] (Suspended)
> waited by: Thread [...] (Suspended)
> waited by: Thread [NioProcessor-2] (Suspended)
> waited by: Thread [...] (Suspended)
> waited by: Thread [...] (Suspended)
> waited by: Thread [...] (Suspended)
> waited by: Thread [...] (Suspended)
> waited by: Thread [...] (Suspended)
> waited by: Thread [...] (Suspended)
> owns: OutputStreamWriter (id=484)
> waiting for: Window (id=485)
> Object.wait(long) line: not available [native method]
> Window(Object).wait() line: 503
> Window.waitForSpace() line: 146
> ChannelOutputStream.flush() line: 104
> ConsoleOutputStream.flush() line: 97
> ConsoleOutputStream.write(int) line: 83
> ConsoleOutputStream(OutputStream).write(byte[], int, int) line: 116
> PrintStream.write(byte[], int, int) line: 480
> PrintStream(FilterOutputStream).write(byte[]) line: 97
> ThreadPrintStream.write(byte[]) line: 245
> ConsoleTarget$1.write(byte[]) line: 36
> PatternLayoutEncoder(LayoutWrappingEncoder<E>).doEncode(E) line: 103
> ConsoleAppender<E>(OutputStreamAppender<E>).writeOut(E) line: 193
> ConsoleAppender<E>(OutputStreamAppender<E>).subAppend(E) line: 217
> ConsoleAppender<E>(OutputStreamAppender<E>).append(E) line: 108
> ConsoleAppender<E>(UnsynchronizedAppenderBase<E>).doAppend(E) line: 88
> AppenderAttachableImpl<E>.appendLoopOnAppenders(E) line: 64
> Logger.appendLoopOnAppenders(ILoggingEvent) line: 285
> Logger.callAppenders(ILoggingEvent) line: 272
> Logger.buildLoggingEventAndAppend(String, Marker, Level, String,
> Object[], Throwable) line: 473
> Logger.filterAndLog_2(String, Marker, Level, String, Object, Object,
> Throwable) line: 464
> Logger.debug(String, Object, Object) line: 542
> ChannelOutputStream.flush() line: 119
> ...
> {noformat}
> Thread 2
> {noformat}
> Thread [NioProcessor-2] (Suspended)
> owns: Object (id=150)
> waiting for: Object (id=202)
> owned by: Thread [Thread-21] (Suspended)
> waiting for: Window (id=485)
> ConsoleAppender<E>(OutputStreamAppender<E>).subAppend(E) line: 217
> ConsoleAppender<E>(OutputStreamAppender<E>).append(E) line: 108
> ConsoleAppender<E>(UnsynchronizedAppenderBase<E>).doAppend(E) line: 88
> AppenderAttachableImpl<E>.appendLoopOnAppenders(E) line: 64
> Logger.appendLoopOnAppenders(ILoggingEvent) line: 285
> Logger.callAppenders(ILoggingEvent) line: 272
> Logger.buildLoggingEventAndAppend(String, Marker, Level, String,
> Object[], Throwable) line: 473
> Logger.filterAndLog_1(String, Marker, Level, String, Object, Throwable)
> line: 445
> Logger.debug(String, Object) line: 538
> ServerSession.handleMessage(Buffer) line: 119
> ...
> {noformat}
> I think that one thread is waiting for Window to expand. The SSHD logger has
> a console appender. Unfortunately, the wait happends within a write by
> console appender. Thus all other threads that also log to the console will
> block because they wait for the Logback console appender lock.
> I think that a Logback console appender should not write to the SSHD console
> by default. Can this be disabled somehow?
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators:
https://issues.apache.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira
