Teensyduino File System Integration, including MTP and MSC

Simple Version of SendObject...

I tried a pretty simple version... Could be rearranged a little, but... Pretty straight forward:

I pushed up changes, that includes this below... Also it includes if you use the not simple send... It has helper function for memcpy, that verifies that the values passed in look reasonable... Did not find any issues.


Code:
#ifdef T4_USE_SIMPLE_SEND_OBJECT
bool MTPD::SendObject() {
  pull_packet(rx_data_buffer);
  read(0, 0);
  //      printContainer();
  uint32_t len = ReadMTPHeader();
  uint32_t index = sizeof(MTPHeader);
  printf("MTPD::SendObject: len:%u\n", len);
  elapsedMicros em_total = 0;

  uint32_t sum_read_em = 0;
  uint32_t c_read_em = 0;
  uint32_t read_em_max = 0;

  uint32_t sum_write_em = 0;
  uint32_t c_write_em = 0;
  uint32_t write_em_max = 0;

  // Quick and dirty write the first partial block of data.
  uint32_t bytes = MTP_RX_SIZE - index; // how many data in usb-packet
  if (len) {
    bytes = min(bytes, len);              // loimit at end
    elapsedMillis emWrite = 0;
    //printf("    $$F: %u %u\n", bytes, len);
    if (storage_->write((const char *)rx_data_buffer + index, bytes) < bytes)
      return false;
    uint32_t em = emWrite;
    sum_write_em = em;
    c_write_em++;
    write_em_max = em;
    len -= bytes;
  }
  

  while ((int)len > 0) {
    elapsedMillis emRead = 0;
    if (usb_mtp_recv(rx_data_buffer, SENDOBJECT_READ_TIMEOUT_MS) > 0) { // read directly in.
      uint32_t em = emRead;
      sum_read_em += em;
      c_read_em++;
      if (em > read_em_max)
        read_em_max = em;
    } else {
      printf("\nMTPD::SendObject *** USB Read Timeout ***\n");
      break; //
    }

    bytes = min((uint32_t)MTP_RX_SIZE, len);              // limit at end

    elapsedMillis emWrite = 0;
    //printf("    $$:  %u %u\n", bytes, len);
    if (storage_->write((const char *)rx_data_buffer, bytes) < bytes)
      return false;
    uint32_t em = emWrite;
    sum_write_em += em;
    c_write_em++;
    if (em > write_em_max)
      write_em_max = em;

    len -= bytes;
  }

  //printf("    $$*: %u\n", len);

  // lets see if we should update the date and time stamps.
  storage_->updateDateTimeStamps(object_id_, dtCreated_, dtModified_);

  storage_->close();

  if (c_read_em)
    printf(" # USB Packets: %u total: %u avg ms: %u max: %u\n", c_read_em,
           sum_read_em, sum_read_em / c_read_em, read_em_max);
  if (c_write_em)
    printf(" # Write: %u total:%u avg ms: %u max: %u\n", c_write_em,
           sum_write_em, sum_write_em / c_write_em, write_em_max);
  printf(">>>Total Time: %u\n", (uint32_t)em_total);
  Serial.flush();

  return (len == 0);
}
#else

But again, this simple version, I tried copy of the 22mb file to in this case USB... It looked like it got all of the way to the end and then died.
Code:
24663 RESP:2001(RSP:OK)l: 24 T:3a : 30001 ffffffff 17
24663 CMD: 100d(SEND_OBJECT)l: 12 T:3b
MTPD::SendObject: len:22015988
 # USB Packets: 42999 total: 0 avg ms: 0 max: 0
 # Write: 43000 total:21608 avg ms: 0 max: 12
>>>Total Time: 21622116
*** Start Interval Timer ***
8050 CMD: 1002(OPEN_SESSION)l: 16 T:0 : 1
The start interval.... is after the teensy reset...

So same behavior as before... Will do a couple more tests, but gut tells me something is at times randomly writing to wrong memory...
 
@Interesting details again Kurt! I wonder if that could explain the SeriaTest.exe and SerMon garbage as well? :: "gut tells me something is at times randomly writing to wrong memory..."

Mike - TSET ( "T" ) without TyComm integration from Sublime is using the IDE - just don't need to have it open or use the sketch editor, or SerMon. TyComm still asks 'what Teensy' - but all upload is "--delegate"'d to Teensy.exe. Doing that allows TyComm to drop the USB port for the upload - and the CmdLine IDE build still passes the .HEX/.eHex name to Teensy.exe.
 
@Interesting details again Kurt! I wonder if that could explain the SeriaTest.exe and SerMon garbage as well? ::

No, that's definitely a Windows bug. It occurs with completely different MCUs, too.
I wait for the comming ESP with inbuilt USB... (hey, the inbuilt DSP functions are already pretty good with the current versions, and often it can run circles around the teensy because it not does burn millions of cycles with polling flags)

But: Missing blocks can occur. And it's not impossible that the Teensy misses some interrupts (because they are disabled everywhere)
 
Last edited:
While @KurtE was testing with RawHid and re-working send_object to be aligned with the way T3's handled file transfers (which didn't work too well for me in testing - @KurtE had better luck using his BogusFS test sketch - I put it directly in MTP_Teensy.cpp and tested) I took a slightly different approach. I tried to basically slow down the transfers in send object. After some trial and error with delay I found that using a delayMicroseconds(50) slowed the read/write loop down enough to successful transfer any size file to USB.

Code:
bool MTPD::SendObject() {
  pull_packet(rx_data_buffer);
  read(0, 0);
  //      printContainer();
  uint32_t len = ReadMTPHeader();
  uint32_t index = sizeof(MTPHeader);
  printf("MTPD::SendObject: len:%u\n", len);
  elapsedMicros em_total = 0;

  uint32_t sum_read_em = 0;
  uint32_t c_read_em = 0;
  uint32_t read_em_max = 0;

  uint32_t sum_write_em = 0;
  uint32_t c_write_em = 0;
  uint32_t write_em_max = 0;

  // Quick and dirty write the first partial block of data.
  uint32_t bytes = MTP_RX_SIZE - index; // how many data in usb-packet
  if (len) {
    bytes = min(bytes, len);              // loimit at end
    elapsedMillis emWrite = 0;
    //printf("    $$F: %u %u\n", bytes, len);
    if (storage_->write((const char *)rx_data_buffer + index, bytes) < bytes)
      return false;
    uint32_t em = emWrite;
    sum_write_em = em;
    c_write_em++;
    write_em_max = em;
    len -= bytes;
  }
  

  while ((int)len > 0) {
    elapsedMillis emRead = 0;
    if (usb_mtp_recv(rx_data_buffer, 750) > 0) { // read directly in.
      uint32_t em = emRead;
      sum_read_em += em;
      c_read_em++;
      if (em > read_em_max)
        read_em_max = em;
    } else {
      printf("\nMTPD::SendObject *** USB Read Timeout ***\n");
      break; //
    }

    bytes = min((uint32_t)MTP_RX_SIZE, len);              // limit at end

    elapsedMillis emWrite = 0;
    //printf("    $$:  %u %u\n", bytes, len);
    if (storage_->write((const char *)rx_data_buffer, bytes) < bytes)
      return false;
    uint32_t em = emWrite;
    sum_write_em += em;
    c_write_em++;
    if (em > write_em_max)
      write_em_max = em;

    len -= bytes;
	
  }

  //printf("    $$*: %u\n", len);

  // lets see if we should update the date and time stamps.
  storage_->updateDateTimeStamps(object_id_, dtCreated_, dtModified_);

  storage_->close();

  if (c_read_em)
    printf(" # USB Packets: %u total: %u avg ms: %u max: %u\n", c_read_em,
           sum_read_em, sum_read_em / c_read_em, read_em_max);
  if (c_write_em)
    printf(" # Write: %u total:%u avg ms: %u max: %u\n", c_write_em,
           sum_write_em, sum_write_em / c_write_em, write_em_max);
  printf(">>>Total Time: %u\n", (uint32_t)em_total);
  Serial.flush();

  return (len == 0);
}
#else
bool MTPD::SendObject() {
  pull_packet(rx_data_buffer);
  read(0, 0);
  //      printContainer();
  uint32_t len = ReadMTPHeader();
  uint32_t index = sizeof(MTPHeader);
  printf("MTPD::SendObject: len:%u\n", len);
  disk_pos = 0;
  elapsedMicros em_total = 0;

  uint32_t sum_read_em = 0;
  uint32_t c_read_em = 0;
  uint32_t read_em_max = 0;

  uint32_t sum_write_em = 0;
  uint32_t c_write_em = 0;
  uint32_t write_em_max = 0;

  while ((int)len > 0) {
    uint32_t bytes = MTP_RX_SIZE - index; // how many data in usb-packet
    bytes = min(bytes, len);              // loimit at end
    uint32_t to_copy =
        min(bytes, DISK_BUFFER_SIZE -
                       disk_pos); // how many data to copy to disk buffer
    //printf("    %u %u %u\n", len, bytes, to_copy);
    memcpy(disk_buffer_ + disk_pos, rx_data_buffer + index, to_copy);
    disk_pos += to_copy;
    bytes -= to_copy;
    len -= to_copy;
    // printf("a %d %d %d %d %d\n", len,disk_pos,bytes,index,to_copy);
    //
    if (disk_pos == DISK_BUFFER_SIZE) {
      elapsedMillis emWrite = 0;
      if (storage_->write((const char *)disk_buffer_, DISK_BUFFER_SIZE) <
          DISK_BUFFER_SIZE)
        return false;
      uint32_t em = emWrite;
      sum_write_em += em;
      c_write_em++;
      if (em > write_em_max)
        write_em_max = em;
      disk_pos = 0;

      if (bytes) // we have still data in transfer buffer, copy to initial
                 // disk_buffer_
      {
        memcpy(disk_buffer_, rx_data_buffer + index + to_copy, bytes);
        disk_pos += bytes;
        len -= bytes;
      }
      // printf("b %d %d %d %d %d\n", len,disk_pos,bytes,index,to_copy);
    }
    if (len > 0) // we have still data to be transfered
    {            // pull_packet(rx_data_buffer);
      elapsedMillis emRead = 0;
      bool usb_mtp_avail = false;
      while (!(usb_mtp_avail = usb_mtp_available()) &&
             (emRead < SENDOBJECT_READ_TIMEOUT_MS))
        ;
      if (usb_mtp_avail) {
        uint32_t em = emRead;
        sum_read_em += em;
        c_read_em++;
        if (em > read_em_max)
          read_em_max = em;
        usb_mtp_recv(rx_data_buffer, 60); // read directly in.
      } else {
        printf("\nMTPD::SendObject *** USB Read Timeout ***\n");
        break; //
      }
      index = 0;
    }
	
[B][COLOR="#FF0000"]	delayMicroseconds(50);
[/COLOR][/B]  }
  // printf("len %d\n",disk_pos);
  if (disk_pos) {
    elapsedMillis emWrite = 0;
    if (storage_->write((const char *)disk_buffer_, disk_pos) < disk_pos)
      return false;
    uint32_t em = emWrite;
    sum_write_em += em;
    c_write_em++;
    if (em > write_em_max)
      write_em_max = em;
    disk_pos = 0;
  }

  // lets see if we should update the date and time stamps.
  storage_->updateDateTimeStamps(object_id_, dtCreated_, dtModified_);

  storage_->close();

  if (c_read_em)
    printf(" # USB Packets: %u total: %u avg ms: %u max: %u\n", c_read_em,
           sum_read_em, sum_read_em / c_read_em, read_em_max);
  if (c_write_em)
    printf(" # Write: %u total:%u avg ms: %u max: %u\n", c_write_em,
           sum_write_em, sum_write_em / c_write_em, write_em_max);
  printf(">>>Total Time: %u\n", (uint32_t)em_total);

  return (len == 0);
}
Transferred multiple files and created directories etc with files was able to get to this point:
Code:
Drive # 1 Selected

 Space Used = 80478208
