Teensy randomly hangs when uploading file via ftp (non deterministic)

[julianblanco]

Hi everyone,

I am working on a project where i have a teensy 4.1 recording audio and then uploading to an ftp server on a Raspberry Pi. I think i have a memory leak somewhere because after 20 minutes or so the teensy just hangs on uploading the file (specially always after the PASV portion of FTP). Running tcpdump on the pi, the teensy sent a fin ack (screenshots attached) where it should of sent a SYN. Some times it runs for 20 minutes before crashing, others 5+ hours. Goal is to be able to record for ten days, in the mean time I have added a watchdog timer to hopefully kick the teensy if it fails but I am afraid of this method and want to know why the thing is crashing.

Putting in debug lines, i traced it down to this function where it appears to be hanging in int EthernetClient::available() from Native Ethernet. Increasing the stack heap (setStackHeap) seemed to help make it run longer but i havent been able to get it to run longer than 12 hours thus far.

More specifically, I am using teensy audio to interface with the Cirrus cs42448 and record 6 channels to an SD card, then I stop recording, and push the recorded raw data across the network to ftp server raspi pi (directly connected via ethernet and static IPs), sleep for X seconds and then repeat.

Any ideas or pointers to keep troubleshooting?

[julianblanco]

.6 is the pi and .10 is the teeensy in the photos just in case

[SidInNJ]

Hi Julian,

I think I may be having a similar problem. I can quickly duplicate what I'm seeing by using FileZilla to transfer a file from a PC to an SD card on the Teensy 4.1. FTP consistently stops working after doing between 3 and 9 file transfers.
In my case, it appears that the failure occurs inside of a function call to tcp_listen(fsm->datapcb) (which ends up calling tcp_listen_with_backlog_and_err(struct tcp_pcb *pcb, u8_t backlog, err_t *err) in lwip\src\core\tcp.c).
Inside of tcp_listen_with_backlog_and_err is a call to memp_malloc(MEMP_TCP_PCB_LISTEN), which returns for my failure -1 (ERR_MEM).
It would appear that memp_malloc() has run out of memory blocks of type MEMP_TCP_PCB_LISTEN.

My environment: Win10, Arduino 1.8.15, Teensyduino 1.54, Code: https://github.com/PaulStoffregen/teensy41_ethernet. I made minor changes to lwip_ftpd.ino: IP addresses for my environment, added some debug messages, fixed a compile error inside of lwip_ftpd.ino's setup():

//enet_init(PHY_ADDR, mac, &ip, &mask, &gateway); 
  // Replace above with below per https://github.com/mesflores/teensy41_ethernet/blob/master/t41ether/lwip_ftpd/lwip_ftpd.ino
  enet_init(&ip, &mask, &gateway);

-Sid

[SidInNJ]

PS. I doubled the number of MEMP_TCP_PCB_LISTEN memory blocks with no apparent change.
I also fixed a compile time warning in lwip_ftpd-sd.cpp: "warning: taking address of temporary", also to no avail.

[shawn]

I’m curious if this also happens in QNEthernet. Do either/both of you feel like trying?

[SidInNJ]

I’m curious if this also happens in QNEthernet. Do either/both of you feel like trying?

Thanks for the suggestion. I just tried it, but FTP also fails after about three file transfers. I'm guessing that the problem is in the FTP implementation, not in the underlying Ethernet code.
One thing I did notice. The Teensy does not respond to a Ping with QNEthernet. I'm pretty sure it did with the original (although at this point my head is spinning enough, I'm not sure of anything. I should retest the ping.).

[shawn]

Thanks for trying it. I'm curious about the ping issue. As long as the device is connected with an IP address, I've never seen a ping to the device fail. Some things to check and to try:
1. Is the Ethernet connection cable loose? Sometimes mine comes off and I don't notice.
2. When you ping, are you certain the device has an IP address?
3. Are you using DHCP or a static IP?
4. Note: There's the convenience `Ethernet.waitForLocalIP(timeout)` convenience function.
5. Note: There's also a listener-based approach (`Ethernet.onLinkStatus` and `Ethernet.onAddressChanged` (`onAddressChanged` is probably the most useful here)) that you can use to start and stop services.
6. Partitioned network? Eg. a guest network not being accessible from other parts of the network.

