thomasdelaet / python-velbus

A python library to control the Velbus home automation system
MIT License
17 stars 8 forks source link

Module VMBGP4-2, VMBGP4PIR does not yet support sub modules #69

Open bvedomotic opened 3 years ago

bvedomotic commented 3 years ago

The problem

When I refresh the Velbus Integration i receive the flowing errors in the configuration logs: Logger: velbus Source: /usr/local/lib/python3.8/site-packages/velbus/controller.py:311 First occurred: 4:09:17 PM (6 occurrences) Last logged: 4:09:35 PM

Module VMBGP4PIR does not yet support sub modules Module VMBGP4-2 does not yet support sub modules

For the modules of this type i also have the flowing error in the configuration logs: Logger: velbus Source: /usr/local/lib/python3.8/site-packages/velbus/controller.py:161 First occurred: 4:12:46 PM (4 occurrences) Last logged: 4:12:46 PM

Failed to completely load module VMBGP4PIRK at address 8 before timeout expired. Failed to completely load module VMBGP4 at address 176 before timeout expired. Failed to completely load module VMBGP4PIRBad at address 177 before timeout expired. Failed to completely load module VMBGP4PIR Living at address 191 before timeout expired.

The rest of the modules works fine only those 2 types are not working and not present in the devices.

Environment


## Traceback/Error logs
<!--
  If you come across any trace or error logs, please provide them.
-->

