Problem mit Blocking.pm auf Windows Server nach Update vom 7.11.

Nobby1805 · 09 November 2016, 11:04:21

Seit dem ich am 1.11. einen Update für Fhem durchgeführt habe werden die PROPLANTA Daten oft nicht mehr regelmässig abgerufen und in der Anzeige aufgefrischt.

Im Log finde ich dann folgende Fehlermeldung:

Zitat2016.11.09 01:32:15.796 1: Cannot fork: Resource temporarily unavailable

Nach einem Restart von Fhem klappt es dann wieder .. für eine Zeit

Da ich nirgendwo einen Hinweis gefunden habe, um welche Ressource es sich handelt, habe ich heute den verbose für PROPLANTA auf 4 erhöht. Aus dem Log habe ich jetzt den Eindruck, dass das eingestellte Abrufintervall von 7200 Sekunden nicht eingehalten wird

Zitat2016.11.09 10:56:35.073 4: PROPLANTA proplanta: HtmlAcquire.523 Start capturing of http://www.proplanta.de/Wetter/profi-wetter.php?SITEID=60&PLZ=Essen&STADT=Essen&WETTERaufrufen=stadt&Wtp=&SUCHE=Wetter&wT=7
2016.11.09 10:56:35.370 4: PROPLANTA proplanta: HtmlAcquire.523 Start capturing of http://www.proplanta.de/Wetter/profi-wetter.php?SITEID=60&PLZ=Essen&STADT=Essen&WETTERaufrufen=stadt&Wtp=&SUCHE=Wetter&wT=7
2016.11.09 10:56:36.041 4: PROPLANTA proplanta: HtmlAcquire.540 199754 characters captured
2016.11.09 10:56:36.043 4: PROPLANTA proplanta: Run.645 Start HTML parsing of captured page
2016.11.09 10:56:36.307 4: PROPLANTA proplanta: HtmlAcquire.540 199754 characters captured
2016.11.09 10:56:36.308 4: PROPLANTA proplanta: Run.645 Start HTML parsing of captured page
2016.11.09 10:56:57.278 4: PROPLANTA proplanta: Run.650 Found terms: 419
2016.11.09 10:56:57.947 4: PROPLANTA proplanta: Run.650 Found terms: 419
2016.11.09 10:56:58.089 4: PROPLANTA proplanta: HtmlAcquire.523 Start capturing of http://www.proplanta.de/Wetter/profi-wetter.php?SITEID=60&PLZ=Essen&STADT=Essen&WETTERaufrufen=stadt&Wtp=&SUCHE=Wetter&wT=0
2016.11.09 10:56:58.651 4: PROPLANTA proplanta: HtmlAcquire.523 Start capturing of http://www.proplanta.de/Wetter/profi-wetter.php?SITEID=60&PLZ=Essen&STADT=Essen&WETTERaufrufen=stadt&Wtp=&SUCHE=Wetter&wT=0
2016.11.09 10:56:58.686 4: PROPLANTA proplanta: Done.676 Forked process successfully finished
2016.11.09 10:56:58.770 4: PROPLANTA proplanta: Done.719 420 values captured
2016.11.09 10:56:59.108 4: PROPLANTA proplanta: Done.676 Forked process successfully finished
2016.11.09 10:56:59.338 4: PROPLANTA proplanta: HtmlAcquire.540 466712 characters captured
2016.11.09 10:56:59.338 4: PROPLANTA proplanta: Run.645 Start HTML parsing of captured page
2016.11.09 10:56:59.369 4: PROPLANTA proplanta: Done.719 420 values captured
2016.11.09 10:56:59.979 4: PROPLANTA proplanta: HtmlAcquire.540 466712 characters captured
2016.11.09 10:56:59.979 4: PROPLANTA proplanta: Run.645 Start HTML parsing of captured page
2016.11.09 10:57:56.838 4: PROPLANTA proplanta: HtmlAcquire.523 Start capturing of http://www.proplanta.de/Wetter/profi-wetter.php?SITEID=60&PLZ=Essen&STADT=Essen&WETTERaufrufen=stadt&Wtp=&SUCHE=Wetter&wT=4
2016.11.09 10:57:57.588 4: PROPLANTA proplanta: HtmlAcquire.523 Start capturing of http://www.proplanta.de/Wetter/profi-wetter.php?SITEID=60&PLZ=Essen&STADT=Essen&WETTERaufrufen=stadt&Wtp=&SUCHE=Wetter&wT=4
2016.11.09 10:57:57.979 4: PROPLANTA proplanta: HtmlAcquire.540 432819 characters captured
2016.11.09 10:57:57.981 4: PROPLANTA proplanta: Run.645 Start HTML parsing of captured page
2016.11.09 10:57:59.010 4: PROPLANTA proplanta: HtmlAcquire.540 432819 characters captured
2016.11.09 10:57:59.013 4: PROPLANTA proplanta: Run.645 Start HTML parsing of captured page
2016.11.09 10:58:48.385 4: PROPLANTA proplanta: HtmlAcquire.523 Start capturing of http://www.proplanta.de/Wetter/profi-wetter.php?SITEID=60&PLZ=Essen&STADT=Essen&WETTERaufrufen=stadt&Wtp=&SUCHE=Wetter&wT=7
2016.11.09 10:58:49.401 4: PROPLANTA proplanta: HtmlAcquire.540 199754 characters captured
2016.11.09 10:58:49.402 4: PROPLANTA proplanta: Run.645 Start HTML parsing of captured page
2016.11.09 10:58:49.698 4: PROPLANTA proplanta: HtmlAcquire.523 Start capturing of http://www.proplanta.de/Wetter/profi-wetter.php?SITEID=60&PLZ=Essen&STADT=Essen&WETTERaufrufen=stadt&Wtp=&SUCHE=Wetter&wT=7
2016.11.09 10:58:50.698 4: PROPLANTA proplanta: HtmlAcquire.540 199754 characters captured
2016.11.09 10:58:50.699 4: PROPLANTA proplanta: Run.645 Start HTML parsing of captured page
2016.11.09 10:59:11.119 4: PROPLANTA proplanta: Run.650 Found terms: 419
2016.11.09 10:59:11.682 4: PROPLANTA proplanta: HtmlAcquire.523 Start capturing of http://www.proplanta.de/Wetter/profi-wetter.php?SITEID=60&PLZ=Essen&STADT=Essen&WETTERaufrufen=stadt&Wtp=&SUCHE=Wetter&wT=0
2016.11.09 10:59:11.712 4: PROPLANTA proplanta: Done.676 Forked process successfully finished
2016.11.09 10:59:11.846 4: PROPLANTA proplanta: Done.719 420 values captured
2016.11.09 10:59:12.542 4: PROPLANTA proplanta: Run.650 Found terms: 419
2016.11.09 10:59:13.151 4: PROPLANTA proplanta: HtmlAcquire.540 466712 characters captured
2016.11.09 10:59:13.153 4: PROPLANTA proplanta: Run.645 Start HTML parsing of captured page
2016.11.09 10:59:13.182 4: PROPLANTA proplanta: HtmlAcquire.523 Start capturing of http://www.proplanta.de/Wetter/profi-wetter.php?SITEID=60&PLZ=Essen&STADT=Essen&WETTERaufrufen=stadt&Wtp=&SUCHE=Wetter&wT=0
2016.11.09 10:59:13.201 4: PROPLANTA proplanta: Done.676 Forked process successfully finished
2016.11.09 10:59:13.328 4: PROPLANTA proplanta: Done.719 420 values captured
2016.11.09 10:59:14.463 4: PROPLANTA proplanta: HtmlAcquire.540 466712 characters captured
2016.11.09 10:59:14.466 4: PROPLANTA proplanta: Run.645 Start HTML parsing of captured page
2016.11.09 11:00:09.260 4: PROPLANTA proplanta: HtmlAcquire.523 Start capturing of http://www.proplanta.de/Wetter/profi-wetter.php?SITEID=60&PLZ=Essen&STADT=Essen&WETTERaufrufen=stadt&Wtp=&SUCHE=Wetter&wT=4
2016.11.09 11:00:10.323 4: PROPLANTA proplanta: HtmlAcquire.540 432819 characters captured
2016.11.09 11:00:10.325 4: PROPLANTA proplanta: Run.645 Start HTML parsing of captured page
2016.11.09 11:00:10.729 4: PROPLANTA proplanta: HtmlAcquire.523 Start capturing of http://www.proplanta.de/Wetter/profi-wetter.php?SITEID=60&PLZ=Essen&STADT=Essen&WETTERaufrufen=stadt&Wtp=&SUCHE=Wetter&wT=4
2016.11.09 11:00:12.073 4: PROPLANTA proplanta: HtmlAcquire.540 432819 characters captured
2016.11.09 11:00:12.074 4: PROPLANTA proplanta: Run.645 Start HTML parsing of captured page

