Bug 953443

Created attachment 737217 [details]
File: dmesg

Description of problem:
I tried mounting the fs as

[root@mail2 ~]# mount -onospace_cache /dev/mapper/sda3 /var/tmp/recover/

please refer https://bugzilla.redhat.com/show_bug.cgi?id=953443

please let me know, how may i mount the fs, it is urgent, thanks

[root@mail2 ~]# btrfs fi df /
Data: total=17.00GB, used=14.71GB
System, RAID1: total=32.00MB, used=4.00KB
Metadata, RAID1: total=2.00GB, used=937.26MB

[root@mail2 ~]# btrfs fi df /home/vikram/
Data: total=17.00GB, used=14.71GB
System, RAID1: total=32.00MB, used=4.00KB
Metadata, RAID1: total=2.00GB, used=937.33MB

[root@mail2 ~]# btrfs fi df /var/tmp/recover/
Data: total=17.00GB, used=14.71GB
System, RAID1: total=32.00MB, used=4.00KB
Metadata, RAID1: total=2.00GB, used=937.33MB

[root@mail2 ~]# btrfs filesystem show
failed to read /dev/sr0
Label: 'Vikram'  uuid: 0809b072-35f3-4866-92b8-af4772b23ed6
        Total devices 2 FS bytes used 81.30GB
        devid    1 size 158.03GB used 157.02GB path /dev/dm-1
        devid    2 size 157.00GB used 157.00GB path /dev/dm-0

Label: 'fedora_mail2'  uuid: d2b3420c-99c1-44cc-a922-ac266072c7fb
        Total devices 2 FS bytes used 15.62GB
        devid    2 size 73.51GB used 11.03GB path /dev/sdb6
        devid    3 size 73.30GB used 10.03GB path /dev/sda2

Btrfs Btrfs v0.19

Version-Release number of selected component:
kernel

Additional info:
cmdline:        BOOT_IMAGE=/vmlinuz-3.8.7-201.fc18.x86_64 root=UUID=d2b3420c-99c1-44cc-a922-ac266072c7fb ro rootflags=subvol=root rd.md=0 rd.lvm=0 rd.dm=0 rd.luks=0 vconsole.keymap=us rhgb quiet LANG=en_US.UTF-8
kernel:         3.8.7-201.fc18.x86_64 #1 Hewlett-Packard HP dx2480 MT(FX801PA
type:           Kerneloops
ureports_counter: 1

