ext3 oops under moderate load

ext3 oops under moderate load

[mb/ext3]

Hi bug hunters,

I left my spangly new dual PIII with an ext3 partition on a Promise
FastTrak 100TX2 being used both by a local process and knfsd for a few
hours, and the following happened:

[ 2.4.9-ac3 SMP (noapic) + the one patch from Zygo Blaxell to recognise
the Promise card; now I have kupdated, kjournald and user-space processes
trying to access the volume in question all in state 'D' ]

kernel BUG at revoke.c:307!
invalid operand: 0000
CPU:    1
EIP:    0010:[<e0829237>]
Using defaults from ksymoops -t elf32-i386 -a i386
EFLAGS: 00010282
eax: 0000001c   ebx: c3e13d6c   ecx: c023f7a0   edx: 0001af83
esi: dfc1b800   edi: c3e13d6c   ebp: 0000000a   esp: d5cd1c70
ds: 0018   es: 0018   ss: 0018
Process nfsd (pid: 568, stackpage=d5cd1000)
Stack: e082e31e 00000133 0000d172 d5688044 00000001 cc89c8ac e0833bfc
cc89c8ac
       0000d172 c3e13d6c d5cd1d28 c0143a68 00007201 c3e13d6c c3e13d6c
0000d172
       d5688044 d5cd1d28 e0835e6d cc89c8ac 00000001 d5688044 c3e13d6c
0000d172
Call Trace: [<e082e31e>] [<e0833bfc>] [<c0143a68>] [<e0835e6d>]
[<e08361ab>]
   [<e082b17b>] [<e0823334>] [<e08234af>] [<e083f800>] [<e0833c96>]
[<e083f800>]
   [<e0833e0e>] [<c015b6b4>] [<c01575d6>] [<e095aa27>] [<e095ac8a>]
[<e095c087>]
   [<e095c65d>] [<c01f0965>] [<c01b15ac>] [<c0134a68>] [<e0959100>]
[<e0968ea0>]
   [<e0958661>] [<e0968ea0>] [<e098785a>] [<e0968d08>] [<e0968d38>]
[<e095847a>]
   [<e0968d00>] [<c0105926>] [<e0958190>]
Code: 0f 0b 58 5a f0 0f ab 6b 18 b8 0b 00 00 00 f0 0f ab 43 18 85

>>EIP; e0829237 <[jbd]journal_revoke+d7/180>   <=====
Trace; e082e31e <[jbd].rodata.start+23de/347f>
Trace; e0833bfc <[ext3]ext3_forget+bc/120>
Trace; c0143a68 <bread+18/70>
Trace; e0835e6d <[ext3]ext3_free_branches+ed/170>
Trace; e08361ab <[ext3]ext3_truncate+2bb/380>
Trace; e082b17b <[jbd]__jbd_kmalloc+2b/c0>
Trace; e0823334 <[jbd]start_this_handle+1d4/290>
Trace; e08234af <[jbd]journal_start+bf/f0>
Trace; e083f800 <[ext3]ext3_sops+0/40>
Trace; e0833c96 <[ext3]start_transaction+36/40>
Trace; e083f800 <[ext3]ext3_sops+0/40>
Trace; e0833e0e <[ext3]ext3_delete_inode+be/170>
Trace; c015b6b4 <iput+1d4/310>
Trace; c01575d6 <dput+166/200>
Trace; e095aa27 <[nfsd]find_fh_dentry+3d7/410>
Trace; e095ac8a <[nfsd]fh_verify+22a/470>
Trace; e095c087 <[nfsd]nfsd_open+27/280>
Trace; e095c65d <[nfsd]nfsd_write+4d/2d0>
Trace; c01f0965 <inet_sendmsg+35/40>
Trace; c01b15ac <sock_sendmsg+6c/90>
Trace; c0134a68 <free_block+1c8/2d0>
Trace; e0959100 <[nfsd]nfsd_proc_write+c0/d0>
Trace; e0968ea0 <[nfsd]nfsd_procedures2+100/240>
Trace; e0958661 <[nfsd]nfsd_dispatch+c1/160>
Trace; e0968ea0 <[nfsd]nfsd_procedures2+100/240>
Trace; e098785a <[sunrpc]svc_process+34a/510>
Trace; e0968d08 <[nfsd]nfsd_version2+0/10>
Trace; e0968d38 <[nfsd]nfsd_program+0/18>
Trace; e095847a <[nfsd]nfsd+2ea/410>
Trace; e0968d00 <[nfsd]nfsd_list+0/0>
Trace; c0105926 <kernel_thread+26/30>
Trace; e0958190 <[nfsd]nfsd+0/410>
Code;  e0829237 <[jbd]journal_revoke+d7/180>
00000000 <_EIP>:
Code;  e0829237 <[jbd]journal_revoke+d7/180>   <=====
   0:   0f 0b                     ud2a      <=====
Code;  e0829239 <[jbd]journal_revoke+d9/180>
   2:   58                        pop    %eax
Code;  e082923a <[jbd]journal_revoke+da/180>
   3:   5a                        pop    %edx
