PATH=/usr/bin:/bin:/Users/fly2400/cpanfly-5.24/var/megalib/bin Start 2016-11-25T15:02:14 ActivePerl-2400 CPAN-2.10 Reading '/Users/fly2400/cpanfly-5.24/var/cpan/Metadata' Database was generated on Fri, 25 Nov 2016 00:17:02 GMT Fetching with LWP: http://ppm.activestate.com/CPAN/authors/id/J/JH/JHI/Time-HiRes-1.9741.tar.gz Fetching with LWP: http://ppm.activestate.com/CPAN/authors/id/J/JH/JHI/CHECKSUMS Checksum for /Users/fly2400/cpanfly-5.24/var/cpan/sources/authors/id/J/JH/JHI/Time-HiRes-1.9741.tar.gz ok Time-HiRes-1.9741/ Time-HiRes-1.9741/Changes Time-HiRes-1.9741/fallback/ Time-HiRes-1.9741/hints/ Time-HiRes-1.9741/HiRes.pm Time-HiRes-1.9741/HiRes.xs Time-HiRes-1.9741/Makefile.PL Time-HiRes-1.9741/MANIFEST Time-HiRes-1.9741/META.json Time-HiRes-1.9741/META.yml Time-HiRes-1.9741/ppport.h Time-HiRes-1.9741/README Time-HiRes-1.9741/t/ Time-HiRes-1.9741/TODO Time-HiRes-1.9741/typemap Time-HiRes-1.9741/t/alarm.t Time-HiRes-1.9741/t/clock.t Time-HiRes-1.9741/t/gettimeofday.t Time-HiRes-1.9741/t/itimer.t Time-HiRes-1.9741/t/nanosleep.t Time-HiRes-1.9741/t/sleep.t Time-HiRes-1.9741/t/stat.t Time-HiRes-1.9741/t/time.t Time-HiRes-1.9741/t/tv_interval.t Time-HiRes-1.9741/t/ualarm.t Time-HiRes-1.9741/t/usleep.t Time-HiRes-1.9741/t/utime.t Time-HiRes-1.9741/t/Watchdog.pm Time-HiRes-1.9741/hints/aix.pl Time-HiRes-1.9741/hints/dec_osf.pl Time-HiRes-1.9741/hints/dynixptx.pl Time-HiRes-1.9741/hints/irix.pl Time-HiRes-1.9741/hints/linux.pl Time-HiRes-1.9741/hints/sco.pl Time-HiRes-1.9741/hints/solaris.pl Time-HiRes-1.9741/hints/svr4.pl Time-HiRes-1.9741/fallback/const-c.inc Time-HiRes-1.9741/fallback/const-xs.inc Configuring J/JH/JHI/Time-HiRes-1.9741.tar.gz with Makefile.PL >>> /Users/fly2400/ap2400-300558/bin/perl-dynamic Makefile.PL Configuring Time::HiRes... Have syscall()... looking for syscall.h... found . Looking for gettimeofday()... found. Looking for setitimer()... found. Looking for getitimer()... found. You have interval timers (both setitimer and getitimer). Looking for ualarm()... found. Looking for usleep()... found. Looking for nanosleep()... testing... found. You can mix subsecond sleeps with signals, if you want to. (It's still not portable, though.) Looking for clockid_t... NOT found, will use int. Looking for clock_gettime()... found (via emulation). Looking for clock_getres()... found (via emulation). Looking for clock_nanosleep()... found (via emulation). Looking for clock()... found. Looking for futimens()... NOT found. Looking for utimensat()... NOT found. Looking for stat() subsecond timestamps... Trying struct stat st_atimespec.tv_nsec...found. Trying struct stat st_atimensec...NOT found. Trying struct stat st_atime_n...NOT found. Trying struct stat st_atim.tv_nsec...NOT found. Trying struct stat st_uatime...NOT found. You seem to have stat() subsecond timestamps. (Your struct stat has them, but the filesystems must help.) Checking if your kit is complete... Looks good Have /Users/fly2400/cpanfly-5.24/var/megalib Want /Users/fly2400/ap2400-300558/lib Your perl and your Config.pm seem to have different ideas about the architecture they are running on. Perl thinks: [megalib] Config says: [darwin-thread-multi-2level] This may or may not cause problems. Please check your installation of perl if you have problems building this extension. Generating a Unix-style Makefile Writing Makefile for Time::HiRes Writing MYMETA.yml and MYMETA.json Now you may issue 'make'. Do not forget also 'make test'. JHI/Time-HiRes-1.9741.tar.gz /Users/fly2400/ap2400-300558/bin/perl-dynamic Makefile.PL -- OK Running make for J/JH/JHI/Time-HiRes-1.9741.tar.gz >>> make cp HiRes.pm blib/lib/Time/HiRes.pm Running Mkbootstrap for HiRes () chmod 644 "HiRes.bs" "/Users/fly2400/ap2400-300558/bin/perl-dynamic" -MExtUtils::Command::MM -e 'cp_nonempty' -- HiRes.bs blib/arch/auto/Time/HiRes/HiRes.bs 644 "/Users/fly2400/ap2400-300558/bin/perl-dynamic" "/Users/fly2400/cpanfly-5.24/var/megalib/ExtUtils/xsubpp" -typemap '/Users/fly2400/ap2400-300558/lib/ExtUtils/typemap' -typemap '/Users/fly2400/cpanfly-5.24/var/tmp/cpan_build/Time-HiRes-1.9741-4hU3b4/typemap' HiRes.xs > HiRes.xsc mv HiRes.xsc HiRes.c gcc -c -fno-common -DPERL_DARWIN -no-cpp-precomp -mmacosx-version-min=10.9 -arch x86_64 -DUSE_SITECUSTOMIZE -DPERL_RELOCATABLE_INCPUSH -fno-strict-aliasing -pipe -fstack-protector -DPERL_USE_SAFE_PUTENV -O3 -DVERSION=\"1.9741\" -DXS_VERSION=\"1.9741\" "-I/Users/fly2400/ap2400-300558/lib/CORE" -DTIME_HIRES_NANOSLEEP -DTIME_HIRES_CLOCK_GETTIME -DTIME_HIRES_CLOCK_GETTIME_EMULATION -DTIME_HIRES_CLOCK_GETRES -DTIME_HIRES_CLOCK_GETRES_EMULATION -DTIME_HIRES_CLOCK_NANOSLEEP -DTIME_HIRES_CLOCK_NANOSLEEP_EMULATION -DTIME_HIRES_CLOCK -DTIME_HIRES_STAT_ST_XTIMESPEC -DTIME_HIRES_STAT=1 -DATLEASTFIVEOHOHFIVE HiRes.c rm -f blib/arch/auto/Time/HiRes/HiRes.bundle gcc -mmacosx-version-min=10.9 -bundle -undefined dynamic_lookup -Wl,-search_paths_first -arch x86_64 -fstack-protector -o blib/arch/auto/Time/HiRes/HiRes.bundle HiRes.o \ \ chmod 755 blib/arch/auto/Time/HiRes/HiRes.bundle Manifying 1 pod document JHI/Time-HiRes-1.9741.tar.gz make -- OK Running make test >>> make test TEST_VERBOSE=1 "/Users/fly2400/ap2400-300558/bin/perl-dynamic" -MExtUtils::Command::MM -e 'cp_nonempty' -- HiRes.bs blib/arch/auto/Time/HiRes/HiRes.bs 644 PERL_DL_NONLAZY=1 "/Users/fly2400/ap2400-300558/bin/perl-dynamic" "-MExtUtils::Command::MM" "-MTest::Harness" "-e" "undef *Test::Harness::Switches; test_harness(1, 'blib/lib', 'blib/arch')" t/*.t t/alarm.t ......... 1..10 # I am the main process 82786, starting the watchdog process... # The watchdog process 82787 launched, continuing testing... # I am the watchdog process 82787, sleeping for 360 seconds... ok 1 - require Time::HiRes; # sigaction tick, ALRM = 14 # Tick! 4 0.302082 # Select returned! 4 0.302204 # 0.899265333333333 # Tick! 3 0.603686 # Select returned! 3 0.603784 # 0.798738666666667 # Tick! 2 0.905277 # Select returned! 2 0.905367 # 0.698211 # Tick! 1 1.206633 # Select returned! 1 1.206721 # 0.597759666666667 # Tick! 0 1.509582 # Select returned! 0 1.509657 # 0.496781 # ok 2 ok 3 - negative time error # Finding delay loop... # N = 1024, t1 = 1480114946.50955, t0 = 1480114946.50951, dt = 3.88622283935547e-05 # N = 2048, t1 = 1480114946.50966, t0 = 1480114946.50958, dt = 7.51018524169922e-05 # N = 4096, t1 = 1480114946.50981, t0 = 1480114946.50967, dt = 0.00014805793762207 # N = 8192, t1 = 1480114946.51013, t0 = 1480114946.50982, dt = 0.000307083129882812 # N = 16384, t1 = 1480114946.51075, t0 = 1480114946.51016, dt = 0.000596046447753906 # N = 32768, t1 = 1480114946.51264, t0 = 1480114946.51079, dt = 0.00185203552246094 # N = 65536, t1 = 1480114946.51655, t0 = 1480114946.51271, dt = 0.00383496284484863 # N = 131072, t1 = 1480114946.52213, t0 = 1480114946.51666, dt = 0.00546693801879883 # N = 262144, t1 = 1480114946.5319, t0 = 1480114946.52221, dt = 0.00969696044921875 # N = 524288, t1 = 1480114946.55152, t0 = 1480114946.53198, dt = 0.0195410251617432 # Alarm 1 - 1480114946.56284 # Alarm 2 - 1480114946.60978 ok 4 ok 5 ok 6 ok 7 ok 8 ok 9 ok 10 # I am the main process 82786, terminating the watchdog process 82787 before it terminates me in 354 seconds (testing took 6 seconds). # kill KILL 82787 = 1 # All done. ok t/clock.t ......... 1..5 # I am the main process 82788, starting the watchdog process... # The watchdog process 82789 launched, continuing testing... # I am the watchdog process 82789, sleeping for 360 seconds... ok 1 - require Time::HiRes; # have_clock_gettime = 1 # have_clock_getres = 1 # have_clock_nanosleep = 1 # have_clock = 1 # CLOCK_REALTIME: try = 1 # t1 = 1480114952.48456, t0 = 1480114950.98059 # dt = 1.50397133827209, rt = 0.00264755884806323 ok 2 ok 3 ok 4 # clock = 0.066872 # clock = 0.066872 0.1122 # clock = 0.066872 0.1122 0.149146 # clock = 0.066872 0.1122 0.149146 0.201072 ok 5 # I am the main process 82788, terminating the watchdog process 82789 before it terminates me in 356 seconds (testing took 4 seconds). # kill KILL 82789 = 1 # All done. ok t/gettimeofday.t .. 1..6 # I am the main process 82790, starting the watchdog process... # The watchdog process 82791 launched, continuing testing... # I am the watchdog process 82791, sleeping for 360 seconds... # gettimeofday returned 2 args ok 1 ok 2 ok 3 ok 4 ok 5 ok 6 # I am the main process 82790, terminating the watchdog process 82791 before it terminates me in 359 seconds (testing took 1 seconds). # kill KILL 82791 = 1 # All done. ok t/itimer.t ........ 1..2 # I am the main process 82792, starting the watchdog process... # The watchdog process 82793 launched, continuing testing... # I am the watchdog process 82793, sleeping for 360 seconds... # setitimer: 0 0 ok 1 - ITIMER_VIRTUAL defined with sufficient granularity # getitimer: 0.499558 0.4 # Tick! 2 0.517007 # Tick! 1 0.929195 # Tick! 0 1.342226 # Tick! 0 1.754029 # getitimer: 0 0 # at end, i=0 ok 2 - time left should be zero # I am the main process 82792, terminating the watchdog process 82793 before it terminates me in 358 seconds (testing took 2 seconds). # kill KILL 82793 = 1 # All done. ok t/nanosleep.t ..... 1..3 # I am the main process 82794, starting the watchdog process... # The watchdog process 82795 launched, continuing testing... # I am the watchdog process 82795, sleeping for 360 seconds... ok 1 - negative time error ok 2 ok 3 # I am the main process 82794, terminating the watchdog process 82795 before it terminates me in 360 seconds (testing took 0 seconds). # kill KILL 82795 = 1 # All done. ok t/sleep.t ......... 1..4 # I am the main process 82796, starting the watchdog process... # The watchdog process 82797 launched, continuing testing... # I am the watchdog process 82797, sleeping for 360 seconds... ok 1 - require Time::HiRes; ok 2 - negative time error # time...1480114957.76195 ok 3 # sleep...0.503089 ok 4 # I am the main process 82796, terminating the watchdog process 82797 before it terminates me in 359 seconds (testing took 1 seconds). # kill KILL 82797 = 1 # All done. ok t/stat.t .......... 1..43 # I am the main process 82798, starting the watchdog process... # The watchdog process 82799 launched, continuing testing... # I am the watchdog process 82799, sleeping for 360 seconds... ok 1 ok 2 ok 3 ok 4 ok 5 ok 6 ok 7 ok 8 ok 9 ok 10 ok 11 ok 12 ok 13 ok 14 ok 15 ok 16 ok 17 ok 18 ok 19 ok 20 ok 21 ok 22 ok 23 ok 24 ok 25 ok 26 ok 27 ok 28 ok 29 ok 30 ok 31 ok 32 ok 33 ok 34 ok 35 # mtime = 1480114958 1480114958 1480114959 1480114959 1480114959 # atime = 1480114958 1480114959 1480114959 1480114959 1480114959 # ai = 4, mi = 4, ss = 0 ok 36 # skip no subsecond timestamps detected ok 37 ok 38 ok 39 ok 40 ok 41 ok 42 ok 43 # I am the main process 82798, terminating the watchdog process 82799 before it terminates me in 359 seconds (testing took 1 seconds). # kill KILL 82799 = 1 # All done. ok t/time.t .......... 1..2 # I am the main process 82800, starting the watchdog process... # The watchdog process 82801 launched, continuing testing... # I am the watchdog process 82801, sleeping for 360 seconds... ok 1 - require Time::HiRes; ok 2 # s = 4.30907607078552, n = 100, s/n = 0.0430907607078552 # I am the main process 82800, terminating the watchdog process 82801 before it terminates me in 360 seconds (testing took 0 seconds). # kill KILL 82801 = 1 # All done. ok t/tv_interval.t ... 1..2 ok 1 - require Time::HiRes; ok 2 ok t/ualarm.t ........ 1..12 # I am the main process 82803, starting the watchdog process... # The watchdog process 82804 launched, continuing testing... # I am the watchdog process 82804, sleeping for 360 seconds... ok 1 # tick = 1, one = 1480114960, two = 1480114960, three = 1480114960 ok 2 # tick = 3, one = 1480114960, two = 1480114960, three = 1480114960 ok 3 - negative time error # t0 = 1480114960.22417 # ualarm(100000) # t1 = 1480114960.32539 # dt = 0.101227045059204 # r = 1.01227045059204 ok 4 # t0 = 1480114960.32568 # ualarm(1100000) # t1 = 1480114961.42682 # dt = 1.10114693641663 # r = 1.00104266946966 ok 5 # t0 = 1480114961.42711 # ualarm(2200000) # t1 = 1480114963.62874 # dt = 2.20162487030029 # r = 1.00073857740922 ok 6 # t0 = 1480114963.629 # ualarm(4300000) # t1 = 1480114967.9321 # dt = 4.3031051158905 # r = 1.00072211997454 ok 7 # t0 = 1480114967.9324 # got0 = 0 # t1 = 1480114968.2324 # t1 - t0 = 0.300000905990601 # got1 = 199988 ok 8 ok 9 ok 10 ok 11 ok 12 # I am the main process 82803, terminating the watchdog process 82804 before it terminates me in 352 seconds (testing took 8 seconds). # kill KILL 82804 = 1 # All done. ok t/usleep.t ........ 1..6 # I am the main process 82805, starting the watchdog process... # The watchdog process 82806 launched, continuing testing... # I am the watchdog process 82806, sleeping for 360 seconds... ok 1 - negative time error ok 2 ok 3 ok 4 ok 5 ok 6 # I am the main process 82805, terminating the watchdog process 82806 before it terminates me in 356 seconds (testing took 4 seconds). # kill KILL 82806 = 1 # All done. ok t/utime.t ......... skipped: no hires_utime All tests successful. Files=12, Tests=95, 28 wallclock secs ( 0.09 usr 0.04 sys + 15.00 cusr 0.23 csys = 15.36 CPU) Result: PASS JHI/Time-HiRes-1.9741.tar.gz make test TEST_VERBOSE=1 -- OK Jarkko Hietaniemi <jhi@iki.fi> High resolution alarm, sleep, gettimeofday, interval timers >>> (cd /Users/fly2400/cpanfly-5.24/var/tmp/cpan_build/Time-HiRes-1.9741-4hU3b4 && tar cvf - Time-HiRes-1.9741.ppd blib) | gzip -c >/Users/fly2400/cpanfly-5.24/var/REPO/J/JH/JHI/Time-HiRes-1.9741.tar.gz Time-HiRes-1.9741.ppd blib/ blib/arch/ blib/arch/auto/ blib/arch/auto/Time/ blib/arch/auto/Time/HiRes/ blib/arch/auto/Time/HiRes/HiRes.bundle blib/lib/ blib/lib/Time/ blib/lib/Time/HiRes.pm blib/man3/ blib/man3/Time::HiRes.3 Finished 2016-11-25T15:02:52