vcontrol_test.py - FRAMER: could not close (3 attempts)

[tclas]

Hello,
thank you for your excellent work in this project. It led to an important progress communitcating with my heating system. While experimenting with the example scripts I noticed, that it seemed to fail communicating in raw-mode with vcontrold. The message was

Traceback (most recent call last): File "vcontrold_test.py", line 125, in <module> out = bytes.fromhex(out) ValueError: non-hexadecimal number found in fromhex() arg at position 1

The vcontrold.log came up with:
`
[16917] Tue Jan 4 20:48:37 2022 : Child process started with pid 26989
[26989] Tue Jan 4 20:48:37 2022 : Command: raw
[26989] Tue Jan 4 20:48:37 2022 : Raw mode: Temp file: /tmp/vitotmp-7IhCQa
[26989] Tue Jan 4 20:48:37 2022 : Raw: Read: SEND 04

[26989] Tue Jan 4 20:48:37 2022 : Raw: Read: WAIT 05

[26989] Tue Jan 4 20:48:37 2022 : Raw: Read: SEND 16 00 00

[26989] Tue Jan 4 20:48:37 2022 : Raw: Read: WAIT 06

[26989] Tue Jan 4 20:48:37 2022 : Raw: Read: SEND 41 05 00 01 00 F8 08 06

[26989] Tue Jan 4 20:48:37 2022 : Raw: Read: RECV 17

[26989] Tue Jan 4 20:48:37 2022 : Process 26989 tries to aquire lock
[26989] Tue Jan 4 20:48:37 2022 : Process 26989 got lock
[26989] Tue Jan 4 20:48:37 2022 : >FRAMER: open device /dev/vitoir0 ProtocolID 41
[26989] Tue Jan 4 20:48:37 2022 : Configuring serial interface /dev/vitoir0
[26989] Tue Jan 4 20:48:37 2022 : >SENT: 04
[26989] Tue Jan 4 20:48:39 2022 : <RECV: len=1 05 (2040.0 ms)
[26989] Tue Jan 4 20:48:39 2022 : <RECV: received 05
[26989] Tue Jan 4 20:48:39 2022 : >FRAMER: framer_reset_actaddr framer_current_addr = FRAMER_LINK_STATUS(05) (was FFFF)
[26989] Tue Jan 4 20:48:39 2022 : >FRAMER: closed
[26989] Tue Jan 4 20:48:39 2022 : >SENT: 16
[26989] Tue Jan 4 20:48:39 2022 : >SENT: 00
[26989] Tue Jan 4 20:48:39 2022 : >SENT: 00
[26989] Tue Jan 4 20:48:41 2022 : <RECV: len=1 05 (2000.0 ms)
[26989] Tue Jan 4 20:48:41 2022 : <RECV: received 05
[26989] Tue Jan 4 20:48:41 2022 : >SENT: 04
[26989] Tue Jan 4 20:48:43 2022 : <RECV: len=1 05 (2000.0 ms)
[26989] Tue Jan 4 20:48:43 2022 : <RECV: received 05
[26989] Tue Jan 4 20:48:43 2022 : >FRAMER: framer_reset_actaddr framer_current_addr = FRAMER_LINK_STATUS(05) (was FE05)
[26989] Tue Jan 4 20:48:43 2022 : >FRAMER: closed
[26989] Tue Jan 4 20:48:43 2022 : >SENT: 16
[26989] Tue Jan 4 20:48:43 2022 : >SENT: 00
[26989] Tue Jan 4 20:48:43 2022 : >SENT: 00
[26989] Tue Jan 4 20:48:45 2022 : <RECV: len=1 05 (2020.0 ms)
[26989] Tue Jan 4 20:48:45 2022 : <RECV: received 05
[26989] Tue Jan 4 20:48:45 2022 : >SENT: 04
[26989] Tue Jan 4 20:48:47 2022 : <RECV: len=1 05 (1990.0 ms)
[26989] Tue Jan 4 20:48:47 2022 : <RECV: received 05
[26989] Tue Jan 4 20:48:47 2022 : >FRAMER: framer_reset_actaddr framer_current_addr = FRAMER_LINK_STATUS(05) (was FE05)
[26989] Tue Jan 4 20:48:47 2022 : >FRAMER: closed
[26989] Tue Jan 4 20:48:47 2022 : >SENT: 16
[26989] Tue Jan 4 20:48:47 2022 : >SENT: 00
[26989] Tue Jan 4 20:48:47 2022 : >SENT: 00
[26989] Tue Jan 4 20:48:49 2022 : <RECV: len=1 05 (1990.0 ms)
[26989] Tue Jan 4 20:48:49 2022 : <RECV: received 05
[26989] Tue Jan 4 20:48:49 2022 : >FRAMER: framer_reset_actaddr framer_current_addr = FRAMER_LINK_STATUS(15) (was FE05)
[26989] Tue Jan 4 20:48:49 2022 : >FRAMER: could not close (3 attempts)
[26989] Tue Jan 4 20:48:50 2022 : Process 26989 released lock
[26989] Tue Jan 4 20:48:50 2022 : Error opening /dev/vitoir0
[26989] Tue Jan 4 20:48:50 2022 : Error reading from socket
[26989] Tue Jan 4 20:48:50 2022 : Received SIGPIPE
[26989] Tue Jan 4 20:48:50 2022 : Process 26989 released lock
[26989] Tue Jan 4 20:48:50 2022 : Closed connection (fd:1)
[26989] Tue Jan 4 20:48:50 2022 : Child process with PID 26989 terminated

`
It seems to be unable to close the connection. Can you please give me an hint, how to fix the issue?

My device is a "VT200-S WO1C"
ecnsysDeviceIdent:204D : CU401B_S

Best regards
tclas

[tclas]

Digging a little deeper, I noticed, that the problem is connected to the usage of protocol VS2. Using VS1 the script returns values - alhrough, the adresses doesn't always match the ones found in results of PrintEventsForDatapoint.py for my Datapoint.

Best Regards
tclas