Beefy Boxes and Bandwidth Generously Provided by pair Networks
XP is just a number
 
PerlMonks  

5:10: Why is this slower than 5.8.8?

by jk2addict (Chaplain)
on Dec 23, 2007 at 00:40 UTC ( #658723=perlquestion: print w/ replies, xml ) Need Help??
jk2addict has asked for the wisdom of the Perl Monks concerning the following question:

This all started with a report from a user about Class::Accessor::Grouped being much slower on 5.10 compared to 5.8.8.

At this point, I call 'not it'...but only because I really don't know what in the hell is going on. Two brand new fresh FreeBSD 6.2 installs. One with a a compiled (not ports) Perl 5.8.8 and the other with a compiled 5.10.0.

The test case is simple set_inherited, sans C::A::G in the picture, since the reporter noted set was slower as well (which BTW has no MRO interaction):

#test.pl use lib '.'; use Foo; use Benchmark ':all'; my $f = bless {}, 'Foo'; timethese(0, { set_inherited_class => sub {Foo->set_inherited('bar', 'baz')}, set_inherited_object => sub {$f->set_inherited('bar', 'baz')} }); ##Foo.pm package Foo; use Scalar::Util qw/blessed reftype/; sub set_inherited { my ($self, $set, $val) = @_; if (blessed $self) { if (reftype $self eq 'HASH') { return $self->{$set} = $val; } else { croak('Cannot set inherited value on an object instance th +at is not hash-based'); }; } else { no strict 'refs'; return ${$self.'::__cag_'.$set} = $val; }; } 1;

The results are:

Perl 5.8.8 Machine: > Benchmark: running set_inherited_class, set_inherited_object for at +least 3 CPU seconds... > set_inherited_class: 4 wallclock secs ( 3.16 usr + 0.00 sys = 3.1 +6 CPU) @ 575596.40/s (n=1821223) > set_inherited_object: 3 wallclock secs ( 3.16 usr + -0.01 sys = 3. +15 CPU) @ 687794.82/s (n=2165479) > claco@fbsd588 ~ $ Perl 5.10.0 Machine: > Benchmark: running set_inherited_class, set_inherited_object for at +least 3 CPU seconds... > set_inherited_class: 3 wallclock secs ( 3.12 usr + 0.01 sys = 3.1 +3 CPU) @ 335388.09/s (n=1050708) > set_inherited_object: 2 wallclock secs ( 3.15 usr + 0.00 sys = 3. +15 CPU) @ 412676.76/s (n=1299287) > claco@fbsd510 ~ $

My to my shock, if I whittle down the code in set_inherited to just this:

package Foo; use Scalar::Util qw/blessed reftype/; sub set_inherited { my ($self, $set, $val) = @_; } 1;

performance still seriouesly sucks:

5.8.8 > Benchmark: running set_inherited_class, set_inherited_object for at +least 3 CPU seconds... > set_inherited_class: 3 wallclock secs ( 3.08 usr + 0.02 sys = 3.0 +9 CPU) @ 1199923.07/s (n=3712262) > set_inherited_object: 4 wallclock secs ( 3.27 usr + 0.00 sys = 3. +27 CPU) @ 1380589.06/s (n=4519272) > claco@fbsd588 ~ $ 5.10.0 > Benchmark: running set_inherited_class, set_inherited_object for at +least 3 CPU seconds... > set_inherited_class: 4 wallclock secs ( 3.09 usr + 0.01 sys = 3.1 +0 CPU) @ 536733.34/s (n=1664712) > set_inherited_object: 4 wallclock secs ( 3.13 usr + 0.00 sys = 3. +13 CPU) @ 638055.42/s (n=1998908) > claco@fbsd510 ~ $

A this point, I'm stumped. my ($, $, $) = @_; is a common idiom. Changing to this makes 5.10 faster.

package Foo; use Scalar::Util qw/blessed reftype/; sub set_inherited { my $self = shift; my $set = shift; my $val = shift; } 1;

I know shift is always faster than assigning @_, but the performaance difference of assigning @_ on 5.10 vs. 5.8.8 is worrysome to me.

Updated with -V output

Summary of my perl5 (revision 5 version 8 subversion 8) configuration: Platform: osname=freebsd, osvers=6.2-release, archname=i386-freebsd uname='freebsd fbsd588.local 6.2-release freebsd 6.2-release #0: f +ri jan 12 10:40:27 utc 2007 root@dessler.cse.buffalo.edu:usrobjusrsrc +sysgeneric i386 ' config_args='-de' hint=recommended, useposix=true, d_sigaction=define usethreads=undef use5005threads=undef useithreads=undef usemultipl +icity=undef useperlio=define d_sfio=undef uselargefiles=define usesocks=undef use64bitint=undef use64bitall=undef uselongdouble=undef usemymalloc=n, bincompat5005=undef Compiler: cc='cc', ccflags ='-DHAS_FPSETMASK -DHAS_FLOATINGPOINT_H -fno-stri +ct-aliasing -pipe -Wdeclaration-after-statement -I/usr/local/include' +, optimize='-O', cppflags='-DHAS_FPSETMASK -DHAS_FLOATINGPOINT_H -fno-strict-aliasi +ng -pipe -Wdeclaration-after-statement -I/usr/local/include' ccversion='', gccversion='3.4.6 [FreeBSD] 20060305', gccosandvers= +'' intsize=4, longsize=4, ptrsize=4, doublesize=8, byteorder=1234 d_longlong=define, longlongsize=8, d_longdbl=define, longdblsize=1 +2 ivtype='long', ivsize=4, nvtype='double', nvsize=8, Off_t='off_t', + lseeksize=8 alignbytes=4, prototype=define Linker and Libraries: ld='cc', ldflags ='-Wl,-E -L/usr/local/lib' libpth=/usr/lib /usr/local/lib libs=-lm -lcrypt -lutil -lc perllibs=-lm -lcrypt -lutil -lc libc=, so=so, useshrplib=false, libperl=libperl.a gnulibc_version='' Dynamic Linking: dlsrc=dl_dlopen.xs, dlext=so, d_dlsymun=undef, ccdlflags=' ' cccdlflags='-DPIC -fPIC', lddlflags='-shared -L/usr/local/lib' Characteristics of this binary (from libperl): Compile-time options: PERL_MALLOC_WRAP USE_LARGE_FILES USE_PERLIO Built under freebsd Compiled at Dec 22 2007 15:52:43 @INC: /usr/local/lib/perl5/5.8.8/i386-freebsd /usr/local/lib/perl5/5.8.8 /usr/local/lib/perl5/site_perl/5.8.8/i386-freebsd /usr/local/lib/perl5/site_perl/5.8.8 /usr/local/lib/perl5/site_perl . ------------- Summary of my perl5 (revision 5 version 10 subversion 0) configuration +: Platform: osname=freebsd, osvers=6.2-release, archname=i386-freebsd uname='freebsd fbsd510.local 6.2-release freebsd 6.2-release #0: f +ri jan 12 10:40:27 utc 2007 root@dessler.cse.buffalo.edu:usrobjusrsrc +sysgeneric i386 ' config_args='' hint=recommended, useposix=true, d_sigaction=define useithreads=undef, usemultiplicity=undef useperlio=define, d_sfio=undef, uselargefiles=define, usesocks=und +ef use64bitint=undef, use64bitall=undef, uselongdouble=undef usemymalloc=n, bincompat5005=undef Compiler: cc='cc', ccflags ='-DHAS_FPSETMASK -DHAS_FLOATINGPOINT_H -fno-stri +ct-aliasing -pipe -I/usr/local/include', optimize='-O', cppflags='-DHAS_FPSETMASK -DHAS_FLOATINGPOINT_H -fno-strict-aliasi +ng -pipe -I/usr/local/include' ccversion='', gccversion='3.4.6 [FreeBSD] 20060305', gccosandvers= +'' intsize=4, longsize=4, ptrsize=4, doublesize=8, byteorder=1234 d_longlong=define, longlongsize=8, d_longdbl=define, longdblsize=1 +2 ivtype='long', ivsize=4, nvtype='double', nvsize=8, Off_t='off_t', + lseeksize=8 alignbytes=4, prototype=define Linker and Libraries: ld='cc', ldflags ='-Wl,-E -L/usr/local/lib' libpth=/usr/lib /usr/local/lib libs=-lm -lcrypt -lutil -lc perllibs=-lm -lcrypt -lutil -lc libc=, so=so, useshrplib=false, libperl=libperl.a gnulibc_version='' Dynamic Linking: dlsrc=dl_dlopen.xs, dlext=so, d_dlsymun=undef, ccdlflags=' ' cccdlflags='-DPIC -fPIC', lddlflags='-shared -L/usr/local/lib' Characteristics of this binary (from libperl): Compile-time options: PERL_DONT_CREATE_GVSV PERL_MALLOC_WRAP USE_LARGE_FILES USE_PERLIO Built under freebsd Compiled at Dec 22 2007 17:32:47 @INC: /usr/local/lib/perl5/5.10.0/i386-freebsd /usr/local/lib/perl5/5.10.0 /usr/local/lib/perl5/site_perl/5.10.0/i386-freebsd /usr/local/lib/perl5/site_perl/5.10.0 .

Updated: Also this from a thread on use.perl. I hate cross posting, but given the nature of this issue...

Comment on 5:10: Why is this slower than 5.8.8?
Select or Download Code
Reaped: Re: 5:10: Why is this slower than 5.8.8?
by NodeReaper (Curate) on Dec 23, 2007 at 01:51 UTC
Re: 5:10: Why is this slower than 5.8.8?
by polettix (Vicar) on Dec 23, 2007 at 04:36 UTC
    Uhm, I probably hit another dark corner:
    #!/usr/bin/perl use strict; use warnings; use Benchmark qw( cmpthese ); cmpthese -2, { by_substr => sub { my $nomedir = '20070502-11'; my $anno = substr $nomedir, 0, 4; my $mese = substr $nomedir, 4, 2; my $giorno = substr $nomedir, 6, 2; my $progressivo = substr $nomedir, 9, 2; }, by_unpack => sub { my $nomedir = '20070502-11'; my ($anno, $mese, $giorno, $progressivo) = unpack 'A4 A2 A2 x A2', $nomedir; }, }; poletti@PolettiX:~/sviluppo/perl$ /opt/perl-5.8.8/bin/perl numstat.pl Rate by_unpack by_substr by_unpack 417553/s -- -32% by_substr 613303/s 47% -- poletti@PolettiX:~/sviluppo/perl$ /opt/perl-5.10.0/bin/perl numstat.pl Rate by_unpack by_substr by_unpack 372754/s -- -34% by_substr 565358/s 52% -- poletti@PolettiX:~/sviluppo/perl$ /opt/perl-5.8.8/bin/perl numstat.pl Rate by_unpack by_substr by_unpack 415531/s -- -33% by_substr 616325/s 48% -- poletti@PolettiX:~/sviluppo/perl$ /opt/perl-5.10.0/bin/perl numstat.pl Rate by_unpack by_substr by_unpack 374480/s -- -33% by_substr 562716/s 50% -- poletti@PolettiX:~/sviluppo/perl$ /opt/perl-5.8.8/bin/perl numstat.pl Rate by_unpack by_substr by_unpack 415531/s -- -33% by_substr 616325/s 48% -- poletti@PolettiX:~/sviluppo/perl$ /opt/perl-5.10.0/bin/perl numstat.pl Rate by_unpack by_substr by_unpack 369821/s -- -34% by_substr 562716/s 52% --
    I made some repeated calls just to be sure not to hit some "spots".

    Update: I forgot to say that I'm under Linux, and that the two perls where compiled with the same configure options (-des for 5.8.8, and a more verbose -de for 5.10.0).

    Hey! Up to Dec 16, 2007 I was named frodo72, take note of the change! Flavio
    perl -ple'$_=reverse' <<<ti.xittelop@oivalf

    Io ho capito... ma tu che hai detto?
Re: 5:10: Why is this slower than 5.8.8?
by doom (Deacon) on Dec 23, 2007 at 06:03 UTC

    A few comments:

    That assign from @_ idiom may still be relatively common, but it's not recommended these days. While Conway does use the @_ assign throughout his "Object Oriented Perl", now his "Perl Best Practices" recommends using shift to access @_.

    And myself, I'm having trouble reproducing this problem at present. I just made a quick try at comparing assigning an array vs shifting off of an array, and I find that they've both gotten slightly faster under perl 5.9.5 vs perl 5.8.8 on my AMD64 based laptop, running kubuntu (linux kernel: 2.6.22-14-generic).

    And incidentally, I see that the "shift" method is around 30% faster than assign from array.

    (Benchmark code available upon request. At present I'm just skipping it because it's fairly dull.)

      There's a big diference between 'common/not recommended', and almost 50% slower. And with all due respect to PBP, using three lines of shift instead of = @_ is just silly in some ways. To each their own.
        Well, obviously it would be better if there wasn't a speed penalty associated with array assigns, but since there is it might be better to live with the extra lines of shifts, even if they seem inelegant.

        Anyway, the main point is that we should probably assume that this is a FreeBSD oddity of some sort (ala the "malloc" issue under discussion), unless someone chimes in with some data that shows the contrary.

      Where does he say that? Looking at page 180 of PBP TheDamian recommends using the shift idiom if you need to comment or sanity check one of the variables, but otherwise either the my()=@_ or the shift idioms are okay. The only thing he really recommends against is accessing @_ directly (e.g. $_[1]).
Re: 5:10: Why is this slower than 5.8.8?
by eserte (Deacon) on Dec 23, 2007 at 10:32 UTC
    Try compiling both perls with usemymalloc=y. FreeBSD's malloc may be very slow in some situations.
      Thanks for that thought. I'll give that a try for sure. If using FreeBSD malloc solves the problem, I'd vote that it should be the default in Configure given the nature of the 50% performance difference for a common idiom.
        s/solves/causes/

        Perl's malloc is fine.

      usemymalloc=y will bring 20-30% more perfomance penalty! This is stupid trying to solve one slowdown by another slowdown. FreeBSD's malloc is faster than perl's malloc anyway.
        Well, then try the following script
        my $max = 50000; my @l = ('a'..'z'); my @keys = map { join '', map $l[rand @l], 0..71 } 0..$max;
        On my system running this script with a perlmalloc-built perl is 600x (!) faster than with a sysmalloc-built perl:
        $ time /usr/local/src/perl-5.10.0-perlmalloc/perl -I/usr/local/src/per +l-5.10.0-perlmalloc/lib ~/trash/slow_malloc2.pl 3.027u 0.435s 0:03.68 93.7% 1448+324155k 0+0io 0pf+0w $ time /usr/local/src/perl-5.10.0-sysmalloc/perl -I/usr/local/src/perl +-5.10.0-sysmalloc/lib ~/trash/slow_malloc2.pl 405.090u 189.574s 13:01.52 76.0% 1466+495449k 0+0io 0pf+0w
        This is a pathological case, but this may happen with FreeBSD's malloc.
Re: 5:10: Why is this slower than 5.8.8?
by eserte (Deacon) on Dec 24, 2007 at 09:52 UTC
    Here are my results (amd64-freebsd 6.2, perl5.8.8 from ports, perl5.10.0 self-compiled):
    $ perl5.8.8 ~/trash/test.pl Benchmark: running set_inherited_class, set_inherited_object for at le +ast 3 CPU seconds... set_inherited_class: 5 wallclock secs ( 3.14 usr + 0.00 sys = 3.14 +CPU) @ 403854.65/s (n=1268356) set_inherited_object: 4 wallclock secs ( 3.16 usr + 0.01 sys = 3.17 + CPU) @ 441967.29/s (n=1401865) $ /usr/local/src/perl-5.10.0-sysmalloc/perl -I/usr/local/src/perl-5.10 +.0-sysmalloc/lib ~/trash/test.pl Benchmark: running set_inherited_class, set_inherited_object for at le +ast 3 CPU seconds... set_inherited_class: 4 wallclock secs ( 3.15 usr + 0.01 sys = 3.16 +CPU) @ 309119.05/s (n=975657) set_inherited_object: 5 wallclock secs ( 3.08 usr + 0.00 sys = 3.08 + CPU) @ 402004.47/s (n=1237420) $/usr/local/src/perl-5.10.0-perlmalloc/perl -I/usr/local/src/perl-5.10 +.0-perlmalloc/lib ~/trash/test.pl Benchmark: running set_inherited_class, set_inherited_object for at le +ast 3 CPU seconds... set_inherited_class: 6 wallclock secs ( 3.12 usr + 0.00 sys = 3.12 +CPU) @ 378921.38/s (n=1181169) set_inherited_object: 6 wallclock secs ( 3.15 usr + 0.00 sys = 3.15 + CPU) @ 469993.13/s (n=1479744)
    perl with sysmalloc seems to be the worst, while the both perls with perlmalloc have similar results.
      You forgot 5.8.8 without perlmalloc (not from ports) which would be the fastest (at least on i386)
        I'm curious to know under what benchmark you ran these tests and what the results were. Also, were there any other flags in the perl build that be factors, i.e. what's the output of perl -V?
        -- Ian Tegebo
Re: 5:10: Why is this slower than 5.8.8?
by schwern (Scribe) on Dec 26, 2007 at 04:48 UTC

    This thread on p5p explains the problem. In short...

    For some reason the optimiser has decided that there are common elements
    on both sides, and that therefore a temporary copy of each element must be
    made. This is to handle cases like:
    
        ($a,$b) = ($b,$a);
    
    but is now slowing down the normal case.
    

    It was tracked back to this patch. Now that it's been nailed down there's a very good chance it'll be fixed in 5.10.1.

      The resolution came not appended to the above thread but in a reply to the p5p summaries generously written by grinder and made possible through Vienna.pm

      Big slowdown fix patch, provided by Rick Delaney.

Log In?
Username:
Password:

What's my password?
Create A New User
Node Status?
node history
Node Type: perlquestion [id://658723]
Approved by Limbic~Region
Front-paged by Limbic~Region
help
Chatterbox?
and the web crawler heard nothing...

How do I use this? | Other CB clients
Other Users?
Others pondering the Monastery: (6)
As of 2014-09-01 18:50 GMT
Sections?
Information?
Find Nodes?
Leftovers?
    Voting Booth?

    My favorite cookbook is:










    Results (15 votes), past polls