FHEM Forum

FHEM - Hardware => Einplatinencomputer => Thema gestartet von: Olli7766 am 19 Juli 2023, 12:24:47

Titel: perl invoked oom-killer -> Memory leak -> Ram läuft voll
Beitrag von: Olli7766 am 19 Juli 2023, 12:24:47
Hi Leute,

alle 2 Tage stürzt mein FHEM 6.2 ab.

Dies passiert da hier wohl der RAM Speicher zu läuft.
Betrachte ich das ganze aber im TOP sehe ich 350MB freien RAM. Ich kann mir das also nicht so wirklich erklären.

FHEM läuft auf einen Raspberry Pi 3 Model B Rev 1.2.
Außer dem FHEM Server ist nur noch Node-RED installiert... ansonsten hat das System keine andere Aufgabe.

Könnt ihr mir Tipps geben was hier schief läuft?

Logfile FHEM
2023.07.18 20:09:24 3: EnOcean set EnO_0599D728 off
2023.07.18 20:46:25 3: EnOcean set EnO_0599D728 on
2023.07.18 22:52:24 2: bridge: http request failed: read from https://192.168.1.112:443 timed out
2023.07.18 22:52:24 2: bridge: EventStream: terminated
2023.07.19 00:25:35 3: EnOcean set EnO_0599D728 off
2023.07.19 02:00:01 2: bridge: http request failed: read from https://192.168.1.112:443 timed out
2023.07.19 02:00:01 2: bridge: EventStream: terminated
2023.07.19 02:23:34 1: Including fhem.cfg
2023.07.19 02:23:35 3: WEB: port 8083 opened
2023.07.19 02:23:35 2: eventTypes: loaded 124 lines from ./log/eventTypes.txt
2023.07.19 02:23:35 3: Opening CUL_0 device /dev/ttyACM0
2023.07.19 02:23:35 3: Setting CUL_0 serial parameters to 9600,8,N,1
2023.07.19 02:23:35 3: CUL_0: Possible commands: ABbCeFGhiKkLlMmNRTtUuVWXxYZ
2023.07.19 02:23:35 3: CUL_0 device opened
2023.07.19 02:23:39 3: tPort: port 7072 opened
2023.07.19 02:23:40 2: EnOcean Cryptographic functions are not available.
2023.07.19 02:23:40 2: EnOcean XML functions are not available.
2023.07.19 02:23:42 3: HUEDevice1: I/O device is bridge
2023.07.19 02:23:42 3: HUEDevice2: I/O device is bridge
2023.07.19 02:23:42 3: HUEDevice4: I/O device is bridge
2023.07.19 02:23:42 3: HUEDevice5: I/O device is bridge
2023.07.19 02:23:42 3: HUEDevice6: I/O device is bridge
2023.07.19 02:23:42 3: HUEDevice7: I/O device is bridge
2023.07.19 02:23:42 3: HUEDevice8: I/O device is bridge
2023.07.19 02:23:42 3: HUEDevice9: I/O device is bridge
2023.07.19 02:23:42 3: HUEGroup0: I/O device is bridge
2023.07.19 02:23:42 3: HUEGroup1: I/O device is bridge
2023.07.19 02:23:42 3: HUEGroup2: I/O device is bridge
2023.07.19 02:23:42 3: HUESensor1: I/O device is bridge
2023.07.19 02:23:42 3: HUESensor2: I/O device is bridge
2023.07.19 02:23:42 3: HUESensor4: I/O device is bridge
2023.07.19 02:23:42 3: mqttBroker: port 1883 opened
2023.07.19 02:23:42 3: Opening TCM_ESP3_2 device /dev/ttyUSB2
2023.07.19 02:23:42 3: Setting TCM_ESP3_2 serial parameters to 57600,8,N,1
2023.07.19 02:23:42 3: TCM_ESP3_2 device opened
2023.07.19 02:23:42 1: Including ./log/fhem.save
2023.07.19 02:23:42 1: Messages collected while initializing FHEM:SecurityCheck:
  mqttBroker is not password protected
  tPort is not password protected
  WEB is not password protected

Protect this FHEM installation by configuring the allowed device allowed
You can disable this message with attr global motd none

2023.07.19 02:23:42 3: TCM TCM_ESP3_2 set reset
2023.07.19 02:23:43 3: TCM TCM_ESP3_2 get baseID
2023.07.19 02:23:43 2: TCM TCM_ESP3_2 RESPONSE: BaseID: FFC46B00 RemainingWriteCycles: 0A
2023.07.19 02:23:43 3: TCM TCM_ESP3_2 get version
2023.07.19 02:23:43 2: TCM TCM_ESP3_2 RESPONSE: APIVersion: 02060900 APPVersion: 020F0000 ChipID: 051488D6 ChipVersion: 454F0103 Desc: GATEWAYCTRL
2023.07.19 02:23:43 3: TCM TCM_ESP3_2 set mode 00
2023.07.19 02:23:43 2: TCM TCM_ESP3_2 RESPONSE: NOT_SUPPORTED
2023.07.19 02:23:43 3: TCM TCM_ESP3_2 set repeater 0000
2023.07.19 02:23:43 2: TCM TCM_ESP3_2 repeater 0000 restored
2023.07.19 02:23:43 3: TCM TCM_ESP3_2 set smartAckMailboxMax 0
2023.07.19 02:23:43 2: TCM TCM_ESP3_2 smartAckMailboxMax 0 restored
2023.07.19 02:23:43 3: TCM TCM_ESP3_2 set maturity 01
2023.07.19 02:23:43 2: TCM TCM_ESP3_2 maturity 01 restored
2023.07.19 02:23:43 2: TCM TCM_ESP3_2 initialized
2023.07.19 02:23:43 2: TCM registered transceiver BaseID: FFC46B00 ChipID: 051488D6
2023.07.19 02:23:43 2: EnOcean EnO_05234D6F XML functions are not available
2023.07.19 02:23:43 2: EnOcean EnO_0599D728 XML functions are not available
2023.07.19 02:23:43 2: EnOcean EnO_8100CEFE XML functions are not available
2023.07.19 02:23:43 2: bridge: autocreate: created 0/0/0 devices (ignored 0/3/6)
2023.07.19 02:23:43 1: usb create starting
2023.07.19 02:23:44 3: Probing ZWDongle device /dev/serial0
2023.07.19 02:23:44 1: ZWDongle: Can't open /dev/serial0: Permission denied
2023.07.19 02:23:44 3: Probing ZWDongle device /dev/serial1
2023.07.19 02:23:44 1: PERL WARNING: can't getattr: Input/output error at FHEM/DevIo.pm line 613.
2023.07.19 02:23:44 1: ZWDongle: Can't open /dev/serial1: Input/output error
2023.07.19 02:23:44 3: Probing CUL device /dev/ttyAMA0
2023.07.19 02:23:44 1: CUL: Can't open /dev/ttyAMA0: Permission denied
2023.07.19 02:23:44 3: Probing CUL device /dev/ttyS0
2023.07.19 02:23:44 1: CUL: Can't open /dev/ttyS0: Input/output error
2023.07.19 02:23:44 3: Probing TCM_ESP3 device /dev/ttyUSB0
2023.07.19 02:23:44 3: Probing TCM_ESP2 device /dev/ttyUSB0
2023.07.19 02:23:45 3: Probing FHZ device /dev/ttyUSB0
2023.07.19 02:23:45 3: Probing TRX device /dev/ttyUSB0
2023.07.19 02:23:46 3: Probing ZWDongle device /dev/ttyUSB0
2023.07.19 02:23:46 3: Probing SIGNALDuino device /dev/ttyUSB0
2023.07.19 02:23:47 3: Probing MYSENSORS device /dev/ttyUSB0
2023.07.19 02:23:47 3: Probing ArduCounter device /dev/ttyUSB0
2023.07.19 02:23:48 3: Probing ElsnerWS device /dev/ttyUSB0
2023.07.19 02:23:49 3: Probing FRM device /dev/ttyUSB0
2023.07.19 02:23:54 3: Probing TCM_ESP3 device /dev/ttyUSB1
2023.07.19 02:23:54 3: Probing TCM_ESP2 device /dev/ttyUSB1
2023.07.19 02:23:54 3: Probing FHZ device /dev/ttyUSB1
2023.07.19 02:23:55 3: Probing TRX device /dev/ttyUSB1
2023.07.19 02:23:55 3: Probing ZWDongle device /dev/ttyUSB1
2023.07.19 02:23:55 3: Probing SIGNALDuino device /dev/ttyUSB1
2023.07.19 02:23:55 3: Probing MYSENSORS device /dev/ttyUSB1
2023.07.19 02:23:55 3: Probing ArduCounter device /dev/ttyUSB1
2023.07.19 02:23:56 3: Probing ElsnerWS device /dev/ttyUSB1
2023.07.19 02:23:57 3: Probing FRM device /dev/ttyUSB1
2023.07.19 02:24:02 1: usb create end
2023.07.19 02:24:02 0: Featurelevel: 6.2
2023.07.19 02:24:02 0: Server started with 120 defined entities (fhem.pl:27750/2023-07-11 perl:5.032001 os:linux user:fhem pid:5169)
2023.07.19 02:24:02 2: bridge: http request failed:  SSL connect attempt failed
2023.07.19 02:24:02 1: 192.168.1.181:19444 reappeared (wz_TVLicht)
2023.07.19 02:24:02 2: bridge: http request failed:  SSL connect attempt failed
2023.07.19 02:24:02 2: bridge: EventStream: terminated; retrying later
2023.07.19 03:24:04 2: bridge: http request failed: read from https://192.168.1.112:443 timed out
2023.07.19 03:24:04 2: bridge: EventStream: terminated; retrying later
2023.07.19 04:24:07 2: bridge: http request failed: read from https://192.168.1.112:443 timed out
2023.07.19 04:24:07 2: bridge: EventStream: terminated; retrying later
2023.07.19 06:47:29 2: AttrTemplates: got 259 entries
2023.07.19 07:04:43 3: EnOcean set EnO_0599D728 on
2023.07.19 08:09:07 2: bridge: http request failed: read from https://192.168.1.112:443 timed out
2023.07.19 08:09:07 2: bridge: EventStream: terminated
2023.07.19 09:23:55 2: bridge: http request failed: read from https://192.168.1.112:443 timed out
2023.07.19 09:23:55 2: bridge: EventStream: terminated
2023.07.19 11:31:26 3: EnOcean set EnO_0599D728 off

