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

UHS_FS_NEW_DEMO crashing #46

Closed
marcio-ao opened this issue May 29, 2019 · 40 comments
Closed

UHS_FS_NEW_DEMO crashing #46

marcio-ao opened this issue May 29, 2019 · 40 comments

Comments

@marcio-ao
Copy link
Contributor

I am trying to run the UHS_FS_NEW_DEMO on an Tosduino MEGA 2560 (Arduino Mega compatible) with an Arduino USB Host Shield and it seems to crash during Init_Generic_Storage(&UHS_Usb);, as shown by this screen shot:

usb_rebooting

One of our engineers had made a small modification to the RESET pin of the Arduino shield, so I had to add the following bit of code to the start of the sketch:

void setup() {
  // MAX3421 reset pin on D7
  pinMode(7, OUTPUT);
  digitalWrite(7, LOW);
  delay(100);
  digitalWrite(7, HIGH);
  delay(100);
  ...
}

I presume this won't cause a problem, but I thought I would mention it, just in case. I'll try narrowing down where in Init_Generic_Storage the crash is happening.

@xxxajk
Copy link
Collaborator

xxxajk commented May 29, 2019 via email

@marcio-ao
Copy link
Contributor Author

marcio-ao commented May 29, 2019

No need to do a hardware reset on the max chip. Resetting is able to be done by commands on SPI. See the RM for details.

I'll have to ask why he did this, but I seem to recall it was recommended somewhere because apparently that pin wasn't properly connected on the shield and could cause issues.

The crash happens here:

for(int i = 0; i < MAX_USB_MS_DRIVERS; i++) {

/**
 * This must be called before using UHS USB Mass Storage. This works around a G++ bug.
 * Thanks to Lei Shi for the heads up.
 */

static void UHS_USB_BulkOnly_Init(UHS_USB_HOST_BASE *hd) {
        for(int i = 0; i < MAX_USB_MS_DRIVERS; i++) {
                UHS_USB_Storage[i] = new UHS_FS_BULK_DRIVER(hd, i);
       }
}

I'm a bit surprised to see "new" in Arduino code. This seems like it would be highly inefficient, considering we only have a couple kbytes of RAM.

@xxxajk
Copy link
Collaborator

xxxajk commented May 29, 2019 via email

@marcio-ao
Copy link
Contributor Author

Yeah, but notice that UHS3 comes with it's own ISR safe memory management...

My concern is with the overhead of heap management. I don't know what type of data structure is used for the heap, but I imagine it must have at least a few bytes per allocated block of overhead.

Anyhow, I guess at this point I just need to know why it is crashing. I am using Arduino 1.8.8, BTW.

@xxxajk
Copy link
Collaborator

xxxajk commented May 29, 2019

use avr boards 1.6.11 (boards manager) and see if that works.

@marcio-ao
Copy link
Contributor Author

When I downgrade to 1.6.11 via the boards manager, it fails to link:

Linking everything together...
/home/aleph/.arduino15/packages/arduino/tools/avr-gcc/4.8.1-arduino5/bin/avr-gcc -w -Os -Wl,--gc-sections,--relax -mmcu=atmega2560 -o /tmp/arduino_build_187361/UHS_FS_NEW_DEMO.ino.elf /tmp/arduino_build_187361/sketch/UHS_FS_NEW_DEMO.ino.cpp.o /tmp/arduino_build_187361/libraries/RTClib/RTClib.cpp.o /tmp/arduino_build_187361/libraries/RTClib/asc_store.c.o /tmp/arduino_build_187361/libraries/RTClib/asctime.c.o /tmp/arduino_build_187361/libraries/RTClib/asctime_r.c.o /tmp/arduino_build_187361/libraries/RTClib/ctime.c.o /tmp/arduino_build_187361/libraries/RTClib/ctime_r.c.o /tmp/arduino_build_187361/libraries/RTClib/daylight_seconds.c.o /tmp/arduino_build_187361/libraries/RTClib/difftime.c.o /tmp/arduino_build_187361/libraries/RTClib/dst_pointer.c.o /tmp/arduino_build_187361/libraries/RTClib/equation_of_time.c.o /tmp/arduino_build_187361/libraries/RTClib/fatfs_time.c.o /tmp/arduino_build_187361/libraries/RTClib/geo_location.c.o /tmp/arduino_build_187361/libraries/RTClib/gm_sidereal.c.o /tmp/arduino_build_187361/libraries/RTClib/gmtime.c.o /tmp/arduino_build_187361/libraries/RTClib/gmtime_r.c.o /tmp/arduino_build_187361/libraries/RTClib/isLeap.c.o /tmp/arduino_build_187361/libraries/RTClib/iso_week_date.c.o /tmp/arduino_build_187361/libraries/RTClib/iso_week_date_r.c.o /tmp/arduino_build_187361/libraries/RTClib/isotime.c.o /tmp/arduino_build_187361/libraries/RTClib/isotime_r.c.o /tmp/arduino_build_187361/libraries/RTClib/lm_sidereal.c.o /tmp/arduino_build_187361/libraries/RTClib/localtime.c.o /tmp/arduino_build_187361/libraries/RTClib/localtime_r.c.o /tmp/arduino_build_187361/libraries/RTClib/mk_gmtime.c.o /tmp/arduino_build_187361/libraries/RTClib/mktime.c.o /tmp/arduino_build_187361/libraries/RTClib/month_length.c.o /tmp/arduino_build_187361/libraries/RTClib/moon_phase.c.o /tmp/arduino_build_187361/libraries/RTClib/print_lz.c.o /tmp/arduino_build_187361/libraries/RTClib/set_dst.c.o /tmp/arduino_build_187361/libraries/RTClib/set_position.c.o /tmp/arduino_build_187361/libraries/RTClib/set_system_time.cpp.o /tmp/arduino_build_187361/libraries/RTClib/set_zone.c.o /tmp/arduino_build_187361/libraries/RTClib/solar_declination.c.o /tmp/arduino_build_187361/libraries/RTClib/solar_noon.c.o /tmp/arduino_build_187361/libraries/RTClib/strftime.c.o /tmp/arduino_build_187361/libraries/RTClib/sun_rise.c.o /tmp/arduino_build_187361/libraries/RTClib/sun_set.c.o /tmp/arduino_build_187361/libraries/RTClib/system_time.c.o /tmp/arduino_build_187361/libraries/RTClib/time.cpp.o /tmp/arduino_build_187361/libraries/RTClib/tm_store.c.o /tmp/arduino_build_187361/libraries/RTClib/utc_offset.c.o /tmp/arduino_build_187361/libraries/RTClib/week_of_month.c.o /tmp/arduino_build_187361/libraries/RTClib/week_of_year.c.o /tmp/arduino_build_187361/libraries/Wire/Wire.cpp.o /tmp/arduino_build_187361/libraries/Wire/utility/twi.c.o /tmp/arduino_build_187361/libraries/ISR_safe_memory/malloc.c.o /tmp/arduino_build_187361/libraries/ISR_safe_memory/mlock.c.o /tmp/arduino_build_187361/libraries/SPI/SPI.cpp.o /tmp/arduino_build_187361/libraries/UHS_ByteBuffer/UHS_ByteBuffer.cpp.o /tmp/arduino_build_187361/../arduino_cache_776507/core/core_arduino_avr_mega_cpu_atmega2560_75113dea4c28b702c789f24c1ec54ef2.a -L/tmp/arduino_build_187361 -lm
/home/aleph/.arduino15/packages/arduino/tools/avr-gcc/4.8.1-arduino5/bin/avr-objcopy -O ihex -j .eeprom --set-section-flags=.eeprom=alloc,load --no-change-warnings --change-section-lma .eeprom=0 /tmp/arduino_build_187361/UHS_FS_NEW_DEMO.ino.elf /tmp/arduino_build_187361/UHS_FS_NEW_DEMO.ino.eep
/home/aleph/.arduino15/packages/arduino/tools/avr-gcc/4.8.1-arduino5/bin/avr-objcopy -O ihex -R .eeprom /tmp/arduino_build_187361/UHS_FS_NEW_DEMO.ino.elf /tmp/arduino_build_187361/UHS_FS_NEW_DEMO.ino.hex
Using library RTClib in folder: /home/aleph/Arduino/libraries/RTClib (legacy)
Using library Wire at version 1.0 in folder: /home/aleph/.arduino15/packages/arduino/hardware/avr/1.6.11/libraries/Wire 
Using library UHS_host in folder: /home/aleph/Arduino/libraries/UHS_host (legacy)
Using library ISR_safe_memory in folder: /home/aleph/Arduino/libraries/ISR_safe_memory (legacy)
Using library SPI at version 1.0 in folder: /home/aleph/.arduino15/packages/arduino/hardware/avr/1.6.11/libraries/SPI 
Using library UHS_ByteBuffer in folder: /home/aleph/Arduino/libraries/UHS_ByteBuffer (legacy)
Using library UHS_FS in folder: /home/aleph/Arduino/libraries/UHS_FS (legacy)
/home/aleph/.arduino15/packages/arduino/tools/avr-gcc/4.8.1-arduino5/bin/avr-size -A /tmp/arduino_build_187361/UHS_FS_NEW_DEMO.ino.elf
Sketch uses 60038 bytes (23%) of program storage space. Maximum is 253952 bytes.
Global variables use 1870 bytes (22%) of dynamic memory, leaving 6322 bytes for local variables. Maximum is 8192 bytes.
/home/aleph/.arduino15/packages/arduino/tools/avrdude/6.0.1-arduino5/bin/avrdude -C/home/aleph/.arduino15/packages/arduino/tools/avrdude/6.0.1-arduino5/etc/avrdude.conf -v -patmega2560 -cwiring -P/dev/ttyACM0 -b115200 -D -Uflash:w:/tmp/arduino_build_187361/UHS_FS_NEW_DEMO.ino.hex:i 
/home/aleph/.arduino15/packages/arduino/tools/avrdude/6.0.1-arduino5/bin/avrdude: error while loading shared libraries: libreadline.so.6: cannot open shared object file: No such file or directory
An error occurred while uploading the sketch

@marcio-ao
Copy link
Contributor Author

Oh, wait, that looks like it is avrdude that is failing to run. Let me see if I can use something else to load the hex file.

@xxxajk
Copy link
Collaborator

xxxajk commented May 29, 2019

you may need to install 32bit compatibility libs...

@marcio-ao
Copy link
Contributor Author

I'm pretty sure if I ask the answer will be no. This is 2019...

What is it about the newer AVR stuff that is incompatible with this library? Even if I can get this particular example to work, if it requires older libs, then I'll run into integration problems later, so it's kind of a catch-22.

@xxxajk
Copy link
Collaborator

xxxajk commented May 29, 2019

I'm aware of that fact.
Basically I need to spend the time to resolve this issue.
For now, just try with the older one.
Also, I use 1.6.11 for production here, along with UHS3, which is actually used on mega2560.

@marcio-ao
Copy link
Contributor Author

I had to use the system copy of avrdude to flash the .hex file, but now it gets past the initialization. Woot!

Start.


USB HOST READY.
No media. Waiting to mount /

Oddly, inserting a USB drive does nothing. But at least it's getting closer... and it seems like at least I confirmed that the latest AVR stuff is having some adverse effects.

Basically I need to spend the time to resolve this issue.

Makes sense. And we can't really make any demands unless we hire you as a consultant and you are willing to do that :) But I have a couple weeks to determine whether it is feasible for us to make a new printer based on UHS3, so this is a good thing to know. Incompatibilities with current tools would definitely be a significant obstacle and would recommend against that.

Do you have any notion whether the AVR incompatibility is just with the FAT parsing stuff, or whether it affects the USB_HOST and BULK_STORAGE code too? If it were only the FAT code, we could still possibly proceed since my plans were to use the Marlin FAT code anyway.

@xxxajk
Copy link
Collaborator

xxxajk commented May 29, 2019 via email

@marcio-ao
Copy link
Contributor Author

Format the drive as fat, not ntfs? Also, may take a few moments to mount the volume.

Linux identifies it as vfat. Is that compatible?

Anyhow, I don't think it's a file system issue. Here is what it shows when I enable the code to show state:

Start.


USB HOST READY.
USB HOST state 1d
No media. Waiting to mount /
USB HOST state 02
USB HOST state 0a
USB HOST state 03
USB HOST state 0c
USB HOST state f0

I'll dig further, but I bet the drive is returning NAKs. If that is the case, then it is the same issue I was seeing before when I tried running UHS3 inside Marlin. This is both good and bad news. It's good news in that it seems like the issue is reproducible outside of Marlin, so my integration work must not the the cause; but the bad news is we still don't know why our drives get stuck in this odd state. And of course it's equally puzzling why UHS2.0 running on 32-bit is able to mount them. The plot thickens...

@xxxajk
Copy link
Collaborator

xxxajk commented May 29, 2019 via email

@marcio-ao
Copy link
Contributor Author

We have some Lulzbot branded USB sticks that we ship with our TAZ Pros. I've tried a 3rd-party one too and it does not work either, but it fails in a different way. Even if these particular sticks are particularly finicky, we've kind of gotten ourselves in a pickle since we've shipped hundreds of printers with them, so if they suddenly don't work after a firmware upgrade, customers will not be happy.

I feel slowly we are learning more and more. I feel this is one of those situations where multiple factors are conspiring to make it a particularly hard to nail down problem. Thank you for the patience with me!

@xxxajk
Copy link
Collaborator

xxxajk commented May 29, 2019 via email

@marcio-ao
Copy link
Contributor Author

@xxxajk: I would definitely appreciate it, but again, don't feel you have to take time away from your other projects. You've done quite enough already :)

