btrfs-transacti hammering the system

Is there any way to figure out what exactly btrfs-transacti is chugging on?  I have a few file systems that seem to get wedged for days on end with this process pegged around 100%.  I've stopped all snapshots, made sure no quotas were enabled, turned on autodefrag in the mount options, tried manual defragging, kernel upgrades, yet still this brings my system to a crawl.

Network I/O to the system seems very tiny.  The only I/O I see to the disk is btrfs-transacti writing a couple M/s.

# time touch foo

real    2m54.303s
user    0m0.000s
sys     0m0.002s

# uname -r
4.12.8-custom

# btrfs --version
btrfs-progs v4.13.3

Yes, I know I'm a bit behind there...

Thanks for this.  Here's what I get:

[...]

[<ffffffffaa0a8406>] io_schedule+0x16/0x40
[<ffffffffaa3b3cde>] get_request+0x23e/0x720
[<ffffffffaa3b6861>] blk_queue_bio+0xc1/0x3a0
[<ffffffffaa3b4a88>] generic_make_request+0xf8/0x2a0
[<ffffffffaa3b4ca5>] submit_bio+0x75/0x150
[<ffffffffc087fac5>] btrfs_map_bio+0xe5/0x2f0 [btrfs]
[<ffffffffc084834c>] btree_submit_bio_hook+0x8c/0xe0 [btrfs]
[<ffffffffc086f1e3>] submit_one_bio+0x63/0xa0 [btrfs]
[<ffffffffc086f39b>] flush_epd_write_bio+0x3b/0x50 [btrfs]
[<ffffffffc086f3be>] flush_write_bio+0xe/0x10 [btrfs]
[<ffffffffc08777a9>] btree_write_cache_pages+0x379/0x450 [btrfs]
[<ffffffffc08478ed>] btree_writepages+0x5d/0x70 [btrfs]
[<ffffffffaa1a326c>] do_writepages+0x1c/0x70
[<ffffffffaa196f2a>] __filemap_fdatawrite_range+0xaa/0xe0
[<ffffffffaa197023>] filemap_fdatawrite_range+0x13/0x20
[<ffffffffc084fba9>] btrfs_write_marked_extents+0xe9/0x110 [btrfs]
[<ffffffffc084fc4d>] btrfs_write_and_wait_transaction.isra.22+0x3d/0x80

[btrfs]
[<ffffffffc0851645>] btrfs_commit_transaction+0x665/0x900 [btrfs]

[...]

[<ffffffffaa0a8406>] io_schedule+0x16/0x40
[<ffffffffaa1959c8>] wait_on_page_bit+0xe8/0x120
[<ffffffffc087639d>] read_extent_buffer_pages+0x1cd/0x2e0 [btrfs]
[<ffffffffc0846fcf>] btree_read_extent_buffer_pages+0x9f/0x100 [btrfs]
[<ffffffffc0848542>] read_tree_block+0x32/0x50 [btrfs]
[<ffffffffc0828980>] read_block_for_search.isra.32+0x120/0x2e0 [btrfs]
[<ffffffffc082daa5>] btrfs_next_old_leaf+0x215/0x400 [btrfs]
[<ffffffffc082dca0>] btrfs_next_leaf+0x10/0x20 [btrfs]
[<ffffffffc0843c3e>] btrfs_lookup_csums_range+0x12e/0x410 [btrfs]
[<ffffffffc08d09ea>] csum_exist_in_range.isra.49+0x2a/0x81 [btrfs]
[<ffffffffc08596a2>] run_delalloc_nocow+0x9b2/0xa10 [btrfs]
[<ffffffffc0859768>] run_delalloc_range+0x68/0x340 [btrfs]
[<ffffffffc0872070>] writepage_delalloc.isra.47+0xf0/0x140 [btrfs]
[<ffffffffc0872f97>] __extent_writepage+0xc7/0x290 [btrfs]
[<ffffffffc0873415>] extent_write_cache_pages.constprop.53+0x2b5/0x450
[btrfs]
[<ffffffffc0874fed>] extent_writepages+0x4d/0x70 [btrfs]
[<ffffffffc0852d88>] btrfs_writepages+0x28/0x30 [btrfs]
[<ffffffffaa1a326c>] do_writepages+0x1c/0x70

[<ffffffffaa196f2a>] __filemap_fdatawrite_range+0xaa/0xe0
[<ffffffffaa197023>] filemap_fdatawrite_range+0x13/0x20
[<ffffffffc08695c0>] btrfs_fdatawrite_range+0x20/0x50 [btrfs]
[<ffffffffc089abf9>] __btrfs_write_out_cache+0x3d9/0x420 [btrfs]
[<ffffffffc089b066>] btrfs_write_out_cache+0x86/0x100 [btrfs]
[<ffffffffc083bc61>] btrfs_write_dirty_block_groups+0x261/0x390 [btrfs]
[<ffffffffc084e83b>] commit_cowonly_roots+0x1fb/0x290 [btrfs]
[<ffffffffc0851414>] btrfs_commit_transaction+0x434/0x900 [btrfs]

1) The one right above, btrfs_write_out_cache, is the write-out of the free space cache v1. Do you see this for multiple seconds going on, and does it match the time when it's writing X MB/s to disk?

2) How big is this filesystem? What does your btrfs fi df /mountpoint say?

3) What kind of workload are you running? E.g. how can you describe it within a range from "big files which just sit there" to "small writes and deletes all over the place all the time"?

4) What kernel version is this? uname -a output?

Sorry, I missed your in-line reply:

Quoted 4 lines

1) The one right above, btrfs_write_out_cache, is the write-out of the free space cache v1. Do you see this for multiple seconds going on, and does it match the time when it's writing X MB/s to disk?

It seems to only last until the next watch update.

[<ffffffffaa0a8406>] io_schedule+0x16/0x40
[<ffffffffaa3b3cde>] get_request+0x23e/0x720
[<ffffffffaa3b6861>] blk_queue_bio+0xc1/0x3a0
[<ffffffffaa3b4a88>] generic_make_request+0xf8/0x2a0
[<ffffffffaa3b4ca5>] submit_bio+0x75/0x150
[<ffffffffc087fac5>] btrfs_map_bio+0xe5/0x2f0 [btrfs]
[<ffffffffc084834c>] btree_submit_bio_hook+0x8c/0xe0 [btrfs]
[<ffffffffc086f1e3>] submit_one_bio+0x63/0xa0 [btrfs]
[<ffffffffc086f39b>] flush_epd_write_bio+0x3b/0x50 [btrfs]
[<ffffffffc086f3be>] flush_write_bio+0xe/0x10 [btrfs]
[<ffffffffc08777a9>] btree_write_cache_pages+0x379/0x450 [btrfs]
[<ffffffffc08478ed>] btree_writepages+0x5d/0x70 [btrfs]
[<ffffffffaa1a326c>] do_writepages+0x1c/0x70
[<ffffffffaa196f2a>] __filemap_fdatawrite_range+0xaa/0xe0
[<ffffffffaa197023>] filemap_fdatawrite_range+0x13/0x20
[<ffffffffc084fba9>] btrfs_write_marked_extents+0xe9/0x110 [btrfs]
[<ffffffffc084fc4d>] btrfs_write_and_wait_transaction.isra.22+0x3d/0x80
[btrfs]
[<ffffffffc0851645>] btrfs_commit_transaction+0x665/0x900 [btrfs]
[<ffffffffc084baca>] transaction_kthread+0x18a/0x1c0 [btrfs]
[<ffffffffaa09b839>] kthread+0x109/0x140
[<ffffffffaa8459f5>] ret_from_fork+0x25/0x30

The last three lines will stick around for a while.  Is switching to space cache v2 something that everyone should be doing?  Something that would be a good test at least?

Quoted 3 lines

2) How big is this filesystem? What does your btrfs fi df /mountpoint say?

# btrfs fi df /export/
Data, single: total=30.45TiB, used=30.25TiB
System, DUP: total=32.00MiB, used=3.62MiB
Metadata, DUP: total=66.50GiB, used=65.08GiB
GlobalReserve, single: total=512.00MiB, used=53.69MiB

Quoted 3 lines

3) What kind of workload are you running? E.g. how can you describe it within a range from "big files which just sit there" to "small writes and deletes all over the place all the time"?

It's a pretty light workload most of the time.  It's a file system that exports two NFS shares to a small lab group.  I believe it is more small reads all over a large file (MRI imaging) rather than small writes.

Quoted 1 line

4) What kernel version is this? uname -a output?

# uname -a
Linux machine_name 4.12.8-custom #1 SMP Tue Aug 22 10:15:01 EDT 2017
x86_64 x86_64 x86_64 GNU/Linux

Additional tips (forgot to ask for your /proc/mounts before):
* Use the noatime mount option, so that only accessing files does not lead to changes in metadata,

01.12.2017 20:06, Hans van Kranenburg пишет:

Quoted 4 lines

Additional tips (forgot to ask for your /proc/mounts before):
* Use the noatime mount option, so that only accessing files does not lead to changes in metadata,

Is not 'lazytime" default today? It gives you correct atime + no extra metadata update cause by update of atime only.

Quoted 7 lines

01.12.2017 20:06, Hans van Kranenburg пишет:

Quoted 4 lines

Additional tips (forgot to ask for your /proc/mounts before):
* Use the noatime mount option, so that only accessing files does not lead to changes in metadata,

Is not 'lazytime" default today?

It gives you correct atime + no extra

Quoted 1 line

metadata update cause by update of atime only.

Unless things have changed since the last time this came up, BTRFS does not support the 'lazytime' mount option (but it doesn't complain about it either).

Also, lazytime is independent from noatime, and using both can have benefits (lazytime will still have to write out the inode for every file read on the system every 24 hours, but with noatime it only has to write out the inode for files that have changed).

Thanks, I'll give space_cache=v2 a shot.

My mount options are: rw,relatime,space_cache,autodefrag,subvolid=5,subvol=/

Quoted 1 line · Matt McKinnon

Thanks, I'll give space_cache=v2 a shot.

Yes, very much recommended.

Quoted 1 line

My mount options are: rw,relatime,space_cache,autodefrag,subvolid=5,subvol=/

Turn autodefrag off and use noatime instead of relatime.

Your filesystem also seems very full,

that's bad with every filesystem but
*especially* with btrfs because the allocator has to work really hard to find free space for COWing. Really consider deleting stuff or adding more space.

Quoted 10 lines · Holger Hoffstätte

Quoted 1 line · Matt McKinnon

Thanks, I'll give space_cache=v2 a shot.

Yes, very much recommended.

Quoted 1 line

My mount options are: rw,relatime,space_cache,autodefrag,subvolid=5,subvol=/

Turn autodefrag off and use noatime instead of relatime.

Your filesystem also seems very full,

We don't know. btrfs fi df only displays allocated space. And that being full is good, it means not too much free space fragments everywhere.

Quoted 3 lines

that's bad with every filesystem but
*especially* with btrfs because the allocator has to work really hard to find free space for COWing. Really consider deleting stuff or adding more space.

Right. The file system is 48T, with 17T available, so we're not quite pushing it yet.

So far so good on the space_cache=v2 mount. I'm surprised this isn't on the gotcha page in the wiki; it may end up making a world of difference to the users here

Quoted 7 lines

Sorry, I missed your in-line reply:

Quoted 3 lines

2) How big is this filesystem? What does your btrfs fi df /mountpoint say?

Quoted 5 lines

# btrfs fi df /export/
Data, single: total=30.45TiB, used=30.25TiB
System, DUP: total=32.00MiB, used=3.62MiB
Metadata, DUP: total=66.50GiB, used=65.08GiB
GlobalReserve, single: total=512.00MiB, used=53.69MiB

Multi-TiB filesystem, check. total/used ratio looks healthy.

Hans van Kranenburg posted on Fri, 01 Dec 2017 18:06:23 +0100 as excerpted:

Quoted 8 lines · Matt McKinnon

Quoted 7 lines

Sorry, I missed your in-line reply:

Quoted 3 lines

2) How big is this filesystem? What does your btrfs fi df /mountpoint say?

Quoted 7 lines

Quoted 5 lines

# btrfs fi df /export/
Data, single: total=30.45TiB, used=30.25TiB
System, DUP: total=32.00MiB, used=3.62MiB
Metadata, DUP: total=66.50GiB, used=65.08GiB
GlobalReserve, single: total=512.00MiB, used=53.69MiB

Multi-TiB filesystem, check. total/used ratio looks healthy.

Not so healthy, from here. Data/metadata are healthy, yes, but...

Any usage at all of global reserve is a red flag indicating that something in the filesystem thinks, or thought when it resorted to global reserve, that space is running out.

Global reserve usage doesn't really hint what the problem is, but it's definitely a red flag that there /is/ a problem, and it's easily overlooked, as it apparently was here.

It's likely indication of a bug, possibly one of the ones fixed right around 4.12/4.13. I'll let the devs and better experts take it from there, but I'd certainly be worried until global reserve drops to zero usage.

Well, it's at zero now...

# btrfs fi df /export/
Data, single: total=30.45TiB, used=30.25TiB
System, DUP: total=32.00MiB, used=3.62MiB
Metadata, DUP: total=66.50GiB, used=65.16GiB
GlobalReserve, single: total=512.00MiB, used=0.00B

Quoted 35 lines

Hans van Kranenburg posted on Fri, 01 Dec 2017 18:06:23 +0100 as excerpted:

Quoted 8 lines · Matt McKinnon

Quoted 7 lines

Sorry, I missed your in-line reply:

Quoted 3 lines

2) How big is this filesystem? What does your btrfs fi df /mountpoint say?

Quoted 7 lines

Quoted 5 lines

# btrfs fi df /export/
Data, single: total=30.45TiB, used=30.25TiB
System, DUP: total=32.00MiB, used=3.62MiB
Metadata, DUP: total=66.50GiB, used=65.08GiB
GlobalReserve, single: total=512.00MiB, used=53.69MiB

Multi-TiB filesystem, check. total/used ratio looks healthy.

Not so healthy, from here.  Data/metadata are healthy, yes, but...

Any usage at all of global reserve is a red flag indicating that something in the filesystem thinks, or thought when it resorted to global reserve, that space is running out.

Global reserve usage doesn't really hint what the problem is, but it's definitely a red flag that there /is/ a problem, and it's easily overlooked, as it apparently was here.

It's likely indication of a bug, possibly one of the ones fixed right around 4.12/4.13.  I'll let the devs and better experts take it from there, but I'd certainly be worried until global reserve drops to zero usage.

Quoted 7 lines

Well, it's at zero now...

# btrfs fi df /export/
Data, single: total=30.45TiB, used=30.25TiB
System, DUP: total=32.00MiB, used=3.62MiB
Metadata, DUP: total=66.50GiB, used=65.16GiB
GlobalReserve, single: total=512.00MiB, used=0.00B

GlobalReserve seems to be used temporarily for certain cases of metadata COW regardless of how full the FS actually is, I'm betting that it just so happened that such a case was in progress when you got the info previously. If you aren't seeing it regularly used, it's (probably) not an issue.

Duncan is correct though when dealing with long-term usage. If you see GlobalReserve usage that persists for an extended period of time, something is almost certainly wrong, especially if the FS isn't close to being full.

Austin S. Hemmelgarn posted on Mon, 04 Dec 2017 07:18:11 -0500 as excerpted:

Quoted 15 lines · Matt McKinnon

Quoted 7 lines

Well, it's at zero now...

# btrfs fi df /export/
Data, single: total=30.45TiB, used=30.25TiB
System, DUP: total=32.00MiB, used=3.62MiB
Metadata, DUP: total=66.50GiB, used=65.16GiB
GlobalReserve, single: total=512.00MiB, used=0.00B

GlobalReserve seems to be used temporarily for certain cases of metadata COW regardless of how full the FS actually is, I'm betting that it just so happened that such a case was in progress when you got the info previously. If you aren't seeing it regularly used, it's (probably) not an issue.

Quoted 4 lines

Duncan is correct though when dealing with long-term usage. If you see GlobalReserve usage that persists for an extended period of time, something is almost certainly wrong, especially if the FS isn't close to being full.

Thanks. I wasn't aware global reserve was routinely temporarily used.