[gelöst]FHEM Neustart nach paar Stunden / manchmal ** stack smashing detected **

[thgorjup]

Hallo,
mein FHEM stürzt immer wieder ab und startet neu. Aufgefallen ist mir das, weil einige Werte wie z.B. PRESENCE hin und wieder nicht mehr stimmten und einige HM Geräte auf einmel MISSING ACK meldeten. Durch Eingabe von "uptime" in der FHEM Konsole sehe ich, dass es unregelmäßig alle paar Stunden passiert. Die "uptime" zeigt nie mehr als 20h aber es passiert auch schonmal nach 1-2h. Nach dem Einschalten von verbose 5 habe ich nun ein paar weitere Informationen. Kann mir jemand helfen?

Nicht immer aber manchmal startet FHEM neu nach der Ausgabe von *** stack smashing detected ***: <unknown> terminated

Die Ausgabe Initializing Type Library ist der Anfang vom Neustart.

Code Auswählen Erweitern


2023.02.07 05:11:34 4: Connection accepted from espBridge_10.4.70.108_64519
2023.02.07 05:11:34 4: ESPEasy espBridge_10.4.70.108_64519: Peer address 10.4.70.108 accepted
2023.02.07 05:11:34 4: ESPEasy espBridge_10.4.70.108_64519: Received content length ok
2023.02.07 05:11:34 5: ESPEasy espBridge_10.4.70.108_64519: Received header: {'User-Agent' => 'ESP Easy/20104/Feb  4 2020 22:55:05','Accept' => '*/*;q=0.1','Host' => '10.4.70.158:8383','Con
tent-Length' => 281,'Connection' => 'close'}
2023.02.07 05:11:34 5: ESPEasy espBridge_10.4.70.108_64519: Received content: {"module":"ESPEasy","version":"1.04","data":{"ESP":{"name":"WS","unit":1,"version":2,"build":20104,"build_notes
":" - Mega","build_git":"mega-20200204","node_type_id":17,"sleep":0,"ip":"10.4.70.108"},"SENSOR":{"0":{"deviceName":"Regensensor","valueName":"R","type":1,"value":"6"}}}}
2023.02.07 05:11:34 4: ESPEasy espBridge_10.4.70.108_64519: No basic authentication required
2023.02.07 05:11:34 4: ESPEasy espBridge_10.4.70.108_64519: Send http close '200 OK'
2023.02.07 05:11:34 4: ESPEasy espBridge_10.4.70.108_64519: Src:'WS'/'Regensensor' => ident:WS_Regensensor dev:ESPEasy_WS_Regensensor combinedDevice:0
2023.02.07 05:11:34 5: espBridge: dispatch WS_Regensensor::10.4.70.108::1::0::1::i||unit||1||0|||i||sleep||0||0|||i||build||20104||0|||i||build_git||mega-20200204||0|||i||build_notes|| - Me
ga||0|||i||version||2||0|||i||node_type_id||17||0|||r||R||6||1
2023.02.07 05:11:34 5: ESPEasy ESPEasy_WS_Regensensor: Received: WS_Regensensor::10.4.70.108::1::0::1::i||unit||1||0|||i||sleep||0||0|||i||build||20104||0|||i||build_git||mega-20200204||0||
|i||build_notes|| - Mega||0|||i||version||2||0|||i||node_type_id||17||0|||r||R||6||1
2023.02.07 05:11:34 4: ESPEasy ESPEasy_WS_Regensensor: R: 6
2023.02.07 05:11:34 5: ESPEasy ESPEasy_WS_Regensensor: Internals: unit:ESP Easy sleep:0 build:20104 build_git:mega-20200204 build_notes: - Mega version:2 node_type_id:ESP Easy Mega
2023.02.07 05:11:35 5: Starting notify loop for ESPEasy_WS_Regensensor, 2 event(s), first is R: 6
2023.02.07 05:11:35 4: DbLog DBLOG - check Device: ESPEasy_WS_Regensensor , Event: R: 6
2023.02.07 05:11:35 5: DbLog DBLOG - parsed Event: ESPEasy_WS_Regensensor , Event: R: 6
2023.02.07 05:11:35 4: DbLog DBLOG - added event - Timestamp: 2023-02-07 05:11:35, Device: ESPEasy_WS_Regensensor, Type: ESPEASY, Event: R: 6, Reading: R, Value: 6, Unit:
2023.02.07 05:11:35 4: DbLog DBLOG - check Device: ESPEasy_WS_Regensensor , Event: raincount: 67
2023.02.07 05:11:35 5: DbLog DBLOG - TempStore contains:  12823 -> 2023-02-07 05:11:35|ESPEasy_WS_Regensensor|ESPEASY|R: 6|R|6|
2023.02.07 05:11:35 5: End notify loop for ESPEasy_WS_Regensensor
2023.02.07 05:11:35 4: DbLog DBLOG - Primary Key used in history: none
2023.02.07 05:11:35 4: DbLog DBLOG - Primary Key used in current: none
*** stack smashing detected ***: <unknown> terminated
2023.02.07 05:13:06 5: Initializing Type Library:
2023.02.07 05:13:06 1: Including fhem.cfg
2023.02.07 05:13:06 5: Cmd: >attr global userattr DbLogExclude DbLogInclude DbLogValueFn:textField-long alarmDevice alarmSettings cmdIcon devStateIcon devStateIcon:textField-long devStateStyle fm_type genericDeviceType:switch,outlet,light,blind,speaker,thermostat homebridgeMapping:textField-long icon sortby webCmd webCmdLabel:textField-long widgetOverride<
2023.02.07 05:13:06 5: Cmd: >attr global autoload_undefined_devices 1<
2023.02.07 05:13:06 5: Cmd: >attr global autosave 0<
2023.02.07 05:13:06 5: Cmd: >attr global latitude 50.052633<
2023.02.07 05:13:06 5: Cmd: >attr global logfile ./log/fhem-%Y-%m.log<
2023.02.07 05:13:06 5: Cmd: >attr global longitude 8.792675<
2023.02.07 05:13:06 5: Cmd: >attr global modpath .<
2023.02.07 05:13:06 5: Loading ./FHEM/99_FritzboxCallUtils.pm
2023.02.07 05:13:06 1: PERL WARNING: Subroutine FritzBoxCallUtils_Initialize redefined at ./FHEM/99_FritzboxCallUtils.pm line 10, <$fh> line 7.
2023.02.07 05:13:06 1: PERL WARNING: Subroutine FBAnrufer_vorlesen redefined at ./FHEM/99_FritzboxCallUtils.pm line 14, <$fh> line 7.
2023.02.07 05:13:06 1: PERL WARNING: Subroutine FBAnrufer_pushover redefined at ./FHEM/99_FritzboxCallUtils.pm line 41, <$fh> line 7.
2023.02.07 05:13:06 5: Loading ./FHEM/99_myAbfallKalender.pm
2023.02.07 05:13:06 1: PERL WARNING: Subroutine myUtils_Initialize redefined at ./FHEM/99_myAbfallKalender.pm line 15, <$fh> line 7.
2023.02.07 05:13:06 5: Loading ./FHEM/99_myUtils.pm



Aber dann auch mal ohne einen Hinweis:

Code Auswählen Erweitern


2023.02.07 00:58:45 4: http://10.4.70.106/web/timerlist: HTTP response code 200
2023.02.07 00:58:45 5: HttpUtils http://10.4.70.106/web/timerlist: Got data, length: 68
2023.02.07 00:58:45 5: HttpUtils response header:
HTTP/1.1 200 OK
Transfer-Encoding: chunked
Date: Mon, 06 Feb 2023 23:58:44 GMT
Connection: close
Content-Type: text/xml
Server: TwistedWeb/13.2.0
2023.02.07 00:58:45 5: ENIGMA2 Wz.TvReceiver: called function ENIGMA2_ReceiveCommand()
2023.02.07 00:58:45 4: ENIGMA2 Wz.TvReceiver: RCV timerlist
2023.02.07 00:58:45 5: ENIGMA2 Wz.TvReceiver: RES timerlist
<?xml version="1.0" encoding="UTF-8"?>
<e2timerlist>
</e2timerlist>

2023.02.07 00:58:45 5: ENIGMA2 Wz.TvReceiver: timerlist seems to be empty
2023.02.07 00:58:45 4: ESPEasy ESPEasy_WS_Regensensor: set statusRequest
2023.02.07 00:58:46 5: Starting notify loop for ESPEasy_WS_Regensensor, 2 event(s), first is presence: present
2023.02.07 00:58:46 4: DbLog DBLOG - check Device: ESPEasy_WS_Regensensor , Event: presence: present
2023.02.07 00:58:46 4: DbLog DBLOG - check Device: ESPEasy_WS_Regensensor , Event: raincount: 116
2023.02.07 00:58:46 5: End notify loop for ESPEasy_WS_Regensensor
2023.02.07 00:58:46 4: ESPEasy ESPEasy_WS_Regensensor: presence: present
2023.02.07 01:00:16 5: Initializing Type Library:
2023.02.07 01:00:16 1: Including fhem.cfg
2023.02.07 01:00:16 5: Cmd: >attr global userattr DbLogExclude DbLogInclude DbLogValueFn:textField-long alarmDevice alarmSettings cmdIcon devStateIcon devStateIcon:textField-long devStateStyle fm_type genericDeviceType:switch,outlet,light,blind,speaker,thermostat homebridgeMapping:textField-long icon sortby webCmd webCmdLabel:textField-long widgetOverride<
2023.02.07 01:00:16 5: Cmd: >attr global autoload_undefined_devices 1<
2023.02.07 01:00:16 5: Cmd: >attr global autosave 0<
2023.02.07 01:00:16 5: Cmd: >attr global latitude 50.052633<
2023.02.07 01:00:16 5: Cmd: >attr global logfile ./log/fhem-%Y-%m.log<
2023.02.07 01:00:16 5: Cmd: >attr global longitude 8.792675<
2023.02.07 01:00:16 5: Cmd: >attr global modpath .<
2023.02.07 01:00:16 5: Loading ./FHEM/99_FritzboxCallUtils.pm
2023.02.07 01:00:16 1: PERL WARNING: Subroutine FritzBoxCallUtils_Initialize redefined at ./FHEM/99_FritzboxCallUtils.pm line 10, <$fh> line 7.
2023.02.07 01:00:16 1: PERL WARNING: Subroutine FBAnrufer_vorlesen redefined at ./FHEM/99_FritzboxCallUtils.pm line 14, <$fh> line 7.
2023.02.07 01:00:16 1: PERL WARNING: Subroutine FBAnrufer_pushover redefined at ./FHEM/99_FritzboxCallUtils.pm line 41, <$fh> line 7.
2023.02.07 01:00:16 5: Loading ./FHEM/99_myAbfallKalender.pm
2023.02.07 01:00:16 1: PERL WARNING: Subroutine myUtils_Initialize redefined at ./FHEM/99_myAbfallKalender.pm line 15, <$fh> line 7.
2023.02.07 01:00:16 5: Loading ./FHEM/99_myUtils.pm


Danke und Gruß
Thomas

[thgorjup]

Hier nochmal eine kleine Auswertung der letzten Tage.
Ein paar waren manuelle Neustarts von mir "shutdown restart" aber die meisten haben automatisch stattgefunden.

Code Auswählen Erweitern


root@fhem:/var/log/fhem# grep --text "Including fhem.cfg" fhem-2023-02.log
2023.02.01 05:19:02 1: Including fhem.cfg
2023.02.01 07:42:43 1: Including fhem.cfg
2023.02.01 10:11:22 1: Including fhem.cfg
2023.02.02 20:09:03 1: Including fhem.cfg
2023.02.03 03:34:04 1: Including fhem.cfg
2023.02.03 09:10:40 1: Including fhem.cfg
2023.02.03 17:04:03 1: Including fhem.cfg
2023.02.04 01:38:04 1: Including fhem.cfg
2023.02.04 02:00:17 1: Including fhem.cfg
2023.02.04 13:19:36 1: Including fhem.cfg
2023.02.04 19:38:04 1: Including fhem.cfg
2023.02.04 21:26:07 1: Including fhem.cfg
2023.02.04 22:43:15 1: Including fhem.cfg
2023.02.05 04:28:05 1: Including fhem.cfg
2023.02.06 03:36:15 1: Including fhem.cfg
2023.02.06 07:31:37 1: Including fhem.cfg
2023.02.06 09:48:05 1: Including fhem.cfg
2023.02.07 01:00:16 1: Including fhem.cfg
2023.02.07 05:13:06 1: Including fhem.cfg


[thgorjup]

Ich bin dahinter gekommen. Mein service für den Landroid Rasenmäher scheint das Problem zu verursachen.
Ich frag mich allerdings, warum der Service ärgere macht?

Code Auswählen Erweitern


Feb  7 23:17:12 iobroker01 pm2[30646]: [PM2] PM2 Successfully daemonized
Feb  7 23:17:12 iobroker01 pm2[30646]: [PM2] Resurrecting
Feb  7 23:17:12 iobroker01 pm2[30646]: [PM2] Restoring processes located in /root/.pm2/dump.pm2
Feb  7 23:17:12 iobroker01 pm2[30646]: [PM2] Process /opt/landroid/fhem-landroid-s/LandroidSrv.js restored
Feb  7 23:17:12 iobroker01 pm2[30646]: ┌─────┬────────────────┬─────────────┬─────────┬─────────┬──────────┬────────┬──────┬───────────┬──────────┬──────────┬──────────┬──────────┐
Feb  7 23:17:12 iobroker01 pm2[30646]: │ id  │ name           │ namespace   │ version │ mode    │ pid      │ uptime │ ↺    │ status    │ cpu      │ mem      │ user     │ watching │
Feb  7 23:17:12 iobroker01 pm2[30646]: ├─────┼────────────────┼─────────────┼─────────┼─────────┼──────────┼────────┼──────┼───────────┼──────────┼──────────┼──────────┼──────────┤
Feb  7 23:17:12 iobroker01 pm2[30646]: │ 0   │ LandroidSrv    │ default     │ N/A     │ fork    │ N/A      │ 0      │ 27   │ stopped   │ 0%       │ 0b       │ root     │ disabled │
Feb  7 23:17:12 iobroker01 pm2[30646]: └─────┴────────────────┴─────────────┴─────────┴─────────┴──────────┴────────┴──────┴───────────┴──────────┴──────────┴──────────┴──────────┘
Feb  7 23:17:12 iobroker01 systemd[1]: pm2-root.service: Can't open PID file /root/.pm2/pm2.pid (yet?) after start: No such file or directory
Feb  7 23:18:05 iobroker01 systemd[1]: fhem.service: State 'stop-sigterm' timed out. Killing.
Feb  7 23:18:05 iobroker01 systemd[1]: fhem.service: Killing process 25584 (perl) with signal SIGKILL.
Feb  7 23:18:05 iobroker01 systemd[1]: fhem.service: Failed with result 'core-dump'.
Feb  7 23:18:06 iobroker01 systemd[1]: fhem.service: Service hold-off time over, scheduling restart.
Feb  7 23:18:06 iobroker01 systemd[1]: fhem.service: Scheduled restart job, restart counter is at 4.
Feb  7 23:18:06 iobroker01 systemd[1]: Stopped FHEM Home Automation.
Feb  7 23:18:06 iobroker01 systemd[1]: Starting FHEM Home Automation...
Feb  7 23:18:06 iobroker01 systemd[1]: Started FHEM Home Automation.
Feb  7 23:18:41 iobroker01 systemd[1]: pm2-root.service: Start operation timed out. Terminating.
Feb  7 23:18:41 iobroker01 systemd[1]: pm2-root.service: Failed with result 'timeout'.
Feb  7 23:18:41 iobroker01 systemd[1]: Failed to start PM2 process manager.
Feb  7 23:18:42 iobroker01 systemd[1]: pm2-root.service: Service hold-off time over, scheduling restart.
Feb  7 23:18:42 iobroker01 systemd[1]: pm2-root.service: Scheduled restart job, restart counter is at 4436.
Feb  7 23:18:42 iobroker01 systemd[1]: Stopped PM2 process manager.
Feb  7 23:18:42 iobroker01 systemd[1]: Starting PM2 process manager...
Feb  7 23:18:42 iobroker01 pm2[30760]: [PM2] Spawning PM2 daemon with pm2_home=/root/.pm2


[thgorjup]

Problem behoben. Letztendlich lag es an einer corrupten sqlite3 Datenbank.
Datenbank gelöscht, neu angelegt und es läuft jetzt wieder seit 4 tagen ohne Neustart.

Code Auswählen Erweitern


# DB anlegen
sqlite3 fhem.db
CREATE TABLE 'history' (TIMESTAMP TIMESTAMP, DEVICE varchar(64), TYPE varchar(64), EVENT varchar(512), READING varchar(64), VALUE varchar(128), UNIT varchar(32));
CREATE TABLE 'current' (TIMESTAMP TIMESTAMP, DEVICE varchar(64), TYPE varchar(64), EVENT varchar(512), READING varchar(64), VALUE varchar(128), UNIT varchar(32));
CREATE INDEX Search_Idx ON `history` (DEVICE, READING, TIMESTAMP);