search

the-darkvoid / BrcmPatchRAM

Broadcom PatchRAM driver for OS X
GNU General Public License v2.0
88 stars 62 forks source link

With continuous_read, loading firmware takes 2x time #12

Closed RehabMan closed 9 years ago

RehabMan commented 9 years ago

Yup... it is twice as slow. Before the continuous_read, I had elapsed times around 800ms. Now it is near ~1700ms.

Here is a log (cold boot)...

Mar  9 16:56:05 localhost kernel[0]: BrcmPatchRAM: Firmware store start
Mar  9 16:56:05 localhost kernel[0]: BrcmPatchRAM: probe
Mar  9 16:56:05 localhost kernel[0]: BrcmPatchRAM: Version 1.5 starting on OS X Darwin 14.1.
Mar  9 16:56:05 localhost kernel[0]: BrcmPatchRAM: [0a5c:21fb]: USB [240A64076EE0 v274] "BCM20702A0" by "Broadcom Corp"
Mar  9 16:56:05 localhost kernel[0]: BrcmPatchRAM: getFirmware
Mar  9 16:56:05 localhost kernel[0]: BrcmPatchRAM: loadFirmware
Mar  9 16:56:05 localhost kernel[0]: BrcmPatchRAM: Retrieved firmware for firmware key "BCM20702A1_001.002.014.1483.1648_v5744".
Mar  9 16:56:05 localhost kernel[0]: BrcmPatchRAM: Decompressed firmware (29812 bytes --> 70286 bytes).
Mar  9 16:56:05 localhost kernel[0]: BrcmPatchRAM: Firmware is valid IntelHex firmware.
Mar  9 16:56:05 localhost kernel[0]: BrcmPatchRAM: [0a5c:21fb]: Available composite configurations: 1.
Mar  9 16:56:05 localhost kernel[0]: BrcmPatchRAM: [0a5c:21fb]: Set device configuration to configuration index 0 successfully.
Mar  9 16:56:05 localhost kernel[0]: BrcmPatchRAM: [0a5c:21fb]: Interface 0 (class ff, subclass 01, protocol 01) located.
Mar  9 16:56:05 localhost kernel[0]: BrcmPatchRAM: [0a5c:21fb]: Located pipe at 0x81.
Mar  9 16:56:05 localhost kernel[0]: BrcmPatchRAM: [0a5c:21fb]: Located pipe at 0x02.
Mar  9 16:56:05 localhost kernel[0]: BrcmPatchRAM: [0a5c:21fb]: State "Unknown" --> "Initialize".
Mar  9 16:56:05 localhost kernel[0]: BrcmPatchRAM: [0a5c:21fb]: READ VERBOSE CONFIG complete (status: 0x00, length: 10 bytes).
Mar  9 16:56:05 localhost kernel[0]: BrcmPatchRAM: [0a5c:21fb]: Firmware version: v4096.
Mar  9 16:56:05 localhost kernel[0]: BrcmPatchRAM: [0a5c:21fb]: State "Initialize" --> "Firmware version".
Mar  9 16:56:05 localhost kernel[0]: BrcmPatchRAM: getFirmware
Mar  9 16:56:05 localhost kernel[0]: BrcmPatchRAM: Retrieved cached firmware for "BCM20702A1_001.002.014.1483.1648_v5744".
Mar  9 16:56:05 localhost kernel[0]: BrcmPatchRAM: [0a5c:21fb]: DOWNLOAD MINIDRIVER complete (status: 0x00, length: 4 bytes).
Mar  9 16:56:05 localhost kernel[0]: BrcmPatchRAM: [0a5c:21fb]: State "Firmware version" --> "Mini-driver complete".
Mar  9 16:56:05 localhost kernel[0]: BrcmPatchRAM: [0a5c:21fb]: END OF RECORD complete (status: 0x00, length: 4 bytes).
Mar  9 16:56:05 localhost kernel[0]: BrcmPatchRAM: [0a5c:21fb]: State "Instruction write" --> "Firmware written".
Mar  9 16:56:05 localhost kernel[0]: BrcmPatchRAM: [0a5c:21fb]: RESET complete (status: 0x00, length: 4 bytes).
Mar  9 16:56:05 localhost kernel[0]: BrcmPatchRAM: [0a5c:21fb]: Unknown event code (0xff).
Mar  9 16:56:05 localhost kernel[0]: BrcmPatchRAM: [0a5c:21fb]: State "Firmware written" --> "Reset complete".
Mar  9 16:56:05 localhost kernel[0]: BrcmPatchRAM: [0a5c:21fb]: readCompletion - Return aborted (0xe00002eb)
Mar  9 16:56:05 localhost kernel[0]: BrcmPatchRAM: [0a5c:21fb]: Device reset.
Mar  9 16:56:05 localhost kernel[0]: BrcmPatchRAM: [0a5c:21fb]: Device status 0x00000001.
Mar  9 16:56:05 localhost kernel[0]: BrcmPatchRAM: [0a5c:21fb]: State "Reset complete" --> "Update complete".
Mar  9 16:56:05 localhost kernel[0]: BrcmPatchRAM: [0a5c:21fb]: Firmware upgrade completed successfully.
Mar  9 16:56:05 localhost kernel[0]: BrcmPatchRAM: [0a5c:21fb]: 1 matching driver personalities.
Mar  9 16:56:05 localhost kernel[0]: BrcmPatchRAM: brcmBundIdentifier: "com.apple.iokit.BroadcomBluetoothHostControllerUSBTransport"
Mar  9 16:56:05 localhost kernel[0]: BrcmPatchRAM: brcmIOClass: "BroadcomBluetoothHostControllerUSBTransport"
Mar  9 16:56:05 localhost kernel[0]: BrcmPatchRAM: [0a5c:21fb]: Published new IOKit personality.
Mar  9 16:56:05 localhost kernel[0]: BrcmPatchRAM: [0a5c:21fb]: 2 matching driver personalities.
Mar  9 16:56:05 localhost kernel[0]: BrcmPatchRAM: [0a5c:21fb]: existing IOKit personality "com.no-one.BrcmPatchRAM".
Mar  9 16:56:05 localhost kernel[0]: BrcmPatchRAM: [0a5c:21fb]: existing IOKit personality "com.apple.iokit.BroadcomBluetoothHostControllerUSBTransport".
Mar  9 16:56:05 localhost kernel[0]: BrcmPatchRAM: Processing time 1.772 seconds.
Mar  9 16:56:05 localhost kernel[0]: BrcmPatchRAM: setPowerState: which = 0x1

