USBTMC example not working on SAMD21/SAMD51

[charkster]

Setup
Setup 1:
PC OS: Windows 10
Board: Seeeduino Xiao (samd21),
Firmware: examples/device/usbtmc

Setup 2:
PC OS: Raspberry Pi OS (using pyvisa 1.11.1, pyvisa-py 0.4.1)
Board: Seeeduino Xiao (samd21),
Firmware: examples/device/usbtmc

Describe the bug
On Windows 10 pyvisa (using NI VISA backend) will not report the device.
On Raspberry Pi pyvisa reports the device, but the resource manager is unable to connect.

To reproduce
Steps to reproduce the behavior:

1. Compiled the USBTMC example on raspberry pi and downloaded it to the Seeeduino Xiao (samd21) using uf2 drag-n-drop.
2. Cycled power on the device after 5 seconds
3. Used the following python script to list USBTMC devices:

import pyvisa
rm = pyvisa.ResourceManager('@py')
print(rm.list_resources())
samd21 = rm.open_resource('USB0::51966::16384::123456::0::INSTR')

('ASRL/dev/ttyAMA0::INSTR', 'USB0::51966::16384::123456::0::INSTR')
Traceback (most recent call last):
File "/home/pi/.local/lib/python3.7/site-packages/pyvisa_py/protocols/usbtmc.py", line 216, in init
self.usb_dev.set_configuration()
File "/home/pi/.local/lib/python3.7/site-packages/usb/core.py", line 869, in set_configuration
self._ctx.managed_set_configuration(self, configuration)
File "/home/pi/.local/lib/python3.7/site-packages/usb/core.py", line 102, in wrapper
return f(self, *args, **kwargs)
File "/home/pi/.local/lib/python3.7/site-packages/usb/core.py", line 148, in managed_set_configuration
self.backend.set_configuration(self.handle, cfg.bConfigurationValue)
File "/home/pi/.local/lib/python3.7/site-packages/usb/backend/libusb1.py", line 794, in set_configuration
_check(self.lib.libusb_set_configuration(dev_handle.handle, config_value))
File "/home/pi/.local/lib/python3.7/site-packages/usb/backend/libusb1.py", line 595, in _check
raise USBError(_strerror(ret), ret, _libusb_errno[ret])
usb.core.USBError: [Errno None] Other error

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
File "test_tinyusb.py", line 4, in
samd21 = rm.open_resource('USB0::51966::16384::123456::0::INSTR')
File "/home/pi/.local/lib/python3.7/site-packages/pyvisa/highlevel.py", line 3304, in open_resource
res.open(access_mode, open_timeout)
File "/home/pi/.local/lib/python3.7/site-packages/pyvisa/resources/resource.py", line 298, in open
self._resource_name, access_mode, open_timeout
File "/home/pi/.local/lib/python3.7/site-packages/pyvisa/highlevel.py", line 3232, in open_bare_resource
return self.visalib.open(self.session, resource_name, access_mode, open_timeout)
File "/home/pi/.local/lib/python3.7/site-packages/pyvisa_py/highlevel.py", line 167, in open
sess = cls(session, resource_name, parsed, open_timeout)
File "/home/pi/.local/lib/python3.7/site-packages/pyvisa_py/sessions.py", line 323, in init
self.after_parsing()
File "/home/pi/.local/lib/python3.7/site-packages/pyvisa_py/usb.py", line 84, in after_parsing
self.parsed.serial_number,
File "/home/pi/.local/lib/python3.7/site-packages/pyvisa_py/protocols/usbtmc.py", line 287, in init
super(USBTMC, self).init(vendor, product, serial_number, **kwargs)
File "/home/pi/.local/lib/python3.7/site-packages/pyvisa_py/protocols/usbtmc.py", line 218, in init
raise Exception("failed to set configuration\n %s" % e)
Exception: failed to set configuration
[Errno None] Other error

Screenshots

Log
Working to get log file. Have not been successful yet.