Filesystem Size = 126057054208
System Volume Information            C: 11/04/2021 17:48 M: 11/04/2021 17:48  /
  IndexerVolumeGuid                  C: 11/04/2021 17:48 M: 11/04/2021 17:48  76
Picture1.png                         C: 11/04/2021 17:50 M: 11/04/2021 17:50  1037303
2106.01974.pdf                       C: 11/04/2021 17:51 M: 11/04/2021 17:52  23672380
ZED-F9P_InterfaceDescription_(UBX-18010854).pdf C: 11/04/2021 17:52 M: 11/04/2021 17:52  3008805
22AT Commands.pdf                    C: 11/04/2021 17:52 M: 11/04/2021 17:52  133488
Shaya.jpg                            C: 11/04/2021 17:52 M: 11/04/2021 17:52  1120550
DS4.pcapng                           C: 11/04/2021 17:53 M: 11/04/2021 17:53  182852
T_4.1                                C: 01/01/2021 00:00 M: 01/01/2021 00:00  /
  AN12253.pdf                        C: 11/04/2021 17:58 M: 11/04/2021 17:58  929397
  aoyue-8032a.pdf                    C: 11/04/2021 17:58 M: 11/04/2021 17:58  1156208
  card11a_rev3_web.pdf               C: 11/04/2021 17:58 M: 11/04/2021 17:58  377551
  card11b_rev3_web.pdf               C: 11/04/2021 17:58 M: 11/04/2021 17:58  396325
  D435 Obs-slam Links.txt            C: 11/04/2021 17:58 M: 11/04/2021 17:58  4879
  esp-psram64_.pdf                   C: 11/04/2021 17:58 M: 11/04/2021 17:58  1344699
  esp-psram64_esp-psram64h_datasheet_en.txt C: 11/04/2021 17:58 M: 11/04/2021 17:58  61440
  NXP_i2c_UM10204.pdf                C: 11/04/2021 17:58 M: 11/04/2021 17:58  1395785
  PRINTOUTPUTs2.txt                  C: 11/04/2021 17:58 M: 11/04/2021 17:58  630
  Routed_A.jpg                       C: 11/04/2021 17:58 M: 11/04/2021 17:58  212439
  Routed_B.jpg                       C: 11/04/2021 17:58 M: 11/04/2021 17:58  194564
  schematic41.png                    C: 11/04/2021 17:58 M: 11/04/2021 17:58  72649
  T4.1-Cardlike0.jpg                 C: 11/04/2021 17:58 M: 11/04/2021 17:58  220021
  teensy41_card.png                  C: 11/04/2021 17:58 M: 11/04/2021 17:58  320054
  T_4.1_KurtE.jpg                    C: 11/04/2021 17:58 M: 11/04/2021 17:58  295968
  Visio-driver.pdf                   C: 11/04/2021 17:58 M: 11/04/2021 17:58  1472938
  VSLAM_and_Navigation_System_of_Unmanned_Ground_Vehicle_Based_on_RGB-D_Camera.pdf C: 11/04/2021 17:58 M: 11/04/2021 17:58  5725283
  w25m02gw revd 012219.pdf           C: 11/04/2021 17:58 M: 11/04/2021 17:58  1673403
  W25N02aKV_Datasheet_20201022_C.pdf C: 11/04/2021 17:58 M: 11/04/2021 17:58  1665621
  workshop.pdf                       C: 11/04/2021 17:58 M: 11/04/2021 17:58  8894873
LFS_CPY                              C: 01/01/2021 00:00 M: 01/01/2021 00:00  /
  calculations.wav                   C: 11/04/2021 17:54 M: 11/04/2021 17:57  426812
  completed.wav                      C: 11/04/2021 17:55 M: 11/04/2021 17:55  276972
  dangerous_to_remain.wav            C: 11/04/2021 17:55 M: 11/04/2021 17:55  373404
  functional.wav                     C: 11/04/2021 17:55 M: 11/04/2021 17:55  237868
  enough_info.wav                    C: 11/04/2021 17:55 M: 11/04/2021 17:55  513900
  one_moment.wav                     C: 11/04/2021 17:55 M: 11/04/2021 17:55  202748
  operational.wav                    C: 11/04/2021 17:56 M: 11/04/2021 17:56  772652
  odd1.wav                           C: 11/04/2021 17:55 M: 11/04/2021 17:55  553460
  sorry_dave.wav                     C: 11/04/2021 17:56 M: 11/04/2021 17:56  791676
  stop.wav                           C: 11/04/2021 17:56 M: 11/04/2021 17:56  201356
  SDTEST4.wav                        C: 11/04/2021 17:56 M: 11/04/2021 17:57  17173664
And yes wav files played with media player and pdf's opened correctly.

Unfortunately other issues pop up with MTP like format exFAT still not working, create/modify dates are off as well, and transferring a file from USB to PC hangs MTP usuage while the sketch still runs.

Again think all this is pointing to issues with HS transfer - but can't be 100% sure might be something else with usb_mtp or endpoints or..
 
While @KurtE was testing with RawHid and re-working send_object to be aligned with the way T3's handled file transfers (which didn't work too well for me in testing - @KurtE had better luck using his BogusFS test sketch - I put it directly in MTP_Teensy.cpp and tested) I took a slightly different approach. I tried to basically slow down the transfers in send object. After some trial and error with delay I found that using a delayMicroseconds(50) slowed the read/write loop down enough to successful transfer any size file to USB.
Right now it is sort of interesting to get some different data points on this.

I will be turning off the simple mode and testing some more... Added it as another way to again try to isolate the issue.

Was wondering if there was a chance the code for putting the packets together to write out large buffers had issues and overwriting memory... Does not appear to, as even the simple one goes off the deep end... Where for example we finish the transfer, print out statistics and return and put in another print right after the call to sendobject and that message does not print... So sort of implies the stack was probably screwed up...

It is interesting that the delay helps... If we were near a release and this was reliable, we should jump on using this!

But still wonder what the fundamental issue is.
 
We had this in several other threads - the reason are missing memory barriers (wrong use of "volatile") which produce race conditions, missed interrupts (you miss some if there are more than one when they are disabled) etc...
Didn't Paul say he was working on this?
 
@KurtE - Decided to re-write diskIO based on current developments and keeping in mind that things can and will probably change. I use diskIO strictly for testing. Based on what you are doing with MTP_Teensy and the multitude of other developments you are pumping out I was motivated to just use FS.
So far working with what has been done with MTP_Teensy is making it easier to understand what you and others are trying to accomplish as well as understanding MTP_Teensy itself.
Enjoying the heck out of this. Deep respect for you and the others on this forum :)
 
SendObject (host file to Teensy) - Crash/Stall and other wierd things!

Issues probably with underlying USB support and/or timing and/or my head hurts ;)

Been trying to figure out why sending files, especially larger files would stall or the like and error with incomplete transfer or would look like it went through and teensy would reboot sometimes showing fault... Fault location give nothing helpful.

