[velux] New OpenHAB2 binding - feedback welcome!

Hello Fabien,

After the binding is accepted as official part of the distribution, this can be addressed as new change-request.

Hello Fabien,

this inconvenience will be eliminated soon.

Hi Guenther,

Thanks for your work.
But the fact is that this is not only unwanted logs : the scenes are actualy used (and they work).
BTW, the 2 logs problems are the same :

[WARN ] [nal.handler.utils.ThingConfiguration] - exists(): Channel velux:klf200:home:check does not belong to a thing.

ā€¦ x30 (number of scenes in KLF200 ) and just after :

[INFO ] [.internal.handler.ChannelBridgeCheck] - Integrity check failed: The following scenes are unused:[...]

This happens every 40 minutes.

Obsolete logging is eliminated within the next PR now.

Hello @funcat,

the integrated fixes lead to silence within the log.

The messages

indicate that the KLF200 has recognized an error state, i.e. opening of a window during rain.

Very nice Guenther !
I tried your last snapshot :

org.openhab.binding.velux-2.5.3-SNAPSHOT-PR7098+7102-20200305.jar

And all spamming logs disappear. :ok_hand:
Now i still have a warning after each command sent to KLF200 :

[WARN ] [al.handler.utils.Thing2VeluxActuator] - mapThing2Velux(): aborting processing as serial is not set.

I guess this is because on somfy devices the serial is the name and not digits ā€¦
Right ?

Hi Guenther I have just bought the KLF200 with the latest firmware and Iā€™m using your latest binding. I am able to connect to the bridge but it seems to crash after detecting some of the windows. I am using the text configuration as in the readme file.

here is the error message I get. It seems to hang the bindingā€¦do you have any ideas what is happening? Iā€™m running openhabian 2.5

Thanks

2020-03-08 19:00:32.861 [DEBUG] [internal.bridge.VeluxBridgeActuators] - getProducts() storing new product Product "Nell_Blind" / SLIDER_SHUTTER (bridgeIndex=17,serial=53:22:24:26:0B:01:03:10,position=C800).
2020-03-08 19:00:32.864 [TRACE] [nternal.things.VeluxExistingProducts] - register(Product "Nell_Blind" / SLIDER_SHUTTER (bridgeIndex=17,serial=53:22:24:26:0B:01:03:10,position=C800)) called.
2020-03-08 19:00:32.866 [TRACE] [nternal.things.VeluxExistingProducts] - isRegistered(VeluxProduct Product "Nell_Blind" / SLIDER_SHUTTER (bridgeIndex=17,serial=53:22:24:26:0B:01:03:10,position=C800)) called.
2020-03-08 19:00:32.869 [TRACE] [nternal.things.VeluxExistingProducts] - isRegistered(String 53:22:24:26:0B:01:03:10) returns false.
2020-03-08 19:00:32.871 [TRACE] [nternal.things.VeluxExistingProducts] - register() registering new product Product "Nell_Blind" / SLIDER_SHUTTER (bridgeIndex=17,serial=53:22:24:26:0B:01:03:10,position=C800).
2020-03-08 19:00:32.873 [TRACE] [nternal.things.VeluxExistingProducts] - register() registering by UniqueIndex 53:22:24:26:0B:01:03:10
2020-03-08 19:00:32.875 [TRACE] [nternal.things.VeluxExistingProducts] - register() registering by ProductBridgeIndex 17
2020-03-08 19:00:32.877 [TRACE] [nternal.things.VeluxExistingProducts] - register() registering set of modifications by UniqueIndex 53:22:24:26:0B:01:03:10
2020-03-08 19:00:32.880 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: 
java.lang.NullPointerException: null
	at org.openhab.binding.velux.internal.bridge.VeluxBridgeActuators.getProducts(VeluxBridgeActuators.java:133) ~[?:?]
	at org.openhab.binding.velux.internal.handler.VeluxBridgeHandler.bridgeParamsUpdated(VeluxBridgeHandler.java:368) ~[?:?]
	at org.openhab.binding.velux.internal.handler.VeluxBridgeHandler.lambda$0(VeluxBridgeHandler.java:259) ~[?:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:?]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) ~[?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
	at java.lang.Thread.run(Thread.java:748) [?:?]
1 Like

Hello Julian,

this is the first NullPointerException and, even more confusing, at an unusual code locationā€¦

   logger.trace("getProducts() found product {} (type {}).", product.getProductName(),  product.getProductType());

Could you please add some more log informations, i.e. starting at the line with the information
[TRACE] [internal.bridge.VeluxBridgeActuators] - getProducts() called.
?

Thanks in advance, Guenther

Hi that was quick! log.txt (163.8 KB)

Hi Guenther - I think Iā€™ve found the problem! I have solar blinds and one of them has run out of battery (Iā€™ve been playing around too much today!) It looks like the binding does not get back a correct status from the KLF and that is crashing it. May be an unusual case but at least we know if this happens again. Sorry for wasting your time.

Great work btw!

Good evening Julian

Thanks for the feedback.
But even with some bad communication messages, the binding should be bullet-proof against such errorsā€¦ it will take some time to scrutinize the origin of this error.

Regards, Guenther

Thank you, @Julian_Divett, for the logfile. In fact, it is impossible for me to understand this: No NPE can appear from the source code at this point.

Please report any further errors!

Hello Guenther,
I still have failures on my side (in particular with WARN log mapThing2Velux).
If i look into your code (with cautionā€¦) i can see that :
-> mapThing2Velux() -> calls ThingConfiguration.exists() -> calls bridge.getThingByUID() -> which return null.
Why does the bridge cannot get the thing ? due to serial in plain text ?
Tell me if i can help.

Hello Fabian,
could you please increase the log level to trace for a moment to get an in-depth snapshot of the situation where this issue

occurs? Thanks in advance.

@gs4711
I did one test just now, send basic down command to one rollershutter.
These are logs, they are huge :sweat_smile: hopefully i can activate trace level only 2 minutes during the test.
klf200.log (547.1 KB)
(filtered with grep ā€˜bridgeā€™ keyword, as i dont know how to filter only klf200 logs ā€¦)

Sorry to bother you ā€¦ but the logfile does not contain any error (nor a line WARN).

Ha yes of course my bad, sorry =)
I filtered the WARN because of the grep command.
During this test and this log extract, the WARN were :

