From patchwork Tue Oct 13 17:03:08 2015 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Jaegeuk Kim X-Patchwork-Id: 7386901 Return-Path: X-Original-To: patchwork-linux-fsdevel@patchwork.kernel.org Delivered-To: patchwork-parsemail@patchwork2.web.kernel.org Received: from mail.kernel.org (mail.kernel.org [198.145.29.136]) by patchwork2.web.kernel.org (Postfix) with ESMTP id 08057BEEA4 for ; Tue, 13 Oct 2015 17:03:30 +0000 (UTC) Received: from mail.kernel.org (localhost [127.0.0.1]) by mail.kernel.org (Postfix) with ESMTP id 092612074E for ; Tue, 13 Oct 2015 17:03:29 +0000 (UTC) Received: from vger.kernel.org (vger.kernel.org [209.132.180.67]) by mail.kernel.org (Postfix) with ESMTP id DB46320749 for ; Tue, 13 Oct 2015 17:03:27 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S932393AbbJMRDM (ORCPT ); Tue, 13 Oct 2015 13:03:12 -0400 Received: from mail.kernel.org ([198.145.29.136]:50029 "EHLO mail.kernel.org" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1753032AbbJMRDL (ORCPT ); Tue, 13 Oct 2015 13:03:11 -0400 Received: from mail.kernel.org (localhost [127.0.0.1]) by mail.kernel.org (Postfix) with ESMTP id 9C6A82074E; Tue, 13 Oct 2015 17:03:10 +0000 (UTC) Received: from localhost (mobile-166-171-249-193.mycingular.net [166.171.249.193]) (using TLSv1.2 with cipher AES128-GCM-SHA256 (128/128 bits)) (No client certificate requested) by mail.kernel.org (Postfix) with ESMTPSA id 1466E20749; Tue, 13 Oct 2015 17:03:09 +0000 (UTC) Date: Tue, 13 Oct 2015 10:03:08 -0700 From: Jaegeuk Kim To: He YunLei Cc: linux-fsdevel@vger.kernel.org, linux-kernel@vger.kernel.org, linux-f2fs-devel@lists.sourceforge.net Subject: Re: [f2fs-dev] [PATCH 2/3] f2fs: add a tracepoint for background gc Message-ID: <20151013170308.GB60592@jaegeuk-mac02.mot.com> References: <1444085040-12843-1-git-send-email-jaegeuk@kernel.org> <1444085040-12843-2-git-send-email-jaegeuk@kernel.org> <5618B96A.50205@huawei.com> MIME-Version: 1.0 Content-Disposition: inline In-Reply-To: <5618B96A.50205@huawei.com> User-Agent: Mutt/1.5.21 (2010-09-15) X-Spam-Status: No, score=-6.9 required=5.0 tests=BAYES_00, RCVD_IN_DNSWL_HI, T_RP_MATCHES_RCVD, UNPARSEABLE_RELAY autolearn=unavailable version=3.3.1 X-Spam-Checker-Version: SpamAssassin 3.3.1 (2010-03-16) on mail.kernel.org X-Virus-Scanned: ClamAV using ClamSMTP Sender: linux-fsdevel-owner@vger.kernel.org Precedence: bulk List-ID: X-Mailing-List: linux-fsdevel@vger.kernel.org X-Virus-Scanned: ClamAV using ClamSMTP On Sat, Oct 10, 2015 at 03:08:26PM +0800, He YunLei wrote: > On 2015/10/6 6:43, Jaegeuk Kim wrote: > > This patch introduces a tracepoint to monitor background gc behaviors. > > > > Signed-off-by: Jaegeuk Kim > > --- > > fs/f2fs/gc.c | 3 +++ > > include/trace/events/f2fs.h | 28 ++++++++++++++++++++++++++++ > > 2 files changed, 31 insertions(+) > > > > diff --git a/fs/f2fs/gc.c b/fs/f2fs/gc.c > > index e627c19..e7cec86 100644 > > --- a/fs/f2fs/gc.c > > +++ b/fs/f2fs/gc.c > > @@ -77,6 +77,9 @@ static int gc_thread_func(void *data) > > > > stat_inc_bggc_count(sbi); > > > > + trace_f2fs_background_gc(sbi->sb, wait_ms, > > + prefree_segments(sbi), free_segments(sbi)); > > + > > /* if return value is not zero, no victim was selected */ > > if (f2fs_gc(sbi, test_opt(sbi, FORCE_FG_GC))) > > wait_ms = gc_th->no_gc_sleep_time; > > diff --git a/include/trace/events/f2fs.h b/include/trace/events/f2fs.h > > index 6aa63d9..7de751d 100644 > > --- a/include/trace/events/f2fs.h > > +++ b/include/trace/events/f2fs.h > > @@ -514,6 +514,34 @@ TRACE_EVENT(f2fs_map_blocks, > > __entry->ret) > > ); > > > > +TRACE_EVENT(f2fs_background_gc, > > + > > + TP_PROTO(struct super_block *sb, long wait_ms, > > + unsigned int prefree, unsigned int free), > > + > > + TP_ARGS(sb, wait_ms, prefree, free), > > + > > + TP_STRUCT__entry( > > + __field(dev_t, dev) > > + __field(long, wait_ms) > > + __field(unsigned int, prefree) > > + __field(unsigned int, free) > > + ), > > + > > + TP_fast_assign( > > + __entry->dev = sb->s_dev; > > + __entry->wait_ms = wait_ms; > > + __entry->prefree = prefree; > > + __entry->free = free; > > + ), > > + > > + TP_printk("dev = (%d,%d), wait_ms = %ld, prefree = %u, free = %u", > > + show_dev(__entry), > > + __entry->wait_ms, > > + __entry->prefree, > > + __entry->free) > > +); > > + > hi, > I open f2fs_background_gc and f2fs_get_victim trace points, first, the partition has no dirty segment, so no victim is > selected, wait_ms is equal to 300s. > > f2fs_gc-8:33-2827 [001] .... 5014.608396: f2fs_background_gc: dev = (8,33), wait_ms = 300000, prefree = 0, free = 73 > f2fs_gc-8:33-2827 [000] .... 5314.793436: f2fs_background_gc: dev = (8,33), wait_ms = 300000, prefree = 0, free = 73 > > then I made the partition satisfied the condition of has_enough_invalid_blocks, gc can get a victim and do garbage collection, wait_ms = 30s > > f2fs_gc-8:33-2827 [001] .... 5614.978486: f2fs_background_gc: dev = (8,33), wait_ms = 30000, prefree = 0, free = 54 > f2fs_gc-8:33-2827 [001] .... 5614.978538: f2fs_get_victim: dev = (8,33), type = No TYPE, policy = (Background GC, LFS-mode, Cost-Benefit), victim = 441 ofs_unit = 1, pre_victim_secno = -1, prefree = 0, free = 54 > f2fs_gc-8:33-2827 [000] .... 5644.996989: f2fs_background_gc: dev = (8,33), wait_ms = 30000, prefree = 0, free = 54 > f2fs_gc-8:33-2827 [000] .... 5644.997027: f2fs_get_victim: dev = (8,33), type = No TYPE, policy = (Background GC, LFS-mode, Cost-Benefit), victim = 97 ofs_unit = 1, pre_victim_secno = -1, prefree = 0, free = 54 > > when there no dirty segments left, I think wait_ms could turn back to 300s > > f2fs_gc-8:33-2827 [000] .... 6305.596205: f2fs_background_gc: dev = (8,33), wait_ms = 30000, prefree = 1, free = 64 > f2fs_gc-8:33-2827 [001] .... 6605.781281: f2fs_background_gc: dev = (8,33), wait_ms = 30000, prefree = 0, free = 65 > f2fs_gc-8:33-2827 [000] .... 6905.966301: f2fs_background_gc: dev = (8,33), wait_ms = 30000, prefree = 0, free = 65 > f2fs_gc-8:33-2827 [001] .... 7206.151344: f2fs_background_gc: dev = (8,33), wait_ms = 30000, prefree = 0, free = 65 > > here, background gc triggers every 300s, but wait_ms is still 30s, I don't know why? Oh, it's due to the tracepoint timing. In gc_thread_func(), do { wait with wait_ms = 300s decrease_sleep_time(&wait_ms); -> wait_ms = 30s tracepoint with wait_ms = 30s after f2fs_gc() call, wait_ms becomes 300s again. } So, this patch should fix that. From 84e4214f0868ae77771837d0ed4cc6eff10738ba Mon Sep 17 00:00:00 2001 From: Jaegeuk Kim Date: Tue, 13 Oct 2015 10:00:53 -0700 Subject: [PATCH] f2fs: relocate the tracepoint for background_gc Once f2fs_gc is done, wait_ms is changed once more. So, its tracepoint would be located after it. Reported-by: He YunLei Signed-off-by: Jaegeuk Kim --- fs/f2fs/gc.c | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/fs/f2fs/gc.c b/fs/f2fs/gc.c index af7c24c..fedbf67 100644 --- a/fs/f2fs/gc.c +++ b/fs/f2fs/gc.c @@ -77,13 +77,13 @@ static int gc_thread_func(void *data) stat_inc_bggc_count(sbi); - trace_f2fs_background_gc(sbi->sb, wait_ms, - prefree_segments(sbi), free_segments(sbi)); - /* if return value is not zero, no victim was selected */ if (f2fs_gc(sbi, test_opt(sbi, FORCE_FG_GC))) wait_ms = gc_th->no_gc_sleep_time; + trace_f2fs_background_gc(sbi->sb, wait_ms, + prefree_segments(sbi), free_segments(sbi)); + /* balancing f2fs's metadata periodically */ f2fs_balance_fs_bg(sbi);