dorssel / usbipd-win

Windows software for sharing locally connected USB devices to other machines, including Hyper-V guests and WSL 2.
GNU General Public License v3.0
3.52k stars 225 forks source link

Trying to restore iPhone from WSL - asyncReadComplete, message was too large #959

Open d0n13 opened 3 months ago

d0n13 commented 3 months ago

Hi @dorssel

I am trying to run an idevicerestore in wsl to a connected iPhone. When the firmware starts to load onto the phone we get the following error in syslog as reported by usbmuxd on the WSL side.

2024-05-23T16:41:42.806058+01:00 DESKTOP-LVPVFTP usbmuxd[58211]: [16:41:42.805][3] usbmuxd v1.1.1 starting up
2024-05-23T16:41:42.806434+01:00 DESKTOP-LVPVFTP usbmuxd[58211]: [16:41:42.806][3] Successfully dropped privileges to 'usbmux'
2024-05-23T16:41:42.806483+01:00 DESKTOP-LVPVFTP usbmuxd[58211]: [16:41:42.806][3] Using libusb 1.0.27
2024-05-23T16:41:42.808529+01:00 DESKTOP-LVPVFTP usbmuxd[58211]: libusb: warning [op_get_configuration] device unconfigured
2024-05-23T16:41:42.808604+01:00 DESKTOP-LVPVFTP usbmuxd[58211]: libusb: error [op_get_active_config_descriptor] device unconfigured
2024-05-23T16:41:42.808635+01:00 DESKTOP-LVPVFTP usbmuxd[58211]: [16:41:42.808][3] Could not get old configuration descriptor for device 1-21: LIBUSB_ERROR_NOT_FOUND
2024-05-23T16:41:42.850999+01:00 DESKTOP-LVPVFTP usbmuxd[58211]: [16:41:42.850][3] Initialization complete
2024-05-23T16:41:42.851142+01:00 DESKTOP-LVPVFTP usbmuxd[58211]: [16:41:42.850][3] Enabled exit on SIGUSR1 if no devices are attached. Start a new instance with "--exit" to trigger.
2024-05-23T16:41:42.852935+01:00 DESKTOP-LVPVFTP usbmuxd[58211]: [16:41:42.852][3] Connecting to new device on location 0x10015 as ID 1
2024-05-23T16:41:42.853395+01:00 DESKTOP-LVPVFTP usbmuxd[58211]: [16:41:42.853][3] Connected to v2.0 device 1 on location 0x10015 with serial number 00008101-001E48CXXXXXXXXX
2024-05-23T16:41:48.692940+01:00 DESKTOP-LVPVFTP wsl-pro-service[208]: #033[36mINFO#033[0m Daemon: connecting to Windows Agent
2024-05-23T16:41:48.693071+01:00 DESKTOP-LVPVFTP wsl-pro-service[208]: #033[37mDEBUG#033[0m Updated systemd status to "Connecting"
2024-05-23T16:41:48.693316+01:00 DESKTOP-LVPVFTP wsl-pro-service[208]: #033[33mWARNING#033[0m Daemon: could not connect to Windows Agent: could not get address: could not read agent port file "/mnt/c/Users/donie/.ubuntupro/.address": open /mnt/c/Users/donie/.ubuntupro/.address: no such file or directory
2024-05-23T16:41:48.693382+01:00 DESKTOP-LVPVFTP wsl-pro-service[208]: #033[36mINFO#033[0m Reconnecting to Windows host in 60 seconds
2024-05-23T16:41:48.693406+01:00 DESKTOP-LVPVFTP wsl-pro-service[208]: #033[37mDEBUG#033[0m Updated systemd status to "Not connected: waiting to retry"
2024-05-23T16:41:49.409533+01:00 DESKTOP-LVPVFTP usbmuxd[58211]: [16:41:49.409][1] device_control_input: ERROR (on device): asyncReadComplete, message was too large (65536 bytes, max = 65535)
2024-05-23T16:41:49.411258+01:00 DESKTOP-LVPVFTP usbmuxd[58211]: [16:41:49.411][1] device_control_input: ERROR (on device): asyncReadComplete, message was too large (65536 bytes, max = 65535)
2024-05-23T16:42:23.510946+01:00 DESKTOP-LVPVFTP usbmuxd[58211]: [16:42:23.510][2] device_control_input: Got unhandled payload type 4
2024-05-23T16:42:48.752655+01:00 DESKTOP-LVPVFTP wsl-pro-service[208]: #033[36mINFO#033[0m Daemon: connecting to Windows Agent
2024-05-23T16:42:48.757790+01:00 DESKTOP-LVPVFTP wsl-pro-service[208]: #033[37mDEBUG#033[0m Updated systemd status to "Connecting"
2024-05-23T16:42:48.757865+01:00 DESKTOP-LVPVFTP wsl-pro-service[208]: #033[33mWARNING#033[0m Daemon: could not connect to Windows Agent: could not get address: could not read agent port file "/mnt/c/Users/donie/.ubuntupro/.address": open /mnt/c/Users/donie/.ubuntupro/.address: no such file or directory
2024-05-23T16:42:48.757878+01:00 DESKTOP-LVPVFTP wsl-pro-service[208]: #033[36mINFO#033[0m Reconnecting to Windows host in 60 seconds
2024-05-23T16:42:48.757888+01:00 DESKTOP-LVPVFTP wsl-pro-service[208]: #033[37mDEBUG#033[0m Updated systemd status to "Not connected: waiting to retry"

