Hello,
FYI this happens in mainline kernel 4.17.0-rc1.
It at least dates back to v4.16 .
It occurs in 2 out of 6 boots.
[ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 128869
[ 0.000000] Kernel command line: ip=::::vm-intel12-yocto-x86_64-2::dhcp root=/dev/ram0 user=lkp job=/lkp/scheduled/vm-intel12-yocto-x86_64-2/boot-1-yocto-minimal-x86_64-2016-04-22.cgz-60cc43fc888428bb2f18f08997432d426a243338-20180418-63270-jrkd3n-1.yaml ARCH=x86_64 kconfig=x86_64-randconfig-s0-04090505 branch=linux-devel/devel-spot-201804082042 commit=60cc43fc888428bb2f18f08997432d426a243338 BOOT_IMAGE=/pkg/linux/x86_64-randconfig-s0-04090505/gcc-6/60cc43fc888428bb2f18f08997432d426a243338/vmlinuz-4.17.0-rc1 max_uptime=600 RESULT_ROOT=/result/boot/1/vm-intel12-yocto-x86_64/yocto-minimal-x86_64-2016-04-22.cgz/x86_64-randconfig-s0-04090505/gcc-6/60cc43fc888428bb2f18f08997432d426a243338/2 LKP_SERVER=inn debug apic=debug sysrq_always_enabled rcupdate.rcu_cpu_stall_timeout=100 net.ifnames=0 printk.devkmsg=on panic=-1 softlockup_panic=1 nmi_watchdog=panic oops=panic load_ramdisk=2 prompt_ramdisk=0 drbd.minor_count=8 systemd.log_level=err ignore_loglevel console=tty0 earlyprintk=ttyS0,115200 co
[ 0.000000] sysrq: sysrq always enabled.
[ 0.000000] Dentry cache hash table entries: 65536 (order: 7, 524288 bytes)
[ 0.000000] Inode-cache hash table entries: 32768 (order: 6, 262144 bytes)
[ 0.000000] BUG: unable to handle kernel NULL pointer dereference at 0000000000000000
[ 0.000000] PGD 0 P4D 0
[ 0.000000] Oops: 0000 [#1] PREEMPT DEBUG_PAGEALLOC
[ 0.000000] CPU: 0 PID: 0 Comm: swapper Not tainted 4.17.0-rc1 #1
[ 0.000000] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 0.000000] RIP: 0010:per_cpu_ptr_to_phys+0xf1/0x14e:
__section_mem_map_addr at include/linux/mmzone.h:1188
(inlined by) per_cpu_ptr_to_phys at mm/percpu.c:1849
[ 0.000000] RSP: 0000:ffffffff87803ea0 EFLAGS: 00010046
[ 0.000000] RAX: ffff88001f00c240 RBX: ffffffff87809000 RCX: 0000000000000000
[ 0.000000] RDX: ffffffffffffffff RSI: ffff88001ffd2000 RDI: 0000000000000000
[ 0.000000] RBP: ffffffff87803ea8 R08: 0000000000000000 R09: ffff88001f8c4000
[ 0.000000] R10: 000000000000b080 R11: ffffffff8868746c R12: 8000000000000161
[ 0.000000] R13: ffffffff87a70940 R14: ffffffff87a772e0 R15: 0000000000000000
[ 0.000000] FS: 0000000000000000(0000) GS:ffffffff8783d000(0000) knlGS:0000000000000000
[ 0.000000] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 0.000000] CR2: 0000000000000000 CR3: 000000001c21a000 CR4: 00000000000006b0
[ 0.000000] Call Trace:
[ 0.000000] setup_cpu_entry_areas+0x35/0x15e:
setup_cpu_entry_area at arch/x86/mm/cpu_entry_area.c:104
(inlined by) setup_cpu_entry_areas at arch/x86/mm/cpu_entry_area.c:177
[ 0.000000] trap_init+0x9/0x6e:
trap_init at arch/x86/kernel/traps.c:949
[ 0.000000] start_kernel+0x241/0x54b:
mm_init at init/main.c:519
(inlined by) start_kernel at init/main.c:589
[ 0.000000] x86_64_start_reservations+0x2a/0x2c:
x86_64_start_reservations at arch/x86/kernel/head64.c:446
[ 0.000000] x86_64_start_kernel+0x76/0x79:
x86_64_start_kernel at arch/x86/kernel/head64.c:427
[ 0.000000] secondary_startup_64+0xa5/0xb0:
secondary_startup_64 at arch/x86/kernel/head_64.S:242
[ 0.000000] Code: c1 e1 05 48 01 ca 48 8b 12 eb 23 48 8b 10 48 89 d1 48 c1 e9 34 48 8b 0c ce 48 85 c9 74 0d 48 c1 ea 28 81 e2 e0 0f 00 00 48 01 d1 <48> 8b 11 48 83 e2 f8 81 e3 ff 0f 00 00 48 29 d0 48 c1 f8 06 48
[ 0.000000] RIP: per_cpu_ptr_to_phys+0xf1/0x14e:
__section_mem_map_addr at include/linux/mmzone.h:1188
(inlined by) per_cpu_ptr_to_phys at mm/percpu.c:1849 RSP: ffffffff87803ea0
[ 0.000000] CR2: 0000000000000000
[ 0.000000] ---[ end trace 142a0423c71f6258 ]---
[ 0.000000] Kernel panic - not syncing: Fatal exception
Attached the full dmesg, kconfig and reproduce scripts.
Thanks,
Fengguang
Hello,
FYI here is a slightly different boot error in mainline kernel 4.17.0-rc1.
It also dates back to v4.16 .
It occurs in 4 out of 4 boots.
[ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 128873
[ 0.000000] Kernel command line: root=/dev/ram0 hung_task_panic=1 debug apic=debug sysrq_always_enabled rcupdate.rcu_cpu_stall_timeout=100 net.ifnames=0 printk.devkmsg=on panic=-1 softlockup_panic=1 nmi_watchdog=panic oops=panic load_ramdisk=2 prompt_ramdisk=0 drbd.minor_count=8 systemd.log_level=err ignore_loglevel console=tty0 earlyprintk=ttyS0,115200 console=ttyS0,115200 vga=normal rw link=/kbuild-tests/run-queue/kvm/x86_64-randconfig-a0-04172313/linux-devel:devel-hourly-2018041714:60cc43fc888428bb2f18f08997432d426a243338/.vmlinuz-60cc43fc888428bb2f18f08997432d426a243338-20180418000325-19:yocto-lkp-nhm-dp2-4 branch=linux-devel/devel-hourly-2018041714 BOOT_IMAGE=/pkg/linux/x86_64-randconfig-a0-04172313/gcc-7/60cc43fc888428bb2f18f08997432d426a243338/vmlinuz-4.17.0-rc1 drbd.minor_count=8 rcuperf.shutdown=0
[ 0.000000] sysrq: sysrq always enabled.
[ 0.000000] Dentry cache hash table entries: 65536 (order: 7, 524288 bytes)
[ 0.000000] Inode-cache hash table entries: 32768 (order: 6, 262144 bytes)
PANIC: early exception 0x0d IP 10:ffffffffa892f15f error 0 cr2 0xffff88001fbff000
[ 0.000000] CPU: 0 PID: 0 Comm: swapper Tainted: G T 4.17.0-rc1 #238
[ 0.000000] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 0.000000] RIP: 0010:per_cpu_ptr_to_phys+0x16a/0x298:
__section_mem_map_addr at include/linux/mmzone.h:1188
(inlined by) per_cpu_ptr_to_phys at mm/percpu.c:1849
[ 0.000000] RSP: 0000:ffffffffab407e50 EFLAGS: 00010046 ORIG_RAX: 0000000000000000
[ 0.000000] RAX: dffffc0000000000 RBX: ffff88001f17c340 RCX: 000000000000000f
[ 0.000000] RDX: 0000000000000000 RSI: 0000000000000001 RDI: ffffffffacfbf580
[ 0.000000] RBP: ffffffffab40d000 R08: fffffbfff57c4eca R09: 0000000000000000
[ 0.000000] R10: ffff880015421000 R11: fffffbfff57c4ec9 R12: 0000000000000000
[ 0.000000] R13: ffff88001fb03ff8 R14: ffff88001fc051c0 R15: 0000000000000000
[ 0.000000] FS: 0000000000000000(0000) GS:ffffffffab4c5000(0000) knlGS:0000000000000000
[ 0.000000] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 0.000000] CR2: ffff88001fbff000 CR3: 000000001a06c000 CR4: 00000000000006b0
[ 0.000000] Call Trace:
[ 0.000000] setup_cpu_entry_areas+0x7b/0x27b:
setup_cpu_entry_area at arch/x86/mm/cpu_entry_area.c:104
(inlined by) setup_cpu_entry_areas at arch/x86/mm/cpu_entry_area.c:177
[ 0.000000] trap_init+0xb/0x13d:
trap_init at arch/x86/kernel/traps.c:949
[ 0.000000] start_kernel+0x2a5/0x91d:
mm_init at init/main.c:519
(inlined by) start_kernel at init/main.c:589
[ 0.000000] ? thread_stack_cache_init+0x6/0x6
[ 0.000000] ? memcpy_orig+0x16/0x110:
memcpy_orig at arch/x86/lib/memcpy_64.S:77
[ 0.000000] ? x86_family+0x5/0x1d:
x86_family at arch/x86/lib/cpu.c:8
[ 0.000000] ? load_ucode_bsp+0x42/0x13e:
load_ucode_bsp at arch/x86/kernel/cpu/microcode/core.c:183
[ 0.000000] secondary_startup_64+0xa5/0xb0:
secondary_startup_64 at arch/x86/kernel/head_64.S:242
[ 0.000000] Code: 78 06 00 49 8b 45 00 48 85 c0 74 a5 49 c1 ec 28 41 81 e4 e0 0f 00 00 49 01 c4 4c 89 e2 48 b8 00 00 00 00 00 fc ff df 48 c1 ea 03 <80> 3c 02 00 74 08 4c 89 e7 e8 63 78 06 00 49 8b 04 24 81 e5 ff
BUG: kernel hang in boot stage
Attached the full dmesg, kconfig and reproduce scripts.
Thanks,
Fengguang
Hi,
On Wed, Apr 18, 2018 at 09:55:53PM +0800, Fengguang Wu wrote:
>
> Hello,
>
> FYI here is a slightly different boot error in mainline kernel 4.17.0-rc1.
> It also dates back to v4.16 .
>
> It occurs in 4 out of 4 boots.
>
> [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 128873
> [ 0.000000] Kernel command line: root=/dev/ram0 hung_task_panic=1 debug apic=debug sysrq_always_enabled rcupdate.rcu_cpu_stall_timeout=100 net.ifnames=0 printk.devkmsg=on panic=-1 softlockup_panic=1 nmi_watchdog=panic oops=panic load_ramdisk=2 prompt_ramdisk=0 drbd.minor_count=8 systemd.log_level=err ignore_loglevel console=tty0 earlyprintk=ttyS0,115200 console=ttyS0,115200 vga=normal rw link=/kbuild-tests/run-queue/kvm/x86_64-randconfig-a0-04172313/linux-devel:devel-hourly-2018041714:60cc43fc888428bb2f18f08997432d426a243338/.vmlinuz-60cc43fc888428bb2f18f08997432d426a243338-20180418000325-19:yocto-lkp-nhm-dp2-4 branch=linux-devel/devel-hourly-2018041714 BOOT_IMAGE=/pkg/linux/x86_64-randconfig-a0-04172313/gcc-7/60cc43fc888428bb2f18f08997432d426a243338/vmlinuz-4.17.0-rc1 drbd.minor_count=8 rcuperf.shutdown=0
> [ 0.000000] sysrq: sysrq always enabled.
> [ 0.000000] Dentry cache hash table entries: 65536 (order: 7, 524288 bytes)
> [ 0.000000] Inode-cache hash table entries: 32768 (order: 6, 262144 bytes)
> PANIC: early exception 0x0d IP 10:ffffffffa892f15f error 0 cr2 0xffff88001fbff000
> [ 0.000000] CPU: 0 PID: 0 Comm: swapper Tainted: G T 4.17.0-rc1 #238
> [ 0.000000] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
> [ 0.000000] RIP: 0010:per_cpu_ptr_to_phys+0x16a/0x298:
> __section_mem_map_addr at include/linux/mmzone.h:1188
> (inlined by) per_cpu_ptr_to_phys at mm/percpu.c:1849
> [ 0.000000] RSP: 0000:ffffffffab407e50 EFLAGS: 00010046 ORIG_RAX: 0000000000000000
> [ 0.000000] RAX: dffffc0000000000 RBX: ffff88001f17c340 RCX: 000000000000000f
> [ 0.000000] RDX: 0000000000000000 RSI: 0000000000000001 RDI: ffffffffacfbf580
> [ 0.000000] RBP: ffffffffab40d000 R08: fffffbfff57c4eca R09: 0000000000000000
> [ 0.000000] R10: ffff880015421000 R11: fffffbfff57c4ec9 R12: 0000000000000000
> [ 0.000000] R13: ffff88001fb03ff8 R14: ffff88001fc051c0 R15: 0000000000000000
> [ 0.000000] FS: 0000000000000000(0000) GS:ffffffffab4c5000(0000) knlGS:0000000000000000
> [ 0.000000] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 0.000000] CR2: ffff88001fbff000 CR3: 000000001a06c000 CR4: 00000000000006b0
> [ 0.000000] Call Trace:
> [ 0.000000] setup_cpu_entry_areas+0x7b/0x27b:
> setup_cpu_entry_area at arch/x86/mm/cpu_entry_area.c:104
> (inlined by) setup_cpu_entry_areas at arch/x86/mm/cpu_entry_area.c:177
> [ 0.000000] trap_init+0xb/0x13d:
> trap_init at arch/x86/kernel/traps.c:949
> [ 0.000000] start_kernel+0x2a5/0x91d:
> mm_init at init/main.c:519
> (inlined by) start_kernel at init/main.c:589
> [ 0.000000] ? thread_stack_cache_init+0x6/0x6
> [ 0.000000] ? memcpy_orig+0x16/0x110:
> memcpy_orig at arch/x86/lib/memcpy_64.S:77
> [ 0.000000] ? x86_family+0x5/0x1d:
> x86_family at arch/x86/lib/cpu.c:8
> [ 0.000000] ? load_ucode_bsp+0x42/0x13e:
> load_ucode_bsp at arch/x86/kernel/cpu/microcode/core.c:183
> [ 0.000000] secondary_startup_64+0xa5/0xb0:
> secondary_startup_64 at arch/x86/kernel/head_64.S:242
> [ 0.000000] Code: 78 06 00 49 8b 45 00 48 85 c0 74 a5 49 c1 ec 28 41 81 e4 e0 0f 00 00 49 01 c4 4c 89 e2 48 b8 00 00 00 00 00 fc ff df 48 c1 ea 03 <80> 3c 02 00 74 08 4c 89 e7 e8 63 78 06 00 49 8b 04 24 81 e5 ff
> BUG: kernel hang in boot stage
>
I spent some time bisecting this one and it seemse to be an intermittent
issue starting with this commit for me:
c9e97a1997, mm: initialize pages on demand during boot. The prior
commit, 3a2d7fa8a3, did not run into this issue after 10+ boots.
I don't have that much time right now, nor the expertise with this code.
Pavel could you take a look at this?
Thanks,
Dennis
On Wed, Apr 18, 2018 at 06:38:25PM -0500, Dennis Zhou wrote:
>Hi,
>
>On Wed, Apr 18, 2018 at 09:55:53PM +0800, Fengguang Wu wrote:
>>
>> Hello,
>>
>> FYI here is a slightly different boot error in mainline kernel 4.17.0-rc1.
>> It also dates back to v4.16 .
>>
>> It occurs in 4 out of 4 boots.
>>
>> [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 128873
>> [ 0.000000] Kernel command line: root=/dev/ram0 hung_task_panic=1 debug apic=debug sysrq_always_enabled rcupdate.rcu_cpu_stall_timeout=100 net.ifnames=0 printk.devkmsg=on panic=-1 softlockup_panic=1 nmi_watchdog=panic oops=panic load_ramdisk=2 prompt_ramdisk=0 drbd.minor_count=8 systemd.log_level=err ignore_loglevel console=tty0 earlyprintk=ttyS0,115200 console=ttyS0,115200 vga=normal rw link=/kbuild-tests/run-queue/kvm/x86_64-randconfig-a0-04172313/linux-devel:devel-hourly-2018041714:60cc43fc888428bb2f18f08997432d426a243338/.vmlinuz-60cc43fc888428bb2f18f08997432d426a243338-20180418000325-19:yocto-lkp-nhm-dp2-4 branch=linux-devel/devel-hourly-2018041714 BOOT_IMAGE=/pkg/linux/x86_64-randconfig-a0-04172313/gcc-7/60cc43fc888428bb2f18f08997432d426a243338/vmlinuz-4.17.0-rc1 drbd.minor_count=8 rcuperf.shutdown=0
>> [ 0.000000] sysrq: sysrq always enabled.
>> [ 0.000000] Dentry cache hash table entries: 65536 (order: 7, 524288 bytes)
>> [ 0.000000] Inode-cache hash table entries: 32768 (order: 6, 262144 bytes)
>> PANIC: early exception 0x0d IP 10:ffffffffa892f15f error 0 cr2 0xffff88001fbff000
>> [ 0.000000] CPU: 0 PID: 0 Comm: swapper Tainted: G T 4.17.0-rc1 #238
>> [ 0.000000] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
>> [ 0.000000] RIP: 0010:per_cpu_ptr_to_phys+0x16a/0x298:
>> __section_mem_map_addr at include/linux/mmzone.h:1188
>> (inlined by) per_cpu_ptr_to_phys at mm/percpu.c:1849
>> [ 0.000000] RSP: 0000:ffffffffab407e50 EFLAGS: 00010046 ORIG_RAX: 0000000000000000
>> [ 0.000000] RAX: dffffc0000000000 RBX: ffff88001f17c340 RCX: 000000000000000f
>> [ 0.000000] RDX: 0000000000000000 RSI: 0000000000000001 RDI: ffffffffacfbf580
>> [ 0.000000] RBP: ffffffffab40d000 R08: fffffbfff57c4eca R09: 0000000000000000
>> [ 0.000000] R10: ffff880015421000 R11: fffffbfff57c4ec9 R12: 0000000000000000
>> [ 0.000000] R13: ffff88001fb03ff8 R14: ffff88001fc051c0 R15: 0000000000000000
>> [ 0.000000] FS: 0000000000000000(0000) GS:ffffffffab4c5000(0000) knlGS:0000000000000000
>> [ 0.000000] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>> [ 0.000000] CR2: ffff88001fbff000 CR3: 000000001a06c000 CR4: 00000000000006b0
>> [ 0.000000] Call Trace:
>> [ 0.000000] setup_cpu_entry_areas+0x7b/0x27b:
>> setup_cpu_entry_area at arch/x86/mm/cpu_entry_area.c:104
>> (inlined by) setup_cpu_entry_areas at arch/x86/mm/cpu_entry_area.c:177
>> [ 0.000000] trap_init+0xb/0x13d:
>> trap_init at arch/x86/kernel/traps.c:949
>> [ 0.000000] start_kernel+0x2a5/0x91d:
>> mm_init at init/main.c:519
>> (inlined by) start_kernel at init/main.c:589
>> [ 0.000000] ? thread_stack_cache_init+0x6/0x6
>> [ 0.000000] ? memcpy_orig+0x16/0x110:
>> memcpy_orig at arch/x86/lib/memcpy_64.S:77
>> [ 0.000000] ? x86_family+0x5/0x1d:
>> x86_family at arch/x86/lib/cpu.c:8
>> [ 0.000000] ? load_ucode_bsp+0x42/0x13e:
>> load_ucode_bsp at arch/x86/kernel/cpu/microcode/core.c:183
>> [ 0.000000] secondary_startup_64+0xa5/0xb0:
>> secondary_startup_64 at arch/x86/kernel/head_64.S:242
>> [ 0.000000] Code: 78 06 00 49 8b 45 00 48 85 c0 74 a5 49 c1 ec 28 41 81 e4 e0 0f 00 00 49 01 c4 4c 89 e2 48 b8 00 00 00 00 00 fc ff df 48 c1 ea 03 <80> 3c 02 00 74 08 4c 89 e7 e8 63 78 06 00 49 8b 04 24 81 e5 ff
>> BUG: kernel hang in boot stage
>>
>
>I spent some time bisecting this one and it seemse to be an intermittent
>issue starting with this commit for me:
>c9e97a1997, mm: initialize pages on demand during boot. The prior
>commit, 3a2d7fa8a3, did not run into this issue after 10+ boots.
Dennis, thanks for bisecting it down!
Pavel, here is an early boot error bisected to c9e97a1997 ("mm:
initialize pages on demand during boot"). Reproduce script attached.
3a2d7fa8a3 mm: disable interrupts while initializing deferred pages
c9e97a1997 mm: initialize pages on demand during boot
48023102b7 Merge branch 'overlayfs-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/mszeredi/vfs
238879f45b Add linux-next specific files for 20180413
+-------------------------------------------------------+------------+------------+------------+---------------+
| | 3a2d7fa8a3 | c9e97a1997 | 48023102b7 | next-20180413 |
+-------------------------------------------------------+------------+------------+------------+---------------+
| boot_successes | 51 | 9 | 10 | 3 |
| boot_failures | 1 | 12 | 11 | 9 |
| Mem-Info | 1 | | | |
| BUG:kernel_reboot-without-warning_in_early-boot_stage | 0 | 12 | 11 | 9 |
+-------------------------------------------------------+------------+------------+------------+---------------+
early console in setup code
BUG: kernel reboot-without-warning in early-boot stage, last printk: early console in setup code
Linux version 4.16.0-07313-gc9e97a1 #2
Command line: root=/dev/ram0 hung_task_panic=1 debug apic=debug sysrq_always_enabled rcupdate.rcu_cpu_stall_timeout=100 net.ifnames=0 printk.devkmsg=on panic=-1 softlockup_panic=1 nmi_watchdog=panic oops=panic load_ramdisk=2 prompt_ramdisk=0 drbd.minor_count=8 systemd.log_level=err ignore_loglevel console=tty0 earlyprintk=ttyS0,115200 console=ttyS0,115200 vga=normal rw link=/kbuild-tests/run-queue/yocto-ivb41/x86_64-randconfig-r0-04141244/linux-devel:devel-spot-201804141202:c9e97a1997fbf3a1d18d4065c2ca381f0704d7e5:bisect-linux-20/.vmlinuz-c9e97a1997fbf3a1d18d4065c2ca381f0704d7e5-20180414175501-14:yocto-ivb41-130 branch=linux-devel/devel-spot-201804141202 BOOT_IMAGE=/pkg/linux/x86_64-randconfig-r0-04141244/gcc-6/c9e97a1997fbf3a1d18d4065c2ca381f0704d7e5/vmlinuz-4.16.0-07313-gc9e97a1 drbd.minor_count=8 rcuperf.shutdown=0
# HH:MM RESULT GOOD BAD GOOD_BUT_DIRTY DIRTY_NOT_BAD
git bisect start f6604fa7518c1cda05b95590a7965fd7ab502d16 0adb32858b0bddf4ada5f364a84ed60b196dbcda --
git bisect bad 036ea404fd8d46c7b2b6290f820212df3be70553 # 13:45 B 1 5 0 0 Merge 'linux-review/Daniel-Mack/wcn36xx-pass-correct-BSS-index-when-deleting-BSS-keys/20180413-220635' into devel-spot-201804141202
git bisect bad 0f85c8e00aecc556114d75a182a26bfe1ccadef0 # 14:00 B 0 8 22 0 Merge 'nfsd/nfsd-next' into devel-spot-201804141202
git bisect bad 7342865df7cb1e1f2120493de329665744fa8946 # 14:11 B 0 10 24 0 Merge 'linux-review/Hern-n-Gonzalez/Move-ad7746-driver-out-of-staging/20180414-090557' into devel-spot-201804141202
git bisect good 895a25a4c71353fa48cf389d8003f5b30ecc30cc # 14:22 G 17 0 1 1 Merge 'thermal/thermal-soc-v2' into devel-spot-201804141202
git bisect bad d5111e404f5518298cf50ba910ac3a3362572d0d # 14:35 B 2 7 1 3 Merge 'linux-review/Hans-de-Goede/ACPI-LPSS-Only-call-pwm_add_table-for-Bay-Trail-PWM-if-PMIC-HRV-is-2/20180414-092906' into devel-spot-201804141202
git bisect bad 1fb7bf52382687618e345cc587abdf301c3d485a # 14:59 B 0 3 17 0 Merge 'linux-review/Christian-Brauner/statfs-handle-mount-propagation/20180414-104639' into devel-spot-201804141202
git bisect good f9ca6a561d40115696a54f16085c4edb17effc74 # 15:19 G 17 0 0 0 Merge git://git.kernel.org/pub/scm/linux/kernel/git/davem/net
git bisect good b240b419db5d624ce7a5a397d6f62a1a686009ec # 15:30 G 17 0 2 2 Merge tag 'armsoc-dt' of git://git.kernel.org/pub/scm/linux/kernel/git/arm/arm-soc
git bisect bad 49a695ba723224875df50e327bd7b0b65dd9a56b # 15:41 B 0 3 17 0 Merge tag 'powerpc-4.17-1' of git://git.kernel.org/pub/scm/linux/kernel/git/powerpc/linux
git bisect bad 28da7be5ebc096ada5e6bc526c623bdd8c47800a # 15:50 B 0 6 20 0 Merge tag 'mailbox-v4.17' of git://git.linaro.org/landing-teams/working/fujitsu/integration
git bisect good 38c23685b273cfb4ccf31a199feccce3bdcb5d83 # 16:03 G 17 0 1 1 Merge tag 'armsoc-drivers' of git://git.kernel.org/pub/scm/linux/kernel/git/arm/arm-soc
git bisect good 3fd14cdcc05a682b03743683ce3a726898b20555 # 16:18 G 17 0 3 3 Merge tag 'mtd/for-4.17' of git://git.infradead.org/linux-mtd
git bisect bad e92bb4dd9673945179b1fc738c9817dd91bfb629 # 16:30 B 1 10 0 3 mm: fix races between address_space dereference and free in page_evicatable
git bisect good d5f866550df237861f9d59ca0206434b0dea9701 # 16:46 G 17 0 2 2 slab: make size_index[] array u8
git bisect good 613a5eb5677923fdaecfa582738c7bcf80abe186 # 16:56 G 17 0 1 1 slab, slub: remove size disparity on debug kernel
git bisect bad ba325585230ed17079fd5b4065c359ebba117bbe # 17:11 B 0 9 23 0 mm/memory_hotplug: enforce block size aligned range check
git bisect good 310253514bbf179c5f82e20a7a4bbf07abc7f5ad # 17:22 G 17 0 1 1 mm/migrate: rename migration reason MR_CMA to MR_CONTIG_RANGE
git bisect good 3a2d7fa8a3d5ae740bd0c21d933acc6220857ed0 # 17:35 G 17 0 3 3 mm: disable interrupts while initializing deferred pages
git bisect bad f0849ac0b8e072073ec5fcc7fadd05a77434364e # 17:44 B 0 9 23 0 mm: thp: fix potential clearing to referenced flag in page_idle_clear_pte_refs_one()
git bisect bad c9e97a1997fbf3a1d18d4065c2ca381f0704d7e5 # 17:55 B 0 1 15 0 mm: initialize pages on demand during boot
# first bad commit: [c9e97a1997fbf3a1d18d4065c2ca381f0704d7e5] mm: initialize pages on demand during boot
git bisect good 3a2d7fa8a3d5ae740bd0c21d933acc6220857ed0 # 18:00 G 51 0 2 5 mm: disable interrupts while initializing deferred pages
# extra tests with debug options
git bisect bad c9e97a1997fbf3a1d18d4065c2ca381f0704d7e5 # 18:09 B 2 5 0 0 mm: initialize pages on demand during boot
# extra tests on HEAD of linux-devel/devel-spot-201804141202
git bisect bad f6604fa7518c1cda05b95590a7965fd7ab502d16 # 18:09 B 3 10 0 0 0day head guard for 'devel-spot-201804141202'
# extra tests on tree/branch linus/master
git bisect bad 48023102b7078a6674516b1fe0d639669336049d # 18:21 B 1 9 1 2 Merge branch 'overlayfs-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/mszeredi/vfs
# extra tests with first bad commit reverted
git bisect good 4fed2454050629cde24d5b66649a136d07c89f1b # 18:41 G 17 0 2 2 Revert "mm: initialize pages on demand during boot"
# extra tests on tree/branch linux-next/master
git bisect bad 238879f45b80794d457ca553ff26986a833f1d2c # 19:08 B 2 9 1 1 Add linux-next specific files for 20180413
---
0-DAY kernel test infrastructure Open Source Technology Center
https://lists.01.org/pipermail/lkp Intel Corporation
Thank you, I am studying the problem.
Pavel
On Wed, Apr 18, 2018 at 9:31 PM, Fengguang Wu <[email protected]> wrote:
> On Wed, Apr 18, 2018 at 06:38:25PM -0500, Dennis Zhou wrote:
>>Hi,
>>
>>On Wed, Apr 18, 2018 at 09:55:53PM +0800, Fengguang Wu wrote:
>>>
>>> Hello,
>>>
>>> FYI here is a slightly different boot error in mainline kernel 4.17.0-rc1.
>>> It also dates back to v4.16 .
>>>
>>> It occurs in 4 out of 4 boots.
>>>
>>> [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 128873
>>> [ 0.000000] Kernel command line: root=/dev/ram0 hung_task_panic=1 debug apic=debug sysrq_always_enabled rcupdate.rcu_cpu_stall_timeout=100 net.ifnames=0 printk.devkmsg=on panic=-1 softlockup_panic=1 nmi_watchdog=panic oops=panic load_ramdisk=2 prompt_ramdisk=0 drbd.minor_count=8 systemd.log_level=err ignore_loglevel console=tty0 earlyprintk=ttyS0,115200 console=ttyS0,115200 vga=normal rw link=/kbuild-tests/run-queue/kvm/x86_64-randconfig-a0-04172313/linux-devel:devel-hourly-2018041714:60cc43fc888428bb2f18f08997432d426a243338/.vmlinuz-60cc43fc888428bb2f18f08997432d426a243338-20180418000325-19:yocto-lkp-nhm-dp2-4 branch=linux-devel/devel-hourly-2018041714 BOOT_IMAGE=/pkg/linux/x86_64-randconfig-a0-04172313/gcc-7/60cc43fc888428bb2f18f08997432d426a243338/vmlinuz-4.17.0-rc1 drbd.minor_count=8 rcuperf.shutdown=0
>>> [ 0.000000] sysrq: sysrq always enabled.
>>> [ 0.000000] Dentry cache hash table entries: 65536 (order: 7, 524288 bytes)
>>> [ 0.000000] Inode-cache hash table entries: 32768 (order: 6, 262144 bytes)
>>> PANIC: early exception 0x0d IP 10:ffffffffa892f15f error 0 cr2 0xffff88001fbff000
>>> [ 0.000000] CPU: 0 PID: 0 Comm: swapper Tainted: G T 4.17.0-rc1 #238
>>> [ 0.000000] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
>>> [ 0.000000] RIP: 0010:per_cpu_ptr_to_phys+0x16a/0x298:
>>> __section_mem_map_addr at include/linux/mmzone.h:1188
>>> (inlined by) per_cpu_ptr_to_phys at mm/percpu.c:1849
>>> [ 0.000000] RSP: 0000:ffffffffab407e50 EFLAGS: 00010046 ORIG_RAX: 0000000000000000
>>> [ 0.000000] RAX: dffffc0000000000 RBX: ffff88001f17c340 RCX: 000000000000000f
>>> [ 0.000000] RDX: 0000000000000000 RSI: 0000000000000001 RDI: ffffffffacfbf580
>>> [ 0.000000] RBP: ffffffffab40d000 R08: fffffbfff57c4eca R09: 0000000000000000
>>> [ 0.000000] R10: ffff880015421000 R11: fffffbfff57c4ec9 R12: 0000000000000000
>>> [ 0.000000] R13: ffff88001fb03ff8 R14: ffff88001fc051c0 R15: 0000000000000000
>>> [ 0.000000] FS: 0000000000000000(0000) GS:ffffffffab4c5000(0000) knlGS:0000000000000000
>>> [ 0.000000] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>>> [ 0.000000] CR2: ffff88001fbff000 CR3: 000000001a06c000 CR4: 00000000000006b0
>>> [ 0.000000] Call Trace:
>>> [ 0.000000] setup_cpu_entry_areas+0x7b/0x27b:
>>> setup_cpu_entry_area at arch/x86/mm/cpu_entry_area.c:104
>>> (inlined by) setup_cpu_entry_areas at arch/x86/mm/cpu_entry_area.c:177
>>> [ 0.000000] trap_init+0xb/0x13d:
>>> trap_init at arch/x86/kernel/traps.c:949
>>> [ 0.000000] start_kernel+0x2a5/0x91d:
>>> mm_init at init/main.c:519
>>> (inlined by) start_kernel at init/main.c:589
>>> [ 0.000000] ? thread_stack_cache_init+0x6/0x6
>>> [ 0.000000] ? memcpy_orig+0x16/0x110:
>>> memcpy_orig at arch/x86/lib/memcpy_64.S:77
>>> [ 0.000000] ? x86_family+0x5/0x1d:
>>> x86_family at arch/x86/lib/cpu.c:8
>>> [ 0.000000] ? load_ucode_bsp+0x42/0x13e:
>>> load_ucode_bsp at arch/x86/kernel/cpu/microcode/core.c:183
>>> [ 0.000000] secondary_startup_64+0xa5/0xb0:
>>> secondary_startup_64 at arch/x86/kernel/head_64.S:242
>>> [ 0.000000] Code: 78 06 00 49 8b 45 00 48 85 c0 74 a5 49 c1 ec 28 41 81 e4 e0 0f 00 00 49 01 c4 4c 89 e2 48 b8 00 00 00 00 00 fc ff df 48 c1 ea 03 <80> 3c 02 00 74 08 4c 89 e7 e8 63 78 06 00 49 8b 04 24 81 e5 ff
>>> BUG: kernel hang in boot stage
>>>
>>
>>I spent some time bisecting this one and it seemse to be an intermittent
>>issue starting with this commit for me:
>>c9e97a1997, mm: initialize pages on demand during boot. The prior
>>commit, 3a2d7fa8a3, did not run into this issue after 10+ boots.
>
> Dennis, thanks for bisecting it down!
>
> Pavel, here is an early boot error bisected to c9e97a1997 ("mm:
> initialize pages on demand during boot"). Reproduce script attached.
>
> 3a2d7fa8a3 mm: disable interrupts while initializing deferred pages
> c9e97a1997 mm: initialize pages on demand during boot
> 48023102b7 Merge branch 'overlayfs-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/mszeredi/vfs
> 238879f45b Add linux-next specific files for 20180413
> +-------------------------------------------------------+------------+------------+------------+---------------+
> | | 3a2d7fa8a3 | c9e97a1997 | 48023102b7 | next-20180413 |
> +-------------------------------------------------------+------------+------------+------------+---------------+
> | boot_successes | 51 | 9 | 10 | 3 |
> | boot_failures | 1 | 12 | 11 | 9 |
> | Mem-Info | 1 | | | |
> | BUG:kernel_reboot-without-warning_in_early-boot_stage | 0 | 12 | 11 | 9 |
> +-------------------------------------------------------+------------+------------+------------+---------------+
>
> early console in setup code
> BUG: kernel reboot-without-warning in early-boot stage, last printk: early console in setup code
> Linux version 4.16.0-07313-gc9e97a1 #2
> Command line: root=/dev/ram0 hung_task_panic=1 debug apic=debug sysrq_always_enabled rcupdate.rcu_cpu_stall_timeout=100 net.ifnames=0 printk.devkmsg=on panic=-1 softlockup_panic=1 nmi_watchdog=panic oops=panic load_ramdisk=2 prompt_ramdisk=0 drbd.minor_count=8 systemd.log_level=err ignore_loglevel console=tty0 earlyprintk=ttyS0,115200 console=ttyS0,115200 vga=normal rw link=/kbuild-tests/run-queue/yocto-ivb41/x86_64-randconfig-r0-04141244/linux-devel:devel-spot-201804141202:c9e97a1997fbf3a1d18d4065c2ca381f0704d7e5:bisect-linux-20/.vmlinuz-c9e97a1997fbf3a1d18d4065c2ca381f0704d7e5-20180414175501-14:yocto-ivb41-130 branch=linux-devel/devel-spot-201804141202 BOOT_IMAGE=/pkg/linux/x86_64-randconfig-r0-04141244/gcc-6/c9e97a1997fbf3a1d18d4065c2ca381f0704d7e5/vmlinuz-4.16.0-07313-gc9e97a1 drbd.minor_count=8 rcuperf.shutdown=0
>
>
> # HH:MM RESULT GOOD BAD GOOD_BUT_DIRTY DIRTY_NOT_BAD
> git bisect start f6604fa7518c1cda05b95590a7965fd7ab502d16 0adb32858b0bddf4ada5f364a84ed60b196dbcda --
> git bisect bad 036ea404fd8d46c7b2b6290f820212df3be70553 # 13:45 B 1 5 0 0 Merge 'linux-review/Daniel-Mack/wcn36xx-pass-correct-BSS-index-when-deleting-BSS-keys/20180413-220635' into devel-spot-201804141202
> git bisect bad 0f85c8e00aecc556114d75a182a26bfe1ccadef0 # 14:00 B 0 8 22 0 Merge 'nfsd/nfsd-next' into devel-spot-201804141202
> git bisect bad 7342865df7cb1e1f2120493de329665744fa8946 # 14:11 B 0 10 24 0 Merge 'linux-review/Hern-n-Gonzalez/Move-ad7746-driver-out-of-staging/20180414-090557' into devel-spot-201804141202
> git bisect good 895a25a4c71353fa48cf389d8003f5b30ecc30cc # 14:22 G 17 0 1 1 Merge 'thermal/thermal-soc-v2' into devel-spot-201804141202
> git bisect bad d5111e404f5518298cf50ba910ac3a3362572d0d # 14:35 B 2 7 1 3 Merge 'linux-review/Hans-de-Goede/ACPI-LPSS-Only-call-pwm_add_table-for-Bay-Trail-PWM-if-PMIC-HRV-is-2/20180414-092906' into devel-spot-201804141202
> git bisect bad 1fb7bf52382687618e345cc587abdf301c3d485a # 14:59 B 0 3 17 0 Merge 'linux-review/Christian-Brauner/statfs-handle-mount-propagation/20180414-104639' into devel-spot-201804141202
> git bisect good f9ca6a561d40115696a54f16085c4edb17effc74 # 15:19 G 17 0 0 0 Merge git://git.kernel.org/pub/scm/linux/kernel/git/davem/net
> git bisect good b240b419db5d624ce7a5a397d6f62a1a686009ec # 15:30 G 17 0 2 2 Merge tag 'armsoc-dt' of git://git.kernel.org/pub/scm/linux/kernel/git/arm/arm-soc
> git bisect bad 49a695ba723224875df50e327bd7b0b65dd9a56b # 15:41 B 0 3 17 0 Merge tag 'powerpc-4.17-1' of git://git.kernel.org/pub/scm/linux/kernel/git/powerpc/linux
> git bisect bad 28da7be5ebc096ada5e6bc526c623bdd8c47800a # 15:50 B 0 6 20 0 Merge tag 'mailbox-v4.17' of git://git.linaro.org/landing-teams/working/fujitsu/integration
> git bisect good 38c23685b273cfb4ccf31a199feccce3bdcb5d83 # 16:03 G 17 0 1 1 Merge tag 'armsoc-drivers' of git://git.kernel.org/pub/scm/linux/kernel/git/arm/arm-soc
> git bisect good 3fd14cdcc05a682b03743683ce3a726898b20555 # 16:18 G 17 0 3 3 Merge tag 'mtd/for-4.17' of git://git.infradead.org/linux-mtd
> git bisect bad e92bb4dd9673945179b1fc738c9817dd91bfb629 # 16:30 B 1 10 0 3 mm: fix races between address_space dereference and free in page_evicatable
> git bisect good d5f866550df237861f9d59ca0206434b0dea9701 # 16:46 G 17 0 2 2 slab: make size_index[] array u8
> git bisect good 613a5eb5677923fdaecfa582738c7bcf80abe186 # 16:56 G 17 0 1 1 slab, slub: remove size disparity on debug kernel
> git bisect bad ba325585230ed17079fd5b4065c359ebba117bbe # 17:11 B 0 9 23 0 mm/memory_hotplug: enforce block size aligned range check
> git bisect good 310253514bbf179c5f82e20a7a4bbf07abc7f5ad # 17:22 G 17 0 1 1 mm/migrate: rename migration reason MR_CMA to MR_CONTIG_RANGE
> git bisect good 3a2d7fa8a3d5ae740bd0c21d933acc6220857ed0 # 17:35 G 17 0 3 3 mm: disable interrupts while initializing deferred pages
> git bisect bad f0849ac0b8e072073ec5fcc7fadd05a77434364e # 17:44 B 0 9 23 0 mm: thp: fix potential clearing to referenced flag in page_idle_clear_pte_refs_one()
> git bisect bad c9e97a1997fbf3a1d18d4065c2ca381f0704d7e5 # 17:55 B 0 1 15 0 mm: initialize pages on demand during boot
> # first bad commit: [c9e97a1997fbf3a1d18d4065c2ca381f0704d7e5] mm: initialize pages on demand during boot
> git bisect good 3a2d7fa8a3d5ae740bd0c21d933acc6220857ed0 # 18:00 G 51 0 2 5 mm: disable interrupts while initializing deferred pages
> # extra tests with debug options
> git bisect bad c9e97a1997fbf3a1d18d4065c2ca381f0704d7e5 # 18:09 B 2 5 0 0 mm: initialize pages on demand during boot
> # extra tests on HEAD of linux-devel/devel-spot-201804141202
> git bisect bad f6604fa7518c1cda05b95590a7965fd7ab502d16 # 18:09 B 3 10 0 0 0day head guard for 'devel-spot-201804141202'
> # extra tests on tree/branch linus/master
> git bisect bad 48023102b7078a6674516b1fe0d639669336049d # 18:21 B 1 9 1 2 Merge branch 'overlayfs-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/mszeredi/vfs
> # extra tests with first bad commit reverted
> git bisect good 4fed2454050629cde24d5b66649a136d07c89f1b # 18:41 G 17 0 2 2 Revert "mm: initialize pages on demand during boot"
> # extra tests on tree/branch linux-next/master
> git bisect bad 238879f45b80794d457ca553ff26986a833f1d2c # 19:08 B 2 9 1 1 Add linux-next specific files for 20180413
>
> ---
> 0-DAY kernel test infrastructure Open Source Technology Center
> https://lists.01.org/pipermail/lkp Intel Corporation
I have root caused the issue, and will submit a fix shortly. The fix
also fixes the per_cpu_ptr_to_phys bug that is sent in a separate
thread.
The issue arises in this stack:
start_kernel()
trap_init()
setup_cpu_entry_areas()
setup_cpu_entry_area(cpu)
get_cpu_gdt_paddr(cpu)
per_cpu_ptr_to_phys(addr)
pcpu_addr_to_page(addr)
virt_to_page(addr)
pfn_to_page(__pa(addr) >> PAGE_SHIFT)
The returned "struct page" is sometimes uninitialized, and thus
failing later when used. It turns out sometimes is because it depends
on KASLR.
When boot is failing we have this when pfn_to_page() is called:
kasrl: 0x000000000d600000
addr: ffffffff83e0d000
pa: 1040d000
pfn: 1040d
page: ffff88001f113340
page->flags ffffffffffffffff <- Uninitialized!
When boot is successful:
kaslr: 0x000000000a800000
addr: ffffffff83e0d000
pa: d60d000
pfn: d60d
page: ffff88001f05b340
page->flags 280000000000 <- Initialized!
Here are physical addresses that BIOS provided to us:
[ 0.000000] e820: BIOS-provided physical RAM map:
[ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable
[ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved
[ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved
[ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000001ffdffff] usable
[ 0.000000] BIOS-e820: [mem 0x000000001ffe0000-0x000000001fffffff] reserved
[ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved
[ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
In both cases, working and non-working the real physical address is the same:
pa - kasrl = 0x2E0D000
The only thing that is different is PFN.
We initialize struct pages in four places:
1. Early in boot a small set of struct pages is initialized to fill
the first section, and lower zones.
2. During mm_init() we initialize "struct pages" for all the memory
that is allocated, i.e reserved in memblock.
3. Using on-demand logic when pages are allocated after mm_init call
4. After smp_init() when the rest free deferred pages are initialized.
The above path happens before deferred memory is initialized, and thus
it must be covered either by 1, 2 or 3.
So, lets check what PFNs are initialized after (1).
memmap_init_zone() is called for pfn ranges:
1 - 1000, and 1000 - 1ffe0, but it quits after reaching pfn 0x10000,
as it leaves the rest to be initialized as deferred pages.
In the working scenario pfn ended up being below 1000, but in the
failing scenario it is above. Hence, we must initialize this page in
(2). But trap_init() is called before mm_init().
The bug was introduced by "mm: initialize pages on demand during boot"
because we lowered amount of pages that is initialized in the step
(1). But, it still could happen, because the number of initialized
pages was a guessing.
The proposed fix is this:
diff --git a/init/main.c b/init/main.c
index b795aa341a3a..870f75581cea 100644
--- a/init/main.c
+++ b/init/main.c
@@ -585,8 +585,8 @@ asmlinkage __visible void __init start_kernel(void)
setup_log_buf(0);
vfs_caches_init_early();
sort_main_extable();
- trap_init();
mm_init();
+ trap_init();
ftrace_init();
Hi all,
On Wed, Apr 18, 2018 at 06:38:25PM -0500, Dennis Zhou wrote:
>Hi,
>
>On Wed, Apr 18, 2018 at 09:55:53PM +0800, Fengguang Wu wrote:
>>
>> Hello,
>>
>> FYI here is a slightly different boot error in mainline kernel 4.17.0-rc1.
>> It also dates back to v4.16 .
Now I find 2 more occurrances in v4.15 kernel.
Here are the statistics:
kernel count error-id
v4.15: 2 RIP:per_cpu_ptr_to_phys
v4.16: 12 RIP:per_cpu_ptr_to_phys
v4.16: 1 BUG:KASAN:null-ptr-deref-in-per_cpu_ptr_to_phys
v4.16-rc7: 2 RIP:per_cpu_ptr_to_phys
v4.17-rc1: 217 RIP:per_cpu_ptr_to_phys
v4.17-rc1: 5 BUG:KASAN:null-ptr-deref-in-per_cpu_ptr_to_phys
v4.17-rc2: 46 RIP:per_cpu_ptr_to_phys
v4.17-rc2: 15 BUG:KASAN:null-ptr-deref-in-per_cpu_ptr_to_phys
v4.17-rc3: 12 RIP:per_cpu_ptr_to_phys
>> It occurs in 4 out of 4 boots.
>>
>> [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 128873
>> [ 0.000000] Kernel command line: root=/dev/ram0 hung_task_panic=1 debug apic=debug sysrq_always_enabled rcupdate.rcu_cpu_stall_timeout=100 net.ifnames=0 printk.devkmsg=on panic=-1 softlockup_panic=1 nmi_watchdog=panic oops=panic load_ramdisk=2 prompt_ramdisk=0 drbd.minor_count=8 systemd.log_level=err ignore_loglevel console=tty0 earlyprintk=ttyS0,115200 console=ttyS0,115200 vga=normal rw link=/kbuild-tests/run-queue/kvm/x86_64-randconfig-a0-04172313/linux-devel:devel-hourly-2018041714:60cc43fc888428bb2f18f08997432d426a243338/.vmlinuz-60cc43fc888428bb2f18f08997432d426a243338-20180418000325-19:yocto-lkp-nhm-dp2-4 branch=linux-devel/devel-hourly-2018041714 BOOT_IMAGE=/pkg/linux/x86_64-randconfig-a0-04172313/gcc-7/60cc43fc888428bb2f18f08997432d426a243338/vmlinuz-4.17.0-rc1 drbd.minor_count=8 rcuperf.shutdown=0
>> [ 0.000000] sysrq: sysrq always enabled.
>> [ 0.000000] Dentry cache hash table entries: 65536 (order: 7, 524288 bytes)
>> [ 0.000000] Inode-cache hash table entries: 32768 (order: 6, 262144 bytes)
>> PANIC: early exception 0x0d IP 10:ffffffffa892f15f error 0 cr2 0xffff88001fbff000
>> [ 0.000000] CPU: 0 PID: 0 Comm: swapper Tainted: G T 4.17.0-rc1 #238
>> [ 0.000000] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
>> [ 0.000000] RIP: 0010:per_cpu_ptr_to_phys+0x16a/0x298:
>> __section_mem_map_addr at include/linux/mmzone.h:1188
>> (inlined by) per_cpu_ptr_to_phys at mm/percpu.c:1849
>> [ 0.000000] RSP: 0000:ffffffffab407e50 EFLAGS: 00010046 ORIG_RAX: 0000000000000000
>> [ 0.000000] RAX: dffffc0000000000 RBX: ffff88001f17c340 RCX: 000000000000000f
>> [ 0.000000] RDX: 0000000000000000 RSI: 0000000000000001 RDI: ffffffffacfbf580
>> [ 0.000000] RBP: ffffffffab40d000 R08: fffffbfff57c4eca R09: 0000000000000000
>> [ 0.000000] R10: ffff880015421000 R11: fffffbfff57c4ec9 R12: 0000000000000000
>> [ 0.000000] R13: ffff88001fb03ff8 R14: ffff88001fc051c0 R15: 0000000000000000
>> [ 0.000000] FS: 0000000000000000(0000) GS:ffffffffab4c5000(0000) knlGS:0000000000000000
>> [ 0.000000] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>> [ 0.000000] CR2: ffff88001fbff000 CR3: 000000001a06c000 CR4: 00000000000006b0
>> [ 0.000000] Call Trace:
>> [ 0.000000] setup_cpu_entry_areas+0x7b/0x27b:
>> setup_cpu_entry_area at arch/x86/mm/cpu_entry_area.c:104
>> (inlined by) setup_cpu_entry_areas at arch/x86/mm/cpu_entry_area.c:177
>> [ 0.000000] trap_init+0xb/0x13d:
>> trap_init at arch/x86/kernel/traps.c:949
>> [ 0.000000] start_kernel+0x2a5/0x91d:
>> mm_init at init/main.c:519
>> (inlined by) start_kernel at init/main.c:589
>> [ 0.000000] ? thread_stack_cache_init+0x6/0x6
>> [ 0.000000] ? memcpy_orig+0x16/0x110:
>> memcpy_orig at arch/x86/lib/memcpy_64.S:77
>> [ 0.000000] ? x86_family+0x5/0x1d:
>> x86_family at arch/x86/lib/cpu.c:8
>> [ 0.000000] ? load_ucode_bsp+0x42/0x13e:
>> load_ucode_bsp at arch/x86/kernel/cpu/microcode/core.c:183
>> [ 0.000000] secondary_startup_64+0xa5/0xb0:
>> secondary_startup_64 at arch/x86/kernel/head_64.S:242
>> [ 0.000000] Code: 78 06 00 49 8b 45 00 48 85 c0 74 a5 49 c1 ec 28 41 81 e4 e0 0f 00 00 49 01 c4 4c 89 e2 48 b8 00 00 00 00 00 fc ff df 48 c1 ea 03 <80> 3c 02 00 74 08 4c 89 e7 e8 63 78 06 00 49 8b 04 24 81 e5 ff
>> BUG: kernel hang in boot stage
>>
>
>I spent some time bisecting this one and it seemse to be an intermittent
>issue starting with this commit for me:
>c9e97a1997, mm: initialize pages on demand during boot. The prior
>commit, 3a2d7fa8a3, did not run into this issue after 10+ boots.
That commit is post-4.16, so probably not the root cause.
>I don't have that much time right now, nor the expertise with this code.
>Pavel could you take a look at this?
Thanks,
Fengguang
Hi Fengguang,
My root cause for the problem was correct. You are now finding either a
different problem that has the same signature, or what is more likely the
same issue but simply was not introduced by my change: my change reduced
number of pre-initialized pages because we init them on demand with my
work, but we could run out of them even before my change, and because of
KASLR we never know how much is needed to be pre-initialized.
Could you please test if my patch fixes the issue?
http://ozlabs.org/~akpm/mmots/broken-out/mm-access-to-uninitialized-struct-page.patch
Thank you,
Pavel
On Wed, May 2, 2018 at 8:44 AM Fengguang Wu <[email protected]> wrote:
> Hi all,
> On Wed, Apr 18, 2018 at 06:38:25PM -0500, Dennis Zhou wrote:
> >Hi,
> >
> >On Wed, Apr 18, 2018 at 09:55:53PM +0800, Fengguang Wu wrote:
> >>
> >> Hello,
> >>
> >> FYI here is a slightly different boot error in mainline kernel
4.17.0-rc1.
> >> It also dates back to v4.16 .
> Now I find 2 more occurrances in v4.15 kernel.
> Here are the statistics:
> kernel count error-id
> v4.15: 2 RIP:per_cpu_ptr_to_phys
> v4.16: 12 RIP:per_cpu_ptr_to_phys
> v4.16: 1
BUG:KASAN:null-ptr-deref-in-per_cpu_ptr_to_phys
> v4.16-rc7: 2 RIP:per_cpu_ptr_to_phys
> v4.17-rc1: 217 RIP:per_cpu_ptr_to_phys
> v4.17-rc1: 5
BUG:KASAN:null-ptr-deref-in-per_cpu_ptr_to_phys
> v4.17-rc2: 46 RIP:per_cpu_ptr_to_phys
> v4.17-rc2: 15
BUG:KASAN:null-ptr-deref-in-per_cpu_ptr_to_phys
> v4.17-rc3: 12 RIP:per_cpu_ptr_to_phys
> >> It occurs in 4 out of 4 boots.
> >>
> >> [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages:
128873
> >> [ 0.000000] Kernel command line: root=/dev/ram0 hung_task_panic=1
debug apic=debug sysrq_always_enabled rcupdate.rcu_cpu_stall_timeout=100
net.ifnames=0 printk.devkmsg=on panic=-1 softlockup_panic=1
nmi_watchdog=panic oops=panic load_ramdisk=2 prompt_ramdisk=0
drbd.minor_count=8 systemd.log_level=err ignore_loglevel console=tty0
earlyprintk=ttyS0,115200 console=ttyS0,115200 vga=normal rw
link=/kbuild-tests/run-queue/kvm/x86_64-randconfig-a0-04172313/linux-devel:devel-hourly-2018041714:60cc43fc888428bb2f18f08997432d426a243338/.vmlinuz-60cc43fc888428bb2f18f08997432d426a243338-20180418000325-19:yocto-lkp-nhm-dp2-4
branch=linux-devel/devel-hourly-2018041714
BOOT_IMAGE=/pkg/linux/x86_64-randconfig-a0-04172313/gcc-7/60cc43fc888428bb2f18f08997432d426a243338/vmlinuz-4.17.0-rc1
drbd.minor_count=8 rcuperf.shutdown=0
> >> [ 0.000000] sysrq: sysrq always enabled.
> >> [ 0.000000] Dentry cache hash table entries: 65536 (order: 7,
524288 bytes)
> >> [ 0.000000] Inode-cache hash table entries: 32768 (order: 6, 262144
bytes)
> >> PANIC: early exception 0x0d IP 10:ffffffffa892f15f error 0 cr2
0xffff88001fbff000
> >> [ 0.000000] CPU: 0 PID: 0 Comm: swapper Tainted: G T
4.17.0-rc1 #238
> >> [ 0.000000] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
BIOS 1.10.2-1 04/01/2014
> >> [ 0.000000] RIP: 0010:per_cpu_ptr_to_phys+0x16a/0x298:
> >> __section_mem_map_addr at
include/linux/mmzone.h:1188
> >> (inlined by)
per_cpu_ptr_to_phys at mm/percpu.c:1849
> >> [ 0.000000] RSP: 0000:ffffffffab407e50 EFLAGS: 00010046 ORIG_RAX:
0000000000000000
> >> [ 0.000000] RAX: dffffc0000000000 RBX: ffff88001f17c340 RCX:
000000000000000f
> >> [ 0.000000] RDX: 0000000000000000 RSI: 0000000000000001 RDI:
ffffffffacfbf580
> >> [ 0.000000] RBP: ffffffffab40d000 R08: fffffbfff57c4eca R09:
0000000000000000
> >> [ 0.000000] R10: ffff880015421000 R11: fffffbfff57c4ec9 R12:
0000000000000000
> >> [ 0.000000] R13: ffff88001fb03ff8 R14: ffff88001fc051c0 R15:
0000000000000000
> >> [ 0.000000] FS: 0000000000000000(0000) GS:ffffffffab4c5000(0000)
knlGS:0000000000000000
> >> [ 0.000000] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> >> [ 0.000000] CR2: ffff88001fbff000 CR3: 000000001a06c000 CR4:
00000000000006b0
> >> [ 0.000000] Call Trace:
> >> [ 0.000000] setup_cpu_entry_areas+0x7b/0x27b:
> >> setup_cpu_entry_area at
arch/x86/mm/cpu_entry_area.c:104
> >> (inlined by)
setup_cpu_entry_areas at arch/x86/mm/cpu_entry_area.c:177
> >> [ 0.000000] trap_init+0xb/0x13d:
> >> trap_init at
arch/x86/kernel/traps.c:949
> >> [ 0.000000] start_kernel+0x2a5/0x91d:
> >> mm_init at init/main.c:519
> >> (inlined by)
start_kernel at init/main.c:589
> >> [ 0.000000] ? thread_stack_cache_init+0x6/0x6
> >> [ 0.000000] ? memcpy_orig+0x16/0x110:
> >> memcpy_orig at
arch/x86/lib/memcpy_64.S:77
> >> [ 0.000000] ? x86_family+0x5/0x1d:
> >> x86_family at
arch/x86/lib/cpu.c:8
> >> [ 0.000000] ? load_ucode_bsp+0x42/0x13e:
> >> load_ucode_bsp at
arch/x86/kernel/cpu/microcode/core.c:183
> >> [ 0.000000] secondary_startup_64+0xa5/0xb0:
> >> secondary_startup_64 at
arch/x86/kernel/head_64.S:242
> >> [ 0.000000] Code: 78 06 00 49 8b 45 00 48 85 c0 74 a5 49 c1 ec 28
41 81 e4 e0 0f 00 00 49 01 c4 4c 89 e2 48 b8 00 00 00 00 00 fc ff df 48 c1
ea 03 <80> 3c 02 00 74 08 4c 89 e7 e8 63 78 06 00 49 8b 04 24 81 e5 ff
> >> BUG: kernel hang in boot stage
> >>
> >
> >I spent some time bisecting this one and it seemse to be an intermittent
> >issue starting with this commit for me:
> >c9e97a1997, mm: initialize pages on demand during boot. The prior
> >commit, 3a2d7fa8a3, did not run into this issue after 10+ boots.
> That commit is post-4.16, so probably not the root cause.
> >I don't have that much time right now, nor the expertise with this code.
> >Pavel could you take a look at this?
> Thanks,
> Fengguang