From patchwork Thu Apr 3 13:05:09 2025 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Bernd Schubert X-Patchwork-Id: 14036729 Received: from outbound-ip191a.ess.barracuda.com (outbound-ip191a.ess.barracuda.com [209.222.82.58]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by smtp.subspace.kernel.org (Postfix) with ESMTPS id 2EDEE24E001 for ; Thu, 3 Apr 2025 13:05:22 +0000 (UTC) Authentication-Results: smtp.subspace.kernel.org; arc=fail smtp.client-ip=209.222.82.58 ARC-Seal: i=2; a=rsa-sha256; d=subspace.kernel.org; s=arc-20240116; t=1743685528; cv=fail; b=pZQ8mbJVipClChfNjcwqOrOP7ms3vR5rQBtsU2kz9tdWU0hvM2JJJvUVzgKwS9F9WXwCC4Ukz5Mwz2v4/mKmHaCy1gEZrKBAZMF6Keon9T8uyaYRKTJVWLesN4j6146B6svKJZZLqLLp/wNiv9iUu+ivtnnxF+k5NcB4Z2kY0NQ= ARC-Message-Signature: i=2; a=rsa-sha256; d=subspace.kernel.org; s=arc-20240116; t=1743685528; c=relaxed/simple; bh=Dua8+hES0iXumoTTq1YQ89zt7sXm6RE3yEjmy3Dxfg8=; h=From:Date:Subject:MIME-Version:Content-Type:Message-Id:References: In-Reply-To:To:Cc; b=cphPSDMbFrQNBV633yLdrWSLdJwTzr7SMAbzM/yb0jlzZQwR8L4Fo7s4OjNB+RvrutapAo+u9eLDGDxRL0nOjRnh31CDPeATR4kSLG23m272cUwedbI94pnbQBGGkxd+VZ0iNpgviiGSIfViuWQtOJX8AnCF4Na6Hhi384p23kU= ARC-Authentication-Results: i=2; smtp.subspace.kernel.org; dmarc=pass (p=reject dis=none) header.from=ddn.com; spf=pass smtp.mailfrom=ddn.com; dkim=pass (1024-bit key) header.d=ddn.com header.i=@ddn.com header.b=sAJiiHJF; arc=fail smtp.client-ip=209.222.82.58 Authentication-Results: smtp.subspace.kernel.org; dmarc=pass (p=reject dis=none) header.from=ddn.com Authentication-Results: smtp.subspace.kernel.org; spf=pass smtp.mailfrom=ddn.com Authentication-Results: smtp.subspace.kernel.org; dkim=pass (1024-bit key) header.d=ddn.com header.i=@ddn.com header.b="sAJiiHJF" Received: from NAM12-DM6-obe.outbound.protection.outlook.com (mail-dm6nam12lp2169.outbound.protection.outlook.com [104.47.59.169]) by mx-outbound42-120.us-east-2c.ess.aws.cudaops.com (version=TLSv1.2 cipher=ECDHE-RSA-AES256-GCM-SHA384 bits=256 verify=NO); Thu, 03 Apr 2025 13:05:18 +0000 ARC-Seal: i=1; a=rsa-sha256; s=arcselector10001; d=microsoft.com; cv=none; b=ic3udTghpdm2ztZaWgVCRjezXyVHlFSB8gxChw8VJo+It3WW08pZ1DWamDSV/1+xoPukv3IDBKGma96PDd4grfVYfInpC6MckDGY0NNecLMibMeIG4RhI7d4hgVIXmeq+ExjwdhsXn0dnIzwWNY93z2zSf/D9mn+Png+/2w9a2GhbHQtAICbBA6gEJgD8lrF3uHC1sbjCfF8lFNGtaONQA0QZmoLBv/tGyg3SPKHAyO1zdALRVtefL99dCTP75J5gRpfZmvAXZtNquRKOJu9GFD5+cv/TRvKkHKhWudCzigC8Vx3gx0oe9aggEwAcwjCFtXUwbVWX84EwoWbnvHBcw== ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=microsoft.com; s=arcselector10001; h=From:Date:Subject:Message-ID:Content-Type:MIME-Version:X-MS-Exchange-AntiSpam-MessageData-ChunkCount:X-MS-Exchange-AntiSpam-MessageData-0:X-MS-Exchange-AntiSpam-MessageData-1; bh=906l0uz2nUjyJTIeUeXoSrOz5nvaEGy28z0fUxDyJ0M=; b=ZwwnQRaIVpdewaS59xzRi2Pmhhm1gedCD4LcdpZwadIDKnHgIvHZCx7Ezkoc3vjIq/EWar2rQ0YvMyeWp5Cd2q3G/ORaDcRFLRe1zmrRSBKu+X7soBL+C8IDOxEXZdDMmj6TCH8koiUZDI9hrqfOpEmLILmwCHBlZEh9x7GSrhUTK97Hamwwiww0becSrCwJ4FpH7DLZJGR/Z9JA1qjRwU0S9OEogsUMp1NzoK5mgW6Tm3N+KEIou1oDIvDckSW0nF0Y+MX6PDlIc4FOsaTbe3byrRh3rWcSnnhpKchW5yAIluB8DYIapIw0BzTvDIp8ubadbBvhwyjek6/tyWj6RQ== ARC-Authentication-Results: i=1; mx.microsoft.com 1; spf=pass (sender ip is 50.222.100.11) smtp.rcpttodomain=ddn.com smtp.mailfrom=ddn.com; dmarc=pass (p=reject sp=reject pct=100) action=none header.from=ddn.com; dkim=none (message not signed); arc=none (0) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=ddn.com; s=selector2; h=From:Date:Subject:Message-ID:Content-Type:MIME-Version:X-MS-Exchange-SenderADCheck; bh=906l0uz2nUjyJTIeUeXoSrOz5nvaEGy28z0fUxDyJ0M=; b=sAJiiHJFj0VIIy/OpgQEaSgFunKdsOpTQWFzqr3HXUN3Sc9dH2mzLoPir+N/qAd0bxm11gQ/yIVAcTHOJjQGaJYAqpmhoy9mlvBzbUlvMNeCyiIJ1gI8FZABhhB+eR0/pwAmuUDRtxv0chRwZwJy96r9cpqo744OcAydYfYV11E= Received: from BL0PR05CA0021.namprd05.prod.outlook.com (2603:10b6:208:91::31) by MW6PR19MB8084.namprd19.prod.outlook.com (2603:10b6:303:246::21) with Microsoft SMTP Server (version=TLS1_2, cipher=TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384) id 15.20.8534.44; Thu, 3 Apr 2025 13:05:17 +0000 Received: from BL6PEPF0001AB76.namprd02.prod.outlook.com (2603:10b6:208:91:cafe::12) by BL0PR05CA0021.outlook.office365.com (2603:10b6:208:91::31) with Microsoft SMTP Server (version=TLS1_3, cipher=TLS_AES_256_GCM_SHA384) id 15.20.8606.25 via Frontend Transport; Thu, 3 Apr 2025 13:05:16 +0000 X-MS-Exchange-Authentication-Results: spf=pass (sender IP is 50.222.100.11) smtp.mailfrom=ddn.com; dkim=none (message not signed) header.d=none;dmarc=pass action=none header.from=ddn.com; Received-SPF: Pass (protection.outlook.com: domain of ddn.com designates 50.222.100.11 as permitted sender) receiver=protection.outlook.com; client-ip=50.222.100.11; helo=uww-mrp-01.datadirectnet.com; pr=C Received: from uww-mrp-01.datadirectnet.com (50.222.100.11) by BL6PEPF0001AB76.mail.protection.outlook.com (10.167.242.169) with Microsoft SMTP Server (version=TLS1_3, cipher=TLS_AES_256_GCM_SHA384) id 15.20.8606.22 via Frontend Transport; Thu, 3 Apr 2025 13:05:15 +0000 Received: from localhost (unknown [10.68.0.8]) by uww-mrp-01.datadirectnet.com (Postfix) with ESMTP id 3A2954A; Thu, 3 Apr 2025 13:05:14 +0000 (UTC) From: Bernd Schubert Date: Thu, 03 Apr 2025 15:05:09 +0200 Subject: [PATCH v2 4/4] fuse: fine-grained request ftraces Precedence: bulk X-Mailing-List: linux-fsdevel@vger.kernel.org List-Id: List-Subscribe: List-Unsubscribe: MIME-Version: 1.0 Message-Id: <20250403-fuse-io-uring-trace-points-v2-4-bd04f2b22f91@ddn.com> References: <20250403-fuse-io-uring-trace-points-v2-0-bd04f2b22f91@ddn.com> In-Reply-To: <20250403-fuse-io-uring-trace-points-v2-0-bd04f2b22f91@ddn.com> To: Miklos Szeredi , Vivek Goyal , Stefan Hajnoczi , =?utf-8?q?Eugenio_P=C3=A9rez?= Cc: linux-fsdevel@vger.kernel.org, Joanne Koong , Josef Bacik , Bernd Schubert X-Mailer: b4 0.15-dev-2a633 X-Developer-Signature: v=1; a=ed25519-sha256; t=1743685510; l=4634; i=bschubert@ddn.com; s=20240529; h=from:subject:message-id; bh=Dua8+hES0iXumoTTq1YQ89zt7sXm6RE3yEjmy3Dxfg8=; b=JriWI+fPEFMOuKu0fjXj1yX+DRxu82y+JMciMRHOFaqseb/LKM9pEyohYvOdTa9HOMtBOgx4S gakp7VWxlzBBdWJXwcqqMFKBCp+sjC6K4HMCIq2jfopOmy3lNYtFn3M X-Developer-Key: i=bschubert@ddn.com; a=ed25519; pk=EZVU4bq64+flgoWFCVQoj0URAs3Urjno+1fIq9ZJx8Y= X-EOPAttributedMessage: 0 X-MS-PublicTrafficType: Email X-MS-TrafficTypeDiagnostic: BL6PEPF0001AB76:EE_|MW6PR19MB8084:EE_ X-MS-Office365-Filtering-Correlation-Id: 506bbbe5-ac63-4036-621a-08dd72b02d59 X-MS-Exchange-SenderADCheck: 1 X-MS-Exchange-AntiSpam-Relay: 0 X-Microsoft-Antispam: BCL:0;ARA:13230040|36860700013|82310400026|376014|1800799024; X-Microsoft-Antispam-Message-Info: =?utf-8?q?nHJllqMin22639OBLt/jKVKHWP2rGJn?= =?utf-8?q?S0HxefOJ33+PCKNRc1eeVEc9I3Y6v/92WeXvPTow7lyakrJ3wyR9DJMnDxGuojI+9?= =?utf-8?q?xOSaQKUOWQinK3x+5MBSpCdEcNIRewm5bhmbMggYxv/A1Z7/WuEh2BeNH+w6kJ21/?= =?utf-8?q?DSmfY5KDqHEkWbgpU3axQEmAEA18Li2cM7Uu4FWPVlvk+PNJJtzvZGykmTwYIBAxO?= =?utf-8?q?Lhn/ndFXurDExaMcCEduWlfy7LweTHtdiK2R/sBLZMwyIEb9T+7h3zJrJs081Qd/V?= =?utf-8?q?0lLlqBqynn77/ni3z4VolXwZa+d70FlvPY+wdoa5djsnhhg82z9N/lvV9Ebe0LLF0?= =?utf-8?q?kWtmUZISTL1kDhXPDLiyLCCEieEMDF4h/5vysBVvPTEu5dm6zE5kB/ztY3Tc8OsYK?= =?utf-8?q?lswy3oKWwSk4tBQlmwCHBMftrFlOAUliP8P7oYAURuUZKFyo0p74ZprsrSGtLz80K?= =?utf-8?q?T/wLfLb3ZZHLYo+5MSuGaXU1/Lf30Fx5yEgMHk0Ro7NNC8qFSPdQSaM+jSe9PdHB8?= =?utf-8?q?Dglo6FNWbP+ng4KnKV0U0R/6kwzGu537HvvF7RyRC0BaDqYUh7yxwsY2AOUyynztL?= =?utf-8?q?RGz9mH9r7L+QYVC+i8/O4PiahbcJutrftTN61kImfVHqnHx0zO6IJ3oD5jksuthQ5?= =?utf-8?q?tfM9JZcOWn/rju3pvXYf/skuo5RcdcAvjQ538dEUtOQsAkqz07fSzTQTsWUKOYD3C?= =?utf-8?q?FJi4gA6kbX43Try47ns3cBimqU1HO3DYPQ3HCvNwodLvBQyiqB5ajEOAy/lpXrLB4?= =?utf-8?q?RBLncJdPxZLqqjRe4+j0aSVuZYwhj/3oTNBjiz5XfplmtRzSUXoRLPYyVlKiGGYE6?= =?utf-8?q?WJrrJILX+fp+mFBov6xiToUXbOfmZPse3Qeqt+yVyE1gVGE8FHaXndgURvZb1I8Id?= =?utf-8?q?d41wP3kYned9z8Kx5Eko9k9SEU/8Ls1iDp3ELEfm2Aarx4Yaa6Sxo3M3mJGZuJOpS?= =?utf-8?q?F50fVWbstfh4ve3ET7Q4a1hNXnuQX2UmhY9Ix/3tSs+LGgLajLyOLWtfHAXxIPRSz?= =?utf-8?q?+E+pDlBPF9awKUYw1EpTKBqRj+kVWJ2317/EnPTX7m2+phPDJRzTMd1KpXq45x+4S?= =?utf-8?q?MhrTyGguM3gc04LjWcwcp/GcpOP4PYpcQM2f3D9eXHdVUqfthiIZFXf7O2Wn1/kk5?= =?utf-8?q?gs2or+U347jAksiH04oB2p05N80/v1PFPOm+Dv8FDhNoyQyCcEcJF3xSLz/MW493R?= =?utf-8?q?9a/Q1Dn/txjKz5+nqrtoHsuLdFtFsYm7Tmov7G/mhP2B3HyXHUXONTFhcsrgmXnDk?= =?utf-8?q?uhiHzFZPoTdY38jKQfWn5zbg4A7NpnhtlYHZrkDAfEh4liE2/ZDoGBaEVpZ6o5/+8?= =?utf-8?q?ad9ejMgBT1cb9wBdIYYTyqrjcMbHZ//EbgF7+5OaHVZqqwCxxvpvz2Fmtz0P4hI2+?= =?utf-8?q?Lh8a3EHPKfXiwct+R30m5F7bqoCMv/bhnDZbXXvdzK+Zpww9Ck4EC4=3D?= X-Forefront-Antispam-Report: CIP:50.222.100.11;CTRY:US;LANG:en;SCL:1;SRV:;IPV:NLI;SFV:NSPM;H:uww-mrp-01.datadirectnet.com;PTR:InfoDomainNonexistent;CAT:NONE;SFS:(13230040)(36860700013)(82310400026)(376014)(1800799024);DIR:OUT;SFP:1102; X-MS-Exchange-AntiSpam-ExternalHop-MessageData-ChunkCount: 1 X-MS-Exchange-AntiSpam-ExternalHop-MessageData-0: LemZRmT5IUGQWfpAsxYKVW6LAzRMaCTjSRXd7h/wyQnd7sbwL2ROHcTJNLC4REpu94C4VF740NYlA6iCq/htanl+rmfOFK8UjPgLRt1kpSgbS5Sb3u32ND2I7UkoxSfXLXNtXzDX9jIlL5lbc2P26/0nJJs9O9UMBR5RLEtW6WA2WHauiVpErqkLqhKXKIACnWY7uM7h24WGpmc1xlaVkrUVSiPk/0picgWfaSXs8GPd/ik3D+bmjU+LO6MzQMxjApzKgJ7+qSpA+u1NpLEssSjqC5e234MLt7f86H3euwOwEIeo7ml3FYnNHEe+zX6s7q6U02dDTHca/Lqvdzz2bRso2sBZI2sUjeZqPeBSClTfyXEzFfwCZ7p6KO6tD+xF1J9DORsxpuh4vrEcbMFS3C/3uiUo+mAaNGUrL+Ohta32X3wYXhzpUkWvGeAOoCBaEBi/RbBkdQExRXzzkUyAvjVGOqctFhNlw5xwneJtKJX1gUJekDV9GvWJU3zq7kZ/3aKNB0u7K5iQB73cffAo90YZklms0dvmPqtqb1c5AJgxbl8b1EIzMBbvHE4CeIhSXdr2LOHFlhw6pTE88cfMr9ZB9YhvgZmsG1meLMQijWFsQrwLcCmS0XPlKs/Rh7y+zoscxqbtxnFhfzV5FyVmyQ== X-OriginatorOrg: ddn.com X-MS-Exchange-CrossTenant-OriginalArrivalTime: 03 Apr 2025 13:05:15.4621 (UTC) X-MS-Exchange-CrossTenant-Network-Message-Id: 506bbbe5-ac63-4036-621a-08dd72b02d59 X-MS-Exchange-CrossTenant-Id: 753b6e26-6fd3-43e6-8248-3f1735d59bb4 X-MS-Exchange-CrossTenant-OriginalAttributedTenantConnectingIp: TenantId=753b6e26-6fd3-43e6-8248-3f1735d59bb4;Ip=[50.222.100.11];Helo=[uww-mrp-01.datadirectnet.com] X-MS-Exchange-CrossTenant-AuthSource: BL6PEPF0001AB76.namprd02.prod.outlook.com X-MS-Exchange-CrossTenant-AuthAs: Anonymous X-MS-Exchange-CrossTenant-FromEntityHeader: HybridOnPrem X-MS-Exchange-Transport-CrossTenantHeadersStamped: MW6PR19MB8084 X-BESS-ID: 1743685518-110872-10170-13523-1 X-BESS-VER: 2019.1_20250402.1544 X-BESS-Apparent-Source-IP: 104.47.59.169 X-BESS-Parts: H4sIAAAAAAACA4uuVkqtKFGyUioBkjpK+cVKViYmFpZAVgZQMMUoLdnczDAxJd EiydDA0MjcNMUo0Tw52cDYOMnAOClZqTYWAAQQG+xBAAAA X-BESS-Outbound-Spam-Score: 0.50 X-BESS-Outbound-Spam-Report: Code version 3.2, rules version 3.2.2.263622 [from cloudscan19-234.us-east-2b.ess.aws.cudaops.com] Rule breakdown below pts rule name description ---- ---------------------- -------------------------------- 0.50 BSF_RULE7568M META: Custom Rule 7568M 0.00 BSF_BESS_OUTBOUND META: BESS Outbound X-BESS-Outbound-Spam-Status: SCORE=0.50 using account:ESS124931 scores of KILL_LEVEL=7.0 tests=BSF_RULE7568M, BSF_BESS_OUTBOUND X-BESS-BRTS-Status: 1 Rename trace_fuse_request_send to trace_fuse_request_enqueue Add trace_fuse_request_send Add trace_fuse_request_bg_enqueue Add trace_fuse_request_enqueue This helps to track entire request time and time in different queues. Signed-off-by: Bernd Schubert --- fs/fuse/dev.c | 7 ++++++- fs/fuse/dev_uring.c | 2 ++ fs/fuse/fuse_trace.h | 57 +++++++++++++++++++++++++++++++++++++--------------- 3 files changed, 49 insertions(+), 17 deletions(-) diff --git a/fs/fuse/dev.c b/fs/fuse/dev.c index 1ccf5a9c61ae2b11bc1d0b799c08e6da908a9782..8e1a95f80e5454d1351ecb90beacbb35779731bb 100644 --- a/fs/fuse/dev.c +++ b/fs/fuse/dev.c @@ -281,7 +281,9 @@ static void fuse_send_one(struct fuse_iqueue *fiq, struct fuse_req *req) req->in.h.len = sizeof(struct fuse_in_header) + fuse_len_args(req->args->in_numargs, (struct fuse_arg *) req->args->in_args); - trace_fuse_request_send(req); + + /* enqueue, as it is send to "fiq->ops queue" */ + trace_fuse_request_enqueue(req); fiq->ops->send_req(fiq, req); } @@ -580,6 +582,8 @@ static int fuse_request_queue_background(struct fuse_req *req) } __set_bit(FR_ISREPLY, &req->flags); + trace_fuse_request_bg_enqueue(req); + #ifdef CONFIG_FUSE_IO_URING if (fuse_uring_ready(fc)) return fuse_request_queue_background_uring(fc, req); @@ -1314,6 +1318,7 @@ static ssize_t fuse_dev_do_read(struct fuse_dev *fud, struct file *file, clear_bit(FR_PENDING, &req->flags); list_del_init(&req->list); spin_unlock(&fiq->lock); + trace_fuse_request_send(req); args = req->args; reqsize = req->in.h.len; diff --git a/fs/fuse/dev_uring.c b/fs/fuse/dev_uring.c index c5cb2aea75af523e22f539c8e18cfd0d6e771ffc..e5ed146b990e12c6cc2a18aaa9b527c276870aba 100644 --- a/fs/fuse/dev_uring.c +++ b/fs/fuse/dev_uring.c @@ -7,6 +7,7 @@ #include "fuse_i.h" #include "dev_uring_i.h" #include "fuse_dev_i.h" +#include "fuse_trace.h" #include #include @@ -678,6 +679,7 @@ static void fuse_uring_send(struct fuse_ring_ent *ent, struct io_uring_cmd *cmd, ent->cmd = NULL; spin_unlock(&queue->lock); + trace_fuse_request_send(ent->fuse_req); io_uring_cmd_done(cmd, ret, 0, issue_flags); } diff --git a/fs/fuse/fuse_trace.h b/fs/fuse/fuse_trace.h index bbe9ddd8c71696ddcbca055f6c4c451661bb4444..393c630e7726356da16add7da4b5913b9f725b25 100644 --- a/fs/fuse/fuse_trace.h +++ b/fs/fuse/fuse_trace.h @@ -77,30 +77,55 @@ OPCODES #define EM(a, b) {a, b}, #define EMe(a, b) {a, b} -TRACE_EVENT(fuse_request_send, +#define FUSE_REQ_TRACE_FIELDS \ + __field(dev_t, connection) \ + __field(uint64_t, unique) \ + __field(enum fuse_opcode, opcode) \ + __field(uint32_t, len) \ + +#define FUSE_REQ_TRACE_ASSIGN(req) \ + do { \ + __entry->connection = req->fm->fc->dev; \ + __entry->unique = req->in.h.unique; \ + __entry->opcode = req->in.h.opcode; \ + __entry->len = req->in.h.len; \ + } while (0) + + +TRACE_EVENT(fuse_request_enqueue, TP_PROTO(const struct fuse_req *req), - TP_ARGS(req), - - TP_STRUCT__entry( - __field(dev_t, connection) - __field(uint64_t, unique) - __field(enum fuse_opcode, opcode) - __field(uint32_t, len) - ), - - TP_fast_assign( - __entry->connection = req->fm->fc->dev; - __entry->unique = req->in.h.unique; - __entry->opcode = req->in.h.opcode; - __entry->len = req->in.h.len; - ), + TP_STRUCT__entry(FUSE_REQ_TRACE_FIELDS), + TP_fast_assign(FUSE_REQ_TRACE_ASSIGN(req)), TP_printk("connection %u req %llu opcode %u (%s) len %u ", __entry->connection, __entry->unique, __entry->opcode, __print_symbolic(__entry->opcode, OPCODES), __entry->len) ); +TRACE_EVENT(fuse_request_bg_enqueue, + TP_PROTO(const struct fuse_req *req), + TP_ARGS(req), + TP_STRUCT__entry(FUSE_REQ_TRACE_FIELDS), + TP_fast_assign(FUSE_REQ_TRACE_ASSIGN(req)), + + TP_printk("connection %u req %llu opcode %u (%s) len %u ", + __entry->connection, __entry->unique, __entry->opcode, + __print_symbolic(__entry->opcode, OPCODES), __entry->len) +); + +TRACE_EVENT(fuse_request_send, + TP_PROTO(const struct fuse_req *req), + TP_ARGS(req), + TP_STRUCT__entry(FUSE_REQ_TRACE_FIELDS), + TP_fast_assign(FUSE_REQ_TRACE_ASSIGN(req)), + + TP_printk("connection %u req %llu opcode %u (%s) len %u ", + __entry->connection, __entry->unique, __entry->opcode, + __print_symbolic(__entry->opcode, OPCODES), __entry->len) +); + + TRACE_EVENT(fuse_request_end, TP_PROTO(const struct fuse_req *req),