Teensyduino File System Integration, including MTP and MSC

@KurtE
Couldn't sleep so decided to play with changing the buffer size back to 8k from 2k. We changed 2k early on but never retested after all the other changes were made.

Bottom line up front - looks like can change back to 8k buffer size. May want to test with your SSD:

Code:
128GB jump drive with 2 exFAT Primary partitions

2k buffer
MTPD::SendObject: len:23672380
 # USB Packets: 46235 total: 0 avg ms: 0 max: 0
 # Write: 11559 total:68924 avg ms: 5 max: 944

4k buffer
MTPD::SendObject: len:23672380
 # USB Packets: 46235 total: 704 avg ms: 0 max: 1
 # Write: 5780 total:57794 avg ms: 9 max: 950

8k buffer
MTPD::SendObject: len:23672380
 # USB Packets: 46235 total: 665 avg ms: 0 max: 1
 # Write: 2890 total:68511 avg ms: 23 max: 958
==================================================

GPT Disk 
exFat partition - 2k buffer
MTPD::SendObject: len:23672380
 # USB Packets: 46235 total: 0 avg ms: 0 max: 0
 # Write: 11559 total:41561 avg ms: 3 max: 31
 
 exFat partition - 4k buffer
MTPD::SendObject: len:23672380
 # USB Packets: 46235 total: 652 avg ms: 0 max: 1
 # Write: 5780 total:41567 avg ms: 7 max: 34

 exFat partition - 8k buffer
MTPD::SendObject: len:23672380
 # USB Packets: 46235 total: 682 avg ms: 0 max: 1
 # Write: 2890 total:41605 avg ms: 14 max: 41
 
 
 ====================================
Try Partition list
PART	Type	Start	Count	(MBR	Part)	Volume Type
1	M	2048	47298560	0	0	Fat32:
2	E	47300672	73844672	47300608	0	exFAT

8k buffer fat32
MTPD::SendObject: len:23672380
 # USB Packets: 46235 total: 679 avg ms: 0 max: 1
 # Write: 2890 total:50911 avg ms: 17 max: 691
 
8k buffer xFAT
MTPD::SendObject: len:23672380
 # USB Packets: 46235 total: 691 avg ms: 0 max: 1
 # Write: 2890 total:55321 avg ms: 19 max: 692

=====================================================
Try Partition list
PART	Type	Start	Count	(MBR	Part)	Volume Type
1	M	32768	121112576	0	0	exFAT

8k buffer xFAT
MTPD::SendObject: len:23672380
 # USB Packets: 46235 total: 685 avg ms: 0 max: 1
 # Write: 2890 total:52773 avg ms: 18 max: 689
 
This sketch? : \MTP_Teensy\examples\USB_MTP-logger\USB_MTP-logger.ino

Two drives - PLEX is an older SSD/SATA:
Code:
Dump Storage list(3)
store:0 storage:10001 name:RAM fs:2000bd98
store:1 storage:20001 name:MSC0-Plex120 fs:2000a270
store:2 storage:30001 name:MSC1-120GB_Ext fs:2000a740

Copy a 18+ MB file?

2k
Code:
MTPD::SendObject: len:19256968
 # USB Packets: 37611 total: 6 avg ms: 0 max: 4
 # Write: 9403 total:37678 avg ms: 4 max: 72
>>>Total Time: 37,693,776

?? 8K here? ::
Code:
C:\T_Drive\tCode\libraries\MTP_Teensy\src\MTP_Teensy.h:
  103    uint8_t tx_data_buffer[MTP_TX_SIZE] __attribute__((aligned(32)));
  104  
  105:   static const uint32_t DISK_BUFFER_SIZE = 2 * 1024;

8k?
Code:
MTPD::SendObject: len:19256968
 # USB Packets: 37611 total: 597 avg ms: 0 max: 13
 # Write: 2351 total:37824 avg ms: 16 max: 17
>>>Total Time: 38,481,715
 
Morning all,

The write size for transfers has/is sort of a tricky balancing act...

For SD and USB, most of the times, the bigger the better.

But the problem I have been running into is more with LittleFS...

I still more often then I would like get the incomplete transfers and MTP is toast state.

For example with the memory board: Running the sketch that adds all of them:

screenshot.jpg

Transferring a 3.21MB jpg

Even at 2K I have had transfers time out on Flash 3: twice

3:
Code:
MTPD::SendObject *** USB Read Timeout ***
 # USB Packets: 4084 total: 0 avg ms: 0 max: 0
 # Write: 1022 total:10916 avg ms: 10 max: 45
>>>Total Time: 11434904
*MTPD::send_Event(4001)
125852 RESP:2007(RSP:INCOMPLETE_TRANSFER)l: 12 T:44

Code:
MTPD::SendObject *** USB Read Timeout ***
 # USB Packets: 4596 total: 0 avg ms: 0 max: 0
 # Write: 1150 total:26856 avg ms: 23 max: 46
>>>Total Time: 27373953
*MTPD::send_Event(4001)
192528 RESP:2007(RSP:INCOMPLETE_TRANSFER)l: 12 T:10

