HMCCU: Version 4.3 verfügbar

[Wolle02]

Hallo zap,

danke für den Tip. Das Ergebnis lautet:

Code Auswählen Erweitern

tcp        0      0 0.0.0.0:7420            0.0.0.0:*               LISTEN     
tcp        0      0 0.0.0.0:7411            0.0.0.0:*               LISTEN

mit

Code Auswählen Erweitern

netstat -ane | grep -E "74[0-9]{2}"

habe ich dann folgendes bekommen:

Code Auswählen Erweitern

tcp        0      0 0.0.0.0:7420            0.0.0.0:*               LISTEN      999        14006
tcp        0      0 0.0.0.0:7411            0.0.0.0:*               LISTEN      999        15642

14006 und 15642 sollten also die PIDs sein.

Leider findet ein kill -9 14006 und kill -9 15642 keinen passenden Prozess dazu.

Gruß
Wolle

[Wernieman]

und wenn Du als Schalter "-lntp" verwendest, was sagt er dann?

Und bitte .. als root ...

[Wolle02]

....hier kam dann folgendes raus:

Code Auswählen Erweitern

tcp        0      0 0.0.0.0:7420            0.0.0.0:*               LISTEN      774/perl           
tcp        0      0 0.0.0.0:7411            0.0.0.0:*               LISTEN      773/perl 

Die Prozesse 773 und 774 konnte ich auch finden und killen. Super, die RPC-Server laufen wieder 
Wieder was gelernt....... leider ist die Halbwertszeit von solchen Problemlösungen immer recht kurz 

Vielen herzlichen Dank an alle.

Gruß
Wolle

[zap]

....hier kam dann folgendes raus:

Code Auswählen Erweitern

tcp        0      0 0.0.0.0:7420            0.0.0.0:*               LISTEN      774/perl           
tcp        0      0 0.0.0.0:7411            0.0.0.0:*               LISTEN      773/perl 

Die Prozesse 773 und 774 konnte ich auch finden und killen. Super, die RPC-Server laufen wieder 
Wieder was gelernt....... leider ist die Halbwertszeit von solchen Problemlösungen immer recht kurz 

Vielen herzlichen Dank an alle.

Gruß
Wolle

Ursache: Da liegen noch 2 RPC Server Leichen, die die Ports geblockt hatten.
Passiert, wenn FHEM abstürzt. Da die RPC Server separate Prozesse sind, bleiben die übrig.

[Wolle02]

Danke für die Erklärung. Ich hatte nur gar nicht bemerkt, dass FHEM abgestürzt gewesen sei. Deshalb habe ich dieser Richtung auch gar nicht geforscht. Aufgetreten war das wie gesagt nach einem FHEM-Update; aber eigentlich lief hier alles normal weiter...... bis halt auf die RPC-Server.

Naja, jetzt laufen sie zwar wieder, aber ich habe das Gefühl, dass ich auf dem System irgendwas "kaputt konfiguriert" habe. Und da ich eh vorhatte mal ein paar Sachen grundlegend umzustellen, habe ich die Gelegenheit genutzt und angefangen FHEM neu aufzusetzen.

Danke nochmal und Grüße an alle.
Wolle

[zap]

Nach einem FHEM Update wird FHEM neu gestartet. Kann sein, dass die RPC Server noch nicht richtig gestoppt waren, als FHEM wieder gestartet wurde.
Zumindest das sollte mit der letzten HMCCU Version nicht mehr auftreten. FHEM wartet jetzt, bis die RPC Server gestoppt sind.

[Wernieman]

Was mich dabei nur wundert, hattest Du nicht geschrieben, das Du den PI rebootet hattest?

[Wolle02]

Was mich dabei nur wundert, hattest Du nicht geschrieben, das Du den PI rebootet hattest?

