Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Alert when QEMU fails to launch doesn't include error message #3369

Open
zakhildev opened this issue Dec 5, 2021 · 28 comments
Open

Alert when QEMU fails to launch doesn't include error message #3369

zakhildev opened this issue Dec 5, 2021 · 28 comments
Labels
bug Something isn't working macOS macOS issues

Comments

@zakhildev
Copy link

Describe the issue
After starting ANY vm, immediately an error pops up saying: "启动 QEMU 时出错". App language in the system preferences is set to English.

Configuration

  • UTM Version: 2.4.1 (40)
  • OS Version: macOS Monterey 12.0.1
  • M1 Mac mini

Crash log
No crash log is available after that error.

Debug log
QEMU Debug Log: debug.log

Upload VM
VM Direct Download Link

error

@conath
Copy link
Contributor

conath commented Dec 5, 2021

Please try this: add English to the preferred languages list in System Preferences => Language & Region. This way UTM will show English UI.

@conath
Copy link
Contributor

conath commented Dec 5, 2021

Unfortunately, the Debug Log is blank. This leads me to believe there is a system error that occurs before UTM can even start the VM properly.

Have you tried restarting your Mac?

Does this error occur with x86_64 VM as well? Please try creating a new VM with x86_64 system and starting that.

@conath conath added the question Further information is requested label Dec 5, 2021
@zakhildev
Copy link
Author

Please try this: add English to the preferred languages list in System Preferences => Language & Region. This way UTM will show English UI.

The default app language is set to English.

Unfortunately, the Debug Log is blank. This leads me to believe there is a system error that occurs before UTM can even start the VM properly.

Have you tried restarting your Mac?

Does this error occur with x86_64 VM as well? Please try creating a new VM with x86_64 system and starting that.

I restarted UTM and my Mac few times. This problem happens with x86_64 VM's as well.

@conath
Copy link
Contributor

conath commented Dec 6, 2021

The default app language is set to English.

that’s not what I asked you to do:

Please try this: add English to the preferred languages list in System Preferences => Language & Region. This way UTM will show English UI.

English doesn’t have to be the default system language, it just has to be in the list.

@zakhildev
Copy link
Author

English doesn’t have to be the default system language, it just has to be in the list.

I meant exactly that. It is on the list, but it is set as the default language as well.

@conath
Copy link
Contributor

conath commented Dec 7, 2021

Ok thanks for double-checking. I would like to solve this, so let's try another way to get some technical diagnostic data from your Mac.

Have you used the Console app before? We can get a detailed log from it. Here's the steps to get additional info via Console app:

  1. Quit UTM if it is opened.
  2. Open Console app, click Start streaming.
  3. In the Console app search box type "UTM" and press return, then click on the grey "any" dropdown and choose "process". The app should show no results (if there are any, click Clear).
  4. Open UTM and attempt to start a VM (the error popup should show)
  5. Quit UTM
  6. In Console app, click one of the lines of activity (center of the window), then in the Menu Bar, choose Edit => Select All and Edit => Copy.
  7. Open TextEdit, choose File => New, then Format => Make Plain Text.
  8. Choose Edit => Paste, then File => Save
  9. In the "Save As:" field, type UTM-System-Log.log, in the "Where" field choose Desktop, then click Save.
  10. Open this issue page in your web browser and attach the UTM-System-Log.log file in a new comment.

Thank you in advance!

@zakhildev

This comment has been minimized.

@conath conath added bug Something isn't working and removed question Further information is requested labels Dec 11, 2021
@conath

This comment has been minimized.

@conath conath changed the title Weird 启动 QEMU 时出错 error Weird 启动 QEMU 时出错 error when attempting to start VM Dec 11, 2021
@conath
Copy link
Contributor

conath commented Dec 11, 2021

FWIW I just tested what I assume is the same ArchLinux ARM VM from the UTM Gallery website:

  1. Go to UTM Gallery site for ArchLinux ARM
  2. Click on Open in UTM
  3. Wait until VM appears in UTM with Play button
  4. Click Play button
  5. VM boots as expected

