All of lore.kernel.org
 help / color / mirror / Atom feed
* 4.15-rc1 crash on Midway in teardown_hyp_mode()
@ 2017-12-06 14:11 ` Andre Przywara
  0 siblings, 0 replies; 11+ messages in thread
From: Andre Przywara @ 2017-12-06 14:11 UTC (permalink / raw)
  To: Marc Zyngier, Christoffer Dall
  Cc: Rob Herring, kvmarm, linux-arm-kernel, Eric Auger

Hi,

while trying to boot 4.15-rc1 on my Calxeda Midway I observed a crash
(see below). I can't look further into this today, but wanted to report
this anyway.

Digging around a bit this is due to the VGIC not initializing properly
due to GICC being advertised as just 4K, not 8K.
This can be worked around by adjusting the DT or using
irqchip.gicv2_force_probe. However this still raises some questions:
1) Even if the VGIC fails to register, we should certainly not crash.
The chain of events seems to be:
virt/kvm/arm/arm.c:init_subsystems():
  - kvm_vgic_hyp_init() returns -ENODEV, this leads to vgic_present
    being set to false, but "err" being reset to 0 (meaning: carry on).
    However this seems now to miss some initialization.
  - kvm_timer_hyp_init() now fails on calling irq_set_vcpu_affinity(),
    because this returns -ENOSYS. This leads to it returning this error,
    init_subsystems() failing and subsequently tearing down KVM.
  - This seems to have some bug and leads to the kernel crash.

Even with the VGIC not being usable, we should be able to cleanly tear
down KVM (or HYP?).

2) Is it intended that an unusable VGIC now denies KVM entirely? I
believe in the past we could live with that (no arch timer
virtualization, no in-kernel GIC emulation) and rely on userland
emulation (for instance in QEMU). This seemed to have changed now?
3) Wouldn't it be smarter to fix up the GICC range by default, if we
have enough evidence that the GICC is actually 8K? Shouldn't this be
true for every architecture compliant GICv2, actually? So whenever we
see "arm,cortex-a15-gic", for instance, we force GICC to 8K?
Or do we know of GICs which have only 4K, but advertise themselves
wrongly? Otherwise this could just go as some firmware quirk, based on a
compatible string, for instance, or some ID registers.

The reason I am asking is that the Midway loads the DT from firmware
flash, and this one hasn't changed in years (for obvious reasons). So
while *I* am able to update the DT in the SPI flash, I guess many users
just won't do so, so they are left with a crashing kernel (or loosing
KVM), starting from 4.15. All the previous kernels booted and ran KVM
guests fine in the past with the existing DT.

Cheers,
Andre.

----------------
Booting Linux on physical CPU 0x0
Linux version 4.15.0-rc2-00174-g328b4ed93b69-dirty
(andprz01@e104803-lin) (gcc version 5.3.0 (GCC)) #614 SMP Wed Dec 6
12:19:02 GMT 2017
CPU: ARMv7 Processor [413fc0f2] revision 2 (ARMv7), cr=30c5387d
CPU: div instructions available: patching division code
CPU: PIPT / VIPT nonaliasing data cache, PIPT instruction cache
OF: fdt: Machine model: Calxeda ECX-2000
Memory policy: Data cache writealloc
efi: Getting EFI parameters from FDT:
efi: UEFI not found.
cma: Reserved 64 MiB at 0x00000000fb800000
psci: probing for conduit method from DT.
psci: Using PSCI v0.1 Function IDs from DT
percpu: Embedded 18 pages/cpu @(ptrval) s42240 r8192 d23296 u73728
Built 1 zonelists, mobility grouping on.  Total pages: 2093568
Kernel command line: console=ttyAMA0,115200n8 ro root=/dev/sda7
Dentry cache hash table entries: 131072 (order: 7, 524288 bytes)
Inode-cache hash table entries: 65536 (order: 6, 262144 bytes)
Memory: 8225660K/8380416K available (12288K kernel code, 1565K rwdata,
4052K rodata, 2048K init, 564K bss, 89220K reserved, 65536K
cma-reserved, 7528448K highmem)
Virtual kernel memory layout:
    vector  : 0xffff0000 - 0xffff1000   (   4 kB)
    fixmap  : 0xffc00000 - 0xfff00000   (3072 kB)
    vmalloc : 0xf0800000 - 0xff800000   ( 240 MB)
    lowmem  : 0xc0000000 - 0xf0000000   ( 768 MB)
    pkmap   : 0xbfe00000 - 0xc0000000   (   2 MB)
    modules : 0xbf000000 - 0xbfe00000   (  14 MB)
      .text : 0x(ptrval) - 0x(ptrval)   (14304 kB)
      .init : 0x(ptrval) - 0x(ptrval)   (2048 kB)
      .data : 0x(ptrval) - 0x(ptrval)   (1566 kB)
       .bss : 0x(ptrval) - 0x(ptrval)   ( 565 kB)
SLUB: HWalign=128, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
ftrace: allocating 46629 entries in 137 pages
Hierarchical RCU implementation.
        RCU restricting CPUs from NR_CPUS=16 to nr_cpu_ids=4.
RCU: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4
NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
GIC: GICv2 detected, but range too small and irqchip.gicv2_force_probe
not set
arch_timer: cp15 timer(s) running at 150.00MHz (phys).
clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles:
0x2298375bd0, max_idle_ns: 440795208267 ns
sched_clock: 56 bits at 150MHz, resolution 6ns, wraps every 2199023255551ns
Switching to timer-based delay loop, resolution 6ns
clocksource: arm,sp804: mask: 0xffffffff max_cycles: 0xffffffff,
max_idle_ns: 12741736309 ns
sched_clock: 32 bits at 150MHz, resolution 6ns, wraps every 14316557820ns
Console: colour dummy device 80x30
Calibrating delay loop (skipped), value calculated using timer
frequency.. 300.00 BogoMIPS (lpj=1500000)
pid_max: default: 32768 minimum: 301
Mount-cache hash table entries: 2048 (order: 1, 8192 bytes)
Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes)
CPU: Testing write buffer coherency: ok
/cpus/cpu@0 missing clock-frequency property
/cpus/cpu@1 missing clock-frequency property
/cpus/cpu@2 missing clock-frequency property
/cpus/cpu@3 missing clock-frequency property
CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
Setting up static identity map for 0x400000 - 0x400178
Hierarchical SRCU implementation.
EFI services will not be available.
smp: Bringing up secondary CPUs ...
CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
CPU2: thread -1, cpu 2, socket 0, mpidr 80000002
CPU3: thread -1, cpu 3, socket 0, mpidr 80000003
smp: Brought up 1 node, 4 CPUs
SMP: Total of 4 processors activated (1200.00 BogoMIPS).
CPU: All CPU(s) started in HYP mode.
CPU: Virtualization extensions available.
devtmpfs: initialized
random: get_random_u32 called from bucket_table_alloc+0xf8/0x24c with
crng_init=0
VFP support v0.3: implementor 41 architecture 4 part 30 variant f rev 0
clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff,
max_idle_ns: 19112604462750000 ns
futex hash table entries: 1024 (order: 5, 131072 bytes)
pinctrl core: initialized pinctrl subsystem
DMI not present or invalid.
NET: Registered protocol family 16
DMA: preallocated 256 KiB pool for atomic coherent allocations
cpuidle: using governor ladder
cpuidle: using governor menu
hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
hw-breakpoint: maximum watchpoint size is 8 bytes.
Serial: AMBA PL011 UART driver
fff36000.serial: ttyAMA0 at MMIO 0xfff36000 (irq = 31, base_baud = 0) is
a PL011 rev3
console [ttyAMA0] enabled
AT91: Could not find identification node
vgaarb: loaded
SCSI subsystem initialized
usbcore: registered new interface driver usbfs
usbcore: registered new interface driver hub
usbcore: registered new device driver usb
pps_core: LinuxPPS API ver. 1 registered
pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti
<giometti@linux.it>
PTP clock support registered
EDAC MC: Ver: 3.0.0
dmi: Firmware registration failed.
clocksource: Switched to clocksource arch_sys_counter
NET: Registered protocol family 2
TCP established hash table entries: 8192 (order: 3, 32768 bytes)
TCP bind hash table entries: 8192 (order: 4, 65536 bytes)
TCP: Hash tables configured (established 8192 bind 8192)
UDP hash table entries: 512 (order: 2, 16384 bytes)
UDP-Lite hash table entries: 512 (order: 2, 16384 bytes)
NET: Registered protocol family 1
RPC: Registered named UNIX socket transport module.
RPC: Registered udp transport module.
RPC: Registered tcp transport module.
RPC: Registered tcp NFSv4.1 backchannel transport module.
kvm [1]: 8-bit VMID
kvm [1]: IDMAP page: 401000
kvm [1]: HYP VA range: c0000000:ffffffff
kvm_vgic_hyp_init() returns 0, vgic_present: 0
kvm [1]: == kvm_timer_hyp_init: host_vtimer_irq: 19
kvm [1]: == kvm_timer_hyp_init: host_vtimer_irq_flags: 8
kvm [1]: == kvm_timer_hyp_init: request_percpu_irq() returned 0
kvm [1]: kvm_arch_timer: error setting vcpu affinity: -38
disabling KVM arch hardware on each CPU
 ... done that.
Unable to handle kernel paging request at virtual address 40000000
pgd = (ptrval)
[40000000] *pgd=80000000205003, *pmd=00000000
Internal error: Oops: 206 [#1] SMP ARM
Modules linked in:
CPU: 1 PID: 1 Comm: swapper/0 Not tainted
4.15.0-rc2-00174-g328b4ed93b69-dirty #614
Hardware name: Highbank
PC is at unmap_hyp_range+0x15c/0x3f8
LR is at free_hyp_pgds+0x168/0x1a0
pc : [<c041a3a8>]    lr : [<c041bda8>]    psr: 80000013
sp : ed11fda0  ip : ed11fe10  fp : ed11fe0c
r10: 40000000  r9 : 00000000  r8 : 00000000
r7 : c19ba980  r6 : 00200000  r5 : 00000000  r4 : 3fffffff
r3 : 40000000  r2 : c19ba980  r1 : 00000000  r0 : 001fffff
Flags: Nzcv  IRQs on  FIQs on  Mode SVC_32  ISA ARM  Segment user
Control: 30c5387d  Table: 00203000  DAC: 55555555
Process swapper/0 (pid: 1, stack limit = 0x(ptrval))
Stack: (0xed11fda0 to 0xed120000)
fda0: 00000000 c19ba980 c13a5054 40000000 30800000 00000001 307fffff
00000001
fdc0: 40000000 00000000 ed1b7b40 ed1b3000 3fffffff 00000000 40000000
00000000
fde0: c19881f8 40000000 00000000 c19881f8 c19ba990 30800000 00000000
ffffffda
fe00: ed11fe3c ed11fe10 c041bda8 c041a258 40000000 00000000 c18053d0
c177c08c
fe20: 000053d0 0000585c c180585c c180585c ed11fe5c ed11fe40 c0417e4c
c041bc4c
fe40: c18053d0 00000010 c1988e48 c19881e8 ed11fe94 ed11fe60 c0419ee8
c0417e30
fe60: ed11febc 00000000 c1602568 c1987800 c0417e9c 00000000 00000000
00000ee8
fe80: c1987800 00000153 ed11fecc ed11fe98 c040c94c c0419c0c c1987800
c1987840
fea0: ed11febc ed11feb0 c1987800 c0417e9c c1600640 c16dc83c 00000000
c1987800
fec0: ed11fedc ed11fed0 c0417ec4 c040c930 ed11ff4c ed11fee0 c0402470
c0417ea8
fee0: c1600664 c0f5f9c8 c13f4f50 00000153 ed11ff4c ed11ff00 c0489724
c160064c
ff00: c129317c 00000006 00000006 00000000 c13f34d4 c136a0d8 efffca9c
efffcaa1
ff20: 00000000 c1987800 c16dc830 c1987800 c16dc834 c1600640 c16dc83c
00000006
ff40: ed11ff94 ed11ff50 c1600f74 c040242c 00000006 00000006 00000000
c1600640
ff60: 00000001 c177a164 00000000 00000000 c0f65544 00000000 00000000
00000000
ff80: 00000000 00000000 ed11ffac ed11ff98 c0f6555c c1600e2c 00000000
c0f65544
ffa0: 00000000 ed11ffb0 c042be58 c0f65550 00000000 00000000 00000000
00000000
ffc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000
00000000
ffe0: 00000000 00000000 00000000 00000000 00000013 00000000 ed11fff4
00000000
[<c041a3a8>] (unmap_hyp_range) from [<c041bda8>] (free_hyp_pgds+0x168/0x1a0)
[<c041bda8>] (free_hyp_pgds) from [<c0417e4c>] (teardown_hyp_mode+0x28/0x78)
[<c0417e4c>] (teardown_hyp_mode) from [<c0419ee8>]
(kvm_arch_init+0x2e8/0x51c)
[<c0419ee8>] (kvm_arch_init) from [<c040c94c>] (kvm_init+0x28/0x2bc)
[<c040c94c>] (kvm_init) from [<c0417ec4>] (arm_init+0x28/0x2c)
[<c0417ec4>] (arm_init) from [<c0402470>] (do_one_initcall+0x50/0x17c)
[<c0402470>] (do_one_initcall) from [<c1600f74>]
(kernel_init_freeable+0x154/0x1f4)
[<c1600f74>] (kernel_init_freeable) from [<c0f6555c>]
(kernel_init+0x18/0x124)
[<c0f6555c>] (kernel_init) from [<c042be58>] (ret_from_fork+0x14/0x3c)
Code: e1510005 e1a06a86 e2460001 01500004 (e1c300d0)
---[ end trace affbac93bd070906 ]---
Kernel panic - not syncing: Attempted to kill init! exitcode=0x0000000b

CPU3: stopping
CPU: 3 PID: 0 Comm: swapper/3 Tainted: G      D
4.15.0-rc2-00174-g328b4ed93b69-dirty #614
Hardware name: Highbank
[<c043644c>] (unwind_backtrace) from [<c04304ec>] (show_stack+0x20/0x24)
[<c04304ec>] (show_stack) from [<c0f4f034>] (dump_stack+0x98/0xac)
[<c0f4f034>] (dump_stack) from [<c0433f84>] (handle_IPI+0x2d0/0x350)
[<c0433f84>] (handle_IPI) from [<c0401954>] (gic_handle_irq+0xa8/0xac)
[<c0401954>] (gic_handle_irq) from [<c04310b8>] (__irq_svc+0x58/0x74)
Exception stack(0xed155f28 to 0xed155f70)
5f20:                   00000001 00000000 00000000 c0440ba0 c18052cc
ed154000
5f40: c1805338 00000008 c17847b8 00000000 00000000 ed155f84 ed155f88
ed155f78
5f60: c042c954 c042c958 60000013 ffffffff
[<c04310b8>] (__irq_svc) from [<c042c958>] (arch_cpu_idle+0x48/0x4c)
[<c042c958>] (arch_cpu_idle) from [<c0f6c7f8>] (default_idle_call+0x30/0x3c)
[<c0f6c7f8>] (default_idle_call) from [<c04aa33c>] (do_idle+0x194/0x228)
[<c04aa33c>] (do_idle) from [<c04aa67c>] (cpu_startup_entry+0x28/0x2c)
[<c04aa67c>] (cpu_startup_entry) from [<c0433a68>]
(secondary_start_kernel+0x160/0x16c)
[<c0433a68>] (secondary_start_kernel) from [<004021ec>] (0x4021ec)
CPU2: stopping
CPU: 2 PID: 0 Comm: swapper/2 Tainted: G      D
4.15.0-rc2-00174-g328b4ed93b69-dirty #614
Hardware name: Highbank
[<c043644c>] (unwind_backtrace) from [<c04304ec>] (show_stack+0x20/0x24)
[<c04304ec>] (show_stack) from [<c0f4f034>] (dump_stack+0x98/0xac)
[<c0f4f034>] (dump_stack) from [<c0433f84>] (handle_IPI+0x2d0/0x350)
[<c0433f84>] (handle_IPI) from [<c0401954>] (gic_handle_irq+0xa8/0xac)
[<c0401954>] (gic_handle_irq) from [<c04310b8>] (__irq_svc+0x58/0x74)
Exception stack(0xed153f28 to 0xed153f70)
3f20:                   00000001 00000000 00000000 c0440ba0 c18052cc
ed152000
3f40: c1805338 00000004 c17847b8 00000000 00000000 ed153f84 ed153f88
ed153f78
3f60: c042c954 c042c958 60000013 ffffffff
[<c04310b8>] (__irq_svc) from [<c042c958>] (arch_cpu_idle+0x48/0x4c)
[<c042c958>] (arch_cpu_idle) from [<c0f6c7f8>] (default_idle_call+0x30/0x3c)
[<c0f6c7f8>] (default_idle_call) from [<c04aa33c>] (do_idle+0x194/0x228)
[<c04aa33c>] (do_idle) from [<c04aa67c>] (cpu_startup_entry+0x28/0x2c)
[<c04aa67c>] (cpu_startup_entry) from [<c0433a68>]
(secondary_start_kernel+0x160/0x16c)
[<c0433a68>] (secondary_start_kernel) from [<004021ec>] (0x4021ec)
CPU0: stopping
CPU: 0 PID: 0 Comm: swapper/0 Tainted: G      D
4.15.0-rc2-00174-g328b4ed93b69-dirty #614
Hardware name: Highbank
[<c043644c>] (unwind_backtrace) from [<c04304ec>] (show_stack+0x20/0x24)
[<c04304ec>] (show_stack) from [<c0f4f034>] (dump_stack+0x98/0xac)
[<c0f4f034>] (dump_stack) from [<c0433f84>] (handle_IPI+0x2d0/0x350)
[<c0433f84>] (handle_IPI) from [<c0401954>] (gic_handle_irq+0xa8/0xac)
[<c0401954>] (gic_handle_irq) from [<c04310b8>] (__irq_svc+0x58/0x74)
Exception stack(0xc1801ed8 to 0xc1801f20)
1ec0:                                                       00000001
00000000
1ee0: 00000000 c0440ba0 c18052cc c1800000 c1805338 00000001 c17847b8
00000000
1f00: 00000000 c1801f34 c1801f38 c1801f28 c042c954 c042c958 60000013
ffffffff
[<c04310b8>] (__irq_svc) from [<c042c958>] (arch_cpu_idle+0x48/0x4c)
[<c042c958>] (arch_cpu_idle) from [<c0f6c7f8>] (default_idle_call+0x30/0x3c)
[<c0f6c7f8>] (default_idle_call) from [<c04aa33c>] (do_idle+0x194/0x228)
[<c04aa33c>] (do_idle) from [<c04aa67c>] (cpu_startup_entry+0x28/0x2c)
[<c04aa67c>] (cpu_startup_entry) from [<c0f65540>] (rest_init+0xbc/0xc0)
[<c0f65540>] (rest_init) from [<c1600e14>] (start_kernel+0x3d4/0x3e0)
[<c1600e14>] (start_kernel) from [<00000000>] (  (null))
---[ end Kernel panic - not syncing: Attempted to kill init!
exitcode=0x0000000b

^ permalink raw reply	[flat|nested] 11+ messages in thread

* 4.15-rc1 crash on Midway in teardown_hyp_mode()
@ 2017-12-06 14:11 ` Andre Przywara
  0 siblings, 0 replies; 11+ messages in thread
