ConfigDB defekt? - FHEM GUI nach Homebridge Update nicht mehr erreichbar

[Spezialtrick]

"Man" kann nicht, aber Du kannst. Die Taste ist links unten.

Entschuldige meine Blindheit. 

[Spezialtrick]

So langsam verzweifle ich und meine besser Hälfte steigt mir aufs Dach, wenn ich Fhem nicht bald wieder ans Laufen bekommen. 

Ich habe nun anhand diesem Beitrag

https://forum.fhem.de/index.php?topic=46538.0

versucht die Config Version vor dem Homebridge Update zu laden. Leider verhält sich diese Version genauso wie die aktuellste und startet Fhem, jedoch geht es ab einem bestimmten Punkt nicht weiter:

Code Auswählen Erweitern


2017.05.16 09:37:18 2: Perfmon: ready to watch out for delays greater than one second
2017.05.16 09:37:19 3: telnetPort: port 7072 opened
2017.05.16 09:37:19 3: WEB: port 8083 opened
2017.05.16 09:37:19 3: WEBphone: port 8084 opened
2017.05.16 09:37:19 3: WEBtablet: port 8085 opened
2017.05.16 09:37:20 2: eventTypes: loaded 5411 events from ./log/eventTypes.txt
2017.05.16 09:37:20 3: Opening nanoCUL868 device /dev/serial/by-id/usb-FTDI_FT232R_USB_UART_A4035XBY-if00-port0
2017.05.16 09:37:20 3: Setting nanoCUL868 serial parameters to 38400,8,N,1
2017.05.16 09:37:24 3: nanoCUL868: Possible commands: BCFiAZEGMKUYRTVWXefltx
2017.05.16 09:37:24 3: nanoCUL868 device opened
2017.05.16 09:37:24 2: Switched nanoCUL868 rfmode to MAX
2017.05.16 09:37:24 3: CUL_MAX_Check: Detected firmware version 154 of the CUL-compatible IODev
2017.05.16 09:37:27 3: Opening nanoCUL433 device /dev/serial/by-id/usb-FTDI_FT232R_USB_UART_A4035XGY-if00-port0
2017.05.16 09:37:27 3: Setting nanoCUL433 serial parameters to 38400,8,N,1
2017.05.16 09:37:30 3: nanoCUL433: Possible commands: BCFiAGMKUYRTVWXefLltx
2017.05.16 09:37:30 3: nanoCUL433 device opened
2017.05.16 09:37:30 1: PERL WARNING: "my" variable $host masks earlier declaration in same scope at ./FHEM/30_MilightBridge.pm line 72.
2017.05.16 09:37:33 3: additional HM config file loaded: ./FHEM/HMConfig_SenTHPL.pm
2017.05.16 09:37:33 3: Opening nanoCUL868hm device /dev/serial/by-id/usb-FTDI_FT232R_USB_UART_A600CZUB-if00-port0
2017.05.16 09:37:33 3: Setting nanoCUL868hm serial parameters to 38400,8,N,1
2017.05.16 09:37:37 3: nanoCUL868hm: Possible commands: BCFiAZEkGMKUYRTVWXefltx
2017.05.16 09:37:37 3: nanoCUL868hm device opened
2017.05.16 09:37:37 2: Switched nanoCUL868hm rfmode to HomeMatic
2017.05.16 09:37:37 3: WifiLight: requested bridge bridge-V3 at 192.168.188.32 already in use by Farbkugel, copy llCmdQueue
2017.05.16 09:37:37 1: HMLAN_Parse: hmusb new condition disconnected
2017.05.16 09:37:37 3: Opening hmusb device 127.0.0.1:1234
2017.05.16 09:37:37 1: HMLAN_Parse: hmusb new condition init
2017.05.16 09:37:37 3: hmusb device opened
2017.05.16 09:37:38 3: DbLog DBLog: Creating Push-Handle to database mysql:database=fhem;host=localhost;port=3306 with user fhemuser
2017.05.16 09:37:38 3: DbLog DBLog: Push-Handle to db mysql:database=fhem;host=localhost;port=3306 created
2017.05.16 09:37:38 3: WifiLight: requested bridge bridge-V3 at 192.168.188.32 already in use by SZ.Ledstripe.Schrank, copy llCmdQueue
2017.05.16 09:37:38 3: WifiLight: requested bridge bridge-V3 at 192.168.188.32 already in use by Farbkugel, copy llCmdQueue
2017.05.16 09:37:41 3: Departure_Define (myDeparture) - defined with interval 90 (sec)
2017.05.16 09:37:42 3: DLCD LCDD has been defined
2017.05.16 09:37:47 3: DLCD LCDD: Line1 (22) is longer than display (20), ignoring some data
2017.05.16 09:37:47 3: DLCD LCDD: Line1: attr dlcdLine1 %time1%
2017.05.16 09:37:47 3: DLCD LCDD: Line2 (22) is longer than display (20), ignoring some data
2017.05.16 09:37:47 3: DLCD LCDD: Line2: attr dlcdLine2 %time1%
2017.05.16 09:37:47 3: DLCD LCDD: Line3 (22) is longer than display (20), ignoring some data
2017.05.16 09:37:47 3: DLCD LCDD: Line3: attr dlcdLine3 %time1%
2017.05.16 09:37:47 3: DLCD LCDD: Line4 (22) is longer than display (20), ignoring some data
2017.05.16 09:37:47 3: DLCD LCDD: Line4: attr dlcdLine4 %time1%
2017.05.16 09:37:47 3: DLCD LCDD: Line2 (24) is longer than display (20), ignoring some data
2017.05.16 09:37:47 3: DLCD LCDD: Line2: attr dlcdVal1 unreadable
2017.05.16 09:37:47 3: DLCD LCDD: Line3 (24) is longer than display (20), ignoring some data
2017.05.16 09:37:47 3: DLCD LCDD: Line3: attr dlcdVal2 unreadable
2017.05.16 09:37:47 3: DLCD LCDD: Line4 (24) is longer than display (20), ignoring some data
2017.05.16 09:37:47 3: DLCD LCDD: Line4: attr dlcdVal2 unreadable
2017.05.16 09:37:49 3: Device BZ.Fenster added to ActionDetector with 002:50 time
2017.05.16 09:37:49 3: Device BZ.Klimasensor added to ActionDetector with 000:10 time
2017.05.16 09:37:49 3: Device FL.Haustur added to ActionDetector with 002:50 time
2017.05.16 09:37:49 3: Device FL.Klimasensor.Aussen added to ActionDetector with 000:10 time
2017.05.16 09:37:49 3: Device FL.Klimasensor.Innen added to ActionDetector with 000:10 time
2017.05.16 09:37:50 3: Device HM_567899 added to ActionDetector with 000:20 time
2017.05.16 09:37:50 3: Device Ku.Fenster added to ActionDetector with 002:50 time
2017.05.16 09:37:50 3: Device Ku.Klimasensor added to ActionDetector with 000:10 time
2017.05.16 09:37:50 3: Device SZ.Balkontur added to ActionDetector with 002:50 time
2017.05.16 09:37:50 3: Device SZ.Klimasensor added to ActionDetector with 000:10 time
2017.05.16 09:37:50 3: Device UM.Klimasensor added to ActionDetector with 000:10 time
2017.05.16 09:37:50 3: Device WZ.Balkontur added to ActionDetector with 002:50 time
2017.05.16 09:37:50 3: Device WZ.Fenster.links added to ActionDetector with 002:50 time
2017.05.16 09:37:50 3: Device WZ.Klimasensor added to ActionDetector with 000:10 time
2017.05.16 09:37:51 3: HarmonyHub: connected
2017.05.16 09:37:51 3: DLCD LCDD initialized
2017.05.16 09:37:54 3: Opening PRESENCE_rr_***** device 192.168.188.2:5333
2017.05.16 09:37:54 3: PRESENCE_rr_***** device opened
2017.05.16 09:37:54 3: Opening PRESENCE_rr_**** device 192.168.188.2:5333
2017.05.16 09:37:54 3: PRESENCE_rr_**** device opened
2017.05.16 09:37:54 1: usb create starting
2017.05.16 09:37:56 1: usb create end
2017.05.16 09:37:56 0: Featurelevel: 5.8
2017.05.16 09:37:56 0: Server started with 267 defined entities (fhem.pl:14284/2017-05-14 perl:5.020002 os:linux user:root pid:2003)
2017.05.16 09:37:56 1: Perfmon: possible freeze starting at 09:37:19, delay is 37.736
2017.05.16 09:37:56 3: telnetForBlockingFn_1494920276: port 44159 opened


