search

libimobiledevice / idevicerestore

Restore/upgrade firmware of iOS devices
https://libimobiledevice.org
GNU Lesser General Public License v3.0
1.33k stars 392 forks source link

ASR failing on iPadOS14 #364

Open cheesycod opened 4 years ago

cheesycod commented 4 years ago 
[liveuser@tmeow Downloads]$ sudo idevicerestore -e iPad_64bit_TouchID_14.0_18A5373a_Restore.ipsw 
Found device in Recovery mode
Identified device as j81ap, iPad5,3
Extracting BuildManifest from IPSW
Product Version: 14.0
Product Build: 18A5373a Major: 18
INFO: device serial number is DLXQD75SG5VJ
Device supports Image4: true
Variant: Developer Erase Install (IPSW)
This restore will erase your device data.
################################ [ WARNING ] #################################
# You are about to perform an *ERASE* restore. ALL DATA on the target device #
# will be IRREVERSIBLY DESTROYED. If you want to update your device without  #
# erasing the user data, hit CTRL+C now and restart without -e or --erase    #
# command line switch.                                                       #
# If you want to continue with the ERASE, please type YES and press ENTER.   #
##############################################################################
> YES
Checking IPSW for required components...
All required components found in IPSW
Using cached filesystem from 'iPad_64bit_TouchID_14.0_18A5373a_Restore/038-44187-100.dmg'
Found ECID 4830739247531046
Getting ApNonce in recovery mode... 4e 87 b1 f6 09 d5 66 ba 1f 4d 4f 9c 51 7a 6d db 25 dd 90 89 
Trying to fetch new SHSH blob
Getting SepNonce in recovery mode... 59 40 80 5d 19 35 eb b9 56 c4 64 40 68 1e 5d 59 3d d4 27 99 
Request URL set to https://gs.apple.com/TSS/controller?action=2
Sending TSS request attempt 1... response successfully received
Received SHSH blobs
Extracting iBEC.ipad5b.RELEASE.im4p...
Personalizing IMG4 component iBEC...
Sending iBEC (772708 bytes)...
Recovery Mode Environment:
iBoot build-version=iBoot-6723.0.48
iBoot build-style=RELEASE
Sending RestoreLogo...
Extracting applelogo@2x~ipad.im4p...
Personalizing IMG4 component RestoreLogo...
Sending RestoreLogo (27607 bytes)...
Extracting 038-44206-142.dmg.trustcache...
Personalizing IMG4 component RestoreTrustCache...
Sending RestoreTrustCache (10843 bytes)...
ramdisk-size=0x20000000
Extracting 038-44206-142.dmg...
Personalizing IMG4 component RestoreRamDisk...
Sending RestoreRamDisk (102880163 bytes)...
Extracting DeviceTree.j81ap.im4p...
Personalizing IMG4 component RestoreDeviceTree...
Sending RestoreDeviceTree (27986 bytes)...
Extracting kernelcache.release.ipad5b...
Personalizing IMG4 component RestoreKernelCache...
Sending RestoreKernelCache (18435882 bytes)...
Waiting for device to enter restore mode...
About to restore device... 
Connecting now...
Connected to com.apple.mobile.restored, version 15
Device 27366c82a3e380dbcf6c2a0a6614acbc352c8b70 has successfully entered restore mode
Hardware Information:
BoardID: 6
ChipID: 28673
UniqueChipID: 4830739247531046
ProductionMode: true
Previous restore exit status: 0x100
Starting FDR listener thread
About to send RootTicket...
Sending RootTicket now...
Done sending RootTicket
Waiting for NAND (28)
About to send NORData...
Found firmware path Firmware/all_flash
Getting firmware manifest from build identity
Extracting LLB.ipad5b.RELEASE.im4p...
Personalizing IMG4 component LLB...
Extracting applelogo@2x~ipad.im4p...
Personalizing IMG4 component AppleLogo...
Extracting batterycharging0@2x~ipad.im4p...
Personalizing IMG4 component BatteryCharging0...
Extracting batterycharging1@2x~ipad.im4p...
Personalizing IMG4 component BatteryCharging1...
Extracting batteryfull@2x~ipad.im4p...
Personalizing IMG4 component BatteryFull...
Extracting batterylow0@2x~ipad.im4p...
Personalizing IMG4 component BatteryLow0...
Extracting batterylow1@2x~ipad.im4p...
Personalizing IMG4 component BatteryLow1...
Extracting glyphplugin@2x~ipad-lightning.im4p...
Personalizing IMG4 component BatteryPlugin...
Extracting DeviceTree.j81ap.im4p...
Personalizing IMG4 component DeviceTree...
Extracting recoverymode@2x~ipad-lightning.im4p...
Personalizing IMG4 component RecoveryMode...
Extracting iBoot.ipad5b.RELEASE.im4p...
Personalizing IMG4 component iBoot...
Extracting sep-firmware.j81.RELEASE.im4p...
Personalizing IMG4 component RestoreSEP...
Extracting sep-firmware.j81.RELEASE.im4p...
Personalizing IMG4 component SEP...
Sending NORData now...
Done sending NORData
Unmounting filesystems (29)
Unmounting filesystems (29)
Unmounting filesystems (29)
Unmounting filesystems (29)
Unmounting filesystems (29)
About to send FDR Trust data...
Sending FDR Trust data now...
Done sending FDR Trust Data
Checking for uncollected logs (44)
Unmounting filesystems (29)
Unmounting filesystems (29)
Unmounting filesystems (29)
Unmounting filesystems (29)
Unmounting filesystems (29)
Creating partition map (11)
Creating filesystem (12)
About to send filesystem...
Connected to ASR
Validating the filesystem
Filesystem validated
Sending filesystem now...
ERROR: Unable to send data to ASR. Sent 0 of 20 bytes.
ERROR: Unable to send chunk checksum
ERROR: Unable to send payload to ASR
ERROR: Unable to send filesystem
ERROR: Unable to successfully restore device
Got status message
Status: Fail
Log is available:
[05:26:40.0529-GMT]{4>8} CHECKPOINT NOTICE: Image4 device: AP nonce clearable
entering ramrod_clear_ap_nonce
[05:26:40.0541-GMT]{4>8} CHECKPOINT NOTICE: AP nonce consumed
[05:26:40.0542-GMT]{4>8} CHECKPOINT NOTICE: Pre-existing NVRAM variable: auto-boot=false
[05:26:40.0542-GMT]{4>8} CHECKPOINT NOTICE: Pre-existing NVRAM variable: restore-outcome=initial_monitor_no_return
[05:26:40.0543-GMT]{4>8} CHECKPOINT PROGRESS: START (unknown) -> (initial_engine_no_return)
[05:26:40.0543-GMT]{4>8} CHECKPOINT NOTICE: NVRAM access available on initial check
restore-outcome = initial_engine_no_return
executing /usr/sbin/nvram restore-outcome=initial_engine_no_return
[05:26:40.0563-GMT]{4>8} CHECKPOINT BEGIN: MAIN:[0x0400] umask
restore-step-ids = {0x11030400:1}
restore-step-names = {0x11030400:umask}
restore-step-uptime = 1
restore-step-user-progress = -1
[05:26:40.0564-GMT]{4>8} CHECKPOINT END: MAIN:[0x0400] umask
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 1
restore-step-user-progress = -1
[05:26:40.0564-GMT]{4>8} CHECKPOINT BEGIN: MAIN:[0x0402] setvbuf
restore-step-ids = {0x11030402:2}
restore-step-names = {0x11030402:setvbuf}
restore-step-uptime = 1
restore-step-user-progress = -1
[05:26:40.0564-GMT]{4>8} CHECKPOINT END: MAIN:[0x0402] setvbuf
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 1
restore-step-user-progress = -1
[05:26:40.0565-GMT]{4>8} CHECKPOINT BEGIN: MAIN:[0x0403] kernel_logger_thread
restore-step-ids = {0x11030403:3}
restore-step-names = {0x11030403:kernel_logger_thread}
restore-step-uptime = 1
restore-step-user-progress = -1
[05:26:40.0565-GMT]{4>8} CHECKPOINT END: MAIN:[0x0403] kernel_logger_thread
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 1
restore-step-user-progress = -1
[05:26:40.0566-GMT]{4>8} CHECKPOINT BEGIN: MAIN:[0x0406] set_progress_0
restore-step-ids = {0x11030406:4}
restore-step-names = {0x11030406:set_progress_0}
restore-step-uptime = 1
restore-step-user-progress = -1
found display: primary
display-boot-rotation = 0
display-scale = 2
display-rotation = 0
found applelogo at /usr/share/progressui/applelogo@2x~ipad.tga
display: 1536 x 2048
Progress Bar Y offset at 160, display class 4
powering on display
ramrod_display_set_granular_progress_forced: 0.000000
[05:26:40.0604-GMT]{4>8} CHECKPOINT END: MAIN:[0x0406] set_progress_0
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 1
restore-step-user-progress = 0
[05:26:40.0605-GMT]{4>8} CHECKPOINT BEGIN: MAIN:[0x0407] start_gasgauge_thread
restore-step-ids = {0x11030407:5}
restore-step-names = {0x11030407:start_gasgauge_thread}
restore-step-uptime = 1
restore-step-user-progress = 0
[05:26:40.0606-GMT]{4>8} CHECKPOINT END: MAIN:[0x0407] start_gasgauge_thread
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 1
restore-step-user-progress = 0
[05:26:40.0606-GMT]{4>8} CHECKPOINT BEGIN: MAIN:[0x0408] listen_for_log_client
restore-step-ids = {0x11030408:6}
restore-step-names = {0x11030408:listen_for_log_client}
restore-step-uptime = 1
restore-step-user-progress = 0
[05:26:40.0607-GMT]{4>8} CHECKPOINT END: MAIN:[0x0408] listen_for_log_client
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 1
restore-step-user-progress = 0
[05:26:40.0608-GMT]{4>8} CHECKPOINT BEGIN: MAIN:[0x040D] create_listen_socket
restore-step-ids = {0x1103040D:7}
restore-step-names = {0x1103040D:create_listen_socket}
restore-step-uptime = 1
restore-step-user-progress = 0
[05:26:40.0608-GMT]{4>8} CHECKPOINT END: MAIN:[0x040D] create_listen_socket
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 1
restore-step-user-progress = 0
[05:26:40.0609-GMT]{4>8} CHECKPOINT BEGIN: MAIN:[0x0404] update_root_mount
restore-step-ids = {0x11030404:8}
restore-step-names = {0x11030404:update_root_mount}
restore-step-uptime = 1
restore-step-user-progress = 0
[05:26:40.0612-GMT]{4>8} CHECKPOINT END: MAIN:[0x0404] update_root_mount
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 1
restore-step-user-progress = 0
[05:26:40.0612-GMT]{4>8} CHECKPOINT BEGIN: MAIN:[0x0405] disable_watchdog
restore-step-ids = {0x11030405:9}
restore-step-names = {0x11030405:disable_watchdog}
restore-step-uptime = 1
restore-step-user-progress = 0
[05:26:40.0613-GMT]{4>8} CHECKPOINT END: MAIN:[0x0405] disable_watchdog
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 1
restore-step-user-progress = 0
[05:26:40.0613-GMT]{4>8} CHECKPOINT BEGIN: MAIN:[0x040E] enable_usb
restore-step-ids = {0x1103040E:10}
restore-step-names = {0x1103040E:enable_usb}
restore-step-uptime = 1
restore-step-user-progress = 0
waiting for matching IOKit service: {
    IOProviderClass = AppleUSBDeviceMux;
}
[05:26:43.0633-GMT]{4>8} CHECKPOINT END: MAIN:[0x040E] enable_usb
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 4
restore-step-user-progress = 0
waiting for host to trigger start of restore [timeout of 120 seconds]
recv(9, 4) failed: connection closed
unable to read message size: -1
could not receive message
unrecognized request 'GetValue'
unrecognized request 'GetValue'
[05:26:43.0801-GMT]{4>8} CHECKPOINT BEGIN: RESTORED:[0x0600] client_protocol_version
restore-step-ids = {0x11030600:11}
restore-step-names = {0x11030600:client_protocol_version}
restore-step-uptime = 4
restore-step-user-progress = 0
client protocol version 15
[05:26:43.0802-GMT]{4>8} CHECKPOINT END: RESTORED:[0x0600] client_protocol_version
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 4
restore-step-user-progress = 0
[05:26:43.0803-GMT]{4>8} CHECKPOINT BEGIN: RESTORED:[0x0601] copy_restore_options
restore-step-ids = {0x11030601:12}
restore-step-names = {0x11030601:copy_restore_options}
restore-step-uptime = 4
restore-step-user-progress = 0
unable to open /usr/local/share/restore//options.j81.plist: No such file or directory
0: NSPOSIXErrorDomain/2: create_dictionary_from_plist: unable to open plist
unable to open /usr/local/share/restore//options.plist: No such file or directory
0: NSPOSIXErrorDomain/2: create_dictionary_from_plist: unable to open plist
*** UUID F289ECDD-BCF7-C617-EDB9-F630E9632478 ***
Restore options:
    PersonalizedDuringPreflight    => <CFBoolean 0x101a82040 [0x1018b9a18]>{value = true}
    CreateFilesystemPartitions     => <CFBoolean 0x101a82040 [0x1018b9a18]>{value = true}
    UUID                           => <CFString 0x158c05c60 [0x1018b9a18]>{contents = "F289ECDD-BCF7-C617-EDB9-F630E9632478"}
