Strace
Simon Peyton Jones
simonpj at microsoft.com
Mon Jun 18 10:44:26 UTC 2018
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: test] Error 1
.../tests/plugins$
From: Phyx <lonetiger at gmail.com>
Sent: 13 June 2018 20:47
To: Simon Peyton Jones <simonpj at microsoft.com>
Cc: ghc-devs at haskell.org
Subject: Re: Strace
Hi Simon,
On Wed, Jun 13, 2018 at 5:24 PM, Simon Peyton Jones <simonpj at microsoft.com<mailto:simonpj at microsoft.com>> 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 <lonetiger at gmail.com<mailto:lonetiger at gmail.com>>
Sent: 13 June 2018 17:19
To: Simon Peyton Jones <simonpj at microsoft.com<mailto:simonpj at microsoft.com>>
Cc: ghc-devs at haskell.org<mailto:ghc-devs at 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/4778cba1dbb6adf495930322d7f9e9db0af60d8f..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 <simonpj at microsoft.com<mailto:simonpj at microsoft.com>> 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 <tamar at zhox.com<mailto:tamar at zhox.com>>
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
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mail.haskell.org/pipermail/ghc-devs/attachments/20180618/4bbc618f/attachment-0001.html>
More information about the ghc-devs
mailing list