Knacksen bei opus files (insb. 48kHz) / vormals auch wav files

sfields · 21. Dezember 2023 um 16:33

Hallo zusammen,

ich habe einige Audiofiles von derTube und zwar im Format opus, 48000 Hz, stereo, fltp. Das ist das Format, das man mittels -f 251 erhält, und das ist üblicherweise die höchste Qualität.

Leider werden die files nur mit audio-dropouts/crackling sound/Knacksen wiedergegeben.

Ich habe jetzt mal Wolles example File ausprobiert, da werden die gleichen Dateien einwandfrei und in sehr guter Qualität wiedergegeben.

Es liegt also nicht an der verwendeten Audio-Bibliothek.

Vor wenigen Wochen habe ich diese Files mal testweise in wav konvertiert, da hat es ebenfalls geknackst, aber etwas weniger als in opus. Heute habe ich es nochmal probiert, die wav Files knacksen nicht mehr und die opus files immer noch, aber weniger als noch vor wenigen Wochen.

Vielleicht liegt die Verbesserung an

Ich habe hier noch etwas an den Zeiten experimentiert, vielleicht ist es noch etwas besser geworden, ganz weg bekomme ich das Knacksen nicht. Weiß jemand, woran das Knacksen liegt?

Kann es daran liegen, dass die Auslastung ziemlich hoch ist:
mp3play 109844954 83%

Aber wieso schafft es Wolles lib ohne Probleme? Läuft neben dem mp3play noch was auf demselben Core?

Da ich nicht weiß, ob man darf, stelle ich die Files mal nicht hier rein, bei Interesse PN.

Vielen Dank für jede Hilfe.

tueddy · 21. Dezember 2023 um 20:31

Ja eine Menge: Webserver, RFID, LED usw. Task-Prioriät (gelb) & Core(blau) kannst Du mit http://espuino.local/stats live anschauen:

Wir haben aktuell Probleme, der Core scheint ausgelastet / am Limit zu sein.
Eine wirklich gute Lösung wurde noch nicht gefunden. Weil wenn etwas geändert wird z.B. Task-Priorität oder Core funktioniert z.B. der Webserver nicht mehr zuverlässig.
Wenn Du das mit der Audiodatei gut nachvollziehen kannst dann sende sie mir doch mal als PM zu.

sfields · 21. Dezember 2023 um 21:23

Danke, jetzt wird mir auch die 1. Tabelle klarer.

Der espuino macht viel mehr als die Beispieldatei von Wolle, da ist es kein Wunder, dass er irgendwann an die Grenzen kommt, wo Wolles Lib noch ohne Probleme spielt. Bei anderen Dateiformaten war es ja in der letzten Zeit auch manchmal grenzwertig, wobei das ja verbessert werden konnten, so dass die jetzt wieder ohne Knacksen laufen. Die 48khz opus Files scheinen ihn dann gerade etwas zu viel zu beanspruchen.

Wäre natürlich cool, wenn es irgendwann ohne Knacksen läuft, zumindest wenn er (außer dem Abspielen) im Leerlauf ist (kein Webzugriff, usw).

SZenglein · 21. Dezember 2023 um 22:12

Sollte nicht Audio als mit Abstand wichtigstes feature die höchste Priorität bekommen? Bei Audio hört man jedes Ruckeln und jede Verzögerung extrem.
Instabil darf natürlich kein anderer Task laufen, aber dann kann der Webserver vielleicht auf den anderen Core?

Joe91 · 22. Dezember 2023 um 20:47

Es gibt heir gerade sehr viele Abhängigkeiten, die dieses Audioverhalten verstärken / verbessern. Auch die Code-Size spielt schienbar eine Rolle. So verlockend die Lösung ist einfach mehr Zeug auf Core 0 zu schieben (z.B. auch über DCONFIG_ASYNC_TCP_RUNNING_CORE=0 im Platformio.ini) sollten wir die Ursache zunächst noch identifizieren.
Auch das separieren der Audio-Loop bringt hier Verbesserung, die Ursache muss aber was anderes sein…

tueddy · 23. Dezember 2023 um 19:12

