Skip Menu |

This queue is for tickets about the Compress-Raw-Lzma CPAN distribution.

Report information
The Basics
Id: 128194
Status: resolved
Priority: 0/
Queue: Compress-Raw-Lzma
People
Owner: Nobody in particular
Requestors: SREZIC [...] cpan.org
Cc:
AdminCc:
Bug Information
Severity: (no value)
Broken in: 2.084
Fixed in: 2.085

History Show all quoted text
  Mon Jan 07 16:13:37 2019 SREZIC [...] cpan.org - Ticket created
Subject: t/050interop-xz.t may fail (memory leak?)
On a few of my smokers the test suite fails like in this report: http://www.cpantesters.org/cpan/report/ba2d8f26-11ca-11e9-b3e9-cc477c15f8a6 What's strange here: apparently system("xz ...") did not return 0, but $? is zero, as the diag() output following the system() call shows. I could not reproduce the failure outside of CPAN.pm, e.g. using "perl -Mblib t/050interop-xz.t" or "make test". But I could reproduce it with "cpan -t .". An strace log shows the following line: 19814 20:48:51.556543 clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f2d96c5e590) = -1 ENOMEM (Cannot allocate memory) <0.027514> So this would explain why it only fails under CPAN.pm: with CPAN.pm some ~350MB are already consumed and not available anymore (this is a Debian/stretch VM with 1.6GB RAM). For further debugging I put a process memory calculation function into the test script ( https://github.com/eserte/srezic-repository/blob/master/perl/currmem#L14 ) and this is the output: t/050interop-xz.t .... 1/1006 151035904,107311104 at t/050interop-xz.t line 205. 151175168,107450368 at t/050interop-xz.t line 205. 117620736,73895936 at t/050interop-xz.t line 205. 151175168,107450368 at t/050interop-xz.t line 205. 151175168,107450368 at t/050interop-xz.t line 205. 151175168,107450368 at t/050interop-xz.t line 205. 168226816,124502016 at t/050interop-xz.t line 205. t/050interop-xz.t .... 54/1006 168226816,124502016 at t/050interop-xz.t line 205. 168226816,124502016 at t/050interop-xz.t line 205. 168226816,124502016 at t/050interop-xz.t line 205. 134672384,90947584 at t/050interop-xz.t line 205. 134672384,90947584 at t/050interop-xz.t line 205. 168226816,124502016 at t/050interop-xz.t line 205. 168226816,124502016 at t/050interop-xz.t line 205. 168226816,124502016 at t/050interop-xz.t line 205. 101113856,57389056 at t/050interop-xz.t line 205. 101113856,57389056 at t/050interop-xz.t line 205. 101113856,57389056 at t/050interop-xz.t line 205. 101113856,57389056 at t/050interop-xz.t line 205. 134672384,90947584 at t/050interop-xz.t line 205. 168226816,124502016 at t/050interop-xz.t line 205. 168226816,124502016 at t/050interop-xz.t line 205. 294866944,251142144 at t/050interop-xz.t line 205. 487804928,444080128 at t/050interop-xz.t line 205. 806572032,762847232 at t/050interop-xz.t line 205. # '/usr/bin/xz -dc -F xz' failed: 0 # Failed test (t/050interop-xz.t at line 207) # Failed test (t/050interop-xz.t at line 208) ... (etc) ... I assume that a fork (or clone) requires the same amount of memory as already used, so another ~800MB to the existing ~800MB is needed here. And it looks like there's a lot of memory consumption before the first test failure. (Another question is: why doesn't system() return -1 in this situation?)
  Mon Jan 07 16:55:59 2019 SREZIC [...] cpan.org - Correspondence added
On 2019-01-07 16:13:37, SREZIC wrote: [...] Show quoted text
> What's strange here: apparently system("xz ...") did not return 0, but > $? is zero, as the diag() output following the system() call shows.
[...] Show quoted text
> (Another question is: why doesn't system() return -1 in this > situation?)
Nonsense, system() returned -1 in this situation. But if this happens then $? is meaningless, and $! has to be investigated. If the diag() line is changed, e.g. like this - diag "'$comp' failed: $?"; + diag "'$comp' failed: \$?=$? \$!=$!"; then the following is printed: # '/usr/bin/xz -dc -F xz' failed: $?=0 $!=Cannot allocate memory
  Tue Jan 08 03:53:29 2019 pmqs [...] cpan.org - Correspondence added
Interesting. I knew that xz (and lzma in general) are very memory hungry, but this is surprising. Presumably running under cpan has almost, but not quite, exceeded the memory available on the box by the time it gets to that test. The interoperability tests then just push it over the edge. I should be able catch the "Cannot allocate memory" errors when system is invoked, and output a better error message. Means the smoke will still be flagged a failing, but I don't think there is much I can about that. thanks Paul
  Tue Jan 08 03:53:29 2019 The RT System itself - Status changed from 'new' to 'open'
  Sat Jan 12 08:35:28 2019 SREZIC [...] cpan.org - Correspondence added
On 2019-01-08 03:53:29, PMQS wrote: Show quoted text
> Interesting. > > I knew that xz (and lzma in general) are very memory hungry, but this > is surprising. Presumably running under cpan has almost, but not > quite, exceeded the memory available on the box by the time it gets to > that test. The interoperability tests then just push it over the edge. > > I should be able catch the "Cannot allocate memory" errors when system > is invoked, and output a better error message. Means the smoke will > still be flagged a failing, but I don't think there is much I can > about that.
What probably does help here: doing "undef $x" in the compressWith() subroutine, somewhere between writeFile() and readWithXz(). This would free memory allocated in the Compress::Raw::Lzma object before system() is called, and the saving might be quite large, especially with preset=9. If I do this, then the currmem() call shows relatively low allocated memory before the system() call.
  Sat Jan 12 17:25:11 2019 pmqs [...] cpan.org - Correspondence added
... Show quoted text
> > What probably does help here: doing "undef $x" in the compressWith() > subroutine, somewhere between writeFile() and readWithXz(). This would > free memory allocated in the Compress::Raw::Lzma object before > system() is called, and the saving might be quite large, especially > with preset=9. If I do this, then the currmem() call shows relatively > low allocated memory before the system() call.
Just tried that on my setup along with your currmem function. It does seem to make a good difference. Uploaded version 2.085 to CPAN. Will see how that gets on. Thnaks again Paul
  Sun Jan 13 06:54:33 2019 SREZIC [...] cpan.org - Correspondence added
On 2019-01-12 17:25:11, PMQS wrote: Show quoted text
> ...
> > > > What probably does help here: doing "undef $x" in the compressWith() > > subroutine, somewhere between writeFile() and readWithXz(). This > > would > > free memory allocated in the Compress::Raw::Lzma object before > > system() is called, and the saving might be quite large, especially > > with preset=9. If I do this, then the currmem() call shows relatively > > low allocated memory before the system() call.
> > > Just tried that on my setup along with your currmem function. It does > seem to make a good difference. > > Uploaded version 2.085 to CPAN. Will see how that gets on. >
Looks good now!
  Sun Jan 13 06:54:34 2019 SREZIC [...] cpan.org - Status changed from 'open' to 'resolved'
  Sun Jan 13 06:54:34 2019 SREZIC [...] cpan.org - Fixed in 2.085 added