ArduCounter Support und neue Versionen (war: Stromzähler mit S0 Schnitt...)

[Otto123]

Hallo Stefan,

nachdem jetzt alles ne Weile gut lief, habe ich folgendes Phänomen:
Ich habe drei Pins definiert, die werden beim reset vom Arduino auch gemeldet:

Code Auswählen Erweitern

2016.12.12 10:11:46 3: AC: Arduino reported setup done, Firmware 1.5 - sending config cmds
2016.12.12 10:11:46 3: AC: InitDev calls Attr with pinD4 rising pullup
2016.12.12 10:11:46 3: AC: InitDev calls Attr with pinD5 rising pullup
2016.12.12 10:11:46 3: AC: InitDev calls Attr with interval 60 300
2016.12.12 10:11:46 3: AC: InitDev calls Attr with pinD6 rising pullup
2016.12.12 10:11:46 3: AC: defined pin 4 PCInt pin 20, iMode rising, no min len, count 0 (+0) in 0 ms
2016.12.12 10:11:46 3: AC: defined pin 5 PCInt pin 21, iMode rising, no min len, count 0 (+0) in 0 ms
2016.12.12 10:11:46 3: AC: defined pin 6 PCInt pin 22, iMode rising, no min len, count 0 (+0) in 1 ms

Starte ich jetzt FHEM neu, fehlt pin 6:

Code Auswählen Erweitern

2016.12.12 10:15:58 3: AC: Arduino reported setup done, Firmware 1.5 - sending config cmds
2016.12.12 10:15:58 3: AC: InitDev calls Attr with pinD4 rising pullup
2016.12.12 10:15:58 3: AC: InitDev calls Attr with pinD5 rising pullup
2016.12.12 10:15:58 3: AC: InitDev calls Attr with interval 60 300
2016.12.12 10:15:58 3: AC: InitDev calls Attr with pinD6 rising pullup
2016.12.12 10:16:00 3: AC: defined pin 4 PCInt pin 20, iMode rising, no min len, count 0 (+0) in 1 ms
2016.12.12 10:16:00 3: AC: defined pin 5 PCInt pin 21, iMode rising, no min len, count 0 (+0) in 0 ms

Ach der Aufruf get AC info fördert ihn nicht zu Tage

Code Auswählen Erweitern

2016.12.12 10:22:34 3: AC: Sending info command to Arduino
2016.12.12 10:22:34 3: AC: Status: ArduCounter V1.5
2016.12.12 10:22:34 3: AC: normal interval 60000
2016.12.12 10:22:34 3: AC: max interval 300000
2016.12.12 10:22:34 3: AC: min interval 2000
2016.12.12 10:22:34 3: AC: min count 1
2016.12.12 10:22:34 3: AC: pin 4 PCInt pin 20, iMode rising, no min len, count 33 (+0) in 200060 ms
2016.12.12 10:22:34 3: AC: pin 5 PCInt pin 21, iMode rising, no min len, count 0 (+0) in 95116 ms
2016.12.12 10:22:34 3: AC: Next report in 24861 Milliseconds

So ist es definiert:

Code Auswählen Erweitern

Internals:
   DEF        /dev/ttyUSB0@38400
   DeviceName /dev/ttyUSB0@38400
   FD         10
   Initialized 1
   ModuleVersion 3.5 - 13.11.2016
   NAME       AC
   NR         29
   PARTIAL
   STATE      opened
   TYPE       ArduCounter
   buffer
   Readings:
     2016-12-12 10:15:58   FirmwareVersion 1.5
     2016-12-12 10:28:59   ZaehlerHzg      3639.1825
     2016-12-12 00:35:34   ZaehlerHzgKorr  3639.065
     2016-12-12 10:28:59   ZaehlerSumme    43452.4966666667
     2016-12-12 00:41:58   ZaehlerSummeKorr 43452.3766666667
     2016-12-12 10:28:59   ZaehlerWW       4597.314
     2016-12-12 00:36:20   ZaehlerWWKorr   4597.314
     2016-11-19 12:34:36   countDiff       1
     2016-11-19 12:34:36   lastMsg         first at 7804, last at 7804
     2016-12-12 10:28:59   pin4            47
     2016-12-12 10:25:59   pin5            0
     2016-12-12 10:15:16   pin6            9
     2016-12-12 10:28:59   power4          0.309
     2016-12-12 10:25:59   power5          0.000
     2016-12-12 10:15:16   power6          1.949
     2016-12-12 10:15:53   state           opened
     2016-11-19 12:34:36   timeDiff        9301
     2016-11-03 11:38:13   version         ArduCounter V1.2
