Trane XR524 ZWave not updating / OH3

flpaoli · January 19, 2021, 3:57am

Hi, I’m new to OpenHAB but technically literate. I setup a RPi 4 OH3 Z-Wave build using an Aeotec USB Z-Wave Gen5+, an Aeotec Multisensor and two Trane XR524 thermostats.

My Multisensor is working fine, updating in OH3, but the thernmostats aren’t. They rarely update the temperature sensor, for example right now one says in OH3 that it’s 71.6 but on the Thermostat screen I see 74.

Network map seems fine, all devices see each other bi-directionally, in theory everything should be working fine.

I saw this thread [SOLVED] Zwave devices not updating item states after upgrade to OH 3 - #9 by JamesC and updated my zwave binding to 3.1.0-snapshot, but that didn’t change the behavior.

Any pointers on what I should look at? I’ve put Zwave in debug and the only strange message is one that says Transaction not completed, as this example below for TID 136:

openhabian@openHABianDevice:~ $ cat  /var/log/openhab/openhab.log | grep "136"
2021-01-18 22:13:59.136 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 69: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 56
2021-01-18 22:13:59.136 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2021-01-18 22:24:18.136 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2021-01-18 22:24:34.136 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 95: Advanced to WAIT_DATA
2021-01-18 22:40:17.136 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2021-01-18 22:50:17.155 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Added 136 to queue - size 6
2021-01-18 22:50:17.654 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 136: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 123
2021-01-18 22:50:17.663 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 136: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 123
2021-01-18 22:50:17.669 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 136: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 123
2021-01-18 22:50:17.671 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 136: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 123
2021-01-18 22:50:17.674 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 136: Advanced to WAIT_REQUEST
2021-01-18 22:50:17.676 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: TID 136: Transaction not completed
2021-01-18 22:50:17.688 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 136: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 123
2021-01-18 22:50:17.690 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 136: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 123
2021-01-18 22:50:17.691 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 136: (Callback 123)
2021-01-18 22:50:17.694 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 136: callback 123
2021-01-18 22:50:17.700 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 136: Advanced to WAIT_DATA
2021-01-18 22:50:17.701 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: TID 136: Transaction not completed
2021-01-18 22:50:17.728 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: notifyTransactionResponse TID:136 DONE

Thanks

Bruce_Osborne · January 19, 2021, 7:48am

I am not an expert but the log viewer may help. Be sure to use unfiltered logs.

flpaoli · January 19, 2021, 5:26pm

Thank you @Bruce_Osborne , that log viewer seems useful. I’m still not sure what is happening , but it gives a clearer view by grouping things together.

It seems everything is communicating, but some strange findings.

For example I learned that the thermostat seems to be responding in Celsius even though it is configured in Fahrenheit and the Thermostat screen shows Fahrenheit.

Other elements, like the setpoint, is informed in Fahrenheit:

Maybe that’s why I see less change in OpenHab than in the Thermostat, since C is larger than F (change of 1C = 1.8F)?

Does anyone know if this is something I can reconfigure in OpenHab, or is it something that needs to be fixed in the Thermostat?

flpaoli · January 20, 2021, 4:31am

OK, so it seems the Celsius or Fahrenheit setting for the temperature of the Thermostat is something I configure in OpenHab, specifically Parameter 4 of XR524.

So I went into the UI and changed it from 0 (Celsius) to 1 (Fahrenheit), Saved, restarted OpenHab from command line (services openhab stop then start), ran a script I created to get the item state then print the temperature to log, and… it comes as Celsius

Stopped OpenHab again, went to look into the jsondb, org.openhab.core.thing.Thing.json, found that “config_4_1” was set to 0 , so I stopped OH, changed it to 1 in both Thermostats, restarted OH, ran my script, and… I get a Celsius temperature printed to the log, and, if I go in Things it shows the parameters as 0, even though if I check the file it is “config_4_1”: 1 . Seems like some kind of bug that whatever is configured in jsondb isn’t properly read .

Can my problem be that I’ve configured everything through the UI and the UI + jsondb is just too buggy still?

At least by looking at the logs through the log viewer I can see my original suspicion that the nodes weren’t communicating correctly was wrong.

Has someone experienced something similar which was resolved by dumping the UI + jsondb completely and configuring all through files in etc? I haven’t tried that, can do it, but just don’t want to spend the time doing it if I don’t have to.

flpaoli · January 22, 2021, 4:23am

Hi @chris , it seems you are one of the experts in ZWave binding, so Id like to ask you a question in the context of this thread.

