Hi Simon, T11244 and the plugin output changes have been done after my commit to fix the tests, hence the new std issues. Those have to be fixed up again... I'm curious about the threading issues though. One way to find out is by running the entire testsuite with -j again but with VERBOSE=3 and piping to a file. This will show the underlying tool's output instead of throwing it away. This will of course generate lots of data but shouldn't be at the level of the strace output, but should give an indication of what's going on. Cheers, Tamar On Mon, Jun 18, 2018, 11:44 Simon Peyton Jones wrote:

Tamar

OK, the first thing I tried was this

- cd testsuite/tests/plugins - make

Note no “-j”, so this is single threaded.

Output is below. Yes, fewer failures, so it does seem that many of the failures I see in a generic test suite run are to do with concurrency. So that’s Bug #1.

But even if Bug #1 was solved, I seem to get three failures that happen even in the absence of concurrent testing. This is Bug #2 (or maybe 2,3,4).

Happy to run more commands!

Simon

*.../tests/plugins$ make*

*PYTHON="python3" "python3" ../../driver/runtests.py -e "ghc_compiler_always_flags='-dcore-lint -dcmm-lint -no-user-package-db -rtsopts -fno-warn-missed-specialisations -fshow-warning-groups -fdiagnostics-color=never -fno-diagnostics-show-caret -dno-debug-output'" -e config.compiler_debugged=False -e ghc_with_native_codegen=1 -e config.have_vanilla=True -e config.have_dynamic=False -e config.have_profiling=False -e ghc_with_threaded_rts=1 -e ghc_with_dynamic_rts=0 -e config.have_interp=True -e config.unregisterised=False -e config.have_gdb=False -e config.have_readelf=True -e config.ghc_dynamic_by_default=False -e config.ghc_dynamic=False -e ghc_with_smp=1 -e ghc_with_llvm=0 -e windows=True -e darwin=False -e config.in_tree_compiler=True -e config.cleanup=True -e config.local=True --rootdir=. --config-file=../../config/ghc -e 'config.confdir="../../config"' -e 'config.platform="x86_64-unknown-mingw32"' -e 'config.os="mingw32"' -e 'config.arch="x86_64"' -e 'config.wordsize="64"' -e 'config.timeout=int() or config.timeout' -e 'config.exeext=".exe"' -e 'config.top="/c/code/HEAD/testsuite"' --config 'compiler="/c/code/HEAD/inplace/bin/ghc-stage2.exe"' --config 'ghc_pkg="/c/code/HEAD/inplace/bin/ghc-pkg.exe"' --config 'haddock=' --config 'hp2ps="/c/code/HEAD/inplace/bin/hp2ps.exe"' --config 'hpc="/c/code/HEAD/inplace/bin/hpc.exe"' --config 'gs="gs"' --config 'timeout_prog="../../timeout/install-inplace/bin/timeout.exe"' -e "config.stage=2" \*

* \*

* \*

* \*

* \*

* \*

* \*

*Timeout is 300*

*Found 1 .T files...*

*Beginning test run at Mon Jun 18 11:24:57 2018 GMTST*

*--- ./plugins09.run/plugins09.stdout.normalised 2018-06-18 11:27:47.971987800 +0100*

*+++ ./plugins09.run/plugins09.run.stdout.normalised 2018-06-18 11:27:47.972177400 +0100*

*@@ -1,9 +0,0 @@*

*-parsePlugin(a,b)*

*-interfacePlugin: Prelude*

*-interfacePlugin: GHC.Float*

*-interfacePlugin: GHC.Base*

*-interfacePlugin: GHC.Types*

*-typeCheckPlugin (rn)*

*-typeCheckPlugin (tc)*

*-interfacePlugin: GHC.Integer.Type*

*-interfacePlugin: GHC.Natural*

*--- ./plugins11.run/plugins11.stdout.normalised 2018-06-18 11:28:40.307222400 +0100*

*+++ ./plugins11.run/plugins11.run.stdout.normalised 2018-06-18 11:28:40.307675400 +0100*

*@@ -1,9 +0,0 @@*

