btrfs crashing at boot

Mon Oct 19 13:27:16 UTC 2015

Hi,

I started using btrfs recently.  Sometime today, my scratch disk started
turning read-only.  journalctl reports btrfs crashed (output shown
below).  ABRT says the problem cannot be reported.  I don't understand
this since I blacklisted the only module I'm aware of that might taint
the kernel on my system (openafs).  This happens within the first few
minutes of boot.  Immediately after boot I can write a simple file, but
soon after it crashes.  When I try to run btrfs check (after
unmounting), I get a core dump:

  # btrfs check /dev/sda1
  Checking filesystem on /dev/sda1
  UUID: 19ec6a44-fc5b-428d-9aec-fda803ce805b
  checking extents
  Aborted (core dumped)

I can't find any core file in the present working directory either.

In case it is relevant, this filesystem was converted from ext4.  What
could be going wrong?  How can I debug this?

Thanks for any ideas.

Cheers,

BTRFS detecting my disk:

Oct 19 18:30:09 localhost kernel: BTRFS: device fsid 19ec6a44-fc5b-428d-9aec-fda803ce805b devid 1 transid 1336 /dev/sda1
Oct 19 18:30:09 localhost kernel: BTRFS info (device sda1): disk space caching is enabled
Oct 19 18:30:09 localhost kernel: BTRFS: has skinny extents

BTRFS crash log:

Oct 19 18:33:59 localhost kernel: ------------[ cut here ]------------
Oct 19 18:33:59 localhost kernel: WARNING: CPU: 1 PID: 152 at fs/btrfs/extent-tree.c:6255 __btrfs_free_extent.isra.68+0x8c8/0xd70 [btrfs]()
Oct 19 18:33:59 localhost kernel: Modules linked in: ccm ip6t_rpfilter ip6t_REJECT nf_reject_ipv6 xt_conntrack ebtable_nat ebtable_broute bridge stp llc ebtable_filter ebtables ip6table_nat nf_conntrack_ipv6 nf_defrag_ipv6 nf_nat_ipv6 ip6table_mangle ip6table_security ip6table_raw ip6table_filter ip6_tables iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack iptable_mangle iptable_security iptable_raw btrfs arc4 xor intel_rapl iosf_mbi x86_pkg_temp_thermal iTCO_wdt coretemp kvm_intel iTCO_vendor_support kvm raid6_pq iwlmvm crct10dif_pclmul snd_hda_codec_hdmi crc32_pclmul crc32c_intel mac80211 snd_hda_codec_realtek snd_hda_codec_generic ghash_clmulni_intel uvcvideo snd_hda_intel snd_hda_codec snd_hda_core snd_hwdep videobuf2_vmalloc snd_seq videobuf2_core videobuf2_memops snd_seq_device v4l2_common
Oct 19 18:33:59 localhost kernel:  iwlwifi snd_pcm videodev rtsx_pci_ms cfg80211 media thinkpad_acpi memstick i2c_i801 lpc_ich snd_timer snd tpm_tis wmi rfkill tpm soundcore mei_me mei shpchp binfmt_misc i915 rtsx_pci_sdmmc mmc_core i2c_algo_bit e1000e drm_kms_helper drm serio_raw ptp rtsx_pci pps_core video
Oct 19 18:33:59 localhost kernel: CPU: 1 PID: 152 Comm: kworker/u16:5 Tainted: G        W       4.2.3-200.fc22.x86_64 #1
Oct 19 18:33:59 localhost kernel: Hardware name: LENOVO 20ALCTO1WW/20ALCTO1WW, BIOS GIET66WW (2.16 ) 12/02/2013
Oct 19 18:33:59 localhost kernel: Workqueue: btrfs-extent-refs btrfs_extent_refs_helper [btrfs]
Oct 19 18:33:59 localhost kernel:  0000000000000000 00000000673d9c47 ffff8802125d7a88 ffffffff8177220a
Oct 19 18:33:59 localhost kernel:  0000000000000000 0000000000000000 ffff8802125d7ac8 ffffffff8109e4a6
Oct 19 18:33:59 localhost kernel:  0000000000000002 00000001874d9000 00000000fffffffe 0000000000000000
Oct 19 18:33:59 localhost kernel: Call Trace:
Oct 19 18:33:59 localhost kernel:  [<ffffffff8177220a>] dump_stack+0x45/0x57
Oct 19 18:33:59 localhost kernel:  [<ffffffff8109e4a6>] warn_slowpath_common+0x86/0xc0
Oct 19 18:33:59 localhost kernel:  [<ffffffff8109e5da>] warn_slowpath_null+0x1a/0x20
Oct 19 18:33:59 localhost kernel:  [<ffffffffa07ae628>] __btrfs_free_extent.isra.68+0x8c8/0xd70 [btrfs]
Oct 19 18:33:59 localhost kernel:  [<ffffffffa0816a5a>] ? find_ref_head+0x5a/0x80 [btrfs]
Oct 19 18:33:59 localhost kernel:  [<ffffffffa07b23c8>] __btrfs_run_delayed_refs+0x998/0x1080 [btrfs]
Oct 19 18:33:59 localhost kernel:  [<ffffffff81200083>] ? kmem_cache_alloc+0x193/0x210
Oct 19 18:33:59 localhost kernel:  [<ffffffffa07b5674>] btrfs_run_delayed_refs.part.73+0x74/0x270 [btrfs]
Oct 19 18:33:59 localhost kernel:  [<ffffffffa07b590e>] delayed_ref_async_start+0x7e/0x90 [btrfs]
Oct 19 18:33:59 localhost kernel:  [<ffffffffa07fb322>] btrfs_scrubparity_helper+0xc2/0x260 [btrfs]
Oct 19 18:33:59 localhost kernel:  [<ffffffffa07fb4fe>] btrfs_extent_refs_helper+0xe/0x10 [btrfs]
Oct 19 18:33:59 localhost kernel:  [<ffffffff810b64fe>] process_one_work+0x19e/0x3f0
Oct 19 18:33:59 localhost kernel:  [<ffffffff810b679e>] worker_thread+0x4e/0x450
Oct 19 18:33:59 localhost kernel:  [<ffffffff810b6750>] ? process_one_work+0x3f0/0x3f0
Oct 19 18:33:59 localhost kernel:  [<ffffffff810b6750>] ? process_one_work+0x3f0/0x3f0
Oct 19 18:33:59 localhost kernel:  [<ffffffff810bc8a8>] kthread+0xd8/0xf0
Oct 19 18:33:59 localhost kernel:  [<ffffffff810bc7d0>] ? kthread_worker_fn+0x160/0x160
Oct 19 18:33:59 localhost kernel:  [<ffffffff81778fdf>] ret_from_fork+0x3f/0x70
Oct 19 18:33:59 localhost kernel:  [<ffffffff810bc7d0>] ? kthread_worker_fn+0x160/0x160
Oct 19 18:33:59 localhost kernel: ---[ end trace 0eadb91546850dac ]---
Oct 19 18:33:59 localhost kernel: BTRFS info (device sda1): leaf 139591680 total ptrs 184 free space 5551
Oct 19 18:33:59 localhost kernel:         item 0 key (6554550272 169 0) itemoff 16250 itemsize 33
Oct 19 18:33:59 localhost kernel:                 extent refs 1 gen 355 flags 2
Oct 19 18:33:59 localhost kernel:                 tree block backref root 7

