openhab / openhab-addons

Add-ons for openHAB
https://www.openhab.org/
Eclipse Public License 2.0
1.86k stars 3.58k forks source link

[Lutron] Adding QSE-CL-NWK support to binding #14585

Open phinnay opened 1 year ago

phinnay commented 1 year ago

I started a thread on the OpenHAB community forums and was directed to post here / tag @bobadair - I'm trying to get the Lutron addon to work with the QSE-CL-NWK IP gateway. I am able to log in, issue commands directly via TELNET in the LIP protocol, however OpenHAB can not log in and times out when trying to communicate.

Expected Behavior

The binding should talk via LIP to devices connected to the QS bus and allow for bi-directional control as is possible with other Lutron gateways.

Current Behavior

I install the plugin, define my Bridge Thing as below:

Bridge lutron:ipbridge:QSNNWK01 [ipAddress="192.168.10.31", user="nwk"]

Save the file, and the binding attempts to connect however is not able to complete handshake and set it's status to ONLINE.

8:55:25.892 [DEBUG] [.lutron.internal.LutronHandlerFactory] - Registering XML device discovery service.
18:55:25.915 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'lutron:ipbridge:QSNNWK01' changed from UNINITIALIZED to INITIALIZING
18:55:30.924 [WARN ] [.core.thing.internal.ThingManagerImpl] - Initializing handler for thing 'lutron:ipbridge:QSNNWK01' takes more than 5000ms.
18:55:30.954 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'lutron:keypad:QSNNWK01:testKeypad' changed from UNINITIALIZED to UNINITIALIZED (BRIDGE_UNINITIALIZED)
19:18:40.063 [DEBUG] [ery.LutronMcastBridgeDiscoveryService] - Scanning for Lutron bridge devices using multicast
19:18:41.073 [TRACE] [ery.LutronMcastBridgeDiscoveryService] - Bridge property: LUTRON : 2
19:18:41.077 [TRACE] [ery.LutronMcastBridgeDiscoveryService] - Bridge property: MACADDR : 000FE70669DE
19:18:41.080 [TRACE] [ery.LutronMcastBridgeDiscoveryService] - Bridge property: CMDREV : 3
19:18:41.084 [TRACE] [ery.LutronMcastBridgeDiscoveryService] - Bridge property: PRODFAM : GRAFIK
19:18:41.087 [TRACE] [ery.LutronMcastBridgeDiscoveryService] - Bridge property: PRODTYPE : Interface
19:18:41.091 [TRACE] [ery.LutronMcastBridgeDiscoveryService] - Bridge property: DEVTYPE : 0042
19:18:41.094 [TRACE] [ery.LutronMcastBridgeDiscoveryService] - Bridge property: IPADDR : 192.168.010.031
19:18:41.098 [TRACE] [ery.LutronMcastBridgeDiscoveryService] - Bridge property: SUBNETMK : 255.255.255.000
19:18:41.101 [TRACE] [ery.LutronMcastBridgeDiscoveryService] - Bridge property: GATEADDR : 192.168.010.001
19:18:41.106 [TRACE] [ery.LutronMcastBridgeDiscoveryService] - Bridge property: TELPORT : 0017
19:18:41.110 [TRACE] [ery.LutronMcastBridgeDiscoveryService] - Bridge property: CODEVER : 08.60
19:18:43.117 [TRACE] [ery.LutronMcastBridgeDiscoveryService] - Timed out waiting for multicast response. Presumably all bridge devices have already responded.

Randomly, the addon is able to log in, but ignores all the communication sent by the QSE-CL-NWK.

18:31:24.526 [DEBUG] [tron.internal.handler.IPBridgeHandler] - Received message QSE>~DEVICE,0x002a8ece,19,4
18:31:24.530 [DEBUG] [tron.internal.handler.IPBridgeHandler] - Ignoring message QSE>~DEVICE,0x002a8ece,19,4
18:31:24.538 [DEBUG] [tron.internal.handler.IPBridgeHandler] - Received message QSE>~DEVICE,0x002a8ece,19,4
18:31:24.543 [DEBUG] [tron.internal.handler.IPBridgeHandler] - Ignoring message QSE>~DEVICE,0x002a8ece,19,4