Code;  e082923b <[jbd]journal_revoke+db/180>
   4:   f0 0f ab 6b 18            lock bts %ebp,0x18(%ebx)
Code;  e0829240 <[jbd]journal_revoke+e0/180>
   9:   b8 0b 00 00 00            mov    $0xb,%eax
Code;  e0829245 <[jbd]journal_revoke+e5/180>
   e:   f0 0f ab 43 18            lock bts %eax,0x18(%ebx)
Code;  e082924a <[jbd]journal_revoke+ea/180>
  13:   85 00                     test   %eax,(%eax)

Re: ext3 oops under moderate load

[mb/ext3]

At 08:19 +0100 mb/ext3@dcs.qmul.ac.uk wrote:

>I left my spangly new dual PIII with an ext3 partition on a Promise
>FastTrak 100TX2 being used both by a local process and knfsd for a few
>hours, and the following happened:

>[ 2.4.9-ac3 SMP (noapic) + the one patch from Zygo Blaxell to recognise
>the Promise card; now I have kupdated, kjournald and user-space processes
>trying to access the volume in question all in state 'D' ]

>kernel BUG at revoke.c:307!
[snip oops]

found this on my screen when I got into work:

Assertion failure in journal_revoke() at revoke.c:307: "!(__builtin_constant_p(BH_Revoked) ? constant_test_bit((BH_Revoked),(&bh->b_state)) : variable_test_bit((BH_Revoked),(&bh->b_state)))"

Anything else I can provide, do let me know!

Re: ext3 oops under moderate load

[Andrew Morton]

mb/ext3@dcs.qmul.ac.uk wrote:
> 
> Hi bug hunters,
> 
> I left my spangly new dual PIII with an ext3 partition on a Promise
> FastTrak 100TX2 being used both by a local process and knfsd for a few
> hours, and the following happened:
> 
> [ 2.4.9-ac3 SMP (noapic) + the one patch from Zygo Blaxell to recognise
> the Promise card; now I have kupdated, kjournald and user-space processes
> trying to access the volume in question all in state 'D' ]
> 
> kernel BUG at revoke.c:307!

Yours is the third report of this - it's definitely a bug in
ext3.  I still need to work out how you managed to get a page
attached to the inode which has not had its buffers fed through
journal_dirty_data().  There seem to be several ways in which
this can happen.

Is it possible that you ran out of disk space on the relevant
partition shortly before it died?

-

Re: ext3 oops under moderate load

[mb/ext3]

On Aug 31 Andrew Morton wrote:

>> kernel BUG at revoke.c:307!
>
>Yours is the third report of this - it's definitely a bug in
>ext3.  I still need to work out how you managed to get a page
>attached to the inode which has not had its buffers fed through
>journal_dirty_data().  There seem to be several ways in which
>this can happen.
>
>Is it possible that you ran out of disk space on the relevant
>partition shortly before it died?

I think I can safely rule that one out :)

alan:~$ df /export
Filesystem           1k-blocks      Used Available Use% Mounted on
/dev/ataraid/d0p1    240196512  29362544 210833968  13% /export

..that's about as full as it's got, well it may have got up to 50GB used.
[NB for now I've switched the partition to reiserfs (didn't fancy the
fsck), but I'll have a very similar box to play with soon.]

Re: ext3 oops under moderate load

[Stephen C. Tweedie]

Hi,

On Fri, Aug 31, 2001 at 07:41:08PM -0700, Andrew Morton wrote:

> > kernel BUG at revoke.c:307!
> 
> Yours is the third report of this - it's definitely a bug in
> ext3.  I still need to work out how you managed to get a page
> attached to the inode which has not had its buffers fed through
> journal_dirty_data().  There seem to be several ways in which
> this can happen.

I've just been able to reproduce it, using large symlinks.

The killer seems to be a situation when you have a revoked
buffer-cache buffer and we then start allocating, and deallocating,
the same buffer from the page cache.  Large symlinks work from the
page cache and satisfy this condition nicely.

Running a few parallel tasks writing to the end of large sparse files
and truncating them (to create and delete lots of indirect blocks,
populating the buffer cache with revoked data), then adding large
symlink create/delete activity in the same directory, I was able to
reproduce the oops in a few minutes.

I suspect that the same sort of effect is causing the revoke oops
Peter Braam saw with discretionally journaled files.

How to fix?  Well, the issue is that whenever we create any journaled
data, we need to cancel all previous indications of the revoke, even
if the old revoke was in the buffer cache but the new block is in the
page cache.  That implies we effectively need the same as
unmap_underlying_metadata, but for our own specific piece of metadata.
Indeed, unmap_underlying_metadata already does the required lookup of
the old cached buffer_head.  If we can pass in the page and the
looked-up alias to an address_space a_ops, then:

1) we can piggy-back the revoke cleanup on top of the existing
get_hash_table which unmap_underlying_metadata performs; and

2) we can detect whether the calling inode is journaled, so we know
whether or not to clear out the revoke status on the underlying
buffer_head (after all, if we're only allocating the new page as
unjournaled data, the old revoke status should stay intact.)

It's now 10pm and the baby is crying, so I guess that testing the fix
can wait until tomorrow. :)