The idevicerestore command logs are shown below for reference ...

Is it possible to fix this "message was too large (65536 bytes, max = 65535)"??

Many thanks Donie

Note: during the process of restoring the firmware the iPhone presents as different things on the usbipd side as shown. The apple devices persisted are all the same device. Just in case it's relevant. I have to manually bind and attach during the process before the code times out. I'm not worried about that as we can automate that later. Just need it to transfer the image to restore manually first.

PS C:\Users\donie> usbipd list
Connected:
BUSID  VID:PID    DEVICE                                                        STATE
2-1    05ac:12a8  Apple Mobile Device USB Composite Device                      Attached
2-6    1bcf:28cf  Integrated Webcam                                             Not shared
2-8    0a5c:5842  Dell ControlVault w/o Fingerprint Sensor, Microsoft Usbcc...  Not shared
2-10   8087:0026  Intel(R) Wireless Bluetooth(R)                                Not shared
3-2    0bda:8153  Realtek USB GbE Family Controller                             Not shared
4-3    046d:c52b  Logitech USB Input Device, USB Input Device                   Not shared
4-5    0bda:4014  Realtek USB Audio                                             Not shared

Persisted:
GUID                                  DEVICE
33a1cdbf-4373-4d17-a813-00d3bb825d3f  Apple Recovery (iBoot) USB Composite Device, Apple Mobile...v
5002e98e-b231-464b-8fb7-72c912858934  Apple Recovery (iBoot) USB Composite Device, Apple Mobile...v
$ idevicerestore --erase iPhone13,2,iPhone13,3_17.5_21F79_Restore.ipsw
idevicerestore 1.0.0-188-g56d2c01
Found device in Recovery mode
ECID: 8524247579XXXXXX
Identified device as d53gap, iPhone13,2
Device Product Version: N/A
Device Product Build: N/A
Extracting BuildManifest from IPSW
IPSW Product Version: 17.5
IPSW Product Build: 21F79 Major: 21
INFO: device serial number is FFXDNXXXXXXX
Device supports Image4: true
Variant: Customer Erase Install (IPSW)
This restore will erase all 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
Getting ApNonce in recovery mode... 00 a2 ad 7d 37 76 01 fe ba bb f5 8c 5d 6a d1 51 53 b4 0a d8 bf 69 0f 16 59 9e 13 c8 bb 8b c2 13 
Trying to fetch new SHSH blob
Getting SepNonce in recovery mode... f1 21 da 43 aa 5a 7d 1a 5b 8d b4 1f 06 23 a3 24 4e 05 18 91 
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.d53g.RELEASE.im4p (Firmware/dfu/iBEC.d53g.RELEASE.im4p)...
Personalizing IMG4 component iBEC...
Sending iBEC (921917 bytes)...
Recovery Mode Environment:
iBoot build-version=iBoot-10151.122.3
iBoot build-style=RELEASE
Sending RestoreLogo...
Extracting applelogo@2532~iphone.im4p (Firmware/all_flash/applelogo@2532~iphone.im4p)...
Personalizing IMG4 component RestoreLogo...
Sending RestoreLogo (29090 bytes)...
Extracting h13_ane_fw_styx_d5x.im4p (Firmware/ane/h13_ane_fw_styx_d5x.im4p)...
Personalizing IMG4 component ANE...
Sending ANE (4925117 bytes)...
Extracting aopfw-iphone13aop.RELEASE.im4p (Firmware/AOP/aopfw-iphone13aop.RELEASE.im4p)...
Personalizing IMG4 component AOP...
Sending AOP (2430653 bytes)...
Extracting AppleAVE2FW_H13.im4p (Firmware/ave/AppleAVE2FW_H13.im4p)...
Personalizing IMG4 component AVE...
Sending AVE (1373045 bytes)...
Extracting armfw_g13p.im4p (Firmware/agx/armfw_g13p.im4p)...
Personalizing IMG4 component GFX...
Sending GFX (2932181 bytes)...
Extracting adc-pallas-d5xg.im4p (Firmware/isp_bni/adc-pallas-d5xg.im4p)...
Personalizing IMG4 component ISP...
Sending ISP (20702912 bytes)...
Extracting t8101pmp.im4p (Firmware/pmp/t8101pmp.im4p)...
Personalizing IMG4 component PMP...
Sending PMP (435901 bytes)...
Extracting rans.t8101.release.im4p (Firmware/rans.t8101.release.im4p)...
Personalizing IMG4 component RestoreANS...
Sending RestoreANS (963657 bytes)...
Extracting iphone13dcp_restore.im4p (Firmware/dcp/iphone13dcp_restore.im4p)...
Personalizing IMG4 component RestoreDCP...
Sending RestoreDCP (4998845 bytes)...
Extracting 090-24459-112.dmg.trustcache (Firmware/090-24459-112.dmg.trustcache)...
Personalizing IMG4 component RestoreTrustCache...
Sending RestoreTrustCache (16032 bytes)...
Extracting SmartIOFirmware_ASCv4.im4p (Firmware/SmartIOFirmware_ASCv4.im4p)...
Personalizing IMG4 component SIO...
Sending SIO (1163409 bytes)...
Extracting WirelessPower.iphone13.im4p (Firmware/WirelessPower/WirelessPower.iphone13.im4p)...
Personalizing IMG4 component WCHFirmwareUpdater...
Sending WCHFirmwareUpdater (168431 bytes)...
Extracting iBootData.d53g.RELEASE.im4p (Firmware/all_flash/iBootData.d53g.RELEASE.im4p)...
Personalizing IMG4 component iBootData...
Sending iBootData (16970 bytes)...
ramdisk-size=0x20000000
Extracting 090-24459-112.dmg (090-24459-112.dmg)...
Personalizing IMG4 component RestoreRamDisk...
Sending RestoreRamDisk (201336512 bytes)...
Extracting DeviceTree.d53gap.im4p (Firmware/all_flash/DeviceTree.d53gap.im4p)...
Personalizing IMG4 component RestoreDeviceTree...
Sending RestoreDeviceTree (59165 bytes)...
Extracting sep-firmware.d53g.RELEASE.im4p (Firmware/all_flash/sep-firmware.d53g.RELEASE.im4p)...
Personalizing IMG4 component RestoreSEP...
Sending RestoreSEP (6631356 bytes)...
Extracting kernelcache.release.iphone13 (kernelcache.release.iphone13)...
Personalizing IMG4 component RestoreKernelCache...
Sending RestoreKernelCache (17247894 bytes)...
Waiting for device to enter restore mode...
About to restore device... 
Connecting now...
Connected to com.apple.mobile.restored, version 15
Device 00008101-001E48C20CF1003A has successfully entered restore mode
Hardware Information:
BoardID: 12
ChipID: 33025
UniqueChipID: 8524247579295802
ProductionMode: true
Previous restore exit status: 0x100
Starting FDR listener thread
Checkpoint completed id: 0x655 (is_host_compatible) result=0
Checkpoint started   id: 0x604 (set_weight_from_options)
Checkpoint completed id: 0x604 (set_weight_from_options) result=0
Checkpoint started   id: 0x68F (libauthinstall_callback)
Checkpoint completed id: 0x68F (libauthinstall_callback) result=0
Checkpoint started   id: 0x608 (device_has_hoover)
Checkpoint completed id: 0x608 (device_has_hoover) result=0
Checkpoint started   id: 0x60B (update_ticket)
About to send RootTicket...
Sending RootTicket now...
Done sending RootTicket
Checkpoint completed id: 0x60B (update_ticket) result=0
Checkpoint started   id: 0x60D (wait_for_storage)
Waiting for NAND (28)
Checkpoint completed id: 0x60D (wait_for_storage) result=0
Checkpoint started   id: 0x60E (update_NAND_firmware)
Updating NAND Firmware (58)
Checkpoint completed id: 0x60E (update_NAND_firmware) result=0
Checkpoint started   id: 0x60F (clear_remap_variable)
Checkpoint completed id: 0x60F (clear_remap_variable) result=0
Checkpoint started   id: 0x65C (print_nvram_variables)
Checkpoint completed id: 0x65C (print_nvram_variables) result=0
Checkpoint started   id: 0x610 (asp_nand_set_writable)
Checkpoint completed id: 0x610 (asp_nand_set_writable) result=0
Checkpoint started   id: 0x613 (find_filesystem_partitions)
Checkpoint completed id: 0x613 (find_filesystem_partitions) result=0
Checkpoint started   id: 0x67E (verify_storage_for_update)
Checkpoint completed id: 0x67E (verify_storage_for_update) result=0
Checkpoint started   id: 0x609 (load_sep_os)
About to send NORData...
Found firmware path Firmware/all_flash
Getting firmware manifest from build identity
Extracting LLB.d53g.RELEASE.im4p (Firmware/all_flash/LLB.d53g.RELEASE.im4p)...
Personalizing IMG4 component LLB...
Extracting ansf.t8101.release.im4p (Firmware/ansf.t8101.release.im4p)...
Personalizing IMG4 component ANS...
Extracting applelogo@2532~iphone.im4p (Firmware/all_flash/applelogo@2532~iphone.im4p)...
Personalizing IMG4 component AppleLogo...
Extracting batterycharging0@2532~iphone.im4p (Firmware/all_flash/batterycharging0@2532~iphone.im4p)...
Personalizing IMG4 component BatteryCharging0...
Extracting batterycharging1@2532~iphone.im4p (Firmware/all_flash/batterycharging1@2532~iphone.im4p)...
Personalizing IMG4 component BatteryCharging1...
Extracting batteryfull@2532~iphone.im4p (Firmware/all_flash/batteryfull@2532~iphone.im4p)...
Personalizing IMG4 component BatteryFull...
Extracting batterylow0@2532~iphone.im4p (Firmware/all_flash/batterylow0@2532~iphone.im4p)...
Personalizing IMG4 component BatteryLow0...
Extracting batterylow1@2532~iphone.im4p (Firmware/all_flash/batterylow1@2532~iphone.im4p)...
Personalizing IMG4 component BatteryLow1...
Extracting glyphplugin@2532~iphone-lightning.im4p (Firmware/all_flash/glyphplugin@2532~iphone-lightning.im4p)...
Personalizing IMG4 component BatteryPlugin...
Extracting DeviceTree.d53gap.im4p (Firmware/all_flash/DeviceTree.d53gap.im4p)...
Personalizing IMG4 component DeviceTree...
Extracting liquiddetect@2532~iphone-lightning.im4p (Firmware/all_flash/liquiddetect@2532~iphone-lightning.im4p)...
Personalizing IMG4 component Liquid...
Extracting lowpowermode@2532~iphone-lightning.im4p (Firmware/all_flash/lowpowermode@2532~iphone-lightning.im4p)...
Personalizing IMG4 component LowPowerWallet0...
Extracting lowpowerfindmymode@2532~iphone-lightning.im4p (Firmware/all_flash/lowpowerfindmymode@2532~iphone-lightning.im4p)...
Personalizing IMG4 component LowPowerWallet1...
Extracting recoverymode@2532~iphone-lightning.im4p (Firmware/all_flash/recoverymode@2532~iphone-lightning.im4p)...
Personalizing IMG4 component RecoveryMode...
Extracting WirelessPower.iphone13.im4p (Firmware/WirelessPower/WirelessPower.iphone13.im4p)...
Personalizing IMG4 component WCHFirmwareUpdater...
Extracting iBoot.d53g.RELEASE.im4p (Firmware/all_flash/iBoot.d53g.RELEASE.im4p)...
Personalizing IMG4 component iBoot...
Extracting sep-firmware.d53g.RELEASE.im4p (Firmware/all_flash/sep-firmware.d53g.RELEASE.im4p)...
Personalizing IMG4 component RestoreSEP...
Extracting sep-firmware.d53g.RELEASE.im4p (Firmware/all_flash/sep-firmware.d53g.RELEASE.im4p)...
Personalizing IMG4 component SEP...
Sending NORData now...
ERROR: Unable to send NORData
ERROR: Unable to send NOR data
ERROR: Unable to successfully restore device
ERROR: Unable to restore device
$
d0n13 commented 3 months ago

Maybe related to #867

dorssel commented 3 months ago

The usbmuxd error is logged here: https://github.com/libimobiledevice/usbmuxd/blob/1.1.1/src/device.c#L601

It looks like it is not usbmuxd's error. usbmuxd is just reporting/relaying the error from whatever underlying driver/library it is talking to. But I don't know what that is; I have no Apple knowledge.

The explanation in https://github.com/dorssel/usbipd-win/issues/867#issuecomment-1956410565 is still the best I can come up with. Try to find whatever usbmuxd is using to talk to the device and see if you can increase the buffer size there.

d0n13 commented 3 months ago

The explanation in #867 (comment) is still the best I can come up with. Try to find whatever usbmuxd is using to talk to the device and see if you can increase the buffer size there.

I changed all buffer sizes I could find in idevicerestore which had hardcoded buffers of 65535 and 0xFFFF but the error was the same... Will have to dig deeper for this one I think.