Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Darwin: Can't claim device #158

Closed
tresf opened this issue Feb 29, 2016 · 37 comments
Closed

Darwin: Can't claim device #158

tresf opened this issue Feb 29, 2016 · 37 comments

Comments

@tresf
Copy link

tresf commented Feb 29, 2016

I'm using a high-level api wrapper, usb4java to claim a USB device on Mac.

  • The logic works 100% of the time on Windows and Ubuntu (with udev workarounds)
  • The logic rarely works on Mac OS X 10.11, but does work reliably on OS X 10.7 (via libusb_bulk_transfer never returns on OS X El Capitan #123, the 10.11.4 beta doesn't fix it, even with kext dummy extension, csrutil disable, kext-dev-mode=1, etc..)

The errors:

  • The original symptom of this problem was a NullPointerException due to assumptions about the active configuration. (reported by Java of course)
  • When I choose the first configuration blindly, I get Configuration not active when trying to "claim" the device.
  • When I try to force the active configuration using the low-level part of the wrapper, it doesn't help.

Since libusb is so popular for being wrapper by other languages (py, java), how best to provide debug information for wrapper libraries such as usb4java? Edit The LIBUSB_DEBUG=4 works fine on usb4java if the Java app is started from Terminal. Logs appended below.

I've filed a downstream bug here:
usb4java/usb4java#51

And as well as our own downstream-downstream bug:
qzind/qz-print#180

I have a C/C++ build environment on the 10.11 machine, but I'm not familiar enough with C nor the API to start writing test cases, etc, so any help is appreciated.

[timestamp] [threadID] facility level [function call] <message>
--------------------------------------------------------------------------------
[ 0.000011] [0000e903] libusb: debug [libusb_init] created default context
[ 0.000056] [0000e903] libusb: debug [libusb_init] libusb v1.0.18.10866
[ 0.000260] [0000e903] libusb: debug [darwin_get_cached_device] finding cached device for sessionID 0x115bca9ca
[ 0.000372] [0000e903] libusb: debug [darwin_get_cached_device] caching new device with sessionID 0x115bca9ca
[ 0.004309] [0000e903] libusb: debug [darwin_cache_device_descriptor] cached device descriptor:
[ 0.004325] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bDescriptorType:    0x01
[ 0.004329] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bcdUSB:             0x0110
[ 0.004333] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bDeviceClass:       0x00
[ 0.004336] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bDeviceSubClass:    0x00
[ 0.004889] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bDeviceProtocol:    0x00
[ 0.004898] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bMaxPacketSize0:    0x08
[ 0.004901] [0000e903] libusb: debug [darwin_cache_device_descriptor]   idVendor:           0x0e0f
[ 0.004905] [0000e903] libusb: debug [darwin_cache_device_descriptor]   idProduct:          0x0003
[ 0.004908] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bcdDevice:          0x0102
[ 0.004911] [0000e903] libusb: debug [darwin_cache_device_descriptor]   iManufacturer:      0x01
[ 0.004914] [0000e903] libusb: debug [darwin_cache_device_descriptor]   iProduct:           0x02
[ 0.004917] [0000e903] libusb: debug [darwin_cache_device_descriptor]   iSerialNumber:      0x00
[ 0.004920] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bNumConfigurations: 0x01
[ 0.004957] [0000e903] libusb: debug [darwin_check_configuration] active config: 1, first config: 1
[ 0.007400] [0000e903] libusb: debug [process_new_device] allocating new device in context 0x7fbe93eb9070 for with session 0x115bca9ca
[ 0.007431] [0000e903] libusb: debug [process_new_device] found device with address 1 port = 1 parent = 0x0 at 0x7fbe93eb9d8a
[ 0.007460] [0000e903] libusb: debug [darwin_get_cached_device] finding cached device for sessionID 0x0
[ 0.007482] [0000e903] libusb: debug [darwin_get_cached_device] matching sessionID 0x0 against cached device with sessionID 0x115bca9ca
[ 0.007487] [0000e903] libusb: debug [darwin_get_cached_device] caching new device with sessionID 0x0
[ 0.008499] [0000e903] libusb: debug [darwin_cache_device_descriptor] cached device descriptor:
[ 0.008539] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bDescriptorType:    0x01
[ 0.008546] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bcdUSB:             0x0100
[ 0.008553] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bDeviceClass:       0x09
[ 0.009471] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bDeviceSubClass:    0xff
[ 0.009480] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bDeviceProtocol:    0x00
[ 0.009483] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bMaxPacketSize0:    0x08
[ 0.009486] [0000e903] libusb: debug [darwin_cache_device_descriptor]   idVendor:           0x05ac
[ 0.009489] [0000e903] libusb: debug [darwin_cache_device_descriptor]   idProduct:          0x8005
[ 0.009492] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bcdDevice:          0x0198
[ 0.009494] [0000e903] libusb: debug [darwin_cache_device_descriptor]   iManufacturer:      0x00
[ 0.009497] [0000e903] libusb: debug [darwin_cache_device_descriptor]   iProduct:           0x00
[ 0.009500] [0000e903] libusb: debug [darwin_cache_device_descriptor]   iSerialNumber:      0x00
[ 0.009503] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bNumConfigurations: 0x01
[ 0.009545] [0000e903] libusb: debug [darwin_check_configuration] active config: 0, first config: 1
[ 0.009858] [0000e903] libusb: debug [process_new_device] allocating new device in context 0x7fbe93eb9070 for with session 0x0
[ 0.009874] [0000e903] libusb: debug [process_new_device] found device with address 0 port = 0 parent = 0x0 at 0x7fbe93eb976a
[ 0.009969] [0000e903] libusb: debug [darwin_get_cached_device] finding cached device for sessionID 0x119f64e08
[ 0.009994] [0000e903] libusb: debug [darwin_get_cached_device] matching sessionID 0x119f64e08 against cached device with sessionID 0x0
[ 0.009999] [0000e903] libusb: debug [darwin_get_cached_device] matching sessionID 0x119f64e08 against cached device with sessionID 0x115bca9ca
[ 0.010014] [0000e903] libusb: debug [darwin_get_cached_device] caching new device with sessionID 0x119f64e08
[ 0.012125] [0000e903] libusb: debug [darwin_cache_device_descriptor] cached device descriptor:
[ 0.012142] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bDescriptorType:    0x01
[ 0.012147] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bcdUSB:             0x0110
[ 0.012152] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bDeviceClass:       0x09
[ 0.012156] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bDeviceSubClass:    0x00
[ 0.012160] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bDeviceProtocol:    0x00
[ 0.012164] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bMaxPacketSize0:    0x08
[ 0.012168] [0000e903] libusb: debug [darwin_cache_device_descriptor]   idVendor:           0x0e0f
[ 0.012171] [0000e903] libusb: debug [darwin_cache_device_descriptor]   idProduct:          0x0002
[ 0.012175] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bcdDevice:          0x0100
[ 0.012179] [0000e903] libusb: debug [darwin_cache_device_descriptor]   iManufacturer:      0x00
[ 0.012248] [0000e903] libusb: debug [darwin_cache_device_descriptor]   iProduct:           0x01
[ 0.012256] [0000e903] libusb: debug [darwin_cache_device_descriptor]   iSerialNumber:      0x00
[ 0.012260] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bNumConfigurations: 0x01
[ 0.012300] [0000e903] libusb: debug [darwin_check_configuration] active config: 1, first config: 1
[ 0.012306] [0000e903] libusb: debug [process_new_device] allocating new device in context 0x7fbe93eb9070 for with session 0x119f64e08
[ 0.012313] [0000e903] libusb: debug [process_new_device] found device with address 2 port = 2 parent = 0x0 at 0x7fbe93eba71a
[ 0.012397] [0000e903] libusb: debug [darwin_get_cached_device] finding cached device for sessionID 0x12a2dc27f
[ 0.012458] [0000e903] libusb: debug [darwin_get_cached_device] matching sessionID 0x12a2dc27f against cached device with sessionID 0x119f64e08
[ 0.012467] [0000e903] libusb: debug [darwin_get_cached_device] matching sessionID 0x12a2dc27f against cached device with sessionID 0x0
[ 0.012760] [0000e903] libusb: debug [darwin_get_cached_device] matching sessionID 0x12a2dc27f against cached device with sessionID 0x115bca9ca
[ 0.012770] [0000e903] libusb: debug [darwin_get_cached_device] caching new device with sessionID 0x12a2dc27f
[ 0.014424] [0000e903] libusb: debug [darwin_cache_device_descriptor] cached device descriptor:
[ 0.014437] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bDescriptorType:    0x01
[ 0.014442] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bcdUSB:             0x0110
[ 0.014446] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bDeviceClass:       0x00
[ 0.014450] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bDeviceSubClass:    0x00
[ 0.014454] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bDeviceProtocol:    0x00
[ 0.014458] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bMaxPacketSize0:    0x08
[ 0.014461] [0000e903] libusb: debug [darwin_cache_device_descriptor]   idVendor:           0x05ac
[ 0.014465] [0000e903] libusb: debug [darwin_cache_device_descriptor]   idProduct:          0x020b
[ 0.014469] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bcdDevice:          0x0100
[ 0.014473] [0000e903] libusb: debug [darwin_cache_device_descriptor]   iManufacturer:      0x01
[ 0.014732] [0000e903] libusb: debug [darwin_cache_device_descriptor]   iProduct:           0x02
[ 0.014740] [0000e903] libusb: debug [darwin_cache_device_descriptor]   iSerialNumber:      0x00
[ 0.014744] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bNumConfigurations: 0x01
[ 0.014777] [0000e903] libusb: debug [darwin_check_configuration] active config: 1, first config: 1
[ 0.014782] [0000e903] libusb: debug [process_new_device] allocating new device in context 0x7fbe93eb9070 for with session 0x12a2dc27f
[ 0.014789] [0000e903] libusb: debug [process_new_device] found device with address 3 port = 1 parent = 0x7fbe93ebaa30 at 0x7fbe93ebacea
[ 0.014859] [0000e903] libusb: debug [darwin_get_cached_device] finding cached device for sessionID 0x12d71f123
[ 0.014910] [0000e903] libusb: debug [darwin_get_cached_device] matching sessionID 0x12d71f123 against cached device with sessionID 0x12a2dc27f
[ 0.014917] [0000e903] libusb: debug [darwin_get_cached_device] matching sessionID 0x12d71f123 against cached device with sessionID 0x119f64e08
[ 0.015169] [0000e903] libusb: debug [darwin_get_cached_device] matching sessionID 0x12d71f123 against cached device with sessionID 0x0
[ 0.015176] [0000e903] libusb: debug [darwin_get_cached_device] matching sessionID 0x12d71f123 against cached device with sessionID 0x115bca9ca
[ 0.015180] [0000e903] libusb: debug [darwin_get_cached_device] caching new device with sessionID 0x12d71f123
[ 0.016811] [0000e903] libusb: debug [darwin_cache_device_descriptor] cached device descriptor:
[ 0.016823] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bDescriptorType:    0x01
[ 0.016827] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bcdUSB:             0x0200
[ 0.016830] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bDeviceClass:       0xe0
[ 0.016833] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bDeviceSubClass:    0x01
[ 0.016836] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bDeviceProtocol:    0x01
[ 0.016838] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bMaxPacketSize0:    0x40
[ 0.016841] [0000e903] libusb: debug [darwin_cache_device_descriptor]   idVendor:           0x0e0f
[ 0.016844] [0000e903] libusb: debug [darwin_cache_device_descriptor]   idProduct:          0x0008
[ 0.016847] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bcdDevice:          0x0100
[ 0.016850] [0000e903] libusb: debug [darwin_cache_device_descriptor]   iManufacturer:      0x01
[ 0.016969] [0000e903] libusb: debug [darwin_cache_device_descriptor]   iProduct:           0x02
[ 0.016976] [0000e903] libusb: debug [darwin_cache_device_descriptor]   iSerialNumber:      0x03
[ 0.016979] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bNumConfigurations: 0x01
[ 0.017013] [0000e903] libusb: debug [darwin_check_configuration] active config: 1, first config: 1
[ 0.017018] [0000e903] libusb: debug [process_new_device] allocating new device in context 0x7fbe93eb9070 for with session 0x12d71f123
[ 0.017025] [0000e903] libusb: debug [process_new_device] found device with address 4 port = 2 parent = 0x7fbe93ebaa30 at 0x7fbe93ebac3a
[ 0.017095] [0000e903] libusb: debug [darwin_get_cached_device] finding cached device for sessionID 0x30f2a0e0819
[ 0.017145] [0000e903] libusb: debug [darwin_get_cached_device] matching sessionID 0x30f2a0e0819 against cached device with sessionID 0x12d71f123
[ 0.017153] [0000e903] libusb: debug [darwin_get_cached_device] matching sessionID 0x30f2a0e0819 against cached device with sessionID 0x12a2dc27f
[ 0.017375] [0000e903] libusb: debug [darwin_get_cached_device] matching sessionID 0x30f2a0e0819 against cached device with sessionID 0x119f64e08
[ 0.017383] [0000e903] libusb: debug [darwin_get_cached_device] matching sessionID 0x30f2a0e0819 against cached device with sessionID 0x0
[ 0.017387] [0000e903] libusb: debug [darwin_get_cached_device] matching sessionID 0x30f2a0e0819 against cached device with sessionID 0x115bca9ca
[ 0.017390] [0000e903] libusb: debug [darwin_get_cached_device] caching new device with sessionID 0x30f2a0e0819
[ 0.051344] [0000e903] libusb: debug [darwin_cache_device_descriptor] cached device descriptor:
[ 0.051374] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bDescriptorType:    0x01
[ 0.051379] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bcdUSB:             0x0110
[ 0.051382] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bDeviceClass:       0x00
[ 0.051385] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bDeviceSubClass:    0x00
[ 0.051388] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bDeviceProtocol:    0x00
[ 0.051390] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bMaxPacketSize0:    0x08
[ 0.051393] [0000e903] libusb: debug [darwin_cache_device_descriptor]   idVendor:           0x0eb8
[ 0.051396] [0000e903] libusb: debug [darwin_cache_device_descriptor]   idProduct:          0xf000
[ 0.051399] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bcdDevice:          0x0205
[ 0.051402] [0000e903] libusb: debug [darwin_cache_device_descriptor]   iManufacturer:      0x01
[ 0.051510] [0000e903] libusb: debug [darwin_cache_device_descriptor]   iProduct:           0x02
[ 0.051516] [0000e903] libusb: debug [darwin_cache_device_descriptor]   iSerialNumber:      0x03
[ 0.051519] [0000e903] libusb: debug [darwin_cache_device_descriptor]   bNumConfigurations: 0x01
[ 0.051544] [0000e903] libusb: debug [darwin_check_configuration] active config: 0, first config: 1
[ 0.051549] [0000e903] libusb: debug [process_new_device] allocating new device in context 0x7fbe93eb9070 for with session 0x30f2a0e0819
[ 0.051558] [0000e903] libusb: debug [process_new_device] found device with address 5 port = 3 parent = 0x7fbe93ebaa30 at 0x7fbe93ebb3da
[ 0.051667] [00010f0b] libusb: debug [darwin_event_thread_main] creating hotplug event source
[ 0.051907] [00010f0b] libusb: debug [darwin_event_thread_main] darwin event thread ready to receive events
[ 0.051955] [0000e903] libusb: debug [usbi_add_pollfd] add fd 46 events 1
[ 0.051969] [0000e903] libusb: debug [usbi_add_pollfd] add fd 48 events 1
[ 0.057107] [0000e903] libusb: debug [libusb_get_device_list] 
[ 0.059639] [0000e903] libusb: debug [libusb_get_device_descriptor] 
[ 0.063044] [0000e903] libusb: debug [libusb_get_device_descriptor] 
[ 0.066337] [0000e903] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.075064] [0000e903] libusb: debug [libusb_get_device_descriptor] 
[ 0.075124] [0000e903] libusb: debug [libusb_get_device_descriptor] 
[ 0.075154] [0000e903] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.075448] [0000e903] libusb: debug [libusb_get_device_descriptor] 
[ 0.075485] [0000e903] libusb: debug [libusb_get_device_descriptor] 
[ 0.075507] [0000e903] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.075582] [0000e903] libusb: debug [libusb_get_device_descriptor] 
[ 0.075707] [0000e903] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.075801] [0000e903] libusb: debug [libusb_get_device_descriptor] 
[ 0.075829] [0000e903] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.078955] [0000e903] libusb: debug [libusb_get_device_descriptor] 
[ 0.078988] [0000e903] libusb: debug [libusb_get_config_descriptor] index 0
[ERROR] 2016-02-29 02:27:13,977 @ qz.ws.PrintSocketClient:?
    Problem processing message
