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:
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
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
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
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?
Bitte mal für all deine PRESENCE Definitionen das Attribut setzen. Am besten mit:
attr TYPE=PRESENCE verbose 5
Dann nochmal bitte den Log nach dem Neustart posten.
Gruß
Markus
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
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
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
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
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.:
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...
Hallo,
ich habe zufällig gestern auch diese Zombies entdeckt, da kommt der Thread ja gerade recht um meinen Senf dazuzugeben 8) . 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
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.
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
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.
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
Habs mir schon mal runtergeladen und auch mehrfach neu gestartet, aber die Zombies kommen nach jedem Neustart wieder und bleiben auch...
73_PRESENCE.pm 11463 2016-05-16 11:11:11Z markusbloch
Gruß
Ingo
Bei mir leider dasselbe. Ich habe zudem festgestellt, dass enablen/disablen der einzelnen PRESENCE-Entities keinen (direkten) Einfluss auf die Anzahl der Zombies hat. Meine Überschlags-Rechnung 4 Presence-Defines - 1 x disablen = 3 Zombies war also etwas vorschnell.
Soweit erstmal
Gruß StefanP
Wenn die Zombies da sind, dann sind die da bis der Elternprozess gestoppt wird - also FHEM shutdown - ein disable 1 und disable 0 während FHEM läuft bringt nix. Du kannst nur die Pings auf disable 1 setzen, speichern, dann FHEM neu starten und die Pings wieder auf disable 0 setzen - dann sind sie weg.
Aber die lieben Kleinen tun in unserem Fall ja nix...
Hallo ihr beiden,
könnt ihr bitte mal in fhem.pl die Zeile 4525
$SIG{CHLD} = 'DEFAULT'; # Forum #50898
auskommentieren ("#" davor setzen)? Dann FHEM beenden, schauen, dass alle Zombies weg sind und erneut starten?
Danke
Gruß
Markus
Und falls das Problem weiterhin besteht, die Ausgaben von:
- grep Sig /proc/<FHEM-PID>/status
- ps -ef | grep fhem
hier posten? ps -ef wg. Parent-PID.
Eine "kleine" Verbesserung:
Für die erste Ausgabe "grep Sig /proc/<FHEM-PID>/status" eine "copy-paste-Lösung"
for i in $(pgrep [f]hem); do echo $i; grep Sig /proc/$i/status; done
Und das 2. ist Optimaler mit:
ps -ef | grep [f]hem
ZitatEine "kleine" Verbesserung:
Aeh: das mit Sig wollt ich nur vom "richtigen" FHEM-Prozess wissen, die Zombies interessieren mich weniger...
ZitatUnd das 2. ist Optimaler mit:
Warum eigentlich? Je nachdem wo man ps ausfuehrt, kriegt man dann: grep: No match.
das 2. hatte ich nur geschrieben, damit es "übersichtlicher" ist. bei einem "ps | grep" findet man auch immer den grep-Prozess. Mit dem "trick" [] kann er sich aber nicht selber finden. Macht es manchmal "übersichtlicher". Und da ich für Deinen 1. Punkt schon etwas geschrieben hatte ...
Du wolltest also eigentlich "grep Sig /proc/<FHEM-Parend-PID>/status"? Rauszufinden mit 2.?
ZitatMit dem "trick" [] kann er sich aber nicht selber finden.
Sorry, habs uebersehen, dass das "no match" Problem nur im tcsh besteht.
ZitatDu wolltest also eigentlich "grep Sig /proc/<FHEM-Parend-PID>/status"? Rauszufinden mit 2.?
Verstehe nicht, was du damit sagen willst.
Du schriebst:
"grep Sig /proc/<FHEM-PID>/status"
Später als Ergänzung "das mit Sig wollt ich nur vom "richtigen" FHEM-Prozess wissen", deshalb meine "Ergänzung".
Warten wir aber erst mal auf die Antwort der "Betroffenen" .. und ich hoffe mit meinem Beitrag nicht zu viele Verunsicherungen aufgerufen zu haben.
Zombies sind noch da... Zeile 4525 habe ich wieder 'einkommentiert'.
Hier die gewünschten Ausgaben:
bananapi@bapiFHEM /opt/fhem $ ps aux|grep fhem
fhem 15188 28.7 5.1 51408 46000 pts/0 S 12:49 0:35 perl fhem.pl fhem.cfg
fhem 15216 0.0 0.0 0 0 pts/0 Z 12:49 0:00 [perl] <defunct>
fhem 15218 0.0 0.0 0 0 pts/0 Z 12:49 0:00 [perl] <defunct>
fhem 15219 0.0 0.0 0 0 pts/0 Z 12:49 0:00 [perl] <defunct>
fhem 15222 0.0 0.0 0 0 pts/0 Z 12:49 0:00 [perl] <defunct>
fhem 15228 0.0 0.0 0 0 pts/0 Z 12:49 0:00 [perl] <defunct>
fhem 15230 0.0 0.0 0 0 pts/0 Z 12:49 0:00 [perl] <defunct>
fhem 15231 0.0 0.0 0 0 pts/0 Z 12:49 0:00 [perl] <defunct>
fhem 15233 0.0 0.0 0 0 pts/0 Z 12:49 0:00 [perl] <defunct>
fhem 15236 0.0 0.0 0 0 pts/0 Z 12:49 0:00 [perl] <defunct>
fhem 15237 0.0 0.0 0 0 pts/0 Z 12:49 0:00 [perl] <defunct>
fhem 15240 0.0 0.0 0 0 pts/0 Z 12:49 0:00 [perl] <defunct>
fhem 15241 0.0 0.0 0 0 pts/0 Z 12:49 0:00 [perl] <defunct>
fhem 15244 0.0 0.0 0 0 pts/0 Z 12:49 0:00 [perl] <defunct>
fhem 15248 0.0 0.0 0 0 pts/0 Z 12:49 0:00 [perl] <defunct>
fhem 15256 0.0 0.0 0 0 pts/0 Z 12:49 0:00 [perl] <defunct>
bananapi@bapiFHEM /opt/fhem $ grep Sig /proc/15188/status
SigQ: 15/6993
SigPnd: 0000000000000000
SigBlk: 0000000000000000
SigIgn: 0000000000011080
SigCgt: 0000000180006003
bananapi@bapiFHEM /opt/fhem $ ps -ef | grep fhem
fhem 15188 1 15 12:49 pts/0 00:00:42 perl fhem.pl fhem.cfg
fhem 15216 15188 0 12:49 pts/0 00:00:00 [perl] <defunct>
fhem 15218 15188 0 12:49 pts/0 00:00:00 [perl] <defunct>
fhem 15219 15188 0 12:49 pts/0 00:00:00 [perl] <defunct>
fhem 15222 15188 0 12:49 pts/0 00:00:00 [perl] <defunct>
fhem 15228 15188 0 12:49 pts/0 00:00:00 [perl] <defunct>
fhem 15230 15188 0 12:49 pts/0 00:00:00 [perl] <defunct>
fhem 15231 15188 0 12:49 pts/0 00:00:00 [perl] <defunct>
fhem 15233 15188 0 12:49 pts/0 00:00:00 [perl] <defunct>
fhem 15236 15188 0 12:49 pts/0 00:00:00 [perl] <defunct>
fhem 15237 15188 0 12:49 pts/0 00:00:00 [perl] <defunct>
fhem 15240 15188 0 12:49 pts/0 00:00:00 [perl] <defunct>
fhem 15241 15188 0 12:49 pts/0 00:00:00 [perl] <defunct>
fhem 15244 15188 0 12:49 pts/0 00:00:00 [perl] <defunct>
fhem 15248 15188 0 12:49 pts/0 00:00:00 [perl] <defunct>
fhem 15256 15188 0 12:49 pts/0 00:00:00 [perl] <defunct>
fhem 15370 15188 0 12:54 pts/0 00:00:00 perl fhem.pl fhem.cfg
fhem 15371 15370 0 12:54 pts/0 00:00:00 ping -c 4 192.168.171.131
fhem 15372 15188 0 12:54 pts/0 00:00:00 perl fhem.pl fhem.cfg
fhem 15373 15188 1 12:54 pts/0 00:00:00 perl fhem.pl fhem.cfg
fhem 15374 15372 0 12:54 pts/0 00:00:00 ping -c 4 192.168.171.141
fhem 15375 15373 0 12:54 pts/0 00:00:00 ping -c 4 192.168.171.142
bananapi 15377 14918 0 12:54 pts/0 00:00:00 grep --color=auto fhem
ps -ef sagt: Alle <defunct> Prozesse haben den Prozess 15188 (den "eigentlichen" FHEM-Prozess) als Elternprozess.
grep status sagt: SIGCHLD steht auf Ignore: SIGCHLD ist 17, und Bit 17 ist laut "SigIgn: 0000000000011080" (Zahl ist als Hex zu lesen) gesetzt.
Theorie: Die Prozesse sind verstorben, bevor FHEM die Signal-Behandlung konfiguriert hat, und ein nachtraeglich gesetztes $SIG{CHLD} = 'IGNORE' hat keine Auswirkung auf Zombies.
Pruefung: Bitte den Aufruf von SignalHandling(); in fhem.pl weiter nach oben schieben, z.Bsp. direkt unter "# End of client code".
Zitat von: rudolfkoenig am 17 Mai 2016, 19:44:59
Theorie: Die Prozesse sind verstorben, bevor FHEM die Signal-Behandlung konfiguriert hat, und ein nachtraeglich gesetztes $SIG{CHLD} = 'IGNORE' hat keine Auswirkung auf Zombies.
Das bestätigt meine Theorie, dass der Fork innerhalb von 60 Sekunden nach Start von BlockingCall() noch garnicht durch das OS gestartet wird, aufgrund der enormen Last beim Starten und Initialisieren von FHEM. Nach 60 Sekunden werden die Calls durch BlockingKill() abgeschossen. Ich glaube, dass zu dieser Zeit der Fork noch garnicht vom OS gestartet wurde und die Child-Prozesse deshalb als Zombies enden.
Gruß
Markus
'Nabend,
nachdem ich jetzt 3 Std. gebraucht hab' erst den Raspi kaputt zu updaten (der Framebuffer war plötzlich nicht mehr da), und dann fhem solange zu bearbeiten bis es nicht mehr startete, braucht ihr jetzt meine Untersuchungsergebnisse wohl nicht mehr.
Ihr kriegt sie aber trotzdem ;) :
pi@dbDB-Raspi:/opt/fhem $ ps aux|grep fhem
fhem 1094 15.3 14.6 74208 65288 ? S 19:48 9:44 /usr/bin/perl fhem.pl fhem.cfg
fhem 1098 0.0 0.0 0 0 ? Z 19:49 0:01 [perl] <defunct>
pi@dbDB-Raspi:/opt/fhem $ grep Sig /proc//1094/status
SigQ: 1/3410
SigPnd: 0000000000000000
SigBlk: 0000000000000000
SigIgn: 0000000000011084
SigCgt: 0000000180006003
pi@dbDB-Raspi:/opt/fhem $ ps -ef | grep fhem
fhem 1094 1 15 19:48 ? 00:09:44 /usr/bin/perl fhem.pl fhem.cfg
fhem 1098 1094 0 19:49 ? 00:00:01 [perl] <defunct>
Komischerweise hab ich jetzt nur noch einen Zombie, nicht mehr drei.
Gruß StefanP
Ich hab mal ganz mutig irgend welche Zeilen in der fhem.pl verschoben...
Das von Zeile 527 nach 446 ...
SignalHandling();
my $pfn = $attr{global}{pidfilename};
if($pfn) {
die "$pfn: $!\n" if(!open(PID, ">$pfn"));
print PID $$ . "\n";
close(PID);
}
my $gp = $attr{global}{port};
if($gp) {
Log 3, "Converting 'attr global port $gp' to 'define telnetPort telnet $gp'";
my $ret = CommandDefine(undef, "telnetPort telnet $gp");
Log 1, "$ret" if($ret);
delete($attr{global}{port});
}
my $sc_text = "SecurityCheck:";
$attr{global}{motd} = "$sc_text\n\n"
if(!$attr{global}{motd} || $attr{global}{motd} =~ m/^$sc_text/);
$init_done = 1;
$lastDefChange = 1;
foreach my $d (keys %defs) {
if($defs{$d}{IODevMissing}) {
Log 3, "No I/O device found for $defs{$d}{NAME}";
delete $defs{$d}{IODevMissing};
}
}
DoTrigger("global", "INITIALIZED", 1);
$fhem_started = time;
$attr{global}{motd} .= "Running with root privileges."
if($^O !~ m/Win/ && $<==0 && $attr{global}{motd} =~ m/^$sc_text/);
$attr{global}{motd} .=
"\nRestart FHEM for a new check if the problem is fixed,\n".
"or set the global attribute motd to none to supress this message.\n"
if($attr{global}{motd} =~ m/^$sc_text\n\n./);
my $motd = $attr{global}{motd};
if($motd eq "$sc_text\n\n") {
delete($attr{global}{motd});
} else {
if($motd ne "none") {
$motd =~ s/\n/ /g;
Log 2, $motd;
}
}
my $osuser = "os:$^O user:".(getlogin || getpwuid($<) || "unknown");
Log 0, "Featurelevel: $featurelevel";
Log 0, "Server started with ".int(keys %defs).
" defined entities ($attr{global}{version} perl:$] $osuser pid:$$)";
Ich hab keinen Plan was ich da gemacht hab und ob das richtig war.
Die Zombies sind weg, beim Start gabs aber ein paar Fehlermeldungen.
bananapi@bapiFHEM ~ $ sudo service fhem start
Starting fhem...
Use of uninitialized value in numeric gt (>) at fhem.pl line 819.
Use of uninitialized value in numeric gt (>) at fhem.pl line 819.
Use of uninitialized value in numeric gt (>) at fhem.pl line 819.
2016.05.18 08:11:37 0: Featurelevel: 5.7
Use of uninitialized value in numeric gt (>) at fhem.pl line 819.
2016.05.18 08:11:37 0: Server started with 1 defined entities ( perl:5.014002 os:linux user:bananapi pid:2803)
Beim ersten mal hab ich nach der Meldung 'Server started with 1 defined entities' die Nerven verloren, abgebrochen und wieder die Originale fhem.pl genommen. Da der Start danach reibungslos lief, hab ich dann einen zweiten Versuch mit der veränderten fhem.pl gestartet.
Wieder die gleichen Fehlermeldungen, der Start dauerte sehr lange, dass Webif war lange (~2 Minuten) nicht zu erreichen - geht jetzt aber. Im LOG (global verbose 1) steht nix besonderes.
Ich habe SignalHandling nach oben geschoben und fhem.pl eingecheckt.
ZitatIch hab mal ganz mutig irgend welche Zeilen in der fhem.pl verschoben...
Na so kaputt ist die Initialisierung auch nicht.
Bin gerne bereit was zu aendern, aber nicht planlos.
ZitatWieder die gleichen Fehlermeldungen, der Start dauerte sehr lange, dass Webif war lange (~2 Minuten) nicht zu erreichen - geht jetzt aber. Im LOG (global verbose 1) steht nix besonderes.
Ist kein Wunder, selbst auf dem default 3 wird nichts zu sehen sein. Mit "attr global verbose 5" und "attr global mseclog" koennte man vermutlich feststellen, welche der 500+ FHEM-Geraete fuer die Verzoegerung zustaendig ist. Wie man das beheben kann, ist eine andere Baustelle.
runtergeladen und Läuft - Zombies sind weg!
Edit:
Der Systemstart dauert in etwa 30 Sekunden, denke das ist OK.