WG: Re: UBIFS - ubifs_get_pnode.part.4: error -22 reading pnode

[Erdrich, Frank]

Hello Richard,

At the end of the last week I analyzed the data of our test setup. We have around 26 devices in a long time test setup where we are doing several stress tests on the devices. A typical test run is to power up the device, execute the test, power down (hard power cut). The tests were run for around 2 Weeks and we have two devices that show that error. The interesting thing about that is that it never corrupted the root-partition, although this partition is written during every testrun. And there seems to be a pattern when that error happens.

During the bootup before the error from my first post pops up (ubifs_get_pnode.part.4: error -22 reading pnode) this error messages were seen on all of the two devices that have shown the other error:

ubi2: attaching mtd2
ubi2: scanning is finished
ubi2: attached mtd2 (name \"log\", size 70 MiB)
ubi2: PEB size: 524288 bytes (512 KiB), LEB size: 516096 bytes
ubi2: min./max. I/O unit sizes: 4096/4096, sub-page size 4096
ubi2: VID header offset: 4096 (aligned 4096), data offset: 8192
ubi2: good PEBs: 140, bad PEBs: 0, corrupted PEBs: 0
ubi2: user volume: 1, internal volumes: 1, max. volumes count: 128
ubi2: max/mean erase counter: 66/30, WL threshold: 4096, image sequence number: 1574181447
ubi2: available PEBs: 0, total reserved PEBs: 140, PEBs reserved for bad PEB handling: 40
ubi2: background thread \"ubi_bgt2d\" started, PID 129
         Mounting log partition...
UBIFS (ubi2:0): background thread \"ubifs_bgt2_0\" started, PID 145 UBIFS (ubi2:0): recovery needed UBIFS assert failed in ubifs_change_lp at 559 (pid 143)
CPU: 0 PID: 143 Comm: mount Not tainted 4.9.51 #152 Hardware name: Atmel SAMA5 [<c0110570>] (unwind_backtrace) from [<c010d488>] (show_stack+0x20/0x24) [<c010d488>] (show_stack) from [<c0390cdc>] (dump_stack+0x24/0x28) [<c0390cdc>] (dump_stack) from [<c031f7b8>] (ubifs_change_lp+0x754/0x794) [<c031f7b8>] (ubifs_change_lp) from [<c030d6c8>] (ubifs_replay_journal+0x105c/0x1670)
[<c030d6c8>] (ubifs_replay_journal) from [<c0300380>] (ubifs_mount+0x1194/0x1e8c) [<c0300380>] (ubifs_mount) from [<c0209ea0>] (mount_fs+0x54/0x170) [<c0209ea0>] (mount_fs) from [<c0228dec>] (vfs_kern_mount+0x58/0x124) [<c0228dec>] (vfs_kern_mount) from [<c022c6e0>] (do_mount+0x1bc/0xcc0) [<c022c6e0>] (do_mount) from [<c022d548>] (SyS_mount+0x84/0xac) [<c022d548>] (SyS_mount) from [<c0109380>] (ret_fast_syscall+0x0/0x3c) UBIFS assert failed in pack_bits at 242 (pid 143)
CPU: 0 PID: 143 Comm: mount Not tainted 4.9.51 #152 Hardware name: Atmel SAMA5 [<c0110570>] (unwind_backtrace) from [<c010d488>] (show_stack+0x20/0x24) [<c010d488>] (show_stack) from [<c0390cdc>] (dump_stack+0x24/0x28) [<c0390cdc>] (dump_stack) from [<c0319408>] (pack_bits+0x244/0x248) [<c0319408>] (pack_bits) from [<c031a274>] (ubifs_pack_pnode+0xa0/0x12c) [<c031a274>] (ubifs_pack_pnode) from [<c0325ad4>] (ubifs_lpt_end_commit+0x29c/0x8d4)
[<c0325ad4>] (ubifs_lpt_end_commit) from [<c0310044>] (do_commit+0x2b4/0x5d8) [<c0310044>] (do_commit) from [<c03106c0>] (ubifs_run_commit+0xcc/0x184) [<c03106c0>] (ubifs_run_commit) from [<c03219ec>] (ubifs_rcvry_gc_commit+0xc0/0x348)
[<c03219ec>] (ubifs_rcvry_gc_commit) from [<c030049c>] (ubifs_mount+0x12b0/0x1e8c) [<c030049c>] (ubifs_mount) from [<c0209ea0>] (mount_fs+0x54/0x170) [<c0209ea0>] (mount_fs) from [<c0228dec>] (vfs_kern_mount+0x58/0x124) [<c0228dec>] (vfs_kern_mount) from [<c022c6e0>] (do_mount+0x1bc/0xcc0) [<c022c6e0>] (do_mount) from [<c022d548>] (SyS_mount+0x84/0xac) [<c022d548>] (SyS_mount) from [<c0109380>] (ret_fast_syscall+0x0/0x3c) UBIFS (ubi2:0): recovery completed UBIFS (ubi2:0): UBIFS: mounted UBI device 2, volume 0, name \"log\"
UBIFS (ubi2:0): LEB size: 516096 bytes (504 KiB), min./max. I/O unit sizes: 4096 bytes/4096 bytes UBIFS (ubi2:0): FS size: 44384256 bytes (42 MiB, 86 LEBs), journal size 4128769 bytes (3 MiB, 6 LEBs) UBIFS (ubi2:0): reserved for root: 2096377 bytes (2047 KiB) UBIFS (ubi2:0): media format: w4/r0 (latest is w4/r0), UUID 05834B37-B18C-476F-BFA5-DB76ADF26D50, small LPT model
systemd[1]: Mounted log partition.

So the cycle is as follows:

- power up the device
- error " UBIFS assert failed in ubifs_change_lp" was seen during bootup
- tests are run
- device gets power cut
- device is powered up again
- error ubifs_get_pnode.part.4: error -22 reading pnode pops up during bootup

I'm not sure if that helps.
I also have to retest your patches. I tried to backport them to kernel 4.9 which isn't that easy due to fscrypt so I will prepare a newer kernel where the patches will apply in an easier way.


Best regards,
Frank Erdrich