[charkster]

I tried examples/device/hid_generic_inout and had no issues with the compile and uf2 programming. I was able to run the example without any issues.

[charkster]

I did notice this in DMESG on the raspberry pi:

[ 2.214996] usb 1-1.4: new full-speed USB device number 4 using xhci_hcd
[ 2.354164] usb 1-1.4: New USB device found, idVendor=cafe, idProduct=4000, bcdDevice= 1.00
[ 2.354184] usb 1-1.4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 2.354202] usb 1-1.4: Product: TinyUSB Device
[ 2.354218] usb 1-1.4: Manufacturer: TinyUSB
[ 2.354234] usb 1-1.4: SerialNumber: 123456
[ 2.359368] usb 1-1.4: can't set config #1, error -32

[charkster]

I tried using my itsybitsy_m4 (SAMD51) and it has the exact same issue.

[hathach]

have you managed to get the stack log with LOG=1 or 2 option. Also you should try to test with PC first, when it all works well, then test with RPI later on.

PS: just realize itsybitsy bsp doesn't have board_uart_read/board_uart_write implemented just yet, you need to implement that first before getting the log. I will add it later when I have time.

[pigrew]

I just tested usbtmc example (master branch) on a STM32F0, and it's enumerating and responding to "*IDN?" on Windows 10. As far as I know, I'm the only person who has used the class and I've only used it on a ST MCU.

