lists.openwall.net   lists  /  announce  owl-users  owl-dev  john-users  john-dev  passwdqc-users  yescrypt  popa3d-users  /  oss-security  kernel-hardening  musl  sabotage  tlsify  passwords  /  crypt-dev  xvendor  /  Bugtraq  Full-Disclosure  linux-kernel  linux-netdev  linux-ext4  linux-hardening  linux-cve-announce  PHC 
Open Source and information security mailing list archives
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <165364828612.3334034.9708930432198654847.stgit@warthog.procyon.org.uk>
Date:   Fri, 27 May 2022 11:44:46 +0100
From:   David Howells <dhowells@...hat.com>
To:     Steve French <smfrench@...il.com>
Cc:     dhowells@...hat.com, Shyam Prasad N <nspmangalore@...il.com>,
        Rohith Surabattula <rohiths.msft@...il.com>,
        Jeff Layton <jlayton@...nel.org>,
        Al Viro <viro@...iv.linux.org.uk>, linux-cifs@...r.kernel.org,
        linux-fsdevel@...r.kernel.org, linux-kernel@...r.kernel.org
Subject: [PATCH v3 7/9] cifs: Trace writedata page wrangling


---

 fs/cifs/cifsfs.h   |    9 +++++--
 fs/cifs/cifsglob.h |    1 +
 fs/cifs/cifssmb.c  |   46 ++++++++++++++++++++++++++++++------
 fs/cifs/file.c     |    9 +++++--
 fs/cifs/trace.h    |   66 ++++++++++++++++++++++++++++++++++++++++++++++++++++
 5 files changed, 117 insertions(+), 14 deletions(-)

diff --git a/fs/cifs/cifsfs.h b/fs/cifs/cifsfs.h
index 34ad965cde21..51905a999f92 100644
--- a/fs/cifs/cifsfs.h
+++ b/fs/cifs/cifsfs.h
@@ -110,9 +110,12 @@ extern int cifs_file_strict_mmap(struct file * , struct vm_area_struct *);
 extern const struct file_operations cifs_dir_ops;
 extern int cifs_dir_open(struct inode *inode, struct file *file);
 extern int cifs_readdir(struct file *file, struct dir_context *ctx);
-extern void cifs_pages_written_back(struct inode *inode, loff_t start, unsigned int len);
-extern void cifs_pages_write_failed(struct inode *inode, loff_t start, unsigned int len);
-extern void cifs_pages_write_redirty(struct inode *inode, loff_t start, unsigned int len);
+extern void cifs_pages_written_back(struct inode *inode, loff_t start, unsigned int len,
+				    unsigned int wdata_debug_id);
+extern void cifs_pages_write_failed(struct inode *inode, loff_t start, unsigned int len,
+				    unsigned int wdata_debug_id);
+extern void cifs_pages_write_redirty(struct inode *inode, loff_t start, unsigned int len,
+				     unsigned int wdata_debug_id);
 
 /* Functions related to dir entries */
 extern const struct dentry_operations cifs_dentry_ops;
