shutdown restart, 2mal restart durch gassistant

[CoolTux]

Beginn des Logs in mitten eines Restart-Prozesses nach Eingabe von shutdown restart

Code Auswählen Erweitern

2022.03.29 07:52:36 3: Opening SOCAT_signalDuino device 192.168.240.20:2100
2022.03.29 07:52:36 3: HUEGroup20: I/O device is PhosconGw
2022.03.29 07:52:36 3: Opening SOCAT_HmUART1 device 192.168.240.20:2000
2022.03.29 07:52:36 1: CUL_HM start inital cleanup
2022.03.29 07:52:37 1: CUL_HM finished initial cleanup
2022.03.29 07:52:37 2: NUKIDevice (Haustuer) - GetUpdate Call IOWrite
2022.03.29 07:52:37 3: PhosconGw: websocket opened to 192.168.240.21:443
2022.03.29 07:52:37 2: PhosconGw: autocreate: created 0/0/0 devices (ignored 0/0/0)
2022.03.29 07:52:37 2: NUKIDevice (Wohnungstuer) - GetUpdate Call IOWrite
2022.03.29 07:52:37 2: gAssistant: starting gassistant-fhem: /usr/bin/gassistant-fhem -c ./gassistant-fhem.cfg
2022.03.29 07:52:37 3: gAssistant: starting
2022.03.29 07:52:37 3: gAssistant: using logfile: ./log/gassistant-2022-03-29.log
2022.03.29 07:52:37 3: Opening presenceGast device 192.168.240.20:5333
2022.03.29 07:52:37 3: presenceGast device opened
2022.03.29 07:52:37 3: Opening presenceMarko device 192.168.240.20:5333
2022.03.29 07:52:37 3: presenceMarko device opened
2022.03.29 07:52:37 3: Opening presenceSteven device 192.168.240.20:5333
2022.03.29 07:52:37 3: presenceSteven device opened
2022.03.29 07:52:38 3: backupToStorage (nextcloudBackup) - _CheckIsDisabledAfterSetAttr
2022.03.29 07:52:38 0: Featurelevel: 6.1
2022.03.29 07:52:38 0: Server started with 360 defined entities (fhem.pl:25889/2022-03-27 perl:5.032001 os:linux user:fhem pid:1300797)



!!! Hier ist der Restart abgeschlossen!!!



