rnpgp / rnp

RNP: high performance C++ OpenPGP library used by Mozilla Thunderbird
https://www.rnpgp.org
Other
198 stars 55 forks source link

s390x and sparc64 "failures" in s2k_iteration_tuning : ratios < 6 #1439

Closed dkg closed 2 years ago

dkg commented 3 years ago

in the s390x debian build, with #1419 applied, the s2k_iteration_tuning test fails with a ratio of ~1.8:

 15/213 Test  #15: rnp_tests.s2k_iteration_tuning ................................................***Failed    0.51 sec
Note: Google Test filter = rnp_tests.s2k_iteration_tuning
[==========] Running 1 test from 1 test suite.
[----------] Global test environment set-up.
[----------] 1 test from rnp_tests
[ RUN      ] rnp_tests.s2k_iteration_tuning
./src/tests/cipher.cpp:665: Failure
Expected: ((static_cast<double>(iters_100) / iters_10)) > ((6)), actual: 1.82353 vs 6
[pgp_s2k_compute_iters() ./src/lib/crypto/s2k.cpp:178] failed to create hash object
[  FAILED  ] rnp_tests.s2k_iteration_tuning (506 ms)
[----------] 1 test from rnp_tests (506 ms total)

[----------] Global test environment tear-down
[==========] 1 test from 1 test suite ran. (506 ms total)
[  PASSED  ] 0 tests.
[  FAILED  ] 1 test, listed below:
[  FAILED  ] rnp_tests.s2k_iteration_tuning

 1 FAILED TEST

on the sparc64 buildd we see a ratio of ~4.4:

 31/213 Test  #15: rnp_tests.s2k_iteration_tuning ................................................***Failed    0.64 sec
Note: Google Test filter = rnp_tests.s2k_iteration_tuning
[==========] Running 1 test from 1 test suite.
[----------] Global test environment set-up.
[----------] 1 test from rnp_tests
[ RUN      ] rnp_tests.s2k_iteration_tuning
./src/tests/cipher.cpp:665: Failure
Expected: ((static_cast<double>(iters_100) / iters_10)) > ((6)), actual: 4.42857 vs 6
[pgp_s2k_compute_iters() ./src/lib/crypto/s2k.cpp:178] failed to create hash object
[  FAILED  ] rnp_tests.s2k_iteration_tuning (621 ms)
[----------] 1 test from rnp_tests (621 ms total)

[----------] Global test environment tear-down
[==========] 1 test from 1 test suite ran. (621 ms total)
[  PASSED  ] 0 tests.
[  FAILED  ] 1 test, listed below:
[  FAILED  ] rnp_tests.s2k_iteration_tuning

 1 FAILED TEST

I've asked the buildds to retry the package on those architectures, but in previous versions (before #1419 was applied) we also saw repeated failures on them in this tuning test.

It seems possible that something about the tuning calculation is different on these different platforms -- either the hardware does some kind of more intensive parallelism, or the particular build daemons used are under heavy, jittery load.

I really appreciate that y'all have this test in place -- it's the right way to validate any assumptions that the code makes about s2k tuning.

If y'all have any thoughts or suggestions about what to do about this, i'm open to them.

dkg commented 3 years ago

it's also possible that given the limits of the range of s2k iterations, and the power of modern hardware, that we just want to ignore the tuning and always turn it up to the maximum.

ni4 commented 3 years ago

pgp_s2k_compute_iters() uses :gettimeofday(), and quick reading tells that it's not the best solution. Looks like we should switch to the clock_gettime at some point. Periodically it fails on macOS CI builds as well.

dkg commented 2 years ago

This is still happening with 0.15.2 on s390x on debian.

Do you have a suggestion about how to disable or skip this test on that architecture? I'd like to clear up the problem so that the package can (finally) migrate into debian testing.

here's the relevant snippet from the s390x build logs:

test 15
        Start  15: rnp_tests.s2k_iteration_tuning

15: Test command: /&lt;&lt;PKGBUILDDIR&gt;&gt;/build/src/tests/rnp_tests &quot;--gtest_filter=rnp_tests.s2k_iteration_tuning&quot; &quot;--gtest_also_run_disabled_tests&quot;
15: Environment variables: 
15:  RNP_TEST_DATA=/&lt;&lt;PKGBUILDDIR&gt;&gt;/src/tests/data
15: Test timeout computed to be: 3000
15: Note: Google Test filter = rnp_tests.s2k_iteration_tuning
15: [==========] Running 1 test from 1 test suite.
15: [----------] Global test environment set-up.
15: [----------] 1 test from rnp_tests
15: [ RUN      ] rnp_tests.s2k_iteration_tuning
15: ./src/tests/cipher.cpp:634: Failure
15: Expected: ((static_cast&lt;double&gt;(iters_100) / iters_10)) &gt; ((6)), actual: 1.82353 vs 6
15: [pgp_s2k_compute_iters() ./src/lib/crypto/s2k.cpp:162] failed to create hash object
15: [  FAILED  ] rnp_tests.s2k_iteration_tuning (506 ms)
15: [----------] 1 test from rnp_tests (506 ms total)
15: 
15: [----------] Global test environment tear-down
15: [==========] 1 test from 1 test suite ran. (507 ms total)
15: [  PASSED  ] 0 tests.
15: [  FAILED  ] 1 test, listed below:
15: [  FAILED  ] rnp_tests.s2k_iteration_tuning
15: 
15:  1 FAILED TEST
 15/227 Test  #15: rnp_tests.s2k_iteration_tuning ................................................***Failed    0.51 sec
Note: Google Test filter = rnp_tests.s2k_iteration_tuning
[==========] Running 1 test from 1 test suite.
[----------] Global test environment set-up.
[----------] 1 test from rnp_tests
[ RUN      ] rnp_tests.s2k_iteration_tuning
./src/tests/cipher.cpp:634: Failure
Expected: ((static_cast&lt;double&gt;(iters_100) / iters_10)) &gt; ((6)), actual: 1.82353 vs 6
[pgp_s2k_compute_iters() ./src/lib/crypto/s2k.cpp:162] failed to create hash object
[  FAILED  ] rnp_tests.s2k_iteration_tuning (506 ms)
[----------] 1 test from rnp_tests (506 ms total)

[----------] Global test environment tear-down
[==========] 1 test from 1 test suite ran. (507 ms total)
[  PASSED  ] 0 tests.
[  FAILED  ] 1 test, listed below:
[  FAILED  ] rnp_tests.s2k_iteration_tuning

 1 FAILED TEST