Quad Update #7

In my earlier post I said that the bootloader for the KroozSD was luftboot, but in reality it’s available here. The version contained in that tree doesn’t appear to be fully up to date as there is no CRC and the strings reported by the device are different, but I’m assuming the current code is similar.

While I realise I could simply switch to a different laptop, I can’t help but feel this should be a simple enough problem to fix and as I’m always interested in learning another wee adventure begins!

USB Debugging

Having gone from working USB transfers to non-working USB transfers I’ve been doing a little bit of debugging of the USB. The stm32_mem.py script uses PyUSB so my first stop was to enable additional debug information for the library. The library authors have made this very easy.

$ export PYUSB_DEBUG=debug $ ./stm32_mem.py ... 2016-05-21 10:05:06,719 DEBUG:usb.backend.libusb1:_LibUSB.init() 2016-05-21 10:05:06,721 INFO:usb.core:find(): using backend "usb.backend.libusb1" 2016-05-21 10:05:06,721 DEBUG:usb.backend.libusb1:_LibUSB.enumerate_devices() 2016-05-21 10:05:06,721 DEBUG:usb.backend.libusb1:_LibUSB.get_device_descriptor(<usb .backend.libusb1._device="" at="" object="">) 2016-05-21 10:05:06,721 DEBUG:usb.backend.libusb1:_LibUSB.get_device_descriptor(<usb .backend.libusb1._device="" at="" object="">) 2016-05-21 10:05:06,721 DEBUG:usb.backend.libusb1:_LibUSB.get_device_descriptor(<usb .backend.libusb1._device="" at="" object="">)

The level of information is impressive and allowed me to check that no additional calls had been made and that what I thought was taking place was reflected in the calls being made. Having checked that the next level was to look at whether there were other calls being made by the system. For this I turned to usbmon.

The Ubuntu kernel already has the basic support needed, so the first step was simply to load the usbmon kernel module and verify that it was available.

$ sudo modprobe usbmon $ ls /sys/kernel/debug/usb/usbmon 0s 0u 1s 1t 1u 2s 2t 2u

Finding the bus number was easy enough.

$ dmesg ... [25450.332261] usb 1-2: new full-speed USB device number 34 using xhci_hcd [25450.462462] usb 1-2: New USB device found, idVendor=0483, idProduct=df11 [25450.462505] usb 1-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3 [25450.462510] usb 1-2: Product: KroozSD CRC [25450.462514] usb 1-2: Manufacturer: S.Krukowski [25450.462517] usb 1-2: SerialNumber: Bootloader

So, bus #1 was where to look, but which endpoint did I need? The usbmon documentation explains that endpoints ending with ‘u’ are the best ones to use, so ‘1u’ endpoint was what I wanted. Getting the data into a file so I could analyse it turned out to be as easy as

$ cat /sys/kernel/debug/usb/usbmon/1u > krooz.mon

Running the stm32_mem.py script again (in a different terminal) resulted in a capture file that contained a lot of information so I used CTRL-C to stop the capture. Analysing the data turned out to be simple enough as well thanks to Virtual USB Analyzer. The app wasn’t installed by default but was in apt, so installation and usage was simple enough.

$ sudo apt-get install vusb-analyzer $ vusb-analyzer krooz.mon

The app displayed the information needed, but without DFU support built in some interpretation was required.

Not an issue…

One of the recurring entries in dmesg has been

[25457.004284] usb 1-4: usbfs: interface 0 claimed by btusb while 'python' sets config #1

Looking at this in more detail it’s not an issue and merely informing me that the discovery phase of the stm32_mem.py script has attempted to claim ownership of my bluetooth device (which has a DFU endpoint). It would be nice if PyUSb had a way to check whether a device was already claimed, but I couldn’t find anything that would allow such a check. It does remove one source of concern.

Results?

Everything I looked at showed me that the script does exactly what I expected it to and there is no interference from anything else on my system. Not a big surprise and certainly what I expected, but it also illustrates how easy it can be to get the additional information I wanted. As the scripts haven’t changed I can rule that out as the source of problem, which would imply that the bootloader code has an odd bug in it somewhere. Figuring out what and how to fix it will be much harder.

The bootloader code I have looked at all appears to be simple enough that there is only one way the manifestation stage can be triggered.

static int usbdfu_control_request(usbd_device *usbd_dev, struct usb_setup_data *req, u8 **buf, u16 *len, void (**complete)(usbd_device *usbd_dev, struct usb_setup_data req)) { if ((req->bmRequestType & 0x7F) != 0x21) return 0; / Only accept class request. */ switch (req->bRequest) { case DFU_DNLOAD: if ((len == NULL) || (*len == 0)) { usbdfu_state = STATE_DFU_MANIFEST_SYNC; return 1; } else { ...

This is meant to be triggered by an empty download request, but somehow is being triggered following a 2050 byte download. The function is a callback supplied to the libopencm3 usb setup code,

usbd_register_control_callback(usbd_dev, USB_REQ_TYPE_CLASS | USB_REQ_TYPE_INTERFACE, USB_REQ_TYPE_TYPE | USB_REQ_TYPE_RECIPIENT, usbdfu_control_request);

The sequence leading to the crash is always the same.

DFU_DNLOAD DFU_ERASE command DFU_DNLOAD 2050 bytes DFU_GETSTATUS => STATE_DFU_DNBUSY DFU_GETSTATUS => STATE_DFU_IDLE ... DFU_DNLOAD DFU_ERASE command DFU_DNLOAD 2050 bytes of data DFU_GETSTATUS => STATE_DFU_DNBUSY DFU_GETSTATUS => STATE_DFU_MANIFEST

In all my debugging I see that the download transfer completes for the erase and then the data transfer, and after a few transfers (which is normally 3) working as expected the manifestation stage is triggered. Answers on how to further debug are welcomed on postcards (or emails) 🙂