UBIFS-AUTH panic after reboot

UBIFS-AUTH panic after reboot

[Kristof Havasi]

Hi there,

I am trying to deploy a root filesystem with UBIFS encryption and
authentication.
The target is similar to a raspberry pi 2 with an ARM MCU and 1Gb NAND Flash.

Observation:
===========
My applications have been running on a bare UBIFS root filesystem without
encryption or authentication for years now.
When I turn on the UBIFS encryption, the system is still running stable.
But with encryption and authentication I encounter a kernel panic after reboot.
Snippet of the output is at [1].

Interestingly, if I just test the system with filling up the flash via `dd` and
rebooting it periodically, no panic is encountered. But if I install my business
logic and let the daemons and apps start up via bb-init.d and then
kill some apps
and do one or two reboots, I can reproduce the panic every time.
(App installation is done via a manual wget and ipkg install.
The killing is done via killall xxx. I am trying to isolate a minimal scenario
from our business logic with which the phenomenon is reproducible, but with no
success yet.)

Set-up:
======
The root filesystem is created with Buildroot-2020.02.3 with mtd-utils manually
bumped to v2.1.2 and extended to depend on host-openssl because of building with
`--with-crypto` option. The auth-key comes from softHSM and the certificate
counterpart is compiled into the used kernel (v5.4.63) via `signing_key.pem` and
the Kconfigs settings `X509_CERTIFICATE_PARSER` and `SYSTEM_TRUSTED_KEYS`.

So the image is signed off-line. But another auth-key is also injected to the
kernel keyring via a custom driver which takes this key from the bootstrap and
injects it as a logon key to the keyring. The descriptor of this new key is
specified via bootargs using `auth_key`. (And of the hash is defined as sha256
equivalently as the adequate mkfs.ubifs argument.)
With this instrumentation, if I understand correctly, there is a re-signing
taking place after the first boot process/mounting.
The system comes up successfully for the first time.

