Unexplained delay Module::Build + ExtUtils::MakeMaker building pureperl modules

[Klaus]

I am having a problem when building pure perl modules on Windows 7,
ActiveState Perl 5.12.3.

The module build / test / install works correctly, but my issue is
that the build process for a very simple pure perl module
(Acme::SList::Utilities in this case) takes about 60 seconds on my
Windows machine. The Build test and Build install process work rapidly
in about 2 seconds each.

Well, I could just live with that and shut up, after all the whole
Build / Build test / Build install process runs to completion (after
64 seconds).

....hmm...

However, what bugs me is that if I re-Build the module a second time,
the Build process runs in 2 seconds extremely fast (down from 60
seconds in my first Build).

What is even more annoying is that the exact same odd behaviour exists
also with ExtUtils::MakeMaker, both nmake and dmake (first build takes
60 seconds, subsequent builds take only 2 seconds).

Finally, on my Linux Ubuntu box, everything works fast, run to
completion of Build / Build test / Build install in 2 seconds, even on
the first Build. --> This seems to be a Windows issue.

Does anybody share this experience (first build takes 60 seconds for a
pure Perl module) on a Windows box ?

******************************************************

For reference, here is my Build.PL

use strict;
use warnings;
use 5.008;

use Module::Build;

Module::Build->new(
module_name => 'Acme::SList::Utilities',
license => 'perl',
configure_requires => { 'Module::Build' => 0.30 },
requires => { },
dist_abstract => 'Various utilitiy-functions for the SList
suite of programs',
)->create_build_script;

******************************************************

and here is my Makefile.PL

use 5.008;

use ExtUtils::MakeMaker;
# See lib/ExtUtils/MakeMaker.pm for details of how to influence
# the contents of the Makefile that is written.
WriteMakefile(
NAME => 'Acme::SList::Utilities',
VERSION_FROM => 'lib/Acme/SList/Utilities.pm', # finds
$VERSION
PREREQ_PM => { }, # e.g., Module::Name => 1.1
($] >= 5.005 ? ## Add these new keywords supported since 5.005
(ABSTRACT_FROM => 'lib/Acme/SList/Utilities.pm', # retrieve
abstract from module
AUTHOR => 'Klaus Eichner <[email protected]>') : ()),
);

******************************************************

And here is a logfile of my first and second Build / Build test /
Build install process:

Microsoft Windows [version 6.1.7601]
Copyright (c) 2009 Microsoft Corporation. Tous droits réservés.

C:\Acme-SList-Utilities-0.01>perl Build.pl
Set up gcc environment - 3.4.5 (mingw-vista special r3)
Set up gcc environment - 3.4.5 (mingw-vista special r3)
Created MYMETA.yml and MYMETA.json
Creating new 'Build' script for 'Acme-SList-Utilities' version '0.01'

** This takes 60 seconds to complete

C:\Acme-SList-Utilities-0.01>Build
Set up gcc environment - 3.4.5 (mingw-vista special r3)
Set up gcc environment - 3.4.5 (mingw-vista special r3)
Set up gcc environment - 3.4.5 (mingw-vista special r3)
Building Acme-SList-Utilities

** This takes 2 seconds to complete

C:\Acme-SList-Utilities-0.01>Build test
Set up gcc environment - 3.4.5 (mingw-vista special r3)
Set up gcc environment - 3.4.5 (mingw-vista special r3)
Set up gcc environment - 3.4.5 (mingw-vista special r3)
t\0010_test.t .. ok
All tests successful.
Files=1, Tests=1, 1 wallclock secs ( 0.09 usr + 0.17 sys = 0.27
CPU)
Result: PASS

** This takes 2 seconds to complete

C:\Acme-SList-Utilities-0.01>Build install
Set up gcc environment - 3.4.5 (mingw-vista special r3)
Set up gcc environment - 3.4.5 (mingw-vista special r3)
Set up gcc environment - 3.4.5 (mingw-vista special r3)
Building Acme-SList-Utilities
Building ActivePerl Table of Contents
For ActivePerl's PPM: touch 'C:\Perl\lib\perllocal.pod'

