Probleme beim Webtransfer

Moin zusammen,

mir ist vor einer Weile schon mal etwas aufgefallen, von dem ich inzwischen dachte, dass es gelöst sei. Und zwar fiel auf, dass Dateien unvollständig auf SD geschrieben wurden (sowohl Webtransfer als auch FTP). Hatte dies eher einem Speicherproblem zugeschrieben.
Also scheinbar werden sie kopiert, defacto werden sie jedoch unnvollständig geschrieben. Nun hatte ich am Wochenende größere Mengen (2 GB oder so) via Webtransfer auf den ESPuino meiner Tochter kopiert - da wird ein Lolin32 + PN5180 + SD_MMC verwendet. Da sind mir keine Probleme aufgefallen. Der Durchsatz lag hier bei etwa 350 kB/s - an den kürzlich eingeführten Statistiken kann man das ja gut sehen.

Gestern beim Kopieren auf den ESPuino meines Sohnemanns (Lolin D32 + RC522 + SD-SPI) trat das Problem jedoch wieder auf. Schon beim Transfer (SD-SPI ist ja etwas langsamer als SD_MMC) ist etwas verwunderlich, dass dieser erst etwas langsamer losgeht, um sich dann jedoch irgendwann auf dem Durchsatz von SD_MMC einzupendeln. Das ist dann wohl der Punkt, an dem es Probleme gibt.

Der Webtransfer (@Harry hatte das damals implementiert) funktioniert so, dass der Webserver den Datenstrom entgegennimmt und in IP-Paketgröße ganz oft (bis die ganze Datei abgearbeitet ist) den Datenstrom an eine Methode übergibt. Diese Methode (explorerHandleFileUpload()) erstellt bei ihrem ersten Aufruf einen Ringpuffer, in dem die Daten landen. Zusätzlich einen Task, der die Daten des Ringpuffers entgegen nimmt und in eine Datei schreibt (explorerHandleFileStorageTask()). Ist der Transfer zu Ende, so werden Ringpuffer und Task wieder gelöscht, so dass sie keinen Speicher mehr belegen. Vorteile an dieser Vorgehensweise ist: Das Empfangen und das Schreiben des Datenstroms kann parallel passieren, was die Sache schneller macht. Es frisst aber auch keinen Speicher, wenn nix übertragen wird.

Ein Task ist im Endeffekt eine Funktion, die losgelöst vom Rest läuft und von der der Teil, der zyklisch laufen soll, in einer Endlosschleife läuft. Läuft diese Schleife zu schnell, so kann sie den ESP32 zum Neustart bringen oder andere Funktionen beeinträchtigen, da diese keine CPU-Zeit mehr kriegen. Es kann daher notwendig sein, an dieser Stelle Delays einzubauen. Und genau an dieser Stelle gab es jetzt offenbar ein Problem:

Wir hatten uns einfach darauf verlassen, dass uploadFile.write() schon klappen wird und haben den Rückgabewert nicht ausgewertet. In Verbindung mit nur einer Millisekunde Delay, was ich für SD_MMC optimiert hatte, zeigte sich jedoch, dass diese Methode ganz oft „hat nicht geklappt“ zurückliefert. Ich habe daher jetzt beim Delay eine Unterscheidung vorgenommen, die zwischen SD_MMC und SPI-SD unterscheidet:

Ich habe zusätzlich eine kleine Statistik implementiert, die im Log ausgegeben wird. Dort kann man sehen, ob eine Datei ohne Fehler geschrieben wurde. Das sieht z.B. so aus:

Datei geschrieben: /mp313.mp3 => 240170769 bytes in 646190 ms (371 kB/s)
Bytes [ok] 240170769 / [not ok] 0

Also offenbar ist es so, dass das eigentliche Schreiben auf SD asynchron geschieht und der ESP32 nicht mehr nachkommt, wenn das Delay nicht lange genug ist. Ich meine in Erinnerung zu haben, dass bei SPI-SD noch irgendwelche Checks stattfinden, die das Ganze im Endeffekt auch langsamer machen im Vergleich zu SD_MMC. Vermutung: Diese finden nachgelagert statt und hier gibt es Probleme.

TL;DR:
Meine Bitte an diejenigen, die bereits den aktuellen Master benutzen: Aktualisiert bitte mal auf den aktuellen Softwarestand, ladet ein paar Files via Webtransfer hoch und schaut, ob es hier Probleme gibt. Wenn bei „not ok“ eine 0 steht dann passt alles. Für SD_MMC ist es aus meiner Sicht ok. Bei SPI-SD habe ich jetzt ein wenig mit dem Delay „gespielt“, bis es aus meiner Sicht ok war.

