# JMH 1.12 (released 7 days ago) # VM version: JDK 9-internal, VM 9-internal+0-2016-04-08-203619.shade.jdk9-hscomp # VM invoker: /home/shade/trunks/jdk9-hscomp/build/linux-x86_64-normal-server-release/images/jdk/bin/java # VM options: -Xmx1g -Xms1g # Warmup: 5 iterations, 1 s each # Measurement: 5 iterations, 1 s each # Timeout: 10 min per iteration # Threads: 1 thread, will synchronize iterations # Benchmark mode: Average time, time/op # Benchmark: org.openjdk.AllocInstance.testReflective # Run progress: 0.00% complete, ETA 00:00:10 # Fork: 1 of 1 # Preparing profilers: LinuxPerfAsmProfiler # Profilers consume stdout and stderr from target VM, use -v EXTRA to copy to console # Warmup Iteration 1: 7.197 ns/op # Warmup Iteration 2: 5.469 ns/op # Warmup Iteration 3: 6.221 ns/op # Warmup Iteration 4: 5.482 ns/op # Warmup Iteration 5: 5.531 ns/op Iteration 1: 5.488 ns/op Iteration 2: 5.480 ns/op Iteration 3: 5.501 ns/op Iteration 4: 5.498 ns/op Iteration 5: 5.535 ns/op # Processing profiler results: LinuxPerfAsmProfiler Result "testReflective": 5.500 ±(99.9%) 0.081 ns/op [Average] (min, avg, max) = (5.480, 5.500, 5.535), stdev = 0.021 CI (99.9%): [5.419, 5.582] (assumes normal distribution) Secondary result "·asm": PrintAssembly processed: 140278 total address lines. Perf output processed (skipped 5.066 seconds): Column 1: cycles (7061 events) Column 2: instructions (6972 events) Hottest code regions (>10.00% "cycles" events): ....[Hottest Region 1].............................................................................. [0x7fd1c4de1c00:0x7fd1c4de1ce3] in org.openjdk.AllocInstance::testReflective # {method} {0x00007fd174f80c20} 'testReflective' '()Ljava/lang/Object;' in 'org/openjdk/AllocInstance' # [sp+0x30] (sp of caller) 0x00007fd1c4de1c00: mov 0x8(%rsi),%r10d 0x00007fd1c4de1c04: shl $0x3,%r10 0x00007fd1c4de1c08: cmp %r10,%rax 0x00007fd1c4de1c0b: jne 0x00007fd1bd320f60 ; {runtime_call ic_miss_stub} 0x00007fd1c4de1c11: data16 xchg %ax,%ax 0x00007fd1c4de1c14: nopl 0x0(%rax,%rax,1) 0x00007fd1c4de1c1c: data16 data16 xchg %ax,%ax [Verified Entry Point] 0.58% 0.44% 0x00007fd1c4de1c20: mov %eax,-0x14000(%rsp) 3.60% 4.25% 0x00007fd1c4de1c27: push %rbp 0.04% 0.04% 0x00007fd1c4de1c28: sub $0x20,%rsp ;*synchronization entry ; - org.openjdk.AllocInstance::testReflective@-1 (line 43) 0.59% 0.76% 0x00007fd1c4de1c2c: mov 0xc(%rsi),%r11d ;*getfield cls {reexecute=0 rethrow=0 return_oop=0} ; - org.openjdk.AllocInstance::testReflective@4 (line 43) 3.48% 3.83% 0x00007fd1c4de1c30: mov 0x50(%r11),%rsi ;*invokevirtual isPrimitive {reexecute=0 rethrow=0 return_oop=0} ; - jdk.internal.misc.Unsafe::allocateInstance@1 (line 1164) ; - sun.misc.Unsafe::allocateInstance@4 (line 889) ; - org.openjdk.AllocInstance::testReflective@7 (line 43) ; implicit exception: dispatches to 0x00007fd1c4de1d09 0.35% 0.36% 0x00007fd1c4de1c34: mov 0x8(%rsi),%r10d ; implicit exception: dispatches to 0x00007fd1c4de1d19 1.47% 1.69% 0x00007fd1c4de1c38: test %r10d,%r10d 0x00007fd1c4de1c3b: jl 0x00007fd1c4de1ce5 ;*invokevirtual isArray {reexecute=0 rethrow=0 return_oop=0} ; - jdk.internal.misc.Unsafe::allocateInstance@8 (line 1164) ; - sun.misc.Unsafe::allocateInstance@4 (line 889) ; - org.openjdk.AllocInstance::testReflective@7 (line 43) 1.18% 1.48% 0x00007fd1c4de1c41: movzbl 0x172(%rsi),%r11d 2.82% 3.93% 0x00007fd1c4de1c49: mov %r10d,%r9d 0.01% 0.03% 0x00007fd1c4de1c4c: and $0x1,%r9d 0.33% 0.59% 0x00007fd1c4de1c50: add $0xfffffffc,%r11d 0.93% 0.92% 0x00007fd1c4de1c54: or %r9d,%r11d 2.65% 2.47% 0x00007fd1c4de1c57: test %r11d,%r11d ╭ 0x00007fd1c4de1c5a: jne 0x00007fd1c4de1cd9 1.50% 1.16% │ 0x00007fd1c4de1c5c: movslq %r10d,%rcx 0.17% 0.10% │ 0x00007fd1c4de1c5f: mov %rcx,%r10 0.08% 0.06% │ 0x00007fd1c4de1c62: and $0xfffffffffffffff8,%r10 2.82% 1.06% │ 0x00007fd1c4de1c66: mov 0x60(%r15),%r8 0.89% 0.57% │ 0x00007fd1c4de1c6a: mov %r8,%r11 0.18% 0.22% │ 0x00007fd1c4de1c6d: add %r10,%r11 1.01% 0.70% │ 0x00007fd1c4de1c70: cmp 0x70(%r15),%r11 │╭ 0x00007fd1c4de1c74: jae 0x00007fd1c4de1cd9 3.36% 1.42% ││ 0x00007fd1c4de1c76: mov %r11,0x60(%r15) 0.50% 0.52% ││ 0x00007fd1c4de1c7a: mov %r8,%rdi 0.11% 0.10% ││ 0x00007fd1c4de1c7d: add $0x10,%rdi 0.14% 0.04% ││ 0x00007fd1c4de1c81: mov 0xb0(%rsi),%r10 3.16% 3.74% ││ 0x00007fd1c4de1c88: mov %r10,(%r8) 0.61% 0.80% ││ 0x00007fd1c4de1c8b: prefetchnta 0xc0(%r11) 8.60% 10.38% ││ 0x00007fd1c4de1c93: shr $0x3,%rcx 0.07% 0.04% ││ 0x00007fd1c4de1c97: mov %rsi,%r11 0.51% 0.40% ││ 0x00007fd1c4de1c9a: shr $0x3,%r11 0.34% 0.04% ││ 0x00007fd1c4de1c9e: mov %r11d,0x8(%r8) 3.27% 3.84% ││ 0x00007fd1c4de1ca2: mov %r12d,0xc(%r8) 0.07% 0.04% ││ 0x00007fd1c4de1ca6: add $0xfffffffffffffffe,%rcx 0.47% 0.50% ││ 0x00007fd1c4de1caa: xor %rax,%rax 0.04% 0.06% ││ 0x00007fd1c4de1cad: cmp $0x8,%rcx ││╭ 0x00007fd1c4de1cb1: jg 0x00007fd1c4de1cc3 3.50% 3.41% │││ 0x00007fd1c4de1cb3: dec %rcx 0.10% 0.01% │││╭ 0x00007fd1c4de1cb6: js 0x00007fd1c4de1cca ││││↗ 0x00007fd1c4de1cb8: mov %rax,(%rdi,%rcx,8) │││││ 0x00007fd1c4de1cbc: dec %rcx ││││╰ 0x00007fd1c4de1cbf: jge 0x00007fd1c4de1cb8 ││││ ╭ 0x00007fd1c4de1cc1: jmp 0x00007fd1c4de1cca ││↘│ │ 0x00007fd1c4de1cc3: shl $0x3,%rcx ││ │ │ 0x00007fd1c4de1cc7: rep rex.W stos %al,%es:(%rdi) ;*synchronization entry ││ │ │ ; - org.openjdk.AllocInstance::testReflective@-1 (line 43) 0.50% 0.56% ││ ↘ ↘ 0x00007fd1c4de1cca: mov %r8,%rax 0.07% 0.03% ││ 0x00007fd1c4de1ccd: add $0x20,%rsp 3.40% 4.06% ││ 0x00007fd1c4de1cd1: pop %rbp 0.10% 0.07% ││ 0x00007fd1c4de1cd2: test %eax,0x17e91328(%rip) # 0x00007fd1dcc73000 ││ ; {poll_return} 0.59% 0.53% ││ 0x00007fd1c4de1cd8: retq ↘↘ 0x00007fd1c4de1cd9: xchg %ax,%ax 0x00007fd1c4de1cdb: callq 0x00007fd1bd3538e0 ; ImmutableOopMap{} ;*invokespecial allocateInstance0 {reexecute=0 rethrow=0 return_oop=1} ; - jdk.internal.misc.Unsafe::allocateInstance@28 (line 1167) ; - sun.misc.Unsafe::allocateInstance@4 (line 889) ; - org.openjdk.AllocInstance::testReflective@7 (line 43) ; {runtime_call _new_instance_Java} 0x00007fd1c4de1ce0: mov %rax,%r8 0x00007fd1c4de1ce3: jmp 0x00007fd1c4de1cca .................................................................................................... 54.20% 55.28% ....[Hottest Region 2].............................................................................. [0x7fd1c4de20e0:0x7fd1c4de2169] in org.openjdk.jmh.infra.Blackhole::consume # parm0: rdx:rdx = 'java/lang/Object' # [sp+0x20] (sp of caller) 0x00007fd1c4de20e0: mov 0x8(%rsi),%r10d 0x00007fd1c4de20e4: shl $0x3,%r10 0x00007fd1c4de20e8: cmp %r10,%rax 0x00007fd1c4de20eb: jne 0x00007fd1bd320f60 ; {runtime_call ic_miss_stub} 0x00007fd1c4de20f1: data16 xchg %ax,%ax 0x00007fd1c4de20f4: nopl 0x0(%rax,%rax,1) 0x00007fd1c4de20fc: data16 data16 xchg %ax,%ax [Verified Entry Point] 3.60% 4.09% 0x00007fd1c4de2100: sub $0x18,%rsp 0.71% 0.63% 0x00007fd1c4de2107: mov %rbp,0x10(%rsp) ;*synchronization entry ; - org.openjdk.jmh.infra.Blackhole::consume@-1 (line 316) 3.65% 3.44% 0x00007fd1c4de210c: mov %rdx,%rbx 0.03% 0.07% 0x00007fd1c4de210f: mov %rsi,%r13 0.47% 0.55% 0x00007fd1c4de2112: mov 0xc4(%rsi),%ebp ;*getfield tlrMask {reexecute=0 rethrow=0 return_oop=0} ; - org.openjdk.jmh.infra.Blackhole::consume@1 (line 316) 0.25% 0.14% 0x00007fd1c4de2118: imul $0x19660d,0xc0(%rsi),%r11d 2.99% 3.59% 0x00007fd1c4de2123: add $0x3c6ef35f,%r11d ;*iadd {reexecute=0 rethrow=0 return_oop=0} ; - org.openjdk.jmh.infra.Blackhole::consume@15 (line 317) 0.06% 0.04% 0x00007fd1c4de212a: mov %r11d,0xc0(%rsi) ;*putfield tlr {reexecute=0 rethrow=0 return_oop=0} ; - org.openjdk.jmh.infra.Blackhole::consume@17 (line 317) 0.51% 0.72% 0x00007fd1c4de2131: and %ebp,%r11d 0.13% 0.19% 0x00007fd1c4de2134: test %r11d,%r11d ╭ 0x00007fd1c4de2137: je 0x00007fd1c4de2145 ;*putfield obj1 {reexecute=0 rethrow=0 return_oop=0} │ ; - org.openjdk.jmh.infra.Blackhole::consume@29 (line 320) 3.51% 3.00% │ 0x00007fd1c4de2139: add $0x10,%rsp 0.04% 0.01% │ 0x00007fd1c4de213d: pop %rbp 0.42% 0.39% │ 0x00007fd1c4de213e: test %eax,0x17e90ebc(%rip) # 0x00007fd1dcc73000 │ ; {poll_return} 0.20% 0.22% │ 0x00007fd1c4de2144: retq ↘ 0x00007fd1c4de2145: movsbl 0x328(%r15),%r11d 0x00007fd1c4de214d: test %r11d,%r11d 0x00007fd1c4de2150: jne 0x00007fd1c4de21f2 0x00007fd1c4de2156: mov %r13,%r10 0x00007fd1c4de2159: mov %rbx,%r8 0x00007fd1c4de215c: mov %r8,%r11 0x00007fd1c4de215f: mov %r11d,0xd4(%r13) 0x00007fd1c4de2166: mov %r8,%r11 0x00007fd1c4de2169: xor %r10,%r11 .................................................................................................... 16.57% 17.07% ....[Hottest Region 3].............................................................................. [0x7fd1c4de6024:0x7fd1c4de608d] in org.openjdk.generated.AllocInstance_testReflective_jmhTest::testReflective_avgt_jmhStub 0x00007fd1c4de6024: mov 0x10(%rsp),%r10 0x00007fd1c4de6029: movzbl 0x94(%r10),%r11d ;*getfield isDone {reexecute=0 rethrow=0 return_oop=0} ; - org.openjdk.generated.AllocInstance_testReflective_jmhTest::testReflective_avgt_jmhStub@29 (line 199) ; implicit exception: dispatches to 0x00007fd1c4de60f5 0x00007fd1c4de6031: mov $0x1,%ebp 0x00007fd1c4de6036: test %r11d,%r11d ╭ 0x00007fd1c4de6039: jne 0x00007fd1c4de6078 ;*ifeq {reexecute=0 rethrow=0 return_oop=0} │ ; - org.openjdk.generated.AllocInstance_testReflective_jmhTest::testReflective_avgt_jmhStub@32 (line 199) │ 0x00007fd1c4de603b: nopl 0x0(%rax,%rax,1) ;*aload {reexecute=0 rethrow=0 return_oop=0} │ ; - org.openjdk.generated.AllocInstance_testReflective_jmhTest::testReflective_avgt_jmhStub@13 (line 197) 0.45% 0.24% │↗ 0x00007fd1c4de6040: mov 0x8(%rsp),%rsi 0.27% 0.14% ││ 0x00007fd1c4de6045: xchg %ax,%ax 3.64% 3.94% ││ 0x00007fd1c4de6047: callq 0x00007fd1bd321160 ; ImmutableOopMap{[0]=Oop [8]=Oop [16]=Oop [24]=Oop } ││ ;*invokevirtual testReflective {reexecute=0 rethrow=0 return_oop=1} ││ ; - org.openjdk.generated.AllocInstance_testReflective_jmhTest::testReflective_avgt_jmhStub@16 (line 197) ││ ; {optimized virtual_call} 0.67% 0.49% ││ 0x00007fd1c4de604c: mov 0x18(%rsp),%rsi 2.96% 3.27% ││ 0x00007fd1c4de6051: mov %rax,%rdx 0.50% 0.29% ││ 0x00007fd1c4de6054: data16 xchg %ax,%ax 0.18% 0.19% ││ 0x00007fd1c4de6057: callq 0x00007fd1bd321160 ; ImmutableOopMap{[0]=Oop [8]=Oop [16]=Oop [24]=Oop } ││ ;*invokevirtual consume {reexecute=0 rethrow=0 return_oop=0} ││ ; - org.openjdk.generated.AllocInstance_testReflective_jmhTest::testReflective_avgt_jmhStub@19 (line 197) ││ ; {optimized virtual_call} 3.71% 3.60% ││ 0x00007fd1c4de605c: mov 0x10(%rsp),%r10 0.40% 0.80% ││ 0x00007fd1c4de6061: movzbl 0x94(%r10),%r11d ;*getfield isDone {reexecute=0 rethrow=0 return_oop=0} ││ ; - org.openjdk.generated.AllocInstance_testReflective_jmhTest::testReflective_avgt_jmhStub@29 (line 199) 0.17% 0.14% ││ 0x00007fd1c4de6069: add $0x1,%rbp ; ImmutableOopMap{r10=Oop [0]=Oop [8]=Oop [16]=Oop [24]=Oop } ││ ;*ifeq {reexecute=1 rethrow=0 return_oop=0} ││ ; - org.openjdk.generated.AllocInstance_testReflective_jmhTest::testReflective_avgt_jmhStub@32 (line 199) 3.51% 3.40% ││ 0x00007fd1c4de606d: test %eax,0x17e8cf8d(%rip) # 0x00007fd1dcc73000 ││ ; {poll} 0.06% 0.04% ││ 0x00007fd1c4de6073: test %r11d,%r11d │╰ 0x00007fd1c4de6076: je 0x00007fd1c4de6040 ;*aload_2 {reexecute=0 rethrow=0 return_oop=0} │ ; - org.openjdk.generated.AllocInstance_testReflective_jmhTest::testReflective_avgt_jmhStub@35 (line 200) ↘ 0x00007fd1c4de6078: movabs $0x7fd1db679400,%r10 0x00007fd1c4de6082: callq *%r10 ;*invokestatic nanoTime {reexecute=0 rethrow=0 return_oop=0} ; - org.openjdk.generated.AllocInstance_testReflective_jmhTest::testReflective_avgt_jmhStub@36 (line 200) 0x00007fd1c4de6085: mov (%rsp),%r10 0x00007fd1c4de6089: mov %rbp,0x18(%r10) ;*putfield measuredOps {reexecute=0 rethrow=0 return_oop=0} ; - org.openjdk.generated.AllocInstance_testReflective_jmhTest::testReflective_avgt_jmhStub@51 (line 202) 0x00007fd1c4de608d: mov %rax,0x30(%r10) ;*putfield stopTime {reexecute=0 rethrow=0 return_oop=0} .................................................................................................... 16.51% 16.55% ....[Hottest Regions]............................................................................... 54.20% 55.28% [0x7fd1c4de1c00:0x7fd1c4de1ce3] in org.openjdk.AllocInstance::testReflective 16.57% 17.07% [0x7fd1c4de20e0:0x7fd1c4de2169] in org.openjdk.jmh.infra.Blackhole::consume 16.51% 16.55% [0x7fd1c4de6024:0x7fd1c4de608d] in org.openjdk.generated.AllocInstance_testReflective_jmhTest::testReflective_avgt_jmhStub 4.94% 4.98% [0xffffffff8105b83a:0xffffffff8105b83d] in [unknown] ([unknown]) 2.62% 1.64% [0x7fd1db5225e0:0x7fd1db5225e9] in SpinPause (libjvm.so) 1.25% 1.64% [0x7fd1db7c031e:0x7fd1db7c0351] in _ZN22ParallelTaskTerminator17offer_terminationEP20TerminatorTerminator (libjvm.so) 0.33% 0.22% [0x7fd1db76482f:0x7fd1db764865] in _ZN11StringTable25possibly_parallel_oops_doEP10OopClosure (libjvm.so) 0.17% 0.06% [0x7fd1dc50c660:0x7fd1dc50c67b] in memset (libc-2.19.so) 0.14% 0.07% [0x7fd1db35de57:0x7fd1db35de60] in _ZN16HeapRegionRemSet16iter_is_completeEv (libjvm.so) 0.13% 0.13% [0xffffffff8102cdb4:0xffffffff8102cdb8] in [unknown] ([unknown]) 0.10% 0.10% [0xffffffff817b5a06:0xffffffff817b5a12] in [unknown] ([unknown]) 0.08% 0.09% [0xffffffff81032b28:0xffffffff81032b2c] in [unknown] ([unknown]) 0.08% 0.03% [0x7fd1db2b0f2d:0x7fd1db2b0f49] in _ZN18G1ParCleanupCTTask4workEj (libjvm.so) 0.07% [0xffffffff8117cc7d:0xffffffff8117cc7d] in [unknown] ([unknown]) 0.07% 0.03% [0x7fd1db757135:0x7fd1db757151] in _ZN15RSHashTableIter8has_nextERm (libjvm.so) 0.06% 0.03% [0xffffffff811837a8:0xffffffff811837ae] in [unknown] ([unknown]) 0.06% 0.01% [0x7fd1db7647fa:0x7fd1db7647fa] in _ZN11StringTable25possibly_parallel_oops_doEP10OopClosure (libjvm.so) 0.04% 0.04% [0xffffffff8109cf70:0xffffffff8109cf70] in [unknown] ([unknown]) 0.04% 0.04% [0xffffffff817b1650:0xffffffff817b1650] in [unknown] ([unknown]) 0.04% 0.03% [0x7fd1db2d4d9c:0x7fd1db2d4d9c] in _ZN18G1KlassScanClosure8do_klassEP5Klass (libjvm.so) 2.48% 1.97% <...other 254 warm regions...> .................................................................................................... 99.99% 99.99% ....[Hottest Methods (after inlining)].............................................................. 54.20% 55.28% org.openjdk.AllocInstance::testReflective 16.57% 17.07% org.openjdk.jmh.infra.Blackhole::consume 16.51% 16.55% org.openjdk.generated.AllocInstance_testReflective_jmhTest::testReflective_avgt_jmhStub 6.36% 6.27% [unknown] ([unknown]) 2.62% 1.64% SpinPause (libjvm.so) 1.26% 1.64% _ZN22ParallelTaskTerminator17offer_terminationEP20TerminatorTerminator (libjvm.so) 0.38% 0.23% _ZN11StringTable25possibly_parallel_oops_doEP10OopClosure (libjvm.so) 0.21% 0.07% memset (libc-2.19.so) 0.14% 0.07% _ZN16HeapRegionRemSet16iter_is_completeEv (libjvm.so) 0.11% 0.03% _ZN18G1ParCleanupCTTask4workEj (libjvm.so) 0.07% 0.03% _ZN15RSHashTableIter8has_nextERm (libjvm.so) 0.07% vfprintf (libc-2.19.so) 0.06% 0.01% print_insn (libhsdis-amd64.so) 0.06% 0.04% 0.03% _ZN18G1KlassScanClosure8do_klassEP5Klass (libjvm.so) 0.04% 0.01% _ZNK17OtherRegionsTable8occupiedEv (libjvm.so) 0.04% 0.01% _ZN11OptoRuntime14new_instance_CEP5KlassP10JavaThread (libjvm.so) 0.03% 0.01% _ZN16G1ParScanClosure9do_oop_nvIjEEvPT_ (libjvm.so) 0.03% _ZN11G1Allocator21unsafe_max_tlab_allocEh (libjvm.so) 0.03% 0.01% _ZNK17G1CollectorPolicy30predict_region_elapsed_time_msEP10HeapRegionb (libjvm.so) 1.15% 0.33% <...other 76 warm methods...> .................................................................................................... 99.99% 99.30% ....[Distribution by Area].......................................................................... 87.41% 88.94% 6.36% 6.27% 5.71% 4.52% 0.42% 0.24% 0.06% 0.01% 0.01% 0.01% .................................................................................................... 99.99% 99.99% # Run complete. Total time: 00:00:12 Benchmark Mode Cnt Score Error Units AllocInstance.testReflective avgt 5 5.500 ± 0.081 ns/op AllocInstance.testReflective:·asm avgt NaN ---