4:
Code:
MTPD::SendObject: len:3373255
 # USB Packets: 6588 total: 0 avg ms: 0 max: 0
 # Write: 1648 total:12071 avg ms: 7 max: 10
>>>Total Time: 12088731

5:
Code:
44070 CMD: 100d(SEND_OBJECT)l: 12 T:11
MTPD::SendObject: len:3373255
 # USB Packets: 6588 total: 1 avg ms: 0 max: 1
 # Write: 1648 total:3947 avg ms: 2 max: 37
>>>Total Time: 3989373

6:
Code:
MTPD::SendObject: len:3373255
 # USB Packets: 6588 total: 0 avg ms: 0 max: 0
 # Write: 1648 total:3794 avg ms: 2 max: 36
>>>Total Time: 3832753

Again this is with 2K... I remember when at 8K we were seeing max write times > 100ms... I think the T3.x code writes the buffers as they come in, which would then be unaligned as the first buffer of 512 has header information...

Need to play more.

But again maybe still need code that says, if SDFS use write sizes of X, if USB use write sizes of Y and for LittleFS size Z (maybe z1, z2... depending on Flash vs...)

Need to play more once I wake up :D
 
But again maybe still need code that says, if SDFS use write sizes of X, if USB use write sizes of Y and for LittleFS size Z (maybe z1, z2... depending on Flash vs...)

Need to play more once I wake up
Forgot that LittleFS was the issue with the buffer size. But may have to go that route, i.e., file system dependent. Or... but still on my first sip of coffee.
 
I have had a few more sips :D

Sorry I am jumping around...

But again wondered about USB speed for writing those files...

So I am still at 2kb... Have not changed it yet...

But was curious, so instrumented the writeSectors call:
Code:
//------------------------------------------------------------------------------
bool USBMSCDevice::writeSectors(uint32_t sector, const uint8_t* src, size_t n) {
	// Check if device is plugged in and initialized
	if((m_errorCode = ((msController *)thisDrive)->checkConnectedInitialized()) != MS_CBW_PASS) {
		return false;
	}
  if (digitalReadFast(0)) Serial.println(n, DEC);
  
	m_errorCode = thisDrive->msWriteBlocks(sector, n,
	              (uint16_t)thisDrive->msDriveInfo.capacity.BlockSize, src);
	if(m_errorCode) {
		return false;
	}
  return true;
}

Ran a smaller object:
Code:
135405 RESP:2001(RSP:OK)l: 24 T:51 : 30001 ffffffff 19
135406 CMD: 100d(SEND_OBJECT)l: 12 T:52
MTPD::SendObject: len:17686
1
1
1
1
1
1
1
1
1
1
1
1
1
1
1
1
1
1
1
1
1
1
1
1
1
1
1
1
1
1
1
1
1
1
1
1
1
1
1
1
 # USB Packets: 34 total: 0 avg ms: 0 max: 0
 # Write: 9 total:17 avg ms: 1 max: 2

So while I am making 2KB calls to write, we are only writing one sector at a time... So now wondering how hard will it be to have the code go... I can actually write N sectors in one call. As each of these calls, does sends, plus wait for acks...
 
Follow on to the previous post:

Was again curious why Fat code was calling the writes 1 sector at a time:

First off print out information on clusters:
!!!FatPartition::init SecPerClus:64 mask:3f: Shirt:6

So should handle writing 4 sectors...

Actually turns out we are calling the Fat write function 1 byte at a time:

Trying to track down where in the code: Some initial debut output:


Code:
41172 CMD: 100d(SEND_OBJECT)l: 12 T:75
MTPD::SendObject: len:2048
MTPStorage::write(20007cc0, 2048)
MSCFile::write(2005fed7, 1)
PFSFile::write(2005fed7, 1)
FFW: 2005fed7 1
MSCFile::write(2005fed7, 1)
PFSFile::write(2005fed7, 1)
FFW: 2005fed7 1
MSCFile::write(2005fed7, 1)
PFSFile::write(2005fed7, 1)
FFW: 2005fed7 1
...
MSCFile::write(2005fed7, 1)
PFSFile::write(2005fed7, 1)
FFW: 2005fed7 1
MSCFile::write(2005fed7, 1)
PFSFile::write(2005fed7, 1)
FFW: 2005fed7 1
1

So the MTP code callsoff to MTPStorage:: with a write of 2048

Code:
size_t MTPStorage::write(const char *data, uint32_t bytes)
{
	mtp_lock_storage(true);
	Serial.printf("MTPStorage::write(%x, %u)\n", (uint32_t)data, bytes);
	size_t ret = file_.write(data, bytes);
	mtp_lock_storage(false);
	return ret;
}
But somewhere in chain of objects is not handling the block write and has unwound it to loop through calling 1 byte at a time... Still trying to figure out where in the types of objects...
 
That sounds like an interesting find ... at least it wasn't doing bits :)

4 sectors (2KB) at a time might make a huge perf increase.

Is my p#404 getting me to the right place? This is my first wander into this code so hoping Sublime is leading the right way.
 
