MacBook Pro M3 2023 Unable to connect to device

[shadowwalkersteam]

I've M3 Mac connected in DFU mode, Apple Configurator is showing the DFU Mac connected but irecovery is not showing it. Below are the logs coming up when I executed with -v -q parameters.

Attempting to connect... 
Attempting to connect... 
Attempting to connect... 
Attempting to connect... 
Attempting to connect... 
Attempting to connect... 
ERROR: Unable to connect to device

I want to get the ECID of the connected Mac. I've latest compiled binaries. need your help @nikias

[nikias]

I assume that you are trying with the latest code?

[shadowwalkersteam]

I assume that you are trying with the latest code?

Yes I'm trying with the latest code.

[shadowwalkersteam]

This is how it is showing in USB Tree and Apple Configurator

[nikias]

Ahhh I see. It's using KIS DFU. I have pending commits to push that add support for it (macOS and Linux -- windows not yet). Will push it later today and then you can try again.

[nikias]

I actually pushed the commits now. Let me know if this works now.

[shadowwalkersteam]

Sure, I'll test this.

[shadowwalkersteam]

@nikias it is working with the new commits. But the thing is if I have 2 Macs connected in DFU it only gives 1 device, Is there a way to list them all?

[nikias]

Thanks for confirming. The irecovery tool hasn't been designed to support multiple devices; the underlying library code could handle it though. The enumeration of devices is missing, then it would be just a matter of calling irecv_open_with_ecid with the given ECID of the devices found. I will see what we can do here.

[shadowwalkersteam]

@nikias I got M3 Pro (15,6) as well and that is not showing in irecovery -q and this one looks different from the simple M3 in terms of response from System report. Please check the below screenshots. However the simple M3 (15,3) is showing perfectly fine with the last changes you made.

[nikias]

I see. The USB Product ID is different, 0xf014 as you can see in the screenshot. This is Port DFU mode, not sure how this is different...

[shadowwalkersteam]

I see. The USB Product ID is different, 0xf014 as you can see in the screenshot. This is Port DFU mode, not sure how this is different...

So what change you recommend should I do to add this product support?

[shadowwalkersteam]

Also look at the CPID and BDID they look totally different, and this Mac15,6 doesn't have these CPID and BDID.

[nikias]

Yes it's a totally different mode it seems... you could try to add the 0xf014 here: https://github.com/libimobiledevice/libirecovery/blob/1a12fc2877a5aac5ef28b196753c83188fc13ef0/src/libirecovery.c#L1644 but I don't really think this will work

[nikias]

Just for reference, adding this here: https://infosec.exchange/@siguza/111118479751581819

[Siguza]

Also FWIW if you use macvdmtool to put the target into DFU, then the AP will be in DFU but the USB-C port will not be, so it will enumerate as KIS (Debug USB).

[scwgoire]

Hi guys, we started hacking around with idevicerestore and M3 Pro laptop. Our findings are the same:

• going DFU from keyboard combo enumerates as "Port DFU mode" (devid= 0xF014)
• going DFU from USB PD VDM enumerates as KIS (devid= 0x1881)

Not sure yet what we can do with idevicerestore from either mode, we'll start digging into that. We may end up with the oscilloscope to reverse any new VDM that may be required.

Happy to share our future findings to contribute to M3 (not yet tried) and M3 Pro (M3 Max unlikely at this stage) support to idevicerestore as we did with M1 a few years back. Please reach out to me.

[Siguza]

@scwgoire KIS DFU support is tracked in #106 and should be supported on macOS and Linux hosts already. Port DFU mode seems to want a personalised USB-C firmware uploaded first. The CPID and BDID of Port DFU Mode are also found in the BuildManifest.plist of devices that have it, and the BDID of Port DFU is just 00000000[BDID][CPID]00 of the AP anyway. The lower two zeroes may also be SCEP of the AP... or just zeroes, I can't tell. Either way, MobileDevice.framework has the code to deal with Port DFU somewhere, as always.

[tbellavia]

