[velux] New OpenHAB2 binding - feedback welcome!

openhab2
binding
Tags: #<Tag:0x00007f51efce0020> #<Tag:0x00007f51efcdff08>

(Guenther Schreiner) #104

@Kellermeister
the issue with the missing library is fixed with the recent snapshot, now.


(Christian) #105

Hi @jewesta,

many thanks - will give it a try tomorrow. Meanwhile I’ve set the KLF’s WIFI to “never off”, at least until I got something working :).

Regarding “and use the .things, .items and .cfg files from this thread” I guess I can also fall back to those at https://github.com/gs4711/org.openhab.binding.velux#full-example-for-firmware-version-two?

Danke & Servus!


(Marcel) #106

hi guenther, thanks, the error concerning the library is no longer output.


(Marcel) #107

hi guenther
i executed the delayed execution of the velux commands in debug mode. it took about 10 seconds from the command to the movement of the roller blind.

following the excerpt of the log file:

2019-03-11 19:49:45.998 [ome.event.ItemCommandEvent] - Item 'DgZr_VeluxOben' received command DOWN
==> /var/log/openhab2/openhab.log <==
2019-03-11 19:49:46.004 [DEBUG] [.velux.handler.VeluxBridgeHandlerOH1] - handleCommandOnChannel(item=DgZr_VeluxOben,command=DOWN,config=org.openhab.binding.velux.internal.VeluxBindingConfig@1b358b3,provider=org.openhab.binding.velux.internal.VeluxGenericBindingProvider@a24dd1) called.
==> /var/log/openhab2/events.log <==
2019-03-11 19:49:46.023 [vent.ItemStateChangedEvent] - DgZr_VeluxOben changed from 0 to 100
2019-03-11 19:49:49.275 [vent.ItemStateChangedEvent] - CurrentDateTime changed from 2019-03-11T19:48:49.205+0100 to 2019-03-11T19:49:49.207+0100
==> /var/log/openhab2/openhab.log <==
2019-03-11 19:49:53.158 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): received packet with 13 bytes.
2019-03-11 19:49:53.168 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): working on response GW_GET_STATE_CFM with 6 bytes of data.
2019-03-11 19:49:53.172 [DEBUG] [.velux.bridge.slip.SCgetDeviceStatus] - setResponse(GW_GET_STATE_CFM with 6 bytes of data) called.
2019-03-11 19:49:53.175 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(GW_GET_STATE_REQ) returns success.
2019-03-11 19:49:53.179 [DEBUG] [.velux.handler.VeluxBridgeHandlerOH1] - handleCommandOnChannel(): updating Velux_Status to GW_S_GWM/GW_SS_IDLE.
2019-03-11 19:49:53.189 [DEBUG] [ding.velux.bridge.slip.SCgetProducts] - getRequestCommand() returns GW_GET_ALL_NODES_INFORMATION_REQ (0x202).
2019-03-11 19:49:53.193 [DEBUG] [.binding.velux.internal.VeluxBinding] - execute() done.
2019-03-11 19:49:53.193 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(GW_GET_ALL_NODES_INFORMATION_REQ,authenticated) called.
2019-03-11 19:49:53.197 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): working on request GW_GET_ALL_NODES_INFORMATION_REQ with 0 bytes of data.
2019-03-11 19:49:53.204 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): sending packet of size 7.
==> /var/log/openhab2/events.log <==
2019-03-11 19:50:08.197 [DEBUG] [.binding.velux.internal.VeluxBinding] - execute() called.
2019-03-11 19:50:08.202 [DEBUG] [.velux.handler.VeluxBridgeHandlerOH1] - handleCommandOnChannel(item=Velux_Status,command=null,config=org.openhab.binding.velux.internal.VeluxBindingConfig@1ad6a33,provider=org.openhab.binding.velux.internal.VeluxGenericBindingProvider@a24dd1) called.
2019-03-11 19:50:08.230 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): received packet with 9 bytes.
2019-03-11 19:50:08.236 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): working on response GW_GET_ALL_NODES_INFORMATION_CFM with 2 bytes of data.
2019-03-11 19:50:08.240 [DEBUG] [ding.velux.bridge.slip.SCgetProducts] - setResponse(GW_GET_ALL_NODES_INFORMATION_CFM with 2 bytes of data) called.
2019-03-11 19:50:08.245 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): received packet with 131 bytes.
2019-03-11 19:50:08.290 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): working on response GW_GET_ALL_NODES_INFORMATION_NTF with 124 bytes of data.
2019-03-11 19:50:08.300 [DEBUG] [ding.velux.bridge.slip.SCgetProducts] - setResponse(GW_GET_ALL_NODES_INFORMATION_NTF with 124 bytes of data) called.
2019-03-11 19:50:08.306 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): received packet with 131 bytes.
2019-03-11 19:50:08.329 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): working on response GW_GET_ALL_NODES_INFORMATION_NTF with 124 bytes of data.
2019-03-11 19:50:08.337 [DEBUG] [ding.velux.bridge.slip.SCgetProducts] - setResponse(GW_GET_ALL_NODES_INFORMATION_NTF with 124 bytes of data) called.
2019-03-11 19:50:08.343 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): received packet with 131 bytes.
2019-03-11 19:50:08.356 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): working on response GW_GET_ALL_NODES_INFORMATION_NTF with 124 bytes of data.
2019-03-11 19:50:08.361 [DEBUG] [ding.velux.bridge.slip.SCgetProducts] - setResponse(GW_GET_ALL_NODES_INFORMATION_NTF with 124 bytes of data) called.
2019-03-11 19:50:08.364 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): received packet with 131 bytes.
2019-03-11 19:50:08.375 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): working on response GW_GET_ALL_NODES_INFORMATION_NTF with 124 bytes of data.
2019-03-11 19:50:08.378 [DEBUG] [ding.velux.bridge.slip.SCgetProducts] - setResponse(GW_GET_ALL_NODES_INFORMATION_NTF with 124 bytes of data) called.
2019-03-11 19:50:08.381 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): received packet with 7 bytes.
2019-03-11 19:50:08.384 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): working on response GW_GET_ALL_NODES_INFORMATION_FINISHED_NTF with 0 bytes of data.
2019-03-11 19:50:08.385 [DEBUG] [ding.velux.bridge.slip.SCgetProducts] - setResponse(GW_GET_ALL_NODES_INFORMATION_FINISHED_NTF with 0 bytes of data) called.
2019-03-11 19:50:08.387 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(GW_GET_ALL_NODES_INFORMATION_REQ) returns success.
2019-03-11 19:50:08.390 [DEBUG] [ng.velux.bridge.VeluxBridgeActuators] - getProducts() storing updates for product Product "DgZr_RolloOben" / SOLAR_SLIDER (bridgeIndex=0,serial=53:14:1E:26:12:25:03:68,position=0000).
2019-03-11 19:50:08.391 [DEBUG] [g.velux.things.VeluxExistingProducts] - update(bridgeProductIndex=0,productState=5,productPosition=0,productTarget=0) called.
2019-03-11 19:50:08.394 [DEBUG] [ng.velux.bridge.VeluxBridgeActuators] - getProducts() storing updates for product Product "DgZr_RolloUnten" / SOLAR_SLIDER (bridgeIndex=1,serial=53:14:1E:26:12:25:03:73,position=0000).
2019-03-11 19:50:08.396 [DEBUG] [g.velux.things.VeluxExistingProducts] - update(bridgeProductIndex=1,productState=5,productPosition=0,productTarget=0) called.
2019-03-11 19:50:08.398 [DEBUG] [ng.velux.bridge.VeluxBridgeActuators] - getProducts() storing updates for product Product "DgZl_RolloOben" / SOLAR_SLIDER (bridgeIndex=2,serial=53:14:1E:32:12:25:06:F8,position=0000).
2019-03-11 19:50:08.400 [DEBUG] [g.velux.things.VeluxExistingProducts] - update(bridgeProductIndex=2,productState=5,productPosition=0,productTarget=0) called.
2019-03-11 19:50:08.402 [DEBUG] [ng.velux.bridge.VeluxBridgeActuators] - getProducts() storing updates for product Product "DgZl_RolloUnten" / SOLAR_SLIDER (bridgeIndex=3,serial=53:14:1E:32:12:25:06:FF,position=0000).
2019-03-11 19:50:08.406 [DEBUG] [g.velux.things.VeluxExistingProducts] - update(bridgeProductIndex=3,productState=5,productPosition=0,productTarget=0) called.
2019-03-11 19:50:08.410 [DEBUG] [ng.velux.bridge.VeluxBridgeActuators] - getProducts() finally has found products 4 members: Product "DgZr_RolloUnten" / SOLAR_SLIDER (bridgeIndex=1,serial=53:14:1E:26:12:25:03:73,position=0000),Product "DgZl_RolloOben" / SOLAR_SLIDER (bridgeIndex=2,serial=53:14:1E:32:12:25:06:F8,position=0000),Product "DgZl_RolloUnten" / SOLAR_SLIDER (bridgeIndex=3,serial=53:14:1E:32:12:25:06:FF,position=0000),Product "DgZr_RolloOben" / SOLAR_SLIDER (bridgeIndex=0,serial=53:14:1E:26:12:25:03:68,position=0000).
2019-03-11 19:50:08.413 [DEBUG] [.velux.handler.VeluxBridgeHandlerOH1] - handleCommandOnChannel(): sending command with target level 100.
2019-03-11 19:50:08.418 [DEBUG] [ding.velux.bridge.slip.SCsendCommand] - setNodeAndMainParameter(0) called.
2019-03-11 19:50:08.421 [DEBUG] [ding.velux.bridge.slip.SCsendCommand] - getRequestCommand() returns 0x300.
2019-03-11 19:50:08.424 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(GW_COMMAND_SEND_REQ,authenticated) called.
2019-03-11 19:50:08.427 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): working on request GW_COMMAND_SEND_REQ with 66 bytes of data.
2019-03-11 19:50:08.432 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): sending packet of size 73.
==> /var/log/openhab2/events.log <==
2019-03-11 19:50:10.322 [vent.ItemStateChangedEvent] - DgZr_Lichtschalter_SwitchLicht changed from ON to OFF
2019-03-11 19:50:10.358 [vent.ItemStateChangedEvent] - NoOfLights changed from 10 to 9
==> /var/log/openhab2/openhab.log <==
2019-03-11 19:50:23.435 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): received packet with 10 bytes.
2019-03-11 19:50:23.439 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): working on response GW_COMMAND_SEND_CFM with 3 bytes of data.
2019-03-11 19:50:23.441 [DEBUG] [ding.velux.bridge.slip.SCsendCommand] - setResponse(GW_COMMAND_SEND_CFM with 3 bytes of data) called.
2019-03-11 19:50:23.444 [DEBUG] [ding.velux.bridge.slip.SCsendCommand] - setResponse(): returned status: OK - Command is accepted.
2019-03-11 19:50:23.447 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): received packet with 27 bytes.
2019-03-11 19:50:23.451 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): working on response GW_NODE_STATE_POSITION_CHANGED_NTF with 20 bytes of data.
2019-03-11 19:50:23.453 [DEBUG] [ng.velux.bridge.slip.SCreceiveStatus] - setResponse(GW_NODE_STATE_POSITION_CHANGED_NTF with 20 bytes of data) called.
2019-03-11 19:50:23.455 [DEBUG] [g.velux.things.VeluxExistingProducts] - update(bridgeProductIndex=0,productState=2,productPosition=0,productTarget=51200) called.
2019-03-11 19:50:23.457 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): received packet with 20 bytes.
2019-03-11 19:50:23.461 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): working on response GW_COMMAND_RUN_STATUS_NTF with 13 bytes of data.
2019-03-11 19:50:23.463 [DEBUG] [ding.velux.bridge.slip.SCsendCommand] - setResponse(GW_COMMAND_RUN_STATUS_NTF with 13 bytes of data) called.
2019-03-11 19:50:23.465 [DEBUG] [ding.velux.bridge.slip.SCsendCommand] - setResponse(): ntfSessionID=1272 (requested 1272).
2019-03-11 19:50:23.466 [DEBUG] [ding.velux.bridge.slip.SCsendCommand] - setResponse(): ntfStatusiD=8.
2019-03-11 19:50:23.468 [DEBUG] [ding.velux.bridge.slip.SCsendCommand] - setResponse(): ntfIndex=0.
2019-03-11 19:50:23.470 [DEBUG] [ding.velux.bridge.slip.SCsendCommand] - setResponse(): ntfNodeParameter=0.
2019-03-11 19:50:23.472 [DEBUG] [ding.velux.bridge.slip.SCsendCommand] - setResponse(): ntfParameterValue=0.
2019-03-11 19:50:23.473 [DEBUG] [ding.velux.bridge.slip.SCsendCommand] - setResponse(): ntfRunStatus=2.
2019-03-11 19:50:23.475 [DEBUG] [ding.velux.bridge.slip.SCsendCommand] - setResponse(): ntfStatusReply=1.
2019-03-11 19:50:23.477 [DEBUG] [ding.velux.bridge.slip.SCsendCommand] - setResponse(): ntfInformationCode=106955776.
2019-03-11 19:50:23.479 [DEBUG] [ding.velux.bridge.slip.SCsendCommand] - setResponse(): returned ntfRunStatus: EXECUTION_ACTIVE.
2019-03-11 19:50:23.481 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): received packet with 13 bytes.
2019-03-11 19:50:23.484 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): working on response GW_COMMAND_REMAINING_TIME_NTF with 6 bytes of data.
2019-03-11 19:50:23.486 [DEBUG] [ding.velux.bridge.slip.SCsendCommand] - setResponse(GW_COMMAND_REMAINING_TIME_NTF with 6 bytes of data) called.
2019-03-11 19:50:23.487 [DEBUG] [ding.velux.bridge.slip.SCsendCommand] - setResponse(): timeNtfSessionID=1272.
2019-03-11 19:50:23.489 [DEBUG] [ding.velux.bridge.slip.SCsendCommand] - setResponse(): timeNtfIndex=0.
2019-03-11 19:50:23.491 [DEBUG] [ding.velux.bridge.slip.SCsendCommand] - setResponse(): timeNtfNodeParameter=0.
2019-03-11 19:50:23.493 [DEBUG] [ding.velux.bridge.slip.SCsendCommand] - setResponse(): timeNtfSeconds=32.
2019-03-11 19:50:23.495 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): received packet with 27 bytes.
2019-03-11 19:50:23.499 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): working on response GW_NODE_STATE_POSITION_CHANGED_NTF with 20 bytes of data.
2019-03-11 19:50:23.501 [DEBUG] [ng.velux.bridge.slip.SCreceiveStatus] - setResponse(GW_NODE_STATE_POSITION_CHANGED_NTF with 20 bytes of data) called.
2019-03-11 19:50:23.503 [DEBUG] [g.velux.things.VeluxExistingProducts] - update(bridgeProductIndex=0,productState=4,productPosition=0,productTarget=51200) called.
==> /var/log/openhab2/events.log <==
2019-03-11 19:50:42.644 [vent.ItemStateChangedEvent] - DgZr_Lichtschalter_SwitchLicht changed from OFF to ON
2019-03-11 19:50:42.683 [vent.ItemStateChangedEvent] - NoOfLights changed from 9 to 10
2019-03-11 19:50:42.689 [vent.ItemStateChangedEvent] - DgZr_RoomData_IconLowerRight changed from light_off.svg to light_on.svg
==> /var/log/openhab2/openhab.log <==
2019-03-11 19:50:45.167 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): received packet with 20 bytes.
2019-03-11 19:50:45.177 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): working on response GW_COMMAND_RUN_STATUS_NTF with 13 bytes of data.
2019-03-11 19:50:45.183 [DEBUG] [ding.velux.bridge.slip.SCsendCommand] - setResponse(GW_COMMAND_RUN_STATUS_NTF with 13 bytes of data) called.
2019-03-11 19:50:45.188 [DEBUG] [ding.velux.bridge.slip.SCsendCommand] - setResponse(): ntfSessionID=1272 (requested 1272).
2019-03-11 19:50:45.193 [DEBUG] [ding.velux.bridge.slip.SCsendCommand] - setResponse(): ntfStatusiD=8.
2019-03-11 19:50:45.198 [DEBUG] [ding.velux.bridge.slip.SCsendCommand] - setResponse(): ntfIndex=0.
2019-03-11 19:50:45.203 [DEBUG] [ding.velux.bridge.slip.SCsendCommand] - setResponse(): ntfNodeParameter=0.
2019-03-11 19:50:45.207 [DEBUG] [ding.velux.bridge.slip.SCsendCommand] - setResponse(): ntfParameterValue=51200.
2019-03-11 19:50:45.212 [DEBUG] [ding.velux.bridge.slip.SCsendCommand] - setResponse(): ntfRunStatus=0.
2019-03-11 19:50:45.217 [DEBUG] [ding.velux.bridge.slip.SCsendCommand] - setResponse(): ntfStatusReply=1.
2019-03-11 19:50:45.222 [DEBUG] [ding.velux.bridge.slip.SCsendCommand] - setResponse(): ntfInformationCode=543163648.
2019-03-11 19:50:45.230 [DEBUG] [ding.velux.bridge.slip.SCsendCommand] - setResponse(): returned ntfRunStatus: EXECUTION_COMPLETED.
2019-03-11 19:50:45.234 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): received packet with 9 bytes.
2019-03-11 19:50:45.239 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): working on response GW_SESSION_FINISHED_NTF with 2 bytes of data.
2019-03-11 19:50:45.243 [DEBUG] [ding.velux.bridge.slip.SCsendCommand] - setResponse(GW_SESSION_FINISHED_NTF with 2 bytes of data) called.
2019-03-11 19:50:45.246 [DEBUG] [ding.velux.bridge.slip.SCsendCommand] - setResponse(): finishedNtfSessionID=1272.
2019-03-11 19:50:45.249 [DEBUG] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(GW_COMMAND_SEND_REQ) returns success.
2019-03-11 19:50:45.252 [DEBUG] [.velux.bridge.VeluxBridgeSendCommand] - sendCommand() finished successfully.
2019-03-11 19:50:45.254 [DEBUG] [.velux.handler.VeluxBridgeHandlerOH1] - handleCommandOnChannel(): updating DgZr_VeluxOben to 100.
2019-03-11 19:50:45.256 [DEBUG] [ng.velux.bridge.VeluxBridgeActuators] - updateOH(): updating item DgZr_VeluxOben to position 0%.