Again been trying to isolate down, is problem with the underlying FS like SD or LittleFS? Is it our combining of multiple reads (500(+12 byte header) followed by lots of 512 bytes into 2k writes... Or underlying MTP code...

So again tried to break it down to eliminate possible issues.

So have simple MTP transfer similar to T3.x version which does not show these issues. Receive packet, Write data, repeat... (In the T3.x case first packet as 52 bytes of file data, the rest 64)
Did not appear to help, make more reliable..

So created simple Bogus FS which nothing, except in this case, with special file sent to it, it looks at beginning sequence numbers to see if it finds any missing packets...
Still hangs/crashes... So probably not FS... (But more on this in second)...

Was wondering if maybe issue in cores/teensy4/usb_mtp.c ... Still not sure yet...

So I instrumented the code to use with Logic Analyzer.

Was curious of the usage of the 4 RX transfers so added: Quick and dirty:
Code:
static void rx_queue_transfer(int i)
{
	NVIC_DISABLE_IRQ(IRQ_USB1);
	void *buffer = rx_buffer + i * MTP_RX_SIZE_480;
	arm_dcache_delete(buffer, rx_packet_size);
	usb_prepare_transfer(rx_transfer + i, buffer, rx_packet_size, i);
	usb_receive(MTP_RX_ENDPOINT, rx_transfer + i);
	switch (i) {
		case 0: digitalWriteFast(0, LOW); break;
		case 1: digitalWriteFast(1, LOW); break;
		case 2: digitalWriteFast(2, LOW); break;
		case 3: digitalWriteFast(3, LOW); break;
		default: digitalWriteFast(4, LOW); break;
	}
	NVIC_ENABLE_IRQ(IRQ_USB1);
}

static void rx_event(transfer_t *t)
{
	int i = t->callback_param;
	//printf("rx event i=%d\n", i);
	// received a packet with data
	uint32_t head = rx_head;
	if (++head > RX_NUM) head = 0;
	rx_list[head] = i;
	switch (i) {
		case 0: digitalWriteFast(0, HIGH); break;
		case 1: digitalWriteFast(1, HIGH); break;
		case 2: digitalWriteFast(2, HIGH); break;
		case 3: digitalWriteFast(3, HIGH); break;
		default: digitalWriteFast(4, HIGH); break;
	}
	rx_head = head;
}

...
int usb_mtp_recv(void *buffer, uint32_t timeout)
{
	uint32_t wait_begin_at = systick_millis_count;
	uint32_t tail = rx_tail;
	digitalWriteFast(4, HIGH);
	while (1) {
		if (!usb_configuration) return -1; // usb not enumerated by host
		if (tail != rx_head) break;
		if (systick_millis_count - wait_begin_at > timeout)  {
			return 0;
		}
		//yield();
	}
//	digitalWriteFast(0, LOW);
	if (++tail > RX_NUM) tail = 0;
	uint32_t i = rx_list[tail];
	rx_tail = tail;

	memcpy(buffer,  rx_buffer + i * MTP_RX_SIZE_480, rx_packet_size);
	rx_queue_transfer(i);
	//memset(rx_transfer, 0, sizeof(rx_transfer));
	//usb_prepare_transfer(rx_transfer + 0, rx_buffer, rx_packet_size, 0);
	//usb_receive(MTP_RX_ENDPOINT, rx_transfer + 0);
	digitalWriteFast(4, LOW);
	return rx_packet_size;
}
Note pin 4 in couple of places the default one never hit... So no bogus indexes seen...
In the simple transfer code I added:
Code:
...
    digitalWriteFast(5, HIGH);
    if (storage_->write((const char *)rx_data_buffer, bytes) < bytes)
      return false;
    digitalWriteFast(5, LOW);
...
So pin 5 brackets the writes...

The bogus writes do:
Code:
	virtual size_t write(const void *buf, size_t size) {
		// lets walk through the data and see if we have sequence numbers
		uint8_t *pb = (uint8_t*)buf;
		bool first_packet = (_file_size == 0);
		if (first_packet) _simple_send_object = (size == 500);
		
		if (_simple_send_object) {
			int32_t packet_number = 0;
			for (uint16_t i = 0; pb[i] >= '0' && pb[i] <= '9'; i++) packet_number = packet_number * 10 + pb[i] - '0';
			if (packet_number != (_last_packet_number + 1)) {
				if (_error_count < 10) 	Serial.printf("BF Sequence error %u %u\n", packet_number, _last_packet_number);
				_error_count++;
			}
			_last_packet_number = packet_number;
		} else {
			while (_offset < size) {
				int32_t packet_number = 0;
				for (uint16_t i = _offset; pb[i] >= '0' && pb[i] <= '9'; i++) packet_number = packet_number * 10 + pb[i] - '0';
				if (packet_number != (_last_packet_number + 1)) {
					if (_error_count < 10) 	Serial.printf("BF Sequence error %u %u\n", packet_number, _last_packet_number);
					_error_count++;
				}
				_last_packet_number = packet_number;
				_offset += first_packet? 500 : 512;
				first_packet = false;
			}
			_offset &= 0x1ff; // probably ok...
		}
		_file_size += size;
		delayMicroseconds(500);
		return size;
	}
Note this will doing the simple send part...

Note the delay at end... Here is where it get interesting...

Without this delay, we timeout at the end: Like shown in the run:
screenshot.jpg
screenshot2.jpg

Now here is where it gets interesting with the delay, everything changes and makes no sense:

screenshot3.jpg
screenshot3.jpg
(Edit put in second one as cut/paste did not show while transfer)
I ask for a 500us delay and I get about 250ms (1/4 second)

Note: earlier I had 1 delay(1) instead and the delay was half second?

Paul and others - Suggestions on what could cause this?

I thought well maybe MSC was doing some stuff with timers, so created this version with MSC/USBHost...

HELP

Maybe take another break and go back to playing with RAWHID512, which has been fun :D
 
Last edited:
...
Code:

(Edit put in second one as cut/paste did not show while transfer)
I ask for a 500us delay and I get about 250ms (1/4 second)

Note: earlier I had 1 delay(1) instead and the delay was half second?

Paul and others - Suggestions on what could cause this?

I thought well maybe MSC was doing some stuff with timers, so created this version with MSC/USBHost...

HELP

Maybe take another break and go back to playing with RAWHID512, which has been fun :D

I was sort of trying to see if I could reproduce this hang/timing/... issues with something simpler, so played some more with the rawhid...
At least not yet...

BUT their end points are configured differently...
That is MTP is setup with BULK endpoints.

Code:
  #define ENDPOINT3_CONFIG	ENDPOINT_RECEIVE_BULK + ENDPOINT_TRANSMIT_BULK
Code:
        0x02,                                   // bmAttributes (0x02=bulk)
        LSB(MTP_RX_SIZE_480),MSB(MTP_RX_SIZE_480), // wMaxPacketSize
        0,                                      // bInterval

And rawhid is Interrupt:
Code:
 #define ENDPOINT3_CONFIG	ENDPOINT_RECEIVE_UNUSED + ENDPOINT_TRANSMIT_INTERRUPT
  #define ENDPOINT4_CONFIG	ENDPOINT_RECEIVE_INTERRUPT + ENDPOINT_TRANSMIT_UNUSED
RAWHID_RX_ENDPOINT, // bEndpointAddress
Code:
        0x03,                                   // bmAttributes (0x03=intr)
        LSB(RAWHID_RX_SIZE_480),                // wMaxPacketSize 
        MSB(RAWHID_RX_SIZE_480),
        RAWHID_RX_INTERVAL,			// bInterval

So again need to refresh on differences between bulk and interrupt... Also wondering if I should try interrupt and see what happens...
 
I'm a few weeks and nearly 200 messages behind on this thread... but going to catch up this week. Any chance you can give me a quick summary of the main issues needing my attention?

Also considering buying a low-end Android phone or tablet so I can watch with my USB protocol analyzer which MTP events it actually sends to Windows. But I have never used *any* Android phone, so not really sure where to start. Any ideas?
 
Paul, my hands are sort of done for the day...
So will do a real quick summary.. Hopefully more in the morning.

FS.h - Discussions here and other threads and issues. What other things should be added? Things like, preferred sizes for IOs, preallocate, know what FS it is...

MSC - We have worked on integrating it into usbhost... To do so, I converted the library to more standard arduino, with src directory. This allows some code to be moved into subdirectories.
Still things can be cleaned up here, but I set it up to allow MSC drives to come in as one type object sort of like HidParser and volumes show up as another sort of like Hid devices...
Would be good to have you take a look through and see if this is a direction that makes sense.
It is in my fork in the branch FS_Integration_MSC

MTP - We (or at least me) have struggled to reliably be able to sending objects to the teensy (SendObject), sometimes OK, sometimes we don't receive everything, sometimes the teensy resets, sometimes it resets with a crash report... Most of my more recent postings on this was trying different things to see why. Especially true on T4.x...
If you look at the images and the like in #458, you can see where I am pulling my hair out.
If the logical write does not take any time, then simple call to bogusfs->write() which does very little except look at the text to see if the sequences of packets looks correct.
and no delay added, the call takes about: 38us , but if I add a 500us delay in the code, this call takes 250ms (or quarter second) to return... 8)

Why? Not sure, but best guess. There may be an underlying issue with the main t4 usb code, again guessing, that maybe when we receive information on a BULK endpoint and all transfer objects (in this case 4) of our RX endpoint have already received data and are waiting for code to read it and then put the transfer back on the list. I think something is going very wrong...

Maybe it walks off the list and uses garbage, or maybe it loops for some time hoping one will be come available and times out after so long or??? I am trying to start looking through this, but have not done much in this end of the code... Could use some hints!

Sorry my main phones/tablets are Apple. I do have Kindle Fire which I have hooked up to Linux to experiment. It looked like it hooks up more like PTP than MTP...

Other diversion: playing with Rawhid... Sort of fun with 512 packets, with 8 times throughput... was hoping to reproduce USB issue, but so far not... But it uses Interrupt instead of Bulk... Not sure if you will be interested... But that is different thread....

Sorry about as much as hands can take today... Maybe others will fill in more... Or will check to see if more feedback in morning.

Kurt
 
@KurtE - Have been trying to get some sort of lock on what is going wrong. It does not seem to matter the size of the file or how many files or directories are copied from a PC (Linux) to either an SD card (SDIO) or MSC device. They all read back on a PC ok. But when trying to read it back from MTP on the Teensy I get this:
Code:
/*
  SD card test 
   
 This example shows how use the utility libraries on which the'
 SD library is based in order to get info about your SD card.
 Very useful for testing a card when you're not sure whether its working or not.
 	
 The circuit:
  * SD card attached to SPI bus as follows:
 ** MOSI - pin 11 on Arduino Uno/Duemilanove/Diecimila, pin 7 on Teensy with audio board
 ** MISO - pin 12 on Arduino Uno/Duemilanove/Diecimila
 ** CLK - pin 13 on Arduino Uno/Duemilanove/Diecimila, pin 14 on Teensy with audio board
 ** CS - depends on your SD card shield or module - pin 10 on Teensy with audio board
 		Pin 4 used here for consistency with other Arduino examples

 
 created  28 Mar 2011
 by Limor Fried 
 modified 9 Apr 2012
 by Tom Igoe
 */
 // include the SD library:
#include <SD.h>
#include <SPI.h>

// set up variables using the SD utility library functions:
Sd2Card card;
SdVolume volume;
SdFile root;

// change this to match your SD shield or module;
// Arduino Ethernet shield: pin 4
// Adafruit SD shields and modules: pin 10
// Sparkfun SD shield: pin 8
// Teensy audio board: pin 10
// Teensy 3.5 & 3.6 & 4.1 on-board: BUILTIN_SDCARD
// Wiz820+SD board: pin 4
// Teensy 2.0: pin 0
// Teensy++ 2.0: pin 20
const int chipSelect = 10;

void setup()
{
  //UNCOMMENT THESE TWO LINES FOR TEENSY AUDIO BOARD:
  //SPI.setMOSI(7);  // Audio shield has MOSI on pin 7
  //SPI.setSCK(14);  // Audio shield has SCK on pin 14
  
 // Open serial communications and wait for port to open:
  Serial.begin(9600);
   while (!Serial) {
    ; // wait for serial port to connect.
  }


  Serial.print("\nInitializing SD card...");


  // we'll use the initialization code from the utility libraries
  // since we're just testing if the card is working!
  if (!card.init(SPI_HALF_SPEED, chipSelect)) {
    Serial.println("initialization failed. Things to check:");
    Serial.println("* is a card inserted?");
    Serial.println("* is your wiring correct?");
    Serial.println("* did you change the chipSelect pin to match your shield or module?");
    return;
  } else {
   Serial.println("Wiring is correct and a card is present.");
  }

  // print the type of card
  Serial.print("\nCard type: ");
  switch(card.type()) {
    case SD_CARD_TYPE_SD1:
      Serial.println("SD1");
      break;
    case SD_CARD_TYPE_SD2:
      Serial.println("SD2");
      break;
    case SD_CARD_TYPE_SDHC:
      Serial.println("SDHC");
      break;
    default:
      Serial.println("Unknown");
  }

  // Now we will try to open the 'volume'/'partition' - it should be FAT16 or FAT32
  if (!volume.init(card)) {
    Serial.println("Could not find FAT16/FAT32 partition.\nMake sure you've formatted the card");
    return;
  }


  // print the type and size of the first FAT-type volume
  uint32_t volumesize;
  Serial.print("\nVolume type is FAT");
  Serial.println(volume.fatType(), DEC);
  Serial.println();
  
  volumesize = volume.blocksPerCluster();    // clusters are collections of blocks
  volumesize *= volume.clusterCount();       // we'll have a lot of clusters
  if (volumesize < 8388608ul) {
    Serial.print("Volume size (bytes): ");
    Serial.println(volumesize * 512);        // SD card blocks are always 512 bytes
  }
  Serial.print("Volume size (Kbytes): ");
  volumesize /= 2;
  Serial.println(volumesize);
  Serial.print("Volume size (Mbytes): ");
  volumesize /= 1024;
  Serial.println(volumesize);

  
  //Serial.println("\nFiles found on the card (name, date and size in bytes): ");
  //root.openRoot(volume);
  
  // list all files in the card with date and size
  //root.ls(LS_R | LS_DATE | LS_SIZE);
}


void loop(void) {
  
}
[COLOR="#FF0000"]: ");[/COLOR]
    Serial.println(volumesize * 512);        // SD card blocks are always 512 bytes
  }
  Serial.print("Volume size (Kbytes): ");
  volumesize /= 2;
  Serial.println(volumesize);
  Serial.print("Volume size (Mbytes): ");
  volumesize /= 1024;
  Serial.println(volumesize);

  
  //Serial.println("\nFiles found on the card (name, date and size in bytes): ");
  //root.openRoot(volume);
  
  // list all files in the card with date and size
  //root.ls(LS_R | LS_DATE | LS_SIZE);
}


void loop(void) {
  
}
[COLOR="#FF0000"]: ")[/COLOR]

