Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[somfytahoma] Too many attempts with an invalid token, temporarily banned. #14763

Closed
BasvanH opened this issue Apr 8, 2023 · 34 comments · Fixed by #17361
Closed

[somfytahoma] Too many attempts with an invalid token, temporarily banned. #14763

BasvanH opened this issue Apr 8, 2023 · 34 comments · Fixed by #17361
Assignees
Labels
bug An unexpected problem or unintended behavior of an add-on

Comments

@BasvanH
Copy link

BasvanH commented Apr 8, 2023

Expected Behavior

Stable binding.

Current Behavior

Binding looses connection after a few days. The bridge goes offline with a Bad credentials error. The username and password are just fine. At the same time I login to tahomalink website I also get an error message, F12 in the browser and i see a Too many attempts with an invalid token, temporarily banned. in the login response.

So the binding somehow triggers this ban.

Possible Solution

The binding seems to authenticate with username and password to www.tahomalink.com and retrieves a JWT token which it uses to authenticate all the upcoming requests. Looking at the tahomalink webpage they seem to authenticate to https://accounts.somfy.com/oauth/oauth/v2/token and using OATH2 with a refresh_token. This authentication endpoind seems more solid than tahomalink JWT as it also returns a message when there are issues with authentication.

I'm already busy recoding the binding but I would like to discuss if this is the parmant way to go and agreed by all involved.