javax.usb.UsbNotActiveException: Configuration is not active
    at org.usb4java.javax.Interface.checkActive(Interface.java:74)
    at org.usb4java.javax.Interface.claim(Interface.java:99)
    at qz.communication.UsbIO.open(Unknown Source)
    at qz.ws.PrintSocketClient.processMessage(Unknown Source)
    at qz.ws.PrintSocketClient.onMessage(Unknown Source)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:497)
    at org.eclipse.jetty.websocket.common.events.annotated.CallableMethod.call(CallableMethod.java:70)
    at org.eclipse.jetty.websocket.common.events.annotated.OptionalSessionCallableMethod.call(OptionalSessionCallableMethod.java:68)
    at org.eclipse.jetty.websocket.common.events.JettyAnnotatedEventDriver$2.run(JettyAnnotatedEventDriver.java:210)
    at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:635)
    at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:555)
    at java.lang.Thread.run(Thread.java:745)
[ 0.554027] [00010807] libusb: debug [libusb_get_device_list] 
[ 0.554140] [00010807] libusb: debug [libusb_get_device_descriptor] 
[ 0.554334] [00010807] libusb: debug [libusb_get_device_descriptor] 
[ 0.554395] [00010807] libusb: debug [libusb_get_device_descriptor] 
[ 0.554460] [00010807] libusb: debug [libusb_get_device_descriptor] 
[ 0.554521] [00010807] libusb: debug [libusb_get_device_descriptor] 
[ 0.554590] [00010807] libusb: debug [libusb_get_device_descriptor] 
[ 1.059600] [00010807] libusb: debug [libusb_get_device_list] 
[ 1.059717] [00010807] libusb: debug [libusb_get_device_descriptor] 
[ 1.059812] [00010807] libusb: debug [libusb_get_device_descriptor] 
[ 1.059878] [00010807] libusb: debug [libusb_get_device_descriptor] 
[ 1.059917] [00010807] libusb: debug [libusb_get_device_descriptor] 
[ 1.059955] [00010807] libusb: debug [libusb_get_device_descriptor] 
[ 1.059999] [00010807] libusb: debug [libusb_get_device_descriptor] 
[ 1.562633] [00010807] libusb: debug [libusb_get_device_list] 
# This seems to repeat forever afterward
@mcuee
Copy link
Member

