ubifs issue about ubifs_tnc_remove_ino when replay journal

Fri Jun 24 23:08:57 PDT 2016

hi mtd-list

I've seen a problem on embedded board with UBIFS/UBI.
My environment is as follows:

kernel version : 3.10.49
flash : 512MB nand, 128KB PEB

If a power cut occurs when the system is operating
a problem occur in a journal replay at reboot.

ubifs_jnl_delete_inode or ubifs_jnl_delete_xattr remove 
all nodes belonging to the extended attribute inode from TNC.
And it makes the journal to delete the information in flash. 
The journal is applied to flash on reboot.
However, the GC delete the region before applying journal,
I guess that the problem occurs.

------------------ kernel log -------------------------
[    3.637490]   No soundcard[    3.644631] UBIFS-0: background thread "ubifs_bgt0_0" started, PID 108
[    3.675468] UBIFS-0: recovery needed
[    4.323462] UBIFS-0 error (pid 1): ubifs_read_node: bad node type (192 but expected 3)
[    4.330341] UBIFS-0 error (pid 1): ubifs_read_node: bad node at LEB 635:58544, LEB mapping status 1
[    4.339388] Not a node, first 24 bytes:
[    4.343030] 00000000: 47 5f 49 44 45 4e 54 49 46 49 45 52 3d 6e 65 74 6d 67 72 64 c0 05 fd 04                          G_IDENTIFIER=netmgrd....
[    4.356051] CPU: 0 PID: 1 Comm: swapper Tainted: G        W    3.10.49+ #1
[    4.362923] [<c00143b8>] (unwind_backtrace+0x0/0xe0) from [<c00118a8>] (show_stack+0x10/0x14)
[    4.371419] [<c00118a8>] (show_stack+0x10/0x14) from [<c01ba514>] (ubifs_read_node+0x240/0x27c)
[    4.380089] [<c01ba514>] (ubifs_read_node+0x240/0x27c) from [<c01d41a4>] (ubifs_tnc_read_node+0x48/0x130)
[    4.389651] [<c01d41a4>] (ubifs_tnc_read_node+0x48/0x130) from [<c01bb2d4>] (tnc_read_node_nm+0xb4/0x1b8)
[    4.399196] [<c01bb2d4>] (tnc_read_node_nm+0xb4/0x1b8) from [<c01be624>] (ubifs_tnc_next_ent+0x144/0x18c)
[    4.408744] [<c01be624>] (ubifs_tnc_next_ent+0x144/0x18c) from [<c01be6b0>] (ubifs_tnc_remove_ino+0x44/0x124)
[    4.418641] [<c01be6b0>] (ubifs_tnc_remove_ino+0x44/0x124) from [<c01c0c9c>] (ubifs_replay_journal+0xbdc/0x1130)
[    4.428796] [<c01c0c9c>] (ubifs_replay_journal+0xbdc/0x1130) from [<c01b6a50>] (ubifs_mount+0xb80/0x1568)
[    4.438352] [<c01b6a50>] (ubifs_mount+0xb80/0x1568) from [<c00d9a40>] (mount_fs+0x10/0xb4)
[    4.446593] [<c00d9a40>] (mount_fs+0x10/0xb4) from [<c00f11dc>] (vfs_kern_mount+0x48/0xc4)
[    4.454838] [<c00f11dc>] (vfs_kern_mount+0x48/0xc4) from [<c00f35d4>] (do_mount+0x6a8/0x79c)
[    4.463258] [<c00f35d4>] (do_mount+0x6a8/0x79c) from [<c00f374c>] (SyS_mount+0x84/0xb8)
[    4.471245] [<c00f374c>] (SyS_mount+0x84/0xb8) from [<c09cedd4>] (mount_block_root+0xf8/0x274)
[    4.479824] [<c09cedd4>] (mount_block_root+0xf8/0x274) from [<c09cf124>] (prepare_namespace+0x88/0x1b8)
[    4.489212] [<c09cf124>] (prepare_namespace+0x88/0x1b8) from [<c09ceb90>] (kernel_init_freeable+0x170/0x1b4)
[    4.499023] [<c09ceb90>] (kernel_init_freeable+0x170/0x1b4) from [<c06b9c1c>] (kernel_init+0x8/0xe4)
[    4.508136] [<c06b9c1c>] (kernel_init+0x8/0xe4) from [<c000dc98>] (ret_from_fork+0x14/0x3c)
[    4.517918] UBIFS-0: background thread "ubifs_bgt0_0" stops
------------------ kernel log -------------------------

The following message has been reporting on the mailing list in the past.
This message is similar to my problem.

