USBHost_t36 USB Mass Storage Driver Experiments

notice the sector count?

Looks like it's being printed as a signed 32-bit int when it should be unsigned. -387938129 = 0xE8E088AF = 3,907,029,167 sectors. Multiply by 512 bytes per sector = 2000398933504 bytes which matches the reported capacity.
 
Ok did some testing with MTP (writing/reading files and transferring files) and all worked fine with that change.

Drives tested so far:
1. Crucial MX500 500GB 3D NAND SATA 2.5 Inch Internal SSD, up to 560MB/s - CT500MX500SSD1
2. INDMEM mSATA SSD 256GB Internal Mini SATA III SSD Micro-SATA TLC 3D NAND Flash 256 GB
3. HP SSD S 600 120GB


4. Silicon Power 2TB Rugged Portable External Hard Drive Armor A30:
This was a strange one:
Code:
       connected: 1
     initialized: 1
   USB Vendor ID: 174c
  USB Product ID: 55aa
      HUB Number: 0
        HUB Port: 0
  Device Address: 1
Removable Device: NO
        VendorID: PHD 3.0 
       ProductID: Silicon-Power   
      RevisionID: 0   
         Version: 6
    Sector Count:[COLOR="#FF0000"] -387938129[/COLOR]
     Sector size: 512
   Disk Capacity: 2000398933504 Bytes
notice the sector count?

PS did find adding a delay(500) allowed the drive to come on line
Code:
  while (!myDrive) {
    myusb.Task();
  }
[COLOR="#FF0000"]delay(500)[/COLOR];

Thanks for testing:) I'll test more of my devices and issue an appropriate PR.
 
Thanks for testing:) I'll test more of my devices and issue an appropriate PR.

Thanks for digging and finding the issue!!!!! I had the easy part. Oh of course I tested the three sansdisk drives I had as I previously mentioned.
 
Quick update:

The problem child (SDCZ73-032G-G46) that "works now"
https://www.amazon.com/dp/B01FTQP7ZM?psc=1

I was able to transfer a 6.44mb file to it, but it took probably over a minute to complete.

As compared to an SSD I recently purchased to test...
https://www.amazon.com/gp/product/B095P3ZT2B
which is installed onto:
https://www.amazon.com/gp/product/B07VP2WH73

Which maybe took something like 7 seconds for MTP to transfer to the SSD.

I also tried it with another 8gb stick enfain (USB 2) Probably: https://www.amazon.com/Enfain-Delivering-presentations-Promotional-Distribution/dp/B00HQWLHIE
same file took maybe 15 seconds.

EDIT: I also tried with Kingston SSD https://www.amazon.com/gp/product/B01N6JQS8C
connected using: https://www.amazon.com/gp/product/B00HJZJI84
And again in the 7 to 8 second range of time to copy the file
 
Quick update:

The problem child (SDCZ73-032G-G46) that "works now"
https://www.amazon.com/dp/B01FTQP7ZM?psc=1

I was able to transfer a 6.44mb file to it, but it took probably over a minute to complete.

As compared to an SSD I recently purchased to test...
https://www.amazon.com/gp/product/B095P3ZT2B
which is installed onto:
https://www.amazon.com/gp/product/B07VP2WH73

Which maybe took something like 7 seconds for MTP to transfer to the SSD.

I also tried it with another 8gb stick enfain (USB 2) Probably: https://www.amazon.com/Enfain-Delivering-presentations-Promotional-Distribution/dp/B00HQWLHIE
same file took maybe 15 seconds.

Seeing the same issue with copying large files to those drives from the PC. Just copied a 12gb directory to the drive and took like 10 minutes
 
Thank you all for your effort, I'm a bit lost, what is the change to finally make? Tomorrow I'll have access to the teensy 4.1 to try all the drives that didn't work for me until now.
 
@KurtE @mjs512 - Decided to just comment out "msReset()" call. Updated my version of USBHost_t36 with @PaulStoffregen version and did a PR for it and extending the timeouts defined in "msc.h".

Glad to see a lot of the problem USB drives are working now:) Sorry it took so long to discover the problem...
 
I am still sort of curious on the speed of these drives:
So put an elapsedMillis into the sendObject code, and at the end (debug >= 1)
Code:
  printf("SendObject complete size:%u dt:%u\n", size, (uint32_t)emSendObject);

First run: Kingston SSD 240gb
SendObject complete size:6754230 dt:5839

