Details
-
Bug
-
Status: Resolved
-
Critical
-
Resolution: Won't Fix
-
4.2.7
-
None
-
None
-
Windows 10
Picked up JAVA_TOOL_OPTIONS: "-XX:+UsePerfData" "-Duser.language=en" "-Duser.country=US" "-Duser.timezone=UTC" "-Dfile.encoding=UTF-8" openjdk version "11.0.4" 2019-07-16 LTS OpenJDK Runtime Environment Zulu11.33+15-CA (build 11.0.4+11-LTS) OpenJDK 64-Bit Server VM Zulu11.33+15-CA (build 11.0.4+11-LTS, mixed mode)
(this was also encountered with Java 8)
Windows 10 Picked up JAVA_TOOL_OPTIONS: "-XX:+UsePerfData" "-Duser.language=en" "-Duser.country=US" "-Duser.timezone=UTC" "-Dfile.encoding=UTF-8" openjdk version "11.0.4" 2019-07-16 LTS OpenJDK Runtime Environment Zulu11.33+15-CA (build 11.0.4+11-LTS) OpenJDK 64-Bit Server VM Zulu11.33+15-CA (build 11.0.4+11-LTS, mixed mode) (this was also encountered with Java 8)
Description
- Extract Karaf distribution
- Start Karaf instance karaf
- Open 2 clients (ssh)
- log:tail
- In main initial console
- log:set DEBUG org.apache.sshd
- Perform some actions such as feature:repo-add cellar, feature:install cellar
- Sometime clients get disconnected, sometimes they are dead locked (use threads commands to see or use external process like jconsole)
- When dead lock happen, SSH server does not respond to new connections
This can also happen when log:tail is executing from the main console, rendering the console ineffective.
"sshd-SshServer[46bcb190]-nio2-thread-3" Id=146 in BLOCKED on lock=org.apache.karaf.log.core.internal.LogServiceImpl@46fdf7b8 owned by sshd-SshServer[46bcb190]-nio2-thread-4 Id=147 at org.apache.karaf.log.core.internal.LogServiceImpl.doAppend(LogServiceImpl.java:176) at org.ops4j.pax.logging.spi.support.PaxAppenderProxy.doAppend(PaxAppenderProxy.java:69) at org.ops4j.pax.logging.log4j2.internal.bridges.PaxOsgiAppender.append(PaxOsgiAppender.java:100) at org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:156) at org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:129) at org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:120) at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:84) at org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:543) at org.apache.logging.log4j.core.config.LoggerConfig.processLogEvent(LoggerConfig.java:502) at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:485) at org.apache.logging.log4j.core.config.LoggerConfig.logParent(LoggerConfig.java:534) at org.apache.logging.log4j.core.config.LoggerConfig.processLogEvent(LoggerConfig.java:504) at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:485) at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:412) at org.apache.logging.log4j.core.config.AwaitCompletionReliabilityStrategy.log(AwaitCompletionReliabilityStrategy.java:63) at org.apache.logging.log4j.core.Logger.logMessage(Logger.java:154) at org.ops4j.pax.logging.log4j2.internal.PaxLoggerImpl.doLog0(PaxLoggerImpl.java:354) at org.ops4j.pax.logging.log4j2.internal.PaxLoggerImpl.doLog(PaxLoggerImpl.java:337) at org.ops4j.pax.logging.log4j2.internal.PaxLoggerImpl.debug(PaxLoggerImpl.java:142) at org.ops4j.pax.logging.internal.TrackingLogger.debug(TrackingLogger.java:115) at org.ops4j.pax.logging.slf4j.Slf4jLogger.debug(Slf4jLogger.java:340) at org.apache.sshd.common.io.nio2.Nio2Session.writePacket(Nio2Session.java:136) at org.apache.sshd.common.session.helpers.AbstractSession.doWritePacket(AbstractSession.java:1154) - locked java.lang.Object@76a33827 at org.apache.sshd.common.session.helpers.AbstractSession.writePacket(AbstractSession.java:1096) at org.apache.sshd.common.channel.AbstractChannel.sendResponse(AbstractChannel.java:369) at org.apache.sshd.server.channel.ChannelSession.sendResponse(ChannelSession.java:336) at org.apache.sshd.common.channel.AbstractChannel.handleChannelRequest(AbstractChannel.java:302) at org.apache.sshd.common.channel.AbstractChannel.handleRequest(AbstractChannel.java:270) at org.apache.sshd.common.session.helpers.AbstractConnectionService.channelRequest(AbstractConnectionService.java:517) at org.apache.sshd.common.session.helpers.AbstractConnectionService.process(AbstractConnectionService.java:341) at org.apache.sshd.common.session.helpers.AbstractSession.doHandleMessage(AbstractSession.java:614) at org.apache.sshd.common.session.helpers.AbstractSession.handleMessage(AbstractSession.java:547) - locked java.lang.Object@1da148eb at org.apache.sshd.common.session.helpers.AbstractSession.decode(AbstractSession.java:1498) at org.apache.sshd.common.session.helpers.AbstractSession.messageReceived(AbstractSession.java:508) - locked java.lang.Object@430f279b at org.apache.sshd.common.session.helpers.AbstractSessionIoHandler.messageReceived(AbstractSessionIoHandler.java:66) at org.apache.sshd.common.io.nio2.Nio2Session.handleReadCycleCompletion(Nio2Session.java:301) at org.apache.sshd.common.io.nio2.Nio2Session$1.onCompleted(Nio2Session.java:281) at org.apache.sshd.common.io.nio2.Nio2Session$1.onCompleted(Nio2Session.java:278) at org.apache.sshd.common.io.nio2.Nio2CompletionHandler.lambda$completed$0(Nio2CompletionHandler.java:38) at org.apache.sshd.common.io.nio2.Nio2CompletionHandler$$Lambda$562/0x0000000100634840.run(Unknown Source) at java.base@11.0.4/java.security.AccessController.doPrivileged(Native Method) at org.apache.sshd.common.io.nio2.Nio2CompletionHandler.completed(Nio2CompletionHandler.java:37) at java.base@11.0.4/sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:127) at java.base@11.0.4/sun.nio.ch.Invoker$2.run(Invoker.java:219) at java.base@11.0.4/sun.nio.ch.AsynchronousChannelGroupImpl$1.run(AsynchronousChannelGroupImpl.java:112) at java.base@11.0.4/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base@11.0.4/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)
"sshd-SshServer[46bcb190]-nio2-thread-4" Id=147 in BLOCKED on lock=java.lang.Object@76a33827 owned by sshd-SshServer[46bcb190]-nio2-thread-3 Id=146 at org.apache.sshd.common.session.helpers.AbstractSession.doWritePacket(AbstractSession.java:1147) at org.apache.sshd.common.session.helpers.AbstractSession.writePacket(AbstractSession.java:1096) at org.apache.sshd.common.channel.AbstractChannel.writePacket(AbstractChannel.java:794) at org.apache.sshd.common.channel.ChannelOutputStream.flush(ChannelOutputStream.java:221) - locked org.apache.sshd.common.channel.ChannelOutputStream@397cee8f at org.jline.terminal.impl.LineDisciplineTerminal$FilteringOutputStream.flush(LineDisciplineTerminal.java:301) at org.jline.terminal.impl.LineDisciplineTerminal$FilteringOutputStream.write(LineDisciplineTerminal.java:296) at java.base@11.0.4/java.io.PrintStream.write(PrintStream.java:559) - locked java.io.PrintStream@1bd7d088 at java.base@11.0.4/sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:233) at java.base@11.0.4/sun.nio.cs.StreamEncoder.implFlushBuffer(StreamEncoder.java:312) at java.base@11.0.4/sun.nio.cs.StreamEncoder.flushBuffer(StreamEncoder.java:104) - locked java.io.OutputStreamWriter@c263509 at java.base@11.0.4/java.io.OutputStreamWriter.flushBuffer(OutputStreamWriter.java:184) at java.base@11.0.4/java.io.PrintStream.write(PrintStream.java:606) - locked java.io.PrintStream@1bd7d088 at java.base@11.0.4/java.io.PrintStream.print(PrintStream.java:745) at java.base@11.0.4/java.io.PrintStream.append(PrintStream.java:1147) at org.apache.karaf.log.command.DisplayLog.printEvent(DisplayLog.java:126) at org.apache.karaf.log.command.DisplayLog.printEvent(DisplayLog.java:110) at org.apache.karaf.log.command.LogTail.lambda$execute$0(LogTail.java:52) at org.apache.karaf.log.command.LogTail$$Lambda$611/0x00000001006b9c40.doAppend(Unknown Source) at org.apache.karaf.log.core.internal.LogServiceImpl.doAppend(LogServiceImpl.java:181) - locked org.apache.karaf.log.core.internal.LogServiceImpl@46fdf7b8 at org.ops4j.pax.logging.spi.support.PaxAppenderProxy.doAppend(PaxAppenderProxy.java:69) at org.ops4j.pax.logging.log4j2.internal.bridges.PaxOsgiAppender.append(PaxOsgiAppender.java:100) at org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:156) at org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:129) at org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:120) at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:84) at org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:543) at org.apache.logging.log4j.core.config.LoggerConfig.processLogEvent(LoggerConfig.java:502) at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:485) at org.apache.logging.log4j.core.config.LoggerConfig.logParent(LoggerConfig.java:534) at org.apache.logging.log4j.core.config.LoggerConfig.processLogEvent(LoggerConfig.java:504) at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:485) at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:412) at org.apache.logging.log4j.core.config.AwaitCompletionReliabilityStrategy.log(AwaitCompletionReliabilityStrategy.java:63) at org.apache.logging.log4j.core.Logger.logMessage(Logger.java:154) at org.ops4j.pax.logging.log4j2.internal.PaxLoggerImpl.doLog0(PaxLoggerImpl.java:354) at org.ops4j.pax.logging.log4j2.internal.PaxLoggerImpl.doLog(PaxLoggerImpl.java:337) at org.ops4j.pax.logging.log4j2.internal.PaxLoggerImpl.debug(PaxLoggerImpl.java:142) at org.ops4j.pax.logging.internal.TrackingLogger.debug(TrackingLogger.java:115) at org.ops4j.pax.logging.slf4j.Slf4jLogger.debug(Slf4jLogger.java:340) at org.apache.sshd.common.io.nio2.Nio2Session.handleCompletedWriteCycle(Nio2Session.java:397) at org.apache.sshd.common.io.nio2.Nio2Session$2.onCompleted(Nio2Session.java:372) at org.apache.sshd.common.io.nio2.Nio2Session$2.onCompleted(Nio2Session.java:369) at org.apache.sshd.common.io.nio2.Nio2CompletionHandler.lambda$completed$0(Nio2CompletionHandler.java:38) at org.apache.sshd.common.io.nio2.Nio2CompletionHandler$$Lambda$562/0x0000000100634840.run(Unknown Source) at java.base@11.0.4/java.security.AccessController.doPrivileged(Native Method) at org.apache.sshd.common.io.nio2.Nio2CompletionHandler.completed(Nio2CompletionHandler.java:37) at java.base@11.0.4/sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:127) at java.base@11.0.4/sun.nio.ch.Invoker$2.run(Invoker.java:219) at java.base@11.0.4/sun.nio.ch.AsynchronousChannelGroupImpl$1.run(AsynchronousChannelGroupImpl.java:112) at java.base@11.0.4/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base@11.0.4/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)