Ja, sogar mehrfach.
Irgendwas scheint in meinem bisherigen System nicht mehr richtig zu funktionieren. Nachdem heute mittag die RPC-Server dann wieder liefen, habe ich zum Testen den Raspi nochmal gebootet, um zu sehen, ob die RPC-Server wieder automatisch gestartet werden. Leider standen Sie wieder auf 'inactive' und es handelte sich wieder um die gleichen Prozessleichen wie oben geschrieben.

Im Logfile habe ich dann folgendes gefunden:

Code Auswählen Erweitern

2020.03.30 14:31:12 2: HMCCURPCPROC: [d_rpcBidCos_RF : 10272] RPC server process started for interface BidCos-RF with PID=10350
2020.03.30 14:31:12 2: HMCCURPCPROC: [d_rpcBidCos_RF : 10350] Initializing RPC server CB2001001009001020 for interface BidCos-RF
2020.03.30 14:31:12 2: HMCCURPCPROC: [d_rpcBidCos_RF : 10350] Callback server CB2001001009001020 created. Listening on port 7411
2020.03.30 14:31:12 2: HMCCURPCPROC: [d_rpcBidCos_RF : 10350] CB2001001009001020 accepting connections. PID=10350
2020.03.30 14:31:12 1: HMCCURPCPROC: [d_rpcBidCos_RF : 10272] RPC server starting
2020.03.30 14:31:12 2: HMCCURPCPROC: [d_rpc178020HmIP_RF : 10272] RPC server process started for interface HmIP-RF with PID=10351
2020.03.30 14:31:12 2: HMCCURPCPROC: [d_rpc178020HmIP_RF : 10351] Initializing RPC server CB2010001009001020 for interface HmIP-RF
2020.03.30 14:31:12 2: HMCCURPCPROC: [d_rpc178020HmIP_RF : 10351] Callback server CB2010001009001020 created. Listening on port 7420
2020.03.30 14:31:12 2: HMCCURPCPROC: [d_rpc178020HmIP_RF : 10351] CB2010001009001020 accepting connections. PID=10351
2020.03.30 14:31:12 1: HMCCURPCPROC: [d_rpc178020HmIP_RF : 10272] RPC server starting
2020.03.30 14:31:13 3: ESPEasy espBridge: Bridge v2.18 port [TCP:IPV4:8383] opened.
2020.03.30 14:32:35 3: FB_CALLMONITOR (my_callmonitor) - found 2 phonebooks
2020.03.30 14:32:38 3: FB_CALLMONITOR (my_callmonitor) - found 3 blocking rules (deflections)
2020.03.30 14:32:39 2: FB_CALLMONITOR (my_callmonitor) - read 15 contacts from remote phonebook "Telefonbuch"
2020.03.30 14:32:39 2: FB_CALLMONITOR (my_callmonitor) - read 19 contacts from remote phonebook "Spambuch"
2020.03.30 14:32:40 0: Featurelevel: 6
2020.03.30 14:32:40 0: Server started with 517 defined entities (fhem.pl:21524/2020-03-27 perl:5.024001 os:linux user:fhem pid:10272)
2020.03.30 14:32:40 4: RESIDENTStk rr_Wolle_wakeuptimer2: Wakeuptime recalculation triggered by at-device at_rr_Wolle_wakeuptimer2
2020.03.30 14:32:40 4: RESIDENTStk rr_Wolle_wakeuptimer2: wakeupGetBegin source: defaultValue
2020.03.30 14:32:40 4: RESIDENTStk rr_Wolle_wakeuptimer2: wakeupGetBegin result: 05:00 = 18000 s - 0 m = 05:00:00
2020.03.30 14:32:42 3: telnetForBlockingFn_1585571562: port 34855 opened
2020.03.30 14:32:43 3: NUT antwortet nicht
2020.03.30 14:32:43 1: 192.168.1.5:3493 disconnected, waiting to reappear (USVControl)
2020.03.30 14:32:43 1: 192.168.1.5:3493 reappeared (USVControl)
2020.03.30 14:32:43 0: HourCounter CN.FB_Internet_connect Run.598 first run done countsOverall:87
2020.03.30 14:32:43 3: SB_SERVER_CheckConnection(Squeezebox): STATE: opened power: ?
2020.03.30 14:32:43 3: SB_SERVER_CheckConnection(Squeezebox): forcing power on
2020.03.30 14:32:43 1: Timeout for PRESENCE_DoLocalFunctionScan reached, terminated process 10273
2020.03.30 14:32:43 2: PRESENCE (Handy_Wolle_wlan) - device could not be checked (retrying in 10 seconds): Timeout: process terminated
2020.03.30 14:32:44 1: Timeout for PRESENCE_DoLocalFunctionScan reached, terminated process 10274
2020.03.30 14:32:44 2: PRESENCE (Handy_Tanja_wlan) - device could not be checked (retrying in 10 seconds): Timeout: process terminated
2020.03.30 14:32:44 2: HMCCURPCPROC: [d_rpcBidCos_RF : 10272] RPC server process started for interface BidCos-RF with PID=10375
2020.03.30 14:32:44 2: HMCCURPCPROC: [d_rpcBidCos_RF : 10375] Initializing RPC server CB2001001009001020 for interface BidCos-RF
2020.03.30 14:32:44 2: HMCCURPCPROC: [d_rpc178020HmIP_RF : 10272] RPC server process started for interface HmIP-RF with PID=10376
2020.03.30 14:32:44 1: HMCCURPCPROC: [d_rpcBidCos_RF : 10375] Can't create RPC callback server CB2001001009001020 on port 7411. Port in use?
2020.03.30 14:32:44 1: HMCCURPCPROC: [d_rpcBidCos_RF : 10375] Can't initialize RPC server CB2001001009001020 for interface BidCos-RF
2020.03.30 14:32:44 2: HMCCURPCPROC: [d_rpc178020HmIP_RF : 10376] Initializing RPC server CB2010001009001020 for interface HmIP-RF
2020.03.30 14:32:44 1: HMCCURPCPROC: [d_rpc178020HmIP_RF : 10376] Can't create RPC callback server CB2010001009001020 on port 7420. Port in use?
2020.03.30 14:32:44 1: HMCCURPCPROC: [d_rpc178020HmIP_RF : 10376] Can't initialize RPC server CB2010001009001020 for interface HmIP-RF
2020.03.30 14:32:44 1: Timeout for PRESENCE_DoLocalFunctionScan reached, terminated process 10300
2020.03.30 14:32:44 2: PRESENCE (Handy_Susl_wlan) - device could not be checked (retrying in 10 seconds): Timeout: process terminated
2020.03.30 14:32:44 1: Timeout for PRESENCE_DoLocalPingScan reached, terminated process 10301
2020.03.30 14:32:44 2: PRESENCE (FB_Internet_connect) - device could not be checked (retrying in 10 seconds): Timeout: process terminated
2020.03.30 14:32:44 2: HMCCURPCPROC: [d_rpcBidCos_RF : 10272] Checking if RPC server process is running
2020.03.30 14:32:44 1: HMCCURPCPROC: [d_rpcBidCos_RF : 10272] RPC server process not running. Cleaning up
2020.03.30 14:32:44 1: HMCCURPCPROC: [d_rpcBidCos_RF : 10272] Housekeeping called. Cleaning up RPC environment
2020.03.30 14:32:44 1: HMCCURPCPROC: [d_rpcBidCos_RF : 10272] RPC server process CB2001001009001020 not runnning
2020.03.30 14:32:44 2: HMCCURPCPROC: [d_rpcBidCos_RF : 10272] Stop I/O handling
2020.03.30 14:32:44 2: HMCCURPCPROC: [d_rpcBidCos_RF : 10272] RPC server stopped. Cancel delayed shutdown.
2020.03.30 14:32:44 2: HMCCURPCPROC: [d_rpc178020HmIP_RF : 10272] Checking if RPC server process is running
2020.03.30 14:32:44 1: HMCCURPCPROC: [d_rpc178020HmIP_RF : 10272] RPC server process not running. Cleaning up
2020.03.30 14:32:44 1: HMCCURPCPROC: [d_rpc178020HmIP_RF : 10272] Housekeeping called. Cleaning up RPC environment
2020.03.30 14:32:44 1: HMCCURPCPROC: [d_rpc178020HmIP_RF : 10272] RPC server process CB2010001009001020 not runnning
2020.03.30 14:32:44 2: HMCCURPCPROC: [d_rpc178020HmIP_RF : 10272] Stop I/O handling
2020.03.30 14:32:45 2: HMCCURPCPROC: [d_rpc178020HmIP_RF : 10272] RPC server stopped. Cancel delayed shutdown.