Since it seems like three transfers are successful, I'm guessing that most of the things on the above list aren't applicable. I'm putting them in for posterity.

Would you like to share the code you have? Maybe I can spot something when I have a chance to look.

[SidInNJ]

Hi Shawn,

Thanks for your quick reply!!

Oops. I think the Ping problem was cockpit error. I loaded up TFTP, did 40 file transfers in a row, did Ping (after fixing the ping address !!!), reloaded FTP, did ping again, and the Ping was fine. Sorry for the rabbit trail.

Here's my .ino code:

// stepl's lwIP 2.0.2, for IDE add -I to boards.txt
// https://forum.pjrc.com/threads/45647-k6x-LAN8720(A)-amp-lwip
//  ftpd with SD lib   TODO
#include <SPI.h>
#include <SD.h>
#include <time.h>


// These were the includes used for the first FTP attempt
//#include "lwip_t41.h"
//#include "lwip/inet.h"
//#include "lwip/dhcp.h"
//#include "lwip_ftpd-sd.h"


#include "lwip_t41.h" 
#include "QNEthernet.h"                 // added per https://github.com/ssilverman/QNEthernet
using namespace qindesign::network;     // added per https://github.com/ssilverman/QNEthernet
//
#include "lwip/inet.h"
#include "lwip/dhcp.h"
#include "lwip_ftpd-sd.h"


#define LOG Serial.printf
#define PHY_ADDR 0 /*for read/write PHY registers (check link status,...)*/
#define DHCP 0
//#define IP "192.168.1.19"
#define IP "169.254.17.177"     // Same first 2 bytes as T41_AudioTftpTest_ManitouVer.ino
#define MASK "255.255.255.0"
//#define GW "192.168.1.1"
#define GW "169.254.17.1"


File *file;



static void dateTime(uint16_t* p_date, uint16_t* p_time)
{
  time_t rawtime;
  struct tm *timeinfo;

  time(&rawtime);
  timeinfo = localtime(&rawtime);

  *p_date = FAT_DATE(timeinfo->tm_year + 1900, timeinfo->tm_mon, timeinfo->tm_mday);
  *p_time = FAT_TIME(timeinfo->tm_hour, timeinfo->tm_min, 0);
}

extern "C" {
  extern int _gettimeofday_r(struct _reent *r, struct timeval *__tp, void *__tzp);

  //sd,ftp - set current time for new files, dirs.
  int _gettimeofday_r(struct _reent *r, struct timeval *__tp, void *__tzp)
  {
    //seconds and microseconds since the Epoch
    //__tp->tv_sec = 0;
    //__tp->tv_usec = 0;
    return 0;
  }
}



static void teensyMAC(uint8_t *mac)
{
  uint32_t m1 = HW_OCOTP_MAC1;
  uint32_t m2 = HW_OCOTP_MAC0;
  mac[0] = m1 >> 8;
  mac[1] = m1 >> 0;
  mac[2] = m2 >> 24;
  mac[3] = m2 >> 16;
  mac[4] = m2 >> 8;
  mac[5] = m2 >> 0;
}


static void netif_status_callback(struct netif *netif)
{
  static char str1[IP4ADDR_STRLEN_MAX], str2[IP4ADDR_STRLEN_MAX], str3[IP4ADDR_STRLEN_MAX];
  LOG("netif status changed: ip %s, mask %s, gw %s\n", ip4addr_ntoa_r(netif_ip_addr4(netif), str1, IP4ADDR_STRLEN_MAX), ip4addr_ntoa_r(netif_ip_netmask4(netif), str2, IP4ADDR_STRLEN_MAX), ip4addr_ntoa_r(netif_ip_gw4(netif), str3, IP4ADDR_STRLEN_MAX));
}