Following the @scwgoire message, when testing against M3 in KIS mode, we have a segfault on _irecv_handle_device_add on the strcpy(serial_str, client->device_info.serial_string) call while running idevicrestore -ey file.ipsw.

The reason is that when calling the libusb_usb_open_handle_with_descriptor_and_ecid function to get client infos it never try to get the serial_str because it does not validate the product_id != KIS_PRODUCT_ID condition. Thus client->device_info.serial_string is null.

We tried to forcefully enter the client->mode != KIS_PRODUCT_ID condition in the libusb_usb_open_handle_with_descriptor_and_ecid function, but irecv_get_string_descriptor_ascii does not fill the serial_str buffer, and the function returns with status LIBUSB_ERROR_INVALID_PARAM (-2). This is expected because when doing an lsusb, iSerial is empty :

  idVendor           0x05ac Apple, Inc.
  idProduct          0x1881
  bcdDevice            4.00
  iManufacturer           1 Apple Inc.
  iProduct                2 Debug USB
  iSerial                 0

When recovering using apple configurator 2 the usb "sequence" seems to be :

• Port DFU (Entered via key combo) (0xf014)
• KIS (0x1881)
• Recovery mode 2 (0x1281)

The question now seems to be, how to transition from KIS to Recovery mode 2 (our setup is to go to KIS directly with USB VDM messages, so we are not yet blocked by port DFU) ?

How can we help ?

[tbellavia]

For the MobileDevice.framework, I don't believe the source is open, can you give me some insight on where to start exploring ?

[Siguza]

@Cardiox12 file path is /Library/Apple/System/Library/PrivateFrameworks/MobileDevice.framework/MobileDevice. The distinction between Port DFU, USB DFU, Recovery, etc. happens in _deviceConnected, and for Port DFU it calls _AMPortDFUModeDeviceCreate. I haven't looked into it much, but from there it seems to go through multiple layers, look for symbols with PortDFU, Ace3 and UARP/uarp in their name.

[nikias]

@Cardiox12 in KIS mode, the serial string is taken from a buffer (KIS_device_info) read from the device, that contains a usb descriptor buffer. It's not read from a typical string descriptor.

[nikias]

You can turn on debug info for libirecovery by setting an environment variable, so you can run

LIBIRECOVERY_DEBUG_LEVEL=1 idevicerestore file.ipsw

Look out for a line Loading device info in KIS mode... and see what follows.

[scwgoire]

You can turn on debug info for libirecovery by setting an environment variable, so you can run LIBIRECOVERY_DEBUG_LEVEL=1 idevicerestore file.ipsw Look out for a line Loading device info in KIS mode... and see what follows.

idevicerestore SEGFAULTs (in libirecovery.c:2437) before we can get a chance to get this message. This is because it uses libusb_usb_open_handle_with_descriptor_and_ecid which doesn't implement reading serial string from KIS. (This is a piece of code that is located in irecv_open_with_ecid).

We managed to leverage code from irecv_open_with_ecid to get the serial string and move on. We are now stuck further down the process in idevicerestore_start, we need to check out why. Will get back to you in January with more findings, this is holidays time now 😁.

[nikias]

Just tested on macOS and it has the same issue when the _irecv_handle_device_add code is used; the KIS init is missing. Working on a fix.

[tbellavia]

@nikias I tried what you merged for M3 support on M3, install was ok, we'll try on M3 Pro tomorrow.

[nikias]

Thanks, excited to see the results.

[tbellavia]

We tried on M3-Pro, it does not work yet, we may not be very far from making it. It is probably caused by how idevicerestore handles the 4 USBPortControllers (those ones are not present on M3 "not pro" variant).

See the log file m3-pro.log

First clue is line 198 (not sure what RestoreRequestRules are) :

DEBUG: tss_request_add_ap_tags: Skipping 'USBPortController1,USBFirmware' as it doesn't have RestoreRequestRules
DEBUG: tss_request_add_ap_tags: Skipping 'USBPortController2,USBFirmware' as it doesn't have RestoreRequestRules
DEBUG: tss_request_add_ap_tags: Skipping 'USBPortController3,USBFirmware' as it doesn't have RestoreRequestRules
DEBUG: tss_request_add_ap_tags: Skipping 'USBPortController4,USBFirmware' as it doesn't have RestoreRequestRules