Diese Verhalten ändert sich auch nicht, wenn ich eine deutlich ältere oder auch die älteste von ca. 450 vorhanden Versionen lade.

Lösche ich hingegen allerdings meine ConfigDB aus /opt/fhem und kopiere die Basis ConfigDB aus /opt/fhem/contrib/configDB/ nach /opt/fhem lässt sich Fhem starten und ist auch über die GUI erreichbar.

Hat irgendwer eine Idee ?

[Thorsten Pferdekaemper]

Hi,
vielleicht als erstes mal den Thread-Titel ändern (nicht nur den Titel eines Posts). So sieht das momentan so aus, als ob sich der Thread hierher verirrt hat.
Also wenn das jetzt in der fhem.cfg wäre, dann würde ich sagen mal Einträge rauswerfen/auskommentieren bis es wieder geht und dann wieder reinnehmen, bis es nicht mehr geht. Wie das mit der configDB geht, keine Ahnung. Vielleicht gibt es ja einen Weg, die configDB wieder in fhem.cfg zu konvertieren und dann damit zu arbeiten.
Gruß,
   Thorsten

[papa]

Wenn ich das richtig sehe, hängt FHEM doch mit einem Telnet auf Port 44159. Versuch doch mal den Process rauszukriegen, der am Port 44159 hängt und diesen mit kill zu beenden. Dann sollte der BlockingCall doch zurück kommen.