Attributes:
   factor     1000
   flashCommand avrdude -p atmega328P -c arduino -P [PORT] -D -U flash:w:[HEXFILE] 2>[LOGFILE]
   interval   60 300
   pinD4      rising pullup
   pinD5      rising pullup
   pinD6      rising pullup
   readingFactor4 2500
   readingFactor5 1000
   readingFactor6 13333
   userReadings ZaehlerHzg {ReadingsVal("AC","pin4",0)/400 + ReadingsNum("AC","ZaehlerHzgKorr",0) },ZaehlerWW {ReadingsVal("AC","pin5",0)/1000 + ReadingsNum("AC","ZaehlerWWKorr",0)},ZaehlerSumme {ReadingsVal("AC","pin6",0)/75 + ReadingsNum("AC","ZaehlerSummeKorr",0) }
   userattr   pinD4 pinD5 pinD6 readingFactor4 readingFactor5 readingFactor6

Habe ich schon wieder ein Problem mit einem Arduino? Hast Du dazu eine Idee?
Wenn ich den Arduino resette dann ist pin 6 wieder da, siehe ersten Code Block.

Gruß Otto

[BillyPbg]

Hallo Otto,

Dein Arduino dürfte "ok" sein, habe selbiges Phänomen:
bei mir ist Pin 4, 5 und 6 definiert, wobei nur Pin 5 tatsächlich scharf geschalten ist, sprich Impulse erhält.
Und Dieser verabschiedet sich aus unerfindlichen Gründen, konnte noch kein Muster feststellen, deshalb auch mein Schweigen...

VG.
BillyPbg

[Otto123]

Hi,

ja ich habe gerade einen anderen Arduino probiert, gleiches Verhalten. Nachdem neustart von FHEM ist das pin 6 weg. Mit nicht ganz nachvollziehbaren Aktionen bekomme ich es wieder:
- Power Reset
- Reset Knopf
- Neu flashen.

Offensichtlich ein Glücksspiel ob beim Reset das pin 6 wieder mitkommt oder nicht.

Anstatt der letzten Nachricht -> AC: defined pin 6 PCInt pin 22, iMode rising, no min len, count 0 (+0) in 1 ms
habe ich auch so etwas mal gesehen -> AC: unparseable message: Error in input: r

Habe jetzt mal verbose 5 laufen, dass sieht aber alles gut aus 

Gruß Otto

[StefanStrobel]

Hallo,

das erfreuliche daran ist aber auch dass das Problem offensichtlich reproduzierbar ist.
Dann wird sich der Fehler auch finden lassen

Ich versuche es bei mir auch mal mit den entsprechenden Pins.

Gruss
    Stefan

[StefanStrobel]

Ich denke das ist ein Problem der Kommunikation zwischen Fhem und Arduino.
Wenn Fhem neu startet und der Arduino noch läuft, dann kommt keine Setup done Meldung und das Fhem-Modul wartet bis sich der Arduino mit den nächsten Zählerständen meldet. Bis dahin ist das interne initialized-Flag nicht gesetzt und es kann nichts an den Arduino gesendet werden.
Zudem scheint in der seriellen Queue Müll zu stehen, was zu den Fehlermeldungen führt.
Außerdem verwende ich im Sketch noch die String-Klasse, was für den dynamischen Speicher sehr ungünstig ist.
Daher baue ich den ganzen Kommunikationsteil nochmal um ...
Wird ein paar Tage dauern.

Gruß
    Stefan

[StefanStrobel]

Hallo,