Possible Solution

I do not know much about Java. Looking through the source, the public class IPBridgeHandler of IPBridgeHandler.java needs to be adjusted to recognize the “QSE>” prompt used by this bridge.

private static final String PROMPT_GNET = "GNET>";
private static final String PROMPT_QNET = "QNET>";
private static final String PROMPT_SAFE = "SAFE>";
private static final String LOGIN_MATCH_REGEX = "(login:|[GQ]NET>|SAFE>)";

From then on, the protocol is standard LIP… The only other quirk I see is some of the monitoring types (SYSTEM,TIMECLOCK,MODE,SYSVAR,GROUP) do not apply. I am not sure if this matters.

Steps to Reproduce (for Bugs)

  1. Add the Lutron plugin to OpenHAB
  2. Attempt to connect to a QSE-CL-NWK

Context

The QSE-CL-NWK is a cost effective ($40 used) way to utilize Lutron scene controllers, keypads, and many other devices that talk on the QS bus without needing other Lutron products, licenses, or software. My end goal is to use SeeTouch keypads to trigger rules in OpenHAB and provide tactile, easy to use wall controls and indicators.

Description of the QSE-CL-NWK LIP Protocol refrence - specifically the "Standalone" section Similar use case and notes on quirks of it's protocol

Your Environment

Linux openhab3 5.10.0-21-amd64 #1 SMP Debian 5.10.162-1 (2023-01-21) x86_64

                           _   _     _     ____
   ___   ___   ___   ___  | | | |   / \   | __ )
  / _ \ / _ \ / _ \ / _ \ | |_| |  / _ \  |  _ \
 | (_) | (_) |  __/| | | ||  _  | / ___ \ | |_) )
  \___/|  __/ \___/|_| |_||_| |_|/_/   \_\|____/
       |_|       3.4.2 - Release Build

Use '<tab>' for a list of available commands
and '[cmd] --help' for help on a specific command.
To exit, use '<ctrl-d>' or 'logout'.

openhab> bundle:list | grep Lutron
241 x Active x  80 x 3.4.2                  x openHAB Add-ons :: Bundles :: Lutron Binding
openhab>
openhab-bot commented 1 year ago

This issue has been mentioned on openHAB Community. There might be relevant details there:

https://community.openhab.org/t/lutron-qse-cl-nwk-support/145102/4

phinnay commented 1 year ago

I proved out that this is possible with some workarounds in the code. This is very outside my skillset - its not pretty but it works:

There are four(?) issues:

The other file that needed to be changed was LutronMcastBridgeDiscoveryService.java since I was noticing timeouts waiting on the multicast discovery. Lutron QS and above IP based devices announce on port 2647 so the master controller knows to add them, the QSE-CL-NWK also does this but since its operating in 'standalone' mode there's nothing to handshake with and no serial number is reported back during discovery.

I compiled the edits using the instructions on the OH site and loaded the plugin manually via the addons folder.