From: Andre Przywara @ 2017-12-06 14:11 UTC (permalink / raw)
  To: linux-arm-kernel

Hi,

while trying to boot 4.15-rc1 on my Calxeda Midway I observed a crash
(see below). I can't look further into this today, but wanted to report
this anyway.

Digging around a bit this is due to the VGIC not initializing properly
due to GICC being advertised as just 4K, not 8K.
This can be worked around by adjusting the DT or using
irqchip.gicv2_force_probe. However this still raises some questions:
1) Even if the VGIC fails to register, we should certainly not crash.
The chain of events seems to be:
virt/kvm/arm/arm.c:init_subsystems():
  - kvm_vgic_hyp_init() returns -ENODEV, this leads to vgic_present
    being set to false, but "err" being reset to 0 (meaning: carry on).
    However this seems now to miss some initialization.
  - kvm_timer_hyp_init() now fails on calling irq_set_vcpu_affinity(),
    because this returns -ENOSYS. This leads to it returning this error,
    init_subsystems() failing and subsequently tearing down KVM.
  - This seems to have some bug and leads to the kernel crash.

Even with the VGIC not being usable, we should be able to cleanly tear
down KVM (or HYP?).

2) Is it intended that an unusable VGIC now denies KVM entirely? I
believe in the past we could live with that (no arch timer
virtualization, no in-kernel GIC emulation) and rely on userland
emulation (for instance in QEMU). This seemed to have changed now?
3) Wouldn't it be smarter to fix up the GICC range by default, if we
have enough evidence that the GICC is actually 8K? Shouldn't this be
true for every architecture compliant GICv2, actually? So whenever we
see "arm,cortex-a15-gic", for instance, we force GICC to 8K?
Or do we know of GICs which have only 4K, but advertise themselves
wrongly? Otherwise this could just go as some firmware quirk, based on a
compatible string, for instance, or some ID registers.

The reason I am asking is that the Midway loads the DT from firmware
flash, and this one hasn't changed in years (for obvious reasons). So
while *I* am able to update the DT in the SPI flash, I guess many users
just won't do so, so they are left with a crashing kernel (or loosing
KVM), starting from 4.15. All the previous kernels booted and ran KVM
guests fine in the past with the existing DT.

Cheers,
Andre.

----------------
Booting Linux on physical CPU 0x0
Linux version 4.15.0-rc2-00174-g328b4ed93b69-dirty
(andprz01 at e104803-lin) (gcc version 5.3.0 (GCC)) #614 SMP Wed Dec 6
12:19:02 GMT 2017
CPU: ARMv7 Processor [413fc0f2] revision 2 (ARMv7), cr=30c5387d
CPU: div instructions available: patching division code
CPU: PIPT / VIPT nonaliasing data cache, PIPT instruction cache
OF: fdt: Machine model: Calxeda ECX-2000
Memory policy: Data cache writealloc
efi: Getting EFI parameters from FDT:
efi: UEFI not found.
cma: Reserved 64 MiB at 0x00000000fb800000
psci: probing for conduit method from DT.
psci: Using PSCI v0.1 Function IDs from DT
percpu: Embedded 18 pages/cpu @(ptrval) s42240 r8192 d23296 u73728
Built 1 zonelists, mobility grouping on.  Total pages: 2093568
Kernel command line: console=ttyAMA0,115200n8 ro root=/dev/sda7
Dentry cache hash table entries: 131072 (order: 7, 524288 bytes)
Inode-cache hash table entries: 65536 (order: 6, 262144 bytes)
Memory: 8225660K/8380416K available (12288K kernel code, 1565K rwdata,
4052K rodata, 2048K init, 564K bss, 89220K reserved, 65536K
cma-reserved, 7528448K highmem)
Virtual kernel memory layout:
    vector  : 0xffff0000 - 0xffff1000   (   4 kB)
    fixmap  : 0xffc00000 - 0xfff00000   (3072 kB)
    vmalloc : 0xf0800000 - 0xff800000   ( 240 MB)
    lowmem  : 0xc0000000 - 0xf0000000   ( 768 MB)
    pkmap   : 0xbfe00000 - 0xc0000000   (   2 MB)
    modules : 0xbf000000 - 0xbfe00000   (  14 MB)
      .text : 0x(ptrval) - 0x(ptrval)   (14304 kB)
      .init : 0x(ptrval) - 0x(ptrval)   (2048 kB)
      .data : 0x(ptrval) - 0x(ptrval)   (1566 kB)
       .bss : 0x(ptrval) - 0x(ptrval)   ( 565 kB)
SLUB: HWalign=128, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
ftrace: allocating 46629 entries in 137 pages
Hierarchical RCU implementation.
        RCU restricting CPUs from NR_CPUS=16 to nr_cpu_ids=4.
RCU: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4
NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
GIC: GICv2 detected, but range too small and irqchip.gicv2_force_probe
not set
arch_timer: cp15 timer(s) running at 150.00MHz (phys).
clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles:
0x2298375bd0, max_idle_ns: 440795208267 ns
sched_clock: 56 bits at 150MHz, resolution 6ns, wraps every 2199023255551ns
Switching to timer-based delay loop, resolution 6ns
clocksource: arm,sp804: mask: 0xffffffff max_cycles: 0xffffffff,
max_idle_ns: 12741736309 ns
sched_clock: 32 bits at 150MHz, resolution 6ns, wraps every 14316557820ns
Console: colour dummy device 80x30
Calibrating delay loop (skipped), value calculated using timer
frequency.. 300.00 BogoMIPS (lpj=1500000)
pid_max: default: 32768 minimum: 301
Mount-cache hash table entries: 2048 (order: 1, 8192 bytes)
Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes)
CPU: Testing write buffer coherency: ok
/cpus/cpu at 0 missing clock-frequency property
/cpus/cpu at 1 missing clock-frequency property
/cpus/cpu at 2 missing clock-frequency property
/cpus/cpu at 3 missing clock-frequency property
CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
Setting up static identity map for 0x400000 - 0x400178
Hierarchical SRCU implementation.
EFI services will not be available.
smp: Bringing up secondary CPUs ...
CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
CPU2: thread -1, cpu 2, socket 0, mpidr 80000002
CPU3: thread -1, cpu 3, socket 0, mpidr 80000003
smp: Brought up 1 node, 4 CPUs
SMP: Total of 4 processors activated (1200.00 BogoMIPS).
CPU: All CPU(s) started in HYP mode.
CPU: Virtualization extensions available.
devtmpfs: initialized
random: get_random_u32 called from bucket_table_alloc+0xf8/0x24c with
crng_init=0
VFP support v0.3: implementor 41 architecture 4 part 30 variant f rev 0
clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff,
max_idle_ns: 19112604462750000 ns
futex hash table entries: 1024 (order: 5, 131072 bytes)
pinctrl core: initialized pinctrl subsystem
DMI not present or invalid.
NET: Registered protocol family 16
DMA: preallocated 256 KiB pool for atomic coherent allocations
cpuidle: using governor ladder
cpuidle: using governor menu
hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
hw-breakpoint: maximum watchpoint size is 8 bytes.
Serial: AMBA PL011 UART driver
fff36000.serial: ttyAMA0 at MMIO 0xfff36000 (irq = 31, base_baud = 0) is
a PL011 rev3
console [ttyAMA0] enabled
AT91: Could not find identification node
vgaarb: loaded
SCSI subsystem initialized
usbcore: registered new interface driver usbfs
usbcore: registered new interface driver hub
usbcore: registered new device driver usb
pps_core: LinuxPPS API ver. 1 registered
pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti
<giometti@linux.it>
PTP clock support registered
EDAC MC: Ver: 3.0.0
dmi: Firmware registration failed.
clocksource: Switched to clocksource arch_sys_counter
NET: Registered protocol family 2
TCP established hash table entries: 8192 (order: 3, 32768 bytes)
TCP bind hash table entries: 8192 (order: 4, 65536 bytes)
TCP: Hash tables configured (established 8192 bind 8192)
UDP hash table entries: 512 (order: 2, 16384 bytes)
UDP-Lite hash table entries: 512 (order: 2, 16384 bytes)
NET: Registered protocol family 1
RPC: Registered named UNIX socket transport module.
RPC: Registered udp transport module.
RPC: Registered tcp transport module.
RPC: Registered tcp NFSv4.1 backchannel transport module.
kvm [1]: 8-bit VMID
kvm [1]: IDMAP page: 401000
kvm [1]: HYP VA range: c0000000:ffffffff
kvm_vgic_hyp_init() returns 0, vgic_present: 0
kvm [1]: == kvm_timer_hyp_init: host_vtimer_irq: 19
kvm [1]: == kvm_timer_hyp_init: host_vtimer_irq_flags: 8
kvm [1]: == kvm_timer_hyp_init: request_percpu_irq() returned 0
kvm [1]: kvm_arch_timer: error setting vcpu affinity: -38
disabling KVM arch hardware on each CPU
 ... done that.
