When I run an evolution of this script with a particular set of arguments: Ibufd.pl -IBUF=20971520 -NBUF=6000 1GB.csv, about 18 seconds into a 2 minute run, the cpu and IO activity suddenly drop to 0 and stay there for 3 seconds. Memory requirements are exactly stable at that point in time and the overall memory requirements are well within the bounds of my free physical storage.

I've posted a screen grab graphing the cpu/memory/IO history of the entire process run here. The vertical divisions represent 3 seconds. This is entirely consistent regardless of what else is running or how many times I re-run the test.

I'm trying to track down the cause of the pause. I've tried several methods of trying to instrument the process, but all of them completely change the performance characteristics of the process rendering all the information produced meaningless. My purpose in posting is to try and get answers to the following questions:

1. Is this down to my system?

   If anyone running Win64/AS1007 can reproduce the graph it might be helpful.

   If anyone with a non-windows system has the tools to produce a similar graph (or at least data points) on their system, that might be even more useful.

2. How can I work out what is going on inside the script during those 3 seconds?

   At it simplest, a time-point/line-number trace might shed some light, but how can I produce it without changing the performance characteristics?

3. Anyone have any thoughts, evidence or just wild speculations (preferably not alien-based) as to what might be the cause?

   Speculations accompanied by mechanisms of how to verify would be most useful.

To aid anyone thinking of trying to reproduce the problem, this script (with default options) will create a 1GB CSV file consistent with the input expectation of the script:

And this is the evolved script, the required command line is shown at the bottom:

#! perl -slw
use strict;

our $NBUF //= 5000;
our $IBUF //= 2e6;

my $start  = time;

my @outFHs;
my @outBufs;
my $n = 0;
my( $o, $buf ) = 0;

open DISK, '<', $ARGV[0] or die $!;

while( read( DISK, $buf, $IBUF, $o ) ) {
    open RAM, '<', \$buf;
    while( my $line = <RAM> ) {
        unless( $line =~ /\n$/ ) {
            $buf = $line;
            $o = length $buf;
            next;
        }
        ++$n;
        my $key = substr( $line, 7, 3 ) % 600;
        if(
            push( @{ $outBufs[ $key ] }, $line ) > $NBUF
        or
            !$outFHs[ $key ] && @{ $outBufs[ $key ] } > rand( $NBUF )

        ) {
            unless( defined $outFHs[ $key ] ) {
                open $outFHs[ $key ], '>', "$key.out" or die $!;
            }
            print { $outFHs[ $key ] } @{ $outBufs[ $key ] };
            @{ $outBufs[ $key ] } = ();
        }
    }
}

print { $outFHs[ $_ ] } @{ $outBufs[ $_ ] } for 0 .. $#outBufs;
close $_ for @outFHs;
close DISK;

printf "Took %d seconds for $n records\n", time() - $start, $n;

__END__
C:\test>Ibufd.pl -IBUF=20971520 -NBUF=6000 1GB.csv
Took 114 seconds for 16777216 records
[download]

A hearty thank-you to anyone taking the time to help me with this.