So I can't reproduce this. My setup:

  • UTM Version: 2.4.1 (40)
  • OS Version: macOS Monterey 12.1 RC (21C51)
  • M1 MacBook Pro

@conath conath added the not reproducible This issue could not be reproduced and therefore unlikely to be fixed. label Dec 11, 2021
@zakhildev
Copy link
Author

zakhildev commented Dec 11, 2021

I think that it is an with QEMU error and not with the UTM it self.

@zakhildev
Copy link
Author

Here I attach additional log after trying to start the VM, not just UTM.

UTM-System-Log.log

@SimaoDias
Copy link

SimaoDias commented Dec 11, 2021

I am having the exact same problem.
I don't have a fix yet tho

Configuration

  • UTM Version: Version 2.4.1 (40)
  • OS Version: macOS Big Sur 11.6
  • M1 MacBook Air

@conath
Copy link
Contributor

conath commented Dec 11, 2021

Here is the relevant part from @zakhil-dev new system log:

         19:28:25.784183+0100    UTM    Running:  -L "/Volumes/Dysk zewnętrzny/Applications/UTM.app/Contents/Resources/qemu" -S -qmp tcp:127.0.0.1:4000,server,nowait -nodefaults -vga none -nographic -chardev "pipe,id=term0,path=/Users/piotrek/Library/Group Containers/WDNLXAD4W8.com.utmapp.UTM/E3459327-D6AC-409C-ABCA-08EAAC345F57.terminal" -serial chardev:term0 -cpu cortex-a72 -smp cpus=8,sockets=1,cores=8,threads=1 -machine virt,highmem=off -accel hvf -accel tcg,tb-size=512 -boot menu=on -m 2048 -device ac97 -name "ArchLinux ARM" -device qemu-xhci,id=usb-bus -device usb-tablet,bus=usb-bus.0 -device usb-mouse,bus=usb-bus.0 -device usb-kbd,bus=usb-bus.0 -device qemu-xhci,id=usb-controller-0 -chardev spicevmc,name=usbredir,id=usbredirchardev0 -device usb-redir,chardev=usbredirchardev0,id=usbredirdev0,bus=usb-controller-0.0 -chardev spicevmc,name=usbredir,id=usbredirchardev1 -device usb-redir,chardev=usbredirchardev1,id=usbredirdev1,bus=usb-controller-0.0 -chardev spicevmc,name=usbredir,id=usbredirchardev2 -device usb-redir,chardev=usbredirc
         19:28:25.809106+0100    UTM    TCP Conn [1:0x6000015d9810] using empty proxy configuration
         19:28:25.810061+0100    UTM    Stream client bypassing proxies on TCP Conn [1:0x6000015d9810]
         19:28:25.810468+0100    UTM    TCP Conn 0x6000015d9810 started
         19:28:25.810988+0100    UTM    [C1 9851D6D7-1A85-4163-B789-946C0E373333 127.0.0.1:4000 tcp, definite, attribution: developer, context: Default Network Context (private), proc: FC72DC0E-88DF-332A-BB5E-15354D110883, no proxy, no fallback, allow socket access] start
         19:28:25.811362+0100    UTM    [C1 127.0.0.1:4000 initial path ((null))] event: path:start @0.000s
         19:28:25.811721+0100    UTM    [C1 127.0.0.1:4000 waiting path (satisfied (Path is satisfied), interface: lo0)] event: path:satisfied @0.000s, uuid: F5F65EBD-C776-4977-8B50-526A310CFD1A
         19:28:25.812726+0100    UTM    [C1 127.0.0.1:4000 in_progress socket-flow (satisfied (Path is satisfied), interface: lo0)] event: flow:start_connect @0.001s
         19:28:25.812736+0100    UTM    nw_connection_report_state_with_handler_on_nw_queue [C1] reporting state preparing
         19:28:25.813340+0100    UTM    nw_socket_handle_socket_event [C1:1] Socket received CONNRESET event
         19:28:25.813509+0100    UTM    nw_socket_handle_socket_event [C1:1] Socket received DISCONNECTED event
error    19:28:25.813708+0100    UTM    nw_socket_handle_socket_event <private> Socket SO_ERROR [61: Connection refused]
         19:28:25.814151+0100    UTM    nw_flow_disconnected [C1 127.0.0.1:4000 in_progress socket-flow (satisfied (Path is satisfied), viable, interface: lo0)] Output protocol disconnected
         19:28:25.814718+0100    UTM    [C1 127.0.0.1:4000 failed socket-flow (satisfied (Path is satisfied), viable, interface: lo0)] event: flow:failed_connect @0.003s, error Connection refused
         19:28:25.815398+0100    UTM    nw_connection_report_state_with_handler_on_nw_queue [C1] reporting state failed error Connection refused
         19:28:25.815920+0100    UTM    TCP Conn 0x6000015d9810 event 3. err: 61
error    19:28:25.815948+0100    UTM    nw_connection_get_connected_socket [C1] Client called nw_connection_get_connected_socket on unconnected nw_connection
         19:28:25.816140+0100    UTM    TCP Conn 0x6000015d9810 complete. fd: -1, err: 61
error    19:28:25.816298+0100    UTM    TCP Conn 0x6000015d9810 Failed : error 0:61 [61]
         19:28:25.816579+0100    UTM    Stream error Error Domain=NSPOSIXErrorDomain Code=61 "Connection refused" UserInfo={_kCFStreamErrorCodeKey=61, _kCFStreamErrorDomainKey=1}
         19:28:25.816781+0100    UTM    QMP stream error seen: Error Domain=NSPOSIXErrorDomain Code=61 "Connection refused" UserInfo={_kCFStreamErrorCodeKey=61, _kCFStreamErrorDomainKey=1}
         19:28:25.817204+0100    UTM    TCP Conn 0x6000015d9810 canceled
         19:28:25.817222+0100    UTM    [C1 9851D6D7-1A85-4163-B789-946C0E373333 127.0.0.1:4000 tcp, legacy-socket, definite, attribution: developer] cancel
         19:28:25.817430+0100    UTM    QMP connection failed, retries left: 29
         19:28:25.817600+0100    UTM    [C1 127.0.0.1:4000 tcp, legacy-socket, definite, attribution: developer] cancelled
         19:28:25.818624+0100    UTM    nw_connection_report_state_with_handler_on_nw_queue [C1] reporting state cancelled error Connection refused
         19:28:25.822381+0100    UTM    filteredItemsFromItems:<private> [8263]--> <private>
         19:28:25.822405+0100    UTM    Requesting sharingServicesForFilteredItems:<private> mask:<private>
         19:28:25.822426+0100    UTM    Query extensions (async) for items: <private> onlyViewerOrEditor:1
         19:28:25.822482+0100    UTM    filteredItemsFromItems:<private> [8263]--> <private>
         19:28:25.822498+0100    UTM    Requesting sharingServicesForFilteredItems:<private> mask:<private>
         19:28:25.822509+0100    UTM    Query extensions (async) for items: <private> onlyViewerOrEditor:1
         19:28:25.822576+0100    UTM    0x120030d00 - [PID=8268] WebProcessProxy::didFinishLaunching:
         19:28:25.824162+0100    UTM    Faulting in CFHTTPCookieStorage singleton
         19:28:25.824176+0100    UTM    Creating default cookie storage with default identifier
         19:28:25.824567+0100    UTM    Faulting in NSHTTPCookieStorage singleton
         19:28:25.827562+0100    UTM    Matching dictionary: <private>, attributesArray: <private>
         19:28:25.827807+0100    UTM    Matching dictionary: <private>, attributesArray: <private>
         19:28:25.827801+0100    UTM    Discover extensions with attributes <private>
         19:28:25.827999+0100    UTM    Discover extensions with attributes <private>
         19:28:25.828447+0100    UTM    [d <private>] <PKHost:0x60000375e000> Beginning discovery for flags: 1024, point: com.apple.ui-services
         19:28:25.828584+0100    UTM    [d <private>] <PKHost:0x60000375e000> Beginning discovery for flags: 1024, point: com.apple.ui-services
         19:28:25.835881+0100    UTM    0x120060340 - NetworkProcessProxy is taking a background assertion because a web process is requesting a connection
         19:28:25.841020+0100    UTM    filteredItemsFromItems:<private> [8263]--> <private>
         19:28:25.841136+0100    UTM    Requesting sharingServicesForFilteredItems:<private> mask:<private>
         19:28:25.841196+0100    UTM    Query extensions (async) for items: <private> onlyViewerOrEditor:1
         19:28:25.841269+0100    UTM    0x135991018 - [pageProxyID=5, webPageID=6, PID=8268] WebPageProxy::updateActivityState: view visibility state changed 0 -> 1
         19:28:25.841291+0100    UTM    Matching dictionary: <private>, attributesArray: <private>
         19:28:25.841399+0100    UTM    Discover extensions with attributes <private>
         19:28:25.840996+0100    UTM    [d <private>] <PKHost:0x60000375e000> Completed discovery. Final # of matches: 1
         19:28:25.842849+0100    UTM    [d <private>] <PKHost:0x60000375e000> Beginning discovery for flags: 1024, point: com.apple.ui-services
         19:28:25.842953+0100    UTM    1 plugins found
         19:28:25.847970+0100    UTM    Service with identifier <private> passes activation rule: 0
         19:28:25.847985+0100    UTM    Service dictionary for plugin <private> not available, skip it.
         19:28:25.848037+0100    UTM    0 compatible services found for attributes <private>
         19:28:25.848143+0100    UTM    Discovery done
         19:28:25.848257+0100    UTM    Discover extensions with attributes <private>
         19:28:25.848463+0100    UTM    [d <private>] <PKHost:0x60000375e000> Beginning discovery for flags: 1024, point: com.apple.services
         19:28:25.850317+0100    UTM    [d <private>] <PKHost:0x60000375e000> Completed discovery. Final # of matches: 1
         19:28:25.850369+0100    UTM    1 plugins found
         19:28:25.850545+0100    UTM    Service with identifier <private> passes activation rule: 1
         19:28:25.864164+0100    UTM    1 compatible services found for attributes <private>
         19:28:25.864272+0100    UTM    Discovery done
         19:28:25.864418+0100    UTM    Discover extensions with attributes <private>
         19:28:25.864626+0100    UTM    [d <private>] <PKHost:0x60000375e000> Beginning discovery for flags: 1024, point: com.apple.services
         19:28:25.865082+0100    UTM    [d <private>] <PKHost:0x60000375e000> Completed discovery. Final # of matches: 1
         19:28:25.865387+0100    UTM    1 plugins found
         19:28:25.865801+0100    UTM    Service with identifier <private> passes activation rule: 0
         19:28:25.865813+0100    UTM    Service dictionary for plugin <private> not available, skip it.
         19:28:25.865844+0100    UTM    [d <private>] <PKHost:0x60000375e000> Completed discovery. Final # of matches: 0
         19:28:25.865931+0100    UTM    0 compatible services found for attributes <private>
         19:28:25.865993+0100    UTM    0 plugins found
         19:28:25.866031+0100    UTM    Discovery done
         19:28:25.866092+0100    UTM    0 compatible services found for attributes <private>
         19:28:25.866175+0100    UTM    Discover extensions with attributes <private>
         19:28:25.866291+0100    UTM    Discovery done
         19:28:25.866504+0100    UTM    Completed querying extensions: <private>
         19:28:25.866585+0100    UTM    [d <private>] <PKHost:0x60000375e000> Beginning discovery for flags: 1024, point: com.apple.services
         19:28:25.866699+0100    UTM    [d <private>] <PKHost:0x60000375e000> Completed discovery. Final # of matches: 0
         19:28:25.866777+0100    UTM    0 plugins found
         19:28:25.866935+0100    UTM    0 compatible services found for attributes <private>
         19:28:25.867062+0100    UTM    Discovery done
         19:28:25.867378+0100    UTM    Completed querying extensions: <private>
         19:28:25.867974+0100    UTM    [d <private>] <PKHost:0x60000375e000> Completed discovery. Final # of matches: 0
         19:28:25.867991+0100    UTM    0 plugins found
         19:28:25.868006+0100    UTM    0 compatible services found for attributes <private>
         19:28:25.868060+0100    UTM    Discovery done
         19:28:25.868355+0100    UTM    Completed querying extensions: <private>
         19:28:25.872637+0100    UTM    Sorted services: <private>
         19:28:25.872787+0100    UTM    Sorted services: <private>
         19:28:25.873024+0100    UTM    Sorted services: <private>
         19:28:25.939086+0100    UTM    0x120011be0 - [PID=0, throttler=0x120030e70] ProcessThrottler::Activity::invalidate: Ending background activity / 'WebProcess initialization'
         19:28:25.993012+0100    UTM    0x135991018 - [pageProxyID=5, webPageID=6, PID=8268] WebPageProxy::decidePolicyForNavigationAction: frameID=3, navigationID=1
         19:28:25.993278+0100    UTM    0x1200118d0 - SOAuthorizationCoordinator::tryAuthorize
         19:28:25.994191+0100    UTM    -[SOConfigurationClient init]  on <private>
         19:28:25.994262+0100    UTM    <SOServiceConnection: 0x600002248000>: new XPC connection
         19:28:25.994366+0100    UTM    0x1200118d0 - SOAuthorizationCoordinator::tryAuthorize: Cannot authorize the requested URL.
         19:28:25.995420+0100    UTM    0x135991018 - [pageProxyID=5, webPageID=6, PID=8268] WebPageProxy::decidePolicyForNavigationAction: listener called: frameID=3, navigationID=1, policyAction=0, safeBrowsingWarning=0, isAppBoundDomain=0
         19:28:25.995439+0100    UTM    0x135991018 - [pageProxyID=5, webPageID=6, PID=8268] WebPageProxy::receivedNavigationPolicyDecision: frameID=3, navigationID=1, policyAction=0
         19:28:25.995533+0100    UTM    0x135991018 - [pageProxyID=5, webPageID=6, PID=8268] WebPageProxy::decidePolicyForNavigationAction: keep using process 8268 for navigation, reason=Process has not yet committed any provisional loads
         19:28:26.063534+0100    UTM    0x135991018 - [pageProxyID=5, webPageID=6, PID=8268] WebPageProxy::didStartProvisionalLoadForFrame: frameID=3
         19:28:26.063555+0100    UTM    0x120030d00 - [PID=8268] WebProcessProxy::didStartProvisionalLoadForMainFrame:
         19:28:26.068382+0100    UTM    Stop operation timeout or force quit
         19:28:26.068447+0100    UTM    Successfuly disconnected!
         19:28:26.068475+0100    UTM    Successfuly disconnected!
         19:28:26.068475+0100    UTM    Input dispatch_io is being closed
         19:28:26.068491+0100    UTM    Exit operation timeout or force quit
         19:28:26.068521+0100    UTM    Successfuly disconnected!
         19:28:26.068713+0100    UTM    Cleanup completed!
         19:28:26.068737+0100    UTM    Source got cancelled
         19:28:26.073496+0100    UTM    Requested resource was not within the code object: /System/Library/Frameworks/AppKit.framework/Resources/NSAlertPanelVertical.nib, /Volumes/Dysk zewnętrzny/Applications/UTM.app/Contents
         19:28:26.073508+0100    UTM    MacOS error: -50
         19:28:26.081213+0100    UTM    Ignoring nib not in main bundle: <private>, <private> v<private>
         19:28:26.084927+0100    UTM    RPC: Error Domain=com.utmapp.utm Code=-1 "No connection for RPC." UserInfo={NSLocalizedDescription=No connection for RPC.}
         19:28:26.376346+0100    UTM    0x135991018 - [pageProxyID=5, webPageID=6, PID=8268] WebPageProxy::didNavigateWithNavigationDataShared:
         19:28:26.376399+0100    UTM    0x135991018 - [pageProxyID=5, webPageID=6, PID=8268] WebPageProxy::didCommitLoadForFrame: frameID=3
         19:28:26.376462+0100    UTM    0x135991018 - [pageProxyID=5, webPageID=6, PID=8268] WebPageProxy::didFinishDocumentLoadForFrame: frameID=3
         19:28:26.376496+0100    UTM    0x135991018 - [pageProxyID=5, webPageID=6, PID=8268] WebPageProxy::decidePolicyForNavigationAction: frameID=12, navigationID=0
         19:28:26.376564+0100    UTM    0x1200118d0 - SOAuthorizationCoordinator::tryAuthorize
         19:28:26.376791+0100    UTM    0x1200118d0 - SOAuthorizationCoordinator::tryAuthorize: Cannot authorize the requested URL.
         19:28:26.376873+0100    UTM    0x135991018 - [pageProxyID=5, webPageID=6, PID=8268] WebPageProxy::didStartProvisionalLoadForFrame: frameID=12
         19:28:26.376895+0100    UTM    0x135991018 - [pageProxyID=5, webPageID=6, PID=8268] WebPageProxy::didCommitLoadForFrame: frameID=12
         19:28:26.376907+0100    UTM    0x135991018 - [pageProxyID=5, webPageID=6, PID=8268] WebPageProxy::didFinishDocumentLoadForFrame: frameID=12
         19:28:26.376918+0100    UTM    0x135991018 - [pageProxyID=5, webPageID=6, PID=8268] WebPageProxy::didFinishLoadForFrame: frameID=12
         19:28:26.377515+0100    UTM    0x135991018 - [pageProxyID=5, webPageID=6, PID=8268] WebPageProxy::decidePolicyForNavigationAction: listener called: frameID=12, navigationID=2, policyAction=0, safeBrowsingWarning=0, isAppBoundDomain=0
         19:28:26.377533+0100    UTM    0x135991018 - [pageProxyID=5, webPageID=6, PID=8268] WebPageProxy::receivedNavigationPolicyDecision: frameID=12, navigationID=2, policyAction=0
         19:28:26.379312+0100    UTM    0x135991018 - [pageProxyID=5, webPageID=6, PID=8268] WebPageProxy::didFinishLoadForFrame: frameID=3
         19:28:26.397768+0100    UTM    0x12015c0c0 - GPUProcessProxy is taking a background assertion because a web process is requesting a connection
         19:28:26.464349+0100    UTM    WebMediaSessionManager::addPlaybackTargetPickerClient 23
         19:28:26.475014+0100    UTM    WebMediaSessionManager::addPlaybackTargetPickerClient 29
         19:28:26.475397+0100    UTM    WebMediaSessionManager::addPlaybackTargetPickerClient 34
         19:28:26.917586+0100    UTM    TCP Conn [2:0x6000015f4210] using empty proxy configuration
         19:28:26.917619+0100    UTM    Stream client bypassing proxies on TCP Conn [2:0x6000015f4210]
         19:28:26.917635+0100    UTM    TCP Conn 0x6000015f4210 started
         19:28:26.917848+0100    UTM    TCP Conn 0x6000015f4210 canceled
         19:28:26.917767+0100    UTM    [C2 EB0F94F8-33A3-437B-8F2D-85569688ADD8 127.0.0.1:4000 tcp, definite, attribution: developer, context: Default Network Context (private), proc: FC72DC0E-88DF-332A-BB5E-15354D110883, no proxy, no fallback, allow socket access] start
         19:28:26.918181+0100    UTM    [C2 127.0.0.1:4000 initial path ((null))] event: path:start @0.000s
         19:28:26.918349+0100    UTM    [C2 127.0.0.1:4000 waiting path (satisfied (Path is satisfied), viable, interface: lo0)] event: path:satisfied @0.000s, uuid: F5F65EBD-C776-4977-8B50-526A310CFD1A
         19:28:26.918977+0100    UTM    [C2 127.0.0.1:4000 in_progress socket-flow (satisfied (Path is satisfied), viable, interface: lo0)] event: flow:start_connect @0.000s
         19:28:26.918999+0100    UTM    nw_connection_report_state_with_handler_on_nw_queue [C2] reporting state preparing
         19:28:26.919166+0100    UTM    [C2 EB0F94F8-33A3-437B-8F2D-85569688ADD8 127.0.0.1:4000 tcp, legacy-socket, definite, attribution: developer] cancel
         19:28:26.919193+0100    UTM    [C2 127.0.0.1:4000 tcp, legacy-socket, definite, attribution: developer] cancelled
         19:28:26.919341+0100    UTM    nw_flow_disconnected [C2 127.0.0.1:4000 cancelled socket-flow ((null))] Output protocol disconnected
         19:28:26.919374+0100    UTM    nw_connection_report_state_with_handler_on_nw_queue [C2] reporting state cancelled
         19:28:32.936317+0100    UTM    Stop operation timeout or force quit
         19:28:32.936399+0100    UTM    Exit operation timeout or force quit