I may order a SAMD21 (I've never used one before), and see if I can figure anything out if this issue doesn't get debugged soon.

The only "different" thing in the UBTMC class is that it uses an interrupt endpoint by default. You could try disabling it? Set examples/device/usbtmc/src/tusb_config.h:81-82 to #define CFG_TUD_USBTMC_ENABLE_INT_EP 0 and set #define CFG_TUD_USBTMC_ENABLE_488 0, also. (IIRC, 488 mode requires an interrupt endpoint.)

[charkster]

I just tested usbtmc example (master branch) on a STM32F0, and it's enumerating and responding to "*IDN?" on Windows 10. As far as I know, I'm the only person who has used the class and I've only used it on a ST MCU.

I may order a SAMD21 (I've never used one before), and see if I can figure anything out if this issue doesn't get debugged soon.

The only "different" thing in the UBTMC class is that it uses an interrupt endpoint by default. You could try disabling it? Set examples/device/usbtmc/src/tusb_config.h:81-82 to #define CFG_TUD_USBTMC_ENABLE_INT_EP 0 and set #define CFG_TUD_USBTMC_ENABLE_488 0, also. (IIRC, 488 mode requires an interrupt endpoint.)

Thank you for the suggestion.
I made the changes:
#define CFG_TUD_USBTMC_ENABLE_INT_EP 0
#define CFG_TUD_USBTMC_ENABLE_488 0
I recompiled and tried first on Win10 with python VISA (and a separate run with python PYVISA).

Here's my code:

import visa
rm = visa.ResourceManager()
print rm.list_resources()
samd21 = rm.open_resource('USB0::0xCAFE::0x4000::123456::INSTR')
samd21.query("*IDN?")

Here is the response (it is identical for both visa and pyvisa):

(u'USB0::0xCAFE::0x4000::123456::INSTR', u'ASRL3::INSTR')
Traceback (most recent call last):
  File "<input>", line 2, in <module>
  File "P:\venv-27\lib\site-packages\pyvisa\resources\messagebased.py", line 564, in query
    return self.read()
  File "P:\venv-27\lib\site-packages\pyvisa\resources\messagebased.py", line 413, in read
    message = self._read_raw().decode(enco)
  File "P:\venv-27\lib\site-packages\pyvisa\resources\messagebased.py", line 386, in _read_raw
    chunk, status = self.visalib.read(self.session, size)
  File "P:\venv-27\lib\site-packages\pyvisa\ctwrapper\functions.py", line 1584, in read
    ret = library.viRead(session, buffer, count, byref(return_count))
  File "P:\venv-27\lib\site-packages\pyvisa\ctwrapper\highlevel.py", line 188, in _return_handler
    raise errors.VisaIOError(ret_value)
VisaIOError: VI_ERROR_TMO (-1073807339): Timeout expired before operation completed.

I tried on Raspberry Pi python (using pyvisa and pyvisa-py backend)
Here's my code:

import pyvisa
rm = pyvisa.ResourceManager('@py')
print(rm.list_resources())
samd21 = rm.open_resource('USB0::51966::16384::123456::0::INSTR')
samd21.query("*IDN?");

Here's the response:

(u'ASRL/dev/ttyAMA0::INSTR', u'USB0::51966::16384::123456::0::INSTR')
Traceback (most recent call last):
  File "test_tinyusb.py", line 5, in <module>
    samd21.query("*IDN?");
  File "/home/pi/.local/lib/python2.7/site-packages/pyvisa/resources/messagebased.py", line 613, in query
    return self.read()
  File "/home/pi/.local/lib/python2.7/site-packages/pyvisa/resources/messagebased.py", line 427, in read
    message = self._read_raw().decode(enco)
  File "/home/pi/.local/lib/python2.7/site-packages/pyvisa/resources/messagebased.py", line 400, in _read_raw
    chunk, status = self.visalib.read(self.session, size)
  File "/home/pi/.local/lib/python2.7/site-packages/pyvisa-py/highlevel.py", line 398, in read
    ret = self.sessions[session].read(count)
  File "/home/pi/.local/lib/python2.7/site-packages/pyvisa-py/usb.py", line 128, in read
    USBTimeoutException)
  File "/home/pi/.local/lib/python2.7/site-packages/pyvisa-py/sessions.py", line 530, in _read
    current = reader()
  File "/home/pi/.local/lib/python2.7/site-packages/pyvisa-py/usb.py", line 108, in _usb_reader
    return self.interface.read(count)
  File "/home/pi/.local/lib/python2.7/site-packages/pyvisa-py/protocols/usbtmc.py", line 417, in read
    raw_write(req)
  File "/home/pi/.local/lib/python2.7/site-packages/pyvisa-py/protocols/usbtmc.py", line 255, in write
    raise ValueError(str(e))
ValueError: [Errno 110] Operation timed out

I ordered a STM32FC411CE "Black Pill" and it should be arriving early next week (got a 3pack on a Black Friday sale).
The SAMD21 boards are very popular on Adafruit and Sparkfun. I have both the QT PY and Seeeduino Xiao which sell for $6.
It is single core Cortex M0+. The SAMD51 is a single core Cortex M4. The ItsyBitsy M4 from Adafruit is the cheapest SAMD51 board that I have seen at $15 (it does overclock to 200MHz and has 2 DACs).

[pigrew]

I've been able to reproduce the symptoms on a NXP LPCXpresso54114 board.

I'll attempt to debug the problem, but I'm not at all familiar with NXP MCUs.

[charkster]

I tried the example on a STM32F411CE blackpill board and had no issues. Runs as expected. I have obtained a j-link debugger to see if I can see differences between the STM32 board and the SAMD21 board with the code execution.

[charkster]

I believe the problem is in the usb_descriptors.c file. When I compare the example/device/cdc_msc/src/usb_descriptors.c file, there is a comment about SAMG:

#elif CFG_TUSB_MCU == OPT_MCU_SAMG
// SAMG doesn't support a same endpoint number with different direction IN and OUT
// e.g EP1 OUT & EP1 IN cannot exist together

[hathach]

I believe the problem is in the usb_descriptors.c file. When I compare the example/device/cdc_msc/src/usb_descriptors.c file, there is a comment about SAMG:

#elif CFG_TUSB_MCU == OPT_MCU_SAMG
// SAMG doesn't support a same endpoint number with different direction IN and OUT
// e.g EP1 OUT & EP1 IN cannot exist together

SAMG and SAMD aren't the same, they are using different usb controller.

[charkster]

I have my Segger JLINK Edu setup and have 2 microcontrollers: (1) Adafruit Trinket M0 (ATSAMD21E18) and (2) STM32 Blackpill (STM32F411CE). STM32 board is working. In "main.c" I tried commenting-out the "usbtmc_app_task_iter()" subroutine and STM32 was just fine (the app did not work but the operating system was fine with the USBTMC device attach). This makes me believe the problem is with either "tusb_init()" or "tud_task()".

Here is my make command for the SAMD21:
make BOARD=trinket_m0 LOG=2 LOGGER=rtt all flash-jlink
Board gets programmed with no problems.

I am running "JLinkRTTLogger" but I get an empty RTT logfile. This is my first time using this tool, and I read a couple of tutorials. Am I supposed to start the logger and then reset the part to get the logfile?
Once I get the logfiles from the SAMD21 and STM32F411 boards should I upload them here?
Thanks.

[hathach]

rtt should print some log out, please try with JLinkRTTViewer, I think you have to select the MCU and it could detect the clock speed, the swd clock around 1-4Mhz is pretty safe. Also you need to clean the project first, since LOG=2 make use of newlib nano which needs a clean to link retarget.

[charkster]

Thanks for the feedback. I am cleaning the build directory before each new make command. When I try a make with the "LOGGER=rtt", program the part and reboot I am not seeing the device enumerate properly. Is this expected?
This is what I see when I am not using the logger:
[ 2900.059388] usb 1-1.1: new full-speed USB device number 97 using xhci_hcd
[ 2900.206578] usb 1-1.1: New USB device found, idVendor=cafe, idProduct=4000, bcdDevice= 1.00
[ 2900.206596] usb 1-1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 2900.206611] usb 1-1.1: Product: TinyUSB Device
[ 2900.206624] usb 1-1.1: Manufacturer: TinyUSB
[ 2900.206638] usb 1-1.1: SerialNumber: 123456
[ 2900.218758] usb 1-1.1: can't set config #1, error -32