[05:26:43.0805-GMT]{4>8} CHECKPOINT END: RESTORED:[0x0601] copy_restore_options
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 4
restore-step-user-progress = 0
[05:26:43.0806-GMT]{4>8} CHECKPOINT BEGIN: RESTORED:[0x0655] is_host_compatible
restore-step-ids = {0x11030655:13}
restore-step-names = {0x11030655:is_host_compatible}
restore-step-uptime = 4
restore-step-user-progress = 0
Checkpoint engine recorder path set to /mnt5
[05:26:43.0806-GMT]{4>8} CHECKPOINT END: RESTORED:[0x0655] is_host_compatible
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 4
restore-step-user-progress = 0
[05:26:43.0807-GMT]{4>8} CHECKPOINT BEGIN: RESTORED:[0x0604] set_weight_from_options
restore-step-ids = {0x11030604:14}
restore-step-names = {0x11030604:set_weight_from_options}
restore-step-uptime = 4
restore-step-user-progress = 0
[05:26:43.0808-GMT]{4>8} CHECKPOINT END: RESTORED:[0x0604] set_weight_from_options
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 4
restore-step-user-progress = 0
[05:26:43.0809-GMT]{4>8} CHECKPOINT BEGIN: RESTORED:[0x068F] libauthinstall_callback
restore-step-ids = {0x1103068F:15}
restore-step-names = {0x1103068F:libauthinstall_callback}
restore-step-uptime = 4
restore-step-user-progress = 0
[05:26:43.0810-GMT]{4>8} CHECKPOINT END: RESTORED:[0x068F] libauthinstall_callback
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 4
restore-step-user-progress = 0
[05:26:43.0811-GMT]{4>8} CHECKPOINT BEGIN: RESTORED:[0x0608] device_has_hoover
restore-step-ids = {0x11030608:16}
restore-step-names = {0x11030608:device_has_hoover}
restore-step-uptime = 4
restore-step-user-progress = 0
[05:26:43.0812-GMT]{4>8} CHECKPOINT END: RESTORED:[0x0608] device_has_hoover
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 4
restore-step-user-progress = 0
[05:26:43.0812-GMT]{4>8} CHECKPOINT BEGIN: RESTORED:[0x060B] update_ticket
restore-step-ids = {0x1103060B:17}
restore-step-names = {0x1103060B:update_ticket}
restore-step-uptime = 4
restore-step-user-progress = 0
entering ramrod_ticket_update_verify
looking up boot manifest hash
device tree ticket_hash: CA759C40376209086D2132B14265CF41792CE944
crypto-hash-method found. Using SHA1
computed ticket_hash   : CA759C40376209086D2132B14265CF41792CE944
received valid ticket (6008 bytes)
[05:26:43.0816-GMT]{4>8} CHECKPOINT END: RESTORED:[0x060B] update_ticket
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 4
restore-step-user-progress = 0
[05:26:43.0817-GMT]{4>8} CHECKPOINT BEGIN: RESTORED:[0x060D] wait_for_storage
restore-step-ids = {0x1103060D:18}
restore-step-names = {0x1103060D:wait_for_storage}
restore-step-uptime = 4
restore-step-user-progress = 0
entering wait_for_storage_device
ramrod_display_set_granular_progress_forced: 0.000000
Searching for NAND service
Searching for NAND service
Found NAND service: ASPStorage
NAND initialized. Waiting for devnode.
entering wait_for_device: 'EmbeddedDeviceTypeRoot'
Using device path /dev/disk0 for EmbeddedDeviceTypeRoot
entering ramrod_probe_media_internal
entering wait_for_device: 'EmbeddedDeviceTypeRoot'
Using device path /dev/disk0 for EmbeddedDeviceTypeRoot
device partitioning scheme is GPT
APFS Container 'Container' /dev/disk0s1
device is APFS formatted
[05:26:43.0826-GMT]{4>8} CHECKPOINT END: RESTORED:[0x060D] wait_for_storage
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 4
restore-step-user-progress = 0
[05:26:43.0826-GMT]{4>8} CHECKPOINT BEGIN: RESTORED:[0x060E] update_NAND_firmware
restore-step-ids = {0x1103060E:19}
restore-step-names = {0x1103060E:update_NAND_firmware}
restore-step-uptime = 4
restore-step-user-progress = 0
[05:26:43.0827-GMT]{4>8} CHECKPOINT END: RESTORED:[0x060E] update_NAND_firmware
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 4
restore-step-user-progress = 0
[05:26:43.0827-GMT]{4>8} CHECKPOINT BEGIN: RESTORED:[0x060F] clear_remap_variable
restore-step-ids = {0x1103060F:20}
restore-step-names = {0x1103060F:clear_remap_variable}
restore-step-uptime = 4
restore-step-user-progress = 0
entering clear_remap_variable
executing /usr/sbin/nvram -d enable-remap-mode
enable-remap-mode
[05:26:43.0847-GMT]{4>8} CHECKPOINT END: RESTORED:[0x060F] clear_remap_variable
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 4
restore-step-user-progress = 0
[05:26:43.0847-GMT]{4>8} CHECKPOINT BEGIN: RESTORED:[0x065C] print_nvram_variables
restore-step-ids = {0x1103065C:21}
restore-step-names = {0x1103065C:print_nvram_variables}
restore-step-uptime = 4
restore-step-user-progress = 0
ramrod_print_NVRAM_variables
executing /usr/sbin/nvram -xp
<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE plist PUBLIC "-//Apple//DTD PLIST 1.0//EN" "http://www.apple.com/DTDs/PropertyList-1.0.dtd">
<plist version="1.0">
<dict>
    <key>auto-boot</key>
    <data>
    ZmFsc2U=
    </data>
    <key>backlight-level</key>
    <data>
    MTU5Nw==
    </data>
    <key>backlight-nits</key>
    <data>
    MDA5MzRlZDA=
    </data>
    <key>boot-args</key>
    <string></string>
    <key>boot-breadcrumbs</key>
    <data>
    PEJPT1Q+IDAwMWMwMDJiKDAyMDA2NTAwKSAwMDAyMDAxMiA0MDA2MDAwNCA0MDAzMDAx
    NiA8Q09NTUlUPiAwMDAzMDAwYygwMDAwMDAwMCkgMDAwMzAwMGQgMDAwMTAwMDIgPENP
    TU1JVD4gPEJPT1Q+IDAwMWMwMDJiKDAyMDA2NTAwKSAwMDAyMDAxMiA0MDA2MDAwNCA0
    MDAzMDAxNiA8Q09NTUlUPiAwMDAzMDAwYygwMDAwMDAwMCkgMDAwMzAwMGQgMDAwMzAw
    MGMoNjk2MjY1NjMpIDAwMDMwMDBkIDxET05FPiA8Q09NTUlUPiA=
    </data>
    <key>com.apple.System.tz0-size</key>
    <data>
    MHhDMDAwMDA=
    </data>
    <key>oblit-begins</key>
    <data>
    T2JsaXRUeXBlOiBPYmxpdGVyYXRlRGF0YVBhcnRpdGlvbi4gUmVhc29uOiB1bmtub3du
    </data>
    <key>obliteration</key>
    <data>
    aGFuZGxlX21lc3NhZ2U6IE9ibGl0ZXJhdGlvbiBDb21wbGV0ZQo=
    </data>
    <key>ota-controllerVersion</key>
    <data>
    U1VTLTIuMA==
    </data>
    <key>restore-outcome</key>
    <data>
    aW5pdGlhbF9lbmdpbmVfbm9fcmV0dXJu
    </data>
    <key>restored-exit-status</key>
    <data>
    MHgxMDA=
    </data>