mcuee commented Feb 29, 2016 via email

@tresf
Copy link
Author

tresf commented Feb 29, 2016

@mcuee:

Bus 001 Device 023: ID 0eb8:f000  
Device Descriptor:
  bLength                18
  bDescriptorType         1
  bcdUSB               1.10
  bDeviceClass            0 (Defined at Interface level)
  bDeviceSubClass         0 
  bDeviceProtocol         0 
  bMaxPacketSize0         8
  idVendor           0x0eb8 
  idProduct          0xf000 
  bcdDevice            2.05
  iManufacturer           1 Mettler Toledo
  iProduct                2 PS60    
  iSerial                 3 ????????
  bNumConfigurations      1
  Configuration Descriptor:
    bLength                 9
    bDescriptorType         2
    wTotalLength           34
    bNumInterfaces          1
    bConfigurationValue     1
    iConfiguration          4 HID-POS
    bmAttributes         0x80
      (Bus Powered)
    MaxPower              100mA
    Interface Descriptor:
      bLength                 9
      bDescriptorType         4
      bInterfaceNumber        0
      bAlternateSetting       0
      bNumEndpoints           1
      bInterfaceClass         3 Human Interface Device
      bInterfaceSubClass      0 No Subclass
      bInterfaceProtocol      0 None
      iInterface              0 
        HID Device Descriptor:
          bLength                 9
          bDescriptorType        33
          bcdHID               1.10
          bCountryCode            0 Not supported
          bNumDescriptors         1
          bDescriptorType        34 Report
          wDescriptorLength     292
         Report Descriptors: 
           ** UNAVAILABLE **
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x81  EP 1 IN
        bmAttributes            3
          Transfer Type            Interrupt
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0008  1x 8 bytes
        bInterval             100
