Re: Test::Smoke failing to test most recent commit to Perl 5 blead

--------------BEB06D10B0C2E8332FABD8A4
Content-Type: text/plain; charset=utf-8; format=flowed
Content-Transfer-Encoding: 7bit

On 01/13/2017 11:25 PM, James E Keenan wrote:
> The most recent smoke testing of Perl 5 blead I have conducted in my
> FreeBSD-10.3 VM is that found at:
>
> http://perl5.test-smoke.org/report/53193
>
> The commit tested there was 3626fc2020b81652c4b3c7dd5ef0822b194d2d5e:
>
> #####
> commit 3626fc2020b81652c4b3c7dd5ef0822b194d2d5e
> Author:     Karl Williamson <[email protected]>
> AuthorDate: Wed Jan 11 14:21:16 2017 -0700
> Commit:     Karl Williamson <[email protected]>
> CommitDate: Thu Jan 12 10:14:27 2017 -0700
>
>     Rmv unused regex implementation structure element
> #####
>
> However, at the point in time when I kicked off the smoke run -- Fri Jan
> 13 21:37:48 EST 2017 -- HEAD of blead had already received 11 additional
> commits:
>
> #####
> $ git log | grep '^commit' | head -12
> commit cbe2fc5001aa59cdc73e04cc35e097a2ecfbeec0 # <- HEAD, which should
> have been tested
> commit a4368cc338f9178e7f4861a61ab56710050e50dc
> commit b1793c1ad815aa7190b1daead0f0d4fce340aff6
> commit 92e8e65053b85a7f695f0a1b5270a3567df87863
> commit 75ea5c6c82d3602be563bf9c72e8b8e2c711225b
> commit 77c8f26370dcc0e16ca7c5f1b8f3bd1b99a57a28
> commit 2ab076704905c338cc874079818784698cd5bc85
> commit 563642b4907d9b1b6beaa96b472ae787ae81d56f
> commit fc54a9b2090b5f71905241c319706e3cca18acc9
> commit af4226f2469589e84d382a08a6a5242303758f0b
> commit afa4768ac90fcd6a53a3661885a238d344a02f92
> commit 3626fc2020b81652c4b3c7dd5ef0822b194d2d5e # <- commit actually tested
> #####
>
> This suggests that the run kicked off, as always, via Test::Smoke's 'sh
> ./smokecurrent.sh', failed to update blead in the perl-current/ directory:
>
> #####
> [perl-current] $ gitcurr
> blead
> [perl-current] $ git show | head -1
> commit 3626fc2020b81652c4b3c7dd5ef0822b194d2d5e
> #####
>
> This discrepancy can also be seen by a close look at Tony Cook's log:
>
> http://perl.develop-help.com/?b=blead
>
> On a number of occasions in the past month I've suspected that this was
> happening, but this if the first time I assembled all the evidence.
>
> Has anyone else experienced this?
>

I am attaching a heavily reduced version of smokecurrent.log for the 
smoke-testing run in question.  As you can see from approximately lines 
54-55 of this log, the program only updated the checkout of blead to 
3626fc2; it should, IMO, have updated blead to cbe2fc5.

Thank you very much.
Jim Keenan

--------------BEB06D10B0C2E8332FABD8A4
Content-Type: text/x-log;
 name="reduced.smokecurrent.log"
Content-Transfer-Encoding: 7bit
Content-Disposition: attachment;
 filename="reduced.smokecurrent.log"

[2017-01-13 21:37:49-0500] Read configuration from: /usr/home/jkeenan/p5smoke/install/smokecurrent_config
[2017-01-13 21:37:49-0500] Commitlevel before sync: 2798a0195639a49658cb716c479950bacb5d522e
[2017-01-13 21:37:49-0500] ==> Starting synctree
[2017-01-13 21:37:49-0500] Reading branch to smoke from: '/usr/home/jkeenan/p5smoke/install/smokecurrent.gitbranch'
[2017-01-13 21:37:49-0500] In pwd(/usr/home/jkeenan/p5smoke/git-perl) running:
[2017-01-13 21:37:49-0500] qx[/usr/local/bin/git pull --all]
From git://perl5.git.perl.org/perl
   3626fc2..fe7df09  blead      -> origin/blead
 * [new branch]      smoke-me/jkeenan/130550-out-of-bounds -> origin/smoke-me/jkeenan/130550-out-of-bounds