static void link_status_callback(struct netif *netif)
{
  LOG("enet link status: %s\n", netif_is_link_up(netif) ? "up" : "down");
}




File root;

void setup()
{
  Serial.begin(115200);
  while (!Serial) delay(100);

  Serial.println("Compiled at: " __DATE__ ", " __TIME__);


  // FatFile::dateTimeCallback(dateTime);

  Serial.print("MEMP_NUM_TCP_PCB_LISTEN = ");
  Serial.println(MEMP_NUM_TCP_PCB_LISTEN);

  Serial.print("Initializing SD card...");

  if (!SD.begin(BUILTIN_SDCARD)) {
  //if (!SD.begin(SDCARD_CS_PIN)) {             // Use this line when the SD card is in the Audio board instead of 4.1
    Serial.println("initialization failed!");
    return;
  }
  Serial.println("initialization done.");

  root = SD.open("/");
  root.rewindDirectory();
  printDirectory(root, 0);
  root.rewindDirectory();

  LOG("PHY_ADDR %d\n", PHY_ADDR);
  uint8_t mac[6];
  teensyMAC(mac);
  LOG("MAC_ADDR %02x:%02x:%02x:%02x:%02x:%02x\n", mac[0], mac[1], mac[2], mac[3], mac[4], mac[5]);

  LOG("DHCP is %s\n", DHCP == 1 ? "on" : "off");

  ip_addr_t ip, mask, gateway;
  if (DHCP == 1)
  {
    ip = IPADDR4_INIT(IPADDR_ANY);
    mask = IPADDR4_INIT(IPADDR_ANY);
    gateway = IPADDR4_INIT(IPADDR_ANY);
  }
  else
  {
    inet_aton(IP, &ip);
    inet_aton(MASK, &mask);
    inet_aton(GW, &gateway);
  }

  //enet_init(PHY_ADDR, mac, &ip, &mask, &gateway); 
  // Replace above with below per https://github.com/mesflores/teensy41_ethernet/blob/master/t41ether/lwip_ftpd/lwip_ftpd.ino
  // Sid 2021-08-19
  //enet_init(&ip, &mask, &gateway);
  // and remove  for QNEthernet
  // Instead call .begin()
  // begin defined as: static void begin(IPAddress ip, IPAddress dns, IPAddress gateway);

  IPAddress myIp   = IPAddress(169,254,17,177);
  IPAddress myMask = IPAddress(255,255,255,0);
  IPAddress myGW   = IPAddress(169,254,17,1);

  Ethernet.begin(myIp, myMask, myGW);
  //Ethernet.begin();

  Serial.print(F("My IP address before setting again: "));
  Ethernet.localIP().printTo(Serial);
  Serial.println();

  Ethernet.setLocalIP(myIp);

  Serial.print(F("My IP address after: "));
  Ethernet.localIP().printTo(Serial);
  Serial.println();

  netif_set_status_callback(netif_default, netif_status_callback);
  netif_set_link_callback(netif_default, link_status_callback);
  netif_set_up(netif_default);

  if (DHCP == 1)
    dhcp_start(netif_default);

  ftpd_init(&SD);

}

void loop()
{
  static uint32_t last_ms;
  uint32_t ms;

  enet_proc_input();

  ms = millis();
  if (ms - last_ms > 100)
  {
    last_ms = ms;
    enet_poll();
  }

  if (Serial.available())
  {
      char c = toupper(Serial.read());
      switch (c)
      {
      case 'F':
          root.rewindDirectory();
          printDirectory(root, 0);
          root.rewindDirectory();
          break;

      case '\n':
      case '\r':
          break;

      default:
          {
              Serial.print(F("?? Cmd?: "));
              Serial.println(c);
          }
          break;
      }
}
}


