From patchwork Mon Feb 25 20:52:34 2019 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Steve French X-Patchwork-Id: 1047985 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=pass (p=none dis=none) header.from=gmail.com Authentication-Results: ozlabs.org; dkim=pass (2048-bit key; unprotected) header.d=gmail.com header.i=@gmail.com header.b="rlQK1Ch+"; dkim-atps=neutral Received: from vger.kernel.org (vger.kernel.org [209.132.180.67]) by ozlabs.org (Postfix) with ESMTP id 447Z010Pckz9s71 for ; Tue, 26 Feb 2019 07:52:49 +1100 (AEDT) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1727424AbfBYUws (ORCPT ); Mon, 25 Feb 2019 15:52:48 -0500 Received: from mail-pg1-f170.google.com ([209.85.215.170]:37524 "EHLO mail-pg1-f170.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1727113AbfBYUwr (ORCPT ); Mon, 25 Feb 2019 15:52:47 -0500 Received: by mail-pg1-f170.google.com with SMTP id q206so5039816pgq.4 for ; Mon, 25 Feb 2019 12:52:47 -0800 (PST) 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=sbFSYLpPos/SIxSxQP++8hGnQhJ0hDCR87aen5amVEc=; b=rlQK1Ch+q/lzw7ggoffxrs7t8nHZ6VMiLDBlrYgdSghqVbZWIWck/oAs7rOMW/G5SW r4xjUcITPZkyZwnLKqVvOB6tmMglDB3KwQrVOgmsBTFj5DyoHHDSJDPHhVa0XhFPXNIF EdRDEWn6/eyz5ONAHTk4HVxqeVF+507s03kwv9/zJpV0x1y1nu3KWO+bjBhEein7YqCU aQNdwCdL9A4VXTkw8nqDF0Va/e22V/gQH67a35zRxFDhMhdlfVCwVVrsCCagL07k76JT n5C7v6vB8Whp6hVYOrO7wSYjukppNVcycr2LFotlCNhTyQFsjzILPXKHRlMIFwIHi2Os H8/A== 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=sbFSYLpPos/SIxSxQP++8hGnQhJ0hDCR87aen5amVEc=; b=eKaQ3XAbyP8rftXn3Nw4zbcW1ei6Vlc5Gza7XT3IHZ0tu466Kwj0DEWMh1pBKJQoL4 VpFUP6NiVZFnTW77m68PFvpoeWy3Z9PRel4+XLI5Gpixx4Gq35zFnkBW6iVkGLFPJhuM XrSEPER7fLswLQGMJtT7gaVBEg6q5GagoRapj/eoJ0bq6ksZeUy1C4sw2JpAgsbRpNj8 LquJsv+PIq5a++ehUO0kA4I2+G9DrjBbLOhHXL0PxhfO66RGDKH0D7vgCamLtNTpWFfl A3YLJEIbzmMxHy7W2W0lC1ikt3A1O3PR8tnYvtGE7HOQYjwBObnF1KmNURXLcO0fKYw3 y+NQ== X-Gm-Message-State: AHQUAuayeGPJvJNmVaILtIHznQUCY6mwy+n9T0mBAdmrydk0ZMpCIGro f68EeqoZn2I2F6hSWg1poPL6DKtK5vX6X/reHUic9I8f X-Google-Smtp-Source: AHgI3IYuX7FhyxbokjWjPgc98tIHmpVX8VfcjYTz1il8MjBq1dgpkNd8ScRKeQ+KFneCAe4u7wnm40/3MMWwRl9WfuY= X-Received: by 2002:aa7:8d42:: with SMTP id s2mr3494662pfe.116.1551127966121; Mon, 25 Feb 2019 12:52:46 -0800 (PST) MIME-Version: 1.0 From: Steve French Date: Mon, 25 Feb 2019 14:52:34 -0600 Message-ID: Subject: Updated ftrace patches for read/write/query_dir To: CIFS Sender: linux-cifs-owner@vger.kernel.org Precedence: bulk List-ID: X-Mailing-List: linux-cifs@vger.kernel.org Sample output (from "trace-cmd record -e smb3_query* -e smb3_read* -e smb3_write*") # TASK-PID CPU# |||| TIMESTAMP FUNCTION # | | | |||| | | ls-25909 [004] .... 91084.368421: smb3_query_dir_enter: xid=8 sid=0x45a21759 tid=0x821ad8fd fid=0x50da7b4 offset=0x0 len=0x4000 ls-25909 [004] .... 91084.369413: smb3_query_dir_done: xid=8 sid=0x45a21759 tid=0x821ad8fd fid=0x50da7b4 offset=0x0 len=0x8 ls-25909 [004] .... 91084.369530: smb3_query_dir_enter: xid=9 sid=0x45a21759 tid=0x821ad8fd fid=0x50da7b4 offset=0x0 len=0x4000 ls-25909 [004] .... 91084.370020: smb3_query_dir_done: xid=9 sid=0x45a21759 tid=0x821ad8fd fid=0x50da7b4 offset=0x0 len=0x0 dd-25915 [004] .... 91101.999225: smb3_read_enter: xid=0 sid=0x45a21759 tid=0x821ad8fd fid=0x85b15605 offset=0x0 len=0x400000 cifsd-25891 [005] .... 91102.010600: smb3_read_done: xid=0 sid=0x45a21759 tid=0x821ad8fd fid=0x85b15605 offset=0x0 len=0x400000 dd-25915 [004] .... 91102.015131: smb3_read_enter: xid=0 sid=0x45a21759 tid=0x821ad8fd fid=0x85b15605 offset=0x400000 len=0x3d0000 cifsd-25891 [005] .... 91102.026541: smb3_read_done: xid=0 sid=0x45a21759 tid=0x821ad8fd fid=0x85b15605 offset=0x400000 len=0x3d0000 dd-25915 [004] .... 91102.028261: smb3_read_enter: xid=0 sid=0x45a21759 tid=0x821ad8fd fid=0x85b15605 offset=0x7d0000 len=0x1000 dd-25919 [006] .... 91121.554908: smb3_write_enter: xid=0 sid=0x45a21759 tid=0x821ad8fd fid=0x402ee709 offset=0x0 len=0x400000 dd-25919 [006] .... 91121.556448: smb3_write_enter: xid=0 sid=0x45a21759 tid=0x821ad8fd fid=0x402ee709 offset=0x400000 len=0x3d0000 cifsd-25891 [005] .... 91121.559831: smb3_write_done: xid=0 sid=0x45a21759 tid=0x821ad8fd fid=0x402ee709 offset=0x0 len=0x400000 cifsd-25891 [005] .... 91121.561798: smb3_write_done: xid=0 sid=0x45a21759 tid=0x821ad8fd fid=0x402ee709 offset=0x400000 len=0x3d0000 dd-25931 [007] .... 91161.643194: smb3_read_enter: xid=0 sid=0x45a21759 tid=0x821ad8fd fid=0x115afb41 offset=0x0 len=0x400000 cifsd-25891 [005] .... 91161.650859: smb3_read_done: xid=0 sid=0x45a21759 tid=0x821ad8fd fid=0x115afb41 offset=0x0 len=0x400000 dd-25931 [007] .... 91161.655470: smb3_read_enter: xid=0 sid=0x45a21759 tid=0x821ad8fd fid=0x115afb41 offset=0x400000 len=0x3d0000 cifsd-25891 [004] .... 91161.663517: smb3_read_done: xid=0 sid=0x45a21759 tid=0x821ad8fd fid=0x115afb41 offset=0x400000 len=0x3d0000 dd-25931 [001] .... 91161.664921: smb3_read_enter: xid=0 sid=0x45a21759 tid=0x821ad8fd fid=0x115afb41 offset=0x7d0000 len=0x1000 From 6db924e70daae155845c6b7dd0f441dbff7bd658 Mon Sep 17 00:00:00 2001 From: Steve French Date: Mon, 25 Feb 2019 00:52:43 -0600 Subject: [PATCH 2/2] smb3: Add tracepoints for read, write and query_dir enter Allows tracing begin (not just completion) of read, write and query_dir which may be helpful in finding slow requests and other timing information Signed-off-by: Steve French Reviewed-by: Pavel Shilovsky --- fs/cifs/smb2pdu.c | 15 +++++++++++++++ fs/cifs/trace.h | 3 +++ 2 files changed, 18 insertions(+) diff --git a/fs/cifs/smb2pdu.c b/fs/cifs/smb2pdu.c index 965c4c7e87f9..ec9abe293279 100644 --- a/fs/cifs/smb2pdu.c +++ b/fs/cifs/smb2pdu.c @@ -3142,6 +3142,11 @@ smb2_new_read_req(void **buf, unsigned int *total_len, req->MinimumCount = 0; req->Length = cpu_to_le32(io_parms->length); req->Offset = cpu_to_le64(io_parms->offset); + + trace_smb3_read_enter(0 /* xid */, + io_parms->persistent_fid, + io_parms->tcon->tid, io_parms->tcon->ses->Suid, + io_parms->offset, io_parms->length); #ifdef CONFIG_CIFS_SMB_DIRECT /* * If we want to do a RDMA write, fill in and append @@ -3541,6 +3546,9 @@ smb2_async_writev(struct cifs_writedata *wdata, req->DataOffset = cpu_to_le16( offsetof(struct smb2_write_req, Buffer)); req->RemainingBytes = 0; + + trace_smb3_write_enter(0 /* xid */, wdata->cfile->fid.persistent_fid, + tcon->tid, tcon->ses->Suid, wdata->offset, wdata->bytes); #ifdef CONFIG_CIFS_SMB_DIRECT /* * If we want to do a server RDMA read, fill in and append @@ -3688,6 +3696,10 @@ SMB2_write(const unsigned int xid, struct cifs_io_parms *io_parms, offsetof(struct smb2_write_req, Buffer)); req->RemainingBytes = 0; + trace_smb3_write_enter(xid, io_parms->persistent_fid, + io_parms->tcon->tid, io_parms->tcon->ses->Suid, + io_parms->offset, io_parms->length); + iov[0].iov_base = (char *)req; /* 1 for Buffer */ iov[0].iov_len = total_len - 1; @@ -3850,6 +3862,9 @@ SMB2_query_directory(const unsigned int xid, struct cifs_tcon *tcon, rqst.rq_iov = iov; rqst.rq_nvec = 2; + trace_smb3_query_dir_enter(xid, persistent_fid, tcon->tid, + tcon->ses->Suid, index, output_size); + rc = cifs_send_recv(xid, ses, &rqst, &resp_buftype, flags, &rsp_iov); cifs_small_buf_release(req); rsp = (struct smb2_query_directory_rsp *)rsp_iov.iov_base; diff --git a/fs/cifs/trace.h b/fs/cifs/trace.h index bf4f43f6893b..660176e34dde 100644 --- a/fs/cifs/trace.h +++ b/fs/cifs/trace.h @@ -101,6 +101,9 @@ DEFINE_EVENT(smb3_rw_done_class, smb3_##name, \ __u32 len), \ TP_ARGS(xid, fid, tid, sesid, offset, len)) +DEFINE_SMB3_RW_DONE_EVENT(write_enter); +DEFINE_SMB3_RW_DONE_EVENT(read_enter); +DEFINE_SMB3_RW_DONE_EVENT(query_dir_enter); DEFINE_SMB3_RW_DONE_EVENT(write_done); DEFINE_SMB3_RW_DONE_EVENT(read_done); DEFINE_SMB3_RW_DONE_EVENT(query_dir_done); -- 2.17.1