17:37:39.762 [DEBUG] [very.LutronMdnsBridgeDiscoveryService] - bundle org.openhab.binding.lutron:3.4.3.202303142136 (302)[org.openhab.binding.lutron.internal.discovery.LutronMdnsBridgeDiscoveryService(352)] : Changed state from satisfied to active
17:38:39.695 [DEBUG] [ery.LutronMcastBridgeDiscoveryService] - Scanning for Lutron bridge devices using multicast
17:38:40.707 [TRACE] [ery.LutronMcastBridgeDiscoveryService] - Bridge property: LUTRON : 2
17:38:40.711 [TRACE] [ery.LutronMcastBridgeDiscoveryService] - Bridge property: MACADDR : 000FE70669DE
17:38:40.714 [TRACE] [ery.LutronMcastBridgeDiscoveryService] - Bridge property: CMDREV : 3
17:38:40.717 [TRACE] [ery.LutronMcastBridgeDiscoveryService] - Bridge property: PRODFAM : GRAFIK
17:38:40.720 [TRACE] [ery.LutronMcastBridgeDiscoveryService] - Bridge property: PRODTYPE : Interface
17:38:40.722 [TRACE] [ery.LutronMcastBridgeDiscoveryService] - Bridge property: DEVTYPE : 0042
17:38:40.725 [TRACE] [ery.LutronMcastBridgeDiscoveryService] - Bridge property: IPADDR : 192.168.010.031
17:38:40.728 [TRACE] [ery.LutronMcastBridgeDiscoveryService] - Bridge property: SUBNETMK : 255.255.255.000
17:38:40.731 [TRACE] [ery.LutronMcastBridgeDiscoveryService] - Bridge property: GATEADDR : 192.168.010.001
17:38:40.734 [TRACE] [ery.LutronMcastBridgeDiscoveryService] - Bridge property: TELPORT : 0017
17:38:40.737 [TRACE] [ery.LutronMcastBridgeDiscoveryService] - Bridge property: CODEVER : 08.60
17:38:40.757 [INFO ] [ig.discovery.internal.PersistentInbox] - Added new thing 'lutron:ipbridge:12345678abcd' to inbox.
17:38:40.759 [INFO ] [openhab.event.InboxAddedEvent        ] - Discovery Result with UID 'lutron:ipbridge:12345678abcd' has been added.
17:38:40.761 [DEBUG] [ery.LutronMcastBridgeDiscoveryService] - Discovered Lutron bridge device lutron:ipbridge:12345678abcd
17:38:42.766 [TRACE] [ery.LutronMcastBridgeDiscoveryService] - Timed out waiting for multicast response. Presumably all bridge devices have already responded.
17:39:08.694 [TRACE] [ing.lutron.internal.net.TelnetSession] - Creating new TelnetSession
17:39:08.732 [DEBUG] [.lutron.internal.LutronHandlerFactory] - Registering XML device discovery service.
17:39:08.809 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'lutron:ipbridge:QSNNWK01' changed from UNINITIALIZED (DISABLED) to INITIALIZING
17:39:08.822 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'lutron:ipbridge:QSNNWK01' changed from INITIALIZING to OFFLINE: Connecting
17:39:08.823 [DEBUG] [tron.internal.handler.IPBridgeHandler] - Connecting to bridge at ltnwk01.home.catfeesh.com
17:39:08.826 [TRACE] [ing.lutron.internal.net.TelnetSession] - TelnetSession open called
17:39:08.841 [TRACE] [ing.lutron.internal.net.TelnetSession] - TelnetSession waitFor called with login: 0
17:39:08.850 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'lutron:keypad:QSNNWK01:testKeypad' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING
17:39:08.852 [TRACE] [ing.lutron.internal.net.TelnetSession] - TelnetSession writeLine called with nwk
17:39:08.854 [TRACE] [ing.lutron.internal.net.TelnetSession] - TelnetSession waitFor called with (login:|QSE>|[GQ]NET>|SAFE>) 0
17:39:08.860 [DEBUG] [on.internal.handler.BaseKeypadHandler] - Initializing Keypad Handler for integration ID 10
17:39:08.862 [DEBUG] [tron.internal.handler.IPBridgeHandler] - Received message connection established
17:39:08.864 [DEBUG] [on.internal.handler.BaseKeypadHandler] - Async init thread staring for keypad handler 10
17:39:08.865 [DEBUG] [tron.internal.handler.IPBridgeHandler] - Ignoring message connection established
17:39:08.866 [DEBUG] [lutron.internal.handler.KeypadHandler] - Configuring components for keypad model W7B
17:39:08.869 [DEBUG] [on.internal.handler.BaseKeypadHandler] - Configuring channels for keypad 10
17:39:08.877 [DEBUG] [on.internal.handler.BaseKeypadHandler] - Done configuring channels for keypad 10
17:39:08.880 [DEBUG] [on.internal.handler.BaseKeypadHandler] - Initializing device state for Keypad 10
17:39:08.882 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'lutron:keypad:QSNNWK01:testKeypad' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE)
17:39:08.885 [DEBUG] [on.internal.handler.BaseKeypadHandler] - Async init thread finishing for keypad handler 10
17:39:26.932 [DEBUG] [tron.internal.handler.IPBridgeHandler] - Received message ~DEVICE,10,1,3
17:39:26.937 [TRACE] [on.internal.handler.BaseKeypadHandler] - Handling command DEVICE [1, 3] from keypad 10
17:39:26.948 [DEBUG] [lutron.internal.handler.LutronHandler] - Bridge status changed to ONLINE for lutron device handler 10
17:39:26.951 [DEBUG] [on.internal.handler.BaseKeypadHandler] - Initializing device state for Keypad 10
17:39:26.954 [DEBUG] [tron.internal.handler.IPBridgeHandler] - Starting keepAlive job with interval 5
17:39:26.957 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'lutron:ipbridge:QSNNWK01' changed from OFFLINE: Connecting to ONLINE
17:39:26.960 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'tstbtn1' changed from OFF to ON
17:39:26.954 [DEBUG] [tron.internal.handler.IPBridgeHandler] - Sending command #MONITORING,12,2
17:39:26.962 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'tstbtn1' changed from ON to OFF