So wie es aussieht wurden die RPC-Server um 14:31:12 Uhr korrekt gestartet.
Um 14:32:44 Uhr wurde dann allerdings nochmal versucht die RPC-Server zu starten was natürlich mislang, weil sie ja schon liefen oder schon als Zombiprozesse im System lagen.
Keine Ahnung, ob der zweite Startversuch die Prozesse getötet hat oder ob sie schon vorher gestorben sind und deshalb der zweite Versuch gestartet wurde.

Da aber bislang sonst niemand von solch einen Problem berichtet hat, denke ich, dass es sich hier um ein spezielles Problem auf meinem System handelt und es deshalb sinnvoll ist, das ganze System sauber neu aufzubauen.

[Wernieman]

Könnte es sein, das er versucht, FHEM 2 mal zu starten?
Installiert Du "nur" fhem neu, oder das komplette System?

[Wolle02]

Könnte es sein, das er versucht, FHEM 2 mal zu starten?

Ich habe jedenfalls nichts bewusst an den Startroutinen geändert. Auch aus dem restlichen Logfile kann ich eigentlich nichts erkennen, was darauf schließen lassen würde.

Installiert Du "nur" fhem neu, oder das komplette System?

Bei der Gelegenheit mache ich gleich das ganze Grundsystem auf Busterbasis neu.

