Ewelink / Sonoff Binding - New binding without flashing

What do you mean with not showing up ?
Did you download and install the correct jar file ?

Download the jar file?
Don´t know how to proceed with such a jar file.
Will there be no “official” binding via PaperUI?

No, there will be none. openHAB 2.5 is on feature freeze since last year…
You need to download the jar file and copy it into your addons folder.

sorry to ask, but couldn´t find that s… folder :slight_smile:
Can you help me? And when it is there, will it automatically be activated with next boot, or what?

Thanks

Sorry, what about reading the docummentation ??

Folder locations :

After copying, it will be activated straight on, no reboot/restart required.

Thanks - Yes, cristal clear that documentation :upside_down_face:

I am on 2.5.12.
I copied the jar file into the addons folder but - nothing!
Nothing in the log neither in bindings in PaperUI nor when I try to add something new.
I tried to follow up reading the history but for me is not clear how the get that thing up and running …

This isn´t the right approach!
I will try a restart now, when not helping I will delete that jar file and come to the understanding that this thing isn´t really ready for OH 2.5.12

It was a nice try but costs me too much time for nothing

Hi guys
Sorry got snowed under again with work and crypto. Be back on it next week fingers crossed. I’ll look at the devices that need adding above and dm’s I’ve been sent. :+1:

I have analyzed a bit more what could be the problem the jar file isn´t started in my 2.5.12 on my PI4.
Can it be that the file permission is the guilty? I copied the jar file with mc from my Windows PC.
There is nothing in the log

If this is the problem, how do I change the permission for that file?

Hi all,
I have been trying for a long time to make this binding work and I have failed. With the account I use for OH I can log in to the Android application and everything is fine. I log out and then try in OH. I use OH 3.1.0 and Sonoff Binding 3.1.0.202106011018. This is log from debug:

08:32:15.543 [DEBUG] [ternal.connection.SonoffApiConnection] - Api Login Request:{“email"zzzz@abv.bg”,“password”:"*****",“countryCode”:"+1"}
08:32:15.544 [DEBUG] [munication.SonoffCommunicationManager] - Message queue is running
08:32:17.254 [DEBUG] [ternal.connection.SonoffApiConnection] - Api Login Response:{“error”:10004,“msg”:“request redirection”,“data”:{“region”:“eu”}}
08:32:17.259 [DEBUG] [ternal.connection.SonoffApiConnection] - Api Login Request:{“email”:“zzzz@abv.bg”,“password”:"**********",“countryCode”:"+1"}
08:32:18.501 [DEBUG] [ternal.connection.SonoffApiConnection] - Api Login Response:{“error”:10001,“msg”:“password error!”,“data”:null}
08:32:18.506 [DEBUG] [al.connection.SonoffConnectionManager] - Api disconnected
08:32:18.511 [DEBUG] [.connection.SonoffWebSocketConnection] - Stopping websocket client

Any Idea about this problem?

Thanks in advance

Sorry, all
I resolved the problem. Error is right- pass is wrong. After carefully checking I found my mistake.

Regards

Hi Again,
@delid4ve I write to you because all this thread is about the same problem.
I need to know they are solved or not.

Scan not find the POWR2 devices but cloud return needed information.
the log from scan is:

2021-11-13 09:38:38.071 [DEBUG] [nternal.handler.SonoffAccountHandler] - Running connection check task
2021-11-13 09:38:38.072 [DEBUG] [l.connection.SonoffConnectionManager] - Connection Check Running for cloud mode
2021-11-13 09:38:50.073 [DEBUG] [nal.discovery.SonoffDiscoveryService] - Stop Scan
2021-11-13 09:38:50.076 [DEBUG] [nal.discovery.SonoffDiscoveryService] - Start Scan
2021-11-13 09:38:50.078 [DEBUG] [nal.discovery.SonoffDiscoveryService] - Sonoff - Start Discovery
2021-11-13 09:38:50.082 [DEBUG] [ernal.connection.SonoffApiConnection] - Api Cache Request:{"appid":"oeVkj2l$$$$$tWisfW4utiN4u9Mq","nonce":"h24kfLpa","ts":1636789130082,"version":8}
2021-11-13 09:38:51.454 [DEBUG] [ernal.connection.SonoffApiConnection] - Api Cache response:{"error":0,"msg":"","data":{"thingList":[{"itemType":2,"itemData":{"name":"POW R2- OFFICE","deviceid":"1000fe48cb","apikey":"---------3a1e-4e39-aa35-925059f34cbf","extra":{"uiid":32,"description":"20200924013","brandId":"5c4c1aee3a7d24c7100be054","apmac":"d0:27:01:fc:8e:e7","mac":"d0:27:01:fc:8e:e6","ui":"功率检测插座过载告警","modelInfo":"5c700f7ecc248c47441fd236","model":"PSC-B67-GL","manufacturer":"深圳松诺技术有限公司","chipid":"00E312E0","staMac":"98:F4:AB:E3:12:E0"},"brandName":"SONOFF","brandLogo":"https://eu-ota.coolkit.cc/logo/q62PevoglDNmwUJ9oPE7kRrpt1nL1CoA.png","showBrand":true,"productModel":"POWR2","tags":{"m_4cbf_kebi":"on"},"devConfig":{"timerCount":"16/28"},"settings":{"opsNotify":0,"opsHistory":1,"alarmNotify":1,"wxAlarmNotify":0,"wxOpsNotify":0,"wxDoorbellNotify":0,"appDoorbellNotify":1},"devGroups":[],"family":{"familyid":"60fc35fe6e61220009468edf","index":-2},"sharedBy":{"apikey":"---------3a1e-4e39-aa35-925059f34cbf","email":"kebibg@gmail.com","comment":"","permit":15,"shareTime":1636709883238},"devicekey":"---------f3f3-420d-8700-afce90b348c6","online":true,"params":{"bindInfos":{"gaction":["--------3a1e-4e39-aa35-925059f34cbf_ewelinkGoogleHome"]},"version":8,"only_device":{"ota":"success"},"sledOnline":"on","ssid":"--------ent Bulgaria","bssid":"04:18:d6:0b:78:2f","fwVersion":"3.5.0","staMac":"98:F4:AB:E3:12:E0","rssi":-45,"init":1,"alarmType":"pcv","alarmVValue":[-1,-1],"alarmCValue":[-1,-1],"alarmPValue":[-1,-1],"switch":"off","startup":"off","pulse":"off","pulseWidth":500,"power":"0.00","voltage":"231.51","current":"0.00","oneKwh":"stop","uiActive":60,"hundredDaysKwh":"get","endTime":"2021-05-03T05:27:43.348Z","startTime":"2021-05-03T05:25:26.247Z","timeZone":3},"isSupportGroup":false},"index":-2},{"itemType":2,"itemData":{"name":"Kidroom","deviceid":"1000fe3ed8","apikey":"-------3a1e-4e39-aa35-925059f34cbf","extra":{"uiid":32,"description":"20200924013","brandId":"5c4c1aee3a7d24c7100be054","apmac":"d0:27:01:fc:7b:01","mac":"d0:27:01:fc:7b:00","ui":"功率检测插座过载告警","modelInfo":"5c700f7ecc248c47441fd236","model":"PSC-B67-GL","manufacturer":"深圳松诺技术有限公司","chipid":"00E2D6D4","staMac":"98:F4:AB:E2:D6:D4"},"brandName":"SONOFF","brandLogo":"https://eu-ota.coolkit.cc/logo/q62PevoglDNmwUJ9oPE7kRrpt1nL1CoA.png","showBrand":true,"productModel":"POWR2","tags":{"m_4cbf_kebi":"on","m_b112_kebi":"on","disable_timers":[{"mId":"---------5375-5c0d-0e8b-903174db2759","type":"repeat","at":"0 5 * * 1,2,3,4,5","coolkit_timer_type":"repeat","enabled":1,"do":{"switch":"off"}},{"mId":"-----b-c0cb-4dbc-40bf-9d4aa83d5640","type":"repeat","at":"0 15 * * 1,2,3,4,5","coolkit_timer_type":"repeat","enabled":1,"do":{"switch":"on"}}]},"devConfig":{"timerCount":"16/28"},"settings":{"opsNotify":0,"opsHistory":1,"alarmNotify":1,"wxAlarmNotify":0,"wxOpsNotify":0,"wxDoorbellNotify":0,"appDoorbellNotify":1},"devGroups":[],"family":{"familyid":"60fc35fe6e61220009468edf","index":-1},"sharedBy":{"apikey":"-------3a1e-4e39-aa35-925059f34cbf","email":"kebibg@gmail.com","comment":"","permit":15,"shareTime":1627650946995},"devicekey":"--------ad4d-4424-90cb-1e7f5c4aa67a","online":true,"params":{"bindInfos":{"gaction":["-------3a1e-4e39-aa35-925059f34cbf_ewelinkGoogleHome"]},"version":8,"only_device":{"ota":"success"},"sledOnline":"off","ssid":"MikroTik","bssid":"6c:3b:6b:88:ba:48","fwVersion":"3.5.0","staMac":"98:F4:AB:E2:D6:D4","rssi":-69,"init":1,"alarmType":"pcv","alarmVValue":[-1,-1],"alarmCValue":[-1,-1],"alarmPValue":[-1,-1],"switch":"off","startup":"on","pulse":"off","pulseWidth":500,"power":"0.00","voltage":"231.03","current":"0.00","oneKwh":"start","uiActive":60,"hundredDaysKwh":"get","endTime":"","startTime":"2021-10-10T09:47:23.402Z","timeZone":3,"timers":[]},"isSupportGroup":false},"index":-1},{"itemType":2,"itemData":{"name":"Bedroom Climate","deviceid":"1000fe43e8","apikey":"-------3a1e-4e39-aa35-925059f34cbf","extra":{"uiid":32,"description":"20200924013","brandId":"5c4c1aee3a7d24c7100be054","apmac":"d0:27:01:fc:85:21","mac":"d0:27:01:fc:85:20","ui":"功率检测插座过载告警","modelInfo":"5c700f7ecc248c47441fd236","model":"PSC-B67-GL","manufacturer":"深圳松诺技术有限公司","chipid":"00E2DCE4","staMac":"98:F4:AB:E2:DC:E4"},"brandName":"SONOFF","brandLogo":"https://eu-ota.coolkit.cc/logo/q62PevoglDNmwUJ9oPE7kRrpt1nL1CoA.png","showBrand":true,"productModel":"POWR2","tags":{"m_4cbf_kebi":"on","m_b112_kebi":"on","disable_timers":[{"mId":"-------c-97ef-940a-ca83-e4ec5c865071","type":"repeat","at":"0 21 * * 0,1,2,3,4","coolkit_timer_type":"repeat","enabled":1,"do":{"switch":"off"}},{"mId":"--------4-9a7a-531f-c611-443697b73a9a","type":"repeat","at":"30 11 * * 1,2,3,4,5","coolkit_timer_type":"repeat","enabled":1,"do":{"switch":"on"}}]},"devConfig":{"timerCount":"16/28"},"settings":{"opsNotify":0,"opsHistory":1,"alarmNotify":1,"wxAlarmNotify":0,"wxOpsNotify":0,"wxDoorbellNotify":0,"appDoorbellNotify":1},"devGroups":[],"family":{"familyid":"60fc35fe6e61220009468edf","index":0},"sharedBy":{"apikey":"-------3a1e-4e39-aa35-925059f34cbf","email":"kebibg@gmail.com","comment":"","permit":15,"shareTime":1627141680992},"devicekey":"------d7-37cf-475a-9a0f-e879eee16988","online":true,"params":{"bindInfos":{"gaction":["-------3a1e-4e39-aa35-925059f34cbf_ewelinkGoogleHome"]},"version":8,"only_device":{"ota":"success"},"sledOnline":"off","ssid":"MikroTik","bssid":"6c:3b:6b:88:ba:48","fwVersion":"3.5.0","staMac":"98:F4:AB:E2:DC:E4","rssi":-58,"init":1,"alarmType":"pcv","alarmVValue":[-1,-1],"alarmCValue":[-1,-1],"alarmPValue":[-1,-1],"switch":"off","startup":"on","pulse":"off","pulseWidth":500,"power":"0.00","voltage":"231.16","current":"0.00","oneKwh":"start","uiActive":60,"hundredDaysKwh":"get","endTime":"","startTime":"2021-08-25T15:18:54.673Z","timeZone":3,"timers":[]},"isSupportGroup":false},"index":0}],"total":3}}
2021-11-13 09:38:57.629 [DEBUG] [nternal.handler.SonoffAccountHandler] - Running Activation task
2021-11-13 09:38:57.631 [DEBUG] [connection.SonoffWebSocketConnection] - Websocket Sending Message:ping
2021-11-13 09:38:57.670 [DEBUG] [connection.SonoffWebSocketConnection] - Pong Response received
2021-11-13 09:39:00.076 [DEBUG] [nal.discovery.SonoffDiscoveryService] - Stop Scan

After that do not have new devices in inbox. In user directory /var/lib/openhab/sonoff does not have any file. Ownes and group of the directory are openhab:openhab. Have write permission. I am on openhab 3.1.0. I try with many jar bindings versions, with all is the same.

The thing on the first image is created manually. They not work of course :frowning: .

PS: Log of startup openhab:

2021-11-13 10:03:20.860 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory] : BundleComponentActivator : ComponentHolder created.
2021-11-13 10:03:20.882 [DEBUG] [nal.discovery.SonoffDiscoveryService] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.discovery.SonoffDiscoveryService] : BundleComponentActivator : ComponentHolder created.
2021-11-13 10:03:20.910 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory] : Dependency Manager created $000interface=org.openhab.core.io.net.http.WebSocketFactory, filter=null, policy=static, cardinality=1..1, bind=null, unbind=null, updated=null, field=null, field-option=null, collection-type=null, parameter=0
2021-11-13 10:03:20.915 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory] : Dependency Manager created $001interface=org.openhab.core.io.net.http.HttpClientFactory, filter=null, policy=static, cardinality=1..1, bind=null, unbind=null, updated=null, field=null, field-option=null, collection-type=null, parameter=1
2021-11-13 10:03:20.934 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory] : Component created: DS=DS14, implementation=org.openhab.binding.sonoff.internal.SonoffHandlerFactory, immediate=false, default-enabled=true, factory=null, configuration-policy=optional, activate=activate, deactivate=deactivate, modified=null configuration-pid=[binding.sonoff]
2021-11-13 10:03:20.940 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory] : Component Services: scope=singleton, services=[org.openhab.core.thing.binding.ThingHandlerFactory]
2021-11-13 10:03:20.957 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory] : Component Properties: {}
2021-11-13 10:03:20.963 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory] : Querying state disabled
2021-11-13 10:03:20.969 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory] : Querying state disabled
2021-11-13 10:03:20.975 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory] : Component can not be activated since it is in state disabled
2021-11-13 10:03:20.981 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory] : Querying state disabled
2021-11-13 10:03:21.001 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : Updating target filters
2021-11-13 10:03:21.016 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : No change in target property for dependency $000: currently registered: false
2021-11-13 10:03:21.042 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] :  No existing service listener to unregister for dependency $000
2021-11-13 10:03:21.048 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : Setting target property for dependency $000 to null
2021-11-13 10:03:21.055 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : New service tracker for $000, initial active: false, previous references: {}, classFilter: (objectClass=org.openhab.core.io.net.http.WebSocketFactory), initialReferenceFilter (objectClass=org.openhab.core.io.net.http.WebSocketFactory)
2021-11-13 10:03:21.071 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : dm $000 tracker reset (closed)
2021-11-13 10:03:21.081 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : dm $000 tracking 1 SingleStatic added {org.openhab.core.io.net.http.HttpClientFactory, org.openhab.core.io.net.http.WebSocketFactory}={service.id=269, service.bundleid=178, service.scope=bundle, component.name=org.openhab.core.io.net.http.internal.WebClientFactoryImpl, component.id=137} (enter)
2021-11-13 10:03:21.100 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : dm $000 tracking 1 SingleStatic active: false trackerOpened: false optional: false
2021-11-13 10:03:21.108 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : dm $000 tracking 1 SingleStatic added {org.openhab.core.io.net.http.HttpClientFactory, org.openhab.core.io.net.http.WebSocketFactory}={service.id=269, service.bundleid=178, service.scope=bundle, component.name=org.openhab.core.io.net.http.internal.WebClientFactoryImpl, component.id=137} (exit)
2021-11-13 10:03:21.123 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : dm $000 tracker opened
2021-11-13 10:03:21.132 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : registering service listener for dependency $000
2021-11-13 10:03:21.237 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : No change in target property for dependency $001: currently registered: false
2021-11-13 10:03:21.245 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] :  No existing service listener to unregister for dependency $001
2021-11-13 10:03:21.264 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : Setting target property for dependency $001 to null
2021-11-13 10:03:21.279 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : New service tracker for $001, initial active: false, previous references: {}, classFilter: (objectClass=org.openhab.core.io.net.http.HttpClientFactory), initialReferenceFilter (objectClass=org.openhab.core.io.net.http.HttpClientFactory)
2021-11-13 10:03:21.285 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : dm $001 tracker reset (closed)
2021-11-13 10:03:21.294 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : dm $001 tracking 2 SingleStatic added {org.openhab.core.io.net.http.HttpClientFactory, org.openhab.core.io.net.http.WebSocketFactory}={service.id=269, service.bundleid=178, service.scope=bundle, component.name=org.openhab.core.io.net.http.internal.WebClientFactoryImpl, component.id=137} (enter)
2021-11-13 10:03:21.300 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : dm $001 tracking 2 SingleStatic active: false trackerOpened: false optional: false
2021-11-13 10:03:21.307 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : dm $001 tracking 2 SingleStatic added {org.openhab.core.io.net.http.HttpClientFactory, org.openhab.core.io.net.http.WebSocketFactory}={service.id=269, service.bundleid=178, service.scope=bundle, component.name=org.openhab.core.io.net.http.internal.WebClientFactoryImpl, component.id=137} (exit)
2021-11-13 10:03:21.312 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : dm $001 tracker opened
2021-11-13 10:03:21.318 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : registering service listener for dependency $001
2021-11-13 10:03:21.339 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : Changed state from disabled to unsatisfiedReference
2021-11-13 10:03:21.344 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : Component enabled
2021-11-13 10:03:21.350 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : ActivateInternal
2021-11-13 10:03:21.365 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : Querying state unsatisfiedReference
2021-11-13 10:03:21.372 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : Querying state unsatisfiedReference
2021-11-13 10:03:21.387 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : Activating component from state unsatisfiedReference
2021-11-13 10:03:21.392 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : Querying state unsatisfiedReference
2021-11-13 10:03:21.407 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : Querying state unsatisfiedReference
2021-11-13 10:03:21.414 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : Changed state from unsatisfiedReference to satisfied
2021-11-13 10:03:21.432 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : registration change queue [registered]
2021-11-13 10:03:21.502 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : Checking constructor public org.openhab.binding.sonoff.internal.SonoffHandlerFactory(org.openhab.core.io.net.http.WebSocketFactory,org.openhab.core.io.net.http.HttpClientFactory)
2021-11-13 10:03:21.509 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : getReferenceClass: Looking for interface class org.openhab.core.io.net.http.WebSocketFactory through loader of org.openhab.binding.sonoff.internal.SonoffHandlerFactory
2021-11-13 10:03:21.513 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : getParameterClass: Found class org.openhab.core.io.net.http.WebSocketFactory
2021-11-13 10:03:21.542 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : getReferenceClass: Looking for interface class org.openhab.core.io.net.http.HttpClientFactory through loader of org.openhab.binding.sonoff.internal.SonoffHandlerFactory
2021-11-13 10:03:21.556 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : getParameterClass: Found class org.openhab.core.io.net.http.HttpClientFactory
2021-11-13 10:03:21.571 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : Found constructor with 2 arguments : public org.openhab.binding.sonoff.internal.SonoffHandlerFactory(org.openhab.core.io.net.http.WebSocketFactory,org.openhab.core.io.net.http.HttpClientFactory)
2021-11-13 10:03:21.584 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : This thread collected dependencies
2021-11-13 10:03:21.599 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : getService (single component manager) dependencies collected.
2021-11-13 10:03:21.611 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : Querying state satisfied
2021-11-13 10:03:21.616 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : Querying state satisfied
2021-11-13 10:03:21.654 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : 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=269, service.bundleid=178, service.scope=bundle, component.name=org.openhab.core.io.net.http.internal.WebClientFactoryImpl, component.id=137}] service: [null]]]
2021-11-13 10:03:21.669 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : For dependency $001, optional: false; to bind: [[RefPair: ref: [{org.openhab.core.io.net.http.HttpClientFactory, org.openhab.core.io.net.http.WebSocketFactory}={service.id=269, service.bundleid=178, service.scope=bundle, component.name=org.openhab.core.io.net.http.internal.WebClientFactoryImpl, component.id=137}] service: [null]]]
2021-11-13 10:03:21.685 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : getting activate: activate
2021-11-13 10:03:21.701 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : Locating method activate in class org.openhab.binding.sonoff.internal.SonoffHandlerFactory
2021-11-13 10:03:21.717 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : Declared Method org.openhab.binding.sonoff.internal.SonoffHandlerFactory.activate([interface org.osgi.service.component.ComponentContext]) not found
2021-11-13 10:03:21.725 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : Locating method activate in class org.openhab.core.thing.binding.BaseThingHandlerFactory
2021-11-13 10:03:21.743 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : Found activate method: protected void org.openhab.core.thing.binding.BaseThingHandlerFactory.activate(org.osgi.service.component.ComponentContext)
2021-11-13 10:03:21.749 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : invoking activate: activate: parameters [org.apache.felix.scr.impl.manager.ComponentContextImpl]
2021-11-13 10:03:21.759 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : invoked activate: activate
2021-11-13 10:03:21.772 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : Set implementation object for component
2021-11-13 10:03:21.789 [DEBUG] [sonoff.internal.SonoffHandlerFactory] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.SonoffHandlerFactory(314)] : Changed state from satisfied to active
2021-11-13 10:03:21.811 [DEBUG] [nal.discovery.SonoffDiscoveryService] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.discovery.SonoffDiscoveryService] : Component created: DS=DS13, implementation=org.openhab.binding.sonoff.internal.discovery.SonoffDiscoveryService, immediate=true, default-enabled=true, factory=null, configuration-policy=optional, activate=activate, deactivate=deactivate, modified=null configuration-pid=[discovery.sonoff]
2021-11-13 10:03:21.815 [DEBUG] [nal.discovery.SonoffDiscoveryService] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.discovery.SonoffDiscoveryService] : Component Services: scope=singleton, services=[org.openhab.binding.sonoff.internal.discovery.SonoffDiscoveryService]
2021-11-13 10:03:21.819 [DEBUG] [nal.discovery.SonoffDiscoveryService] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.discovery.SonoffDiscoveryService] : Component Properties: {}
2021-11-13 10:03:21.824 [DEBUG] [nal.discovery.SonoffDiscoveryService] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.discovery.SonoffDiscoveryService] : Querying state disabled
2021-11-13 10:03:21.829 [DEBUG] [nal.discovery.SonoffDiscoveryService] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.discovery.SonoffDiscoveryService] : Querying state disabled
2021-11-13 10:03:21.835 [DEBUG] [nal.discovery.SonoffDiscoveryService] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.discovery.SonoffDiscoveryService] : Component can not be activated since it is in state disabled
2021-11-13 10:03:21.840 [DEBUG] [nal.discovery.SonoffDiscoveryService] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.discovery.SonoffDiscoveryService] : Querying state disabled
2021-11-13 10:03:21.845 [DEBUG] [nal.discovery.SonoffDiscoveryService] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.discovery.SonoffDiscoveryService(315)] : Updating target filters
2021-11-13 10:03:21.850 [DEBUG] [nal.discovery.SonoffDiscoveryService] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.discovery.SonoffDiscoveryService(315)] : Changed state from disabled to unsatisfiedReference
2021-11-13 10:03:21.856 [DEBUG] [nal.discovery.SonoffDiscoveryService] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.discovery.SonoffDiscoveryService(315)] : Component enabled
2021-11-13 10:03:21.860 [DEBUG] [nal.discovery.SonoffDiscoveryService] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.discovery.SonoffDiscoveryService(315)] : ActivateInternal
2021-11-13 10:03:21.865 [DEBUG] [nal.discovery.SonoffDiscoveryService] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.discovery.SonoffDiscoveryService(315)] : Querying state unsatisfiedReference
2021-11-13 10:03:21.870 [DEBUG] [nal.discovery.SonoffDiscoveryService] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.discovery.SonoffDiscoveryService(315)] : Querying state unsatisfiedReference
2021-11-13 10:03:21.876 [DEBUG] [nal.discovery.SonoffDiscoveryService] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.discovery.SonoffDiscoveryService(315)] : Activating component from state unsatisfiedReference
2021-11-13 10:03:21.881 [DEBUG] [nal.discovery.SonoffDiscoveryService] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.discovery.SonoffDiscoveryService(315)] : Querying state unsatisfiedReference
2021-11-13 10:03:21.888 [DEBUG] [nal.discovery.SonoffDiscoveryService] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.discovery.SonoffDiscoveryService(315)] : Querying state unsatisfiedReference
2021-11-13 10:03:21.906 [DEBUG] [nal.discovery.SonoffDiscoveryService] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.discovery.SonoffDiscoveryService(315)] : Changed state from unsatisfiedReference to satisfied
2021-11-13 10:03:21.912 [DEBUG] [nal.discovery.SonoffDiscoveryService] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.discovery.SonoffDiscoveryService(315)] : registration change queue [registered]
2021-11-13 10:03:21.930 [DEBUG] [nal.discovery.SonoffDiscoveryService] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.discovery.SonoffDiscoveryService(315)] : Checking constructor public org.openhab.binding.sonoff.internal.discovery.SonoffDiscoveryService()
2021-11-13 10:03:21.936 [DEBUG] [nal.discovery.SonoffDiscoveryService] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.discovery.SonoffDiscoveryService(315)] : Found constructor with 0 arguments : public org.openhab.binding.sonoff.internal.discovery.SonoffDiscoveryService()
2021-11-13 10:03:21.941 [DEBUG] [nal.discovery.SonoffDiscoveryService] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.discovery.SonoffDiscoveryService(315)] : This thread collected dependencies
2021-11-13 10:03:21.946 [DEBUG] [nal.discovery.SonoffDiscoveryService] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.discovery.SonoffDiscoveryService(315)] : getService (single component manager) dependencies collected.
2021-11-13 10:03:21.951 [DEBUG] [nal.discovery.SonoffDiscoveryService] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.discovery.SonoffDiscoveryService(315)] : Querying state satisfied
2021-11-13 10:03:21.956 [DEBUG] [nal.discovery.SonoffDiscoveryService] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.discovery.SonoffDiscoveryService(315)] : Querying state satisfied
2021-11-13 10:03:21.963 [DEBUG] [nal.discovery.SonoffDiscoveryService] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.discovery.SonoffDiscoveryService(315)] : getting activate: activate
2021-11-13 10:03:21.970 [DEBUG] [nal.discovery.SonoffDiscoveryService] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.discovery.SonoffDiscoveryService(315)] : Locating method activate in class org.openhab.binding.sonoff.internal.discovery.SonoffDiscoveryService
2021-11-13 10:03:21.976 [DEBUG] [nal.discovery.SonoffDiscoveryService] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.discovery.SonoffDiscoveryService(315)] : Declared Method org.openhab.binding.sonoff.internal.discovery.SonoffDiscoveryService.activate([interface org.osgi.service.component.ComponentContext]) not found
2021-11-13 10:03:21.981 [DEBUG] [nal.discovery.SonoffDiscoveryService] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.discovery.SonoffDiscoveryService(315)] : Found activate method: protected void org.openhab.binding.sonoff.internal.discovery.SonoffDiscoveryService.activate(java.util.Map)
2021-11-13 10:03:21.992 [DEBUG] [nal.discovery.SonoffDiscoveryService] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.discovery.SonoffDiscoveryService(315)] : invoking activate: activate: parameters [org.apache.felix.scr.impl.helper.ReadOnlyDictionary]
2021-11-13 10:03:22.006 [DEBUG] [nal.discovery.SonoffDiscoveryService] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.discovery.SonoffDiscoveryService(315)] : invoked activate: activate
2021-11-13 10:03:22.018 [DEBUG] [nal.discovery.SonoffDiscoveryService] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.discovery.SonoffDiscoveryService(315)] : Set implementation object for component
2021-11-13 10:03:22.021 [DEBUG] [nal.discovery.SonoffDiscoveryService] - bundle org.openhab.binding.sonoff:3.2.0.202110181436 (285)[org.openhab.binding.sonoff.internal.discovery.SonoffDiscoveryService(315)] : Changed state from satisfied to active
2021-11-13 10:03:23.441 [DEBUG] [nternal.handler.SonoffAccountHandler] - Initialising Sonoff Account: sonoff:account:8b68f580d7
2021-11-13 10:03:23.446 [INFO ] [nternal.handler.SonoffAccountHandler] - Sonoff Access Mode set to: cloud
2021-11-13 10:03:23.474 [DEBUG] [unication.SonoffCommunicationManager] - Message queue is running
2021-11-13 10:03:23.480 [DEBUG] [ernal.connection.SonoffApiConnection] - Api Login Request:{"email":"k***g@abv.bg","password":"s*****23**","countryCode":"+1"}
2021-11-13 10:03:27.346 [DEBUG] [ernal.connection.SonoffApiConnection] - Api Login Response:{"error":10004,"msg":"request redirection","data":{"region":"eu"}}
2021-11-13 10:03:27.351 [DEBUG] [ernal.connection.SonoffApiConnection] - Api Login Request:{"email":"k***g@abv.bg","password":"s*****23**","countryCode":"+1"}
2021-11-13 10:03:28.466 [WARN ] [core.thing.internal.ThingManagerImpl] - Initializing handler for thing 'sonoff:account:8b68f580d7' takes more than 5000ms.
2021-11-13 10:03:29.400 [DEBUG] [ernal.connection.SonoffApiConnection] - Api Login Response:{"error":0,"msg":"","data":{"user":{"accountLevel":10,"countryCode":"+359","email":"k***g@abv.bg","apikey":"********-3331-48b2-bb28-3e1598a2b112","accountConsult":false,"appForumEnterHide":true,"appVersion":"4.16.2","denyRecharge":false,"ipCountry":"BG"},"at":"8e58c74881e67ee7772f0b0c8765e1cce31f917b","rt":"8b86fe4d9dc67d396709c6d0599891337454f89d","region":"eu"}}
2021-11-13 10:03:29.408 [DEBUG] [l.connection.SonoffConnectionManager] - Api connected
2021-11-13 10:03:29.417 [DEBUG] [ernal.connection.SonoffApiConnection] - Attempt to get websocket server
2021-11-13 10:03:29.445 [DEBUG] [ernal.connection.SonoffApiConnection] - Websocket URL Request:{"appid":"o******u5XUtWisfW4utiN4u9Mq","nonce":"pVyPqsVb","ts":1636790609426,"version":8,"accept":"ws"}
2021-11-13 10:03:30.236 [DEBUG] [ernal.connection.SonoffApiConnection] - Websocket URL Response:{"port":8080,"IP":"35.157.208.224","reason":"ok","domain":"eu-pconnect2.coolkit.cc","error":0}
2021-11-13 10:03:31.210 [DEBUG] [connection.SonoffWebSocketConnection] - WebSocket Socket successfully connected to eu-pconnect2.coolkit.cc/35.157.208.224
2021-11-13 10:03:31.214 [DEBUG] [l.connection.SonoffConnectionManager] - Websocket connected
2021-11-13 10:03:31.227 [DEBUG] [connection.SonoffWebSocketConnection] - Websocket Sending Message:{"action":"userOnline","at":"8e58c74881e67ee7772f0b0c8765e1cce31f917b","apikey":"*****-3331-48b2-bb28-3e1598a2b112","appid":"*******nJu5XUtWisfW4utiN4u9Mq","nonce":"GKHtzjA0","ts":1636790611,"userAgent":"app","sequence":1636790611221,"version":8}
2021-11-13 10:03:31.312 [DEBUG] [connection.SonoffWebSocketConnection] - Login Response Received: {"error":0,"apikey":"*******-3331-48b2-bb28-3e1598a2b112","config":{"hb":1,"hbInterval":145},"sequence":"1636790611221"}
2021-11-13 10:03:31.438 [DEBUG] [rnal.handler.SonoffBaseDeviceHandler] - Initialising device: sonoff:32:8b68f580d7:663ed8d2bb
2021-11-13 10:03:50.418 [DEBUG] [nternal.handler.SonoffAccountHandler] - Running Activation task
2021-11-13 10:03:50.421 [DEBUG] [connection.SonoffWebSocketConnection] - Websocket Sending Message:ping
2021-11-13 10:03:50.491 [DEBUG] [connection.SonoffWebSocketConnection] - Pong Response received
2021-11-13 10:04:30.416 [DEBUG] [nternal.handler.SonoffAccountHandler] - Running connection check task
2021-11-13 10:04:30.420 [DEBUG] [l.connection.SonoffConnectionManager] - Connection Check Running for cloud mode 
2021-11-13 10:04:50.430 [DEBUG] [nternal.handler.SonoffAccountHandler] - Running Activation task
2021-11-13 10:04:50.434 [DEBUG] [connection.SonoffWebSocketConnection] - Websocket Sending Message:ping
2021-11-13 10:04:50.470 [DEBUG] [connection.SonoffWebSocketConnection] - Pong Response received
2021-11-13 10:05:30.424 [DEBUG] [nternal.handler.SonoffAccountHandler] - Running connection check task
2021-11-13 10:05:30.427 [DEBUG] [l.connection.SonoffConnectionManager] - Connection Check Running for cloud mode 
2021-11-13 10:05:50.440 [DEBUG] [nternal.handler.SonoffAccountHandler] - Running Activation task
2021-11-13 10:05:50.443 [DEBUG] [connection.SonoffWebSocketConnection] - Websocket Sending Message:ping
2021-11-13 10:05:50.480 [DEBUG] [connection.SonoffWebSocketConnection] - Pong Response received

