vorige Seite
 Inhaltsverzeichnis nächste Seite

Nachlese

Irgendwie haben kleine, eigentlich unkritische, Änderungen am Programm für den ATmega328 dazu geführt, dass die berechnete Anzahl von Tiefschlaf-Phasen nicht mehr stimmte. Laut Doku führt das Setzen der Register WDP3 und WDP0 dazu, dass 1.048.576 WDT Oscillator Cycles gewartet wird und dies bei VCC=5.0V einem Typical Time-out von 8.0 Sekunden entspricht. Die Batterie hatte zu diesem Zeitpunkt 5.07V (bzw. 5.03V mit einem anderen Multimeter).

Am ArduinoUNO (über USB versorgt) hat folgendes Progrämmchen
  char i;
  static unsigned long t1, t2;
  get_RTC();
  t1=RTC.time2000;
  for(i=0; i<100; i++)  {
    sleep_PWR_DOWN(); // ca. 8 Sekunden Tiefschlaf
  }
  get_RTC();
  t2=RTC.time2000;

  ESP8266_power_on_setup_and_wait_for_ip(10);
  ESP8266_connect_TCPIP(10);

  RTC.fillByTime2000(t1);
  snprintf(buf_g, 30, "INFO=%4d.%.2d.%.2d %.2d:%.2d:%.2d",
                RTC.year, RTC.month, RTC.day, RTC.hour, RTC.minute, RTC.second);
  TCPIP_send(buf_g);

  RTC.fillByTime2000(t2);
  snprintf(buf_g, 30, "INFO=%4d.%.2d.%.2d %.2d:%.2d:%.2d",
                RTC.year, RTC.month, RTC.day, RTC.hour, RTC.minute, RTC.second);
  TCPIP_send(buf_g);

  snprintf(buf_g, 30, "INFO=%4d", t2-t1);
  TCPIP_send(buf_g);

  ESP8266_disconnect_TCPIP();
  ESP8266_disable();
diese Ausgabe ergeben:
2015.11.14 10:41:35 Verbindung hergestellt ESP8266-2 (192.168.42.102)
2015.11.14 10:41:35 Info: 2015.11.14 10:27:53
2015.11.14 10:41:35 Info: 2015.11.14 10:41:31
2015.11.14 10:41:36 Info:  818
2015.11.14 10:41:36 Verbindung geschlossen ESP8266-2 (192.168.42.102)

Nach Einsetzen des ATmega328 in die Schaltung (mit obiger Spannung von 5.07V) kam dies:
2015.11.14 11:00:46 Verbindung hergestellt ESP8266-1 (192.168.42.101)
2015.11.14 11:00:46 Info: 2015.11.14 10:47:05
2015.11.14 11:00:46 Info: 2015.11.14 11:00:42
2015.11.14 11:00:46 Info:  817
2015.11.14 11:00:47 Verbindung geschlossen ESP8266-1 (192.168.42.101)

Also keineswegs 8 Sekunden - sondern vielmehr 8.18 bzw. 8.17 Sekunden.
Bei acht Stunden Wartezeit summiert sich so ein Fehler von 0.17 Sekunden auf
8[h]*60[m/h]*60[s/m]=28800[s]
28800[s]/8[s/z]=3600[z] Wartezyklen im Gegensatz zu
28800[s]/8.17[s/z]=3525.09[z] Wartezyklen.

3600[z]-3525[z]=75[z] Zyklen Unterschied
75[z]*8.17[s/z]=612.75[s] und somit
612.75[s]/60[s/m]=10.2[m] Minuten später als gewünscht.

Nicht ganz deuten kann ich, warum vorige Programm-Versionen am ArduinoUNO (mit seiner gleichbleibenden Spannung über USB) jemals pünktlich die Tiefschlaf-Phase verlassen haben....???  Wobei ich ihn da sicher nie acht Stunden habe warten lassen. Höchstens mal 30 Minuten. Aber auch dann wäre das eine Abweichung von immerhin 38 Sekunden. Hmmm...sehr sonderbar. Aber stimmt eigentlich, dass ich mich häufiger mal gewundert habe, dass er zu spät aufgewacht ist, obwohl ich die counter-Variable sogar mit 3 oder 4 initialisiert hatte.

