dCache-View stays in fetching data followed by a Stacktrace

[christianvoss]

Hi all,

in dCache-View we find the curious behaviour, that dCache view takes forever to fetch it's data for the directory view. This coincides with the stacktrace shown below. We are running 9.0.3. I'd assume this might be due to some missing tags? Indeed the directories might not have values for Retention Policy or Access Latency. I'm not sure if having these tags is mandatory now?

Thanks a lot,
Christian

28 Apr 2023 14:48:41 [jetty-136] [] Uncaught exception in thread jetty-136java.lang.IllegalStateException: Attribute is not defined: RETENTION_POLICY
at org.dcache.vehicles.FileAttributes.guard(FileAttributes.java:314)
at org.dcache.vehicles.FileAttributes.getRetentionPolicy(FileAttributes.java:483)
at org.dcache.pool.classic.ALRPReplicaStatePolicy.getTargetState(ALRPReplicaStatePolicy.java:42)
at org.dcache.qos.QoSTransitionEngine.directoryQoS(QoSTransitionEngine.java:458)
at org.dcache.qos.QoSTransitionEngine.getQosStatus(QoSTransitionEngine.java:424)
at org.dcache.restful.util.namespace.NamespaceUtils.addQoSAttributes(NamespaceUtils.java:57)
at org.dcache.restful.resources.namespace.FileResources.getFileAttributes(FileResources.java:237)
at jdk.internal.reflect.GeneratedMethodAccessor139.invoke(Unknown Source)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory.lambda$static$0(ResourceMethodInvocationHandlerFactory.java:52)
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:124)
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:167)
at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$TypeOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:219)
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:79)
at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:469)
at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:391)
at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:80)
at org.glassfish.jersey.server.ServerRuntime$1.run(ServerRuntime.java:253)
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:248)
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:244)
at org.glassfish.jersey.internal.Errors.process(Errors.java:292)
at org.glassfish.jersey.internal.Errors.process(Errors.java:274)
at org.glassfish.jersey.internal.Errors.process(Errors.java:244)
at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:265)
at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:232)
at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:679)
at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:392)
at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:346)
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:365)
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:318)
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:205)
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:799)
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:550)
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1434)
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:501)
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1349)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
at org.eclipse.jetty.server.handler.HandlerList.handle(HandlerList.java:59)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
at org.dcache.http.AuthenticationHandler.access$001(AuthenticationHandler.java:55)
at org.dcache.http.AuthenticationHandler.lambda$handle$0(AuthenticationHandler.java:156)
at java.base/java.security.AccessController.doPrivileged(Native Method)
at java.base/javax.security.auth.Subject.doAs(Subject.java:361)
at org.dcache.http.AuthenticationHandler.handle(AuthenticationHandler.java:153)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
at org.dcache.http.AbstractLoggingHandler.handle(AbstractLoggingHandler.java:110)
at org.eclipse.jetty.server.handler.HandlerList.handle(HandlerList.java:59)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
at org.eclipse.jetty.rewrite.handler.RewriteHandler.handle(RewriteHandler.java:322)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
at org.eclipse.jetty.server.Server.handle(Server.java:516)
at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:400)
at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:645)
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:392)
at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277)
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)
at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.onFillable(SslConnection.java:555)
at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:410)
at org.eclipse.jetty.io.ssl.SslConnection$2.succeeded(SslConnection.java:164)
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)
at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:338)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:315)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:173)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:131)
at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:409)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:883)
at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1034)
at java.base/java.lang.Thread.run(Thread.java:829)

[alrossi]