The lines that begin with error are where the system log message type is "error".

UTM attempts to start the QEMU backend with management port at local TCP 4000 (-qmp tcp:127.0.0.1:4000); but gets Connection refused.

@zakhil-dev do you have some kind of Firewall enabled, or are you seeing a "QEMUHelper" crash report appear? It might be useful to re-do the test and instead of searching for "utm" in the Console, search for "qemu".

@zakhildev
Copy link
Author

The only firewall which was running was the system one. I have turned it off, but the error still occurred. Down below I attach logs from the Console app after searching "qemu" in it.

QEMU-System-Log.log

@zakhildev
Copy link
Author

Just updated to MacOS 12.1, and I want to let you know that the issue is still happening.

@conath
Copy link
Contributor

conath commented Dec 16, 2021

The only firewall which was running was the system one. I have turned it off, but the error still occurred. Down below I attach logs from the Console app after searching "qemu" in it.

QEMU-System-Log.log

There are three errors in this log:

QEMUHelper cannot open file at line 45340 of [d24547a13b]
QEMUHelper os_unix.c:45340: (2) open(/var/db/DetachedSignatures) - No such file or directory
QEMUHelper Error starting QEMU: Error Domain=NSPOSIXErrorDomain Code=1 "Operation not permitted"

I just successfully started a UTM VM on my Mac and my System Log also includes the first two errors, but not the last one. This line of log and the error alert text is generated in the following lines of UTM code:

UTM/QEMUHelper/QEMUHelper.m

Lines 127 to 128 in 6524c73

NSLog(@"Error starting QEMU: %@", err);
onExit(NO, NSLocalizedString(@"Error starting QEMU.", @"QEMUHelper"));

So here in line 128 we have the bug that leads to the missing information in the popup. The returned text does not include the underlying error message, that should be fixed.

As to the actual error why you can't launch VMs, I am not sure what causes "Operation not permitted". Maybe your macOS user isn't admin? (not sure if this is required, actually - just guessing)

@conath conath added interface Design, UX/UI issues macOS macOS issues and removed not reproducible This issue could not be reproduced and therefore unlikely to be fixed. interface Design, UX/UI issues labels Dec 16, 2021
@conath conath changed the title Weird 启动 QEMU 时出错 error when attempting to start VM Alert when QEMU fails to launch doesn't include error message Dec 16, 2021
@samuela
Copy link

samuela commented Dec 19, 2021

I'm seeing the same error after upgrading to macOS 12.1. FWIW I don't have any qemu-* executables in PATH anymore after the upgrade (not sure if they were they prior to the upgrade tho):

❯ qemu
zsh: command not found: qemu

Is this related? Does UTM maintain its own internal qemu binaries or does it search PATH? Are there any known fixes for this?

