| Message ID | 1548078577-10353-1-git-send-email-penguin-kernel@I-love.SAKURA.ne.jp (mailing list archive) |
|---|---|
| State | New, archived |
| Headers | show |
| Series | [v3] fs: ratelimit __find_get_block_slow() failure message. | expand |
Hello, Jens. Can we apply this patch? On 2019/01/21 22:49, Tetsuo Handa wrote: > When something let __find_get_block_slow() hit all_mapped path, it calls > printk() for 100+ times per a second. But there is no need to print same > message with such high frequency; it is just asking for stall warning, or > at least bloating log files. > > [ 399.866302][T15342] __find_get_block_slow() failed. block=1, b_blocknr=8 > [ 399.873324][T15342] b_state=0x00000029, b_size=512 > [ 399.878403][T15342] device loop0 blocksize: 4096 > [ 399.883296][T15342] __find_get_block_slow() failed. block=1, b_blocknr=8 > [ 399.890400][T15342] b_state=0x00000029, b_size=512 > [ 399.895595][T15342] device loop0 blocksize: 4096 > [ 399.900556][T15342] __find_get_block_slow() failed. block=1, b_blocknr=8 > [ 399.907471][T15342] b_state=0x00000029, b_size=512 > [ 399.912506][T15342] device loop0 blocksize: 4096 > > This patch reduces frequency to up to once per a second, in addition to > concatenating three lines into one. > > [ 399.866302][T15342] __find_get_block_slow() failed. block=1, b_blocknr=8, b_state=0x00000029, b_size=512, device loop0 blocksize: 4096 > > Signed-off-by: Tetsuo Handa <penguin-kernel@I-love.SAKURA.ne.jp> > Reviewed-by: Jan Kara <jack@suse.cz> > Cc: Dmitry Vyukov <dvyukov@google.com> > --- > fs/buffer.c | 19 ++++++++++--------- > 1 file changed, 10 insertions(+), 9 deletions(-) > > diff --git a/fs/buffer.c b/fs/buffer.c > index 52d024b..48318fb 100644 > --- a/fs/buffer.c > +++ b/fs/buffer.c > @@ -200,6 +200,7 @@ void end_buffer_write_sync(struct buffer_head *bh, int uptodate) > struct buffer_head *head; > struct page *page; > int all_mapped = 1; > + static DEFINE_RATELIMIT_STATE(last_warned, HZ, 1); > > index = block >> (PAGE_SHIFT - bd_inode->i_blkbits); > page = find_get_page_flags(bd_mapping, index, FGP_ACCESSED); > @@ -227,15 +228,15 @@ void end_buffer_write_sync(struct buffer_head *bh, int uptodate) > * file io on the block device and getblk. It gets dealt with > * elsewhere, don't buffer_error if we had some unmapped buffers > */ > - if (all_mapped) { > - printk("__find_get_block_slow() failed. " > - "block=%llu, b_blocknr=%llu\n", > - (unsigned long long)block, > - (unsigned long long)bh->b_blocknr); > - printk("b_state=0x%08lx, b_size=%zu\n", > - bh->b_state, bh->b_size); > - printk("device %pg blocksize: %d\n", bdev, > - 1 << bd_inode->i_blkbits); > + ratelimit_set_flags(&last_warned, RATELIMIT_MSG_ON_RELEASE); > + if (all_mapped && __ratelimit(&last_warned)) { > + printk("__find_get_block_slow() failed. block=%llu, " > + "b_blocknr=%llu, b_state=0x%08lx, b_size=%zu, " > + "device %pg blocksize: %d\n", > + (unsigned long long)block, > + (unsigned long long)bh->b_blocknr, > + bh->b_state, bh->b_size, bdev, > + 1 << bd_inode->i_blkbits); > } > out_unlock: > spin_unlock(&bd_mapping->private_lock); >
On 1/21/19 6:49 AM, Tetsuo Handa wrote: > When something let __find_get_block_slow() hit all_mapped path, it calls > printk() for 100+ times per a second. But there is no need to print same > message with such high frequency; it is just asking for stall warning, or > at least bloating log files. > > [ 399.866302][T15342] __find_get_block_slow() failed. block=1, b_blocknr=8 > [ 399.873324][T15342] b_state=0x00000029, b_size=512 > [ 399.878403][T15342] device loop0 blocksize: 4096 > [ 399.883296][T15342] __find_get_block_slow() failed. block=1, b_blocknr=8 > [ 399.890400][T15342] b_state=0x00000029, b_size=512 > [ 399.895595][T15342] device loop0 blocksize: 4096 > [ 399.900556][T15342] __find_get_block_slow() failed. block=1, b_blocknr=8 > [ 399.907471][T15342] b_state=0x00000029, b_size=512 > [ 399.912506][T15342] device loop0 blocksize: 4096 > > This patch reduces frequency to up to once per a second, in addition to > concatenating three lines into one. Applied, thanks.
diff --git a/fs/buffer.c b/fs/buffer.c index 52d024b..48318fb 100644 --- a/fs/buffer.c +++ b/fs/buffer.c @@ -200,6 +200,7 @@ void end_buffer_write_sync(struct buffer_head *bh, int uptodate) struct buffer_head *head; struct page *page; int all_mapped = 1; + static DEFINE_RATELIMIT_STATE(last_warned, HZ, 1); index = block >> (PAGE_SHIFT - bd_inode->i_blkbits); page = find_get_page_flags(bd_mapping, index, FGP_ACCESSED); @@ -227,15 +228,15 @@ void end_buffer_write_sync(struct buffer_head *bh, int uptodate) * file io on the block device and getblk. It gets dealt with * elsewhere, don't buffer_error if we had some unmapped buffers */ - if (all_mapped) { - printk("__find_get_block_slow() failed. " - "block=%llu, b_blocknr=%llu\n", - (unsigned long long)block, - (unsigned long long)bh->b_blocknr); - printk("b_state=0x%08lx, b_size=%zu\n", - bh->b_state, bh->b_size); - printk("device %pg blocksize: %d\n", bdev, - 1 << bd_inode->i_blkbits); + ratelimit_set_flags(&last_warned, RATELIMIT_MSG_ON_RELEASE); + if (all_mapped && __ratelimit(&last_warned)) { + printk("__find_get_block_slow() failed. block=%llu, " + "b_blocknr=%llu, b_state=0x%08lx, b_size=%zu, " + "device %pg blocksize: %d\n", + (unsigned long long)block, + (unsigned long long)bh->b_blocknr, + bh->b_state, bh->b_size, bdev, + 1 << bd_inode->i_blkbits); } out_unlock: spin_unlock(&bd_mapping->private_lock);