Amir Hirsch | 6 Aug 2012 21:56

mac performance, unsuspending

I did a bit of digging to figure out why OpenNI device enumeration was slow on Mac while Kinect hacking. I measured the timing of different calls in libusb.  some logs and a description are in my post to the OpenNI dev list:


https://groups.google.com/forum/?fromgroups#!topic/openni-dev/Wqrtj09BkhY


OpenNI does device enumeration in a way that makes multiple requests to get the device list, once per sensor type and twice if it finds a sensor. this needs to be fixed in OpenNI, but the main slowness in libusb is that darwin_cache_device_descriptor calls USB Device Suspend and this call is expensive and takes about 100ms per call and it was being re-tried several times between sleeping for 30ms.

#######USBDeviceSuspend 312454000 
#######USBDeviceSuspend end 415979000 

I was able to greatly speed up my kinect hacking experience by modifying the function darwin_cache_device_descriptor, setting retries = 0 and try_unsuspend = 0  and commenting out the call to usleep. 

some talk on this list last year indicated that this might be associated with why I would sometimes lose my keyboard and trackpad when hacking with Kinect on Mac too:
http://libusb.6.n5.nabble.com/OSX-critical-bug-td4576409.html

I am going to distribute a fork in our kinect osx installer which ignores enumeration errors, and modify our openni distribution to use it. Is there a better solution in general? 


Amir
------------------------------------------------------------------------------
Live Security Virtual Conference
Exclusive live event will cover all the ways today's security and 
threat landscape has changed and how IT managers can respond. Discussions 
will include endpoint security, mobile security and the latest in malware 
threats. http://www.accelacomm.com/jaw/sfrnl04242012/114/50122263/
_______________________________________________
libusb-devel mailing list
libusb-devel <at> lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/libusb-devel
Xiaofan Chen | 25 Aug 2012 15:24
Picon

Re: mac performance, unsuspending

On Tue, Aug 7, 2012 at 3:56 AM, Amir Hirsch <amir <at> zigfu.com> wrote:
> I did a bit of digging to figure out why OpenNI device enumeration was slow
> on Mac while Kinect hacking. I measured the timing of different calls in
> libusb.  some logs and a description are in my post to the OpenNI dev list:
>
> https://groups.google.com/forum/?fromgroups#!topic/openni-dev/Wqrtj09BkhY
>
>
> OpenNI does device enumeration in a way that makes multiple requests to get
> the device list, once per sensor type and twice if it finds a sensor. this
> needs to be fixed in OpenNI, but the main slowness in libusb is that
> darwin_cache_device_descriptor calls USB Device Suspend and this call is
> expensive and takes about 100ms per call and it was being re-tried several
> times between sleeping for 30ms.
>
> #######USBDeviceSuspend 312454000
> #######USBDeviceSuspend end 415979000
>
> I was able to greatly speed up my kinect hacking experience by modifying the
> function darwin_cache_device_descriptor, setting retries = 0 and
> try_unsuspend = 0  and commenting out the call to usleep.
>
> some talk on this list last year indicated that this might be associated
> with why I would sometimes lose my keyboard and trackpad when hacking with
> Kinect on Mac too:
> http://libusb.6.n5.nabble.com/OSX-critical-bug-td4576409.html
>
> I am going to distribute a fork in our kinect osx installer which ignores
> enumeration errors, and modify our openni distribution to use it. Is there a
> better solution in general?

Yes I agree that it is good to fix this issue. In my Mac Mini (Mac OS X
Lion 10.7.4), the Apple bluetooth controller will get suspended and then
there will be debug log like this (for libusbx, the fork of libusb at
libusbx.org,
but it is similar for libusb-1.0)

