On Sun, Oct 3, 2021 at 3:23 PM Dave Wysochanski <[email protected]> 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 <[email protected]>
> ---
> 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
> [email protected]
> 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