Bitte um Hilfe: Logfiles bleiben nach Update 5.8 leer

Begonnen von yalgoo, 27 Februar 2017, 22:01:08

Vorheriges Thema - Nächstes Thema

yalgoo

Hallo ich habe 15 1-wire DS18b20 Sensoren seit 1/2 Jahr erfolgreich im Einsatz.

Alle sind wie folgt eingerichtet:
define T1 GPIO4 28-031664016fff
attr T1 model DS18B20
attr T1 room GPIO-Devices
attr T1 group 1-wire
attr T1 icon temp_temperature
define FileLog_T1 FileLog ./log/T1-%Y-%W.log T1
attr FileLog_T1 logtype text

Seit dem Update gestern bleiben die Logfiles leer. Die Temperatur wir im Device ganz normal angezeigt und bei Seite neu laden aktualisiert.
Nur wenn ich unter Device Overview die Ansicht aktualisiere, werden neue Werte ausgelesen und auch im Logfile gespeichert. Sonst bleibt das Logfile leer.

Wer hat eine Idee, woran das liegen könnte?

cat /sys/bus/w1/devices/28-031664016fff/w1_slave
96 01 4b 46 7f ff 0c 10 a0 : crc=a0 YES
96 01 4b 46 7f ff 0c 10 a0 t=25375

$ lsmod | grep w1
ergibt:
w1_therm                3584  0
w1_gpio                 3657  0
wire                   25219  2 w1_gpio,w1_therm

Prof. Dr. Peter Henning

Vorschlag: Commandref zu FileLog lesen und etwas über reguläre Ausdrücke lernen.

LG

pah

Thorsten Pferdekaemper

Hi pah,
ich habe das gerade mal bei mir ausprobiert. Wenn man als Regex im Filelog einen Devicenamen angibt, dann wird einfach alles zu diesem Device geloggt. Ich glaube also nicht, dass es an einer fehlerhaften Regex liegt. Oder wie hattest Du das gemeint?
Gruß,
   Thorsten
FUIP

Prof. Dr. Peter Henning

Stimmt schon - aber das will er ja gar nicht, sondern nur die Temperatur.

Der Fehler scheint im GPIO4 zu liegen, das keine zyklischen Abfragen (mehr) macht.

LG

pah

Thorsten Pferdekaemper

Zitat von: Prof. Dr. Peter Henning am 02 März 2017, 12:20:10
Stimmt schon - aber das will er ja gar nicht, sondern nur die Temperatur.
Du hast anscheinend eine andere Glaskugel als ich.
FUIP

Prof. Dr. Peter Henning


KölnSolar

aber beide etwas getrübt  ;D

