Description of problem: Version-Release number of selected component (if applicable): [ 1.3.2 / 0.94.5-1 ] How reproducible: Always Steps to Reproduce: Run qemu-io tests Actual results: 2016-01-14T03:09:42.823 INFO:tasks.ceph:Generating config... 2016-01-14T03:09:42.826 INFO:tasks.ceph:[client] rbd cache = True 2016-01-14T03:09:42.827 INFO:tasks.ceph:[mon] debug mon = 20 2016-01-14T03:09:42.827 INFO:tasks.ceph:[mon] debug paxos = 20 2016-01-14T03:09:42.828 INFO:tasks.ceph:[mon] debug ms = 1 2016-01-14T03:09:42.829 INFO:tasks.ceph:[osd] debug osd = 20 2016-01-14T03:09:42.830 INFO:tasks.ceph:[osd] debug filestore = 20 2016-01-14T03:09:42.831 INFO:tasks.ceph:[osd] debug journal = 20 2016-01-14T03:09:42.831 INFO:tasks.ceph:[osd] debug ms = 1 2016-01-14T03:09:42.832 INFO:tasks.ceph:Setting up mon.a... 2016-01-14T03:09:42.833 INFO:teuthology.orchestra.run.clara010:Running: 'sudo adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage ceph-authtool --create-keyring /etc/ceph/ceph.keyring' 2016-01-14T03:09:42.937 INFO:teuthology.orchestra.run.clara010.stdout:creating /etc/ceph/ceph.keyring 2016-01-14T03:09:42.940 INFO:teuthology.orchestra.run.clara010:Running: 'sudo adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage ceph-authtool --gen-key --name=mon. /etc/ceph/ceph.keyring' 2016-01-14T03:09:43.047 INFO:teuthology.orchestra.run.clara010:Running: 'sudo chmod 0644 /etc/ceph/ceph.keyring' 2016-01-14T03:09:43.113 DEBUG:teuthology.misc:Ceph mon addresses: [('a', '10.8.129.10:6789')] 2016-01-14T03:09:43.114 INFO:teuthology.orchestra.run.clara010:Running: 'adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage monmaptool --create --clobber --add a 10.8.129.10:6789 --print /home/ubuntu/cephtest/monmap' 2016-01-14T03:09:43.216 INFO:tasks.ceph:Writing ceph.conf for FSID d1c76e92-ebad-4ac5-b415-f3fba9f3c9d2... 2016-01-14T03:09:43.218 INFO:teuthology.orchestra.run.clara010:Running: 'sudo mkdir -p /etc/ceph && sudo chmod 0755 /etc/ceph && sudo python -c \'import shutil, sys; shutil.copyfileobj(sys.stdin, file(sys.argv[1], "wb"))\' /etc/ceph/ceph.conf && sudo chmod 0644 /etc/ceph/ceph.conf' 2016-01-14T03:09:43.326 INFO:tasks.ceph:Creating admin key on mon.a... 2016-01-14T03:09:43.327 INFO:teuthology.orchestra.run.clara010:Running: "sudo adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage ceph-authtool --gen-key --name=client.admin --set-uid=0 --cap mon 'allow *' --cap osd 'allow *' --cap mds 'allow *' /etc/ceph/ceph.keyring" 2016-01-14T03:09:43.439 INFO:tasks.ceph:Copying monmap to all nodes... 2016-01-14T03:09:43.572 INFO:tasks.ceph:Sending monmap to node ubuntu.redhat.com 2016-01-14T03:09:43.573 INFO:teuthology.orchestra.run.clara010:Running: 'sudo python -c \'import shutil, sys; shutil.copyfileobj(sys.stdin, file(sys.argv[1], "wb"))\' /etc/ceph/ceph.keyring && sudo chmod 0644 /etc/ceph/ceph.keyring' 2016-01-14T03:09:43.663 INFO:teuthology.orchestra.run.clara010:Running: 'python -c \'import shutil, sys; shutil.copyfileobj(sys.stdin, file(sys.argv[1], "wb"))\' /home/ubuntu/cephtest/monmap' 2016-01-14T03:09:43.739 INFO:tasks.ceph:Setting up mon nodes... 2016-01-14T03:09:43.740 INFO:teuthology.orchestra.run.clara010:Running: 'adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage osdmaptool -c /etc/ceph/ceph.conf --clobber --createsimple 2 /home/ubuntu/cephtest/osdmap --pg_bits 2 --pgp_bits 4' 2016-01-14T03:09:43.910 INFO:teuthology.orchestra.run.clara010.stderr:osdmaptool: osdmap file '/home/ubuntu/cephtest/osdmap' 2016-01-14T03:09:44.292 INFO:teuthology.orchestra.run.clara010.stdout:osdmaptool: writing epoch 1 to /home/ubuntu/cephtest/osdmap 2016-01-14T03:09:44.294 INFO:tasks.ceph:Setting up mds nodes... 2016-01-14T03:09:44.294 INFO:tasks.ceph_client:Setting up client nodes... 2016-01-14T03:09:44.295 INFO:teuthology.orchestra.run.clara010:Running: 'sudo adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage ceph-authtool --create-keyring --gen-key --name=client.0 /etc/ceph/ceph.client.0.keyring && sudo chmod 0644 /etc/ceph/ceph.client.0.keyring' 2016-01-14T03:09:44.401 INFO:teuthology.orchestra.run.clara010.stdout:creating /etc/ceph/ceph.client.0.keyring 2016-01-14T03:09:44.411 INFO:tasks.ceph:Running mkfs on osd nodes... 2016-01-14T03:09:44.412 INFO:tasks.ceph:ctx.disk_config.remote_to_roles_to_dev: {Remote(name='ubuntu.redhat.com'): {}} 2016-01-14T03:09:44.413 INFO:teuthology.orchestra.run.clara010:Running: 'sudo mkdir -p /var/lib/ceph/osd/ceph-0' 2016-01-14T03:09:44.479 INFO:tasks.ceph:{} 2016-01-14T03:09:44.480 INFO:tasks.ceph:0 2016-01-14T03:09:44.481 INFO:teuthology.orchestra.run.clara010:Running: 'sudo mkdir -p /var/lib/ceph/osd/ceph-1' 2016-01-14T03:09:44.549 INFO:tasks.ceph:{} 2016-01-14T03:09:44.550 INFO:tasks.ceph:1 2016-01-14T03:09:44.550 INFO:teuthology.orchestra.run.clara010:Running: 'sudo MALLOC_CHECK_=3 adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage ceph-osd --mkfs --mkkey -i 0 --monmap /home/ubuntu/cephtest/monmap' 2016-01-14T03:09:44.666 INFO:teuthology.orchestra.run.clara010.stderr:2016-01-14 03:09:44.665959 7f46f8626840 -1 journal FileJournal::_open: disabling aio for non-block journal. Use journal_force_aio to force use of aio anyway 2016-01-14T03:09:45.182 INFO:teuthology.orchestra.run.clara010.stderr:2016-01-14 03:09:45.181874 7f46f8626840 -1 journal FileJournal::_open: disabling aio for non-block journal. Use journal_force_aio to force use of aio anyway 2016-01-14T03:09:45.184 INFO:teuthology.orchestra.run.clara010.stderr:2016-01-14 03:09:45.182480 7f46f8626840 -1 filestore(/var/lib/ceph/osd/ceph-0) could not find 23c2fcde/osd_superblock/0//-1 in index: (2) No such file or directory 2016-01-14T03:09:45.192 INFO:teuthology.orchestra.run.clara010.stderr:2016-01-14 03:09:45.190962 7f46f8626840 -1 created object store /var/lib/ceph/osd/ceph-0 journal /var/lib/ceph/osd/ceph-0/journal for osd.0 fsid d1c76e92-ebad-4ac5-b415-f3fba9f3c9d2 2016-01-14T03:09:45.193 INFO:teuthology.orchestra.run.clara010.stderr:2016-01-14 03:09:45.191010 7f46f8626840 -1 auth: error reading file: /var/lib/ceph/osd/ceph-0/keyring: can't open /var/lib/ceph/osd/ceph-0/keyring: (2) No such file or directory 2016-01-14T03:09:45.194 INFO:teuthology.orchestra.run.clara010.stderr:2016-01-14 03:09:45.191123 7f46f8626840 -1 created new key in keyring /var/lib/ceph/osd/ceph-0/keyring 2016-01-14T03:09:45.196 INFO:teuthology.orchestra.run.clara010:Running: 'sudo MALLOC_CHECK_=3 adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage ceph-osd --mkfs --mkkey -i 1 --monmap /home/ubuntu/cephtest/monmap' 2016-01-14T03:09:45.313 INFO:teuthology.orchestra.run.clara010.stderr:2016-01-14 03:09:45.313005 7f4f959d7840 -1 journal FileJournal::_open: disabling aio for non-block journal. Use journal_force_aio to force use of aio anyway 2016-01-14T03:09:45.321 INFO:teuthology.orchestra.run.clara010.stderr:2016-01-14 03:09:45.321304 7f4f959d7840 -1 journal FileJournal::_open: disabling aio for non-block journal. Use journal_force_aio to force use of aio anyway 2016-01-14T03:09:45.323 INFO:teuthology.orchestra.run.clara010.stderr:2016-01-14 03:09:45.321857 7f4f959d7840 -1 filestore(/var/lib/ceph/osd/ceph-1) could not find 23c2fcde/osd_superblock/0//-1 in index: (2) No such file or directory 2016-01-14T03:09:45.330 INFO:teuthology.orchestra.run.clara010.stderr:2016-01-14 03:09:45.329438 7f4f959d7840 -1 created object store /var/lib/ceph/osd/ceph-1 journal /var/lib/ceph/osd/ceph-1/journal for osd.1 fsid d1c76e92-ebad-4ac5-b415-f3fba9f3c9d2 2016-01-14T03:09:45.331 INFO:teuthology.orchestra.run.clara010.stderr:2016-01-14 03:09:45.329485 7f4f959d7840 -1 auth: error reading file: /var/lib/ceph/osd/ceph-1/keyring: can't open /var/lib/ceph/osd/ceph-1/keyring: (2) No such file or directory 2016-01-14T03:09:45.332 INFO:teuthology.orchestra.run.clara010.stderr:2016-01-14 03:09:45.329598 7f4f959d7840 -1 created new key in keyring /var/lib/ceph/osd/ceph-1/keyring 2016-01-14T03:09:45.334 INFO:tasks.ceph:Reading keys from all nodes... 2016-01-14T03:09:45.336 INFO:teuthology.orchestra.run.clara010:Running: "python -c 'import os; import tempfile; import sys;(fd,fname) = tempfile.mkstemp();os.close(fd);sys.stdout.write(fname.rstrip());sys.stdout.flush()'" 2016-01-14T03:09:45.419 INFO:teuthology.orchestra.run.clara010:Running: 'sudo cp /var/lib/ceph/osd/ceph-0/keyring /tmp/tmpwfpdS8' 2016-01-14T03:09:45.486 INFO:teuthology.orchestra.run.clara010:Running: 'sudo chmod 0666 /tmp/tmpwfpdS8' 2016-01-14T03:09:45.619 INFO:teuthology.orchestra.run.clara010:Running: 'rm -fr /tmp/tmpwfpdS8' 2016-01-14T03:09:45.677 INFO:teuthology.orchestra.run.clara010:Running: "python -c 'import os; import tempfile; import sys;(fd,fname) = tempfile.mkstemp();os.close(fd);sys.stdout.write(fname.rstrip());sys.stdout.flush()'" 2016-01-14T03:09:45.823 INFO:teuthology.orchestra.run.clara010:Running: 'sudo cp /var/lib/ceph/osd/ceph-1/keyring /tmp/tmpNyhxrb' 2016-01-14T03:09:45.890 INFO:teuthology.orchestra.run.clara010:Running: 'sudo chmod 0666 /tmp/tmpNyhxrb' 2016-01-14T03:09:46.020 INFO:teuthology.orchestra.run.clara010:Running: 'rm -fr /tmp/tmpNyhxrb' 2016-01-14T03:09:46.208 INFO:tasks.ceph:Adding keys to all mons... 2016-01-14T03:09:46.210 INFO:teuthology.orchestra.run.clara010:Running: 'sudo tee -a /etc/ceph/ceph.keyring' 2016-01-14T03:09:46.275 INFO:teuthology.orchestra.run.clara010:Running: "sudo adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage ceph-authtool /etc/ceph/ceph.keyring --name=osd.0 --cap osd 'allow *' --cap mon 'allow *'" 2016-01-14T03:09:46.447 INFO:teuthology.orchestra.run.clara010:Running: "sudo adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage ceph-authtool /etc/ceph/ceph.keyring --name=osd.1 --cap osd 'allow *' --cap mon 'allow *'" 2016-01-14T03:09:46.557 INFO:teuthology.orchestra.run.clara010:Running: "sudo adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage ceph-authtool /etc/ceph/ceph.keyring --name=client.0 --cap mds allow --cap osd 'allow rwx' --cap mon 'allow rw'" 2016-01-14T03:09:46.667 INFO:tasks.ceph:Running mkfs on mon nodes... 2016-01-14T03:09:46.668 INFO:teuthology.orchestra.run.clara010:Running: 'sudo mkdir -p /var/lib/ceph/mon/ceph-a' 2016-01-14T03:09:46.735 INFO:teuthology.orchestra.run.clara010:Running: 'sudo adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage ceph-mon --mkfs -i a --monmap=/home/ubuntu/cephtest/monmap --osdmap=/home/ubuntu/cephtest/osdmap --keyring=/etc/ceph/ceph.keyring' 2016-01-14T03:09:46.845 INFO:teuthology.orchestra.run.clara010.stdout:ceph-mon: set fsid to d1c76e92-ebad-4ac5-b415-f3fba9f3c9d2 2016-01-14T03:09:46.850 INFO:teuthology.orchestra.run.clara010.stdout:ceph-mon: created monfs at /var/lib/ceph/mon/ceph-a for mon.a 2016-01-14T03:09:46.852 INFO:teuthology.orchestra.run.clara010:Running: 'rm -- /home/ubuntu/cephtest/monmap /home/ubuntu/cephtest/osdmap' 2016-01-14T03:09:46.911 INFO:tasks.ceph:Starting mon daemons... 2016-01-14T03:09:46.912 INFO:tasks.ceph.mon.a:Restarting daemon 2016-01-14T03:09:46.913 INFO:teuthology.orchestra.run.clara010:Running: 'sudo adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage daemon-helper kill ceph-mon -f -i a' 2016-01-14T03:09:46.918 INFO:tasks.ceph.mon.a:Started 2016-01-14T03:09:46.919 INFO:tasks.ceph:Setting crush tunables to default 2016-01-14T03:09:46.920 INFO:teuthology.orchestra.run.clara010:Running: 'sudo ceph osd crush tunables default' 2016-01-14T03:09:47.068 INFO:tasks.ceph.mon.a.clara010.stdout:starting mon.a rank 0 at 10.8.129.10:6789/0 mon_data /var/lib/ceph/mon/ceph-a fsid d1c76e92-ebad-4ac5-b415-f3fba9f3c9d2 2016-01-14T03:09:47.270 INFO:teuthology.orchestra.run.clara010.stderr:adjusted tunables profile to default 2016-01-14T03:09:47.284 INFO:tasks.ceph:Starting osd daemons... 2016-01-14T03:09:47.285 INFO:tasks.ceph.osd.0:Restarting daemon 2016-01-14T03:09:47.287 INFO:teuthology.orchestra.run.clara010:Running: 'sudo adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage daemon-helper kill ceph-osd -f -i 0' 2016-01-14T03:09:47.292 INFO:tasks.ceph.osd.0:Started 2016-01-14T03:09:47.293 INFO:tasks.ceph.osd.1:Restarting daemon 2016-01-14T03:09:47.294 INFO:teuthology.orchestra.run.clara010:Running: 'sudo adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage daemon-helper kill ceph-osd -f -i 1' 2016-01-14T03:09:47.298 INFO:tasks.ceph.osd.1:Started 2016-01-14T03:09:47.299 INFO:tasks.ceph:Starting mds daemons... 2016-01-14T03:09:47.300 INFO:tasks.ceph:Waiting until ceph is healthy... 2016-01-14T03:09:47.300 INFO:teuthology.orchestra.run.clara010:Running: 'adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage ceph osd dump --format=json' 2016-01-14T03:09:47.397 INFO:tasks.ceph.osd.0.clara010.stdout:starting osd.0 at :/0 osd_data /var/lib/ceph/osd/ceph-0 /var/lib/ceph/osd/ceph-0/journal 2016-01-14T03:09:47.435 INFO:tasks.ceph.osd.1.clara010.stdout:starting osd.1 at :/0 osd_data /var/lib/ceph/osd/ceph-1 /var/lib/ceph/osd/ceph-1/journal 2016-01-14T03:09:47.451 INFO:tasks.ceph.osd.0.clara010.stderr:2016-01-14 03:09:47.450708 7f0f2e67f840 -1 journal FileJournal::_open: disabling aio for non-block journal. Use journal_force_aio to force use of aio anyway 2016-01-14T03:09:47.464 INFO:tasks.ceph.osd.0.clara010.stderr:2016-01-14 03:09:47.463766 7f0f2e67f840 -1 osd.0 0 log_to_monitors {default=true} 2016-01-14T03:09:47.488 INFO:tasks.ceph.osd.1.clara010.stderr:2016-01-14 03:09:47.487907 7f1c86323840 -1 journal FileJournal::_open: disabling aio for non-block journal. Use journal_force_aio to force use of aio anyway 2016-01-14T03:09:47.497 INFO:tasks.ceph.osd.1.clara010.stderr:2016-01-14 03:09:47.497314 7f1c86323840 -1 osd.1 0 log_to_monitors {default=true} 2016-01-14T03:09:47.657 DEBUG:teuthology.misc:0 of 2 OSDs are up 2016-01-14T03:09:48.658 INFO:teuthology.orchestra.run.clara010:Running: 'adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage ceph osd dump --format=json' 2016-01-14T03:09:49.053 DEBUG:teuthology.misc:2 of 2 OSDs are up 2016-01-14T03:09:49.277 INFO:teuthology.orchestra.run.clara010:Running: 'adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage ceph health' 2016-01-14T03:09:49.632 DEBUG:teuthology.misc:Ceph health: HEALTH_WARN 8 pgs stuck inactive; 8 pgs stuck unclean 2016-01-14T03:09:56.634 INFO:teuthology.orchestra.run.clara010:Running: 'adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage ceph health' 2016-01-14T03:09:56.989 DEBUG:teuthology.misc:Ceph health: HEALTH_OK 2016-01-14T03:09:56.991 INFO:teuthology.orchestra.run.clara010:Running: 'adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage ceph osd dump --format=json' 2016-01-14T03:09:57.347 INFO:tasks.ceph.ceph_manager:[{u'cache_target_full_ratio_micro': 0, u'stripe_width': 0, u'flags_names': u'hashpspool', u'tier_of': -1, u'pg_placement_num': 8, u'quota_max_bytes': 0, u'erasure_code_profile': u'', u'expected_num_objects': 0, u'size': 2, u'snap_seq': 0, u'auid': 0, u'cache_min_flush_age': 0, u'hit_set_period': 0, u'min_read_recency_for_promote': 0, u'target_max_objects': 0, u'pg_num': 8, u'type': 1, u'crush_ruleset': 0, u'pool_name': u'rbd', u'cache_min_evict_age': 0, u'snap_mode': u'selfmanaged', u'cache_mode': u'none', u'min_size': 1, u'crash_replay_interval': 0, u'object_hash': 2, u'write_tier': -1, u'cache_target_dirty_ratio_micro': 0, u'pool': 0, u'removed_snaps': u'[]', u'tiers': [], u'hit_set_params': {u'type': u'none'}, u'last_force_op_resend': u'0', u'pool_snaps': [], u'quota_max_objects': 0, u'hit_set_count': 0, u'flags': 1, u'target_max_bytes': 0, u'snap_epoch': 0, u'last_change': u'1', u'read_tier': -1}] 2016-01-14T03:09:57.348 INFO:teuthology.orchestra.run.clara010:Running: 'adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage ceph osd pool get rbd pg_num' 2016-01-14T03:09:57.704 INFO:teuthology.run_tasks:Running task workunit... 2016-01-14T03:09:57.706 INFO:tasks.workunit:Pulling workunits from ref 9764da52395923e0b32908d83a9f7304401fee43 2016-01-14T03:09:57.707 INFO:tasks.workunit:Making a separate scratch dir for every client... 2016-01-14T03:09:57.708 DEBUG:tasks.workunit:getting remote for 0 role client.0 2016-01-14T03:09:57.709 INFO:teuthology.orchestra.run.clara010:Running: 'stat -- /home/ubuntu/cephtest/mnt.0' 2016-01-14T03:09:57.769 INFO:teuthology.orchestra.run.clara010.stderr:stat: cannot stat ‘/home/ubuntu/cephtest/mnt.0’: No such file or directory 2016-01-14T03:09:57.771 INFO:teuthology.orchestra.run.clara010:Running: 'mkdir -- /home/ubuntu/cephtest/mnt.0' 2016-01-14T03:09:57.829 INFO:tasks.workunit:Created dir /home/ubuntu/cephtest/mnt.0 2016-01-14T03:09:57.831 INFO:teuthology.orchestra.run.clara010:Running: 'cd -- /home/ubuntu/cephtest/mnt.0 && mkdir -- client.0' 2016-01-14T03:09:57.890 INFO:teuthology.orchestra.run.clara010:Running: "mkdir -- /home/ubuntu/cephtest/workunit.client.0 && git archive --remote=git://git.ceph.com/ceph.git 9764da52395923e0b32908d83a9f7304401fee43:qa/workunits | tar -C /home/ubuntu/cephtest/workunit.client.0 -x -f- && cd -- /home/ubuntu/cephtest/workunit.client.0 && if test -e Makefile ; then make ; fi && find -executable -type f -printf '%P\\0' >/home/ubuntu/cephtest/workunits.list.client.0" 2016-01-14T03:10:01.818 INFO:tasks.workunit.client.0.clara010.stdout:for d in direct_io fs ; do ( cd $d ; make all ) ; done 2016-01-14T03:10:01.822 INFO:tasks.workunit.client.0.clara010.stdout:make[1]: Entering directory `/home/ubuntu/cephtest/workunit.client.0/direct_io' 2016-01-14T03:10:01.823 INFO:tasks.workunit.client.0.clara010.stdout:cc -Wall -Wextra -D_GNU_SOURCE direct_io_test.c -o direct_io_test 2016-01-14T03:10:01.900 INFO:tasks.workunit.client.0.clara010.stdout:cc -Wall -Wextra -D_GNU_SOURCE test_sync_io.c -o test_sync_io 2016-01-14T03:10:01.978 INFO:tasks.workunit.client.0.clara010.stdout:cc -Wall -Wextra -D_GNU_SOURCE test_short_dio_read.c -o test_short_dio_read 2016-01-14T03:10:02.037 INFO:tasks.workunit.client.0.clara010.stdout:make[1]: Leaving directory `/home/ubuntu/cephtest/workunit.client.0/direct_io' 2016-01-14T03:10:02.040 INFO:tasks.workunit.client.0.clara010.stdout:make[1]: Entering directory `/home/ubuntu/cephtest/workunit.client.0/fs' 2016-01-14T03:10:02.041 INFO:tasks.workunit.client.0.clara010.stdout:cc -Wall -Wextra -D_GNU_SOURCE test_o_trunc.c -o test_o_trunc 2016-01-14T03:10:02.098 INFO:tasks.workunit.client.0.clara010.stdout:make[1]: Leaving directory `/home/ubuntu/cephtest/workunit.client.0/fs' 2016-01-14T03:10:02.185 INFO:tasks.workunit:Running workunits matching rbd/qemu-iotests.sh on client.0... 2016-01-14T03:10:02.186 INFO:tasks.workunit:Running workunit rbd/qemu-iotests.sh... 2016-01-14T03:10:02.186 INFO:teuthology.orchestra.run.clara010:Running (workunit test rbd/qemu-iotests.sh): '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=9764da52395923e0b32908d83a9f7304401fee43 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/rbd/qemu-iotests.sh' 2016-01-14T03:10:02.253 INFO:tasks.workunit.client.0.clara010.stderr:++ lsb_release -sc 2016-01-14T03:10:02.279 INFO:tasks.workunit.client.0.clara010.stderr:+ codevers=Maipo 2016-01-14T03:10:02.280 INFO:tasks.workunit.client.0.clara010.stderr:+ iotests=qemu-iotests 2016-01-14T03:10:02.281 INFO:tasks.workunit.client.0.clara010.stderr:+ testlist='001 002 003 004 005 008 009 010 011 021 025' 2016-01-14T03:10:02.282 INFO:tasks.workunit.client.0.clara010.stderr:+ for chkcode in '"trusty"' 2016-01-14T03:10:02.284 INFO:tasks.workunit.client.0.clara010.stderr:+ '[' trusty = Maipo ']' 2016-01-14T03:10:02.284 INFO:tasks.workunit.client.0.clara010.stderr:+ '[' qemu-iotests = qemu/tests/qemu-iotests ']' 2016-01-14T03:10:02.286 INFO:tasks.workunit.client.0.clara010.stderr:+ git clone git://git.ceph.com/qemu-iotests.git 2016-01-14T03:10:02.679 INFO:tasks.workunit.client.0.clara010.stdout:Cloning into 'qemu-iotests'... 2016-01-14T03:10:03.821 INFO:tasks.workunit.client.0.clara010.stderr:+ cd qemu-iotests 2016-01-14T03:10:04.290 INFO:tasks.workunit.client.0.clara010.stderr:+ mkdir bin 2016-01-14T03:10:04.292 INFO:tasks.workunit.client.0.clara010.stderr:+ '[' -x /usr/bin/qemu-system-x86_64 ']' 2016-01-14T03:10:04.330 INFO:tasks.workunit.client.0.clara010.stderr:+ QEMU=/usr/libexec/qemu-kvm 2016-01-14T03:10:04.331 INFO:tasks.workunit.client.0.clara010.stderr:+ ln -s /usr/libexec/qemu-kvm bin/qemu 2016-01-14T03:10:04.372 INFO:tasks.workunit.client.0.clara010.stderr:+ touch common.env 2016-01-14T03:10:04.372 INFO:tasks.workunit.client.0.clara010.stderr:+ TEST_DIR=rbd 2016-01-14T03:10:04.413 INFO:tasks.workunit.client.0.clara010.stderr:+ PATH=/usr/lib64/qt-3.3/bin:/usr/local/bin:/usr/bin:/usr/sbin:/home/ubuntu/cephtest/mnt.0/client.0/tmp/qemu-iotests/bin 2016-01-14T03:10:04.414 INFO:tasks.workunit.client.0.clara010.stderr:+ ./check -rbd 001 002 003 004 005 008 009 010 011 021 025 2016-01-14T03:10:04.455 INFO:tasks.workunit.client.0.clara010.stdout:QEMU -- /home/ubuntu/cephtest/mnt.0/client.0/tmp/qemu-iotests/bin/qemu 2016-01-14T03:10:04.456 INFO:tasks.workunit.client.0.clara010.stdout:QEMU_IMG -- /usr/bin/qemu-img 2016-01-14T03:10:04.497 INFO:tasks.workunit.client.0.clara010.stdout:QEMU_IO -- /usr/bin/qemu-io 2016-01-14T03:10:04.497 INFO:tasks.workunit.client.0.clara010.stdout:IMGFMT -- raw 2016-01-14T03:10:04.498 INFO:tasks.workunit.client.0.clara010.stdout:IMGPROTO -- rbd 2016-01-14T03:10:04.499 INFO:tasks.workunit.client.0.clara010.stdout:PLATFORM -- Linux/x86_64 clara010 3.10.0-327.el7.x86_64 2016-01-14T03:10:04.500 INFO:tasks.workunit.client.0.clara010.stdout: 2016-01-14T03:10:07.572 INFO:tasks.workunit.client.0.clara010.stdout:001 2016-01-14T03:10:14.997 INFO:tasks.workunit.client.0.clara010.stdout:002 - output mismatch (see 002.out.bad) 2016-01-14T03:10:15.000 INFO:tasks.workunit.client.0.clara010.stdout:--- 002.out 2016-01-14 03:10:03.785658729 -0500 2016-01-14T03:10:15.001 INFO:tasks.workunit.client.0.clara010.stdout:+++ 002.out.bad 2016-01-14 03:10:14.849417169 -0500 2016-01-14T03:10:15.002 INFO:tasks.workunit.client.0.clara010.stdout:@@ -15,9 +15,9 @@ 2016-01-14T03:10:15.003 INFO:tasks.workunit.client.0.clara010.stdout: 2016-01-14T03:10:15.004 INFO:tasks.workunit.client.0.clara010.stdout: unaligned pwrite 2016-01-14T03:10:15.005 INFO:tasks.workunit.client.0.clara010.stdout: wrote 42/42 bytes at offset 66 2016-01-14T03:10:15.006 INFO:tasks.workunit.client.0.clara010.stdout:-42.000000 bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec) 2016-01-14T03:10:15.007 INFO:tasks.workunit.client.0.clara010.stdout:+42 bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec) 2016-01-14T03:10:15.008 INFO:tasks.workunit.client.0.clara010.stdout: 2016-01-14T03:10:15.009 INFO:tasks.workunit.client.0.clara010.stdout: verify pattern 2016-01-14T03:10:15.010 INFO:tasks.workunit.client.0.clara010.stdout: read 42/42 bytes at offset 66 2016-01-14T03:10:15.011 INFO:tasks.workunit.client.0.clara010.stdout:-42.000000 bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec) 2016-01-14T03:10:15.012 INFO:tasks.workunit.client.0.clara010.stdout:+42 bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec) 2016-01-14T03:10:15.013 INFO:tasks.workunit.client.0.clara010.stdout: *** done 2016-01-14T03:10:22.548 INFO:tasks.workunit.client.0.clara010.stdout:003 2016-01-14T03:10:24.126 INFO:tasks.workunit.client.0.clara010.stdout:004 2016-01-14T03:15:34.962 INFO:tasks.workunit.client.0.clara010.stdout:005 2016-01-14T03:15:38.051 INFO:tasks.workunit.client.0.clara010.stdout:008 2016-01-14T03:15:38.882 INFO:tasks.workunit.client.0.clara010.stdout:009 2016-01-14T03:15:39.713 INFO:tasks.workunit.client.0.clara010.stdout:010 2016-01-14T03:15:43.706 INFO:tasks.workunit.client.0.clara010.stdout:011 2016-01-14T03:15:47.249 INFO:tasks.workunit.client.0.clara010.stdout:021 2016-01-14T03:15:50.511 INFO:tasks.workunit.client.0.clara010.stdout:025 2016-01-14T03:15:50.522 INFO:tasks.workunit.client.0.clara010.stdout:Failures: 002 2016-01-14T03:15:50.523 INFO:tasks.workunit.client.0.clara010.stdout:Failed 1 of 11 tests 2016-01-14T03:15:50.528 INFO:tasks.workunit:Stopping ['rbd/qemu-iotests.sh'] on client.0... Expected results: All tests should pass Additional info: http://magna002.ceph.redhat.com/vasu-2016-01-08_19:19:02-rbd-v0.94.5---basic-clara/210485/teuthology.log
Note that the failure is only related to number formating in the output (extra .000000): -42.000000 bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec) +42 bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec) This issue was already fixed in the upstream test suite (i.e. not a RBD bug).
Jason thanks will pickup the fix.