[jboss-jira] [JBoss JIRA] (WFCORE-40) Deadlock while logging
Harshvardhan Joshi (JIRA)
issues at jboss.org
Thu Apr 12 03:07:01 EDT 2018
[ https://issues.jboss.org/browse/WFCORE-40?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13559914#comment-13559914 ]
Harshvardhan Joshi commented on WFCORE-40:
------------------------------------------
Hi, I am using Wildfly 10 Final build.
I also encountered the above issue.
Default task-7 is waiting for PrintStream lock and Default task-6 has the lock but stuck at writeBytes() method.
Here is the Thread Dump for both the Threads:
{code:java}
"default task-7" #160 prio=5 os_prio=0 tid=0x000000005deaf800 nid=0x22dc waiting for monitor entry [0x000000005840e000]
java.lang.Thread.State: BLOCKED (on object monitor)
at java.io.PrintStream.println(PrintStream.java:806)
- waiting to lock <0x00000000e008bd60> (a java.io.PrintStream)
at org.jboss.stdio.StdioContext$DelegatingPrintStream.println(StdioContext.java:474)
at AndroidServlet.processRequest(AndroidServlet.java:183)
at AndroidServlet.doGet(AndroidServlet.java:252)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:687)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:85)
at io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62)
at io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36)
at org.wildfly.extension.undertow.security.SecurityContextAssociationHandler.handleRequest(SecurityContextAssociationHandler.java:78)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:131)
at io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46)
at io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64)
at io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:60)
at io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:77)
at io.undertow.security.handlers.NotificationReceiverHandler.handleRequest(NotificationReceiverHandler.java:50)
at io.undertow.security.handlers.AbstractSecurityContextAssociationHandler.handleRequest(AbstractSecurityContextAssociationHandler.java:43)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at org.wildfly.extension.undertow.security.jacc.JACCContextIdHandler.handleRequest(JACCContextIdHandler.java:61)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:284)
at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:263)
at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:81)
at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:174)
at io.undertow.server.Connectors.executeRootHandler(Connectors.java:202)
at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:793)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Locked ownable synchronizers:
- <0x00000000fa066038> (a java.util.concurrent.ThreadPoolExecutor$Worker)
"default task-6" #159 prio=5 os_prio=0 tid=0x000000005deb0800 nid=0x1b28 runnable [0x000000005f05d000]
java.lang.Thread.State: RUNNABLE
at java.io.FileOutputStream.writeBytes(Native Method)
at java.io.FileOutputStream.write(FileOutputStream.java:326)
at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140)
- locked <0x00000000e0e97a70> (a java.io.BufferedOutputStream)
at java.io.PrintStream.write(PrintStream.java:482)
- locked <0x00000000e0e97a50> (a java.io.PrintStream)
at org.jboss.logmanager.handlers.UncloseableOutputStream.write(UncloseableOutputStream.java:44)
at org.jboss.logmanager.handlers.UninterruptibleOutputStream.write(UninterruptibleOutputStream.java:84)
at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221)
at sun.nio.cs.StreamEncoder.implFlushBuffer(StreamEncoder.java:291)
at sun.nio.cs.StreamEncoder.implFlush(StreamEncoder.java:295)
at sun.nio.cs.StreamEncoder.flush(StreamEncoder.java:141)
- locked <0x00000000e0ee0780> (a java.io.OutputStreamWriter)
at java.io.OutputStreamWriter.flush(OutputStreamWriter.java:229)
at java.io.BufferedWriter.flush(BufferedWriter.java:254)
- locked <0x00000000e0ee0780> (a java.io.OutputStreamWriter)
at org.jboss.logmanager.handlers.WriterHandler.safeFlush(WriterHandler.java:170)
at org.jboss.logmanager.handlers.WriterHandler.flush(WriterHandler.java:139)
- locked <0x00000000e0ee0748> (a java.lang.Object)
at org.jboss.logmanager.ExtHandler.doPublish(ExtHandler.java:104)
at org.jboss.logmanager.handlers.WriterHandler.doPublish(WriterHandler.java:67)
- locked <0x00000000e0ee0748> (a java.lang.Object)
at org.jboss.logmanager.ExtHandler.publish(ExtHandler.java:76)
at org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:314)
at org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:322)
at org.jboss.logmanager.Logger.logRaw(Logger.java:850)
at org.jboss.logmanager.Logger.log(Logger.java:596)
at org.jboss.stdio.AbstractLoggingWriter.write(AbstractLoggingWriter.java:71)
- locked <0x00000000e008bdc0> (a java.lang.StringBuilder)
at org.jboss.stdio.WriterOutputStream.finish(WriterOutputStream.java:143)
at org.jboss.stdio.WriterOutputStream.flush(WriterOutputStream.java:164)
- locked <0x00000000e008bf30> (a sun.nio.cs.SingleByte$Decoder)
at java.io.PrintStream.write(PrintStream.java:482)
- locked <0x00000000e008bd60> (a java.io.PrintStream)
at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221)
at sun.nio.cs.StreamEncoder.implFlushBuffer(StreamEncoder.java:291)
at sun.nio.cs.StreamEncoder.flushBuffer(StreamEncoder.java:104)
- locked <0x00000000e008c308> (a java.io.OutputStreamWriter)
at java.io.OutputStreamWriter.flushBuffer(OutputStreamWriter.java:185)
at java.io.PrintStream.newLine(PrintStream.java:546)
- locked <0x00000000e008bd60> (a java.io.PrintStream)
at java.io.PrintStream.println(PrintStream.java:807)
- locked <0x00000000e008bd60> (a java.io.PrintStream)
at org.jboss.stdio.StdioContext$DelegatingPrintStream.println(StdioContext.java:474)
at AndroidServlet.processRequest(AndroidServlet.java:183)
at AndroidServlet.doGet(AndroidServlet.java:252)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:687)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:85)
at io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62)
at io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36)
at org.wildfly.extension.undertow.security.SecurityContextAssociationHandler.handleRequest(SecurityContextAssociationHandler.java:78)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:131)
at io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46)
at io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64)
at io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:60)
at io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:77)
at io.undertow.security.handlers.NotificationReceiverHandler.handleRequest(NotificationReceiverHandler.java:50)
at io.undertow.security.handlers.AbstractSecurityContextAssociationHandler.handleRequest(AbstractSecurityContextAssociationHandler.java:43)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at org.wildfly.extension.undertow.security.jacc.JACCContextIdHandler.handleRequest(JACCContextIdHandler.java:61)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:284)
at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:263)
at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:81)
at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:174)
at io.undertow.server.Connectors.executeRootHandler(Connectors.java:202)
at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:793)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Locked ownable synchronizers:
- <0x00000000f601cf68> (a java.util.concurrent.ThreadPoolExecutor$Worker)
{code}
> Deadlock while logging
> ----------------------
>
> Key: WFCORE-40
> URL: https://issues.jboss.org/browse/WFCORE-40
> Project: WildFly Core
> Issue Type: Bug
> Components: Logging
> Environment: CentOS 6.5 64bit, java7u45 64bit (and 32 bit, the same behavior)
> Reporter: Stefan Schueffler
> Assignee: James Perkins
> Priority: Critical
> Attachments: stack_140901_2254
>
>
> We hit really often a deadlock? in org.jboss.stdio.StdioContext$DelegatingPrintStream.println(StdioContext.java:474)
> Even if the "StdioContext" belongs to Jboss-Logging, the problem occurs in our production wildfly installation twice to 4 times a day - all threads are deadlocking while trying to log.debug, log.error, or (sometimes) System.out.println from our application code, and wildfly does not respond anymore...
> The partial stacktrace always is similar to this one:
> {code}
> "default task-64" prio=10 tid=0x4c539c00 nid=0x5ef9 waiting for monitor entry [0x495e0000]
> java.lang.Thread.State: BLOCKED (on object monitor)
> at java.io.PrintStream.println(PrintStream.java:806)
> - waiting to lock <0x5ee0adf8> (a java.io.PrintStream)
> at org.jboss.stdio.StdioContext$DelegatingPrintStream.println(StdioContext.java:474)
> at jsp.communications.statuschange.selectStatus_jsp._jspService(selectStatus_jsp.java:413)
> at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:69)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
> at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:85)
> at io.undertow.servlet.handlers.FilterHandler.handleRequest(FilterHandler.java:82)
> {code}
> While investigating the StdioContext - class, i really wondered whether the used "locking/checking by using a threadlocal" could have worked in a multi-threaded environment (it should have the very same problems as every "double checking" algorithm without proper synchronization).
> If all threads are hanging in this particular lock, only a full wildfly-restart recovers in our case.
> My preferred solution would be a rework of the used org.jboss.stdio. classes, as the used idioms of ThreadLocals for reentrant-checks are at least highly unusual?
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
More information about the jboss-jira
mailing list