@KurtE - That explains why I was only getting a 1 MB/s transfer rate when copying a file to my Kingston SSD drive. When using diskIo I was getting over 10 MB/s transfer rate. In diskIo I have a 32768 byte buffer. Performing the same printout as above I was seeing n=64 which is 64*512= 32768. In ExFatFileWrite.cpp at line #714:
Code:
#if USE_MULTI_SECTOR_IO
[COLOR="#FF0000"]   } else if (toWrite >= 2*m_vol->bytesPerSector()) {[/COLOR] 
      // use multiple sector write command
      uint32_t ns = toWrite >> m_vol->bytesPerSectorShift();
      // Limit writes to current cluster.
      uint32_t maxNs = m_vol->sectorsPerCluster()
                       - (clusterOffset >> m_vol->bytesPerSectorShift());
      if (ns > maxNs) {
        ns = maxNs;
      }
      n = ns << m_vol->bytesPerSectorShift();
      if (!m_vol->cacheSafeWrite(sector, src, ns)) {
         DBG_FAIL_MACRO;
        goto fail;
      }
#endif  // USE_MULTI_SECTOR_IO
    } else {
      n = m_vol->bytesPerSector();
      if (!m_vol->cacheSafeWrite(sector, src)) {
        DBG_FAIL_MACRO;
        goto fail;
      }
    }
'toWrite' is showing 1 as well.

I am not sure how the count goes through the chain of objects but I have tracked it into FS.h. It is going through this write function line #231:
Code:
	size_t write(uint8_t b) {
Serial.printf("size_t write(uint8_t b)\n");
		return (f) ? f->write(&b, 1) : 0;
	}
Don't know if that helps or not...

EDIT: In mscFS.h line #58:
Code:
	virtual size_t write(const void *buf, size_t size) {
Serial.printf("size = %d\n",size);
		return mscfatfile.write(buf, size);
	}

Is also part of the sequence of events. size = 1.
 
Last edited:
That sounds like an interesting find ... at least it wasn't doing bits :)

4 sectors (2KB) at a time might make a huge perf increase.

Is my p#404 getting me to the right place? This is my first wander into this code so hoping Sublime is leading the right way.

Yep that is an interesting find - am curious why as well.

Tim - that is the correct spot for changing the buffer size. As Kurt mentioned for Nor flash it has to be 2k - for NAND flash you can use 8k. Might be related to the prog size specified in littleFS which is based on the chip spects. The Q512 for instance used a 256 byte buffer for writing while the NANDs use 2048 byte buffer
 
@Paul and all... Much more fundamental problem!

Dummy Sketch:
Code:
#include <FS.h>

class FOOFileImpl : public FileImpl
{
public:
  FOOFileImpl() {}
  virtual ~FOOFileImpl() { }
  virtual size_t read(void *buf, size_t nbyte) {return 0;}
  virtual size_t write(const void *buf, size_t size) {
    Serial.printf("Foo::Write (%x %u)\n", (uint32_t)buf, size);
    return size;}
  virtual int available() {return 0;}
  virtual int peek() {return 0;}
  virtual void flush() {}
  virtual bool truncate(uint64_t size=0) {return 0;}
  virtual bool seek(uint64_t pos, int mode) {return 0;}
  virtual uint64_t position() {return 0;}
  virtual uint64_t size() {return 0;}
  virtual void close() {}
  virtual bool isOpen() {return 0;}
  virtual const char* name() {return 0;}
  virtual bool isDirectory() {return 0;}
  virtual File openNextFile(uint8_t mode=0) {return File();}
  virtual void rewindDirectory(void) {}
  virtual bool getCreateTime(DateTimeFields &tm) { return false; }
  virtual bool getModifyTime(DateTimeFields &tm) { return false; }
  virtual bool setCreateTime(const DateTimeFields &tm) { return false; }
  virtual bool setModifyTime(const DateTimeFields &tm) { return false; }
private:
  friend class File;
  unsigned int refcount = 0; // number of File instances referencing this FileImpl
};

File file;
uint8_t buffer[] = "abcd";

void setup() {
   while(!Serial) ;
   Serial.begin(115200);
   file = File(new FOOFileImpl);
  file.write(buffer, sizeof(buffer));     

}

void loop() {
  // put your main code here, to run repeatedly:

}
Output:
Code:
Foo::Write (20077fd7 1)
Foo::Write (20077fd7 1)
Foo::Write (20077fd7 1)
Foo::Write (20077fd7 1)
Foo::Write (20077fd7 1)

The problem is there are two write buffer functions in the File class: including:
Code:
size_t write(const void *buf, size_t size) {
		return (f) ? f->write(buf, size) : 0;
	}
Which is not called...