[ 0.197248] [00000e07] libusbx: debug [process_new_device] found
device with address 5 port = 3 parent = 0x102e0a998 at 0x7fdd08e01130
[ 0.198148] [00000e07] libusbx: debug [process_new_device] allocating
new device for location 0xfa113000
[ 0.198454] [00000e07] libusbx: debug [darwin_cache_device_descriptor]
kernel responded with code: 0xe000404f. sleeping for 30 ms before
trying again
[ 0.229673] [00000e07] libusbx: debug [darwin_cache_device_descriptor]
kernel responded with code: 0xe00002ed. sleeping for 30 ms before
trying again
[ 0.261248] [00000e07] libusbx: debug [darwin_cache_device_descriptor]
kernel responded with code: 0xe000404f. sleeping for 30 ms before
trying again
[ 0.292716] [00000e07] libusbx: debug [darwin_cache_device_descriptor]
kernel responded with code: 0xe00002ed. sleeping for 30 ms before
trying again
[ 0.324141] [00000e07] libusbx: debug [darwin_cache_device_descriptor]
kernel responded with code: 0xe000404f. sleeping for 30 ms before
trying again
[ 0.355759] [00000e07] libusbx: debug [darwin_cache_device_descriptor]
kernel responded with code: 0xe00002ed. sleeping for 30 ms before
trying again
[ 0.386888] [00000e07] libusbx: warning
[darwin_cache_device_descriptor] could not retrieve device descriptor
05ac:8281: device not responding. skipping device
[ 0.387024] [00000e07] libusbx: debug [libusb_unref_device] destroy device 0.0

But I am not so sure if your two fixes are desirable or not.

Maybe the better fix is what suggested by Nathan in the above libusb-devel
thread.

"On Lion, I have noticed when probe suspended devices is selected the
 trackpad and keyboard can become unresponsive for several seconds.
I hadn't seen this behavior before with USB Prober (and never seen it with
 libusb). I might be able to reproduce the problem and find an appropriate
workaround (like not un-suspending certain classes of devices with
vendor ID 0x05ac -- Apple)."

--

-- 
Xiaofan

------------------------------------------------------------------------------
Live Security Virtual Conference
Exclusive live event will cover all the ways today's security and 
threat landscape has changed and how IT managers can respond. Discussions 
will include endpoint security, mobile security and the latest in malware 
threats. http://www.accelacomm.com/jaw/sfrnl04242012/114/50122263/
Xiaofan Chen | 26 Aug 2012 04:38
Picon

Re: mac performance, unsuspending

On Sat, Aug 25, 2012 at 9:24 PM, Xiaofan Chen <xiaofanc <at> gmail.com> wrote:
> But I am not so sure if your two fixes are desirable or not.
>
> Maybe the better fix is what suggested by Nathan in the above libusb-devel
> thread.
>
> "On Lion, I have noticed when probe suspended devices is selected the
>  trackpad and keyboard can become unresponsive for several seconds.
> I hadn't seen this behavior before with USB Prober (and never seen it with
>  libusb). I might be able to reproduce the problem and find an appropriate
> workaround (like not un-suspending certain classes of devices with
> vendor ID 0x05ac -- Apple)."

Another possible fix is to introduce device filter support.

One simple proposal is like this. It does not cover all ground but should
help many use cases.
http://lists.infradead.org/pipermail/libusbx/2012-January/000041.html
https://github.com/vlovich/libusb/commits/filter_support

--

-- 
Xiaofan

------------------------------------------------------------------------------
Live Security Virtual Conference
Exclusive live event will cover all the ways today's security and 
threat landscape has changed and how IT managers can respond. Discussions 
will include endpoint security, mobile security and the latest in malware 
threats. http://www.accelacomm.com/jaw/sfrnl04242012/114/50122263/
Nathan Hjelm | 26 Aug 2012 05:53

Re: mac performance, unsuspending

Reply inline.

On Aug 25, 2012, at 7:24 AM, Xiaofan Chen <xiaofanc <at> gmail.com> wrote:

> On Tue, Aug 7, 2012 at 3:56 AM, Amir Hirsch <amir <at> zigfu.com> wrote:
>> I did a bit of digging to figure out why OpenNI device enumeration was slow
>> on Mac while Kinect hacking. I measured the timing of different calls in
>> libusb.  some logs and a description are in my post to the OpenNI dev list:
>> 
>> https://groups.google.com/forum/?fromgroups#!topic/openni-dev/Wqrtj09BkhY
>> 
>> 
>> OpenNI does device enumeration in a way that makes multiple requests to get
>> the device list, once per sensor type and twice if it finds a sensor. this
>> needs to be fixed in OpenNI, but the main slowness in libusb is that
>> darwin_cache_device_descriptor calls USB Device Suspend and this call is
>> expensive and takes about 100ms per call and it was being re-tried several
>> times between sleeping for 30ms.
>> 
>> #######USBDeviceSuspend 312454000
>> #######USBDeviceSuspend end 415979000
>> 
>> I was able to greatly speed up my kinect hacking experience by modifying the
>> function darwin_cache_device_descriptor, setting retries = 0 and
>> try_unsuspend = 0  and commenting out the call to usleep.
>> 
>> some talk on this list last year indicated that this might be associated
>> with why I would sometimes lose my keyboard and trackpad when hacking with
>> Kinect on Mac too:
>> http://libusb.6.n5.nabble.com/OSX-critical-bug-td4576409.html
>> 
>> I am going to distribute a fork in our kinect osx installer which ignores
>> enumeration errors, and modify our openni distribution to use it. Is there a
>> better solution in general?
> 
> Yes I agree that it is good to fix this issue. In my Mac Mini (Mac OS X
> Lion 10.7.4), the Apple bluetooth controller will get suspended and then
> there will be debug log like this (for libusbx, the fork of libusb at
> libusbx.org,
> but it is similar for libusb-1.0)

I will not put any fixes into libusbx. I don't like the direction that project is taking (HID support == bad
idea) or the fragmentation having a second projects creates. 

> [ 0.197248] [00000e07] libusbx: debug [process_new_device] found
> device with address 5 port = 3 parent = 0x102e0a998 at 0x7fdd08e01130
> [ 0.198148] [00000e07] libusbx: debug [process_new_device] allocating
> new device for location 0xfa113000
> [ 0.198454] [00000e07] libusbx: debug [darwin_cache_device_descriptor]
> kernel responded with code: 0xe000404f. sleeping for 30 ms before
> trying again
> [ 0.229673] [00000e07] libusbx: debug [darwin_cache_device_descriptor]
> kernel responded with code: 0xe00002ed. sleeping for 30 ms before
> trying again
> [ 0.261248] [00000e07] libusbx: debug [darwin_cache_device_descriptor]
> kernel responded with code: 0xe000404f. sleeping for 30 ms before
> trying again
> [ 0.292716] [00000e07] libusbx: debug [darwin_cache_device_descriptor]
> kernel responded with code: 0xe00002ed. sleeping for 30 ms before
> trying again
> [ 0.324141] [00000e07] libusbx: debug [darwin_cache_device_descriptor]
> kernel responded with code: 0xe000404f. sleeping for 30 ms before
> trying again
> [ 0.355759] [00000e07] libusbx: debug [darwin_cache_device_descriptor]
> kernel responded with code: 0xe00002ed. sleeping for 30 ms before
> trying again
> [ 0.386888] [00000e07] libusbx: warning
> [darwin_cache_device_descriptor] could not retrieve device descriptor
> 05ac:8281: device not responding. skipping device
> [ 0.387024] [00000e07] libusbx: debug [libusb_unref_device] destroy device 0.0
> 

I added the retry code to enumerate buggy devices. This code is similar to code within the generic usb device
driver (see IOUSBFamily). I can't say I loose sleep over something on the order of 100 ms (or even 500ms)
when it comes to usb enumeration. In the future that code will not be called very often (when hotplug
support is in-- we should probably get on that sooner rather than later). I will agree that I made it a little
too aggressive. Might back it off to retrying once or twice to speed things up in the meantime.

> But I am not so sure if your two fixes are desirable or not.

I don't think they are. The unsuspend code allows libusb to enumerate more devices and some developers
might be taking advantage of this. Also, as I mentioned before if the unsuspend code was the problem USB
Prober would cause the mouse and keyboard to drop as well.

