[GELÖST] - Sporadisch passiert etwas / Licht an/aus ohne erkennbaren Grund

[Wernieman]

Für einen syslog-Server reicht ein minimales Unix .... am besten gleich mit rsyslog

Code Auswählen Erweitern

apt-get install rsyslog

Und mit den Zeilen:

Code Auswählen Erweitern


module(load="imuxsock") # provides support for local system logging
module(load="imklog")   # provides kernel logging support

# provides UDP syslog reception
module(load="imudp")
input(type="imudp" port="514")

# provides TCP syslog reception
module(load="imtcp")
input(type="imtcp" port="514")

# Enable non-kernel facility klog messages
$KLogPermitNonKernelFacility on

# Log remote hosts to separate log file
$template PerHostLog,"/var/log/remote-hosts/%HOSTNAME%.log"
$template RemoteHostFileFormat,"%TIMESTAMP% %HOSTNAME% %syslogfacility-text% %syslogtag%%msg:::sp-if-no-1st-sp%%msg:::space-cc,drop-last-lf%\n"

$template Incoming-logs,"/var/log/%HOSTNAME%/%PROGRAMNAME%.log"
*.*  ?Incoming-logs
& ~


Hinweis:
Obiges ist KEINE komplette Config ....

[87insane]

Hab es mir einfach gemacht. Hab auf meinem Synology einfach im Protokollcenter den Empfang aktiv gesetzt und den ESPeasy´s (az_licht, bz_licht) verraten wohin diese loggen sollen.
Aktuell habe ich das Loglevel erstmal nur auf Error. Sollte das nicht reichen, muss ich es tiefer stellen.

Nun warte ich mal ab....

Die oben genannten Änderungen + Syslog sind aktiv. Weitere Ideen? Will auch nicht zu viel auf einmal machen. Aber wenn ich schon mal ein weiteres doing habe, wäre es super. Logge ja jetzt in FHEM und Syslog auf den beiden Schaltern. AZ ist mit neuer FW, BZ ist mit der älteren FW. So kann ich auch direkt sehen ob die neuere FW Verbesserung bringt. Bin gespannt was ich morgen sehe wenn ich rein schaue

[Wernieman]

Synology hatte ich wirklich vergessen .. ;o)
(Danke für den Tipp, auch wenn ich dort jetzt "senden" eingerichtet habe ;o) )

Auf Error loggt espeasy wirklich nur error, aber z.B. keine Schalterbetätigung. Eventuell solltest Du das Logging höher stellen ... mindestens Warning, wenn nicht sogar erstmal Info ..

[87insane]

Schön zu hören... Ihr Urgesteine vergesst auch Dinge :-P

Ich hatte auch erst überlegt wo ich den installiere. Danach eben, welche Geräte eigentlich eh immer an sind. Ist ja kein großer Job. Naja und dann eben....
Hab die Logs auf normal debug stehen. So müllt der zwar schon viel aber das lässt sich am Ende ja rauß selektieren.

Danke schonmal...


EDIT: Kein Problem. Bin ja froh wenn ich auch mal was beitragen kann - Hab auf dem kleineren von beiden echt alles am laufen. Sehr praktisch... Keiner brauch einen eigenen PXE Server. Aber naja :-P

PS: Hab jetzt schon von beiden Schaltern immer wieder:

Code Auswählen Erweitern

EspEasy: WD : Uptime 132 ConnectFailures 0 FreeMem 19472 WiFiStatus 3

Bedeutet laut Wiki (https://www.letscontrolit.com/wiki/index.php/Wifi)

=

3   Deauthenticated because sending STA is leaving (or has left) IBSS or ESS   The access point went offline, deauthenticating the client.

Kann aber beide erreichen.... Die ganze Zeit.

[Wernieman]

Naja .. dafür reicht eine kurze Störung des WLANs, welche Du selber nicht merkst ...

Aber in der Zeit macht er doch kein reboot?

P.S. der syslog geht auch über WLAN .. also muß es zu der Zeit funktioniert haben ;o)