Instead: from the class definition: class File final : public Stream {
We are actually in this case calling:
Code:
ize_t Print::write(const uint8_t *buffer, size_t size)
{
	if (buffer == nullptr) return 0;
	size_t count = 0;
	while (size--) count += write(*buffer++);
	return count;
}
which gives it to us one byte at a time

EDIT:
It turns out that the two methods are defined slightly different:

in FS.h
Code:
size_t write(const void *buf, size_t size) {

In Print.h
Code:
	virtual size_t write(const uint8_t *buffer, size_t size);

So if in example I cast my call to (void*), then it calls through passing the whole buffer!
 
Last edited:
Follow on: For now on mine I edited 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;
	}

	size_t write(const void *buf, size_t size) {
		return (f) ? f->write(buf, size) : 0;
	}
I left the void version...

Then for the 3.2mb file:
Code:
0515 CMD: 100d(SEND_OBJECT)l: 12 T:a
MTPD::SendObject: len:3373255
 # USB Packets: 6588 total: 1 avg ms: 0 max: 1
 # Write: 1648 total:619 avg ms: 0 max: 1
>>>Total Time: 622650

Or to exfat my 26mbg sixpair.... zip file:
Code:
MTPD::SendObject: len:26917168
 # USB Packets: 52572 total: 6 avg ms: 0 max: 1
 # Write: 13144 total:4928 avg ms: 0 max: 1
>>>Total Time: 4937904
Which is a ton better!
 
Cool, I just changed this in MTP_storage.cpp:
Code:
size_t MTPStorage::write(const char *data, uint32_t bytes)
{
	mtp_lock_storage(true);
	size_t ret = file_.write([COLOR="#FF0000"](void *)[/COLOR]data, bytes);
//Serial.printf("bytes = %d, ret = %d\n",bytes,ret);
	mtp_lock_storage(false);
	return ret;
}

Will do your temporary change in FS.h.

Good sleuthing:)

EDIT: My result with a 32meg file:
Code:
SendObjectInfo: 131073 4294967295 20007ac0: 20001 3000 0 1f40200 0 0 0 0 0 0 0 ffffffff 0 0 0 : 32MEGfile.dat
Created: 0
Modified: 0
32154 RESP:2001(RSP:OK)l: 24 T:85 : 20001 ffffffff 16
32154 CMD: 100d(SEND_OBJECT)l: 12 T:86
MTPD::SendObject: len:32768512
&&DT (0,0) (1635689720,1635689720)
 # USB Packets: 64001 total: 1585 avg ms: 0 max: 2
 # Write: 1001 total:1477 avg ms: 1 max: 15
>>>Total Time: 3160549
 
Last edited:
Next: Copying a file from one MTP Teensy device to another fails in (Copy Object). Copying from a MTP Teensy device to the host works fine both way's. One step at a time:)
 
This sketch? : \MTP_Teensy\examples\USB_MTP-logger\USB_MTP-logger.ino

Two drives - PLEX is an older SSD/SATA:
Code:
Dump Storage list(3)
store:0 storage:10001 name:RAM fs:2000bd98
store:1 storage:20001 name:MSC0-Plex120 fs:2000a270
store:2 storage:30001 name:MSC1-120GB_Ext fs:2000a740

Copy a 18+ MB file?

2k
Code:
MTPD::SendObject: len:19256968
 # USB Packets: 37611 total: 6 avg ms: 0 max: 4
 # Write: 9403 total:37678 avg ms: 4 max: 72
>>>Total Time: 37,693,776
...

@mjs513 thanks for confirming - but back to 2KB buffe rusage - and the edit to FS.h:
Code:
MTPD::SendObject: len:19256968
 # USB Packets: 37611 total: 15 avg ms: 0 max: 8
[B] # Write: 9403 total:9399 avg ms: 0 max: 2[/B]
>>>Total Time: 9,424,619

Same file copy to the 2.5" HDD mounted internal to the powered HUB unit - 2.6X faster than 19 year old SSD:
Code:
MTPD::SendObject: len:19256968
 # USB Packets: 37611 total: 9 avg ms: 0 max: 6
 # Write: 9403 total:3542 avg ms: 0 max: 1
>>>Total Time: 3,569,320

Same file MTP transferred to SSD in 9.4 secs instead of 37.7 secs! And only 3.6 secs to HDD.
> and avg and max # Write much improved!

> Added 2 PSRAMS to that updated Locked Beta T_4.1 and it is programming and running without issue to run this test and the PSRAM integrity w/16MB

Also other unpinned updated Locked Beta T_4.0 soldered into FRDM 4236 Adapter and SD working!
> PCB also has the USB Host pins brought out for @blackketter's OSH board - need to find parts to assemble that add on.

NOTE: Trying to use 16MB PSRAM fails to .begin is seems? 15MB works, and 16MB works in Integrity/PSRAM ???

Seeing this odd string of 'Fail' on USB_MTP-logger startup:
Code:
*** Start Interval Timer ***
8050 CMD: 1002(OPEN_SESSION)l: 16 T:0 : 1
8050 RESP:2001(RSP:OK)l: 16 T:0 : 1
8100 CMD: 1001(GET_DEVICE_INFO)l: 12 T:1
8100 RESP:2001(RSP:OK)l: 12 T:1
8150 CMD: 1014(GET_DEVICE_PROP_DESC)l: 16 T:2 : d402
8150 RESP:2001(RSP:OK)l: 16 T:2 : d402
Ram Drive of size: 15728640 initialized
addFilesystem: 0 RAM 2000a598
Set Storage Index drive to 0
Initializing MSC Drives ...
Initializing USB MSC drives...
MSC and MTP initialized.

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
	r - reset MTP
	h - Menu

