[gelöst] VCONTROL300 und Waiting for sync byte...

[andies]

Guten Morgen,

ich habe seit einem Tag VCONTROL laufen und wollte nun parallel VCONTROL300 anschließen. Beide greifen auf einen RPi zurück, der seine Daten aus der seriellen Schnittstelle via ser2net sendet. VCONTROL läuft, VCONTROL300 gibt eine Fehlermeldung und hat keine Daten. Vielleicht hat jemand eine Idee?

Hier die Definition

Code Auswählen Erweitern

Internals:
   CFGFN
   DEF        192.168.2.105:3002 /opt/fhem/FHEM/VScotHO1_300.cfg 300 kw
   DeviceName 192.168.2.105:3002
   INTERVAL   300
   NAME       Viessmann2
   NR         143
   PROTOCOL   kw
   STATE      defined
   TYPE       VCONTROL300
   UPDATESTATUS INACTIVE
   READINGS:
     2017-09-27 09:46:43   UpdateStatus    Inactive
   helper:
Attributes:
   group      Info
   room       Info
   verbose    0
   vitotronicType 200_HOxx
und hier der Fehler

Code Auswählen Erweitern

2017.09.27 08:56:33 3: Opening Viessmann2 device 192.168.2.105:3002
2017.09.27 08:56:33 3: Viessmann2 device opened
2017.09.27 08:56:33 4: VCONTROL300: Start of update...
2017.09.27 08:56:33 4: VCONTROL300: Start of polling values...
2017.09.27 08:56:33 4: VCONTROL300: Waiting for sync byte...
2017.09.27 08:56:34 4: VCONTROL300: Waiting for sync byte...
2017.09.27 08:56:34 2: Viessmann2: first attempt to read timed out, trying to close and open the device.
2017.09.27 08:56:34 3: Opening Viessmann2 device 192.168.2.105:3002
2017.09.27 08:56:34 3: Viessmann2 device opened
2017.09.27 08:56:35 4: VCONTROL300: Waiting for sync byte...
2017.09.27 08:56:35 2: Viessmann2: first attempt to read timed out, trying to close and open the device.
2017.09.27 08:56:35 3: Opening Viessmann2 device 192.168.2.105:3002
2017.09.27 08:56:35 3: Viessmann2 device opened
2017.09.27 08:56:36 4: VCONTROL300: Waiting for sync byte...
2017.09.27 08:56:36 2: Viessmann2: first attempt to read timed out, trying to close and open the device.
2017.09.27 08:56:36 3: Opening Viessmann2 device 192.168.2.105:3002
2017.09.27 08:56:36 3: Viessmann2 device opened
2017.09.27 08:56:37 4: VCONTROL300: Waiting for sync byte...
2017.09.27 08:56:37 2: Viessmann2: first attempt to read timed out, trying to close and open the device.
2017.09.27 08:56:37 3: Opening Viessmann2 device 192.168.2.105:3002
2017.09.27 08:56:37 3: Viessmann2 device opened
2017.09.27 08:56:38 4: VCONTROL300: Waiting for sync byte...
2017.09.27 08:56:38 2: Viessmann2: first attempt to read timed out, trying to close and open the device.
2017.09.27 08:56:38 3: Opening Viessmann2 device 192.168.2.105:3002
2017.09.27 08:56:38 3: Viessmann2 device opened
2017.09.27 08:56:39 4: VCONTROL300: Waiting for sync byte...
2017.09.27 08:56:39 2: Viessmann2: first attempt to read timed out, trying to close and open the device.
2017.09.27 08:56:39 3: Opening Viessmann2 device 192.168.2.105:3002
2017.09.27 08:56:39 3: Viessmann2 device opened
2017.09.27 08:56:40 4: VCONTROL300: Waiting for sync byte...
2017.09.27 08:56:40 2: Viessmann2: first attempt to read timed out, trying to close and open the device.
2017.09.27 08:56:40 3: Opening Viessmann2 device 192.168.2.105:3002
2017.09.27 08:56:40 3: Viessmann2 device opened
2017.09.27 08:56:41 4: VCONTROL300: Waiting for sync byte...
2017.09.27 08:56:41 2: Viessmann2: first attempt to read timed out, trying to close and open the device.
2017.09.27 08:56:41 3: Opening Viessmann2 device 192.168.2.105:3002
2017.09.27 08:56:41 3: Viessmann2 device opened
2017.09.27 08:56:42 4: VCONTROL300: Waiting for sync byte...
2017.09.27 08:56:42 2: Viessmann2: first attempt to read timed out, trying to close and open the device.
2017.09.27 08:56:42 3: Opening Viessmann2 device 192.168.2.105:3002
2017.09.27 08:56:42 3: Viessmann2 device opened
2017.09.27 08:56:43 1: Timeout for VCONTROL300_DoUpdate reached, terminated process 26383
2017.09.27 08:56:43 4: VCONTROL300: Update aborted!
2017.09.27 08:56:43 2: VCONTROL300: TCP connection closed
2017.09.27 09:01:33 3: VCONTROL300: TCP connection opened
2017.09.27 09:01:33 3: Opening Viessmann2 device 192.168.2.105:3002
2017.09.27 09:01:33 3: Viessmann2 device opened
2017.09.27 09:01:33 4: VCONTROL300: Start of update...
2017.09.27 09:01:33 4: VCONTROL300: Start of polling values...
2017.09.27 09:01:33 4: VCONTROL300: Waiting for sync byte...
2017.09.27 09:01:34 4: VCONTROL300: Waiting for sync byte...
2017.09.27 09:01:34 2: Viessmann2: first attempt to read timed out, trying to close and open the device.
2017.09.27 09:01:34 3: Opening Viessmann2 device 192.168.2.105:3002
2017.09.27 09:01:34 3: Viessmann2 device opened
2017.09.27 09:01:35 4: VCONTROL300: Waiting for sync byte...
2017.09.27 09:01:35 2: Viessmann2: first attempt to read timed out, trying to close and open the device.
2017.09.27 09:01:35 3: Opening Viessmann2 device 192.168.2.105:3002
2017.09.27 09:01:35 3: Viessmann2 device opened
2017.09.27 09:01:36 4: VCONTROL300: Waiting for sync byte...
2017.09.27 09:01:36 2: Viessmann2: first attempt to read timed out, trying to close and open the device.
2017.09.27 09:01:36 3: Opening Viessmann2 device 192.168.2.105:3002
2017.09.27 09:01:36 3: Viessmann2 device opened
2017.09.27 09:01:37 4: VCONTROL300: Waiting for sync byte...
2017.09.27 09:01:37 2: Viessmann2: first attempt to read timed out, trying to close and open the device.
2017.09.27 09:01:37 3: Opening Viessmann2 device 192.168.2.105:3002
2017.09.27 09:01:37 3: Viessmann2 device opened
2017.09.27 09:01:38 4: VCONTROL300: Waiting for sync byte...
2017.09.27 09:01:38 2: Viessmann2: first attempt to read timed out, trying to close and open the device.
2017.09.27 09:01:38 3: Opening Viessmann2 device 192.168.2.105:3002
2017.09.27 09:01:38 3: Viessmann2 device opened
2017.09.27 09:01:39 4: VCONTROL300: Waiting for sync byte...
2017.09.27 09:01:39 2: Viessmann2: first attempt to read timed out, trying to close and open the device.
2017.09.27 09:01:39 3: Opening Viessmann2 device 192.168.2.105:3002
2017.09.27 09:01:39 3: Viessmann2 device opened
2017.09.27 09:01:40 4: VCONTROL300: Waiting for sync byte...
2017.09.27 09:01:40 2: Viessmann2: first attempt to read timed out, trying to close and open the device.
2017.09.27 09:01:40 3: Opening Viessmann2 device 192.168.2.105:3002
2017.09.27 09:01:40 3: Viessmann2 device opened
2017.09.27 09:01:41 4: VCONTROL300: Waiting for sync byte...
2017.09.27 09:01:41 2: Viessmann2: first attempt to read timed out, trying to close and open the device.
2017.09.27 09:01:41 3: Opening Viessmann2 device 192.168.2.105:3002
2017.09.27 09:01:41 3: Viessmann2 device opened
2017.09.27 09:01:42 4: VCONTROL300: Waiting for sync byte...
2017.09.27 09:01:42 2: Viessmann2: first attempt to read timed out, trying to close and open the device.
2017.09.27 09:01:42 3: Opening Viessmann2 device 192.168.2.105:3002
2017.09.27 09:01:42 3: Viessmann2 device opened
2017.09.27 09:01:43 1: Timeout for VCONTROL300_DoUpdate reached, terminated process 26505
2017.09.27 09:01:43 4: VCONTROL300: Update aborted!
2017.09.27 09:01:43 2: VCONTROL300: TCP connection closed
2017.09.27 09:06:33 3: VCONTROL300: TCP connection opened
2017.09.27 09:06:33 3: Opening Viessmann2 device 192.168.2.105:3002
2017.09.27 09:06:33 3: Viessmann2 device opened
2017.09.27 09:06:33 4: VCONTROL300: Start of update...
2017.09.27 09:06:33 4: VCONTROL300: Start of polling values...
2017.09.27 09:06:33 4: VCONTROL300: Waiting for sync byte...
2017.09.27 09:06:34 4: VCONTROL300: Waiting for sync byte...
2017.09.27 09:06:34 2: Viessmann2: first attempt to read timed out, trying to close and open the device.
2017.09.27 09:06:34 3: Opening Viessmann2 device 192.168.2.105:3002
2017.09.27 09:06:34 3: Viessmann2 device opened
2017.09.27 09:06:35 4: VCONTROL300: Waiting for sync byte...
2017.09.27 09:06:35 2: Viessmann2: first attempt to read timed out, trying to close and open the device.
2017.09.27 09:06:35 3: Opening Viessmann2 device 192.168.2.105:3002
2017.09.27 09:06:35 3: Viessmann2 device opened
2017.09.27 09:06:36 4: VCONTROL300: Waiting for sync byte...
2017.09.27 09:06:36 2: Viessmann2: first attempt to read timed out, trying to close and open the device.
2017.09.27 09:06:36 3: Opening Viessmann2 device 192.168.2.105:3002
2017.09.27 09:06:36 3: Viessmann2 device opened
2017.09.27 09:06:37 4: VCONTROL300: Waiting for sync byte...
2017.09.27 09:06:37 2: Viessmann2: first attempt to read timed out, trying to close and open the device.
2017.09.27 09:06:37 3: Opening Viessmann2 device 192.168.2.105:3002
2017.09.27 09:06:37 3: Viessmann2 device opened
2017.09.27 09:06:38 4: VCONTROL300: Waiting for sync byte...
2017.09.27 09:06:38 2: Viessmann2: first attempt to read timed out, trying to close and open the device.
2017.09.27 09:06:38 3: Opening Viessmann2 device 192.168.2.105:3002
2017.09.27 09:06:38 3: Viessmann2 device opened
2017.09.27 09:06:39 4: VCONTROL300: Waiting for sync byte...
2017.09.27 09:06:39 2: Viessmann2: first attempt to read timed out, trying to close and open the device.
2017.09.27 09:06:39 3: Opening Viessmann2 device 192.168.2.105:3002
2017.09.27 09:06:39 3: Viessmann2 device opened
2017.09.27 09:06:40 4: VCONTROL300: Waiting for sync byte...
2017.09.27 09:06:40 2: Viessmann2: first attempt to read timed out, trying to close and open the device.
2017.09.27 09:06:40 3: Opening Viessmann2 device 192.168.2.105:3002
2017.09.27 09:06:40 3: Viessmann2 device opened
2017.09.27 09:06:41 4: VCONTROL300: Waiting for sync byte...
2017.09.27 09:06:41 2: Viessmann2: first attempt to read timed out, trying to close and open the device.
2017.09.27 09:06:41 3: Opening Viessmann2 device 192.168.2.105:3002
2017.09.27 09:06:41 3: Viessmann2 device opened
2017.09.27 09:06:42 4: VCONTROL300: Waiting for sync byte...
2017.09.27 09:06:42 2: Viessmann2: first attempt to read timed out, trying to close and open the device.
2017.09.27 09:06:42 3: Opening Viessmann2 device 192.168.2.105:3002
2017.09.27 09:06:42 3: Viessmann2 device opened
2017.09.27 09:06:43 1: Timeout for VCONTROL300_DoUpdate reached, terminated process 26557
2017.09.27 09:06:43 4: VCONTROL300: Update aborted!
2017.09.27 09:06:43 2: VCONTROL300: TCP connection closed
2017.09.27 09:11:43 1: Timeout for VCONTROL300_DoUpdate reached, terminated process 26709
2017.09.27 09:16:43 1: Timeout for VCONTROL300_DoUpdate reached, terminated process 26815
2017.09.27 09:21:43 1: Timeout for VCONTROL300_DoUpdate reached, terminated process 26918
2017.09.27 09:26:43 1: Timeout for VCONTROL300_DoUpdate reached, terminated process 27001
2017.09.27 09:31:43 1: Timeout for VCONTROL300_DoUpdate reached, terminated process 27057
2017.09.27 09:36:43 1: Timeout for VCONTROL300_DoUpdate reached, terminated process 27142
2017.09.27 09:41:43 1: Timeout for VCONTROL300_DoUpdate reached, terminated process 27231
2017.09.27 09:46:43 1: Timeout for VCONTROL300_DoUpdate reached, terminated process 27283

Kann es sein, dass nicht beide auf die Schnittstelle zugreifen können?

[andies]

Die Abschaltung des anderen Gerätes bringt nichts. Es bringt auch nichts, wenn (fast) alle Poll-Commands ausgeblendet werden - ich hatte zuerst gedacht, dass falsche Adressen den Fehler verursachen. Danach habe ich weiterhin

Code Auswählen Erweitern

2017.09.28 08:08:37 3: VCONTROL300: File '/opt/fhem/FHEM/VScotHO1_300.cfg' refreshed
2017.09.28 08:08:47 1: Timeout for VCONTROL300_DoUpdate reached, terminated process 19033

[andies]

Verbose 5 liefert

Code Auswählen Erweitern

2017.09.28 09:16:35 5: VCONTROL300: Set InternalTimer to 1506583295.07241
2017.09.28 09:16:35 3: VCONTROL300: TCP connection opened
2017.09.28 09:16:35 3: Opening Viessmann2 device 192.168.2.105:3002
2017.09.28 09:16:35 3: Viessmann2 device opened
2017.09.28 09:16:35 4: VCONTROL300: Start of update...
2017.09.28 09:16:35 4: VCONTROL300: Start of polling values...
2017.09.28 09:16:35 4: VCONTROL300: Waiting for sync byte...
2017.09.28 09:16:36 4: VCONTROL300: Waiting for sync byte...
2017.09.28 09:16:36 2: Viessmann2: first attempt to read timed out, trying to close and open the device.
2017.09.28 09:16:36 3: Opening Viessmann2 device 192.168.2.105:3002
2017.09.28 09:16:36 3: Viessmann2 device opened
2017.09.28 09:16:37 4: VCONTROL300: Waiting for sync byte...
2017.09.28 09:16:37 2: Viessmann2: first attempt to read timed out, trying to close and open the device.
2017.09.28 09:16:37 3: Opening Viessmann2 device 192.168.2.105:3002
2017.09.28 09:16:37 3: Viessmann2 device opened
2017.09.28 09:16:38 4: VCONTROL300: Waiting for sync byte...
2017.09.28 09:16:38 2: Viessmann2: first attempt to read timed out, trying to close and open the device.
2017.09.28 09:16:38 3: Opening Viessmann2 device 192.168.2.105:3002
2017.09.28 09:16:38 3: Viessmann2 device opened
2017.09.28 09:16:39 4: VCONTROL300: Waiting for sync byte...
2017.09.28 09:16:39 5: SW: 04
2017.09.28 09:16:39 2: Viessmann2: first attempt to read timed out, trying to close and open the device.
2017.09.28 09:16:39 3: Opening Viessmann2 device 192.168.2.105:3002
2017.09.28 09:16:39 3: Viessmann2 device opened
2017.09.28 09:16:40 4: VCONTROL300: Waiting for sync byte...
2017.09.28 09:16:40 2: Viessmann2: first attempt to read timed out, trying to close and open the device.
2017.09.28 09:16:40 3: Opening Viessmann2 device 192.168.2.105:3002
2017.09.28 09:16:40 3: Viessmann2 device opened
2017.09.28 09:16:41 4: VCONTROL300: Waiting for sync byte...
2017.09.28 09:16:41 2: Viessmann2: first attempt to read timed out, trying to close and open the device.
2017.09.28 09:16:41 3: Opening Viessmann2 device 192.168.2.105:3002
2017.09.28 09:16:41 3: Viessmann2 device opened
2017.09.28 09:16:42 4: VCONTROL300: Waiting for sync byte...
2017.09.28 09:16:42 2: Viessmann2: first attempt to read timed out, trying to close and open the device.
2017.09.28 09:16:42 3: Opening Viessmann2 device 192.168.2.105:3002
2017.09.28 09:16:42 3: Viessmann2 device opened
2017.09.28 09:16:43 4: VCONTROL300: Waiting for sync byte...
2017.09.28 09:16:43 2: Viessmann2: first attempt to read timed out, trying to close and open the device.
2017.09.28 09:16:43 3: Opening Viessmann2 device 192.168.2.105:3002
2017.09.28 09:16:43 3: Viessmann2 device opened
2017.09.28 09:16:44 4: VCONTROL300: Waiting for sync byte...
2017.09.28 09:16:44 2: Viessmann2: first attempt to read timed out, trying to close and open the device.
2017.09.28 09:16:44 3: Opening Viessmann2 device 192.168.2.105:3002
2017.09.28 09:16:44 3: Viessmann2 device opened
2017.09.28 09:16:45 1: Timeout for VCONTROL300_DoUpdate reached, terminated process 21024
2017.09.28 09:16:45 4: VCONTROL300: Update aborted!
2017.09.28 09:16:45 2: VCONTROL300: TCP connection closed
2017.09.28 09:16:45 5: VCONTROL300: Undef set_cmd_list_values!

Wenn ich das richtig lese, kommt er auf das Gerät, wartet auf ein Byte - und das kommt nicht und deshalb bricht er ab. Also ist das Protokoll falsch? Denn das Sync-Byte dürfte da festgelegt werden, oder?

Im Quelltext findet sich folgendes

Code Auswählen Erweitern

Log3 $name, 4,"VCONTROL300: Received sync byte!";

und das habe ich nicht. Aber wieso kann dann das Gerät Viessmann zugreifen und wieso kann ich Werte auslesen?!

[andies]

Ich habe mir jetzt die folgende Stelle im Code genauer angeschaut (Zeile 1170, um ein paar Logs erweitert)

Code Auswählen Erweitern

sub VCONTROL300_ExpectFromDevice($$$) {
my ($hash,$sendbuf,$timeout) = @_;
Log3 "Viessmann2", 5, "VCONTROL300: hash $hash"; ##DEBUG
Log3 "Viessmann2", 5, "VCONTROL300: sendbuf $sendbuf";
Log3 "Viessmann2", 5, "VCONTROL300: timeout $timeout";
my $buf = DevIo_Expect($hash,$sendbuf,$timeout);
Log3 "Viessmann2", 5, "VCONTROL300: DevIo_Expect $buf";

return $buf;
}


und ich erhalte da im Log folgende Einträge

Code Auswählen Erweitern

2017.09.28 13:07:10 4: VCONTROL300: Waiting for sync byte...
2017.09.28 13:07:10 5: VCONTROL300: hash HASH(0x39863e8)
2017.09.28 13:07:10 5: VCONTROL300: sendbuf 
2017.09.28 13:07:10 5: VCONTROL300: timeout 10
2017.09.28 13:07:10 5: SW: 04
2017.09.28 13:07:10 2: Viessmann2: first attempt to read timed out, trying to close and open the device.
2017.09.28 13:07:10 3: Opening Viessmann2 device 192.168.2.105:3002
2017.09.28 13:07:10 3: Viessmann2 device opened
2017.09.28 13:07:10 5: SW: 04
2017.09.28 13:07:10 5: VCONTROL300: DevIo_Expect Port already in use

Hmm. Das heißt doch, dass der Port belegt ist. Oder? Ich dachte, man kann da mehrfach drauf zugreifen? Ist das ein ser2net-Problem? Aber wieso ist sendbuf leer?

[andies]

Das war es. Ich stelle das mal mit meinen Laienprogrammkenntnissen dar.

Wenn man zwei Geräte hat, die gleichzeitig auf 3002 zugreifen, kommen die sich anscheinend in die Quere. Ich habe auch nicht darauf geachtet, wie lange beide Geräte auf die Ports zugreifen (dürfen). Nachdem ich das erste Gerät entfernt habe und den RPi neu gestartet habe, läuft alles. Ich entferne jetzt das erste Gerät und arbeite nur mit VCONTROL300.pm.