@Harry Du hattest die Ringpuffergröße und auch den Task auf 4k gesetzt. Hat das Vorteile aus deiner Sicht ggü 2k? Weil so wie ich das sehe, kommen die Daten maximal in IP-Paketgröße an (knapp über 1400).
EDIT: Glaube die Frage kann ich mir selbst beantworten: Es erhöht die Sicherheit, falls das Schreiben mal nicht nachkommt. Mit weniger Puffer wäre das Problem vermutlich noch größer bei SPI-SD.

Hallo,

Ich habe zweimal versucht via Webtransfer 30 Lieder Hochzuladen. Einmal hörte die Übertragung bei Track11 auf, das andere mal bei Track 6.
Im logfile bekomme ich aber nicht die von dir erwähnte Anzeige?


Also beim Hochladen müsste nach jeder Datei sowas im Log stehen, wie ich es oben gepostet habe. Zumindest dann, wenn der Loglevel Debug ist.

Habe es mal mit einem einzelnen Track ausprobiert, da bekomme ich einen Logfile-Eintrag:

Schreibe Datei: /fasching/05 Ich Bin Die Kleine Hexe.mp3
Datei geschrieben: /fasching/05 Ich Bin Die Kleine Hexe.mp3 => 2941508 bytes in 19482 ms (150 kB/s)
Bytes [ok] 2941508 / [not ok] 0

Habe dann versucht 30 Tracks zu laden, da kamen zwischendurch mehr Bytes NOK als Dateigröße, Der ESP ist dann irgendwann neugestartet.

Leider konnte ich das Logfile nicht sichern, da ich den /log nicht in einen neuem Tab aufgerufen habe sondern nur alle 3 Sekunden neu geladen habe.
Nun kann ich über das Webinterace nicht mal eine einzelne Datei hochladen ohne das er Neustartet.

Edit: Neu die Firmware geflasht und eine Datei hochgeladen:

Maximale Inaktivitätszeit wurde aus NVS geladen: 10
Initiale LED-Helligkeit wurde aus NVS geladen: 16
LED-Helligkeit für Nachtmodus wurde aus NVS geladen: 2
Versuche SD-Karte wird im SPI-Modus zu mounten…
FTP-User wurde aus NVS geladen: esp32
FTP-Passwort wurde aus NVS geladen: esp32
Initiale Lautstärke wurde aus NVS geladen: 3
Maximale Lautstärke für Lautsprecher wurde ins NVS geschrieben.
Unterer Spannungslevel (Batterie) fuer Neopixel-Anzeige aus NVS geladen: 3.00 V
Oberer Spannungslevel (Batterie) fuer Neopixel-Anzeige aus NVS geladen: 4.20 V
Spannungslevel (Batterie) fuer Warnung via Neopixel aus NVS geladen: 3.40 V
Zyklus für Spannungsmessung (Batterie) fuer Neopixel-Anzeige aus NVS geladen: 10 Minuten
RFID-Tags koennen jetzt gescannt werden…
Hostname aus NVS geladen: espunio
Aktuelle IP: 192.168.0.220
Freier Heap-Speicher nach Setup-Routine: 133352
PSRAM: 4194204 bytes
Flash-size: 16777216 bytes
RSSI: -60 dBm
Neue Lautstärke empfangen via Queue: 3
Aktuelle Batteriespannung: 4.16 V
RSSI: -56 dBm
Schreibe Datei: /t3/02 Meine Hände Sind Verschwunden.mp3
Datei geschrieben: /t3/02 Meine H„nde Sind Verschwunden.mp3 => 4159856 bytes in 16833 ms (247 kB/s)
Bytes [ok] 692352 / [not ok] 3467504

RSSI: -57 dBm

Dann muss ich wohl mal recherchieren, was man da machen kann. Mit sdmmc ist es ok.

Nachdem ich gestern noch einige Dateien auf die SD schieben wollte und es via Webtransfer nicht ging, habe ich es über FTP probiert. Leider erfolglos.

Client connected!
USER esp32
PASS esp32
OK. Waiting for commands.
CWD /t3
CWD P=/t3 CWD=/
250 CWD Ok. Current directory is „/t3“
PWD
TYPE I
PASV
Connection management set to passive
Data port set to 50009
STOR 002.mp3
ftpdataserver client…
Receiving 002.mp3
assertion „0 && „fatfs internal error““ failed: file „/home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/fatfs/src/vfs_fat.c“, line 253, function: fresult_to_errno
abort() was called at PC 0x4018ca2b on core 1

Habe dann noch mit den Dateinamen experimentiert und nachdem es mit der Google Suche auch keinen klaren Hinweis gab, habe ich die SD-Karte im Rechner nochmal neu formatiert.
Nun funktioniert der Upload via FTP ohne Probleme.