</dict>
</plist>
[05:26:43.0865-GMT]{4>8} CHECKPOINT END: RESTORED:[0x065C] print_nvram_variables
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 4
restore-step-user-progress = 0
[05:26:43.0865-GMT]{4>8} CHECKPOINT BEGIN: RESTORED:[0x0610] asp_nand_set_writable
restore-step-ids = {0x11030610:22}
restore-step-names = {0x11030610:asp_nand_set_writable}
restore-step-uptime = 4
restore-step-user-progress = 0
Service name : ASPStorage
Set ASP writable successfully
[05:26:43.0869-GMT]{4>8} CHECKPOINT END: RESTORED:[0x0610] asp_nand_set_writable
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 4
restore-step-user-progress = 0
[05:26:43.0869-GMT]{4>8} CHECKPOINT BEGIN: RESTORED:[0x0613] find_filesystem_partitions
restore-step-ids = {0x11030613:23}
restore-step-names = {0x11030613:find_filesystem_partitions}
restore-step-uptime = 4
restore-step-user-progress = 0
entering ramrod_probe_media_internal
entering wait_for_device: 'EmbeddedDeviceTypeRoot'
Using device path /dev/disk0 for EmbeddedDeviceTypeRoot
device partitioning scheme is GPT
APFS Container 'Container' /dev/disk0s1
device is APFS formatted
find_filesystem_partitions: storage=/dev/disk0 container=/dev/disk0s1 system=/dev/disk0s1s1 data= baseband data= log= update= xart= hardware= scratch= preboot=
find_filesystem_partitions: recovery os container= volume= 
[05:26:43.0873-GMT]{4>8} CHECKPOINT END: RESTORED:[0x0613] find_filesystem_partitions
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 4
restore-step-user-progress = 0
[05:26:43.0873-GMT]{4>8} CHECKPOINT BEGIN: RESTORED:[0x067E] verify_storage_for_update
restore-step-ids = {0x1103067E:24}
restore-step-names = {0x1103067E:verify_storage_for_update}
restore-step-uptime = 4
restore-step-user-progress = 0
[05:26:43.0874-GMT]{4>8} CHECKPOINT END: RESTORED:[0x067E] verify_storage_for_update
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 4
restore-step-user-progress = 0
[05:26:43.0874-GMT]{4>8} CHECKPOINT BEGIN: RESTORED:[0x0609] load_sep_os
restore-step-ids = {0x11030609:25}
restore-step-names = {0x11030609:load_sep_os}
restore-step-uptime = 4
restore-step-user-progress = 0
entering load_sep_os
We should not have an xART partition.
device has sep - getting firmware
entering copy_restore_sep
got sep firmware - making call to load it
entering ramrod_load_sep_os
entering ramrod_execute_command_with_input_data: /usr/libexec/seputil (0x15aa14000 - 2685025)
executing /usr/libexec/seputil --restore+art -
waiting for child to exit
child exited
exit status: 0
entering ramrod_wait_for_sep_load
executing /usr/libexec/seputil --ping
seputil: ping failed
unrecognized request 'GetValue'
executing /usr/libexec/seputil --ping
SEP OS is booted
entering ramrod_notify_sep_for_erase
executing /usr/libexec/seputil --erase
[05:26:47.0591-GMT]{4>8} CHECKPOINT END: RESTORED:[0x0609] load_sep_os
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 8
restore-step-user-progress = 0
[05:26:47.0591-GMT]{4>8} CHECKPOINT BEGIN: RESTORED:[0x0693] preload_keys_for_fsck
restore-step-ids = {0x11030693:26}
restore-step-names = {0x11030693:preload_keys_for_fsck}
restore-step-uptime = 8
restore-step-user-progress = 0
Erase install, not preloading keys
No data volume present; must avoid any read/write mounting
[05:26:47.0592-GMT]{4>8} CHECKPOINT END: RESTORED:[0x0693] preload_keys_for_fsck
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 8
restore-step-user-progress = 0
[05:26:47.0592-GMT]{4>8} CHECKPOINT BEGIN: RESTORED:[0x0665] fsck_filesystems
restore-step-ids = {0x11030665:27}
restore-step-names = {0x11030665:fsck_filesystems}
restore-step-uptime = 8
restore-step-user-progress = 0
entering unmount_filesystems
ramrod_display_set_granular_progress_forced: 0.000000
entering force_unmount_partition
Preboot not mounted (unmount ignored)
Skipping unmount of the update partition
ramrod_display_set_granular_progress_forced: 0.000000
entering force_unmount_partition
Hardware not mounted (unmount ignored)
ramrod_display_set_granular_progress_forced: 0.000000
entering force_unmount_partition
Data not mounted (unmount ignored)
ramrod_display_set_granular_progress_forced: 0.000000
entering force_unmount_partition
xART not mounted (unmount ignored)
ramrod_display_set_granular_progress_forced: 0.000000
entering force_unmount_partition
System not mounted (unmount ignored)
Skipping fsck on erase install
[05:26:47.0595-GMT]{4>8} CHECKPOINT END: RESTORED:[0x0665] fsck_filesystems
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 8
restore-step-user-progress = 0
[05:26:47.0595-GMT]{4>8} CHECKPOINT BEGIN: RESTORED:[0x0614] mount_system_partition
restore-step-ids = {0x11030614:28}
restore-step-names = {0x11030614:mount_system_partition}
restore-step-uptime = 8
restore-step-user-progress = 0
entering mount_partition
executing /sbin/mount_apfs -R -o rdonly /dev/disk0s1s1 /mnt1
/dev/disk0s1s1 mounted on /mnt1
System mounted read-only
[05:26:47.0622-GMT]{4>8} CHECKPOINT END: RESTORED:[0x0614] mount_system_partition
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 8
restore-step-user-progress = 0
[05:26:47.0622-GMT]{4>8} CHECKPOINT BEGIN: RESTORED:[0x0654] read_previous_os_build_version
restore-step-ids = {0x11030654:29}
restore-step-names = {0x11030654:read_previous_os_build_version}
restore-step-uptime = 8
restore-step-user-progress = 0
unable to open /mnt1/System/Library/CoreServices/SystemVersion.plist: No such file or directory
ramrod_read_os_build_version: Unable to read system version plist
[05:26:47.0623-GMT]{4>8} CHECKPOINT END: RESTORED:[0x0654] read_previous_os_build_version
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 8
restore-step-user-progress = 0
[05:26:47.0623-GMT]{4>8} CHECKPOINT BEGIN: RESTORED:[0x0615] copy_hardware_info
restore-step-ids = {0x11030615:30}
restore-step-names = {0x11030615:copy_hardware_info}
restore-step-uptime = 8
restore-step-user-progress = 0
[05:26:47.0624-GMT]{4>8} CHECKPOINT END: RESTORED:[0x0615] copy_hardware_info
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 8
restore-step-user-progress = 0
[05:26:47.0625-GMT]{4>8} CHECKPOINT BEGIN: RESTORED:[0x0616] fdr_create
restore-step-ids = {0x11030616:31}
restore-step-names = {0x11030616:fdr_create}
restore-step-uptime = 8
restore-step-user-progress = 0
restored_fdr_initialize: FDR is supported
CryptoAcceleratorEncrypt: perform aes => 0 (kIOReturnSuccess)
pseudo_ccrng_allocate: ccdrbg_init() -> 0
CryptoGenerateRSAKeys: ccrsa_generate_key() -> 0
CryptoGenerateRSAKeys: [RSA Public Key SHA1: 20 bytes]
: 64 58 13 ec 52 ba 85 02 c5 7a 26 d8 8d 6e 7d 86 
: 26 33 68 86 
: -----------------------------------------------
CryptoGenerateRSAKeys: SecKeyCreateRSAPrivateKey -> 0x1004e0090
CryptoGenerateRSAKeys: SecKeyCreateRSAPublicKey -> 0x1004e0098
created HTTP FDR client 0x15880c040
created local FDR client 0x15880c680
Received response without expected RESTORED_FDR_TRUST_DATA
Received response without expected RESTORED_BOOTED_OS_FDR_TRUST_DATA
AMSupportPlatformMakeDirectoryForURL: Could not mkdir (Read-only file system)
AMSupportPlatformMakeDirectoryForURL: /mnt1/System
AMFDRCreateError: AMFDRDataLocalCopyDataStoragePath: AMSupportMakeDirectory failed: code=4
AMFDRCreateError: AMFDRDataLocalCopy: missing data storage path: code=4
AMSupportPlatformMakeDirectoryForURL: Could not mkdir (Read-only file system)
AMSupportPlatformMakeDirectoryForURL: /mnt1/System
AMFDRCreateError: AMFDRDataLocalCopyDataStoragePath: AMSupportMakeDirectory failed: code=4
AMFDRCreateError: AMFDRDataLocalCopy: missing data storage path: code=4
failed to copy trust object from fdrLocal
0: AMFDRError/4: missing data storage path
1: AMFDRError/4: AMSupportMakeDirectory failed
2: AMFDRError/4: missing data storage path
3: AMFDRError/4: AMSupportMakeDirectory failed
Found ramdisk trust object, computing digest..
Ramdisk trust object digest DOES match AP ticket.
Not enabling SSO for FDR
Skip register RestoredFDRSignVeridian callback since vcrt is not supported
RestoredFDRCreate() returned 0
FDR is supported on this device
[05:26:48.0063-GMT]{4>8} CHECKPOINT END: RESTORED:[0x0616] fdr_create
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 9
restore-step-user-progress = 0
[05:26:48.0063-GMT]{4>8} CHECKPOINT BEGIN: RESTORED:[0x0617] fdr_save_data
restore-step-ids = {0x11030617:32}
restore-step-names = {0x11030617:fdr_save_data}
restore-step-uptime = 9
restore-step-user-progress = 0
_AMFDRAPTicketHasBooleanEntitlement: no ticket in options
AMFDRSealingMapCreateAndPopulateSealedData: populate sealedData with sealing manifest, sealingManifestOverride : (null), forceSealing : (null), allowForbidden : (null), allowUnSeal : 0
AMSupportPlatformMakeDirectoryForURL: Could not mkdir (Read-only file system)
AMSupportPlatformMakeDirectoryForURL: /mnt1/System
AMFDRCreateError: AMFDRDataLocalCopyDataStoragePath: AMSupportMakeDirectory failed: code=4
AMFDRCreateError: AMFDRDataLocalCopy: missing data storage path: code=4
AMFDRCreateError: AMFDRDataCopy: seal:00007001-0011298820DA0426 get data failed - foundData is NULL: code=10
AMFDRCreateError: AMFDRSealingMapPopulateSealingManifest: sealingManifest is NULL: code=10
AMFDRCreateError: AMFDRSealingMapCreateAndPopulateSealedData: AMFDRSealingMapPopulateSealingManifest failed on amfdr: code=10
AMFDRSealedDataRestoreOptions: sealedData is NULL
failed to save FDR persistent state
RestoredFDRSaveData success
[05:26:48.0065-GMT]{4>8} CHECKPOINT END: RESTORED:[0x0617] fdr_save_data
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 9
restore-step-user-progress = 0
[05:26:48.0065-GMT]{4>8} CHECKPOINT BEGIN: RESTORED:[0x0618] store_baseband_migration
restore-step-ids = {0x11030618:33}
restore-step-names = {0x11030618:store_baseband_migration}
restore-step-uptime = 9
restore-step-user-progress = 0
[05:26:48.0067-GMT]{4>8} CHECKPOINT END: RESTORED:[0x0618] store_baseband_migration
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 9
restore-step-user-progress = 0
[05:26:48.0067-GMT]{4>8} CHECKPOINT BEGIN: RESTORED:[0x0619] check_for_restore_log
restore-step-ids = {0x11030619:34}
restore-step-names = {0x11030619:check_for_restore_log}
restore-step-uptime = 9
restore-step-user-progress = 0
entering check_for_restore_log
ramrod_display_set_granular_progress_forced: 0.000000
restore log does not exist
[05:26:48.0068-GMT]{4>8} CHECKPOINT END: RESTORED:[0x0619] check_for_restore_log
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 9
restore-step-user-progress = 0
[05:26:48.0068-GMT]{4>8} CHECKPOINT BEGIN: RESTORED:[0x061A] check_for_ota_logs
restore-step-ids = {0x1103061A:35}
restore-step-names = {0x1103061A:check_for_ota_logs}
restore-step-uptime = 9
restore-step-user-progress = 0
Initializing libpartition
Skipping OTA log submission on erase install with damaged gigalocker or missing data
[05:26:48.0068-GMT]{4>8} CHECKPOINT END: RESTORED:[0x061A] check_for_ota_logs
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 9
restore-step-user-progress = 0
[05:26:48.0069-GMT]{4>8} CHECKPOINT BEGIN: RESTORED:[0x061B] submit_update_stats
restore-step-ids = {0x1103061B:36}
restore-step-names = {0x1103061B:submit_update_stats}
restore-step-uptime = 9
restore-step-user-progress = 0
Skipping OTA metrics submission on erase install with damaged gigalocker
[05:26:48.0069-GMT]{4>8} CHECKPOINT END: RESTORED:[0x061B] submit_update_stats
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 9
restore-step-user-progress = 0
[05:26:48.0069-GMT]{4>8} CHECKPOINT BEGIN: RESTORED:[0x0661] read_persistent_files
restore-step-ids = {0x11030661:37}
restore-step-names = {0x11030661:read_persistent_files}
restore-step-uptime = 9
restore-step-user-progress = 0
persistent_files_create has nothing to persist.
Checking if hardware folder contents need to be stashed
entering mount_partition
executing /sbin/mount_apfs -R -o rdonly  /mnt4
mount_apfs: volume could not be mounted: No such file or directory
mounting  on /mnt4 failed
ramrod_dump_mounted_filesystem_info:**********DUMPING MOUNTED FILESYSTEMS********
ramrod_dump_mounted_filesystem_info: 4 filesystems are mounted
/dev/disk0s1s1 is mounted at /mnt1
tmpfs is mounted at /mnt5
devfs is mounted at /dev
/dev/md0 is mounted at /
ramrod_dump_mounted_filesystem_info: *********DONE DUMPING MOUNTED FILESYSTEMS********
Unable to mount or no update partition present(not necessarily a ). Hardware folder contents will *not* be stashed
Done checking hardware folder contents
[05:26:48.0089-GMT]{4>8} CHECKPOINT END: RESTORED:[0x0661] read_persistent_files
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 9
restore-step-user-progress = 0
[05:26:48.0089-GMT]{4>8} CHECKPOINT BEGIN: RESTORED:[0x061D] unmount_unconditionally
restore-step-ids = {0x1103061D:38}
restore-step-names = {0x1103061D:unmount_unconditionally}
restore-step-uptime = 9
restore-step-user-progress = 0
entering unmount_filesystems
ramrod_display_set_granular_progress_forced: 0.000000
entering force_unmount_partition
Preboot not mounted (unmount ignored)
Skipping unmount of the update partition
ramrod_display_set_granular_progress_forced: 0.000000
entering force_unmount_partition
Hardware not mounted (unmount ignored)
ramrod_display_set_granular_progress_forced: 0.000000
entering force_unmount_partition
Data not mounted (unmount ignored)
ramrod_display_set_granular_progress_forced: 0.000000
entering force_unmount_partition
xART not mounted (unmount ignored)
ramrod_display_set_granular_progress_forced: 0.000000
entering force_unmount_partition
System unmounted
[05:26:48.0092-GMT]{4>8} CHECKPOINT END: RESTORED:[0x061D] unmount_unconditionally
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 9
restore-step-user-progress = 0
[05:26:48.0092-GMT]{4>8} CHECKPOINT BEGIN: RESTORED:[0x064E] clean_nand
restore-step-ids = {0x1103064E:39}
restore-step-names = {0x1103064E:clean_nand}
restore-step-uptime = 9
restore-step-user-progress = 0
entering clean_NAND
NAND format complete
entering ramrod_probe_media_internal
entering wait_for_device: 'EmbeddedDeviceTypeRoot'
Using device path /dev/disk0 for EmbeddedDeviceTypeRoot
find_filesystem_partitions: storage=/dev/disk0 container= system= data= baseband data= log= update= xart= hardware= scratch= preboot=
find_filesystem_partitions: recovery os container= volume= 
[05:26:49.0325-GMT]{4>8} CHECKPOINT END: RESTORED:[0x064E] clean_nand
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 10
restore-step-user-progress = 0
[05:26:49.0325-GMT]{4>8} CHECKPOINT BEGIN: RESTORED:[0x061F] format_effaceable_storage
restore-step-ids = {0x1103061F:40}
restore-step-names = {0x1103061F:format_effaceable_storage}
restore-step-uptime = 10
restore-step-user-progress = 0
entering format_effaceable_storage
effaceable storage is formatted, clearing it
effaceable storaged cleared
[05:26:49.0349-GMT]{4>8} CHECKPOINT END: RESTORED:[0x061F] format_effaceable_storage
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 10
restore-step-user-progress = 0
[05:26:49.0349-GMT]{4>8} CHECKPOINT BEGIN: RESTORED:[0x068A] format_ean_storage
restore-step-ids = {0x1103068A:41}
restore-step-names = {0x1103068A:format_ean_storage}
restore-step-uptime = 10
restore-step-user-progress = 0
entering format_ean_storage
Ean storage not present for this device. Skipping ean format.
[05:26:49.0350-GMT]{4>8} CHECKPOINT END: RESTORED:[0x068A] format_ean_storage
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 10
restore-step-user-progress = 0
[05:26:49.0351-GMT]{4>8} CHECKPOINT BEGIN: RESTORED:[0x0621] create_filesystem_partitions
restore-step-ids = {0x11030621:42}
restore-step-names = {0x11030621:create_filesystem_partitions}
restore-step-uptime = 10
restore-step-user-progress = 0
APFS Erase Install
entering create_filesystem_partition
ramrod_display_set_granular_progress_forced: 0.000000
[05:26:49.0451-GMT]{4>8} CHECKPOINT END: RESTORED:[0x0621] create_filesystem_partitions
restore-step-ids = {}
restore-step-names = {}
restore-step-uptime = 10
restore-step-user-progress = 0
[05:26:49.0453-GMT]{4>8} CHECKPOINT BEGIN: RESTORED:[0x0677] perform_main_os_prepare
restore-step-ids = {0x11030677:43}
restore-step-names = {0x11030677:perform_main_os_prepare}
restore-step-uptime = 10
restore-step-user-progress = 0
[05:26:49.0454-GMT]{4>8} CHECKPOINT BEGIN: (null):[0x0660] update_partitions_for_apfs
restore-step-ids = {0x11030677:43;0x11030660:44}
restore-step-names = {0x11030677:perform_main_os_prepare;0x11030660:update_partitions_for_apfs}
restore-step-uptime = 10
restore-step-user-progress = 0
[05:26:49.0456-GMT]{4>8} CHECKPOINT END: (null):[0x0660] update_partitions_for_apfs
restore-step-ids = {0x11030677:43}
restore-step-names = {0x11030677:perform_main_os_prepare}
restore-step-uptime = 10
restore-step-user-progress = 0
[05:26:49.0457-GMT]{4>8} CHECKPOINT BEGIN: (null):[0x0622] reload_filesystem_partitions
restore-step-ids = {0x11030677:43;0x11030622:45}
restore-step-names = {0x11030677:perform_main_os_prepare;0x11030622:reload_filesystem_partitions}
restore-step-uptime = 10
restore-step-user-progress = 0
entering ramrod_probe_media_internal
entering wait_for_device: 'EmbeddedDeviceTypeRoot'
Using device path /dev/disk0 for EmbeddedDeviceTypeRoot
device partitioning scheme is GPT
APFS Container 'Container' /dev/disk0s1
find_filesystem_partitions: storage=/dev/disk0 container=/dev/disk0s1 system= data= baseband data= log= update= xart= hardware= scratch= preboot=
find_filesystem_partitions: recovery os container= volume= 
[05:26:49.0464-GMT]{4>8} CHECKPOINT END: (null):[0x0622] reload_filesystem_partitions
restore-step-ids = {0x11030677:43}
restore-step-names = {0x11030677:perform_main_os_prepare}
restore-step-uptime = 10
restore-step-user-progress = 0
[05:26:49.0465-GMT]{4>8} CHECKPOINT BEGIN: (null):[0x065D] delete_mobilebackups
restore-step-ids = {0x11030677:43;0x1103065D:46}
restore-step-names = {0x11030677:perform_main_os_prepare;0x1103065D:delete_mobilebackups}
restore-step-uptime = 10
restore-step-user-progress = 0
[05:26:49.0465-GMT]{4>8} CHECKPOINT END: (null):[0x065D] delete_mobilebackups
restore-step-ids = {0x11030677:43}
restore-step-names = {0x11030677:perform_main_os_prepare}
restore-step-uptime = 10
restore-step-user-progress = 0
[05:26:49.0465-GMT]{4>8} CHECKPOINT BEGIN: (null):[0x160D] delete_recovery_partition
restore-step-ids = {0x11030677:43;0x1103160D:47}
restore-step-names = {0x11030677:perform_main_os_prepare;0x1103160D:delete_recovery_partition}
restore-step-uptime = 10
restore-step-user-progress = 0
[05:26:49.0466-GMT]{4>8} CHECKPOINT END: (null):[0x160D] delete_recovery_partition
restore-step-ids = {0x11030677:43}
restore-step-names = {0x11030677:perform_main_os_prepare}
restore-step-uptime = 10
restore-step-user-progress = 0
[05:26:49.0466-GMT]{4>8} CHECKPOINT BEGIN: (null):[0x0658] format_media
restore-step-ids = {0x11030677:43;0x11030658:48}
restore-step-names = {0x11030677:perform_main_os_prepare;0x11030658:format_media}
restore-step-uptime = 10
restore-step-user-progress = 0
entering create_apfs_filesystems
entering ramrod_probe_media_internal
entering wait_for_device: 'EmbeddedDeviceTypeRoot'
Using device path /dev/disk0 for EmbeddedDeviceTypeRoot
device partitioning scheme is GPT
APFS Container 'Container' /dev/disk0s1
find_filesystem_partitions: storage=/dev/disk0 container=/dev/disk0s1 system= data= baseband data= log= update= xart= hardware= scratch= preboot=
find_filesystem_partitions: recovery os container= volume= 
ramrod_display_set_granular_progress_forced: 0.000000
/System/Library/Filesystems/apfs.fs/newfs_apfs -C /dev/disk0s1 
executing /System/Library/Filesystems/apfs.fs/newfs_apfs -C /dev/disk0s1
2020-09-11 05:26:49.499371+0000 newfs_apfs[19:721] Warning, unable to start xartutil, spawn error: 2
entering ramrod_probe_media_internal
entering wait_for_device: 'EmbeddedDeviceTypeRoot'
Using device path /dev/disk0 for EmbeddedDeviceTypeRoot
device partitioning scheme is GPT
APFS Container 'Container' /dev/disk0s1
device is APFS formatted
find_filesystem_partitions: storage=/dev/disk0 container=/dev/disk0s1 system= data= baseband data= log= update= xart= hardware= scratch= preboot=
find_filesystem_partitions: recovery os container= volume= 
block size for /dev/disk0s1: 4096
/System/Library/Filesystems/apfs.fs/newfs_apfs -A -o role=s -v System /dev/disk0s1 
executing /System/Library/Filesystems/apfs.fs/newfs_apfs -A -o role=s -v System /dev/disk0s1
We should not have an xART partition.
Not creating an xART partition because we're on a system that doesn't support it.
We should not have a baseband volume.
Hardware partition size calculation:
   2 MiB FDR