Regards

Thanks @delid4ve for the efforts.

I finally had time to test the jar for R1D1 and I notice the same behaviour as mentioned above by @tdlr

The difference is that I am running in local only mode and I notice in the log that the brightness is stuck at 9, no matter what setting I set in OH. Switching the device ON and OFF works

I read in the log that brightness is not supported in local mode, is that right? (My firewall blocks the internet of all cheap WiFi devices, that is why my preference goes to local mode only)
I was reading the API docs of the R1D1 and apparently it could work locally (but if set to local mode it will not work with the eWelink app)

Below some logs:

2021-11-13 22:02:04.799 [DEBUG] [internal.handler.SonoffDimmerHandler] - CCT received command on channel sonoff:44:SonoffAccount:sonoffCornerLamp:brightness, with id brightness

2021-11-13 22:02:04.800 [DEBUG] [rnal.handler.SonoffBaseDeviceHandler] - Sonoff - Command Payload:org.openhab.binding.sonoff.internal.dto.commands.Brightness@8af61e

2021-11-13 22:02:05.064 [INFO ] [l.script.lights:CornerLampBrightness] -  Corner lamp living switched to ON,with brightness 0

2021-11-13 22:02:05.068 [DEBUG] [internal.handler.SonoffDimmerHandler] - CCT received command on channel sonoff:44:SonoffAccount:sonoffCornerLamp:brightness, with id brightness

2021-11-13 22:02:05.784 [WARN ] [unication.SonoffCommunicationManager] - Ok message not received for transaction: 1636837324781, command was brightness, retrying again. Retry count 2

2021-11-13 22:02:05.886 [WARN ] [unication.SonoffCommunicationManager] - Cannot send command brightness for device 1001106f87, Not supported by local mode

2021-11-13 22:02:06.887 [WARN ] [unication.SonoffCommunicationManager] - Ok message not received for transaction: 1636837324781, command was brightness, retrying again. Retry count 3

2021-11-13 22:02:06.991 [WARN ] [unication.SonoffCommunicationManager] - Cannot send command brightness for device 1001106f87, Not supported by local mode

2021-11-13 22:02:07.992 [WARN ] [unication.SonoffCommunicationManager] - Unable to send transaction 1636837324781, command was brightness, after 3 retry attempts

2021-11-13 22:02:08.380 [DEBUG] [unication.SonoffCommunicationManager] - Updated state for 1001106f87, with data {"data1":"6CDVhGwZerBx4YeR747tDZjLIYy7pIDc6Y5/FZJKrXSD+Uj5yNMb1/eSooZkXzvzC/FxzJ1zK4zcyE+HfTPou2KQi/mAlE6OnBdYvB148FG3ELdlM1shZ+ONHue6dSeb","seq":"7","iv":"NzkzNDQzMjkyMzYyOTM3Ng\u003d\u003d","apivers":"1","type":"light","txtvers":"1","encrypt":"true","deviceid":"1001106f87","localAddress":"192.168.4.213","params":{"switch":"on","brightness":9,"brightMin":0,"brightMax":255,"startup":"on","mode":0,"rssi":-75},"ipaddress":"192.168.4.213"}