Second clue, is line 2386-2421:

• the Trusted, EPRO and ESEC keys are missing for the 4 USBPortControllers
• the digest list size for USBPortController4 is different from the others (again not sure what this is).

Third clue:

• at line 3726: it sends firmware for USBPortController4 and then requests ticket for the 4 USBPortControllers
• at line 4180: it believes it received a ticket for USBPortController1 (probably can't handle the 4 tickets bundle response)
• at line 4205: sends firmware for USBPortController4 but requests tickets for USBPortController 2-4 only
• at line 4567: it complains it received no ticket for USBPortController1 and exits

We are working on it, if you have any ideas on where we can start, we would love to hear about it.

[scwgoire]

About lin 4180, the culprit is in restore_get_generic_firmware_data:

        const char* response_ticket = NULL;
    if (PLIST_IS_ARRAY(response_tags)) {
        plist_t tag0 = plist_array_get_item(response_tags, 0);
        if (tag0) {
            response_ticket = plist_get_string_ptr(tag0, NULL);
        }
    }

If multiple tickets are requested, we only keep track of the first one to verify the response is correct. However this simply is a warning, no big deal.

Some oddities:

• the mac asks twice for the same USBPortController4,Firmware (lines 3726 and 4205)
• the second time, the DeviceGeneratedRequest received doesn't contain info about USBPortController1 but a ticket for it still is requested in ResponseTags
• in both cases, Arguments.MessageArgInfo.TicketName is USBPortController1,Ticket which is not consistent with the firmware just sent.

Keeping up with digging... 😄

[scwgoire]

Little update: I couldn't find something suspicious in the code today. idevicerestore seems to be performing the job, properly forwarding Ace3 TSS requests from the mac to the TSS server and sending back the tickets to the mac.

The following questions remain unanswered:

• why is the mac unhappy with the first set of 4 tickets?
• why is it doing something looking like a retry with a different query? (no TSS query data for USBPortController1,Firmware)
• why is the mac asking for a 4 tickets set instead of just one for the previously requested firmware? (here USBPortController4,Firmware)

The TicketName query parameter for 4 tickets being USBPortController1,Firmware may indicate a confusion in the firmware request order (the first usb port controller firmware request being for controller 4) or just a "why not? there is only room for one value there"

Still pretty much in the dark there.

[scwgoire]

Allright, time for a little update. I have been skimming through a USB dump of the communication between an M2 Pro being restored and Apple Configurator 2 restoring it. The interesting fact is the same happens there (USBPortController4,USBFirmware is asked twice, asks for 4 tickets the first time, then 3 tickets only).

In this dump, after the 3 tickets are send back to the mac, I get 7 ProgressMsg in a row and then CHECKPOINT_COMPLETE for update_ac3.

With idevicerestore I can't reach this checkpoint, it fails before (see my previous log's ending, ReverseProxy[Ctrl]: Connection closed)

I now think the problem is somewhere else. If the Ace3 TSS process was incorrect, it would probably fail before asking for the 3 tickets.

[scwgoire]

Allright, I found something promising!

Maybe restore_device() function doesn't provide enough data to the mac, here are the RestoreOptions I can't find any reference for in idevicerestore source code:

• HostHasFixFor99053849 (true)
• PersonalizedRecoveryOSBundlePath (a temp path on my machine)
• RecoveryOSBundlePath (a temp path on my machine)
• RecoveryOSImage
  • ImageFile (a temp path on my machine)
  • RecoveryOSImageOriginalPath (a temp path on my machine)
• RecoveryOSSourceBundlePath (a temp path on my machine)
• RestoreBundleOriginalPathOverride (a temp path on my machine)
• SupportedDataTypes
  • FirmwareUpdaterDataV3 (true) <-- may be important
  • UpdateVolumeOverlayRootDataCount (true)
