Linux-Fsdevel Archive on lore.kernel.org
 help / Atom feed
* [PATCH v3] fs: ratelimit __find_get_block_slow() failure message.
@ 2019-01-21 13:49 Tetsuo Handa
  2019-02-06 14:37 ` Tetsuo Handa
  2019-02-06 19:59 ` Jens Axboe
  0 siblings, 2 replies; 3+ messages in thread
From: Tetsuo Handa @ 2019-01-21 13:49 UTC (permalink / raw)
  To: Jens Axboe
  Cc: linux-block, linux-fsdevel, Tetsuo Handa, Dmitry Vyukov, Jan Kara

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);
-- 
1.8.3.1


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

* Re: [PATCH v3] fs: ratelimit __find_get_block_slow() failure message.
  2019-01-21 13:49 [PATCH v3] fs: ratelimit __find_get_block_slow() failure message Tetsuo Handa
@ 2019-02-06 14:37 ` Tetsuo Handa
  2019-02-06 19:59 ` Jens Axboe
  1 sibling, 0 replies; 3+ messages in thread
From: Tetsuo Handa @ 2019-02-06 14:37 UTC (permalink / raw)
  To: Jens Axboe; +Cc: linux-block, linux-fsdevel, Dmitry Vyukov, Jan Kara

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);
> 


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

* Re: [PATCH v3] fs: ratelimit __find_get_block_slow() failure message.
  2019-01-21 13:49 [PATCH v3] fs: ratelimit __find_get_block_slow() failure message Tetsuo Handa
  2019-02-06 14:37 ` Tetsuo Handa
@ 2019-02-06 19:59 ` Jens Axboe
  1 sibling, 0 replies; 3+ messages in thread
From: Jens Axboe @ 2019-02-06 19:59 UTC (permalink / raw)
  To: Tetsuo Handa; +Cc: linux-block, linux-fsdevel, Dmitry Vyukov, Jan Kara

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.

-- 
Jens Axboe


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

end of thread, back to index

Thread overview: 3+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2019-01-21 13:49 [PATCH v3] fs: ratelimit __find_get_block_slow() failure message Tetsuo Handa
2019-02-06 14:37 ` Tetsuo Handa
2019-02-06 19:59 ` Jens Axboe

Linux-Fsdevel Archive on lore.kernel.org

Archives are clonable:
	git clone --mirror https://lore.kernel.org/linux-fsdevel/0 linux-fsdevel/git/0.git

	# If you have public-inbox 1.1+ installed, you may
	# initialize and index your mirror using the following commands:
	public-inbox-init -V2 linux-fsdevel linux-fsdevel/ https://lore.kernel.org/linux-fsdevel \
		linux-fsdevel@vger.kernel.org linux-fsdevel@archiver.kernel.org
	public-inbox-index linux-fsdevel


Newsgroup available over NNTP:
	nntp://nntp.lore.kernel.org/org.kernel.vger.linux-fsdevel


AGPL code for this site: git clone https://public-inbox.org/ public-inbox