[infinispan-dev] if (trace) logger.tracef - it makes sense

Dan Berindei dan.berindei at gmail.com
Mon Oct 3 08:40:49 EDT 2016


Hi Sebastian

I modified your benchmark so that the logger and the trace field are
static final and looked at the generated assembly with JITWatch [1].
Based on the attached assembly listings, caching isTraceEnabled() in a
constant field is "infinitely faster", because there are no assembly
instructions that can be traced back to the test method.

JBossLogManagerLogger::translate() is inlined in this listing, but it
still goes through the switch machinery, I'm guessing because the
ordinal of an Enum is not considered a constant.

Cheers
Dan


[1]: https://github.com/AdoptOpenJDK/jitwatch

On Mon, Oct 3, 2016 at 11:28 AM, Sebastian Laskawiec
<slaskawi at redhat.com> wrote:
> Hey!
>
> Please have a look at the latest perf test results [1][2]:
>
> Benchmark                             Mode  Cnt           Score
> Error  Units
> MyBenchmark.noVariable               thrpt   20   681131269.875 ±
> 3961932.923  ops/s
> MyBenchmark.withIsTraceEnabledCheck  thrpt   20   676307984.921 ±
> 14305970.393  ops/s
> MyBenchmark.withVariable             thrpt   20  2411000894.582 ±
> 17382438.635  ops/s
>
> I think there is no surprise here.. using a field, which stores the result
> of `logger.isTraceEnabled()` evaluation is 3 times faster than other
> options.
>
> If anyone is interested in printing out JIT stuff, I also ran it with
> "-XX:+PrintCompilation", "-XX:+PrintCompilation2" and "-XX:+PrintInlining"
> here [3].
>
> I'm not a performance expert but it seems that JIT could not inline the
> "translate" method because of its size (see line 1861). However it tried
> several times with different optimizations (and some of them were thrown
> away - "made not entrant" messages [4]).
>
> Let's wait for James' opinion on this, but I think we should address this
> issue on JBoss Logging/LogManager side (so I agree with David here) and make
> those parts inlinable (wow, does this word even exist? :D). Once this is
> done, we could experiment further in Infinispan codebase and see how this
> relates to some real world benchmarks...
>
> Thanks
> Sebastian
>
> [1] https://gist.github.com/slaskawi/6766b6e17c7a28ac8d8962293c48a53c
> [2] Test repository: https://github.com/slaskawi/jboss-logging-perf-test
> [3] https://gist.github.com/slaskawi/6f317bb05539611434bc91d66924bae0
> [4]
> https://www.safaribooksonline.com/library/view/java-performance-the/9781449363512/ch04.html
>
> On Mon, Oct 3, 2016 at 7:32 AM, Sebastian Laskawiec <slaskawi at redhat.com>
> wrote:
>>
>> Hey!
>>
>> Adding James to this thread.
>>
>> @Dennis - I think Dan has a point here. The trick with checking a field in
>> a class is 3 times faster. Most of the checks are done in core so they are
>> executed multiple times per operation. Changing all those places is probably
>> not an option.
>>
>> @David - Let me run a test with JBoss Log Manager and get back to you with
>> some results. But if Dan is right, and the problem is with enum mapping, I
>> will get similar results.
>>
>> Thanks
>> Sebastian
>>
>> On Sat, Oct 1, 2016 at 11:53 AM, Dan Berindei <dan.berindei at gmail.com>
>> wrote:
>>>
>>> On Fri, Sep 30, 2016 at 10:15 PM, David M. Lloyd <david.lloyd at redhat.com>
>>> wrote:
>>> > The performance problem that this trick is meant to resolve is really a
>>> > problem in the logging backend.  It *should* be faster inside of
>>> > WildFly, where JBoss LogManager is used, because that project just
>>> > checks a single volatile field for the level check... and the path to
>>> > that code *should* be inline-friendly.
>>> >
>>>
>>> Indeed, we started using this trick because of log4j 1.2, which needs
>>> to walk the logger hierarchy in order to check the level, and it made
>>> a significant difference there.
>>>
>>> Nowadays I think it's pretty close to optimal in all logging
>>> frameworks. The only nitpick is that they all use enums for the
>>> levels, and the JIT can't inline Level.TRACE.value as it would with a
>>> Level.TRACE_VALUE int constant. If JDK9 fixes that, then it's going to
>>> be more or less equivalent to using a volatile "trace" field in each
>>> class, so it should be suitable even for local read operations that
>>> take < 200ns.
>>>
>>> We'd probably still need to weed out some of the trace messages, as we
>>> probably have more than 10 of them during such a read operation. I
>>> confess that I added way too many trace logs myself, precisely because
>>> I knew we are using a static final field and the JIT compiler doesn't
>>> even generate code for that branch.
>>>
>>> Cheers
>>> Dan
>>> _______________________________________________
>>> infinispan-dev mailing list
>>> infinispan-dev at lists.jboss.org
>>> https://lists.jboss.org/mailman/listinfo/infinispan-dev
>>
>>
>
>
> _______________________________________________
> infinispan-dev mailing list
> infinispan-dev at lists.jboss.org
> https://lists.jboss.org/mailman/listinfo/infinispan-dev
-------------- next part --------------
# {method} {0x00007f0033478a50} 'constantIsTraceEnabled_thrpt_jmhStub' '(Lorg/openjdk/jmh/runner/InfraControl;Lorg/openjdk/jmh/results/RawResults;Lorg/openjdk/jmh/infra/BenchmarkParams;Lorg/openjdk/jmh/infra/IterationParams;Lorg/openjdk/jmh/infra/ThreadParams;Lorg/openjdk/jmh/infra/Blackhole;Lorg/openjdk/jmh/infra/Control;ILorg/infinispan/generated/MyBenchmark_jmhType;)V' in 'org/infinispan/generated/MyBenchmark_constantIsTraceEnabled_jmhTest'
0x00007f00491d9160: call 0x00007f005e4cc0b0  ;   {runtime_call}
0x00007f00491d9165: nop
0x00007f00491d9170: mov
0x00007f00491d9177: push rbp
0x00007f00491d9178: sub rsp,0x40
0x00007f00491d917c: mov rbx
0x00007f00491d917f: mov r13
0x00007f00491d9183: mov r10
0x00007f00491d9187: mov
0x00007f00491d918b: mov rbp
0x00007f00491d918f: mov r14
0x00007f00491d9193: mov rdi,rsi
0x00007f00491d9196: mov r10,0x7f005e56e9e0
0x00007f00491d91a0: call r10
0x00007f00491d91a3: mov r10
0x00007f00491d91a7: test r10,r10
0x00007f00491d91aa: je L0003
0x00007f00491d91b0: mov r11d
0x00007f00491d91b4: cmp r11d,0xf8013e3b  ;   {metadata('org/openjdk/jmh/runner/InfraControl')}
0x00007f00491d91bb: jne L0006
0x00007f00491d91c1: mov r11,r10
             L0000: test rbp,rbp