void printDirectory(File dir, int numTabs)
{
    while (true)
    {
        File entry = dir.openNextFile();
        if (!entry)
        {
            if (numTabs == 0) Serial.println("** Done **");
            return;
        }
        for (uint8_t i = 0; i < numTabs; i++)
            Serial.print('\t');
        Serial.print(entry.name());
        if (entry.isDirectory())
        {
            Serial.println("/");
            printDirectory(entry, numTabs + 1);
        }
        else
        {
            Serial.print("\t\t");
            Serial.println(entry.size(), DEC);
        }
        entry.close();
    }
}

Thanks,
Sid

[shawn]

If 40 transfers worked, does this mean the problem appears solved with QNEthernet? Having a look at the source anyway...

[SidInNJ]

Sorry, no. It was with TFTP that the transfers worked. With FTP I still get the "Out of memory error" after 3+ file transfers.
And thanks for looking!

[shawn]

I'm almost done with the example. Where's lwip_ftpd-sd.h from?

Update: Found it here: https://github.com/PaulStoffregen/te...r/lwip-ftpd-sd

[shawn]

I had to fix some compile problems: Changed FAT_* to FS_* in the `gmtime` function in vfs.cpp.

[shawn]

Sid, let's call this "Example 1". I cleaned up the networking code, but left the ftpd part as-is. If this still has problems, then we'd need to look inside ftpd. (I don't have the hardware with which to test.)

Please make sure you have the latest QNEthernet, whatever's the latest on GitHub.

#include <QNEthernet.h>
#include <SD.h>
#include <TimeLib.h>
#include <lwip_ftpd-sd.h>

// Use members from QNEthernet's namespace
// See: https://github.com/ssilverman/QNEthernet
using namespace qindesign::network;

// --------------------------------------------------------------------------
//  Configuration
// --------------------------------------------------------------------------

constexpr uint32_t kDHCPTimeout = 10000;  // 10 seconds

// IP configuration
IPAddress staticIP{0, 0, 0, 0};    // Set to non-zero for a static IP
IPAddress subnetMask{0, 0, 0, 0};  // Used if staticIP != 0
IPAddress gateway{0, 0, 0, 0};     // Used if staticIP != 0

// --------------------------------------------------------------------------
//  Main program
// --------------------------------------------------------------------------

File root;
bool rootExists = false;  // SD may not have initialized; loop() needs this

// Forward declarations
void printDirectory(File &dir, int numTabs);

// Main program setup.
void setup() {
  Serial.begin(115200);
  while (!Serial && millis() < 4000) {
    // Wait for Serial initialization
    yield();
  }
  Serial.println("Waiting 3s...");
  delay(3000);  // Give a monitor time to come up, if using an external tool

  Serial.println("Compiled at: " __DATE__ ", " __TIME__);

  // Set up the clock
  // Note: Should probably set the time via SNTP once in a while
  setSyncProvider([]() -> time_t { return Teensy3Clock.get(); });

  // Set the time callback for the FS
  SdFile::dateTimeCallback([](uint16_t *date, uint16_t *time) {
    tmElements_t tm;
    breakTime(now(), tm);
    *date = FAT_DATE(tm.Year + 1970, tm.Month, tm.Day);
    *time = FAT_TIME(tm.Hour, tm.Minute, tm.Second);
  });

  // Include <lwip/opt.h> if you want to examine lwIP variables
  // Serial.printf("MEMP_NUM_TCP_PCB_LISTEN = %d", MEMP_NUM_TCP_PCB_LISTEN);

  Serial.print("Initializing SD card...");
  if (!SD.begin(BUILTIN_SDCARD)) {  // Use SDCARD_CS_PIN when on Audio board
    Serial.println("failed!");
    return;
  }
  Serial.println("done.");

  root = SD.open("/");
  root.rewindDirectory();
  printDirectory(root, 0);
  root.rewindDirectory();

  rootExists = true;

  // Add some Ethernet listeners before we initialize it
  // We could use just Ethernet.waitForLocalIP(timeout) if using DHCP,
  // but let's get fancy and use listeners to track stuff.

  Ethernet.onLinkStatus([](bool state) {
    Serial.printf("Ethernet: Link %s\n", state ? "ON" : "OFF");
  });

  Ethernet.onAddressChanged([]() {
    IPAddress ip = Ethernet.localIP();
    bool hasIP = !(ip == INADDR_NONE);
    if (hasIP) {
      Serial.println("Ethernet: Address changed:");

      IPAddress ip = Ethernet.localIP();
      Serial.printf("    Local IP = %u.%u.%u.%u\n", ip[0], ip[1], ip[2], ip[3]);
      ip = Ethernet.subnetMask();
      Serial.printf("    Subnet   = %u.%u.%u.%u\n", ip[0], ip[1], ip[2], ip[3]);
      ip = Ethernet.gatewayIP();
      Serial.printf("    Gateway  = %u.%u.%u.%u\n", ip[0], ip[1], ip[2], ip[3]);
      ip = Ethernet.dnsServerIP();
      if (!(ip == INADDR_NONE)) {  // May happen with static IP
        Serial.printf("    DNS      = %u.%u.%u.%u\n",
                      ip[0], ip[1], ip[2], ip[3]);
      }
    } else {
      Serial.println("Ethernet: Address changed: No IP address");
    }
  });

  // Initialize Ethernet
  uint8_t mac[6];
  Ethernet.macAddress(mac);
  Serial.printf("MAC = %02x:%02x:%02x:%02x:%02x:%02x\n",
                mac[0], mac[1], mac[2], mac[3], mac[4], mac[5]);

  if (staticIP == INADDR_NONE) {
    Serial.println("Starting Ethernet (DHCP)...");
    uint32_t t = millis();
    if (Ethernet.begin()) {
      // Give DHCP some time
      if (!Ethernet.waitForLocalIP(kDHCPTimeout)) {
        Serial.printf("    No IP from DHCP (%lu ms).\n", millis() - t);
      } else {
        Serial.printf("DHCP and setup took about %lu ms.\n", millis() - t);
      }
    } else {
      Serial.println("Failed to start Ethernet");
    }
  } else {
    Serial.println("Server: Starting Ethernet (Static)...");
    Ethernet.begin(staticIP, subnetMask, gateway);
    Ethernet.setDNSServerIP(gateway);
  }

  ftpd_init(&SD);
}

// Main program loop.
void loop() {
  // loop() will still run when SD failed to initialize
  if (!rootExists) {
    return;
  }

  while (Serial.available() > 0) {
    char c = Serial.read();
    switch (c) {
      case 'f':
      case 'F':
        root.rewindDirectory();
        printDirectory(root, 0);
        root.rewindDirectory();
        break;

      case '\n':
      case '\r':
        break;

      default: {
        // Make printing each character a little nicer
        Serial.print("?? Cmd?: ");
        if (0x20 <= c && c < 0x7f) {
          // Only print the printable characters
          Serial.println(c);
        } else {
          Serial.printf("0x%02x\n", c);
        }
      } break;
    }
  }
}

// Prints a directory.
//
// Note that this uses a reference to avoid a copy.
void printDirectory(File &dir, int numTabs) {
  while (true) {
    File entry = dir.openNextFile();
    if (!entry) {
      if (numTabs == 0) {
        Serial.println("** Done **");
      }
      return;
    }
    for (int i = 0; i < numTabs; i++) {
      Serial.print('\t');
    }
    Serial.print(entry.name());
    if (entry.isDirectory()) {
      Serial.println("/");
      printDirectory(entry, numTabs + 1);
    } else {
      Serial.print("\t\t");
      Serial.println(entry.size());
    }
    entry.close();
  }
}

[SidInNJ]

Hi Shawn,

Thanks for the nice example. I tried it, but sadly had the same results.
With some debug prints:

response: 200 Command okay.
query: PASV
#### tcp_listen(fsm->datapcb) returned NULL. res=-1

The -1 is:

/** Out of memory error.     */
  ERR_MEM        = -1,

(I saved the res code to a global)
It looks like I got QNEthernet just after the latest update three days ago.

[shawn]

A couple things I can think of:
1. Try increasing the number of listening things by setting MEMP_NUM_TCP_PCB_LISTEN to something greater than 8 in lwipopts.h.
2. Is it possible that whatever FTP client you're using isn't closing the PASV connections? For example, with an FTP client, try a manual FTP transfer, then closing the connection, then restarting a bunch of times. Something isn't closing the PASV connection so my guess is that the FTP client isn't closing them. When I say "closing the connection", I mean clean-killing the FTP client, eg. "quit" or whatever's needed.
3. See if you can correlate MEMP_NUM_TCP_PCB_LISTEN with the number of FTP transfers allowed and post the results here. i.e. set MEMP_NUM_TCP_PCB_LISTEN to something, run some tests, and get the number of allowed transfers. For each "allowed transfer", do two experiments: 1) Do what you're doing now, and 2) Kill the FTP client between each transfer.
4. What is the exact sequence of FTP steps you're doing?
5. I think there's a strong possibility your FTP client is holding connections open or doing more than a few simultaneous transfers at a time. Each PASV command requires a listening socket.

[SidInNJ]

Thanks for the suggestions!

I increased MEMP_NUM_TCP_PCB_LISTEN from 8 to 16. It took about twice as many transfers before failing (3 or 4 when set to 8, 7 or 8 when set to 16). This was without doing a manual disconnect between transfers.
Doing a "Disconnect" in FileZilla between file transfers didn't make any difference; still failed after 7 transfers.

Reset the Teensy 4.1 and tried again: After each transfer did a "Disconnect" in FileZilla, closed FileZilla, opened FileZilla, did another transfer. Failed attempting the 8th transfer.

Below is the last couple of successful transfer/disconnect/log-in/transfer, the failure, along with FileZilla doing some auto-retries:

response: 220 lwIP FTP Server ready.
query: USER arduino
response: 331 User name okay, need password.
query: PASS terst
response: 230 User logged in, proceed.
query: SYST
response: 214 UNIX system type.
query: FEAT
response: 502 Command not implemented.
query: PWD
response: 257 "/" is current directory.
query: TYPE I
Got TYPE -I-
response: 200 Command okay.
query: PASV
response: 227 Entering Passive Mode (169,254,17,177,16,11).
query: LIST
response: 150 File status okay; about to open data connection.
Sent: [System Volume Information/ 
Bounce2.cpp  140166
Bounce2.h  6330
SDTEST1.mp3  2791046
SDTEST2.mp3  2962926
SDTEST3.mp3  2079162
SDTEST4.mp3  3135327
VOICE1.MP3  586098
VOICE2.MP3  622883
]
response: 226 Closing data connection.
query: TYPE A
Got TYPE -A-
response: 200 Command okay.
query: PASV
response: 227 Entering Passive Mode (169,254,17,177,16,12).
query: STOR Bounce2.cpp
response: 150 Opening BINARY mode data connection for Bounce2.cpp.
response: 226 Closing data connection.
response: 220 lwIP FTP Server ready.
query: USER arduino
response: 331 User name okay, need password.
query: PASS terst
response: 230 User logged in, proceed.
query: SYST
response: 214 UNIX system type.
query: FEAT
response: 502 Command not implemented.
query: PWD
response: 257 "/" is current directory.
query: TYPE I
Got TYPE -I-
response: 200 Command okay.
query: PASV
response: 227 Entering Passive Mode (169,254,17,177,16,13).
query: LIST
response: 150 File status okay; about to open data connection.
Sent: [System Volume Information/ 
Bounce2.cpp  143760
Bounce2.h  6330
SDTEST1.mp3  2791046
SDTEST2.mp3  2962926
SDTEST3.mp3  2079162
SDTEST4.mp3  3135327
VOICE1.MP3  586098
VOICE2.MP3  622883
]
response: 226 Closing data connection.
query: TYPE A
Got TYPE -A-
response: 200 Command okay.
query: PASV
response: 227 Entering Passive Mode (169,254,17,177,16,14).
query: STOR Bounce2.cpp
response: 150 Opening BINARY mode data connection for Bounce2.cpp.
response: 226 Closing data connection.
response: 220 lwIP FTP Server ready.
query: USER arduino
response: 331 User name okay, need password.
query: PASS terst
response: 230 User logged in, proceed.
query: SYST
response: 214 UNIX system type.
query: FEAT
response: 502 Command not implemented.
query: PWD
response: 257 "/" is current directory.
query: TYPE I
Got TYPE -I-
response: 200 Command okay.
query: PASV
response: 227 Entering Passive Mode (169,254,17,177,16,15).
query: LIST
response: 150 File status okay; about to open data connection.
Sent: [System Volume Information/ 
Bounce2.cpp  147354
Bounce2.h  6330
SDTEST1.mp3  2791046
SDTEST2.mp3  2962926
SDTEST3.mp3  2079162
SDTEST4.mp3  3135327
VOICE1.MP3  586098
VOICE2.MP3  622883
]
response: 226 Closing data connection.
query: TYPE A
Got TYPE -A-
response: 200 Command okay.
query: PASV
#### tcp_listen(fsm->datapcb) returned NULL. res=-1
response: 220 lwIP FTP Server ready.
query: USER arduino
response: 331 User name okay, need password.
query: PASS terst
response: 230 User logged in, proceed.
query: CWD /
response: 250 Requested file action okay, completed.
query: PWD
response: 257 "/" is current directory.
query: TYPE A
Got TYPE -A-
response: 200 Command okay.
query: PASV
#### tcp_listen(fsm->datapcb) returned NULL. res=-1
response: 220 lwIP FTP Server ready.
query: USER arduino
response: 331 User name okay, need password.
query: PASS terst
response: 230 User logged in, proceed.
query: CWD /
response: 250 Requested file action okay, completed.
query: TYPE A
Got TYPE -A-
response: 200 Command okay.
query: PASV
#### tcp_listen(fsm->datapcb) returned NULL. res=-1

