reading XXX did not return a value

tca · 13 März 2019, 18:03:20

Hallo,

ich habe meine FHEM Installation vor wenigen Tagen leider neu aufsetzen müssen. Die fhem.cfg hatte ich noch, der 1-Wire-Server (owserver) läuft auf einem anderen Host und ist unverändert. Ich dachte (hoffte), dass 'nur' die fehlenden Pakete mit apt-get zu installieren sind.

Jetzt wird aber kontinuierlich von jedem owdevice die Meldung "reading XXX did not return a value" in das LOG geschrieben, Beispiel:

Code Auswählen


019.03.12 22:39:21 3: Water_Alarm_A: reading sensed.A did not return a value
2019.03.12 22:39:21 3: Water_Alarm_A: reading sensed.B did not return a value
2019.03.12 22:39:21 3: WW_Aufbereitung: reading temperature did not return a value
2019.03.12 22:40:21 3: Opening heating_meter device heatmeter.caktas.local:5003
2019.03.12 22:40:21 1: heating_meter: Can't connect to heatmeter.caktas.local:5003: Invalid argument
2019.03.12 22:41:11 3: WW_Zirkulation_AUF: reading temperature did not return a value
2019.03.12 22:41:21 3: pressure: reading VAD did not return a value
2019.03.12 22:41:21 3: pressure: reading VDD did not return a value
2019.03.12 22:41:21 3: pressure: reading temperature did not return a value
2019.03.12 22:41:21 3: VL_Wohnung: reading temperature did not return a value
2019.03.12 22:41:21 3: Water_Alarm_B: reading sensed.A did not return a value
2019.03.12 22:41:21 3: Water_Alarm_B: reading sensed.B did not return a value
2019.03.12 22:41:21 3: WW_Zirkulation_AB: reading temperature did not return a value
2019.03.12 22:41:21 3: KS_Kessel: reading temperature did not return a value
2019.03.12 22:41:21 3: RL_Wohnung: reading temperature did not return a value
2019.03.12 22:41:21 3: Water_Alarm_A: reading sensed.A did not return a value
2019.03.12 22:41:21 3: Water_Alarm_A: reading sensed.B did not return a value
2019.03.12 22:41:21 3: WW_Aufbereitung: reading temperature did not return a value
2019.03.12 22:43:11 3: WW_Zirkulation_AUF: reading temperature did not return a value
2019.03.12 22:43:21 3: pressure: reading VAD did not return a value
2019.03.12 22:43:21 3: pressure: reading VDD did not return a value
2019.03.12 22:43:21 3: pressure: reading temperature did not return a value
2019.03.12 22:43:21 3: VL_Wohnung: reading temperature did not return a value
2019.03.12 22:43:21 3: Water_Alarm_B: reading sensed.A did not return a value
2019.03.12 22:43:21 3: Water_Alarm_B: reading sensed.B did not return a value
2019.03.12 22:43:21 3: WW_Zirkulation_AB: reading temperature did not return a value
2019.03.12 22:43:21 3: KS_Kessel: reading temperature did not return a value
2019.03.12 22:43:21 3: RL_Wohnung: reading temperature did not return a value
2019.03.12 22:43:21 3: Water_Alarm_A: reading sensed.A did not return a value
2019.03.12 22:43:21 3: Water_Alarm_A: reading sensed.B did not return a value
2019.03.12 22:43:21 3: WW_Aufbereitung: reading temperature did not return a value
2019.03.12 22:43:59 3: CCU2_outside: Read callback: Error: gethostbyname ccu2.caktas.local failed
2019.03.12 22:45:11 3: WW_Zirkulation_AUF: reading temperature did not return a value
2019.03.12 22:45:21 3: pressure: reading VAD did not return a value
2019.03.12 22:45:21 3: pressure: reading VDD did not return a value
2019.03.12 22:45:21 3: pressure: reading temperature did not return a value
2019.03.12 22:45:21 3: VL_Wohnung: reading temperature did not return a value
2019.03.12 22:45:21 3: Water_Alarm_B: reading sensed.A did not return a value
2019.03.12 22:45:21 3: Water_Alarm_B: reading sensed.B did not return a value
2019.03.12 22:45:21 3: WW_Zirkulation_AB: reading temperature did not return a value
2019.03.12 22:45:21 3: KS_Kessel: reading temperature did not return a value
2019.03.12 22:45:21 3: RL_Wohnung: reading temperature did not return a value
2019.03.12 22:45:21 3: Water_Alarm_A: reading sensed.A did not return a value
2019.03.12 22:45:21 3: Water_Alarm_A: reading sensed.B did not return a value
2019.03.12 22:45:21 3: WW_Aufbereitung: reading temperature did not return a value
2019.03.12 22:45:21 3: Opening heating_meter device heatmeter.caktas.local:5003
2019.03.12 22:45:21 1: heating_meter: Can't connect to heatmeter.caktas.local:5003: Invalid argument
2019.03.12 22:47:11 3: WW_Zirkulation_AUF: reading temperature did not return a value
2019.03.12 22:47:21 3: pressure: reading VAD did not return a value
2019.03.12 22:47:21 3: pressure: reading VDD did not return a value
2019.03.12 22:47:21 3: pressure: reading temperature did not return a value
2019.03.12 22:47:21 3: VL_Wohnung: reading temperature did not return a value
2019.03.12 22:47:21 3: Water_Alarm_B: reading sensed.A did not return a value
2019.03.12 22:47:21 3: Water_Alarm_B: reading sensed.B did not return a value
2019.03.12 22:47:21 3: WW_Zirkulation_AB: reading temperature did not return a value
2019.03.12 22:47:21 3: KS_Kessel: reading temperature did not return a value
2019.03.12 22:47:21 3: RL_Wohnung: reading temperature did not return a value
2019.03.12 22:47:21 3: Water_Alarm_A: reading sensed.A did not return a value
2019.03.12 22:47:21 3: Water_Alarm_A: reading sensed.B did not return a value
2019.03.12 22:47:21 3: WW_Aufbereitung: reading temperature did not return a value
2019.03.12 22:49:09 3: UG_Bistro_Fenster: reading temperature did not return a value
2019.03.12 22:49:10 3: 4OG_Decke: reading temperature did not return a value
2019.03.12 22:49:11 3: WW_Zirkulation_AUF: reading temperature did not return a value
2019.03.12 22:49:21 3: pressure: reading VAD did not return a value
2019.03.12 22:49:21 3: pressure: reading VDD did not return a value
2019.03.12 22:49:21 3: pressure: reading temperature did not return a value
2019.03.12 22:49:21 2: DbLog DB_Heizung - DBI connect('database=fhem;host=192.168.0.6;port=3306','fhemuser',...) failed: Can't connect to MySQL server on '192.168.0.6' (101 "Network is unreachable") at /opt/fhem/FHEM/93_DbLog.pm line 2467.

