From patchwork Sat Aug 4 10:32:25 2018 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Steve French X-Patchwork-Id: 10555665 Return-Path: Received: from mail.wl.linuxfoundation.org (pdx-wl-mail.web.codeaurora.org [172.30.200.125]) by pdx-korg-patchwork-2.web.codeaurora.org (Postfix) with ESMTP id BCBA114E2 for ; Sat, 4 Aug 2018 10:32:41 +0000 (UTC) Received: from mail.wl.linuxfoundation.org (localhost [127.0.0.1]) by mail.wl.linuxfoundation.org (Postfix) with ESMTP id A93AE2A13F for ; Sat, 4 Aug 2018 10:32:41 +0000 (UTC) Received: by mail.wl.linuxfoundation.org (Postfix, from userid 486) id 9D4E42A167; Sat, 4 Aug 2018 10:32:41 +0000 (UTC) X-Spam-Checker-Version: SpamAssassin 3.3.1 (2010-03-16) on pdx-wl-mail.web.codeaurora.org X-Spam-Level: X-Spam-Status: No, score=-7.8 required=2.0 tests=BAYES_00,DKIM_ADSP_CUSTOM_MED, DKIM_SIGNED,FREEMAIL_FROM,MAILING_LIST_MULTI,RCVD_IN_DNSWL_HI,T_DKIM_INVALID, T_TVD_MIME_EPI autolearn=ham version=3.3.1 Received: from vger.kernel.org (vger.kernel.org [209.132.180.67]) by mail.wl.linuxfoundation.org (Postfix) with ESMTP id 898632A13F for ; Sat, 4 Aug 2018 10:32:39 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1726744AbeHDMcx (ORCPT ); Sat, 4 Aug 2018 08:32:53 -0400 Received: from mail-pl0-f68.google.com ([209.85.160.68]:44483 "EHLO mail-pl0-f68.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1726576AbeHDMcx (ORCPT ); Sat, 4 Aug 2018 08:32:53 -0400 Received: by mail-pl0-f68.google.com with SMTP id ba4-v6so3638690plb.11 for ; Sat, 04 Aug 2018 03:32:37 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20161025; h=mime-version:from:date:message-id:subject:to; bh=NApMa7kPb5UqwSvGyTShM7VPQ/fl/LdMLBu1g8wyQU8=; b=O/+TCZWCq+eSjVwg/UwUt09gyAVxYtLNobS81RTu1ij9HlqpwrIbCqjhd6i4DvYnkD Sfpnf5pU/z9v9CG0OWNroeyWSOHwUK5wUfBlKmSCMEFDqDz6o/zZMFuj2DqiDJB99KKY Jh9D7BmjjUzNGSe20s5DCLwMeJb2Bnkmx5TkB2wtppRyy3DIqcWfPpe0oEa+6i2Q7z65 +WlAadrhrRSuN8fBp9PGVRNkxcEAhpVhOrm6TSFO0Kl3057IzrFwNB+5ccB9+cPgwaAm 6J8+GPbdd3jqVHtw/LYc4Q2B7CK9A232aZnd3RS4HeV8BVnHNfPuX0ahtaoNE7Sk0o2o V3+w== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:mime-version:from:date:message-id:subject:to; bh=NApMa7kPb5UqwSvGyTShM7VPQ/fl/LdMLBu1g8wyQU8=; b=HyZmyTptU9+/7HjP06BQvvgL+v33X13aU0JvozzaRJ8q5koXtEoJwOIwSXg7XsXK+Y Bu4mhgVe3E0m6sSQ9yH9/2/unaLhaU9YhIIpl0kdAV5QSfyTeAqsPvHJzY6DuscVbvxF y/HQfEOFre21uJWfyGMkv1Mwt2/st0CbE+b+G9MEHB2EnsCnZCfZGTyCkEhcNFhxnNu0 FWwkAuktNhKDYZgH15xfKS0g60VegmYhauZ9BbdreNSUcQVhF98GMi6ZHYf5+m/U7jLJ 72fWPHZoYHtWR2az4a+0VkGHA9FsAVndQtMlgnR5XrzkCCswOUkqFP8+OeHa1Y1LjXhy jjMA== X-Gm-Message-State: AOUpUlFrz/7DYWqcc3pBrHhMyWfhcMnkilFqxlq5SFiOJTlraoLLEoSa YHMDp6soSw/22bNf7OCIsewSCAxfdYYw6y4tWiNbD2En X-Google-Smtp-Source: AAOMgpfc1M1aVwwtqkxLPtKJyCL2PpSwF6nqlItDYW3nMOGnjIk65PGZKdoyObV6G7eRsnBF1Iazm0/TViLE7V/Z8v4= X-Received: by 2002:a17:902:b708:: with SMTP id d8-v6mr6913825pls.184.1533378757040; Sat, 04 Aug 2018 03:32:37 -0700 (PDT) MIME-Version: 1.0 From: Steve French Date: Sat, 4 Aug 2018 05:32:25 -0500 Message-ID: Subject: [PATCH][SMB3] display stats counters for number of slow commands To: CIFS , samba-technical Sender: linux-cifs-owner@vger.kernel.org Precedence: bulk List-ID: X-Mailing-List: linux-cifs@vger.kernel.org X-Virus-Scanned: ClamAV using ClamSMTP When CONFIG_CIFS_STATS2 is enabled keep counters for slow commands (ie server took longer than 1 second to respond) by SMB2/SMB3 command code. This can help in diagnosing whether performance problems are on server (instead of client) and which commands are causing the problem. Sample output (the new lines contain words "slow responses ...") $ cat /proc/fs/cifs/Stats Resources in use CIFS Session: 1 Share (unique mount targets): 2 SMB Request/Response Buffer: 1 Pool size: 5 SMB Small Req/Resp Buffer: 1 Pool size: 30 Total Large 10 Small 490 Allocations Operations (MIDs): 0 0 session 0 share reconnects Total vfs operations: 67 maximum at one time: 2 4 slow responses from localhost for command 5 1 slow responses from localhost for command 6 1 slow responses from localhost for command 14 1 slow responses from localhost for command 16 1) \\localhost\test SMBs: 243 Bytes read: 1024000 Bytes written: 104857600 TreeConnects: 1 total 0 failed TreeDisconnects: 0 total 0 failed Creates: 40 total 0 failed Closes: 39 total 0 failed ... Signed-off-by: Steve French Reviewed-by: Aurelien Aptel Reviewed-by: Pavel Shilovsky Signed-off-by: Steve French --- fs/cifs/cifs_debug.c | 19 +++++++++++++++++-- fs/cifs/cifsglob.h | 3 ++- fs/cifs/transport.c | 5 +++++ 3 files changed, 24 insertions(+), 3 deletions(-) From 3d27dcac7a44cb22b8f75ba18fef9bfc88e506b4 Mon Sep 17 00:00:00 2001 From: Steve French Date: Sat, 4 Aug 2018 05:24:34 -0500 Subject: [PATCH] smb3: display stats counters for number of slow commands When CONFIG_CIFS_STATS2 is enabled keep counters for slow commands (ie server took longer than 1 second to respond) by SMB2/SMB3 command code. This can help in diagnosing whether performance problems are on server (instead of client) and which commands are causing the problem. Sample output (the new lines contain words "slow responses ...") $ cat /proc/fs/cifs/Stats Resources in use CIFS Session: 1 Share (unique mount targets): 2 SMB Request/Response Buffer: 1 Pool size: 5 SMB Small Req/Resp Buffer: 1 Pool size: 30 Total Large 10 Small 490 Allocations Operations (MIDs): 0 0 session 0 share reconnects Total vfs operations: 67 maximum at one time: 2 4 slow responses from localhost for command 5 1 slow responses from localhost for command 6 1 slow responses from localhost for command 14 1 slow responses from localhost for command 16 1) \\localhost\test SMBs: 243 Bytes read: 1024000 Bytes written: 104857600 TreeConnects: 1 total 0 failed TreeDisconnects: 0 total 0 failed Creates: 40 total 0 failed Closes: 39 total 0 failed ... Signed-off-by: Steve French --- fs/cifs/cifs_debug.c | 19 +++++++++++++++++-- fs/cifs/cifsglob.h | 3 ++- fs/cifs/transport.c | 5 +++++ 3 files changed, 24 insertions(+), 3 deletions(-) diff --git a/fs/cifs/cifs_debug.c b/fs/cifs/cifs_debug.c index 748cabd6d20b..f1fbea947fef 100644 --- a/fs/cifs/cifs_debug.c +++ b/fs/cifs/cifs_debug.c @@ -378,6 +378,8 @@ static ssize_t cifs_stats_proc_write(struct file *file, rc = kstrtobool_from_user(buffer, count, &bv); if (rc == 0) { #ifdef CONFIG_CIFS_STATS2 + int i; + atomic_set(&totBufAllocCount, 0); atomic_set(&totSmBufAllocCount, 0); #endif /* CONFIG_CIFS_STATS2 */ @@ -389,6 +391,10 @@ static ssize_t cifs_stats_proc_write(struct file *file, list_for_each(tmp1, &cifs_tcp_ses_list) { server = list_entry(tmp1, struct TCP_Server_Info, tcp_ses_list); +#ifdef CONFIG_CIFS_STATS2 + for (i = 0; i < NUMBER_OF_SMB2_COMMANDS; i++) + atomic_set(&server->smb2slowcmd[i], 0); +#endif /* CONFIG_CIFS_STATS2 */ list_for_each(tmp2, &server->smb_ses_list) { ses = list_entry(tmp2, struct cifs_ses, smb_ses_list); @@ -417,13 +423,15 @@ static ssize_t cifs_stats_proc_write(struct file *file, static int cifs_stats_proc_show(struct seq_file *m, void *v) { int i; +#ifdef CONFIG_CIFS_STATS2 + int j; +#endif /* STATS2 */ struct list_head *tmp1, *tmp2, *tmp3; struct TCP_Server_Info *server; struct cifs_ses *ses; struct cifs_tcon *tcon; - seq_printf(m, - "Resources in use\nCIFS Session: %d\n", + seq_printf(m, "Resources in use\nCIFS Session: %d\n", sesInfoAllocCount.counter); seq_printf(m, "Share (unique mount targets): %d\n", tconInfoAllocCount.counter); @@ -452,6 +460,13 @@ static int cifs_stats_proc_show(struct seq_file *m, void *v) list_for_each(tmp1, &cifs_tcp_ses_list) { server = list_entry(tmp1, struct TCP_Server_Info, tcp_ses_list); +#ifdef CONFIG_CIFS_STATS2 + for (j = 0; j < NUMBER_OF_SMB2_COMMANDS; j++) + if (atomic_read(&server->smb2slowcmd[j])) + seq_printf(m, "%d slow responses from %s for command %d\n", + atomic_read(&server->smb2slowcmd[j]), + server->hostname, j); +#endif /* STATS2 */ list_for_each(tmp2, &server->smb_ses_list) { ses = list_entry(tmp2, struct cifs_ses, smb_ses_list); diff --git a/fs/cifs/cifsglob.h b/fs/cifs/cifsglob.h index 0553929e8339..41803d374da0 100644 --- a/fs/cifs/cifsglob.h +++ b/fs/cifs/cifsglob.h @@ -680,7 +680,8 @@ struct TCP_Server_Info { #ifdef CONFIG_CIFS_STATS2 atomic_t in_send; /* requests trying to send */ atomic_t num_waiters; /* blocked waiting to get in sendrecv */ -#endif + atomic_t smb2slowcmd[NUMBER_OF_SMB2_COMMANDS]; /* count resps > 1 sec */ +#endif /* STATS2 */ unsigned int max_read; unsigned int max_write; __le16 cipher_type; diff --git a/fs/cifs/transport.c b/fs/cifs/transport.c index 92de5c528161..c53c0908d4c6 100644 --- a/fs/cifs/transport.c +++ b/fs/cifs/transport.c @@ -117,6 +117,11 @@ DeleteMidQEntry(struct mid_q_entry *midEntry) something is wrong, unless it is quite a slow link or server */ if (time_after(now, midEntry->when_alloc + HZ) && (midEntry->command != command)) { + /* smb2slowcmd[NUMBER_OF_SMB2_COMMANDS] counts by command */ + if ((le16_to_cpu(midEntry->command) < NUMBER_OF_SMB2_COMMANDS) && + (le16_to_cpu(midEntry->command) >= 0)) + cifs_stats_inc(&midEntry->server->smb2slowcmd[le16_to_cpu(midEntry->command)]); + trace_smb3_slow_rsp(le16_to_cpu(midEntry->command), midEntry->mid, midEntry->pid, midEntry->when_sent, midEntry->when_received); -- 2.17.1