[gelöst: es ist die Engine von mysql] freezes und MQTT?

[andies]

Guten Tag,

ich habe seit einiger Zeit einige freezes im Betrieb und bin auf der Suche nach den Ursachen. Ich habe freeze-Log aktiviert und einen 1,5MB großen Logfile, der detailliert über die Freezes von 1 bis 3 Sekunden berichtet. Die interessieren mich aber nicht, das sind Kollateralschäden. In der Log-Datei habe ich nun Einträge der Form

Code Auswählen Erweitern

11:27:50 1: [Freezemon] freezemon: possible freeze starting at 11:22:19, delay is 330.704 possibly caused by: tmr-MQTT2_SERVER_keepaliveChecker(Mosquitto) tmr-HMUARTLGW_CheckCmdResp(WLAN_HmUART)
11:28:13 1: [Freezemon] freezemon: possible freeze starting at 11:27:50, delay is 23.233 possibly caused by: tmr-HMUARTLGW_CheckCredits(WLAN_HmUART) tmr-HMUARTLGW_CheckCredits(WLAN_HmUART2) tmr-Shelly_status(ShellyVintage) tmr-DbLog_execmemcache(DbLog) tmr-YAAHM_checkstate(Profil_check) tmr-VZLOGGER_StatusTimer(N/A) tmr-SIGNALduino_KeepAlive(sduino) tmr-CODE(0x6b9d8c0)(GetUpdate) tmr-FW_closeInactiveClients(N/A) tmr-CODE(0x6b9d8c0)(GetUpdate) tmr-FBAHAHTTP_Poll(fritzbox) tmr-CODE(0x6b9d8c0)(GetUpdate) tmr-CODE(0x6b9d8c0)(GetUpdate) tmr-CODE(0x6b9d8c0)(GetUpdate) tmr-CODE(0x6b9d8c0)(GetUpdate) tmr-CODE(0x6b9d8c0)(GetUpdate) tmr-FRITZBOX_Readout_Start(N/A) tmr-vitoconnect_GetUpdate(Hannah) tmr-HttpUtils_TimeoutErr(N/A) tmr-ESPEasy_statusRequest(ESPEasy_ESP_Easy_Fernbedienung_RSSI) tmr-HttpUtils_TimeoutErr(N/A) tmr-ESPEasy_statusRequest(ESPEasy_ESP_Easy_Fernbedienung_drei) tmr-ESPEasy_statusRequest(ESPEasy_ESP_Easy_Fernbedienung_zwei) tmr-ESPEasy_statusRequest(ESPEasy_ESP_Easy_Fernbedienung_eins) tmr-ESPEasy_statusRequest(Viessmann2) tmr-at_Exec(StartUpTimeat) prio-__ANON__(N/A)
11:36:15 1: [Freezemon] freezemon: possible freeze starting at 11:36:01, delay is 14.047 possibly caused by: tmr-HMUARTLGW_CheckCmdResp(WLAN_HmUART) tmr-HMUARTLGW_CheckCmdResp(WLAN_HmUART2)
12:16:24 1: [Freezemon] freezemon: possible freeze starting at 12:16:02, delay is 22.566 possibly caused by: tmr-HMUARTLGW_CheckCredits(WLAN_HmUART) tmr-HMUARTLGW_CheckCredits(WLAN_HmUART2)

und ich kann mir da überhaupt keinen Reim darauf machen? Wie komme ich an mehr Informationen? Selbst im Log steht ja praktisch nichts, was ich nachverfolgen kann?

[rudolfkoenig]

Dass MQTT2_SERVER_keepaliveChecker 5.5 Minuten lang blockiert war, halte ich fuer ein Geruecht, da wird nur pro entferntes Client (der sich nicht an seinem Keepalive gehalten hat) ein Event (nrclient) generiert.

Gibt es auch Probleme ohne freezemon? Es gibt berichte, wo freezemon selbst die Ursache war.
Ansonsten bin ich eher ein Fan von vebose Logs (mit mseclog), auch wenn das muehsamer ist.

[andies]

Ja, leider gibt es (unspezifische) Probleme. Wenn ich am Anfang des Tages die Webseite von FHEM Aufrufe, ,,steht" die Seite. Sie wird im Browser nicht angezeigt und irgendetwas im Hintergrund arbeitet. Nach drei, vier Minuten geht alles wieder - bis dahin kann ich weder Infos anrufen noch devices schalten. Load steigt in der Zeit auf 30-50, normal ist 0.3.

Ich habe leider keinen Anhaltspunkt,welches Gerät ich auf verbose 5 schalten sollte. Wenn ich alles so logge, werde ich schnell auf GB-Logs kommen, das legt dann wiederum meinen Raspi lahm. Die freezemon-Meldungen kamen direkt hintereinander, kann man daraus irgendwas folgern?

[Wernieman]

Load ist nur ein Teil "der Wahrheit". Infos zu Load: https://de.wikipedia.org/wiki/Load. Interessanter eher, was sagt Mem, CPU etc. zu der Zeit?

[sledge]

Ins Blaue:

Die Homematic-Wifi-Gateways? Gutes Wifi überall verfügbar?

Bei der Suche nach Freezes verwende ich ansonsten perfmon / apptime in Kombination. Und ja - Freezes finden ist aufwändig. Aber Freezes von 30 - 330 Sekunden - die findet man idR schneller. Oft hat das Ursachen außerhalb von FHEM (Netzwerk, timeout, etc).

Und bei mir hing schonmal eines der Homematic Gateway... seitdem werden die engmaschig überwacht und bei Bedarf neu gestartet.

[andies]

Inzwischen hatte ich sogar einen freezemon über 5 Minuten, bei dem kein bad guy gefunden wurde. Ich vermute inzwischen auch das Zusammenwirken mehrerer Faktoren und keinen einzelnen Versursacher. Wie Homematic-Gateways stehen da oben an, weil die im Dachboden verbaut sind und manchmal die Verbindung abbricht. Komischerweise bemerke ich solche extremen Freezes aber nur dann, wenn ich nicht vor Ort bin und mit VPN (fritzbox) auf mein System zugreife.