*** end Interval Timer ***
    Valid ExFat
    Fail
    Fail
    Fail
    Fail
    Fail
    Fail
    Fail
    Fail
    Fail
    Fail
    Fail
    Fail
    Valid ExFat
    Fail
    Fail
    Fail
    Fail
    Fail
    Fail
    Fail
    Fail
    Fail

USB Drive: 0 connected

msc # Partition Table
	part,boot,bgnCHS[3],type,endCHS[3],start,length
exFAT:	1,0,0x20,0x21,0x0,0x7,0xFE,0xFF,0xFF,2048,234436608
pt_#0:	2,0,0x0,0x0,0x0,0x0,0x0,0x0,0x0,0,0
pt_#0:	3,0,0x0,0x0,0x0,0x0,0x0,0x0,0x0,0,0
pt_#0:	4,0,0x0,0x0,0x0,0x0,0x0,0x0,0x0,0,0

Try Partition list
PART	Type	Start	Count	(MBR	Part)	Volume Type
1	M	2048	234436608	0	0	exFAT

USB Drive: 1 connected

msc # Partition Table
	part,boot,bgnCHS[3],type,endCHS[3],start,length
exFAT:	1,0,0x20,0x21,0x0,0x7,0xFE,0xFF,0xFF,2048,250064896
pt_#0:	2,0,0x0,0x0,0x0,0x0,0x0,0x0,0x0,0,0
pt_#0:	3,0,0x0,0x0,0x0,0x0,0x0,0x0,0x0,0,0
pt_#0:	4,0,0x0,0x0,0x0,0x0,0x0,0x0,0x0,0,0

Try Partition list
PART	Type	Start	Count	(MBR	Part)	Volume Type
1	M	2048	250064896	0	0	exFAT
Found new Volume:0
addFilesystem: 1 MSC0-Plex120 20008a70
Found new Volume:1
addFilesystem: 2 MSC1-120GB_Ext 20008f40
13495 CMD: 1004(GET_STORAGE_IDS)l: 12 T:3
13495 RESP:2001(RSP:OK)l: 12 T:3
13495 CMD: 1005(GET_STORAGE_INFO)l: 16 T:4 : 10001
65537 0 name:RAM
65537 0 name:RAM
13495 RESP:2001(RSP:OK)l: 16 T:4 : 10001
13495 CMD: 1005(GET_STORAGE_INFO)l: 16 T:5 : 20001
131073 1 name:MSC0-Plex120
131073 1 name:MSC0-Plex120
14033 RESP:2001(RSP:OK)l: 16 T:5 : 20001
14033 CMD: 1005(GET_STORAGE_INFO)l: 16 T:6 : 30001
196609 2 name:MSC1-120GB_Ext
196609 2 name:MSC1-120GB_Ext
14232 RESP:2001(RSP:OK)l: 16 T:6 : 30001
14233 CMD: 9801(GET_OBJECT_PROPS_SUPPORTED)l: 16 T:7 : 3000
14233 RESP:2001(RSP:OK)l: 16 T:7 : 3000
14234 CMD: 9801(GET_OBJECT_PROPS_SUPPORTED)l: 16 T:8 : 3001
14234 RESP:2001(RSP:OK)l: 16 T:8 : 3001
 
Made the change to FS.h as well.

on the 128gb 2 exFAT primary partition Jump drive:
With the change:
Code:
MTPD::SendObject: len:23672380
 # USB Packets: 46235 total: 1 avg ms: 0 max: 1
 # Write: 11559 total:[B]14716 [/B]avg ms: 1 max: 941
w/o the change I had
Code:
MTPD::SendObject: len:23672380
 # USB Packets: 46235 total: 0 avg ms: 0 max: 0
 # Write: 11559 total:[B]68924 [/B]avg ms: 5 max: 944
big change

EDIT: Hooked up a new Crucial 500GB SSD setup as a GPT single drive:
Code:
msc # Partition Table
	part,boot,bgnCHS[3],type,endCHS[3],start,length
*** GPT Disk WIP ***
GPT guard:	1,0,0x0,0x2,0x0,0xEE,0xFE,0x7F,0x80,1,4294967295
pt_#0:	2,0,0x0,0x0,0x0,0x0,0x0,0x0,0x0,0,0
pt_#0:	3,0,0x0,0x0,0x0,0x0,0x0,0x0,0x0,0,0
pt_#0:	4,0,0x0,0x0,0x0,0x0,0x0,0x0,0x0,0,0

GPT partition header revision: 10000
LBAs current:1 backup:976773167 first:34 last:976773134
Disk GUID:B6FFA720-3A6A-437F-AF29-67244A1895BDStart LBA Array: 2 Count: 128 size:128
Part	 Type Guid, Unique Guid, First, last, attr, name
0	E3C9E316-0B5C-4DB8-817D-F92DF00215AE, E32AD918-2475-4F37-8D5B-2CFF194C6FB2, 34, 32767, 0, Microsoft reserved partition
1	EBD0A0A2-B9E5-4433-87C0-68B6B72699C7, 3CADDE87-F876-438D-89DB-A6922E8CC0D3, 32768, 976771071, 0, Basic data partition
>>> Microsoft Basic Data Partition
    EXFAT:
3	00000000-0000-0000-0000-000000000000, 00000000-0000-0000-0000-000000000000, 0, 0, 0, 

