Hallo
Ich verwende fhem auf einem Linux sserver und habe abgesetzt dazu ein Raspi mit dem ich via i2c diverse Sensoren auswerte. Der einfachheithalber habe ich auf dem RPI ein Webserver laufen und frage in einem PHP Script die i2c sensoren ab so dass ich sie auf dem Server via HTTPMOD auslesen kann.
Nun habe ich aber ein etwas komisches Phenomen: die Werte welche mir das HTTPMOD Device ausgibt, sind teilweise falsch, resp. unsinnig (s. Beispiel unten). Wenn ich jedoch mit dem Browser oder wget (auch unten) die gleiche Siete aufrufe, dann kommen die Werte korrekt. Selbst im Debug output vom HTTPMOD (in der Antwort vom Server) sind die Werte bereits falsch. Kann es sein, dass die unterliegenden HTTPUtils ein Fehler haben?
Auch bei mehrmaligem ausführen mit kurzen oder langen Pausen dazwischen immer das gleiche Phenomen. Nur ca. 1 von 10 HTTPMOD abfragen ist korrekt.
Hat jemand eine Idee?
Danke und Grüsse
STefan
Output von wget, telnet und/oder Browser:
> telnet raspi-1.clumsy.ch 80
Trying 10.0.10.81...
Connected to raspi-1.clumsy.ch.
Escape character is '^]'.
GET /index.php HTTP/1.0
Host: raspi-1.clumsy.ch
User-Agent: fhem
Content-Length: 0
Content-Type: application/x-www-form-urlencoded
HTTP/1.1 200 OK
Date: Sun, 03 Sep 2017 08:10:20 GMT
Server: Apache/2.4.18 (Ubuntu)
Content-Length: 556
Connection: close
Content-Type: application/json
{
"bme280aussen": {
"sensor": "bme280",
"address": "0x76",
"humidity": 71.24,
"pressure": 975.40,
"temperature": 16.12,
"altitude": 317.89,
"timestamp": 1504426221
}
,"bme280innen": {
"sensor": "bme280",
"address": "0x77",
"humidity": 34.06,
"pressure": 972.72,
"temperature": 29.69,
"altitude": 340.98,
"timestamp": 1504426221
}
,"lm75ainnen": {
"sensor": "lm75a",
"address": "0x48",
"temperature": 29.50,
"timestamp": 1504426221
}
,"tsl2561": {
"sensor": "tls2561",
"address": "0x39",
"broadband": 1918,
"ir": 518,
"lux": 156,
"timestamp": 1504426221
}
}
Debug Output vom HTTPMOD:
2017.09.03 10:07:48 5: HttpUtils request header:
GET /index.php HTTP/1.0
Host: raspi-1.clumsy.ch
User-Agent: fhem
Content-Length: 0
Content-Type: application/x-www-form-urlencoded
2017.09.03 10:07:49 3: tsl2561: error while parsing JSON data: 'null' expected, at character offset 132 (before "nan,\n"timestamp": 1...") at (eval 1707841) line 1
2017.09.03 10:07:49 3: tsl2561: Read response to get04 didn't match any Reading
2017.09.03 10:07:49 4: http://raspi-1.clumsy.ch/index.php: HTTP response code 200
2017.09.03 10:07:49 4: HttpUtils http://raspi-1.clumsy.ch/index.php: Got data, length: 552
2017.09.03 10:07:49 5: HttpUtils response header:
HTTP/1.1 200 OK
Date: Sun, 03 Sep 2017 08:07:48 GMT
Server: Apache/2.4.18 (Ubuntu)
Content-Length: 552
Connection: close
Content-Type: application/json
2017.09.03 10:07:49 4: http_raspi_1: Read callback: request type was update retry 0,
Header: HTTP/1.1 200 OK
Date: Sun, 03 Sep 2017 08:07:48 GMT
Server: Apache/2.4.18 (Ubuntu)
Content-Length: 552
Connection: close
Content-Type: application/json,
Body: {
"bme280aussen": {
"sensor": "bme280",
"address": "0x76",
"humidity": 0.00,
"pressure": 1021.53,
"temperature": 40.51,
"altitude": -70.80,
"timestamp": 1504426068
}
,"bme280innen": {
"sensor": "bme280",
"address": "0x77",
"humidity": 30.07,
"pressure": 245.47,
"temperature": -22.35,
"altitude": 10480.66,
"timestamp": 1504426068
}
,"lm75ainnen": {
"sensor": "lm75a",
"address": "0x48",
"temperature": 29.50,
"timestamp": 1504426068
}
,"tsl2561": {
"sensor": "tls2561",
"address": "0x39",
"broadband": 0,
"ir": 0,
"lux": 0,
"timestamp": 1504426069
}
}
Die beiden Uhrzeiten sind nicht identisch. Könnte es sein, dass die Fehlermeldung unten dann eine andere ist? Auf den ersten Blick würde ich irgend etwas mit Kodierung vermuten, und zwar von clumsy.ch
Gesendet von iPad mit Tapatalk Pro
Beide Abfragen hab ich vom gleichen Rechner aus gemacht (linux server) mit dem gleichen Request-Header. Die Uhrzeit ist auf beiden Rechnern gleich, die ausführung "von Hand" war ca. 3 min. unterschied. Die UNterschiedliche Zeit im Log und HTML Output kommt wohl von der unterschiedlichen Zeitzone (CEST vs. GMT). Ob das ein Problem sein könnte?! Dann eher die Kodierung... aber was/wie/wo kann ich da ändern?! und v.a. was macht HTTPMOD da anders als eine pure abfrage auf Port 80?
Das eigentlich Problem ist jedoch, dass ich sowohl im browser wie mit wget oder telnet 99 von 100 mal das richtige Ergebnis erhalte (es gibt Situationen, bei denen der i2c Sensor nicht antwortet und das Script ein fehler zurück gibt, aber eben in 1% der Fälle..), bei HTTPMOD sind jedoch 9 von 10 Abfragen falsch... komisch auch die eine Fehlermeldiung beim Parser (NaN), welche so nicht ersichtlich ist beim output... und zwar kommt nur immer ein Fehler, aber mehrere Werte sind falsch...
was mir auch noch aufgefallen ist, ist dass im Debug-Output vom HTTPMOD der Antwort-Header doppelt drin ist... evtl. auch noch ein Ansatzpunkt...
ich weiss nicht wo ich noch suchen oder debuggen soll...
Ich verwende HTTPMOD noch an diversen anderen Orten, hab das so aber noch nie gesehen. Scheint auch nur bei Float-Werten zu passieren!
Das Gerät selbst ist sonst trivial:
define http_raspi_1 HTTPMOD http://raspi-1.clumsy.ch/index.php 20
attr http_raspi_1 alias Raspi-1
attr http_raspi_1 enableCookies 1
attr http_raspi_1 event-on-update-reading .*
attr http_raspi_1 extractAllJSON 1
attr http_raspi_1 timeout 10
Du hast die wget-Abfrage in einer Datei gespeichert? Hast du die mal genau angeschaut? Ich würde vermute , dass da irgendwelche Sonderzeichen drin sind, die das Problem verursachen. Alles andere ist sonst nicht nachvollziehbar.
Gesendet von iPhone mit Tapatalk Pro
Hab ich grad probiert, finde aber nichts (s.u.)...
Komisch auch, dass das ja "nur" beim HTTPMOD passiert... Kann es sein, dass irgendein Modul/Parser durch die "0x.." adress-felder verwirrt wird?
kann ich das noch irgendwie anders tracen?
0000000: 7b0a 2262 6d65 3238 3061 7573 7365 6e22 {."bme280aussen"
0000010: 3a20 7b0a 2273 656e 736f 7222 3a20 2262 : {."sensor": "b
0000020: 6d65 3238 3022 2c0a 2261 6464 7265 7373 me280",."address
0000030: 223a 2022 3078 3736 222c 0a22 6875 6d69 ": "0x76",."humi
0000040: 6469 7479 223a 2036 352e 3232 2c0a 2270 dity": 65.22,."p
0000050: 7265 7373 7572 6522 3a20 3937 312e 3736 ressure": 971.76
0000060: 2c0a 2274 656d 7065 7261 7475 7265 223a ,."temperature":
0000070: 2031 362e 3032 2c0a 2261 6c74 6974 7564 16.02,."altitud
0000080: 6522 3a20 3334 392e 3236 2c0a 2274 696d e": 349.26,."tim
0000090: 6573 7461 6d70 223a 2031 3530 3434 3634 estamp": 1504464
00000a0: 3939 300a 7d0a 2c22 626d 6532 3830 696e 990.}.,"bme280in
00000b0: 6e65 6e22 3a20 7b0a 2273 656e 736f 7222 nen": {."sensor"
00000c0: 3a20 2262 6d65 3238 3022 2c0a 2261 6464 : "bme280",."add
00000d0: 7265 7373 223a 2022 3078 3737 222c 0a22 ress": "0x77",."
00000e0: 6875 6d69 6469 7479 223a 2033 322e 3839 humidity": 32.89
00000f0: 2c0a 2270 7265 7373 7572 6522 3a20 3936 ,."pressure": 96
0000100: 392e 3138 2c0a 2274 656d 7065 7261 7475 9.18,."temperatu
0000110: 7265 223a 2033 302e 3135 2c0a 2261 6c74 re": 30.15,."alt
0000120: 6974 7564 6522 3a20 3337 312e 3435 2c0a itude": 371.45,.
0000130: 2274 696d 6573 7461 6d70 223a 2031 3530 "timestamp": 150
0000140: 3434 3634 3939 300a 7d0a 2c22 6c6d 3735 4464990.}.,"lm75
0000150: 6169 6e6e 656e 223a 207b 0a22 7365 6e73 ainnen": {."sens
0000160: 6f72 223a 2022 6c6d 3735 6122 2c0a 2261 or": "lm75a",."a
0000170: 6464 7265 7373 223a 2022 3078 3438 222c ddress": "0x48",
0000180: 0a22 7465 6d70 6572 6174 7572 6522 3a20 ."temperature":
0000190: 3330 2e30 302c 0a22 7469 6d65 7374 616d 30.00,."timestam
00001a0: 7022 3a20 3135 3034 3436 3439 3930 0a7d p": 1504464990.}
00001b0: 0a2c 2274 736c 3235 3631 223a 207b 0a22 .,"tsl2561": {."
00001c0: 7365 6e73 6f72 223a 2022 746c 7332 3536 sensor": "tls256
00001d0: 3122 2c0a 2261 6464 7265 7373 223a 2022 1",."address": "
00001e0: 3078 3339 222c 0a22 6272 6f61 6462 616e 0x39",."broadban
00001f0: 6422 3a20 312c 0a22 6972 223a 2030 2c0a d": 1,."ir": 0,.
0000200: 226c 7578 223a 2030 2c0a 2274 696d 6573 "lux": 0,."times
0000210: 7461 6d70 223a 2031 3530 3434 3634 3939 tamp": 150446499
0000220: 300a 7d0a 7d 0.}.}
Mea Culpa...
Ich glaub ich hab den Fehelr gefunden... Hab mal noch ein Wireshark laufen lassen, der zeigt ebenso, dass die Daten bereits falsch auf dem Netz sind (richtung Server)....
D.h. also dass es eher nicht das FHEM ist...
Anscheinend gibts eine art "Race-Condition" auf der Raspi-Seite. Ich habe testweise noch einzelne Devices mit HTTPMOD definiert, welche die gleihce URL abfragen. Wenn nun mehrere "gleichzeitig" die URL aufrufen und damit auch mehrer i2c abfragen stattfinden, scheint das ein Problem zu sein (kein exclusiver Zugriff auf i2c oder so...). Das kann ich nachstellen indem ich 2 effektiv parallele wgets mache... was natprlich sonst so gut wie nie der fall ist via browser etc... da fhem nur alle 20sek. abfragt...
Da das HTTPMOD aber anscheinend ziemlich parallel die requests macht, ergibt das probleme...
Fazit: muss die race-condition/exclusiv access auf der raspi seite ansehen um das problem zuverlässig zu lösen (bis dahin nur ein device definieren auf diese URL damit das gar nicht erst passiert...)
Trotzdem vielen Dank für die prompte und spontane Hilfe!!!! und Sorry nochmals dass ich erst jetzt drauf gekommen bin... aber der entscheidende hinweis war das mit den "sonderzeichen" und damit verbundnen wireshark analyse...
Geht mir auch so: man hat Probleme, Leute fragen was (oft am Problem vorbei) und dann fällt einem die Lösung ein ;-)
Gesendet von iPhone mit Tapatalk Pro