Failed to read resource

Help / Discuss
#1

Hello everyone,

I am running XWiki inside a docker container and get random crashes, because some web resources cannot be loaded (according to the logs).

Sometimes it is Bootstrap, sometimes it is CKEditor, so it’s not consistent.

Snippet from the logs:

2021-05-26 09:07:01,786 [http-nio-8080-exec-10 - http://wiki.example.com/webjars/wiki%3Axwiki/application-ckeditor-webjar/1.53.2/plugins/emoji/emoji.json?t=L2OC] ERROR ebJarsResourceReferenceHandle                                                        r - Failed to read resource [application-ckeditor-webjar/1.53.2/plugins/emoji/emoji.json]
org.xwiki.resource.ResourceReferenceHandlerException: Failed to read resource [application-ckeditor-webjar/1.53.2/plugins/emoji/emoji.json]
        at org.xwiki.resource.servlet.AbstractServletResourceReferenceHandler.serveResource(AbstractServletResourceReferenceHandler.java:180)
        at org.xwiki.resource.servlet.AbstractServletResourceReferenceHandler.handle(AbstractServletResourceReferenceHandler.java:85)
        at org.xwiki.resource.internal.DefaultResourceReferenceHandlerChain.handleNext(DefaultResourceReferenceHandlerChain.java:79)
        at org.xwiki.resource.internal.AbstractResourceReferenceHandlerManager.handle(AbstractResourceReferenceHandlerManager.java:82)
        at org.xwiki.resource.servlet.ResourceReferenceHandlerServlet.handleResourceReference(ResourceReferenceHandlerServlet.java:159)
        at org.xwiki.resource.servlet.ResourceReferenceHandlerServlet.service(ResourceReferenceHandlerServlet.java:87)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:733)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
        at org.xwiki.container.servlet.filters.internal.SetHTTPHeaderFilter.doFilter(SetHTTPHeaderFilter.java:63)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
        at org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:711)
        at org.apache.catalina.core.ApplicationDispatcher.processRequest(ApplicationDispatcher.java:460)
        at org.apache.catalina.core.ApplicationDispatcher.doForward(ApplicationDispatcher.java:355)
        at org.apache.catalina.core.ApplicationDispatcher.forward(ApplicationDispatcher.java:315)
        at org.xwiki.resource.servlet.RoutingFilter.doFilter(RoutingFilter.java:145)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:201)
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97)
        at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:544)
        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:143)
        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:81)
        at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:698)
        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78)
        at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:364)
        at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:616)
        at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
        at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:831)
        at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1629)
        at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
        at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: org.apache.catalina.connector.ClientAbortException: java.io.IOException: Broken pipe
        at org.apache.catalina.connector.OutputBuffer.realWriteBytes(OutputBuffer.java:371)
        at org.apache.catalina.connector.OutputBuffer.appendByteArray(OutputBuffer.java:815)
        at org.apache.catalina.connector.OutputBuffer.append(OutputBuffer.java:744)
        at org.apache.catalina.connector.OutputBuffer.writeBytes(OutputBuffer.java:406)
        at org.apache.catalina.connector.OutputBuffer.write(OutputBuffer.java:384)
        at org.apache.catalina.connector.CoyoteOutputStream.write(CoyoteOutputStream.java:96)
        at org.apache.commons.io.IOUtils.copyLarge(IOUtils.java:1159)
        at org.apache.commons.io.IOUtils.copy(IOUtils.java:878)
        at org.apache.commons.io.IOUtils.copyLarge(IOUtils.java:1135)
        at org.apache.commons.io.IOUtils.copy(IOUtils.java:854)
        at org.xwiki.resource.servlet.AbstractServletResourceReferenceHandler.serveResource(AbstractServletResourceReferenceHandler.java:178)
        ... 35 common frames omitted
Caused by: java.io.IOException: Broken pipe
        at java.base/sun.nio.ch.FileDispatcherImpl.write0(Native Method)
        at java.base/sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:47)
        at java.base/sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:113)
        at java.base/sun.nio.ch.IOUtil.write(IOUtil.java:79)
        at java.base/sun.nio.ch.IOUtil.write(IOUtil.java:50)
        at java.base/sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:462)
        at org.apache.tomcat.util.net.NioChannel.write(NioChannel.java:140)
        at org.apache.tomcat.util.net.NioBlockingSelector.write(NioBlockingSelector.java:118)
        at org.apache.tomcat.util.net.NioSelectorPool.write(NioSelectorPool.java:167)
        at org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper.doWrite(NioEndpoint.java:1318)
        at org.apache.tomcat.util.net.SocketWrapperBase.doWrite(SocketWrapperBase.java:718)
        at org.apache.tomcat.util.net.SocketWrapperBase.writeBlocking(SocketWrapperBase.java:538)
        at org.apache.tomcat.util.net.SocketWrapperBase.write(SocketWrapperBase.java:482)
        at org.apache.coyote.http11.Http11OutputBuffer$SocketOutputBuffer.doWrite(Http11OutputBuffer.java:631)
        at org.apache.coyote.http11.filters.ChunkedOutputFilter.doWrite(ChunkedOutputFilter.java:121)
        at org.apache.coyote.http11.Http11OutputBuffer.doWrite(Http11OutputBuffer.java:228)
        at org.apache.coyote.Response.doWrite(Response.java:605)
        at org.apache.catalina.connector.OutputBuffer.realWriteBytes(OutputBuffer.java:358)
        ... 45 common frames omitted