Unable to handle kernel paging request at virtual address 40000000
pgd = (ptrval)
[40000000] *pgd=80000000205003, *pmd=00000000
Internal error: Oops: 206 [#1] SMP ARM
Modules linked in:
CPU: 1 PID: 1 Comm: swapper/0 Not tainted
4.15.0-rc2-00174-g328b4ed93b69-dirty #614
Hardware name: Highbank
PC is at unmap_hyp_range+0x15c/0x3f8
LR is at free_hyp_pgds+0x168/0x1a0
pc : [<c041a3a8>]    lr : [<c041bda8>]    psr: 80000013
sp : ed11fda0  ip : ed11fe10  fp : ed11fe0c
r10: 40000000  r9 : 00000000  r8 : 00000000
r7 : c19ba980  r6 : 00200000  r5 : 00000000  r4 : 3fffffff
r3 : 40000000  r2 : c19ba980  r1 : 00000000  r0 : 001fffff
Flags: Nzcv  IRQs on  FIQs on  Mode SVC_32  ISA ARM  Segment user
Control: 30c5387d  Table: 00203000  DAC: 55555555
Process swapper/0 (pid: 1, stack limit = 0x(ptrval))
Stack: (0xed11fda0 to 0xed120000)
fda0: 00000000 c19ba980 c13a5054 40000000 30800000 00000001 307fffff
00000001
fdc0: 40000000 00000000 ed1b7b40 ed1b3000 3fffffff 00000000 40000000
00000000
fde0: c19881f8 40000000 00000000 c19881f8 c19ba990 30800000 00000000
ffffffda
fe00: ed11fe3c ed11fe10 c041bda8 c041a258 40000000 00000000 c18053d0
c177c08c
fe20: 000053d0 0000585c c180585c c180585c ed11fe5c ed11fe40 c0417e4c
c041bc4c
fe40: c18053d0 00000010 c1988e48 c19881e8 ed11fe94 ed11fe60 c0419ee8
c0417e30
fe60: ed11febc 00000000 c1602568 c1987800 c0417e9c 00000000 00000000
00000ee8
fe80: c1987800 00000153 ed11fecc ed11fe98 c040c94c c0419c0c c1987800
c1987840
fea0: ed11febc ed11feb0 c1987800 c0417e9c c1600640 c16dc83c 00000000
c1987800
fec0: ed11fedc ed11fed0 c0417ec4 c040c930 ed11ff4c ed11fee0 c0402470
c0417ea8
fee0: c1600664 c0f5f9c8 c13f4f50 00000153 ed11ff4c ed11ff00 c0489724
c160064c
ff00: c129317c 00000006 00000006 00000000 c13f34d4 c136a0d8 efffca9c
efffcaa1
ff20: 00000000 c1987800 c16dc830 c1987800 c16dc834 c1600640 c16dc83c
00000006
ff40: ed11ff94 ed11ff50 c1600f74 c040242c 00000006 00000006 00000000
c1600640
ff60: 00000001 c177a164 00000000 00000000 c0f65544 00000000 00000000
00000000
ff80: 00000000 00000000 ed11ffac ed11ff98 c0f6555c c1600e2c 00000000
c0f65544
ffa0: 00000000 ed11ffb0 c042be58 c0f65550 00000000 00000000 00000000
00000000
ffc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000
00000000
ffe0: 00000000 00000000 00000000 00000000 00000013 00000000 ed11fff4
00000000
[<c041a3a8>] (unmap_hyp_range) from [<c041bda8>] (free_hyp_pgds+0x168/0x1a0)
[<c041bda8>] (free_hyp_pgds) from [<c0417e4c>] (teardown_hyp_mode+0x28/0x78)
[<c0417e4c>] (teardown_hyp_mode) from [<c0419ee8>]
(kvm_arch_init+0x2e8/0x51c)
[<c0419ee8>] (kvm_arch_init) from [<c040c94c>] (kvm_init+0x28/0x2bc)
[<c040c94c>] (kvm_init) from [<c0417ec4>] (arm_init+0x28/0x2c)
[<c0417ec4>] (arm_init) from [<c0402470>] (do_one_initcall+0x50/0x17c)
[<c0402470>] (do_one_initcall) from [<c1600f74>]
(kernel_init_freeable+0x154/0x1f4)
[<c1600f74>] (kernel_init_freeable) from [<c0f6555c>]
(kernel_init+0x18/0x124)
[<c0f6555c>] (kernel_init) from [<c042be58>] (ret_from_fork+0x14/0x3c)
Code: e1510005 e1a06a86 e2460001 01500004 (e1c300d0)
---[ end trace affbac93bd070906 ]---
Kernel panic - not syncing: Attempted to kill init! exitcode=0x0000000b

CPU3: stopping
CPU: 3 PID: 0 Comm: swapper/3 Tainted: G      D
4.15.0-rc2-00174-g328b4ed93b69-dirty #614
Hardware name: Highbank
[<c043644c>] (unwind_backtrace) from [<c04304ec>] (show_stack+0x20/0x24)
[<c04304ec>] (show_stack) from [<c0f4f034>] (dump_stack+0x98/0xac)
[<c0f4f034>] (dump_stack) from [<c0433f84>] (handle_IPI+0x2d0/0x350)
[<c0433f84>] (handle_IPI) from [<c0401954>] (gic_handle_irq+0xa8/0xac)
[<c0401954>] (gic_handle_irq) from [<c04310b8>] (__irq_svc+0x58/0x74)
Exception stack(0xed155f28 to 0xed155f70)
5f20:                   00000001 00000000 00000000 c0440ba0 c18052cc
ed154000
5f40: c1805338 00000008 c17847b8 00000000 00000000 ed155f84 ed155f88
ed155f78
5f60: c042c954 c042c958 60000013 ffffffff
[<c04310b8>] (__irq_svc) from [<c042c958>] (arch_cpu_idle+0x48/0x4c)
[<c042c958>] (arch_cpu_idle) from [<c0f6c7f8>] (default_idle_call+0x30/0x3c)
[<c0f6c7f8>] (default_idle_call) from [<c04aa33c>] (do_idle+0x194/0x228)
[<c04aa33c>] (do_idle) from [<c04aa67c>] (cpu_startup_entry+0x28/0x2c)
[<c04aa67c>] (cpu_startup_entry) from [<c0433a68>]
(secondary_start_kernel+0x160/0x16c)
[<c0433a68>] (secondary_start_kernel) from [<004021ec>] (0x4021ec)
CPU2: stopping
CPU: 2 PID: 0 Comm: swapper/2 Tainted: G      D
4.15.0-rc2-00174-g328b4ed93b69-dirty #614
Hardware name: Highbank
[<c043644c>] (unwind_backtrace) from [<c04304ec>] (show_stack+0x20/0x24)
[<c04304ec>] (show_stack) from [<c0f4f034>] (dump_stack+0x98/0xac)
[<c0f4f034>] (dump_stack) from [<c0433f84>] (handle_IPI+0x2d0/0x350)
[<c0433f84>] (handle_IPI) from [<c0401954>] (gic_handle_irq+0xa8/0xac)
[<c0401954>] (gic_handle_irq) from [<c04310b8>] (__irq_svc+0x58/0x74)
Exception stack(0xed153f28 to 0xed153f70)
3f20:                   00000001 00000000 00000000 c0440ba0 c18052cc
ed152000
3f40: c1805338 00000004 c17847b8 00000000 00000000 ed153f84 ed153f88
ed153f78
3f60: c042c954 c042c958 60000013 ffffffff
[<c04310b8>] (__irq_svc) from [<c042c958>] (arch_cpu_idle+0x48/0x4c)
[<c042c958>] (arch_cpu_idle) from [<c0f6c7f8>] (default_idle_call+0x30/0x3c)
[<c0f6c7f8>] (default_idle_call) from [<c04aa33c>] (do_idle+0x194/0x228)
[<c04aa33c>] (do_idle) from [<c04aa67c>] (cpu_startup_entry+0x28/0x2c)
[<c04aa67c>] (cpu_startup_entry) from [<c0433a68>]
(secondary_start_kernel+0x160/0x16c)
[<c0433a68>] (secondary_start_kernel) from [<004021ec>] (0x4021ec)
CPU0: stopping
CPU: 0 PID: 0 Comm: swapper/0 Tainted: G      D
4.15.0-rc2-00174-g328b4ed93b69-dirty #614
Hardware name: Highbank
[<c043644c>] (unwind_backtrace) from [<c04304ec>] (show_stack+0x20/0x24)
[<c04304ec>] (show_stack) from [<c0f4f034>] (dump_stack+0x98/0xac)
[<c0f4f034>] (dump_stack) from [<c0433f84>] (handle_IPI+0x2d0/0x350)
[<c0433f84>] (handle_IPI) from [<c0401954>] (gic_handle_irq+0xa8/0xac)
[<c0401954>] (gic_handle_irq) from [<c04310b8>] (__irq_svc+0x58/0x74)
Exception stack(0xc1801ed8 to 0xc1801f20)
1ec0:                                                       00000001
00000000
1ee0: 00000000 c0440ba0 c18052cc c1800000 c1805338 00000001 c17847b8
00000000
1f00: 00000000 c1801f34 c1801f38 c1801f28 c042c954 c042c958 60000013
ffffffff
[<c04310b8>] (__irq_svc) from [<c042c958>] (arch_cpu_idle+0x48/0x4c)
[<c042c958>] (arch_cpu_idle) from [<c0f6c7f8>] (default_idle_call+0x30/0x3c)
[<c0f6c7f8>] (default_idle_call) from [<c04aa33c>] (do_idle+0x194/0x228)
[<c04aa33c>] (do_idle) from [<c04aa67c>] (cpu_startup_entry+0x28/0x2c)
[<c04aa67c>] (cpu_startup_entry) from [<c0f65540>] (rest_init+0xbc/0xc0)
[<c0f65540>] (rest_init) from [<c1600e14>] (start_kernel+0x3d4/0x3e0)
[<c1600e14>] (start_kernel) from [<00000000>] (  (null))
---[ end Kernel panic - not syncing: Attempted to kill init!
exitcode=0x0000000b

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: 4.15-rc1 crash on Midway in teardown_hyp_mode()
  2017-12-06 14:11 ` Andre Przywara
@ 2017-12-06 14:17   ` Andre Przywara
  -1 siblings, 0 replies; 11+ messages in thread
From: Andre Przywara @ 2017-12-06 14:17 UTC (permalink / raw)
  To: Marc Zyngier, Christoffer Dall
  Cc: Rob Herring, kvmarm, linux-arm-kernel, Eric Auger

Hi,

On 06/12/17 14:11, Andre Przywara wrote:
> Hi,
> 
> while trying to boot 4.15-rc1 on my Calxeda Midway I observed a crash
> (see below). I can't look further into this today, but wanted to report
> this anyway.
> 
> Digging around a bit this is due to the VGIC not initializing properly
> due to GICC being advertised as just 4K, not 8K.
> This can be worked around by adjusting the DT or using
> irqchip.gicv2_force_probe. However this still raises some questions:
> 1) Even if the VGIC fails to register, we should certainly not crash.
> The chain of events seems to be:
> virt/kvm/arm/arm.c:init_subsystems():
>   - kvm_vgic_hyp_init() returns -ENODEV, this leads to vgic_present
>     being set to false, but "err" being reset to 0 (meaning: carry on).
>     However this seems now to miss some initialization.
>   - kvm_timer_hyp_init() now fails on calling irq_set_vcpu_affinity(),
>     because this returns -ENOSYS. This leads to it returning this error,
>     init_subsystems() failing and subsequently tearing down KVM.
>   - This seems to have some bug and leads to the kernel crash.
> 
> Even with the VGIC not being usable, we should be able to cleanly tear
> down KVM (or HYP?).

Just checked: If I let kvm_timer_hyp_init() deliberately fail in 4.14, I
get the same splat (4.14 works fine, otherwise). So this particular
issue existed already before. You should be able to reproduce it on any
box by forcing "err = -ENOSYS;" after the call to kvm_timer_hyp_init()
in virt/kvm/arm/arm.c:init_subsystems().

Cheers,
Andre

> 
> 2) Is it intended that an unusable VGIC now denies KVM entirely? I
> believe in the past we could live with that (no arch timer
> virtualization, no in-kernel GIC emulation) and rely on userland
> emulation (for instance in QEMU). This seemed to have changed now?
> 3) Wouldn't it be smarter to fix up the GICC range by default, if we
> have enough evidence that the GICC is actually 8K? Shouldn't this be
> true for every architecture compliant GICv2, actually? So whenever we
> see "arm,cortex-a15-gic", for instance, we force GICC to 8K?
> Or do we know of GICs which have only 4K, but advertise themselves
> wrongly? Otherwise this could just go as some firmware quirk, based on a
> compatible string, for instance, or some ID registers.
> 
> The reason I am asking is that the Midway loads the DT from firmware
> flash, and this one hasn't changed in years (for obvious reasons). So
> while *I* am able to update the DT in the SPI flash, I guess many users
> just won't do so, so they are left with a crashing kernel (or loosing
> KVM), starting from 4.15. All the previous kernels booted and ran KVM
> guests fine in the past with the existing DT.
> 
> Cheers,
> Andre.
> 
> ----------------
> Booting Linux on physical CPU 0x0
> Linux version 4.15.0-rc2-00174-g328b4ed93b69-dirty
> (andprz01@e104803-lin) (gcc version 5.3.0 (GCC)) #614 SMP Wed Dec 6
> 12:19:02 GMT 2017
> CPU: ARMv7 Processor [413fc0f2] revision 2 (ARMv7), cr=30c5387d
> CPU: div instructions available: patching division code
> CPU: PIPT / VIPT nonaliasing data cache, PIPT instruction cache
> OF: fdt: Machine model: Calxeda ECX-2000
> Memory policy: Data cache writealloc
> efi: Getting EFI parameters from FDT:
> efi: UEFI not found.
> cma: Reserved 64 MiB at 0x00000000fb800000
> psci: probing for conduit method from DT.
> psci: Using PSCI v0.1 Function IDs from DT
> percpu: Embedded 18 pages/cpu @(ptrval) s42240 r8192 d23296 u73728
> Built 1 zonelists, mobility grouping on.  Total pages: 2093568
> Kernel command line: console=ttyAMA0,115200n8 ro root=/dev/sda7
> Dentry cache hash table entries: 131072 (order: 7, 524288 bytes)
> Inode-cache hash table entries: 65536 (order: 6, 262144 bytes)
> Memory: 8225660K/8380416K available (12288K kernel code, 1565K rwdata,
> 4052K rodata, 2048K init, 564K bss, 89220K reserved, 65536K
> cma-reserved, 7528448K highmem)
> Virtual kernel memory layout:
>     vector  : 0xffff0000 - 0xffff1000   (   4 kB)
>     fixmap  : 0xffc00000 - 0xfff00000   (3072 kB)
>     vmalloc : 0xf0800000 - 0xff800000   ( 240 MB)
>     lowmem  : 0xc0000000 - 0xf0000000   ( 768 MB)
>     pkmap   : 0xbfe00000 - 0xc0000000   (   2 MB)
>     modules : 0xbf000000 - 0xbfe00000   (  14 MB)
>       .text : 0x(ptrval) - 0x(ptrval)   (14304 kB)
>       .init : 0x(ptrval) - 0x(ptrval)   (2048 kB)
>       .data : 0x(ptrval) - 0x(ptrval)   (1566 kB)
>        .bss : 0x(ptrval) - 0x(ptrval)   ( 565 kB)
> SLUB: HWalign=128, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
> ftrace: allocating 46629 entries in 137 pages
> Hierarchical RCU implementation.
>         RCU restricting CPUs from NR_CPUS=16 to nr_cpu_ids=4.
> RCU: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4
> NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
> GIC: GICv2 detected, but range too small and irqchip.gicv2_force_probe
> not set
> arch_timer: cp15 timer(s) running at 150.00MHz (phys).
> clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles:
> 0x2298375bd0, max_idle_ns: 440795208267 ns
> sched_clock: 56 bits at 150MHz, resolution 6ns, wraps every 2199023255551ns
> Switching to timer-based delay loop, resolution 6ns
> clocksource: arm,sp804: mask: 0xffffffff max_cycles: 0xffffffff,
> max_idle_ns: 12741736309 ns
> sched_clock: 32 bits at 150MHz, resolution 6ns, wraps every 14316557820ns
> Console: colour dummy device 80x30
> Calibrating delay loop (skipped), value calculated using timer
> frequency.. 300.00 BogoMIPS (lpj=1500000)
> pid_max: default: 32768 minimum: 301
> Mount-cache hash table entries: 2048 (order: 1, 8192 bytes)
> Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes)
> CPU: Testing write buffer coherency: ok
> /cpus/cpu@0 missing clock-frequency property
> /cpus/cpu@1 missing clock-frequency property
> /cpus/cpu@2 missing clock-frequency property
> /cpus/cpu@3 missing clock-frequency property
> CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
> Setting up static identity map for 0x400000 - 0x400178
> Hierarchical SRCU implementation.
> EFI services will not be available.
> smp: Bringing up secondary CPUs ...
> CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
> CPU2: thread -1, cpu 2, socket 0, mpidr 80000002
> CPU3: thread -1, cpu 3, socket 0, mpidr 80000003
> smp: Brought up 1 node, 4 CPUs
> SMP: Total of 4 processors activated (1200.00 BogoMIPS).
> CPU: All CPU(s) started in HYP mode.
> CPU: Virtualization extensions available.
> devtmpfs: initialized
> random: get_random_u32 called from bucket_table_alloc+0xf8/0x24c with
> crng_init=0
> VFP support v0.3: implementor 41 architecture 4 part 30 variant f rev 0
> clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff,
> max_idle_ns: 19112604462750000 ns
> futex hash table entries: 1024 (order: 5, 131072 bytes)
> pinctrl core: initialized pinctrl subsystem
> DMI not present or invalid.
> NET: Registered protocol family 16
> DMA: preallocated 256 KiB pool for atomic coherent allocations
> cpuidle: using governor ladder
> cpuidle: using governor menu
> hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
> hw-breakpoint: maximum watchpoint size is 8 bytes.
> Serial: AMBA PL011 UART driver
> fff36000.serial: ttyAMA0 at MMIO 0xfff36000 (irq = 31, base_baud = 0) is
> a PL011 rev3
> console [ttyAMA0] enabled
> AT91: Could not find identification node
> vgaarb: loaded
> SCSI subsystem initialized
> usbcore: registered new interface driver usbfs
> usbcore: registered new interface driver hub
> usbcore: registered new device driver usb
> pps_core: LinuxPPS API ver. 1 registered
> pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti
> <giometti@linux.it>
> PTP clock support registered
> EDAC MC: Ver: 3.0.0
> dmi: Firmware registration failed.
> clocksource: Switched to clocksource arch_sys_counter
> NET: Registered protocol family 2
> TCP established hash table entries: 8192 (order: 3, 32768 bytes)
> TCP bind hash table entries: 8192 (order: 4, 65536 bytes)
> TCP: Hash tables configured (established 8192 bind 8192)
> UDP hash table entries: 512 (order: 2, 16384 bytes)
> UDP-Lite hash table entries: 512 (order: 2, 16384 bytes)
> NET: Registered protocol family 1
> RPC: Registered named UNIX socket transport module.
> RPC: Registered udp transport module.
> RPC: Registered tcp transport module.
> RPC: Registered tcp NFSv4.1 backchannel transport module.
> kvm [1]: 8-bit VMID
> kvm [1]: IDMAP page: 401000
> kvm [1]: HYP VA range: c0000000:ffffffff
> kvm_vgic_hyp_init() returns 0, vgic_present: 0
> kvm [1]: == kvm_timer_hyp_init: host_vtimer_irq: 19
> kvm [1]: == kvm_timer_hyp_init: host_vtimer_irq_flags: 8
> kvm [1]: == kvm_timer_hyp_init: request_percpu_irq() returned 0
> kvm [1]: kvm_arch_timer: error setting vcpu affinity: -38
> disabling KVM arch hardware on each CPU
>  ... done that.
> Unable to handle kernel paging request at virtual address 40000000
> pgd = (ptrval)
> [40000000] *pgd=80000000205003, *pmd=00000000
> Internal error: Oops: 206 [#1] SMP ARM
> Modules linked in:
> CPU: 1 PID: 1 Comm: swapper/0 Not tainted
> 4.15.0-rc2-00174-g328b4ed93b69-dirty #614
> Hardware name: Highbank
> PC is at unmap_hyp_range+0x15c/0x3f8
> LR is at free_hyp_pgds+0x168/0x1a0
> pc : [<c041a3a8>]    lr : [<c041bda8>]    psr: 80000013
> sp : ed11fda0  ip : ed11fe10  fp : ed11fe0c
> r10: 40000000  r9 : 00000000  r8 : 00000000
> r7 : c19ba980  r6 : 00200000  r5 : 00000000  r4 : 3fffffff
> r3 : 40000000  r2 : c19ba980  r1 : 00000000  r0 : 001fffff
> Flags: Nzcv  IRQs on  FIQs on  Mode SVC_32  ISA ARM  Segment user
> Control: 30c5387d  Table: 00203000  DAC: 55555555
> Process swapper/0 (pid: 1, stack limit = 0x(ptrval))
> Stack: (0xed11fda0 to 0xed120000)
> fda0: 00000000 c19ba980 c13a5054 40000000 30800000 00000001 307fffff
> 00000001
> fdc0: 40000000 00000000 ed1b7b40 ed1b3000 3fffffff 00000000 40000000
> 00000000
> fde0: c19881f8 40000000 00000000 c19881f8 c19ba990 30800000 00000000
> ffffffda
> fe00: ed11fe3c ed11fe10 c041bda8 c041a258 40000000 00000000 c18053d0
> c177c08c
> fe20: 000053d0 0000585c c180585c c180585c ed11fe5c ed11fe40 c0417e4c
> c041bc4c
> fe40: c18053d0 00000010 c1988e48 c19881e8 ed11fe94 ed11fe60 c0419ee8
> c0417e30
> fe60: ed11febc 00000000 c1602568 c1987800 c0417e9c 00000000 00000000
> 00000ee8
> fe80: c1987800 00000153 ed11fecc ed11fe98 c040c94c c0419c0c c1987800
> c1987840
> fea0: ed11febc ed11feb0 c1987800 c0417e9c c1600640 c16dc83c 00000000
> c1987800
> fec0: ed11fedc ed11fed0 c0417ec4 c040c930 ed11ff4c ed11fee0 c0402470
> c0417ea8
> fee0: c1600664 c0f5f9c8 c13f4f50 00000153 ed11ff4c ed11ff00 c0489724
> c160064c
> ff00: c129317c 00000006 00000006 00000000 c13f34d4 c136a0d8 efffca9c
> efffcaa1
> ff20: 00000000 c1987800 c16dc830 c1987800 c16dc834 c1600640 c16dc83c
> 00000006
> ff40: ed11ff94 ed11ff50 c1600f74 c040242c 00000006 00000006 00000000
> c1600640
> ff60: 00000001 c177a164 00000000 00000000 c0f65544 00000000 00000000
> 00000000
> ff80: 00000000 00000000 ed11ffac ed11ff98 c0f6555c c1600e2c 00000000
> c0f65544
> ffa0: 00000000 ed11ffb0 c042be58 c0f65550 00000000 00000000 00000000
> 00000000
> ffc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000
> 00000000
> ffe0: 00000000 00000000 00000000 00000000 00000013 00000000 ed11fff4
> 00000000
> [<c041a3a8>] (unmap_hyp_range) from [<c041bda8>] (free_hyp_pgds+0x168/0x1a0)
> [<c041bda8>] (free_hyp_pgds) from [<c0417e4c>] (teardown_hyp_mode+0x28/0x78)
> [<c0417e4c>] (teardown_hyp_mode) from [<c0419ee8>]
> (kvm_arch_init+0x2e8/0x51c)
> [<c0419ee8>] (kvm_arch_init) from [<c040c94c>] (kvm_init+0x28/0x2bc)
> [<c040c94c>] (kvm_init) from [<c0417ec4>] (arm_init+0x28/0x2c)
> [<c0417ec4>] (arm_init) from [<c0402470>] (do_one_initcall+0x50/0x17c)
> [<c0402470>] (do_one_initcall) from [<c1600f74>]
> (kernel_init_freeable+0x154/0x1f4)
> [<c1600f74>] (kernel_init_freeable) from [<c0f6555c>]
> (kernel_init+0x18/0x124)
> [<c0f6555c>] (kernel_init) from [<c042be58>] (ret_from_fork+0x14/0x3c)
> Code: e1510005 e1a06a86 e2460001 01500004 (e1c300d0)
> ---[ end trace affbac93bd070906 ]---
> Kernel panic - not syncing: Attempted to kill init! exitcode=0x0000000b
> 
> CPU3: stopping
> CPU: 3 PID: 0 Comm: swapper/3 Tainted: G      D
> 4.15.0-rc2-00174-g328b4ed93b69-dirty #614
> Hardware name: Highbank
> [<c043644c>] (unwind_backtrace) from [<c04304ec>] (show_stack+0x20/0x24)
> [<c04304ec>] (show_stack) from [<c0f4f034>] (dump_stack+0x98/0xac)
> [<c0f4f034>] (dump_stack) from [<c0433f84>] (handle_IPI+0x2d0/0x350)
> [<c0433f84>] (handle_IPI) from [<c0401954>] (gic_handle_irq+0xa8/0xac)
> [<c0401954>] (gic_handle_irq) from [<c04310b8>] (__irq_svc+0x58/0x74)
> Exception stack(0xed155f28 to 0xed155f70)
> 5f20:                   00000001 00000000 00000000 c0440ba0 c18052cc
> ed154000
> 5f40: c1805338 00000008 c17847b8 00000000 00000000 ed155f84 ed155f88
> ed155f78
> 5f60: c042c954 c042c958 60000013 ffffffff
> [<c04310b8>] (__irq_svc) from [<c042c958>] (arch_cpu_idle+0x48/0x4c)
> [<c042c958>] (arch_cpu_idle) from [<c0f6c7f8>] (default_idle_call+0x30/0x3c)
> [<c0f6c7f8>] (default_idle_call) from [<c04aa33c>] (do_idle+0x194/0x228)
> [<c04aa33c>] (do_idle) from [<c04aa67c>] (cpu_startup_entry+0x28/0x2c)
> [<c04aa67c>] (cpu_startup_entry) from [<c0433a68>]
> (secondary_start_kernel+0x160/0x16c)
> [<c0433a68>] (secondary_start_kernel) from [<004021ec>] (0x4021ec)
> CPU2: stopping
> CPU: 2 PID: 0 Comm: swapper/2 Tainted: G      D
> 4.15.0-rc2-00174-g328b4ed93b69-dirty #614
> Hardware name: Highbank
> [<c043644c>] (unwind_backtrace) from [<c04304ec>] (show_stack+0x20/0x24)
> [<c04304ec>] (show_stack) from [<c0f4f034>] (dump_stack+0x98/0xac)
> [<c0f4f034>] (dump_stack) from [<c0433f84>] (handle_IPI+0x2d0/0x350)
> [<c0433f84>] (handle_IPI) from [<c0401954>] (gic_handle_irq+0xa8/0xac)
> [<c0401954>] (gic_handle_irq) from [<c04310b8>] (__irq_svc+0x58/0x74)
> Exception stack(0xed153f28 to 0xed153f70)
> 3f20:                   00000001 00000000 00000000 c0440ba0 c18052cc
> ed152000
> 3f40: c1805338 00000004 c17847b8 00000000 00000000 ed153f84 ed153f88
> ed153f78
> 3f60: c042c954 c042c958 60000013 ffffffff
> [<c04310b8>] (__irq_svc) from [<c042c958>] (arch_cpu_idle+0x48/0x4c)
> [<c042c958>] (arch_cpu_idle) from [<c0f6c7f8>] (default_idle_call+0x30/0x3c)
> [<c0f6c7f8>] (default_idle_call) from [<c04aa33c>] (do_idle+0x194/0x228)
> [<c04aa33c>] (do_idle) from [<c04aa67c>] (cpu_startup_entry+0x28/0x2c)
> [<c04aa67c>] (cpu_startup_entry) from [<c0433a68>]
> (secondary_start_kernel+0x160/0x16c)
> [<c0433a68>] (secondary_start_kernel) from [<004021ec>] (0x4021ec)
> CPU0: stopping
> CPU: 0 PID: 0 Comm: swapper/0 Tainted: G      D
> 4.15.0-rc2-00174-g328b4ed93b69-dirty #614
> Hardware name: Highbank
> [<c043644c>] (unwind_backtrace) from [<c04304ec>] (show_stack+0x20/0x24)
> [<c04304ec>] (show_stack) from [<c0f4f034>] (dump_stack+0x98/0xac)
> [<c0f4f034>] (dump_stack) from [<c0433f84>] (handle_IPI+0x2d0/0x350)
> [<c0433f84>] (handle_IPI) from [<c0401954>] (gic_handle_irq+0xa8/0xac)
> [<c0401954>] (gic_handle_irq) from [<c04310b8>] (__irq_svc+0x58/0x74)
> Exception stack(0xc1801ed8 to 0xc1801f20)
> 1ec0:                                                       00000001
> 00000000
> 1ee0: 00000000 c0440ba0 c18052cc c1800000 c1805338 00000001 c17847b8
> 00000000
> 1f00: 00000000 c1801f34 c1801f38 c1801f28 c042c954 c042c958 60000013
> ffffffff
> [<c04310b8>] (__irq_svc) from [<c042c958>] (arch_cpu_idle+0x48/0x4c)
> [<c042c958>] (arch_cpu_idle) from [<c0f6c7f8>] (default_idle_call+0x30/0x3c)
> [<c0f6c7f8>] (default_idle_call) from [<c04aa33c>] (do_idle+0x194/0x228)
> [<c04aa33c>] (do_idle) from [<c04aa67c>] (cpu_startup_entry+0x28/0x2c)
> [<c04aa67c>] (cpu_startup_entry) from [<c0f65540>] (rest_init+0xbc/0xc0)
> [<c0f65540>] (rest_init) from [<c1600e14>] (start_kernel+0x3d4/0x3e0)
> [<c1600e14>] (start_kernel) from [<00000000>] (  (null))
> ---[ end Kernel panic - not syncing: Attempted to kill init!
> exitcode=0x0000000b
> 

^ permalink raw reply	[flat|nested] 11+ messages in thread

* 4.15-rc1 crash on Midway in teardown_hyp_mode()
@ 2017-12-06 14:17   ` Andre Przywara
  0 siblings, 0 replies; 11+ messages in thread
From: Andre Przywara @ 2017-12-06 14:17 UTC (permalink / raw)
  To: linux-arm-kernel

Hi,

On 06/12/17 14:11, Andre Przywara wrote:
> Hi,
> 
> while trying to boot 4.15-rc1 on my Calxeda Midway I observed a crash
> (see below). I can't look further into this today, but wanted to report
> this anyway.
> 
> Digging around a bit this is due to the VGIC not initializing properly
> due to GICC being advertised as just 4K, not 8K.
> This can be worked around by adjusting the DT or using
> irqchip.gicv2_force_probe. However this still raises some questions:
> 1) Even if the VGIC fails to register, we should certainly not crash.
> The chain of events seems to be:
> virt/kvm/arm/arm.c:init_subsystems():
>   - kvm_vgic_hyp_init() returns -ENODEV, this leads to vgic_present
>     being set to false, but "err" being reset to 0 (meaning: carry on).
>     However this seems now to miss some initialization.
>   - kvm_timer_hyp_init() now fails on calling irq_set_vcpu_affinity(),
>     because this returns -ENOSYS. This leads to it returning this error,
>     init_subsystems() failing and subsequently tearing down KVM.
>   - This seems to have some bug and leads to the kernel crash.
> 
> Even with the VGIC not being usable, we should be able to cleanly tear
> down KVM (or HYP?).

Just checked: If I let kvm_timer_hyp_init() deliberately fail in 4.14, I
get the same splat (4.14 works fine, otherwise). So this particular
issue existed already before. You should be able to reproduce it on any
box by forcing "err = -ENOSYS;" after the call to kvm_timer_hyp_init()
in virt/kvm/arm/arm.c:init_subsystems().

Cheers,
Andre

> 
> 2) Is it intended that an unusable VGIC now denies KVM entirely? I
> believe in the past we could live with that (no arch timer
> virtualization, no in-kernel GIC emulation) and rely on userland
> emulation (for instance in QEMU). This seemed to have changed now?
> 3) Wouldn't it be smarter to fix up the GICC range by default, if we
> have enough evidence that the GICC is actually 8K? Shouldn't this be
> true for every architecture compliant GICv2, actually? So whenever we
> see "arm,cortex-a15-gic", for instance, we force GICC to 8K?
> Or do we know of GICs which have only 4K, but advertise themselves
> wrongly? Otherwise this could just go as some firmware quirk, based on a
> compatible string, for instance, or some ID registers.
> 
> The reason I am asking is that the Midway loads the DT from firmware
> flash, and this one hasn't changed in years (for obvious reasons). So
> while *I* am able to update the DT in the SPI flash, I guess many users
> just won't do so, so they are left with a crashing kernel (or loosing
> KVM), starting from 4.15. All the previous kernels booted and ran KVM
> guests fine in the past with the existing DT.
> 
> Cheers,
> Andre.
> 
> ----------------
> Booting Linux on physical CPU 0x0
> Linux version 4.15.0-rc2-00174-g328b4ed93b69-dirty
> (andprz01 at e104803-lin) (gcc version 5.3.0 (GCC)) #614 SMP Wed Dec 6
> 12:19:02 GMT 2017
> CPU: ARMv7 Processor [413fc0f2] revision 2 (ARMv7), cr=30c5387d
> CPU: div instructions available: patching division code
> CPU: PIPT / VIPT nonaliasing data cache, PIPT instruction cache
> OF: fdt: Machine model: Calxeda ECX-2000
> Memory policy: Data cache writealloc
> efi: Getting EFI parameters from FDT:
> efi: UEFI not found.
> cma: Reserved 64 MiB at 0x00000000fb800000
> psci: probing for conduit method from DT.
> psci: Using PSCI v0.1 Function IDs from DT
> percpu: Embedded 18 pages/cpu @(ptrval) s42240 r8192 d23296 u73728
> Built 1 zonelists, mobility grouping on.  Total pages: 2093568
> Kernel command line: console=ttyAMA0,115200n8 ro root=/dev/sda7
> Dentry cache hash table entries: 131072 (order: 7, 524288 bytes)
> Inode-cache hash table entries: 65536 (order: 6, 262144 bytes)
> Memory: 8225660K/8380416K available (12288K kernel code, 1565K rwdata,
> 4052K rodata, 2048K init, 564K bss, 89220K reserved, 65536K
> cma-reserved, 7528448K highmem)
> Virtual kernel memory layout:
>     vector  : 0xffff0000 - 0xffff1000   (   4 kB)
>     fixmap  : 0xffc00000 - 0xfff00000   (3072 kB)
>     vmalloc : 0xf0800000 - 0xff800000   ( 240 MB)
>     lowmem  : 0xc0000000 - 0xf0000000   ( 768 MB)
>     pkmap   : 0xbfe00000 - 0xc0000000   (   2 MB)
>     modules : 0xbf000000 - 0xbfe00000   (  14 MB)
>       .text : 0x(ptrval) - 0x(ptrval)   (14304 kB)
>       .init : 0x(ptrval) - 0x(ptrval)   (2048 kB)
>       .data : 0x(ptrval) - 0x(ptrval)   (1566 kB)
>        .bss : 0x(ptrval) - 0x(ptrval)   ( 565 kB)
> SLUB: HWalign=128, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
> ftrace: allocating 46629 entries in 137 pages
> Hierarchical RCU implementation.
>         RCU restricting CPUs from NR_CPUS=16 to nr_cpu_ids=4.
> RCU: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4
> NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
> GIC: GICv2 detected, but range too small and irqchip.gicv2_force_probe
> not set
> arch_timer: cp15 timer(s) running at 150.00MHz (phys).
> clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles:
> 0x2298375bd0, max_idle_ns: 440795208267 ns
> sched_clock: 56 bits at 150MHz, resolution 6ns, wraps every 2199023255551ns
> Switching to timer-based delay loop, resolution 6ns
> clocksource: arm,sp804: mask: 0xffffffff max_cycles: 0xffffffff,
> max_idle_ns: 12741736309 ns
> sched_clock: 32 bits at 150MHz, resolution 6ns, wraps every 14316557820ns
> Console: colour dummy device 80x30
> Calibrating delay loop (skipped), value calculated using timer
> frequency.. 300.00 BogoMIPS (lpj=1500000)
> pid_max: default: 32768 minimum: 301
> Mount-cache hash table entries: 2048 (order: 1, 8192 bytes)
> Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes)
> CPU: Testing write buffer coherency: ok
> /cpus/cpu at 0 missing clock-frequency property
> /cpus/cpu at 1 missing clock-frequency property
> /cpus/cpu at 2 missing clock-frequency property
> /cpus/cpu at 3 missing clock-frequency property
> CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
> Setting up static identity map for 0x400000 - 0x400178
> Hierarchical SRCU implementation.
> EFI services will not be available.
> smp: Bringing up secondary CPUs ...
> CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
> CPU2: thread -1, cpu 2, socket 0, mpidr 80000002
> CPU3: thread -1, cpu 3, socket 0, mpidr 80000003
> smp: Brought up 1 node, 4 CPUs
> SMP: Total of 4 processors activated (1200.00 BogoMIPS).
> CPU: All CPU(s) started in HYP mode.
> CPU: Virtualization extensions available.
> devtmpfs: initialized
> random: get_random_u32 called from bucket_table_alloc+0xf8/0x24c with
> crng_init=0
> VFP support v0.3: implementor 41 architecture 4 part 30 variant f rev 0
> clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff,
> max_idle_ns: 19112604462750000 ns
> futex hash table entries: 1024 (order: 5, 131072 bytes)
> pinctrl core: initialized pinctrl subsystem
> DMI not present or invalid.
> NET: Registered protocol family 16
> DMA: preallocated 256 KiB pool for atomic coherent allocations
> cpuidle: using governor ladder
> cpuidle: using governor menu
> hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
> hw-breakpoint: maximum watchpoint size is 8 bytes.
> Serial: AMBA PL011 UART driver
> fff36000.serial: ttyAMA0 at MMIO 0xfff36000 (irq = 31, base_baud = 0) is
> a PL011 rev3
> console [ttyAMA0] enabled
> AT91: Could not find identification node
> vgaarb: loaded
> SCSI subsystem initialized
> usbcore: registered new interface driver usbfs
> usbcore: registered new interface driver hub
> usbcore: registered new device driver usb
> pps_core: LinuxPPS API ver. 1 registered
> pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti
> <giometti@linux.it>
> PTP clock support registered
> EDAC MC: Ver: 3.0.0
> dmi: Firmware registration failed.
> clocksource: Switched to clocksource arch_sys_counter
> NET: Registered protocol family 2
> TCP established hash table entries: 8192 (order: 3, 32768 bytes)
> TCP bind hash table entries: 8192 (order: 4, 65536 bytes)
> TCP: Hash tables configured (established 8192 bind 8192)
> UDP hash table entries: 512 (order: 2, 16384 bytes)
> UDP-Lite hash table entries: 512 (order: 2, 16384 bytes)
> NET: Registered protocol family 1
> RPC: Registered named UNIX socket transport module.
> RPC: Registered udp transport module.
> RPC: Registered tcp transport module.
> RPC: Registered tcp NFSv4.1 backchannel transport module.
> kvm [1]: 8-bit VMID
> kvm [1]: IDMAP page: 401000
> kvm [1]: HYP VA range: c0000000:ffffffff
> kvm_vgic_hyp_init() returns 0, vgic_present: 0
> kvm [1]: == kvm_timer_hyp_init: host_vtimer_irq: 19
> kvm [1]: == kvm_timer_hyp_init: host_vtimer_irq_flags: 8
> kvm [1]: == kvm_timer_hyp_init: request_percpu_irq() returned 0
> kvm [1]: kvm_arch_timer: error setting vcpu affinity: -38
> disabling KVM arch hardware on each CPU
>  ... done that.
> Unable to handle kernel paging request at virtual address 40000000
> pgd = (ptrval)
> [40000000] *pgd=80000000205003, *pmd=00000000
> Internal error: Oops: 206 [#1] SMP ARM
> Modules linked in:
> CPU: 1 PID: 1 Comm: swapper/0 Not tainted
> 4.15.0-rc2-00174-g328b4ed93b69-dirty #614
> Hardware name: Highbank
> PC is at unmap_hyp_range+0x15c/0x3f8
> LR is at free_hyp_pgds+0x168/0x1a0
> pc : [<c041a3a8>]    lr : [<c041bda8>]    psr: 80000013
> sp : ed11fda0  ip : ed11fe10  fp : ed11fe0c
> r10: 40000000  r9 : 00000000  r8 : 00000000
> r7 : c19ba980  r6 : 00200000  r5 : 00000000  r4 : 3fffffff
> r3 : 40000000  r2 : c19ba980  r1 : 00000000  r0 : 001fffff
> Flags: Nzcv  IRQs on  FIQs on  Mode SVC_32  ISA ARM  Segment user
> Control: 30c5387d  Table: 00203000  DAC: 55555555
> Process swapper/0 (pid: 1, stack limit = 0x(ptrval))
> Stack: (0xed11fda0 to 0xed120000)
> fda0: 00000000 c19ba980 c13a5054 40000000 30800000 00000001 307fffff
> 00000001
> fdc0: 40000000 00000000 ed1b7b40 ed1b3000 3fffffff 00000000 40000000
> 00000000
> fde0: c19881f8 40000000 00000000 c19881f8 c19ba990 30800000 00000000
> ffffffda
> fe00: ed11fe3c ed11fe10 c041bda8 c041a258 40000000 00000000 c18053d0
> c177c08c
> fe20: 000053d0 0000585c c180585c c180585c ed11fe5c ed11fe40 c0417e4c
> c041bc4c
> fe40: c18053d0 00000010 c1988e48 c19881e8 ed11fe94 ed11fe60 c0419ee8
> c0417e30
> fe60: ed11febc 00000000 c1602568 c1987800 c0417e9c 00000000 00000000
> 00000ee8
> fe80: c1987800 00000153 ed11fecc ed11fe98 c040c94c c0419c0c c1987800
> c1987840
> fea0: ed11febc ed11feb0 c1987800 c0417e9c c1600640 c16dc83c 00000000
> c1987800
> fec0: ed11fedc ed11fed0 c0417ec4 c040c930 ed11ff4c ed11fee0 c0402470
> c0417ea8
> fee0: c1600664 c0f5f9c8 c13f4f50 00000153 ed11ff4c ed11ff00 c0489724
> c160064c
> ff00: c129317c 00000006 00000006 00000000 c13f34d4 c136a0d8 efffca9c
> efffcaa1
> ff20: 00000000 c1987800 c16dc830 c1987800 c16dc834 c1600640 c16dc83c
> 00000006
> ff40: ed11ff94 ed11ff50 c1600f74 c040242c 00000006 00000006 00000000
> c1600640
> ff60: 00000001 c177a164 00000000 00000000 c0f65544 00000000 00000000
> 00000000
> ff80: 00000000 00000000 ed11ffac ed11ff98 c0f6555c c1600e2c 00000000
> c0f65544
> ffa0: 00000000 ed11ffb0 c042be58 c0f65550 00000000 00000000 00000000
> 00000000
> ffc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000
> 00000000
> ffe0: 00000000 00000000 00000000 00000000 00000013 00000000 ed11fff4
> 00000000
> [<c041a3a8>] (unmap_hyp_range) from [<c041bda8>] (free_hyp_pgds+0x168/0x1a0)
> [<c041bda8>] (free_hyp_pgds) from [<c0417e4c>] (teardown_hyp_mode+0x28/0x78)
> [<c0417e4c>] (teardown_hyp_mode) from [<c0419ee8>]
> (kvm_arch_init+0x2e8/0x51c)
> [<c0419ee8>] (kvm_arch_init) from [<c040c94c>] (kvm_init+0x28/0x2bc)
> [<c040c94c>] (kvm_init) from [<c0417ec4>] (arm_init+0x28/0x2c)
> [<c0417ec4>] (arm_init) from [<c0402470>] (do_one_initcall+0x50/0x17c)
> [<c0402470>] (do_one_initcall) from [<c1600f74>]
> (kernel_init_freeable+0x154/0x1f4)
> [<c1600f74>] (kernel_init_freeable) from [<c0f6555c>]
> (kernel_init+0x18/0x124)
> [<c0f6555c>] (kernel_init) from [<c042be58>] (ret_from_fork+0x14/0x3c)
> Code: e1510005 e1a06a86 e2460001 01500004 (e1c300d0)
> ---[ end trace affbac93bd070906 ]---
> Kernel panic - not syncing: Attempted to kill init! exitcode=0x0000000b
> 
> CPU3: stopping
> CPU: 3 PID: 0 Comm: swapper/3 Tainted: G      D
> 4.15.0-rc2-00174-g328b4ed93b69-dirty #614
> Hardware name: Highbank
> [<c043644c>] (unwind_backtrace) from [<c04304ec>] (show_stack+0x20/0x24)
> [<c04304ec>] (show_stack) from [<c0f4f034>] (dump_stack+0x98/0xac)
> [<c0f4f034>] (dump_stack) from [<c0433f84>] (handle_IPI+0x2d0/0x350)
> [<c0433f84>] (handle_IPI) from [<c0401954>] (gic_handle_irq+0xa8/0xac)
> [<c0401954>] (gic_handle_irq) from [<c04310b8>] (__irq_svc+0x58/0x74)
> Exception stack(0xed155f28 to 0xed155f70)
> 5f20:                   00000001 00000000 00000000 c0440ba0 c18052cc
> ed154000
> 5f40: c1805338 00000008 c17847b8 00000000 00000000 ed155f84 ed155f88
> ed155f78
> 5f60: c042c954 c042c958 60000013 ffffffff
> [<c04310b8>] (__irq_svc) from [<c042c958>] (arch_cpu_idle+0x48/0x4c)
> [<c042c958>] (arch_cpu_idle) from [<c0f6c7f8>] (default_idle_call+0x30/0x3c)
> [<c0f6c7f8>] (default_idle_call) from [<c04aa33c>] (do_idle+0x194/0x228)
> [<c04aa33c>] (do_idle) from [<c04aa67c>] (cpu_startup_entry+0x28/0x2c)
> [<c04aa67c>] (cpu_startup_entry) from [<c0433a68>]
> (secondary_start_kernel+0x160/0x16c)
> [<c0433a68>] (secondary_start_kernel) from [<004021ec>] (0x4021ec)
> CPU2: stopping
> CPU: 2 PID: 0 Comm: swapper/2 Tainted: G      D
> 4.15.0-rc2-00174-g328b4ed93b69-dirty #614
> Hardware name: Highbank
> [<c043644c>] (unwind_backtrace) from [<c04304ec>] (show_stack+0x20/0x24)
> [<c04304ec>] (show_stack) from [<c0f4f034>] (dump_stack+0x98/0xac)
> [<c0f4f034>] (dump_stack) from [<c0433f84>] (handle_IPI+0x2d0/0x350)
> [<c0433f84>] (handle_IPI) from [<c0401954>] (gic_handle_irq+0xa8/0xac)
> [<c0401954>] (gic_handle_irq) from [<c04310b8>] (__irq_svc+0x58/0x74)
> Exception stack(0xed153f28 to 0xed153f70)
> 3f20:                   00000001 00000000 00000000 c0440ba0 c18052cc
> ed152000
> 3f40: c1805338 00000004 c17847b8 00000000 00000000 ed153f84 ed153f88
> ed153f78
> 3f60: c042c954 c042c958 60000013 ffffffff
> [<c04310b8>] (__irq_svc) from [<c042c958>] (arch_cpu_idle+0x48/0x4c)
> [<c042c958>] (arch_cpu_idle) from [<c0f6c7f8>] (default_idle_call+0x30/0x3c)
> [<c0f6c7f8>] (default_idle_call) from [<c04aa33c>] (do_idle+0x194/0x228)
> [<c04aa33c>] (do_idle) from [<c04aa67c>] (cpu_startup_entry+0x28/0x2c)
> [<c04aa67c>] (cpu_startup_entry) from [<c0433a68>]
> (secondary_start_kernel+0x160/0x16c)
> [<c0433a68>] (secondary_start_kernel) from [<004021ec>] (0x4021ec)
> CPU0: stopping
> CPU: 0 PID: 0 Comm: swapper/0 Tainted: G      D
> 4.15.0-rc2-00174-g328b4ed93b69-dirty #614
> Hardware name: Highbank
> [<c043644c>] (unwind_backtrace) from [<c04304ec>] (show_stack+0x20/0x24)
> [<c04304ec>] (show_stack) from [<c0f4f034>] (dump_stack+0x98/0xac)
> [<c0f4f034>] (dump_stack) from [<c0433f84>] (handle_IPI+0x2d0/0x350)
> [<c0433f84>] (handle_IPI) from [<c0401954>] (gic_handle_irq+0xa8/0xac)
> [<c0401954>] (gic_handle_irq) from [<c04310b8>] (__irq_svc+0x58/0x74)
> Exception stack(0xc1801ed8 to 0xc1801f20)
> 1ec0:                                                       00000001
> 00000000
> 1ee0: 00000000 c0440ba0 c18052cc c1800000 c1805338 00000001 c17847b8
> 00000000
> 1f00: 00000000 c1801f34 c1801f38 c1801f28 c042c954 c042c958 60000013
> ffffffff
> [<c04310b8>] (__irq_svc) from [<c042c958>] (arch_cpu_idle+0x48/0x4c)
> [<c042c958>] (arch_cpu_idle) from [<c0f6c7f8>] (default_idle_call+0x30/0x3c)
> [<c0f6c7f8>] (default_idle_call) from [<c04aa33c>] (do_idle+0x194/0x228)
> [<c04aa33c>] (do_idle) from [<c04aa67c>] (cpu_startup_entry+0x28/0x2c)
> [<c04aa67c>] (cpu_startup_entry) from [<c0f65540>] (rest_init+0xbc/0xc0)
> [<c0f65540>] (rest_init) from [<c1600e14>] (start_kernel+0x3d4/0x3e0)
> [<c1600e14>] (start_kernel) from [<00000000>] (  (null))
> ---[ end Kernel panic - not syncing: Attempted to kill init!
> exitcode=0x0000000b
> 

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: 4.15-rc1 crash on Midway in teardown_hyp_mode()
  2017-12-06 14:11 ` Andre Przywara
@ 2017-12-06 14:23   ` Marc Zyngier
  -1 siblings, 0 replies; 11+ messages in thread
From: Marc Zyngier @ 2017-12-06 14:23 UTC (permalink / raw)
  To: Andre Przywara, Christoffer Dall
  Cc: Rob Herring, kvmarm, linux-arm-kernel, Eric Auger

On 06/12/17 14:11, Andre Przywara wrote:
> Hi,
> 
> while trying to boot 4.15-rc1 on my Calxeda Midway I observed a crash
> (see below). I can't look further into this today, but wanted to report
> this anyway.
> 
> Digging around a bit this is due to the VGIC not initializing properly
> due to GICC being advertised as just 4K, not 8K.
> This can be worked around by adjusting the DT or using
> irqchip.gicv2_force_probe. However this still raises some questions:
> 1) Even if the VGIC fails to register, we should certainly not crash.
> The chain of events seems to be:
> virt/kvm/arm/arm.c:init_subsystems():
>   - kvm_vgic_hyp_init() returns -ENODEV, this leads to vgic_present
>     being set to false, but "err" being reset to 0 (meaning: carry on).
>     However this seems now to miss some initialization.
>   - kvm_timer_hyp_init() now fails on calling irq_set_vcpu_affinity(),
>     because this returns -ENOSYS. This leads to it returning this error,
>     init_subsystems() failing and subsequently tearing down KVM.
>   - This seems to have some bug and leads to the kernel crash.
> 
> Even with the VGIC not being usable, we should be able to cleanly tear
> down KVM (or HYP?).
> 
> 2) Is it intended that an unusable VGIC now denies KVM entirely? I
> believe in the past we could live with that (no arch timer
> virtualization, no in-kernel GIC emulation) and rely on userland
> emulation (for instance in QEMU). This seemed to have changed now?
> 3) Wouldn't it be smarter to fix up the GICC range by default, if we
> have enough evidence that the GICC is actually 8K? Shouldn't this be
> true for every architecture compliant GICv2, actually? So whenever we
> see "arm,cortex-a15-gic", for instance, we force GICC to 8K?
> Or do we know of GICs which have only 4K, but advertise themselves
> wrongly? Otherwise this could just go as some firmware quirk, based on a
> compatible string, for instance, or some ID registers.

I'm certainly not willing to blindly apply some range extension to the
the GIC registers without the user telling me that it is safe to do so.
There is too much quirky HW out there to do otherwise. How can you prove
that because you see "arm,cortex-a15-gic", you can safely extend the
range to 8K?

The rational is: you don't describe the HW correctly, you don't get a
working kernel. I don't think that's something new.

> The reason I am asking is that the Midway loads the DT from firmware
> flash, and this one hasn't changed in years (for obvious reasons). So
> while *I* am able to update the DT in the SPI flash, I guess many users
> just won't do so, so they are left with a crashing kernel (or loosing
> KVM), starting from 4.15. All the previous kernels booted and ran KVM
> guests fine in the past with the existing DT.

Which is why these people now get a kernel option that says "my firmware
is busted, do as I say".

Thanks,

	M.
-- 
Jazz is not dead. It just smells funny...

^ permalink raw reply	[flat|nested] 11+ messages in thread

* 4.15-rc1 crash on Midway in teardown_hyp_mode()
@ 2017-12-06 14:23   ` Marc Zyngier
  0 siblings, 0 replies; 11+ messages in thread
From: Marc Zyngier @ 2017-12-06 14:23 UTC (permalink / raw)
  To: linux-arm-kernel

On 06/12/17 14:11, Andre Przywara wrote:
> Hi,
> 
> while trying to boot 4.15-rc1 on my Calxeda Midway I observed a crash
> (see below). I can't look further into this today, but wanted to report
> this anyway.
> 
> Digging around a bit this is due to the VGIC not initializing properly
> due to GICC being advertised as just 4K, not 8K.
> This can be worked around by adjusting the DT or using
> irqchip.gicv2_force_probe. However this still raises some questions:
> 1) Even if the VGIC fails to register, we should certainly not crash.
> The chain of events seems to be:
> virt/kvm/arm/arm.c:init_subsystems():
>   - kvm_vgic_hyp_init() returns -ENODEV, this leads to vgic_present
>     being set to false, but "err" being reset to 0 (meaning: carry on).
>     However this seems now to miss some initialization.
>   - kvm_timer_hyp_init() now fails on calling irq_set_vcpu_affinity(),
>     because this returns -ENOSYS. This leads to it returning this error,
>     init_subsystems() failing and subsequently tearing down KVM.
>   - This seems to have some bug and leads to the kernel crash.
> 
> Even with the VGIC not being usable, we should be able to cleanly tear
> down KVM (or HYP?).
> 
> 2) Is it intended that an unusable VGIC now denies KVM entirely? I
> believe in the past we could live with that (no arch timer
> virtualization, no in-kernel GIC emulation) and rely on userland
> emulation (for instance in QEMU). This seemed to have changed now?
> 3) Wouldn't it be smarter to fix up the GICC range by default, if we
> have enough evidence that the GICC is actually 8K? Shouldn't this be
> true for every architecture compliant GICv2, actually? So whenever we
> see "arm,cortex-a15-gic", for instance, we force GICC to 8K?
> Or do we know of GICs which have only 4K, but advertise themselves
> wrongly? Otherwise this could just go as some firmware quirk, based on a
> compatible string, for instance, or some ID registers.

