Return-Path: X-Original-To: archive-asf-public-internal@cust-asf2.ponee.io Delivered-To: archive-asf-public-internal@cust-asf2.ponee.io Received: from cust-asf.ponee.io (cust-asf.ponee.io [163.172.22.183]) by cust-asf2.ponee.io (Postfix) with ESMTP id 65BBB200BDF for ; Sat, 3 Dec 2016 15:52:28 +0100 (CET) Received: by cust-asf.ponee.io (Postfix) id 64ACF160B0E; Sat, 3 Dec 2016 14:52:28 +0000 (UTC) Delivered-To: archive-asf-public@cust-asf.ponee.io Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by cust-asf.ponee.io (Postfix) with SMTP id 602D4160B09 for ; Sat, 3 Dec 2016 15:52:27 +0100 (CET) Received: (qmail 60494 invoked by uid 500); 3 Dec 2016 14:52:26 -0000 Mailing-List: contact commits-help@zest.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@zest.apache.org Delivered-To: mailing list commits@zest.apache.org Received: (qmail 60483 invoked by uid 99); 3 Dec 2016 14:52:26 -0000 Received: from git1-us-west.apache.org (HELO git1-us-west.apache.org) (140.211.11.23) by apache.org (qpsmtpd/0.29) with ESMTP; Sat, 03 Dec 2016 14:52:26 +0000 Received: by git1-us-west.apache.org (ASF Mail Server at git1-us-west.apache.org, from userid 33) id 772CBDFDE4; Sat, 3 Dec 2016 14:52:26 +0000 (UTC) Content-Type: text/plain; charset="us-ascii" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit From: paulmerlin@apache.org To: commits@zest.apache.org Date: Sat, 03 Dec 2016 14:52:26 -0000 Message-Id: X-Mailer: ASF-Git Admin Mailer Subject: [1/3] zest-java git commit: refine composite creation performance tests archived-at: Sat, 03 Dec 2016 14:52:28 -0000 Repository: zest-java Updated Branches: refs/heads/develop 07f569983 -> 96080d0ac refine composite creation performance tests warmup runs, more iterations, pauses to let GC & JIT do their job unsurprisingly, the results are now more accurate, realistic measured plain object instantiation is now down to 1 nanosec our instanciations are much slower than that Project: http://git-wip-us.apache.org/repos/asf/zest-java/repo Commit: http://git-wip-us.apache.org/repos/asf/zest-java/commit/e1dccf2b Tree: http://git-wip-us.apache.org/repos/asf/zest-java/tree/e1dccf2b Diff: http://git-wip-us.apache.org/repos/asf/zest-java/diff/e1dccf2b Branch: refs/heads/develop Commit: e1dccf2b6324e9541e74ffced9c3c0449fa9fbff Parents: 07f5699 Author: Paul Merlin Authored: Sat Dec 3 14:05:21 2016 +0100 Committer: Paul Merlin Committed: Sat Dec 3 14:05:21 2016 +0100 ---------------------------------------------------------------------- .../CompositeCreationPerformanceTest.java | 174 +++++++++++++------ 1 file changed, 118 insertions(+), 56 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/zest-java/blob/e1dccf2b/tests/performance/src/perf/java/org/apache/zest/test/performance/runtime/composite/CompositeCreationPerformanceTest.java ---------------------------------------------------------------------- diff --git a/tests/performance/src/perf/java/org/apache/zest/test/performance/runtime/composite/CompositeCreationPerformanceTest.java b/tests/performance/src/perf/java/org/apache/zest/test/performance/runtime/composite/CompositeCreationPerformanceTest.java index ad6c93a..e77a00f 100644 --- a/tests/performance/src/perf/java/org/apache/zest/test/performance/runtime/composite/CompositeCreationPerformanceTest.java +++ b/tests/performance/src/perf/java/org/apache/zest/test/performance/runtime/composite/CompositeCreationPerformanceTest.java @@ -17,21 +17,16 @@ */ package org.apache.zest.test.performance.runtime.composite; -import java.time.Duration; -import java.time.Instant; -import org.apache.zest.api.time.SystemTime; -import org.junit.Test; import org.apache.zest.api.activation.ActivationException; -import org.apache.zest.api.composite.TransientBuilder; import org.apache.zest.api.composite.TransientBuilderFactory; import org.apache.zest.api.composite.TransientComposite; import org.apache.zest.api.object.ObjectFactory; -import org.apache.zest.api.value.ValueBuilder; import org.apache.zest.api.value.ValueBuilderFactory; import org.apache.zest.api.value.ValueComposite; import org.apache.zest.bootstrap.AssemblyException; import org.apache.zest.bootstrap.ModuleAssembly; import org.apache.zest.bootstrap.SingletonAssembler; +import org.junit.Test; /** * Tests performance of new composite creation. @@ -40,7 +35,7 @@ public class CompositeCreationPerformanceTest { @Test public void newInstanceForRegisteredCompositePerformance() - throws ActivationException, AssemblyException + throws ActivationException, AssemblyException, InterruptedException { SingletonAssembler assembler = new SingletonAssembler() { @@ -53,70 +48,122 @@ public class CompositeCreationPerformanceTest module.values( AnyValue.class ); } }; - int loops = 2; - long t0 = 0; + int warmups = 10; + int runs = 20; + long waitBeforeRun = 1000; + long waitBetweenRuns = 500; + long timeForJavaObject = 0; { - for( int i = 0; i < loops; i++ ) + // Warmup + for( int i = 0; i < warmups; i++ ) + { + testJavaObjectCreationPerformance( false ); + } + Thread.sleep( waitBeforeRun ); + // Run + for( int i = 0; i < runs; i++ ) { - t0 = t0 + testJavaObjectCreationPerformance(); + timeForJavaObject += testJavaObjectCreationPerformance( true ); + Thread.sleep( waitBetweenRuns ); } - t0 = t0 / loops; + timeForJavaObject = timeForJavaObject / runs; } - long t1 = 0; + long timeForTransientComposite = 0; { TransientBuilderFactory module = assembler.module(); - for( int i = 0; i < loops; i++ ) + // Warmup + for( int i = 0; i < warmups; i++ ) { - t1 = t1 + testCompositeCreationPerformance( module ); + testCompositeCreationPerformance( module, false ); } - t1 = t1 / loops; + Thread.sleep( waitBeforeRun ); + // Run + for( int i = 0; i < runs; i++ ) + { + timeForTransientComposite += testCompositeCreationPerformance( module, true ); + Thread.sleep( waitBetweenRuns ); + } + timeForTransientComposite = timeForTransientComposite / runs; } - long t2 = 0; + long timeForManagedObject = 0; { ObjectFactory objectFactory = assembler.module(); - for( int i = 0; i < loops; i++ ) + // Warmup + for( int i = 0; i < warmups; i++ ) + { + testObjectCreationPerformance( objectFactory, false ); + } + Thread.sleep( waitBeforeRun ); + // Run + for( int i = 0; i < runs; i++ ) { - t2 = t2 + testObjectCreationPerformance( objectFactory ); + timeForManagedObject += testObjectCreationPerformance( objectFactory, true ); + Thread.sleep( waitBetweenRuns ); } - t2 = t2 / loops; + timeForManagedObject = timeForManagedObject / runs; } - long t3 = 0; + long timeForValueComposite = 0; { ValueBuilderFactory valueBuilderFactory = assembler.module(); - for( int i = 0; i < loops; i++ ) + // Warmup + for( int i = 0; i < warmups; i++ ) + { + testValueCreationPerformance( valueBuilderFactory, false ); + } + Thread.sleep( waitBeforeRun ); + // Run + for( int i = 0; i < runs; i++ ) { - t3 = t3 + testValueCreationPerformance( valueBuilderFactory ); + timeForValueComposite += testValueCreationPerformance( valueBuilderFactory, true ); + Thread.sleep( waitBetweenRuns ); } - t3 = t3 / loops; + timeForValueComposite = timeForValueComposite / runs; } - long t4 = 0; + long timeForTransientCompositeBuilder = 0; { TransientBuilderFactory module = assembler.module(); - for( int i = 0; i < loops; i++ ) + // Warmup + for( int i = 0; i < warmups; i++ ) { - t4 = t4 + testCompositeCreationWithBuilderPerformance( module ); + testCompositeCreationWithBuilderPerformance( module, false ); } - t4 = t4 / loops; + Thread.sleep( waitBeforeRun ); + // Run + for( int i = 0; i < runs; i++ ) + { + timeForTransientCompositeBuilder += testCompositeCreationWithBuilderPerformance( module, true ); + Thread.sleep( waitBetweenRuns ); + } + timeForTransientCompositeBuilder = timeForTransientCompositeBuilder / runs; } - long t6 = 0; + long timeForValueCompositeBuilder = 0; { ValueBuilderFactory valueBuilderFactory = assembler.module(); - for( int i = 0; i < loops; i++ ) + // Warmup + for( int i = 0; i < warmups; i++ ) + { + testValueCreationWithBuilderPerformance( valueBuilderFactory, false ); + } + Thread.sleep( waitBeforeRun ); + // Run + for( int i = 0; i < runs; i++ ) { - t6 = t6 + testValueCreationWithBuilderPerformance( valueBuilderFactory ); + timeForValueCompositeBuilder += testValueCreationWithBuilderPerformance( valueBuilderFactory, true ); + Thread.sleep( waitBetweenRuns ); } - t6 = t6 / loops; + timeForValueCompositeBuilder = timeForValueCompositeBuilder / runs; } - System.out.println( "Transient: " + ( t1 / t0 ) + "x" ); - System.out.println( "TransientBuilder: " + ( t4 / t0 ) + "x" ); - System.out.println( "Value: " + ( t3 / t0 ) + "x" ); - System.out.println( "ValueBuilder: " + ( t6 / t0 ) + "x" ); - System.out.println( "Object: " + ( t2 / t0 ) + "x" ); + System.out.println( "----" ); + System.out.println( "Transient: " + ( timeForTransientComposite / timeForJavaObject ) + "x" ); + System.out.println( "TransientBuilder: " + ( timeForTransientCompositeBuilder / timeForJavaObject ) + "x" ); + System.out.println( "Value: " + ( timeForValueComposite / timeForJavaObject ) + "x" ); + System.out.println( "ValueBuilder: " + ( timeForValueCompositeBuilder / timeForJavaObject ) + "x" ); + System.out.println( "Object: " + ( timeForManagedObject / timeForJavaObject ) + "x" ); } - private long testCompositeCreationPerformance( TransientBuilderFactory module ) + private long testCompositeCreationPerformance( TransientBuilderFactory module, boolean run ) { long start = System.currentTimeMillis(); int iter = 1000000; @@ -127,27 +174,32 @@ public class CompositeCreationPerformanceTest long end = System.currentTimeMillis(); long time = 1000000L * ( end - start ) / iter; - System.out.println( "Minimum Composite Creation Time:" + time + " nanoseconds per composite" ); + if( run ) + { + System.out.println( "Composite Creation Time:" + time + " nanoseconds per composite" ); + } return time; } - private long testCompositeCreationWithBuilderPerformance( TransientBuilderFactory module ) + private long testCompositeCreationWithBuilderPerformance( TransientBuilderFactory module, boolean run ) { long start = System.currentTimeMillis(); int iter = 1000000; for( int i = 0; i < iter; i++ ) { - TransientBuilder builder = module.newTransientBuilder( AnyComposite.class ); - builder.newInstance(); + module.newTransientBuilder( AnyComposite.class ).newInstance(); } long end = System.currentTimeMillis(); long time = 1000000L * ( end - start ) / iter; - System.out.println( "Minimum Composite (builder) Creation Time:" + time + " nanoseconds per composite" ); + if( run ) + { + System.out.println( "Composite (builder) Creation Time:" + time + " nanoseconds per composite" ); + } return time; } - private long testValueCreationPerformance( ValueBuilderFactory valueBuilderFactory ) + private long testValueCreationPerformance( ValueBuilderFactory valueBuilderFactory, boolean run ) { long start = System.currentTimeMillis(); int iter = 1000000; @@ -158,27 +210,32 @@ public class CompositeCreationPerformanceTest long end = System.currentTimeMillis(); long time = 1000000L * ( end - start ) / iter; - System.out.println( "Minimum Value Creation Time:" + time + " nanoseconds per composite" ); + if( run ) + { + System.out.println( "Value Creation Time:" + time + " nanoseconds per composite" ); + } return time; } - private long testValueCreationWithBuilderPerformance( ValueBuilderFactory valueBuilderFactory ) + private long testValueCreationWithBuilderPerformance( ValueBuilderFactory valueBuilderFactory, boolean run ) { long start = System.currentTimeMillis(); int iter = 1000000; for( int i = 0; i < iter; i++ ) { - ValueBuilder builder = valueBuilderFactory.newValueBuilder( AnyValue.class ); - builder.newInstance(); + valueBuilderFactory.newValueBuilder( AnyValue.class ).newInstance(); } long end = System.currentTimeMillis(); long time = 1000000L * ( end - start ) / iter; - System.out.println( "Minimum Value (builder) Creation Time:" + time + " nanoseconds per composite" ); + if( run ) + { + System.out.println( "Value (builder) Creation Time:" + time + " nanoseconds per composite" ); + } return time; } - private long testObjectCreationPerformance( ObjectFactory objectFactory ) + private long testObjectCreationPerformance( ObjectFactory objectFactory, boolean run ) { long start = System.currentTimeMillis(); int iter = 1000000; @@ -189,11 +246,14 @@ public class CompositeCreationPerformanceTest long end = System.currentTimeMillis(); long time = 1000000L * ( end - start ) / iter; - System.out.println( "Minimum Zest Object Creation Time:" + time + " nanoseconds per object" ); + if( run ) + { + System.out.println( "Zest Object Creation Time:" + time + " nanoseconds per object" ); + } return time; } - private long testJavaObjectCreationPerformance() + private long testJavaObjectCreationPerformance( boolean run ) { long start = System.currentTimeMillis(); int iter = 1000000; @@ -204,16 +264,19 @@ public class CompositeCreationPerformanceTest long end = System.currentTimeMillis(); long time = 1000000L * ( end - start ) / iter; - System.out.println( "Minimum Java Object Creation Time:" + time + " nanoseconds per object" ); + if( run ) + { + System.out.println( "Java Object Creation Time:" + time + " nanoseconds per object" ); + } return time; } - public static interface AnyComposite + public interface AnyComposite extends TransientComposite { } - public static interface AnyValue + public interface AnyValue extends ValueComposite { } @@ -221,5 +284,4 @@ public class CompositeCreationPerformanceTest public static class AnyObject { } - }