[PATCH v1 0/7] Various NFS fscache cleanups

[PATCH v1 0/7] Various NFS fscache cleanups

[Dave Wysochanski]

This patchset is on top of David Howells fscache-iter-3 branch, which
he posted v2 recently
https://lore.kernel.org/all/163189104510.2509237.10805032055807259087.stgit@warthog.procyon.org.uk/

The first patch in this series should probably be merged into David Howells
3/8 patch of that series.  Otherwise, these patches are applied on top of
his series, and this series is mostly orthogonal to fscache-iter-3 branch.

The second and third patches are a few cleanups, and the last 4 remove
dfprintks in the NFS fscache code, and add in few new tracepoints.  I am
not sure about the new tracepoints, but I think we need at least a couple
tracepoints with the NFS fscache interface to tie in NFS tracepoints with
fscache and cachefiles ones.

These have been tested with xfstests against various NFS versions (NFS4.0,
NFS4.1, and NFS4.2) and servers (hammerspace, Netapp Ontap 9.x, RHEL8.4),
and all tracepoints enabled per the following:
trace-cmd start -e fscache:* -e nfs:* -e nfs4:* -e cachefiles:*

I plan to use this series at the BakeAThon this week for further testing
and refinement.

Dave Wysochanski (7):
  NFS: Fixup patch 3/8 of fscache-iter-3 v2
  NFS: Use nfs_i_fscache() consistently within NFS fscache code
  NFS: Cleanup usage of nfs_inode in fscache interface and handle i_size
    properly
  NFS: Convert NFS fscache enable/disable dfprintks to tracepoints
  NFS: Replace dfprintks in favor of tracepoints in fscache IO paths
  NFS: Remove remaining dfprintks related to fscache cookies
  NFS: Remove remaining usages of NFSDBG_FSCACHE

 fs/nfs/fscache-index.c      |  2 -
 fs/nfs/fscache.c            | 70 +++++++++-----------------------
 fs/nfs/fscache.h            |  8 ++--
 fs/nfs/nfstrace.h           | 99 +++++++++++++++++++++++++++++++++++++++++++++
 include/uapi/linux/nfs_fs.h |  2 +-
 5 files changed, 123 insertions(+), 58 deletions(-)

-- 
1.8.3.1

[PATCH v1 1/7] NFS: Fixup patch 3/8 of fscache-iter-3 v2

[Dave Wysochanski]

Handle failed return values of fscache_fallback_read_page() in
switch statement.

Signed-off-by: Dave Wysochanski <dwysocha@redhat.com>
---
 fs/nfs/fscache.c | 7 +------
 1 file changed, 1 insertion(+), 6 deletions(-)

diff --git a/fs/nfs/fscache.c b/fs/nfs/fscache.c
index 5b0e78742444..d3efb8ba4fb7 100644
--- a/fs/nfs/fscache.c
+++ b/fs/nfs/fscache.c
@@ -345,11 +345,6 @@ int __nfs_readpage_from_fscache(struct inode *inode, struct page *page)
 	}
 
 	ret = fscache_fallback_read_page(nfs_i_fscache(inode), page);
-	if (ret < 0) {
-		dfprintk(FSCACHE, "NFS:    readpage_from_fscache: "
-			 "fscache_fallback_read_page failed ret = %d\n", ret);
-		return ret;
-	}
 
 	switch (ret) {
 	case 0: /* Read completed synchronously */
@@ -363,7 +358,7 @@ int __nfs_readpage_from_fscache(struct inode *inode, struct page *page)
 	case -ENODATA: /* page not in cache */
 		nfs_inc_fscache_stats(inode, NFSIOS_FSCACHE_PAGES_READ_FAIL);
 		dfprintk(FSCACHE,
-			 "NFS:    readpage_from_fscache %d\n", ret);
+			 "NFS:    readpage_from_fscache failed %d\n", ret);
 		SetPageChecked(page);
 		return 1;
 
-- 
1.8.3.1

[PATCH v1 2/7] NFS: Use nfs_i_fscache() consistently within NFS fscache code

[Dave Wysochanski]

The nfs_i_fscache() is the API defined to check whether fscache
is enabled on an NFS inode or not, so use it consistently through
the code.

Signed-off-by: Dave Wysochanski <dwysocha@redhat.com>
---
 fs/nfs/fscache.h | 8 ++++----
 1 file changed, 4 insertions(+), 4 deletions(-)