Newer 250GB SSD
SendObject complete size:6754230 dt:5096

Old 8 GB Stick:
SendObject complete size:6754230 dt:8429

New 32 GB USB 3 stick:
SendObject complete size:6754230 dt:75461

So like 9 times slower than old stick and like 15 times slower than the SSDs

None of these was running using a HB, the SSDs are running and they have the USB3 connector (blue)
 
Is it just me or are there major race conditions in ehci.cpp? Lots of list manipulation happening without interrupts disabled and isr() being triggered can easily modify those same lists...

As a basic example, look at USBDriverTimer::Start(). Imagine there's already one active timer, so our timer will be added after it. Instruction flow reaches line 512 and the timer interrupt triggers for the already active timer; when the interrupt handler returns, our timer gets added after the now retired timer and will never be triggered.
 
Hi, thank you again, both Sandisk drives working now, CSW error is gone, but Kingston Datatraveler G2 keeps initializing infinitely as shown here. Maybe the unit is too old and is faulty but works on Windows, what I've noticed is when I plug into PC the led light flashes, aswell when writing/reading, but not when I plug into teensy even being detected and reported in log.
 
@KurtE @mjs512 - Decided to just comment out "msReset()" call. Updated my version of USBHost_t36 with @PaulStoffregen version and did a PR for it and extending the timeouts defined in "msc.h".

Glad to see a lot of the problem USB drives are working now:) Sorry it took so long to discover the problem...

@wwatson - sounds good and again glad you tracked it down and it was a easy fix.
 
Is it just me or are there major race conditions in ehci.cpp? Lots of list manipulation happening without interrupts disabled and isr() being triggered can easily modify those same lists...

As a basic example, look at USBDriverTimer::Start(). Imagine there's already one active timer, so our timer will be added after it. Instruction flow reaches line 512 and the timer interrupt triggers for the already active timer; when the interrupt handler returns, our timer gets added after the now retired timer and will never be triggered.

I understand what you are saying, but at least in many of these cases it may depend on who and how these methods are called. For example if you look in Serial.cpp,
where the txTimer is used.

Whenever we start or stop the timer, there hopefully is code in it like:
Code:
	NVIC_DISABLE_IRQ(IRQ_USBHS);
	txtimer.stop();  		// Stop longer timer.
	txtimer.start(100);		// Start a mimimal timeout
//	timer_event(nullptr);   // Try calling direct - fails to work 
	NVIC_ENABLE_IRQ(IRQ_USBHS);
So it disables the USB interrupt while it is mucking with the stuff.

I believe Paul originally set it up, this way and I then when I was working on Serial, I continued to do it how the earlier code was.

We could use sledgehammer and turn off all interrupts.

But we may not always know the context of how it is going to be called. That is, OK easy to disable all interrupts or specific interrupt, but now always sure it is OK to enable them afterwords. That is the change to the timer may only a part of changing a logical state.

Hope that makes sense
 
I understand what you are saying, but at least in many of these cases it may depend on who and how these methods are called. For example if you look in Serial.cpp,
where the txTimer is used.

Whenever we start or stop the timer, there hopefully is code in it like:
Code:
	NVIC_DISABLE_IRQ(IRQ_USBHS);
	txtimer.stop();  		// Stop longer timer.
	txtimer.start(100);		// Start a mimimal timeout
//	timer_event(nullptr);   // Try calling direct - fails to work 
	NVIC_ENABLE_IRQ(IRQ_USBHS);
So it disables the USB interrupt while it is mucking with the stuff.

I believe Paul originally set it up, this way and I then when I was working on Serial, I continued to do it how the earlier code was.
The mass storage code definitely isn't doing anything like that, data transfers are being queued with interrupts enabled which means there is the potential for list corruption (due to the interrupt service routine modifying the lists while they're being updated). I don't think it should be the responsibility of the individual USB device drivers to handle that; the lists are private to the host controller so the proper place would be in ehci.cpp.

We could use sledgehammer and turn off all interrupts.

But we may not always know the context of how it is going to be called. That is, OK easy to disable all interrupts or specific interrupt, but now always sure it is OK to enable them afterwords. That is the change to the timer may only a part of changing a logical state.

Hope that makes sense

Saving+clearing then restoring bit 7 of SREG (which is an AVR register but emulated in code for Teensy) is one way of disabling global interrupts without unconditionally turning them on at the end. Or else it's easy to make a reference counting class to disable/restore the state of the USBHS interrupt in the NVIC registers.
 