For the above I set: #define FTPD_DEBUG 1
and put a buffer print into send_data() in lwip_ftpd-sd.cpp

[SidInNJ]

Making some progress!! Even though it appears that "response: 226 Closing data connection." should be taking care of everything, there must be something unique to FileZilla.
I tried running FTP from a command prompt in Win10. After the initial connection, I was able to do 40 file transfers without ever quitting out of FTP. I just entered "put sdep.h" each time. The repeated printouts were:

query: PORT 169,254,17,101,245,233
response: 200 Command okay.
query: STOR sdep.h
response: 150 Opening BINARY mode data connection for sdep.h.
response: 226 Closing data connection.

I also did about 35 "dir" commands and each time the SD card directory was returned! BTW, FileZilla never successfully showed the directory.

I can use this!! Thank you so much for all your time, help, hints, research,...

The only thing I think I need to do now is see why each time I do a "put" with the same file name the file gets appended instead of replaced. But I saw that with TFTP and was able to fix it there. And then I'll do some stress tests (big files, pull and replace the Ethernet cable and see what recovery looks like...)

I'll keep you posted! Thanks again!!

[shawn]

Glad you found a solution. It sounds like:
1. That ftpd code should be modified to protect against malicious clients. I.e. ones that don’t close the PASV connection and cause the listening sockets to stay open. (There might be a reason, eg. performance, why some clients do this.) Some sort of timeout scheme would help. And here, I’d consider FileZilla a “malicious client” from the perspective of an embedded system.
2. Since doubling the number of MEMP_NUM_TCP_PCB_LISTENs resulted in being able to double the number of successful transfers, this further confirms the client’s misbehaviour.

