improve performance of ContentCachingRequestWrapper [SPR-15762]

[spring-projects-issues]

Zilong Song opened SPR-15762 and commented

The ContentCachingInputStream class has only implemented the int read() method defined in the InputStream class, and inherit all other methods from the super class. Among them, one is the int read(byte[], int, int) method which is often used for reading a batch of bytes.

The default implementation defined in the InputStream only do a repeated call of the int read() method. However, many subclasses of the InputStream provide some more efficient implementations for the int read(byte[], int, int) method, instead of using the default implementation (it is encouraged by the JDK). The following is part of the java doc for the int read(byte[], int, int) method.

The read(b, off, len) method for class InputStream simply calls the method read() repeatedly. If the first such call results in an IOException, that exception is returned from the call to the int read(b, off, len) method. If any subsequent call to read() results in a IOException, the exception is caught and treated as if it were end of file; the bytes read up to that point are stored into b and the number of bytes read before the exception occurred is returned. The default implementation of this method blocks until the requested amount of input data len has been read, end of file is detected, or an exception is thrown. Subclasses are encouraged to provide a more efficient implementation of this method.

Performance of reading a few bytes from an InputStream with a loop call of the int read() method and a call with the int read(byte[], int, int) method differs a lot. The latter method is much faster than the former method. My code and result for this comparison are listed bellow.

byte[] bytes = new byte[100_000]; // 100k
// test reading an input stream with loop method
ByteArrayInputStream in1 = new ByteArrayInputStream(bytes);
long start = System.nanoTime();
for (int i = 0; i < 100_000; i++) {
    in1.read();
}
System.out.println("loop calling cost: " + (System.nanoTime() - start) + "ns");

// test reading the same input stream with batch method
ByteArrayInputStream in2 = new ByteArrayInputStream(bytes);
byte[] buffer = new byte[1000];
int c = 0;
start = System.nanoTime();
while (c < 100_000) {
    c += in2.read(buffer);
}
System.out.println("batch calling cost: " + (System.nanoTime() - start) + "ns");

Finally, I got the following result on my machine.

loop calling cost: 9158452ns
batch calling cost: 85389ns

---

Affects: 4.3.9

Referenced from: pull request #1474, and commits d00f6f0, 4d0800f

[spring-projects-issues]

Brian Clozel commented

Hello Zilong Song

I've tried to reproduce this behavior in a JMH benchmark, as the approach to benchmarking you've chosen does not take into account many aspects of the JVM's behavior.

Feel free to revisit this benchmark and point at issues, but it seems that the JVM is already optimizing those calls in very efficient ways, and that adding your changes do not improve performance. I'm actually seeing a 8% drop with your changes:

Benchmark                                Mode  Cnt          Score         Error  Units
RequestWrapperBenchmark.baseline        thrpt    5  167607477,796 ± 9809112,218  ops/s
RequestWrapperBenchmark.currentWrapper  thrpt    5       5003,855 ±      99,431  ops/s
RequestWrapperBenchmark.newWrapper      thrpt    5       4644,817 ±     158,167  ops/s

Could you take a look at that benchmark?

[spring-projects-issues]

Zilong Song commented

Hi @Brian Clozel

I'm very sorry for the late reply. I have checked the JMH benchmark you provided. But I'm afraid that there is mistake in it. (also my mistake)

In the read method of OptimizedCachingRequestWrapper.ContentCachingInputStream

public int read(final byte[] b, final int off, final int len) throws IOException {
    // in the benchmark code, it reads data with the super.read(...) method, 
    //
    //           int count = super.read(b, off, len); 
    // 
    // but the super.read(...) method works with a loop of reading 
    // the single byte read method
    // 
    //           int read()
    // 
    // that's to say, optimization is not applied. 
    // 
    // my optimization should be applied by calling the batch read method
    // directly with the wrapped input stream "is".
    int count = is.read(b, off, len);


    if (!this.overflow && count > 0) {
        if (contentCacheLimit != null && cachedContent.size() == contentCacheLimit) {
            this.overflow = true;
            handleContentOverflow(contentCacheLimit);
        } else {
            int sizeToCache = contentCacheLimit == null || count + cachedContent.size() < contentCacheLimit
                ? count
                : contentCacheLimit - cachedContent.size();
            cachedContent.write(b, off, sizeToCache);
            if (sizeToCache < count) {
                this.overflow = true;
                handleContentOverflow(contentCacheLimit);
            }
        }
    }
    return count;
}

After I made such change on both the read(byte[] b, int off, int len) method and the readLine(byte[] b, int off, int len), and run the benchmark again, I got the following result

Benchmark                                Mode  Cnt          Score         Error  Units
RequestWrapperBenchmark.baseline        thrpt    5  163572708.628 ± 8332293.824  ops/s
RequestWrapperBenchmark.currentWrapper  thrpt    5       3800.549 ±     134.436  ops/s
RequestWrapperBenchmark.newWrapper      thrpt    5      12154.424 ±     752.049  ops/s

The result shows that my change will bring 219% improvement on performance.

[spring-projects-issues]

Brian Clozel commented

Hi Zilong Song,

Thanks for following up with this. With that change (and a few more changes to the proposed implementation), I'm seeing a consistent +80-100% improvement, depending on the JDK.

 

I'm going to merge an amend your PR for the next 5.1 release. Thanks!