• SupportedMessageTypes
  • AsyncDataRequestMsg (true) <-- looks important
  • AsyncWait (true) <-- maybe important
• Ace3Binary (46849 bytes blob) <-- prime suspect, this blob is extracted from Firmware/Ace3/j516/usbcfw_j516.uarp file. Couldn't find documentation about the blob format nor the uarp file format.

AsyncDataRequestMsg looks important because here is the plist requesting the RecoveryOS image. Not sure it will be used by the mac if not advertised by idevicerestore though.

<?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>DataPort</key>
    <integer>12346</integer>
    <key>DataType</key>
    <string>RecoveryOSASRImage</string>
    <key>MsgType</key>
    <string>AsyncDataRequestMsg</string>
</dict>
</plist>

Some more fun next time... see ya! 😄

[scwgoire]

Allright guys, I'm back with some new, I hope you didn't miss me 😄

Looks like this is a usbmuxd problem after all. After lots of attempts I could sometimes have idevicerestore to finish. Every time but once, it happened just after a fresh reboot of the system running idevicerestore (a RaspberryPI).

So, here is how it goes in idevicerestore when it fails (see previously posted log):

• idevicerestore does its thing until...
• it uploads USBPortController4,USBFirmware
• there is a ~20 seconds where nothing happens
• it uploads, again, USBPortController4,USBFirmware (same happens when using apple configurator 2, seems legit)
• there is, again, a ~20 seconds where nothing happens
• the reverse proxy closes the connection with an unknown (-256) error.

Now, on the usbmuxd side (in very verbose mode), we can also observe the 2 pauses (I guess the mac has stuff to do there), but after the second one an error happens. (with errno -104 or -71).

[105.956251] [000005c9] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[105.956324] [000005c9] libusb: debug [usbi_wait_for_events] poll() 3 fds with timeout in 0ms
[105.956385] [000005c9] libusb: debug [usbi_wait_for_events] poll() returned 1
[105.956446] [000005c9] libusb: debug [reap_for_handle] urb type=3 status=-104 transferred=0
[105.956481] [000005c9] libusb: debug [handle_bulk_completion] handling completion status -104 of bulk urb 1/1
[105.956513] [000005c9] libusb: debug [handle_bulk_completion] all URBs in transfer reaped --> complete!
[105.956546] [000005c9] libusb: debug [usbi_handle_transfer_completion] transfer 0x5593878a68 has callback 0x557efe869c
[105.956583] [000005c9] libusb: debug [libusb_submit_transfer] transfer 0x5593878a68
[105.956616] [000005c9] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 16384
[105.961133] [000005c9] libusb: debug [submit_bulk_transfer] first URB failed, easy peasy
[105.961194] [000005c9] libusb: debug [reap_for_handle] urb type=3 status=-104 transferred=0
[105.961228] [000005c9] libusb: debug [handle_bulk_completion] handling completion status -104 of bulk urb 1/1
[105.961255] [000005c9] libusb: debug [handle_bulk_completion] all URBs in transfer reaped --> complete!
[105.961281] [000005c9] libusb: debug [usbi_handle_transfer_completion] transfer 0x5593877ba8 has callback 0x557efe869c
[105.961309] [000005c9] libusb: debug [libusb_submit_transfer] transfer 0x5593877ba8
[105.961339] [000005c9] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 16384
[105.965804] [000005c9] libusb: debug [submit_bulk_transfer] first URB failed, easy peasy
[105.965869] [000005c9] libusb: debug [reap_for_handle] urb type=3 status=-104 transferred=0
[105.965902] [000005c9] libusb: debug [handle_bulk_completion] handling completion status -104 of bulk urb 1/1
[105.965928] [000005c9] libusb: debug [handle_bulk_completion] all URBs in transfer reaped --> complete!
[105.965955] [000005c9] libusb: debug [usbi_handle_transfer_completion] transfer 0x5593877c98 has callback 0x557efe869c
[105.965985] [000005c9] libusb: debug [libusb_submit_transfer] transfer 0x5593877c98
[105.966011] [000005c9] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 16384
[105.970442] [000005c9] libusb: debug [submit_bulk_transfer] first URB failed, easy peasy

