themillhousegroup / openhab2-addons

Add-ons for openHAB 2.x
Eclipse Public License 2.0
36 stars 17 forks source link

Issues with binding #23

Open learnlinuxnow opened 3 years ago

learnlinuxnow commented 3 years ago

After switching to OH3.1.0-M5

Broadlink devices are not recognized anymore and stay uninitialised

Expected Behavior

Broadlink devices shall be recognized and shall initialised

Current Behavior

Broadlink devices are not recognized anymore and stay uninitialised

Restarting OH and so does not take any effect due to changes in UoM dependencies.

https://github.com/openhab/openhab-core/pull/2319

Possible Solution

recompile with changed UoM dependencies from code binding 3.1.0.b5

Steps to Reproduce (for Bugs)

Starting from OH3.0.2 and upgradeing to 3.1.0-M5 after waiting and migration time broadlink binding is not working anymore

See as well https://community.openhab.org/t/broadlink-binding-for-rmx-a1-spx-and-mp-any-interest/22768/1391

Your Environment

niebochod commented 3 years ago

Reproduces also for me. I can see the following in logs:

2021-07-06 20:16:47.510 [DEBUG] [.discovery.BroadlinkDiscoveryService] - bundle org.openhab.binding.broadlink:3.1.0.202107010042 (310)[org.openhab.binding.broadlink.internal.discovery.BroadlinkDiscoveryService(387)] : getting activate: activate
2021-07-06 20:16:47.511 [DEBUG] [.discovery.BroadlinkDiscoveryService] - bundle org.openhab.binding.broadlink:3.1.0.202107010042 (310)[org.openhab.binding.broadlink.internal.discovery.BroadlinkDiscoveryService(387)] : Locating method activate in class org.openhab.binding.broadlink.internal.discovery.BroadlinkDiscoveryService
2021-07-06 20:16:47.513 [DEBUG] [.discovery.BroadlinkDiscoveryService] - bundle org.openhab.binding.broadlink:3.1.0.202107010042 (310)[org.openhab.binding.broadlink.internal.discovery.BroadlinkDiscoveryService(387)] : Declared Method org.openhab.binding.broadlink.internal.discovery.BroadlinkDiscoveryService.activate([interface org.osgi.service.component.ComponentContext]) not found
2021-07-06 20:16:47.515 [DEBUG] [.discovery.BroadlinkDiscoveryService] - bundle org.openhab.binding.broadlink:3.1.0.202107010042 (310)[org.openhab.binding.broadlink.internal.discovery.BroadlinkDiscoveryService(387)] : Locating method activate in class org.openhab.core.config.discovery.AbstractDiscoveryService
2021-07-06 20:16:47.517 [DEBUG] [.discovery.BroadlinkDiscoveryService] - bundle org.openhab.binding.broadlink:3.1.0.202107010042 (310)[org.openhab.binding.broadlink.internal.discovery.BroadlinkDiscoveryService(387)] : Declared Method org.openhab.core.config.discovery.AbstractDiscoveryService.activate([interface org.osgi.service.component.ComponentContext]) not found
2021-07-06 20:16:47.518 [DEBUG] [.discovery.BroadlinkDiscoveryService] - bundle org.openhab.binding.broadlink:3.1.0.202107010042 (310)[org.openhab.binding.broadlink.internal.discovery.BroadlinkDiscoveryService(387)] : Found activate method: protected void org.openhab.core.config.discovery.AbstractDiscoveryService.activate(java.util.Map)
2021-07-06 20:16:47.520 [DEBUG] [.discovery.BroadlinkDiscoveryService] - bundle org.openhab.binding.broadlink:3.1.0.202107010042 (310)[org.openhab.binding.broadlink.internal.discovery.BroadlinkDiscoveryService(387)] : invoking activate: activate: parameters [org.apache.felix.scr.impl.helper.ReadOnlyDictionary]
2021-07-06 20:16:47.521 [DEBUG] [.discovery.BroadlinkDiscoveryService] - bundle org.openhab.binding.broadlink:3.1.0.202107010042 (310)[org.openhab.binding.broadlink.internal.discovery.BroadlinkDiscoveryService(387)] : invoked activate: activate
2021-07-06 20:16:47.523 [DEBUG] [.discovery.BroadlinkDiscoveryService] - bundle org.openhab.binding.broadlink:3.1.0.202107010042 (310)[org.openhab.binding.broadlink.internal.discovery.BroadlinkDiscoveryService(387)] : Set implementation object for component
2021-07-06 20:16:47.524 [DEBUG] [.discovery.BroadlinkDiscoveryService] - bundle org.openhab.binding.broadlink:3.1.0.202107010042 (310)[org.openhab.binding.broadlink.internal.discovery.BroadlinkDiscoveryService(387)] : Changed state from satisfied to active
2021-07-06 20:16:47.639 [DEBUG] [ink.internal.BroadlinkHandlerFactory] - Creating Thing handler for 'broadlink:rm2'
2021-07-06 20:16:47.640 [DEBUG] [ink.internal.BroadlinkHandlerFactory] - RM 2 handler requested created
2021-07-06 20:16:47.642 [DEBUG] [handler.BroadlinkRemoteModel2Handler] - constructed: resetting deviceKey to '<key-of-mydevice-was-here>', length 32
2021-07-06 20:16:47.652 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'broadlink:rm2:livingroom' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (HANDLER_CONFIGURATION_PENDING)

isn't this due to Declared Method org.openhab.binding.broadlink.internal.discovery.BroadlinkDiscoveryService.activate([interface org.osgi.service.component.ComponentContext]) not found ??

niebochod commented 3 years ago

