Perl 5.10 Storable extremely slow for large trees of data

[p5pRT]

Migrated from rt.perl.org#50352 (status was 'resolved')

Searchable as RT50352$

[p5pRT]

From clintp@gmail.com

Created by clintp@gmail.com

To duplicate a large expat-parsed XML structure (with refs of refs of refs),

I'm doing the following​:

my $temp = Storable​::freeze $originalXml;
my $copyXml = Storable​::thaw($temp);

And by "large" I mean about 8MB when dumped with Data​::Dumper. Under Perl
5.6
the "freeze" takes fractions of a second. Under Perl 5.10 it takes many
seconds
(between 5-8 seconds).

Perl Info

Flags:
    category=core
    severity=high

Site configuration information for perl 5.10.0:

Configured by SYSTEM at Thu Jan 10 11:00:30 2008.

Summary of my perl5 (revision 5 version 10 subversion 0) configuration:
  Platform:
    osname=MSWin32, osvers=5.00, archname=MSWin32-x86-multi-thread
    uname=''
    config_args='undef'
    hint=recommended, useposix=true, d_sigaction=undef
    useithreads=define, usemultiplicity=define
    useperlio=define, d_sfio=undef, uselargefiles=define, usesocks=undef
    use64bitint=undef, use64bitall=undef, uselongdouble=undef
    usemymalloc=n, bincompat5005=undef
  Compiler:
    cc='cl', ccflags ='-nologo -GF -W3 -MD -Zi -DNDEBUG -O1 -DWIN32
-D_CONSOLE -DNO_STRICT -DHAVE_DES_FCRYPT -DUSE_SITECUSTOMIZE
-DPRIVLIB_LAST_IN_INC -DPERL_IMPLICIT_CONTEXT -DPERL_IMPLICIT_SYS
-DUSE_PERLIO -DPERL_MSVCRT_READFIX',
    optimize='-MD -Zi -DNDEBUG -O1',
    cppflags='-DWIN32'
    ccversion='12.00.8804', gccversion='', gccosandvers=''
    intsize=4, longsize=4, ptrsize=4, doublesize=8, byteorder=1234
    d_longlong=undef, longlongsize=8, d_longdbl=define, longdblsize=10
    ivtype='long', ivsize=4, nvtype='double', nvsize=8, Off_t='__int64',
lseeksize=8
    alignbytes=8, prototype=define
  Linker and Libraries:
    ld='link', ldflags ='-nologo -nodefaultlib -debug -opt:ref,icf
-libpath:"C:\Perl\lib\CORE"  -machine:x86'
    libpth=\lib
    libs=  oldnames.lib kernel32.lib user32.lib gdi32.lib winspool.lib
comdlg32.lib advapi32.lib shell32.lib ole32.lib oleaut32.lib  netapi32.lib
uuid.lib ws2_32.lib mpr.lib winmm.lib  version.lib odbc32.lib odbccp32.lib
msvcrt.lib
    perllibs=  oldnames.lib kernel32.lib user32.lib gdi32.lib winspool.lib
comdlg32.lib advapi32.lib shell32.lib ole32.lib oleaut32.lib  netapi32.lib
uuid.lib ws2_32.lib mpr.lib winmm.lib  version.lib odbc32.lib odbccp32.lib
msvcrt.lib
    libc=msvcrt.lib, so=dll, useshrplib=true, libperl=perl510.lib
    gnulibc_version=''
  Dynamic Linking:
    dlsrc=dl_win32.xs, dlext=dll, d_dlsymun=undef, ccdlflags=' '
    cccdlflags=' ', lddlflags='-dll -nologo -nodefaultlib -debug
-opt:ref,icf  -libpath:"C:\Perl\lib\CORE"  -machine:x86'

Locally applied patches:
    ACTIVEPERL_LOCAL_PATCHES_ENTRY
    32809 Load 'loadable object' with non-default file extension
    32728 64-bit fix for Time::Local


@INC for perl 5.10.0:
    c:/perl/site/lib
    c:/perl/lib
    .


Environment for perl 5.10.0:
    HOME (unset)
    LANG (unset)
    LANGUAGE (unset)
    LD_LIBRARY_PATH (unset)
    LOGDIR (unset)
    PATH=C:\Program Files (x86)\Microsoft Visual Studio