@marcio-ao
Copy link
Contributor Author

@xxxajk: Are you able to gleam anything from these debug logs?

Pass SPI speed 25000000

USB HOST READY.
USB HOST state 01
UHS_USB_HOST_STATE_DEBOUNCE

BEFORE CDIRQ T BEIRQ T resetting F state 0x02

AFTER CDIRQ T BEIRQ T resetting F state 0x02
No media. Waiting to mount /
USB HOST state 02
UHS_USB_HOST_STATE_DEBOUNCE
UHS_USB_HOST_STATE_DEBOUNCE_NOT_COMPLETE
USB HOST state 0a
UHS_USB_HOST_STATE_RESET_DEVICE
UHS_USB_HOST_STATE_RESET_NOT_COMPLETE
UHS_USB_HOST_STATE_RESET_NOT_COMPLETE
UHS_USB_HOST_STATE_RESET_NOT_COMPLETE
UHS_USB_HOST_STATE_RESET_NOT_COMPLETE
UHS_USB_HOST_STATE_RESET_NOT_COMPLETE
UHS_USB_HOST_STATE_RESET_NOT_COMPLETE
UHS_USB_HOST_STATE_RESET_NOT_COMPLETE
UHS_USB_HOST_STATE_RESET_NOT_COMPLETE
UHS_USB_HOST_STATE_RESET_NOT_COMPLETE
UHS_USB_HOST_STATE_RESET_NOT_COMPLETE
UHS_USB_HOST_STATE_RESET_NOT_COMPLETE
UHS_USB_HOST_STATE_RESET_NOT_COMPLETE
UHS_USB_HOST_STATE_RESET_NOT_COMPLETE
UHS_USB_HOST_STATE_RESET_NOT_COMPLETE
UHS_USB_HOST_STATE_RESET_NOT_COMPLETE