Your configuration specifies to merge with the ref 'refs/heads/smoke-me/jkeenan/77934-threads'
from the remote, but no such ref was fetched.
[2017-01-13 21:37:59-0500] Fetching origin
[2017-01-13 21:37:59-0500] In pwd(/usr/home/jkeenan/p5smoke/git-perl) running:
[2017-01-13 21:37:59-0500] qx[/usr/local/bin/git remote prune origin]
[2017-01-13 21:38:00-0500] Pruning origin
[2017-01-13 21:38:00-0500] URL: git://perl5.git.perl.org/perl.git
[2017-01-13 21:38:00-0500]  * [pruned] origin/smoke-me/jkeenan/77934-threads
[2017-01-13 21:38:00-0500] In pwd(/usr/home/jkeenan/p5smoke/git-perl) running:
[2017-01-13 21:38:00-0500] qx[/usr/local/bin/git checkout blead
[2017-01-13 21:38:00-0500]  2>&1]
Switched to branch 'blead'
[2017-01-13 21:38:04-0500] Your branch is behind 'origin/blead' by 12 commits, and can be fast-forwarded.
[2017-01-13 21:38:04-0500]   (use "git pull" to update your local branch)
[2017-01-13 21:38:04-0500] In pwd(/usr/home/jkeenan/p5smoke/perl-current) running:
[2017-01-13 21:38:04-0500] qx[/usr/local/bin/git reset --hard]
[2017-01-13 21:38:04-0500] HEAD is now at 2798a01 Write tests for RT #77934.
[2017-01-13 21:38:04-0500] In pwd(/usr/home/jkeenan/p5smoke/perl-current) running:
[2017-01-13 21:38:04-0500] qx[/usr/local/bin/git clean -dfx]
[2017-01-13 21:38:08-0500] Removing .config/
[2017-01-13 21:38:08-0500] Removing .patch
# snip
[2017-01-13 21:38:08-0500] Removing uudmap.h
[2017-01-13 21:38:08-0500] Removing veryclean.sh
[2017-01-13 21:38:08-0500] In pwd(/usr/home/jkeenan/p5smoke/perl-current) running:
[2017-01-13 21:38:08-0500] qx[/usr/local/bin/git pull --all]
[2017-01-13 21:38:09-0500] Fetching origin
[2017-01-13 21:38:09-0500] Already up-to-date.
[2017-01-13 21:38:09-0500] In pwd(/usr/home/jkeenan/p5smoke/perl-current) running:
[2017-01-13 21:38:09-0500] qx[/usr/local/bin/git checkout blead
[2017-01-13 21:38:09-0500]  2>&1]
Switched to branch 'blead'
[2017-01-13 21:38:09-0500] Your branch is up-to-date with 'origin/blead'.
[2017-01-13 21:38:09-0500] In pwd(/usr/home/jkeenan/p5smoke/perl-current) running:
[2017-01-13 21:38:09-0500] qx[/usr/local/bin/perl Porting/make_dot_patch.pl > .patch]