then it repeats like that many times.  The log ends like this:

Oct 19 18:33:59 localhost kernel: BTRFS error (device sda1): unable to find ref byte nr 6564974592 parent 0 root 7  owner 2 offset 0
Oct 19 18:33:59 localhost kernel: ------------[ cut here ]------------
Oct 19 18:33:59 localhost kernel: WARNING: CPU: 1 PID: 152 at fs/btrfs/extent-tree.c:6261 __btrfs_free_extent.isra.68+0x92f/0xd70 [btrfs]()
Oct 19 18:33:59 localhost kernel: BTRFS: Transaction aborted (error -2)
Oct 19 18:33:59 localhost kernel: Modules linked in: ccm ip6t_rpfilter ip6t_REJECT nf_reject_ipv6 xt_conntrack ebtable_nat ebtable_broute bridge stp llc ebtable_filter ebtables ip6table_nat nf_conntrack_ipv6 nf_defrag_ipv6 nf_nat_ipv6 ip6table_mangle ip6table_security ip6table_raw ip6table_filter ip6_tables iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack iptable_mangle iptable_security iptable_raw btrfs arc4 xor intel_rapl iosf_mbi x86_pkg_temp_thermal iTCO_wdt coretemp kvm_intel iTCO_vendor_support kvm raid6_pq iwlmvm crct10dif_pclmul snd_hda_codec_hdmi crc32_pclmul crc32c_intel mac80211 snd_hda_codec_realtek snd_hda_codec_generic ghash_clmulni_intel uvcvideo snd_hda_intel snd_hda_codec snd_hda_core snd_hwdep videobuf2_vmalloc snd_seq videobuf2_core videobuf2_memops snd_seq_device v4l2_common
Oct 19 18:33:59 localhost kernel:  iwlwifi snd_pcm videodev rtsx_pci_ms cfg80211 media thinkpad_acpi memstick i2c_i801 lpc_ich snd_timer snd tpm_tis wmi rfkill tpm soundcore mei_me mei shpchp binfmt_misc i915 rtsx_pci_sdmmc mmc_core i2c_algo_bit e1000e drm_kms_helper drm serio_raw ptp rtsx_pci pps_core video
Oct 19 18:33:59 localhost kernel: CPU: 1 PID: 152 Comm: kworker/u16:5 Tainted: G        W       4.2.3-200.fc22.x86_64 #1
Oct 19 18:33:59 localhost kernel: Hardware name: LENOVO 20ALCTO1WW/20ALCTO1WW, BIOS GIET66WW (2.16 ) 12/02/2013
Oct 19 18:33:59 localhost kernel: Workqueue: btrfs-extent-refs btrfs_extent_refs_helper [btrfs]
Oct 19 18:33:59 localhost kernel:  0000000000000000 00000000673d9c47 ffff8802125d7a28 ffffffff8177220a
Oct 19 18:33:59 localhost kernel:  0000000000000000 ffff8802125d7a80 ffff8802125d7a68 ffffffff8109e4a6
Oct 19 18:33:59 localhost kernel:  ffffffffa0849349 00000001874d9000 00000000fffffffe 0000000000000000
Oct 19 18:33:59 localhost kernel: Call Trace:
Oct 19 18:33:59 localhost kernel:  [<ffffffff8177220a>] dump_stack+0x45/0x57
Oct 19 18:33:59 localhost kernel:  [<ffffffff8109e4a6>] warn_slowpath_common+0x86/0xc0
Oct 19 18:33:59 localhost kernel:  [<ffffffff8109e535>] warn_slowpath_fmt+0x55/0x70
Oct 19 18:33:59 localhost kernel:  [<ffffffffa07ae68f>] __btrfs_free_extent.isra.68+0x92f/0xd70 [btrfs]
Oct 19 18:33:59 localhost kernel:  [<ffffffffa0816a5a>] ? find_ref_head+0x5a/0x80 [btrfs]
Oct 19 18:33:59 localhost kernel:  [<ffffffffa07b23c8>] __btrfs_run_delayed_refs+0x998/0x1080 [btrfs]
Oct 19 18:33:59 localhost kernel:  [<ffffffff81200083>] ? kmem_cache_alloc+0x193/0x210
Oct 19 18:33:59 localhost kernel:  [<ffffffffa07b5674>] btrfs_run_delayed_refs.part.73+0x74/0x270 [btrfs]
Oct 19 18:33:59 localhost kernel:  [<ffffffffa07b590e>] delayed_ref_async_start+0x7e/0x90 [btrfs]
Oct 19 18:33:59 localhost kernel:  [<ffffffffa07fb322>] btrfs_scrubparity_helper+0xc2/0x260 [btrfs]
Oct 19 18:33:59 localhost kernel:  [<ffffffffa07fb4fe>] btrfs_extent_refs_helper+0xe/0x10 [btrfs]
Oct 19 18:33:59 localhost kernel:  [<ffffffff810b64fe>] process_one_work+0x19e/0x3f0
Oct 19 18:33:59 localhost kernel:  [<ffffffff810b679e>] worker_thread+0x4e/0x450
Oct 19 18:33:59 localhost kernel:  [<ffffffff810b6750>] ? process_one_work+0x3f0/0x3f0
Oct 19 18:33:59 localhost kernel:  [<ffffffff810b6750>] ? process_one_work+0x3f0/0x3f0
Oct 19 18:33:59 localhost kernel:  [<ffffffff810bc8a8>] kthread+0xd8/0xf0
Oct 19 18:33:59 localhost kernel:  [<ffffffff810bc7d0>] ? kthread_worker_fn+0x160/0x160
Oct 19 18:33:59 localhost kernel:  [<ffffffff81778fdf>] ret_from_fork+0x3f/0x70
Oct 19 18:33:59 localhost kernel:  [<ffffffff810bc7d0>] ? kthread_worker_fn+0x160/0x160
Oct 19 18:33:59 localhost kernel: ---[ end trace 0eadb91546850dad ]---
Oct 19 18:33:59 localhost kernel: BTRFS: error (device sda1) in __btrfs_free_extent:6261: errno=-2 No such entry
Oct 19 18:33:59 localhost kernel: BTRFS info (device sda1): forced readonly
Oct 19 18:33:59 localhost kernel: BTRFS: error (device sda1) in btrfs_run_delayed_refs:2781: errno=-2 No such entry
Oct 19 18:33:59 localhost kernel: BTRFS warning (device sda1): Skipping commit of aborted transaction.
Oct 19 18:33:59 localhost kernel: BTRFS: error (device sda1) in cleanup_transaction:1710: errno=-2 No such entry

-- 
Suvayu

Open source is the future. It sets us free.