Sorry, I am just trying to be pragmatic here and go with the flow.

As I mentioned, I have tried to keep things within the ways that Paul has used in some of these areas. And with the case you mentioned, tried to show where that should be currently handled. In other setups I would probably use things like semaphores and the like, but ...

Now if someone comes up with a better solution, that for example makes it easier and does not impact other things like the latency for higher priority interrupts, like maybe those who service the Audio board and Paul agrees, with it, I will happily adapt to the new...

In the meantime, if you know of specific places in the code which are currently at risk, please point those out, and hopefully we can plug the holes.

Thanks again!

P.S. - Before you mention it. Yes there should be better documentation for things like this. I just don't know where to put it. Readme file is one obvious place, however I don't believe Teensyduino installs the readme files for the different libraries it installs.
(It appears there are Readme files now...)

EDIT: One area I earlier suspected for unprotected structures was calls like:
queue_Data_Transfer(datapipeOut, CBW, sizeof(msCommandBlockWrapper_t), this); // Command stage.

Which we may need to look into:
Two cases:

a) The calls are made from within the ISR... in which case we are safe as the ISR will not be called again until we return. I think this is most of them.

b) Not within ISR... These we should for sure look at.
 
Last edited:
however I don't believe Teensyduino installs the readme files for the different libraries it installs.
...loads of ReadMe.txt and other text/help files in my Teensy Libraries stored in C:\Program Files (x86)\Arduino\hardware\teensy\avr\libraries.
 
...loads of ReadMe.txt and other text/help files in my Teensy Libraries stored in C:\Program Files (x86)\Arduino\hardware\teensy\avr\libraries.
You are right... For awhile, I did not see ones from some libraries I have worked on... like FlexIO... But it is there now
Thanks
 
I am still sort of curious on the speed of these drives:
So put an elapsedMillis into the sendObject code, and at the end (debug >= 1)
Code:
  printf("SendObject complete size:%u dt:%u\n", size, (uint32_t)emSendObject);

First run: Kingston SSD 240gb
SendObject complete size:6754230 dt:5839

Newer 250GB SSD
SendObject complete size:6754230 dt:5096

Old 8 GB Stick:
SendObject complete size:6754230 dt:8429

New 32 GB USB 3 stick:
SendObject complete size:6754230 dt:75461

So like 9 times slower than old stick and like 15 times slower than the SSDs

None of these was running using a HB, the SSDs are running and they have the USB3 connector (blue)

@wwatson @mjs513 @defragster and all

I hacked up the USB_MTP-logger.ino sketch and added a write file test. Pretty primitive:
Code:
void test_write_file(int ch) {
  test_file_write_size = CommandLineReadNextNumber(ch, test_file_write_size);
  test_file_size = CommandLineReadNextNumber(ch, test_file_size);
  if (ch >= ' ') {
    Serial.setTimeout(0);
    int cb = Serial.readBytesUntil( '\n', test_file_name, sizeof(test_file_name));
  }
  File testFile; // Specifes that dataFile is of File type

  mscDisk->remove(test_file_name);  // try to remove files before as to force it to reallocate the file...
  
  testFile = mscDisk->open(test_file_name, FILE_WRITE_BEGIN);
  if (!testFile) {
    Serial.printf("Failed to open %s\n", test_file_name);
    return;
  }
  Serial.printf("Start write file: %s length:%u Write Size:%u\n", test_file_name, test_file_size, test_file_write_size);  

  uint32_t cb_write = test_file_write_size;
  uint32_t cb_left = test_file_size;
  uint8_t fill_char = '0';
  test_file_buffer[cb_write - 2] = '\n'; // make in to text...

  elapsedMillis em;
  while (cb_left) {
    if (cb_left < cb_write) cb_write = cb_left;
    memset(test_file_buffer, cb_write - 1, fill_char);
    testFile.write(test_file_buffer, cb_write);
    fill_char = (fill_char == '9')? '0' : fill_char + 1;
    cb_left -= cb_write;
  }  
  testFile.close();
  Serial.printf("Time to write: %u\n", (uint32_t)em);
  
}
Changes pushed up mtp_teensy:

Now running MMOD... With the slow drive:
Code:
Menu Options:
	1 - List USB Drives (Step 1)
	2 - Select USB Drive for Logging (Step 2)
	l - List files on disk
	e - Erase files on disk
	s - Start Logging data (Restarting logger will append records to existing log)
	x - Stop Logging data
	d - Dump Log
	w [write size] [size] [file name]
	r - reset MTP
	h - Menu

Start write file: write_test_file.txt length:1048576 Write Size:512
Time to write: 10959
Start write file: write_test_file.txt length:1048576 Write Size:64
Time to write: 10935
Start write file: write_test_file.txt length:1048576 Write Size:4096
Time to write: 258

Now with the 8GB stick I mentioned:
Code:
Dump Index List
Drive # 2 Selected
Start write file: write_test_file.txt length:1048576 Write Size:512
Time to write: 1270
Start write file: write_test_file.txt length:1048576 Write Size:64
Time to write: 912
Start write file: write_test_file.txt length:1048576 Write Size:4096
Time to write: 263
One the newer SSD:
Code:
Start write file: write_test_file.txt length:1048576 Write Size:512
Time to write: 802
Start write file: write_test_file.txt length:1048576 Write Size:64
Time to write: 788
Start write file: write_test_file.txt length:1048576 Write Size:4096
Time to write: 212

So those newer 32GB drives really want to write whole clusters! A lot more than the others appear to require.
 
Is it just me or are there major race conditions in ehci.cpp? Lots of list manipulation happening without interrupts disabled and isr() being triggered can easily modify those same lists...

It's not just you. This probably explains the problems I'm seeing. I have a hub / MIDI / rawUSB also running concurrently, so my device is putting ehci through its paces. Sometimes a drive will timeout during msGetCSW(), other times I'll see very slow performance, with reads and writes delayed by over a second. And it's not exactly determinisitic. I can reboot the device and everything will be fine.

This would probably also explain why some of wwatson's drives are taking over 5 seconds to initialize.
 
Last edited:
@KurtE - Linux Arduino 1,.8.19 TD1.58B3 - Downloaded MTP_TEENY-MAIN.zip. Setup T4.1 and uploaded. All good. Then selected:
Code:
store:2 storage:30001 name:MSC0-126GEXFAT fs:200030cc
Ran this:
Code:
w 1048576 512 test.txt

The T4.1 reset with:
Code:
CrashReport:
  A problem occurred at (system time) 17:35:54
  Code was executing from address 0x10E6
  CFSR: 82
	(DACCVIOL) Data Access Violation
	(MMARVALID) Accessed Address: 0x20109222
  Temperature inside the chip was 52.26 °C
  Startup CPU clock speed is 600MHz
  Reboot was caused by auto reboot after fault or bad interrupt detected

Test.txt was created but size was zero. Tried with 3 flash drives,,,
 
@yeahtuna
This would probably also explain why some of wwatson's drives are taking over 5 seconds to initialize.

Incorrect - at that point no SCSI command has been called...
 
@KurtE - Linux Arduino 1,.8.19 TD1.58B3 - Downloaded MTP_TEENY-MAIN.zip. Setup T4.1 and uploaded. All good. Then selected:
Code:
store:2 storage:30001 name:MSC0-126GEXFAT fs:200030cc
Ran this:
Code:
w 1048576 512 test.txt

The T4.1 reset with:
Code:
CrashReport:
  A problem occurred at (system time) 17:35:54
  Code was executing from address 0x10E6
  CFSR: 82
	(DACCVIOL) Data Access Violation
	(MMARVALID) Accessed Address: 0x20109222
  Temperature inside the chip was 52.26 °C
  Startup CPU clock speed is 600MHz
  Reboot was caused by auto reboot after fault or bad interrupt detected

Test.txt was created but size was zero. Tried with 3 flash drives,,,
Sorry, there is not much of checking in this code. Like most of the commands in that sketch, it runs off of the currently selected drive.
SO in Command prompt after comes up if you use the 1 command
1<cr>

It will show you a list of drives (and also all of the enumerated files up to that point).

You then use the 2 command to choose which drive. In most cases for fresh startup of teensy this was 2nd drive.
so then:
2 2 <cr>

This should get you to the command. Note the w command I believe is in the order write size, how big and name.

So I get away with just:
w 512

And file name and size are defaulted.
 
@KurtE - that worked. Thanks. Want to test some hard drives as well. They are always faster but probably not practical for remote applications.
 
Here is a minimal setup to cause the MassStorageDriver to fail.

