Bug #10534
closedfull-object read crc 0x######## != expected 0x######## on
0%
Description
2015-01-13 18:55:18,979.979 INFO:tasks.ceph.osd.0.plana02.stderr:2015-01-13 18:55:18.860647 7fe6d209b700 -1 log_channel(default) log [ERR] : 1.67 full-object read crc 0x52b5f
03f != expected 0x4fae88b7 on 31c93c67/plana0213876-8/head//1
5-01-13 18:55:18,989.989 INFO:tasks.rados.rados.0.plana02.stderr:8308: Error: oid 8 read returned error code -5
2015-01-13 18:55:18,994.994 INFO:tasks.thrashosds.thrasher:Recovered, killing an osd
2015-01-13 18:55:18,995.995 INFO:tasks.thrashosds.thrasher:Killing osd 1, live_osds are [4, 0, 3, 5, 2, 1]
2015-01-13 18:55:18,996.996 INFO:tasks.rados.rados.0.plana02.stderr:./test/osd/RadosModel.h: In function 'virtual void ReadOp::_finish(TestOp::CallbackInfo*)' thread 7f4b38ff9700 time 2015-01-13 18:55:18.969589
2015-01-13 18:55:18,996.996 INFO:tasks.rados.rados.0.plana02.stderr:./test/osd/RadosModel.h: 1067: FAILED assert(0)
2015-01-13 18:55:18,997.997 INFO:tasks.rados.rados.0.plana02.stderr: ceph version 0.90-940-gd159586 (d15958631b52a116ef596523fac5ffb8d77ead4e)
2015-01-13 18:55:18,997.997 INFO:tasks.rados.rados.0.plana02.stderr: 1: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x85) [0x4e0e65]
2015-01-13 18:55:18,997.997 INFO:tasks.rados.rados.0.plana02.stderr: 2: (ReadOp::_finish(TestOp::CallbackInfo*)+0xff) [0x4d0eff]
2015-01-13 18:55:18,998.998 INFO:tasks.rados.rados.0.plana02.stderr: 3: (()+0x7ff8d) [0x7f4b4582cf8d]
2015-01-13 18:55:18,998.998 INFO:tasks.rados.rados.0.plana02.stderr: 4: (()+0x5c259) [0x7f4b45809259]
2015-01-13 18:55:18,998.998 INFO:tasks.rados.rados.0.plana02.stderr: 5: (()+0x125868) [0x7f4b458d2868]
2015-01-13 18:55:18,998.998 INFO:tasks.rados.rados.0.plana02.stderr: 6: (()+0x7df3) [0x7f4b44bf9df3]
2015-01-13 18:55:18,999.999 INFO:tasks.rados.rados.0.plana02.stderr: 7: (clone()+0x6d) [0x7f4b43cfb3dd]
2015-01-13 18:55:18,999.999 INFO:tasks.rados.rados.0.plana02.stderr: NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.
2015-01-13 18:55:18,999.999 INFO:tasks.rados.rados.0.plana02.stderr:terminate called after throwing an instance of 'ceph::FailedAssertion'
Traceback (most recent call last):
File "/home/dzafman/src/teuthology/virtualenv/local/lib/python2.7/site-packages/gevent/greenlet.py", line 390, in run
result = self._run(*self.args, **self.kwargs)
File "/home/dzafman/src/ceph-qa-suite_master/tasks/rados.py", line 179, in thread
run.wait(tests.itervalues())
File "/home/dzafman/src/teuthology/teuthology/orchestra/run.py", line 391, in wait
proc.wait()
File "/home/dzafman/src/teuthology/teuthology/orchestra/run.py", line 103, in wait
raise CommandCrashedError(command=self.command)
CommandCrashedError: Command crashed: 'CEPH_CLIENT_ID=0 adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage ceph_test_rados --op read 100 --op write 0 --op delete 50 --max-ops 40000 --objects 50 --max-in-flight 16 --size 4000000 --min-stride-size 400000 --max-stride-size 800000 --max-seconds 0 --op snap_create 50 --op snap_remove 50 --op rollback 50 --op setattr 25 --op rmattr 25 --op copy_from 50 --op append 100 --pool unique_pool_0'
<Greenlet at 0x3117cd0: thread> failed with CommandCrashedError
I have reproduced this on the ceph master branch doing a single rados:thrash type job on xfs using master branch ceph-qa-suite. I found the object plana0213876-8 on osd.2 that got the read-crc error and another replica on osd.0. Both have the exact same object_info_t (see below). Also, md5sum of data are the same.
[ubuntu@plana02 ~]$ md5sum /var/lib/ceph/osd/ceph-0/current/1.67_head/plana0213876-8__head_31C93C67__1
bbdbef60799393ca24d66a6344c56a5b /var/lib/ceph/osd/ceph-0/current/1.67_head/plana0213876-8__head_31C93C67__1
[ubuntu@plana02 ~]$ md5sum /var/lib/ceph/osd/ceph-2/current/1.67_head/plana0213876-8__head_31C93C67__1
bbdbef60799393ca24d66a6344c56a5b /var/lib/ceph/osd/ceph-2/current/1.67_head/plana0213876-8__head_31C93C67__1
{ "oid": { "oid": "plana0213876-8",
"key": "",
"snapid": -2,
"hash": 835271783,
"max": 0,
"pool": 1,
"namespace": ""},
"version": "2380'1669",
"prior_version": "0'0",
"last_reqid": "client.4128.0:14753",
"user_version": 3102,
"size": 9911803,
"mtime": "2015-01-13 18:55:08.395923",
"local_mtime": "2015-01-13 18:55:08.573775",
"lost": 0,
"flags": 52,
"wrlock_by": "unknown.0.0:0",
"snaps": [],
"truncate_seq": 0,
"truncate_size": 0,
"data_digest": 1336838327,
"omap_digest": 4294967295,
"watchers": {}}
data_digest in hex 0x4FAE88B7 as seen in read-crc error
I picked another random object and it has the same content and the same object_info_t digest values.
[ubuntu@plana02 ~]$ md5sum /var/lib/ceph/osd/ceph-2/current/1.ad_head/plana0213876-29__head_7161D4AD__1
bbdbef60799393ca24d66a6344c56a5b /var/lib/ceph/osd/ceph-2/current/1.ad_head/plana0213876-29__head_7161D4AD__1
{ "oid": { "oid": "plana0213876-29",
"key": "",
"snapid": -2,
"hash": 1902236845,
"max": 0,
"pool": 1,
"namespace": ""},
"version": "2382'1056",
"prior_version": "0'0",
"last_reqid": "client.4128.0:14777",
"user_version": 3102,
"size": 9911803,
"mtime": "2015-01-13 18:55:12.870849",
"local_mtime": "2015-01-13 18:55:13.044068",
"lost": 0,
"flags": 52,
"wrlock_by": "unknown.0.0:0",
"snaps": [],
"truncate_seq": 0,
"truncate_size": 0,
"data_digest": 1336838327,
"omap_digest": 4294967295,
"watchers": {}}