This was cardinfo.ino from the SD library that I copied through MTP to both SDIO and MSC devices (The whole SD directory). The results were the same. They copied without issue to the Teensy and when trying to read it back through MTP from the Teensy I got the above results. I then removed both the SD card and the USB stick from the Teensy and plugged both back into a PC(Linux) and got this listing of the same file:
Code:
/*
  SD card test 
   
 This example shows how use the utility libraries on which the'
 SD library is based in order to get info about your SD card.
 Very useful for testing a card when you're not sure whether its working or not.
 	
 The circuit:
  * SD card attached to SPI bus as follows:
 ** MOSI - pin 11 on Arduino Uno/Duemilanove/Diecimila, pin 7 on Teensy with audio board
 ** MISO - pin 12 on Arduino Uno/Duemilanove/Diecimila
 ** CLK - pin 13 on Arduino Uno/Duemilanove/Diecimila, pin 14 on Teensy with audio board
 ** CS - depends on your SD card shield or module - pin 10 on Teensy with audio board
 		Pin 4 used here for consistency with other Arduino examples

 
 created  28 Mar 2011
 by Limor Fried 
 modified 9 Apr 2012
 by Tom Igoe
 */
 // include the SD library:
#include <SD.h>
#include <SPI.h>

// set up variables using the SD utility library functions:
Sd2Card card;
SdVolume volume;
SdFile root;

// change this to match your SD shield or module;
// Arduino Ethernet shield: pin 4
// Adafruit SD shields and modules: pin 10
// Sparkfun SD shield: pin 8
// Teensy audio board: pin 10
// Teensy 3.5 & 3.6 & 4.1 on-board: BUILTIN_SDCARD
// Wiz820+SD board: pin 4
// Teensy 2.0: pin 0
// Teensy++ 2.0: pin 20
const int chipSelect = 10;

void setup()
{
  //UNCOMMENT THESE TWO LINES FOR TEENSY AUDIO BOARD:
  //SPI.setMOSI(7);  // Audio shield has MOSI on pin 7
  //SPI.setSCK(14);  // Audio shield has SCK on pin 14
  
 // Open serial communications and wait for port to open:
  Serial.begin(9600);
   while (!Serial) {
    ; // wait for serial port to connect.
  }


  Serial.print("\nInitializing SD card...");


  // we'll use the initialization code from the utility libraries
  // since we're just testing if the card is working!
  if (!card.init(SPI_HALF_SPEED, chipSelect)) {
    Serial.println("initialization failed. Things to check:");
    Serial.println("* is a card inserted?");
    Serial.println("* is your wiring correct?");
    Serial.println("* did you change the chipSelect pin to match your shield or module?");
    return;
  } else {
   Serial.println("Wiring is correct and a card is present.");
  }

  // print the type of card
  Serial.print("\nCard type: ");
  switch(card.type()) {
    case SD_CARD_TYPE_SD1:
      Serial.println("SD1");
      break;
    case SD_CARD_TYPE_SD2:
      Serial.println("SD2");
      break;
    case SD_CARD_TYPE_SDHC:
      Serial.println("SDHC");
      break;
    default:
      Serial.println("Unknown");
  }

  // Now we will try to open the 'volume'/'partition' - it should be FAT16 or FAT32
  if (!volume.init(card)) {
    Serial.println("Could not find FAT16/FAT32 partition.\nMake sure you've formatted the card");
    return;
  }


  // print the type and size of the first FAT-type volume
  uint32_t volumesize;
  Serial.print("\nVolume type is FAT");
  Serial.println(volume.fatType(), DEC);
  Serial.println();
  
  volumesize = volume.blocksPerCluster();    // clusters are collections of blocks
  volumesize *= volume.clusterCount();       // we'll have a lot of clusters
  if (volumesize < 8388608ul) {
    Serial.print("Volume size (bytes): ");
    Serial.println(volumesize * 512);        // SD card blocks are always 512 bytes
  }
  Serial.print("Volume size (Kbytes): ");
  volumesize /= 2;
  Serial.println(volumesize);
  Serial.print("Volume size (Mbytes): ");
  volumesize /= 1024;
  Serial.println(volumesize);

  
  //Serial.println("\nFiles found on the card (name, date and size in bytes): ");
  //root.openRoot(volume);
  
  // list all files in the card with date and size
  //root.ls(LS_R | LS_DATE | LS_SIZE);
}


void loop(void) {
  
}

As far as I can tell writes through MTP to the the Teensy work but reading them back is dropping packets. If I copy a single small text file to the Teensy it will read back correctly (Without any directories)...
Hold on to what hair is left @KurtE:)
 
Last edited:
I'm a few weeks and nearly 200 messages behind on this thread... but going to catch up this week. Any chance you can give me a quick summary of the main issues needing my attention?

Also considering buying a low-end Android phone or tablet so I can watch with my USB protocol analyzer which MTP events it actually sends to Windows. But I have never used *any* Android phone, so not really sure where to start. Any ideas?

My old phone is a Samsung Galaxy S5 and I have a Galaxy Tab 4 tablet (both rather old now) along with my iPhone.

As for MTP/MSC/FS along with the info that @KurtE provided I tried a couple of different approaches.

1. In post #436 I tried to copy a file without transferring it via MTP (i.e. windows interface) using just FS file write. While transfer completed a lot of records missing at the end of the file. Probably going to do it again.

2. I did manage to get consistent large file transfers ~20mb working on a Windows formatted jump drive (exFAT) by adding a delayMicroseconds(50) in the send_object loop. While it transferred correctly and was able to copy it back to the PC MTP lost the drives in explorer but the sketch still ran so I could say see the drives and write a log file to the disks.

3. Just recently I found that if I tried formatting a SD Card using SDIO (didn't test yet on a ext card reader) it would succeed but the card would show as 0 used and 0 total space. But card would work in the PC. This might be more related to how we restart the SD card but I remember testing this earlier and it worked I think.

4. After doing a format on a exFAT jump drive and you try to copy a file to the drive it fails to complete transfer almost immediately. On a FAT32 drive it completes the transfer. But then you run into the issue described in item 2 on transferring a file back to the PC or even when you open it directly from the jump drive. If I move the drives (whether exFAT or FAT32 back to the PC there are no issues identified on the PC, i.e., correctly identifies the files, chekdsk clear etc)

Ok that probably the hightligths in addition to what @KurtE posted.
 
MTP - We (or at least me) have struggled to reliably be able to sending objects to the teensy (SendObject), sometimes OK, sometimes we don't receive everything, sometimes the teensy resets, sometimes it resets with a crash report... Most of my more recent postings on this was trying different things to see why. Especially true on T4.x...
If you look at the images and the like in #458, you can see where I am pulling my hair out.
If the logical write does not take any time, then simple call to bogusfs->write() which does very little except look at the text to see if the sequences of packets looks correct.
and no delay added, the call takes about: 38us , but if I add a 500us delay in the code, this call takes 250ms (or quarter second) to return... 8)

Why? Not sure, but best guess. There may be an underlying issue with the main t4 usb code, again guessing, that maybe when we receive information on a BULK endpoint and all transfer objects (in this case 4) of our RX endpoint have already received data and are waiting for code to read it and then put the transfer back on the list. I think something is going very wrong...

Maybe it walks off the list and uses garbage, or maybe it loops for some time hoping one will be come available and times out after so long or??? I am trying to start looking through this, but have not done much in this end of the code... Could use some hints!

Quick update here. Some of this timing issues is self induced...

That is I forgot I switched back to my github version of cores, which did not have my FS.h fix so:
when: MTP_Teensy.cpp code:
Code:
    digitalWriteFast(5, HIGH);
    if (storage_->write((const char *)rx_data_buffer + index, bytes) < bytes)
      return false;
    digitalWriteFast(5, LOW);

where bytes is lets say 512...

It was calling my Bogus code:
Code:
size_t BogusFile::write(const void *buf, size_t size) {
#ifdef T4_USE_SIMPLE_SEND_OBJECT // should match mtp_teensy
	digitalWriteFast(6, HIGH);
	const uint8_t *pb = (const uint8_t*)buf;
	int32_t packet_number = 0;
	for (uint16_t i = 0; pb[i] >= '0' && pb[i] <= '9'; i++) packet_number = packet_number * 10 + pb[i] - '0';
	if (packet_number != (_last_packet_number + 1)) {
		if (_error_count < 10) 	Serial.printf("$$$ BF Sequence error %d %d\n", packet_number, _last_packet_number);
		_error_count++;
	}
	_last_packet_number = packet_number;
	_file_size += size;
	//delayMicroseconds(500);
	delay(3);
	digitalWriteFast(6, LOW);
	return size;
#else
512 times...
Thanks @mjs513 for reminding me...

FS.h has two versions of file writes with buffers.
There is one: that comes from print class which takes uint8_t * and then there is one directly in the File class which take void *

So our code take the one from the Print class, which is not overwritten which then loops calling the simple write(char) function, which then call our one with one byte at a time...

Current hack in fs.h
Code:
	// override print version
	virtual size_t write(const uint8_t *buf, size_t size) {
		return (f) ? f->write((void*)buf, size) : 0;
	}

Will also change mtp to cast to void* so don't hit again if we don't actually change FS.h


Note: so the quick die is not currently happening, but with the 3ms delay for long file, which took minutes... It gets to the end thinks everything is output

We see:
Code:
>> date/Time: 6184db30 11/5/2021 7:20:16
Modified: 6184db30
BogusFS::open(/T4LargeIndexedTestfile.txt, 2)
24524 RESP:2001(RSP:OK)l: 24 T:a : 20001 ffffffff 14
24524 CMD: 100d(SEND_OBJECT)l: 12 T:b
MTPD::SendObject: len:22015988
    $$*: 0
 # USB Packets: 42999 total: 40 avg ms: 0 max: 1
 # Write: 43000*** Start Interval Timer ***

The *** start interval is the start of a new run...


The code outputting that last part:
Code:
  if (c_read_em)
    printf(" # USB Packets: %u total: %u avg ms: %u max: %u\n", c_read_em,
           sum_read_em, sum_read_em / c_read_em, read_em_max);
  if (c_write_em)
    printf(" # Write: %u total:%u avg ms: %u max: %u\n", c_write_em,
           sum_write_em, sum_write_em / c_write_em, write_em_max);
  printf(">>>Total Time: %u\n", (uint32_t)em_total);
  Serial.flush();
Notice that it was not a complete output... Also did a flush before this call returns...
 
How do you use the SD drop in replacement? I want to use long filenames with the wave file player in the Audio library.

Do I just add the new SD.h file? And what do I need to do with the SD.cpp file? Add it to my project and compile it?
 
How do you use the SD drop in replacement? I want to use long filenames with the wave file player in the Audio library.

Do I just add the new SD.h file? And what do I need to do with the SD.cpp file? Add it to my project and compile it?

Simplest answer is to run the current released version of Teensyduino... It has the SD library as a simple layer above the SDFat library. For the most part if you have a sketch that
uses SD, that is has: #include <SD.h>
It will use the new stuff...

And like all Arduino libraries. assuming you are building with the Arduino IDE, the build will compile all of the other stuff needed...
 
Sounds like you need to make an installer Kurt :) ... lots of moving parts

At this point, maybe a bit premature to do a new beta build. Although there are some interesting things we have found for example issues with FS.h which most code now using FS, like for SD... May be running really slow as their code may very likely be calling the devices with one byte writes.

Also bug fix in ExFat when you try to set dates...

But before that maybe some simple fundamental things might be good to decide on. Like are there any new stuff added to FS and File classes?
Merging in MSC into USBHost? OK? If yes a few more questions, like issues building somethings when USBHost_t36.h includes FS.h... Which is why I have second header file... Maybe not bad idea to have all of the MSC classes in their own top level header?
...

Plus it would be great if we could figure out who appears to be trashing the stack...
 
