in reply to Re^2: CPAN module install really slow
in thread CPAN module install really slow

I think I spoke too soon.

It appears to be the Makefile.PL that is taking ages and for every module install?

ps -ef | grep cpanm admtst 10665 18671 0 13:01 pts/1 00:00:00 /opt/app/release/perl/li +nux/5.18.2-7/bin/perl 5.18.2-7/bin/cpanm --verbose LWP::UserAgent pstree -pa 10665 cpanm,10665 5.18.2-7/bin/cpanm --verbose LWP::UserAgent `-perl,11170 Makefile.PL
Yes if I do manual install of any of these modules it pretty instant.

Replies are listed 'Best First'.
Re^4: CPAN module install really slow
by marto (Cardinal) on Jul 13, 2015 at 13:09 UTC

    Are you sure you're comparing the same things here? Using a tool like cpan/cpanm installs dependencies, running perl Makefile.PL does not. LWP::UserAgent has many dependencies.

      Yes, the manual install lets you know the dependencies, I then download those and install them. The manual process to get all dependencies, gunzip - untar - build - test - install is still faster than cpanm doing it.

      Also, I have been using cpanm --verbose which shows the install of each dependency, it gets 'stuck' at the same place for each dependency as well.

        Well, this is great news, regardless of install method (manual/cpanm) you've discovered the point at which this weird pause occurs. Could you please post an example of this?

        Update: Nope. Strikeout. See below.

Re^4: CPAN module install really slow - extra strace info
by gsee (Acolyte) on Jul 14, 2015 at 11:26 UTC
    Some further information which may help someone help me!

    If I run the cpanm command with strace, I get the following output:

    ...... ...... open("/home/admtst/.cpanm/work/1436872577.16214/build.log", O_WRONLY|O +_CREAT|O_APPEND, 0666) = 4 lseek(4, 0, SEEK_END) = 2506 ioctl(4, SNDCTL_TMR_TIMEBASE or TCGETS, 0x7fffd6360540) = -1 ENOTTY (I +nappropriate ioctl for device) lseek(4, 0, SEEK_CUR) = 2506 fstat(4, {st_mode=S_IFREG|0644, st_size=2506, ...}) = 0 fcntl(4, F_SETFD, FD_CLOEXEC) = 0 write(4, "Configuring Email-MIME-ContentTy"..., 41) = 41 close(4) = 0 stat("cpanfile", 0x7651a0) = -1 ENOENT (No such file or d +irectory) stat("Build.PL", 0x7651a0) = -1 ENOENT (No such file or d +irectory) stat("Makefile.PL", {st_mode=S_IFREG|0644, st_size=1327, ...}) = 0 write(2, "Running Makefile.PL\n", 20Running Makefile.PL ) = 20 open("/home/admtst/.cpanm/work/1436872577.16214/build.log", O_WRONLY|O +_CREAT|O_APPEND, 0666) = 4 lseek(4, 0, SEEK_END) = 2547 ioctl(4, SNDCTL_TMR_TIMEBASE or TCGETS, 0x7fffd6360540) = -1 ENOTTY (I +nappropriate ioctl for device) lseek(4, 0, SEEK_CUR) = 2547 fstat(4, {st_mode=S_IFREG|0644, st_size=2547, ...}) = 0 fcntl(4, F_SETFD, FD_CLOEXEC) = 0 write(4, "Running Makefile.PL\n", 20) = 20 close(4) = 0 write(1, "Configuring Email-MIME-ContentTy"..., 45Configuring Email-MI +ME-ContentType-1.018 ... ) = 45 rt_sigprocmask(SIG_SETMASK, ~[RTMIN RT_1], [], 8) = 0 clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIG +CHLD, child_tidptr=0x7f74c45de9d0) = 16777 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0 wait4(16777, Checking if your kit is complete... Looks good
    It has a wait command which I am unsure about, any ideas?

      strace -f should show child processes, too.
      لսႽ† ᥲᥒ⚪⟊Ⴙᘓᖇ Ꮅᘓᖇ⎱ Ⴙᥲ𝇋ƙᘓᖇ
        Hi choroba thanks for that tip, here is the output of that command after from the "looks good"
        [pid 15031] chdir("/home/admtst/.cpanm/work/1436964574.13928/Devel-Glo +balDestruction-0.13") = 0 [pid 15031] write(1, "Looks good\n", 11Looks good ) = 11 [pid 15031] stat("hints", 0x7651a0) = -1 ENOENT (No such file or d +irectory) [pid 15031] stat("/opt/app/perlModules/Sub/Exporter/Progressive.pm", 0 +x7651a0) = -1 ENOENT (No such file or directory) [pid 15031] stat("/opt/app/release/perl/linux/5.18.2-7.1/lib/site_perl +/5.18.2/x86_64-linux/Sub/Exporter/Progressive.pm", 0x7651a0) = -1 ENO +ENT (No such file or directory) [pid 15031] stat("/opt/app/release/perl/linux/5.18.2-7.1/lib/site_perl +/5.18.2/Sub/Exporter/Progressive.pm", 0x7651a0) = -1 ENOENT (No such +file or directory) [pid 15031] stat("/opt/app/release/perl/linux/5.18.2-7.1/lib/5.18.2/x8 +6_64-linux/Sub/Exporter/Progressive.pm", 0x7651a0) = -1 ENOENT (No su +ch file or directory) [pid 15031] stat("/opt/app/release/perl/linux/5.18.2-7.1/lib/5.18.2/Su +b/Exporter/Progressive.pm", 0x7651a0) = -1 ENOENT (No such file or di +rectory) [pid 15031] stat("./Sub/Exporter/Progressive.pm", 0x7651a0) = -1 ENOEN +T (No such file or directory) [pid 15031] write(2, "Warning: prerequisite Sub::Expor"..., 69Warning: + prerequisite Sub::Exporter::Progressive 0.001011 not found. ) = 69 [pid 15031] open("/usr/share/locale/locale.alias", O_RDONLY) = 3 [pid 15031] fstat(3, {st_mode=S_IFREG|0644, st_size=2512, ...}) = 0 [pid 15031] mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANO +NYMOUS, -1, 0) = 0x7fbd8d758000 [pid 15031] read(3, "# Locale name alias data base.\n#"..., 4096) = 25 +12 [pid 15031] read(3, "", 4096) = 0 [pid 15031] close(3) = 0 [pid 15031] munmap(0x7fbd8d758000, 4096) = 0 [pid 15031] open("/usr/share/locale/en_GB/LC_MESSAGES/libc.mo", O_RDON +LY) = 3 [pid 15031] fstat(3, {st_mode=S_IFREG|0644, st_size=1474, ...}) = 0 [pid 15031] mmap(NULL, 1474, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fbd8d7 +58000 [pid 15031] close(3) = 0 [pid 15031] open("/usr/share/locale/en/LC_MESSAGES/libc.mo", O_RDONLY) + = -1 ENOENT (No such file or directory) [pid 15031] getuid() = 1000007625 [pid 15031] geteuid() = 1000007625 [pid 15031] getgid() = 1000001421 [pid 15031] getegid() = 1000001421 [pid 15031] stat("../config_h.SH", 0x7651a0) = -1 ENOENT (No such file + or directory) [pid 15031] stat("../../config_h.SH", 0x7651a0) = -1 ENOENT (No such f +ile or directory) [pid 15031] stat("../../../config_h.SH", 0x7651a0) = -1 ENOENT (No suc +h file or directory) [pid 15031] stat("../../../../config_h.SH", 0x7651a0) = -1 ENOENT (No +such file or directory) [pid 15031] stat("../../../../../config_h.SH",
        and again
        [pid 16035] chdir("/home/admtst/.cpanm/work/1436964574.13928/MooX-Type +s-MooseLike-0.29") = 0 [pid 16035] write(1, "Looks good\n", 11Looks good ) = 11 [pid 16035] stat("hints", 0x7651a0) = -1 ENOENT (No such file or d +irectory) [pid 16035] stat("/opt/app/perlModules/Module/Runtime.pm", 0x7651a0) = + -1 ENOENT (No such file or directory) [pid 16035] stat("/opt/app/release/perl/linux/5.18.2-7.1/lib/site_perl +/5.18.2/x86_64-linux/Module/Runtime.pm", 0x7651a0) = -1 ENOENT (No su +ch file or directory) [pid 16035] stat("/opt/app/release/perl/linux/5.18.2-7.1/lib/site_perl +/5.18.2/Module/Runtime.pm", {st_mode=S_IFREG|0444, st_size=16613, ... +}) = 0 [pid 16035] geteuid() = 1000007625 [pid 16035] geteuid() = 1000007625 [pid 16035] open("/opt/app/release/perl/linux/5.18.2-7.1/lib/site_perl +/5.18.2/Module/Runtime.pm", O_RDONLY) = 3 [pid 16035] ioctl(3, SNDCTL_TMR_TIMEBASE or TCGETS, 0x7fff09fef040) = +-1 ENOTTY (Inappropriate ioctl for device) [pid 16035] lseek(3, 0, SEEK_CUR) = 0 [pid 16035] fstat(3, {st_mode=S_IFREG|0444, st_size=16613, ...}) = 0 [pid 16035] fcntl(3, F_SETFD, FD_CLOEXEC) = 0 [pid 16035] read(3, "=head1 NAME\n\nModule::Runtime - r"..., 8192) = 8 +192 [pid 16035] stat("/opt/app/perlModules/version.pmc", 0x7fff09feed90) = + -1 ENOENT (No such file or directory) [pid 16035] stat("/opt/app/perlModules/version.pm", 0x7fff09feecf0) = +-1 ENOENT (No such file or directory) [pid 16035] stat("/opt/app/release/perl/linux/5.18.2-7.1/lib/site_perl +/5.18.2/x86_64-linux/version.pmc", 0x7fff09feed90) = -1 ENOENT (No su +ch file or directory) [pid 16035] stat("/opt/app/release/perl/linux/5.18.2-7.1/lib/site_perl +/5.18.2/x86_64-linux/version.pm", 0x7fff09feecf0) = -1 ENOENT (No suc +h file or directory) [pid 16035] stat("/opt/app/release/perl/linux/5.18.2-7.1/lib/site_perl +/5.18.2/version.pmc", 0x7fff09feed90) = -1 ENOENT (No such file or di +rectory) [pid 16035] stat("/opt/app/release/perl/linux/5.18.2-7.1/lib/site_perl +/5.18.2/version.pm", 0x7fff09feecf0) = -1 ENOENT (No such file or dir +ectory) [pid 16035] stat("/opt/app/release/perl/linux/5.18.2-7.1/lib/5.18.2/x8 +6_64-linux/version.pmc", 0x7fff09feed90) = -1 ENOENT (No such file or + directory) [pid 16035] stat("/opt/app/release/perl/linux/5.18.2-7.1/lib/5.18.2/x8 +6_64-linux/version.pm", 0x7fff09feecf0) = -1 ENOENT (No such file or +directory) [pid 16035] stat("/opt/app/release/perl/linux/5.18.2-7.1/lib/5.18.2/ve +rsion.pmc", 0x7fff09feed90) = -1 ENOENT (No such file or directory) [pid 16035] stat("/opt/app/release/perl/linux/5.18.2-7.1/lib/5.18.2/ve +rsion.pm", {st_mode=S_IFREG|0444, st_size=5284, ...}) = 0 [pid 16035] open("/opt/app/release/perl/linux/5.18.2-7.1/lib/5.18.2/ve +rsion.pm", O_RDONLY) = 4 [pid 16035] ioctl(4, SNDCTL_TMR_TIMEBASE or TCGETS, 0x7fff09feead0) = +-1 ENOTTY (Inappropriate ioctl for device) [pid 16035] lseek(4, 0, SEEK_CUR) = 0 [pid 16035] read(4, "#!perl -w\npackage version;\n\nuse "..., 8192) = +5284 [pid 16035] read(4, "", 8192) = 0 [pid 16035] close(4) = 0 [pid 16035] lseek(3, 5384, SEEK_SET) = 5384 [pid 16035] lseek(3, 0, SEEK_CUR) = 5384 [pid 16035] close(3) = 0 [pid 16035] getuid() = 1000007625 [pid 16035] geteuid() = 1000007625 [pid 16035] getgid() = 1000001421 [pid 16035] getegid() = 1000001421 [pid 16035] stat("../config_h.SH", 0x7651a0) = -1 ENOENT (No such file + or directory) [pid 16035] stat("../../config_h.SH", 0x7651a0) = -1 ENOENT (No such f +ile or directory) [pid 16035] stat("../../../config_h.SH", 0x7651a0) = -1 ENOENT (No suc +h file or directory) [pid 16035] stat("../../../../config_h.SH", 0x7651a0) = -1 ENOENT (No +such file or directory) [pid 16035] stat("../../../../../config_h.SH",

        every time in exactly the same place.

        this location of "../../../../../config_h.SH is the same as /home/config_h.SH - /home/admtst is a bind mount on /opt/home/admtst

        so I presume the problem is here but have no idea why