Frédéric Chuong created KARAF-6512:
--------------------------------------
Summary: Dead lock in LogServiceImpl
Key: KARAF-6512
URL: https://issues.apache.org/jira/browse/KARAF-6512
Project: Karaf
Issue Type: Bug
Components: karaf
Affects Versions: 4.2.7
Environment: Windows 10
{noformat}
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)
{noformat}
(this was also encountered with Java 8)
Reporter: Frédéric Chuong
# 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.
{noformat}
"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 [email protected]/java.security.AccessController.doPrivileged(Native
Method)
at
org.apache.sshd.common.io.nio2.Nio2CompletionHandler.completed(Nio2CompletionHandler.java:37)
at [email protected]/sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:127)
at [email protected]/sun.nio.ch.Invoker$2.run(Invoker.java:219)
at
[email protected]/sun.nio.ch.AsynchronousChannelGroupImpl$1.run(AsynchronousChannelGroupImpl.java:112)
at
[email protected]/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at
[email protected]/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at [email protected]/java.lang.Thread.run(Thread.java:834)
{noformat}
{noformat}
"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 [email protected]/java.io.PrintStream.write(PrintStream.java:559)
- locked java.io.PrintStream@1bd7d088
at
[email protected]/sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:233)
at
[email protected]/sun.nio.cs.StreamEncoder.implFlushBuffer(StreamEncoder.java:312)
at
[email protected]/sun.nio.cs.StreamEncoder.flushBuffer(StreamEncoder.java:104)
- locked java.io.OutputStreamWriter@c263509
at
[email protected]/java.io.OutputStreamWriter.flushBuffer(OutputStreamWriter.java:184)
at [email protected]/java.io.PrintStream.write(PrintStream.java:606)
- locked java.io.PrintStream@1bd7d088
at [email protected]/java.io.PrintStream.print(PrintStream.java:745)
at [email protected]/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 [email protected]/java.security.AccessController.doPrivileged(Native
Method)
at
org.apache.sshd.common.io.nio2.Nio2CompletionHandler.completed(Nio2CompletionHandler.java:37)
at [email protected]/sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:127)
at [email protected]/sun.nio.ch.Invoker$2.run(Invoker.java:219)
at
[email protected]/sun.nio.ch.AsynchronousChannelGroupImpl$1.run(AsynchronousChannelGroupImpl.java:112)
at
[email protected]/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at
[email protected]/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at [email protected]/java.lang.Thread.run(Thread.java:834)
{noformat}
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
