tahoe-lafs/trac

allmydata.test.test_util.FileUtil.test_disk_stats sometimes fails on Travis #2290

New issue

Closed

opened 2014-09-02 14:50:06 +00:00 by daira · 15 comments

daira commented

2014-09-02 14:50:06 +00:00

(https://travis-ci.org/travis-tahoe/tahoe-lafs/jobs/34190813)

[FAIL]
Traceback (most recent call last):

File "/home/travis/build/travis-tahoe/tahoe-lafs/src/allmydata/test/test_util.py", line 522, in test_disk_stats
  self.failUnless(disk['used'] > 0, disk['used'])

File "/home/travis/virtualenv/python2.6.9/lib/python2.6/site-packages/twisted/trial/_synctest.py", line 308, in assertTrue
  raise self.failureException(msg)

twisted.trial.unittest.FailTest: 0

allmydata.test.test_util.FileUtil.test_disk_stats

I don't understand why this failed on Python 2.6.9 but succeeded (https://travis-ci.org/travis-tahoe/tahoe-lafs/jobs/34190811) on the Python 2.7.8 run of the same build. Also, a previous build with identical source (https://travis-ci.org/travis-tahoe/tahoe-lafs/jobs/34187776) passed on Python 2.6.9.

(Travis isn't enabled yet for the main repo, but this is an identical test repo.)

(https://travis-ci.org/travis-tahoe/tahoe-lafs/jobs/34190813) ``` [FAIL] Traceback (most recent call last): File "/home/travis/build/travis-tahoe/tahoe-lafs/src/allmydata/test/test_util.py", line 522, in test_disk_stats self.failUnless(disk['used'] > 0, disk['used']) File "/home/travis/virtualenv/python2.6.9/lib/python2.6/site-packages/twisted/trial/_synctest.py", line 308, in assertTrue raise self.failureException(msg) twisted.trial.unittest.FailTest: 0 allmydata.test.test_util.FileUtil.test_disk_stats ``` I don't understand why this failed on Python 2.6.9 but succeeded (<https://travis-ci.org/travis-tahoe/tahoe-lafs/jobs/34190811>) on the Python 2.7.8 run of the same build. Also, a previous build with identical source (<https://travis-ci.org/travis-tahoe/tahoe-lafs/jobs/34187776>) passed on Python 2.6.9. (Travis isn't enabled yet for the main repo, but this is an identical test repo.)

daira added the

labels 2014-09-02 14:50:06 +00:00

daira added this to the undecided milestone 2014-09-02 14:50:06 +00:00

warner commented

2014-09-12 16:11:51 +00:00

I caught an instance of this with extra debug prints turned on, to dump the return value from statvfs

https://travis-ci.org/tahoe-lafs/tahoe-lafs/jobs/35096649

allmydata.test.test_util.FileUtil.test_disk_stats ...
 STATVFS posix.statvfs_result(f_bsize=4096, f_frsize=4096, f_blocks=5242880, f_bfree=5242880, f_bavail=5242880, f_files=2621440, f_ffree=2621439, f_favail=2621439, f_flag=4096, f_namemax=255)
 STATVFS posix.statvfs_result(f_bsize=4096, f_frsize=4096, f_blocks=5242880, f_bfree=5242880, f_bavail=5242880, f_files=2621440, f_ffree=2621439, f_favail=2621439, f_flag=4096, f_namemax=255)
 GET_DISK_STATS {'free_for_root': 21474836480, 'avail': 21474828288, 'free_for_nonroot': 21474836480, 'total': 21474836480, 'used': 0}

Traceback (most recent call last):
  File "/home/travis/build/tahoe-lafs/tahoe-lafs/src/allmydata/test/test_util.py", line 523, in test_disk_stats
    self.failUnless(disk['used'] > 0, disk['used'])
  File "/home/travis/virtualenv/python2.6.9/lib/python2.6/site-packages/twisted/trial/_synctest.py", line 308, in assertTrue
    raise self.failureException(msg)
twisted.trial.unittest.FailTest: 0

[FAILURE]

From what I can tell, every call to the os.statvfs in get_disk_stats()
in this particular run returned the same thing.

In the passing test runs, os.statvfs() returns varying values. The 2.7 job that happened on the same git hash got:

allmydata.test.test_util.FileUtil.test_disk_stats ... 
STATVFS posix.statvfs_result(f_bsize=4096, f_frsize=4096, f_blocks=31457280, f_bfree=25937477, f_bavail=25937477, f_files=24741045, f_ffree=24172188, f_favail=24172188, f_flag=4096, f_namemax=255)
STATVFS posix.statvfs_result(f_bsize=4096, f_frsize=4096, f_blocks=31457280, f_bfree=25937477, f_bavail=25937477, f_files=24741045, f_ffree=24172188, f_favail=24172188, f_flag=4096, f_namemax=255)
GET_DISK_STATS {'free_for_root': 106239905792, 'avail': 106239897600, 'free_for_nonroot': 106239905792, 'total': 128849018880, 'used': 22609113088}

I caught an instance of this with extra debug prints turned on, to dump the return value from statvfs <https://travis-ci.org/tahoe-lafs/tahoe-lafs/jobs/35096649> ``` allmydata.test.test_util.FileUtil.test_disk_stats ... STATVFS posix.statvfs_result(f_bsize=4096, f_frsize=4096, f_blocks=5242880, f_bfree=5242880, f_bavail=5242880, f_files=2621440, f_ffree=2621439, f_favail=2621439, f_flag=4096, f_namemax=255) STATVFS posix.statvfs_result(f_bsize=4096, f_frsize=4096, f_blocks=5242880, f_bfree=5242880, f_bavail=5242880, f_files=2621440, f_ffree=2621439, f_favail=2621439, f_flag=4096, f_namemax=255) GET_DISK_STATS {'free_for_root': 21474836480, 'avail': 21474828288, 'free_for_nonroot': 21474836480, 'total': 21474836480, 'used': 0} Traceback (most recent call last): File "/home/travis/build/tahoe-lafs/tahoe-lafs/src/allmydata/test/test_util.py", line 523, in test_disk_stats self.failUnless(disk['used'] > 0, disk['used']) File "/home/travis/virtualenv/python2.6.9/lib/python2.6/site-packages/twisted/trial/_synctest.py", line 308, in assertTrue raise self.failureException(msg) twisted.trial.unittest.FailTest: 0 [FAILURE] ``` From what I can tell, every call to the os.statvfs in get_disk_stats() in this particular run returned the same thing. In the passing test runs, os.statvfs() returns varying values. The 2.7 job that happened on the same git hash got: ``` allmydata.test.test_util.FileUtil.test_disk_stats ... STATVFS posix.statvfs_result(f_bsize=4096, f_frsize=4096, f_blocks=31457280, f_bfree=25937477, f_bavail=25937477, f_files=24741045, f_ffree=24172188, f_favail=24172188, f_flag=4096, f_namemax=255) STATVFS posix.statvfs_result(f_bsize=4096, f_frsize=4096, f_blocks=31457280, f_bfree=25937477, f_bavail=25937477, f_files=24741045, f_ffree=24172188, f_favail=24172188, f_flag=4096, f_namemax=255) GET_DISK_STATS {'free_for_root': 106239905792, 'avail': 106239897600, 'free_for_nonroot': 106239905792, 'total': 128849018880, 'used': 22609113088} ```

warner commented

2014-09-12 19:50:35 +00:00

#2298 was a dup.

After some more investigation, it appears that Travis-CI workers sometimes report fake-looking os.statvfs() values. I've filed an issue to investigate:

https://github.com/travis-ci/travis-ci/issues/2788

On the job that failed, every single os.statvfs() call for the whole 20-minute test suite claimed that the 20 GiB disk was empty (f_bfree == f_blocks). On passing jobs, f_blocks reported a 120 GiB disk (or larger) and the number of free blocks rose and fell over the course of the test run.

My hunch is that some of the travis workers are using a virtual disk that happens to return bogus or simulated data to os.statvfs(). Daira and I decided that it'd be ok to relax this test (to accept disk["used"] >= 0). If the Travis folks find an easy solution, we can tighten the test back up again.

#2298 was a dup. After some more investigation, it appears that Travis-CI workers sometimes report fake-looking `os.statvfs()` values. I've filed an issue to investigate: <https://github.com/travis-ci/travis-ci/issues/2788> On the job that failed, every single `os.statvfs()` call for the whole 20-minute test suite claimed that the 20 GiB disk was empty (`f_bfree == f_blocks`). On passing jobs, f_blocks reported a 120 GiB disk (or larger) and the number of free blocks rose and fell over the course of the test run. My hunch is that some of the travis workers are using a virtual disk that happens to return bogus or simulated data to `os.statvfs()`. Daira and I decided that it'd be ok to relax this test (to accept `disk["used"] >= 0`). If the Travis folks find an easy solution, we can tighten the test back up again.

Brian Warner <warner@lothar.com> commented

2014-09-12 20:00:29 +00:00

Owner

In /tahoe-lafs/trac/commit/38668c9e35a9f27123f05d3726e12263248996e6:

test_disk_stats: tolerate used==0 for a Travis worker bug

Some Travis-CI workers report persistently empty disks, causing spurious
test failures. It's not really that important to assert used>0, so this
relaxes the test.

Closes ticket:2290

In [/tahoe-lafs/trac/commit/38668c9e35a9f27123f05d3726e12263248996e6](/tahoe-lafs/trac/commit/38668c9e35a9f27123f05d3726e12263248996e6): ``` test_disk_stats: tolerate used==0 for a Travis worker bug Some Travis-CI workers report persistently empty disks, causing spurious test failures. It's not really that important to assert used>0, so this relaxes the test. Closes ticket:2290 ```

tahoe-lafs added the

r/fixed

label 2014-09-12 20:00:29 +00:00

Brian Warner <warner@lothar.com> closed this issue

2014-09-12 20:00:29 +00:00

Brian Warner <warner@lothar.com> commented

2014-09-12 20:02:42 +00:00

Owner

In /tahoe-lafs/trac/commit/38668c9e35a9f27123f05d3726e12263248996e6:

test_disk_stats: tolerate used==0 for a Travis worker bug

Some Travis-CI workers report persistently empty disks, causing spurious
test failures. It's not really that important to assert used>0, so this
relaxes the test.

Closes ticket:2290

Brian Warner <warner@lothar.com> commented

2014-09-29 15:46:09 +00:00

Owner

In /tahoe-lafs/trac/commit/e80f0753471948419466ad943d659b2a0f9e91a8:

travis: remove the os.statvfs debug command

According to https://github.com/travis-ci/travis-ci/issues/2788 (which
was WONTFIXED), roughly half the travis-ci buildserver fleet runs off
tmpfs volumes, which have different notions of space-free and space-used
than real filesystems. We've adapted our tests to avoid relying upon
space-used>0, and no longer need this call to investigate the problem.

refs ticket:2290

In [/tahoe-lafs/trac/commit/e80f0753471948419466ad943d659b2a0f9e91a8](/tahoe-lafs/trac/commit/e80f0753471948419466ad943d659b2a0f9e91a8): ``` travis: remove the os.statvfs debug command According to https://github.com/travis-ci/travis-ci/issues/2788 (which was WONTFIXED), roughly half the travis-ci buildserver fleet runs off tmpfs volumes, which have different notions of space-free and space-used than real filesystems. We've adapted our tests to avoid relying upon space-used>0, and no longer need this call to investigate the problem. refs ticket:2290 ```