Device Status:     0x0001
  Self Powered

@hjelmn
Copy link
Member

hjelmn commented Feb 29, 2016

Can you give the debug output with the call to libusb_set_configuration. That call should be fixing your issue but it must be made before you try to claim an interface. You can use libusb_get_configuration to detect if the device is configured as a configuration of 0 means the device is unconfigured.

@hjelmn
Copy link
Member

hjelmn commented Feb 29, 2016

Also, it might be better for you to use libhid to access this device. Due to the way Microsoft handles USB a lot of devices erroneously use HID to avoid having to make a driver.

@tresf
Copy link
Author

tresf commented Feb 29, 2016

Can you post the output of lsusb -vvv for this device (under Linux)?

@mcuee I hope the information I've posted is adequate. 👍

Can you give the debug output with the call to libusb_set_configuration. That call should be fixing your issue but it must be made before you try to claim an interface. You can use libusb_get_configuration to detect if the device is configured as a configuration of 0 means the device is unconfigured.

@hjelmn This is where debugging is difficult. I think I had already done this via https://github.com/tresf/qz-print/commit/30d5c2229b3cffaeba854263a9cb96f21d5ff98f#diff-66e51979c4dd4f537b85c3203a0f1568R55.

That call should be fixing your issue but it must be made before you try to claim an interface.

