[bug] FHEM Ausfall Zeitsteuerung/Polling/Zyklische Abfrage bei Störung I2C Bus

[tante ju]

Habe nach ca. einem Monat oder so, FHEM auf meinen RPi 2 am Sonntag aktualisiert und seitdem den Effekt, daß es nicht mehr richtig läuft.
MQTT zickt rum und MODBUS geht gar nicht mehr. Vielleicht geht auch mehr nicht mehr, weiß ich noch nicht.

Es scheint so, daß irgendwo intern ein Timing Problem auftritt?

Im Log sehe ich:

Code Auswählen Erweitern


2016.07.12 19:21:01 1: 127.0.0.1:1883 disconnected, waiting to reappear (mqtt)
2016.07.12 19:21:01 1: 127.0.0.1:1883 reappeared (mqtt)

ca. jede Minute.

Die MODBUS Devices scheinen gar nicht mehr bearbeitet zu werden. Writes und Reads werden einfach gar nicht mehr ausgeführt.

Habe extra noch auf der Befehlszeile geprüft, technisch geht MODBUS noch und die Devices auch.

Irgendwelche Ideen?

Hier noch alle Meldungen vom FHEM-Start:

Code Auswählen Erweitern


2016.07.12 19:04:01 1: PERL WARNING: Use of uninitialized value $iodev in concatenation (.) or string at ./FHEM/3
1_HUEDevice.pm line 257.
2016.07.12 19:04:02 1: PERL WARNING: Smartmatch is experimental at ./FHEM/52_I2C_PCF8574.pm line 48, <$fh> line 1
26.
2016.07.12 19:04:02 1: PERL WARNING: Smartmatch is experimental at ./FHEM/52_I2C_PCF8574.pm line 53, <$fh> line 1
26.
2016.07.12 19:04:02 1: PERL WARNING: Smartmatch is experimental at ./FHEM/52_I2C_PCF8574.pm line 55, <$fh> line 1
26.
2016.07.12 19:04:02 1: PERL WARNING: Smartmatch is experimental at ./FHEM/52_I2C_PCF8574.pm line 65, <$fh> line 1
26.
2016.07.12 19:04:02 1: PERL WARNING: Smartmatch is experimental at ./FHEM/52_I2C_PCF8574.pm line 75, <$fh> line 1
26.
2016.07.12 19:04:02 1: PERL WARNING: Smartmatch is experimental at ./FHEM/52_I2C_PCF8574.pm line 215, <$fh> line
126.
2016.07.12 19:04:02 1: PERL WARNING: Smartmatch is experimental at ./FHEM/52_I2C_PCF8574.pm line 287, <$fh> line
126.
2016.07.12 19:04:04 1: PERL WARNING: given is experimental at ./FHEM/98_LW12.pm line 389, <$fh> line 479.
2016.07.12 19:04:04 1: PERL WARNING: when is experimental at ./FHEM/98_LW12.pm line 390, <$fh> line 479.
2016.07.12 19:04:06 1: PERL WARNING: given is experimental at ./FHEM/98_openweathermap.pm line 129, <$fh> line 54
1.
2016.07.12 19:04:06 1: PERL WARNING: when is experimental at ./FHEM/98_openweathermap.pm line 130, <$fh> line 541
.
2016.07.12 19:04:06 1: PERL WARNING: when is experimental at ./FHEM/98_openweathermap.pm line 132, <$fh> line 541
.
2016.07.12 19:04:06 1: PERL WARNING: when is experimental at ./FHEM/98_openweathermap.pm line 139, <$fh> line 541
.
2016.07.12 19:04:06 1: PERL WARNING: when is experimental at ./FHEM/98_openweathermap.pm line 144, <$fh> line 541
.
2016.07.12 19:04:06 1: PERL WARNING: when is experimental at ./FHEM/98_openweathermap.pm line 153, <$fh> line 541
.
2016.07.12 19:04:06 1: PERL WARNING: when is experimental at ./FHEM/98_openweathermap.pm line 157, <$fh> line 541
.
2016.07.12 19:04:06 1: PERL WARNING: given is experimental at ./FHEM/98_openweathermap.pm line 185, <$fh> line 54
1.
2016.07.12 19:04:06 1: PERL WARNING: when is experimental at ./FHEM/98_openweathermap.pm line 186, <$fh> line 541
.
2016.07.12 19:04:06 1: PERL WARNING: when is experimental at ./FHEM/98_openweathermap.pm line 188, <$fh> line 541
.
2016.07.12 19:04:06 1: PERL WARNING: when is experimental at ./FHEM/98_openweathermap.pm line 197, <$fh> line 541
.
2016.07.12 19:04:06 1: PERL WARNING: when is experimental at ./FHEM/98_openweathermap.pm line 201, <$fh> line 541
.
2016.07.12 19:04:06 1: PERL WARNING: given is experimental at ./FHEM/98_openweathermap.pm line 222, <$fh> line 54
1.
2016.07.12 19:04:06 1: PERL WARNING: when is experimental at ./FHEM/98_openweathermap.pm line 224, <$fh> line 541
.
2016.07.12 19:04:06 1: PERL WARNING: when is experimental at ./FHEM/98_openweathermap.pm line 237, <$fh> line 541
.
2016.07.12 19:04:11 1: HMLAN_Parse: HMLAN1 new condition disconnected
2016.07.12 19:04:11 1: HMLAN_Parse: HMLAN1 new condition init
2016.07.12 19:04:25 1: PERL WARNING: Prototype mismatch: sub main::CTRL: none vs () at /usr/share/perl/5.20/const
ant.pm line 156, <$fh> line 1557.
2016.07.12 19:04:27 1: PERL WARNING: Constant subroutine main::URL redefined at /usr/share/perl/5.20/constant.pm
line 156, <$fh> line 1669.
2016.07.12 19:04:55 1: Including ./log/fhem.save
2016.07.12 19:05:15 1: usb create starting
2016.07.12 19:05:17 1: usb create end
2016.07.12 19:05:17 0: Featurelevel: 5.7
2016.07.12 19:05:17 0: Server started with 352 defined entities (fhem.pl:11756/2016-07-07 perl:5.020002 os:linux
user:fhem pid:30070)
2016.07.12 19:05:17 1: PERL WARNING: Exiting subroutine via last at ./FHEM/00_RPII2C.pm line 520.
2016.07.12 19:05:18 1: HMLAN_Parse: HMLAN1 new condition ok
2016.07.12 19:05:26 1: PERL WARNING: Argument "Unknown argument state, choose one of updateStatus:noArg" isn't nu
meric in numeric lt (<) at FHEM/Color.pm line 435.
2016.07.12 19:07:01 1: 127.0.0.1:1883 disconnected, waiting to reappear (mqtt)
2016.07.12 19:07:01 1: 127.0.0.1:1883 reappeared (mqtt)
2016.07.12 19:08:31 1: 127.0.0.1:1883 disconnected, waiting to reappear (mqtt)
2016.07.12 19:08:31 1: 127.0.0.1:1883 reappeared (mqtt)
2016.07.12 19:11:00 1: 127.0.0.1:1883 disconnected, waiting to reappear (mqtt)
2016.07.12 19:11:00 1: 127.0.0.1:1883 reappeared (mqtt)
2016.07.12 19:12:32 1: 127.0.0.1:1883 disconnected, waiting to reappear (mqtt)
2016.07.12 19:12:32 1: 127.0.0.1:1883 reappeared (mqtt)