[SidInNJ]

That sounds like a great solution.
And maybe also: if a new PASV request arrives, check for an existing one and close if so, then handle the new request.

Meanwhile, I'm still working on the append problem.... :-) But that shouldn't be horrific.

[shawn]

Maybe close if it’s from the same host.

[SidInNJ]

Hmm, yes. That does make for a better general case!

[SidInNJ]

Hi Shawn,

I should have done this before, but I just did a quick compare between the printouts between running FTP from a Win10 command line (works!) and FileZilla (fails at about 3 or 4 file transfers with MEMP_NUM_TCP_PCB_LISTEN set back to the original 8). Shown in initiating the connection (logging in...), and sending a file to the FTP server. Logging stopped before disconnecting.
FileZilla:

response: 220 lwIP FTP Server ready.
query: USER arduino
response: 331 User name okay, need password.
query: PASS terst
response: 230 User logged in, proceed.
query: PWD
response: 257 "/" is current directory.
query: TYPE A
Got TYPE -A-
response: 200 Command okay.
query: PASV
response: 227 Entering Passive Mode (169,254,17,177,16,8).
query: STOR sdep.h
cmd_stor() file name: /sdep.h
mode for SDClass::open(): 0x2flags: 0x602, O_RDWR: 0x2, O_AT_END: 0x4000, O_READ: 0x0, O_WRITE: 0x1, USE_FCNTL_H: 0x1, sizeof(oflag_t): 0x4
response: 150 Opening BINARY mode data connection for /sdep.h.
response: 226 Closing data connection.