> Maybe the better fix is what suggested by Nathan in the above libusb-devel
> thread.
> 
> "On Lion, I have noticed when probe suspended devices is selected the
> trackpad and keyboard can become unresponsive for several seconds.
> I hadn't seen this behavior before with USB Prober (and never seen it with
> libusb). I might be able to reproduce the problem and find an appropriate
> workaround (like not un-suspending certain classes of devices with
> vendor ID 0x05ac -- Apple)."

Let me see if I can get this into the next version. Its getting about time for a 1.0.10!

-Nathan

------------------------------------------------------------------------------
Live Security Virtual Conference
Exclusive live event will cover all the ways today's security and 
threat landscape has changed and how IT managers can respond. Discussions 
will include endpoint security, mobile security and the latest in malware 
threats. http://www.accelacomm.com/jaw/sfrnl04242012/114/50122263/
Xiaofan Chen | 28 Aug 2012 06:57
Picon

Re: mac performance, unsuspending

On Sun, Aug 26, 2012 at 11:53 AM, Nathan Hjelm <hjelmn <at> me.com> wrote:
> I added the retry code to enumerate buggy devices. This code is
> similar to code within the generic usb device driver (see IOUSBFamily).
> I can't say I loose sleep over something on the order of 100 ms (or even 500ms)
> when it comes to usb enumeration. In the future that code will not be called
> very often (when hotplug support is in-- we should probably get on that
> sooner rather than later). I will agree that I made it a little too aggressive.
> Might back it off to retrying once or twice to speed things up in the meantime.

I agree that hotplug support is one of the most requested feature for
libusb-1.0. But it may take time.

On the other hand, I think in the mean time, your proposed fix to
reduce the retry count should help.

>> But I am not so sure if your two fixes are desirable or not.
>
> I don't think they are. The unsuspend code allows libusb to enumerate more
> devices and some developers might be taking advantage of this. Also,
> as I mentioned before if the unsuspend code was the problem USB Prober
> would cause the mouse and keyboard to drop as well.

I agree with you that the OP's fixes are not desirable. On the other
hand, USB Prober is more of a debugging tool and it is probably
not that often used by the users whereas the libusb program may
run more often and it is probably more annoying than USB Prober
if the mouse/keyboard/trackpad are dropped.

>> Maybe the better fix is what suggested by Nathan in the above libusb-devel
>> thread.
>>
>> "On Lion, I have noticed when probe suspended devices is selected the
>> trackpad and keyboard can become unresponsive for several seconds.
>> I hadn't seen this behavior before with USB Prober (and never seen it with
>> libusb). I might be able to reproduce the problem and find an appropriate
>> workaround (like not un-suspending certain classes of devices with
>> vendor ID 0x05ac -- Apple)."
>
> Let me see if I can get this into the next version. Its getting about time
> for a 1.0.10!

I agree. This is especially true since that libusb-1.0.9 release got quite
some serious bugs under Windows and some users are hit by the bugs.
The fixes are already in libusb-1.0 git and just need Peter to release a
new version.

Eg:
http://libusb.6.n5.nabble.com/windows-vs-linux-behaviour-question-tt5710347.html#a5710351

--

-- 
Xiaofan

------------------------------------------------------------------------------
Live Security Virtual Conference
Exclusive live event will cover all the ways today's security and 
threat landscape has changed and how IT managers can respond. Discussions 
will include endpoint security, mobile security and the latest in malware 
threats. http://www.accelacomm.com/jaw/sfrnl04242012/114/50122263/
Segher Boessenkool | 28 Aug 2012 09:18

Re: mac performance, unsuspending

>>> But I am not so sure if your two fixes are desirable or not.
>>
>> I don't think they are. The unsuspend code allows libusb to  
>> enumerate more
>> devices and some developers might be taking advantage of this. Also,
>> as I mentioned before if the unsuspend code was the problem USB  
>> Prober
>> would cause the mouse and keyboard to drop as well.
>
> I agree with you that the OP's fixes are not desirable. On the other
> hand, USB Prober is more of a debugging tool and it is probably
> not that often used by the users whereas the libusb program may
> run more often and it is probably more annoying than USB Prober
> if the mouse/keyboard/trackpad are dropped.

