Re: [inotify_read] BUG: unable to handle kernel paging request at ffff8800172f8000

[Fengguang Wu <fengguang.wu@intel.com>]

On Tue, Nov 07, 2017 at 02:39:47PM +0100, Jan Kara wrote:
>On Tue 07-11-17 18:28:27, Wu Fengguang wrote:
>> FYI This bug trace also contains inotify_read().
>>
>> [    3.187637] debug: unmapping init [mem 0xffff880001760000-0xffff8800017fffff]
>> [    3.188582] debug: unmapping init [mem 0xffff880001b33000-0xffff880001bfffff]
>> [    3.215019] x86/mm: Checked W+X mappings: passed, no W+X pages found.
>> [    3.215815] rodata_test: all tests were successful
>> mountall: Event failed
>> [    3.365745] BUG: unable to handle kernel paging request at ffff8800172f8000
>> [    3.366661] IP: slob_free+0x1c4/0x276
>> [    3.367108] PGD 38c6067 P4D 38c6067 PUD 38c7067 PMD 1e747067 PTE 80000000172f8060
>> [    3.367996] Oops: 0000 [#1] DEBUG_PAGEALLOC
>> [    3.368505] Modules linked in:
>> [    3.368876] CPU: 0 PID: 1 Comm: init Not tainted 4.14.0-rc8 #136
>> [    3.369585] task: ffff8800002ec000 task.stack: ffffc90000008000
>> [    3.370286] RIP: 0010:slob_free+0x1c4/0x276
>> [    3.370781] RSP: 0018:ffffc9000000bd60 EFLAGS: 00010046
>> [    3.371396] RAX: ffff8800172f7ffe RBX: ffff8800172f7fc0 RCX: 0000000000001420
>> [    3.372230] RDX: ffff8800172f7000 RSI: ffffffff81e35608 RDI: ffff8800172f74f8
>> [    3.373500] RBP: ffff8800172f7ffe R08: 0000000000000001 R09: 0000000000000001
>> [    3.374781] R10: ffffc9000000bcb8 R11: 00000000ed37afc6 R12: ffff8800172f74f8
>> [    3.375848] R13: 000000000000001f R14: 000000000000001f R15: 000000000000001f
>> [    3.376699] FS:  00007fcb05cb1700(0000) GS:ffffffff81c2e000(0000) knlGS:0000000000000000
>> [    3.377649] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>> [    3.378334] CR2: ffff8800172f8000 CR3: 000000001727a000 CR4: 00000000000006b0
>> [    3.379167] Call Trace:
>> [    3.379481]  inotify_read+0x1d2/0x29c
>> [    3.379928]  ? prepare_to_wait_exclusive+0x64/0x64
>> [    3.380495]  ? SYSC_inotify_init1+0x195/0x195
>> [    3.381134]  __vfs_read+0x45/0xef
>> [    3.381673]  ? __do_page_fault+0x449/0x5af
>> [    3.382328]  ? lock_release+0x26c/0x2cd
>> [    3.382935]  vfs_read+0xba/0x100
>> [    3.383457]  SyS_read+0x5b/0xa1
>> [    3.383959]  entry_SYSCALL_64_fastpath+0x1f/0xbd
>> [    3.384685] RIP: 0033:0x7fcb05222d10
>> [    3.385247] RSP: 002b:00007fff14b56018 EFLAGS: 00000246 ORIG_RAX: 0000000000000000
>> [    3.386427] RAX: ffffffffffffffda RBX: 0000000000000046 RCX: 00007fcb05222d10
>> [    3.387532] RDX: 0000000000002000 RSI: 000055e4667a3620 RDI: 0000000000000005
>> [    3.388633] RBP: 0000000000002041 R08: 0000000000000000 R09: 0000000001000000
>> [    3.389736] R10: 0000000000000000 R11: 0000000000000246 R12: 00007fcb05005778
>> [    3.390838] R13: 0000000000002030 R14: 000055e4667a35e0 R15: 000000000001b9e1
>> [    3.391947] Code: 89 ec e8 d1 f5 ff ff 48 39 c3 48 89 c5 77 ed 4c 89 e7 e8 c1 f5 ff ff a9 ff 0f 00 00 74 31 49 0f bf c5 48 8d 04 43 48 39 e8 75 24 <8b> 45 00 41 be 01 00 00 00 48 89 ef 66 85 c0 44 0f 4f f0 45 01
>> [    3.394915] RIP: slob_free+0x1c4/0x276 RSP: ffffc9000000bd60
>> [    3.395797] CR2: ffff8800172f8000
>> [    3.396328] ---[ end trace 66f2347dc7fa73e0 ]---
>> [    3.397046] Kernel panic - not syncing: Fatal exception
>>
>> Attached the full dmesg and kconfig.
>
>Ok, I assume this is still valid even though previous KASAN report need not
>be?

Yeah it's real panic.

>I'm not sure if this could be inotify related though... Possibly if
>double-free could trigger this in SLOB but then we should see issues also
>with SLAB or SLUB.

The same kernel also triggered this bug trace:


See 'systemctl status systemd-journald.service' for details.
[  186.238181] BUG: unable to handle kernel paging request at ffff880210af6000
[  186.257107] IP: slob_free+0x1c4/0x276
[  186.266992] PGD 38c6067 P4D 38c6067 PUD 38c9067 PMD 23f077067 PTE 8000000210af6060
[  186.287018] Oops: 0000 [#1] DEBUG_PAGEALLOC
[  186.298199] Modules linked in:
[  186.306655] CPU: 0 PID: 1 Comm: systemd Not tainted 4.14.0-rc8 #136
[  186.323383] task: ffff88023da70000 task.stack: ffffc90000008000
[  186.339101] RIP: 0010:slob_free+0x1c4/0x276
[  186.350307] RSP: 0018:ffffc9000000bd70 EFLAGS: 00010046
[  186.364370] RAX: ffff880210af5ffe RBX: ffff880210af5ff0 RCX: 0000000000001420
[  186.383035] RDX: ffff880210af5000 RSI: ffffffff81e35608 RDI: ffff880210af5f08
[  186.401667] RBP: ffff880210af5ffe R08: 0000000000000001 R09: 0000000000000001
[  186.420365] R10: ffffc9000000bcc8 R11: 000000002a1a0f28 R12: ffff880210af5f08
[  186.437647] R13: 0000000000000007 R14: 0000000000000007 R15: 0000000000000007
[  186.455399] FS:  00007fc9d537d900(0000) GS:ffffffff81c2e000(0000) knlGS:0000000000000000
[  186.476759] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  186.491952] CR2: ffff880210af6000 CR3: 000000021095d000 CR4: 00000000000006b0
[  186.510588] Call Trace:
[  186.517908]  kernfs_put+0xd4/0x1d6
[  186.527178]  __kernfs_remove+0x2d1/0x306
[  186.537741]  kernfs_remove+0x24/0x31
[  186.547499]  cgroup_destroy_locked+0x186/0x20f
[  186.559461]  cgroup_rmdir+0x36/0x16e
[  186.569184]  kernfs_iop_rmdir+0x67/0x89
[  186.579552]  vfs_rmdir+0x8c/0xee
[  186.588423]  do_rmdir+0x10f/0x19d
[  186.597529]  entry_SYSCALL_64_fastpath+0x1f/0xbd
[  186.611108] RIP: 0033:0x7fc9d395a857
[  186.620703] RSP: 002b:00007ffccf7933c8 EFLAGS: 00000202 ORIG_RAX: 0000000000000054
[  186.640597] RAX: ffffffffffffffda RBX: 0000000000000046 RCX: 00007fc9d395a857
[  186.659306] RDX: 00007fc9d3c1ab78 RSI: 0000000000000000 RDI: 00005632485bb960
[  186.678134] RBP: fffffffffffffe10 R08: 0000000000000100 R09: 000056324862c380
[  186.697215] R10: 0000000000000100 R11: 0000000000000202 R12: 0000000000000000
[  186.715919] R13: 00000000ffffffff R14: 00007ffccf7932a0 R15: 0000000000000000
[  186.734777] Code: 89 ec e8 d1 f5 ff ff 48 39 c3 48 89 c5 77 ed 4c 89 e7 e8 c1 f5 ff ff a9 ff 0f 00 0074 31 49 0f bf c5 48 8d 04 43 48 39 e8 75 24 <8b> 45 00 41 be 01 00 00 00 48 89 ef 66 85 c0 44 0f 4f f0 45 01
[  186.785065] RIP: slob_free+0x1c4/0x276 RSP: ffffc9000000bd70
[  186.800042] CR2: ffff880210af6000
[  186.808986] ---[ end trace 1a1c6afc0e9b5ec9 ]---
[  186.821358] Kernel panic - not syncing: Fatal exception
[  186.835329] Kernel Offset: disabled

And both of them are not easily reproducible.
In fact the 2 traces are each the only occurrence.

I've queued much more test boots for it, with gcc-6 and DEBUG_INFO.
Hope we can get something tomorrow.

Thanks,
Fengguang