*-parsePlugin()*

*-interfacePlugin: Prelude*

*-interfacePlugin: GHC.Float*

*-interfacePlugin: GHC.Base*

*-interfacePlugin: GHC.Types*

*-typeCheckPlugin (rn)*

*-typeCheckPlugin (tc)*

*-interfacePlugin: GHC.Integer.Type*

*-interfacePlugin: GHC.Natural*

*--- ./T11244.run/T11244.stderr.normalised 2018-06-18 11:32:21.142334600 +0100*

*+++ ./T11244.run/T11244.run.stderr.normalised 2018-06-18 11:32:21.145148100 +0100*

*@@ -1,4 +1,4 @@*

*-<command line>: Could not load module ‘RuleDefiningPlugin’*

*+<command line>: Could not find module ‘RuleDefiningPlugin’*

*It is a member of the hidden package ‘rule-defining-plugin-0.1’.*

*You can run ‘:set -package rule-defining-plugin’ to expose it.*

*(Note: this unloads all the modules in the current scope.)*

*====> Scanning ./all.T*

*=====> plugins01(normal) 1 of 25 [0, 0, 0]*

*cd "./plugins01.run" && $MAKE -s --no-print-directory -C simple-plugin package.plugins01 TOP=/c/code/HEAD/testsuite*

*cd "./plugins01.run" && $MAKE -s --no-print-directory plugins01 *

*=====> plugins02(normal) 2 of 25 [0, 0, 0]*

*cd "./plugins02.run" && $MAKE -s --no-print-directory -C simple-plugin package.plugins02 TOP=/c/code/HEAD/testsuite*

*cd "./plugins02.run" && "/c/code/HEAD/inplace/bin/ghc-stage2.exe" -c plugins02.hs -dcore-lint -dcmm-lint -no-user-package-db -rtsopts -fno-warn-missed-specialisations -fshow-warning-groups -fdiagnostics-color=never -fno-diagnostics-show-caret -dno-debug-output -package-db simple-plugin/pkg.plugins02/local.package.conf -fplugin Simple.BadlyTypedPlugin -package simple-plugin -static*

*=====> plugins03(normal) 3 of 25 [0, 0, 0]*

*cd "./plugins03.run" && $MAKE -s --no-print-directory -C simple-plugin package.plugins03 TOP=/c/code/HEAD/testsuite*

*cd "./plugins03.run" && "/c/code/HEAD/inplace/bin/ghc-stage2.exe" -c plugins03.hs -dcore-lint -dcmm-lint -no-user-package-db -rtsopts -fno-warn-missed-specialisations -fshow-warning-groups -fdiagnostics-color=never -fno-diagnostics-show-caret -dno-debug-output -package-db simple-plugin/pkg.plugins03/local.package.conf -fplugin Simple.NonExistentPlugin -package simple-plugin*

*=====> plugins04(normal) 4 of 25 [0, 0, 0]*

*cd "./plugins04.run" && "/c/code/HEAD/inplace/bin/ghc-stage2.exe" --make plugins04 -dcore-lint -dcmm-lint -no-user-package-db -rtsopts -fno-warn-missed-specialisations -fshow-warning-groups -fdiagnostics-color=never -fno-diagnostics-show-caret -dno-debug-output -package ghc -fplugin HomePackagePlugin*

*=====> plugins05(normal) 5 of 25 [0, 0, 0]*

*cd "./plugins05.run" && "/c/code/HEAD/inplace/bin/ghc-stage2.exe" --make -o plugins05 plugins05 -dcore-lint -dcmm-lint -no-user-package-db -rtsopts -fno-warn-missed-specialisations -fshow-warning-groups -fdiagnostics-color=never -fno-diagnostics-show-caret -dno-debug-output -package ghc*

*cd "./plugins05.run" && ./plugins05 *

*=====> plugins07(normal) 7 of 25 [0, 0, 0]*

*cd "./plugins07.run" && $MAKE -s --no-print-directory -C rule-defining-plugin package.plugins07 TOP=/c/code/HEAD/testsuite*

*cd "./plugins07.run" && $MAKE -s --no-print-directory plugins07 *

