logging-log4j-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Remko Popma <remko.po...@gmail.com>
Subject Re: No for each loop comment?
Date Sat, 27 Sep 2014 14:29:50 GMT
I think we have consensus that in this performance-sensitive code it is
better to be safe and use a normal for loop.
I've taken the liberty to make the change in master.

On Sat, Sep 27, 2014 at 2:28 AM, Ralph Goers <ralph.goers@dslextreme.com>
wrote:

> While true,  if it is coded as an old-style for loop their is nothing
> really to be gained by converting it to a foreach except for making people
> happy that it uses the newer syntax. Even if Java is changed so that they
> are equivalent it won’t be faster.
>
> Ralph
>
> On Sep 26, 2014, at 8:59 AM, Paul Benedict <pbenedict@apache.org> wrote:
>
> My recommendation is to write the core openjdk making list. Raise this
> issue and see what they say about your findings... because there is not
> supposed to be any performance impact using foreach.
> On Sep 26, 2014 10:34 AM, "Mikael Ståldal" <
> mikael.staldal@appearnetworks.com> wrote:
>
>> 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