Project

General

Profile

Bug #24192

cluster [ERR] Corruption detected: object 2:f59d1934:::smithi14913526-5822:head is missing hash_info

Added by David Zafman almost 6 years ago. Updated over 5 years ago.

Status:
Duplicate
Priority:
Normal
Assignee:
Category:
-
Target version:
-
% Done:

0%

Source:
Tags:
Backport:
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Component(RADOS):
Pull request ID:
Crash signature (v1):
Crash signature (v2):

Description

davidz@teuthology:/a/dzafman-2018-05-18_11:36:58-rados-wip-zafman-testing-distro-basic-smithi/2549009

$ grep smithi14913526-5822 teuthology.log
2018-05-19T04:35:52.114 INFO:tasks.rados.rados.0.smithi149.stdout:5822:  writing smithi14913526-5822 from 633547 to 1268021 tid 1
2018-05-19T04:35:52.129 INFO:tasks.rados.rados.0.smithi149.stdout:5822:  writing smithi14913526-5822 from 1863448 to 2642823 tid 2
2018-05-19T04:35:52.129 INFO:tasks.rados.rados.0.smithi149.stdout:5822:  writing smithi14913526-5822 from 3135006 to 3583040 tid 3
2018-05-19T04:35:52.260 INFO:tasks.rados.rados.0.smithi149.stdout:5822:  finishing write tid 1 to smithi14913526-5822
2018-05-19T04:35:52.260 INFO:tasks.rados.rados.0.smithi149.stdout:5822:  finishing write tid 2 to smithi14913526-5822
2018-05-19T04:35:52.260 INFO:tasks.rados.rados.0.smithi149.stdout:5822:  finishing write tid 3 to smithi14913526-5822
2018-05-19T04:35:52.260 INFO:tasks.rados.rados.0.smithi149.stdout:5822:  finishing write tid 5 to smithi14913526-5822
2018-05-19T04:35:52.260 INFO:tasks.rados.rados.0.smithi149.stdout:5822:  finishing write tid 6 to smithi14913526-5822
2018-05-19T04:38:45.866 INFO:tasks.rados.rados.0.smithi149.stdout:9429:  finishing copy_from to smithi14913526-5822
2018-05-19T04:38:45.907 INFO:tasks.ceph.osd.4.smithi163.stderr:2018-05-19 04:38:45.906 7f0123440700 -1 log_channel(cluster) log [ERR] : Corruption detected: object 2:f59d1934:::smithi14913526-5822:head is missing hash_info
2018-05-19T04:38:45.922 INFO:tasks.ceph.osd.1.smithi149.stderr:2018-05-19 04:38:45.922 7f1385ab4700 -1 log_channel(cluster) log [ERR] : Corruption detected: object 2:f59d1934:::smithi14913526-5822:head is missing hash_info
2018-05-19T04:38:45.939 INFO:tasks.rados.rados.0.smithi149.stdout:9429:  finishing copy_from racing read to smithi14913526-5822
2018-05-19T04:39:16.704 INFO:tasks.ceph.osd.3.smithi149.stderr:2018-05-19 04:39:16.702 7f56378b6700 -1 log_channel(cluster) log [ERR] : 2.3s0 shard 1(3): soid 2:f59d1934:::smithi14913526-5822:head size 1916928 != size 1548288 from auth oi 2:f59d1934:::smithi14913526-5822:head(207'1398 client.4445.0:38291 dirty s 3092521 uv 364 alloc_hint [0 0 0]), size 1916928 != size 1548288 from shard 3(0)
2018-05-19T04:39:16.704 INFO:tasks.ceph.osd.3.smithi149.stderr:2018-05-19 04:39:16.702 7f56378b6700 -1 log_channel(cluster) log [ERR] : 2.3s0 shard 2(1): soid 2:f59d1934:::smithi14913526-5822:head size 1916928 != size 1548288 from auth oi 2:f59d1934:::smithi14913526-5822:head(207'1398 client.4445.0:38291 dirty s 3092521 uv 364 alloc_hint [0 0 0]), size 1916928 != size 1548288 from shard 3(0)
2018-05-19T04:39:16.704 INFO:tasks.ceph.osd.3.smithi149.stderr:2018-05-19 04:39:16.702 7f56378b6700 -1 log_channel(cluster) log [ERR] : 2.3s0 shard 4(2): soid 2:f59d1934:::smithi14913526-5822:head size 1916928 != size 1548288 from auth oi 2:f59d1934:::smithi14913526-5822:head(207'1398 client.4445.0:38291 dirty s 3092521 uv 364 alloc_hint [0 0 0]), size 1916928 != size 1548288 from shard 3(0)
2018-05-19T04:40:38.748 INFO:tasks.ceph.osd.3.smithi149.stderr:2018-05-19 04:40:38.745 7f56338ae700 -1 log_channel(cluster) log [ERR] : 2.3s0 shard 1(3): soid 2:f59d1934:::smithi14913526-5822:head size 1916928 != size 1548288 from auth oi 2:f59d1934:::smithi14913526-5822:head(207'1398 client.4445.0:38291 dirty s 3092521 uv 364 alloc_hint [0 0 0]), size 1916928 != size 1548288 from shard 3(0)
2018-05-19T04:40:38.748 INFO:tasks.ceph.osd.3.smithi149.stderr:2018-05-19 04:40:38.745 7f56338ae700 -1 log_channel(cluster) log [ERR] : 2.3s0 shard 2(1): soid 2:f59d1934:::smithi14913526-5822:head size 1916928 != size 1548288 from auth oi 2:f59d1934:::smithi14913526-5822:head(207'1398 client.4445.0:38291 dirty s 3092521 uv 364 alloc_hint [0 0 0]), size 1916928 != size 1548288 from shard 3(0)
2018-05-19T04:40:38.748 INFO:tasks.ceph.osd.3.smithi149.stderr:2018-05-19 04:40:38.745 7f56338ae700 -1 log_channel(cluster) log [ERR] : 2.3s0 shard 4(2): soid 2:f59d1934:::smithi14913526-5822:head size 1916928 != size 1548288 from auth oi 2:f59d1934:::smithi14913526-5822:head(207'1398 client.4445.0:38291 dirty s 3092521 uv 364 alloc_hint [0 0 0]), size 1916928 != size 1548288 from shard 3(0)
2018-05-19T04:41:18.868 INFO:tasks.ceph.osd.3.smithi149.stderr:2018-05-19 04:41:18.862 7f56378b6700 -1 log_channel(cluster) log [ERR] : 2.3s0 shard 1(3): soid 2:f59d1934:::smithi14913526-5822:head candidate had a read error, size 1916928 != size 1548288 from auth oi 2:f59d1934:::smithi14913526-5822:head(207'1398 client.4445.0:38291 dirty s 3092521 uv 364 alloc_hint [0 0 0]), size 1916928 != size 1548288 from shard 3(0)
2018-05-19T04:41:18.869 INFO:tasks.ceph.osd.3.smithi149.stderr:2018-05-19 04:41:18.862 7f56378b6700 -1 log_channel(cluster) log [ERR] : 2.3s0 shard 2(1): soid 2:f59d1934:::smithi14913526-5822:head candidate had a read error, size 1916928 != size 1548288 from auth oi 2:f59d1934:::smithi14913526-5822:head(207'1398 client.4445.0:38291 dirty s 3092521 uv 364 alloc_hint [0 0 0]), size 1916928 != size 1548288 from shard 3(0)
2018-05-19T04:41:18.869 INFO:tasks.ceph.osd.3.smithi149.stderr:2018-05-19 04:41:18.862 7f56378b6700 -1 log_channel(cluster) log [ERR] : 2.3s0 shard 4(2): soid 2:f59d1934:::smithi14913526-5822:head candidate had a read error, size 1916928 != size 1548288 from auth oi 2:f59d1934:::smithi14913526-5822:head(207'1398 client.4445.0:38291 dirty s 3092521 uv 364 alloc_hint [0 0 0]), size 1916928 != size 1548288 from shard 3(0)
2018-05-19T04:42:13.784 INFO:teuthology.orchestra.run.smithi149.stdout:2018-05-19 04:38:45.911300 osd.4 osd.4 172.21.15.163:6805/10909 165 : cluster [ERR] Corruption detected: object 2:f59d1934:::smithi14913526-5822:head is missing hash_info
2018-05-19T04:42:13.957 INFO:teuthology.orchestra.run.smithi149.stdout:2018-05-19 04:38:45.911300 osd.4 osd.4 172.21.15.163:6805/10909 165 : cluster [ERR] Corruption detected: object 2:f59d1934:::smithi14913526-5822:head is missing hash_info
2018-05-19 04:38:45.906 7f0123440700 10 osd.4 207 dequeue_op 0x55b7dd1d1880 prio 127 cost 0 latency 0.000142 MOSDECSubOpRead(2.3s2 207/206 ECSubRead(tid=20154, to_read={2:f59d1934:::smithi14913526-5822:head=0,1548288,8}, subchunks={2:f59d1934:::smithi14913526-5822:head=[0,1]}, attrs_to_read=)) v3 pg pg[2.3s2( v 207'1401 lc 155'1281 (0'0,207'1401] local-lis/les=206/207 n=1212 ec=20/20 lis/c 206/71 les/c/f 207/73/0 205/206/195) [3,2,4,1]/[3,2147483647,4,1]p3(0) r=2 lpr=206 pi=[71,206)/4 luod=0'0 crt=207'1401 active+remapped m=106 mbc={}]
2018-05-19 04:38:45.906 7f0123440700 10 osd.4 pg_epoch: 207 pg[2.3s2( v 207'1401 lc 155'1281 (0'0,207'1401] local-lis/les=206/207 n=1212 ec=20/20 lis/c 206/71 les/c/f 207/73/0 205/206/195) [3,2,4,1]/[3,2147483647,4,1]p3(0) r=2 lpr=206 pi=[71,206)/4 luod=0'0 crt=207'1401 active+remapped m=106 mbc={}] _handle_message: MOSDECSubOpRead(2.3s2 207/206 ECSubRead(tid=20154, to_read={2:f59d1934:::smithi14913526-5822:head=0,1548288,8}, subchunks={2:f59d1934:::smithi14913526-5822:head=[0,1]}, attrs_to_read=)) v3
2018-05-19 04:38:45.906 7f0123440700 10 osd.4 pg_epoch: 207 pg[2.3s2( v 207'1401 lc 155'1281 (0'0,207'1401] local-lis/les=206/207 n=1212 ec=20/20 lis/c 206/71 les/c/f 207/73/0 205/206/195) [3,2,4,1]/[3,2147483647,4,1]p3(0) r=2 lpr=206 pi=[71,206)/4 luod=0'0 crt=207'1401 active+remapped m=106 mbc={}] get_hash_info: Getting attr on 2:f59d1934:::smithi14913526-5822:head
2018-05-19 04:38:45.906 7f0123440700 10 osd.4 pg_epoch: 207 pg[2.3s2( v 207'1401 lc 155'1281 (0'0,207'1401] local-lis/les=206/207 n=1212 ec=20/20 lis/c 206/71 les/c/f 207/73/0 205/206/195) [3,2,4,1]/[3,2147483647,4,1]p3(0) r=2 lpr=206 pi=[71,206)/4 luod=0'0 crt=207'1401 active+remapped m=106 mbc={}] get_hash_info: not in cache 2:f59d1934:::smithi14913526-5822:head
2018-05-19 04:38:45.906 7f0123440700 10 osd.4 pg_epoch: 207 pg[2.3s2( v 207'1401 lc 155'1281 (0'0,207'1401] local-lis/les=206/207 n=1212 ec=20/20 lis/c 206/71 les/c/f 207/73/0 205/206/195) [3,2,4,1]/[3,2147483647,4,1]p3(0) r=2 lpr=206 pi=[71,206)/4 luod=0'0 crt=207'1401 active+remapped m=106 mbc={}] get_hash_info: found on disk, size 1916928
2018-05-19 04:38:45.906 7f0123440700  0 osd.4 pg_epoch: 207 pg[2.3s2( v 207'1401 lc 155'1281 (0'0,207'1401] local-lis/les=206/207 n=1212 ec=20/20 lis/c 206/71 les/c/f 207/73/0 205/206/195) [3,2,4,1]/[3,2147483647,4,1]p3(0) r=2 lpr=206 pi=[71,206)/4 luod=0'0 crt=207'1401 active+remapped m=106 mbc={}] get_hash_info: Mismatch of total_chunk_size 1548288
2018-05-19 04:38:45.906 7f0123440700  5 osd.4 pg_epoch: 207 pg[2.3s2( v 207'1401 lc 155'1281 (0'0,207'1401] local-lis/les=206/207 n=1212 ec=20/20 lis/c 206/71 les/c/f 207/73/0 205/206/195) [3,2,4,1]/[3,2147483647,4,1]p3(0) r=2 lpr=206 pi=[71,206)/4 luod=0'0 crt=207'1401 active+remapped m=106 mbc={}] handle_sub_read: No hinfo for 2:f59d1934:::smithi14913526-5822:head
$ grep "bluestore.*_do_trunc.*smithi14913526-5822:\|bluestore.*_do_write.*smithi14913526-5822:" ceph-osd.3.log
2018-05-19 04:36:02.514 7f563c0bf700 20 bluestore(/var/lib/ceph/osd/ceph-3) _do_write 0#2:f59d1934:::smithi14913526-5822:head# 0x0~1d4000 - have 0x0 (0) bytes fadvise_flags 0x20
2018-05-19 04:38:43.530 7f563c0bf700 20 bluestore(/var/lib/ceph/osd/ceph-3) _do_write 0#2:f59d1934:::smithi14913526-5822:head# 0x0~17a000 - have 0x0 (0) bytes fadvise_flags 0x0
2018-05-19 04:38:43.554 7f56338ae700 15 bluestore(/var/lib/ceph/osd/ceph-3) _do_truncate 2.3s0_head 0#2:f59d1934:::smithi14913526-5822:head#576 0x0
2018-05-19 04:38:44.530 7f56338ae700 15 bluestore(/var/lib/ceph/osd/ceph-3) _do_truncate 2.3s0_head 0#2:f59d1934:::smithi14913526-5822:head# 0x0
2018-05-19 04:38:45.678 7f563c0bf700 20 bluestore(/var/lib/ceph/osd/ceph-3) _do_write 0#2:f59d1934:::smithi14913526-5822:head# 0x0~17a000 - have 0x0 (0) bytes fadvise_flags 0x0
$ grep "bluestore.*_do_trunc.*smithi14913526-5822:\|bluestore.*_do_write.*smithi14913526-5822:" ceph-osd.1.log
2018-05-19 04:36:02.514 7f1381aac700 20 bluestore(/var/lib/ceph/osd/ceph-1) _do_write 3#2:f59d1934:::smithi14913526-5822:head# 0x0~1d4000 - have 0x0 (0) bytes fadvise_flags 0x20
2018-05-19 04:38:45.678 7f1385ab4700 20 bluestore(/var/lib/ceph/osd/ceph-1) _do_write 3#2:f59d1934:::smithi14913526-5822:head# 0x0~17a000 - have 0x1d4000 (1916928) bytes fadvise_flags 0x20
$ grep "bluestore.*_do_trunc.*smithi14913526-5822:\|bluestore.*_do_write.*smithi14913526-5822:" ceph-osd.4.log
2018-05-19 04:36:02.518 7f0123440700 20 bluestore(/var/lib/ceph/osd/ceph-4) _do_write 2#2:f59d1934:::smithi14913526-5822:head# 0x0~1d4000 - have 0x0 (0) bytes fadvise_flags 0x20
2018-05-19 04:38:45.682 7f0123440700 20 bluestore(/var/lib/ceph/osd/ceph-4) _do_write 2#2:f59d1934:::smithi14913526-5822:head# 0x0~17a000 - have 0x1d4000 (1916928) bytes fadvise_flags 0x20

Related issues

Duplicates RADOS - Bug #24597: FAILED assert(0 == "ERROR: source must exist") in FileStore::_collection_move_rename() Resolved 06/20/2018

History

#1 Updated by David Zafman almost 6 years ago

$ grep "rollback\|do_write\|truncate\|remove" 5822.prim.log
2018-05-19 04:36:02.514 7f563c0bf700 20 bluestore(/var/lib/ceph/osd/ceph-3) _do_write 0#2:f59d1934:::smithi14913526-5822:head# 0x0~1d4000 - have 0x0 (0) bytes fadvise_flags 0x20
2018-05-19 04:38:43.530 7f563c0bf700 20 bluestore(/var/lib/ceph/osd/ceph-3) _do_write 0#2:f59d1934:::smithi14913526-5822:head# 0x0~17a000 - have 0x0 (0) bytes fadvise_flags 0x0
2018-05-19 04:38:43.554 7f56338ae700 15 bluestore(/var/lib/ceph/osd/ceph-3) _remove 2.3s0_head 0#2:f59d1934:::smithi14913526-5822:head#576
2018-05-19 04:38:43.554 7f56338ae700 15 bluestore(/var/lib/ceph/osd/ceph-3) _do_truncate 2.3s0_head 0#2:f59d1934:::smithi14913526-5822:head#576 0x0
2018-05-19 04:38:43.554 7f56338ae700 10 bluestore(/var/lib/ceph/osd/ceph-3) _remove 2.3s0_head 0#2:f59d1934:::smithi14913526-5822:head#576 = 0
2018-05-19 04:38:44.526 7f56338ae700 10 _merge_object_divergent_entries: hoid 2:f59d1934:::smithi14913526-5822:head must be rolled back or recovered, attempting to rollback
2018-05-19 04:38:44.530 7f56338ae700 15 bluestore(/var/lib/ceph/osd/ceph-3) _remove 2.3s0_head 0#2:f59d1934:::smithi14913526-5822:head#
2018-05-19 04:38:44.530 7f56338ae700 15 bluestore(/var/lib/ceph/osd/ceph-3) _do_truncate 2.3s0_head 0#2:f59d1934:::smithi14913526-5822:head# 0x0
2018-05-19 04:38:44.530 7f56338ae700 10 bluestore(/var/lib/ceph/osd/ceph-3) _remove 2.3s0_head 0#2:f59d1934:::smithi14913526-5822:head# = 0
2018-05-19 04:38:45.678 7f563c0bf700 20 bluestore(/var/lib/ceph/osd/ceph-3) _do_write 0#2:f59d1934:::smithi14913526-5822:head# 0x0~17a000 - have 0x0 (0) bytes fadvise_flags 0x0
2018-05-19 04:38:45.686 7f56378b6700 10 _merge_object_divergent_entries: hoid 2:f59d1934:::smithi14913526-5822:head must be rolled back or recovered, attempting to rollback

#2 Updated by David Zafman almost 6 years ago

  • Assignee changed from David Zafman to Josh Durgin

#3 Updated by Josh Durgin over 5 years ago

  • Duplicates Bug #24597: FAILED assert(0 == "ERROR: source must exist") in FileStore::_collection_move_rename() added

#4 Updated by Josh Durgin over 5 years ago

  • Status changed from New to Duplicate

Also available in: Atom PDF