*=====> plugins08(normal) 8 of 25 [0, 0, 0]*

*cd "./plugins08.run" && $MAKE -s --no-print-directory -C simple-plugin package.plugins08 TOP=/c/code/HEAD/testsuite*

*cd "./plugins08.run" && $MAKE -s --no-print-directory plugins08 *

*=====> plugins09(normal) 9 of 25 [0, 0, 0]*

*cd "./plugins09.run" && $MAKE -s --no-print-directory -C simple-plugin package.plugins09 TOP=/c/code/HEAD/testsuite*

*cd "./plugins09.run" && $MAKE -s --no-print-directory plugins09 *

*Actual stdout output differs from expected:*

*diff -uw "./plugins09.run/plugins09.stdout.normalised" "./plugins09.run/plugins09.run.stdout.normalised"*

**** unexpected failure for plugins09(normal)*

*=====> plugins10(normal) 10 of 25 [0, 1, 0]*

*cd "./plugins10.run" && $MAKE -s --no-print-directory -C simple-plugin package.plugins10 TOP=/c/code/HEAD/testsuite*

*cd "./plugins10.run" && $MAKE -s --no-print-directory plugins10 *

*=====> plugins11(normal) 11 of 25 [0, 1, 0]*

*cd "./plugins11.run" && $MAKE -s --no-print-directory -C simple-plugin package.plugins11 TOP=/c/code/HEAD/testsuite*

*cd "./plugins11.run" && $MAKE -s --no-print-directory plugins11 *

*Actual stdout output differs from expected:*

*diff -uw "./plugins11.run/plugins11.stdout.normalised" "./plugins11.run/plugins11.run.stdout.normalised"*

**** unexpected failure for plugins11(normal)*

*=====> plugins12(normal) 12 of 25 [0, 2, 0]*

*cd "./plugins12.run" && $MAKE -s --no-print-directory -C simple-plugin package.plugins12 TOP=/c/code/HEAD/testsuite*

*cd "./plugins12.run" && $MAKE -s --no-print-directory plugins12 *

*=====> plugins13(normal) 13 of 25 [0, 2, 0]*

*cd "./plugins13.run" && $MAKE -s --no-print-directory -C simple-plugin package.plugins13 TOP=/c/code/HEAD/testsuite*

*cd "./plugins13.run" && $MAKE -s --no-print-directory plugins13 *

*=====> plugins14(normal) 14 of 25 [0, 2, 0]*

*cd "./plugins14.run" && $MAKE -s --no-print-directory -C simple-plugin package.plugins14 TOP=/c/code/HEAD/testsuite*

*cd "./plugins14.run" && $MAKE -s --no-print-directory plugins14 *

*=====> plugins15(normal) 15 of 25 [0, 2, 0]*

*cd "./plugins15.run" && $MAKE -s --no-print-directory -C simple-plugin package.plugins15 TOP=/c/code/HEAD/testsuite*

*cd "./plugins15.run" && $MAKE -s --no-print-directory plugins15 *

*=====> T10420(normal) 16 of 25 [0, 2, 0]*

*cd "./T10420.run" && $MAKE -s --no-print-directory -C rule-defining-plugin package.T10420 TOP=/c/code/HEAD/testsuite*

*cd "./T10420.run" && $MAKE -s --no-print-directory T10420 *

*=====> T10294(normal) 17 of 25 [0, 2, 0]*

*cd "./T10294.run" && $MAKE -s --no-print-directory -C annotation-plugin package.T10294 TOP=/c/code/HEAD/testsuite*

*cd "./T10294.run" && $MAKE -s --no-print-directory T10294 *

*=====> T10294a(normal) 18 of 25 [0, 2, 0]*

*cd "./T10294a.run" && $MAKE -s --no-print-directory -C annotation-plugin package.T10294a TOP=/c/code/HEAD/testsuite*

*cd "./T10294a.run" && $MAKE -s --no-print-directory T10294a *

*=====> frontend01(normal) 19 of 25 [0, 2, 0]*

*cd "./frontend01.run" && $MAKE -s --no-print-directory frontend01 *