@samuela
Copy link

samuela commented Dec 19, 2021

Re-downloading and re-installing UTM "solved" the issue for me.

@conath
Copy link
Contributor

conath commented Dec 19, 2021

@samuela UTM is a sandboxed Mac app, so you won't find its included version of QEMU as a standalone binary. In other words, there is no need to install QEMU separately, unless you want to run VMs without UTM.

Thank you for letting us know you were able to resolve your issue by reinstalling. @zakhil-dev and @SimaoDias might also want to try this. Your VMs are not deleted when you reinstall UTM.

@zakhildev
Copy link
Author

I will check this out asap and let you know if it helped.

@zakhildev
Copy link
Author

For me full reinstall resolved the issue

@SimaoDias
Copy link

Hi @conath.

I uninstalled UTM and installed it fresh from https://mac.getutm.app.

It is working now. My configuration is the same. Did the dmg package change? I didn't update my OS

UTM Version: Version 2.4.1 (40)
OS Version: macOS Big Sur 11.6
M1 MacBook Air

@conath
Copy link
Contributor

conath commented Dec 19, 2021

No, the dmg did not change. Not sure what’s at fault here, either a file permission error or another macOS security system that interferes with launching the QEMU process.

@SimaoDias
Copy link

So strange. Thank you for your help @conath @samuela and @zakhil-dev

