Hello! Recently got deadlock in one of our applications. Using locks in toString() it's generally not a good idea. I wonder if it's possible to avoid indefinite blocking inside SSLIOSession.toString()? Maybe it's better to use tryLock and if returns 'false' - then show only parts which are _safe_ to show. As alternative use lock with some small timeout. What do you think?
``` Found one Java-level deadlock: ============================= "firebase-default-68": waiting for ownable synchronizer 0x00000000c8c01aa0, (a java.util.concurrent.locks.ReentrantLock$NonfairSync), which is held by "httpclient-dispatch-1" "httpclient-dispatch-1": waiting to lock monitor 0x00007f65a8009ae0 (object 0x00000000c1f1d5e0, a java.lang.Object), which is held by "firebase-default-68" Java stack information for the threads listed above: =================================================== "firebase-default-68": at jdk.internal.misc.Unsafe.park([email protected]/Native Method) - parking to wait for <0x00000000c8c01aa0> (a java.util.concurrent.locks.ReentrantLock$NonfairSync) at java.util.concurrent.locks.LockSupport.park([email protected]/LockSupport.java:221) at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire([email protected]/AbstractQueuedSynchronizer.java:788) at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire([email protected]/AbstractQueuedSynchronizer.java:1024) at java.util.concurrent.locks.ReentrantLock$Sync.lock([email protected]/ReentrantLock.java:153) at java.util.concurrent.locks.ReentrantLock.lock([email protected]/ReentrantLock.java:322) at org.apache.hc.core5.reactor.ssl.SSLIOSession.toString(SSLIOSession.java:903) at org.apache.logging.log4j.message.ParameterFormatter.tryObjectToString(ParameterFormatter.java:600) at org.apache.logging.log4j.message.ParameterFormatter.recursiveDeepToString(ParameterFormatter.java:450) at org.apache.logging.log4j.message.ParameterFormatter.recursiveDeepToString(ParameterFormatter.java:419) at org.apache.logging.log4j.message.ParameterFormatter.formatMessageContainingNoEscapes(ParameterFormatter.java:284) at org.apache.logging.log4j.message.ParameterFormatter.formatMessage(ParameterFormatter.java:267) at org.apache.logging.log4j.message.ReusableParameterizedMessage.formatTo(ReusableParameterizedMessage.java:351) at org.apache.logging.log4j.core.async.RingBufferLogEvent.setMessage(RingBufferLogEvent.java:146) at org.apache.logging.log4j.core.async.RingBufferLogEvent.setValues(RingBufferLogEvent.java:116) at org.apache.logging.log4j.core.async.RingBufferLogEventTranslator.translateTo(RingBufferLogEventTranslator.java:60) at org.apache.logging.log4j.core.async.RingBufferLogEventTranslator.translateTo(RingBufferLogEventTranslator.java:37) at com.lmax.disruptor.RingBuffer.translateAndPublish(RingBuffer.java:962) at com.lmax.disruptor.RingBuffer.publishEvent(RingBuffer.java:466) at com.lmax.disruptor.dsl.Disruptor.publishEvent(Disruptor.java:331) at org.apache.logging.log4j.core.async.AsyncLoggerDisruptor.enqueueLogMessageWhenQueueFull(AsyncLoggerDisruptor.java:274) - locked <0x00000000c1f1d5e0> (a java.lang.Object) at org.apache.logging.log4j.core.async.AsyncLogger.handleRingBufferFull(AsyncLogger.java:291) at org.apache.logging.log4j.core.async.AsyncLogger.publish(AsyncLogger.java:275) at org.apache.logging.log4j.core.async.AsyncLogger.logWithThreadLocalTranslator(AsyncLogger.java:270) at org.apache.logging.log4j.core.async.AsyncLogger.access$000(AsyncLogger.java:70) at org.apache.logging.log4j.core.async.AsyncLogger$1.log(AsyncLogger.java:177) at org.apache.logging.log4j.core.async.AsyncLogger.log(AsyncLogger.java:148) at org.apache.logging.log4j.spi.AbstractLogger.tryLogMessage(AbstractLogger.java:2904) at org.apache.logging.log4j.spi.AbstractLogger.logMessageTrackRecursion(AbstractLogger.java:2857) at org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely(AbstractLogger.java:2839) at org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:2629) at org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:2392) at org.apache.logging.slf4j.Log4jLogger.debug(Log4jLogger.java:128) at org.apache.hc.client5.http.impl.async.LoggingIOSession.enqueue(LoggingIOSession.java:83) at org.apache.hc.core5.reactor.InternalDataChannel.enqueue(InternalDataChannel.java:286) at org.apache.hc.client5.http.impl.nio.DefaultManagedAsyncClientConnection.submitCommand(DefaultManagedAsyncClientConnection.java:201) at org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnectionManager$InternalConnectionEndpoint.execute(PoolingAsyncClientConnectionManager.java:765) at org.apache.hc.client5.http.impl.async.InternalHttpAsyncExecRuntime.execute(InternalHttpAsyncExecRuntime.java:298) at org.apache.hc.client5.http.impl.async.HttpAsyncMainClientExec.execute(HttpAsyncMainClientExec.java:295) at org.apache.hc.client5.http.impl.async.AsyncExecChainElement.execute(AsyncExecChainElement.java:54) at org.apache.hc.client5.http.impl.async.AsyncExecChainElement$$Lambda/0x00007f662cfd9680.proceed(Unknown Source) at org.apache.hc.client5.http.impl.async.AsyncConnectExec$1.completed(AsyncConnectExec.java:159) at org.apache.hc.client5.http.impl.async.AsyncConnectExec$1.completed(AsyncConnectExec.java:153) at org.apache.hc.client5.http.impl.async.InternalHttpAsyncExecRuntime$1.completed(InternalHttpAsyncExecRuntime.java:128) at org.apache.hc.client5.http.impl.async.InternalHttpAsyncExecRuntime$1.completed(InternalHttpAsyncExecRuntime.java:120) at org.apache.hc.core5.concurrent.BasicFuture.completed(BasicFuture.java:148) at org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnectionManager$3$1.leaseCompleted(PoolingAsyncClientConnectionManager.java:342) at org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnectionManager$3$1.completed(PoolingAsyncClientConnectionManager.java:324) at org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnectionManager$3$1.completed(PoolingAsyncClientConnectionManager.java:289) at org.apache.hc.core5.concurrent.BasicFuture.completed(BasicFuture.java:148) at org.apache.hc.core5.pool.StrictConnPool.fireCallbacks(StrictConnPool.java:401) at org.apache.hc.core5.pool.StrictConnPool.lease(StrictConnPool.java:219) at org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnectionManager$3.<init>(PoolingAsyncClientConnectionManager.java:286) at org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnectionManager.lease(PoolingAsyncClientConnectionManager.java:281) at org.apache.hc.client5.http.impl.async.InternalHttpAsyncExecRuntime.acquireEndpoint(InternalHttpAsyncExecRuntime.java:115) at org.apache.hc.client5.http.impl.async.AsyncConnectExec.execute(AsyncConnectExec.java:152) at org.apache.hc.client5.http.impl.async.AsyncExecChainElement.execute(AsyncExecChainElement.java:54) at org.apache.hc.client5.http.impl.async.AsyncExecChainElement$$Lambda/0x00007f662cfd9680.proceed(Unknown Source) at org.apache.hc.client5.http.impl.async.AsyncProtocolExec.internalExecute(AsyncProtocolExec.java:209) at org.apache.hc.client5.http.impl.async.AsyncProtocolExec.execute(AsyncProtocolExec.java:174) at org.apache.hc.client5.http.impl.async.AsyncExecChainElement.execute(AsyncExecChainElement.java:54) at org.apache.hc.client5.http.impl.async.InternalAbstractHttpAsyncClient$$Lambda/0x00007f662cfd8fd0.proceed(Unknown Source) at org.apache.hc.client5.http.impl.async.InternalAbstractHttpAsyncClient.executeImmediate(InternalAbstractHttpAsyncClient.java:389) at org.apache.hc.client5.http.impl.async.InternalAbstractHttpAsyncClient.lambda$doExecute$0(InternalAbstractHttpAsyncClient.java:245) at org.apache.hc.client5.http.impl.async.InternalAbstractHttpAsyncClient$$Lambda/0x00007f662cfd2e30.sendRequest(Unknown Source) at org.apache.hc.core5.http.nio.support.BasicRequestProducer.sendRequest(BasicRequestProducer.java:93) at org.apache.hc.client5.http.impl.async.InternalAbstractHttpAsyncClient.doExecute(InternalAbstractHttpAsyncClient.java:209) at org.apache.hc.client5.http.impl.async.CloseableHttpAsyncClient.execute(CloseableHttpAsyncClient.java:96) at org.apache.hc.client5.http.impl.async.CloseableHttpAsyncClient.execute(CloseableHttpAsyncClient.java:106) at org.apache.hc.client5.http.impl.async.CloseableHttpAsyncClient.execute(CloseableHttpAsyncClient.java:115) at com.google.firebase.internal.ApacheHttp2Request.execute(ApacheHttp2Request.java:98) at com.google.api.client.http.HttpRequest.execute(HttpRequest.java:1012) at com.google.firebase.internal.ErrorHandlingHttpClient.send(ErrorHandlingHttpClient.java:97) at com.google.firebase.internal.ErrorHandlingHttpClient.sendAndParse(ErrorHandlingHttpClient.java:72) at com.google.firebase.messaging.FirebaseMessagingClientImpl.sendSingleRequest(FirebaseMessagingClientImpl.java:127) at com.google.firebase.messaging.FirebaseMessagingClientImpl.send(FirebaseMessagingClientImpl.java:113) at com.google.firebase.messaging.FirebaseMessaging$1.execute(FirebaseMessaging.java:142) at com.google.firebase.messaging.FirebaseMessaging$1.execute(FirebaseMessaging.java:139) at com.google.firebase.internal.CallableOperation.call(CallableOperation.java:36) at com.google.common.util.concurrent.TrustedListenableFutureTask$TrustedFutureInterruptibleTask.runInterruptibly(TrustedListenableFutureTask.java:131) at com.google.common.util.concurrent.InterruptibleTask.run(InterruptibleTask.java:75) at com.google.common.util.concurrent.TrustedListenableFutureTask.run(TrustedListenableFutureTask.java:82) "httpclient-dispatch-1": at org.apache.logging.log4j.core.async.AsyncLoggerDisruptor.enqueueLogMessageWhenQueueFull(AsyncLoggerDisruptor.java:273) - waiting to lock <0x00000000c1f1d5e0> (a java.lang.Object) at org.apache.logging.log4j.core.async.AsyncLogger.handleRingBufferFull(AsyncLogger.java:291) at org.apache.logging.log4j.core.async.AsyncLogger.publish(AsyncLogger.java:275) at org.apache.logging.log4j.core.async.AsyncLogger.logWithThreadLocalTranslator(AsyncLogger.java:270) at org.apache.logging.log4j.core.async.AsyncLogger.access$000(AsyncLogger.java:70) at org.apache.logging.log4j.core.async.AsyncLogger$1.log(AsyncLogger.java:177) at org.apache.logging.log4j.core.async.AsyncLogger.log(AsyncLogger.java:148) at org.apache.logging.log4j.spi.AbstractLogger.tryLogMessage(AbstractLogger.java:2904) at org.apache.logging.log4j.spi.AbstractLogger.logMessageTrackRecursion(AbstractLogger.java:2857) at org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely(AbstractLogger.java:2839) at org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:2646) at org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:2413) at org.apache.logging.slf4j.Log4jLogger.debug(Log4jLogger.java:123) at org.apache.hc.client5.http.impl.async.LogAppendable.append(LogAppendable.java:63) at org.apache.hc.client5.http.impl.async.LogAppendable.append(LogAppendable.java:55) at org.apache.hc.client5.http.impl.async.LogAppendable.append(LogAppendable.java:49) at org.apache.hc.core5.http2.frame.FramePrinter.printData(FramePrinter.java:209) at org.apache.hc.core5.http2.frame.FramePrinter.printPayload(FramePrinter.java:174) at org.apache.hc.client5.http.impl.async.HttpAsyncClientProtocolNegotiationStarter$2.logFramePayload(HttpAsyncClientProtocolNegotiationStarter.java:183) at org.apache.hc.client5.http.impl.async.HttpAsyncClientProtocolNegotiationStarter$2.onFrameOutput(HttpAsyncClientProtocolNegotiationStarter.java:227) at org.apache.hc.core5.http2.impl.nio.AbstractH2StreamMultiplexer.streamDataFrame(AbstractH2StreamMultiplexer.java:344) at org.apache.hc.core5.http2.impl.nio.AbstractH2StreamMultiplexer.streamData(AbstractH2StreamMultiplexer.java:362) at org.apache.hc.core5.http2.impl.nio.AbstractH2StreamMultiplexer.access$1200(AbstractH2StreamMultiplexer.java:98) at org.apache.hc.core5.http2.impl.nio.AbstractH2StreamMultiplexer$H2StreamChannelImpl.write(AbstractH2StreamMultiplexer.java:1477) at org.apache.hc.core5.http2.impl.nio.ClientH2StreamHandler$1.write(ClientH2StreamHandler.java:92) at org.apache.hc.client5.http.impl.async.LoggingAsyncClientExchangeHandler$1.write(LoggingAsyncClientExchangeHandler.java:100) at org.apache.hc.client5.http.impl.async.HttpAsyncMainClientExec$1$1.write(HttpAsyncMainClientExec.java:176) at com.google.firebase.internal.ApacheHttp2AsyncEntityProducer.produce(ApacheHttp2AsyncEntityProducer.java:117) at org.apache.hc.core5.http.nio.support.BasicRequestProducer.produce(BasicRequestProducer.java:104) at org.apache.hc.client5.http.impl.async.InternalAbstractHttpAsyncClient$3.produce(InternalAbstractHttpAsyncClient.java:300) at org.apache.hc.client5.http.impl.async.HttpAsyncMainClientExec$1.produce(HttpAsyncMainClientExec.java:167) at org.apache.hc.client5.http.impl.async.LoggingAsyncClientExchangeHandler.produce(LoggingAsyncClientExchangeHandler.java:88) at org.apache.hc.core5.http2.impl.nio.ClientH2StreamHandler.commitRequest(ClientH2StreamHandler.java:157) at org.apache.hc.core5.http2.impl.nio.ClientH2StreamHandler.lambda$produceOutput$0(ClientH2StreamHandler.java:172) at org.apache.hc.core5.http2.impl.nio.ClientH2StreamHandler$$Lambda/0x00007f662cffb878.sendRequest(Unknown Source) at org.apache.hc.client5.http.impl.async.LoggingAsyncClientExchangeHandler.lambda$produceRequest$0(LoggingAsyncClientExchangeHandler.java:74) at org.apache.hc.client5.http.impl.async.LoggingAsyncClientExchangeHandler$$Lambda/0x00007f662cffbaa0.sendRequest(Unknown Source) at org.apache.hc.client5.http.impl.async.HttpAsyncMainClientExec$1.produceRequest(HttpAsyncMainClientExec.java:154) at org.apache.hc.client5.http.impl.async.LoggingAsyncClientExchangeHandler.produceRequest(LoggingAsyncClientExchangeHandler.java:69) at org.apache.hc.core5.http2.impl.nio.ClientH2StreamHandler.produceOutput(ClientH2StreamHandler.java:172) at org.apache.hc.core5.http2.impl.nio.AbstractH2StreamMultiplexer$H2Stream.produceOutput(AbstractH2StreamMultiplexer.java:1675) at org.apache.hc.core5.http2.impl.nio.AbstractH2StreamMultiplexer.processPendingCommands(AbstractH2StreamMultiplexer.java:654) at org.apache.hc.core5.http2.impl.nio.AbstractH2StreamMultiplexer.onOutput(AbstractH2StreamMultiplexer.java:518) at org.apache.hc.core5.http2.impl.nio.AbstractH2IOEventHandler.outputReady(AbstractH2IOEventHandler.java:74) at org.apache.hc.core5.http2.impl.nio.ClientH2IOEventHandler.outputReady(ClientH2IOEventHandler.java:39) at org.apache.hc.client5.http.impl.async.LoggingIOSession$1.outputReady(LoggingIOSession.java:243) at org.apache.hc.core5.reactor.ssl.SSLIOSession.encryptData(SSLIOSession.java:658) at org.apache.hc.core5.reactor.ssl.SSLIOSession.access$400(SSLIOSession.java:74) at org.apache.hc.core5.reactor.ssl.SSLIOSession$1.outputReady(SSLIOSession.java:210) at org.apache.hc.core5.reactor.InternalDataChannel.onIOEvent(InternalDataChannel.java:149) at org.apache.hc.core5.reactor.InternalChannel.handleIOEvent(InternalChannel.java:51) at org.apache.hc.core5.reactor.SingleCoreIOReactor.processEvents(SingleCoreIOReactor.java:176) at org.apache.hc.core5.reactor.SingleCoreIOReactor.doExecute(SingleCoreIOReactor.java:125) at org.apache.hc.core5.reactor.AbstractSingleCoreIOReactor.execute(AbstractSingleCoreIOReactor.java:92) at org.apache.hc.core5.reactor.IOReactorWorker.run(IOReactorWorker.java:44) ``` Andrey Turbanov --------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
