Jetty.project: Large files get truncated

[bu3]

Hi,

I have an application serving large files from a directory using an Embedded Jetty.
As long as the file is smaller than 4Gb, it can be downloaded with no issue but if the file is bigger than that it gets truncated.

The file directory is configured in a ResourceColletion as BaseResource (https://github.com/bu3/jetty-big-files-provider/blob/76e1fd67723596ebd662d51e334183c25ad89770/src/main/java/com/acme/Main.java#L63).

I have created a repo to show you the problem:
https://github.com/bu3/jetty-big-files-provider

[joakime]

The ability to serve over 4Gb is dependent on your OS, your filesystem type, and your JVM.
Can you tell us what you are using in each case?

[bu3]

I'm running the application on Linux and JVM 1.8.
I guess it is related to integer max value (2^31 = 2147483648) because we spot this pattern:

4464444523 (4.1G) got truncated to 169477227 (1.5M) (4464444523 % 2147483648 = 169477227)
10485760000 (9.8G) got truncated to 1895825408 (1.8G) (10485760000 % 2147483648 = 1895825408)

[joakime]

You are using a 64-bit JVM I hope.
What specific version of Java are you using? Be exact.
What kind of File System are you using? hopefully its a local filesystem and not a virtual or networked one.
What specific Linux kernel are you using? hopefully an up to date Kernel 4.x or 5.x series.
What specific Linux distribution are you using? Be exact.

[joakime]

Huge file download works.
Using a simple file serving setup like this ...

package org.eclipse.jetty.demo;

import java.io.IOException;
import java.nio.file.Files;
import java.nio.file.Path;
import java.nio.file.Paths;

import org.eclipse.jetty.server.Server;
import org.eclipse.jetty.server.handler.DefaultHandler;
import org.eclipse.jetty.server.handler.HandlerList;
import org.eclipse.jetty.servlet.DefaultServlet;
import org.eclipse.jetty.servlet.ServletContextHandler;
import org.eclipse.jetty.servlet.ServletHolder;
import org.eclipse.jetty.util.resource.PathResource;
import org.eclipse.jetty.util.resource.Resource;

public class Main
{
    public static void main(String[] args) throws Exception
    {
        Main main = new Main();
        Server server = main.createServer();
        server.start();
        server.join();
    }

    public Server server;
    public Path baseResourcePath;

    public Server createServer() throws IOException
    {
        server = new Server(8888);

        ServletContextHandler context = new ServletContextHandler();
        context.setContextPath("/");
        context.setBaseResource(getBaseResource());

        ServletHolder defHolder = new ServletHolder("default", DefaultServlet.class);
        context.addServlet(defHolder, "/");

        HandlerList handlers = new HandlerList();
        handlers.addHandler(context);
        handlers.addHandler(new DefaultHandler()); // to report (in html) any issues serving request in prior contexts

        server.setHandler(handlers);
        return server;
    }

    /**
     * Get the Resource representing the Base Resource for the Root Context
     */
    private Resource getBaseResource() throws IOException
    {
        Path tempDir = Paths.get(System.getProperty("java.io.tmpdir"));
        Path workDir = tempDir.resolve("jetty-huge-work");

        if (!Files.exists(workDir))
        {
            Files.createDirectories(workDir);
        }

        baseResourcePath = workDir;
        System.err.println("Using base resource of : " + workDir);

        return new PathResource(workDir);
    }
}

Using Jetty 9.4.19.v20190610.

Running on Oracle Java 1.8 update 192 (64-bit)

$ java -version
java version "1.8.0_192"
Java(TM) SE Runtime Environment (build 1.8.0_192-b12)
Java HotSpot(TM) 64-Bit Server VM (build 25.192-b12, mixed mode)

On Fedora Core 28.

$ uname -a
Linux ceres 5.0.16-100.fc28.x86_64 #1 SMP Tue May 14 18:22:28 UTC 2019 x86_64 x86_64 x86_64 GNU/Linux

With 3 files ....

$ ls -lah /tmp/jetty-huge-work
total 14G
drwxr-xr-x  2 joakim joakim 4.0K Jul 16 10:37 ./
drwxrwxrwt 19 root   root    12K Jul 16 10:37 ../
-rw-r--r--  1 joakim joakim 9.8G Jul 16 10:34 file10G.txt
-rw-r--r--  1 joakim joakim   54 Jul 16 10:37 file10G.txt.sha1
-rw-r--r--  1 joakim joakim 4.0G Jul 16 10:35 file4G.txt
-rw-r--r--  1 joakim joakim   53 Jul 16 10:37 file4G.txt.sha1
-rw-r--r--  1 joakim joakim 1.0M Jul 16 10:31 test.txt
-rw-r--r--  1 joakim joakim   51 Jul 16 10:37 test.txt.sha1
$ cat /tmp/jetty-huge-work/*.sha1
32d610773b9b7c013bbfbc7097b2da30a051914c  file10G.txt
64a476e4cc099da3e9a66bafe02f8b0d2da1b2c3  file4G.txt
46ba5f3969dd6bb7cfd414286e72449ab99cba6d  test.txt

Using curl to download the resources ...

[~]$ cd tmp
[tmp]$ mkdir huge-dl
[tmp]$ cd huge-dl/
[huge-dl]$ ls -la
total 8
drwxr-xr-x 2 joakim joakim 4096 Jul 16 10:38 ./
drwxr-xr-x 7 joakim joakim 4096 Jul 16 10:38 ../
[huge-dl]$ curl -O http://localhost:8888/test.txt
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100 1024k  100 1024k    0     0  76.9M      0 --:--:-- --:--:-- --:--:-- 76.9M
[huge-dl]$ curl -O http://localhost:8888/file4G.txt
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100 4000M  100 4000M    0     0  1561M      0  0:00:02  0:00:02 --:--:-- 1560M
[huge-dl]$ curl -O http://localhost:8888/file10G.txt
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100  9.7G  100  9.7G    0     0  1518M      0  0:00:06  0:00:06 --:--:-- 1485M
[huge-dl]$ ls -lah
total 14G
drwxr-xr-x 2 joakim joakim 4.0K Jul 16 10:38 ./
drwxr-xr-x 7 joakim joakim 4.0K Jul 16 10:38 ../
-rw-r--r-- 1 joakim joakim 9.8G Jul 16 10:38 file10G.txt
-rw-r--r-- 1 joakim joakim 4.0G Jul 16 10:38 file4G.txt
-rw-r--r-- 1 joakim joakim 1.0M Jul 16 10:38 test.txt
[huge-dl]$ sha1sum *
32d610773b9b7c013bbfbc7097b2da30a051914c  file10G.txt
64a476e4cc099da3e9a66bafe02f8b0d2da1b2c3  file4G.txt
46ba5f3969dd6bb7cfd414286e72449ab99cba6d  test.txt

[joakime]

Demo project of above can be found at https://github.com/jetty-project/embedded-jetty-serving-huge-files

[bu3]

In production, the application runs on CentOS 7 on openjdk1.8.0_172_x64 and it load files from the local file system.
I can reproduce the same problem on my Mac with macOs 10.14.5 on openjdk1.8.0_172_x64.

Did you take a look at the code in the example project? Do you see something wrong in that?

[bu3]

I have updated my project using the DefaultServlet as the example you gave me but I see the same problem.
https://github.com/bu3/jetty-big-files-provider/blob/71cf25c175216216c3966e938cc186c2d000236a/src/main/java/com/acme/Main.java#L68

[bu3]

The different behaviour seems to be related to ContexHandler implementation. I'm using the WebAppContext because I need to load a web.xml file while you're a using the parent class ServletContextHandler.
Changing my code to use ServletContextHandler instead, fixes the problem and I can download files properly.

It seems to be a problem with WebAppContext class and I cannot avoid to use it.

[joakime]

Your example project / code works with WebAppContext as well, no modifications, no changes, it just works.

The example project / code works even better when you use fully qualified paths (like I indicated in your prior commit), not relative paths.
That means you use a known Resource implementation, and are not subject to the whims of classpath ordering and classloader based lookups that relative paths introduce.

It works better (better thread utilization) when you eliminate the ResourceCollection and just use a single Resource (like I also indicated in that prior commit).
There's very little reason to have a ResourceCollection as a webapp base resource.
Do you want to serve content from multiple base directories?
See: https://github.com/jetty-project/embedded-jetty-cookbook/blob/master/src/main/java/org/eclipse/jetty/cookbook/DefaultServletMultipleBases.java

Why must you use WebAppContext?
Everything you can do with WebAppContext you can do with ServletContextHandler as well (with the only exception being bytecode/annotation scanning).
In fact, WebAppContext just extends ServletContextHandler.
If you are using embedded-jetty, and you only have 1 webapp, there's really no reason you can't use ServletContextHandler instead.

[bu3]

Sorry @joakime there is something I didn't get. Does my code work for you?

My example project does not work for me. I managed to have it working as expected only changing the ContextHandler to ServletContextHandler.

The size of file10G.txt is 1808M

fmangione-ltm1:heapdump-provider fmangione$ curl -O http://localhost:8080/file10G.txt
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100 1808M  100 1808M    0     0   325M      0  0:00:05  0:00:05 --:--:--  466M

While in the file directory is

fmangione-ltm1:heapdump-provider fmangione$ ls -alh shared/
total 28678144
drwxr-xr-x   5 fmangione  staff   160B 16 Jul 12:06 .
drwxr-xr-x  15 fmangione  staff   480B 18 Jul 16:11 ..
-rw-r--r--   1 fmangione  staff   9.8G 18 Jul 15:58 file10G.txt
-rw-r--r--   1 fmangione  staff   3.9G 18 Jul 16:00 file4G.txt
-rw-r--r--   1 fmangione  staff   1.0M 18 Jul 15:54 test.txt
fmangione-ltm1:heapdump-provider fmangione$

[joakime]

Been using your demo without issue for a few hours now.

I did get 1 Exception, which I'm digging into, but even that Exception didn't prevent the files from downloading properly.

2019-07-18 11:02:08.317:WARN:oejs.CachedContentFactory:qtp1144748369-45: Could not load CachedContent@55a4cf39{r=file:///tmp/jetty-huge-work/file4G.txt,e=true,lm=Last-Modified: Tue, 16 Jul 2019 15:35:47 GMT,ct=Content-Type: text/plain,c=0}
2019-07-18 11:02:08.317:WARN:oejs.CachedContentFactory:qtp1144748369-45: 
java.lang.IllegalArgumentException: invalid resource: file:///tmp/jetty-huge-work/file4G.txt len=-100663296
    at org.eclipse.jetty.util.BufferUtil.toBuffer(BufferUtil.java:970)
    at org.eclipse.jetty.server.CachedContentFactory.getIndirectBuffer(CachedContentFactory.java:338)
    at org.eclipse.jetty.server.CachedContentFactory$CachedHttpContent.getIndirectBuffer(CachedContentFactory.java:558)
    at org.eclipse.jetty.server.HttpOutput.sendContent(HttpOutput.java:988)
    at org.eclipse.jetty.server.HttpOutput.sendContent(HttpOutput.java:869)
    at org.eclipse.jetty.server.ResourceService.sendData(ResourceService.java:731)
    at org.eclipse.jetty.server.ResourceService.doGet(ResourceService.java:294)
    at org.eclipse.jetty.servlet.DefaultServlet.doGet(DefaultServlet.java:457)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:687)
        ...

[joakime]

Opened issue #3888 to fix for the Exception seen.

[bu3]

Hi @joakime,

I managed to have my example project running on 4 different machines with the same outcome. The 10G file gets truncated to 1.8G on any of those.

I've updated my example project and I've added a test and I've also made a pipeline in CodeShip to double-check. Same exact outcome.
Please take a look at the following output from that pipeline.

Tests run: 1, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 12.709 sec <<< FAILURE!
shouldDownloadTenGigsFile(com.acme.MainTest)  Time elapsed: 9.658 sec  <<< FAILURE!
java.lang.AssertionError: 
Expected: is <10485760000L>
but: was <1895825408L>
    at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
    at org.junit.Assert.assertThat(Assert.java:956)
    at org.junit.Assert.assertThat(Assert.java:923)
    at com.acme.MainTest.shouldDownloadTenGigsFile(MainTest.java:59)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
    at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
    at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
    at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
    at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
    at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
    at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
    at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
    at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
    at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
    at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
    at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
    at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
    at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:252)
    at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:141)
    at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:112)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.apache.maven.surefire.util.ReflectionUtils.invokeMethodWithArray(ReflectionUtils.java:189)
    at org.apache.maven.surefire.booter.ProviderFactory$ProviderProxy.invoke(ProviderFactory.java:165)
    at org.apache.maven.surefire.booter.ProviderFactory.invokeProvider(ProviderFactory.java:85)
    at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:115)
    at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:75)

The WebAppContext does not work as the ServletContextHandler to me even though it extends it.

Would you help me understand why it is working on your machine?

[bu3]

I have also created the branch servlet_context_handler where I used ServletContextHandler instead of WebAppContext. On that branch, the test passes with no issue.

[joakime]

In Issue #3888 we implemented a testcase (for PR #3889) on commit aef58168d06f3e1edd95e2a007be9df5f1f4ccb2 which mimics your WebAppContext scenario.

There's a few interesting discoveries during the analysis in the Issue #3888 comments. Would encourage you to read them.
The reason curl doesn't fail in the 4G scenario is that curl doesn't seem to care about the bad Content-Length: 0 header and will download the entire file up to the connection close event.
The reason 10G always works is because it's done with Transfer-Encoding: chunked, which has no Content-Length to confuse things.
The fixes in PR #3889 to address the warning stacktraces and bad Content-Length will likely help you as well.

[bu3]

I read the changes made for issue #3888 and I hope it works for my case as well.

Sorry maybe it's me but I don't understand why you keep saying that the 10G file download works even if I showed you that the downloaded file is always of the wrong size of 1.8G. No matter if using CURL or not.

[joakime]

There are a few things discovered while investigating this.

First, the 1GB testcase is fine, in all cases, all versions of Jetty.

The 4GB testcase on Jetty 9.4.19 has response headers of ...

  HTTP/1.1 200 OK
  Date: Thu, 18 Jul 2019 16:56:05 GMT
  Last-Modified: Thu, 18 Jul 2019 16:55:59 GMT
  Accept-Ranges: bytes
  Content-Length: 0
  Server: Jetty(9.4.z-SNAPSHOT)

That Content-Length: 0 is bad, and has been fixed in PR #3889
The reason curl had no problem with this, is that curl doesn't care about the Content-Length and operates on the connection level, downloading everything until the connection is closed.

Now the 10GB testcase on 9.4.19 returns the following response headers ...

  HTTP/1.1 200 OK
  Date: Thu, 18 Jul 2019 16:56:05 GMT
  Last-Modified: Thu, 18 Jul 2019 16:56:04 GMT
  Accept-Ranges: bytes
  Transfer-Encoding: chunked
  Server: Jetty(9.4.z-SNAPSHOT)

This is valid, but not what is expected by DefaultServlet.
Curl happily downloads this file until the connection is closed, handling the chunked transfer encoding properly.
The Transfer-Encoding: chunked shouldn't have been selected, as this is a static file, the standard Content-Length and no Transfer-Encoding should have been used instead.
This has also been fixed in PR #3889

In the process of investigating Issue #3888 it was also discovered that we are not following the Servlet spec properly with regards to ServletRequest.getContentLength() (it should return -1 for values exceeding Integer.MAX_VALUE. The getContentLengthLong() should be used instead in this case) This is also fixed in PR #3889.

As for testing these changes with your scenario, you have a few options ...

1. You can choose to build branch jetty-9.4.x-3888-huge-resources and test with it now.
2. Wait till PR #3889 is merged to jetty-9.4.x and use a SNAPSHOT build. (available in standard snapshot location on oss.sonatype.org)
3. Wait till Jetty 9.4.20 is staged to test your scenario again.
4. Wait till Jetty 9.4.20 is released to test your scenario again.

[joakime]

Work completed in PR #3889, merged to jetty-9.4.x branch, and will be available in jetty 9.4.20 release.