[geloest] Zombie Prozesse durch Lan-Ping

automatisierer · 14 Mai 2016, 08:01:27

Hallo,
ich bin durch Zufall (Diskussion in einem anderen Thread) darauf aufmerksam geworden, dass auf meinem System Zombie-Prozesse vorhanden sind. In meinem Fall verursachen die zwar keine Probleme, allerdings sind ein paar User der Meinung, dass man der Ursache auf den Grund gehen sollte.

Zur Lage:
Die Zombie PID's verschwinden wenn FHEM (der Eltern-Prozess) beendet wird. Wenn ich FHEM starte, sind die Zombies wieder da.
Im FHEM-Log stehen folgende Meldungen:

Code Auswählen


2016.05.13 22:06:09 1: Timeout for PRESENCE_DoLocalPingScan reached, terminated process 1685
2016.05.13 22:06:09 1: Timeout for PRESENCE_DoLocalPingScan reached, terminated process 1682
2016.05.13 22:06:09 1: Timeout for PRESENCE_DoLocalPingScan reached, terminated process 1680
2016.05.13 22:06:09 1: Timeout for PRESENCE_DoLocalPingScan reached, terminated process 1678
2016.05.13 22:06:09 1: Timeout for PRESENCE_DoLocalPingScan reached, terminated process 1676
2016.05.13 22:06:09 1: Timeout for PRESENCE_DoLocalPingScan reached, terminated process 1675
2016.05.13 22:06:09 1: Timeout for PRESENCE_DoLocalPingScan reached, terminated process 1672
2016.05.13 22:06:09 1: Timeout for PRESENCE_DoLocalPingScan reached, terminated process 1671
2016.05.13 22:05:59 1: Timeout for PRESENCE_DoLocalPingScan reached, terminated process 1669
2016.05.13 22:05:59 1: Timeout for PRESENCE_DoLocalPingScan reached, terminated process 1666
2016.05.13 22:05:59 1: Timeout for PRESENCE_DoLocalPingScan reached, terminated process 1665
2016.05.13 22:05:59 1: Timeout for PRESENCE_DoLocalPingScan reached, terminated process 1663

Die PID's passen zu den Zombie PID's die 'ps aux|grep fhem' ausgibt

Code Auswählen


bananapi@bapiFHEM ~ $ ps aux|grep fhem
fhem      1639 10.0  5.7  57000 51084 ?        S    22:04   4:31 /usr/bin/perl fhem.pl fhem.cfg
fhem      1663  0.0  0.0      0     0 ?        Z    22:04   0:00 [perl] <defunct>
fhem      1665  0.0  0.0      0     0 ?        Z    22:04   0:00 [perl] <defunct>
fhem      1666  0.0  0.0      0     0 ?        Z    22:04   0:00 [perl] <defunct>
fhem      1669  0.0  0.0      0     0 ?        Z    22:04   0:00 [perl] <defunct>
fhem      1671  0.0  0.0      0     0 ?        Z    22:05   0:00 [perl] <defunct>
fhem      1672  0.0  0.0      0     0 ?        Z    22:05   0:00 [perl] <defunct>
fhem      1675  0.0  0.0      0     0 ?        Z    22:05   0:00 [perl] <defunct>
fhem      1676  0.0  0.0      0     0 ?        Z    22:05   0:00 [perl] <defunct>
fhem      1678  0.0  0.0      0     0 ?        Z    22:05   0:00 [perl] <defunct>
fhem      1680  0.0  0.0      0     0 ?        Z    22:05   0:00 [perl] <defunct>
fhem      1682  0.0  0.0      0     0 ?        Z    22:05   0:00 [perl] <defunct>
fhem      1685  0.0  0.0      0     0 ?        Z    22:05   0:00 [perl] <defunct>
bananapi  2689  0.0  0.1   3616   920 pts/0    S+   22:49   0:00 grep --color=auto fhem

Also hängen die Zombies offensichtlich irgendwie mit dem PRESENCE Lan-Ping zusammen. Die Zombies entstehen nur während dem starten von FHEM, danach nicht mehr und die definierten Lan-Pings funktionieren alle. Deaktiviere ich die Lan-Pings während dem Start und aktiviere sie wieder wenn FHEM vollständig gestartet ist, dann entstehen auch keine Zombies.

Es laufen nicht alle definierten LanPings in den Timeout und es ist unabhängig davon, ob die angepingten Geräte im Lan erreichbar sind oder nicht.

FHEM läuft bei mir auf einem Bananapi
ich habe insgesamt 17 LanPings in FHEM
Perl v5.14.2

Gruß
Ingo

Markus Bloch · 14 Mai 2016, 09:46:53

Hallo Ingo,

bitte mal bei der PRESENCE-Definition das Attribut verbose auf 5 stellen, die Konfiguration speichern und FHEM neustarten. Anschließend bitte eine Weile laufen lassen und dann die Logmeldungen hier posten.

Danke

Gruß
Markus

automatisierer · 14 Mai 2016, 12:04:15

Code Auswählen


2016.05.14 11:52:46 1: Including ./log/fhem.save
2016.05.14 11:52:58 0: Featurelevel: 5.7
2016.05.14 11:52:58 0: Server started with 542 defined entities (fhem.pl:11425/2016-05-10 perl:5.014002 os:linux user:fhem pid:17998)
2016.05.14 11:53:00 1: HMLAN_Parse: HMLANingo1 new condition ok
2016.05.14 11:53:01 1: HMLAN_Parse: HMLANingo2 new condition ok
2016.05.14 11:53:02 0: HourCounter Heizung_Brenner_Betriebstunden Run.598 first run done countsOverall:1780
2016.05.14 11:53:02 5: PRESENCE (PC_Laptop_Ingo_wlan) - blocking scan result: PC_Laptop_Ingo_wlan|0|present
2016.05.14 11:53:02 4: PRESENCE (PC_Laptop_Ingo_wlan) - rescheduling next check in 300 seconds
2016.05.14 11:53:07 5: PRESENCE (PC_Kopierer) - blocking scan result: PC_Kopierer|0|absent
2016.05.14 11:53:07 4: PRESENCE (PC_Kopierer) - rescheduling next check in 300 seconds
2016.05.14 11:53:16 5: PRESENCE (PC_Laptop_Ingo_lan) - blocking scan result: PC_Laptop_Ingo_lan|0|absent
2016.05.14 11:53:16 4: PRESENCE (PC_Laptop_Ingo_lan) - rescheduling next check in 300 seconds
2016.05.14 11:53:30 1: Timeout for PRESENCE_DoLocalPingScan reached, terminated process 18022
2016.05.14 11:53:30 1: Timeout for PRESENCE_DoLocalPingScan reached, terminated process 18024
2016.05.14 11:53:30 1: Timeout for PRESENCE_DoLocalPingScan reached, terminated process 18026
2016.05.14 11:53:30 1: Timeout for PRESENCE_DoLocalPingScan reached, terminated process 18028
2016.05.14 11:53:40 1: Timeout for PRESENCE_DoLocalPingScan reached, terminated process 18030
2016.05.14 11:53:40 1: Timeout for PRESENCE_DoLocalPingScan reached, terminated process 18032
2016.05.14 11:53:40 1: Timeout for PRESENCE_DoLocalPingScan reached, terminated process 18034
2016.05.14 11:53:41 1: Timeout for PRESENCE_DoLocalPingScan reached, terminated process 18035
2016.05.14 11:53:41 1: Timeout for PRESENCE_DoLocalPingScan reached, terminated process 18038
2016.05.14 11:53:41 1: Timeout for PRESENCE_DoLocalPingScan reached, terminated process 18039
2016.05.14 11:53:41 1: Timeout for PRESENCE_DoLocalPingScan reached, terminated process 18042
2016.05.14 11:53:41 2: PRESENCE (PC_Laptop_Ingo_lan) - device could not be checked (retrying in 10 seconds)
2016.05.14 11:53:41 1: Timeout for PRESENCE_DoLocalPingScan reached, terminated process 18043
2016.05.14 11:53:41 2: PRESENCE (PC_Laptop_Ingo_wlan) - device could not be checked (retrying in 10 seconds)
2016.05.14 11:53:51 5: PRESENCE (PC_Laptop_Ingo_lan) - stopping timer
2016.05.14 11:53:51 5: PRESENCE (PC_Laptop_Ingo_lan) - starting blocking call for mode lan-ping
2016.05.14 11:53:51 5: PRESENCE (PC_Laptop_Ingo_wlan) - stopping timer
2016.05.14 11:53:51 5: PRESENCE (PC_Laptop_Ingo_wlan) - starting blocking call for mode lan-ping
2016.05.14 11:53:51 5: PRESENCE (PC_Laptop_Ingo_lan) - starting ping scan: PC_Laptop_Ingo_lan|192.168.171.121|0|4
2016.05.14 11:53:51 5: PRESENCE (PC_Laptop_Ingo_wlan) - starting ping scan: PC_Laptop_Ingo_wlan|192.168.171.120|0|4
2016.05.14 11:53:54 5: PRESENCE (PC_Laptop_Ingo_wlan) - ping command returned with output:
PING 192.168.171.120 (192.168.171.120) 56(84) bytes of data.
64 bytes from 192.168.171.120: icmp_req=1 ttl=64 time=1.36 ms
64 bytes from 192.168.171.120: icmp_req=2 ttl=64 time=134 ms
64 bytes from 192.168.171.120: icmp_req=3 ttl=64 time=55.9 ms
64 bytes from 192.168.171.120: icmp_req=4 ttl=64 time=1.26 ms

--- 192.168.171.120 ping statistics ---
4 packets transmitted, 4 received, 0% packet loss, time 3003ms
rtt min/avg/max/mdev = 1.261/48.212/134.302/54.475 ms
2016.05.14 11:53:54 5: PRESENCE (PC_Laptop_Ingo_wlan) - blocking scan result: PC_Laptop_Ingo_wlan|0|present
2016.05.14 11:53:54 2: PRESENCE (PC_Laptop_Ingo_wlan) - check returned a valid result after 1 unsuccesful retry
2016.05.14 11:53:54 4: PRESENCE (PC_Laptop_Ingo_wlan) - rescheduling next check in 300 seconds
2016.05.14 11:53:57 5: PRESENCE (PC_Laptop_Ingo_lan) - ping command returned with output:
PING 192.168.171.121 (192.168.171.121) 56(84) bytes of data.
From 192.168.171.180 icmp_seq=1 Destination Host Unreachable
From 192.168.171.180 icmp_seq=2 Destination Host Unreachable
From 192.168.171.180 icmp_seq=3 Destination Host Unreachable
From 192.168.171.180 icmp_seq=4 Destination Host Unreachable

--- 192.168.171.121 ping statistics ---
4 packets transmitted, 0 received, +4 errors, 100% packet loss, time 3004ms
pipe 3
2016.05.14 11:53:57 5: PRESENCE (PC_Laptop_Ingo_lan) - blocking scan result: PC_Laptop_Ingo_lan|0|absent
2016.05.14 11:53:57 2: PRESENCE (PC_Laptop_Ingo_lan) - check returned a valid result after 1 unsuccesful retry
2016.05.14 11:53:57 4: PRESENCE (PC_Laptop_Ingo_lan) - rescheduling next check in 300 seconds
2016.05.14 11:58:07 5: PRESENCE (PC_Kopierer) - stopping timer
2016.05.14 11:58:07 5: PRESENCE (PC_Kopierer) - starting blocking call for mode lan-ping
2016.05.14 11:58:07 5: PRESENCE (PC_Kopierer) - starting ping scan: PC_Kopierer|192.168.171.109|0|4
2016.05.14 11:58:13 5: PRESENCE (PC_Kopierer) - ping command returned with output:
PING 192.168.171.109 (192.168.171.109) 56(84) bytes of data.
From 192.168.171.180 icmp_seq=1 Destination Host Unreachable
From 192.168.171.180 icmp_seq=2 Destination Host Unreachable
From 192.168.171.180 icmp_seq=3 Destination Host Unreachable
From 192.168.171.180 icmp_seq=4 Destination Host Unreachable

--- 192.168.171.109 ping statistics ---
4 packets transmitted, 0 received, +4 errors, 100% packet loss, time 3000ms
pipe 3
2016.05.14 11:58:13 5: PRESENCE (PC_Kopierer) - blocking scan result: PC_Kopierer|0|absent
2016.05.14 11:58:13 4: PRESENCE (PC_Kopierer) - rescheduling next check in 300 seconds
2016.05.14 11:58:54 5: PRESENCE (PC_Laptop_Ingo_wlan) - stopping timer
2016.05.14 11:58:54 5: PRESENCE (PC_Laptop_Ingo_wlan) - starting blocking call for mode lan-ping
2016.05.14 11:58:54 5: PRESENCE (PC_Laptop_Ingo_wlan) - starting ping scan: PC_Laptop_Ingo_wlan|192.168.171.120|0|4
2016.05.14 11:58:57 5: PRESENCE (PC_Laptop_Ingo_lan) - stopping timer
2016.05.14 11:58:57 5: PRESENCE (PC_Laptop_Ingo_lan) - starting blocking call for mode lan-ping
2016.05.14 11:58:57 5: PRESENCE (PC_Laptop_Ingo_lan) - starting ping scan: PC_Laptop_Ingo_lan|192.168.171.121|0|4
2016.05.14 11:58:57 5: PRESENCE (PC_Laptop_Ingo_wlan) - ping command returned with output:
PING 192.168.171.120 (192.168.171.120) 56(84) bytes of data.
64 bytes from 192.168.171.120: icmp_req=1 ttl=64 time=71.9 ms
64 bytes from 192.168.171.120: icmp_req=2 ttl=64 time=100 ms
64 bytes from 192.168.171.120: icmp_req=3 ttl=64 time=15.2 ms
64 bytes from 192.168.171.120: icmp_req=4 ttl=64 time=5.06 ms

--- 192.168.171.120 ping statistics ---
4 packets transmitted, 4 received, 0% packet loss, time 3004ms
rtt min/avg/max/mdev = 5.064/48.123/100.201/39.405 ms
2016.05.14 11:58:57 5: PRESENCE (PC_Laptop_Ingo_wlan) - blocking scan result: PC_Laptop_Ingo_wlan|0|present
2016.05.14 11:58:57 4: PRESENCE (PC_Laptop_Ingo_wlan) - rescheduling next check in 300 seconds
2016.05.14 11:59:03 5: PRESENCE (PC_Laptop_Ingo_lan) - ping command returned with output:
PING 192.168.171.121 (192.168.171.121) 56(84) bytes of data.
From 192.168.171.180 icmp_seq=1 Destination Host Unreachable
From 192.168.171.180 icmp_seq=2 Destination Host Unreachable
From 192.168.171.180 icmp_seq=3 Destination Host Unreachable
From 192.168.171.180 icmp_seq=4 Destination Host Unreachable

--- 192.168.171.121 ping statistics ---
4 packets transmitted, 0 received, +4 errors, 100% packet loss, time 3002ms
pipe 3
2016.05.14 11:59:03 5: PRESENCE (PC_Laptop_Ingo_lan) - blocking scan result: PC_Laptop_Ingo_lan|0|absent
2016.05.14 11:59:03 4: PRESENCE (PC_Laptop_Ingo_lan) - rescheduling next check in 300 seconds

reicht das?

Markus Bloch · 14 Mai 2016, 12:33:58

Bitte mal für all deine PRESENCE Definitionen das Attribut setzen. Am besten mit:

Code Auswählen

attr TYPE=PRESENCE verbose 5

Dann nochmal bitte den Log nach dem Neustart posten.

Gruß
Markus

automatisierer · 14 Mai 2016, 12:51:48

Code Auswählen


2016.05.14 12:43:09 0: Server shutdown
2016.05.14 12:43:12 5: PRESENCE (Anwesend_Ha_Kathrin) - ping command returned with output:
PING 192.168.171.131 (192.168.171.131) 56(84) bytes of data.
64 bytes from 192.168.171.131: icmp_req=1 ttl=64 time=452 ms
64 bytes from 192.168.171.131: icmp_req=2 ttl=64 time=30.4 ms
64 bytes from 192.168.171.131: icmp_req=3 ttl=64 time=393 ms
64 bytes from 192.168.171.131: icmp_req=4 ttl=64 time=75.3 ms

--- 192.168.171.131 ping statistics ---
4 packets transmitted, 4 received, 0% packet loss, time 3004ms
rtt min/avg/max/mdev = 30.416/237.896/452.120/186.852 ms
2016.05.14 12:43:12 1: BlockingInformParent (PRESENCE_ProcessLocalScan): Can't connect to localhost:60412: IO::Socket::INET: connect: Verbindungsaufbau abgelehnt
2016.05.14 12:43:12 1: Including fhem.cfg
2016.05.14 12:43:15 1: FBAHA FBingo registered with handle: 00000015
2016.05.14 12:43:15 1: HMLAN_Parse: HMLANingo1 new condition disconnected
2016.05.14 12:43:15 1: HMLAN_Parse: HMLANingo1 new condition init
2016.05.14 12:43:15 1: HMLAN_Parse: HMLANingo2 new condition disconnected
2016.05.14 12:43:15 1: HMLAN_Parse: HMLANingo2 new condition init
2016.05.14 12:43:17 0: MSGMail: SSL is available, provided by Net::SMTP::SSL
2016.05.14 12:43:17 1: Including ./FHEM/anwesend.cfg
2016.05.14 12:43:17 1: Including ./FHEM/flur_eg.cfg
2016.05.14 12:43:18 1: Including ./FHEM/schlafzimmer.cfg
2016.05.14 12:43:18 1: Including ./FHEM/wohnzimmer.cfg
2016.05.14 12:43:18 1: Including ./FHEM/garage.cfg
2016.05.14 12:43:18 1: Including ./FHEM/flur_og.cfg
2016.05.14 12:43:18 1: Including ./FHEM/flur_dg.cfg
2016.05.14 12:43:19 1: Including ./FHEM/gaestezimmer.cfg
2016.05.14 12:43:19 1: Including ./FHEM/ignore.cfg
2016.05.14 12:43:19 1: Including ./FHEM/buero.cfg
2016.05.14 12:43:23 1: Including ./FHEM/wetter.cfg
2016.05.14 12:43:23 1: Including ./FHEM/johannes.cfg
Use of uninitialized value $xmlre in pattern match (m//) at ./FHEM/17_SIRD.pm line 264, <> line 3.
2016.05.14 12:43:25 1: Including ./FHEM/jonathan.cfg
Use of uninitialized value $xmlre in pattern match (m//) at ./FHEM/17_SIRD.pm line 264, <> line 109.
2016.05.14 12:43:27 1: Including ./FHEM/pc.cfg
2016.05.14 12:43:28 1: Including ./FHEM/kueche.cfg
2016.05.14 12:43:28 1: Including ./FHEM/bad.cfg
2016.05.14 12:43:28 1: Including ./FHEM/charlotte.cfg
Use of uninitialized value $xmlre in pattern match (m//) at ./FHEM/17_SIRD.pm line 264, <> line 3.
2016.05.14 12:43:30 1: Including ./FHEM/Garagen_fuer_ingo.cfg
2016.05.14 12:43:32 0: HourCounter Heizung_Brenner_Betriebstunden Define.228 parameters: Heizung_Brenner_Betriebstunden HourCounter Flur_eg_MOD_1_Btn_04:an Flur_eg_MOD_1_Btn_04:aus
2016.05.14 12:43:33 1: Including ./log/fhem.save
2016.05.14 12:43:45 0: Featurelevel: 5.7
2016.05.14 12:43:45 0: Server started with 542 defined entities (fhem.pl:11425/2016-05-10 perl:5.014002 os:linux user:fhem pid:19047)
2016.05.14 12:43:46 5: PRESENCE (Anwesend_fhemRoland) - stopping timer
2016.05.14 12:43:46 5: PRESENCE (Anwesend_fhemRoland) - starting blocking call for mode lan-ping
2016.05.14 12:43:46 5: PRESENCE (Anwesend_fhemRoland) - starting ping scan: Anwesend_fhemRoland|192.168.170.10|0|4
2016.05.14 12:43:47 1: HMLAN_Parse: HMLANingo1 new condition ok
2016.05.14 12:43:48 1: HMLAN_Parse: HMLANingo2 new condition ok
2016.05.14 12:43:49 5: PRESENCE (Anwesend_fhemRoland) - ping command returned with output:
PING 192.168.170.10 (192.168.170.10) 56(84) bytes of data.
64 bytes from 192.168.170.10: icmp_req=1 ttl=64 time=2.16 ms
64 bytes from 192.168.170.10: icmp_req=2 ttl=64 time=1.10 ms
64 bytes from 192.168.170.10: icmp_req=3 ttl=64 time=1.02 ms
64 bytes from 192.168.170.10: icmp_req=4 ttl=64 time=1.12 ms

--- 192.168.170.10 ping statistics ---
4 packets transmitted, 4 received, 0% packet loss, time 3004ms
rtt min/avg/max/mdev = 1.022/1.352/2.165/0.472 ms
2016.05.14 12:43:49 0: HourCounter Heizung_Brenner_Betriebstunden Run.598 first run done countsOverall:1781
2016.05.14 12:43:49 5: PRESENCE (Anwesend_Ha_Kathrin) - blocking scan result: Anwesend_Ha_Kathrin|0|present
2016.05.14 12:43:49 4: PRESENCE (Anwesend_Ha_Kathrin) - rescheduling next check in 60 seconds
2016.05.14 12:43:49 5: PRESENCE (Anwesend_Ha_Jonathan) - blocking scan result: Anwesend_Ha_Jonathan|0|present
2016.05.14 12:43:49 4: PRESENCE (Anwesend_Ha_Jonathan) - rescheduling next check in 60 seconds
2016.05.14 12:43:49 5: PRESENCE (Anwesend_Ha_Johannes) - blocking scan result: Anwesend_Ha_Johannes|0|present
2016.05.14 12:43:49 4: PRESENCE (Anwesend_Ha_Johannes) - rescheduling next check in 60 seconds
2016.05.14 12:43:49 5: PRESENCE (Anwesend_fhemRoland) - blocking scan result: Anwesend_fhemRoland|0|present
2016.05.14 12:43:49 4: PRESENCE (Anwesend_fhemRoland) - rescheduling next check in 300 seconds
2016.05.14 12:43:50 5: PRESENCE (Anwesend_Ha_Charlotte) - blocking scan result: Anwesend_Ha_Charlotte|0|present
2016.05.14 12:43:50 4: PRESENCE (Anwesend_Ha_Charlotte) - rescheduling next check in 60 seconds
2016.05.14 12:43:50 5: PRESENCE (PC_Laptop_Johannes_wlan) - blocking scan result: PC_Laptop_Johannes_wlan|0|absent
2016.05.14 12:43:50 4: PRESENCE (PC_Laptop_Johannes_wlan) - rescheduling next check in 300 seconds
2016.05.14 12:43:50 5: PRESENCE (PC_Laptop_Ingo_wlan) - blocking scan result: PC_Laptop_Ingo_wlan|0|present
2016.05.14 12:43:50 4: PRESENCE (PC_Laptop_Ingo_wlan) - rescheduling next check in 300 seconds
2016.05.14 12:43:50 5: PRESENCE (PC_Schlafzimmer) - blocking scan result: PC_Schlafzimmer|0|absent
2016.05.14 12:43:50 4: PRESENCE (PC_Schlafzimmer) - rescheduling next check in 110 seconds
2016.05.14 12:43:50 5: PRESENCE (PC_Laptop_Kinder_lan) - blocking scan result: PC_Laptop_Kinder_lan|0|absent
2016.05.14 12:43:50 4: PRESENCE (PC_Laptop_Kinder_lan) - rescheduling next check in 300 seconds
2016.05.14 12:43:50 5: PRESENCE (PC_Laptop_Kinder_wlan) - blocking scan result: PC_Laptop_Kinder_wlan|0|absent
2016.05.14 12:43:50 4: PRESENCE (PC_Laptop_Kinder_wlan) - rescheduling next check in 300 seconds
2016.05.14 12:43:50 5: PRESENCE (PC_Laptop_Johannes_lan) - blocking scan result: PC_Laptop_Johannes_lan|0|absent
2016.05.14 12:43:50 4: PRESENCE (PC_Laptop_Johannes_lan) - rescheduling next check in 300 seconds
2016.05.14 12:43:50 5: PRESENCE (PC_Laptop_Ingo_lan) - blocking scan result: PC_Laptop_Ingo_lan|0|absent
2016.05.14 12:43:50 4: PRESENCE (PC_Laptop_Ingo_lan) - rescheduling next check in 300 seconds
2016.05.14 12:43:52 5: PRESENCE (PC_PS4) - blocking scan result: PC_PS4|0|absent
2016.05.14 12:43:52 4: PRESENCE (PC_PS4) - rescheduling next check in 300 seconds
2016.05.14 12:43:52 5: PRESENCE (PC_SamsungTV) - blocking scan result: PC_SamsungTV|0|absent
2016.05.14 12:43:52 4: PRESENCE (PC_SamsungTV) - rescheduling next check in 300 seconds
2016.05.14 12:43:54 5: PRESENCE (PC_Kopierer) - blocking scan result: PC_Kopierer|0|absent
2016.05.14 12:43:54 4: PRESENCE (PC_Kopierer) - rescheduling next check in 300 seconds
2016.05.14 12:43:55 5: PRESENCE (PC_Buero) - blocking scan result: PC_Buero|0|absent
2016.05.14 12:43:55 4: PRESENCE (PC_Buero) - rescheduling next check in 300 seconds
2016.05.14 12:44:17 1: Timeout for PRESENCE_DoLocalPingScan reached, terminated process 19071
2016.05.14 12:44:17 2: PRESENCE (Anwesend_Ha_Kathrin) - device could not be checked (retrying in 10 seconds)
2016.05.14 12:44:17 1: Timeout for PRESENCE_DoLocalPingScan reached, terminated process 19073
2016.05.14 12:44:17 2: PRESENCE (Anwesend_Ha_Johannes) - device could not be checked (retrying in 10 seconds)
2016.05.14 12:44:17 1: Timeout for PRESENCE_DoLocalPingScan reached, terminated process 19075
2016.05.14 12:44:17 2: PRESENCE (Anwesend_Ha_Charlotte) - device could not be checked (retrying in 10 seconds)
2016.05.14 12:44:17 1: Timeout for PRESENCE_DoLocalPingScan reached, terminated process 19077
2016.05.14 12:44:17 2: PRESENCE (Anwesend_Ha_Jonathan) - device could not be checked (retrying in 10 seconds)
2016.05.14 12:44:27 5: PRESENCE (Anwesend_Ha_Kathrin) - stopping timer
2016.05.14 12:44:27 5: PRESENCE (Anwesend_Ha_Kathrin) - starting blocking call for mode lan-ping
2016.05.14 12:44:27 5: PRESENCE (Anwesend_Ha_Kathrin) - starting ping scan: Anwesend_Ha_Kathrin|192.168.171.131|0|4
2016.05.14 12:44:27 5: PRESENCE (Anwesend_Ha_Johannes) - stopping timer
2016.05.14 12:44:27 5: PRESENCE (Anwesend_Ha_Johannes) - starting blocking call for mode lan-ping
2016.05.14 12:44:27 5: PRESENCE (Anwesend_Ha_Johannes) - starting ping scan: Anwesend_Ha_Johannes|192.168.171.140|0|4
2016.05.14 12:44:27 5: PRESENCE (Anwesend_Ha_Charlotte) - stopping timer
2016.05.14 12:44:27 5: PRESENCE (Anwesend_Ha_Charlotte) - starting blocking call for mode lan-ping
2016.05.14 12:44:27 1: Timeout for PRESENCE_DoLocalPingScan reached, terminated process 19079
2016.05.14 12:44:27 2: PRESENCE (PC_Schlafzimmer) - device could not be checked (retrying in 10 seconds)
2016.05.14 12:44:27 5: PRESENCE (Anwesend_Ha_Charlotte) - starting ping scan: Anwesend_Ha_Charlotte|192.168.171.141|0|4
2016.05.14 12:44:27 5: PRESENCE (Anwesend_Ha_Jonathan) - stopping timer
2016.05.14 12:44:27 5: PRESENCE (Anwesend_Ha_Jonathan) - starting blocking call for mode lan-ping
2016.05.14 12:44:27 1: Timeout for PRESENCE_DoLocalPingScan reached, terminated process 19083
2016.05.14 12:44:27 2: PRESENCE (PC_Laptop_Kinder_lan) - device could not be checked (retrying in 10 seconds)
2016.05.14 12:44:27 5: PRESENCE (Anwesend_Ha_Jonathan) - starting ping scan: Anwesend_Ha_Jonathan|192.168.171.142|0|4
2016.05.14 12:44:27 1: Timeout for PRESENCE_DoLocalPingScan reached, terminated process 19085
2016.05.14 12:44:27 2: PRESENCE (PC_Laptop_Kinder_wlan) - device could not be checked (retrying in 10 seconds)
2016.05.14 12:44:28 1: Timeout for PRESENCE_DoLocalPingScan reached, terminated process 19086
2016.05.14 12:44:28 2: PRESENCE (PC_Laptop_Johannes_lan) - device could not be checked (retrying in 10 seconds)
2016.05.14 12:44:28 1: Timeout for PRESENCE_DoLocalPingScan reached, terminated process 19088
2016.05.14 12:44:28 2: PRESENCE (PC_Laptop_Johannes_wlan) - device could not be checked (retrying in 10 seconds)
2016.05.14 12:44:28 1: Timeout for PRESENCE_DoLocalPingScan reached, terminated process 19090
2016.05.14 12:44:28 2: PRESENCE (PC_Laptop_Ingo_lan) - device could not be checked (retrying in 10 seconds)
2016.05.14 12:44:28 1: Timeout for PRESENCE_DoLocalPingScan reached, terminated process 19093
2016.05.14 12:44:28 2: PRESENCE (PC_Laptop_Ingo_wlan) - device could not be checked (retrying in 10 seconds)
2016.05.14 12:44:30 5: PRESENCE (Anwesend_Ha_Kathrin) - ping command returned with output:
PING 192.168.171.131 (192.168.171.131) 56(84) bytes of data.
64 bytes from 192.168.171.131: icmp_req=1 ttl=64 time=406 ms
64 bytes from 192.168.171.131: icmp_req=2 ttl=64 time=91.9 ms
64 bytes from 192.168.171.131: icmp_req=3 ttl=64 time=451 ms
64 bytes from 192.168.171.131: icmp_req=4 ttl=64 time=30.6 ms

--- 192.168.171.131 ping statistics ---
4 packets transmitted, 4 received, 0% packet loss, time 3002ms
rtt min/avg/max/mdev = 30.652/245.157/451.400/185.825 ms
2016.05.14 12:44:30 5: PRESENCE (Anwesend_Ha_Kathrin) - blocking scan result: Anwesend_Ha_Kathrin|0|present
2016.05.14 12:44:30 2: PRESENCE (Anwesend_Ha_Kathrin) - check returned a valid result after 1 unsuccesful retry
2016.05.14 12:44:30 4: PRESENCE (Anwesend_Ha_Kathrin) - rescheduling next check in 60 seconds
2016.05.14 12:44:30 5: PRESENCE (Anwesend_Ha_Johannes) - ping command returned with output:
PING 192.168.171.140 (192.168.171.140) 56(84) bytes of data.
64 bytes from 192.168.171.140: icmp_req=1 ttl=64 time=85.1 ms
64 bytes from 192.168.171.140: icmp_req=2 ttl=64 time=109 ms
64 bytes from 192.168.171.140: icmp_req=3 ttl=64 time=136 ms
64 bytes from 192.168.171.140: icmp_req=4 ttl=64 time=55.0 ms

--- 192.168.171.140 ping statistics ---
4 packets transmitted, 4 received, 0% packet loss, time 3002ms
rtt min/avg/max/mdev = 55.036/96.697/136.849/30.218 ms
2016.05.14 12:44:30 5: PRESENCE (Anwesend_Ha_Johannes) - blocking scan result: Anwesend_Ha_Johannes|0|present
2016.05.14 12:44:30 2: PRESENCE (Anwesend_Ha_Johannes) - check returned a valid result after 1 unsuccesful retry
2016.05.14 12:44:30 5: PRESENCE (Anwesend_Ha_Charlotte) - ping command returned with output:
PING 192.168.171.141 (192.168.171.141) 56(84) bytes of data.
64 bytes from 192.168.171.141: icmp_req=1 ttl=64 time=95.6 ms
64 bytes from 192.168.171.141: icmp_req=2 ttl=64 time=115 ms
64 bytes from 192.168.171.141: icmp_req=3 ttl=64 time=118 ms
64 bytes from 192.168.171.141: icmp_req=4 ttl=64 time=59.1 ms

--- 192.168.171.141 ping statistics ---
4 packets transmitted, 4 received, 0% packet loss, time 3002ms
rtt min/avg/max/mdev = 59.158/97.307/118.879/23.740 ms
2016.05.14 12:44:30 4: PRESENCE (Anwesend_Ha_Johannes) - rescheduling next check in 60 seconds
2016.05.14 12:44:30 5: PRESENCE (Anwesend_Ha_Charlotte) - blocking scan result: Anwesend_Ha_Charlotte|0|present
2016.05.14 12:44:30 2: PRESENCE (Anwesend_Ha_Charlotte) - check returned a valid result after 1 unsuccesful retry
2016.05.14 12:44:30 4: PRESENCE (Anwesend_Ha_Charlotte) - rescheduling next check in 60 seconds
2016.05.14 12:44:30 5: PRESENCE (Anwesend_Ha_Jonathan) - ping command returned with output:
PING 192.168.171.142 (192.168.171.142) 56(84) bytes of data.
64 bytes from 192.168.171.142: icmp_req=1 ttl=64 time=1.99 ms
64 bytes from 192.168.171.142: icmp_req=2 ttl=64 time=1.86 ms
64 bytes from 192.168.171.142: icmp_req=3 ttl=64 time=1.49 ms
64 bytes from 192.168.171.142: icmp_req=4 ttl=64 time=2.45 ms

--- 192.168.171.142 ping statistics ---
4 packets transmitted, 4 received, 0% packet loss, time 3002ms
rtt min/avg/max/mdev = 1.492/1.951/2.453/0.346 ms
2016.05.14 12:44:30 5: PRESENCE (Anwesend_Ha_Jonathan) - blocking scan result: Anwesend_Ha_Jonathan|0|present
2016.05.14 12:44:30 2: PRESENCE (Anwesend_Ha_Jonathan) - check returned a valid result after 1 unsuccesful retry
2016.05.14 12:44:31 4: PRESENCE (Anwesend_Ha_Jonathan) - rescheduling next check in 60 seconds
2016.05.14 12:44:37 5: PRESENCE (PC_Schlafzimmer) - stopping timer
2016.05.14 12:44:37 5: PRESENCE (PC_Schlafzimmer) - starting blocking call for mode lan-ping
2016.05.14 12:44:37 5: PRESENCE (PC_Schlafzimmer) - starting ping scan: PC_Schlafzimmer|192.168.171.112|0|4
2016.05.14 12:44:37 5: PRESENCE (PC_Laptop_Kinder_lan) - stopping timer
2016.05.14 12:44:37 5: PRESENCE (PC_Laptop_Kinder_lan) - starting blocking call for mode lan-ping
2016.05.14 12:44:37 5: PRESENCE (PC_Laptop_Kinder_lan) - starting ping scan: PC_Laptop_Kinder_lan|192.168.171.123|0|4
2016.05.14 12:44:37 5: PRESENCE (PC_Laptop_Kinder_wlan) - stopping timer
2016.05.14 12:44:37 5: PRESENCE (PC_Laptop_Kinder_wlan) - starting blocking call for mode lan-ping
2016.05.14 12:44:37 5: PRESENCE (PC_Laptop_Kinder_wlan) - starting ping scan: PC_Laptop_Kinder_wlan|192.168.171.122|0|4
2016.05.14 12:44:38 5: PRESENCE (PC_Laptop_Johannes_lan) - stopping timer
2016.05.14 12:44:38 5: PRESENCE (PC_Laptop_Johannes_lan) - starting blocking call for mode lan-ping
2016.05.14 12:44:38 5: PRESENCE (PC_Laptop_Johannes_wlan) - stopping timer
2016.05.14 12:44:38 5: PRESENCE (PC_Laptop_Johannes_wlan) - starting blocking call for mode lan-ping
2016.05.14 12:44:38 5: PRESENCE (PC_Laptop_Johannes_lan) - starting ping scan: PC_Laptop_Johannes_lan|192.168.171.125|0|4
2016.05.14 12:44:38 5: PRESENCE (PC_Laptop_Ingo_lan) - stopping timer
2016.05.14 12:44:38 5: PRESENCE (PC_Laptop_Ingo_lan) - starting blocking call for mode lan-ping
2016.05.14 12:44:38 5: PRESENCE (PC_Laptop_Johannes_wlan) - starting ping scan: PC_Laptop_Johannes_wlan|192.168.171.124|0|4
2016.05.14 12:44:38 5: PRESENCE (PC_Laptop_Ingo_wlan) - stopping timer
2016.05.14 12:44:38 5: PRESENCE (PC_Laptop_Ingo_wlan) - starting blocking call for mode lan-ping
2016.05.14 12:44:38 5: PRESENCE (PC_Laptop_Ingo_lan) - starting ping scan: PC_Laptop_Ingo_lan|192.168.171.121|0|4
2016.05.14 12:44:38 5: PRESENCE (PC_Laptop_Ingo_wlan) - starting ping scan: PC_Laptop_Ingo_wlan|192.168.171.120|0|4
2016.05.14 12:44:41 5: PRESENCE (PC_Laptop_Ingo_wlan) - ping command returned with output:
PING 192.168.171.120 (192.168.171.120) 56(84) bytes of data.
64 bytes from 192.168.171.120: icmp_req=1 ttl=64 time=32.0 ms
64 bytes from 192.168.171.120: icmp_req=2 ttl=64 time=53.7 ms
64 bytes from 192.168.171.120: icmp_req=3 ttl=64 time=75.0 ms
64 bytes from 192.168.171.120: icmp_req=4 ttl=64 time=99.4 ms

--- 192.168.171.120 ping statistics ---
4 packets transmitted, 4 received, 0% packet loss, time 3002ms
rtt min/avg/max/mdev = 32.067/65.071/99.426/24.994 ms
2016.05.14 12:44:41 5: PRESENCE (PC_Laptop_Ingo_wlan) - blocking scan result: PC_Laptop_Ingo_wlan|0|present
2016.05.14 12:44:41 2: PRESENCE (PC_Laptop_Ingo_wlan) - check returned a valid result after 1 unsuccesful retry
2016.05.14 12:44:41 4: PRESENCE (PC_Laptop_Ingo_wlan) - rescheduling next check in 300 seconds
2016.05.14 12:44:43 5: PRESENCE (PC_Schlafzimmer) - ping command returned with output:
PING 192.168.171.112 (192.168.171.112) 56(84) bytes of data.
From 192.168.171.180 icmp_seq=1 Destination Host Unreachable
From 192.168.171.180 icmp_seq=2 Destination Host Unreachable
From 192.168.171.180 icmp_seq=3 Destination Host Unreachable
From 192.168.171.180 icmp_seq=4 Destination Host Unreachable

--- 192.168.171.112 ping statistics ---
4 packets transmitted, 0 received, +4 errors, 100% packet loss, time 3005ms
pipe 3
2016.05.14 12:44:43 5: PRESENCE (PC_Schlafzimmer) - blocking scan result: PC_Schlafzimmer|0|absent
2016.05.14 12:44:43 2: PRESENCE (PC_Schlafzimmer) - check returned a valid result after 1 unsuccesful retry
2016.05.14 12:44:43 4: PRESENCE (PC_Schlafzimmer) - rescheduling next check in 110 seconds
2016.05.14 12:44:43 5: PRESENCE (PC_Laptop_Kinder_lan) - ping command returned with output:
PING 192.168.171.123 (192.168.171.123) 56(84) bytes of data.
From 192.168.171.180 icmp_seq=1 Destination Host Unreachable
From 192.168.171.180 icmp_seq=2 Destination Host Unreachable
From 192.168.171.180 icmp_seq=3 Destination Host Unreachable
From 192.168.171.180 icmp_seq=4 Destination Host Unreachable

--- 192.168.171.123 ping statistics ---
4 packets transmitted, 0 received, +4 errors, 100% packet loss, time 3003ms
pipe 3
2016.05.14 12:44:43 5: PRESENCE (PC_Laptop_Kinder_lan) - blocking scan result: PC_Laptop_Kinder_lan|0|absent
2016.05.14 12:44:43 2: PRESENCE (PC_Laptop_Kinder_lan) - check returned a valid result after 1 unsuccesful retry
2016.05.14 12:44:43 4: PRESENCE (PC_Laptop_Kinder_lan) - rescheduling next check in 300 seconds
2016.05.14 12:44:43 5: PRESENCE (PC_Laptop_Kinder_wlan) - ping command returned with output:
PING 192.168.171.122 (192.168.171.122) 56(84) bytes of data.
From 192.168.171.180 icmp_seq=1 Destination Host Unreachable
From 192.168.171.180 icmp_seq=2 Destination Host Unreachable
From 192.168.171.180 icmp_seq=3 Destination Host Unreachable
From 192.168.171.180 icmp_seq=4 Destination Host Unreachable

--- 192.168.171.122 ping statistics ---
4 packets transmitted, 0 received, +4 errors, 100% packet loss, time 3000ms
pipe 3
2016.05.14 12:44:44 5: PRESENCE (PC_Laptop_Kinder_wlan) - blocking scan result: PC_Laptop_Kinder_wlan|0|absent
2016.05.14 12:44:44 2: PRESENCE (PC_Laptop_Kinder_wlan) - check returned a valid result after 1 unsuccesful retry
2016.05.14 12:44:44 4: PRESENCE (PC_Laptop_Kinder_wlan) - rescheduling next check in 300 seconds
2016.05.14 12:44:44 5: PRESENCE (PC_Laptop_Johannes_lan) - ping command returned with output:
PING 192.168.171.125 (192.168.171.125) 56(84) bytes of data.
From 192.168.171.180 icmp_seq=1 Destination Host Unreachable
From 192.168.171.180 icmp_seq=2 Destination Host Unreachable
From 192.168.171.180 icmp_seq=3 Destination Host Unreachable
From 192.168.171.180 icmp_seq=4 Destination Host Unreachable

--- 192.168.171.125 ping statistics ---
4 packets transmitted, 0 received, +4 errors, 100% packet loss, time 3010ms
pipe 3
2016.05.14 12:44:44 5: PRESENCE (PC_Laptop_Johannes_lan) - blocking scan result: PC_Laptop_Johannes_lan|0|absent
2016.05.14 12:44:44 2: PRESENCE (PC_Laptop_Johannes_lan) - check returned a valid result after 1 unsuccesful retry
2016.05.14 12:44:44 4: PRESENCE (PC_Laptop_Johannes_lan) - rescheduling next check in 300 seconds
2016.05.14 12:44:44 5: PRESENCE (PC_Laptop_Johannes_wlan) - ping command returned with output:
PING 192.168.171.124 (192.168.171.124) 56(84) bytes of data.
From 192.168.171.180 icmp_seq=1 Destination Host Unreachable
From 192.168.171.180 icmp_seq=2 Destination Host Unreachable
From 192.168.171.180 icmp_seq=3 Destination Host Unreachable
From 192.168.171.180 icmp_seq=4 Destination Host Unreachable

--- 192.168.171.124 ping statistics ---
4 packets transmitted, 0 received, +4 errors, 100% packet loss, time 3007ms
pipe 3
2016.05.14 12:44:44 5: PRESENCE (PC_Laptop_Johannes_wlan) - blocking scan result: PC_Laptop_Johannes_wlan|0|absent
2016.05.14 12:44:44 2: PRESENCE (PC_Laptop_Johannes_wlan) - check returned a valid result after 1 unsuccesful retry
2016.05.14 12:44:44 5: PRESENCE (PC_Laptop_Ingo_lan) - ping command returned with output:
PING 192.168.171.121 (192.168.171.121) 56(84) bytes of data.
From 192.168.171.180 icmp_seq=1 Destination Host Unreachable
From 192.168.171.180 icmp_seq=2 Destination Host Unreachable
From 192.168.171.180 icmp_seq=3 Destination Host Unreachable
From 192.168.171.180 icmp_seq=4 Destination Host Unreachable

--- 192.168.171.121 ping statistics ---
4 packets transmitted, 0 received, +4 errors, 100% packet loss, time 3006ms
pipe 3
2016.05.14 12:44:44 4: PRESENCE (PC_Laptop_Johannes_wlan) - rescheduling next check in 300 seconds
2016.05.14 12:44:44 5: PRESENCE (PC_Laptop_Ingo_lan) - blocking scan result: PC_Laptop_Ingo_lan|0|absent
2016.05.14 12:44:44 2: PRESENCE (PC_Laptop_Ingo_lan) - check returned a valid result after 1 unsuccesful retry
2016.05.14 12:44:44 4: PRESENCE (PC_Laptop_Ingo_lan) - rescheduling next check in 300 seconds
2016.05.14 12:45:30 5: PRESENCE (Anwesend_Ha_Kathrin) - stopping timer
2016.05.14 12:45:30 5: PRESENCE (Anwesend_Ha_Kathrin) - starting blocking call for mode lan-ping
2016.05.14 12:45:30 5: PRESENCE (Anwesend_Ha_Kathrin) - starting ping scan: Anwesend_Ha_Kathrin|192.168.171.131|0|4
2016.05.14 12:45:30 5: PRESENCE (Anwesend_Ha_Johannes) - stopping timer
2016.05.14 12:45:30 5: PRESENCE (Anwesend_Ha_Johannes) - starting blocking call for mode lan-ping
2016.05.14 12:45:30 5: PRESENCE (Anwesend_Ha_Johannes) - starting ping scan: Anwesend_Ha_Johannes|192.168.171.140|0|4
2016.05.14 12:45:30 5: PRESENCE (Anwesend_Ha_Charlotte) - stopping timer
2016.05.14 12:45:30 5: PRESENCE (Anwesend_Ha_Charlotte) - starting blocking call for mode lan-ping
2016.05.14 12:45:30 5: PRESENCE (Anwesend_Ha_Charlotte) - starting ping scan: Anwesend_Ha_Charlotte|192.168.171.141|0|4
2016.05.14 12:45:31 5: PRESENCE (Anwesend_Ha_Jonathan) - stopping timer
2016.05.14 12:45:31 5: PRESENCE (Anwesend_Ha_Jonathan) - starting blocking call for mode lan-ping
2016.05.14 12:45:31 5: PRESENCE (Anwesend_Ha_Jonathan) - starting ping scan: Anwesend_Ha_Jonathan|192.168.171.142|0|4
2016.05.14 12:45:33 5: PRESENCE (Anwesend_Ha_Kathrin) - ping command returned with output:
PING 192.168.171.131 (192.168.171.131) 56(84) bytes of data.
64 bytes from 192.168.171.131: icmp_req=1 ttl=64 time=359 ms
64 bytes from 192.168.171.131: icmp_req=2 ttl=64 time=4.87 ms
64 bytes from 192.168.171.131: icmp_req=3 ttl=64 time=345 ms
64 bytes from 192.168.171.131: icmp_req=4 ttl=64 time=6.17 ms

--- 192.168.171.131 ping statistics ---
4 packets transmitted, 4 received, 0% packet loss, time 3001ms
rtt min/avg/max/mdev = 4.871/179.030/359.768/173.581 ms
2016.05.14 12:45:33 5: PRESENCE (Anwesend_Ha_Kathrin) - blocking scan result: Anwesend_Ha_Kathrin|0|present
2016.05.14 12:45:33 4: PRESENCE (Anwesend_Ha_Kathrin) - rescheduling next check in 60 seconds
2016.05.14 12:45:33 5: PRESENCE (Anwesend_Ha_Johannes) - ping command returned with output:
PING 192.168.171.140 (192.168.171.140) 56(84) bytes of data.
64 bytes from 192.168.171.140: icmp_req=1 ttl=64 time=45.6 ms
64 bytes from 192.168.171.140: icmp_req=2 ttl=64 time=34.7 ms
64 bytes from 192.168.171.140: icmp_req=3 ttl=64 time=1.40 ms
64 bytes from 192.168.171.140: icmp_req=4 ttl=64 time=2.94 ms

--- 192.168.171.140 ping statistics ---
4 packets transmitted, 4 received, 0% packet loss, time 3002ms
rtt min/avg/max/mdev = 1.409/21.186/45.624/19.401 ms
2016.05.14 12:45:33 5: PRESENCE (Anwesend_Ha_Johannes) - blocking scan result: Anwesend_Ha_Johannes|0|present
2016.05.14 12:45:33 4: PRESENCE (Anwesend_Ha_Johannes) - rescheduling next check in 60 seconds
2016.05.14 12:45:34 5: PRESENCE (Anwesend_Ha_Jonathan) - ping command returned with output:
PING 192.168.171.142 (192.168.171.142) 56(84) bytes of data.
64 bytes from 192.168.171.142: icmp_req=1 ttl=64 time=5.31 ms
64 bytes from 192.168.171.142: icmp_req=2 ttl=64 time=1.90 ms
64 bytes from 192.168.171.142: icmp_req=3 ttl=64 time=1.24 ms
64 bytes from 192.168.171.142: icmp_req=4 ttl=64 time=109 ms

--- 192.168.171.142 ping statistics ---
4 packets transmitted, 4 received, 0% packet loss, time 3004ms
rtt min/avg/max/mdev = 1.245/29.569/109.817/46.356 ms
2016.05.14 12:45:34 5: PRESENCE (Anwesend_Ha_Jonathan) - blocking scan result: Anwesend_Ha_Jonathan|0|present
2016.05.14 12:45:34 4: PRESENCE (Anwesend_Ha_Jonathan) - rescheduling next check in 60 seconds
2016.05.14 12:45:34 5: PRESENCE (Anwesend_Ha_Charlotte) - ping command returned with output:
PING 192.168.171.141 (192.168.171.141) 56(84) bytes of data.
64 bytes from 192.168.171.141: icmp_req=1 ttl=64 time=117 ms
64 bytes from 192.168.171.141: icmp_req=2 ttl=64 time=14.7 ms
64 bytes from 192.168.171.141: icmp_req=3 ttl=64 time=8.26 ms
64 bytes from 192.168.171.141: icmp_req=4 ttl=64 time=236 ms

--- 192.168.171.141 ping statistics ---
4 packets transmitted, 4 received, 0% packet loss, time 3001ms
rtt min/avg/max/mdev = 8.263/94.111/236.003/92.672 ms
2016.05.14 12:45:34 5: PRESENCE (Anwesend_Ha_Charlotte) - blocking scan result: Anwesend_Ha_Charlotte|0|present
2016.05.14 12:45:34 4: PRESENCE (Anwesend_Ha_Charlotte) - rescheduling next check in 60 seconds
2016.05.14 12:46:33 5: PRESENCE (Anwesend_Ha_Kathrin) - stopping timer
2016.05.14 12:46:33 5: PRESENCE (Anwesend_Ha_Kathrin) - starting blocking call for mode lan-ping
2016.05.14 12:46:33 5: PRESENCE (Anwesend_Ha_Kathrin) - starting ping scan: Anwesend_Ha_Kathrin|192.168.171.131|0|4
2016.05.14 12:46:33 5: PRESENCE (PC_Schlafzimmer) - stopping timer
2016.05.14 12:46:33 5: PRESENCE (PC_Schlafzimmer) - starting blocking call for mode lan-ping
2016.05.14 12:46:33 5: PRESENCE (Anwesend_Ha_Johannes) - stopping timer
2016.05.14 12:46:33 5: PRESENCE (Anwesend_Ha_Johannes) - starting blocking call for mode lan-ping
2016.05.14 12:46:33 5: PRESENCE (PC_Schlafzimmer) - starting ping scan: PC_Schlafzimmer|192.168.171.112|0|4
2016.05.14 12:46:33 5: PRESENCE (Anwesend_Ha_Johannes) - starting ping scan: Anwesend_Ha_Johannes|192.168.171.140|0|4
2016.05.14 12:46:34 5: PRESENCE (Anwesend_Ha_Jonathan) - stopping timer
2016.05.14 12:46:34 5: PRESENCE (Anwesend_Ha_Jonathan) - starting blocking call for mode lan-ping
2016.05.14 12:46:34 5: PRESENCE (Anwesend_Ha_Charlotte) - stopping timer
2016.05.14 12:46:34 5: PRESENCE (Anwesend_Ha_Charlotte) - starting blocking call for mode lan-ping
2016.05.14 12:46:34 5: PRESENCE (Anwesend_Ha_Jonathan) - starting ping scan: Anwesend_Ha_Jonathan|192.168.171.142|0|4
2016.05.14 12:46:34 5: PRESENCE (Anwesend_Ha_Charlotte) - starting ping scan: Anwesend_Ha_Charlotte|192.168.171.141|0|4
2016.05.14 12:46:36 5: PRESENCE (Anwesend_Ha_Kathrin) - ping command returned with output:
PING 192.168.171.131 (192.168.171.131) 56(84) bytes of data.
64 bytes from 192.168.171.131: icmp_req=1 ttl=64 time=435 ms
64 bytes from 192.168.171.131: icmp_req=2 ttl=64 time=16.3 ms
64 bytes from 192.168.171.131: icmp_req=3 ttl=64 time=379 ms
64 bytes from 192.168.171.131: icmp_req=4 ttl=64 time=62.3 ms

--- 192.168.171.131 ping statistics ---
4 packets transmitted, 4 received, 0% packet loss, time 3001ms
rtt min/avg/max/mdev = 16.342/223.529/435.704/185.960 ms
2016.05.14 12:46:36 5: PRESENCE (Anwesend_Ha_Kathrin) - blocking scan result: Anwesend_Ha_Kathrin|0|present
2016.05.14 12:46:36 4: PRESENCE (Anwesend_Ha_Kathrin) - rescheduling next check in 60 seconds
2016.05.14 12:46:37 5: PRESENCE (Anwesend_Ha_Johannes) - ping command returned with output:
PING 192.168.171.140 (192.168.171.140) 56(84) bytes of data.
64 bytes from 192.168.171.140: icmp_req=1 ttl=64 time=313 ms
64 bytes from 192.168.171.140: icmp_req=2 ttl=64 time=68.9 ms
64 bytes from 192.168.171.140: icmp_req=3 ttl=64 time=53.8 ms
64 bytes from 192.168.171.140: icmp_req=4 ttl=64 time=27.9 ms

--- 192.168.171.140 ping statistics ---
4 packets transmitted, 4 received, 0% packet loss, time 3002ms
rtt min/avg/max/mdev = 27.995/116.058/313.431/114.889 ms
2016.05.14 12:46:37 5: PRESENCE (Anwesend_Ha_Johannes) - blocking scan result: Anwesend_Ha_Johannes|0|present
2016.05.14 12:46:37 4: PRESENCE (Anwesend_Ha_Johannes) - rescheduling next check in 60 seconds
2016.05.14 12:46:37 5: PRESENCE (Anwesend_Ha_Jonathan) - ping command returned with output:
PING 192.168.171.142 (192.168.171.142) 56(84) bytes of data.
64 bytes from 192.168.171.142: icmp_req=1 ttl=64 time=7.87 ms
64 bytes from 192.168.171.142: icmp_req=2 ttl=64 time=1.65 ms
64 bytes from 192.168.171.142: icmp_req=3 ttl=64 time=2.36 ms
64 bytes from 192.168.171.142: icmp_req=4 ttl=64 time=2.22 ms

--- 192.168.171.142 ping statistics ---
4 packets transmitted, 4 received, 0% packet loss, time 3004ms
rtt min/avg/max/mdev = 1.656/3.530/7.879/2.524 ms
2016.05.14 12:46:37 5: PRESENCE (Anwesend_Ha_Jonathan) - blocking scan result: Anwesend_Ha_Jonathan|0|present
2016.05.14 12:46:37 4: PRESENCE (Anwesend_Ha_Jonathan) - rescheduling next check in 60 seconds
2016.05.14 12:46:37 5: PRESENCE (Anwesend_Ha_Charlotte) - ping command returned with output:
PING 192.168.171.141 (192.168.171.141) 56(84) bytes of data.
64 bytes from 192.168.171.141: icmp_req=1 ttl=64 time=61.7 ms
64 bytes from 192.168.171.141: icmp_req=2 ttl=64 time=89.4 ms
64 bytes from 192.168.171.141: icmp_req=3 ttl=64 time=107 ms
64 bytes from 192.168.171.141: icmp_req=4 ttl=64 time=131 ms

--- 192.168.171.141 ping statistics ---
4 packets transmitted, 4 received, 0% packet loss, time 3003ms
rtt min/avg/max/mdev = 61.790/97.776/131.919/25.662 ms
2016.05.14 12:46:37 5: PRESENCE (Anwesend_Ha_Charlotte) - blocking scan result: Anwesend_Ha_Charlotte|0|present
2016.05.14 12:46:37 4: PRESENCE (Anwesend_Ha_Charlotte) - rescheduling next check in 60 seconds
2016.05.14 12:46:39 5: PRESENCE (PC_Schlafzimmer) - ping command returned with output:
PING 192.168.171.112 (192.168.171.112) 56(84) bytes of data.
From 192.168.171.180 icmp_seq=1 Destination Host Unreachable
From 192.168.171.180 icmp_seq=2 Destination Host Unreachable
From 192.168.171.180 icmp_seq=3 Destination Host Unreachable
From 192.168.171.180 icmp_seq=4 Destination Host Unreachable

--- 192.168.171.112 ping statistics ---
4 packets transmitted, 0 received, +4 errors, 100% packet loss, time 3000ms
pipe 3
2016.05.14 12:46:39 5: PRESENCE (PC_Schlafzimmer) - blocking scan result: PC_Schlafzimmer|0|absent
2016.05.14 12:46:39 4: PRESENCE (PC_Schlafzimmer) - rescheduling next check in 110 seconds
2016.05.14 12:47:36 5: PRESENCE (Anwesend_Ha_Kathrin) - stopping timer
2016.05.14 12:47:36 5: PRESENCE (Anwesend_Ha_Kathrin) - starting blocking call for mode lan-ping
2016.05.14 12:47:37 5: PRESENCE (Anwesend_Ha_Kathrin) - starting ping scan: Anwesend_Ha_Kathrin|192.168.171.131|0|4
2016.05.14 12:47:37 5: PRESENCE (Anwesend_Ha_Johannes) - stopping timer
2016.05.14 12:47:37 5: PRESENCE (Anwesend_Ha_Johannes) - starting blocking call for mode lan-ping
2016.05.14 12:47:37 5: PRESENCE (Anwesend_Ha_Johannes) - starting ping scan: Anwesend_Ha_Johannes|192.168.171.140|0|4
2016.05.14 12:47:37 5: PRESENCE (Anwesend_Ha_Jonathan) - stopping timer
2016.05.14 12:47:37 5: PRESENCE (Anwesend_Ha_Jonathan) - starting blocking call for mode lan-ping
2016.05.14 12:47:37 5: PRESENCE (Anwesend_Ha_Jonathan) - starting ping scan: Anwesend_Ha_Jonathan|192.168.171.142|0|4
2016.05.14 12:47:37 5: PRESENCE (Anwesend_Ha_Charlotte) - stopping timer
2016.05.14 12:47:37 5: PRESENCE (Anwesend_Ha_Charlotte) - starting blocking call for mode lan-ping
2016.05.14 12:47:37 5: PRESENCE (Anwesend_Ha_Charlotte) - starting ping scan: Anwesend_Ha_Charlotte|192.168.171.141|0|4
2016.05.14 12:47:40 5: PRESENCE (Anwesend_Ha_Kathrin) - ping command returned with output:
PING 192.168.171.131 (192.168.171.131) 56(84) bytes of data.
64 bytes from 192.168.171.131: icmp_req=1 ttl=64 time=447 ms
64 bytes from 192.168.171.131: icmp_req=2 ttl=64 time=29.2 ms
64 bytes from 192.168.171.131: icmp_req=3 ttl=64 time=392 ms
64 bytes from 192.168.171.131: icmp_req=4 ttl=64 time=75.1 ms

--- 192.168.171.131 ping statistics ---
4 packets transmitted, 4 received, 0% packet loss, time 3003ms
rtt min/avg/max/mdev = 29.218/236.079/447.882/185.675 ms
2016.05.14 12:47:40 5: PRESENCE (Anwesend_Ha_Kathrin) - blocking scan result: Anwesend_Ha_Kathrin|0|present
2016.05.14 12:47:40 4: PRESENCE (Anwesend_Ha_Kathrin) - rescheduling next check in 60 seconds
2016.05.14 12:47:40 5: PRESENCE (Anwesend_Ha_Johannes) - ping command returned with output:
PING 192.168.171.140 (192.168.171.140) 56(84) bytes of data.
64 bytes from 192.168.171.140: icmp_req=1 ttl=64 time=139 ms
64 bytes from 192.168.171.140: icmp_req=2 ttl=64 time=42.0 ms
64 bytes from 192.168.171.140: icmp_req=3 ttl=64 time=75.6 ms
64 bytes from 192.168.171.140: icmp_req=4 ttl=64 time=108 ms

--- 192.168.171.140 ping statistics ---
4 packets transmitted, 4 received, 0% packet loss, time 3004ms
rtt min/avg/max/mdev = 42.031/91.383/139.839/36.424 ms
2016.05.14 12:47:40 5: PRESENCE (Anwesend_Ha_Johannes) - blocking scan result: Anwesend_Ha_Johannes|0|present
2016.05.14 12:47:40 4: PRESENCE (Anwesend_Ha_Johannes) - rescheduling next check in 60 seconds
2016.05.14 12:47:40 5: PRESENCE (Anwesend_Ha_Jonathan) - ping command returned with output:
PING 192.168.171.142 (192.168.171.142) 56(84) bytes of data.
64 bytes from 192.168.171.142: icmp_req=1 ttl=64 time=1.57 ms
64 bytes from 192.168.171.142: icmp_req=2 ttl=64 time=1.24 ms
64 bytes from 192.168.171.142: icmp_req=3 ttl=64 time=2.84 ms
64 bytes from 192.168.171.142: icmp_req=4 ttl=64 time=1.23 ms

--- 192.168.171.142 ping statistics ---
4 packets transmitted, 4 received, 0% packet loss, time 3004ms
rtt min/avg/max/mdev = 1.238/1.723/2.844/0.661 ms
2016.05.14 12:47:40 5: PRESENCE (Anwesend_Ha_Jonathan) - blocking scan result: Anwesend_Ha_Jonathan|0|present
2016.05.14 12:47:40 4: PRESENCE (Anwesend_Ha_Jonathan) - rescheduling next check in 60 seconds
2016.05.14 12:47:40 5: PRESENCE (Anwesend_Ha_Charlotte) - ping command returned with output:
PING 192.168.171.141 (192.168.171.141) 56(84) bytes of data.
64 bytes from 192.168.171.141: icmp_req=1 ttl=64 time=125 ms
64 bytes from 192.168.171.141: icmp_req=2 ttl=64 time=42.9 ms
64 bytes from 192.168.171.141: icmp_req=3 ttl=64 time=62.8 ms
64 bytes from 192.168.171.141: icmp_req=4 ttl=64 time=87.0 ms

--- 192.168.171.141 ping statistics ---
4 packets transmitted, 4 received, 0% packet loss, time 3003ms
rtt min/avg/max/mdev = 42.959/79.618/125.581/30.794 ms
2016.05.14 12:47:40 5: PRESENCE (Anwesend_Ha_Charlotte) - blocking scan result: Anwesend_Ha_Charlotte|0|present
2016.05.14 12:47:40 4: PRESENCE (Anwesend_Ha_Charlotte) - rescheduling next check in 60 seconds

Markus Bloch · 14 Mai 2016, 14:10:36

Das sieht für mich sehr stark nach einem Ressourcen-Engpass auf deiner Hardware aus. Nachdem FHEM startet werden aufgrund deiner Vielzahl an PRESENCE-Definitionen viele Forks erzeugt. Aufgrund des Startvorgangs wo insgesamt über 500 Definitionen initialisiert werden ist natürlich CPU und Speicher gut beschäftigt.

Da innerhalb des Timeouts (60 Sekunden) die Pings noch nichtmal gestartet werden glaube ich, dass deine Hardware beim Starten von FHEM hoffnungslos überlastet ist und erst, nachdem der Initialisierungsvorgang der meisten Definitionen abgeschlossen ist, deine Hardware sich wieder im Stande sieht, Forks zu starten und zu bearbeiten.

Über 500 Definitionen ist definitiv eine ordentliche Hausnummer für eine FHEM Installation. Er brauch über 30 Sekunden um überhaupt erstmal alle Definitionen anzulegen, dazu kommen noch Initialisierungen die über Timer nach der erfolgten Definition gestartet werden.

Gruß
Markus

automatisierer · 14 Mai 2016, 14:34:51

Die Forks werden ja angelegt und enden dann als Zombies.
Wäre ja eine Möglichkeit dem ganzen z.B. per attr eine Verzögerung zu geben, so dass die ersten Pings erst nach 60 Sekunden ausgeführt werden...

Gruß
Ingo

Markus Bloch · 14 Mai 2016, 14:58:26

Zitat von: automatisierer am 14 Mai 2016, 14:34:51
Die Forks werden ja angelegt und enden dann als Zombies.

Weil sie innerhalb von 60 Sekunden kein Ergebnis liefern. Sie generieren ja noch nicht mal Logmeldungen, was also bedeutet, dass sie zu dem entsprechenden Zeitpunkt noch nichtmal gestartet wurden. Nach 60 Sekunden trennt der Hauptprozess die Verbindung zum Fork und versucht ihn zu beenden, aber da ist er ja noch nicht mal gestartet. Daher endet er als Zombie, da der Hauptprozess den Fork nicht mehr benutzt.

Zitat von: automatisierer am 14 Mai 2016, 14:34:51
Wäre ja eine Möglichkeit dem ganzen z.B. per attr eine Verzögerung zu geben, so dass die ersten Pings erst nach 60 Sekunden ausgeführt werden...

Ist aus meiner Sicht aber eher ein Workaround als eine Lösung. Das kann die bei anderen Modulen, die ebenfalls diesen Fork-Mechanismus nutzen genauso passieren. In deinem speziellen Fall müsste man sogar noch eine Zufallskomponente zu dem Delay addieren, damit nicht alle Forks mit einmal erzeugt werden.

Gruß
Markus

automatisierer · 14 Mai 2016, 16:48:15

hab mal htop während einem neustart laufen lassen, da waren schon ein paar Peaks Richtung 100% CPU Auslastung, immer in Verbindung mit einem neuen Fork.
Dann hab ich mit sysstat 3minuten während einem neustart aufgenommen.:

Code Auswählen


Linux 3.4.103 (bapiFHEM) 	14.05.2016 	_armv7l_	(2 CPU)

16:27:15        CPU     %user     %nice   %system   %iowait    %steal     %idle
16:27:16        all      0,51      0,00      0,51      0,00      0,00     98,99
16:27:17        all     10,15      0,00      1,52      0,00      0,00     88,32
16:27:18        all     13,20      0,00      5,58      0,00      0,00     81,22
16:27:19        all      0,51      0,00      0,51      0,51      0,00     98,47
16:27:20        all     36,55      0,00      3,05      0,00      0,00     60,41
16:27:21        all     46,23      0,00      5,03      0,00      0,00     48,74
16:27:22        all     38,78      0,00     13,27      0,00      0,00     47,96
16:27:23        all     49,75      0,00      2,01      0,00      0,00     48,24
16:27:24        all     48,74      0,00      0,50      0,00      0,00     50,75
16:27:25        all     42,64      0,00     10,15      0,00      0,00     47,21
16:27:26        all     49,50      0,00      2,00      0,00      0,00     48,50
16:27:27        all     50,25      0,00      1,01      0,00      0,00     48,74
16:27:28        all     20,30      0,00      2,03      0,00      0,00     77,66
16:27:29        all      1,01      0,00      0,51      0,00      0,00     98,48
16:27:30        all     28,00      0,00      2,00      0,50      0,00     69,50
16:27:31        all     34,67      0,00      3,52      0,00      0,00     61,81
16:27:32        all      1,01      0,00      0,50      0,00      0,00     98,49
16:27:33        all     14,57      0,00      1,51      0,00      0,00     83,92
16:27:34        all      7,04      0,00      1,01      0,00      0,00     91,96
16:27:35        all      0,00      0,00      1,02      0,00      0,00     98,98
16:27:36        all     27,27      0,00     17,68      0,00      0,00     55,05
16:27:37        all     12,63      0,00      0,51      0,00      0,00     86,87
16:27:38        all      0,00      0,00      1,53      0,00      0,00     98,47
16:27:39        all     38,97      0,00      3,08      0,00      0,00     57,95
16:27:40        all     48,99      0,00      5,56      0,00      0,00     45,45
16:27:41        all     47,24      0,00      6,03      0,00      0,00     46,73
16:27:42        all     36,73      0,00      5,10      0,00      0,00     58,16
16:27:43        all     50,76      0,00      1,02      0,00      0,00     48,22
16:27:44        all     51,27      0,00      0,51      0,00      0,00     48,22
16:27:45        all     51,01      0,00      1,01      0,00      0,00     47,98
16:27:46        all     50,76      0,00      2,54      0,00      0,00     46,70
16:27:47        all     49,24      0,00      2,54      0,00      0,00     48,22
16:27:48        all     49,25      0,00      3,02      0,00      0,00     47,74

16:27:48        CPU     %user     %nice   %system   %iowait    %steal     %idle
16:27:49        all     50,00      0,00      1,52      0,00      0,00     48,48
16:27:50        all     33,00      0,00      1,50      0,50      0,00     65,00
16:27:51        all      0,00      0,00      1,01      0,00      0,00     98,99
16:27:52        all      0,50      0,00      0,50      0,00      0,00     98,99
16:27:53        all     15,15      0,00      2,02      0,00      0,00     82,83
16:27:54        all     80,50      0,00     12,50      0,00      0,00      7,00
16:27:55        all     79,40      0,00      7,04      0,00      0,00     13,57
16:27:56        all     41,92      0,00      2,53      0,00      0,00     55,56
16:27:57        all     43,94      0,00      2,53      0,00      0,00     53,54
16:27:58        all     29,08      0,00      2,04      0,00      0,00     68,88
16:27:59        all      6,09      0,00      0,51      0,00      0,00     93,40
16:28:00        all      5,13      0,00      0,51      0,51      0,00     93,85
16:28:01        all      8,04      0,00      0,50      0,00      0,00     91,46
16:28:02        all      4,57      0,00      0,51      0,00      0,00     94,92
16:28:03        all     28,79      0,00      0,51      0,00      0,00     70,71
16:28:04        all     36,04      0,00     10,66      0,00      0,00     53,30
16:28:05        all     38,89      0,00      2,53      0,00      0,00     58,59
16:28:06        all      6,60      0,00      0,51      0,00      0,00     92,89
16:28:07        all      6,09      0,00      1,02      0,00      0,00     92,89
16:28:08        all      4,52      0,00      1,51      0,00      0,00     93,97
16:28:09        all      2,56      0,00      0,51      0,00      0,00     96,92
16:28:10        all      5,08      0,00      0,51      0,00      0,00     94,42
16:28:11        all      8,72      0,00      1,03      0,00      0,00     90,26
16:28:12        all      9,14      0,00      0,51      0,00      0,00     90,36
16:28:13        all      7,04      0,00      0,50      0,00      0,00     92,46
16:28:14        all      6,12      0,00      0,51      0,00      0,00     93,37
16:28:15        all      6,57      0,00      0,51      0,00      0,00     92,93
16:28:16        all     24,74      0,00      0,00      0,00      0,00     75,26
16:28:17        all     20,92      0,00      0,51      0,00      0,00     78,57
16:28:18        all      3,05      0,00      0,51      0,00      0,00     96,45
16:28:19        all     10,05      0,00      1,51      0,00      0,00     88,44
16:28:20        all      4,57      0,00      2,54      0,00      0,00     92,89
16:28:21        all      6,60      0,00      0,51      0,51      0,00     92,39

16:28:21        CPU     %user     %nice   %system   %iowait    %steal     %idle
16:28:22        all      7,58      0,00      8,59      0,00      0,00     83,84
16:28:23        all     14,80      0,00      0,51      0,00      0,00     84,69
16:28:24        all      8,67      0,00      0,51      0,00      0,00     90,82
16:28:25        all     15,15      0,00      1,01      0,00      0,00     83,84
16:28:26        all     24,24      0,00      1,52      0,00      0,00     74,24
16:28:27        all     16,75      0,00      1,52      0,00      0,00     81,73
16:28:28        all     10,05      0,00      0,00      0,00      0,00     89,95
16:28:29        all      8,72      0,00      1,03      0,00      0,00     90,26
16:28:30        all      9,14      0,00      0,51      0,00      0,00     90,36
16:28:31        all      0,00      0,00      0,51      1,01      0,00     98,48
16:28:32        all      0,51      0,00      0,51      0,00      0,00     98,98
16:28:33        all      1,02      0,00      0,51      0,00      0,00     98,48
16:28:34        all      4,55      0,00      0,51      0,00      0,00     94,95
16:28:35        all      3,54      0,00      6,57      0,00      0,00     89,90
16:28:36        all     21,32      0,00      7,11      0,00      0,00     71,57
16:28:37        all      0,51      0,00      0,00      0,51      0,00     98,98
16:28:38        all      0,51      0,00      0,00      0,00      0,00     99,49
16:28:39        all     13,64      0,00      2,02      0,00      0,00     84,34
16:28:40        all      1,02      0,00      0,00      0,00      0,00     98,98
16:28:41        all      1,52      0,00      0,51      0,00      0,00     97,98
16:28:42        all     12,24      0,00      1,02      0,00      0,00     86,73
16:28:43        all      0,51      0,00      0,00      0,00      0,00     99,49
16:28:44        all      3,05      0,00      0,51      0,00      0,00     96,45
16:28:45        all      3,03      0,00      1,52      0,00      0,00     95,45
16:28:46        all     11,06      0,00     22,11      0,00      0,00     66,83
16:28:47        all      3,55      0,00      0,51      0,51      0,00     95,43
16:28:48        all      5,58      0,00      1,52      0,00      0,00     92,89
16:28:49        all      5,26      0,00      2,11      0,00      0,00     92,63
16:28:50        all      0,00      0,00      1,02      0,00      0,00     98,98
16:28:51        all      0,00      0,00      1,01      0,00      0,00     98,99
16:28:52        all     21,35      0,00      4,69      0,00      0,00     73,96
16:28:53        all     14,72      0,00      0,51      0,00      0,00     84,77
16:28:54        all      1,01      0,00      0,50      0,00      0,00     98,49

16:28:54        CPU     %user     %nice   %system   %iowait    %steal     %idle
16:28:55        all      2,54      0,00      0,51      0,00      0,00     96,95
16:28:56        all      0,51      0,00      0,00      0,00      0,00     99,49
16:28:57        all      1,51      0,00      0,00      0,00      0,00     98,49
16:28:58        all      0,00      0,00      1,01      0,51      0,00     98,48
16:28:59        all      0,51      0,00      1,02      0,00      0,00     98,48
16:29:00        all      0,51      0,00      0,00      0,00      0,00     99,49
16:29:01        all      1,01      0,00      1,01      0,00      0,00     97,98
16:29:02        all      0,00      0,00      1,01      0,00      0,00     98,99
16:29:03        all      0,51      0,00      0,51      0,00      0,00     98,98
16:29:04        all      0,00      0,00      1,53      0,00      0,00     98,47
16:29:05        all      3,03      0,00      1,01      0,00      0,00     95,96
16:29:06        all      1,02      0,00      0,51      0,00      0,00     98,48
16:29:07        all      2,02      0,00      0,00      0,00      0,00     97,98
16:29:08        all      0,51      0,00      0,51      0,00      0,00     98,98
16:29:09        all      4,06      0,00      0,51      0,00      0,00     95,43
16:29:10        all      0,51      0,00      0,51      0,00      0,00     98,98
16:29:11        all     27,41      0,00      5,08      0,00      0,00     67,51
16:29:12        all     50,75      0,00      1,00      0,00      0,00     48,26
16:29:13        all     45,23      0,00      2,01      0,00      0,00     52,76
16:29:14        all     24,62      0,00      7,04      0,00      0,00     68,34
16:29:15        all     19,19      0,00      1,52      0,00      0,00     79,29
16:29:16        all      0,00      0,00      1,01      0,00      0,00     98,99
16:29:17        all      0,51      0,00      1,01      0,00      0,00     98,48
16:29:18        all      1,01      0,00      0,51      0,51      0,00     97,98
16:29:19        all      9,09      0,00      0,51      0,00      0,00     90,40
16:29:20        all      1,01      0,00      1,01      0,00      0,00     97,99
16:29:21        all      7,50      0,00      0,50      0,00      0,00     92,00
16:29:22        all     15,74      0,00      7,11      0,00      0,00     77,16
16:29:23        all      2,03      0,00      0,51      0,00      0,00     97,46
16:29:24        all      2,00      0,00      1,50      0,00      0,00     96,50
16:29:25        all      1,01      0,00      0,50      0,00      0,00     98,49
16:29:26        all      0,00      0,00      1,01      0,00      0,00     98,99
16:29:27        all      0,00      0,00      1,01      0,00      0,00     98,99

16:29:27        CPU     %user     %nice   %system   %iowait    %steal     %idle
16:29:28        all      0,51      0,00      1,01      0,00      0,00     98,48
16:29:29        all      0,51      0,00      0,51      0,00      0,00     98,98
16:29:30        all      0,51      0,00      1,01      0,00      0,00     98,48
16:29:31        all      0,00      0,00      1,02      0,00      0,00     98,98
16:29:32        all      0,00      0,00      1,02      0,00      0,00     98,98
16:29:33        all      1,01      0,00      0,51      0,51      0,00     97,98
16:29:34        all      0,51      0,00      0,51      0,00      0,00     98,98
16:29:35        all      0,51      0,00      1,02      0,00      0,00     98,48
16:29:36        all      1,51      0,00      1,01      0,00      0,00     97,49
16:29:37        all      0,51      0,00      0,51      0,00      0,00     98,99
16:29:38        all      1,02      0,00      0,51      0,00      0,00     98,47
16:29:39        all      2,01      0,00      4,02      0,00      0,00     93,97
16:29:40        all      1,02      0,00      0,00      0,00      0,00     98,98
16:29:41        all      1,01      0,00      0,50      0,00      0,00     98,49
16:29:42        all      5,05      0,00      7,58      0,00      0,00     87,37
16:29:43        all      0,50      0,00      1,99      0,50      0,00     97,01
16:29:44        all      6,09      0,00      3,05      0,00      0,00     90,86
16:29:45        all      0,51      0,00      0,51      0,00      0,00     98,97
16:29:46        all      3,48      0,00      1,00      0,00      0,00     95,52
16:29:47        all      0,00      0,00      1,02      0,00      0,00     98,98
16:29:48        all      3,11      0,00      5,18      0,00      0,00     91,71
16:29:49        all      1,52      0,00      4,06      0,00      0,00     94,42
16:29:50        all      0,00      0,00      1,51      0,00      0,00     98,49
16:29:51        all      1,01      0,00      0,50      0,00      0,00     98,49
16:29:52        all      0,00      0,00      1,01      0,00      0,00     98,99
16:29:53        all      0,51      0,00      1,02      0,51      0,00     97,97
16:29:54        all      0,00      0,00      1,01      0,00      0,00     98,99
16:29:55        all      0,51      0,00      0,51      0,00      0,00     98,98
16:29:56        all      0,00      0,00      1,02      0,00      0,00     98,98
16:29:57        all      0,51      0,00      0,51      0,00      0,00     98,99
16:29:58        all      0,00      0,00      1,52      0,00      0,00     98,48
16:29:59        all      0,51      0,00      1,02      0,00      0,00     98,48
16:30:00        all     14,21      0,00      1,52      0,00      0,00     84,26

16:30:00        CPU     %user     %nice   %system   %iowait    %steal     %idle
16:30:01        all     14,65      0,00      0,51      0,00      0,00     84,85
16:30:02        all      0,51      0,00      1,03      0,00      0,00     98,46
16:30:03        all      0,51      0,00      0,00      0,00      0,00     99,49
16:30:04        all      2,53      0,00      0,51      0,00      0,00     96,97
16:30:05        all      1,02      0,00      0,51      0,00      0,00     98,47
16:30:06        all      1,01      0,00      0,50      0,00      0,00     98,49
16:30:07        all      0,00      0,00      0,51      0,00      0,00     99,49
16:30:08        all      0,00      0,00      1,01      0,51      0,00     98,48
16:30:09        all     17,26      0,00      1,02      0,00      0,00     81,73
16:30:10        all      0,51      0,00      0,51      0,00      0,00     98,99
16:30:11        all      0,00      0,00      0,51      0,00      0,00     99,49
16:30:12        all      0,50      0,00      0,50      0,00      0,00     98,99
16:30:13        all     14,14      0,00      0,51      0,51      0,00     84,85
16:30:14        all     13,64      0,00      2,53      0,00      0,00     83,84
16:30:15        all      7,61      0,00      0,51      0,00      0,00     91,88
Durchschn.:     all     12,43      0,00      1,90      0,05      0,00     85,63

da siehts nicht so wild aus... kleiner 1 Sekunde kann man wohl nicht aufnehmen?!?

EDIT:
ich Ochse... FHEM läuft nur auf der ersten CPU, somit ist dann bei 51% CPU Auslastung natürlich die 1. CPU am Limit und die 2. hat noch Luft...

StefanP · 14 Mai 2016, 18:30:16

Hallo,
ich habe zufällig gestern auch diese Zombies entdeckt, da kommt der Thread ja gerade recht um meinen Senf dazuzugeben

. Bei mir sind's drei Zombies, genau die Anzahl meiner aktiven Lan-Pings (definiert sind vier, einer ist momentan disabled).
Evtl. wäre ja die vorgeschlagene Startverzögerung doch ein überlegenswerter Workaround?
Die fhem-Installation hat übrigens 401 Entities.

Gruß StefanP

rudolfkoenig · 14 Mai 2016, 18:59:37

Womoeglich habe ich was nicht verstanden, aber: fhemFork setzt "neuerdings" $SIG{CHLD} = 'DEFAULT' (siehe https://forum.fhem.de/index.php?topic=50898), d.h. alle Funktionen, die fhemFork (oder BlockingCall) verwenden, und nach dem Fork Prozesse starten, muessen selbst um das Wegraeumen dieser Kinder kuemmern (d.h. wait() aufrufen) oder $SIG{CHLD} = 'IGNORE'; nach fhemFork wieder setzen.
Sonst bleiben Zombies uebrig.

Markus Bloch · 15 Mai 2016, 02:09:52

Hallo Rudi,

ich versteh leider gerade den Zusammenhang mit der genannten Änderung nicht. Wo müsste ich in PRESENCE jetzt was einbauen und warum?

Gruß
Markus

rudolfkoenig · 15 Mai 2016, 14:52:32

Falls(!) PRESENCE BlockingCall verwendet, und in dieser Funktion regelmaessig einen Prozess startet (ping/hcitool/etc), dann entstehen Zombie Prozesse, bis entweder die BlockingCall Funktion diese abraeumt, oder die Funktion (und damit der Prozess) terminiert. Eine moegliche Loesung: in der BlockingCall Funktion $SIG{CHLD} = 'IGNORE'; aufrufen.
Wie gesagt, bin nicht sicher, ob alle Bedingungen erfuellt sind.

Markus Bloch · 16 Mai 2016, 13:15:32

Hallo zusammen,

ich habe jetzt wie von Rudi vorgeschlagen $SIG{CHLD} auf 'IGNORE' gesetzt um Zombie-Prozesse zu vermeiden. Da in meiner Umgebung kein einziger Zombie je aufgetreten ist, würde ich Ingo und Stefan bitten das ganze morgen mal zu testen, ob die Zombies nach einem Neustart, ein paar Minuten warten und dann erneuter Neustart weg sind.

Die Änderung gibt es mit dem morgigen Update. Falls ihr es direkt ausprobieren wollt, könnt ihr euch die neue Version hier runterladen: https://sourceforge.net/p/fhem/code/11463/tree//trunk/fhem/FHEM/73_PRESENCE.pm?format=raw

@Rudi: Ja, PRESENCE nutzt BlockingCall. War meine ich damals auch das erste Modul was Blocking.pm verwendet hat.

Allen noch ein angenehmen Pfingsmontag.

Gruß
Markus

automatisierer · 16 Mai 2016, 15:11:47

Habs mir schon mal runtergeladen und auch mehrfach neu gestartet, aber die Zombies kommen nach jedem Neustart wieder und bleiben auch...

Code Auswählen


73_PRESENCE.pm      11463 2016-05-16 11:11:11Z markusbloch

Gruß
Ingo