usbmuxd.service daemon doesn't survive suspend/resume

[axper]

Scenario:

1. Connect iphone to computer, run some commands like ideviceinstaller
2. Suspend the computerm
3. Resume the computer, iphone still plugged in the whole time
4. Run a command, i.e. ideviceinstaller.
5. Getting this error:

No iOS device found, is it plugged in?

A workaround is to manually restart usbmuxd.service or to replug the device which triggers the udev rule. After suspend I see this in usbmuxd service logs:

Apr 07 15:27:52 asus systemd[1]: Started Socket daemon for the usbmux protocol used by Apple devices.
Apr 07 15:27:52 asus usbmuxd[9668]: [05:10:12.970][3] usbmuxd v1.1.1 starting up
Apr 07 15:27:52 asus usbmuxd[9668]: [05:10:12.970][3] Successfully dropped privileges to 'usbmux'
Apr 07 15:27:52 asus usbmuxd[9668]: [05:10:12.973][3] Could not get old configuration descriptor for device 1-33: -5
Apr 07 15:27:52 asus usbmuxd[9668]: [05:10:12.975][3] Connecting to new device on location 0x10021 as ID 1
Apr 07 15:27:52 asus usbmuxd[9668]: [05:10:12.975][3] Initialization complete
Apr 07 15:27:52 asus usbmuxd[9668]: [05:10:12.975][3] Enabled exit on SIGUSR1 if no devices are attached. Start a new instance with "--exit" to trigger.
Apr 07 15:27:52 asus usbmuxd[9668]: [05:10:12.976][3] Connected to v2.0 device 1 on location 0x10021 with serial number 3a7c6c8596bbef789f711e9ecb9f50fecc5a6c79
Apr 07 20:52:24 asus usbmuxd[9668]: [07:30:43.064][3] Removed device 1 on location 0x10021
Apr 07 20:52:24 asus usbmuxd[9668]: [07:30:43.089][3] usbmuxd shutting down
Apr 07 20:52:24 asus usbmuxd[9668]: [07:30:43.191][3] Shutdown complete

I think there's a better way to handle this particular scenario.

[maciejsszmigiero]

After a resume from suspend (S3 or S4), with an iPhone connected the whole sleep time, usbmuxd logs: usbmuxd[1234]: [2] Attempted to connect to nonexistent device 1

This is because it gets LIBUSB_TRANSFER_NO_DEVICE result from TX or RX libusb callback and forgets about the device being connected.

I've checked what udev events are triggered for the iPhone upon suspend /+ resume cycle and I am getting only unbind + bind events for various usb_interface devices but no events for the whole usb_device.

usbmuxd udev rules trigger only on events for the whole usb_device, so in this case usbmuxd never gets notified to reconnect to the phone.

Playing with power/persist USB device attribute does not help.

I would suggest that upon receiving LIBUSB_TRANSFER_NO_DEVICE usbmuxd should try to rediscover the device, just one time.

[nikias]

I am not sure if this is that simple to fix. First, the Attempted to connect to nonexistent device is when a new connection is attempted. I think the Removed device X on location Y is the result of handling the libusb hotplug event LIBUSB_HOTPLUG_EVENT_DEVICE_LEFT, but I might be wrong. Can you run usbmuxd in super verbose mode, like pass -v -v -v and do the same sleep/wake cycle again, then paste the log output?

[maciejsszmigiero]

First, the Attempted to connect to nonexistent device is when a new connection is attempted.

Likely it is caused by UPower trying to periodically poll the connected phone battery level.

I think the Removed device X on location Y is the result of handling the libusb hotplug event LIBUSB_HOTPLUG_EVENT_DEVICE_LEFT, but I might be wrong. Can you run usbmuxd in super verbose mode, like pass -v -v -v and do the same sleep/wake cycle again, then paste the log output?

You are right, the following gets logged during system resume with -v -v -v:

usbmuxd[1234]: [4] Device 3-11 RX aborted due to disconnect
usbmuxd[1234]: [4] Device 3-11 RX aborted due to disconnect
usbmuxd[1234]: [4] Device 3-11 RX aborted due to disconnect
usbmuxd[1234]: [3] Removed device 1 on location 0x3000b
usbmuxd[1234]: [5] client_device_remove: id 1
usbmuxd[1234]: [5] send_pkt fd 5 tag 0 msg 8 payload_length 282

There is no output from usbmuxd during the system suspend sequence.

However, Removed device X on location Y is normally not logged since it has NOTICE level while when usbmuxd is run in background it only logs messages starting from WARNING level.

The next messages are these UPower polls:

usbmuxd[1234]: [4] New client on fd 13 (pid 5678)
usbmuxd[1234]: [5] Client command in fd 13 len 512 ver 1 msg 8 tag 1534
usbmuxd[1234]: [5] Client 13 connection request to device 1 port 62078
usbmuxd[1234]: [2] Attempted to connect to nonexistent device 1
usbmuxd[1234]: [5] send_pkt fd 13 tag 1534 msg 8 payload_length 278
usbmuxd[1234]: [4] Client 13 connection closed
usbmuxd[1234]: [4] Disconnecting client fd 13

[nikias]

Ok I see... well the problem is that even when usbmuxd would re-scan for devices the device will have a different numerical identifier, looking at the above case it would then be 2. upower seems to keep the idevice_t handle and just tries to connect to lockdownd (port 62078) using that handle, even though the device has disconnected.

[maciejsszmigiero]

This ID seems to be something internal to usbmuxd, looking that it is generated sequentially in get_next_device_id() in src/device.c.

Can't usbmuxd simply check whether the device of this UDID (or so) is already known and then reuse the existing ID in such reconnection case?

[maciejsszmigiero]

BTW. I think it is simply a bad design on the kernel / libusb side to not allow differentiating between a genuine device disconnection event and a suspend / resume cycle without applying some hacky heuristics.

For example, ALSA has SND_PCM_STATE_SUSPENDED state for such occurence.

[nikias]

Ok I checked the log messages again and

usbmuxd[1234]: [4] Device 3-11 RX aborted due to disconnect

Will cause the device removal, not the usb hotplug remove event.

I think it would be an option to have it check if the usb device is still there, but somehow this still seems like a hacky solution to me...

[maciejsszmigiero]

Ok I checked the log messages again and usbmuxd[1234]: [4] Device 3-11 RX aborted due to disconnect Will cause the device removal, not the usb hotplug remove event.

As I said on Sunday:

I am getting only unbind + bind events for various usb_interface devices but no events for the whole usb_device.

usbmuxd udev rules trigger only on events for the whole usb_device, so in this case usbmuxd never gets notified to reconnect to the phone.

Technically, usbmuxd isn't notified that the phone has disconnected by udev either, it is only that libusb calls start returning NO_DEVICE error.