[nikita-3002]: assertion failed: carry_level_invariant(doing, CARRY_DOING)

[nikita-3002]: assertion failed: carry_level_invariant(doing, CARRY_DOING)

[Andrew James Wade]

Hello,

     Every few weeks reiser4 panics on me, generally while kmail is
receiving emails. Until recently, the panic was "invalid opcode: 0000
[#1]" (previously reported), but I have some new errors:

The first is:
reiser4 panicked cowardly: reiser4[less(7234)]: set_file_state (fs/reiser4/plugin/file/file.c:200)[vs-1162]:
assertion failed: ergo(level == LEAF_LEVEL && cbk_result == CBK_COORD_FOUND, uf_info->container == UF_CONTAINER_TAILS)
Kernel panic - not syncing: reiser4[less(7234)]: set_file_state (fs/reiser4/plugin/file/file.c:200)[vs-1162]:
assertion failed: ergo(level == LEAF_LEVEL && cbk_result == CBK_COORD_FOUND, uf_info->container == UF_CONTAINER_TAILS)

and the second is:
reiser4[patch(25956)]: carry_level_invariant (fs/reiser4/carry.c:1250)[]:
WARNING: wrong key order
reiser4 panicked cowardly: reiser4[patch(25956)]: carry_on_level (fs/reiser4/carry.c:356)[nikita-3002]:
assertion failed: carry_level_invariant(doing, CARRY_DOING)
Kernel panic - not syncing: reiser4[patch(25956)]: carry_on_level (fs/reiser4/carry.c:356)[nikita-3002]:
assertion failed: carry_level_invariant(doing, CARRY_DOING)

Both were for 2.6.18-rc2-mm1 [1]. The second error occurred on a recently fscked filesystem.

[1] with one patch reverted for unrelated reasons.

I hope this helps get to the root of the problem. Unfortunately, I do
not yet have a reproduceable test case.

Andrew Wade

Re: [nikita-3002]: assertion failed: carry_level_invariant(doing, CARRY_DOING)

[Andrew James Wade]

I've just had some warnings show up in my kernel log. I don't know if
they're related to the troubles I've been having (I fscked after the
last panic).

reiser4[updatedb(32445)]: key_warning (fs/reiser4/plugin/file_plugin_common.c:513)[nikita-717]:
WARNING: Error for inode 401698 (-2)
for key: (6211c:1:656e646f727365:0:62122:0)[stat data]
reiser4[updatedb(32445)]: key_warning (fs/reiser4/plugin/file_plugin_common.c:513)[nikita-717]:
WARNING: Error for inode 401697 (-2)
for key: (6211c:1:6576656e74732e:0:62121:0)[stat data]
reiser4[updatedb(32445)]: key_warning (fs/reiser4/plugin/file_plugin_common.c:513)[nikita-717]:
WARNING: Error for inode 401694 (-2)
for key: (6211c:1:736e617073686f:0:6211e:0)[stat data]
reiser4[updatedb(32445)]: key_warning (fs/reiser4/plugin/file_plugin_common.c:513)[nikita-717]:
WARNING: Error for inode 401699 (-2)
for key: (6211c:1:776f6d656e5f6c:0:62123:0)[stat data]

Hope this helps,
Andrew Wade

Re: [nikita-3002]: assertion failed: carry_level_invariant(doing, CARRY_DOING)

[Alexander Zarochentsev]

Hello,

> I've just had some warnings show up in my kernel log. I don't know if
> they're related to the troubles I've been having (I fscked after the
> last panic).

please apply the following patch:

re-add to reiser4_releasepage mistakenly removed page_count check.
extra page reference is used to protect page from detaching from the 
jnode.

Signed-off-by: Alexander Zarochentsev <zam@namesys.com>
---
 fs/reiser4/as_ops.c |    5 +++++
 1 file changed, 5 insertions(+)

Index: linux-2.6-git/fs/reiser4/as_ops.c
===================================================================
--- linux-2.6-git.orig/fs/reiser4/as_ops.c
+++ linux-2.6-git/fs/reiser4/as_ops.c
@@ -350,6 +350,11 @@ int reiser4_releasepage(struct page *pag
 	if (PageDirty(page))
 		return 0;
 
+	/* extra page reference is used by reiser4 to protect
+	 * jnode<->page link from this ->releasepage(). */
+	if (page_count(page) > 3)
+		return 0;
+
 	/* releasable() needs jnode lock, because it looks at the jnode fields
 	 * and we need jload_lock here to avoid races with jload(). */
 	spin_lock_jnode(node);

Re: [nikita-3002]: assertion failed: carry_level_invariant(doing, CARRY_DOING)

[Andrew James Wade]

Thanks.

I've applied the patch, and I'll let you know if any errors reccur.

Andrew Wade

Re: [nikita-3002]: assertion failed: carry_level_invariant(doing, CARRY_DOING)

[Andrew James Wade]

Hello,

I have had another assertion fail. This one is with 2.6.18-rc2-mm1 +
the fix in reiser4_releasepage. This was on a filesystem that had not
been unmounted cleanly. (2.6.18-rc3-mm1 crashed on me). 

reiser4 panicked cowardly: reiser4[ktxnmgrd:hdb1:r(1977)]: sibling_list_remove (fs/reiser4/tree_walk.c:813)[zam-32245]:
assertion failed: keyeq(znode_get_rd_key(node), znode_get_ld_key(node->right))
Kernel panic - not syncing: reiser4[ktxnmgrd:hdb1:r(1977)]: sibling_list_remove (fs/reiser4/tree_walk.c:813)[zam-32245]:
assertion failed: keyeq(znode_get_rd_key(node), znode_get_ld_key(node->right))

The next boot had this diagnostic:
reiser4[kde-config(3707)]: present_lw_sd (fs/reiser4/plugin/item/static_stat.c:276)[]:
WARNING: partially converted file is encountered
and is continuing to work fine. I have not yet fscked the filesystem.

I hope this helps,
Andrew Wade

Re: [nikita-3002]: assertion failed: carry_level_invariant(doing, CARRY_DOING)

[Andrew James Wade]

Hello,

I've had another panic on a fscked filesystem:

reiser4 panicked cowardly: reiser4[updatedb(3302)]: reiser4_writepage (fs/reiser4/page_cache.c:521)[]:
assertion failed: can_hit_entd(ctx, s)
Kernel panic - not syncing: reiser4[updatedb(3302)]: reiser4_writepage (fs/reiser4/page_cache.c:521)[]:
assertion failed: can_hit_entd(ctx, s)

It's getting pretty obvious that there must be something unusual/unique
in my setup that's giving me grief. My guess would be that data is
getting corrupted going between the drive and memory. I do have my
pci bus underclocked to 30 MHz so maybe that's a factor. I have had
problems with memory corruption in the past (hence the underclocking),
but I haven't had any of the symptoms of memory corruption
re-appearing. (Note that /dev/hdb is my /home filesystem only, so
it's plausible that problems there would mostly tickle reiser4 code).

If that's what is going on, I would expect file contents to also
corrupt. I'm going to whip up some scripts to exercise the reading
and writing large amounts of data to the disk and and see if I can
find corruption of the data. (I hope to be able to use O_DIRECT to
avoid thrashing). 

I suppose another possibility is that there is something strange in
my filesystem that survives fsck, but causes problems. Given the
variety of symptoms (and the lack of other reports) I would tend to
discount that though. For the record this is what fsck keeps telling
me:

FSCK: Node (33160105), item (0), [29:1(SD):0:2a:0]: the slot (9) contains the invalid opset member (compress mode), id (2).
FSCK: Node (33160105), item (0), [29:1(SD):0:2a:0]: removing broken slots.
FSCK: Node (33160105), item (0), [29:1(SD):0:2a:0]: item has the wrong length (94). Should be (90). Fixed.

I'm going to run fsck twice in a row to verify that fsck fixes the
problems, but I'm working under the assumption that what fsck is
finding is unrelated.

I think the ball is in my court: fortunately I now have time to devote
to investigation. I'll let you know what I find.

Comments?

Andrew Wade

Re: [nikita-3002]: assertion failed: carry_level_invariant(doing, CARRY_DOING)

[Vladimir V. Saveliev]

Hello

On Thursday 10 August 2006 21:55, Andrew James Wade wrote:
> Hello,
>
> I've had another panic on a fscked filesystem:
>
> reiser4 panicked cowardly: reiser4[updatedb(3302)]: reiser4_writepage
> (fs/reiser4/page_cache.c:521)[]: assertion failed: can_hit_entd(ctx, s)
> Kernel panic - not syncing: reiser4[updatedb(3302)]: reiser4_writepage
> (fs/reiser4/page_cache.c:521)[]: assertion failed: can_hit_entd(ctx, s)
>

What kernel do you use? Recently we had few fixes of such problem.

> It's getting pretty obvious that there must be something unusual/unique
> in my setup that's giving me grief. My guess would be that data is
> getting corrupted going between the drive and memory. I do have my
> pci bus underclocked to 30 MHz so maybe that's a factor. I have had
> problems with memory corruption in the past (hence the underclocking),
> but I haven't had any of the symptoms of memory corruption
> re-appearing. (Note that /dev/hdb is my /home filesystem only, so
> it's plausible that problems there would mostly tickle reiser4 code).
>
> If that's what is going on, I would expect file contents to also
> corrupt. I'm going to whip up some scripts to exercise the reading
> and writing large amounts of data to the disk and and see if I can
> find corruption of the data. (I hope to be able to use O_DIRECT to
> avoid thrashing).
>
> I suppose another possibility is that there is something strange in
> my filesystem that survives fsck, but causes problems. Given the
> variety of symptoms (and the lack of other reports) I would tend to
> discount that though. For the record this is what fsck keeps telling
> me:
>
> FSCK: Node (33160105), item (0), [29:1(SD):0:2a:0]: the slot (9) contains
> the invalid opset member (compress mode), id (2). FSCK: Node (33160105),
> item (0), [29:1(SD):0:2a:0]: removing broken slots. FSCK: Node (33160105),
> item (0), [29:1(SD):0:2a:0]: item has the wrong length (94). Should be
> (90). Fixed.
>
> I'm going to run fsck twice in a row to verify that fsck fixes the
> problems, but I'm working under the assumption that what fsck is
> finding is unrelated.
>
> I think the ball is in my court: fortunately I now have time to devote
> to investigation. I'll let you know what I find.
>
> Comments?
>
> Andrew Wade

Re: [nikita-3002]: assertion failed: carry_level_invariant(doing, CARRY_DOING)

[Andrew James Wade]

On Friday 11 August 2006 05:15, Vladimir V. Saveliev wrote:
> Hello
> 
> On Thursday 10 August 2006 21:55, Andrew James Wade wrote:
> > Hello,
> >
> > I've had another panic on a fscked filesystem:
> >
> > reiser4 panicked cowardly: reiser4[updatedb(3302)]: reiser4_writepage
> > (fs/reiser4/page_cache.c:521)[]: assertion failed: can_hit_entd(ctx, s)
> > Kernel panic - not syncing: reiser4[updatedb(3302)]: reiser4_writepage
> > (fs/reiser4/page_cache.c:521)[]: assertion failed: can_hit_entd(ctx, s)
> >
> 
> What kernel do you use? Recently we had few fixes of such problem.

2.6.18-rc3-mm2 + the patch below.

I've been unable to observe any corruption in over 300 GB of file data
written to the hd, so I don't think I have a hardware issue.

I will continue poking away at the problem.

Andrew Wade

------

re-add to reiser4_releasepage mistakenly removed page_count check.
extra page reference is used to protect page from detaching from the 
jnode.

Signed-off-by: Alexander Zarochentsev <zam@namesys.com>
---
 fs/reiser4/as_ops.c |    5 +++++
 1 file changed, 5 insertions(+)

Index: linux-2.6-git/fs/reiser4/as_ops.c
===================================================================
--- linux-2.6-git.orig/fs/reiser4/as_ops.c
+++ linux-2.6-git/fs/reiser4/as_ops.c
@@ -350,6 +350,11 @@ int reiser4_releasepage(struct page *pag
        if (PageDirty(page))
                return 0;
 
+       /* extra page reference is used by reiser4 to protect
+        * jnode<->page link from this ->releasepage(). */
+       if (page_count(page) > 3)
+               return 0;
+
        /* releasable() needs jnode lock, because it looks at the jnode fields
         * and we need jload_lock here to avoid races with jload(). */
        spin_lock_jnode(node);

Re: [nikita-3002]: assertion failed: carry_level_invariant(doing, CARRY_DOING)

[Benjamin Vander Jagt]

Vladimir V. Saveliev wrote:
> 
> Hello
> 
> What kernel do you use? Recently we had few fixes of such problem.
> 
> 

I am having the exact same problems but with one difference.  After a while,
the drive starts thrashing, and the system becomes totally unresponsive.  I
have no way of knowing what it's doing, and I've tried leaving it alone for
as much as 24 hours, and it just doesn't stop.  So far I don't see any data
loss.  I am running 2.6.17 vanilla + reiser4 patch "2.6.17-3".  There are no
signs of hardware errors, but I'll run a full hard drive test next just to
be sure.

Here's what dmesg says right now:

reiser4[find(26470)]: parse_node40
(fs/reiser4/plugin/node/node40.c:673)[nikita-494]:
WARNING: Wrong level found in node: 2 != 1
reiser4[find(26470)]: key_warning
(fs/reiser4/plugin/file_plugin_common.c:513)[nikita-717]:
WARNING: Error for inode 876827 (-2)
reiser4[syslog-ng(2407)]: parse_node40
(fs/reiser4/plugin/node/node40.c:673)[nikita-494]:
WARNING: Wrong level found in node: 2 != 1
reiser4[syslog-ng(2407)]: parse_node40
(fs/reiser4/plugin/node/node40.c:673)[nikita-494]:
WARNING: Wrong level found in node: 2 != 1
reiser4[udevd(883)]: parse_node40
(fs/reiser4/plugin/node/node40.c:673)[nikita-494]:
WARNING: Wrong level found in node: 2 != 1
reiser4[udevd(883)]: parse_node40
(fs/reiser4/plugin/node/node40.c:673)[nikita-494]:
WARNING: Wrong level found in node: 2 != 1
reiser4[udevd(883)]: parse_node40
(fs/reiser4/plugin/node/node40.c:673)[nikita-494]:
WARNING: Wrong level found in node: 2 != 1

Then it says this message about 50 times:
reiser4[find(26470)]: key_warning
(fs/reiser4/plugin/file_plugin_common.c:513)[nikita-717]:
WARNING: Error for inode 876827 (-2)

Then it says this:
reiser4[find(26470)]: cbk_level_lookup (fs/reiser4/search.c:961)[vs-3533]:
WARNING: Keys are inconsistent. Fsck?

Andrew, may I ask for the contents of your /proc/meminfo file?  I noticed
now that I have made a typo in my fstab and have never had swap space on
this computer.  I also found a lot of OOM errors earlier in dmesg.  I'll be
putting swap back in now and see if it fixes anything.

-Benjamin Vander Jagt
-Vander Jagt Computers
-- 
View this message in context: http://www.nabble.com/-nikita-3002-%3A-assertion-failed%3A-carry_level_invariant%28doing%2C-CARRY_DOING%29-tf2042550.html#a5832497
Sent from the ReiserFS - General forum at Nabble.com.

Re: [nikita-3002]: assertion failed: carry_level_invariant(doing, CARRY_DOING)

[Andrew James Wade]

On Wednesday 16 August 2006 09:32, Benjamin Vander Jagt wrote:

> I am having the exact same problems but with one difference.  After
> a while, the drive starts thrashing, and the system becomes totally
> unresponsive. 
     I've been getting occasional short freezes of a couple of minutes.
But that's probably unrelated: as I have debugging turned on and am
deliberately stressing the fs poor performance is not unexpected.

...
> Andrew, may I ask for the contents of your /proc/meminfo file? 

Sure:

MemTotal:       512648 kB
MemFree:         70612 kB
Buffers:          2800 kB
Cached:         105236 kB
SwapCached:      33812 kB
Active:         335988 kB
Inactive:        63028 kB
SwapTotal:     9791608 kB
SwapFree:      9757768 kB
Dirty:              84 kB
Writeback:           0 kB
AnonPages:      267960 kB
Mapped:          52792 kB
Slab:            22760 kB
PageTables:       3148 kB
NFS Unstable:        0 kB
Bounce:              0 kB
CommitLimit:  10047932 kB
Committed_AS:   686084 kB
VmallocTotal:   515796 kB
VmallocUsed:     25572 kB
VmallocChunk:   489680 kB
HugePages_Total:     0
HugePages_Free:      0
HugePages_Rsvd:      0
Hugepagesize:     4096 kB

I am currently trying to distill a test-case for crashing the fs.
It is going slowly, but I have managed to provoke a few panics,
including some new ones:

reiser4 panicked cowardly: reiser4[scatteredwrites(4506)]: reiser4_writepage (fs/reiser4/page_cache.c:522)[]:
assertion failed: can_hit_entd(ctx, s)
Kernel panic - not syncing: reiser4[scatteredwrites(4506)]: reiser4_writepage (fs/reiser4/page_cache.c:522)[]:
assertion failed: can_hit_entd(ctx, s)

reiser4 panicked cowardly: reiser4[tar(4238)]: reiser4_update_extent (fs/reiser4/plugin/item/extent_file_ops.c:807)[]:
assertion failed: reiser4_lock_counters()->d_refs == 0
Kernel panic - not syncing: reiser4[tar(4238)]: reiser4_update_extent (fs/reiser4/plugin/item/extent_file_ops.c:807)[]:
assertion failed: reiser4_lock_counters()->d_refs == 0

reiser4 panicked cowardly: reiser4[patch(9302)]: reiser4_set_page_dirty_internal (fs/reiser4/page_cache.c:475)[]:
assertion failed: JF_ISSET(jprivate(page), JNODE_DIRTY)
Kernel panic - not syncing: reiser4[patch(9302)]: reiser4_set_page_dirty_internal (fs/reiser4/page_cache.c:475)[]:
assertion failed: JF_ISSET(jprivate(page), JNODE_DIRTY)

These are all for 2.6.18-rc4-mm1 + the small patch upthread.

Andrew Wade

Re: [nikita-3002]: assertion failed: carry_level_invariant(doing, CARRY_DOING)

[Benjamin Vander Jagt]

Andrew James Wade-3 wrote:
> 
>      I've been getting occasional short freezes of a couple of minutes.
> But that's probably unrelated: as I have debugging turned on and am
> deliberately stressing the fs poor performance is not unexpected.
> ...
>> Andrew, may I ask for the contents of your /proc/meminfo file? 
> 
> Sure:
> 
> MemTotal:       512648 kB
> MemFree:         70612 kB
> Buffers:          2800 kB
> Cached:         105236 kB
> SwapCached:      33812 kB
> Active:         335988 kB
> Inactive:        63028 kB
> SwapTotal:     9791608 kB
> SwapFree:      9757768 kB
> Dirty:              84 kB
> Writeback:           0 kB
> AnonPages:      267960 kB
> Mapped:          52792 kB
> Slab:            22760 kB
> PageTables:       3148 kB
> NFS Unstable:        0 kB
> Bounce:              0 kB
> CommitLimit:  10047932 kB
> Committed_AS:   686084 kB
> VmallocTotal:   515796 kB
> VmallocUsed:     25572 kB
> VmallocChunk:   489680 kB
> HugePages_Total:     0
> HugePages_Free:      0
> HugePages_Rsvd:      0
> Hugepagesize:     4096 kB
> 
> I am currently trying to distill a test-case for crashing the fs.
> It is going slowly, but I have managed to provoke a few panics,
> including some new ones:
> 
> reiser4 panicked cowardly: reiser4[scatteredwrites(4506)]:
> reiser4_writepage (fs/reiser4/page_cache.c:522)[]:
> assertion failed: can_hit_entd(ctx, s)
> Kernel panic - not syncing: reiser4[scatteredwrites(4506)]:
> reiser4_writepage (fs/reiser4/page_cache.c:522)[]:
> assertion failed: can_hit_entd(ctx, s)
> 
> reiser4 panicked cowardly: reiser4[tar(4238)]: reiser4_update_extent
> (fs/reiser4/plugin/item/extent_file_ops.c:807)[]:
> assertion failed: reiser4_lock_counters()->d_refs == 0
> Kernel panic - not syncing: reiser4[tar(4238)]: reiser4_update_extent
> (fs/reiser4/plugin/item/extent_file_ops.c:807)[]:
> assertion failed: reiser4_lock_counters()->d_refs == 0
> 
> reiser4 panicked cowardly: reiser4[patch(9302)]:
> reiser4_set_page_dirty_internal (fs/reiser4/page_cache.c:475)[]:
> assertion failed: JF_ISSET(jprivate(page), JNODE_DIRTY)
> Kernel panic - not syncing: reiser4[patch(9302)]:
> reiser4_set_page_dirty_internal (fs/reiser4/page_cache.c:475)[]:
> assertion failed: JF_ISSET(jprivate(page), JNODE_DIRTY)
> 
> These are all for 2.6.18-rc4-mm1 + the small patch upthread.
> 
> Andrew Wade
> 

I will watch for your results.  Turning on the swap *blush* seems to have
eliminated all dmesg warnings and errors, but I'm still hanging at shutdown
time.  It now sounds like we have two different circumstances that resulted
in the same error, so I'll just watch the results of your testing. 
Meanwhile, I'll run the same kernel + patch you're running on another
computer and watch.

-Benjamin Vander Jagt
-- 
View this message in context: http://www.nabble.com/-nikita-3002-%3A-assertion-failed%3A-carry_level_invariant%28doing%2C-CARRY_DOING%29-tf2042550.html#a5880857
Sent from the ReiserFS - General forum at Nabble.com.