Bug 1299041 - [1.3.2 - 0.94.5-1.el7cp] qemu-io testlist 002 failure
[1.3.2 - 0.94.5-1.el7cp] qemu-io testlist 002 failure
Status: CLOSED UPSTREAM
Product: Red Hat Ceph Storage
Classification: Red Hat
Component: RBD (Show other bugs)
1.3.2
Unspecified Unspecified
unspecified Severity unspecified
: rc
: 1.3.3
Assigned To: Josh Durgin
ceph-qe-bugs
:
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2016-01-15 13:40 EST by Vasu Kulkarni
Modified: 2017-07-30 11:33 EDT (History)
2 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2016-01-15 13:47:09 EST
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)


External Trackers
Tracker ID Priority Status Summary Last Updated
Ceph Project Bug Tracker 13483 None None None 2016-01-15 13:43 EST

  None (edit)
Description Vasu Kulkarni 2016-01-15 13:40:50 EST
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@clara010.ceph.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@clara010.ceph.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
Comment 1 Jason Dillaman 2016-01-15 13:43:36 EST
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).
Comment 2 Vasu Kulkarni 2016-01-15 13:47:09 EST
Jason thanks will pickup the fix.

Note You need to log in before you can comment on or make changes to this bug.