I would suggest to recode the binding to authenticate to ```https://accounts.somfy.com/oauth/oauth/v2/token`` with OATH2 as this would probably solve the ban issue.

Steps to Reproduce (for Bugs)

Run binding for a few days.
Refresh: 180
Timeout:300
Retries: 1
Retry delay: 120000
Developer mode: ON or OFF (ON takes a few days longer when it gets banned)

@BasvanH BasvanH added the bug An unexpected problem or unintended behavior of an add-on label Apr 8, 2023
@BasvanH
Copy link
Author

BasvanH commented Apr 9, 2023

@octa22, you seem to be contributing a lot to this binding. Could you please take a look at this?

@clinique
Copy link
Contributor

clinique commented Apr 11, 2023

I also face this issue. Usually, disabling the bridge for some hours is enough to bring it back ONLINE, but for sure this is a real constraint.

@BasvanH
Copy link
Author

BasvanH commented Apr 12, 2023

I also face this issue. Usually, disabling the bridge for some hours is enough to bring it back ONLINE, but for sure this is a real constraint.

It's getting worse, I need to do this almost very day now.

@octa22, I've got a test version working with OATH2 to https://accounts.somfy.com/oauth/oauth/v2/token and it looks promising. I do however need your help with fully integrating it into the full code.

@lsiepel
Copy link
Contributor

lsiepel commented Apr 16, 2023

Is this binding using the common oauth2 client? If not, it might also be something to consider when refactoring the authentication code.

@BasvanH
Copy link
Author

BasvanH commented Apr 17, 2023

Is this binding using the common oauth2 client? If not, it might also be something to consider when refactoring the authentication code.

No it's using a self made one, can you point me to a binding which is using the common oath2 client?

@lsiepel
Copy link
Contributor

lsiepel commented Apr 17, 2023

#14818 Has a list of those bindings

@lsiepel
Copy link
Contributor

lsiepel commented May 7, 2023

@BasvanH you need any help with the common client?

@BasvanH
Copy link
Author

BasvanH commented May 30, 2023

@lsiepel, I need @octa22 help for this. For me it's to much reverse engineering. Waiting for him to check in.

@octa22
Copy link
Contributor

octa22 commented Jun 2, 2023

sorry for replying so late, I have been pretty busy last days. Currently this binding uses three auth schemas - JWT/OAUTH2 for Cozytouch cloud, simple JSESSIONID token for Tahoma cloud connection and bearer tokens for the local mode. The local (developer) mode uses the JSESSIONID schema for getting the bearer token as described here: https://github.com/Somfy-Developer/Somfy-TaHoma-Developer-Mode (just 2-3 calls).

Somfy introduced the login api throttling 2-3 years ago, so you cannot call login for getting the JSESSIONID (I am not using the Cozytouch) too frequently, you just get something like "Too many attemps ...". The binding tries to recognize this throttling message and postpones the login attempt for some time (I guess two minutes). Maybe the message has changed or maybe we need to try setting longer period between the attempts.

Unfortunately I do not experience these login errors even with the default configuration (I have 13 Somfy devices). The binding tries to relogin once it gets an error message response from the API call - maybe some network unstability causes more frequent reconnects? I don't know, but it might help, if someone could trace the logging frequency and errors which triggered the relogin attempts.

I don't think the OAUTH2 authentication will sort out the current issues and maybe it even breaks the local mode implementation because it relies on the JSESSIONID way and follows the official documentation.

What I really do not understand at all, why is still somebody experiencing problems with the developer mode - there is no throttling on the local API and there are only 2-3 calls on the cloud API, so it is really weird that it fails several times in a row and ends with the throttling limit reaching.

I would really start with the trace logs and finding out, what triggers the relogin.
If you want I can build a special version with disabled autodiscovery and longer period between the relogin attempts. This definitely lowers the number of API calls.

@BasvanH
Copy link
Author

BasvanH commented Jun 7, 2023

Hi @octa22, with https://accounts.somfy.com/oauth/oauth/v2/token with OATH2 the JSESSIONID is no longer required and I no longer get throttles. I think it's a good way forward to adopt OATH2 for Tahoma cloud, this would possible eliminate the need for developer mode completely.

We could spend hours on troubleshooting but adopting the new would make more sense wont you think?

@octa22
Copy link
Contributor

octa22 commented Jun 7, 2023

OK, but we need to be sure, that we do not break the local control funtionality, which recommends the JSESSIONID way according to the documentation. I implemented the OAUTH2 functionality some time ago just for testing, but stayed with the JSESSIONID, because of the same behaviour in my case and following the official documentation.

@BasvanH
Copy link
Author

BasvanH commented Jun 13, 2023

Ok cool, @lsiepel requested to start using the OATH2 common client, perhaps you could start using this? But that might be a big change for now. I can assist you if you need any help!

@BasvanH
Copy link
Author

BasvanH commented Aug 17, 2023

@octa22, made any progress? Need any help?

@octa22
Copy link
Contributor

octa22 commented Aug 23, 2023

@BasvanH well some testing would be handy :-). Here is a snapshot for testing (compatible with 4.0.1), so far seems to be stable enough and you are right, maybe there there is no throttling in the OAUTH API, I have been unable to simulate any of the issues we are facing with the standard login API.
https://www.dropbox.com/scl/fi/3xyzrea4pg31kdxbe9c7h/org.openhab.binding.somfytahoma-4.1.0-SNAPSHOT.jar?rlkey=mnztpdrkl1fhmutpx1m4lmayq&dl=1

@BasvanH
Copy link
Author

BasvanH commented Aug 29, 2023

@octa22, ok will do. Need to upgrade to v4 first but will get back within a week.

@lsiepel
Copy link
Contributor

lsiepel commented Aug 29, 2023

@octa22 just dropped the jar to my openHAB 4.0.2 instance, but it is not compatible:

2023-08-29 20:39:10.420 [ERROR] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202308231444 (296)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(396)] : Error during instantiation of the implementation object
java.lang.IllegalArgumentException: argument type mismatch
	at jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) ~[?:?]
	at jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:77) ~[?:?]
	at jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) ~[?:?]
	at java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:499) ~[?:?]
	at java.lang.reflect.Constructor.newInstance(Constructor.java:480) ~[?:?]
	at org.apache.felix.scr.impl.inject.internal.ComponentConstructorImpl.newInstance(ComponentConstructorImpl.java:326) ~[?:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.createImplementationObject(SingleComponentManager.java:286) ~[?:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.createComponent(SingleComponentManager.java:115) ~[?:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:1002) ~[?:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getServiceInternal(SingleComponentManager.java:975) ~[?:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:920) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse$1.run(ServiceFactoryUse.java:220) ~[org.eclipse.osgi-3.18.0.jar:?]
	at java.security.AccessController.doPrivileged(AccessController.java:318) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:217) ~[org.eclipse.osgi-3.18.0.jar:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.getService(ServiceFactoryUse.java:118) ~[org.eclipse.osgi-3.18.0.jar:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceConsumer$2.getService(ServiceConsumer.java:48) ~[org.eclipse.osgi-3.18.0.jar:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:547) ~[org.eclipse.osgi-3.18.0.jar:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.getService(ServiceRegistry.java:534) ~[org.eclipse.osgi-3.18.0.jar:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.getService(BundleContextImpl.java:660) ~[org.eclipse.osgi-3.18.0.jar:?]
	at org.apache.felix.scr.impl.manager.SingleRefPair.getServiceObject(SingleRefPair.java:88) ~[?:?]
	at org.apache.felix.scr.impl.inject.methods.BindMethod.getServiceObject(BindMethod.java:675) ~[?:?]
	at org.apache.felix.scr.impl.manager.DependencyManager.getServiceObject(DependencyManager.java:2612) ~[?:?]
	at org.apache.felix.scr.impl.manager.DependencyManager.invokeUnbindMethod(DependencyManager.java:2204) ~[?:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.invokeUnbindMethod(SingleComponentManager.java:466) ~[?:?]
	at org.apache.felix.scr.impl.manager.DependencyManager$MultipleDynamicCustomizer.removedService(DependencyManager.java:398) ~[?:?]
	at org.apache.felix.scr.impl.manager.DependencyManager$MultipleDynamicCustomizer.removedService(DependencyManager.java:304) ~[?:?]
	at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerRemoved(ServiceTracker.java:1258) ~[?:?]
	at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerRemoved(ServiceTracker.java:1152) ~[?:?]
	at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.untrack(ServiceTracker.java:1012) ~[?:?]
	at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1192) ~[?:?]
	at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:116) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:123) ~[org.eclipse.osgi-3.18.0.jar:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:961) ~[org.eclipse.osgi-3.18.0.jar:?]
	at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:234) ~[org.eclipse.osgi-3.18.0.jar:?]
	at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:151) ~[org.eclipse.osgi-3.18.0.jar:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:937) ~[org.eclipse.osgi-3.18.0.jar:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:874) ~[org.eclipse.osgi-3.18.0.jar:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.unregister(ServiceRegistrationImpl.java:241) ~[org.eclipse.osgi-3.18.0.jar:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.unregister(AbstractComponentManager.java:952) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.unregister(AbstractComponentManager.java:915) ~[?:?]
	at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:140) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.unregisterService(AbstractComponentManager.java:994) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.doDeactivate(AbstractComponentManager.java:844) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.deactivateInternal(AbstractComponentManager.java:825) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.dispose(AbstractComponentManager.java:589) ~[?:?]
	at org.apache.felix.scr.impl.manager.ConfigurableComponentHolder.disposeComponents(ConfigurableComponentHolder.java:722) ~[?:?]
	at org.apache.felix.scr.impl.BundleComponentActivator.dispose(BundleComponentActivator.java:492) ~[?:?]
	at org.apache.felix.scr.impl.Activator.disposeComponents(Activator.java:652) ~[?:?]
	at org.apache.felix.scr.impl.Activator.access$300(Activator.java:74) ~[?:?]
	at org.apache.felix.scr.impl.Activator$ScrExtension.destroy(Activator.java:490) ~[?:?]
	at org.apache.felix.scr.impl.AbstractExtender$1.run(AbstractExtender.java:216) ~[?:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[?:?]
	at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
	at org.apache.felix.scr.impl.AbstractExtender.destroyExtension(AbstractExtender.java:238) ~[?:?]
	at org.apache.felix.scr.impl.AbstractExtender.bundleChanged(AbstractExtender.java:132) ~[?:?]
	at org.apache.felix.scr.impl.Activator.bundleChanged(Activator.java:255) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:949) ~[org.eclipse.osgi-3.18.0.jar:?]
	at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:234) ~[org.eclipse.osgi-3.18.0.jar:?]
	at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:151) ~[org.eclipse.osgi-3.18.0.jar:?]
	at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEventPrivileged(EquinoxEventPublisher.java:229) ~[org.eclipse.osgi-3.18.0.jar:?]
	at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:138) ~[org.eclipse.osgi-3.18.0.jar:?]
	at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:130) ~[org.eclipse.osgi-3.18.0.jar:?]
	at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor.publishModuleEvent(EquinoxContainerAdaptor.java:217) ~[org.eclipse.osgi-3.18.0.jar:?]
	at org.eclipse.osgi.container.Module.publishEvent(Module.java:499) ~[org.eclipse.osgi-3.18.0.jar:?]
	at org.eclipse.osgi.container.Module.doStop(Module.java:658) ~[org.eclipse.osgi-3.18.0.jar:?]
	at org.eclipse.osgi.container.Module.stop(Module.java:521) ~[org.eclipse.osgi-3.18.0.jar:?]
	at org.eclipse.osgi.container.ModuleContainer.uninstall(ModuleContainer.java:444) ~[org.eclipse.osgi-3.18.0.jar:?]
	at org.eclipse.osgi.internal.framework.EquinoxBundle.uninstall(EquinoxBundle.java:504) ~[org.eclipse.osgi-3.18.0.jar:?]
	at org.apache.felix.fileinstall.internal.DirectoryWatcher.uninstall(DirectoryWatcher.java:1098) ~[?:?]
	at org.apache.felix.fileinstall.internal.DirectoryWatcher.uninstall(DirectoryWatcher.java:901) ~[?:?]
	at org.apache.felix.fileinstall.internal.DirectoryWatcher.doProcess(DirectoryWatcher.java:487) ~[?:?]
	at org.apache.felix.fileinstall.internal.DirectoryWatcher.process(DirectoryWatcher.java:365) ~[?:?]
	at org.apache.felix.fileinstall.internal.DirectoryWatcher.run(DirectoryWatcher.java:316) ~[?:?]

@BasvanH
Copy link
Author

BasvanH commented Aug 31, 2023

@octa22 i have the same issue on Stable 4.0.2. looking at your bundle name could be you build it on 4.1.0?

@octa22
Copy link
Contributor

octa22 commented Sep 3, 2023

@BasvanH
Copy link
Author

BasvanH commented Sep 11, 2023

Still getting the same kind of erros with this bundle:

2023-09-11 11:59:01.571 [ERROR] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (322)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(403)] : Error during instantiation of the implementation object
java.lang.IllegalArgumentException: argument type mismatch
        at jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) ~[?:?]
        at jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:77) ~[?:?]
        at jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) ~[?:?]
        at java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:499) ~[?:?]
        at java.lang.reflect.Constructor.newInstance(Constructor.java:480) ~[?:?]
        at org.apache.felix.scr.impl.inject.internal.ComponentConstructorImpl.newInstance(ComponentConstructorImpl.java:326) ~[?:?]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.createImplementationObject(SingleComponentManager.java:286) ~[?:?]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.createComponent(SingleComponentManager.java:115) ~[?:?]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:1002) ~[?:?]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.getServiceInternal(SingleComponentManager.java:975) ~[?:?]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:920) ~[?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse$1.run(ServiceFactoryUse.java:220) ~[org.eclipse.osgi-3.18.0.jar:?]
        at java.security.AccessController.doPrivileged(AccessController.java:318) ~[?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:217) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.getService(ServiceFactoryUse.java:118) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceConsumer$2.getService(ServiceConsumer.java:48) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:547) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.getService(ServiceRegistry.java:534) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.getService(BundleContextImpl.java:660) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.apache.felix.scr.impl.manager.SingleRefPair.getServiceObject(SingleRefPair.java:88) ~[?:?]
        at org.apache.felix.scr.impl.inject.methods.BindMethod.getServiceObject(BindMethod.java:675) ~[?:?]
        at org.apache.felix.scr.impl.manager.DependencyManager.getServiceObject(DependencyManager.java:2612) ~[?:?]
        at org.apache.felix.scr.impl.manager.DependencyManager.doInvokeBindMethod(DependencyManager.java:2078) ~[?:?]
        at org.apache.felix.scr.impl.manager.DependencyManager.invokeBindMethod(DependencyManager.java:2061) ~[?:?]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.invokeBindMethod(SingleComponentManager.java:443) ~[?:?]
        at org.apache.felix.scr.impl.manager.DependencyManager$MultipleDynamicCustomizer.addedService(DependencyManager.java:336) ~[?:?]
        at org.apache.felix.scr.impl.manager.DependencyManager$MultipleDynamicCustomizer.addedService(DependencyManager.java:304) ~[?:?]
        at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1232) ~[?:?]
        at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1152) ~[?:?]
        at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.trackAdding(ServiceTracker.java:959) ~[?:?]
        at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.track(ServiceTracker.java:895) ~[?:?]
        at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1184) ~[?:?]
        at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:116) ~[?:?]
        at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:123) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:961) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:234) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:151) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:937) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:874) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.register(ServiceRegistrationImpl.java:141) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.registerService(ServiceRegistry.java:262) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:500) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:929) ~[?:?]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:915) ~[?:?]
        at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:133) ~[?:?]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:984) ~[?:?]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:752) ~[?:?]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.enableInternal(AbstractComponentManager.java:674) ~[?:?]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.enable(AbstractComponentManager.java:437) ~[?:?]
        at org.apache.felix.scr.impl.manager.ConfigurableComponentHolder.enableComponents(ConfigurableComponentHolder.java:671) ~[?:?]
        at org.apache.felix.scr.impl.BundleComponentActivator.initialEnable(BundleComponentActivator.java:310) ~[?:?]
        at org.apache.felix.scr.impl.Activator.loadComponents(Activator.java:593) ~[?:?]
        at org.apache.felix.scr.impl.Activator.access$200(Activator.java:74) ~[?:?]
        at org.apache.felix.scr.impl.Activator$ScrExtension.start(Activator.java:460) ~[?:?]
        at org.apache.felix.scr.impl.AbstractExtender.createExtension(AbstractExtender.java:196) ~[?:?]
        at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:169) ~[?:?]
        at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:49) ~[?:?]
        at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:488) ~[osgi.core-8.0.0.jar:?]
        at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:420) ~[osgi.core-8.0.0.jar:?]
        at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:232) ~[osgi.core-8.0.0.jar:?]
        at org.osgi.util.tracker.BundleTracker$Tracked.bundleChanged(BundleTracker.java:450) ~[osgi.core-8.0.0.jar:?]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:949) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:234) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:151) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEventPrivileged(EquinoxEventPublisher.java:229) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:138) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:130) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor.publishModuleEvent(EquinoxContainerAdaptor.java:217) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.container.Module.publishEvent(Module.java:499) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.container.Module.start(Module.java:486) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel$2.run(ModuleContainer.java:1847) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor$1$1.execute(EquinoxContainerAdaptor.java:136) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1840) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1783) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.doContainerStartLevel(ModuleContainer.java:1745) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1667) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:234) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:345) ~[org.eclipse.osgi-3.18.0.jar:?]
2023-09-11 11:59:01.640 [WARN ] [g.discovery.internal.PersistentInbox] - bundle org.openhab.core.config.discovery:4.0.2 (163)[org.openhab.core.config.discovery.internal.PersistentInbox(126)] : Could not get service from ref {org.openhab.core.thing.binding.ThingHandlerFactory}={service.id=658, service.bundleid=322, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), component.name=org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory, component.id=403}
2023-09-11 11:59:01.640 [WARN ] [g.discovery.internal.PersistentInbox] - bundle org.openhab.core.config.discovery:4.0.2 (163)[org.openhab.core.config.discovery.internal.PersistentInbox(126)] : DependencyManager : invokeBindMethod : Service not available from service registry for ServiceReference {org.openhab.core.thing.binding.ThingHandlerFactory}={service.id=658, service.bundleid=322, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), component.name=org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory, component.id=403} for reference ThingHandlerFactory
2023-09-11 11:59:01.642 [ERROR] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (322)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(403)] : Error during instantiation of the implementation object
java.lang.IllegalArgumentException: argument type mismatch
        at jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) ~[?:?]
        at jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:77) ~[?:?]
        at jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) ~[?:?]
        at java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:499) ~[?:?]
        at java.lang.reflect.Constructor.newInstance(Constructor.java:480) ~[?:?]
        at org.apache.felix.scr.impl.inject.internal.ComponentConstructorImpl.newInstance(ComponentConstructorImpl.java:326) ~[?:?]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.createImplementationObject(SingleComponentManager.java:286) ~[?:?]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.createComponent(SingleComponentManager.java:115) ~[?:?]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:1002) ~[?:?]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.getServiceInternal(SingleComponentManager.java:975) ~[?:?]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:920) ~[?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse$1.run(ServiceFactoryUse.java:220) ~[org.eclipse.osgi-3.18.0.jar:?]
        at java.security.AccessController.doPrivileged(AccessController.java:318) ~[?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:217) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.getService(ServiceFactoryUse.java:118) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceConsumer$2.getService(ServiceConsumer.java:48) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:547) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.getService(ServiceRegistry.java:534) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.getService(BundleContextImpl.java:660) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.apache.felix.scr.impl.manager.SingleRefPair.getServiceObject(SingleRefPair.java:88) ~[?:?]
        at org.apache.felix.scr.impl.inject.methods.BindMethod.getServiceObject(BindMethod.java:675) ~[?:?]
        at org.apache.felix.scr.impl.manager.DependencyManager.getServiceObject(DependencyManager.java:2612) ~[?:?]
        at org.apache.felix.scr.impl.manager.DependencyManager.doInvokeBindMethod(DependencyManager.java:2078) ~[?:?]
        at org.apache.felix.scr.impl.manager.DependencyManager.invokeBindMethod(DependencyManager.java:2061) ~[?:?]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.invokeBindMethod(SingleComponentManager.java:443) ~[?:?]
        at org.apache.felix.scr.impl.manager.DependencyManager$MultipleDynamicCustomizer.addedService(DependencyManager.java:336) ~[?:?]
        at org.apache.felix.scr.impl.manager.DependencyManager$MultipleDynamicCustomizer.addedService(DependencyManager.java:304) ~[?:?]
        at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1232) ~[?:?]
        at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1152) ~[?:?]
        at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.trackAdding(ServiceTracker.java:959) ~[?:?]
        at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.track(ServiceTracker.java:895) ~[?:?]
        at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1184) ~[?:?]
        at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:116) ~[?:?]
        at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:123) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:961) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:234) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:151) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:937) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:874) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.register(ServiceRegistrationImpl.java:141) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.registerService(ServiceRegistry.java:262) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:500) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:929) ~[?:?]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:915) ~[?:?]
        at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:133) ~[?:?]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:984) ~[?:?]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:752) ~[?:?]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.enableInternal(AbstractComponentManager.java:674) ~[?:?]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.enable(AbstractComponentManager.java:437) ~[?:?]
        at org.apache.felix.scr.impl.manager.ConfigurableComponentHolder.enableComponents(ConfigurableComponentHolder.java:671) ~[?:?]
        at org.apache.felix.scr.impl.BundleComponentActivator.initialEnable(BundleComponentActivator.java:310) ~[?:?]
        at org.apache.felix.scr.impl.Activator.loadComponents(Activator.java:593) ~[?:?]
        at org.apache.felix.scr.impl.Activator.access$200(Activator.java:74) ~[?:?]
        at org.apache.felix.scr.impl.Activator$ScrExtension.start(Activator.java:460) ~[?:?]
        at org.apache.felix.scr.impl.AbstractExtender.createExtension(AbstractExtender.java:196) ~[?:?]
        at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:169) ~[?:?]
        at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:49) ~[?:?]
        at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:488) ~[osgi.core-8.0.0.jar:?]
        at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:420) ~[osgi.core-8.0.0.jar:?]
        at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:232) ~[osgi.core-8.0.0.jar:?]
        at org.osgi.util.tracker.BundleTracker$Tracked.bundleChanged(BundleTracker.java:450) ~[osgi.core-8.0.0.jar:?]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:949) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:234) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:151) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEventPrivileged(EquinoxEventPublisher.java:229) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:138) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:130) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor.publishModuleEvent(EquinoxContainerAdaptor.java:217) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.container.Module.publishEvent(Module.java:499) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.container.Module.start(Module.java:486) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel$2.run(ModuleContainer.java:1847) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor$1$1.execute(EquinoxContainerAdaptor.java:136) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1840) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1783) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.doContainerStartLevel(ModuleContainer.java:1745) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1667) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:234) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:345) ~[org.eclipse.osgi-3.18.0.jar:?]
2023-09-11 11:59:01.710 [WARN ] [.thing.internal.GenericThingProvider] - bundle org.openhab.core.model.thing:4.0.2 (206)[org.openhab.core.model.thing.internal.GenericThingProvider(229)] : Could not get service from ref {org.openhab.core.thing.binding.ThingHandlerFactory}={service.id=658, service.bundleid=322, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), component.name=org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory, component.id=403}
2023-09-11 11:59:01.711 [WARN ] [.thing.internal.GenericThingProvider] - bundle org.openhab.core.model.thing:4.0.2 (206)[org.openhab.core.model.thing.internal.GenericThingProvider(229)] : DependencyManager : invokeBindMethod : Service not available from service registry for ServiceReference {org.openhab.core.thing.binding.ThingHandlerFactory}={service.id=658, service.bundleid=322, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), component.name=org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory, component.id=403} for reference ThingHandlerFactory
2023-09-11 11:59:01.712 [ERROR] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (322)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(403)] : Error during instantiation of the implementation object
java.lang.IllegalArgumentException: argument type mismatch
        at jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) ~[?:?]
        at jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:77) ~[?:?]
        at jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) ~[?:?]
        at java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:499) ~[?:?]
        at java.lang.reflect.Constructor.newInstance(Constructor.java:480) ~[?:?]
        at org.apache.felix.scr.impl.inject.internal.ComponentConstructorImpl.newInstance(ComponentConstructorImpl.java:326) ~[?:?]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.createImplementationObject(SingleComponentManager.java:286) ~[?:?]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.createComponent(SingleComponentManager.java:115) ~[?:?]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:1002) ~[?:?]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.getServiceInternal(SingleComponentManager.java:975) ~[?:?]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:920) ~[?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse$1.run(ServiceFactoryUse.java:220) ~[org.eclipse.osgi-3.18.0.jar:?]
        at java.security.AccessController.doPrivileged(AccessController.java:318) ~[?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:217) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.getService(ServiceFactoryUse.java:118) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceConsumer$2.getService(ServiceConsumer.java:48) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:547) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.getService(ServiceRegistry.java:534) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.getService(BundleContextImpl.java:660) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.apache.felix.scr.impl.manager.SingleRefPair.getServiceObject(SingleRefPair.java:88) ~[?:?]
        at org.apache.felix.scr.impl.inject.methods.BindMethod.getServiceObject(BindMethod.java:675) ~[?:?]
        at org.apache.felix.scr.impl.manager.DependencyManager.getServiceObject(DependencyManager.java:2612) ~[?:?]
        at org.apache.felix.scr.impl.manager.DependencyManager.doInvokeBindMethod(DependencyManager.java:2078) ~[?:?]
        at org.apache.felix.scr.impl.manager.DependencyManager.invokeBindMethod(DependencyManager.java:2061) ~[?:?]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.invokeBindMethod(SingleComponentManager.java:443) ~[?:?]
        at org.apache.felix.scr.impl.manager.DependencyManager$MultipleDynamicCustomizer.addedService(DependencyManager.java:336) ~[?:?]
        at org.apache.felix.scr.impl.manager.DependencyManager$MultipleDynamicCustomizer.addedService(DependencyManager.java:304) ~[?:?]
        at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1232) ~[?:?]
        at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1152) ~[?:?]
        at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.trackAdding(ServiceTracker.java:959) ~[?:?]
        at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.track(ServiceTracker.java:895) ~[?:?]
        at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1184) ~[?:?]
        at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:116) ~[?:?]
        at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:123) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:961) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:234) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:151) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:937) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:874) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.register(ServiceRegistrationImpl.java:141) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.registerService(ServiceRegistry.java:262) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:500) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:929) ~[?:?]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:915) ~[?:?]
        at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:133) ~[?:?]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:984) ~[?:?]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:752) ~[?:?]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.enableInternal(AbstractComponentManager.java:674) ~[?:?]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.enable(AbstractComponentManager.java:437) ~[?:?]
        at org.apache.felix.scr.impl.manager.ConfigurableComponentHolder.enableComponents(ConfigurableComponentHolder.java:671) ~[?:?]
        at org.apache.felix.scr.impl.BundleComponentActivator.initialEnable(BundleComponentActivator.java:310) ~[?:?]
        at org.apache.felix.scr.impl.Activator.loadComponents(Activator.java:593) ~[?:?]
        at org.apache.felix.scr.impl.Activator.access$200(Activator.java:74) ~[?:?]
        at org.apache.felix.scr.impl.Activator$ScrExtension.start(Activator.java:460) ~[?:?]
        at org.apache.felix.scr.impl.AbstractExtender.createExtension(AbstractExtender.java:196) ~[?:?]
        at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:169) ~[?:?]
        at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:49) ~[?:?]
        at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:488) ~[osgi.core-8.0.0.jar:?]
        at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:420) ~[osgi.core-8.0.0.jar:?]
        at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:232) ~[osgi.core-8.0.0.jar:?]
        at org.osgi.util.tracker.BundleTracker$Tracked.bundleChanged(BundleTracker.java:450) ~[osgi.core-8.0.0.jar:?]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:949) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:234) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:151) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEventPrivileged(EquinoxEventPublisher.java:229) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:138) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:130) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor.publishModuleEvent(EquinoxContainerAdaptor.java:217) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.container.Module.publishEvent(Module.java:499) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.container.Module.start(Module.java:486) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel$2.run(ModuleContainer.java:1847) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor$1$1.execute(EquinoxContainerAdaptor.java:136) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1840) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1783) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.doContainerStartLevel(ModuleContainer.java:1745) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1667) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:234) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:345) ~[org.eclipse.osgi-3.18.0.jar:?]
2023-09-11 11:59:01.742 [WARN ] [core.thing.internal.ThingManagerImpl] - bundle org.openhab.core.thing:4.0.2 (212)[org.openhab.core.thing.internal.ThingManagerImpl(257)] : Could not get service from ref {org.openhab.core.thing.binding.ThingHandlerFactory}={service.id=658, service.bundleid=322, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), component.name=org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory, component.id=403}
2023-09-11 11:59:01.744 [WARN ] [core.thing.internal.ThingManagerImpl] - bundle org.openhab.core.thing:4.0.2 (212)[org.openhab.core.thing.internal.ThingManagerImpl(257)] : DependencyManager : invokeBindMethod : Service not available from service registry for ServiceReference {org.openhab.core.thing.binding.ThingHandlerFactory}={service.id=658, service.bundleid=322, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), component.name=org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory, component.id=403} for reference ThingHandlerFactory
2023-09-11 11:59:01.748 [ERROR] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (322)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(403)] : Error during instantiation of the implementation object
java.lang.IllegalArgumentException: argument type mismatch
        at jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) ~[?:?]
        at jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:77) ~[?:?]
        at jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) ~[?:?]
        at java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:499) ~[?:?]
        at java.lang.reflect.Constructor.newInstance(Constructor.java:480) ~[?:?]
        at org.apache.felix.scr.impl.inject.internal.ComponentConstructorImpl.newInstance(ComponentConstructorImpl.java:326) ~[?:?]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.createImplementationObject(SingleComponentManager.java:286) ~[?:?]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.createComponent(SingleComponentManager.java:115) ~[?:?]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:1002) ~[?:?]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.getServiceInternal(SingleComponentManager.java:975) ~[?:?]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:920) ~[?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse$1.run(ServiceFactoryUse.java:220) ~[org.eclipse.osgi-3.18.0.jar:?]
        at java.security.AccessController.doPrivileged(AccessController.java:318) ~[?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:217) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.getService(ServiceFactoryUse.java:118) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceConsumer$2.getService(ServiceConsumer.java:48) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:547) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.getService(ServiceRegistry.java:534) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.getService(BundleContextImpl.java:660) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.apache.felix.scr.impl.manager.SingleRefPair.getServiceObject(SingleRefPair.java:88) ~[?:?]
        at org.apache.felix.scr.impl.inject.methods.BindMethod.getServiceObject(BindMethod.java:675) ~[?:?]
        at org.apache.felix.scr.impl.manager.DependencyManager.getServiceObject(DependencyManager.java:2612) ~[?:?]
        at org.apache.felix.scr.impl.manager.DependencyManager.doInvokeBindMethod(DependencyManager.java:2078) ~[?:?]
        at org.apache.felix.scr.impl.manager.DependencyManager.invokeBindMethod(DependencyManager.java:2061) ~[?:?]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.invokeBindMethod(SingleComponentManager.java:443) ~[?:?]
        at org.apache.felix.scr.impl.manager.DependencyManager$MultipleDynamicCustomizer.addedService(DependencyManager.java:336) ~[?:?]
        at org.apache.felix.scr.impl.manager.DependencyManager$MultipleDynamicCustomizer.addedService(DependencyManager.java:304) ~[?:?]
        at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1232) ~[?:?]
        at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1152) ~[?:?]
        at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.trackAdding(ServiceTracker.java:959) ~[?:?]
        at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.track(ServiceTracker.java:895) ~[?:?]
        at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1184) ~[?:?]
        at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:116) ~[?:?]
        at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:123) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:961) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:234) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:151) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:937) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:874) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.register(ServiceRegistrationImpl.java:141) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.registerService(ServiceRegistry.java:262) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:500) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:929) ~[?:?]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:915) ~[?:?]
        at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:133) ~[?:?]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:984) ~[?:?]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:752) ~[?:?]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.enableInternal(AbstractComponentManager.java:674) ~[?:?]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.enable(AbstractComponentManager.java:437) ~[?:?]
        at org.apache.felix.scr.impl.manager.ConfigurableComponentHolder.enableComponents(ConfigurableComponentHolder.java:671) ~[?:?]
        at org.apache.felix.scr.impl.BundleComponentActivator.initialEnable(BundleComponentActivator.java:310) ~[?:?]
        at org.apache.felix.scr.impl.Activator.loadComponents(Activator.java:593) ~[?:?]
        at org.apache.felix.scr.impl.Activator.access$200(Activator.java:74) ~[?:?]
        at org.apache.felix.scr.impl.Activator$ScrExtension.start(Activator.java:460) ~[?:?]
        at org.apache.felix.scr.impl.AbstractExtender.createExtension(AbstractExtender.java:196) ~[?:?]
        at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:169) ~[?:?]
        at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:49) ~[?:?]
        at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:488) ~[osgi.core-8.0.0.jar:?]
        at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:420) ~[osgi.core-8.0.0.jar:?]
        at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:232) ~[osgi.core-8.0.0.jar:?]
        at org.osgi.util.tracker.BundleTracker$Tracked.bundleChanged(BundleTracker.java:450) ~[osgi.core-8.0.0.jar:?]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:949) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:234) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:151) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEventPrivileged(EquinoxEventPublisher.java:229) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:138) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:130) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor.publishModuleEvent(EquinoxContainerAdaptor.java:217) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.container.Module.publishEvent(Module.java:499) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.container.Module.start(Module.java:486) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel$2.run(ModuleContainer.java:1847) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor$1$1.execute(EquinoxContainerAdaptor.java:136) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1840) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1783) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.doContainerStartLevel(ModuleContainer.java:1745) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1667) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:234) ~[org.eclipse.osgi-3.18.0.jar:?]
        at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:345) ~[org.eclipse.osgi-3.18.0.jar:?]

@octa22
Copy link
Contributor

octa22 commented Sep 11, 2023

I have tested this SNAPSHOT in 4.0.2 and 4.0.3, both working fine. Have you disabled the bundled version first?

@BasvanH
Copy link
Author

BasvanH commented Sep 21, 2023

Ok got your build binding working, like you wrote I needed to disable the bundled version. This I never had to do with other build bundles I added to addons. But lets leave that.

The bundle seems to work but I notice it's doing a re-login every few minutes. This should not be necessary as the token is validity is much longer. It's getting 400/401 from certain URL's then the bridge goes in offline and it does a re-login. Any idea's why this is happening?

Secondly, are you using the refresh token method?

Can I see your build code somewhere?

2023-09-21 09:42:37.148 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory] : Querying state disabled
2023-09-21 09:42:37.149 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory] : Component can not be activated since it is in state disabled
2023-09-21 09:42:37.150 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory] : Querying state disabled
2023-09-21 09:42:37.150 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : Updating target filters
2023-09-21 09:42:37.151 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : No change in target property for dependency $000: currently registered: false
2023-09-21 09:42:37.152 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] :  No existing service listener to unregister for dependency $000
2023-09-21 09:42:37.153 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : Setting target property for dependency $000 to null
2023-09-21 09:42:37.153 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : New service tracker for $000, initial active: false, previous references: {}, classFilter: (objectClass=org.openhab.core.io.net.http.HttpClientFactory), initialReferenceFilter (objectClass=org.openhab.core.io.net.http.HttpClientFactory)
2023-09-21 09:42:37.154 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : dm $000 tracker reset (closed)
2023-09-21 09:42:37.155 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : dm $000 tracking 1 SingleStatic added {org.openhab.core.io.net.http.HttpClientFactory, org.openhab.core.io.net.http.WebSocketFactory}={service.id=275, service.bundleid=174, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), component.name=org.openhab.core.io.net.http.internal.WebClientFactoryImpl, component.id=152} (enter)
2023-09-21 09:42:37.156 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : dm $000 tracking 1 SingleStatic active: false trackerOpened: false optional: false
2023-09-21 09:42:37.157 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : dm $000 tracking 1 SingleStatic added {org.openhab.core.io.net.http.HttpClientFactory, org.openhab.core.io.net.http.WebSocketFactory}={service.id=275, service.bundleid=174, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), component.name=org.openhab.core.io.net.http.internal.WebClientFactoryImpl, component.id=152} (exit)
2023-09-21 09:42:37.158 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : dm $000 tracker opened
2023-09-21 09:42:37.159 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : registering service listener for dependency $000
2023-09-21 09:42:37.159 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : No change in target property for dependency $001: currently registered: false
2023-09-21 09:42:37.160 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] :  No existing service listener to unregister for dependency $001
2023-09-21 09:42:37.161 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : Setting target property for dependency $001 to null
2023-09-21 09:42:37.161 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : New service tracker for $001, initial active: false, previous references: {}, classFilter: (objectClass=org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider), initialReferenceFilter (objectClass=org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider)
2023-09-21 09:42:37.162 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : dm $001 tracker reset (closed)
2023-09-21 09:42:37.163 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : dm $001 tracker opened
2023-09-21 09:42:37.163 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : registering service listener for dependency $001
2023-09-21 09:42:37.164 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] :  No existing service listener to unregister for dependency osgi.ds.satisfying.condition
2023-09-21 09:42:37.165 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : Setting target property for dependency osgi.ds.satisfying.condition to (osgi.condition.id=true)
2023-09-21 09:42:37.165 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : New service tracker for osgi.ds.satisfying.condition, initial active: false, previous references: {}, classFilter: (objectClass=org.osgi.service.condition.Condition), initialReferenceFilter (&(objectClass=org.osgi.service.condition.Condition)(osgi.condition.id=true))
2023-09-21 09:42:37.166 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : dm osgi.ds.satisfying.condition tracker reset (closed)
2023-09-21 09:42:37.167 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : dm osgi.ds.satisfying.condition tracking 2 SingleDynamic added {org.osgi.service.condition.Condition}={service.id=6, service.bundleid=0, service.scope=singleton, service.pid=0.org.osgi.service.condition.ConditionImpl, osgi.condition.id=true} (enter)
2023-09-21 09:42:37.168 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : dm osgi.ds.satisfying.condition tracking 2 SingleDynamic added {org.osgi.service.condition.Condition}={service.id=6, service.bundleid=0, service.scope=singleton, service.pid=0.org.osgi.service.condition.ConditionImpl, osgi.condition.id=true} (exit)
2023-09-21 09:42:37.169 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : dm osgi.ds.satisfying.condition tracker opened
2023-09-21 09:42:37.169 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : registering service listener for dependency osgi.ds.satisfying.condition
2023-09-21 09:42:37.170 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : Changed state from disabled to unsatisfiedReference
2023-09-21 09:42:37.170 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : Component enabled
2023-09-21 09:42:37.171 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : ActivateInternal
2023-09-21 09:42:37.172 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : Querying state unsatisfiedReference
2023-09-21 09:42:37.172 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : Querying state unsatisfiedReference
2023-09-21 09:42:37.173 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : Activating component from state unsatisfiedReference
2023-09-21 09:42:37.174 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : Querying state unsatisfiedReference
2023-09-21 09:42:37.175 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : Querying state unsatisfiedReference
2023-09-21 09:42:37.175 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : Dependency not satisfied: $001
2023-09-21 09:42:37.176 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : Not all dependencies satisfied, cannot activate
2023-09-21 09:42:37.177 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider] : Dependency Manager created $000interface=org.openhab.core.events.EventPublisher, filter=null, policy=static, cardinality=1..1, bind=null, unbind=null, updated=null, field=null, field-option=null, collection-type=service, parameter=0
2023-09-21 09:42:37.177 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider] : Dependency Manager created $001interface=org.openhab.core.thing.link.ItemChannelLinkRegistry, filter=null, policy=static, cardinality=1..1, bind=null, unbind=null, updated=null, field=null, field-option=null, collection-type=service, parameter=1
2023-09-21 09:42:37.178 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider] : Dependency Manager created $002interface=org.openhab.core.thing.i18n.ChannelTypeI18nLocalizationService, filter=null, policy=static, cardinality=1..1, bind=null, unbind=null, updated=null, field=null, field-option=null, collection-type=service, parameter=2
2023-09-21 09:42:37.179 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider] : Dependency Manager created osgi.ds.satisfying.conditioninterface=org.osgi.service.condition.Condition, filter=(osgi.condition.id=true), policy=dynamic, cardinality=1..1, bind=null, unbind=null, updated=null, field=null, field-option=null, collection-type=null, parameter=null
2023-09-21 09:42:37.179 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider] : Component created: DS=DS14, implementation=org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider, immediate=false, default-enabled=true, factory=null, configuration-policy=optional, activate=activate, deactivate=deactivate, modified=null configuration-pid=[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider]
2023-09-21 09:42:37.180 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider] : Component Services: scope=singleton, services=[org.openhab.core.thing.type.DynamicStateDescriptionProvider, org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider]
2023-09-21 09:42:37.181 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider] : Component Properties: {osgi.ds.satisfying.condition.target=(osgi.condition.id=true)}
2023-09-21 09:42:37.181 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider] : Querying state disabled
2023-09-21 09:42:37.182 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider] : Querying state disabled
2023-09-21 09:42:37.183 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider] : Component can not be activated since it is in state disabled
2023-09-21 09:42:37.183 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider] : Querying state disabled
2023-09-21 09:42:37.184 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : Updating target filters
2023-09-21 09:42:37.185 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : No change in target property for dependency $000: currently registered: false
2023-09-21 09:42:37.186 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] :  No existing service listener to unregister for dependency $000
2023-09-21 09:42:37.186 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : Setting target property for dependency $000 to null
2023-09-21 09:42:37.187 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : New service tracker for $000, initial active: false, previous references: {}, classFilter: (objectClass=org.openhab.core.events.EventPublisher), initialReferenceFilter (objectClass=org.openhab.core.events.EventPublisher)
2023-09-21 09:42:37.188 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : dm $000 tracker reset (closed)
2023-09-21 09:42:37.189 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : dm $000 tracking 1 SingleStatic added {org.openhab.core.events.EventPublisher}={service.id=168, service.bundleid=150, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), component.name=org.openhab.core.internal.events.OSGiEventPublisher, component.id=14} (enter)
2023-09-21 09:42:37.189 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : dm $000 tracking 1 SingleStatic active: false trackerOpened: false optional: false
2023-09-21 09:42:37.190 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : dm $000 tracking 1 SingleStatic added {org.openhab.core.events.EventPublisher}={service.id=168, service.bundleid=150, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), component.name=org.openhab.core.internal.events.OSGiEventPublisher, component.id=14} (exit)
2023-09-21 09:42:37.191 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : dm $000 tracker opened
2023-09-21 09:42:37.192 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : registering service listener for dependency $000
2023-09-21 09:42:37.192 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : No change in target property for dependency $001: currently registered: false
2023-09-21 09:42:37.193 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] :  No existing service listener to unregister for dependency $001
2023-09-21 09:42:37.194 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : Setting target property for dependency $001 to null
2023-09-21 09:42:37.195 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : New service tracker for $001, initial active: false, previous references: {}, classFilter: (objectClass=org.openhab.core.thing.link.ItemChannelLinkRegistry), initialReferenceFilter (objectClass=org.openhab.core.thing.link.ItemChannelLinkRegistry)
2023-09-21 09:42:37.195 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : dm $001 tracker reset (closed)
2023-09-21 09:42:37.196 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : dm $001 tracking 2 SingleStatic added {org.openhab.core.thing.link.ItemChannelLinkRegistry}={service.id=397, service.bundleid=212, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), component.name=org.openhab.core.thing.link.ItemChannelLinkRegistry, component.id=268} (enter)
2023-09-21 09:42:37.197 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : dm $001 tracking 2 SingleStatic active: false trackerOpened: false optional: false
2023-09-21 09:42:37.198 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : dm $001 tracking 2 SingleStatic added {org.openhab.core.thing.link.ItemChannelLinkRegistry}={service.id=397, service.bundleid=212, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), component.name=org.openhab.core.thing.link.ItemChannelLinkRegistry, component.id=268} (exit)
2023-09-21 09:42:37.198 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : dm $001 tracker opened
2023-09-21 09:42:37.199 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : registering service listener for dependency $001
2023-09-21 09:42:37.200 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : No change in target property for dependency $002: currently registered: false
2023-09-21 09:42:37.201 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] :  No existing service listener to unregister for dependency $002
2023-09-21 09:42:37.202 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : Setting target property for dependency $002 to null
2023-09-21 09:42:37.202 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : New service tracker for $002, initial active: false, previous references: {}, classFilter: (objectClass=org.openhab.core.thing.i18n.ChannelTypeI18nLocalizationService), initialReferenceFilter (objectClass=org.openhab.core.thing.i18n.ChannelTypeI18nLocalizationService)
2023-09-21 09:42:37.203 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : dm $002 tracker reset (closed)
2023-09-21 09:42:37.204 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : dm $002 tracking 3 SingleStatic added {org.openhab.core.thing.i18n.ChannelTypeI18nLocalizationService}={service.id=378, service.bundleid=212, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), component.name=org.openhab.core.thing.i18n.ChannelTypeI18nLocalizationService, component.id=247} (enter)
2023-09-21 09:42:37.204 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : dm $002 tracking 3 SingleStatic active: false trackerOpened: false optional: false
2023-09-21 09:42:37.205 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : dm $002 tracking 3 SingleStatic added {org.openhab.core.thing.i18n.ChannelTypeI18nLocalizationService}={service.id=378, service.bundleid=212, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), component.name=org.openhab.core.thing.i18n.ChannelTypeI18nLocalizationService, component.id=247} (exit)
2023-09-21 09:42:37.206 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : dm $002 tracker opened
2023-09-21 09:42:37.206 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : registering service listener for dependency $002
2023-09-21 09:42:37.207 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] :  No existing service listener to unregister for dependency osgi.ds.satisfying.condition
2023-09-21 09:42:37.208 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : Setting target property for dependency osgi.ds.satisfying.condition to (osgi.condition.id=true)
2023-09-21 09:42:37.208 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : New service tracker for osgi.ds.satisfying.condition, initial active: false, previous references: {}, classFilter: (objectClass=org.osgi.service.condition.Condition), initialReferenceFilter (&(objectClass=org.osgi.service.condition.Condition)(osgi.condition.id=true))
2023-09-21 09:42:37.209 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : dm osgi.ds.satisfying.condition tracker reset (closed)
2023-09-21 09:42:37.209 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : dm osgi.ds.satisfying.condition tracking 4 SingleDynamic added {org.osgi.service.condition.Condition}={service.id=6, service.bundleid=0, service.scope=singleton, service.pid=0.org.osgi.service.condition.ConditionImpl, osgi.condition.id=true} (enter)
2023-09-21 09:42:37.210 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : dm osgi.ds.satisfying.condition tracking 4 SingleDynamic added {org.osgi.service.condition.Condition}={service.id=6, service.bundleid=0, service.scope=singleton, service.pid=0.org.osgi.service.condition.ConditionImpl, osgi.condition.id=true} (exit)
2023-09-21 09:42:37.210 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : dm osgi.ds.satisfying.condition tracker opened
2023-09-21 09:42:37.211 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : registering service listener for dependency osgi.ds.satisfying.condition
2023-09-21 09:42:37.211 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : Changed state from disabled to unsatisfiedReference
2023-09-21 09:42:37.211 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : Component enabled
2023-09-21 09:42:37.212 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : ActivateInternal
2023-09-21 09:42:37.212 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : Querying state unsatisfiedReference
2023-09-21 09:42:37.213 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : Querying state unsatisfiedReference
2023-09-21 09:42:37.213 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : Activating component from state unsatisfiedReference
2023-09-21 09:42:37.213 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : Querying state unsatisfiedReference
2023-09-21 09:42:37.214 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : Querying state unsatisfiedReference
2023-09-21 09:42:37.214 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : Changed state from unsatisfiedReference to satisfied
2023-09-21 09:42:37.214 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : registration change queue [registered]
2023-09-21 09:42:37.216 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : Checking constructor public org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(org.openhab.core.events.EventPublisher,org.openhab.core.thing.link.ItemChannelLinkRegistry,org.openhab.core.thing.i18n.ChannelTypeI18nLocalizationService)
2023-09-21 09:42:37.217 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : getClassFromComponentClassLoader: Looking for interface class org.openhab.core.events.EventPublisher through loader of org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider
2023-09-21 09:42:37.218 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : getClassFromComponentClassLoader: Found class org.openhab.core.events.EventPublisher
2023-09-21 09:42:37.218 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : getClassFromComponentClassLoader: Looking for interface class org.openhab.core.thing.link.ItemChannelLinkRegistry through loader of org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider
2023-09-21 09:42:37.219 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : getClassFromComponentClassLoader: Found class org.openhab.core.thing.link.ItemChannelLinkRegistry
2023-09-21 09:42:37.219 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : getClassFromComponentClassLoader: Looking for interface class org.openhab.core.thing.i18n.ChannelTypeI18nLocalizationService through loader of org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider
2023-09-21 09:42:37.220 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : getClassFromComponentClassLoader: Found class org.openhab.core.thing.i18n.ChannelTypeI18nLocalizationService
2023-09-21 09:42:37.221 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : Found constructor with 3 arguments : public org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(org.openhab.core.events.EventPublisher,org.openhab.core.thing.link.ItemChannelLinkRegistry,org.openhab.core.thing.i18n.ChannelTypeI18nLocalizationService)
2023-09-21 09:42:37.221 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : This thread collected dependencies
2023-09-21 09:42:37.222 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : getService (single component manager) dependencies collected.
2023-09-21 09:42:37.222 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : Querying state satisfied
2023-09-21 09:42:37.223 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : Querying state satisfied
2023-09-21 09:42:37.224 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : For dependency $000, optional: false; to bind: [[RefPair: ref: [{org.openhab.core.events.EventPublisher}={service.id=168, service.bundleid=150, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), component.name=org.openhab.core.internal.events.OSGiEventPublisher, component.id=14}] service: [null]]]
2023-09-21 09:42:37.224 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : For dependency $001, optional: false; to bind: [[RefPair: ref: [{org.openhab.core.thing.link.ItemChannelLinkRegistry}={service.id=397, service.bundleid=212, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), component.name=org.openhab.core.thing.link.ItemChannelLinkRegistry, component.id=268}] service: [null]]]
2023-09-21 09:42:37.225 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : For dependency $002, optional: false; to bind: [[RefPair: ref: [{org.openhab.core.thing.i18n.ChannelTypeI18nLocalizationService}={service.id=378, service.bundleid=212, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), component.name=org.openhab.core.thing.i18n.ChannelTypeI18nLocalizationService, component.id=247}] service: [null]]]
2023-09-21 09:42:37.225 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : For dependency osgi.ds.satisfying.condition, optional: false; to bind: [[RefPair: ref: [{org.osgi.service.condition.Condition}={service.id=6, service.bundleid=0, service.scope=singleton, service.pid=0.org.osgi.service.condition.ConditionImpl, osgi.condition.id=true}] service: [null]]]
2023-09-21 09:42:37.226 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : getting activate: activate
2023-09-21 09:42:37.226 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : Locating method activate in class org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider
2023-09-21 09:42:37.227 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : Declared Method org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider.activate([interface org.osgi.service.component.ComponentContext]) not found
2023-09-21 09:42:37.227 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : Locating method activate in class org.openhab.core.thing.binding.BaseDynamicStateDescriptionProvider
2023-09-21 09:42:37.227 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : Declared Method org.openhab.core.thing.binding.BaseDynamicStateDescriptionProvider.activate([interface org.osgi.service.component.ComponentContext]) not found
2023-09-21 09:42:37.228 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : Locating method activate in class org.openhab.core.thing.binding.AbstractDynamicDescriptionProvider
2023-09-21 09:42:37.228 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : Found activate method: protected void org.openhab.core.thing.binding.AbstractDynamicDescriptionProvider.activate(org.osgi.service.component.ComponentContext)
2023-09-21 09:42:37.229 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : invoking activate: activate: parameters [org.apache.felix.scr.impl.manager.ComponentContextImpl]
2023-09-21 09:42:37.229 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : invoked activate: activate
2023-09-21 09:42:37.229 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : Set implementation object for component
2023-09-21 09:42:37.230 [DEBUG] [TahomaStateDescriptionOptionProvider] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider(413)] : Changed state from satisfied to active
2023-09-21 09:42:37.230 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : dm $001 tracking 3 SingleStatic added {org.openhab.core.thing.type.DynamicStateDescriptionProvider, org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider}={service.id=662, service.bundleid=321, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), component.name=org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider, component.id=413} (enter)
2023-09-21 09:42:37.231 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : ActivateInternal
2023-09-21 09:42:37.231 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : Querying state unsatisfiedReference
2023-09-21 09:42:37.231 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : Querying state unsatisfiedReference
2023-09-21 09:42:37.232 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : Activating component from state unsatisfiedReference
2023-09-21 09:42:37.232 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : Querying state unsatisfiedReference
2023-09-21 09:42:37.232 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : Querying state unsatisfiedReference
2023-09-21 09:42:37.233 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : Changed state from unsatisfiedReference to satisfied
2023-09-21 09:42:37.233 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : registration change queue [registered]
2023-09-21 09:42:37.235 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : Checking constructor public org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(org.openhab.core.io.net.http.HttpClientFactory,org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider)
2023-09-21 09:42:37.236 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : getClassFromComponentClassLoader: Looking for interface class org.openhab.core.io.net.http.HttpClientFactory through loader of org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory
2023-09-21 09:42:37.236 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : getClassFromComponentClassLoader: Found class org.openhab.core.io.net.http.HttpClientFactory
2023-09-21 09:42:37.237 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : getClassFromComponentClassLoader: Looking for interface class org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider through loader of org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory
2023-09-21 09:42:37.237 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : getClassFromComponentClassLoader: Found class org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider
2023-09-21 09:42:37.237 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : Found constructor with 2 arguments : public org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(org.openhab.core.io.net.http.HttpClientFactory,org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider)
2023-09-21 09:42:37.238 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : This thread collected dependencies
2023-09-21 09:42:37.238 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : getService (single component manager) dependencies collected.
2023-09-21 09:42:37.238 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : Querying state satisfied
2023-09-21 09:42:37.239 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : Querying state satisfied
2023-09-21 09:42:37.239 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : For dependency $000, optional: false; to bind: [[RefPair: ref: [{org.openhab.core.io.net.http.HttpClientFactory, org.openhab.core.io.net.http.WebSocketFactory}={service.id=275, service.bundleid=174, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), component.name=org.openhab.core.io.net.http.internal.WebClientFactoryImpl, component.id=152}] service: [null]]]
2023-09-21 09:42:37.239 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : For dependency $001, optional: false; to bind: [[RefPair: ref: [{org.openhab.core.thing.type.DynamicStateDescriptionProvider, org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider}={service.id=662, service.bundleid=321, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), component.name=org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider, component.id=413}] service: [null]]]
2023-09-21 09:42:37.240 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : For dependency osgi.ds.satisfying.condition, optional: false; to bind: [[RefPair: ref: [{org.osgi.service.condition.Condition}={service.id=6, service.bundleid=0, service.scope=singleton, service.pid=0.org.osgi.service.condition.ConditionImpl, osgi.condition.id=true}] service: [null]]]
2023-09-21 09:42:37.241 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : getting activate: activate
2023-09-21 09:42:37.241 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : Locating method activate in class org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory
2023-09-21 09:42:37.241 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : Declared Method org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory.activate([interface org.osgi.service.component.ComponentContext]) not found
2023-09-21 09:42:37.242 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : Locating method activate in class org.openhab.core.thing.binding.BaseThingHandlerFactory
2023-09-21 09:42:37.242 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : Found activate method: protected void org.openhab.core.thing.binding.BaseThingHandlerFactory.activate(org.osgi.service.component.ComponentContext)
2023-09-21 09:42:37.242 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : invoking activate: activate: parameters [org.apache.felix.scr.impl.manager.ComponentContextImpl]
2023-09-21 09:42:37.243 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : invoked activate: activate
2023-09-21 09:42:37.243 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : Set implementation object for component
2023-09-21 09:42:37.244 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : Changed state from satisfied to active
2023-09-21 09:42:37.263 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.SomfyTahomaHandlerFactory(412)] : dm $001 tracking 3 SingleStatic added {org.openhab.core.thing.type.DynamicStateDescriptionProvider, org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider}={service.id=662, service.bundleid=321, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), component.name=org.openhab.binding.somfytahoma.internal.SomfyTahomaStateDescriptionOptionProvider, component.id=413} (exit)
2023-09-21 09:42:37.264 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension] : Dependency Manager created $000interface=org.openhab.core.thing.ThingRegistry, filter=null, policy=static, cardinality=1..1, bind=null, unbind=null, updated=null, field=null, field-option=null, collection-type=service, parameter=0
2023-09-21 09:42:37.264 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension] : Dependency Manager created osgi.ds.satisfying.conditioninterface=org.osgi.service.condition.Condition, filter=(osgi.condition.id=true), policy=dynamic, cardinality=1..1, bind=null, unbind=null, updated=null, field=null, field-option=null, collection-type=null, parameter=null
2023-09-21 09:42:37.265 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension] : Component created: DS=DS14, implementation=org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension, immediate=false, default-enabled=true, factory=null, configuration-policy=optional, activate=activate, deactivate=deactivate, modified=null configuration-pid=[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension]
2023-09-21 09:42:37.265 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension] : Component Services: scope=singleton, services=[org.openhab.core.io.console.extensions.ConsoleCommandExtension]
2023-09-21 09:42:37.266 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension] : Component Properties: {osgi.ds.satisfying.condition.target=(osgi.condition.id=true)}
2023-09-21 09:42:37.266 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension] : Querying state disabled
2023-09-21 09:42:37.267 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension] : Querying state disabled
2023-09-21 09:42:37.267 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension] : Component can not be activated since it is in state disabled
2023-09-21 09:42:37.268 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension] : Querying state disabled
2023-09-21 09:42:37.268 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : Updating target filters
2023-09-21 09:42:37.269 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : No change in target property for dependency $000: currently registered: false
2023-09-21 09:42:37.269 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] :  No existing service listener to unregister for dependency $000
2023-09-21 09:42:37.270 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : Setting target property for dependency $000 to null
2023-09-21 09:42:37.271 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : New service tracker for $000, initial active: false, previous references: {}, classFilter: (objectClass=org.openhab.core.thing.ThingRegistry), initialReferenceFilter (objectClass=org.openhab.core.thing.ThingRegistry)
2023-09-21 09:42:37.271 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : dm $000 tracker reset (closed)
2023-09-21 09:42:37.272 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : dm $000 tracking 1 SingleStatic added {org.openhab.core.thing.ThingRegistry}={service.id=382, service.bundleid=212, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), component.name=org.openhab.core.thing.internal.ThingRegistryImpl, component.id=258} (enter)
2023-09-21 09:42:37.273 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : dm $000 tracking 1 SingleStatic active: false trackerOpened: false optional: false
2023-09-21 09:42:37.274 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : dm $000 tracking 1 SingleStatic added {org.openhab.core.thing.ThingRegistry}={service.id=382, service.bundleid=212, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), component.name=org.openhab.core.thing.internal.ThingRegistryImpl, component.id=258} (exit)
2023-09-21 09:42:37.274 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : dm $000 tracker opened
2023-09-21 09:42:37.275 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : registering service listener for dependency $000
2023-09-21 09:42:37.276 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] :  No existing service listener to unregister for dependency osgi.ds.satisfying.condition
2023-09-21 09:42:37.276 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : Setting target property for dependency osgi.ds.satisfying.condition to (osgi.condition.id=true)
2023-09-21 09:42:37.277 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : New service tracker for osgi.ds.satisfying.condition, initial active: false, previous references: {}, classFilter: (objectClass=org.osgi.service.condition.Condition), initialReferenceFilter (&(objectClass=org.osgi.service.condition.Condition)(osgi.condition.id=true))
2023-09-21 09:42:37.278 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : dm osgi.ds.satisfying.condition tracker reset (closed)
2023-09-21 09:42:37.278 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : dm osgi.ds.satisfying.condition tracking 2 SingleDynamic added {org.osgi.service.condition.Condition}={service.id=6, service.bundleid=0, service.scope=singleton, service.pid=0.org.osgi.service.condition.ConditionImpl, osgi.condition.id=true} (enter)
2023-09-21 09:42:37.279 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : dm osgi.ds.satisfying.condition tracking 2 SingleDynamic added {org.osgi.service.condition.Condition}={service.id=6, service.bundleid=0, service.scope=singleton, service.pid=0.org.osgi.service.condition.ConditionImpl, osgi.condition.id=true} (exit)
2023-09-21 09:42:37.280 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : dm osgi.ds.satisfying.condition tracker opened
2023-09-21 09:42:37.280 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : registering service listener for dependency osgi.ds.satisfying.condition
2023-09-21 09:42:37.281 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : Changed state from disabled to unsatisfiedReference
2023-09-21 09:42:37.282 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : Component enabled
2023-09-21 09:42:37.282 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : ActivateInternal
2023-09-21 09:42:37.283 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : Querying state unsatisfiedReference
2023-09-21 09:42:37.283 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : Querying state unsatisfiedReference
2023-09-21 09:42:37.284 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : Activating component from state unsatisfiedReference
2023-09-21 09:42:37.284 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : Querying state unsatisfiedReference
2023-09-21 09:42:37.285 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : Querying state unsatisfiedReference
2023-09-21 09:42:37.285 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : Changed state from unsatisfiedReference to satisfied
2023-09-21 09:42:37.286 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : registration change queue [registered]
2023-09-21 09:42:37.288 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : Checking constructor public org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(org.openhab.core.thing.ThingRegistry)
2023-09-21 09:42:37.289 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : getClassFromComponentClassLoader: Looking for interface class org.openhab.core.thing.ThingRegistry through loader of org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension
2023-09-21 09:42:37.290 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : getClassFromComponentClassLoader: Found class org.openhab.core.thing.ThingRegistry
2023-09-21 09:42:37.290 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : Found constructor with 1 arguments : public org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(org.openhab.core.thing.ThingRegistry)
2023-09-21 09:42:37.291 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : This thread collected dependencies
2023-09-21 09:42:37.291 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : getService (single component manager) dependencies collected.
2023-09-21 09:42:37.292 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : Querying state satisfied
2023-09-21 09:42:37.292 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : Querying state satisfied
2023-09-21 09:42:37.293 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : For dependency $000, optional: false; to bind: [[RefPair: ref: [{org.openhab.core.thing.ThingRegistry}={service.id=382, service.bundleid=212, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), component.name=org.openhab.core.thing.internal.ThingRegistryImpl, component.id=258}] service: [null]]]
2023-09-21 09:42:37.293 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : For dependency osgi.ds.satisfying.condition, optional: false; to bind: [[RefPair: ref: [{org.osgi.service.condition.Condition}={service.id=6, service.bundleid=0, service.scope=singleton, service.pid=0.org.osgi.service.condition.ConditionImpl, osgi.condition.id=true}] service: [null]]]
2023-09-21 09:42:37.294 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : getting activate: activate
2023-09-21 09:42:37.295 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : Locating method activate in class org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension
2023-09-21 09:42:37.296 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : Declared Method org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension.activate([interface org.osgi.service.component.ComponentContext]) not found
2023-09-21 09:42:37.297 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : Locating method activate in class org.openhab.core.io.console.extensions.AbstractConsoleCommandExtension
2023-09-21 09:42:37.297 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : Declared Method org.openhab.core.io.console.extensions.AbstractConsoleCommandExtension.activate([interface org.osgi.service.component.ComponentContext]) not found
2023-09-21 09:42:37.298 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : Locating method activate in class java.lang.Object
2023-09-21 09:42:37.299 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : Declared Method java.lang.Object.activate([interface org.osgi.service.component.ComponentContext]) not found
2023-09-21 09:42:37.299 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : activate method [activate] not found, ignoring
2023-09-21 09:42:37.300 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : Set implementation object for component
2023-09-21 09:42:37.300 [DEBUG] [.console.SomfyTahomaCommandExtension] - bundle org.openhab.binding.somfytahoma:4.1.0.202309030902 (321)[org.openhab.binding.somfytahoma.internal.console.SomfyTahomaCommandExtension(414)] : Changed state from satisfied to active
2023-09-21 09:42:38.667 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - Creating handler for bridge
2023-09-21 09:42:38.675 [DEBUG] [very.SomfyTahomaItemDiscoveryService] - Creating discovery service
2023-09-21 09:42:38.676 [DEBUG] [very.SomfyTahomaItemDiscoveryService] - Starting SomfyTahoma background discovery
2023-09-21 09:42:38.683 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - Creating handler for venetianblind
2023-09-21 09:42:38.686 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - Creating handler for gateway
2023-09-21 09:42:38.686 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - Creating handler for exteriorscreen
2023-09-21 09:42:38.686 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - Creating handler for venetianblind
2023-09-21 09:42:38.695 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - Creating handler for exteriorscreen
2023-09-21 09:42:38.697 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - Creating handler for exteriorscreen
2023-09-21 09:42:38.703 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Postponing login to avoid throttling
2023-09-21 09:42:38.704 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - Creating handler for venetianblind
2023-09-21 09:42:38.704 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Initialize done...
2023-09-21 09:42:38.711 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - Creating handler for awning
2023-09-21 09:42:38.722 [DEBUG] [a.internal.SomfyTahomaHandlerFactory] - Creating handler for venetianblind
2023-09-21 09:42:48.677 [DEBUG] [very.SomfyTahomaItemDiscoveryService] - Starting scanning for things...
2023-09-21 09:42:48.677 [DEBUG] [very.SomfyTahomaItemDiscoveryService] - Cannot start discovery since the bridge is not online!
2023-09-21 09:42:48.704 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Getting Tahoma Updates...
2023-09-21 09:43:38.704 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Refreshing Tahoma states...
2023-09-21 09:43:38.705 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending PUT to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/setup/devices/states/refresh with data: 
2023-09-21 09:43:38.791 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Received unexpected status code: 401
2023-09-21 09:43:38.792 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Cannot call url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/setup/devices/states/refresh with params: !
	at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.sendMethodToTahomaWithCookie(SomfyTahomaBridgeHandler.java:833) ~[?:?]
	at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.sendMethodToTahomaWithCookie(SomfyTahomaBridgeHandler.java:803) ~[?:?]
	at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.sendPutToTahomaWithCookie(SomfyTahomaBridgeHandler.java:793) ~[?:?]
	at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.invokeCallToURL(SomfyTahomaBridgeHandler.java:1170) ~[?:?]
	at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.forceGatewaySync(SomfyTahomaBridgeHandler.java:1096) ~[?:?]
	at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.refreshTahomaStates(SomfyTahomaBridgeHandler.java:754) ~[?:?]
	at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.lambda$2(SomfyTahomaBridgeHandler.java:222) ~[?:?]
2023-09-21 09:45:48.704 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Getting Tahoma Updates...
2023-09-21 09:45:48.705 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Doing relogin
2023-09-21 09:45:49.439 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - OAuth2 Access Token: MjBhZGJmZjgzYjY5OTA0MmZhZGU0ZTNhNDIwNGJmZjE3MTg2ZjMwN2VjMGNlYjJlYzZkODE2YWUyNTk1YTE1Yw
2023-09-21 09:45:49.440 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending POST to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/events/register with data: 
2023-09-21 09:45:49.558 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Events id: b6b3c5ed-0a19-0482-6976-d2290a394493
2023-09-21 09:45:49.560 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending GET to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/setup/devices with data: 
2023-09-21 09:45:49.560 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending GET to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/setup/gateways/1227-9296-2479 with data: 
2023-09-21 09:45:49.561 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending POST to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/events/b6b3c5ed-0a19-0482-6976-d2290a394493/fetch with data: 
2023-09-21 09:45:49.618 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/12411512 updating RSSI channel with value: 62.0
2023-09-21 09:45:49.619 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/1512731 updating RSSI channel with value: 50.0
2023-09-21 09:45:49.620 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/12411512 updating channel: control with value: 0.0
2023-09-21 09:45:49.620 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/4379625 updating RSSI channel with value: 32.0
2023-09-21 09:45:49.621 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/4379625 updating channel: control with value: 0.0
2023-09-21 09:45:49.620 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/1512731 updating channel: control with value: 0.0
2023-09-21 09:45:49.622 [DEBUG] [nal.handler.SomfyTahomaAwningHandler] - io://1227-9296-2479/12727770 updating RSSI channel with value: 74.0
2023-09-21 09:45:49.623 [DEBUG] [nal.handler.SomfyTahomaAwningHandler] - io://1227-9296-2479/12727770 updating channel: control with value: 0.0
2023-09-21 09:45:49.630 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Tahoma status: OK
2023-09-21 09:45:49.631 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Tahoma protocol version: 2023.3.4
2023-09-21 09:45:49.632 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending GET to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/actionGroups with data: 
2023-09-21 09:48:38.794 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Refreshing Tahoma states...
2023-09-21 09:48:38.794 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending PUT to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/setup/devices/states/refresh with data: 
2023-09-21 09:48:49.630 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Getting Tahoma Updates...
2023-09-21 09:48:49.631 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending POST to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/events/b6b3c5ed-0a19-0482-6976-d2290a394493/fetch with data: 
2023-09-21 09:48:49.682 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Received unexpected status code: 400
2023-09-21 09:48:49.683 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Cannot call url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/events/b6b3c5ed-0a19-0482-6976-d2290a394493/fetch with params: !
	at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.sendMethodToTahomaWithCookie(SomfyTahomaBridgeHandler.java:833) ~[?:?]
	at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.sendPostToTahomaWithCookie(SomfyTahomaBridgeHandler.java:783) ~[?:?]
	at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.invokeCallToURL(SomfyTahomaBridgeHandler.java:1173) ~[?:?]
	at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.getEvents(SomfyTahomaBridgeHandler.java:456) ~[?:?]
	at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.getTahomaUpdates(SomfyTahomaBridgeHandler.java:587) ~[?:?]
	at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.lambda$4(SomfyTahomaBridgeHandler.java:232) ~[?:?]
2023-09-21 09:51:49.686 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Getting Tahoma Updates...
2023-09-21 09:51:49.686 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Doing relogin
2023-09-21 09:51:50.323 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - OAuth2 Access Token: NDViNzg5ZWEyY2VkMTc4MmY4MzI3ZmI0NDIzYTYwNTIwY2RhYWVhNmQwNmI2NGVmNjEwODMxY2FjMDkzZTUyMg
2023-09-21 09:51:50.323 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending POST to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/events/register with data: 
2023-09-21 09:51:50.421 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Events id: b6b9478d-0a19-0482-6976-d229e5a23612
2023-09-21 09:51:50.422 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending POST to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/events/b6b9478d-0a19-0482-6976-d229e5a23612/fetch with data: 
2023-09-21 09:51:50.422 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending GET to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/setup/devices with data: 
2023-09-21 09:51:50.423 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending GET to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/setup/gateways/1227-9296-2479 with data: 
2023-09-21 09:51:50.450 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Tahoma status: OK
2023-09-21 09:51:50.450 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Tahoma protocol version: 2023.3.4
2023-09-21 09:51:50.451 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending GET to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/actionGroups with data: 
2023-09-21 09:51:50.503 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/4379625 updating RSSI channel with value: 32.0
2023-09-21 09:51:50.503 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/12411512 updating RSSI channel with value: 62.0
2023-09-21 09:51:50.504 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/4379625 updating channel: control with value: 0.0
2023-09-21 09:51:50.503 [DEBUG] [nal.handler.SomfyTahomaAwningHandler] - io://1227-9296-2479/12727770 updating RSSI channel with value: 74.0
2023-09-21 09:51:50.505 [DEBUG] [nal.handler.SomfyTahomaAwningHandler] - io://1227-9296-2479/12727770 updating channel: control with value: 0.0
2023-09-21 09:51:50.503 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/1512731 updating RSSI channel with value: 50.0
2023-09-21 09:51:50.505 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/1512731 updating channel: control with value: 0.0
2023-09-21 09:51:50.506 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/12411512 updating channel: control with value: 0.0
2023-09-21 09:52:38.704 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Enabling reconciliation
2023-09-21 09:53:38.878 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Refreshing Tahoma states...
2023-09-21 09:53:38.879 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending PUT to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/setup/devices/states/refresh with data: 
2023-09-21 09:54:50.436 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Getting Tahoma Updates...
2023-09-21 09:54:50.436 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending POST to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/events/b6b9478d-0a19-0482-6976-d229e5a23612/fetch with data: 
2023-09-21 09:54:50.508 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: GatewaySynchronizationStartedEvent
2023-09-21 09:54:50.509 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: GatewaySynchronizationEndedEvent
2023-09-21 09:54:50.509 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: GatewaySynchronizationStartedEvent
2023-09-21 09:54:50.509 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: GatewaySynchronizationEndedEvent
2023-09-21 09:54:50.510 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: GatewaySynchronizationStartedEvent
2023-09-21 09:54:50.510 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: GatewaySynchronizationEndedEvent
2023-09-21 09:54:50.510 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: RefreshAllDevicesStatesCompletedEvent
2023-09-21 09:54:51.512 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Updating all states
2023-09-21 09:54:51.512 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending GET to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/setup/devices with data: 
2023-09-21 09:54:51.555 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/12411512 updating RSSI channel with value: 62.0
2023-09-21 09:54:51.556 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/12411512 updating channel: control with value: 0.0
2023-09-21 09:54:51.557 [DEBUG] [nal.handler.SomfyTahomaAwningHandler] - io://1227-9296-2479/12727770 updating RSSI channel with value: 74.0
2023-09-21 09:54:51.558 [DEBUG] [nal.handler.SomfyTahomaAwningHandler] - io://1227-9296-2479/12727770 updating channel: control with value: 0.0
2023-09-21 09:54:51.559 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/1512731 updating RSSI channel with value: 50.0
2023-09-21 09:54:51.560 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/1512731 updating channel: control with value: 0.0
2023-09-21 09:54:51.561 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/4379625 updating RSSI channel with value: 32.0
2023-09-21 09:54:51.562 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/4379625 updating channel: control with value: 0.0
2023-09-21 09:57:50.511 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Getting Tahoma Updates...
2023-09-21 09:57:50.512 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending POST to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/events/b6b9478d-0a19-0482-6976-d229e5a23612/fetch with data: 
2023-09-21 09:57:50.583 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Received unexpected status code: 400
2023-09-21 09:57:50.584 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Cannot call url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/events/b6b9478d-0a19-0482-6976-d229e5a23612/fetch with params: !
	at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.sendMethodToTahomaWithCookie(SomfyTahomaBridgeHandler.java:833) ~[?:?]
	at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.sendPostToTahomaWithCookie(SomfyTahomaBridgeHandler.java:783) ~[?:?]
	at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.invokeCallToURL(SomfyTahomaBridgeHandler.java:1173) ~[?:?]
	at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.getEvents(SomfyTahomaBridgeHandler.java:456) ~[?:?]
	at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.getTahomaUpdates(SomfyTahomaBridgeHandler.java:587) ~[?:?]
	at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.lambda$4(SomfyTahomaBridgeHandler.java:232) ~[?:?]
2023-09-21 09:58:38.949 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Refreshing Tahoma states...
2023-09-21 09:58:38.950 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Doing relogin
2023-09-21 09:58:39.552 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - OAuth2 Access Token: Mjc0NDRiMGExOGRhNTFjMGQ1ZWU3OWRmZDEwOTY1MmZhYWMzMmYzYWI1MjRlMWM4YjdkMGVmZTI4MTQzMTI4MA
2023-09-21 09:58:39.553 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending POST to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/events/register with data: 
2023-09-21 09:58:39.649 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Events id: b6bf8619-0a19-0482-6976-d229e48fbc15
2023-09-21 09:58:39.649 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending PUT to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/setup/devices/states/refresh with data: 
2023-09-21 09:58:39.650 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending GET to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/setup/devices with data: 
2023-09-21 09:58:39.650 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending GET to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/setup/gateways/1227-9296-2479 with data: 
2023-09-21 09:58:39.680 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Tahoma status: OK
2023-09-21 09:58:39.681 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Tahoma protocol version: 2023.3.4
2023-09-21 09:58:39.681 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending GET to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/actionGroups with data: 
2023-09-21 09:58:39.731 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/4379625 updating RSSI channel with value: 32.0
2023-09-21 09:58:39.731 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/12411512 updating RSSI channel with value: 62.0
2023-09-21 09:58:39.732 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/4379625 updating channel: control with value: 0.0
2023-09-21 09:58:39.732 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/12411512 updating channel: control with value: 0.0
2023-09-21 09:58:39.733 [DEBUG] [nal.handler.SomfyTahomaAwningHandler] - io://1227-9296-2479/12727770 updating RSSI channel with value: 74.0
2023-09-21 09:58:39.733 [DEBUG] [nal.handler.SomfyTahomaAwningHandler] - io://1227-9296-2479/12727770 updating channel: control with value: 0.0
2023-09-21 09:58:39.733 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/1512731 updating RSSI channel with value: 50.0
2023-09-21 09:58:39.734 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/1512731 updating channel: control with value: 0.0
2023-09-21 10:00:50.586 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Getting Tahoma Updates...
2023-09-21 10:00:50.587 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending POST to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/events/b6bf8619-0a19-0482-6976-d229e48fbc15/fetch with data: 
2023-09-21 10:00:50.659 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Received unexpected status code: 400
2023-09-21 10:00:50.660 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Cannot call url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/events/b6bf8619-0a19-0482-6976-d229e48fbc15/fetch with params: !
	at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.sendMethodToTahomaWithCookie(SomfyTahomaBridgeHandler.java:833) ~[?:?]
	at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.sendPostToTahomaWithCookie(SomfyTahomaBridgeHandler.java:783) ~[?:?]
	at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.invokeCallToURL(SomfyTahomaBridgeHandler.java:1173) ~[?:?]
	at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.getEvents(SomfyTahomaBridgeHandler.java:456) ~[?:?]
	at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.getTahomaUpdates(SomfyTahomaBridgeHandler.java:587) ~[?:?]
	at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.lambda$4(SomfyTahomaBridgeHandler.java:232) ~[?:?]
2023-09-21 10:02:38.705 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Enabling reconciliation
2023-09-21 10:02:44.956 [DEBUG] [nal.handler.SomfyTahomaAwningHandler] - io://1227-9296-2479/12727770 Received command 0 for channel somfytahoma:awning:a52746421f:22b15ab1-7d32-42e6-9e43-2b3b08196263:control
2023-09-21 10:02:44.957 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Doing relogin
2023-09-21 10:02:45.579 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - OAuth2 Access Token: ZjZlOTMwN2QzMmZkMGYyMzIyNWY2YThkZWQxYmNiNjRiMDA2MmJhYzA3ZDk5NzUyMDA5YjdkNjYzM2JkZDAyNw
2023-09-21 10:02:45.579 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending POST to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/events/register with data: 
2023-09-21 10:02:45.689 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Events id: b6c34730-0a19-0482-6976-d229b77ec797
2023-09-21 10:02:45.690 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending GET to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/setup/devices with data: 
2023-09-21 10:02:45.691 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending GET to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/setup/gateways/1227-9296-2479 with data: 
2023-09-21 10:02:45.692 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Currently 0 retries are scheduled.
2023-09-21 10:02:45.693 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending POST to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/exec/apply with data: {"label":"Zonnescherm - setDeployment [0] - openHAB","actions":[{"deviceURL":"io://1227-9296-2479/12727770","commands":[{"name":"setDeployment","parameters":[0]}]}]}
2023-09-21 10:02:45.733 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/4379625 updating RSSI channel with value: 32.0
2023-09-21 10:02:45.733 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/1512731 updating RSSI channel with value: 50.0
2023-09-21 10:02:45.734 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/4379625 updating channel: control with value: 0.0
2023-09-21 10:02:45.733 [DEBUG] [nal.handler.SomfyTahomaAwningHandler] - io://1227-9296-2479/12727770 updating RSSI channel with value: 74.0
2023-09-21 10:02:45.734 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/12411512 updating RSSI channel with value: 62.0
2023-09-21 10:02:45.736 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/1512731 updating channel: control with value: 0.0
2023-09-21 10:02:45.736 [DEBUG] [nal.handler.SomfyTahomaAwningHandler] - io://1227-9296-2479/12727770 updating channel: control with value: 0.0
2023-09-21 10:02:45.736 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/12411512 updating channel: control with value: 0.0
2023-09-21 10:02:45.742 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Tahoma status: OK
2023-09-21 10:02:45.743 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Tahoma protocol version: 2023.3.4
2023-09-21 10:02:45.744 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending GET to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/actionGroups with data: 
2023-09-21 10:02:45.748 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Exec id: b6c34768-0a19-0482-6976-d2299a9de594
2023-09-21 10:02:45.959 [DEBUG] [nal.handler.SomfyTahomaAwningHandler] - io://1227-9296-2479/12727770 Received command 13 for channel somfytahoma:awning:a52746421f:22b15ab1-7d32-42e6-9e43-2b3b08196263:control
2023-09-21 10:02:45.960 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Currently 0 retries are scheduled.
2023-09-21 10:02:45.960 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending POST to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/exec/apply with data: {"label":"Zonnescherm - setDeployment [13] - openHAB","actions":[{"deviceURL":"io://1227-9296-2479/12727770","commands":[{"name":"setDeployment","parameters":[13]}]}]}
2023-09-21 10:02:45.979 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Exec id: b6c3484f-0a19-0482-6976-d229ca6589e9
2023-09-21 10:02:45.980 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Previous execution exists for url: io://1227-9296-2479/12727770
2023-09-21 10:02:47.980 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Getting Tahoma Updates...
2023-09-21 10:02:47.981 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending POST to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/events/b6c34730-0a19-0482-6976-d229b77ec797/fetch with data: 
2023-09-21 10:02:47.998 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: ExecutionRegisteredEvent
2023-09-21 10:02:47.999 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: ExecutionStateChangedEvent
2023-09-21 10:02:48.000 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: GatewaySynchronizationStartedEvent
2023-09-21 10:02:48.000 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: ExecutionStateChangedEvent
2023-09-21 10:02:48.001 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: GatewaySynchronizationEndedEvent
2023-09-21 10:02:48.001 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: ExecutionRegisteredEvent
2023-09-21 10:02:48.002 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Previous execution exists for url: 
2023-09-21 10:02:48.002 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: ExecutionStateChangedEvent
2023-09-21 10:02:48.003 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: GatewaySynchronizationStartedEvent
2023-09-21 10:02:48.003 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: ExecutionStateChangedEvent
2023-09-21 10:02:48.004 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: GatewaySynchronizationEndedEvent
2023-09-21 10:02:48.004 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: DeviceStateChangedEvent
2023-09-21 10:02:48.005 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - States for device io://1227-9296-2479/12727770 : [{name='core:TargetClosureState', type=1, value=13}, {name='core:MovingState', type=6, value=true}]
2023-09-21 10:02:48.005 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Updating status of thing: Somfy - Zonnescherm
2023-09-21 10:02:48.008 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: ExecutionStateChangedEvent
2023-09-21 10:02:48.008 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Removing execution id: b6c34768-0a19-0482-6976-d2299a9de594
2023-09-21 10:02:48.009 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Cannot remove execution id: b6c34768-0a19-0482-6976-d2299a9de594, because it is not registered
2023-09-21 10:02:48.010 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: ExecutionStateChangedEvent
2023-09-21 10:02:50.010 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Getting Tahoma Updates...
2023-09-21 10:02:50.011 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending POST to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/events/b6c34730-0a19-0482-6976-d229b77ec797/fetch with data: 
2023-09-21 10:02:52.027 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Getting Tahoma Updates...
2023-09-21 10:02:52.028 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending POST to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/events/b6c34730-0a19-0482-6976-d229b77ec797/fetch with data: 
2023-09-21 10:02:54.043 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Getting Tahoma Updates...
2023-09-21 10:02:54.044 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending POST to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/events/b6c34730-0a19-0482-6976-d229b77ec797/fetch with data: 
2023-09-21 10:02:54.059 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: DeviceStateChangedEvent
2023-09-21 10:02:54.060 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - States for device io://1227-9296-2479/12727770 : [{name='core:ManufacturerSettingsState', type=3, value=java.lang.Object@7729abc}, {name='core:OpenClosedState', type=3, value=open}, {name='core:DeploymentState', type=1, value=13}, {name='core:OpenClosedState', type=3, value=open}, {name='core:DeploymentState', type=1, value=13}, {name='core:MovingState', type=6, value=false}]
2023-09-21 10:02:54.061 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Updating status of thing: Somfy - Zonnescherm
2023-09-21 10:02:54.061 [DEBUG] [nal.handler.SomfyTahomaAwningHandler] - io://1227-9296-2479/12727770 updating channel: control with value: 13
2023-09-21 10:02:54.062 [DEBUG] [nal.handler.SomfyTahomaAwningHandler] - io://1227-9296-2479/12727770 updating channel: control with value: 13
2023-09-21 10:02:54.064 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: ExecutionStateChangedEvent
2023-09-21 10:02:54.065 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Removing execution id: b6c3484f-0a19-0482-6976-d229ca6589e9
2023-09-21 10:03:13.360 [DEBUG] [nal.handler.SomfyTahomaAwningHandler] - io://1227-9296-2479/12727770 Received command 0 for channel somfytahoma:awning:a52746421f:22b15ab1-7d32-42e6-9e43-2b3b08196263:control
2023-09-21 10:03:13.361 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Currently 0 retries are scheduled.
2023-09-21 10:03:13.361 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending POST to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/exec/apply with data: {"label":"Zonnescherm - setDeployment [0] - openHAB","actions":[{"deviceURL":"io://1227-9296-2479/12727770","commands":[{"name":"setDeployment","parameters":[0]}]}]}
2023-09-21 10:03:13.413 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Exec id: b6c3b37a-0a19-0482-6976-d2292e70a447
2023-09-21 10:03:15.414 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Getting Tahoma Updates...
2023-09-21 10:03:15.414 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending POST to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/events/b6c34730-0a19-0482-6976-d229b77ec797/fetch with data: 
2023-09-21 10:03:15.429 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: ExecutionRegisteredEvent
2023-09-21 10:03:15.429 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: ExecutionStateChangedEvent
2023-09-21 10:03:15.430 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: GatewaySynchronizationStartedEvent
2023-09-21 10:03:15.430 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: ExecutionStateChangedEvent
2023-09-21 10:03:15.430 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: GatewaySynchronizationEndedEvent
2023-09-21 10:03:15.430 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: DeviceStateChangedEvent
2023-09-21 10:03:15.430 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - States for device io://1227-9296-2479/12727770 : [{name='core:TargetClosureState', type=1, value=0}, {name='core:MovingState', type=6, value=true}]
2023-09-21 10:03:15.430 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Updating status of thing: Somfy - Zonnescherm
2023-09-21 10:03:15.431 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: ExecutionStateChangedEvent
2023-09-21 10:03:17.432 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Getting Tahoma Updates...
2023-09-21 10:03:17.432 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending POST to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/events/b6c34730-0a19-0482-6976-d229b77ec797/fetch with data: 
2023-09-21 10:03:19.447 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Getting Tahoma Updates...
2023-09-21 10:03:19.448 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending POST to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/events/b6c34730-0a19-0482-6976-d229b77ec797/fetch with data: 
2023-09-21 10:03:21.463 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Getting Tahoma Updates...
2023-09-21 10:03:21.463 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending POST to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/events/b6c34730-0a19-0482-6976-d229b77ec797/fetch with data: 
2023-09-21 10:03:21.478 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: DeviceStateChangedEvent
2023-09-21 10:03:21.479 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - States for device io://1227-9296-2479/12727770 : [{name='core:ManufacturerSettingsState', type=3, value=java.lang.Object@1e499781}, {name='core:OpenClosedState', type=3, value=closed}, {name='core:DeploymentState', type=1, value=0}, {name='core:OpenClosedState', type=3, value=closed}, {name='core:DeploymentState', type=1, value=0}]
2023-09-21 10:03:21.480 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Updating status of thing: Somfy - Zonnescherm
2023-09-21 10:03:21.480 [DEBUG] [nal.handler.SomfyTahomaAwningHandler] - io://1227-9296-2479/12727770 updating channel: control with value: 0
2023-09-21 10:03:21.481 [DEBUG] [nal.handler.SomfyTahomaAwningHandler] - io://1227-9296-2479/12727770 updating channel: control with value: 0
2023-09-21 10:03:23.483 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Getting Tahoma Updates...
2023-09-21 10:03:23.484 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending POST to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/events/b6c34730-0a19-0482-6976-d229b77ec797/fetch with data: 
2023-09-21 10:03:23.499 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: DeviceStateChangedEvent
2023-09-21 10:03:23.500 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - States for device io://1227-9296-2479/12727770 : [{name='core:MovingState', type=6, value=false}]
2023-09-21 10:03:23.500 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Updating status of thing: Somfy - Zonnescherm
2023-09-21 10:03:23.502 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: ExecutionStateChangedEvent
2023-09-21 10:03:23.502 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Removing execution id: b6c3b37a-0a19-0482-6976-d2292e70a447
2023-09-21 10:03:39.666 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Refreshing Tahoma states...
2023-09-21 10:03:39.667 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending PUT to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/setup/devices/states/refresh with data: 
2023-09-21 10:04:58.478 [DEBUG] [nal.handler.SomfyTahomaAwningHandler] - io://1227-9296-2479/12727770 Received command 5 for channel somfytahoma:awning:a52746421f:22b15ab1-7d32-42e6-9e43-2b3b08196263:control
2023-09-21 10:04:58.479 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Currently 0 retries are scheduled.
2023-09-21 10:04:58.480 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending POST to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/exec/apply with data: {"label":"Zonnescherm - setDeployment [5] - openHAB","actions":[{"deviceURL":"io://1227-9296-2479/12727770","commands":[{"name":"setDeployment","parameters":[5]}]}]}
2023-09-21 10:04:58.556 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Exec id: b6c54e30-0a19-0482-6976-d22930fb37c4
2023-09-21 10:05:00.557 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Getting Tahoma Updates...
2023-09-21 10:05:00.558 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending POST to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/events/b6c34730-0a19-0482-6976-d229b77ec797/fetch with data: 
2023-09-21 10:05:00.572 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: GatewaySynchronizationStartedEvent
2023-09-21 10:05:00.572 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: GatewaySynchronizationEndedEvent
2023-09-21 10:05:00.572 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: GatewaySynchronizationStartedEvent
2023-09-21 10:05:00.572 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: GatewaySynchronizationEndedEvent
2023-09-21 10:05:00.573 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: GatewaySynchronizationStartedEvent
2023-09-21 10:05:00.573 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: GatewaySynchronizationEndedEvent
2023-09-21 10:05:00.573 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: RefreshAllDevicesStatesCompletedEvent
2023-09-21 10:05:00.573 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: GatewaySynchronizationStartedEvent
2023-09-21 10:05:00.573 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: GatewaySynchronizationEndedEvent
2023-09-21 10:05:00.574 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: GatewaySynchronizationStartedEvent
2023-09-21 10:05:00.574 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: PushSubscriptionCreatedEvent
2023-09-21 10:05:00.574 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: GatewaySynchronizationEndedEvent
2023-09-21 10:05:00.574 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: GatewaySynchronizationStartedEvent
2023-09-21 10:05:00.574 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: GatewaySynchronizationEndedEvent
2023-09-21 10:05:00.574 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: RefreshAllDevicesStatesCompletedEvent
2023-09-21 10:05:00.575 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: ExecutionRegisteredEvent
2023-09-21 10:05:00.575 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: ExecutionStateChangedEvent
2023-09-21 10:05:00.575 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: GatewaySynchronizationStartedEvent
2023-09-21 10:05:00.576 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: ExecutionStateChangedEvent
2023-09-21 10:05:00.576 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: GatewaySynchronizationEndedEvent
2023-09-21 10:05:00.576 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: ExecutionStateChangedEvent
2023-09-21 10:05:00.576 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: ExecutionRegisteredEvent
2023-09-21 10:05:00.576 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Previous execution exists for url: 
2023-09-21 10:05:00.576 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: ExecutionStateChangedEvent
2023-09-21 10:05:00.577 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: GatewaySynchronizationStartedEvent
2023-09-21 10:05:00.577 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: ExecutionStateChangedEvent
2023-09-21 10:05:00.577 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: GatewaySynchronizationEndedEvent
2023-09-21 10:05:00.577 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: DeviceStateChangedEvent
2023-09-21 10:05:00.577 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - States for device io://1227-9296-2479/12727770 : [{name='core:TargetClosureState', type=1, value=13}, {name='core:MovingState', type=6, value=true}]
2023-09-21 10:05:00.578 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Updating status of thing: Somfy - Zonnescherm
2023-09-21 10:05:00.579 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: ExecutionStateChangedEvent
2023-09-21 10:05:00.579 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: DeviceStateChangedEvent
2023-09-21 10:05:00.579 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - States for device io://1227-9296-2479/12727770 : [{name='core:ManufacturerSettingsState', type=3, value=java.lang.Object@39d49e4e}, {name='core:OpenClosedState', type=3, value=open}, {name='core:DeploymentState', type=1, value=13}, {name='core:OpenClosedState', type=3, value=open}, {name='core:DeploymentState', type=1, value=13}, {name='core:MovingState', type=6, value=false}]
2023-09-21 10:05:00.579 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Updating status of thing: Somfy - Zonnescherm
2023-09-21 10:05:00.580 [DEBUG] [nal.handler.SomfyTahomaAwningHandler] - io://1227-9296-2479/12727770 updating channel: control with value: 13
2023-09-21 10:05:00.580 [DEBUG] [nal.handler.SomfyTahomaAwningHandler] - io://1227-9296-2479/12727770 updating channel: control with value: 13
2023-09-21 10:05:00.582 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: ExecutionStateChangedEvent
2023-09-21 10:05:00.582 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Removing execution id: b6c4b7d5-0a19-0482-6976-d229db716893
2023-09-21 10:05:00.582 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: ExecutionStateChangedEvent
2023-09-21 10:05:00.583 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Removing execution id: b6c481c0-0a19-0482-6976-d229bcf7afee
2023-09-21 10:05:00.583 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Cannot remove execution id: b6c481c0-0a19-0482-6976-d229bcf7afee, because it is not registered
2023-09-21 10:05:00.583 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: ExecutionRegisteredEvent
2023-09-21 10:05:00.584 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: ExecutionStateChangedEvent
2023-09-21 10:05:00.584 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: GatewaySynchronizationStartedEvent
2023-09-21 10:05:00.584 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: ExecutionStateChangedEvent
2023-09-21 10:05:00.584 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: GatewaySynchronizationEndedEvent
2023-09-21 10:05:00.585 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: DeviceStateChangedEvent
2023-09-21 10:05:00.585 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - States for device io://1227-9296-2479/12727770 : [{name='core:TargetClosureState', type=1, value=5}, {name='core:MovingState', type=6, value=true}]
2023-09-21 10:05:00.585 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Updating status of thing: Somfy - Zonnescherm
2023-09-21 10:05:00.587 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: ExecutionStateChangedEvent
2023-09-21 10:05:01.573 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Updating all states
2023-09-21 10:05:01.574 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending GET to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/setup/devices with data: 
2023-09-21 10:05:01.619 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/12411512 updating RSSI channel with value: 62.0
2023-09-21 10:05:01.619 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/12411512 updating channel: control with value: 0.0
2023-09-21 10:05:01.620 [DEBUG] [nal.handler.SomfyTahomaAwningHandler] - io://1227-9296-2479/12727770 updating RSSI channel with value: 74.0
2023-09-21 10:05:01.620 [DEBUG] [nal.handler.SomfyTahomaAwningHandler] - io://1227-9296-2479/12727770 updating channel: control with value: 13.0
2023-09-21 10:05:01.622 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/1512731 updating RSSI channel with value: 50.0
2023-09-21 10:05:01.623 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/1512731 updating channel: control with value: 0.0
2023-09-21 10:05:01.623 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/4379625 updating RSSI channel with value: 32.0
2023-09-21 10:05:01.624 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/4379625 updating channel: control with value: 0.0
2023-09-21 10:05:02.587 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Getting Tahoma Updates...
2023-09-21 10:05:02.587 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending POST to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/events/b6c34730-0a19-0482-6976-d229b77ec797/fetch with data: 
2023-09-21 10:05:04.695 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Getting Tahoma Updates...
2023-09-21 10:05:04.696 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending POST to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/events/b6c34730-0a19-0482-6976-d229b77ec797/fetch with data: 
2023-09-21 10:05:04.710 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: DeviceStateChangedEvent
2023-09-21 10:05:04.710 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - States for device io://1227-9296-2479/12727770 : [{name='core:ManufacturerSettingsState', type=3, value=java.lang.Object@755cf9ce}, {name='core:OpenClosedState', type=3, value=open}, {name='core:DeploymentState', type=1, value=6}, {name='core:OpenClosedState', type=3, value=open}, {name='core:DeploymentState', type=1, value=5}, {name='core:OpenClosedState', type=3, value=open}, {name='core:DeploymentState', type=1, value=5}, {name='core:OpenClosedState', type=3, value=open}, {name='core:DeploymentState', type=1, value=5}]
2023-09-21 10:05:04.711 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Updating status of thing: Somfy - Zonnescherm
2023-09-21 10:05:04.711 [DEBUG] [nal.handler.SomfyTahomaAwningHandler] - io://1227-9296-2479/12727770 updating channel: control with value: 6
2023-09-21 10:05:04.712 [DEBUG] [nal.handler.SomfyTahomaAwningHandler] - io://1227-9296-2479/12727770 updating channel: control with value: 5
2023-09-21 10:05:04.713 [DEBUG] [nal.handler.SomfyTahomaAwningHandler] - io://1227-9296-2479/12727770 updating channel: control with value: 5
2023-09-21 10:05:04.714 [DEBUG] [nal.handler.SomfyTahomaAwningHandler] - io://1227-9296-2479/12727770 updating channel: control with value: 5
2023-09-21 10:05:04.717 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: DeviceStateChangedEvent
2023-09-21 10:05:04.717 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - States for device io://1227-9296-2479/12727770 : [{name='core:MovingState', type=6, value=false}]
2023-09-21 10:05:04.718 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Updating status of thing: Somfy - Zonnescherm
2023-09-21 10:05:04.720 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Got event: ExecutionStateChangedEvent
2023-09-21 10:05:04.721 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Removing execution id: b6c54e30-0a19-0482-6976-d22930fb37c4
2023-09-21 10:08:04.721 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Getting Tahoma Updates...
2023-09-21 10:08:04.722 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending POST to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/events/b6c34730-0a19-0482-6976-d229b77ec797/fetch with data: 
2023-09-21 10:08:04.792 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Received unexpected status code: 400
2023-09-21 10:08:04.793 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Cannot call url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/events/b6c34730-0a19-0482-6976-d229b77ec797/fetch with params: !
	at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.sendMethodToTahomaWithCookie(SomfyTahomaBridgeHandler.java:833) ~[?:?]
	at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.sendPostToTahomaWithCookie(SomfyTahomaBridgeHandler.java:783) ~[?:?]
	at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.invokeCallToURL(SomfyTahomaBridgeHandler.java:1173) ~[?:?]
	at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.getEvents(SomfyTahomaBridgeHandler.java:456) ~[?:?]
	at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.getTahomaUpdates(SomfyTahomaBridgeHandler.java:587) ~[?:?]
	at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.lambda$4(SomfyTahomaBridgeHandler.java:232) ~[?:?]
2023-09-21 10:08:39.732 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Refreshing Tahoma states...
2023-09-21 10:08:39.733 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Doing relogin
2023-09-21 10:08:40.343 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - OAuth2 Access Token: YzIyMzY0ZWQ4MWU4YmExNzJhN2RmNTk3YzZkYWM1ZWU1YzE4ZTE0ZDg1MzVkNDQwYTg1ZjI0Y2Y2NWNjODllZg
2023-09-21 10:08:40.344 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending POST to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/events/register with data: 
2023-09-21 10:08:40.451 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Events id: b6c8b0fb-0a19-0482-6976-d2293fd80732
2023-09-21 10:08:40.452 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending PUT to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/setup/devices/states/refresh with data: 
2023-09-21 10:08:40.452 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending GET to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/setup/devices with data: 
2023-09-21 10:08:40.453 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending GET to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/setup/gateways/1227-9296-2479 with data: 
2023-09-21 10:08:40.482 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Tahoma status: OK
2023-09-21 10:08:40.482 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Tahoma protocol version: 2023.3.4
2023-09-21 10:08:40.482 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending GET to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/actionGroups with data: 
2023-09-21 10:08:40.527 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/4379625 updating RSSI channel with value: 32.0
2023-09-21 10:08:40.528 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/1512731 updating RSSI channel with value: 50.0
2023-09-21 10:08:40.528 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/1512731 updating channel: control with value: 0.0
2023-09-21 10:08:40.527 [DEBUG] [nal.handler.SomfyTahomaAwningHandler] - io://1227-9296-2479/12727770 updating RSSI channel with value: 74.0
2023-09-21 10:08:40.531 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/4379625 updating channel: control with value: 0.0
2023-09-21 10:08:40.531 [DEBUG] [nal.handler.SomfyTahomaAwningHandler] - io://1227-9296-2479/12727770 updating channel: control with value: 0.0
2023-09-21 10:08:40.528 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/12411512 updating RSSI channel with value: 62.0
2023-09-21 10:08:40.532 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/12411512 updating channel: control with value: 0.0
2023-09-21 10:11:04.795 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Getting Tahoma Updates...
2023-09-21 10:11:04.796 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending POST to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/events/b6c8b0fb-0a19-0482-6976-d2293fd80732/fetch with data: 
2023-09-21 10:11:04.862 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Received unexpected status code: 400
2023-09-21 10:11:04.863 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Cannot call url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/events/b6c8b0fb-0a19-0482-6976-d2293fd80732/fetch with params: !
	at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.sendMethodToTahomaWithCookie(SomfyTahomaBridgeHandler.java:833) ~[?:?]
	at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.sendPostToTahomaWithCookie(SomfyTahomaBridgeHandler.java:783) ~[?:?]
	at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.invokeCallToURL(SomfyTahomaBridgeHandler.java:1173) ~[?:?]
	at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.getEvents(SomfyTahomaBridgeHandler.java:456) ~[?:?]
	at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.getTahomaUpdates(SomfyTahomaBridgeHandler.java:587) ~[?:?]
	at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.lambda$4(SomfyTahomaBridgeHandler.java:232) ~[?:?]

@octa22
Copy link
Contributor

octa22 commented Sep 23, 2023

What is your refresh interval? The 400 errors are not because of OAuth, but because your fetching interval is too high and Tahoma cloud just drops the event registration id. (and this id is part of the fetch uri which leads to the http 400 error and new login)

The code is here: https://github.com/octa22/openhab2-addons/tree/somfytahoma-binding-oauth-new

@BasvanH
Copy link
Author

BasvanH commented Nov 25, 2023

Ok I've increased the refresh interval and no more 400 errors. I think the binding is OK and much more stable.

@BasvanH
Copy link
Author

BasvanH commented Jan 4, 2024

@octa22 when will you create the pull request?

@octa22
Copy link
Contributor

octa22 commented Jan 20, 2024

hello @BasvanH,
here is the latest snapshot rebased on the main branch, but for the 4.1.1 version. I am ready to create pull request, once you test it.
Could you do it for me, please?
https://www.dropbox.com/scl/fi/538lpq7i5z8iwt0p2mub7/org.openhab.binding.somfytahoma-4.2.0-SNAPSHOT.jar?rlkey=71bsqm7sseb9b5wyxdde22oua&dl=1

@BasvanH
Copy link
Author

BasvanH commented Jan 21, 2024 via email

@BasvanH
Copy link
Author

BasvanH commented Jan 22, 2024

I'm seeing this in my logs:

2024-01-22 15:16:19.940 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Getting Tahoma Updates...
2024-01-22 15:16:19.940 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending POST to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/events/3150f10b-0a19-0482-5287-3eb9c4b766e9/fetch with data:
2024-01-22 15:16:49.977 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Getting Tahoma Updates...
2024-01-22 15:16:49.977 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending POST to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/events/3150f10b-0a19-0482-5287-3eb9c4b766e9/fetch with data:
2024-01-22 15:16:50.051 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Received unexpected status code: 401
2024-01-22 15:16:50.052 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Cannot call url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/events/3150f10b-0a19-0482-5287-3eb9c4b766e9/fetch with params: !
java.util.concurrent.ExecutionException: Unknown http error 401 while attempting to send a message.
        at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.sendMethodToTahomaWithCookie(SomfyTahomaBridgeHandler.java:833) ~[?:?]
        at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.sendPostToTahomaWithCookie(SomfyTahomaBridgeHandler.java:783) ~[?:?]
        at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.invokeCallToURL(SomfyTahomaBridgeHandler.java:1174) ~[?:?]
        at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.getEvents(SomfyTahomaBridgeHandler.java:456) ~[?:?]
        at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.getTahomaUpdates(SomfyTahomaBridgeHandler.java:587) ~[?:?]
        at org.openhab.binding.somfytahoma.internal.handler.SomfyTahomaBridgeHandler.lambda$4(SomfyTahomaBridgeHandler.java:232) ~[?:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) [?:?]
        at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
        at java.lang.Thread.run(Thread.java:840) [?:?]
2024-01-22 15:17:20.053 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Getting Tahoma Updates...
2024-01-22 15:17:20.054 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Doing relogin
2024-01-22 15:17:20.793 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - OAuth2 Access Token: NGE4YjMxNzY1ODIwNGUwZGI1NTQ5NjljMWE4YzQ5YjU0YTlhMTIzMGU5ODg4ZDIwMTMzYTJhNWQzNTE0MDE4Yg
2024-01-22 15:17:20.793 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending POST to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/events/register with data:
2024-01-22 15:17:20.874 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Events id: 31886ce7-0a19-0482-5287-3eb99a489d79
2024-01-22 15:17:20.875 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending POST to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/events/31886ce7-0a19-0482-5287-3eb99a489d79/fetch with data:
2024-01-22 15:17:20.875 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending GET to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/setup/devices with data:
2024-01-22 15:17:20.876 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending GET to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/setup/gateways/1227-9296-2479 with data:
2024-01-22 15:17:20.893 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Tahoma status: OK
2024-01-22 15:17:20.894 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Tahoma protocol version: 2023.5.4
2024-01-22 15:17:20.894 [DEBUG] [nal.handler.SomfyTahomaBridgeHandler] - Sending GET to url: https://www.tahomalink.com/enduser-mobile-web/enduserAPI/actionGroups with data:
2024-01-22 15:17:20.922 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/4379625 updating RSSI channel with value: 50.0
2024-01-22 15:17:20.923 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/12411512 updating RSSI channel with value: 80.0
2024-01-22 15:17:20.922 [DEBUG] [nal.handler.SomfyTahomaAwningHandler] - io://1227-9296-2479/12727770 updating RSSI channel with value: 80.0
2024-01-22 15:17:20.923 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/4379625 updating channel: control with value: 0.0
2024-01-22 15:17:20.923 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/12411512 updating channel: control with value: 0.0
2024-01-22 15:17:20.923 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/1512731 updating RSSI channel with value: 64.0
2024-01-22 15:17:20.923 [DEBUG] [dler.SomfyTahomaRollerShutterHandler] - io://1227-9296-2479/1512731 updating channel: control with value: 0.0
2024-01-22 15:17:20.923 [DEBUG] [nal.handler.SomfyTahomaAwningHandler] - io://1227-9296-2479/12727770 updating channel: control with value: 0.0

Could be the OATH token is expired? Do you look at the token lifetime and refresh just before expiring or do you just wait for a request to fail and then to a re-logon?

@octa22
Copy link
Contributor

octa22 commented Jan 26, 2024

Could be the OATH token is expired? Do you look at the token lifetime and refresh just before expiring or do you just wait for a request to fail and then to a re-logon?

You are right, there was no functionality to refresh the token. This version automatically refreshes the token once it is close to its expiration - https://www.dropbox.com/scl/fi/538lpq7i5z8iwt0p2mub7/org.openhab.binding.somfytahoma-4.2.0-SNAPSHOT.jar?rlkey=71bsqm7sseb9b5wyxdde22oua&dl=1

@BasvanH
Copy link
Author

BasvanH commented Mar 6, 2024

Hi @octa22, can you make this final and pull to main? Please.

@BasvanH
Copy link
Author

BasvanH commented Apr 1, 2024

Hi @octa22, kindly requesting you to finish this issue. Thanks!

@Dooleweerdt
Copy link

I have seen this issue too, the Tahoma Bridge thing connects/disconnects continously every 2 min.

Based on comments above, I tried to lower the refresh interval from 2 min to 1 min, and now it keeps staying online. Could it be because there is a timeout less than 2 min on the JSESSIONID, which causes the 401 response when the binding tries to do a refresh?

I'm using OpenHAB 4.1.2 (docker image) with the 4.1.2 Somfy Tahoma plugin.

@octa22
Copy link
Contributor

octa22 commented Jun 2, 2024

Hi @octa22, kindly requesting you to finish this issue. Thanks!

Hi, is the last version working? I am missing an feedback, if it works well, I am ready to create the PR. thanks.

@BasvanH
Copy link
Author

BasvanH commented Jun 3, 2024

Hi @octa22, nice to hear from you. Hope you are well. Yes, running your OATH code for quite some time and all my issues are gone. Working great.

@lsiepel
Copy link
Contributor

lsiepel commented Aug 30, 2024

I guess it is this branch
https://github.com/octa22/openhab2-addons/commits/somfytahoma-binding-oauth-4.2.x/

I’ll be able to provide testing and or review once the PR is added.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug An unexpected problem or unintended behavior of an add-on
Projects
None yet
Development

Successfully merging a pull request may close this issue.

5 participants