Martin Steigerwald
2011-Jun-23 17:37 UTC
btrfs: failed to load free space cache for block group on rsync´ing to space_cache BTRFS with subvolume
Hi!
Short summary: I suspect that rsync´ing files to a newly created BTRFS
partition with a subvolume *and* enabled space_cache triggers the error
mentioned in the subject line of this mail. I reported this also as:
Bug 38112 - btrfs: failed to load free space cache for block group on
rsync´ing to space_cache BTRFS with subvolume
https://bugzilla.kernel.org/show_bug.cgi?id=38112
I will add a reference to my post here to the bug report, so feel free to
use whatever suits you best to follow up.
This happened on a ThinkPad T520 with 3.0.0-rc3-amd64 Debian/GNU Linux
kernel. The issue happened on a 2.5 inch external eSATA/USB harddisk which
I changed to BTRFS. On the repoot after the rsync process was stalled the
unrelated non space cache using root filesystem did not mount anymore with
3.0.0-rc3-amd64 and 2.6.39-2-amd64 kernel. But thankfully it did mount
with a 2.6.38 grml 2011 amd64 kernel and now work again.
Thus I did
merkaba:~> mkfs.btrfs -L daten /dev/sdc2
WARNING! - Btrfs Btrfs v0.19 IS EXPERIMENTAL
WARNING! - see http://btrfs.wiki.kernel.org before using
fs created label daten on /dev/sdc2
nodesize 4096 leafsize 4096 sectorsize 4096 size 447.13GB
Btrfs Btrfs v0.19
merkaba:~> mount -o space_cache,compress=lzo /dev/sdc2 /mnt/amazon-daten
merkaba:~> dmesg | tail -3
[137440.930038] device label daten devid 1 transid 7 /dev/sdc2
[137440.930507] btrfs: enabling disk space caching
[137440.930518] btrfs: use lzo compression
Then I unmounted, added a fstab entry without space_cache option since I
read that once BTRFS created a space_cache it would use it anyway it is
mounted with clear_cache to clear the cache again.
I created a sub volume for movies, cause I wanted to be able to not
snapshot the movie files:
merkaba:~> btrfs subvolume create /mnt/amazon-daten/Filme
Create subvolume ''/mnt/amazon-daten/Filme''
I then did my rsync from the backup which BTW was a BTRFS with space_cache
as well - created today:
merkaba:~> rsync -a -H --acls --xattrs --sparse /mnt/steigerwald-daten/
/mnt/amazon-daten
A short while after starting the rsync I got:
137927.147255] btrfs: failed to load free space cache for block group
147131990016
[138110.390962] ------------[ cut here ]------------
[138110.392736] kernel BUG at
/media/data/mattems/src/linux-2.6-3.0.0~rc3/debian/build/source_amd64_none/fs/btrfs/free-
space-cache.c:1186!
[138110.394536] invalid opcode: 0000 [#1] SMP
[138110.396322] CPU 0
[138110.396331] Modules linked in: ufs qnx4 hfsplus hfs minix ntfs vfat
msdos fat jfs xfs reiserfs ext3 jbd ext2 ums_cypress usb_storage uas tun
cpufreq_conservative cpufreq_stats parport_pc ppdev cpufreq_powersave
cpufreq_userspace lp parport bnep acpi_cpufreq mperf rfcomm bluetooth
uinput fuse nfsd nfs lockd fscache auth_rpcgss nfs_acl sunrpc ext4 mbcache
jbd2 crc16 acpiphp pci_hotplug loop firewire_sbp2 snd_hda_codec_hdmi
snd_hda_codec_conexant joydev arc4 snd_hda_intel snd_hda_codec snd_hwdep
ac snd_pcm snd_seq snd_timer snd_seq_device thinkpad_acpi tpm_tis snd
nvram psmouse tpm battery evdev serio_raw i2c_i801 pcspkr tpm_bios
power_supply i915 wmi drm_kms_helper soundcore snd_page_alloc rfkill drm
i2c_algo_bit i2c_core video button processor dm_mod raid10 raid456
async_raid6_recov async_pq raid6_pq async_xor xor async_memcpy async_tx
raid1 raid0 multipath linear md_mod btrfs zlib_deflate crc32c libcrc32c sg
sr_mod sd_mod cdrom crc_t10dif usbhid sdhci_pci firewire_ohci sdhci hid
mmc_core ahci sata_sil24 libahci libata firewire_core crc_itu_t scsi_mod
ehci_hcd thermal thermal_sys usbcore e1000e [last unloaded: cfg80211]
[138110.407957]
[138110.409950] Pid: 26438, comm: btrfs-transacti Tainted: G W
3.0.0-rc3-amd64 #1 LENOVO 42433WG/42433WG
[138110.411984] RIP: 0010:[<ffffffffa01b845b>] [<ffffffffa01b845b>]
recalculate_thresholds+0x21/0x6c [btrfs]
[138110.414051] RSP: 0018:ffff880182b2fcd8 EFLAGS: 00010202
[138110.416107] RAX: 0000000000000001 RBX: ffff880212442440 RCX:
0000000008000000
[138110.418179] RDX: 0000000007ffffff RSI: 0000000000000002 RDI:
ffff880212442440
[138110.420244] RBP: 0000000000000000 R08: 0000000008000000 R09:
ffff88019a155720
[138110.422297] R10: ffff880105f6e3b8 R11: ffff880100000001 R12:
ffff88020f220ba0
[138110.424356] R13: 0000002241fdd000 R14: ffff880105f6e3b8 R15:
0000000000001000
[138110.426410] FS: 0000000000000000(0000) GS:ffff88021e200000(0000)
knlGS:0000000000000000
[138110.428467] CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[138110.430522] CR2: 00007f0529281034 CR3: 0000000146086000 CR4:
00000000000406f0
[138110.432576] DR0: 0000000000000000 DR1: 0000000000000000 DR2:
0000000000000000
[138110.434620] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7:
0000000000000400
[138110.436656] Process btrfs-transacti (pid: 26438, threadinfo
ffff880182b2e000, task ffff880212054140)
[138110.438704] Stack:
[138110.440740] ffffffffa01baa5e ffff880105f6e390 ffff8802092f7c80
0000000005f6c0b8
[138110.442788] ffff8802092f7d58 0000000000000001 ffff8802092f7c80
0000000000001000
[138110.444814] 0000002241fdd000 0000002241fddfff 0000002241fde000
ffff880105f6c000
[138110.446836] Call Trace:
[138110.448914] [<ffffffffa01baa5e>] ? __btrfs_add_free_space+0x1fc/0x2f4
[btrfs]
[138110.450923] [<ffffffffa01781e7>] ? unpin_extent_range+0x95/0x131
[btrfs]
[138110.452917] [<ffffffffa0179c57>] ?
btrfs_finish_extent_commit+0xab/0x19f
[btrfs]
[138110.454902] [<ffffffffa018afb6>] ?
btrfs_commit_transaction+0x566/0x67e
[btrfs]
[138110.456874] [<ffffffff8105ff19>] ? wake_up_bit+0x20/0x20
[138110.458838] [<ffffffffa018b507>] ? start_transaction+0x1f5/0x242
[btrfs]
[138110.460786] [<ffffffffa0185fd3>] ? transaction_kthread+0x173/0x22d
[btrfs]
[138110.462733] [<ffffffffa0185e60>] ? find_and_setup_root+0xcb/0xcb
[btrfs]
[138110.464658] [<ffffffffa0185e60>] ? find_and_setup_root+0xcb/0xcb
[btrfs]
[138110.466541] [<ffffffff8105fadd>] ? kthread+0x7a/0x82
[138110.468411] [<ffffffff8133dd24>] ? kernel_thread_helper+0x4/0x10
[138110.470274] [<ffffffff8105fa63>] ? kthread_worker_fn+0x147/0x147
[138110.472111] [<ffffffff8133dd20>] ? gs_change+0x13/0x13
[138110.473928] Code: 30 48 c7 47 20 00 00 00 00 c3 48 8b 47 38 31 d2 8b
77 20 4c 8b 40 70 48 8b 48 09 49 c1 e0 0f 49 8d 44 08 ff 49 f7 f0 39 c6 7e
04 <0f> 0b eb fe 48 81 f9 ff ff ff 3f b8 00 80 00 00 76 0b 48 89 c8
[138110.475922] RIP [<ffffffffa01b845b>] recalculate_thresholds+0x21/0x6c
[btrfs]
[138110.477847] RSP <ffff880182b2fcd8>
[138110.549460] ---[ end trace 131766a12388cd20 ]---
[138138.490877] BUG: soft lockup - CPU#2 stuck for 22s! [btrfs-delayed-
m:26480]
[138138.490885] Modules linked in: ufs qnx4 hfsplus hfs minix ntfs vfat
msdos fat jfs xfs reiserfs ext3 jbd ext2 ums_cypress usb_storage uas tun
cpufreq_conservative cpufreq_stats parport_pc ppdev cpufreq_powersave
cpufreq_userspace lp parport bnep acpi_cpufreq mperf rfcomm bluetooth
uinput fuse nfsd nfs lockd fscache auth_rpcgss nfs_acl sunrpc ext4 mbcache
jbd2 crc16 acpiphp pci_hotplug loop firewire_sbp2 snd_hda_codec_hdmi
snd_hda_codec_conexant joydev arc4 snd_hda_intel snd_hda_codec snd_hwdep
ac snd_pcm snd_seq snd_timer snd_seq_device thinkpad_acpi tpm_tis snd
nvram psmouse tpm battery evdev serio_raw i2c_i801 pcspkr tpm_bios
power_supply i915 wmi drm_kms_helper soundcore snd_page_alloc rfkill drm
i2c_algo_bit i2c_core video button processor dm_mod raid10 raid456
async_raid6_recov async_pq raid6_pq async_xor xor async_memcpy async_tx
raid1 raid0 multipath linear md_mod btrfs zlib_deflate crc32c libcrc32c sg
sr_mod sd_mod cdrom crc_t10dif usbhid sdhci_pci firewire_ohci sdhci hid
mmc_core ahci sata_sil24 libahci libata firewire_core crc_itu_t scsi_mod
ehci_hcd thermal thermal_sys usbcore e1000e [last unloaded: cfg80211]
[138138.491076] CPU 2
[138138.491079] Modules linked in: ufs qnx4 hfsplus hfs minix ntfs vfat
msdos fat jfs xfs reiserfs ext3 jbd ext2 ums_cypress usb_storage uas tun
cpufreq_conservative cpufreq_stats parport_pc ppdev cpufreq_powersave
cpufreq_userspace lp parport bnep acpi_cpufreq mperf rfcomm bluetooth
uinput fuse nfsd nfs lockd fscache auth_rpcgss nfs_acl sunrpc ext4 mbcache
jbd2 crc16 acpiphp pci_hotplug loop firewire_sbp2 snd_hda_codec_hdmi
snd_hda_codec_conexant joydev arc4 snd_hda_intel snd_hda_codec snd_hwdep
ac snd_pcm snd_seq snd_timer snd_seq_device thinkpad_acpi tpm_tis snd
nvram psmouse tpm battery evdev serio_raw i2c_i801 pcspkr tpm_bios
power_supply i915 wmi drm_kms_helper soundcore snd_page_alloc rfkill drm
i2c_algo_bit i2c_core video button processor dm_mod raid10 raid456
async_raid6_recov async_pq raid6_pq async_xor xor async_memcpy async_tx
raid1 raid0 multipath linear md_mod btrfs zlib_deflate crc32c libcrc32c sg
sr_mod sd_mod cdrom crc_t10dif usbhid sdhci_pci firewire_ohci sdhci hid
mmc_core ahci sata_sil24 libahci libata firewire_core crc_itu_t scsi_mod
ehci_hcd thermal thermal_sys usbcore e1000e [last unloaded: cfg80211]
[138138.491241]
[138138.491248] Pid: 26480, comm: btrfs-delayed-m Tainted: G D W
3.0.0-rc3-amd64 #1 LENOVO 42433WG/42433WG
[138138.491258] RIP: 0010:[<ffffffff81337607>] [<ffffffff81337607>]
_raw_spin_lock+0x13/0x1b
[138138.491276] RSP: 0018:ffff8801011ff958 EFLAGS: 00000297
[138138.491282] RAX: 000000000000143d RBX: ffff88019576cc28 RCX:
0000000000001000
[138138.491288] RDX: 000000000000143c RSI: ffff8802092f7c80 RDI:
ffff880212442440
[138138.491294] RBP: ffff880105f6e390 R08: 0000002241c8c000 R09:
ffffffffffffffff
[138138.491299] R10: dead000000200200 R11: 0000000000000000 R12:
ffffffff8133d5ce
[138138.491305] R13: 0000000000000000 R14: 0000000000000af7 R15:
ffffffffa01a4f88
[138138.491312] FS: 0000000000000000(0000) GS:ffff88021e280000(0000)
knlGS:0000000000000000
[138138.491318] CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[138138.491324] CR2: 00007f9be3bed000 CR3: 0000000001603000 CR4:
00000000000406e0
[138138.491329] DR0: 0000000000000000 DR1: 0000000000000000 DR2:
0000000000000000
[138138.491335] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7:
0000000000000400
[138138.491342] Process btrfs-delayed-m (pid: 26480, threadinfo
ffff8801011fe000, task ffff8801c2b3d120)
[138138.491347] Stack:
[138138.491351] ffffffffa017fbcc ffff880189996b40 ffff880100000021
0000000000000000
[138138.491361] 0000000000001000 0000000003856f00 ffffffffa01a4300
ffff880105f6e394
[138138.491371] 0000000000000000 0000002241c8c000 00010000a01a4300
ffff880138b41800
[138138.491382] Call Trace:
[138138.491419] [<ffffffffa017fbcc>] ? find_free_extent+0x542/0xa4b
[btrfs]
[138138.491456] [<ffffffffa01a4300>] ?
map_private_extent_buffer+0xa3/0xc4
[btrfs]
[138138.491489] [<ffffffffa0180191>] ? btrfs_reserve_extent+0xbc/0x1cd
[btrfs]
[138138.491518] [<ffffffffa0178ffd>] ? reserve_metadata_bytes+0x54/0x1a6
[btrfs]
[138138.491548] [<ffffffffa0180403>] ? btrfs_alloc_free_block+0x161/0x292
[btrfs]
[138138.491575] [<ffffffffa0173091>] ? __btrfs_cow_block+0x109/0x34b
[btrfs]
[138138.491586] [<ffffffff810415ab>] ? check_preempt_wakeup+0x11f/0x19f
[138138.491612] [<ffffffffa0173862>] ? btrfs_cow_block+0xf7/0x143 [btrfs]
[138138.491639] [<ffffffffa0175135>] ? btrfs_search_slot+0x140/0x4c6
[btrfs]
[138138.491647] [<ffffffff81008596>] ? __switch_to+0xc5/0x288
[138138.491654] [<ffffffff8103b918>] ? pick_next_task_fair+0xf9/0x10b
[138138.491664] [<ffffffff81336c31>] ? mutex_lock+0xd/0x2c
[138138.491695] [<ffffffffa01839ad>] ? btrfs_lookup_inode+0x25/0x84
[btrfs]
[138138.491704] [<ffffffff81336c31>] ? mutex_lock+0xd/0x2c
[138138.491733] [<ffffffffa01c59ae>] ?
btrfs_update_delayed_inode+0x6b/0x126
[btrfs]
[138138.491767] [<ffffffffa018b507>] ? start_transaction+0x1f5/0x242
[btrfs]
[138138.491795] [<ffffffffa01c640f>] ?
btrfs_async_run_delayed_node_done+0x8a/0x138 [btrfs]
[138138.491828] [<ffffffffa01ae872>] ? worker_loop+0x186/0x4a1 [btrfs]
[138138.491837] [<ffffffff813361ea>] ? schedule+0x5ed/0x61a
[138138.491866] [<ffffffffa01ae6ec>] ? btrfs_queue_worker+0x24a/0x24a
[btrfs]
[138138.491894] [<ffffffffa01ae6ec>] ? btrfs_queue_worker+0x24a/0x24a
[btrfs]
[138138.491904] [<ffffffff8105fadd>] ? kthread+0x7a/0x82
[138138.491914] [<ffffffff8133dd24>] ? kernel_thread_helper+0x4/0x10
[138138.491923] [<ffffffff8105fa63>] ? kthread_worker_fn+0x147/0x147
[138138.491932] [<ffffffff8133dd20>] ? gs_change+0x13/0x13
[138138.491936] Code: 00 01 00 75 04 f0 0f b1 17 0f 94 c2 0f b6 c2 85 c0
0f 95 c0 0f b6 c0 c3 b8 00 00 01 00 f0 0f c1 07 0f b7 d0 c1 e8 10 39 c2 74
07 <f3> 90 0f b7 17 eb f5 c3 9c 58 66 66 90 66 90 48 89 c2 fa 66 66
[138138.492000] Call Trace:
[138138.492029] [<ffffffffa017fbcc>] ? find_free_extent+0x542/0xa4b
[btrfs]
[138138.492062] [<ffffffffa01a4300>] ?
map_private_extent_buffer+0xa3/0xc4
[btrfs]
[138138.492092] [<ffffffffa0180191>] ? btrfs_reserve_extent+0xbc/0x1cd
[btrfs]
[138138.492121] [<ffffffffa0178ffd>] ? reserve_metadata_bytes+0x54/0x1a6
[btrfs]
[138138.492150] [<ffffffffa0180403>] ? btrfs_alloc_free_block+0x161/0x292
[btrfs]
[138138.492176] [<ffffffffa0173091>] ? __btrfs_cow_block+0x109/0x34b
[btrfs]
[138138.492185] [<ffffffff810415ab>] ? check_preempt_wakeup+0x11f/0x19f
[138138.492211] [<ffffffffa0173862>] ? btrfs_cow_block+0xf7/0x143 [btrfs]
[138138.492238] [<ffffffffa0175135>] ? btrfs_search_slot+0x140/0x4c6
[btrfs]
[138138.492245] [<ffffffff81008596>] ? __switch_to+0xc5/0x288
[138138.492251] [<ffffffff8103b918>] ? pick_next_task_fair+0xf9/0x10b
[138138.492260] [<ffffffff81336c31>] ? mutex_lock+0xd/0x2c
[138138.492289] [<ffffffffa01839ad>] ? btrfs_lookup_inode+0x25/0x84
[btrfs]
[138138.492298] [<ffffffff81336c31>] ? mutex_lock+0xd/0x2c
[138138.492326] [<ffffffffa01c59ae>] ?
btrfs_update_delayed_inode+0x6b/0x126
[btrfs]
[138138.492359] [<ffffffffa018b507>] ? start_transaction+0x1f5/0x242
[btrfs]
[138138.492387] [<ffffffffa01c640f>] ?
btrfs_async_run_delayed_node_done+0x8a/0x138 [btrfs]
[138138.492417] [<ffffffffa01ae872>] ? worker_loop+0x186/0x4a1 [btrfs]
[138138.492426] [<ffffffff813361ea>] ? schedule+0x5ed/0x61a
[138138.492453] [<ffffffffa01ae6ec>] ? btrfs_queue_worker+0x24a/0x24a
[btrfs]
[138138.492480] [<ffffffffa01ae6ec>] ? btrfs_queue_worker+0x24a/0x24a
[btrfs]
[138138.492489] [<ffffffff8105fadd>] ? kthread+0x7a/0x82
[138138.492498] [<ffffffff8133dd24>] ? kernel_thread_helper+0x4/0x10
[138138.492507] [<ffffffff8105fa63>] ? kthread_worker_fn+0x147/0x147
[138138.492516] [<ffffffff8133dd20>] ? gs_change+0x13/0x13
merkaba:~>
Message from syslogd@merkaba at Jun 23 18:30:41 ...
kernel:[138166.427817] Stack:
Message from syslogd@merkaba at Jun 23 18:30:41 ...
kernel:[138166.427851] Call Trace:
Message from syslogd@merkaba at Jun 23 18:30:41 ...
kernel:[138166.428406] Code: 00 01 00 75 04 f0 0f b1 17 0f 94 c2 0f b6 c2
85 c0 0f 95 c0 0f b6 c0 c3 b8 00 00 01 00 f0 0f c1 07 0f b7 d0 c1 e8 10 39
c2 74 07 <f3> 90 0f b7 17 eb f5 c3 9c 58 66 66 90 66 90 48 89 c2 fa 66 66
Message from syslogd@merkaba at Jun 23 18:30:46 ...
kernel:[138171.396102] Stack:
Message from syslogd@merkaba at Jun 23 18:30:46 ...
kernel:[138171.396150] Call Trace:
Message from syslogd@merkaba at Jun 23 18:30:46 ...
kernel:[138171.396227] Code: e0 ff ff a8 08 75 0e e8 7e ba da e0 66 90 fa
66 66 90 66 66 90 65 48 8b 04 25 08 cd 00 00 83 88 3c e0 ff ff 04 eb 0c 8b
57 04 ec
Message from syslogd@merkaba at Jun 23 18:30:46 ...
kernel:[138171.396667] Stack:
Message from syslogd@merkaba at Jun 23 18:30:46 ...
kernel:[138171.396700] Call Trace:
Message from syslogd@merkaba at Jun 23 18:30:46 ...
kernel:[138171.396703] <IRQ>
Message from syslogd@merkaba at Jun 23 18:30:46 ...
kernel:[138171.396840] <EOI>
Message from syslogd@merkaba at Jun 23 18:30:46 ...
kernel:[138171.397396] Code: 41 ff c0 4c 89 0c 07 48 83 c0 08 41 39 c8 7c
e8 c3 48 63 c9 45 31 c0 45 31 c9 48 83 c1 3f 45 31 d2 48 c1 e9 06 eb 19 4a
8b 04 02
Message from syslogd@merkaba at Jun 23 18:30:46 ...
kernel:[138171.398412] Stack:
Message from syslogd@merkaba at Jun 23 18:30:46 ...
kernel:[138171.398447] Call Trace:
Message from syslogd@merkaba at Jun 23 18:30:46 ...
kernel:[138171.398451] <IRQ>
Message from syslogd@merkaba at Jun 23 18:30:46 ...
kernel:[138171.398485] <EOI>
Message from syslogd@merkaba at Jun 23 18:30:46 ...
kernel:[138171.398574] Code: 44 e0 ff ff 00 00 01 00 48 63 80 44 e0 ff ff a9
00 ff ff 07 75 37 65 8b 04 25 80 26 01 00 85 c0 74 2b 80 3d 2d a2 63 00 00
75 07 <e8> 4e f4 fb ff eb 1b 65 48 8b 3c 25 70 e6 00 00 48 85 ff 74 0d
Since the backup process was stalled, rsync was D+ and umount -lf did
hang, too. I decided that it would be better to reboot my machine.
Then I was scared away that neither 3.0.0-rc3-amd64 and 2.6.39-2-amd64
debian kernel were able to mount a completely unrelated BTRFS filesystem.
Namely my BTRFS root filesystem located on an Intel SSD 320 with 300 GB. I
got a backtrace I unfortunately did not photograph, cause I thought I will
see it on recovery with GRML anyway, and got dumped to initramfs shell.
On an other ThinkPad, a T42, I grabbed grml 2011.05 64-Bit and dd´d it a
an USB stick. And thanks God there, with a 2.6.38 grml kernel, my BTRFS
root filesystem did mount well. Just for sure I run a mount -o clear_cache
on the root filesystem although I never activated space_cache there.
Then I rebooted into my Debian Unstable and all was well again.
The only hints in syslog I found were:
1741 Jun 23 18:15:34 merkaba kernel: [137261.752879] ata6: SATA link up
3.0 Gbps (SStatus 123 SControl 300)
1742 Jun 23 18:15:34 merkaba kernel: [137261.753946] ata6.00: ACPI cmd
ef/02:00:00:00:00:a0 (SET FEATURES) succeeded
1743 Jun 23 18:15:34 merkaba kernel: [137261.753956] ata6.00: ACPI cmd
f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out
1744 Jun 23 18:15:34 merkaba kernel: [137261.756041] ata6.00: ACPI cmd
ef/02:00:00:00:00:a0 (SET FEATURES) succeeded
1745 Jun 23 18:15:34 merkaba kernel: [137261.756055] ata6.00: ACPI cmd
f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out
1746 Jun 23 18:15:34 merkaba kernel: [137261.757703] ata6.00: configured
for UDMA/133
1747 Jun 23 18:15:34 merkaba kernel: [137261.772834] ata6: EH complete
1748 Jun 23 18:17:01 merkaba /USR/SBIN/CRON[25888]: (root) CMD ( cd /
&&
run-parts --report /etc/cron.hourly)
1749 Jun 23 18:18:34 merkaba kernel: [137440.930038] device label daten
devid 1 transid 7 /dev/sdc2
1750 Jun 23 18:18:34 merkaba kernel: [137440.930507] btrfs: enabling disk
space caching
1751 Jun 23 18:18:34 merkaba kernel: [137440.930518] btrfs: use lzo
compression
1752 Jun 23 18:22:00 merkaba kernel: [137646.534245] device label daten
devid 1 transid 10 /dev/sdc2
1753 Jun 23 18:22:00 merkaba kernel: [137646.534556] btrfs: use lzo
compression
1754 Jun 23 18:22:00 merkaba kernel: [137646.549740] btrfs: disk space
caching is enabled
1755 Jun 23 18:24:48 merkaba kernel: [137813.653916] device label daten-
backup devid 1 transid 162 /dev/mapper/steigerwald-daten
1756 Jun 23 18:24:48 merkaba kernel: [137813.654566] btrfs: use lzo
compression
1757 Jun 23 18:24:48 merkaba kernel: [137813.691677] btrfs: disk space
caching is enabled
1758 Jun 23 18:26:41 merkaba kernel: [137927.147252] block group
147131990016 has an wrong amount of free space
1759 Jun 23 18:26:41 merkaba kernel: [137927.147255] btrfs: failed to load
free space cache for block group 147131990016
Then there is a long gap where apparently nothing got written onto the
root filesystem anymore. Partly due to me using GRML trying to restore
things.
1760 Jun 23 19:00:01 merkaba kernel: imklog 5.8.2, log source = /proc/kmsg
started.
1761 Jun 23 19:00:01 merkaba rsyslogd: [origin software="rsyslogd"
swVersion="5.8.2" x-pid="1342"
x-info="http://www.rsyslog.com"] start
1762 Jun 23 19:00:01 merkaba kernel: [ 0.000000] Initializing cgroup
subsys cpuset
1763 Jun 23 19:00:01 merkaba kernel: [ 0.000000] Initializing cgroup
subsys cpu
1764 Jun 23 19:00:01 merkaba kernel: [ 0.000000] Linux version 3.0.0-
rc3-amd64 (Debian 3.0.0~rc3-1~experimental.1) (maks@debian.org) ( gcc
version 4.4.6 (Debian 4.4.6-6) ) #1 SMP Thu Jun 16 13:23:22 UTC 2011
Since rsyncing files and movies to two different BTRFS partitions that
actually used space_cache I suspect that the failure is related to having
the subvolume on the BTRFS filesystem that failed so miserably.
As for reproducability: I am now restoring the backup for my external
drive to a BTRFS *without* space cache to have my data redundant again.
But I did create the subvolume again to see whether the only difference
really is the space cache. Lets see how it turns out.
Thus I do not like to use this drive for another experiment. But I should
have another 60/80 GB 2.5 inch drives here where I could test it.
Suspected steps to reproduce:
- create BTRFS
- mount with compress=lzo,space_cache enabled
- umount
- mount again only with compress=lzo
- create subvolume
- rsync stuff to it
- issue should appear after some MB of data transferred
Ciao,
--
Martin ''Helios'' Steigerwald - http://www.Lichtvoll.de
GPG: 03B0 0D6C 0040 0710 4AFA B82F 991B EAAC A599 84C7
--
To unsubscribe from this list: send the line "unsubscribe linux-btrfs"
in
the body of a message to majordomo@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Josef Bacik
2011-Jun-23 20:05 UTC
Re: btrfs: failed to load free space cache for block group on rsync´ing to space_cache BTRFS with subvolume
On Thu, Jun 23, 2011 at 07:37:12PM +0200, Martin Steigerwald wrote:> Hi! > > Short summary: I suspect that rsync´ing files to a newly created BTRFS > partition with a subvolume *and* enabled space_cache triggers the error > mentioned in the subject line of this mail. I reported this also as: > > Bug 38112 - btrfs: failed to load free space cache for block group on > rsync´ing to space_cache BTRFS with subvolume > > https://bugzilla.kernel.org/show_bug.cgi?id=38112 > > I will add a reference to my post here to the bug report, so feel free to > use whatever suits you best to follow up. > > > This happened on a ThinkPad T520 with 3.0.0-rc3-amd64 Debian/GNU Linux > kernel. The issue happened on a 2.5 inch external eSATA/USB harddisk which > I changed to BTRFS. On the repoot after the rsync process was stalled the > unrelated non space cache using root filesystem did not mount anymore with > 3.0.0-rc3-amd64 and 2.6.39-2-amd64 kernel. But thankfully it did mount > with a 2.6.38 grml 2011 amd64 kernel and now work again. > > > Thus I did > > merkaba:~> mkfs.btrfs -L daten /dev/sdc2 > > WARNING! - Btrfs Btrfs v0.19 IS EXPERIMENTAL > WARNING! - see http://btrfs.wiki.kernel.org before using > > fs created label daten on /dev/sdc2 > nodesize 4096 leafsize 4096 sectorsize 4096 size 447.13GB > Btrfs Btrfs v0.19 > > merkaba:~> mount -o space_cache,compress=lzo /dev/sdc2 /mnt/amazon-daten > merkaba:~> dmesg | tail -3 > [137440.930038] device label daten devid 1 transid 7 /dev/sdc2 > [137440.930507] btrfs: enabling disk space caching > [137440.930518] btrfs: use lzo compression > > > Then I unmounted, added a fstab entry without space_cache option since I > read that once BTRFS created a space_cache it would use it anyway it is > mounted with clear_cache to clear the cache again. > > I created a sub volume for movies, cause I wanted to be able to not > snapshot the movie files: > > merkaba:~> btrfs subvolume create /mnt/amazon-daten/Filme > Create subvolume ''/mnt/amazon-daten/Filme'' > > I then did my rsync from the backup which BTW was a BTRFS with space_cache > as well - created today: > > merkaba:~> rsync -a -H --acls --xattrs --sparse /mnt/steigerwald-daten/ > /mnt/amazon-daten > > A short while after starting the rsync I got: >I''ve just posted a patch for this, sorry about that I''ve fixed this before but there has been recent work in this area to make it more generic and we lost that particular fix. Thanks, Josef -- To unsubscribe from this list: send the line "unsubscribe linux-btrfs" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Gerhard Kulzer
2011-Jun-23 20:42 UTC
Re: btrfs: failed to load free space cache for block group on rsync´ing to space_cache BTRFS with subvolume
Martin Steigerwald <Martin <at> lichtvoll.de> writes:> > Hi! > > Short summary: I suspect that rsync´ing files to a newly created BTRFS > partition with a subvolume *and* enabled space_cache triggers the error > mentioned in the subject line of this mail. I reported this also as: > > Bug 38112 - btrfs: failed to load free space cache for block group on > rsync´ing to space_cache BTRFS with subvolume > > https://bugzilla.kernel.org/show_bug.cgi?id=38112 >Same happens to me when I use Ubuntu kernel 3.0.1, after a short time like 20 seconds into the desktop I get the same error message. This happens on a btrfs system that is already 2 years old and never had that problem (mount=ssd, compress=lzo,noatime, space_cache). When I boot with 2.6.38-10 I never get this error. So I assume that the problem is with the newer code of 3.0.1 Gerhard -- To unsubscribe from this list: send the line "unsubscribe linux-btrfs" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Martin Steigerwald
2011-Jun-24 12:46 UTC
Re: btrfs: failed to load free space cache for block group on rsync´ing to space_cache BTRFS with subvolume
Am Donnerstag, 23. Juni 2011 schrieb Josef Bacik:> On Thu, Jun 23, 2011 at 07:37:12PM +0200, Martin Steigerwald wrote: > > Hi! > > > > Short summary: I suspect that rsync´ing files to a newly created > > BTRFS partition with a subvolume *and* enabled space_cache triggers > > the error mentioned in the subject line of this mail. I reported > > this also as: > > > > Bug 38112 - btrfs: failed to load free space cache for block group > > on rsync´ing to space_cache BTRFS with subvolume > > > > https://bugzilla.kernel.org/show_bug.cgi?id=38112 > > > > I will add a reference to my post here to the bug report, so feel > > free to use whatever suits you best to follow up. > > > > > > This happened on a ThinkPad T520 with 3.0.0-rc3-amd64 Debian/GNU > > Linux kernel. The issue happened on a 2.5 inch external eSATA/USB > > harddisk which I changed to BTRFS. On the repoot after the rsync > > process was stalled the unrelated non space cache using root > > filesystem did not mount anymore with 3.0.0-rc3-amd64 and > > 2.6.39-2-amd64 kernel. But thankfully it did mount with a 2.6.38 > > grml 2011 amd64 kernel and now work again. > > > > > > Thus I did > > > > merkaba:~> mkfs.btrfs -L daten /dev/sdc2 > > > > WARNING! - Btrfs Btrfs v0.19 IS EXPERIMENTAL > > WARNING! - see http://btrfs.wiki.kernel.org before using > > > > fs created label daten on /dev/sdc2 > > > > nodesize 4096 leafsize 4096 sectorsize 4096 size 447.13GB > > > > Btrfs Btrfs v0.19 > > > > merkaba:~> mount -o space_cache,compress=lzo /dev/sdc2 > > /mnt/amazon-daten merkaba:~> dmesg | tail -3 > > [137440.930038] device label daten devid 1 transid 7 /dev/sdc2 > > [137440.930507] btrfs: enabling disk space caching > > [137440.930518] btrfs: use lzo compression > > > > > > Then I unmounted, added a fstab entry without space_cache option > > since I read that once BTRFS created a space_cache it would use it > > anyway it is mounted with clear_cache to clear the cache again. > > > > I created a sub volume for movies, cause I wanted to be able to not > > snapshot the movie files: > > > > merkaba:~> btrfs subvolume create /mnt/amazon-daten/Filme > > Create subvolume ''/mnt/amazon-daten/Filme'' > > > > I then did my rsync from the backup which BTW was a BTRFS with > > space_cache as well - created today: > > > > merkaba:~> rsync -a -H --acls --xattrs --sparse > > /mnt/steigerwald-daten/ /mnt/amazon-daten > > > A short while after starting the rsync I got: > I''ve just posted a patch for this, sorry about that I''ve fixed this > before but there has been recent work in this area to make it more > generic and we lost that particular fix. Thanks,Is it: [PATCH] Btrfs: make sure to update total_bitmaps when freeing cache V2 ? Do you need testing? Is this scheduled for 3.0.0-rc5 or something like this? Then I could wait for the Debian kernel 3.0.0-rc5 to become available. I can do without space_cache for the time being. I am a bit reluctant with testing as even tough the problem happened on a different filesystem my root filesystem located on a different was not mountable with 2.6.39 and 3.0.0-rc3. Too bad I didn´t take a photo of the backtrace that dumped me to initramfs. I can try this again, hoping, that again 2.6.38 grml will mount this, but I am a bit wary with that. Thanks, -- Martin ''Helios'' Steigerwald - http://www.Lichtvoll.de GPG: 03B0 0D6C 0040 0710 4AFA B82F 991B EAAC A599 84C7 -- To unsubscribe from this list: send the line "unsubscribe linux-btrfs" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Josef Bacik
2011-Jun-24 13:04 UTC
Re: btrfs: failed to load free space cache for block group on rsync´ing to space_cache BTRFS with subvolume
On 06/24/2011 08:46 AM, Martin Steigerwald wrote:> Am Donnerstag, 23. Juni 2011 schrieb Josef Bacik: >> On Thu, Jun 23, 2011 at 07:37:12PM +0200, Martin Steigerwald wrote: >>> Hi! >>> >>> Short summary: I suspect that rsync´ing files to a newly created >>> BTRFS partition with a subvolume *and* enabled space_cache triggers >>> the error mentioned in the subject line of this mail. I reported >>> this also as: >>> >>> Bug 38112 - btrfs: failed to load free space cache for block group >>> on rsync´ing to space_cache BTRFS with subvolume >>> >>> https://bugzilla.kernel.org/show_bug.cgi?id=38112 >>> >>> I will add a reference to my post here to the bug report, so feel >>> free to use whatever suits you best to follow up. >>> >>> >>> This happened on a ThinkPad T520 with 3.0.0-rc3-amd64 Debian/GNU >>> Linux kernel. The issue happened on a 2.5 inch external eSATA/USB >>> harddisk which I changed to BTRFS. On the repoot after the rsync >>> process was stalled the unrelated non space cache using root >>> filesystem did not mount anymore with 3.0.0-rc3-amd64 and >>> 2.6.39-2-amd64 kernel. But thankfully it did mount with a 2.6.38 >>> grml 2011 amd64 kernel and now work again. >>> >>> >>> Thus I did >>> >>> merkaba:~> mkfs.btrfs -L daten /dev/sdc2 >>> >>> WARNING! - Btrfs Btrfs v0.19 IS EXPERIMENTAL >>> WARNING! - see http://btrfs.wiki.kernel.org before using >>> >>> fs created label daten on /dev/sdc2 >>> >>> nodesize 4096 leafsize 4096 sectorsize 4096 size 447.13GB >>> >>> Btrfs Btrfs v0.19 >>> >>> merkaba:~> mount -o space_cache,compress=lzo /dev/sdc2 >>> /mnt/amazon-daten merkaba:~> dmesg | tail -3 >>> [137440.930038] device label daten devid 1 transid 7 /dev/sdc2 >>> [137440.930507] btrfs: enabling disk space caching >>> [137440.930518] btrfs: use lzo compression >>> >>> >>> Then I unmounted, added a fstab entry without space_cache option >>> since I read that once BTRFS created a space_cache it would use it >>> anyway it is mounted with clear_cache to clear the cache again. >>> >>> I created a sub volume for movies, cause I wanted to be able to not >>> snapshot the movie files: >>> >>> merkaba:~> btrfs subvolume create /mnt/amazon-daten/Filme >>> Create subvolume ''/mnt/amazon-daten/Filme'' >>> >>> I then did my rsync from the backup which BTW was a BTRFS with >>> space_cache as well - created today: >>> >>> merkaba:~> rsync -a -H --acls --xattrs --sparse >>> /mnt/steigerwald-daten/ /mnt/amazon-daten >> >>> A short while after starting the rsync I got: >> I''ve just posted a patch for this, sorry about that I''ve fixed this >> before but there has been recent work in this area to make it more >> generic and we lost that particular fix. Thanks, > > Is it: > > [PATCH] Btrfs: make sure to update total_bitmaps when freeing cache V2 > > ? > > Do you need testing? Is this scheduled for 3.0.0-rc5 or something like > this? Then I could wait for the Debian kernel 3.0.0-rc5 to become > available. I can do without space_cache for the time being. >Nope I don''t need testing, you don''t have to try and reproduce, I know exactly what this is as I''ve fixed it before :). Thanks, Josef -- To unsubscribe from this list: send the line "unsubscribe linux-btrfs" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html