1

I routinely connect and disconnect USB devices many times when debugging and programming firmware. The devices tend to be things like USB to UART adapters, Arduino's, and ISP/JTAG/SWD programmers.

To facilitate this I use a powered hub with individual power buttons. The one I have currently is a J.Burrows 7 Port USB 3.0 Hub:

enter image description here

This allows me to leave several devices plugged in and swap between them with the power button. I have the hub plugged in via its USB-A cable into a port on my Mac Studio running Ventura 13.4.1, with hub power supplied by a dedicated wall wart. I also saw the same behaviour on at least one predecessor Mac desktop (an iMac), though it might have been the same hub.

Inevitably, at some stage one of the devices will fail to enumerate. It powers up, but never appears in the device tree in System Information nor in the /dev/ directory.

Then, plugging the same device into a different port on the same hub succeeds! Eventually it fails in the same way, and I move ports again, until I run out of combinations. The only fix I've found at that point is a system reboot, which resets everything to normal.

There doesn't seem to be a pattern to which device or port fails, or why. But after it fails, if I try again I see this in the Console:

error   21:01:34.461045+1000    kernel  AppleUSBXHCICommandRing: AppleUSBXHCICommandRing::executeCommand: command[227] 0x0000000000180000 00000000 58002c01 got result 0x0000000000068e30 04000000 58008400 after 5ms (enqueued 0ms)
error   21:01:34.461061+1000    kernel  AppleUSBXHCICommandRing: AppleUSBXHCICommandRing::setAddress: completed with result code 4
error   21:01:34.461258+1000    kernel  AppleUSBXHCICommandRing: AppleUSBXHCICommandRing::executeCommand: command[228] 0x0000000000000000 00000000 58013c01 got result 0x0000000000068e40 13000000 58008400 after 0ms (enqueued 0ms)
error   21:01:34.461261+1000    kernel  AppleUSBXHCICommandRing: AppleUSBXHCICommandRing::stopEndpoint: completed with result code 19
default 21:01:34.464715+1000    kernel  AppleUSB20HubPort@08333400: AppleUSBHostPort::createDevice: failed to create device (0xe00002bc)
default 21:01:34.464724+1000    kernel  AppleUSB20HubPort@08333400: AppleUSB20HubPort::resetAndCreateDevice: failed to create device, disabling port

I'm not sure how to debug this further, but the messages lead me to suspect the behaviour is not specific to my hub. Or at least, a potential resolution is not! My theory is that the device behaves badly at some point (plausible, since I'm bringing up devices that are under development), and gets blacklisted by the system. You can imagine how confusing this is when you're debugging a suspect device!

Is there a way to undo the "disabling" of the port mentioned in the error message? Or a way to disprove my theory?

The ideas here made no difference: Reset USB bus without reboot (MacBook ignores display)


Addendum 1: plugging a device that has failed into another port (where it succeeds) produces this in the console, though I'm not sure how much of it is relevant. I haven't caught logs of a device failing, and not sure how I would achieve that.