Do you see anything about long reaction time?


(Jens W.) #108

Yes, I did that as well. What were they thinking! :slight_smile: The API-Password is printed on the back and cannot be changed, but for security reasons no UI access over Ethernet… :thinking: Okay.

Confession: I cannot currently get the binding to work, so I am not 100% sure what the minimum requirements for a working testing scenario are. I am in talks with @gs4711 who is kindly assisting me to find the problem. We both don’t know what’s going on yet. Maybe the problem sits in front of the screen. :wink: OpenHAB connects to the KLF200 successfully but somehow fails to load the registered blinds. In theory, with the following configuration, the binding should connect to the KLF and print a list of discovered devices to the logs.

velux.cfg:

bridgeIPAddress=*.*.*.*
bridgeProtocol=slip
bridgeTCPPort=51200
bridgePassword=***
timeoutMsecs=2000
retries=6

velux.items:

String V_FIRMWARE "Firmware [%s]" {velux="thing=bridge;channel=firmware"}
String V_STATUS "Status [%s]" {velux="thing=bridge;channel=status"}
String V_CHECK "Velux Config Check [%s]" {velux="thing=bridge;channel=check"}

velux.things:

Bridge velux:klf200:home [bridgeIPAddress="*.*.*.*", bridgeProtocol="slip", bridgeTCPPort=51200, bridgePassword="***", timeoutMsecs=15000, retries=15]