diff --git a/fs/cifs/cifsglob.h b/fs/cifs/cifsglob.h
index 06e0dd2c408d..9b39f920d5a0 100644
--- a/fs/cifs/cifsglob.h
+++ b/fs/cifs/cifsglob.h
@@ -1351,6 +1351,7 @@ struct cifs_writedata {
 	pid_t				pid;
 	unsigned int			bytes;
 	int				result;
+	unsigned int			debug_id;
 	struct TCP_Server_Info		*server;
 #ifdef CONFIG_CIFS_SMB_DIRECT
 	struct smbd_mr			*mr;
diff --git a/fs/cifs/cifssmb.c b/fs/cifs/cifssmb.c
index 865fb679cbee..fbb9ae267757 100644
--- a/fs/cifs/cifssmb.c
+++ b/fs/cifs/cifssmb.c
@@ -1959,7 +1959,8 @@ static void cifs_undirty_folios(struct inode *inode, loff_t start, unsigned int
 /*
  * Completion of write to server.
  */
-void cifs_pages_written_back(struct inode *inode, loff_t start, unsigned int len)
+void cifs_pages_written_back(struct inode *inode, loff_t start, unsigned int len,
+			     unsigned int wdata_debug_id)
 {
 	struct address_space *mapping = inode->i_mapping;
 	struct folio *folio;
@@ -1970,11 +1971,14 @@ void cifs_pages_written_back(struct inode *inode, loff_t start, unsigned int len
 	if (!len)
 		return;
 
+	trace_smb3_pages_written_back(inode, start, len, 0, wdata_debug_id);
+
 	rcu_read_lock();
 
 	end = (start + len - 1) / PAGE_SIZE;
 	xas_for_each(&xas, folio, end) {
 		if (!folio_test_writeback(folio)) {
+			trace_smb3_pages_write_bad(inode, start, len, 0, wdata_debug_id);
 			WARN_ONCE(1, "bad %x @%llx page %lx %lx\n",
 				  len, start, folio_index(folio), end);
 			continue;
@@ -1990,7 +1994,8 @@ void cifs_pages_written_back(struct inode *inode, loff_t start, unsigned int len
 /*
  * Failure of write to server.
  */
-void cifs_pages_write_failed(struct inode *inode, loff_t start, unsigned int len)
+void cifs_pages_write_failed(struct inode *inode, loff_t start, unsigned int len,
+			     unsigned int wdata_debug_id)
 {
 	struct address_space *mapping = inode->i_mapping;
 	struct folio *folio;
@@ -2001,11 +2006,14 @@ void cifs_pages_write_failed(struct inode *inode, loff_t start, unsigned int len
 	if (!len)
 		return;
 
+	trace_smb3_pages_write_failed(inode, start, len, 0, wdata_debug_id);
+
 	rcu_read_lock();
 
 	end = (start + len - 1) / PAGE_SIZE;
 	xas_for_each(&xas, folio, end) {
 		if (!folio_test_writeback(folio)) {
+			trace_smb3_pages_write_bad(inode, start, len, 0, wdata_debug_id);
 			WARN_ONCE(1, "bad %x @%llx page %lx %lx\n",
 				  len, start, folio_index(folio), end);
 			continue;
@@ -2021,7 +2029,8 @@ void cifs_pages_write_failed(struct inode *inode, loff_t start, unsigned int len
 /*
  * Redirty pages after a temporary failure.
  */
-void cifs_pages_write_redirty(struct inode *inode, loff_t start, unsigned int len)
+void cifs_pages_write_redirty(struct inode *inode, loff_t start, unsigned int len,
+			      unsigned int wdata_debug_id)
 {
 	struct address_space *mapping = inode->i_mapping;
 	struct folio *folio;
@@ -2032,11 +2041,14 @@ void cifs_pages_write_redirty(struct inode *inode, loff_t start, unsigned int le
 	if (!len)
 		return;
 
+	trace_smb3_pages_write_redirty(inode, start, len, 0, wdata_debug_id);
+
 	rcu_read_lock();
 
 	end = (start + len - 1) / PAGE_SIZE;
 	xas_for_each(&xas, folio, end) {
 		if (!folio_test_writeback(folio)) {
+			trace_smb3_pages_write_bad(inode, start, len, 0, wdata_debug_id);
 			WARN_ONCE(1, "bad %x @%llx page %lx %lx\n",
 				  len, start, folio_index(folio), end);
 			continue;
@@ -2109,10 +2121,17 @@ cifs_writev_requeue(struct cifs_writedata *wdata)
 				rc = -EBADF;
 		} else {
 			wdata2->pid = wdata2->cfile->pid;
+
+			trace_smb3_pages_write_requeue(inode, fpos, cur_len,
+						       wdata->debug_id,
+						       wdata2->debug_id);
 			rc = server->ops->async_writev(wdata2,
 						       cifs_writedata_release);
 		}
 
+		trace_smb3_pages_write_done(inode, wdata->offset, wdata->bytes,
+					    rc, wdata2->debug_id);
+
 		kref_put(&wdata2->refcount, cifs_writedata_release);
 		if (rc) {
 			if (is_retryable_error(rc))
@@ -2127,8 +2146,10 @@ cifs_writev_requeue(struct cifs_writedata *wdata)
 	} while (rest_len > 0);
 
 	/* Clean up remaining pages from the original wdata */
-	if (iov_iter_is_xarray(&wdata->iter))
-		cifs_pages_write_failed(inode, fpos, rest_len);
+	if (iov_iter_is_xarray(&wdata->iter)) {
+		trace_smb3_pages_write_cleanup(inode, fpos, rest_len, rc, wdata->debug_id);
+		cifs_pages_write_failed(inode, fpos, rest_len, wdata->debug_id);
+	}
 
 	if (rc != 0 && !is_retryable_error(rc))
 		mapping_set_error(inode->i_mapping, rc);
@@ -2142,6 +2163,9 @@ cifs_writev_complete(struct work_struct *work)
 						struct cifs_writedata, work);
 	struct inode *inode = d_inode(wdata->cfile->dentry);
 
+	trace_smb3_pages_writev_complete(inode, wdata->offset, wdata->bytes, wdata->result,
+					 wdata->debug_id);
+
 	if (wdata->result == 0) {
 		spin_lock(&inode->i_lock);
 		cifs_update_eof(CIFS_I(inode), wdata->offset, wdata->bytes);
@@ -2151,18 +2175,23 @@ cifs_writev_complete(struct work_struct *work)
 	} else if (wdata->sync_mode == WB_SYNC_ALL && wdata->result == -EAGAIN)
 		return cifs_writev_requeue(wdata);
 
+
+	trace_smb3_pages_write_complete(inode, wdata->offset, wdata->bytes,
+					wdata->result, wdata->debug_id);
 	if (wdata->result == -EAGAIN)
-		cifs_pages_write_redirty(inode, wdata->offset, wdata->bytes);
+		cifs_pages_write_redirty(inode, wdata->offset, wdata->bytes, wdata->debug_id);
 	else if (wdata->result < 0)
-		cifs_pages_write_failed(inode, wdata->offset, wdata->bytes);
+		cifs_pages_write_failed(inode, wdata->offset, wdata->bytes, wdata->debug_id);
 	else
-		cifs_pages_written_back(inode, wdata->offset, wdata->bytes);
+		cifs_pages_written_back(inode, wdata->offset, wdata->bytes, wdata->debug_id);
 
 	if (wdata->result != -EAGAIN)
 		mapping_set_error(inode->i_mapping, wdata->result);
 	kref_put(&wdata->refcount, cifs_writedata_release);
 }
 
+static atomic_t cifs_writedata_debug_counter;
+
 struct cifs_writedata *
 cifs_writedata_alloc(work_func_t complete)
 {
@@ -2174,6 +2203,7 @@ cifs_writedata_alloc(work_func_t complete)
 		INIT_LIST_HEAD(&wdata->list);
 		init_completion(&wdata->done);
 		INIT_WORK(&wdata->work, complete);
+		wdata->debug_id = atomic_inc_return(&cifs_writedata_debug_counter);
 	}
 	return wdata;
 }
diff --git a/fs/cifs/file.c b/fs/cifs/file.c
index e72059e002f2..881065e38a0b 100644
--- a/fs/cifs/file.c
+++ b/fs/cifs/file.c
@@ -2467,6 +2467,7 @@ static ssize_t cifs_write_back_from_locked_folio(struct address_space *mapping,
 		if (rc)
 			goto err_wdata;
 
+		trace_smb3_pages_write_back(inode, start, len, 0, wdata->debug_id);
 		if (wdata->cfile->invalidHandle)
 			rc = -EAGAIN;
 		else
@@ -2478,7 +2479,8 @@ static ssize_t cifs_write_back_from_locked_folio(struct address_space *mapping,
 		}
 	} else {
 		/* The dirty region was entirely beyond the EOF. */
-		cifs_pages_written_back(inode, start, len);
+		trace_smb3_pages_write_beyond(inode, start, len, rc, wdata->debug_id);
+		cifs_pages_written_back(inode, start, len, wdata->debug_id);
 		rc = 0;
 	}
 
@@ -2491,12 +2493,13 @@ static ssize_t cifs_write_back_from_locked_folio(struct address_space *mapping,
 		cifsFileInfo_put(cfile);
 err_xid:
 	free_xid(xid);
+	trace_smb3_pages_write_end(inode, start, len, rc, wdata->debug_id);
 	if (rc == 0) {
 		wbc->nr_to_write = count;
 	} else if (is_retryable_error(rc)) {
-		cifs_pages_write_redirty(inode, start, len);
+		cifs_pages_write_redirty(inode, start, len, wdata->debug_id);
 	} else {
-		cifs_pages_write_failed(inode, start, len);
+		cifs_pages_write_failed(inode, start, len, wdata->debug_id);
 		mapping_set_error(mapping, rc);
 	}
 	/* Indication to update ctime and mtime as close is deferred */
diff --git a/fs/cifs/trace.h b/fs/cifs/trace.h
index bc279616c513..d73d3093b67b 100644
--- a/fs/cifs/trace.h
+++ b/fs/cifs/trace.h
@@ -1015,6 +1015,72 @@ DEFINE_SMB3_CREDIT_EVENT(waitff_credits);
 DEFINE_SMB3_CREDIT_EVENT(overflow_credits);
 DEFINE_SMB3_CREDIT_EVENT(set_credits);
 
+DECLARE_EVENT_CLASS(smb3_pages_written_class,
+	TP_PROTO(struct inode *inode, loff_t start, unsigned int len, int rc,
+		 unsigned int wdata_debug_id),
+	TP_ARGS(inode, start, len, rc, wdata_debug_id),
+	TP_STRUCT__entry(
+		__field(__u64, ino)
+		__field(__u64, start)
+		__field(__u32, len)
+		__field(int, rc)
+		__field(unsigned int, wdata_debug_id)
+	),
+	TP_fast_assign(
+		__entry->wdata_debug_id = wdata_debug_id;
+		__entry->ino = inode->i_ino;
+		__entry->start = start;
+		__entry->len = len;
+		__entry->rc = rc;
+	),
+	TP_printk("W=%x ino=%llx %llx-%llx rc=%d",
+		  __entry->wdata_debug_id, __entry->ino,
+		  __entry->start, __entry->start + __entry->len,
+		  __entry->rc)
+)
+
+#define DEFINE_SMB3_PAGES_WRITTEN_EVENT(name)          \
+DEFINE_EVENT(smb3_pages_written_class, smb3_##name,    \
+	TP_PROTO(struct inode *inode, loff_t start, unsigned int len, int rc, \
+		 unsigned int wdata_debug_id), \
+	TP_ARGS(inode, start, len, rc, wdata_debug_id))
+
+DEFINE_SMB3_PAGES_WRITTEN_EVENT(pages_write_back);
+DEFINE_SMB3_PAGES_WRITTEN_EVENT(pages_write_bad);
+DEFINE_SMB3_PAGES_WRITTEN_EVENT(pages_write_beyond);
+DEFINE_SMB3_PAGES_WRITTEN_EVENT(pages_write_complete);
+DEFINE_SMB3_PAGES_WRITTEN_EVENT(pages_write_cleanup);
+DEFINE_SMB3_PAGES_WRITTEN_EVENT(pages_write_done);
+DEFINE_SMB3_PAGES_WRITTEN_EVENT(pages_write_end);
+DEFINE_SMB3_PAGES_WRITTEN_EVENT(pages_write_failed);
+DEFINE_SMB3_PAGES_WRITTEN_EVENT(pages_write_redirty);
+DEFINE_SMB3_PAGES_WRITTEN_EVENT(pages_writev_complete);
+DEFINE_SMB3_PAGES_WRITTEN_EVENT(pages_written_back);
+
+TRACE_EVENT(smb3_pages_write_requeue,
+	TP_PROTO(struct inode *inode, loff_t start, unsigned int len,
+		 unsigned int wdata_debug_id, unsigned int wdata_debug_id2),
+	TP_ARGS(inode, start, len, wdata_debug_id, wdata_debug_id2),
+	TP_STRUCT__entry(
+		__field(__u64, ino)
+		__field(__u64, start)
+		__field(__u32, len)
+		__field(unsigned int, wdata_debug_id)
+		__field(unsigned int, wdata_debug_id2)
+	),
+	TP_fast_assign(
+		__entry->wdata_debug_id = wdata_debug_id;
+		__entry->wdata_debug_id2 = wdata_debug_id2;
+		__entry->ino = inode->i_ino;
+		__entry->start = start;
+		__entry->len = len;
+	),
+	TP_printk("W=%x ino=%llx %llx-%llx NW=%x",
+		  __entry->wdata_debug_id, __entry->ino,
+		  __entry->start, __entry->start + __entry->len,
+		  __entry->wdata_debug_id2)
+)
+
 #endif /* _CIFS_TRACE_H */
 
 #undef TRACE_INCLUDE_PATH


Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