Dann habe ich nochmal den Upload via WebGUI versucht. 30 Dateien. Bei Track22 kam er kurz ins Stolpern:

Datei geschrieben: /test/20 - Das Obstlied.mp3 => 4438516 bytes in 28090 ms (158 kB/s)
Bytes [ok] 3319246 / [not ok] 1119270

Diese Datei hatte beim Übertragen auch die höchste Geschwindigkeit, sonst lag der Schnitt meistens zwischen 130-140kB/s.

Ich glaube das es bei mir nun wohl zufriedenstellend funktioniert.

Ich habe am Freitag noch ein bisschen rumprobiert, aber das Problem nicht so wirklich gelöst bekommen. Weiß aktuell nicht, was ich machen soll, um das zu verbessern :woman_shrugging:

Hallo,

auch bei mir kommt es beim Upload von Dateien via WebGUI zu Fehlern:

Writing file: /sounds/THE WHITE WALKERS - SEVEN KINGDOM ARMY… (SEVEN NATION ARMY PARODY).mp3
RSSI: -73 dBm
File written: /sounds/THE WHITE WALKERS - SEVEN KINGDOM ARMY… (SEVEN NATION ARMY PARODY).mp3 => 7135129 bytes in 24897 ms (286 kB/s)
Bytes [ok] 156290 / [not ok] 6978839
Control-command received via queue: 3
Command: pause
RSSI: -73 dBm
Writing file: /sounds/Puscifer - Trekka.mp3
RSSI: -73 dBm
File written: /sounds/Puscifer - Trekka.mp3 => 6873591 bytes in 24167 ms (284 kB/s)
Bytes [ok] 794957 / [not ok] 6078634

Bei der Dateiübertragung mittels FTP scheint es keine Probleme zu geben. Infos dazu finden sich aber nicht im Log.

Im Einsatz ist hier Deine Lolin32 D32 pro mit RC522 Platine @biologist

Ist eigentlich davon auszugehen, dass es beim OTA-Update auch zu einer fehlerhaften Übertragung kommen kann?

Ich habe für das Thema bislang leider noch keine Lösung. Via FTP läuft das Ganze komplett anders und da habe ich bisher noch kein Logging eingebaut - deswegen sieht man da nix.
Beim OTA-Update ist es so, dass die Daten im Flash und nicht auf SD landet. Mir sind da bislang keine Probleme bekannt.

Können wir diesen Fehler eigentlich auf die per SPI angebundenen SD-Karten eingrenzen?

@Joe Hast Du die Dateien gemeinsam hochgeladen, also wurden beide direkt hintereinander gestartet?

Es sieht ja so aus, als wenn „er“ nach einem Fehler komplett abbricht, also gar keine Daten mehr schreibt. Deshalb geht auch die angezeigte Geschwindigkeit hoch.
Zur Eingrenzung könnte man bei einem „false“ beim write auch direkt 5 ms warten und es erneut probieren. Nach drei Versuchen dann den Transfer komplett beenden.

Wie ist eigentlich die aktuelle Zuteilung von CPU und Prio pro Task? Es könnte ja wirklich so sein, dass die anderen Tasks zu wenig Zeit für das Schreiben lassen. Das würde man durch den wdt_reset evtl. nicht mitbekommen.

Die Dateiuploads wurden einzeln ausgeführt.

Ich vermute mal, dass es gar nicht so erheblich ist, ob das einzelne Transfers sind oder ein „Batch“. Weil der Task, der die Daten annimmt, wird für jedes zu übertragende File angelegt und am Ende wieder gelöscht.

Kann ich nicht 100% sagen, aber ich habe den Fehler bei SD_MMC zumindest noch nicht gesehen in der aktuellen Implementierung.

Das könnte man testen, ja.

Muss man ausprobieren. Also ich habe die Taskprio des empfangenden Tasks mal erhöht und sowohl bei bei der Funktion, die der Webserver aufruft (die schickt die Daten) - als auch beim empfangenden Task, ein bisschen mit Delays gespielt. Hat leider nix gebracht.

Den wdt_reset habe ich beim schreibenden Task vor kurzem übrigens rausgenommen, als ich dort Delays eingeführt habe.

Stattdessen habe ich jetzt Delays drin, die sich daran orientieren, ob es SD_MMC ist oder nicht. Bringt nur leider offenbar nix für SPI:

Also ich habe eben mal versucht, den Schreibvorgang im Falle eines Fehlers erneut auszuführen. Dazwischen habe ich Delays von 5 bzw. 20 ms eingefügt. Also man kriegt das damit nicht gerettet.

Offenbar ist das Problem aber nicht unbekannt: Problem writing to card in SPI mode - ESP32 Forum.
uSD card using SPI and fwrite() consistently fails after short operating period - ESP32 Forum

