Fhem stürzt ab oder bleibt hängen

Michi240281 · 16 Juli 2018, 18:27:40

Hallo zusammen,

mein Fhem läuft in einer VM auf meinem QNAP TVS463. Seit ca. 2 Jahren keinerlei Probleme.

Seit einigen Tagen stürzt Fhem alle paar Stunden unerklärlicherweise ab. Ich habe nichts am System geändert, nur das GDS define, das ich noch hatte disabled.

Hier ein Log mit den letzten Einträgen beim Absturz:

Code Auswählen

2018.07.16 09:39:02.478 5: HMLAN_Parse: HMLAN1 R:E2C90B9   stat:0000 t:09468D04 d:FF r:FFBD     m:31 845E 2C90B9 000000 820B680000000000091EFE
2018.07.16 09:39:02.478 5: HMLAN1 dispatch A1431845E2C90B9000000820B680000000000091EFE::-67:HMLAN1
2018.07.16 09:39:02.483 5: Triggering Steckdose_Frostwaechter_Messkanal (5 changes)
2018.07.16 09:39:02.483 5: Starting notify loop for Steckdose_Frostwaechter_Messkanal, first event current: 0
2018.07.16 09:39:02.536 5: Unifi_Controller (Unifi_DoUpdate) - executed.
2018.07.16 09:39:02.537 5: Unifi_Controller (Unifi_GetWlans_Send) - executed.
2018.07.16 09:39:02.537 5: HttpUtils url=https://192.168.188.100:8443/api/s/default/list/wlanconf
2018.07.16 09:39:02.563 5: https://192.168.188.100:8443/api/s/default/list/wlanconf: HTTP response code 200
2018.07.16 09:39:02.564 5: HttpUtils https://192.168.188.100:8443/api/s/default/list/wlanconf: Got data, length: 1771
2018.07.16 09:39:02.564 5: Unifi_Controller (Unifi_GetWlans_Receive) - executed.
2018.07.16 09:39:02.564 5: Unifi_Controller (Unifi_GetWlans_Receive) - state:'ok'
2018.07.16 09:39:02.564 5: Unifi_Controller (Unifi_GetHealth_Send) - executed.
2018.07.16 09:39:02.564 5: HttpUtils url=https://192.168.188.100:8443/api/s/default/stat/health
2018.07.16 09:39:02.587 5: https://192.168.188.100:8443/api/s/default/stat/health: HTTP response code 200
2018.07.16 09:39:02.587 5: HttpUtils https://192.168.188.100:8443/api/s/default/stat/health: Got data, length: 624
2018.07.16 09:39:02.587 5: Unifi_Controller (Unifi_GetHealth_Receive) - executed.
2018.07.16 09:39:02.587 5: Unifi_Controller (Unifi_GetHealth_Receive) - state:'ok'
2018.07.16 09:39:02.587 5: Unifi_Controller (Unifi_GetClients_Send) - executed.
2018.07.16 09:39:02.587 5: HttpUtils url=https://192.168.188.100:8443/api/s/default/stat/sta
2018.07.16 09:39:02.609 5: https://192.168.188.100:8443/api/s/default/stat/sta: HTTP response code 200
2018.07.16 09:39:02.609 5: HttpUtils https://192.168.188.100:8443/api/s/default/stat/sta: Got data, length: 7902
2018.07.16 09:39:02.609 5: Unifi_Controller (Unifi_GetClients_Receive) - executed.
2018.07.16 09:39:02.610 5: Unifi_Controller (Unifi_GetClients_Receive) - state:'ok'
2018.07.16 09:39:02.610 5: Unifi_Controller (Unifi_GetUnarchivedAlerts_Send) - executed.
2018.07.16 09:39:02.610 5: HttpUtils url=https://192.168.188.100:8443/api/s/default/list/alarm
2018.07.16 09:39:02.633 5: https://192.168.188.100:8443/api/s/default/list/alarm: HTTP response code 200
2018.07.16 09:39:02.633 5: HttpUtils https://192.168.188.100:8443/api/s/default/list/alarm: Got data, length: 9903
2018.07.16 09:39:02.634 5: Unifi_Controller (Unifi_GetUnarchivedAlerts_Receive) - executed.
2018.07.16 09:39:02.634 5: Unifi_Controller (Unifi_GetUnarchivedAlerts_Receive) - state:'ok'
2018.07.16 09:39:02.635 5: Unifi_Controller (Unifi_GetAccesspoints_Send) - executed.
2018.07.16 09:39:02.635 5: HttpUtils url=https://192.168.188.100:8443/api/s/default/stat/device
2018.07.16 09:39:02.664 5: https://192.168.188.100:8443/api/s/default/stat/device: HTTP response code 200
2018.07.16 09:39:02.664 5: HttpUtils https://192.168.188.100:8443/api/s/default/stat/device: Got data, length: 45282
2018.07.16 09:39:02.664 5: Unifi_Controller (Unifi_GetAccesspoints_Receive) - executed.
2018.07.16 09:39:02.667 5: Unifi_Controller (Unifi_GetAccesspoints_Receive) - state:'ok'
2018.07.16 09:39:02.669 5: Unifi_Controller (Unifi_GetEvents_Send) - executed.
2018.07.16 09:39:02.669 5: HttpUtils url=https://192.168.188.100:8443/api/s/default/stat/event
2018.07.16 09:39:02.759 5: https://192.168.188.100:8443/api/s/default/stat/event: HTTP response code 200
2018.07.16 09:39:02.759 5: HttpUtils https://192.168.188.100:8443/api/s/default/stat/event: Got data, length: 368055
2018.07.16 09:39:02.759 5: Unifi_Controller (Unifi_GetEvents_Receive) - executed.
2018.07.16 09:39:02.773 5: Unifi_Controller (Unifi_GetEvents_Receive) - state:'ok'
2018.07.16 09:39:02.780 5: Unifi_Controller (Unifi_ProcessUpdate) - executed after 0.2437 seconds.
2018.07.16 09:39:02.781 5: Unifi_Controller (Unifi_SetHealthReadings) - executed.
2018.07.16 09:39:02.782 5: Unifi_Controller (Unifi_SetClientReadings) - executed.
2018.07.16 09:39:02.786 5: Unifi_Controller (Unifi_SetAccesspointReadings) - executed.
2018.07.16 09:39:02.788 5: Unifi_Controller (Unifi_ProcessUpdate) - finished after 0.2521 seconds.
2018.07.16 09:39:04.921 5: SYSMON sysmon: updateReadings.1056 
2018.07.16 09:39:04.930 4: BlockingCall (SYSMON_blockingCall): created child (31140), uses telnetPort to connect back
2018.07.16 09:39:04.948 5: SYSMON sysmon: blockingCall.950 sysmon, 
2018.07.16 09:39:04.949 5: SYSMON sysmon: Exec_Local.4093 Execute 'cat /proc/uptime'
2018.07.16 09:39:04.957 5: SYSMON Qnap463: updateReadings.1056 
2018.07.16 09:39:04.967 5: SYSMON sysmon: Exec_Local.4106 Result '221079.24 429560.17'
2018.07.16 09:39:04.969 5: SYSMON sysmon: Exec_Local.4093 Execute 'cat /proc/loadavg'
2018.07.16 09:39:04.971 4: BlockingCall (SYSMON_blockingCall): created child (31142), uses telnetPort to connect back
2018.07.16 09:39:04.989 5: SYSMON sysmon: Exec_Local.4106 Result '0.09 0.08 0.02 2/1120 31143'
2018.07.16 09:39:04.990 5: SYSMON sysmon: Exec_Local.4093 Execute 'cat /proc/stat'
2018.07.16 09:39:04.994 5: [My_Twilight] Original weather readings
2018.07.16 09:39:04.996 5: [My_Twilight] removing Timer: My_Twilight_sunpos
2018.07.16 09:39:04.997 5: [My_Twilight] setting  Timer: My_Twilight_sunpos 2018-07-16 09:44:04
2018.07.16 09:39:05.009 5: SYSMON Qnap463: blockingCall.950 Qnap463, 
2018.07.16 09:39:05.010 5: SYSMON Qnap463: obtainParameters.1112 Qnap463: Open shared telnet connection
2018.07.16 09:39:05.011 5: SYSMON Qnap463: readPassword.3735 Read password from file
2018.07.16 09:39:05.011 5: SYSMON sysmon: Exec_Local.4098 Result '$VAR1 = 'cpu  844049 4258 224532 42814751 182154 0 6648 2981 0 0
';
$VAR2 = 'cpu0 418976 1690 111578 21468080 38947 0 2614 1206 0 0
';
$VAR3 = 'cpu1 425072 2567 112953 21346670 143206 0 4034 1775 0 0
';
$VAR4 = 'intr 61297461 14 308 0 0 0 0 3 0 1 0 0 0 15 0 0 216012 0 0 0 0 0 0 0 0 0 403898 0 1272307 14 28 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
';
$VAR5 = 'ctxt 114859128
';
$VAR6 = 'btime 1531505665
';
$VAR7 = 'processes 62554
';
$VAR8 = 'procs_running 3
';
$VAR9 = 'procs_blocked 0
';
$VAR10 = 'softirq 19607328 1 6761166 0 4248037 108033 0 329 5041785 0 3447977
';
'
2018.07.16 09:39:05.012 5: SYSMON Qnap463: Open_Connection.3829 Open Telnet connection to 192.168.188.45:13131
2018.07.16 09:39:05.013 5: SYSMON sysmon: Exec_Local.4093 Execute 'free'
2018.07.16 09:39:05.017 5: SYSMON Qnap463: Open_Connection.3843 Wait for user or password prompt.
2018.07.16 09:39:05.024 5: SYSMON Qnap463: Open_Connection.3862 Entering user name
2018.07.16 09:39:05.025 5: SYSMON Qnap463: Open_Connection.3865 Wait for password prompt
2018.07.16 09:39:05.036 5: SYSMON sysmon: Exec_Local.4098 Result '$VAR1 = '              gesamt       benutzt     frei      gemns.  Puffer/Cache verfügbar
';
$VAR2 = 'Speicher:     3047508      856744      115476       26736     2075288     1941452
';
$VAR3 = 'Auslagerungsspeicher:     2095100       13848     2081252
';
'
2018.07.16 09:39:05.037 5: SYSMON sysmon: getNetworkInfo.2653 get eth0:eth0:Ethernet
2018.07.16 09:39:05.037 5: SYSMON sysmon: Exec_Local.4093 Execute 'ifconfig eth0 2>&1'
2018.07.16 09:39:05.055 5: SYSMON sysmon: Exec_Local.4106 Result 'eth0: Fehler beim Auslesen der Schnittstelleninformation: Gerät nicht gefunden'
2018.07.16 09:39:05.056 5: SYSMON sysmon: getNetworkInfo.2665 SYSMON_getNetworkInfo>>>>>>>>>>>>>>>>$VAR1 = 'eth0: Fehler beim Auslesen der Schnittstelleninformation: Gerät nicht gefunden';