[87insane]

Guten Morgen,

er hat die ganze Zeit über Probleme, ist aber erreichbar. Nach einer ewigen Zeit startet er dann neu aus irgendwelchen Bedingungen. Ich vermute fast, nach Zeit x oder Versuch x.
Habe hier mal das Log vom AZ Schalter. Dieser ist um 06:11:20 neugestartet. Kein weiteres mal. Leider erkenne ich im LOG nur nicht warum. Hier sieht man nur das er ein paar Sekunden weg war.
Das Log ist hier leider nicht aussagekräftig genug. Ich werde ein Log Level tiefer (debug more) gehen und nochmal abwarten.

Code Auswählen Erweitern

2019-02-21 06:12:02 Notice 192.168.20.50 kern az_licht EspEasy: WD : Uptime 1 ConnectFailures 0 FreeMem 19704 WiFiStatus 3
2019-02-21 06:12:00 Debug 192.168.20.50 kern az_licht EspEasy: EVENT: Clock#Time=Thu,07:12 Processing time:27 milliSeconds
2019-02-21 06:12:00 Notice 192.168.20.50 kern az_licht EspEasy: EVENT: Clock#Time=Thu,07:12
2019-02-21 06:11:46 Debug 192.168.20.50 kern az_licht EspEasy: HTTP : C009 closing connection
2019-02-21 06:11:46 Debug 192.168.20.50 kern az_licht EspEasy: HTTP : C009 Success! HTTP/1.1 200 OK
2019-02-21 06:11:46 Debug 192.168.20.50 kern az_licht EspEasy: HTTP : C009 written to client (187/443)
2019-02-21 06:11:46 Debug 192.168.20.50 kern az_licht EspEasy: POST /ESPEasy HTTP/1.1 Content-Length: 303 Host: 192.168.20.3:8383 User-Agent: ESP Easy/20103/Feb 16 2019 03:06:46 Connection: close
2019-02-21 06:11:46 Debug 192.168.20.50 kern az_licht EspEasy: HTTP : C009 connecting to 192.168.20.3:8383
2019-02-21 06:11:46 Debug 192.168.20.50 kern az_licht EspEasy: EVENT: Clock#Time=Thu,07:11 Processing time:24 milliSeconds
2019-02-21 06:11:46 Notice 192.168.20.50 kern az_licht EspEasy: EVENT: Clock#Time=Thu,07:11
2019-02-21 06:11:46 Debug 192.168.20.50 kern az_licht EspEasy: EVENT: Time#Initialized Processing time:27 milliSeconds
2019-02-21 06:11:46 Notice 192.168.20.50 kern az_licht EspEasy: EVENT: Time#Initialized
2019-02-21 06:11:46 Notice 192.168.20.50 kern az_licht EspEasy: Current Time Zone: DST time start: 2019-01-28 02:00:00 offset: 120 minSTD time start: 2019-12-29 03:00:00 offset: 60 min
2019-02-21 06:11:46 Notice 192.168.20.50 kern az_licht EspEasy: Time adjusted by -1550725891041.52 msec. Wander: -430757191.96 msec/second
2019-02-21 06:11:46 Notice 192.168.20.50 kern az_licht EspEasy: NTP : NTP replied: delay 30 mSec Accuracy increased by 0.473 seconds
2019-02-21 06:11:46 Debug 192.168.20.50 kern az_licht EspEasy: HTTP : C009 closing connection
2019-02-21 06:11:46 Debug 192.168.20.50 kern az_licht EspEasy: HTTP : C009 Success! HTTP/1.1 200 OK
2019-02-21 06:11:46 Debug 192.168.20.50 kern az_licht EspEasy: HTTP : C009 written to client (185/441)
2019-02-21 06:11:46 Debug 192.168.20.50 kern az_licht EspEasy: POST /ESPEasy HTTP/1.1 Content-Length: 301 Host: 192.168.20.3:8383 User-Agent: ESP Easy/20103/Feb 16 2019 03:06:46 Connection: close
2019-02-21 06:11:46 Debug 192.168.20.50 kern az_licht EspEasy: HTTP : C009 connecting to 192.168.20.3:8383
2019-02-21 06:11:46 Debug 192.168.20.50 kern az_licht EspEasy: HTTP : C009 closing connection
2019-02-21 06:11:46 Debug 192.168.20.50 kern az_licht EspEasy: HTTP : C009 Success! HTTP/1.1 200 OK
2019-02-21 06:11:45 Debug 192.168.20.50 kern az_licht EspEasy: HTTP : C009 written to client (187/443)
2019-02-21 06:11:45 Debug 192.168.20.50 kern az_licht EspEasy: POST /ESPEasy HTTP/1.1 Content-Length: 303 Host: 192.168.20.3:8383 User-Agent: ESP Easy/20103/Feb 16 2019 03:06:46 Connection: close
2019-02-21 06:11:45 Debug 192.168.20.50 kern az_licht EspEasy: HTTP : C009 connecting to 192.168.20.3:8383
2019-02-21 06:11:45 Debug 192.168.20.50 kern az_licht EspEasy: HTTP : C009 closing connection
2019-02-21 06:11:45 Debug 192.168.20.50 kern az_licht EspEasy: HTTP : C009 Success! HTTP/1.1 200 OK
2019-02-21 06:11:45 Debug 192.168.20.50 kern az_licht EspEasy: HTTP : C009 written to client (185/441)
2019-02-21 06:11:45 Debug 192.168.20.50 kern az_licht EspEasy: POST /ESPEasy HTTP/1.1 Content-Length: 301 Host: 192.168.20.3:8383 User-Agent: ESP Easy/20103/Feb 16 2019 03:06:46 Connection: close
2019-02-21 06:11:45 Debug 192.168.20.50 kern az_licht EspEasy: HTTP : C009 connecting to 192.168.20.3:8383
2019-02-21 06:11:45 Notice 192.168.20.50 kern az_licht EspEasy: Webserver: start
2019-02-21 06:11:20 Debug 192.168.20.50 kern az_licht EspEasy: Scheduler stats: (called/tasks/max_length/idle%) 189539/2161/9/82.90
2019-02-21 06:11:20 Debug 192.168.20.50 kern az_licht EspEasy: LoopStats: shortestLoop: 122 longestLoop: 3697693 avgLoopDuration: 153.25 loopCounterMax: 245901 loopCounterLast: 189539 countFindPluginId: 0
2019-02-21 06:11:19 Notice 192.168.20.50 kern az_licht EspEasy: WD : Uptime 824 ConnectFailures 0 FreeMem 19392 WiFiStatus 3
2019-02-21 06:11:00 Debug 192.168.20.50 kern az_licht EspEasy: EVENT: Clock#Time=Thu,07:11 Processing time:26 milliSeconds
2019-02-21 06:11:00 Notice 192.168.20.50 kern az_licht EspEasy: EVENT: Clock#Time=Thu,07:11
2019-02-21 06:10:50 Debug 192.168.20.50 kern az_licht EspEasy: Scheduler stats: (called/tasks/max_length/idle%) 188355/2160/9/82.40
2019-02-21 06:10:50 Debug 192.168.20.50 kern az_licht EspEasy: LoopStats: shortestLoop: 122 longestLoop: 3697693 avgLoopDuration: 154.24 loopCounterMax: 245901 loopCounterLast: 188355 countFindPluginId: 0
2019-02-21 06:10:49 Notice 192.168.20.50 kern az_licht EspEasy: WD : Uptime 824 ConnectFailures 0 FreeMem 19392 WiFiStatus 3
2019-02-21 06:10:38 Debug 192.168.20.50 kern az_licht EspEasy: HTTP : C009 closing connection
2019-02-21 06:10:38 Debug 192.168.20.50 kern az_licht EspEasy: HTTP : C009 Success! HTTP/1.1 200 OK
2019-02-21 06:10:38 Debug 192.168.20.50 kern az_licht EspEasy: HTTP : C009 written to client (187/443)
2019-02-21 06:10:38 Debug 192.168.20.50 kern az_licht EspEasy: POST /ESPEasy HTTP/1.1 Content-Length: 303 Host: 192.168.20.3:8383 User-Agent: ESP Easy/20103/Feb 16 2019 03:06:46 Connection: close
2019-02-21 06:10:38 Debug 192.168.20.50 kern az_licht EspEasy: HTTP : C009 connecting to 192.168.20.3:8383
2019-02-21 06:10:38 Debug 192.168.20.50 kern az_licht EspEasy: HTTP : C009 closing connection
2019-02-21 06:10:38 Debug 192.168.20.50 kern az_licht EspEasy: HTTP : C009 Success! HTTP/1.1 200 OK
2019-02-21 06:10:38 Debug 192.168.20.50 kern az_licht EspEasy: HTTP : C009 written to client (185/441)
2019-02-21 06:10:38 Debug 192.168.20.50 kern az_licht EspEasy: POST /ESPEasy HTTP/1.1 Content-Length: 301 Host: 192.168.20.3:8383 User-Agent: ESP Easy/20103/Feb 16 2019 03:06:46 Connection: close
2019-02-21 06:10:38 Debug 192.168.20.50 kern az_licht EspEasy: HTTP : C009 connecting to 192.168.20.3:8383
2019-02-21 06:10:38 Debug 192.168.20.50 kern az_licht EspEasy: EVENT: strom_rechts#strom_rechts=0.00 Processing time:24 milliSeconds
2019-02-21 06:10:38 Notice 192.168.20.50 kern az_licht EspEasy: EVENT: strom_rechts#strom_rechts=0.00
2019-02-21 06:10:38 Notice 192.168.20.50 kern az_licht EspEasy: SW : State 0.00
2019-02-21 06:10:38 Debug 192.168.20.50 kern az_licht EspEasy: EVENT: strom_links#strom_links=0.00 Processing time:27 milliSeconds
2019-02-21 06:10:38 Notice 192.168.20.50 kern az_licht EspEasy: EVENT: strom_links#strom_links=0.00
2019-02-21 06:10:38 Notice 192.168.20.50 kern az_licht EspEasy: SW : State 0.00
2019-02-21 06:10:20 Debug 192.168.20.50 kern az_licht EspEasy: Scheduler stats: (called/tasks/max_length/idle%) 189472/2161/9/82.80
2019-02-21 06:10:20 Debug 192.168.20.50 kern az_licht EspEasy: LoopStats: shortestLoop: 122 longestLoop: 3697693 avgLoopDuration: 153.30 loopCounterMax: 245901 loopCounterLast: 189472 countFindPluginId: 0
2019-02-21 06:10:19 Notice 192.168.20.50 kern az_licht EspEasy: WD : Uptime 823 ConnectFailures 0 FreeMem 19392 WiFiStatus 3

Hinzu habe ich im AZ Schalter mal Force WiFi B/G: aktiviert. Die 20/40MHz Koexistenz ist im Router wieder aktiv. Diese war wohl nicht schuld.

[Wernieman]

Mal eine andere Frage .. wie voll ist Dein WLAN, bzw. der Verwendete WLAN-Kanal?

Stört eventuell ein Nachbar?

[87insane]

Hab autohopping aktiv. An sich wohne ich WLAN Seitig ganz gut hier. Alles Einfamilien-Häuser mit alten Leuten die teils nicht mal WLAN haben. Hab gerade nochmal geprüft was passiert bei WLAN komplett aus. Habe nun nur noch den Hauptrouter aktiv und komplett nur noch b/g. Auf meinem Channel sind aktuell +/- 3 keine weiteren WLANs. Also optimal.


EDIT:
Folgendes ist mir noch aufgefallen. In dem Moment wo wirklich kein Router da ist spucken die Schalter aus: Last Disconnect Reason:   (201) No AP found
In diesem Moment wird das Fallback WLAN der Schalter auch aktiv. Also wenn wirklich keine Verbindung besteht. Nachdem der Router wieder da ist, verschwinden die Fallback WLAN auf einmal und alle Geräte sind wieder am Router angemeldet.
Habe aktuell nur b/g an und den Hauptrouter und trotzdem Status 3. So langsam gehen mir die Ideen aus...

