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=-9.7 required=3.0 tests=HEADER_FROM_DIFFERENT_DOMAINS, INCLUDES_PATCH,MAILING_LIST_MULTI,SIGNED_OFF_BY,SPF_HELO_NONE,SPF_PASS, UNPARSEABLE_RELAY,USER_AGENT_GIT 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 34F00C3A59E for ; Mon, 2 Sep 2019 14:56:09 +0000 (UTC) Received: from vger.kernel.org (vger.kernel.org [209.132.180.67]) by mail.kernel.org (Postfix) with ESMTP id 0C31E2173E for ; Mon, 2 Sep 2019 14:56:09 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1731731AbfIBO4I (ORCPT ); Mon, 2 Sep 2019 10:56:08 -0400 Received: from out30-57.freemail.mail.aliyun.com ([115.124.30.57]:46049 "EHLO out30-57.freemail.mail.aliyun.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1731676AbfIBO4I (ORCPT ); Mon, 2 Sep 2019 10:56:08 -0400 X-Alimail-AntiSpam: AC=PASS;BC=-1|-1;BR=01201311R371e4;CH=green;DM=||false|;FP=0|-1|-1|-1|0|-1|-1|-1;HT=e01e04400;MF=xiaoguang.wang@linux.alibaba.com;NM=1;PH=DS;RN=2;SR=0;TI=SMTPD_---0TbBQeIs_1567436137; Received: from localhost(mailfrom:xiaoguang.wang@linux.alibaba.com fp:SMTPD_---0TbBQeIs_1567436137) by smtp.aliyun-inc.com(127.0.0.1); Mon, 02 Sep 2019 22:55:40 +0800 From: Xiaoguang Wang To: linux-ext4@vger.kernel.org Cc: Xiaoguang Wang Subject: [PATCH 1/2] jbd2: add new tracepoint jbd2_sleep_on_shadow Date: Mon, 2 Sep 2019 22:54:41 +0800 Message-Id: <20190902145442.1921-1-xiaoguang.wang@linux.alibaba.com> X-Mailer: git-send-email 2.17.2 Sender: linux-ext4-owner@vger.kernel.org Precedence: bulk List-ID: X-Mailing-List: linux-ext4@vger.kernel.org Sometimes process will be stalled in "wait_on_bit_io(&bh->b_state, BH_Shadow, TASK_UNINTERRUPTIBLE)" for a while, and in order to analyse app's latency thoroughly, add a new tracepoint to track this delay. Trace info likes below: fsstress-5068 [008] .... 11007.757543: jbd2_sleep_on_shadow: dev 254,17 sleep 1 fsstress-5070 [007] .... 11007.757544: jbd2_sleep_on_shadow: dev 254,17 sleep 2 fsstress-5069 [009] .... 11007.757548: jbd2_sleep_on_shadow: dev 254,17 sleep 2 fsstress-5067 [011] .... 11007.757569: jbd2_sleep_on_shadow: dev 254,17 sleep 1 fsstress-5063 [007] .... 11007.757651: jbd2_sleep_on_shadow: dev 254,17 sleep 2 fsstress-5070 [007] .... 11007.757792: jbd2_sleep_on_shadow: dev 254,17 sleep 0 fsstress-5071 [011] .... 11007.763493: jbd2_sleep_on_shadow: dev 254,17 sleep 1 Signed-off-by: Xiaoguang Wang --- fs/jbd2/transaction.c | 3 +++ include/trace/events/jbd2.h | 21 +++++++++++++++++++++ 2 files changed, 24 insertions(+) diff --git a/fs/jbd2/transaction.c b/fs/jbd2/transaction.c index 990e7b5062e7..84974fb9d4f9 100644 --- a/fs/jbd2/transaction.c +++ b/fs/jbd2/transaction.c @@ -991,7 +991,10 @@ do_get_write_access(handle_t *handle, struct journal_head *jh, if (buffer_shadow(bh)) { JBUFFER_TRACE(jh, "on shadow: sleep"); jbd_unlock_bh_state(bh); + start_lock = jiffies; wait_on_bit_io(&bh->b_state, BH_Shadow, TASK_UNINTERRUPTIBLE); + trace_jbd2_sleep_on_shadow(bh->b_bdev->bd_dev, + jiffies_to_msecs(jiffies - start_lock)); goto repeat; } diff --git a/include/trace/events/jbd2.h b/include/trace/events/jbd2.h index 2310b259329f..2f048fdb63c6 100644 --- a/include/trace/events/jbd2.h +++ b/include/trace/events/jbd2.h @@ -380,6 +380,27 @@ TRACE_EVENT(jbd2_lock_buffer_stall, __entry->stall_ms) ); +TRACE_EVENT(jbd2_sleep_on_shadow, + + TP_PROTO(dev_t dev, unsigned long stall_ms), + + TP_ARGS(dev, stall_ms), + + TP_STRUCT__entry( + __field( dev_t, dev ) + __field(unsigned long, stall_ms ) + ), + + TP_fast_assign( + __entry->dev = dev; + __entry->stall_ms = stall_ms; + ), + + TP_printk("dev %d,%d sleep %lu", + MAJOR(__entry->dev), MINOR(__entry->dev), + __entry->stall_ms) +); + #endif /* _TRACE_JBD2_H */ /* This part must be outside protection */ -- 2.17.2