anbei eine neue Version zum Testen.
Ich habe die Kommunikation zwischen Fhem und dem Arduino komplett umgebaut. Es sollte jetzt robuster laufen.

Gruss
    Stefan

[BillyPbg]

Hallo Stefan,
Danke für das tolle Weihnachtsgeschenk!

Frohes Fest!

[Otto123]

Hallo Stefan,

na da wird es ja Weihnachten  nicht langweilig!

Danke und schöne Weihnachten
Otto

[Otto123]

Hallo Stefan,

ich wollt endlich mal am Pi flashen und nicht erst den Arduino nano an Windows anstöpseln müssen:
Da muss ich meckern  im flashCommand fehlt die Baudrate, offenbar kann nur mit 57600 geflashed werden.

Also Inhalt vom attr flashCommand

Code Auswählen Erweitern

avrdude -p atmega328P -b 57600 -c arduino -P [PORT] -D -U flash:w:[HEXFILE] 2>[LOGFILE]
Und es funktioniert!

Gruß Otto

[Otto123]

Hallo Stephan,

irgendwie zählt die neue Version zusätzliche Impulse.

Ich werde morgen mal auf die alte Version gehen.

Wie könnte ich das Verhalten analysieren?

Gruß Otto

[StefanStrobel]

Hallo Otto,

bei Verbose 5 wird alles protokolliert.
Verwendest Du eine Mindestlänge um Störungen auszufiltern?

Gruss
   Stefan

[Otto123]

Hallo Stefan,

ich zähle drei Zähler, ich kann immer nach einiger Zeit einfach die Zählerstände vergleichen um zu sehen ob es richtig läuft.
Die DEF habe ich nicht verändert
Die Hardware habe ich nicht verändert.

Ich hatte von Version 1.5 zu 1.6 lediglich das pm ausgetauscht und das hex File geflashed.
Jetzt habe ich das Ganze retour gemacht, also altes pm (Version 1.5) und Version 1.5 hex File geflashed.

Anbei zwei Logs,
eines mit der Version 1.6  - das Ergebnis im Vergleich mit meinen Zählern ist Fehlerhaft, AC hat zu viel gezählt!
Das andere mit Version 1.5 - das Ergebnis stimmt exakt.

Hier noch das List (aktuell wieder Version 1.5 andere deswegen aber noch anderes Internal und anderes Reading)

Code Auswählen Erweitern

Internals:
   DEF        /dev/ttyUSB0@38400
   DeviceName /dev/ttyUSB0@38400
   FD         4
   Initialized 1
   NAME       AC
   NOTIFYDEV  global
   NR         29
   NTFY_ORDER 50-AC
   PARTIAL
   STATE      opened
   TYPE       ArduCounter
   VersionFirmware 1.6
   VersionModule 4.01 - 21.12.2016
   buffer
   Readings:
     2016-12-30 17:58:37   FirmwareVersion 1.5
     2016-12-30 22:22:09   ZaehlerHzg      3940.3325
     2016-12-30 22:22:09   ZaehlerSumme    44187.4533333335
     2016-12-30 22:22:09   ZaehlerWW       4658.74
     2016-12-30 22:22:09   pin4            2458
     2016-12-30 22:21:09   pin5            1754
     2016-12-30 22:22:09   pin6            1043
     2016-12-30 22:22:09   power4          1.930
     2016-12-30 22:21:09   power5          0.000
     2016-12-30 22:22:09   power6          2.463
     2016-12-30 17:58:36   state           opened
Attributes:
   factor     1000
   flashCommand avrdude -p atmega328P -b57600 -c arduino -P [PORT] -D -U flash:w:[HEXFILE] 2>[LOGFILE]
   interval   60 300
   pinD4      rising pullup
   pinD5      rising pullup
   pinD6      rising pullup
   readingFactor4 2500
   readingFactor5 1000
   readingFactor6 13333
   userReadings ZaehlerHzg monotonic {ReadingsVal("AC","pin4",0)/400},ZaehlerWW monotonic {ReadingsVal("AC","pin5",0)/1000},ZaehlerSumme monotonic {ReadingsVal("AC","pin6",0)/75}

   userattr   pinD4 pinD5 pinD6 readingFactor4 readingFactor5 readingFactor6
   verbose    5