Right after that, clients are disconnected.

[105.993208] [000005c9] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[105.993266] [000005c9] libusb: debug [usbi_wait_for_events] poll() 3 fds with timeout in 0ms
[105.993309] [000005c9] libusb: debug [usbi_wait_for_events] poll() returned 1
[105.993340] [000005c9] libusb: debug [usbi_remove_event_source] remove fd 10
[105.993391] [000005c9] libusb: debug [usbi_handle_disconnect] device 3.19
[105.993459] [000005c9] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[105.993493] [000005c9] libusb: debug [handle_events] event sources modified, reallocating event data
[105.993531] [000005c9] libusb: debug [usbi_wait_for_events] poll() 2 fds with timeout in 0ms
[105.993568] [000005c9] libusb: debug [usbi_wait_for_events] poll() returned 1
[105.993594] [000005c9] libusb: debug [handle_event_trigger] event triggered
[105.993618] [000005c9] libusb: debug [handle_event_trigger] hotplug message received
[17:59:23.050][3] Removed device 1 on location 0x30013
[17:59:23.050][5] connection_teardown dev 1 sport 2 dport 62078
[17:59:23.050][4] Client 11 is going to be disconnected: idevicerestore[1469]
[17:59:23.050][5] connection_teardown dev 1 sport 5 dport 62078
[17:59:23.050][4] Client 12 is going to be disconnected: idevicerestore[1469]
[17:59:23.050][5] connection_teardown dev 1 sport 6 dport 1082
[17:59:23.050][4] Client 13 is going to be disconnected: idevicerestore[1469]
[17:59:23.051][5] client_device_remove: id 1
[17:59:23.051][5] Client 9 output buffer got tag 0 msg 8 payload_length 282
[17:59:23.051][2] Cannot find device entry while removing USB device 0x5593877940 on location 0x30013
[17:59:23.051][5] usb_disconnect: cancelling RX xfer 0x5593878a68
[105.995436] [000005c9] libusb: debug [libusb_cancel_transfer] transfer 0x5593878a68
[17:59:23.052][5] usb_disconnect: cancelling RX xfer 0x5593877ba8
[105.995498] [000005c9] libusb: debug [libusb_cancel_transfer] transfer 0x5593877ba8
[17:59:23.052][5] usb_disconnect: cancelling RX xfer 0x5593877c98
[105.995558] [000005c9] libusb: debug [libusb_cancel_transfer] transfer 0x5593877c98

Then usbmuxd goes in an infinite loop, it has to be kill -9'ed and restarted.

[105.995593] [000005c9] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[105.995621] [000005c9] libusb: debug [usbi_wait_for_events] poll() 2 fds with timeout in 1ms
[105.996742] [000005c9] libusb: debug [usbi_wait_for_events] poll() returned 0
[105.996790] [000005c9] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[105.996822] [000005c9] libusb: debug [usbi_wait_for_events] poll() 2 fds with timeout in 1ms
[105.997936] [000005c9] libusb: debug [usbi_wait_for_events] poll() returned 0
[105.997976] [000005c9] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[105.998009] [000005c9] libusb: debug [usbi_wait_for_events] poll() 2 fds with timeout in 1ms
[105.999127] [000005c9] libusb: debug [usbi_wait_for_events] poll() returned 0
[105.999174] [000005c9] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[105.999206] [000005c9] libusb: debug [usbi_wait_for_events] poll() 2 fds with timeout in 1ms
[106.000338] [000005c9] libusb: debug [usbi_wait_for_events] poll() returned 0
...

As for when the operation succeeds, I suspect this is a lucky timing, instead of failing after sending the USBFirmware with the following log lines,

...
Sending FirmwareResponse data now...
Done sending FirmwareUpdater data
ReverseProxy[Ctrl]: Connection closed
ReverseProxy[Ctrl]: Terminating
ReverseProxy[Ctrl]: (status=2) Terminated
ERROR: Could not read data (-256). Aborting.
ERROR: Unable to restore device