*=====> T11244(normal) 20 of 25 [0, 2, 0]*

*cd "./T11244.run" && $MAKE -s --no-print-directory -C rule-defining-plugin package.T11244 TOP=/c/code/HEAD/testsuite*

*cd "./T11244.run" && $MAKE -s --no-print-directory T11244 *

*Actual stderr output differs from expected:*

*diff -uw "./T11244.run/T11244.stderr.normalised" "./T11244.run/T11244.run.stderr.normalised"*

**** unexpected failure for T11244(normal)*

*=====> T12567a(normal) 21 of 25 [0, 3, 0]*

*cd "./T12567a.run" && $MAKE -s --no-print-directory -C simple-plugin package.T12567a TOP=/c/code/HEAD/testsuite*

*cd "./T12567a.run" && $MAKE -s --no-print-directory T12567a *

*=====> T14335(normal) 22 of 25 [0, 3, 0]*

*cd "./T14335.run" && $MAKE -s --no-print-directory -C simple-plugin package.plugins01 TOP=/c/code/HEAD/testsuite*

*cd "./T14335.run" && "/c/code/HEAD/inplace/bin/ghc-stage2.exe" -c T14335.hs -dcore-lint -dcmm-lint -no-user-package-db -rtsopts -fno-warn-missed-specialisations -fshow-warning-groups -fdiagnostics-color=never -fno-diagnostics-show-caret -dno-debug-output -package-db simple-plugin/pkg.plugins01/local.package.conf -fplugin Simple.Plugin -fexternal-interpreter -package simple-plugin -static*

*=====> plugin-recomp-pure(normal) 23 of 25 [0, 3, 0]*

*cd "./plugin-recomp-pure.run" && $MAKE -s --no-print-directory -C plugin-recomp package.plugins01 TOP=/c/code/HEAD/testsuite*

*cd "./plugin-recomp-pure.run" && $MAKE -s --no-print-directory plugin-recomp-pure *

*=====> plugin-recomp-impure(normal) 24 of 25 [0, 3, 0]*

*cd "./plugin-recomp-impure.run" && $MAKE -s --no-print-directory -C plugin-recomp package.plugins01 TOP=/c/code/HEAD/testsuite*

*cd "./plugin-recomp-impure.run" && $MAKE -s --no-print-directory plugin-recomp-impure *

*=====> plugin-recomp-flags(normal) 25 of 25 [0, 3, 0]*

*cd "./plugin-recomp-flags.run" && $MAKE -s --no-print-directory -C plugin-recomp package.plugins01 TOP=/c/code/HEAD/testsuite*

*cd "./plugin-recomp-flags.run" && $MAKE -s --no-print-directory plugin-recomp-flags *

*Unexpected results from:*

*TEST="T11244 plugins09 plugins11"*

*SUMMARY for test run started at Mon Jun 18 11:24:57 2018 GMTST*

*0:11:18 spent to go through*

* 25 total tests, which gave rise to*

* 35 test cases, of which*

* 11 were skipped*

* 0 had missing libraries*

* 19 expected passes*

* 2 expected failures*

* 0 caused framework failures*

* 0 caused framework warnings*

* 0 unexpected passes*

* 3 unexpected failures*

* 0 unexpected stat failures*

*Unexpected failures:*

* plugins09.run plugins09 [bad stdout] (normal)*

* plugins11.run plugins11 [bad stdout] (normal)*

* T11244.run T11244 [bad stderr] (normal)*