I'm certainly not willing to blindly apply some range extension to the
the GIC registers without the user telling me that it is safe to do so.
There is too much quirky HW out there to do otherwise. How can you prove
that because you see "arm,cortex-a15-gic", you can safely extend the
range to 8K?

The rational is: you don't describe the HW correctly, you don't get a
working kernel. I don't think that's something new.

> The reason I am asking is that the Midway loads the DT from firmware
> flash, and this one hasn't changed in years (for obvious reasons). So
> while *I* am able to update the DT in the SPI flash, I guess many users
> just won't do so, so they are left with a crashing kernel (or loosing
> KVM), starting from 4.15. All the previous kernels booted and ran KVM
> guests fine in the past with the existing DT.

Which is why these people now get a kernel option that says "my firmware
is busted, do as I say".

Thanks,

	M.
-- 
Jazz is not dead. It just smells funny...

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: 4.15-rc1 crash on Midway in teardown_hyp_mode()
  2017-12-06 14:17   ` Andre Przywara
@ 2017-12-06 14:41     ` Marc Zyngier
  -1 siblings, 0 replies; 11+ messages in thread
From: Marc Zyngier @ 2017-12-06 14:41 UTC (permalink / raw)
  To: Andre Przywara, Christoffer Dall
  Cc: Rob Herring, kvmarm, linux-arm-kernel, Eric Auger

