All of lore.kernel.org
 help / color / mirror / Atom feed
* ENOSPC on mostly empty file system
@ 2014-09-09 14:29 Arnd Bergmann
  2014-09-09 15:06 ` Holger Hoffstätte
  2014-09-09 18:18 ` Arnd Bergmann
  0 siblings, 2 replies; 11+ messages in thread
From: Arnd Bergmann @ 2014-09-09 14:29 UTC (permalink / raw)
  To: linux-btrfs; +Cc: Chris Mason

Hi Chris,

As I mentioned at the kernel summit, I have a file system that I use mostly
for storing my one kernel git tree and occasionally some build trees
(those are normally on a tmpfs), and I have again run into the problem
where the file system is only partially full (I think 18% in this case)
but I am unable to create new files.

As you recommended, I have created an image using btrfs-image and
uploaded it to google drive for inspection.

I also played around with it some more. After removing a few small
files, I could create new files with up to 20-60MB again before hitting
ENOSPC. I then did a 'make clean' in all the object directories I had
and after that could fill the file system up to 100% by creating a
62GB file using the same command (dd if=/dev/zero of=x).

While probably unrelated, I also saw a few older 'hung task' messages
with btrfs call chains in dmesg and I'm adding them here in this mail
as well. The kernel messages are ten days old, but I did not reboot
in the meantime and I never saw them again before or after that.
The kernel is the stock Ubuntu 3.16.0 image from Ubuntu, I upgrade
to that after running an old 3.11 kernel that I never rebooted.

The 82 MB image file is at
https://drive.google.com/file/d/0B_XQwQ5KlfJAWDJfS1E0TG1CLTA/edit?usp=sharing

	Arnd