2019.03.12 22:49:21 3: VL_Wohnung: reading temperature did not return a value
2019.03.12 22:49:21 3: Water_Alarm_B: reading sensed.A did not return a value
2019.03.12 22:49:21 3: Water_Alarm_B: reading sensed.B did not return a value
2019.03.12 22:49:21 3: WW_Zirkulation_AB: reading temperature did not return a value
2019.03.12 22:49:21 3: KS_Kessel: reading temperature did not return a value
2019.03.12 22:49:21 3: RL_Wohnung: reading temperature did not return a value
2019.03.12 22:49:21 3: Water_Alarm_A: reading sensed.A did not return a value
2019.03.12 22:49:21 3: Water_Alarm_A: reading sensed.B did not return a value
2019.03.12 22:49:21 3: WW_Aufbereitung: reading temperature did not return a value
2019.03.12 22:50:21 3: Opening heating_meter device heatmeter.caktas.local:5003
2019.03.12 22:50:21 1: heating_meter: Can't connect to heatmeter.caktas.local:5003: Invalid argument
2019.03.12 22:51:11 3: WW_Zirkulation_AUF: reading temperature did not return a value

Hier der OWServer

Code Auswählen

Internals:
   DEF        192.168.0.6:4304 2.8p20
   FUUID      5c452ad8-f33f-b27c-a069-f5ebe69a6b060568
   LAST_READ_FAILED 0
   NAME       ApollonOW
   NOTIFYDEV  global
   NR         77
   NTFY_ORDER 50a-ApollonOW
   OWNET_VERSION 2.8p20
   STATE      Initialized
   TYPE       OWServer
   READINGS:
     2019-03-13 17:21:48   /settings/timeout/directory           60
     2019-03-13 17:21:48   /settings/timeout/ftp          900
     2019-03-13 17:21:48   /settings/timeout/ha7           60
     2019-03-13 17:21:48   /settings/timeout/network            1
     2019-03-13 17:21:48   /settings/timeout/presence          120
     2019-03-13 17:21:48   /settings/timeout/serial            5
     2019-03-13 17:21:48   /settings/timeout/server           10
     2019-03-13 17:21:48   /settings/timeout/stable          300
     2019-03-13 17:21:48   /settings/timeout/uncached 0
     2019-03-13 17:21:48   /settings/timeout/usb            5
     2019-03-13 17:21:48   /settings/timeout/volatile           15
     2019-03-13 17:21:48   /settings/timeout/w1           30
     2019-03-13 17:21:48   /settings/units/pressure_scale mbar
     2019-03-13 17:21:48   /settings/units/temperature_scale C
     2019-03-13 17:21:48   state           Initialized
   fhem:
     protocol   192.168.0.6:4304
Attributes:
   group      Steuerung
   icon       it_nas
   nonblocking 1
   room       -1UG,OneWire

Der Aufruf

Code Auswählen

get ApollonOW devices bringt nur ein leeres Fenster.

- OWNet.pm ist mit verschiedenen Versionen installiert.
- Der 1-Wire-Server (owserver, V2.8p20) liegt auf dem Host 192.168.0.6, so wie z.B. auch die Maria-DB.
- Der Zugriff vom Terminal auf diesen oder auch andere Hosts klappt. Andere Netzwerkgeräte, wie 2*CUNO (WMBUS), funktionieren.
Es scheint, als ob FHEM (OWServer??) bestimmte Netzwerkzugriffe blockiert oder bis zum Time-out verlangsamt.

Hat jemand eine Idee?

tca · 14 März 2019, 01:12:04

... habe einen kleinen Test für OWNet.pm geschrieben:

Code Auswählen


# Create owserver object                                                                                                        
my $owserver = OWNet->new("192.168.0.6:4304 -v -C") ; #default location, verbose errors, Celsius degrees                        
print $owserver->dir("/") ;

... gibt alle 1-Wire devices aus

Es scheint evtl. an 10_OWServer.pm zu liegen?
Hat jemand einen Tipp?

eldrik · 14 März 2019, 14:33:03

Zitat von: tca am 14 März 2019, 01:12:04
... habe einen kleinen Test für OWNet.pm geschrieben:

Code Auswählen Erweitern
# Create owserver object my $owserver = OWNet->new("192.168.0.6:4304 -v -C") ; #default location, verbose errors, Celsius degrees print $owserver->dir("/") ;

... gibt alle 1-Wire devices aus

Es scheint evtl. an 10_OWServer.pm zu liegen?
Hat jemand einen Tipp?

Von wo erfolgte dieser Test? Vom Server auf dem der owserver läuft oder vom FHEM Server?

Nach der folgenden Meldung hast du auch Probleme mit deiner MariaDB so dass dein FHEM Host irgendwelche Netzprobleme zu haben scheint.

Code Auswählen

 DbLog DB_Heizung - DBI connect('database=fhem;host=192.168.0.6;port=3306','fhemuser',...) failed: Can't connect to MySQL server on '192.168.0.6' (101 "Network is unreachable") at /opt/fhem/FHEM/93_DbLog.pm line 2467.

Wie sieht denn deine Netzinfrastruktur aus?

Hat der FHEM Server mehrere Netzwerkinterfaces?

Ist das Routing korrekt wenn unterschiedliche Netze verwendet werden?

Hat der FHEM Server auch wieder dieselbe IP wie vorher bekommen?

Ist der FHEM Server ggfs. virtuell und noch nicht wieder vollständig Netzwerktechnisch angebunden?

Ist auf dem FHEM Server noch eine lokale Firewall aktiv?

Ist auf dem OWServer eine lokale Firewall aktiv?

Greetz
Eldrik

tca · 15 März 2019, 16:44:18

Hallo eldrik, Danke für die Liste

ZitatVon wo erfolgte dieser Test? Vom Server auf dem der owserver läuft oder vom FHEM Server?

Der Test läuft auf dem FHEM-Server.

Das Kommunikationsmodell sollte ungefähr so aussehen: 11_OWDevice.pm [local] <-> 10_OWServer.pm [local] <-> OWNet.pm [local] <-> owserver [remote]
Der Test hat diese Verbindung: test.pl [local] <-> OWNet.pm [local] <-> owserver [remote]

Ich habe auch mal ein "sleep(130)" zwischen Verbindung-Aufbau und Abfrage eingebaut (s.u. wg. Timeout), aber auch das hat geklappt.

Zitat
Nach der folgenden Meldung hast du auch Probleme mit deiner MariaDB so dass dein FHEM Host irgendwelche Netzprobleme zu haben scheint.
...
Wie sieht denn deine Netzinfrastruktur aus?
Hat der FHEM Server mehrere Netzwerkinterfaces?
Ist das Routing korrekt wenn unterschiedliche Netze verwendet werden?
Hat der FHEM Server auch wieder dieselbe IP wie vorher bekommen?
Ist der FHEM Server ggfs. virtuell und noch nicht wieder vollständig Netzwerktechnisch angebunden?
Ist auf dem FHEM Server noch eine lokale Firewall aktiv?
Ist auf dem OWServer eine lokale Firewall aktiv?

FHEM läuft als Docker Container mit gleichen Einstellungen wie zuvor, d.h. 1 Netzwerkkarte, gleiche IP. Firewalls sind nicht installiert.
Der FHEM Server kann das Intra- und Extranet voll erreichen und ist umgekehrt aus dem Intranet erreichbar.

Ja, owserver und Maria-DB sind auf dem gleichen (remote)Host, aber an dem Host wurde nichts verändert.

Es sieht für mich ehr nach einem Timeout aus. Die Meldungen von ~~10_OWServer.pm~~ 11_OWDevice.pm kommen nach immer genau 120 Sekunden. Die Abfrage von einzelnen OW-Devices klappt. Die Meldungen der MariaDB-Verbindung scheinen mir auch Timeouts zu sein, aber in einem anderen Takt.

Ich habe auch zwei CUNOs für WMBus Daten (per Netzwerk) verbunden - da läuft gut Traffic und es kommt zu keinem Fehler.
Ich dachte mehr in die Richtung "IO::Socket::Timeout", habe aber in 10_OWServer.pm bzw. 11_OWDevice.pm nichts gefunden.

tca · 17 März 2019, 19:48:26

Lösung nach vielen Stunden gefunden. Ich kann mir keinen Reim darauf machen, aber vielleicht ist es für jemanden von Nutzen:

Ausgangssituation: FHEM läuft als Docker, d.h. FHEM ist persistent ausserhalb des Containers. Sollte der Container abstürzen (leider passiert) bleibt alles unterhalb der Verzeichnisebene /fhem erhalten. Der Container wird neu aufgebaut, fehlende Pakete, soweit sie separat installiert wurden (sollte man nicht machen, passiert aber), werden nach-installiert (apt-get install ..., cpan -i ...). Container neu starten, alles sollte wieder funktionieren - soweit die Theorie.

Fehler: reading XXX did not return a value (1-wire)

Lösung (hier): Datei OWNet-2.8p20.pm im Verzeichnis fhem/FHEM/lib nach OWNet-3.1p5.pm kopieren/überschreiben/umbenennen.

Ich kann nur vermuten, dass OWserver, obwohl die richtige owserver Version (auf remote host V2.8p20) erkannt wird, scheinbar nicht das entsprechende lokale Modul nimmt sonder das default OWNet-3.1p5.pm.
Alle anderen Fehlermeldungen erscheinen auch nicht mehr.

Dr. Boris Neubert · 23 März 2019, 20:24:48

Eine Lösung, aber eine schaurige...

Wenn Du den OWServer mit verbose 5 startest, kommt eine Menge Gespräch im Log zum Thema, welche OWNet-Version er sucht usw. Vielleicht hilft Dir das, die eigentliche Ursache des Problems zu finden.

FHEM Forum

reading XXX did not return a value

tca

tca

eldrik

tca

tca

Dr. Boris Neubert