On 06/12/17 14:17, Andre Przywara wrote:
> Hi,
> 
> On 06/12/17 14:11, Andre Przywara wrote:
>> Hi,
>>
>> while trying to boot 4.15-rc1 on my Calxeda Midway I observed a crash
>> (see below). I can't look further into this today, but wanted to report
>> this anyway.
>>
>> Digging around a bit this is due to the VGIC not initializing properly
>> due to GICC being advertised as just 4K, not 8K.
>> This can be worked around by adjusting the DT or using
>> irqchip.gicv2_force_probe. However this still raises some questions:
>> 1) Even if the VGIC fails to register, we should certainly not crash.
>> The chain of events seems to be:
>> virt/kvm/arm/arm.c:init_subsystems():
>>   - kvm_vgic_hyp_init() returns -ENODEV, this leads to vgic_present
>>     being set to false, but "err" being reset to 0 (meaning: carry on).
>>     However this seems now to miss some initialization.
>>   - kvm_timer_hyp_init() now fails on calling irq_set_vcpu_affinity(),
>>     because this returns -ENOSYS. This leads to it returning this error,
>>     init_subsystems() failing and subsequently tearing down KVM.
>>   - This seems to have some bug and leads to the kernel crash.
>>
>> Even with the VGIC not being usable, we should be able to cleanly tear
>> down KVM (or HYP?).
> 
> Just checked: If I let kvm_timer_hyp_init() deliberately fail in 4.14, I
> get the same splat (4.14 works fine, otherwise). So this particular
> issue existed already before. You should be able to reproduce it on any
> box by forcing "err = -ENOSYS;" after the call to kvm_timer_hyp_init()
> in virt/kvm/arm/arm.c:init_subsystems().