@sfields hilft es hier die Audio-Bibliothek zu aktualisieren?

lib_deps =
	https://github.com/schreibfaul1/ESP32-audioI2S.git#8ba3208
    ;https://github.com/schreibfaul1/ESP32-audioI2S.git#961b320 - unser aktueller DEV

Damit habe ich einen besseren Klang & keine Aussetzer mehr. Die Verbesserung gilt anscheinend nur für das OPUS-Format.

sfields · 23. Dezember 2023 um 20:41

Super! Das Knacken ist weg.

Ist das jetzt absoluter Zufall? Egal, jedenfalls sehr schön. Danke.

tueddy · 23. Dezember 2023 um 20:59

Das ist kein Zufall, der Autor liest hier auch immer mal mit & verbessert die Audio-Bibliothek ständig. Also bedankt Euch bei @wolle
Der Audiotask läuft jetzt wohl etwas performanter & bremst unsere anderen Tasks weniger aus. Die Aktualisierung ist jetzt im DEV-Branch verfügbar.

compactflash · 26. Dezember 2023 um 10:44

Leider hilft das bei mir nicht. Die DEV vom 4.12.2023 ist die letzte die bei mir läuft, bei allen nachfolgenden habe ich wieder keinen Webzugriff.
@Wolle Hast du keine Lite-Version deiner Lib? MP3 in 128 und vielleicht ein paar weitere Formate für Radiostreams würden doch reichen. Viele Features sind für Kinder nicht relevant und wenn es das Verhalten der Box so stark beeinflusst sollte man es weglassen. Es handelt sich um eine Kinderbox, kein Spielzeug für Daddy.
Schön wenn man alles machen kann, aber das ist dann das falsche Projekt. Wer mehr will sollte sich das Webradio von @Wolle ansehen.

JHB · 26. Dezember 2023 um 12:15

sehe ich nicht so.

Das ist gerade der derzeitige Vorteil der Lib, ich kann da reinwerfen was ich will (in gewissen Grenzen) und es wird abgespielt
Dein Vorschlag würde alle dazu zwingen ihre Dateien in Format x oder y bereitzustellen…

tueddy · 26. Dezember 2023 um 12:18

@compactflash Wir aktualisieren die Audio-Bibliothek nicht, damit Papa möglichst viele neue Audioformate zur Verfügung hat, sondern weil viele MP3s vorher nicht abspielbar waren und Fehler wie z.B. die Darstellung der Coverbilder behoben wurden.

Leider gibt es derzeit noch ungelöste Probleme wie teils Knackser beim Abspielen, nicht reagierendes Webinterface und zu wenig Speicher ohne PSRAM (Lolin D32 ohne Pro). Diese betreffen hauptsächlich den DEV-Zweig, der genau dafür da ist, solche Probleme zu lösen. Ist halt auch schwierig einzugrenzen da wir begrenzte Debug-Möglichkeiten haben. Trotzdem sehe ich da den Weg nach vorn & nicht zurück.

Wolle · 27. Dezember 2023 um 18:41

@compactflash hat Recht, die Audiobibliothek ist in den letzten Jahren gewachsen und nicht alle Funktionen werden von euch genutzt (HLS Streams, Vorbis…). Unbenutzte Routinen sind immer inaktiv sind und verschwenden keine Zeit.
Das Problem der Knackgeräusche könnte im DMA liegen. Lt. Espressif ist die DMA Größe: dma_buffer_size = dma_frame_num * slot_num * slot_bit_width / 8, das sind (512 * 16 * 16 / 8) 16KB. Bei 44,1KHz, stereo und 16 Bit/Kanal reicht das für weniger als 0,093s. Der audio.loop() muss so schnell sein, und Verzögerungen in der Größenordnung nie auftreten, damit der DMA Speicher nicht leer läuft.

tueddy · 27. Dezember 2023 um 20:11

@wolle Vielen Dank für die Erklärungen!

Dann dürften wir beim Abspielen von Audio in der Loop auch kein vTaskDelay aufrufen. Hatte das schon mal testweise rausgenommen & konnte in einem Grenzfall das Knacken beheben:

github.com

biologist79/ESPuino/blob/212f941645f2cb62be2aa108991102eaaeb5206a/src/AudioPlayer.cpp#L861


      
          				gPlayProperties.trackFinished = true;
          				playbackTimeoutStart = millis();
          			}
          		} else {
          			// we are idle, update timeout so that we do not get a spurious error when launching into a playlist
          			playbackTimeoutStart = millis();
          		}
          		if ((System_GetOperationMode() == OPMODE_BLUETOOTH_SOURCE) && audio->isRunning()) {
          			// do not delay here, audio task is time critical in BT-Source mode
          		} else {
          			vTaskDelay(portTICK_PERIOD_MS * 1);
          		}
          		// esp_task_wdt_reset(); // Don't forget to feed the dog!
          
          #ifdef DONT_ACCEPT_SAME_RFID_TWICE_ENABLE
          		static uint8_t resetOnNextIdle = false;
          		if (gPlayProperties.playlistFinished || gPlayProperties.playMode == NO_PLAYLIST) {
          			if (resetOnNextIdle) {
          				Rfid_ResetOldRfid();
          				resetOnNextIdle = false;
          			}

Negative Auswirkungen konnte ich nicht feststellen, Neopixel, Web und die anderen Funktionen laufen wie gehabt. Was meint Ihr?

Joe91 · 27. Dezember 2023 um 21:40

Wir reden hier laut @Wolle von 93 ms. Ich würde das delay vom 1 ms da auf jeden Fall drin lassen wollen solange es möglich ist um nicht in den Animation der LEDs hängen zu bleiben oder nicht mehr auf Buttons zu reagieren…
Aber vielleicht macht es auch keinen großen Unterschied.

Wenn diese 1ms ein Problem macht müssen wir meiner Meinung nach wo anders suchen…

Wenn das wirklich ein Problem ist wäre es vielleicht besser die Audio-loop komplett zu separieren, dass die ganzen anderen checks gar nicht mehr in dem task laufen. Die könnten größeren Einfluss als die 1 ms haben…

biologist · 27. Dezember 2023 um 21:43

Ich habe auf die Schnelle mal eine Funktion runtergeschrieben, die Statistiken ausgibt:

gist.github.com

https://gist.github.com/biologist79/72e72e1ca4ed6675c973d4946c324da9

gistfile1.txt

void AudioPlayer_LoopStats(uint16_t statsIterationCount) {
	static uint32_t iterationStartTimestamp = 0;
	static uint32_t loopCount = 0;
	static uint32_t minLoopDuration = 0;
	static uint32_t maxLoopDuration = 0;
	static uint32_t avgLoopDuration = 0;
	static uint32_t startTimestampOfLoop = 0;
	static uint32_t currentTimestamp = millis(); // Only get millis once
	static uint32_t currentLoopDuration = 0;

This file has been truncated. show original

Die kann man einfach z.B. so bei Zeile 245 in AudioPlayer.cpp integrieren und ganz oben im Loop unterhalb von for (;;) integrieren, indem man das Ganze z.B. aufruft mit AudioPlayer_LoopStats(100);.

Die 100 ist die Anzahl der Loops, die pro Iteration analysiert werden. Ausgegeben werden minTime, maxTime, avgTime und loopCount.

Das sieht im Leerlauf dann z.B. so aus:

D [12935] LoopStats: min: 11 max: 23 avg: 11 loops: 1200
D [14035] LoopStats: min: 11 max: 11 avg: 11 loops: 1300
D [15135] LoopStats: min: 11 max: 11 avg: 11 loops: 1400
D [16235] LoopStats: min: 11 max: 11 avg: 11 loops: 1500

Mit Webradio (192 kBit/s via http):

D [61061] LoopStats: min: 1 max: 24 avg: 5 loops: 6300
D [61629] LoopStats: min: 1 max: 25 avg: 5 loops: 6400
D [62198] LoopStats: min: 1 max: 25 avg: 5 loops: 6500

Mit mp3 (320 kBit/s):

D [538430] LoopStats: min: 1 max: 23 avg: 6 loops: 82800
D [539131] LoopStats: min: 1 max: 23 avg: 7 loops: 82900
D [539781] LoopStats: min: 1 max: 19 avg: 6 loops: 83000
D [540464] LoopStats: min: 1 max: 26 avg: 6 loops: 83100
D [541116] LoopStats: min: 1 max: 20 avg: 6 loops: 83200

Ich hoffe mal, dass mir dabei kein Denkfehler unterlaufen ist - vielleicht aber doch . Die Variablen kann man sicherlich auch besser benennen. Aber grundsätzlich wirkt es erstmal plausibel und wenn man verschiedenen Kram macht, dann erhöht sich die Zeit teilweise. Also bis 44 ms habe ich gesehen.

Mit min kann man leider nicht viel anfangen. Man sieht nur, dass im Leerlauf ein 10ms-Delay greift, damit der Audiotask nicht alles Andere „platt macht“.

biologist · 27. Dezember 2023 um 22:07

Also was man auf jeden Fall sehen kann: Das Webinterface alleine ist kein Problem (nur das initiale Öffnen erzeugt einen Peak), aber wenn man dort den Tab „Steuerung“ öffnet, dann hat das deutlichen Impact:

Webradio ohne Webinterface:

D [890189] LoopStats: min: 1 max: 24 avg: 6 loops: 137600
D [890805] LoopStats: min: 1 max: 25 avg: 6 loops: 137700
D [891394] LoopStats: min: 1 max: 25 avg: 5 loops: 137800
D [891965] LoopStats: min: 1 max: 25 avg: 5 loops: 137900
D [892536] LoopStats: min: 1 max: 19 avg: 5 loops: 138000
D [893117] LoopStats: min: 1 max: 23 avg: 5 loops: 138100
D [893693] LoopStats: min: 1 max: 23 avg: 5 loops: 138200

Webradio mit Webinterface:

D [932157] LoopStats: min: 1 max: 25 avg: 5 loops: 144500
D [932735] LoopStats: min: 1 max: 19 avg: 5 loops: 144600
D [933322] LoopStats: min: 1 max: 19 avg: 5 loops: 144700
D [933881] LoopStats: min: 1 max: 24 avg: 5 loops: 144800
D [934450] LoopStats: min: 1 max: 21 avg: 5 loops: 144900
D [935027] LoopStats: min: 1 max: 24 avg: 5 loops: 145000

Webradio mit Webinterface, bei dem der Tab „Steuerung“ geöffnet ist:

D [981998] LoopStats: min: 1 max: 32 avg: 6 loops: 152800
D [982674] LoopStats: min: 1 max: 25 avg: 6 loops: 152900
D [983269] LoopStats: min: 1 max: 19 avg: 5 loops: 153000
D [983982] LoopStats: min: 1 max: 33 avg: 7 loops: 153100
D [984662] LoopStats: min: 1 max: 25 avg: 6 loops: 153200
D [985287] LoopStats: min: 1 max: 24 avg: 6 loops: 153300
D [985962] LoopStats: min: 1 max: 33 avg: 6 loops: 153400
D [986672] LoopStats: min: 1 max: 33 avg: 7 loops: 153500
D [987264] LoopStats: min: 1 max: 25 avg: 5 loops: 153600

tueddy · 27. Dezember 2023 um 22:30

Hatte es Nachbarthread schon geschrieben, es gibt seit gestern einen PR der den Port-Expander Zugriff deutlich beschleunigt. Wenn ich den Code einsetze verschwindet auch das Krackseln. Kann jetzt Zufall sein aber ist für mich plausibel weil weniger Rechenzeit auf Core 1.
@biologist weil Du die Schleife grad laufen hast, verändert sich die Loopzeit zum Guten? Einfach Port.cpp durch diesen Code ersetzen.

biologist · 27. Dezember 2023 um 22:39

Hmm, ja, ich denke das macht es etwas besser. 7 ms als avg-Zeit sind eher selten.
Webradio + Tab Steuerung:

D [207226] LoopStats: min: 1 max: 19 avg: 6 loops: 33400
D [207815] LoopStats: min: 1 max: 23 avg: 5 loops: 33500
D [208504] LoopStats: min: 1 max: 31 avg: 6 loops: 33600
D [209148] LoopStats: min: 1 max: 31 avg: 6 loops: 33700
D [209704] LoopStats: min: 1 max: 22 avg: 5 loops: 33800
D [210257] LoopStats: min: 1 max: 19 avg: 5 loops: 33900
D [210854] LoopStats: min: 1 max: 23 avg: 5 loops: 34000
D [211506] LoopStats: min: 1 max: 24 avg: 6 loops: 34100
D [212158] LoopStats: min: 1 max: 25 avg: 6 loops: 34200
D [212735] LoopStats: min: 1 max: 24 avg: 5 loops: 34300

Das ist jetzt mal SD + 320 kBit/s + Tab Steuerung (hatte ich vorher nicht getestet):

D [297640] LoopStats: min: 1 max: 32 avg: 7 loops: 47500
D [298363] LoopStats: min: 1 max: 34 avg: 7 loops: 47600
D [299096] LoopStats: min: 1 max: 24 avg: 7 loops: 47700
D [299722] LoopStats: min: 1 max: 19 avg: 6 loops: 47800
D [300486] LoopStats: min: 1 max: 32 avg: 7 loops: 47900
D [301233] LoopStats: min: 1 max: 32 avg: 7 loops: 48000
D [301907] LoopStats: min: 1 max: 32 avg: 6 loops: 48100
D [302656] LoopStats: min: 1 max: 28 avg: 7 loops: 48200
D [303403] LoopStats: min: 1 max: 25 avg: 7 loops: 48300
D [304171] LoopStats: min: 1 max: 32 avg: 7 loops: 48400

Nachtrag: Hier nochmal SD + 320 kBit/s + Tab Steuerung mit bisherigem Port.cpp

D [31426] LoopStats: min: 1 max: 32 avg: 7 loops: 3400
D [32169] LoopStats: min: 1 max: 32 avg: 7 loops: 3500
D [32843] LoopStats: min: 1 max: 22 avg: 6 loops: 3600
D [33555] LoopStats: min: 1 max: 33 avg: 7 loops: 3700
D [34303] LoopStats: min: 1 max: 26 avg: 7 loops: 3800
D [34979] LoopStats: min: 1 max: 21 avg: 6 loops: 3900
D [35721] LoopStats: min: 1 max: 33 avg: 7 loops: 4000
D [36506] LoopStats: min: 1 max: 33 avg: 7 loops: 4100

Also bei SD macht’s eher nix. Bei Webradio wohl schon.
Ist aber auch mehr so semi-quantitativ der Vergleich

tueddy · 27. Dezember 2023 um 23:14

Ich bekomme die Verbesserung beim Abspielen von SD, bei Webstreams hatte ich noch nie Kracksler (selten mal HTTP-Dropouts aber das ist ja was anderes).
Die Port-Expander Optimierung halte ich für gelungen & das könnte hier zusätzlich helfen.

Joe91 · 28. Dezember 2023 um 06:31

Der port-expander-PR ist auf jeden Fall sinnvoll, ich glaube aber, dass wir hier an der falschen Stelle unterwegs sind und nur die Auswirkungen bekämpfen.

Um tatsächlich die Performance weiter zu verbessern würde ich folgendes vorschlagen:

weitere Last-reduzierung in der main-loop (langsamer Sachen z.B nur alle 10 / 100 ms ausführen)
einen Task nur für die Audio-Loop (so stellen wir sicher, dass nichts dazwischen funken kann oder verzögert wird)
die Audio-loop ins IRAM packen, so dass wir dort nicht auf den MMU Cache angewiesen sind.

Weitere mögliche Schritte:

Prioritäten und delays sauber aufeinander abstimmen
Core0 optimieren um dort z.B. die LEDs wieder hin zu packen

Gibt es hier weitere Meinungen oder Anregungen?
Natürlich braucht es entsprechende Benchmarks um den Effekt der jeweiligen Änderung beurteilen zu können, hier können wir den Code von oben vielleicht noch bisschen erweitern und mit den Task-Stats kombinieren…