Logfile SYSLOG
Jul 19 02:17:03 raspberrypi CRON[5126]: (root) CMD (  cd / && run-parts --report /etc/cron.hourly)
Jul 19 02:23:31 raspberrypi kernel: [307120.371267] perl invoked oom-killer: gfp_mask=0x400dc0(GFP_KERNEL_ACCOUNT|__GFP_ZERO), order=0, oom_score_adj=0
Jul 19 02:23:31 raspberrypi kernel: [307120.371308] CPU: 3 PID: 11307 Comm: perl Tainted: G        C        6.1.21-v7+ #1642
Jul 19 02:23:31 raspberrypi kernel: [307120.371319] Hardware name: BCM2835
Jul 19 02:23:31 raspberrypi kernel: [307120.371332]  unwind_backtrace from show_stack+0x18/0x1c
Jul 19 02:23:31 raspberrypi kernel: [307120.371358]  show_stack from dump_stack_lvl+0x68/0x8c
Jul 19 02:23:31 raspberrypi kernel: [307120.371375]  dump_stack_lvl from dump_header+0x54/0x214
Jul 19 02:23:31 raspberrypi kernel: [307120.371392]  dump_header from oom_kill_process+0x238/0x244
Jul 19 02:23:31 raspberrypi kernel: [307120.371413]  oom_kill_process from out_of_memory+0x288/0x358
Jul 19 02:23:31 raspberrypi kernel: [307120.371432]  out_of_memory from __alloc_pages+0x7c4/0xf9c
Jul 19 02:23:31 raspberrypi kernel: [307120.371454]  __alloc_pages from __pte_alloc+0x40/0x1a4
Jul 19 02:23:31 raspberrypi kernel: [307120.371472]  __pte_alloc from handle_mm_fault+0xcb4/0xeac
Jul 19 02:23:31 raspberrypi kernel: [307120.371486]  handle_mm_fault from do_page_fault+0x144/0x39c
Jul 19 02:23:31 raspberrypi kernel: [307120.371505]  do_page_fault from do_DataAbort+0x44/0xb8
Jul 19 02:23:31 raspberrypi kernel: [307120.371523]  do_DataAbort from __dabt_usr+0x58/0x60
Jul 19 02:23:31 raspberrypi kernel: [307120.371535] Exception stack(0xbbc55fb0 to 0xbbc55ff8)
Jul 19 02:23:31 raspberrypi kernel: [307120.371546] 5fa0:                                    67400000 50db9fc0 00405ef8 5fc5dd00
Jul 19 02:23:31 raspberrypi kernel: [307120.371556] 5fc0: 026afb40 00000003 026afa98 006b3190 00024403 00000602 0f2a9cf9 10b4a24c
Jul 19 02:23:31 raspberrypi kernel: [307120.371565] 5fe0: ffffff40 7e9e0a30 08000000 76f6d254 20000010 ffffffff
Jul 19 02:23:31 raspberrypi kernel: [307120.371573] Mem-Info:
Jul 19 02:23:31 raspberrypi kernel: [307120.371580] active_anon:56329 inactive_anon:145387 isolated_anon:0
Jul 19 02:23:31 raspberrypi kernel: [307120.371580]  active_file:10 inactive_file:0 isolated_file:0
Jul 19 02:23:31 raspberrypi kernel: [307120.371580]  unevictable:4 dirty:0 writeback:24
Jul 19 02:23:31 raspberrypi kernel: [307120.371580]  slab_reclaimable:8782 slab_unreclaimable:4301
Jul 19 02:23:31 raspberrypi kernel: [307120.371580]  mapped:3 shmem:3 pagetables:1025
Jul 19 02:23:31 raspberrypi kernel: [307120.371580]  sec_pagetables:0 bounce:0
Jul 19 02:23:31 raspberrypi kernel: [307120.371580]  kernel_misc_reclaimable:0
Jul 19 02:23:31 raspberrypi kernel: [307120.371580]  free:16395 free_pcp:493 free_cma:12316
Jul 19 02:23:31 raspberrypi kernel: [307120.371601] Node 0 active_anon:225316kB inactive_anon:581548kB active_file:40kB inactive_file:0kB unevictable:16kB isolated(anon):0kB isolated(file):0kB mapped:12kB dirty:0kB writeback:96kB shmem:12kB writeback_tmp:0kB kernel_stack:1264kB pagetables:4100kB sec_pagetables:0kB all_unreclaimable? yes
Jul 19 02:23:31 raspberrypi kernel: [307120.371620] DMA free:65580kB boost:0kB min:16384kB low:20480kB high:24576kB reserved_highatomic:0KB active_anon:225316kB inactive_anon:581000kB active_file:40kB inactive_file:0kB unevictable:16kB writepending:96kB present:970752kB managed:944092kB mlocked:16kB bounce:0kB free_pcp:1972kB local_pcp:504kB free_cma:49264kB
Jul 19 02:23:31 raspberrypi kernel: [307120.371641] lowmem_reserve[]: 0 0 0
Jul 19 02:23:31 raspberrypi kernel: [307120.371659] DMA: 2020*4kB (UEC) 3342*8kB (UEC) 1039*16kB (UEC) 295*32kB (UEC) 64*64kB (UEC) 6*128kB (UEC) 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 65744kB
Jul 19 02:23:31 raspberrypi kernel: [307120.371728] 102 total pagecache pages
Jul 19 02:23:31 raspberrypi kernel: [307120.371734] 89 pages in swap cache
Jul 19 02:23:31 raspberrypi kernel: [307120.371739] Free swap  = 0kB
Jul 19 02:23:31 raspberrypi kernel: [307120.371744] Total swap = 102396kB
Jul 19 02:23:31 raspberrypi kernel: [307120.371749] 242688 pages RAM
Jul 19 02:23:31 raspberrypi kernel: [307120.371754] 0 pages HighMem/MovableOnly
Jul 19 02:23:31 raspberrypi kernel: [307120.371759] 6665 pages reserved
Jul 19 02:23:31 raspberrypi kernel: [307120.371763] 65536 pages cma reserved
Jul 19 02:23:31 raspberrypi kernel: [307120.371769] Tasks state (memory values in pages):
Jul 19 02:23:31 raspberrypi kernel: [307120.371774] [  pid  ]  uid  tgid total_vm      rss pgtables_bytes swapents oom_score_adj name
Jul 19 02:23:31 raspberrypi kernel: [307120.371795] [    141]    0  141    55341      73  204800      121          -250 systemd-journal
Jul 19 02:23:31 raspberrypi kernel: [307120.371808] [    167]    0  167    5112      10    22528      397        -1000 systemd-udevd
Jul 19 02:23:31 raspberrypi kernel: [307120.371823] [    328]  103  328    5573        0    22528      140            0 systemd-timesyn
Jul 19 02:23:31 raspberrypi kernel: [307120.371835] [    431]  108  431    1729      49    14336      59            0 avahi-daemon
Jul 19 02:23:31 raspberrypi kernel: [307120.371847] [    441]    0  441    2050      18    16384      35            0 cron
Jul 19 02:23:31 raspberrypi kernel: [307120.371858] [    443]  104  443    2012        0    18432      229          -900 dbus-daemon
Jul 19 02:23:31 raspberrypi kernel: [307120.371869] [    451]  108  451    1689        0    14336      75            0 avahi-daemon
Jul 19 02:23:31 raspberrypi kernel: [307120.371881] [    457]    0  457    10316        2    34816      562            0 polkitd
Jul 19 02:23:31 raspberrypi kernel: [307120.371893] [    468]    0  468    3267      10    22528      150            0 systemd-logind
Jul 19 02:23:31 raspberrypi kernel: [307120.371904] [    469] 65534  469    1328        5    14336      42            0 thd
Jul 19 02:23:31 raspberrypi kernel: [307120.371916] [    470]    0  470    2948      12    16384      90            0 wpa_supplicant
Jul 19 02:23:31 raspberrypi kernel: [307120.371927] [    534]    0  534    6924        0    18432      38            0 rngd
Jul 19 02:23:31 raspberrypi kernel: [307120.371938] [    557]    0  557      701      18    10240      67            0 dhcpcd
Jul 19 02:23:31 raspberrypi kernel: [307120.371950] [    570]    0  570    2004        0    16384      46            0 vncserver-x11-s
Jul 19 02:23:31 raspberrypi kernel: [307120.371962] [    575]    0  575    1121        0    12288      26            0 agetty
Jul 19 02:23:31 raspberrypi kernel: [307120.371973] [    577]    0  577    1663        0    16384      26            0 agetty
Jul 19 02:23:31 raspberrypi kernel: [307120.371984] [    580]    0  580    12146        0    38912      344            0 ModemManager
Jul 19 02:23:31 raspberrypi kernel: [307120.371995] [    581]    0  581    9096      29    36864      399            0 vncserver-x11-c
Jul 19 02:23:31 raspberrypi kernel: [307120.372007] [    583]    0  583    3100        0    20480      175        -1000 sshd
Jul 19 02:23:31 raspberrypi kernel: [307120.372018] [    744]  114  744    19777        2    55296      934            0 colord
Jul 19 02:23:31 raspberrypi kernel: [307120.372030] [    840]  111  840    6052        7    20480      56            0 rtkit-daemon
Jul 19 02:23:31 raspberrypi kernel: [307120.372041] [  1435]    0  1435    23927      29    59392      453            0 packagekitd
Jul 19 02:23:31 raspberrypi kernel: [307120.372054] [  11307]  999 11307  209080  189270  819200    8516            0 perl
Jul 19 02:23:31 raspberrypi kernel: [307120.372065] [  11872]  1000 11872    61052    11880  561152    11981            0 node-red
Jul 19 02:23:31 raspberrypi kernel: [307120.372078] [  3378]    0  3378    6636      46    22528      86            0 rsyslogd
Jul 19 02:23:31 raspberrypi kernel: [307120.372094] oom-kill:constraint=CONSTRAINT_NONE,nodemask=(null),cpuset=/,mems_allowed=0,global_oom,task_memcg=/,task=perl,pid=11307,uid=999
Jul 19 02:23:31 raspberrypi kernel: [307120.372142] Out of memory: Killed process 11307 (perl) total-vm:836320kB, anon-rss:757068kB, file-rss:12kB, shmem-rss:0kB, UID:999 pgtables:800kB oom_score_adj:0
Jul 19 02:23:32 raspberrypi systemd[1]: fhem.service: Main process exited, code=killed, status=9/KILL
Jul 19 02:23:32 raspberrypi systemd[1]: fhem.service: Failed with result 'signal'.
Jul 19 02:23:32 raspberrypi systemd[1]: fhem.service: Consumed 9h 4min 17.450s CPU time.
Jul 19 02:23:32 raspberrypi systemd[1]: fhem.service: Scheduled restart job, restart counter is at 1.
Jul 19 02:23:32 raspberrypi systemd[1]: Stopped FHEM Home Automation.
Jul 19 02:23:33 raspberrypi systemd[1]: fhem.service: Consumed 9h 4min 17.450s CPU time.
Jul 19 02:23:33 raspberrypi systemd[1]: Starting FHEM Home Automation...
Jul 19 02:23:34 raspberrypi systemd[1]: Started FHEM Home Automation.
Jul 19 03:05:11 raspberrypi rngd[534]: stats: bits received from HRNG source: 2620064
Jul 19 03:05:11 raspberrypi rngd[534]: stats: bits sent to kernel pool: 2578432
Jul 19 03:05:11 raspberrypi rngd[534]: stats: entropy added to kernel pool: 2578432
Jul 19 03:05:11 raspberrypi rngd[534]: stats: FIPS 140-2 successes: 131
Jul 19 03:05:11 raspberrypi rngd[534]: stats: FIPS 140-2 failures: 0
Jul 19 03:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Monobit: 0
Jul 19 03:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Poker: 0
Jul 19 03:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Runs: 0
Jul 19 03:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Long run: 0
Jul 19 03:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Continuous run: 0
Jul 19 03:05:11 raspberrypi rngd[534]: stats: HRNG source speed: (min=606.090; avg=873.748; max=971.414)Kibits/s
Jul 19 03:05:11 raspberrypi rngd[534]: stats: FIPS tests speed: (min=18.903; avg=25.992; max=51.830)Mibits/s
Jul 19 03:05:11 raspberrypi rngd[534]: stats: Lowest ready-buffers level: 2
Jul 19 03:05:11 raspberrypi rngd[534]: stats: Entropy starvations: 0
Jul 19 03:05:11 raspberrypi rngd[534]: stats: Time spent starving for entropy: (min=0; avg=0.000; max=0)us
Jul 19 03:10:02 raspberrypi CRON[5484]: (root) CMD (test -e /run/systemd/system || SERVICE_MODE=1 /sbin/e2scrub_all -A -r)
Jul 19 03:10:02 raspberrypi CRON[5485]: (pi) CMD (/home/pi/Bins/wetter.sh)
Jul 19 03:17:01 raspberrypi CRON[5597]: (root) CMD (  cd / && run-parts --report /etc/cron.hourly)
Jul 19 04:05:11 raspberrypi rngd[534]: stats: bits received from HRNG source: 2660064
Jul 19 04:05:11 raspberrypi rngd[534]: stats: bits sent to kernel pool: 2608192
Jul 19 04:05:11 raspberrypi rngd[534]: stats: entropy added to kernel pool: 2608192
Jul 19 04:05:11 raspberrypi rngd[534]: stats: FIPS 140-2 successes: 133
Jul 19 04:05:11 raspberrypi rngd[534]: stats: FIPS 140-2 failures: 0
Jul 19 04:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Monobit: 0
Jul 19 04:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Poker: 0
Jul 19 04:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Runs: 0
Jul 19 04:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Long run: 0
Jul 19 04:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Continuous run: 0
Jul 19 04:05:11 raspberrypi rngd[534]: stats: HRNG source speed: (min=606.090; avg=874.546; max=971.414)Kibits/s
Jul 19 04:05:11 raspberrypi rngd[534]: stats: FIPS tests speed: (min=18.903; avg=26.001; max=51.830)Mibits/s
Jul 19 04:05:11 raspberrypi rngd[534]: stats: Lowest ready-buffers level: 2
Jul 19 04:05:11 raspberrypi rngd[534]: stats: Entropy starvations: 0
Jul 19 04:05:11 raspberrypi rngd[534]: stats: Time spent starving for entropy: (min=0; avg=0.000; max=0)us
Jul 19 04:10:01 raspberrypi CRON[5904]: (pi) CMD (/home/pi/Bins/wetter.sh)
Jul 19 04:17:01 raspberrypi CRON[5952]: (root) CMD (  cd / && run-parts --report /etc/cron.hourly)
Jul 19 05:01:14 raspberrypi dhcpcd[557]: eth0: fe80::de39:6fff:feee:e155: no longer a default router
Jul 19 05:01:14 raspberrypi dhcpcd[557]: eth0: deleting default route via fe80::de39:6fff:feee:e155
Jul 19 05:01:19 raspberrypi dhcpcd[557]: eth0: adding address fd00::3543:cdd1:1d1b:a0a9/64
Jul 19 05:01:19 raspberrypi dhcpcd[557]: eth0: adding route to fd00::/64
Jul 19 05:01:19 raspberrypi avahi-daemon[431]: Withdrawing address record for 2001:a62:362:4501:82c6:2811:6ed8:a7cf on eth0.
Jul 19 05:01:19 raspberrypi avahi-daemon[431]: Registering new address record for fd00::3543:cdd1:1d1b:a0a9 on eth0.*.
Jul 19 05:01:21 raspberrypi dhcpcd[557]: eth0: adding address 2001:a62:376:5301:78ca:564a:c1fa:1567/64
Jul 19 05:01:21 raspberrypi avahi-daemon[431]: Registering new address record for 2001:a62:376:5301:78ca:564a:c1fa:1567 on eth0.*.
Jul 19 05:01:21 raspberrypi dhcpcd[557]: eth0: adding route to 2001:a62:376:5301::/64
Jul 19 05:01:21 raspberrypi dhcpcd[557]: eth0: adding default route via fe80::de39:6fff:feee:e155
Jul 19 05:01:21 raspberrypi dhcpcd[557]: eth0: deleting address 2001:a62:362:4501:82c6:2811:6ed8:a7cf/64
Jul 19 05:01:21 raspberrypi dhcpcd[557]: eth0: deleting route to 2001:a62:362:4501::/64
Jul 19 05:01:21 raspberrypi avahi-daemon[431]: Got SIGHUP, reloading.
Jul 19 05:01:21 raspberrypi avahi-daemon[431]: No service file found in /etc/avahi/services.
Jul 19 05:01:30 raspberrypi avahi-daemon[431]: Withdrawing address record for fd00::3543:cdd1:1d1b:a0a9 on eth0.
Jul 19 05:01:32 raspberrypi avahi-daemon[431]: Got SIGHUP, reloading.
Jul 19 05:01:32 raspberrypi avahi-daemon[431]: No service file found in /etc/avahi/services.
Jul 19 05:05:11 raspberrypi rngd[534]: stats: bits received from HRNG source: 2680064
Jul 19 05:05:11 raspberrypi rngd[534]: stats: bits sent to kernel pool: 2638432
Jul 19 05:05:11 raspberrypi rngd[534]: stats: entropy added to kernel pool: 2638432
Jul 19 05:05:11 raspberrypi rngd[534]: stats: FIPS 140-2 successes: 134
Jul 19 05:05:11 raspberrypi rngd[534]: stats: FIPS 140-2 failures: 0
Jul 19 05:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Monobit: 0
Jul 19 05:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Poker: 0
Jul 19 05:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Runs: 0
Jul 19 05:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Long run: 0
Jul 19 05:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Continuous run: 0
Jul 19 05:05:11 raspberrypi rngd[534]: stats: HRNG source speed: (min=606.090; avg=875.022; max=971.414)Kibits/s
Jul 19 05:05:11 raspberrypi rngd[534]: stats: FIPS tests speed: (min=18.903; avg=25.983; max=51.830)Mibits/s
Jul 19 05:05:11 raspberrypi rngd[534]: stats: Lowest ready-buffers level: 2
Jul 19 05:05:11 raspberrypi rngd[534]: stats: Entropy starvations: 0
Jul 19 05:05:11 raspberrypi rngd[534]: stats: Time spent starving for entropy: (min=0; avg=0.000; max=0)us
Jul 19 05:10:01 raspberrypi CRON[6445]: (pi) CMD (/home/pi/Bins/wetter.sh)
Jul 19 05:17:01 raspberrypi CRON[6491]: (root) CMD (  cd / && run-parts --report /etc/cron.hourly)
Jul 19 05:38:36 raspberrypi systemd[1]: Starting Daily apt download activities...
Jul 19 05:38:39 raspberrypi systemd[1]: apt-daily.service: Succeeded.
Jul 19 05:38:39 raspberrypi systemd[1]: Finished Daily apt download activities.
Jul 19 05:38:39 raspberrypi systemd[1]: apt-daily.service: Consumed 2.154s CPU time.
Jul 19 05:58:38 raspberrypi dhcpcd[557]: eth0: fe80::de39:6fff:feee:e155: no longer a default router
Jul 19 05:58:38 raspberrypi dhcpcd[557]: eth0: deleting default route via fe80::de39:6fff:feee:e155
Jul 19 05:58:43 raspberrypi avahi-daemon[431]: Registering new address record for fd00::3543:cdd1:1d1b:a0a9 on eth0.*.
Jul 19 05:58:43 raspberrypi avahi-daemon[431]: Withdrawing address record for 2001:a62:376:5301:78ca:564a:c1fa:1567 on eth0.
Jul 19 05:58:44 raspberrypi avahi-daemon[431]: Got SIGHUP, reloading.
Jul 19 05:58:44 raspberrypi avahi-daemon[431]: No service file found in /etc/avahi/services.
Jul 19 05:58:44 raspberrypi avahi-daemon[431]: Withdrawing address record for fd00::3543:cdd1:1d1b:a0a9 on eth0.
Jul 19 05:58:44 raspberrypi dhcpcd[557]: eth0: adding address 2001:a62:378:1301:6037:9b:e0ae:bd47/64
Jul 19 05:58:44 raspberrypi dhcpcd[557]: eth0: adding route to 2001:a62:378:1301::/64
Jul 19 05:58:44 raspberrypi avahi-daemon[431]: Registering new address record for 2001:a62:378:1301:6037:9b:e0ae:bd47 on eth0.*.
Jul 19 05:58:44 raspberrypi dhcpcd[557]: eth0: adding default route via fe80::de39:6fff:feee:e155
Jul 19 05:58:45 raspberrypi dhcpcd[557]: eth0: deleting address 2001:a62:376:5301:78ca:564a:c1fa:1567/64
Jul 19 05:58:45 raspberrypi dhcpcd[557]: eth0: deleting route to 2001:a62:376:5301::/64
Jul 19 05:58:45 raspberrypi avahi-daemon[431]: Got SIGHUP, reloading.
Jul 19 05:58:45 raspberrypi avahi-daemon[431]: No service file found in /etc/avahi/services.
Jul 19 06:05:11 raspberrypi rngd[534]: stats: bits received from HRNG source: 2720064
Jul 19 06:05:11 raspberrypi rngd[534]: stats: bits sent to kernel pool: 2668192
Jul 19 06:05:11 raspberrypi rngd[534]: stats: entropy added to kernel pool: 2668192
Jul 19 06:05:11 raspberrypi rngd[534]: stats: FIPS 140-2 successes: 136
Jul 19 06:05:11 raspberrypi rngd[534]: stats: FIPS 140-2 failures: 0
Jul 19 06:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Monobit: 0
Jul 19 06:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Poker: 0
Jul 19 06:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Runs: 0
Jul 19 06:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Long run: 0
Jul 19 06:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Continuous run: 0
Jul 19 06:05:11 raspberrypi rngd[534]: stats: HRNG source speed: (min=606.090; avg=875.688; max=971.414)Kibits/s
Jul 19 06:05:11 raspberrypi rngd[534]: stats: FIPS tests speed: (min=18.903; avg=25.967; max=51.830)Mibits/s
Jul 19 06:05:11 raspberrypi rngd[534]: stats: Lowest ready-buffers level: 2
Jul 19 06:05:11 raspberrypi rngd[534]: stats: Entropy starvations: 0
Jul 19 06:05:11 raspberrypi rngd[534]: stats: Time spent starving for entropy: (min=0; avg=0.000; max=0)us
Jul 19 06:08:32 raspberrypi systemd[1]: Starting Daily apt upgrade and clean activities...
Jul 19 06:08:34 raspberrypi systemd[1]: apt-daily-upgrade.service: Succeeded.
Jul 19 06:08:34 raspberrypi systemd[1]: Finished Daily apt upgrade and clean activities.
Jul 19 06:08:34 raspberrypi systemd[1]: apt-daily-upgrade.service: Consumed 2.013s CPU time.
Jul 19 06:10:01 raspberrypi CRON[7282]: (pi) CMD (/home/pi/Bins/wetter.sh)
Jul 19 06:17:01 raspberrypi CRON[7328]: (root) CMD (  cd / && run-parts --report /etc/cron.hourly)
Jul 19 06:25:01 raspberrypi CRON[7370]: (root) CMD (test -x /usr/sbin/anacron || ( cd / && run-parts --report /etc/cron.daily ))
Jul 19 07:05:11 raspberrypi rngd[534]: stats: bits received from HRNG source: 2740064
Jul 19 07:05:11 raspberrypi rngd[534]: stats: bits sent to kernel pool: 2698432
Jul 19 07:05:11 raspberrypi rngd[534]: stats: entropy added to kernel pool: 2698432
Jul 19 07:05:11 raspberrypi rngd[534]: stats: FIPS 140-2 successes: 137
Jul 19 07:05:11 raspberrypi rngd[534]: stats: FIPS 140-2 failures: 0
Jul 19 07:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Monobit: 0
Jul 19 07:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Poker: 0
Jul 19 07:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Runs: 0
Jul 19 07:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Long run: 0
Jul 19 07:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Continuous run: 0
Jul 19 07:05:11 raspberrypi rngd[534]: stats: HRNG source speed: (min=606.090; avg=876.027; max=971.414)Kibits/s
Jul 19 07:05:11 raspberrypi rngd[534]: stats: FIPS tests speed: (min=18.903; avg=25.951; max=51.830)Mibits/s
Jul 19 07:05:11 raspberrypi rngd[534]: stats: Lowest ready-buffers level: 2
Jul 19 07:05:11 raspberrypi rngd[534]: stats: Entropy starvations: 0
Jul 19 07:05:11 raspberrypi rngd[534]: stats: Time spent starving for entropy: (min=0; avg=0.000; max=0)us
Jul 19 07:10:01 raspberrypi CRON[7738]: (pi) CMD (/home/pi/Bins/wetter.sh)
Jul 19 07:17:01 raspberrypi CRON[7808]: (root) CMD (  cd / && run-parts --report /etc/cron.hourly)
Jul 19 08:00:02 raspberrypi dhcpcd[557]: eth0: expired address fd00::3543:cdd1:1d1b:a0a9/64
Jul 19 08:00:02 raspberrypi dhcpcd[557]: eth0: part of Router Advertisement expired
Jul 19 08:00:02 raspberrypi dhcpcd[557]: eth0: deleting route to fd00::/64
Jul 19 08:05:11 raspberrypi rngd[534]: stats: bits received from HRNG source: 2780064
Jul 19 08:05:11 raspberrypi rngd[534]: stats: bits sent to kernel pool: 2728192
Jul 19 08:05:11 raspberrypi rngd[534]: stats: entropy added to kernel pool: 2728192
Jul 19 08:05:11 raspberrypi rngd[534]: stats: FIPS 140-2 successes: 139
Jul 19 08:05:11 raspberrypi rngd[534]: stats: FIPS 140-2 failures: 0
Jul 19 08:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Monobit: 0
Jul 19 08:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Poker: 0
Jul 19 08:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Runs: 0
Jul 19 08:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Long run: 0
Jul 19 08:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Continuous run: 0
Jul 19 08:05:11 raspberrypi rngd[534]: stats: HRNG source speed: (min=606.090; avg=876.710; max=971.414)Kibits/s
Jul 19 08:05:11 raspberrypi rngd[534]: stats: FIPS tests speed: (min=18.903; avg=25.922; max=51.830)Mibits/s
Jul 19 08:05:11 raspberrypi rngd[534]: stats: Lowest ready-buffers level: 2
Jul 19 08:05:11 raspberrypi rngd[534]: stats: Entropy starvations: 0
Jul 19 08:05:11 raspberrypi rngd[534]: stats: Time spent starving for entropy: (min=0; avg=0.000; max=0)us
Jul 19 08:10:01 raspberrypi CRON[8124]: (pi) CMD (/home/pi/Bins/wetter.sh)
Jul 19 08:17:01 raspberrypi CRON[8194]: (root) CMD (  cd / && run-parts --report /etc/cron.hourly)
Jul 19 09:05:11 raspberrypi rngd[534]: stats: bits received from HRNG source: 2800064
Jul 19 09:05:11 raspberrypi rngd[534]: stats: bits sent to kernel pool: 2758432
Jul 19 09:05:11 raspberrypi rngd[534]: stats: entropy added to kernel pool: 2758432
Jul 19 09:05:11 raspberrypi rngd[534]: stats: FIPS 140-2 successes: 140
Jul 19 09:05:11 raspberrypi rngd[534]: stats: FIPS 140-2 failures: 0
Jul 19 09:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Monobit: 0
Jul 19 09:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Poker: 0
Jul 19 09:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Runs: 0
Jul 19 09:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Long run: 0
Jul 19 09:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Continuous run: 0
Jul 19 09:05:11 raspberrypi rngd[534]: stats: HRNG source speed: (min=606.090; avg=877.116; max=971.414)Kibits/s
Jul 19 09:05:11 raspberrypi rngd[534]: stats: FIPS tests speed: (min=18.903; avg=25.900; max=51.830)Mibits/s
Jul 19 09:05:11 raspberrypi rngd[534]: stats: Lowest ready-buffers level: 2
Jul 19 09:05:11 raspberrypi rngd[534]: stats: Entropy starvations: 0
Jul 19 09:05:11 raspberrypi rngd[534]: stats: Time spent starving for entropy: (min=0; avg=0.000; max=0)us
Jul 19 09:10:01 raspberrypi CRON[8481]: (pi) CMD (/home/pi/Bins/wetter.sh)
Jul 19 09:17:01 raspberrypi CRON[8524]: (root) CMD (  cd / && run-parts --report /etc/cron.hourly)
Jul 19 10:05:11 raspberrypi rngd[534]: stats: bits received from HRNG source: 2840064
Jul 19 10:05:11 raspberrypi rngd[534]: stats: bits sent to kernel pool: 2788192
Jul 19 10:05:11 raspberrypi rngd[534]: stats: entropy added to kernel pool: 2788192
Jul 19 10:05:11 raspberrypi rngd[534]: stats: FIPS 140-2 successes: 142
Jul 19 10:05:11 raspberrypi rngd[534]: stats: FIPS 140-2 failures: 0
Jul 19 10:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Monobit: 0
Jul 19 10:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Poker: 0
Jul 19 10:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Runs: 0
Jul 19 10:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Long run: 0
Jul 19 10:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Continuous run: 0
Jul 19 10:05:11 raspberrypi rngd[534]: stats: HRNG source speed: (min=606.090; avg=877.608; max=971.414)Kibits/s
Jul 19 10:05:11 raspberrypi rngd[534]: stats: FIPS tests speed: (min=18.903; avg=25.902; max=51.830)Mibits/s
Jul 19 10:05:11 raspberrypi rngd[534]: stats: Lowest ready-buffers level: 2
Jul 19 10:05:11 raspberrypi rngd[534]: stats: Entropy starvations: 0
Jul 19 10:05:11 raspberrypi rngd[534]: stats: Time spent starving for entropy: (min=0; avg=0.000; max=0)us
Jul 19 10:10:01 raspberrypi CRON[8813]: (pi) CMD (/home/pi/Bins/wetter.sh)
Jul 19 10:17:01 raspberrypi CRON[8861]: (root) CMD (  cd / && run-parts --report /etc/cron.hourly)
Jul 19 11:05:11 raspberrypi rngd[534]: stats: bits received from HRNG source: 2860064
Jul 19 11:05:11 raspberrypi rngd[534]: stats: bits sent to kernel pool: 2818432
Jul 19 11:05:11 raspberrypi rngd[534]: stats: entropy added to kernel pool: 2818432
Jul 19 11:05:11 raspberrypi rngd[534]: stats: FIPS 140-2 successes: 143
Jul 19 11:05:11 raspberrypi rngd[534]: stats: FIPS 140-2 failures: 0
Jul 19 11:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Monobit: 0
Jul 19 11:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Poker: 0
Jul 19 11:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Runs: 0
Jul 19 11:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Long run: 0
Jul 19 11:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Continuous run: 0
Jul 19 11:05:11 raspberrypi rngd[534]: stats: HRNG source speed: (min=606.090; avg=877.929; max=971.414)Kibits/s
Jul 19 11:05:11 raspberrypi rngd[534]: stats: FIPS tests speed: (min=18.903; avg=25.893; max=51.830)Mibits/s
Jul 19 11:05:11 raspberrypi rngd[534]: stats: Lowest ready-buffers level: 2
Jul 19 11:05:11 raspberrypi rngd[534]: stats: Entropy starvations: 0
Jul 19 11:05:11 raspberrypi rngd[534]: stats: Time spent starving for entropy: (min=0; avg=0.000; max=0)us
Jul 19 11:10:01 raspberrypi CRON[9186]: (pi) CMD (/home/pi/Bins/wetter.sh)
Jul 19 11:17:01 raspberrypi CRON[9233]: (root) CMD (  cd / && run-parts --report /etc/cron.hourly)
Jul 19 12:05:11 raspberrypi rngd[534]: stats: bits received from HRNG source: 2900064
Jul 19 12:05:11 raspberrypi rngd[534]: stats: bits sent to kernel pool: 2848192
Jul 19 12:05:11 raspberrypi rngd[534]: stats: entropy added to kernel pool: 2848192
Jul 19 12:05:11 raspberrypi rngd[534]: stats: FIPS 140-2 successes: 145
Jul 19 12:05:11 raspberrypi rngd[534]: stats: FIPS 140-2 failures: 0
Jul 19 12:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Monobit: 0
Jul 19 12:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Poker: 0
Jul 19 12:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Runs: 0
Jul 19 12:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Long run: 0
Jul 19 12:05:11 raspberrypi rngd[534]: stats: FIPS 140-2(2001-10-10) Continuous run: 0
Jul 19 12:05:11 raspberrypi rngd[534]: stats: HRNG source speed: (min=606.090; avg=878.697; max=971.414)Kibits/s
Jul 19 12:05:11 raspberrypi rngd[534]: stats: FIPS tests speed: (min=18.903; avg=26.055; max=51.830)Mibits/s
Jul 19 12:05:11 raspberrypi rngd[534]: stats: Lowest ready-buffers level: 2
Jul 19 12:05:11 raspberrypi rngd[534]: stats: Entropy starvations: 0
Jul 19 12:05:11 raspberrypi rngd[534]: stats: Time spent starving for entropy: (min=0; avg=0.000; max=0)us
Jul 19 12:09:59 raspberrypi systemd[1]: Created slice User Slice of UID 1000.
Jul 19 12:09:59 raspberrypi systemd[1]: Starting User Runtime Directory /run/user/1000...
Jul 19 12:09:59 raspberrypi systemd[1]: Finished User Runtime Directory /run/user/1000.
Jul 19 12:09:59 raspberrypi systemd[1]: Starting User Manager for UID 1000...
Jul 19 12:10:00 raspberrypi systemd[9513]: Queued start job for default target Main User Target.
Jul 19 12:10:00 raspberrypi systemd[9513]: Created slice User Application Slice.
Jul 19 12:10:00 raspberrypi systemd[9513]: Reached target Paths.
Jul 19 12:10:00 raspberrypi systemd[9513]: Reached target Timers.
Jul 19 12:10:00 raspberrypi systemd[9513]: Starting D-Bus User Message Bus Socket.
Jul 19 12:10:00 raspberrypi systemd[9513]: Listening on GnuPG network certificate management daemon.
Jul 19 12:10:00 raspberrypi systemd[9513]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers).
Jul 19 12:10:00 raspberrypi systemd[9513]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).
Jul 19 12:10:00 raspberrypi systemd[9513]: Listening on GnuPG cryptographic agent (ssh-agent emulation).
Jul 19 12:10:00 raspberrypi systemd[9513]: Listening on GnuPG cryptographic agent and passphrase cache.
Jul 19 12:10:00 raspberrypi systemd[9513]: Listening on Multimedia System.
Jul 19 12:10:00 raspberrypi systemd[9513]: Listening on debconf communication socket.
Jul 19 12:10:00 raspberrypi systemd[9513]: Listening on Sound System.
Jul 19 12:10:00 raspberrypi systemd[9513]: Listening on D-Bus User Message Bus Socket.
Jul 19 12:10:00 raspberrypi systemd[9513]: Reached target Sockets.
Jul 19 12:10:00 raspberrypi systemd[9513]: Reached target Basic System.
Jul 19 12:10:00 raspberrypi systemd[1]: Started User Manager for UID 1000.
Jul 19 12:10:00 raspberrypi systemd[9513]: Started Multimedia Service.
Jul 19 12:10:00 raspberrypi systemd[9513]: Starting Sound Service...
Jul 19 12:10:00 raspberrypi systemd[1]: Started Session 215 of user pi.
Jul 19 12:10:00 raspberrypi pipewire[9528]: could not set nice-level to -11: Permission denied
Jul 19 12:10:00 raspberrypi rtkit-daemon[840]: Supervising 0 threads of 0 processes of 1 users.
Jul 19 12:10:00 raspberrypi rtkit-daemon[840]: Supervising 0 threads of 0 processes of 1 users.
Jul 19 12:10:00 raspberrypi pipewire[9528]: could not make thread realtime: Permission denied
Jul 19 12:10:01 raspberrypi systemd[9513]: Started D-Bus User Message Bus.
Jul 19 12:10:01 raspberrypi pipewire[9528]: Failed to receive portal pid: org.freedesktop.DBus.Error.NameHasNoOwner: Could not get PID of name 'org.freedesktop.portal.Desktop': no such name
Jul 19 12:10:01 raspberrypi pipewire-media-session[9537]: could not set nice-level to -11: Permission denied
Jul 19 12:10:01 raspberrypi rtkit-daemon[840]: Supervising 0 threads of 0 processes of 1 users.
Jul 19 12:10:01 raspberrypi rtkit-daemon[840]: Supervising 0 threads of 0 processes of 1 users.
Jul 19 12:10:01 raspberrypi pipewire-media-session[9537]: could not make thread realtime: Permission denied
Jul 19 12:10:01 raspberrypi rtkit-daemon[840]: Supervising 0 threads of 0 processes of 1 users.
Jul 19 12:10:01 raspberrypi rtkit-daemon[840]: Supervising 0 threads of 0 processes of 1 users.
Jul 19 12:10:01 raspberrypi rtkit-daemon[840]: Supervising 0 threads of 0 processes of 1 users.
Jul 19 12:10:01 raspberrypi rtkit-daemon[840]: Supervising 0 threads of 0 processes of 1 users.
Jul 19 12:10:01 raspberrypi rtkit-daemon[840]: Supervising 0 threads of 0 processes of 1 users.
Jul 19 12:10:03 raspberrypi CRON[9541]: (pi) CMD (/home/pi/Bins/wetter.sh)
Jul 19 12:10:04 raspberrypi pulseaudio[9529]: Failed to find a working profile.
Jul 19 12:10:04 raspberrypi pulseaudio[9529]: Failed to load module "module-alsa-card" (argument: "device_id="1" name="platform-3f902000.hdmi" card_name="alsa_card.platform-3f902000.hdmi" namereg_fail=false tsched=no fixed_latency_range=no ignore_dB=no deferred_volume=yes use_ucm=yes avoid_resampling=no card_properties="module-udev-detect.discovered=1""): initialization failed.
Jul 19 12:10:04 raspberrypi dbus-daemon[443]: [system] Activating via systemd: service name='org.bluez' unit='dbus-org.bluez.service' requested by ':1.266' (uid=1000 pid=9529 comm="/usr/bin/pulseaudio --daemonize=no --log-target=jo")
Jul 19 12:10:04 raspberrypi systemd[1]: Condition check resulted in Bluetooth service being skipped.
Jul 19 12:10:04 raspberrypi systemd[9513]: Started Sound Service.
Jul 19 12:10:04 raspberrypi systemd[9513]: Reached target Main User Target.
Jul 19 12:10:04 raspberrypi systemd[9513]: Startup finished in 4.783s.