2014 jul 12 ubifs issue about xattr node when replay journal : 
-------------------------------------------
http://lists.infradead.org/pipermail/linux-mtd/2014-July/054620.html

Hi all,

Now we use xattr based on ubifs, and find some issues about it.
Situation like that:
1.poweron ->2.create a file -> 3.set xattr -> 4.delete the file -> 5.power cut
After several cycles with above steps, we can not boot up the device
with the error below.


Analysis:
when delete a file, ubifs will remove the xent node from tnc, if gc
happend, it will remove the xent node data from the GCed LEB because
of it has been removed form tnc ,
then if a power cut happen, the journal replay may also try to remove
the related xattr node, the error occurred because of it has been
GCed.


Now I run commit when ubifs_jnl_delete_inode called, and it's OK.
Does anyone have a better way for the issue?


-------- kernel 3.10 log --------
[   64.916532] UBIFS: background thread "ubifs_bgt0_16" started, PID 92
[   64.926411] UBIFS: recovery needed
[   65.013786] UBIFS error (pid 91): ubifs_read_node: bad node type
(255 but expected 3)
[   65.021595] UBIFS error (pid 91): ubifs_read_node: bad node at LEB
88:39680, LEB mapping status 1
[   65.030431] Not a node, first 24 bytes:
[   65.034073] 00000000: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff
ff ff ff ff ff ff ff ff ff
........................
[   65.047529] cpufreq_scx35: 600000 --> 1000000, real=1000000, index=0
[   65.047557] CPU: 0 PID: 91 Comm: mount Not tainted
3.10.17-g3891906-dirty #66-Tizen
[   65.047598] [<c00136c4>] (unwind_backtrace+0x0/0x120) from
[<c0011fd4>] (show_stack+0x10/0x14)
[   65.047617] [<c0011fd4>] (show_stack+0x10/0x14) from [<c0189880>]
(ubifs_read_node+0x2a4/0x2d0)
[   65.047635] [<c0189880>] (ubifs_read_node+0x2a4/0x2d0) from
[<c01a8d60>] (ubifs_tnc_read_node+0x4c/0x1dc)
[   65.047650] [<c01a8d60>] (ubifs_tnc_read_node+0x4c/0x1dc) from
[<c018af5c>] (tnc_read_node_nm+0xb4/0x1b4)
[   65.047666] [<c018af5c>] (tnc_read_node_nm+0xb4/0x1b4) from
[<c018e6e0>] (ubifs_tnc_next_ent+0x1ec/0x244)
[   65.047681] [<c018e6e0>] (ubifs_tnc_next_ent+0x1ec/0x244) from
[<c018e7c8>] (ubifs_tnc_remove_ino+0x90/0x1dc)
[   65.047698] [<c018e7c8>] (ubifs_tnc_remove_ino+0x90/0x1dc) from
[<c0191bdc>] (ubifs_replay_journal+0x1164/0x173c)
[   65.047713] [<c0191bdc>] (ubifs_replay_journal+0x1164/0x173c) from
[<c0184c04>] (ubifs_mount+0x1158/0x1eac)
[   65.047733] [<c0184c04>] (ubifs_mount+0x1158/0x1eac) from
[<c00b44ec>] (mount_fs+0x10/0xb4)
[   65.047750] [<c00b44ec>] (mount_fs+0x10/0xb4) from [<c00cb4a0>]
(vfs_kern_mount+0x4c/0xc0)
[   65.047764] [<c00cb4a0>] (vfs_kern_mount+0x4c/0xc0) from
[<c00cd468>] (do_mount+0x6e0/0x800)
[   65.047778] [<c00cd468>] (do_mount+0x6e0/0x800) from [<c00cd60c>]
(SyS_mount+0x84/0xb8)
[   65.047794] [<c00cd60c>] (SyS_mount+0x84/0xb8) from [<c000f1c0>]
(ret_fast_syscall+0x0/0x30)
[   65.048019] UBIFS: background thread "ubifs_bgt0_16" stops


----debug patch test ok----

diff --git a/fs/ubifs/journal.c b/fs/ubifs/journal.c
index f755a24..eba555e 100755
--- a/fs/ubifs/journal.c
+++ b/fs/ubifs/journal.c
@@ -900,6 +900,9 @@ int ubifs_jnl_delete_inode(struct ubifs_info *c,
const struct inode *inode)
        else
                ubifs_delete_orphan(c, inode->i_ino);
        up_read(&c->commit_sem);
+
+       ubifs_run_commit(c);
+
        return err;
}
-------------------------------------------

Is there any information relevant to the solution of this problem?



