4.15-rc2 crash on RPi2 in teardown_hyp_mode()

["Andreas Färber" <afaerber@suse.de>]

[-- Attachment #1: Type: text/plain, Size: 1842 bytes --]

Hi,

Am 06.12.2017 um 15:11 schrieb Andre Przywara:
> while trying to boot 4.15-rc1 on my Calxeda Midway I observed a crash
[snip]

I'm seeing a possibly related crash in 4.15-rc2 on Raspberry Pi 2.
Using its 4.15-rc2 dtb I see a ton of timer interrupt errors (attached)
and then KVM runs into an error in unmap_hyp_range():

[    3.974575] kvm [1]: 8-bit VMID
[    3.977734] kvm [1]: IDMAP page: 401000
[    3.981632] kvm [1]: HYP VA range: c0000000:ffffffff
[    3.987575] kvm [1]: Invalid trigger for IRQ19, assuming level low
[    3.993864] kvm [1]: kvm_arch_timer: error setting vcpu affinity
[    4.000174] Unable to handle kernel paging request at virtual address
ae46a000
[    4.007470] pgd = 6db59d0e
[    4.010206] [ae46a000] *pgd=80000000306003, *pmd=00000000
[    4.015666] Internal error: Oops: 206 [#1] PREEMPT SMP ARM
[    4.021181] Modules linked in:
[    4.024259] CPU: 1 PID: 1 Comm: swapper/0 Not tainted
4.15.0-rc2-2.gef715eb-lpae #1
[    4.031955] Hardware name: BCM2835
[    4.035373] task: 27c0e1b0 task.stack: 6730d7bc
[    4.039936] PC is at unmap_hyp_range+0x130/0x414
[    4.044580] LR is at 0x40000000
[...]
[    4.273820] [<c0425b0c>] (unmap_hyp_range) from [<c0427728>]
(free_hyp_pgds+0x10c/0x18c)
[    4.281965] [<c0427728>] (free_hyp_pgds) from [<c0423338>]
(teardown_hyp_mode+0x28/0x84)
[    4.290109] [<c0423338>] (teardown_hyp_mode) from [<c04256b0>]
(kvm_arch_init+0x324/0x52c)

4.14.3 boots fine on RPi2 with the same dtb.
4.15-rc2 boots fine on RPi3 with its latest dtb.

I'm assuming there's two bugs here, one in the RPi2 dts for the
arch_timer and that error triggering Andre's kvm teardown bug that
hopefully will be fixed with Marc's patch.

Regards,
Andreas

-- 
SUSE Linux GmbH, Maxfeldstr. 5, 90409 Nürnberg, Germany
GF: Felix Imendörffer, Jane Smithard, Graham Norton
HRB 21284 (AG Nürnberg)

[-- Attachment #2: 4.15-rc2_timer.txt --]
[-- Type: text/plain, Size: 14916 bytes --]

[    0.000018] sched_clock: 32 bits at 1000kHz, resolution 1000ns, wraps every 2147483647500ns
[    0.008447] clocksource: timer: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275 ns
[    0.017868] bcm2835: system timer (irq = 33)
[    0.023521] arch_timer: WARNING: Invalid trigger for IRQ16, assuming level low
[    0.030783] arch_timer: WARNING: Please fix your firmware
[    0.036213] arch_timer: WARNING: Invalid trigger for IRQ17, assuming level low
[    0.043472] arch_timer: WARNING: Please fix your firmware
[    0.048962] arch_timer: cp15 timer(s) running at 19.20MHz (phys).
[    0.055097] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x46d987e47, max_idle_ns: 440795202767 ns
[    0.065948] sched_clock: 56 bits at 19MHz, resolution 52ns, wraps every 4398046511078ns
[    0.074000] Switching to timer-based delay loop, resolution 52ns
[    0.081047] Console: colour dummy device 80x30
[    0.085587] Calibrating delay loop (skipped), value calculated using timer frequency.. 38.40 BogoMIPS (lpj=96000)
[    0.095933] pid_max: default: 32768 minimum: 301
[    0.100843] Security Framework initialized
[    0.105075] AppArmor: AppArmor initialized
[    0.109425] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes)
[    0.116111] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes)
[    0.124221] CPU: Testing write buffer coherency: ok
[    0.129653] CPU0: update cpu_capacity 1024
[    0.133775] CPU0: thread -1, cpu 0, socket 15, mpidr 80000f00
[    0.159728] Setting up static identity map for 0x400000 - 0x400178
[    0.166330] Hierarchical SRCU implementation.
[    0.201151] smp: Bringing up secondary CPUs ...
[    0.231794] arch_timer: WARNING: Invalid trigger for IRQ16, assuming level low
[    0.231799] arch_timer: WARNING: Please fix your firmware
[    0.231808] arch_timer: WARNING: Invalid trigger for IRQ17, assuming level low
[    0.231811] arch_timer: WARNING: Please fix your firmware
[    0.231826] CPU1: update cpu_capacity 1024
[    0.231833] CPU1: thread -1, cpu 1, socket 15, mpidr 80000f01
[    0.271836] arch_timer: WARNING: Invalid trigger for IRQ16, assuming level low
[    0.271840] arch_timer: WARNING: Please fix your firmware
[    0.271848] arch_timer: WARNING: Invalid trigger for IRQ17, assuming level low
[    0.271850] arch_timer: WARNING: Please fix your firmware
[    0.271861] CPU2: update cpu_capacity 1024
[    0.271868] CPU2: thread -1, cpu 2, socket 15, mpidr 80000f02
[    0.311947] arch_timer: WARNING: Invalid trigger for IRQ16, assuming level low
[    0.311951] arch_timer: WARNING: Please fix your firmware
[    0.311958] arch_timer: WARNING: Invalid trigger for IRQ17, assuming level low
[    0.311961] arch_timer: WARNING: Please fix your firmware
[    0.311972] CPU3: update cpu_capacity 1024
[    0.311979] CPU3: thread -1, cpu 3, socket 15, mpidr 80000f03
[    0.312107] smp: Brought up 1 node, 4 CPUs
[    0.422191] SMP: Total of 4 processors activated (153.60 BogoMIPS).
[    0.428503] CPU: All CPU(s) started in HYP mode.
[    0.433141] CPU: Virtualization extensions available.
[    0.439406] devtmpfs: initialized
[    0.450431] VFP support v0.3: implementor 41 architecture 2 part 30 variant 7 rev 5
[    0.458668] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 9556302231375000 ns
[    0.468498] futex hash table entries: 1024 (order: 4, 65536 bytes)
[    0.477848] pinctrl core: initialized pinctrl subsystem
[    0.484796] NET: Registered protocol family 16
[    0.490950] DMA: preallocated 256 KiB pool for atomic coherent allocations
[    0.500004] audit: initializing netlink subsys (disabled)
[    0.505763] audit: type=2000 audit(0.360:1): state=initialized audit_enabled=0 res=1
[    0.513596] cpuidle: using governor ladder
[    0.517893] cpuidle: using governor menu
[    0.522533] No ATAGs?
[    0.522682] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
[    0.533029] hw-breakpoint: maximum watchpoint size is 8 bytes.
[    0.539784] Serial: AMBA PL011 UART driver
[    0.547053] uart-pl011 3f201000.serial: could not find pctldev for node /soc/gpio@7e200000/uart0_gpio14, deferring probe
[    0.571829] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages
[    0.582255] vgaarb: loaded
[    0.586426] SCSI subsystem initialized
[    0.590892] pps_core: LinuxPPS API ver. 1 registered
[    0.595932] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
[    0.605155] PTP clock support registered
[    0.609131] EDAC MC: Ver: 3.0.0
[    0.613714] NetLabel: Initializing
[    0.617136] NetLabel:  domain hash size = 128
[    0.621543] NetLabel:  protocols = UNLABELED CIPSOv4 CALIPSO
[    0.627327] NetLabel:  unlabeled traffic allowed by default
[    0.633382] clocksource: Switched to clocksource arch_sys_counter
[    0.714970] VFS: Disk quotas dquot_6.6.0
[    0.719077] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[    0.726774] AppArmor: AppArmor Filesystem Enabled
[    0.731790] simple-framebuffer 3eaf0000.framebuffer: framebuffer at 0x3eaf0000, 0x10a800 bytes, mapped to 0x895a7b01
[    0.742417] simple-framebuffer 3eaf0000.framebuffer: format=a8r8g8b8, mode=656x416x32, linelength=2624
[    0.757353] Console: switching to colour frame buffer device 82x26
[    0.768438] simple-framebuffer 3eaf0000.framebuffer: fb0: simplefb registered!
[    0.786988] NET: Registered protocol family 2
[    0.792316] TCP established hash table entries: 8192 (order: 3, 32768 bytes)
[    0.799539] TCP bind hash table entries: 8192 (order: 4, 65536 bytes)
[    0.806154] TCP: Hash tables configured (established 8192 bind 8192)
[    0.812710] UDP hash table entries: 512 (order: 2, 16384 bytes)
[    0.818733] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes)
[    0.825432] NET: Registered protocol family 1
[    0.830328] Unpacking initramfs...
[    3.963674] Freeing initrd memory: 6460K
[    3.967752] NetWinder Floating Point Emulator V0.97 (extended precision)
[    3.974575] kvm [1]: 8-bit VMID
[    3.977734] kvm [1]: IDMAP page: 401000
[    3.981632] kvm [1]: HYP VA range: c0000000:ffffffff
[    3.987575] kvm [1]: Invalid trigger for IRQ19, assuming level low
[    3.993864] kvm [1]: kvm_arch_timer: error setting vcpu affinity
[    4.000174] Unable to handle kernel paging request at virtual address ae46a000
[    4.007470] pgd = 6db59d0e
[    4.010206] [ae46a000] *pgd=80000000306003, *pmd=00000000
[    4.015666] Internal error: Oops: 206 [#1] PREEMPT SMP ARM
[    4.021181] Modules linked in:
[    4.024259] CPU: 1 PID: 1 Comm: swapper/0 Not tainted 4.15.0-rc2-2.gef715eb-lpae #1
[    4.031955] Hardware name: BCM2835
[    4.035373] task: 27c0e1b0 task.stack: 6730d7bc
[    4.039936] PC is at unmap_hyp_range+0x130/0x414
[    4.044580] LR is at 0x40000000
[    4.047735] pc : [<c0425b0c>]    lr : [<40000000>]    psr: 20000113
[    4.054035] sp : ef125d70  ip : 00000000  fp : ef125de4
[    4.059286] r10: c17afb80  r9 : 00000001  r8 : ae46a000
[    4.064538] r7 : 00000000  r6 : 00000000  r5 : 00000001  r4 : ee465000
[    4.071100] r3 : ffe00000  r2 : ae46a000  r1 : 00000000  r0 : ee46a000
[    4.077664] Flags: nzCv  IRQs on  FIQs on  Mode SVC_32  ISA ARM  Segment user
[    4.084838] Control: 30c5387d  Table: 00303000  DAC: bd77eaef
[    4.090615] Process swapper/0 (pid: 1, stack limit = 0x1e1e7ba4)
[    4.096654] Stack: (0xef125d70 to 0xef126000)
[    4.101036] 5d60:                                     ef7de448 ae46a000 30800000 00000001
[    4.109263] 5d80: ff800000 00000000 307fffff 00000001 ee469fe0 ee465008 ee465000 ffe00000
[    4.117490] 5da0: 3fffffff 00000000 40000000 00000000 00000000 00000000 00001000 c1712ea0
[    4.125717] 5dc0: c17afb90 40000000 00000000 ff800000 30800000 c1606544 ef125e14 ef125de8
[    4.133944] 5de0: c0427728 c04259e8 40000000 00000000 00000010 0000a04c 00005ddc 00005f04
[    4.142171] 5e00: 00006544 c1606544 ef125e3c ef125e18 c0423338 c0427628 00000010 c1605f04
[    4.150398] 5e20: c1713618 c1712e90 c1605ddc c1606544 ef125e7c ef125e40 c04256b0 c042331c
[    4.158625] 5e40: c10767f4 ffffffda 00000000 00000001 000000c0 c1605d98 c0423394 ffffe000
[    4.166852] 5e60: 00000000 00000000 00000000 00000ee8 ef125ec4 ef125e80 c0417cbc c0425398
[    4.175079] 5e80: ffffe000 00000000 ef125eac ef125e98 c0d29340 c05797a8 c1712ee4 c1605d98
[    4.183306] 5ea0: c0423394 ffffe000 00000000 c148f834 000000c0 c1712d80 ef125ed4 ef125ec8
[    4.191533] 5ec0: c04233bc c0417ca0 ef125f4c ef125ed8 c0402170 c04233a0 ef125f4c ef125ee8
[    4.199761] 5ee0: c04a34dc c1400600 ef125ee8 ef125ee8 c1088fe4 c1088fc4 c1089010 c109cfc8
[    4.207988] 5f00: 00000000 c1088f58 00000006 00000006 c1126694 c11a527c efffed57 efffed5e
[    4.216215] 5f20: 00000000 7beb558d c11a527c c150888c 00000007 c1712d80 c148f834 000000c0
[    4.224442] 5f40: ef125f94 ef125f50 c14010b0 c0402118 00000006 00000006 00000000 c1400664
[    4.232669] 5f60: aa08aaaa c1400664 ab0aaaaa 00000000 c0d225c4 00000000 00000000 00000000
[    4.240895] 5f80: 00000000 00000000 ef125fac ef125f98 c0d225dc c1400eb8 00000000 c0d225c4
[    4.249122] 5fa0: 00000000 ef125fb0 c0437cec c0d225d0 00000000 00000000 00000000 00000000
[    4.257348] 5fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[    4.265575] 5fe0: 00000000 00000000 00000000 00000000 00000013 00000000 ee9aaaaa 8a8aaaaa
[    4.273820] [<c0425b0c>] (unmap_hyp_range) from [<c0427728>] (free_hyp_pgds+0x10c/0x18c)
[    4.281965] [<c0427728>] (free_hyp_pgds) from [<c0423338>] (teardown_hyp_mode+0x28/0x84)
[    4.290109] [<c0423338>] (teardown_hyp_mode) from [<c04256b0>] (kvm_arch_init+0x324/0x52c)
[    4.298428] [<c04256b0>] (kvm_arch_init) from [<c0417cbc>] (kvm_init+0x28/0x2d8)
[    4.305871] [<c0417cbc>] (kvm_init) from [<c04233bc>] (arm_init+0x28/0x30)
[    4.312790] [<c04233bc>] (arm_init) from [<c0402170>] (do_one_initcall+0x64/0x1a8)
[    4.320411] [<c0402170>] (do_one_initcall) from [<c14010b0>] (kernel_init_freeable+0x204/0x2a8)
[    4.329169] [<c14010b0>] (kernel_init_freeable) from [<c0d225dc>] (kernel_init+0x18/0x120)
[    4.337487] [<c0d225dc>] (kernel_init) from [<c0437cec>] (ret_from_fork+0x14/0x28)
[    4.345106] Code: e1a08009 e1530005 01520004 0a000077 (e1c820d0) 
[    4.351375] ---[ end trace 9b4e0bcddd8c1cd7 ]---
[    4.356079] Kernel panic - not syncing: Attempted to kill init! exitcode=0x0000000b
[    4.356079] 
[    4.365275] CPU0: stopping
[    4.367999] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G      D          4.15.0-rc2-2.gef715eb-lpae #1
[    4.377005] Hardware name: BCM2835
[    4.380437] [<c0443eb0>] (unwind_backtrace) from [<c043ca40>] (show_stack+0x20/0x28)
[    4.388234] [<c043ca40>] (show_stack) from [<c0d0af38>] (dump_stack+0xb8/0xe4)
[    4.395507] [<c0d0af38>] (dump_stack) from [<c04404e8>] (handle_IPI+0x3bc/0x3cc)
[    4.402952] [<c04404e8>] (handle_IPI) from [<c0401638>] (bcm2836_arm_irqchip_handle_irq+0x84/0xbc)
[    4.411968] [<c0401638>] (bcm2836_arm_irqchip_handle_irq) from [<c0d2ac3c>] (__irq_svc+0x5c/0x94)
[    4.420889] Exception stack(0xc1601ec8 to 0xc1601f10)
[    4.425970] 1ec0:                   00000001 00000000 2e2b8000 20000093 ffffe000 c1605dd4
[    4.434196] 1ee0: c1605e38 00000001 00000000 00000000 c1605e44 c1601f24 c1601f18 c1601f18
[    4.442420] 1f00: c0438efc c0438f00 20000013 ffffffff
[    4.447504] [<c0d2ac3c>] (__irq_svc) from [<c0438f00>] (arch_cpu_idle+0x54/0x5c)
[    4.454948] [<c0438f00>] (arch_cpu_idle) from [<c0d28be4>] (default_idle_call+0x30/0x48)
[    4.463092] [<c0d28be4>] (default_idle_call) from [<c04cd5c0>] (do_idle+0x1a4/0x240)
[    4.470884] [<c04cd5c0>] (do_idle) from [<c04cd938>] (cpu_startup_entry+0x28/0x2c)
[    4.478501] [<c04cd938>] (cpu_startup_entry) from [<c0d225c0>] (rest_init+0xe0/0xe4)
[    4.486294] [<c0d225c0>] (rest_init) from [<c1400ea0>] (start_kernel+0x454/0x460)
[    4.493823] [<c1400ea0>] (start_kernel) from [<00000000>] (  (null))
[    4.500215] CPU2: stopping
[    4.502938] CPU: 2 PID: 0 Comm: swapper/2 Tainted: G      D          4.15.0-rc2-2.gef715eb-lpae #1
[    4.511945] Hardware name: BCM2835
[    4.515371] [<c0443eb0>] (unwind_backtrace) from [<c043ca40>] (show_stack+0x20/0x28)
[    4.523165] [<c043ca40>] (show_stack) from [<c0d0af38>] (dump_stack+0xb8/0xe4)
[    4.530434] [<c0d0af38>] (dump_stack) from [<c04404e8>] (handle_IPI+0x3bc/0x3cc)
[    4.537878] [<c04404e8>] (handle_IPI) from [<c0401638>] (bcm2836_arm_irqchip_handle_irq+0x84/0xbc)
[    4.546893] [<c0401638>] (bcm2836_arm_irqchip_handle_irq) from [<c0d2ac3c>] (__irq_svc+0x5c/0x94)
[    4.555814] Exception stack(0xef163f20 to 0xef163f68)
[    4.560896] 3f20: 00000001 00000000 2e2dc000 20000093 ffffe000 c1605dd4 c1605e38 00000004
[    4.569123] 3f40: 00000000 00000000 c1605e44 ef163f7c ef163f70 ef163f70 c0438efc c0438f00
[    4.577345] 3f60: 20000013 ffffffff
[    4.580855] [<c0d2ac3c>] (__irq_svc) from [<c0438f00>] (arch_cpu_idle+0x54/0x5c)
[    4.588298] [<c0438f00>] (arch_cpu_idle) from [<c0d28be4>] (default_idle_call+0x30/0x48)
[    4.596440] [<c0d28be4>] (default_idle_call) from [<c04cd5c0>] (do_idle+0x1a4/0x240)
[    4.604231] [<c04cd5c0>] (do_idle) from [<c04cd938>] (cpu_startup_entry+0x28/0x2c)
[    4.611850] [<c04cd938>] (cpu_startup_entry) from [<c043fe74>] (secondary_start_kernel+0x184/0x1b0)
[    4.620953] [<c043fe74>] (secondary_start_kernel) from [<00401eac>] (0x401eac)
[    4.628217] CPU3: stopping
[    4.630940] CPU: 3 PID: 0 Comm: swapper/3 Tainted: G      D          4.15.0-rc2-2.gef715eb-lpae #1
[    4.639948] Hardware name: BCM2835
[    4.643374] [<c0443eb0>] (unwind_backtrace) from [<c043ca40>] (show_stack+0x20/0x28)
[    4.651168] [<c043ca40>] (show_stack) from [<c0d0af38>] (dump_stack+0xb8/0xe4)
[    4.658438] [<c0d0af38>] (dump_stack) from [<c04404e8>] (handle_IPI+0x3bc/0x3cc)
[    4.665881] [<c04404e8>] (handle_IPI) from [<c0401638>] (bcm2836_arm_irqchip_handle_irq+0x84/0xbc)
[    4.674896] [<c0401638>] (bcm2836_arm_irqchip_handle_irq) from [<c0d2ac3c>] (__irq_svc+0x5c/0x94)
[    4.683817] Exception stack(0xef165f20 to 0xef165f68)
[    4.688899] 5f20: 00000001 00000000 2e2ee000 20000093 ffffe000 c1605dd4 c1605e38 00000008
[    4.697126] 5f40: 00000000 00000000 c1605e44 ef165f7c ef165f70 ef165f70 c0438efc c0438f00
[    4.705348] 5f60: 20000013 ffffffff
[    4.708859] [<c0d2ac3c>] (__irq_svc) from [<c0438f00>] (arch_cpu_idle+0x54/0x5c)
[    4.716302] [<c0438f00>] (arch_cpu_idle) from [<c0d28be4>] (default_idle_call+0x30/0x48)
[    4.724444] [<c0d28be4>] (default_idle_call) from [<c04cd5c0>] (do_idle+0x1a4/0x240)
[    4.732235] [<c04cd5c0>] (do_idle) from [<c04cd938>] (cpu_startup_entry+0x28/0x2c)
[    4.739854] [<c04cd938>] (cpu_startup_entry) from [<c043fe74>] (secondary_start_kernel+0x184/0x1b0)
[    4.748956] [<c043fe74>] (secondary_start_kernel) from [<00401eac>] (0x401eac)
[    4.756231] Rebooting in 90 seconds..
[   95.774608] Reboot failed -- System halted


[-- Attachment #3: Type: text/plain, Size: 151 bytes --]

_______________________________________________
kvmarm mailing list
kvmarm@lists.cs.columbia.edu
https://lists.cs.columbia.edu/mailman/listinfo/kvmarm