[zap]

Sind die Meldungen oben tatsächlich die einzigen HMCCU / HMCCURPCPROC Meldungen im Log?

[Wolle02]

Im Großen und Ganzen schon. Gibt es etwas spezielles das du vermisst und nach dem ich nochmal gezielt schauen soll?

[zap]

Die RPC Server und HMCCU schreiben bei jedem Start Meldungen ins Log. Wenn die Server tatsächlich doppelt gestartet werden, muss es auch doppelte Log Einträge geben

[Wolle02]

Nun ja, im oben geposteten Logfileauszug sind ja doppelte HMCCURPCPROC Einträge vorhanden; um 14:31:12 und 14:32:44. Für mich sieht das schon gleich aus, aber ich weiß jetzt nicht, ob es auch wirklich das ist was du meinst.

Jedenfalls wurde ja der Grund warum die RPC server nicht starteten und eine Lösung gefunden. Wenn du wegen des Moduls noch etwas in Erfahrung bringen möchtest, dann steuere ich gerne noch Infos bei, so ich kann. Aber da ich ja sowieso dabei bin das System neu aufzusetzen, brauchen wir hier wegen mir nicht weiter zu machen.

Viele Grüße
Wolle

.....und bleibt gesund!

[zap]

Du könntest folgendes versuchen:

- RPC-Server anhalten
- Alle HMCCURPCPROC Devices löschen
- Im IO Device Attribut rpcserver erst mal auf off
- Config speichern
- FHEM neu starten
- Mit set <ioDev> rpcserver on die RPC Server starten (dabei werden die Devices neu angelegt)
- Config speichern