I did some investigation, and I got to the following:
The problem seems to be connected to waiting for the superblock based on
the WCHAN field in the ps output.
So I changed the superblock locking code to print some diagnostic (after
taking it out of inline) as follows:
void andras_trace(const char *str);
void wait_on_super(struct super_block * sb)
{
if (sb->s_lock) {
andras_trace("wait_on_super - waiting");
__wait_on_super(sb);
andras_trace("wait_on_super - waking up");
} else {
andras_trace("wait_on_super - not waiting");
}
}
void lock_super(struct super_block * sb)
{
if (sb->s_lock) {
andras_trace("lock_super - waiting");
__wait_on_super(sb);
andras_trace("lock_super - waking up");
} else {
andras_trace("lock_super - not waiting");
}
sb->s_lock = 1;
}
void unlock_super(struct super_block * sb)
{
andras_trace("unlock_super");
sb->s_lock = 0;
wake_up(&sb->s_wait);
}
(andras_trace is a function similar to the 'Oops' stack tracer code)
I got the following (after running it through ksymoops):
47154:: lock_super - not waiting Process httpsd (pid: 280,
stackpage=02cfd000)
Stack: 00160721 0012a37a 001ae28d 02c4f900 0015eb48 001e79bc 02c4f900
02c4f900
02c4f900 00000001 00000000 02ded698 0015f4d2 0015f4f1 02c4f900
02c4f900
00126129 02c4f900 03850e14 00124daa 02c4f900 00000000 03850e14
00124e08
Call Trace: [<00160721>] [<0012a37a>] [<0015eb48>] [<0015f4d2>]
[<0015f4f1>] [<00126129>] [<00124daa>]
[<00124e08>] [<00117e54>] [<0010a75b>] [<0010a94a>]
Trace: 12a37a <lock_super+3a/50>
Trace: 15eb48 <ext2_free_inode+98/250>
Trace: 15f4d2 <ext2_put_inode+42/70>
Trace: 15f4f1 <ext2_put_inode+61/70>
Trace: 126129 <iput+d9/1c0>
Trace: 124daa <__fput+3a/40>
Trace: 124e08 <close_fp+58/70>
Trace: 117e54 <do_exit+124/200>
Trace: 10a75b <do_signal+24b/2ac>
Trace: 10a94a <signal_return+12/38>
47154:: wait_on_super - waiting Process httpsd (pid: 280,
stackpage=02cfd000)
Stack: 02cfdd7c 0012a315 001ae213 0000140b 0015f550 001e79bc 00000002
0000140b
000007ff 03d96d00 00000008 001e79bc 000007ff 03d96d00 0015fcb4
03d96d00
0000140b 02cfde40 00000008 000006f3 000007ff 03d96d00 00000002
02de9018
Call Trace: [<0012a315>] [<0015f550>] [<0015fcb4>] [<0015ff47>]
[<0015e099>] [<001aacdf>] [<001aacdf>]
[<0010a94a>] [<0010a94a>] [<04800000>] [<04800000>] [<00134f12>]
[<00135809>] [<00135ef1>] [<00125a68>]
[<0015ece0>] [<0015eced>] [<0015f4f1>] [<00126129>] [<00124daa>]
[<00124e08>] [<00117e54>] [<0010a75b>]
[<0010a94a>]
Trace: 12a315 <wait_on_super+15/40>
Trace: 15f550 <ext2_alloc_block+20/1b0>
Trace: 15fcb4 <block_getblk+174/2a0>
Trace: 15ff47 <ext2_getblk+167/240>
Trace: 15e099 <ext2_file_write+1b9/4a0>
Trace: 1aacdf <vsprintf+48f/4d0>
Trace: 1aacdf <vsprintf+48f/4d0>
Trace: 10a94a <signal_return+12/38>
Trace: 10a94a <signal_return+12/38>
Trace: 4800000
Trace: 4800000
Trace: 134f12 <write_dquot+f2/150>
Trace: 135809 <dqput+a9/e0>
Trace: 135ef1 <dquot_drop+21/40>
Trace: 125a68 <clear_inode+68/160>
Trace: 15ece0 <ext2_free_inode+230/250>
Trace: 15eced <ext2_free_inode+23d/250>
Trace: 15f4f1 <ext2_put_inode+61/70>
Trace: 126129 <iput+d9/1c0>
Trace: 124daa <__fput+3a/40>
Trace: 124e08 <close_fp+58/70>
Trace: 117e54 <do_exit+124/200>
Trace: 10a75b <do_signal+24b/2ac>
Trace: 10a94a <signal_return+12/38>
49882:: wait_on_super - waiting Process update (pid: 20,
stackpage=03e9e000)
Stack: 0000c2da 0012a315 001ae213 001e79bc 0012a3ec 001e79bc 03e92018
00000000
001294dd 00000000 03e92018 00000000 08048780 00002898 00129631
03e92018
00000005 0010a889 00000001 00000000 00000100 00000005 08048780
00000000
Call Trace: [<0012a315>] [<0012a3ec>] [<001294dd>] [<00129631>]
[<0010a889>]
Trace: 12a315 <wait_on_super+15/40>
Trace: 12a3ec <sync_supers+2c/70>
Trace: 1294dd <sync_old_buffers+d/120>
Trace: 129631 <sys_bdflush+41/c0>
Trace: 10a889 <system_call+55/7c>
What seems to be happening is:
* the signal gets delivered to httpsd and ext2_free_inode locks the
superblock (this is the first trace)
* write_dquot gets called before releasing the superblock which does
something I don't understand (second trace around signal_return in the
middle) which ends up requesting a second lock on the superblock in the
same process. This hangs of course since control never returns to the
first lock to be freed.
* later other processes try to acquire the superblock lock (like
update in the third trace) and hang as well. Slowly things die.
All this seems to be tied to quotas. If I turn quotas off, none of this
happens.
This is as far as I got in understanding the situation. I'm somewhat of a
novice kernel hacker, so I'd really appreciate it if I could get some
help. I'd like to find a solution to this since it is happening to a
stable kernel.
Thanks
Andras Pataki
apataki@viconet.com
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.rutgers.edu