[2017-01-13 21:38:09-0500] /usr/home/jkeenan/p5smoke/perl-current is now up to patchlevel 3626fc2020b81652c4b3c7dd5ef0822b194d2d5e
[2017-01-13 21:38:09-0500] Commitlevel after sync: 3626fc2020b81652c4b3c7dd5ef0822b194d2d5e
[2017-01-13 21:38:09-0500] ==> Starting runsmoke
[2017-01-13 21:38:09-0500] [./tssmokeperl.pl] chdir(/usr/home/jkeenan/p5smoke/perl-current)
[2017-01-13 21:38:09-0500] [filetest] /usr/home/jkeenan/p5smoke/perl-current/ext/Test-Harness/lib/Test/Harness.pm: N
[2017-01-13 21:38:09-0500] [filetest] /usr/home/jkeenan/p5smoke/perl-current/cpan/Test-Harness/lib/Test/Harness.pm: Y
[2017-01-13 21:38:09-0500] [filetest] /usr/home/jkeenan/p5smoke/perl-current/lib/Test/Harness.pm: N
[2017-01-13 21:38:09-0500] Test::Harness candidate '/usr/home/jkeenan/p5smoke/perl-current/cpan/Test-Harness/lib/Test/Harness.pm'
[2017-01-13 21:38:09-0500] In pwd(/usr/home/jkeenan/p5smoke/perl-current) running:
[2017-01-13 21:38:09-0500] qx[/usr/local/bin/perl -e "require q[/usr/home/jkeenan/p5smoke/perl-current/cpan/Test-Harness/lib/Test/Harness.pm];print Test::Harness->VERSION" 2>&1]
Argument "3.36_01" isn't numeric in numeric ge (>=) at /usr/home/jkeenan/p5smoke/install/Test/Smoke/App/RunSmoke.pm line 188.
[2017-01-13 21:38:09-0500] Found: Test::Harness version 3.36_01.
[2017-01-13 21:38:09-0500] Reading build configurations from /usr/home/jkeenan/p5smoke/install/perlcurrent.cfg
[2017-01-13 21:38:09-0500] Found 4 raw-sections
[2017-01-13 21:38:09-0500] Left with 2 parsed sections
[2017-01-13 21:38:09-0500] Found 1 (unfiltered) configurations
[2017-01-13 21:38:09-0500] Reading 'Policy.sh' from default content (v=2)
[2017-01-13 21:38:09-0500] [get_patch] found: '3626fc2020b81652c4b3c7dd5ef0822b194d2d5e', 'v5.25.8-196-g3626fc2', 'blead'
[2017-01-13 21:38:09-0500] make distclean ...
[2017-01-13 21:38:09-0500] [make -i distclean 2>/dev/null]
[2017-01-13 21:38:09-0500] Smoking patch 3626fc2020b81652c4b3c7dd5ef0822b194d2d5e v5.25.8-196-g3626fc2
[2017-01-13 21:38:09-0500] Smoking branch blead
[2017-01-13 21:38:09-0500] Found 5994 entries in MANIFEST
[2017-01-13 21:38:09-0500] Found 7 entries in MANIFEST.SKIP
[2017-01-13 21:38:09-0500] [manicheck] Matched .dir-locals.el
[2017-01-13 21:38:09-0500] [manicheck] Skipped .gitignore
# snip
[2017-01-13 21:38:10-0500] [manicheck] Matched win32/include/sys/socket.h
[2017-01-13 21:38:10-0500] [manicheck] 0 entries missing
[2017-01-13 21:38:10-0500] Locally applied patches from '/usr/home/jkeenan/p5smoke/perl-current/patchlevel.h'
[2017-01-13 21:38:10-0500] Patches: 'uncommitted-changes'
[2017-01-13 21:38:10-0500] Adding 'SMOKE3626fc2020b81652c4b3c7dd5ef0822b194d2d5e' to the registered patches.
[2017-01-13 21:38:10-0500] 
[2017-01-13 21:38:10-0500] Configuration: -Dusedevel -Duseithreads -Doptimize="-O2 -pipe -fstack-protector -fno-strict-aliasing" -DDEBUGGING
[2017-01-13 21:38:10-0500] ------------------------------------------------------------------------------
[2017-01-13 21:38:10-0500] make distclean ...
[2017-01-13 21:38:10-0500] [make -i distclean 2>/dev/null]
[2017-01-13 21:38:10-0500] manicheck: extra 'patchlevel.bak' (not in MANIFEST)
[2017-01-13 21:38:10-0500] 
[2017-01-13 21:38:10-0500] Copy Policy.sh ...
[2017-01-13 21:38:10-0500] 
[2017-01-13 21:38:10-0500] Configure ...
[2017-01-13 21:38:10-0500] [./Configure -des -Dusedevel -Duseithreads -Doptimize="-O2 -pipe -fstack-protector -fno-strict-aliasing" -DDEBUGGING]
[2017-01-13 21:39:16-0500] 
[2017-01-13 21:39:16-0500] make ...
[2017-01-13 21:39:16-0500] [make ]
magic: PERL_MAGIC_qr already provided by misc
Warning (mostly harmless): No library found for -ldb
magic: PERL_MAGIC_qr already provided by misc
Warning (mostly harmless): No library found for -lndbm
Warning (mostly harmless): No library found for -ldbm
Warning (mostly harmless): No library found for -lucb
Warning (mostly harmless): No library found for -lposix
Warning (mostly harmless): No library found for -lcposix
Making header files for XS...
[2017-01-13 21:42:45-0500] [make test-prep]
Warning (mostly harmless): No library found for -ldb
[2017-01-13 21:43:00-0500] Skip tests from '/usr/home/jkeenan/p5smoke/install/smokecurrent.skiptests'
[2017-01-13 21:43:00-0500] 
[2017-01-13 21:43:00-0500]  Tests start here:
[2017-01-13 21:43:00-0500] TSTENV = stdio	
The _test target is deprecated. Please upgrade your smoker
[2017-01-13 21:43:00-0500] echo >&2 The _test target is deprecated. Please upgrade your smoker
[2017-01-13 21:43:00-0500] echo >&2 The _test target is deprecated. Please upgrade your smoker
[2017-01-13 21:43:00-0500] ./runtests choose
[2017-01-13 21:43:00-0500] ./runtests choose
[2017-01-13 21:43:00-0500] t/base/cond .................................................... ok
[2017-01-13 21:43:00-0500] t/base/if ...................................................... ok
# snip
[2017-01-13 22:15:47-0500] lib/warnings ................................................... ok
[2017-01-13 22:15:47-0500] All tests successful.
[2017-01-13 22:15:47-0500] All tests successful.
[2017-01-13 22:15:47-0500] Elapsed: 970 sec
[2017-01-13 22:15:47-0500] Elapsed: 970 sec
[2017-01-13 22:15:47-0500] u=9.01  s=25.23  cu=438.33  cs=170.46  scripts=2440  tests=1242510
[2017-01-13 22:15:47-0500] u=9.01  s=25.23  cu=438.33  cs=170.46  scripts=2440  tests=1242510
[2017-01-13 22:15:47-0500] 
[2017-01-13 22:15:47-0500] OK, archive results ...