org.ops4j.pax.logging.cfg:

# Velux
log4j2.logger.velux.name = org.openhab.binding.velux
log4j2.logger.velux.level = ALL

Cheers,
Jens :slight_smile:


(Christian) #109

Hi there,

what I’ve done so far;

  1. uploaded org.openhab.binding.velux-1.14.0-SNAPSHOT-20190312.jar to /usr/share/openhab2/addons
  2. created velux.cfg with the content above in /etc/openhab2/services ([bridgeIPAddress] and [bridgePassword] altered of course)
  3. created velux.items with the content above in /etc/openhab2/items
  4. created velux.things with the content above in /etc/openhab2/things ([bridgeIPAddress] and [bridgePassword] altered of course)

I get the following errors (in 6 pairs, according to the [retries] setting);

2019-03-13 16:43:09.503 [WARN ] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): raised an error during sending: Connection has been shutdown: javax.net.ssl.SSLException: java.net.SocketException: Connection reset.
2019-03-13 16:43:11.504 [WARN ] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): Exception occurred during I/O: Connection has been shutdown: javax.net.ssl.SSLException: java.net.SocketException: Connection reset.

finally resulting in…

2019-03-13 16:47:33.527 [INFO ] [ng.velux.bridge.slip.SlipVeluxBridge] - io(): socket I/O failed 6 times.
2019-03-13 16:47:33.528 [INFO ] [g.velux.bridge.slip.io.SSLconnection] - Shutting down Velux bridge connection.
2019-03-13 16:47:33.528 [WARN ] [ng.velux.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): method io() raised an error: Connection has been shutdown: javax.net.ssl.SSLException: java.net.SocketException: Connection reset.
2019-03-13 16:47:33.529 [WARN ] [.velux.handler.VeluxBridgeHandlerOH1] - velux bridge login sequence failed; expecting bridge is OFFLINE.
2019-03-13 16:47:33.531 [INFO ] [g.velux.bridge.slip.io.SSLconnection] - Starting velux bridge connection.
2019-03-13 16:47:40.217 [INFO ] [.velux.handler.VeluxBridgeHandlerOH1] - handleCommandOnChannel(): updating of item V_STATUS (type BRIDGE_STATUS) failed.
2019-03-13 16:47:57.221 [WARN ] [.velux.handler.VeluxBridgeHandlerOH1] - velux bridge login sequence failed; expecting bridge is OFFLINE.

