toddr
Memory leaks (doubles the input buffer size at regular intervals, with no limit on that)
Seems to indefinitely grow the input buffer by double at regular intervals, resulting in system memory starvation eventually.
Example of problem:-
# echo ' PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND ';for I in {0..999};do top -n 1 | grep ipcrun_leak.pl;sleep 10;done
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
15660 root 20 0 129696 56252 4724 S 47.1 0.1 0:03.41 perl ipcrun_leak.pl
15660 root 20 0 181544 135032 4724 R 41.2 0.3 0:08.12 perl ipcrun_leak.pl
15660 root 20 0 224924 169084 4724 S 37.5 0.4 0:12.57 perl ipcrun_leak.pl
15660 root 20 0 292704 239724 4724 S 43.8 0.6 0:17.12 perl ipcrun_leak.pl
15660 root 20 0 2445980 404572 4724 S 35.3 1.0 0:21.56 perl ipcrun_leak.pl
15660 root 20 0 2445980 404572 4724 S 43.8 1.0 0:26.09 perl ipcrun_leak.pl
15660 root 20 0 2445980 404572 4724 S 43.8 1.0 0:30.59 perl ipcrun_leak.pl
15660 root 20 0 2504816 486744 4724 S 41.2 1.2 0:35.19 perl ipcrun_leak.pl
15660 root 20 0 2578364 570816 4724 R 50.0 1.4 0:39.81 perl ipcrun_leak.pl
15660 root 20 0 2670296 652012 4724 S 41.2 1.6 0:44.40 perl ipcrun_leak.pl
15660 root 20 0 2785216 735044 4724 S 43.8 1.8 0:49.00 perl ipcrun_leak.pl
15660 root 20 0 2928860 1.3g 4724 R 43.8 3.4 0:53.76 perl ipcrun_leak.pl
15660 root 20 0 2928860 1.3g 4724 R 47.1 3.4 0:58.36 perl ipcrun_leak.pl
15660 root 20 0 2928860 1.3g 4724 R 35.3 3.4 1:02.89 perl ipcrun_leak.pl
15660 root 20 0 2928860 1.3g 4724 S 50.0 3.4 1:07.48 perl ipcrun_leak.pl
[etc]
15660 root 20 0 14.3g 12.6g 4724 S 43.8 32.1 3:51.89 perl ipcrun_leak.pl
The code causing the leak:-
#!/usr/bin/perl -w
use strict;
use IPC::Run qw( start pump finish timeout );
my ($fh, $got);
open($fh,'<','data.json.bz2') or die $!; # Put a huge (e.g. 2gb) .bz2-compressed file here
my @cmd=('bzip2','-d'); my($in,$out)=('','');
my $h = start \@cmd, \$in, \$out;
my($ol)=0;
do {
my $buf; $got=sysread($fh, $buf, 1024);
if(length($in) < $ol) { print "$ol " . length($in) . "\n"; } # Example showing where the bug is
$ol=length($in);
$in.=$buf; $h->pump();
if(length($out)) {
#$md5->add($out); # Process the decompressed stream
$out='';
}
} until($got<1024);
$h->finish();
if(length($out)) {
#$md5->add($out); # Process the decompressed stream
$out='';
}
Outputs:-
# perl ipcrun_leak.pl
180224 0
579584 0
1741824 0
5782528 0
18942976 0
60907520 0
190749696 0
570285056 0
Example input file size:-
# dir data.json.bz2
-rwxr-xr-x. 1 root cnd 2052715775 Jan 7 2018 data.json.bz2
#
Version:-
cpan[1]> i IPC::Run
Reading '/home/cnd/.local/share/.cpan/Metadata'
Database was generated on Thu, 19 May 2022 13:17:03 GMT
Module id = IPC::Run
CPAN_USERID TODDR (Todd Rinaldo <[email protected]>)
CPAN_VERSION 20200505.0
CPAN_FILE T/TO/TODDR/IPC-Run-20200505.0.tar.gz
UPLOAD_DATE 2020-05-05
MANPAGE IPC::Run - system() and background procs w/ piping, redirs, ptys (Unix, Win32)
INST_FILE /usr/local/share/perl5/IPC/Run.pm
INST_VERSION 20200505.0
The size issue is almost exactly 3 x (not double, like I said before).
i.e. Each time it's consumed X bytes, it flushes its buffer, and X=X*3 for next time...
Same problem using brotli instead of bzip2 (in case you're wondering)
#!/usr/bin/perl -w
use strict;
use IPC::Run qw( start pump finish timeout );
my ($fh, $got);
open($fh,'<','ticks-2021_12_04.json.br') or die $!; # Put a huge (e.g. 2gb) file here
my @cmd=('brotli','-d','-f'); my($in,$out)=('','');
my $h = start \@cmd, \$in, \$out;
my($ol,$l)=(0,0);
my $buffsz=102400;
do {
my $buf; $got=sysread($fh, $buf, $buffsz);
if(length($in) < $l) { print "$l " . length($in) . "\n"; } # Example showing where the bug is
$in.=$buf; $h->pump();
$ol=length($in); $l=$ol;
while(length($out) || $ol) {
$out='';
$h->pump_nb(); # This consumes stuff - but doesn't stop the buffer tripling in size periodically
if($ol==length($in)) { $ol=0; } else {$ol=length($in);}
}
} until($got<$buffsz);
$h->finish();
if(length($out)) {
$out='';
}
Digging further into this... I notice that using a buffer size of 310 or less bytes tends not to cause the problem
Using 320 or more bytes for the buffer, and the problem rapidly grows.
Strange, but true.
i.e. This works, albeit annoyingly slowly, owing to the tiny buffer...
#!/usr/bin/perl -w
use strict;
use IPC::Run qw( start pump finish timeout );
my ($fh, $got);
open($fh,'<','ticks.json.br') or die $!;
my @cmd=('brotli','-d','-f'); my($in,$out)=('','');
#open($fh,'<','data.bz2') or die $!; # both brotli and bzip2 work with 310 or less byte buffers
#my @cmd=('bzip2','-d'); my($in,$out)=('','');
my $h = start \@cmd, \$in, \$out;
my($ol)=0; my $buffsz=310; my %seen;
do {
my $buf; $got=sysread($fh, $buf, $buffsz);
if(length($in) < $ol) { print "$ol " . length($in) . "\n" unless($seen{$ol}++); }
$ol=length($in);
$in.=$buf;
my $more=0;
do {
$more=! $h->pump(); #$in='';
warn length($in) . "\t" . length($out) if($more); # Never happens
if(length($out)) {
#$md5->add($out); # Process the decompressed stream
#print $out;
$out='';
}
} while($more); # pump
} until($got<$buffsz);
$h->finish();
if(length($out)) {
#$md5->add($out); # Process the decompressed stream
$out='';
}
# print $md5->hexdigest;
print " end.\n";
exit(0);
Output:-
# perl ipcrun_leak0.pl
43400 0
2170 0
55800 0
3100 0
55490 0
3410 0
55180 0
54870 0
54560 0
2790 0
54250 0
53320 0
58590 0
58280 0
53940 0
57350 0
57970 0
57660 0
59520 0
57040 0
58900 0
52700 0
59210 0
56730 0
56110 0
53630 0
53010 0
56420 0
51150 0
52080 0
49910 0
52390 0
51770 0
51460 0
48360 0
2480 0
50530 0
50840 0
3720 0
48670 0
114390 0
117490 0
62310 0
113770 0
62000 0
50220 0
111910 0
117180 0
115320 0
115940 0
49290 0
41850 0
34410 0
1860 0
25110 0
1240 0
37820 0
36890 0
end.
Memory:-
# echo ' PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND ';for I in {0..999};do top -n 1 | grep ipcrun_leak;sleep 10;done
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
24826 root 20 0 41936 10688 4648 S 52.9 0.0 5:16.35 perl ipcrun_leak0.pl
24826 root 20 0 41936 10688 4648 R 62.5 0.0 5:22.33 perl ipcrun_leak0.pl
24826 root 20 0 41936 10688 4648 R 62.5 0.0 5:28.28 perl ipcrun_leak0.pl
24826 root 20 0 41936 10688 4648 R 56.2 0.0 5:34.25 perl ipcrun_leak0.pl
24826 root 20 0 41936 10688 4648 S 52.9 0.0 5:40.15 perl ipcrun_leak0.pl
24826 root 20 0 41936 10688 4648 S 56.2 0.0 5:46.01 perl ipcrun_leak0.pl
24826 root 20 0 41936 10688 4648 S 52.9 0.0 5:51.97 perl ipcrun_leak0.pl
24826 root 20 0 41936 10688 4648 R 52.9 0.0 5:58.02 perl ipcrun_leak0.pl
I spent all day trying to find and fix the bug, with no luck. I attempted to use IPC::Run3 as an alternative, but that has even more bugs, and doesn't seem to have any pump() mechanism, making it not very useful.
If anyone can give me some clues about where and/or why this buffer-size-tripling might be taking place, do please let me know!! The code is almost beyond comprehension to me - I only have 26 years perl experience...
OK - so another whole day on this problem, and I discovered this workaround. Basically - if IPC::Run does not consume the entire input you last gave it, you must back-off the amount of data you give it next time (to 240 bytes max) until pump() has finally consumed it all, then you can go back to sending larger buffers. 65536 seems to be the most it ever reads in one go - so use that.
Working example:-
#!/usr/bin/perl -w
use strict;
use IPC::Run qw( start pump finish timeout );
my ($fh, $got);
open($fh,'<','data.json.bz2') or die $!; # Put a huge (e.g. 2gb) .bz2-compressed file here
my @cmd=('bzip2','-d'); my($in,$out)=('','');
my $h = start \@cmd, \$in, \$out;
my($inl)=0; my($outl)=0; my ($oinl,$ooutl); my $buffsz;
do {
my $buf='';
$buffsz = (length($in) > 0) ? 248 : 65536;
$got=sysread($fh, $buf, $buffsz);
$in.=$buf; $h->pump();
$inl=length($in);
do { # Flush as much in and out as we can, before sending any more.
$h->pump_nb() if($inl);
if(length($out)) { $out=''; } # Read and process the output here.
($oinl,$ooutl)=($inl,$outl);
$inl=length($in); $outl=length($out);
} while((($inl!=$oinl) || $outl!=$ooutl) && ( $inl>0 || $outl>0 ));
} until($got<$buffsz);
$h->finish();
if(length($out)) { $out=''; } # Finish processing the output
exit(0);
Two+ more days on this problem, again... the bug appears to be inside Run.pm in the _select_loop handler:
When the pipe is finish()'d it enters a loop which drains all the process output into the buffer "while ( $self->pumpable )"
That's wrong. e.g. A brotli-compressed logfile can easily return tens or hundreds of gigs at this point.
I'm not sure how to fix...
The docs show the example code assigning to (i.e. overwriting) the contents of $in, whereas you're appending to it. Is that really what you intend to do, i.e. keep sending the same input but with more stuff added to the end? Apologies if I am misunderstanding something, I am highly rusty on this module.
$in is not necessarily always consumed entirely in each "pump" (depends on the simplicity/triviality of the receiving process I expect, but for brotli and bzip2, and in-general all well-behaved code etc, you can't just overwrite $in)
The bug is in the finish() sub in Run.pm:-
while ( $self->pumpable ) {
$self->_select_loop($options);
}
It doesn't yield to the caller at any time until it has accumulated the entirety of the decompressed-output in RAM... which, for my brotli-compressed log files when you finally reach the end of the compressed input, is way more ram and swap than I've got...
Having stared at the various versions of your code for about 15 mins, I am somewhat stumped: all the abbreviated variable names may make perfect sense to you, but I am not going to write myself a lookup chart to constantly refer back to, to keep decoding what e.g. $ol or $inl mean. I'm a fan of short variable names if there's a couple, but this is too many for my small brain.
What you say about $in not always being fully consumed makes sense, thank you. It looks like you're:
- reading a compressed
.bz2file a chunk at a time, sending it using IPC::Run to a decompressor, then in a loop:- reading output from that
- then (quite rightly, for debugging purposes) throwing it away
- stopping when no more input
I don't understand how there is room for any large amount of data to be pending in the above scenario, for finish to have to deal with. It does seem to me like finish is doing the right thing (keep processing everything) because that's what I would expect finish to do. I'm not saying there's no error here, but I am saying I don't see it yet.
@mohawk2 - compression programs consume input, and spit back expanded output - but it's not a "give one get one" relationship - you might give it data, and get nothing back (yet). When it comes to the end of the file, the decompressor, before it knows that no more input is coming, has not necessarily given you back all the expanded output it can - only when you finally close the input handle, does the decompressor know that no more data is coming in - and at this point, it finally returns the expansion of everything you gave it before.
That's where the bug is. It's an architectural error on the part of the module author - not something that can be trivially fixed by changing the code - the entire way the module works needs to be changed... The bug is that after you close the handle, it accumulates all the output into memory, because there's no way that the caller can continue to iterate over the (now closed, or half-closed) pump loop after performing the close.
I fixed this by writing my own code to replace the flawed IPC::Run version entirely - you can see my approach here: https://github.com/gitcnd/perl-IPC-Open3-example/blob/master/ipc_open3_example.pl
It sounds like this module's API needs a close_fh type of method? That would let you do that, yet keep pumping for output.