Probleme mit HttpUtils line 866 -> fhem hängt sich komplett auf

[Andal]

Hallo,

ich habe seit dem Neuaufsetzen meines Pis Probleme mit den HttpUtils-Abfragen. Dazu habe ich dieses Thema gefunden: https://forum.fhem.de/index.php?topic=95600.0
Aber leider wird hier das Problem bei mir nicht gelöst, habe das letzte Update eingespielt und leider gibt es folgende Fehlermeldungen im Logfile auf Verbose 5:

Code Auswählen Erweitern

2019.05.05 12:52:20 5: HttpUtils request header:
GET /calendar/ical/*****/basic.ics HTTP/1.0
Host: calendar.google.com
User-Agent: fhem
Accept-Encoding: gzip,deflate

2019.05.05 13:00:14 4: https://www.clever-tanken.de/tankstelle_liste?lat=&lon=&ort=80331&spritsorte=3&r=5: HTTP response code 200
2019.05.05 13:00:14 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at FHEM/HttpUtils.pm line 866.
2019.05.05 13:00:14 5: HttpUtils https://www.clever-tanken.de/tankstelle_liste?lat=&lon=&ort=80331&spritsorte=3&r=5: Got data, length:
2019.05.05 13:00:14 5: HttpUtils response header:
HTTP/1.1 200 OK

Code Auswählen Erweitern

2019.05.05 13:20:10 5: HttpUtils request header:
GET /tankstelle_liste?lat=&lon=&ort=80331&spritsorte=7&r=5 HTTP/1.0
Host: www.clever-tanken.de
User-Agent: fhem
Accept-Encoding: gzip,deflate
Content-Length: 0
Content-Type: application/x-www-form-urlencoded

2019.05.05 13:25:36 4: https://www.clever-tanken.de/tankstelle_liste?lat=&lon=&ort=80331&spritsorte=3&r=5: HTTP response code 200
2019.05.05 13:25:36 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at FHEM/HttpUtils.pm line 866.
2019.05.05 13:25:36 5: HttpUtils https://www.clever-tanken.de/tankstelle_liste?lat=&lon=&ort=80331&spritsorte=3&r=5: Got data, length:
2019.05.05 13:25:36 5: HttpUtils response header:
HTTP/1.1 200 OK

Fhem reagiert im Prinzip in der freien Zeile auf gar nichts mehr. Wenn ich es per service fhem stop beende, dann werden die ab diesem Zeitpunkt verpassten Befehle nachgeholt und beendet.

Ich habe mir schon mal von HttpUtils.pm die Zeile 866 angeschaut, aber leider kenne ich mich zu wenig damit aus, dass ich einen Fix erreichen könnte.

[rudolfkoenig]

Die Meldung in der Zeile 866 kann nicht fuer ein Aufhaengen verantwortlich sein.
Wurde FHEM nach dem update neu gestartet?
Mich wuerden die letzen 20 Zeilen des Logs mit "attr global verbose 5" Log vor dem Haenger interessieren.

Wenn ich es per service fhem stop beende, dann werden die ab diesem Zeitpunkt verpassten Befehle nachgeholt und beendet.

Das verwirrt mich. Wenn ich FHEM stoppe, dann erledigt es keine Befehle.

[Andal]

Danke erstmal für die schnell Rückmeldung.
Ja, ich habe Fhem mehrfach neu gestartet, da ich es versucht habe zu debuggen. Und "update" sagt, dass momentan keine Aktion erforderlich ist. Der Raspberry ist auch auf dem aktuellsten Debian Stretch.
Und es passiert immer nach einer Abfrage von HttpUtils. Manchmal direkt beim Starten schon, manchmal erst Stunden darauf.

Also in folgendem, längeren Logfileauszug sieht man, um 14:15:35 war die letzte Aktion. Dann um 21:45:44 habe ich Fhem per service fhem stop beendet. Dazwischen war Fhem nicht ansprechbar per Webinterface.

Code Auswählen Erweitern

2019.05.05 14:15:33 5: dr_Spritpreis_Diesel: ExtractSid called, context reading, num
2019.05.05 14:15:33 4: dr_Spritpreis_Diesel: CheckAuth decided no authentication required
2019.05.05 14:15:33 5: dr_Spritpreis_Diesel: Read starts parsing response to update with defined readings: 01,02,03,04,05,06,07,08
2019.05.05 14:15:33 5: dr_Spritpreis_Diesel: ExtractReading Diesel_EDEKA with regex /*', '*','','EDEKA Tankstelle',null,2209,2210,60,'([0-9].[0-9][0-9][0-9])/...
2019.05.05 14:15:33 5: dr_Spritpreis_Diesel: 1 capture group(s), matchlist = 1,259
2019.05.05 14:15:33 5: dr_Spritpreis_Diesel: FormatReading changed value with Expr $val =~ s/,/\./; $val; from 1,259 to 1.259
2019.05.05 14:15:33 4: dr_Spritpreis_Diesel: ExtractReading for reading01-1 sets Diesel_EDEKA to 1.259
2019.05.05 14:15:33 5: dr_Spritpreis_Diesel: ExtractReading Diesel_Shell with regex /'*', '*','','Shell',null,2209,2210,60,'([0-9].[0-9][0-9][0-9])/...
2019.05.05 14:15:33 5: dr_Spritpreis_Diesel: 1 capture group(s), matchlist = 1,279
2019.05.05 14:15:33 5: dr_Spritpreis_Diesel: FormatReading changed value with Expr $val =~ s/,/\./; $val; from 1,279 to 1.279
2019.05.05 14:15:33 4: dr_Spritpreis_Diesel: ExtractReading for reading02-1 sets Diesel_Shell to 1.279
2019.05.05 14:15:33 5: dr_Spritpreis_Diesel: ExtractReading Diesel_Agip with regex /'*', '*','','Agip',null,2209,2210,60,'([0-9].[0-9][0-9][0-9])/...
2019.05.05 14:15:33 5: dr_Spritpreis_Diesel: 1 capture group(s), matchlist = 1,289
2019.05.05 14:15:33 5: dr_Spritpreis_Diesel: FormatReading changed value with Expr $val =~ s/,/\./; $val; from 1,289 to 1.289
2019.05.05 14:15:33 4: dr_Spritpreis_Diesel: ExtractReading for reading03-1 sets Diesel_Agip to 1.289
2019.05.05 14:15:33 5: dr_Spritpreis_Diesel: ExtractReading Diesel_Aral with regex /'*', '*','','ARAL',null,2209,2210,60,'([0-9].[0-9][0-9][0-9])/...
2019.05.05 14:15:33 5: dr_Spritpreis_Diesel: 1 capture group(s), matchlist = 1,319
2019.05.05 14:15:34 5: dr_Spritpreis_Diesel: FormatReading changed value with Expr $val =~ s/,/\./; $val; from 1,319 to 1.319
2019.05.05 14:15:34 4: dr_Spritpreis_Diesel: ExtractReading for reading04-1 sets Diesel_Aral to 1.319
2019.05.05 14:15:34 5: dr_Spritpreis_Diesel: ExtractReading Diesel_Bavaria with regex /'*', '*','','Bavaria Petrol',null,2209,2210,60,'([0-9].[0-9][0-9][0-9])/...
2019.05.05 14:15:34 5: dr_Spritpreis_Diesel: 1 capture group(s), matchlist = 1,279
2019.05.05 14:15:34 5: dr_Spritpreis_Diesel: FormatReading changed value with Expr $val =~ s/,/\./; $val; from 1,279 to 1.279
2019.05.05 14:15:34 4: dr_Spritpreis_Diesel: ExtractReading for reading05-1 sets Diesel_Bavaria to 1.279
2019.05.05 14:15:34 5: dr_Spritpreis_Diesel: ExtractReading Diesel_ESSO with regex /'*', '*','','ESSO',null,2209,2210,60,'([0-9].[0-9][0-9][0-9])/...
2019.05.05 14:15:34 5: dr_Spritpreis_Diesel: 1 capture group(s), matchlist = 1,289
2019.05.05 14:15:34 5: dr_Spritpreis_Diesel: FormatReading changed value with Expr $val =~ s/,/\./; $val; from 1,289 to 1.289
2019.05.05 14:15:34 4: dr_Spritpreis_Diesel: ExtractReading for reading06-1 sets Diesel_ESSO to 1.289
2019.05.05 14:15:34 5: dr_Spritpreis_Diesel: ExtractReading Diesel_OMV with regex /'*', '*','','OMV',null,2209,2210,60,'([0-9].[0-9][0-9][0-9])/...
2019.05.05 14:15:34 5: dr_Spritpreis_Diesel: 1 capture group(s), matchlist = 1,259
2019.05.05 14:15:34 5: dr_Spritpreis_Diesel: FormatReading changed value with Expr $val =~ s/,/\./; $val; from 1,259 to 1.259
2019.05.05 14:15:34 4: dr_Spritpreis_Diesel: ExtractReading for reading07-1 sets Diesel_OMV to 1.259
2019.05.05 14:15:34 5: dr_Spritpreis_Diesel: ExtractReading Diesel_Jet with regex /'*', '*','','JET',null,2209,2210,60,'([0-9].[0-9][0-9][0-9])/...
2019.05.05 14:15:34 5: dr_Spritpreis_Diesel: 1 capture group(s), matchlist = 1,259
2019.05.05 14:15:34 5: dr_Spritpreis_Diesel: FormatReading changed value with Expr $val =~ s/,/\./; $val; from 1,259 to 1.259
2019.05.05 14:15:34 4: dr_Spritpreis_Diesel: ExtractReading for reading08-1 sets Diesel_Jet to 1.259
2019.05.05 14:15:34 4: dr_Spritpreis_Diesel: Read response to update matched Reading(s) Diesel_EDEKA Diesel_Shell Diesel_Agip Diesel_Aral Diesel_Bavaria Diesel_ESSO Diesel_OMV Diesel_Jet
2019.05.05 14:15:34 5: Starting notify loop for dr_Spritpreis_Diesel, 8 event(s), first is Diesel_EDEKA: 1.259
2019.05.05 14:15:34 4: DbLog DBLogging -> ################################################################
2019.05.05 14:15:34 4: DbLog DBLogging -> ###              start of new Logcycle                       ###
2019.05.05 14:15:34 4: DbLog DBLogging -> ################################################################
2019.05.05 14:15:34 4: DbLog DBLogging -> number of events received: 8 for device: dr_Spritpreis_Diesel
2019.05.05 14:15:34 4: DbLog DBLogging -> check Device: dr_Spritpreis_Diesel , Event: Diesel_EDEKA: 1.259
2019.05.05 14:15:34 5: DbLog DBLogging -> parsed Event: dr_Spritpreis_Diesel , Event: Diesel_EDEKA: 1.259
2019.05.05 14:15:34 4: DbLog DBLogging -> added event - Timestamp: 2019-05-05 14:15:34, Device: dr_Spritpreis_Diesel, Type: HTTPMOD, Event: Diesel_EDEKA: 1.259, Reading: Diesel_EDEKA, Value: 1.259, Unit:
2019.05.05 14:15:34 4: DbLog DBLogging -> check Device: dr_Spritpreis_Diesel , Event: Diesel_Shell: 1.279
2019.05.05 14:15:34 5: DbLog DBLogging -> parsed Event: dr_Spritpreis_Diesel , Event: Diesel_Shell: 1.279
2019.05.05 14:15:34 4: DbLog DBLogging -> added event - Timestamp: 2019-05-05 14:15:34, Device: dr_Spritpreis_Diesel, Type: HTTPMOD, Event: Diesel_Shell: 1.279, Reading: Diesel_Shell, Value: 1.279, Unit:
2019.05.05 14:15:34 4: DbLog DBLogging -> check Device: dr_Spritpreis_Diesel , Event: Diesel_Agip: 1.289
2019.05.05 14:15:34 5: DbLog DBLogging -> parsed Event: dr_Spritpreis_Diesel , Event: Diesel_Agip: 1.289
2019.05.05 14:15:34 4: DbLog DBLogging -> added event - Timestamp: 2019-05-05 14:15:34, Device: dr_Spritpreis_Diesel, Type: HTTPMOD, Event: Diesel_Agip: 1.289, Reading: Diesel_Agip, Value: 1.289, Unit:
2019.05.05 14:15:34 4: DbLog DBLogging -> check Device: dr_Spritpreis_Diesel , Event: Diesel_Aral: 1.319
2019.05.05 14:15:34 5: DbLog DBLogging -> parsed Event: dr_Spritpreis_Diesel , Event: Diesel_Aral: 1.319
2019.05.05 14:15:34 4: DbLog DBLogging -> added event - Timestamp: 2019-05-05 14:15:34, Device: dr_Spritpreis_Diesel, Type: HTTPMOD, Event: Diesel_Aral: 1.319, Reading: Diesel_Aral, Value: 1.319, Unit:
2019.05.05 14:15:34 4: DbLog DBLogging -> check Device: dr_Spritpreis_Diesel , Event: Diesel_Bavaria: 1.279
2019.05.05 14:15:34 5: DbLog DBLogging -> parsed Event: dr_Spritpreis_Diesel , Event: Diesel_Bavaria: 1.279
2019.05.05 14:15:34 4: DbLog DBLogging -> added event - Timestamp: 2019-05-05 14:15:34, Device: dr_Spritpreis_Diesel, Type: HTTPMOD, Event: Diesel_Bavaria: 1.279, Reading: Diesel_Bavaria, Value: 1.279, Unit:
2019.05.05 14:15:34 4: DbLog DBLogging -> check Device: dr_Spritpreis_Diesel , Event: Diesel_ESSO: 1.289
2019.05.05 14:15:34 5: DbLog DBLogging -> parsed Event: dr_Spritpreis_Diesel , Event: Diesel_ESSO: 1.289
2019.05.05 14:15:34 4: DbLog DBLogging -> added event - Timestamp: 2019-05-05 14:15:34, Device: dr_Spritpreis_Diesel, Type: HTTPMOD, Event: Diesel_ESSO: 1.289, Reading: Diesel_ESSO, Value: 1.289, Unit:
2019.05.05 14:15:34 4: DbLog DBLogging -> check Device: dr_Spritpreis_Diesel , Event: Diesel_OMV: 1.259
2019.05.05 14:15:34 5: DbLog DBLogging -> parsed Event: dr_Spritpreis_Diesel , Event: Diesel_OMV: 1.259
2019.05.05 14:15:34 4: DbLog DBLogging -> added event - Timestamp: 2019-05-05 14:15:34, Device: dr_Spritpreis_Diesel, Type: HTTPMOD, Event: Diesel_OMV: 1.259, Reading: Diesel_OMV, Value: 1.259, Unit:
2019.05.05 14:15:34 4: DbLog DBLogging -> check Device: dr_Spritpreis_Diesel , Event: Diesel_Jet: 1.259
2019.05.05 14:15:34 5: DbLog DBLogging -> parsed Event: dr_Spritpreis_Diesel , Event: Diesel_Jet: 1.259
2019.05.05 14:15:34 4: DbLog DBLogging -> added event - Timestamp: 2019-05-05 14:15:34, Device: dr_Spritpreis_Diesel, Type: HTTPMOD, Event: Diesel_Jet: 1.259, Reading: Diesel_Jet, Value: 1.259, Unit:
2019.05.05 14:15:34 4: DbLog DBLogging -> ################################################################
2019.05.05 14:15:34 4: DbLog DBLogging -> ###         New database processing cycle - synchronous      ###
2019.05.05 14:15:34 4: DbLog DBLogging -> ################################################################
2019.05.05 14:15:34 4: DbLog DBLogging -> DbLogType is: History
2019.05.05 14:15:34 4: DbLog DBLogging -> AutoCommit mode: ON, Transaction mode: ON
2019.05.05 14:15:34 4: DbLog DBLogging -> Insert mode: Array
2019.05.05 14:15:34 5: DbLog DBLogging -> Primary Key used in fhem.history: none
2019.05.05 14:15:34 5: DbLog DBLogging -> Primary Key used in fhem.current: none
2019.05.05 14:15:34 4: DbLog DBLogging -> processing event Timestamp: 2019-05-05 14:15:34, Device: dr_Spritpreis_Diesel, Type: HTTPMOD, Event: Diesel_EDEKA: 1.259, Reading: Diesel_EDEKA, Value: 1.259, Unit:
2019.05.05 14:15:34 4: DbLog DBLogging -> processing event Timestamp: 2019-05-05 14:15:34, Device: dr_Spritpreis_Diesel, Type: HTTPMOD, Event: Diesel_Shell: 1.279, Reading: Diesel_Shell, Value: 1.279, Unit:
2019.05.05 14:15:34 4: DbLog DBLogging -> processing event Timestamp: 2019-05-05 14:15:34, Device: dr_Spritpreis_Diesel, Type: HTTPMOD, Event: Diesel_Agip: 1.289, Reading: Diesel_Agip, Value: 1.289, Unit:
2019.05.05 14:15:34 4: DbLog DBLogging -> processing event Timestamp: 2019-05-05 14:15:34, Device: dr_Spritpreis_Diesel, Type: HTTPMOD, Event: Diesel_Aral: 1.319, Reading: Diesel_Aral, Value: 1.319, Unit:
2019.05.05 14:15:34 4: DbLog DBLogging -> processing event Timestamp: 2019-05-05 14:15:34, Device: dr_Spritpreis_Diesel, Type: HTTPMOD, Event: Diesel_Bavaria: 1.279, Reading: Diesel_Bavaria, Value: 1.279, Unit:
2019.05.05 14:15:34 4: DbLog DBLogging -> processing event Timestamp: 2019-05-05 14:15:34, Device: dr_Spritpreis_Diesel, Type: HTTPMOD, Event: Diesel_ESSO: 1.289, Reading: Diesel_ESSO, Value: 1.289, Unit:
2019.05.05 14:15:34 4: DbLog DBLogging -> processing event Timestamp: 2019-05-05 14:15:34, Device: dr_Spritpreis_Diesel, Type: HTTPMOD, Event: Diesel_OMV: 1.259, Reading: Diesel_OMV, Value: 1.259, Unit:
2019.05.05 14:15:34 4: DbLog DBLogging -> processing event Timestamp: 2019-05-05 14:15:34, Device: dr_Spritpreis_Diesel, Type: HTTPMOD, Event: Diesel_Jet: 1.259, Reading: Diesel_Jet, Value: 1.259, Unit:
2019.05.05 14:15:34 4: DbLog DBLogging -> 8 of 8 events inserted into table history
2019.05.05 14:15:34 4: DbLog DBLogging -> insert table history committed by autocommit
2019.05.05 14:15:34 5: DbLog DBLogging -> DbLog_Push Returncode: 0
2019.05.05 14:15:34 5: End notify loop for dr_Spritpreis_Diesel
2019.05.05 14:15:34 5: dr_Spritpreis_Diesel: HandleSendQueue called, qlen = 0
2019.05.05 14:15:34 4: Calendar Kalender_Abfall: Wakeup
2019.05.05 14:15:34 4: Calendar Kalender_Abfall: Updating...
2019.05.05 14:15:34 5: HttpUtils url=<hidden>
2019.05.05 14:15:34 4: IP: calendar.google.com -> 216.58.207.174
2019.05.05 14:15:34 4: Calendar Kalender_Abfall: Getting data from URL <hidden>
2019.05.05 14:15:34 4: dr_Spritpreis_Benzin: GetUpdate called (update)
2019.05.05 14:15:34 4: dr_Spritpreis_Benzin: update timer modified: will call GetUpdate in 600.0 seconds at 2019-05-05 14:25:34
2019.05.05 14:15:34 4: dr_Spritpreis_Benzin: AddToQueue adds update, initial queue len: 0
2019.05.05 14:15:34 5: dr_Spritpreis_Benzin: AddToQueue adds type update to URL https://www.clever-tanken.de/tankstelle_liste?lat=&lon=&ort=80331&spritsorte=7&r=5, no data, no headers, retry 0
2019.05.05 14:15:34 5: dr_Spritpreis_Benzin: HandleSendQueue called, qlen = 1
2019.05.05 14:15:34 4: dr_Spritpreis_Benzin: HandleSendQueue sends request type update to URL https://www.clever-tanken.de/tankstelle_liste?lat=&lon=&ort=80331&spritsorte=7&r=5, No Data, No Header
timeout 5
2019.05.05 14:15:34 5: HttpUtils url=https://www.clever-tanken.de/tankstelle_liste?lat=&lon=&ort=80331&spritsorte=7&r=5
2019.05.05 14:15:34 4: IP: www.clever-tanken.de -> 212.11.226.57
2019.05.05 14:15:34 5: HttpUtils request header:
GET /calendar/ical/******/basic.ics HTTP/1.0
Host: calendar.google.com
User-Agent: fhem
Accept-Encoding: gzip,deflate

