koverstreet / bcachefs

Other
686 stars 71 forks source link

fsck counted i_sectors wrong for inode, internal_fsck_err #745

Closed g2p closed 1 day ago

g2p commented 1 month ago

Got this error when running fsck with fix_errors, dumping metadata now

bcachefs (99…): check_extents...
bcachefs (99…): fsck counted i_sectors wrong for inode 738202108:4294967295: got 0 should be 10352
bcachefs (99…): check_extent(): error internal_fsck_err
bcachefs (99…): bch2_check_extents(): error internal_fsck_err
bcachefs (99…): bch2_fs_recovery(): error internal_fsck_err
bcachefs (99…): bch2_fs_start(): error starting filesystem internal_fsck_err
bcachefs (99…): shutting down

Had no urgent reason to fsck (no significant corruption before), just wanted to check lru entries, fix accounting issues after an upgrade and make sure it didn't oom anymore.

This was in-kernel fsck from 3cf7e1146e501249d73b9fb08766cd8d4a93e8e4 (recent bcachefs/master) merged with v6.11-rc7.

show-super ``` Device: (unknown device) External UUID: 9986b9d8-9f64-43c3-9a1d-cd397dcf3643 Internal UUID: 8c62e0f5-da29-4f90-b500-a08bd80af1c5 Magic number: c68573f6-66ce-90a9-d96a-60cf803df7ef Device index: 0 Label: Down Version: 1.12: rebalance_work_acct_fix Version upgrade complete: 1.12: rebalance_work_acct_fix Oldest version on disk: 0.27: fragmentation_lru Created: Sun Mar 5 10:42:51 2023 Sequence number: 766 Time of last write: Mon Sep 9 16:46:57 2024 Superblock size: 5.29 KiB/1.00 MiB Clean: 0 Devices: 2 Sections: members_v1,crypt,replicas_v0,disk_groups,clean,journal_seq_blacklist,journal_v2,counters,members_v2,errors,ext,downgrade Features: lz4,zstd,journal_seq_blacklist_v3,reflink,new_siphash,inline_data,new_extent_overwrite,btree_ptr_v2,extents_above_btree_updates,btree_updates_journalled,reflink_inline_data,new_varint,journal_no_flush,alloc_v2,extents_across_btree_nodes Compat features: alloc_info,alloc_metadata,extents_above_btree_updates_done,bformat_overflow_done Options: block_size: 4.00 KiB btree_node_size: 256 KiB errors: continue [fix_safe] panic ro metadata_replicas: 1 data_replicas: 1 metadata_replicas_required: 1 data_replicas_required: 1 encoded_extent_max: 64.0 KiB metadata_checksum: none [crc32c] crc64 xxhash data_checksum: none [crc32c] crc64 xxhash compression: lz4 background_compression: zstd str_hash: crc32c crc64 [siphash] metadata_target: none foreground_target: ssd background_target: hdd promote_target: ssd erasure_code: 0 inodes_32bit: 1 shard_inode_numbers: 1 inodes_use_key_cache: 1 gc_reserve_percent: 5 gc_reserve_bytes: 0 B root_reserve_percent: 0 wide_macs: 0 promote_whole_extents: 1 acl: 1 usrquota: 0 grpquota: 0 prjquota: 0 journal_flush_delay: 1000 journal_flush_disabled: 0 journal_reclaim_delay: 100 journal_transaction_names: 1 allocator_stuck_timeout: 30 version_upgrade: [compatible] incompatible none nocow: 0 members_v2 (size 448): Device: 0 Label: hdd (0) UUID: c75e08b9-b199-4daa-a17a-ac61aafee6cc Size: 11.6 TiB read errors: 0 write errors: 0 checksum errors: 0 seqread iops: 0 seqwrite iops: 0 randread iops: 0 randwrite iops: 0 Bucket size: 512 KiB First bucket: 0 Buckets: 24225784 Last mount: Mon Sep 9 16:22:39 2024 Last superblock write: 766 State: rw Data allowed: journal,btree,user Has data: journal,btree,user Btree allocated bitmap blocksize: 512 MiB Btree allocated bitmap: 0000000000000000000000001111111111111111111111111111111111111111 Durability: 1 Discard: 0 Freespace initialized: 1 Device: 2 Label: ssd (1) UUID: 94af33ae-cd3b-4be1-babf-22f3eeac2530 Size: 128 GiB read errors: 0 write errors: 0 checksum errors: 0 seqread iops: 0 seqwrite iops: 0 randread iops: 0 randwrite iops: 0 Bucket size: 512 KiB First bucket: 0 Buckets: 262144 Last mount: Mon Sep 9 16:22:39 2024 Last superblock write: 766 State: rw Data allowed: journal,btree,user Has data: journal,btree,user,cached Btree allocated bitmap blocksize: 4.00 MiB Btree allocated bitmap: 1111111111011101111111111110010110111011011111111001110111011111 Durability: 1 Discard: 1 Freespace initialized: 1 errors (size 72): accounting_mismatch 9 Mon Sep 9 16:46:53 2024 alloc_key_fragmentation_lru_wrong 20 Fri Jul 12 10:35:17 2024 accounting_key_junk_at_end 72 Sun Aug 11 10:32:56 2024 accounting_key_replicas_nr_devs_0 28 Sun Aug 11 10:32:56 2024 ```

Rest of the fsck log follows, extents_to_backpointers progress was also strange. Ignore the fff… lines which were another bcachefs filesystem being checked at the same time; Ctrl-F 990% then scroll to end.

fsck output https://sebsauvage.net/paste/?e2e52aca8ac03f6b#1WN7jtBK4akf9YtO70bzRCeyQ6ueI60bk4paBwZ3CYg=
g2p commented 1 month ago

I've tried to reproduce, but didn't get the nonsensical progress of extents_to_backpointers's first slice going to 990%, or the fsck assert. I don't know if it needs another concurrent in-kernel fsck to reproduce, or the exact same extents_to_backpointers batch size.

find -inum 738202108 found the file in good health with the expected contents.

grep -A30 738202108 /sys/kernel/debug/bcachefs/9986b9d8-9f64-43c3-9a1d-cd397dcf3643/btrees/inodes/keys 
u64s 20 type inode_v3 0:738202108:U32_MAX len 0 ver 0: 
  mode=100644
  flags=(15300000)
  journal_seq=23751972
  bi_size=5299061
  bi_sectors=10352
  bi_version=0
  bi_atime=20429319974314121
  bi_ctime=182905176609055
  bi_mtime=18184195279177480749
  bi_otime=66327931944888
  bi_uid=1000
  bi_gid=1000
  bi_nlink=1
  bi_generation=0
  bi_dev=0
  bi_data_checksum=0
  bi_compression=0
  bi_project=0
  bi_background_compression=0
  bi_data_replicas=0
  bi_promote_target=0
  bi_foreground_target=0
  bi_background_target=0
  bi_erasure_code=0
  bi_fields_set=0
  bi_dir=738215108
  bi_dir_offset=2712236950493384615
  bi_subvol=0
  bi_parent_subvol=0
  bi_nocow=0
koverstreet commented 1 day ago

this turned out to be caused by an incorrectly handled transaction restart, it's fixed now