TOP bei laufendem System:
top - 12:17:33 up 3 days, 23:12,  1 user,  load average: 0,10, 0,11, 0,15
Tasks: 135 total,  1 running, 134 sleeping,  0 stopped,  0 zombie
%CPU(s):  3,7 us,  0,3 sy,  0,0 ni, 95,8 id,  0,2 wa,  0,0 hi,  0,1 si,  0,0 st
MiB Spch:    922,0 total,    353,7 free,    303,6 used,    264,7 buff/cache
MiB Swap:    100,0 total,    56,2 free,    43,8 used.    560,2 avail Spch

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM    ZEIT+ BEFEHL
 5169 fhem      20  0  196292 182348  7468 S  0,0  19,3  32:29.19 perl
11872 pi        20  0  246856  95440  19184 S  14,2  10,1  97:36.51 node-red
  141 root      20  0  237748  36980  36604 S  0,3  3,9  2:35.51 systemd-journal
 9634 pi        20  0  104620  9968  8092 S  0,0  1,1  0:00.27 pulseaudio
 9618 pi        20  0  14544  7588  6604 S  0,0  0,8  0:00.60 systemd
 9615 root      20  0  14516  6888  5952 S  0,0  0,7  0:01.01 sshd
    1 root      20  0  34972  6424  4872 S  0,0  0,7  1:28.07 systemd
 9637 pi        20  0  19568  4976  4212 S  0,0  0,5  0:00.04 pipewire-media-
 9633 pi        20  0  26604  4892  3972 S  0,0  0,5  0:00.03 pipewire
  457 root      20  0  41264  4852  3508 S  0,0  0,5  0:03.66 polkitd
  468 root      20  0  13072  4800  4428 S  0,0  0,5  0:02.85 systemd-logind
 9644 pi        20  0  14516  4428  3488 S  0,0  0,5  0:00.01 sshd
 9645 pi        20  0    8600  3864  2908 S  0,0  0,4  0:00.17 bash
 9619 pi        20  0  38424  3528  1640 S  0,0  0,4  0:00.00 (sd-pam)
 9656 pi        20  0  11468  3228  2636 R  0,7  0,3  0:00.20 top
 9636 pi        20  0    7560  3088  2812 S  0,0  0,3  0:00.02 dbus-daemon
 1435 root      20  0  95708  2824  2552 S  0,0  0,3  0:04.61 packagekitd
  580 root      20  0  48584  2516  2244 S  0,0  0,3  0:00.58 ModemManager
  431 avahi    20  0    6916  1976  1732 S  0,0  0,2  1:41.23 avahi-daemon
  443 message+  20  0    8048  1788  1356 S  0,0  0,2  0:14.83 dbus-daemon
  583 root      20  0  12400  1612  1480 S  0,0  0,2  0:00.14 sshd
  557 root      20  0    2804  1580  1408 S  0,0  0,2  0:13.72 dhcpcd
  581 root      20  0  36384  1160  1044 S  0,0  0,1  0:27.81 vncserver-x11-c
  441 root      20  0    8200  1032    960 S  0,0  0,1  0:01.69 cron
  167 root      20  0  20448    896    840 S  0,0  0,1  0:52.16 systemd-udevd
  328 systemd+  20  0  22292    500    444 S  0,0  0,1  0:01.92 systemd-timesyn
 3378 root      20  0  26544    216      0 S  0,0  0,0  0:02.41 rsyslogd
  840 rtkit    21  1  24208    100      0 S  0,0  0,0  0:07.07 rtkit-daemon
  470 root      20  0  11792    48      0 S  0,0  0,0  0:03.14 wpa_supplicant
  534 root      20  0  27696    36      0 S  0,0  0,0  0:01.21 rngd
  469 nobody    20  0    5312    20      0 S  0,0  0,0  0:05.01 thd
  744 colord    20  0  79108      8      8 S  0,0  0,0  0:01.59 colord
    2 root      20  0      0      0      0 S  0,0  0,0  0:01.19 kthreadd
    3 root      0 -20      0      0      0 I  0,0  0,0  0:00.00 rcu_gp
Titel: Aw: perl invoked oom-killer -> Obwohl 350MB Ram frei sind?
Beitrag von: Wernieman am 19 Juli 2023, 17:08:15
top zeigt Dir das "Normale System an", der OOM sagt etwas anderes:
Killed process 11307 (perl) total-vm:836320kBc.a. 830000kB sind fürs System zu viel ...

Außerdem wird in Deinem System schon viel in den SPA gepakt (SWAP-Free laut OOM =0)

Da die letzte Meldung ein HTTP-Zugriff mit Fehlermeldung ist ... könnte es sein, das Dein FHEM Zyklisch zu viel Speicher braucht? z.B: bei Verarbeitung obiger Http-Abfrage?
Ich meine Folgende Meldung:
bridge: http request failed: read from https://192.168.1.112:443 timed out
Hast Du "Presence" Devices die Du mit "ping" abfragst? Oder sonstige "geforkte" Prozesse? Eventuell diese mal begrenzt?
Titel: Aw: perl invoked oom-killer -> Obwohl 350MB Ram frei sind?
Beitrag von: Olli7766 am 19 Juli 2023, 23:16:48
Zitat von: Wernieman am 19 Juli 2023, 17:08:15Da die letzte Meldung ein HTTP-Zugriff mit Fehlermeldung ist ... könnte es sein, das Dein FHEM Zyklisch zu viel Speicher braucht? z.B: bei Verarbeitung obiger Http-Abfrage?
Ich meine Folgende Meldung:
Das ist meine HUE Bridge. Dies ist angelegt und bringt ständig diese Lesefehler:

Logfile:
2023.07.19 02:24:02 2: bridge: http request failed:  SSL connect attempt failed
2023.07.19 02:24:02 2: bridge: EventStream: terminated; retrying later
2023.07.19 03:24:04 2: bridge: http request failed: read from https://192.168.1.112:443 timed out
2023.07.19 03:24:04 2: bridge: EventStream: terminated; retrying later
2023.07.19 04:24:07 2: bridge: http request failed: read from https://192.168.1.112:443 timed out
2023.07.19 04:24:07 2: bridge: EventStream: terminated; retrying later
2023.07.19 06:47:29 2: AttrTemplates: got 259 entries
2023.07.19 07:04:43 3: EnOcean set EnO_0599D728 on
2023.07.19 08:09:07 2: bridge: http request failed: read from https://192.168.1.112:443 timed out
2023.07.19 08:09:07 2: bridge: EventStream: terminated
2023.07.19 09:23:55 2: bridge: http request failed: read from https://192.168.1.112:443 timed out
2023.07.19 09:23:55 2: bridge: EventStream: terminated
2023.07.19 11:31:26 3: EnOcean set EnO_0599D728 off
2023.07.19 12:39:45 2: bridge: http request failed: read from https://192.168.1.112:443 timed out
2023.07.19 12:39:45 2: bridge: EventStream: terminated
2023.07.19 12:40:04 3: EnOcean set EnO_0599D728 off
2023.07.19 13:39:45 2: bridge: http request failed: read from https://192.168.1.112:443 timed out
2023.07.19 13:39:45 2: bridge: EventStream: terminated; retrying later
2023.07.19 14:39:47 2: bridge: http request failed: read from https://192.168.1.112:443 timed out
2023.07.19 14:39:47 2: bridge: EventStream: terminated; retrying later
2023.07.19 15:08:38 3: EnOcean set EnO_0599D728 off
2023.07.19 15:39:50 2: bridge: http request failed: read from https://192.168.1.112:443 timed out
2023.07.19 15:39:50 2: bridge: EventStream: terminated; retrying later
2023.07.19 17:55:26 2: bridge: http request failed: read from https://192.168.1.112:443 timed out
2023.07.19 17:55:26 2: bridge: EventStream: terminated
2023.07.19 21:55:16 2: bridge: http request failed: read from https://192.168.1.112:443 timed out
2023.07.19 21:55:16 2: bridge: EventStream: terminated
Warum hier ein Timeout kommt kann ich nicht nachvollziehen. Die Bridge läuft ohne Probleme eigentlich.

Mit Presence Devices meinst du Anwesendheitssensoren?
Nein eigentlich wird nichts gepingt. Ich habe jede Menge FS20 Zeugs drin.
Am besten ich hänge mal die Config an.

Was meinst du mit geforkte Prozesse?

Titel: Aw: perl invoked oom-killer -> Obwohl 350MB Ram frei sind?
Beitrag von: Wernieman am 20 Juli 2023, 08:24:21
Für "non blocking" Prozesse werden FHEM Instansen "geforkt". Sieht man am bestezen mit:
ps aux | grep fhem
Titel: Aw: perl invoked oom-killer -> Obwohl 350MB Ram frei sind?
Beitrag von: Olli7766 am 20 Juli 2023, 09:31:14
Sieht ziemlich sauber aus:

pi@raspberrypi:~ $ ps aux | grep fhem
fhem      5169 16.2 45.2 475528 426808 ?       S    Jul19 302:49 /usr/bin/perl fhem.pl fhem.cfg
pi       18630  0.0  0.0   7472   508 pts/0    S+   09:30   0:00 grep --color=auto fhem
pi@raspberrypi:~ $

Auffällig ist, dass im top der Speicher langsam voll läuft. Ist jetzt bei 50%.
Zudem ständige CPU peaks bis auf 100% für ein paar Sekunden..............
Das ist nicht normal. Das Logfile vom FHEM zeigt nichts......

top - 09:33:09 up 4 days, 20:28,  1 user,  load average: 0,34, 0,43, 0,45
Tasks: 136 total,   2 running, 134 sleeping,   0 stopped,   0 zombie
%CPU(s):  7,4 us,  4,3 sy,  0,0 ni, 88,3 id,  0,0 wa,  0,0 hi,  0,0 si,  0,0 st
MiB Spch:    922,0 total,    278,4 free,    518,0 used,    125,5 buff/cache
MiB Swap:    100,0 total,      7,6 free,     92,4 used.    344,1 avail Spch

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     ZEIT+ BEFEHL
 5169 fhem      20   0  475788 426608   4576 R  43,9  45,2 303:34.74 perl
11872 pi        20   0  248160  65248   9788 S   0,3   6,9 131:22.80 node-red
  141 root      20   0  254132  14776  14440 S   0,0   1,6   2:55.80 systemd-journal
18606 pi        20   0  104620   9004   7756 S   0,0   1,0   0:00.37 pulseaudio
18589 pi        20   0   14544   6760   6652 S   0,0   0,7   0:00.84 systemd
18582 root      20   0   14516   6268   5888 S   0,0   0,7   0:01.16 sshd
    1 root      20   0   34972   6264   4868 S   0,0   0,7   1:29.80 systemd
18626 pi        20   0   19576   4876   4112 S   0,0   0,5   0:00.04 pipewire-media-
  468 root      20   0   13072   4608   4248 S   0,0   0,5   0:03.18 systemd-logind
18605 pi        20   0   26604   4384   3880 S   0,0   0,5   0:00.06 pipewire
  457 root      20   0   41264   4144   3184 S   0,0   0,4   0:04.26 polkitd
18613 pi        20   0   14516   3716   3352 S   0,0   0,4   0:00.02 sshd
18614 pi        20   0    8600   3396   2856 S   0,0   0,4   0:00.17 bash
18634 pi        20   0   11468   3196   2700 R   0,3   0,3   0:00.24 top
18616 pi        20   0    7560   2800   2800 S   0,0   0,3   0:00.04 dbus-daemon
  580 root      20   0   48584   2388   2064 S   0,0   0,3   0:00.61 ModemManager
 1435 root      20   0   95708   2348   2164 S   0,0   0,2   0:05.50 packagekitd
  443 message+  20   0    8048   2276   1808 S   0,0   0,2   0:15.62 dbus-daemon
18591 pi        20   0   38424   2260   1640 S   0,0   0,2   0:00.00 (sd-pam)
  328 systemd+  20   0   22292   1976   1892 S   0,0   0,2   0:02.20 systemd-timesyn
  431 avahi     20   0    6916   1792   1580 S   0,0   0,2   2:00.80 avahi-daemon
  583 root      20   0   12400   1724   1628 S   0,0   0,2   0:00.15 sshd
  557 root      20   0    2804   1488   1328 S   0,0   0,2   0:16.75 dhcpcd
  840 rtkit     21   1   24208   1436   1356 S   0,0   0,2   0:08.57 rtkit-daemon
  581 root      20   0   36384   1236   1196 S   0,0   0,1   0:33.83 vncserver-x11-c
  167 root      20   0   20448   1176   1120 S   0,0   0,1   0:52.41 systemd-udevd
  441 root      20   0    8200   1032    960 S   0,0   0,1   0:02.00 cron
  534 root      20   0   27696    884    868 S   0,0   0,1   0:01.46 rngd
  451 avahi     20   0    6756    556    556 S   0,0   0,1   0:00.00 avahi-daemon
  470 root      20   0   11792    392    344 S   0,0   0,0   0:03.76 wpa_supplicant
 3378 root      20   0   26544    328    168 S   0,0   0,0   0:05.48 rsyslogd
  469 nobody    20   0    5312    228    208 S   0,0   0,0   0:06.08 thd
  744 colord    20   0   79108      8      8 S   0,0   0,0   0:01.59 colord
    2 root      20   0       0      0      0 S   0,0   0,0   0:01.41 kthreadd
    3 root       0 -20       0      0      0 I   0,0   0,0   0:00.00 rcu_gp
    4 root       0 -20       0      0      0 I   0,0   0,0   0:00.00 rcu_par_gp
    5 root       0 -20       0      0      0 I   0,0   0,0   0:00.00 slub_flushwq
    6 root       0 -20       0      0      0 I   0,0   0,0   0:00.00 netns
   10 root       0 -20       0      0      0 I   0,0   0,0   0:00.00 mm_percpu_wq
   11 root      20   0       0      0      0 I   0,0   0,0   0:00.00 rcu_tasks_rude_kthread
   12 root      20   0       0      0      0 I   0,0   0,0   0:00.00 rcu_tasks_trace_kthread
   13 root      20   0       0      0      0 S   0,3   0,0   0:59.61 ksoftirqd/0
   14 root      20   0       0      0      0 I   0,0   0,0   0:58.46 rcu_sched
   15 root      rt   0       0      0      0 S   0,0   0,0   0:00.18 migration/0
   16 root      20   0       0      0      0 S   0,0   0,0   0:00.00 cpuhp/0
   17 root      20   0       0      0      0 S   0,0   0,0   0:00.00 cpuhp/1
   18 root      rt   0       0      0      0 S   0,0   0,0   0:02.03 migration/1
   19 root      20   0       0      0      0 S   0,0   0,0   0:03.28 ksoftirqd/1

top - 09:37:42 up 4 days, 20:32,  1 user,  load average: 0,06, 0,19, 0,34
Tasks: 135 total,   1 running, 134 sleeping,   0 stopped,   0 zombie
%CPU(s): 14,8 us, 10,7 sy,  0,0 ni, 74,5 id,  0,0 wa,  0,0 hi,  0,0 si,  0,0 st
MiB Spch:    922,0 total,    280,0 free,    522,6 used,    119,4 buff/cache
MiB Swap:    100,0 total,      5,6 free,     94,4 used.    339,6 avail Spch

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     ZEIT+ BEFEHL
 5169 fhem      20   0  476280 429532   4776 S  89,7  45,5 305:02.83 perl
11872 pi        20   0  248160  65424   9784 S   0,0   6,9 131:28.93 node-red
  141 root      20   0  254132  13880  13536 S   0,0   1,5   2:55.88 systemd-journal
18606 pi        20   0  104620   7692   7692 S   0,0   0,8   0:00.37 pulseaudio
18589 pi        20   0   14544   6756   6652 S   0,0   0,7   0:00.84 systemd
18582 root      20   0   14516   6268   5888 S   0,0   0,7   0:01.16 sshd
    1 root      20   0   34972   6176   4868 S   0,0   0,7   1:29.81 systemd
  468 root      20   0   13072   4608   4248 S   0,0   0,5   0:03.18 systemd-logind
18626 pi        20   0   19576   4320   4320 S   0,0   0,5   0:00.04 pipewire-media-
  457 root      20   0   41264   4136   3184 S   0,0   0,4   0:04.26 polkitd
18605 pi        20   0   26604   3876   3876 S   0,0   0,4   0:00.06 pipewire
18613 pi        20   0   14516   3712   3352 S   0,0   0,4   0:00.22 sshd
18614 pi        20   0    8600   3296   2856 S   0,0   0,3   0:00.17 bash
18634 pi        20   0   11468   3128   2700 R   0,7   0,3   0:02.13 top
18616 pi        20   0    7560   2800   2800 S   0,0   0,3   0:00.04 dbus-daemon
  580 root      20   0   48584   2388   2064 S   0,0   0,3   0:00.61 ModemManager
 1435 root      20   0   95708   2348   2164 S   0,0   0,2   0:05.50 packagekitd
  443 message+  20   0    8048   2276   1808 S   0,0   0,2   0:15.62 dbus-daemon
18591 pi        20   0   38424   2260   1640 S   0,0   0,2   0:00.00 (sd-pam)
  328 systemd+  20   0   22292   1976   1892 S   0,0   0,2   0:02.20 systemd-timesyn
  431 avahi     20   0    6916   1792   1580 S   0,0   0,2   2:00.88 avahi-daemon
  583 root      20   0   12400   1724   1628 S   0,0   0,2   0:00.15 sshd
  557 root      20   0    2804   1492   1328 S   0,0   0,2   0:16.78 dhcpcd
  840 rtkit     21   1   24208   1436   1356 S   0,0   0,2   0:08.59 rtkit-daemon
  581 root      20   0   36384   1228   1188 S   0,0   0,1   0:33.86 vncserver-x11-c
  167 root      20   0   20448   1172   1116 S   0,0   0,1   0:52.41 systemd-udevd
  441 root      20   0    8200   1020    948 S   0,0   0,1   0:02.00 cron
 3378 root      20   0   26544    928    784 S   0,0   0,1   0:05.49 rsyslogd
  534 root      20   0   27696    884    868 S   0,0   0,1   0:01.46 rngd
  451 avahi     20   0    6756    556    556 S   0,0   0,1   0:00.00 avahi-daemon
  470 root      20   0   11792    392    344 S   0,0   0,0   0:03.76 wpa_supplicant
  469 nobody    20   0    5312    228    208 S   0,0   0,0   0:06.09 thd
  744 colord    20   0   79108      8      8 S   0,0   0,0   0:01.59 colord
    2 root      20   0       0      0      0 S   0,0   0,0   0:01.41 kthreadd
    3 root       0 -20       0      0      0 I   0,0   0,0   0:00.00 rcu_gp
    4 root       0 -20       0      0      0 I   0,0   0,0   0:00.00 rcu_par_gp
    5 root       0 -20       0      0      0 I   0,0   0,0   0:00.00 slub_flushwq
    6 root       0 -20       0      0      0 I   0,0   0,0   0:00.00 netns
   10 root       0 -20       0      0      0 I   0,0   0,0   0:00.00 mm_percpu_wq
   11 root      20   0       0      0      0 I   0,0   0,0   0:00.00 rcu_tasks_rude_kthread
   12 root      20   0       0      0      0 I   0,0   0,0   0:00.00 rcu_tasks_trace_kthread
   13 root      20   0       0      0      0 S   0,0   0,0   0:59.64 ksoftirqd/0
   14 root      20   0       0      0      0 I   0,0   0,0   0:58.50 rcu_sched
   15 root      rt   0       0      0      0 S   0,0   0,0   0:00.18 migration/0
   16 root      20   0       0      0      0 S   0,0   0,0   0:00.00 cpuhp/0
   17 root      20   0       0      0      0 S   0,0   0,0   0:00.00 cpuhp/1
   18 root      rt   0       0      0      0 S   0,0   0,0   0:02.03 migration/1
   19 root      20   0       0      0      0 S   0,0   0,0   0:03.28 ksoftirqd/1

Titel: Aw: perl invoked oom-killer -> Obwohl 350MB Ram frei sind?
Beitrag von: Wernieman am 20 Juli 2023, 10:41:48
Es gibt einen Großen Unterschied zwischen Windows und Unix in der Speicherberechnung:

Unix: Verwendeter Speicher (incl. Cache)
Windows: Verwendeter Speicher (!ohne! Cache)

Da der Cache bei Unix schon immer Dynamisch ist, muß man zum "freien Speicher" auch die "Cache" Zeile beachten. Erst dann hat meine Aussage, wie viel Speicher für das System zur Verfügung steht. Hatten wir hier schon mehrfach betrachtet.

Aber .. braucht Dein FHEM wirklich 45% des Speichers? also c.a. 450MByte von 1G?
Titel: Aw: perl invoked oom-killer -> Obwohl 350MB Ram frei sind?
Beitrag von: Olli7766 am 20 Juli 2023, 12:16:08
Was du sagst verstehe ich nicht ganz.

RAM ist ein Stück Hardware. Deshalb wird der RAM auch fest durch die Hardware vorgegeben.
In meinem Fall hat der Pi 1GB RAM.

Ich gehe stark davon aus, dass wenn top sagt 522MB used, dann ist das auch so. Ist übrigends gerade wieder abgestürzt. Da war der RAM dann mal wieder voll.
Offensichtlich gibt es irgendwie einen Memory Leak im FHEM wodurch der RAM voll läuft.

Ich habe jetzt mal das komplette HUE Zeug raus genommen, da dieser Part ja auch immer wieder die Fehler produziert. Vielleicht bringt es was.
Titel: Aw: perl invoked oom-killer -> Obwohl 350MB Ram frei sind?
Beitrag von: Wernieman am 20 Juli 2023, 23:08:35
Falsch:
Wenn 600 Ram used, aber 300 Caced, dann verwenden Programme nur 300 Ram .. Windows würde schreiben: 300 Used ..
Titel: Aw: perl invoked oom-killer -> Obwohl 350MB Ram frei sind?
Beitrag von: Olli7766 am 21 Juli 2023, 15:28:37
Also HUE raus zu schmeißen hat nichts gebracht.

Nach 24 Stunden ist der RAM wieder voll gelaufen:

top - 15:26:28 up 6 days,  2:21,  1 user,  load average: 0,01, 0,20, 0,38
Tasks: 135 total,   1 running, 134 sleeping,   0 stopped,   0 zombie
%CPU(s):  0,2 us,  0,0 sy,  0,0 ni, 99,8 id,  0,0 wa,  0,0 hi,  0,0 si,  0,0 st
MiB Spch:    922,0 total,    235,1 free,    488,4 used,    198,4 buff/cache
MiB Swap:    100,0 total,     42,1 free,     57,9 used.    371,8 avail Spch

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     ZEIT+ BEFEHL
19631 fhem      20   0  436628 372804   3588 S   0,0  39,5 234:24.36 perl
11872 pi        20   0  249712  82204  10872 S   0,3   8,7 178:14.28 node-red
  141 root      20   0  294984  25772  25436 S   0,0   2,7   3:24.77 systemd-journal
31960 pi        20   0  104624  10084   8200 S   0,0   1,1   0:00.36 pulseaudio
31944 pi        20   0   14548   7688   6704 S   0,0   0,8   0:00.57 systemd
31940 root      20   0   14516   6900   5964 S   0,0   0,7   0:01.06 sshd
    1 root      20   0   34972   6720   5156 S   0,0   0,7   1:33.52 systemd
31963 pi        20   0   19568   5184   4364 S   0,0   0,5   0:00.05 pipewire-media-
31959 pi        20   0   26604   4996   4028 S   0,0   0,5   0:00.03 pipewire
  468 root      20   0   13072   4616   4252 S   0,0   0,5   0:03.78 systemd-logind
31969 pi        20   0   14516   4380   3440 S   0,0   0,5   0:00.02 sshd
  457 root      20   0   41264   3984   2544 S   0,0   0,4   0:05.55 polkitd
31970 pi        20   0    8600   3820   2844 S   0,0   0,4   0:00.19 bash
31962 pi        20   0    7560   3440   3120 S   0,0   0,4   0:00.03 dbus-daemon
31945 pi        20   0   38424   3332   1640 S   0,0   0,4   0:00.00 (sd-pam)
32004 pi        20   0   11460   3156   2676 R   1,3   0,3   0:00.25 top
 1435 root      20   0   95708   2392   2044 S   0,0   0,3   0:06.76 packagekitd
  443 message+  20   0    8048   2376   1872 S   0,0   0,3   0:17.56 dbus-daemon
  328 systemd+  20   0   22292   2200   2112 S   0,0   0,2   0:02.57 systemd-timesyn
  431 avahi     20   0    6916   2000   1784 S   0,0   0,2   2:26.58 avahi-daemon
  580 root      20   0   48584   1948   1632 S   0,0   0,2   0:00.69 ModemManager
  167 root      20   0   20448   1900   1840 S   0,0   0,2   0:52.74 systemd-udevd
  840 rtkit     21   1   24208   1584   1504 S   0,0   0,2   0:10.70 rtkit-daemon
  583 root      20   0   12400   1516   1392 S   0,0   0,2   0:00.17 sshd
  557 root      20   0    2804   1496   1332 S   0,0   0,2   0:20.46 dhcpcd
  441 root      20   0    8200   1040    968 S   0,0   0,1   0:02.40 cron
  534 root      20   0   27696    904    864 S   0,0   0,1   0:01.78 rngd
 3378 root      20   0   26544    596    436 S   0,0   0,1   0:09.64 rsyslogd
  470 root      20   0   11792    404    356 S   0,0   0,0   0:04.59 wpa_supplicant
  469 nobody    20   0    5312    180    160 S   0,0   0,0   0:07.59 thd
  744 colord    20   0   79108      8      8 S   0,0   0,0   0:01.59 colord
    2 root      20   0       0      0      0 S   0,0   0,0   0:01.73 kthreadd
    3 root       0 -20       0      0      0 I   0,0   0,0   0:00.00 rcu_gp
    4 root       0 -20       0      0      0 I   0,0   0,0   0:00.00 rcu_par_gp
    5 root       0 -20       0      0      0 I   0,0   0,0   0:00.00 slub_flushwq
    6 root       0 -20       0      0      0 I   0,0   0,0   0:00.00 netns
   10 root       0 -20       0      0      0 I   0,0   0,0   0:00.00 mm_percpu_wq
   11 root      20   0       0      0      0 I   0,0   0,0   0:00.00 rcu_tasks_rude_kthread
   12 root      20   0       0      0      0 I   0,0   0,0   0:00.00 rcu_tasks_trace_kthread

Kann man denn FHEM nicht debuggen und sehen wo der RAM hinläuft?
Titel: Aw: perl invoked oom-killer -> Memory leak -> Ram läuft voll
Beitrag von: MadMax-FHEM am 21 Juli 2023, 15:50:49
Zitat von: Olli7766 am 21 Juli 2023, 15:28:3719631 fhem      20   0  436628 372804   3588 S   0,0  39,5 234:24.36 perl
Was hast du denn in deinem fhem wenn es fast 40% des Speichers braucht?
Ich habe denke ich auch keine kleine Installation auch auf einem PI mit 1GB und bei mir genehmigt sich fhem so ca. 13%

Wenn dein fhem wirklich 40% (schon bei Start?) benötigt, dann wird einmal geforkt und "Feierabend"...

Das
ps -ax | grep fhem
ist ja nur eine Momentaufnahme.
Um zu sehen, ob fhem forkt das öfter mal machen...

Oder eben schauen, ob du Module verwendest, die "Blocking" verwenden um "non-blocking" zu sein ;)
Diese forken...

Ansonsten gibt es noch diesen Thread:

https://forum.fhem.de/index.php?topic=84372.msg766405#msg766405

Gruß, Joachim
Titel: Aw: perl invoked oom-killer -> Memory leak -> Ram läuft voll
Beitrag von: Olli7766 am 21 Juli 2023, 21:08:25
Zitat von: MadMax-FHEM am 21 Juli 2023, 15:50:49Wenn dein fhem wirklich 40% (schon bei Start?) benötigt, dann wird einmal geforkt und "Feierabend"...
Ich glaube das Entscheidene ist, dass es beim Start mit ca. 10% Speicher läuft.
Und dann wird es immer mehr. Ganz langsam aber stetig.
Nach 24 Stunden Laufzeit bin ich bei ca. 40% RAM Auslastung.
Nach ca. 48 Stunden dann beim 80% und dann wird der Prozess gekillt und neu gestartet.

Das Thread mit dem Watchdog gehe ich mal durch. Danke für den Tipp!

Zitat von: MadMax-FHEM am 21 Juli 2023, 15:50:49Oder eben schauen, ob du Module verwendest, die "Blocking" verwenden um "non-blocking" zu sein ;)
Diese forken...
Kannst du mir erklären was du hiermit meinst bzw. wie ich das prüfen kann?