What I have tried:
=================
Based on the panic log [1], I can see that the panic happens here:
    ubifs_lpt_calc_hash
        `->ubifs_get_pnode
inside the iteration over the LPT pnodes with hashing

Because of this, I re-did the panic-scenario with chk_lprops turned on via
/sys/kernel/debug/ubifs. This generates a lot of logs, even before any business
logic has ever run. E.g. upon `ipkg install`. The logs are scrambled and very
repetitive. A cleaned up snippet is included at [2].

As I researched the www, UBIFS Authentication seems to be a rather new feature,
with rather few documentation and usage examples. (E.g. the otherwise excellent
infradead documentation does not refer to it at all.)

Other things I tried, but didn't gain any improvements by them:

- After killing the business logic apps, a manual `sync && sleep 10 && reboot`
- Turn off runtime compression
- Mount with chk_data_crc
- Mount with sync
- pass `-F` also as a mkfs.ubifs argument
- dmesg -c && dmesg -n 7 and then redo the sequence which generates leads to the
  panic, calling dmesg between each step: Nothing gets logged

Questions:
=========
Q1: Are the chk_* knobs authentication aware? Or do they report so loudly
    because I enabled the authentication and they cannot handle it yet?

Q2: Could I use `integr_chk` with authentication and so that the UBI volume is
    my root filesystem?

Q3: Could anyone help which tools I could use to narrow down the on the trigger?
    E.g. Maybe with some formats combined with dynamic debugging [3]?

Q4: If I stumbled upon a mainline bug, what could I do to help analysis and fix?

Q5: Is there any UBIFS-Auth specific instrumentation for mkfs.ubifs apart from
    passing in the secrets and hash-algo? IDK something like, the journal size
    needs to be increased or other smaller detail?


Any help or suggestion would be greatly appreciated.

Best Regards,
    Kristof

[1]
ubi0: scanning is finished
ubi0: attached mtd1 (name "ubivols", size 1023 MiB)
ubi0: PEB size: 262144 bytes (256 KiB), LEB size: 253952 bytes
ubi0: min./max. I/O unit sizes: 4096/4096, sub-page size 4096
ubi0: VID header offset: 4096 (aligned 4096), data offset: 8192
ubi0: good PEBs: 4076, bad PEBs: 19, corrupted PEBs: 0
ubi0: user volume: 5, internal volumes: 1, max. volumes count: 128
ubi0: max/mean erase counter: 2/0, WL threshold: 4096, image sequence
number: 793556105
ubi0: available PEBs: 0, total reserved PEBs: 4076, PEBs reserved for
bad PEB handling: 61
ubi0: background thread "ubi_bgt0d" started, PID 628
rtc-rv8803 1-0032: setting system clock to 2020-09-08T09:33:20 UTC (1599557600)
UBIFS (ubi0:4): Mounting in authenticated mode
UBIFS (ubi0:4): background thread "ubifs_bgt0_4" started, PID 632
UBIFS error (ubi0:4 pid 1): ubifs_get_pnode.part.6: error -22 reading
pnode at 7:37186
(pid 1) dumping pnode:
        address c7138c80 parent c7138e80 cnext 0
        flags 0 iip 3 level 0 num 0
        0: free 0 dirty 255408 flags 1 lnum 0
        1: free 0 dirty 190192 flags 1 lnum 0
        2: free 0 dirty 255360 flags 1 lnum 0
        3: free 0 dirty 248896 flags 1 lnum 0
CPU: 0 PID: 1 Comm: swapper Not tainted 5.4.49-00026-gb40c178a4299 #2
Hardware name: Atmel SAMA5
[<c010bb5c>] (unwind_backtrace) from [<c010a7c8>] (show_stack+0x10/0x14)
[<c010a7c8>] (show_stack) from [<c0260c8c>] (ubifs_get_pnode.part.6+0x228/0x298)
[<c0260c8c>] (ubifs_get_pnode.part.6) from [<c0262a10>]
(ubifs_lpt_calc_hash+0x1c8/0x220)
[<c0262a10>] (ubifs_lpt_calc_hash) from [<c0262fcc>]
(ubifs_lpt_init+0x564/0x5b0)
[<c0262fcc>] (ubifs_lpt_init) from [<c024bd30>] (ubifs_mount+0x7b8/0x15e8)
[<c024bd30>] (ubifs_mount) from [<c01e38e0>] (legacy_get_tree+0x24/0x50)
[<c01e38e0>] (legacy_get_tree) from [<c01b8b10>] (vfs_get_tree+0x24/0xdc)
[<c01b8b10>] (vfs_get_tree) from [<c01d5fc8>] (do_mount+0x610/0x840)
[<c01d5fc8>] (do_mount) from [<c01d6584>] (ksys_mount+0x8c/0xb4)
[<c01d6584>] (ksys_mount) from [<c0801438>] (mount_block_root+0x124/0x23c)
[<c0801438>] (mount_block_root) from [<c08016dc>] (prepare_namespace+0x9c/0x188)
[<c08016dc>] (prepare_namespace) from [<c0593718>] (kernel_init+0x8/0x108)
[<c0593718>] (kernel_init) from [<c01010e8>] (ret_from_fork+0x14/0x2c)
Exception stack(0xc7829fb0 to 0xc7829ff8)
9fa0:                                     00000000 00000000 00000000 00000000
9fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
9fe0: 00000000 00000000 00000000 00000000 00000013 00000000
UBIFS error (ubi0:4 pid 1): ubifs_get_pnode.part.6: calc num: 71
UBIFS (ubi0:4): background thread "ubifs_bgt0_4" stops


[2]
UBIFS error (ubi0:4 pid 802): do_writepage: cannot write page 29 of
inode 4185, error -30
UBIFS error (ubi0:4 pid 802): make_reservation: cannot reserve 1672
bytes in jhead 2, error -30
UBIFS error (ubi0:4 pid 802): do_writepage: cannot write page 29 of
inode 4187, error -30
UBIFS error (ubi0:4 pid 802): make_reservation: cannot reserve 3720
bytes in jhead 2, error -30
UBIFS error (ubi0:4 pid 802): do_writepage: cannot write page 29 of
inode 4189, error -30
UBIFS error (ubi0:4 pid 802): make_reservation: cannot reserve 1192
bytes in jhead 2, error -30
UBIFS error (ubi0:4 pid 802): do_writepage: cannot write page 29 of
inode 4193, error -30
UBIFS error (ubi0:4 pid 802): make_reservation: cannot reserve 4040
bytes in jhead 2, error -30
UBIFS error (ubi0:4 pid 802): do_writepage: cannot write page 29 of
inode 4207, error -30
UBIFS error (ubi0:4 pid 802): make_reservation: cannot reserve 4200
bytes in jhead 2, error -30
UBIFS error (ubi0:4 pid 802): do_writepage: cannot write page 29 of
inode 4223, error -30


[3] http://www.linux-mtd.infradead.org/faq/ubifs.html#L_how_debug

______________________________________________________
Linux MTD discussion mailing list
http://lists.infradead.org/mailman/listinfo/linux-mtd/

Re: UBIFS-AUTH panic after reboot

[Richard Weinberger]

On Tue, Sep 15, 2020 at 4:51 PM Kristof Havasi <havasiefr@gmail.com> wrote:
> What I have tried:
> =================
> Based on the panic log [1], I can see that the panic happens here:
>     ubifs_lpt_calc_hash
>         `->ubifs_get_pnode
> inside the iteration over the LPT pnodes with hashing

Hmm.

> Questions:
> =========
> Q1: Are the chk_* knobs authentication aware? Or do they report so loudly
>     because I enabled the authentication and they cannot handle it yet?

They should. If not they need fixing. :-)

