Re: RFR: 8247532, 8248135: Records deserialization is slow + Build microbenchmarks with --enable-preview
On 6/23/20 2:47 PM, Chris Hegarty wrote: On 23 Jun 2020, at 10:46, Chris Hegarty wrote: On 23 Jun 2020, at 10:17, Peter Levart wrote: ... http://cr.openjdk.java.net/~plevart/jdk-dev/RecordsDeserialization/webrev.08/ Good stuff. Reviewed. I am going to take this latest change and run it through our internal build and test system. Will post the results here soon. All clear - builds and tests with this change are green. -Chris. Ok, I'm going to push this to jdk15. Thanks Johannes, Chris, Remi, Paul, Claes and Magnus, for the help and reviews. Regards, Peter
Re: RFR: 8247532, 8248135: Records deserialization is slow + Build microbenchmarks with --enable-preview
> On 23 Jun 2020, at 10:46, Chris Hegarty wrote: > > > >> On 23 Jun 2020, at 10:17, Peter Levart wrote: >> >> ... >> http://cr.openjdk.java.net/~plevart/jdk-dev/RecordsDeserialization/webrev.08/ > > Good stuff. Reviewed. > > I am going to take this latest change and run it through our internal build > and test system. Will post the results here soon. All clear - builds and tests with this change are green. -Chris.
Re: RFR: 8247532, 8248135: Records deserialization is slow + Build microbenchmarks with --enable-preview
> On 23 Jun 2020, at 10:17, Peter Levart wrote: > > ... > http://cr.openjdk.java.net/~plevart/jdk-dev/RecordsDeserialization/webrev.08/ Good stuff. Reviewed. I am going to take this latest change and run it through our internal build and test system. Will post the results here soon. -Chris.
Re: RFR: 8247532, 8248135: Records deserialization is slow + Build microbenchmarks with --enable-preview
Looks good to me! /Claes On 2020-06-23 11:17, Peter Levart wrote: Including build-dev since this patch is adding new issue 8248135: https://bugs.openjdk.java.net/browse/JDK-8248135 So here's new webrev with a patch for building benchmarks with --enable-preview included: http://cr.openjdk.java.net/~plevart/jdk-dev/RecordsDeserialization/webrev.08/ Regards, Peter On 6/23/20 10:23 AM, Claes Redestad wrote: On 2020-06-23 10:06, Claes Redestad wrote: Hi, On 2020-06-23 09:49, Peter Levart wrote: Hi Chris, Claes, Ok then, here's with benchmark included: http://cr.openjdk.java.net/~plevart/jdk-dev/RecordsDeserialization/webrev.07/ I haven't been able to run the benchmark with "make test" though. I have tried various ways to pass javac options to build like: make test TEST='micro:org.openjdk.bench.java.io.RecordDeserialization' TEST_OPTS="VM_OPTIONS=--enable-preview --release=16" ...but javac doesn't seem to get them. Is there some secret option to achieve that? Hmm, we might as well have the microbenchmarks build with --enable-preview on by default. Try this: Fixed: diff -r f2e1cd498381 make/test/BuildMicrobenchmark.gmk --- a/make/test/BuildMicrobenchmark.gmk Tue Jun 23 10:08:35 2020 +0200 +++ b/make/test/BuildMicrobenchmark.gmk Tue Jun 23 10:33:17 2020 +0200 @@ -90,10 +90,11 @@ TARGET_RELEASE := $(TARGET_RELEASE_NEWJDK_UPGRADED), \ SMALL_JAVA := false, \ CLASSPATH := $(MICROBENCHMARK_CLASSPATH), \ - DISABLED_WARNINGS := processing rawtypes cast serial, \ + DISABLED_WARNINGS := processing rawtypes cast serial preview, \ SRC := $(MICROBENCHMARK_SRC), \ BIN := $(MICROBENCHMARK_CLASSES), \ JAVA_FLAGS := --add-modules jdk.unsupported --limit-modules java.management, \ + JAVAC_FLAGS := --enable-preview, \ )) $(BUILD_JDK_MICROBENCHMARK): $(JMH_COMPILE_JARS) I verified this works with your micro, and doesn't seem to cause any issues elsewhere: make test TEST=micro:RecordDeserialization I can shepherd this as a separate fix for documentation purposes, but feel free to include it in your patch and ping build-dev@.. /Claes diff -r 52741f85bf23 make/test/BuildMicrobenchmark.gmk --- a/make/test/BuildMicrobenchmark.gmk Tue Jun 23 09:54:42 2020 +0200 +++ b/make/test/BuildMicrobenchmark.gmk Tue Jun 23 09:59:29 2020 +0200 @@ -93,7 +93,7 @@ DISABLED_WARNINGS := processing rawtypes cast serial, \ SRC := $(MICROBENCHMARK_SRC), \ BIN := $(MICROBENCHMARK_CLASSES), \ - JAVA_FLAGS := --add-modules jdk.unsupported --limit-modules java.management, \ + JAVA_FLAGS := --enable-preview --add-modules jdk.unsupported --limit-modules java.management, \ )) $(BUILD_JDK_MICROBENCHMARK): $(JMH_COMPILE_JARS) Otherwise, I simulated what would happen when there are more then 10 ObjectStreamClass layouts for same class rapidly interchanging, so that they push each other out of the cache, by temporarily setting cache's MAX_SIZE = 0. Note that this is worst case scenario: Benchmark (length) Mode Cnt Score Error Units RecordDeserializationBench.deserializeClasses 10 avgt 10 9.393 ± 0.287 us/op RecordDeserializationBench.deserializeClasses 100 avgt 10 35.642 ± 0.977 us/op RecordDeserializationBench.deserializeClasses 1000 avgt 10 293.769 ± 7.321 us/op RecordDeserializationBench.deserializeRecords 10 avgt 10 15.335 ± 0.496 us/op RecordDeserializationBench.deserializeRecords 100 avgt 10 211.427 ± 11.908 us/op RecordDeserializationBench.deserializeRecords 1000 avgt 10 990.398 ± 26.681 us/op This is using JMH option '-gc true' to force GC after each iteration of benchmark. Without it, I get a big (~4s) full-GC pause just in the middle of a run with length=100: Iteration 1: 528.577 us/op Iteration 2: 580.404 us/op Iteration 3: 4438.228 us/op Iteration 4: 644.532 us/op Iteration 5: 698.493 us/op Iteration 6: 800.738 us/op Iteration 7: 929.791 us/op Iteration 8: 870.946 us/op Iteration 9: 863.416 us/op Iteration 10: 916.508 us/op ...so results are a bit off because of that: Benchmark (length) Mode Cnt Score Error Units RecordDeserializationBench.deserializeClasses 10 avgt 10 8.263 ± 0.043 us/op RecordDeserializationBench.deserializeClasses 100 avgt 10 33.406 ± 0.160 us/op RecordDeserializationBench.deserializeClasses 1000 avgt 10 287.595 ± 0.960 us/op RecordDeserializationBench.deserializeRecords 10 avgt 10 15.270 ± 0.080 us/op RecordDeserializationBench.deserializeRecords 100 avgt 10 1127.163 ± 1771.892 us/op RecordDeserializationBench.deserializeRecords 1000 avgt 10 2003.235 ± 227.159 us/op Yes, there is quite a bit of GCing going on when cache is thrashing. Note that I haven't tuned GC in any way and I'm running this on a machine with 64GiB of RAM
Re: RFR: 8247532, 8248135: Records deserialization is slow + Build microbenchmarks with --enable-preview
Thanks, Magnus. Peter On 6/23/20 11:27 AM, Magnus Ihse Bursie wrote: On 2020-06-23 11:17, Peter Levart wrote: Including build-dev since this patch is adding new issue 8248135: https://bugs.openjdk.java.net/browse/JDK-8248135 So here's new webrev with a patch for building benchmarks with --enable-preview included: http://cr.openjdk.java.net/~plevart/jdk-dev/RecordsDeserialization/webrev.08/ Build changes look good. /Magnus Regards, Peter On 6/23/20 10:23 AM, Claes Redestad wrote: On 2020-06-23 10:06, Claes Redestad wrote: Hi, On 2020-06-23 09:49, Peter Levart wrote: Hi Chris, Claes, Ok then, here's with benchmark included: http://cr.openjdk.java.net/~plevart/jdk-dev/RecordsDeserialization/webrev.07/ I haven't been able to run the benchmark with "make test" though. I have tried various ways to pass javac options to build like: make test TEST='micro:org.openjdk.bench.java.io.RecordDeserialization' TEST_OPTS="VM_OPTIONS=--enable-preview --release=16" ...but javac doesn't seem to get them. Is there some secret option to achieve that? Hmm, we might as well have the microbenchmarks build with --enable-preview on by default. Try this: Fixed: diff -r f2e1cd498381 make/test/BuildMicrobenchmark.gmk --- a/make/test/BuildMicrobenchmark.gmk Tue Jun 23 10:08:35 2020 +0200 +++ b/make/test/BuildMicrobenchmark.gmk Tue Jun 23 10:33:17 2020 +0200 @@ -90,10 +90,11 @@ TARGET_RELEASE := $(TARGET_RELEASE_NEWJDK_UPGRADED), \ SMALL_JAVA := false, \ CLASSPATH := $(MICROBENCHMARK_CLASSPATH), \ - DISABLED_WARNINGS := processing rawtypes cast serial, \ + DISABLED_WARNINGS := processing rawtypes cast serial preview, \ SRC := $(MICROBENCHMARK_SRC), \ BIN := $(MICROBENCHMARK_CLASSES), \ JAVA_FLAGS := --add-modules jdk.unsupported --limit-modules java.management, \ + JAVAC_FLAGS := --enable-preview, \ )) $(BUILD_JDK_MICROBENCHMARK): $(JMH_COMPILE_JARS) I verified this works with your micro, and doesn't seem to cause any issues elsewhere: make test TEST=micro:RecordDeserialization I can shepherd this as a separate fix for documentation purposes, but feel free to include it in your patch and ping build-dev@.. /Claes diff -r 52741f85bf23 make/test/BuildMicrobenchmark.gmk --- a/make/test/BuildMicrobenchmark.gmk Tue Jun 23 09:54:42 2020 +0200 +++ b/make/test/BuildMicrobenchmark.gmk Tue Jun 23 09:59:29 2020 +0200 @@ -93,7 +93,7 @@ DISABLED_WARNINGS := processing rawtypes cast serial, \ SRC := $(MICROBENCHMARK_SRC), \ BIN := $(MICROBENCHMARK_CLASSES), \ - JAVA_FLAGS := --add-modules jdk.unsupported --limit-modules java.management, \ + JAVA_FLAGS := --enable-preview --add-modules jdk.unsupported --limit-modules java.management, \ )) $(BUILD_JDK_MICROBENCHMARK): $(JMH_COMPILE_JARS) Otherwise, I simulated what would happen when there are more then 10 ObjectStreamClass layouts for same class rapidly interchanging, so that they push each other out of the cache, by temporarily setting cache's MAX_SIZE = 0. Note that this is worst case scenario: Benchmark (length) Mode Cnt Score Error Units RecordDeserializationBench.deserializeClasses 10 avgt 10 9.393 ± 0.287 us/op RecordDeserializationBench.deserializeClasses 100 avgt 10 35.642 ± 0.977 us/op RecordDeserializationBench.deserializeClasses 1000 avgt 10 293.769 ± 7.321 us/op RecordDeserializationBench.deserializeRecords 10 avgt 10 15.335 ± 0.496 us/op RecordDeserializationBench.deserializeRecords 100 avgt 10 211.427 ± 11.908 us/op RecordDeserializationBench.deserializeRecords 1000 avgt 10 990.398 ± 26.681 us/op This is using JMH option '-gc true' to force GC after each iteration of benchmark. Without it, I get a big (~4s) full-GC pause just in the middle of a run with length=100: Iteration 1: 528.577 us/op Iteration 2: 580.404 us/op Iteration 3: 4438.228 us/op Iteration 4: 644.532 us/op Iteration 5: 698.493 us/op Iteration 6: 800.738 us/op Iteration 7: 929.791 us/op Iteration 8: 870.946 us/op Iteration 9: 863.416 us/op Iteration 10: 916.508 us/op ...so results are a bit off because of that: Benchmark (length) Mode Cnt Score Error Units RecordDeserializationBench.deserializeClasses 10 avgt 10 8.263 ± 0.043 us/op RecordDeserializationBench.deserializeClasses 100 avgt 10 33.406 ± 0.160 us/op RecordDeserializationBench.deserializeClasses 1000 avgt 10 287.595 ± 0.960 us/op RecordDeserializationBench.deserializeRecords 10 avgt 10 15.270 ± 0.080 us/op RecordDeserializationBench.deserializeRecords 100 avgt 10 1127.163 ± 1771.892 us/op RecordDeserializationBench.deserializeRecords 1000 avgt 10 2003.235 ± 227.159 us/op Yes, there is quite a bit of GCing going on when cache is
Re: RFR: 8247532, 8248135: Records deserialization is slow + Build microbenchmarks with --enable-preview
On 2020-06-23 11:17, Peter Levart wrote: Including build-dev since this patch is adding new issue 8248135: https://bugs.openjdk.java.net/browse/JDK-8248135 So here's new webrev with a patch for building benchmarks with --enable-preview included: http://cr.openjdk.java.net/~plevart/jdk-dev/RecordsDeserialization/webrev.08/ Build changes look good. /Magnus Regards, Peter On 6/23/20 10:23 AM, Claes Redestad wrote: On 2020-06-23 10:06, Claes Redestad wrote: Hi, On 2020-06-23 09:49, Peter Levart wrote: Hi Chris, Claes, Ok then, here's with benchmark included: http://cr.openjdk.java.net/~plevart/jdk-dev/RecordsDeserialization/webrev.07/ I haven't been able to run the benchmark with "make test" though. I have tried various ways to pass javac options to build like: make test TEST='micro:org.openjdk.bench.java.io.RecordDeserialization' TEST_OPTS="VM_OPTIONS=--enable-preview --release=16" ...but javac doesn't seem to get them. Is there some secret option to achieve that? Hmm, we might as well have the microbenchmarks build with --enable-preview on by default. Try this: Fixed: diff -r f2e1cd498381 make/test/BuildMicrobenchmark.gmk --- a/make/test/BuildMicrobenchmark.gmk Tue Jun 23 10:08:35 2020 +0200 +++ b/make/test/BuildMicrobenchmark.gmk Tue Jun 23 10:33:17 2020 +0200 @@ -90,10 +90,11 @@ TARGET_RELEASE := $(TARGET_RELEASE_NEWJDK_UPGRADED), \ SMALL_JAVA := false, \ CLASSPATH := $(MICROBENCHMARK_CLASSPATH), \ - DISABLED_WARNINGS := processing rawtypes cast serial, \ + DISABLED_WARNINGS := processing rawtypes cast serial preview, \ SRC := $(MICROBENCHMARK_SRC), \ BIN := $(MICROBENCHMARK_CLASSES), \ JAVA_FLAGS := --add-modules jdk.unsupported --limit-modules java.management, \ + JAVAC_FLAGS := --enable-preview, \ )) $(BUILD_JDK_MICROBENCHMARK): $(JMH_COMPILE_JARS) I verified this works with your micro, and doesn't seem to cause any issues elsewhere: make test TEST=micro:RecordDeserialization I can shepherd this as a separate fix for documentation purposes, but feel free to include it in your patch and ping build-dev@.. /Claes diff -r 52741f85bf23 make/test/BuildMicrobenchmark.gmk --- a/make/test/BuildMicrobenchmark.gmk Tue Jun 23 09:54:42 2020 +0200 +++ b/make/test/BuildMicrobenchmark.gmk Tue Jun 23 09:59:29 2020 +0200 @@ -93,7 +93,7 @@ DISABLED_WARNINGS := processing rawtypes cast serial, \ SRC := $(MICROBENCHMARK_SRC), \ BIN := $(MICROBENCHMARK_CLASSES), \ - JAVA_FLAGS := --add-modules jdk.unsupported --limit-modules java.management, \ + JAVA_FLAGS := --enable-preview --add-modules jdk.unsupported --limit-modules java.management, \ )) $(BUILD_JDK_MICROBENCHMARK): $(JMH_COMPILE_JARS) Otherwise, I simulated what would happen when there are more then 10 ObjectStreamClass layouts for same class rapidly interchanging, so that they push each other out of the cache, by temporarily setting cache's MAX_SIZE = 0. Note that this is worst case scenario: Benchmark (length) Mode Cnt Score Error Units RecordDeserializationBench.deserializeClasses 10 avgt 10 9.393 ± 0.287 us/op RecordDeserializationBench.deserializeClasses 100 avgt 10 35.642 ± 0.977 us/op RecordDeserializationBench.deserializeClasses 1000 avgt 10 293.769 ± 7.321 us/op RecordDeserializationBench.deserializeRecords 10 avgt 10 15.335 ± 0.496 us/op RecordDeserializationBench.deserializeRecords 100 avgt 10 211.427 ± 11.908 us/op RecordDeserializationBench.deserializeRecords 1000 avgt 10 990.398 ± 26.681 us/op This is using JMH option '-gc true' to force GC after each iteration of benchmark. Without it, I get a big (~4s) full-GC pause just in the middle of a run with length=100: Iteration 1: 528.577 us/op Iteration 2: 580.404 us/op Iteration 3: 4438.228 us/op Iteration 4: 644.532 us/op Iteration 5: 698.493 us/op Iteration 6: 800.738 us/op Iteration 7: 929.791 us/op Iteration 8: 870.946 us/op Iteration 9: 863.416 us/op Iteration 10: 916.508 us/op ...so results are a bit off because of that: Benchmark (length) Mode Cnt Score Error Units RecordDeserializationBench.deserializeClasses 10 avgt 10 8.263 ± 0.043 us/op RecordDeserializationBench.deserializeClasses 100 avgt 10 33.406 ± 0.160 us/op RecordDeserializationBench.deserializeClasses 1000 avgt 10 287.595 ± 0.960 us/op RecordDeserializationBench.deserializeRecords 10 avgt 10 15.270 ± 0.080 us/op RecordDeserializationBench.deserializeRecords 100 avgt 10 1127.163 ± 1771.892 us/op RecordDeserializationBench.deserializeRecords 1000 avgt 10 2003.235 ± 227.159 us/op Yes, there is quite a bit of GCing going on when cache is thrashing. Note that I haven't tuned GC in any way and I'm running
Re: RFR: 8247532, 8248135: Records deserialization is slow + Build microbenchmarks with --enable-preview
Including build-dev since this patch is adding new issue 8248135: https://bugs.openjdk.java.net/browse/JDK-8248135 So here's new webrev with a patch for building benchmarks with --enable-preview included: http://cr.openjdk.java.net/~plevart/jdk-dev/RecordsDeserialization/webrev.08/ Regards, Peter On 6/23/20 10:23 AM, Claes Redestad wrote: On 2020-06-23 10:06, Claes Redestad wrote: Hi, On 2020-06-23 09:49, Peter Levart wrote: Hi Chris, Claes, Ok then, here's with benchmark included: http://cr.openjdk.java.net/~plevart/jdk-dev/RecordsDeserialization/webrev.07/ I haven't been able to run the benchmark with "make test" though. I have tried various ways to pass javac options to build like: make test TEST='micro:org.openjdk.bench.java.io.RecordDeserialization' TEST_OPTS="VM_OPTIONS=--enable-preview --release=16" ...but javac doesn't seem to get them. Is there some secret option to achieve that? Hmm, we might as well have the microbenchmarks build with --enable-preview on by default. Try this: Fixed: diff -r f2e1cd498381 make/test/BuildMicrobenchmark.gmk --- a/make/test/BuildMicrobenchmark.gmk Tue Jun 23 10:08:35 2020 +0200 +++ b/make/test/BuildMicrobenchmark.gmk Tue Jun 23 10:33:17 2020 +0200 @@ -90,10 +90,11 @@ TARGET_RELEASE := $(TARGET_RELEASE_NEWJDK_UPGRADED), \ SMALL_JAVA := false, \ CLASSPATH := $(MICROBENCHMARK_CLASSPATH), \ - DISABLED_WARNINGS := processing rawtypes cast serial, \ + DISABLED_WARNINGS := processing rawtypes cast serial preview, \ SRC := $(MICROBENCHMARK_SRC), \ BIN := $(MICROBENCHMARK_CLASSES), \ JAVA_FLAGS := --add-modules jdk.unsupported --limit-modules java.management, \ + JAVAC_FLAGS := --enable-preview, \ )) $(BUILD_JDK_MICROBENCHMARK): $(JMH_COMPILE_JARS) I verified this works with your micro, and doesn't seem to cause any issues elsewhere: make test TEST=micro:RecordDeserialization I can shepherd this as a separate fix for documentation purposes, but feel free to include it in your patch and ping build-dev@.. /Claes diff -r 52741f85bf23 make/test/BuildMicrobenchmark.gmk --- a/make/test/BuildMicrobenchmark.gmk Tue Jun 23 09:54:42 2020 +0200 +++ b/make/test/BuildMicrobenchmark.gmk Tue Jun 23 09:59:29 2020 +0200 @@ -93,7 +93,7 @@ DISABLED_WARNINGS := processing rawtypes cast serial, \ SRC := $(MICROBENCHMARK_SRC), \ BIN := $(MICROBENCHMARK_CLASSES), \ - JAVA_FLAGS := --add-modules jdk.unsupported --limit-modules java.management, \ + JAVA_FLAGS := --enable-preview --add-modules jdk.unsupported --limit-modules java.management, \ )) $(BUILD_JDK_MICROBENCHMARK): $(JMH_COMPILE_JARS) Otherwise, I simulated what would happen when there are more then 10 ObjectStreamClass layouts for same class rapidly interchanging, so that they push each other out of the cache, by temporarily setting cache's MAX_SIZE = 0. Note that this is worst case scenario: Benchmark (length) Mode Cnt Score Error Units RecordDeserializationBench.deserializeClasses 10 avgt 10 9.393 ± 0.287 us/op RecordDeserializationBench.deserializeClasses 100 avgt 10 35.642 ± 0.977 us/op RecordDeserializationBench.deserializeClasses 1000 avgt 10 293.769 ± 7.321 us/op RecordDeserializationBench.deserializeRecords 10 avgt 10 15.335 ± 0.496 us/op RecordDeserializationBench.deserializeRecords 100 avgt 10 211.427 ± 11.908 us/op RecordDeserializationBench.deserializeRecords 1000 avgt 10 990.398 ± 26.681 us/op This is using JMH option '-gc true' to force GC after each iteration of benchmark. Without it, I get a big (~4s) full-GC pause just in the middle of a run with length=100: Iteration 1: 528.577 us/op Iteration 2: 580.404 us/op Iteration 3: 4438.228 us/op Iteration 4: 644.532 us/op Iteration 5: 698.493 us/op Iteration 6: 800.738 us/op Iteration 7: 929.791 us/op Iteration 8: 870.946 us/op Iteration 9: 863.416 us/op Iteration 10: 916.508 us/op ...so results are a bit off because of that: Benchmark (length) Mode Cnt Score Error Units RecordDeserializationBench.deserializeClasses 10 avgt 10 8.263 ± 0.043 us/op RecordDeserializationBench.deserializeClasses 100 avgt 10 33.406 ± 0.160 us/op RecordDeserializationBench.deserializeClasses 1000 avgt 10 287.595 ± 0.960 us/op RecordDeserializationBench.deserializeRecords 10 avgt 10 15.270 ± 0.080 us/op RecordDeserializationBench.deserializeRecords 100 avgt 10 1127.163 ± 1771.892 us/op RecordDeserializationBench.deserializeRecords 1000 avgt 10 2003.235 ± 227.159 us/op Yes, there is quite a bit of GCing going on when cache is thrashing. Note that I haven't tuned GC in any way and I'm running this on a machine with 64GiB of RAM so heap is allowed to grow quite big and G1 is