0x00007f00491d91c7: je L0004
0x00007f00491d91cd: mov r8d
0x00007f00491d91d1: cmp r8d,0xf801403e  ;   {metadata('org/openjdk/jmh/results/RawResults')}
0x00007f00491d91d8: jne L0006
0x00007f00491d91de: mov r9,rbp
             L0001: mov r8d
0x00007f00491d91e5: cmp r8d,0xf801446d  ;   {metadata('org/infinispan/generated/MyBenchmark_jmhType')}
0x00007f00491d91ec: jne L0006
0x00007f00491d91f2: test r11,r11
0x00007f00491d91f5: je L0005
0x00007f00491d91f7: nop  ; - org.infinispan.generated.MyBenchmark_constantIsTraceEnabled_jmhTest::constantIsTraceEnabled_thrpt_jmhStub at 15 (line 113)
             L0002: movzx r10d  ; - org.infinispan.generated.MyBenchmark_constantIsTraceEnabled_jmhTest::constantIsTraceEnabled_thrpt_jmhStub at 25 (line 115)
0x00007f00491d9208: add r13,0x1  ; OopMap{r11=Oop r9=Oop r14=Oop off=172}
                                 ;*ifeq
                                 ; - org.infinispan.generated.MyBenchmark_constantIsTraceEnabled_jmhTest::constantIsTraceEnabled_thrpt_jmhStub at 28 (line 115)
0x00007f00491d920c: test  ;   {poll} *** SAFEPOINT POLL ***
0x00007f00491d9212: test r10d,r10d
0x00007f00491d9215: je L0002  ;*ifeq
                              ; - org.infinispan.generated.MyBenchmark_constantIsTraceEnabled_jmhTest::constantIsTraceEnabled_thrpt_jmhStub at 28 (line 115)
0x00007f00491d9217: mov esi,0xffffff65
0x00007f00491d921c: mov rbp,r11
0x00007f00491d921f: mov
0x00007f00491d9223: mov
0x00007f00491d9228: mov
0x00007f00491d922d: mov
0x00007f00491d9232: mov
0x00007f00491d9237: call 0x00007f00490051a0  ; OopMap{rbp=Oop [0]=Oop [8]=Oop off=220}
                                             ;*ifeq
                                             ; - org.infinispan.generated.MyBenchmark_constantIsTraceEnabled_jmhTest::constantIsTraceEnabled_thrpt_jmhStub at 28 (line 115)
                                             ;   {runtime_call}
0x00007f00491d923c: call 0x00007f005e4cc0b0  ;*ifeq
                                             ; - org.infinispan.generated.MyBenchmark_constantIsTraceEnabled_jmhTest::constantIsTraceEnabled_thrpt_jmhStub at 28 (line 115)
                                             ;   {runtime_call}
             L0003: xor r11d,r11d
0x00007f00491d9244: jmp L0000
             L0004: xor r9d,r9d
0x00007f00491d924c: jmp L0001
0x00007f00491d924e: xor r14d,r14d
             L0005: mov esi,0xffffff86
0x00007f00491d9256: mov rbp,r11
0x00007f00491d9259: mov
0x00007f00491d925d: mov
0x00007f00491d9262: mov
0x00007f00491d9267: mov
0x00007f00491d926c: xchg ax,ax
0x00007f00491d926f: call 0x00007f00490051a0  ; OopMap{rbp=Oop [0]=Oop [8]=Oop off=276}
                                             ;*aload
                                             ; - org.infinispan.generated.MyBenchmark_constantIsTraceEnabled_jmhTest::constantIsTraceEnabled_thrpt_jmhStub at 13 (line 113)
                                             ;   {runtime_call}
0x00007f00491d9274: call 0x00007f005e4cc0b0  ;   {runtime_call}
             L0006: mov esi,0xffffff9d
0x00007f00491d927e: mov
0x00007f00491d9282: mov
0x00007f00491d9287: mov
0x00007f00491d928c: mov
0x00007f00491d9291: xchg ax,ax
0x00007f00491d9293: call 0x00007f00490051a0  ; OopMap{rbp=Oop [0]=Oop [24]=Oop off=312}
                                             ;*aload
                                             ; - org.infinispan.generated.MyBenchmark_constantIsTraceEnabled_jmhTest::constantIsTraceEnabled_thrpt_jmhStub at 13 (line 113)
                                             ;   {runtime_call}
0x00007f00491d9298: call 0x00007f005e4cc0b0  ;*aload
                                             ; - org.infinispan.generated.MyBenchmark_constantIsTraceEnabled_jmhTest::constantIsTraceEnabled_thrpt_jmhStub at 13 (line 113)
                                             ;   {runtime_call}
0x00007f00491d929d: hlt
0x00007f00491d929e: hlt
0x00007f00491d929f: hlt
[Exception Handler]
[Stub Code]
0x00007f00491d92a0: jmp 0x00007f004906c760  ;   {no_reloc}
[Deopt Handler Code]
0x00007f00491d92a5: call 0x00007f00491d92aa
0x00007f00491d92aa: sub
0x00007f00491d92af: jmp 0x00007f00490473c0  ;   {runtime_call}
0x00007f00491d92b4: hlt
0x00007f00491d92b5: hlt
0x00007f00491d92b6: hlt
0x00007f00491d92b7: hlt
-------------- next part --------------
# {method} {0x00007f937f478a50} 'tracef_thrpt_jmhStub' '(Lorg/openjdk/jmh/runner/InfraControl;Lorg/openjdk/jmh/results/RawResults;Lorg/openjdk/jmh/infra/BenchmarkParams;Lorg/openjdk/jmh/infra/IterationParams;Lorg/openjdk/jmh/infra/ThreadParams;Lorg/openjdk/jmh/infra/Blackhole;Lorg/openjdk/jmh/infra/Control;ILorg/infinispan/generated/MyBenchmark_jmhType;)V' in 'org/infinispan/generated/MyBenchmark_tracef_jmhTest'
# parm0:    rsi:rsi   = 'org/openjdk/jmh/runner/InfraControl'
# parm1:    rdx:rdx   = 'org/openjdk/jmh/results/RawResults'
# parm2:    rcx:rcx   = 'org/openjdk/jmh/infra/BenchmarkParams'
# parm3:    r8:r8     = 'org/openjdk/jmh/infra/IterationParams'
# parm4:    r9:r9     = 'org/openjdk/jmh/infra/ThreadParams'
# parm5:    rdi:rdi   = 'org/openjdk/jmh/infra/Blackhole'
# parm6:    [sp+0x30]   = 'org/openjdk/jmh/infra/Control'  (sp of caller)
# parm7:    [sp+0x38]   = int
# parm8:    [sp+0x40]   = 'org/infinispan/generated/MyBenchmark_jmhType'
0x00007f93951e9fa0: mov
0x00007f93951e9fa7: push rbp
0x00007f93951e9fa8: sub rsp,0x20  ;*synchronization entry
                                  ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at -1 (line 109)
0x00007f93951e9fac: mov r13,rsi
0x00007f93951e9faf: mov rbx,rdx
0x00007f93951e9fb2: mov r10,0x7f93aa365ad0
0x00007f93951e9fbc: call r10  ;*invokestatic nanoTime
                              ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 7 (line 111)
0x00007f93951e9fbf: mov  ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 10 (line 111)
                         ; implicit exception: dispatches to 0x00007f93951ea261
0x00007f93951e9fc3: mov r9
0x00007f93951e9fc8: test r9,r9
0x00007f93951e9fcb: je L0012  ;*invokevirtual tracef
                              ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 15 (line 113)
0x00007f93951e9fd1: mov rdx,0x76d4e9898  ;   {oop(a 'org/jboss/logging/JBossLogManagerLogger')}
0x00007f93951e9fdb: mov r10d  ;*getfield logger
                              ; - org.jboss.logging.JBossLogManagerLogger::isEnabled at 1 (line 35)
                              ; - org.jboss.logging.Logger::tracef at 4 (line 287)
                              ; - org.infinispan.MyBenchmark::tracef at 7 (line 26)
                              ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 15 (line 113)
0x00007f93951e9fdf: mov rdi,0x76d4e6d48  ;   {oop(a 'org/jboss/logging/Logger$Level')}
0x00007f93951e9fe9: mov ebp  ; - java.lang.Enum::ordinal at 1 (line 103)
                             ; - org.jboss.logging.JBossLogManagerLogger::translate at 8 (line 58)
                             ; - org.jboss.logging.JBossLogManagerLogger::isEnabled at 5 (line 35)
                             ; - org.jboss.logging.Logger::tracef at 4 (line 287)
                             ; - org.infinispan.MyBenchmark::tracef at 7 (line 26)
                             ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 15 (line 113)