das sieht für mich eher nach einem Abruf im Minutenrhythmus aus

frank · 09 November 2016, 12:04:57

die neueste version ist aber schon ziehmlich alt, 2016-07-06. wie lange hattest du kein update gemacht?
wie sieht deine definition aus?
das fork problem hatte ich auf der fritzbox => zu wenig speicher.
die anzahl der forks müsste man inzwischen durch einstellen eines attributs beschränken können. siehe hier https://forum.fhem.de/index.php/topic,55290.msg480010.html#msg480010

Nobby1805 · 09 November 2016, 12:36:29

PROPLANTA ist bei dem Update auch gar nicht verändert worden ... das scheint also ein Nebeneffekt eines anderen Updates zu sein.

Meine vorherigen Updates waren am 8.8. und am 26.7.

Ist das normal, dass so häufig auf die Proplanta-Seite zugegriffen wird ?

Code Auswählen

define proplanta PROPLANTA Essen
attr proplanta INTERVAL 7200
attr proplanta forecastDays 11
attr proplanta room Unsorted
attr proplanta verbose 0

bzw. aktuell testweise verbose auf 4 gesetzt

frank · 09 November 2016, 13:22:46

mein letztes update ist sicherlich schon 2 monate her.
das reading lastConnection habe ich auf event-on-update und sehe nichts auffälliges.
setze das attr INTERVAL doch mal neu. ist das interval korrekt in den internals vorhanden?

