Skip Menu |
Report information

Subject: COW speedup lost after e8c6a474
Download (untitled) / with headers
text/plain 612b
I have this test program: $x = "x" x 1_000_000; $y = $x for 1..1_000_000; On my box (OS X, will attach perl -V shortly) this program takes 90s to run on 5.18 and 5.20. It takes a fraction of a second on 5.19.11. The change in speed occurs at: commit e8c6a474e88610b73e62a19256dc8706b42f42b9 Author: Yves Orton <demerphq@gmail.com> Date: Sun May 11 12:37:33 2014 +0200 Implement "max waste" thresholds to avoid problems with COW and deliberately overallocated pvs Matthew Horsfall reports no slowdown on his Ubuntu box. Obviously it'd be great to get this sorted out for 5.20.1. -- rjbs
Download (untitled) / with headers
text/plain 2.9k
Summary of my perl5 (revision 5 version 20 subversion 0) configuration: Platform: osname=darwin, osvers=13.2.0, archname=darwin-2level uname='darwin walrus.local 13.2.0 darwin kernel version 13.2.0: thu apr 17 23:03:13 pdt 2014; root:xnu-2422.100.13~1release_x86_64 x86_64 ' config_args='-Dprefix=/Users/rjbs/.plenv/versions/20.0 -de -Dusedevel -A'eval:scriptdir=/Users/rjbs/.plenv/versions/20.0/bin'' hint=recommended, useposix=true, d_sigaction=define useithreads=undef, usemultiplicity=undef use64bitint=define, use64bitall=define, uselongdouble=undef usemymalloc=n, bincompat5005=undef Compiler: cc='cc', ccflags ='-fno-common -DPERL_DARWIN -fno-strict-aliasing -pipe -fstack-protector -I/usr/local/include -I/opt/local/include', optimize='-O3', cppflags='-fno-common -DPERL_DARWIN -fno-strict-aliasing -pipe -fstack-protector -I/usr/local/include -I/opt/local/include' ccversion='', gccversion='4.2.1 Compatible Apple LLVM 5.1 (clang-503.0.40)', gccosandvers='' intsize=4, longsize=8, ptrsize=8, doublesize=8, byteorder=12345678 d_longlong=define, longlongsize=8, d_longdbl=define, longdblsize=16 ivtype='long', ivsize=8, nvtype='double', nvsize=8, Off_t='off_t', lseeksize=8 alignbytes=8, prototype=define Linker and Libraries: ld='env MACOSX_DEPLOYMENT_TARGET=10.3 cc', ldflags =' -fstack-protector -L/usr/local/lib -L/opt/local/lib' libpth=/usr/local/lib /Applications/Xcode.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/bin/../lib/clang/5.1/lib /Applications/Xcode.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/lib /usr/lib /opt/local/lib libs=-lgdbm -ldbm -ldl -lm -lutil -lc perllibs=-ldl -lm -lutil -lc libc=, so=dylib, useshrplib=false, libperl=libperl.a gnulibc_version='' Dynamic Linking: dlsrc=dl_dlopen.xs, dlext=bundle, d_dlsymun=undef, ccdlflags=' ' cccdlflags=' ', lddlflags=' -bundle -undefined dynamic_lookup -L/usr/local/lib -L/opt/local/lib -fstack-protector' Characteristics of this binary (from libperl): Compile-time options: HAS_TIMES PERLIO_LAYERS PERL_DONT_CREATE_GVSV PERL_HASH_FUNC_ONE_AT_A_TIME_HARD PERL_MALLOC_WRAP PERL_NEW_COPY_ON_WRITE PERL_PRESERVE_IVUV PERL_USE_DEVEL USE_64_BIT_ALL USE_64_BIT_INT USE_LARGE_FILES USE_LOCALE USE_LOCALE_COLLATE USE_LOCALE_CTYPE USE_LOCALE_NUMERIC USE_PERLIO USE_PERL_ATOF Built under darwin Compiled at May 26 2014 15:17:02 %ENV: PERLDOC="-n/opt/local/bin/groff" PERL_AUTOINSTALL="--skipdeps" PERL_MAILERS="sendmail:/Users/rjbs/bin/sendmail" @INC: /Users/rjbs/.plenv/versions/20.0/lib/perl5/site_perl/5.20.0/darwin-2level /Users/rjbs/.plenv/versions/20.0/lib/perl5/site_perl/5.20.0 /Users/rjbs/.plenv/versions/20.0/lib/perl5/5.20.0/darwin-2level /Users/rjbs/.plenv/versions/20.0/lib/perl5/5.20.0 .
RT-Send-CC: perl5-porters [...] perl.org
Download (untitled) / with headers
text/plain 796b
On Wed May 28 09:04:19 2014, rjbs wrote: Show quoted text
> I have this test program: > > $x = "x" x 1_000_000; > $y = $x for 1..1_000_000; > > On my box (OS X, will attach perl -V shortly) this program takes 90s > to run on 5.18 and 5.20. It takes a fraction of a second on 5.19.11. > > The change in speed occurs at: > > commit e8c6a474e88610b73e62a19256dc8706b42f42b9 > Author: Yves Orton <demerphq@gmail.com> > Date: Sun May 11 12:37:33 2014 +0200 > > Implement "max waste" thresholds to avoid problems with COW and > deliberately overallocated pvs > > Matthew Horsfall reports no slowdown on his Ubuntu box. > > Obviously it'd be great to get this sorted out for 5.20.1. >
I foolishly put this bug in the wrong place to start, and am replying to it here simply to trigger a mail to p5p. -- rjbs
RT-Send-CC: perl5-porters [...] perl.org
Download (untitled) / with headers
text/plain 1.4k
On Wed May 28 09:04:19 2014, rjbs wrote: Show quoted text
> I have this test program: > > $x = "x" x 1_000_000; > $y = $x for 1..1_000_000; > > On my box (OS X, will attach perl -V shortly) this program takes 90s > to run on 5.18 and 5.20. It takes a fraction of a second on 5.19.11. >
[snip] Show quoted text
> > Matthew Horsfall reports no slowdown on his Ubuntu box. > > Obviously it'd be great to get this sorted out for 5.20.1. >
I am not getting a slowdown on either of two Linux machines. In what follows I use only released versions, compiled from source without threading. #1: current laptop ### $ uname -a Linux zareason 3.13.0-27-generic #50-Ubuntu SMP Thu May 15 18:06:16 UTC 2014 x86_64 x86_64 x86_64 GNU/Linux $ which perl /home/jkeenan/perl5/perlbrew/perls/perl-5.20.0/bin/perl $ time perl ~/learn/perl/rjbs_speed.pl real 0m0.061s user 0m0.058s sys 0m0.003s $ perlbrew switch perl-5.18.2 $ which perl /home/jkeenan/perl5/perlbrew/perls/perl-5.18.2/bin/perl $ time perl ~/learn/perl/rjbs_speed.pl real 1m17.144s user 1m17.167s sys 0m0.045s ### #2: older Linode ### $ uname -a Linux li11-226 2.6.18.8-linode22 #1 SMP Tue Nov 10 16:12:12 UTC 2009 i686 GNU/Linux $ perl -v This is perl 5, version 20, subversion 0 (v5.20.0) built for i686-linux $ time perl rjbs_speed.pl real 0m0.194s user 0m0.144s sys 0m0.002s $ time /usr/local/bin/perl5.18.1 rjbs_speed.pl real 1m43.419s user 1m42.182s sys 0m0.002s ### Could there be an OS-specific aspect to this problem? Thank you very much. Jim Keenan
RT-Send-CC: perl5-porters [...] perl.org
Download (untitled) / with headers
text/plain 1.3k
On Wed May 28 13:33:40 2014, jkeenan wrote: Show quoted text
> On Wed May 28 09:04:19 2014, rjbs wrote:
> > I have this test program: > > > > $x = "x" x 1_000_000; > > $y = $x for 1..1_000_000; > > > > On my box (OS X, will attach perl -V shortly) this program takes 90s > > to run on 5.18 and 5.20. It takes a fraction of a second on 5.19.11. > >
> > [snip] >
> > > > Matthew Horsfall reports no slowdown on his Ubuntu box. > > > > Obviously it'd be great to get this sorted out for 5.20.1. > >
> > I am not getting a slowdown on either of two Linux machines. In what > follows I use only released versions, compiled from source without > threading. >
[snip Linux results ] Show quoted text
> > Could there be an OS-specific aspect to this problem? >
Yes, there could be. I was able to reproduce rjbs's results on Darwin -- a very old Darwin! (I had to modify rjbs's program to take a command-line argument for number of iterations.) I compared 5.18.0 and 5.20.0, both built from source. There did not appear to be significant differences. Performance degraded rapidly as the number of iterations increased; I control-C-ed runs of 300,000. However, I then checked out the commit immediately preceding the one rjbs cited and built a perl from that. Using that, rjbs's program went like lightning. I was able to do a run of 3,000,000 with no problem. Please see attached file. Let's get reports from other OSes. Thank you very much. Jim Keenan
Subject: timings_darwin_ppc_rjbs_speed.txt
# 5.18.0 $ time /usr/local/bin/perl5.18.0 rjbs_speed.pl 100000 real 0m3.379s user 0m3.239s sys 0m0.035s $ time /usr/local/bin/perl5.18.0 rjbs_speed.pl 150000 real 0m7.591s user 0m7.323s sys 0m0.071s $ time /usr/local/bin/perl5.18.0 rjbs_speed.pl 200000 real 0m38.278s user 0m36.926s sys 0m0.374s # v5.19.11-45-gc8180b0; see perl -V below $ time ./perl -Ilib ~/learn/perl/rjbs_speed.pl 100000 real 0m0.181s user 0m0.063s sys 0m0.020s $ time ./perl -Ilib ~/learn/perl/rjbs_speed.pl 150000 real 0m0.164s user 0m0.092s sys 0m0.021s $ time ./perl -Ilib ~/learn/perl/rjbs_speed.pl 200000 real 0m0.185s user 0m0.122s sys 0m0.022s $ time ./perl -Ilib ~/learn/perl/rjbs_speed.pl 3000000 real 0m1.953s user 0m1.759s sys 0m0.038s # 5.20.0 $ time perl rjbs_speed.pl 100000 real 0m3.352s user 0m3.228s sys 0m0.034s $ time perl rjbs_speed.pl 150000 real 0m7.800s user 0m7.532s sys 0m0.068s $ time perl rjbs_speed.pl 200000 real 0m35.307s user 0m34.186s sys 0m0.323s ##### $ ./perl -Ilib -V Summary of my perl5 (revision 5 version 19 subversion 12) configuration: Commit id: c8180b0692cef05079a2e250b3faccaca4592b10 Platform: osname=darwin, osvers=8.11.0, archname=darwin-2level uname='darwin macintosh-9.local 8.11.0 darwin kernel version 8.11.0: wed oct 10 18:26:00 pdt 2007; root:xnu-792.24.17~1release_ppc power macintosh powerpc ' config_args='-des -Dusedevel'
Date: Thu, 29 May 2014 01:11:21 +0200
To: Perl RT Bug Tracker <perlbug-followup [...] perl.org>
Subject: Re: [perl #121975] COW speedup lost after e8c6a474
CC: Perl5 Porteros <perl5-porters [...] perl.org>
From: demerphq <demerphq [...] gmail.com>
Download (untitled) / with headers
text/plain 1.7k
On 28 May 2014 23:53, James E Keenan via RT <perlbug-followup@perl.org> wrote:
Show quoted text
On Wed May 28 13:33:40 2014, jkeenan wrote:
> On Wed May 28 09:04:19 2014, rjbs wrote:
> > I have this test program:
> >
> > $x = "x" x 1_000_000;
> > $y = $x for 1..1_000_000;
> >
> > On my box (OS X, will attach perl -V shortly) this program takes 90s
> > to run on 5.18 and 5.20.  It takes a fraction of a second on 5.19.11.
> >
>
> [snip]
>
> >
> > Matthew Horsfall reports no slowdown on his Ubuntu box.
> >
> > Obviously it'd be great to get this sorted out for 5.20.1.
> >
>
> I am not getting a slowdown on either of two Linux machines.  In what
> follows I use only released versions, compiled from source without
> threading.
>

[snip Linux results ]

>
> Could there be an OS-specific aspect to this problem?
>

Yes, there could be.  I was able to reproduce rjbs's results on Darwin -- a very old Darwin!  (I had to modify rjbs's program to take a command-line argument for number of iterations.)

