Windows CI keeps failing (flaky)

[jku]

Windows CI keeps failing (flaky)

[lukpueh]

#542 works around the HSM LoadLibrary() failure, by disabling HSM tests on Windows, AND likely fixes the gpg timeout failures by increasing gpg subprocess timeout (although only time can prove if a flaky test is indeed fixed)

FWIW, I ssh'ed into a runner that had timed out on a gpg test and was able to successfully run the same test manually. This is no prove either, but at least suggests that the failures were actually timeouts.

Let's close here with #542 and open a new ticket that requests re-instating HSM tests on Windows, including an actual fix for the documented problem.

Btw. I briefly considered switching to the SoftHSM2-for-Windows "portable" ZIP archive instead of using the installer from chocolatey, because this is what the author of PyKCS11 uses. But then I saw that they have the same error message in their build logs.

[lukpueh]

Thanks for reporting!

happened on at least python 3.7 and 3.10

I've seen it on 3.9 as well.

[lukpueh]

I hope it's okay to make this a catch all flaky tests on Windows ticket... Here are two more issues:

py: commands[0]> python -m tests.check_gpg_available
F
======================================================================
FAIL: test_gpg_available (__main__.TestGpgAvailable)
Test that GPG is available.
----------------------------------------------------------------------
Traceback (most recent call last):
  File "D:\a\securesystemslib\securesystemslib\tests\check_gpg_available.py", line 39, in test_gpg_available
py: exit 1 ([15](https://github.com/secure-systems-lab/securesystemslib/actions/runs/4281618767/jobs/7454863852#step:6:16).45 seconds) D:\a\securesystemslib\securesystemslib> python -m tests.check_gpg_available pid=2508
    self.assertTrue(securesystemslib.gpg.constants.have_gpg())
AssertionError: False is not true

----------------------------------------------------------------------
Ran 1 test in 10.520s
  py: FAIL code 1 (77.[17](https://github.com/secure-systems-lab/securesystemslib/actions/runs/4281618767/jobs/7454863852#step:6:18)=setup[61.72]+cmd[15.45] seconds)

https://github.com/secure-systems-lab/securesystemslib/actions/runs/4281618767/jobs/7454863852

[lukpueh]

py: commands[2]> coverage run tests/aggregate_tests.py
...............................EExporting master key '8465a1e2e0fb2b40adb2478e18fb3f537e0c8a17' including subkeys '6a112fd3390b2e53afc2e57f8fc8e12099aeceea, c5a0abe6ec19d0d65f85e2c39be9df5131d924e9' for passed keyid 'C5A0ABE6EC19D0D65F85E2C39BE9DF5131D924E9'.
...E................................................s..........................Exporting master key '8465a1e2e0fb2b40adb2478e18fb3f537e0c8a17' including subkeys '6a112fd3390b2e53afc2e57f8fc8e12099aeceea, c5a0abe6ec19d0d65f85e2c39be9df5131d924e9' for passed keyid 'C5A0ABE6EC19D0D65F85E2C39BE9DF5131D924E9'.
...................s............
======================================================================
ERROR: test_create_signature_with_expired_key (tests.test_gpg.TestGPGRSA)
Test signing with expired key raises gpg CommandError.
----------------------------------------------------------------------
Traceback (most recent call last):
  File "D:\a\securesystemslib\securesystemslib\tests\test_gpg.py", line 712, in test_create_signature_with_expired_key
    create_signature(
  File "D:\a\securesystemslib\securesystemslib\securesystemslib\gpg\functions.py", line 129, in create_signature
    gpg_process = subprocess.run(  # nosec
  File "C:\hostedtoolcache\windows\Python\3.10.10\x64\lib\subprocess.py", line 505, in run
    stdout, stderr = process.communicate(input, timeout=timeout)
  File "C:\hostedtoolcache\windows\Python\3.10.10\x64\lib\subprocess.py", line 1154, in communicate
    stdout, stderr = self._communicate(input, endtime, timeout)
  File "C:\hostedtoolcache\windows\Python\3.10.10\x64\lib\subprocess.py", line 1530, in _communicate
    raise TimeoutExpired(self.args, orig_timeout)
subprocess.TimeoutExpired: Command '['gpg', '--detach-sign', '--digest-algo', 'SHA256', '--local-user', 'E8AC80C9[24](https://github.com/secure-systems-lab/securesystemslib/actions/runs/4281618767/jobs/7454864323#step:6:25)116DABB51D4B987CB07D6D2C199C7C', '--homedir', 'rsa']' timed out after 10 seconds

https://github.com/secure-systems-lab/securesystemslib/actions/runs/4281618767/jobs/7454864323

[lukpueh]

I think these two gpg related failures are actually both timeouts, given that have_gpg() also just returns False on timeout. A logging statement would be helpful there.

[jku]

Looking at test runs on main branch, 10-15% currently pass completely, almost 90% fail in one or more windows builds.

Should we (partially?) disable windows tests on CI again if flakiness is at this level?

(unless you're planning to invest time into this in near future -- then it makes sense to log as much as possible)