*make: *** [../../mk/test.mk:329 http://test.mk:329: test] Error 1*

*.../tests/plugins$*

*From:* Phyx *Sent:* 13 June 2018 20:47

*To:* Simon Peyton Jones *Cc:* ghc-devs@haskell.org *Subject:* Re: Strace

Hi Simon,

On Wed, Jun 13, 2018 at 5:24 PM, Simon Peyton Jones wrote:

OK – so maybe the root cause is a framework failure – and indeed for the last few weeks I’ve seen

Framework failures:

plugins/plugins07.run plugins07 [normal] (pre_cmd failed: 2)

plugins/T10420.run T10420 [normal] (pre_cmd failed: 2)

plugins/T11244.run T11244 [normal] (pre_cmd failed: 2)

I have just learned to live with these failures, because I knew you were working on making things better. But it sounds as if they are still taking place.

The commit I made should have reduced the amount of failing tests to 0. framework failures are always quite unusual.

So:

- Yes, please make it not happen by default

I've removed the code, if you update it should be gone. It was there and on by default because I was trying to debug failures on Harbormaster, I

realized a switch isn't very useful as I won't be able to toggle it for Harbormaster anyway.

- - If you don’t get these framework failures, can we work together to resolve them?

These don't happen for me nor on Harbormaster, try picking a test, e.g T10420

run only that test to make sure it's not a threading issue:

make TEST=T10420 test -C testsuite/tests

If it still gives a framework error then do at the top level

make VERBOSE=3 TEST=T10420 test -C testsuite/tests

once it runs, the output should contain the command it ran as a pre_cmd, and the stdout and

stderr from the pre_cmd output. Could you then send the error?

if it doesn't show any of this, try

make CLEANP=0 VERBOSE=3 TEST= T10420 test -C testsuite/tests --trace

and copy and paste the pre_cmd command, which should just replay the action it did.

Cheers,

Tamar

Thanks

Simon

*From:* Phyx *Sent:* 13 June 2018 17:19 *To:* Simon Peyton Jones *Cc:* ghc-devs@haskell.org *Subject:* Re: Strace

Hi Simon,

The strace is only supposed to run when the normal test pre_cmd fails.

If it's running that often it means your tests are all failing during pre_cmd with a framework failure

https://git.haskell.org/ghc.git/blobdiff/4778cba1dbb6adf495930322d7f9e9 db0af60d8f..60fb2b2160aa16194b74262f4df8fad5af171b0f:/testsuite/driver/ testlib.py

But maybe I shouldn't turn this on my default. I'll pramaterize it when I get home.

Tamar.

On Wed, Jun 13, 2018, 17:09 Simon Peyton Jones wrote:

Tamar

I’m getting *megabytes* of output from ‘sh validate’ on windows. It looks like this

629 151745 [main] sh 2880 fhandler_base::fhaccess: returning 0

291 152036 [main] sh 2880 faccessat: returning 0

7757 159793 [main] sh 2880 fhandler_base_overlapped::wait_overlapped: wfres 0, wores 1, bytes 7

179457 1608947 [main] make 11484 fhandler_base_overlapped::wait_overlapped: wfres 0, wores 1, bytes 7

99 159892 [main] sh 2880 fhandler_base_overlapped::wait_overlapped: normal write, 7 bytes ispipe() 1

180 1609127 [main] make 11484 fhandler_base_overlapped::wait_overlapped: normal read, 7 bytes ispipe() 1

139 160031 [main] sh 2880 write: 7 = write(1, 0x6000396A0, 7)

142 1609269 [main] make 11484 fhandler_base::read: returning 7, binary mode

139 1609408 [main] make 11484 read: 7 = read(5, 0x60005B4B0, 7)

136 1609544 [main] make 11484 read: read(5, 0x60005B4B7, 193) blocking

4693 164724 [main] sh 2880 set_signal_mask: setmask 0, newmask 80000, mask_bits 0

but with hundreds of thousands of lines. (I have not counted)

I believe that it may be the result of this line, earlier in the log

cd "/c/Users/simonpj/AppData/Local/Temp/ghctest-8fa9s6rk/test spaces/./plugins/plugins07.run" && *strace* $MAKE -s --no-print-directory -C rule-defining-plugin package.plugins07 TOP=/c/code/HEAD/testsuite#

Note the strace.

That in turn was added in your commit

commit 60fb2b2160aa16194b74262f4df8fad5af171b0f

Author: Tamar Christina

Date: Mon May 28 19:34:11 2018 +0100

Clean up Windows testsuite failures

Summary:

Another round and attempt at getting these down to 0.

Could you perhaps have made a mistake here? Currently validate is unusable.

Thanks!

Simon