xfs: optimise away log forces on timestamp updates for fdatasync
PATCH 1/1 xfs: optimise away log forces on timestamp updates for fdatasync
From: Dave Chinner <[email protected]>
xfs: timestamp updates cause excessive fdatasync log traffic
Sage Weil reported that a ceph test workload was writing to the log on every fdatasync during an overwrite workload. Event tracing showed that the only metadata modification being made was the timestamp updates during the write(2) syscall, but fdatasync(2) is supposed to ignore them. The key observation was that the transactions in the log all looked like this:
INODE: #regs: 4 ino: 0x8b flags: 0x45 dsize: 32
And contained a flags field of 0x45 or 0x85, and had data and attribute forks following the inode core. This means that the timestamp updates were triggering dirty relogging of previously logged parts of the inode that hadn't yet been flushed back to disk.
There are two parts to this problem. The first is that XFS relogs dirty regions in subsequnet transactions, so it carries around the fields that have been dirtied since the last time the inode was written back to disk, not since the last time the inode was forced into the log.
The second part is that on v5 filesystems, the inode change count update during inode dirtying also sets the XFS_ILOG_CORE flag, so on v5 filesystems this makes a timestamp update dirty the entire inode.
As a result when fdatasync is run, it looks at the dirty fields in the inode, and sees more than just the timestamp flag, even though the only metadata change since the last fdatasync was just the timestamps. Hence we force the log on every subsequent fdatasync even though it is not needed.
To fix this, add a new field to the inode log item that tracks changes since the last time fsync/fdatasync forced the log to flush the changes to the journal. This flag is updated when we dirty the inode, but we do it before updating the change count so it does not carry the "core dirty" flag from timestamp updates. The fields are zeroed when the inode is marked clean (due to writeback/freeing) or when an fsync/datasync forces the log. Hence if we only dirty the timestamps on the inode between fsync/fdatasync calls, the fdatasync will not trigger another log force.
Over 100 runs of the test program:
Ext4 baseline:
runtime: 1.63s +/- 0.24s avg lat: 1.59ms +/- 0.24ms iops: ~2000
XFS, vanilla kernel:
runtime: 2.45s +/- 0.18s avg lat: 2.39ms +/- 0.18ms log forces: ~400/s iops: ~1000
XFS, patched kernel:
runtime: 1.49s +/- 0.26s avg lat: 1.46ms +/- 0.25ms log forces: ~30/s iops: ~1500
--- fs/xfs/xfs_file.c | 4 +++- fs/xfs/xfs_inode.c | 2 ++ fs/xfs/xfs_inode_item.c | 1 + fs/xfs/xfs_inode_item.h | 1 + fs/xfs/xfs_trans_inode.c | 9 +++++++++ 5 files changed, 16 insertions(+), 1 deletion(-)
fs/xfs/xfs_file.c +3 -1
@@ -248,8 +248,10 @@ xfs_file_fsync(xfs_ilock (ip,XFS_ILOCK_SHARED );if (xfs_ipincount (ip)) {if (!datasync || - (ip->i_itemp->ili_fields & ~XFS_ILOG_TIMESTAMP )) + (ip->i_itemp->ili_fsync_fields & ~XFS_ILOG_TIMESTAMP )) { lsn = ip->i_itemp->ili_last_lsn; + ip->i_itemp->ili_fsync_fields =0 ; + } }xfs_iunlock (ip,XFS_ILOCK_SHARED );
fs/xfs/xfs_inode.c +2 -0
@@ -2379,6 +2379,7 @@ retry: iip->ili_last_fields = iip->ili_fields; iip->ili_fields =0 ; + iip->ili_fsync_fields =0 ; iip->ili_logged =1 ;xfs_trans_ail_copy_lsn (mp->m_ail, &iip->ili_flush_lsn, &iip->ili_item.li_lsn);
@@ -3574,6 +3575,7 @@ xfs_iflush_int(*/ iip->ili_last_fields = iip->ili_fields; iip->ili_fields =0 ; + iip->ili_fsync_fields =0 ; iip->ili_logged =1 ; xfs_trans_ail_copy_lsn(mp->m_ail, &iip->ili_flush_lsn,
fs/xfs/xfs_inode_item.c +1 -0
@@ -719,6 +719,7 @@ xfs_iflush_abort(* attempted. */ iip->ili_fields =0 ; + iip->ili_fsync_fields =0 ; }/* * Release the inode's flush lock since we're done with it.
fs/xfs/xfs_inode_item.h +1 -0
@@ -34,6 +34,7 @@ typedef struct xfs_inode_log_item {unsigned short ili_logged;/* flushed logged data */ unsigned int ili_last_fields;/* fields when flushed */ unsigned int ili_fields;/* fields to be logged */ +unsigned int ili_fsync_fields;/* logged since last fsync */ } xfs_inode_log_item_t;static inline int xfs_inode_clean (xfs_inode_t *ip)
fs/xfs/xfs_trans_inode.c +9 -0
@@ -108,6 +108,15 @@ xfs_trans_log_inode(ASSERT (xfs_isilocked (ip,XFS_ILOCK_EXCL ));/* +* Record the specific change for fdatasync optimisation. This +* allows fdatasync to skip log forces for inodes that are only +* timestamp dirty. We do this before the change count so that +* the core being logged in this case does not impact on fdatasync +* behaviour. +*/ + ip->i_itemp->ili_fsync_fields |= flags; + +/* * First time we log the inode in a transaction, bump the inode change * counter if it is configured for this to occur. We don't use * inode_inc_version() because there is no need for extra locking around
Signature · 6 lines
2.5.0 _______________________________________________ xfs mailing list [email protected] http://oss.sgi.com/mailman/listinfo/xfs
Quoted 13 lines · Dave Chinner
From: Dave Chinner <[email protected]>
xfs: timestamp updates cause excessive fdatasync log traffic
Sage Weil reported that a ceph test workload was writing to the log on every fdatasync during an overwrite workload. Event tracing showed that the only metadata modification being made was the timestamp updates during the write(2) syscall, but fdatasync(2) is supposed to ignore them. The key observation was that the transactions in the log all looked like this:
INODE: #regs: 4 ino:
0x8bflags:0x45dsize: 32
Quoted 8 lines
And contained a flags field of
0x45or0x85, and had data and attribute forks following the inode core. This means that the timestamp updates were triggering dirty relogging of previously logged parts of the inode that hadn't yet been flushed back to disk.There are two parts to this problem. The first is that XFS relogs dirty regions in subsequnet transactions, so it carries around the
subsequent
Quoted 59 lines
fields that have been dirtied since the last time the inode was written back to disk, not since the last time the inode was forced into the log.
The second part is that on v5 filesystems, the inode change count update during inode dirtying also sets the
XFS_ILOG_COREflag, so on v5 filesystems this makes a timestamp update dirty the entire inode.As a result when fdatasync is run, it looks at the dirty fields in the inode, and sees more than just the timestamp flag, even though the only metadata change since the last fdatasync was just the timestamps. Hence we force the log on every subsequent fdatasync even though it is not needed.
To fix this, add a new field to the inode log item that tracks changes since the last time fsync/fdatasync forced the log to flush the changes to the journal. This flag is updated when we dirty the inode, but we do it before updating the change count so it does not carry the "core dirty" flag from timestamp updates. The fields are zeroed when the inode is marked clean (due to writeback/freeing) or when an fsync/datasync forces the log. Hence if we only dirty the timestamps on the inode between fsync/fdatasync calls, the fdatasync will not trigger another log force.
Over 100 runs of the test program:
Ext4 baseline:
runtime: 1.63s +/- 0.24s avg lat: 1.59ms +/- 0.24ms iops: ~2000XFS, vanilla kernel:
runtime: 2.45s +/- 0.18s avg lat: 2.39ms +/- 0.18ms log forces: ~400/s iops: ~1000XFS, patched kernel:
runtime: 1.49s +/- 0.26s avg lat: 1.46ms +/- 0.25ms log forces: ~30/s iops: ~1500Reported-by Sage Weil <[email protected]>Signed-off-by Dave Chinner <[email protected]>--- fs/xfs/xfs_file.c | 4 +++- fs/xfs/xfs_inode.c | 2 ++ fs/xfs/xfs_inode_item.c | 1 + fs/xfs/xfs_inode_item.h | 1 + fs/xfs/xfs_trans_inode.c | 9 +++++++++ 5 files changed, 16 insertions(+), 1 deletion(-)fs/xfs/xfs_file.c +0
-0
fs/xfs/xfs_file.c xfs_file_fsync( · line 254
Quoted 8 lines
fs/xfs/xfs_file.c +3
-1@@ -248,8 +248,10 @@ xfs_file_fsync(xfs_ilock (ip,XFS_ILOCK_SHARED );if (xfs_ipincount (ip)) {if (!datasync || - (ip->i_itemp->ili_fields & ~XFS_ILOG_TIMESTAMP )) + (ip->i_itemp->ili_fsync_fields & ~XFS_ILOG_TIMESTAMP )) { lsn = ip->i_itemp->ili_last_lsn; + ip->i_itemp->ili_fsync_fields =0 ; + }
Ok, so we check what's been logged since the last fsync that forced the log. If anything other than the timestamp has been logged, we force the log and clear the fields. Seems like a reasonable optimization to me.
One question... is it safe to clear the ili_fsync fields here if we have parallel fsync()/fdatasync() calls coming in? This is under the shared ilock, so assume that one fsync() comes in and finds non-timestamp changes to flush. It grabs the lsn, clears the flags and calls the log force. If an fdatasync() comes in before the log force completes, shouldn't it wait?
Also, is it me or are we sending an unconditional flush in the hunk following the log force call in xfs_file_fsync() (even if we've skipped the log force)?
Brian
Quoted 74 lines
fs/xfs/xfs_file.c +0
-0}xfs_iunlock (ip,XFS_ILOCK_SHARED );fs/xfs/xfs_inode.c +2
-0@@ -2379,6 +2379,7 @@ retry: iip->ili_last_fields = iip->ili_fields; iip->ili_fields =0 ; + iip->ili_fsync_fields =0 ; iip->ili_logged =1 ;xfs_trans_ail_copy_lsn (mp->m_ail, &iip->ili_flush_lsn, &iip->ili_item.li_lsn);@@ -3574,6 +3575,7 @@ xfs_iflush_int(*/ iip->ili_last_fields = iip->ili_fields; iip->ili_fields =0 ; + iip->ili_fsync_fields =0 ; iip->ili_logged =1 ; xfs_trans_ail_copy_lsn(mp->m_ail, &iip->ili_flush_lsn,fs/xfs/xfs_inode_item.c +1
-0@@ -719,6 +719,7 @@ xfs_iflush_abort(* attempted. */ iip->ili_fields =0 ; + iip->ili_fsync_fields =0 ; }/* * Release the inode's flush lock since we're done with it. fs/xfs/xfs_inode_item.h +1
-0@@ -34,6 +34,7 @@ typedef struct xfs_inode_log_item {unsigned short ili_logged;/* flushed logged data */ unsigned int ili_last_fields;/* fields when flushed */ unsigned int ili_fields;/* fields to be logged */ +unsigned int ili_fsync_fields;/* logged since last fsync */ } xfs_inode_log_item_t;static inline int xfs_inode_clean (xfs_inode_t *ip)fs/xfs/xfs_trans_inode.c +9
-0@@ -108,6 +108,15 @@ xfs_trans_log_inode(ASSERT (xfs_isilocked (ip,XFS_ILOCK_EXCL ));/* +* Record the specific change for fdatasync optimisation. This +* allows fdatasync to skip log forces for inodes that are only +* timestamp dirty. We do this before the change count so that +* the core being logged in this case does not impact on fdatasync +* behaviour. +*/ + ip->i_itemp->ili_fsync_fields |= flags; + +/* * First time we log the inode in a transaction, bump the inode change * counter if it is configured for this to occur. We don't use * inode_inc_version() because there is no need for extra locking around Signature · 6 lines
2.5.0 _______________________________________________ xfs mailing list [email protected] http://oss.sgi.com/mailman/listinfo/xfs
_______________________________________________
xfs mailing list
[email protected]
http://oss.sgi.com/mailman/listinfo/xfs
Quoted 4 lines · Brian Foster
Quoted 3 lines · Dave Chinner
From: Dave Chinner <[email protected]>
xfs: timestamp updates cause excessive fdatasync log traffic
....
Quoted 15 lines
fs/xfs/xfs_file.c xfs_file_fsync( · line 254
Quoted 10 lines
+++
b/fs/xfs/xfs_file.cfs/xfs/xfs_file.c +3
-1@@ -248,8 +248,10 @@ xfs_file_fsync(xfs_ilock (ip,XFS_ILOCK_SHARED );if (xfs_ipincount (ip)) {if (!datasync || - (ip->i_itemp->ili_fields & ~XFS_ILOG_TIMESTAMP )) + (ip->i_itemp->ili_fsync_fields & ~XFS_ILOG_TIMESTAMP )) { lsn = ip->i_itemp->ili_last_lsn; + ip->i_itemp->ili_fsync_fields =0 ; + }Ok, so we check what's been logged since the last fsync that forced the log. If anything other than the timestamp has been logged, we force the log and clear the fields. Seems like a reasonable optimization to me.
Quoted 6 lines
One question... is it safe to clear the
ili_fsyncfields here if we have parallel fsync()/fdatasync() calls coming in? This is under the shared ilock, so assume that onefsync()comes in and finds non-timestamp changes to flush. It grabs the lsn, clears the flags and calls the log force. If anfdatasync()comes in before the log force completes, shouldn't it wait?
Probably, but the only way to do that is to run a log force on that same lsn. Actually, it is safe to do that log force while holding the XFS_ILOCK (xfs_trans_commit() does that for synchronous transactions), so we should simply be able to do:
xfs_ilock(ip, XFS_ILOCK_SHARED);
if (xfs_ipincount(ip)) {
if (!datasync ||
(ip->i_itemp->ili_fsync_fields & ~XFS_ILOG_TIMESTAMP))
lsn = ip->i_itemp->ili_last_lsn;
}
if (lsn) {
error = _xfs_log_force_lsn(mp, lsn, XFS_LOG_SYNC, &log_flushed);
ip->i_itemp->ili_fsync_fields = 0;
}
xfs_iunlock(ip, XFS_ILOCK_SHARED);Quoted 3 lines
Also, is it me or are we sending an unconditional flush in the hunk following the log force call in
xfs_file_fsync()(even if we've skipped the log force)?
The flush is needed - fdatasync needs to guarantee the data is on stable storage even if no metadata needs to be written to the journal.
Cheers,
Dave.
Signature · 7 lines
Dave Chinner [email protected] _______________________________________________ xfs mailing list [email protected] http://oss.sgi.com/mailman/listinfo/xfs
Quoted 28 lines · Dave Chinner
Quoted 4 lines · Brian Foster
Quoted 3 lines · Dave Chinner
From: Dave Chinner <[email protected]>
xfs: timestamp updates cause excessive fdatasync log traffic
....
Quoted 15 lines
fs/xfs/xfs_file.c xfs_file_fsync( · line 254
Quoted 10 lines
+++
b/fs/xfs/xfs_file.cfs/xfs/xfs_file.c +3
-1@@ -248,8 +248,10 @@ xfs_file_fsync(xfs_ilock (ip,XFS_ILOCK_SHARED );if (xfs_ipincount (ip)) {if (!datasync || - (ip->i_itemp->ili_fields & ~XFS_ILOG_TIMESTAMP )) + (ip->i_itemp->ili_fsync_fields & ~XFS_ILOG_TIMESTAMP )) { lsn = ip->i_itemp->ili_last_lsn; + ip->i_itemp->ili_fsync_fields =0 ; + }Ok, so we check what's been logged since the last fsync that forced the log. If anything other than the timestamp has been logged, we force the log and clear the fields. Seems like a reasonable optimization to me.
Quoted 6 lines
One question... is it safe to clear the
ili_fsyncfields here if we have parallel fsync()/fdatasync() calls coming in? This is under the shared ilock, so assume that onefsync()comes in and finds non-timestamp changes to flush. It grabs the lsn, clears the flags and calls the log force. If anfdatasync()comes in before the log force completes, shouldn't it wait?
Quoted 5 lines
Probably, but the only way to do that is to run a log force on that same lsn. Actually, it is safe to do that log force while holding the
XFS_ILOCK(xfs_trans_commit()does that for synchronous transactions), so we should simply be able to do:
Yeah, a parallel fsync on a single inode situation is probably not the most likely thing. Thinking about it further, the case where multiple inodes happen to have the same lsn might be more likely and takes the shared ilock out of the equation.
Quoted 4 lines
xfs_ilock(ip, XFS_ILOCK_SHARED);
if (xfs_ipincount(ip)) {
if (!datasync ||
(ip->i_itemp->ili_fsync_fields & ~XFS_ILOG_TIMESTAMP))Quoted 9 lines
lsn = ip->i_itemp->ili_last_lsn;
}
if (lsn) {
error = _xfs_log_force_lsn(mp, lsn, XFS_LOG_SYNC, &log_flushed);
ip->i_itemp->ili_fsync_fields = 0;
}
xfs_iunlock(ip, XFS_ILOCK_SHARED);This looks better to me. We send the caller through the log force infrastructure until we know the log has been forced.
Quoted 9 lines
Quoted 4 lines
Also, is it me or are we sending an unconditional flush in the hunk following the log force call in
xfs_file_fsync()(even if we've skipped the log force)?The flush is needed - fdatasync needs to guarantee the data is on stable storage even if no metadata needs to be written to the journal.
Ok. Well it's too bad we don't get any feedback about what was written from the filemap_write_and_wait_range() call. As it is, we send a flush even if there's nothing to write back. I suppose that's also not a major problem since an fsync() caller implies something was modified one way or another. Thanks.
Brian
Quoted 11 lines
Cheers,
Dave.
Signature · 7 lines
Dave Chinner [email protected] _______________________________________________ xfs mailing list [email protected] http://oss.sgi.com/mailman/listinfo/xfs
_______________________________________________
xfs mailing list
[email protected]
http://oss.sgi.com/mailman/listinfo/xfs
Quoted 5 lines · Brian Foster
Quoted 4 lines · Dave Chinner
Quoted 3 lines
Also, is it me or are we sending an unconditional flush in the hunk following the log force call in
xfs_file_fsync()(even if we've skipped the log force)?
Quoted 8 lines
Quoted 4 lines
The flush is needed - fdatasync needs to guarantee the data is on stable storage even if no metadata needs to be written to the journal.
Ok. Well it's too bad we don't get any feedback about what was written from the
filemap_write_and_wait_range()call. As it is, we send a flush even if there's nothing to write back.
Direct IO still needs cache flushes.
Cheers,
Dave.
Signature · 7 lines
Dave Chinner [email protected] _______________________________________________ xfs mailing list [email protected] http://oss.sgi.com/mailman/listinfo/xfs