diff --git a/fs/cifs/Makefile b/fs/cifs/Makefile index 7e4a1e2f0696..85817991ee68 100644 --- a/fs/cifs/Makefile +++ b/fs/cifs/Makefile @@ -1,11 +1,12 @@ # SPDX-License-Identifier: GPL-2.0 # -# Makefile for Linux CIFS VFS client +# Makefile for Linux CIFS/SMB2/SMB3 VFS client # +ccflags-y += -I$(src) # needed for trace events obj-$(CONFIG_CIFS) += cifs.o -cifs-y := cifsfs.o cifssmb.o cifs_debug.o connect.o dir.o file.o inode.o \ - link.o misc.o netmisc.o smbencrypt.o transport.o asn1.o \ +cifs-y := trace.o cifsfs.o cifssmb.o cifs_debug.o connect.o dir.o file.o \ + inode.o link.o misc.o netmisc.o smbencrypt.o transport.o asn1.o \ cifs_unicode.o nterr.o cifsencrypt.o \ readdir.o ioctl.o sess.o export.o smb1ops.o winucase.o \ smb2ops.o smb2maperror.o smb2transport.o \ diff --git a/fs/cifs/smb2maperror.c b/fs/cifs/smb2maperror.c index 3bfc9c990724..20185be4a93d 100644 --- a/fs/cifs/smb2maperror.c +++ b/fs/cifs/smb2maperror.c @@ -27,6 +27,7 @@ #include "smb2proto.h" #include "smb2status.h" #include "smb2glob.h" +#include "trace.h" struct status_to_posix_error { __le32 smb2_status; @@ -2455,8 +2456,12 @@ map_smb2_to_linux_error(char *buf, bool log_err) int rc = -EIO; __le32 smb2err = shdr->Status; - if (smb2err == 0) + 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)); return 0; + } /* mask facility */ if (log_err && (smb2err != STATUS_MORE_PROCESSING_REQUIRED) && @@ -2478,5 +2483,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), + le64_to_cpu(shdr->MessageId), le32_to_cpu(smb2err), rc); return rc; } diff --git a/fs/cifs/smb2pdu.c b/fs/cifs/smb2pdu.c index 35350057fc23..47d53314fc7f 100644 --- a/fs/cifs/smb2pdu.c +++ b/fs/cifs/smb2pdu.c @@ -49,6 +49,7 @@ #include "cifspdu.h" #include "cifs_spnego.h" #include "smbdirect.h" +#include "trace.h" /* * The following table defines the expected "StructureSize" of SMB2 requests @@ -2090,6 +2091,10 @@ SMB2_ioctl(const unsigned int xid, struct cifs_tcon *tcon, u64 persistent_fid, cifs_small_buf_release(req); rsp = (struct smb2_ioctl_rsp *)rsp_iov.iov_base; + if (rc != 0) + trace_smb3_fsctl_err(xid, persistent_fid, tcon->tid, + ses->Suid, 0, opcode, rc); + if ((rc != 0) && (rc != -EINVAL)) { cifs_stats_fail_inc(tcon, SMB2_IOCTL_HE); goto ioctl_exit; @@ -2200,6 +2205,8 @@ SMB2_close_flags(const unsigned int xid, struct cifs_tcon *tcon, if (rc != 0) { cifs_stats_fail_inc(tcon, SMB2_CLOSE_HE); + trace_smb3_close_err(xid, persistent_fid, tcon->tid, ses->Suid, + rc); goto close_exit; } @@ -2326,6 +2333,8 @@ query_info(const unsigned int xid, struct cifs_tcon *tcon, if (rc) { cifs_stats_fail_inc(tcon, SMB2_QUERY_INFO_HE); + trace_smb3_query_info_err(xid, persistent_fid, tcon->tid, + ses->Suid, info_class, (__u32)info_type, rc); goto qinf_exit; } @@ -2556,8 +2565,11 @@ SMB2_flush(const unsigned int xid, struct cifs_tcon *tcon, u64 persistent_fid, rc = smb2_send_recv(xid, ses, iov, 1, &resp_buftype, flags, &rsp_iov); cifs_small_buf_release(req); - if (rc != 0) + if (rc != 0) { cifs_stats_fail_inc(tcon, SMB2_FLUSH_HE); + trace_smb3_flush_err(xid, persistent_fid, tcon->tid, ses->Suid, + rc); + } free_rsp_buf(resp_buftype, rsp_iov.iov_base); return rc; @@ -2799,7 +2811,13 @@ smb2_async_readv(struct cifs_readdata *rdata) if (rc) { kref_put(&rdata->refcount, cifs_readdata_release); cifs_stats_fail_inc(io_parms.tcon, SMB2_READ_HE); - } + trace_smb3_read_err(rc, 0 /* xid */, io_parms.persistent_fid, + io_parms.tcon->tid, io_parms.tcon->ses->Suid, + io_parms.offset, io_parms.length); + } else + trace_smb3_read_done(0 /* xid */, io_parms.persistent_fid, + io_parms.tcon->tid, io_parms.tcon->ses->Suid, + io_parms.offset, io_parms.length); cifs_small_buf_release(buf); return rc; @@ -2840,9 +2858,15 @@ SMB2_read(const unsigned int xid, struct cifs_io_parms *io_parms, cifs_stats_fail_inc(io_parms->tcon, SMB2_READ_HE); cifs_dbg(VFS, "Send error in read = %d\n", rc); } + trace_smb3_read_err(rc, xid, req->PersistentFileId, + io_parms->tcon->tid, ses->Suid, + io_parms->offset, io_parms->length); free_rsp_buf(resp_buftype, rsp_iov.iov_base); return rc == -ENODATA ? 0 : rc; - } + } else + trace_smb3_read_done(xid, req->PersistentFileId, + io_parms->tcon->tid, ses->Suid, + io_parms->offset, io_parms->length); *nbytes = le32_to_cpu(rsp->DataLength); if ((*nbytes > CIFS_MAX_MSGSIZE) || @@ -3058,9 +3082,15 @@ smb2_async_writev(struct cifs_writedata *wdata, wdata, flags); if (rc) { + trace_smb3_write_err(0 /* no xid */, req->PersistentFileId, + tcon->tid, tcon->ses->Suid, wdata->offset, + wdata->bytes, rc); kref_put(&wdata->refcount, release); cifs_stats_fail_inc(tcon, SMB2_WRITE_HE); - } + } else + trace_smb3_write_done(0 /* no xid */, req->PersistentFileId, + tcon->tid, tcon->ses->Suid, wdata->offset, + wdata->bytes); async_writev_out: cifs_small_buf_release(req); @@ -3124,10 +3154,19 @@ SMB2_write(const unsigned int xid, struct cifs_io_parms *io_parms, rsp = (struct smb2_write_rsp *)rsp_iov.iov_base; if (rc) { + trace_smb3_write_err(xid, req->PersistentFileId, + io_parms->tcon->tid, + io_parms->tcon->ses->Suid, + io_parms->offset, io_parms->length, rc); cifs_stats_fail_inc(io_parms->tcon, SMB2_WRITE_HE); cifs_dbg(VFS, "Send error in write = %d\n", rc); - } else + } else { *nbytes = le32_to_cpu(rsp->DataLength); + trace_smb3_write_done(xid, req->PersistentFileId, + io_parms->tcon->tid, + io_parms->tcon->ses->Suid, + io_parms->offset, *nbytes); + } free_rsp_buf(resp_buftype, rsp); return rc; @@ -3374,8 +3413,11 @@ send_set_info(const unsigned int xid, struct cifs_tcon *tcon, cifs_small_buf_release(req); rsp = (struct smb2_set_info_rsp *)rsp_iov.iov_base; - if (rc != 0) + if (rc != 0) { cifs_stats_fail_inc(tcon, SMB2_SET_INFO_HE); + trace_smb3_set_info_err(xid, persistent_fid, tcon->tid, + ses->Suid, info_class, (__u32)info_type, rc); + } free_rsp_buf(resp_buftype, rsp); kfree(iov); @@ -3766,6 +3808,8 @@ smb2_lockv(const unsigned int xid, struct cifs_tcon *tcon, if (rc) { cifs_dbg(FYI, "Send error in smb2_lockv = %d\n", rc); cifs_stats_fail_inc(tcon, SMB2_LOCK_HE); + trace_smb3_lock_err(xid, persist_fid, tcon->tid, + tcon->ses->Suid, rc); } return rc; diff --git a/fs/cifs/trace.c b/fs/cifs/trace.c new file mode 100644 index 000000000000..bd4a546feec1 --- /dev/null +++ b/fs/cifs/trace.c @@ -0,0 +1,18 @@ +// SPDX-License-Identifier: GPL-2.0 +/* + * Copyright (C) 2018, Microsoft Corporation. + * + * Author(s): Steve French + * + * This program is free software; you can redistribute it and/or modify + * it under the terms of the GNU General Public License as published by + * the Free Software Foundation; either version 2 of the License, or + * (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See + * the GNU General Public License for more details. + */ +#define CREATE_TRACE_POINTS +#include "trace.h" diff --git a/fs/cifs/trace.h b/fs/cifs/trace.h new file mode 100644 index 000000000000..935a58979e1b --- /dev/null +++ b/fs/cifs/trace.h @@ -0,0 +1,298 @@ +/* SPDX-License-Identifier: GPL-2.0 */ +/* + * Copyright (C) 2018, Microsoft Corporation. + * + * Author(s): Steve French + * + * This program is free software; you can redistribute it and/or modify + * it under the terms of the GNU General Public License as published by + * the Free Software Foundation; either version 2 of the License, or + * (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See + * the GNU General Public License for more details. + */ +#undef TRACE_SYSTEM +#define TRACE_SYSTEM cifs + +#if !defined(_CIFS_TRACE_H) || defined(TRACE_HEADER_MULTI_READ) +#define _CIFS_TRACE_H + +#include + +/* For logging errors in read or write */ +DECLARE_EVENT_CLASS(smb3_rw_err_class, + TP_PROTO(unsigned int xid, + __u64 fid, + __u32 tid, + __u64 sesid, + __u64 offset, + __u32 len, + int rc), + TP_ARGS(xid, fid, tid, sesid, offset, len, rc), + TP_STRUCT__entry( + __field(unsigned int, xid) + __field(__u64, fid) + __field(__u32, tid) + __field(__u64, sesid) + __field(__u64, offset) + __field(__u32, len) + __field(int, rc) + ), + TP_fast_assign( + __entry->xid = xid; + __entry->fid = fid; + __entry->tid = tid; + __entry->sesid = sesid; + __entry->offset = offset; + __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, + __entry->offset, __entry->len, __entry->rc) +) + +#define DEFINE_SMB3_RW_ERR_EVENT(name) \ +DEFINE_EVENT(smb3_rw_err_class, smb3_##name, \ + TP_PROTO(unsigned int xid, \ + __u64 fid, \ + __u32 tid, \ + __u64 sesid, \ + __u64 offset, \ + __u32 len, \ + int rc), \ + TP_ARGS(xid, fid, tid, sesid, offset, len, rc)) + +DEFINE_SMB3_RW_ERR_EVENT(write_err); +DEFINE_SMB3_RW_ERR_EVENT(read_err); + + +/* For logging successful read or write */ +DECLARE_EVENT_CLASS(smb3_rw_done_class, + TP_PROTO(unsigned int xid, + __u64 fid, + __u32 tid, + __u64 sesid, + __u64 offset, + __u32 len), + TP_ARGS(xid, fid, tid, sesid, offset, len), + TP_STRUCT__entry( + __field(unsigned int, xid) + __field(__u64, fid) + __field(__u32, tid) + __field(__u64, sesid) + __field(__u64, offset) + __field(__u32, len) + ), + TP_fast_assign( + __entry->xid = xid; + __entry->fid = fid; + __entry->tid = tid; + __entry->sesid = sesid; + __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, + __entry->offset, __entry->len) +) + +#define DEFINE_SMB3_RW_DONE_EVENT(name) \ +DEFINE_EVENT(smb3_rw_done_class, smb3_##name, \ + TP_PROTO(unsigned int xid, \ + __u64 fid, \ + __u32 tid, \ + __u64 sesid, \ + __u64 offset, \ + __u32 len), \ + TP_ARGS(xid, fid, tid, sesid, offset, len)) + +DEFINE_SMB3_RW_DONE_EVENT(write_done); +DEFINE_SMB3_RW_DONE_EVENT(read_done); + +/* + * For handle based calls other than read and write, and get/set info + */ +DECLARE_EVENT_CLASS(smb3_fd_err_class, + TP_PROTO(unsigned int xid, + __u64 fid, + __u32 tid, + __u64 sesid, + int rc), + TP_ARGS(xid, fid, tid, sesid, rc), + TP_STRUCT__entry( + __field(unsigned int, xid) + __field(__u64, fid) + __field(__u32, tid) + __field(__u64, sesid) + __field(int, rc) + ), + TP_fast_assign( + __entry->xid = xid; + __entry->fid = fid; + __entry->tid = tid; + __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, + __entry->rc) +) + +#define DEFINE_SMB3_FD_ERR_EVENT(name) \ +DEFINE_EVENT(smb3_fd_err_class, smb3_##name, \ + TP_PROTO(unsigned int xid, \ + __u64 fid, \ + __u32 tid, \ + __u64 sesid, \ + int rc), \ + TP_ARGS(xid, fid, tid, sesid, rc)) + +DEFINE_SMB3_FD_ERR_EVENT(flush_err); +DEFINE_SMB3_FD_ERR_EVENT(lock_err); +DEFINE_SMB3_FD_ERR_EVENT(close_err); + +/* + * For handle based query/set info calls + */ +DECLARE_EVENT_CLASS(smb3_inf_err_class, + TP_PROTO(unsigned int xid, + __u64 fid, + __u32 tid, + __u64 sesid, + __u8 infclass, + __u32 type, + int rc), + TP_ARGS(xid, fid, tid, sesid, infclass, type, rc), + TP_STRUCT__entry( + __field(unsigned int, xid) + __field(__u64, fid) + __field(__u32, tid) + __field(__u64, sesid) + __field(__u8, infclass) + __field(__u32, type) + __field(int, rc) + ), + TP_fast_assign( + __entry->xid = xid; + __entry->fid = fid; + __entry->tid = tid; + __entry->sesid = sesid; + __entry->infclass = infclass; + __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, + __entry->infclass, __entry->type, __entry->rc) +) + +#define DEFINE_SMB3_INF_ERR_EVENT(name) \ +DEFINE_EVENT(smb3_inf_err_class, smb3_##name, \ + TP_PROTO(unsigned int xid, \ + __u64 fid, \ + __u32 tid, \ + __u64 sesid, \ + __u8 infclass, \ + __u32 type, \ + int rc), \ + TP_ARGS(xid, fid, tid, sesid, infclass, type, rc)) + +DEFINE_SMB3_INF_ERR_EVENT(query_info_err); +DEFINE_SMB3_INF_ERR_EVENT(set_info_err); +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, + __u64 sesid, + __u16 cmd, + __u64 mid, + __u32 status, + int rc), + TP_ARGS(pid, tid, sesid, cmd, mid, status, rc), + TP_STRUCT__entry( + __field(__u32, pid) + __field(__u32, tid) + __field(__u64, sesid) + __field(__u16, cmd) + __field(__u64, mid) + __field(__u32, status) + __field(int, rc) + ), + TP_fast_assign( + __entry->pid = pid; + __entry->tid = tid; + __entry->sesid = sesid; + __entry->cmd = cmd; + __entry->mid = mid; + __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) +) + +#define DEFINE_SMB3_CMD_ERR_EVENT(name) \ +DEFINE_EVENT(smb3_cmd_err_class, smb3_##name, \ + TP_PROTO(unsigned int pid, \ + __u32 tid, \ + __u64 sesid, \ + __u16 cmd, \ + __u64 mid, \ + __u32 status, \ + int rc), \ + TP_ARGS(pid, 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, + __u64 sesid, + __u16 cmd, + __u64 mid), + TP_ARGS(pid, 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, + __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, \ + __u64 sesid, \ + __u16 cmd, \ + __u64 mid), \ + TP_ARGS(pid, tid, sesid, cmd, mid)) + +DEFINE_SMB3_CMD_DONE_EVENT(cmd_done); + +#endif /* _CIFS_TRACE_H */ + +#undef TRACE_INCLUDE_PATH +#define TRACE_INCLUDE_PATH . +#define TRACE_INCLUDE_FILE trace +#include