Diese Erkenntnisse haben jedenfalls dazu geführt, dass das mittlerweile nicht mehr nötige Aufwachen um 01:00 Uhr jetzt dazu genutzt wird, die Dauer des sleep_PWR_DOWN() bei aktueller Batterie-Spannung auszumessen und diesen Messwert für die Berechnung der Anzahl der zu wartenden Tiefschlaf-Phasen zu nutzen. 100 Tiefschlaf-Phasen dauern 8.17*100/60=13.62 Minuten. Das passt also ganz locker in die Zeit zwischen 01:00 Uhr und 03:00 Uhr. Und erfreulicherweise kostet es keinerlei zusätzliche Energie aus dem Akku. Weil nach Restart nicht erstmal eine Viertelstunde nix passieren soll, wird in  setup() der Wert mit 8.3 bzw. 8300 initialisiert (kommt ja noch der Lebenszeichen-LED-delay hinzu) und dann erst in der folgenden Nacht korrigiert.

Zusätzlich wird jetzt am Ende der Routine zur Bestimmung der Dauer bis zur nächsten Aktion geprüft, ob die berechnete Dauer 12 Stunden übersteigt. In diesem Fall wird als Dauer 0 zurückgeliefert. Eine Dauer von fast 24 Stunden konnte vorkommen, wenn mehr als eine Minute nach der vorgesehenen Zeit nach der verbleibenden Zeit gefragt wurde. In diesem Fall hat die Routine nämlich bereits auf den Folge-Tag umgeschaltet.

Noch ist etwas Debug-Code im Programm für den ATmega328 aktiv.
Die Log-Einträge für einen TCPIP_sync_all() sehen derzeit so aus:
2015.11.19 03:00:03 Verbindung hergestellt ESP8266-1 (192.168.42.101)
2015.11.19 03:00:04 Autorisierung abgeschlossen
2015.11.19 03:00:04 Abweichung [sek]: 0
2015.11.19 03:00:05 Datum/Zeit übermittelt
2015.11.19 03:00:05 Zeiten-Tabelle ist aktuell
2015.11.19 03:00:05 Akku-Spannung: 5.25V
2015.11.19 03:00:05 Firmware-Version: 1.6.5
2015.11.19 03:00:05 Info: sleep_PWR_DOWN_duration_g=8350
2015.11.19 03:00:05 Info: sunw_g[0]=23
2015.11.19 03:00:05 Info: sunw_g[1]=14
2015.11.19 03:00:06 Info: sunw_g[2]=6
2015.11.19 03:00:06 Info: sunw_g[3]=52
2015.11.19 03:00:06 Info: sunw_g[4]=10
2015.11.19 03:00:06 Info: sunw_g[5]=2
2015.11.19 03:00:06 Info: sunw_g[6]=23
2015.11.19 03:00:06 Info: sunw_g[7]=15
2015.11.19 03:00:07 Info: sunw_g[8]=6
2015.11.19 03:00:07 Verbindung geschlossen ESP8266-1 (192.168.42.101)

Die erste Info-Meldung zeigt die zuletzt gemessene Dauer einer Tiefschlaf-Phase in Millisekunden.
Die folgenden Info-Meldungen zeigen die Sekunden bis zur jeweils nächsten Aktion im Moment des Aufwachens.
Der Log-Eintrag ist offensichtlich von der Sync-Aktion um 03:00 Uhr.
Somit sind die ersten drei Werte (23, 14, 6) also vor dem Runterfahren der Rollläden um 17:00 Uhr angefallen, die nächsten drei Werte (52, 10, 2) vor der Aktion um 01:00 Uhr und die letzten drei Werte (23, 15, 6) vor der Sync-Aktion, zu der die Log-Einträge gehören.
Die Aktions-Zeitpunkte sind:  15:00, 17:00, 01:00, 03:00
Die Zeit-Dauern dazwischen somit:  2h, 8h, 2h
Gut. Das passt ja verhältnismäßig zu: 23, 52, 23 ... auch wenn es nicht gerade sonderlich linear ist....
Aber ich könnte da schon noch etwas justieren, damit er vor jeder Aktion nur einmal zu früh aufwacht - also die Werte 14, 10 und 15 nicht mehr kämen.

Eigentlich sollte es reichen, die Variable counter mit 0 (statt 1) zu initialisieren. Aber andererseits will ich ja genau eine Tiefschlaf-Phase zu früh aufwachen.
Warum stimmt dieser blöde Wert nicht, wenn er doch nun schon täglich neu bestimmt wird und somit Änderungen der Batterie-Spannung kein Grund für Abweichungen mehr sein sollte...!?
In der Funktion zur Bestimmung der Dauer einer Tiefschlaf-Phase wird nach 100 Tiefschlaf-Phasen eine Sekunde addiert, um damit den Fall abzufangen, dass die Uhrzeit vor den 100 Tiefschlaf-Phasen ein paar Millisekunden vor Beginn der nächsten Sekunde abgefragt wurde. Wenn dann nach den 100 Tiefschlaf-Phasen wieder die Zeit abgefragt wird und dabei zufällig die Sekunde gerade erst ein paar Millisekunden alt wäre, ergäbe das einen Fehler für die Gesamtdauer von fast einer Sekunde.
Daher also plus eine Sekunde über alles. Für eine einzelne Tiefschlaf-Phase somit 1/100 Sekunde bzw. 10 Millisekunden.
Im Mittel bekomme ich dadurch einen um 5ms zu hohen Wert pro Tiefschlaf-Phase.
In acht Stunden summiert sich der Fehler auf zwei Sekunden, im Maximum (bei 10ms Fehler) auf vier Sekunden.

Mal überlegen, wie das bzgl. obiger Abweichungen hinkommen könnte ... hmmm ... irgendwie nicht ... dann müsste es linear ansteigen ... und das ist ja gerade nicht der Fall.
Bei höherer Anzahl an Tiefschlaf-Phasen wird der Fehler im Verhältnis kleiner.
Und dann gibts ja noch diese jeweils zweiten Werte. Nach zwei Stunden kommt er 23 Sekunden zu früh rein. 23/8,35=2,7545. Er könnte also noch zweimal schlafen, schläft aber nur einmal. Klar. Wegen der Initialisierung von counter mit 1 statt 0.
Nach acht Stunden kommt er 52 Sekunden zu früh rein. 52/8,35=6,2275. Von sechs mal schläft er offenbar nur fünf mal: (52-10)/8,35=5,03. Grund ist wieder die Initialisierung von counter mit 1.

Aber wieso will ich eigentlich, dass er eine Tiefschlaf-Phase zu früh aufwacht. Es langt ja, wenn er genau rechtzeitig aufwacht. Das "zu früh aufwachen" war seinerzeit schließlich nur zum Anglühen des ESP8266 gedacht und wäre damit jetzt überflüssig.
Die gemessene Tiefschlaf-Dauer wird nach oben angepasst und bei der Berechnung der Anzahl benötigter Tiefschlaf-Phasen werden Nachkommastellen rigoros abgeschnitten.
Damit sollte gewährleistet sein, dass er vielleicht zu früh, aber nie zu spät aufwacht.
Bei maximalem Fehler und maximalem Nachkommastellen-Verschnitt für acht Stunden Tiefschlaf also 4 Sekunden plus eine Tiefschlaf-Phase minus eine Millisekunde. Macht 12 bis 13 Sekunden, die er zu früh aufwachen könnte.
Dann kann ich mit gutem Gewissen die volle berechnete Anzahl von Tiefschlaf-Phasen warten bzw. counter mit 0 initialisieren.
Nun hatte ich ja aber den Eindruck, dass die RTC vorgeht.
Könnte das was an der Rechnung ändern oder verfälschen?
Der Zeitpunkt der Berechnung der Anzahl von Tiefschlaf-Phasen ist t0. Das ist ein Zeitpunkt und damit unbeeinflusst von einer vorgehenden Uhr.
Während der Tiefschlaf-Loop wird die Uhr nicht abgefragt. Erst beim Aufwachen. Da meldet die Uhr dann vielleicht eine Zeit, die nach der erwarteten (und tatsächlichen) Zeit liegt. Dadurch würde der Code-Block für die Aktions-Ausführung zu früh betreten werden. Das lässt sich aber ohnehin nicht ändern, weil die Schaltung ja nur die eine Uhr hat. Also egal ... und kein dramatisches Problem. Dann werden die Rollläden eben eine Sekunde zu früh angesteuert oder mit dem Python-Script gesprochen.