This is what I see when I am using the logger:
[ 3536.635883] usb 1-1.1: new full-speed USB device number 106 using xhci_hcd
[ 3541.795976] usb 1-1.1: unable to read config index 0 descriptor/start: -110
[ 3541.795983] usb 1-1.1: can't read configurations, error -110
[ 3541.895849] usb 1-1.1: new full-speed USB device number 107 using xhci_hcd

Perhaps the logger code is too large. Also I am seeing that I am not overwriting the bootloader when I flash with tinyusb. It appears to be protected by the BOOTPROT fuse. I was able to clear the BOOTPROT fuse by writing it to 0xFF, but that did not help me to flash the logger code and see proper enumeration.
I was using this guide to unlocking BOOTPROT:
https://roamingthings.de/posts/use-j-link-to-change-the-boot-loader-protection-of-a-sam-d21/

Sorry for all the questions, I'm making slow progress.

[hathach]

maybe you could drop the -DSEGGER_RTT_MODE_DEFAULT=SEGGER_RTT_MODE_BLOCK_IF_FIFO_FULL that will cause some missing log, but it doesn't blockingly wait on anything.
https://github.com/hathach/tinyusb/blob/master/examples/make.mk#L121

I will try to pull out an SAMD21 board to test out with RTT log tomorrow or so if I could find time.

[charkster]

Thanks. I tried the "LOGGER=rtt" make arguement with the STM32F411CE blackpill board and I get the same results as the SAMD21.

[ 1390.525659] usb 1-1.3: new full-speed USB device number 17 using xhci_hcd
[ 1405.716388] usb 1-1.3: device descriptor read/64, error -110
[ 1420.196747] usb 1-1.3: device descriptor read/64, error -32

[charkster]

I was able to see the RTT log using JLinkRTTViewer with the
-DSEGGER_RTT_MODE_DEFAULT=SEGGER_RTT_MODE_BLOCK_IF_FIFO_FULL option enabled.
The JLinkRTTLogger doesn't work at all... I had to run JLinkRTTViewer under Ubuntu x86 as the ARM tools version does not have that tool.