Gruß Otto

[StefanStrobel]

Hallo Otto,

das ist sehr seltsam. Zwischen 1.5 und 1.6 hat sich der Code nur an den Stellen geändert, an denen der Arduino mit Fhem kommuniziert. Das Zählen ist unverändert. Im Log sehe ich nichts auffälliges.

Könntest Du bitte nochmal einen Test mit 1.6 machen und nach dem Start mit get Info prüfen ob auch alle Werte korrekt sind?

Um wie viel weicht der Zähler denn ab?
Kann es sein, dass die Abweichung nur durch den Ablesezeitpunkt kommt? Fhem bzw. der Arduino aktualisiert den Zählerstand ja erst am Ende eines Intervalls und wenn Du kurz vor Ablauf des Intervalls vergleichst, dann ist eine Abweichung zwangsläufig vorhanden.

Gruss
   Stefan

[Otto123]

Hallo Stefan,

also jetzt mit Version 1.5 ist seit gestern Abend der Zählerstand mit den physischen Zählern bis auf die Nachkommastellen absolut identisch. Das mit den Nachkommastellen ist Zeitabhängig das ist mir klar.

Mit Version 1.6 waren die Unterschiede an einem Tag erheblich, die Vorkommastellen gingen gegenüber den physischen Zählern um einige 10 bis 200 "vor"

Das war auch zu sehen an den Plots. Man sah deutliche Peaks, die sonst nicht zu sehen waren.
Im Anhang der Plot von gestern. Das ist nicht ganz eindeutig zu sehen, aber es sind ja die Zeitraüme von gestern wo ich Dir auch die Logs angehangen hatte. Die rote Kurve geht im Normalfall nicht über 5 kW Du siehst es aber deutlich vor 18:00 geht sie das mehrfach. Danach hatte ich umgestellt auf 1.5
Ich mache das nochmal mit Version 1.6 aber heute wird das nichts mehr 
Nächste Woche könnte ich das sicher sogar mal mit konstanten Leistungen nachstellen, geht im normalen Familienbetrieb nicht 

Dir eine guten Rutsch in neue Jahr!

Otto

[StefanStrobel]

Hallo Otto,

kannst Du nochmal testen und ein paar ausführlichere Daten posten?
- ein SVG nur mit der roten Kurve und mit größerer Y-Achse, so dass man den tatsächlichen Verlauf der Werte sieht
- Die tatsächliche Abweichung im Betrachtungszeitraum zwischen Fhem und Deinem Zähler mit Einheit (Impulse oder kWh?)

Da sich der relevante Code nicht geändert hat und die Kommunikation in Deinen Logs korrekt aussieht, sieht es für mich so aus als ob Deine Heizung tatsächlich mal eine Weile mehr Strom verbraucht hat.

Code Auswählen Erweitern


2016.12.30 16:37:35 4: AC: Parsed: Pin 4 count 52627 (diff 50) in 60548 ms, first at 1653, last at 59888
2016.12.30 16:38:35 4: AC: Parsed: Pin 4 count 52675 (diff 48) in 57919 ms, first at 2214, last at 57807

und viele ähnliche Zeilen in dem Zeitraum zeigen ca. 50 Impulse in ca einer Minute.
Das entspricht laut den Logs bei Deinem Faktor für Pin4 von 2500 einem Verbrauch von ca. 7,5kW.
Das geht dann recht lange so und erst gegen 16:47 auf 5,7 kW und gegen 17:04 auf 3,6kW und danach auf 0 herunter.
nach einem Bug sieht das eigentlich nicht aus und die Version 1.5 hätte in der Zeit sicher genau das gleiche gezählt.

Ich baue gerade noch ein ausführlicheres Logging ins Modul ein, aber bei allen meinen bisherigen Tests mit 1.6 hat bei mir jetzt alles korrekt funktioniert.

Gruss
   Stefan