Re: slow start of Pod HVM domU with qemu 9.1

["Edgar E. Iglesias" <edgar.iglesias@xxxxxxx>]

On Tue, Jan 28, 2025 at 03:15:44PM +0100, Olaf Hering wrote:
> Hello,
> 
> starting with qemu 9.1 a PoD HVM domU takes a long time to start.
> Depending on the domU kernel, it may trigger a warning, which prompted me
> to notice this change in behavior:
> 
> [    0.000000] Linux version 4.12.14-120-default (geeko@buildhost) (gcc 
> version 4.8.5 (SUSE Linux) ) #1 SMP Thu Nov 7 16:39:09 UTC 2019 (fd9dc36)
> ...
> [    1.096432] HPET: 3 timers in total, 0 timers will be used for per-cpu 
> timer
> [    1.101636] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0
> [    1.104051] hpet0: 3 comparators, 64-bit 62.500000 MHz counter
> [   16.136086] random: crng init done
> [   31.712052] BUG: workqueue lockup - pool cpus=1 node=0 flags=0x0 nice=0 
> stuck for 30s!
> [   31.716029] Showing busy workqueues and worker pools:
> [   31.721164] workqueue events: flags=0x0
> [   31.724054]   pwq 2: cpus=1 node=0 flags=0x0 nice=0 active=2/256
> [   31.728000]     in-flight: 17:balloon_process
> [   31.728000]     pending: hpet_work
> [   31.728023] workqueue mm_percpu_wq: flags=0x8
> [   31.732987]   pwq 2: cpus=1 node=0 flags=0x0 nice=0 active=1/256
> [   31.736000]     pending: vmstat_update
> [   31.736024] pool 2: cpus=1 node=0 flags=0x0 nice=0 hung=30s workers=2 
> idle: 34
> [   50.400102] clocksource: Switched to clocksource xen
> [   50.441153] VFS: Disk quotas dquot_6.6.0
> ...
> 
> With qemu 9.0 and older, this domU will start the /init task after 8 seconds.
> 
> The change which caused this commit is qemu.git commit 
> 9ecdd4bf08dfe4a37e16b8a8b228575aff641468
> Author:     Edgar E. Iglesias <edgar.iglesias@xxxxxxx>
> AuthorDate: Tue Apr 30 10:26:45 2024 +0200
> Commit:     Edgar E. Iglesias <edgar.iglesias@xxxxxxx>
> CommitDate: Sun Jun 9 20:16:14 2024 +0200
> 
>     xen: mapcache: Add support for grant mappings
> 
> As you can see, v4 instead of v5 was apparently applied.
> This was probably unintentional, but would probably not change the result.

Hi Olaf,

It looks like v8 was applied, or am I missing something?


> 
> With this change the domU starts fast again:
> 
> --- a/hw/xen/xen-mapcache.c
> +++ b/hw/xen/xen-mapcache.c
> @@ -522,6 +522,7 @@ ram_addr_t xen_ram_addr_from_mapcache(void *ptr)
>      ram_addr_t addr;
>  
>      addr = xen_ram_addr_from_mapcache_single(mapcache, ptr);
> +    if (1)
>      if (addr == RAM_ADDR_INVALID) {
>          addr = xen_ram_addr_from_mapcache_single(mapcache_grants, ptr);
>      }
> @@ -626,6 +627,7 @@ static void 
> xen_invalidate_map_cache_entry_single(MapCache *mc, uint8_t *buffer)
>  static void xen_invalidate_map_cache_entry_all(uint8_t *buffer)
>  {
>      xen_invalidate_map_cache_entry_single(mapcache, buffer);
> +    if (1)
>      xen_invalidate_map_cache_entry_single(mapcache_grants, buffer);
>  }
>  
> @@ -700,6 +702,7 @@ void xen_invalidate_map_cache(void)
>      bdrv_drain_all();
>  
>      xen_invalidate_map_cache_single(mapcache);
> +    if (0)
>      xen_invalidate_map_cache_single(mapcache_grants);
>  }
>  
> I did the testing with libvirt, the domU.cfg equivalent looks like this:
> maxmem = 4096
> memory = 2048
> maxvcpus = 4
> vcpus = 2
> pae = 1
> acpi = 1
> apic = 1
> viridian = 0
> rtc_timeoffset = 0
> localtime = 0
> on_poweroff = "destroy"
> on_reboot = "destroy"
> on_crash = "destroy"
> device_model_override = "/usr/lib64/qemu-9.1/bin/qemu-system-i386"
> sdl = 0
> vnc = 1
> vncunused = 1
> vnclisten = "127.0.0.1"
> vif = [ "mac=52:54:01:23:63:29,bridge=br0,script=vif-bridge" ]
> parallel = "none"
> serial = "pty"
> builder = "hvm"
> kernel = "/bug1236329/linux"
> ramdisk = "/bug1236329/initrd"
> cmdline = "console=ttyS0,115200n8 quiet ignore_loglevel""
> boot = "c" 
> disk = [ 
> "format=qcow2,vdev=hda,access=rw,backendtype=qdisk,target=/bug1236329/sles12sp5.qcow2"
>  ]
> usb = 1
> usbdevice = "tablet"
> 
> Any idea what can be done to restore boot times?


A guess is that it's taking a long time to walk the grants mapcache
when invalidating (in QEMU). Despite it being unused and empty. We
could try to find a way to keep track of usage and do nothing when
invalidating an empty/unused cache.

Best regards,
Edgar