Attached are the 2 log files from JLinkRTTViewer:
tinyusb_usbtmc_example_stm32f411ce.log
tinyusb_usbtmc_example_atsamd21e18_2.log

[charkster]

I needed to remove the "00>" text from the tinyusb_usbtmc_example_atsamd21e18_2.log file so that it can be compared with the other log file. Here is the updated file.
tinyusb_usbtmc_example_atsamd21e18_2.log

[pigrew]

I needed to remove the "00>" text from the tinyusb_usbtmc_example_atsamd21e18_2.log file so that it can be compared with the other log file. Here is the updated file.

The highlighted difference is the host assigning a different USB device address for each MCU. I don't think it's a significant difference.

The "interesting" part is the usbtmcd_open_cb 313: assert failed output in the atsamd log. Its DCD (device driver) doesn't like something about EP 0x81.

One conjecture is that this due to the wMaxPacketSize of 2 bytes. I'm having trouble deciding if this is legal or not for interrupt endpoints. Full-speed bulk endpoints are restricted to 8, 16, 32, or 64 byte max. High-speed bulk endpoints are restricted to 512 byte. My reading is that interrupt endpoints can be anywhere between 0 and 64 bytes for interrupt full-speed endpoints, so 2 should be legal.

Could you try changing the packet length to 8 and check if it the device works?

tinyusb/examples/device/usbtmc/src/usb_descriptors.c

Line 86 in 40870f9

TUD_USBTMC_INT_DESCRIPTOR(/* INT ep # */ 0x82, /* epMaxSize = */ 2, /* bInterval = */16u )

If this works, probably we just change it, and assume that nobody is as crazy as I am to choose a weird wMaxPacketLength of 2. USBTMC interrupt payloads are always two bytes long.

(We also should have a condition that sets the bulk endpoints to 256 bytes when in full-speed mode)

ADDED LATER: Yep, the samd driver only supports 8, 16, 32, 64, etc. lengths, so I expect this change will fix the issues.

[charkster]

@pigrew, @hathach Thank you very much for finding the bug. The example is working as expected on my SAMD21 and STM32F411 boards. I made the change to 8 bytes for the TUD_USBTMC_INT_DESCRIPTOR.
Should I close the issue, or do you want to do that when the fix has been committed?

[hathach]

One conjecture is that this due to the wMaxPacketSize of 2 bytes. I'm having trouble deciding if this is legal or not for interrupt endpoints. Full-speed bulk endpoints are restricted to 8, 16, 32, or 64 byte max. High-speed bulk endpoints are restricted to 512 byte. My reading is that interrupt endpoints can be anywhere between 0 and 64 bytes for interrupt full-speed endpoints, so 2 should be legal.

You are right, any number from 0 to 64 is complaint to the specs. However, many MCUs like SAMD will only accept 8,16,32,64 where endpoint size is configured in bit-field register.

@pigrew, @hathach Thank you very much for finding the bug. The example is working as expected on my SAMD21 and STM32F411 boards. I made the change to 8 bytes for the TUD_USBTMC_INT_DESCRIPTOR.
Should I close the issue, or do you want to do that when the fix has been committed?

No problem, I am glad that we could help. Would you submitting the PT that include fix #558 in its 1st post. That will auto close this issue when that is merged.

[charkster]

@hathach, do I create a branch with the changes and then do a pull-request? I setup my ssh key with my github account and made a tinyusb clone using it. I was going to push the changes to a new branch but I don't have permission to do that.
I'm sorry, I don't know what "PT" means.

[pigrew]

@charkster, I think "PT" is a typo. He means "PR".

What you need to do is "fork" the repository, and then create a new branch in your fork and push the branch to your fork of the repository. Once you do that, the GitHub website will let you create a new pull request between tinyusb/master and your branch in the forked repository.