BEFORE CDIRQ T BEIRQ T resetting F state 0x03

AFTER CDIRQ T BEIRQ T resetting F state 0x03
UHS_USB_HOST_STATE_WAIT_BUS_READY

Configuring: parent = 0, port = 1, speed = 1

Configuring PktSize 0x40,  rcode: 0x00, retries 0,
ep entry for interface 0 ep 0 max packet size = 64

dispatchPkt rcode: 0
ctrlReq2: left: 64, read:64, nbytes 64
ctrlReqRead left: 64
Requesting 64 bytes 
dispatchPkt nak_count:1
dispatchPkt rcode: 0
Got 18 bytes 
ctrlReqRead left: 46, read 18
ctrlReq2: left: 46, read:64, nbytes 64
ctrlReqRead left: 46
Requesting 64 bytes 
dispatchPkt nak_count:1
dispatchPkt rcode: 0
Got 0 bytes 
ctrlReqRead left: 46, read 0
ctrlReq2: left: 46, read:64, nbytes 64
ctrlReqRead left: 46
Requesting 64 bytes 
dispatchPkt nak_count:1
dispatchPkt rcode: 0
Got 0 bytes 
ctrlReqRead left: 46, read 0
ctrlReq2: left: 46, read:64, nbytes 64
ctrlReqRead left: 46
Requesting 64 bytes 
dispatchPkt nak_count:1

...

What stands out to me is the fact that the host seems to be requesting 64 bytes as part of the ctrlReq, but the device only replies with 18 bytes once, then subsequently replies with 0 bytes. UHS_USB_HOST_BASE::ctrlReq gets stuck in a loop here because "left" never decrements down to zero.

It seems like getting zero bytes is an abnormal condition and ctrlReq should somehow detect and do something to break out of the loop. Any thoughts?

@marcio-ao
Copy link
Contributor Author

I discussed this with one of my co-workers who is fiddling with UHS2.0 and he pointed out that device descriptors are 18 bytes. This jives with what I was seeing above. It seems like this particular drive will only transfer 18 bytes, no more, and UHS3.0 is expecting more.

I made a small change to the code:

uint8_t UHS_USB_HOST_BASE::ctrlReq(uint8_t addr, uint64_t Request, uint16_t nbytes, uint8_t* dataptr) {
        ...
        if(dataptr != NULL) {
                //data stage
                if((rt & 0x80) == 0x80) {
                        //IN transfer
                        while(left) {
                                // Bytes read into buffer
                                uint16_t read = nbytes;
                                HOST_DEBUG("ctrlReq2: left: %i, read:%i, nbytes %i\r\n", left, read, nbytes);
                                rcode = ctrlReqRead(pep, &left, &read, nbytes, dataptr);
                                if(read == 0) return 0; // I added this
                                if(rcode) {
                                        return rcode;
                                }
                          ...
                        }
                } else {
                        // OUT transfer
                        rcode = OutTransfer(pep, 0, nbytes, dataptr);
                }
                if(rcode) {
                        //return error
                        return ( rcode);
                }
        }

        ...
        return rcode;
}

Now, when I run the code with this particular drive, I get something way more promising:

Start.
 HOST state 60
Start.


USB HOST READY.
USB HOST state 1d
No media. Waiting to mount /
USB HOST state 02
USB HOST state 0a
USB HOST state 0d
/ mounted.
Removing '/HeLlO.tXt' file... completed with 4

Starting Write test...
File opened OK, fd = 1
Wrote 19 bytes, File closed result = 0.