The last two lines are repeated continuously. I also rebooted the KLF200 in order to “reactivate” the bridge-gateway.

Thanks & BR,
Chris


(Christian) #110

First of all thanks for the great work with this binding. I am using the 2.4 version of it with Openhab 2 and it works very well. Since I am using the old firmware version and I want to upgrade because of the API advantages I would like to know if the version 1 of the binding ist working well with Openhab 2? Are there any issues downgrading the binding version? Since the firmware downgrade is not working I would like to ask you if someone can give me some information related to this. Thanks in advance.

Br, Christian


(Guenther Schreiner) #111

If you start with a plain openHAB2, you have to activate the OH1 compatibility layer, i.e. with the console by applying the command

feature:install openhab-runtime-compat1x

This will eliminate errors like missing libraries. When you create the basic configuration of the service, i.e. the file services/velux.cfg with

bridgeIPAddress=192.168.45.42
bridgeProtocol=slip
bridgeTCPPort=51200
bridgePassword=WLAN-Password-from-the-label
timeoutMsecs=500
refresh=300000

this should lead to a basic initialization of the module, resulting in log lines like

2019-03-14 21:57:07.681 [INFO ] [b.core.service.AbstractActiveService] - velux Refresh Service has been started
2019-03-14 21:58:13.821 [INFO ] [.binding.velux.internal.VeluxBinding] - veluxConfig[bridgeProtocol=slip,bridgeIPAddress=192.168.45.42,bridgeTCPPort=51200,bridgePassword=********,timeoutMsecs=500,retries=6,refreshMsecs=300000,isBulkRetrievalEnabled=true]