2021-11-13 22:02:08.460 [WARN ] [unication.SonoffCommunicationManager] - Cannot send command brightness for device 1001106f87, Not supported by local mode

2021-11-13 22:02:09.461 [WARN ] [unication.SonoffCommunicationManager] - Ok message not received for transaction: 1636837324801, command was brightness, retrying again. Retry count 2

2021-11-13 22:02:09.566 [WARN ] [unication.SonoffCommunicationManager] - Cannot send command brightness for device 1001106f87, Not supported by local mode

2021-11-13 22:02:10.568 [WARN ] [unication.SonoffCommunicationManager] - Ok message not received for transaction: 1636837324801, command was brightness, retrying again. Retry count 3

2021-11-13 22:02:10.674 [WARN ] [unication.SonoffCommunicationManager] - Cannot send command brightness for device 1001106f87, Not supported by local mode

2021-11-13 22:02:11.675 [WARN ] [unication.SonoffCommunicationManager] - Unable to send transaction 1636837324801, command was brightness, after 3 retry attempts

2021-11-13 22:02:11.902 [DEBUG] [unication.SonoffCommunicationManager] - Updated state for 1001106f87, with data {"data1":"U6+KODJMj9lk6enZTqn0iBCC/Un0SciU53Qf8R7UZ2UytNRvgf997aHIy89vKnhuMm0VdOpg/BgY9QbgBcUB5zYBHYgmNwaJizzCJfN3NUznEhHO/ZJVCUiznO3aQmi7+LiRP0XasYOjE9J5R4LrvQ\u003d\u003d","seq":"8","iv":"OTc3OTY2NTIzMTAyMzg3Mw\u003d\u003d","apivers":"1","type":"light","txtvers":"1","encrypt":"true","deviceid":"1001106f87","localAddress":"192.168.4.213","params":{"switch":"off","brightness":9,"brightMin":0,"brightMax":255,"startup":"on","mode":0,"rssi":-75},"ipaddress":"192.168.4.213"}