I wonder if the bigger hammer-type solution is not to expose that the
GIC is not capable of EOImode==1, and not enable the vgic in that
particular case...

I'll cook an RFC patch set for you to test.

Thanks,

	M.
-- 
Jazz is not dead. It just smells funny...

^ permalink raw reply	[flat|nested] 11+ messages in thread

* 4.15-rc1 crash on Midway in teardown_hyp_mode()
@ 2017-12-06 14:41     ` Marc Zyngier
  0 siblings, 0 replies; 11+ messages in thread
From: Marc Zyngier @ 2017-12-06 14:41 UTC (permalink / raw)
  To: linux-arm-kernel

On 06/12/17 14:17, Andre Przywara wrote:
> Hi,
> 
> On 06/12/17 14:11, Andre Przywara wrote:
>> Hi,
>>
>> while trying to boot 4.15-rc1 on my Calxeda Midway I observed a crash
>> (see below). I can't look further into this today, but wanted to report
>> this anyway.
>>
>> Digging around a bit this is due to the VGIC not initializing properly
>> due to GICC being advertised as just 4K, not 8K.
>> This can be worked around by adjusting the DT or using
>> irqchip.gicv2_force_probe. However this still raises some questions:
>> 1) Even if the VGIC fails to register, we should certainly not crash.
>> The chain of events seems to be:
>> virt/kvm/arm/arm.c:init_subsystems():
>>   - kvm_vgic_hyp_init() returns -ENODEV, this leads to vgic_present
>>     being set to false, but "err" being reset to 0 (meaning: carry on).
>>     However this seems now to miss some initialization.
>>   - kvm_timer_hyp_init() now fails on calling irq_set_vcpu_affinity(),
>>     because this returns -ENOSYS. This leads to it returning this error,
>>     init_subsystems() failing and subsequently tearing down KVM.
>>   - This seems to have some bug and leads to the kernel crash.
>>
>> Even with the VGIC not being usable, we should be able to cleanly tear
>> down KVM (or HYP?).
> 
> Just checked: If I let kvm_timer_hyp_init() deliberately fail in 4.14, I
> get the same splat (4.14 works fine, otherwise). So this particular
> issue existed already before. You should be able to reproduce it on any
> box by forcing "err = -ENOSYS;" after the call to kvm_timer_hyp_init()
> in virt/kvm/arm/arm.c:init_subsystems().

I wonder if the bigger hammer-type solution is not to expose that the
GIC is not capable of EOImode==1, and not enable the vgic in that
particular case...

I'll cook an RFC patch set for you to test.

Thanks,

	M.
-- 
Jazz is not dead. It just smells funny...

^ permalink raw reply	[flat|nested] 11+ messages in thread

* 4.15-rc2 crash on RPi2 in teardown_hyp_mode()
  2017-12-06 14:11 ` Andre Przywara
                   ` (2 preceding siblings ...)
  (?)
@ 2017-12-09 15:48 ` Andreas Färber
  2017-12-09 16:33     ` Marc Zyngier
  -1 siblings, 1 reply; 11+ messages in thread
From: Andreas Färber @ 2017-12-09 15:48 UTC (permalink / raw)
  To: Andre Przywara, Marc Zyngier, linux-rpi-kernel
  Cc: Rob Herring, Eric Auger, kvmarm, linux-arm-kernel

[-- 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

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: 4.15-rc2 crash on RPi2 in teardown_hyp_mode()
  2017-12-09 15:48 ` 4.15-rc2 crash on RPi2 " Andreas Färber