Mit

Code Auswählen Erweitern

netstat -anp | less

kannst Du Dir die geöffneten Ports und die dazugehörigen Processe ansehen.

[Spezialtrick]

Danke für den Hinweis, hier zwei Ausgaben:

Code Auswählen Erweitern

2017.05.16 17:50:08 3: telnetForBlockingFn_1494949808: port 34321 opened

Code Auswählen Erweitern


Proto    Recv-Q Send-Q   Local Address              Foreign Address          State                 PID/Program name
tcp        0         0            127.0.0.1:34321         0.0.0.0:*                    LISTEN              1640/perl
tcp       68        0            127.0.0.1:34321         127.0.0.1:43264         CLOSE_WAIT      - 

Code Auswählen Erweitern

2017.05.16 18:03:39 3: telnetForBlockingFn_1494950619: port 45877 opened

Code Auswählen Erweitern


Proto    Recv-Q Send-Q   Local Address              Foreign Address          State                 PID/Program name
tcp        0         0            127.0.0.1:45877         0.0.0.0:*                    LISTEN              1596/perl
tcp       68        0            127.0.0.1:45877         127.0.0.1:60962         CLOSE_WAIT       -     


Wenn ich nun Perl beende, wird in der Folge ja auch Fhem beendet, allerdings wird noch einiges geloggt:

Code Auswählen Erweitern

