Various non-deterministic test failures

[estebandf]

2. Test shows the following error:

tests/t5_cache.py::TestPerstCache::test_cache_flush[True] FAILED                                                                                                                                           [ 87%]

==================================================================================================== FAILURES ====================================================================================================
_____________________________________________________________________________________ TestPerstCache.test_cache_flush[True] ______________________________________________________________________________________
Traceback (most recent call last):
  File "/usr/src/s3ql-3.1/tests/t5_cache.py", line 120, in test_cache_flush
    self.fsck(args=['--keep-cache'])
  File "/usr/src/s3ql-3.1/tests/t4_fuse.py", line 128, in fsck
    assert proc.wait() == expect_retcode
AssertionError: assert 128 == 0
  -128
  +0
---------------------------------------------------------------------------------------------- Captured stdout call ----------------------------------------------------------------------------------------------
Please store the following master key in a safe location. It allows 
decryption of the S3QL file system in case the storage objects holding 
this information get corrupted:
---BEGIN MASTER KEY---
dQow xSHp ZzBW QHpF bcRj xjo0 yBVP qw36 gxtI Dr9L vZ0=
---END MASTER KEY---
---------------------------------------------------------------------------------------------- Captured stderr call ----------------------------------------------------------------------------------------------
WARNING: Maximum object sizes less than 1 MiB will degrade performance.
WARNING: Deleted spurious object 2
================================================================================ 1 failed, 297 passed, 5 skipped in 57.66 seconds ================================================================================

3. Succesive test runs show different errors:

tests/t5_cache.py::TestPerstCache::test_cache_flush[True] FAILED                                                                                                                                           [ 87%]

==================================================================================================== FAILURES ====================================================================================================
_____________________________________________________________________________________ TestPerstCache.test_cache_flush[True] ______________________________________________________________________________________
Traceback (most recent call last):
  File "/usr/src/s3ql-3.1/tests/t5_cache.py", line 123, in test_cache_flush
    assert fh.read() == TEST_DATA