Nobby1805 · 09 November 2016, 16:41:10

7200 als Intervall stand auch in den Internals ... habe ich jetzt testweise mal auf 3600 gesetzt

Zitat2016-11-09 16:30:28.345 PROPLANTA proplanta lastConnection: 420 values captured in 135.81 s
2016-11-09 16:30:36.720 PROPLANTA proplanta lastConnection: 420 values captured in 131.47 s
2016-11-09 16:32:47.148 PROPLANTA proplanta lastConnection: 420 values captured in 138.09 s
2016-11-09 16:32:50.749 PROPLANTA proplanta lastConnection: 420 values captured in 132.83 s
2016-11-09 16:35:07.781 PROPLANTA proplanta lastConnection: 420 values captured in 135.63 s
2016-11-09 16:35:30.184 PROPLANTA proplanta lastConnection: 420 values captured in 162.34 s
2016-11-09 16:37:47.815 PROPLANTA proplanta lastConnection: 420 values captured in 136.31 s
2016-11-09 16:38:06.616 PROPLANTA proplanta lastConnection: 420 values captured in 178.17 s
2016-11-09 16:40:27.457 PROPLANTA proplanta lastConnection: 420 values captured in 140.13 s
2016-11-09 16:40:32.927 PROPLANTA proplanta lastConnection: 420 values captured in 164.39 s

frank · 09 November 2016, 17:44:58

seltsam...

hast du zusätzlich irgendwo einen code in einem at, notify, doif, ...

Code Auswählen

set proplanta update

laufen zufällig mehrere fhem's?

kannst du es über disable stoppen?

vom gefühl her würde ich das problem im zusammenhang mit der fork meldung sehen. vielleicht hat blocking.pm bei dir ein problem.

Nobby1805 · 09 November 2016, 23:54:56

kein at, notify oder doif ... nur ein fhem ... disable hat keine Auswirkung

aber eben kam noch eine neue Fehlermeldung

Zitat2016.11.09 20:54:33.899 1: Cannot fork: Resource temporarily unavailable
2016.11.09 20:54:33.899 4: PROPLANTA proplanta: Start.588 Start forked process to capture html
2016.11.09 21:54:33.898 1: PROPLANTA proplanta: Start.592 Could not start forked process, old process still running

blocking.pm ist vielleicht ein guter Tipp ... das ist eins der Module die beim letzten Update geändert worden sind ... ich mach das mal rückgängig

Nobby1805 · 10 November 2016, 00:16:58

Ich spekuliere schon mal vorsichtig: es liegt an der neuen Version von Blocking.pm
Ich habe es um 23:56 rückgängig gemacht und bis jetzt, 00:15, ist Proplanta nur einmal aufgerufen worden

Edit: so, die Probleme sind mit der "alten" Version von blocking.pm definitiv nicht mehr vorhanden

frank · 10 November 2016, 12:40:40

dann würde ich den thread verschieben und den titel verändern.

Nobby1805 · 10 November 2016, 12:42:50

wohin denn ?

frank · 10 November 2016, 13:08:47

Zitat von: Nobby1805 am 10 November 2016, 12:42:50
wohin denn ?

ZitatFHEM/Blocking.pm rudolfkoenig http://forum.fhem.de Automatisierung

Nobby1805 · 10 November 2016, 17:31:05

Ich habe gerade gesehen, dass es eine neue Version von blocking.pn gibt, vom 7.11.
Ausprobiert: Nein, es funktioniert auch damit nicht ... ich bin wieder zurück auf die Version vom 8.8.

Nobby1805 · 11 November 2016, 17:25:07

Im Kopf des blocking.pn steht wie man das Blocking testen kann/soll
wenn ich diesen Test mit dem Blocking.pn vom 7.11.16 aufrufe kommt

Zitat2016.11.11 17:13:30.059 1 : SleepDone: I'm done

2016.11.11 17:13:35.277 1 : SleepDone: I'm done

2016.11.11 17:13:36.762 1 : SleepDone: I'm done

2016.11.11 17:13:39.153 1 : SleepDone: I'm done

2016.11.11 17:13:40.699 1 : SleepDone: I'm done

2016.11.11 17:13:43.465 1 : SleepDone: I'm done

2016.11.11 17:13:45.965 1 : SleepDone: I'm done

2016.11.11 17:13:48.559 1 : SleepDone: I'm done

2016.11.11 17:13:50.246 1 : SleepDone: I'm done

2016.11.11 17:13:51.965 1 : SleepDone: I'm done

2016.11.11 17:13:55.871 1 : SleepDone: I'm done

2016.11.11 17:13:58.059 1 : SleepDone: I'm done

2016.11.11 17:13:59.559 1 : SleepDone: I'm done

2016.11.11 17:14:02.856 1 : SleepDone: I'm done

2016.11.11 17:14:05.480 1 : SleepDone: I'm done

2016.11.11 17:14:08.856 1 : SleepDone: I'm done

2016.11.11 17:14:11.137 1 : SleepDone: I'm done

2016.11.11 17:14:14.512 1 : SleepDone: I'm done

2016.11.11 17:14:18.152 1 : SleepDone: I'm done

2016.11.11 17:14:18.154 1 : Perfmon: possible freeze starting at 17:14:15, delay is 3.154

2016.11.11 17:14:23.058 1 : SleepDone: I'm done

2016.11.11 17:14:23.059 1 : Perfmon: possible freeze starting at 17:14:19, delay is 4.059

2016.11.11 17:14:36.449 1 : SleepDone: I'm done

2016.11.11 17:14:36.451 1 : Perfmon: possible freeze starting at 17:14:24, delay is 12.451

2016.11.11 17:14:48.824 1 : SleepDone: I'm done

2016.11.11 17:14:48.936 1 : Perfmon: possible freeze starting at 17:14:37, delay is 11.936

2016.11.11 17:14:55.824 1 : SleepDone: I'm done

2016.11.11 17:14:55.828 1 : Perfmon: possible freeze starting at 17:14:49, delay is 6.828

2016.11.11 17:14:59.402 1 : SleepDone: I'm done

2016.11.11 17:14:59.407 1 : Perfmon: possible freeze starting at 17:14:56, delay is 3.407

2016.11.11 17:15:01.903 1 : SleepDone: I'm done

2016.11.11 17:15:06.884 1 : Perfmon: possible freeze starting at 17:15:00, delay is 6.884

2016.11.11 17:15:10.918 1 : SleepDone: I'm done

2016.11.11 17:15:15.606 1 : SleepDone: I'm done

2016.11.11 17:15:15.612 1 : Perfmon: possible freeze starting at 17:15:11, delay is 4.612

2016.11.11 17:15:17.855 1 : Cannot fork: Resource temporarily unavailable

beim Aufruf mit dem alten Modul kommt die Logausgabe genau 1x pro Aufruf

frank · 16 November 2016, 14:11:34

ich habe mich jetzt auch mal zu einem update entschieden. bei mir läuft weiterhin alles normal und gut.

Code Auswählen

Latest Revision: 12591 

File                                 Rev   Last Change 

fhem.pl                              12564 2016-11-13 16:11:52Z rudolfkoenig 
Blocking.pm                          12521 2016-11-07 14:29:48Z rudolfkoenig
59_PROPLANTA.pm                      11752 2016-07-06 16:27:06Z grompo

hast du vielleicht spezielle hardware oder eine exotische perl version?

Nobby1805 · 16 November 2016, 23:41:10

Im Modul gibt es einige Code-Teile, die nur bei Windows durchlaufen werden ...

Windows Server 2003
StrawberryPerl 5.20.2.1-32bit