@hjelmn Well, that's the part I'm a bit unfamiliar with. Unlike the C or Python API, the High-Level Java API isn't clear how to do this, so I did it using the technique linked in the comment segment just above. I'd be happy to provide these logs.

[...] use libhid to access this device [if the device] erroneously use HID to avoid having to make a driver

@hjelmn Can you elaborate a bit on this recommendation? This recommendation seems a bit drastic given the amount of success we've had with libusb, although what you are describing seems to be consistent with other implementations I've seen of the USB-scale code (we're looking to expand our hardware support beyond scales in the near future, hence libusb).

@hjelmn
Copy link
Member

hjelmn commented Feb 29, 2016

The logs would be helpful to see if the device is actually getting configured.

As for using hidapi. In OS X USB devices that use the HID device class are opened by IOUSBHID and can not be used by libusb in any meaningful way without writing a codeless kext. This means you will need to use hidapi to use the device. It sucks but this is a side-effect of the manufacturer abusing the HID device class to simplify their Windows support. Its hard to tell if this will happen in this case because the configuration specifies the device class.

You should be able use libusb and hidapi side-by-side without any problems.

@tresf
Copy link
Author

tresf commented Feb 29, 2016

can not be used by libusb in any meaningful way without writing a codeless kext.

I've done the kext (awaiting approval from Apple for signing rights) per:

The logic rarely works on Mac OS X 10.11, but does work reliably on OS X 10.7 (via #123, the 10.11.4 beta doesn't fix it, even with kext dummy extension, csrutil disable, kext-dev-mode=1, etc..)

...

You should be able use libusb and hidapi side-by-side without any problems.

I'll have the logs later, and we may eventually bundle HID support if needed, but I'd first like to isolate the cause since this happens on 10.11 but not in 10.7 and not in Windows or Linux.

@hjelmn
Copy link
Member

hjelmn commented Feb 29, 2016

Good luck on the signing rights. Apple is really strict on when they will allow KEXT signing. I couldn't get rights to sign a kext I wrote because I was not the one who created the hardware. Really irritating.

@tresf
Copy link
Author

tresf commented Feb 29, 2016

Good luck on the signing rights. Apple is really strict on when they will allow KEXT signing. I couldn't get rights to sign a kext I wrote because I was not the one who created the hardware. Really irritating.

Thanks for the heads up. The hardware manufacturer has been great to work with if I need to escalate, but getting approved for signing can be a tricky thing. I know some Mac sound drivers have to go through the kernel extension route to override device-claim settings too, so this shouldn't be off the mark in regards to what's allowed. If indeed the kext is impossible, the only other option is to drop USB support for Mac completely and fallback on HID-only, which would be a shame.

We write a JavaScript shim to talk to these devices through all major web browsers and we'd like to keep Mac on that list. Anyway... back on topic... for now, I'll proceed as if it will be approved and get those logs over. 👍

@tresf
Copy link
Author

tresf commented Mar 1, 2016

I believe this to be the relevant portion of the logs where I set the active configuration...

Should I not be calling close()? usb4java offers both a high-level api and I don't know any way but to mix them. I call the set_active_configuration call using the low level api, then calling claim() with the high-level api. Is that a bad idea?

Edit: I've placed the full log here if interested: https://gist.github.com/tresf/c26c14d55aba91d0efcc

  [21.986931] [0000d903] libusb: debug [usbi_add_pollfd] add fd 63 events 1
  [21.986940] [0000d903] libusb: debug [usbi_add_pollfd] add fd 65 events 1
  [21.986986] [0000d903] libusb: debug [libusb_open] open 0.5
  [21.987021] [0000d903] libusb: debug [usbi_add_pollfd] add fd 67 events 1
  [21.987026] [0000d903] libusb: debug [darwin_open] device open for access
+ [21.987087] [0000d903] libusb: debug [libusb_set_configuration] configuration 1
+ [22.012154] [0000d903] libusb: debug [libusb_close] 
  [22.012190] [0000d903] libusb: debug [usbi_remove_pollfd] remove fd 67
  [22.012235] [0000d903] libusb: debug [libusb_exit] 
  [22.012244] [0000d903] libusb: debug [libusb_get_next_timeout] no URBs, no timeout!
  [22.012248] [0000d903] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
  [22.012252] [0000d903] libusb: debug [handle_events] poll() 2 fds with timeout in 0ms
  [22.012269] [0000d903] libusb: debug [handle_events] poll() returned 0
  [22.012274] [0000d903] libusb: debug [libusb_unref_device] destroy device 0.5
  [22.012278] [0000d903] libusb: debug [libusb_unref_device] destroy device 0.4
  [22.012282] [0000d903] libusb: debug [libusb_unref_device] destroy device 0.3
  [22.012286] [0000d903] libusb: debug [libusb_unref_device] destroy device 0.2
  [22.012290] [0000d903] libusb: debug [libusb_unref_device] destroy device 0.0
  [22.012293] [0000d903] libusb: debug [libusb_unref_device] destroy device 0.1
  [22.012297] [0000d903] libusb: debug [usbi_remove_pollfd] remove fd 63
  [22.016617] [0000d903] libusb: debug [usbi_remove_pollfd] remove fd 65
  [ERROR] 2016-02-29 20:55:55,832 @ qz.ws.PrintSocketClient:?
    Problem processing message
  javax.usb.UsbNotActiveException: Configuration is not active
    at org.usb4java.javax.Interface.checkActive(Interface.java:74)
    at org.usb4java.javax.Interface.claim(Interface.java:99)
    at qz.communication.UsbIO.open(Unknown Source)
    at qz.ws.PrintSocketClient.processMessage(Unknown Source)
    at qz.ws.PrintSocketClient.onMessage(Unknown Source)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:497)
    at org.eclipse.jetty.websocket.common.events.annotated.CallableMethod.call(CallableMethod.java:70)
    at org.eclipse.jetty.websocket.common.events.annotated.OptionalSessionCallableMethod.call(OptionalSessionCallableMethod.java:68)
    at org.eclipse.jetty.websocket.common.events.JettyAnnotatedEventDriver$2.run(JettyAnnotatedEventDriver.java:210)
    at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:635)
    at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:555)
    at java.lang.Thread.run(Thread.java:745)

