test-pgp and test-pgpmime fails non-deterministically
Hi,
This affects at least 3.2.14 and 3.2.15. Sometimes the test suite passes, sometimes it fails, like so:
Testing GnuPG crypto context: failed (4 errors, 0 warnings)
Testing PGP/MIME implementation: passed
Results: 12 tests passed; 1 tests failed.
Failed tests:
test-pgp
make[3]: *** [Makefile:1137: check-local] Error 255
make[3]: Leaving directory '/tmp/guix-build-gmime-3.2.15.drv-0/source/tests'
make[2]: *** [Makefile:974: check-am] Error 2
make[2]: Leaving directory '/tmp/guix-build-gmime-3.2.15.drv-0/source/tests'
make[1]: *** [Makefile:824: check-recursive] Error 1
make[1]: Leaving directory '/tmp/guix-build-gmime-3.2.15.drv-0/source/tests'
make: *** [Makefile:536: check-recursive] Error 1
Test suite failed, dumping logs.
error: in phase 'check': uncaught exception:
%exception #<&invoke-error program: "make" arguments: ("check" "-j" "32") exit-status: 2 term-signal: #f stop-signal: #f>
phase `check' failed after 67.0 seconds
command "make" "check" "-j" "32" failed with status 2
build process 18 exited with status 256
I suppose there is a race somewhere in the build system.
I think I've seen test-pgpmime fail as well.
Building with many cores is probably key to reproduce (I'm using 32 here). And I confirm the test-pgpmime fails spuriously as well:
Results: 12 tests passed; 1 tests failed.
Failed tests:
test-pgpmime
make[3]: *** [Makefile:1137: check-local] Error 255
make[3]: Leaving directory '/tmp/guix-build-gmime-3.2.15.drv-0/source/tests'
make[2]: *** [Makefile:974: check-am] Error 2
make[2]: Leaving directory '/tmp/guix-build-gmime-3.2.15.drv-0/source/tests'
make[1]: *** [Makefile:824: check-recursive] Error 1
make[1]: Leaving directory '/tmp/guix-build-gmime-3.2.15.drv-0/source/tests'
make: *** [Makefile:536: check-recursive] Error 1
Test suite failed, dumping logs.
error: in phase 'check': uncaught exception:
%exception #<&invoke-error program: "make" arguments: ("check" "-j" "32") exit-status: 2 term-signal: #f stop-signal:
phase `check' failed after 10.5 seconds
command "make" "check" "-j" "32" failed with status 2
build process 18 exited with status 256
The dependencies used are:
[email protected] [email protected] [email protected] [email protected] [email protected]
+ [email protected] [email protected] [email protected] [email protected] [email protected] [email protected] [email protected]
It should be relatively easy to reproduce using Guix (e.g. with guix build --no-grafts gmime && guix build --no-grafts gmime --check --rounds=10).
With this patch removing the two tests, I could build/run the test suites 10 times without a failure.
Are the tests being run in parallel? This might cause issues since test-pgp and test-pgpmime both setup/use/clobber (the same) temporary GNUPG_HOME environment.
If you just run one of those tests by itself, using a command like ./test-pgp -vvvv, does it ever fail? And if so, what are the diagnostics?
I can't investigate much at the moment, but yes, the tests were run in parallel, via make check -j32.
Then that is probably why.
I was able to reproduce the problem running only test-pgp like so:
$ timeout 5m sh -c 'while ./test-pgp -vvvv; do :; done'
[...]
Checking GMimeGpgContext::encrypt... PASSED
Checking GMimeGpgContext::decrypt... PASSED
ciphertext:
-----BEGIN PGP MESSAGE-----
hQIOAwTJ0obO8knpEAf/TK1IKYjU7ab+p+ghgOraYjxGc34j93fYG1AgUtdZKFWq
jnSBKr+e6HVHgWAttfhWWNz36OliGZNgm6ZJJNJti8aca4gqZ/ucK4QZY84kWRr/
ohNBtPEXDARPCNuruhQwWbpyeoynvPEqfhTVTKSlYvGewZsW4SGCDR7Zt7tuHox5
Md92jCFYRhDKfwouct0iq3mNCMBFkgP+y4IcrfRDQo3SMw6xwKzccXJCqFVhkne/
LnWo9GWMgw7vbVeZeKh4qWV/h3th/fgBOwoTumbMWJgw3fsQB2pHss2hl04ADl8d
5dpgzXJW5ZsnfWxAAbC0xo1AHum/gcWvLdM/+DWicgf/VZ6wPdfE9AxYSFl3WG7C
Mu4r1s9amLzJE6/k/1DkHaDxmu+MVc7MmPi+UpUjeE87Ircnicat7iJT60Q6qJcP
Gn5a8UXBNLl8MotPlzlAsobLYWvYi+MntiBIsXShD/L3nl0ielpv5FCJx26/uNpJ
4JQyYziuGOz/DaX3mfFoWIvGOK9fW4Vk2TZrVuF/qrnxPgy0q63qrE8Ese7JtwHI
xVX4/1TtusB2fl68R2Wcz+/60iVxe9M86/dYAzI/2WvGKDWBV3szRXAl5qkpQZeL
W0xq4/tTIOYR003075u56PYtfpBaoYFPZhoz4YQixNs7TaCiflSvendfUXHlWbXr
SdK1AdtI30lCNHyah56ocxRhsIMdeoX1zYBRQCbWhi3FdtRi7+dcQq5j8u+yxwpa
aDWBhxsDVBAecU8Eti4UfzgrsgINX2CFcAsc0w5GndlLMmpr98Bt+LjI2Rb4aCvg
wjz+sI/ladOiI1g+5YTMw1rtWOlrdJLgxjMtmFRKSzAtlhMqzLb/zjEjuvhnCo/1
55+6+JatJ+73PfSixqaahd54Fc5FXTcGHc/hBtKb2LYrej2BhP82Ow==
=65jU
-----END PGP MESSAGE-----
Checking GMimeGpgContext::encrypt+sign... PASSED
Checking GMimeGpgContext::decrypt+verify... PASSED
Checking GMimeFilterOpenPGP::public key block... PASSED
Checking GMimeFilterOpenPGP::private key block... PASSED
Checking GMimeFilterOpenPGP::signed message block... PASSED
Checking GMimeFilterOpenPGP::encrypted message block... PASSED
Testing GnuPG crypto context: failed (1 errors, 0 warnings)
It probably happened in the first minute of looping the test.
which test failed?
Hm, sorry for the too short output, here's more context including the failure:
Checking GMimeGpgContext::encrypt... PASSED
Checking GMimeGpgContext::decrypt... PASSED
ciphertext:
-----BEGIN PGP MESSAGE-----
hQIOAwTJ0obO8knpEAgAx/bKA4UaimXp1g+4ULMLy9APk3TwFTnZ236TstOyNgx4
G0dpaeEewvUSHugLc0Xrx1+P9kwdPcOr52jVODv1pfa8ifhgcTL1tawSCNLv6Jnp
fjZcUtF3YTDVxEqbYp6Yrckeq3KDxXSvhKZSuNUMU7LX5lpBrHDmE+hk1wgnDfeB
aJrCy6yvUT8Si0pKT4uJgKG+EmTJYjA8sR1SV6seCi3h6UblTf0/SxkmH0UpGafB
VNGJnegcrXbH0KYffXCbix/cX9RczwCoM9saiJNhIQ9x3elNYqPA4sxsE1zJCVY+
vBQviUBSwwo9vUg46nRO8YZ8U2JrdWihhhj5rM3CNggAi8CM/q8Gl0nAaM+brXSZ
JAnGoueJQGtjqnmdiE5tbWzb99F62fR0/aB+rk2IASJz9V8LrR58CrGnB/0W/o2f
dN6DqIB9Du6vww/GNlSJyVRzStsLeOYDOM+0gD1Rg3TDoqv09hgcBo2qziOpPfoT
Yelrh9xP+DUct3t7J00JhJwILWQT8GpVXc/ya0QLWgTQATlyrThy+Wdu8BoA3Lq5
pfuFg1rfaQ8cccpY62Wm6GCn4vBoWMaQJ58zzx1rWE6qhHQH2YSNePcf3eO6Yh6r
Ja/W7ub8Fie/HLhlk9nrnUjdUFuvFNBmD1PuQEowhhTFpfpn4LMnB9OyT6zPn4cY
rdK1AXlu1yUIh+M1d9KoYk5oOeNIorOtaSUEAQ8cqEdH6gJDmm4poN3LctfO8mea
hv6S0cNNis4bEtcaqejiA31BU3YaC17pIPoBhV5MkdVxw1FhmOk0fUhjogI4NBVT
r3vPHKZctO5HyVr4DMDC2f+3WCkgqD8gWgUYyH0sTkj1QVZreHg9JJiG7CP6rCj4
wKR5E2R6iOiLnCZnkZt/7Sebk3aWHEHrtNprIBsugKMIeFcAsiuYFA==
=mXkS
-----END PGP MESSAGE-----
Checking GMimeGpgContext::encrypt+sign... PASSED
Checking GMimeGpgContext::decrypt+verify... PASSED
Checking GMimeFilterOpenPGP::public key block... PASSED
Checking GMimeFilterOpenPGP::private key block... PASSED
Checking GMimeFilterOpenPGP::signed message block... PASSED
Checking GMimeFilterOpenPGP::encrypted message block... PASSED
Testing GnuPG crypto context: passed
Checking GMimeGpgContext::import... PASSED
GMimeGpgContext::export failed: Could not export key data: Input/output error
Checking GMimeGpgContext::export... FAILED
signature (pgp-sha1):
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1
this is some cleartext
-----BEGIN PGP SIGNATURE-----
iF0EARECAB0WIQTaJtq3VyocXyqxp0u0d2DpUYLCAAUCZ/ABZQAKCRC0d2DpUYLC
AMoyAKCwhVZcwPseBLQ66v7uRFHtwTsxgwCgk5i8VWFnlfqdRXmLS8Opp52qKd4=
=nbgW
-----END PGP SIGNATURE-----
Checking GMimeGpgContext::sign... PASSED
Checking GMimeGpgContext::verify... PASSED
signature (pgp-sha1):
-----BEGIN PGP SIGNATURE-----
iF0EABECAB0WIQTaJtq3VyocXyqxp0u0d2DpUYLCAAUCZ/ABZgAKCRC0d2DpUYLC
ABhzAJ9/uNUHEmBnkrsROIcJ5WLOFnUZ1ACcD4WcmVygpMHNLtBnb8weSDBCSQk=
=YwIP
-----END PGP SIGNATURE-----
Checking GMimeGpgContext::sign (detached)... PASSED
Checking GMimeGpgContext::verify (detached)... PASSED
ciphertext:
-----BEGIN PGP MESSAGE-----
hQIOAwTJ0obO8knpEAf+P+Skp8aGp8157AOpOLPbVmBYJGsI2J3yBgDoZnASES4v
f3PqLjn9efusR56M3gb/SLAw3OqxMZ7RSXhnNglM0MuoSH5P1xzCBfRuY0gYS2T3
d98ZHKjE+r9CMtGEjuIkGc+1+NbsehpDTXF9y05LWmv/qZ3J1cc3beRuAbjUnUoJ
F0Jla2Pmrbl83mUehelxkTF5viK9GR/Uk5TO+hi4a1ol3IMq1BcB4Z1kOOvoBHUt
D8Sa8SB2C6v6lagpGJc4jf37wLOKa2FBZleuXSEyv0xOZ7SOPMvStKXAm11q20Ej
eoE00CgBerh0H5AMKi9KDefTb0ZCNFb3Km4dMz6zhwgAn7AYHTRPCHXzmlVTimNh
jDJQreshtCN4JOL9fsOYxCEYoWBpt0SOJWYasiaSFbuFw8D341Gndg+7yioTojCs
VeRMB8OCKedeKgD5e2SMYSTYde+/s4GPT498ALg57JeWY+0wKUFJ8gaHmLWuHAfV
aocJVEPaRPn4+DsQ72pNRJt5RUR3YweRWuC1MycG34WG8YF/dv6wWb0n8kkcvFW6
/BnQn5MVBGaBVpbbskGTfI3sLISg/oAVGTSVRLOQMe1+KquZKk8cMKX2IAT0Wpai
g645I17nK+3k1+op6/JmW14qPopZXqvZjkkYvMIEtedgoSn8C7xPKd5Bs/ofymqx
xtJRAcvx77BdqQLurxZnSrB9ngUQXzOI/eTkxEuJlxZtDpLajxwhyShJMrYhYaGo
l59M1XVtZfz2ggopjQC/Y4WU+u6GG1cuY50s2qhTHNUh7LKF
=FBG0
-----END PGP MESSAGE-----
Checking GMimeGpgContext::encrypt... PASSED
Checking GMimeGpgContext::decrypt... PASSED
ciphertext:
-----BEGIN PGP MESSAGE-----
hQIOAwTJ0obO8knpEAf/TK1IKYjU7ab+p+ghgOraYjxGc34j93fYG1AgUtdZKFWq
jnSBKr+e6HVHgWAttfhWWNz36OliGZNgm6ZJJNJti8aca4gqZ/ucK4QZY84kWRr/
ohNBtPEXDARPCNuruhQwWbpyeoynvPEqfhTVTKSlYvGewZsW4SGCDR7Zt7tuHox5
Md92jCFYRhDKfwouct0iq3mNCMBFkgP+y4IcrfRDQo3SMw6xwKzccXJCqFVhkne/
LnWo9GWMgw7vbVeZeKh4qWV/h3th/fgBOwoTumbMWJgw3fsQB2pHss2hl04ADl8d
5dpgzXJW5ZsnfWxAAbC0xo1AHum/gcWvLdM/+DWicgf/VZ6wPdfE9AxYSFl3WG7C
Mu4r1s9amLzJE6/k/1DkHaDxmu+MVc7MmPi+UpUjeE87Ircnicat7iJT60Q6qJcP
Gn5a8UXBNLl8MotPlzlAsobLYWvYi+MntiBIsXShD/L3nl0ielpv5FCJx26/uNpJ
4JQyYziuGOz/DaX3mfFoWIvGOK9fW4Vk2TZrVuF/qrnxPgy0q63qrE8Ese7JtwHI
xVX4/1TtusB2fl68R2Wcz+/60iVxe9M86/dYAzI/2WvGKDWBV3szRXAl5qkpQZeL
W0xq4/tTIOYR003075u56PYtfpBaoYFPZhoz4YQixNs7TaCiflSvendfUXHlWbXr
SdK1AdtI30lCNHyah56ocxRhsIMdeoX1zYBRQCbWhi3FdtRi7+dcQq5j8u+yxwpa
aDWBhxsDVBAecU8Eti4UfzgrsgINX2CFcAsc0w5GndlLMmpr98Bt+LjI2Rb4aCvg
wjz+sI/ladOiI1g+5YTMw1rtWOlrdJLgxjMtmFRKSzAtlhMqzLb/zjEjuvhnCo/1
55+6+JatJ+73PfSixqaahd54Fc5FXTcGHc/hBtKb2LYrej2BhP82Ow==
=65jU
-----END PGP MESSAGE-----
Checking GMimeGpgContext::encrypt+sign... PASSED
Checking GMimeGpgContext::decrypt+verify... PASSED
Checking GMimeFilterOpenPGP::public key block... PASSED
Checking GMimeFilterOpenPGP::private key block... PASSED
Checking GMimeFilterOpenPGP::signed message block... PASSED
Checking GMimeFilterOpenPGP::encrypted message block... PASSED
Testing GnuPG crypto context: failed (1 errors, 0 warnings)
It failed on GMimeGpgContext::export.