Ich glaube, am Ende muss mir der Zufall zu Hilfe kommen. Ich muss beobachten und schauen, vielleicht hat noch jemand eine Idee, was man so alles anstellen kann. Es liegt jedenfalls nicht direkt an Modul XYZ.

[Wernieman]

Wenn es im Netzwerkbereich liegen sollte ... Monitoring aufsetzen.

Code Auswählen Erweitern

bemerke ich solche extremen Freezes aber nur dann, wenn ich nicht vor Ort bin und mit VPN (fritzbox) auf mein System zugreife.
Wie sieht Dein Netzwerk aus? Flach??
Nicht das es am VPN liegt ....

[andies]

Netzwerk: Fritzbox mit VPN (IPSec, Cisco) und dahinter ist dann das Scheunentor weit offen. Ich verbinde mich mit dem VPN und bin drin.

Angeblich kann Fritzbox Wireguard, das einrichten geht aber nicht bei mir. Da ich momentan nicht zu Hause bin, will ich da keine großen Experimente starten und bleibe bei Cisco, denn das geht.

[andies]

PS Gerade steht er wieder

Code Auswählen Erweitern

top - 11:33:02 up 33 days, 33 min,  3 users,  load average: 15,22, 6,73, 2,80
Tasks: 163 total,   1 running, 162 sleeping,   0 stopped,   0 zombie
%Cpu(s):  1,6 us,  1,6 sy,  0,0 ni, 90,5 id,  6,3 wa,  0,0 hi,  0,0 si,  0,0 st
MiB Mem :    923,5 total,    116,0 free,    645,9 used,    161,6 buff/cache
MiB Swap:    100,0 total,      0,0 free,    100,0 used.    174,0 avail Mem
...
977 fhem      20   0  315644 223072   5724 S  12,9  23,6   2187:05 perl
17820 root      20   0       0      0      0 I   7,9   0,0   0:46.19 kworker/2:3-mm_percpu_wq
17945 pi        20   0   10400   3008   2488 R   1,0   0,3   0:00.41 top
   22 root      20   0       0      0      0 S   0,3   0,0  36:06.87 ksoftirqd/2
2281 signal-+  20   0  374288  80732   2488 S   0,3   8,5  54:01.84 java


[Wernieman]

Code Auswählen Erweitern

%Cpu(s):  1,6 us,  1,6 sy,  0,0 ni, 90,5 id,  6,3 wa,  0,0 hi,  0,0 si,  0,0 st
MiB Mem :    923,5 total,    116,0 free,    645,9 used,    161,6 buff/cache
MiB Swap:    100,0 total,      0,0 free,    100,0 used.    174,0 avail Mem


Was Auffällt:
1. 90,5 id .. d.h. die CPU langweilt sich
2. MiB Swap: ... 0,0 free
Dein System Swaped ... und Swap ist FOLL .. gar nicht gut.
Steht zu der Zeit im /var/log/kern.log etwas interessantes?

Was hast Du denn so am laufen? Kannst Du mal die Top-Ausgabe nach "Mem" Sortieren?

[andies]

Vermutlich Volltreffer, danke. Da steht immer dann, wenn das System "stand":

Code Auswählen Erweitern