important bits below :D

image

lutron.things

Bridge lutron:ipbridge:QSNNWK01 [ ipAddress="ltnwk01.home.domain.com", user="nwk", password="NOPASS"] {
         Thing keypad ltKeypad10 [integrationId="10", model="W7B", autorelease="false"]   
}

lutron.items

Switch ltKeypad10_B1              "Lutron B1"                                     {channel="lutron:keypad:QSNNWK01:ltKeypad10:button1"}
Switch ltKeypad10_B2              "Lutron B2"                                     {channel="lutron:keypad:QSNNWK01:ltKeypad10:button2"}
Switch ltKeypad10_B3              "Lutron B3"                                     {channel="lutron:keypad:QSNNWK01:ltKeypad10:button3"}
Switch ltKeypad10_B4              "Lutron B4"                                     {channel="lutron:keypad:QSNNWK01:ltKeypad10:button4"}
Switch ltKeypad10_B5              "Lutron B5"                                     {channel="lutron:keypad:QSNNWK01:ltKeypad10:button5"}
Switch ltKeypad10_B6              "Lutron B6"                                     {channel="lutron:keypad:QSNNWK01:ltKeypad10:button6"}

lutron.rules

rule ltKeypad10-test
when
        Item ltKeypad10_B1 received update ON
then
        swGarageRadioPWR.sendCommand(ON) 
    logInfo('Lutron - Debug', " **BUTTON 1 PRESSED** ")
end

It works as expected and has been stable for a day or so! I know I'm missing something in the code since it still shows offline in the GUI: image image

I don't use the GUI so it's not a showstopper however I do hope @bobadair or someone smarter than me can make sense of the above and roll it in to the source for all to use. This solves my biggest gripe with OH (and all ""non-professional"" automation platforms) of the lack of physical controls / having to use an app. For under $100 you can get a few keypads and really make things nice or bring new life to a broken / outdated / discontinued system.

openhab-bot commented 1 year ago

This issue has been mentioned on openHAB Community. There might be relevant details there:

https://community.openhab.org/t/lutron-qse-cl-nwk-support/145102/5

phinnay commented 1 year ago

Had to do some more tinkering with this yesterday, I don't know why the binding worked for a little while and then stopped... It would make sense for OH3 to have some internal health-check to kick out bindings marked as "offline" after X time but nothing in the logs shows this to be the case. Either way, after about a week the binding stopped accepting input from the NWK interface.

One of the features I see all over the binding is XML auto-discovery, which, makes sense with a processor - the NWK has no such ability and the binding logic (understandably) doesn't really know how to deal with that. I followed references until getting to the registerDiscoveryService class of LutronHandlerFactory.java

image

Registering XML device discovery service was the last thing the binding logs before going into it's offline-but-still-working state so figured that might be a good thing to remove. The class is called around line 143 and it seemed like a bridgeHandler object would be returned with or without it.... so I commented that out.

image

Compliled and moved the new file to the addons folder, restarted and it came online :D

image

the binding seems much more stable now, it's sending keep-alive messages and associated keypads also show online properly so hoping thats the last tweak we need to do. Again, I do hope someone with a clue to what they are doing can take these hacks and roll them upstream for a larger audience.