Decided to take a bit more structured approach to documenting testing results. The following table compares testing results with our latest changes to MTP/USBHost/SDfat/SD (using @KurtE's current forks) as well as my delayMicroseconds(50) hack in send_object. The test compares T3.6 and T4.1 using FAT32 and exFAT formatting issues and coping files after at format in MTP via windows explorer.


Teensy 3.6 plus Audio Shield on pin 10
FAT32 SDCards:
Builtin_SDCard with 8GB SD card:
Format successful
Shows correct used space and total size
Can copy 20mb+ files without receiving incomplete messages

Extern Card on pin 10 with 32GB SD card:
Format successful
Shows correct used space and total size
Can copy 20mb+ files without receiving incomplete messages
ExFAT SDCards:
Builtin_SDCard with 64GB SD card:
Formatting successful but…
FAILS = 0 bytes used 0 bytes total Size
Not restarting properly on SDIO?
Note on RESTART of T3.6 card is available and can copy a 20mb+ file from PC to card

Extern Card on pin 10 with 512GB SD card:
Format successful
Shows correct used space and total size
Can copy 20mb+ files without receiving incomplete messages
Teensy 4.1 plus Adafruit Ext Card Reader
FAT32 SDCards:
Builtin_SDCard with 8GB SD card:
Format successful
Shows correct used space and total size
Incomplete message received after file completed transfer >>>>>

MTPD::SendObject: len:23672380
MTPD::SendObject *** USB Read Timeout ***
# USB Packets: 46232 total: 78 avg ms: 0 max: 1
# Write: 11559 total:1977 avg ms: 0 max: 54
>>>Total Time: 4880668
*MTPD::send_Event(4001)
73144 RESP:2007(RSP:INCOMPLETE_TRANSFER)l: 12 T:a
73174 CMD: 1005(GET_STORAGE_INFO)l: 16 T:b : 10001
NOTE: On RESTART file was there but did not open properly​

Extern Card on pin 10 with 32GB SD card:
Format successful
Shows correct used space and total size
Can copy 20mb+ files without receiving incomplete messages
ExFAT SDCards:
Builtin_SDCard with 64GB SD card:
Formatting successful but…
FAILS = 0 bytes used 0 bytes total Size
Not restarting properly on SDIO?
Note on RESTART Can not copy large file

MTPD::SendObject: len:23672380
MTPD::SendObject *** USB Read Timeout ***
# USB Packets: 46234 total: 87 avg ms: 0 max: 1
# Write: 11559 total:1111 avg ms: 0 max: 74
>>>Total Time: 4246887
*MTPD::send_Event(4001)
25988 RESP:2007(RSP:INCOMPLETE_TRANSFER)l: 12 T:b​

Extern Card on pin 10 with 512GB SD card:
Format successful
Shows correct used space and total size
MTPD::SendObject: len:23672380

MTPD::SendObject *** USB Read Timeout ***
# USB Packets: 46234 total: 68 avg ms: 0 max: 1
# Write: 11559 total:24737 avg ms: 2 max: 26
>>>Total Time: 27669951
*MTPD::send_Event(4001)
168083 RESP:2007(RSP:INCOMPLETE_TRANSFER)l: 12 T:a
168115 CMD: 1005(GET_STORAGE_INFO)l: 16 T:b : 2000​

On RESTART File was there and opened properly,

 
This is a followup to my previous post.

The test sketch in post #469 put the mtpindex file on the lfsram drive. However if you put if you let the sketch put it on the sdio drive and try a exFAT format it goes boom and it is very repeatable:
Code:
Format Complete(1 1169) ***
*** end Interval Timer ***
Return Response OK
50090 RESP:2001(RSP:OK)l: 20 T:9 : 10001 0
*MTPD::send_Event(400b)
50093 CMD: 1005(GET_STORAGE_INFO)l: 16 T:a : 10001
65537 0 name:SDIO
65537 0 name:SDIO
50093 RESP:2001(RSP:OK)l: 16 T:a : 10001
50096 CMD: 1002(OPEN_SESSION)l: 16 T:0 : 1
50096 RESP:2001(RSP:OK)l: 16 T:0 : 1
50096 CMD: 1001(GET_DEVICE_INFO)l: 12 T:1
50096 RESP:2001(RSP:OK)l: 12 T:1
50097 CMD: 1004(GET_STORAGE_IDS)l: 12 T:2
50097 RESP:2001(RSP:OK)l: 12 T:2
50097 CMD: 1005(GET_STORAGE_INFO)l: 16 T:3 : 10001
65537 0 name:SDIO
65537 0 name:SDIO
50097 RESP:2001(RSP:OK)l: 16 T:3 : 10001
50098 CMD: 1005(GET_STORAGE_INFO)l: 16 T:4 : 20001
131073 1 name:SPI10
131073 1 name:SPI10
50688 RESP:2001(RSP:OK)l: 16 T:4 : 20001
50688 CMD: 1005(GET_STORAGE_INFO)l: 16 T:5 : 30001
196609 2 name:RAM
196609 2 name:RAM
50688 RESP:2001(RSP:OK)l: 16 T:5 : 30001
50688 CMD: 9801(GET_OBJECT_PROPS_SUPPORTED)l: 16 T:6 : 3000
50688 RESP:2001(RSP:OK)l: 16 T:6 : 3000
50688 CMD: 9801(GET_OBJECT_PROPS_SUPPORTED)l: 16 T:7 : 3001
50688 RESP:2001(RSP:OK)l: 16 T:7 : 3001
50689 CMD: 1007(GET_OBJECT_HANDLES)l: 24 T:8 : 10001 0 ffffffff
*** MTPStorage::GenerateIndex called ***
    remove called: 0 /mtpindex.dat
cannot open Index file
0: 0 1 0 -1 0 0 /
cannot open Index file
1: 1 1 0 -1 0 0 /
cannot open Index file
2: 2 1 0 -1 0 0 /
cannot open Index file
3: 3 1 0 -1 0 0 /
cannot open Index file
4: 4 1 0 -1 0 0 /
cannot open Index file
5: 5 1 0 -1 0 0 /
cannot open Index file
6: 6 1 0 -1 0 0 /
cannot open Index file
7: 7 1 0 -1 0 0 /
cannot open Index file
8: 8 1 0 -1 0 0 /
cannot open Index file
9: 9 1 0 -1 0 0 /
cannot open Index file
10: 10 1 0 -1 0 0 /
cannot open Index file
11: 11 1 0 -1 0 0 /
cannot open Index file
12: 12 1 0 -1 0 0 /
cannot open Index file
13: 13 1 0 -1 0 0 /
cannot open Index file
14: 14 1 0 -1 0 0 /
cannot open Index file
15: 15 1 0 -1 0 0 /
cannot open Index file
16: 16 1 0 -1 0 0 /
cannot open Index file
17: 17 1 0 -1 0 0 /
cannot open Index file
18: 18 1 0 -1 0 0 /
cannot open Index file
19: 19 1 0 -1 0 0 /
** ScanDir called 0 0
cannot open Index file
cannot open Index file
OpenFileByIndex failed to open (0):/ mode: 0
cannot open Index file
** ScanDir called 0 0
cannot open Index file
cannot open Index file
OpenFileByIndex failed to open (0):/ mode: 0
cannot open Index file
** ScanDir called 0 0
cannot open Index file
cannot open Index file
OpenFileByIndex failed to open (0):/ mode: 0
cannot open Index file
50690 RESP:2001(RSP:OK)l: 24 T:8 : 10001 0 ffffffff
50690 CMD: 1007(GET_OBJECT_HANDLES)l: 24 T:9 : 20001 0 ffffffff
** ScanDir called 1 1
cannot open Index file
cannot open Index file
cannot open Index file
  >> 20: 1 0 0 1 0 23672308 2106.01974.pdf
cannot open Index file
cannot open Index file
cannot open Index file
** ScanDir called 1 1
cannot open Index file
cannot open Index file
cannot open Index file
** ScanDir called 1 1
cannot open Index file
cannot open Index file
cannot open Index file
50691 RESP:2001(RSP:OK)l: 24 T:9 : 20001 0 ffffffff
50691 CMD: 9803(GET_OBJECT_PROP_VALUE)l: 20 T:a : 14 dc02 (FORMAT)
cannot open Index file
cannot open Index file
50692 RESP:2001(RSP:OK)l: 20 T:a : 14 dc02
50692 CMD: 9802(GET_OBJECT_PROP_DESC)l: 20 T:b : dc41 3001 (PERSISTENT_UID)
50692 RESP:2001(RSP:OK)l: 20 T:b : dc41 3001
50692 CMD: 9803(GET_OBJECT_PROP_VALUE)l: 20 T:c : 14 dc41 (PERSISTENT_UID)
cannot open Index file
cannot open Index file
50692 RESP:2001(RSP:OK)l: 20 T:c : 14 dc41
50692 CMD: 9802(GET_OBJECT_PROP_DESC)l: 20 T:d : dc01 3001 (STORAGE_ID)
50693 RESP:2001(RSP:OK)l: 20 T:d : dc01 3001
50693 CMD: 9803(GET_OBJECT_PROP_VALUE)l: 20 T:e : 14 dc01 (STORAGE_ID)
cannot open Index file
cannot open Index file
50693 RESP:2001(RSP:OK)l: 20 T:e : 14 dc01
50693 CMD: 1007(GET_OBJECT_HANDLES)l: 24 T:f : 10001 0 14
** ScanDir called 0 20
cannot open Index file
cannot open Index file
cannot open Index file

Code:
CrashReport:
  A problem occurred at (system time) 0:0:21
  Code was executing from address 0xA258
  CFSR: 82
	(DACCVIOL) Data Access Violation
	(MMARVALID) Accessed Address: 0x9BDC4E0B
  Temperature inside the chip was 44.55 °C
  Startup CPU clock speed is 600MHz
  Reboot was caused by auto reboot after fault or bad interrupt detected
 
Decided to take a bit more structured approach to documenting testing results. The following table compares testing results with our latest changes to MTP/USBHost/SDfat/SD (using @KurtE's current forks) as well as my delayMicroseconds(50) hack in send_object. The test compares T3.6 and T4.1 using FAT32 and exFAT formatting issues and coping files after at format in MTP via windows explorer.
:D
Thanks @mjs513!

Sorry I don't have the patience to create tables like this on the forum :lol:

In SendObject, I assume you are not using the Simple Read/Write one logical packet (500 followed by 512 bytes long), but instead using the one that combines them int 2048 byte writes?

It is interesting with the 50us delay... ... Again just feels like there is some timing window in there... I know with the simple read/write, it feels like somewhere is trashing memory... Could be a timing window, like with the simple SendObject with no delays, we were more or less only using one out of four of the Transfer objects. We would get the callback that there is a buffer, which gets put onto the queue, we ask for data, it takes this one off the queue, copies the buffer to ours, and then queues it back up to be able to receive a packet... And it grabbed again and again.... With delays, it is more likely that the USB code will cycle at least through a couple of transfers/buffers... If there is too much delay than all 4 transfers will be sitting in the array of pending reads (like RAWHID), where it is waiting for user code to request data... Again wondering if there could also be issue in these cases where the other side sends us data to the endpoint and we have no available transfers...

Also interesting, that in several cases, it looked like all but the last two buffers were transferred. Thought in many cases maybe we missed a packet, but that is why I have the BogusFS and I send a file with sequence numbers in it, which my bogus FS checks for and prints out if it does not get the right sequence... Maybe this is a Windows MTP issue? or ???
 
@KurtE

In SendObject, I assume you are not using the Simple Read/Write one logical packet (500 followed by 512 bytes long), but instead using the one that combines them int 2048 byte writes?
That is correct I am using the stock send_object. This was intentional since I know you are testing with BogusFS and wanted to see the comparisons between that testing and what is in MTP.

It is interesting with the 50us delay... ... Again just feels like there is some timing window in there... I know with the simple read/write, it feels like somewhere is trashing memory... Could be a timing window, like with the simple SendObject with no delays, we were more or less only using one out of four of the Transfer objects. We would get the callback that there is a buffer, which gets put onto the queue, we ask for data, it takes this one off the queue, copies the buffer to ours, and then queues it back up to be able to receive a packet... And it grabbed again and again.... With delays, it is more likely that the USB code will cycle at least through a couple of transfers/buffers... If there is too much delay than all 4 transfers will be sitting in the array of pending reads (like RAWHID), where it is waiting for user code to request data... Again wondering if there could also be issue in these cases where the other side sends us data to the endpoint and we have no available transfers...
Based on different testing that we are doing sounds like you are right.

What would be interesting is if there was an easy way just to tell T4.1 to use 12mbit transfers instead of the 480 and see if we have the same issue or somehow throttle it back.

Also interesting, that in several cases, it looked like all but the last two buffers were transferred. Thought in many cases maybe we missed a packet, but that is why I have the BogusFS and I send a file with sequence numbers in it, which my bogus FS checks for and prints out if it does not get the right sequence... Maybe this is a Windows MTP issue? or ???
That is what kind of gave me the thought to put the delay in the send object loop. Since I was using the same file to test the copy to T4 with.

The current sketch I am using is variation of the copy file sketches. I repurposed some of @defragster's code to write big files (my case used 24mb) and 2mb files directly to the storage medium. Writing directly to the SD Cards (SDIO or SD10) seem to have no issue. Probably should modify that to use an indexed file.

Either way here is the sketch I am using with the storage index defaulting to SDIO card that goes boom:
Code:
#include <SD.h>
#include <MTP_Teensy.h>
#include <USBHost_t36.h>
#include <USBHost_ms.h>


// Add in MTPD objects
MTPStorage storage;
MTPD mtpd(&storage);

// Add USBHost objectsUsbFs
USBHost myusb;
USBHub hub1(myusb);
USBHub hub2(myusb);
USBHub hub(myusb);

// MSC objects.
msController drive1(myusb);
msController drive2(myusb);
msController drive3(myusb);

msFilesystem msFS1(myusb);
msFilesystem msFS2(myusb);
msFilesystem msFS3(myusb);
msFilesystem msFS4(myusb);
msFilesystem msFS5(myusb);

// Quick and dirty
msFilesystem *pmsFS[] = {&msFS1, &msFS2, &msFS3, &msFS4, &msFS5};
#define CNT_MSC  (sizeof(pmsFS)/sizeof(pmsFS[0]))
uint32_t pmsfs_store_ids[CNT_MSC] = {0xFFFFFFFFUL, 0xFFFFFFFFUL, 0xFFFFFFFFUL, 0xFFFFFFFFUL, 0xFFFFFFFFUL};
char  pmsFS_display_name[CNT_MSC][20];

msController *pdrives[] {&drive1, &drive2, &drive3};
#define CNT_DRIVES  (sizeof(pdrives)/sizeof(pdrives[0]))
bool drive_previous_connected[CNT_DRIVES] = {false, false, false};

//Add SD Card
#define USE_BUILTIN_SDCARD
#if defined(USE_BUILTIN_SDCARD) && defined(BUILTIN_SDCARD)
#define CS_SD BUILTIN_SDCARD
#else
#define CS_SD 10
#endif

#define COUNT_MYFS 2 // could do by count, but can limit how many are created...
typedef struct {
  uint8_t csPin;
  const char *name;
  SDClass sd;

} SDList_t;
SDList_t myFS[] = {
  {BUILTIN_SDCARD, "SDIO"},
  {10, "SPI10"}
};

// Experiment add memory FS to mainly hold the storage index
// May want to wrap this all up as well
#include <LittleFS.h>
#define LFSRAM_SIZE 65536 // probably more than enough...
LittleFS_RAM lfsram;

//==================================================
FS *myfs = &lfsram;

File myFile, dataFile;
int iRecord = 0;
int line = 0;

#define BUFFER_SIZE_INDEX 128
uint8_t write_buffer[BUFFER_SIZE_INDEX];
#define buffer_mult 4
uint8_t buffer_temp[buffer_mult*BUFFER_SIZE_INDEX];

int bytesRead;
uint32_t drive_index = 0;

// These can likely be left unchanged
#define MYBLKSIZE 2048 // 2048
#define SLACK_SPACE  40960 // allow for overhead slack space :: WORKS on FLASH {some need more with small alloc units}
#define size_bigfile 1024*1024*24  //24 mb file

// Various Globals
const uint32_t lowOffset = 'a' - 'A';
const uint32_t lowShift = 13;
uint32_t errsLFS = 0, warnLFS = 0; // Track warnings or Errors
uint32_t lCnt = 0, LoopCnt = 0; // loop counters
uint64_t rdCnt = 0, wrCnt = 0; // Track Bytes Read and Written
int filecount = 0;
int loopLimit = 0; // -1 continuous, otherwise # to count down to 0
bool bWriteVerify = true;  // Verify on Write Toggle
File file3; // Single FILE used for all functions

void setup()
{
  while (!Serial && millis() < 5000);
  Serial.begin(9600);

  if (CrashReport) {
    Serial.print(CrashReport);
  }
  Serial.println("\n" __FILE__ " " __DATE__ " " __TIME__);
  delay(3000);

  mtpd.begin();
  
  bool storage_added = false;
  for (uint8_t i = 0; i < COUNT_MYFS; i++) {
    if (myFS[i].sd.begin(myFS[i].csPin)) {
      storage_added = true;
      storage.addFilesystem(myFS[i].sd, myFS[i].name);
    }
  }
  if (!storage_added) {
    Serial.println("Failed to add any valid storage objects");
    pinMode(13, OUTPUT);
    while (1) {
      digitalToggleFast(13);
      delay(250);
    }
  }

  // lets initialize a RAM drive.
  if (lfsram.begin(LFSRAM_SIZE)) {
    Serial.printf("Ram Drive of size: %u initialized\n", LFSRAM_SIZE);
    uint32_t istore = storage.addFilesystem(lfsram, "RAM");
    //if (istore != 0xFFFFFFFFUL)
    //  storage.setIndexStore(istore);
    //Serial.printf("Set Storage Index drive to %u\n", istore);
  }

  
  myusb.begin();
  Serial.print("Initializing MSC Drives ...");
  Serial.println("\nInitializing USB MSC drives...");
  Serial.println("MSC and MTP initialized.");
  checkMSCChanges();

  menu();
  
}

void loop() {
  checkMSCChanges();
  mtpd.loop();
  
  if (Serial.available()) {
    uint8_t command = Serial.read();
    int ch = Serial.read();
    drive_index = CommandLineReadNextNumber(ch, 0);
    while (ch == ' ')
      ch = Serial.read();
    switch (command) {
    case '1': {
      // first dump list of storages:
      uint32_t fsCount = storage.getFSCount();
      Serial.printf("\nDump Storage list(%u)\n", fsCount);
      for (uint32_t ii = 0; ii < fsCount; ii++) {
        Serial.printf("store:%u storage:%x name:%s fs:%x\n", ii,
                      mtpd.Store2Storage(ii), storage.getStoreName(ii),
                      (uint32_t)storage.getStoreFS(ii));
      }
      Serial.println("\nDump Index List");
      storage.dumpIndexList();
    } break;
    case '2':
      Serial.printf("Drive # %d Selected\n", drive_index);
      myfs = storage.getStoreFS(drive_index);
      break;
    case 'l':
      listFiles();
      break;    
    case 'b':
      bigFile( 0 ); // delete
      command = 0;
      break;
    case 'B':
      bigFile( 1 ); // CREATE
      command = 0;
      break;
    case 's':
      bigFile2MB( 0 ); // CREATE
      command = 0;
      break;
    case 'S':
      bigFile2MB( 1 ); // CREATE
      command = 0;
     break;
    case 'n': // No Verify on write
      bWriteVerify = !bWriteVerify;
      bWriteVerify ? Serial.print(" Write Verify on: ") : Serial.print(" Write Verify off: ");
     command = 0;
      break;
    case 'R':
      Serial.print(" RESTART Teensy ...");
      delay(100);
      SCB_AIRCR = 0x05FA0004;
      break;
    case '\r':
    case '\n':
    case 'h':
      menu();
      break;
    default:
      menu();
      break;
    }
    while (Serial.read() != -1)
      ; // remove rest of characters.
  }
  
}

void checkMSCChanges() {
  myusb.Task();

  USBMSCDevice mscDrive;
  PFsLib pfsLIB;
  for (uint8_t i=0; i < CNT_DRIVES; i++) {
    if (*pdrives[i]) {
      if (!drive_previous_connected[i]) {
        if (mscDrive.begin(pdrives[i])) {
          Serial.printf("\nUSB Drive: %u connected\n", i);
          pfsLIB.mbrDmp(&mscDrive, (uint32_t)-1, Serial);
          Serial.printf("\nTry Partition list");
          pfsLIB.listPartitions(&mscDrive, Serial);
          drive_previous_connected[i] = true;
        }
      }
    } else {
      drive_previous_connected[i] = false;
    }
  }
  bool send_device_reset = false;
  for (uint8_t i = 0; i < CNT_MSC; i++) {
    if (*pmsFS[i] && (pmsfs_store_ids[i] == 0xFFFFFFFFUL)) {
      Serial.printf("Found new Volume:%u\n", i); Serial.flush();
      // Lets see if we can get the volume label:
      char volName[20];
      if (pmsFS[i]->mscfs.getVolumeLabel(volName, sizeof(volName)))
        snprintf(pmsFS_display_name[i], sizeof(pmsFS_display_name[i]), "MSC%d-%s", i, volName);
      else
        snprintf(pmsFS_display_name[i], sizeof(pmsFS_display_name[i]), "MSC%d", i);
      pmsfs_store_ids[i] = storage.addFilesystem(*pmsFS[i], pmsFS_display_name[i]);

      // Try to send store added. if > 0 it went through = 0 stores have not been enumerated
      if (mtpd.send_StoreAddedEvent(pmsfs_store_ids[i]) < 0) send_device_reset = true;
    }
    // Or did volume go away?
    else if ((pmsfs_store_ids[i] != 0xFFFFFFFFUL) && !*pmsFS[i] ) {
      if (mtpd.send_StoreRemovedEvent(pmsfs_store_ids[i]) < 0) send_device_reset = true;
      storage.removeFilesystem(pmsfs_store_ids[i]);
      // Try to send store added. if > 0 it went through = 0 stores have not been enumerated
      pmsfs_store_ids[i] = 0xFFFFFFFFUL;
    }
  }
  if (send_device_reset) mtpd.send_DeviceResetEvent();
}



void menu() {
  Serial.println();
  Serial.println("Menu Options:");
  Serial.printf("\n%s","1 - List USB Drives (Step 1)");
  Serial.printf("\n%s","2 - Select USB Drive for Logging (Step 2)");
  Serial.printf("\n%s","l - List files on disk");
  Serial.printf("\n%s","'B, or b': Make Big file half of free space, or remove all Big files");
  Serial.printf("\n%s","'S, or s': Make 2MB file , or remove all 2MB files");
  Serial.printf("\n%s","'n' No verify on Write- TOGGLE");
  Serial.printf("\n%s","'h' - Menu");
  Serial.println();
}


void listFiles() {
  Serial.print("\n Space Used = ");
  Serial.println(myfs->usedSize());
  Serial.print("Filesystem Size = ");
  Serial.println(myfs->totalSize());

  File root = myfs->open("/");
  printDirectory(root, 0);
  root.close();
}


void printDirectory(File dir, int numSpaces) {
  DateTimeFields dtf;
  while (true) {
    File entry = dir.openNextFile();
    if (!entry) {
      // Serial.println("** no more files **");
      break;
    }
    printSpaces(numSpaces);
    Serial.print(entry.name());
    printSpaces(36 - numSpaces - strlen(entry.name()));

    if (entry.getCreateTime(dtf)) {
      Serial.printf(" C: %02u/%02u/%04u %02u:%02u", dtf.mon + 1, dtf.mday, dtf.year + 1900, dtf.hour, dtf.min );
    }

    if (entry.getModifyTime(dtf)) {
      Serial.printf(" M: %02u/%02u/%04u %02u:%02u", dtf.mon + 1, dtf.mday, dtf.year + 1900, dtf.hour, dtf.min );
    }
    if (entry.isDirectory()) {
      Serial.println("  /");
      printDirectory(entry, numSpaces + 2);
    } else {
      // files have sizes, directories do not
      Serial.print("  ");
      Serial.println(entry.size(), DEC);
    }
    entry.close();
  }
}

void printSpaces(int num) {
  for (int i = 0; i < num; i++) {
    Serial.print(" ");
  }
}

uint32_t CommandLineReadNextNumber(int &ch, uint32_t default_num) {
  while (ch == ' ')
    ch = Serial.read();
  if ((ch < '0') || (ch > '9'))
    return default_num;

  uint32_t return_value = 0;
  while ((ch >= '0') && (ch <= '9')) {
    return_value = return_value * 10 + ch - '0';
    ch = Serial.read();
  }
  return return_value;
}

void readVerify( char szPath[], char chNow ) {
  uint32_t timeMe = micros();
  file3 = myfs->open(szPath);
  if ( 0 == file3 ) {
    Serial.printf( "\tV\t Fail File open %s\n", szPath );
    errsLFS++;
  }
  char mm;
  char chNow2 = chNow + lowOffset;
  uint32_t ii = 0;
  while ( file3.available() ) {
    file3.read( &mm , 1 );
    rdCnt++;
    //Serial.print( mm ); // show chars as read
    ii++;
    if ( 0 == (ii / lowShift) % 2 ) {
      if ( chNow2 != mm ) {
        Serial.printf( "<Bad Byte!  %c! = %c [0x%X] @%u\n", chNow2, mm, mm, ii );
        errsLFS++;
        break;
      }
    }
    else {
      if ( chNow != mm ) {
        Serial.printf( "<Bad Byte!  %c! = %c [0x%X] @%u\n", chNow, mm, mm, ii );
        errsLFS++;
        break;
      }
    }
  }
  Serial.printf( "  Verify %u Bytes ", ii );
  if (ii != file3.size()) {
    Serial.printf( "\n\tRead Count fail! :: read %u != f.size %llu", ii, file3.size() );
    errsLFS++;
  }
  file3.close();
  timeMe = micros() - timeMe;
  Serial.printf( " @KB/sec %5.2f", ii / (timeMe / 1000.0) );
}

bool bigVerify( char szPath[], char chNow ) {
  uint32_t timeMe = micros();
  file3 = myfs->open(szPath);
  uint64_t fSize;
  if ( 0 == file3 ) {
    return false;
  }
  char mm;
  uint32_t ii = 0;
  uint32_t kk = file3.size() / 50;
  fSize = file3.size();
  Serial.printf( "\tVerify %s bytes %lu : ", szPath, fSize );
  while ( file3.available() ) {
    file3.read( &mm , 1 );
    rdCnt++;
    ii++;
    if ( !(ii % kk) ) Serial.print('.');
    if ( chNow != mm ) {
      Serial.printf( "<Bad Byte!  %c! = %c [0x%X] @%u\n", chNow, mm, mm, ii );
      errsLFS++;
      break;
    }
    if ( ii > fSize ) { // catch over length return makes bad loop !!!
      Serial.printf( "\n\tFile LEN Corrupt!  FS returning over %u bytes\n", fSize );
      errsLFS++;
      break;
    }
  }
  if (ii != file3.size()) {
    Serial.printf( "\n\tRead Count fail! :: read %u != f.size %llu\n", ii, file3.size() );
    errsLFS++;
  }
  else
    Serial.printf( "\tGOOD! >>  bytes %lu", ii );
  file3.close();
  timeMe = micros() - timeMe;
  Serial.printf( "\n\tBig read&compare KBytes per second %5.2f \n", ii / (timeMe / 1000.0) );
  if ( 0 == ii ) return false;
  return true;
}



void bigFile( int doThis ) {
  char myFile[] = "/0_bigfile.txt";
  char fileID = '0' - 1;
  DateTimeFields dtf = {0, 10, 7, 0, 22, 7, 121};

  if ( 0 == doThis ) {  // delete File
    Serial.printf( "\nDelete with read verify all #bigfile's\n");
    do {
      fileID++;
      myFile[1] = fileID;
      if ( myfs->exists(myFile) && bigVerify( myFile, fileID) ) {
        filecount--;
        myfs->remove(myFile);
      }
      else break; // no more of these
    } while ( 1 );
  }
  else {  // FILL DISK
    uint32_t resW = 1;
    
    char someData[MYBLKSIZE];
    uint32_t xx, toWrite;
    toWrite = (myfs->totalSize()) - myfs->usedSize();
    if ( toWrite < 65535 ) {
      Serial.print( "Disk too full! DO :: reformat");
      return;
    }
    toWrite = size_bigfile;
    toWrite -= SLACK_SPACE;
    xx = toWrite;
    Serial.printf( "\nStart Big write of %u Bytes", xx);
    uint32_t timeMe = micros();
    file3 = nullptr;
    do {
      if ( file3 ) file3.close();
      fileID++;
      myFile[1] = fileID;
      file3 = myfs->open(myFile, FILE_WRITE);
    } while ( fileID < '9' && file3.size() > 0);
    if ( fileID == '9' ) {
      Serial.print( "Disk has 9 halves 0-8! DO :: b or q or F");
      return;
    }
    memset( someData, fileID, 2048 );
    int hh = 0;
    while ( toWrite > 2048 && resW > 0 ) {
      resW = file3.write( someData , 2048 );
      hh++;
      if ( !(hh % 40) ) Serial.print('.');
      toWrite -= 2048;
    }
    xx = toWrite;
    file3.setCreateTime(dtf);
    file3.setModifyTime(dtf);
    file3.close();
    timeMe = micros() - timeMe;
    file3 = myfs->open(myFile, FILE_WRITE);
    if ( file3.size() > 0 ) {
      filecount++;
      Serial.printf( "\nBig write %s took %5.2f Sec for %lu Bytes : file3.size()=%llu", myFile , timeMe / 1000000.0, xx, file3.size() );
    }
    if ( file3 != 0 ) file3.close();
    Serial.printf( "\n\tBig write KBytes per second %5.2f \n", xx / (timeMe / 1000.0) );
    Serial.printf("\nBytes Used: %llu, Bytes Total:%llu\n", myfs->usedSize(), myfs->totalSize());
    if ( myfs->usedSize() == myfs->totalSize() ) {
      Serial.printf("\n\n\tWARNING: DISK FULL >>>>>  Bytes Used: %llu, Bytes Total:%llu\n\n", myfs->usedSize(), myfs->totalSize());
      warnLFS++;
    }
    if ( resW < 0 ) {
      Serial.printf( "\nBig write ERR# %i 0x%X \n", resW, resW );
      errsLFS++;
      myfs->remove(myFile);
    }
  }
}

void bigFile2MB( int doThis ) {
  char myFile[] = "/0_2MBfile.txt";
  char fileID = '0' - 1;
  DateTimeFields dtf = {0, 10, 7, 0, 22, 7, 121};

  if ( 0 == doThis ) {  // delete File
    Serial.printf( "\nDelete with read verify all #bigfile's\n");
    do {
      fileID++;
      myFile[1] = fileID;
      if ( myfs->exists(myFile) && bigVerify( myFile, fileID) ) {
        filecount--;
        myfs->remove(myFile);
      }
      else break; // no more of these
    } while ( 1 );
  }
  else {  // FILL DISK
    uint32_t resW = 1;
    
    char someData[2048];
    uint32_t xx, toWrite;
    toWrite = 2048 * 1000;
    if ( toWrite > (65535 + (myfs->totalSize() - myfs->usedSize()) ) ) {
      Serial.print( "Disk too full! DO :: q or F");
      return;
    }
    xx = toWrite;
    Serial.printf( "\nStart Big write of %u Bytes", xx);
    uint32_t timeMe = micros();
    file3 = nullptr;
    do {
      if ( file3 ) file3.close();
      fileID++;
      myFile[1] = fileID;
      file3 = myfs->open(myFile, FILE_WRITE);
    } while ( fileID < '9' && file3.size() > 0);
    if ( fileID == '9' ) {
      Serial.print( "Disk has 9 files 0-8! DO :: b or q or F");
      return;
    }
    memset( someData, fileID, 2048 );
    int hh = 0;
    while ( toWrite >= 2048 && resW > 0 ) {
      resW = file3.write( someData , 2048 );
      hh++;
      if ( !(hh % 40) ) Serial.print('.');
      toWrite -= 2048;
    }
    xx -= toWrite;
    file3.setCreateTime(dtf);
    file3.setModifyTime(dtf);
    file3.close();
    timeMe = micros() - timeMe;
    file3 = myfs->open(myFile, FILE_WRITE);
    if ( file3.size() > 0 ) {
      filecount++;
      Serial.printf( "\nBig write %s took %5.2f Sec for %lu Bytes : file3.size()=%llu", myFile , timeMe / 1000000.0, xx, file3.size() );
    }
    if ( file3 != 0 ) file3.close();
    Serial.printf( "\n\tBig write KBytes per second %5.2f \n", xx / (timeMe / 1000.0) );
    Serial.printf("\nBytes Used: %llu, Bytes Total:%llu\n", myfs->usedSize(), myfs->totalSize());
    if ( myfs->usedSize() == myfs->totalSize() ) {
      Serial.printf("\n\n\tWARNING: DISK FULL >>>>>  Bytes Used: %llu, Bytes Total:%llu\n\n", myfs->usedSize(), myfs->totalSize());
      warnLFS++;
    }
    if ( resW < 0 ) {
      Serial.printf( "\nBig write ERR# %i 0x%X \n", resW, resW );
      errsLFS++;
      myfs->remove(myFile);
    }
  }
}
 
@Paul and @mjs513 and ...

Note: Running T4.1 (RC firmware in this case)

Sort of to illustrate the issue:
I have setup bogusFS... Which is really bogus...
Code:
#ifndef __BogusFS_H__
#define __BogusFS_H__
#define T4_USE_SIMPLE_SEND_OBJECT // should match mtp_teensy
#include <Arduino.h>
#include <FS.h>

class BogusFile : public  FileImpl {
public:
	BogusFile(const char *filename, uint8_t mode) {
		strlcpy(_filename, filename, sizeof(_filename));
		_fOpen = true;
		_last_packet_number = -1;
		_error_count = 0;
		_file_size = 0;
	};
	~BogusFile() {close(); }
	virtual size_t read(void *buf, size_t nbyte) { return 0; }
	virtual size_t write(const void *buf, size_t size);
	virtual int available() { return 0;}
	virtual int peek() {return -1;}
	virtual void flush() {}
	virtual bool truncate(uint64_t size=0) {return true;};
	virtual bool seek(uint64_t pos, int mode) {return false;}
	virtual uint64_t position()  { return 0;}
	virtual uint64_t size()  { return _file_size;}
	virtual void close() {_fOpen = false;};
	virtual bool isOpen() {return _fOpen;}
	virtual const char* name() {return _filename;}
	virtual bool isDirectory() { return (strcmp(_filename, "/") == 0);}
	virtual File openNextFile(uint8_t mode=0) {return File();}
	virtual void rewindDirectory(void) {};
	char _filename[256];
	uint32_t _file_size = 0;
	uint32_t _offset = 0;
	int32_t _last_packet_number = -1;
	uint32_t _error_count = 0;
	bool _fOpen;
	bool _simple_send_object = false;
};

size_t BogusFile::write(const void *buf, size_t size) {
//	digitalWriteFast(6, HIGH);
	const uint8_t *pb = (const uint8_t*)buf;
	int32_t packet_number = 0;
	for (uint16_t i = 0; pb[i] >= '0' && pb[i] <= '9'; i++) packet_number = packet_number * 10 + pb[i] - '0';
	if (packet_number != (_last_packet_number + 1)) {
		if (_error_count < 10) 	Serial.printf("$$$ BF Sequence error %d %d\n", packet_number, _last_packet_number);
		_error_count++;
	}
	_last_packet_number = packet_number;
	_file_size += size;
	//delayMicroseconds(500);
	delay(1);
//	digitalWriteFast(6, LOW);
	return size;
}

class BogusFS : public  FS
{
public:
	BogusFS() {};
	virtual File open(const char *filename, uint8_t mode = FILE_READ) {
		Serial.printf("BogusFS::open(%s, %x)\n", filename, mode);
		return File(new BogusFile(filename, mode));
	}
	virtual bool exists(const char *filepath) {Serial.printf("BogusFS::exists(%s)\n", filepath); return true;}
	virtual bool mkdir(const char *filepath)  {Serial.printf("BogusFS::mkdir(%s)\n", filepath); return true;}
	virtual bool rename(const char *oldfilepath, const char *newfilepath) {Serial.printf("BogusFS::rename(%s, %s)\n", oldfilepath, newfilepath); return true;}
	virtual bool remove(const char *filepath)  {Serial.printf("BogusFS::remove(%s)\n", filepath); return true;}
	virtual bool rmdir(const char *filepath)  { Serial.printf("BogusFS::rmdir(%s)\n", filepath); return true;}
	virtual uint64_t usedSize()  { return 16000000000ul;} 
	virtual uint64_t totalSize() { return 32000000000ul;}
};

#endif // __BogusFS_H__
Note I did not include the ifdefed out code (for larger buffered writes)...

In this last run of copying the large file to bogus: we see:
Code:
BogusFS::open(/T4LargeIndexedTestfile.txt, 2)
56107 RESP:2001(RSP:OK)l: 24 T:a : 20001 ffffffff 14
56107 CMD: 100d(SEND_OBJECT)l: 12 T:b
MTPD::SendObject: len:22015988
    $$*: 0
BogusFS::open(/T4LargeIndexedTestfile.txt, 0)
 # USB Packets: 42999 total: 56 avg ms: 0 max: 6
 # Write: 43000 total:43021 avg ms: 1 max: 2
>>>Total Time: 43077043
1 : 41414141 41414141 41414141 41414141 41414141
*** Start Interval Timer ***
The start interval... Is in setup after it restarts...
Not sure where the 1:... line came from?
The end of the SendObject code is:
Code:
  if (c_read_em)
    printf(" # USB Packets: %u total: %u avg ms: %u max: %u\n", c_read_em,
           sum_read_em, sum_read_em / c_read_em, read_em_max);
  if (c_write_em)
    printf(" # Write: %u total:%u avg ms: %u max: %u\n", c_write_em,
           sum_write_em, sum_write_em / c_write_em, write_em_max);
  printf(">>>Total Time: %u\n", (uint32_t)em_total);
  Serial.flush();

  return (len == 0);
}
So you can see where most of those outputs come from
The call to it is:
Code:
        if (!SendObject()) {
          return_code = MTP_RESPONSE_INCOMPLETE_TRANSFER;
          send_Event(
              MTP_EVENT_CANCEL_TRANSACTION); // try sending an event to cancel?
        } else {
            printf("SendObject() returned true\n"); Serial.flush();
        }
        len = 12;
        break;
This should have returned TRUE as $$*: 0 the 0 was the len value... And we don't get the simple message from caller???


Next Interesting information by Logic Analyzer: Right now using 7 channels of output:
First 4 show the status of the 4 RX transfers: I hacked up cores: usb_tmp.c
Code:
static void rx_queue_transfer(int i)
{
	NVIC_DISABLE_IRQ(IRQ_USB1);
	void *buffer = rx_buffer + i * MTP_RX_SIZE_480;
	arm_dcache_delete(buffer, rx_packet_size);
	usb_prepare_transfer(rx_transfer + i, buffer, rx_packet_size, i);
	usb_receive(MTP_RX_ENDPOINT, rx_transfer + i);
	switch (i) {
		case 0: digitalWriteFast(0, LOW); break;
		case 1: digitalWriteFast(1, LOW); break;
		case 2: digitalWriteFast(2, LOW); break;
		case 3: digitalWriteFast(3, LOW); break;
		default: digitalWriteFast(4, LOW); break;
	}
	NVIC_ENABLE_IRQ(IRQ_USB1);
}

static void rx_event(transfer_t *t)
{
	int i = t->callback_param;
	//printf("rx event i=%d\n", i);
	// received a packet with data
	uint32_t head = rx_head;
	if (++head > RX_NUM) head = 0;
	rx_list[head] = i;
	switch (i) {
		case 0: digitalWriteFast(0, HIGH); break;
		case 1: digitalWriteFast(1, HIGH); break;
		case 2: digitalWriteFast(2, HIGH); break;
		case 3: digitalWriteFast(3, HIGH); break;
		default: digitalWriteFast(4, HIGH); break;
	}
	rx_head = head;
}
Note: could remove default never hit it... So I now use it to know when the host code calls usb_mtp_recv to retrieve data:

Code:
int usb_mtp_recv(void *buffer, uint32_t timeout)
{
	uint32_t wait_begin_at = systick_millis_count;
	uint32_t tail = rx_tail;
	digitalWriteFast(4, HIGH);
	while (1) {
		if (!usb_configuration) return -1; // usb not enumerated by host
		if (tail != rx_head) break;
		if (systick_millis_count - wait_begin_at > timeout)  {
			return 0;
		}
		//yield();
	}
//	digitalWriteFast(0, LOW);
	if (++tail > RX_NUM) tail = 0;
	uint32_t i = rx_list[tail];
	rx_tail = tail;

	memcpy(buffer,  rx_buffer + i * MTP_RX_SIZE_480, rx_packet_size);
	rx_queue_transfer(i);
	//memset(rx_transfer, 0, sizeof(rx_transfer));
	//usb_prepare_transfer(rx_transfer + 0, rx_buffer, rx_packet_size, 0);
	//usb_receive(MTP_RX_ENDPOINT, rx_transfer + 0);
	digitalWriteFast(4, LOW);
	return rx_packet_size;
}

I use pin 5 in the SendObject code to bracket calls to write:
Code:
    digitalWriteFast(5, HIGH);
    if (storage_->write((const char *)rx_data_buffer, bytes) < bytes)
      return false;
    digitalWriteFast(5, LOW);

and right now I am using pin 6 to bracket when we are in (cores\teensy4\usb.c: void usb_isr(void) ... At start and end...


Now the fun. From the crash above the complete capture looks like:
screenshot.jpg

Note the large gap in all of the traces at the right hand side... This is when it stopped and then the little bit at far right is when it reset...

Now zooming in toward the end: you can see where each of the RX transfers had their last data, which was then processed for the sendObject and no New data yet. and then the usb_isr goes nuts... Before the transfer nothing on it, during it you can see each call to it for the transfer data that came in.
screenshot2.jpg

Close up looks like some state or the like that maybe not clearing some state?
screenshot3.jpg

Now where to instrument next?
 
Gave a quick read of today's posts ...

The only thing that jumped out was ... when all four buffers filled for output ? ... a historical/anecdotal observation clouded by time and not known resolution as it has stopped doing that ...

There was a case on the Beta 1 thread, or prior? Unceasing fast Teensy output to T_sermon hung the Teensy I/O process. Adding DUAL USB was still good for debug I/O as it has unique buffer space.

When all the USB buffers are filled for output - can the Teensy receive a new packet from the host?
> Does one of the Logic Analyzer pins track Host message 'seen' and then processed?
 
Further update: I turned on teensy4 core debug to Serial4 (I then unfortunately I think Fried the T4.1 :( ) Was connecting up to wrong rail of T4 used to forward Serial4... SO plugged in different one...

I went into the usb_isr code and uncommented all of the printf... Actually made them conditional:

Code:
uint8_t g_usb_isr_print = 0;

void usb_isr(void)
{
	digitalWriteFast(6, HIGH);
	if (g_usb_isr_print) printf("*");

Then hacked up the SendObject code that after it exited the loop, it turned that variable true...
When I hit this point, It just ended up printing the *'s... None of the other printfs happened.
So added:
Code:
	// USB_USBSTS_SRI - set at start of frame
	// USB_USBSTS_SRI - set when USB reset detected

	if (g_usb_isr_print) printf("status: %x\n", status);
	if (status & USB_USBSTS_UI) {

And now you get a lot of: status 80 and then startup...

Code:
*status: 00000080
*status: 00000080
*status: 00000080
*status: 00000080
*status: 00000080
*status: 00000080
...
*status: 00000080
*status: 00000080
*status: 00000080

***********IMXRT Startup**********
test 1 -1234567 3
CCM_ANALOG_PLL_USB1=80003000
  enable USB clocks
CCM_ANALOG_PLL_USB1=80003040
Increasing voltage to 1250 mV
need to switch to alternate clock during reconfigure of ARM PLL
USB PLL is running, so we can use 120 MHz
Freq: 12 MHz * 100 / 2 / 1
ARM PLL=80002042
ARM PLL needs reconfigure
ARM PLL=80002064
New Frequency: ARM=600000000, IPG=150000000
analogInit
BURSTSIZE=00000808
BURSTSIZE=00000808
USB1_TXFILLTUNING=00000000
USB reset took 6 loops
usb_seremu_configure
usb_mtp_configure
beginCycles 1199999

I think these are Start of Frame? (SRI).
Which looks like it can be setup for a reset:
Code:
	if ((USB1_USBINTR & USB_USBINTR_SRE) && (status & USB_USBSTS_SRI)) {
		if (g_usb_isr_print) printf("sof %d\n", usb_reboot_timer);
		if (usb_reboot_timer) {
			if (--usb_reboot_timer == 0) {
So now to see what next to ....
 
Back
Top