Hallo Zusammen
(Hinweis 1: Problemlösung und Patch weiter unten)
(Hinweis 2: Mangels fundierter Python-Kenntnisse (habe dieser Tage meine ersten Zeilen Python gesehen) können meine Schlussfolgerungen beliebig falsch und die Code-Schnipsel sehr laienhaft sein - ich bitte um Nachsicht :-) )
Im Zuge meiner ersten Gehversuche mit SmartHome.py möchte ich auch die OneWire-Temperatursensoren, die ich bisher mit digitemp in einem Shell-Script (per cron gestartet) abgefragt habe, mit SmartHome.py und dem 1-Wire-Plugin abfragen.
Nachdem das 1-Wire-Plugin owfs benötigt, habe ich dies installiert, bekomme bei mehreren Starts von SmartHome.py in gefühlt 75% der Fälle keine Werte vom owserver. In diesem Zustand liefert owdir/owread ohne Probleme Werte, d.h. der owserver funktioniert grundsätzlich. Ich habe die beiden auf der Home-Page genannten Versionen owfs-2.7p34 und owfs-2.8p15 und einige weitere (2.8p2, 2.8p13, 2.8p20) ausprobiert und konnte keinen nennenswerten Unterschied feststellen.
Nach meinen Beobachtung ist es so, dass wenn SmartHome.py direkt nach dem Start erfolgreich Werte vom owserver bekommt, dies auch weiterhin funktionieren wird. Erhält SmartHome.py jedoch direkt nach dem Start keine Werte, so wird es auch später keine erhalten.
Im Fehlerfall sieht das Log so aus:
Nachdem ich einige logger.debug()-Ausgaben eingefügt habe, konnte ich das Problem auf folgende Stelle in der _request()-Methode eingrenzen:
Die Exception "Exception e: unpack requires a string argument of length 24 -- __init__.py:_sensor_cycle:237" wird wohl von der letzten Zeile ausgelöst.
Füge ich ein logger.debug() vor und nach dieser Zeile ein...
... so sieht das Log nach dem nächsten Start im Fehlerfall aus:
... und im Erfolgsfall so:
D.h. nach meiner Interpretation liefert self._sock.recv(24) im Fehlerfall keine Daten, die dann eben mit struct.unpack() auch nicht verarbeitet werden können und eine Exception auslösen, wohingegen im Erfolgsfall 24 Byte geliefert werden.
Da durch die Exception von unpack() die Methode _request() ohne Freigabe von self._lock verlassen wird, bleibt beim nächsten Aufruf von _request() die Ausführung bereits bei self._lock.acquire() hängen, wodurch kein weiterer Versuch, die Sensoren abzufragen, stattfinden kann.
Tatsächlich konnte ich durch viele Versuche feststellen, dass das Fehlerszenario genau dann auftritt, wenn zwischen dem Herstellen der Verbindung in connect() und dem ersten, durch den Scheduler über _sensor_cycle() ausgelösten Aufruf von _request() mehr als 10 Sekunden vergangen sind. Ist diese Zeit < 10 Sekunden, funktioniert die erste und alle folgenden Abfragen einwandfrei.
Ich habe nun festgestellt, dass sich diese Zeit direkt mit folgender Option des owservers zusammen hängt:
Sobald die Zeit zwischen dem connect() und dem ersten Datenaustausch in _request() größer ist, als diese (Default) 10 Sekunden, so findet im OneWire-Plugin keine Kommunikation statt (bzw. der owserver antwortet nicht) und self._sock.recv() liefert stets len(header) == 0, wodurch wie oben beschrieben eine Exception in unpack() ausgelöst, der self._lock jedoch nicht freigegeben wird.
Warum dann keine socket.timeout-Exception ausgelöst wird, weiss ich - mangels tiefergehender Python-Kentnisse - leider nicht.
Füge ich eine Überprüfung auf len(header) == 0 ein und gebe hier den _lock frei und schließe die Verbindung, so wird _request() zumindest kontrolliert beendet:
Damit versucht SmartHome.py offensichtlich zu gegebener Zeit über den Scheduler erneut eine Verbindung herzustellen.
Dies kann erfolgreich sein oder wiederum scheitern, je nachdem, ob zwischen connect() und dem nächsten _request() weniger oder mehr als die o.g. 10 Sekunden liegen.
Weiter unten in _sensor_cycle(), wo in einer for-Schleife die Sensoren abgearbeitet werden, könnte es mglw. sinnvoll sein, im Falle dass der _request()-Aufrufs eines Sensors mit einer Exception scheitert UND die Verbindung nicht mehr vorhanden ist, die for-Schleife zu verlassen:
Mit diesen Änderungen (und ohne den Wert von timeout_server des owserver zu ändern) verhält sich SmartHome.py bzw. das 1-Wire-Plugin zumindest ein wenig robuster in der Situation, dass zwischen connect() und _request() länger als timeout_server vergeht.
Frage: Wie lange kann denn die Zeit in SmartHome.py werden, die maximal zwischen dem Aufruf von connect() und dem ersten Aufruf von _request() (verursacht durch ow oder ow.bus) vergehen kann?
IMHO sollte in der Doku des 1-Wire-Plugins der Hinweis angegeben werden, dass der owserver mit dem Parameter "--timeout_server=<XXX>" gestartet werden sollte, wobei XXX > die maximale Zeit zwischen connect() und _request() sein sollte.
Ich habe den owserver nun mal mit "--timeout_server=30" gestartet und hatte bei etlichen Starts von SmartHome.py keine Probleme mehr.
Noch eine Bitte / Vorschlag: Ich würde die OneWire-Sensoren gerne etwas häufiger abfragen (als die voreingestellten 300 Sekunden). Also habe ich diese Zyklus-Zeit für meine Tests in den Plugin-Einstellungen konfigurierbar gemacht, siehe Patch unten.
Dafür würde ich nicht das OneWire-Attribut "temperature", sondern "temperature9", "temperature10" oder "temperature11" verwenden, was sich schneller abfragen ließe. Das funktioniert soweit auch wunderbar, ich wundere mich allerdings über folgendes:
Wenn nun schon der präziseste Wert für "temperature" auf 1 Nachkommastelle gerundet wird, wäre es dann nicht sinnvoll, die weniger präzisen Werte "temperature9", "temperature10" oder "temperature11" ebenfalls zu runden?
Also etwa so:
Sodele, ich hoffe, ich habe mich mit diesen langen Ausführungen und meinen Interpretationen (und mit meinen bisher nicht vorhandenen Python-Kentnissen) nicht gänzlich zum Narren gemacht.
Hier nochmal das komplette diff (gegen git) mit allen Änderungen, die ich bei mir lokal gemacht habe:
Änderungen:
Marcus, vielen Dank nochmals für die Entwicklung von SmartHome.py - wenngleich mein Start etwas holprig war, macht es dennoch großen Spaß! Und nun bin ich auf die Kommentare gespannt...
Viele Grüße,
Alex
(Hinweis 1: Problemlösung und Patch weiter unten)
(Hinweis 2: Mangels fundierter Python-Kenntnisse (habe dieser Tage meine ersten Zeilen Python gesehen) können meine Schlussfolgerungen beliebig falsch und die Code-Schnipsel sehr laienhaft sein - ich bitte um Nachsicht :-) )
Im Zuge meiner ersten Gehversuche mit SmartHome.py möchte ich auch die OneWire-Temperatursensoren, die ich bisher mit digitemp in einem Shell-Script (per cron gestartet) abgefragt habe, mit SmartHome.py und dem 1-Wire-Plugin abfragen.
Nachdem das 1-Wire-Plugin owfs benötigt, habe ich dies installiert, bekomme bei mehreren Starts von SmartHome.py in gefühlt 75% der Fälle keine Werte vom owserver. In diesem Zustand liefert owdir/owread ohne Probleme Werte, d.h. der owserver funktioniert grundsätzlich. Ich habe die beiden auf der Home-Page genannten Versionen owfs-2.7p34 und owfs-2.8p15 und einige weitere (2.8p2, 2.8p13, 2.8p20) ausprobiert und konnte keinen nennenswerten Unterschied feststellen.
Nach meinen Beobachtung ist es so, dass wenn SmartHome.py direkt nach dem Start erfolgreich Werte vom owserver bekommt, dies auch weiterhin funktionieren wird. Erhält SmartHome.py jedoch direkt nach dem Start keine Werte, so wird es auch später keine erhalten.
Im Fehlerfall sieht das Log so aus:
Code:
2012-12-30 11:05:10,191 SmartHome.py INFO Init SmartHome.py v0.7 -- smarthome.py:__init__:183 2012-12-30 11:05:10,192 SmartHome.py INFO Init Scheduler -- scheduler.py:__init__:52 2012-12-30 11:05:10,192 Scheduler DEBUG creating 5 workers -- scheduler.py:run:58 2012-12-30 11:05:10,192 SmartHome.py INFO Init plugins -- smarthome.py:__init__:198 2012-12-30 11:05:10,193 SmartHome.py INFO Init Plugins -- plugin.py:__init__:34 2012-12-30 11:05:10,193 SmartHome.py DEBUG Plugin: ow -- plugin.py:__init__:43 2012-12-30 11:05:10,194 SmartHome.py DEBUG Plugin: cli -- plugin.py:__init__:43 2012-12-30 11:05:10,195 SmartHome.py INFO Init items -- smarthome.py:__init__:200 2012-12-30 11:05:10,200 SmartHome.py DEBUG Item 'test': No type specified. -- item.py:__init__:97 2012-12-30 11:05:10,200 SmartHome.py DEBUG sh.con next time: 2012-12-30 11:05:10+01:00 -- scheduler.py:_next_time:193 2012-12-30 11:05:10,200 SmartHome.py INFO Start Plugins -- plugin.py:start:64 2012-12-30 11:05:10,200 ow DEBUG ow.bus next time: 2012-12-30 11:05:26+01:00 -- scheduler.py:_next_time:193 2012-12-30 11:05:10,200 SmartHome.py INFO Starting logics -- logic.py:__init__:33 2012-12-30 11:05:10,201 ow DEBUG ow next time: 2012-12-30 11:05:21+01:00 -- scheduler.py:_next_time:193 2012-12-30 11:05:10,201 SmartHome.py DEBUG reading logics from /usr/local/smarthome/etc/logic.conf -- logic.py:__init__:40 2012-12-30 11:05:10,412 sh.gc DEBUG Garbage collector: collected 0 objects. -- smarthome.py:_garbage_collection:295 2012-12-30 11:05:10,413 sh.con INFO Onewire: connected to 192.168.1.1:4304 -- __init__.py:connect:62 2012-12-30 11:05:10,596 Scheduler DEBUG sh.con next time: 2012-12-30 11:07:10+01:00 -- scheduler.py:_next_time:193 2012-12-30 11:05:10,597 Scheduler DEBUG sh.gc next time: 2012-12-31 02:04:00+01:00 -- scheduler.py:_next_time:193 2012-12-30 11:05:21,059 ow DEBUG Could not read test.test_03 (28.52E030000000). Exception e: unpack requires a string argument of length 24 -- __init__.py:_sensor_cycle:237 2012-12-30 11:05:21,210 Scheduler DEBUG ow next time: 2012-12-30 11:10:21+01:00 -- scheduler.py:_next_time:193 2012-12-30 11:05:26,217 Scheduler DEBUG ow.bus next time: 2012-12-30 11:15:26+01:00 -- scheduler.py:_next_time:193
Code:
try:
header = self._sock.recv(24)
except socket.timeout:
self._lock.release()
raise owex("error receiving header: timeout")
except Exception, e:
self._lock.release()
self.close()
raise owex("error receiving header: {0}".format(e))
header = struct.unpack('IIIIII', header)
Füge ich ein logger.debug() vor und nach dieser Zeile ein...
Code:
logger.debug("received: {0} unpacking...".format(len(header)))
header = struct.unpack('IIIIII', header)
logger.debug("received: {0} unpacking...done".format(len(header)))
Code:
... 2012-12-30 11:10:44,031 ow DEBUG received: 0 unpacking... -- __init__.py:_request:106 2012-12-30 11:10:44,032 ow DEBUG Could not read test.test_03 (28.52E030000000). Exception e: unpack requires a string argument of length 24 -- __init__.py:_sensor_cycle:239 ...
Code:
2012-12-30 11:13:26,309 Scheduler DEBUG ow next time: 2012-12-30 11:18:26+01:00 -- scheduler.py:_next_time:193 2012-12-30 11:13:26,885 ow DEBUG received: 24 unpacking... -- __init__.py:_request:108 2012-12-30 11:13:26,885 ow DEBUG received: 6 unpacking...done -- __init__.py:_request:110 2012-12-30 11:13:26,885 ow INFO test.test_03 = 15.25 via 1-Wire None -- item.py:_update:183
Da durch die Exception von unpack() die Methode _request() ohne Freigabe von self._lock verlassen wird, bleibt beim nächsten Aufruf von _request() die Ausführung bereits bei self._lock.acquire() hängen, wodurch kein weiterer Versuch, die Sensoren abzufragen, stattfinden kann.
Tatsächlich konnte ich durch viele Versuche feststellen, dass das Fehlerszenario genau dann auftritt, wenn zwischen dem Herstellen der Verbindung in connect() und dem ersten, durch den Scheduler über _sensor_cycle() ausgelösten Aufruf von _request() mehr als 10 Sekunden vergangen sind. Ist diese Zeit < 10 Sekunden, funktioniert die erste und alle folgenden Abfragen einwandfrei.
Ich habe nun festgestellt, dass sich diese Zeit direkt mit folgender Option des owservers zusammen hängt:
Code:
~ # owserver --help=cache ... Communication timing [default] (in seconds) ... --timeout_server [ 10] Timeout for first server connection ...
Warum dann keine socket.timeout-Exception ausgelöst wird, weiss ich - mangels tiefergehender Python-Kentnisse - leider nicht.
Füge ich eine Überprüfung auf len(header) == 0 ein und gebe hier den _lock frei und schließe die Verbindung, so wird _request() zumindest kontrolliert beendet:
Code:
try:
header = self._sock.recv(24)
except socket.timeout:
...
except Exception, e:
...
+ if len(header) == 0:
+ self._lock.release()
+ self.close()
+ raise owex("error receiving header: no data")
Dies kann erfolgreich sein oder wiederum scheitern, je nachdem, ob zwischen connect() und dem nächsten _request() weniger oder mehr als die o.g. 10 Sekunden liegen.
Weiter unten in _sensor_cycle(), wo in einer for-Schleife die Sensoren abgearbeitet werden, könnte es mglw. sinnvoll sein, im Falle dass der _request()-Aufrufs eines Sensors mit einer Exception scheitert UND die Verbindung nicht mehr vorhanden ist, die for-Schleife zu verlassen:
Code:
def _sensor_cycle(self):
if not self.is_connected:
return
for sensor in self._sensors:
typ = self._sensors[sensor]['sensor']
path = "/" + sensor + '/' + typ
item = self._sensors[sensor]['item']
try:
value = self.read(path)
except Exception, e:
logger.debug("Could not read {0} ({1}). Exception e: {2}".format(item, sensor, e))
- continue
+ if self.is_connected:
+ continue
+ else:
+ break
Frage: Wie lange kann denn die Zeit in SmartHome.py werden, die maximal zwischen dem Aufruf von connect() und dem ersten Aufruf von _request() (verursacht durch ow oder ow.bus) vergehen kann?
IMHO sollte in der Doku des 1-Wire-Plugins der Hinweis angegeben werden, dass der owserver mit dem Parameter "--timeout_server=<XXX>" gestartet werden sollte, wobei XXX > die maximale Zeit zwischen connect() und _request() sein sollte.
Ich habe den owserver nun mal mit "--timeout_server=30" gestartet und hatte bei etlichen Starts von SmartHome.py keine Probleme mehr.
Noch eine Bitte / Vorschlag: Ich würde die OneWire-Sensoren gerne etwas häufiger abfragen (als die voreingestellten 300 Sekunden). Also habe ich diese Zyklus-Zeit für meine Tests in den Plugin-Einstellungen konfigurierbar gemacht, siehe Patch unten.
Dafür würde ich nicht das OneWire-Attribut "temperature", sondern "temperature9", "temperature10" oder "temperature11" verwenden, was sich schneller abfragen ließe. Das funktioniert soweit auch wunderbar, ich wundere mich allerdings über folgendes:
Code:
if typ == 'temperature':
value = round(value, 1)
Also etwa so:
Code:
if typ.startswith('temperature'):
value = round(value, 1)
Hier nochmal das komplette diff (gegen git) mit allen Änderungen, die ich bei mir lokal gemacht habe:
Code:
diff --git a/plugins/onewire/__init__.py b/plugins/onewire/__init__.py
index 0577c31..e57d782 100755
--- a/plugins/onewire/__init__.py
+++ b/plugins/onewire/__init__.py
@@ -103,6 +103,12 @@ class Owconnection():
self._lock.release()
self.close()
raise owex("error receiving header: {0}".format(e))
+
+ if len(header) == 0:
+ self._lock.release()
+ self.close()
+ raise owex("error receiving header: no data")
+
header = struct.unpack('IIIIII', header)
header = map(socket.ntohl, header)
fields = ['version', 'payload', 'ret', 'flags', 'size', 'offset']
@@ -170,16 +176,20 @@ class OneWire(Owconnection):
_ibutton_masters = {}
_intruders = []
alive = True
+ _bus_interval = 600
+ _sensor_interval = 300
- def __init__(self, smarthome, host='127.0.0.1', port=4304):
+ def __init__(self, smarthome, host='127.0.0.1', port=4304, bus_interval=600, sensor_interval=300):
Owconnection.__init__(self, host, port)
self._sh = smarthome
+ self._bus_interval = int(bus_interval)
+ self._sensor_interval = int(sensor_interval)
smarthome.monitor_connection(self)
def run(self):
self.alive = True
- self._sh.scheduler.add('ow.bus', self._busmaster_discovery, prio=5, cycle=600)
- self._sh.scheduler.add('ow', self._sensor_cycle, cycle=300, prio=5)
+ self._sh.scheduler.add('ow.bus', self._busmaster_discovery, prio=5, cycle=self._bus_interval)
+ self._sh.scheduler.add('ow', self._sensor_cycle, cycle=self._sensor_interval, prio=5)
if self._ibutton_masters != {}:
self._ibutton_loop()
@@ -235,11 +245,14 @@ class OneWire(Owconnection):
value = self.read(path)
except Exception, e:
logger.debug("Could not read {0} ({1}). Exception e: {2}".format(item, sensor, e))
- continue
+ if self.is_connected:
+ continue
+ else:
+ break
if type(value) != float:
logger.warning("OneWire: value {0} for {1} is not a float.".format(repr(value), path))
continue
- if typ == 'temperature':
+ if typ.startswith('temperature'):
value = round(value, 1)
elif typ == 'humidity':
value = round(value)
- Falls in _request() keine Daten vom Socket empfangen werden: Verbindung schließen, Lock freigeben und Exception werfen
- bus_interval und sensor_interval sind in plugin.conf konfigurierbar. Default-Werte wie bisher.
- Wird bei der Abfrage der Sensoren eine Exception geworfen und ist die Verbindung nicht mehr vorhanden -> Schleife abbrechen
- Alle Temperaturen auf eine Nachkommastelle runden
Marcus, vielen Dank nochmals für die Entwicklung von SmartHome.py - wenngleich mein Start etwas holprig war, macht es dennoch großen Spaß! Und nun bin ich auf die Kommentare gespannt...
Viele Grüße,
Alex
Aber dazu erst im nächsten Jahr...
Kommentar