Adding some items, i.e. with the file items/velux.items with

String V_FIRMWARE "Firmware [%s]" {velux="thing=bridge;channel=firmware"}
String V_STATUS "Status [%s]" {velux="thing=bridge;channel=status"}
Rollershutter V_DG_M_W	"DG Window Bath [%d]"		{ velux="thing=actuator;channel=serial#56:23:3E:26:0C:1B:00:10" }

there should be some logging visible like

2019-03-14 21:59:08.000 [INFO ] [el.core.internal.ModelRepositoryImpl] - Refreshing model 'velux.items'
2019-03-14 21:59:08.102 [INFO ] [g.velux.bridge.slip.io.SSLconnection] - Starting velux bridge connection.
2019-03-14 21:59:15.126 [INFO ] [ab.binding.velux.bridge.slip.SClogin] - velux bridge connection successfully established (login succeeded).
2019-03-14 21:59:18.233 [INFO ] [.velux.handler.VeluxBridgeHandlerOH1] - Found velux scenes:
	Scene "V_DG_Shutter_West_100" (index 5) with non-silent mode and 0 actions
	Scene "V_DG_Shutter_West_000" (index 4) with non-silent mode and 0 actions
	Scene "V_DG_Shutter_Ost_090" (index 10) with non-silent mode and 0 actions