2021-11-13 22:02:12.029 [DEBUG] [unication.SonoffCommunicationManager] - Updated state for 1001106f87, with data {"data1":"fYlnQEBYirF43FarAY43VkT2pqnEVM09E5iyieLBomIOiaAIaHMJB/LJKTNugyjxwkvvx6mgA5qB4yWjYtpkuii81XUrwQtx2yczkGdZBuBgB1l4Mr0mLs0YUq/LcRol0rUsYxuHSOFxbZGGhbBzZg\u003d\u003d","seq":"9","iv":"MDQ3NDQwNTA1MzIzMjY5Ng\u003d\u003d","apivers":"1","type":"light","txtvers":"1","encrypt":"true","deviceid":"1001106f87","localAddress":"192.168.4.213","params":{"switch":"off","brightness":9,"brightMin":0,"brightMax":255,"startup":"on","mode":0,"rssi":-75},"ipaddress":"192.168.4.213"}

2021-11-13 22:07:18.681 [DEBUG] [unication.SonoffCommunicationManager] - Updated state for 1001106f87, with data {"data1":"4d7y0dh9cVoTS3YtDmXkQS9emlOeeTH+VBdku/gLWclnkDodp1zdes9VF667T79zBatlAVhN5g7REz6SYKjDUqBONABkWV4Vki8Jd94rBaZGrNjtshVzmPRyie9cYTKaPdzuHaHjjo3fAqXl0WNOTg\u003d\u003d","seq":"10","iv":"ODI2MTU4Mjg1MzQzMTA4MA\u003d\u003d","apivers":"1","type":"light","txtvers":"1","encrypt":"true","deviceid":"1001106f87","localAddress":"192.168.4.213","params":{"switch":"off","brightness":9,"brightMin":0,"brightMax":255,"startup":"on","mode":0,"rssi":-74},"ipaddress":"192.168.4.213"}

