Open
Description
Description
The issue is same as in #104962. We missed to cover places where the logout and session invalidation actions fork back to transport_worker and get blocked waiting on slow SAML metadata refresh.
Thread dump which shows transport_worker thread being blocked on a lock obtained by a timer thread that executes HTTP call to refresh SAML metadata
0.0% [cpu=0.0%, idle=100.0%] (0s out of 500ms) cpu usage by thread 'elasticsearch[xxxx][transport_worker][T#2]'
10/10 snapshots sharing following 73 elements
[email protected]/net.shibboleth.utilities.java.support.component.AbstractInitializableComponent.isInitialized(AbstractInitializableComponent.java:43)
[email protected]/net.shibboleth.utilities.java.support.component.ComponentSupport.ifNotInitializedThrowUninitializedComponentException(ComponentSupport.java:104)
[email protected]/org.opensaml.saml.metadata.resolver.impl.AbstractMetadataResolver.resolveSingle(AbstractMetadataResolver.java:262)
[email protected]/org.elasticsearch.xpack.security.authc.saml.SamlRealm.resolveEntityDescriptorWithPossibleRefresh(SamlRealm.java:844)
[email protected]/org.elasticsearch.xpack.security.authc.saml.SamlRealm.resolveEntityDescriptor(SamlRealm.java:822)
[email protected]/org.elasticsearch.xpack.security.authc.saml.SamlRealm.lambda$parseHttpMetadata$9(SamlRealm.java:734)
[email protected]/org.elasticsearch.xpack.security.authc.saml.SamlRealm$$Lambda/0x00007f7d87e9eb58.run(Unknown Source)
[email protected]/java.security.AccessController.executePrivileged(AccessController.java:816)
[email protected]/java.security.AccessController.doPrivileged(AccessController.java:571)
[email protected]/org.elasticsearch.xpack.security.authc.saml.SamlRealm.lambda$parseHttpMetadata$10(SamlRealm.java:733)
[email protected]/org.elasticsearch.xpack.security.authc.saml.SamlRealm$$Lambda/0x00007f7d87e9b108.get(Unknown Source)
[email protected]/org.elasticsearch.xpack.security.authc.saml.SamlRealm.buildLogoutRequest(SamlRealm.java:935)
[email protected]/org.elasticsearch.xpack.security.action.saml.TransportSamlLogoutAction.buildResponse(TransportSamlLogoutAction.java:127)
[email protected]/org.elasticsearch.xpack.security.action.saml.TransportSamlLogoutAction.lambda$doExecuteForked$2(TransportSamlLogoutAction.java:76)
[email protected]/org.elasticsearch.xpack.security.action.saml.TransportSamlLogoutAction$$Lambda/0x00007f7d88394800.accept(Unknown Source)
app/[email protected]/org.elasticsearch.action.ActionListener$2.onResponse(ActionListener.java:249)
[email protected]/org.elasticsearch.xpack.security.authc.TokenService.lambda$getAuthenticationAndMetadata$5(TokenService.java:495)
[email protected]/org.elasticsearch.xpack.security.authc.TokenService$$Lambda/0x00007f7d88394c60.accept(Unknown Source)
app/[email protected]/org.elasticsearch.action.ActionListener$2.onResponse(ActionListener.java:249)
[email protected]/org.elasticsearch.xpack.security.authc.TokenService.lambda$getAndValidateUserToken$6(TokenService.java:536)
[email protected]/org.elasticsearch.xpack.security.authc.TokenService$$Lambda/0x00007f7d88a15400.accept(Unknown Source)
app/[email protected]/org.elasticsearch.action.ActionListener$2.onResponse(ActionListener.java:249)
[email protected]/org.elasticsearch.xpack.security.authc.TokenService.lambda$getTokenDocById$9(TokenService.java:607)
[email protected]/org.elasticsearch.xpack.security.authc.TokenService$$Lambda/0x00007f7d885ee400.accept(Unknown Source)
app/[email protected]/org.elasticsearch.action.ActionListener$2.onResponse(ActionListener.java:249)
app/[email protected]/org.elasticsearch.action.support.ContextPreservingActionListener.onResponse(ContextPreservingActionListener.java:32)
app/[email protected]/org.elasticsearch.tasks.TaskManager$1.onResponse(TaskManager.java:202)
app/[email protected]/org.elasticsearch.tasks.TaskManager$1.onResponse(TaskManager.java:196)
app/[email protected]/org.elasticsearch.action.ActionListenerImplementations$RunBeforeActionListener.onResponse(ActionListenerImplementations.java:307)
app/[email protected]/org.elasticsearch.action.support.ContextPreservingActionListener.onResponse(ContextPreservingActionListener.java:32)
app/[email protected]/org.elasticsearch.action.ActionListenerImplementations$MappedActionListener.onResponse(ActionListenerImplementations.java:95)
app/[email protected]/org.elasticsearch.action.ActionListenerResponseHandler.handleResponse(ActionListenerResponseHandler.java:48)
app/[email protected]/org.elasticsearch.transport.TransportService$ContextRestoreResponseHandler.handleResponse(TransportService.java:1480)
app/[email protected]/org.elasticsearch.transport.InboundHandler.doHandleResponse(InboundHandler.java:432)
app/[email protected]/org.elasticsearch.transport.InboundHandler.handleResponse(InboundHandler.java:381)
app/[email protected]/org.elasticsearch.transport.InboundHandler.executeResponseHandler(InboundHandler.java:148)
app/[email protected]/org.elasticsearch.transport.InboundHandler.messageReceived(InboundHandler.java:123)
app/[email protected]/org.elasticsearch.transport.InboundHandler.inboundMessage(InboundHandler.java:97)
app/[email protected]/org.elasticsearch.transport.TcpTransport.inboundMessage(TcpTransport.java:821)
[email protected]/org.elasticsearch.transport.netty4.Netty4Transport$$Lambda/0x00007f7d885c67e0.accept(Unknown Source)
app/[email protected]/org.elasticsearch.transport.InboundPipeline.forwardFragments(InboundPipeline.java:124)
app/[email protected]/org.elasticsearch.transport.InboundPipeline.doHandleBytes(InboundPipeline.java:96)
app/[email protected]/org.elasticsearch.transport.InboundPipeline.handleBytes(InboundPipeline.java:61)
[email protected]/org.elasticsearch.transport.netty4.Netty4MessageInboundHandler.channelRead(Netty4MessageInboundHandler.java:57)
[email protected]/io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444)
[email protected]/io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
[email protected]/io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
[email protected]/io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:103)
[email protected]/io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444)
[email protected]/io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
[email protected]/io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
[email protected]/io.netty.handler.ssl.SslHandler.unwrap(SslHandler.java:1475)
[email protected]/io.netty.handler.ssl.SslHandler.decodeJdkCompatible(SslHandler.java:1338)
[email protected]/io.netty.handler.ssl.SslHandler.decode(SslHandler.java:1387)
[email protected]/io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:530)
[email protected]/io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:469)
[email protected]/io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:290)
[email protected]/io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444)
[email protected]/io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
[email protected]/io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
[email protected]/io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410)
[email protected]/io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:440)
[email protected]/io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
[email protected]/io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919)
[email protected]/io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166)
[email protected]/io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:788)
[email protected]/io.netty.channel.nio.NioEventLoop.processSelectedKeysPlain(NioEventLoop.java:689)
[email protected]/io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:652)
[email protected]/io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:562)
[email protected]/io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997)
[email protected]/io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
[email protected]/java.lang.Thread.runWith(Thread.java:1583)
[email protected]/java.lang.Thread.run(Thread.java:1570)
0.0% [cpu=0.0%, other=0.0%] (0s out of 500ms) cpu usage by thread 'Timer for org.elasticsearch.xpack.security.authc.saml.SamlRealm$PrivilegedHTTPMetadataResolver@73128b3a'
10/10 snapshots sharing following 39 elements
[email protected]/sun.nio.ch.SocketDispatcher.read0(Native Method)
[email protected]/sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:47)
[email protected]/sun.nio.ch.NioSocketImpl.tryRead(NioSocketImpl.java:256)
[email protected]/sun.nio.ch.NioSocketImpl.implRead(NioSocketImpl.java:307)
[email protected]/sun.nio.ch.NioSocketImpl.read(NioSocketImpl.java:346)
[email protected]/sun.nio.ch.NioSocketImpl$1.read(NioSocketImpl.java:796)
[email protected]/java.net.Socket$SocketInputStream.implRead(Socket.java:1108)
[email protected]/java.net.Socket$SocketInputStream.read(Socket.java:1095)
[email protected]/sun.security.ssl.SSLSocketInputRecord.read(SSLSocketInputRecord.java:489)
[email protected]/sun.security.ssl.SSLSocketInputRecord.readHeader(SSLSocketInputRecord.java:483)
[email protected]/sun.security.ssl.SSLSocketInputRecord.decode(SSLSocketInputRecord.java:160)
[email protected]/sun.security.ssl.SSLTransport.decode(SSLTransport.java:111)
[email protected]/sun.security.ssl.SSLSocketImpl.decode(SSLSocketImpl.java:1507)
[email protected]/sun.security.ssl.SSLSocketImpl.readHandshakeRecord(SSLSocketImpl.java:1422)
[email protected]/sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:455)
[email protected]/sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:426)
[email protected]/org.apache.http.conn.ssl.SSLConnectionSocketFactory.createLayeredSocket(SSLConnectionSocketFactory.java:436)
[email protected]/org.apache.http.conn.ssl.SSLConnectionSocketFactory.connectSocket(SSLConnectionSocketFactory.java:384)
[email protected]/org.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:142)
[email protected]/org.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:376)
[email protected]/org.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:393)
[email protected]/org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:236)
[email protected]/org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:186)
[email protected]/org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)
[email protected]/org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110)
[email protected]/org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)
[email protected]/org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)
[email protected]/org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56)
[email protected]/org.opensaml.saml.metadata.resolver.impl.HTTPMetadataResolver.fetchMetadata(HTTPMetadataResolver.java:212)
[email protected]/org.elasticsearch.xpack.security.authc.saml.SamlRealm$PrivilegedHTTPMetadataResolver.access$001(SamlRealm.java:747)
[email protected]/org.elasticsearch.xpack.security.authc.saml.SamlRealm$PrivilegedHTTPMetadataResolver.lambda$fetchMetadata$0(SamlRealm.java:758)
[email protected]/org.elasticsearch.xpack.security.authc.saml.SamlRealm$PrivilegedHTTPMetadataResolver$$Lambda/0x00007f7d87e5b0e0.run(Unknown Source)
[email protected]/java.security.AccessController.executePrivileged(AccessController.java:816)
[email protected]/java.security.AccessController.doPrivileged(AccessController.java:571)
[email protected]/org.elasticsearch.xpack.security.authc.saml.SamlRealm$PrivilegedHTTPMetadataResolver.fetchMetadata(SamlRealm.java:757)
[email protected]/org.opensaml.saml.metadata.resolver.impl.AbstractReloadingMetadataResolver.refresh(AbstractReloadingMetadataResolver.java:364)
[email protected]/org.opensaml.saml.metadata.resolver.impl.AbstractReloadingMetadataResolver$RefreshMetadataTask.run(AbstractReloadingMetadataResolver.java:685)
[email protected]/java.util.TimerThread.mainLoop(Timer.java:571)
[email protected]/java.util.TimerThread.run(Timer.java:521)