2019-03-14 21:59:19.173 [INFO ] [.velux.handler.VeluxBridgeHandlerOH1] - Found velux actuators:
	Product "DG_M_Window" / WINDOW_OPENER (bridgeIndex=0,serial=56:23:3E:26:0C:1B:00:10,position=C800)
2019-03-14 21:59:19.181 [INFO ] [.velux.handler.VeluxBridgeHandlerOH1] - velux Bridge is online, now.

After creating a sitemap sitemap/default.sitemap for example

sitemap default label="Velux Demo"
{
        Frame label="Actuators" {
                Text    item=V_FIRMWARE
                Text    item=V_STATUS
                Switch  item=V_DG_M_W
        }
}

the binding will confirm this configuration with logging like:

2019-03-14 22:15:09.044 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'default.sitemap'
2019-03-14 22:15:10.389 [INFO ] [el.core.internal.ModelRepositoryImpl] - Refreshing model 'default.sitemap'

Then, try to control the actuators via the openHAB web at https://this.is.my.openhab/basicui/app


(Guenther Schreiner) #112

@Kellermeister,
tried to scrutinze the delay …having set up a tiny OH2 with only the velux binding on a PI3B. The delay between button press (PaperUI) and the action of the window is less than a second.

Regards, Guenther


(Christian) #113

