FHEM Forum

FHEM => Sonstiges => Thema gestartet von: Mitch am 27 Oktober 2020, 12:51:29

Titel: [gelöst] shutdown restart wird immer 2x ausgeführt
Beitrag von: Mitch am 27 Oktober 2020, 12:51:29
Hallo Zusammen,

seit einiger Zeit wird ein shutdown restart immer zweimal ausgeführt.
d.h. ich gebe shutdown restart ein, fhem startet neu, wenn es "oben" ist, startet es nochmal.

Hier mal der Log nach einem Neustart:
2020.10.27 12:46:56 3: CUL_HM set CUL_HM_HM_SEC_KEY_23DB96 statusRequest noArg
2020.10.27 12:46:45 2: SignalESP433: CheckVersionResp, initialized v3.4.4
2020.10.27 12:46:43 2: HMCCURPCPROC: [d_rpc000207HmIP_RF : 28873] CB2010000202000207 NewDevice received 62 device and channel specifications
2020.10.27 12:46:43 1: HMCCURPCPROC: [d_rpc000207HmIP_RF : 28845] Scheduled CCU ping every 300 seconds
2020.10.27 12:46:43 1: HMCCURPCPROC: [d_rpc000207HmIP_RF : 28845] RPC server CB2010000202000207 running
2020.10.27 12:46:42 2: HMCCURPCPROC: [d_rpc000207HmIP_RF : 28845] Registering callback http://192.168.0.202:7420/fh2010 of type A with ID CB2010000202000207 at http://Admin:PWD@192.168.0.207:2010
2020.10.27 12:46:42 2: HMCCURPCPROC: [d_rpc000207HmIP_RF : 28845] RPC server CB2010000202000207 enters server loop
2020.10.27 12:46:42 2: SIGNALduino868: CheckVersionResp, initialized v3.4.4
2020.10.27 12:46:41 1: SignalESP433: DoInit, 192.168.0.182:23
2020.10.27 12:46:41 2: HMCCURPCPROC: [d_rpc000207HmIP_RF : 28873] CB2010000202000207 accepting connections. PID=28873
2020.10.27 12:46:41 2: HMCCURPCPROC: [d_rpc000207HmIP_RF : 28873] Callback server CB2010000202000207 created. Listening on port 7420
2020.10.27 12:46:41 2: HMCCURPCPROC: [d_rpc000207HmIP_RF : 28873] Initializing RPC server CB2010000202000207 for interface HmIP-RF
2020.10.27 12:46:41 1: HMCCURPCPROC: [d_rpc000207HmIP_RF : 28845] RPC server starting
2020.10.27 12:46:41 2: HMCCURPCPROC: [d_rpc000207HmIP_RF : 28845] RPC server process started for interface HmIP-RF with PID=28873
2020.10.27 12:46:41 0: HourCounter Thermenlaufzeit Run.598 first run done countsOverall:92
2020.10.27 12:46:39 1: PERL WARNING: Use of uninitialized value in localtime at ./FHEM/59_Twilight.pm line 1019.
2020.10.27 12:46:39 1: PERL WARNING: Use of uninitialized value in localtime at ./FHEM/59_Twilight.pm line 1018.
2020.10.27 12:46:39 1: PERL WARNING: Use of uninitialized value $n in hash element at fhem.pl line 4507.
2020.10.27 12:46:39 0: Server started with 731 defined entities (fhem.pl:23032/2020-10-26 perl:5.030000 os:linux user:fhem pid:28845)
2020.10.27 12:46:39 0: Featurelevel: 6
2020.10.27 12:46:22 0: HMCCU: Start of RPC server after FHEM initialization in 12 seconds
2020.10.27 12:46:22 2: Ikea: starting tradfri-fhem: /usr/local/bin/tradfri-fhem -s sssss -i iiiii -p ppppp -D --ip 192.168.0.30
2020.10.27 12:46:12 1: Including /opt/fhem/log/fhem.save
2020.10.27 12:46:12 1: HMCCURPCPROC: [d_rpc000207HmIP_RF : 28845] Initialized version 1.9.001 for interface HmIP-RF with I/O device d_ccu
2020.10.27 12:46:10 1: SIGNALduino868: DoInit, /dev/serial/by-id/usb-1a86_USB2.0-Serial-if00-port0
2020.10.27 12:46:08 0: HourCounter Thermenlaufzeit Define.228 parameters: Thermenlaufzeit HourCounter Vaillant:on Vaillant:off
2020.10.27 12:46:08 1: PERL WARNING: Unescaped left brace in regex is deprecated here (and will be fatal in Perl 5.32), passed through in regex; marked by <-- HERE in m/^(.*)({ <-- HERE .*})(.*)$/ at ./FHEM/10_MQTT_GENERIC_BRIDGE.pm line 1358, <$fh> line 2219.
2020.10.27 12:46:02 1: HMCCU: [d_ccu : 28845] HMCCU: Read 0 virtual groups from CCU 192.168.0.207
2020.10.27 12:46:02 1: HMCCU: [d_ccu : 28845] HMCCU: Read 0 programs from CCU 192.168.0.207
2020.10.27 12:46:02 1: HMCCU: [d_ccu : 28845] HMCCU: Read 2 interfaces from CCU 192.168.0.207
2020.10.27 12:46:02 1: HMCCU: [d_ccu : 28845] HMCCU: Read 3 devices with 59 channels from CCU 192.168.0.207
2020.10.27 12:46:02 1: HMCCU: [d_ccu : 28845] Changed default interface from BidCos-RF to HmIP-RF
2020.10.27 12:46:02 1: HMCCU: [d_ccu : 28845] Default interface BidCos-RF does not exist or has no devices assigned. Changing default interface.
2020.10.27 12:46:02 1: HMCCU: [d_ccu : 28845] HMCCU: Initializing device
2020.10.27 12:46:02 1: HMCCU: [d_ccu : 28845] Initialized version 4.3.025
2020.10.27 12:45:56 1: Including fhem.cfg
2020.10.27 12:45:56 1: PERL WARNING: Subroutine trim redefined at ./FHEM/99_myUtils.pm line 18.
Select error -1 (3)
2020.10.27 12:45:52 1: ERROR: Select error -1 (3), error count= 0
2020.10.27 12:45:52 1: Server shutdown delayed due to myDbLog,d_ccu,Ikea,d_rpc000207HmIP_RF for max 10 sec
2020.10.27 12:45:51 2: HMCCURPCPROC: [d_rpc000207HmIP_RF : 28803] RPC server stopped. Cancel delayed shutdown.
2020.10.27 12:45:51 2: HMCCURPCPROC: [d_rpc000207HmIP_RF : 28803] Stop I/O handling
2020.10.27 12:45:51 2: HMCCURPCPROC: [d_rpc000207HmIP_RF : 28803] RPC server process CB2010000202000207 deleted
2020.10.27 12:45:49 2: HMCCURPCPROC: [d_rpc000207HmIP_RF : 28831] Number of I/O errors = 0
2020.10.27 12:45:49 1: HMCCURPCPROC: [d_rpc000207HmIP_RF : 28831] RPC server CB2010000202000207 stopped handling connections. PID=28831
2020.10.27 12:45:49 2: HMCCURPCPROC: [d_rpc000207HmIP_RF : 28831] CB2010000202000207 received signal INT
2020.10.27 12:45:49 1: HMCCURPCPROC: [d_rpc000207HmIP_RF : 28803] Housekeeping called. Cleaning up RPC environment
2020.10.27 12:45:49 2: HMCCURPCPROC: [d_rpc000207HmIP_RF : 28831] CB2010000202000207 received signal INT
2020.10.27 12:45:49 2: HMCCURPCPROC: [d_rpc000207HmIP_RF : 28803] Cleaning up immediately
2020.10.27 12:45:49 2: HMCCURPCPROC: [d_rpc000207HmIP_RF : 28803] Sending signal INT to RPC server process CB2010000202000207 with PID=28831
2020.10.27 12:45:49 1: HMCCURPCPROC: [d_rpc000207HmIP_RF : 28803] Callback for RPC server CB2010000202000207 deregistered
2020.10.27 12:45:49 1: HMCCURPCPROC: [d_rpc000207HmIP_RF : 28803] Deregistering RPC server http://192.168.0.202:7420/fh2010 with ID CB2010000202000207 at http://Admin:PWD@192.168.0.207:2010
2020.10.27 12:45:49 1: HMCCURPCPROC: [d_rpc000207HmIP_RF : 28803] Stopping RPC server CB2010000202000207
2020.10.27 12:45:44 3: CUL_HM set CUL_HM_HM_SEC_KEY_23DB96 statusRequest noArg
2020.10.27 12:45:38 2: HMCCURPCPROC: [d_rpc000207HmIP_RF : 28831] CB2010000202000207 NewDevice received 62 device and channel specifications
2020.10.27 12:45:34 2: SignalESP433: CheckVersionResp, initialized v3.4.4
2020.10.27 12:45:33 1: HMCCURPCPROC: [d_rpc000207HmIP_RF : 28803] Scheduled CCU ping every 300 seconds
2020.10.27 12:45:33 1: HMCCURPCPROC: [d_rpc000207HmIP_RF : 28803] RPC server CB2010000202000207 running
2020.10.27 12:45:32 2: HMCCURPCPROC: [d_rpc000207HmIP_RF : 28803] Registering callback http://192.168.0.202:7420/fh2010 of type A with ID CB2010000202000207 at http://Admin:PWD@192.168.0.207:2010
2020.10.27 12:45:32 2: HMCCURPCPROC: [d_rpc000207HmIP_RF : 28803] RPC server CB2010000202000207 enters server loop
2020.10.27 12:45:31 2: HMCCURPCPROC: [d_rpc000207HmIP_RF : 28831] CB2010000202000207 accepting connections. PID=28831
2020.10.27 12:45:31 2: HMCCURPCPROC: [d_rpc000207HmIP_RF : 28831] Callback server CB2010000202000207 created. Listening on port 7420
2020.10.27 12:45:31 1: SignalESP433: DoInit, 192.168.0.182:23
2020.10.27 12:45:31 2: SIGNALduino868: CheckVersionResp, initialized v3.4.4
2020.10.27 12:45:30 2: HMCCURPCPROC: [d_rpc000207HmIP_RF : 28831] Initializing RPC server CB2010000202000207 for interface HmIP-RF
2020.10.27 12:45:30 1: HMCCURPCPROC: [d_rpc000207HmIP_RF : 28803] RPC server starting
2020.10.27 12:45:30 2: HMCCURPCPROC: [d_rpc000207HmIP_RF : 28803] RPC server process started for interface HmIP-RF with PID=28831
2020.10.27 12:45:30 0: HourCounter Thermenlaufzeit Run.598 first run done countsOverall:92
2020.10.27 12:45:29 1: PERL WARNING: Use of uninitialized value in localtime at ./FHEM/59_Twilight.pm line 1019.
2020.10.27 12:45:29 1: PERL WARNING: Use of uninitialized value in localtime at ./FHEM/59_Twilight.pm line 1018.
2020.10.27 12:45:29 1: PERL WARNING: Use of uninitialized value $n in hash element at fhem.pl line 4507.
2020.10.27 12:45:28 0: Server started with 731 defined entities (fhem.pl:23032/2020-10-26 perl:5.030000 os:linux user:fhem pid:28803)
2020.10.27 12:45:28 0: Featurelevel: 6
2020.10.27 12:45:08 0: HMCCU: Start of RPC server after FHEM initialization in 12 seconds
2020.10.27 12:45:08 2: Ikea: starting tradfri-fhem: /usr/local/bin/tradfri-fhem -s sssss -i iiiii -p ppppp -D --ip 192.168.0.30
2020.10.27 12:44:58 1: Including /opt/fhem/log/fhem.save
2020.10.27 12:44:58 1: HMCCURPCPROC: [d_rpc000207HmIP_RF : 28803] Initialized version 1.9.001 for interface HmIP-RF with I/O device d_ccu
2020.10.27 12:44:56 1: SIGNALduino868: DoInit, /dev/serial/by-id/usb-1a86_USB2.0-Serial-if00-port0
2020.10.27 12:44:53 0: HourCounter Thermenlaufzeit Define.228 parameters: Thermenlaufzeit HourCounter Vaillant:on Vaillant:off
2020.10.27 12:44:53 1: PERL WARNING: Unescaped left brace in regex is deprecated here (and will be fatal in Perl 5.32), passed through in regex; marked by <-- HERE in m/^(.*)({ <-- HERE .*})(.*)$/ at ./FHEM/10_MQTT_GENERIC_BRIDGE.pm line 1358, <$fh> line 2219.
2020.10.27 12:44:42 1: HMCCU: [d_ccu : 28803] HMCCU: Read 0 virtual groups from CCU 192.168.0.207
2020.10.27 12:44:42 1: HMCCU: [d_ccu : 28803] HMCCU: Read 0 programs from CCU 192.168.0.207
2020.10.27 12:44:42 1: HMCCU: [d_ccu : 28803] HMCCU: Read 2 interfaces from CCU 192.168.0.207
2020.10.27 12:44:42 1: HMCCU: [d_ccu : 28803] HMCCU: Read 3 devices with 59 channels from CCU 192.168.0.207
2020.10.27 12:44:42 1: HMCCU: [d_ccu : 28803] Changed default interface from BidCos-RF to HmIP-RF
2020.10.27 12:44:42 1: HMCCU: [d_ccu : 28803] Default interface BidCos-RF does not exist or has no devices assigned. Changing default interface.
2020.10.27 12:44:41 1: HMCCU: [d_ccu : 28803] HMCCU: Initializing device
2020.10.27 12:44:41 1: HMCCU: [d_ccu : 28803] Initialized version 4.3.025
2020.10.27 12:44:32 1: Including fhem.cfg
2020.10.27 12:44:32 1: PERL WARNING: Subroutine trim redefined at ./FHEM/99_myUtils.pm line 18.
2020.10.27 12:44:20 0: SONOS0: Das Lauschen auf der Schnittstelle wurde beendet. Prozess endet nun auch...
2020.10.27 12:44:20 0: Server shutdown
2020.10.27 12:44:10 1: Server shutdown delayed due to d_ccu,d_rpc000207HmIP_RF,myDbLog,Ikea for max 10 sec
2020.10.27 12:44:09 2: HMCCURPCPROC: [d_rpc000207HmIP_RF : 17179] RPC server stopped. Cancel delayed shutdown.
2020.10.27 12:44:09 2: HMCCURPCPROC: [d_rpc000207HmIP_RF : 17179] Stop I/O handling
2020.10.27 12:44:08 2: HMCCURPCPROC: [d_rpc000207HmIP_RF : 17179] RPC server process CB2010000202000207 deleted
2020.10.27 12:44:07 1: HMCCURPCPROC: [d_rpc000207HmIP_RF : 17179] Process CB2010000202000207 with PID=17207 still running. Killing it.
2020.10.27 12:44:07 2: HMCCURPCPROC: [d_rpc000207HmIP_RF : 17207] Number of I/O errors = 0
2020.10.27 12:44:07 1: HMCCURPCPROC: [d_rpc000207HmIP_RF : 17207] RPC server CB2010000202000207 stopped handling connections. PID=17207
2020.10.27 12:44:07 2: HMCCURPCPROC: [d_rpc000207HmIP_RF : 17207] CB2010000202000207 received signal INT
2020.10.27 12:44:05 2: HMCCURPCPROC: [d_rpc000207HmIP_RF : 17207] CB2010000202000207 received signal INT
2020.10.27 12:44:05 1: HMCCURPCPROC: [d_rpc000207HmIP_RF : 17179] Housekeeping called. Cleaning up RPC environment
2020.10.27 12:44:05 2: HMCCURPCPROC: [d_rpc000207HmIP_RF : 17179] Cleaning up immediately
2020.10.27 12:44:05 2: HMCCURPCPROC: [d_rpc000207HmIP_RF : 17179] Sending signal INT to RPC server process CB2010000202000207 with PID=17207
2020.10.27 12:44:05 1: HMCCURPCPROC: [d_rpc000207HmIP_RF : 17179] Callback for RPC server CB2010000202000207 deregistered
2020.10.27 12:44:04 1: HMCCURPCPROC: [d_rpc000207HmIP_RF : 17179] Deregistering RPC server http://192.168.0.202:7420/fh2010 with ID CB2010000202000207 at http://Admin:PWD@192.168.0.207:2010
2020.10.27 12:44:04 1: HMCCURPCPROC: [d_rpc000207HmIP_RF : 17179] Stopping RPC server CB2010000202000207
Titel: Antw:shutdown restart wird immer 2x ausgeführt
Beitrag von: Otto123 am 27 Oktober 2020, 13:08:03
Hi,