I have a thermostat configured (in the hardware) to use Unit Farenheit, I have OpenHab configured to use Imperial units, but somehow when I run the script below and look at zwave binding logs I see Celsius:

Script:

var logger = Java.type('org.slf4j.LoggerFactory').getLogger('org.openhab.rule.' + ctx.ruleUID);


logger.info('thermostat2_sensortemperature');
logger.info(itemRegistry.getItem('thermostat2_sensortemperature').getState());

Output of the script in the logs:

2021-01-21 22:38:18.658 [INFO ] [org.openhab.rule.73f2b2e323         ] - thermostat2_sensortemperature
2021-01-21 22:38:18.689 [INFO ] [org.openhab.rule.73f2b2e323         ] - 71.60 °F

What comes out of log:set DEBUG for zwave, using viewer to read it easier https://opensmarthouse.org/utilities/logviewer/zwave/

Here is the raw log:

2021-01-21 22:37:15.081 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Application Command Request (ALIVE:DONE)
2021-01-21 22:37:15.082 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: resetResendCount initComplete=true isDead=false
2021-01-21 22:37:15.083 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: Incoming command class COMMAND_CLASS_SENSOR_MULTILEVEL, endpoint 0
2021-01-21 22:37:15.084 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: SECURITY not supported
2021-01-21 22:37:15.085 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 3: Received COMMAND_CLASS_SENSOR_MULTILEVEL V5 SENSOR_MULTILEVEL_REPORT
2021-01-21 22:37:15.087 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 3: Sensor Type = Temperature(1), Scale = 0
2021-01-21 22:37:15.088 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 3: Sensor Value = 22
2021-01-21 22:37:15.089 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got an event from Z-Wave network: ZWaveMultiLevelSensorValueEvent
2021-01-21 22:37:15.090 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_SENSOR_MULTILEVEL, value=22
2021-01-21 22:37:15.092 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Updating channel state zwave:device:114695ed8b:node3:sensor_temperature to 22 °C [QuantityType]
2021-01-21 22:37:15.096 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Commands processed 1.
2021-01-21 22:37:15.097 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1652b0e.
2021-01-21 22:37:15.099 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Command verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1652b0e.
2021-01-21 22:37:15.100 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: notifyTransactionResponse TID:2909 DONE
2021-01-21 22:37:15.102 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent

Please can you help me understand what I’m doing wrong here, what is left to configure?

flpaoli · January 27, 2021, 4:20am

Okay, so I dug deeper and checked the source code at github and in ZWaveMultiLevelSensorCommandClass.java I see that because I’m getting these log lines I can be 100% sure my Thermostat is sending temperature sensor value in Celsius, even if its screen says it is operating in Fahrenheit:

2021-01-21 22:37:15.085 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 3: Received COMMAND_CLASS_SENSOR_MULTILEVEL V5 SENSOR_MULTILEVEL_REPORT
2021-01-21 22:37:15.087 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 3: Sensor Type = Temperature(1), Scale = 0
2021-01-21 22:37:15.088 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 3: Sensor Value = 22

So I guess this problem is not in anything Openhab, nor is it fixable in Openhab.

I will try to run one of the Thermostats in Celsius and see what the hell happens in Openhab. I’ll report back on what I find out.

I wonder if a firmware update on the Thermostat could fix it, but it seems you can’t do that for a Trane XR524 without buying equipment for Nexia bridge, which I’m not intending to do.

Might have to swap these for another brand/model. Problem is I liked their looks.

flpaoli · January 31, 2021, 7:20pm

So, this is what I found out as I changed the Thermostats to Celsius and then back to Fahrenheit…

When I go to the XR524’s setup and change it’s base unti to Celsius, without changing anything in OpenHAB, like magic it starts to report more frequently or with better granularity. See the Grafana chart below. I flipped it to Celsius close to midnight on 27/Jan. Visible change.

I did the same with the second unit, and, same behavior.

Then, after a day or so I flipped it back to Fahrenheit around 23:00 of 28/Jan, and look what happens, I lost granularity again:

Flipped it later back to Celsius and got granular measures again.

So… I don’t know, but, based on my experience I think the Trane XR524 operates internally in Celsius, and then converts to Fahrenheit with zero decimal point math. That is a plausible explanation why Celsius has such granularity (1 decimal point precision) whilst Fahrenheit doesn’t.

I am going to keep these Thermostats because family is Celsius-enabled, it might even be good for the kids to practice their Celsius, and I like the clean looks.

But if you’re wanting a thermostat for OpenHAB and Fahrenheit only operation, I think Trane XR524 is not for you.