Re: Filesystem wedge, SUJ-related?

From: René Ladan <rene_at_freebsd.org>
Date: Thu, 12 Aug 2010 14:01:57 +0200
Hi,

if I understand correctly, this is what r211212 and r211213 fixes?

Rene

2010/8/8 Rene Ladan <rene_at_freebsd.org>:
> On 18-07-2010 15:02, Gavin Atkinson wrote:
>>
>> On Sat, 17 Jul 2010, Gavin Atkinson wrote:
>>>
>>> Semi-regularly (every two-three days) I'm seeing what appears to be some
>>> sort of filesystem wedge.  I usually see it initially with web browsers,
>>> but it's possible that's only because it's what produces most disk
>>> activity on this machine.  I've seen it with both Opera and Firefox.
>>>
> I've been seeing this too. It still happens with kernel r211000.
>
>>> What happens is that the process will just wedge.  A "procstat -kk" on it
>>> shows the following stack backtrace:
>>>
>>>  9012 100243 firefox-bin      initial thread   mi_switch+0x21d
>>> sleepq_switch+0x123 sleepq_wait+0x4d _sleep+0x357 getdirtybuf+0x21e
>>> flush_deplist+0x6f softdep_sync_metadata+0x153 ffs_syncvnode+0x213
>>> ffs_fsync+0x43 fsync+0x148 syscallenter+0x1b5 syscall+0x4c
>>> Xfast_syscall+0xe2
>>
> Firefox is the usual first sign:
> acer % ps ax|grep firefox
> 82117  v0  T     16:24,08 /usr/local/lib/firefox3/firefox-bin
> 13416   3  S+     0:00,00 grep firefox
> acer % procstat -kk 82117
>  PID    TID COMM             TDNAME           KSTACK
> 82117 100195 firefox-bin      -                mi_switch+0x219
> thread_suspend_switch+0x103 thread_single+0x25c exit1+0x81 sigexit+0x84
> cursig+0 ast+0x1aa doreti_ast+0x1f
> 82117 100221 firefox-bin      initial thread   mi_switch+0x219
> sleepq_switch+0xfa sleepq_wait+0x46 _sleep+0x256 getdirtybuf+0x1af
> flush_deplist+0x6a softdep_sync_metadata+0x153 ffs_syncvnode+0x22d
> ffs_fsync+0x43 fsync+0x13d syscallenter+0x194 syscall+0x41
> Xfast_syscall+0xe2
> acer %
>
>> A bit more detail: it does look like whatever is supposed to periodically
>> flush the journal just stops doing it's job.  Presumably this is also the
>> root cause of the "softdep: Out of journal space!" messages I have been
>> seeing in the past, which I had assumed may have been fixed by r209717.
>>
> I haven't seen any "softdep: Out of journal space!" messages since June 24,
> but I've indeed seen it once before (somewhere after June 11).
>
>> (I'm running r209723 at the moment)
>>
>> While processes are starting to hang, "sh ffs" from ddb shows:
>>
>> db>  sh ffs
>> mp 0xffffff0002c45be0 / devvp 0xffffff0002c51000 fs 0xffffff0002c67000
>> su_wl 0 su_wl_in 0 su_deps 0 su_req 0
>> mp 0xffffff0002d705f0 /tmp devvp 0xffffff0002d48780 fs 0xffffff0002c64800
>> su_wl 0 su_wl_in 0 su_deps 0 su_req 0
>> mp 0xffffff0002c458e8 /usr devvp 0xffffff0002d485a0 fs 0xffffff0002c66000
>> su_wl 0 su_wl_in 0 su_deps 17345 su_req 0
>> mp 0xffffff0002c455f0 /var devvp 0xffffff0002d483c0 fs 0xffffff0002c66800
>> su_wl 0 su_wl_in 0 su_deps 55 su_req 0
>>
>> Leaving it another couple of hours, I then see:
>>
>> db>  sh ffs
>> mp 0xffffff0002c45be0 / devvp 0xffffff0002c51000 fs 0xffffff0002c67000
>> su_wl 0 su_wl_in 0 su_deps 0 su_req 0
>> mp 0xffffff0002d705f0 /tmp devvp 0xffffff0002d48780 fs 0xffffff0002c64800
>> su_wl 0 su_wl_in 0 su_deps 36 su_req 0
>> mp 0xffffff0002c458e8 /usr devvp 0xffffff0002d485a0 fs 0xffffff0002c66000
>> su_wl 0 su_wl_in 0 su_deps 31899 su_req 0
>> mp 0xffffff0002c455f0 /var devvp 0xffffff0002d483c0 fs 0xffffff0002c66800
>> su_wl 0 su_wl_in 0 su_deps 95 su_req 0
>>
>> so, su_deps is increasing significantly.
>>
>> During reboot, vnlru failed to stop within 60 seconds, and gave up on
>> syncing 125 vnodes and 140 buffers (no idea if these are related).  On
>> reboot, SU+J fsck shows for /usr:
>>
>> ** SU+J Recovering /dev/ad4s1f
>> ** Reading 33554432 byte journal from inode 150.
>> ** Building recovery table.
>> ** Resolving unreferenced inode list.
>> ** Processing journal entries.
>> ** 405991 journal records in 18194944 bytes for 71.40% utilization
>> ** Freed 3872 inodes (0 dirs) 48157 blocks, and 8744 frags.
>>
> Similar here.
>
>> So it seems clear that somehow the journal is filling up, and never being
>> written.
>>
>> Any other suggestions as to where I should go from here?
>>
> Disabling the journal would be a "solution", but not desirable.
> Maybe any lock order reversals to look out for (most are ufs-related) ?
>
> I don't know if it is related, but yesterday a full fsck on /usr cleared up
> two unallocated files in /usr/ports/editors/openoffice-3/work/ (they were in
> userland as having a bad file descriptor), which the journal didn't catch.
>
Received on Thu Aug 12 2010 - 10:01:59 UTC

This archive was generated by hypermail 2.4.0 : Wed May 19 2021 - 11:40:06 UTC