ext3 on latest -git: BUG: unable to handle kernel NULL pointer dereference at 0000000c

ext3 on latest -git: BUG: unable to handle kernel NULL pointer dereference at 0000000c

[Vegard Nossum]

Hi,

I get this with both clean v2.6.26 and latest -git
(33af79d12e0fa25545d49e86afc67ea8ad5f2f40):

BUG: unable to handle kernel NULL pointer dereference at 0000000c
IP: [<c01fd1e0>] journal_dirty_metadata+0xa0/0x160
*pde = 00000000
Oops: 0000 [#1] PREEMPT SMP DEBUG_PAGEALLOC
Pid: 4935, comm: rm Not tainted (2.6.26-03414-g33af79d #39)
EIP: 0060:[<c01fd1e0>] EFLAGS: 00210246 CPU: 1
EIP is at journal_dirty_metadata+0xa0/0x160
EAX: 00000000 EBX: cca59160 ECX: 00000001 EDX: f5114000
ESI: 00000000 EDI: f3d27750 EBP: f5115d58 ESP: f5115d40
 DS: 007b ES: 007b FS: 00d8 GS: 0033 SS: 0068
Process rm (pid: 4935, ti=f5114000 task=f6a04fb0 task.ti=f5114000)
Stack: 00000001 f77d0050 cca00c90 f3d27750 f77d0050 f3d27750 f5115d78 c01f9eff
       00000001 00000001 c05c2a53 f3d27750 00000000 f60da560 f5115da8 c01ef9ef
       00000001 00000001 f60da560 f60da800 f3d27750 f3cc5944 f77d0050 f3d27750
Call Trace:
 [<c01f9eff>] ? __ext3_journal_dirty_metadata+0x1f/0x50
 [<c01ef9ef>] ? ext3_free_data+0x9f/0x100
 [<c01efc8b>] ? ext3_free_branches+0x23b/0x250
 [<c01c8cc0>] ? sync_buffer+0x0/0x40
 [<c01efafe>] ? ext3_free_branches+0xae/0x250
 [<c01efafe>] ? ext3_free_branches+0xae/0x250
 [<c01f0268>] ? ext3_truncate+0x5c8/0x940
 [<c015ad76>] ? trace_hardirqs_on_caller+0x116/0x170
 [<c01ff1d0>] ? journal_start+0xb0/0x110
 [<c01ff1f3>] ? journal_start+0xd3/0x110
 [<c01ff1d0>] ? journal_start+0xb0/0x110
 [<c01f7cb9>] ? ext3_journal_start_sb+0x29/0x50
 [<c01f06b7>] ? ext3_delete_inode+0xd7/0xe0
 [<c01f05e0>] ? ext3_delete_inode+0x0/0xe0
 [<c01b97c2>] ? generic_delete_inode+0x62/0xe0
 [<c01b995d>] ? generic_drop_inode+0x11d/0x170
 [<c01b8877>] ? iput+0x47/0x50
 [<c01aee4c>] ? do_unlinkat+0xec/0x170
 [<c0293dd8>] ? trace_hardirqs_on_thunk+0xc/0x10
 [<c0120140>] ? do_page_fault+0x0/0x880
 [<c015ad76>] ? trace_hardirqs_on_caller+0x116/0x170
 [<c01af013>] ? sys_unlinkat+0x23/0x50
 [<c010407f>] ? sysenter_past_esp+0x78/0xc5
 =======================
Code: b8 01 00 00 00 e8 f1 57 f3 ff 89 e0 25 00 e0 ff ff f6 40 08 08
74 05 e8 2f e6 3a 00 83 c4 0c 31 c0 5b 5e 5f 5d c3 90 8d 74 26 00 <8b>
46 0c 85 c0 0f 84 8c 00 00 00 39 5e 18 74 68 8d 47 02 89 45
EIP: [<c01fd1e0>] journal_dirty_metadata+0xa0/0x160 SS:ESP 0068:f5115d40
---[ end trace ad9c7bca1cad9e55 ]---

This corresponds to "jh" being NULL in journal_dirty_metadata():

        if (jh->b_modified == 0) {

I also tried with this patch, but without success:

    http://folk.uio.no/vegardno/linux/jbd-transaction.patch

so the problem seems quite reproducible by intentionally corrupting a
disk image.


Vegard

-- 
"The animistic metaphor of the bug that maliciously sneaked in while
the programmer was not looking is intellectually dishonest as it
disguises that the error is the programmer's own creation."
	-- E. W. Dijkstra, EWD1036

Re: ext3 on latest -git: BUG: unable to handle kernel NULL pointer dereference at 0000000c

[Josef Bacik]

On Thu, Jul 17, 2008 at 8:51 AM, Vegard Nossum <vegard.nossum@gmail.com> wrote:
> Hi,
>
> I get this with both clean v2.6.26 and latest -git
> (33af79d12e0fa25545d49e86afc67ea8ad5f2f40):
>

Thanks for the report, do you happen to have any messages above the
panic message that would indicate if there was some sort of fs error
that was hit before the panic?  That would help me figure out what
exactly happened.  Thanks,

Josef

Re: ext3 on latest -git: BUG: unable to handle kernel NULL pointer dereference at 0000000c

[Vegard Nossum]

On Thu, Jul 17, 2008 at 3:13 PM, Josef Bacik <josef@toxicpanda.com> wrote:
> On Thu, Jul 17, 2008 at 8:51 AM, Vegard Nossum <vegard.nossum@gmail.com> wrote:
>> Hi,
>>
>> I get this with both clean v2.6.26 and latest -git
>> (33af79d12e0fa25545d49e86afc67ea8ad5f2f40):
>>
>
> Thanks for the report, do you happen to have any messages above the
> panic message that would indicate if there was some sort of fs error
> that was hit before the panic?  That would help me figure out what
> exactly happened.  Thanks,

Yeah, the full log exists at

    http://folk.uio.no/vegardno/linux/log-1216293934.txt

I think this is the interesting part:

kjournald starting.  Commit interval 5 seconds
EXT3-fs warning: mounting fs with errors, running e2fsck is recommended
EXT3 FS on loop0, internal journal
EXT3-fs: mounted filesystem with ordered data mode.
EXT3-fs error (device loop0): ext3_free_blocks_sb: bit already cleared
for block 1507
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
datazone - block = 1050159, count = 1
EXT3-fs error (device loop0) in ext3_reserve_inode_write: IO failure
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
datazone - block = 2048, count = 1
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
datazone - block = 102, count = 1
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
datazone - block = 496, count = 1
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
datazone - block = 245, count = 1
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
datazone - block = 1, count = 1
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
datazone - block = 8192, count = 1
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
datazone - block = 8192, count = 1
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
datazone - block = 256, count = 1
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
datazone - block = 1216293753, count = 1
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
datazone - block = 1216293753, count = 1
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
datazone - block = 1703965, count = 1
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
datazone - block = 257875, count = 1
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
datazone - block = 1, count = 1
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
datazone - block = 1216293738, count = 1
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
datazone - block = 15552000, count = 1
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
datazone - block = 1, count = 1
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
datazone - block = 11, count = 1
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
datazone - block = 128, count = 1
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
datazone - block = 52, count = 1
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
datazone - block = 6, count = 1
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
datazone - block = 1, count = 1
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
datazone - block = 3246399477, count = 1
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
datazone - block = 860559364, count = 1
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
datazone - block = 1659021227, count = 1
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
datazone - block = 2723221558, count = 1
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
datazone - block = 458752, count = 1
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
datazone - block = 8, count = 1
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
datazone - block = 11, count = 1
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
datazone - block = 1092049505, count = 1
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
datazone - block = 2823687499, count = 1
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
datazone - block = 2276435116, count = 1
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
datazone - block = 2703362334, count = 1
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
datazone - block = 258, count = 1
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
datazone - block = 1216293738, count = 1
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
datazone - block = 58, count = 13
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
datazone - block = 327, count = 1
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
datazone - block = 1048576, count = 1
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
datazone - block = 1, count = 1
BUG: unable to handle kernel NULL pointer dereference at 0000000c
IP: [<c01fd1e0>] journal_dirty_metadata+0xa0/0x160

Would it also help to reproduce with jbd/ext3 debug enabled? (If it
isn't already.)


Vegard

-- 
"The animistic metaphor of the bug that maliciously sneaked in while
the programmer was not looking is intellectually dishonest as it
disguises that the error is the programmer's own creation."
	-- E. W. Dijkstra, EWD1036

Re: ext3 on latest -git: BUG: unable to handle kernel NULL pointer dereference at 0000000c

[Josef Bacik]

On Thu, Jul 17, 2008 at 9:20 AM, Vegard Nossum <vegard.nossum@gmail.com> wrote:
> On Thu, Jul 17, 2008 at 3:13 PM, Josef Bacik <josef@toxicpanda.com> wrote:
>> On Thu, Jul 17, 2008 at 8:51 AM, Vegard Nossum <vegard.nossum@gmail.com> wrote:
>>> Hi,
>>>
>>> I get this with both clean v2.6.26 and latest -git
>>> (33af79d12e0fa25545d49e86afc67ea8ad5f2f40):
>>>
>>
>> Thanks for the report, do you happen to have any messages above the
>> panic message that would indicate if there was some sort of fs error
>> that was hit before the panic?  That would help me figure out what
>> exactly happened.  Thanks,
>
> Yeah, the full log exists at
>
>    http://folk.uio.no/vegardno/linux/log-1216293934.txt
>
> I think this is the interesting part:

Hmm well the journal should have aborted, but it looks like it didn't,
are you mounting with errors=continue by any chance?  Thanks much,

Josef

Re: ext3 on latest -git: BUG: unable to handle kernel NULL pointer dereference at 0000000c

[Vegard Nossum]

On Thu, Jul 17, 2008 at 3:34 PM, Josef Bacik <josef@toxicpanda.com> wrote:
>> Yeah, the full log exists at
>>
>>    http://folk.uio.no/vegardno/linux/log-1216293934.txt
>>
>> I think this is the interesting part:
>
> Hmm well the journal should have aborted, but it looks like it didn't,
> are you mounting with errors=continue by any chance?  Thanks much,

No, this is the command I used:

        mount -o loop disk mnt

I think this looks interesting:

EXT3-fs error (device loop0) in ext3_reserve_inode_write: IO failure

The code in ext3_reserve_inode_write() is here:

        err = ext3_journal_get_write_access(handle, iloc->bh);
        if (err) {
                brelse(iloc->bh);
                iloc->bh = NULL;
        }

Maybe it should do something different here?

But I don't know :-)

Thanks for helping out!


Vegard

-- 
"The animistic metaphor of the bug that maliciously sneaked in while
the programmer was not looking is intellectually dishonest as it
disguises that the error is the programmer's own creation."
	-- E. W. Dijkstra, EWD1036

Re: ext3 on latest -git: BUG: unable to handle kernel NULL pointer dereference at 0000000c

[Josef Bacik]

On Thu, Jul 17, 2008 at 03:39:24PM +0200, Vegard Nossum wrote:
> On Thu, Jul 17, 2008 at 3:34 PM, Josef Bacik <josef@toxicpanda.com> wrote:
> >> Yeah, the full log exists at
> >>
> >>    http://folk.uio.no/vegardno/linux/log-1216293934.txt
> >>
> >> I think this is the interesting part:
> >
> > Hmm well the journal should have aborted, but it looks like it didn't,
> > are you mounting with errors=continue by any chance?  Thanks much,
> 
> No, this is the command I used:
> 
>         mount -o loop disk mnt
> 
> I think this looks interesting:
> 
> EXT3-fs error (device loop0) in ext3_reserve_inode_write: IO failure
> 
> The code in ext3_reserve_inode_write() is here:
> 
>         err = ext3_journal_get_write_access(handle, iloc->bh);
>         if (err) {
>                 brelse(iloc->bh);
>                 iloc->bh = NULL;
>         }
> 
> Maybe it should do something different here?
> 
> But I don't know :-)
> 
> Thanks for helping out!
>

Well this is really odd, after that we call ext3_std_error which calls
journal_abort, so when we come into journal_dirty_metadata is_handle_aborted()
should have returned 1 and we should have just exited.  I'm going to have to
think on this for a bit.

Josef 

Re: ext3 on latest -git: BUG: unable to handle kernel NULL pointer dereference at 0000000c

[Josef Bacik]

On Thu, Jul 17, 2008 at 03:39:24PM +0200, Vegard Nossum wrote:
> On Thu, Jul 17, 2008 at 3:34 PM, Josef Bacik <josef@toxicpanda.com> wrote:
> >> Yeah, the full log exists at
> >>
> >>    http://folk.uio.no/vegardno/linux/log-1216293934.txt
> >>
> >> I think this is the interesting part:
> >
> > Hmm well the journal should have aborted, but it looks like it didn't,
> > are you mounting with errors=continue by any chance?  Thanks much,
> 
> No, this is the command I used:
> 
>         mount -o loop disk mnt
> 
> I think this looks interesting:
> 
> EXT3-fs error (device loop0) in ext3_reserve_inode_write: IO failure
> 
> The code in ext3_reserve_inode_write() is here:
> 
>         err = ext3_journal_get_write_access(handle, iloc->bh);
>         if (err) {
>                 brelse(iloc->bh);
>                 iloc->bh = NULL;
>         }
> 
> Maybe it should do something different here?
> 
> But I don't know :-)
> 
> Thanks for helping out!
> 
>

Can you try this patch out and see if it fixes the problem?  I didn't compile
test it, so you may need to tweak somethings, but it should work.  Thanks,

Signed-off-by: Josef Bacik <jbacik@redhat.com>

 
Index: linux-2.6/fs/ext3/inode.c
===================================================================
--- linux-2.6.orig/fs/ext3/inode.c
+++ linux-2.6/fs/ext3/inode.c
@@ -2023,13 +2023,27 @@ static void ext3_clear_blocks(handle_t *
 		unsigned long count, __le32 *first, __le32 *last)
 {
 	__le32 *p;
+	int ret;
+
 	if (try_to_extend_transaction(handle, inode)) {
 		if (bh) {
 			BUFFER_TRACE(bh, "call ext3_journal_dirty_metadata");
-			ext3_journal_dirty_metadata(handle, bh);
+			ret = ext3_journal_dirty_metadata(handle, bh);
+			if (ret) {
+				ext3_std_error(inode->i_sb, ret);
+				return;
+			}
 		}
-		ext3_mark_inode_dirty(handle, inode);
-		ext3_journal_test_restart(handle, inode);
+		ret = ext3_mark_inode_dirty(handle, inode);
+		if (ret)
+			return;
+
+		ret = ext3_journal_test_restart(handle, inode);
+		if (ret) {
+			ext3_std_error(inode->i_sb, ret);
+			return;
+		}
+
 		if (bh) {
 			BUFFER_TRACE(bh, "retaking write access");
 			ext3_journal_get_write_access(handle, bh);

Re: ext3 on latest -git: BUG: unable to handle kernel NULL pointer dereference at 0000000c

[Vegard Nossum]

On Thu, Jul 17, 2008 at 3:57 PM, Josef Bacik <jbacik@redhat.com> wrote:
> Can you try this patch out and see if it fixes the problem?  I didn't compile
> test it, so you may need to tweak somethings, but it should work.  Thanks,
>
> Signed-off-by: Josef Bacik <jbacik@redhat.com>

Nope, seems to be the same problem:

kjournald starting.  Commit interval 5 seconds
EXT3-fs warning: mounting fs with errors, running e2fsck is recommended
EXT3 FS on loop0, internal journal
EXT3-fs: mounted filesystem with ordered data mode.
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks in
system zones - Block = 16, count = 1
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks in
system zones - Block = 32, count = 1
EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
datazone - block = 262144, count = 1
BUG: unable to handle kernel NULL pointer dereference at 0000000c
IP: [<c01fd210>] journal_dirty_metadata+0xa0/0x160

Full log at http://folk.uio.no/vegardno/linux/log-1216304953.txt


Vegard

-- 
"The animistic metaphor of the bug that maliciously sneaked in while
the programmer was not looking is intellectually dishonest as it
disguises that the error is the programmer's own creation."
	-- E. W. Dijkstra, EWD1036

Re: ext3 on latest -git: BUG: unable to handle kernel NULL pointer dereference at 0000000c

[Josef Bacik]

On Thu, Jul 17, 2008 at 04:25:49PM +0200, Vegard Nossum wrote:
> On Thu, Jul 17, 2008 at 3:57 PM, Josef Bacik <jbacik@redhat.com> wrote:
> > Can you try this patch out and see if it fixes the problem?  I didn't compile
> > test it, so you may need to tweak somethings, but it should work.  Thanks,
> >
> > Signed-off-by: Josef Bacik <jbacik@redhat.com>
> 
> Nope, seems to be the same problem:
> 
> kjournald starting.  Commit interval 5 seconds
> EXT3-fs warning: mounting fs with errors, running e2fsck is recommended
> EXT3 FS on loop0, internal journal
> EXT3-fs: mounted filesystem with ordered data mode.
> EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks in
> system zones - Block = 16, count = 1
> EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks in
> system zones - Block = 32, count = 1
> EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
> datazone - block = 262144, count = 1
> BUG: unable to handle kernel NULL pointer dereference at 0000000c
> IP: [<c01fd210>] journal_dirty_metadata+0xa0/0x160
> 
> Full log at http://folk.uio.no/vegardno/linux/log-1216304953.txt
> 
>

Ok, this should do it then.  Thanks,

Josef

 
Index: linux-2.6/fs/ext3/inode.c
===================================================================
--- linux-2.6.orig/fs/ext3/inode.c
+++ linux-2.6/fs/ext3/inode.c
@@ -2023,13 +2023,27 @@ static void ext3_clear_blocks(handle_t *
 		unsigned long count, __le32 *first, __le32 *last)
 {
 	__le32 *p;
+	int ret;
+
 	if (try_to_extend_transaction(handle, inode)) {
 		if (bh) {
 			BUFFER_TRACE(bh, "call ext3_journal_dirty_metadata");
-			ext3_journal_dirty_metadata(handle, bh);
+			ret = ext3_journal_dirty_metadata(handle, bh);
+			if (ret) {
+				ext3_std_error(inode->i_sb, ret);
+				return;
+			}
 		}
-		ext3_mark_inode_dirty(handle, inode);
-		ext3_journal_test_restart(handle, inode);
+		ret = ext3_mark_inode_dirty(handle, inode);
+		if (ret)
+			return;
+
+		ret = ext3_journal_test_restart(handle, inode);
+		if (ret) {
+			ext3_std_error(inode->i_sb, ret);
+			return;
+		}
+
 		if (bh) {
 			BUFFER_TRACE(bh, "retaking write access");
 			ext3_journal_get_write_access(handle, bh);
Index: linux-2.6/fs/ext3/balloc.c
===================================================================
--- linux-2.6.orig/fs/ext3/balloc.c
+++ linux-2.6/fs/ext3/balloc.c
@@ -498,6 +498,7 @@ void ext3_free_blocks_sb(handle_t *handl
 		ext3_error (sb, "ext3_free_blocks",
 			    "Freeing blocks not in datazone - "
 			    "block = "E3FSBLK", count = %lu", block, count);
+		err = -EIO;
 		goto error_return;
 	}
 
@@ -535,6 +536,7 @@ do_more:
 			    "Freeing blocks in system zones - "
 			    "Block = "E3FSBLK", count = %lu",
 			    block, count);
+		err = -EIO;
 		goto error_return;
 	}
 

Re: ext3 on latest -git: BUG: unable to handle kernel NULL pointer dereference at 0000000c

[Vegard Nossum]

On Thu, Jul 17, 2008 at 4:13 PM, Josef Bacik <jbacik@redhat.com> wrote:
> On Thu, Jul 17, 2008 at 04:25:49PM +0200, Vegard Nossum wrote:
>> On Thu, Jul 17, 2008 at 3:57 PM, Josef Bacik <jbacik@redhat.com> wrote:
>> > Can you try this patch out and see if it fixes the problem?  I didn't compile
>> > test it, so you may need to tweak somethings, but it should work.  Thanks,
>> >
>> > Signed-off-by: Josef Bacik <jbacik@redhat.com>
>>
>> Nope, seems to be the same problem:
>>
>> kjournald starting.  Commit interval 5 seconds
>> EXT3-fs warning: mounting fs with errors, running e2fsck is recommended
>> EXT3 FS on loop0, internal journal
>> EXT3-fs: mounted filesystem with ordered data mode.
>> EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks in
>> system zones - Block = 16, count = 1
>> EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks in
>> system zones - Block = 32, count = 1
>> EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
>> datazone - block = 262144, count = 1
>> BUG: unable to handle kernel NULL pointer dereference at 0000000c
>> IP: [<c01fd210>] journal_dirty_metadata+0xa0/0x160
>>
>> Full log at http://folk.uio.no/vegardno/linux/log-1216304953.txt
>>
>>
>
> Ok, this should do it then.  Thanks,

Hm, it doesn't apply. Should I revert the previous patch?


Vegard

-- 
"The animistic metaphor of the bug that maliciously sneaked in while
the programmer was not looking is intellectually dishonest as it
disguises that the error is the programmer's own creation."
	-- E. W. Dijkstra, EWD1036

Re: ext3 on latest -git: BUG: unable to handle kernel NULL pointer dereference at 0000000c

[Josef Bacik]

On Thu, Jul 17, 2008 at 04:35:16PM +0200, Vegard Nossum wrote:
> On Thu, Jul 17, 2008 at 4:13 PM, Josef Bacik <jbacik@redhat.com> wrote:
> > On Thu, Jul 17, 2008 at 04:25:49PM +0200, Vegard Nossum wrote:
> >> On Thu, Jul 17, 2008 at 3:57 PM, Josef Bacik <jbacik@redhat.com> wrote:
> >> > Can you try this patch out and see if it fixes the problem?  I didn't compile
> >> > test it, so you may need to tweak somethings, but it should work.  Thanks,
> >> >
> >> > Signed-off-by: Josef Bacik <jbacik@redhat.com>
> >>
> >> Nope, seems to be the same problem:
> >>
> >> kjournald starting.  Commit interval 5 seconds
> >> EXT3-fs warning: mounting fs with errors, running e2fsck is recommended
> >> EXT3 FS on loop0, internal journal
> >> EXT3-fs: mounted filesystem with ordered data mode.
> >> EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks in
> >> system zones - Block = 16, count = 1
> >> EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks in
> >> system zones - Block = 32, count = 1
> >> EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
> >> datazone - block = 262144, count = 1
> >> BUG: unable to handle kernel NULL pointer dereference at 0000000c
> >> IP: [<c01fd210>] journal_dirty_metadata+0xa0/0x160
> >>
> >> Full log at http://folk.uio.no/vegardno/linux/log-1216304953.txt
> >>
> >>
> >
> > Ok, this should do it then.  Thanks,
> 
> Hm, it doesn't apply. Should I revert the previous patch?
>

Yeah sorry about that.

Josef 

Re: ext3 on latest -git: BUG: unable to handle kernel NULL pointer dereference at 0000000c

[Vegard Nossum]

On Thu, Jul 17, 2008 at 4:16 PM, Josef Bacik <jbacik@redhat.com> wrote:
> On Thu, Jul 17, 2008 at 04:35:16PM +0200, Vegard Nossum wrote:
>> On Thu, Jul 17, 2008 at 4:13 PM, Josef Bacik <jbacik@redhat.com> wrote:
>> > On Thu, Jul 17, 2008 at 04:25:49PM +0200, Vegard Nossum wrote:
>> >> On Thu, Jul 17, 2008 at 3:57 PM, Josef Bacik <jbacik@redhat.com> wrote:
>> >> > Can you try this patch out and see if it fixes the problem?  I didn't compile
>> >> > test it, so you may need to tweak somethings, but it should work.  Thanks,
>> >> >
>> >> > Signed-off-by: Josef Bacik <jbacik@redhat.com>
>> >>
>> >> Nope, seems to be the same problem:
>> >>
>> >> kjournald starting.  Commit interval 5 seconds
>> >> EXT3-fs warning: mounting fs with errors, running e2fsck is recommended
>> >> EXT3 FS on loop0, internal journal
>> >> EXT3-fs: mounted filesystem with ordered data mode.
>> >> EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks in
>> >> system zones - Block = 16, count = 1
>> >> EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks in
>> >> system zones - Block = 32, count = 1
>> >> EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
>> >> datazone - block = 262144, count = 1
>> >> BUG: unable to handle kernel NULL pointer dereference at 0000000c
>> >> IP: [<c01fd210>] journal_dirty_metadata+0xa0/0x160
>> >>
>> >> Full log at http://folk.uio.no/vegardno/linux/log-1216304953.txt
>> >>
>> >>
>> >
>> > Ok, this should do it then.  Thanks,

-ENOLUCK

EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
datazone - block = 524288, count = 1
EXT3-fs error (device loop0) in ext3_free_blocks_sb: IO failure
BUG: unable to handle kernel NULL pointer dereference at 0000000c
IP: [<c01fd200>] journal_dirty_metadata+0xa0/0x160

It did seem to get further, though.

http://folk.uio.no/vegardno/linux/log-1216306142.txt


Vegard

-- 
"The animistic metaphor of the bug that maliciously sneaked in while
the programmer was not looking is intellectually dishonest as it
disguises that the error is the programmer's own creation."
	-- E. W. Dijkstra, EWD1036

Re: ext3 on latest -git: BUG: unable to handle kernel NULL pointer dereference at 0000000c

[Josef Bacik]

On Thu, Jul 17, 2008 at 04:44:47PM +0200, Vegard Nossum wrote:
> On Thu, Jul 17, 2008 at 4:16 PM, Josef Bacik <jbacik@redhat.com> wrote:
> > On Thu, Jul 17, 2008 at 04:35:16PM +0200, Vegard Nossum wrote:
> >> On Thu, Jul 17, 2008 at 4:13 PM, Josef Bacik <jbacik@redhat.com> wrote:
> >> > On Thu, Jul 17, 2008 at 04:25:49PM +0200, Vegard Nossum wrote:
> >> >> On Thu, Jul 17, 2008 at 3:57 PM, Josef Bacik <jbacik@redhat.com> wrote:
> >> >> > Can you try this patch out and see if it fixes the problem?  I didn't compile
> >> >> > test it, so you may need to tweak somethings, but it should work.  Thanks,
> >> >> >
> >> >> > Signed-off-by: Josef Bacik <jbacik@redhat.com>
> >> >>
> >> >> Nope, seems to be the same problem:
> >> >>
> >> >> kjournald starting.  Commit interval 5 seconds
> >> >> EXT3-fs warning: mounting fs with errors, running e2fsck is recommended
> >> >> EXT3 FS on loop0, internal journal
> >> >> EXT3-fs: mounted filesystem with ordered data mode.
> >> >> EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks in
> >> >> system zones - Block = 16, count = 1
> >> >> EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks in
> >> >> system zones - Block = 32, count = 1
> >> >> EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
> >> >> datazone - block = 262144, count = 1
> >> >> BUG: unable to handle kernel NULL pointer dereference at 0000000c
> >> >> IP: [<c01fd210>] journal_dirty_metadata+0xa0/0x160
> >> >>
> >> >> Full log at http://folk.uio.no/vegardno/linux/log-1216304953.txt
> >> >>
> >> >>
> >> >
> >> > Ok, this should do it then.  Thanks,
> 
> -ENOLUCK
> 
> EXT3-fs error (device loop0): ext3_free_blocks: Freeing blocks not in
> datazone - block = 524288, count = 1
> EXT3-fs error (device loop0) in ext3_free_blocks_sb: IO failure
> BUG: unable to handle kernel NULL pointer dereference at 0000000c
> IP: [<c01fd200>] journal_dirty_metadata+0xa0/0x160
> 
> It did seem to get further, though.
> 
> http://folk.uio.no/vegardno/linux/log-1216306142.txt
>

Ok run dumpe2fs -h on your image and see if you have a line that says

Errors behavior:          Continue

if you do run tune2fs -e remount-ro and then do the mount.  That would explain
why you are still having panics even though we should be aborting the journal.
Thanks,

Josef 

Re: ext3 on latest -git: BUG: unable to handle kernel NULL pointer dereference at 0000000c

[Vegard Nossum]

On Thu, Jul 17, 2008 at 4:33 PM, Josef Bacik <jbacik@redhat.com> wrote:
> Ok run dumpe2fs -h on your image and see if you have a line that says
>
> Errors behavior:          Continue
>
> if you do run tune2fs -e remount-ro and then do the mount.  That would explain
> why you are still having panics even though we should be aborting the journal.
> Thanks,

Ahh, that probably explains it. I didn't realize there was such a thing.

I am doing random-corruption tests, so it is quite possible that this
bit gets set anywhere along the road...

But even so, is it correct that the kernel should crash? It seems
quite possible that error behaviour can change (like this) even with
"normal" corruption, e.g. outside my test scripts.

But I cannot even run dumpe2fs on my image (even with -f switch):

dumpe2fs: Bad magic number in super-block while trying to open disk



Vegard

-- 
"The animistic metaphor of the bug that maliciously sneaked in while
the programmer was not looking is intellectually dishonest as it
disguises that the error is the programmer's own creation."
	-- E. W. Dijkstra, EWD1036

Re: ext3 on latest -git: BUG: unable to handle kernel NULL pointer dereference at 0000000c

[Josef Bacik]

On Thu, Jul 17, 2008 at 05:00:07PM +0200, Vegard Nossum wrote:
> On Thu, Jul 17, 2008 at 4:33 PM, Josef Bacik <jbacik@redhat.com> wrote:
> > Ok run dumpe2fs -h on your image and see if you have a line that says
> >
> > Errors behavior:          Continue
> >
> > if you do run tune2fs -e remount-ro and then do the mount.  That would explain
> > why you are still having panics even though we should be aborting the journal.
> > Thanks,
> 
> Ahh, that probably explains it. I didn't realize there was such a thing.
> 
> I am doing random-corruption tests, so it is quite possible that this
> bit gets set anywhere along the road...
> 
> But even so, is it correct that the kernel should crash? It seems
> quite possible that error behaviour can change (like this) even with
> "normal" corruption, e.g. outside my test scripts.
>

Yeah thats a hard to answer question, one that I will leave up to others who
have been doing this much longer than I.  My thought is remount-ro is there to
keep you from crashing, so if you have errors=continue then you expect to live
with the consequences.  Course if that bit gets flipped via corruption thats not
good either.  Thanks,

Josef

Re: ext3 on latest -git: BUG: unable to handle kernel NULL pointer dereference at 0000000c

[Andreas Dilger]

On Jul 17, 2008  10:43 -0400, Josef Bacik wrote:
> Yeah thats a hard to answer question, one that I will leave up to others
> who have been doing this much longer than I.  My thought is remount-ro
> is there to keep you from crashing, so if you have errors=continue then
> you expect to live with the consequences.  Course if that bit gets flipped
> via corruption thats not good either.

It shouldn't cause the kernel to crash, but it should definitely return
an error to the application.  This is probably one of the code paths
that the Coverity folks were reporting on in FAST this year where on-disk
errors are not propagated to the application.

Cheers, Andreas
--
Andreas Dilger
Sr. Staff Engineer, Lustre Group
Sun Microsystems of Canada, Inc.

Re: ext3 on latest -git: BUG: unable to handle kernel NULL pointer dereference at 0000000c

[Josef Bacik]

On Thu, Jul 17, 2008 at 05:09:05PM -0600, Andreas Dilger wrote:
> On Jul 17, 2008  10:43 -0400, Josef Bacik wrote:
> > Yeah thats a hard to answer question, one that I will leave up to others
> > who have been doing this much longer than I.  My thought is remount-ro
> > is there to keep you from crashing, so if you have errors=continue then
> > you expect to live with the consequences.  Course if that bit gets flipped
> > via corruption thats not good either.
> 
> It shouldn't cause the kernel to crash, but it should definitely return
> an error to the application.  This is probably one of the code paths
> that the Coverity folks were reporting on in FAST this year where on-disk
> errors are not propagated to the application.

Ok, please revert the previous patch and apply this one.  On errors=continue we
will just abort the handle which should keep the NULL pointer dereference from
happening and return an error back to the application.  Please let me know how
this works Vegard, and thanks alot for testing all this.

Signed-off-by: Josef Bacik <jbacik@redhat.com>

Index: linux-2.6/fs/ext3/inode.c
===================================================================
--- linux-2.6.orig/fs/ext3/inode.c
+++ linux-2.6/fs/ext3/inode.c
@@ -2023,13 +2023,27 @@ static void ext3_clear_blocks(handle_t *
 		unsigned long count, __le32 *first, __le32 *last)
 {
 	__le32 *p;
+	int ret;
+
 	if (try_to_extend_transaction(handle, inode)) {
 		if (bh) {
 			BUFFER_TRACE(bh, "call ext3_journal_dirty_metadata");
-			ext3_journal_dirty_metadata(handle, bh);
+			ret = ext3_journal_dirty_metadata(handle, bh);
+			if (ret) {
+				ext3_std_error(inode->i_sb, ret);
+				return;
+			}
 		}
-		ext3_mark_inode_dirty(handle, inode);
-		ext3_journal_test_restart(handle, inode);
+		ret = ext3_mark_inode_dirty(handle, inode);
+		if (ret)
+			return;
+
+		ret = ext3_journal_test_restart(handle, inode);
+		if (ret) {
+			ext3_std_error(inode->i_sb, ret);
+			return;
+		}
+
 		if (bh) {
 			BUFFER_TRACE(bh, "retaking write access");
 			ext3_journal_get_write_access(handle, bh);
Index: linux-2.6/fs/ext3/balloc.c
===================================================================
--- linux-2.6.orig/fs/ext3/balloc.c
+++ linux-2.6/fs/ext3/balloc.c
@@ -498,6 +498,7 @@ void ext3_free_blocks_sb(handle_t *handl
 		ext3_error (sb, "ext3_free_blocks",
 			    "Freeing blocks not in datazone - "
 			    "block = "E3FSBLK", count = %lu", block, count);
+		err = -EIO;
 		goto error_return;
 	}
 
@@ -535,6 +536,7 @@ do_more:
 			    "Freeing blocks in system zones - "
 			    "Block = "E3FSBLK", count = %lu",
 			    block, count);
+		err = -EIO;
 		goto error_return;
 	}
 
Index: linux-2.6/fs/ext3/super.c
===================================================================
--- linux-2.6.orig/fs/ext3/super.c
+++ linux-2.6/fs/ext3/super.c
@@ -167,7 +167,15 @@ static void ext3_handle_error(struct sup
 		EXT3_SB(sb)->s_mount_opt |= EXT3_MOUNT_ABORT;
 		if (journal)
 			journal_abort(journal, -EIO);
+	} else {
+		handle_t *handle = current->journal_info;
+		if (handle && !is_handle_aborted(handle)) {
+			if (!handle->h_err)
+				handle->h_err = -EIO;
+			journal_abort_handle(handle);
+		}
 	}
+
 	if (test_opt (sb, ERRORS_RO)) {
 		printk (KERN_CRIT "Remounting filesystem read-only\n");
 		sb->s_flags |= MS_RDONLY;

Re: ext3 on latest -git: BUG: unable to handle kernel NULL pointer dereference at 0000000c

[Vegard Nossum]

On Fri, Jul 18, 2008 at 12:51 PM, Josef Bacik <jbacik@redhat.com> wrote:
> On Thu, Jul 17, 2008 at 05:09:05PM -0600, Andreas Dilger wrote:
>> On Jul 17, 2008  10:43 -0400, Josef Bacik wrote:
>> > Yeah thats a hard to answer question, one that I will leave up to others
>> > who have been doing this much longer than I.  My thought is remount-ro
>> > is there to keep you from crashing, so if you have errors=continue then
>> > you expect to live with the consequences.  Course if that bit gets flipped
>> > via corruption thats not good either.
>>
>> It shouldn't cause the kernel to crash, but it should definitely return
>> an error to the application.  This is probably one of the code paths
>> that the Coverity folks were reporting on in FAST this year where on-disk
>> errors are not propagated to the application.
>
> Ok, please revert the previous patch and apply this one.  On errors=continue we
> will just abort the handle which should keep the NULL pointer dereference from
> happening and return an error back to the application.  Please let me know how
> this works Vegard, and thanks alot for testing all this.
>
> Signed-off-by: Josef Bacik <jbacik@redhat.com>

Thanks for doing the patches :-)

I still got this:

loop0: rw=0, want=4294967298, limit=24576
EXT3-fs error (device loop0): ext3_free_branches: Read failure,
inode=74, block=2147483648
EXT3-fs error (device loop0) in ext3_reserve_inode_write: Readonly filesystem
EXT3-fs error (device loop0) in ext3_truncate: IO failure
EXT3-fs error (device loop0) in ext3_reserve_inode_write: Readonly filesystem
EXT3-fs error (device loop0) in ext3_orphan_del: Readonly filesystem
EXT3-fs error (device loop0) in ext3_reserve_inode_write: Readonly filesystem
EXT3-fs error (device loop0) in ext3_delete_inode: IO failure
EXT3-fs unexpected failure: !jh->b_committed_data;
inconsistent data on disk
ext3_forget: aborting transaction: IO failure in __ext3_journal_forget
BUG: unable to handle kernel paging request at f1e79ffc
IP: [<c02224d6>] read_block_bitmap+0xc6/0x180
*pde = 33cc5163 *pte = 31e79160
Oops: 0000 [#1] PREEMPT SMP DEBUG_PAGEALLOC
Pid: 4257, comm: rm Not tainted (2.6.26-03416-g11155ca #46)
EIP: 0060:[<c02224d6>] EFLAGS: 00210297 CPU: 1
EIP is at read_block_bitmap+0xc6/0x180
EAX: ffffffff EBX: f1e7a000 ECX: f3c20000 EDX: 00000001
ESI: f5663c30 EDI: f1e7a800 EBP: f62e3cdc ESP: f62e3cac
 DS: 007b ES: 007b FS: 00d8 GS: 0033 SS: 0068
Process rm (pid: 4257, ti=f62e2000 task=f637dfa0 task.ti=f62e2000)
Stack: 00000400 f637e4c0 f637dfa0 f62e3cd4 00200246 00000000 f3d2c860 00000000
       f1e7a000 f3c20098 00000000 f56c4b7c f62e3d3c c0222704 c025efd3 f637dfa0
       c015addb f77aa050 f3d2db0c 00000031 00000000 00000032 f3d2c860 f77aa050
Call Trace:
 [<c0222704>] ? ext3_free_blocks_sb+0xd4/0x620
 [<c025efd3>] ? journal_forget+0x213/0x220
 [<c015addb>] ? trace_hardirqs_on+0xb/0x10
 [<c0222c7a>] ? ext3_free_blocks+0x2a/0xa0
 [<c0228d85>] ? ext3_clear_blocks+0x145/0x160
 [<c0228e67>] ? ext3_free_data+0xc7/0x100
 [<c02290b3>] ? ext3_free_branches+0x213/0x220
 [<c01c9160>] ? sync_buffer+0x0/0x40
 [<c0228f4e>] ? ext3_free_branches+0xae/0x220
 [<c0228f4e>] ? ext3_free_branches+0xae/0x220
 [<c0229688>] ? ext3_truncate+0x5c8/0x940
 [<c015ad76>] ? trace_hardirqs_on_caller+0x116/0x170
 [<c02606f3>] ? journal_start+0xd3/0x110
 [<c02606d0>] ? journal_start+0xb0/0x110
 [<c0229ad7>] ? ext3_delete_inode+0xd7/0xe0
 [<c0229a00>] ? ext3_delete_inode+0x0/0xe0
 [<c01b9ba1>] ? generic_delete_inode+0x81/0x120
 [<c01b9d67>] ? generic_drop_inode+0x127/0x180
 [<c01b8be7>] ? iput+0x47/0x50
 [<c01af1bc>] ? do_unlinkat+0xec/0x170
 [<c01b185b>] ? vfs_readdir+0x6b/0xa0
 [<c01b1540>] ? filldir64+0x0/0xf0
 [<c04309a8>] ? trace_hardirqs_on_thunk+0xc/0x10
 [<c015ad76>] ? trace_hardirqs_on_caller+0x116/0x170
 [<c01af383>] ? sys_unlinkat+0x23/0x50
 [<c010407f>] ? sysenter_past_esp+0x78/0xc5
 =======================
Code: 00 00 00 8b 45 e8 8b 1f 8b 55 e4 8b 88 ac 02 00 00 8b 41 34 0f
af 51 10 03 50 14 89 5d ec 8b 46 18 89 45 f0 89 d8 8b 5d f0 29 d0 <0f>
a3 03 19 c0 85 c0 74 11 8b 47 04 89 45 ec 29 d0 0f a3 03 19
EIP: [<c02224d6>] read_block_bitmap+0xc6/0x180 SS:ESP 0068:f62e3cac
Kernel panic - not syncing: Fatal exception
------------[ cut here ]------------

This was with error=continue.

$ addr2line -e vmlinux -i c02224d6
include/asm/bitops.h:305
fs/ext3/balloc.c:98
fs/ext3/balloc.c:167

It looks similar to the ext2 crash which I just reported:
http://lkml.org/lkml/2008/7/18/136

Which had this EIP:

$ addr2line -e vmlinux -i c026ee46
include/asm/bitops.h:305
fs/ext2/balloc.c:87
fs/ext2/balloc.c:153

You can see the full log at
http://folk.uio.no/vegardno/linux/log-1216380709.txt which shows that
it already survived a lot of failures, so I'm guessing your patch was
correct and we just hit a different case. What do you think?


Vegard

-- 
"The animistic metaphor of the bug that maliciously sneaked in while
the programmer was not looking is intellectually dishonest as it
disguises that the error is the programmer's own creation."
	-- E. W. Dijkstra, EWD1036

Re: ext3 on latest -git: BUG: unable to handle kernel NULL pointer dereference at 0000000c

[Josef Bacik]

On Fri, Jul 18, 2008 at 01:32:10PM +0200, Vegard Nossum wrote:
> On Fri, Jul 18, 2008 at 12:51 PM, Josef Bacik <jbacik@redhat.com> wrote:
> > On Thu, Jul 17, 2008 at 05:09:05PM -0600, Andreas Dilger wrote:
> >> On Jul 17, 2008  10:43 -0400, Josef Bacik wrote:
> >> > Yeah thats a hard to answer question, one that I will leave up to others
> >> > who have been doing this much longer than I.  My thought is remount-ro
> >> > is there to keep you from crashing, so if you have errors=continue then
> >> > you expect to live with the consequences.  Course if that bit gets flipped
> >> > via corruption thats not good either.
> >>
> >> It shouldn't cause the kernel to crash, but it should definitely return
> >> an error to the application.  This is probably one of the code paths
> >> that the Coverity folks were reporting on in FAST this year where on-disk
> >> errors are not propagated to the application.
> >
> > Ok, please revert the previous patch and apply this one.  On errors=continue we
> > will just abort the handle which should keep the NULL pointer dereference from
> > happening and return an error back to the application.  Please let me know how
> > this works Vegard, and thanks alot for testing all this.
> >
> > Signed-off-by: Josef Bacik <jbacik@redhat.com>
> 
> Thanks for doing the patches :-)
> 
> I still got this:
> 
> loop0: rw=0, want=4294967298, limit=24576
> EXT3-fs error (device loop0): ext3_free_branches: Read failure,
> inode=74, block=2147483648
> EXT3-fs error (device loop0) in ext3_reserve_inode_write: Readonly filesystem
> EXT3-fs error (device loop0) in ext3_truncate: IO failure
> EXT3-fs error (device loop0) in ext3_reserve_inode_write: Readonly filesystem
> EXT3-fs error (device loop0) in ext3_orphan_del: Readonly filesystem
> EXT3-fs error (device loop0) in ext3_reserve_inode_write: Readonly filesystem
> EXT3-fs error (device loop0) in ext3_delete_inode: IO failure
> EXT3-fs unexpected failure: !jh->b_committed_data;
> inconsistent data on disk
> ext3_forget: aborting transaction: IO failure in __ext3_journal_forget
> BUG: unable to handle kernel paging request at f1e79ffc
> IP: [<c02224d6>] read_block_bitmap+0xc6/0x180
> *pde = 33cc5163 *pte = 31e79160
> Oops: 0000 [#1] PREEMPT SMP DEBUG_PAGEALLOC
> Pid: 4257, comm: rm Not tainted (2.6.26-03416-g11155ca #46)
> EIP: 0060:[<c02224d6>] EFLAGS: 00210297 CPU: 1
> EIP is at read_block_bitmap+0xc6/0x180
> EAX: ffffffff EBX: f1e7a000 ECX: f3c20000 EDX: 00000001
> ESI: f5663c30 EDI: f1e7a800 EBP: f62e3cdc ESP: f62e3cac
>  DS: 007b ES: 007b FS: 00d8 GS: 0033 SS: 0068
> Process rm (pid: 4257, ti=f62e2000 task=f637dfa0 task.ti=f62e2000)
> Stack: 00000400 f637e4c0 f637dfa0 f62e3cd4 00200246 00000000 f3d2c860 00000000
>        f1e7a000 f3c20098 00000000 f56c4b7c f62e3d3c c0222704 c025efd3 f637dfa0
>        c015addb f77aa050 f3d2db0c 00000031 00000000 00000032 f3d2c860 f77aa050
> Call Trace:
>  [<c0222704>] ? ext3_free_blocks_sb+0xd4/0x620
>  [<c025efd3>] ? journal_forget+0x213/0x220
>  [<c015addb>] ? trace_hardirqs_on+0xb/0x10
>  [<c0222c7a>] ? ext3_free_blocks+0x2a/0xa0
>  [<c0228d85>] ? ext3_clear_blocks+0x145/0x160
>  [<c0228e67>] ? ext3_free_data+0xc7/0x100
>  [<c02290b3>] ? ext3_free_branches+0x213/0x220
>  [<c01c9160>] ? sync_buffer+0x0/0x40
>  [<c0228f4e>] ? ext3_free_branches+0xae/0x220
>  [<c0228f4e>] ? ext3_free_branches+0xae/0x220
>  [<c0229688>] ? ext3_truncate+0x5c8/0x940
>  [<c015ad76>] ? trace_hardirqs_on_caller+0x116/0x170
>  [<c02606f3>] ? journal_start+0xd3/0x110
>  [<c02606d0>] ? journal_start+0xb0/0x110
>  [<c0229ad7>] ? ext3_delete_inode+0xd7/0xe0
>  [<c0229a00>] ? ext3_delete_inode+0x0/0xe0
>  [<c01b9ba1>] ? generic_delete_inode+0x81/0x120
>  [<c01b9d67>] ? generic_drop_inode+0x127/0x180
>  [<c01b8be7>] ? iput+0x47/0x50
>  [<c01af1bc>] ? do_unlinkat+0xec/0x170
>  [<c01b185b>] ? vfs_readdir+0x6b/0xa0
>  [<c01b1540>] ? filldir64+0x0/0xf0
>  [<c04309a8>] ? trace_hardirqs_on_thunk+0xc/0x10
>  [<c015ad76>] ? trace_hardirqs_on_caller+0x116/0x170
>  [<c01af383>] ? sys_unlinkat+0x23/0x50
>  [<c010407f>] ? sysenter_past_esp+0x78/0xc5
>  =======================
> Code: 00 00 00 8b 45 e8 8b 1f 8b 55 e4 8b 88 ac 02 00 00 8b 41 34 0f
> af 51 10 03 50 14 89 5d ec 8b 46 18 89 45 f0 89 d8 8b 5d f0 29 d0 <0f>
> a3 03 19 c0 85 c0 74 11 8b 47 04 89 45 ec 29 d0 0f a3 03 19
> EIP: [<c02224d6>] read_block_bitmap+0xc6/0x180 SS:ESP 0068:f62e3cac
> Kernel panic - not syncing: Fatal exception
> ------------[ cut here ]------------
> 
> This was with error=continue.
> 
> $ addr2line -e vmlinux -i c02224d6
> include/asm/bitops.h:305
> fs/ext3/balloc.c:98
> fs/ext3/balloc.c:167
> 
> It looks similar to the ext2 crash which I just reported:
> http://lkml.org/lkml/2008/7/18/136
> 
> Which had this EIP:
> 
> $ addr2line -e vmlinux -i c026ee46
> include/asm/bitops.h:305
> fs/ext2/balloc.c:87
> fs/ext2/balloc.c:153
> 
> You can see the full log at
> http://folk.uio.no/vegardno/linux/log-1216380709.txt which shows that
> it already survived a lot of failures, so I'm guessing your patch was
> correct and we just hit a different case. What do you think?
>

Yeah you are right, its like a shitty game of wack-a-mole.  Heres another patch,
same thing as last time, pull the other one out put this one on.  Thanks,

Josef

 
Index: linux-2.6/fs/ext3/inode.c
===================================================================
--- linux-2.6.orig/fs/ext3/inode.c
+++ linux-2.6/fs/ext3/inode.c
@@ -2023,13 +2023,27 @@ static void ext3_clear_blocks(handle_t *
 		unsigned long count, __le32 *first, __le32 *last)
 {
 	__le32 *p;
+	int ret;
+
 	if (try_to_extend_transaction(handle, inode)) {
 		if (bh) {
 			BUFFER_TRACE(bh, "call ext3_journal_dirty_metadata");
-			ext3_journal_dirty_metadata(handle, bh);
+			ret = ext3_journal_dirty_metadata(handle, bh);
+			if (ret) {
+				ext3_std_error(inode->i_sb, ret);
+				return;
+			}
 		}
-		ext3_mark_inode_dirty(handle, inode);
-		ext3_journal_test_restart(handle, inode);
+		ret = ext3_mark_inode_dirty(handle, inode);
+		if (ret)
+			return;
+
+		ret = ext3_journal_test_restart(handle, inode);
+		if (ret) {
+			ext3_std_error(inode->i_sb, ret);
+			return;
+		}
+
 		if (bh) {
 			BUFFER_TRACE(bh, "retaking write access");
 			ext3_journal_get_write_access(handle, bh);
@@ -2051,7 +2065,9 @@ static void ext3_clear_blocks(handle_t *
 
 			*p = 0;
 			bh = sb_find_get_block(inode->i_sb, nr);
-			ext3_forget(handle, 0, inode, bh, nr);
+			ret = ext3_forget(handle, 0, inode, bh, nr);
+			if (ret)
+				return;
 		}
 	}
 
Index: linux-2.6/fs/ext3/balloc.c
===================================================================
--- linux-2.6.orig/fs/ext3/balloc.c
+++ linux-2.6/fs/ext3/balloc.c
@@ -498,6 +498,7 @@ void ext3_free_blocks_sb(handle_t *handl
 		ext3_error (sb, "ext3_free_blocks",
 			    "Freeing blocks not in datazone - "
 			    "block = "E3FSBLK", count = %lu", block, count);
+		err = -EIO;
 		goto error_return;
 	}
 
@@ -535,6 +536,7 @@ do_more:
 			    "Freeing blocks in system zones - "
 			    "Block = "E3FSBLK", count = %lu",
 			    block, count);
+		err = -EIO;
 		goto error_return;
 	}
 
Index: linux-2.6/fs/ext3/super.c
===================================================================
--- linux-2.6.orig/fs/ext3/super.c
+++ linux-2.6/fs/ext3/super.c
@@ -167,7 +167,15 @@ static void ext3_handle_error(struct sup
 		EXT3_SB(sb)->s_mount_opt |= EXT3_MOUNT_ABORT;
 		if (journal)
 			journal_abort(journal, -EIO);
+	} else {
+		handle_t *handle = current->journal_info;
+		if (handle && !is_handle_aborted(handle)) {
+			if (!handle->h_err)
+				handle->h_err = -EIO;
+			journal_abort_handle(handle);
+		}
 	}
+
 	if (test_opt (sb, ERRORS_RO)) {
 		printk (KERN_CRIT "Remounting filesystem read-only\n");
 		sb->s_flags |= MS_RDONLY;

Re: ext3 on latest -git: BUG: unable to handle kernel NULL pointer dereference at 0000000c

[Vegard Nossum]

On Fri, Jul 18, 2008 at 1:20 PM, Josef Bacik <jbacik@redhat.com> wrote:
>> You can see the full log at
>> http://folk.uio.no/vegardno/linux/log-1216380709.txt which shows that
>> it already survived a lot of failures, so I'm guessing your patch was
>> correct and we just hit a different case. What do you think?
>>
>
> Yeah you are right, its like a shitty game of wack-a-mole.  Heres another patch,
> same thing as last time, pull the other one out put this one on.  Thanks,

It seems to hold up -- no stacktraces, but lots of IO failures.

I would leave it in testing for a bit more, but I've got to run; I'll
give it another go when I get home.

You may see the log so far: http://folk.uio.no/vegardno/linux/log-1216382128.txt


Vegard

-- 
"The animistic metaphor of the bug that maliciously sneaked in while
the programmer was not looking is intellectually dishonest as it
disguises that the error is the programmer's own creation."
	-- E. W. Dijkstra, EWD1036

Re: ext3 on latest -git: BUG: unable to handle kernel NULL pointer dereference at 0000000c

[Vegard Nossum]

On Fri, Jul 18, 2008 at 1:58 PM, Vegard Nossum <vegard.nossum@gmail.com> wrote:
> On Fri, Jul 18, 2008 at 1:20 PM, Josef Bacik <jbacik@redhat.com> wrote:
>>> You can see the full log at
>>> http://folk.uio.no/vegardno/linux/log-1216380709.txt which shows that
>>> it already survived a lot of failures, so I'm guessing your patch was
>>> correct and we just hit a different case. What do you think?
>>>
>>
>> Yeah you are right, its like a shitty game of wack-a-mole.  Heres another patch,
>> same thing as last time, pull the other one out put this one on.  Thanks,
>
> It seems to hold up -- no stacktraces, but lots of IO failures.
>
> I would leave it in testing for a bit more, but I've got to run; I'll
> give it another go when I get home.

Ok, we still got this:

BUG: unable to handle kernel NULL pointer dereference at 0000000c
IP: [<c025ea28>] journal_dirty_metadata+0xb8/0x1b0
*pde = 00000000
Oops: 0000 [#1] PREEMPT SMP DEBUG_PAGEALLOC
Pid: 4770, comm: rm Not tainted (2.6.26-03421-g253a722 #49)
EIP: 0060:[<c025ea28>] EFLAGS: 00210246 CPU: 1
EIP is at journal_dirty_metadata+0xb8/0x1b0
EAX: 00000000 EBX: f3d70c90 ECX: 00000001 EDX: f3e12000
ESI: 00000000 EDI: f21118f0 EBP: f3e13d94 ESP: f3e13d6c
 DS: 007b ES: 007b FS: 00d8 GS: 0033 SS: 0068
Process rm (pid: 4770, ti=f3e12000 task=f62cdfa0 task.ti=f3e12000)
Stack: f3d70430 f578047c f578047c f3e13d94 c0222cdb f779c000 f6ff2e70 f21118f0
       f779c000 f21118f0 f3e13db4 c02345ef 0000001c 00001499 c0760bc4 f21118f0
       00000000 ef36d004 f3e13de4 c0228e6f 0000147e 0000001c ef36d004 ef36d400
Call Trace:
 [<c0222cdb>] ? ext3_free_blocks+0x6b/0xa0
 [<c02345ef>] ? __ext3_journal_dirty_metadata+0x1f/0x50
 [<c0228e6f>] ? ext3_free_data+0x9f/0x100
 [<c02290e3>] ? ext3_free_branches+0x213/0x220
 [<c0222cdb>] ? ext3_free_blocks+0x6b/0xa0
 [<c0228f7e>] ? ext3_free_branches+0xae/0x220
 [<c022967c>] ? ext3_truncate+0x58c/0x940
 [<c015ad96>] ? trace_hardirqs_on_caller+0x116/0x170
 [<c0260733>] ? journal_start+0xd3/0x110
 [<c0260710>] ? journal_start+0xb0/0x110
 [<c0229b07>] ? ext3_delete_inode+0xd7/0xe0
 [<c0229a30>] ? ext3_delete_inode+0x0/0xe0
 [<c01b9bc1>] ? generic_delete_inode+0x81/0x120
 [<c01b9d87>] ? generic_drop_inode+0x127/0x180
 [<c01b8c07>] ? iput+0x47/0x50
 [<c01af1dc>] ? do_unlinkat+0xec/0x170
 [<c01b187b>] ? vfs_readdir+0x6b/0xa0
 [<c01b1560>] ? filldir64+0x0/0xf0
 [<c0430a08>] ? trace_hardirqs_on_thunk+0xc/0x10
 [<c015ad96>] ? trace_hardirqs_on_caller+0x116/0x170
 [<c01af3a3>] ? sys_unlinkat+0x23/0x50
 [<c010407f>] ? sysenter_past_esp+0x78/0xc5
 =======================
Code: b8 01 00 00 00 e8 c9 3f ed ff 89 e0 25 00 e0 ff ff f6 40 08 08
74 05 e8 47 98 4e 00 83 c4 1c 31 c0 5b 5e 5f 5d c3 90 8d 74 26 00 <8b>
46 0c 85 c0 0f 84 8d 00 00 00 8b 45 f0 39 46 18 74 66 8d 47
EIP: [<c025ea28>] journal_dirty_metadata+0xb8/0x1b0 SS:ESP 0068:f3e13d6c
Kernel panic - not syncing: Fatal exception


It looks similar to one of the others we saw. Are you sure I should
back out all your previous patches? My stack looks like this:

Duane Griffin (1):
      ext3: validate directory entry

Josef Bacik (1):
      ext3 on latest -git: BUG: unable to handle kernel NULL pointer dereference

And I am using error=continue.

Now I've modified my scripts to also save the bad image, so I (or
whomever) can re-test a specific crash easily. For instance, this one
can be downloaded from
http://folk.uio.no/vegardno/linux/ext3-crash-fs.bin.bz2 and mounted.
Then you run rm -rf mnt/* and it should crash.

Log is also available at http://folk.uio.no/vegardno/linux/log-1216412153.txt


Vegard

-- 
"The animistic metaphor of the bug that maliciously sneaked in while
the programmer was not looking is intellectually dishonest as it
disguises that the error is the programmer's own creation."
	-- E. W. Dijkstra, EWD1036

Re: ext3 on latest -git: BUG: unable to handle kernel NULL pointer dereference at 0000000c

[Theodore Tso]

Vegard,

How big is the filesystem?  Is there any chance you can make a
compressed e2image of the file?  (This will not include file contents,
but does reveal the names of the file.)  Given the nature of the bug
which you are reporting, it should be safe to scramble the names of
the filenames using the -s option if that would make you feel more
comfortable.

The quick version is:

    e2image -r /dev/loop0 | bzip2 > badfs.e2i.bz2

Then folks like Josef would be able to test your filesystem right
away, instead of asking oyu to test it.

					- Ted

Re: ext3 on latest -git: BUG: unable to handle kernel NULL pointer dereference at 0000000c

[Vegard Nossum]

On Thu, Jul 17, 2008 at 5:08 PM, Theodore Tso <tytso@mit.edu> wrote:
> Vegard,
>
> How big is the filesystem?  Is there any chance you can make a
> compressed e2image of the file?  (This will not include file contents,
> but does reveal the names of the file.)  Given the nature of the bug
> which you are reporting, it should be safe to scramble the names of
> the filenames using the -s option if that would make you feel more
> comfortable.

Oh, just 2M. It doesn't contain anything but copies of /bin/bash.

I basically just made a crash-tester script that corrupts a dummy
filesystem on purpose. But it seems that it might be partly my own
fault for not protecting the bits in the filesystem image that say
"oh, proceed on error". But I do have a feeling that the filesystem
should not be able to say this in the first place. Because those bits
can be corrupted legitimately in other ways too!

http://folk.uio.no/vegardno/linux/corrupt.tar.bz2

Is there a way to override the

    "Errors behavior:          Continue"

information which is present in the filesystem?


Vegard

-- 
"The animistic metaphor of the bug that maliciously sneaked in while
the programmer was not looking is intellectually dishonest as it
disguises that the error is the programmer's own creation."
	-- E. W. Dijkstra, EWD1036

Re: ext3 on latest -git: BUG: unable to handle kernel NULL pointer dereference at 0000000c

[Theodore Tso]

On Thu, Jul 17, 2008 at 05:16:39PM +0200, Vegard Nossum wrote:
> Is there a way to override the
> 
>     "Errors behavior:          Continue"
> 
> information which is present in the filesystem?

Yep:

tune2fs -e remount-ro /dev/XXXX

I should probably make the default configurable, and not "continue"....

  	 	       	   	   		     - Ted

Re: ext3 on latest -git: BUG: unable to handle kernel NULL pointer dereference at 0000000c

[Andreas Dilger]

On Jul 17, 2008  11:40 -0400, Theodore Ts'o wrote:
> On Thu, Jul 17, 2008 at 05:16:39PM +0200, Vegard Nossum wrote:
> > Is there a way to override the
> > 
> >     "Errors behavior:          Continue"
> > 
> > information which is present in the filesystem?
> 
> tune2fs -e remount-ro /dev/XXXX
> 
> I should probably make the default configurable, and not "continue"....

Yes, it has been that way on Debian for many years...  I was going to
say the same thing, but you beat me to it.

Cheers, Andreas
--
Andreas Dilger
Sr. Staff Engineer, Lustre Group
Sun Microsystems of Canada, Inc.