** This takes 2 seconds to complete

C:\Acme-SList-Utilities-0.01>Build
Set up gcc environment - 3.4.5 (mingw-vista special r3)
Set up gcc environment - 3.4.5 (mingw-vista special r3)
Set up gcc environment - 3.4.5 (mingw-vista special r3)
Building Acme-SList-Utilities

** This now takes also only 2 seconds to complete
** (down from 60 seconds previously)

 

[Klaus]

C:\Acme-SList-Utilities-0.01>perl Build.pl
[...]
** This takes 60 seconds to complete

C:\Acme-SList-Utilities-0.01>Build
[...]
** This takes 2 seconds to complete

whoops, I accidently swapped two lines, the time to completion is, of
course:

C:\Acme-SList-Utilities-0.01>perl Build.pl
[...]
** This takes 2 seconds to complete

C:\Acme-SList-Utilities-0.01>Build
[...]
** This takes 60 seconds to complete

The issue remains:
the build process for a very simple pure perl module
(Acme::SList::Utilities in this case) takes about 60 seconds on my
Windows machine.

Does anybody have the same experience ?

 

[Klaus]

C:\Acme-SList-Utilities-0.01>perl Build.pl
[...]
** This takes 60 seconds to complete
C:\Acme-SList-Utilities-0.01>Build
[...]
** This takes 2 seconds to complete

whoops, I accidently swapped two lines, the time to completion is, of
course:

C:\Acme-SList-Utilities-0.01>perl Build.pl
[...]
** This takes 2 seconds to complete

C:\Acme-SList-Utilities-0.01>Build
[...]
** This takes 60 seconds to complete

The issue remains:
the build process for a very simple pure perl module
(Acme::SList::Utilities in this case) takes about 60 seconds on my
Windows machine.

Does anybody have the same experience ?

IME building perl modules on Windows is always mind-numbingly slow. This
tends to apply more to EUMM modules than MB, since the usual cause is
that Win32 appears to be incapable of creating a process without taking
several seconds.

You say that if you re-run the build it doesn't take so long: what makes
it go back to taking a long time again? Build clean? Is the fact it
takes less time the second time simply because it isn't actually doing
anything? Try rerunning the build with --verbose, to see which steps of
the process are taking the time.

My first suspect for something like this would be some sort of
on-access virus scanner, that's catching every attempt by Build to write
a new file and wasting a whole lot of time scanning it. Do you have
anything like that installed, and can you turn it off?

Thanks for your comments.

C:\Acme-SList-Utilities-0.01>Build clean
Set up gcc environment - 3.4.5 (mingw-vista special r3)
Set up gcc environment - 3.4.5 (mingw-vista special r3)
Set up gcc environment - 3.4.5 (mingw-vista special r3)
Cleaning up build files

Yes, a Build clean actually makes it go back to taking a long time
again.

C:\Acme-SList-Utilities-0.01>Build --verbose
Set up gcc environment - 3.4.5 (mingw-vista special r3)
Set up gcc environment - 3.4.5 (mingw-vista special r3)
Set up gcc environment - 3.4.5 (mingw-vista special r3)
Building Acme-SList-Utilities
Copying lib\Acme\SList\Utilities.pm -> blib\lib\Acme\SList
\Utilities.pm
Manifying blib\lib/Acme/SList/Utilities.pm -> blib\libdoc
\Acme.SList.Utilities.3
Converting Pod to HTML with ActiveState:ocTools:od
HTMLifying blib\lib\Acme\SList\Utilities.pm -> blib\libhtml\site\lib
\Acme\SList\Utilities.html

** It's actually the HTMLifying step which takes such a long time.

I suspect that the HTMLifying step of the Build actually crawls the
filesystem (or even worse, goes out on the net to verify external
links)

Anyway, I think I now have an explanation for why the Build takes such
a long time.

Thanks,
Klaus