Micropython Startup Zeit auf ESP8266 / ESP32

[Haiko (haiko_kurt)]

Liebe ESP-Fans,

ich baue gerade eine Steuerung, die darauf angewiesen ist, das der ESP 
sehr schnell hochfährt, da mit einem Signal die Stromversorgung 
angeschaltet wird und dann ein anderes Signal (was ca. 100ms 
zeitverzögert kommt) gezählt werden soll. Bei meinen ersten Experimenten 
hat der Code fast zwei Sekunden benötigt, um ausgeführt zu werden. Durch 
Optimierungen konnte ich das auf ca. 300ms (bei einem ESP8266) drücken. 
Ein ESP32 startet naturgemäß schneller. hier lag der Wert deutlich 
niedriger.

Jetzt kommt die erstaunliche Entdeckung: Die Startzeit variiert sehr 
stark und hängt von Kopiervorgängen von Dateien auf den ESP ab. Das 
heißt, wenn ich alle Quellen auf dem ESP lösche und wieder drauf kopiere 
erhöht sich die Startzeit. Aber noch kurioser ist, dass ab einer 
gewissen Anzahl von Kopiervorgängen die Zeit wieder schlagartig auf 
einen kleinen Wert sinkt. Hier die Messwerte für einen ESP32:

MicroPython v1.20.0 on 2023-04-26; ESP32 module with ESP32

1. Durchlauf: Startup duration = 8 ms
2. Durchlauf: Startup duration = 10 ms
3. Durchlauf: Startup duration = 13 ms
4. Durchlauf: Startup duration = 14 ms
5. Durchlauf: Startup duration = 16 ms
6. Durchlauf: Startup duration = 19 ms
7. Durchlauf: Startup duration = 22 ms
8. Durchlauf: Startup duration = 23 ms
9. Durchlauf: Startup duration = 25 ms
10. Durchlauf: Startup duration = 28 ms
11. Durchlauf: Startup duration = 30 ms
12. Durchlauf: Startup duration = 32 ms
13. Durchlauf: Startup duration = 34 ms
14. Durchlauf: Startup duration = 37 ms
15. Durchlauf: Startup duration = 39 ms
16. Durchlauf: Startup duration = 40 ms
17. Durchlauf: Startup duration = 43 ms
18. Durchlauf: Startup duration = 5 ms

Ein Durchlauf besteht immer aus:

rm /pyboard/*
cp *.py /pyboard/
repl
Strg-D (soft reboot)

Der Programmcode ist:

from time import ticks_diff, ticks_ms, sleep
pstart = ticks_ms()
from machine import Pin

# read Configuration
POWER_PIN = 14

power = Pin(POWER_PIN, Pin.OUT)
print(f"Startup duration = {ticks_diff(ticks_ms(), pstart)} ms")
power.on()
sleep(1)
power.off()

Hat jemand eine Idee, woran das liegen könnte. Gibt es irgend eine 
Möglichkeit, den Zustand der kurzen Startup-Zeit direkt zu erreichen? 
Liegt es eventuell am Filesystem des ESPs. Gibt es so etwas wie eine 
Formatierung oder Defragmentierung?

Ich freue mich über Tipps oder ähnliche Erfahrungsberichte.

Viele Grüße
Haiko

[Monk (roehrmond)]

Haiko schrieb:
> Hat jemand eine Idee, woran das liegen könnte?

Das ist ja strange. Bist du ganz sicher, dass kein Messfehler vorliegt?

[Robert M. (r_mu)]

Kann schon sein, dass das mit der Struktur des FAT Filesystems 
zusammenhängt. Um dem auf den Grund zu gehen würde ich mal einen 
Schnappschuss des Flash-Speichers wenn er "schnell" ist und wenn er 
"langsam" ist machen und dann z.B mit sowas 
https://www.heise.de/download/product/active-disk-editor analysieren.

[Jack V. (jackv)]

Haiko schrieb:
> ich baue gerade eine Steuerung, die darauf angewiesen ist, das der ESP
> sehr schnell hochfährt

Dann ist Micropython oder eine andere interpretierte Sprache nicht die 
beste Wahl.

Hast du schon versucht, dein Programm einzufrieren, also zumindest in 
Bytecode zu kompilieren?

[Haiko (haiko_kurt)]

Ja, das war auch mein erster Gedanke. C++ hab ich auch vor Jahren mal 
geschrieben, aber das Problem ist ja oft nicht die Programmiersprache, 
sondern die verfügbaren Bibliotheken. Und bis man sich da zurecht 
gefunden hat ist immer so eine Sache. Also war mein erster Plan, 
MicroPython etwas Beine zu machen ;-)

Und ja, ich habe auch mit dem mpy-cross ein Kombinat erzeugt. Das 
interessante: Es ändert überhaupt nichts an der Ausführungszeit. Was ja 
auch eigentlich klar ist, denn ich müsste dazu die Zeit zwischen Strom 
an und Ende des Programms messen. Dazu müsste ich aber meinen 
Versuchsaufbau erweitern. Vielleicht mache ich das, denn es interessiert 
mich.

Eins ist klar: Imports benötigen extrem viel Zeit. Wenn man aus der Weld 
der schnellen Maschinen kommt, nimmt man das nicht wahr. Aber ich habe 
aus den sieben Python-Dateien eine gemacht und damit die Startzeit auf 
40% reduziert!

[Haiko (haiko_kurt)]

Robert M. schrieb:
> Kann schon sein, dass das mit der Struktur des FAT Filesystems
> zusammenhängt. Um dem auf den Grund zu gehen würde ich mal einen
> Schnappschuss des Flash-Speichers wenn er "schnell" ist und wenn er
> "langsam" ist machen und dann z.B mit sowas
> https://www.heise.de/download/product/active-disk-editor analysieren.

Wie macht man einen Schnappschuss?

[Haiko (haiko_kurt)]

Steve van de Grens schrieb:
> Haiko schrieb:
>> Hat jemand eine Idee, woran das liegen könnte?
>
> Das ist ja strange. Bist du ganz sicher, dass kein Messfehler vorliegt?

100% sicher. Ich habe das ganze mit einem ESP8266 zwei mal und mit einem 
ESP32 durchgespielt. Bei einem ESP8266 liegen die Zeiten zwischen 20ms 
und 330ms. (D1mini V3)

[Yalu X. (yalu) (Moderator)]

Hast mal das andere Filesystem ausprobiert? Für Micropython auf dem
ESP32 kann man ja zwischen FAT und littlefs auswählen.

[Haiko (haiko_kurt)]

Yalu X. schrieb:
> Hast mal das andere Filesystem ausprobiert? Für Micropython auf dem
> ESP32 kann man ja zwischen FAT und littlefs auswählen.

Nein das habe ich noch nicht. Guter Tipp! Wie kann ich zwischen den 
Filesystemen wählen? Wie kann ich Dateien auf ein anderes Filesystem 
kopieren?

[Yalu X. (yalu) (Moderator)]

Haiko schrieb:
> Wie kann ich zwischen den
> Filesystemen wählen?

Hier gibt es einen Artikel zu dem Thema:

  https://docs.micropython.org/en/latest/reference/filesystem.html

[Haiko (haiko_kurt)]

Ich hatte noch einen TinyPICO with ESP32-PICO-D4 mit MicroPython v1.17 
on 2021-09-02 in der Schublade. Verblüffend:

Die Ausführungszeit schwankt zwischen 0 und 1ms. Und es gibt nicht 
dieses Steigerungseffekt. Jetzt wäre zu prüfen, ob es an der Micropython 
Version oder am Board liegt... ich berichte

[Haiko (haiko_kurt)]

Yalu X. schrieb:
> Haiko schrieb:
>> Wie kann ich zwischen den
>> Filesystemen wählen?
>
> Hier gibt es einen Artikel zu dem Thema:
>
>   https://docs.micropython.org/en/latest/reference/filesystem.html

Danke!!

[MaWin O. (mawin_original)]

Haiko schrieb:
> Ein Durchlauf besteht immer aus:
> rm /pyboard/*
> cp *.py /pyboard/

Formatiere das rootfs immer frisch neu, statt nur die Dateien zu 
löschen.
Im Modul uos gibts entsprechende Routinen zum mounten/umounten und 
formatieren des FS. Das kannst du aus dem repl heraus machen.

[Haiko (haiko_kurt)]

Haiko schrieb:
> Ich hatte noch einen TinyPICO with ESP32-PICO-D4 mit MicroPython v1.17
> on 2021-09-02 in der Schublade. Verblüffend:

Ich habe mal weiter geforscht und siehe da, dieses Verhalten, dass der 
'import' unterschiedlich lange braucht ist erst ab der Micropython 
Version 1.18

Die Version 1.17 importiert viel schneller (1ms bei ESP8266).

Hat jemand ähnliche Beobachtungen gemacht?

---
Ich werde jetzt mal versuchen mein Projekt mit dieser alten Micropython 
Version aufzubauen.

[Haiko (haiko_kurt)]

Offenbar verwendet Micropython per default das littlefs. Ich habe das 
mal probehalber auf FAT umgestellt:

import os
os.umount('/')
os.VfsFat.mkfs(bdev)
os.mount(bdev, '/')

Das merkwürdige Verhalten ist komplett verschwunden. Auch ein 
wiederholtes Kopieren und Löschen der Files verändert nicht das 
Zeitverhalten. Auch bei der Micropthon Version 1.20. Imports gehen jetzt 
auch sehr viel schneller und benötigen nur noch 4ms (ESP8266). Hat 
jemand eine Erklärung dafür?

[Haiko (haiko_kurt)]

Robert M. schrieb:
> Kann schon sein, dass das mit der Struktur des FAT Filesystems
> zusammenhängt. Um dem auf den Grund zu gehen würde ich mal einen
> Schnappschuss des Flash-Speichers wenn er "schnell" ist und wenn er
> "langsam" ist machen und dann z.B mit sowas
> https://www.heise.de/download/product/active-disk-editor analysieren.

Default wird offenbar littlefs verwendet.

[Gerd A. (gerd_a289)]

Hallo Heiko,
nur so eine Idee: Du könntest den Python-Code auch mit mpy-cross 
vor-comilieren: mpy-cross -march=xtensa <file>.py und das .pyc statt des 
py auf den ESP kopieren. Spart Platz und Laufzeit (hoffe ich). Das 
funktioniert bei mir außer bei main.py richtig gut.
Gruß Gerd

[Haiko (haiko_kurt)]

Gerd A. schrieb:
> Hallo Heiko,
> nur so eine Idee: Du könntest den Python-Code auch mit mpy-cross
> vor-comilieren: mpy-cross -march=xtensa <file>.py und das .pyc statt des
> py auf den ESP kopieren. Spart Platz und Laufzeit (hoffe ich). Das
> funktioniert bei mir außer bei main.py richtig gut.
> Gruß Gerd

Schon probiert und hilft in diesem fall überhaupt nicht. Ich war auch 
etwas verwundert. Um die richtige Startzeit zu ermitteln, nutzt mein 
Versuchsaufbau auch gar nicht, denn ich müsste die Zeit zwischen 
'Versorgungsspannung an' und 'Programm läuft' messen. Da mich das aber 
interessiert, werde ich mir wohl mal über ein Messverfahren Gedanken 
machen.

Übrigens hilft ein Umformatieren der Flash-Disk auf das FAT-Filesystem. 
Dann ist das Laden von imports konstant schnell.

Viele Grüße Haiko