Hello,

First Thanks for the work done!!!

I using openhab 3.1, and I’m trying to make my dualr3 working.

Has someone got the latest version of the binding for OH 3.1?
The online version is not well supporting dual r3 relays.

I’ve tried to use 3.2 version but it looks to not work, so I hope that a version for 3.1 should do the job

Thanks again
PleKy

@pleky,
I also use 3.1 and 3.2 but failed to release the bind. The scan option does not find the devices and when I put them by hand it also does not work. Unfortunately, he has written some kind of binding, but there is no detailed documentation. Like most free stuff.

Hello kebibg,

Maybe I can help you at least to get the things detected.

Latest found 3.1 was fine with my 4CH pro, but mad with the dual R3.

I’ve done a couple of modification to make it scan (and not discovery - read lots of stuff in order to find it was the same but not on OH GUI :slight_smile: ).

You’re right free things means that some one is “paying” for this with his time. And documentation is always a really boring thing too :slight_smile: So I won’ blame him.

Saddly, github is not up to date, so I can’t recompile the JAR for 3.1. I hope that guys with 3.2 were able to make it run. If so, I’ll just wait for its release.
But if I can make it works with 3.1, I’ll be able to continue scripting my rules

ok, found something strange.

my 4CH was working fine, but not the dualR3.
I’ve reboot my OH vm, and the 4CH stopped working too COMM ERROR.

Then I’ve check the setup and found that local IP was not seen.
So I’ve reboot my 4CH and tada, OH received an update message from ewelink : got the IP.
So I’ve also reboot my dual R3, and bingo, got the IP.

So it looks like there is a missing point in order to get this IP address. maybe I should add persistancy to the channel hosting the local IP, but I guess it is not so easy.

I also wonder how is it going to work if I choose local only…

I will get back on this eventually guys, just too busy at present. Stuff I get paid for has to come first unfortunately and it’s looking this way until crimbo. Fingers crossed for the new year :+1:

The local discovery is detected when the binding starts, it’s multicast traffic and subscription only happens either when the binding loads or when the device is added at present.

Pretty sure I added dual R3 in latest release, this should also be backwards compatible to 3.1 main release (from memory, can’t remember exactly when javax got changed again). Enable debug log and see what it says when you drop the jar in

I think it is important for people trying to get that binding up and running when using Openhabian on Pi4 Version 2.5.12, as I do.
I was struggling when using the latest .jar file cause there was just nothing happening!! No possibility to add an sonoff account thing in PaperUI.
Reading all the whole thread multiple times I saw one message that it might be a try to use an older .jar file and Yes this was it!!! (it was really frustrating to reach this…)
OK I used the following version " [org.openhab.binding.sonoff-2.5.13-SNAPSHOT_2.4.jar] and it was running and suddenly I could create a new Thing.

  1. Created an account thing
  2. Automatically it found the SONOFF DW2-WiFi Magnetic Switch

I played a bit with the access mode in the account thing and was setting this to Cloud and Local.
Now both the account and the thing as such stay Online.

What concerns me a bit there are now some strange log entries like these, do I need to change something here?

2021-12-13 21:43:16.775 [ERROR] [connection.SonoffWebSocketConnection] - Websocket Closed, Status Code: 0, Reason:

==> /var/log/openhab2/events.log <==

2021-12-13 21:43:16.783 [hingStatusInfoChangedEvent] - 'sonoff:account:2657ebb4' changed from ONLINE to ONLINE (COMMUNICATION_ERROR): Cloud Offline

==> /var/log/openhab2/openhab.log <==

2021-12-13 21:43:16.787 [ERROR] [connection.SonoffWebSocketConnection] - Websocket Closed, Status Code: 1006, Reason:NullPointerException

2021-12-13 21:43:16.798 [ERROR] [connection.SonoffWebSocketConnection] - Websocket Closed, Status Code: 0, Reason:Disconnected

==> /var/log/openhab2/events.log <==

2021-12-13 21:43:48.064 [hingStatusInfoChangedEvent] - 'sonoff:account:2657ebb4' changed from ONLINE (COMMUNICATION_ERROR): Cloud Offline to ONLINE