```Logger: velbus
Source: /usr/local/lib/python3.8/site-packages/velbus/controller.py:311
First occurred: 4:09:17 PM (6 occurrences)
Last logged: 4:09:35 PM

Module VMBGP4PIR does not yet support sub modules
Module VMBGP4-2 does not yet support sub modules

Logger: velbus
Source: /usr/local/lib/python3.8/site-packages/velbus/controller.py:161
First occurred: 4:12:46 PM (4 occurrences)
Last logged: 4:12:46 PM

Failed to completely load module VMBGP4PIRK at address 8 before timeout expired.
Failed to completely load module VMBGP4 at address 176 before timeout expired.
Failed to completely load module VMBGP4PIRBad at address 177 before timeout expired.
Failed to completely load module VMBGP4PIR Living at address 191 before timeout expired.

Additional information

Cereal2nd commented 3 years ago

i think i have a fix for this, but i can not test this as i do not own these modules ...

bvedomotic commented 3 years ago

I wil test it on my system, wil this update (fix) apply automatically on home assistant os or have i to wait following release update?

Cereal2nd commented 3 years ago

i can not commit this until we test this out, as i can break other parts of the system.

2 options: 1- i provide a difff and you test it on your local system 2- you provide me with some (temporary) access to your system over an ssh tunnel or something like thats and i debug on your system.

bvedomotic commented 3 years ago

I will try to setup a separate system that is connected on my velbus installation and inform you when it is accessible.

AlbertHakvoort commented 3 years ago

I've got the same issue @Cereal2nd , I would like to try it

ErikRat commented 3 years ago

I have a similar problem. Module VMBGP4-2 does not yet support sub modules Failed to completely load module VMB4RYLD at address 100 before timeout expired This has worked until Home Assistant version 0.113.3 I have 10 x VMB4RYLD. Sometimes it loads one or two of these modules and gives the error message for the others. All the modules with an address higher than the one that was loaded last will give this error.

Cereal2nd commented 3 years ago

i'm currently working on a complete new implementation in homeassistent

not sure when i will be able to push it. people who want to test can alreeady try it. https://github.com/Cereal2nd/velbus-aio

VMBGP*-2 are not yet supported, althought it should be an easy fix (if i can login to someones installation with these active)

@ErikRat that the modules are not loaded after some time is not normal, maybe some buss errors? i have this running in an installation with about 80 modules and it works perfect.

ErikRat commented 3 years ago

@Cereal2nd My active installation runs on Home Assistant version 0.113.3, here it loads all modules without any problems. He will give the warning 'Module VMBGP4-2 does not yet support sub modules'. But not the error message 'Failed to completely load module VMB4RYLD at address 100 before timeout expired' I also get this warning in my logs Logger: velbus Source: /usr/local/lib/python3.8/site-packages/velbus/connections/serial.py:75 First occurred: January 16, 2021 15:28:46 (5 occurrences) Last logged: 11:21:50 Stop executed If I update my installation to a later version, the problems start. Here is a list of all my modules: 10 x VMB4RYLD 1 x VMB4RYNOS 1 x VMB1RYNOS 1 x VMB1RY 1 x VMB4DC 1 x VMBGPO 1 x VMBGPOD 1 x VMBELO 6 x VMB8PBU 6 x VMBGP2

Cereal2nd commented 3 years ago

the warning is normal in case the velbus connection is not stable.

what you could try is to extend the timeout in the velbus module in the controller file there isa timer, increase this one

On Sun, Jan 17, 2021 at 1:46 PM ErikRat notifications@github.com wrote:

@Cereal2nd https://github.com/Cereal2nd My active installation runs on Home Assistant version 0.113.3, here it loads all modules without any problems. He will give the warning 'Module VMBGP4-2 does not yet support sub modules'. But not the error message 'Failed to completely load module VMB4RYLD at address 100 before timeout expired' I also get this warning in my logs Logger: velbus Source: /usr/local/lib/python3.8/site-packages/velbus/connections/serial.py:75 First occurred: January 16, 2021 15:28:46 (5 occurrences) Last logged: 11:21:50 If I update my installation to a later version, the problems start. Stop executed

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/thomasdelaet/python-velbus/issues/69#issuecomment-761806888, or unsubscribe https://github.com/notifications/unsubscribe-auth/AA4LF4NVCSB443SNBPDJGQTS2LL3VANCNFSM4UQSQYLQ .

ErikRat commented 3 years ago

I have a separate test environment on a raspberry pi 4. Here I can perform any tests, it also has a connection with my velbus installation. Where can I find this file where I can adjust the timer? Can I access the file via the terminal in home assistant? Or do I have to use the file editor in home assistant.

Cereal2nd commented 3 years ago

the files depend on your installation type. how is it installed?

On Sun, Jan 17, 2021 at 3:47 PM ErikRat notifications@github.com wrote:

I have a separate test environment on a raspberry pi 4. Here I can perform any tests, it also has a connection with my velbus installation. Where can I find this file where I can adjust the timer?

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/thomasdelaet/python-velbus/issues/69#issuecomment-761823919, or unsubscribe https://github.com/notifications/unsubscribe-auth/AA4LF4MBZC5ZFS3X6SFYVGLS2LZ6XANCNFSM4UQSQYLQ .

ErikRat commented 3 years ago

In my test environment this is HA image My active installation Operating System Ubuntu 20.04 LTS Docker version 19.03.11

ErikRat commented 3 years ago

My concern is why does everything work in Home Assistant version 0.113.3 and not in a later version? The only thing that has changed is the Home Assistant version. Then it is Home Assistant that has broken something.

KevChief commented 3 years ago

I seem to have the same kind of error, but for modules VMBEL1 (failed to load address before timeout) and VMBEL4 (does not yet support sub modules)

Cereal2nd commented 3 years ago

Previously before hass 0.115 we hardfailed in case a module was not loaded, since hass 0.115 we softail and do not continue with the error modules.

If we increase the timer, then it should solve your problems.

On Mon, 18 Jan 2021, 00:46 KevChief, notifications@github.com wrote:

I seem to have the same kind of error, but for modules VMBEL1 (failed to load address before timeout) and VMBEL4 (does not yet support sub modules)

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/thomasdelaet/python-velbus/issues/69#issuecomment-761902071, or unsubscribe https://github.com/notifications/unsubscribe-auth/AA4LF4LQCVAXCQTW76E6GILS2NZFHANCNFSM4UQSQYLQ .

Cereal2nd commented 3 years ago

My concern is why does everything work in Home Assistant version 0.113.3 and not in a later version? The only thing that has changed is the Home Assistant version. Then it is Home Assistant that has broken something.

ErikRat commented 3 years ago

I installed velbus in my test environment via custom components. And adjusted the timer in the controller file to 300 sec, but still the same result. In my active installation Home Assistant version 0.113.3 the scan of the velbus takes 2 min, in the test installation Home Assistant core-2021.1.3 this scan takes 4min.I also see a lot of rtr errors in the log.

Cereal2nd commented 3 years ago

rtr errors in the logs? never seen this, can you copy paste one?

we now also load the module names, this could be one of the reasons why its slower

Cereal2nd commented 3 years ago

the problem with the long loading times is that we need to send/recive a lot of messages on the bus

so yes on a big installation this ca take a while.

for example 10 * VMB4RYLD

so this takes already 3 minuts, the glasspanels also have submodules so that makes it a lot more messages

ErikRat commented 3 years ago

Here are some of the many rtr errors.

2021-01-17 20:16:59 INFO (write_packets_process) [velbus] Sending message on USB bus: {"name": "ChannelNameRequestMessage", "priority": 251, "address": 102, "rtr": false} 2021-01-17 20:16:59 INFO (write_packets_process) [velbus] Sending message on USB bus: {"name": "ReadDataFromMemoryMessage", "priority": 251, "address": 103, "rtr": false} 2021-01-17 20:16:59 INFO (write_packets_process) [velbus] Sending message on USB bus: {"name": "ReadDataFromMemoryMessage", "priority": 251, "address": 103, "rtr": false} 2021-01-17 20:16:43 INFO (write_packets_process) [velbus] Sending message on USB bus: {"name": "ReadDataFromMemoryMessage", "priority": 251, "address": 100, "rtr": false} 2021-01-17 20:16:43 INFO (Thread-3) [velbus] New message: {"name": "ModuleStatusMessage2", "priority": 251, "address": 60, "rtr": false, "closed": [], "enabled": [1, 2, 3, 4, 5, 6, 7, 8], "normal": [1, 2, 3, 4, 5, 6, 7, 8], "locked": []} 2021-01-17 20:16:43 INFO (Thread-3) [velbus] New message: {"name": "ChannelNamePart1Message", "priority": 251, "address": 60, "rtr": false, "channel": 1} 2021-01-17 20:16:43 INFO (Thread-3) [velbus] New message: {"name": "ChannelNamePart2Message", "priority": 251, "address": 60, "rtr": false, "channel": 1}

These are all addresses of relay modules. The addresses of my relay modules run from 100 to 113 and there is another VMB4DC at address 150. Relay 100 and 101 are still loading and the addresses after it are no longer loaded.

Cereal2nd commented 3 years ago

these are not errors, there are just log messages

On Tue, Jan 19, 2021 at 5:04 PM ErikRat notifications@github.com wrote:

Here are some of the many rtr errors.

2021-01-17 20:16:59 INFO (write_packets_process) [velbus] Sending message on USB bus: {"name": "ChannelNameRequestMessage", "priority": 251, "address": 102, "rtr": false} 2021-01-17 20:16:59 INFO (write_packets_process) [velbus] Sending message on USB bus: {"name": "ReadDataFromMemoryMessage", "priority": 251, "address": 103, "rtr": false} 2021-01-17 20:16:59 INFO (write_packets_process) [velbus] Sending message on USB bus: {"name": "ReadDataFromMemoryMessage", "priority": 251, "address": 103, "rtr": false} 2021-01-17 20:16:43 INFO (write_packets_process) [velbus] Sending message on USB bus: {"name": "ReadDataFromMemoryMessage", "priority": 251, "address": 100, "rtr": false} 2021-01-17 20:16:43 INFO (Thread-3) [velbus] New message: {"name": "ModuleStatusMessage2", "priority": 251, "address": 60, "rtr": false, "closed": [], "enabled": [1, 2, 3, 4, 5, 6, 7, 8], "normal": [1, 2, 3, 4, 5, 6, 7, 8], "locked": []} 2021-01-17 20:16:43 INFO (Thread-3) [velbus] New message: {"name": "ChannelNamePart1Message", "priority": 251, "address": 60, "rtr": false, "channel": 1} 2021-01-17 20:16:43 INFO (Thread-3) [velbus] New message: {"name": "ChannelNamePart2Message", "priority": 251, "address": 60, "rtr": false, "channel": 1}

These are all addresses of relay modules. The addresses of my relay modules run from 100 to 113 and there is another VMB4DC at address 150. Relay 100 and 101 are still loading and the addresses after it are no longer loaded.

— You are receiving this because you modified the open/close state. Reply to this email directly, view it on GitHub https://github.com/thomasdelaet/python-velbus/issues/69#issuecomment-762942232, or unsubscribe https://github.com/notifications/unsubscribe-auth/AA4LF4I3BJ257Z635COFLBDS2WUQRANCNFSM4UQSQYLQ .

ErikRat commented 3 years ago

This is what I see in the log of my fixed installation when I reload velbus. Here you see rtr = true.

2021-01-19 17:16:44 INFO (write_packets_process) [velbus] Sending message on USB bus: {"name": "ModuleTypeRequestMessage", "priority": 251, "address": 100, "rtr": true} 2021-01-19 17:16:44 INFO (Thread-2) [velbus] New message: {"name": "ModuleTypeMessage", "priority": 251, "address": 100, "rtr": false} 2021-01-19 17:16:44 INFO (write_packets_process) [velbus] Sending message on USB bus: {"name": "ModuleTypeRequestMessage", "priority": 251, "address": 101, "rtr": true} 2021-01-19 17:16:44 INFO (Thread-2) [velbus] New message: {"name": "ModuleTypeMessage", "priority": 251, "address": 101, "rtr": false} 2021-01-19 17:16:45 INFO (write_packets_process) [velbus] Sending message on USB bus: {"name": "ModuleTypeRequestMessage", "priority": 251, "address": 102, "rtr": true} 2021-01-19 17:16:45 INFO (Thread-2) [velbus] New message: {"name": "ModuleTypeMessage", "priority": 251, "address": 102, "rtr": false} 2021-01-19 17:16:45 INFO (write_packets_process) [velbus] Sending message on USB bus: {"name": "ModuleTypeRequestMessage", "priority": 251, "address": 103, "rtr": true} 2021-01-19 17:16:45 INFO (Thread-2) [velbus] New message: {"name": "ModuleTypeMessage", "priority": 251, "address": 103, "rtr": false} 2021-01-19 17:16:45 INFO (write_packets_process) [velbus] Sending message on USB bus: {"name": "ModuleTypeRequestMessage", "priority": 251, "address": 104, "rtr": true}

Cereal2nd commented 3 years ago

according to:https://github.com/velbus/packetprotocol

RTR (Remote Transmit Request)

The high nibble is used in a packet in which it requests information without supplying any data (e.g. scanning the bus).

Should you wish to use RTR in the packet, mask the byte with 0x40.

so the rtr should only be true in case of a scan message (aka ModuleTypeRequestMessage)

On Tue, Jan 19, 2021 at 5:26 PM ErikRat notifications@github.com wrote:

This is what I see in the log of my fixed installation when I reload velbus. Here you see rtr = true.

2021-01-19 17:16:44 INFO (write_packets_process) [velbus] Sending message on USB bus: {"name": "ModuleTypeRequestMessage", "priority": 251, "address": 100, "rtr": true} 2021-01-19 17:16:44 INFO (Thread-2) [velbus] New message: {"name": "ModuleTypeMessage", "priority": 251, "address": 100, "rtr": false} 2021-01-19 17:16:44 INFO (write_packets_process) [velbus] Sending message on USB bus: {"name": "ModuleTypeRequestMessage", "priority": 251, "address": 101, "rtr": true} 2021-01-19 17:16:44 INFO (Thread-2) [velbus] New message: {"name": "ModuleTypeMessage", "priority": 251, "address": 101, "rtr": false} 2021-01-19 17:16:45 INFO (write_packets_process) [velbus] Sending message on USB bus: {"name": "ModuleTypeRequestMessage", "priority": 251, "address": 102, "rtr": true} 2021-01-19 17:16:45 INFO (Thread-2) [velbus] New message: {"name": "ModuleTypeMessage", "priority": 251, "address": 102, "rtr": false} 2021-01-19 17:16:45 INFO (write_packets_process) [velbus] Sending message on USB bus: {"name": "ModuleTypeRequestMessage", "priority": 251, "address": 103, "rtr": true} 2021-01-19 17:16:45 INFO (Thread-2) [velbus] New message: {"name": "ModuleTypeMessage", "priority": 251, "address": 103, "rtr": false} 2021-01-19 17:16:45 INFO (write_packets_process) [velbus] Sending message on USB bus: {"name": "ModuleTypeRequestMessage", "priority": 251, "address": 104, "rtr": true}

— You are receiving this because you modified the open/close state. Reply to this email directly, view it on GitHub https://github.com/thomasdelaet/python-velbus/issues/69#issuecomment-762957137, or unsubscribe https://github.com/notifications/unsubscribe-auth/AA4LF4LT5COTG5FSLAPLIVLS2WXCTANCNFSM4UQSQYLQ .

ErikRat commented 3 years ago

May I ask which version of Home Assistant your velbus is running. Then I can also try this in my test environment. Because I have already increased the timer to 600 sec and still get no better result. I am not a real programmer, can make small adjustments with help. Can I try the older version of velbus for version 0.115?

Cereal2nd commented 3 years ago

Home Assistant 2021.1.4

can you log in to discord or something, to really hepl debug this it would be simpler via chat

On Tue, Jan 19, 2021 at 8:01 PM ErikRat notifications@github.com wrote:

May I ask which version of Home Assistant your velbus is running. Then I can also try this in my test environment. Because I have already increased the timer to 600 sec and still get no better result. I am not a real programmer, can make small adjustments with help. Can I try the older version of velbus for version 0.115?

— You are receiving this because you modified the open/close state. Reply to this email directly, view it on GitHub https://github.com/thomasdelaet/python-velbus/issues/69#issuecomment-763055237, or unsubscribe https://github.com/notifications/unsubscribe-auth/AA4LF4IHYHIDFLUU2Q3KEQ3S2XJJVANCNFSM4UQSQYLQ .

ErikRat commented 3 years ago

How can I do this is the first time. Am Dutch speaking.

Cereal2nd commented 3 years ago

https://discord.gg/8vX4kqDw I'm cereal#0919 there

On Tue, Jan 19, 2021 at 8:05 PM ErikRat notifications@github.com wrote:

How can I do this is the first time. Am Dutch speaking.

— You are receiving this because you modified the open/close state. Reply to this email directly, view it on GitHub https://github.com/thomasdelaet/python-velbus/issues/69#issuecomment-763059554, or unsubscribe https://github.com/notifications/unsubscribe-auth/AA4LF4OPEM76M226H73HSF3S2XJYLANCNFSM4UQSQYLQ .

ErikRat commented 3 years ago

@Cereal2nd When I run the scan.py script I get this error after it has scanned for + - 20 sec.

INFO: root: Exiting ... WARNING: velbus: Stop executed INFO: velbus: Sending message on USB bus: {"name": "ModuleStatusRequestMessage", "priority": 251, "address": 18, "rtr": false} Exception in thread write_packets_process: Traceback (most recent call last): File "/usr/lib/python3.7/threading.py", line 917, in _bootstrap_inner self.run () File "/usr/lib/python3.7/threading.py", line 865, in run self._target (* self._args, ** self._kwargs) File "/home/pi/Desktop/python-velbus-master/velbus/connections/serial.py", line 99, in write_daemon self._reader.write (message.to_binary ()) File "/usr/lib/python3/dist-packages/serial/threaded/init.py", line 217, in write self.serial.write (data) File "/usr/lib/python3/dist-packages/serial/serialposix.py", line 531, in write raise portNotOpenError serial.serialutil.SerialException: Attempting to use a port that is not open

Cereal2nd commented 3 years ago

it seems that the connection parameters in the beginning of the script are not set correctly. make sure to set the port correctly

On Sun, Jan 24, 2021 at 11:40 PM ErikRat notifications@github.com wrote:

@Cereal2nd https://github.com/Cereal2nd When I run the scan.py script I get this error after it has scanned for +

  • 20 sec.

INFO: root: Exiting ... WARNING: velbus: Stop executed INFO: velbus: Sending message on USB bus: {"name": "ModuleStatusRequestMessage", "priority": 251, "address": 18, "rtr": false} Exception in thread write_packets_process: Traceback (most recent call last): File "/usr/lib/python3.7/threading.py", line 917, in _bootstrap_inner self.run () File "/usr/lib/python3.7/threading.py", line 865, in run self._target (* self._args, * self._kwargs) File "/home/pi/Desktop/python-velbus-master/velbus/connections/serial.py", line 99, in write_daemon self._reader.write (message.to_binary ()) File "/usr/lib/python3/dist-packages/serial/threaded/init*.py", line 217, in write self.serial.write (data) File "/usr/lib/python3/dist-packages/serial/serialposix.py", line 531, in write raise portNotOpenError serial.serialutil.SerialException: Attempting to use a port that is not open

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/thomasdelaet/python-velbus/issues/69#issuecomment-766452300, or unsubscribe https://github.com/notifications/unsubscribe-auth/AA4LF4LCETB6FA4NODIBPE3S3SOWFANCNFSM4UQSQYLQ .

ErikRat commented 3 years ago

My port settings are correct because I see the scan running in velbusLink and in my terminal. It scans for about half a minute, then it has read in all module types. But when he starts reading the name part, it goes wrong. This at a VMBGPO, after about 5 seconds it gives the message INFO: root: Exiting ... WARNING: velbus: Stop executed Then he only scanned a total of 32 seconds. Could it have something to do with the submodulles of the VMBGPO? In the name part scan I also see no outgoing packets from the velbus, and in the module scan I do see these.

bvedomotic commented 3 years ago

@ErikRat Hello, In the past i had problems with VMBGPO because i didn't adresse all pages of the VMBGPO. Are all the submodules adressed?