--------
   2 MiB total
IORegistry requires a 2 MiB Hardware Partition
block size for /dev/disk0s1: 4096
/System/Library/Filesystems/apfs.fs/newfs_apfs -s 2097152 -A -o role=h -v Hardware /dev/disk0s1 
executing /System/Library/Filesystems/apfs.fs/newfs_apfs -s 2097152 -A -o role=h -v Hardware /dev/disk0s1
Waiting to decide if scratch is needed.
Update partition is not created as part of create_apfs_filesystems..skipping
block size for /dev/disk0s1: 4096
/System/Library/Filesystems/apfs.fs/newfs_apfs -A -o role=b -v Preboot /dev/disk0s1 
executing /System/Library/Filesystems/apfs.fs/newfs_apfs -A -o role=b -v Preboot /dev/disk0s1
[05:26:50.0263-GMT]{4>8} CHECKPOINT END: (null):[0x0658] format_media
restore-step-ids = {0x11030677:43}
restore-step-names = {0x11030677:perform_main_os_prepare}
restore-step-uptime = 11
restore-step-user-progress = 0
[05:26:50.0264-GMT]{4>8} CHECKPOINT BEGIN: (null):[0x0659] find_volumes_after_format
restore-step-ids = {0x11030677:43;0x11030659:49}
restore-step-names = {0x11030677:perform_main_os_prepare;0x11030659:find_volumes_after_format}
restore-step-uptime = 11
restore-step-user-progress = 0
entering ramrod_probe_media_internal
entering wait_for_device: 'EmbeddedDeviceTypeRoot'
Using device path /dev/disk0 for EmbeddedDeviceTypeRoot
device partitioning scheme is GPT
APFS Container 'Container' /dev/disk0s1
device is APFS formatted
Captured preboot partition on main OS container 2
find_filesystem_partitions: storage=/dev/disk0 container=/dev/disk0s1 system=/dev/disk0s1s1 data= baseband data= log= update= xart= hardware=/dev/disk0s1s3 scratch= preboot=/dev/disk0s1s4
find_filesystem_partitions: recovery os container= volume= 
[05:26:50.0268-GMT]{4>8} CHECKPOINT END: (null):[0x0659] find_volumes_after_format
restore-step-ids = {0x11030677:43}
restore-step-names = {0x11030677:perform_main_os_prepare}
restore-step-uptime = 11
restore-step-user-progress = 0
[05:26:50.0268-GMT]{4>8} CHECKPOINT BEGIN: (null):[0x065A] baseband_migration_data
restore-step-ids = {0x11030677:43;0x1103065A:50}
restore-step-names = {0x11030677:perform_main_os_prepare;0x1103065A:baseband_migration_data}
restore-step-uptime = 11
restore-step-user-progress = 0
[05:26:50.0269-GMT]{4>8} CHECKPOINT END: (null):[0x065A] baseband_migration_data
restore-step-ids = {0x11030677:43}
restore-step-names = {0x11030677:perform_main_os_prepare}
restore-step-uptime = 11
restore-step-user-progress = 0
[05:26:50.0269-GMT]{4>8} CHECKPOINT BEGIN: (null):[0x065B] asr_and_invert_image
restore-step-ids = {0x11030677:43;0x1103065B:51}
restore-step-names = {0x11030677:perform_main_os_prepare;0x1103065B:asr_and_invert_image}
restore-step-uptime = 11
restore-step-user-progress = 0
restore_apfs_image : started restoring an APFS image
entering mount_partition
executing /sbin/mount_apfs -R /dev/disk0s1s1 /mnt1
/dev/disk0s1s1 mounted on /mnt1
System mounted read-write
Successfully marked device node /dev/rdisk0s1s1 as static data
OS digest = 547e80658da44c0852da3be1825e69c81a46ed76
Restoring to APFS Inverter Image = /mnt1/apfs_invert_asr_img
executing /usr/sbin/asr -source asr://localhost:12345 -target /mnt1/apfs_invert_asr_img --embed -erase -noprompt --chunkchecksum --puppetstrings --expectedhash 547e80658da44c0852da3be1825e69c81a46ed76
ASR: 2020-09-11 05:26:50.368203+0000 asr[25:749] [User Defaults] Could not connect to cfprefsd. No CFPreferences/NSUserDefaults changes will be saved
ASR STATUS: start   537 multicast-client
ASR: 2020-09-11 05:26:50.373185+0000 asr[25:749] [si_destination_compare] send failed: Invalid argument
ASR: 2020-09-11 05:26:50.373270+0000 asr[25:749] [si_destination_compare] send failed: Undefined error: 0
ASR: 2020-09-11 05:26:50.373340+0000 asr[25:749] [si_destination_compare] send failed: Invalid argument
ASR: Waiting for connection attempt from server
ASR STATUS: setup
ASR: Validating target...
ASR: done
ASR STATUS: metadata
ASR: Validating source...
ASR: done
ASR: Retrieving scan information...
ASR: done
ASR: Validating sizes...
ASR: done
ASR STATUS: restore
ASR: asr: 
ASR: Socket unexpectedly closed while trying to read() offset 0x3C0000
ASR: asr: Failed to read the stream: Input/output error
ASR: __decompressChunk: backing store read at offset 1199132 length 223524 failed with error 5
ASR: __decompressChunk() error: 5
ASR STATUS: fail
ASR: Could not restore - Input/output error
ASR STATUS: fail
restore_apfs_image : failed to restore an APFS image, error = 14
[05:26:55.0236-GMT]{4>8} CHECKPOINT FAILURE:(FAILURE:14) (null):[0x065B] asr_and_invert_image [0]D(failed to restore APFS image)
restore-step-results = {0x1107065B:{0:14}}
restore-step-codes = {0x1107065B:{0:14}}
restore-step-domains = {0x1107065B:{0:"AMRestoreErrorDomain"}}
restore-step-error = {0x1107065B:"[0]D(failed to restore APFS image)"}
restore-step-uptime = 16
restore-step-user-progress = 0
[05:26:55.0239-GMT]{4>8} CHECKPOINT NOTICE: (NVRAM set) restore-step-user-progress=0 [sync=true] (first failure)
[05:26:55.0239-GMT]{4>8} CHECKPOINT FAILURE:(FAILURE:14) RESTORED:[0x0677] perform_main_os_prepare [0]D(failed to restore APFS image)
restore-step-results = {0x11070677:{0:14};0x1107065B:{0:14}}
restore-step-codes = {0x11070677:{0:14};0x1107065B:{0:14}}
restore-step-domains = {0x11070677:{0:"AMRestoreErrorDomain"};0x1107065B:{0:"AMRestoreErrorDomain"}}
restore-step-error = {0x11070677:"[0]D(failed to restore APFS image)"}
restore-step-uptime = 16
restore-step-user-progress = 0
[05:26:55.0241-GMT]{4>8} CHECKPOINT BEGIN: RESTORED:[0x067C] cleanup_boot_command
restore-step-ids = {0x11030677:43;0x1103065B:51;0x1103067C:52}
restore-step-names = {0x11030677:perform_main_os_prepare;0x1103065B:asr_and_invert_image;0x1103067C:cleanup_boot_command}
restore-step-uptime = 16
restore-step-user-progress = 0
entering reset_boot_command_if_value
executing /usr/sbin/nvram -d recovery-boot-mode
recovery-boot-mode
[05:26:55.0283-GMT]{4>8} CHECKPOINT END: RESTORED:[0x067C] cleanup_boot_command
restore-step-ids = {0x11030677:43;0x1103065B:51}
restore-step-names = {0x11030677:perform_main_os_prepare;0x1103065B:asr_and_invert_image}
restore-step-uptime = 16
restore-step-user-progress = 0
[05:26:55.0284-GMT]{4>8} CHECKPOINT BEGIN: RESTORED:[0x1613] cleanup_recovery_os_volume
restore-step-ids = {0x11030677:43;0x1103065B:51;0x11031613:53}
restore-step-names = {0x11030677:perform_main_os_prepare;0x1103065B:asr_and_invert_image;0x11031613:cleanup_recovery_os_volume}
restore-step-uptime = 16
restore-step-user-progress = 0
[05:26:55.0284-GMT]{4>8} CHECKPOINT END: RESTORED:[0x1613] cleanup_recovery_os_volume
restore-step-ids = {0x11030677:43;0x1103065B:51}
restore-step-names = {0x11030677:perform_main_os_prepare;0x1103065B:asr_and_invert_image}
restore-step-uptime = 16
restore-step-user-progress = 0
[05:26:55.0285-GMT]{4>8} CHECKPOINT BEGIN: RESTORED:[0x0647] cleanup_check_result
restore-step-ids = {0x11030677:43;0x1103065B:51;0x11030647:54}
restore-step-names = {0x11030677:perform_main_os_prepare;0x1103065B:asr_and_invert_image;0x11030647:cleanup_check_result}
restore-step-uptime = 16
restore-step-user-progress = 0
[05:26:55.0285-GMT]{4>8} CHECKPOINT END: RESTORED:[0x0647] cleanup_check_result
restore-step-ids = {0x11030677:43;0x1103065B:51}
restore-step-names = {0x11030677:perform_main_os_prepare;0x1103065B:asr_and_invert_image}
restore-step-uptime = 16
restore-step-user-progress = 0
[05:26:55.0286-GMT]{4>8} CHECKPOINT BEGIN: RESTORED:[0x0648] cleanup_send_final_status
restore-step-ids = {0x11030677:43;0x1103065B:51;0x11030648:55}
restore-step-names = {0x11030677:perform_main_os_prepare;0x1103065B:asr_and_invert_image;0x11030648:cleanup_send_final_status}
restore-step-uptime = 16
restore-step-user-progress = 0

