clarin-dspace icon indicating copy to clipboard operation
clarin-dspace copied to clipboard

Sometimes the download fails but returns 200

Open kosarko opened this issue 5 months ago • 0 comments

10.10.xx.yy - - [23/Jul/2025:10:51:49 +0200] "GET /repository/server/api/core/items/55b06337-e49c-4631-9328-b1a38322b1d4/allzip?handleId=11234/1-5901&authentication-token=SOME_TOKEN HTTP/1.1" 200 549954444
10.10.xx.yy - - [23/Jul/2025:10:51:50 +0200] "GET /repository/server/api/core/metadatabitstreams/search/byHandle?handle=11234/1-5901&fileGrpType=ORIGINAL HTTP/1.1" 200 2337
10.10.xx.yy - - [23/Jul/2025:10:53:47 +0200] "GET /repository/server/api/core/metadatabitstreams/search/byHandle?handle=11234/1-5901&fileGrpType=ORIGINAL HTTP/1.1" 200 2337
10.10.xx.yy - - [23/Jul/2025:10:54:36 +0200] "GET /repository/server/api/core/items/55b06337-e49c-4631-9328-b1a38322b1d4/allzip?handleId=11234/1-5901&authentication-token=SOME_TOKEN HTTP/1.1" 200 776835356
10.10.xx.yy - - [23/Jul/2025:10:55:12 +0200] "GET /repository/server/api/core/items/55b06337-e49c-4631-9328-b1a38322b1d4/allzip?handleId=11234/1-5901 HTTP/1.1" 200 776835356

first ~524MB with 200 and then 2x ~740MB also with 200

and dspace.log

2025-07-23 10:51:49,774 http-nio-8080-exec-9890 ERROR unknown 392b2f1d-8507-4569-8f0e-b5ab3ee2aeec org.dspace.app.rest.exception.DSpaceApiExceptionControllerAdvice @ An internal read or write operation failed (status:500)
2025-07-23 10:51:49,776 http-nio-8080-exec-9890 ERROR unknown unknown org.springframework.boot.web.servlet.support.ErrorPageFilter @ Cannot forward to error page for request [/api/core/items/55b06337-e49c-4631-9328-b1a38322b1d4/allzip] as the response has already been committed. As a result, the response may have the wrong status code. If your application is running on WebSphere Application Server you may be able to resolve this problem by setting com.ibm.ws.webcontainer.invokeFlushAfterService to false

~Looking into the code this is some sort of IOException but the details are not logged, cf https://github.com/dataquest-dev/DSpace/blob/77fc4b057ef45e3520d85dc076134973ad78f476/dspace-server-webapp/src/main/java/org/dspace/app/rest/exception/DSpaceApiExceptionControllerAdvice.java#L323~ (the error is there, I just filtered the logs by data time).

The exception is:

org.apache.catalina.connector.ClientAbortException: java.net.SocketTimeoutException
        at org.apache.catalina.connector.OutputBuffer.realWriteBytes(OutputBuffer.java:342) ~[catalina.jar:9.0.107]
        at org.apache.catalina.connector.OutputBuffer.flushByteBuffer(OutputBuffer.java:777) ~[catalina.jar:9.0.107]
        at org.apache.catalina.connector.OutputBuffer.append(OutputBuffer.java:674) ~[catalina.jar:9.0.107]
        at org.apache.catalina.connector.OutputBuffer.writeBytes(OutputBuffer.java:377) ~[catalina.jar:9.0.107]
        at org.apache.catalina.connector.OutputBuffer.write(OutputBuffer.java:355) ~[catalina.jar:9.0.107]
        at org.apache.catalina.connector.CoyoteOutputStream.write(CoyoteOutputStream.java:102) ~[catalina.jar:9.0.107]
        at org.springframework.security.web.util.OnCommittedResponseWrapper$SaveContextServletOutputStream.write(OnCommittedResponseWrapper.java:638) ~[spring-security-web-5.7.8.jar:5.7.8]
        at org.apache.commons.compress.archivers.zip.StreamCompressor$OutputStreamCompressor.writeOut(StreamCompressor.java:306) ~[commons-compress-1.21.jar:1.21]
        at org.apache.commons.compress.archivers.zip.StreamCompressor.writeCounted(StreamCompressor.java:273) ~[commons-compress-1.21.jar:1.21]
        at org.apache.commons.compress.archivers.zip.StreamCompressor.deflate(StreamCompressor.java:264) ~[commons-compress-1.21.jar:1.21]
        at org.apache.commons.compress.archivers.zip.StreamCompressor.deflateUntilInputIsNeeded(StreamCompressor.java:257) ~[commons-compress-1.21.jar:1.21]
        at org.apache.commons.compress.archivers.zip.StreamCompressor.writeDeflated(StreamCompressor.java:238) ~[commons-compress-1.21.jar:1.21]
        at org.apache.commons.compress.archivers.zip.StreamCompressor.write(StreamCompressor.java:205) ~[commons-compress-1.21.jar:1.21]
        at org.apache.commons.compress.archivers.zip.ZipArchiveOutputStream.write(ZipArchiveOutputStream.java:1050) ~[commons-compress-1.21.jar:1.21]
        at org.apache.commons.compress.utils.IOUtils.copy(IOUtils.java:96) ~[commons-compress-1.21.jar:1.21]
        at org.apache.commons.compress.utils.IOUtils.copy(IOUtils.java:70) ~[commons-compress-1.21.jar:1.21]
        at org.dspace.app.rest.MetadataBitstreamController.downloadFileZip(MetadataBitstreamController.java:134) ~[classes/:7.6.1]
        at org.dspace.app.rest.MetadataBitstreamController$$FastClassBySpringCGLIB$$df158cf.invoke(<generated>) ~[classes/:7.6.1]
        at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218) ~[spring-core-5.3.27.jar:5.3.27]
        at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:793) ~[spring-aop-5.3.27.jar:5.3.27]
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) ~[spring-aop-5.3.27.jar:5.3.27]
        at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:763) ~[spring-aop-5.3.27.jar:5.3.27]
        at org.springframework.security.access.intercept.aopalliance.MethodSecurityInterceptor.invoke(MethodSecurityInterceptor.java:61) ~[spring-security-core-5.7.8.jar:5.7.8]
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.27.jar:5.3.27]
        at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:763) ~[spring-aop-5.3.27.jar:5.3.27]
        at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:708) ~[spring-aop-5.3.27.jar:5.3.27]
        at org.dspace.app.rest.MetadataBitstreamController$$EnhancerBySpringCGLIB$$433cfe64.downloadFileZip(<generated>) ~[classes/:7.6.1]
        at jdk.internal.reflect.GeneratedMethodAccessor773.invoke(Unknown Source) ~[?:?]
        at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
        at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?]

kosarko avatar Jul 31 '25 09:07 kosarko