8\Common7\IDE;C:\Program Files (x86)\Microsoft Visual Studio
8\VC\BIN;C:\Program Files (x86)\Microsoft Visual Studio
8\Common7\Tools;C:\Program Files (x86)\Microsoft Visual Studio
8\Common7\Tools\bin;C:\Program Files (x86)\Microsoft Visual Studio
8\VC\PlatformSDK\bin;C:\Program Files (x86)\Microsoft Visual Studio
8\SDK\v2.0\bin;C:\Windows\Microsoft.NET\Framework\v2.0.50727;C:\Program
Files (x86)\Microsoft Visual Studio
8\VC\VCPackages;c:\cygwin\bin;c:\Users\cpierce\Documents\bin;C:\Windows\system32;C:\Windows;C:\Windows\System32\Wbem;c:\perl\bin;c:\cygwin\bin;c:\program
files (x86)\vim\vim70;C:\Program Files (x86)\MySQL\MySQL Server
5.0\bin;g:\util;g:\tlib;C:\Program
Files (x86)\Microsoft SQL Server\80\Tools\Binn\;C:\Program Files\Microsoft
SQL Server\90\Tools\binn\;C:\Program Files (x86)\Microsoft SQL
Server\90\Tools\binn\;C:\Program Files (x86)\Microsoft SQL
Server\90\DTS\Binn\;C:\Program Files (x86)\Microsoft SQL
Server\90\Tools\Binn\VSShell\Common7\IDE\;C:\Program Files (x86)\Microsoft
Visual Studio 8\Common7\IDE\PrivateAssemblies\;c:\Program Files\Microsoft
SQL Server\90\DTS\Binn\;C:\Program Files (x86)\Sandcastle\ProductionTools\
    PERL_BADLANG (unset)
    SHELL (unset)

[p5pRT]

From clintp@gmail.com

A copy of a sample Data-Dumped file is attached. The sample program I'm
using to demonstrate the bug is​:

#!/usr/bin/perl

use Storable;
open(XML, "t​:\\temp\\Bug50352.xml") || die;

{
  local $/;
  $_=<XML>;
  eval $_;
}

$|=1;
print "Retrieved.\n";
print $VAR1;

# Takes almost immeasurable amount of time in 5.6
# Takes seconds in 5.10
print "Freezing...\n";
my $temp=Storable​::freeze $VAR1;

# Fast again.
print "Thawing...\n";
my $n=Storable​::thaw($temp);

close(XML);

[p5pRT]

From clintp@gmail.com

Bug50352.xml

[p5pRT]

clintp@gmail.com - Status changed from 'new' to 'open'

[p5pRT]

From @nwc10

On Mon, Jan 28, 2008 at 11​:26​:34AM -0800, Clinton A. Pierce wrote​:

To duplicate a large expat-parsed XML structure (with refs of refs of refs),

I'm doing the following​:

my $temp = Storable​::freeze $originalXml;
my $copyXml = Storable​::thaw($temp);

And by "large" I mean about 8MB when dumped with Data​::Dumper. Under Perl
5.6
the "freeze" takes fractions of a second. Under Perl 5.10 it takes many
seconds
(between 5-8 seconds).

Do you have a sample data structure you can attach?
Do you have results for perl 5.8.8?

5.10 comes with Storable 2.18. If you download this from CPAN and build it
for 5.6, is it slow?

Nicholas Clark

[p5pRT]

From clintp@gmail.com

I commented to my own bug report, and a sample structure is attached.

Building Storable 2.18 for 5.6 is going to be really, really tough these
days on my Windows machine which is where I found the problem. If I had a
time machine...

On Jan 29, 2008 4​:53 AM, Nicholas Clark via RT <perlbug-followup@​perl.org>
wrote​:

On Mon, Jan 28, 2008 at 11​:26​:34AM -0800, Clinton A. Pierce wrote​:

To duplicate a large expat-parsed XML structure (with refs of refs of
refs),

I'm doing the following​:

my $temp = Storable​::freeze $originalXml;
my $copyXml = Storable​::thaw($temp);