Merging '3.1.0' + rebuilding addon unfortunately still not solves this problem for me.

I can see: AbstractDynamicDescriptionProvider.activate(ComponentContext componentContext) being introduced between 3.1.M5 and 3.1.0: https://github.com/openhab/openhab-core/compare/3.1.0.M5...3.1.0#diff-b4485d5f4197326099196bde0336eaed585c0f1c5299082949f9bfc900a74a09 but not sure if it's related to this issue.

niebochod commented 3 years ago

Reproduces for me also with: https://github.com/themillhousegroup/openhab2-addons/releases/tag/BROADLINK_3.2.beta1

niebochod commented 3 years ago

I can still see the same errors, however the problem with thing remaining in HANDLER_CONFIGURATION_PENDING occurs only with configuration done in .things file:

Thing broadlink:rm2:livingroom "Broadlink: RM2" @ "Livingroom"
        [ pollingInterval=180,
        ipAddress="10.0.0.161",
        port=80,
        staticIp=true,
        mac="<MAC>",
        authorizationKey="<auth-key>",
        iv="<iv>",
        retries=4,
        ignoreFailedUpdates=true,
        mapFilename="broadlink.map"
]

where i the MAC address of the broadlink device. Removing above declarations:

2021-07-26 21:56:29.352 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'broadlink:rm2:livingroom' changed from UNINITIALIZED (HANDLER_CONFIGURATION_PENDING) to UNINITIALIZED
2021-07-26 21:56:29.363 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'ThingStatus_Broadlink' changed from UNINITIALIZED to ?
2021-07-26 21:56:29.381 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'broadlink:rm2:livingroom' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

and letting autodiscover to detect device (under the same IP and MAC) makes it ONLINE:

2021-07-26 21:56:46.021 [WARN ] [.discovery.BroadlinkDiscoveryService] - BroadlinkDiscoveryService - Beginning Broadlink device scan...
2021-07-26 21:56:46.023 [WARN ] [.discovery.BroadlinkDiscoveryService] - Beginning async Broadlink device scan; will wait 10000 ms for responses
2021-07-26 21:56:46.035 [WARN ] [.discovery.BroadlinkDiscoveryService] - Broadlink device scan waiting for 10000 ms to complete ...
2021-07-26 21:56:46.147 [DEBUG] [.discovery.BroadlinkDiscoveryService] - Looking for thing type corresponding to model 10119
2021-07-26 21:56:46.150 [DEBUG] [.discovery.BroadlinkDiscoveryService] - Adding new Broadlink device (2787 => broadlink:rm2) at 10.0.0.161 with mac '<MAC>' to Smarthome inbox
2021-07-26 21:56:46.152 [DEBUG] [.discovery.BroadlinkDiscoveryService] - Device 'broadlink:rm2:<MAC>' discovered at '10.0.0.161'.
2021-07-26 21:56:46.218 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'broadlink:rm2:<MAC>' to inbox.
2021-07-26 21:56:46.219 [INFO ] [openhab.event.InboxAddedEvent       ] - Discovery Result with UID 'broadlink:rm2:<MAC>' has been added.
2021-07-26 21:56:56.038 [WARN ] [.discovery.BroadlinkDiscoveryService] - Device scan: wait complete ...
2021-07-26 21:56:56.040 [WARN ] [.discovery.BroadlinkDiscoveryService] - Ended Broadlink device scan...
2021-07-26 21:56:56.042 [INFO ] [.discovery.BroadlinkDiscoveryService] - Socket closed
2021-07-26 21:56:56.044 [INFO ] [.discovery.BroadlinkDiscoveryService] - Discovery complete. Found 1 Broadlink devices
2021-07-26 21:56:56.045 [INFO ] [.discovery.BroadlinkDiscoveryService] - Receiver thread ended
2021-07-26 21:56:57.340 [DEBUG] [ink.internal.BroadlinkHandlerFactory] - Creating Thing handler for 'broadlink:rm2'
2021-07-26 21:56:57.342 [DEBUG] [ink.internal.BroadlinkHandlerFactory] - RM 2 handler requested created
2021-07-26 21:56:57.343 [DEBUG] [handler.BroadlinkRemoteModel2Handler] - constructed: resetting deviceKey to '097628343fe99e23765c1513accf8b02', length 32
2021-07-26 21:56:57.369 [DEBUG] [handler.BroadlinkRemoteModel2Handler] - initializing handler
2021-07-26 21:56:57.375 [DEBUG] [handler.BroadlinkRemoteModel2Handler] - We've never actually successfully authenticated with this device in this session. Doing so now
2021-07-26 21:56:57.337 [INFO ] [openhab.event.InboxRemovedEvent     ] - Discovery Result with UID 'broadlink:rm2:<MAC>' has been removed.
2021-07-26 21:56:57.352 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'broadlink:rm2:<MAC>' changed from UNINITIALIZED to INITIALIZING
2021-07-26 21:56:57.672 [DEBUG] [handler.BroadlinkRemoteModel2Handler] - Authenticated with id '02000000' and key '<key>'
2021-07-26 21:56:57.674 [DEBUG] [handler.BroadlinkRemoteModel2Handler] - Authenticated with newly-detected device, will now get its status
2021-07-26 21:56:57.718 [INFO ] [ink.internal.BroadlinkMappingService] - Read 35 commands from /etc/openhab/transform/broadlink.map
2021-07-26 21:56:57.720 [DEBUG] [ink.internal.BroadlinkMappingService] - notifying framework about 35 commands from broadlink.map
....
2021-07-26 21:56:57.714 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'broadlink:rm2:<MAC>' changed from INITIALIZING to ONLINE