Subject: | build_dir_reuse when smoking causes massive slowdown in CPAN |
I'm running an unattended smoker on Windows and noticed a while ago
that it was behaving a bit oddly:
I would get literally thousands of lines like this:
prerequisite module[overload] not known
prerequisite module[Carp] not known
prerequisite module[overload] not known
prerequisite module[Carp] not known
prerequisite module[overload] not known
prerequisite module[Carp] not known
Now this i could live with, but additionally these errors also
introduced considerable delay until it would restart processing,
leading to a single smoking taking more than a day at times. (I found
out this evening that's due to an intentional sleep 2 in
Distribution.pm.)
So, i set out tonight to at least get a quickfix in for myself and
figure out why this kept happening. While im not *entirely* sure why it
happens, i think i have reasonably useful instructions for reproducing
the problem. I am not sure whether CPAN::Reporter needs to be set up, i
ran out of time for today. (CPAN::SQLite may also be related to this
happening, no evidence for it, just a gut feeling i got while stepping
through code.)
Any way, reproduction steps:
=====================================================================
First, set up build dir reusing:
-----
o conf init build_dir_reuse
<build_dir_reuse>
...
CPAN.pm sessions? [no] yes
-----
Test-Fatal may not be installed. Instead, only set up a build dir for
CPAN to find later on:
$ perl -MCPAN -e "$CPAN::Config->{test_report} = 1;CPAN::Index->reload;
$CPAN::META->reset_tested;test( 'RJBS/Test-Fatal-0.003.tar.gz' );"
Next, run the test for DepMan, which *must* find and use the already
built Test-Fatal, but may not be in the same process:
$ perl -MCPAN -e "$CPAN::Config->{test_report} = 1;CPAN::Index->reload;
$CPAN::META->reset_tested;test( 'DROLSKY/Package-
DeprecationManager-0.10.tar.gz' );"
Which results in this:
-----
CPAN: CPAN::SQLite loaded ok (v0.199)
CPAN: YAML::XS loaded ok (v0.34)
Going to read 4 yaml files from C:\Perl/cpan/build/
Database was generated on Mon, 07 Feb 2011 21:05:28 GMT
CPAN: Time::HiRes loaded ok (v1.9721)
.........................................................DONE
Restored the state of 1 (in 0.0145 secs)
Running make for D/DR/DROLSKY/Package-DeprecationManager-0.10.tar.gz
Has already been unwrapped into directory C:\Perl\cpan\build\Package-
DeprecationManager-0.10-l3TJ5A
Show quoted text
---- Unsatisfied dependencies detected during ----
---- DROLSKY/Package-DeprecationManager-0.10.tar.gz ----
Test::Fatal [build_requires]
prerequisite module[overload] not known
Running make test
Delayed until after prerequisites
Running test for module 'Test::Fatal'
-----
=====================================================================
One of the reasons for the prerequisite message occuring is that CPAN
finds the previous build dir for Test-Fatal, which contains
prerequisite information for the dist and then calls this on it:
$dist->color_cmd_tmps
This function then proceeds to go through all the prereqs, trying to
expand the module names into module objects and delving into them if
possible, or throwing the mentioned error. The only skipped prereq is
'perl' itself.
This expanding seems to happen via CPAN::SQLite and in this case is
result-less for overload, causing an error message and a two-second
sleep. Interestingly it goes fine when Carp shows up as a dependency in
this case, although i've seen it act like overload acts here.
I have no idea why this is happening, but i hope this will help you
figure it out. If it's not enough, let me know and i'll try to dig up
any info you need.