@hjelmn
Copy link
Member

hjelmn commented Mar 1, 2016

Its hard to tell ordering from this log since the java error is not printed near any messages from the matching open call. Can you use gist to post the entire log?

The call to close should be fine as the device should remain configured until it is disconnected.

@tresf
Copy link
Author

tresf commented Mar 1, 2016

Can you use gist to post the entire log?

I thought of that and edited/appended that right away. 😉

@hjelmn
Copy link
Member

hjelmn commented Mar 1, 2016

Weird. I do not see usb4java calling libusb_get_configuration anywhere. I would expect to see a message from that function:

                usbi_dbg("active config %d", *config);

I wonder where checkActive is getting the configuration from? It might be caching it somewhere that isn't catching your change to set the configuration.

@mcuee
Copy link
Member

mcuee commented Mar 1, 2016 via email

@tresf
Copy link
Author

tresf commented Mar 1, 2016

I do not see the code to setUsbConfiguration, only
getUsbConfiguration.

@mcuee the API doesn't provide one in the High-Level (that I can find), only the low-level. Also, you're looking at a moving target, it was here at the time of testing... https://github.com/tresf/qz-print/commit/a7b86dc1fb9d96cba71023a2ac52ff76c1a90cc7.

I wonder where checkActive is getting the configuration from? It might be caching it somewhere that isn't catching your change to set the configuration.

@hjelmn agreed. I suppose I should not expect them to be synchronized when combining two completely separate apis from the same library.

What if I were to take usb4java out of the equation and tackle this in something like pyusb? Is someone comfortable enough to assist me to get a quick snippet setup to claim the device? (homebrew, etc)

I will also recommend to forget about libusb for HID device under Mac OS X. It is much easier to use HIDAPI instead. In fact, HIDAPI should be the recommended tool to use for HID device if it is cross-platform projects.

Duly noted. Are we OK to see this through? Surely the research on set_active_configuration remains valid, no? Our library isn't written for weight scales specifically, it's a generic USB wrapper, so regardless of the end solution for this specific hardware, the usb4java portions will remain.

@hjelmn
Copy link
Member

hjelmn commented Mar 1, 2016

@mcuee I agree with you but this device seems to be usable by libusb because the HID device class is specified in the configuration descriptor. Since the device will be exclusively opened by libusb I don't think that IOUSBHID will be able to attach once the device is configured. I may be wrong though.

@tresf I think I see an issue in your code @ https://github.com/tresf/qz-print/blob/30d5c2229b3cffaeba854263a9cb96f21d5ff98f/src/qz/communication/UsbIO.java#L30

You are getting the interface before the setConfiguration call. Try moving this line to after the setConfiguration call and see if that helps.

Hmm, thinking about it that might not make a difference. Not too familiar with usb4java.

@tresf
Copy link
Author

tresf commented Mar 1, 2016

@hjelmn Thanks for the spot check. Tried this via tresf/94cd928 to no avail.

Growing a bit concerned about the lack of verbosity with the usb4java library, I decided to do the claim directly with the LibUsb low-level API via tresf/ba3d797 and the error message is quite different from the high-level API. On second thought, I don't think any (many?) of the logs have come from the high-level API, which explains the items @hjelmn observed as missing.

  [167.690699] [0000dd03] libusb: debug [libusb_set_configuration] configuration 1
  [167.690712] [0000dd03] libusb: debug [libusb_claim_interface] interface 0
