Teensyduino File System Integration, including MTP and MSC

In addition to what @KurtE is seeing with missing packets I am experiencing timeouts of receipt of data which when using the 512MB flash chip from USB. In this case I get that 1 block out transfer:
Capture.PNG

Going through the data I am seeing some interesting things with pipe stalls and resets as well as pipe aborts:
Capture0.PNG

You can look either at the no column or time column to see its relationship to the block-out transfer.
 
Bulk versus Interrupt USB Endpoints

Paul and maybe others,

I know that some of this may be really Fundamental USB stuff, but I am not sure of the functionality
differences of end points that are type 2(BULK) versus type 3(interrupt) or more specifically how that translates to what goes on within usb.c and how the different usb drivers should call it.

For now lets assume T4 where Max Packet size is 512 bytes. Now suppose I wish to transfer a large file in my case like 22mb...

Now looking at lets say using libusb and going along the line of the Ubuntu run I did, I might use some 16K(16416) byte buffers,
and maybe call something like: libusb_fill_bulk_transfer(...) with this buffer that I read in 16kb at a time, and then call off the libusb_transfer... Could do it sync or async... If I was doing this on pc, the receive side would be done the same way, and it would check to see how much was received...

But the question is, how does or should this translate to T4x?

For example to receive this file, we currently the code is setup, that we have 4 RX transfers max and each one has a 512 (MAX_PACKET size) buffer associated with it. So when we receive this I am assuming we cycle through the endpoints to receive 32 (or 33 if ZLP?) packets of data. Need to figure out where that is happening.
Or should we try to allocate and user larger buffers with each transfer? I think I read that we can do up to 20k? Although I think I read something like more likely 16k.
Should we do that? Are there examples that do this?

Dito for when we try to send the file down to the host. We currently actually read in maybe 2KB at a time but we then call USB to transfer 512 bytes at a time.
Should we setup to do larger transfers? Again probably need to see if usb_prepare_transfer works if we pass in something like 2K or 16 as a transfer length?
And again are there examples that do this?

Again sorry if I did not ask this very clearly.

Kurt

EDIT1: - Tried recording session of downloading a file from Teensy to PC (GetObject)...
The code is setup looping, doing calls to usb_transmit with 512 byte records...

But when I look through WireShark Capture I see a similar pattern of large/small transfers:
screenshot.jpg
 
Last edited:
Just glancing in passing ... all searches show 512B max packet for - at least in articles like this : beyondlogic.org/usbnutshell/usb4.shtml

I do see 1024B in some notes - but not just now to see the context ...

Above link has summary notes on 'Endpoint Types' - probably no news there?

needless to say, I am not an expert on all of this, (i.e. the questions)

You are right about the max per packet payload is 512 at high speed. But as I browse through the USB spec... Things like how many transfers it can do per second and the like, plus it looked like it did multiple transfers one direction before the other side would send some form of ack...

But I believe somehow BULK logically groups the transfers together...

Opps - meant to ask dumb question ...

Does the transfer work Teensy > PC, but not PC > Teensy?
It works a lot better than the other way around. Not 100% sure for the USB part but also add into that that when we upload we have the real slow downs when we save data away especially to some forms of LittlFS. Where reading is not that bad.
 
Out of curiosity wanted to see what the teensy > PC transfer looked like and seems to be the exact opposite of the PC > Teensy transfer:
Capture.PNG


EDIT: Sorry @KurtE missed your edit on the post - so this is a duplicate
 
Out of curiosity wanted to see what the teensy > PC transfer looked like and seems to be the exact opposite of the PC > Teensy transfer:
View attachment 26693


EDIT: Sorry @KurtE missed your edit on the post - so this is a duplicate
:D Glad we saw the same thing.

Again I feel like I am throwing darts into a pitch black room, hoping to hit a small target :D

But I have pushed up some experiments in progress for cores and mtp_teensy in new branches throwing_darts
Branches are likely to be pruned, but trying got bet better understandings

Two things I have tried in send object:

a) interval timer to try reading in some stuff while a write to storage is in progress. Currently disabled the interval timer with 2nd test...

b) Wondering if larger rx transfers would help... So setup transfers for 2048... max packet is still 512...

Just started experimenting with b) but at least fixed enough stuff to allow me to send the 22mb file to teensy and send it back and at least this time they compared... But only tried once so far so does not imply yet it is helping not lose data... But maybe.
With the runs I turned on debug output to Serial4 and was looking at what I received:
Here is showing some of that output from Serial4:
Code:
rx event i=2 status:07EC8000 len:20
rx event i=3 status:07EC8000 len:20
rx event i=0 status:07EC8000 len:20
rx event i=1 status:073E8000 len:194
rx event i=2 status:07F48000 len:12
rx event i=3 status:00009000 len:2048
rx event i=0 status:00008000 len:2048
rx event i=1 status:00009000 len:2048
rx event i=2 status:00008000 len:2048
rx event i=3 status:00009000 len:2048
rx event i=0 status:00008000 len:2048
rx event i=1 status:00009000 len:2048

The upper part of status field is used to compute the length: (transfer size) - the upper count... So 0 up there implies full count in this case 2048

But another interesting thing is that at full size, the status alternates values: 0x8000 and 0x9000
I get the impression, that the 8000 (bit 15) bit is the transfer is active and maybe bit 12?
Page number? cErr? .. Still loooking up.

Now back to playing
 
Got 64GB ADATA brand SDHC cards showing 'A2' app rating and V30 speed. Uding the MSC-TEST.ino it is giving "B" big write of
Code:
Start Big write of 129982464 Bytes............................................................
Big write /0_bigfile.txt took  6.38 Sec for [B]129982464 [/B]Bytes : file3.size()=[B]129980416[/B]
	Big write KBytes per second 20379.82
