[velux] login sequence failed after upgrade to v3.2.0M4

Hi, just upgraded to OH 3.2.0M4 and cannot connect to velux bridge anymore. I get the following error

Login sequence failed.

Tried several reboots, restart of binding through karaf console, restart through suggested rule and reboot of KLF200 but nothing works. The bridge remains in status “offline - configuration error”.
Set log at debug level, here is the log

2021-11-16 12:03:53.811 [DEBUG] [nternal.bridge.slip.io.SSLconnection] - SSLconnection() called.
2021-11-16 12:03:54.934 [DEBUG] [internal.bridge.slip.SCgetLimitation] - SCgetLimitation(Constructor) called.
2021-11-16 12:03:54.936 [DEBUG] [internal.bridge.slip.SCgetLimitation] - SCgetLimitation(): starting sessions with the random number 407.
2021-11-16 12:03:54.950 [DEBUG] [rnal.bridge.slip.SCrunProductCommand] - SCgetProduct(Constructor) called.
2021-11-16 12:03:54.956 [DEBUG] [rnal.bridge.slip.SCrunProductCommand] - SCgetProduct(): starting sessions with the random number 3024.
2021-11-16 12:03:54.963 [DEBUG] [idge.slip.SCrunProductIdentification] - SCrunProductIdentification(Constructor) called.
2021-11-16 12:03:54.965 [DEBUG] [idge.slip.SCrunProductIdentification] - SCrunProductIdentification(): starting sessions with the random number 681.
2021-11-16 12:03:54.970 [DEBUG] [elux.internal.bridge.slip.SCrunScene] - SCrunScene(Constructor) called.
2021-11-16 12:03:54.971 [DEBUG] [elux.internal.bridge.slip.SCrunScene] - SCrunScene(): starting sessions with the random number 1610.
2021-11-16 12:03:54.978 [DEBUG] [internal.bridge.slip.SCsetLimitation] - SCsetLimitation(Constructor) called.
2021-11-16 12:03:54.980 [DEBUG] [internal.bridge.slip.SCsetLimitation] - SCsetLimitation(): starting sessions with the random number 3610.
2021-11-16 12:03:55.005 [DEBUG] [.internal.handler.VeluxBridgeHandler] - Creating a VeluxBridgeHandler for thing 'velux:klf200:velux_klf200'.
2021-11-16 12:03:55.036 [DEBUG] [.binding.velux.internal.VeluxBinding] - veluxConfig[protocol=slip,ipAddress=192.168.2.124,tcpPort=51200,password=**********,timeoutMsecs=3000,retries=5,refreshMsecs=10000,isBulkRetrievalEnabled=true,isSequentialEnforced=false,isProtocolTraceEnabled=false]
2021-11-16 12:03:55.060 [DEBUG] [.velux.internal.handler.VeluxHandler] - initialize(): Initializing thing velux:rollershutter:velux_klf200:velux_est_tent in combination with bridge org.openhab.core.thing.internal.BridgeImpl@1af0df5c.
2021-11-16 12:03:55.082 [WARN ] [ab.binding.mqtt.generic.ChannelState] - Command 'Offline' not supported by type 'OnOffValue': No enum constant org.openhab.core.library.types.OnOffType.Offline
2021-11-16 12:03:55.751 [DEBUG] [.internal.handler.VeluxBridgeHandler] - bridgeParamsUpdated() called.
2021-11-16 12:03:55.752 [DEBUG] [.internal.handler.VeluxBridgeHandler] - bridgeParamsUpdated(): choosing SLIP as communication method.
2021-11-16 12:03:55.754 [DEBUG] [internal.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate() [192.168.2.124] GW_PASSWORD_ENTER_REQ => started => Thread[OH-thingHandler-5,5,main] 
2021-11-16 12:03:55.760 [DEBUG] [internal.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate() [192.168.2.124] GW_PASSWORD_ENTER_REQ => GW_PASSWORD_ENTER_REQ => sending data length => 32
2021-11-16 12:03:55.761 [DEBUG] [nternal.bridge.slip.io.SSLconnection] - close() called.
2021-11-16 12:03:55.762 [DEBUG] [nternal.bridge.slip.io.SSLconnection] - Starting velux bridge connection.
2021-11-16 12:03:55.772 [INFO ] [x.internal.bridge.slip.io.Connection] - io() on 192.168.2.124: Exception occurred during I/O: raised a non-recoverable error during connection setup: Connection refused (Connection refused).
2021-11-16 12:03:58.773 [DEBUG] [nternal.bridge.slip.io.SSLconnection] - close() called.
2021-11-16 12:03:58.774 [DEBUG] [nternal.bridge.slip.io.SSLconnection] - Starting velux bridge connection.
2021-11-16 12:03:58.777 [INFO ] [x.internal.bridge.slip.io.Connection] - io() on 192.168.2.124: Exception occurred during I/O: raised a non-recoverable error during connection setup: Connection refused (Connection refused).
2021-11-16 12:04:03.588 [DEBUG] [rnal.discovery.VeluxDiscoveryService] - startScan(): creating a thing of type binding.
2021-11-16 12:04:03.591 [DEBUG] [rnal.discovery.VeluxDiscoveryService] - startScan(): registering new thing DiscoveryResult [thingUID=velux:binding:org_openhab_binding_velux, properties={bundleVersion=org.openhab.binding.velux_3.2.0.M4 [376]}, representationProperty=bundleVersion, flag=NEW, label=Velux Binding Information Element, bridgeUID=null, ttl=-1, timestamp=1637060643590].
2021-11-16 12:04:03.599 [DEBUG] [rnal.discovery.VeluxDiscoveryService] - startScan(): VeluxDiscoveryService cannot proceed due to missing Velux bridge(s).
2021-11-16 12:04:03.965 [DEBUG] [.velux.internal.handler.VeluxHandler] - initialize(): Initializing thing velux:rollershutter:velux_klf200:velux_ovest_rollershutter in combination with bridge org.openhab.core.thing.internal.BridgeImpl@1af0df5c.
2021-11-16 12:04:03.974 [DEBUG] [.velux.internal.handler.VeluxHandler] - initialize(): Initializing thing velux:rollershutter:velux_klf200:velux_est_rollershutter in combination with bridge org.openhab.core.thing.internal.BridgeImpl@1af0df5c.
2021-11-16 12:04:03.982 [DEBUG] [.velux.internal.handler.VeluxHandler] - initialize(): Initializing thing velux:scene:velux_klf200:velux_scene_allclosed in combination with bridge org.openhab.core.thing.internal.BridgeImpl@1af0df5c.
2021-11-16 12:04:03.992 [DEBUG] [.velux.internal.handler.VeluxHandler] - initialize(): Initializing thing velux:window:velux_klf200:velux_est_window in combination with bridge org.openhab.core.thing.internal.BridgeImpl@1af0df5c.
2021-11-16 12:04:03.999 [DEBUG] [.velux.internal.handler.VeluxHandler] - initialize(): Initializing thing velux:rollershutter:velux_klf200:velux_ovest_tent in combination with bridge org.openhab.core.thing.internal.BridgeImpl@1af0df5c.
2021-11-16 12:04:04.007 [DEBUG] [.velux.internal.handler.VeluxHandler] - initialize(): Initializing thing velux:window:velux_klf200:velux_ovest_window in combination with bridge org.openhab.core.thing.internal.BridgeImpl@1af0df5c.
2021-11-16 12:04:04.778 [DEBUG] [nternal.bridge.slip.io.SSLconnection] - close() called.
2021-11-16 12:04:04.779 [DEBUG] [nternal.bridge.slip.io.SSLconnection] - Starting velux bridge connection.
2021-11-16 12:04:04.783 [INFO ] [x.internal.bridge.slip.io.Connection] - io() on 192.168.2.124: Exception occurred during I/O: raised a non-recoverable error during connection setup: Connection refused (Connection refused).
2021-11-16 12:04:16.784 [DEBUG] [nternal.bridge.slip.io.SSLconnection] - close() called.
2021-11-16 12:04:16.787 [DEBUG] [nternal.bridge.slip.io.SSLconnection] - Starting velux bridge connection.
2021-11-16 12:04:16.790 [INFO ] [x.internal.bridge.slip.io.Connection] - io() on 192.168.2.124: Exception occurred during I/O: raised a non-recoverable error during connection setup: Connection refused (Connection refused).
2021-11-16 12:04:17.346 [INFO ] [control.internal.WebSocketConnection] - Web Socket close 1005. Reason: null
2021-11-16 12:04:40.791 [DEBUG] [nternal.bridge.slip.io.SSLconnection] - close() called.
2021-11-16 12:04:40.792 [DEBUG] [nternal.bridge.slip.io.SSLconnection] - Starting velux bridge connection.
2021-11-16 12:04:40.796 [INFO ] [x.internal.bridge.slip.io.Connection] - io() on 192.168.2.124: Exception occurred during I/O: raised a non-recoverable error during connection setup: Connection refused (Connection refused).
2021-11-16 12:04:57.952 [INFO ] [control.internal.WebSocketConnection] - Web Socket close 1005. Reason: null
2021-11-16 12:05:28.797 [DEBUG] [nternal.bridge.slip.io.SSLconnection] - close() called.
2021-11-16 12:05:28.798 [DEBUG] [nternal.bridge.slip.io.SSLconnection] - Starting velux bridge connection.
2021-11-16 12:05:28.803 [INFO ] [x.internal.bridge.slip.io.Connection] - io() on 192.168.2.124: Exception occurred during I/O: raised a non-recoverable error during connection setup: Connection refused (Connection refused).

Anyone having same issue?
thx

Yes exactly the same problem! I did not do an upgrade I am still on M3 and the binding is M3 I just did a reboot and now it won’t login.

update:

I managed to get it back up again - I think the klf200 sometimes gets stuck. I had to unplug it for a while then restarted everything including the openhab server and it finally came back online.

HI Julian, I tried many times to unplug and re-plug with no success. I think the key thing here is unplug it for a while, that works. Thanks!

Yeah. It is the infamous zombie socket problem. You will find more on this in the main Velux thread. But the short answer is to DISABLE the Velux hub things a few minutes before shutting down (or upgrading) your system. And the ENABLE them again once everything else is up and running.

Hi Andrew. I don’t know when that issue started but it is totally annoying that out of the sudden this “raised a non-recoverable error during connection setup” is happening. My velux items (and I have 12 shutters controlled) get useless with this issue happening every couple of days. Is this a software or a hardware issue? Where is the main thread you’re referring to? Sorry but I’m really desperate…

This sounds to be a hardware issue to me, as my velux items (two roof windows and two shutters on top) are not showing this behaviour on openHAB 3.4.1

What OH version are you running? Did you recently upgrade versions? And can you please post the exact log entries?

Back to this thread I meanwhile bough a new KLF200 in desperation which shows exactly the same… I try to nail this now down and am really glad of the super support that you provide here. Shall I continue in this thread or open a new one? As the two links above seem outdated to me?

I meanwhile use the most recent openhabian version with openhab release 3.4.3.
Maybe my setup is additionally complex as I have velux and somfy devices which are controlled manually with a Control Pad KLR200 (VELUX INTEGRA® Control Pad - KLR 200) which works fine. For further investigations I switched this off to assure its not interfering the anaysis.

First thing I discovered that even though I disabled all items as well as the bridge and the “Kopplungselement” I stil l see the

error: io() on 192.168.11.210: Exception occurred during I/O: raised a non-recoverable error during connection setup: Verbindungsaufbau abgelehnt (Connection refused).

in addition to

binding.BaseThingHandler] - Handler VeluxBridgeHandler of thing velux:klf200:a5c325f422 tried checking if channel reload is linked although the handler was already disposed.

How is that possible with everything disabled?

When in that state a telnet to this adress / port is refused so the klf200 seems to be in a stealth mode where nothing is accepted anymore. When I power cycle everything it manage to get it working again, but its only a matter of minutes when it breaks down again.

Indeed. If the connection between OH and KLF is dropped (e.g. if OH or your router go unexpectedly offline) then the KLF may still be happily sitting and thinking it is connected. And when the KLF thinks it is connected, it refuses all new connection attempts. I call this the ‘zombie’ state…

Solution is…

  • disable the bridge thing in OH
  • power cycle the KLF (and wait 15 seconds)
  • enable the bridge thing in OH

Thank you for your support. Apart from this I also struggle with this strange behaviour. Initially all worked fine, then the connection abort, restarted and now I have such messages where it seems he can’t get ahold of some configuration. But when I login to the velux admin webgui I can see this Actuator and I can also move it (with the identify item option). Something is really strange here…

2023-05-02 15:36:19.484 [WARN ] [al.handler.utils.Thing2VeluxActuator] - mapThing2Velux(): actuator with uniqueIndex=LevinFenster is not registered

2023-05-02 15:36:19.487 [WARN ] [rnal.handler.ChannelActuatorPosition] - handleRefresh(): unknown actuator.

2023-05-02 15:36:19.489 [WARN ] [.internal.handler.VeluxBridgeHandler] - handleCommandCommsJob(velux:rollershutter:klf200bridge:LevinFenster:position,REFRESH): updating of item velux:rollershutter:klf200bridge:LevinFenster:position (type velux:rollershutter/position) failed.

Is the device a Velux device or Somfy?

EDIT: a Velux device thing needs to be identified with a serial number not a name.