In setup() sollte ich sleep_PWR_DOWN_duration_g dann aber lieber mit 8400 initialisieren. Besser zu wenige Tiefschlaf-Phasen warten, als zu viele.


Ein vermeintlich neues Problem entstand, nachdem ich testhalber je einen debug_WLAN_send() direkt nach open_shutters() und close_shutters() eingebaut hatte. Dadurch hat sich der ATmega328 aufgehängt, keinen Reset gemacht und das Relais dauerhaft eingeschaltet gelassen.
Offenbar lag es daran, dass durch die Ansteuerung der IR-LEDs der 2200µF Kondensator komplett leergelutscht war.
Wurde dann bei leerem Kondensator das Relais und der 3.3V-Regler eingeschaltet, hats den ATmega328 ins Nirvana befördert. Kenne ich ja schon.
Nach Einfügen einer üppigen Kondensator-Auflade-Pause von einer Sekunde zwischen den Funktionsaufrufen war wieder alles gut.
Ich muss das mal im Auge behalten....vielleicht brauche ich doch noch einen Hardware-Watchdog-Timer (z.B. mit NE555), der nach spätestens 30 Sekunden ohne Retrigger (alias: Ansteuerung der Lebenszeichen-LED) einen Reset auf Pin-1 des ATmega328 schickt.

Das obige ESP8266-AnsteuerungV7.ino enthält bereits alle eben genannten Anpassungen.



Kaum schreibt man sowas, kommt beim nächsten Sync das hier:
2015.11.20 15:00:05 Info: sleep_PWR_DOWN_duration_g=8340
[....]
2015.11.21 03:00:03 Verbindung hergestellt ESP8266-1 (192.168.42.101)
2015.11.21 03:00:03 Autorisierung abgeschlossen
2015.11.21 03:00:04 Abweichung [sek]: 0
2015.11.21 03:00:05 Datum/Zeit übermittelt
2015.11.21 03:00:05 Zeiten-Tabelle ist aktuell
2015.11.21 03:00:05 Akku-Spannung: 5.23V
2015.11.21 03:00:05 Firmware-Version: 1.6.5
2015.11.21 03:00:05 Info: sleep_PWR_DOWN_duration_g=8380
2015.11.21 03:00:05 Info: sunw_g[0]=10
2015.11.21 03:00:06 Info: sunw_g[1]=2
2015.11.21 03:00:06 Info: sunw_g[2]=-41
2015.11.21 03:00:06 Info: sunw_g[3]=15
2015.11.21 03:00:06 Info: sunw_g[4]=6
2015.11.21 03:00:06 Verbindung geschlossen ESP8266-1 (192.168.42.101)

2015.11.21 07:00:05 Verbindung hergestellt ESP8266-1 (192.168.42.101)
2015.11.21 07:00:06 Info: open shutters
2015.11.21 07:00:06 Verbindung geschlossen ESP8266-1 (192.168.42.101)