@conath
Copy link
Contributor

conath commented Dec 28, 2021

Re-opening because the UI bug remains: we need to show a meaningful error message.

@barrykn
Copy link

barrykn commented Aug 24, 2022

I just got my first Apple Silicon Mac (M1 Mac Mini, for what it's worth) and ran into this problem, as well as a different "solution"/workaround.

Basic steps to reproduce:

  1. Have a(n Apple Silicon) Mac running Monterey (12.5.1 21G83 in my case) with two admin users, which I will call admin1 and admin2.
  2. With admin1, download UTM from mac.getutm.app or GitHub, and install it into the Applications folder.
  3. With admin2, create a new VM (virtualized or emulated, it doesn't make a difference) and try to start it.

The workaround is to sudo chown -R admin2 /Applications/UTM.app between steps 2 and 3. I imagine that this breaks UTM for admin1, but I did not test that yet. I also don't yet know if this issue is exclusive to Apple Silicon or if it also affects Intel.

ETA: I forgot to mention, this is with UTM 3.2.4.

@dreamchaser96
Copy link

Reinstalling UTM solved the issue

@BenPhegan
Copy link

BenPhegan commented Jul 6, 2023

Just in case this helps anyone in future. I had a similar issue with UTM not being able to launch a VM post an update of UTM with an error of "Operation not permitted". After a bit of digging, I found that the QEMULauncher had been quarantined by MacOS Safari due to being downloaded.

To check:

❯ ls -l@  /Applications/UTM.app/Contents/XPCServices/QEMUHelper.xpc/Contents/MacOS/QEMULauncher.app/Contents/MacOS/QEMULauncher
-rwxr-xr-x@ 1 ben  admin  168480  4 Jul 01:16 /Applications/UTM.app/Contents/XPCServices/QEMUHelper.xpc/Contents/MacOS/QEMULauncher.app/Contents/MacOS/QEMULauncher
	com.apple.quarantine	    57 

Note the com.apple.quarantine.

To fix:

xattr -d com.apple.quarantine /Applications/UTM.app/Contents/XPCServices/QEMUHelper.xpc/Contents/MacOS/QEMULauncher.app/Contents/MacOS/QEMULauncher

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working macOS macOS issues
Projects
None yet
Development

No branches or pull requests

7 participants