utmapp / UTM

Virtual machines for iOS and macOS
https://getutm.app
Apache License 2.0
26.58k stars 1.33k forks source link

Failed to install macOS 12.2.1: internal virtualization error #3638

Open sclsj opened 2 years ago

sclsj commented 2 years ago

Describe the issue Installation of macOS 12.2.1_21D62 on macOS 12.2 using UTM 3.0.4 (46) resulted in error message "internal virtualization error. installation has failed" with menu bar showing "Installation: 0%"

Configuration

Crash log No crashes have occured.

Debug log Seems to be unavailable for Apple Virtualization.

Upload VM All options are left as default.

osy commented 2 years ago

1) Can you confirm that you have allocated at least 25GB to the VM and have enough disk space to run it? 2) Can you open Console and filter by "Virtualization" and see if any additional error messages show up when you try to install?

Thanks

sclsj commented 2 years ago

After a few more tries, it suddenly just works. The default allocation should be 64GB. I have about 1.5 TB free on my internal SSD and no APFS snapshots, so shouldn't be a problem with disk space. I think it's probably a bug in Apple Virtualization because I have encountered some weird glitches here and there when I transitioned to m1 mac / macOS 12.

sclsj commented 2 years ago

I cannot replicate the error now, but I collected the logs via log --collect and searched for "Virtualization". 0 messages are shown.

conath commented 2 years ago

Closing as the issue appears to be resolved.

mvarie commented 2 years ago

Same with UniversalMac_13.0_22A5266r_Restore.ipsw on UTM Version 3.2.4 (58) :

Internal Virtualization error. Installation failed.

Log:


default 21:48:54.248995+0200    com.apple.Virtualization.Installation   Entered:_AMRecoveryDeviceDisconnected, libusbrestore-device:0x3EFEACF0
default 21:48:54.249032+0200    com.apple.Virtualization.Installation   Entered:__thr_AMRecoveryDeviceDisconnected, libusbrestore-device:0x3EFEACF0
default 21:48:54.249094+0200    com.apple.Virtualization.Installation   tid:7703 - Recovery mode device disconnected
default 21:48:54.305279+0200    com.apple.Virtualization.VirtualMachine Guest requested binary version: 43, setting binary version to: 31
default 21:48:54.317440+0200    com.apple.Virtualization.VirtualMachine PGDisplayNub[0]: Created
default 21:48:54.777940+0200    InternetSharing com.apple.Virtualization.Virtua: com.apple.NetworkSharing.broadcast-0 has been started
error   21:49:06.704942+0200    com.apple.Virtualization.VirtualMachine interrupt <private>
default 21:49:09.661792+0200    com.apple.Virtualization.Installation   USBMuxHandleDictionary:1437 Adding event 0x11f7ea880 to changelist.
default 21:49:09.662311+0200    com.apple.Virtualization.Installation   Entered:_AMMuxedVersion2DeviceConnected, mux-device:4
default 21:49:09.669792+0200    com.apple.Virtualization.Installation   USBMuxConnectByPort:584 Connecting to port 32498 (f2, 7e)
default 21:49:09.673851+0200    com.apple.Virtualization.Installation   AMDeviceConnect (thread 0x16d28b000): Device @0x80100000 is not a device this instance is tracking (is actually com.apple.mobile.restored). Move along, move along.
default 21:49:09.676747+0200    com.apple.Virtualization.Installation   USBMuxConnectByPort:584 Connecting to port 32498 (f2, 7e)
default 21:49:09.680373+0200    com.apple.Virtualization.Installation   USBMuxConnectByPort:584 Connecting to port 32498 (f2, 7e)
default 21:49:09.683643+0200    com.apple.Virtualization.Installation   USBMuxConnectByPort:584 Connecting to port 32498 (f2, 7e)
default 21:49:09.686743+0200    com.apple.Virtualization.Installation   USBMuxConnectByPort:584 Connecting to port 32498 (f2, 7e)
default 21:49:09.691495+0200    com.apple.Virtualization.Installation   tid:2c0b - RestoreOS mode device connected
default 21:49:09.691972+0200    com.apple.Virtualization.Installation   USBMuxConnectByPort:584 Connecting to port 34835 (13, 88)
default 21:49:11.697149+0200    com.apple.Virtualization.Installation   USBMuxConnectByPort:584 Connecting to port 32498 (f2, 7e)
default 21:49:11.703169+0200    com.apple.Virtualization.Installation   USBMuxConnectByPort:584 Connecting to port 32498 (f2, 7e)
default 21:49:11.761194+0200    com.apple.Virtualization.Installation   tid:1530b - amai: AMAuthInstallBundleCopyBuildIdentityForVariant: AMAuthInstallBundleCopyBuildIdentityForVariant: Found variant: Customer Erase Install (IPSW)
default 21:49:11.769345+0200    com.apple.Virtualization.Installation   tid:1530b - no override trust object found
default 21:49:11.795578+0200    com.apple.Virtualization.Installation   tid:1530b - amai: AMAuthInstallBundleCopyBuildIdentityForVariant: AMAuthInstallBundleCopyBuildIdentityForVariant: Found variant: macOS Customer
default 21:49:11.846776+0200    com.apple.Virtualization.Installation   AMAuthInstallApImg4FindProperty: failed to find property tag 0x16140901066331742576
default 21:49:11.846807+0200    com.apple.Virtualization.Installation   AMAuthInstallApImg4FindProperty: failed to find property tag 0x16140901066415039591
default 21:49:11.886013+0200    com.apple.Virtualization.Installation   AMAuthInstallApImg4FindProperty: failed to find property tag 0x16140901066331742576
default 21:49:11.886023+0200    com.apple.Virtualization.Installation   AMAuthInstallApImg4FindProperty: failed to find property tag 0x16140901066415039591
default 21:49:11.887497+0200    com.apple.Virtualization.Installation   AMSupportPlatformCreateBufferFromNativeFilePath: open failed: No such file or directory
default 21:49:11.887579+0200    com.apple.Virtualization.Installation   tid:1530b - amai: AMAuthInstallApCopyDeviceEntryFromDeviceMap: Failed to read devicemap from file:///usr/local/standalone/firmware/device_map.plist
default 21:49:11.887609+0200    com.apple.Virtualization.Installation   tid:1530b - amai: AMAuthInstallApImg4ServerRequestAddUIDMode: WARNING: Could not apply UID mode from device map.
default 21:49:11.889430+0200    com.apple.Virtualization.Installation   tid:1530b - overwrite InstallDiags to false
default 21:49:11.889482+0200    com.apple.Virtualization.Installation   USBMuxConnectByPort:584 Connecting to port 32498 (f2, 7e)
default 21:49:11.892142+0200    com.apple.Virtualization.Installation   USBMuxConnectByPort:584 Connecting to port 32498 (f2, 7e)
default 21:49:11.893368+0200    com.apple.Virtualization.Installation   tid:1530b - unable to open device_map.txt: No such file or directory
default 21:49:11.893621+0200    com.apple.Virtualization.Installation   USBMuxConnectByPort:584 Connecting to port 32498 (f2, 7e)
default 21:49:11.895076+0200    com.apple.Virtualization.Installation   tid:1530b - no value returned for BootArgs
default 21:49:11.895118+0200    com.apple.Virtualization.Installation   tid:1530b - _copyDeviceProperty() failed for restore bootargs
default 21:49:11.895155+0200    com.apple.Virtualization.Installation   USBMuxConnectByPort:584 Connecting to port 32498 (f2, 7e)
default 21:49:11.896644+0200    com.apple.Virtualization.Installation   tid:1530b - no value returned for MarketingPartNumber
default 21:49:11.896682+0200    com.apple.Virtualization.Installation   tid:1530b - _copyDeviceProperty() failed for mpn
default 21:49:11.898196+0200    com.apple.Virtualization.Installation   USBMuxConnectByPort:584 Connecting to port 32498 (f2, 7e)
default 21:49:11.924900+0200    com.apple.Virtualization.Installation   tid:1530b - Couldn't get asset 3 path, skiping to next asset.
default 21:49:11.924923+0200    com.apple.Virtualization.Installation   tid:1530b - Couldn't get asset 4 path, skiping to next asset.
default 21:49:11.924990+0200    com.apple.Virtualization.Installation   tid:1530b - Couldn't get asset 6 path, skiping to next asset.
default 21:49:11.925015+0200    com.apple.Virtualization.Installation   tid:1530b - Couldn't get asset 7 path, skiping to next asset.
default 21:49:11.925302+0200    com.apple.Virtualization.Installation   tid:1530b - Can't return padding information since it's not in the Restore.plist, looking in BuildManifest.plist
default 21:49:11.949443+0200    com.apple.Virtualization.Installation   tid:1530b - Established proxy for device ID 4
default 21:49:11.949497+0200    com.apple.Virtualization.Installation   USBMuxConnectByPort:584 Connecting to port 14852 (04, 3a)
default 21:49:12.024844+0200    com.apple.Virtualization.Installation   tid:1530b - dumping CFError returned by restored:
default 21:49:12.024868+0200    com.apple.Virtualization.Installation   tid:1530b - CFError domain:AMRestoreErrorDomain code:10 description:This host version is unsupported. You may need to update your host tools.
default 21:49:12.216963+0200    com.apple.Virtualization.Installation   tid:1530b - 
==== device restore output ====
[19:48:56.0233-GMT]{4>7} CHECKPOINT NOTICE: Image4 device: AP nonce clearable
entering ramrod_clear_ap_nonce
[19:48:56.0259-GMT]{4>7} CHECKPOINT NOTICE: AP nonce consumed
This target supports system nvram
ramrod_copy_NVRAM_variable_from_devicetree: Reading 40A0DDD2-77F8-4392-B4A3XXXXXXXXX6516:auto-boot as a system nvram var
[19:48:56.0259-GMT]{4>7} CHECKPOINT NOTICE: Pre-existing NVRAM variable: auto-boot=false
ramrod_copy_NVRAM_variable_from_devicetree: Reading 40A0DDD2-77F8-4392-B4A3XXXXXXXXX6516:boot-command as a system nvram var
ramrod_copy_NVRAM_variable_from_devicetree: Reading 40A0DDD2-77F8-4392-B4A3XXXXXXXXX6516:upgrade-retry as a system nvram var
ramrod_copy_NVRAM_variable_from_devicetree: Reading 40A0DDD2-77F8-4392-B4A3-1E7304206516:ota-uuid as a system nvram var
[19:48:56.0259-GMT]{4>7} CHECKPOINT NOTICE: Pre-existing NVRAM variable: restore-outcome=initial_monitor_no_return
ramrod_copy_NVRAM_variable_from_devicetree: Reading 40A0DDD2-77F8-4<…>
default 21:49:12.231456+0200    com.apple.Virtualization.Installation   tid:1530b - <Restore Device 0x11ee19820>: Restore failed (result = 10)
default 21:49:12.231496+0200    com.apple.Virtualization.Installation   tid:1530b - Can't send dump_console command since device is not in recovery mode
default 21:49:12.231520+0200    com.apple.Virtualization.Installation   AMRestorePerformRestoreModeRestoreWithError failed with error: 10
default 21:49:12.231571+0200    com.apple.Virtualization.Installation   tid:1530b - State Machine Dump, status:ERROR - [state:DFU remaining-cycles:1] -> [state:Recovery remaining-cycles:0] -> [state:RestoreOS remaining-cycles:0 (current state)]
default 21:49:12.231625+0200    com.apple.Virtualization.Installation   tid:1530b - State is now set to error: AMRestorePerformRestoreModeRestoreWithError failed with error: 10
default 21:49:12.232527+0200    powerd  Process com.apple.Virtualization.Instal.2151 Released NetworkClientActive "Restoring" age:00:00:52  id:73014477475 [System: PrevIdle DeclUser kDisp]
default 21:49:12.232692+0200    runningboardd   Invalidating assertion 397-326-631 (target:[xpcservice<com.apple.Virtualization.Installation([app<application.com.utmapp.UTM.72552887.72553688(501)>:2128])(501)>:2151:2151]) from originator [daemon<com.apple.powerd>:326]
default 21:49:12.233844+0200    com.apple.Virtualization.Installation   TCP Conn [4:0x13efa88a0] using empty proxy configuration
default 21:49:12.233860+0200    com.apple.Virtualization.Installation   Stream client bypassing proxies on TCP Conn [4:0x13efa88a0]
default 21:49:12.233869+0200    com.apple.Virtualization.Installation   TCP Conn 0x13efa88a0 started
default 21:49:12.233968+0200    com.apple.Virtualization.Installation   [C4 74733CF7-2EF6-4A36-B8BE-F053A2537BF5 Hostname#64ede6c7:443 tcp, definite, attribution: developer, context: Default Network Context (private), proc: C291F4D9-DA80-32BC-A2CF-868CC726F15B, no proxy, allow socket access] start
default 21:49:12.233994+0200    com.apple.Virtualization.Installation   [C4 Hostname#64ede6c7:443 initial path ((null))] event: path:start @0.000s
default 21:49:12.234328+0200    InternetSharing com.apple.Virtualization.Virtua: com.apple.NetworkSharing.broadcast-0 (idle) has been stopped
default 21:49:12.234150+0200    com.apple.Virtualization.Installation   [C4 Hostname#64ede6c7:443 waiting path (satisfied (Path is satisfied), interface: en0, ipv4, dns)] event: path:satisfied @0.000s, uuid: AAAA2814-D1E4-4730-B0FA-86FBD06B0D05
default 21:49:12.234296+0200    com.apple.Virtualization.Installation   [C4 Hostname#64ede6c7:443 in_progress resolver (satisfied (Path is satisfied), interface: en0, ipv4, dns)] event: resolver:start_dns @0.000s
default 21:49:12.234388+0200    com.apple.Virtualization.Installation   nw_connection_report_state_with_handler_on_nw_queue [C4] reporting state preparing
default 21:49:12.234770+0200    com.apple.Virtualization.VirtualMachine PGDisplayNub[0]: Destroyed
default 21:49:12.234805+0200    com.apple.Virtualization.VirtualMachine PGDisplay[0](Apple Virtual/0x12345678): Destroyed
default 21:49:12.237412+0200    com.apple.Virtualization.Installation   USBMuxHandleDictionary:1437 Adding event 0x13ef74410 to changelist.
default 21:49:12.237445+0200    com.apple.Virtualization.Installation   Entered:_AMMuxedDeviceDisconnected, mux-device:4
default 21:49:12.237484+0200    com.apple.Virtualization.Installation   Entered:__thr_AMMuxedDeviceDisconnected, mux-device:4
default 21:49:12.237551+0200    com.apple.Virtualization.Installation   tid:8307 - RestoreOS mode device disconnected
default 21:49:12.238490+0200    com.apple.Virtualization.Installation   tid:2c0b - [PurpleReverseProxy]: Jun 18 21:49:12 com.apple.Virtualization.Installation[2151] <Error>: RPSocket.cpp:508(RPSocketReadBuffer): EOF on <RPSocket 0x13ee16dd0: (null) fd=14>
default 21:49:12.238548+0200    com.apple.Virtualization.Installation   tid:2c0b - [PurpleReverseProxy]: Jun 18 21:49:12 com.apple.Virtualization.Installation[2151] <Error>: RPSocket.cpp:218(signal): No client callback, missing event 8 for socket 0x13ee52830
default 21:49:12.266918+0200    com.apple.Virtualization.Installation   nw_endpoint_resolver_update [C4 Hostname#64ede6c7:443 in_progress resolver (satisfied (Path is satisfied), interface: en0, ipv4, dns)] Adding endpoint handler for IPv4#15bf723a:443
default 21:49:12.267298+0200    com.apple.Virtualization.Installation   [C4 Hostname#64ede6c7:443 in_progress resolver (satisfied (Path is satisfied), interface: en0, ipv4, dns)] event: resolver:receive_dns @0.033s
default 21:49:12.268199+0200    com.apple.Virtualization.Installation   [C4.1 IPv4#15bf723a:443 initial path ((null))] event: path:start @0.034s
default 21:49:12.268709+0200    com.apple.Virtualization.Installation   [C4.1 IPv4#15bf723a:443 waiting path (satisfied (Path is satisfied), interface: en0, ipv4, dns)] event: path:satisfied @0.034s, uuid: 2941AA83-8DAD-4D12-A386-A688DF0DA63B
default 21:49:12.270142+0200    com.apple.Virtualization.Installation   [C4.1 IPv4#15bf723a:443 in_progress socket-flow (satisfied (Path is satisfied), interface: en0, ipv4, dns)] event: flow:start_connect @0.036s
default 21:49:12.285388+0200    com.apple.Virtualization.Installation   nw_socket_handle_socket_event [C4.1:1] Socket received CONNECTED event
default 21:49:12.285427+0200    com.apple.Virtualization.Installation   nw_flow_connected [C4.1 IPv4#15bf723a:443 in_progress socket-flow (satisfied (Path is satisfied), viable, interface: en0, ipv4, dns)] Output protocol connected (socket)
default 21:49:12.285480+0200    com.apple.Virtualization.Installation   [C4.1 IPv4#15bf723a:443 ready socket-flow (satisfied (Path is satisfied), viable, interface: en0, ipv4, dns)] event: flow:finish_connect @0.051s
default 21:49:12.285509+0200    com.apple.Virtualization.Installation   nw_connection_report_state_with_handler_on_nw_queue [C4] reporting state ready
default 21:49:12.285588+0200    com.apple.Virtualization.Installation   [C4 Hostname#64ede6c7:443 ready resolver (satisfied (Path is satisfied), interface: en0, ipv4, dns)] event: flow:finish_connect @0.051s
default 21:49:12.285797+0200    com.apple.Virtualization.Installation   [C4.1 IPv4#15bf723a:443 ready socket-flow (satisfied (Path is satisfied), viable, interface: en0, ipv4, dns)] event: flow:changed_viability @0.051s
default 21:49:12.285952+0200    com.apple.Virtualization.Installation   [C4 Hostname#64ede6c7:443 ready resolver (satisfied (Path is satisfied), interface: en0, ipv4, dns)] event: flow:changed_viability @0.051s
default 21:49:12.286056+0200    com.apple.Virtualization.Installation   TCP Conn 0x13efa88a0 event 1. err: 0
default 21:49:12.286190+0200    com.apple.Virtualization.Installation   TCP Conn 0x13efa88a0 complete. fd: 9, err: 0
default 21:49:12.286303+0200    com.apple.Virtualization.Installation   TCP Conn 0x13efa88a0 starting SSL negotiation
error   21:49:12.307712+0200    kernel  Sandbox: com.apple.Virtua(2151) deny(1) file-write-create /private/var/folders/lg/8cctkvdn2r51mn8lxygljjym0000gn/C/com.apple.Virtualization.Installation.dNl9iu/mds
default 21:49:12.308077+0200    com.apple.Virtualization.Installation   UNIX error exception: 1
default 21:49:12.321999+0200    com.apple.Virtualization.Installation   CSSM Exception: 100001 UNIX[Operation not permitted]
default 21:49:12.327378+0200    com.apple.Virtualization.Installation   CSSM Exception: 100001 UNIX[Operation not permitted]
default 21:49:12.330218+0200    com.apple.Virtualization.Installation   CFNetwork SSLHandshake failed (-9808)
error   21:49:12.330279+0200    com.apple.Virtualization.Installation   TCP Conn 0x13efa88a0 SSLHandshake failed (-9808)
default 21:49:12.341027+0200    runningboardd   [xpcservice<com.apple.Virtualization.Installation([app<application.com.utmapp.UTM.72552887.72553688(501)>:2128])(501)>:2151:2151] Ignoring jetsam update because this process is not memory-managed
default 21:49:12.341394+0200    runningboardd   [xpcservice<com.apple.Virtualization.Installation([app<application.com.utmapp.UTM.72552887.72553688(501)>:2128])(501)>:2151:2151] Ignoring suspend because this process is not lifecycle managed
default 21:49:12.341509+0200    runningboardd   [xpcservice<com.apple.Virtualization.Installation([app<application.com.utmapp.UTM.72552887.72553688(501)>:2128])(501)>:2151:2151] Ignoring role changes because this process is not role managed
default 21:49:12.341578+0200    runningboardd   [xpcservice<com.apple.Virtualization.Installation([app<application.com.utmapp.UTM.72552887.72553688(501)>:2128])(501)>:2151:2151] Ignoring GPU update because this process is not GPU managed
default 21:49:12.401281+0200    runningboardd   [xpcservice<com.apple.Virtualization.VirtualMachine([app<application.com.utmapp.UTM.72552887.72553688(501)>:2128])(501)>:2157:2157] termination reported by launchd (0, 0, 0)
default 21:49:12.401374+0200    runningboardd   Removing process: [xpcservice<com.apple.Virtualization.VirtualMachine([app<application.com.utmapp.UTM.72552887.72553688(501)>:2128])(501)>:2157:2157]
default 21:49:12.401535+0200    runningboardd   removeJobWithInstance called for identity without existing job [xpcservice<com.apple.Virtualization.VirtualMachine([app<application.com.utmapp.UTM.72552887.72553688(501)>:2128])(501)>:2157:2157]
default 21:49:12.401565+0200    runningboardd   Removing assertions for terminated process: [xpcservice<com.apple.Virtualization.VirtualMachine([app<application.com.utmapp.UTM.72552887.72553688(501)>:2128])(501)>:2157:2157]
default 21:49:12.481245+0200    com.apple.Virtualization.Installation   tid:1530b - amai: AMAuthInstallPlatformRemoveDirectory: failed to remove directory: No such file or directory
default 21:49:12.481337+0200    com.apple.Virtualization.Installation   tid:1530b - Failed to remove directory file:///var/folders/lg/8cctkvdn2r51mn8lxygljjym0000gn/T/com.apple.Virtualization.Installation.dNl9iu/PersonalizedBundle.5AyCxn
default 21:49:12.506176+0200    com.apple.Virtualization.Installation   TCP Conn 0x13efa88a0 canceled
default 21:49:12.506220+0200    com.apple.Virtualization.Installation   [C4 74733CF7-2EF6-4A36-B8BE-F053A2537BF5 Hostname#64ede6c7:443 tcp, legacy-socket, definite, attribution: developer] cancel
default 21:49:12.506268+0200    com.apple.Virtualization.Installation   [C4 74733CF7-2EF6-4A36-B8BE-F053A2537BF5 Hostname#64ede6c7:443 tcp, legacy-socket, definite, attribution: developer] cancelled
    [C4.1 2941AA83-8DAD-4D12-A386-A688DF0DA63B 192.168.0.3:49339<->IPv4#15bf723a:443]
    Connected Path: satisfied (Path is satisfied), viable, interface: en0, ipv4, dns
    Privacy Stance: Not Eligible
    Duration: 0.272s, DNS @0.000s took 0.033s, TCP @0.036s took 0.015s
    bytes in/out: 5516/172, packets in/out: 2/1, rtt: 0.016s, retransmitted bytes: 0, out-of-order bytes: 0
default 21:49:12.506377+0200    com.apple.Virtualization.Installation   nw_flow_disconnected [C4.1 IPv4#15bf723a:443 cancelled socket-flow ((null))] Output protocol disconnected
default 21:49:12.506661+0200    com.apple.Virtualization.Installation   nw_connection_report_state_with_handler_on_nw_queue [C4] reporting state cancelled
mvarie commented 2 years ago

Solved here: https://github.com/utmapp/UTM/issues/4099