[PATCH 18/28] lustre: llite: Add COMPLETED iotrace messages

[James Simmons <jsimmons@xxxxxxxxxxxxx>]

From: Patrick Farrell <pfarrell@xxxxxxxxxxxxx>

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.

WC-bug-id: https://jira.whamcloud.com/browse/LU-15317
Lustre-commit: d48b10cef36d74cc6 ("LU-15317 llite: Add COMPLETED iotrace messages")
Signed-off-by: Patrick Farrell <pfarrell@xxxxxxxxxxxxx>
Reviewed-on: https://review.whamcloud.com/46484
Reviewed-by: Sebastien Buisson <sbuisson@xxxxxxx>
Reviewed-by: Andreas Dilger <adilger@xxxxxxxxxxxxx>
Reviewed-by: Oleg Drokin <green@xxxxxxxxxxxxx>
Signed-off-by: James Simmons <jsimmons@xxxxxxxxxxxxx>
---
 fs/lustre/llite/file.c       | 12 ++++++++++++
 fs/lustre/llite/llite_mmap.c | 12 +++++++++++-
 2 files changed, 23 insertions(+), 1 deletion(-)

diff --git a/fs/lustre/llite/file.c b/fs/lustre/llite/file.c
index 5be77e8..efe117d 100644
--- a/fs/lustre/llite/file.c
+++ b/fs/lustre/llite/file.c
@@ -2013,6 +2013,12 @@ static ssize_t ll_file_read_iter(struct kiocb *iocb, struct iov_iter *to)
 				   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;
 }
 
@@ -2158,6 +2164,12 @@ static ssize_t ll_file_write_iter(struct kiocb *iocb, struct iov_iter *from)
 				   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/fs/lustre/llite/llite_mmap.c b/fs/lustre/llite/llite_mmap.c
index 2e762b1..4acc7ee 100644
--- a/fs/lustre/llite/llite_mmap.c
+++ b/fs/lustre/llite/llite_mmap.c
@@ -415,7 +415,7 @@ static vm_fault_t ll_fault(struct vm_fault *vmf)
 			goto restart;
 		}
 
-		result = VM_FAULT_LOCKED;
+		result |= VM_FAULT_LOCKED;
 	}
 	sigprocmask(SIG_SETMASK, &old, NULL);
 
@@ -430,6 +430,11 @@ static vm_fault_t ll_fault(struct vm_fault *vmf)
 				   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;
 }
 
@@ -498,6 +503,11 @@ static vm_fault_t ll_page_mkwrite(struct vm_fault *vmf)
 				   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 ret;
 }
 
-- 
1.8.3.1