Hi @gs4711,

many thanks for that!

2019-03-15 18:23:44.138 [INFO ] [ab.binding.velux.bridge.slip.SClogin] - velux bridge connection successfully established (login succeeded).

I just get the following errors (index0-4):

2019-03-15 18:25:48.929 [WARN ] [g.velux.things.VeluxExistingProducts] - update() failed as actuator (with index 0) is not registered.

Don’t know how often I clicked on the “register” icon within the web interface and pushed the reset-button on my 3UR remote control.


(Guenther Schreiner) #114

Hi Chris (@csi_oh),

thanks for the explanation. I’m doubting that we have go one step back to verify the initial connection: Did the binding show a successfull connection with a mandatory logging entry like

[ab.binding.velux.bridge.slip.SClogin] - velux bridge connection successfully established (login succeeded).

Regards, Guenther


(Guenther Schreiner) #115

Hello Christian (@kutzi),
downgrading of the binding is not an issue. But be aware that an upgrade of the KLF200 is irreversible: AFAIK there is no way back to the v1 firmware.

Best regards, Guenther


(Christian) #116

hi Guenther,

Thanks for the detailed explanation above. I guess I will try to upgrade the firmware and switch then to the version 1 of the binding by using the compatibility layer.
I will report my progress. Thanks for the support again.

Br, Christian


(Christian) #117

Servus Guenther,

thx 4 your reply. Yes, OH is successfully connecting to my KLF200.

2019-03-15 18:23:44.138 [INFO ] [ab.binding.velux.bridge.slip.SClogin] - velux bridge connection successfully established (login succeeded).

At the moment I’ve got 5 rollershutters (a sixth is not power-wired yet), my KLF200 recognised all of them (so when I click the “identify” button every single one is moving accordingly). Also, your binding is perfectly fine as these five are found by it.

But these reading attempts lead to the following warning;

2019-03-15 18:25:48.929 [WARN ] [g.velux.things.VeluxExistingProducts] - update() failed as actuator (with index 0) is not registered.