Starting Read test...
File opened OK, fd = 1, displaying contents...
]-[ello \/\/orld!

Read completed, last read result = -1 (20), file close result = 0.
Testing rename
file rename result = 0.

Removing '/1MB.bin' file... completed with 0
1MB write timing test  2048 writes, (0), (0),  9656 ms (10 sec)
completed with 0
1MB read timing test 2048 reads, (20),  10585 ms (11 sec)
completed with 0
Directory of '/'
-rw--a      4057591 2018-09-19 16:33:00 STEAK_~1.GCO (Steak_QUIVER_DUAL.gcode)
-rw--a        19897 2018-09-25 14:45:26 TOOLHE~1.GCO (toolhead_longevity.gcode)
-rw--a       218812 2018-09-26 13:22:16 TOOLHE~2.GCO (toolhead_longevity_2540.gcode)
-rw--a       875182 2018-11-02 21:24:18 TOOLHE~3.GCO (toolhead_longevity_100hrs.gcode)
-rw--a      4839359 2018-09-12 13:58:14 MOAI_D~1.GCO (Moai_dual_Marlin_offsets.gcode)
-rw--a        27937 2018-11-02 17:07:24 TEST_2~1.GCO (TEST_2.gcode)
-rw--a      1048576 2019-06-29 14:20:50 1MB.bin
-rw--a           19 2019-06-29 14:20:40 newtest.txt
4007010304 bytes available on disk.

Flushing caches...
Remove and insert media...
USB HOST state 60

So, success!

@marcio-ao
Copy link
Contributor Author

Just to sort of wrap things up, with this change, UHS3.0 seems to work fine on our Mini 2 (8-bit board) as well as our 32-bit board (TAZ Pro) when using software SPI for the color LCD panel. Trying to use hardware SPI for the color LCD panel crashes the machine, but this is expected due to the fact that UHS3.0 is using interrupts. Earlier you said that wrapping everything up with begin/endTransaction should fix that problem, so I guess that's my next step.

@xxxajk
Copy link
Collaborator

xxxajk commented May 30, 2019

Yes, they are 18 bytes. Last I checked everything worked here.
Might be a drive quirk. If so there is a better way to handle it, but you have found the root of the problem.

SPI sharing won't be a problem once you guard the remaining SPI code.
If you got official USB shields, you can use up to two of them. There should be an example.

@marcio-ao
Copy link
Contributor Author

Might be a drive quirk. If so there is a better way to handle it, but you have found the root of the problem.

One thing I notice is that "ctrlReq" is called from a lot of places, so my fix of returning success (0) when a short read happens is probably not correct for anything other than descriptors, and even then, it is probably only a success if the drive returns exactly 18 bytes.

So could I ask you a favor? Could you look at the code and perhaps come up with a better way of handling the situation? Perhaps look at UHS2.0 and see what is happening there? I imagine the fix will either be requesting only 18 bytes (if that is possible) when reading descriptors, or having a way in which "ctrlReq" can report how many bytes were actually read and then the code for reading device descriptors could treat it as a success if exactly 18 bytes were read, while all other code using ctrlReq would treat short reads as errors.

It may well be a quirk of these particular drives, but for maximum compatibility, the code needs to be resilient to known bad implementations out there. I recall reading somewhere that a large part of the driver code in Windows is about working around poor implementations of standards in devices...

@xxxajk
Copy link
Collaborator

xxxajk commented May 30, 2019

Actually, part of the "bad behavior" is because of how older versions of windows did USB.
There was a bug that did strange things that some companies thought of as "how it should work" instead of reading the actual spec.Some companies still do this stupid thing today, and it is very annoying.
Going to take a short break here from work and take a look at what is going on.

@xxxajk
Copy link
Collaborator

xxxajk commented May 30, 2019

1: Update RTClib, pushed a fix
2: Tested here and works for me...

Please try the following:
in the demo, add

#define UHS_DEVICE_WINDOWS_USB_SPEC_VIOLATION_DESCRIPTOR_DEVICE 0

See if that makes a difference.

@xxxajk
Copy link
Collaborator

xxxajk commented May 30, 2019

Also, what MCU is giving the problem exactly? AVR? ARM? MIPS?

@marcio-ao
Copy link
Contributor Author

AVR.

I'll test UHS_DEVICE_WINDOWS_USB_SPEC_VIOLATION_DESCRIPTOR_DEVICE. You want me to remove my patch and test with UHS_DEVICE_WINDOWS_USB_SPEC_VIOLATION_DESCRIPTOR_DEVICE. Is this correct?

@xxxajk
Copy link
Collaborator

xxxajk commented May 30, 2019

Here's what the startup should look like:

Start.


USB HOST READY.
No media. Waiting to mount /



Configuring: parent = 0, port = 1, speed = 1


Configuring PktSize 0x40,  rcode: 0x00, retries 0,
ep entry for interface 0 ep 0 max packet size = 64
ctrlReq2: left: 64, read:64, nbytes 64
ctrlReq3: acceptBuffer sz 18 nbytes 64 left 46

ep entry for interface 0 ep 0 max packet size = 64
0 retries.
DevDescr 2nd poll, bMaxPacketSize0:64
ep entry for interface 15 ep 0 max packet size = 64
ctrlReq2: left: 18, read:18, nbytes 18
ep entry for interface 0 ep 0 max packet size = 64
0 retries.
configs: 1
ep entry for interface 0 ep 0 max packet size = 64
ctrlReq2: left: 9, read:9, nbytes 9
CONFIGURATION: 0, bNumInterfaces 1, wTotalLength 39
ep entry for interface 0 ep 0 max packet size = 64
bLength: 9 bDescriptorType: 02
eating 8
bLength: 9 bDescriptorType: 04
INTERFACE DESCRIPTOR FOUND
Getting 3 endpoints
bLength: 7 bDescriptorType: 05
ENDPOINT DESCRIPTOR: 0
ENDPOINT DESCRIPTOR OK
eating 0
bLength: 7 bDescriptorType: 05
ENDPOINT DESCRIPTOR: 1
ENDPOINT DESCRIPTOR OK
eating 0
bLength: 7 bDescriptorType: 05
ENDPOINT DESCRIPTOR: 2
ENDPOINT DESCRIPTOR OK
eating 0
eating 1
ENDPOINT DESCRIPTORS FILLED
TestInterface VID:0718 PID:0065 Class:00 Subclass:00 Protocol 00
Interface data: Class:08 Subclass:06 Protocol 06, number of endpoints 3
Parent: 00, bAddress: 01
Driver 1 supports this interface
Driver 1 can be used for this interface
USB_INTERFACE END OF STREAM
ep entry for interface 0 ep 0 max packet size = 64
ctrlReq2: left: 9, read:9, nbytes 9
CONFIGURATION: 1, bNumInterfaces 1, wTotalLength 39
Best configuration is 1, enumerating interfaces.
ep entry for interface 0 ep 0 max packet size = 64
bLength: 9 bDescriptorType: 02
eating 8
bLength: 9 bDescriptorType: 04
INTERFACE DESCRIPTOR FOUND
Getting 3 endpoints
bLength: 7 bDescriptorType: 05
ENDPOINT DESCRIPTOR: 0
ENDPOINT DESCRIPTOR OK
eating 0
bLength: 7 bDescriptorType: 05
ENDPOINT DESCRIPTOR: 1
ENDPOINT DESCRIPTOR OK
eating 0
bLength: 7 bDescriptorType: 05
ENDPOINT DESCRIPTOR: 2
ENDPOINT DESCRIPTOR OK
eating 0
eating 1
ENDPOINT DESCRIPTORS FILLED
AttemptConfig: parent = 0, port = 1
Driver 1 supports this interface
Interface Configured
ep entry for interface 0 ep 0 max packet size = 64
Driver 0 @ 00 Skipped
Driver 1 @ 01 Initialize
ep entry for interface 188 ep 0 max packet size = 64
ctrlReq2: left: 1, read:1, nbytes 1
outTransfer: addr: 0x01 ep: 0x02 nbytes: 0x001f data: 0x0x2094
ep entry for interface 0 ep 2 max packet size = 64
outTransfer: SetAddress 0x00
ep entry for interface 0 ep 1 max packet size = 64
ep entry for interface 0 ep 1 max packet size = 64
outTransfer: addr: 0x01 ep: 0x02 nbytes: 0x001f data: 0x0x2094
ep entry for interface 0 ep 2 max packet size = 64
outTransfer: SetAddress 0x00
ep entry for interface 0 ep 1 max packet size = 64
outTransfer: addr: 0x01 ep: 0x02 nbytes: 0x001f data: 0x0x208f
ep entry for interface 0 ep 2 max packet size = 64
outTransfer: SetAddress 0x00
ep entry for interface 0 ep 1 max packet size = 64
outTransfer: addr: 0x01 ep: 0x02 nbytes: 0x001f data: 0x0x2080
ep entry for interface 0 ep 2 max packet size = 64
outTransfer: SetAddress 0x00
ep entry for interface 0 ep 1 max packet size = 64
ep entry for interface 0 ep 1 max packet size = 64
outTransfer: addr: 0x01 ep: 0x02 nbytes: 0x001f data: 0x0x1fb5
ep entry for interface 0 ep 2 max packet size = 64
outTransfer: SetAddress 0x00
ep entry for interface 0 ep 1 max packet size = 64
ep entry for interface 0 ep 1 max packet size = 64
outTransfer: addr: 0x01 ep: 0x02 nbytes: 0x001f data: 0x0x2084
ep entry for interface 0 ep 2 max packet size = 64
outTransfer: SetAddress 0x00
ep entry for interface 0 ep 1 max packet size = 64
Total endpoints = (3)3
Driver 2 @ 00 Skipped
Driver 3 no driver at this index.
Driver 4 no driver at this index.
Driver 5 no driver at this index.
Driver 6 no driver at this index.
Driver 7 no driver at this index.
Driver 8 no driver at this index.
Driver 9 no driver at this index.
Driver 10 no driver at this index.
Driver 11 no driver at this index.
Driver 12 no driver at this index.
Driver 13 no driver at this index.
Driver 14 no driver at this index.
Driver 15 no driver at this index.

At this point, things are ready to roll, and the probe and automount happens.

utTransfer: addr: 0x01 ep: 0x02 nbytes: 0x001f data: 0x0x2168
ep entry for interface 0 ep 2 max packet size = 64
outTransfer: SetAddress 0x00
ep entry for interface 0 ep 1 max packet size = 64
outTransfer: addr: 0x01 ep: 0x02 nbytes: 0x001f data: 0x0x1f1a
ep entry for interface 0 ep 2 max packet size = 64
outTransfer: SetAddress 0x00
ep entry for interface 0 ep 1 max packet size = 64
ep entry for interface 0 ep 1 max packet size = 64
outTransfer: addr: 0x01 ep: 0x02 nbytes: 0x001f data: 0x0x1e09
ep entry for interface 0 ep 2 max packet size = 64
outTransfer: SetAddress 0x00
ep entry for interface 0 ep 1 max packet size = 64
ep entry for interface 0 ep 1 max packet size = 64
outTransfer: addr: 0x01 ep: 0x02 nbytes: 0x001f data: 0x0x1dd6
ep entry for interface 0 ep 2 max packet size = 64
outTransfer: SetAddress 0x00
ep entry for interface 0 ep 1 max packet size = 64
ep entry for interface 0 ep 1 max packet size = 64
outTransfer: addr: 0x01 ep: 0x02 nbytes: 0x001f data: 0x0x1dbe
ep entry for interface 0 ep 2 max packet size = 64
outTransfer: SetAddress 0x00
ep entry for interface 0 ep 1 max packet size = 64
ep entry for interface 0 ep 1 max packet size = 64
outTransfer: addr: 0x01 ep: 0x02 nbytes: 0x001f data: 0x0x1dce
ep entry for interface 0 ep 2 max packet size = 64
outTransfer: SetAddress 0x00
ep entry for interface 0 ep 1 max packet size = 64
ep entry for interface 0 ep 1 max packet size = 64
/ mounted.

@xxxajk
Copy link
Collaborator

xxxajk commented May 30, 2019

Yes, with a pure pull, please.
Also, add the following two lines to get the above output from UHS_FS_NEW_DEMO
#define DEBUG_PRINTF_EXTRA_HUGE 1
#define DEBUG_PRINTF_EXTRA_HUGE_UHS_HOST 1

@marcio-ao
Copy link
Contributor Author

Without UHS_DEVICE_WINDOWS_USB_SPEC_VIOLATION_DESCRIPTOR_DEVICE:

USB HOST READY.
USB HOST state 01
No media. Waiting to mount /
USB HOST state 02
USB HOST state 0a



Configuring: parent = 0, port = 1, speed = 1


Configuring PktSize 0x40,  rcode: 0x00, retries 0,
ep entry for interface 0 ep 0 max packet size = 64
ctrlReq2: left: 64, read:64, nbytes 64
ctrlReq2: left: 46, read:64, nbytes 64
ctrlReq2: left: 46, read:64, nbytes 64
Configuring error: 0x01 Can't get USB_DEVICE_DESCRIPTOR
USB HOST state f0

With UHS_DEVICE_WINDOWS_USB_SPEC_VIOLATION_DESCRIPTOR_DEVICE:

USB HOST READY.
USB HOST state 1d
No media. Waiting to mount /
USB HOST state 02
USB HOST state 0a



Configuring: parent = 0, port = 1, speed = 1


Configuring PktSize 0x40,  rcode: 0x00, retries 0,
ep entry for interface 0 ep 0 max packet size = 64
ctrlReq2: left: 64, read:64, nbytes 64
ctrlReq2: left: 46, read:64, nbytes 64
ctrlReq2: left: 46, read:64, nbytes 64
Configuring error: 0xf0 Can't get USB_DEVICE_DESCRIPTOR
USB HOST state f0

i.e. no change.

@marcio-ao
Copy link
Contributor Author

The above is what happens using one drive (call it the "black" drive). With the "blue" drive, I get an infinite loop (the following is with UHS_DEVICE_WINDOWS_USB_SPEC_VIOLATION_DESCRIPTOR_DEVICE):

USB HOST READY.
USB HOST state 1d
No media. Waiting to mount /
USB HOST state 02
USB HOST state 0a



Configuring: parent = 0, port = 1, speed = 1


Configuring PktSize 0x40,  rcode: 0x00, retries 0,
ep entry for interface 0 ep 0 max packet size = 64
ctrlReq2: left: 64, read:64, nbytes 64
ctrlReq2: left: 46, read:64, nbytes 64
ctrlReq2: left: 46, read:64, nbytes 64
ctrlReq2: left: 46, read:64, nbytes 64
ctrlReq2: left: 46, read:64, nbytes 64
ctrlReq2: left: 46, read:64, nbytes 64
ctrlReq2: left: 46, read:64, nbytes 64
ctrlReq2: left: 46, read:64, nbytes 64
ctrlReq2: left: 46, read:64, nbytes 64
ctrlReq2: left: 46, read:64, nbytes 64

...

Both the black and blue drives appear to be from the same vendor, although one is branded with our logo, and one isn't (I presume it was a sample from the manufacturer).

@marcio-ao
Copy link
Contributor Author

For what it is worth, one of the drives is labeled "VICFüN". It appears to be these guys: https://www.amazon.com/VICFUN-10pcs-Drives-Sticks-Drive-Black/dp/B00UALPCFW

@marcio-ao
Copy link
Contributor Author

"COMPATIBILITY AND HIGH PERFORMANCE - plug and use, unplug and go, support Win7/8/10 /Vista/XP/2000/ME/NT Linux and Mac OS, support USB 2.0 and backwards, support TV, speakers with USB slots, support share around"

... it's totally compatible. It even supports share around ;)

@marcio-ao
Copy link
Contributor Author

marcio-ao commented May 30, 2019

It looks like the blue drive is a 4GB, while the black one is 8GB. I also have a 16GB. It behaves like the 8GB:

Start.

USB HOST READY.
USB HOST state 1d
No media. Waiting to mount /
USB HOST state 02
USB HOST state 0a

Configuring: parent = 0, port = 1, speed = 1

Configuring PktSize 0x40,  rcode: 0x00, retries 0,
ep entry for interface 0 ep 0 max packet size = 64
ctrlReq2: left: 64, read:64, nbytes 64
ctrlReq2: left: 46, read:64, nbytes 64
Configuring error: 0x01 Can't get USB_DEVICE_DESCRIPTOR
USB HOST state f0

Anyhow, in short, it seems like all the VICFuN drives behave somewhat similarly, but the 4GB has the special wrinkle of getting the code into an infinite loop. I assume they changed the FW in the 8GB and 16GB to eventually return some sort of error to tell the host no more bytes were available.

@marcio-ao
Copy link
Contributor Author

I have a "Datastick Pro by Centron" and it behaves similarly:

Start.


USB HOST READY.
USB HOST state 01
No media. Waiting to mount /
USB HOST state 02
USB HOST state 0a



Configuring: parent = 0, port = 1, speed = 1


Configuring PktSize 0x40,  rcode: 0x00, retries 0,
ep entry for interface 0 ep 0 max packet size = 64
ctrlReq2: left: 64, read:64, nbytes 64
ctrlReq2: left: 46, read:64, nbytes 64
ctrlReq2: left: 46, read:64, nbytes 64
Configuring error: 0x01 Can't get USB_DEVICE_DESCRIPTOR
USB HOST state f0

@xxxajk
Copy link
Collaborator

xxxajk commented May 30, 2019

I'll email you the needed details to get the stick to me. This is a deep quirk.

@marcio-ao
Copy link
Contributor Author

Okay. I'll see what I can do. We only have one of the blue drives, so we're a little reluctant to part with it, but I think if you manage to figure out what is happening with the black drives, it will probably fix it for the blue drive as well.

@xxxajk
Copy link
Collaborator

xxxajk commented May 31, 2019

Pushed something that might work.
Let me know.

@xxxajk
Copy link
Collaborator

xxxajk commented Jul 17, 2019

Identified as a USB host hardware implementation bug.
Solutions taht we discussed:
Use different stick on custom hardware.
Use a passive USB VBUS power conditioner.
Fix the design.
Close it?

@marcio-ao
Copy link
Contributor Author

@xxxajk: Well, the software fix we came up with solved the problem. No hardware fixes needed.

@marcio-ao
Copy link
Contributor Author

@xxxajk: I think we may be referring to two separate problems. We were able to solve one of them with the change to UHS_DEVICE_WINDOWS_USB_SPEC_VIOLATION_DESCRIPTOR_DEVICE. The hardware fix was adding a cap to VBUS. Our EE is back in today and I forwarded the suggestion.

Anyhow, either way, I think this ticket can be closed.

This issue was closed.
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

2 participants