[2017-01-13 22:15:47-0500] Unskip tests from '/usr/home/jkeenan/p5smoke/install/smokecurrent.skiptests'
# snip
[2017-01-13 22:15:48-0500] ==> Starting poster
[2017-01-13 22:15:48-0500] Posting to http://perl5.test-smoke.org/report via HTTP::Tiny.
[2017-01-13 22:15:48-0500] Reading from (/usr/home/jkeenan/p5smoke/perl-current/mktest.jsn)
[2017-01-13 22:15:48-0500] Report data: {
[2017-01-13 22:15:48-0500]    "skip_tests" : "/usr/home/jkeenan/p5smoke/install/smokecurrent.skiptests",
[2017-01-13 22:15:48-0500]    "manifest_msgs" : [],
[2017-01-13 22:15:48-0500]    "skipped_tests" : [
[2017-01-13 22:15:48-0500]       "    # One test name on a line"
[2017-01-13 22:15:48-0500]    ],
[2017-01-13 22:15:48-0500]    "rptfile" : "mktest.rpt",
[2017-01-13 22:15:48-0500]    "lfile" : "/usr/home/jkeenan/p5smoke/install/smokecurrent.log",
[2017-01-13 22:15:48-0500]    "un_file" : "/usr/home/jkeenan/p5smoke/install/smokecurrent.usernote",
[2017-01-13 22:15:48-0500]    "is56x" : 0,
[2017-01-13 22:15:48-0500]    "sysinfo" : {
[2017-01-13 22:15:48-0500]       "hostname" : "localhost",
[2017-01-13 22:15:48-0500]       "git_id" : "3626fc2020b81652c4b3c7dd5ef0822b194d2d5e",
[2017-01-13 22:15:48-0500]       "cpu_description" : "Intel(R) Core(TM) i5-4200M CPU @ 2.50GHz",
[2017-01-13 22:15:48-0500]       "reporter" : null,
[2017-01-13 22:15:48-0500]       "cpu_count" : "1",
[2017-01-13 22:15:48-0500]       "smoke_branch" : "blead",
[2017-01-13 22:15:48-0500]       "git_describe" : "v5.25.8-196-g3626fc2",
[2017-01-13 22:15:48-0500]       "username" : "jkeenan",
[2017-01-13 22:15:48-0500]       "perl_id" : "5.25.9",
[2017-01-13 22:15:48-0500]       "lang" : null,
[2017-01-13 22:15:48-0500]       "smoker_version" : "0.046",
[2017-01-13 22:15:48-0500]       "osname" : "freebsd",
[2017-01-13 22:15:48-0500]       "reporter_version" : "0.053",
[2017-01-13 22:15:48-0500]       "lc_all" : null,
[2017-01-13 22:15:48-0500]       "smoke_revision" : "1.70",
[2017-01-13 22:15:48-0500]       "user_note" : "Occasional failures observed in long-running tests in:\n    t/re/speed.t\n    t/re/speed_thr.t\n    cpan/Memoize/t/expmod_t.t\n    dist/Time-HiRes/t/alarm.t\n",
[2017-01-13 22:15:48-0500]       "smoke_perl" : "5.20.3",
[2017-01-13 22:15:48-0500]       "smoke_date" : "2017-01-13 21:38:09 -0500",
[2017-01-13 22:15:48-0500]       "architecture" : "amd64",
[2017-01-13 22:15:48-0500]       "duration" : 2258,
[2017-01-13 22:15:48-0500]       "test_jobs" : "8",
[2017-01-13 22:15:48-0500]       "osversion" : "10.3-RELEASE",
[2017-01-13 22:15:48-0500]       "config_count" : 1,
[2017-01-13 22:15:48-0500]       "smoke_version" : "1.70"
[2017-01-13 22:15:48-0500]    },
[2017-01-13 22:15:48-0500]    "v" : "2",
[2017-01-13 22:15:48-0500]    "outfile" : "mktest.out",
[2017-01-13 22:15:48-0500]    "showcfg" : 0,
[2017-01-13 22:15:48-0500]    "cfg" : "/usr/home/jkeenan/p5smoke/install/perlcurrent.cfg",
[2017-01-13 22:15:48-0500]    "defaultenv" : 0,
[2017-01-13 22:15:48-0500]    "ddir" : "/usr/home/jkeenan/p5smoke/perl-current",
[2017-01-13 22:15:48-0500]    "compiler_msgs" : [],
[2017-01-13 22:15:48-0500]    "log_file" : null,
[2017-01-13 22:15:48-0500]    "applied_patches" : [
[2017-01-13 22:15:48-0500]       "SMOKE3626fc2020b81652c4b3c7dd5ef0822b194d2d5e"
[2017-01-13 22:15:48-0500]    ],
[2017-01-13 22:15:48-0500]    "summary" : "PASS",
[2017-01-13 22:15:48-0500]    "out_file" : null,
[2017-01-13 22:15:48-0500]    "nonfatal_msgs" : [],
[2017-01-13 22:15:48-0500]    "harness_only" : "0",
[2017-01-13 22:15:48-0500]    "jsnfile" : "mktest.jsn",
[2017-01-13 22:15:48-0500]    "un_position" : "bottom",
[2017-01-13 22:15:48-0500]    "harness3opts" : null,
[2017-01-13 22:15:48-0500]    "locale" : "",
[2017-01-13 22:15:48-0500]    "configs" : [
[2017-01-13 22:15:48-0500]       {
[2017-01-13 22:15:48-0500]          "results" : [
[2017-01-13 22:15:48-0500]             {
[2017-01-13 22:15:48-0500]                "summary" : "O",
[2017-01-13 22:15:48-0500]                "stat_cpu_time" : 651.03,
[2017-01-13 22:15:48-0500]                "io_env" : "stdio",
[2017-01-13 22:15:48-0500]                "locale" : null,
[2017-01-13 22:15:48-0500]                "statistics" : "u=8.11  s=23.07  cu=435.73  cs=184.12  scripts=2440  tests=1242458",
[2017-01-13 22:15:48-0500]                "stat_tests" : "1242458",
[2017-01-13 22:15:48-0500]                "failures" : []
[2017-01-13 22:15:48-0500]             },
[2017-01-13 22:15:48-0500]             {
[2017-01-13 22:15:48-0500]                "summary" : "O",
[2017-01-13 22:15:48-0500]                "stat_cpu_time" : 643.03,
[2017-01-13 22:15:48-0500]                "locale" : null,
[2017-01-13 22:15:48-0500]                "io_env" : "perlio",
[2017-01-13 22:15:48-0500]                "statistics" : "u=9.01  s=25.23  cu=438.33  cs=170.46  scripts=2440  tests=1242510",
[2017-01-13 22:15:48-0500]                "failures" : [],
[2017-01-13 22:15:48-0500]                "stat_tests" : "1242510"
[2017-01-13 22:15:48-0500]             }
[2017-01-13 22:15:48-0500]          ],
[2017-01-13 22:15:48-0500]          "debugging" : "D",
[2017-01-13 22:15:48-0500]          "duration" : 2257,
[2017-01-13 22:15:48-0500]          "started" : "2017-01-13 21:38:10 -0500",
[2017-01-13 22:15:48-0500]          "ccversion" : "4.2.1 Compatible FreeBSD Clang 3.4.1 (tags/RELEASE_34/dot1-final 208032)",
[2017-01-13 22:15:48-0500]          "cc" : "cc",
[2017-01-13 22:15:48-0500]          "arguments" : "-Duseithreads -Doptimize=\"-O2 -pipe -fstack-protector -fno-strict-aliasing\""
[2017-01-13 22:15:48-0500]       }
[2017-01-13 22:15:48-0500]    ]
[2017-01-13 22:15:48-0500] }
[2017-01-13 22:15:49-0500] http://perl5.test-smoke.org/report/53193
[2017-01-13 22:15:49-0500] ==> Starting archiver
[2017-01-13 22:15:49-0500] Copy(/usr/home/jkeenan/p5smoke/perl-current/mktest.rpt, /usr/home/jkeenan/p5smoke/install/logs/smokecurrent/rpt3626fc2020b81652c4b3c7dd5ef0822b194d2d5e.rpt): ok
[2017-01-13 22:15:49-0500] Copy(/usr/home/jkeenan/p5smoke/perl-current/mktest.out, /usr/home/jkeenan/p5smoke/install/logs/smokecurrent/out3626fc2020b81652c4b3c7dd5ef0822b194d2d5e.out): ok
[2017-01-13 22:15:49-0500] Copy(/usr/home/jkeenan/p5smoke/perl-current/mktest.jsn, /usr/home/jkeenan/p5smoke/install/logs/smokecurrent/jsn3626fc2020b81652c4b3c7dd5ef0822b194d2d5e.jsn): ok
[2017-01-13 22:15:49-0500] Copy(/usr/home/jkeenan/p5smoke/install/smokecurrent.log, /usr/home/jkeenan/p5smoke/install/logs/smokecurrent/log3626fc2020b81652c4b3c7dd5ef0822b194d2d5e.log): ok

--------------BEB06D10B0C2E8332FABD8A4--