I compared 5.18.0 and 5.20.0, both built from source.  There did not appear to be significant differences.  Performance degraded rapidly as the number of iterations increased; I control-C-ed runs of 300,000.

However, I then checked out the commit immediately preceding the one rjbs cited and built a perl from that.  Using that, rjbs's program went like lightning.  I was able to do a run of 3,000,000 with no problem.


Can you add something like

use Devel::Peek;
Dump($x);

and then send us the last couple of lines. It will print a lot of "x"s and then print something like this:

  CUR = 1000000
  LEN = 1000002
  COW_REFCNT = 1

 Id like to see that. (We need to patch Devel::Peek dump to be a little less annoying with long strings)

Yves
From: Ricardo Signes <perl.p5p [...] rjbs.manxome.org>
Date: Wed, 28 May 2014 19:31:31 -0400
To: demerphq <demerphq [...] gmail.com>
Subject: Re: [perl #121975] COW speedup lost after e8c6a474
CC: Perl RT Bug Tracker <perlbug-followup [...] perl.org>, Perl5 Porteros <perl5-porters [...] perl.org>
Download (untitled) / with headers
text/plain 695b
* demerphq <demerphq@gmail.com> [2014-05-28T19:11:21] Show quoted text
> use Devel::Peek; > Dump($x); > > and then send us the last couple of lines. It will print a lot of "x"s and > then print something like this:
I would be delighted to do so! (type type type) I ran it piped to 'grep -v xxxxxx' and I get, on perl 5.20.0: ~$ perl terastring.pl |& grep -v xxxxxx SV = PV(0x7fd923004070) at 0x7fd92302d0f0 REFCNT = 1 FLAGS = (POK,pPOK) CUR = 1000000 LEN = 1003520 When I use perl 5.19.11: ~$ perl terastring.pl |& grep -v xxxxxx SV = PV(0x7ffe73802e70) at 0x7ffe73023cf0 REFCNT = 1 FLAGS = (POK,IsCOW,pPOK) CUR = 1000000 LEN = 1003520 COW_REFCNT = 1 -- rjbs
Download signature.asc
application/pgp-signature 473b

Message body not shown because it is not plain text.

RT-Send-CC: perl5-porters [...] perl.org
Download (untitled) / with headers
text/plain 481b
On Wed May 28 16:12:07 2014, demerphq wrote: Show quoted text
> >
> Can you add something like > > use Devel::Peek; > Dump($x); > > and then send us the last couple of lines. It will print a lot of "x"s > and > then print something like this: > > CUR = 1000000 > LEN = 1000002 > COW_REFCNT = 1 > > Id like to see that. (We need to patch Devel::Peek dump to be a little > less annoying with long strings) > > Yves
Results on older Darwin appear similar to what rjbs got. See file attached.
Subject: devel-peek-findings-darwin-ppc.txt
$ /usr/local/bin/perl5.18.0 121975-rjbs_speed.pl 100000 2> xyz; grep -v xxxxxx xyz;rm xyz SV = PV(0x1803558) at 0x180f810 REFCNT = 1 FLAGS = (POK,pPOK) CUR = 100000 LEN = 102400 $ ./perl -v | head -2 | tail -1 This is perl 5, version 19, subversion 12 (v5.19.12 (v5.19.11-45-gc8180b0)) built for darwin-2level $ ./perl -Ilib ~/learn/perl/p5p/121975-rjbs_speed.pl 100000 2>xyz;grep -v xxxxxx xyz;rm xyz SV = PV(0x2803528) at 0x2810110 REFCNT = 1 FLAGS = (POK,IsCOW,pPOK) CUR = 100000 LEN = 102400 COW_REFCNT = 1 $ /usr/local/bin/perl5.20.0 121975-rjbs_speed.pl 100000 2> xyz; grep -v xxxxxx xyz;rm xyz SV = PV(0x1803560) at 0x1810180 REFCNT = 1 FLAGS = (POK,pPOK) CUR = 100000 LEN = 102400
Subject: Re: [perl #121975] COW speedup lost after e8c6a474
CC: Perl RT Bug Tracker <perlbug-followup [...] perl.org>, Perl5 Porteros <perl5-porters [...] perl.org>
From: demerphq <demerphq [...] gmail.com>
Date: Thu, 29 May 2014 11:11:51 +0200
To: Ricardo Signes <perl.p5p [...] rjbs.manxome.org>
Download (untitled) / with headers
text/plain 4.2k
On 29 May 2014 01:31, Ricardo Signes <perl.p5p@rjbs.manxome.org> wrote:
Show quoted text
* demerphq <demerphq@gmail.com> [2014-05-28T19:11:21]
> use Devel::Peek;
> Dump($x);
>
> and then send us the last couple of lines. It will print a lot of "x"s and
> then print something like this:

I would be delighted to do so!

(type type type)

I ran it piped to 'grep -v xxxxxx' and I get, on perl 5.20.0:

  ~$ perl terastring.pl |& grep -v xxxxxx
  SV = PV(0x7fd923004070) at 0x7fd92302d0f0
    REFCNT = 1
    FLAGS = (POK,pPOK)
    CUR = 1000000
    LEN = 1003520

When I use perl 5.19.11:

  ~$ perl terastring.pl |& grep -v xxxxxx
  SV = PV(0x7ffe73802e70) at 0x7ffe73023cf0
    REFCNT = 1
    FLAGS = (POK,IsCOW,pPOK)
    CUR = 1000000
    LEN = 1003520
    COW_REFCNT = 1

So there is the reason. For some reason the slow builds are preallocating a lot more bytes than the fast build is, and by doing so it exceeds the SV_COW_MAX_WASTE_THRESHOLD or SV_COWBUF_MAX_WASTE_THRESHOLD of 80, causing the string to not be COW'ed. 

Obviously you *could* raise these thresholds, for instance to 4000 and this script should be "fast" again.

However I think the real problem we need to get to the bottom of is why it is preallocating so much extra space on the slow builds.

On Linux we see this:

$ cat ../t2.pl 
$x = "x" x 1_000_000;
$y = $x for 1..1_000_000;
use Devel::Peek;
Dump($x);
 
$ time ./perl -Ilib ../t2.pl 2>&1 | grep -v xxxx
SV = PV(0x1a23d80) at 0x1a42808
  REFCNT = 1
  FLAGS = (POK,IsCOW,pPOK)
  CUR = 1000000
  LEN = 1000002
  COW_REFCNT = 1

real 0m0.139s
user 0m0.132s
sys 0m0.004s

Note the LEN-CUR == 2 compared to your run where LEN-CUR==3520.  If we look at James Keenans results:

SV = PV(0x1803558) at 0x180f810
  REFCNT = 1
  FLAGS = (POK,pPOK)
  CUR = 100000
  LEN = 102400

We can see it is LEN-CUR==2400.

I suspect the Linux results are because of this:

./perl -Ilib -V:d_malloc_size
d_malloc_size='undef';

Which affects the following logic in sv.c:

#ifdef Perl_safesysmalloc_size
        /* Do this here, do it once, do it right, and then we will never get
           called back into sv_grow() unless there really is some growing
           needed.  */
        SvLEN_set(sv, Perl_safesysmalloc_size(s));
#else   
        SvLEN_set(sv, newlen);
#endif

In Linux we compile the second branch, and in OSX and BSD's I think that d_malloc_size is defined, so they do the first branch, and on linux we do the second branch.

When we do something like 

my $x= "x" x 1000000;

we end up doing SvGROW(sv,1000000);

Assuming $x was originally empty we will try to malloc() K+2 bytes, one byte extra to guarantee room to null terminate the buffer, and one extra byte for the cow-refcount should this string become COW.

On linux this ends up with SvLEN()==1000002 and SvCUR()==1000000.

On systems where Perl_safesysmalloc_size() is defined we set the SvLEN() to the size that malloc() has actually allocated for us. This means we can avoid some realloc() calls later (which would be fast anyway), but crucially it means we can't tell the difference between "deliberately preallocated" and "preallocated by virtue of the whims of malloc".

Basically there is a big difference when Perl or a perl user decides to deliberately preallocate (in which case we probably care about the wastage), and when malloc() does it on our behalf (in which case we probably don't [insert hand waving here]).

There are multiple optimisations at multiple levels operating and clashing here:

1. Deliberate preallocation of a buffer - useful on OS'es with a braindead realloc() and in code like sv_gets() where you avoid a bunch of checks by preallocating for the "worst case" when processing block-read data.
2. Unwarranted chumminess with malloc() on systems with d_malloc_size
3. COW.

So one option would be to stop using Perl_safesysmalloc_size(). Another would be to somehow make the wastage checks Perl_safesysmalloc_size() aware, probaby by disabling some of the checks if it is available, or maybe by somehow using the function as part of the wastage checks.

Regardless I feel like there is a bit of a clash of concepts here that we need to think through properly before COW is really going to settle down.

--
perl -Mre=debug -e "/just|another|perl|hacker/"
From: demerphq <demerphq [...] gmail.com>
CC: Perl RT Bug Tracker <perlbug-followup [...] perl.org>, Perl5 Porteros <perl5-porters [...] perl.org>
Subject: Re: [perl #121975] COW speedup lost after e8c6a474
To: Ricardo Signes <perl.p5p [...] rjbs.manxome.org>
Date: Thu, 29 May 2014 11:36:13 +0200
Download (untitled) / with headers
text/plain 939b
On 29 May 2014 11:11, demerphq <demerphq@gmail.com> wrote:
Show quoted text

So one option would be to stop using Perl_safesysmalloc_size().

As this is the easiest to do to prove this is actually the problem I have pushed:

commit ce861ea7963084a7fe72fbb5485e77bb85037b55
Author: Yves Orton <demerphq@gmail.com>
Date:   Thu May 29 11:33:56 2014 +0200

    temporary fix for [perl #121975] COW speedup lost after e8c6a474
    
    Disable use of Perl_safesysmalloc_size by default. Only use it when PERL_USE_MALLOC_SIZE is defined.
    
    Using Perl_safesysmalloc_size() perl cannot tell a deliberately preallocated buffer
    which we probably dont want to COW from a malloc() preallocated buffer where we probably
    dont care. Hopefully this fixes the slowdown observed on some platforms.

How this affects performance as a whole on the affected platforms I do not know. I suspect not much.

Yves 



--
perl -Mre=debug -e "/just|another|perl|hacker/"
RT-Send-CC: perl5-porters [...] perl.org
Download (untitled) / with headers
text/plain 178b
On Wed May 28 13:33:40 2014, jkeenan wrote: Show quoted text
> $ time perl ~/learn/perl/rjbs_speed.pl
Where is rjbs_speed.pl? Its not attached to this ticket. -- bulk88 ~ bulk88 at hotmail.com
From: Ricardo Signes <perl.p5p [...] rjbs.manxome.org>
Date: Thu, 29 May 2014 08:02:49 -0400
To: demerphq <demerphq [...] gmail.com>
Subject: Re: [perl #121975] COW speedup lost after e8c6a474
CC: Perl RT Bug Tracker <perlbug-followup [...] perl.org>, Perl5 Porteros <perl5-porters [...] perl.org>
Download (untitled) / with headers
text/plain 481b
* demerphq <demerphq@gmail.com> [2014-05-29T05:36:13] Show quoted text
> commit ce861ea7963084a7fe72fbb5485e77bb85037b55
As you suspected: ~/code/perl5$ time ./perl -I lib ~/terastring.pl |& grep -v xx SV = PV(0x7f7f53805098) at 0x7f7f53831538 REFCNT = 1 FLAGS = (POK,IsCOW,pPOK) CUR = 1000000 LEN = 1000002 COW_REFCNT = 1 ./perl -I lib ~/terastring.pl 2>&1 0.20s user 0.01s system 98% cpu 0.206 total grep -v xx 0.00s user 0.00s system 2% cpu 0.206 total -- rjbs
Download signature.asc
application/pgp-signature 473b

Message body not shown because it is not plain text.

Subject: Re: [perl #121975] COW speedup lost after e8c6a474
From: Ricardo Signes <rjbs [...] cpan.org>
Date: Thu, 29 May 2014 08:04:46 -0400
To: bulk88 via RT <perlbug-followup [...] perl.org>
Download (untitled) / with headers
text/plain 409b
* bulk88 via RT <perlbug-followup@perl.org> [2014-05-29T07:49:08] Show quoted text
> On Wed May 28 13:33:40 2014, jkeenan wrote:
> > $ time perl ~/learn/perl/rjbs_speed.pl
> > Where is rjbs_speed.pl? Its not attached to this ticket.
It's the two-line program described in the ticket. With Devel::Peek added: # terastring.perl use Devel::Peek; $x = "x" x 1_000_000; $y = $x for 1..1_000_000; Dump($x); -- rjbs
Download signature.asc
application/pgp-signature 473b

Message body not shown because it is not plain text.

To: perl5-porters [...] perl.org
Date: Thu, 29 May 2014 08:05:26 -0400
From: James E Keenan <jkeen [...] verizon.net>
Subject: Re: [perl #121975] COW speedup lost after e8c6a474
Download (untitled) / with headers
text/plain 358b
On 5/29/14 7:49 AM, bulk88 via RT wrote: Show quoted text
> On Wed May 28 13:33:40 2014, jkeenan wrote:
>> $ time perl ~/learn/perl/rjbs_speed.pl
> > Where is rjbs_speed.pl? Its not attached to this ticket. >
It was just rjbs's 2-liner put into a program, then provision for command-line argument added, then later the Devel::Peek stuff added. Nothing special. Attached.

Message body is not shown because sender requested not to inline it.

From: Jarkko Hietaniemi <jhi [...] iki.fi>
CC: Perl RT Bug Tracker <perlbug-followup [...] perl.org>, Perl5 Porteros <perl5-porters [...] perl.org>
Subject: Re: [perl #121975] COW speedup lost after e8c6a474
Date: Thu, 29 May 2014 09:14:12 -0400
To: Ricardo Signes <perl.p5p [...] rjbs.manxome.org>, demerphq <demerphq [...] gmail.com>
Download (untitled) / with headers
text/plain 1.4k
On Thursday-201405-29, 8:02, Ricardo Signes wrote: Show quoted text
> * demerphq <demerphq@gmail.com> [2014-05-29T05:36:13]
>> commit ce861ea7963084a7fe72fbb5485e77bb85037b55
> > As you suspected: > > ~/code/perl5$ time ./perl -I lib ~/terastring.pl |& grep -v xx > SV = PV(0x7f7f53805098) at 0x7f7f53831538 > REFCNT = 1 > FLAGS = (POK,IsCOW,pPOK) > CUR = 1000000 > LEN = 1000002 > COW_REFCNT = 1 > ./perl -I lib ~/terastring.pl 2>&1 0.20s user 0.01s system 98% cpu 0.206 total > grep -v xx 0.00s user 0.00s system 2% cpu 0.206 total >
FWIW, in an OS X 10.9.3 (I tweaked the for loop to do the copy "only" 100K times, since I got bored waiting): * with blead time ./perl -Ilib /tmp/ts.pl 2>&1 |grep -v xxx SV = PV(0x7ff5d1804070) at 0x7ff5d182d108 REFCNT = 1 FLAGS = (POK,IsCOW,pPOK) CUR = 1000000 LEN = 1000002 COW_REFCNT = 1 r 0.20s u 0.14s s 0.01s 73% "./perl -Ilib /tmp/ts.pl 2>&1" r 0.20s u 0.00s s 0.01s 4% "grep -v xxx" * with 5.20.0 time ./perl -Ilib /tmp/ts.pl 2>&1 |grep -v xxx SV = PV(0x7fcefb004070) at 0x7fcefb02d108 REFCNT = 1 FLAGS = (POK,pPOK) CUR = 1000000 LEN = 1003520 r 11.71s u 11.56s s 0.04s 99% "./perl -Ilib /tmp/ts.pl 2>&1" r 11.71s u 0.00s s 0.01s 0% "grep -v xxx" * with 5.18.2 (from macports) time perl /tmp/ts.pl 2>&1 |grep -v xxx SV = PV(0x7f9802004070) at 0x7f98020286b8 REFCNT = 1 FLAGS = (POK,pPOK) CUR = 1000000 LEN = 1003520 r 11.30s u 11.24s s 0.04s 99% "perl /tmp/ts.pl 2>&1" r 11.30s u 0.00s s 0.01s 0% "grep -v xxx"
RT-Send-CC: perl5-porters [...] perl.org
Download (untitled) / with headers
text/plain 2.4k
On Wed May 28 13:33:40 2014, jkeenan wrote: Show quoted text
> > Could there be an OS-specific aspect to this problem? > > Thank you very much. > Jim Keenan
strawberry 5.18, VC blead 5.21, AP 5.10 ------------------------- Owner@delld620 ~ $ "C:/sperl/perl/bin/perl.exe" -v This is perl 5, version 18, subversion 0 (v5.18.0) built for MSWin32-x86-multi-thread-64int Copyright 1987-2013, Larry Wall Perl may be copied only under the terms of either the Artistic License or the GNU General Public License, which may be found in the Perl 5 source kit. Complete documentation for Perl, including FAQ lists, should be found on this system using "man perl" or "perldoc perl". If you have access to the Internet, point your browser at http://www.perl.org/, the Perl Home Page. Owner@delld620 ~ $ time "C:/sperl/perl/bin/perl.exe" "C:\perl521\rjbsspeed.pl" 100000 real 0m2.203s user 0m0.015s sys 0m0.031s Owner@delld620 ~ $ "C:/perl521/bin/perl.exe" -v This is perl 5, version 21, subversion 1 (v5.21.1 (v5.21.0-29-g1abbcfa)) built for MSWin32-x86-multi-thread (with 4 registered patches, see perl -V for more detail) Copyright 1987-2014, Larry Wall Perl may be copied only under the terms of either the Artistic License or the GNU General Public License, which may be found in the Perl 5 source kit. Complete documentation for Perl, including FAQ lists, should be found on this system using "man perl" or "perldoc perl". If you have access to the Internet, point your browser at http://www.perl.org/, the Perl Home Page. Owner@delld620 ~ $ time "C:/perl521/bin/perl.exe" "C:\perl521\rjbsspeed.pl" 100000 real 0m0.094s user 0m0.046s sys 0m0.000s Owner@delld620 ~ $ "C:/perl/bin/perl.exe" -v This is perl, v5.10.0 built for MSWin32-x86-multi-thread (with 5 registered patches, see perl -V for more detail) Copyright 1987-2007, Larry Wall Binary build 1003 [285500] provided by ActiveState http://www.ActiveState.com Built May 13 2008 16:52:49 Perl may be copied only under the terms of either the Artistic License or the GNU General Public License, which may be found in the Perl 5 source kit. Complete documentation for Perl, including FAQ lists, should be found on this system using "man perl" or "perldoc perl". If you have access to the Internet, point your browser at http://www.perl.org/, the Perl Home Page. Owner@delld620 ~ $ time "C:/perl/bin/perl.exe" "C:\perl521\rjbsspeed.pl" 100000 real 0m2.188s user 0m0.015s sys 0m0.031s Owner@delld620 ~ $ ------------------------- -- bulk88 ~ bulk88 at hotmail.com
RT-Send-CC: perl5-porters [...] perl.org
Download (untitled) / with headers
text/plain 1.2k
On Thu May 29 05:03:15 2014, perl.p5p@rjbs.manxome.org wrote: Show quoted text
> * demerphq <demerphq@gmail.com> [2014-05-29T05:36:13]
> > commit ce861ea7963084a7fe72fbb5485e77bb85037b55
> > As you suspected: > > ~/code/perl5$ time ./perl -I lib ~/terastring.pl |& grep -v xx > SV = PV(0x7f7f53805098) at 0x7f7f53831538 > REFCNT = 1 > FLAGS = (POK,IsCOW,pPOK) > CUR = 1000000 > LEN = 1000002 > COW_REFCNT = 1 > ./perl -I lib ~/terastring.pl 2>&1 0.20s user 0.01s system 98% cpu > 0.206 total > grep -v xx 0.00s user 0.00s system 2% cpu 0.206 total
Confirmable on the older Darwin as well: ### $ ./perl -v |head -2 |tail -1 This is perl 5, version 21, subversion 1 (v5.21.1 (v5.21.0-95-gc02d599)) built for darwin-2level $ time ./perl -Ilib ~/learn/perl/p5p/121975-rjbs_speed.pl 150000 real 0m0.160s user 0m0.092s sys 0m0.021s $ time ./perl -Ilib ~/learn/perl/p5p/121975-rjbs_speed.pl 200000 real 0m0.194s user 0m0.125s sys 0m0.022s $ time ./perl -Ilib ~/learn/perl/p5p/121975-rjbs_speed.pl 3000000 real 0m1.917s user 0m1.810s sys 0m0.038s ### And with the Devel::Peek check: ### $ ./perl -Ilib ~/learn/perl/p5p/121975-rjbs_speed.pl 150000 2>xyz;grep -v xxxxxx xyz;rm xyz SV = PV(0x2803528) at 0x2810110 REFCNT = 1 FLAGS = (POK,IsCOW,pPOK) CUR = 150000 LEN = 150004 COW_REFCNT = 1 ###
RT-Send-CC: perl5-porters [...] perl.org
Download (untitled) / with headers
text/plain 642b
On Thu May 29 02:12:26 2014, demerphq wrote: Show quoted text
> Obviously you *could* raise these thresholds, for instance to 4000 and this > script should be "fast" again. > > However I think the real problem we need to get to the bottom of is why it > is preallocating so much extra space on the slow builds.
How about making the threshold a percentage, rather than a fixed number of bytes? Show quoted text
> Regardless I feel like there is a bit of a clash of concepts here that we > need to think through properly before COW is really going to settle down.
Well, at least 5.20 was no slower than 5.18 in that case, and faster in others. :-) -- Father Chrysostomos
RT-Send-CC: perl5-porters [...] perl.org
On Thu May 29 02:36:38 2014, demerphq wrote: Show quoted text
> On 29 May 2014 11:11, demerphq <demerphq@gmail.com> wrote: >
> > > > So one option would be to stop using Perl_safesysmalloc_size(). > >
> > As this is the easiest to do to prove this is actually the problem I have > pushed: > > commit ce861ea7963084a7fe72fbb5485e77bb85037b55 > Author: Yves Orton <demerphq@gmail.com> > Date: Thu May 29 11:33:56 2014 +0200 > > temporary fix for [perl #121975] COW speedup lost after e8c6a474 > > Disable use of Perl_safesysmalloc_size by default. Only use it when > PERL_USE_MALLOC_SIZE is defined. > > Using Perl_safesysmalloc_size() perl cannot tell a deliberately > preallocated buffer > which we probably dont want to COW from a malloc() preallocated buffer > where we probably > dont care. Hopefully this fixes the slowdown observed on some platforms. > > How this affects performance as a whole on the affected platforms I do not > know. I suspect not much.
Any news? Should this ticket stay open? (It's listed in perl5201delta.)
RT-Send-CC: perl5-porters [...] perl.org
Download (untitled) / with headers
text/plain 1.4k
On Fri Feb 26 10:31:01 2016, mauke- wrote: Show quoted text
> On Thu May 29 02:36:38 2014, demerphq wrote:
> > On 29 May 2014 11:11, demerphq <demerphq@gmail.com> wrote: > >
> > > > > > So one option would be to stop using Perl_safesysmalloc_size(). > > >
> > > > As this is the easiest to do to prove this is actually the problem I > > have > > pushed: > > > > commit ce861ea7963084a7fe72fbb5485e77bb85037b55 > > Author: Yves Orton <demerphq@gmail.com> > > Date: Thu May 29 11:33:56 2014 +0200 > > > > temporary fix for [perl #121975] COW speedup lost after e8c6a474 > > > > Disable use of Perl_safesysmalloc_size by default. Only use it when > > PERL_USE_MALLOC_SIZE is defined. > > > > Using Perl_safesysmalloc_size() perl cannot tell a deliberately > > preallocated buffer > > which we probably dont want to COW from a malloc() preallocated > > buffer > > where we probably > > dont care. Hopefully this fixes the slowdown observed on some > > platforms. > > > > How this affects performance as a whole on the affected platforms I > > do not > > know. I suspect not much.
> > Any news? Should this ticket stay open? (It's listed in > perl5201delta.)
On the older Darwin on which I reported, Yves' patch, while it did not get back the speeds reported up through v5.19.11-45-gc8180b0, did improve performance considerably. So I don't need to have the ticket remain open ... but let's see what rjbs has to say, particularly on a more up-to-date Darwin. Thank you very much. -- James E Keenan (jkeenan@cpan.org)
Subject: Re: [perl #121975] COW speedup lost after e8c6a474
CC: perl5-porters [...] perl.org
Date: Mon, 29 Feb 2016 10:11:24 +0000
From: Dave Mitchell <davem [...] iabyn.com>
To: James E Keenan via RT <perlbug-followup [...] perl.org>
Download (untitled) / with headers
text/plain 577b
On Fri, Feb 26, 2016 at 03:56:36PM -0800, James E Keenan via RT wrote: Show quoted text
> On the older Darwin on which I reported, Yves' patch, while it did not > get back the speeds reported up through v5.19.11-45-gc8180b0, did > improve performance considerably. So I don't need to have the ticket > remain open ... but let's see what rjbs has to say, particularly on a > more up-to-date Darwin.
I think the ticket should stay open. There's still a whole bunch of stuff related to COW and thresholds that could do with some love. It's on my todo list. -- You're only as old as you look.
RT-Send-CC: perl5-porters [...] perl.org
Download (untitled) / with headers
text/plain 776b
On Mon Feb 29 02:11:53 2016, davem wrote: Show quoted text
> On Fri, Feb 26, 2016 at 03:56:36PM -0800, James E Keenan via RT wrote:
> > On the older Darwin on which I reported, Yves' patch, while it did not > > get back the speeds reported up through v5.19.11-45-gc8180b0, did > > improve performance considerably. So I don't need to have the ticket > > remain open ... but let's see what rjbs has to say, particularly on a > > more up-to-date Darwin.
> > I think the ticket should stay open. There's still a whole bunch of > stuff related to COW and thresholds that could do with some love. > It's on my todo list.
I'd probably like to see those become their own tickets, but as it stands I'm happy to let you own this issue and the structure of the tickets to handle it. ;) -- -- rjbs


This service is sponsored and maintained by Best Practical Solutions and runs on Perl.org infrastructure.

For issues related to this RT instance (aka "perlbug"), please contact perlbug-admin at perl.org