Try Partition list
PART	Type	Start	Count	(MBR	Part)	Volume Type
1	O	34	32734	2	0	E3C9E316-0B5C-4DB8-817D-F92DF00215AE
2	G	32768	976738304	2	1	exFAT
and doing the same file transfer
Code:
MTPD::SendObject: len:23672380
 # USB Packets: 46235 total: 1 avg ms: 0 max: 1
 # Write: 11559 total:[B]4335 [/B]avg ms: 0 max: 1
 
Note: there are some debug messages I meant to comment out... "Fail"
It is looping through all of the possible partitions. On these drives, there appears to a Microsoft Reserved partition, which they all fail to grab... I keep thinking maybe should add a little more smarts, and if the device type is invalid or the like, maybe return a special value, and punt for all of the others... My concern was maybe there will other drivers that will understand a different partition type...

Also minor things, still loop for 4 partitions... But can now have more... Will probably extend some of this soon. But first try to understand a fix a few more things.

Edit: Pushed up changes to my SDFat GPT_Disks WIP branch to remove those two debug messages
 
I just pushed up some fixes in MTP_Teensy to the Copy an object from one store to another.

Simple cases work. Things fixed in: uint32_t MTPStorage::copy(uint32_t handle, uint32_t newStore, uint32_t newParent)

Before it would not work if the destination was the root directory of the new store... Why in this case MTP passes you the new parent = 0
Which implies to use the root of the new store... So did that.

After that the new file showed up in the folder view, but showed 0 length as we did not update the index record with the actual size...
Also did not preserve the dates... So sort of fixed size to simply copy size from source record... Fixed dates and times by calling our update dates function.

What I have not done is any validation stuff... Example: You say copy a 20mb file to a store that has only 5mb free... Should return not enough size...

Also did not play at all with the case where you try to copy a directory... There is code there... Have not tried running it. For sure it does not have any verification of sizes. It does not preserve dates...
 
Good Morning Paul and all...

We have run into issues with copy of large files over MTP, especially when saving the files to LittleFS Flash or the like. Right now looking at the T4.x stuff...

It sometimes ends in a crash, like I just had. More often either the host has given up on us due to how slow things are going or some packets are lost along the way and so the host thinks we have all of the data, and w are still expecting more...

I am trying to isolate down when we timeout waiting for messages on what type of error. SO am trying to send a file that is setup where each record(s) corresponds to USB packets of 512 bytes.
Note: the first packet of a object sent to us has 12 bytes of header data, so I shortened the first line output by 12 bytes.

I also decided to make the file into 128 byte lines with usb packet numbers at start of each line:

Built the file using quick and dirty sketch:
Code:
#include <SD.h>
#include <SPI.h>

File myFile;

const int chipSelect = BUILTIN_SDCARD;
#define BUFFER_SIZE 128
uint8_t write_buffer[BUFFER_SIZE];

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

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

  if (!SD.begin(chipSelect)) {
    Serial.println("initialization failed!");
    return;
  }
  Serial.println("initialization done.");

  // open the file.
  Serial.println("Write Large Index File");
  myFile = SD.open("LargeIndexedTestfile.txt", FILE_WRITE_BEGIN);
  if (myFile) {
    myFile.truncate(); // Make sure we wipe out whatever was written earlier
    for (uint32_t i = 0; i < 43000*4; i++) {
      memset(write_buffer, 'A'+ (i & 0xf), sizeof(write_buffer));
      myFile.printf("%06u ", i >> 2);  // 4 per physical buffer
      myFile.write(write_buffer, i? 120 : 120-12); // first buffer has other data...
      myFile.printf("\n");
    }
    myFile.close();
    Serial.println("\ndone.");
  }
}

void loop()
{
  // nothing happens after setup
}

My last MTP run trying to copy this file from PC to a littleFS drive.

It looked like maybe the whole file was sent to the littleFS:
But system crashed after it completed:

Code:
23602 RESP:2001(RSP:OK)l: 24 T:37 : 60001 ffffffff 17
23603 CMD: 100d(SEND_OBJECT)l: 12 T:38
MTPD::SendObject: len:22015988
 # USB Packets: 42999 total: 2 avg ms: 0 max: 1
 # Write: 10750 total:74788 avg ms: 6 max: 176
>>>Total Time: 74882385
98485 RES*** Start Interval Timer ***
2351 CMD: 1002(OPEN_SESSION)l: 16 T:0 : 1
2351 RESP:2001(RSP:OK)l: 16 T:0 : 1
2401 CMD: 1001(GET_DEVICE_INFO)l: 12 T:1
2401 RESP:2001(RSP:OK)l: 12 T:1
2451 CMD: 1014(GET_DEVICE_PROP_DESC)l: 16 T:2 : d402
2451 RESP:2001(RSP:OK)l: 16 T:2 : d402
2751 CMD: 1004(GET_STORAGE_IDS)l: 12 T:3
2751 RESP:2019(RSP:DEVICE_BUSY)l: 12 T:3
2901 CMD: 1004(GET_STORAGE_IDS)l: 12 T:4
2901 RESP:2019(RSP:DEVICE_BUSY)l: 12 T:4
CrashReport:
  A problem occurred at (system time) 9:49:32
  Code was executing from address 0x15F64
  CFSR: 82
	(DACCVIOL) Data Access Violation
	(MMARVALID) Accessed Address: 0x20007260 (Stack problem)
	  Check for stack overflows, array bounds, etc.
  Temperature inside the chip was nan °C
  Startup CPU clock speed is 600MHz
  Reboot was caused by auto reboot after fault or bad interrupt detected