Truncated backtrace:
kernel BUG at fs/btrfs/free-space-cache.c:1542!
invalid opcode: 0000 [#1] SMP 
Modules linked in: fuse dm_crypt nf_conntrack_netbios_ns nf_conntrack_broadcast ipt_MASQUERADE ip6table_mangle ip6t_REJECT nf_conntrack_ipv6 nf_defrag_ipv6 iptable_nat nf_nat_ipv4 nf_nat iptable_mangle nf_conntrack_ipv4 nf_defrag_ipv4 xt_conntrack nf_conntrack ebtable_filter ebtables ip6table_filter ip6_tables be2iscsi iscsi_boot_sysfs bnx2i cnic it87 hwmon_vid uio cxgb4i cxgb4 cxgb3i cxgb3 mdio libcxgbi ib_iser rdma_cm ib_addr iw_cm ib_cm ib_sa ib_mad ib_core iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi snd_hda_codec_realtek snd_hda_intel snd_hda_codec r8169 snd_hwdep coretemp snd_seq iTCO_wdt snd_seq_device ppdev snd_pcm iTCO_vendor_support 3c59x snd_page_alloc mii microcode snd_timer snd lpc_ich soundcore i2c_i801 mfd_core parport_pc parport binfmt_misc uinput btrfs zlib_deflate libcrc32c i915 video i2c_algo_bit drm_kms_helper drm i2c_core
CPU 0 
Pid: 2685, comm: mount Not tainted 3.8.7-201.fc18.x86_64 #1 Hewlett-Packard HP dx2480 MT(FX801PA)/0B08h
RIP: 0010:[<ffffffffa0179e47>]  [<ffffffffa0179e47>] remove_from_bitmap+0x1b7/0x1d0 [btrfs]
RSP: 0018:ffff8800581e36e8  EFLAGS: 00010287
RAX: 00000004c1974000 RBX: ffff880063908c00 RCX: ffff88005806a7e4
RDX: 0000000000002000 RSI: 0000000000008000 RDI: 0000000000000280
RBP: ffff8800581e3738 R08: ffff880093e2afb0 R09: 0000000000007d80
R10: ffffffffa0125880 R11: 0000000000000000 R12: ffff88005806a7c0
R13: ffff8800581e3760 R14: ffff8800581e3758 R15: 00000004c1c00000
FS:  00007fefe5631840(0000) GS:ffff8800bf200000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
CR2: 00007f0df6290a08 CR3: 0000000054022000 CR4: 00000000000007f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Process mount (pid: 2685, threadinfo ffff8800581e2000, task ffff88005eb18000)
Stack:
 ffff88006307ec00 ffff88005806a7e4 00000004c1983000 0000000000002000
 ffff8800581e3738 ffff88005806a7c0 ffff88005806a7e4 0000000000000001
 ffff88006307ec00 ffff8800b746c000 ffff8800581e3788 ffffffffa017bc33
Call Trace:
 [<ffffffffa017bc33>] btrfs_remove_free_space+0x53/0x280 [btrfs]
 [<ffffffffa012e0bf>] btrfs_alloc_logged_file_extent+0x1bf/0x1e0 [btrfs]
 [<ffffffffa011a2da>] ? btrfs_free_path+0x2a/0x40 [btrfs]
 [<ffffffffa0176058>] replay_one_extent+0x608/0x680 [btrfs]
 [<ffffffffa015e0d6>] ? read_extent_buffer_pages+0x276/0x350 [btrfs]
 [<ffffffffa0176e3b>] replay_one_buffer+0x2db/0x3a0 [btrfs]
 [<ffffffffa015cce3>] ? alloc_extent_buffer+0x93/0x3e0 [btrfs]
 [<ffffffffa0172852>] walk_down_log_tree+0x212/0x400 [btrfs]
 [<ffffffffa0172add>] walk_log_tree+0x9d/0x1f0 [btrfs]
 [<ffffffffa0178dfb>] btrfs_recover_log_trees+0x21b/0x3a0 [btrfs]
 [<ffffffffa0176b60>] ? fixup_inode_link_counts+0x150/0x150 [btrfs]
 [<ffffffffa013d8fb>] open_ctree+0x166b/0x1cf0 [btrfs]
 [<ffffffff812e314a>] ? disk_name+0xba/0xc0
 [<ffffffffa0116afc>] btrfs_mount+0x62c/0x770 [btrfs]
 [<ffffffff8113ad8a>] ? __free_pages+0x5a/0x90
 [<ffffffff811a14e3>] mount_fs+0x43/0x1b0
 [<ffffffff811babff>] vfs_kern_mount+0x6f/0x100
 [<ffffffff811bd01f>] do_mount+0x21f/0xab0
 [<ffffffff811bcc6a>] ? copy_mount_options+0x3a/0x180
 [<ffffffff811bd93e>] sys_mount+0x8e/0xe0
 [<ffffffff8165bb59>] system_call_fastpath+0x16/0x1b
Code: 86 0f 1f 00 31 c0 48 83 7b 20 00 75 ce 48 89 de 4c 89 e7 89 45 b0 e8 09 fe ff ff 8b 45 b0 eb bb 0f 1f 40 00 b8 ea ff ff ff eb b0 <0f> 0b e8 03 8f 02 00 e8 f8 8e 02 00 66 66 66 66 2e 0f 1f 84 00 
RIP  [<ffffffffa0179e47>] remove_from_bitmap+0x1b7/0x1d0 [btrfs]
 RSP <ffff8800581e36e8>

Description of problem:

Please refer to:

https://bugzilla.redhat.com/show_bug.cgi?id=953443

I tried to mount as below:

[root@mail2 ~]# mount -oclear_cache,recovery /dev/mapper/sda3 /var/tmp/recover/
Segmentation fault
[root@mail2 ~]#

Every time it try to mount the fs it crashes & I cannot issue another mount command as then the next mount command hangs with prompt not returning & system has to be rebooted, but which in the end has a comment, something like "2 dm devices could not be detached, giving up" & then system has to hard reset.

Version-Release number of selected component:
kernel

Additional info:
cmdline:        BOOT_IMAGE=/vmlinuz-3.8.7-201.fc18.x86_64 root=UUID=d2b3420c-99c1-44cc-a922-ac266072c7fb ro rootflags=subvol=root rd.md=0 rd.lvm=0 rd.dm=0 rd.luks=0 vconsole.keymap=us rhgb quiet LANG=en_US.UTF-8
kernel:         3.8.7-201.fc18.x86_64 #1 Hewlett-Packard HP dx2480 MT(FX801PA
type:           Kerneloops
ureports_counter: 1

Truncated backtrace:
kernel BUG at fs/btrfs/free-space-cache.c:1542!
invalid opcode: 0000 [#1] SMP 
Modules linked in: dm_crypt nf_conntrack_netbios_ns nf_conntrack_broadcast ipt_MASQUERADE ip6table_mangle ip6t_REJECT nf_conntrack_ipv6 nf_defrag_ipv6 iptable_nat nf_nat_ipv4 nf_nat iptable_mangle nf_conntrack_ipv4 nf_defrag_ipv4 xt_conntrack nf_conntrack ebtable_filter ebtables ip6table_filter ip6_tables be2iscsi iscsi_boot_sysfs bnx2i cnic uio cxgb4i cxgb4 it87 hwmon_vid cxgb3i cxgb3 mdio libcxgbi ib_iser rdma_cm ib_addr iw_cm ib_cm ib_sa ib_mad ib_core iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi snd_hda_codec_realtek snd_hda_intel snd_hda_codec snd_hwdep snd_seq snd_seq_device snd_pcm coretemp iTCO_wdt iTCO_vendor_support snd_page_alloc snd_timer snd soundcore r8169 ppdev 3c59x i2c_i801 microcode mii lpc_ich mfd_core parport_pc parport uinput binfmt_misc btrfs zlib_deflate libcrc32c i915 video i2c_algo_bit drm_kms_helper drm i2c_core
CPU 1 
Pid: 1536, comm: mount Not tainted 3.8.7-201.fc18.x86_64 #1 Hewlett-Packard HP dx2480 MT(FX801PA)/0B08h
RIP: 0010:[<ffffffffa0179e47>]  [<ffffffffa0179e47>] remove_from_bitmap+0x1b7/0x1d0 [btrfs]
RSP: 0018:ffff88009fae56e8  EFLAGS: 00010287
RAX: 00000004c1974000 RBX: ffff880099b1c940 RCX: ffff88009d6fd5e4
RDX: 0000000000002000 RSI: 0000000000008000 RDI: 0000000000000280
RBP: ffff88009fae5738 R08: ffff88009f883fb0 R09: 0000000000007d80
R10: ffffffffa0125880 R11: 0000000000000000 R12: ffff88009d6fd5c0
R13: ffff88009fae5760 R14: ffff88009fae5758 R15: 00000004c1c00000
FS:  00007f5abe44f840(0000) GS:ffff8800bf280000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
CR2: 00007f8dccea667c CR3: 000000009315f000 CR4: 00000000000007e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Process mount (pid: 1536, threadinfo ffff88009fae4000, task ffff8800366b2ec0)
Stack:
 ffff880036694600 ffff88009d6fd5e4 00000004c1983000 0000000000002000
 ffff88009fae5738 ffff88009d6fd5c0 ffff88009d6fd5e4 0000000000000001
 ffff880036694600 ffff88009f88c000 ffff88009fae5788 ffffffffa017bc33
Call Trace:
 [<ffffffffa017bc33>] btrfs_remove_free_space+0x53/0x280 [btrfs]
 [<ffffffffa012e0bf>] btrfs_alloc_logged_file_extent+0x1bf/0x1e0 [btrfs]
 [<ffffffffa011a2da>] ? btrfs_free_path+0x2a/0x40 [btrfs]
 [<ffffffffa0176058>] replay_one_extent+0x608/0x680 [btrfs]
 [<ffffffffa015e0d6>] ? read_extent_buffer_pages+0x276/0x350 [btrfs]
 [<ffffffffa0176e3b>] replay_one_buffer+0x2db/0x3a0 [btrfs]
 [<ffffffffa015cce3>] ? alloc_extent_buffer+0x93/0x3e0 [btrfs]
 [<ffffffffa0172852>] walk_down_log_tree+0x212/0x400 [btrfs]
 [<ffffffffa0172add>] walk_log_tree+0x9d/0x1f0 [btrfs]
 [<ffffffffa0178dfb>] btrfs_recover_log_trees+0x21b/0x3a0 [btrfs]
 [<ffffffffa0176b60>] ? fixup_inode_link_counts+0x150/0x150 [btrfs]
 [<ffffffffa013d8fb>] open_ctree+0x166b/0x1cf0 [btrfs]
 [<ffffffff812e314a>] ? disk_name+0xba/0xc0
 [<ffffffffa0116afc>] btrfs_mount+0x62c/0x770 [btrfs]
 [<ffffffff8113ad8a>] ? __free_pages+0x5a/0x90
 [<ffffffff811a14e3>] mount_fs+0x43/0x1b0
 [<ffffffff811babff>] vfs_kern_mount+0x6f/0x100
 [<ffffffff811bd01f>] do_mount+0x21f/0xab0
 [<ffffffff811bcc6a>] ? copy_mount_options+0x3a/0x180
 [<ffffffff811bd93e>] sys_mount+0x8e/0xe0
 [<ffffffff8165bb59>] system_call_fastpath+0x16/0x1b
Code: 86 0f 1f 00 31 c0 48 83 7b 20 00 75 ce 48 89 de 4c 89 e7 89 45 b0 e8 09 fe ff ff 8b 45 b0 eb bb 0f 1f 40 00 b8 ea ff ff ff eb b0 <0f> 0b e8 03 8f 02 00 e8 f8 8e 02 00 66 66 66 66 2e 0f 1f 84 00 
RIP  [<ffffffffa0179e47>] remove_from_bitmap+0x1b7/0x1d0 [btrfs]
 RSP <ffff88009fae56e8>

I don't know how I may scrub, as many comments say that scrub may rescue the FS. Please see below:

[root@mail2 ~]# btrfs device scan
Scanning for Btrfs filesystems
failed to read /dev/sr0

[root@mail2 ~]# btrfs filesystem show
failed to read /dev/sr0
Label: 'Vikram'  uuid: 0809b072-35f3-4866-92b8-af4772b23ed6
        Total devices 2 FS bytes used 81.30GB
        devid    2 size 157.00GB used 157.00GB path /dev/dm-1
        devid    1 size 158.03GB used 157.02GB path /dev/dm-0

Label: 'fedora_mail2'  uuid: d2b3420c-99c1-44cc-a922-ac266072c7fb
        Total devices 2 FS bytes used 15.63GB
        devid    2 size 73.51GB used 11.03GB path /dev/sdb6
        devid    3 size 73.30GB used 10.03GB path /dev/sda2

Btrfs Btrfs v0.19

[root@mail2 ~]# btrfs scrub start -Bdr /dev/mapper/sda3
ERROR: getting dev info for scrub failed: Inappropriate ioctl for device

[root@mail2 ~]# btrfs scrub start -Bdr /dev/mapper/sdb1
ERROR: getting dev info for scrub failed: Inappropriate ioctl for device


[root@mail2 ~]# btrfs scrub start -Bdr /dev/dm-1
ERROR: getting dev info for scrub failed: Inappropriate ioctl for device

[root@mail2 ~]# btrfs scrub start -Bdr /dev/dm-0
ERROR: getting dev info for scrub failed: Inappropriate ioctl for device

This is a feed back:

I ran btrfs-zero-log  /dev/mapper/sda3
which created a dump. I have attached the abrt dir.

Then I ran the same command on the other device of the raid 1 fs
btrfs-zero-log  /dev/mapper/sdb1 which seems to have cleared the problem.

Below are the relevant /var/log/messages:

Apr 20 09:59:01 mail2 kernel: [   63.251463] bio: create slab <bio-1> at 1
Apr 20 09:59:01 mail2 kernel: [   63.446113] bio: create slab <bio-1> at 1
Apr 20 09:59:01 mail2 kernel: [   63.503134] device label Vikram devid 2 transid 21701 /dev/dm-0
Apr 20 09:59:01 mail2 dbus-daemon[553]: ** Message: No devices in use, exit
Apr 20 09:59:13 mail2 kernel: [   75.517567] device label Vikram devid 1 transid 21701 /dev/dm-1
Apr 20 09:59:41 mail2 chronyd[560]: Selected source 123.108.200.163
Apr 20 10:00:11 mail2 kernel: [  133.481392] device label fedora_mail2 devid 3 transid 140087 /dev/sda2
Apr 20 10:00:11 mail2 kernel: [  133.571011] device label fedora_mail2 devid 2 transid 140087 /dev/sdb6
Apr 20 10:00:11 mail2 kernel: [  133.599906] device label Vikram devid 2 transid 21701 /dev/dm-0
Apr 20 10:00:11 mail2 kernel: [  133.600188] device label Vikram devid 1 transid 21701 /dev/dm-1
Apr 20 10:00:11 mail2 kernel: [  133.623443] device label fedora_mail2 devid 3 transid 140087 /dev/sda2
Apr 20 10:00:11 mail2 kernel: [  133.642217] device label fedora_mail2 devid 2 transid 140087 /dev/sdb6
Apr 20 10:00:11 mail2 kernel: [  133.643145] device label Vikram devid 2 transid 21701 /dev/dm-0
Apr 20 10:00:11 mail2 kernel: [  133.643444] device label Vikram devid 1 transid 21701 /dev/dm-1
Apr 20 10:00:12 mail2 kernel: [  134.482053] device label Vikram devid 1 transid 21701 /dev/dm-1
Apr 20 10:00:15 mail2 kernel: [  137.975085] device label Vikram devid 2 transid 21702 /dev/dm-0
Apr 20 10:00:15 mail2 kernel: [  138.005067] device label Vikram devid 1 transid 21702 /dev/dm-1
Apr 20 10:00:16 mail2 abrtd: Directory 'ccpp-2013-04-20-10:00:15-1614' creation detected
Apr 20 10:00:16 mail2 abrt[1620]: Saved core dump of pid 1614 (/usr/sbin/btrfs-zero-log) to /var/tmp/abrt/ccpp-2013-04-20-10:00:15-1614 (491520 bytes)
Apr 20 10:00:19 mail2 abrtd: Generating backtrace
Apr 20 10:00:21 mail2 abrtd: Backtrace is generated, 3811 bytes
Apr 20 10:00:21 mail2 abrtd: Core backtrace is generated and saved, 738 bytes
Apr 20 10:00:28 mail2 abrtd: New problem directory /var/tmp/abrt/ccpp-2013-04-20-10:00:15-1614, processing
Apr 20 10:01:24 mail2 kernel: [  206.689667] device label fedora_mail2 devid 3 transid 140089 /dev/sda2
Apr 20 10:01:24 mail2 kernel: [  206.727906] device label fedora_mail2 devid 2 transid 140089 /dev/sdb6
Apr 20 10:01:24 mail2 kernel: [  206.728327] device label Vikram devid 2 transid 21702 /dev/dm-0
Apr 20 10:01:24 mail2 kernel: [  206.754267] device label Vikram devid 1 transid 21702 /dev/dm-1
Apr 20 10:01:24 mail2 kernel: [  206.773400] device label fedora_mail2 devid 3 transid 140089 /dev/sda2
Apr 20 10:01:24 mail2 kernel: [  206.774819] device label fedora_mail2 devid 2 transid 140089 /dev/sdb6
Apr 20 10:01:24 mail2 kernel: [  206.775249] device label Vikram devid 2 transid 21702 /dev/dm-0
Apr 20 10:01:24 mail2 kernel: [  206.776079] device label Vikram devid 1 transid 21702 /dev/dm-1
Apr 20 10:01:25 mail2 kernel: [  207.484444] device label Vikram devid 2 transid 21702 /dev/dm-0
Apr 20 10:01:28 mail2 kernel: [  210.855947] device label Vikram devid 2 transid 21703 /dev/dm-0
Apr 20 10:01:28 mail2 kernel: [  210.921609] device label Vikram devid 1 transid 21703 /dev/dm-1
Apr 20 10:01:53 mail2 kernel: [  235.535556] device label Vikram devid 2 transid 21703 /dev/mapper/sdb1
Apr 20 10:01:53 mail2 kernel: [  235.554166] btrfs: disk space caching is enabled
Apr 20 10:01:53 mail2 kernel: [  235.569638] btrfs: mismatching generation and generation_v2 found in root item. This root was probably mounted with an older
 kernel. Resetting all new fields.
Apr 20 10:01:54 mail2 kernel: [  236.154561] btrfs: unlinked 1 orphans
Apr 20 10:02:25 mail2 kernel: [  267.899278] device label Vikram devid 1 transid 21706 /dev/mapper/sda3
Apr 20 10:02:25 mail2 kernel: [  267.901356] btrfs: disk space caching is enabled

Created attachment 737912 [details]
abrt dump dir in tar bzip2 format

zero log dump from one device of the two in raid1 set up. running zero-log on the other device seems to have cleared the problem. FS can be mounted & unmounted easily.

Created attachment 754053 [details]
Screenshot of kernel bug at free-space-cache.c:1542

I recently installed Fedora 18, applied updates. System is located on btrfs partition. When running "yum update", computer was accidentally rebooted. Now it does not boot due to kernel bug at free-space-cache.c:1542. Stack trace is very similar to the stack trace reported above. Since system is not bootable, cannot provide system log in text form. Screenshot (slightly processed to reduce size) is attached.

*** Bug 975506 has been marked as a duplicate of this bug. ***

I had this issue today on Arch Linux (kernel 3.9.8) after my notebook ran out of power. Running btrfs-zero-log fixed it.

This bug hit me too.   Not sure what the original event was.  Not a power reset, maybe when I killed a virtual guest system running on an encrypted virtual file system ...

Tried:
    btrfs-zero-log /dev/sda3
but it died with:
   `btrfs-zero-log': corrupted double-linked list

Tried booting with linux option:
    -o clear_cache
and that seems to have worked after 20min or so of some kind of disk rebuilding.

But the system died again today, with the same or similar symptoms.

This time, "-o clear_cache" isn't working for me.

Can repeatably cause this fs corruption with by shutting down a Windows VM and triggering BUG #980254

Can recover by running
    btrfs-zero-log /dev/sda3
from a live usb image.  (The btrfs-zero-log command crashes, but it seems to fix the problem first.)

Fixed in 3.10.