Re: xfs-trace-ilock-more

[Mark Fasheh <mfasheh@suse.de>]

On Sun, Dec 18, 2011 at 03:27:34PM -0500, Christoph Hellwig wrote:
> Given that the patch is fairly clean can you send it to us for
> inclusion?

Here goes. I updated the patch for 3.2 and of course gave it a quick test.
	--Mark

--
Mark Fasheh

From: Mark Fasheh <mfasheh@suse.com>

[PATCH] xfs: add more ilock tracing

Let's get a trace of the amount of time spent in xfs_ilock(). This has
helped us (SUSE) in investigating read/write performance issues in the past
when ilock() contention has come up as a possibile issue.

Signed-off-by: Mark Fasheh <mfasheh@suse.de>
---
 fs/xfs/xfs_iget.c  |   16 ++++++++++++----
 fs/xfs/xfs_trace.h |   13 ++++++++-----
 2 files changed, 20 insertions(+), 9 deletions(-)

diff --git a/fs/xfs/xfs_iget.c b/fs/xfs/xfs_iget.c
index 0fa98b1..b83108b 100644
--- a/fs/xfs/xfs_iget.c
+++ b/fs/xfs/xfs_iget.c
@@ -543,6 +543,8 @@ xfs_ilock(
 	xfs_inode_t		*ip,
 	uint			lock_flags)
 {
+	unsigned long start = jiffies;
+
 	/*
 	 * You can't set both SHARED and EXCL for the same lock,
 	 * and only XFS_IOLOCK_SHARED, XFS_IOLOCK_EXCL, XFS_ILOCK_SHARED,
@@ -564,7 +566,7 @@ xfs_ilock(
 	else if (lock_flags & XFS_ILOCK_SHARED)
 		mraccess_nested(&ip->i_lock, XFS_ILOCK_DEP(lock_flags));
 
-	trace_xfs_ilock(ip, lock_flags, _RET_IP_);
+	trace_xfs_ilock(ip, lock_flags, start, _RET_IP_);
 }
 
 /*
@@ -584,6 +586,8 @@ xfs_ilock_nowait(
 	xfs_inode_t		*ip,
 	uint			lock_flags)
 {
+	unsigned long start = jiffies;
+
 	/*
 	 * You can't set both SHARED and EXCL for the same lock,
 	 * and only XFS_IOLOCK_SHARED, XFS_IOLOCK_EXCL, XFS_ILOCK_SHARED,
@@ -609,7 +613,7 @@ xfs_ilock_nowait(
 		if (!mrtryaccess(&ip->i_lock))
 			goto out_undo_iolock;
 	}
-	trace_xfs_ilock_nowait(ip, lock_flags, _RET_IP_);
+	trace_xfs_ilock_nowait(ip, lock_flags, start, _RET_IP_);
 	return 1;
 
  out_undo_iolock:
@@ -638,6 +642,8 @@ xfs_iunlock(
 	xfs_inode_t		*ip,
 	uint			lock_flags)
 {
+	unsigned long start = jiffies;
+
 	/*
 	 * You can't set both SHARED and EXCL for the same lock,
 	 * and only XFS_IOLOCK_SHARED, XFS_IOLOCK_EXCL, XFS_ILOCK_SHARED,
@@ -671,7 +677,7 @@ xfs_iunlock(
 		xfs_trans_unlocked_item(ip->i_itemp->ili_item.li_ailp,
 					(xfs_log_item_t*)(ip->i_itemp));
 	}
-	trace_xfs_iunlock(ip, lock_flags, _RET_IP_);
+	trace_xfs_iunlock(ip, lock_flags, start, _RET_IP_);
 }
 
 /*
@@ -683,6 +689,8 @@ xfs_ilock_demote(
 	xfs_inode_t		*ip,
 	uint			lock_flags)
 {
+	unsigned long start = jiffies;
+
 	ASSERT(lock_flags & (XFS_IOLOCK_EXCL|XFS_ILOCK_EXCL));
 	ASSERT((lock_flags & ~(XFS_IOLOCK_EXCL|XFS_ILOCK_EXCL)) == 0);
 
@@ -691,7 +699,7 @@ xfs_ilock_demote(
 	if (lock_flags & XFS_IOLOCK_EXCL)
 		mrdemote(&ip->i_iolock);
 
-	trace_xfs_ilock_demote(ip, lock_flags, _RET_IP_);
+	trace_xfs_ilock_demote(ip, lock_flags, start, _RET_IP_);
 }
 
 #ifdef DEBUG
diff --git a/fs/xfs/xfs_trace.h b/fs/xfs/xfs_trace.h
index 4940357..ef5523a 100644
--- a/fs/xfs/xfs_trace.h
+++ b/fs/xfs/xfs_trace.h
@@ -507,32 +507,35 @@ DEFINE_BUF_ITEM_EVENT(xfs_trans_binval);
 
 DECLARE_EVENT_CLASS(xfs_lock_class,
 	TP_PROTO(struct xfs_inode *ip, unsigned lock_flags,
-		 unsigned long caller_ip),
-	TP_ARGS(ip,  lock_flags, caller_ip),
+		 unsigned long start, unsigned long caller_ip),
+	TP_ARGS(ip,lock_flags, start, caller_ip),
 	TP_STRUCT__entry(
 		__field(dev_t, dev)
 		__field(xfs_ino_t, ino)
 		__field(int, lock_flags)
+		__field(unsigned long, start)
 		__field(unsigned long, caller_ip)
 	),
 	TP_fast_assign(
 		__entry->dev = VFS_I(ip)->i_sb->s_dev;
 		__entry->ino = ip->i_ino;
 		__entry->lock_flags = lock_flags;
+		__entry->start = start;
 		__entry->caller_ip = caller_ip;
 	),
-	TP_printk("dev %d:%d ino 0x%llx flags %s caller %pf",
+	TP_printk("dev %d:%d ino 0x%llx flags %s wait %lu caller %pf",
 		  MAJOR(__entry->dev), MINOR(__entry->dev),
 		  __entry->ino,
 		  __print_flags(__entry->lock_flags, "|", XFS_LOCK_FLAGS),
+		  (jiffies - __entry->start),
 		  (void *)__entry->caller_ip)
 )
 
 #define DEFINE_LOCK_EVENT(name) \
 DEFINE_EVENT(xfs_lock_class, name, \
 	TP_PROTO(struct xfs_inode *ip, unsigned lock_flags, \
-		 unsigned long caller_ip), \
-	TP_ARGS(ip,  lock_flags, caller_ip))
+		 unsigned long start, unsigned long caller_ip),	\
+	TP_ARGS(ip,  lock_flags, start, caller_ip))
 DEFINE_LOCK_EVENT(xfs_ilock);
 DEFINE_LOCK_EVENT(xfs_ilock_nowait);
 DEFINE_LOCK_EVENT(xfs_ilock_demote);
-- 
1.7.6

_______________________________________________
xfs mailing list
xfs@oss.sgi.com
http://oss.sgi.com/mailman/listinfo/xfs