Did we ever find out what is happening (on the bus, in the kernel)
when the mouse etc. become unresponsive?  We need to know that to
do any _good_ fix to the problem.

>>> "On Lion, I have noticed when probe suspended devices is selected  
>>> the
>>> trackpad and keyboard can become unresponsive for several seconds.
>>> I hadn't seen this behavior before with USB Prober (and never  
>>> seen it with
>>> libusb). I might be able to reproduce the problem and find an  
>>> appropriate
>>> workaround (like not un-suspending certain classes of devices with
>>> vendor ID 0x05ac -- Apple)."
>>
>> Let me see if I can get this into the next version.

I think it would be a reasonable workaround, but better would be
e.g. if we could properly unsuspend those devices.  Or do it only
for very specific cases, not whole classes of devices.  Oh, and
if it's Apple's fault, file a radar :-)

Segher

------------------------------------------------------------------------------
Live Security Virtual Conference
Exclusive live event will cover all the ways today's security and 
threat landscape has changed and how IT managers can respond. Discussions 
will include endpoint security, mobile security and the latest in malware 
threats. http://www.accelacomm.com/jaw/sfrnl04242012/114/50122263/
Xiaofan Chen | 28 Aug 2012 14:40
Picon

Re: mac performance, unsuspending

On Tue, Aug 28, 2012 at 3:18 PM, Segher Boessenkool
<segher <at> kernel.crashing.org> wrote:
>>>> But I am not so sure if your two fixes are desirable or not.
>>>
>>>
>>> I don't think they are. The unsuspend code allows libusb to enumerate
>>> more
>>> devices and some developers might be taking advantage of this. Also,
>>> as I mentioned before if the unsuspend code was the problem USB Prober
>>> would cause the mouse and keyboard to drop as well.
>>
>>
>> I agree with you that the OP's fixes are not desirable. On the other
>> hand, USB Prober is more of a debugging tool and it is probably
>> not that often used by the users whereas the libusb program may
>> run more often and it is probably more annoying than USB Prober
>> if the mouse/keyboard/trackpad are dropped.
>
>
> Did we ever find out what is happening (on the bus, in the kernel)
> when the mouse etc. become unresponsive?  We need to know that to
> do any _good_ fix to the problem.

I do not have any Apple Mouse/Keyboard/Trackpad (I have a
Mac Mini). In my case, the Apple USB Bluetooth contoller
is the problem. But it seems not related to the suspend issue.

In my system, Apple IR receiver will get suspended but I
do not have any IR device to test.

When it turns it off and then on, it will work.

Full Speed device  <at>  8 (0xFA113000):
.............................................
Vendor-specific device: "Bluetooth USB Host Controller"
    Port Information:   0x001d
           Captive
           Internal Device
           Connected
           Enabled
    Number Of Endpoints (includes EP0):
        Total Endpoints for Configuration 1 (current):   8
    Device Descriptor
        Descriptor Version Number:   0x0200
        Device Class:   255   (Vendor-specific)
        Device Subclass:   1   (Vendor-specific)
        Device Protocol:   1
        Device MaxPacketSize:   64
        Device VendorID/ProductID:   0x05AC/0x8281   (Apple Inc.)
        Device Version Number:   0x0052
        Number of Configurations:   1
        Manufacturer String:   1 "Apple Inc."
        Product String:   2 "Bluetooth USB Host Controller"
        Serial Number String:   0 (none)
    Configuration Descriptor (current config)
        Length (and contents):   216
            Raw Descriptor (hex)    0000: 09 02 D8 00 04 01 00 E0  00
09 04 00 00 03 FF 01
            Raw Descriptor (hex)    0010: 01 00 07 05 81 03 10 00  01
07 05 82 02 40 00 01
            Raw Descriptor (hex)    0020: 07 05 02 02 40 00 01 09  04