+ [167.713521] [0000dd03] libusb: error [darwin_claim_interface] USBInterfaceOpen: another process has device opened for exclusive access
  [167.713570] [0000dd03] libusb: debug [libusb_release_interface] interface 0
  [167.713577] [0000dd03] libusb: debug [libusb_close] 

Full gist here: https://gist.github.com/tresf/0e6bde6

@hjelmn
Copy link
Member

hjelmn commented Mar 1, 2016

Hmmm, well that error suggest the device was successfully configured. I wonder if IOUSBHID somehow managed to grab the interface after the device was configured even with a user-space process holding the device. Unfortunately I can't look at the IOUSBFamily source code of 10.11 to verify as Apple has decided to no longer release the code. If IOUSBHID is grabbing the interface it would suggest that hidapi is going to be the only way to get this working. It looks like there has been some work on java bindings for the hidapi library: https://github.com/gary-rowe/hid4java

@tresf
Copy link
Author

tresf commented Mar 1, 2016

IOUSBHID somehow managed to grab the interface after the device was configured even with a user-space process holding the device.

Ok, I finally claimed it...

I had to use a remote desktop utility because this command kills the mouse...

 sudo kextunload -b com.apple.driver.usb.IOUSBHostHIDDevice

Once this was run, I could claim the device. 👿

There must be something wrong with my kext.

  • kextutil shows warnings, but no errors.
  • kextload doesn't return any errors
  • kextstat doesn't list it.

It's a pretty vanilla kext file. Here's it unconfigured: apple/apple-kext.plist.in and here's it configured: https://gist.github.com/tresf/0c808628e6f1c461cc0f

@hjelmn
Copy link
Member

hjelmn commented Mar 1, 2016

You need to prevent IOUSBHID from loading on the interfaces not the device. Example: https://github.com/hjelmn/gcusbadapter_osx/blob/master/gcusbadapter/Info_raw.plist

@tresf
Copy link
Author

tresf commented Mar 1, 2016

You need to prevent IOUSBHID from loading on the interfaces not the device. Example: https://github.com/hjelmn/gcusbadapter_osx/blob/master/gcusbadapter/Info_raw.plist

I was following the documentation here: https://developer.apple.com/library/mac/qa/qa1076/_index.html

[quoted]

  • Note that you should never add your own IOProbeScore property to a USB driver's property list.
  • Don't add extra keys; only use the key combinations shown in the following tables.
  • Table 1 Properties for matching a USB device (IOProviderClass is IOUSBDevice)
    • idVendor + idProduct + bcdDevice
    • idVendor + idProduct
    • ... etc.
  • Properties for matching a USB interface (IOProviderClass is IOUSBInterface)
    • idVendor + idProduct + bInterfaceNumber + bConfigurationValue + bcdDevice
    • idVendor + idProduct + bInterfaceNumber + bConfigurationValue
    • ...etc

I wasn't sure how reliable the bInterfaceNumber and bConfigurationValue would be, so I just listed the devices by idVendor + idProduct, which I feel will match the hardware device as broadly as possible.

Edit: Example: https://github.com/RehabMan/OS-X-BrcmPatchRAM/blob/master/BrcmBluetoothInjector-Info.plist

Edit2: Comparing the two...

  • Mine does not use IOUSBHostDevice but rather IOUSBDevice
  • Mine uses hex values in an integer field.
  • His doesn't use OSBundleLibraries at all
  • Mine doesn't have the CFBundleSignature tag.

Finally... is early-boot availability needed via <key>OSBundleRequired</key><string>Root</string>

@hjelmn
Copy link
Member

hjelmn commented Mar 1, 2016

The main takeaway from my example (which is a HID device) is that you need to match the IOProviderClass IOUSBInterface (or IOUSBHostInterface-- 10.11+ only) not IOUSBDevice. Your kext may very well be matching the device but that won't prevent IOUSBHID from grabbing the interfaces.

@tresf
Copy link
Author

tresf commented Mar 1, 2016

you need to match the IOProviderClass IOUSBInterface (or IOUSBHostInterface-- 10.11+ only) not IOUSBDevice. Your kext may very well be matching the device but that won't prevent IOUSBHID from grabbing the interfaces.

Gotcha, I'll switch that over and take another crack at it tonight.

Can you help explain the volatility of these settings? e.g. Should these stay relatively identical for all HID devices? How would I know what these should be?

<key>bInterfaceNumber</key>
   <integer>0</integer>

<key>bConfigurationValue</key>
   <integer>1</integer>

@hjelmn
Copy link
Member

hjelmn commented Mar 1, 2016

Those lines limit the matching to a specific configuration/interface. It prevents the kext from matching interfaces that were not intended.

@tresf
Copy link
Author

tresf commented Mar 1, 2016

@hjelmn Thanks. I guess my question is, how do I know which options are safe to use for a particular HID device? Are they almost always bInterfaceNumber=0, bConfigurationValue=1 for HID, or does this vary from device to device? Or does lsusb (linux, etc) give me the answers to what I'm asking? If we hard-code these settings, I just want to know the process for getting/setting these values as we add support for more devices in the Info.plist file. 👍

@hjelmn
Copy link
Member

hjelmn commented Mar 1, 2016

It device specific. You can tell from the device/configuration/interface descriptors which options you want. In most cases it will be bInterfaceNumber=0, bConfigurationValue=1.

@tresf
Copy link
Author

tresf commented Mar 2, 2016

