Bug #4976
osd powercycle triggers object corruption on xfs
0%
Description
logs: ubuntu@teuthology:/a/teuthology-2013-05-09_01:00:05-rados-next-testing-basic/9325
2013-05-09T01:37:29.943 INFO:teuthology.task.rados.rados.0.out:Writing plana3332167-39 from 2072826 to 2611791 tid 3 ranges are [0~56,638473~673998,2072826~538965] 2013-05-09T01:37:29.944 INFO:teuthology.task.rados.rados.0.out:1169: oids not in use 497 2013-05-09T01:37:29.944 INFO:teuthology.task.rados.rados.0.out:Reading 22 2013-05-09T01:37:29.944 INFO:teuthology.task.rados.rados.0.out:1170: oids not in use 496 2013-05-09T01:37:29.944 INFO:teuthology.task.rados.rados.0.out:Reading 342 2013-05-09T01:37:29.944 INFO:teuthology.task.rados.rados.0.out:1171: oids not in use 495 2013-05-09T01:37:29.945 INFO:teuthology.task.rados.rados.0.out:Deleting 67 current snap is 0 2013-05-09T01:37:30.131 INFO:teuthology.orchestra.remote:Power off for plana55 completed 2013-05-09T01:37:31.224 INFO:teuthology.task.rados.rados.0.out:incorrect buffer at pos 1146884 2013-05-09T01:37:31.224 INFO:teuthology.task.rados.rados.0.err:Object 342 contents ObjNum: 341 snap: 0 seqnum: 341 prefix: plana3332167-OID: 342 snap 0 2013-05-09T01:37:31.224 INFO:teuthology.task.rados.rados.0.err: corrupt 2013-05-09T01:37:31.225 INFO:teuthology.task.rados.rados.0.err:./test/osd/RadosModel.h: In function 'virtual void ReadOp::_finish(TestOp::CallbackInfo*)' thread 7fe9cdffb700 time 2013-05-09 01:37:46.947876 2013-05-09T01:37:31.225 INFO:teuthology.task.rados.rados.0.err:./test/osd/RadosModel.h: 1053: FAILED assert(0) 2013-05-09T01:37:31.240 INFO:teuthology.task.rados.rados.0.err: ceph version 0.61-160-g5177fcb (5177fcb6bf384d5c9caed9b28f28f656823b3d64) 2013-05-09T01:37:31.240 INFO:teuthology.task.rados.rados.0.err: 1: (ReadOp::_finish(TestOp::CallbackInfo*)+0x13ce) [0x414dbe] 2013-05-09T01:37:31.241 INFO:teuthology.task.rados.rados.0.err: 2: (librados::C_AioComplete::finish(int)+0x1d) [0x7fe9d8003f4d] 2013-05-09T01:37:31.241 INFO:teuthology.task.rados.rados.0.err: 3: (Finisher::finisher_thread_entry()+0x1c0) [0x7fe9d80719d0] 2013-05-09T01:37:31.241 INFO:teuthology.task.rados.rados.0.err: 4: (()+0x7e9a) [0x7fe9d7cb6e9a] 2013-05-09T01:37:31.241 INFO:teuthology.task.rados.rados.0.err: 5: (clone()+0x6d) [0x7fe9d74cdccd] 2013-05-09T01:37:31.242 INFO:teuthology.task.rados.rados.0.err: NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this. 2013-05-09T01:37:31.242 INFO:teuthology.task.rados.rados.0.err:terminate called after throwing an instance of 'ceph::FailedAssertion' 2013-05-09T01:37:31.424 ERROR:teuthology.run_tasks:Manager failed: <contextlib.GeneratorContextManager object at 0x320db50> Traceback (most recent call last): File "/var/lib/teuthworker/teuthology-next/teuthology/run_tasks.py", line 45, in run_tasks suppress = manager.__exit__(*exc_info) File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__ self.gen.next() File "/var/lib/teuthworker/teuthology-next/teuthology/task/rados.py", line 118, in task running.get() File "/var/lib/teuthworker/teuthology-next/virtualenv/local/lib/python2.7/site-packages/gevent/greenlet.py", line 331, in get raise self._exception CommandCrashedError: Command crashed: 'CEPH_CLIENT_ID=0 /home/ubuntu/cephtest/9325/enable-coredump ceph-coverage /home/ubuntu/cephtest/9325/archive/coverage ceph_test_rados --op read 45 --op write 45 --op delete 10 --op snap_create 0 --op snap_remove 0 --op rollback 0 --op setattr 0 --op rmattr 0 --op watch 0 --max-ops 4000 --objects 500 --max-in-flight 16 --size 4000000 --min-stride-size 400000 --max-stride-size 800000 --max-seconds 0' ubuntu@teuthology:/a/teuthology-2013-05-09_01:00:05-rados-next-testing-basic/9325$ cat orig.config.yaml kernel: kdb: true sha1: b5b09be30cf99f9c699e825629f02e3bce555d44 machine_type: plana nuke-on-error: true overrides: ceph: conf: mon: debug mon: 20 debug ms: 20 debug paxos: 20 fs: xfs log-whitelist: - slow request sha1: 6c1e4791782ce2b3e101ee80640d896bcda684de s3tests: branch: next workunit: sha1: 6c1e4791782ce2b3e101ee80640d896bcda684de roles: - - mon.0 - mon.1 - mon.2 - mds.0 - client.0 - - osd.0 - - osd.1 - - osd.2 tasks: - chef: null - clock.check: null - install: null - ceph: null - thrashosds: chance_down: 1.0 powercycle: true - rados: clients: - client.0 objects: 500 op_weights: delete: 10 read: 45 write: 45 ops: 4000
Related issues
Associated revisions
os/FileStore: use fdatasync(2) instead of sync_file_range(2)
This fixes data corruption on XFS. Backported from
ffade3c85dfffa13a16edd9630a52d99eb8a413d.
Fixes: #4976
Signed-off-by: Sage Weil <sage@inktank.com>
Reviewed-by: Samuel Just <sam.just@inktank.com>
History
#1 Updated by Tamilarasi muthamizhan almost 11 years ago
- Assignee set to Samuel Just
#2 Updated by Samuel Just almost 11 years ago
- Assignee deleted (
Samuel Just)
Looks like there were 4 inconsistent objects in pg 3.0
2013-05-09 01:37:39.771684 7fdc077f2700 0 log [INF] : 2.6 deep-scrub ok
2013-05-09 01:37:45.901582 7fdc077f2700 0 log [INF] : 2.8 deep-scrub ok
2013-05-09 01:37:50.763676 7fdc077f2700 0 log [INF] : 2.9 deep-scrub ok
2013-05-09 01:37:57.765040 7fdc077f2700 0 log [INF] : 2.a deep-scrub ok
2013-05-09 01:37:59.765180 7fdc077f2700 0 log [INF] : 2.b deep-scrub ok
2013-05-09 01:38:20.487161 7fdc077f2700 0 log [ERR] : 3.0 osd.0: soid a840d671/plana3332167-342/head//3 digest 3225952747 != known digest 293065042
2013-05-09 01:38:23.501161 7fdc077f2700 0 log [ERR] : 3.0 osd.0: soid 2b884b3b/plana3332167-361/head//3 digest 3120190675 != known digest 1749218233
2013-05-09 01:38:23.698283 7fdc077f2700 0 log [ERR] : 3.0 osd.0: soid 97ac4bdb/plana3332167-359/head//3 digest 4007521181 != known digest 1203775870
2013-05-09 01:38:24.470476 7fdc077f2700 0 log [ERR] : 3.0 osd.0: soid 6707116f/plana3332167-335/head//3 digest 35276847 != known digest 3722161389
2013-05-09 01:38:24.677529 7fdc077f2700 0 log [ERR] : 3.0 deep-scrub 0 missing, 4 inconsistent objects
2013-05-09 01:38:24.677535 7fdc077f2700 0 log [ERR] : 3.0 deep-scrub 4 errors
#3 Updated by Tamilarasi muthamizhan almost 11 years ago
ubuntu@teuthology:/a/teuthology-2013-05-10_01:00:06-rados-master-testing-basic/10288
#4 Updated by Tamilarasi muthamizhan almost 11 years ago
ubuntu@teuthology:/a/teuthology-2013-05-10_01:00:06-rados-master-testing-basic/10288$ cat config.yaml kernel: &id001 kdb: true sha1: b5b09be30cf99f9c699e825629f02e3bce555d44 machine_type: plana nuke-on-error: true overrides: ceph: conf: mon: debug mon: 20 debug ms: 20 debug paxos: 20 fs: xfs log-whitelist: - slow request sha1: b353da6f682d223ba14812da0fe814eca72ad6f5 s3tests: branch: master workunit: sha1: b353da6f682d223ba14812da0fe814eca72ad6f5 roles: - - mon.0 - mon.1 - mon.2 - mds.0 - client.0 - - osd.0 - - osd.1 - - osd.2 targets: ubuntu@plana08.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQCqqzUa6OfNvqirlipO2jY32KanSfk2mSstJJdakPuKVijDoaDHvC7L14A9iNMChI/+OgVJRpBF4DI+QwrO00yj4jSGSuq/dtp6vxkX5fw1+g21uqZG7Sl6S89ytRkRs+NFoNY1jhWR0Qo4opEim9qApVSxlouG61L++IEv7zhZ62ogpknTMQhkgpHJ4w146silaCh6vnmoNsTBt+eIuVE/7vhMQep4REpw5uVZR6PVUBsJDJAkJuyAkNu3Xva7KC4W22sjzSqHKWqzNeAmPxQ8Ywvu5PWQulOtA/LF9gAVsJjbKE7+ZsXVYvTfpZtEKfOduss8dB3lP8Xez6CbUzsv ubuntu@plana09.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQCsROY/kuvJRrw3yOos6aHDtveOLPgZ+mBs4ul/O6LTm0swWIpeiilmIeILba12z98XmkoqIGTAgZqcGx6FfNpwrOg8P2pdDg9YKT9YrdESlFZryHyu3Rjyn+lZcskMdHAoXhTUzRkHh7t9/vM5cuhq+BoO5+nAebtFCQ1mcn9w8jn6ZqnXkQiplB93UBmXqGKhbqnaGok6xJfYtV3NtmXOFBJ0keja0rOT4ylnSBExG3YBdZ4qSEaWVNeBtoDslu6K0hq5/mmNtZwJf2iXQWOkhfM3tVUbcMfwaGVEe77gzg3CeU0lT7ag1oJan9MAxzVBqOXO1ZS2h8w4zBrX7eYt ubuntu@plana39.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQCbo4KGzlqjC+4jdO3xTeMPDlEV6kI+ybIFMu0Hp/p4phefQbrjNRM5CngnRnrEhlrj7wLlrGEO7QceuIx3rTMlsprZlw+A6ZFAWdImzQuwIXSYUyMrb89LoENVJr3IylX1w1DLDkfHSNFeXmq/t0sl1LIpIs5H52dKfxuQvTMNVYOhVzchELrXY62TVMrv2WH2tKGoKFm57OsHlxaM79LBk0IKQfWDPbs4IYYCfDQ4ySS8jHCyjk7PGDhQV1K07CfjPAhriGKYamSCTnQHyfKkkun2Ue+CB+zPW26us0iA/Lj1mDsqICfi4uiIDkljPbOEnzuOn8WaVFF9FctarNM7 ubuntu@plana40.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDEwyNlwC9Utqf3PCjL2JR4wwDkzpdEJuW93DOW82vYVisYEGod454JwXeNkjqzTUk6tXeRoUM9f/C6sZS3LFgHcMYt6m0sxP8DC4qU+q0YxCw9zLY8bXKe4DDjijM62h/SnyqyOWIh9amGT7wRwZEHBV1BKvZbNxQIJ7ESkuKsk/tJfWKhq7dSw6E/+MZ4yQtXvTyaJ3pK96Hq2uoUkawv+FxXBrzG3FtTTYA8gqA1SIiV3erEIQuBK/WD74i5yK4rwpfGTo7jNc0V6wrwO1BKFj/OGjSC+2LSAkBgf8WLe6UL/dHr3bBEyzm0V4xMf5Iqb8JGvkaXNEfbFqzKC2Wv tasks: - internal.lock_machines: - 4 - plana - internal.save_config: null - internal.check_lock: null - internal.connect: null - internal.check_conflict: null - internal.check_ceph_data: null - internal.vm_setup: null - kernel: *id001 - internal.base: null - internal.archive: null - internal.coredump: null - internal.syslog: null - internal.timer: null - chef: null - clock.check: null - install: null - ceph: null - thrashosds: chance_down: 1.0 powercycle: true - rados: clients: - client.0 objects: 500 op_weights: delete: 50 read: 100 rollback: 50 snap_create: 50 snap_remove: 50 write: 100 ops: 4000
#5 Updated by Sage Weil almost 11 years ago
ubuntu@teuthology:/a/teuthology-2013-05-11_01:00:07-rados-next-testing-basic/11133$ cat orig.config.yaml kernel: kdb: true sha1: b5b09be30cf99f9c699e825629f02e3bce555d44 machine_type: plana nuke-on-error: true overrides: ceph: conf: mon: debug mon: 20 debug ms: 20 debug paxos: 20 fs: xfs log-whitelist: - slow request sha1: fd901056831586e8135e28c8f4ba9c2ec44dfcf6 s3tests: branch: next workunit: sha1: fd901056831586e8135e28c8f4ba9c2ec44dfcf6 roles: - - mon.0 - mon.1 - mon.2 - mds.0 - client.0 - - osd.0 - - osd.1 - - osd.2 tasks: - chef: null - clock.check: null - install: null - ceph: null - thrashosds: chance_down: 1.0 powercycle: true - rados: clients: - client.0 objects: 500 op_weights: delete: 50 read: 100 rollback: 50 snap_create: 50 snap_remove: 50 write: 100 ops: 4000
#6 Updated by Samuel Just almost 11 years ago
- Assignee set to Samuel Just
#7 Updated by Sage Weil almost 11 years ago
- Subject changed from assertion in ReadOp::_finish to osd powercycle triggers object corruption on xfs
#8 Updated by Sage Weil almost 11 years ago
- Status changed from New to In Progress
- Assignee changed from Samuel Just to Sage Weil
ubuntu@teuthology:/a/teuthology-2013-05-31_20:00:08-rados-cuttlefish-master-basic/28270
trying to reproduce this with logs and interactive-on-error so we can inspect the (corrupt?) xfs post-reboot.
#9 Updated by Sage Weil almost 11 years ago
- Priority changed from Urgent to Immediate
#10 Updated by Sage Weil almost 11 years ago
- File a.tar.gz added
two writes to the object, at offset A~B and C~D, then read the whole thing. the original write appears intact, but at A+B there are a few byte sof 0's op ot the block boundary and then about 30k of random garbage, then zeros until you get to offset C
currently theory is a stray write to a random fd, probably while the fd is sitting in the flusher queue. pushed wip-4976 to lseek to a magic offset and use pwrite instead so that we can look for garbage writes at that offset...
#11 Updated by Sage Weil almost 11 years ago
- Priority changed from Immediate to Urgent
this is looking more like an xfs bug to me.. sent something to the list.
i also think it is new in 3.9. need to try to reproduce using a 3.8 kernel.
#12 Updated by Tamilarasi muthamizhan almost 11 years ago
ubuntu@teuthology:/a/teuthology-2013-06-05_10:57:29-rados-cuttlefish-master-basic/31967
#13 Updated by Sage Weil almost 11 years ago
- Status changed from In Progress to Fix Under Review
the problem is that sync_file_range(2) and posix_fadvaise(..DONTNEED) break xfs's internal write and zero ordering. the sync_file_range is already gone from master; remove fadvise. for cuttlefish and bobtail, just remove these calls.
#14 Updated by Greg Farnum almost 11 years ago
What do you mean "remove fadvise"? And is this a known upstream issue?
#15 Updated by Sage Weil almost 11 years ago
- Status changed from Fix Under Review to Resolved