the restored_receive call fails with a timeout which somehow allows it to recover and keep going on until the restore succeeds.

...
Sending FirmwareResponse data now...
Done sending FirmwareUpdater data
No data to read (timeout)
Unhandled progress operation 85 (85)
Checkpoint completed id: 0x131D (update_ace3) result=0
Checkpoint started   id: 0x1318 (update_usbcretimer)
Unknown operation (82)
About to send BuildIdentity Dict...
Sending BuildIdentityDict now...
Done sending BuildIdentityDict
...

Does this ring any bell?

[scwgoire]

Ok folks, this seems to be harder than I thought. Here is a kernel log for the event:

Feb 22 14:51:10 brashat kernel: dwc2 fe980000.usb: Not connected
Feb 22 14:51:10 brashat kernel: usb 3-1: usbfs: usb_submit_urb returned -19
Feb 22 14:51:10 brashat kernel: usb 3-1: USB disconnect, device number 42
Feb 22 14:51:13 brashat kernel: usb 3-1: new high-speed USB device number 43 using dwc2
Feb 22 14:51:13 brashat kernel: usb 3-1: New USB device found, idVendor=05ac, idProduct=1905, bcdDevice=15.07
Feb 22 14:51:13 brashat kernel: usb 3-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Feb 22 14:51:13 brashat kernel: usb 3-1: Product: Mac
Feb 22 14:51:13 brashat kernel: usb 3-1: Manufacturer: Apple Inc.
Feb 22 14:51:13 brashat kernel: usb 3-1: SerialNumber: 00006030-001031811A28001C

As you can see, when the restore process fails after sending USBPortController firmware, there is an EPROTO error on the USB bus.

My current guess is the USB controller on the mac is restarted after new firmware is applied. Sometimes this generates a protocol error (due to an USB timeout?) and Linux removes the device, and sometimes the device has better luck and this is only seen as a "USB lag" by the kernel.

This really sucks because usbmuxd is made to disconnect clients when the device is removed (and that shouldn't change IMHO) and idevicerestore relies on a stable connection to usbmuxd during the restore operation.

Do you think we could and/or should expect usbmuxd disconnections during the restore process and implement a retry logic somewhere there?

[nikias]

Hi all, I added port DFU support to libirecovery with the latest commit. However this does not allow port DFU restoring, this will be implemented in idevicerestore.

I already figured out a part of the process, namely:

• A @USBPortController1,Ticket TSS request is sent, and this gives us a USBPortController1,Ticket (usual DER encoded IM4M)
• The ace3 firmware UARP file is parsed, it has a plist at the end, in NSKeyedArchiver format. The firmware contains multiple payloads (called "SuperBinary Payloads"), and there is a selection process. Some of the payload entries in the plist have a "Payload Metadata" dictionary, and that contains an entry "Personalization Board ID (64 bits)" which is the BoardID of the port DFU device. The corresponding payload entry is selected; it has a "Payload 4CC" item, e.g. DL03 which will later be used to get the actual payload blob from the other part of the UARP file. Next, the selected payload entry has a list called "Personalization Matching Data". This contains further entries with "Personalization Matching Data Payload Tags", and two more keys defining "Personalization Matching Data Product Revision Minimum" and "Personalization Matching Data Product Revision Maximum". Using the PREV: value from the USB serial number, one of these entries is selected and the "Tags", e.g. "PT03,AC06" are later selected from the UARP.
• A new Ace3Binary file is created. Structure is basically:
  • header (64 bytes) with a CRC checksum
  • PT03 payload
  • AC06 payload
  • IM4M
  • DL03 payload

I can create that file now with the required checksum. This file is sent to the port DFU device. Not sure yet what is the next step. I just wanted to document this somewhere.

[nikias]

In case you missed it, I got Port DFU restore working: https://github.com/libimobiledevice/idevicerestore/commit/e4a5ac4114177293e3a1b555ee767377b21d4432.

The only thing wrong was that the nonce I get via USB string descriptor has to be reversed in order... took me only a day to see that 🤦