Bestimmte MP3s brechen ab

Hallo zusammen,

wie schon im DEV-Branch Thread erwähnt, habe ich meine Box auf den neuesten MAster-Stand aktualisiert, da ein paar MP3s nicht gingen. Nach dieser Aktion gingen die meisten der bis dahin problematischen MP3s. Ehrlich gesagt verstehe ich nicht ganz, wie das überhaupt passiert ist, hatte ich bisher noch nicht, an meinem Prozess zum Import hat sich im Prinzip auch nichts geändert (Import mithilfe von Apple Music, Transfer per FileZilla). Es ist also eine Hörspiel-CD, die sich nicht abspielen lässt. Wenn man die Karte auflegt, kommt kein Ton. Der Neoring zeigt Fortschritt (etwas 4-5 LEDs) und springt dann wieder in den Idle-State. Hier mal das Log:

I [92] Maximale Inaktivitätszeit wurde aus NVS geladen: 22 Minuten
D [143] RFID-Tags koennen jetzt gescannt werden...
N [144] Port-expander gefunden
N [146] Interrupt für Port-Expander aktiviert
I [147] Zyklus für Batteriemessung fuer Neopixel-Anzeige aus NVS geladen: 10 Minuten
I [159] Unterer Spannungslevel (Batterie) fuer Neopixel-Anzeige aus NVS geladen: 3.00V
I [160] Oberer Spannungslevel (Batterie) fuer Neopixel-Anzeige aus NVS geladen: 3.30V
I [172] Spannungslevel (Batterie) fuer Niedrig-Warnung via Neopixel aus NVS geladen: 3.00V
I [184] Spannungslevel (Batterie) fuer Kritisch-Warnung via Neopixel aus NVS geladen: 3.10V
I [185] Initiale Lautstärke wurde aus NVS geladen: 3
I [196] Maximale Lautstärke für Lautsprecher wurde aus NVS geladen: 10
I [196] Maximale Lautstärke für Kopfhörer wurde aus NVS geladen: 1
N [206] Lautsprecher eingeschaltet
I [207] Maximale Lautstärke wurde gesetzt auf: 10
I [260] Initiale LED-Helligkeit wurde aus NVS geladen: 16
I [260] LED-Helligkeit für Nachtmodus wurde aus NVS geladen: 1
N [327] Software-revision: 20231125-1-DEV
N [328] Git-revision: 556d1f4-dirty
N [328] Arduino version: 2.0.11
N [338] ESP-IDF version: 4.4.5
N [338] Wakeup was not caused by deepsleep: 0
N [338] Versuche SD-Karte im SD_MMC-Modus (1 Bit) zu mounten...
D [349] SD card type: SDHC
N [349] SD-Kartengröße / freier Speicherplatz: 61120 MB / 58684 MB
I [360] FTP-User wurde aus NVS geladen: esp32
I [361] FTP-Passwort wurde aus NVS geladen: esp32
D [469] RFID-Tags koennen jetzt gescannt werden...
I [471] Hostname aus NVS geladen: luki
N [473] SSID 0 von NVS geladen: aLANbert
N [673] Versuche mit WLAN 'aLANbert' zu verbinden...
D [724] Freier Heap-Speicher nach Setup-Routine: 110964
D [724] PSRAM: 4191947 bytes
D [725] Flash-size: 16777216 bytes
D [725] Datum/Uhrzeit (Interne RTC): 26.11.2023, 12:02:42
N [1457] Verbunden mit WLAN 'aLANbert' (Signalstärke: -69 dBm, Kanal: 6, MAC-Adresse: 44:4E:6D:BC:B6:AA)
N [1457] Aktuelle IP: 192.168.178.135
N [1468] Synchronisiere Uhrzeit via NTP...
N [1481] mDNS gestartet: http://luki.local
N [1487] HTTP-Server gestartet.
D [4006] logo request
D [4100] ws[/ws][1] connect
N [6281] RFID-Karte erkannt: 04-53-98-01 
I [6282] RFID-Karte empfangen: 004083152001
D [6299] Freier Speicher: 76708 Bytes
N [6299] Playlist-Generierung
N [6301] Datum/Uhrzeit empfangen von NTP-Server: 26.11.2023, 11:57:12
N [6313] Anzahl gültiger Files/Webstreams: 13
N [6314] Modus: Hoerspiel in Endlosschleife
N [6322] Neue Playlist mit 13 Titel(n) empfangen
D [6322] Free heap: 77004
I [6381] info        : PSRAM found, inputBufferSize: 638965 bytes
I [6382] info        : buffers freed, free Heap: 77004 bytes
I [6382] info        : Reading file: "/Hörbücher/Meine Freundin Conni/Conni Und Das Hausboot-Abenteuer/01 Conni Und Das Hausboot-Abenteuer. Hörspiel. Track 01.mp3"
I [6435] info        : MP3Decoder has been initialized, free Heap: 49160 bytes , free stack 2952 DWORDs
N [6439] '/Hörbücher/Meine Freundin Conni/Conni Und Das Hausboot-Abenteuer/01 Conni Und Das Hausboot-Abenteuer. Hörspiel. Track 01.mp3' wird abgespielt (1 von 13)
I [6457] info        : Content-Length: 2019031
I [6458] info        : ID3 framesSize: 538933
I [6458] info        : ID3 version: 2.2
I [6475] id3data     : Title/Songname/Content description: ��C
I [6483] id3data     : Track number/Position in set: 1/13
D [6489] no cover image for SD-card audio
I [6497] id3data     : Part of a set: 1/1
I [6505] id3data     : Year: 2022
I [6513] id3data     : Content type: Spoken & Audio
I [6528] id3data     : Encoded by: Music 1.3.6.14
I [8920] id3data     : Lead artist(s)/Lead performer(s)/Soloist(s)/Performing group: Conni
I [8920] id3data     : Album/Movie/Show title: Conni Und Das Hausboot-Abenteuer
I [10006] Aktuelle Batteriespannung: 3.17 V
I [10033] Aktuelle Batterieladung: 55.65 %