ZitatNur wenn ich unter Device Overview die Ansicht aktualisiere, werden neue Werte ausgelesen und auch im Logfile gespeichert. Sonst bleibt das Logfile leer.
heißt, dass der internaltimer keine Werte mehr abruft, also kein periodisches polling, kein event, kein Logging
Das liegt weder an FileLog, noch am GPIO4.
Einzige Idee zur Fehlerbehebung: Reboot(sofern nicht schon probiert)
Grüße Markus
RPi3/2 buster/stretch-SamsungAV_E/N-RFXTRX-IT-RSL-NC5462-Oregon-CUL433-GT-TMBBQ-01e-CUL868-FS20-EMGZ-1W(GPIO)-DS18B20-CO2-USBRS232-USBRS422-Betty_Boop-EchoDot-OBIS(Easymeter-Q3/EMH-KW8)-PCA301(S'duino)-Deebot(mqtt2)-zigbee2mqtt

Thorsten Pferdekaemper

Zitat von: KölnSolar am 02 März 2017, 18:24:12heißt, dass der internaltimer keine Werte mehr abruft, also kein periodisches polling, kein event, kein Logging
Da gibt es doch noch einen Thread mit Problemen in periodischen "at". Das könnte verwandt sein.
Gruß,
   Thorsten
FUIP

CoolTux

Wenn dann Update machen. Rudi hatte das die Tage gefixt.
Du musst nicht wissen wie es geht! Du musst nur wissen wo es steht, wie es geht.
Support me to buy new test hardware for development: https://www.paypal.com/paypalme/MOldenburg
My FHEM Git: https://git.cooltux.net/FHEM/
Das TuxNet Wiki:
https://www.cooltux.net

Prof. Dr. Peter Henning

Zitataber beide etwas getrübt
Der letzte, der das zu mir gesagt hat, fristet jetzt sein Leben als Kakerlake.

LG

pah

yalgoo

#10
Ich habe meinen RPi komplett noch mal neu aufgesetzt.  :'(
Kernel: 4.4.48-v7+

Die fhem.cfg enthält jetzt nur den 1-wire DS18B20

define T1 GPIO4 28-031664016fff
attr T1 model DS18B20
attr T1 room GPIO-Devices
define FileLog_T1 FileLog ./log/T1-%Y-%W.log T1:temperature.*
attr FileLog_T1 logtype text


Die Messwerte werden wieder nur manueller Aktualisierung der Browseranzeige in den Logfile geschrieben:

2017-03-02_22:18:31 T1 temperature: 32.312
2017-03-02_22:19:26 T1 temperature: 32.375
2017-03-02_22:19:31 T1 temperature: 32.437
2017-03-02_22:19:33 T1 temperature: 32.437
2017-03-02_22:19:35 T1 temperature: 32.437
2017-03-02_22:19:37 T1 temperature: 32.437
2017-03-02_22:47:57 T1 temperature: 32.25

Das selbständige Logen funktioniert leider immer noch nicht.
Alle 15 1-wire Sensoren werden erkannt und geben eine plausible Temperatur über die Konsole aus.
Nur der Filelog tut nicht mehr seit dem Update auf 5.8 via update

yalgoo

#11
Zitat von: Prof. Dr. Peter Henning am 02 März 2017, 09:27:48
Vorschlag: Commandref zu FileLog lesen und etwas über reguläre Ausdrücke lernen.

LG

pah

Es hat ja alles funktioniert. Mein 2ter RPi ohne Update auf 5.8 läuft ohne Probleme.

Logfile:
2017.03.02 23:14:24 1: PERL WARNING: readline() on closed filehandle DATA at ./FHEM/58_GPIO4.pm line 132.
2017.03.02 23:14:24 1: PERL WARNING: Use of uninitialized value in pattern match (m//) at ./FHEM/58_GPIO4.pm line 132.

rudolfkoenig

ZitatNur wenn ich unter Device Overview die Ansicht aktualisiere, werden neue Werte ausgelesen und auch im Logfile gespeicher

Wie stellst du fest, dass die Daten im Logfile sind?
Sieht man die Daten, wenn man im FileLog-Detail auf text klickt?
Sieht man die Events im Event-Monitor rechtzeitig?

KölnSolar

ZitatLogfile:
2017.03.02 23:14:24 1: PERL WARNING: readline() on closed filehandle DATA at ./FHEM/58_GPIO4.pm line 132.
2017.03.02 23:14:24 1: PERL WARNING: Use of uninitialized value in pattern match (m//) at ./FHEM/58_GPIO4.pm line 132.
Einmalige Meldung ? Periodisch ? Failure-Counter im device auf 0 ? Kamen die auch vor dem neu aufsetzen ? Oder hast Du evtl. jetzt die GPIOs oder w1-therm/w1-gpio nicht richtig eingerichtet(siehe viele Threads zur Logmeldung) ? Woher stammt Deine 58_GPIO4.pm ?

Ich hab gerade mal ein update gemacht und der Fehler lässt sich bei mir nicht nachstellen  :(

Und für eins musst Du Dich langsam mal entscheiden, entweder
ZitatNur der Filelog tut nicht mehr seit dem Update auf 5.8 via
oder
ZitatDie Messwerte werden wieder nur manueller Aktualisierung der Browseranzeige in den Logfile geschrieben:

Letzteres besagt: KEIN FileLog, sondern event-Problem und da hatte ich ja schon gestern geschrieben
Zitatheißt, dass der internaltimer keine Werte mehr abruft, also kein periodisches polling, kein event, kein Logging
RPi3/2 buster/stretch-SamsungAV_E/N-RFXTRX-IT-RSL-NC5462-Oregon-CUL433-GT-TMBBQ-01e-CUL868-FS20-EMGZ-1W(GPIO)-DS18B20-CO2-USBRS232-USBRS422-Betty_Boop-EchoDot-OBIS(Easymeter-Q3/EMH-KW8)-PCA301(S'duino)-Deebot(mqtt2)-zigbee2mqtt

yalgoo

#14
Zitat von: rudolfkoenig am 03 März 2017, 06:39:59
Wie stellst du fest, dass die Daten im Logfile sind?
Sieht man die Daten, wenn man im FileLog-Detail auf text klickt?
Sieht man die Events im Event-Monitor rechtzeitig?


Ja, die wenn ich im FileLog auf text klicke sind die Messwerte vorhanden. Es werden jedoch nur Messwerte geschrieben, wenn ich unter DeviceOverview den Name des Device anklicke oder die Browseransicht aktualisiere.
Der Code im fhem.cfg ist:

define T1 GPIO4 28-031664016fff
attr T1 model DS18B20
attr T1 room GPIO-Devices
define FileLog_T1 FileLog ./log/T1-%Y-%W.log T1:temperature.*
attr FileLog_T1 logtype text
define RPi GPIO4 BUSMASTER


Sonst habe ich zum Neuaufsetzen:

mit sudo raspi-config 1-wire aktiviert

/boot/config.txt mit
# activating 1-wire with pullup
dtoverlay=w1-gpio-pullup
erweitert

nach dem 1ten Update habe ich das Modul 58_GPIO4.pm kopiert
sudo cp /opt/fhem/contrib/58_GPIO4.pm /opt/fhem/FHEM/

und danach mit dem zuvor beschriebenen Code de nSensor definiert.

mittels ls /sys/bus/w1/devices/  werden alle angeschlossen Sensoren angezeigt
und
cat /sys/bus/w1/devices/28-031664016fff/w1_slave
erzeugt diese Ausgabe
54 02 4b 46 7f ff 0c 10 ba : crc=ba YES
54 02 4b 46 7f ff 0c 10 ba t=37250

... und noch 3 Screenshots
- Event monitor
- Def Device T1
- Def LogFile T1
- Ausgabe von sudo vcdbg log msg
- Def RPi Busmaster, bei klick auf RPi oder Browser aktualisieren wir das failures Reading um 1 hochgezählt

rudolfkoenig

#15
@yalgoo: Du verwirrst mich. Bitte nur meine Fragen beantworten, diese aber genau..

Ich versuche sie anders zu formulieren:
- wie stellst Du fest, dass die Daten _nicht_ im Logfile sind? Du sagst ja, dass beim Klick auf dem FileLog sind sie da.
- der Screenshot des Event-Monitors steht im direkten Gegensatz zum roten Kommentar: Man kann doch im Event-Monitor nicht auf T1 klicken. Kommen diese Werte zu dem im Screenshot sichtbaren Zeitpunkt, oder alle auf einmal?

Uebrigens die Definition des FileLogs ist kaputt, und das liegt sicher nicht an dem update. Mit
define FileLog_T1 FileLog ./log/T1-%Y-%W.log FileLog_T1:.*

hoert er auf seine eigenen Events, NAME und NOTIFYDEV sind gleich. Ich frage mich, wie damit die Werte in die Datei gekommen sind.

yalgoo

#16
Ich habe 2 Monitore (Mac mit iPad, duet, den Pi bediene ich per Terminal). Ich kann gleichzeitig die Definition von T1 anklicken oder aktualisieren und dabei den Event monitor ansehen.
Nur wenn ich auf die Def von T1 klicke werden den Temperatur, Datum und Uhrzeit in den Logfile geschrieben, sonst passiert nichts. Gilt genauso für den Event monitor. Klick auf T1 und es wird ein werden T: ... und temperature: ... im Event monitor ausgegeben. Kein Klick keine Messwerte.

Die Definition meines FileLogs ist meiner Ansicht nach nicht kaputt. Normalerweise wird die Temperatur doppelt ausgeben:
20017-03-02_22:17:38 T1 T: 32.187
2017-03-02_22:17:38 T1 temperature: 32.187

Ich habe die Ausgabe auf eine reduziert. Siehe aktuellen Screenshot meiner FileLog-Def mit nur einer Temperatur:

Deine Def. habe ich in meine fhem.cfg kopiert. Meine mit # auskommentiert, alles gespeichert, Shutdown restart
define FileLog_T1 FileLog ./log/T1-%Y-%W.log FileLog_T1:.*

Dann im DeviceOverview mehrmals auf T1 geklickt. Im Event monitor werden die Messungen angezeigt (wenn ich nicht klicke gibt es auch keine neuen Einträge im Event monitor). Im FileLog_T1 tauchen die neuen Werte nicht auf.

Wenn ich deinen FileLog Code in:

  define FileLog_T1 FileLog ./log/T1-%Y-%W.log T1:.*
ändere, bekomme ich folgenden FileLog:
2017-03-04_01:37:24 T1 temperature: 25.312
2017-03-04_01:37:27 T1 T: 25.312
2017-03-04_01:37:27 T1 temperature: 25.312
2017-03-04_01:42:49 T1 T: 25.125
2017-03-04_01:42:49 T1 temperature: 25.125

rudolfkoenig

ZitatDie Definition meines FileLogs ist meiner Ansicht nach nicht kaputt.
Ich versuche es deutlicher. Ich habe das Modul FileLog geschrieben, und so wie du das definiert hast, wird es definitiv nicht die Zeilen in die Logdatei schreiben, die du mir weiter oben gezeigt hast, und dafuer kann ich mehrere Gruende aufzaehlen:
- da NOTIFYDEV auf FileLog_T1 steht, wird das Modul nicht benachrichtigt, falls T1 sich aendert.
- falls FileLog benachrichtigt waere, dann filtert es selbst solche Events aus: in der Datei steht "T1 temperature", und das kann auf FileLog_T1:.* nicht matchen. Dieser Feature ist ca 10 Jahre alt, es hat schon immer so funktioniert.
- ein FileLog generiert keine Events, es sei denn man hat eventOnThreshold explizit gesetzt. Und diese Events haben einen anderen Format.


Zitat
Im Event monitor werden die Messungen angezeigt (wenn ich nicht klicke gibt es auch keine neuen Einträge im Event monitor).
Ich kenne das GPIO Modul nicht, aber die restlichen Komponenten, die du beschreibst. Ein Klick auf DEF verursacht keine Browser-FHEM Kommunikation. Wenn dabei bei Dir im EventMonitor zur Aenderung kommt, dann hat das nicht mit FHEM oder gar mit dem update zu tun, ich kann nur _extrem_ unplausible Betriebsystem-Bugs als Erklaerung vorstellen.

Fuer wahrscheinlicher halte ich, dass mir relevante Information, wie ein zweiter FileLog oder gar parallel laufender FHEM-Instanz nicht erwaehnt wird.

yalgoo

Danke für die Ausführungen, auch wenn ich sie nur zum Teil verstehe.

Ich haben meinen RPi komplett neuaufgesetzt. Betriebssystem und FHEM. Das FHEM wurde nur 1-wire für DS18B20 erweitert. Eingerichtet habe ich die 1-wire habe ich wie hier "https://wiki.fhem.de/wiki/Raspberry_Pi_und_1-Wire" für ab 2015 durchgeführt.

Alle Abfragen der Sensoren die ich über die Konsole mache, sind ohne Fehler wie ich sie erwarte. Auch im FHEM kann ich die Sensoren auslesen. Nur der LogFile wird nicht mehr von selbst mit Daten gefüttert. Sondern nur wenn ich hier, siehe Screenshot, klicke.

Thorsten Pferdekaemper

Zitat von: yalgoo am 04 März 2017, 01:32:57Wenn ich deinen FileLog Code in:

  define FileLog_T1 FileLog ./log/T1-%Y-%W.log T1:.*
ändere, bekomme ich folgenden FileLog:
2017-03-04_01:37:24 T1 temperature: 25.312
2017-03-04_01:37:27 T1 T: 25.312
2017-03-04_01:37:27 T1 temperature: 25.312
2017-03-04_01:42:49 T1 T: 25.125
2017-03-04_01:42:49 T1 temperature: 25.125
Dann ist doch alles gut, oder?
Gruß,
   Thorsten
FUIP

rudolfkoenig

Sondern nur wenn ich hier, siehe Screenshot, klicke.
Das ist aber nicht Def, DEF steht zwei Zeilen weiter unten, das habe ich in meinen Ausfuehrungen gemeint.
Ein Klick auf T1 ist gleichwertig mit einem Refresh. Erklaert mir aber deine Probleme nicht.

yalgoo

#21
Also neuer Versuch: nur bei einem Refresh von "T1" werden Daten in den Logfile "FileLog_T1" geschrieben. Anderenfalls kommen keine Daten an.

Nächster Versuch:
1. Ich habe alle Einträge zu den Sensoren aus der fhem.cfg gelöscht
2. Nur der Eintrag zum Busmaster: define RPi GPIO4 BUSMASTER ist noch da
3. save shutdown restart
4. Alle Sensoren wurde nach dem Restart durch autocreate im Room GPIO4 angelegt, auch die Logfiles. Siehe Screenshot
5. Messwerte werden wieder nur nach dem Refesh eines jeden Sensors an das dazugehörige Logfile übertragen. Anderenfalls bleibt es leer
6. Alle 10 angeschlossenen Sensoren einer Bauart senden fehlerfrei bei Eingabe von:
cat /sys/bus/w1/devices/28-03166484c0ff/w1_slave &&
cat /sys/bus/w1/devices/28-041663f158ff/w1_slave &&
cat /sys/bus/w1/devices/28-041663f2a4ff/w1_slave &&
cat /sys/bus/w1/devices/28-0316645594ff/w1_slave &&
cat /sys/bus/w1/devices/28-0316645f54ff/w1_slave &&
cat /sys/bus/w1/devices/28-031664a234ff/w1_slave &&
cat /sys/bus/w1/devices/28-041663f652ff/w1_slave &&
cat /sys/bus/w1/devices/28-031664a3baff/w1_slave &&
cat /sys/bus/w1/devices/28-031664a839ff/w1_slave &&
cat /sys/bus/w1/devices/28-031664016fff/w1_slave

Thorsten Pferdekaemper

@Rudi: Wenn man mal das durch den OP verursachte Rauschen herausfiltert, dann könnte das doch etwas mit dem InternalTimer-Bug zu tun haben, oder? Du hattest gesagt, dass FileLog u.U. so etwas wie InternalTimer(0... macht. Außerdem verwendet GPIO4 InternalTimer für sein Polling. Ist der InternalTimer-Fix schon normal per update verfügbar? Dann könnte man ja das mal empfehlen.

Gruß,
   Thorsten
FUIP

KölnSolar

Ach  ::)
Ist per update verfügbar. Also lieber TE, bitte mal update und nachfolgendes shutdown restart ausführen.
RPi3/2 buster/stretch-SamsungAV_E/N-RFXTRX-IT-RSL-NC5462-Oregon-CUL433-GT-TMBBQ-01e-CUL868-FS20-EMGZ-1W(GPIO)-DS18B20-CO2-USBRS232-USBRS422-Betty_Boop-EchoDot-OBIS(Easymeter-Q3/EMH-KW8)-PCA301(S'duino)-Deebot(mqtt2)-zigbee2mqtt

rudolfkoenig

Thorsten: gut kombiniert, du kannst Recht haben. Ich bin auch fuer ein update und retest.

yalgoo

#25
Zitat von: KölnSolar am 04 März 2017, 11:24:39
Ach  ::)
Ist per update verfügbar. Also lieber TE, bitte mal update und nachfolgendes shutdown restart ausführen.

Ich habe das Update und den Shutdown + Restart ausgeführt. Hurra es werden wieder Messwerte aufgezeichnet.
Ich habe noch die Autocreate Name umbenannt und den Log auf Jahr + KW umgestellt.


define RPi GPIO4 BUSMASTER
define T01 GPIO4 28-031664016fff
attr T01 model DS18B20
attr T01 room GPIO4
define FileLog_T01 FileLog ./log/T01-%Y-%W.log T01:temperature.*
attr FileLog_T01 logtype text
attr FileLog_T01 room GPIO4
define SVG_FileLog_T01_1 SVG FileLog_T01:SVG_FileLog_T01_1:CURRENT
attr SVG_FileLog_T01_1 room Plots


/boot/config.txt
# activating 1-wire with pullup
dtoverlay=w1-gpio-pullup
Kopieren von GPIO4.pm
sudo cp /opt/fhem/contrib/58_GPIO4.pm /opt/fhem/FHEM/

Reboot RPi + FHEM und Backup erstellt
Dann habe ich diese Screenshots gemacht:

Thorsten Pferdekaemper

Hi,
freut mich, dass es jetzt klappt und danke für die Rückmeldung.
Es wäre gut, wenn Du in Zukunft weniger Screenshots machst sondern statt dessen ein "list" des betreffenden Devices in code-Tags in den Beitrag kopierst. Dasselbe für den Event monitor. Das ist dann für die meisten einfacher zu interpretieren.
Danke&Gruß,
   Thorsten
FUIP

rudolfkoenig

ZitatDas ist dann für die meisten einfacher zu interpretieren.
Konkreter: wenn ich was nachstellen will, dann muss ich nicht alles abtippen, und eine Suche nach einem String ist auch einfacher. Auf Bilder kann man oft 0 und O nicht unterscheiden, usw.