From: Chuck Lever III <chuck.lever@oracle.com>
To: David Wysochanski <dwysocha@redhat.com>
Cc: Trond Myklebust <trondmy@hammerspace.com>,
Linux NFS Mailing List <linux-nfs@vger.kernel.org>
Subject: Re: [PATCH v4 5/7] NFS: Replace dprintk callsites in nfs_readpage(s)
Date: Tue, 2 Nov 2021 19:41:09 +0000 [thread overview]
Message-ID: <A0A92DE7-78F5-4217-9C43-8AF7C0C8644A@oracle.com> (raw)
In-Reply-To: <CALF+zOm1gCuVOJ5bEf6_t=PvmTQ4KQPCYQsgLUenxMNhzUx_oQ@mail.gmail.com>
> On Nov 2, 2021, at 3:36 PM, David Wysochanski <dwysocha@redhat.com> wrote:
>
> On Sat, Oct 16, 2021 at 6:03 PM Chuck Lever <chuck.lever@oracle.com> wrote:
>>
>> These new events report slightly different information for readpage
>> and readpages/readahead.
>>
>> For readpage:
>> fsx-1387 [006] 380.761896: nfs_aop_readpage: fileid=00:28:2 fhandle=0x36fbbe51 version=1752899355910932437 offset=131072
>> fsx-1387 [006] 380.761900: nfs_aop_readpage_done: fileid=00:28:2 fhandle=0x36fbbe51 version=1752899355910932437 offset=131072 ret=0
>>
>> The index of a synchronous single-page read is reported.
>>
>> For readpages:
>>
>> fsx-1387 [006] 380.760847: nfs_aop_readahead: fileid=00:28:2 fhandle=0x36fbbe51 version=1752899355909932456 nr_pages=3
>> fsx-1387 [006] 380.760853: nfs_aop_readahead_done: fileid=00:28:2 fhandle=0x36fbbe51 version=1752899355909932456 nr_pages=3 ret=0
>>
>
> Chuck,
>
> I was doing more debugging and thought about the readahead trace event.
> Are you set on "nr_pages" output here, or was that mainly due to the parameter?
> I think maybe it would be better to have byte fields, "offset" and
> "count" like the other IO tracepoints (trace_nfs_initiate_read() for
> example). Or do you see some advantages to using nr_pages?
>
> We can get the offset with lru_to_page(pages) and of course "count"
> with nr_pages*PAGE_SIZE
IMO offset is interesting to include, but I don't think multiplying
by PAGE_SIZE adds much value. If you disagree, you can always tuck
that into the tracepoint's TP_fast_assign section.
>> The count of pages requested is reported. nfs_readpages does not
>> wait for the READ requests to complete.
>>
>> Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
>> ---
>> fs/nfs/nfstrace.h | 146 +++++++++++++++++++++++++++++++++++++++++++++++++++++
>> fs/nfs/read.c | 11 ++--
>> 2 files changed, 151 insertions(+), 6 deletions(-)
>>
>> diff --git a/fs/nfs/nfstrace.h b/fs/nfs/nfstrace.h
>> index e9be65b52bfe..898308780df8 100644
>> --- a/fs/nfs/nfstrace.h
>> +++ b/fs/nfs/nfstrace.h
>> @@ -862,6 +862,152 @@ TRACE_EVENT(nfs_sillyrename_unlink,
>> )
>> );
>>
>> +TRACE_EVENT(nfs_aop_readpage,
>> + TP_PROTO(
>> + const struct inode *inode,
>> + struct page *page
>> + ),
>> +
>> + TP_ARGS(inode, page),
>> +
>> + TP_STRUCT__entry(
>> + __field(dev_t, dev)
>> + __field(u32, fhandle)
>> + __field(u64, fileid)
>> + __field(u64, version)
>> + __field(loff_t, offset)
>> + ),
>> +
>> + TP_fast_assign(
>> + const struct nfs_inode *nfsi = NFS_I(inode);
>> +
>> + __entry->dev = inode->i_sb->s_dev;
>> + __entry->fileid = nfsi->fileid;
>> + __entry->fhandle = nfs_fhandle_hash(&nfsi->fh);
>> + __entry->version = inode_peek_iversion_raw(inode);
>> + __entry->offset = page_index(page) << PAGE_SHIFT;
>> + ),
>> +
>> + TP_printk(
>> + "fileid=%02x:%02x:%llu fhandle=0x%08x version=%llu offset=%lld",
>> + MAJOR(__entry->dev), MINOR(__entry->dev),
>> + (unsigned long long)__entry->fileid,
>> + __entry->fhandle, __entry->version,
>> + __entry->offset
>> + )
>> +);
>> +
>> +TRACE_EVENT(nfs_aop_readpage_done,
>> + TP_PROTO(
>> + const struct inode *inode,
>> + struct page *page,
>> + int ret
>> + ),
>> +
>> + TP_ARGS(inode, page, ret),
>> +
>> + TP_STRUCT__entry(
>> + __field(dev_t, dev)
>> + __field(u32, fhandle)
>> + __field(int, ret)
>> + __field(u64, fileid)
>> + __field(u64, version)
>> + __field(loff_t, offset)
>> + ),
>> +
>> + TP_fast_assign(
>> + const struct nfs_inode *nfsi = NFS_I(inode);
>> +
>> + __entry->dev = inode->i_sb->s_dev;
>> + __entry->fileid = nfsi->fileid;
>> + __entry->fhandle = nfs_fhandle_hash(&nfsi->fh);
>> + __entry->version = inode_peek_iversion_raw(inode);
>> + __entry->offset = page_index(page) << PAGE_SHIFT;
>> + __entry->ret = ret;
>> + ),
>> +
>> + TP_printk(
>> + "fileid=%02x:%02x:%llu fhandle=0x%08x version=%llu offset=%lld ret=%d",
>> + MAJOR(__entry->dev), MINOR(__entry->dev),
>> + (unsigned long long)__entry->fileid,
>> + __entry->fhandle, __entry->version,
>> + __entry->offset, __entry->ret
>> + )
>> +);
>> +
>> +TRACE_EVENT(nfs_aop_readahead,
>> + TP_PROTO(
>> + const struct inode *inode,
>> + unsigned int nr_pages
>> + ),
>> +
>> + TP_ARGS(inode, nr_pages),
>> +
>> + TP_STRUCT__entry(
>> + __field(dev_t, dev)
>> + __field(u32, fhandle)
>> + __field(u64, fileid)
>> + __field(u64, version)
>> + __field(unsigned int, nr_pages)
>> + ),
>> +
>> + TP_fast_assign(
>> + const struct nfs_inode *nfsi = NFS_I(inode);
>> +
>> + __entry->dev = inode->i_sb->s_dev;
>> + __entry->fileid = nfsi->fileid;
>> + __entry->fhandle = nfs_fhandle_hash(&nfsi->fh);
>> + __entry->version = inode_peek_iversion_raw(inode);
>> + __entry->nr_pages = nr_pages;
>> + ),
>> +
>> + TP_printk(
>> + "fileid=%02x:%02x:%llu fhandle=0x%08x version=%llu nr_pages=%u",
>> + MAJOR(__entry->dev), MINOR(__entry->dev),
>> + (unsigned long long)__entry->fileid,
>> + __entry->fhandle, __entry->version,
>> + __entry->nr_pages
>> + )
>> +);
>> +
>> +TRACE_EVENT(nfs_aop_readahead_done,
>> + TP_PROTO(
>> + const struct inode *inode,
>> + unsigned int nr_pages,
>> + int ret
>> + ),
>> +
>> + TP_ARGS(inode, nr_pages, ret),
>> +
>> + TP_STRUCT__entry(
>> + __field(dev_t, dev)
>> + __field(u32, fhandle)
>> + __field(int, ret)
>> + __field(u64, fileid)
>> + __field(u64, version)
>> + __field(unsigned int, nr_pages)
>> + ),
>> +
>> + TP_fast_assign(
>> + const struct nfs_inode *nfsi = NFS_I(inode);
>> +
>> + __entry->dev = inode->i_sb->s_dev;
>> + __entry->fileid = nfsi->fileid;
>> + __entry->fhandle = nfs_fhandle_hash(&nfsi->fh);
>> + __entry->version = inode_peek_iversion_raw(inode);
>> + __entry->nr_pages = nr_pages;
>> + __entry->ret = ret;
>> + ),
>> +
>> + TP_printk(
>> + "fileid=%02x:%02x:%llu fhandle=0x%08x version=%llu nr_pages=%u ret=%d",
>> + MAJOR(__entry->dev), MINOR(__entry->dev),
>> + (unsigned long long)__entry->fileid,
>> + __entry->fhandle, __entry->version,
>> + __entry->nr_pages, __entry->ret
>> + )
>> +);
>> +
>> TRACE_EVENT(nfs_initiate_read,
>> TP_PROTO(
>> const struct nfs_pgio_header *hdr
>> diff --git a/fs/nfs/read.c b/fs/nfs/read.c
>> index 08d6cc57cbc3..c8273d4b12ad 100644
>> --- a/fs/nfs/read.c
>> +++ b/fs/nfs/read.c
>> @@ -337,8 +337,7 @@ int nfs_readpage(struct file *file, struct page *page)
>> struct inode *inode = page_file_mapping(page)->host;
>> int ret;
>>
>> - dprintk("NFS: nfs_readpage (%p %ld@%lu)\n",
>> - page, PAGE_SIZE, page_index(page));
>> + trace_nfs_aop_readpage(inode, page);
>> nfs_inc_stats(inode, NFSIOS_VFSREADPAGE);
>>
>> /*
>> @@ -390,9 +389,11 @@ int nfs_readpage(struct file *file, struct page *page)
>> }
>> out:
>> put_nfs_open_context(desc.ctx);
>> + trace_nfs_aop_readpage_done(inode, page, ret);
>> return ret;
>> out_unlock:
>> unlock_page(page);
>> + trace_nfs_aop_readpage_done(inode, page, ret);
>> return ret;
>> }
>>
>> @@ -403,10 +404,7 @@ int nfs_readpages(struct file *file, struct address_space *mapping,
>> struct inode *inode = mapping->host;
>> int ret;
>>
>> - dprintk("NFS: nfs_readpages (%s/%Lu %d)\n",
>> - inode->i_sb->s_id,
>> - (unsigned long long)NFS_FILEID(inode),
>> - nr_pages);
>> + trace_nfs_aop_readahead(inode, nr_pages);
>> nfs_inc_stats(inode, NFSIOS_VFSREADPAGES);
>>
>> ret = -ESTALE;
>> @@ -439,6 +437,7 @@ int nfs_readpages(struct file *file, struct address_space *mapping,
>> read_complete:
>> put_nfs_open_context(desc.ctx);
>> out:
>> + trace_nfs_aop_readahead_done(inode, nr_pages, ret);
>> return ret;
>> }
--
Chuck Lever
next prev parent reply other threads:[~2021-11-02 19:41 UTC|newest]
Thread overview: 13+ messages / expand[flat|nested] mbox.gz Atom feed top
2021-10-16 22:02 [PATCH v4 0/7] Update RPC task pid as displayed by tracepoints Chuck Lever
2021-10-16 22:02 ` [PATCH v4 1/7] SUNRPC: Tracepoints should display tk_pid and cl_clid as a fixed-size field Chuck Lever
2021-10-16 22:02 ` [PATCH v4 2/7] SUNRPC: Avoid NULL pointer dereferences in tracepoints Chuck Lever
2021-10-20 18:43 ` Trond Myklebust
2021-10-20 19:39 ` Chuck Lever III
2021-10-20 20:09 ` Trond Myklebust
2021-10-16 22:02 ` [PATCH v4 3/7] SUNRPC: Use BIT() macro in rpc_show_xprt_state() Chuck Lever
2021-10-16 22:02 ` [PATCH v4 4/7] SUNRPC: Don't dereference xprt->snd_task if it's a cookie Chuck Lever
2021-10-16 22:02 ` [PATCH v4 5/7] NFS: Replace dprintk callsites in nfs_readpage(s) Chuck Lever
2021-11-02 19:36 ` David Wysochanski
2021-11-02 19:41 ` Chuck Lever III [this message]
2021-10-16 22:02 ` [PATCH v4 6/7] SUNRPC: Trace calls to .rpc_call_done Chuck Lever
2021-10-16 22:03 ` [PATCH v4 7/7] NFS: Remove --> and <-- dprintk call sites Chuck Lever
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=A0A92DE7-78F5-4217-9C43-8AF7C0C8644A@oracle.com \
--to=chuck.lever@oracle.com \
--cc=dwysocha@redhat.com \
--cc=linux-nfs@vger.kernel.org \
--cc=trondmy@hammerspace.com \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.