Entirely unexpected ENOSPC?

Entirely unexpected ENOSPC?

[Hugo Mills]

[-- Attachment #1: Type: text/plain, Size: 7080 bytes --]

   Last night, this event jammed up a good chunk of my server:

Mar  4 01:51:36 vlad kernel: btrfs searching for 1716224 bytes, num_bytes 1716224, loop 2, allowed_alloc 1
Mar  4 01:51:36 vlad kernel: btrfs searching for 860160 bytes, num_bytes 860160, loop 2, allowed_alloc 1
[lots of this...]
Mar  4 01:55:52 vlad kernel: btrfs searching for 4096 bytes, num_bytes 4096, loop 2, allowed_alloc 1
Mar  4 01:55:52 vlad kernel: btrfs allocation failed flags 1, wanted 4096
Mar  4 01:55:52 vlad kernel: space_info has 0 free, is full
Mar  4 01:55:52 vlad kernel: block group 12582912 has 8388608 bytes, 8388608 used 0 pinned 0 reserved
Mar  4 01:55:52 vlad kernel: 0 blocks of free space at or bigger than bytes is
Mar  4 01:55:52 vlad kernel: block group 1103101952 has 1073741824 bytes, 1073741824 used 0 pinned 0 reserved
Mar  4 01:55:52 vlad kernel: 0 blocks of free space at or bigger than bytes is
[30 more lines of this]
Mar  4 01:55:52 vlad kernel: ------------[ cut here ]------------
Mar  4 01:55:52 vlad kernel: kernel BUG at fs/btrfs/extent-tree.c:3190!
Mar  4 01:55:52 vlad kernel: invalid opcode: 0000 [#1]
Mar  4 01:55:52 vlad kernel: last sysfs file: /sys/devices/virtual/block/dm-1/removable
Mar  4 01:55:52 vlad kernel: CPU 0
Mar  4 01:55:52 vlad kernel: Modules linked in: tcp_diag inet_diag kqemu tun cpufreq_userspace ipv6 nfsd nfs lockd nfs_acl auth_rpcgss sunrpc bridge stp llc btrfs zlib_deflate xfs exportfs it87 hwmon_vid powernow_k8 sbp2 ieee1394 ide_generic ide_gd_mod ide_cd_mod pcspkr evdev k8temp hwmon i2c_viapro i2c_core button usbhid usb_storage libusual dm_mirror dm_region_hash dm_log dm_snapshot dm_mod raid1 md_mod sg sr_mod cdrom via82cxxx floppy via_rhine mii ehci_hcd uhci_hcd usbcore pata_via ide_pci_generic ide_core sd_mod thermal processor fan unix
Mar  4 01:55:52 vlad kernel: Pid: 218, comm: pdflush Tainted: G    B      2.6.29-rc6 #1 System Product Name
Mar  4 01:55:52 vlad kernel: RIP: 0010:[<ffffffffa0256b6b>]  [<ffffffffa0256b6b>] __btrfs_reserve_extent+0x296/0x2ab [btrfs]
Mar  4 01:55:52 vlad kernel: RSP: 0018:ffff88003ea618d0  EFLAGS: 00010282
Mar  4 01:55:52 vlad kernel: RAX: ffff880039924aa0 RBX: ffff8800399249d0 RCX: 0000000000001000
Mar  4 01:55:52 vlad kernel: RDX: 00000000ffffffff RSI: 0000000000023b8a RDI: ffff880039924a98
Mar  4 01:55:52 vlad kernel: RBP: ffff880039924a88 R08: 0000000000000000 R09: 000000000000000a
Mar  4 01:55:52 vlad kernel: R10: 000000000000000a R11: ffff88000100f980 R12: ffff880039924a98
Mar  4 01:55:52 vlad kernel: R13: 0000000000001000 R14: ffff88003cb74488 R15: 0000000000001000
Mar  4 01:55:52 vlad kernel: FS:  00007ff4154246e0(0000) GS:ffffffff80577010(0000) knlGS:0000000000000000
Mar  4 01:55:52 vlad kernel: CS:  0010 DS: 0018 ES: 0018 CR0: 000000008005003b
Mar  4 01:55:52 vlad kernel: CR2: 00007f45ee1f54f8 CR3: 000000003bdea000 CR4: 00000000000006e0
Mar  4 01:55:52 vlad kernel: DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Mar  4 01:55:52 vlad kernel: DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Mar  4 01:55:52 vlad kernel: Process pdflush (pid: 218, threadinfo ffff88003ea60000, task ffff88003f93b1b0)
Mar  4 01:55:52 vlad kernel: Stack:
Mar  4 01:55:52 vlad kernel: 0000000381c00000 ffff88003ea619f0 0000000000000000 0000000000000000
Mar  4 01:55:52 vlad kernel: ffff880000000001 0000000381c00000 0000000000000000 ffff88003ea619f0
Mar  4 01:55:52 vlad kernel: 000000001da5d000 0000000000001000 ffff88003ef22800 ffff88003a8214f0
Mar  4 01:55:52 vlad kernel: Call Trace:
Mar  4 01:55:52 vlad kernel: [<ffffffffa0256bae>] ? btrfs_reserve_extent+0x2e/0x52 [btrfs]
Mar  4 01:55:52 vlad kernel: [<ffffffffa026903d>] ? cow_file_range+0x1ae/0x307 [btrfs]
Mar  4 01:55:52 vlad kernel: [<ffffffffa026983f>] ? run_delalloc_range+0x9e/0x2f1 [btrfs]
Mar  4 01:55:52 vlad kernel: [<ffffffffa027c814>] ? find_lock_delalloc_range+0x124/0x17d [btrfs]
Mar  4 01:55:52 vlad kernel: [<ffffffffa027d066>] ? __extent_writepage+0x1e3/0x791 [btrfs]
Mar  4 01:55:52 vlad kernel: [<ffffffff802890ff>] ? sync_buffer+0x0/0x3d
Mar  4 01:55:52 vlad kernel: [<ffffffff80312f86>] ? radix_tree_gang_lookup_tag_slot+0x7d/0xa2
Mar  4 01:55:52 vlad kernel: [<ffffffff8024d343>] ? find_get_pages_tag+0x46/0xb6
Mar  4 01:55:52 vlad kernel: [<ffffffff802387b1>] ? wake_bit_function+0x0/0x23
Mar  4 01:55:52 vlad kernel: [<ffffffffa027a95a>] ? extent_write_cache_pages+0x13c/0x242 [btrfs]
Mar  4 01:55:52 vlad kernel: [<ffffffffa027967a>] ? flush_write_bio+0x0/0x23 [btrfs]
Mar  4 01:55:52 vlad kernel: [<ffffffffa027ce83>] ? __extent_writepage+0x0/0x791 [btrfs]
Mar  4 01:55:52 vlad kernel: [<ffffffffa027aa9b>] ? extent_writepages+0x3b/0x5c [btrfs]
Mar  4 01:55:52 vlad kernel: [<ffffffffa02677c9>] ? btrfs_get_extent+0x0/0x73c [btrfs]
Mar  4 01:55:52 vlad kernel: [<ffffffff80252cf5>] ? do_writepages+0x20/0x2d
Mar  4 01:55:52 vlad kernel: [<ffffffff80284549>] ? __writeback_single_inode+0x15a/0x33b
Mar  4 01:55:52 vlad kernel: [<ffffffffa01048b2>] ? dm_any_congested+0x2f/0x39 [dm_mod]
Mar  4 01:55:52 vlad kernel: [<ffffffff80284afa>] ? generic_sync_sb_inodes+0x287/0x3e4
Mar  4 01:55:52 vlad kernel: [<ffffffff80284dbe>] ? writeback_inodes+0x68/0xa1
Mar  4 01:55:52 vlad kernel: [<ffffffff80252e10>] ? wb_kupdate+0x8b/0xfd
Mar  4 01:55:52 vlad kernel: [<ffffffff8025374b>] ? pdflush+0x0/0x1b5
Mar  4 01:55:52 vlad kernel: [<ffffffff8025374b>] ? pdflush+0x0/0x1b5
Mar  4 01:55:52 vlad kernel: [<ffffffff80253869>] ? pdflush+0x11e/0x1b5
Mar  4 01:55:52 vlad kernel: [<ffffffff80252d85>] ? wb_kupdate+0x0/0xfd
Mar  4 01:55:52 vlad kernel: [<ffffffff802383f1>] ? kthread+0x47/0x73
Mar  4 01:55:52 vlad kernel: [<ffffffff8020c07a>] ? child_rip+0xa/0x20
Mar  4 01:55:52 vlad kernel: [<ffffffff802383aa>] ? kthread+0x0/0x73
Mar  4 01:55:52 vlad kernel: [<ffffffff8020c070>] ? child_rip+0x0/0x20
Mar  4 01:55:52 vlad kernel: Code: 8b 83 b8 00 00 00 48 8d 98 48 ff ff ff 48 8b 83 b8 00 00 00 0f 18 08 48 8d 83 b8 00 00 00 48 39 c5 75 b0 4c 89 e7 e8 63 42 fe df <0f> 0b eb fe 48 83 c4 38 31 c0 5b 5d 41 5c 41 5d 41 5e 41 5f c3
Mar  4 01:55:52 vlad kernel: RIP  [<ffffffffa0256b6b>] __btrfs_reserve_extent+0x296/0x2ab [btrfs]
Mar  4 01:55:52 vlad kernel: RSP <ffff88003ea618d0>
Mar  4 01:55:52 vlad kernel: ---[ end trace eb8a7132a207a474 ]---

   Now, to my untrained eye, this looks like it might be an ENOSPC
problem, and thus wouldn't be entirely unexpected, except for one
thing:

hrm@vlad:~ $ df -h
Filesystem            Size  Used Avail Use% Mounted on
[...]
/dev/mapper/media-scratch
                       41G   17G   25G  42% /media/vlad/video/video

   The filesystem was nowhere near full, and I wasn't expecting it to
become anywhere near full. The only thing that writes to the
filesystem is deliberately coded to leave several gigabytes of space
free.

   Hugo.

-- 
=== Hugo Mills: hugo@... carfax.org.uk | darksatanic.net | lug.org.uk ===
  PGP key: 515C238D from wwwkeys.eu.pgp.net or http://www.carfax.org.uk
   --- Nothing wrong with being written in Perl... Some of my best ---   
                      friends are written in Perl.                       

[-- Attachment #2: Digital signature --]
[-- Type: application/pgp-signature, Size: 189 bytes --]

Re: Entirely unexpected ENOSPC?

[Josef Bacik]

On Wed, Mar 04, 2009 at 06:06:19PM +0000, Hugo Mills wrote:
>    Last night, this event jammed up a good chunk of my server:
> 
> Mar  4 01:51:36 vlad kernel: btrfs searching for 1716224 bytes, num_bytes 1716224, loop 2, allowed_alloc 1
> Mar  4 01:51:36 vlad kernel: btrfs searching for 860160 bytes, num_bytes 860160, loop 2, allowed_alloc 1
> [lots of this...]
> Mar  4 01:55:52 vlad kernel: btrfs searching for 4096 bytes, num_bytes 4096, loop 2, allowed_alloc 1
> Mar  4 01:55:52 vlad kernel: btrfs allocation failed flags 1, wanted 4096
> Mar  4 01:55:52 vlad kernel: space_info has 0 free, is full
> Mar  4 01:55:52 vlad kernel: block group 12582912 has 8388608 bytes, 8388608 used 0 pinned 0 reserved
> Mar  4 01:55:52 vlad kernel: 0 blocks of free space at or bigger than bytes is
> Mar  4 01:55:52 vlad kernel: block group 1103101952 has 1073741824 bytes, 1073741824 used 0 pinned 0 reserved
> Mar  4 01:55:52 vlad kernel: 0 blocks of free space at or bigger than bytes is
> [30 more lines of this]

So yeah thats expected, you ran out of space.  The key thing is this

Mar  4 01:55:52 vlad kernel: space_info has 0 free, is full

If space_info has 0 free and is full, then there is no space to allocate for it
and its completely used.  I'd recommend switching to the -rc7 kernel since that
has things in place to keep this from happening as often.  Thanks,

Josef

Re: Entirely unexpected ENOSPC?

[Hugo Mills]

[-- Attachment #1: Type: text/plain, Size: 2215 bytes --]

On Wed, Mar 04, 2009 at 01:50:53PM -0500, Josef Bacik wrote:
> On Wed, Mar 04, 2009 at 06:06:19PM +0000, Hugo Mills wrote:
> >    Last night, this event jammed up a good chunk of my server:
> > 
> > Mar  4 01:51:36 vlad kernel: btrfs searching for 1716224 bytes, num_bytes 1716224, loop 2, allowed_alloc 1
> > Mar  4 01:51:36 vlad kernel: btrfs searching for 860160 bytes, num_bytes 860160, loop 2, allowed_alloc 1
> > [lots of this...]
> > Mar  4 01:55:52 vlad kernel: btrfs searching for 4096 bytes, num_bytes 4096, loop 2, allowed_alloc 1
> > Mar  4 01:55:52 vlad kernel: btrfs allocation failed flags 1, wanted 4096
> > Mar  4 01:55:52 vlad kernel: space_info has 0 free, is full
> > Mar  4 01:55:52 vlad kernel: block group 12582912 has 8388608 bytes, 8388608 used 0 pinned 0 reserved
> > Mar  4 01:55:52 vlad kernel: 0 blocks of free space at or bigger than bytes is
> > Mar  4 01:55:52 vlad kernel: block group 1103101952 has 1073741824 bytes, 1073741824 used 0 pinned 0 reserved
> > Mar  4 01:55:52 vlad kernel: 0 blocks of free space at or bigger than bytes is
> > [30 more lines of this]
> 
> So yeah thats expected, you ran out of space.  The key thing is this
> 
> Mar  4 01:55:52 vlad kernel: space_info has 0 free, is full
> 
> If space_info has 0 free and is full, then there is no space to allocate for it
> and its completely used.  I'd recommend switching to the -rc7 kernel since that
> has things in place to keep this from happening as often.  Thanks,

   I'll do that.

   However, what's confusing me is that the filesystem was reported as
less than half full (17/41GiB used) at the time that it decided it had
no space. Is there any likely explanation for that behaviour?

   I've used btrfsctl to resize it online several times: shrink by
1GiB, then enlarge by 12, 10, 10GiB. Might that have been a factor?

   Hugo.

-- 
=== Hugo Mills: hugo@... carfax.org.uk | darksatanic.net | lug.org.uk ===
  PGP key: 515C238D from wwwkeys.eu.pgp.net or http://www.carfax.org.uk
    --- How do you become King?  You stand in the marketplace and ---    
          announce you're going to tax everyone. If you get out          
                           alive, you're King.                           

[-- Attachment #2: Digital signature --]
[-- Type: application/pgp-signature, Size: 189 bytes --]

Re: Entirely unexpected ENOSPC?

[Hugo Mills]

[-- Attachment #1: Type: text/plain, Size: 1153 bytes --]

On Mon, Mar 09, 2009 at 07:08:16AM -0600, Yien Zheng wrote:
> At this point I'm wondering if this is a anomaly or if it has anything
> to do with using an SSD.  It seems the pre-2.7.29-rc7 code had a hard
> stop at 85%.  But the recent patch doesn't seem to have solve the
> issue for me.  Is there another issue that makes btrfs want to reserve
> 2G free?  I see another email with someone growing their filesystem
> from 48G to 70G because they ran out of space on their 50G disk, which
> should still have 2G free.

   Not quite -- I was some 5G free on a 50G filesystem, without
errors. I expanded the filesystem online to 70G because I knew I would
run out within the next few hours. Despite the expansion, it still ran
out at (just short of) 50G.

   Unless you've resized your filesystem online, I think we're seeing
different problems.

   Hugo.

-- 
=== Hugo Mills: hugo@... carfax.org.uk | darksatanic.net | lug.org.uk ===
  PGP key: 515C238D from wwwkeys.eu.pgp.net or http://www.carfax.org.uk
   --- Do not meddle in the affairs of system administrators,  for ---   
                  they are subtle,  and quick to anger.                  

[-- Attachment #2: Digital signature --]
[-- Type: application/pgp-signature, Size: 189 bytes --]

Re: Entirely unexpected ENOSPC?

[Yien Zheng]

>
> This is just a hunch, but maybe the handling of spare files (such as
> .vdi) is not ideal or not what we're used to with extN. Normally
> "skipped" blocks do not count towards the disk full size, but given
> btrfs' nature they may count as a reservation that would certainly
> cause an early ENOSPC.
>

I don't think this is the case, since my .vdi is a dynamically
expanding file, and isn't a sparse file that wants to reserve more
space than it actually is taking up.  So the vdi file is reported to
be 5G by du, and it is indeed taking up 5G (and not 3G).

> You can try to narrow down the problem using qemu-img or dd. Example:
>
> qemu-img create -f raw test.img 16G
>
> See if it counts towards the disk fill count and ENOSPC threshold. See
> if it even completes at all :P
>

I tried a test like this for kicks after deleting my vdi file.  I
tried a while loop:

while [ 1 ]; dd if=/dev/zero of=file.`date +%s` count=2097152; done

My machine subsequently froze.  Repeating the experiment unvieled that
eventually the system get stuck on pdflush taking up 100% CPU.  At
this point, I had to turn off my laptop, as a soft reset was not
possible, even with a "halt" command.

At this point I'm wondering if this is a anomaly or if it has anything
to do with using an SSD.  It seems the pre-2.7.29-rc7 code had a hard
stop at 85%.  But the recent patch doesn't seem to have solve the
issue for me.  Is there another issue that makes btrfs want to reserve
2G free?  I see another email with someone growing their filesystem
from 48G to 70G because they ran out of space on their 50G disk, which
should still have 2G free.

Re: Entirely unexpected ENOSPC?

[Dmitri Nikulin]

2009/3/8 Yien Zheng <esprout@gmail.com>:
> On Wed, 04 Mar 2009 14:48:43 -0600, Hugo Mills <hugo-lkml@carfax.org.uk> wrote:
> I just started playing with btrfs on my SSD drive last week and
> encountered the out of space problem using VirtualBox .vdi disks on
> the btrfs partition.

This is just a hunch, but maybe the handling of spare files (such as
.vdi) is not ideal or not what we're used to with extN. Normally
"skipped" blocks do not count towards the disk full size, but given
btrfs' nature they may count as a reservation that would certainly
cause an early ENOSPC.

You can try to narrow down the problem using qemu-img or dd. Example:

qemu-img create -f raw test.img 16G

See if it counts towards the disk fill count and ENOSPC threshold. See
if it even completes at all :P

-- 
Dmitri Nikulin

Centre for Synchrotron Science
Monash University
Victoria 3800, Australia

Re: Entirely unexpected ENOSPC?

[Yien Zheng]

I just tried umounting the partition and got this:

[ 1395.028651] btrfs searching for 69632 bytes, num_bytes 69632, loop
2, allowed_alloc 1
[ 1395.028661] btrfs allocation failed flags 1, wanted 69632
[ 1395.028667] space_info has 81920 free, is full
[ 1395.028673] space_info total=3D10720313344, pinned=3D2678784,
delalloc=3D0, may_use=3D0, used=3D10717552640
[ 1395.028681] block group 12582912 has 8388608 bytes, 8388608 used 0
pinned 0 reserved
[ 1395.028687] 0 blocks of free space at or bigger than bytes is
[ 1395.028694] block group 1103101952 has 1073741824 bytes, 1072877568
used 864256 pinned 0 reserved
[ 1395.028700] 0 blocks of free space at or bigger than bytes is
[ 1395.028706] block group 2176843776 has 1073741824 bytes, 1073741824
used 0 pinned 0 reserved
[ 1395.028712] 0 blocks of free space at or bigger than bytes is
[ 1395.028718] block group 3250585600 has 1073741824 bytes, 1073709056
used 32768 pinned 0 reserved
[ 1395.028724] 0 blocks of free space at or bigger than bytes is
[ 1395.028730] block group 4324327424 has 1073741824 bytes, 1073741824
used 0 pinned 0 reserved
[ 1395.028736] 0 blocks of free space at or bigger than bytes is
[ 1395.028742] block group 5398069248 has 1073741824 bytes, 1073741824
used 0 pinned 0 reserved
[ 1395.028748] 0 blocks of free space at or bigger than bytes is
[ 1395.028754] block group 6471811072 has 1073741824 bytes, 1073741824
used 0 pinned 0 reserved
[ 1395.028760] 0 blocks of free space at or bigger than bytes is
[ 1395.028767] block group 7545552896 has 1073741824 bytes, 1073618944
used 122880 pinned 0 reserved
[ 1395.028772] 0 blocks of free space at or bigger than bytes is
[ 1395.028779] block group 8619294720 has 1073741824 bytes, 1073639424
used 102400 pinned 0 reserved
[ 1395.028785] 0 blocks of free space at or bigger than bytes is
[ 1395.028791] block group 9693036544 has 1073741824 bytes, 1073549312
used 192512 pinned 0 reserved
[ 1395.028797] 0 blocks of free space at or bigger than bytes is
[ 1395.028804] block group 10766778368 has 1048248320 bytes,
1046802432 used 1363968 pinned 0 reserved
[ 1395.028811] 0 blocks of free space at or bigger than bytes is
[ 1395.028858] ------------[ cut here ]------------
[ 1395.028863] kernel BUG at fs/btrfs/extent-tree.c:3412!
[ 1395.028869] invalid opcode: 0000 [#1] SMP
[ 1395.028876] last sysfs file:
/sys/devices/pci0000:00/0000:00:1e.0/0000:0b:02.0/rf_kill
[ 1395.028882] Modules linked in: arc4 ecb lib80211_crypt_wep
af_packet radeon drm i2c_core sco bridge rfcomm stp bnep l2cap
bluetooth vboxnetflt vboxdrv ppdev acpi_cpufreq cpufreq_ondemand
cpufreq_conservative cpufreq_userspace cpufreq_powersave cpufreq_stats
freq_table sbs container sbshc pci_slot iptable_filter ip_tables
x_tables loop btrfs zlib_deflate crc32c libcrc32c lp pcmcia joydev
thinkpad_acpi rfkill led_class nvram snd_intel8x0 snd_ac97_codec
ac97_bus snd_pcm_oss snd_mixer_oss snd_pcm snd_seq_dummy evdev
snd_seq_oss psmouse snd_seq_midi snd_rawmidi serio_raw
snd_seq_midi_event pcspkr snd_seq snd_timer snd_seq_device
yenta_socket rsrc_nonstatic pcmcia_core ipw2200 libipw lib80211 snd
iTCO_wdt iTCO_vendor_support soundcore snd_page_alloc battery ac video
output parport_pc parport nsc_ircc irda crc_ccitt button shpchp
pci_hotplug intel_agp agpgart ext3 jbd mbcache sd_mod crc_t10dif
usb_storage libusual sg ahci pata_acpi ata_generic ata_piix libata
scsi_mod ehci_hcd uhci_hcd usbcore tg3 libphy thermal processor fan
fuse
[ 1395.029058]
[ 1395.029064] Pid: 4015, comm: btrfs-delalloc- Not tainted
(2.6.29-rc7-custom #2) 2686DHU
[ 1395.029071] EIP: 0060:[<f8055289>] EFLAGS: 00010257 CPU: 0
[ 1395.029108] EIP is at __btrfs_reserve_extent+0x2d9/0x450 [btrfs]
[ 1395.029114] EAX: f6e6535c EBX: f5879300 ECX: ffffffff EDX: 00000001
[ 1395.029120] ESI: 00011000 EDI: 00000000 EBP: f5a9fe8c ESP: f5a9fe04
[ 1395.029126]  DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
[ 1395.029132] Process btrfs-delalloc- (pid: 4015, ti=3Df5a9e000
task=3Df6f7b100 task.ti=3Df5a9e000)
[ 1395.029137] Stack:
[ 1395.029141]  f80960dc 81c00000 00000002 3e7b0000 00000000 3e64f000
00000000 0014d000
[ 1395.029154]  00000000 00000000 00000000 00000000 00000000 00000000
00000000 00000001
[ 1395.029168]  00000000 00000000 00000000 00000000 00000000 00011000
00000000 00000001
[ 1395.029183] Call Trace:
[ 1395.029202]  [<f8055472>] ? btrfs_reserve_extent+0x72/0xb0 [btrfs]
[ 1395.029240]  [<f80659dd>] ? submit_compressed_extents+0x17d/0x4c0 [b=
trfs]
[ 1395.029282]  [<f8065db3>] ? async_cow_submit+0x93/0xa0 [btrfs]
[ 1395.029322]  [<f8087f3c>] ? run_ordered_completions+0x6c/0xc0 [btrfs=
]
[ 1395.029363]  [<f8088110>] ? worker_loop+0x90/0x1e0 [btrfs]
[ 1395.029401]  [<f8088080>] ? worker_loop+0x0/0x1e0 [btrfs]
[ 1395.029436]  [<c0146dcc>] ? kthread+0x3c/0x70
[ 1395.029448]  [<c0146d90>] ? kthread+0x0/0x70
[ 1395.029456]  [<c0103fa7>] ? kernel_thread_helper+0x7/0x10
[ 1395.029465] Code: 53 50 8d 82 74 ff ff ff 89 45 e8 8b 80 8c 00 00
00 0f 18 00 90 83 c3 5039 d3 89 5d ec 0f 85 da 00 00 00 8b 45 f0 e8 f7
5e 0f c8 <0f> 0b eb fe 8d 76 00 8b 4d d8 8b 5d e0 8b 81 2c 01 00 00 8b
50
[ 1395.029543] EIP: [<f8055289>] __btrfs_reserve_extent+0x2d9/0x450
[btrfs] SS:ESP 0068:f5a9fe04
[ 1395.029583] ---[ end trace 652a082f590907db ]---


> Here's my dmesg output:
>
> [ =A0884.445441] no space left, need 8192, 2760704 delalloc bytes,
> 10717552640 bytes_used, 0 bytes_reserved, 0 bytes_pinned, 0
> bytes_readonly, 0 may use10720313344 total
> [ =A0912.026372] btrfs searching for 524288 bytes, num_bytes 524288,
> loop 2, allowed_alloc 1
> [ =A0912.026389] btrfs searching for 262144 bytes, num_bytes 262144,
> loop 2, allowed_alloc 1
> [ =A0912.026403] btrfs searching for 131072 bytes, num_bytes 131072,
> loop 2, allowed_alloc 1
> [ =A0912.026426] btrfs searching for 458752 bytes, num_bytes 458752,
> loop 2, allowed_alloc 1
> [ =A0912.026439] btrfs searching for 229376 bytes, num_bytes 229376,
> loop 2, allowed_alloc 1
> [...more lines like this]
> [ 1363.318175] no space left, need 8192, 81920 delalloc bytes,
> 10720231424 bytes_used, 0 bytes_reserved, 0 bytes_pinned, 0
> bytes_readonly, 0 may use10720313344 total
>
--
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

Re: Entirely unexpected ENOSPC?

[Yien Zheng]

On Wed, 04 Mar 2009 14:48:43 -0600, Hugo Mills <hugo-lkml@carfax.org.uk=
> wrote:

> On Wed, Mar 04, 2009 at 01:50:53PM -0500, Josef Bacik wrote:
>> On Wed, Mar 04, 2009 at 06:06:19PM +0000, Hugo Mills wrote:
>> >    Last night, this event jammed up a good chunk of my server:
>> >
>> > Mar  4 01:51:36 vlad kernel: btrfs searching for 1716224 bytes,
>> num_bytes 1716224, loop 2, allowed_alloc 1
>> > Mar  4 01:51:36 vlad kernel: btrfs searching for 860160 bytes,
>> num_bytes 860160, loop 2, allowed_alloc 1
>> > [lots of this...]
>> > Mar  4 01:55:52 vlad kernel: btrfs searching for 4096 bytes,
>> num_bytes 4096, loop 2, allowed_alloc 1
>> > Mar  4 01:55:52 vlad kernel: btrfs allocation failed flags 1, want=
ed
>> 4096
>> > Mar  4 01:55:52 vlad kernel: space_info has 0 free, is full
>> > Mar  4 01:55:52 vlad kernel: block group 12582912 has 8388608 byte=
s,
>> 8388608 used 0 pinned 0 reserved
>> > Mar  4 01:55:52 vlad kernel: 0 blocks of free space at or bigger t=
han
>> bytes is
>> > Mar  4 01:55:52 vlad kernel: block group 1103101952 has 1073741824
>> bytes, 1073741824 used 0 pinned 0 reserved
>> > Mar  4 01:55:52 vlad kernel: 0 blocks of free space at or bigger t=
han
>> bytes is
>> > [30 more lines of this]
>>
>> So yeah thats expected, you ran out of space.  The key thing is this
>>
>> Mar  4 01:55:52 vlad kernel: space_info has 0 free, is full
>>
>> If space_info has 0 free and is full, then there is no space to
>> allocate for it
>> and its completely used.  I'd recommend switching to the -rc7 kernel
>> since that
>> has things in place to keep this from happening as often.  Thanks,
>
>    I'll do that.
>
>    However, what's confusing me is that the filesystem was reported a=
s
> less than half full (17/41GiB used) at the time that it decided it ha=
d
> no space. Is there any likely explanation for that behaviour?
>
>    I've used btrfsctl to resize it online several times: shrink by
> 1GiB, then enlarge by 12, 10, 10GiB. Might that have been a factor?
>
>    Hugo.
>

I just started playing with btrfs on my SSD drive last week and
encountered the out of space problem using VirtualBox .vdi disks on
the btrfs partition.  I initially used the backport to ubuntu posted
by Filip Br=E8i=E6 with my 2.6.27-7-generic kernel (from Linux Mint 6 K=
DE
CE RC1).

I downloaded and compiled the latest git version ( 2.6.29-rc7) with
the ENOSPC patches, but still run out of disk space quite prematurely.
 With 2.6.27-7 based on btrfs 0.17, I was running out of disk space at
with 1.9G free.  Now with the patched git in 2.6.29-rc7, it's running
out with 1.7G free:

df -h /mnt/btrfs/
=46ilesystem            Size  Used Avail Use% Mounted on
/dev/sdc1              13G   11G  1.7G  87% /mnt/btrfs

This is the same result as from the btrfs unstable repository based on
2.6.29-rc3 which I also tried from git clone
git://git.kernel.org/pub/scm/linux/kernel/git/mason/btrfs-unstable.git.
 It looks like the btrfs code from this repository is identical to
rc7, but I was hoping some other kernel changes in rc7 made the
situation better as Josef implied.

I supposed this is not really an ENOSPC, but it's running out of space
much earlier than I would expect.

Here's my dmesg output:

[  884.445441] no space left, need 8192, 2760704 delalloc bytes,
10717552640 bytes_used, 0 bytes_reserved, 0 bytes_pinned, 0
bytes_readonly, 0 may use10720313344 total
[  912.026372] btrfs searching for 524288 bytes, num_bytes 524288,
loop 2, allowed_alloc 1
[  912.026389] btrfs searching for 262144 bytes, num_bytes 262144,
loop 2, allowed_alloc 1
[  912.026403] btrfs searching for 131072 bytes, num_bytes 131072,
loop 2, allowed_alloc 1
[  912.026426] btrfs searching for 458752 bytes, num_bytes 458752,
loop 2, allowed_alloc 1
[  912.026439] btrfs searching for 229376 bytes, num_bytes 229376,
loop 2, allowed_alloc 1
[...more lines like this]
[ 1363.318175] no space left, need 8192, 81920 delalloc bytes,
10720231424 bytes_used, 0 bytes_reserved, 0 bytes_pinned, 0
bytes_readonly, 0 may use10720313344 total
--
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