> Q2: Could I use `integr_chk` with authentication and so that the UBI volume is
>     my root filesystem?

What is "integr_chk"? Do you mean the integ test from mtd-utils?

> Q3: Could anyone help which tools I could use to narrow down the on the trigger?
>     E.g. Maybe with some formats combined with dynamic debugging [3]?

Let's try first with logs.

> Q4: If I stumbled upon a mainline bug, what could I do to help analysis and fix?

We will ask for what we need. No worries.
In most cases logs are fine. Sometimes a dump of a filesystem is helpful too.
Depends on the bug.

> Q5: Is there any UBIFS-Auth specific instrumentation for mkfs.ubifs apart from
>     passing in the secrets and hash-algo? IDK something like, the journal size
>     needs to be increased or other smaller detail?

Not really. It should as-is work. Otherwise mkfs.ubkfs needs fixing.

> UBIFS (ubi0:4): Mounting in authenticated mode
> UBIFS (ubi0:4): background thread "ubifs_bgt0_4" started, PID 632
> UBIFS error (ubi0:4 pid 1): ubifs_get_pnode.part.6: error -22 reading

So, it returns -EINVAL. Is this with chk_* enabled?

> pnode at 7:37186
> (pid 1) dumping pnode:
>         address c7138c80 parent c7138e80 cnext 0
>         flags 0 iip 3 level 0 num 0
>         0: free 0 dirty 255408 flags 1 lnum 0
>         1: free 0 dirty 190192 flags 1 lnum 0
>         2: free 0 dirty 255360 flags 1 lnum 0
>         3: free 0 dirty 248896 flags 1 lnum 0

Sascha, does this ring a bell?

-- 
Thanks,
//richard

______________________________________________________
Linux MTD discussion mailing list
http://lists.infradead.org/mailman/listinfo/linux-mtd/

Re: UBIFS-AUTH panic after reboot

[Kristof Havasi]

In the meantime we could create a simple "clean trigger", independent from our
business logic! It is done by creating random files and then deleting them.
BUT *the size* of the files and *the number* of them do have an influence.
As well as whether we delete them or not.
We could reproduce this behaviour on multiple devices.

A stripped down version of the trigger-script (without echos and such):

```
#!/bin/bash
DEST_DIR=/root/panictest
FILE_CNT=15
FILE_SIZE="10M"
DO_CLEANUP='y'
POST_SYNC_SLEEP=1

[ -d "$DEST_DIR" ] && rm -rf "$DEST_DIR"

mkdir -p "$DEST_DIR"

for i in `seq 1 $FILE_CNT` ; do
    OUT_FILE="$DEST_DIR/file$i"
    if ! dd if=/dev/urandom of=$OUT_FILE bs=$FILE_SIZE count=1 > /dev/null; then
        break
    fi
done

sync
sleep $POST_SYNC_SLEEP
df -h

if [[ "$DO_CLEANUP" == 'y' ]]; then
    rm -rf $DEST_DIR
    sync
    sleep $POST_SYNC_SLEEP
fi

reboot
```

Without "chk_lprops" the panic is only visible after the restart, but if it was
enabled the following assertion was triggering an immediate panic:
(Should I "reformat" long log lines in the future or leave them verbatim?)

UBIFS error (ubi0:4 pid 649): ubifs_assert_failed: UBIFS assert
failed: (val >> nrbits) == 0 || nrbits == 32, in fs/ubifs/lpt.c:231
UBIFS warning (ubi0:4 pid 649): ubifs_ro_mode.part.1: switched to
read-only mode, error -22
CPU: 0 PID: 649 Comm: ubifs_bgt0_4 Not tainted 5.4.64-00030-gbcb07cf6f1bb #35
Hardware name: Atmel SAMA5
[<c010bb5c>] (unwind_backtrace) from [<c010a7c8>] (show_stack+0x10/0x14)
[<c010a7c8>] (show_stack) from [<c0260c40>] (pack_bits+0x1ac/0x1d0)
[<c0260c40>] (pack_bits) from [<c0261854>] (ubifs_pack_pnode+0xa4/0x144)
[<c0261854>] (ubifs_pack_pnode) from [<c02631c4>]
(ubifs_lpt_calc_hash+0x134/0x220)
[<c02631c4>] (ubifs_lpt_calc_hash) from [<c026acdc>]
(ubifs_lpt_start_commit+0x754/0xe54)
[<c026acdc>] (ubifs_lpt_start_commit) from [<c02599c8>] (do_commit+0x1d0/0x484)
[<c02599c8>] (do_commit) from [<c0259dbc>] (ubifs_bg_thread+0x140/0x154)
[<c0259dbc>] (ubifs_bg_thread) from [<c012fef8>] (kthread+0x114/0x144)
[<c012fef8>] (kthread) from [<c01010e8>] (ret_from_fork+0x14/0x2c)
Exception stack(0xc71fffb0 to 0xc71ffff8)
ffa0:                                     00000000 00000000 00000000 00000000
ffc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
ffe0: 00000000 00000000 00000000 00000000 00000013 00000000
UBIFS error (ubi0:4 pid 649): ubifs_assert_failed: UBIFS assert
failed: (val >> nrbits) == 0 || nrbits == 32, in fs/ubifs/lpt.c:231
UBIFS error (ubi0:4 pid 649): ubifs_assert_failed: UBIFS assert
failed: (val >> nrbits) == 0 || nrbits == 32, in fs/ubifs/lpt.c:231