Update:

Der I2C Bus war es, deswegen habe ich das Subject angepasst.

[franky08]

Hallo, schmeiß das "usb create" mal raus, auskommentieren oder auf disable setzen. smartmatch kannst du umbauen:
z.B. Code mit smartmatch "$hour ~~ [17..24]" und umgebaut wäre: "$hour >= 17 && $hour <= 24"

Ah, sehe gerade das es aus einem Modul stammt, dann kontaktiere den Maintainer oder baue das Modul selbst um (Smartmatch is experimental at ./FHEM/52_I2C_PCF8574.pm) also das 52_I2C_PCF8574.pm Modul.

VG
Frank

[tante ju]

Ok, weitere Eingrenzung:
Alles zeitgesteuerte läuft nicht. Also wenn per MQTT oder HM Werte kommen, werden die notifies generiert und verarbeitet. Ein Set funktioniert auch. Aber alle at oder andere zyklische Befehle, wie zum Beispiel auch MODBUS, der zyklisch wollt, laufen nicht mehr.

Irgendwelche Hinweise, wo ich noch suchen kann?

[franky08]

Hast du es mal mit disable usb create probiert, neustart??

[tante ju]

Ja, hatte keine Auswirkung.

Ich denke, ich habe die Ursache. Ein verbose 5 (global) förderte diese Meldungen zutage:

Code Auswählen Erweitern


2016.07.12 20:00:00 5: KellerBus: HWaccess I2CAddr: 0x21
2016.07.12 20:00:00 5: KellerBus: vom client empfangen|i2caddress: 33|direction: i2cread
2016.07.12 20:00:00 3: KellerBus: HWaccess blockweise von 0x21 lesen, -> sysread failure: Eingabe-/Ausgabefehler


Es scheint sich in der Nacht, als ich das Update machte, auch ein Gerät am I2C-Bus verabschiedet zu haben.
Und dieser Fehler scheint dazu zu führen, daß nichts zeitgesteuertes mehr funktioniert, da ja auch I2C zyklisch gepollt wird.
Habe den I2C aus der Config genommen und jetzt geht alles wieder.

Ich denke, da muß noch was gefixt werden in der Zeitsteuerung. Ist nicht schön, wenn so ein Fehler alles zeitgesteuerte lahm legt.

Werde jetzt mal wieder den Softwareupdate laufen lassen (war auf backup) und schauen, ob es immer noch geht.

[tante ju]

Es scheint sich in der Nacht, als ich das Update machte, auch ein Gerät am I2C-Bus verabschiedet zu haben.
Und dieser Fehler scheint dazu zu führen, daß nichts zeitgesteuertes mehr funktioniert, da ja auch I2C zyklisch gepollt wird.
Habe den I2C aus der Config genommen und jetzt geht alles wieder.

Ich denke, da muß noch was gefixt werden in der Zeitsteuerung. Ist nicht schön, wenn so ein Fehler alles zeitgesteuerte lahm legt.

Werde jetzt mal wieder den Softwareupdate laufen lassen (war auf backup) und schauen, ob es immer noch geht.

Ok, neuester Softwarestand und es ist reproduzierbar. Blockiere ich den I2C-Bus (ich nehme dem Gerät die Spannung) und habe ein Gerät darauf konfiguriert (egal, ob mit ignore oder ohne), dann werden KEINE Timer-gesteuerten Aktionen mehr ausgeführt. Also kein Polling, keine at und dgl.
Lösche ich den I2C Bus aus der Config oder versorge das Gerät wieder mit Spannung, ist alles gut.

[Lobot]

Hallo zusammen,

ich würde diesem Thema gerne nochmal hochholen, da ich ähnliche Probleme habe.

Ich habe immer mal wieder einen Fehler in der I2C-Kommunikation und in Folge hängen sich dann alle zeitgesteuerten Vorgänge und insbesondere Pollings auf. Z.B das Polling der PCF8574.

Gibt es eine Möglichkeit, dies zu unterbinden?

Also dass man z.B. bei einem Fehlereintrag im Log (I2CBus: HWaccess blockweise von 0x5d lesen, -> sysread failure: Remote I/O error) die Poll und Timer-Funktionen resetet?

Besser wäre natürlich, dass wenn sich die Timer bei solch einem Fehler überhaupt nicht mehr aufhängen würden.

Beste Grüße,
Martin

[Mario67]

Hallo,

da kommen bei mir böse Erinnerungen an das Verhalten von FHEM bei fehlendem I2C-Teilnehmer hoch
https://forum.fhem.de/index.php/topic,38512.msg308439.html#msg308439
Ich wollte das Ganze damals eigentlich noch weiter verfolgen, aber es lief ja wieder

Gruß,
Mario