Zum zweiten Link: yield() aufzurufen hat leider das Problem nicht gelöst.

1 „Gefällt mir“

Bin gestern noch auf diesen Post gestoßen: SD Card random long write times - ESP32 Forum. Da schreibt einer:

SD cards can be really slow and high-latency, especially if you’re only writing small blocks at a time. It’s the nature of the beast, unfortunately, and it varies from SD-card to SD-card. Has something to do witht he fact that the SD’s internal blocksize and erase-size may not be the same as the sector size the SD-card-interface is using, so it sometimes needs time to do something like read-modify-erase-write cycles, or internal wear leveling cleanups. Suggest decoupling the SD-card writing from the collection task and putting a buffer in between. Furthermore, writing larger buffers (4K or multiples thereof probably will work well) at a time can also speed things up a bit.

Einen 4k großen Puffer haben wir auf jeden Fall. Die Datenmenge, die en bloc jeweils geschrieben wird, schwankt ziemlich stark. Üblicherweise ist sie vierstellig, aber es passiert auch manchmal, dass z.B. nur 2 Bytes geschrieben werden. Vielleicht ist es noch ein Ansatz dafür zu sorgen, dass eine gewisse Schreibgröße (z.B. 1k vielleicht) nicht unterschritten wird.

Auf jeden Fall ist die ESP32-Behandlung hier irgendwie buggy.

Klingt ja interessant. Meint er jetzt einen großen Buffer oder direkt 4K in einem Block schreiben? Eine konstante Schreibgröße würde ja generell Sinn machen. Mir war gar nicht klar, dass es aktuell nicht so ist. Bei den delays müsste man ja auch deutlich länger warten nach einem Fehler. >= 500 ms. Das File-Objekt hat keinen „ready-status“, oder? So dass man quasi prüfen kann, ob der vorherige Schreibvorgang abgeschlossen ist?

Da ich nicht weiß, wie die Dateiübertragung funktioniert, kann ich das nicht beurteilen, aber hilft euch das vielleicht auch irgendwie weiter?

Hi, that is interesting. I don’t think I use the sdmmc, but rather the more basic calls (I think) fseek and fwrite.
I noticed a significant bottleneck when trying to write from psram → sd using the fwrite, which I think went two-times over the spi bus, and I assumed it was 512 bytes blocks starting and stopping, slowing things down.
I switched to a memcpy from psram to regular ram of 32kb blocks, and then fwrite to sd with a 32k block. It dramatically increased the thoughput.

Nächster Kommentar dazu:

fwrite calls sdmmc under the hood, so you are likely executing huge numbers of 512 byte writes, allocating and then deallocating. You are right in transferring to RAM as a way stop between the SD card and PSRAM, since DMA can speed data transfer between SD and RAM or PSRAM and RAM, but not directly between PSRAM and SD card.

Hab mir die Funktion gerade mal angeschaut. Aktuell warten wir ja einfach 100ms auf Daten. Vielleicht könnte man mit
xRingbufferReceiveUpTo
versuchen mind. 1k zu lesen. Oder länger auf Daten warten.

Die „write-delays“ würden aber vermutlich bleiben.

@Joe 32k zu allokieren ist halt schon ein Problem. Das geht beim ESPuino eigentlich nur direkt nach dem Start. Und wenn man das gemacht hat und jmd. auf die Idee kommt, parallel noch Musik abzuspielen, dann knallt es, weil es nicht genügend Heap en-bloc gibt. PSRAM macht, wie da steht, keinen Sinn, da es ja selbst nur mit SPI angebunden ist.

@Christian Was es gibt ist die Methode xRingbufferReceiveUpTo(). Aber wenn man da 4k schreiben will, dann muss man natürlich den Ringpuffer größer als 4k machen. Und man muss vor dem Aufruf von xRingbufferReceiveUpTo() vermutlich xRingbufferGetCurFreeSize() aufrufen, damit man weiß, ob auch >=4k gerade im Ringpuffer drin sind.

Oh, ich sehe gerade, dass du es selbst schon entdeckt hast :slight_smile:

Quelle: FreeRTOS Additions - ESP32 - — ESP-IDF Programming Guide latest documentation

Möchte den Thread hier nochmal aufgreifen.
Alle Ansätze, die Transfer-Probleme in den Griff zu bekommen, sind bisher gescheitert.

Dazu zählt auch das Schreiben von Blöclen, die 4k groß sind.

Es muss daher davon abgeraten werden, die SD-Karte per SPI anzubinden. Lieber stattdessen SDMMC benutzen. Da gibt es das Problem nicht, man braucht einen GPIO weniger und wesentlich schneller ist es auch.