And by "large" I mean about 8MB when dumped with Data​::Dumper. Under
Perl
5.6
the "freeze" takes fractions of a second. Under Perl 5.10 it takes many
seconds
(between 5-8 seconds).

Do you have a sample data structure you can attach?
Do you have results for perl 5.8.8?

5.10 comes with Storable 2.18. If you download this from CPAN and build it
for 5.6, is it slow?

Nicholas Clark

[p5pRT]

From @steve-m-hay

Clinton Pierce wrote​:

I commented to my own bug report, and a sample structure is attached.

Building Storable 2.18 for 5.6 is going to be really, really tough
these days on my Windows machine which is where I found the problem.
If I had a time machine...

On Jan 29, 2008 4​:53 AM, Nicholas Clark via RT
<perlbug-followup@​perl.org> wrote​:

On Mon, Jan 28, 2008 at 11​:26​:34AM -0800, Clinton A. Pierce wrote​:

To duplicate a large expat-parsed XML structure (with refs of refs
of refs),

I'm doing the following​:

my $temp = Storable​::freeze $originalXml;
my $copyXml = Storable​::thaw($temp);

And by "large" I mean about 8MB when dumped with Data​::Dumper.
Under Perl
5.6
the "freeze" takes fractions of a second. Under Perl 5.10 it takes
many seconds (between 5-8 seconds).

Do you have a sample data structure you can attach?
Do you have results for perl 5.8.8?

5.10 comes with Storable 2.18. If you download this from CPAN and
build it for 5.6, is it slow?

I gave this a quick whirl while waiting for something to compile &&
link...

Using the xml attached in the bug report, my 5.10.0 build takes about
2.7 secs to do the freeze, while my 5.6.2 build takes about 0.9 secs.
Both are using Storable 2.18.

I also tried a 5.8.8 building Storable 2.16​: it takes 2.7 secs again.