root@cubietruck:~# tail -f /opt/fhem/log/fhem-2017-05.log
2017.05.16 18:09:30 1: [Alarm 1] has undefined save data , disarming
2017.05.16 18:09:30 1: [Alarm 2] has undefined save data , disarming
2017.05.16 18:09:30 1: [Alarm 3] has undefined save data , disarming
2017.05.16 18:09:30 1: [Alarm 4] has undefined save data , disarming
2017.05.16 18:09:30 1: [Alarm 5] has undefined save data , disarming
2017.05.16 18:09:30 1: [Alarm 6] has undefined save data , disarming
2017.05.16 18:09:30 1: [Alarm 7] has undefined save data , disarming
2017.05.16 18:09:30 0: Server shutdown
2017.05.16 18:09:32 1: BlockingInformParent (BlockingStart): Can't connect to localhost:45877: IO::Socket::INET: connect: Connection refused
2017.05.16 18:09:32 1: BlockingInformParent (FRITZBOX_Readout_Done): Can't connect to localhost:45877: IO::Socket::INET: connect: Connection refused

[Thorsten Pferdekaemper]

Wenn ich nun Perl beende,

Wie hast Du das gemacht, also mit welchem Befehl genau?
Gruß,
   Thorsten

[Spezialtrick]

Wie hast Du das gemacht, also mit welchem Befehl genau?
Gruß,
   Thorsten

Mit:

Code Auswählen Erweitern

pkill perl

[papa]

Und wenn du dich einfach mal mit Telnet an den Port verbindest ? Kommt da irgendwas ?

[Thorsten Pferdekaemper]

Das killt wahrscheinlich jeden Perl-Prozess... Du solltest das mit "kill <PID>" machen. Also in Deinem ersten Beispiel

Code Auswählen Erweitern


kill 1640

...und wenn der Prozess das überlebt, dann

Code Auswählen Erweitern


kill -9 1640

Gruß,
  Thorsten

[Spezialtrick]

Das killt wahrscheinlich jeden Perl-Prozess... Du solltest das mit "kill <PID>" machen. Also in Deinem ersten Beispiel

Code Auswählen Erweitern


kill 1640

...und wenn der Prozess das überlebt, dann

Code Auswählen Erweitern


kill -9 1640

Gruß,
  Thorsten

Habe den entsprechenden Prozess nun mit

Code Auswählen Erweitern

kill 1634

beendet. Dies beendet Fhem jedoch auch:

Code Auswählen Erweitern

2017.05.16 18:38:52 3: telnetForBlockingFn_1494952732: port 38273 opened
2017.05.16 18:38:52 3: DbRep DBlog_DbRep - connected
2017.05.16 18:40:52 1: [Alarm 0] has undefined save data , disarming
2017.05.16 18:40:52 1: [Alarm 1] has undefined save data , disarming
2017.05.16 18:40:52 1: [Alarm 2] has undefined save data , disarming
2017.05.16 18:40:52 1: [Alarm 3] has undefined save data , disarming
2017.05.16 18:40:52 1: [Alarm 4] has undefined save data , disarming
2017.05.16 18:40:53 1: [Alarm 5] has undefined save data , disarming
2017.05.16 18:40:53 1: [Alarm 6] has undefined save data , disarming
2017.05.16 18:40:53 1: [Alarm 7] has undefined save data , disarming
2017.05.16 18:40:53 0: Server shutdown

Hängt wahrscheinlich damit zusammen, dass einige andere Verbindungen auch unter diese Prozess fallen:

Code Auswählen Erweitern


tcp        0      0 0.0.0.0:8083            0.0.0.0:*               LISTEN      1634/perl       
tcp        0      0 0.0.0.0:8084            0.0.0.0:*               LISTEN      1634/perl       
tcp        0      0 0.0.0.0:8085            0.0.0.0:*               LISTEN      1634/perl
tcp     1497      0 127.0.0.1:49034         127.0.0.1:1234          ESTABLISHED 1634/perl       
tcp        0      0 192.168.188.2:48930     108.59.13.232:443       ESTABLISHED 1634/perl       
tcp       61      0 192.168.188.2:33852     192.168.188.2:5333      ESTABLISHED 1634/perl

