OS X Virtual machine has async io problems causing iy to fail

[unixwzrd]

Getting these messages during the install. It's accessing the ISO installation CD and the VDI disk. I've tried different chip types, and had best success using the same ATA controller for both the CD image and the installation drive. When using the SATA, it seems to fail, but I haven't looked at the logs. I assume it's the same problem. Here's a bit of the log file from the VM.

00:52:18.532264 PIIX3 ATA LUN#2: Async I/O thread probably stuck in operation, interrupting 00:52:20.452002 PIIX3 ATA LUN#2: Async I/O thread probably stuck in operation, interrupting 00:52:22.372029 PIIX3 ATA LUN#2: Async I/O thread probably stuck in operation, interrupting 00:52:24.292006 PIIX3 ATA LUN#2: Async I/O thread probably stuck in operation, interrupting 00:52:26.212237 PIIX3 ATA LUN#2: Async I/O thread probably stuck in operation, interrupting 00:52:27.112089 PIIX3 ATA: Ctl#1: RESET, DevSel=0 AIOIf=0 CmdIf0=0xa0 (51722074 usec ago) CmdIf1=0x00 (-1 usec ago) 00:52:28.172301 PIIX3 ATA LUN#2: Async I/O thread probably stuck in operation, interrupting 00:52:30.091945 PIIX3 ATA LUN#2: Async I/O thread probably stuck in operation, interrupting 00:52:32.011961 PIIX3 ATA LUN#2: Async I/O thread probably stuck in operation, interrupting 00:52:33.528271 AsyncCompletion: Task 0x00000113628f00 completed after 141 seconds 00:52:33.528418 PIIX3 ATA: execution time for ATA command 0xca was 141 seconds 00:52:33.528437 PIIX3 ATA: Ctl#0: finished processing RESET 00:52:33.528568 AsyncCompletion: Task 0x00000113628fc0 completed after 58 seconds 00:52:33.528585 PIIX3 ATA: execution time for ATAPI command 0x28 was 58 seconds 00:52:33.528604 PIIX3 ATA: Ctl#1: finished processing RESET

The VM Manager also SEGFAULTed when I powered off the machine, and I'll attach the crash dump output as well.

This is also present in versions 5.2 and 6.0 releases as well.

[unixwzrd]

VM Log file

[unixwzrd]

VMManager SVC log

[unixwzrd]

Apple OS X Crash reporter output

[unixwzrd]

It also occurs with LUN# 0 which is the VDI disk.

[unixwzrd]

Have tried several/many combinations of controllers and locations for each device on the controllers. This is reporting problems with ASYNC IO on pretty much any type disk controller type.

[Graham Perrin]

Replying to unixwzrd:

… VDI …

Please describe the physical storage for the virtual disk.

---

I sometimes have the same symptoms with virtual disk images stored on OpenZFS with native compression (currently ZStd at its default) on a StoreJet Transcend – /dev/da3 at the time of <​https://bsd-hardware.info/?probe=86613b04d3https://bsd-hardware.info/?probe=86613b04d3>.

root@mowa219-gjp4-8570p-freebsd:~ # zfs get compression Transcend/VirtualBox
NAME                  PROPERTY     VALUE           SOURCE
Transcend/VirtualBox  compression  zstd            local
root@mowa219-gjp4-8570p-freebsd:~ # zpool history Transcend | grep compression
2020-09-02.18:31:48 zpool create -f -m /Volumes/t500 -O compression=zstd Transcend /dev/da0p1
2021-03-27.20:03:56 zfs set compression=zstd-9 Transcend
2021-03-27.20:13:33 zfs set compression=zstd-19 Transcend
2021-03-27.20:19:44 zfs set compression=zstd-19 Transcend
2021-03-29.07:24:35 zfs set compression=zstd-15 Transcend
2021-04-14.14:06:28 zfs set compression=zstd-19 Transcend
2021-04-14.14:06:48 zfs set compression=zstd-10 Transcend/VirtualBox
2021-05-22.00:39:25 zfs set compression=zstd-15 Transcend
2021-05-22.03:27:49 zfs set compression=zstd-19 Transcend/VirtualBox
2021-05-22.07:46:40 zfs set compression=zstd-10 Transcend/VirtualBox
2021-06-13.19:52:56 zfs set compression=zstd-19 Transcend/VirtualBox
2021-06-14.00:45:55 zfs set compression=zstd-12 Transcend/VirtualBox
2021-06-19.20:16:20 zfs set compression=zstd Transcend/VirtualBox
2021-06-23.05:53:34 zfs set compression=zstd-19 Transcend/VirtualBox
2021-06-23.08:02:27 zfs set compression=zstd-15 Transcend/VirtualBox
2021-06-23.18:12:51 zfs set compression=zstd-12 Transcend/VirtualBox
2021-06-24.02:47:47 zfs set compression=zstd-19 Transcend/VirtualBox
2021-06-24.06:10:32 zfs set compression=zstd-15 Transcend/VirtualBox
2021-06-24.06:56:02 zfs set compression=zstd-12 Transcend/VirtualBox
2021-09-02.12:31:24 zfs set compression=zstd Transcend/VirtualBox
2021-09-19.14:34:46 zfs set compression=zstd-19 Transcend/VirtualBox
2021-09-19.14:56:38 zfs set compression=zstd Transcend/VirtualBox
root@mowa219-gjp4-8570p-freebsd:~ # 

From a recent log:

00:03:05.029968 PIIX3 ATA: Ctl#0: RESET, DevSel=0 AIOIf=0 CmdIf0=0xc8 (29924497 usec ago) CmdIf1=0x00 (-1 usec ago)
00:03:05.140372 PIIX3 ATA LUN#0: Async I/O thread probably stuck in operation, interrupting
00:03:08.341409 PIIX3 ATA LUN#0: Async I/O thread probably stuck in operation, interrupting
00:03:11.542040 PIIX3 ATA LUN#0: Async I/O thread probably stuck in operation, interrupting
00:03:14.744446 PIIX3 ATA LUN#0: Async I/O thread probably stuck in operation, interrupting
00:03:17.945101 PIIX3 ATA LUN#0: Async I/O thread probably stuck in operation, interrupting
00:03:21.145837 PIIX3 ATA LUN#0: Async I/O thread probably stuck in operation, interrupting
00:03:24.346794 PIIX3 ATA LUN#0: Async I/O thread probably stuck in operation, interrupting
00:03:27.547553 PIIX3 ATA LUN#0: Async I/O thread probably stuck in operation, interrupting
00:03:30.748660 PIIX3 ATA LUN#0: Async I/O thread probably stuck in operation, interrupting
00:03:33.949206 PIIX3 ATA LUN#0: Async I/O thread probably stuck in operation, interrupting
00:03:39.833579 PIIX3 ATA: execution time for ATA command 0xc8 was 64 seconds
00:03:39.833615 PIIX3 ATA: Ctl#0: finished processing RESET