C:\Users\kurte\Documents\Arduino\libraries\MTP_Teensy\examples\SD_SPI_QSPI_MTP-logger\SD_SPI_QSPI_MTP-logger.ino Nov  1 2021 09:44:20
5000 Initializing MTP Storage list ...Date: 1 Nov 2021 9:49:45

Again a few interesting tidbits here: # Write: 10750 total:74788 avg ms: 6 max: 176
Right now I am calling littleFs with a write with a buffer of 2KB.. And an average each write is taking 6ms, but the longest one was 176ms (almost .2 seconds!).
So while this write is being processed, we are not processing any data from the host. We currently are configured for 4 RX transfers in the usb_mpt.c code...

Question will be: again are we dropping packets. i.e. what happens if the host tries to keep sending data while we are processing a long write such as this, does the host wait for it, or is the data in some circumstances lost? ...

Trying to figure that out from looking at the partial files.

Now back to pulling out hair ;)

EDIT: Tried copy to Flash 5 (memory board IO pin 5)...
Did a quick format first...

Code:
MTPD::SendObject *** USB Read Timeout ***
 # USB Packets: 8700 total: 0 avg ms: 0 max: 0
 # Write: 2176 total:50332 avg ms: 23 max: 46
>>>Total Time: 50857615
*MTPD::send_Event(4001)
103083 RESP:2007(RSP:INCOMPLETE_TRANSFER)l: 12 T:e
It was moving real slow estimated time kept creeping up: last estimate was 3.5 minutes left...
The partial file last line it output showed: 008700 as the line number, so it does not look like it lost any intermediary lines
 
Last edited:
I have been using LittleFS v2.4.1 (latest) and am seeing the same thing on large file transfers to SPI flash - NAND SPI flash seem to fair better and I can transfer the files without issue. Only difference is that I have not seen may restarts except on exFAT with USB sticks. But that is another story.

Before getting in tests with LittleFS I decided to try a SSD 500Gb Crucial drive to see if we had the same problem:
1. Started with clean windows format as exFAT
Code:
msc # Partition Table
	part,boot,bgnCHS[3],type,endCHS[3],start,length
*** GPT Disk WIP ***
GPT guard:	1,0,0x0,0x2,0x0,0xEE,0xFE,0x7F,0x80,1,4294967295
pt_#0:	2,0,0x0,0x0,0x0,0x0,0x0,0x0,0x0,0,0
pt_#0:	3,0,0x0,0x0,0x0,0x0,0x0,0x0,0x0,0,0
pt_#0:	4,0,0x0,0x0,0x0,0x0,0x0,0x0,0x0,0,0

GPT partition header revision: 10000
LBAs current:1 backup:976773167 first:34 last:976773134
Disk GUID:B6FFA720-3A6A-437F-AF29-67244A1895BDStart LBA Array: 2 Count: 128 size:128
Part	 Type Guid, Unique Guid, First, last, attr, name
0	E3C9E316-0B5C-4DB8-817D-F92DF00215AE, E32AD918-2475-4F37-8D5B-2CFF194C6FB2, 34, 32767, 0, Microsoft reserved partition
1	EBD0A0A2-B9E5-4433-87C0-68B6B72699C7, 3CADDE87-F876-438D-89DB-A6922E8CC0D3, 32768, 976771071, 0, Basic data partition
>>> Microsoft Basic Data Partition
    EXFAT:
3	00000000-0000-0000-0000-000000000000, 00000000-0000-0000-0000-000000000000, 0, 0, 0, 

Try Partition list
PART	Type	Start	Count	(MBR	Part)	Volume Type
1	O	34	32734	2	0	E3C9E316-0B5C-4DB8-817D-F92DF00215AE
2	G	32768	976738304	2	1	exFAT
Found new Volume:0
addFilesystem: 1 MSC0-New Volume 20008a70

2. On copy of the Index file to the SSD I get the INCOMPLETE TRANSFER MESSAGE:
Code:
MTPD::SendObject *** USB Read Timeout ***
 # USB Packets: 42997 total: 38 avg ms: 0 max: 1
 # Write: 10750 total:4851 avg ms: 0 max: 1
>>>Total Time: 5852679
*MTPD::send_Event(4001)
74391 RESP:2007(RSP:INCOMPLETE_TRANSFER)l: 12 T:30
74430 CMD: 1005(GET_STORAGE_INFO)l: 16 T:31 : 20001
131073 1 name:MSC0-New Volume
131073 1 name:MSC0-New Volume
75129 RESP:2001(RSP:OK)l: 16 T:31 : 20001

3. On the incomplete transfer I have to reset in the terminal and a refresh to see the file that was created by the copy to PC.