schau mal hier hatte ich mal was dazu geschrieben: https://wiki.fhem.de/wiki/Fhem.service_(systemd_unit_file)#Restart_verz.C3.B6gern

Gruß Otto
Titel: Antw:shutdown restart wird immer 2x ausgeführt
Beitrag von: Mitch am 27 Oktober 2020, 13:43:28
Danke Otto, das war es.
Scheint eine "Besonderheit" auf Proxmox zu sein.
Titel: Antw:[gelöst] shutdown restart wird immer 2x ausgeführt
Beitrag von: Wernieman am 27 Oktober 2020, 13:59:13
Nee ... von Systemen mit WatchDog (wie z.B. systemd)
Titel: Antw:[gelöst] shutdown restart wird immer 2x ausgeführt
Beitrag von: Mitch am 27 Oktober 2020, 14:01:50
kann nicht sein, habe mein System 1:1 von Physik auf VM umgezogen.
Hatte auch vorher systemd, ohne Probleme.
Titel: Antw:shutdown restart wird immer 2x ausgeführt
Beitrag von: SamNitro am 27 Oktober 2020, 14:52:48
Zitat von: Mitch am 27 Oktober 2020, 13:43:28
Danke Otto, das war es.
Scheint eine "Besonderheit" auf Proxmox zu sein.


Bei mir läuft FHEM auch auf Proxmox aber in einer VM nicht in einem Container.
Ich hatte das Problem nicht.
Titel: Antw:[gelöst] shutdown restart wird immer 2x ausgeführt
Beitrag von: binford6000 am 27 Oktober 2020, 15:51:12
Hallo,
ich hatte das Phänomen auch beim fhem im Linux Container, nicht aber unter Docker.
Habe es bei mir mit
attr global restartDelay 5
in den Griff bekommen. In /etc/systemd/system/fhem.service hab ich nichts geändert.
VG Sebastian
Titel: Antw:[gelöst] shutdown restart wird immer 2x ausgeführt
Beitrag von: Otto123 am 27 Oktober 2020, 19:15:15
Meine und Sebastian Lösung haken quasi an der gleichen Stelle ein (der Restart wird mehr verzögert als der Standard: 2 sec bei FHEM - 100 ms bei systemd).
Letztlich ist es meiner Meinung nach so ein ganz knapper Laufzeit "Unterschied" im System. Als ich damals experimentiert habe, trat dieser Effekt vermehrt bei Pi4 und Buster auf.

Und das attr global restartDelay kannte ich damals nicht  :-[