From efc1672ec6072c0aba7c720c4d0d2518a1d9bedb Mon Sep 17 00:00:00 2001 From: Patrick Farrell Date: Fri, 4 Mar 2022 10:34:01 -0500 Subject: [PATCH] LU-15317 llite: Add COMPLETED iotrace messages It's very useful to see how long an I/O call took. There are other ways to do this, but the goal is for iotrace to provide all necessary information for basic I/O performance analysis, so we add COMPLETED messages to iotrace. Lustre-change: https://review.whamcloud.com/46484/ Lustre-commit: 1c90d638a8d7993f5cbd70680d33052e888da6c3 (tbd) Signed-off-by: Patrick Farrell Change-Id: I17f52ebc87a31d5ba34f63dc8b6a279e83cd10ef Reviewed-on: https://review.whamcloud.com/46703 Tested-by: jenkins Tested-by: Maloo Reviewed-by: Andreas Dilger --- lustre/llite/file.c | 12 ++++++++++++ lustre/llite/llite_mmap.c | 10 ++++++++++ 2 files changed, 22 insertions(+) diff --git a/lustre/llite/file.c b/lustre/llite/file.c index 5e8bbb5..c8e2fc8 100644 --- a/lustre/llite/file.c +++ b/lustre/llite/file.c @@ -1977,6 +1977,12 @@ out: ktime_us_delta(ktime_get(), kstart)); } + CDEBUG(D_IOTRACE, + "COMPLETED: file %s:"DFID", ppos: %lld, count: %zu\n", + file_dentry(file)->d_name.name, + PFID(ll_inode2fid(file_inode(file))), iocb->ki_pos, + iov_iter_count(to)); + RETURN(result); } @@ -2121,6 +2127,12 @@ out: ktime_us_delta(ktime_get(), kstart)); } + CDEBUG(D_IOTRACE, + "COMPLETED: file %s:"DFID", ppos: %lld, count: %zu\n", + file_dentry(file)->d_name.name, + PFID(ll_inode2fid(file_inode(file))), iocb->ki_pos, + iov_iter_count(from)); + RETURN(rc_normal); } diff --git a/lustre/llite/llite_mmap.c b/lustre/llite/llite_mmap.c index c16404c..7242108 100644 --- a/lustre/llite/llite_mmap.c +++ b/lustre/llite/llite_mmap.c @@ -425,6 +425,11 @@ restart: ktime_us_delta(ktime_get(), kstart)); } + CDEBUG(D_IOTRACE, + "COMPLETED: "DFID": vma=%p start=%#lx end=%#lx vm_flags=%#lx idx=%lu\n", + PFID(&ll_i2info(file_inode(vma->vm_file))->lli_fid), + vma, vma->vm_start, vma->vm_end, vma->vm_flags, vmf->pgoff); + return result; } @@ -499,6 +504,11 @@ static vm_fault_t ll_page_mkwrite(struct vm_area_struct *vma, ktime_us_delta(ktime_get(), kstart)); } + CDEBUG(D_IOTRACE, + "COMPLETED: "DFID": vma=%p start=%#lx end=%#lx vm_flags=%#lx idx=%lu\n", + PFID(&ll_i2info(file_inode(vma->vm_file))->lli_fid), + vma, vma->vm_start, vma->vm_end, vma->vm_flags, + vmf->page->index); return result; } -- 1.8.3.1