2015.11.21 15:00:03 Verbindung hergestellt ESP8266-1 (192.168.42.101)
2015.11.21 15:00:04 Autorisierung abgeschlossen
2015.11.21 15:00:04 Abweichung [sek]: 0
2015.11.21 15:00:05 Datum/Zeit übermittelt
2015.11.21 15:00:05 Zeiten-Tabelle ist aktuell
2015.11.21 15:00:05 Akku-Spannung: 5.23V
2015.11.21 15:00:05 Firmware-Version: 1.6.5
2015.11.21 15:00:05 Info: sleep_PWR_DOWN_duration_g=8380
2015.11.21 15:00:05 Info: sunw_g[0]=54
2015.11.21 15:00:05 Info: sunw_g[1]=4
2015.11.21 15:00:06 Info: sunw_g[2]=110
2015.11.21 15:00:06 Info: sunw_g[3]=1
2015.11.21 15:00:06 Verbindung geschlossen ESP8266-1 (192.168.42.101)

Erste Auffälligkeit ist die Änderung der gemessenen Tiefschlaf-Dauer von 8340 auf 8380. In 24 Stunden um 40ms. Ganz schön happig.
Bei der Aktion um 17:00 Uhr ist er wie erwartet angekommen (10, 2). Da galt noch die Tiefschlaf-Dauer von 8340ms.
Auch bei der Aktion um 01:00 Uhr galt noch 8340ms. Da hat er aber um 41 Sekunden verpennt.
Danach wurde auf 8380ms umgeschaltet und daraufhin kam er um 03:00 Uhr 15 Sekunden zu früh aus dem Tiefschlaf.
Also zwei Sekunden über dem oben hergeleiteten Maximum.
Bei der Aktion um 07:00 Uhr ist er dann schon 54 Sekunden und um 15:00 Uhr sogar 110 Sekunden zu früh aufgewacht.
Das ist doch ein elender Mist.

Denkbar wäre, dass die Tiefschlaf-Dauer Temperatur-abhängig ist.
Ich habe gestern Abend nämlich den Ofen angemacht.
Die Schaltung steht schräg über dem Ofen, knapp einen Meter daneben und einen Meter höher als die Oberkante des Ofens.
Damit könnte das dort locker 10°C wärmer geworden sein - also so zwischen 18:00 - 01:00 Uhr.
Danach ist es langsam abgekühlt und die Tiefschlaf-Phasen wurden wieder kürzer.
Passt jedenfalls zu den Daten:
    01:00 - 03:00 (2h) -> 15 Sekunden zu früh
    03:00 - 07:00 (4h) -> 54 Sekunden zu früh
    07:00 - 15:00 (8h) -> 110 Sekunden zu früh
Tja, wenn das so ist, hilfts nix.
Ich werde der Schaltung deswegen jetzt sicher keinen LM35 zufügen und dann versuchen, aus der Temperatur einen Korrektur-Wert für die Tiefschlaf-Dauer abzuleiten. Dann lieber einfach 100ms auf die gemessene Tiefschlaf-Dauer aufschlagen und jeweils ein paar mal zu früh aufwachen.
Erstmal werde ich das jetzt mindestens eine Woche laufen lassen und danach anhand der gesammelten Logs entscheiden, ob ich doch noch was ändern muss.
Ein möglicher Ansatz wäre, die Tiefschlaf-Dauer bei jedem Aufwachen neu zu berechnen bzw. zu korrigieren.
Wobei das an diesem konkreten Verschlafen auch nix geändert hätte, da die Temperatur erst nach der vorigen Aktion (17:00 Uhr) angestiegen ist.

Nachtrag: ich bin jetzt sicher, dass eine höhere Temperatur die Dauer der Tiefschlaf-Phase beeinflusst bzw. verlängert.
Der Ofen war jetzt abends mehrmals an und immer nur genau dann gabs danach den Effekt, dass die Tiefschlaf-Phasen länger wurden.

vorige Seite
 nächste Seite