ERROR: Unable to restore device
[liveuser@tmeow Downloads]$
cheesycod commented 4 years ago

This only happens with iPadOS 14 and does not happen on iPadOS 13

cheesycod commented 4 years ago

This is on a iPad Air 2

cheesycod commented 4 years ago

This bug also only happens on idevicerestore. 3utools using the same ipsw and cable via virtualbox works perfectly fine

nikias commented 4 years ago

Can you make sure libusbmuxd is latest?

cheesycod commented 4 years ago

libusbmuxd-2.0.2-3.fc33.x86_64 So yes, I am using the latest stable release of libusbmuxd @nikias

nikias commented 4 years ago

Can you try to increase the timeout here to something like 5000 or 10000 and recompile libusbmuxd, then try again: https://github.com/libimobiledevice/libusbmuxd/blob/c7d7d1a03f65a27be2eddb13d1f2b0c0e7a60ec6/common/socket.c#L855

a-gunter commented 4 years ago

Had a similar issue on iOS 14 on iPhone 11 Pro. ASR kept failing at sending the filesystem consistently around the 57% mark. Tried different cables and different devices to no avail, and then increasing the timeout to 10000 did the trick.

nikias commented 4 years ago

@a-gunter I also had it fail on an iPad Air 2 right now. With an increased timeout it did work. I pushed commit https://github.com/libimobiledevice/libusbmuxd/commit/73cb5c182e36e7aafcff8a8932b21c6ab5cae5a6 to libusbmuxd with the increased timeout. But the actual problem is the error handling that I need to take care of in usbmuxd_send and idevice_connection_send, and then also inside idevicerestore. But the current workaround will help for most cases now :)