Es ist ein Hörbuch mit 13 Kapiteln, habe auch versucht ein paar andere vom Hörbuch per WebGUI abzuspielen, gleiches Verhalten. Ich kann in dem Log jetzt keine Fehlermeldung o.ä. erkennen. Das einzig auffällige sind die merkwürdigen Zeichen beim id3tag.

Hatte auch versucht, den CD-Import mit geringerer Bitrate (Reduktion von 160 auf 128) abzuspielen, gleiches Verhalten.

Hat jemand eine Idee, was hier das Problem sein könnte, oder zumindest, wie ich dem auf die Schliche kommen könnte?

Schöne Grüße
Dirk

Sind die komische Zeichen denn wirklich da?

Was sagt z.B. https://www.mp3tag.de/ ?

Kannst die damit dann ja mal löschen…

Es sieht für mich jetzt nicht direkt so aus, als ob die Zeichen da sind. So sieht das in mp3tag aus:

image

1 „Gefällt mir“

Hallo Dirk,

die Audiobibliothek gibt uns die ID3 Metainformationen wie Titel/Album zurück. Leider ist das mächtig kompliziert & es gibt auch noch verschiedene Enkodierungen. Ich hatte vor kurzem dazu einen Bug berichtet & @Wolle hat das auch superschnell korrigiert. Wenn Du auf die neueste Audiobibliothek wechselst, tritt das Problem dann noch auf? Also in Platform.ini eintragen:

https://github.com/schreibfaul1/ESP32-audioI2S.git#5a1bd13 ;ID3 bugfix, latest commit
; https://github.com/schreibfaul1/ESP32-audioI2S.git#2ef8cf7;

VG Dirk

Hi Dirk,

habe den aktuellen DEV-Branch genutzt, da ist diese Version von ESP32-audioI2S schon drin, ist also die, bei der bei diesem MP3 das Problem auftritt. Kann das im Log auftauchende fehlerhafte id3tag denn die Ursache dafür sein, dass das MP3 nicht abgespielt wird?

Schöne Grüße
Dirk

Hallo, hab auch Probleme mit den MP3 Dateien, die mit dem alten Ardino1 Master ohne Probleme liefen. Mit dem ändern der Cover lassen sich die meisten wieder abspielen.

Es tauchten aber jetzt die Tage MP3 Dateien auf, die kein Cover im ID3 haben, und auch nicht abgespielt werden.

Bei mir spielt die MP3 Datei auch nicht ab: Der Audiostart-Header wird anscheinend überlesen und die Audio-Bibliothek rauscht bis zum Ende der Datei durch. Auch das Ereignis für’s Coverbild kommt nicht an:

N [21055] Neue Playlist mit 1 Titel(n) empfangen
D [21066] Free heap: 85492
I [21138] info        : PSRAM found, inputBufferSize: 638965 bytes
I [21138] info        : buffers freed, free Heap: 89936 bytes
I [21139] info        : Reading file: "/01 Conni Und Das Hausboot-Abenteuer. Hörspiel. Track 01.mp3"
I [21207] info        : MP3Decoder has been initialized, free Heap: 62156 bytes , free stack 3252 DWORDs
N [21212] '/01 Conni Und Das Hausboot-Abenteuer. Hörspiel. Track 01.mp3' wird abgespielt (1 von 1)
I [21262] info        : Content-Length: 2086715
I [21262] info        : ID3 framesSize: 902508
I [21262] info        : ID3 version: 2.3
D [21283] no cover image for SD-card audio
I [21322] info        : ID3 normal frames
I [21480] id3data     : Album: Julia Boehme: Conni Und Das Hausboot-Abenteuer
I [21638] id3data     : Artist: Julia Boehme: Conni Und Das Hausboot-Abenteuer
I [21795] id3data     : Band: Conni
I [22732] id3data     : PartOfSet: 1/1
I [22789] id3data     : ContentType: Spoken & Audio
I [22793] id3data     : Title: Conni Und Das Hausboot-Abenteuer. Hörspiel. Track 01
I [22802] id3data     : Track: 1/13
I [22806] id3data     : Year: 2022
[ 23725][E][Audio.cpp:2702] processLocalFile(): audioHeader reading timeout

Siehe letzte Zeile im Log.
Evt. kannst Du dazu direkt in der Audiobibliothek ein Issue aufmachen & evt. auch die Datei mit dranhängen.

Tatsächlich, bei mir löst der Timeout auch aus. Ich kann nicht allein den Zeiger innerhlb der mp3 Datei weitersetzen, die 800KB die das Bild benötigt müssen zusätzlich im Audiobuffer „vernichtet“ werden.
Der Vorgang läuft nun etwa 1s schneller ab, das sollte jetzt jetzt okay sein.

10 „Gefällt mir“

Wahnsinn für den schnellen Fix, gebt Wolle alle Herzen:

Ich habe die platformio.ini angepasst:

https://github.com/schreibfaul1/ESP32-audioI2S.git#9d1759e

Neu gebaut und die Firmware aufgespielt. Irgendwie hat sich bei mir das Verhalten noch nicht geändert, Fehlerbild ist noch identisch.

Habe ich irgendwas vergessen?

Es scheint aber schon das Problem mit dem Cover zu sein. Habe nun testweise mal ein kleines Coverbild verwendet, da funktioniert es.

Die Änderungen sind jetzt eingecheckt, Software-revision: 20231129-1-DEV

Außerdem wird das Coverbild schneller im Webplayer angezeigt (weniger Chunks).
Bei Deinem MP3 sinkt die Ladezeit von 8 auf ca. 1 Sekunde.

@albert0815: Führe zur Sicherheit ein „Full clean“ durch. Dann werden alle Bibliotheken neu geladen.

Edit 29.11.2023:
Ich hatte noch eine nicht abspielbare MP3 gefunden, die läuft jetzt auch.

Vlt ist das was für eine FAQ/Erste Hilfe Seite?

Checkliste mp3s:
-Keine Umlaute/Sonderzeichen im Verzeichnis/Namen/ID3Tag (ich weiß geht, aber besser ist ohne :wink: )
-keine Cover Bilder größer x in der mp3
-Encoding bei ID3 Tag = y
-…