===> letzte Zeile aus dem vorigen Stillstand
Dec 28 00:37:49 raspfhem kernel: [2813884.848931] oom_reaper: reaped process 9013 (perl), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
===> und dann geht es los
Dec 28 10:41:10 raspfhem kernel: [2850087.409479] thd invoked oom-killer: gfp_mask=0x1100cca(GFP_HIGHUSER_MOVABLE), order=0, oom_score_adj=0
Dec 28 10:41:10 raspfhem kernel: [2850087.409513] CPU: 2 PID: 362 Comm: thd Tainted: G         C        5.15.32-v7+ #1539
Dec 28 10:41:10 raspfhem kernel: [2850087.409524] Hardware name: BCM2835
Dec 28 10:41:10 raspfhem kernel: [2850087.409529] Backtrace:
Dec 28 10:41:10 raspfhem kernel: [2850087.409537] [<80a3cb94>] (dump_backtrace) from [<80a3cddc>] (show_stack+0x20/0x24)
Dec 28 10:41:10 raspfhem kernel: [2850087.409560]  r7:80d2770c r6:80d175cc r5:00000000 r4:60000113
Dec 28 10:41:10 raspfhem kernel: [2850087.409565] [<80a3cdbc>] (show_stack) from [<80a41314>] (dump_stack_lvl+0x70/0x94)
Dec 28 10:41:10 raspfhem kernel: [2850087.409579] [<80a412a4>] (dump_stack_lvl) from [<80a41350>] (dump_stack+0x18/0x1c)
Dec 28 10:41:10 raspfhem kernel: [2850087.409596]  r7:80d2770c r6:93d17d58 r5:93e6be00 r4:93d17d58
Dec 28 10:41:10 raspfhem kernel: [2850087.409600] [<80a41338>] (dump_stack) from [<80a3f434>] (dump_header+0x68/0x210)
Dec 28 10:41:10 raspfhem kernel: [2850087.409613] [<80a3f3cc>] (dump_header) from [<802c5f68>] (oom_kill_process+0x1b4/0x1c0)
Dec 28 10:41:10 raspfhem kernel: [2850087.409632]  r7:80d2770c r6:93d17d58 r5:00000598 r4:93e6be00
Dec 28 10:41:10 raspfhem kernel: [2850087.409636] [<802c5db4>] (oom_kill_process) from [<802c6ab0>] (out_of_memory+0x2b8/0x390)
Dec 28 10:41:10 raspfhem kernel: [2850087.409653]  r7:80f084c0 r6:80f05008 r5:93e6be00 r4:93d17d58
Dec 28 10:41:10 raspfhem kernel: [2850087.409657] [<802c67f8>] (out_of_memory) from [<8031b9cc>] (__alloc_pages+0x80c/0x1140)
Dec 28 10:41:10 raspfhem kernel: [2850087.409676]  r7:00000000 r6:00000000 r5:00400100 r4:93d16000
Dec 28 10:41:10 raspfhem kernel: [2850087.409680] [<8031b1c0>] (__alloc_pages) from [<802bf868>] (pagecache_get_page+0x174/0x490)
Dec 28 10:41:10 raspfhem kernel: [2850087.409697]  r10:00000406 r9:00000001 r8:92227460 r7:01100cca r6:80f05008 r5:00000044
Dec 28 10:41:10 raspfhem kernel: [2850087.409703]  r4:2d9c0003
Dec 28 10:41:10 raspfhem kernel: [2850087.409706] [<802bf6f4>] (pagecache_get_page) from [<802c0230>] (filemap_fault+0x6ac/0x970)
Dec 28 10:41:10 raspfhem kernel: [2850087.409723]  r10:92efa480 r9:92efa480 r8:92efa480 r7:92227460 r6:80f05008 r5:93d17ec8
Dec 28 10:41:10 raspfhem kernel: [2850087.409728]  r4:92227350
Dec 28 10:41:10 raspfhem kernel: [2850087.409732] [<802bfb84>] (filemap_fault) from [<802fc580>] (__do_fault+0x48/0x198)
Dec 28 10:41:10 raspfhem kernel: [2850087.409752]  r10:93d17fb0 r9:93d17ec8 r8:00000040 r7:00000000 r6:004e2000 r5:91ca88a0
Dec 28 10:41:10 raspfhem kernel: [2850087.409757]  r4:93d17ec8
Dec 28 10:41:10 raspfhem kernel: [2850087.409761] [<802fc538>] (__do_fault) from [<80301a30>] (handle_mm_fault+0xac4/0xe68)
Dec 28 10:41:10 raspfhem kernel: [2850087.409777]  r7:00000000 r6:004e2000 r5:80f05008 r4:00000254
Dec 28 10:41:10 raspfhem kernel: [2850087.409781] [<80300f6c>] (handle_mm_fault) from [<80a4dce4>] (do_page_fault+0x158/0x38c)
Dec 28 10:41:10 raspfhem kernel: [2850087.409799]  r10:00000254 r9:00000000 r8:8245ec40 r7:8245ec00 r6:80000007 r5:004e246c
Dec 28 10:41:10 raspfhem kernel: [2850087.409804]  r4:93d17fb0
Dec 28 10:41:10 raspfhem kernel: [2850087.409808] [<80a4db8c>] (do_page_fault) from [<80114694>] (do_PrefetchAbort+0x48/0x9c)
Dec 28 10:41:10 raspfhem kernel: [2850087.409826]  r10:ffffffff r9:004f8008 r8:93d17fb0 r7:004e246c r6:80a4db8c r5:00000007
Dec 28 10:41:10 raspfhem kernel: [2850087.409831]  r4:80f0af44
Dec 28 10:41:10 raspfhem kernel: [2850087.409835] [<8011464c>] (do_PrefetchAbort) from [<80100fe4>] (ret_from_exception+0x0/0x1c)
Dec 28 10:41:10 raspfhem kernel: [2850087.409848] Exception stack(0x93d17fb0 to 0x93d17ff8)
Dec 28 10:41:10 raspfhem kernel: [2850087.409857] 7fa0:                                     00000004 004f8e74 00000000 00000000
Dec 28 10:41:10 raspfhem kernel: [2850087.409867] 7fc0: 004f8ef0 004f8008 004f8e74 004f8e6c 76fe3968 004f8008 ffffffff 00000000
Dec 28 10:41:10 raspfhem kernel: [2850087.409875] 7fe0: 00000000 7ee43ad8 004e33e4 004e246c 00000010 ffffffff
Dec 28 10:41:10 raspfhem kernel: [2850087.409883]  r8:10c5387d r7:10c5383d r6:ffffffff r5:00000010 r4:004e246c
Dec 28 10:41:10 raspfhem kernel: [2850087.409888] Mem-Info:
Dec 28 10:41:10 raspfhem kernel: [2850087.409895] active_anon:37413 inactive_anon:178194 isolated_anon:0
Dec 28 10:41:10 raspfhem kernel: [2850087.409895]  active_file:117 inactive_file:513 isolated_file:0
Dec 28 10:41:10 raspfhem kernel: [2850087.409895]  unevictable:4 dirty:0 writeback:0
Dec 28 10:41:10 raspfhem kernel: [2850087.409895]  slab_reclaimable:4933 slab_unreclaimable:5473
Dec 28 10:41:10 raspfhem kernel: [2850087.409895]  mapped:1284 shmem:12787 pagetables:2180 bounce:0
Dec 28 10:41:10 raspfhem kernel: [2850087.409895]  kernel_misc_reclaimable:0
Dec 28 10:41:10 raspfhem kernel: [2850087.409895]  free:4060 free_pcp:168 free_cma:130
Dec 28 10:41:10 raspfhem kernel: [2850087.409916] Node 0 active_anon:149652kB inactive_anon:712776kB active_file:468kB inactive_file:2052kB unevictable:16kB isolated(anon):0kB isolated(file):0kB mapped:5136kB dirty:0kB writeback:0kB shmem:51148kB writeback_tmp:0kB kernel_stack:2560kB pagetables:8720kB all_unreclaimable? yes
Dec 28 10:41:10 raspfhem kernel: [2850087.409934] DMA free:16240kB min:16384kB low:20480kB high:24576kB reserved_highatomic:0KB active_anon:149652kB inactive_anon:712776kB active_file:0kB inactive_file:2160kB unevictable:16kB writepending:0kB present:970752kB managed:945680kB mlocked:16kB bounce:0kB free_pcp:672kB local_pcp:0kB free_cma:520kB
Dec 28 10:41:10 raspfhem kernel: [2850087.409954] lowmem_reserve[]: 0 0 0
Dec 28 10:41:10 raspfhem kernel: [2850087.409979] DMA: 574*4kB (UMEC) 213*8kB (UMEC) 122*16kB (UME) 72*32kB (UME) 29*64kB (UME) 24*128kB (UME) 9*256kB (UME) 2*512kB (M) 0*1024kB 0*2048kB 0*4096kB = 16512kB
Dec 28 10:41:10 raspfhem kernel: [2850087.410095] 19938 total pagecache pages
Dec 28 10:41:10 raspfhem kernel: [2850087.410102] 6423 pages in swap cache
Dec 28 10:41:10 raspfhem kernel: [2850087.410108] Swap cache stats: add 69277, delete 62854, find 3241659/3250621
Dec 28 10:41:10 raspfhem kernel: [2850087.410117] Free swap  = 0kB
Dec 28 10:41:10 raspfhem kernel: [2850087.410122] Total swap = 102396kB
Dec 28 10:41:10 raspfhem kernel: [2850087.410128] 242688 pages RAM
Dec 28 10:41:10 raspfhem kernel: [2850087.410134] 0 pages HighMem/MovableOnly
Dec 28 10:41:10 raspfhem kernel: [2850087.410140] 6268 pages reserved
Dec 28 10:41:10 raspfhem kernel: [2850087.410146] 16384 pages cma reserved
Dec 28 10:41:10 raspfhem kernel: [2850087.410152] Tasks state (memory values in pages):
Dec 28 10:41:10 raspfhem kernel: [2850087.410158] [  pid  ]   uid  tgid total_vm      rss pgtables_bytes swapents oom_score_adj name
Dec 28 10:41:10 raspfhem kernel: [2850087.410180] [    150]     0   150     4634       23    22528      210         -1000 systemd-udevd
Dec 28 10:41:10 raspfhem kernel: [2850087.410195] [    349]   102   349     4782       51    26624      170             0 systemd-resolve
Dec 28 10:41:10 raspfhem kernel: [2850087.410208] [    350]     0   350     1927        0    16384      769             0 haveged
Dec 28 10:41:10 raspfhem kernel: [2850087.410221] [    352]   100   352     5595       45    22528      125             0 systemd-timesyn
Dec 28 10:41:10 raspfhem kernel: [2850087.410234] [    356]     0   356     6375      220    18432       64             0 rsyslogd
Dec 28 10:41:10 raspfhem kernel: [2850087.410245] [    362] 65534   362     1079        5    12288       39             0 thd
Dec 28 10:41:10 raspfhem kernel: [2850087.410258] [    365]     0   365     2930       13    20480      140             0 alsactl
Dec 28 10:41:10 raspfhem kernel: [2850087.410270] [    367]     0   367     3280       58    20480      124             0 systemd-logind
Dec 28 10:41:10 raspfhem kernel: [2850087.410283] [    368]   108   368     1503      107    14336       31             0 avahi-daemon
Dec 28 10:41:10 raspfhem kernel: [2850087.410296] [    369]   104   369     1774      172    14336       66          -900 dbus-daemon
Dec 28 10:41:10 raspfhem kernel: [2850087.410309] [    371]     0   371    15796      222    43008      240             0 udisksd
Dec 28 10:41:10 raspfhem kernel: [2850087.410321] [    372]     0   372     2677       12    18432       89             0 wpa_supplicant
Dec 28 10:41:10 raspfhem kernel: [2850087.410334] [    415]   108   415     1441       13    12288       50             0 avahi-daemon
Dec 28 10:41:10 raspfhem kernel: [2850087.410347] [    445]     0   445      707       58    10240       33             0 dhcpcd
Dec 28 10:41:10 raspfhem kernel: [2850087.410359] [    453]     0   453     2156        0    16384       57             0 vncserver-x11-s
Dec 28 10:41:10 raspfhem kernel: [2850087.410372] [    459]     0   459     9674        0    38912     1303             0 unattended-upgr
Dec 28 10:41:10 raspfhem kernel: [2850087.410385] [    471]   114   471    11941      130    38912      591             0 colord
Dec 28 10:41:10 raspfhem kernel: [2850087.410397] [    472]     0   472     9713      197    30720      171             0 polkitd
Dec 28 10:41:10 raspfhem kernel: [2850087.410410] [    480]     0   480     9110      275    36864      419             0 vncserver-x11-c
Dec 28 10:41:10 raspfhem kernel: [2850087.410423] [    537]     0   537     2670       34    18432      113         -1000 sshd
Dec 28 10:41:10 raspfhem kernel: [2850087.410436] [    544]     0   544      533        1     6144       28             0 hciattach
Dec 28 10:41:10 raspfhem kernel: [2850087.410448] [    559]     0   559     2448       38    16384       65             0 bluetoothd
Dec 28 10:41:10 raspfhem kernel: [2850087.410461] [    564]     0   564     6673        0    24576      114             0 bluealsa
Dec 28 10:41:10 raspfhem kernel: [2850087.410474] [    730]     0   730     1993       18    16384       35             0 cron
Dec 28 10:41:10 raspfhem kernel: [2850087.410486] [    744]     0   744     9372       82    28672       92             0 lightdm
Dec 28 10:41:10 raspfhem kernel: [2850087.410498] [    751]     0   751     6913       25    16384       10             0 rngd
Dec 28 10:41:10 raspfhem kernel: [2850087.410510] [    765]     0   765    47829      734   131072     2632             0 Xorg
Dec 28 10:41:10 raspfhem kernel: [2850087.410523] [    766]     0   766     1404        0    14336      110             0 login
Dec 28 10:41:10 raspfhem kernel: [2850087.410535] [    838]     0   838    50641     1529    61440       87             0 apache2
Dec 28 10:41:10 raspfhem kernel: [2850087.410547] [    843]  1000   843     3674       53    24576      218             0 systemd
Dec 28 10:41:10 raspfhem kernel: [2850087.410559] [    846]  1000   846     4215       41    24576      402             0 (sd-pam)
Dec 28 10:41:10 raspfhem kernel: [2850087.410572] [    847]   116   847   258288     7571   202752     1491             0 grafana-server
Dec 28 10:41:10 raspfhem kernel: [2850087.410584] [   1127]   117  1127     3591       14    24576      140             0 exim4
Dec 28 10:41:10 raspfhem kernel: [2850087.410597] [   1136]  1000  1136     2223        2    16384      339             0 bash
Dec 28 10:41:10 raspfhem kernel: [2850087.410609] [   1259]     0  1259     2869        3    22528      119             0 vncagent
Dec 28 10:41:10 raspfhem kernel: [2850087.410622] [   1274]     0  1274     7473       15    28672      157             0 lightdm
Dec 28 10:41:10 raspfhem kernel: [2850087.410634] [   1278]  1000  1278    13744       40    45056      275             0 lxsession
Dec 28 10:41:10 raspfhem kernel: [2850087.410647] [   1286]  1000  1286     1634        5    14336      101             0 dbus-daemon
Dec 28 10:41:10 raspfhem kernel: [2850087.410660] [   1390]  1000  1390     1121       10    14336       62             0 ssh-agent
Dec 28 10:41:10 raspfhem kernel: [2850087.410672] [   1512]  1000  1512    10899        9    30720      155             0 gvfsd
Dec 28 10:41:10 raspfhem kernel: [2850087.410685] [   1517]  1000  1517    13624        8    32768      128             0 gvfsd-fuse
Dec 28 10:41:10 raspfhem kernel: [2850087.410698] [   1522]  1000  1522    15755      257    49152      448             0 openbox
Dec 28 10:41:10 raspfhem kernel: [2850087.410710] [   1526]  1000  1526    11919       79    40960      206             0 lxpolkit
Dec 28 10:41:10 raspfhem kernel: [2850087.410723] [   1531]  1000  1531   103376      988    96256      529             0 lxpanel
Dec 28 10:41:10 raspfhem kernel: [2850087.410735] [   1536]  1000  1536    18230      492    59392      611             0 pcmanfm
Dec 28 10:41:10 raspfhem kernel: [2850087.410748] [   1544]  1000  1544     1121       13    14336       59             0 ssh-agent
Dec 28 10:41:10 raspfhem kernel: [2850087.410760] [   1546]  1000  1546      484        7    10240        6             0 sh
Dec 28 10:41:10 raspfhem kernel: [2850087.410773] [   1550]  1000  1550    80196     1520   192512     1749             0 zenity
Dec 28 10:41:10 raspfhem kernel: [2850087.410786] [   1552]  1000  1552    11608      907    55296     2354             0 applet.py
Dec 28 10:41:10 raspfhem kernel: [2850087.410799] [   1554]  1000  1554     8008      201    38912      344             0 vncserverui
Dec 28 10:41:10 raspfhem kernel: [2850087.410811] [   1580]  1000  1580    89566      143    38912      161             0 pulseaudio
Dec 28 10:41:10 raspfhem kernel: [2850087.410824] [   1592]   111  1592     5796       18    20480       42             0 rtkit-daemon
Dec 28 10:41:10 raspfhem kernel: [2850087.410836] [   1597]  1000  1597     8079      212    40960      259             0 vncserverui
Dec 28 10:41:10 raspfhem kernel: [2850087.410849] [   1602]  1000  1602     6607       19    20480       92             0 menu-cached
Dec 28 10:41:10 raspfhem kernel: [2850087.410861] [   1607]  1000  1607    19932      121    45056      217             0 gvfs-udisks2-vo
Dec 28 10:41:10 raspfhem kernel: [2850087.410873] [   1611]  1000  1611    10071       27    32768      108             0 gvfs-mtp-volume
Dec 28 10:41:10 raspfhem kernel: [2850087.410886] [   1615]  1000  1615    10072        5    32768      120             0 gvfs-goa-volume
Dec 28 10:41:10 raspfhem kernel: [2850087.410899] [   1619]  1000  1619    10463       12    28672      148             0 gvfs-gphoto2-vo
Dec 28 10:41:10 raspfhem kernel: [2850087.410911] [   1626]  1000  1626    14053       35    38912      153             0 gvfs-afc-volume
Dec 28 10:41:10 raspfhem kernel: [2850087.410924] [   1633]  1000  1633    13325       58    36864      156             0 gvfsd-trash
Dec 28 10:41:10 raspfhem kernel: [2850087.410936] [   2281]  1001  2281    93572    19561   143360     1375             0 java
Dec 28 10:41:10 raspfhem kernel: [2850087.410948] [    977]   999   977    78911    54322   301056     4901             0 perl
Dec 28 10:41:10 raspfhem kernel: [2850087.410961] [  19459]   110 19459   187323    55417   335872        0             0 mysqld
Dec 28 10:41:10 raspfhem kernel: [2850087.410974] [   4274]     0  4274     8818      703    59392        0             0 systemd-journal
Dec 28 10:41:10 raspfhem kernel: [2850087.410987] [   9672]    33  9672    50647      939    51200       87             0 apache2
Dec 28 10:41:10 raspfhem kernel: [2850087.410999] [   9673]    33  9673    50647      939    51200       87             0 apache2
Dec 28 10:41:10 raspfhem kernel: [2850087.411012] [   9674]    33  9674    50647      939    51200       87             0 apache2
Dec 28 10:41:10 raspfhem kernel: [2850087.411025] [   9675]    33  9675    50647      939    51200       87             0 apache2
Dec 28 10:41:10 raspfhem kernel: [2850087.411037] [   9676]    33  9676    50647      939    51200       87             0 apache2
Dec 28 10:41:10 raspfhem kernel: [2850087.411053] [  17390]   999 17390    78911    55658   299008     3565             0 perl
Dec 28 10:41:10 raspfhem kernel: [2850087.411066] [  17391]   999 17391    78911    55667   299008     3581             0 perl
Dec 28 10:41:10 raspfhem kernel: [2850087.411078] [  17392]   999 17392    78911    55659   299008     3564             0 perl
Dec 28 10:41:10 raspfhem kernel: [2850087.411091] [  17393]   999 17393    78911    55656   299008     3567             0 perl
Dec 28 10:41:10 raspfhem kernel: [2850087.411103] oom-kill:constraint=CONSTRAINT_NONE,nodemask=(null),cpuset=/,mems_allowed=0,global_oom,task_memcg=/,task=perl,pid=17391,uid=999
Dec 28 10:41:10 raspfhem kernel: [2850087.411160] Out of memory: Killed process 17391 (perl) total-vm:315644kB, anon-rss:222668kB, file-rss:0kB, shmem-rss:0kB, UID:999 pgtables:292kB oom_score_adj:0
Dec 28 10:41:10 raspfhem kernel: [2850087.465156] oom_reaper: reaped process 17391 (perl), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB

Leider kenne ich mich diesen Sachen nicht aus. Wie genau ist das zu interpretieren oder wo kann ich mehr nachlesen?

[andies]

PS Ich konnte in top nicht nach Speicher sortieren. Dann habe ich  htop genommen:

Code Auswählen Erweitern


Linux raspfhem 5.15.32-v7+ #1539 SMP Fri Apr 1 11:38:09 BST 2022 armv7l

The programs included with the Debian GNU/Linux system are free software;
the exact distribution terms for each program are described in the
individual files in /usr/share/doc/*/copyright.

Debian GNU/Linux comes with ABSOLUTELY NO WARRANTY, to the extent
permitted by applicable law.
Last login: Wed Dec 28 11:32:50 2022 from 192.168.2.243

SSH is enabled and the default password for the 'pi' user has not been changed.
This is a security risk - please login as the 'pi' user and type 'passwd' to set a new password.

dpi@raspfhem:~ $ df -h
Dateisystem                         Größe Benutzt Verf. Verw% Eingehängt auf
/dev/root                            287G     13G  260G    5% /
devtmpfs                             430M       0  430M    0% /dev
tmpfs                                462M       0  462M    0% /dev/shm
tmpfs                                462M     47M  416M   11% /run
tmpfs                                5,0M    4,0K  5,0M    1% /run/lock
tmpfs                                462M       0  462M    0% /sys/fs/cgroup
/dev/sda1                            253M     51M  202M   21% /boot
ds218.fritz.box:/volume1/FHEMBackup  5,3T    1,3T  4,0T   25% /media
tmpfs                                 93M    4,0K   93M    1% /run/user/1000
pi@raspfhem:~ $ mem
-bash: mem: Kommando nicht gefunden.
pi@raspfhem:~ $ top

top - 12:04:23 up 33 days,  1:04,  3 users,  load average: 4,81, 5,03, 2,64
top - 12:04:26 up 33 days,  1:04,  3 users,  load average: 4,81, 5,03, 2,64
top - 12:05:16 up 33 days,  1:05,  3 users,  load average: 2,35, 4,32, 2,52
Tasks: 162 total,   1 running, 161 sleeping,   0 stopped,   0 zombie
%Cpu(s):  2,1 us,  1,7 sy,  0,0 ni, 96,3 id,  0,0 wa,  0,0 hi,  0,0 si,  0,0 st
MiB Mem :    923,5 total,     90,0 free,    649,2 used,    184,3 buff/cache
MiB Swap:    100,0 total,      0,0 free,    100,0 used.    170,6 avail Mem

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND                                                                   
   78 root       0 -20       0      0      0 I   0,0   0,0   0:00.00 zswap-shrink                                                             
1550 pi        20   0  320784   6080      0 S   0,0   0,6   0:01.79 zenity                                                                   
   66 root       0 -20       0      0      0 I   0,0   0,0   0:00.00 xprtiod                                                                   
   40 root       0 -20       0      0      0 I   0,0   0,0   0:00.00 writeback                                                                 
  372 root      20   0   10708    300    252 S   0,0   0,0   0:25.74 wpa_supplicant                                                           
   61 root     -51   0       0      0      0 S   0,0   0,0   0:00.00 watchdogd                                                                 
1554 pi        20   0   32032    796      0 S   0,0   0,1   0:21.59 vncserverui                                                               
1597 pi        20   0   32316    840    216 S   0,0   0,1   0:09.59 vncserverui                                                               
  453 root      20   0    8624      0      0 S   0,0   0,0   0:00.02 vncserver-x11-s                                                           
  480 root      20   0   36440   2632   1532 S   0,0   0,3   9:32.74 vncserver-x11-c                                                           
1259 root      20   0   11476     12      8 S   0,0   0,0   0:00.21 vncagent                                                                 
   77 root       0 -20       0      0      0 S   0,0   0,0   0:00.00 vchiq-sync/0                                                             
   75 root       1 -19       0      0      0 S   0,0   0,0   0:00.02 vchiq-slot/0                                                             
   76 root       1 -19       0      0      0 S   0,0   0,0   0:00.00 vchiq-recy/0                                                             
  174 root      20   0       0      0      0 S   0,0   0,0   0:00.00 vchiq-keep/0                                                             
   83 root      20   0       0      0      0 S   0,0   0,0 273:45.75 usb-storage                                                               
pi@raspfhem:~ $ htop


  1  [                                                                   0.0%]   Tasks: 74, 154 thr; 1 running
  2  [|                                                                  0.4%]   Load average: 1.37 3.74 2.42
  3  [||||||                                                             7.4%]   Uptime: 33 days, 01:06:17
  4  [||||||                                                             6.2%]
  Mem[||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||704M/924M]
  Swp[||||||||||||||||||||||||||||||||||||||||||||||||||||||||||100.0M/100.0M]

  PID USER      PRI  NI  VIRT   RES   SHR S CPU% MEM%   TIME+  Command
  977 fhem       20   0  308M  219M  6416 S  4.5 23.7 36h28:44 /usr/bin/perl fhem.pl fhem.cfg
19459 mysql      20   0  731M  219M  2708 S  0.0 23.7 25h45:25 /usr/sbin/mysqld
19467 mysql      20   0  731M  219M  2708 S  0.0 23.7  1:43.33 /usr/sbin/mysqld
19460 mysql      20   0  731M  219M  2708 S  0.0 23.7  0:00.00 /usr/sbin/mysqld
19465 mysql      20   0  731M  219M  2708 S  0.0 23.7  0:06.13 /usr/sbin/mysqld
19466 mysql      20   0  731M  219M  2708 S  0.0 23.7  1:28.24 /usr/sbin/mysqld
19468 mysql      20   0  731M  219M  2708 S  0.0 23.7  1:45.59 /usr/sbin/mysqld
19469 mysql      20   0  731M  219M  2708 S  0.0 23.7  1:46.50 /usr/sbin/mysqld
19470 mysql      20   0  731M  219M  2708 S  0.0 23.7  1:47.95 /usr/sbin/mysqld
19471 mysql      20   0  731M  219M  2708 S  0.0 23.7  1:48.07 /usr/sbin/mysqld
19472 mysql      20   0  731M  219M  2708 S  0.0 23.7  2:18.15 /usr/sbin/mysqld
19473 mysql      20   0  731M  219M  2708 S  0.0 23.7  1:36.71 /usr/sbin/mysqld
19474 mysql      20   0  731M  219M  2708 S  0.0 23.7  1:34.27 /usr/sbin/mysqld
19475 mysql      20   0  731M  219M  2708 S  0.0 23.7  2:08.05 /usr/sbin/mysqld
19476 mysql      20   0  731M  219M  2708 S  0.0 23.7  6:21.77 /usr/sbin/mysqld
19479 mysql      20   0  731M  219M  2708 S  0.0 23.7  0:50.48 /usr/sbin/mysqld
19480 mysql      20   0  731M  219M  2708 S  0.0 23.7  2:00.85 /usr/sbin/mysqld
19481 mysql      20   0  731M  219M  2708 S  0.0 23.7  0:14.06 /usr/sbin/mysqld
19482 mysql      20   0  731M  219M  2708 S  0.0 23.7  0:07.27 /usr/sbin/mysqld
19483 mysql      20   0  731M  219M  2708 S  0.0 23.7  0:15.33 /usr/sbin/mysqld
19484 mysql      20   0  731M  219M  2708 S  0.0 23.7  2:43.13 /usr/sbin/mysqld
19485 mysql      20   0  731M  219M  2708 S  0.0 23.7  6:05.08 /usr/sbin/mysqld
19486 mysql      20   0  731M  219M  2708 S  0.0 23.7  3:03.79 /usr/sbin/mysqld
19487 mysql      20   0  731M  219M  2708 S  0.0 23.7  2:38.09 /usr/sbin/mysqld
19488 mysql      20   0  731M  219M  2708 S  0.0 23.7  2:13.89 /usr/sbin/mysqld
19489 mysql      20   0  731M  219M  2708 S  0.0 23.7  0:00.41 /usr/sbin/mysqld
19490 mysql      20   0  731M  219M  2708 S  0.0 23.7  0:35.24 /usr/sbin/mysqld
19491 mysql      20   0  731M  219M  2708 S  0.0 23.7  0:00.00 /usr/sbin/mysqld
19492 mysql      20   0  731M  219M  2708 S  0.0 23.7  0:00.00 /usr/sbin/mysqld
19493 mysql      20   0  731M  219M  2708 S  0.0 23.7  0:00.00 /usr/sbin/mysqld
F1Help  F2Setup F3SearchF4FilterF5Tree  F6SortByF7Nice -F8Nice +F9Kill  F10Quit

Habe ich ein mysql-Problem?

[andies]

Könnte das hier auch mein Problem sein: https://stackoverflow.com/questions/55925630/my-mysql-procedure-is-randomly-running-really-slow?

[Wernieman]

- Hast Du mysql getuned? c.a. 25% vom Memory ist gaaaans schön voll. Kannst Du uns die Config posten?
- vncserverui .. hast Du ein Desktopimage? Braucht Mem ...
- FHEM braucht auch 25% Mem .... 

Auf jedem falle sieht Du im kern.log den oom-killer (Out Of Memory Killer), d.h. Unix beendet einen Prozess, bei dem es  Glaubt das es wenig gebraucht wird, um den Rechner am laufen zu halten ... gar nicht gut ....

Und wenn htop, dann bitte unter "Setup -> Display Options -> Hude userland process threads" aktivieren! Sonst bekommst Du für jeden Thread eine eigene Zeile ...
oder besser, einfach mal die ps Zeile verwenden ...

Code Auswählen Erweitern

ps aux --sort=-%mem | head -n20

Btw:
Du must bei der Maschine deutlich mehr freien Speicher besorgen. In Deinem htop ist der Speicher schon zu 76% voll! Wenn ein Prozess dann dazukommt *) ... wenn oom-killer zugreifen muß, hast Du ein Problem. Der ist nur ein Notfall Automatismuß!
Aber .. wenn Du das im Griff bekommen hast, solltest Du eventuell an der Swapines drehen ... nur s.o. das kommt später

Edit:
Nur mal am Rande .. wie groß ist Deine fhem.save? Habe da zusätzlich einen Verdacht ...

Code Auswählen Erweitern

ls -lha /opt/fhem/log/fhem.save

Edit2:
Habe nochmals Nachgedacht .. einen 1G Pi mit fhem und mysql-Datenbank ... sehr sportlich. Würde ich persönlich definitiv nicht machen. mysql und SDCard zusammen sind nicht gerade optimal. mysql schreibt sehr viel ... und was mag eine SDCard überhaupt nicht??

Edit3:
*) Dazu reicht schon ein present-Device mit "ping" (Wegen nonblocking, Forking). Oder wenn Du eine SVN-Grafik Dir anschauen willst (parallele Berechnung der Grafiken). Für beides gibt es Schalter zum abschalten, nur ob das optimal ist ...der 220 MByte freie Speicher in Deinem Beispiel ist schnell verbraten ...

Edit4:
Sorry aktuell sende ich zu schnell:
Was sagt folgende Ausgabe?

Code Auswählen Erweitern

free -lm

[andies]

Vielen Dank für die Hilfe!

Nein, ich habe nichts an der Standard-Konfiguration von MySQL gemacht. Ich habe keine SD-Card, sondern eine SSD-Festplatte am Raspberry. Die gewünschten Angaben stehen hier:

Code Auswählen Erweitern

pi@raspfhem:~ $ ls -lha /opt/fhem/log/fhem.save
-rwxr-xr-x 1 fhem dialout 483K Dez 28 12:03 /opt/fhem/log/fhem.save
pi@raspfhem:~ $ free -lm
              total        used        free      shared  buff/cache   available
Mem:            923         706          23          51         194         111
Low:            923         900          23
High:             0           0           0
Swap:            99          99           0
pi@raspfhem:~ $ ps aux --sort=-%mem | head -n20
USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
fhem       977  5.2 23.7 318672 224824 ?       S    Nov29 2214:57 /usr/bin/perl fhem.pl fhem.cfg
fhem     24912  0.0 23.4 318672 222160 ?       S    21:22   0:00 /usr/bin/perl fhem.pl fhem.cfg
mysql    20049  3.1 22.9 727704 217304 ?       Ssl  14:45  12:53 /usr/sbin/mysqld
signal-+  2281  0.1  8.2 374288 78244 ?        Ssl  Nov25  54:44 /home/pi/.sdkman/candidates/java/current/bin/java -Xms2m -classpath /opt/signal/lib/signal-cli-0.11.2.jar:/opt/signal/lib/lib.jar:/opt/signal/lib/bcprov-jdk15on-1.70.jar:/opt/signal/lib/jackson-annotations-2.13.4.jar:/opt/signal/lib/jackson-core-2.13.4.jar:/opt/signal/lib/signal-service-java-2.15.3_unofficial_59.jar:/opt/signal/lib/jackson-databind-2.13.4.jar:/opt/signal/lib/argparse4j-0.9.0.jar:/opt/signal/lib/dbus-java-transport-native-unixsocket-4.2.1.jar:/opt/signal/lib/logback-classic-1.4.3.jar:/opt/signal/lib/jul-to-slf4j-2.0.3.jar:/opt/signal/lib/dbus-java-core-4.2.1.jar:/opt/signal/lib/HikariCP-5.0.1.jar:/opt/signal/lib/slf4j-api-2.0.3.jar:/opt/signal/lib/logback-core-1.4.3.jar:/opt/signal/lib/protobuf-javalite-3.11.4.jar:/opt/signal/lib/sqlite-jdbc-3.39.3.0.jar:/opt/signal/lib/jsr305-3.0.2.jar:/opt/signal/lib/libphonenumber-8.12.54.jar:/opt/signal/lib/libsignal-client-0.20.0.jar:/opt/signal/lib/okhttp-4.10.0.jar:/opt/signal/lib/rxjava-3.0.13.jar:/opt/signal/lib/okio-jvm-3.2.0.jar:/opt/signal/lib/kotlin-stdlib-jdk8-1.6.20.jar:/opt/signal/lib/kotlin-stdlib-jdk7-1.6.20.jar:/opt/signal/lib/kotlin-stdlib-1.6.20.jar:/opt/signal/lib/reactive-streams-1.0.3.jar:/opt/signal/lib/kotlin-stdlib-common-1.6.20.jar:/opt/signal/lib/annotations-13.0.jar org.asamk.signal.Main --config /var/lib/signal-cli daemon --system
grafana    847  0.3  4.9 1033152 47224 ?       Ssl  Nov25 173:19 /usr/sbin/grafana-server --config=/etc/grafana/grafana.ini --pidfile=/run/grafana/grafana-server.pid --packaging=deb cfg:default.paths.logs=/var/log/grafana cfg:default.paths.data=/var/lib/grafana cfg:default.paths.plugins=/var/lib/grafana/plugins cfg:default.paths.provisioning=/etc/grafana/provisioning
www-data  9672  0.0  1.6 203028 15172 ?        S    00:00   0:00 /usr/sbin/apache2 -k start
www-data  9673  0.0  1.4 203188 13688 ?        S    00:00   0:00 /usr/sbin/apache2 -k start
www-data  9676  0.0  1.0 203036  9780 ?        S    00:00   0:00 /usr/sbin/apache2 -k start
www-data  9674  0.0  0.9 203028  9048 ?        S    00:00   0:00 /usr/sbin/apache2 -k start
www-data 19501  0.0  0.9 203028  8888 ?        S    13:39   0:00 /usr/sbin/apache2 -k start
www-data 19500  0.0  0.9 203028  8728 ?        S    13:39   0:00 /usr/sbin/apache2 -k start
www-data  9675  0.0  0.9 203028  8680 ?        S    00:00   0:00 /usr/sbin/apache2 -k start
www-data 19556  0.0  0.9 203060  8584 ?        S    13:41   0:00 /usr/sbin/apache2 -k start
www-data 19499  0.0  0.9 203184  8568 ?        S    13:39   0:00 /usr/sbin/apache2 -k start
pi        1531  0.0  0.8 413504  8148 ?        Sl   Nov25  24:22 lxpanel --profile LXDE-pi
root       838  0.0  0.6 202564  6264 ?        Ss   Nov25   3:52 /usr/sbin/apache2 -k start
pi        1550  0.0  0.6 320784  6080 ?        Sl   Nov25   0:01 zenity --warning --width=400 --text=SSH is enabled and the default password for the 'pi' user has not been changed.\n\nThis is a security risk - please login as the 'pi' user and run Raspberry Pi Configuration to set a new password.
root     24989  0.2  0.6  12192  5984 ?        Ss   21:32   0:00 sshd: pi [priv]
root      4274  0.0  0.5  35272  5352 ?        Ss   Dez18   0:38 /lib/systemd/systemd-journald

Das mit htop versuche ich gleich mal und vnc nutze ich gar nicht.