AssertionError: assert b'\n)(tnuomu....ne/nib/rsu/!#' == b'#!/usr/bin/e...lf.umount()\n'
  At index 0 diff: 10 != 35
  Full diff:
  - (b'\n)(tnuomu.fles        \nATAD_TSET == )(daer.hf tressa            \n:hf sa '
  -  b")'br' ,)'eliftset' ,rid_tnm.fles(niojp(nepo htiw        \n)(tnuom.fles   "
  -  b"     \n)]'ehcac-peek--' ,'etomer-ecrof--'[=sgra                  \n,0=edoc"
  -  b'ter_tcepxe(kcsf.fles        \nderongi si ehcac taht erus ekaM #        \n\n'
  -  b'kab = rid_ehcac.fles            \n)rid_ehcac.fles(eertmr.lituhs          '...
  
  ...Full output truncated (154 lines hidden), use '-vv' to show
---------------------------------------------------------------------------------------------- Captured stdout call ----------------------------------------------------------------------------------------------
Please store the following master key in a safe location. It allows 
decryption of the S3QL file system in case the storage objects holding 
this information get corrupted:
---BEGIN MASTER KEY---
kYom jZq7 2fqs M8RY wXe4 QC4Y NJmR Yc2E SHxJ J7Dl 7NI=
---END MASTER KEY---
---------------------------------------------------------------------------------------------- Captured stderr call ----------------------------------------------------------------------------------------------
WARNING: Maximum object sizes less than 1 MiB will degrade performance.
================================================================================ 1 failed, 297 passed, 5 skipped in 58.27 seconds ================================================================================

Next run:

tests/t5_failsafe.py::TestNewerMetadata::test FAILED                                                                                                                                                       [ 89%]
tests/t5_failsafe.py::TestNewerMetadata::test ERROR                                                                                                                                                        [ 89%]

===================================================================================================== ERRORS =====================================================================================================
__________________________________________________________________________________ ERROR at teardown of TestNewerMetadata.test ___________________________________________________________________________________
Traceback (most recent call last):
  File "/usr/src/s3ql-3.1/tests/pytest_checklogs.py", line 143, in pytest_runtest_teardown
    check_output(item)
  File "/usr/src/s3ql-3.1/tests/pytest_checklogs.py", line 132, in check_output
    check_test_output(capmethod, item)
  File "/usr/src/s3ql-3.1/tests/pytest_checklogs.py", line 106, in check_test_output
    raise AssertionError('Suspicious output to stderr (matched "%s")' % hit.group(0))
AssertionError: Suspicious output to stderr (matched "ERROR")
---------------------------------------------------------------------------------------------- Captured stdout call ----------------------------------------------------------------------------------------------
Please store the following master key in a safe location. It allows 
decryption of the S3QL file system in case the storage objects holding 
this information get corrupted:
---BEGIN MASTER KEY---
sp0w ux24 JwJ+ XlRW WHKT lhfW YUH9 /74h hbqg 9tES FeE=
---END MASTER KEY---
---------------------------------------------------------------------------------------------- Captured stderr call ----------------------------------------------------------------------------------------------
WARNING: Maximum object sizes less than 1 MiB will degrade performance.
-------------------------------------------------------------------------------------------- Captured stderr teardown --------------------------------------------------------------------------------------------
ERROR: Remote metadata is newer than local (1555031773 vs 1555031772), refusing to overwrite!
ERROR: The locally cached metadata will be *lost* the next time the file system is mounted or checked and has therefore been backed up.
==================================================================================================== FAILURES ====================================================================================================
_____________________________________________________________________________________________ TestNewerMetadata.test _____________________________________________________________________________________________
Traceback (most recent call last):
  File "/usr/src/s3ql-3.1/tests/t5_failsafe.py", line 143, in test
    time.sleep(1)
  File "/usr/local/lib/python3.6/site-packages/_pytest/python_api.py", line 729, in __exit__
    fail(self.message)
  File "/usr/local/lib/python3.6/site-packages/_pytest/outcomes.py", line 117, in fail
    raise Failed(msg=msg, pytrace=pytrace)
Failed: DID NOT RAISE <class 'PermissionError'>
---------------------------------------------------------------------------------------------- Captured stdout call ----------------------------------------------------------------------------------------------
Please store the following master key in a safe location. It allows 
decryption of the S3QL file system in case the storage objects holding 
this information get corrupted:
---BEGIN MASTER KEY---
sp0w ux24 JwJ+ XlRW WHKT lhfW YUH9 /74h hbqg 9tES FeE=
---END MASTER KEY---
---------------------------------------------------------------------------------------------- Captured stderr call ----------------------------------------------------------------------------------------------
WARNING: Maximum object sizes less than 1 MiB will degrade performance.
=========================================================================== 1 failed, 302 passed, 6 skipped, 1 error in 88.13 seconds ============================================================================

Next run:

tests/t5_cache.py::TestPerstCache::test_cache_flush_unclean FAILED                                                                                                                                         [ 88%]

==================================================================================================== FAILURES ====================================================================================================
____________________________________________________________________________________ TestPerstCache.test_cache_flush_unclean _____________________________________________________________________________________
Traceback (most recent call last):
  File "/usr/src/s3ql-3.1/tests/t5_cache.py", line 161, in test_cache_flush_unclean
    args=['--force-remote'])
  File "/usr/src/s3ql-3.1/tests/t4_fuse.py", line 128, in fsck
    assert proc.wait() == expect_retcode
AssertionError: assert 128 == 0
  -128
  +0
---------------------------------------------------------------------------------------------- Captured stdout call ----------------------------------------------------------------------------------------------
Please store the following master key in a safe location. It allows 
decryption of the S3QL file system in case the storage objects holding 
this information get corrupted:
---BEGIN MASTER KEY---
/r2k e8L/ 2SUJ 43O8 wSyw 6A3e QtJH ow3u Myr2 T4eI D40=
---END MASTER KEY---
Backend reports that file system is still mounted elsewhere. Either
the file system has not been unmounted cleanly or the data has not yet
propagated through the backend. In the later case, waiting for a while
should fix the problem, in the former case you should try to run fsck
on the computer where the file system has been mounted most recently.
You may also continue and use whatever metadata is available in the
backend. However, in that case YOU MAY LOOSE ALL DATA THAT HAS BEEN
UPLOADED OR MODIFIED SINCE THE LAST SUCCESSFULL METADATA UPLOAD.
Moreover, files and directories that you have deleted since then MAY
REAPPEAR WITH SOME OF THEIR CONTENT LOST.
Enter "continue, I know what I am doing" to use the outdated data anyway:
> (--force-remote specified, continuing anyway)
---------------------------------------------------------------------------------------------- Captured stderr call ----------------------------------------------------------------------------------------------
WARNING: Maximum object sizes less than 1 MiB will degrade performance.
WARNING: Deleted spurious object 1
================================================================================ 1 failed, 299 passed, 5 skipped in 68.40 seconds ================================================================================

[Nikratio]

Thanks for the report! I'm somewhat at a loss here. It seems you consistently get errors on just one system (based on your ML post), but not the same error, nor has anyone else seen such errors.

[Nikratio]

Are you still able to reproduce this issue?

[d--j]

I'm closing this since the test failures are sporadic and not really reproducible (and maybe gone anyway?).

Feel free to re-open when you have more information on how we can reproduce the issue.