Cheers,
 Stephen

Re: ext3 oops under moderate load

[Stephen Tweedie]

Hi,

On Fri, Aug 31, 2001 at 07:41:08PM -0700, Andrew Morton wrote:

> > kernel BUG at revoke.c:307!
> 
> Yours is the third report of this - it's definitely a bug in
> ext3.  I still need to work out how you managed to get a page
> attached to the inode which has not had its buffers fed through
> journal_dirty_data().  There seem to be several ways in which
> this can happen.

I've just been able to reproduce it, using large symlinks.

The killer seems to be a situation when you have a revoked
buffer-cache buffer and we then start allocating, and deallocating,
the same buffer from the page cache.  Large symlinks work from the
page cache and satisfy this condition nicely.

Running a few parallel tasks writing to the end of large sparse files
and truncating them (to create and delete lots of indirect blocks,
populating the buffer cache with revoked data), then adding large
symlink create/delete activity in the same directory, I was able to
reproduce the oops in a few minutes.

I suspect that the same sort of effect is causing the revoke oops
Peter Braam saw with discretionally journaled files.

How to fix?  Well, the issue is that whenever we create any journaled
data, we need to cancel all previous indications of the revoke, even
if the old revoke was in the buffer cache but the new block is in the
page cache.  That implies we effectively need the same as
unmap_underlying_metadata, but for our own specific piece of metadata.
Indeed, unmap_underlying_metadata already does the required lookup of
the old cached buffer_head.  If we can pass in the page and the
looked-up alias to an address_space a_ops, then:

1) we can piggy-back the revoke cleanup on top of the existing
get_hash_table which unmap_underlying_metadata performs; and

2) we can detect whether the calling inode is journaled, so we know
whether or not to clear out the revoke status on the underlying
buffer_head (after all, if we're only allocating the new page as
unjournaled data, the old revoke status should stay intact.)

It's now 10pm and the baby is crying, so I guess that testing the fix
can wait until tomorrow. :)

Cheers,
 Stephen

Re: ext3 oops under moderate load

[Steve Kieu]

 --- Stephen Tweedie <sct@redhat.com> wrote: > Hi,
> 
> On Fri, Aug 31, 2001 at 07:41:08PM -0700, Andrew
> Morton wrote:
> 
> > > kernel BUG at revoke.c:307!
> > 
> > Yours is the third report of this - it's
> definitely a bug in
> > ext3.  I still need to work out how you managed to
> get a page
> > attached to the inode which has not had its
> buffers fed through
> > journal_dirty_data().  There seem to be several
> ways in which
> > this can happen.
> 
> I've just been able to reproduce it, using large
> symlinks.
> 
> The killer seems to be a situation when you have a
> revoked
> buffer-cache buffer and we then start allocating,

Just want to add another situation. The previous post
about the system hang-up I suspected DRI module
related but it is not. It wont happen when I mount my
/dev/hda6 as ext2 (not ext3). The hang up happen when
I untar a tgz file (about 20Mb) to a loop device, loop
device attached to a 100Mb file in the ext3 partition.
And at the same time I untar the linux kenel from ext2
partition to ext3 partition. And I am playing Timidity
, running Mozilla. It is not swap related problem.

Hope that you may find it useful for your fix :-)

Cheers,

> and deallocating,
> the same buffer from the page cache.  Large symlinks
> work from the
> page cache and satisfy this condition nicely.
> 
> Running a few parallel tasks writing to the end of
> large sparse files
> and truncating them (to create and delete lots of
> indirect blocks,
> populating the buffer cache with revoked data), then
> adding large
> symlink create/delete activity in the same
> directory, I was able to
> reproduce the oops in a few minutes.
> 
> I suspect that the same sort of effect is causing
> the revoke oops
> Peter Braam saw with discretionally journaled files.
> 
> How to fix?  Well, the issue is that whenever we
> create any journaled
> data, we need to cancel all previous indications of
> the revoke, even
> if the old revoke was in the buffer cache but the
> new block is in the
> page cache.  That implies we effectively need the
> same as
> unmap_underlying_metadata, but for our own specific
> piece of metadata.
> Indeed, unmap_underlying_metadata already does the
> required lookup of
> the old cached buffer_head.  If we can pass in the
> page and the
> looked-up alias to an address_space a_ops, then:
> 
> 1) we can piggy-back the revoke cleanup on top of
> the existing
> get_hash_table which unmap_underlying_metadata
> performs; and
> 
> 2) we can detect whether the calling inode is
> journaled, so we know
> whether or not to clear out the revoke status on the
> underlying
> buffer_head (after all, if we're only allocating the
> new page as
> unjournaled data, the old revoke status should stay
> intact.)
> 
> It's now 10pm and the baby is crying, so I guess
> that testing the fix
> can wait until tomorrow. :)
> 
> Cheers,
>  Stephen
> 
> -
> To unsubscribe from this list: send the line
> "unsubscribe linux-kernel" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at 
> http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at  http://www.tux.org/lkml/ 

=====
S.KIEU

http://travel.yahoo.com.au - Yahoo! Travel
- Got Itchy feet? Get inspired!