error   21:31:42.650033+1000    kernel  AppleUSBXHCICommandRing: AppleUSBXHCICommandRing::executeCommand: command[236] 0x0000000000000000 00000000 5a013c01 got result 0x0000000000068ec0 13000000 5a008401 after 0ms (enqueued 0ms)
error   21:31:42.650083+1000    kernel  AppleUSBXHCICommandRing: AppleUSBXHCICommandRing::stopEndpoint: completed with result code 19
default 21:31:42.671041+1000    heard   -[AXHeardController shutdownIfPossible]:337 BT not yet ready, delaying shutdown check
error   21:31:42.681257+1000    kernel  AppleUSBXHCIRequest: AppleUSBXHCIRequest::finish: transfer completed with status 0xe0005000
error   21:31:42.682199+1000    kernel  IOUSBHostDevice@08332000: IOUSBHostDevice::getDescriptorGated: type 0x03 index 2 length 2 completed with 0xe0005000 bytesTransferred 0 type 0x01
error   21:31:42.683166+1000    kernel  AppleUSBXHCIEndpoint: AppleUSBXHCIEndpoint::waitForStateChange: 90-1 endpoint did not start
error   21:31:42.708642+1000    kernel  AppleUSBXHCIRequest: AppleUSBXHCIRequest::finish: transfer completed with status 0xe0005000
error   21:31:42.735338+1000    kernel  IOUSBHostDevice@08332000: IOUSBHostDevice::getDescriptorGated: type 0x03 index 2 length 2 completed with 0xe0005000 bytesTransferred 0 type 0x01
error   21:31:42.736255+1000    kernel  AppleUSBXHCIEndpoint: AppleUSBXHCIEndpoint::waitForStateChange: 90-1 endpoint did not start
error   21:31:42.761735+1000    kernel  AppleUSBXHCIRequest: AppleUSBXHCIRequest::finish: transfer completed with status 0xe0005000
error   21:31:42.788460+1000    kernel  IOUSBHostDevice@08332000: IOUSBHostDevice::getDescriptorGated: type 0x03 index 2 length 2 completed with 0xe0005000 bytesTransferred 0 type 0x01
error   21:31:42.788499+1000    kernel  IOUSBHostDevice@08332000: IOUSBHostDevice::getDescriptorGated: type 0x03 index 2 length 2 completed with 0xe0005000 bytesTransferred 0 type 0x01
error   21:31:42.789357+1000    kernel  AppleUSBXHCIEndpoint: AppleUSBXHCIEndpoint::waitForStateChange: 90-1 endpoint did not start
default 21:31:42.817236+1000    kernel  AppleUSB20HubPort@08332000: AppleUSBHostPort::enumerateDeviceComplete_block_invoke: enumerated 0x2341/0043/0001 (IOUSBHostDevice / 90) at 12 Mbps
default 21:31:42.820175+1000    kernel    IOTimeSyncTimeSyncTimePort(0x9c760e45d22b0008): Other 0xe0034150
default 21:31:42.821959+1000    kernel  IOUSBHostDevice@08332000: IOUSBHostDevice::setConfigurationGated: AppleUSBCDCCompositeDevice selected configuration 1
error   21:31:42.822602+1000    kernel  IOUSBHostDevice@08332000: IOUSBHostDevice::getDescriptorGated: type 0x03 index 2 length 2 completed with 0xe00002cd bytesTransferred 0 type 0x00
default 21:31:42.825164+1000    kernel    IOTimeSyncTimeSyncTimePort(0x9c760e45d22b0008): Other 0xe0034150
default 21:31:42.826144+1000    kernel    IOTimeSyncTimeSyncTimePort(0x9c760e45d22b0008): Other 0xe0034150
error   21:31:42.827331+1000    kernel  IOUSBHostDevice@08332000: IOUSBHostDevice::getDescriptorGated: type 0x03 index 2 length 2 completed with 0xe00002cd bytesTransferred 0 type 0x00
default 21:31:42.828670+1000    kernelmanagerd  Received kext load notification: com.apple.DriverKit.AppleUserECM
error   21:31:42.841610+1000    com.apple.ifdreader Failed to find AppleUSBAlternateServiceRegistryID.
default 21:31:42.844515+1000    kernel  Driver com.apple.DriverKit.AppleUserECM has crashed 0 time(s)
default 21:31:42.844578+1000    kernel  DK: AppleUserECMData-0x1000053f0 waiting for server com.apple.DriverKit.AppleUserECM.data-1000053f0
default 21:31:42.847119+1000    kernelmanagerd  Found 1 dexts with bundle identifier com.apple.DriverKit.AppleUserECM
default 21:31:42.847259+1000    kernelmanagerd  Using unique id 7d560a96077260bbdd14afd27f38a79044a066c873ef01c63359cd396d15ed73 to pick dext matching bundle identifier com.apple.DriverKit.AppleUserECM
default 21:31:42.847744+1000    kernelmanagerd  Picked matching dext for bundle identifier com.apple.DriverKit.AppleUserECM: Dext com.apple.DriverKit.AppleUserECM v1 in executable dext bundle com.apple.DriverKit.AppleUserECM at /System/Library/DriverExtensions/com.apple.DriverKit.AppleUserECM.dext
default 21:31:42.847873+1000    kernelmanagerd  Launching driver extension: Dext com.apple.DriverKit.AppleUserECM v1 in executable dext bundle com.apple.DriverKit.AppleUserECM at /System/Library/DriverExtensions/com.apple.DriverKit.AppleUserECM.dext
default 21:31:42.851361+1000    kernel  memorystatus_update(enter): pid 40954, priority 210, dirty=0x0, Active(-1MB NF), Inactive(-1MB, NF)
default 21:31:42.851392+1000    kernel  memorystatus_update: init: limit on pid 40954 (-1MB F ) targeting priority(210) dirty?=0x0
default 21:31:42.862335+1000    kernel  /System/Library/DriverExtensions/com.apple.DriverKit.AppleUserECM.dext/com.apple.DriverKit.AppleUserECM[40954] ==> com.apple.dext
default 21:31:42.871046+1000    kernel  memorystatus_update(enter): pid 40954, priority 150, dirty=0x0, Active(-1MB NF), Inactive(-1MB, NF)
default 21:31:42.871078+1000    kernel  memorystatus_update: init: limit on pid 40954 (-1MB F ) targeting priority(150) dirty?=0x0
default 21:31:42.871603+1000    kernelmanagerd  <OSLaunchdJob | handle=58015A93-8CB7-4CD3-9E0A-E1BB4AB3A3D9>: submitAndStart completed, info=running, pid=40954
default 21:31:42.874747+1000    kernel  Boot args:
default 21:31:42.874773+1000    kernel  debug=0x0
default 21:31:42.874839+1000    kernel  Found class: IOBufferMemoryDescriptor
default 21:31:42.874844+1000    kernel  Found class: IOCommand
default 21:31:42.874847+1000    kernel  Found class: IOCommandPool
default 21:31:42.874984+1000    kernel  Found class: IODMACommand
default 21:31:42.875046+1000    kernel  Found class: IODataQueueDispatchSource
default 21:31:42.875113+1000    kernel  Found class: IODispatchQueue
default 21:31:42.875160+1000    kernel  Found class: IODispatchSource
default 21:31:42.875222+1000    kernel  Found class: IOInterruptDispatchSource
default 21:31:42.875334+1000    kernel  Found class: IOMemoryDescriptor
default 21:31:42.875395+1000    kernel  Found class: IOMemoryMap
default 21:31:42.875472+1000    kernel  Found class: IOReporter
default 21:31:42.875514+1000    kernel  Found class: IOSimpleReporter
default 21:31:42.875587+1000    kernel  Found class: IOStateReporter
default 21:31:42.875631+1000    kernel  Found class: IOHistogramReporter
default 21:31:42.875704+1000    kernel  Found class: IOReportLegend
default 21:31:42.875746+1000    kernel  Found class: IOService
default 21:31:42.875819+1000    kernel  Found class: IOServiceNotificationDispatchSource
default 21:31:42.875864+1000    kernel  Found class: IOServiceStateNotificationDispatchSource
default 21:31:42.876364+1000    kernel  Found class: IOTimerDispatchSource
default 21:31:42.876451+1000    kernel  Found class: IOUserClient
default 21:31:42.876534+1000    kernel  Found class: OSAction_IOUserClient_KernelCompletion
default 21:31:42.876580+1000    kernel  Found class: IOUserServer
default 21:31:42.876657+1000    kernel  Found class: OSAction
default 21:31:42.876703+1000    kernel  Found class: OSArray
default 21:31:42.876775+1000    kernel  Found class: OSBoolean
default 21:31:42.876820+1000    kernel  Found class: OSBundle
default 21:31:42.876899+1000    kernel  Found class: OSCollection
default 21:31:42.876985+1000    kernel  Found class: OSContainer
default 21:31:42.877028+1000    kernel  Found class: OSData
default 21:31:42.877104+1000    kernel  Found class: OSDictionary
default 21:31:42.877147+1000    kernel  Found class: OSMappedFile
default 21:31:42.877223+1000    kernel  Found class: OSNumber
default 21:31:42.877266+1000    kernel  Found class: OSObject
default 21:31:42.877341+1000    kernel  Found class: OSOrderedSet
default 21:31:42.877386+1000    kernel  Found class: OSSerialization
default 21:31:42.877461+1000    kernel  Found class: OSSet
default 21:31:42.877505+1000    kernel  Found class: OSString
default 21:31:42.877577+1000    kernel  Found class: _IOBlockStorageDevice
default 21:31:42.877621+1000    kernel  Found class: OSAction__IOBlockStorageDevice_KernelCompletion
default 21:31:42.877693+1000    kernel  Found class: IOEventLink
default 21:31:42.877825+1000    kernel  Found class: IOThread
default 21:31:42.877907+1000    kernel  Found class: IOWorkGroup
default 21:31:42.879080+1000    kernel  Found class: AppleUserECMData
default 21:31:42.879131+1000    kernel  Found class: AppleUserECM
default 21:31:42.879205+1000    kernel  Found class: OSAction_AppleUserECM_TxPacketsAvailable
default 21:31:42.879251+1000    kernel  Found class: OSAction_AppleUserECM_RxPacketsAvailable
default 21:31:42.879327+1000    kernel  Found class: OSAction_AppleUserECM_TxComplete
default 21:31:42.879635+1000    kernel  Found class: OSAction_AppleUserECM_RxComplete
default 21:31:42.880292+1000    kernel  Found class: OSAction_AppleUserECM_InterruptReadComplete
default 21:31:42.880321+1000    kernel  Found class: OSAction_AppleUserECM_InterruptReadTimerOccurred
default 21:31:42.880343+1000    kernel  Found class: IOUserNetworkPacket
default 21:31:42.880350+1000    kernel  Found class: IOUserNetworkEthernet
default 21:31:42.880390+1000    kernel  Found class: OSAction_IOUserNetworkEthernet__RxSQDataAvailable
default 21:31:42.880403+1000    kernel  Found class: OSAction_IOUserNetworkEthernet__TxSQDataAvailable
default 21:31:42.880409+1000    kernel  Found class: OSAction_IOUserNetworkEthernet__DataAvailable
default 21:31:42.880414+1000    kernel  Found class: IOUserNetworkPacketBufferPool
default 21:31:42.880419+1000    kernel  Found class: IOUserNetworkPacketQueue
default 21:31:42.880422+1000    kernel  Found class: IOUserNetworkPacketPoller
default 21:31:42.880425+1000    kernel  Found class: OSAction_IOUserNetworkPacketPoller_TimerOccurred
default 21:31:42.880430+1000    kernel  Found class: IOUserNetworkTxSubmissionQueue
default 21:31:42.880435+1000    kernel  Found class: IOUserNetworkTxCompletionQueue
default 21:31:42.880439+1000    kernel  Found class: IOUserNetworkQueueSet
default 21:31:42.880445+1000    kernel  Found class: IOUserNetworkRxSubmissionQueue
default 21:31:42.880449+1000    kernel  Found class: IOUserNetworkRxCompletionQueue
default 21:31:42.880486+1000    kernel  Found class: IOUserNetworkLogicalLink
default 21:31:42.880491+1000    kernel  Found class: IOUserNetworkWLAN
default 21:31:42.880497+1000    kernel  Found class: IOUSBHostPipe
default 21:31:42.880502+1000    kernel  Found class: IOUSBHostDevice
default 21:31:42.880506+1000    kernel  Found class: IOUSBHostInterface
default 21:31:42.882055+1000    kernel  OnQueue SDK version 0x160500
default 21:31:42.883152+1000    kernel  no services left, exiting
default 21:31:42.883399+1000    kernel  DK: IOUserServer(com.apple.DriverKit.AppleUserECM.data-0x1000053f0)::terminate(AppleUserECMData-0x1000053f0) server exit before start()
default 21:31:42.883529+1000    kernel  DK: AppleUserECMData-0x1000053f0::start(IOUSBHostInterface-0x1000053ee) fail
default 21:31:42.886472+1000    contextstored   Restart preventer: <private>
default 21:31:43.056178+1000    kernel  com.apple.p2p: isInfraRealtimePacketThresholdAllowed allowed:1 option:32 threshold:50 noRegistrations:1 cachedPeerCount:0 fastDiscoveryInactive:1 fastDiscoveryOnSince:32734095
default 21:31:43.056219+1000    kernel  com.apple.p2p: currentInfraTrafficType:8087 checking if realtime upgrade required with inputPackets:0 outputPackets:0 packetThreshold:50
error   21:31:43.085110+1000    kernel  AppleUSBXHCIRequest: AppleUSBXHCIRequest::finish: transfer completed with status 0xe0005000
error   21:31:43.086055+1000    kernel  IOUSBHostDevice@08332000: IOUSBHostDevice::getDescriptorGated: type 0x03 index 2 length 2 completed with 0xe0005000 bytesTransferred 0 type 0x01
error   21:31:43.086185+1000    kernel  AppleUSBXHCIRequest: AppleUSBXHCIRequest::finish: transfer completed with status 0xe0005000
error   21:31:43.086973+1000    kernel  IOUSBHostDevice@08332000: IOUSBHostDevice::getDescriptorGated: type 0x03 index 2 length 2 completed with 0xe0005000 bytesTransferred 0 type 0x01
error   21:31:43.087095+1000    kernel  AppleUSBXHCIRequest: AppleUSBXHCIRequest::finish: transfer completed with status 0xe0005000
error   21:31:43.087908+1000    kernel  IOUSBHostDevice@08332000: IOUSBHostDevice::getDescriptorGated: type 0x03 index 2 length 2 completed with 0xe0005000 bytesTransferred 0 type 0x01
error   21:31:43.087925+1000    kernel  IOUSBHostDevice@08332000: IOUSBHostDevice::getDescriptorGated: type 0x03 index 2 length 2 completed with 0xe0005000 bytesTransferred 0 type 0x01
default 21:31:43.089976+1000    kernel    IOTimeSyncTimeSyncTimePort(0x9c760e45d22b0008): Other 0xe0034150
default 21:31:43.090075+1000    kernel    IOTimeSyncTimeSyncTimePort(0x9c760e45d22b0008): Other 0xe0034150
default 21:31:43.090954+1000    kernel    IOTimeSyncTimeSyncTimePort(0x9c760e45d22b0008): Other 0xe0034150
error   21:31:43.098866+1000    kernel  AppleUSBXHCIRequest: AppleUSBXHCIRequest::finish: transfer completed with status 0xe0005000
default 21:31:43.106508+1000    icdd               Device DB | Creating local devices
default 21:31:43.108072+1000    icdd               Device DB | Creating bonjour devices
default 21:31:43.108032+1000    kernel  Sandbox: icdd(3155) allow file-read-data /Library/Image Capture/Devices
default 21:31:43.108396+1000    icdd          =>  [Matching] | [ 0x00,0x00,0x00 ]
default 21:31:43.108439+1000    icdd                   Added | 0x100000d0 - [USB][     IOUSBHostDevice ] ( 0, 0, 0) @ 0x8332000 |
default 21:31:43.108555+1000    icdd              Autolaunch | 38353133-3833-3133-3933-333335313331 => (null)
default 21:31:43.108586+1000    icdd          =>  [Matching] | [ 0x0a,0x00,0x00 ]
default 21:31:43.108608+1000    icdd                Inferior | 0x100000d1 - [USB][     IOUSBHostDevice ] ( a, 0, 0) @ 0x8332000 |
default 21:31:43.108637+1000    icdd          =>  [Matching] | [ 0x02,0x02,0x01 ]
default 21:31:43.108678+1000    icdd                Inferior | 0x100000d3 - [USB][     IOUSBHostDevice ] ( 2, 2, 1) @ 0x8332000 |
default 21:31:43.108989+1000    icdd               --Local-- | [0000]
default 21:31:43.109009+1000    icdd             --Bonjour-- | [0000]

Addendum 2: to cause a failure, it is enough to launch Arduino IDE. In particular, if I plug a device in, use it from the command line (with avrdude), and then launch Arduino IDE, the device disappears from the bus in the manner described in this question.

0

You must log in to answer this question.

Browse other questions tagged .