Anybody has an idea why this occurs?

Thanks!
Sam

UPDATES:
EDIT: Longer stacktrace
ADDITIONAL INFO: User is logged in via Keycloak

#2

There’s no more information? It seems to be missing a large part of the stack trace with the original cause.

#3

Good point! I just updated the description. I thought maybe it’s because the user has an expired token but is still not logged out?? Not sure.

#4

I just found more in the logs, which might support my last comment:

2021-05-26 09:34:45,826 [pool-14-thread-1] ERROR o.x.c.o.a.i.OIDCUserManager    - Failed to update user informations
org.xwiki.contrib.oidc.provider.internal.OIDCException: Failed to get user info:invalid_token
        at org.xwiki.contrib.oidc.auth.internal.OIDCUserManager.updateUserInfo(OIDCUserManager.java:189)
        at org.xwiki.contrib.oidc.auth.internal.OIDCUserManager.lambda$updateUserInfoAsync$0(OIDCUserManager.java:133)
        at org.xwiki.context.concurrent.ExecutionContextRunnable.run(ExecutionContextRunnable.java:71)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at java.base/java.lang.Thread.run(Thread.java:829)
2021-05-26 09:34:51,343 [http-nio-8080-exec-7 - http://wiki.example.com/xwiki/oidc/logout?id_token_hint=eyJhbGciOiJub25lIn0.eyJhdF9oYXNoIjoiaXF2djdIbHJHdVlYWTJ0U1JCcmsydyIsInN1YiI6IjkzZGY1ZmZhLWE2NTctNDZjMi04ZWJiLTlhNDAxNTI0YjkyNiIsImFkZHJlc3MiOnt9LCJlbWFpbF92ZXJpZmllZCI6dHJ1ZSwiaXNzIjoiaHR0cHM6XC9cL2F1dGguc2VkcmFkLmNvbVwvYXV0aFwvcmVhbG1zXC9zZWRyYWQuY29tIiwiZ3JvdXBzIjpbImFkbWluIl0sInR5cCI6IklEIiwicHJlZmVycmVkX3VzZXJuYW1lIjoiYWRtaW4iLCJsb2NhbGUiOiJlbiIsImdpdmVuX25hbWUiOiJBZG1pbiIsImF1ZCI6Inh3aWtpIiwiYWNyIjoiMSIsImF6cCI6Inh3aWtpIiwiYXV0aF90aW1lIjoxNjIyMDIwMzg2LCJuYW1lIjoiQWRtaW4iLCJleHAiOjE2MjIwMjA2ODcsInNlc3Npb25fc3RhdGUiOiI2NTFhN2I2Mi1lYTlmLTRhMTItYjliMS1jYTdmZmQ3OGMwOTkiLCJ4d2lraV9ncm91cHMiOlsiYWRtaW4iXSwiaWF0IjoxNjIyMDIwMzg3LCJmYW1pbHlfbmFtZSI6IiIsImp0aSI6IjYwZmM4Y2FlLWUyNzEtNDVmNS1hYWZlLWE0MzE3ZmYzYjFhMCIsImVtYWlsIjoic2FtYW4uc3JAZ21haWwuY29tIn0.] INFO  .u.i.DefaultURLSecurityManager - Domain of URL [https://auth.example.com/auth/realms/example.com/protocol/openid-connect/auth?scope=openid+profile+email+address&claims=%7B%7D&response_type=code&redirect_uri=https%3A%2F%2Fwiki.example.com%2Foidc%2Fauthenticator%2Fcallback&state=tPyuNAX2-CjuZ0LuEHlfnrlDm6cDbuN6pf2f3d0NV5k&client_id=xwiki] does not belong to the list of trusted domains but it's considered as trusted since the check has been bypassed.

Seems like the user is not logged logged out, continues navigating, the tokens is expired and causes a crash(?)

#5

See https://jira.xwiki.org/browse/XWIKI-17926 . The browser simply aborted a request for a resource (e.g. when you navigate away from a page before it was fully loaded). I agree that the resource handler shouldn’t log this.

1 Like
#6

Any chance to see this addressed in the near future? It is polluting the logs quite a bit.