[velux] New OpenHAB2 binding - feedback welcome!

gs4711 · April 23, 2019, 9:32am

Hello Kim,

let’s try to clarify the situtation with the v2 firmware:

the connectivity of the bridge is only possible on the LAN interface
with the password printed on the backside of the KLF200.
The webinterface is only available for a period of time after reboot on the WLAN (if not configured to stay always on).

As soon as the binding gets in contact with the KLF200, it will print (in fact, log with priority INFO) the found scenes and products, which can be used as items in addition to the basic bridge items which are described within the README).

Regards, Guenther

spiff42 · April 23, 2019, 9:40am

with the password printed on the backside of the KLF200

This is strange, because I initially tried with the “random” password printed on the back of the KLF200, but I got login-error. Then I tried “velux123” and that is working (as seen in my velux.cfg shown above)

spiff42 · April 23, 2019, 9:47am

I have these in velux.items:

String Velux_Bridge_Firmware        "Firmware [%s]"         { velux="thing=bridge;channel=firmware" }
String Velux_Bridge_Status          "Status [%s]"           { velux="thing=bridge;channel=status" }
String Velux_Bridge_CfgCheck        "Config Check [%s]"     { velux="thing=bridge;channel=check" }

And this in the sitemap:

            Frame label="Velux" {
                Default item=Velux_Bridge_Firmware
                Default item=Velux_Bridge_Status
                Default item=Velux_Bridge_CfgCheck

                Slider item=Velux_DiningTable_WindowL
                Slider item=Velux_DiningTable_WindowR
                Slider item=Velux_DiningTable_MarkiseL
                Slider item=Velux_DiningTable_MarkiseR
            }

But I still get something sensible for the bridge status:

Kim_Andersen · April 23, 2019, 9:49am

Hi Guenther…
As stated above. I tried with both passwords (Web and WiFi (printed on the back)). None of them worked…I havn´t tried with “velux123” though… Hmm…

Second… I am unsure which binding version I should be using.
I´m running openhab 2.5 Milestone 1. I previously was using a 2.4snapshot binding from August 2018. But when reading above, the 1.14 seems to be alot newer, as it´s printed Marts 2019.
The KLF200 is updated to firmware 2
So which binding should I use?

Right now Im trying @mfk . It connects fine, however, it cant locate my 8 roof windows correctly, (it receives their states, but they are not visible in PaperUI), and it only finds 3 sceenes (our of 20 scenes). So it´s pretty useless.

Third…
When using your binding, I find it very confusing how to set it up… Why is there a need of both a .cfg and a .things file?

gs4711 · April 23, 2019, 10:06am

The binding of August 2018 does only contain the JSON-based connectivity which is deprecated with firmware version 2. For the newest firmware the newest OH1 binding runs under OH2 as well. It will be available as OH2 binding as soon as the recent changes are integrated within the OH1 distribution (two PRs are still unconfirmed).

Personally I can only help with this above mentioned binding…
In a parallel discussion, the person shared with us that the default password was the clue to get in contact with the bridge …

Cheers, Guenther

Kim_Andersen · April 23, 2019, 10:20am

Ofcouse… Reason why I mentioned the other binding was to tell you, I can connect fine using that binding. I guess the password beeing used is the same in both bindings…

Kim_Andersen · April 23, 2019, 12:03pm

Just gave 1.14 another try… This is what happens during openhab startup:

2019-04-23 13:58:41.717 [DEBUG] [.velux.handler.VeluxBridgeHandlerOH1] - VeluxBridgeHandlerOH1(constructor) called.
2019-04-23 13:58:41.947 [DEBUG] [.velux.bridge.slip.SCidentifyProduct] - SCidentifyProduct(Constructor) called.
2019-04-23 13:58:41.951 [DEBUG] [.velux.bridge.slip.SCidentifyProduct] - SCidentifyProduct(): starting sessions with the random number 1092.
2019-04-23 13:58:41.995 [DEBUG] [binding.velux.bridge.slip.SCrunScene] - SCrunScene(Constructor) called.
2019-04-23 13:58:41.998 [DEBUG] [binding.velux.bridge.slip.SCrunScene] - SCrunScene(): starting sessions with the random number 938.
2019-04-23 13:58:42.015 [DEBUG] [ding.velux.bridge.slip.SCsendCommand] - SCgetProduct(Constructor) called.
2019-04-23 13:58:42.018 [DEBUG] [ding.velux.bridge.slip.SCsendCommand] - SCgetProduct(): starting sessions with the random number 2997.
2019-04-23 13:58:42.053 [INFO ] [.binding.velux.internal.VeluxBinding] - Active items are: [].
2019-04-23 13:58:42.059 [DEBUG] [org.openhab.binding.velux           ] - ServiceEvent REGISTERED - {org.osgi.service.cm.ManagedService, org.osgi.service.event.EventHandler}={service.id=482, service.bundleid=308, service.scope=bundle, event.topics=openhab/*, service.pid=org.openhab.velux, component.name=org.openhab.binding.velux.binding, component.id=285} - org.openhab.binding.velux
2019-04-23 13:58:42.063 [DEBUG] [.binding.velux.internal.VeluxBinding] - updated() called with 7 dictionary entries.
2019-04-23 13:58:42.064 [DEBUG] [org.openhab.binding.velux           ] - ServiceEvent REGISTERED - {org.openhab.model.item.binding.BindingConfigReader, org.openhab.binding.velux.VeluxBindingProvider}={service.id=480, service.bundleid=308, service.scope=bundle, component.name=org.openhab.binding.velux.genericbindingprovider, component.id=286} - org.openhab.binding.velux
2019-04-23 13:58:42.065 [DEBUG] [.binding.velux.internal.VeluxBinding] - updated(): adapted BRIDGE_PROTOCOL to slip.
2019-04-23 13:58:42.068 [DEBUG] [.binding.velux.internal.VeluxBinding] - updated(): adapted BRIDGE_IPADDRESS to 10.4.28.252.
2019-04-23 13:58:42.070 [DEBUG] [.binding.velux.internal.VeluxBinding] - updated(): adapted BRIDGE_TCPPORT to 51200.
2019-04-23 13:58:42.072 [DEBUG] [.binding.velux.internal.VeluxBinding] - updated(): adapted BRIDGE_PASSWORD to xxxxxxxx.
2019-04-23 13:58:42.074 [DEBUG] [org.openhab.binding.velux           ] - BundleEvent STARTED - org.openhab.binding.velux
2019-04-23 13:58:42.074 [DEBUG] [.binding.velux.internal.VeluxBinding] - updated(): adapted BRIDGE_TIMEOUT_MSECS to 15000.
2019-04-23 13:58:42.089 [DEBUG] [.binding.velux.internal.VeluxBinding] - updated(): adapted BRIDGE_RETRIES to 15.
2019-04-23 13:58:42.100 [INFO ] [.binding.velux.internal.VeluxBinding] - velux refresh interval set to 15000 milliseconds.
2019-04-23 13:58:42.107 [INFO ] [.binding.velux.internal.VeluxBinding] - veluxConfig[bridgeProtocol=slip,bridgeIPAddress=10.4.28.252,bridgeTCPPort=51200,bridgePassword=********,timeoutMsecs=15000,retries=15,refreshMsecs=15000,isBulkRetrievalEnabled=true]
2019-04-23 13:58:42.109 [DEBUG] [.binding.velux.internal.VeluxBinding] - execute() called.
2019-04-23 13:58:42.107 [INFO ] [b.core.service.AbstractActiveService] - velux Refresh Service has been started
2019-04-23 13:58:42.111 [DEBUG] [.binding.velux.internal.VeluxBinding] - There is no existing Velux binding configuration => refresh cycle aborted!
2019-04-23 13:58:42.141 [DEBUG] [.binding.velux.internal.VeluxBinding] - execute() called.
2019-04-23 13:58:42.143 [DEBUG] [.binding.velux.internal.VeluxBinding] - There is no existing Velux binding configuration => refresh cycle aborted!

The same thing happen, no matter what password I use.
This is my .cfg file:

bridgeIPAddress=10.4.28.252
bridgeProtocol=slip
bridgeTCPPort=51200
bridgePassword=xxxxxxxx
timeoutMsecs=15000
retries=15

When entering the binding through PaperUI, I end up with a blank screen.

gs4711 · April 23, 2019, 12:09pm

Hi Kim,

let’s try this approach to verify the valid connectivity: Please put the following content into an item definition file i.e. /etc/openhab2/items/velux.items

String V_FIRMWARE "Firmware [%s]" {velux="thing=bridge;channel=firmware"}
String V_STATUS "Status [%s]" {velux="thing=bridge;channel=status"}
Rollershutter V_DEMO_SHUTTER "Velux demo shutter [%d]" { velux="thing=actuator;channel=serial#01:02:03:04:05:06:07:08" }

Kim_Andersen · April 23, 2019, 12:18pm

This is what happens in debug log:

2019-04-23 14:11:59.527 [INFO ] [el.core.internal.ModelRepositoryImpl] - Refreshing model 'velux.items'
2019-04-23 14:11:59.597 [DEBUG] [internal.VeluxGenericBindingProvider] - VeluxGenericBindingParser() channelIdentifier=firmware, channelValue=.
2019-04-23 14:11:59.605 [DEBUG] [internal.VeluxGenericBindingProvider] - validateItemType() returned w/o exception.
2019-04-23 14:11:59.606 [DEBUG] [internal.VeluxGenericBindingProvider] - VeluxGenericBindingParser() channelIdentifier=firmware, channelValue=.
2019-04-23 14:11:59.609 [DEBUG] [internal.VeluxGenericBindingProvider] - processBindingConfiguration(velux.items,V_FIRMWARE,thing=bridge;channel=firmware) successfully finished.
2019-04-23 14:11:59.611 [DEBUG] [internal.VeluxGenericBindingProvider] - VeluxGenericBindingParser() channelIdentifier=status, channelValue=.
2019-04-23 14:11:59.613 [DEBUG] [internal.VeluxGenericBindingProvider] - validateItemType() returned w/o exception.
2019-04-23 14:11:59.615 [DEBUG] [internal.VeluxGenericBindingProvider] - VeluxGenericBindingParser() channelIdentifier=status, channelValue=.
2019-04-23 14:11:59.617 [DEBUG] [internal.VeluxGenericBindingProvider] - processBindingConfiguration(velux.items,V_STATUS,thing=bridge;channel=status) successfully finished.
2019-04-23 14:11:59.621 [DEBUG] [internal.VeluxGenericBindingProvider] - VeluxGenericBindingParser() channelIdentifier=serial, channelValue=01:02:03:04:05:06:07:08.
2019-04-23 14:11:59.622 [DEBUG] [internal.VeluxGenericBindingProvider] - validateItemType() returned w/o exception.
2019-04-23 14:11:59.624 [DEBUG] [internal.VeluxGenericBindingProvider] - VeluxGenericBindingParser() channelIdentifier=serial, channelValue=01:02:03:04:05:06:07:08.
2019-04-23 14:11:59.626 [DEBUG] [internal.VeluxGenericBindingProvider] - processBindingConfiguration(velux.items,V_DEMO_SHUTTER,thing=actuator;channel=serial#01:02:03:04:05:06:07:08) successfully finished.

And futher more:

2019-04-23 14:12:12.459 [DEBUG] [.binding.velux.internal.VeluxBinding] - execute() called.
2019-04-23 14:12:12.462 [DEBUG] [.velux.handler.VeluxBridgeHandlerOH1] - handleCommandOnChannel(item=V_STATUS,command=null,config=org.openhab.binding.velux.internal.VeluxBindingConfig@65da0c,provider=org.openhab.binding.velux.internal.VeluxGenericBindingProvider@a238b0) called.
2019-04-23 14:12:12.464 [DEBUG] [.velux.handler.VeluxBridgeHandlerOH1] - bridgeParamsUpdated() called.
2019-04-23 14:12:12.466 [DEBUG] [.velux.handler.VeluxBridgeHandlerOH1] - bridgeParamsUpdated(): choosing SLIP as communication method.
2019-04-23 14:12:12.468 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(GW_PASSWORD_ENTER_REQ,unauthenticated) called.
2019-04-23 14:12:12.471 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): working on request GW_PASSWORD_ENTER_REQ with 32 bytes of data.
2019-04-23 14:12:12.496 [DEBUG] [g.velux.bridge.slip.io.SSLconnection] - SSLconnection(10.4.28.252,51200) called.
2019-04-23 14:12:12.499 [INFO ] [g.velux.bridge.slip.io.SSLconnection] - Starting velux bridge connection.

And this:

2019-04-23 14:12:17.101 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): sending packet of size 39.
2019-04-23 14:12:32.110 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): received packet with 8 bytes.
2019-04-23 14:12:32.116 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): working on response GW_PASSWORD_ENTER_CFM with 1 bytes of data.
2019-04-23 14:12:32.123 [DEBUG] [ab.binding.velux.bridge.slip.SClogin] - setResponse(GW_PASSWORD_ENTER_CFM with 1 bytes of data) called.
2019-04-23 14:12:32.129 [INFO ] [ab.binding.velux.bridge.slip.SClogin] - velux bridge connection successfully established (login succeeded).
2019-04-23 14:12:32.131 [DEBUG] [ab.binding.velux.bridge.slip.SClogin] - setResponse(): returned status: The request was successful.
2019-04-23 14:12:32.134 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(GW_PASSWORD_ENTER_REQ) returns success.
2019-04-23 14:12:32.140 [DEBUG] [.velux.bridge.slip.SCgetDeviceStatus] - getRequestCommand() returns GW_GET_STATE_REQ (0xc).
2019-04-23 14:12:32.143 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(GW_GET_STATE_REQ,authenticated) called.
2019-04-23 14:12:32.145 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): working on request GW_GET_STATE_REQ with 0 bytes of data.
2019-04-23 14:12:32.149 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): sending packet of size 7.
2019-04-23 14:12:47.153 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): received packet with 13 bytes.
2019-04-23 14:12:47.161 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): working on response GW_GET_STATE_CFM with 6 bytes of data.
2019-04-23 14:12:47.164 [DEBUG] [.velux.bridge.slip.SCgetDeviceStatus] - setResponse(GW_GET_STATE_CFM with 6 bytes of data) called.
2019-04-23 14:12:47.172 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(GW_GET_STATE_REQ) returns success.
2019-04-23 14:12:47.189 [DEBUG] [inding.velux.bridge.slip.SCgetScenes] - getRequestCommand() returns GW_GET_SCENE_LIST_REQ (0x40c).
2019-04-23 14:12:47.192 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(GW_GET_SCENE_LIST_REQ,authenticated) called.
2019-04-23 14:12:47.194 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): working on request GW_GET_SCENE_LIST_REQ with 0 bytes of data.
2019-04-23 14:12:47.199 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): sending packet of size 7.

And finally this:

2019-04-23 14:13:02.202 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): received packet with 8 bytes.
2019-04-23 14:13:02.205 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): working on response GW_GET_SCENE_LIST_CFM with 1 bytes of data.
2019-04-23 14:13:02.208 [DEBUG] [inding.velux.bridge.slip.SCgetScenes] - setResponse(GW_GET_SCENE_LIST_CFM with 1 bytes of data) called.
2019-04-23 14:13:02.216 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): received packet with 204 bytes.
2019-04-23 14:13:02.253 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): working on response GW_GET_SCENE_LIST_NTF with 197 bytes of data.
2019-04-23 14:13:02.259 [DEBUG] [inding.velux.bridge.slip.SCgetScenes] - setResponse(GW_GET_SCENE_LIST_NTF with 197 bytes of data) called.
2019-04-23 14:13:02.267 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): received packet with 204 bytes.
2019-04-23 14:13:02.288 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): working on response GW_GET_SCENE_LIST_NTF with 197 bytes of data.
2019-04-23 14:13:02.293 [DEBUG] [inding.velux.bridge.slip.SCgetScenes] - setResponse(GW_GET_SCENE_LIST_NTF with 197 bytes of data) called.
2019-04-23 14:13:02.296 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): received packet with 204 bytes.
2019-04-23 14:13:02.313 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): working on response GW_GET_SCENE_LIST_NTF with 197 bytes of data.
2019-04-23 14:13:02.319 [DEBUG] [inding.velux.bridge.slip.SCgetScenes] - setResponse(GW_GET_SCENE_LIST_NTF with 197 bytes of data) called.
2019-04-23 14:13:02.322 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): received packet with 204 bytes.
2019-04-23 14:13:02.337 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): working on response GW_GET_SCENE_LIST_NTF with 197 bytes of data.
2019-04-23 14:13:02.341 [DEBUG] [inding.velux.bridge.slip.SCgetScenes] - setResponse(GW_GET_SCENE_LIST_NTF with 197 bytes of data) called.
2019-04-23 14:13:02.343 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): received packet with 204 bytes.
2019-04-23 14:13:02.358 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): working on response GW_GET_SCENE_LIST_NTF with 197 bytes of data.
2019-04-23 14:13:02.362 [DEBUG] [inding.velux.bridge.slip.SCgetScenes] - setResponse(GW_GET_SCENE_LIST_NTF with 197 bytes of data) called.
2019-04-23 14:13:02.365 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): received packet with 204 bytes.
2019-04-23 14:13:02.386 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): working on response GW_GET_SCENE_LIST_NTF with 197 bytes of data.
2019-04-23 14:13:02.457 [DEBUG] [inding.velux.bridge.slip.SCgetScenes] - setResponse(GW_GET_SCENE_LIST_NTF with 197 bytes of data) called.
2019-04-23 14:13:02.460 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): received packet with 139 bytes.
2019-04-23 14:13:02.470 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): working on response GW_GET_SCENE_LIST_NTF with 132 bytes of data.
2019-04-23 14:13:02.473 [DEBUG] [inding.velux.bridge.slip.SCgetScenes] - setResponse(GW_GET_SCENE_LIST_NTF with 132 bytes of data) called.
2019-04-23 14:13:02.475 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(GW_GET_SCENE_LIST_REQ) returns success.
2019-04-23 14:13:02.481 [DEBUG] [nding.velux.bridge.VeluxBridgeScenes] - getScenes() finally has found scenes 20 members: Scene "AlleVinduer100" (index 1) with non-silent mode and 0 actions,Scene "Spisestue75" (index 12) with non-silent mode and 0 actions,Scene "KoekkenLuk" (index 16) with non-silent mode and 0 actions,Scene "AlleVinduer75" (index 17) with non-silent mode and 0 actions,Scene "Spisestue50" (index 3) with non-silent mode and 0 actions,Scene "AlleVinduer50" (index 8) with non-silent mode and 0 actions,Scene "Koekken75" (index 10) with non-silent mode and 0 actions,Scene "StueLuk" (index 18) with non-silent mode and 0 actions,Scene "SpisestueLuk" (index 19) with non-silent mode and 0 actions,Scene "Koekken50" (index 2) with non-silent mode and 0 actions,Scene "AlleVinduerLuk" (index 0) with non-silent mode and 0 actions,Scene "SpisestueVent" (index 9) with non-silent mode and 0 actions,Scene "Stue75" (index 14) with non-silent mode and 0 actions,Scene "StueVent" (index 13) with non-silent mode and 0 actions,Scene "Stue100" (index 7) with non-silent mode and 0 actions,Scene "Stue50" (index 4) with non-silent mode and 0 actions,Scene "Spisestue100" (index 6) with non-silent mode and 0 actions,Scene "AlleVinduerVent" (index 15) with non-silent mode and 0 actions,Scene "Koekken100" (index 5) with non-silent mode and 0 actions,Scene "KoekkenVent" (index 11) with non-silent mode and 0 actions.
2019-04-23 14:13:02.487 [INFO ] [.velux.handler.VeluxBridgeHandlerOH1] - Found velux scenes:
	Scene "AlleVinduer100" (index 1) with non-silent mode and 0 actions
	Scene "Spisestue75" (index 12) with non-silent mode and 0 actions
	Scene "KoekkenLuk" (index 16) with non-silent mode and 0 actions
	Scene "AlleVinduer75" (index 17) with non-silent mode and 0 actions
	Scene "Spisestue50" (index 3) with non-silent mode and 0 actions
	Scene "AlleVinduer50" (index 8) with non-silent mode and 0 actions
	Scene "Koekken75" (index 10) with non-silent mode and 0 actions
	Scene "StueLuk" (index 18) with non-silent mode and 0 actions
	Scene "SpisestueLuk" (index 19) with non-silent mode and 0 actions
	Scene "Koekken50" (index 2) with non-silent mode and 0 actions
	Scene "AlleVinduerLuk" (index 0) with non-silent mode and 0 actions
	Scene "SpisestueVent" (index 9) with non-silent mode and 0 actions
	Scene "Stue75" (index 14) with non-silent mode and 0 actions
	Scene "StueVent" (index 13) with non-silent mode and 0 actions
	Scene "Stue100" (index 7) with non-silent mode and 0 actions
	Scene "Stue50" (index 4) with non-silent mode and 0 actions
	Scene "Spisestue100" (index 6) with non-silent mode and 0 actions
	Scene "AlleVinduerVent" (index 15) with non-silent mode and 0 actions
	Scene "Koekken100" (index 5) with non-silent mode and 0 actions
	Scene "KoekkenVent" (index 11) with non-silent mode and 0 actions	.
2019-04-23 14:13:02.489 [DEBUG] [ding.velux.bridge.slip.SCgetProducts] - getRequestCommand() returns GW_GET_ALL_NODES_INFORMATION_REQ (0x202).
2019-04-23 14:13:02.491 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(GW_GET_ALL_NODES_INFORMATION_REQ,authenticated) called.
2019-04-23 14:13:02.493 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): working on request GW_GET_ALL_NODES_INFORMATION_REQ with 0 bytes of data.
2019-04-23 14:13:02.497 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): sending packet of size 7.

So I guess things are working as they´re suppose to.

Ups… More logging… Now it seems to be working… I get the serials from my windows:

2019-04-23 14:13:17.500 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): received packet with 9 bytes.
2019-04-23 14:13:17.503 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): working on response GW_GET_ALL_NODES_INFORMATION_CFM with 2 bytes of data.
2019-04-23 14:13:17.506 [DEBUG] [ding.velux.bridge.slip.SCgetProducts] - setResponse(GW_GET_ALL_NODES_INFORMATION_CFM with 2 bytes of data) called.
2019-04-23 14:13:17.514 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): received packet with 131 bytes.
2019-04-23 14:13:17.525 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): working on response GW_GET_ALL_NODES_INFORMATION_NTF with 124 bytes of data.
2019-04-23 14:13:17.529 [DEBUG] [ding.velux.bridge.slip.SCgetProducts] - setResponse(GW_GET_ALL_NODES_INFORMATION_NTF with 124 bytes of data) called.
2019-04-23 14:13:17.539 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): received packet with 131 bytes.
2019-04-23 14:13:17.550 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): working on response GW_GET_ALL_NODES_INFORMATION_NTF with 124 bytes of data.
2019-04-23 14:13:17.554 [DEBUG] [ding.velux.bridge.slip.SCgetProducts] - setResponse(GW_GET_ALL_NODES_INFORMATION_NTF with 124 bytes of data) called.
2019-04-23 14:13:17.557 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): received packet with 131 bytes.
2019-04-23 14:13:17.567 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): working on response GW_GET_ALL_NODES_INFORMATION_NTF with 124 bytes of data.
2019-04-23 14:13:17.571 [DEBUG] [ding.velux.bridge.slip.SCgetProducts] - setResponse(GW_GET_ALL_NODES_INFORMATION_NTF with 124 bytes of data) called.
2019-04-23 14:13:17.574 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): received packet with 131 bytes.
2019-04-23 14:13:17.585 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): working on response GW_GET_ALL_NODES_INFORMATION_NTF with 124 bytes of data.
2019-04-23 14:13:17.589 [DEBUG] [ding.velux.bridge.slip.SCgetProducts] - setResponse(GW_GET_ALL_NODES_INFORMATION_NTF with 124 bytes of data) called.
2019-04-23 14:13:17.592 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): received packet with 131 bytes.
2019-04-23 14:13:17.602 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): working on response GW_GET_ALL_NODES_INFORMATION_NTF with 124 bytes of data.
2019-04-23 14:13:17.605 [DEBUG] [ding.velux.bridge.slip.SCgetProducts] - setResponse(GW_GET_ALL_NODES_INFORMATION_NTF with 124 bytes of data) called.
2019-04-23 14:13:17.608 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): received packet with 131 bytes.
2019-04-23 14:13:17.618 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): working on response GW_GET_ALL_NODES_INFORMATION_NTF with 124 bytes of data.
2019-04-23 14:13:17.622 [DEBUG] [ding.velux.bridge.slip.SCgetProducts] - setResponse(GW_GET_ALL_NODES_INFORMATION_NTF with 124 bytes of data) called.
2019-04-23 14:13:17.624 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): received packet with 131 bytes.
2019-04-23 14:13:17.634 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): working on response GW_GET_ALL_NODES_INFORMATION_NTF with 124 bytes of data.
2019-04-23 14:13:17.637 [DEBUG] [ding.velux.bridge.slip.SCgetProducts] - setResponse(GW_GET_ALL_NODES_INFORMATION_NTF with 124 bytes of data) called.
2019-04-23 14:13:17.640 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): received packet with 131 bytes.
2019-04-23 14:13:17.664 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): working on response GW_GET_ALL_NODES_INFORMATION_NTF with 124 bytes of data.
2019-04-23 14:13:17.667 [DEBUG] [ding.velux.bridge.slip.SCgetProducts] - setResponse(GW_GET_ALL_NODES_INFORMATION_NTF with 124 bytes of data) called.
2019-04-23 14:13:17.669 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): received packet with 7 bytes.
2019-04-23 14:13:17.671 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): working on response GW_GET_ALL_NODES_INFORMATION_FINISHED_NTF with 0 bytes of data.
2019-04-23 14:13:17.672 [DEBUG] [ding.velux.bridge.slip.SCgetProducts] - setResponse(GW_GET_ALL_NODES_INFORMATION_FINISHED_NTF with 0 bytes of data) called.
2019-04-23 14:13:17.674 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(GW_GET_ALL_NODES_INFORMATION_REQ) returns success.
2019-04-23 14:13:17.677 [DEBUG] [ng.velux.bridge.VeluxBridgeActuators] - getProducts() storing new product Product "Vindue 1" / WINDOW_OPENER (bridgeIndex=0,serial=56:08:1D:26:06:29:06:C7,position=C800).
2019-04-23 14:13:17.681 [DEBUG] [ng.velux.bridge.VeluxBridgeActuators] - getProducts() storing new product Product "Vindue 2" / WINDOW_OPENER (bridgeIndex=1,serial=56:08:1D:26:06:30:0A:CD,position=C800).
2019-04-23 14:13:17.683 [DEBUG] [ng.velux.bridge.VeluxBridgeActuators] - getProducts() storing new product Product "Vindue 3" / WINDOW_OPENER (bridgeIndex=2,serial=56:08:1D:26:06:29:12:03,position=C800).
2019-04-23 14:13:17.684 [DEBUG] [ng.velux.bridge.VeluxBridgeActuators] - getProducts() storing new product Product "Vindue 4" / WINDOW_OPENER (bridgeIndex=3,serial=56:08:1D:26:06:29:08:7B,position=C800).
2019-04-23 14:13:17.686 [DEBUG] [ng.velux.bridge.VeluxBridgeActuators] - getProducts() storing new product Product "Vindue 5" / WINDOW_OPENER (bridgeIndex=4,serial=56:08:1D:26:06:29:14:5B,position=C800).
2019-04-23 14:13:17.688 [DEBUG] [ng.velux.bridge.VeluxBridgeActuators] - getProducts() storing new product Product "Vindue 6" / WINDOW_OPENER (bridgeIndex=5,serial=56:08:1D:26:06:30:0C:A1,position=C800).
2019-04-23 14:13:17.690 [DEBUG] [ng.velux.bridge.VeluxBridgeActuators] - getProducts() storing new product Product "Vindue 7" / WINDOW_OPENER (bridgeIndex=6,serial=56:08:1D:26:06:29:0D:0D,position=C800).
2019-04-23 14:13:17.692 [DEBUG] [ng.velux.bridge.VeluxBridgeActuators] - getProducts() storing new product Product "Vindue 8" / WINDOW_OPENER (bridgeIndex=7,serial=56:08:1D:26:06:29:14:5C,position=C800).
2019-04-23 14:13:17.694 [DEBUG] [ng.velux.bridge.VeluxBridgeActuators] - getProducts() finally has found products 8 members: Product "Vindue 2" / WINDOW_OPENER (bridgeIndex=1,serial=56:08:1D:26:06:30:0A:CD,position=C800),Product "Vindue 8" / WINDOW_OPENER (bridgeIndex=7,serial=56:08:1D:26:06:29:14:5C,position=C800),Product "Vindue 5" / WINDOW_OPENER (bridgeIndex=4,serial=56:08:1D:26:06:29:14:5B,position=C800),Product "Vindue 7" / WINDOW_OPENER (bridgeIndex=6,serial=56:08:1D:26:06:29:0D:0D,position=C800),Product "Vindue 4" / WINDOW_OPENER (bridgeIndex=3,serial=56:08:1D:26:06:29:08:7B,position=C800),Product "Vindue 6" / WINDOW_OPENER (bridgeIndex=5,serial=56:08:1D:26:06:30:0C:A1,position=C800),Product "Vindue 1" / WINDOW_OPENER (bridgeIndex=0,serial=56:08:1D:26:06:29:06:C7,position=C800),Product "Vindue 3" / WINDOW_OPENER (bridgeIndex=2,serial=56:08:1D:26:06:29:12:03,position=C800).
2019-04-23 14:13:17.697 [INFO ] [.velux.handler.VeluxBridgeHandlerOH1] - Found velux actuators:
	Product "Vindue 2" / WINDOW_OPENER (bridgeIndex=1,serial=56:08:1D:26:06:30:0A:CD,position=C800)
	Product "Vindue 8" / WINDOW_OPENER (bridgeIndex=7,serial=56:08:1D:26:06:29:14:5C,position=C800)
	Product "Vindue 5" / WINDOW_OPENER (bridgeIndex=4,serial=56:08:1D:26:06:29:14:5B,position=C800)
	Product "Vindue 7" / WINDOW_OPENER (bridgeIndex=6,serial=56:08:1D:26:06:29:0D:0D,position=C800)
	Product "Vindue 4" / WINDOW_OPENER (bridgeIndex=3,serial=56:08:1D:26:06:29:08:7B,position=C800)
	Product "Vindue 6" / WINDOW_OPENER (bridgeIndex=5,serial=56:08:1D:26:06:30:0C:A1,position=C800)
	Product "Vindue 1" / WINDOW_OPENER (bridgeIndex=0,serial=56:08:1D:26:06:29:06:C7,position=C800)
	Product "Vindue 3" / WINDOW_OPENER (bridgeIndex=2,serial=56:08:1D:26:06:29:12:03,position=C800)	.
2019-04-23 14:13:17.701 [DEBUG] [idge.slip.SCmodifyHouseStatusMonitor] - getRequestCommand() returns GW_HOUSE_STATUS_MONITOR_ENABLE_REQ (0x240).
2019-04-23 14:13:17.703 [DEBUG] [idge.slip.SCmodifyHouseStatusMonitor] - getRequestDataAsArrayOfBytes() data is .
2019-04-23 14:13:17.704 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(GW_HOUSE_STATUS_MONITOR_ENABLE_REQ,authenticated) called.
2019-04-23 14:13:17.706 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): working on request GW_HOUSE_STATUS_MONITOR_ENABLE_REQ with 0 bytes of data.
2019-04-23 14:13:17.708 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): sending packet of size 7.

gs4711 · April 23, 2019, 12:22pm

This looks fine to me. You have got eigth windows which are currently closed

Kim_Andersen · April 23, 2019, 12:23pm

Right…
All these info I couldn´t get yesterday when I tried

gs4711 · April 23, 2019, 12:29pm

This might occur from an interesting behaviour of the bridge: From time to time it goes into a sleep mode. According to documentation after 15 minutes of inactivity but in several cases the bridges stays alive for even longer times…

Kim_Andersen · April 23, 2019, 12:48pm

Okay I´ll keep an eye on it…

Now next step is to add the windows. I believe they should just be added to the items file, right?. And Rollershutter type like the demo?

gs4711 · April 23, 2019, 12:49pm

Yes, for the time being (up to the release of OH2-fully-compliant binding).

Kim_Andersen · April 23, 2019, 2:03pm

Things seems to be working…
However, there is a very huge delay from changing the value to a window is actually moving (min 40 seconds)… Using the slider and change it several time within a coupple of seconds will somehow lock up the whole system, untill all commands has been done…
Is this normal??

spiff42 · April 23, 2019, 2:20pm

Try

timeoutMsecs=2000
retries=5

That worked much better for me.

Kim_Andersen · April 23, 2019, 2:27pm

Ahh thanks… You´re right, work much faster now.

Kim_Andersen · April 23, 2019, 3:18pm

@gs4711
I think there is still a few problems or missing features…
The time from I change the state of a window to it´s item actual update, there can be more than 2 minutes…

This is a change of my window 5, from 77 to 100: (please notice, I only move the slider from 77 to 100 once).

2019-04-23 17:11:39.053 [ome.event.ItemCommandEvent] - Item 'Vindue05' received command 100
2019-04-23 17:11:39.054 [DEBUG] [.velux.handler.VeluxBridgeHandlerOH1] - handleCommandOnChannel(item=Vindue05,command=100,config=org.openhab.binding.velux.internal.VeluxBindingConfig@482ead,provider=org.openhab.binding.velux.internal.VeluxGenericBindingProvider@a238b0) called.
2019-04-23 17:11:39.072 [vent.ItemStateChangedEvent] - Vindue05 changed from 77 to 100
2019-04-23 17:11:49.926 [DEBUG] [.velux.handler.VeluxBridgeHandlerOH1] - handleCommandOnChannel(): updating Vindue05 to 100.
2019-04-23 17:11:49.928 [DEBUG] [ng.velux.bridge.VeluxBridgeActuators] - updateOH(): updating item Vindue05 to position 77%.
2019-04-23 17:11:49.939 [vent.ItemStateChangedEvent] - Vindue05 changed from 100 to 77
2019-04-23 17:12:06.977 [DEBUG] [ng.velux.bridge.VeluxBridgeActuators] - updateOH(): updating item Vindue05 to position 77%.
2019-04-23 17:13:49.305 [DEBUG] [.velux.handler.VeluxBridgeHandlerOH1] - handleCommandOnChannel(item=Vindue07,command=null,config=org.openhab.binding.velux.internal.VeluxBindingConfig@109b674,provider=org.openhab.binding.velux.internal.VeluxGenericBindingProvider@a238b0) called.
2019-04-23 17:13:49.306 [DEBUG] [ng.velux.bridge.VeluxBridgeActuators] - updateOH(): updating item Vindue05 to position 100%.
2019-04-23 17:13:49.320 [vent.ItemStateChangedEvent] - Vindue05 changed from 77 to 100

What happens inbetween I can not explain, but it looks like the binding still believe the windows is a position 77, even though it moved to 100 at second line above (17:11:39.054 it started moving).
Yet it took 2 minutes and 10 seconds for the binding to recognized the state of 100. (17:13:49.320).

Kim_Andersen · April 23, 2019, 3:22pm

It also seem I cant get rid of the demo actuator even though it´s removed from the item file more than an hour ago:

2019-04-23 17:20:17.354 [INFO ] [.velux.handler.VeluxBridgeHandlerOH1] - handleCommandOnChannel(): cannot work on unknown actuator: 01:02:03:04:05:06:07:08.
2019-04-23 17:20:17.356 [INFO ] [.velux.handler.VeluxBridgeHandlerOH1] - handleCommandOnChannel(): updating of item V_DEMO_SHUTTER (type ACTUATOR_SERIAL) failed.

I wonder where it has this info from.

gs4711 · April 23, 2019, 3:47pm

Caching of the PaperUI? Have had the same problem a while ago when I had deleted some items via the GUI.