@ 2017-12-09 16:33     ` Marc Zyngier
  0 siblings, 0 replies; 11+ messages in thread
From: Marc Zyngier @ 2017-12-09 16:33 UTC (permalink / raw)
  To: Andreas Färber
  Cc: Rob Herring, Eric Auger, Andre Przywara, linux-rpi-kernel,
	kvmarm, linux-arm-kernel

On Sat, 09 Dec 2017 15:48:05 +0000,
Andreas Färber wrote:
> 
> [1  <text/plain; utf-8 (8bit)>]
> 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

No. Or rather, the RPi bug is to lack a GIC altogether.

> arch_timer and that error triggering Andre's kvm teardown bug that
> hopefully will be fixed with Marc's patch.

Only you can tell. You'll probably need both of these patches:

https://lists.cs.columbia.edu/pipermail/kvmarm/2017-December/028864.html
https://lists.cs.columbia.edu/pipermail/kvmarm/2017-December/028865.html

	M.

-- 
Jazz is not dead, it just smell funny.

^ permalink raw reply	[flat|nested] 11+ messages in thread

* 4.15-rc2 crash on RPi2 in teardown_hyp_mode()
@ 2017-12-09 16:33     ` Marc Zyngier
  0 siblings, 0 replies; 11+ messages in thread
From: Marc Zyngier @ 2017-12-09 16:33 UTC (permalink / raw)
  To: linux-arm-kernel

On Sat, 09 Dec 2017 15:48:05 +0000,
Andreas F?rber wrote:
> 
> [1  <text/plain; utf-8 (8bit)>]
> 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

No. Or rather, the RPi bug is to lack a GIC altogether.

> arch_timer and that error triggering Andre's kvm teardown bug that
> hopefully will be fixed with Marc's patch.

Only you can tell. You'll probably need both of these patches:

https://lists.cs.columbia.edu/pipermail/kvmarm/2017-December/028864.html
https://lists.cs.columbia.edu/pipermail/kvmarm/2017-December/028865.html

	M.

-- 
Jazz is not dead, it just smell funny.

^ permalink raw reply	[flat|nested] 11+ messages in thread

end of thread, other threads:[~2017-12-09 16:33 UTC | newest]

Thread overview: 11+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2017-12-06 14:11 4.15-rc1 crash on Midway in teardown_hyp_mode() Andre Przywara
2017-12-06 14:11 ` Andre Przywara
2017-12-06 14:17 ` Andre Przywara
2017-12-06 14:17   ` Andre Przywara
2017-12-06 14:41   ` Marc Zyngier
2017-12-06 14:41     ` Marc Zyngier
2017-12-06 14:23 ` Marc Zyngier
2017-12-06 14:23   ` Marc Zyngier
2017-12-09 15:48 ` 4.15-rc2 crash on RPi2 " Andreas Färber
2017-12-09 16:33   ` Marc Zyngier
2017-12-09 16:33     ` Marc Zyngier

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.