Bug #13300
LibRadosTwoPoolsPP tests failing in firefly-backports
0%
Description
While testing the most recent firefly integration branch, ran into the following test failure:
http://pulpito.ceph.com/smithfarm-2015-09-29_02:24:57-ceph-deploy-firefly-backports---basic-vps/
The failure is reproducible by re-running the test. Log excerpt:
09-29T09:22:31.618 INFO:tasks.workunit.client.0.vpm168.stdout:waiting for scrub... 2015-09-29T09:22:46.619 INFO:tasks.workunit.client.0.vpm168.stdout:done waiting 2015-09-29T09:22:48.006 INFO:tasks.workunit.client.0.vpm168.stdout:[ OK ] LibRadosTwoPoolsECPP.PromoteSnap (20588 ms) 2015-09-29T09:22:48.006 INFO:tasks.workunit.client.0.vpm168.stdout:[ RUN ] LibRadosTwoPoolsECPP.PromoteSnapTrimRace 2015-09-29T09:22:49.016 INFO:tasks.workunit.client.0.vpm168.stdout:test/librados/tier.cc:2657: Failure 2015-09-29T09:22:49.016 INFO:tasks.workunit.client.0.vpm168.stdout:Value of: cluster.mon_command( "{\"prefix\": \"osd tier add\", \"pool\": \"" + pool_name + "\", \"tierpool\": \"" + cache_pool_name + "\", \"force_nonempty\": \"--force-nonempty\" }", inbl, __null, __null) 2015-09-29T09:22:49.016 INFO:tasks.workunit.client.0.vpm168.stdout: Actual: -39 2015-09-29T09:22:49.016 INFO:tasks.workunit.client.0.vpm168.stdout:Expected: 0 2015-09-29T09:22:49.103 INFO:tasks.workunit.client.0.vpm168.stdout:[ FAILED ] LibRadosTwoPoolsECPP.PromoteSnapTrimRace (1096 ms) 2015-09-29T09:22:49.103 INFO:tasks.workunit.client.0.vpm168.stdout:[ RUN ] LibRadosTwoPoolsECPP.Whiteout 2015-09-29T09:22:49.115 INFO:tasks.workunit.client.0.vpm168.stdout:test/librados/tier.cc:2698: Failure 2015-09-29T09:22:49.115 INFO:tasks.workunit.client.0.vpm168.stdout:Value of: cluster.mon_command( "{\"prefix\": \"osd tier add\", \"pool\": \"" + pool_name + "\", \"tierpool\": \"" + cache_pool_name + "\", \"force_nonempty\": \"--force-nonempty\" }", inbl, __null, __null) 2015-09-29T09:22:49.116 INFO:tasks.workunit.client.0.vpm168.stdout: Actual: -39 2015-09-29T09:22:49.116 INFO:tasks.workunit.client.0.vpm168.stdout:Expected: 0 2015-09-29T09:22:49.157 INFO:tasks.workunit.client.0.vpm168.stdout:[ FAILED ] LibRadosTwoPoolsECPP.Whiteout (54 ms) 2015-09-29T09:22:49.157 INFO:tasks.workunit.client.0.vpm168.stdout:[ RUN ] LibRadosTwoPoolsECPP.Evict 2015-09-29T09:22:49.169 INFO:tasks.workunit.client.0.vpm168.stdout:test/librados/tier.cc:2761: Failure 2015-09-29T09:22:49.170 INFO:tasks.workunit.client.0.vpm168.stdout:Value of: cluster.mon_command( "{\"prefix\": \"osd tier add\", \"pool\": \"" + pool_name + "\", \"tierpool\": \"" + cache_pool_name + "\", \"force_nonempty\": \"--force-nonempty\" }", inbl, __null, __null) 2015-09-29T09:22:49.170 INFO:tasks.workunit.client.0.vpm168.stdout: Actual: -39 2015-09-29T09:22:49.170 INFO:tasks.workunit.client.0.vpm168.stdout:Expected: 0 2015-09-29T09:22:49.210 INFO:tasks.workunit.client.0.vpm168.stdout:[ FAILED ] LibRadosTwoPoolsECPP.Evict (53 ms) 2015-09-29T09:22:49.210 INFO:tasks.workunit.client.0.vpm168.stdout:[ RUN ] LibRadosTwoPoolsECPP.EvictSnap 2015-09-29T09:22:50.161 INFO:tasks.workunit.client.0.vpm168.stdout:test/librados/tier.cc:2904: Failure 2015-09-29T09:22:50.161 INFO:tasks.workunit.client.0.vpm168.stdout:Value of: cluster.mon_command( "{\"prefix\": \"osd tier add\", \"pool\": \"" + pool_name + "\", \"tierpool\": \"" + cache_pool_name + "\", \"force_nonempty\": \"--force-nonempty\" }", inbl, __null, __null) 2015-09-29T09:22:50.161 INFO:tasks.workunit.client.0.vpm168.stdout: Actual: -39 2015-09-29T09:22:50.161 INFO:tasks.workunit.client.0.vpm168.stdout:Expected: 0 2015-09-29T09:22:50.211 INFO:tasks.workunit.client.0.vpm168.stdout:[ FAILED ] LibRadosTwoPoolsECPP.EvictSnap (1000 ms) 2015-09-29T09:22:50.211 INFO:tasks.workunit.client.0.vpm168.stdout:[ RUN ] LibRadosTwoPoolsECPP.TryFlush 2015-09-29T09:22:50.212 INFO:tasks.workunit.client.0.vpm168.stdout:test/librados/tier.cc:3077: Failure 2015-09-29T09:22:50.213 INFO:tasks.workunit.client.0.vpm168.stdout:Value of: cluster.mon_command( "{\"prefix\": \"osd tier add\", \"pool\": \"" + pool_name + "\", \"tierpool\": \"" + cache_pool_name + "\", \"force_nonempty\": \"--force-nonempty\" }", inbl, __null, __null) 2015-09-29T09:22:50.213 INFO:tasks.workunit.client.0.vpm168.stdout: Actual: -39 2015-09-29T09:22:50.213 INFO:tasks.workunit.client.0.vpm168.stdout:Expected: 0 2015-09-29T09:22:50.266 INFO:tasks.workunit.client.0.vpm168.stdout:[ FAILED ] LibRadosTwoPoolsECPP.TryFlush (55 ms) 2015-09-29T09:22:50.266 INFO:tasks.workunit.client.0.vpm168.stdout:[ RUN ] LibRadosTwoPoolsECPP.Flush 2015-09-29T09:22:50.267 INFO:tasks.workunit.client.0.vpm168.stdout:test/librados/tier.cc:3185: Failure 2015-09-29T09:22:50.267 INFO:tasks.workunit.client.0.vpm168.stdout:Value of: cluster.mon_command( "{\"prefix\": \"osd tier add\", \"pool\": \"" + pool_name + "\", \"tierpool\": \"" + cache_pool_name + "\", \"force_nonempty\": \"--force-nonempty\" }", inbl, __null, __null) 2015-09-29T09:22:50.268 INFO:tasks.workunit.client.0.vpm168.stdout: Actual: -39 2015-09-29T09:22:50.268 INFO:tasks.workunit.client.0.vpm168.stdout:Expected: 0 2015-09-29T09:22:50.312 INFO:tasks.workunit.client.0.vpm168.stdout:[ FAILED ] LibRadosTwoPoolsECPP.Flush (46 ms) 2015-09-29T09:22:50.312 INFO:tasks.workunit.client.0.vpm168.stdout:[ RUN ] LibRadosTwoPoolsECPP.FlushSnap 2015-09-29T09:22:50.314 INFO:tasks.workunit.client.0.vpm168.stdout:test/librados/tier.cc:3345: Failure 2015-09-29T09:22:50.314 INFO:tasks.workunit.client.0.vpm168.stdout:Value of: cluster.mon_command( "{\"prefix\": \"osd tier add\", \"pool\": \"" + pool_name + "\", \"tierpool\": \"" + cache_pool_name + "\", \"force_nonempty\": \"--force-nonempty\" }", inbl, __null, __null) 2015-09-29T09:22:50.314 INFO:tasks.workunit.client.0.vpm168.stdout: Actual: -39 2015-09-29T09:22:50.314 INFO:tasks.workunit.client.0.vpm168.stdout:Expected: 0 2015-09-29T09:22:50.359 INFO:tasks.workunit.client.0.vpm168.stdout:[ FAILED ] LibRadosTwoPoolsECPP.FlushSnap (47 ms) 2015-09-29T09:22:50.359 INFO:tasks.workunit.client.0.vpm168.stdout:[ RUN ] LibRadosTwoPoolsECPP.FlushTryFlushRaces 2015-09-29T09:22:50.360 INFO:tasks.workunit.client.0.vpm168.stdout:test/librados/tier.cc:3655: Failure 2015-09-29T09:22:50.361 INFO:tasks.workunit.client.0.vpm168.stdout:Value of: cluster.mon_command( "{\"prefix\": \"osd tier add\", \"pool\": \"" + pool_name + "\", \"tierpool\": \"" + cache_pool_name + "\", \"force_nonempty\": \"--force-nonempty\" }", inbl, __null, __null) 2015-09-29T09:22:50.361 INFO:tasks.workunit.client.0.vpm168.stdout: Actual: -39 2015-09-29T09:22:50.361 INFO:tasks.workunit.client.0.vpm168.stdout:Expected: 0 2015-09-29T09:22:50.401 INFO:tasks.workunit.client.0.vpm168.stdout:[ FAILED ] LibRadosTwoPoolsECPP.FlushTryFlushRaces (42 ms) 2015-09-29T09:22:50.402 INFO:tasks.workunit.client.0.vpm168.stdout:[ RUN ] LibRadosTwoPoolsECPP.TryFlushReadRace 2015-09-29T09:22:50.403 INFO:tasks.workunit.client.0.vpm168.stdout:test/librados/tier.cc:3821: Failure 2015-09-29T09:22:50.403 INFO:tasks.workunit.client.0.vpm168.stdout:Value of: cluster.mon_command( "{\"prefix\": \"osd tier add\", \"pool\": \"" + pool_name + "\", \"tierpool\": \"" + cache_pool_name + "\", \"force_nonempty\": \"--force-nonempty\" }", inbl, __null, __null) 2015-09-29T09:22:50.403 INFO:tasks.workunit.client.0.vpm168.stdout: Actual: -39 2015-09-29T09:22:50.403 INFO:tasks.workunit.client.0.vpm168.stdout:Expected: 0 2015-09-29T09:22:50.445 INFO:tasks.workunit.client.0.vpm168.stdout:[ FAILED ] LibRadosTwoPoolsECPP.TryFlushReadRace (44 ms) 2015-09-29T09:22:50.445 INFO:tasks.workunit.client.0.vpm168.stdout:[ RUN ] LibRadosTwoPoolsECPP.HitSetRead 2015-09-29T09:22:50.446 INFO:tasks.workunit.client.0.vpm168.stdout:test/librados/tier.cc:3903: Failure 2015-09-29T09:22:50.447 INFO:tasks.workunit.client.0.vpm168.stdout:Value of: cluster.mon_command( "{\"prefix\": \"osd tier add\", \"pool\": \"" + pool_name + "\", \"tierpool\": \"" + cache_pool_name + "\", \"force_nonempty\": \"--force-nonempty\" }", inbl, __null, __null) 2015-09-29T09:22:50.447 INFO:tasks.workunit.client.0.vpm168.stdout: Actual: -39 2015-09-29T09:22:50.447 INFO:tasks.workunit.client.0.vpm168.stdout:Expected: 0 2015-09-29T09:22:50.488 INFO:tasks.workunit.client.0.vpm168.stdout:[ FAILED ] LibRadosTwoPoolsECPP.HitSetRead (42 ms) 2015-09-29T09:22:50.488 INFO:tasks.workunit.client.0.vpm168.stdout:[ RUN ] LibRadosTwoPoolsECPP.HitSetTrim 2015-09-29T09:22:50.489 INFO:tasks.workunit.client.0.vpm168.stdout:test/librados/tier.cc:4044: Failure 2015-09-29T09:22:50.489 INFO:tasks.workunit.client.0.vpm168.stdout:Value of: cluster.mon_command( "{\"prefix\": \"osd tier add\", \"pool\": \"" + pool_name + "\", \"tierpool\": \"" + cache_pool_name + "\", \"force_nonempty\": \"--force-nonempty\" }", inbl, __null, __null) 2015-09-29T09:22:50.490 INFO:tasks.workunit.client.0.vpm168.stdout: Actual: -39 2015-09-29T09:22:50.490 INFO:tasks.workunit.client.0.vpm168.stdout:Expected: 0 2015-09-29T09:22:50.530 INFO:tasks.workunit.client.0.vpm168.stdout:[ FAILED ] LibRadosTwoPoolsECPP.HitSetTrim (42 ms) 2015-09-29T09:22:50.531 INFO:tasks.workunit.client.0.vpm168.stdout:[ RUN ] LibRadosTwoPoolsECPP.PromoteOn2ndRead 2015-09-29T09:22:50.545 INFO:tasks.workunit.client.0.vpm168.stdout:test/librados/tier.cc:4123: Failure 2015-09-29T09:22:50.545 INFO:tasks.workunit.client.0.vpm168.stdout:Value of: cluster.mon_command( "{\"prefix\": \"osd tier add\", \"pool\": \"" + pool_name + "\", \"tierpool\": \"" + cache_pool_name + "\", \"force_nonempty\": \"--force-nonempty\" }", inbl, __null, __null) 2015-09-29T09:22:50.545 INFO:tasks.workunit.client.0.vpm168.stdout: Actual: -39 2015-09-29T09:22:50.545 INFO:tasks.workunit.client.0.vpm168.stdout:Expected: 0 2015-09-29T09:22:50.584 INFO:tasks.workunit.client.0.vpm168.stdout:[ FAILED ] LibRadosTwoPoolsECPP.PromoteOn2ndRead (54 ms) 2015-09-29T09:22:53.308 INFO:tasks.workunit.client.0.vpm168.stdout:[----------] 15 tests from LibRadosTwoPoolsECPP (34490 ms total) 2015-09-29T09:22:53.308 INFO:tasks.workunit.client.0.vpm168.stdout: 2015-09-29T09:22:53.308 INFO:tasks.workunit.client.0.vpm168.stdout:[----------] Global test environment tear-down 2015-09-29T09:22:53.308 INFO:tasks.workunit.client.0.vpm168.stdout:[==========] 39 tests from 4 test cases ran. (102204 ms total) 2015-09-29T09:22:53.309 INFO:tasks.workunit.client.0.vpm168.stdout:[ PASSED ] 12 tests. 2015-09-29T09:22:53.309 INFO:tasks.workunit.client.0.vpm168.stdout:[ FAILED ] 27 tests, listed below: 2015-09-29T09:22:53.309 INFO:tasks.workunit.client.0.vpm168.stdout:[ FAILED ] LibRadosTwoPoolsPP.PromoteSnapScrub 2015-09-29T09:22:53.310 INFO:tasks.workunit.client.0.vpm168.stdout:[ FAILED ] LibRadosTwoPoolsPP.PromoteSnapTrimRace 2015-09-29T09:22:53.310 INFO:tasks.workunit.client.0.vpm168.stdout:[ FAILED ] LibRadosTwoPoolsPP.Whiteout 2015-09-29T09:22:53.310 INFO:tasks.workunit.client.0.vpm168.stdout:[ FAILED ] LibRadosTwoPoolsPP.Evict 2015-09-29T09:22:53.310 INFO:tasks.workunit.client.0.vpm168.stdout:[ FAILED ] LibRadosTwoPoolsPP.EvictSnap 2015-09-29T09:22:53.311 INFO:tasks.workunit.client.0.vpm168.stdout:[ FAILED ] LibRadosTwoPoolsPP.EvictSnap2 2015-09-29T09:22:53.311 INFO:tasks.workunit.client.0.vpm168.stdout:[ FAILED ] LibRadosTwoPoolsPP.TryFlush 2015-09-29T09:22:53.311 INFO:tasks.workunit.client.0.vpm168.stdout:[ FAILED ] LibRadosTwoPoolsPP.Flush 2015-09-29T09:22:53.311 INFO:tasks.workunit.client.0.vpm168.stdout:[ FAILED ] LibRadosTwoPoolsPP.FlushSnap 2015-09-29T09:22:53.311 INFO:tasks.workunit.client.0.vpm168.stdout:[ FAILED ] LibRadosTwoPoolsPP.FlushTryFlushRaces 2015-09-29T09:22:53.312 INFO:tasks.workunit.client.0.vpm168.stdout:[ FAILED ] LibRadosTwoPoolsPP.TryFlushReadRace 2015-09-29T09:22:53.312 INFO:tasks.workunit.client.0.vpm168.stdout:[ FAILED ] LibRadosTwoPoolsPP.HitSetRead 2015-09-29T09:22:53.312 INFO:tasks.workunit.client.0.vpm168.stdout:[ FAILED ] LibRadosTwoPoolsPP.HitSetWrite 2015-09-29T09:22:53.312 INFO:tasks.workunit.client.0.vpm168.stdout:[ FAILED ] LibRadosTwoPoolsPP.HitSetTrim 2015-09-29T09:22:53.313 INFO:tasks.workunit.client.0.vpm168.stdout:[ FAILED ] LibRadosTwoPoolsPP.PromoteOn2ndRead 2015-09-29T09:22:53.313 INFO:tasks.workunit.client.0.vpm168.stdout:[ FAILED ] LibRadosTwoPoolsECPP.PromoteSnapTrimRace 2015-09-29T09:22:53.313 INFO:tasks.workunit.client.0.vpm168.stdout:[ FAILED ] LibRadosTwoPoolsECPP.Whiteout 2015-09-29T09:22:53.313 INFO:tasks.workunit.client.0.vpm168.stdout:[ FAILED ] LibRadosTwoPoolsECPP.Evict 2015-09-29T09:22:53.314 INFO:tasks.workunit.client.0.vpm168.stdout:[ FAILED ] LibRadosTwoPoolsECPP.EvictSnap 2015-09-29T09:22:53.314 INFO:tasks.workunit.client.0.vpm168.stdout:[ FAILED ] LibRadosTwoPoolsECPP.TryFlush 2015-09-29T09:22:53.314 INFO:tasks.workunit.client.0.vpm168.stdout:[ FAILED ] LibRadosTwoPoolsECPP.Flush 2015-09-29T09:22:53.314 INFO:tasks.workunit.client.0.vpm168.stdout:[ FAILED ] LibRadosTwoPoolsECPP.FlushSnap 2015-09-29T09:22:53.314 INFO:tasks.workunit.client.0.vpm168.stdout:[ FAILED ] LibRadosTwoPoolsECPP.FlushTryFlushRaces 2015-09-29T09:22:53.315 INFO:tasks.workunit.client.0.vpm168.stdout:[ FAILED ] LibRadosTwoPoolsECPP.TryFlushReadRace 2015-09-29T09:22:53.315 INFO:tasks.workunit.client.0.vpm168.stdout:[ FAILED ] LibRadosTwoPoolsECPP.HitSetRead 2015-09-29T09:22:53.315 INFO:tasks.workunit.client.0.vpm168.stdout:[ FAILED ] LibRadosTwoPoolsECPP.HitSetTrim 2015-09-29T09:22:53.315 INFO:tasks.workunit.client.0.vpm168.stdout:[ FAILED ] LibRadosTwoPoolsECPP.PromoteOn2ndRead 2015-09-29T09:22:53.315 INFO:tasks.workunit.client.0.vpm168.stdout: 2015-09-29T09:22:53.316 INFO:tasks.workunit.client.0.vpm168.stdout:27 FAILED TESTS 2015-09-29T09:22:53.317 INFO:tasks.workunit:Stopping rados/test.sh on client.0... 2015-09-29T09:22:53.317 INFO:teuthology.orchestra.run.vpm168:Running: 'rm -rf -- /home/ubuntu/cephtest/workunits.list /home/ubuntu/cephtest/workunit.client.0' 2015-09-29T09:22:53.335 ERROR:teuthology.parallel:Exception in parallel execution Traceback (most recent call last): File "/home/teuthworker/src/teuthology_master/teuthology/parallel.py", line 82, in __exit__ for result in self: File "/home/teuthworker/src/teuthology_master/teuthology/parallel.py", line 101, in next resurrect_traceback(result) File "/home/teuthworker/src/teuthology_master/teuthology/parallel.py", line 19, in capture_traceback return func(*args, **kwargs) File "/var/lib/teuthworker/src/ceph-qa-suite_firefly/tasks/workunit.py", line 361, in _run_tests label="workunit test {workunit}".format(workunit=workunit) File "/home/teuthworker/src/teuthology_master/teuthology/orchestra/remote.py", line 156, in run r = self._runner(client=self.ssh, name=self.shortname, **kwargs) File "/home/teuthworker/src/teuthology_master/teuthology/orchestra/run.py", line 378, in run r.wait() File "/home/teuthworker/src/teuthology_master/teuthology/orchestra/run.py", line 114, in wait label=self.label) CommandFailedError: Command failed (workunit test rados/test.sh) on vpm168 with status 1: 'mkdir -p -- /home/ubuntu/cephtest/mnt.0/client.0/tmp && cd -- /home/ubuntu/cephtest/mnt.0/client.0/tmp && CEPH_CLI_TEST_DUP_COMMAND=1 CEPH_REF=b2162f4681967442d5f9a1f1d08c7babda212a1b TESTDIR="/home/ubuntu/cephtest" CEPH_ID="0" PATH=$PATH:/usr/sbin adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage timeout 3h /home/ubuntu/cephtest/workunit.client.0/rados/test.sh' 2015-09-29T09:22:53.380 ERROR:teuthology.run_tasks:Saw exception from tasks.
Related issues
History
#1 Updated by Nathan Cutler over 8 years ago
We have backported the fix for #10052, which looks like it could be related, but this particular backport is not yet in the integration branch: https://github.com/ceph/ceph/pull/5050
#2 Updated by Loïc Dachary over 8 years ago
#define ENOTEMPTY 39 /* Directory not empty */
#3 Updated by Nathan Cutler over 8 years ago
How to reproduce:
$ filter='ceph-deploy/rados/{distros/ubuntu_14.04.yaml tasks/rados_api_tests.yaml}' $ ./virtualenv/bin/teuthology-suite --machine-type vps --suite ceph-deploy --suite-branch firefly --ceph firefly-backports --filter="$filter" --email $YOUR_EMAIL_ADDRESS
#4 Updated by Loïc Dachary over 8 years ago
filter='ceph-deploy/rados/{distros/ubuntu_14.04.yaml tasks/rados_api_tests.yaml}' ; ./virtualenv/bin/teuthology-suite --machine-type vps --suite ceph-deploy --suite-branch firefly --ceph firefly --filter="$filter" --email loic@dachary.org
#5 Updated by Nathan Cutler over 8 years ago
- Subject changed from ceph-deploy-firefly-backports---basic-vps: LibRadosTwoPoolsPP tests failing to LibRadosTwoPoolsPP tests failing in firefly-backports
Not unsurprisingly, it's happening in the rados suite, too.
#6 Updated by Nathan Cutler over 8 years ago
- Assignee set to Loïc Dachary
#7 Updated by Loïc Dachary over 8 years ago
- Status changed from New to 12
#8 Updated by Loïc Dachary over 8 years ago
Following https://github.com/ceph/ceph/pull/5236, the test probably need to be adjusted as well.
#9 Updated by Loïc Dachary over 8 years ago
- Related to Bug #13570: "[ FAILED ] LibRadosTwoPoolsECPP.Whiteout" in upgrade:dumpling-firefly-x-giant-distro-basic-vps added
#10 Updated by Yuri Weinstein over 8 years ago
During QE validation of v0.80.11
Run: http://pulpito.ceph.com/teuthology-2015-10-24_18:18:02-upgrade:firefly-x-giant-distro-basic-vps/
Jobs: 56 jobs
#11 Updated by Loïc Dachary over 8 years ago
https://github.com/ceph/ceph/pull/5389 has been backported without the commit 58e6266 from https://github.com/ceph/ceph/pull/4961 but it was added as part of https://github.com/ceph/ceph/pull/5236
#12 Updated by Loïc Dachary over 8 years ago
#13570 is testing an upgrade from firefly to giant. Do we really want to test this upgrade path ?
#13 Updated by Samuel Just over 8 years ago
- Status changed from 12 to Won't Fix