Both teensy devices should be running the same sketch included below. If the test is performed without the second teensy connected to the USB host port, it will complete successfully. If the second teensy is connected to the USB host port, there is a very high probability that it will fail. Even reducing the frequency that the second teensy sends HID packets to 1 packet / 500 ms still has a high probability of causing the driver to fail.

deviceSetup.jpg

Code:
// Make sure to compile for RawHID USB type. 
// This sketch assumes you have migrated the latest changes to the MassStorageDriver

#include "USBHost_t36.h"

USBHost myusb;
USBHub hub1(myusb);
USBDrive usbDrive(myusb);
USBFilesystem usbPart(myusb);
USBHIDParser hid1(myusb);
RawHIDController rawHID1(myusb);

#define LEDPIN 13

void setup() {

    Serial.begin(9600);
    myusb.begin();

    pinMode(LEDPIN, OUTPUT);

    rawHID1.attachReceive(onReceiveHidData1);
    Serial.print("Insert a USB Drive to begin test.\n");
}

bool testHasRun = false;
bool rawHIDConnected = false;

elapsedMillis testTime;
elapsedMillis ledTime;
elapsedMillis rawHIDTimer;



bool ledOn = false;

uint8_t buffer[64];

void loop() {

    myusb.Task();


    if (rawHIDTimer > 50) {
        rawHIDTimer = 0;
        RawHID.send(&buffer, 0);
    }

    if (rawHID1 != rawHIDConnected) {
        rawHIDConnected = !rawHIDConnected;

        if (rawHIDConnected)
            Serial.print("Host port rawHID1 is connected\n");
        else
            Serial.print("Host port rawHID1 is disconnected\n");
    }


    if (ledTime > 100) {
        ledTime = 0;
        ledOn = !ledOn;
        digitalWrite(LEDPIN, ledOn);
    }

    
    if (usbPart) {

        if (!testHasRun) {
            testHasRun = true;
            performTest();
        }
    }

    else {
        testHasRun = false;
    }
}



void performTest() {

    Serial.println("Starting Tests");
    testTime = 0;
  
    Serial.print("Creating /testDir...");
    if (!usbPart.mkdir("/testDir")) {
        Serial.print("FAILED\n");
        return;
    }

    Serial.print("SUCCESS\n");

    File testFile[9];

    for (int i = 0; i < 9; i++) {
        char filename[50];
        sprintf(filename, "/testDir/file_%1d.txt", i);

        testFile[i] = usbPart.open(filename, FILE_WRITE_BEGIN);

        if (!testFile[i]) {
            Serial.print("Failed to create ");
            Serial.println(filename);
        }
        
        if (testFile[i]) {
            Serial.print("Writing to ");
            Serial.println(filename);
            testFile[i].write("Testing");
            testFile[i].close();

            
            if (!usbPart.remove(filename)) {
                Serial.print("Failed to remove ");
                Serial.println(filename);
            }
        }
    }
    
    Serial.print("Removing /testDir...");
    if (!usbPart.rmdir("/testDir")) {
        Serial.print("FAILED\n");
        return;
    }

    Serial.print("SUCCESS\n");

    Serial.print("Test completed in ");
    Serial.print(testTime);
    Serial.println(" miliseconds.");
    Serial.println("Remove and reinsert media to test again.");
}

bool onReceiveHidData1(uint32_t usage, const uint8_t* data, uint32_t len) {
  
    return true;
}
 
Last edited:
Hi, thank you again, both Sandisk drives working now, CSW error is gone, but Kingston Datatraveler G2 keeps initializing infinitely as shown here. Maybe the unit is too old and is faulty but works on Windows, what I've noticed is when I plug into PC the led light flashes, aswell when writing/reading, but not when I plug into teensy even being detected and reported in log.

I've also got one of these old Kingston Datatraveler drives (a 4GB). When connected directly to a Teensy 4.1 it will not work at all, not matter how long the timeouts are or if the initial reset is skipped - the TEST_UNIT_READY command constantly fails and the sense data is UNIT_ATTENTION with NO_MEDIA. The same thing happens when it's connected through a powered hub unless it is first connected to a PC (letting the flash drive show up on the desktop) and then the hub is connected to the Teensy with the flash drive never losing power. Then it will happily talk correctly to the Teensy all day long. It doesn't seem to be a SCSI command out of order or being missed, it's something to do with the way the port is first initialized.
 
Back
Top