In most cases it will be bInterfaceNumber=0, bConfigurationValue=1

Confirmed this on a Windows machine.

Unfortunately, I still can't get the kext to load. You had previously mentioned IOUSBHostInterface on 10.11. Is that a mandatory replacement for IOUSBInterface on El Capitan? If so, I can do system detection and swap it out at install time.

@hjelmn
Copy link
Member

hjelmn commented Mar 2, 2016

It should work with either the legacy IOUSBInterface or IOUSBHostInterface. There is probably some subtle bug that isn't being detected by kextload.

@tresf
Copy link
Author

tresf commented Mar 2, 2016

There is probably some subtle bug that isn't being detected by kextload.

Yeah, I'm having a hard time putting my finger on it. Debugging these codeless kext's seems to be a very "blackbox" process... (kextstat |grep -v apple won't list it, but I think that's normal).

I thought perhaps the package name ending in kext was causing issues. I've renamed the package to something less kext-ish. 😄 The kextutil log seems promising...

I've detached and reattached the device several times and it seem to stay available. Here's the current log (I'll be squashing commits very shortly if this starts to work.)

I'm still a bit uncertain what changed... 😕

On a side note, after some more digging around, I found another comment about Apple denying the kext for non-manufacturer requests from the Dolphin Emulator mailing list (getting Wii-mote support).

[Apple] will only let Nintendo sign a kernel extension that supports the WUP-028 [Wii controller]. Nintendo will never do it so the WUP-028 is unusable on OSX without putting the kernel in development mode (bypassing signing). Those willing to turn off kext verification can ... [truncated]

Although I can somewhat understand Apple's stance in regards to the request coming from an emulator community...

Do you know if Apple does the signing themselves, or do they offer a new developer certificate which has kext capabilities enabled? The documentation refers to codesign, so I assume a new cert is issued.

@tresf
Copy link
Author

tresf commented Mar 2, 2016

Rebooted and same familiar message...

Error: USB error 3: Unable to claim interface: Access denied (insufficient permissions)

Manually ran kextutil, unplugged the USB device and plugged it back in and now it is letting me claim it... (This time I didn't try to run kextload, just kextutil. Edit: Running kextload seems to do the trick too.)

Are you aware if <key>OSBundleRequired</key><string>Root</string> is required for boot-time claiming of an interface? Edit: Shimmed it in, it doesn't seem to make a difference.

I guess the good thing is it's predictable now. It works after unplugging and plugging back in and manually running kextload, which is better than not working at all (...I think...) 🙈

@tresf
Copy link
Author

tresf commented Mar 2, 2016

Ok... it's finally working first try after a reboot without manually firing kextload... The only thing I changed was I took the space out of the kext name. (i.e /Foo Bar.kext/ --> /FooBar.kext/). I'll continue testing.

@tresf
Copy link
Author

tresf commented Mar 2, 2016

... and now it's not working again unless kextload, unplug, plug back in... We'll, I'm closing this issue out as we simply cannot get reliable results with the kext hack and it truly appears to be something caused by Apple.

We'll start implementing the libhid driver, at least to get the USB scale support working. Thanks a bunch for all the help.

@tresf tresf closed this as completed Mar 2, 2016
@tresf
Copy link
Author

tresf commented Mar 10, 2016

Good luck on the signing rights. Apple is really strict on when they will allow KEXT signing. I couldn't get rights to sign a kext I wrote because I was not the one who created the hardware. Really irritating.

@hjelmn, As a follow-up to this, Apple did grant kext signing authority to our company for this purpose. Due to the aforementioned device claiming issues, we are unlikely to use it for the purposes of grabbing the HID devices, but I wanted to offer an update on that issue, as it seems to be a hurdle that many organizations struggle with. 👍

@hjelmn
Copy link
Member

hjelmn commented Mar 10, 2016

@tresf Nice! I keep hitting a brick wall when trying to get signing right but I am an open-source developer. Here is their latest response:

KEXT signing is intended for commercial products that maintain an ownership link between the product and the KEXT.  In the case of a third party retroactively creating a KEXT a signing certificate cannot be generated.

Thanks,

Developer Technical Support
Apple Worldwide Developer Relations

@tresf
Copy link
Author

tresf commented Mar 10, 2016

@hjelmn We're open source as well, but operate a commercial business model, which may be the deciding factor here.

@hjelmn
Copy link
Member

hjelmn commented Mar 11, 2016

@tresf That probably is the difference. Find it a little odd that Apple is willing to shut out third party support when there is no chance of first party support.

@ViralAgency
Copy link

The problem seems to be due to a conflict between different drivers, which use the same libraries, and in my case they were related to previous Samsung device installations. i had solved this way:

kextstat | grep -v apple

To have a return like this:

  70    0 0x57574000 0x3000     0x2000     com.devguru.driver.SamsungComposite (1.2.4) <33 4 3>
  72    0 0x57831000 0x7000     0x6000     com.devguru.driver.SamsungACMData (1.2.4) <71 33 5 4 3>
  94    0 0x57674000 0x3000     0x2000     com.devguru.driver.SamsungACMControl (1.2.4) <33 4 3>

Then:

$ sudo kextunload -b com.devguru.driver.SamsungComposite
$ sudo kextunload -b com.devguru.driver.SamsungACMData
$ sudo kextunload -b com.devguru.driver.SamsungACMControl

Done. Enjoy

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants