Problem with 4.0.0 FS

[bugmenot2]

I'm getting this trace when booting from reiser4 partition (debugging enabled in kernel config):

[    8.456519] reiser4: sda7: found disk format 4.0.0.
[    8.456543] z_hash_table: 8192 buckets
[    8.456555] z_hash_table: 8192 buckets
[    8.456583] j_hash_table: 16384 buckets
[    8.456609] loading reiser4 bitmap...
[    9.612216] ...done (289 jiffies)
[    9.647687] reiser4: sda7: using Hybrid Transaction Model.
[   12.012987] CPU: 1 PID: 345 Comm: sh Not tainted 4.10.0-13-generic #15
[   12.013000] task: ffff9a99725c3fc0 task.stack: ffffb2d00131c000
[   12.013010] RIP: 0010:kgdb_breakpoint+0x14/0x20
[   12.013014] RSP: 0018:ffffb2d00131fb18 EFLAGS: 00000202
[   12.013019] RAX: 000000000000000f RBX: ffff9a997a36b590 RCX: 0000000000000018
[   12.013025] RDX: 0000000000000000 RSI: 0000000000000801 RDI: ffff9a997267a828
[   12.013033] RBP: ffffb2d00131fb18 R08: 0000000000000002 R09: 0000000058dacba8
[   12.013038] R10: 0000000000000000 R11: 0000000000000040 R12: ffff9a9972f94600
[   12.013043] R13: ffff9a99725c3fc0 R14: ffff9a997267a000 R15: 0000000000001000
[   12.013049] FS:  00007fc4ce2ea700(0000) GS:ffff9a997fc80000(0000) knlGS:0000000000000000
[   12.013055] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   12.013060] CR2: 000055db9c784078 CR3: 00000001392e6000 CR4: 00000000000006e0
[   12.013065] Call Trace:
[   12.013073]  reiser4_debugtrap+0xe/0x10
[   12.013079]  reiser4_dirty_inode+0x123/0x1c0
[   12.013086]  __mark_inode_dirty+0x176/0x370
[   12.013092]  generic_update_time+0x79/0xd0
[   12.013096]  ? current_time+0x36/0x70
[   12.013101]  touch_atime+0xa9/0xd0
[   12.013107]  generic_file_read_iter+0x677/0x900
[   12.013112]  ? terminate_walk+0x8e/0xf0
[   12.013118]  new_sync_read+0xd0/0x120
[   12.013124]  read_cryptcompress+0x9c/0x190
[   12.013130]  reiser4_read_dispatch+0x99/0x270
[   12.013134]  __vfs_read+0x18/0x40
[   12.013139]  vfs_read+0x93/0x130
[   12.013144]  prepare_binprm+0x10c/0x1f0
[   12.013149]  do_execveat_common.isra.39+0x49d/0x780
[   12.013154]  SyS_execve+0x3a/0x50
[   12.013160]  do_syscall_64+0x5b/0xc0
[   12.013166]  entry_SYSCALL64_slow_path+0x25/0x25
[   12.013172] RIP: 0033:0x7fc4cddebbc7
[   12.013176] RSP: 002b:00007ffffd60cc48 EFLAGS: 00000246 ORIG_RAX: 000000000000003b
[   12.013182] RAX: ffffffffffffffda RBX: 0000561502dde5c8 RCX: 00007fc4cddebbc7
[   12.013187] RDX: 0000561502dde560 RSI: 0000561502dde548 RDI: 0000561502dde5c8
[   12.013193] RBP: 0000561502dde548 R08: 000000000000000e R09: 0000000000000001
[   12.013198] R10: 0000000000000001 R11: 0000000000000246 R12: 0000561502dde560
[   12.013203] R13: 0000000000000005 R14: 0400002000000001 R15: 0000000000000001
[   12.013209] Code: 00 00 0f 1f 44 00 00 66 66 66 66 90 55 31 c0 48 89 e5 5d c3 0f 1f 00 66 66 66 66 90 55 48 89 e5 f0 ff 05 18 8d 18 01 0f ae f8 cc <0f> ae f8 f0 ff 0d 0a 8d 18 01 5d c3 66 66 66 66 90 55 48 89 e5 
[   12.013243] RIP: kgdb_breakpoint+0x14/0x20 RSP: ffffb2d00131fb18
[   12.013249] ---[ end trace 0caebd4da5bd4c14 ]---

fsck reports that the filesystem is clean. What can this be? Tell me if additional information is needed.

[edward6]

Unfortunately debugging mode works incorrectly in reiser4. Why have you enabled it?

[bugmenot2]

Before this I was getting kernel panic on kernel 4.8 ("kernel BUG at fs/reiser4/block_alloc.c: 152" if I remember correctly), so I decided to enable debugging when building 4.10. Ok, I'll try with debugging disabled then.

[edward6]

Is it reproducible? Anyway, debugging mode won't help here.

[bugmenot2]

Yes, I keep getting block_alloc.c:152 assert on 4.8: https://lut.im/8AqQyzPkpd/a6x4szCgIyXrfEPt.JPG https://lut.im/QhPkHytXRm/Z214fmeyedbXOCs1.JPG I can upload FS metadata if it can help.

[edward6]

Interesting. I'll examine that path carefully.. The second stack-trace is a side-effect, as I understand? Metadata is not needed. Thanks!

[Yurisu1]

(sorry, have to use a different account)

The second stack-trace is a side-effect, as I understand?

Yes, it appears later on.

4.8: After I removed ureadahead package, the block_alloc assert is gone...

4.10: I've noticed the following warnings (note that I haven't yet rebuilt the kernel without debugging, might be related to that):

reiser4[baloo_file(2053)]: release_unix_file (fs/reiser4/plugin/file/file.c:2358)[vs-44]
WARNING: out of memory?
reiser4[wicd(1172)]: release_unix_file (fs/reiser4/plugin/file/file.c:2358)[vs-44]
WARNING: out of memory?

[edward6]

4.8: It's a pity that it has gone: I wanted you to reproduce it with some my debugging extension. Someone steals space reservation (one block per file for stat-data update) which is needed for marking the file accessible after read is done.

4.10: Please, rebuild the kernel without debugging option, and let me know, if something goes wrong.

[Yurisu1]

I haven't encountered any problems after disabling debugging, so feel free to close this ticket.

[edward6]

4.8: Most probably that at some point of the read path a memory allocation happens against memory pressure in the system. The triggered writeback fails with ENOSPC, and our reservation gets released in the error path. Then the read path resumes without any reservation - it leads to kernel BUG at fs/reiser4/block_alloc.c: 152. I fixed reiser4-for-4.9.3 (9eca07b), so that writeback doesn't fail now - this is why you don't have such problems in 4.10. But again - all this is just an assumption. Anyway, the code needs more love...