So I think there might be something I’m missing on the “KLF-side”. On the actuator page I can see all rollershutters (I’ve renamed them) and next to it there are two icons, “identify” and “register”. “Identify” works as they’re physically moving after I click on it. When I click on “register” some sort of manual tells me that I’ve to press the “RESET” button on my 3UR remote control for 1sec. Doesn’t matter how often I do that, I still get the same warnings in OH, telling me that the actuator(s) are not registered.

Many thanks in advance,
Chris


(Guenther Schreiner) #118

Christian,

Today, I have just got a notice about similar issue from another user: there is a possible race condition, which should be fixed now. I can confirm that this is a bug (but I cannot explain why to never occured on my PIs).

BTW are there any messages after the mentioned warning

like
...bridgeParamsUpdated(): Fetching existing actuators/products
within your logfiles?

BR Guenther


(Christian) #119

Hi Guenther,

unfortunately I can’t dive into your link because “I don’t have access to this topic”.

I’ll try your recent snapshot just right after posting (will provide updates of course) - for the moment i stopped the binding via KARAF.

I can tell you that there are no further messages after the “not registered” warning. I’ve never seen

...bridgeParamsUpdated(): Fetching existing actuators/products

or something similar before.

See you in a few minutes,
Chris


(Guenther Schreiner) #120

sorry. Didn’t know that there might be limitions. But you’ve already got the information about the new .jar file.


(Christian) #121

Hi Guenther,

please find the current log below (unfortunately still the same issue).

2019-03-16 17:26:00.698 [INFO ] [inding.velux.internal.VeluxActivator] - velux binding has been started.
2019-03-16 17:26:01.285 [INFO ] [.binding.velux.internal.VeluxBinding] - Active items are: [V_FIRMWARE, V_STATUS].
2019-03-16 17:26:01.355 [INFO ] [.binding.velux.internal.VeluxBinding] - velux refresh interval set to 15000 milliseconds.
2019-03-16 17:26:01.432 [INFO ] [.binding.velux.internal.VeluxBinding] - veluxConfig[bridgeProtocol=slip,bridgeIPAddress=X.X.X.X,bridgeTCPPort=51200,bridgePassword=**********,timeoutMsecs=500,retries=15,refreshMsecs=15000,isBulkRetrievalEnabled=true]
2019-03-16 17:26:01.440 [INFO ] [b.core.service.AbstractActiveService] - velux Refresh Service has been started
2019-03-16 17:26:01.488 [INFO ] [g.velux.bridge.slip.io.SSLconnection] - Starting velux bridge connection.
2019-03-16 17:26:06.312 [INFO ] [ab.binding.velux.bridge.slip.SClogin] - velux bridge connection successfully established (login succeeded).
2019-03-16 17:29:22.598 [WARN ] [g.velux.things.VeluxExistingProducts] - update() failed as actuator (with index 3) is not registered.
2019-03-16 17:31:22.588 [WARN ] [g.velux.things.VeluxExistingProducts] - update() failed as actuator (with index 0) is not registered.
2019-03-16 17:31:23.646 [WARN ] [g.velux.things.VeluxExistingProducts] - update() failed as actuator (with index 1) is not registered.
2019-03-16 17:31:24.711 [WARN ] [g.velux.things.VeluxExistingProducts] - update() failed as actuator (with index 2) is not registered.
2019-03-16 17:31:25.809 [WARN ] [g.velux.things.VeluxExistingProducts] - update() failed as actuator (with index 4) is not registered.

I’m using org.openhab.binding.velux-1.14.0-SNAPSHOT-20190316.jar in /usr/share/openhab2/addons, according to KARAFs [bundle:list] the integration was successful;

256 │ Active   │  80 │ 1.14.0.201903161510    │ openHAB Velux Binding

Thanks & LG,
Chris


(Guenther Schreiner) #122

Chris,
there is an issue with the binding when there are no scenes defined. Jens is, in a parallel thread, about to test a patched release org.openhab.binding.velux-1.14.0.201903161709.jar . Just waiting for his response (as I do not like to remove the scenes from my KLF200).


(Guenther Schreiner) #123

Just got the feedback: The binding org.openhab.binding.velux-1.14.0.201903161709.jar fixes the issue when there any no scenes defined.