[407459.475639] INFO: task BrowserBlocking:3282 blocked for more than 120 seconds.
[407459.475649]       Not tainted 3.16.0-10-generic #15-Ubuntu
[407459.475652] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[407459.475656] BrowserBlocking D ffff88042fc94800     0  3282   2580 0x00000000
[407459.475664]  ffff88040d9f7db0 0000000000000086 ffff88041215b2a0 0000000000014800
[407459.475671]  ffff88040d9f7fd8 0000000000014800 ffff88041215b2a0 ffff8800bbb12af8
[407459.475677]  ffff8800bbb12afc ffff88041215b2a0 00000000ffffffff ffff8800bbb12b00
[407459.475683] Call Trace:
[407459.475699]  [<ffffffff8177b609>] schedule_preempt_disabled+0x29/0x70
[407459.475707]  [<ffffffff8177dba5>] __mutex_lock_slowpath+0xd5/0x1f0
[407459.475714]  [<ffffffff8177dcdf>] mutex_lock+0x1f/0x30
[407459.475771]  [<ffffffffc0546535>] btrfs_log_inode_parent+0xd5/0x550 [btrfs]
[407459.475804]  [<ffffffffc0547822>] btrfs_log_dentry_safe+0x42/0x60 [btrfs]
[407459.475834]  [<ffffffffc0517d64>] btrfs_sync_file+0x184/0x300 [btrfs]
[407459.475844]  [<ffffffff81210461>] do_fsync+0x51/0x80
[407459.475849]  [<ffffffff812106f0>] SyS_fsync+0x10/0x20
[407459.475856]  [<ffffffff8177ff2d>] system_call_fastpath+0x1a/0x1f
[407459.475861] INFO: task BrowserBlocking:3283 blocked for more than 120 seconds.
[407459.475864]       Not tainted 3.16.0-10-generic #15-Ubuntu
[407459.475866] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[407459.475869] BrowserBlocking D ffff88042fd54800     0  3283   2580 0x00000000
[407459.475875]  ffff88040bb13db0 0000000000000086 ffff88041215ef60 0000000000014800
[407459.475881]  ffff88040bb13fd8 0000000000014800 ffff88041215ef60 ffff880429b43590
[407459.475886]  ffff880429b43594 ffff88041215ef60 00000000ffffffff ffff880429b43598
[407459.475892] Call Trace:
[407459.475899]  [<ffffffff8177b609>] schedule_preempt_disabled+0x29/0x70
[407459.475906]  [<ffffffff8177dba5>] __mutex_lock_slowpath+0xd5/0x1f0
[407459.475912]  [<ffffffff8177dcdf>] mutex_lock+0x1f/0x30
[407459.475943]  [<ffffffffc0546895>] btrfs_log_inode_parent+0x435/0x550 [btrfs]
[407459.475976]  [<ffffffffc0547822>] btrfs_log_dentry_safe+0x42/0x60 [btrfs]
[407459.476005]  [<ffffffffc0517d64>] btrfs_sync_file+0x184/0x300 [btrfs]
[407459.476012]  [<ffffffff81210461>] do_fsync+0x51/0x80
[407459.476018]  [<ffffffff81210713>] SyS_fdatasync+0x13/0x20
[407459.476023]  [<ffffffff8177ff2d>] system_call_fastpath+0x1a/0x1f
[407459.476099] INFO: task kworker/u65:6:2090685 blocked for more than 120 seconds.
[407459.476102]       Not tainted 3.16.0-10-generic #15-Ubuntu
[407459.476104] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[407459.476107] kworker/u65:6   D ffff88042fd14800     0 2090685      2 0x00000000
[407459.476131] Workqueue: events_unbound btrfs_async_reclaim_metadata_space [btrfs]
[407459.476134]  ffff8806189ffba0 0000000000000046 ffff880428135100 0000000000014800
[407459.476140]  ffff8806189fffd8 0000000000014800 ffff880428135100 ffff8806189ffcc8
[407459.476145]  ffff8806189ffcc0 7fffffffffffffff ffff880428135100 0000000000000001
[407459.476151] Call Trace:
[407459.476158]  [<ffffffff8177b089>] schedule+0x29/0x70
[407459.476164]  [<ffffffff8177a349>] schedule_timeout+0x229/0x2a0
[407459.476171]  [<ffffffff8108b026>] ? __queue_work+0x136/0x340
[407459.476177]  [<ffffffff8108b2fa>] ? __queue_delayed_work+0xaa/0x1c0
[407459.476184]  [<ffffffff8177c214>] wait_for_completion+0xb4/0x1e0
[407459.476191]  [<ffffffff810a5400>] ? wake_up_state+0x20/0x20
[407459.476198]  [<ffffffff812096c1>] writeback_inodes_sb_nr+0x81/0xb0
[407459.476221]  [<ffffffffc04efb08>] flush_space+0x458/0x4f0 [btrfs]
[407459.476243]  [<ffffffffc04ef617>] ? can_overcommit+0x67/0x100 [btrfs]
[407459.476266]  [<ffffffffc04efd0c>] btrfs_async_reclaim_metadata_space+0x16c/0x1e0 [btrfs]
[407459.476273]  [<ffffffff8108d812>] process_one_work+0x182/0x4e0
[407459.476278]  [<ffffffff8108dbdb>] worker_thread+0x6b/0x6a0
[407459.476284]  [<ffffffff8108db70>] ? process_one_work+0x4e0/0x4e0
[407459.476290]  [<ffffffff81094a1b>] kthread+0xdb/0x100
[407459.476297]  [<ffffffff81094940>] ? kthread_create_on_node+0x1c0/0x1c0
[407459.476302]  [<ffffffff8177fe7c>] ret_from_fork+0x7c/0xb0
[407459.476308]  [<ffffffff81094940>] ? kthread_create_on_node+0x1c0/0x1c0
[407579.528238] INFO: task kworker/u65:6:2090685 blocked for more than 120 seconds.
[407579.528247]       Not tainted 3.16.0-10-generic #15-Ubuntu
[407579.528251] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[407579.528255] kworker/u65:6   D ffff88042fd14800     0 2090685      2 0x00000000
[407579.528308] Workqueue: events_unbound btrfs_async_reclaim_metadata_space [btrfs]
[407579.528312]  ffff8806189ffba0 0000000000000046 ffff880428135100 0000000000014800
[407579.528318]  ffff8806189fffd8 0000000000014800 ffff880428135100 ffff8806189ffcc8
[407579.528324]  ffff8806189ffcc0 7fffffffffffffff ffff880428135100 0000000000000001
[407579.528330] Call Trace:
[407579.528345]  [<ffffffff8177b089>] schedule+0x29/0x70
[407579.528352]  [<ffffffff8177a349>] schedule_timeout+0x229/0x2a0
[407579.528360]  [<ffffffff8108b026>] ? __queue_work+0x136/0x340
[407579.528366]  [<ffffffff8108b2fa>] ? __queue_delayed_work+0xaa/0x1c0
[407579.528373]  [<ffffffff8177c214>] wait_for_completion+0xb4/0x1e0
[407579.528380]  [<ffffffff810a5400>] ? wake_up_state+0x20/0x20
[407579.528388]  [<ffffffff812096c1>] writeback_inodes_sb_nr+0x81/0xb0
[407579.528411]  [<ffffffffc04efb08>] flush_space+0x458/0x4f0 [btrfs]
[407579.528434]  [<ffffffffc04ef617>] ? can_overcommit+0x67/0x100 [btrfs]
[407579.528458]  [<ffffffffc04efd0c>] btrfs_async_reclaim_metadata_space+0x16c/0x1e0 [btrfs]
[407579.528464]  [<ffffffff8108d812>] process_one_work+0x182/0x4e0
[407579.528470]  [<ffffffff8108dbdb>] worker_thread+0x6b/0x6a0
[407579.528475]  [<ffffffff8108db70>] ? process_one_work+0x4e0/0x4e0
[407579.528481]  [<ffffffff81094a1b>] kthread+0xdb/0x100
[407579.528488]  [<ffffffff81094940>] ? kthread_create_on_node+0x1c0/0x1c0
[407579.528494]  [<ffffffff8177fe7c>] ret_from_fork+0x7c/0xb0
[407579.528501]  [<ffffffff81094940>] ? kthread_create_on_node+0x1c0/0x1c0
[407699.580802] INFO: task kworker/u65:6:2090685 blocked for more than 120 seconds.
[407699.580811]       Not tainted 3.16.0-10-generic #15-Ubuntu
[407699.580815] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[407699.580818] kworker/u65:6   D ffff88042fd14800     0 2090685      2 0x00000000
[407699.580872] Workqueue: events_unbound btrfs_async_reclaim_metadata_space [btrfs]
[407699.580877]  ffff8806189ffba0 0000000000000046 ffff880428135100 0000000000014800
[407699.580883]  ffff8806189fffd8 0000000000014800 ffff880428135100 ffff8806189ffcc8
[407699.580889]  ffff8806189ffcc0 7fffffffffffffff ffff880428135100 0000000000000001
[407699.580895] Call Trace:
[407699.580910]  [<ffffffff8177b089>] schedule+0x29/0x70
[407699.580917]  [<ffffffff8177a349>] schedule_timeout+0x229/0x2a0
[407699.580925]  [<ffffffff8108b026>] ? __queue_work+0x136/0x340
[407699.580930]  [<ffffffff8108b2fa>] ? __queue_delayed_work+0xaa/0x1c0
[407699.580938]  [<ffffffff8177c214>] wait_for_completion+0xb4/0x1e0
[407699.580945]  [<ffffffff810a5400>] ? wake_up_state+0x20/0x20
[407699.580952]  [<ffffffff812096c1>] writeback_inodes_sb_nr+0x81/0xb0
[407699.580976]  [<ffffffffc04efb08>] flush_space+0x458/0x4f0 [btrfs]
[407699.580999]  [<ffffffffc04ef617>] ? can_overcommit+0x67/0x100 [btrfs]
[407699.581022]  [<ffffffffc04efd0c>] btrfs_async_reclaim_metadata_space+0x16c/0x1e0 [btrfs]
[407699.581029]  [<ffffffff8108d812>] process_one_work+0x182/0x4e0
[407699.581034]  [<ffffffff8108dbdb>] worker_thread+0x6b/0x6a0
[407699.581040]  [<ffffffff8108db70>] ? process_one_work+0x4e0/0x4e0
[407699.581046]  [<ffffffff81094a1b>] kthread+0xdb/0x100
[407699.581053]  [<ffffffff81094940>] ? kthread_create_on_node+0x1c0/0x1c0
[407699.581059]  [<ffffffff8177fe7c>] ret_from_fork+0x7c/0xb0
[407699.581066]  [<ffffffff81094940>] ? kthread_create_on_node+0x1c0/0x1c0
[407819.633225] INFO: task BrowserBlocking:3282 blocked for more than 120 seconds.
[407819.633234]       Not tainted 3.16.0-10-generic #15-Ubuntu
[407819.633238] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[407819.633242] BrowserBlocking D ffff88042fc94800     0  3282   2580 0x00000000
[407819.633250]  ffff88040d9f7db0 0000000000000086 ffff88041215b2a0 0000000000014800
[407819.633256]  ffff88040d9f7fd8 0000000000014800 ffff88041215b2a0 ffff8800bbb12af8
[407819.633262]  ffff8800bbb12afc ffff88041215b2a0 00000000ffffffff ffff8800bbb12b00
[407819.633269] Call Trace:
[407819.633285]  [<ffffffff8177b609>] schedule_preempt_disabled+0x29/0x70
[407819.633292]  [<ffffffff8177dba5>] __mutex_lock_slowpath+0xd5/0x1f0
[407819.633299]  [<ffffffff8177dcdf>] mutex_lock+0x1f/0x30
[407819.633357]  [<ffffffffc0546535>] btrfs_log_inode_parent+0xd5/0x550 [btrfs]
[407819.633390]  [<ffffffffc0547822>] btrfs_log_dentry_safe+0x42/0x60 [btrfs]
[407819.633419]  [<ffffffffc0517d64>] btrfs_sync_file+0x184/0x300 [btrfs]
[407819.633429]  [<ffffffff81210461>] do_fsync+0x51/0x80
[407819.633435]  [<ffffffff812106f0>] SyS_fsync+0x10/0x20
[407819.633440]  [<ffffffff8177ff2d>] system_call_fastpath+0x1a/0x1f
[407819.633446] INFO: task BrowserBlocking:3284 blocked for more than 120 seconds.
[407819.633449]       Not tainted 3.16.0-10-generic #15-Ubuntu
[407819.633451] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[407819.633454] BrowserBlocking D ffff88042fc14800     0  3284   2580 0x00000000
[407819.633460]  ffff880416d4fdb0 0000000000000086 ffff88041215e540 0000000000014800
[407819.633466]  ffff880416d4ffd8 0000000000014800 ffff88041215e540 ffff880429b43590
[407819.633471]  ffff880429b43594 ffff88041215e540 00000000ffffffff ffff880429b43598
[407819.633477] Call Trace:
[407819.633485]  [<ffffffff8177b609>] schedule_preempt_disabled+0x29/0x70
[407819.633491]  [<ffffffff8177dba5>] __mutex_lock_slowpath+0xd5/0x1f0
[407819.633498]  [<ffffffff8177dcdf>] mutex_lock+0x1f/0x30
[407819.633530]  [<ffffffffc0546895>] btrfs_log_inode_parent+0x435/0x550 [btrfs]
[407819.633561]  [<ffffffffc0547822>] btrfs_log_dentry_safe+0x42/0x60 [btrfs]
[407819.633590]  [<ffffffffc0517d64>] btrfs_sync_file+0x184/0x300 [btrfs]
[407819.633597]  [<ffffffff81210461>] do_fsync+0x51/0x80
[407819.633603]  [<ffffffff81210713>] SyS_fdatasync+0x13/0x20
[407819.633608]  [<ffffffff8177ff2d>] system_call_fastpath+0x1a/0x1f
[407819.633687] INFO: task kworker/u65:6:2090685 blocked for more than 120 seconds.
[407819.633690]       Not tainted 3.16.0-10-generic #15-Ubuntu
[407819.633693] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[407819.633695] kworker/u65:6   D ffff88042fd14800     0 2090685      2 0x00000000
[407819.633719] Workqueue: events_unbound btrfs_async_reclaim_metadata_space [btrfs]
[407819.633722]  ffff8806189ffba0 0000000000000046 ffff880428135100 0000000000014800
[407819.633728]  ffff8806189fffd8 0000000000014800 ffff880428135100 ffff8806189ffcc8
[407819.633734]  ffff8806189ffcc0 7fffffffffffffff ffff880428135100 0000000000000001
[407819.633739] Call Trace:
[407819.633747]  [<ffffffff8177b089>] schedule+0x29/0x70
[407819.633753]  [<ffffffff8177a349>] schedule_timeout+0x229/0x2a0
[407819.633760]  [<ffffffff8108b026>] ? __queue_work+0x136/0x340
[407819.633765]  [<ffffffff8108b2fa>] ? __queue_delayed_work+0xaa/0x1c0
[407819.633772]  [<ffffffff8177c214>] wait_for_completion+0xb4/0x1e0
[407819.633779]  [<ffffffff810a5400>] ? wake_up_state+0x20/0x20
[407819.633786]  [<ffffffff812096c1>] writeback_inodes_sb_nr+0x81/0xb0
[407819.633809]  [<ffffffffc04efb08>] flush_space+0x458/0x4f0 [btrfs]
[407819.633832]  [<ffffffffc04ef617>] ? can_overcommit+0x67/0x100 [btrfs]
[407819.633854]  [<ffffffffc04efd0c>] btrfs_async_reclaim_metadata_space+0x16c/0x1e0 [btrfs]
[407819.633861]  [<ffffffff8108d812>] process_one_work+0x182/0x4e0
[407819.633866]  [<ffffffff8108dbdb>] worker_thread+0x6b/0x6a0
[407819.633872]  [<ffffffff8108db70>] ? process_one_work+0x4e0/0x4e0
[407819.633878]  [<ffffffff81094a1b>] kthread+0xdb/0x100
[407819.633885]  [<ffffffff81094940>] ? kthread_create_on_node+0x1c0/0x1c0
[407819.633890]  [<ffffffff8177fe7c>] ret_from_fork+0x7c/0xb0
[407819.633897]  [<ffffffff81094940>] ? kthread_create_on_node+0x1c0/0x1c0
[407819.633907] INFO: task find:2091978 blocked for more than 120 seconds.
[407819.633910]       Not tainted 3.16.0-10-generic #15-Ubuntu
[407819.633913] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[407819.633915] find            D ffff88042fc94800     0 2091978 2091977 0x00000000
[407819.633921]  ffff8805c8c83ab0 0000000000000086 ffff880271929e60 0000000000014800
[407819.633926]  ffff8805c8c83fd8 0000000000014800 ffff880271929e60 ffff8805c8c83bd8
[407819.633932]  ffff8805c8c83bd0 7fffffffffffffff ffff880271929e60 0000000000000001
[407819.633937] Call Trace:
[407819.633944]  [<ffffffff8177b089>] schedule+0x29/0x70
[407819.633950]  [<ffffffff8177a349>] schedule_timeout+0x229/0x2a0
[407819.633955]  [<ffffffff8108b026>] ? __queue_work+0x136/0x340
[407819.633976]  [<ffffffffc04eb215>] ? block_rsv_release_bytes+0x115/0x180 [btrfs]
[407819.633981]  [<ffffffff8108b2fa>] ? __queue_delayed_work+0xaa/0x1c0
[407819.633988]  [<ffffffff8177c214>] wait_for_completion+0xb4/0x1e0
[407819.633994]  [<ffffffff810a5400>] ? wake_up_state+0x20/0x20
[407819.633999]  [<ffffffff812096c1>] writeback_inodes_sb_nr+0x81/0xb0
[407819.634023]  [<ffffffffc04efb08>] flush_space+0x458/0x4f0 [btrfs]
[407819.634046]  [<ffffffffc04ef617>] ? can_overcommit+0x67/0x100 [btrfs]
[407819.634068]  [<ffffffffc04eff83>] reserve_metadata_bytes+0x203/0x490 [btrfs]
[407819.634075]  [<ffffffff8177dcd2>] ? mutex_lock+0x12/0x30
[407819.634099]  [<ffffffffc04f0786>] btrfs_block_rsv_add+0x26/0x50 [btrfs]
[407819.634126]  [<ffffffffc0507e03>] start_transaction+0x453/0x590 [btrfs]
[407819.634154]  [<ffffffffc0507f5b>] btrfs_start_transaction+0x1b/0x20 [btrfs]
[407819.634182]  [<ffffffffc050d4a8>] btrfs_dirty_inode+0xb8/0xf0 [btrfs]
[407819.634210]  [<ffffffffc050d55f>] btrfs_update_time+0x7f/0xc0 [btrfs]
[407819.634217]  [<ffffffff811fb285>] update_time+0x25/0xd0
[407819.634223]  [<ffffffff811fb409>] touch_atime+0xd9/0x140
[407819.634228]  [<ffffffff811f3b60>] iterate_dir+0xe0/0x130
[407819.634234]  [<ffffffff811f3fb9>] SyS_getdents+0x89/0x100
[407819.634238]  [<ffffffff811f3c80>] ? fillonedir+0xd0/0xd0
[407819.634244]  [<ffffffff8177ff2d>] system_call_fastpath+0x1a/0x1f
[408133.512919] audit: type=1400 audit(1409380699.459:52): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/usr/lib/cups/backend/cups-pdf" pid=2092471 comm="apparmor_parser"
[408133.512930] audit: type=1400 audit(1409380699.459:53): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/usr/sbin/cupsd" pid=2092471 comm="apparmor_parser"
[408133.513460] audit: type=1400 audit(1409380699.459:54): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/usr/sbin/cupsd" pid=2092471 comm="apparmor_parser"
[408299.843229] INFO: task BrowserBlocking:3282 blocked for more than 120 seconds.
[408299.843238]       Not tainted 3.16.0-10-generic #15-Ubuntu
[408299.843241] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[408299.843245] BrowserBlocking D ffff88042fc14800     0  3282   2580 0x00000000
[408299.843253]  ffff88040d9f7db0 0000000000000086 ffff88041215b2a0 0000000000014800
[408299.843260]  ffff88040d9f7fd8 0000000000014800 ffff88041215b2a0 ffff880429b43590
[408299.843266]  ffff880429b43594 ffff88041215b2a0 00000000ffffffff ffff880429b43598
[408299.843272] Call Trace:
[408299.843288]  [<ffffffff8177b609>] schedule_preempt_disabled+0x29/0x70
[408299.843296]  [<ffffffff8177dba5>] __mutex_lock_slowpath+0xd5/0x1f0
[408299.843303]  [<ffffffff8177dcdf>] mutex_lock+0x1f/0x30
[408299.843360]  [<ffffffffc0546895>] btrfs_log_inode_parent+0x435/0x550 [btrfs]
[408299.843393]  [<ffffffffc0547822>] btrfs_log_dentry_safe+0x42/0x60 [btrfs]
[408299.843423]  [<ffffffffc0517d64>] btrfs_sync_file+0x184/0x300 [btrfs]
[408299.843432]  [<ffffffff81210461>] do_fsync+0x51/0x80
[408299.843438]  [<ffffffff812106f0>] SyS_fsync+0x10/0x20
[408299.843444]  [<ffffffff8177ff2d>] system_call_fastpath+0x1a/0x1f


^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: ENOSPC on mostly empty file system
  2014-09-09 14:29 ENOSPC on mostly empty file system Arnd Bergmann
@ 2014-09-09 15:06 ` Holger Hoffstätte
  2014-09-09 15:12   ` Holger Hoffstätte
  2014-09-09 18:18 ` Arnd Bergmann
  1 sibling, 1 reply; 11+ messages in thread
From: Holger Hoffstätte @ 2014-09-09 15:06 UTC (permalink / raw)
  To: linux-btrfs

On Tue, 09 Sep 2014 16:29:05 +0200, Arnd Bergmann wrote:

> As I mentioned at the kernel summit, I have a file system that I use mostly
> for storing my one kernel git tree and occasionally some build trees
> (those are normally on a tmpfs), and I have again run into the problem
> where the file system is only partially full (I think 18% in this case)
> but I am unable to create new files.

You didn't give us any "btrfs fs show" or "btrfs fs df" outpu to look at,
so chances are that a lot of empty data chunks have made themselves
comfortable and prevent new metadata chunks from being allocated.

The usual fix is to run balance with -dusage=x, where 0 <= x <= ~20.

> The 82 MB image file is at
> https://drive.google.com/file/d/0B_XQwQ5KlfJAWDJfS1E0TG1CLTA/edit?usp=sharing

This is >780 MB..

-h


^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: ENOSPC on mostly empty file system
  2014-09-09 15:06 ` Holger Hoffstätte
@ 2014-09-09 15:12   ` Holger Hoffstätte
  0 siblings, 0 replies; 11+ messages in thread
From: Holger Hoffstätte @ 2014-09-09 15:12 UTC (permalink / raw)
  To: linux-btrfs

On Tue, 09 Sep 2014 15:06:19 +0000, Holger Hoffstätte wrote:

> You didn't give us any "btrfs fs show" or "btrfs fs df" outpu to look at,

Of course "fi", not "fs"..

-h




^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: ENOSPC on mostly empty file system
  2014-09-09 14:29 ENOSPC on mostly empty file system Arnd Bergmann
  2014-09-09 15:06 ` Holger Hoffstätte
@ 2014-09-09 18:18 ` Arnd Bergmann
  2014-09-09 19:49   ` Clemens Eisserer
  1 sibling, 1 reply; 11+ messages in thread
From: Arnd Bergmann @ 2014-09-09 18:18 UTC (permalink / raw)
  To: linux-btrfs; +Cc: Chris Mason

On Tuesday 09 September 2014 16:29:05 Arnd Bergmann wrote:
> 
> I also played around with it some more. After removing a few small
> files, I could create new files with up to 20-60MB again before hitting
> ENOSPC. I then did a 'make clean' in all the object directories I had
> and after that could fill the file system up to 100% by creating a
> 62GB file using the same command (dd if=/dev/zero of=x).

Ok, one more data point: I was accidentally building randconfig kernels
in the same partition all the time, meaning I had lots of traffic with
small files using the same names all over all the time. After I got
the file system back to a usable state today, building some more randconfig
kernels broke it in the same way.

	Arnd

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: ENOSPC on mostly empty file system
  2014-09-09 18:18 ` Arnd Bergmann
@ 2014-09-09 19:49   ` Clemens Eisserer
  2014-09-09 19:56     ` Hugo Mills
  2014-09-09 21:49     ` Arnd Bergmann
  0 siblings, 2 replies; 11+ messages in thread
From: Clemens Eisserer @ 2014-09-09 19:49 UTC (permalink / raw)
  To: Arnd Bergmann, linux-btrfs

Hi Arnd,

> Ok, one more data point:

Why don't you provide the data point you were specifically asked for,
"btrfs fi df" ;)

Regards, Clemens

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: ENOSPC on mostly empty file system
  2014-09-09 19:49   ` Clemens Eisserer
@ 2014-09-09 19:56     ` Hugo Mills
  2014-09-09 21:49     ` Arnd Bergmann
  1 sibling, 0 replies; 11+ messages in thread
From: Hugo Mills @ 2014-09-09 19:56 UTC (permalink / raw)
  To: Clemens Eisserer; +Cc: Arnd Bergmann, linux-btrfs

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

On Tue, Sep 09, 2014 at 09:49:12PM +0200, Clemens Eisserer wrote:
> Hi Arnd,
> 
> > Ok, one more data point:
> 
> Why don't you provide the data point you were specifically asked for,
> "btrfs fi df" ;)

   btrfs fi show is important as well -- it's hard to work out the
state of the FS from just one of them.

   Hugo.

-- 
=== Hugo Mills: hugo@... carfax.org.uk | darksatanic.net | lug.org.uk ===
  PGP key: 65E74AC0 from wwwkeys.eu.pgp.net or http://www.carfax.org.uk
  --- You can get more with a kind word and a two-by-four than you ---   
                       can with just a kind word.                        

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

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: ENOSPC on mostly empty file system
  2014-09-09 19:49   ` Clemens Eisserer
  2014-09-09 19:56     ` Hugo Mills
@ 2014-09-09 21:49     ` Arnd Bergmann
  2014-09-09 21:57       ` Hugo Mills
  2014-09-09 22:23       ` Holger Hoffstätte
  1 sibling, 2 replies; 11+ messages in thread
From: Arnd Bergmann @ 2014-09-09 21:49 UTC (permalink / raw)
  To: Clemens Eisserer; +Cc: linux-btrfs

On Tuesday 09 September 2014 21:49:12 Clemens Eisserer wrote:
> Hi Arnd,
> 
> > Ok, one more data point:
> 
> Why don't you provide the data point you were specifically asked for,
> "btrfs fi df" ;)

I've cleaned it up again already. At the moment, it's working fine,
with this data:

Data: total=65.11GB, used=7.41GB
System, DUP: total=8.00MB, used=12.00KB
System: total=4.00MB, used=0.00
Metadata, DUP: total=1.00GB, used=799.54MB
Metadata: total=8.00MB, used=0.00
: total=184.00MB, used=0.00

I also realized that the file I uploaded was the uncompressed 800MB
version, not the compressed 82MB file, which is now at
https://drive.google.com/file/d/0B_XQwQ5KlfJAYzY5c1lJRFVQNEE/edit?usp=sharing
Sorry about that.

Ok, now I'm in the bad state again (after running a 'make allmodconfig'
kernel build:

Label: none  uuid: 1d88cccb-3d0e-42d9-8252-a226dc5c2e47
        Total devices 1 FS bytes used 8.79GB
        devid    1 size 67.14GB used 67.14GB path /dev/sdc6

Data: total=65.11GB, used=7.99GB
System, DUP: total=8.00MB, used=12.00KB
System: total=4.00MB, used=0.00
Metadata, DUP: total=1.00GB, used=821.48MB
Metadata: total=8.00MB, used=0.00
: total=200.00MB, used=0.00

Not much extra space used up. Also, a bit from my last shell session
after getting into this state:

arnd@wuerfel:~/arm-soc$ make -skj40
../arch/arm/mach-mmp/devices.c:81:21: warning: 'u2o_get' defined but not used [-Wunused-function]
 static unsigned int u2o_get(void __iomem *base, unsigned int offset)
                     ^
