Bug 277559 - kldload vmm sometimes hangs kernel on arm64
Summary: kldload vmm sometimes hangs kernel on arm64
Status: Open
Alias: None
Product: Base System
Classification: Unclassified
Component: kern (show other bugs)
Version: 15.0-CURRENT
Hardware: Any Any
: --- Affects Some People
Assignee: freebsd-virtualization (Nobody)
URL: https://reviews.freebsd.org/D44799
Keywords: crash
Depends on:
Blocks:
 
Reported: 2024-03-07 20:44 UTC by John F. Carr
Modified: 2024-10-26 19:04 UTC (History)
6 users (show)

See Also:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description John F. Carr 2024-03-07 20:44:57 UTC
On my RockPro64 "kldload vmm" sometimes hangs the system so hard I can't even enter DDB with a break on the serial console.  The smp_rendezvous call in vmops_modinit appears to be the culprit according to some debugging printfs I added.

  printf("vmmops_modinit rendezvous %p {%lx, %lx}\n", &el2_regs,
         el2_regs.tcr_el2, el2_regs.vtcr_el2);
  pause("vmmon", 20); // let console output queue drain
  	smp_rendezvous(NULL, arm_setup_vectors, NULL, &el2_regs);
  printf("vmmops_modinit rendezvous returned\n");
  pause("vmmon", 20); // let console output queue drain

The last line on the console when it hangs is

  vmmops_modinit rendezvous 0xffff0000a5b9d380 {80823510, 80023559}

The RockPro64 has 4 Cortex-A53 and 2 Cortex A-72 processors, same clock speed but different performance.

According to other printfs I added to vmmops_modinit,

  ID_AA64MMFR0_EL1 = 1122
  vmm_virt_bits = 39

Most of the time the vmm module loads.  About 10% of the time it hangs.
Comment 1 Peter Grehan freebsd_committer freebsd_triage 2024-03-08 08:17:19 UTC
I'm going to hazard a guess this is due to the differences in capabilities between the A53 and A72 cores (having seen a problem with that on Linux/KVM on the same RockPro64).

The theory is that if kldload runs on an A72 core, the passed tcr_el2/vtcr_el2 values aren't compatible with A53 cores, but it's ok the other way around.

One way to see if this is the case would be to pin the kldload onto an A72 core,
and then onto an A53 core, and see if it works one way but hangs the other.

cpuset -l <cpu-num> kldload vmm.ko

where cpu-num is the number assigned to an A72 or A53 core.
Comment 2 John F. Carr 2024-03-08 13:46:06 UTC
Loading vmm sometimes hangs on either type of CPU.  Hangs appear to be more likely on the low numbered A53 CPUs.

The bits are the same whichever CPU is in charge, tcr_el2=80823510 and vtcr_el2=80023559.

Notably, one of the hangs on CPU 0 had debugging output from after the smp_rendezvous:

  # cpuset -l 0 kldload vmm
  vgic0: <Virtual GIC v3> on gic0
  vmm_handler 0xffffa000f4017180 0 0
  vmmdev_init()
  vmmdev init returned
  vmm_init vm_maxcpu = 6
  vmm_regs_init returned 0
  vmmops_modinit 0
  ID_AA64MMFR0_EL1 = 1122
  vmm_virt_bits = 39
  vmmops_modinit rendezvous 0xffff0000d5e18380 {80823510, 80023559}
  vmmops_modinit rendezvous returned
  vmmops_modinit disable interrupts

The last lines come from this code I added at the end of vmmops_modinit:

  printf("vmmops_modinit disable interrupts\n");
  pause("vmmon", 2);
          daif = intr_disable();
          cnthctl_el2 = vmm_call_hyp(HYP_READ_REGISTER, HYP_REG_CNTHCTL);
          intr_restore(daif);
  printf("vmmops_modinit enable interrupts\n");

          vgic_init();
  printf("vmmops_modinit vgic ininitalized\n");
          vtimer_init(cnthctl_el2);
  printf("vmmops_modinit vtimer_init(cnthctl_el2=%lx) returned\n", cnthctl_el2);

The next time I tried the same command it worked:

  # cpuset -l 0 kldload vmm
  vgic0: <Virtual GIC v3> on gic0
  vmm_handler 0xffffa00002782300 0 0
  vmmdev_init()
  vmmdev init returned
  vmm_init vm_maxcpu = 6
  vmm_regs_init returned 0
  vmmops_modinit 0
  ID_AA64MMFR0_EL1 = 1122
  vmm_virt_bits = 39
  vmmops_modinit rendezvous 0xffff0000bd5e7380 {80823510, 80023559}
  vmmops_modinit rendezvous returned
  vmmops_modinit disable interrupts
  vmmops_modinit enable interrupts
  vmmops_modinit vgic ininitalized
  vmmops_modinit vtimer_init(cnthctl_el2=3) returned
  vmm init returned 0

Console output from every other hang stopped before the "vmmops_modinit rendezvous returned" message.

Has anybody successfully used a JTAG debugger on the RockPro64?
Comment 3 Peter Grehan freebsd_committer freebsd_triage 2024-03-09 03:16:54 UTC
Thanks for giving that a try: rules out that theory.
Comment 4 Mark Johnston freebsd_committer freebsd_triage 2024-04-10 13:58:55 UTC
vmmops_modinit() is using smp_rendezvous to execute code (arm_setup_vectors()) on each CPU.  Presumably one or more of the CPUs is hanging in the vmm_call_hyp() call which initializes per-CPU state (various control registers) in EL2.  This is done in handle_hyp_init in vmm_hyp_exception.S.

The first thing that routine does is initialize the vector table; I wonder if that should be done last instead.  Perhaps there is a stray EL2 exception occurring for some reason?

It would be useful to add printf("%d", curcpu)s around the vmm_call_hyp() calls in arm_setup_vectors() to see if there is a pattern to the hangs.  We can also try modifying vmm_call_hyp() to return early after various points, so as to try and narrow down exactly where the hang is happening.
Comment 5 John F. Carr 2024-04-10 21:54:59 UTC
I moved the set of vbar_el2 after the set of vtcr_el2.  The problem is not fixed but it is much better.  I was able to load and unload the vmm module about 270 times before the system hung.
Comment 6 John F. Carr 2024-04-11 00:15:36 UTC
I noticed that the instruction cache types are different for the two processor types.  A-53 is virtually indexed and A-72 is physically indexed.

Cache Type = <64 byte D-cacheline,64 byte I-cacheline,VIPT ICache,64 byte ERG,64 byte CWG>
Cache Type = <64 byte D-cacheline,64 byte I-cacheline,PIPT ICache,64 byte ERG,64 byte CWG>

When changing address translation for EL2 code, are any cache clean operations required?  handle_hyp_init currently contains a TLB flush and isb.
Comment 7 John F. Carr 2024-04-11 14:49:39 UTC
Moving the set of vbar_el2 was not the cause of improvement.  I just saw two runs of over 2,000 successful kldloads before a hang without it.  I also saw the system hang on the first load last night.

I wonder if success of the first load makes the next load more likely to succeed, e.g. because the module reloads at the same address.

Clock frequency does not seem to matter.  I ran my kldload/kldunload loop with powerd on running at 1416 MHz and with powerd off running at 600 MHz.
Comment 8 Andrew Turner freebsd_committer freebsd_triage 2024-04-15 17:14:17 UTC
It looks like the issue is due to the tlbi in handle_hyp_init having insufficient barriers around it.

I have a fix I'm testing that seems to fix the issue.
Comment 9 John F. Carr 2024-04-15 23:01:59 UTC
The change in review D44799 fixes the problem for me – about 780,000 kldload/kldunload pairs without a hang on the RockPro64.  (I got distracted and let the loop run for a couple hours.)
Comment 10 John F. Carr 2024-04-16 17:10:09 UTC
There is still a problem, but less common.  One out of five reboots with the patch the RockPro64 hung the first time I ran kldload.  The ssh session was responsive for a few seconds:

# kldload vmm
load: 0.12  cmd: kldload 81984 [running] 0.97r 0.00u 0.01s 9% 2596k
load: 0.12  cmd: kldload 81984 [running] 2.46r 0.00u 0.01s 23% 2596k
client_loop: send disconnect: Broken pipe

The last entry in /var/log/messages said:

vgic0: <Virtual GIC v3> on gic0

This machine can't save crash dumps and I don't know if there was a panic.  I can hook up a serial console if helpful.

If kldload works the first time after reboot it seems to keep working.  This is an improvement.
Comment 11 commit-hook freebsd_committer freebsd_triage 2024-04-24 18:32:03 UTC
A commit in branch main references this bug:

URL: https://cgit.FreeBSD.org/src/commit/?id=ef80df0a71912500ad84060334a24e903869f00b

commit ef80df0a71912500ad84060334a24e903869f00b
Author:     Andrew Turner <andrew@FreeBSD.org>
AuthorDate: 2024-04-15 14:36:20 +0000
Commit:     Andrew Turner <andrew@FreeBSD.org>
CommitDate: 2024-04-24 18:17:19 +0000

    arm64/vmm: Ensure the tlbi has completed

    Ensure the TLB is invalidated before enabling the EL2 MMU. Without
    this the TLB may be in an inconsistant state leading to a possible
    exception when enabling the MMU.

    PR:             277559
    Reviewed by:    markj
    Sponsored by:   Arm Ltd
    Differential Revision:  https://reviews.freebsd.org/D44799

 sys/arm64/vmm/vmm_hyp_exception.S | 3 +++
 1 file changed, 3 insertions(+)
Comment 12 John F. Carr 2024-05-22 13:34:49 UTC
I got another hang on kldload and this time ^T over the ssh session was responsive for about a minute, ending with

load: 0.19  cmd: kldload 67182 [running] 53.73r 0.00u 0.01s 100% 1944k

The process is using 100% CPU but none of it is counted towards user or system time.

As I understand sched_4bsd.c and kern_clock, the percentage is based on what thread is saved in curthread when the clock ticks and may include time that an ethical accounting system would not bill to the owner of the thread.  "Note that we charge interrupts to the current process, regardless of whether they are ``for'' that process".
Comment 13 Michael Tuexen freebsd_committer freebsd_triage 2024-05-23 12:35:04 UTC
Using FreeBSD main of yesterday (and earlier) on a 32-core Ampere eMAG system and running
sudo kldload vmm
always locks up the machine.
Anything I can do to help resolving this?
Comment 14 Dave Cottlehuber freebsd_committer freebsd_triage 2024-05-27 06:40:14 UTC
Same here, ampere eMAG too. No messages on console, just locks up.
Comment 15 Mark Johnston freebsd_committer freebsd_triage 2024-10-26 15:51:31 UTC
Is this still a problem on the latest main?  I've never seen it myself on some Ampere and Morello systems, and there's been a number of arm64/vmm bug fixes since the last comment.
Comment 16 Michael Tuexen freebsd_committer freebsd_triage 2024-10-26 18:50:20 UTC
(In reply to Mark Johnston from comment #15)
I still do see it everytime I do `kldload vmm` on a 32 core Ampere System (eMAG). On a 128 core (Ampere Altra) everything is fine.
Can I provide any hints? If yes, how?
Comment 17 Michael Tuexen freebsd_committer freebsd_triage 2024-10-26 18:50:38 UTC
(In reply to Mark Johnston from comment #15)
I still do see it everytime I do `kldload vmm` on a 32 core Ampere System (eMAG). On a 128 core (Ampere Altra) everything is fine.
Can I provide any hints? If yes, how?
Comment 18 Mark Johnston freebsd_committer freebsd_triage 2024-10-26 19:04:44 UTC
(In reply to Michael Tuexen from comment #17)
Can you please share the dmesg from your system?

It'd help to try sprinkling prints around arm_setup_vectors() and vmmops_modinit() to see where exactly the hang happens.