Bug 214765

Summary:	ubifs: UBIFS error (ubi0:0 pid 124): ubifs_assert_failed [ubifs]: UBIFS assert failed: c->bi.dd_growth >= 0, in fs/ubifs/budget.c:554
Product:	File System	Reporter:	Zhihao Cheng (chengzhihao1)
Component:	Other	Assignee:	fs_other
Status:	NEW ---
Severity:	normal
Priority:	P1
Hardware:	All
OS:	Linux
Kernel Version:	5.15-rc5	Subsystem:
Regression:	No	Bisected commit-id:
Attachments:	delay.patch test.sh a.c

Description Zhihao Cheng 2021-10-20 02:34:01 UTC

[   23.247289] UBIFS error (ubi0:0 pid 124): ubifs_assert_failed [ubifs]: UBIFS assert failed: c->bi.dd_growth >= 0, in fs/ubifs/budget.c:554
[   23.253718] UBIFS warning (ubi0:0 pid 124): ubifs_ro_mode [ubifs]: switched to read-only mode, error -22
[   23.256672] CPU: 3 PID: 124 Comm: kworker/u8:2 Not tainted 5.15.0-rc5-00259-g1c6a7ce3cb2d-dirty #136
[   23.258300] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS ?-20190727_073836-buildvm-ppc64le-16.ppc.fedoraproject.org-3.fc31 04/01/2014
[   23.260054] Workqueue: writeback wb_workfn (flush-ubifs_0_0)
[   23.260816] Call Trace:
[   23.261156]  ? dump_stack_lvl+0x73/0x9f
[   23.261674]  ? dump_stack+0x13/0x1b
[   23.262152]  ? ubifs_ro_mode+0x54/0x60 [ubifs]
[   23.262766]  ? ubifs_assert_failed+0x4b/0x80 [ubifs]
[   23.263454]  ? ubifs_release_budget+0x468/0x5a0 [ubifs]
[   23.264175]  ? ubifs_release_dirty_inode_budget+0x53/0x80 [ubifs]
[   23.265006]  ? ubifs_write_inode+0x121/0x1f0 [ubifs]
[   23.265786]  ? __writeback_single_inode+0x43c/0x570
[   23.266477]  ? writeback_sb_inodes+0x259/0x740
[   23.267099]  ? __writeback_inodes_wb+0x88/0x120
[   23.267732]  ? wb_writeback+0x3cf/0x4d0
[   23.268272]  ? wb_workfn+0x283/0x7b0
[   23.268782]  ? check_preempt_curr+0x8d/0xb0
[   23.269384]  ? ttwu_do_activate+0xb2/0x200
[   23.269948]  ? process_one_work+0x291/0x650
[   23.270534]  ? worker_thread+0x2b7/0x700
[   23.271183]  ? rescuer_thread+0x580/0x580
[   23.271778]  ? kthread+0x18c/0x1e0
[   23.272286]  ? set_kthread_struct+0x70/0x70
[   23.272918]  ? ret_from_fork+0x1f/0x30

Comment 1 Zhihao Cheng 2021-10-20 02:34:42 UTC

generic/476 can easily trigger this problem.

Comment 2 Zhihao Cheng 2021-10-20 06:30:27 UTC

'ui->dirty' is not protected by ui_mutex in function do_tmpfile() which may race with ubifs_write_inode(wb_workfn) to access/update 'ui->dirty', finally dirty space is released twice.

           open(O_TMPFILE)                wb_workfn
do_tmpfile
  ubifs_budget_space(ino_req = { .dirtied_ino = 1})
  d_tmpfile // mark inode(tmpfile) dirty
  ubifs_jnl_update // without holding tmpfile's ui_mutex
    mark_inode_clean(ui)
      if (ui->dirty)
        ubifs_release_dirty_inode_budget(ui)  // release 
                                       ubifs_write_inode
                                         ubifs_release_dirty_inode_budget(ui)
      ui->dirty = 0

Comment 3 Zhihao Cheng 2021-10-20 06:33:34 UTC

Reproducer:
1. Apply delay.patch and compile kernel (UBIFS/UBI/NANDSIM = m)
2. ./test.sh
3. Compile and run a.c

You may get:
[14569.338625] release dirty budget 65
[14570.338640] wb release 65
[14570.348279] UBIFS error (ubi0:0 pid 2578): ubifs_assert_failed [ubifs]: UBIFS assert failed: c->bi.dd_growth >= 0, in fs/ubifs/budget.c:554
[14570.351928] UBIFS warning (ubi0:0 pid 2578): ubifs_ro_mode [ubifs]: switched to read-only mode, error -22
[14570.353452] CPU: 2 PID: 2578 Comm: kworker/u8:2 Not tainted 5.15.0-rc5-00259-g1c6a7ce3cb2d-dirty #136
[14570.355243] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS ?-20190727_073836-buildvm-ppc64le-16.ppc.fedoraproject.org-3.fc31 04/01/2014
[14570.357187] Workqueue: writeback wb_workfn (flush-ubifs_0_0)
[14570.358024] Call Trace:
[14570.358388]  ? dump_stack_lvl+0x73/0x9f
[14570.358963]  ? dump_stack+0x13/0x1b
[14570.359477]  ? ubifs_ro_mode+0x54/0x60 [ubifs]
[14570.360132]  ? ubifs_assert_failed+0x4b/0x80 [ubifs]
[14570.360865]  ? ubifs_release_budget+0x468/0x5a0 [ubifs]
[14570.361632]  ? ubifs_release_dirty_inode_budget+0x53/0x80 [ubifs]
[14570.362522]  ? ubifs_write_inode+0x121/0x1f0 [ubifs]
[14570.363247]  ? __writeback_single_inode+0x43c/0x570
[14570.363953]  ? writeback_sb_inodes+0x259/0x740
[14570.364601]  ? __writeback_inodes_wb+0x88/0x120
[14570.365266]  ? wb_writeback+0x3cf/0x4d0
[14570.365843]  ? wb_workfn+0x283/0x7b0
[14570.366362]  ? send_call_function_single_ipi+0x9b/0x130
[14570.367148]  ? __smp_call_single_queue+0x48/0x60
[14570.367849]  ? ttwu_queue_wakelist+0xfa/0x1c0
[14570.368490]  ? process_one_work+0x291/0x650
[14570.369114]  ? worker_thread+0x2b7/0x700
[14570.369702]  ? rescuer_thread+0x580/0x580
[14570.370296]  ? kthread+0x18c/0x1e0
[14570.370792]  ? set_kthread_struct+0x70/0x70
[14570.371402]  ? ret_from_fork+0x1f/0x30
[14574.819182] wb finish?

Comment 4 Zhihao Cheng 2021-10-20 06:49:40 UTC

Created attachment 299253 [details]
delay.patch

Comment 5 Zhihao Cheng 2021-10-20 06:49:56 UTC

Created attachment 299255 [details]
test.sh

Comment 6 Zhihao Cheng 2021-10-20 06:50:06 UTC

Created attachment 299257 [details]
a.c