Btrfs Bug Postmortem

shaurz · 2013-05-22 20:18:59

The story begins: While I was changing my screen rotation settings, my system locked up and nothing I tried could restore it. I reset machine and it didn't boot. There was a segfault when systemd attemted to mount my root filesystem, which is formatted as btrfs.

I boot in to an Arch install image and try to mount the filesystem. This is what I was greeted with:

[   19.141300] device label arch devid 1 transid 292426 /dev/sdc2
[   19.141863] btrfs: disk space caching is enabled
[   19.170489] Btrfs detected SSD devices, enabling SSD mode
[   19.200413] ------------[ cut here ]------------
[   19.200445] kernel BUG at fs/btrfs/free-space-cache.c:1555!
[   19.200475] invalid opcode: 0000 [#1] PREEMPT SMP 
[   19.200512] Modules linked in: snd_hda_codec_hdmi snd_hda_codec_realtek arc4 rtl8192se rtlwifi mac80211 coretemp kvm_intel kvm snd_hda_intel ghash_clmulni_intel snd_hda_codec aesni_intel aes_x86_64 aes_generic cfg80211 ablk_helper snd_hwdep cryptd snd_pcm rfkill iTCO_wdt snd_page_alloc psmouse i2c_i801 snd_timer iTCO_vendor_support microcode snd acpi_cpufreq serio_raw soundcore lpc_ich mperf pcspkr mei evdev processor nfs lockd sunrpc fscache ext4 crc16 jbd2 mbcache dm_snapshot dm_mod squashfs loop isofs usb_storage hid_logitech_dj hid_generic usbhid hid btrfs libcrc32c zlib_deflate sd_mod xhci_hcd radeon i915 ahci ttm libahci intel_agp libata intel_gtt i2c_algo_bit drm_kms_helper ehci_hcd drm scsi_mod crc32c_intel tg3 usbcore libphy i2c_core usb_common video button
[   19.201119] CPU 1 
[   19.201134] Pid: 526, comm: mount Not tainted 3.6.4-1-ARCH #1 To Be Filled By O.E.M. To Be Filled By O.E.M./Z77E-ITX
[   19.201188] RIP: 0010:[<ffffffffa044e00f>]  [<ffffffffa044e00f>] remove_from_bitmap+0x16f/0x180 [btrfs]
[   19.201253] RSP: 0018:ffff880417279698  EFLAGS: 00010287
[   19.201281] RAX: 0000000000000000 RBX: ffff880416d4a140 RCX: ffff8804146da864
[   19.201318] RDX: 00000000dd5a0000 RSI: 0000000000008000 RDI: 0000000000004600
[   19.201354] RBP: ffff8804172796e8 R08: ffff880417204748 R09: 0000000000003a00
[   19.201390] R10: ffffea00104da4c0 R11: ffffffffa0400748 R12: ffff880417279710
[   19.201425] R13: ffff880417279708 R14: ffff8804146da840 R15: 00000000e1c00000
[   19.201462] FS:  00007f619fad4780(0000) GS:ffff88042f240000(0000) knlGS:0000000000000000
[   19.201502] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[   19.201532] CR2: 0000000001482fa0 CR3: 00000004135a8000 CR4: 00000000001407e0
[   19.201568] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[   19.201603] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[   19.201639] Process mount (pid: 526, threadinfo ffff880417278000, task ffff8804168c2040)
[   19.201679] Stack:
[   19.201692]  ffff8804172798a3 ffff8804146da864 00000000dd5d9000 0000000000039000
[   19.201743]  ffff880417279748 ffff880416d4a140 ffff8804146da840 0000000000000000
[   19.201793]  ffff8804146da864 ffff880412af3800 ffff880417279748 ffffffffa0450363
[   19.201843] Call Trace:
[   19.201871]  [<ffffffffa0450363>] btrfs_remove_free_space+0x53/0x260 [btrfs]
[   19.201918]  [<ffffffffa0408d5f>] btrfs_alloc_logged_file_extent+0x1bf/0x1e0 [btrfs]
[   19.201965]  [<ffffffffa03f407a>] ? btrfs_free_path+0x2a/0x40 [btrfs]
[   19.202008]  [<ffffffffa044b106>] replay_one_extent+0x626/0x690 [btrfs]
[   19.202053]  [<ffffffffa04115af>] ? btree_set_page_dirty+0x3f/0x50 [btrfs]
[   19.202099]  [<ffffffffa042fd29>] ? release_extent_buffer.isra.37+0xb9/0xe0 [btrfs]
[   19.202148]  [<ffffffffa044a178>] ? overwrite_item+0x158/0x420 [btrfs]
[   19.202192]  [<ffffffffa0436083>] ? read_extent_buffer+0xc3/0x120 [btrfs]
[   19.202236]  [<ffffffffa044b98b>] replay_one_buffer+0x28b/0x360 [btrfs]
[   19.202280]  [<ffffffffa0434a2d>] ? alloc_extent_buffer+0x9d/0x4b0 [btrfs]
[   19.202324]  [<ffffffffa04490a2>] walk_down_log_tree+0x212/0x400 [btrfs]
[   19.202367]  [<ffffffffa044932d>] walk_log_tree+0x9d/0x1f0 [btrfs]
[   19.202409]  [<ffffffffa044d45b>] btrfs_recover_log_trees+0x21b/0x3a0 [btrfs]
[   19.202454]  [<ffffffffa044b700>] ? replay_one_dir_item+0xf0/0xf0 [btrfs]
[   19.202499]  [<ffffffffa04174b1>] open_ctree+0x1581/0x1ba0 [btrfs]
[   19.202535]  [<ffffffff81245da1>] ? disk_name+0x61/0xc0
[   19.202569]  [<ffffffffa03f0a73>] btrfs_mount+0x633/0x770 [btrfs]
[   19.202604]  [<ffffffff8125b328>] ? ida_get_new_above+0x218/0x2a0
[   19.202639]  [<ffffffff81183143>] mount_fs+0x43/0x1b0
[   19.202669]  [<ffffffff8113ee30>] ? __alloc_percpu+0x10/0x20
[   19.202701]  [<ffffffff8119dab4>] vfs_kern_mount+0x74/0x110
[   19.202733]  [<ffffffff8119e014>] do_kern_mount+0x54/0x110
[   19.202764]  [<ffffffff8119fca5>] do_mount+0x315/0x8e0
[   19.202793]  [<ffffffff811396b6>] ? memdup_user+0x46/0x80
[   19.202823]  [<ffffffff8113974b>] ? strndup_user+0x5b/0x80
[   19.202853]  [<ffffffff811a02fd>] sys_mount+0x8d/0xe0
[   19.202883]  [<ffffffff81499ded>] system_call_fastpath+0x1a/0x1f
[   19.202913] Code: 8e 0f 1f 00 31 c0 48 83 7b 20 00 75 d5 48 89 de 4c 89 f7 89 45 b0 e8 01 f8 ff ff 8b 45 b0 eb c2 0f 1f 40 00 b8 ea ff ff ff eb b7 <0f> 0b 66 66 66 66 66 66 2e 0f 1f 84 00 00 00 00 00 55 48 89 e5 
[   19.203242] RIP  [<ffffffffa044e00f>] remove_from_bitmap+0x16f/0x180 [btrfs]
[   19.203291]  RSP <ffff880417279698>
[   19.203324] ---[ end trace c8c1986095aeefa3 ]---
[   19.203353] note: mount[526] exited with preempt_count 1
[   19.203390] BUG: scheduling while atomic: mount/526/0x10000002
[   19.203420] Modules linked in: snd_hda_codec_hdmi snd_hda_codec_realtek arc4 rtl8192se rtlwifi mac80211 coretemp kvm_intel kvm snd_hda_intel ghash_clmulni_intel snd_hda_codec aesni_intel aes_x86_64 aes_generic cfg80211 ablk_helper snd_hwdep cryptd snd_pcm rfkill iTCO_wdt snd_page_alloc psmouse i2c_i801 snd_timer iTCO_vendor_support microcode snd acpi_cpufreq serio_raw soundcore lpc_ich mperf pcspkr mei evdev processor nfs lockd sunrpc fscache ext4 crc16 jbd2 mbcache dm_snapshot dm_mod squashfs loop isofs usb_storage hid_logitech_dj hid_generic usbhid hid btrfs libcrc32c zlib_deflate sd_mod xhci_hcd radeon i915 ahci ttm libahci intel_agp libata intel_gtt i2c_algo_bit drm_kms_helper ehci_hcd drm scsi_mod crc32c_intel tg3 usbcore libphy i2c_core usb_common video button
[   19.204027] Pid: 526, comm: mount Tainted: G      D      3.6.4-1-ARCH #1
[   19.204060] Call Trace:
[   19.204079]  [<ffffffff81489f4c>] __schedule_bug+0x4d/0x59
[   19.204111]  [<ffffffff8149189a>] __schedule+0x8da/0x920
[   19.204143]  [<ffffffff81160de0>] ? alloc_pages_current+0xb0/0x120
[   19.204177]  [<ffffffff81088c3a>] __cond_resched+0x2a/0x40
[   19.206620]  [<ffffffff81491960>] _cond_resched+0x30/0x40
[   19.209054]  [<ffffffff81143e7c>] unmap_single_vma+0x44c/0x870
[   19.211495]  [<ffffffff81129fd0>] ? release_pages+0x1f0/0x230
[   19.211497]  [<ffffffff81144ad2>] unmap_vmas+0x52/0xa0
[   19.211500]  [<ffffffff8114c898>] exit_mmap+0x98/0x170
[   19.211504]  [<ffffffff81052f61>] mmput+0x61/0x120
[   19.211506]  [<ffffffff8105b818>] exit_mm+0x108/0x130
[   19.211510]  [<ffffffff814928e5>] ? _raw_spin_unlock_irq+0x35/0x40
[   19.211512]  [<ffffffff8105b99a>] do_exit+0x15a/0x940
[   19.211515]  [<ffffffff814899ea>] ? printk+0x4d/0x4f
[   19.211518]  [<ffffffff810594f1>] ? kmsg_dump+0xc1/0xd0
[   19.211527]  [<ffffffff81493cdd>] oops_end+0x9d/0xe0
[   19.211531]  [<ffffffff81018c88>] die+0x58/0x90
[   19.211534]  [<ffffffff81493610>] do_trap+0xc0/0x170
[   19.211537]  [<ffffffff8101628c>] do_invalid_op+0x9c/0xb0
[   19.211550]  [<ffffffffa044e00f>] ? remove_from_bitmap+0x16f/0x180 [btrfs]
[   19.211560]  [<ffffffffa0454e9b>] ? tree_insert+0x7b/0xa0 [btrfs]
[   19.211572]  [<ffffffffa042ee6c>] ? check_buffer_tree_ref+0x3c/0x50 [btrfs]
[   19.211584]  [<ffffffffa042ee6c>] ? check_buffer_tree_ref+0x3c/0x50 [btrfs]
[   19.211587]  [<ffffffff8149ae7b>] invalid_op+0x1b/0x20
[   19.211597]  [<ffffffffa0400748>] ? cache_block_group.isra.46+0x2f8/0x3e0 [btrfs]
[   19.211607]  [<ffffffffa044e00f>] ? remove_from_bitmap+0x16f/0x180 [btrfs]
[   19.211617]  [<ffffffffa044df0d>] ? remove_from_bitmap+0x6d/0x180 [btrfs]
[   19.211627]  [<ffffffffa0450363>] btrfs_remove_free_space+0x53/0x260 [btrfs]
[   19.211638]  [<ffffffffa0408d5f>] btrfs_alloc_logged_file_extent+0x1bf/0x1e0 [btrfs]
[   19.211647]  [<ffffffffa03f407a>] ? btrfs_free_path+0x2a/0x40 [btrfs]
[   19.211657]  [<ffffffffa044b106>] replay_one_extent+0x626/0x690 [btrfs]
[   19.211669]  [<ffffffffa04115af>] ? btree_set_page_dirty+0x3f/0x50 [btrfs]
[   19.211679]  [<ffffffffa042fd29>] ? release_extent_buffer.isra.37+0xb9/0xe0 [btrfs]
[   19.211690]  [<ffffffffa044a178>] ? overwrite_item+0x158/0x420 [btrfs]
[   19.211701]  [<ffffffffa0436083>] ? read_extent_buffer+0xc3/0x120 [btrfs]
[   19.211711]  [<ffffffffa044b98b>] replay_one_buffer+0x28b/0x360 [btrfs]
[   19.211722]  [<ffffffffa0434a2d>] ? alloc_extent_buffer+0x9d/0x4b0 [btrfs]
[   19.211732]  [<ffffffffa04490a2>] walk_down_log_tree+0x212/0x400 [btrfs]
[   19.211741]  [<ffffffffa044932d>] walk_log_tree+0x9d/0x1f0 [btrfs]
[   19.211752]  [<ffffffffa044d45b>] btrfs_recover_log_trees+0x21b/0x3a0 [btrfs]
[   19.211761]  [<ffffffffa044b700>] ? replay_one_dir_item+0xf0/0xf0 [btrfs]
[   19.211773]  [<ffffffffa04174b1>] open_ctree+0x1581/0x1ba0 [btrfs]
[   19.211777]  [<ffffffff81245da1>] ? disk_name+0x61/0xc0
[   19.211785]  [<ffffffffa03f0a73>] btrfs_mount+0x633/0x770 [btrfs]
[   19.211789]  [<ffffffff8125b328>] ? ida_get_new_above+0x218/0x2a0
[   19.211793]  [<ffffffff81183143>] mount_fs+0x43/0x1b0
[   19.211796]  [<ffffffff8113ee30>] ? __alloc_percpu+0x10/0x20
[   19.211800]  [<ffffffff8119dab4>] vfs_kern_mount+0x74/0x110
[   19.211803]  [<ffffffff8119e014>] do_kern_mount+0x54/0x110
[   19.211806]  [<ffffffff8119fca5>] do_mount+0x315/0x8e0
[   19.211809]  [<ffffffff811396b6>] ? memdup_user+0x46/0x80
[   19.211811]  [<ffffffff8113974b>] ? strndup_user+0x5b/0x80
[   19.211814]  [<ffffffff811a02fd>] sys_mount+0x8d/0xe0
[   19.211818]  [<ffffffff81499ded>] system_call_fastpath+0x1a/0x1f

Uh oh. I've hit a kernel bug!

I ran btrfsck and it seemed to finish OK without any problems. But I still couldn't mount it.

In the end I gave up and used btrfs-restore to recover as many files as I could. I don't think I lost anything, but unfortunately it did not restore file ownership or permissions or any symlinks and it was too big a job to manually fix them all, so I reinstalled and recovered my configuration files and home directory.

Needless to say I formatted my new root partition as ext4 after being burned like this. I know btrfs is still experimental but it had been very good up until that point.

lucke · 2013-05-22 20:29:50

Maybe, just maybe, mounting it with "clear_cache" option would have helped.

Last edited by lucke (2013-05-22 20:30:05)

falconindy · 2013-05-23 11:40:24

https://bbs.archlinux.org/viewtopic.php … 5#p1274215

Strongly advise you to keep your live media up to date if you're playing with btrfs. You didn't do yourself any favors by booting off such an "old" kernel while using newer btrfs features.

H3g3m0n · 2013-05-28 10:25:37

In my experience btrfs has some fairly annoying bugs that will prevent mounting. They only seem to happen if your media is faulty (which most media is in my experience, all harddrives will fail eventually). Unfortunately there doesn't seem to be anyway to get it back to a working state even though it should be a fairly simple problem.

I think quite a few of these will be fixed in kernel 3.10.

A few extra suggestions should anyone get stuck in a similar problem:

In addition to clear_cache above there is:
mount -o recovery blah blah

By default btrfsck doesn't fix anything, use the flag:
btrfsck --repair /dev/sdX

Having said that, I have yet to run into a problem that btrfsck has actually helped with, it's a fairly new tool though.

There is a tool: btrfs-zero-log that clears the playback journal, I think this could have helped the above problem. It does seem to be in btrfs-progs in the Arch repos. On other systems you will might have to compile it yourself (this isn't to much of a pain to do on a livecd, although personally I compile it on another computer with the same setup and copy it across).

After than if it doesn't fix itself, mount it read only with -o ro, and 'rsync -xav /mnt/rootofdrive /mnt/destination', that will preserve all the permissions.

Arch Linux

#1 2013-05-22 20:18:59

Btrfs Bug Postmortem

#2 2013-05-22 20:29:50

Re: Btrfs Bug Postmortem

#3 2013-05-23 11:40:24

Re: Btrfs Bug Postmortem

#4 2013-05-28 10:25:37

Re: Btrfs Bug Postmortem

Board footer