4. Copying the file back to the PC and using CODECOMPARE it shows that it lost 1 packet (9289) during transfer which in this case is 4 lines or 4x128 = 512 bytes. Packet 42999 duplicated itself so 2 lines of 42999

5. After the file transfer to the PC and doing the Restart and refresh MTP (explorer) freezes but the sketch is still operational

For instances running datalogger works from the USB_MTP_Logger sketch which was used for this test:
Code:
Stopped Logging Data!!!
Records written = 44
*MTPD::send_Event(400b)

 Space Used = 23199744
Filesystem Size = 500073234432
System Volume Information            C: 10/31/2021 16:58 M: 10/31/2021 16:58  /
  IndexerVolumeGuid                  C: 10/31/2021 16:58 M: 10/31/2021 16:58  76
LargeIndexedTestfile.txt             C: 11/01/2021 14:47 M: 11/01/2021 14:50  22014964
datalog.txt                         [COLOR="#FF0000"] C: 01/01/2021[/COLOR] 00:00 M: 11/01/2021 14:58  403

but note that the create date is wrong.
 
EDIT: Tried copy to Flash 5 (memory board IO pin 5)...
Did a quick format first...

Code:
MTPD::SendObject *** USB Read Timeout ***
 # USB Packets: 8700 total: 0 avg ms: 0 max: 0
 # Write: 2176 total:50332 avg ms: 23 max: 46
>>>Total Time: 50857615
*MTPD::send_Event(4001)
103083 RESP:2007(RSP:INCOMPLETE_TRANSFER)l: 12 T:e
It was moving real slow estimated time kept creeping up: last estimate was 3.5 minutes left...
The partial file last line it output showed: 008700 as the line number, so it does not look like it lost any intermediary lines

Did the same thing but did a lowLevelFormat of Flash5 first:
Code:
MTPD::SendObject *** USB Read Timeout ***
 # USB Packets: 42997 total: 432 avg ms: 0 max: 1
 # Write: 10750 total:72686 avg ms: 6 max: 166
>>>Total Time: 74373218
*MTPD::send_Event(4001)
749448 RESP:2007(RSP:INCOMPLETE_TRANSFER)l: 12 T:e
749484 CMD: 1005(GET_STORAGE_INFO)l: 16 T:f : 30001
Had to do the reset and refresh to see the file again.

Code Compared showed
Code:
Missing lines at 17 and 741
Duplicate 42999 line in file from T4

And as for SSD MTP froze after the transfer! but sketch still running. Had to recycle power to get MTP back.

EDIT: Doing a quickFormat from MTP same thing happens as doing a lowlevel format

EDIT2: Same thing happens for the N02 NAND but not for the N01 but only 1 packet lost and that 42999 line duplication.
 
@mjs513 - seeing github.com/mjs513/LittleFS/tree/newVersionLittleFS
Is that a test worthy update? Would be good stay current - especially if it brings improvements for general usage.

RE: PreFormatting: without destroying existing disk : this should allow the disk to be used without "reset and refresh"
> what happens with :: res = myfs.formatUnused( 1, res );
where this starts at zero to start at begin of media:: uint32_t res = 0; // for formatUnused
-> 2nd param tracks what block to start on looking for next unused and unformatted block to format
The first param can be any number : 0 says do all media blocks, a lesser number will only do 'first param' number before return { though it suffers overhead of walking used disk blocks again }
-> there was code to store the block bitmap so it didn't need to be read each time, but it would have to be kept up to date with each 'lfs' request to 'format a block' showing it was put into use.
-> this lfs return can take a long time to walk the media. lfs does cahce these bits - but cache may not be allocated to cover all of media and we don't have direct access to it.
> myfs.formatUnused() returns zero when the end of media last block is passed
 
@defragster

Sorry for taking so long to answer this - got distracted yesterday on other projects. Anyway, yes,
@mjs513 - seeing github.com/mjs513/LittleFS/tree/newVersionLittleFS
Is that a test worthy update? Would be good stay current - especially if it brings improvements for general usage.
that is the latest version of littleFS that I modified for use with Teensy. However, no guarantee that it will be incorporated into Teensyduino. So far haven't seen any performance improvements the advantage it does have is that it does have a provision to make it thread safe.

As to your other suggestions its a possibility to do but I don't think the issue is necessarily with LittleFS. For instance if you run the LittleFS Integrity sketch on the flash5 (memory board cs pin 5) to create a Big File and a small File after a format and do your 'D' command to verify sizes:
Code:
NOTE: WRITE VERIFY IS ON.


Big write /0_bigfile.txt took 307.81 Sec for 33507328 Bytes : file3.size()=33507328
	Big write KBytes per second 108.86 

Bytes Used: 33624064, Bytes Total:67108864

====================================================
Big write /0_2MBfile.txt took  6.68 Sec for 2048000 Bytes : file3.size()=2048000
	Big write KBytes per second 306.46 
	
=====================================================
Doing a "D"
Walk all Files verify Read Size:	
00	D1 
	D2 
	D3 
	D4 
	D5 
	0 Errors found

Bytes Used: 34648064, Bytes Total:67108864
So writing a 33Mb and a 2Mb file has no issues and no errors. Might be some strange interaction between MTP/FS or something else completely
 
Back
Top