Have a Samsung EVO select with no "A#" and it gets the same ... thought that ADATA was FAST for a low price ... :(
A 128GB Samsung EVO with "A2" gives this?
Code:
Start Big write of 129982464 Bytes...........
Big write /0_bigfile.txt took  1.25 Sec for [B]129982464 [/B]Bytes : file3.size()=[U]25296896[/U]
	Big write KBytes per second [B][U]103902.85 [/U][/B]

Though reading that SPEW shows there is a discrepancy in the reported bytes written to look at ...


This T_4.1 has a PSRAM - but using this triggers build errors? Not sure why - things just go missing ??? Is there something odd in LFS_RAM?
#define USE_LFS_RAM 1 // 0 // T4.1 PSRAM (or RAM)
Code:
"R:\\temp\\arduino_build_mtp-test.ino\\sketch\\mtp-test.ino.cpp.o"
C:\T_Drive\tCode\FS_integrate\mtp-test\mtp-test.ino: In function 'void setup()':
C:\T_Drive\tCode\FS_integrate\mtp-test\mtp-test.ino:375:19: error: 'checkMSCChanges' was not declared in this scope
   checkMSCChanges();
                   ^
C:\T_Drive\tCode\FS_integrate\mtp-test\mtp-test.ino:383:8: error: 'menu' was not declared in this scope
   menu();
        ^
C:\T_Drive\tCode\FS_integrate\mtp-test\mtp-test.ino: In function 'void loop()':
C:\T_Drive\tCode\FS_integrate\mtp-test\mtp-test.ino:397:70: error: 'CommandLineReadNextNumber' was not declared in this scope
     if ('2'==command) storage_index = CommandLineReadNextNumber(ch, 0);
                                                                      ^
C:\T_Drive\tCode\FS_integrate\mtp-test\mtp-test.ino:428:25: error: 'listFiles' was not declared in this scope
     case 'l': listFiles(); break;
                         ^
C:\T_Drive\tCode\FS_integrate\mtp-test\mtp-test.ino:429:26: error: 'eraseFiles' was not declared in this scope
     case 'e': eraseFiles(); break;
                          ^
C:\T_Drive\tCode\FS_integrate\mtp-test\mtp-test.ino:436:15: error: 'logData' was not declared in this scope
       logData();
               ^
C:\T_Drive\tCode\FS_integrate\mtp-test\mtp-test.ino:438:27: error: 'stopLogging' was not declared in this scope
     case 'x': stopLogging(); break;
                           ^
C:\T_Drive\tCode\FS_integrate\mtp-test\mtp-test.ino:443:23: error: 'dumpLog' was not declared in this scope
     case 'd': dumpLog(); break;
                       ^
C:\T_Drive\tCode\FS_integrate\mtp-test\mtp-test.ino:445:18: error: 'bigFile' was not declared in this scope
       bigFile( 0 ); // delete
                  ^
C:\T_Drive\tCode\FS_integrate\mtp-test\mtp-test.ino:453:21: error: 'bigFile2MB' was not declared in this scope
       bigFile2MB( 0 ); // CREATE
                     ^
C:\T_Drive\tCode\FS_integrate\mtp-test\mtp-test.ino:466:19: error: 'writeFiles' was not declared in this scope
       writeFiles(1);
                   ^
C:\T_Drive\tCode\FS_integrate\mtp-test\mtp-test.ino:469:23: error: 'writeIndexFile' was not declared in this scope
       writeIndexFile(1);
                       ^
C:\T_Drive\tCode\FS_integrate\mtp-test\mtp-test.ino:482:20: error: 'menu' was not declared in this scope
     case 'h': menu(); break;
                    ^
C:\T_Drive\tCode\FS_integrate\mtp-test\mtp-test.ino:487:21: error: 'checkMSCChanges' was not declared in this scope
     checkMSCChanges();
                     ^
C:\T_Drive\tCode\FS_integrate\mtp-test\mtp-test.ino:492:27: error: 'logData' was not declared in this scope
   if (write_data) logData();
                           ^
C:\T_Drive\tCode\FS_integrate\mtp-test\mtp-test.ino: In function 'void listFiles()':
C:\T_Drive\tCode\FS_integrate\mtp-test\mtp-test.ino:630:22: error: 'printDirectory' was not declared in this scope
   printDirectory(myfs);
                      ^
C:\T_Drive\tCode\FS_integrate\mtp-test\mtp-test.ino: In function 'void printDirectory(FS*)':
C:\T_Drive\tCode\FS_integrate\mtp-test\mtp-test.ino:644:35: error: cannot convert 'File' to 'FS*' for argument '1' to 'void printDirectory(FS*)'
   printDirectory(pfs->open("/"), 0);
                                   ^
C:\T_Drive\tCode\FS_integrate\mtp-test\mtp-test.ino: In function 'void printDirectory(File, int)':
C:\T_Drive\tCode\FS_integrate\mtp-test\mtp-test.ino:655:26: error: 'printSpaces' was not declared in this scope
     printSpaces(numSpaces);
                          ^
 
Hi @defragster - I must admit, I have not been using the mtp-test program for awhile now. Most of the time right now I alternate between:

USB_MTP-logger - When I am testing more of the MSC stuff.

SD_Program_SPI_QSPI_MTP-logger.ino - for testing on most everything else other than MSC... The fun of this one is it has my wrappers for littleFS SPI and QSPI...
So for exampel I can define:
Code:
// Experiment with LittleFS_SPI wrapper
lfs_spi lfsspi[] = {{3}, {4}, {5}, {6}};
And these pins will work with any of the three different types of LittleFS chips that we communicate with using SPI....
They are pretty lame but do make things a bit easier to test different configurations:
Code:
class lfs_spi {
public:
  lfs_spi(uint8_t pin) : csPin(pin) {}
  bool begin();
  inline LittleFS * fs() { return plfs;}
  inline const char * displayName() {return display_name;}
  // You have full access to internals.
  uint8_t csPin;
  LittleFS_SPIFlash flash;
  LittleFS_SPIFram fram;
  LittleFS_SPINAND nand;
  LittleFS *plfs = nullptr;
  char display_name[10];
};
bool lfs_spi::begin() {
  //Serial.printf("Try SPI Pin %u", csPin);
  if (flash.begin(csPin)) {
    //Serial.println(" *** Flash ***");
    sprintf(display_name, (const char *)F("Flash_%u"), csPin);
    plfs = &flash;
    return true;
  } else if (fram.begin(csPin)) {
    //Serial.println(" *** Fram ***");
    sprintf(display_name, (const char *)F("Fram_%u"), csPin);
    plfs = &fram;
    return true;
  } else if (nand.begin(csPin)) {
    //Serial.println(" *** Nand ***");
    sprintf(display_name, (const char *)F("NAND_%u"), csPin);
    plfs = &nand;
    return true;
  }
  //Serial.println(" ### Failed ###");
  return false;
}
I will try building the mtp-test and hopefully push up fixes.
 
Morning @defragster

Been using the MTP_Test_integrity sketch pretty much for all my testing but I am not seeing any compile errors using PSRAM:
Code:
Memory Usage on Teensy 4.1:
  FLASH: code:161420, data:24016, headers:9120   free for files:7931908
   RAM1: variables:55744, code:153144, padding:10696   free for local variables:304704
   RAM2: variables:5216  free for malloc/new:519072
Invalid library found in D:\Users\Merli\Documents\Arduino\libraries\MemoryHexDump-main: Missing 'author' from library
with storages shown as:
Code:
Dump Storage list(10)
store:0 storage:10001 name:sdio fs:2000cba0
store:1 storage:20001 name:sd1 fs:2000d070
store:2 storage:30001 name:RAM0 fs:2000c998
store:3 storage:40001 name:RAM1 fs:2000ca64
store:4 storage:50001 name:PROGM fs:2000c7f4
store:5 storage:60001 name:QSPI fs:2000c8c0
store:6 storage:70001 name:sflash5 fs:2000d540
store:7 storage:80001 name:sflash6 fs:2000d61c
store:8 storage:90001 name:WINBOND1G fs:2000c3a8
store:9 storage:a0001 name:MSC0-exFAT-128 fs:2000a350

Just in case I will push up what I have been using for mtp_test_integrity that uses the bigwrites to Kurt's repository - should have done it a while ago anyway.

EDIT: @KurtE - @defragster
Just pushed the sketch to Kurt's mtp_teensy repository. If that is still giving you issues make sure you have all the latest changes to USBhost_t36 and MTP_Teensy
 
I will try building the mtp-test and hopefully push up fixes.

MTP_Test builds again if you turn on that option:

The compiler did not like the sizes that were being used for the sizes of numbers:
Code:
-const int lfs_ram_size[] = {200'000,4'000'000}; // edit to reflect your configuration

Removed the 's in the numbers and it builds now.

I also changed where <SD.h> was included.. Only if the USE_SD==1
 
MTP_Test builds again if you turn on that option:

The compiler did not like the sizes that were being used for the sizes of numbers:
Code:
-const int lfs_ram_size[] = {200'000,4'000'000}; // edit to reflect your configuration

Removed the 's in the numbers and it builds now.

I also changed where <SD.h> was included.. Only if the USE_SD==1

Just back for a minute after quick late night test and post ... and need to get moving again ...

Wasn't sure how those numbers could break the build so didn't edit out the cute separators - @luni uses them and they have worked before ???

Indeed it builds with : const int lfs_ram_size[] = {200000,4000000}; // edit to reflect your configuration

Thanks

Code:
Dump Storage list(6)
STORE:0 storage:10001 name:RAM1 fs:2000c9b8
store:1 storage:20001 name:RAM2 fs:2000ca84
store:2 storage:30001 name:PROGM fs:2000c814
store:3 storage:40001 name:QSPI fs:2000c8e0
store:4 storage:50001 name:sflash3 fs:2000d54c
store:5 storage:60001 name:sflash6 fs:2000d704

My version of mtp-test still WIP and unique ... One edit is "B" works on LFS_PROG as it reduces the size as needed

> after posting - gave a look over the uint64_t's used for size - not sure where those conflicting numbers come from.
 
Not sure which thread would be best for this: But we were playing with the MTP with MP3 stuff, found everything was working but went to try doing it on MicroMod and am having it fail on WAV file on SDIO on MicroMod, but appears to work fine with T4.1... Here is a more simplified version of the program, without any of the none PJRC stuff also no MTP, no MSC...

Code:
#include <Audio.h>

// GUItool: begin automatically generated code
AudioPlaySdWav           playWav; //xy=154,422
AudioOutputI2S           i2s1;           //xy=334,89
AudioConnection          patchCord3(playWav, 0, i2s1, 0);
AudioConnection          patchCord4(playWav, 1, i2s1, 1);
AudioControlSGTL5000     sgtl5000_1;     //xy=240,153
// GUItool: end automatically generated code
float volume = 0.7f;
char filename[256] = "2001/stop.wav";

#define Serial Serial
FS *myfs;
File dataFile, myFile;  // Specifes that dataFile is of File type
//=============================================================================
// SD classes
//=============================================================================
#include <SD.h>
#define USE_BUILTIN_SDCARD
#if defined(USE_BUILTIN_SDCARD) && defined(BUILTIN_SDCARD)
#define CS_SD  BUILTIN_SDCARD
#else
#define CS_SD 10
#endif
// SDClasses
// edit SPI to reflect your configuration (following is for T4.1)
#define SD_MOSI 11
#define SD_MISO 12
#define SD_SCK  13

#define SPI_SPEED SD_SCK_MHZ(16)  // adjust to sd card 
SDClass sd;

void storage_configure()
{
  DateTimeFields date;
  breakTime(Teensy3Clock.get(), date);
  const char *monthname[12] = {
    "Jan", "Feb", "Mar", "Apr", "May", "Jun", "Jul", "Aug", "Sep", "Oct", "Nov", "Dec"
  };
  Serial.printf("Date: %u %s %u %u:%u:%u\n",
                date.mday, monthname[date.mon], date.year + 1900, date.hour, date.min, date.sec);


#if defined SD_SCK
  SPI.setMOSI(SD_MOSI);
  SPI.setMISO(SD_MISO);
  SPI.setSCK(SD_SCK);
#endif
  if (!sd.begin(CS_SD))
  {
    Serial.printf("SD Failed to start");  Serial.println();
    pinMode(LED_BUILTIN, OUTPUT);
    for (;;) {
      digitalWriteFast(LED_BUILTIN, HIGH);
      delay(100);
      digitalWriteFast(LED_BUILTIN, LOW);
      delay(100);
      digitalWriteFast(LED_BUILTIN, HIGH);
      delay(100);
      digitalWriteFast(LED_BUILTIN, LOW);
      delay(500);
    }
  }
}

void setup()
{

  // Open serial communications and wait for port to open
  while (!Serial && millis() < 5000) ;

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

  //Setup Audio
  // Audio connections require memory to work.  For more
  // detailed information, see the MemoryAndCpuUsage example
  AudioMemory(40);

  sgtl5000_1.enable();
  sgtl5000_1.volume(volume);

  storage_configure();

  Serial.println("\nSetup done");
}

void loop()
{
  listFiles();
  while (Serial.read() != -1) ;
  Serial.println("Press any key to play a wave file\n");
  int ch;
  while ((ch = Serial.read()) == -1) ;
  if (ch >= ' ') {
    char *psz = filename;
    while (ch >= ' ') {
      *psz++ = ch;
      ch = Serial.read();
    }
    *psz = '\0';
  }
  while (Serial.read() != -1) ;

  Serial.printf("Playing %s\n", filename);
  int errAudio = playWav.play(&sd, filename);
  if (errAudio != 0) {
    Serial.printf("Audio Error: %d\n", errAudio);
  }
  delay(5);
  while (playWav.isPlaying()) {
    if (Serial.available()) {
      Serial.println("User Abort");
      break;
    }
    delay(250);
  }
  playWav.stop();
  Serial.println("Done.");
}

void listFiles()
{
  /*
  Serial.print("\n Space Used = ");
  Serial.println(sd.usedSize());
  Serial.print("Filesystem Size = ");
  Serial.println(sd.totalSize());
  */
  printDirectory(&sd);
}


void printDirectory(FS * pfs) {
  Serial.println("Directory\n---------");
  printDirectory(pfs->open("/"), 0);
  Serial.println();
}

void printDirectory(File dir, int numSpaces) {
  while (true) {
    File entry = dir.openNextFile();
    if (! entry) {
      //Serial.println("** no more files **");
      break;
    }
    printSpaces(numSpaces);
    Serial.print(entry.name());
    if (entry.isDirectory()) {
      Serial.println("/");
      printDirectory(entry, numSpaces + 2);
    } else {
      // files have sizes, directories do not
      printSpaces(36 - numSpaces - strlen(entry.name()));
      Serial.print("  ");
      Serial.println(entry.size(), DEC);
    }
    entry.close();
  }

If I run it on TMod I see:
[CODE]
C:\Users\kurte\Documents\Arduino\Teensy Tests\audio_sd_wave_test\audio_sd_wave_test.ino Dec  4 2021 12:33:36
Date: 4 Dec 2021 12:34:15
<<<SdioCard::readSector(0, 20003c6c)  NOT DMA
<<<SdioCard::readSector(8192, 20003c6c)  NOT DMA
<<<SdioCard::readSector(0, 20003a84)  NOT DMA
<<<SdioCard::readSector(8192, 20003a84)  NOT DMA

Setup done
Directory
---------
<<<SdioCard::readSector(24576, 20003a84)  NOT DMA
System Volume Information/
<<<SdioCard::readSector(24640, 20003a84)  NOT DMA
  WPSettings.dat                      12
  IndexerVolumeGuid                   76
<<<SdioCard::readSector(24576, 20003a84)  NOT DMA
odd1.mp3                              46888
odd1.wav                              553004
zarathustra.mp3                       489461
2001/
<<<SdioCard::readSector(27008, 20003a84)  NOT DMA
  calculations.wav                    426300
  completed.wav                       276460
  dangerous_to_remain.wav             372892
  enough_info.wav                     513388
  functional.wav                      237356
<<<SdioCard::readSector(27009, 20003a84)  NOT DMA
  one_moment.wav                      202236
  operational.wav                     772140
  sorry_dave.wav                      791164
  stop.wav                            200844
<<<SdioCard::readSector(24576, 20003a84)  NOT DMA
Audacity/
<<<SdioCard::readSector(34880, 20003a84)  NOT DMA
  Away_in_a_Manger.mp3                2014737
  Dont_Rain_on_My_Parade.mp3          3944449
  Take_My_Breathe_Away.mp3            5740819
  Welcome_Christmas.mp3               2985790
<<<SdioCard::readSector(24576, 20003a84)  NOT DMA
FLAC/
<<<SdioCard::readSector(63808, 20003a84)  NOT DMA
  T1_1024.FLA                         9802802
  T1_128.FLA                          11126659
  T1_256.FLA                          10415954
  T1_512.FLA                          10007370
<<<SdioCard::readSector(24576, 20003a84)  NOT DMA
Candyman.aac                          3177823
<<<SdioCard::readSector(24577, 20003a84)  NOT DMA
<<<SdioCard::readSector(24576, 20003a84)  NOT DMA
Dont Rain on My Parade.mp3            3944449
<<<SdioCard::readSector(24577, 20003a84)  NOT DMA
mtpindex.dat                          0

Press any key to play a wave file

Playing 2001/stop.wav
<<<SdioCard::readSector(24576, 20003a84)  NOT DMA
<<<SdioCard::readSector(27008, 20003a84)  NOT DMA
<<<SdioCard::readSector(27009, 20003a84)  NOT DMA
Audio Error: 1
<<<SdioCard::readSector(34432, 200037f2)  NOT DMA
<<<SdioCard::readSector(34433, 200037f2)  NOT DMA
<<<SdioCard::readSector(34434, 200037f2)  NOT DMA
<<<SdioCard::readSector(34435, 200037f2)  NOT DMA
<<<SdioCard::readSector(34436, 200037f2)  NOT DMA
<<<SdioCard::readSector(34437, 200037f2)  NOT DMA
<<<SdioCard::readSector(34438, 200037f2)  NOT DMA
CrashReport:
  A problem occurred at (system time) 12:34:23
  Code was executing from address 0x28EA
  CFSR: 82
	(DACCVIOL) Data Access Violation
	(MMARVALID) Accessed Address: 0x20003FE1 (Stack problem)
	  Check for stack overflows, array bounds, etc.
  Temperature inside the chip was 57.20 °C
  Startup CPU clock speed is 600MHz
  Reboot was caused by auto reboot after fault or bad interrupt detected

C:\Users\kurte\Documents\Arduino\Teensy Tests\audio_sd_wave_test\audio_sd_wave_test.ino Dec  4 2021 12:33:36
Date: 4 Dec 2021 12:34:35
<<<SdioCard::readSector(0, 20003c6c)  NOT DMA
<<<SdioCard::readSector(8192, 20003c6c)  NOT DMA
<<<SdioCard::readSector(0, 20003a84)  NOT DMA
<<<SdioCard::readSector(8192, 20003a84)  NOT DMA

Setup done
Directory
---------
<<<SdioCard::readSector(24576, 20003a84)  NOT DMA
System Volume Information/
<<<SdioCard::readSector(24640, 20003a84)  NOT DMA
  WPSettings.dat                      12
  IndexerVolumeGuid                   76
<<<SdioCard::readSector(24576, 20003a84)  NOT DMA
odd1.mp3                              46888
odd1.wav                              553004
zarathustra.mp3                       489461
2001/
<<<SdioCard::readSector(27008, 20003a84)  NOT DMA
  calculations.wav                    426300
  completed.wav                       276460
  dangerous_to_remain.wav             372892
  enough_info.wav                     513388
  functional.wav                      237356
<<<SdioCard::readSector(27009, 20003a84)  NOT DMA
  one_moment.wav                      202236
  operational.wav                     772140
  sorry_dave.wav                      791164
  stop.wav                            200844
<<<SdioCard::readSector(24576, 20003a84)  NOT DMA
Audacity/
<<<SdioCard::readSector(34880, 20003a84)  NOT DMA
  Away_in_a_Manger.mp3                2014737
  Dont_Rain_on_My_Parade.mp3          3944449
  Take_My_Breathe_Away.mp3            5740819
  Welcome_Christmas.mp3               2985790
<<<SdioCard::readSector(24576, 20003a84)  NOT DMA
FLAC/
<<<SdioCard::readSector(63808, 20003a84)  NOT DMA
  T1_1024.FLA                         9802802
  T1_128.FLA                          11126659
  T1_256.FLA                          10415954
  T1_512.FLA                          10007370
<<<SdioCard::readSector(24576, 20003a84)  NOT DMA
Candyman.aac                          3177823
<<<SdioCard::readSector(24577, 20003a84)  NOT DMA

Press any key to play a wave file
}

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


Code:
C:\Users\kurte\AppData\Local\Temp\arduino_build_225483>addr2line -e audio_sd_wave_test.ino.elf 0x28EA
C:\Users\kurte\Documents\Arduino\libraries\Audio/play_sd_wav.cpp:477

This appears to be in the function:
// Consume already buffered data. Returns true if audio transmitted.
Code:
bool AudioPlaySdWav::consume(uint32_t size)
{
...
			block_left->data[block_offset] = (msb << 8) | lsb;
			right16:
			lsb = *p++;
			msb = *p++; <<<<<<====== Line 477
			size -= 2;
			block_right->data[block_offset++] = (msb << 8) | lsb;
....


Note: I have hacked up SD LIbrary some with SdioTeensy.cpp to add some debug outputs:
Code:
bool SdioCard::readSector(uint32_t sector, uint8_t* dst) {
  Serial.printf("<<<SdioCard::readSector(%u, %x) ", (uint32_t)sector, dst);
And it prints out DMA in the DMA section and NOT DMA in the else case...

If I run this on T4.1 I see:
But it runs fine on T4.1 with same SD card same program...
Code:
C:\Users\kurte\Documents\Arduino\Teensy Tests\audio_sd_wave_test\audio_sd_wave_test.ino Dec  4 2021 12:39:36
Date: 4 Dec 2021 12:41:30
<<<SdioCard::readSector(0, 20003c70)  NOT DMA
<<<SdioCard::readSector(8192, 20003c70)  NOT DMA
<<<SdioCard::readSector(0, 20003a88)  NOT DMA
<<<SdioCard::readSector(8192, 20003a88)  NOT DMA

Setup done
Directory
---------
<<<SdioCard::readSector(24576, 20003a88)  NOT DMA
System Volume Information/
<<<SdioCard::readSector(24640, 20003a88)  NOT DMA
  WPSettings.dat                      12
  IndexerVolumeGuid                   76
<<<SdioCard::readSector(24576, 20003a88)  NOT DMA
odd1.mp3                              46888
odd1.wav                              553004
zarathustra.mp3                       489461
2001/
<<<SdioCard::readSector(27008, 20003a88)  NOT DMA
  calculations.wav                    426300
  completed.wav                       276460
  dangerous_to_remain.wav             372892
  enough_info.wav                     513388
  functional.wav                      237356
<<<SdioCard::readSector(27009, 20003a88)  NOT DMA
  one_moment.wav                      202236
  operational.wav                     772140
  sorry_dave.wav                      791164
  stop.wav                            200844
<<<SdioCard::readSector(24576, 20003a88)  NOT DMA
Audacity/
<<<SdioCard::readSector(34880, 20003a88)  NOT DMA
  Away_in_a_Manger.mp3                2014737
  Dont_Rain_on_My_Parade.mp3          3944449
  Take_My_Breathe_Away.mp3            5740819
  Welcome_Christmas.mp3               2985790
<<<SdioCard::readSector(24576, 20003a88)  NOT DMA
FLAC/
<<<SdioCard::readSector(63808, 20003a88)  NOT DMA
  T1_1024.FLA                         9802802
  T1_128.FLA                          11126659
  T1_256.FLA                          10415954
  T1_512.FLA                          10007370
<<<SdioCard::readSector(24576, 20003a88)  NOT DMA
Candyman.aac                          3177823
<<<SdioCard::readSector(24577, 20003a88)  NOT DMA
<<<SdioCard::readSector(24576, 20003a88)  NOT DMA
Dont Rain on My Parade.mp3            3944449
<<<SdioCard::readSector(24577, 20003a88)  NOT DMA
mtpindex.dat                          0

Press any key to play a wave file

Playing 2001/stop.wav
<<<SdioCard::readSector(24576, 20003a88)  NOT DMA
<<<SdioCard::readSector(27008, 20003a88)  NOT DMA
<<<SdioCard::readSector(27009, 20003a88)  NOT DMA
<<<SdioCard::readSector(34432, 200037f6)  NOT DMA
<<<SdioCard::readSector(34433, 200037f6)  NOT DMA
Audio Error: 1
<<<SdioCard::readSector(34434, 200037f6)  NOT DMA
<<<SdioCard::readSector(34435, 200037f6)  NOT DMA
<<<SdioCard::readSector(34436, 200037f6)  NOT DMA
<<<SdioCard::readSector(34437, 200037f6)  NOT DMA
<<<SdioCard::readSector(34438, 200037f6)  NOT DMA
<<<SdioCard::readSector(34439, 200037f6)  NOT DMA
<<<SdioCard::readSector(34440, 200037f6)  NOT DMA
<<<SdioCard::readSector(34441, 200037f6)  NOT DMA
<<<SdioCard::readSector(34442, 200037f6)  NOT DMA
<<<SdioCard::readSector(34443, 200037f6)  NOT DMA
<<<SdioCard::readSector(34444, 200037f6)  NOT DMA
<<<SdioCard::readSector(34445, 200037f6)  NOT DMA
<<<SdioCard::readSector(34446, 200037f6)  NOT DMA
<<<SdioCard::readSector(34447, 200037f6)  NOT DMA
<<<SdioCard::readSector(34448, 200037f6)  NOT DMA
<<<SdioCard::readSector(34449, 200037f6)  NOT DMA
<<<SdioCard::readSector(34450, 200037f6)  NOT DMA
<<<SdioCard::readSector(34451, 200037f6)  NOT DMA
<<<SdioCard::readSector(34452, 200037f6)  NOT DMA
<<<SdioCard::readSector(34453, 200037f6)  NOT DMA
<<<SdioCard::readSector(34454, 200037f6)  NOT DMA
<<<SdioCard::readSector(34455, 200037f6)  NOT DMA
<<<SdioCard::readSector(34456, 200037f6)  NOT DMA
<<<SdioCard::readSector(34457, 200037f6)  NOT DMA
<<<SdioCard::readSector(34458, 200037f6)  NOT DMA
<<<SdioCard::readSector(34459, 200037f6)  NOT DMA
<<<SdioCard::readSector(34460, 200037f6)  NOT DMA
<<<SdioCard::readSector(34461, 200037f6)  NOT DMA
<<<SdioCard::readSector(34462, 200037f6)  NOT DMA
<<<SdioCard::readSector(34463, 200037f6)  NOT DMA
<<<SdioCard::readSector(34464, 200037f6)  NOT DMA
<<<SdioCard::readSector(34465, 200037f6)  NOT DMA
<<<SdioCard::readSector(34466, 200037f6)  NOT DMA
<<<SdioCard::readSector(34467, 200037f6)  NOT DMA
<<<SdioCard::readSector(34468, 200037f6)  NOT DMA
...
<<<SdioCard::readSector(34817, 200037f6)  NOT DMA
<<<SdioCard::readSector(34818, 200037f6)  NOT DMA
<<<SdioCard::readSector(34819, 200037f6)  NOT DMA
<<<SdioCard::readSector(34820, 200037f6)  NOT DMA
<<<SdioCard::readSector(34821, 200037f6)  NOT DMA
<<<SdioCard::readSector(34822, 200037f6)  NOT DMA
<<<SdioCard::readSector(34823, 200037f6)  NOT DMA
<<<SdioCard::readSector(34824, 20003a88)  NOT DMA
Done.
Directory
---------
<<<SdioCard::readSector(24576, 20003a88)  NOT DMA
System Volume Information/
<<<SdioCard::readSector(24640, 20003a88)  NOT DMA
  WPSettings.dat                      12
  IndexerVolumeGuid                   76
<<<SdioCard::readSector(24576, 20003a88)  NOT DMA
odd1.mp3                              46888
odd1.wav                              553004
zarathustra.mp3                       489461
2001/
<<<SdioCard::readSector(27008, 20003a88)  NOT DMA
  calculations.wav                    426300
  completed.wav                       276460
  dangerous_to_remain.wav             372892
  enough_info.wav                     513388
  functional.wav                      237356
<<<SdioCard::readSector(27009, 20003a88)  NOT DMA
  one_moment.wav                      202236
  operational.wav                     772140
  sorry_dave.wav                      791164
  stop.wav                            200844
<<<SdioCard::readSector(24576, 20003a88)  NOT DMA
Audacity/
<<<SdioCard::readSector(34880, 20003a88)  NOT DMA
  Away_in_a_Manger.mp3                2014737
  Dont_Rain_on_My_Parade.mp3          3944449
  Take_My_Breathe_Away.mp3            5740819
  Welcome_Christmas.mp3               2985790
<<<SdioCard::readSector(24576, 20003a88)  NOT DMA
FLAC/
<<<SdioCard::readSector(63808, 20003a88)  NOT DMA
  T1_1024.FLA                         9802802
  T1_128.FLA                          11126659
  T1_256.FLA                          10415954
  T1_512.FLA                          10007370
<<<SdioCard::readSector(24576, 20003a88)  NOT DMA
Candyman.aac                          3177823
<<<SdioCard::readSector(24577, 20003a88)  NOT DMA
<<<SdioCard::readSector(24576, 20003a88)  NOT DMA
Dont Rain on My Parade.mp3            3944449
<<<SdioCard::readSector(24577, 20003a88)  NOT DMA
mtpindex.dat                          0

Press any key to play a wave file
 
Try the cache-test (by switching it off for a test) again ... behaves it differently? if yes, you found a reason..
 
Also, I'd add a debug-print for all cache handling (flush, delete, etc), directly inside these funcs that prints an error if address is not 32-alinged (lower bits all == 0) or size is not a 32 multiple..
A long time agoe I had proposed a assert/DIE macro for this kind of tests... it should stop with a abort() or endless loop and print the line number, so you see it easyly.
Perhaps take a look a my logging lib. Your can switch on/off logging with the Arduino-menu (or a simple platformio.ini switch)

2021-12-04 23_15_42-Window.pnghttps://github.com/FrankBoesing/TeensyLogger



I really love Platformio - it compiles *much* faster, and it can print in different colors. (Have still to add colors to my Teensy logging lib some day... Esp has it (of course)..)

These things really save a lot of time, when debugging.. trust me ;-)
Also, i posted a link somewhere for a call-stack print...
 
Last edited:
Also, I'd add a debug-print for all cache handling (flush, delete, etc), directly inside these funcs that prints an error if address is not 32-alinged (lower bits all == 0) or size is not a 32 multiple..
A long time agoe I had proposed a assert/DIE macro for this kind of tests... it should stop with a abort() or endless loop and print the line number, so you see it easyly.
Perhaps take a look a my logging lib. Your can switch on/off logging with the Arduino-menu (or a simple platformio.ini switch)


I really love Platformio - it compiles *much* faster, and it can print in different colors. (Have still to add colors to my Teensy logging lib some day... Esp has it (of course)..)

These things really save a lot of time, when debugging.. trust me ;-)
Also, i posted a link somewhere for a call-stack print...

Thanks Frank for jogging my memory - was using this lib for awhile years ago: https://github.com/thijse/Arduino-Log but forgot all about it - it was in my archives folder :)
 
Thanks @FrankB and @mjs513... As for Cache stuff, I did not think it would make much difference and it did not as all of the reads appear to be using memory in the DTCM:
Code:
Press any key to play a wave file

Playing 2001/stop.wav
<<<SdioCard::readSector(24576, 20003a84)  NOT DMA
<<<SdioCard::readSector(27008, 20003a84)  NOT DMA
<<<SdioCard::readSector(27009, 20003a84)  NOT DMA
<<<SdioCard::readSector(34432, 200037f2)  NOT DMA
<<<SdioCard::readSector(34433, 200037f2)  NOT DMA
Audio Error: 1
<<<SdioCard::readSector(34434, 200037f2)  NOT DMA
<<<SdioCard::readSector(34435, 200037f2)  NOT DMA
<<<SdioCard::readSector(34436, 200037f2)  NOT DMA
CrashReport:
  A problem occurred at (system time) 0:0:16
  Code was executing from address 0x28EA
  CFSR: 82
	(DACCVIOL) Data Access Violation
	(MMARVALID) Accessed Address: 0x20003FE1 (Stack problem)
	  Check for stack overflows, array bounds, etc.
  Temperature inside the chip was 43.20 °C
  Startup CPU clock speed is 600MHz
  Reboot was caused by auto reboot after fault or bad interrupt detected

C:\Users\kurte\Documents\Arduino\Teensy Tests\audio_sd_wave_test\audio_sd_wave_test.ino Dec  4 2021 15:06:5
Also I have not traced the NOT DMA branch yet to see what it does...

But the address above: Looking at sym file:
Code:
20003fb0 g     O .bss	00000004 errno
20003fe0 g       .bss	00000000 _ebss
20068000 g       .text.csf	00000000 _estack

So yes looks like stack problem.
Side not: From the Kernel debug output:
Code:
 >>>>> unused_interrupt_vector <<<<<
  Code was executing from address 0x000028EA
  CFSR: 00000082
	(MMARVALID) Accessed Address: 0x20003FE1
  XPSR: 010F0056
  HFSR: 00000000
  STACK: 20067ED0
	 00000071 00000000 0000000A 20067ED0
	 20001168 0000AFB3 20067ED0 2027FF80
	 20067EB0 20067ED4 2018101B 13110D0C
	 00000008 20067F98 00000049 00000000
	 00000000 20067EFC 00000001 000F4240
	 00000000 00006E89 00000000 00000001
	 20067ED8 00000019 00000000 00000000
	 20067ED8 20067F98 00000000 00000000

Will try using to log library... But may wait until tomorrow.
 
Minor update... Thought I would enable some of the debug output that was ifdefed out or commented out in that function...
screenshot.jpg
I ran it again on MicroMode and T4.1... Notices the sizes of the consume just before boom...

So the read in data is corrupted... Will look tomorrow.

I hope it is not, what I was wondering about awhile ago in https://github.com/PaulStoffregen/cores/pull/593
Where maybe IO pins 38 and 39 were reversed? If so maybe screwing up DAT2/DAT3?

all for tonight
 
Follow on from yesterday... Again not sure what is different between T41 and MMOD...

But @mjs513 and myself have done some more tracing today...
I showed a picture of two runs side by side... But now lets look at some data from MMOD:
The Consumes is the length of data it thinks it has to work with. Note buffer is 512 bytes long, so if it thinks it has 65000+ bytes to work with it will walk off and do bad things
like crash.

So if go up one layer we find that the function is called by: void AudioPlaySdWav::update(void)

So parts I put debug information into on that method:
Code:
	// is there buffered data?
	n = buffer_length - buffer_offset;
	static elapsedMicros em = 0;
	Serial.printf("update em:%u l:%u o:%u n:%d\n", (uint32_t)em, buffer_length, buffer_offset, n);
	em = 0;
	if (n > 0) {
		// we have buffered data
		if (consume(n)) return; // it was enough to transmit audio
	}

	// we only get to this point when buffer[512] is empty
	if (state != STATE_STOP && wavfile.available()) {
		// we can read more data from the file...
		readagain:
		buffer_length = wavfile.read(buffer, 512);
		Serial.printf(" << Read: %u\n", buffer_length);
		if (buffer_length == 0) goto end;
		buffer_offset = 0;
I put in the elapsedMicros and the print statements...

Now for a crash run:
Code:
Press any key to play a wave file

Playing 2001/stop.wav
update em:0 l:0 o:0 n:0
 << Read: 512
AudioPlaySdWav consume, size = 512, buffer_offset = 0, data_length = 20, space = 256, state = 8
is wav file
AudioPlaySdWav consume, size = 492, buffer_offset = 20, data_length = 16, space = 256, state = 9
audio format ok
AudioPlaySdWav consume, size = 476, buffer_offset = 36, data_length = 8, space = 256, state = 10
chunk id = 61746164, length = 200800
wav: found data chunk, len=200800
AudioPlaySdWav consume, size = 468, buffer_offset = 44, data_length = 200800, space = 256, state = 3
 << Read: 512
AudioPlaySdWav consume, size = 512, buffer_offset = 0, data_length = 200332, space = 22, state = 3
Audio Error: 1
update em:2002 l:512 o:44 n:468
AudioPlaySdWav consume, size = 468, buffer_offset = 44, data_length = 200288, space = 256, state = 3
 << Read: 512
AudioPlaySdWav consume, size = 512, buffer_offset = 0, data_length = 199820, space = 22, state = 3
update em:2897 l:512 o:44 n:468
AudioPlaySdWav consume, size = 468, buffer_offset = 44, data_length = 199776, space = 256, state = 3
 << Read: 65535
AudioPlaySdWav consume, size = 65535, buffer_offset = 0, data_length = 199308, space = 22, state = 3
update em:2896 l:65535 o:44 n:65491
AudioPlaySdWav consume, size = 65491, buffer_offset = 44, data_length = 199264, space = 256, state = 3
update em:2896 l:65535 o:556 n:64979
AudioPlaySdWav consume, size = 64979, buffer_offset = 556, data_length = 198752, space = 256, state = 3
update em:2895 l:65535 o:1068 n:64467
AudioPlaySdWav consume, size = 64467, buffer_offset = 1068, data_length = 198240, space = 256, state = 3
update em:2895 l:65535 o:1580 n:63955
AudioPlaySdWav consume, size = 63955, buffer_offset = 1580, data_length = 197728, space = 256, state = 3
CrashReport:
  A problem occurred at (system time) 8:1:2
  Code was executing from address 0x29AA
  CFSR: 82
	(DACCVIOL) Data Access Violation
	(MMARVALID) Accessed Address: 0x20004001 (Stack problem)
	  Check for stack overflows, array bounds, etc.
  Temperature inside the chip was 56.50 °C
  Startup CPU clock speed is 600MHz
  Reboot was caused by auto reboot after fault or bad interrupt detected
Note the last Read: it returned 65535 which is bogus
How can a read of 512 return 65535?

It shouldn't but we do have some inconsistencies on read return values:
Our File::read(buffer, length) returns size_t (which is unsigned) I believe 32 bits...
But FatFile returns int from it's read operation. and returns -1 in an error condition.
So not sure where in the chain converted this to 16 bit -1...

But now why is the read failing here and not on T4.1... Also I did a simple file dump program to try dumping the whole file on either one and it can...

Could it be some timing issue as I believe this read operation is being called on something like a timer?

Can post test programs if anyone wants to see them...

Now back to !$%@#%$@%$@

Kurt
 
Another quick update: I now have it not crashing by detecting the read failure... I try reading again still fails... I also then changed code to use the global object SD
and to print out errorcode...

Code:
	// we only get to this point when buffer[512] is empty
	if (state != STATE_STOP && wavfile.available()) {
		// we can read more data from the file...
		readagain:
		buffer_length = wavfile.read(buffer, 512);
		Serial.printf(" << Read: %u\n", buffer_length);
		if (buffer_length > 512) {
			Serial.printf(" << read returned:%u > 512 try again\n", buffer_length);
			buffer_length = wavfile.read(buffer, 512);
			if (buffer_length > 512) {
				uint8_t error_code = SD.sdfs.card()->errorCode();
				Serial.printf(" << Retry fail again abort: SD last error:%u\n",error_code);
				printSdErrorText(&Serial, error_code);

				goto end;
			}
		}
		if (buffer_length == 0) goto end;

Output now:
Code:
Playing 2001/stop.wav
update em:1 l:0 o:0 n:0
 << Read: 512
AudioPlaySdWav consume, size = 512, buffer_offset = 0, data_length = 20, space = 256, state = 8
is wav file
AudioPlaySdWav consume, size = 492, buffer_offset = 20, data_length = 16, space = 256, state = 9
audio format ok
AudioPlaySdWav consume, size = 476, buffer_offset = 36, data_length = 8, space = 256, state = 10
chunk id = 61746164, length = 200800
wav: found data chunk, len=200800
AudioPlaySdWav consume, size = 468, buffer_offset = 44, data_length = 200800, space = 256, state = 3
 << Read: 512
AudioPlaySdWav consume, size = 512, buffer_offset = 0, data_length = 200332, space = 22, state = 3
Audio Error: 1
update em:2026 l:512 o:44 n:468
AudioPlaySdWav consume, size = 468, buffer_offset = 44, data_length = 200288, space = 256, state = 3
 << Read: 65535
 << read returned:65535 > 512 try again
 << Retry fail again abort: SD last error:26
SDIO fifo read timeoutDone.
Directory
---------
System Volume Information/

So error code: SDIO fifo read timeout
 
Regarding the issue with WAVE files not playing on the Teensy Micromod from the SDIO card we finally traced the problem to the SDFAT library, SdioTeensy.cpp file. Had to add a extra define for the TMM:
Capture.PNG

Basically just add
Code:
|| define(ARDUINO_TEENSY_MICROMOD)
to the end of line 337 in the file.

Once done all files play from the SDIO card no problem. We did submit PR to Paul: https://github.com/PaulStoffregen/SdFat/pull/5
 
SD-Pin settings hit us every time with a new model.. ;)
Good catch.
I hope any future model will have the required (and acc. to the standard mandatory) pullups on all data-lines + cmd...
 
Last edited:
Where maybe IO pins 38 and 39 were reversed? If so maybe screwing up DAT2/DAT3?

Looks like the SDIO DAT2 & DAT3 connection was the only thing actually correct about pins 38 & 39.

Hopefully these commits fix all the lingering pin 38 & 39 swap issues.

https://github.com/PaulStoffregen/cores/commit/17f652645c1af3bb0190d6b3769d48358c7ad276

https://github.com/PaulStoffregen/cores/commit/880c5324a537f852e7aab8040fdc1fb2d6a29878


Basically just add
Code:
|| define(ARDUINO_TEENSY_MICROMOD)
to the end of line 337 in the file.

Once done all files play from the SDIO card no problem. We did submit PR to Paul: https://github.com/PaulStoffregen/SdFat/pull/5

Thanks. Merged it.

Kinda makes me wonder if SDIO is really working on Teensy 4.0 with the change to SdFat? Maybe I'll dig out one of those early breakout boards from the 2019 beta test...
 
Tried quick test with t4 with t4236 adapter and played a few wave files will try more later.
 
Back
Top