KDL in usb_midi

[Pete]

While trying to find out why usb_midi is not working (properly) with my M-Audio UNO, I was adding dprintf statements to track what was failing. I suddenly started going into KDL when I plugged in the UNO, and I've established that it is a particular dprintf in the 'usb_midi_added' function that triggers this. The KDL itself, though, happens in the 'midi_usb_callback', when it hits a '0xcccccccc' pointer. If the dprintf is commented out, that pointer becomes valid.

To avoid the KDL, I added an abort-check for the bad pointer so I can get a record in syslog. Also, the original code to 'set_alt_interface' has been modified so that it isn't called for the UNO, because that stalls if it is.

I will try to attach relevant files, but as I'm new to this (:-/) I'll include some excerpts here.

First, a diff of the changes I made to the original usb_midi.c:

193,195d192
< 	DPRINTF_INFO ((MY_ID "in callback: my_dev = %p endpoint = %p (base %p)\n",
< 		my_dev, my_dev->ept, *(void **)my_dev));
< 	if (my_dev->ept == 0xcccccccc) return;	/* prevent KDL */
217d213
< 	int alt;
236a233
> 		int alt;
265c262
< 	if(alt && (st = usb->set_alt_interface(dev, intf)) != B_OK) {
---
> 	if((st = usb->set_alt_interface(dev, intf)) != B_OK) {
269c266
< 		
---
> 	
280,281d276
< 	DPRINTF_INFO ((MY_ID "my_dev = %p interface endpoint = %p\n",
< 		my_dev, &intf->endpoint [0]));
294d288
< 	DPRINTF_INFO ((MY_ID "queueing bulk xfer ep 0\n"));

Here's the section of syslog if that final DPRINTF_INFO is present:

KERN: usb hub 2: port 0: new device connected
KERN: usb_midi: init_hardware() Jul 17 2009 14:36:17
KERN: usb_midi: init_driver() Jul 17 2009 14:36:17
KERN: usb_midi: device_added()
KERN: usb_midi: vendor ID 0x0763, product ID 0x0150
KERN: usb_midi: interface 0, alt : 0: class 1, subclass 1, protocol 0
KERN: usb_midi: interface 1, alt : 0: class 1, subclass 3, protocol 0
KERN: usb_midi: my_dev = 0x81004bb8 interface endpoint = 0x80ed3bf0
KERN: usb_midi: queueing bulk xfer ep 0
KERN: usb error uhci 0: td (0x0208a980) error: status: 0x18400003; token: 0x006803e1;
KERN: usb_midi: midi_usb_callback()
KERN: usb_midi: bus status -2147442667
KERN: usb_midi: in callback: my_dev = 0x81004bb8 endpoint = 0xcccccccc (base 0xcccccccc)
KERN: usb_midi: added midi/usb/0
KERN: usb_midi: init_driver() OK
KERN: usb_midi: publish_devices()
KERN: usb_midi: publishing midi/usb/0
KERN: usb_midi: find_device(midi/usb/0)

and this is the syslog if it is commented out:

KERN: usb hub 2: port 0: new device connected
KERN: usb_midi: init_hardware() Jul 17 2009 14:30:46
KERN: usb_midi: init_driver() Jul 17 2009 14:30:46
KERN: usb_midi: device_added()
KERN: usb_midi: vendor ID 0x0763, product ID 0x0150
KERN: usb_midi: interface 0, alt : 0: class 1, subclass 1, protocol 0
KERN: usb_midi: interface 1, alt : 0: class 1, subclass 3, protocol 0
KERN: usb_midi: my_dev = 0x873b8258 interface endpoint = 0x80ed39b0
KERN: usb_midi: added midi/usb/0
KERN: usb error uhci 0: td (0x0208a300) error: status: 0x18400003; token: 0x006802e1;
KERN: usb_midi: midi_usb_callback()
KERN: usb_midi: bus status -2147442667
KERN: usb_midi: init_driver() OK
KERN: usb_midi: in callback: my_dev = 0x873b8258 endpoint = 0x80ed39b0 (base 0x00000000)
KERN: usb_midi: publish_devices()
KERN: usb_midi: publishing midi/usb/0
KERN: usb_midi: find_device(midi/usb/0)

Two things may be relevant in the above. One, there is always a uhci error (that I haven't got to look at yet -- uhci is still a black box -- but the UNO partially works if it doesn't KDL, even though it still shows a stall), and two, the order of execution seems different in the two cases. (The 'base' value printout isn't shown in the diff, but is just the first longword in the structure; it also differs, but this doesn't indicate that the whole structure is uninitialized. I did a later check of other values in the structure and they seem to be initialized correctly.) I suspect a race condition may be the root cause.

[Pete]

modified test version of usb_midi.c

[Pete]

Disassembly section of failing usb_midi.o

[Pete]

Disassembly with the dprintf disabled

[mmlr]

Fixed in hrev31666.

The callback wasn't called because of the queue_bulk() call. Instead it was triggered by the queue_request() call that didn't really make sense as it was. If that request would return early enough, i.e. before the other code finished setting the endpoint data, it would lead to this crash. Adding the debug output managed to do that in your case.

About the set_alternate_interface(): If it isn't required by the specs to explicitly set an alternate, the call should simply be removed. Configuring the device will cause the default alternate to be selected anyway. If it is required, you could simply check for and ignore the stall case, as this simply means that the device doesn't support this call/request/function in the context of all the request based calls (set_feature, clear_feature, get_status, get_descriptor, send_request, queue_request and set_configuration).