Livelock when running xfstests generic/127 on ext4 with 3.15
I didn't see this with 3.14, but I'm not sure what's changed.
When running generic/127, fsx ends up taking 30% CPU time with a kthread taking 70% CPU time for hours. It might be making forward progress, but if it is, it's incredibly slow.
I can usually catch fsx waiting for the kthread:
# ./check generic/127 FSTYP -- ext4 PLATFORM -- Linux/x86_64 walter 3.15.0 MKFS_OPTIONS -- /dev/ram1 MOUNT_OPTIONS -- -o acl,user_xattr /dev/ram1 /mnt/ram1
generic/127 19s ...
$ sudo cat /proc/4795/stack [<ffffffff8120bee9>] writeback_inodes_sb_nr+0xa9/0xe0 [<ffffffff8120bfae>] try_to_writeback_inodes_sb_nr+0x5e/0x80 [<ffffffff8120bff5>] try_to_writeback_inodes_sb+0x25/0x30 [<ffffffffa01bae2a>] ext4_nonda_switch+0x8a/0x90 [ext4] [<ffffffffa01c49a5>] ext4_page_mkwrite+0x265/0x440 [ext4] [<ffffffff811936ed>] do_page_mkwrite+0x3d/0x70 [<ffffffff81195887>] do_wp_page+0x627/0x770 [<ffffffff811981a1>] handle_mm_fault+0x781/0xf00 [<ffffffff815a8996>] __do_page_fault+0x186/0x570 [<ffffffff815a8da2>] do_page_fault+0x22/0x30 [<ffffffff815a5038>] page_fault+0x28/0x30 [<ffffffffffffffff>] 0xffffffffffffffff
My setup is a 1GB ram disk:
modprobe brd rd_size=1048576 rd_nr=2
local.config:
TEST_DEV=/dev/ram0
TEST_DIR=/mnt/ram0
SCRATCH_DEV=/dev/ram1
SCRATCH_MNT=/mnt/ram1
Hardware is an Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz with 4GB RAM, in case it matters. But I think what matters is that I'm running it on a "tiny" 1GB filesystem, since this code is only invoked whenever the number of dirty clusters is large relative to the number of free clusters.
df shows:
/dev/ram1 999320 1284 929224 1% /mnt/ram1 /dev/ram0 999320 646088 284420 70% /mnt/ram0
So it's not *unreasonably* full.
Jan Kara
reviewerQuoted 15 lines · Matthew Wilcox
I didn't see this with 3.14, but I'm not sure what's changed.
When running generic/127, fsx ends up taking 30% CPU time with a kthread taking 70% CPU time for hours. It might be making forward progress, but if it is, it's incredibly slow.
I can usually catch fsx waiting for the kthread:
# ./check generic/127 FSTYP -- ext4 PLATFORM -- Linux/x86_64 walter 3.15.0 MKFS_OPTIONS -- /dev/ram1 MOUNT_OPTIONS -- -o acl,user_xattr /dev/ram1 /mnt/ram1
Quoted 8 lines
generic/127 19s ...
$ sudo cat /proc/4795/stack [<ffffffff8120bee9>] writeback_inodes_sb_nr+0xa9/0xe0 [<ffffffff8120bfae>] try_to_writeback_inodes_sb_nr+0x5e/0x80 [<ffffffff8120bff5>] try_to_writeback_inodes_sb+0x25/0x30 [<ffffffffa01bae2a>] ext4_nonda_switch+0x8a/0x90 [ext4] [<ffffffffa01c49a5>] ext4_page_mkwrite+0x265/0x440 [ext4]
Hum, apparently you are running out of space on the test partition. And
that is known to make ext4 extraordinarily slow...
Honza
Quoted 35 lines
[<ffffffff811936ed>] do_page_mkwrite+0x3d/0x70 [<ffffffff81195887>] do_wp_page+0x627/0x770 [<ffffffff811981a1>] handle_mm_fault+0x781/0xf00 [<ffffffff815a8996>] __do_page_fault+0x186/0x570 [<ffffffff815a8da2>] do_page_fault+0x22/0x30 [<ffffffff815a5038>] page_fault+0x28/0x30[<ffffffffffffffff>]
0xffffffffffffffffMy setup is a 1GB ram disk:
modprobe brd rd_size=1048576 rd_nr=2
local.config:
TEST_DEV=/dev/ram0
TEST_DIR=/mnt/ram0
SCRATCH_DEV=/dev/ram1
SCRATCH_MNT=/mnt/ram1Hardware is an Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz with 4GB RAM, in case it matters. But I think what matters is that I'm running it on a "tiny" 1GB filesystem, since this code is only invoked whenever the number of dirty clusters is large relative to the number of free clusters.
df shows:
/dev/ram1 999320 1284 929224 1% /mnt/ram1 /dev/ram0 999320 646088 284420 70% /mnt/ram0So it's not *unreasonably* full.
--
To unsubscribe from this list: send the line "unsubscribe linux-ext4" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Signature · 2 lines
Jan Kara <[email protected]> SUSE Labs, CR
Quoted 8 lines · Jan Kara
Quoted 6 lines
$ sudo cat /proc/4795/stack [<ffffffff8120bee9>] writeback_inodes_sb_nr+0xa9/0xe0 [<ffffffff8120bfae>] try_to_writeback_inodes_sb_nr+0x5e/0x80 [<ffffffff8120bff5>] try_to_writeback_inodes_sb+0x25/0x30 [<ffffffffa01bae2a>] ext4_nonda_switch+0x8a/0x90 [ext4] [<ffffffffa01c49a5>] ext4_page_mkwrite+0x265/0x440 [ext4]Hum, apparently you are running out of space on the test partition. And
that is known to make ext4 extraordinarily slow...
Okay ... but why is it so much worse in 3.15 than 3.14?
And does ext4 think of "running out of space" as a percentage free, or an absolute number of blocks remaining? From the code in ext4_nonda_switch(), it seems to be the former, although maybe excessive fragmentation has caused ext4 to think it's running out of space?
Quoted 29 lines
Quoted 26 lines
My setup is a 1GB ram disk:
modprobe brd rd_size=1048576 rd_nr=2
local.config:
TEST_DEV=/dev/ram0
TEST_DIR=/mnt/ram0
SCRATCH_DEV=/dev/ram1
SCRATCH_MNT=/mnt/ram1Hardware is an Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz with 4GB RAM, in case it matters. But I think what matters is that I'm running it on a "tiny" 1GB filesystem, since this code is only invoked whenever the number of dirty clusters is large relative to the number of free clusters.
df shows:
/dev/ram1 999320 1284 929224 1% /mnt/ram1 /dev/ram0 999320 646088 284420 70% /mnt/ram0So it's not *unreasonably* full.
--
To unsubscribe from this list: send the line "unsubscribe linux-ext4" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.htmlSignature · 2 lines
Jan Kara <[email protected]> SUSE Labs, CR
Jan Kara
reviewerQuoted 11 lines · Matthew Wilcox
Quoted 8 lines · Jan Kara
Quoted 6 lines
$ sudo cat /proc/4795/stack [<ffffffff8120bee9>] writeback_inodes_sb_nr+0xa9/0xe0 [<ffffffff8120bfae>] try_to_writeback_inodes_sb_nr+0x5e/0x80 [<ffffffff8120bff5>] try_to_writeback_inodes_sb+0x25/0x30 [<ffffffffa01bae2a>] ext4_nonda_switch+0x8a/0x90 [ext4] [<ffffffffa01c49a5>] ext4_page_mkwrite+0x265/0x440 [ext4]Hum, apparently you are running out of space on the test partition. And
that is known to make ext4 extraordinarily slow...Okay ... but why is it so much worse in 3.15 than 3.14?
Is it really a difference between kernels? Didn't just the partition get
more full? If it is really just a kernel difference I don't have a good explanation... Bisecting that down would be useful...
Quoted 4 lines
And does ext4 think of "running out of space" as a percentage free, or an absolute number of blocks remaining? From the code in
ext4_nonda_switch(), it seems to be the former, although maybe excessive fragmentation has caused ext4 to think it's running out of space?
We start forcing writeback (and waiting for it) when the amount of free
space is less than twice the amount of delayed-allocated blocks which are not yet written out.
Honza
Quoted 29 lines
Quoted 29 lines
Quoted 26 lines
My setup is a 1GB ram disk:
modprobe brd rd_size=1048576 rd_nr=2
local.config:
TEST_DEV=/dev/ram0
TEST_DIR=/mnt/ram0
SCRATCH_DEV=/dev/ram1
SCRATCH_MNT=/mnt/ram1Hardware is an Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz with 4GB RAM, in case it matters. But I think what matters is that I'm running it on a "tiny" 1GB filesystem, since this code is only invoked whenever the number of dirty clusters is large relative to the number of free clusters.
df shows:
/dev/ram1 999320 1284 929224 1% /mnt/ram1 /dev/ram0 999320 646088 284420 70% /mnt/ram0So it's not *unreasonably* full.
--
To unsubscribe from this list: send the line "unsubscribe linux-ext4" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.htmlSignature · 2 lines
Jan Kara <[email protected]> SUSE Labs, CR
Signature · 2 lines
Jan Kara <[email protected]> SUSE Labs, CR
Quoted 7 lines · Matthew Wilcox
Okay ... but why is it so much worse in 3.15 than 3.14?
And does ext4 think of "running out of space" as a percentage free, or an absolute number of blocks remaining? From the code in
ext4_nonda_switch(), it seems to be the former, although maybe excessive fragmentation has caused ext4 to think it's running out of space?
When the blocks that were allocated using delayed allocation exceeds 50% of the free space, we initiate writeback. When delalloc blocks exceeds 66% of the free space, we fall back to nodelalloc, which among other things, means blocks are allocated for each write system call, and we also have to add and remove the inode from on the orphan inode list so that if we crash in the middle of the write system call, we don't end up exposing stale data.
We did have a change to the orphan inode code to improve scalability, so that could have been a possible cause; but that happened after 3.15, so that can't be it. The other possibility is that there's simply a chance in the writeback code that is changing how aggressively we start writeback when we exceed the 50% threshold, so that we end up switching into nonda mode more often.
Any chance you can run generic/127 under perf so we can see where we're spending all of our CPU time? The other thing I can imagine doing is to add tracepoint when whenver we drop into nonda mode, so we can see if that's happening more often under 3.15 versus 3.14.
- Ted