Und wenn du dich einfach mal mit Telnet an den Port verbindest ? Kommt da irgendwas ?

Wie stelle ich das genau an? 

[betateilchen]

Mit configDB hat das jedenfalls nichts zu tun. Und kaputt ist die configDB mit 99.99% Wahrscheinlichkeit auch nicht, deshalb gibt es da auch nichts zu reparieren.

Das hier:

Code Auswählen Erweitern


2017.05.16 09:37:56 1: Perfmon: possible freeze starting at 09:37:19, delay is 37.736
2017.05.16 09:37:56 3: telnetForBlockingFn_1494920276: port 44159 opened


ist das Problem und das wird definitiv nicht von der configDB verursacht. Entweder (1) Du hast in Deiner Konfiguration ein device, das sich nicht anlegen läßt oder (2) ein device versucht auf Hardwareebene irgendeine Komponente Deines Cubietrucks anzusprechen, was nicht korrekt funktioniert. (Dann wäre (1) die logische Folge aus (2))

Starte FHEM mit configDB im rescue Mode und schau Dir die vorherigen Versionen an.

Mit "configdb list %% 2" kannst Du Dir beispielsweise die komplette Konfiguration "2" komplett anzeigen lassen.

Ich vermute initialUsbCreate als Bösewicht.

[Spezialtrick]

Mit configDB hat das jedenfalls nichts zu tun. Und kaputt ist die configDB mit 99.99% Wahrscheinlichkeit auch nicht, deshalb gibt es da auch nichts zu reparieren.

Das beruhigt mich schon mal ungemein. 

Das hier:

Code Auswählen Erweitern


2017.05.16 09:37:56 1: Perfmon: possible freeze starting at 09:37:19, delay is 37.736
2017.05.16 09:37:56 3: telnetForBlockingFn_1494920276: port 44159 opened


ist das Problem und das wird definitiv nicht von der configDB verursacht. Entweder (1) Du hast in Deiner Konfiguration ein device, das sich nicht anlegen läßt oder (2) ein device versucht auf Hardwareebene irgendeine Komponente Deines Cubietrucks anzusprechen, was nicht korrekt funktioniert. (Dann wäre (1) die logische Folge aus (2))

Ich könnte mir nur vorstellen, dass es sich um das interne Bluetooth des Cubietrucks handelt, dass eigentlich nicht angesprochen werden sollte, weil ich in der Fhem Definition einen externen Bluetooth Dongle verlinkt habe. Kann es sein, dass auf Systemebene Hci0 und Hci1 gewechselt haben und nun das falsche Bluetooth Device angesprochen wird? Ansonsten habe ich nur CULs, einen HM-USB und ein 20x4 Display am Cubie hängen, die jedoch seit Monaten keinerlei Probleme gemacht haben.

Starte FHEM mit configDB im rescue Mode und schau Dir die vorherigen Versionen an.

Mit "configdb list %% 2" kannst Du Dir beispielsweise die komplette Konfiguration "2" komplett anzeigen lassen.

Ich vermute initialUsbCreate als Bösewicht.

Das habe ich hinbekommen. Wonach schaue ich nun genau?

[papa]

Kannst Du die Konfiguration jetzt in eine Datei schreiben ? Dann könnte man die einzelnen Sachen Schritt für Schritt an bzw. abschalten.

[Spezialtrick]

Im Prinzip ja, allerdings ist die Auflistung vollkommen ungeordnet, sodass man alles sortieren müsste, bevor Fhem überhaupt startet.

[Spezialtrick]

Ich vermute initialUsbCreate als Bösewicht.

Ich habe tatsächlich

Code Auswählen Erweitern

define initialUsbCheck notify global:INITIALIZED usb create


in meiner Konfiguration. Daher habe ich es aus meiner ConfigDB gelöscht. Leider startet Fhem weiterhin nicht richtig und bleibt an der selben Stelle stehen wie zuvor. So langsam gebe ich es auf...