Christian, when adding back in the option to use the older qos engine, I added a method to get attributes when processing a qos change when the option is true. But that is not what your trace is all about. Here it is dCacheView wanting to get the directory attributes. I double-checked the code path for this (moving up the stack trace) and can see no differences between 7.2 and your version. I have also looked at the dCacheView code and it is not asking for qos properties as one of the parameters on the RESTful call. Yet somehow the isQos​ argument on the RESTful call is true​ (which is why it it trying to extract RP/AL). Is it possible to list the directory/ies in question using the dCacheView SWAGGER page (RESTful namespace/{path} GET without setting isQos? or using curl? Otherwise, I can only think that somehow your setup has changed and now reveals a bug in the code that has always existed. Al

…

________________________________________________ Albert L. Rossi Senior Software Developer Scientific Computing Division, Scientific Data Services, Distributed Data Development WH 566 Fermi National Accelerator Laboratory Batavia, IL 60510 (630) 840-3023

________________________________ From: christianvoss ***@***.***> Sent: Friday, April 28, 2023 8:01 AM To: dCache/dcache-view ***@***.***> Cc: Subscribed ***@***.***> Subject: [dCache/dcache-view] dCache-View stays in fetching data followed by a Stacktrace (Issue #284) Hi all, in dCache-View we find the curious behaviour, that dCache view takes forever to fetch it's data for the directory view. This coincides with the stacktrace shown below. We are running 9.0.3. I'd assume this might be due to some missing tags? Indeed the directories might not have values for Retention Policy or Access Latency. I'm not sure if having these tags is mandatory now? Thanks a lot, Christian 28 Apr 2023 14:48:41 [jetty-136] [] Uncaught exception in thread jetty-136java.lang.IllegalStateException: Attribute is not defined: RETENTION_POLICY at org.dcache.vehicles.FileAttributes.guard(FileAttributes.java:314) at org.dcache.vehicles.FileAttributes.getRetentionPolicy(FileAttributes.java:483) at org.dcache.pool.classic.ALRPReplicaStatePolicy.getTargetState(ALRPReplicaStatePolicy.java:42) at org.dcache.qos.QoSTransitionEngine.directoryQoS(QoSTransitionEngine.java:458) at org.dcache.qos.QoSTransitionEngine.getQosStatus(QoSTransitionEngine.java:424) at org.dcache.restful.util.namespace.NamespaceUtils.addQoSAttributes(NamespaceUtils.java:57) at org.dcache.restful.resources.namespace.FileResources.getFileAttributes(FileResources.java:237) at jdk.internal.reflect.GeneratedMethodAccessor139.invoke(Unknown Source) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:566) at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory.lambda$static$0(ResourceMethodInvocationHandlerFactory.java:52) at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:124) at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:167) at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$TypeOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:219) at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:79) at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:469) at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:391) at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:80) at org.glassfish.jersey.server.ServerRuntime$1.run(ServerRuntime.java:253) at org.glassfish.jersey.internal.Errors$1.call(Errors.java:248) at org.glassfish.jersey.internal.Errors$1.call(Errors.java:244) at org.glassfish.jersey.internal.Errors.process(Errors.java:292) at org.glassfish.jersey.internal.Errors.process(Errors.java:274) at org.glassfish.jersey.internal.Errors.process(Errors.java:244) at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:265) at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:232) at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:679) at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:392) at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:346) at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:365) at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:318) at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:205) at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:799) at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:550) at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233) at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1434) at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188) at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:501) at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186) at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1349) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) at org.eclipse.jetty.server.handler.HandlerList.handle(HandlerList.java:59) at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) at org.dcache.http.AuthenticationHandler.access$001(AuthenticationHandler.java:55) at org.dcache.http.AuthenticationHandler.lambda$handle$0(AuthenticationHandler.java:156) at java.base/java.security.AccessController.doPrivileged(Native Method) at java.base/javax.security.auth.Subject.doAs(Subject.java:361) at org.dcache.http.AuthenticationHandler.handle(AuthenticationHandler.java:153) at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) at org.dcache.http.AbstractLoggingHandler.handle(AbstractLoggingHandler.java:110) at org.eclipse.jetty.server.handler.HandlerList.handle(HandlerList.java:59) at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) at org.eclipse.jetty.rewrite.handler.RewriteHandler.handle(RewriteHandler.java:322) at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) at org.eclipse.jetty.server.Server.handle(Server.java:516) at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:400) at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:645) at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:392) at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277) at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311) at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105) at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.onFillable(SslConnection.java:555) at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:410) at org.eclipse.jetty.io.ssl.SslConnection$2.succeeded(SslConnection.java:164) at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105) at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104) at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:338) at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:315) at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:173) at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:131) at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:409) at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:883) at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1034) at java.base/java.lang.Thread.run(Thread.java:829) — Reply to this email directly, view it on GitHub<https://urldefense.proofpoint.com/v2/url?u=https-3A__github.com_dCache_dcache-2Dview_issues_284&d=DwMCaQ&c=gRgGjJ3BkIsb5y6s49QqsA&r=60rQ0HHqHmEY1P6VSdyuTQ&m=n1882PaeRs1tfnsa-MQATf7hUKPAQsvtLIThXUF4Nat_cVLQ-p0N6uN22rChTNf3&s=t7r1jWN5pDasmCHROwgydmJPByqIVlmA_-eiwvqnY7o&e=>, or unsubscribe<https://urldefense.proofpoint.com/v2/url?u=https-3A__github.com_notifications_unsubscribe-2Dauth_AA6NBHEK2OIUSQNYU5NMQH3XDO5RLANCNFSM6AAAAAAXPGV5KY&d=DwMCaQ&c=gRgGjJ3BkIsb5y6s49QqsA&r=60rQ0HHqHmEY1P6VSdyuTQ&m=n1882PaeRs1tfnsa-MQATf7hUKPAQsvtLIThXUF4Nat_cVLQ-p0N6uN22rChTNf3&s=gxnwmT3d6Sr2Zo6C3Uy4EYynQFpW19YZAi8ecmCoq7k&e=>. You are receiving this because you are subscribed to this thread.Message ID: ***@***.***>

[alrossi]

But I still think the true value for isQos is suspicious ...

[alrossi]

More:

I just created a directory with no tags.

Compare:

[root@fndcatemp1 notags]# cd ../pnfs
[root@fndcatemp1 pnfs]# cat ".(tag)(RetentionPolicy)"
REPLICA

to

[root@fndcatemp1 pnfs]# cd ../notags
[root@fndcatemp1 notags]# cat ".(tag)(RetentionPolicy)"
cat: .(tag)(RetentionPolicy): No such file or directory

now look at dCacheView home/root:

no files in directory: lists immediately.

And no stack trace in the frontend domain.

[paulmillar]

There are, I think, at least two issues here.

1. dCache is clearly broken, since this is triggering a stack-trace.

@christianvoss Could you open an issue against dCache's repo with the stack-trace?

2. The bug seems to trigger frontend to respond (to dCacheView's request) in such a way that that dCacheView freezes.

@christianvoss . could you try to find out more about this response?

You should be able to use the web-developer mode of your browser to see the HTTP request (from dCacheView) and corresponding response (from dCache)? The problem interaction is quite likely to be the last request-response pair when recreating this problem.