From patchwork Sat May 19 07:31:44 2018 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Steve French X-Patchwork-Id: 916780 Return-Path: X-Original-To: incoming@patchwork.ozlabs.org Delivered-To: patchwork-incoming@bilbo.ozlabs.org Authentication-Results: ozlabs.org; spf=none (mailfrom) smtp.mailfrom=vger.kernel.org (client-ip=209.132.180.67; helo=vger.kernel.org; envelope-from=linux-cifs-owner@vger.kernel.org; receiver=) Authentication-Results: ozlabs.org; dmarc=fail (p=none dis=none) header.from=gmail.com Authentication-Results: ozlabs.org; dkim=fail reason="signature verification failed" (2048-bit key; unprotected) header.d=gmail.com header.i=@gmail.com header.b="IoQH/3AZ"; dkim-atps=neutral Received: from vger.kernel.org (vger.kernel.org [209.132.180.67]) by ozlabs.org (Postfix) with ESMTP id 40nxZH52kLz9s4w for ; Sat, 19 May 2018 17:32:07 +1000 (AEST) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1751117AbeESHcG (ORCPT ); Sat, 19 May 2018 03:32:06 -0400 Received: from mail-pl0-f52.google.com ([209.85.160.52]:38281 "EHLO mail-pl0-f52.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1751034AbeESHcF (ORCPT ); Sat, 19 May 2018 03:32:05 -0400 Received: by mail-pl0-f52.google.com with SMTP id c11-v6so5876992plr.5 for ; Sat, 19 May 2018 00:32:05 -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=Hh5Aa7vbjJuarP+/V+Eq7ttP6INXNMGjMiB9plxoxGE=; b=IoQH/3AZWO9RWG8lTsH2HbxSYuoSXQJJ5BgA7v2IhARCmq3eIFUVzeiHXjdBFCwtXV NSbl/gPuHvhjJvGs+Zw7H7GJupRhn+oXQU32gcxJHxs3YfoYIPIzsisZPBsRbL4Yuete e7ZvCrcNxu2BKy1oJy7ZW+/fFgl8ASyeR2AwoCsyL75Tw2e55EQaApEJwZfjmzRcHOhx OC2U2y5hCyzJ6EG5dHZBHY6ECxCtdErR1AbbxVoEbHNKgSVKZM9cG31RJUn0q0PJJy8w G99CTYA/4/Z9PUsgjnyS2CoRPScmamwYySpM7dJt8SZgU8kJ/1gm9Jp4DgcGislMpmQ6 k5eQ== 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=Hh5Aa7vbjJuarP+/V+Eq7ttP6INXNMGjMiB9plxoxGE=; b=ht6tyl9uoTq46XvnBq4gpni6bmiVq22OZUmysqf2MJ/O9PLI/MYt1YN4u//zdocNbj EOj/Naprx2xICaDJP0KdHCH2jBqa3hjuYDC5tUDt3lgJcbBConaAy+U/+c5grIZt6Euz pu0zfLZ7e0RbKLOTrdQe/Iu+wovjDr5MyPHHRrf7FeLX7sgEHmMIXXcnjxMpByF7jagr QZs7qdHudsF31anKWHi2ljLLxj+z4HwUlypjgcjgXV/IZ1dGo0n2cyt1gxitGEyqpOA4 KquFaW4bQiKMjCEGz0Yh8/vg3P7GFYnLld+S5I+Y01FhE5NA/0mmhK/uTBh5VCJXMVQd ZL/g== X-Gm-Message-State: ALKqPwfZibjZxqW+A8jqoVMRpkXU0FBDvWrlbjQZH7ruPUJK0/3WQf3g TAeM8SJg85tNmwpOgUR3VEuJI3/AxXwW+YOmHWc= X-Google-Smtp-Source: AB8JxZrVsX8rKzomA6Xd8oVTWcRdcpuxAr2vQvXnHWjxVDKvRM/7Bll+NJI7+shce1xoaVcgmwFO86FQKz5brBbYafQ= X-Received: by 2002:a17:902:778a:: with SMTP id o10-v6mr12674457pll.214.1526715124831; Sat, 19 May 2018 00:32:04 -0700 (PDT) MIME-Version: 1.0 Received: by 2002:a17:90a:bd8f:0:0:0:0 with HTTP; Sat, 19 May 2018 00:31:44 -0700 (PDT) From: Steve French Date: Sat, 19 May 2018 02:31:44 -0500 Message-ID: Subject: [PATCH[[SMB3] Add additional ftrace entry points for entry/exit to cifs.ko To: Pavel Shilovskiy , CIFS Sender: linux-cifs-owner@vger.kernel.org Precedence: bulk List-ID: X-Mailing-List: linux-cifs@vger.kernel.org Also fix formatting of a few debug calls (move pid to the right in the printout) From 49fe8ea130a821df90f3a5f616bc02feb2252392 Mon Sep 17 00:00:00 2001 From: Steve French Date: Sat, 19 May 2018 02:28:53 -0500 Subject: [PATCH] smb3: add additional ftrace entry points for entry/exit to cifs.ko Signed-off-by: Steve French --- fs/cifs/cifsproto.h | 8 +++- fs/cifs/smb2maperror.c | 9 ++-- fs/cifs/trace.h | 103 +++++++++++++++++++++++++++++------------ 3 files changed, 85 insertions(+), 35 deletions(-) diff --git a/fs/cifs/cifsproto.h b/fs/cifs/cifsproto.h index 6c4da5de1ab5..dc80f84b4b79 100644 --- a/fs/cifs/cifsproto.h +++ b/fs/cifs/cifsproto.h @@ -21,6 +21,7 @@ #ifndef _CIFSPROTO_H #define _CIFSPROTO_H #include +#include "trace.h" struct statfs; struct smb_vol; @@ -47,6 +48,7 @@ extern void _free_xid(unsigned int); cifs_dbg(FYI, "CIFS VFS: in %s as Xid: %u with uid: %d\n", \ __func__, __xid, \ from_kuid(&init_user_ns, current_fsuid())); \ + trace_smb3_enter(__xid, __func__); \ __xid; \ }) @@ -54,7 +56,11 @@ extern void _free_xid(unsigned int); do { \ _free_xid(curr_xid); \ cifs_dbg(FYI, "CIFS VFS: leaving %s (xid = %u) rc = %d\n", \ - __func__, curr_xid, (int)rc); \ + __func__, curr_xid, (int)rc); \ + if (rc) \ + trace_smb3_exit_err(curr_xid, __func__, (int)rc); \ + else \ + trace_smb3_exit_done(curr_xid, __func__); \ } while (0) extern int init_cifs_idmap(void); extern void exit_cifs_idmap(void); diff --git a/fs/cifs/smb2maperror.c b/fs/cifs/smb2maperror.c index 20185be4a93d..86f1acaa759b 100644 --- a/fs/cifs/smb2maperror.c +++ b/fs/cifs/smb2maperror.c @@ -2457,9 +2457,8 @@ map_smb2_to_linux_error(char *buf, bool log_err) __le32 smb2err = shdr->Status; if (smb2err == 0) { - trace_smb3_cmd_done(le32_to_cpu(shdr->ProcessId), shdr->TreeId, - shdr->SessionId, le16_to_cpu(shdr->Command), - le64_to_cpu(shdr->MessageId)); + trace_smb3_cmd_done(shdr->TreeId, shdr->SessionId, + le16_to_cpu(shdr->Command), le64_to_cpu(shdr->MessageId)); return 0; } @@ -2483,8 +2482,8 @@ map_smb2_to_linux_error(char *buf, bool log_err) cifs_dbg(FYI, "Mapping SMB2 status code 0x%08x to POSIX err %d\n", __le32_to_cpu(smb2err), rc); - trace_smb3_cmd_err(le32_to_cpu(shdr->ProcessId), shdr->TreeId, - shdr->SessionId, le16_to_cpu(shdr->Command), + trace_smb3_cmd_err(shdr->TreeId, shdr->SessionId, + le16_to_cpu(shdr->Command), le64_to_cpu(shdr->MessageId), le32_to_cpu(smb2err), rc); return rc; } diff --git a/fs/cifs/trace.h b/fs/cifs/trace.h index 935a58979e1b..9bba8e1b00ba 100644 --- a/fs/cifs/trace.h +++ b/fs/cifs/trace.h @@ -50,8 +50,8 @@ DECLARE_EVENT_CLASS(smb3_rw_err_class, __entry->len = len; __entry->rc = rc; ), - TP_printk("xid=%u fid=0x%llx tid=0x%x sid=0x%llx offset=0x%llx len=0x%x rc=%d", - __entry->xid, __entry->fid, __entry->tid, __entry->sesid, + TP_printk("\txid=%u sid=0x%llx tid=0x%x fid=0x%llx offset=0x%llx len=0x%x rc=%d", + __entry->xid, __entry->sesid, __entry->tid, __entry->fid, __entry->offset, __entry->len, __entry->rc) ) @@ -95,8 +95,8 @@ DECLARE_EVENT_CLASS(smb3_rw_done_class, __entry->offset = offset; __entry->len = len; ), - TP_printk("xid=%u fid=0x%llx tid=0x%x sid=0x%llx offset=0x%llx len=0x%x", - __entry->xid, __entry->fid, __entry->tid, __entry->sesid, + TP_printk("xid=%u sid=0x%llx tid=0x%x fid=0x%llx offset=0x%llx len=0x%x", + __entry->xid, __entry->sesid, __entry->tid, __entry->fid, __entry->offset, __entry->len) ) @@ -137,8 +137,8 @@ DECLARE_EVENT_CLASS(smb3_fd_err_class, __entry->sesid = sesid; __entry->rc = rc; ), - TP_printk("xid=%u fid=0x%llx tid=0x%x sid=0x%llx rc=%d", - __entry->xid, __entry->fid, __entry->tid, __entry->sesid, + TP_printk("\txid=%u sid=0x%llx tid=0x%x fid=0x%llx rc=%d", + __entry->xid, __entry->sesid, __entry->tid, __entry->fid, __entry->rc) ) @@ -185,8 +185,8 @@ DECLARE_EVENT_CLASS(smb3_inf_err_class, __entry->type = type; __entry->rc = rc; ), - TP_printk("xid=%u fid=0x%llx tid=0x%x sid=0x%llx class=%u type=0x%x rc=%d", - __entry->xid, __entry->fid, __entry->tid, __entry->sesid, + TP_printk("xid=%u sid=0x%llx tid=0x%x fid=0x%llx class=%u type=0x%x rc=%d", + __entry->xid, __entry->sesid, __entry->tid, __entry->fid, __entry->infclass, __entry->type, __entry->rc) ) @@ -209,16 +209,14 @@ DEFINE_SMB3_INF_ERR_EVENT(fsctl_err); * For logging SMB3 Status code and Command for responses which return errors */ DECLARE_EVENT_CLASS(smb3_cmd_err_class, - TP_PROTO(__u32 pid, - __u32 tid, + TP_PROTO(__u32 tid, __u64 sesid, __u16 cmd, __u64 mid, __u32 status, int rc), - TP_ARGS(pid, tid, sesid, cmd, mid, status, rc), + TP_ARGS(tid, sesid, cmd, mid, status, rc), TP_STRUCT__entry( - __field(__u32, pid) __field(__u32, tid) __field(__u64, sesid) __field(__u16, cmd) @@ -227,7 +225,6 @@ DECLARE_EVENT_CLASS(smb3_cmd_err_class, __field(int, rc) ), TP_fast_assign( - __entry->pid = pid; __entry->tid = tid; __entry->sesid = sesid; __entry->cmd = cmd; @@ -235,61 +232,109 @@ DECLARE_EVENT_CLASS(smb3_cmd_err_class, __entry->status = status; __entry->rc = rc; ), - TP_printk(" pid=%u tid=0x%x sid=0x%llx cmd=%u mid=%llu status=0x%x rc=%d", - __entry->pid, __entry->tid, __entry->sesid, - __entry->cmd, __entry->mid, __entry->status, __entry->rc) + TP_printk("\tsid=0x%llx tid=0x%x cmd=%u mid=%llu status=0x%x rc=%d", + __entry->sesid, __entry->tid, __entry->cmd, __entry->mid, + __entry->status, __entry->rc) ) #define DEFINE_SMB3_CMD_ERR_EVENT(name) \ DEFINE_EVENT(smb3_cmd_err_class, smb3_##name, \ - TP_PROTO(unsigned int pid, \ - __u32 tid, \ + TP_PROTO(__u32 tid, \ __u64 sesid, \ __u16 cmd, \ __u64 mid, \ __u32 status, \ int rc), \ - TP_ARGS(pid, tid, sesid, cmd, mid, status, rc)) + TP_ARGS(tid, sesid, cmd, mid, status, rc)) DEFINE_SMB3_CMD_ERR_EVENT(cmd_err); DECLARE_EVENT_CLASS(smb3_cmd_done_class, - TP_PROTO(__u32 pid, - __u32 tid, + TP_PROTO(__u32 tid, __u64 sesid, __u16 cmd, __u64 mid), - TP_ARGS(pid, tid, sesid, cmd, mid), + TP_ARGS(tid, sesid, cmd, mid), TP_STRUCT__entry( - __field(__u32, pid) __field(__u32, tid) __field(__u64, sesid) __field(__u16, cmd) __field(__u64, mid) ), TP_fast_assign( - __entry->pid = pid; __entry->tid = tid; __entry->sesid = sesid; __entry->cmd = cmd; __entry->mid = mid; ), - TP_printk("pid=%u tid=0x%x sid=0x%llx cmd=%u mid=%llu", - __entry->pid, __entry->tid, __entry->sesid, + TP_printk("\tsid=0x%llx tid=0x%x cmd=%u mid=%llu", + __entry->sesid, __entry->tid, __entry->cmd, __entry->mid) ) #define DEFINE_SMB3_CMD_DONE_EVENT(name) \ DEFINE_EVENT(smb3_cmd_done_class, smb3_##name, \ - TP_PROTO(unsigned int pid, \ - __u32 tid, \ + TP_PROTO(__u32 tid, \ __u64 sesid, \ __u16 cmd, \ __u64 mid), \ - TP_ARGS(pid, tid, sesid, cmd, mid)) + TP_ARGS(tid, sesid, cmd, mid)) DEFINE_SMB3_CMD_DONE_EVENT(cmd_done); +DECLARE_EVENT_CLASS(smb3_exit_err_class, + TP_PROTO(unsigned int xid, + const char *func_name, + int rc), + TP_ARGS(xid, func_name, rc), + TP_STRUCT__entry( + __field(unsigned int, xid) + __field(const char *, func_name) + __field(int, rc) + ), + TP_fast_assign( + __entry->xid = xid; + __entry->func_name = func_name; + __entry->rc = rc; + ), + TP_printk("\t%s: xid=%u rc=%d", + __entry->func_name, __entry->xid, __entry->rc) +) + +#define DEFINE_SMB3_EXIT_ERR_EVENT(name) \ +DEFINE_EVENT(smb3_exit_err_class, smb3_##name, \ + TP_PROTO(unsigned int xid, \ + const char *func_name, \ + int rc), \ + TP_ARGS(xid, func_name, rc)) + +DEFINE_SMB3_EXIT_ERR_EVENT(exit_err); + +DECLARE_EVENT_CLASS(smb3_enter_exit_class, + TP_PROTO(unsigned int xid, + const char *func_name), + TP_ARGS(xid, func_name), + TP_STRUCT__entry( + __field(unsigned int, xid) + __field(const char *, func_name) + ), + TP_fast_assign( + __entry->xid = xid; + __entry->func_name = func_name; + ), + TP_printk("\t%s: xid=%u", + __entry->func_name, __entry->xid) +) + +#define DEFINE_SMB3_ENTER_EXIT_EVENT(name) \ +DEFINE_EVENT(smb3_enter_exit_class, smb3_##name, \ + TP_PROTO(unsigned int xid, \ + const char *func_name), \ + TP_ARGS(xid, func_name)) + +DEFINE_SMB3_ENTER_EXIT_EVENT(enter); +DEFINE_SMB3_ENTER_EXIT_EVENT(exit_done); + #endif /* _CIFS_TRACE_H */ #undef TRACE_INCLUDE_PATH -- 2.17.0