[Wernieman]

Mir auch ... Du hast nicht eventuell einen WLAN-Controller rumliegen,? Nur mal um ein ESP-Wlan aufzubauen?

Alternativ einen hostap-fähige WLAN-Hardware?

[87insane]

Hab noch ein paar alte Router die man durchaus nehmen könnte. Die reichen zum testen.

[Wernieman]

Nur mal so am Rande:
Von einem sporadischen Licht-schalten zu einem WLAN-Problem ... der Weg ist jetzt wirklich nicht gradlinig .. ;o)

[87insane]

pumabaer sagte auf Seite 1 bereits so etwas. Ich kann es bis jetzt nicht fassen.
Für mich ist das schon ein wenig komisch.

- Die ESPs melden sich ganz normal am WLAN an, lassen sich schalten und laufen ganz normal.
- Ich sehe die im Router
- Die Dinger selber schalten ihr Fallback WLAN aus
- Trotz verbundenem und laufendem WLAN bekomme ich Status 3
- Achja... Router für mehr als 10min weg und die machen trotzdem nicht den Fehler, den sie nach einigen Stunden machen. Die bauen, wie sie es sollen, ihr Fallback WLAN auf.

Also irgendwas passt da nicht!

EDIT:
Ggf. sind wir auch auf dem Holzweg. Die Zeile heißt ja:
WD : Uptime 42 ConnectFailures 0 FreeMem 17088 WiFiStatus 3