01 00 02 E0 01 01 00
            Raw Descriptor (hex)    0030: 07 05 83 01 00 00 01 07  05
03 01 00 00 01 09 04
            Raw Descriptor (hex)    0040: 01 01 02 E0 01 01 00 07  05
83 01 09 00 01 07 05
            Raw Descriptor (hex)    0050: 03 01 09 00 01 09 04 01  02
02 E0 01 01 00 07 05
            Raw Descriptor (hex)    0060: 83 01 11 00 01 07 05 03  01
11 00 01 09 04 01 03
            Raw Descriptor (hex)    0070: 02 E0 01 01 00 07 05 83  01
20 00 01 07 05 03 01
            Raw Descriptor (hex)    0080: 20 00 01 09 04 01 04 02  E0
01 01 00 07 05 83 01
            Raw Descriptor (hex)    0090: 40 00 01 07 05 03 01 40  00
01 09 04 01 05 02 E0
            Raw Descriptor (hex)    00a0: 01 01 00 07 05 83 01 40  00
01 07 05 03 01 40 00
            Raw Descriptor (hex)    00b0: 01 09 04 02 00 02 FF FF  FF
00 07 05 84 02 20 00
            Raw Descriptor (hex)    00c0: 01 07 05 04 02 20 00 01  09
04 03 00 00 FE 01 01
            Raw Descriptor (hex)    00d0: 00 07 21 07 88 13 40 00
        Number of Interfaces:   4
        Configuration Value:   1
        Attributes:   0xE0 (self-powered, remote wakeup)
        MaxPower:   0 ma
        Interface #0 - Vendor-specific
            Alternate Setting   0
            Number of Endpoints   3
            Interface Class:   255   (Vendor-specific)
            Interface Subclass;   1   (Vendor-specific)
            Interface Protocol:   1
            Endpoint 0x81 - Interrupt Input
                Address:   0x81  (IN)
                Attributes:   0x03  (Interrupt no synchronization data endpoint)
                Max Packet Size:   16
                Polling Interval:   1 ms
            Endpoint 0x82 - Bulk Input
                Address:   0x82  (IN)
                Attributes:   0x02  (Bulk no synchronization data endpoint)
                Max Packet Size:   64
                Polling Interval:   1 ms
            Endpoint 0x02 - Bulk Output
                Address:   0x02  (OUT)
                Attributes:   0x02  (Bulk no synchronization data endpoint)
                Max Packet Size:   64
                Polling Interval:   1 ms
        Interface #1 - Wireless Controller/RF Controller
            Alternate Setting   0
            Number of Endpoints   2
            Interface Class:   224   (Wireless Controller)
            Interface Subclass;   1   (RF Controller)
            Interface Protocol:   1   (Bluetooth Programming Interface)
            Endpoint 0x83 - Isochronous Input
                Address:   0x83  (IN)
                Attributes:   0x01  (Isochronous no synchronization
data endpoint)
                Max Packet Size:   0
                Polling Interval:   1 ms
            Endpoint 0x03 - Isochronous Output
                Address:   0x03  (OUT)
                Attributes:   0x01  (Isochronous no synchronization
data endpoint)
                Max Packet Size:   0
                Polling Interval:   1 ms

But from time to time, it will report error under
USB Prober. In that case, I need to turn it off
and on to get it working under USB Prober.

Full Speed device  <at>  8 (0xFA113000):
.............................................
Bluetooth USB Host Controller (did not respond to inquiry -
kIOReturnNotResponding (0xe00002ed))
    Port Information:   kIOUSBPipeStalled (0xe000404f)
    Number Of Endpoints (includes EP0):
        Total Endpoints for Configuration 1 (current):   8

--

-- 
Xiaofan

------------------------------------------------------------------------------
Live Security Virtual Conference
Exclusive live event will cover all the ways today's security and 
threat landscape has changed and how IT managers can respond. Discussions 
will include endpoint security, mobile security and the latest in malware 
threats. http://www.accelacomm.com/jaw/sfrnl04242012/114/50122263/

Gmane