0x00007f93951e9fec: cmp ebp,0x6
0x00007f93951e9fef: jae L0013
0x00007f93951e9ff5: mov r11,0x76d4e9010  ;   {oop([I)}
0x00007f93951e9fff: mov ecx  ;*iaload
                             ; - org.jboss.logging.JBossLogManagerLogger::translate at 11 (line 58)
                             ; - org.jboss.logging.JBossLogManagerLogger::isEnabled at 5 (line 35)
                             ; - org.jboss.logging.Logger::tracef at 4 (line 287)
                             ; - org.infinispan.MyBenchmark::tracef at 7 (line 26)
                             ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 15 (line 113)
0x00007f93951ea004: cmp ecx,0x4
0x00007f93951ea007: je L0005
0x00007f93951ea009: cmp ecx,0x4
0x00007f93951ea00c: jle L0002
0x00007f93951ea00e: cmp ecx,0x6
0x00007f93951ea011: jne L0000
0x00007f93951ea013: mov r8,0x76d4bbc68  ;   {oop(a 'org/jboss/logmanager/Level')}
0x00007f93951ea01d: jmp L0006
             L0000: cmp ecx,0x6
0x00007f93951ea022: jg L0001  ;*tableswitch
                              ; - org.jboss.logging.JBossLogManagerLogger::translate at 12 (line 58)
                              ; - org.jboss.logging.JBossLogManagerLogger::isEnabled at 5 (line 35)
                              ; - org.jboss.logging.Logger::tracef at 4 (line 287)
                              ; - org.infinispan.MyBenchmark::tracef at 7 (line 26)
                              ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 15 (line 113)
0x00007f93951ea024: mov r8,0x76d4bbac8  ;   {oop(a 'org/jboss/logmanager/Level')}
0x00007f93951ea02e: jmp L0006  ;*getstatic ALL
                               ; - org.jboss.logging.JBossLogManagerLogger::translate at 76 (line 66)
                               ; - org.jboss.logging.JBossLogManagerLogger::isEnabled at 5 (line 35)
                               ; - org.jboss.logging.Logger::tracef at 4 (line 287)
                               ; - org.infinispan.MyBenchmark::tracef at 7 (line 26)
                               ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 15 (line 113)
             L0001: mov r8,0x76d444030  ;   {oop(a 'java/util/logging/Level')}
0x00007f93951ea03a: jmp L0006
             L0002: cmp ecx,0x2
0x00007f93951ea03f: je L0004
0x00007f93951ea041: cmp ecx,0x2
0x00007f93951ea044: jle L0003
0x00007f93951ea046: mov r8,0x76d4bb958  ;   {oop(a 'org/jboss/logmanager/Level')}
0x00007f93951ea050: jmp L0006
             L0003: cmp ecx,0x1
0x00007f93951ea055: jne L0001  ;*tableswitch
                               ; - org.jboss.logging.JBossLogManagerLogger::translate at 12 (line 58)
                               ; - org.jboss.logging.JBossLogManagerLogger::isEnabled at 5 (line 35)
                               ; - org.jboss.logging.Logger::tracef at 4 (line 287)
                               ; - org.infinispan.MyBenchmark::tracef at 7 (line 26)
                               ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 15 (line 113)
0x00007f93951ea057: mov r8,0x76d4bb6b8  ;   {oop(a 'org/jboss/logmanager/Level')}
0x00007f93951ea061: jmp L0006
             L0004: mov r8,0x76d4bb848  ;   {oop(a 'org/jboss/logmanager/Level')}
0x00007f93951ea06d: jmp L0006
             L0005: mov r8,0x76d4bba60  ;*invokestatic translate
                                        ; - org.jboss.logging.JBossLogManagerLogger::isEnabled at 5 (line 35)
                                        ; - org.jboss.logging.Logger::tracef at 4 (line 287)
                                        ; - org.infinispan.MyBenchmark::tracef at 7 (line 26)
                                        ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 15 (line 113)
                                        ;   {oop(a 'org/jboss/logmanager/Level')}
             L0006: mov r10d  ;*getfield loggerNode
                              ; - org.jboss.logmanager.Logger::isLoggable at 1 (line 153)
                              ; - org.jboss.logging.JBossLogManagerLogger::isEnabled at 8 (line 35)
                              ; - org.jboss.logging.Logger::tracef at 4 (line 287)
                              ; - org.infinispan.MyBenchmark::tracef at 7 (line 26)
                              ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 15 (line 113)
                              ; implicit exception: dispatches to 0x00007f93951ea275
0x00007f93951ea07e: mov r10d  ;*getfield effectiveLevel
                              ; - org.jboss.logmanager.LoggerNode::getEffectiveLevel at 1 (line 251)
                              ; - org.jboss.logmanager.Logger::isLoggable at 4 (line 153)
                              ; - org.jboss.logging.JBossLogManagerLogger::isEnabled at 8 (line 35)
                              ; - org.jboss.logging.Logger::tracef at 4 (line 287)
                              ; - org.infinispan.MyBenchmark::tracef at 7 (line 26)
                              ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 15 (line 113)
                              ; implicit exception: dispatches to 0x00007f93951ea289
0x00007f93951ea083: mov ebp  ; - java.util.logging.Level::intValue at 1 (line 398)
                             ; - org.jboss.logmanager.Logger::isLoggable at 9 (line 154)
                             ; - org.jboss.logging.JBossLogManagerLogger::isEnabled at 8 (line 35)
                             ; - org.jboss.logging.Logger::tracef at 4 (line 287)
                             ; - org.infinispan.MyBenchmark::tracef at 7 (line 26)
                             ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 15 (line 113)
0x00007f93951ea087: cmp ebp,r10d
0x00007f93951ea08a: jge L0014  ;*if_icmplt
                               ; - org.jboss.logmanager.Logger::isLoggable at 13 (line 154)
                               ; - org.jboss.logging.JBossLogManagerLogger::isEnabled at 8 (line 35)
                               ; - org.jboss.logging.Logger::tracef at 4 (line 287)
                               ; - org.infinispan.MyBenchmark::tracef at 7 (line 26)
                               ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 15 (line 113)
0x00007f93951ea090: mov rcx,r13
0x00007f93951ea093: movzx r10d  ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 25 (line 115)
                                ; implicit exception: dispatches to 0x00007f93951ea299
0x00007f93951ea09b: mov ebp,0x1
0x00007f93951ea0a0: test r10d,r10d
0x00007f93951ea0a3: je L000a  ;*aload_1
                              ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 31 (line 116)
             L0007: mov r10,0x7f93aa365ad0
0x00007f93951ea0af: call r10  ;*invokestatic nanoTime
                              ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 32 (line 116)
0x00007f93951ea0b2: mov  ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 47 (line 118)
0x00007f93951ea0b6: mov  ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 35 (line 116)
0x00007f93951ea0ba: mov  ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 15 (line 113)
0x00007f93951ea0be: add rsp,0x20
0x00007f93951ea0c2: pop rbp
0x00007f93951ea0c3: test  ;   {poll_return} *** SAFEPOINT POLL ***
0x00007f93951ea0c9: ret
0x00007f93951ea0ca: nop
             L0008: mov r8,0x76d4bba60  ;*invokestatic translate
                                        ; - org.jboss.logging.JBossLogManagerLogger::isEnabled at 5 (line 35)
                                        ; - org.jboss.logging.Logger::tracef at 4 (line 287)
                                        ; - org.infinispan.MyBenchmark::tracef at 7 (line 26)
                                        ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 15 (line 113)
                                        ;   {oop(a 'org/jboss/logmanager/Level')}
             L0009: mov r10d  ;*getfield loggerNode
                              ; - org.jboss.logmanager.Logger::isLoggable at 1 (line 153)
                              ; - org.jboss.logging.JBossLogManagerLogger::isEnabled at 8 (line 35)
                              ; - org.jboss.logging.Logger::tracef at 4 (line 287)
                              ; - org.infinispan.MyBenchmark::tracef at 7 (line 26)
                              ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 15 (line 113)
                              ; implicit exception: dispatches to 0x00007f93951ea23d
0x00007f93951ea0df: mov r10d  ;*getfield effectiveLevel
                              ; - org.jboss.logmanager.LoggerNode::getEffectiveLevel at 1 (line 251)
                              ; - org.jboss.logmanager.Logger::isLoggable at 4 (line 153)
                              ; - org.jboss.logging.JBossLogManagerLogger::isEnabled at 8 (line 35)
                              ; - org.jboss.logging.Logger::tracef at 4 (line 287)
                              ; - org.infinispan.MyBenchmark::tracef at 7 (line 26)
                              ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 15 (line 113)
                              ; implicit exception: dispatches to 0x00007f93951ea251
0x00007f93951ea0e4: mov r8d  ; - java.util.logging.Level::intValue at 1 (line 398)
                             ; - org.jboss.logmanager.Logger::isLoggable at 9 (line 154)
                             ; - org.jboss.logging.JBossLogManagerLogger::isEnabled at 8 (line 35)
                             ; - org.jboss.logging.Logger::tracef at 4 (line 287)
                             ; - org.infinispan.MyBenchmark::tracef at 7 (line 26)
                             ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 15 (line 113)
0x00007f93951ea0e8: cmp r8d,r10d
0x00007f93951ea0eb: jge L0011  ;*if_icmplt
                               ; - org.jboss.logmanager.Logger::isLoggable at 13 (line 154)
                               ; - org.jboss.logging.JBossLogManagerLogger::isEnabled at 8 (line 35)
                               ; - org.jboss.logging.Logger::tracef at 4 (line 287)
                               ; - org.infinispan.MyBenchmark::tracef at 7 (line 26)
                               ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 15 (line 113)
0x00007f93951ea0f1: movzx r10d  ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 25 (line 115)
0x00007f93951ea0f9: add rbp,0x1  ; OopMap{r11=Oop r9=Oop rcx=Oop rbx=Oop rdi=Oop rdx=Oop off=349}
                                 ;*ifeq
                                 ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 28 (line 115)
0x00007f93951ea0fd: test  ;   {poll} *** SAFEPOINT POLL ***
0x00007f93951ea103: test r10d,r10d
0x00007f93951ea106: jne L0007  ;*aload
                               ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 13 (line 113)
             L000a: mov r10d  ;*getfield logger
                              ; - org.jboss.logging.JBossLogManagerLogger::isEnabled at 1 (line 35)
                              ; - org.jboss.logging.Logger::tracef at 4 (line 287)
                              ; - org.infinispan.MyBenchmark::tracef at 7 (line 26)
                              ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 15 (line 113)
0x00007f93951ea10c: mov r8d  ; - java.lang.Enum::ordinal at 1 (line 103)
                             ; - org.jboss.logging.JBossLogManagerLogger::translate at 8 (line 58)
                             ; - org.jboss.logging.JBossLogManagerLogger::isEnabled at 5 (line 35)
                             ; - org.jboss.logging.Logger::tracef at 4 (line 287)
                             ; - org.infinispan.MyBenchmark::tracef at 7 (line 26)
                             ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 15 (line 113)
0x00007f93951ea110: cmp r8d,0x6
0x00007f93951ea114: jae L0010
0x00007f93951ea11a: mov r8d  ;*iaload
                             ; - org.jboss.logging.JBossLogManagerLogger::translate at 11 (line 58)
                             ; - org.jboss.logging.JBossLogManagerLogger::isEnabled at 5 (line 35)
                             ; - org.jboss.logging.Logger::tracef at 4 (line 287)
                             ; - org.infinispan.MyBenchmark::tracef at 7 (line 26)
                             ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 15 (line 113)
0x00007f93951ea11f: cmp r8d,0x4
0x00007f93951ea123: je L0008
0x00007f93951ea125: cmp r8d,0x4
0x00007f93951ea129: jle L000d
0x00007f93951ea12b: cmp r8d,0x6
0x00007f93951ea12f: jne L000b
0x00007f93951ea131: mov r8,0x76d4bbc68  ;   {oop(a 'org/jboss/logmanager/Level')}
0x00007f93951ea13b: jmp L0009
             L000b: cmp r8d,0x6
0x00007f93951ea141: jg L000c  ;*tableswitch
                              ; - org.jboss.logging.JBossLogManagerLogger::translate at 12 (line 58)
                              ; - org.jboss.logging.JBossLogManagerLogger::isEnabled at 5 (line 35)
                              ; - org.jboss.logging.Logger::tracef at 4 (line 287)
                              ; - org.infinispan.MyBenchmark::tracef at 7 (line 26)
                              ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 15 (line 113)
0x00007f93951ea143: mov r8,0x76d4bbac8  ;   {oop(a 'org/jboss/logmanager/Level')}
0x00007f93951ea14d: jmp L0009  ;*getstatic ALL
                               ; - org.jboss.logging.JBossLogManagerLogger::translate at 76 (line 66)
                               ; - org.jboss.logging.JBossLogManagerLogger::isEnabled at 5 (line 35)
                               ; - org.jboss.logging.Logger::tracef at 4 (line 287)
                               ; - org.infinispan.MyBenchmark::tracef at 7 (line 26)
                               ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 15 (line 113)
             L000c: mov r8,0x76d444030  ;   {oop(a 'java/util/logging/Level')}
0x00007f93951ea159: jmp L0009
             L000d: cmp r8d,0x2
0x00007f93951ea162: je L000f
0x00007f93951ea164: cmp r8d,0x2
0x00007f93951ea168: jle L000e
0x00007f93951ea16a: mov r8,0x76d4bb958  ;   {oop(a 'org/jboss/logmanager/Level')}
0x00007f93951ea174: jmp L0009
             L000e: cmp r8d,0x1
0x00007f93951ea17d: jne L000c  ;*tableswitch
                               ; - org.jboss.logging.JBossLogManagerLogger::translate at 12 (line 58)
                               ; - org.jboss.logging.JBossLogManagerLogger::isEnabled at 5 (line 35)
                               ; - org.jboss.logging.Logger::tracef at 4 (line 287)
                               ; - org.infinispan.MyBenchmark::tracef at 7 (line 26)
                               ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 15 (line 113)
0x00007f93951ea17f: mov r8,0x76d4bb6b8  ;   {oop(a 'org/jboss/logmanager/Level')}
0x00007f93951ea189: jmp L0009
             L000f: mov r8,0x76d4bb848  ;   {oop(a 'org/jboss/logmanager/Level')}
0x00007f93951ea198: jmp L0009
             L0010: mov esi,0xffffffe4
0x00007f93951ea1a2: mov
0x00007f93951ea1a7: mov
0x00007f93951ea1ac: mov
0x00007f93951ea1b1: mov
0x00007f93951ea1b5: mov
0x00007f93951ea1ba: nop
0x00007f93951ea1bb: call 0x00007f93950051a0  ; OopMap{[48]=Oop [56]=Oop [64]=Oop [0]=NarrowOop off=544}
                                             ;*iaload
                                             ; - org.jboss.logging.JBossLogManagerLogger::translate at 11 (line 58)
                                             ; - org.jboss.logging.JBossLogManagerLogger::isEnabled at 5 (line 35)
                                             ; - org.jboss.logging.Logger::tracef at 4 (line 287)
                                             ; - org.infinispan.MyBenchmark::tracef at 7 (line 26)
                                             ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 15 (line 113)
                                             ;   {runtime_call}
0x00007f93951ea1c0: call 0x00007f93aa3650b0  ;*iaload
                                             ; - org.jboss.logging.JBossLogManagerLogger::translate at 11 (line 58)
                                             ; - org.jboss.logging.JBossLogManagerLogger::isEnabled at 5 (line 35)
                                             ; - org.jboss.logging.Logger::tracef at 4 (line 287)
                                             ; - org.infinispan.MyBenchmark::tracef at 7 (line 26)
                                             ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 15 (line 113)
                                             ;   {runtime_call}
             L0011: mov esi,0xffffff65
0x00007f93951ea1ca: mov
0x00007f93951ea1cf: mov
0x00007f93951ea1d4: mov
0x00007f93951ea1d9: mov
0x00007f93951ea1de: mov
0x00007f93951ea1e3: call 0x00007f93950051a0  ; OopMap{[48]=Oop [56]=Oop [64]=Oop off=584}
                                             ;*if_icmplt
                                             ; - org.jboss.logmanager.Logger::isLoggable at 13 (line 154)
                                             ; - org.jboss.logging.JBossLogManagerLogger::isEnabled at 8 (line 35)
                                             ; - org.jboss.logging.Logger::tracef at 4 (line 287)
                                             ; - org.infinispan.MyBenchmark::tracef at 7 (line 26)
                                             ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 15 (line 113)
                                             ;   {runtime_call}
0x00007f93951ea1e8: call 0x00007f93aa3650b0  ;   {runtime_call}
             L0012: mov esi,0xfffffff6
0x00007f93951ea1f2: nop
0x00007f93951ea1f3: call 0x00007f93950051a0  ; OopMap{off=600}
                                             ;*invokevirtual tracef
                                             ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 15 (line 113)
                                             ;   {runtime_call}
0x00007f93951ea1f8: call 0x00007f93aa3650b0  ;   {runtime_call}
             L0013: mov esi,0xffffffe4
0x00007f93951ea202: mov
0x00007f93951ea207: mov
0x00007f93951ea20c: mov
0x00007f93951ea210: xchg ax,ax
0x00007f93951ea213: call 0x00007f93950051a0  ; OopMap{[48]=Oop [56]=Oop [64]=Oop [0]=NarrowOop off=632}
                                             ;*iaload
                                             ; - org.jboss.logging.JBossLogManagerLogger::translate at 11 (line 58)
                                             ; - org.jboss.logging.JBossLogManagerLogger::isEnabled at 5 (line 35)
                                             ; - org.jboss.logging.Logger::tracef at 4 (line 287)
                                             ; - org.infinispan.MyBenchmark::tracef at 7 (line 26)
                                             ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 15 (line 113)
                                             ;   {runtime_call}
0x00007f93951ea218: call 0x00007f93aa3650b0  ;*iaload
                                             ; - org.jboss.logging.JBossLogManagerLogger::translate at 11 (line 58)
                                             ; - org.jboss.logging.JBossLogManagerLogger::isEnabled at 5 (line 35)
                                             ; - org.jboss.logging.Logger::tracef at 4 (line 287)
                                             ; - org.infinispan.MyBenchmark::tracef at 7 (line 26)
                                             ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 15 (line 113)
                                             ;   {runtime_call}
             L0014: mov esi,0xffffff65
0x00007f93951ea222: mov
0x00007f93951ea227: mov
0x00007f93951ea22c: mov
0x00007f93951ea231: xchg ax,ax
0x00007f93951ea233: call 0x00007f93950051a0  ; OopMap{[48]=Oop [56]=Oop [64]=Oop off=664}
                                             ;*if_icmplt
                                             ; - org.jboss.logmanager.Logger::isLoggable at 13 (line 154)
                                             ; - org.jboss.logging.JBossLogManagerLogger::isEnabled at 8 (line 35)
                                             ; - org.jboss.logging.Logger::tracef at 4 (line 287)
                                             ; - org.infinispan.MyBenchmark::tracef at 7 (line 26)
                                             ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 15 (line 113)
                                             ;   {runtime_call}
0x00007f93951ea238: call 0x00007f93aa3650b0  ;*if_icmplt
                                             ; - org.jboss.logmanager.Logger::isLoggable at 13 (line 154)
                                             ; - org.jboss.logging.JBossLogManagerLogger::isEnabled at 8 (line 35)
                                             ; - org.jboss.logging.Logger::tracef at 4 (line 287)
                                             ; - org.infinispan.MyBenchmark::tracef at 7 (line 26)
                                             ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 15 (line 113)
                                             ;   {runtime_call}
0x00007f93951ea23d: mov esi,0xfffffff6
0x00007f93951ea242: mov rbp,r8
0x00007f93951ea245: xchg ax,ax
0x00007f93951ea247: call 0x00007f93950051a0  ; OopMap{rbp=Oop off=684}
                                             ;*invokevirtual isLoggable
                                             ; - org.jboss.logging.JBossLogManagerLogger::isEnabled at 8 (line 35)
                                             ; - org.jboss.logging.Logger::tracef at 4 (line 287)
                                             ; - org.infinispan.MyBenchmark::tracef at 7 (line 26)
                                             ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 15 (line 113)
                                             ;   {runtime_call}
0x00007f93951ea24c: call 0x00007f93aa3650b0  ;*invokevirtual isLoggable
                                             ; - org.jboss.logging.JBossLogManagerLogger::isEnabled at 8 (line 35)
                                             ; - org.jboss.logging.Logger::tracef at 4 (line 287)
                                             ; - org.infinispan.MyBenchmark::tracef at 7 (line 26)
                                             ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 15 (line 113)
                                             ;   {runtime_call}
0x00007f93951ea251: mov esi,0xfffffff6
0x00007f93951ea256: nop
0x00007f93951ea257: call 0x00007f93950051a0  ; OopMap{off=700}
                                             ;*invokevirtual getEffectiveLevel
                                             ; - org.jboss.logmanager.Logger::isLoggable at 4 (line 153)
                                             ; - org.jboss.logging.JBossLogManagerLogger::isEnabled at 8 (line 35)
                                             ; - org.jboss.logging.Logger::tracef at 4 (line 287)
                                             ; - org.infinispan.MyBenchmark::tracef at 7 (line 26)
                                             ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 15 (line 113)
                                             ;   {runtime_call}
0x00007f93951ea25c: call 0x00007f93aa3650b0  ;*invokevirtual getEffectiveLevel
                                             ; - org.jboss.logmanager.Logger::isLoggable at 4 (line 153)
                                             ; - org.jboss.logging.JBossLogManagerLogger::isEnabled at 8 (line 35)
                                             ; - org.jboss.logging.Logger::tracef at 4 (line 287)
                                             ; - org.infinispan.MyBenchmark::tracef at 7 (line 26)
                                             ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 15 (line 113)
                                             ;   {runtime_call}
0x00007f93951ea261: mov esi,0xfffffff6
0x00007f93951ea266: mov rbp,rax
0x00007f93951ea269: xchg ax,ax
0x00007f93951ea26b: call 0x00007f93950051a0  ; OopMap{off=720}
                                             ;*putfield startTime
                                             ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 10 (line 111)
                                             ;   {runtime_call}
0x00007f93951ea270: call 0x00007f93aa3650b0  ;   {runtime_call}
0x00007f93951ea275: mov esi,0xfffffff6
0x00007f93951ea27a: mov rbp,r8
0x00007f93951ea27d: xchg ax,ax
0x00007f93951ea27f: call 0x00007f93950051a0  ; OopMap{rbp=Oop off=740}
                                             ;*invokevirtual isLoggable
                                             ; - org.jboss.logging.JBossLogManagerLogger::isEnabled at 8 (line 35)
                                             ; - org.jboss.logging.Logger::tracef at 4 (line 287)
                                             ; - org.infinispan.MyBenchmark::tracef at 7 (line 26)
                                             ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 15 (line 113)
                                             ;   {runtime_call}
0x00007f93951ea284: call 0x00007f93aa3650b0  ;   {runtime_call}
0x00007f93951ea289: mov esi,0xfffffff6
0x00007f93951ea28e: nop
0x00007f93951ea28f: call 0x00007f93950051a0  ; OopMap{off=756}
                                             ;*invokevirtual getEffectiveLevel
                                             ; - org.jboss.logmanager.Logger::isLoggable at 4 (line 153)
                                             ; - org.jboss.logging.JBossLogManagerLogger::isEnabled at 8 (line 35)
                                             ; - org.jboss.logging.Logger::tracef at 4 (line 287)
                                             ; - org.infinispan.MyBenchmark::tracef at 7 (line 26)
                                             ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 15 (line 113)
                                             ;   {runtime_call}
0x00007f93951ea294: call 0x00007f93aa3650b0  ;*invokevirtual getEffectiveLevel
                                             ; - org.jboss.logmanager.Logger::isLoggable at 4 (line 153)
                                             ; - org.jboss.logging.JBossLogManagerLogger::isEnabled at 8 (line 35)
                                             ; - org.jboss.logging.Logger::tracef at 4 (line 287)
                                             ; - org.infinispan.MyBenchmark::tracef at 7 (line 26)
                                             ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 15 (line 113)
                                             ;   {runtime_call}
0x00007f93951ea299: mov esi,0xfffffff6
0x00007f93951ea29e: nop
0x00007f93951ea29f: call 0x00007f93950051a0  ; OopMap{off=772}
                                             ;*getfield isDone
                                             ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 25 (line 115)
                                             ;   {runtime_call}
0x00007f93951ea2a4: call 0x00007f93aa3650b0  ;*getfield isDone
                                             ; - org.infinispan.generated.MyBenchmark_tracef_jmhTest::tracef_thrpt_jmhStub at 25 (line 115)
                                             ;   {runtime_call}
0x00007f93951ea2a9: hlt
0x00007f93951ea2aa: hlt
0x00007f93951ea2ab: hlt
0x00007f93951ea2ac: hlt
0x00007f93951ea2ad: hlt
0x00007f93951ea2ae: hlt
0x00007f93951ea2af: hlt
0x00007f93951ea2b0: hlt
0x00007f93951ea2b1: hlt
0x00007f93951ea2b2: hlt
0x00007f93951ea2b3: hlt
0x00007f93951ea2b4: hlt
0x00007f93951ea2b5: hlt
0x00007f93951ea2b6: hlt
0x00007f93951ea2b7: hlt
0x00007f93951ea2b8: hlt
0x00007f93951ea2b9: hlt
0x00007f93951ea2ba: hlt
0x00007f93951ea2bb: hlt
0x00007f93951ea2bc: hlt
0x00007f93951ea2bd: hlt
0x00007f93951ea2be: hlt
0x00007f93951ea2bf: hlt
[Exception Handler]
[Stub Code]
0x00007f93951ea2c0: jmp 0x00007f93950f94a0  ;   {no_reloc}
[Deopt Handler Code]
0x00007f93951ea2c5: call 0x00007f93951ea2ca
0x00007f93951ea2ca: sub
0x00007f93951ea2cf: jmp 0x00007f93950473c0  ;   {runtime_call}
0x00007f93951ea2d4: hlt
0x00007f93951ea2d5: hlt
0x00007f93951ea2d6: hlt
0x00007f93951ea2d7: hlt


More information about the infinispan-dev mailing list