UTM icon indicating copy to clipboard operation
UTM copied to clipboard

Failed to install macOS 12.2.1: internal virtualization error

Open sclsj opened this issue 2 years ago • 6 comments

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

  • UTM Version: 3.0.4 (46)
  • OS Version: macOS 12.2 (21D49)
  • Apple Silicon (arm64), using Apple Virtualization

Crash log No crashes have occured.

Debug log Seems to be unavailable for Apple Virtualization.

Upload VM All options are left as default.

sclsj avatar Feb 18 '22 13:02 sclsj

  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

osy avatar Feb 20 '22 02:02 osy

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 avatar Feb 21 '22 01:02 sclsj

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

sclsj avatar Feb 21 '22 01:02 sclsj

Closing as the issue appears to be resolved.

conath avatar Mar 11 '22 22:03 conath

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 avatar Jun 18 '22 19:06 mvarie

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

mvarie avatar Jul 19 '22 21:07 mvarie