logging-log4j-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Mikael Ståldal <mikael.stal...@appearnetworks.com>
Subject Re: No for each loop comment?
Date Fri, 26 Sep 2014 15:34:18 GMT
The byte code is actually different. This seems like a weakness of the JDK
Javac to me.

With standard loop:

  private static boolean contains(org.apache.logging.log4j.Marker,
org.apache.logging.log4j.Marker...);
    Code:
       0: iconst_0
       1: istore_2
       2: aload_1
       3: arraylength
       4: istore_3
       5: iload_2
       6: iload_3
       7: if_icmpge     29
      10: aload_1
      11: iload_2
      12: aaload
      13: astore        4
      15: aload         4
      17: aload_0
      18: if_acmpne     23
      21: iconst_1
      22: ireturn
      23: iinc          2, 1
      26: goto          5
      29: iconst_0
      30: ireturn


With for-each:

  private static boolean contains(org.apache.logging.log4j.Marker,
org.apache.logging.log4j.Marker...);
    Code:
       0: aload_1
       1: astore_2
       2: aload_2
       3: arraylength
       4: istore_3
       5: iconst_0
       6: istore        4
       8: iload         4
      10: iload_3
      11: if_icmpge     34
      14: aload_2
      15: iload         4
      17: aaload
      18: astore        5
      20: aload         5
      22: aload_0
      23: if_acmpne     28
      26: iconst_1
      27: ireturn
      28: iinc          4, 1
      31: goto          8
      34: iconst_0
      35: ireturn


On Fri, Sep 26, 2014 at 4:27 PM, Remko Popma <remko.popma@gmail.com> wrote:

> Nope. Maybe I'll get around that next week. If you have time to do that,
> please share!
>
> On Fri, Sep 26, 2014 at 11:23 PM, Mikael Ståldal <
> mikael.staldal@appearnetworks.com> wrote:
>
>> Have you compared the generated byte code (using javap -c) for the two
>> cases?
>>
>> On Fri, Sep 26, 2014 at 3:43 PM, Remko Popma <remko.popma@gmail.com>
>> wrote:
>>
>>> On Windows it looks like normal for loops are slightly faster than
>>> for-each loops, especially for small arrays of primitives. This could be
>>> noise, since we are talking about 5 nanoseconds where the baseline (an
>>> empty method invocation) is 12 nanos.
>>>
>>> On Solaris 10 and Red Hat Enterprise Linux the baseline is so large (255
>>> nanos and 1910 nanos respectively) that any difference we are seeing is
>>> just noise.
>>>
>>> All benchmarks were run with one fork, one thread, 10 warmup iterations
>>> and 10 test iterations.
>>>
>>> *Windows 7 (64bit) with Java 1.8.0_05, 2-core Intel i5-3317u CPU
>>> @1.70Ghz with hyperthreading switched on (4 virtual cores)*
>>> Benchmark                                                Mode  Samples
>>>    Score  Score error  Units
>>> o.a.l.l.p.j.LoopsBenchmark.baseline                    sample   154947
>>>   12.432        0.550  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.intArray10000ForEachLoop    sample   126597
>>> 2759.592        3.431  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.intArray10000ForLoop        sample   126494
>>> 2761.729        3.127  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.intArray1000ForEachLoop     sample   154124
>>>  292.880        1.065  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.intArray1000ForLoop         sample   156155
>>>  288.751        1.101  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.intArray100ForEachLoop      sample   191980
>>>   41.826        0.870  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.intArray100ForLoop          sample   193770
>>>   36.894        0.782  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.intArray10ForEachLoop       sample   190847
>>>   22.393        0.618  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.intArray10ForLoop           sample   192552
>>>   17.146        0.560  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.objArray10000ForEachLoop    sample   173839
>>>  31959.057       14.341  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.objArray10000ForLoop        sample   171137
>>>  32461.985       14.353  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.objArray1000ForEachLoop     sample    97495
>>> 3591.200        4.852  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.objArray1000ForLoop         sample   101560
>>> 3445.998        4.010  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.objArray100ForEachLoop      sample   102796
>>>  438.207        1.923  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.objArray100ForLoop          sample   102333
>>>  439.576        2.139  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.objArray10ForEachLoop       sample   113924
>>>   58.957        1.247  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.objArray10ForLoop           sample   120416
>>>   60.712        1.284  ns/op
>>>
>>>
>>> // For loops for Object arrays are similar but return the total XOR of
>>> the element hashcodes.
>>>
>>> private int forEachLoop(final int[] array) {
>>>     int result = 0;
>>>     for (final int element : array) {
>>>         result ^= element;
>>>     }
>>>     return result;
>>> }
>>>
>>> private int forLoop(final int[] array) {
>>>     int result = 0;
>>>     for (int i = 0; i < array.length; i++) {
>>>         result ^= array[i];
>>>     }
>>>     return result;
>>> }
>>>
>>>
>>>
>>> *Solaris 10 (64bit) with JDK1.7.0_06-b24 (Oracle Hotspot), 2 quad-core
>>> Xeon X5570 dual CPUs @2.93Ghz with hyperthreading switched on (16 virtual
>>> cores)*
>>> Benchmark                                                Mode  Samples
>>>    Score  Score error  Units
>>> o.a.l.l.p.j.LoopsBenchmark.baseline                    sample   110212
>>>  255.300        0.201  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.intArray10000ForEachLoop    sample   187808
>>> 3938.055        1.207  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.intArray10000ForLoop        sample   187897
>>> 3937.929        0.748  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.intArray1000ForEachLoop     sample   123989
>>>  606.631        0.626  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.intArray1000ForLoop         sample   123973
>>>  609.565        0.416  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.intArray100ForEachLoop      sample   126933
>>>  294.204        0.280  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.intArray100ForLoop          sample   127070
>>>  296.411        0.223  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.intArray10ForEachLoop       sample   113400
>>>  261.519        0.181  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.intArray10ForLoop           sample   111637
>>>  260.435        0.115  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.objArray10000ForEachLoop    sample   115872
>>>  48154.673       18.846  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.objArray10000ForLoop        sample   116777
>>>  47793.868       17.615  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.objArray1000ForEachLoop     sample   138432
>>> 5256.767        2.451  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.objArray1000ForLoop         sample   136644
>>> 5325.377        2.388  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.objArray100ForEachLoop      sample   166653
>>>  773.541        0.330  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.objArray100ForLoop          sample   166570
>>>  774.513        0.574  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.objArray10ForEachLoop       sample   178754
>>>  317.232        0.134  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.objArray10ForLoop           sample   180165
>>>  316.189        0.238  ns/op
>>>
>>> *64 bit RHEL 6.5 (Linux 2.6.32-431.el6.x86_64) with JDK1.7.0_05-b06
>>> (Oracle Hotspot), 4 quad-core Xeon X5570 CPUs @2.93GHz with hyperthreading
>>> switched on (16 virtual cores)*
>>> Benchmark                                                Mode  Samples
>>>    Score  Score error  Units
>>> o.a.l.l.p.j.LoopsBenchmark.baseline                    sample   114783
>>> 1910.576       29.256  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.intArray10000ForEachLoop    sample   194584
>>> 5132.885       25.137  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.intArray10000ForLoop        sample   196672
>>> 4811.572       52.072  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.intArray1000ForEachLoop     sample   133119
>>> 1967.213       28.970  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.intArray1000ForLoop         sample   133804
>>> 2004.501       31.554  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.intArray100ForEachLoop      sample   142439
>>> 1575.329        6.457  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.intArray100ForLoop          sample   142215
>>> 1957.714       27.815  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.intArray10ForEachLoop       sample   130826
>>> 1980.301       30.818  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.intArray10ForLoop           sample   132654
>>> 1589.120        8.449  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.objArray10000ForEachLoop    sample   126947
>>>  43301.320       50.589  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.objArray10000ForLoop        sample   126117
>>>  43574.129       55.272  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.objArray1000ForEachLoop     sample   143697
>>> 5831.250       19.667  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.objArray1000ForLoop         sample   163244
>>> 4823.096       13.180  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.objArray100ForEachLoop      sample   162502
>>> 1930.819       24.136  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.objArray100ForLoop          sample   171619
>>> 1625.806       10.385  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.objArray10ForEachLoop       sample   172226
>>> 1888.683       22.554  ns/op
>>> o.a.l.l.p.j.LoopsBenchmark.objArray10ForLoop           sample   188838
>>> 1581.979        6.322  ns/op
>>>
>>>
>>>
>>>
>>> On Fri, Sep 26, 2014 at 2:56 AM, Matt Sicker <boards@gmail.com> wrote:
>>>
>>>> The foreach over an array looks like it's supposed to compile to the
>>>> same thing:
>>>>
>>>> https://jcp.org/aboutJava/communityprocess/jsr/tiger/enhanced-for.html
>>>>
>>>> Same goes for .length which is supposed to be a final field which would
>>>> allow for inlining by the JIT I'd imagine (hence why we use final
>>>> everywhere):
>>>>
>>>> http://docs.oracle.com/javase/specs/jls/se7/html/jls-10.html#jls-10.7
>>>>
>>>> On 25 September 2014 11:33, Gary Gregory <garydgregory@gmail.com>
>>>> wrote:
>>>>
>>>>> On Thu, Sep 25, 2014 at 11:55 AM, Ralph Goers <
>>>>> ralph.goers@dslextreme.com> wrote:
>>>>>
>>>>>> You can think that, but the testing in the testing I did at the time
>>>>>> the difference was quite noticeable.  I would have left it as a foreach
if
>>>>>> it wasn’t.
>>>>>>
>>>>>> Ralph
>>>>>>
>>>>>> On Sep 25, 2014, at 8:51 AM, Paul Benedict <pbenedict@apache.org>
>>>>>> wrote:
>>>>>>
>>>>>> I would be surprised if foreach over an array makes a speed
>>>>>> difference. AFAIK, foreach is synatic sugar. There is no iterator
for an
>>>>>> array so it has to be desugared using a for/index loop like you have
there.
>>>>>> I don't think this code is saving anything.
>>>>>>
>>>>>>
>>>>>> Cheers,
>>>>>> Paul
>>>>>>
>>>>>> On Thu, Sep 25, 2014 at 10:47 AM, Remko Popma <remko.popma@gmail.com>
>>>>>> wrote:
>>>>>>
>>>>>>> Hm.. Why did I think it was configuration? I must have gotten
mixed
>>>>>>> up with another commit email...
>>>>>>> The class is MarkerManager in log4j-api.
>>>>>>>
>>>>>>> On Fri, Sep 26, 2014 at 12:18 AM, Ralph Goers <
>>>>>>> ralph.goers@dslextreme.com> wrote:
>>>>>>>
>>>>>>>> Configuration?  If I recall correctly this method is called
on
>>>>>>>> every log event that contains a Marker.  But I am just guessing
since Gary
>>>>>>>> neglected to say what class this is.  But I do remember doing
extensive
>>>>>>>> testing when this code was written.  And I also remember
someone (probably
>>>>>>>> Gary) mentioning then that it should use a for-loop and we
had this same
>>>>>>>> conversation then.  I think that is why the comment was added.
>>>>>>>>
>>>>>>>> Ralph
>>>>>>>>
>>>>>>>> On Sep 24, 2014, at 9:10 PM, Remko Popma <remko.popma@gmail.com>
>>>>>>>> wrote:
>>>>>>>>
>>>>>>>>
>>>>>>>> On 2014/09/25, at 12:46, Matt Sicker <boards@gmail.com>
wrote:
>>>>>>>>
>>>>>>>> From what I remember, it had something to do with the incredibly
>>>>>>>> large difference in speed between for loops and foreach loops
on arrays.
>>>>>>>> And by incredibly large, I mean most likely negligible.
>>>>>>>>
>>>>>>>> :-)
>>>>>>>> I do remember reading that someone found a speed difference.
But
>>>>>>>> I've never verified it. (Note to self: write a quick jmh
benchmark for
>>>>>>>> this.)
>>>>>>>>
>>>>>>>>
>>>>> I'd be curious to see the results!
>>>>>
>>>>> Gary
>>>>>
>>>>>
>>>>>>
>>>>>>>> On the other hand, this is configuration, so it only happens
once
>>>>>>>> and is very unlikely to be "hot" code so there is probably
not much value
>>>>>>>> in optimizing this loop.
>>>>>>>>
>>>>>>>>
>>>>>>>> On 24 September 2014 22:12, Gary Gregory <garydgregory@gmail.com>
>>>>>>>> wrote:
>>>>>>>>
>>>>>>>>> Why does this "//noinspection ForLoopReplaceableByForEach"
comment
>>>>>>>>> mean?
>>>>>>>>>
>>>>>>>>> Why not for an enhanced for each loop?
>>>>>>>>>
>>>>>>>>>  private static boolean contains(final Marker parent,
final
>>>>>>>>> Marker... localParents) {
>>>>>>>>>             //noinspection ForLoopReplaceableByForEach
>>>>>>>>>             for (int i = 0, localParentsLength =
>>>>>>>>> localParents.length; i < localParentsLength; i++)
{
>>>>>>>>>                 final Marker marker = localParents[i];
>>>>>>>>>                 if (marker == parent) {
>>>>>>>>>                     return true;
>>>>>>>>>                 }
>>>>>>>>>             }
>>>>>>>>>             return false;
>>>>>>>>>         }
>>>>>>>>>
>>>>>>>>> Thanks,
>>>>>>>>> Gary
>>>>>>>>>
>>>>>>>>> --
>>>>>>>>> E-Mail: garydgregory@gmail.com | ggregory@apache.org
>>>>>>>>> Java Persistence with Hibernate, Second Edition
>>>>>>>>> <http://www.manning.com/bauer3/>
>>>>>>>>> JUnit in Action, Second Edition <http://www.manning.com/tahchiev/>
>>>>>>>>> Spring Batch in Action <http://www.manning.com/templier/>
>>>>>>>>> Blog: http://garygregory.wordpress.com
>>>>>>>>> Home: http://garygregory.com/
>>>>>>>>> Tweet! http://twitter.com/GaryGregory
>>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>> --
>>>>>>>> Matt Sicker <boards@gmail.com>
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>
>>>>>>
>>>>>>
>>>>>
>>>>>
>>>>> --
>>>>> E-Mail: garydgregory@gmail.com | ggregory@apache.org
>>>>> Java Persistence with Hibernate, Second Edition
>>>>> <http://www.manning.com/bauer3/>
>>>>> JUnit in Action, Second Edition <http://www.manning.com/tahchiev/>
>>>>> Spring Batch in Action <http://www.manning.com/templier/>
>>>>> Blog: http://garygregory.wordpress.com
>>>>> Home: http://garygregory.com/
>>>>> Tweet! http://twitter.com/GaryGregory
>>>>>
>>>>
>>>>
>>>>
>>>> --
>>>> Matt Sicker <boards@gmail.com>
>>>>
>>>
>>>
>>
>>
>> --
>> Mikael Ståldal
>> Chief Software Architect
>> *Appear*
>> Phone: +46 8 545 91 572
>> Email: mikael.staldal@appearnetworks.com
>>
>
>


-- 
Mikael Ståldal
Chief Software Architect
*Appear*
Phone: +46 8 545 91 572
Email: mikael.staldal@appearnetworks.com

Mime
View raw message