See anything fishy?

RehabMan commented 9 years ago

Here is a log on wake from sleep:

Mar  9 17:01:15 u430 kernel[0]: BrcmPatchRAM: probe
Mar  9 17:01:15 u430 kernel[0]: BrcmPatchRAM: Version 1.5 starting on OS X Darwin 14.1.
Mar  9 17:01:15 u430 kernel[0]: BrcmPatchRAM: [0a5c:21fb]: USB [240A64076EE0 v274] "BCM20702A0" by "Broadcom Corp"
Mar  9 17:01:15 u430 kernel[0]: BrcmPatchRAM: getFirmware
Mar  9 17:01:15 u430 kernel[0]: BrcmPatchRAM: Retrieved cached firmware for "BCM20702A1_001.002.014.1483.1648_v5744".
Mar  9 17:01:15 u430 kernel[0]: BrcmPatchRAM: [0a5c:21fb]: Available composite configurations: 1.
Mar  9 17:01:15 u430 kernel[0]: BrcmPatchRAM: [0a5c:21fb]: Set device configuration to configuration index 0 successfully.
Mar  9 17:01:15 u430 kernel[0]: BrcmPatchRAM: [0a5c:21fb]: Interface 0 (class ff, subclass 01, protocol 01) located.
Mar  9 17:01:15 u430 kernel[0]: BrcmPatchRAM: [0a5c:21fb]: Located pipe at 0x81.
Mar  9 17:01:15 u430 kernel[0]: BrcmPatchRAM: [0a5c:21fb]: Located pipe at 0x02.
Mar  9 17:01:15 u430 kernel[0]: BrcmPatchRAM: [0a5c:21fb]: State "Unknown" --> "Initialize".
Mar  9 17:01:15 u430 kernel[0]: BrcmPatchRAM: [0a5c:21fb]: READ VERBOSE CONFIG complete (status: 0x00, length: 10 bytes).
Mar  9 17:01:15 u430 kernel[0]: BrcmPatchRAM: [0a5c:21fb]: Firmware version: v4096.
Mar  9 17:01:15 u430 kernel[0]: BrcmPatchRAM: [0a5c:21fb]: State "Initialize" --> "Firmware version".
Mar  9 17:01:15 u430 kernel[0]: BrcmPatchRAM: getFirmware
Mar  9 17:01:15 u430 kernel[0]: BrcmPatchRAM: Retrieved cached firmware for "BCM20702A1_001.002.014.1483.1648_v5744".
Mar  9 17:01:15 u430 kernel[0]: BrcmPatchRAM: [0a5c:21fb]: DOWNLOAD MINIDRIVER complete (status: 0x00, length: 4 bytes).
Mar  9 17:01:15 u430 kernel[0]: BrcmPatchRAM: [0a5c:21fb]: State "Firmware version" --> "Mini-driver complete".
Mar  9 17:01:16 u430 kernel[0]: BrcmPatchRAM: [0a5c:21fb]: END OF RECORD complete (status: 0x00, length: 4 bytes).
Mar  9 17:01:16 u430 kernel[0]: BrcmPatchRAM: [0a5c:21fb]: State "Instruction write" --> "Firmware written".
Mar  9 17:01:16 u430 kernel[0]: BrcmPatchRAM: [0a5c:21fb]: RESET complete (status: 0x00, length: 4 bytes).
Mar  9 17:01:16 u430 kernel[0]: BrcmPatchRAM: [0a5c:21fb]: Unknown event code (0xff).
Mar  9 17:01:16 u430 kernel[0]: BrcmPatchRAM: [0a5c:21fb]: State "Firmware written" --> "Reset complete".
Mar  9 17:01:16 u430 kernel[0]: BrcmPatchRAM: [0a5c:21fb]: readCompletion - Return aborted (0xe00002eb)
Mar  9 17:01:16 u430 kernel[0]: BrcmPatchRAM: [0a5c:21fb]: Device reset.
Mar  9 17:01:16 u430 kernel[0]: BrcmPatchRAM: [0a5c:21fb]: Device status 0x00000001.
Mar  9 17:01:16 u430 kernel[0]: BrcmPatchRAM: [0a5c:21fb]: State "Reset complete" --> "Update complete".
Mar  9 17:01:16 u430 kernel[0]: BrcmPatchRAM: [0a5c:21fb]: Firmware upgrade completed successfully.
Mar  9 17:01:16 u430 kernel[0]: BrcmPatchRAM: [0a5c:21fb]: 1 matching driver personalities.
Mar  9 17:01:16 u430 kernel[0]: BrcmPatchRAM: brcmBundIdentifier: "com.apple.iokit.BroadcomBluetoothHostControllerUSBTransport"
Mar  9 17:01:16 u430 kernel[0]: BrcmPatchRAM: brcmIOClass: "BroadcomBluetoothHostControllerUSBTransport"
Mar  9 17:01:16 u430 kernel[0]: BrcmPatchRAM: [0a5c:21fb]: Published new IOKit personality.
Mar  9 17:01:16 u430 kernel[0]: BrcmPatchRAM: [0a5c:21fb]: 2 matching driver personalities.
Mar  9 17:01:16 u430 kernel[0]: BrcmPatchRAM: [0a5c:21fb]: existing IOKit personality "com.no-one.BrcmPatchRAM".
Mar  9 17:01:16 u430 kernel[0]: BrcmPatchRAM: [0a5c:21fb]: existing IOKit personality "com.apple.iokit.BroadcomBluetoothHostControllerUSBTransport".
Mar  9 17:01:16 u430 kernel[0]: BrcmPatchRAM: Processing time 1.779 seconds.
Mar  9 17:01:16 u430 kernel[0]: BrcmPatchRAM: setPowerState: which = 0x1
RehabMan commented 9 years ago

I haven't reviewed the continous_read code yet. I'll take a look at it and see if I can determine why the large performance regression.

RehabMan commented 9 years ago

I think the culprit is the IOSleep(10). We need a better thread synchronization method. I'm experimenting with IOLockSleep (in performUpgrade) and IOLockSleepWakeup (in readCompletion). That way we never sleep for an arbitrary amount of time... instead the io completion thread signals the main/waiting thread on DeviceState changes.

RehabMan commented 9 years ago

Making progress... I have seen 500ms firmware loads. Working from startup, but issues on wake from sleep. Trying to resolve the two queueRead calls after firmware load in the original code as compared to the new code.

I'll keep working on it...

RehabMan commented 9 years ago

I have it working. 500ms startup load. 450ms wake from sleep load.

Pull request forthcoming as soon as I do code review/cleanup.

RehabMan commented 9 years ago

This performance regression is now fixed in my fork.

the-darkvoid commented 9 years ago

@RehabMan,

That's great work. Sorry I did not reply earlier, I was travelling abroad. I will check out your changes as soon as possible.

RehabMan commented 9 years ago

Thanks for merging. Not sure if you want the README.md to have my comments regarding that change...

the-darkvoid commented 9 years ago

Readme reverted now.