History

NFS: Replace dprintk callsites in nfs_readpage(s)

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 The count of pages requested is reported. nfs_readpages does not wait for the READ requests to complete.

Chuck Lever committed 5 years ago

Commit d9f87741 parent 76497b12 files · +151 −6Browse files

Unified · Split

2 files
  1. fs/nfs/nfstrace.h +146 −0
  2. fs/nfs/read.c +5 −6
fs/nfs/nfstrace.h+146−0
@@ -862,6 +862,152 @@ TRACE_EVENT(nfs_sillyrename_unlink, · 861 unmodified lines
862862 )
863863 );
864864
865+TRACE_EVENT(nfs_aop_readpage,
866+ TP_PROTO(
867+ const struct inode *inode,
868+ struct page *page
869+ ),
870+
871+ TP_ARGS(inode, page),
872+
873+ TP_STRUCT__entry(
874+ __field(dev_t, dev)
875+ __field(u32, fhandle)
876+ __field(u64, fileid)
877+ __field(u64, version)
878+ __field(loff_t, offset)
879+ ),
880+
881+ TP_fast_assign(
882+ const struct nfs_inode *nfsi = NFS_I(inode);
883+
884+ __entry->dev = inode->i_sb->s_dev;
885+ __entry->fileid = nfsi->fileid;
886+ __entry->fhandle = nfs_fhandle_hash(&nfsi->fh);
887+ __entry->version = inode_peek_iversion_raw(inode);
888+ __entry->offset = page_index(page) << PAGE_SHIFT;
889+ ),
890+
891+ TP_printk(
892+ "fileid=%02x:%02x:%llu fhandle=0x%08x version=%llu offset=%lld",
893+ MAJOR(__entry->dev), MINOR(__entry->dev),
894+ (unsigned long long)__entry->fileid,
895+ __entry->fhandle, __entry->version,
896+ __entry->offset
897+ )
898+);
899+
900+TRACE_EVENT(nfs_aop_readpage_done,
901+ TP_PROTO(
902+ const struct inode *inode,
903+ struct page *page,
904+ int ret
905+ ),
906+
907+ TP_ARGS(inode, page, ret),
908+
909+ TP_STRUCT__entry(
910+ __field(dev_t, dev)
911+ __field(u32, fhandle)
912+ __field(int, ret)
913+ __field(u64, fileid)
914+ __field(u64, version)
915+ __field(loff_t, offset)
916+ ),
917+
918+ TP_fast_assign(
919+ const struct nfs_inode *nfsi = NFS_I(inode);
920+
921+ __entry->dev = inode->i_sb->s_dev;
922+ __entry->fileid = nfsi->fileid;
923+ __entry->fhandle = nfs_fhandle_hash(&nfsi->fh);
924+ __entry->version = inode_peek_iversion_raw(inode);
925+ __entry->offset = page_index(page) << PAGE_SHIFT;
926+ __entry->ret = ret;
927+ ),
928+
929+ TP_printk(
930+ "fileid=%02x:%02x:%llu fhandle=0x%08x version=%llu offset=%lld ret=%d",
931+ MAJOR(__entry->dev), MINOR(__entry->dev),
932+ (unsigned long long)__entry->fileid,
933+ __entry->fhandle, __entry->version,
934+ __entry->offset, __entry->ret
935+ )
936+);
937+
938+TRACE_EVENT(nfs_aop_readahead,
939+ TP_PROTO(
940+ const struct inode *inode,
941+ unsigned int nr_pages
942+ ),
943+
944+ TP_ARGS(inode, nr_pages),
945+
946+ TP_STRUCT__entry(
947+ __field(dev_t, dev)
948+ __field(u32, fhandle)
949+ __field(u64, fileid)
950+ __field(u64, version)
951+ __field(unsigned int, nr_pages)
952+ ),
953+
954+ TP_fast_assign(
955+ const struct nfs_inode *nfsi = NFS_I(inode);
956+
957+ __entry->dev = inode->i_sb->s_dev;
958+ __entry->fileid = nfsi->fileid;
959+ __entry->fhandle = nfs_fhandle_hash(&nfsi->fh);
960+ __entry->version = inode_peek_iversion_raw(inode);
961+ __entry->nr_pages = nr_pages;
962+ ),
963+
964+ TP_printk(
965+ "fileid=%02x:%02x:%llu fhandle=0x%08x version=%llu nr_pages=%u",
966+ MAJOR(__entry->dev), MINOR(__entry->dev),
967+ (unsigned long long)__entry->fileid,
968+ __entry->fhandle, __entry->version,
969+ __entry->nr_pages
970+ )
971+);
972+
973+TRACE_EVENT(nfs_aop_readahead_done,
974+ TP_PROTO(
975+ const struct inode *inode,
976+ unsigned int nr_pages,
977+ int ret
978+ ),
979+
980+ TP_ARGS(inode, nr_pages, ret),
981+
982+ TP_STRUCT__entry(
983+ __field(dev_t, dev)
984+ __field(u32, fhandle)
985+ __field(int, ret)
986+ __field(u64, fileid)
987+ __field(u64, version)
988+ __field(unsigned int, nr_pages)
989+ ),
990+
991+ TP_fast_assign(
992+ const struct nfs_inode *nfsi = NFS_I(inode);
993+
994+ __entry->dev = inode->i_sb->s_dev;
995+ __entry->fileid = nfsi->fileid;
996+ __entry->fhandle = nfs_fhandle_hash(&nfsi->fh);
997+ __entry->version = inode_peek_iversion_raw(inode);
998+ __entry->nr_pages = nr_pages;
999+ __entry->ret = ret;
1000+ ),
1001+
1002+ TP_printk(
1003+ "fileid=%02x:%02x:%llu fhandle=0x%08x version=%llu nr_pages=%u ret=%d",
1004+ MAJOR(__entry->dev), MINOR(__entry->dev),
1005+ (unsigned long long)__entry->fileid,
1006+ __entry->fhandle, __entry->version,
1007+ __entry->nr_pages, __entry->ret
1008+ )
1009+);
1010+
8651011 TRACE_EVENT(nfs_initiate_read,
8661012 TP_PROTO(
8671013 const struct nfs_pgio_header *hdr
fs/nfs/read.c+5−6
@@ -337,8 +337,7 @@ int nfs_readpage(struct file *file, struct page *page) · 336 unmodified lines
337337 struct inode *inode = page_file_mapping(page)->host;
338338 int ret;
339339
340− dprintk("NFS: nfs_readpage (%p %ld@%lu)\n",
341− page, PAGE_SIZE, page_index(page));
340+ trace_nfs_aop_readpage(inode, page);
342341 nfs_inc_stats(inode, NFSIOS_VFSREADPAGE);
343342
344343 /*
@@ -390,9 +389,11 @@ out_wait: · 45 unmodified lines
390389 }
391390 out:
392391 put_nfs_open_context(desc.ctx);
392+ trace_nfs_aop_readpage_done(inode, page, ret);
393393 return ret;
394394 out_unlock:
395395 unlock_page(page);
396+ trace_nfs_aop_readpage_done(inode, page, ret);
396397 return ret;
397398 }
398399
@@ -403,10 +404,7 @@ int nfs_readpages(struct file *file, struct address_space *mapping, · 4 unmodified lines
403404 struct inode *inode = mapping->host;
404405 int ret;
405406
406− dprintk("NFS: nfs_readpages (%s/%Lu %d)\n",
407− inode->i_sb->s_id,
408− (unsigned long long)NFS_FILEID(inode),
409− nr_pages);
407+ trace_nfs_aop_readahead(inode, nr_pages);
410408 nfs_inc_stats(inode, NFSIOS_VFSREADPAGES);
411409
412410 ret = -ESTALE;
@@ -439,6 +437,7 @@ int nfs_readpages(struct file *file, struct address_space *mapping, · 26 unmodified lines
439437 read_complete:
440438 put_nfs_open_context(desc.ctx);
441439 out:
440+ trace_nfs_aop_readahead_done(inode, nr_pages, ret);
442441 return ret;
443442 }
444443