xfs
[Top] [All Lists]

Marking inode dirty latency > 1000 msec on XFS!

To: Arjan van de Ven <arjan@xxxxxxxxxxxxxxx>
Subject: Marking inode dirty latency > 1000 msec on XFS!
From: Török Edwin <edwintorok@xxxxxxxxx>
Date: Fri, 15 Feb 2008 20:44:44 +0200
Cc: xfs@xxxxxxxxxxx
Dkim-signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=gamma; h=domainkey-signature:received:received:message-id:date:from:user-agent:mime-version:to:cc:subject:content-type:content-transfer-encoding; bh=v0vg0EycYPvG2K66qKcM8GfJDmytvHb0krLF76+PocQ=; b=F0w6RD33IOsoxJna0Z70RSsbP6KEgsPUMwtFRkMJ9FqaaiwHOslmUwM3IMO0y8WpSmiT0uAGhKF9F+TnF2bgHA/Ue9gCogoe+XiLumB6kGmaQd610p8cFQO5hLGgYBEfZKyaJ0ihr++R00OO8PkSX2SD6AsBrCEtcrMeMIYqO2I=
Domainkey-signature: a=rsa-sha1; c=nofws; d=gmail.com; s=gamma; h=message-id:date:from:user-agent:mime-version:to:cc:subject:content-type:content-transfer-encoding; b=Xj3wOa7WfACCTZbCGLQq3+VWTkN8T9SHQoYbZ788XHheK7VEew68HfPcboBqkjE/8pstju1hMwh0TlZizTMgsqOrqTKcZboTfiesilwDhDCGvK3w8XheZea8oRY7ch/CIPVRBFrcbBJqS8eEL80IvlVB0fbWnr7s9Oqr/HRWpdQ=
Sender: xfs-bounce@xxxxxxxxxxx
User-agent: Mozilla-Thunderbird 2.0.0.9 (X11/20080109)
Hi,

Using LatencyTOP 0.3, on the latest 2.6.25-git I see latencies of over a
second on __mark_ inode_dirty.
[see a stacktrace at end of this email]

I tried to locate xfs's implementation of super_operations.dirty_inode,
but it isn't specified in xfs_super.c.
I don't know how mark_inode_dirty ends up calling xfs_trans_commit, but
is it required to commit the dirty status of an inode to the transaction
log?

FWIW, this is a slow laptop hdd (5400 rpm, ST96812AS), but latency of 1
second is still big.

Are there any settings I can tweak to reduce latency?

LatencyTOP output during a 'svn up' on llvm-gcc source tree:

Cause                                                Maximum     Percentage
Marking inode dirty                               1105.8 msec          7.8 %
_xfs_buf_ioapply default_wake_function xlog_state_1065.2 msec          7.0 %
Deleting an inode                                 964.8 msec         20.0 %
_xfs_buf_ioapply default_wake_function xlog_state_780.1 msec          8.3 %
_xfs_buf_ioapply default_wake_function xlog_state_679.4 msec          3.3 %
_xfs_buf_ioapply default_wake_function xlog_state_610.1 msec          5.6 %
XFS I/O wait                                      585.9 msec         12.6 %
_xfs_buf_ioapply default_wake_function xlog_state_528.8 msec          6.8 %
Creating block layer request                      499.6 msec          5.7 %

Earlier I've seen this latencyTOP output too:

Cause                                                Maximum     Percentage
XFS I/O wait                                      407.6 msec         53.4 %
Marking inode dirty                               173.0 msec          0.9 %
Writing a page to disk                            141.6 msec         42.6 %
__generic_unplug_device default_wake_function xfs_ 86.0 msec          0.3 %
Page fault                                         44.1 msec          0.2 %
kobject_put put_device blk_start_queueing __generi 15.9 msec          0.1 %
Scheduler: waiting for cpubuf_find kmem_zone_alloc 12.4 msec          2.2 %
put_device scsi_request_fn blk_start_queueing defa  4.9 msec          0.0 %
Waiting for event (poll)                            4.7 msec          0.4 %

Process svn (10685)
Writing a page to disk                             23.9 msec         55.9 %
XFS I/O wait                                       15.9 msec         35.2 %
Scheduler: waiting for cpu                          0.8 msec          8.9 %

Raw output from /proc/latency shows stacktrace:

7 93862 26567 _xfs_buf_ioapply default_wake_function
xlog_state_get_iclog_space xlog_state_release_iclog xlog_write
xfs_log_write _xfs_trans_commit __mark_inode_dirty igrab xfs_create
xfs_vn_mknod security_inode_permission
1 96331 96331 default_wake_function xlog_state_get_iclog_space
xlog_state_release_iclog xlog_write xfs_log_write _xfs_trans_commit
__mark_inode_dirty igrab xfs_create xfs_vn_mknod
security_inode_permission xfs_vn_permission

Best regards,
--Edwin


<Prev in Thread] Current Thread [Next in Thread>