PERL Modules - Storable: store_fd takes forever to write data to file on 64bit machine

Author

Storable: store_fd takes forever to write data to file on 64bit machine

danielB

2006-11-22, 6:57 pm

Hi!
A routine that writes complex data structures to a file using Storable
(2.14) runs fine on a 32bit-machine with SuSE 9.3 installed (Perl
5.8.4). Storing that data takes less than 10 seconds and results in a
file of about 50MB size.

If I run the same routine on a 64bit-intel-architecture (4 GB ram, two
3 GHz CPUs, Linux (SLES9), Storable is Version 2.15, perl 5.8.3), it
takes forever to write that data to file. (I don't know if it ever
finishes, aborted the program after several hours).

I can watch the file grow slowly, so store_fd doesn't seem to "hang",
it just is painfully slow and gets slower and slower while running. I
can watch it get slower and slower using "strace -e trace=write", too.
At first, lines like
write(3, " \26\3\0\0\0dst\4\3\5\0\0\0\4\0\0\4Y\26\3
\0\0\0src\4\2\2"...,
4096) = 4096
just seem to fly across the screen but that flying gets slower and
slower and is reduced to a trickle within half a minute.
Watching top reveals that memory is not the problem, less than 10% is
used. CPU usage is near 100% though.

Has anybody any idea what I can do about this? Switching to
Data::Dumper for serialization unfortunately is not an option, since it
cannot handle the cross-referencing data-structures. Should I upgrade
Perl to a newer version?

Haven't tried FreezeThaw yet, maybe that could be an option!?

Any help or pointers appreciated ...

Kind regards,
D.B.

danielB

2006-11-23, 7:57 am

An addition to my own post:
The problem seems to be in the C-function pstore used by Storable. I
built a simple test in which I created an array and a hash with 100000
elements respectively and tried to write them to a file with Storables
store function. That should be done in the blink of an eye, yet it
takes more than half a minute.

Running that test with -d:DProf yields:

Storable::_store has 1 unstacked calls in outer
Exporter::export has -2 unstacked calls in outer
Exporter::Heavy::heavy_export has 2 unstacked calls in outer
Storable::store has 1 unstacked calls in outer
AutoLoader::AUTOLOAD has -2 unstacked calls in outer
Total Elapsed Time = 31.29980 Seconds
User+System Time = 31.29980 Seconds
Exclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c Name
99.0 31.01 31.010 1 31.010 31.010 Storable::pstore
0.06 0.020 0.020 4 0.0050 0.0050 Storable::BEGIN
0.03 0.010 0.010 2 0.0050 0.0050 AutoLoader::AUTOLOAD
0.03 0.010 0.030 4 0.0025 0.0075 main::BEGIN
0.00 0.000 0.000 2 0.0000 0.0000
Exporter::Heavy::heavy_export
0.00 0.000 0.000 1 0.0000 0.0000 Storable::store
0.00 0.000 0.000 1 0.0000 0.0000 Storable::_store
0.00 - -0.000 1 - - Fcntl::bootstrap
0.00 - -0.000 1 - - Config::TIEHASH
0.00 - -0.000 1 - - Storable::bootstrap
0.00 - -0.000 1 - - warnings::BEGIN
0.00 - -0.000 1 - - Fcntl::BEGIN
0.00 - -0.000 1 - - AutoLoader::import
0.00 - -0.000 1 - - Config::import
0.00 - -0.000 1 - - DynaLoader::dl_load_flags

I am not very confident that I could dig even deeper and find the
problem in pstore ...

Anybody?

Kind regards,
Daniel.

danielB schrieb:

> Hi!
> A routine that writes complex data structures to a file using Storable
> (2.14) runs fine on a 32bit-machine with SuSE 9.3 installed (Perl
> 5.8.4). Storing that data takes less than 10 seconds and results in a
> file of about 50MB size.
>
> If I run the same routine on a 64bit-intel-architecture (4 GB ram, two
> 3 GHz CPUs, Linux (SLES9), Storable is Version 2.15, perl 5.8.3), it
> takes forever to write that data to file. (I don't know if it ever
> finishes, aborted the program after several hours).
>
> I can watch the file grow slowly, so store_fd doesn't seem to "hang",
> it just is painfully slow and gets slower and slower while running. I
> can watch it get slower and slower using "strace -e trace=write", too.
> At first, lines like
> write(3, " \26\3\0\0\0dst\4\3\5\0\0\0\4\0\0\4Y\26\3
\0\0\0src\4\2\2"...,
> 4096) = 4096
> just seem to fly across the screen but that flying gets slower and
> slower and is reduced to a trickle within half a minute.
> Watching top reveals that memory is not the problem, less than 10% is
> used. CPU usage is near 100% though.
>
> Has anybody any idea what I can do about this? Switching to
> Data::Dumper for serialization unfortunately is not an option, since it
> cannot handle the cross-referencing data-structures. Should I upgrade
> Perl to a newer version?
>
> Haven't tried FreezeThaw yet, maybe that could be an option!?
>
> Any help or pointers appreciated ...
>
> Kind regards,
> D.B.

Ilya Zakharevich

2006-11-23, 9:56 pm

[A complimentary Cc of this posting was sent to
danielB
<daniel.brunkhorst@web.de>], who wrote in article <1164289947.755266.263730@m7g2000cwm.googlegroups.com>:
> An addition to my own post:
> The problem seems to be in the C-function pstore used by Storable. I
> built a simple test in which I created an array and a hash with 100000
> elements respectively and tried to write them to a file with Storables
> store function. That should be done in the blink of an eye, yet it
> takes more than half a minute.

How long does it take on 32bit machine?
[color=darkred]

Data::Dumper should be a last choice when serialization is considered.
Did you consider other serialization modules? [Note that FreezeThaw
builds things in memory, but tieing a scalar to a file may be
possible.]

Yours,
Ilya

danielB

2006-12-04, 6:57 pm

Storable version 2.15 caused that problem. I tried the same code on a
different, similarly equipped 64bit machine wit same perl but different
Storable version (2.09). Downgrading to 2.09 on the machine that caused
problems solved the issue, although it is totally unclear to me where
the actual problem was ...

Cheers,
danielB.

danielB schrieb:
[color=darkred]
> An addition to my own post:
> The problem seems to be in the C-function pstore used by Storable. I
> built a simple test in which I created an array and a hash with 100000
> elements respectively and tried to write them to a file with Storables
> store function. That should be done in the blink of an eye, yet it
> takes more than half a minute.
>
> Running that test with -d:DProf yields:
>
> Storable::_store has 1 unstacked calls in outer
> Exporter::export has -2 unstacked calls in outer
> Exporter::Heavy::heavy_export has 2 unstacked calls in outer
> Storable::store has 1 unstacked calls in outer
> AutoLoader::AUTOLOAD has -2 unstacked calls in outer
> Total Elapsed Time = 31.29980 Seconds
> User+System Time = 31.29980 Seconds
> Exclusive Times
> %Time ExclSec CumulS #Calls sec/call Csec/c Name
> 99.0 31.01 31.010 1 31.010 31.010 Storable::pstore
> 0.06 0.020 0.020 4 0.0050 0.0050 Storable::BEGIN
> 0.03 0.010 0.010 2 0.0050 0.0050 AutoLoader::AUTOLOAD
> 0.03 0.010 0.030 4 0.0025 0.0075 main::BEGIN
> 0.00 0.000 0.000 2 0.0000 0.0000
> Exporter::Heavy::heavy_export
> 0.00 0.000 0.000 1 0.0000 0.0000 Storable::store
> 0.00 0.000 0.000 1 0.0000 0.0000 Storable::_store
> 0.00 - -0.000 1 - - Fcntl::bootstrap
> 0.00 - -0.000 1 - - Config::TIEHASH
> 0.00 - -0.000 1 - - Storable::bootstrap
> 0.00 - -0.000 1 - - warnings::BEGIN
> 0.00 - -0.000 1 - - Fcntl::BEGIN
> 0.00 - -0.000 1 - - AutoLoader::import
> 0.00 - -0.000 1 - - Config::import
> 0.00 - -0.000 1 - - DynaLoader::dl_load_flags
>
>
> I am not very confident that I could dig even deeper and find the
> problem in pstore ...
>
> Anybody?
>
> Kind regards,
> Daniel.
>
>
>
> danielB schrieb:
>

Sponsored Links