Er sagt der Status vom WIFI ist 3 aber er hat 0 ConnectFailures.

[Wernieman]

jep .. und was mich wundert, das Sie dann irgendwann einen reboot hinlegen. Eine uptime >24h solltest Du auf jedem Fall hinkriegen.

Nur .. irgendwo müssen wir mal anfangen und deshalb die Frage nach einem unabängigem WLAN. Am besten sogar in einem eigenen Netz. Wenn es DANN funktioniert, können wir zurückbauen und uns dem Fehler annähern. Wenn es DANN NICHT funktioniert, bin ich mit "meinem Latein" aktuell am Ende ....

Bzw:
hast Du in den ESPs für Zeitserver/Fhem-Server IPs oder DNS-Namen eingetragen?

[87insane]

Die haben alle pool.ntp.org drin. Erreichen ihn auch... Könnte das auch über das NAS via IP spiegeln. Macht das einen Unterschied?

Das mit dem eigenen Netz und WLAN wäre machbar. Suche gerade bei google nach dem Reset Reason 53. Denke, das gibt ggf. mehr Aufschluss.

EDIT: Mache gerade ein issue auf github auf. Mal sehen was die Kollegen sagen. (https://github.com/letscontrolit/ESPEasy/issues/2342)
PS: Mein Englisch ist schlecht aber ich hoffe es reicht dafür....

[Wernieman]

Kannst Du nicht einen Zeitserver auf der Synology aufsetzen?

Und dann gegen diese Deine ESP ... hat den Vorteil, das Deine ganzen Geräte nur eine Zeit haben ... die der Synology.

Mach ich genau so, mit der Ausnahme das es ein "normaler" ntp auf dem fhem-Server ist. Sogar in der Firma mist es so eingerichtet. Es ist nivcht wichtig, das ein gerät die "richtige" Zeit hat, sondern das ALLE Geräte die GLEICHE Zeit haben. Nur dann macht Logfiles-lesen richtig Sinn ... ;o)