Win10 Cmd Line:

response: 220 lwIP FTP Server ready.
query: OPTS UTF8 ON
response: 502 Command not implemented.
query: USER anonymous
response: 331 User name okay, need password.
query: PASS Sid@DESKTOP-S8IQPR0
response: 230 User logged in, proceed.
query: PORT 169,254,17,101,199,226
response: 200 Command okay.
query: STOR sdep.h
cmd_stor() file name: /sdep.h
mode for SDClass::open(): 0x2flags: 0x602, O_RDWR: 0x2, O_AT_END: 0x4000, O_READ: 0x0, O_WRITE: 0x1, USE_FCNTL_H: 0x1, sizeof(oflag_t): 0x4
response: 150 Opening BINARY mode data connection for /sdep.h.
response: 226 Closing data connection.

The biggest difference I'm seeing is that FileZilla does the PASV command, and the command line version does not.
I haven't determined the best way/where to fix that yet, but I have made some other progress:
> Directories are now sent in a format that FileZilla and SlickEdit can understand them and display them (for now just faking the date/time and permissions).
> A file can be sent (PUT) to a subdirectory.
> A file can be received (GET) from a subdirectory.
But not fixed yet: Deleting a file from a subdirectory.

I just upgraded to Arduino IDE 1.8.16 and Teensyduino 1.55. Some things changed under the hood, so I need to do some fixing to get it all to compile again...

[jakespeed]

Hello,
is there any news on this ?
Did someone bring that to Littlefs ?
greedings
Jake

[SidInNJ]

Hi Jake,

I ended up using the Windows command line version of FTP. It doesn't make use of PASV. Everything I tried that did use PASV eventually hung the Teensy.

To take care of the killing the audio when an FTP starts, before handling an FTP request, I check if audio is playing, and if so deny the FTP. If an FTP is in progress, it seems to be a blocking function so it naturally keeps the Audio from starting. Not at all elegant, but unless I get a huge block of time to dive into the bowels of the FTP code, I'll have to make do with this. Sorry I don't have better news.

Thanks for checking,
Sid

[shawn]

Here's what I believe happened: The fault is in the FTP server library that likely opens sockets until they're all used up (because of the all the PASV requests), and then the client hung on to them, so it appeared the Teensy couldn't open or accept any new connections. I wonder if the Teensy would still appear hung if the FTP client is killed?