diff --git a/fs/nfs/fscache.h b/fs/nfs/fscache.h
index 679055720dae..f4deea2908e9 100644
--- a/fs/nfs/fscache.h
+++ b/fs/nfs/fscache.h
@@ -105,7 +105,7 @@ extern void __nfs_read_completion_to_fscache(struct nfs_pgio_header *hdr,
 static inline int nfs_readpage_from_fscache(struct inode *inode,
 					    struct page *page)
 {
-	if (NFS_I(inode)->fscache)
+	if (nfs_i_fscache(inode))
 		return __nfs_readpage_from_fscache(inode, page);
 	return -ENOBUFS;
 }
@@ -117,7 +117,7 @@ static inline int nfs_readpage_from_fscache(struct inode *inode,
 static inline void nfs_readpage_to_fscache(struct inode *inode,
 					   struct page *page)
 {
-	if (NFS_I(inode)->fscache)
+	if (nfs_i_fscache(inode))
 		__nfs_readpage_to_fscache(inode, page);
 }
 
@@ -126,7 +126,7 @@ static inline void nfs_readpage_to_fscache(struct inode *inode,
  */
 static inline void nfs_fscache_invalidate(struct inode *inode)
 {
-	fscache_invalidate(NFS_I(inode)->fscache);
+	fscache_invalidate(nfs_i_fscache(inode));
 }
 
 /*
@@ -134,7 +134,7 @@ static inline void nfs_fscache_invalidate(struct inode *inode)
  */
 static inline void nfs_fscache_wait_on_invalidate(struct inode *inode)
 {
-	fscache_wait_on_invalidate(NFS_I(inode)->fscache);
+	fscache_wait_on_invalidate(nfs_i_fscache(inode));
 }
 
 /*
-- 
1.8.3.1

[PATCH v1 3/7] NFS: Cleanup usage of nfs_inode in fscache interface and handle i_size properly

[Dave Wysochanski]

A number of places in the fscache interface used nfs_inode when inode could
be used, simplifying the code.  Also, handle the read of i_size properly by
utilizing the i_size_read() interface.

Signed-off-by: Dave Wysochanski <dwysocha@redhat.com>
---
 fs/nfs/fscache.c | 24 ++++++++++++------------
 1 file changed, 12 insertions(+), 12 deletions(-)

diff --git a/fs/nfs/fscache.c b/fs/nfs/fscache.c
index d3efb8ba4fb7..8f17fda5b8c9 100644
--- a/fs/nfs/fscache.c
+++ b/fs/nfs/fscache.c
@@ -226,16 +226,16 @@ void nfs_fscache_release_super_cookie(struct super_block *sb)
 }
 
 static void nfs_fscache_update_auxdata(struct nfs_fscache_inode_auxdata *auxdata,
-				  struct nfs_inode *nfsi)
+				  struct inode *inode)
 {
 	memset(auxdata, 0, sizeof(*auxdata));
-	auxdata->mtime_sec  = nfsi->vfs_inode.i_mtime.tv_sec;
-	auxdata->mtime_nsec = nfsi->vfs_inode.i_mtime.tv_nsec;
-	auxdata->ctime_sec  = nfsi->vfs_inode.i_ctime.tv_sec;
-	auxdata->ctime_nsec = nfsi->vfs_inode.i_ctime.tv_nsec;
+	auxdata->mtime_sec  = inode->i_mtime.tv_sec;
+	auxdata->mtime_nsec = inode->i_mtime.tv_nsec;
+	auxdata->ctime_sec  = inode->i_ctime.tv_sec;
+	auxdata->ctime_nsec = inode->i_ctime.tv_nsec;
 
-	if (NFS_SERVER(&nfsi->vfs_inode)->nfs_client->rpc_ops->version == 4)
-		auxdata->change_attr = inode_peek_iversion_raw(&nfsi->vfs_inode);
+	if (NFS_SERVER(inode)->nfs_client->rpc_ops->version == 4)
+		auxdata->change_attr = inode_peek_iversion_raw(inode);
 }
 
 /*
@@ -251,13 +251,13 @@ void nfs_fscache_init_inode(struct inode *inode)
 	if (!(nfss->fscache && S_ISREG(inode->i_mode)))
 		return;
 
-	nfs_fscache_update_auxdata(&auxdata, nfsi);
+	nfs_fscache_update_auxdata(&auxdata, inode);
 
 	nfsi->fscache = fscache_acquire_cookie(NFS_SB(inode->i_sb)->fscache,
 					       &nfs_fscache_inode_object_def,
 					       nfsi->fh.data, nfsi->fh.size,
 					       &auxdata, sizeof(auxdata),
-					       nfsi, nfsi->vfs_inode.i_size, false);
+					       nfsi, i_size_read(inode), false);
 }
 
 /*
@@ -271,7 +271,7 @@ void nfs_fscache_clear_inode(struct inode *inode)
 
 	dfprintk(FSCACHE, "NFS: clear cookie (0x%p/0x%p)\n", nfsi, cookie);
 
-	nfs_fscache_update_auxdata(&auxdata, nfsi);
+	nfs_fscache_update_auxdata(&auxdata, inode);
 	fscache_relinquish_cookie(cookie, &auxdata, false);
 	nfsi->fscache = NULL;
 }
@@ -311,7 +311,7 @@ void nfs_fscache_open_file(struct inode *inode, struct file *filp)
 	if (!fscache_cookie_valid(cookie))
 		return;
 
-	nfs_fscache_update_auxdata(&auxdata, nfsi);
+	nfs_fscache_update_auxdata(&auxdata, inode);
 
 	if (inode_is_open_for_write(inode)) {
 		dfprintk(FSCACHE, "NFS: nfsi 0x%p disabling cache\n", nfsi);
@@ -319,7 +319,7 @@ void nfs_fscache_open_file(struct inode *inode, struct file *filp)
 		fscache_disable_cookie(cookie, &auxdata, true);
 	} else {
 		dfprintk(FSCACHE, "NFS: nfsi 0x%p enabling cache\n", nfsi);
-		fscache_enable_cookie(cookie, &auxdata, nfsi->vfs_inode.i_size,
+		fscache_enable_cookie(cookie, &auxdata, i_size_read(inode),
 				      nfs_fscache_can_enable, inode);
 		if (fscache_cookie_enabled(cookie))
 			set_bit(NFS_INO_FSCACHE, &NFS_I(inode)->flags);
-- 
1.8.3.1

[PATCH v1 4/7] NFS: Convert NFS fscache enable/disable dfprintks to tracepoints

[Dave Wysochanski]

Convert the enable / disable NFS fscache dfprintks to tracepoints.
Utilize the existing NFS inode trace event class, which allows us
to keep the same output format to other NFS inode tracepoints.

Signed-off-by: Dave Wysochanski <dwysocha@redhat.com>
---
 fs/nfs/fscache.c  | 5 +++--
 fs/nfs/nfstrace.h | 2 ++
 2 files changed, 5 insertions(+), 2 deletions(-)

diff --git a/fs/nfs/fscache.c b/fs/nfs/fscache.c
index 8f17fda5b8c9..a2b517846787 100644
--- a/fs/nfs/fscache.c
+++ b/fs/nfs/fscache.c
@@ -19,6 +19,7 @@
 #include "internal.h"
 #include "iostat.h"
 #include "fscache.h"
+#include "nfstrace.h"
 
 #define NFSDBG_FACILITY		NFSDBG_FSCACHE
 
@@ -314,11 +315,11 @@ void nfs_fscache_open_file(struct inode *inode, struct file *filp)
 	nfs_fscache_update_auxdata(&auxdata, inode);
 
 	if (inode_is_open_for_write(inode)) {
-		dfprintk(FSCACHE, "NFS: nfsi 0x%p disabling cache\n", nfsi);
+		trace_nfs_disable_fscache_inode(inode);
 		clear_bit(NFS_INO_FSCACHE, &nfsi->flags);
 		fscache_disable_cookie(cookie, &auxdata, true);
 	} else {
-		dfprintk(FSCACHE, "NFS: nfsi 0x%p enabling cache\n", nfsi);
+		trace_nfs_enable_fscache_inode(inode);
 		fscache_enable_cookie(cookie, &auxdata, i_size_read(inode),
 				      nfs_fscache_can_enable, inode);
 		if (fscache_cookie_enabled(cookie))
diff --git a/fs/nfs/nfstrace.h b/fs/nfs/nfstrace.h
index 8a224871be74..b4177f57f69b 100644
--- a/fs/nfs/nfstrace.h
+++ b/fs/nfs/nfstrace.h
@@ -209,6 +209,8 @@
 DEFINE_NFS_INODE_EVENT(nfs_fsync_enter);
 DEFINE_NFS_INODE_EVENT_DONE(nfs_fsync_exit);
 DEFINE_NFS_INODE_EVENT(nfs_access_enter);
+DEFINE_NFS_INODE_EVENT(nfs_enable_fscache_inode);
+DEFINE_NFS_INODE_EVENT(nfs_disable_fscache_inode);
 
 TRACE_EVENT(nfs_access_exit,
 		TP_PROTO(
-- 
1.8.3.1

[PATCH v1 5/7] NFS: Replace dfprintks in favor of tracepoints in fscache IO paths

[Dave Wysochanski]

Most of fscache and other NFS IO paths are now using tracepoints,
so remove the dfprintks in these code paths and replace with a couple
tracepoints to track page IO.

Signed-off-by: Dave Wysochanski <dwysocha@redhat.com>
---
 fs/nfs/fscache.c  | 22 +++----------
 fs/nfs/nfstrace.h | 97 +++++++++++++++++++++++++++++++++++++++++++++++++++++++
 2 files changed, 101 insertions(+), 18 deletions(-)

diff --git a/fs/nfs/fscache.c b/fs/nfs/fscache.c
index a2b517846787..1db1e298b915 100644
--- a/fs/nfs/fscache.c
+++ b/fs/nfs/fscache.c
@@ -335,22 +335,17 @@ int __nfs_readpage_from_fscache(struct inode *inode, struct page *page)
 {
 	int ret;
 
-	dfprintk(FSCACHE,
-		 "NFS: readpage_from_fscache(fsc:%p/p:%p(i:%lx f:%lx)/0x%p)\n",
-		 nfs_i_fscache(inode), page, page->index, page->flags, inode);
-
 	if (PageChecked(page)) {
-		dfprintk(FSCACHE, "NFS:    readpage_from_fscache: PageChecked\n");
 		ClearPageChecked(page);
 		return 1;
 	}
 
+	trace_nfs_fscache_page_event_read(inode, page);
 	ret = fscache_fallback_read_page(nfs_i_fscache(inode), page);
+	trace_nfs_fscache_page_event_read_done(inode, page, ret);
 
 	switch (ret) {
 	case 0: /* Read completed synchronously */
-		dfprintk(FSCACHE,
-			 "NFS:    readpage_from_fscache: read successful\n");
 		nfs_inc_fscache_stats(inode, NFSIOS_FSCACHE_PAGES_READ_OK);
 		SetPageUptodate(page);
 		return 0;
@@ -358,13 +353,10 @@ int __nfs_readpage_from_fscache(struct inode *inode, struct page *page)
 	case -ENOBUFS: /* inode not in cache */
 	case -ENODATA: /* page not in cache */
 		nfs_inc_fscache_stats(inode, NFSIOS_FSCACHE_PAGES_READ_FAIL);
-		dfprintk(FSCACHE,
-			 "NFS:    readpage_from_fscache failed %d\n", ret);
 		SetPageChecked(page);
 		return 1;
 
 	default:
-		dfprintk(FSCACHE, "NFS:    readpage_from_fscache %d\n", ret);
 		nfs_inc_fscache_stats(inode, NFSIOS_FSCACHE_PAGES_READ_FAIL);
 		SetPageChecked(page);
 	}
@@ -378,15 +370,9 @@ void __nfs_readpage_to_fscache(struct inode *inode, struct page *page)
 {
 	int ret;
 
-	dfprintk(FSCACHE,
-		 "NFS: readpage_to_fscache(fsc:%p/p:%p(i:%lx f:%lx))\n",
-		 nfs_i_fscache(inode), page, page->index, page->flags);
-
+	trace_nfs_fscache_page_event_write(inode, page);
 	ret = fscache_fallback_write_page(nfs_i_fscache(inode), page);
-
-	dfprintk(FSCACHE,
-		 "NFS:     readpage_to_fscache: p:%p(i:%lu f:%lx) ret %d\n",
-		 page, page->index, page->flags, ret);
+	trace_nfs_fscache_page_event_write_done(inode, page, ret);
 
 	if (ret != 0) {
 		nfs_inc_fscache_stats(inode, NFSIOS_FSCACHE_PAGES_WRITTEN_FAIL);
diff --git a/fs/nfs/nfstrace.h b/fs/nfs/nfstrace.h
index b4177f57f69b..662dddc2eb96 100644
--- a/fs/nfs/nfstrace.h
+++ b/fs/nfs/nfstrace.h
@@ -880,6 +880,103 @@
 		)
 );
 
+DECLARE_EVENT_CLASS(nfs_fscache_page_event,
+		TP_PROTO(
+			const struct inode *inode,
+			const struct page *page
+		),
+
+		TP_ARGS(inode, page),
+
+		TP_STRUCT__entry(
+			__field(dev_t, dev)
+			__field(u32, fhandle)
+			__field(u64, fileid)
+			__field(loff_t, offset)
+			__field(u32, count)
+		),
+
+		TP_fast_assign(
+			const struct nfs_inode *nfsi = NFS_I(inode);
+			const struct nfs_fh *fh = &nfsi->fh;
+
+			__entry->offset = page->index << PAGE_SHIFT;
+			__entry->count = 4096;
+			__entry->dev = inode->i_sb->s_dev;
+			__entry->fileid = nfsi->fileid;
+			__entry->fhandle = nfs_fhandle_hash(fh);
+		),
+
+		TP_printk(
+			"fileid=%02x:%02x:%llu fhandle=0x%08x "
+			"offset=%lld count=%u",
+			MAJOR(__entry->dev), MINOR(__entry->dev),
+			(unsigned long long)__entry->fileid,
+			__entry->fhandle,
+			(long long)__entry->offset, __entry->count
+		)
+);
+
+DECLARE_EVENT_CLASS(nfs_fscache_page_event_done,
+		TP_PROTO(
+			const struct inode *inode,
+			const struct page *page,
+			int error
+		),
+
+		TP_ARGS(inode, page, error),
+
+		TP_STRUCT__entry(
+			__field(int, error)
+			__field(dev_t, dev)
+			__field(u32, fhandle)
+			__field(u64, fileid)
+			__field(loff_t, offset)
+			__field(u32, count)
+		),
+
+		TP_fast_assign(
+			const struct nfs_inode *nfsi = NFS_I(inode);
+			const struct nfs_fh *fh = &nfsi->fh;
+
+			__entry->offset = page->index << PAGE_SHIFT;
+			__entry->count = 4096;
+			__entry->dev = inode->i_sb->s_dev;
+			__entry->fileid = nfsi->fileid;
+			__entry->fhandle = nfs_fhandle_hash(fh);
+			__entry->error = error;
+		),
+
+		TP_printk(
+			"fileid=%02x:%02x:%llu fhandle=0x%08x "
+			"offset=%lld count=%u error=%d",
+			MAJOR(__entry->dev), MINOR(__entry->dev),
+			(unsigned long long)__entry->fileid,
+			__entry->fhandle,
+			(long long)__entry->offset, __entry->count,
+			__entry->error
+		)
+);
+#define DEFINE_NFS_FSCACHE_PAGE_EVENT(name) \
+	DEFINE_EVENT(nfs_fscache_page_event, name, \
+			TP_PROTO( \
+				const struct inode *inode, \
+				const struct page *page \
+			), \
+			TP_ARGS(inode, page))
+#define DEFINE_NFS_FSCACHE_PAGE_EVENT_DONE(name) \
+	DEFINE_EVENT(nfs_fscache_page_event_done, name, \
+			TP_PROTO( \
+				const struct inode *inode, \
+				const struct page *page, \
+				int error \
+			), \
+			TP_ARGS(inode, page, error))
+DEFINE_NFS_FSCACHE_PAGE_EVENT(nfs_fscache_page_event_read);
+DEFINE_NFS_FSCACHE_PAGE_EVENT_DONE(nfs_fscache_page_event_read_done);
+DEFINE_NFS_FSCACHE_PAGE_EVENT(nfs_fscache_page_event_write);
+DEFINE_NFS_FSCACHE_PAGE_EVENT_DONE(nfs_fscache_page_event_write_done);
+
 TRACE_EVENT(nfs_initiate_read,
 		TP_PROTO(
 			const struct nfs_pgio_header *hdr
-- 
1.8.3.1

Re: [Linux-cachefs] [PATCH v1 5/7] NFS: Replace dfprintks in favor of tracepoints in fscache IO paths

[David Wysochanski]

On Sun, Oct 3, 2021 at 3:23 PM Dave Wysochanski <dwysocha@redhat.com> wrote:
>
> Most of fscache and other NFS IO paths are now using tracepoints,
> so remove the dfprintks in these code paths and replace with a couple
> tracepoints to track page IO.
>
> Signed-off-by: Dave Wysochanski <dwysocha@redhat.com>
> ---
>  fs/nfs/fscache.c  | 22 +++----------
>  fs/nfs/nfstrace.h | 97 +++++++++++++++++++++++++++++++++++++++++++++++++++++++
>  2 files changed, 101 insertions(+), 18 deletions(-)
>
> diff --git a/fs/nfs/fscache.c b/fs/nfs/fscache.c
> index a2b517846787..1db1e298b915 100644
> --- a/fs/nfs/fscache.c
> +++ b/fs/nfs/fscache.c
> @@ -335,22 +335,17 @@ int __nfs_readpage_from_fscache(struct inode *inode, struct page *page)
>  {
>         int ret;
>
> -       dfprintk(FSCACHE,
> -                "NFS: readpage_from_fscache(fsc:%p/p:%p(i:%lx f:%lx)/0x%p)\n",
> -                nfs_i_fscache(inode), page, page->index, page->flags, inode);
> -
>         if (PageChecked(page)) {
> -               dfprintk(FSCACHE, "NFS:    readpage_from_fscache: PageChecked\n");
>                 ClearPageChecked(page);
>                 return 1;
>         }
>
> +       trace_nfs_fscache_page_event_read(inode, page);
>         ret = fscache_fallback_read_page(nfs_i_fscache(inode), page);
> +       trace_nfs_fscache_page_event_read_done(inode, page, ret);
>
>         switch (ret) {
>         case 0: /* Read completed synchronously */
> -               dfprintk(FSCACHE,
> -                        "NFS:    readpage_from_fscache: read successful\n");
>                 nfs_inc_fscache_stats(inode, NFSIOS_FSCACHE_PAGES_READ_OK);
>                 SetPageUptodate(page);
>                 return 0;
> @@ -358,13 +353,10 @@ int __nfs_readpage_from_fscache(struct inode *inode, struct page *page)
>         case -ENOBUFS: /* inode not in cache */
>         case -ENODATA: /* page not in cache */
>                 nfs_inc_fscache_stats(inode, NFSIOS_FSCACHE_PAGES_READ_FAIL);
> -               dfprintk(FSCACHE,
> -                        "NFS:    readpage_from_fscache failed %d\n", ret);
>                 SetPageChecked(page);
>                 return 1;
>
>         default:
> -               dfprintk(FSCACHE, "NFS:    readpage_from_fscache %d\n", ret);
>                 nfs_inc_fscache_stats(inode, NFSIOS_FSCACHE_PAGES_READ_FAIL);
>                 SetPageChecked(page);
>         }
> @@ -378,15 +370,9 @@ void __nfs_readpage_to_fscache(struct inode *inode, struct page *page)
>  {
>         int ret;
>
> -       dfprintk(FSCACHE,
> -                "NFS: readpage_to_fscache(fsc:%p/p:%p(i:%lx f:%lx))\n",
> -                nfs_i_fscache(inode), page, page->index, page->flags);
> -
> +       trace_nfs_fscache_page_event_write(inode, page);
>         ret = fscache_fallback_write_page(nfs_i_fscache(inode), page);
> -
> -       dfprintk(FSCACHE,
> -                "NFS:     readpage_to_fscache: p:%p(i:%lu f:%lx) ret %d\n",
> -                page, page->index, page->flags, ret);
> +       trace_nfs_fscache_page_event_write_done(inode, page, ret);
>
>         if (ret != 0) {
>                 nfs_inc_fscache_stats(inode, NFSIOS_FSCACHE_PAGES_WRITTEN_FAIL);
> diff --git a/fs/nfs/nfstrace.h b/fs/nfs/nfstrace.h
> index b4177f57f69b..662dddc2eb96 100644
> --- a/fs/nfs/nfstrace.h
> +++ b/fs/nfs/nfstrace.h
> @@ -880,6 +880,103 @@
>                 )
>  );
>
> +DECLARE_EVENT_CLASS(nfs_fscache_page_event,
> +               TP_PROTO(
> +                       const struct inode *inode,
> +                       const struct page *page
> +               ),
> +
> +               TP_ARGS(inode, page),
> +
> +               TP_STRUCT__entry(
> +                       __field(dev_t, dev)
> +                       __field(u32, fhandle)
> +                       __field(u64, fileid)
> +                       __field(loff_t, offset)
> +                       __field(u32, count)
> +               ),
> +
> +               TP_fast_assign(
> +                       const struct nfs_inode *nfsi = NFS_I(inode);
> +                       const struct nfs_fh *fh = &nfsi->fh;
> +
> +                       __entry->offset = page->index << PAGE_SHIFT;
> +                       __entry->count = 4096;
> +                       __entry->dev = inode->i_sb->s_dev;
> +                       __entry->fileid = nfsi->fileid;
> +                       __entry->fhandle = nfs_fhandle_hash(fh);
> +               ),
> +
> +               TP_printk(
> +                       "fileid=%02x:%02x:%llu fhandle=0x%08x "
> +                       "offset=%lld count=%u",
> +                       MAJOR(__entry->dev), MINOR(__entry->dev),
> +                       (unsigned long long)__entry->fileid,
> +                       __entry->fhandle,
> +                       (long long)__entry->offset, __entry->count
> +               )
> +);
> +
> +DECLARE_EVENT_CLASS(nfs_fscache_page_event_done,
> +               TP_PROTO(
> +                       const struct inode *inode,
> +                       const struct page *page,
> +                       int error
> +               ),
> +
> +               TP_ARGS(inode, page, error),
> +
> +               TP_STRUCT__entry(
> +                       __field(int, error)
> +                       __field(dev_t, dev)
> +                       __field(u32, fhandle)
> +                       __field(u64, fileid)
> +                       __field(loff_t, offset)
> +                       __field(u32, count)
> +               ),
> +
> +               TP_fast_assign(
> +                       const struct nfs_inode *nfsi = NFS_I(inode);
> +                       const struct nfs_fh *fh = &nfsi->fh;
> +
> +                       __entry->offset = page->index << PAGE_SHIFT;
> +                       __entry->count = 4096;
> +                       __entry->dev = inode->i_sb->s_dev;
> +                       __entry->fileid = nfsi->fileid;
> +                       __entry->fhandle = nfs_fhandle_hash(fh);
> +                       __entry->error = error;
> +               ),
> +
> +               TP_printk(
> +                       "fileid=%02x:%02x:%llu fhandle=0x%08x "
> +                       "offset=%lld count=%u error=%d",
> +                       MAJOR(__entry->dev), MINOR(__entry->dev),
> +                       (unsigned long long)__entry->fileid,
> +                       __entry->fhandle,
> +                       (long long)__entry->offset, __entry->count,
> +                       __entry->error
> +               )
> +);
> +#define DEFINE_NFS_FSCACHE_PAGE_EVENT(name) \
> +       DEFINE_EVENT(nfs_fscache_page_event, name, \
> +                       TP_PROTO( \
> +                               const struct inode *inode, \
> +                               const struct page *page \
> +                       ), \
> +                       TP_ARGS(inode, page))
> +#define DEFINE_NFS_FSCACHE_PAGE_EVENT_DONE(name) \
> +       DEFINE_EVENT(nfs_fscache_page_event_done, name, \
> +                       TP_PROTO( \
> +                               const struct inode *inode, \
> +                               const struct page *page, \
> +                               int error \
> +                       ), \
> +                       TP_ARGS(inode, page, error))
> +DEFINE_NFS_FSCACHE_PAGE_EVENT(nfs_fscache_page_event_read);
> +DEFINE_NFS_FSCACHE_PAGE_EVENT_DONE(nfs_fscache_page_event_read_done);
> +DEFINE_NFS_FSCACHE_PAGE_EVENT(nfs_fscache_page_event_write);
> +DEFINE_NFS_FSCACHE_PAGE_EVENT_DONE(nfs_fscache_page_event_write_done);
> +
>  TRACE_EVENT(nfs_initiate_read,
>                 TP_PROTO(
>                         const struct nfs_pgio_header *hdr
> --
> 1.8.3.1
>
> --
> Linux-cachefs mailing list
> Linux-cachefs@redhat.com
> https://listman.redhat.com/mailman/listinfo/linux-cachefs
>

This is unnecessarily complicated.  I'm reworking this to:
- add a patch that renames nfs_readpage_to_fscache to
nfs_fscache_read_page and nfs_readpage_from_fscache to
nfs_fscache_write_page; this matches the fallback API and is clearer
- add a single tracepoint only at the return point of these two
functions, printing the return value

[PATCH v1 6/7] NFS: Remove remaining dfprintks related to fscache cookies

[Dave Wysochanski]

The fscache cookie APIs including fscache_acquire_cookie() and
fscache_relinquish_cookie() now have very good tracing.  Thus,
there is no real need for dfprintks in the NFS fscache interface.

Signed-off-by: Dave Wysochanski <dwysocha@redhat.com>
---
 fs/nfs/fscache.c | 14 +-------------
 1 file changed, 1 insertion(+), 13 deletions(-)

diff --git a/fs/nfs/fscache.c b/fs/nfs/fscache.c
index 1db1e298b915..d199ee103dc6 100644
--- a/fs/nfs/fscache.c
+++ b/fs/nfs/fscache.c
@@ -21,7 +21,7 @@
 #include "fscache.h"
 #include "nfstrace.h"
 
-#define NFSDBG_FACILITY		NFSDBG_FSCACHE
+#define NFSDBG_FACILITY                NFSDBG_FSCACHE
 
 static struct rb_root nfs_fscache_keys = RB_ROOT;
 static DEFINE_SPINLOCK(nfs_fscache_keys_lock);
@@ -86,8 +86,6 @@ void nfs_fscache_get_client_cookie(struct nfs_client *clp)
 					      &key, len,
 					      NULL, 0,
 					      clp, 0, true);
-	dfprintk(FSCACHE, "NFS: get client cookie (0x%p/0x%p)\n",
-		 clp, clp->fscache);
 }
 
 /*
@@ -95,9 +93,6 @@ void nfs_fscache_get_client_cookie(struct nfs_client *clp)
  */
 void nfs_fscache_release_client_cookie(struct nfs_client *clp)
 {
-	dfprintk(FSCACHE, "NFS: releasing client cookie (0x%p/0x%p)\n",
-		 clp, clp->fscache);
-
 	fscache_relinquish_cookie(clp->fscache, NULL, false);
 	clp->fscache = NULL;
 }
@@ -191,8 +186,6 @@ void nfs_fscache_get_super_cookie(struct super_block *sb, const char *uniq, int
 					       sizeof(key->key) + ulen,
 					       NULL, 0,
 					       nfss, 0, true);
-	dfprintk(FSCACHE, "NFS: get superblock cookie (0x%p/0x%p)\n",
-		 nfss, nfss->fscache);
 	return;
 
 non_unique:
@@ -211,9 +204,6 @@ void nfs_fscache_release_super_cookie(struct super_block *sb)
 {
 	struct nfs_server *nfss = NFS_SB(sb);
 
-	dfprintk(FSCACHE, "NFS: releasing superblock cookie (0x%p/0x%p)\n",
-		 nfss, nfss->fscache);
-
 	fscache_relinquish_cookie(nfss->fscache, NULL, false);
 	nfss->fscache = NULL;
 
@@ -270,8 +260,6 @@ void nfs_fscache_clear_inode(struct inode *inode)
 	struct nfs_inode *nfsi = NFS_I(inode);
 	struct fscache_cookie *cookie = nfs_i_fscache(inode);
 
-	dfprintk(FSCACHE, "NFS: clear cookie (0x%p/0x%p)\n", nfsi, cookie);
-
 	nfs_fscache_update_auxdata(&auxdata, inode);
 	fscache_relinquish_cookie(cookie, &auxdata, false);
 	nfsi->fscache = NULL;
-- 
1.8.3.1

[PATCH v1 7/7] NFS: Remove remaining usages of NFSDBG_FSCACHE

[Dave Wysochanski]

The NFS fscache interface has removed all dfprintks so remove the
NFSDBG_FSCACHE defines.

Signed-off-by: Dave Wysochanski <dwysocha@redhat.com>
---
 fs/nfs/fscache-index.c      | 2 --
 fs/nfs/fscache.c            | 2 --
 include/uapi/linux/nfs_fs.h | 2 +-
 3 files changed, 1 insertion(+), 5 deletions(-)

diff --git a/fs/nfs/fscache-index.c b/fs/nfs/fscache-index.c
index 4bd5ce736193..71bb4270641f 100644
--- a/fs/nfs/fscache-index.c
+++ b/fs/nfs/fscache-index.c
@@ -17,8 +17,6 @@
 #include "internal.h"
 #include "fscache.h"
 
-#define NFSDBG_FACILITY		NFSDBG_FSCACHE
-
 /*
  * Define the NFS filesystem for FS-Cache.  Upon registration FS-Cache sticks
  * the cookie for the top-level index object for NFS into here.  The top-level
diff --git a/fs/nfs/fscache.c b/fs/nfs/fscache.c
index d199ee103dc6..016e6cb13d28 100644
--- a/fs/nfs/fscache.c
+++ b/fs/nfs/fscache.c
@@ -21,8 +21,6 @@
 #include "fscache.h"
 #include "nfstrace.h"
 
-#define NFSDBG_FACILITY                NFSDBG_FSCACHE
-
 static struct rb_root nfs_fscache_keys = RB_ROOT;
 static DEFINE_SPINLOCK(nfs_fscache_keys_lock);
 
diff --git a/include/uapi/linux/nfs_fs.h b/include/uapi/linux/nfs_fs.h
index 3afe3767c55d..caa8d2234958 100644
--- a/include/uapi/linux/nfs_fs.h
+++ b/include/uapi/linux/nfs_fs.h
@@ -52,7 +52,7 @@
 #define NFSDBG_CALLBACK		0x0100
 #define NFSDBG_CLIENT		0x0200
 #define NFSDBG_MOUNT		0x0400
-#define NFSDBG_FSCACHE		0x0800
+#define NFSDBG_UNUSED		0x0800 /* unused; was FSCACHE */
 #define NFSDBG_PNFS		0x1000
 #define NFSDBG_PNFS_LD		0x2000
 #define NFSDBG_STATE		0x4000
-- 
1.8.3.1

Re: [PATCH v1 7/7] NFS: Remove remaining usages of NFSDBG_FSCACHE

[Trond Myklebust]

On Sun, 2021-10-03 at 15:22 -0400, Dave Wysochanski wrote:
> The NFS fscache interface has removed all dfprintks so remove the
> NFSDBG_FSCACHE defines.
> 
> Signed-off-by: Dave Wysochanski <dwysocha@redhat.com>
> ---
>  fs/nfs/fscache-index.c      | 2 --
>  fs/nfs/fscache.c            | 2 --
>  include/uapi/linux/nfs_fs.h | 2 +-
>  3 files changed, 1 insertion(+), 5 deletions(-)
> 
> diff --git a/fs/nfs/fscache-index.c b/fs/nfs/fscache-index.c
> index 4bd5ce736193..71bb4270641f 100644
> --- a/fs/nfs/fscache-index.c
> +++ b/fs/nfs/fscache-index.c
> @@ -17,8 +17,6 @@
>  #include "internal.h"
>  #include "fscache.h"
>  
> -#define NFSDBG_FACILITY                NFSDBG_FSCACHE
> -
>  /*
>   * Define the NFS filesystem for FS-Cache.  Upon registration FS-
> Cache sticks
>   * the cookie for the top-level index object for NFS into here.  The
> top-level
> diff --git a/fs/nfs/fscache.c b/fs/nfs/fscache.c
> index d199ee103dc6..016e6cb13d28 100644
> --- a/fs/nfs/fscache.c
> +++ b/fs/nfs/fscache.c
> @@ -21,8 +21,6 @@
>  #include "fscache.h"
>  #include "nfstrace.h"
>  
> -#define NFSDBG_FACILITY                NFSDBG_FSCACHE
> -
>  static struct rb_root nfs_fscache_keys = RB_ROOT;
>  static DEFINE_SPINLOCK(nfs_fscache_keys_lock);
>  
> diff --git a/include/uapi/linux/nfs_fs.h
> b/include/uapi/linux/nfs_fs.h
> index 3afe3767c55d..caa8d2234958 100644
> --- a/include/uapi/linux/nfs_fs.h
> +++ b/include/uapi/linux/nfs_fs.h
> @@ -52,7 +52,7 @@
>  #define NFSDBG_CALLBACK                0x0100
>  #define NFSDBG_CLIENT          0x0200
>  #define NFSDBG_MOUNT           0x0400
> -#define NFSDBG_FSCACHE         0x0800
> +#define NFSDBG_UNUSED          0x0800 /* unused; was FSCACHE */

Please leave the name and value unchanged. I'm fine with adding the
comment telling people not to bother using it, but this is supposed to
be part of a user API so it can't be modified unless we're absolutely
certain it isn't being used by anyone.

The other changes are fine.

>  #define NFSDBG_PNFS            0x1000
>  #define NFSDBG_PNFS_LD         0x2000
>  #define NFSDBG_STATE           0x4000

-- 
Trond Myklebust
Linux NFS client maintainer, Hammerspace
trond.myklebust@hammerspace.com

Re: [PATCH v1 7/7] NFS: Remove remaining usages of NFSDBG_FSCACHE

[David Wysochanski]

On Mon, Oct 4, 2021 at 11:57 AM Trond Myklebust <trondmy@hammerspace.com> wrote:
>
> On Sun, 2021-10-03 at 15:22 -0400, Dave Wysochanski wrote:
> > The NFS fscache interface has removed all dfprintks so remove the
> > NFSDBG_FSCACHE defines.
> >
> > Signed-off-by: Dave Wysochanski <dwysocha@redhat.com>
> > ---
> >  fs/nfs/fscache-index.c      | 2 --
> >  fs/nfs/fscache.c            | 2 --
> >  include/uapi/linux/nfs_fs.h | 2 +-
> >  3 files changed, 1 insertion(+), 5 deletions(-)
> >
> > diff --git a/fs/nfs/fscache-index.c b/fs/nfs/fscache-index.c
> > index 4bd5ce736193..71bb4270641f 100644
> > --- a/fs/nfs/fscache-index.c
> > +++ b/fs/nfs/fscache-index.c
> > @@ -17,8 +17,6 @@
> >  #include "internal.h"
> >  #include "fscache.h"
> >
> > -#define NFSDBG_FACILITY                NFSDBG_FSCACHE
> > -
> >  /*
> >   * Define the NFS filesystem for FS-Cache.  Upon registration FS-
> > Cache sticks
> >   * the cookie for the top-level index object for NFS into here.  The
> > top-level
> > diff --git a/fs/nfs/fscache.c b/fs/nfs/fscache.c
> > index d199ee103dc6..016e6cb13d28 100644
> > --- a/fs/nfs/fscache.c
> > +++ b/fs/nfs/fscache.c
> > @@ -21,8 +21,6 @@
> >  #include "fscache.h"
> >  #include "nfstrace.h"
> >
> > -#define NFSDBG_FACILITY                NFSDBG_FSCACHE
> > -
> >  static struct rb_root nfs_fscache_keys = RB_ROOT;
> >  static DEFINE_SPINLOCK(nfs_fscache_keys_lock);
> >
> > diff --git a/include/uapi/linux/nfs_fs.h
> > b/include/uapi/linux/nfs_fs.h
> > index 3afe3767c55d..caa8d2234958 100644
> > --- a/include/uapi/linux/nfs_fs.h
> > +++ b/include/uapi/linux/nfs_fs.h
> > @@ -52,7 +52,7 @@
> >  #define NFSDBG_CALLBACK                0x0100
> >  #define NFSDBG_CLIENT          0x0200
> >  #define NFSDBG_MOUNT           0x0400
> > -#define NFSDBG_FSCACHE         0x0800
> > +#define NFSDBG_UNUSED          0x0800 /* unused; was FSCACHE */
>
> Please leave the name and value unchanged. I'm fine with adding the
> comment telling people not to bother using it, but this is supposed to
> be part of a user API so it can't be modified unless we're absolutely
> certain it isn't being used by anyone.
>
Ok I will post a v2 and leave NFSDBG_FSCACHE defined for now but add
the comment.  But once there's no more usages in the kernel, I'm not sure
what the proper way to deprecate and remove it would be though.

I can post a nfs-utils patch to deprecate (or remove) the usage of fscache
in rpcdebug too. What's the proper way to deprecate and remove rpcdebug
flags, or is there some reason we don't ever want to do it?


> The other changes are fine.
>
Thanks for the review.

Re: [PATCH v1 0/7] Various NFS fscache cleanups

[David Howells]

Dave Wysochanski <dwysocha@redhat.com> wrote:

> This patchset is on top of David Howells fscache-iter-3 branch, which
> he posted v2 recently
> https://lore.kernel.org/all/163189104510.2509237.10805032055807259087.stgit@warthog.procyon.org.uk/
> 
> The first patch in this series should probably be merged into David Howells
> 3/8 patch of that series.  Otherwise, these patches are applied on top of
> his series, and this series is mostly orthogonal to fscache-iter-3 branch.

I've added it to my series, putting it in front of my nfs patch.  Your changes
there aren't really anything to do with mine, so I don't think they want
merging together.

David

Re: [PATCH v1 0/7] Various NFS fscache cleanups

[David Howells]

David Howells <dhowells@redhat.com> wrote:

> > This patchset is on top of David Howells fscache-iter-3 branch, which
> > he posted v2 recently
> > https://lore.kernel.org/all/163189104510.2509237.10805032055807259087.stgit@warthog.procyon.org.uk/
> > 
> > The first patch in this series should probably be merged into David Howells
> > 3/8 patch of that series.  Otherwise, these patches are applied on top of
> > his series, and this series is mostly orthogonal to fscache-iter-3 branch.
> 
> I've added it to my series, putting it in front of my nfs patch.  Your changes
> there aren't really anything to do with mine, so I don't think they want
> merging together.

Ah - I got confused by the "3/8 patch" bit and took patch 3, not patch 1.

David

Re: [PATCH v1 1/7] NFS: Fixup patch 3/8 of fscache-iter-3 v2

[David Howells]

Dave Wysochanski <dwysocha@redhat.com> wrote:

> 
> Handle failed return values of fscache_fallback_read_page() in
> switch statement.

After some discussion on IRC, the attached is probably better.  Returning 1
might result in 1 being returned through ->readpage(), which could be a
problem.

David
---
diff --git a/fs/nfs/fscache.c b/fs/nfs/fscache.c
index 5b0e78742444..68e266a37675 100644
--- a/fs/nfs/fscache.c
+++ b/fs/nfs/fscache.c
@@ -346,33 +346,18 @@ int __nfs_readpage_from_fscache(struct inode *inode, struct page *page)
 
 	ret = fscache_fallback_read_page(nfs_i_fscache(inode), page);
 	if (ret < 0) {
-		dfprintk(FSCACHE, "NFS:    readpage_from_fscache: "
-			 "fscache_fallback_read_page failed ret = %d\n", ret);
-		return ret;
-	}
-
-	switch (ret) {
-	case 0: /* Read completed synchronously */
-		dfprintk(FSCACHE,
-			 "NFS:    readpage_from_fscache: read successful\n");
-		nfs_inc_fscache_stats(inode, NFSIOS_FSCACHE_PAGES_READ_OK);
-		SetPageUptodate(page);
-		return 0;
-
-	case -ENOBUFS: /* inode not in cache */
-	case -ENODATA: /* page not in cache */
 		nfs_inc_fscache_stats(inode, NFSIOS_FSCACHE_PAGES_READ_FAIL);
 		dfprintk(FSCACHE,
-			 "NFS:    readpage_from_fscache %d\n", ret);
-		SetPageChecked(page);
-		return 1;
-
-	default:
-		dfprintk(FSCACHE, "NFS:    readpage_from_fscache %d\n", ret);
-		nfs_inc_fscache_stats(inode, NFSIOS_FSCACHE_PAGES_READ_FAIL);
+			 "NFS:    readpage_from_fscache failed %d\n", ret);
 		SetPageChecked(page);
+		return ret;
 	}
-	return ret;
+
+	/* Read completed synchronously */
+	dfprintk(FSCACHE, "NFS:    readpage_from_fscache: read successful\n");
+	nfs_inc_fscache_stats(inode, NFSIOS_FSCACHE_PAGES_READ_OK);
+	SetPageUptodate(page);
+	return 0;
 }
 
 /*

Re: [PATCH v1 1/7] NFS: Fixup patch 3/8 of fscache-iter-3 v2

[David Wysochanski]

On Tue, Oct 5, 2021 at 8:52 AM David Howells <dhowells@redhat.com> wrote:
>
> Dave Wysochanski <dwysocha@redhat.com> wrote:
>
> >
> > Handle failed return values of fscache_fallback_read_page() in
> > switch statement.
>
> After some discussion on IRC, the attached is probably better.  Returning 1
> might result in 1 being returned through ->readpage(), which could be a
> problem.
>
> David
> ---
> diff --git a/fs/nfs/fscache.c b/fs/nfs/fscache.c
> index 5b0e78742444..68e266a37675 100644
> --- a/fs/nfs/fscache.c
> +++ b/fs/nfs/fscache.c
> @@ -346,33 +346,18 @@ int __nfs_readpage_from_fscache(struct inode *inode, struct page *page)
>
>         ret = fscache_fallback_read_page(nfs_i_fscache(inode), page);
>         if (ret < 0) {
> -               dfprintk(FSCACHE, "NFS:    readpage_from_fscache: "
> -                        "fscache_fallback_read_page failed ret = %d\n", ret);
> -               return ret;
> -       }
> -
> -       switch (ret) {
> -       case 0: /* Read completed synchronously */
> -               dfprintk(FSCACHE,
> -                        "NFS:    readpage_from_fscache: read successful\n");
> -               nfs_inc_fscache_stats(inode, NFSIOS_FSCACHE_PAGES_READ_OK);
> -               SetPageUptodate(page);
> -               return 0;
> -
> -       case -ENOBUFS: /* inode not in cache */
> -       case -ENODATA: /* page not in cache */
>                 nfs_inc_fscache_stats(inode, NFSIOS_FSCACHE_PAGES_READ_FAIL);
>                 dfprintk(FSCACHE,
> -                        "NFS:    readpage_from_fscache %d\n", ret);
> -               SetPageChecked(page);
> -               return 1;
> -
> -       default:
> -               dfprintk(FSCACHE, "NFS:    readpage_from_fscache %d\n", ret);
> -               nfs_inc_fscache_stats(inode, NFSIOS_FSCACHE_PAGES_READ_FAIL);
> +                        "NFS:    readpage_from_fscache failed %d\n", ret);
>                 SetPageChecked(page);
> +               return ret;
>         }
> -       return ret;
> +
> +       /* Read completed synchronously */
> +       dfprintk(FSCACHE, "NFS:    readpage_from_fscache: read successful\n");
> +       nfs_inc_fscache_stats(inode, NFSIOS_FSCACHE_PAGES_READ_OK);
> +       SetPageUptodate(page);
> +       return 0;
>  }
>
>  /*
>

Yes this looks good.
Acked-by: Dave Wysochanski <dwysocha@redhat.com>