Auch am besten mit Verweis auf SW mit der man das prüfen/ändern kann
(Keine Ahnung kann https://www.mp3tag.de/ das Encoding ändern, wenn das wichtig ist)

2 „Gefällt mir“

Ich habe mit der aktuellen audioi2s master auch massive Probleme: WAV Dateien stottern total und manche MP3 spielen gar nicht mehr.

Ich bin noch am schauen, an welcher Revision es liegt, aber es wird je nach commit mal besser und wieder schlechter…

3 „Gefällt mir“

Ich habe jetzt auch stottern bei WAV-Dateien und seltener bei einigen MP3s.
Es scheint mit der aktuellen Audioi2S zusammenzuhängen.

Habe diese Dinge probiert ohne Erfolg:

  • Trackfortschritt auskommentiert
  • Websocket Benachtigungen komplett ausgeschaltet
  • Mit Arduino 2.0.14 kompilert
  • Mit Compileroptimierung CONFIG_COMPILER_OPTIMIZATION_PERF anstelle CONFIG_COMPILER_OPTIMIZATION_SIZE

Bei der Durchsicht konnte ich nichts feststellen was wir irgendwie jetzt langsamer machen. Der Audiotask bekommt weiterhin die Rechenzeit wie zuvor.
Habe dazu erstmal keine weitere Idee, Ihr?

Habe heute ähnliches probiert. Mit einer sehr alten audioi2s Version und der aktuellen ESPuino dev hatte ich zwar sehr gelegentliches stottern, aber kaum merklich. (Alte ESPuino und alte i2s lief komplett ohne stottern).

Das Problem liegt meiner Ansicht nach auch schon seit Monaten vor.

Ich habe die Core-Auslastung überprüft, beide Cores haben noch Zeit für IDLE, also sollte das dekodieren nicht grundsätzlich zu langsam sein. Stack vergrößern hat auch nichts gebracht.

Es könnte vielleicht daran liegen, dass große WAV Dateien zu langsam von der SD Karts gelesen werden, ich konnte das aber noch nicht überprüfen.

@tueddy konntest du einen commit identifizieren mit dem WAV noch ordentlich spielt?

Bin einmal zurück auf den alten ESPuino master Arduino1, dort stottern die WAV-Dateien genauso! Dann:

  • Zurück auf das AudioI2S release 3.0.0 vom Februar 2023, damit schon besser aber immer noch leichtes Schrabbeln.

  • Noch weiter zurück auf AudioI2S Version 2.0.6 vom November 2022 und siehe da: Kein Stottern oder Schrabbeln, perfekter Sound!

  • Dann diese Version mit dem aktuellen DEV kompiliert (VOLUMECURVE auskommentiert): Die WAV Dateien spielen einwandfrei ab!

Also letzte lauffähige Version 2.0.6 ed150bd , das Problem schlummert schon seit einem Jahr vor sich hin und keiner hat es bemerkt…

Probleme mit SD sind ausgeschlossen, ich habe es Alles auf der gleichen Hardware getestet (SD-MMC).

Wenn man schnelle Ohren hat kann man das Schrabbeln auch mit @wolle’s 2 Sekunden Testdatei hören.

1 „Gefällt mir“

Interessant, mein letzter Stand war vor ca. einem Jahr - ich kann die aktuelle Version nicht allzu oft aktualisieren. Da lief alles, ein paar commits nach dem genannten (GitHub - SZenglein/ESP32-audioI2S: Play mp3 files from SD via I2S)

Ich finde das Stottern auch in der Testdatei ziemlich auffällig.

Ich weiß nicht ob es was aussagt, aber weil die Auslastung <60% war, hab ich testweise mal die Frequenz runter gesetzt. Wurde auf jeden Fall viel schlimmer :smiley: .

Irgendwo ein delay zu viel?

Hallo zusammen,
Bei der Optimierung der Playlist Generierung habe ich auch mindesten 2 mp3 gefunden, bei denen die Wiedergabe nicht funktioniert. Zusätzlich kommt bei mir bei den nächsten Versuch eine Playliste zu generieren (bzw dem nächsten malloc / calloc / free) zu einem Heap corruption (Für Fehlersuche habe ich Comprehensive Heap Poisoning aktiv).

Absturz:

N [278675] Neue Playlist mit 36 Titel(n) empfangen
D [278675] Free heap: 63256
I [278692] info        : buffers freed, free Heap: 86624 bytes
I [278692] info        : Reading file: "/Test/Alestorm/Alestorm - Back Through Time - 05 - Buckfast Powersmash.mp3"
I [278746] info        : MP3Decoder has been initialized, free Heap: 58832 bytes , free stack 2876 DWORDs
N [278747] '/Test/Alestorm/Alestorm - Back Through Time - 05 - Buckfast Powersmash.mp3' wird abgespielt (1 von 36)
I [278766] info        : Content-Length: 6915502
I [278766] info        : ID3 framesSize: 781824
I [278766] info        : ID3 version: 2.3
I [278783] info        : ID3 normal frames
I [278815] id3data     : Album: Back Through Time
I [278847] id3data     : Artist: Alestorm
I [278878] id3data     : ContentType: Folk/power Metal
I [278909] id3data     : Title: Buckfast Powersmash
I [278941] id3data     : Track: 5/13
I [278973] id3data     : Year: 2011
[281261][E][Audio.cpp:2708] processLocalFile(): audioHeader reading timeout
N [285517] RFID-Karte erkannt: a2-67-0c-1d 
I [285517] RFID-Karte empfangen: 162103012029
D [285528] Freier Speicher: 58604 Bytes
N [285528] Playlist-Generierung
N [285548] Anzahl gültiger Files/Webstreams: 36
N [285548] Modus: Spiele alle Tracks (zufällig sortiert) des Ordners '/Test/Alestorm'
I [285570] info        : Closing audio file
CORRUPT HEAP: Bad head at 0x3f8b0070. Expected 0xabba1234 got 0x3bcf3925

assert failed: multi_heap_free IDF\components\heap\multi_heap_poisoning.c:259 (head != NULL)


Backtrace: 0x40084f69:0x3ffda170 0x40097759:0x3ffda190 0x4009c269:0x3ffda1b0 0x4009be31:0x3ffda2e0 0x40085ed9:0x3ffda300 0x4009c299:0x3ffda320 0x400d3935:0x3ffda340

  #0  0x40084f69:0x3ffda170 in panic_abort at C:\Users\hel83wi\.platformio\packages\framework-espidf\components\esp_system/panic.c:408
  #1  0x40097759:0x3ffda190 in esp_system_abort at C:\Users\hel83wi\.platformio\packages\framework-espidf\components\esp_system/esp_system.c:137
  #2  0x4009c269:0x3ffda1b0 in __assert_func at C:\Users\hel83wi\.platformio\packages\framework-espidf\components\newlib/assert.c:85
  #3  0x4009be31:0x3ffda2e0 in multi_heap_free at C:\Users\hel83wi\.platformio\packages\framework-espidf\components\heap/multi_heap_poisoning.c:259 (discriminator 1)
  #4  0x40085ed9:0x3ffda300 in heap_caps_free at C:\Users\hel83wi\.platformio\packages\framework-espidf\components\heap/heap_caps.c:382
  #5  0x4009c299:0x3ffda320 in free at C:\Users\hel83wi\.platformio\packages\framework-espidf\components\newlib/heap.c:39
  #6  0x400d3935:0x3ffda340 in freePlaylist(std::vector<char*, std::allocator<char*> >*) at src/Playlist.h:14
      (inlined by) AudioPlayer_Task at src/AudioPlayer.cpp:414

Die Dateien kann ich leider nicht bereit stellen (Copyright), aber ich werde den Abend mal versuchen den Fehler mit einer Copyright freien MP3 nachzustellen. Ich nehme an, dass es mit der in der MP3 eingebetteten Bild zusammenhängt (der ist knapp 800kB) groß. Wenn es hilft, kann ich auch ein Coredump ziehen und zusammen mit der ELF bereit stellen.

Was auch mir aufgefallen ist, dass jeder Fehlerhafte mp3 mit [E][Audio.cpp:2708] processLocalFile(): audioHeader reading timeout reagiert (Anzeige ist dabei aber unterschiedlich, eine mp3 zeigt 0% an, eine andere läuft 0–>100% durch).

Ein zweiter Test, der bei mir auf dem Plan steht ist es ein minimales Beispiel zu machen (also ganz ohne ESPuino drum herum) um den Fehler auf den AudioI2S einzugrenzen. Ich weiß leider nur nicht, ob ich heute Abend noch dazu komme.

1 „Gefällt mir“

Dieser Fehler wurde einigen Tagen gelöst. Tritt es bei Dir mit der aktuellen Dev-Version noch auf?

Zum ersten Mal ist es bei der Branch für die Playlist Optimierung wirklich schlagend geworden und stabil reproduzierbar (ein Grund wieso ich auch einen zusätzlichen Fehler in meinem Code vermute):

Er tritt aber auch mit meinem Test-Rig auf, dieser läuft auf der aktuellen dev (hat den nullptr fix enthalten). Leider nicht so schön reproduzierbar (wobei ich noch nicht dahinter gekommen bin, wieso dem so ist).