2018.07.16 09:39:05.056 5: SYSMON sysmon: getNetworkInfo.2653 get wlan0:wlan0:WiFi
2018.07.16 09:39:05.056 5: SYSMON sysmon: Exec_Local.4093 Execute 'ifconfig wlan0 2>&1'
2018.07.16 09:39:05.063 5: SYSMON Qnap463: Open_Connection.3880 Entering password
2018.07.16 09:39:05.063 5: SYSMON Qnap463: Open_Connection.3883 Wait for command prompt
2018.07.16 09:39:05.076 5: SYSMON sysmon: Exec_Local.4106 Result 'wlan0: Fehler beim Auslesen der Schnittstelleninformation: Gerät nicht gefunden'
2018.07.16 09:39:05.076 5: SYSMON sysmon: getNetworkInfo.2665 SYSMON_getNetworkInfo>>>>>>>>>>>>>>>>$VAR1 = 'wlan0: Fehler beim Auslesen der Schnittstelleninformation: Gerät nicht gefunden';

2018.07.16 09:39:05.103 5: SYSMON Qnap463: Exec_Remote.4050 Execute ''
2018.07.16 09:39:05.143 5: SYSMON Qnap463: Exec_Remote.4050 Execute '[ -d /proc/ ] && echo 1 || echo 0'
2018.07.16 09:39:05.183 5: SYSMON Qnap463: Exec.3995 Result L: '1'
2018.07.16 09:39:05.183 5: SYSMON Qnap463: Exec_Remote.4050 Execute 'cat /proc/uptime'
2018.07.16 09:39:05.223 5: SYSMON Qnap463: Exec.3995 Result L: '1969912.89 7318854.92'
2018.07.16 09:39:05.224 5: SYSMON Qnap463: Exec_Remote.4050 Execute '[ -f /sys/devices/system/cpu/kernel_max ] && echo 1 || echo 0'
2018.07.16 09:39:05.263 5: SYSMON Qnap463: Exec.3995 Result L: '1'
2018.07.16 09:39:05.263 5: SYSMON Qnap463: Exec_Remote.4050 Execute 'cat /sys/devices/system/cpu/kernel_max'
2018.07.16 09:39:05.303 5: SYSMON Qnap463: Exec.3995 Result L: '31'
2018.07.16 09:39:05.304 5: SYSMON Qnap463: obtainParameters.1132 Qnap463: Close shared telnet connection
2018.07.16 09:39:05.304 5: SYSMON Qnap463: Close_Connection.3932 Close Telnet connection

Die nächste Zeile ist dann von gerade eben nach dem Neustart.

Was seltsam ist: Über SSH wird mir bei "service fhem status" angezeigt, dass Fhem noch läuft (active/running).

Jmd ne Idee?

Wäre sehr dankbar für Ratschläge!

FHEM Forum

Fhem stürzt ab oder bleibt hängen

Michi240281