2022.03.29 07:52:38 3: SOCAT_signalDuino: getAttrDevelopment, IdList ### Attribute development is in this version ignored ###
2022.03.29 07:52:38 3: SOCAT_signalDuino: IdList, attr whitelist disabled or not defined (all IDs are enabled, except blacklisted and instable IDs):
2022.03.29 07:52:38 3: SOCAT_signalDuino: IdList, MS 0 0.1 0.2 0.3 0.4 0.5 1 3 3.1 4 6 7 7.1 13 13.2 14 15 17 20 23 25 33 33.1 33.2 35 41 49 51 53 54.1 55 65 68 74.1 87 88 90 91.1 93 106 113
2022.03.29 07:52:38 3: SOCAT_signalDuino: IdList, MU 8 9 13.1 16 17.1 19 21 22 24 26 27 28 29 30 31 32 34 36 37 38 39 40 42 44 44.1 45 46 48 49.1 49.2 50 54 56 59 60 61 62 64 66 67 69 70 71 72 73 74 76 78 79 80 81 83 84 85 86 89 91 92 94 95 97 98 99 104 105 110 111 114
2022.03.29 07:52:38 3: SOCAT_signalDuino: IdList, MC 10 11 12 18 43 47 52 57 58 96
2022.03.29 07:52:38 3: SOCAT_signalDuino: IdList, MN 100 101 102 103 107 107.1 108 109 112 115 116 116.1
2022.03.29 07:52:38 3: SOCAT_signalDuino: IdList, development protocol is active (to activate dispatch to not finshed logical module, enable desired protocol via whitelistIDs) = 2 72.1 82
2022.03.29 07:52:38 2: DbLog logDbHistory - Last database write cycle due to shutdown ...
2022.03.29 07:52:38 2: DbLog logDbHistory - no data for last database write cycle
2022.03.29 07:52:38 1: Server shutdown delayed due to gAssistant,logDbHistory for max 10 sec
2022.03.29 07:52:38 1: SOCAT_signalDuino: DoInit, 192.168.240.20:2100
2022.03.29 07:52:38 3: SOCAT_signalDuino device opened
2022.03.29 07:52:38 3: SOCAT_HmUART1 device opened
2022.03.29 07:52:38 3: PhosconGw: websocket: Switching Protocols ok
2022.03.29 07:52:38 2: AttrTemplates: got 246 entries
2022.03.29 07:52:38 3: UWZ Unwetterzentrale: UWZ.1811 Done fetching data
2022.03.29 07:52:39 3: SOCAT_signalDuino: SimpleWrite_XQ, disable receiver (XQ)
2022.03.29 07:52:40 3: SOCAT_signalDuino: StartInit, get version, retry = 0
2022.03.29 07:52:40 2: SOCAT_signalDuino: CheckVersionResp, initialized 3.5.3
2022.03.29 07:52:40 3: SOCAT_signalDuino: CheckVersionResp, enable receiver (XE)
2022.03.29 07:52:40 3: NUKIBridge WEBHOOK (NukiBridge) - Received webhook for matching NukiId at IODev NukiBridge
2022.03.29 07:52:40 3: DbLog logDbHistory - Creating Push-Handle to database Pg:database=fhemDbLog;host=p-psql01.tuxnet.lan with user fhem
2022.03.29 07:52:40 3: DbLog logDbHistory - Push-Handle to db Pg:database=fhemDbLog;host=p-psql01.tuxnet.lan created
2022.03.29 07:52:41 3: SOCAT_signalDuino: CheckCcpatableResponse, patable: 84
2022.03.29 07:52:42 3: Opening fhempy_at_hphoscongw device ws:192.168.240.21:15733
2022.03.29 07:52:43 3: fhempy_at_hphoscongw device opened


!!!Warum auch immer erfolgt hier ein shutdown vom gAssistant!!!

2022.03.29 07:52:43 3: gAssistant: stopped
2022.03.29 07:52:48 0: Server shutdown
Und das ganze FHEM wird nochmal neugestartet.
Ich konnte das Verhalten bereits 2 mal beobachten.

[frank]

initiiert wird der shutdown bereits 10s früher:

Code Auswählen Erweitern

2022.03.29 07:52:38 1: Server shutdown delayed due to gAssistant,logDbHistory for max 10 sec

wobei die 2 benannten akteure hier aber zunächst nur für die verzögerung des shutdown verantwortlich sind.

der verursacher für den scheinbar "geplanten" shutdown ist eventuell mit verbose=5 vor dieser zeile zu finden.

[CoolTux]

Das dürfte schwer werden, dazu kommt der Fehler zu selten.

[frank]

Das dürfte schwer werden, dazu kommt der Fehler zu selten.

das heisst der erste shutdown war von dir ausgelöst und nur manchmal gibt es dann den zusätzlichen 2. shutdown?
du könntest mit einem notify auf global:INITIALIZED zb für 2 min global verbose=5 setzen.

[CoolTux]

das heisst der erste shutdown war von dir ausgelöst und nur manchmal gibt es dann den zusätzlichen 2. shutdown?
du könntest mit einem notify auf global:INITIALIZED zb für 2 min global verbose=5 setzen.

Ja der erste shutdown restart war von mir. Nach einem Update.

Ich schaue mal was ich da machen kann.

[Otto123]

Die 2 sec restart in systemd?
https://wiki.fhem.de/wiki/Fhem.service_(systemd_unit_file)#Restart_verz.C3.B6gern

systemd weiß noch nicht das fhem schon läuft? 2022.03.29 07:52:38  - 2022.03.29 07:52:43