> On Oct 7, 2021, at 3:16 PM, David Wysochanski <dwysocha@xxxxxxxxxx> wrote:
>
> On Thu, Oct 7, 2021 at 12:22 PM Chuck Lever III <chuck.lever@xxxxxxxxxx> wrote:
>>
>>
>>
>>> On Oct 7, 2021, at 12:17 PM, Chuck Lever <chuck.lever@xxxxxxxxxx> wrote:
>>>
>>> There are two new events that report slightly different information
>>> for readpage and readpages.
>>>
>>> For readpage:
>>> fsx-1387 [006] 380.761896: nfs_aops_readpage: fileid=00:28:2 fhandle=0x36fbbe51 version=1752899355910932437 page_index=32
>>>
>>> The index of a synchronous single-page read is reported.
>>>
>>> For readpages:
>>>
>>> fsx-1387 [006] 380.760847: nfs_aops_readpages: fileid=00:28:2 fhandle=0x36fbbe51 version=1752899355909932456 nr_pages=3
>>>
>>> The count of pages requested is reported. readpages does not wait
>>> for the READ requests to complete.
>>>
>>> Signed-off-by: Chuck Lever <chuck.lever@xxxxxxxxxx>
>>
>> Well obviously I forgot to update the patch description.
>> I can send a v3 later to do that.
>>
>>
>
> Why not just call the tracepoints nfs_readpage and nfs_readpages?
Because there is already an nfs_readpage_done() tracepoint.
>>> ---
>>> 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..85e67b326bcd 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(pgoff_t, index)
>>> + ),
>>> +
>>> + 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->index = page_index(page);
>>> + ),
>>> +
>>> + TP_printk(
>>> + "fileid=%02x:%02x:%llu fhandle=0x%08x version=%llu page_index=%lu",
>>> + MAJOR(__entry->dev), MINOR(__entry->dev),
>>> + (unsigned long long)__entry->fileid,
>>> + __entry->fhandle, __entry->version,
>>> + __entry->index
>>> + )
>>> +);
>>> +
>>> +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(pgoff_t, index)
>>> + ),
>>> +
>>> + 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->index = page_index(page);
>>> + __entry->ret = ret;
>>> + ),
>>> +
>>> + TP_printk(
>>> + "fileid=%02x:%02x:%llu fhandle=0x%08x version=%llu page_index=%lu ret=%d",
>>> + MAJOR(__entry->dev), MINOR(__entry->dev),
>>> + (unsigned long long)__entry->fileid,
>>> + __entry->fhandle, __entry->version,
>>> + __entry->index, __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
--
Chuck Lever
