Description of problem: Running btrfsck on a volume that showed some errors results in a quick core dump Version-Release number of selected component (if applicable): btrfs-progs.x86_64 4.6.1-1.fc25 @anaconda How reproducible: Always Steps to Reproduce: 1. Run btrfsck /dev/sdb4 2. There is no step 2 Actual results: Abort, core dumped. I tried to get a core dump with ulimit -c unlimited, but I did not get it. The debugger shows the following stack trace: Program received signal SIGABRT, Aborted. 0x00007ffff6fa791f in raise () from /lib64/libc.so.6 (gdb) bt #0 0x00007ffff6fa791f in raise () from /lib64/libc.so.6 #1 0x00007ffff6fa951a in abort () from /lib64/libc.so.6 #2 0x0000555555579425 in add_tree_backref () #3 0x0000555555581819 in run_next_block.constprop () #4 0x0000555555582f55 in deal_root_from_list.constprop () #5 0x0000555555583c07 in check_chunks_and_extents () #6 0x0000555555585f05 in cmd_check () #7 0x0000555555563ddb in main () Expected results: Disk repair Additional info: The reason I ran btrfsck is that when running /dev/sdb4 as a boot disk, I had seen the following messages in dmesg (I rebooted on a secondary boot disk to run btrfsck): Mar 23 16:53:27 muse.dinechin.org kernel: BTRFS error (device sdb4): bad tree block start 11022913622198796681 52432896 Mar 23 16:53:27 muse.dinechin.org kernel: BTRFS error (device sdb4): bad tree block start 11022913622198796681 52432896 Mar 23 16:53:38 muse.dinechin.org kernel: BTRFS error (device sdb4): bad tree block start 11022913622198796681 52432896 Mar 23 16:53:38 muse.dinechin.org kernel: BTRFS error (device sdb4): bad tree block start 11022913622198796681 52432896 Mar 23 16:53:38 muse.dinechin.org kernel: BTRFS error (device sdb4): bad tree block start 11022913622198796681 52432896 Mar 23 16:53:38 muse.dinechin.org kernel: BTRFS error (device sdb4): bad tree block start 11022913622198796681 52432896 Mar 23 16:53:41 muse.dinechin.org kernel: BTRFS error (device sdb4): bad tree block start 11022913622198796681 52432896 Mar 23 16:53:41 muse.dinechin.org kernel: BTRFS error (device sdb4): bad tree block start 11022913622198796681 52432896 Mar 23 16:53:58 muse.dinechin.org kernel: BTRFS error (device sdb4): bad tree block start 11022913622198796681 52432896 Mar 23 16:53:58 muse.dinechin.org kernel: BTRFS error (device sdb4): bad tree block start 11022913622198796681 52432896 Mar 23 16:53:58 muse.dinechin.org kernel: BTRFS error (device sdb4): bad tree block start 11022913622198796681 52432896 Mar 23 16:53:58 muse.dinechin.org kernel: BTRFS error (device sdb4): bad tree block start 11022913622198796681 52432896
Any idea why I don't get a core dump after ulimit -c unlimited? Otherwise I could attach it (size permitting).
General btrfs-progs advice is "try a newer release" Can you grab the latest src.rpm out of rawhide, rebuild that, and give it a shot? thanks, -Eric
I lost another disk (failed its SMART self-test after an increasing number of bad sectors). The alternate boot disk was intended as a replacement for that failing disk, and I swapped them. So now the two disks are no longer in the same system. I will try again booting from an external disk, hopefully that will reproduce the problem. Otherwise, this will have to wait until I can shutdown both systems and swap the disks again.
I had yet another BTRFS corruption, this time on a brand new 3T disk, and I ruled out the disk as being bad (at least, it passes an extended SMART self-test). https://bugzilla.redhat.com/show_bug.cgi?id=1444821 I rebuilt btrfs-progs-4.10.1-1.fc25.x86_64.rpm from RawHiude sources, and I get: enabling repair mode Checking filesystem on /dev/sda4 UUID: 26a0c84c-d2ac-4da8-b880-684f2ea48a22 checking extents ERROR: add_tree_backref failed: File exists extent_io.c:143: insert_state: BUG_ON `end < start` triggered, value 1 btrfs check(+0x305a6)[0x556c478505a6] btrfs check(+0x307fd)[0x556c478507fd] btrfs check(set_extent_bits+0x256)[0x556c47850cc6] btrfs check(+0x6329b)[0x556c4788329b] btrfs check(cmd_check+0xb43)[0x556c47885143] btrfs check(main+0x80)[0x556c47837c80] /lib64/libc.so.6(__libc_start_main+0xf1)[0x7f4ed220a401] btrfs check(_start+0x2a)[0x556c47837d8a] Aborted (core dumped) That was booting from a live Fedora25 USB. I am constructing another external boot disk to investigate this issue more thoroughly.
Running under gdb without the --repair option gives: root 258 inode 285735 errors 2001, no inode item, link count wrong unresolved ref dir 362 index 44 namelen 11 name fedora.json filetype 1 errors 4, no inode ref root 258 inode 285736 errors 2001, no inode item, link count wrong unresolved ref dir 472 index 42 namelen 10 name gnome.json filetype 1 errors 4, no inode ref root 258 inode 285737 errors 2001, no inode item, link count wrong unresolved ref dir 481 index 41 namelen 18 name extensions-web.xml filetype 1 errors 4, no inode ref root 258 inode 285738 errors 2001, no inode item, link count wrong unresolved ref dir 389 index 44 namelen 9 name odrs.json filetype 1 errors 4, no inode ref root 258 inode 285759 errors 2001, no inode item, link count wrong unresolved ref dir 281 index 648 namelen 13 name notifications filetype 1 errors 4, no inode ref root 258 inode 285768 errors 2001, no inode item, link count wrong unresolved ref dir 257 index 366 namelen 11 name .Xauthority filetype 1 errors 4, no inode ref root 258 inode 287091 errors 2001, no inode item, link count wrong unresolved ref dir 521 index 38 namelen 30 name .saves-7375-muse.dinechin.org~ filetype 1 errors 4, no inode ref root 258 inode 287119 errors 2001, no inode item, link count wrong unresolved ref dir 257 index 368 namelen 8 name .lesshst filetype 1 errors 4, no inode ref root 258 inode 289021 errors 2001, no inode item, link count wrong unresolved ref dir 266 index 76 namelen 13 name gstreamer-1.0 filetype 2 errors 4, no inode ref root 258 inode 289997 errors 2001, no inode item, link count wrong unresolved ref dir 3058 index 16 namelen 10 name cscope.out filetype 1 errors 4, no inode ref ERROR: errors found in fs roots found 1124075982849 bytes used, error(s) found total csum bytes: 1094304808 total tree bytes: 2285043712 total fs tree bytes: 797573120 total extent tree bytes: 258555904 btree space waste bytes: 294399420 file data blocks allocated: 72350215241728 referenced 1037659140096
Running under the debugger (gdb) r --repair /dev/sda4 Starting program: /usr/sbin/btrfsck --repair /dev/sda4 [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib64/libthread_db.so.1". enabling repair mode Checking filesystem on /dev/sda4 UUID: 26a0c84c-d2ac-4da8-b880-684f2ea48a22 checking extents ERROR: add_tree_backref failed: File exists extent_io.c:143: insert_state: BUG_ON `end < start` triggered, value 1 btrfs check(+0x30596)[0x555555584596] btrfs check(+0x307ed)[0x5555555847ed] btrfs check(set_extent_bits+0x256)[0x555555584cb6] btrfs check(+0x6328b)[0x5555555b728b] btrfs check(cmd_check+0xb43)[0x5555555b9133] btrfs check(main+0x80)[0x55555556bc70] /lib64/libc.so.6(__libc_start_main+0xf1)[0x7ffff6f92401] btrfs check(_start+0x2a)[0x55555556bd7a] Program received signal SIGABRT, Aborted. __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:58 58 } Missing separate debuginfos, use: dnf debuginfo-install libgcc-6.3.1-1.fc25.x86_64 (gdb) up #1 0x00007ffff6fa952a in __GI_abort () at abort.c:89 89 raise (SIGABRT); (gdb) #2 0x00005555555845aa in bugon_trace ( assertion=assertion@entry=0x5555555d5593 "end < start", func=func@entry=0x5555555d56f8 <__func__.9791> "insert_state", line=line@entry=143, val=val@entry=1, filename=0x5555555d5577 "extent_io.c") at kerncompat.h:115 115 abort(); (gdb) #3 0x00005555555847ed in bugon_trace (val=1, line=143, func=<synthetic pointer>, filename=0x5555555d5577 "extent_io.c", assertion=0x5555555d5593 "end < start") at extent_io.c:152 152 } (gdb) #4 insert_state (tree=tree@entry=0x7fffffffdba0, state=state@entry=0x55557eb12010, start=start@entry=52428800, end=end@entry=52428799, bits=bits@entry=1) at extent_io.c:143 143 BUG_ON(end < start); (gdb) #5 0x0000555555584cb6 in set_extent_bits (tree=0x7fffffffdba0, start=52428800, end=52428799, bits=bits@entry=1) at extent_io.c:310 310 err = insert_state(tree, prealloc, start, end, bits); (gdb) #6 0x0000555555584d9a in set_extent_dirty (tree=<optimized out>, start=<optimized out>, end=<optimized out>) at extent_io.c:414 414 return set_extent_bits(tree, start, end, EXTENT_DIRTY); (gdb) #7 0x00005555555b728b in check_extent_refs (extent_cache=0x7fffffffda60, root=0x55555587d570) at cmds-check.c:9255 9255 set_extent_dirty(root->fs_info->excluded_extents, (gdb) #8 check_chunks_and_extents (root=root@entry=0x55555587d570) at cmds-check.c:9945 9945 ret = check_extent_refs(root, &extent_cache); (gdb) #9 0x00005555555b9133 in cmd_check (argc=<optimized out>, argv=<optimized out>) at cmds-check.c:12961 12961 ret = check_chunks_and_extents(root); (gdb) #10 0x000055555556bc70 in main (argc=3, argv=0x7fffffffe328) at btrfs.c:246 246 ret = cmd->fn(argc, argv); (gdb)
Second run under debugger gives me a slightly different result: Program received signal SIGSEGV, Segmentation fault. list_del (entry=0x555555db0420) at /usr/src/debug/btrfs-progs-v4.10.1/kernel-lib/list.h:125 125 __list_del(entry->prev, entry->next); (gdb) bt #0 list_del (entry=0x555555db0420) at /usr/src/debug/btrfs-progs-v4.10.1/kernel-lib/list.h:125 #1 free_all_extent_backrefs (rec=0x555555db0350) at cmds-check.c:5386 #2 maybe_free_extent_rec (extent_cache=0x7fffffffd990, rec=0x555555db0350) at cmds-check.c:5417 #3 0x00005555555b308f in check_block (flags=<optimized out>, buf=0x55557b87cdf0, extent_cache=0x7fffffffd990, root=0x55555587d570) at cmds-check.c:5851 #4 run_next_block (root=root@entry=0x55555587d570, bits=bits@entry=0x555555884170, last=last@entry=0x7fffffffd738, pending=pending@entry=0x7fffffffd9b0, seen=seen@entry=0x7fffffffd9a0, reada=reada@entry=0x7fffffffd9c0, nodes=0x7fffffffd9d0, extent_cache=0x7fffffffd990, chunk_cache=0x7fffffffd980, dev_cache=0x7fffffffd970, block_group_cache=0x7fffffffda80, dev_extent_cache=0x7fffffffdaa0, ri=0x55555587d820, bits_nr=1024) at cmds-check.c:7690 #5 0x00005555555b4b6d in deal_root_from_list (list=list@entry=0x7fffffffda00, root=root@entry=0x55555587d570, bits=bits@entry=0x555555884170, pending=pending@entry=0x7fffffffd9b0, seen=seen@entry=0x7fffffffd9a0, reada=reada@entry=0x7fffffffd9c0, nodes=0x7fffffffd9d0, extent_cache=0x7fffffffd990, chunk_cache=0x7fffffffd980, dev_cache=0x7fffffffd970, block_group_cache=0x7fffffffda80, dev_extent_cache=0x7fffffffdaa0, bits_nr=1024) at cmds-check.c:9751 #6 0x00005555555b5805 in check_chunks_and_extents (root=root@entry=0x55555587d570) at cmds-check.c:9918 #7 0x00005555555b9133 in cmd_check (argc=<optimized out>, argv=<optimized out>) at cmds-check.c:12961 #8 0x000055555556bc70 in main (argc=3, argv=0x7fffffffe258) at btrfs.c:246 (gdb)
Back tracking the problem to what seems to be an inconsistent state in function check_extent_refs. The cause of the assert 'end < start' is from: while(cache) { rec = container_of(cache, struct extent_record, cache); set_extent_dirty(root->fs_info->excluded_extents, rec->start, rec->start + rec->max_size - 1); cache = next_cache_extent(cache); } In that case, rec->max_size is 0, so that triggere the assert. In addition, the cache with the same start has a size of 1, which seems incompatible with max_size = 0. The complete value of 'rec' is: (gdb) p *rec $10 = { backrefs = { next = 0x555556490100, prev = 0x555556490100 }, dups = { next = 0x555556490040, prev = 0x555556490040 }, list = { next = 0x555556490050, prev = 0x555556490050 }, cache = { rb_node = { __rb_parent_color = 93824996670721, rb_right = 0x0, rb_left = 0x0 }, objectid = 0, start = 52428800, size = 1 }, parent_key = { objectid = 0, type = 0 '\000', offset = 0 }, start = 52428800, max_size = 0, nr = 1, refs = 0, extent_item_refs = 0, generation = 0, parent_generation = 0, info_objectid = 0, num_duplicates = 0, info_level = 0 '\000', flag_block_full_backref = 2, found_rec = 0, content_checked = 0, owner_ref_checked = 0, is_root = 0, metadata = 1, bad_full_backref = 0, crossing_stripes = 0, wrong_chunk_type = 0 }
The same issue also exists on master branch.
Honestly, I'd suggest reporting this issue and your triage on the upstream list... Josef doesn't really pay attention to Fedora anymore, and I am unlikely to have time to dig into this any time soon. With the reproducer and your debugging, upstream developers may be quite interested. Thanks, -Eric
Added some instrumentation using a flight recorder, see https://github.com/kdave/btrfs-progs/compare/master...c3d:rhbz1435567. This instrumentation shows that we do insert a max_size of 0 in add_extent_rec_nolookup. 78657 [1.837787:0x44f023] MAX_SIZE_ZERO: Set max size 0 for rec 0x138a030 from tmpl 0x7fffffffcf70 This is indeed the failing rec in check_extent_refs: #6 0x000000000045c529 in check_extent_refs (extent_cache=0x7fffffffdb30, root=0x777570) at cmds-check.c:9322 warning: Source file is more recent than executable. 9322 RECORD(EXTENTS, "Container extent record %p for cache %p start %lu max_size %lu", rec, cache, rec->start, rec->max_size); (gdb) p rec $1 = (struct extent_record *) 0x138a030
I dig a bit deeper. We set rec->max_size = 0 in add_extent_rec_nolookup called from add_tree_backref, where we cleared the extent_record tmpl with a memset, so indeed, max_size is 0. However, we immediately after that do a lookup_cache_extent with a size of 1. So I wonder if at that stage, we should not set max_size to 1 for the newly created extent record. I tried that, but then I hit something else: *** Error in `btrfs check': double free or corruption (!prev): 0x0000000007d9c430 *** ======= Backtrace: ========= /lib64/libc.so.6(+0x7925b)[0x7ffff6feb25b] /lib64/libc.so.6(+0x828ea)[0x7ffff6ff48ea] /lib64/libc.so.6(cfree+0x4c)[0x7ffff6ff831c] btrfs check[0x44d784] btrfs check[0x4531ac] btrfs check[0x45b24b] btrfs check[0x45b743] btrfs check[0x45c2b1] btrfs check(cmd_check+0xcad)[0x4602d4] btrfs check(main+0x8b)[0x40b7fb] /lib64/libc.so.6(__libc_start_main+0xf1)[0x7ffff6f92401] btrfs check(_start+0x2a)[0x40b4ba] ======= Memory map: ======== 00400000-004a4000 r-xp 00000000 08:35 25167142 /home/ddd/Work/btrfs-progs/btrfs 006a4000-006a8000 r--p 000a4000 08:35 25167142 /home/ddd/Work/btrfs-progs/btrfs 006a8000-006fb000 rw-p 000a8000 08:35 25167142 /home/ddd/Work/btrfs-progs/btrfs 006fb000-316a6000 rw-p 00000000 00:00 0 [heap] 7ffff0000000-7ffff0021000 rw-p 00000000 00:00 0 7ffff0021000-7ffff4000000 ---p 00000000 00:00 0 7ffff6d5b000-7ffff6d71000 r-xp 00000000 08:33 3156890 /usr/lib64/libgcc_s-6.3.1-20161221.so.1 7ffff6d71000-7ffff6f70000 ---p 00016000 08:33 3156890 /usr/lib64/libgcc_s-6.3.1-20161221.so.1 7ffff6f70000-7ffff6f71000 r--p 00015000 08:33 3156890 /usr/lib64/libgcc_s-6.3.1-20161221.so.1 7ffff6f71000-7ffff6f72000 rw-p 00016000 08:33 3156890 /usr/lib64/libgcc_s-6.3.1-20161221.so.1 7ffff6f72000-7ffff712f000 r-xp 00000000 08:33 3154711 /usr/lib64/libc-2.24.so 7ffff712f000-7ffff732e000 ---p 001bd000 08:33 3154711 /usr/lib64/libc-2.24.so 7ffff732e000-7ffff7332000 r--p 001bc000 08:33 3154711 /usr/lib64/libc-2.24.so 7ffff7332000-7ffff7334000 rw-p 001c0000 08:33 3154711 /usr/lib64/libc-2.24.so 7ffff7334000-7ffff7338000 rw-p 00000000 00:00 0 7ffff7338000-7ffff7350000 r-xp 00000000 08:33 3155302 /usr/lib64/libpthread-2.24.so 7ffff7350000-7ffff7550000 ---p 00018000 08:33 3155302 /usr/lib64/libpthread-2.24.so 7ffff7550000-7ffff7551000 r--p 00018000 08:33 3155302 /usr/lib64/libpthread-2.24.so 7ffff7551000-7ffff7552000 rw-p 00019000 08:33 3155302 /usr/lib64/libpthread-2.24.so 7ffff7552000-7ffff7556000 rw-p 00000000 00:00 0 7ffff7556000-7ffff7578000 r-xp 00000000 08:33 3155132 /usr/lib64/liblzo2.so.2.0.0 7ffff7578000-7ffff7777000 ---p 00022000 08:33 3155132 /usr/lib64/liblzo2.so.2.0.0 7ffff7777000-7ffff7778000 r--p 00021000 08:33 3155132 /usr/lib64/liblzo2.so.2.0.0 7ffff7778000-7ffff7779000 rw-p 00000000 00:00 0 7ffff7779000-7ffff778e000 r-xp 00000000 08:33 3155608 /usr/lib64/libz.so.1.2.8 7ffff778e000-7ffff798d000 ---p 00015000 08:33 3155608 /usr/lib64/libz.so.1.2.8 7ffff798d000-7ffff798e000 r--p 00014000 08:33 3155608 /usr/lib64/libz.so.1.2.8 7ffff798e000-7ffff798f000 rw-p 00015000 08:33 3155608 /usr/lib64/libz.so.1.2.8 7ffff798f000-7ffff79cc000 r-xp 00000000 08:33 3153511 /usr/lib64/libblkid.so.1.1.0 7ffff79cc000-7ffff7bcc000 ---p 0003d000 08:33 3153511 /usr/lib64/libblkid.so.1.1.0 7ffff7bcc000-7ffff7bd0000 r--p 0003d000 08:33 3153511 /usr/lib64/libblkid.so.1.1.0 7ffff7bd0000-7ffff7bd1000 rw-p 00041000 08:33 3153511 /usr/lib64/libblkid.so.1.1.0 7ffff7bd1000-7ffff7bd2000 rw-p 00000000 00:00 0 7ffff7bd2000-7ffff7bd6000 r-xp 00000000 08:33 3154270 /usr/lib64/libuuid.so.1.3.0 7ffff7bd6000-7ffff7dd5000 ---p 00004000 08:33 3154270 /usr/lib64/libuuid.so.1.3.0 7ffff7dd5000-7ffff7dd6000 r--p 00003000 08:33 3154270 /usr/lib64/libuuid.so.1.3.0 7ffff7dd6000-7ffff7dd7000 rw-p 00000000 00:00 0 7ffff7dd7000-7ffff7dfc000 r-xp 00000000 08:33 3154536 /usr/lib64/ld-2.24.so 7ffff7fdb000-7ffff7fe0000 rw-p 00000000 00:00 0 7ffff7ff5000-7ffff7ff8000 rw-p 00000000 00:00 0 7ffff7ff8000-7ffff7ffa000 r--p 00000000 00:00 0 [vvar] 7ffff7ffa000-7ffff7ffc000 r-xp 00000000 00:00 0 [vdso] 7ffff7ffc000-7ffff7ffd000 r--p 00025000 08:33 3154536 /usr/lib64/ld-2.24.so 7ffff7ffd000-7ffff7ffe000 rw-p 00026000 08:33 3154536 /usr/lib64/ld-2.24.so 7ffff7ffe000-7ffff7fff000 rw-p 00000000 00:00 0 7ffffffde000-7ffffffff000 rw-p 00000000 00:00 0 [stack] ffffffffff600000-ffffffffff601000 r-xp 00000000 00:00 0 [vsyscall]
Again, I would suggest reporting all this on the linux-btrfs mailing list. Thanks, -Eric
(In reply to Eric Sandeen from comment #13) > Again, I would suggest reporting all this on the linux-btrfs mailing list. Sorry, failed to reply to your earlier comment. I did: https://www.mail-archive.com/linux-btrfs@vger.kernel.org/msg63526.html. No response so far, so I keep digging, because there's something really not acceptable about filesystem corruptions ;-) And since I put a pointer to this BZ, I may as well update what I find in case someone decides to help.
We find our friend 52432896 again as the root cause for the message "file exists": Breakpoint 1, add_tree_backref (extent_cache=extent_cache@entry=0x7fffffffdb30, bytenr=bytenr@entry=52445184, parent=parent@entry=0, root=2, found_ref=found_ref@entry=0) at cmds-check.c:6240 6240 return -EEXIST; (gdb) p rec $7 = (struct extent_record *) 0x889cd0 (gdb) p rec->start $8 = 52432896 (gdb) p rec->bytenr There is no member named bytenr. (gdb) p bytenr $9 = 52445184 Not too surprisingly, it's also in the original dmesg log for the disk >crash (https://bugzilla.redhat.com/attachment.cgi?id=1273572): [525761.195108] btree_readpage_end_io_hook: 2 callbacks suppressed [525761.195114] BTRFS error (device sda4): bad tree block start 11022913622198796681 52432896 [525761.203698] BTRFS error (device sda4): bad tree block start 11022913622198796681 52432896 (some stuff removed here) [525970.013825] BTRFS error (device sda4): unable to find ref byte nr 52432896 parent 0 root 2 owner 0 offset 0
This message is a reminder that Fedora 25 is nearing its end of life. Approximately 4 (four) weeks from now Fedora will stop maintaining and issuing updates for Fedora 25. It is Fedora's policy to close all bug reports from releases that are no longer maintained. At that time this bug will be closed as EOL if it remains open with a Fedora 'version' of '25'. Package Maintainer: If you wish for this bug to remain open because you plan to fix it in a currently maintained version, simply change the 'version' to a later Fedora version. Thank you for reporting this issue and we are sorry that we were not able to fix it before Fedora 25 is end of life. If you would still like to see this bug fixed and are able to reproduce it against a later version of Fedora, you are encouraged change the 'version' to a later Fedora version prior this bug is closed as described in the policy above. Although we aim to fix as many bugs as possible during every release's lifetime, sometimes those efforts are overtaken by events. Often a more recent Fedora release includes newer upstream software that fixes bugs or makes them obsolete.
Fedora 25 changed to end-of-life (EOL) status on 2017-12-12. Fedora 25 is no longer maintained, which means that it will not receive any further security or bug fix updates. As a result we are closing this bug. If you can reproduce this bug against a currently maintained version of Fedora please feel free to reopen this bug against that version. If you are unable to reopen this bug, please file a new report against the current release. If you experience problems, please add a comment to this bug. Thank you for reporting this bug and we are sorry it could not be fixed.