Dave Chinner wrote:
On Thu, Jun 19, 2008 at 03:27:48PM +1000, Brian May wrote:
Hello,
I am having (weird) issues with XFS, in that open(...) on certain files
takes 45 seconds to return. After the file has been opened, the next
file in the same directory takes 45 seconds. If the file was recently
opened it returns immediately.
I thought this was a low level I/O issue, so copied the files in
question to a completely independent RAID array (separate LVM, RAID,
controllers, disks), but the problem remains.
More details at thread starting from
<http://lists.luv.asn.au/wws/arc/luv-main/2008-06/msg00143.html>.
Any ideas?
# echo t > /proc/sysrq-trigger
when it is hung to get a stack trace of the blocked open call.
Cheers,
Dave.
Does the following help? I still have the logs of the other processes,
if required (just in case it is some weird interaction between multiple
processes?)
It seems to be pretty consistent with lock_timer_base, every time I look
(assuming I haven't read the stack trace upside down...).
Jun 19 16:33:30 hq kernel: grep S 00000000 0 12793 12567
(NOTLB)
Jun 19 16:33:30 hq kernel: f0c23e7c 00200082 000a1089 00000000 00000010 00000008 cd0db550 dfa97550
Jun 19 16:33:30 hq kernel: 34f84262 00273db2 0008a1dc 00000001 cd0db660 c20140a0 dfe1cbe8 00200286
Jun 19 16:33:30 hq kernel: c0125380 a4dbf26b dfa6a000 00200286 000000ff 00000000 00000000 a4dbf26b
Jun 19 16:33:30 hq kernel: Call Trace:
Jun 19 16:33:30 hq kernel: [<c0125380>] lock_timer_base+0x15/0x2f
Jun 19 16:33:30 hq kernel: [<c027f960>] schedule_timeout+0x71/0x8c
Jun 19 16:33:30 hq kernel: [<c0124a81>] process_timeout+0x0/0x5
Jun 19 16:33:30 hq kernel: [<c016c801>] __break_lease+0x2a8/0x2b9
Jun 19 16:33:30 hq kernel: [<c0117778>] default_wake_function+0x0/0xc
Jun 19 16:33:30 hq kernel: [<c0166450>] may_open+0x125/0x203
Jun 19 16:33:30 hq kernel: [<c0168451>] open_namei+0x23d/0x5c8
Jun 19 16:33:30 hq kernel: [<c0158cb8>] do_filp_open+0x1c/0x31
Jun 19 16:33:30 hq kernel: [<c0161f38>] sys_stat64+0x1e/0x23
Jun 19 16:33:30 hq kernel: [<c0158d0b>] do_sys_open+0x3e/0xb3
Jun 19 16:33:30 hq kernel: [<c0158dad>] sys_open+0x16/0x18
Jun 19 16:33:30 hq kernel: [<c0102c11>] sysenter_past_esp+0x56/0x79
Jun 19 16:33:50 hq kernel: grep S 00000000 0 12793 12567
(NOTLB)
Jun 19 16:33:50 hq kernel: f0c23e7c 00200082 000a1089 00000000 00000010 00000008 cd0db550 dfa97550
Jun 19 16:33:50 hq kernel: 34f84262 00273db2 0008a1dc 00000001 cd0db660 c20140a0 dfe1cbe8 00200286
Jun 19 16:33:50 hq kernel: c0125380 a4dbf26b dfa6a000 00200286 000000ff 00000000 00000000 a4dbf26b
Jun 19 16:33:50 hq kernel: Call Trace:
Jun 19 16:33:50 hq kernel: [<c0125380>] lock_timer_base+0x15/0x2f
Jun 19 16:33:50 hq kernel: [<c027f960>] schedule_timeout+0x71/0x8c
Jun 19 16:33:50 hq kernel: [<c0124a81>] process_timeout+0x0/0x5
Jun 19 16:33:50 hq kernel: [<c016c801>] __break_lease+0x2a8/0x2b9
Jun 19 16:33:50 hq kernel: [<c0117778>] default_wake_function+0x0/0xc
Jun 19 16:33:50 hq kernel: [<c0166450>] may_open+0x125/0x203
Jun 19 16:33:50 hq kernel: [<c0168451>] open_namei+0x23d/0x5c8
Jun 19 16:33:50 hq kernel: [<c0158cb8>] do_filp_open+0x1c/0x31
Jun 19 16:33:50 hq kernel: [<c0161f38>] sys_stat64+0x1e/0x23
Jun 19 16:33:50 hq kernel: [<c0158d0b>] do_sys_open+0x3e/0xb3
Jun 19 16:33:50 hq kernel: [<c0158dad>] sys_open+0x16/0x18
Jun 19 16:33:50 hq kernel: [<c0102c11>] sysenter_past_esp+0x56/0x79
Thanks.
Brian May
|