/var/log/openhab2/openhab.log.6:2020-03-10 00:40:41.451 [WARN ] [al.handler.utils.Thing2VeluxActuator] - mapThing2Velux(): aborting processing as serial is not set.
/var/log/openhab2/openhab.log.6:2020-03-10 00:40:41.454 [WARN ] [al.handler.utils.Thing2VeluxActuator] - mapThing2Velux(): aborting processing as serial is not set.
/var/log/openhab2/openhab.log.6:2020-03-10 00:40:43.488 [WARN ] [al.handler.utils.Thing2VeluxActuator] - mapThing2Velux(): aborting processing as serial is not set.
/var/log/openhab2/openhab.log.6:2020-03-10 00:40:43.490 [WARN ] [al.handler.utils.Thing2VeluxActuator] - mapThing2Velux(): aborting processing as serial is not set.
/var/log/openhab2/openhab.log.6:2020-03-10 00:41:56.537 [WARN ] [al.handler.utils.Thing2VeluxActuator] - mapThing2Velux(): aborting processing as serial is not set.
/var/log/openhab2/openhab.log.6:2020-03-10 00:41:56.544 [WARN ] [al.handler.utils.Thing2VeluxActuator] - mapThing2Velux(): aborting processing as serial is not set.

Here is the complete logs (there were missing also lot of lines)
I hope it is complete this time.
klf200.log (909.0 KB)

Hi I am using the rain sensor example you posted and it works but Iā€™ve noticed that if the windows are open when it rains the binding does not update the position of the velux.
So if they are at 100 Open (mine are inverted) they will close and the limit minimum will got to 11. However the binding will still show them as being 100 open. Do you have the same behaviour?

I do not have that problem. The binding always reflects the position of the window - sometimes it comes a bit delayed though.

Yes Iā€™ve noticed there is a delay so maybe that is what happened. Thanks.

On another point is there a way to change the rollershutter icons? For a Velux window it would be better to have a window type icon not a shutter.