Recently I found a strange issue on my z690 aorus elite ax ddr4 motherboard, with MacOS Monterey 12.6.2.
My bluetooth card is fenvi T919(bcm94360cd) and I confirm my usb mapping was absolutely correct.
I found that when I wake up from usb using usb keyboard or mouse, the bluetoothd process will crash. And The console will report a crash for bluetoothd. I have tried to clean install MacOS ventura 13.0, still crashed.
After further debug, I found some suspect logs:
monterey log(fully log in [monterey-2.log](https://github.com/dortania/bugtracker/files/10330726/monterey-2.log))
The HS11 is the back usb 2.0 x4 hub port, the HS12 is the built-in usb 2.0 connector, and the HS13 is the rgb fusion port.
After waking up, the IOUSBHostFamily driver reports that all usb ports are powering off, including the above usb ports.
It seems that when the IOUSBHostFamily driver was preparing to recovery, the BRCM20702 Hub, USB Camera and other devices host on the usb hub were be terminated because the upstream port was powered off, and bluetoothd reported an error because the bsd device /dev/cu.BLTH opened timeout. Then bluetoothd crashes and restarts, and bluetooth resumes.
But in fact, not only the usb hub will report a power off, all other ports will report too. The relevant logs are as follows:
monterey more port power offlog
```
2023-01-02 11:15:38.978496+0800 0xd984 Default 0x0 0 0 kernel: (IOUSBHostFamily) 003115.335042 HS01@14100000: AppleUSBHostPort::terminateDevice: destroying 0x2109/2817/03e3 (USB2.0 Hub ): port is powering off
2023-01-02 11:15:38.978541+0800 0xd993 Default 0x0 0 0 kernel: (IOUSBHostFamily) 003115.335086 SS01@14a00000: AppleUSBHostPort::terminateDevice: destroying 0x2109/0817/03e3 (USB3.0 Hub ): port is powering off
2023-01-02 11:15:38.978546+0800 0xd984 Default 0x0 0 0 kernel: (IOUSBHostFamily) 003115.335093 SS05@14e00000: AppleUSBHostPort::terminateDevice: destroying 0x0bda/9210/2001 (SSK Storage): port is powering off
2023-01-02 11:15:38.978549+0800 0xd98d Default 0x0 0 0 kernel: (IOUSBHostFamily) 003115.335093 SS04@14d00000: AppleUSBHostPort::terminateDevice: destroying 0x0781/5591/0100 (Ultra USB 3.0): port is powering off
2023-01-02 11:15:38.978557+0800 0xd961 Default 0x0 0 0 kernel: (IOUSBHostFamily) 003115.335101 HS04@14200000: AppleUSBHostPort::terminateDevice: destroying 0x1a81/203e/0116 (USB Keyboard): port is powering off
2023-01-02 11:15:38.978712+0800 0xd99d Default 0x0 0 0 kernel: (IOUSBHostFamily) 003115.335258 HS11@14700000: AppleUSBHostPort::terminateDevice: destroying 0x05e3/0608/6090 (USB2.0 Hub): port is powering off
2023-01-02 11:15:38.978740+0800 0xd99e Default 0x0 0 0 kernel: (IOUSBHostFamily) 003115.335288 HS12@14800000: AppleUSBHostPort::terminateDevice: destroying 0x05e3/0608/6090 (USB2.0 Hub): port is powering off
2023-01-02 11:15:38.978764+0800 0xd99f Default 0x0 0 0 kernel: (IOUSBHostFamily) 003115.335311 HS13@14900000: AppleUSBHostPort::terminateDevice: destroying 0x048d/5702/0001 (ITE Device): port is powering off
2023-01-02 11:15:39.009869+0800 0xda15 Default 0x0 0 0 kernel: (IOUSBHostFamily) 003115.366414 AppleUSB20HubPort@14720000: AppleUSBHostPort::terminateDevice: destroying 0x1532/0085/0200 (Razer Basilisk V2): upstream hub is terminating
2023-01-02 11:15:39.010168+0800 0xda20 Default 0x0 0 0 kernel: (IOUSBHostFamily) 003115.366714 AppleUSB20HubPort@14833000: AppleUSBHostPort::terminateDevice: destroying 0x05ac/828d/0150 (Bluetooth USB Host Controller): upstream hub is terminating
2023-01-02 11:15:39.297471+0800 0xda1d Default 0x0 0 0 kernel: (IOUSBHostFamily) 003115.654017 AppleUSB20HubPort@14830000: AppleUSBHostPort::terminateDevice: destroying 0x0a5c/4500/0100 (BRCM20702 Hub): upstream hub is terminating
2023-01-02 11:15:39.342823+0800 0xda1d Default 0x0 0 0 kernel: (IOUSBHostFamily) 003115.699359 AppleUSB20HubPort@14820000: AppleUSBHostPort::terminateDevice: destroying 0x1415/2000/0200 (USB Camera-B4.09.24.1): upstream hub is terminating
2023-01-02 11:15:39.342938+0800 0xda13 Default 0x0 0 0 kernel: (IOUSBHostFamily) 003115.699483 AppleUSB20HubPort@14810000: AppleUSBHostPort::terminateDevice: destroying 0x045e/028e/0116 (Controller): upstream hub is terminating
...
2023-01-01 15:30:42.354831+0800 0x7f56 Default 0x0 507 0 cloudpaird: (CoreUtils) [com.apple.bluetooth:BTServicesDaemon] Bluetoothd has crashed / Restarted
```
The back usb type c (SS01, HS01), the back usb 3.1 ports (SS04, SS05), and the back usb 3.0 port 2.0 port (HS04), are all report powering off.
The strange thing is that the devices that are directly plugged into usb ports, such as the USB Keyboard plugged into a usb 2.0 port (HS04), do not report be terminated. This may be because AppleUSB20HubPort@14720000: AppleUSBHostPort::terminateDevice is the code for the usb hub. The usb device driectly connected to the usb port, it won't go to there even the usb port is powered off.
In order to verify this , I inserted another usb type-c hub to the back type-c port (HS01, SS02), and then inserted a usb2.0 keyboard (USB Keyboard), a usb3.0 disk (Ultra USB 3.0) to the typc-c hub, the result is that the device connected under the typc-c hub is also terminated after waking up. So it means that even I plug an extra usb hub into the usb port(not board usb hub), the usb hub will still reported as power off.
usb type-c hub port power off log
```
2023-01-02 11:50:59.017856+0800 0x140c4 Default 0x0 0 0 kernel: (IOUSBHostFamily) 005213.599758 HS01@14100000: AppleUSBHostPort::terminateDevice: destroying 0x2109/2817/03e3 (USB2.0 Hub ): port is powering off
2023-01-02 11:50:59.018036+0800 0x140c2 Default 0x0 0 0 kernel: (IOUSBHostFamily) 005213.599937 SS01@14a00000: AppleUSBHostPort::terminateDevice: destroying 0x2109/0817/03e3 (USB3.0 Hub ): port is powering off
2023-01-02 11:50:59.018145+0800 0x140cb Default 0x0 0 0 kernel: (IOUSBHostFamily) 005213.600049 HS11@14700000: AppleUSBHostPort::terminateDevice: destroying 0x05e3/0608/6090 (USB2.0 Hub): port is powering off
2023-01-02 11:50:59.018150+0800 0x140cf Default 0x0 0 0 kernel: (IOUSBHostFamily) 005213.600052 HS12@14800000: AppleUSBHostPort::terminateDevice: destroying 0x05e3/0608/6090 (USB2.0 Hub): port is powering off
2023-01-02 11:50:59.018157+0800 0x140c7 Default 0x0 0 0 kernel: (IOUSBHostFamily) 005213.600058 HS13@14900000: AppleUSBHostPort::terminateDevice: destroying 0x048d/5702/0001 (ITE Device): port is powering off
2023-01-02 11:50:59.020807+0800 0x1406b Default 0x0 0 0 kernel: (IOUSBHostFamily) 005213.602710 AppleUSB20HubPort@14720000: AppleUSBHostPort::terminateDevice: destroying 0x1532/0085/0200 (Razer Basilisk V2): port is powering off
2023-01-02 11:50:59.029704+0800 0x14107 Default 0x0 0 0 kernel: (IOUSBHostFamily) 005213.611607 AppleUSB30HubPort@14a30000: AppleUSBHostPort::terminateDevice: destroying 0x0781/5591/0100 (Ultra USB 3.0): upstream hub is terminating
2023-01-02 11:50:59.031715+0800 0x140e4 Default 0x0 0 0 kernel: (IOUSBHostFamily) 005213.613616 AppleUSB20HubPort@14140000: AppleUSBHostPort::terminateDevice: destroying 0x1a81/203e/0116 (USB Keyboard): upstream hub is terminating
```
Meanwhile, here are some more logs from Big Sur.
big sur log(full log in [bigsur.log](https://github.com/dortania/bugtracker/files/10330764/bigsur.log))
The big sur does not printed any log related to device terminated, and usb devices enumerated success after waking up.
I simply do some reverse engineering on it, the string forcing power state to on does not exist in Monterey's IOUSBFamily.kext.
I guess:
There is something wrong with the usb controller of the motherboard after sleep, and Apple removed the relevant code on Monterey that forced considered the usb port to still power on, causing the usb port to be considered to be powered off. Therefore, when a usb hub is connected to a usb port, all devices on the usb hub will be terminated after the usb port powered off. Then the bluetoothd opens the bsd device /dev/cu.BLTH timeout, and then the process crashes, and then the cloudpaird daemon restart the bluetoothd.
But the most strange thing is, why I press the power button to wake up, sometimes bluetoothd log continuously in loop and consumes a lot of cpu. I think this may be caused by different reasons for wake up. After 11.0, it needs to press twice to wake up from a usb keyboard or usb mouse, but the power button only needs to be pressed once to wake up. After simply looking at the log, the usb device on the hub is still terminated when wake up from power button, there is no difference.
bluetoothd log continuously in loop
```
2023-01-02 13:11:35.209382+0800 0x1f9fe Default 0x0 8243 0 bluetoothd: [com.apple.bluetooth:Stack.LE] Address rotation in progress:NO
2023-01-02 13:11:35.209400+0800 0x1f9fe Error 0x0 8243 0 bluetoothd: [com.apple.bluetooth:Stack.HCI] OI_HCIIfc_SendHciCommand failed (status=1205)
2023-01-02 13:11:35.209419+0800 0x1f9fe Error 0x0 8243 0 bluetoothd: [com.apple.bluetooth:Stack.HCI] HCI expected event 14 with opcode OI_DHCI_VENDOR_OPCODE (0x0000FD4A) error, reason is STATUS 1205
2023-01-02 13:11:35.209438+0800 0x1f9fe Error 0x0 8243 0 bluetoothd: [com.apple.bluetooth:Stack.VSC] status 1205, hlCb 0x00A18974
2023-01-02 13:11:35.209458+0800 0x1f9fe Error 0x0 8243 0 bluetoothd: [com.apple.bluetooth:Stack.LE] setMultipleAdvParamsCompleteCb Could not start advertising : STATUS 1205 (status=65535)
2023-01-02 13:11:35.209477+0800 0x1f9fe Error 0x0 8243 0 bluetoothd: [com.apple.bluetooth:Stack.VSC] VSC state 1, can not create command
2023-01-02 13:11:35.209496+0800 0x1f9fe Error 0x0 8243 0 bluetoothd: [com.apple.bluetooth:Stack.VSC] VSC failed STATUS 3600
2023-01-02 13:11:35.209515+0800 0x1f9fe Error 0x0 8243 0 bluetoothd: [com.apple.bluetooth:Stack.LE] Could not stop the LE advertising BT_VSC_SetMultipleAdvInstanceEnable returned STATUS 3600 (status=65535)
2023-01-02 13:11:35.209533+0800 0x1f9fe Error 0x0 8243 0 bluetoothd: [com.apple.bluetooth:Stack.VSC] VSC state 1, can not create command
2023-01-02 13:11:35.209551+0800 0x1f9fe Error 0x0 8243 0 bluetoothd: [com.apple.bluetooth:Stack.VSC] VSC failed STATUS 3600
2023-01-02 13:11:35.209570+0800 0x1f9fe Error 0x0 8243 0 bluetoothd: [com.apple.bluetooth:Stack.LE] Could not stop the LE advertising BT_VSC_SetMultipleAdvInstanceEnable returned STATUS 3600 (status=65535)
2023-01-02 13:11:35.209588+0800 0x1f9fe Error 0x0 8243 0 bluetoothd: [com.apple.bluetooth:Stack.VSC] VSC state 1, can not create command
2023-01-02 13:11:35.209608+0800 0x1f9fe Error 0x0 8243 0 bluetoothd: [com.apple.bluetooth:Stack.VSC] VSC failed STATUS 3600
2023-01-02 13:11:35.209627+0800 0x1f9fe Error 0x0 8243 0 bluetoothd: [com.apple.bluetooth:Stack.LE] Could not stop the LE advertising BT_VSC_SetMultipleAdvInstanceEnable returned STATUS 3600 (status=65535)
2023-01-02 13:11:35.209646+0800 0x1f9fe Error 0x0 8243 0 bluetoothd: [com.apple.bluetooth:Stack.VSC] VSC state 1, can not create command
2023-01-02 13:11:35.209663+0800 0x1f9fe Error 0x0 8243 0 bluetoothd: [com.apple.bluetooth:Stack.VSC] VSC failed STATUS 3600
2023-01-02 13:11:35.209681+0800 0x1f9fe Error 0x0 8243 0 bluetoothd: [com.apple.bluetooth:Stack.LE] Could not stop the LE advertising BT_VSC_SetMultipleAdvInstanceEnable returned STATUS 3600 (status=65535)
2023-01-02 13:11:35.209699+0800 0x1f9fe Default 0x0 8243 0 bluetoothd: [com.apple.bluetooth:Stack.LE] Address rotation in progress:NO
2023-01-02 13:11:35.209718+0800 0x1f9fe Error 0x0 8243 0 bluetoothd: [com.apple.bluetooth:Stack.LE] failed to start advertising instance 0 with status 1205 . Abort ! Abort ! Abort !
```
I want to fix this issue, but I have no idea. So I hope you can help me.
If someone has same issue, please fell free to let me know.
Hi all, happly new year.
Recently I found a strange issue on my z690 aorus elite ax ddr4 motherboard, with MacOS Monterey 12.6.2.
My bluetooth card is fenvi T919(bcm94360cd) and I confirm my usb mapping was absolutely correct.
I found that when I wake up from usb using usb keyboard or mouse, the bluetoothd process will crash. And The console will report a crash for bluetoothd. I have tried to clean install MacOS ventura 13.0, still crashed.
After further debug, I found some suspect logs:
monterey log(fully log in [monterey-2.log](https://github.com/dortania/bugtracker/files/10330726/monterey-2.log))
``` ... 2023-01-01 15:30:26.019335+0800 0x7b4f Default 0x0 0 0 kernel: (IOUSBHostFamily) 000644.572511 HS11@14700000: AppleUSBHostPort::terminateDevice: destroying 0x05e3/0608/6090 (USB2.0 Hub): port is powering off ... 2023-01-01 15:30:26.019385+0800 0x7b50 Default 0x0 0 0 kernel: (IOUSBHostFamily) 000644.572563 HS12@14800000: AppleUSBHostPort::terminateDevice: destroying 0x05e3/0608/6090 (USB2.0 Hub): port is powering off 2023-01-01 15:30:26.019426+0800 0x7b51 Default 0x0 0 0 kernel: (IOUSBHostFamily) 000644.572603 HS13@14900000: AppleUSBHostPort::terminateDevice: destroying 0x048d/5702/0001 (ITE Device): port is powering off ... 2023-01-01 15:30:26.048082+0800 0x7aec Default 0x0 0 0 kernel: (IOUSBHostFamily) 000644.601259 XHCI@14000000: AppleUSBHostController::hardwareExceptionThreadCallGated: 0x00000100 ... 2023-01-01 15:30:26.048399+0800 0x7aec Default 0x0 0 0 kernel: (IOUSBHostFamily) 000644.601577 XHCI@14000000: AppleUSBHostController::hardwareExceptionThreadCallGated: attempting recovery ... 2023-01-01 15:30:26.100272+0800 0x7b93 Default 0x0 0 0 kernel: (IOUSBHostFamily) 000644.653448 AppleUSB20HubPort@14833000: AppleUSBHostPort::terminateDevice: destroying 0x05ac/828d/0150 (Bluetooth USB Host Controller): upstream hub is terminating 2023-01-01 15:30:26.100671+0800 0x7bd1 Default 0x0 0 0 kernel: (IOUSBHostFamily) 000644.653847 AppleUSB20HubPort@14830000: AppleUSBHostPort::terminateDevice: destroying 0x0a5c/4500/0100 (BRCM20702 Hub): upstream hub is terminating ... 2023-01-01 15:30:26.122630+0800 0x7bdc Default 0x0 0 0 kernel: (IOUSBHostFamily) 000644.675805 AppleUSB20HubPort@14820000: AppleUSBHostPort::terminateDevice: destroying 0x1415/2000/0200 (USB Camera-B4.09.24.1): upstream hub is terminating ... 2023-01-01 15:30:26.291615+0800 0x7bd1 Default 0x0 0 0 kernel: (IOUSBHostFamily) 000644.844790 AppleUSB20HubPort@14810000: AppleUSBHostPort::terminateDevice: destroying 0x045e/028e/0116 (Controller): upstream hub is terminating ... 2023-01-01 15:30:26.292412+0800 0x7bd1 Default 0x0 0 0 kernel: (IOUSBHostFamily) 000644.845590 AppleUSB20HubPort@14710000: AppleUSBHostPort::terminateDevice: destroying 0x1a81/203e/0116 (USB Keyboard): upstream hub is terminating 2023-01-01 15:30:26.292445+0800 0x7bd2 Default 0x0 0 0 kernel: (IOUSBHostFamily) 000644.845623 AppleUSB20HubPort@14720000: AppleUSBHostPort::terminateDevice: destroying 0x1532/0085/0200 (Razer Basilisk V2): upstream hub is terminating ... 2023-01-01 15:30:26.299126+0800 0x26c Default 0x0 0 0 kernel: (IOUSBHostFamily) 000644.852304 HS13@14900000: AppleUSBHostPort::enumerateDeviceComplete_block_invoke: enumerated 0x048d/5702/0001 (ITE Device) at 12 Mbps ... 2023-01-01 15:30:26.365753+0800 0x26c Default 0x0 0 0 kernel: (IOUSBHostFamily) 000644.918930 HS11@14700000: AppleUSBHostPort::enumerateDeviceComplete_block_invoke: enumerated 0x05e3/0608/6090 (USB2.0 Hub) at 480 Mbps ... 2023-01-01 15:30:26.435431+0800 0x26c Default 0x0 0 0 kernel: (IOUSBHostFamily) 000644.988610 HS12@14800000: AppleUSBHostPort::enumerateDeviceComplete_block_invoke: enumerated 0x05e3/0608/6090 (USB2.0 Hub) at 480 Mbps ... 2023-01-01 15:30:26.560399+0800 0x18fe Default 0x0 0 0 kernel: (IOUSBHostFamily) 000645.113577 Google Chrome@(null): AppleUSBHostUserClient::openGated: could not open provider USB2.0 Hub. provider already opened for exclusive access by a kernel client 2023-01-01 15:30:26.560640+0800 0xedf Default 0x0 0 0 kernel: (IOUSBHostFamily) 000645.113818 Android File Tra@(null): AppleUSBHostUserClient::openGated: could not open provider ITE Device. provider already opened for exclusive access by Google Chrome 2023-01-01 15:30:26.560717+0800 0x18fe Default 0x0 0 0 kernel: (IOUSBHostFamily) 000645.113895 Google Chrome@(null): AppleUSBHostUserClient::openGated: could not open provider USB2.0 Hub. provider already opened for exclusive access by a kernel client ... 2023-01-01 15:30:26.561150+0800 0xedf Default 0x0 0 0 kernel: (IOUSBHostFamily) 000645.114327 Android File Tra@(null): AppleUSBHostUserClient::openGated: could not open provider USB2.0 Hub. provider already opened for exclusive access by a kernel client 2023-01-01 15:30:26.561372+0800 0xedf Default 0x0 0 0 kernel: (IOUSBHostFamily) 000645.114550 Android File Tra@(null): AppleUSBHostUserClient::openGated: could not open provider USB2.0 Hub. provider already opened for exclusive access by a kernel client ... 2023-01-01 15:30:26.620944+0800 0x26c Default 0x0 0 0 kernel: (IOUSBHostFamily) 000645.174115 AppleUSB20HubPort@14710000: AppleUSBHostPort::enumerateDeviceComplete_block_invoke: enumerated 0x1a81/203e/0116 (USB Keyboard) at 12 Mbps ... 2023-01-01 15:30:26.665565+0800 0x26c Default 0x0 0 0 kernel: (IOUSBHostFamily) 000645.218741 AppleUSB20HubPort@14720000: AppleUSBHostPort::enumerateDeviceComplete_block_invoke: enumerated 0x1532/0085/0200 (Razer Basilisk V2) at 12 Mbps ... 2023-01-01 15:30:26.708597+0800 0x26c Default 0x0 0 0 kernel: (IOUSBHostFamily) 000645.261775 AppleUSB20HubPort@14810000: AppleUSBHostPort::enumerateDeviceComplete_block_invoke: enumerated 0x045e/028e/0116 (Controller) at 12 Mbps ... 2023-01-01 15:30:26.752462+0800 0x26c Default 0x0 0 0 kernel: (IOUSBHostFamily) 000645.305641 AppleUSB20HubPort@14820000: AppleUSBHostPort::enumerateDeviceComplete_block_invoke: enumerated 0x1415/2000/0200 (USB Camera-B4.09.24.1) at 480 Mbps ... 2023-01-01 15:30:26.802207+0800 0x26c Default 0x0 0 0 kernel: (IOUSBHostFamily) 000645.355378 AppleUSB20HubPort@14830000: AppleUSBHostPort::enumerateDeviceComplete_block_invoke: enumerated 0x0a5c/4500/0100 (BRCM20702 Hub) at 12 Mbps 2023-01-01 15:30:26.806799+0800 0x7c6d Default 0x0 0 0 kernel: (IOUSBHostFamily) 000645.359978 Android File Tra@(null): AppleUSBHostUserClient::start: missing entitlement com.apple.bluetooth.control 2023-01-01 15:30:26.821204+0800 0x369 Default 0x0 0 0 kernel: (IOUSBHostFamily) 000645.374376 systemstats@(null): AppleUSBHostUserClient::start: missing entitlement com.apple.bluetooth.control 2023-01-01 15:30:26.874700+0800 0x1c6b Default 0x0 0 0 kernel: (IOUSBHostFamily) 000645.427878 vmware-usbarbitr@(null): AppleUSBHostUserClient::start: missing entitlement com.apple.bluetooth.control 2023-01-01 15:30:26.882952+0800 0x18fe Default 0x0 0 0 kernel: (IOUSBHostFamily) 000645.436130 Google Chrome@(null): AppleUSBHostUserClient::start: missing entitlement com.apple.bluetooth.control ... 2023-01-01 15:30:26.969477+0800 0x4d6 Default 0x0 0 0 kernel: (IOUSBHostFamily) 000645.522655 airportd@(null): AppleUSBHostUserClient::start: missing entitlement com.apple.bluetooth.control ... 2023-01-01 15:30:27.056576+0800 0x26c Default 0x0 0 0 kernel: (IOUSBHostFamily) 000645.609753 AppleUSB20HubPort@14833000: AppleUSBHostPort::enumerateDeviceComplete_block_invoke: enumerated 0x05ac/828d/0150 (Bluetooth USB Host Controller) at 12 Mbps 2023-01-01 15:30:27.057780+0800 0x7c6d Default 0x0 0 0 kernel: (IOUSBHostFamily) 000645.610958 Android File Tra@(null): AppleUSBHostUserClient::start: missing entitlement com.apple.bluetooth.control ... 2023-01-01 15:30:27.307559+0800 0x4d6 Default 0x0 0 0 kernel: (IOUSBHostFamily) 000645.860736 airportd@(null): AppleUSBHostUserClient::start: missing entitlement com.apple.bluetooth.control 2023-01-01 15:30:27.307614+0800 0x1c6b Default 0x0 0 0 kernel: (IOUSBHostFamily) 000645.860792 vmware-usbarbitr@(null): AppleUSBHostUserClient::start: missing entitlement com.apple.bluetooth.control 2023-01-01 15:30:27.307668+0800 0x18fe Default 0x0 0 0 kernel: (IOUSBHostFamily) 000645.860846 Google Chrome@(null): AppleUSBHostUserClient::start: missing entitlement com.apple.bluetooth.control 2023-01-01 15:30:27.307698+0800 0x369 Default 0x0 0 0 kernel: (IOUSBHostFamily) 000645.860877 systemstats@(null): AppleUSBHostUserClient::start: missing entitlement com.apple.bluetooth.control ... 2023-01-01 15:30:27.644596+0800 0xedf Default 0x0 0 0 kernel: (IOUSBHostFamily) 000646.197774 Android File Tra@(null): AppleUSBHostUserClient::start: missing entitlement com.apple.bluetooth.control 2023-01-01 15:30:27.644726+0800 0xedf Default 0x0 0 0 kernel: (IOUSBHostFamily) 000646.197906 Android File Tra@(null): AppleUSBHostUserClient::start: missing entitlement com.apple.bluetooth.control ... 2023-01-01 15:30:42.350515+0800 0x7c03 Error 0x0 3275 0 bluetoothd: [com.apple.bluetooth:Stack.TRANSPORT] UART open(/dev/cu.BLTH) port failed to appear after 15 seconds (error = Operation timed out) (status=65535) 2023-01-01 15:30:42.350584+0800 0x7c03 Default 0x0 3275 0 bluetoothd: [com.apple.bluetooth:Stack.UNKNOWN] Failed to initialize driver POSIX 2023-01-01 15:30:42.350615+0800 0x7c03 Default 0x0 3275 0 bluetoothd: [com.apple.bluetooth:Stack.UNKNOWN] Failed to initialize transport H4BC 2023-01-01 15:30:42.350641+0800 0x7c03 Default 0x0 3275 0 bluetoothd: [com.apple.bluetooth:Stack.UNKNOWN] Transport layer initialization failed 2023-01-01 15:30:42.350664+0800 0x7c03 Default 0x0 3275 0 bluetoothd: [com.apple.bluetooth:Stack.UNKNOWN] Wake Up Display 2023-01-01 15:30:42.352603+0800 0x7c03 Default 0x0 3275 0 bluetoothd: [com.apple.bluetooth:PacketLogger.HCI] Terminate sniff 2023-01-01 15:30:42.352802+0800 0x7c03 Default 0x0 3275 0 bluetoothd: [com.apple.bluetooth:PacketLogger.HCI] Sniff terminated 2023-01-01 15:30:42.352871+0800 0x7c03 Error 0x0 3275 0 bluetoothd: [com.apple.bluetooth:CBCrash] Bluetooth fatal error - crashing { build=release, reason=1201 } ... ```
The HS11 is the back usb 2.0 x4 hub port, the HS12 is the built-in usb 2.0 connector, and the HS13 is the rgb fusion port. After waking up, the IOUSBHostFamily driver reports that all usb ports are powering off, including the above usb ports.
It seems that when the IOUSBHostFamily driver was preparing to recovery, the BRCM20702 Hub, USB Camera and other devices host on the usb hub were be terminated because the upstream port was powered off, and bluetoothd reported an error because the bsd device
/dev/cu.BLTH
opened timeout. Then bluetoothd crashes and restarts, and bluetooth resumes.But in fact, not only the usb hub will report a power off, all other ports will report too. The relevant logs are as follows:
monterey more port power offlog
``` 2023-01-02 11:15:38.978496+0800 0xd984 Default 0x0 0 0 kernel: (IOUSBHostFamily) 003115.335042 HS01@14100000: AppleUSBHostPort::terminateDevice: destroying 0x2109/2817/03e3 (USB2.0 Hub ): port is powering off 2023-01-02 11:15:38.978541+0800 0xd993 Default 0x0 0 0 kernel: (IOUSBHostFamily) 003115.335086 SS01@14a00000: AppleUSBHostPort::terminateDevice: destroying 0x2109/0817/03e3 (USB3.0 Hub ): port is powering off 2023-01-02 11:15:38.978546+0800 0xd984 Default 0x0 0 0 kernel: (IOUSBHostFamily) 003115.335093 SS05@14e00000: AppleUSBHostPort::terminateDevice: destroying 0x0bda/9210/2001 (SSK Storage): port is powering off 2023-01-02 11:15:38.978549+0800 0xd98d Default 0x0 0 0 kernel: (IOUSBHostFamily) 003115.335093 SS04@14d00000: AppleUSBHostPort::terminateDevice: destroying 0x0781/5591/0100 (Ultra USB 3.0): port is powering off 2023-01-02 11:15:38.978557+0800 0xd961 Default 0x0 0 0 kernel: (IOUSBHostFamily) 003115.335101 HS04@14200000: AppleUSBHostPort::terminateDevice: destroying 0x1a81/203e/0116 (USB Keyboard): port is powering off 2023-01-02 11:15:38.978712+0800 0xd99d Default 0x0 0 0 kernel: (IOUSBHostFamily) 003115.335258 HS11@14700000: AppleUSBHostPort::terminateDevice: destroying 0x05e3/0608/6090 (USB2.0 Hub): port is powering off 2023-01-02 11:15:38.978740+0800 0xd99e Default 0x0 0 0 kernel: (IOUSBHostFamily) 003115.335288 HS12@14800000: AppleUSBHostPort::terminateDevice: destroying 0x05e3/0608/6090 (USB2.0 Hub): port is powering off 2023-01-02 11:15:38.978764+0800 0xd99f Default 0x0 0 0 kernel: (IOUSBHostFamily) 003115.335311 HS13@14900000: AppleUSBHostPort::terminateDevice: destroying 0x048d/5702/0001 (ITE Device): port is powering off 2023-01-02 11:15:39.009869+0800 0xda15 Default 0x0 0 0 kernel: (IOUSBHostFamily) 003115.366414 AppleUSB20HubPort@14720000: AppleUSBHostPort::terminateDevice: destroying 0x1532/0085/0200 (Razer Basilisk V2): upstream hub is terminating 2023-01-02 11:15:39.010168+0800 0xda20 Default 0x0 0 0 kernel: (IOUSBHostFamily) 003115.366714 AppleUSB20HubPort@14833000: AppleUSBHostPort::terminateDevice: destroying 0x05ac/828d/0150 (Bluetooth USB Host Controller): upstream hub is terminating 2023-01-02 11:15:39.297471+0800 0xda1d Default 0x0 0 0 kernel: (IOUSBHostFamily) 003115.654017 AppleUSB20HubPort@14830000: AppleUSBHostPort::terminateDevice: destroying 0x0a5c/4500/0100 (BRCM20702 Hub): upstream hub is terminating 2023-01-02 11:15:39.342823+0800 0xda1d Default 0x0 0 0 kernel: (IOUSBHostFamily) 003115.699359 AppleUSB20HubPort@14820000: AppleUSBHostPort::terminateDevice: destroying 0x1415/2000/0200 (USB Camera-B4.09.24.1): upstream hub is terminating 2023-01-02 11:15:39.342938+0800 0xda13 Default 0x0 0 0 kernel: (IOUSBHostFamily) 003115.699483 AppleUSB20HubPort@14810000: AppleUSBHostPort::terminateDevice: destroying 0x045e/028e/0116 (Controller): upstream hub is terminating ... 2023-01-01 15:30:42.354831+0800 0x7f56 Default 0x0 507 0 cloudpaird: (CoreUtils) [com.apple.bluetooth:BTServicesDaemon] Bluetoothd has crashed / Restarted ```
The back usb type c (SS01, HS01), the back usb 3.1 ports (SS04, SS05), and the back usb 3.0 port 2.0 port (HS04), are all report powering off.
The strange thing is that the devices that are directly plugged into usb ports, such as the USB Keyboard plugged into a usb 2.0 port (HS04), do not report be terminated. This may be because AppleUSB20HubPort@14720000: AppleUSBHostPort::terminateDevice is the code for the usb hub. The usb device driectly connected to the usb port, it won't go to there even the usb port is powered off.
In order to verify this , I inserted another usb type-c hub to the back type-c port (HS01, SS02), and then inserted a usb2.0 keyboard (USB Keyboard), a usb3.0 disk (Ultra USB 3.0) to the typc-c hub, the result is that the device connected under the typc-c hub is also terminated after waking up. So it means that even I plug an extra usb hub into the usb port(not board usb hub), the usb hub will still reported as power off.
usb type-c hub port power off log
``` 2023-01-02 11:50:59.017856+0800 0x140c4 Default 0x0 0 0 kernel: (IOUSBHostFamily) 005213.599758 HS01@14100000: AppleUSBHostPort::terminateDevice: destroying 0x2109/2817/03e3 (USB2.0 Hub ): port is powering off 2023-01-02 11:50:59.018036+0800 0x140c2 Default 0x0 0 0 kernel: (IOUSBHostFamily) 005213.599937 SS01@14a00000: AppleUSBHostPort::terminateDevice: destroying 0x2109/0817/03e3 (USB3.0 Hub ): port is powering off 2023-01-02 11:50:59.018145+0800 0x140cb Default 0x0 0 0 kernel: (IOUSBHostFamily) 005213.600049 HS11@14700000: AppleUSBHostPort::terminateDevice: destroying 0x05e3/0608/6090 (USB2.0 Hub): port is powering off 2023-01-02 11:50:59.018150+0800 0x140cf Default 0x0 0 0 kernel: (IOUSBHostFamily) 005213.600052 HS12@14800000: AppleUSBHostPort::terminateDevice: destroying 0x05e3/0608/6090 (USB2.0 Hub): port is powering off 2023-01-02 11:50:59.018157+0800 0x140c7 Default 0x0 0 0 kernel: (IOUSBHostFamily) 005213.600058 HS13@14900000: AppleUSBHostPort::terminateDevice: destroying 0x048d/5702/0001 (ITE Device): port is powering off 2023-01-02 11:50:59.020807+0800 0x1406b Default 0x0 0 0 kernel: (IOUSBHostFamily) 005213.602710 AppleUSB20HubPort@14720000: AppleUSBHostPort::terminateDevice: destroying 0x1532/0085/0200 (Razer Basilisk V2): port is powering off 2023-01-02 11:50:59.029704+0800 0x14107 Default 0x0 0 0 kernel: (IOUSBHostFamily) 005213.611607 AppleUSB30HubPort@14a30000: AppleUSBHostPort::terminateDevice: destroying 0x0781/5591/0100 (Ultra USB 3.0): upstream hub is terminating 2023-01-02 11:50:59.031715+0800 0x140e4 Default 0x0 0 0 kernel: (IOUSBHostFamily) 005213.613616 AppleUSB20HubPort@14140000: AppleUSBHostPort::terminateDevice: destroying 0x1a81/203e/0116 (USB Keyboard): upstream hub is terminating ```
Meanwhile, here are some more logs from Big Sur.
big sur log(full log in [bigsur.log](https://github.com/dortania/bugtracker/files/10330764/bigsur.log))
``` 2023-01-01 16:47:49.017151+0800 0x291d Default 0x0 0 0 kernel: (IOUSBHostFamily) 000435.390898 XHCI@14000000: AppleUSBHostController::hardwareExceptionThreadCallGated: 0x00000100 ... 2023-01-01 16:47:49.044643+0800 0x291d Default 0x0 0 0 kernel: (IOUSBHostFamily) 000435.418392 XHCI@14000000: AppleUSBHostController::hardwareExceptionThreadCallGated: attempting recovery, forcing power state to on ... 2023-01-01 16:47:49.295509+0800 0x1a5b Default 0x0 0 0 kernel: (IOUSBHostFamily) 000435.669257 HS13@14900000: AppleUSBHostPort::enumerateDeviceComplete_block_invoke: enumerated 0x048d/5702/0001 (ITE Device) ... 2023-01-01 16:47:49.317261+0800 0x1a5b Default 0x0 0 0 kernel: (IOUSBHostFamily) 000435.691010 HS11@14700000: AppleUSBHostPort::enumerateDeviceComplete_block_invoke: enumerated 0x05e3/0608/6090 (USB2.0 Hub) ... 2023-01-01 16:47:49.392479+0800 0x1a5b Default 0x0 0 0 kernel: (IOUSBHostFamily) 000435.766226 HS12@14800000: AppleUSBHostPort::enumerateDeviceComplete_block_invoke: enumerated 0x05e3/0608/6090 (USB2.0 Hub) ... 2023-01-01 16:47:49.570937+0800 0x1a5b Default 0x0 0 0 kernel: (IOUSBHostFamily) 000435.944686 AppleUSB20HubPort@14710000: AppleUSBHostPort::enumerateDeviceComplete_block_invoke: enumerated 0x1a81/203e/0116 (USB Keyboard) ... 2023-01-01 16:47:49.617412+0800 0x1a5b Default 0x0 0 0 kernel: (IOUSBHostFamily) 000435.991160 AppleUSB20HubPort@14720000: AppleUSBHostPort::enumerateDeviceComplete_block_invoke: enumerated 0x1532/0085/0200 (Razer Basilisk V2) ... 2023-01-01 16:47:49.657865+0800 0x1a5b Default 0x0 0 0 kernel: (IOUSBHostFamily) 000436.031613 AppleUSB20HubPort@14810000: AppleUSBHostPort::enumerateDeviceComplete_block_invoke: enumerated 0x045e/028e/0116 (Controller) ... 2023-01-01 16:47:49.698403+0800 0x1a5b Default 0x0 0 0 kernel: (IOUSBHostFamily) 000436.072151 AppleUSB20HubPort@14820000: AppleUSBHostPort::enumerateDeviceComplete_block_invoke: enumerated 0x1415/2000/0200 (USB Camera-B4.09.24.1) ... 2023-01-01 16:47:49.749106+0800 0x1a5b Default 0x0 0 0 kernel: (IOUSBHostFamily) 000436.122854 AppleUSB20HubPort@14830000: AppleUSBHostPort::enumerateDeviceComplete_block_invoke: enumerated 0x0a5c/4500/0100 (BRCM20702 Hub) ... 2023-01-01 16:47:50.000451+0800 0x1a5b Default 0x0 0 0 kernel: (IOUSBHostFamily) 000436.374199 AppleUSB20HubPort@14833000: AppleUSBHostPort::enumerateDeviceComplete_block_invoke: enumerated 0x05ac/828d/0150 (Bluetooth USB Host Controller) ```
The big sur does not printed any log related to device terminated, and usb devices enumerated success after waking up.
I simply do some reverse engineering on it, the string
forcing power state to on
does not exist in Monterey's IOUSBFamily.kext.I guess: There is something wrong with the usb controller of the motherboard after sleep, and Apple removed the relevant code on Monterey that forced considered the usb port to still power on, causing the usb port to be considered to be powered off. Therefore, when a usb hub is connected to a usb port, all devices on the usb hub will be terminated after the usb port powered off. Then the bluetoothd opens the bsd device
/dev/cu.BLTH
timeout, and then the process crashes, and then the cloudpaird daemon restart the bluetoothd.But the most strange thing is, why I press the power button to wake up, sometimes bluetoothd log continuously in loop and consumes a lot of cpu. I think this may be caused by different reasons for wake up. After 11.0, it needs to press twice to wake up from a usb keyboard or usb mouse, but the power button only needs to be pressed once to wake up. After simply looking at the log, the usb device on the hub is still terminated when wake up from power button, there is no difference.
bluetoothd log continuously in loop
``` 2023-01-02 13:11:35.209382+0800 0x1f9fe Default 0x0 8243 0 bluetoothd: [com.apple.bluetooth:Stack.LE] Address rotation in progress:NO 2023-01-02 13:11:35.209400+0800 0x1f9fe Error 0x0 8243 0 bluetoothd: [com.apple.bluetooth:Stack.HCI] OI_HCIIfc_SendHciCommand failed (status=1205) 2023-01-02 13:11:35.209419+0800 0x1f9fe Error 0x0 8243 0 bluetoothd: [com.apple.bluetooth:Stack.HCI] HCI expected event 14 with opcode OI_DHCI_VENDOR_OPCODE (0x0000FD4A) error, reason is STATUS 1205 2023-01-02 13:11:35.209438+0800 0x1f9fe Error 0x0 8243 0 bluetoothd: [com.apple.bluetooth:Stack.VSC] status 1205, hlCb 0x00A18974 2023-01-02 13:11:35.209458+0800 0x1f9fe Error 0x0 8243 0 bluetoothd: [com.apple.bluetooth:Stack.LE] setMultipleAdvParamsCompleteCb Could not start advertising : STATUS 1205 (status=65535) 2023-01-02 13:11:35.209477+0800 0x1f9fe Error 0x0 8243 0 bluetoothd: [com.apple.bluetooth:Stack.VSC] VSC state 1, can not create command 2023-01-02 13:11:35.209496+0800 0x1f9fe Error 0x0 8243 0 bluetoothd: [com.apple.bluetooth:Stack.VSC] VSC failed STATUS 3600 2023-01-02 13:11:35.209515+0800 0x1f9fe Error 0x0 8243 0 bluetoothd: [com.apple.bluetooth:Stack.LE] Could not stop the LE advertising BT_VSC_SetMultipleAdvInstanceEnable returned STATUS 3600 (status=65535) 2023-01-02 13:11:35.209533+0800 0x1f9fe Error 0x0 8243 0 bluetoothd: [com.apple.bluetooth:Stack.VSC] VSC state 1, can not create command 2023-01-02 13:11:35.209551+0800 0x1f9fe Error 0x0 8243 0 bluetoothd: [com.apple.bluetooth:Stack.VSC] VSC failed STATUS 3600 2023-01-02 13:11:35.209570+0800 0x1f9fe Error 0x0 8243 0 bluetoothd: [com.apple.bluetooth:Stack.LE] Could not stop the LE advertising BT_VSC_SetMultipleAdvInstanceEnable returned STATUS 3600 (status=65535) 2023-01-02 13:11:35.209588+0800 0x1f9fe Error 0x0 8243 0 bluetoothd: [com.apple.bluetooth:Stack.VSC] VSC state 1, can not create command 2023-01-02 13:11:35.209608+0800 0x1f9fe Error 0x0 8243 0 bluetoothd: [com.apple.bluetooth:Stack.VSC] VSC failed STATUS 3600 2023-01-02 13:11:35.209627+0800 0x1f9fe Error 0x0 8243 0 bluetoothd: [com.apple.bluetooth:Stack.LE] Could not stop the LE advertising BT_VSC_SetMultipleAdvInstanceEnable returned STATUS 3600 (status=65535) 2023-01-02 13:11:35.209646+0800 0x1f9fe Error 0x0 8243 0 bluetoothd: [com.apple.bluetooth:Stack.VSC] VSC state 1, can not create command 2023-01-02 13:11:35.209663+0800 0x1f9fe Error 0x0 8243 0 bluetoothd: [com.apple.bluetooth:Stack.VSC] VSC failed STATUS 3600 2023-01-02 13:11:35.209681+0800 0x1f9fe Error 0x0 8243 0 bluetoothd: [com.apple.bluetooth:Stack.LE] Could not stop the LE advertising BT_VSC_SetMultipleAdvInstanceEnable returned STATUS 3600 (status=65535) 2023-01-02 13:11:35.209699+0800 0x1f9fe Default 0x0 8243 0 bluetoothd: [com.apple.bluetooth:Stack.LE] Address rotation in progress:NO 2023-01-02 13:11:35.209718+0800 0x1f9fe Error 0x0 8243 0 bluetoothd: [com.apple.bluetooth:Stack.LE] failed to start advertising instance 0 with status 1205 . Abort ! Abort ! Abort ! ```
I want to fix this issue, but I have no idea. So I hope you can help me.
If someone has same issue, please fell free to let me know.
If you need more logs, please contact me.
Thanks.
My EFI is here: https://github.com/lyq1996/Gigabyte-Z690-Aorus-Elite-AX-DDR4_Hackintosh_13700k_6800XT
Some ome similar questions here: