UTM 4.3.3 Linux guest hangs on MacOS with "Error: port is not opened" #5505

gglluukk · 2023-07-29T11:54:09Z

Describe the issue
UTM 4.3.3 Linux guest hangs on MacOS with "Error: port is not opened"

Configuration

UTM Version: 4.3.3
macOS Version: 12.6.8
Mac Chip (Intel, M1, ...): M1

It is related to closed issue: #5472

After upgrading to UTM 4.3.3 UTM itself doesn't crush, however virtual guest hangs on with the following error (see first picture). No external devices were attached.

UTM 4.3.0 runs without any errors.

The only 'non-standart' configuration is the following (second picture):

neldredge-unco · 2023-07-29T17:08:59Z

I am seeing this too, with a Windows 11 ARM guest and no serial devices on the VM. It happens while attempting to download a Windows Update (before the install begins).

I have a vague idea that it might have to do with the fact that the keyboard and mouse have been idle for a few minutes. I wondered if maybe it had something to do with the screen saver. It's not exactly that, because it doesn't always hang when the screen saver activates, but just maybe there is some connection?

osy · 2023-07-30T00:01:33Z

Can you try https://github.com/utmapp/UTM/suites/14668665657/artifacts/832453260 it should have more verbose logging which may help pin point the issue.

gglluukk · 2023-07-30T00:12:53Z

OK, running it now under maximum load but error isn't predictable, it happens randomly, so let's see

neldredge-unco · 2023-07-30T01:17:24Z

I got it to hang with the debug build: debug.log

The hang occurs first. When I attempt to halt the VM is when the "Error: port is not opened" dialog pops up. I think it actually popped up two identical dialogs on top of each other, because I had to dismiss it twice.

After that, the VM is off (gray window with the play button) but the window can't be closed. The red close button is grayed out, and the minimize and maximize buttons don't do anything. It only goes away when you quit UTM.

Snippet from the log:

2023-07-29 19:04:55,663 DEBUG (null)-/Users/runner/Library/Developer/Xcode/DerivedData/UTM-gnwjeapbifchcjczzvitjgckdhnq/SourcePackages/checkouts/CocoaSpice/Sources/CocoaSpice/CSDisplay.m:207 [CocoaSpice] cs_gl_draw
qemu-aarch64-softmmu: warning: Spice: playback:0 (0x14a0d9910): channel->thread_id (0x1df886080) != pthread_self (0x16daa7000).If one of the threads is != io-thread && != vcpu-thread, this might be a BUG
qemu-aarch64-softmmu: warning: Spice: record:0 (0x14a0d99b0): channel->thread_id (0x1df886080) != pthread_self (0x16daa7000).If one of the threads is != io-thread && != vcpu-thread, this might be a BUG
Debug JSON recieved <- {
    data =     {
        client =         {
            family = unix;
            host = "";
            port = "";
        };
        server =         {
            family = unix;
            host = "";
            port = "";
        };
    };
    event = "SPICE_DISCONNECTED";
    timestamp =     {
        microseconds = 944584;
        seconds = 1690679185;
    };
}
Debug JSON recieved <- {
    data =     {
        client =         {
            family = unix;
            host = "";
            port = "";
        };
        server =         {
            family = unix;
            host = "";
            port = "";
        };
    };
    event = "SPICE_DISCONNECTED";
    timestamp =     {
        microseconds = 944675;
        seconds = 1690679185;
    };
}
2023-07-29 19:06:26,069 DEBUG (null)-/Users/runner/Library/Developer/Xcode/DerivedData/UTM-gnwjeapbifchcjczzvitjgckdhnq/SourcePackages/checkouts/CocoaSpice/Sources/CocoaSpice/CSConnection.m:138 [CocoaSpice] SPICE agent connected: 0
2023-07-29 19:06:26,072 MESSAGE (null)-main channel: closed
2023-07-29 19:06:26,073 DEBUG (null)-/Users/runner/Library/Developer/Xcode/DerivedData/UTM-gnwjeapbifchcjczzvitjgckdhnq/SourcePackages/checkouts/CocoaSpice/Sources/CocoaSpice/CSConnection.m:278 zap inputs channel
2023-07-29 19:06:26,073 DEBUG (null)-/Users/runner/Library/Developer/Xcode/DerivedData/UTM-gnwjeapbifchcjczzvitjgckdhnq/SourcePackages/checkouts/CocoaSpice/Sources/CocoaSpice/CSConnection.m:287 zap audio channel
2023-07-29 19:06:26,074 DEBUG (null)-/Users/runner/Library/Developer/Xcode/DerivedData/UTM-gnwjeapbifchcjczzvitjgckdhnq/SourcePackages/checkouts/CocoaSpice/Sources/CocoaSpice/CSConnection.m:273 zap display channel (#0)
2023-07-29 19:06:26,075 DEBUG (null)-/Users/runner/Library/Developer/Xcode/DerivedData/UTM-gnwjeapbifchcjczzvitjgckdhnq/SourcePackages/checkouts/CocoaSpice/Sources/CocoaSpice/CSConnection.m:265 [CocoaSpice] cs_channel_destroy:265
2023-07-29 19:06:26,075 DEBUG (null)-/Users/runner/Library/Developer/Xcode/DerivedData/UTM-gnwjeapbifchcjczzvitjgckdhnq/SourcePackages/checkouts/CocoaSpice/Sources/CocoaSpice/CSConnection.m:266 zap main channel
Debug JSON send -> {
    execute = "query-mice";
}
2023-07-29 19:07:18,942 WARNING (null)-[CocoaSpice] The port is not opened
QMP stream error seen: Error Domain=com.utmapp.QEMUKit Code=-1 "The port is not opened" UserInfo={NSLocalizedDescription=The port is not opened}
RPC: The port is not opened
Debug JSON send -> {
    execute = "query-mice";
}
2023-07-29 19:07:18,948 WARNING (null)-[CocoaSpice] The port is not opened
QMP stream error seen: Error Domain=com.utmapp.QEMUKit Code=-1 "The port is not opened" UserInfo={NSLocalizedDescription=The port is not opened}
RPC: The port is not opened
Debug JSON send -> {
    execute = "query-mice";
}
2023-07-29 19:07:18,957 WARNING (null)-[CocoaSpice] The port is not opened
QMP stream error seen: Error Domain=com.utmapp.QEMUKit Code=-1 "The port is not opened" UserInfo={NSLocalizedDescription=The port is not opened}
RPC: The port is not opened
Debug JSON send -> {
    execute = "query-mice";
}

gglluukk · 2023-07-30T18:08:52Z

debug.log

osy · 2023-07-30T18:43:16Z

This build has even more logging from the QEMU side since I am still not able to figure out what's causing the issue: https://github.com/utmapp/UTM/suites/14676612107/artifacts/833073067

gglluukk · 2023-07-30T19:17:16Z

debug.log
hope this one will help

osy · 2023-07-30T19:22:52Z

Curious if disabling audio (vm settings -> right click sound device -> delete) will change anything?

gglluukk · 2023-07-30T19:25:14Z

ok, i'll try

neldredge-unco · 2023-07-30T19:43:25Z

I reproduced using https://github.com/utmapp/UTM/suites/14676612107/artifacts/833073067 : debug.log. I'll try deleting the sound device now.

neldredge-unco · 2023-07-30T20:02:34Z

It still hung with the sound device removed.
debug.log
config.plist.txt

gglluukk · 2023-07-30T20:08:51Z

same here:
debug.log

osy · 2023-07-30T20:11:07Z

Can either of you share the VM with me? You can email osy at turing dot llc.

gglluukk · 2023-07-30T20:16:22Z

that's kind of problematic for me since i need to clean it deeply from working projects in there and all its artifacts.
@neldredge-unco ?

osy · 2023-07-30T20:17:25Z

One more test: uninstall spice-vdagent and see if that makes a difference

gglluukk · 2023-07-30T20:23:28Z

I don't have it on MacOS host:

me@mika ~ $ find /Applications/UTM-4.3.3.app/ -name spice-vdagent
me@mika ~ $ locate spice-vdagent

as well it's not installed in Linux guest:

lab ~ # locate spice-vdagent
/var/db/repos/gentoo/app-emulation/spice-vdagent
/var/db/repos/gentoo/app-emulation/spice-vdagent/Manifest
/var/db/repos/gentoo/app-emulation/spice-vdagent/files
/var/db/repos/gentoo/app-emulation/spice-vdagent/metadata.xml
/var/db/repos/gentoo/app-emulation/spice-vdagent/spice-vdagent-0.22.1.ebuild
/var/db/repos/gentoo/app-emulation/spice-vdagent/files/spice-vdagent.confd-2
/var/db/repos/gentoo/app-emulation/spice-vdagent/files/spice-vdagent.initd-4
/var/db/repos/gentoo/metadata/md5-cache/app-emulation/spice-vdagent-0.22.1
lab ~ # which spice-vdagent
which: no spice-vdagent in (/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/root/mitigation:/root/scripts:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/opt/bin:/mnt/linux/go/bin/:~/.local/bin/)
lab ~ # ps ax | grep [s]pice-vdagent

osy · 2023-07-30T20:25:09Z

Okay, that makes sense, nvm

neldredge-unco · 2023-07-30T21:25:45Z

My test case starts with the Windows 11 VHDX from build 25346, dated 20230506 (which I happen to have on my disk already, instead of downloading the latest). I followed the install procedure at https://gist.github.com/wrmack/29d580a0bd665bace21609d5ef675ba1 , skipping the LabConfig registry key but still doing the WindowsSelfHost ones, and skipping step 6.

The hang always occurs when doing Windows Update for the first time, during the download of the new build, but always at a different percent. That's also the first time in the process when I leave it unattended for several minutes. In every test, I've gone away at that point, and when I come back and unlock the screen saver, it's hung. I have it on AC power so I don't think the machine would be sleeping during that time, but I'm not completely familiar with how Mac power management works.

When I have some time in the next few days, I can try to reproduce starting from a fresh install, and I'll screen record it. I can also submit the entire VM if it would help, but I'm on a 20 Mbps link so it would take a while to upload.

I might also test whether the hang still occurs if I keep using the VM and moving the mouse, instead of walking away.

osy · 2023-07-30T22:05:11Z

Okay, one more build with even MORE verbose logging. https://github.com/utmapp/UTM/suites/14679241836/artifacts/833192468

gglluukk · 2023-07-30T23:33:39Z

debug.log.gz

osy · 2023-07-31T00:47:28Z

@neldredge-unco @gglluukk How much RAM is your computer configured with? How much free storage?

gglluukk · 2023-07-31T00:50:20Z

lab ~ # free
               total        used        free      shared  buff/cache   available
Mem:         4032896      132600     3782184         728      118112     3769516
Swap:              0           0           0
lab ~ # df
Filesystem      Size  Used Avail Use% Mounted on
none            2.0G  656K  2.0G   1% /run
udev             10M     0   10M   0% /dev
tmpfs           2.0G     0  2.0G   0% /dev/shm
/dev/vda2        15G  9.5G  4.3G  70% /
cgroup_root      10M     0   10M   0% /sys/fs/cgroup

osy · 2023-07-31T00:51:58Z

I'm wondering about your host Mac

gglluukk · 2023-07-31T00:54:35Z

RAM: 8 GB
HDD: Total 245 GB, Free: 62 GB

osy · 2023-07-31T06:02:22Z

Duplicate of #5489

osy · 2023-07-31T06:02:45Z

Confirmed this is the same issue. Follow #5489 for progress.

osy · 2023-07-31T07:18:41Z

Please try https://github.com/utmapp/UTM/suites/14685729939/artifacts/833666921

neldredge-unco · 2023-08-01T23:55:41Z

https://github.com/utmapp/UTM/suites/14685729939/artifacts/833666921 fixes the problem for me too. Thanks!

By the way, my Mac has 16 GB memory and 100+ GB storage free, and the VM is assigned 11 GB memory and 64 GB storage.

This was referenced Jul 29, 2023

[Beta Only]: After a while, VM gets paused and can not be unpaused #5489

Closed

Port is not opened error #5507

Closed

osy added this to the v4.3 milestone Jul 29, 2023

osy removed this from the v4.3 milestone Jul 31, 2023

osy marked this as a duplicate of #5489 Jul 31, 2023

osy closed this as not planned Won't fix, can't repro, duplicate, stale Jul 31, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

UTM 4.3.3 Linux guest hangs on MacOS with "Error: port is not opened" #5505

UTM 4.3.3 Linux guest hangs on MacOS with "Error: port is not opened" #5505

gglluukk commented Jul 29, 2023

neldredge-unco commented Jul 29, 2023

osy commented Jul 30, 2023

gglluukk commented Jul 30, 2023

neldredge-unco commented Jul 30, 2023

gglluukk commented Jul 30, 2023

osy commented Jul 30, 2023

gglluukk commented Jul 30, 2023

osy commented Jul 30, 2023

gglluukk commented Jul 30, 2023

neldredge-unco commented Jul 30, 2023

neldredge-unco commented Jul 30, 2023

gglluukk commented Jul 30, 2023

osy commented Jul 30, 2023

gglluukk commented Jul 30, 2023

osy commented Jul 30, 2023

gglluukk commented Jul 30, 2023

osy commented Jul 30, 2023

neldredge-unco commented Jul 30, 2023

osy commented Jul 30, 2023

gglluukk commented Jul 30, 2023

osy commented Jul 31, 2023

gglluukk commented Jul 31, 2023

osy commented Jul 31, 2023

gglluukk commented Jul 31, 2023

osy commented Jul 31, 2023

osy commented Jul 31, 2023

osy commented Jul 31, 2023

neldredge-unco commented Aug 1, 2023

UTM 4.3.3 Linux guest hangs on MacOS with "Error: port is not opened" #5505

UTM 4.3.3 Linux guest hangs on MacOS with "Error: port is not opened" #5505

Comments

gglluukk commented Jul 29, 2023

neldredge-unco commented Jul 29, 2023

osy commented Jul 30, 2023

gglluukk commented Jul 30, 2023

neldredge-unco commented Jul 30, 2023

gglluukk commented Jul 30, 2023

osy commented Jul 30, 2023

gglluukk commented Jul 30, 2023

osy commented Jul 30, 2023

gglluukk commented Jul 30, 2023

neldredge-unco commented Jul 30, 2023

neldredge-unco commented Jul 30, 2023

gglluukk commented Jul 30, 2023

osy commented Jul 30, 2023

gglluukk commented Jul 30, 2023

osy commented Jul 30, 2023

gglluukk commented Jul 30, 2023

osy commented Jul 30, 2023

neldredge-unco commented Jul 30, 2023

osy commented Jul 30, 2023

gglluukk commented Jul 30, 2023

osy commented Jul 31, 2023

gglluukk commented Jul 31, 2023

osy commented Jul 31, 2023

gglluukk commented Jul 31, 2023

osy commented Jul 31, 2023

osy commented Jul 31, 2023

osy commented Jul 31, 2023

neldredge-unco commented Aug 1, 2023