From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org X-Spam-Level: X-Spam-Status: No, score=-8.5 required=3.0 tests=HEADER_FROM_DIFFERENT_DOMAINS, INCLUDES_PATCH,MAILING_LIST_MULTI,SIGNED_OFF_BY,SPF_PASS,URIBL_BLOCKED, USER_AGENT_MUTT autolearn=ham autolearn_force=no version=3.4.0 Received: from mail.kernel.org (mail.kernel.org [198.145.29.99]) by smtp.lore.kernel.org (Postfix) with ESMTP id ED7BFC282F6 for ; Mon, 21 Jan 2019 08:57:57 +0000 (UTC) Received: from vger.kernel.org (vger.kernel.org [209.132.180.67]) by mail.kernel.org (Postfix) with ESMTP id C5B962084A for ; Mon, 21 Jan 2019 08:57:57 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1727784AbfAUI55 (ORCPT ); Mon, 21 Jan 2019 03:57:57 -0500 Received: from mx2.suse.de ([195.135.220.15]:48404 "EHLO mx1.suse.de" rhost-flags-OK-OK-OK-FAIL) by vger.kernel.org with ESMTP id S1727681AbfAUI55 (ORCPT ); Mon, 21 Jan 2019 03:57:57 -0500 X-Virus-Scanned: by amavisd-new at test-mx.suse.de Received: from relay2.suse.de (unknown [195.135.220.254]) by mx1.suse.de (Postfix) with ESMTP id 05841ADD6; Mon, 21 Jan 2019 08:57:54 +0000 (UTC) Received: by quack2.suse.cz (Postfix, from userid 1000) id 7EA3F1E1584; Mon, 21 Jan 2019 09:57:53 +0100 (CET) Date: Mon, 21 Jan 2019 09:57:53 +0100 From: Jan Kara To: Tetsuo Handa Cc: Jan Kara , Alexander Viro , Dmitry Vyukov , linux-fsdevel@vger.kernel.org Subject: Re: [PATCH v2] fs: ratelimit __find_get_block_slow() failure message. Message-ID: <20190121085753.GB6566@quack2.suse.cz> References: <1547201433-10231-1-git-send-email-penguin-kernel@I-love.SAKURA.ne.jp> <20190111110340.GB4098@quack2.suse.cz> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: User-Agent: Mutt/1.10.1 (2018-07-13) Sender: linux-fsdevel-owner@vger.kernel.org Precedence: bulk List-ID: X-Mailing-List: linux-fsdevel@vger.kernel.org On Fri 11-01-19 20:37:42, 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 > --- > fs/buffer.c | 18 ++++++++---------- > 1 file changed, 8 insertions(+), 10 deletions(-) > > diff --git a/fs/buffer.c b/fs/buffer.c > index 52d024b..4be8083 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,16 +228,13 @@ 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", I would wrap this like: printk("__find_get_block_slow() failed. block=%llu, " "b_blocknr=%llu, b_state=0x%08lx, b_size=%zu, " "device %pg blocksize: %d\n", as 140 chars long line seems really too much. Also I'd embed the 'if body' in { }. I know it's not necessary but it makes the code more readable when printk has to occupy multiple lines. Otherwise the patch looks good so feel free to add: Reviewed-by: Jan Kara WRT merging, you might want to send the fix to Jens Axboe since he's occasionally merging fs/buffer.c patches. Honza > + (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); > put_page(page); > -- > 1.8.3.1 > > -- Jan Kara SUSE Labs, CR