Regarding the variable space (fsize-fcount-docleanup), these were our first
rudimental findings:

fsize | fcount | ~used% | docleanup | panic? |
----- | ------ | ------ | --------- | ------ |
 10M  |  10    |  ~10%  |    yes    |   no   |
 10M  |  15    |  ~15%  |    yes    |   yes  |
 10M  |  NA    |  ~25%  |    yes    |   yes  |
 10M  |  NA    |  ~50%  |    yes    |   yes  |
 10M  |  NA    | ~100%  |    yes    |   yes  |
 10M  |  NA    | ~100%  |    no     |   no   |
  1M  |  NA    | ~100%  |    yes    |   no   |

So if we write >100M worth of 10M files and delete them we can
"ropustly" trigger
the panic. But if we do not delete them, the panic does not occour.

But if we fill the flash with 1M files and delete them, we didn't see the panic.


On Thu, 17 Sep 2020 at 15:24, Richard Weinberger
<richard.weinberger@gmail.com> wrote:
>
> On Tue, Sep 15, 2020 at 4:51 PM Kristof Havasi <havasiefr@gmail.com> wrote:
> > What I have tried:
> > =================
> > Based on the panic log [1], I can see that the panic happens here:
> >     ubifs_lpt_calc_hash
> >         `->ubifs_get_pnode
> > inside the iteration over the LPT pnodes with hashing
>
> Hmm.
>
> > Questions:
> > =========
> > Q1: Are the chk_* knobs authentication aware? Or do they report so loudly
> >     because I enabled the authentication and they cannot handle it yet?
>
> They should. If not they need fixing. :-)

They do seem to be OK, because with chk_lprops enabled, and the clean trigger
script the panic (UBI assertion) was cought immediately, not only
after a restart.

>
> > Q2: Could I use `integr_chk` with authentication and so that the UBI volume is
> >     my root filesystem?
>
> What is "integr_chk"? Do you mean the integ test from mtd-utils?

Sorry, I didn't write the correct name: I meant "integck" from mtd-utlis.

> > UBIFS (ubi0:4): Mounting in authenticated mode
> > UBIFS (ubi0:4): background thread "ubifs_bgt0_4" started, PID 632
> > UBIFS error (ubi0:4 pid 1): ubifs_get_pnode.part.6: error -22 reading
>
> So, it returns -EINVAL. Is this with chk_* enabled?

In both cases: with and without enabled chk_* knobs.

>
> > pnode at 7:37186
> > (pid 1) dumping pnode:
> >         address c7138c80 parent c7138e80 cnext 0
> >         flags 0 iip 3 level 0 num 0
> >         0: free 0 dirty 255408 flags 1 lnum 0
> >         1: free 0 dirty 190192 flags 1 lnum 0
> >         2: free 0 dirty 255360 flags 1 lnum 0
> >         3: free 0 dirty 248896 flags 1 lnum 0
>
> Sascha, does this ring a bell?

FYI: here sometimes I see some node(s) with non-zero value for "free".

>
> --
> Thanks,
> //richard

Just let me know if I can provide any other useful information.

Thank you,
    Kristof

______________________________________________________
Linux MTD discussion mailing list
http://lists.infradead.org/mailman/listinfo/linux-mtd/

Re: UBIFS-AUTH panic after reboot

[Richard Weinberger]

On Thu, Sep 17, 2020 at 4:48 PM Kristof Havasi <havasiefr@gmail.com> wrote:
> Without "chk_lprops" the panic is only visible after the restart, but if it was
> enabled the following assertion was triggering an immediate panic:
> (Should I "reformat" long log lines in the future or leave them verbatim?)
>
> UBIFS error (ubi0:4 pid 649): ubifs_assert_failed: UBIFS assert
> failed: (val >> nrbits) == 0 || nrbits == 32, in fs/ubifs/lpt.c:231
> UBIFS warning (ubi0:4 pid 649): ubifs_ro_mode.part.1: switched to

Hm, the number of bits we ask to pack is smaller than val.
Maybe we have some subtle bug where a node length is not correctly
calculated.

From your other mail:
> >         0: free 0 dirty 255408 flags 1 lnum 0

Dirty is larger than LEB size (253952). Must not happen.

> >         1: free 0 dirty 190192 flags 1 lnum 0
> >         2: free 0 dirty 255360 flags 1 lnum 0

Same.

> >         3: free 0 dirty 248896 flags 1 lnum 0

Does the problem also trigger with encryption disabled? So just with
authentication?

-- 
Thanks,
//richard

______________________________________________________
Linux MTD discussion mailing list
http://lists.infradead.org/mailman/listinfo/linux-mtd/

Re: UBIFS-AUTH panic after reboot

[Richard Weinberger]

On Sat, Sep 19, 2020 at 10:02 PM Richard Weinberger
<richard.weinberger@gmail.com> wrote:
>
> On Thu, Sep 17, 2020 at 4:48 PM Kristof Havasi <havasiefr@gmail.com> wrote:
> > Without "chk_lprops" the panic is only visible after the restart, but if it was
> > enabled the following assertion was triggering an immediate panic:
> > (Should I "reformat" long log lines in the future or leave them verbatim?)
> >
> > UBIFS error (ubi0:4 pid 649): ubifs_assert_failed: UBIFS assert
> > failed: (val >> nrbits) == 0 || nrbits == 32, in fs/ubifs/lpt.c:231
> > UBIFS warning (ubi0:4 pid 649): ubifs_ro_mode.part.1: switched to
>
> Hm, the number of bits we ask to pack is smaller than val.
> Maybe we have some subtle bug where a node length is not correctly
> calculated.
>
> From your other mail:
> > >         0: free 0 dirty 255408 flags 1 lnum 0
>
> Dirty is larger than LEB size (253952). Must not happen.
>
> > >         1: free 0 dirty 190192 flags 1 lnum 0
> > >         2: free 0 dirty 255360 flags 1 lnum 0
>
> Same.
>
> > >         3: free 0 dirty 248896 flags 1 lnum 0
>
> Does the problem also trigger with encryption disabled? So just with
> authentication?

One more question, when you mount ubifs successuflly, you see a line like:
UBIFS (ubi0:0): media format: w5/r0 (latest is w5/r0), UUID
942AA41D-81B8-4F57-9CE6-0548D0D0DCB0, big LPT model

Does it print big LPT or small LPT model?

-- 
Thanks,
//richard

______________________________________________________
Linux MTD discussion mailing list
http://lists.infradead.org/mailman/listinfo/linux-mtd/

Re: UBIFS-AUTH panic after reboot

[Kristof Havasi]

On Sat, 19 Sep 2020 at 22:54, Richard Weinberger
<richard.weinberger@gmail.com> wrote:
>
> On Sat, Sep 19, 2020 at 10:02 PM Richard Weinberger
> <richard.weinberger@gmail.com> wrote:
> >
> > On Thu, Sep 17, 2020 at 4:48 PM Kristof Havasi <havasiefr@gmail.com> wrote:
> > > Without "chk_lprops" the panic is only visible after the restart, but if it was
> > > enabled the following assertion was triggering an immediate panic:
> > > (Should I "reformat" long log lines in the future or leave them verbatim?)
> > >
> > > UBIFS error (ubi0:4 pid 649): ubifs_assert_failed: UBIFS assert
> > > failed: (val >> nrbits) == 0 || nrbits == 32, in fs/ubifs/lpt.c:231
> > > UBIFS warning (ubi0:4 pid 649): ubifs_ro_mode.part.1: switched to
> >
> > Hm, the number of bits we ask to pack is smaller than val.
> > Maybe we have some subtle bug where a node length is not correctly
> > calculated.
> >
> > From your other mail:
> > > >         0: free 0 dirty 255408 flags 1 lnum 0
> >
> > Dirty is larger than LEB size (253952). Must not happen.
> >
> > > >         1: free 0 dirty 190192 flags 1 lnum 0
> > > >         2: free 0 dirty 255360 flags 1 lnum 0
> >
> > Same.
> >
> > > >         3: free 0 dirty 248896 flags 1 lnum 0
> >
> > Does the problem also trigger with encryption disabled? So just with
> > authentication?

I couldn't trigger the same error with encryption disabled and authentication
enabled. Even if I enabled all the chk_* knobs under kernel/debug/ubifs/, no
failed assertion or error/warning log could be observed.

ubi0: attached mtd1 (name "ubivols", size 1023 MiB)
ubi0: PEB size: 262144 bytes (256 KiB), LEB size: 253952 bytes
ubi0: min./max. I/O unit sizes: 4096/4096, sub-page size 4096
ubi0: VID header offset: 4096 (aligned 4096), data offset: 8192
ubi0: good PEBs: 4063, bad PEBs: 32, corrupted PEBs: 0
ubi0: user volume: 5, internal volumes: 1, max. volumes count: 128
ubi0: max/mean erase counter: 2/1, WL threshold: 4096, image sequence
number: 460709978
ubi0: available PEBs: 0, total reserved PEBs: 4063, PEBs reserved for
bad PEB handling: 48
ubi0: background thread "ubi_bgt0d" started, PID 638
rtc-rv8803 1-0032: setting system clock to 2020-09-21T09:11:23 UTC (1600679483)
UBIFS (ubi0:4): Mounting in authenticated mode
UBIFS (ubi0:4): background thread "ubifs_bgt0_4" started, PID 642
UBIFS (ubi0:4): UBIFS: mounted UBI device 0, volume 4, name "rootfs"
UBIFS (ubi0:4): LEB size: 253952 bytes (248 KiB), min./max. I/O unit
sizes: 4096 bytes/4096 bytes
UBIFS (ubi0:4): FS size: 1004888064 bytes (958 MiB, 3957 LEBs),
journal size 9404416 bytes (8 MiB, 38 LEBs)
UBIFS (ubi0:4): reserved for root: 0 bytes (0 KiB)
UBIFS (ubi0:4): media format: w4/r0 (latest is w5/r0), UUID
7BFF4409-EE99-4BAB-9091-16FFDEBBD78A, small LPT model
VFS: Mounted root (ubifs filesystem) on device 0:13.

>
> One more question, when you mount ubifs successuflly, you see a line like:
> UBIFS (ubi0:0): media format: w5/r0 (latest is w5/r0), UUID
> 942AA41D-81B8-4F57-9CE6-0548D0D0DCB0, big LPT model
>
> Does it print big LPT or small LPT model?

small LPT model.

UBIFS (ubi0:4): Mounting in authenticated mode
UBIFS (ubi0:4): Successfully verified super block signature
UBIFS (ubi0:4): background thread "ubifs_bgt0_4" started, PID 634
UBIFS (ubi0:4): UBIFS: mounted UBI device 0, volume 4, name "rootfs"
UBIFS (ubi0:4): LEB size: 253952 bytes (248 KiB), min./max. I/O unit
sizes: 4096 bytes/4096 bytes
UBIFS (ubi0:4): FS size: 1004888064 bytes (958 MiB, 3957 LEBs),
journal size 9404416 bytes (8 MiB, 38 LEBs)
UBIFS (ubi0:4): reserved for root: 0 bytes (0 KiB)
UBIFS (ubi0:4): media format: w5/r0 (latest is w5/r0), UUID
3F835B56-9D63-49F9-A3A8-4EFDF2800462, small LPT model
VFS: Mounted root (ubifs filesystem) on device 0:13.
fscrypt: AES-256-CTS-CBC using implementation "cts(atmel-cbc-aes)"
devtmpfs: mounted
Freeing unused kernel memory: 1024K
fscrypt: AES-256-XTS using implementation "xts(atmel-ecb-aes)"

Thank you,
        Kristof


On Sat, 19 Sep 2020 at 22:54, Richard Weinberger
<richard.weinberger@gmail.com> wrote:
>
> On Sat, Sep 19, 2020 at 10:02 PM Richard Weinberger
> <richard.weinberger@gmail.com> wrote:
> >
> > On Thu, Sep 17, 2020 at 4:48 PM Kristof Havasi <havasiefr@gmail.com> wrote:
> > > Without "chk_lprops" the panic is only visible after the restart, but if it was
> > > enabled the following assertion was triggering an immediate panic:
> > > (Should I "reformat" long log lines in the future or leave them verbatim?)
> > >
> > > UBIFS error (ubi0:4 pid 649): ubifs_assert_failed: UBIFS assert
> > > failed: (val >> nrbits) == 0 || nrbits == 32, in fs/ubifs/lpt.c:231
> > > UBIFS warning (ubi0:4 pid 649): ubifs_ro_mode.part.1: switched to
> >
> > Hm, the number of bits we ask to pack is smaller than val.
> > Maybe we have some subtle bug where a node length is not correctly
> > calculated.
> >
> > From your other mail:
> > > >         0: free 0 dirty 255408 flags 1 lnum 0
> >
> > Dirty is larger than LEB size (253952). Must not happen.
> >
> > > >         1: free 0 dirty 190192 flags 1 lnum 0
> > > >         2: free 0 dirty 255360 flags 1 lnum 0
> >
> > Same.
> >
> > > >         3: free 0 dirty 248896 flags 1 lnum 0
> >
> > Does the problem also trigger with encryption disabled? So just with
> > authentication?
>
> One more question, when you mount ubifs successuflly, you see a line like:
> UBIFS (ubi0:0): media format: w5/r0 (latest is w5/r0), UUID
> 942AA41D-81B8-4F57-9CE6-0548D0D0DCB0, big LPT model
>
> Does it print big LPT or small LPT model?
>
> --
> Thanks,
> //richard

______________________________________________________
Linux MTD discussion mailing list
http://lists.infradead.org/mailman/listinfo/linux-mtd/

Re: UBIFS-AUTH panic after reboot

[Richard Weinberger]

----- Ursprüngliche Mail -----
>> > Does the problem also trigger with encryption disabled? So just with
>> > authentication? 
> I couldn't trigger the same error with encryption disabled and authentication
> enabled. Even if I enabled all the chk_* knobs under kernel/debug/ubifs/, no
> failed assertion or error/warning log could be observed.

So, with either encryption or authentication enabled everything is fine
but when both are enabled you hit the problem?
Interesting.

>> Does it print big LPT or small LPT model?
> 
> small LPT model.

I'll try to reproduce now on a similar sized NAND. :-)

Thanks,
//richard

______________________________________________________
Linux MTD discussion mailing list
http://lists.infradead.org/mailman/listinfo/linux-mtd/

Re: UBIFS-AUTH panic after reboot

[Kristof Havasi]

On Mon, 21 Sep 2020 at 11:51, Richard Weinberger <richard@nod.at> wrote:
>
> ----- Ursprüngliche Mail -----
> >> > Does the problem also trigger with encryption disabled? So just with
> >> > authentication?
> > I couldn't trigger the same error with encryption disabled and authentication
> > enabled. Even if I enabled all the chk_* knobs under kernel/debug/ubifs/, no
> > failed assertion or error/warning log could be observed.
>
> So, with either encryption or authentication enabled everything is fine
> but when both are enabled you hit the problem?
> Interesting.

That is exactly what I can observe.

>
> >> Does it print big LPT or small LPT model?
> >
> > small LPT model.
>
> I'll try to reproduce now on a similar sized NAND. :-)

I mentioned that I use the buildroot's mkfs.ubifs with customization,
but here are the parameters:
(Configured via Kconfig)

--max-leb-cnt=3968
--min-io-size=0x1000
--leb-size=0x3E000
--key /path/to/key
--key-descriptor dead12345678beef
--cipher AES-256-XTS
--hash-algo sha256
--auth-key="pkcs11:token=..."

The flash is a Micron MT29F8G08ABACAWP-IT:C which has 224 bytes OOB,
which is not
included in the --min-io-size. That is ok, isn't?

Thank you,
        Kristof

______________________________________________________
Linux MTD discussion mailing list
http://lists.infradead.org/mailman/listinfo/linux-mtd/

Re: UBIFS-AUTH panic after reboot

[Richard Weinberger]

On Mon, Sep 21, 2020 at 12:46 PM Kristof Havasi <havasiefr@gmail.com> wrote:
>
> On Mon, 21 Sep 2020 at 11:51, Richard Weinberger <richard@nod.at> wrote:
> >
> > ----- Ursprüngliche Mail -----
> > >> > Does the problem also trigger with encryption disabled? So just with
> > >> > authentication?
> > > I couldn't trigger the same error with encryption disabled and authentication
> > > enabled. Even if I enabled all the chk_* knobs under kernel/debug/ubifs/, no
> > > failed assertion or error/warning log could be observed.
> >
> > So, with either encryption or authentication enabled everything is fine
> > but when both are enabled you hit the problem?
> > Interesting.
>
> That is exactly what I can observe.
>
> >
> > >> Does it print big LPT or small LPT model?
> > >
> > > small LPT model.
> >
> > I'll try to reproduce now on a similar sized NAND. :-)
>
> I mentioned that I use the buildroot's mkfs.ubifs with customization,
> but here are the parameters:
> (Configured via Kconfig)
>
> --max-leb-cnt=3968
> --min-io-size=0x1000
> --leb-size=0x3E000
> --key /path/to/key
> --key-descriptor dead12345678beef
> --cipher AES-256-XTS
> --hash-algo sha256
> --auth-key="pkcs11:token=..."
>
> The flash is a Micron MT29F8G08ABACAWP-IT:C which has 224 bytes OOB,
> which is not
> included in the --min-io-size. That is ok, isn't?

Yes. Both UBI and UBIFS don't use OOB.

I think I've found the problem. Can you please test the following change?

diff --git a/fs/ubifs/journal.c b/fs/ubifs/journal.c
index 4a5b06f8d812..869ef6efa48f 100644
--- a/fs/ubifs/journal.c
+++ b/fs/ubifs/journal.c
@@ -936,8 +936,6 @@ int ubifs_jnl_write_inode(struct ubifs_info *c,
const struct inode *inode)
                                          inode->i_ino);
        release_head(c, BASEHD);

-       ubifs_add_auth_dirt(c, lnum);
-
        if (last_reference) {
                err = ubifs_tnc_remove_ino(c, inode->i_ino);
                if (err)
@@ -947,6 +945,8 @@ int ubifs_jnl_write_inode(struct ubifs_info *c,
const struct inode *inode)
        } else {
                union ubifs_key key;

+               ubifs_add_auth_dirt(c, lnum);
+
                ino_key_init(c, &key, inode->i_ino);
                err = ubifs_tnc_add(c, &key, lnum, offs, ilen, hash);
        }

A few lines before in the we last_reference call ubifs_add_dirt(c,
lnum, write_len) and write_len contains
already the auth node size. So the auth node size is accounted twice.
Please let me know whether it helps, I think ubifs_jnl_write_inode()
needs more cleanup.

-- 
Thanks,
//richard

______________________________________________________
Linux MTD discussion mailing list
http://lists.infradead.org/mailman/listinfo/linux-mtd/

Re: UBIFS-AUTH panic after reboot

[Kristof Havasi]

> I think I've found the problem. Can you please test the following change?

I tested quickly with a subset of the previous tests, and until now I
have not seen any panics!
I will keep on running some other tests, including our business logic,
and will report back to
you whether we see any unexpected hic-ups.

Thank you a lot and best regards,
Kristof

On Sun, 27 Sep 2020 at 21:27, Richard Weinberger
<richard.weinberger@gmail.com> wrote:
>
> On Mon, Sep 21, 2020 at 12:46 PM Kristof Havasi <havasiefr@gmail.com> wrote:
> >
> > On Mon, 21 Sep 2020 at 11:51, Richard Weinberger <richard@nod.at> wrote:
> > >
> > > ----- Ursprüngliche Mail -----
> > > >> > Does the problem also trigger with encryption disabled? So just with
> > > >> > authentication?
> > > > I couldn't trigger the same error with encryption disabled and authentication
> > > > enabled. Even if I enabled all the chk_* knobs under kernel/debug/ubifs/, no
> > > > failed assertion or error/warning log could be observed.
> > >
> > > So, with either encryption or authentication enabled everything is fine
> > > but when both are enabled you hit the problem?
> > > Interesting.
> >
> > That is exactly what I can observe.
> >
> > >
> > > >> Does it print big LPT or small LPT model?
> > > >
> > > > small LPT model.
> > >
> > > I'll try to reproduce now on a similar sized NAND. :-)
> >
> > I mentioned that I use the buildroot's mkfs.ubifs with customization,
> > but here are the parameters:
> > (Configured via Kconfig)
> >
> > --max-leb-cnt=3968
> > --min-io-size=0x1000
> > --leb-size=0x3E000
> > --key /path/to/key
> > --key-descriptor dead12345678beef
> > --cipher AES-256-XTS
> > --hash-algo sha256
> > --auth-key="pkcs11:token=..."
> >
> > The flash is a Micron MT29F8G08ABACAWP-IT:C which has 224 bytes OOB,
> > which is not
> > included in the --min-io-size. That is ok, isn't?
>
> Yes. Both UBI and UBIFS don't use OOB.
>
> I think I've found the problem. Can you please test the following change?
>
> diff --git a/fs/ubifs/journal.c b/fs/ubifs/journal.c
> index 4a5b06f8d812..869ef6efa48f 100644
> --- a/fs/ubifs/journal.c
> +++ b/fs/ubifs/journal.c
> @@ -936,8 +936,6 @@ int ubifs_jnl_write_inode(struct ubifs_info *c,
> const struct inode *inode)
>                                           inode->i_ino);
>         release_head(c, BASEHD);
>
> -       ubifs_add_auth_dirt(c, lnum);
> -
>         if (last_reference) {
>                 err = ubifs_tnc_remove_ino(c, inode->i_ino);
>                 if (err)
> @@ -947,6 +945,8 @@ int ubifs_jnl_write_inode(struct ubifs_info *c,
> const struct inode *inode)
>         } else {
>                 union ubifs_key key;
>
> +               ubifs_add_auth_dirt(c, lnum);
> +
>                 ino_key_init(c, &key, inode->i_ino);
>                 err = ubifs_tnc_add(c, &key, lnum, offs, ilen, hash);
>         }
>
> A few lines before in the we last_reference call ubifs_add_dirt(c,
> lnum, write_len) and write_len contains
> already the auth node size. So the auth node size is accounted twice.
> Please let me know whether it helps, I think ubifs_jnl_write_inode()
> needs more cleanup.
>
> --
> Thanks,
> //richard

______________________________________________________
Linux MTD discussion mailing list
http://lists.infradead.org/mailman/listinfo/linux-mtd/

Re: UBIFS-AUTH panic after reboot

[Richard Weinberger]

On Tue, Sep 29, 2020 at 10:29 AM Kristof Havasi <havasiefr@gmail.com> wrote:
>
> Dear Richard,
>
> after a day of stress test, we still didn't see any emerging panics, so we can confirm that your patch fixes the problem!

Nice.

> Thanks for my colleague, Karthik Chintamani Uppund for the extensive testing.

Thanks for reporting and testing!

-- 
Thanks,
//richard

______________________________________________________
Linux MTD discussion mailing list
http://lists.infradead.org/mailman/listinfo/linux-mtd/