RFR: 8279536: jdk/nio/zipfs/ZipFSOutputStreamTest.java timed out

[Lance Andersen]

On Mon, 10 Jan 2022 15:06:11 GMT, Jaikiran Pai <jpai at openjdk.org> wrote:

> Can I please get a review for this test only change which helps drastically improve the time taken by the `jdk/nio/zipfs/ZipFSOutputStreamTest.java` testcase?
> 
> This `jdk/nio/zipfs/ZipFSOutputStreamTest.java` testcase was initially introduced in https://github.com/openjdk/jdk/pull/4607 to reproduce and verify the bug fix for https://bugs.openjdk.java.net/browse/JDK-8190753. The test does the following:
> - Using ZipFS creates a zip file with entries of varying size. Each of these entries use random byte content.
> - One of the entry size is `Integer.MAX_SIZE + 1` byte to trigger/verify the issue noted in JDK-8190753.
> - Finally the test verifies the contents of the generated entries in the zip file by matching it against the previously generated random content. The slowness resides in the way this testing/verification is done in this test case. Currently there's a loop which compares one byte at a time for each of these entries. This is unncessary and this adds up especially for the `Integer.MAX_SIZE + 1` sized entry.
> 
> The change in this PR, improves this verification logic by using a fixed data to write out the entries and then read/verify that (fixed) content. This allows for better/quicker comparison of the entries.
> 
> Without this change, the testcase used to consistently take around 3 minutes 30 seconds to 3 minutes 50 seconds on my local setup. With this change the test now consistently completes (successfully) in just around 40 to 42 seconds (i.e. within a minute).
> 
> The original configuration of this test case uses a timeout of 300 seconds (5 minutes). That timeout was used based on the numbers I was seeing for this test completion. With this change, I don't expect it to require that much amount of time to complete (even on slow setups). However, I decided not to change that value just yet in this PR (since it anyway is a "maximum" time).
> 
> Additionally this PR adds some diagnostic logs for any future use if/when this test times out.

I think you are good to go.

I ran your change 1800 times across the various Mach5 platforms that we have without failure.   37 of the runs were over a minute, with the max run of 3 minutes, 27 seconds.  Only 2 of the runs were over 3 minutes.

In case you are interested, here is the output from the slowest run:

Wrote entry f1 of bytes 2147483648 in 30330 milli seconds
Wrote entry f2 of bytes 26214400 in 889 milli seconds
Wrote entry d1/d2/f4 of bytes 0 in 0 milli seconds
Wrote entry d1/f3 of bytes 1234 in 0 milli seconds
Read entry f1 of bytes 2147483648 in 28988 milli seconds
Read entry f2 of bytes 26214400 in 62 milli seconds
Read entry d1/d2/f4 of bytes 0 in 0 milli seconds
Read entry d1/f3 of bytes 1234 in 0 milli seconds
test ZipFSOutputStreamTest.testOutputStream(java.util.ImmutableCollections$MapN at 15951e35): success
config ZipFSOutputStreamTest.tearDown(): success
config ZipFSOutputStreamTest.setUp(): success
Wrote entry f1 of bytes 2147483648 in 11572 milli seconds
Wrote entry f2 of bytes 26214400 in 145 milli seconds
Wrote entry d1/d2/f4 of bytes 0 in 1 milli seconds
Wrote entry d1/f3 of bytes 1234 in 0 milli seconds
Read entry f1 of bytes 2147483648 in 4783 milli seconds
Read entry f2 of bytes 26214400 in 64 milli seconds
Read entry d1/d2/f4 of bytes 0 in 0 milli seconds
Read entry d1/f3 of bytes 1234 in 0 milli seconds
test ZipFSOutputStreamTest.testOutputStream(java.util.ImmutableCollections$MapN at 2092a6c3): success

-------------

Marked as reviewed by lancea (Reviewer).

PR: https://git.openjdk.java.net/jdk/pull/7010