2019.05.05 14:15:34 5: HttpUtils request header:
GET /tankstelle_liste?lat=&lon=&ort=80331&spritsorte=7&r=5 HTTP/1.0
Host: www.clever-tanken.de
User-Agent: fhem
Accept-Encoding: gzip,deflate
Content-Length: 0
Content-Type: application/x-www-form-urlencoded

2019.05.05 14:15:34 4: <hidden>: HTTP response code 200
2019.05.05 14:15:34 5: HttpUtils <hidden>: Got data, length: 54633
2019.05.05 14:15:34 5: HttpUtils response header:
HTTP/1.0 200 OK
Strict-Transport-Security: max-age=31536000; includeSubDomains; preload
Content-Security-Policy: script-src 'report-sample' 'nonce-EZJRNuWezeyjYY3N8b5z7w' 'unsafe-inline' 'strict-dynamic' https: http: 'unsafe-eval';object-src 'none';base-uri 'self';report-uri /calendar/cspreport
Content-Type: text/calendar; charset=UTF-8
Cache-Control: no-cache, no-store, max-age=0, must-revalidate
Pragma: no-cache
Expires: Mon, 01 Jan 1990 00:00:00 GMT
Date: Sun, 05 May 2019 12:15:34 GMT
Content-Encoding: gzip
X-Content-Type-Options: nosniff
X-Frame-Options: SAMEORIGIN
X-XSS-Protection: 1; mode=block
Server: GSE
Alt-Svc: quic=":443"; ma=2592000; v="46,44,43,39"
2019.05.05 14:15:34 5: Calendar Kalender_Abfall: HTTP response code 200
2019.05.05 14:15:34 5: Starting notify loop for Kalender_Abfall, 1 event(s), first is retrieved
2019.05.05 14:15:34 4: DbLog DBLogging -> ################################################################
2019.05.05 14:15:34 4: DbLog DBLogging -> ###              start of new Logcycle                       ###
2019.05.05 14:15:34 4: DbLog DBLogging -> ################################################################
2019.05.05 14:15:34 4: DbLog DBLogging -> number of events received: 1 for device: Kalender_Abfall
2019.05.05 14:15:34 4: DbLog DBLogging -> check Device: Kalender_Abfall , Event: state: retrieved
2019.05.05 14:15:34 5: DbLog DBLogging -> parsed Event: Kalender_Abfall , Event: state: retrieved
2019.05.05 14:15:34 4: DbLog DBLogging -> added event - Timestamp: 2019-05-05 14:15:34, Device: Kalender_Abfall, Type: CALENDAR, Event: state: retrieved, Reading: state, Value: retrieved, Unit:
2019.05.05 14:15:34 4: DbLog DBLogging -> ################################################################
2019.05.05 14:15:34 4: DbLog DBLogging -> ###         New database processing cycle - synchronous      ###
2019.05.05 14:15:34 4: DbLog DBLogging -> ################################################################
2019.05.05 14:15:34 4: DbLog DBLogging -> DbLogType is: History
2019.05.05 14:15:34 4: DbLog DBLogging -> AutoCommit mode: ON, Transaction mode: ON
2019.05.05 14:15:34 4: DbLog DBLogging -> Insert mode: Array
2019.05.05 14:15:34 5: DbLog DBLogging -> Primary Key used in fhem.history: none
2019.05.05 14:15:34 5: DbLog DBLogging -> Primary Key used in fhem.current: none
2019.05.05 14:15:34 4: DbLog DBLogging -> processing event Timestamp: 2019-05-05 14:15:34, Device: Kalender_Abfall, Type: CALENDAR, Event: state: retrieved, Reading: state, Value: retrieved, Unit:
2019.05.05 14:15:34 4: DbLog DBLogging -> 1 of 1 events inserted into table history
2019.05.05 14:15:34 4: DbLog DBLogging -> insert table history committed by autocommit
2019.05.05 14:15:34 5: DbLog DBLogging -> DbLog_Push Returncode: 0
2019.05.05 14:15:34 5: End notify loop for Kalender_Abfall
2019.05.05 14:15:34 5: SubProcess 24004 created.
2019.05.05 14:15:34 4: Calendar Kalender_Abfall: parsing data asynchronously (PID= 24004)
2019.05.05 14:15:34 5: SubProcess 24004 started.
2019.05.05 14:15:34 5: Calendar Kalender_Abfall: control passed back to main loop.
2019.05.05 14:15:35 5: SubProcess 24004 ended.
2019.05.05 21:45:44 4: https://www.clever-tanken.de/tankstelle_liste?lat=&lon=&ort=80331&spritsorte=7&r=5: HTTP response code 200
2019.05.05 21:45:44 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at FHEM/HttpUtils.pm line 866.
2019.05.05 21:45:44 5: HttpUtils https://www.clever-tanken.de/tankstelle_liste?lat=&lon=&ort=80331&spritsorte=7&r=5: Got data, length:
2019.05.05 21:45:44 5: HttpUtils response header:
HTTP/1.1 200 OK
Date: Sun, 05 May 2019 12:15:34 GMT
Server: Apache/2.4.18 (Ubuntu)
Vary: Cookie,Accept-Encoding
Content-Encoding: gzip
Content-Length: 19524
Content-Type: text/html; charset=utf-8
Set-Cookie: csrftoken=YJEDewvLQjiWJmKGHbFswL9bSidRHe67McknU5m1PJ8bRvfhGOhB0A6U41WnRtDa; expires=Sun, 03-May-2020 12:15:34 GMT; Max-Age=31449600; Path=/
Set-Cookie: spritsorte=7; expires=Mon, 04-May-2020 12:15:34 GMT; Max-Age=31536000; Path=/
Set-Cookie: search_city="{\"plz\": \"80331\"\054 \"avg\": 1.4731667\054 \"spritsorte_name\": \"Super E5\"\054 \"name\": \"münchen\"\054 \"slug\": \"münchen\"}"; expires=Sun, 05-May-2019 12:16:34 GMT; Max-Age=60; Path=/
Connection: close
2019.05.05 21:45:44 4: dr_Spritpreis_Benzin: Read callback: request type was update retry 0, body empty
2019.05.05 21:45:44 5: dr_Spritpreis_Benzin: ExtractSid called, context reading, num
2019.05.05 21:45:44 4: dr_Spritpreis_Benzin: CheckAuth decided no authentication required
2019.05.05 21:45:44 5: dr_Spritpreis_Benzin: Read starts parsing response to update with defined readings: 01,02,03,04,05,06,07,08
2019.05.05 21:45:44 5: dr_Spritpreis_Benzin: ExtractReading Benzin_EDEKA with regex /'*', '*','','EDEKA Tankstelle',null,2209,2210,60,'([0-9].[0-9][0-9][0-9])/...
2019.05.05 21:45:44 5: dr_Spritpreis_Benzin: ExtractReading Benzin_EDEKA did not match
2019.05.05 21:45:44 5: dr_Spritpreis_Benzin: ExtractReading Benzin_Shell with regex /'*', '*','','Shell',null,2209,2210,60,'([0-9].[0-9][0-9][0-9])/...
2019.05.05 21:45:44 5: dr_Spritpreis_Benzin: ExtractReading Benzin_Shell did not match
2019.05.05 21:45:44 5: dr_Spritpreis_Benzin: ExtractReading Benzin_Agip with regex /'*', '*','','Agip',null,2209,2210,60,'([0-9].[0-9][0-9][0-9])/...
2019.05.05 21:45:44 5: dr_Spritpreis_Benzin: ExtractReading Benzin_Agip did not match
2019.05.05 21:45:44 5: dr_Spritpreis_Benzin: ExtractReading Benzin_Aral with regex /'*', '*','','ARAL',null,2209,2210,60,'([0-9].[0-9][0-9][0-9])/...
2019.05.05 21:45:44 5: dr_Spritpreis_Benzin: ExtractReading Benzin_Aral did not match
2019.05.05 21:45:44 5: dr_Spritpreis_Benzin: ExtractReading Benzin_Bavaria with regex /'*', '*','','Bavaria Petrol',null,2209,2210,60,'([0-9].[0-9][0-9][0-9])/...
2019.05.05 21:45:44 5: dr_Spritpreis_Benzin: ExtractReading Benzin_Bavaria did not match
2019.05.05 21:45:44 5: dr_Spritpreis_Benzin: ExtractReading Benzin_ESSO with regex /'*', '*','','ESSO',null,2209,2210,60,'([0-9].[0-9][0-9][0-9])/...
2019.05.05 21:45:44 5: dr_Spritpreis_Benzin: ExtractReading Benzin_ESSO did not match
2019.05.05 21:45:44 5: dr_Spritpreis_Benzin: ExtractReading Benzin_OMV with regex /'*', '*','','OMV',null,2209,2210,60,'([0-9].[0-9][0-9][0-9])/...
2019.05.05 21:45:44 5: dr_Spritpreis_Benzin: ExtractReading Benzin_OMV did not match
2019.05.05 21:45:44 5: dr_Spritpreis_Benzin: ExtractReading Benzin_Jet with regex /'*', '*','','JET',null,2209,2210,60,'([0-9].[0-9][0-9][0-9])/...
2019.05.05 21:45:44 5: dr_Spritpreis_Benzin: ExtractReading Benzin_Jet did not match
2019.05.05 21:45:44 3: dr_Spritpreis_Benzin: Read response to update didn't match any Reading
2019.05.05 21:45:44 5: dr_Spritpreis_Benzin: HandleSendQueue called, qlen = 0
2019.05.05 21:45:47 4: Calendar Kalender_Abfall: got result from asynchronous parsing.
2019.05.05 21:45:47 5: Waiting for SubProcess 24004...
2019.05.05 21:45:47 5: SubProcess 24004 terminated.
2019.05.05 21:45:47 4: Calendar Kalender_Abfall: asynchronous parsing finished.
2019.05.05 21:45:47 5: Starting notify loop for Kalender_Abfall, 1 event(s), first is parsed
2019.05.05 21:45:47 4: DbLog DBLogging -> ################################################################
2019.05.05 21:45:47 4: DbLog DBLogging -> ###              start of new Logcycle                       ###
2019.05.05 21:45:47 4: DbLog DBLogging -> ################################################################
2019.05.05 21:45:47 4: DbLog DBLogging -> number of events received: 1 for device: Kalender_Abfall
2019.05.05 21:45:47 4: DbLog DBLogging -> check Device: Kalender_Abfall , Event: state: parsed
2019.05.05 21:45:47 5: DbLog DBLogging -> parsed Event: Kalender_Abfall , Event: state: parsed
2019.05.05 21:45:47 4: DbLog DBLogging -> added event - Timestamp: 2019-05-05 21:45:47, Device: Kalender_Abfall, Type: CALENDAR, Event: state: parsed, Reading: state, Value: parsed, Unit:
2019.05.05 21:45:47 4: DbLog DBLogging -> ################################################################
2019.05.05 21:45:47 4: DbLog DBLogging -> ###         New database processing cycle - synchronous      ###
2019.05.05 21:45:47 4: DbLog DBLogging -> ################################################################
2019.05.05 21:45:47 4: DbLog DBLogging -> DbLogType is: History
2019.05.05 21:45:47 4: DbLog DBLogging -> AutoCommit mode: ON, Transaction mode: ON
2019.05.05 21:45:47 4: DbLog DBLogging -> Insert mode: Array
2019.05.05 21:45:47 5: DbLog DBLogging -> Primary Key used in fhem.history: none
2019.05.05 21:45:47 5: DbLog DBLogging -> Primary Key used in fhem.current: none
2019.05.05 21:45:47 4: DbLog DBLogging -> processing event Timestamp: 2019-05-05 21:45:47, Device: Kalender_Abfall, Type: CALENDAR, Event: state: parsed, Reading: state, Value: parsed, Unit:
2019.05.05 21:45:47 4: DbLog DBLogging -> 1 of 1 events inserted into table history
2019.05.05 21:45:47 4: DbLog DBLogging -> insert table history committed by autocommit
2019.05.05 21:45:47 5: DbLog DBLogging -> DbLog_Push Returncode: 0
2019.05.05 21:45:47 5: End notify loop for Kalender_Abfall
2019.05.05 21:45:47 4: Calendar Kalender_Abfall: merging data
2019.05.05 21:45:47 4: Calendar Kalender_Abfall: 182 records processed, 0 new, 0 known, 182 modified, 0 changed.
2019.05.05 21:45:47 4: Calendar Kalender_Abfall: creating calendar events
2019.05.05 21:45:48 5: Starting notify loop for Kalender_Abfall, 3 event(s), first is calname: Abfallkalender
2019.05.05 21:45:48 4: DbLog DBLogging -> ################################################################
2019.05.05 21:45:48 4: DbLog DBLogging -> ###              start of new Logcycle                       ###
2019.05.05 21:45:48 4: DbLog DBLogging -> ################################################################
2019.05.05 21:45:48 4: DbLog DBLogging -> number of events received: 3 for device: Kalender_Abfall
2019.05.05 21:45:48 4: DbLog DBLogging -> check Device: Kalender_Abfall , Event: calname: Abfallkalender
2019.05.05 21:45:48 5: DbLog DBLogging -> parsed Event: Kalender_Abfall , Event: calname: Abfallkalender
2019.05.05 21:45:48 4: DbLog DBLogging -> added event - Timestamp: 2019-05-05 21:45:48, Device: Kalender_Abfall, Type: CALENDAR, Event: calname: Abfallkalender, Reading: calname, Value: Abfallkalender, Unit:
2019.05.05 21:45:48 4: DbLog DBLogging -> check Device: Kalender_Abfall , Event: lastUpdate: 2019-05-05 14:15:34
2019.05.05 21:45:48 5: DbLog DBLogging -> parsed Event: Kalender_Abfall , Event: lastUpdate: 2019-05-05 14:15:34
2019.05.05 21:45:48 4: DbLog DBLogging -> added event - Timestamp: 2019-05-05 21:45:48, Device: Kalender_Abfall, Type: CALENDAR, Event: lastUpdate: 2019-05-05 14:15:34, Reading: lastUpdate, Value: 2019-05-05 14:15:34, Unit:
2019.05.05 21:45:48 4: DbLog DBLogging -> check Device: Kalender_Abfall , Event: nextUpdate: 2019-05-05 14:25:34
2019.05.05 21:45:48 5: DbLog DBLogging -> parsed Event: Kalender_Abfall , Event: nextUpdate: 2019-05-05 14:25:34
2019.05.05 21:45:48 4: DbLog DBLogging -> added event - Timestamp: 2019-05-05 21:45:48, Device: Kalender_Abfall, Type: CALENDAR, Event: nextUpdate: 2019-05-05 14:25:34, Reading: nextUpdate, Value: 2019-05-05 14:25:34, Unit:
2019.05.05 21:45:48 4: DbLog DBLogging -> ################################################################
2019.05.05 21:45:48 4: DbLog DBLogging -> ###         New database processing cycle - synchronous      ###
2019.05.05 21:45:48 4: DbLog DBLogging -> ################################################################
2019.05.05 21:45:48 4: DbLog DBLogging -> DbLogType is: History
2019.05.05 21:45:48 4: DbLog DBLogging -> AutoCommit mode: ON, Transaction mode: ON
2019.05.05 21:45:48 4: DbLog DBLogging -> Insert mode: Array
2019.05.05 21:45:48 5: DbLog DBLogging -> Primary Key used in fhem.history: none
2019.05.05 21:45:48 5: DbLog DBLogging -> Primary Key used in fhem.current: none
2019.05.05 21:45:48 4: DbLog DBLogging -> processing event Timestamp: 2019-05-05 21:45:48, Device: Kalender_Abfall, Type: CALENDAR, Event: calname: Abfallkalender, Reading: calname, Value: Abfallkalender, Unit:
2019.05.05 21:45:48 4: DbLog DBLogging -> processing event Timestamp: 2019-05-05 21:45:48, Device: Kalender_Abfall, Type: CALENDAR, Event: lastUpdate: 2019-05-05 14:15:34, Reading: lastUpdate, Value: 2019-05-05 14:15:34, Unit:
2019.05.05 21:45:48 4: DbLog DBLogging -> processing event Timestamp: 2019-05-05 21:45:48, Device: Kalender_Abfall, Type: CALENDAR, Event: nextUpdate: 2019-05-05 14:25:34, Reading: nextUpdate, Value: 2019-05-05 14:25:34, Unit:
2019.05.05 21:45:48 4: DbLog DBLogging -> 3 of 3 events inserted into table history
2019.05.05 21:45:48 4: DbLog DBLogging -> insert table history committed by autocommit
2019.05.05 21:45:48 5: DbLog DBLogging -> DbLog_Push Returncode: 0
2019.05.05 21:45:48 5: End notify loop for Kalender_Abfall
2019.05.05 21:45:48 4: Calendar Kalender_Abfall: Checking times...
2019.05.05 21:45:48 5: Starting notify loop for Kalender_Abfall, 4 event(s), first is modeUpcoming: 295187;144388;528831;906223;175567;788490;347833;505235;837910;539231;365142;769308;367517;549247;974228;839183;690856;451398;94925;696749;50360;43784;465903;299924;372749;774511;377721;717860;382435;107317;501030;590073;376128;197852;958194;539608;18078;824328;913376;322762;202514;64457;350416;625238;442515;506018;613933;338017;633491;461662;823436;158919;515664;210162;322488;290510;888534;188535;618130;540251;875512;156477;511398;5635;981287;781228;39224;115962;867025;627160;718313;256809
2019.05.05 21:45:48 4: DbLog DBLogging -> ################################################################
2019.05.05 21:45:48 4: DbLog DBLogging -> ###              start of new Logcycle                       ###
2019.05.05 21:45:48 4: DbLog DBLogging -> ################################################################
2019.05.05 21:45:48 4: DbLog DBLogging -> number of events received: 4 for device: Kalender_Abfall
2019.05.05 21:45:48 4: DbLog DBLogging -> check Device: Kalender_Abfall , Event: modeUpcoming: 295187;144388;528831;906223;175567;788490;347833;505235;837910;539231;365142;769308;367517;549247;974228;839183;690856;451398;94925;696749;50360;43784;465903;299924;372749;774511;377721;717860;382435;107317;501030;590073;376128;197852;958194;539608;18078;824328;913376;322762;202514;64457;350416;625238;442515;506018;613933;338017;633491;461662;823436;158919;515664;210162;322488;290510;888534;188535;618130;540251;875512;156477;511398;5635;981287;781228;39224;115962;867025;627160;718313;256809
2019.05.05 21:45:48 5: DbLog DBLogging -> parsed Event: Kalender_Abfall , Event: modeUpcoming: 295187;144388;528831;906223;175567;788490;347833;505235;837910;539231;365142;769308;367517;549247;974228;839183;690856;451398;94925;696749;50360;43784;465903;299924;372749;774511;377721;717860;382435;107317;501030;590073;376128;197852;958194;539608;18078;824328;913376;322762;202514;64457;350416;625238;442515;506018;613933;338017;633491;461662;823436;158919;515664;210162;322488;290510;888534;188535;618130;540251;875512;156477;511398;5635;981287;781228;39224;115962;867025;627160;718313;256809
2019.05.05 21:45:48 4: DbLog DBLogging -> added event - Timestamp: 2019-05-05 21:45:48, Device: Kalender_Abfall, Type: CALENDAR, Event: modeUpcoming: 295187;144388;528831;906223;175567;788490;347833;505235;837910;539231;365142;769308;367517;549247;974228;839183;690856;451398;94925;696749;50360;43784;465903;299924;372749;774511;377721;717860;382435;107317;501030;590073;376128;197852;958194;539608;18078;824328;913376;322762;202514;64457;350416;625238;442515;506018;613933;338017;633491;461662;823436;158919;515664;210162;322488;290510;888534;188535;618130;540251;875512;156477;511398;5635;981287;781228;39224;115962;867025;627160;718313;256809, Reading: modeUpcoming, Value: 295187;144388;528831;906223;175567;788490;347833;505235;837910;539231;365142;769308;367517;549247;974228;839183;690856;451398;94, Unit:
2019.05.05 21:45:48 4: DbLog DBLogging -> check Device: Kalender_Abfall , Event: modeAlarmOrStart: 539347;296297;778522;537778;289389;660538;785792;161648
2019.05.05 21:45:48 5: DbLog DBLogging -> parsed Event: Kalender_Abfall , Event: modeAlarmOrStart: 539347;296297;778522;537778;289389;660538;785792;161648
2019.05.05 21:45:48 4: DbLog DBLogging -> added event - Timestamp: 2019-05-05 21:45:48, Device: Kalender_Abfall, Type: CALENDAR, Event: modeAlarmOrStart: 539347;296297;778522;537778;289389;660538;785792;161648, Reading: modeAlarmOrStart, Value: 539347;296297;778522;537778;289389;660538;785792;161648, Unit:
2019.05.05 21:45:48 4: DbLog DBLogging -> check Device: Kalender_Abfall , Event: modeStart: 539347;296297;778522;537778;289389;660538;785792;161648
2019.05.05 21:45:48 5: DbLog DBLogging -> parsed Event: Kalender_Abfall , Event: modeStart: 539347;296297;778522;537778;289389;660538;785792;161648
2019.05.05 21:45:48 4: DbLog DBLogging -> added event - Timestamp: 2019-05-05 21:45:48, Device: Kalender_Abfall, Type: CALENDAR, Event: modeStart: 539347;296297;778522;537778;289389;660538;785792;161648, Reading: modeStart, Value: 539347;296297;778522;537778;289389;660538;785792;161648, Unit:
2019.05.05 21:45:48 4: DbLog DBLogging -> check Device: Kalender_Abfall , Event: state: triggered
2019.05.05 21:45:48 5: DbLog DBLogging -> parsed Event: Kalender_Abfall , Event: state: triggered
2019.05.05 21:45:48 4: DbLog DBLogging -> added event - Timestamp: 2019-05-05 21:45:48, Device: Kalender_Abfall, Type: CALENDAR, Event: state: triggered, Reading: state, Value: triggered, Unit:
2019.05.05 21:45:48 4: DbLog DBLogging -> ################################################################
2019.05.05 21:45:48 4: DbLog DBLogging -> ###         New database processing cycle - synchronous      ###
2019.05.05 21:45:48 4: DbLog DBLogging -> ################################################################
2019.05.05 21:45:48 4: DbLog DBLogging -> DbLogType is: History
2019.05.05 21:45:48 4: DbLog DBLogging -> AutoCommit mode: ON, Transaction mode: ON
2019.05.05 21:45:48 4: DbLog DBLogging -> Insert mode: Array
2019.05.05 21:45:48 5: DbLog DBLogging -> Primary Key used in fhem.history: none
2019.05.05 21:45:48 5: DbLog DBLogging -> Primary Key used in fhem.current: none
2019.05.05 21:45:48 4: DbLog DBLogging -> processing event Timestamp: 2019-05-05 21:45:48, Device: Kalender_Abfall, Type: CALENDAR, Event: modeUpcoming: 295187;144388;528831;906223;175567;788490;347833;505235;837910;539231;365142;769308;367517;549247;974228;839183;690856;451398;94925;696749;50360;43784;465903;299924;372749;774511;377721;717860;382435;107317;501030;590073;376128;197852;958194;539608;18078;824328;913376;322762;202514;64457;350416;625238;442515;506018;613933;338017;633491;461662;823436;158919;515664;210162;322488;290510;888534;188535;618130;540251;875512;156477;511398;5635;981287;781228;39224;115962;867025;627160;718313;256809, Reading: modeUpcoming, Value: 295187;144388;528831;906223;175567;788490;347833;505235;837910;539231;365142;769308;367517;549247;974228;839183;690856;451398;94, Unit:
2019.05.05 21:45:48 4: DbLog DBLogging -> processing event Timestamp: 2019-05-05 21:45:48, Device: Kalender_Abfall, Type: CALENDAR, Event: modeAlarmOrStart: 539347;296297;778522;537778;289389;660538;785792;161648, Reading: modeAlarmOrStart, Value: 539347;296297;778522;537778;289389;660538;785792;161648, Unit:
2019.05.05 21:45:48 4: DbLog DBLogging -> processing event Timestamp: 2019-05-05 21:45:48, Device: Kalender_Abfall, Type: CALENDAR, Event: modeStart: 539347;296297;778522;537778;289389;660538;785792;161648, Reading: modeStart, Value: 539347;296297;778522;537778;289389;660538;785792;161648, Unit:
2019.05.05 21:45:48 4: DbLog DBLogging -> processing event Timestamp: 2019-05-05 21:45:48, Device: Kalender_Abfall, Type: CALENDAR, Event: state: triggered, Reading: state, Value: triggered, Unit:
2019.05.05 21:45:48 4: DbLog DBLogging -> 4 of 4 events inserted into table history
2019.05.05 21:45:48 4: DbLog DBLogging -> insert table history committed by autocommit
2019.05.05 21:45:48 5: DbLog DBLogging -> DbLog_Push Returncode: 0
2019.05.05 21:45:48 5: End notify loop for Kalender_Abfall
2019.05.05 21:45:48 5: Starting notify loop for Kalender_Abfall, 1 event(s), first is nextWakeup: 2019-05-05 14:25:34
2019.05.05 21:45:48 4: DbLog DBLogging -> ################################################################
2019.05.05 21:45:48 4: DbLog DBLogging -> ###              start of new Logcycle                       ###
2019.05.05 21:45:48 4: DbLog DBLogging -> ################################################################
2019.05.05 21:45:48 4: DbLog DBLogging -> number of events received: 1 for device: Kalender_Abfall
2019.05.05 21:45:48 4: DbLog DBLogging -> check Device: Kalender_Abfall , Event: nextWakeup: 2019-05-05 14:25:34
2019.05.05 21:45:48 5: DbLog DBLogging -> parsed Event: Kalender_Abfall , Event: nextWakeup: 2019-05-05 14:25:34
2019.05.05 21:45:48 4: DbLog DBLogging -> added event - Timestamp: 2019-05-05 21:45:48, Device: Kalender_Abfall, Type: CALENDAR, Event: nextWakeup: 2019-05-05 14:25:34, Reading: nextWakeup, Value: 2019-05-05 14:25:34, Unit:
2019.05.05 21:45:48 4: DbLog DBLogging -> ################################################################
2019.05.05 21:45:48 4: DbLog DBLogging -> ###         New database processing cycle - synchronous      ###
2019.05.05 21:45:48 4: DbLog DBLogging -> ################################################################
2019.05.05 21:45:48 4: DbLog DBLogging -> DbLogType is: History
2019.05.05 21:45:48 4: DbLog DBLogging -> AutoCommit mode: ON, Transaction mode: ON
2019.05.05 21:45:48 4: DbLog DBLogging -> Insert mode: Array
2019.05.05 21:45:48 5: DbLog DBLogging -> Primary Key used in fhem.history: none
2019.05.05 21:45:48 5: DbLog DBLogging -> Primary Key used in fhem.current: none
2019.05.05 21:45:48 4: DbLog DBLogging -> processing event Timestamp: 2019-05-05 21:45:48, Device: Kalender_Abfall, Type: CALENDAR, Event: nextWakeup: 2019-05-05 14:25:34, Reading: nextWakeup, Value: 2019-05-05 14:25:34, Unit:
2019.05.05 21:45:48 4: DbLog DBLogging -> 1 of 1 events inserted into table history
2019.05.05 21:45:49 4: DbLog DBLogging -> insert table history committed by autocommit
2019.05.05 21:45:49 5: DbLog DBLogging -> DbLog_Push Returncode: 0
2019.05.05 21:45:49 5: End notify loop for Kalender_Abfall
2019.05.05 21:45:49 4: Calendar Kalender_Abfall: process ended.
2019.05.05 21:45:49 5: MQTT sz_Aquarium_MQTT message sent: PingReq/at-most-once
2019.05.05 21:45:49 5: SW: c000
2019.05.05 21:45:49 5: SYSMON raspberry_fhem: updateReadings.1060
2019.05.05 21:45:49 4: BlockingCall (SYSMON_blockingCall): created child (28326), uses telnetPort to connect back
2019.05.05 21:45:49 5: exec at command DBLogging_Reopen
2019.05.05 21:45:49 5: Cmd: >set DBLogging reopen<
2019.05.05 21:45:49 3: DbLog DBLogging: Reopen requested.
2019.05.05 21:45:49 3: DbLog DBLogging - Creating Push-Handle to database mysql:database=fhem;host=192.168.0.4;port=3306 with user fhemuser
2019.05.05 21:45:49 3: DbLog DBLogging - Push-Handle to db mysql:database=fhem;host=192.168.0.4;port=3306 created
2019.05.05 21:45:49 3: DbLog DBLogging - UTF8 support enabled
2019.05.05 21:45:49 3: DBLogging_Reopen: Reopen executed.
2019.05.05 21:45:49 5: redefine at command DBLogging_Reopen as +*00:05:00 set DBLogging reopen
2019.05.05 21:45:49 5: Starting notify loop for DBLogging_Reopen, 1 event(s), first is Next: 14:25:19
2019.05.05 21:45:49 4: DbLog DBLogging -> ################################################################
2019.05.05 21:45:49 4: DbLog DBLogging -> ###              start of new Logcycle                       ###
2019.05.05 21:45:49 4: DbLog DBLogging -> ################################################################
2019.05.05 21:45:49 4: DbLog DBLogging -> number of events received: 1 for device: DBLogging_Reopen
2019.05.05 21:45:49 4: DbLog DBLogging -> check Device: DBLogging_Reopen , Event: state: Next: 14:25:19
2019.05.05 21:45:49 5: DbLog DBLogging -> parsed Event: DBLogging_Reopen , Event: state: Next: 14:25:19
2019.05.05 21:45:49 4: DbLog DBLogging -> added event - Timestamp: 2019-05-05 21:45:49, Device: DBLogging_Reopen, Type: AT, Event: state: Next: 14:25:19, Reading: state, Value: Next, Unit: 14:25:19
2019.05.05 21:45:49 4: DbLog DBLogging -> ################################################################
2019.05.05 21:45:49 4: DbLog DBLogging -> ###         New database processing cycle - synchronous      ###
2019.05.05 21:45:49 4: DbLog DBLogging -> ################################################################
2019.05.05 21:45:49 4: DbLog DBLogging -> DbLogType is: History
2019.05.05 21:45:49 4: DbLog DBLogging -> AutoCommit mode: ON, Transaction mode: ON
2019.05.05 21:45:49 4: DbLog DBLogging -> Insert mode: Array
2019.05.05 21:45:49 5: DbLog DBLogging -> Primary Key used in fhem.history: none
2019.05.05 21:45:49 5: DbLog DBLogging -> Primary Key used in fhem.current: none
2019.05.05 21:45:49 4: DbLog DBLogging -> processing event Timestamp: 2019-05-05 21:45:49, Device: DBLogging_Reopen, Type: AT, Event: state: Next: 14:25:19, Reading: state, Value: Next, Unit: 14:25:19
2019.05.05 21:45:49 4: DbLog DBLogging -> 1 of 1 events inserted into table history
2019.05.05 21:45:49 4: DbLog DBLogging -> insert table history committed by autocommit
2019.05.05 21:45:49 5: DbLog DBLogging -> DbLog_Push Returncode: 0
2019.05.05 21:45:49 5: End notify loop for DBLogging_Reopen
2019.05.05 21:45:49 5: exec at command DBLogging_Reopen
2019.05.05 21:45:49 5: Cmd: >set DBLogging reopen<
2019.05.05 21:45:49 3: DbLog DBLogging: Reopen requested.
2019.05.05 21:45:49 3: DbLog DBLogging - Creating Push-Handle to database mysql:database=fhem;host=192.168.0.4;port=3306 with user fhemuser
2019.05.05 21:45:49 3: DbLog DBLogging - Push-Handle to db mysql:database=fhem;host=192.168.0.4;port=3306 created
2019.05.05 21:45:49 3: DbLog DBLogging - UTF8 support enabled
2019.05.05 21:45:49 3: DBLogging_Reopen: Reopen executed.
2019.05.05 21:45:49 5: redefine at command DBLogging_Reopen as +*00:05:00 set DBLogging reopen
2019.05.05 21:45:49 5: Starting notify loop for DBLogging_Reopen, 1 event(s), first is Next: 14:30:19
2019.05.05 21:45:49 4: DbLog DBLogging -> ################################################################
2019.05.05 21:45:49 4: DbLog DBLogging -> ###              start of new Logcycle                       ###
2019.05.05 21:45:49 4: DbLog DBLogging -> ################################################################
2019.05.05 21:45:49 4: DbLog DBLogging -> number of events received: 1 for device: DBLogging_Reopen
2019.05.05 21:45:49 4: DbLog DBLogging -> check Device: DBLogging_Reopen , Event: state: Next: 14:30:19
2019.05.05 21:45:49 5: DbLog DBLogging -> parsed Event: DBLogging_Reopen , Event: state: Next: 14:30:19
2019.05.05 21:45:49 4: DbLog DBLogging -> added event - Timestamp: 2019-05-05 21:45:49, Device: DBLogging_Reopen, Type: AT, Event: state: Next: 14:30:19, Reading: state, Value: Next, Unit: 14:30:19
2019.05.05 21:45:49 4: DbLog DBLogging -> ################################################################
2019.05.05 21:45:49 4: DbLog DBLogging -> ###         New database processing cycle - synchronous      ###
2019.05.05 21:45:49 4: DbLog DBLogging -> ################################################################
2019.05.05 21:45:49 4: DbLog DBLogging -> DbLogType is: History
2019.05.05 21:45:49 4: DbLog DBLogging -> AutoCommit mode: ON, Transaction mode: ON
2019.05.05 21:45:49 4: DbLog DBLogging -> Insert mode: Array
2019.05.05 21:45:49 5: DbLog DBLogging -> Primary Key used in fhem.history: none
2019.05.05 21:45:49 5: DbLog DBLogging -> Primary Key used in fhem.current: none
2019.05.05 21:45:49 4: DbLog DBLogging -> processing event Timestamp: 2019-05-05 21:45:49, Device: DBLogging_Reopen, Type: AT, Event: state: Next: 14:30:19, Reading: state, Value: Next, Unit: 14:30:19
2019.05.05 21:45:49 4: DbLog DBLogging -> 1 of 1 events inserted into table history
2019.05.05 21:45:49 4: DbLog DBLogging -> insert table history committed by autocommit
2019.05.05 21:45:49 5: DbLog DBLogging -> DbLog_Push Returncode: 0
2019.05.05 21:45:49 5: End notify loop for DBLogging_Reopen
2019.05.05 21:45:49 5: exec at command at_wz_dht11
2019.05.05 21:45:49 5: Cmd: >{my $value = qx(/home/pi/Adafruit_Python_DHT/examples/AdafruitDHT.py 11 4);;fhem("set wz_DHT11 $value")}<
2019.05.05 21:45:56 5: Cmd: >set wz_DHT11 Temp=24.0*  Humidity=34.0%
<
2019.05.05 21:45:56 4: dummy set wz_DHT11 Temp=24.0* Humidity=34.0%

2019.05.05 21:45:56 5: Starting notify loop for wz_DHT11, 2 event(s), first is Temp: 24.0
2019.05.05 21:45:56 4: DbLog DBLogging -> ################################################################
2019.05.05 21:45:56 4: DbLog DBLogging -> ###              start of new Logcycle                       ###
2019.05.05 21:45:56 4: DbLog DBLogging -> ################################################################
2019.05.05 21:45:56 4: DbLog DBLogging -> number of events received: 2 for device: wz_DHT11
2019.05.05 21:45:56 4: DbLog DBLogging -> check Device: wz_DHT11 , Event: Temp: 24.0
2019.05.05 21:45:56 5: DbLog DBLogging -> parsed Event: wz_DHT11 , Event: Temp: 24.0
2019.05.05 21:45:56 4: DbLog DBLogging -> added event - Timestamp: 2019-05-05 21:45:56, Device: wz_DHT11, Type: DUMMY, Event: Temp: 24.0, Reading: Temp, Value: 24.0, Unit:
2019.05.05 21:45:56 4: DbLog DBLogging -> check Device: wz_DHT11 , Event: Humidity: 34.0
2019.05.05 21:45:56 5: DbLog DBLogging -> parsed Event: wz_DHT11 , Event: Humidity: 34.0
2019.05.05 21:45:56 4: DbLog DBLogging -> added event - Timestamp: 2019-05-05 21:45:56, Device: wz_DHT11, Type: DUMMY, Event: Humidity: 34.0, Reading: Humidity, Value: 34.0, Unit:
2019.05.05 21:45:56 4: DbLog DBLogging -> ################################################################
2019.05.05 21:45:56 4: DbLog DBLogging -> ###         New database processing cycle - synchronous      ###
2019.05.05 21:45:56 4: DbLog DBLogging -> ################################################################
2019.05.05 21:45:56 4: DbLog DBLogging -> DbLogType is: History
2019.05.05 21:45:56 4: DbLog DBLogging -> AutoCommit mode: ON, Transaction mode: ON
2019.05.05 21:45:56 4: DbLog DBLogging -> Insert mode: Array
2019.05.05 21:45:56 5: DbLog DBLogging -> Primary Key used in fhem.history: none
2019.05.05 21:45:56 5: DbLog DBLogging -> Primary Key used in fhem.current: none
2019.05.05 21:45:56 4: DbLog DBLogging -> processing event Timestamp: 2019-05-05 21:45:56, Device: wz_DHT11, Type: DUMMY, Event: Temp: 24.0, Reading: Temp, Value: 24.0, Unit:
2019.05.05 21:45:56 4: DbLog DBLogging -> processing event Timestamp: 2019-05-05 21:45:56, Device: wz_DHT11, Type: DUMMY, Event: Humidity: 34.0, Reading: Humidity, Value: 34.0, Unit:
2019.05.05 21:45:56 4: DbLog DBLogging -> 2 of 2 events inserted into table history
2019.05.05 21:45:56 4: DbLog DBLogging -> insert table history committed by autocommit
2019.05.05 21:45:56 5: DbLog DBLogging -> DbLog_Push Returncode: 0
2019.05.05 21:45:56 5: End notify loop for wz_DHT11
2019.05.05 21:45:56 5: redefine at command at_wz_dht11 as +*00:10:00 {my $value = qx(/home/pi/Adafruit_Python_DHT/examples/AdafruitDHT.py 11 4);;fhem("set wz_DHT11 $value")}
2019.05.05 21:45:56 5: Starting notify loop for at_wz_dht11, 1 event(s), first is Next: 14:35:20
2019.05.05 21:45:56 4: DbLog DBLogging -> ################################################################
2019.05.05 21:45:56 4: DbLog DBLogging -> ###              start of new Logcycle                       ###
2019.05.05 21:45:56 4: DbLog DBLogging -> ################################################################
2019.05.05 21:45:56 4: DbLog DBLogging -> number of events received: 1 for device: at_wz_dht11
2019.05.05 21:45:56 4: DbLog DBLogging -> check Device: at_wz_dht11 , Event: state: Next: 14:35:20
2019.05.05 21:45:56 5: DbLog DBLogging -> parsed Event: at_wz_dht11 , Event: state: Next: 14:35:20
2019.05.05 21:45:56 4: DbLog DBLogging -> added event - Timestamp: 2019-05-05 21:45:56, Device: at_wz_dht11, Type: AT, Event: state: Next: 14:35:20, Reading: state, Value: Next, Unit: 14:35:20
2019.05.05 21:45:56 4: DbLog DBLogging -> ################################################################
2019.05.05 21:45:56 4: DbLog DBLogging -> ###         New database processing cycle - synchronous      ###
2019.05.05 21:45:56 4: DbLog DBLogging -> ################################################################
2019.05.05 21:45:56 4: DbLog DBLogging -> DbLogType is: History
2019.05.05 21:45:56 4: DbLog DBLogging -> AutoCommit mode: ON, Transaction mode: ON
2019.05.05 21:45:56 4: DbLog DBLogging -> Insert mode: Array
2019.05.05 21:45:56 5: DbLog DBLogging -> Primary Key used in fhem.history: none
2019.05.05 21:45:56 5: DbLog DBLogging -> Primary Key used in fhem.current: none
2019.05.05 21:45:56 4: DbLog DBLogging -> processing event Timestamp: 2019-05-05 21:45:56, Device: at_wz_dht11, Type: AT, Event: state: Next: 14:35:20, Reading: state, Value: Next, Unit: 14:35:20
2019.05.05 21:45:56 4: DbLog DBLogging -> 1 of 1 events inserted into table history
2019.05.05 21:45:56 4: DbLog DBLogging -> insert table history committed by autocommit
2019.05.05 21:45:56 5: DbLog DBLogging -> DbLog_Push Returncode: 0
2019.05.05 21:45:56 5: End notify loop for at_wz_dht11
2019.05.05 21:45:56 5: exec at command at_bd_dht11
2019.05.05 21:45:56 5: Cmd: >{ system("ssh pi\@192.168.0.56 'python /home/pi/AdafruitDHT.py 11 17'") }<
ssh: connect to host 192.168.0.56 port 22: No route to host
2019.05.05 21:45:59 3: at_bd_dht11: -1
2019.05.05 21:45:59 5: redefine at command at_bd_dht11 as +*00:10 { system("ssh pi\@192.168.0.56 'python /home/pi/AdafruitDHT.py 11 17'") }
2019.05.05 21:45:59 5: Starting notify loop for at_bd_dht11, 1 event(s), first is Next: 14:35:24
2019.05.05 21:45:59 4: DbLog DBLogging -> ################################################################
2019.05.05 21:45:59 4: DbLog DBLogging -> ###              start of new Logcycle                       ###
2019.05.05 21:45:59 4: DbLog DBLogging -> ################################################################
2019.05.05 21:45:59 4: DbLog DBLogging -> number of events received: 1 for device: at_bd_dht11
2019.05.05 21:45:59 4: DbLog DBLogging -> check Device: at_bd_dht11 , Event: state: Next: 14:35:24
2019.05.05 21:45:59 5: DbLog DBLogging -> parsed Event: at_bd_dht11 , Event: state: Next: 14:35:24
2019.05.05 21:45:59 4: DbLog DBLogging -> added event - Timestamp: 2019-05-05 21:45:59, Device: at_bd_dht11, Type: AT, Event: state: Next: 14:35:24, Reading: state, Value: Next, Unit: 14:35:24
2019.05.05 21:45:59 4: DbLog DBLogging -> ################################################################
2019.05.05 21:45:59 4: DbLog DBLogging -> ###         New database processing cycle - synchronous      ###
2019.05.05 21:45:59 4: DbLog DBLogging -> ################################################################
2019.05.05 21:45:59 4: DbLog DBLogging -> DbLogType is: History
2019.05.05 21:45:59 4: DbLog DBLogging -> AutoCommit mode: ON, Transaction mode: ON
2019.05.05 21:45:59 4: DbLog DBLogging -> Insert mode: Array
2019.05.05 21:45:59 5: DbLog DBLogging -> Primary Key used in fhem.history: none
2019.05.05 21:45:59 5: DbLog DBLogging -> Primary Key used in fhem.current: none
2019.05.05 21:45:59 4: DbLog DBLogging -> processing event Timestamp: 2019-05-05 21:45:59, Device: at_bd_dht11, Type: AT, Event: state: Next: 14:35:24, Reading: state, Value: Next, Unit: 14:35:24
2019.05.05 21:45:59 4: DbLog DBLogging -> 1 of 1 events inserted into table history
2019.05.05 21:45:59 4: DbLog DBLogging -> insert table history committed by autocommit
2019.05.05 21:45:59 5: DbLog DBLogging -> DbLog_Push Returncode: 0
2019.05.05 21:45:59 5: End notify loop for at_bd_dht11
2019.05.05 21:45:59 4: dr_Spritpreis_Diesel: GetUpdate called (update)
2019.05.05 21:45:59 4: dr_Spritpreis_Diesel: update timer modified: will call GetUpdate in 600.0 seconds at 2019-05-05 21:55:59
2019.05.05 21:45:59 4: dr_Spritpreis_Diesel: AddToQueue adds update, initial queue len: 0
2019.05.05 21:45:59 5: dr_Spritpreis_Diesel: AddToQueue adds type update to URL https://www.clever-tanken.de/tankstelle_liste?lat=&lon=&ort=80331&spritsorte=3&r=5, no data, no headers, retry 0
2019.05.05 21:45:59 5: dr_Spritpreis_Diesel: HandleSendQueue called, qlen = 1
2019.05.05 21:45:59 4: dr_Spritpreis_Diesel: HandleSendQueue sends request type update to URL https://www.clever-tanken.de/tankstelle_liste?lat=&lon=&ort=80331&spritsorte=3&r=5, No Data, No Header
timeout 5
2019.05.05 21:45:59 5: HttpUtils url=https://www.clever-tanken.de/tankstelle_liste?lat=&lon=&ort=80331&spritsorte=3&r=5
2019.05.05 21:45:59 4: IP: www.clever-tanken.de -> 212.11.226.57
2019.05.05 21:45:59 4: Calendar Kalender_Abfall: Wakeup
2019.05.05 21:45:59 4: Calendar Kalender_Abfall: Updating...
2019.05.05 21:46:00 5: HttpUtils url=<hidden>
2019.05.05 21:46:00 4: IP: calendar.google.com -> 216.58.210.14
2019.05.05 21:46:00 4: Calendar Kalender_Abfall: Getting data from URL <hidden>
2019.05.05 21:46:00 4: dr_Spritpreis_Benzin: GetUpdate called (update)
2019.05.05 21:46:00 4: dr_Spritpreis_Benzin: update timer modified: will call GetUpdate in 600.0 seconds at 2019-05-05 21:56:00
2019.05.05 21:46:00 4: dr_Spritpreis_Benzin: AddToQueue adds update, initial queue len: 0
2019.05.05 21:46:00 5: dr_Spritpreis_Benzin: AddToQueue adds type update to URL https://www.clever-tanken.de/tankstelle_liste?lat=&lon=&ort=80331&spritsorte=7&r=5, no data, no headers, retry 0
2019.05.05 21:46:00 5: dr_Spritpreis_Benzin: HandleSendQueue called, qlen = 1
2019.05.05 21:46:00 4: dr_Spritpreis_Benzin: HandleSendQueue sends request type update to URL https://www.clever-tanken.de/tankstelle_liste?lat=&lon=&ort=80331&spritsorte=7&r=5, No Data, No Header
timeout 5
2019.05.05 21:46:00 5: HttpUtils url=https://www.clever-tanken.de/tankstelle_liste?lat=&lon=&ort=80331&spritsorte=7&r=5
2019.05.05 21:46:00 4: IP: www.clever-tanken.de -> 212.11.226.57
2019.05.05 21:46:00 5: exec at command DBLogging_Reopen
2019.05.05 21:46:00 5: Cmd: >set DBLogging reopen<
2019.05.05 21:46:00 3: DbLog DBLogging: Reopen requested.
2019.05.05 21:46:00 3: DbLog DBLogging - Creating Push-Handle to database mysql:database=fhem;host=192.168.0.4;port=3306 with user fhemuser
2019.05.05 21:46:00 3: DbLog DBLogging - Push-Handle to db mysql:database=fhem;host=192.168.0.4;port=3306 created
2019.05.05 21:46:00 3: DbLog DBLogging - UTF8 support enabled
2019.05.05 21:46:00 3: DBLogging_Reopen: Reopen executed.
2019.05.05 21:46:00 5: redefine at command DBLogging_Reopen as +*00:05:00 set DBLogging reopen
2019.05.05 21:46:00 5: Starting notify loop for DBLogging_Reopen, 1 event(s), first is Next: 14:35:19
2019.05.05 21:46:00 4: DbLog DBLogging -> ################################################################
2019.05.05 21:46:00 4: DbLog DBLogging -> ###              start of new Logcycle                       ###
2019.05.05 21:46:00 4: DbLog DBLogging -> ################################################################
2019.05.05 21:46:00 4: DbLog DBLogging -> number of events received: 1 for device: DBLogging_Reopen
2019.05.05 21:46:00 4: DbLog DBLogging -> check Device: DBLogging_Reopen , Event: state: Next: 14:35:19
2019.05.05 21:46:00 5: DbLog DBLogging -> parsed Event: DBLogging_Reopen , Event: state: Next: 14:35:19
2019.05.05 21:46:00 4: DbLog DBLogging -> added event - Timestamp: 2019-05-05 21:46:00, Device: DBLogging_Reopen, Type: AT, Event: state: Next: 14:35:19, Reading: state, Value: Next, Unit: 14:35:19
2019.05.05 21:46:00 4: DbLog DBLogging -> ################################################################
2019.05.05 21:46:00 4: DbLog DBLogging -> ###         New database processing cycle - synchronous      ###
2019.05.05 21:46:00 4: DbLog DBLogging -> ################################################################
2019.05.05 21:46:00 4: DbLog DBLogging -> DbLogType is: History
2019.05.05 21:46:00 4: DbLog DBLogging -> AutoCommit mode: ON, Transaction mode: ON
2019.05.05 21:46:00 4: DbLog DBLogging -> Insert mode: Array
2019.05.05 21:46:00 5: DbLog DBLogging -> Primary Key used in fhem.history: none
2019.05.05 21:46:00 5: DbLog DBLogging -> Primary Key used in fhem.current: none
2019.05.05 21:46:00 4: DbLog DBLogging -> processing event Timestamp: 2019-05-05 21:46:00, Device: DBLogging_Reopen, Type: AT, Event: state: Next: 14:35:19, Reading: state, Value: Next, Unit: 14:35:19
2019.05.05 21:46:00 4: DbLog DBLogging -> 1 of 1 events inserted into table history
2019.05.05 21:46:00 4: DbLog DBLogging -> insert table history committed by autocommit
2019.05.05 21:46:00 5: DbLog DBLogging -> DbLog_Push Returncode: 0
2019.05.05 21:46:00 5: End notify loop for DBLogging_Reopen
2019.05.05 21:46:00 5: exec at command DBLogging_Reopen
2019.05.05 21:46:00 5: Cmd: >set DBLogging reopen<
2019.05.05 21:46:00 3: DbLog DBLogging: Reopen requested.
2019.05.05 21:46:00 3: DbLog DBLogging - Creating Push-Handle to database mysql:database=fhem;host=192.168.0.4;port=3306 with user fhemuser
2019.05.05 21:46:00 3: DbLog DBLogging - Push-Handle to db mysql:database=fhem;host=192.168.0.4;port=3306 created
2019.05.05 21:46:00 3: DbLog DBLogging - UTF8 support enabled
2019.05.05 21:46:00 3: DBLogging_Reopen: Reopen executed.
2019.05.05 21:46:00 5: redefine at command DBLogging_Reopen as +*00:05:00 set DBLogging reopen
2019.05.05 21:46:00 5: Starting notify loop for DBLogging_Reopen, 1 event(s), first is Next: 14:40:19
2019.05.05 21:46:00 4: DbLog DBLogging -> ################################################################
2019.05.05 21:46:00 4: DbLog DBLogging -> ###              start of new Logcycle                       ###
2019.05.05 21:46:00 4: DbLog DBLogging -> ################################################################
2019.05.05 21:46:00 4: DbLog DBLogging -> number of events received: 1 for device: DBLogging_Reopen
2019.05.05 21:46:00 4: DbLog DBLogging -> check Device: DBLogging_Reopen , Event: state: Next: 14:40:19
2019.05.05 21:46:00 5: DbLog DBLogging -> parsed Event: DBLogging_Reopen , Event: state: Next: 14:40:19
2019.05.05 21:46:00 4: DbLog DBLogging -> added event - Timestamp: 2019-05-05 21:46:00, Device: DBLogging_Reopen, Type: AT, Event: state: Next: 14:40:19, Reading: state, Value: Next, Unit: 14:40:19
2019.05.05 21:46:00 4: DbLog DBLogging -> ################################################################
2019.05.05 21:46:00 4: DbLog DBLogging -> ###         New database processing cycle - synchronous      ###
2019.05.05 21:46:00 4: DbLog DBLogging -> ################################################################
2019.05.05 21:46:00 4: DbLog DBLogging -> DbLogType is: History
2019.05.05 21:46:00 4: DbLog DBLogging -> AutoCommit mode: ON, Transaction mode: ON
2019.05.05 21:46:00 4: DbLog DBLogging -> Insert mode: Array
2019.05.05 21:46:00 5: DbLog DBLogging -> Primary Key used in fhem.history: none
2019.05.05 21:46:00 5: DbLog DBLogging -> Primary Key used in fhem.current: none
2019.05.05 21:46:00 4: DbLog DBLogging -> processing event Timestamp: 2019-05-05 21:46:00, Device: DBLogging_Reopen, Type: AT, Event: state: Next: 14:40:19, Reading: state, Value: Next, Unit: 14:40:19
2019.05.05 21:46:00 4: DbLog DBLogging -> 1 of 1 events inserted into table history
2019.05.05 21:46:00 4: DbLog DBLogging -> insert table history committed by autocommit
2019.05.05 21:46:00 5: DbLog DBLogging -> DbLog_Push Returncode: 0
2019.05.05 21:46:00 5: End notify loop for DBLogging_Reopen
2019.05.05 21:46:00 5: exec at command at_wz_dht11
2019.05.05 21:46:00 5: Cmd: >{my $value = qx(/home/pi/Adafruit_Python_DHT/examples/AdafruitDHT.py 11 4);;fhem("set wz_DHT11 $value")}<
2019.05.05 21:46:07 5: Cmd: >set wz_DHT11 Temp=23.0*  Humidity=34.0%
<
2019.05.05 21:46:07 4: dummy set wz_DHT11 Temp=23.0* Humidity=34.0%

2019.05.05 21:46:07 5: Starting notify loop for wz_DHT11, 2 event(s), first is Temp: 23.0
2019.05.05 21:46:07 4: DbLog DBLogging -> ################################################################
2019.05.05 21:46:07 4: DbLog DBLogging -> ###              start of new Logcycle                       ###
2019.05.05 21:46:07 4: DbLog DBLogging -> ################################################################
2019.05.05 21:46:07 4: DbLog DBLogging -> number of events received: 2 for device: wz_DHT11
2019.05.05 21:46:07 4: DbLog DBLogging -> check Device: wz_DHT11 , Event: Temp: 23.0
2019.05.05 21:46:07 5: DbLog DBLogging -> parsed Event: wz_DHT11 , Event: Temp: 23.0
2019.05.05 21:46:07 4: DbLog DBLogging -> added event - Timestamp: 2019-05-05 21:46:07, Device: wz_DHT11, Type: DUMMY, Event: Temp: 23.0, Reading: Temp, Value: 23.0, Unit:
2019.05.05 21:46:07 4: DbLog DBLogging -> check Device: wz_DHT11 , Event: Humidity: 34.0
2019.05.05 21:46:07 5: DbLog DBLogging -> parsed Event: wz_DHT11 , Event: Humidity: 34.0
2019.05.05 21:46:07 4: DbLog DBLogging -> added event - Timestamp: 2019-05-05 21:46:07, Device: wz_DHT11, Type: DUMMY, Event: Humidity: 34.0, Reading: Humidity, Value: 34.0, Unit:
2019.05.05 21:46:07 4: DbLog DBLogging -> ################################################################
2019.05.05 21:46:07 4: DbLog DBLogging -> ###         New database processing cycle - synchronous      ###
2019.05.05 21:46:07 4: DbLog DBLogging -> ################################################################
2019.05.05 21:46:07 4: DbLog DBLogging -> DbLogType is: History
2019.05.05 21:46:07 4: DbLog DBLogging -> AutoCommit mode: ON, Transaction mo

[rudolfkoenig]

Meine aktuelle Hypothese: das Calender-Modul laeuft zur gleichen Zeit (neudeutsch "race condition") und das vom Calender Modul gestartete SubProcess liest die Antwort von HttpUtils weg.

Kannst du bitte mit dem angehaengten HttpUtils.pm (und attr global verbose 5) ein Problemfall provozieren?

[Andal]

So, ich habe die Datei eben eingefügt und gestartet und es hat sich um 14:41:07 Uhr wieder aufgehangen. Habe um 14:44:24 Uhr wieder gestoppt.

Code Auswählen Erweitern

2019.05.06 14:41:06 1: CB HASH(0x26dc558)
2019.05.06 14:41:06 4: WEB_192.168.0.10_61151 GET /fhem?XHR=1&inform=type=status;filter=;since=1557114563.148;fmt=JSON&fw_id=89&timestamp=1557146435597; BUFLEN:0
2019.05.06 14:41:06 5: MQTT sz_Aquarium_MQTT message received: SubAck/at-most-once 1/at-most-once,at-most-once
2019.05.06 14:41:06 5: MQTT sz_Aquarium_MQTT message received: SubAck/at-most-once 1/at-most-once,at-most-once
2019.05.06 14:41:06 5: MQTT sz_Aquarium_MQTT message received: Publish/at-most-once sz/PIR
2019.05.06 14:41:06 5: publish received for sz/PIR, 0
2019.05.06 14:41:06 5: calling readingsSingleUpdate(sz_Aquarium_MQTT_DEVICE,PIR,0,1)
2019.05.06 14:41:07 1: directReadFn HASH(0x15288c0) for 10
2019.05.06 14:41:07 1: directReadFn HASH(0x15288c0) returned 692
2019.05.06 14:41:07 1: directReadFn HASH(0x15288c0) for 10
2019.05.06 14:44:24 1: PERL WARNING: Use of uninitialized value $len in concatenation (.) or string at FHEM/HttpUtils.pm line 601.
2019.05.06 14:44:24 1: directReadFn HASH(0x15288c0) returned
2019.05.06 14:44:24 4: https://www.clever-tanken.de/tankstelle_liste?lat=&lon=&ort=80331&spritsorte=3&r=5: HTTP response code 200
2019.05.06 14:44:24 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at FHEM/HttpUtils.pm line 871.
2019.05.06 14:44:24 5: HttpUtils https://www.clever-tanken.de/tankstelle_liste?lat=&lon=&ort=80331&spritsorte=3&r=5: Got data, length:
2019.05.06 14:44:24 5: HttpUtils response header:
HTTP/1.1 200 OK
Date: Mon, 06 May 2019 12:41:06 GMT
Server: Apache/2.4.18 (Ubuntu)
Vary: Cookie,Accept-Encoding
Content-Encoding: gzip
Content-Length: 19464
Content-Type: text/html; charset=utf-8
Set-Cookie: csrftoken=nGm4OhsrLXx13wcFCjo8RHU7ZbiF2Q3MrE9rrNlnChGmqJm0ZQltp6USxFsXH7Qh; expires=Mon, 04-May-2020 12:41:07 GMT; Max-Age=31449600; Path=/
Set-Cookie: spritsorte=3; expires=Tue, 05-May-2020 12:41:06 GMT; Max-Age=31536000; Path=/
Set-Cookie: search_city="{\"plz\": \"80331\"\054 \"avg\": 1.3119167\054 \"spritsorte_name\": \"Diesel\"\054 \"name\": \"münchen\"\054 \"slug\": \"münchen\"}"; expires=Mon, 06-May-2019 12:42:06 GMT; Max-Age=60; Path=/
Connection: close
2019.05.06 14:44:24 4: dr_Spritpreis_Diesel: Read callback: request type was update retry 0, body empty
2019.05.06 14:44:24 5: dr_Spritpreis_Diesel: ExtractSid called, context reading, num
2019.05.06 14:44:24 4: dr_Spritpreis_Diesel: CheckAuth decided no authentication required
2019.05.06 14:44:24 5: dr_Spritpreis_Diesel: UpdateReadingList created list of reading.* nums to parse during getUpdate as 01 02 03 04 05 06 07 08
2019.05.06 14:44:24 5: dr_Spritpreis_Diesel: Read starts parsing response to update with defined readings: 01,02,03,04,05,06,07,08

[rudolfkoenig]

sysread verklemmt sich in deinem Fall, weiss leider nicht, wieso, meine Hypothese von vorhin kann auch nicht zutreffen.
Habe eine Alternative angehaengt, der diesen Haenger versucht zu vermeiden: kannst Du es bitte damit erneut testen?

[Andal]

Okay, also seit 6.5. 20:45 Uhr läuft Fhem nun wieder stabil mit der neuen HttpUtils.pm, danke dir.

[rudolfkoenig]

Danke fuers Feedback.
Wie schnell hat sich das Ding vorher verklemmt?
Habe die Aenderungen (ohne Log-Meldungen) jetzt eingecheckt, ich wuesste nur gerne, wie das Problem ausgeloest wird.

[Andal]

Unterschiedlich, manchmal direkt nach dem Start, quasi bei der ersten Abfrage und manchmal auch erst nach ein paar Stunden.
Das wüsste ich auch gerne, warum das passiert ist.