(I'm using VC++ 6.0 on Win XP.)

[p5pRT]

From @steve-m-hay

Steve Hay wrote​:

Clinton Pierce wrote​:

I commented to my own bug report, and a sample structure is attached.

Building Storable 2.18 for 5.6 is going to be really, really tough
these days on my Windows machine which is where I found the problem.
If I had a time machine...

On Jan 29, 2008 4​:53 AM, Nicholas Clark via RT
<perlbug-followup@​perl.org> wrote​:

On Mon, Jan 28, 2008 at 11​:26​:34AM -0800, Clinton A. Pierce wrote​:

To duplicate a large expat-parsed XML structure (with refs of refs
of refs),

I'm doing the following​:

my $temp = Storable​::freeze $originalXml;
my $copyXml = Storable​::thaw($temp);

And by "large" I mean about 8MB when dumped with Data​::Dumper.
Under Perl
5.6
the "freeze" takes fractions of a second. Under Perl 5.10 it takes
many seconds (between 5-8 seconds).

Do you have a sample data structure you can attach?
Do you have results for perl 5.8.8?

5.10 comes with Storable 2.18. If you download this from CPAN and
build it for 5.6, is it slow?

I gave this a quick whirl while waiting for something to compile &&
link...

Using the xml attached in the bug report, my 5.10.0 build takes about
2.7 secs to do the freeze, while my 5.6.2 build takes about 0.9 secs.
Both are using Storable 2.18.

I also tried a 5.8.8 building Storable 2.16​: it takes 2.7 secs again.

(I'm using VC++ 6.0 on Win XP.)

More detail​:

There is definitely a difference between 5.6.2 and 5.10.0, but a far
more significant difference is brought about by using different mallocs​:

With 5.10.0 the freeze takes about 2.7 secs with the system malloc and
0.03 secs with perl's malloc.
With 5.6.2 it takes about 0.9 secs with the system malloc and 0.03 secs
with perl's malloc.

Not sure why the system malloc figure is slower with 5.10.0, but if the
0.03 secs is more like the time that you were seeing previously, could
it be that your 5.6.x build was using perl's malloc and now your 5.10.0
build is using the system malloc? (ActivePerl builds use the system
malloc because perl's malloc currently doesn't work with "-D
PERL_IMPLICIT_SYS", which is required for the fork() emulation.)

[p5pRT]

From @steve-m-hay

Yes, the usemymalloc=n means your 5.6 was using the system malloc
anyway, so that doesn't explain your problem (although the perl malloc
would still solve it if you were able to use it).

I noticed that you were using 5.6.0 rather than the 5.6.2 that I tried,
so I thought I'd give 5.6.0 a try too. I found that Storable 2.18
doesn't build with it, and I had to go back to 2.12 to get one that
works. 5.6.0+2.12 (with the system malloc) takes about 0.7 secs here,
which is a shade faster than 5.6.2+2.18, but not by much.

The part of 2.13 onwards that doesn't build with 5.6.0 is UTF8 stuff
(bytes_from_utf8 caused a linker error), and I see 2.13's ChangeLog
mentions handling utf8 data. Perhaps this is the difference? (i.e. Your
5.6.0 used an old Storable that doesn't do UTF8 properly, and 5.10.0 is
slower because it uses the current Storable which does handle it?)

________________________________

From​: Clinton Pierce [mailto​:clintp@​gmail.com]
Sent​: 29 January 2008 16​:25
To​: Steve Hay; perlbug-followup@​perl.org
Subject​: Re​: [perl #50352] Perl 5.10 Storable extremely slow for large
trees of data

As a followup to myself, I ran perl -V on the 5.6 build that's nice and
fast. The usemymalloc=n would seem to indicate that it's already using
the system-supplied malloc.

Summary of my perl5 (revision 5 version 6 subversion 0) configuration​:

On Jan 29, 2008 11​:19 AM, Clinton Pierce <clintp@​gmail.com> wrote​:

  More detail​:
 
  There is definitely a difference between 5.6.2 and
5.10.0, but a far
  more significant difference is brought about by using
different mallocs​:
 
  With 5.10.0 the freeze takes about 2.7 secs with the
system malloc and
  0.03 secs with perl's malloc.
  With 5.6.2 it takes about 0.9 secs with the system
malloc and 0.03 secs
  with perl's malloc.
 
  Not sure why the system malloc figure is slower with
5.10.0, but if the
  0.03 secs is more like the time that you were seeing
previously, could
  it be that your 5.6.x build was using perl's malloc and
now your 5.10.0
  build is using the system malloc? (ActivePerl builds use
the system
  malloc because perl's malloc currently doesn't work with
"-D
  PERL_IMPLICIT_SYS", which is required for the fork()
emulation.)

 
  Good find.
 
  And that pretty much leaves me up a creek. I can't really use a
self-built Perl for Production in my situation, and the supplied one is
far, far too slow. Maybe I'll have to find another distribution source
or stay on 5.6.
 
 
 
 

[p5pRT]

From clintp@gmail.com

As a followup to myself, I ran perl -V on the 5.6 build that's nice and
fast. The usemymalloc=n would seem to indicate that it's already using the
system-supplied malloc.

Summary of my perl5 (revision 5 version 6 subversion 0) configuration​:
  Platform​:
  osname=MSWin32, osvers=4.0, archname=MSWin32-x86-multi-thread
  uname=''
  config_args='undef'
  hint=recommended, useposix=true, d_sigaction=undef
  usethreads=undef use5005threads=undef useithreads=define
usemultiplicity=define
  useperlio=undef d_sfio=undef uselargefiles=undef
  use64bitint=undef use64bitall=undef uselongdouble=undef usesocks=undef
  Compiler​:
  cc='cl', optimize='-O1 -MD -DNDEBUG', gccversion=
  cppflags='-DWIN32'
  ccflags ='-O1 -MD -DNDEBUG -DWIN32 -D_CONSOLE -DNO_STRICT
-DHAVE_DES_FCRYPT -DPERL_IMPLICIT_CONTEXT -DPERL_IMPLICIT_SYS -DPERL_
MSVCRT_READFIX'
  stdchar='char', d_stdstdio=define, usevfork=false
  intsize=4, longsize=4, ptrsize=4, doublesize=8
  d_longlong=undef, longlongsize=8, d_longdbl=define, longdblsize=10
  ivtype='long', ivsize=4, nvtype='double', nvsize=8, Off_t='off_t',
lseeksize=4
  alignbytes=8, usemymalloc=n, prototype=define
  Linker and Libraries​:
  ld='link', ldflags ='-nologo -nodefaultlib -release
-libpath​:"D​:\Perl\lib\CORE" -machine​:x86'
  libpth="C​:\Program Files\Mts\Lib" "D​:\Perl\lib\CORE"
  libs= oldnames.lib kernel32.lib user32.lib gdi32.lib winspool.lib
comdlg32.lib advapi32.lib shell32.lib ole32.lib oleaut32.lib
  netapi32.lib uuid.lib wsock32.lib mpr.lib winmm.lib version.lib
odbc32.lib odbccp32.lib msvcrt.lib
  libc=msvcrt.lib, so=dll, useshrplib=yes, libperl=perl56.lib
  Dynamic Linking​:
  dlsrc=dl_win32.xs, dlext=dll, d_dlsymun=undef, ccdlflags=' '
  cccdlflags=' ', lddlflags='-dll -nologo -nodefaultlib -release
-libpath​:"D​:\Perl\lib\CORE" -machine​:x86'

Characteristics of this binary (from libperl)​:
  Compile-time options​: MULTIPLICITY USE_ITHREADS PERL_IMPLICIT_CONTEXT
PERL_IMPLICIT_SYS
  Locally applied patches​:
  ActivePerl Build 623
  Built under MSWin32
  Compiled at Dec 15 2000 16​:27​:07
  @​INC​:
  T​:/Perl/lib
  T​:/Perl/site/lib
  .

On Jan 29, 2008 11​:19 AM, Clinton Pierce <clintp@​gmail.com> wrote​:

More detail​:

There is definitely a difference between 5.6.2 and 5.10.0, but a far
more significant difference is brought about by using different mallocs​:

With 5.10.0 the freeze takes about 2.7 secs with the system malloc and
0.03 secs with perl's malloc.
With 5.6.2 it takes about 0.9 secs with the system malloc and 0.03 secs
with perl's malloc.

Not sure why the system malloc figure is slower with 5.10.0, but if the
0.03 secs is more like the time that you were seeing previously, could
it be that your 5.6.x build was using perl's malloc and now your 5.10.0
build is using the system malloc? (ActivePerl builds use the system
malloc because perl's malloc currently doesn't work with "-D
PERL_IMPLICIT_SYS", which is required for the fork() emulation.)

Good find.

And that pretty much leaves me up a creek. I can't really use a
self-built Perl for Production in my situation, and the supplied one is far,
far too slow. Maybe I'll have to find another distribution source or stay
on 5.6.

[p5pRT]

From clintp@gmail.com

More detail​:

There is definitely a difference between 5.6.2 and 5.10.0, but a far
more significant difference is brought about by using different mallocs​:

With 5.10.0 the freeze takes about 2.7 secs with the system malloc and
0.03 secs with perl's malloc.
With 5.6.2 it takes about 0.9 secs with the system malloc and 0.03 secs
with perl's malloc.

Not sure why the system malloc figure is slower with 5.10.0, but if the
0.03 secs is more like the time that you were seeing previously, could
it be that your 5.6.x build was using perl's malloc and now your 5.10.0
build is using the system malloc? (ActivePerl builds use the system
malloc because perl's malloc currently doesn't work with "-D
PERL_IMPLICIT_SYS", which is required for the fork() emulation.)

Good find.

And that pretty much leaves me up a creek. I can't really use a self-built
Perl for Production in my situation, and the supplied one is far, far too
slow. Maybe I'll have to find another distribution source or stay on 5.6.

[p5pRT]

From clintp@gmail.com

On Jan 29, 2008 1​:07 PM, Steve Hay <SteveHay@​planit.com> wrote​:

Yes, the usemymalloc=n means your 5.6 was using the system malloc anyway,
so that doesn't explain your problem (although the perl malloc would still
solve it if you were able to use it).

I noticed that you were using 5.6.0 rather than the 5.6.2 that I tried, so
I thought I'd give 5.6.0 a try too. I found that Storable 2.18 doesn't
build with it, and I had to go back to 2.12 to get one that works.
5.6.0+2.12 (with the system malloc) takes about 0.7 secs here, which is a
shade faster than 5.6.2+2.18, but not by much.

The part of 2.13 onwards that doesn't build with 5.6.0 is UTF8 stuff
(bytes_from_utf8 caused a linker error), and I see 2.13's ChangeLog
mentions handling utf8 data. Perhaps this is the difference? (i.e. Your
5.6.0 used an old Storable that doesn't do UTF8 properly, and 5.10.0 is
slower because it uses the current Storable which does handle it?)

That is a possibility. We're not using any UTF8 stuff here at all -- it's
all 8-bit ASCII -- so I wouldn't have noticed a difference at all over the
years.

I checked the Storable in the 5.6 distribution we're using here -- Version
1.010. Maybe I can get that version to compile against Perl 5.10? I
honestly don't know.

[p5pRT]

From @steve-m-hay

Clinton Pierce wrote​:

On Jan 29, 2008 1​:07 PM, Steve Hay <SteveHay@​planit.com> wrote​:

Yes, the usemymalloc=n means your 5.6 was using the system malloc
anyway, so that doesn't explain your problem (although the perl
malloc would still solve it if you were able to use it).

I noticed that you were using 5.6.0 rather than the 5.6.2 that I
tried, so I thought I'd give 5.6.0 a try too. I found that Storable
2.18 doesn't build with it, and I had to go back to 2.12 to get one
that works.
5.6.0+2.12 (with the system malloc) takes about 0.7 secs here, which
is a shade faster than 5.6.2+2.18, but not by much.

The part of 2.13 onwards that doesn't build with 5.6.0 is UTF8 stuff
(bytes_from_utf8 caused a linker error), and I see 2.13's ChangeLog
mentions handling utf8 data. Perhaps this is the difference? (i.e.
Your
5.6.0 used an old Storable that doesn't do UTF8 properly, and 5.10.0
is slower because it uses the current Storable which does handle it?)

That is a possibility. We're not using any UTF8 stuff here at all --
it's all 8-bit ASCII -- so I wouldn't have noticed a difference at
all over the years.

I checked the Storable in the 5.6 distribution we're using here --
Version
1.010. Maybe I can get that version to compile against Perl 5.10? I
honestly don't know.

Not straight out-of-the-box. I tried with 1.0.14 and then again with
2.12 (the version prior to the UTF8 changes), but they both choke on
"case SVt_PVBM" in sv_type(). I don't know how to workaround that to get
it building with 5.10, but if it (and any other build problems) can be
worked around then I guess there is no other reason why these older
versions shouldn't work with 5.10, and it would be interesting to see if
that gives you your speed back.

[p5pRT]

From @nwc10

On Wed, Jan 30, 2008 at 09​:43​:22AM -0000, Steve Hay wrote​:

Not straight out-of-the-box. I tried with 1.0.14 and then again with
2.12 (the version prior to the UTF8 changes), but they both choke on
"case SVt_PVBM" in sv_type(). I don't know how to workaround that to get
it building with 5.10, but if it (and any other build problems) can be

I think like this​:

#if PERL_VERSION < 9
  case SVt_PVBM​:
#endif

It's what the current Storable has, and I'd be surprised if anyone ever
managed to get an SV of type SVt_PVBM into a data structure that they were
able to pass into Storable.

Nicholas Clark

[p5pRT]

From @steve-m-hay

Nicholas Clark wrote​:

On Wed, Jan 30, 2008 at 09​:43​:22AM -0000, Steve Hay wrote​:

Not straight out-of-the-box. I tried with 1.0.14 and then again with
2.12 (the version prior to the UTF8 changes), but they both choke on
"case SVt_PVBM" in sv_type(). I don't know how to workaround that to
get it building with 5.10, but if it (and any other build problems)
can be

I think like this​:

#if PERL_VERSION < 9
case SVt_PVBM​:
#endif

It's what the current Storable has, and I'd be surprised if anyone
ever managed to get an SV of type SVt_PVBM into a data structure that
they were able to pass into Storable.

OK, that gets it building and it passed all tests still.

Unfortunately, it's no quicker than 2.18 was with my 5.10/system-malloc
build (about 2.3 secs with either version). (I had to manually delete
the 2.18 version that ships with 5.10 from the lib/ folder, because
1.0.14 installed into site/lib/.)