../arch/arm/mach-mmp/devices.c:86:13: warning: 'u2o_set' defined but not used [-Wunused-function]
 static void u2o_set(void __iomem *base, unsigned int offset,
             ^
../arch/arm/mach-mmp/devices.c:97:13: warning: 'u2o_clear' defined but not used [-Wunused-function]
 static void u2o_clear(void __iomem *base, unsigned int offset,
             ^
../arch/arm/mach-mmp/devices.c:108:13: warning: 'u2o_write' defined but not used [-Wunused-function]
 static void u2o_write(void __iomem *base, unsigned int offset,
             ^
mv: cannot move 'security/selinux/ss/.tmp_conditional.o' to 'security/selinux/ss/conditional.o': No space left on device
make[4]: *** [security/selinux/ss/conditional.o] Error 1
mv: cannot move 'kernel/power/.snapshot.o.tmp' to 'kernel/power/.snapshot.o.cmd': No space left on device
make[4]: *** [kernel/power/snapshot.o] Error 1
mv: cannot move 'drivers/ata/.pata_hpt366.o.tmp' to 'drivers/ata/.pata_hpt366.o.cmd': No space left on device
make[4]: *** [drivers/ata/pata_hpt366.o] Error 1
mv: cannot move 'kernel/irq/.proc.o.tmp' to 'kernel/irq/.proc.o.cmd': No space left on device
make[4]: *** [kernel/irq/proc.o] Error 1
...
arnd@wuerfel:~/arm-soc$ dd if=/dev/zero of=x
dd: writing to 'x': No space left on device
416642+0 records in
416641+0 records out
213320192 bytes (213 MB) copied, 2.97814 s, 71.6 MB/s
arnd@wuerfel:~/arm-soc$ dd if=/dev/zero of=x
dd: opening 'x': No space left on device
arnd@wuerfel:~/arm-soc$ dd if=/dev/zero of=x
dd: opening 'x': No space left on device
arnd@wuerfel:~/arm-soc$ rm x
arnd@wuerfel:~/arm-soc$ dd if=/dev/zero of=x
dd: writing to 'x': No space left on device
366053+0 records in
366052+0 records out
187418624 bytes (187 MB) copied, 3.04426 s, 61.6 MB/s
arnd@wuerfel:~/arm-soc$ rm x
arnd@wuerfel:~/arm-soc$ dd if=/dev/zero of=x
dd: writing to 'x': No space left on device
363482+0 records in
363481+0 records out
186102272 bytes (186 MB) copied, 2.80644 s, 66.3 MB/s
arnd@wuerfel:~/arm-soc$ rm x
arnd@wuerfel:~/arm-soc$ dd if=/dev/zero of=x
dd: writing to 'x': No space left on device
366677+0 records in
366676+0 records out
187738112 bytes (188 MB) copied, 2.86939 s, 65.4 MB/s
arnd@wuerfel:~/arm-soc$ sync
arnd@wuerfel:~/arm-soc$ dd if=/dev/zero of=x
dd: opening 'x': No space left on device
arnd@wuerfel:~/arm-soc$ dd if=/dev/zero of=x
dd: opening 'x': No space left on device
arnd@wuerfel:~/arm-soc$ dd if=/dev/zero of=x
dd: opening 'x': No space left on device

I believe that there were no other processes writing to this partition
at the time.

	Arnd

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: ENOSPC on mostly empty file system
  2014-09-09 21:49     ` Arnd Bergmann
@ 2014-09-09 21:57       ` Hugo Mills
  2014-09-09 22:11         ` Roman Mamedov
  2014-09-09 22:12         ` Arnd Bergmann
  2014-09-09 22:23       ` Holger Hoffstätte
  1 sibling, 2 replies; 11+ messages in thread
From: Hugo Mills @ 2014-09-09 21:57 UTC (permalink / raw)
  To: Arnd Bergmann; +Cc: Clemens Eisserer, linux-btrfs

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

On Tue, Sep 09, 2014 at 11:49:10PM +0200, Arnd Bergmann wrote:
> Ok, now I'm in the bad state again (after running a 'make allmodconfig'
> kernel build:
> 
> Label: none  uuid: 1d88cccb-3d0e-42d9-8252-a226dc5c2e47
>         Total devices 1 FS bytes used 8.79GB
>         devid    1 size 67.14GB used 67.14GB path /dev/sdc6

   All the space on the FS has been allocated to some purpose or other.

> Data: total=65.11GB, used=7.99GB

   Here, you have 65 GiB allocated to data, but only 8 GiB of that
used. The FS won't automatically free up any of that (yet -- it's one
of the project ideas).

> System, DUP: total=8.00MB, used=12.00KB
> System: total=4.00MB, used=0.00
> Metadata, DUP: total=1.00GB, used=821.48MB

   Here, you're running close to full with metadata -- the FS needs
some space to write new copies of metadata block in order to modify
anything. It can't get enough space to do that, because there's
nowhere for any more metadata allocation to come from (because it's
all allocated --see my first comment).

   So... you need to free up some data chunks. You can do this with:

# btrfs balance start -dusage=5 /mountpoint

   Take a look at the output of btrfs fi df and btrfs fi show
afterwards, and see how much the Data allocation has reduced by, and
how much unallocated space you have left afterwards. You may want to
increase the number in the above balance command to some higher value,
to free up even more chunks (it limits the balance to chunks less than
n% full -- so the command above will only touch chunks with 5% actual
data or less). This is in the FAQ.

   Hugo.

> Metadata: total=8.00MB, used=0.00
> : total=200.00MB, used=0.00

-- 
=== Hugo Mills: hugo@... carfax.org.uk | darksatanic.net | lug.org.uk ===
  PGP key: 65E74AC0 from wwwkeys.eu.pgp.net or http://www.carfax.org.uk
   --- Comic Sans goes into a bar,  and the barman says, "We don't ---   
                         serve your type here."                          

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

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: ENOSPC on mostly empty file system
  2014-09-09 21:57       ` Hugo Mills
@ 2014-09-09 22:11         ` Roman Mamedov
  2014-09-09 22:12         ` Arnd Bergmann
  1 sibling, 0 replies; 11+ messages in thread
From: Roman Mamedov @ 2014-09-09 22:11 UTC (permalink / raw)
  To: Hugo Mills; +Cc: Arnd Bergmann, Clemens Eisserer, linux-btrfs

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

On Tue, 9 Sep 2014 22:57:25 +0100
Hugo Mills <hugo@carfax.org.uk> wrote:

> On Tue, Sep 09, 2014 at 11:49:10PM +0200, Arnd Bergmann wrote:
> > Ok, now I'm in the bad state again (after running a 'make allmodconfig'
> > kernel build:
> > 
> > Label: none  uuid: 1d88cccb-3d0e-42d9-8252-a226dc5c2e47
> >         Total devices 1 FS bytes used 8.79GB
> >         devid    1 size 67.14GB used 67.14GB path /dev/sdc6
> 
>    All the space on the FS has been allocated to some purpose or other.
> 
> > Data: total=65.11GB, used=7.99GB
> 
>    Here, you have 65 GiB allocated to data, but only 8 GiB of that
> used. The FS won't automatically free up any of that (yet -- it's one
> of the project ideas).

If you find yourself constantly running into this situation, rather than
incorporating periodical btrfs 'balances' into your scripts, you could consider
going with the "mixed" allocation mode of the FS, using the -M option of mkfs.

Seeing as this is not the largest-sized partition in the world in the first
place, the mixed mode would allow for a more efficient and flexible space
allocation on it; at the cost of some performance penalty (you could compare
your compilation times, but I don't think it's too significant).

-- 
With respect,
Roman

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 198 bytes --]

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: ENOSPC on mostly empty file system
  2014-09-09 21:57       ` Hugo Mills
  2014-09-09 22:11         ` Roman Mamedov
@ 2014-09-09 22:12         ` Arnd Bergmann
  1 sibling, 0 replies; 11+ messages in thread
From: Arnd Bergmann @ 2014-09-09 22:12 UTC (permalink / raw)
  To: Hugo Mills; +Cc: Clemens Eisserer, linux-btrfs

On Tuesday 09 September 2014 22:57:25 Hugo Mills wrote:
> On Tue, Sep 09, 2014 at 11:49:10PM +0200, Arnd Bergmann wrote:
> > Ok, now I'm in the bad state again (after running a 'make allmodconfig'
> > kernel build:
> > 
> > Label: none  uuid: 1d88cccb-3d0e-42d9-8252-a226dc5c2e47
> >         Total devices 1 FS bytes used 8.79GB
> >         devid    1 size 67.14GB used 67.14GB path /dev/sdc6
> 
>    All the space on the FS has been allocated to some purpose or other.
> 
> > Data: total=65.11GB, used=7.99GB
> 
>    Here, you have 65 GiB allocated to data, but only 8 GiB of that
> used. The FS won't automatically free up any of that (yet -- it's one
> of the project ideas).

Ok, I see.
 
>    So... you need to free up some data chunks. You can do this with:
> 
> # btrfs balance start -dusage=5 /mountpoint
> 
>    Take a look at the output of btrfs fi df and btrfs fi show
> afterwards, and see how much the Data allocation has reduced by, and
> how much unallocated space you have left afterwards. You may want to
> increase the number in the above balance command to some higher value,
> to free up even more chunks (it limits the balance to chunks less than
> n% full -- so the command above will only touch chunks with 5% actual
> data or less). This is in the FAQ.

This is the output afterwards:
$ time sudo btrfs fi balance start  -dusage=5 /git/
Done, had to relocate 44 out of 70 chunks

real    0m22.026s
user    0m0.014s
sys     0m8.302s

$ sudo btrfs fi show /dev/sdc6
Label: none  uuid: 1d88cccb-3d0e-42d9-8252-a226dc5c2e47
        Total devices 1 FS bytes used 8.79GB
        devid    1 size 67.14GB used 23.14GB path /dev/sdc6

$ sudo btrfs fi df /git
Data: total=21.01GB, used=7.99GB
System, DUP: total=8.00MB, used=12.00KB
System: total=4.00MB, used=0.00
Metadata, DUP: total=1.05GB, used=821.32MB
Metadata: total=8.00MB, used=0.00
: total=200.00MB, used=0.00

I'm pretty sure I read the FAQ one of the last times this happened,
but I thought it would only apply to mostly full file systems.
I can usually recover by moving all the data to tmpfs and doing
a new mkfs before moving the data back, and that normally lasts
for a few months before I run out of space again.

I'll try to see how long it takes until the problem comes back
now.

	Arnd

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: ENOSPC on mostly empty file system
  2014-09-09 21:49     ` Arnd Bergmann
  2014-09-09 21:57       ` Hugo Mills
@ 2014-09-09 22:23       ` Holger Hoffstätte
  1 sibling, 0 replies; 11+ messages in thread
From: Holger Hoffstätte @ 2014-09-09 22:23 UTC (permalink / raw)
  To: linux-btrfs

On Tue, 09 Sep 2014 23:49:10 +0200, Arnd Bergmann wrote:

> Label: none  uuid: 1d88cccb-3d0e-42d9-8252-a226dc5c2e47
>         Total devices 1 FS bytes used 8.79GB
>         devid    1 size 67.14GB used 67.14GB path /dev/sdc6
                          ^^^^^^^^^^^^^^^^^^^^ *ding ding ding*

The term "used" is confusing here and really should be called
"allocated", since it's more than the number of actually used
bytes. Note that df shows that you "have" ~66GB data and ~1GB
metadata (giving approx. ~67GB), despite the fact that of those
65GB data allocated only ~8GB are actually used.

However all these reserved data chunks are preventing the metadata
space from expanding, which is pretty full:
Metadata, DUP: total=1.00GB, used=799.54MB

Here "total" also should be "allocated/reserved" and is 1GB, but
btrfs feels it's necessary to allocate a new metadata chunk
(which would also increase "total") and fails.

Running balance with -dusage=x will garbage-collect the reserved but
mostly-empty data chunks with "up to x" percent actual usage.

-h


^ permalink raw reply	[flat|nested] 11+ messages in thread

end of thread, other threads:[~2014-09-09 22:23 UTC | newest]

Thread overview: 11+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2014-09-09 14:29 ENOSPC on mostly empty file system Arnd Bergmann
2014-09-09 15:06 ` Holger Hoffstätte
2014-09-09 15:12   ` Holger Hoffstätte
2014-09-09 18:18 ` Arnd Bergmann
2014-09-09 19:49   ` Clemens Eisserer
2014-09-09 19:56     ` Hugo Mills
2014-09-09 21:49     ` Arnd Bergmann
2014-09-09 21:57       ` Hugo Mills
2014-09-09 22:11         ` Roman Mamedov
2014-09-09 22:12         ` Arnd Bergmann
2014-09-09 22:23       ` Holger Hoffstätte

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.