ZWave: Race conditions at 24 hrs

I’ve got 6 ZWave switches throughout my house (start small) and am running into something like a race condition after the binding has been running for 24 hours. The switches are the Homeseer ones that report instant updates and support single/double/triple tap.

When the switch is tapped on, it queries the current state and then determines what to do.

  • If the light is off, it turns on to 35%.
  • If the light is at 35%, it then turns to 85%.
  • If the light is at 85%, it turns down to 35%.
  • If you tap the switch off it turns it off.

This logic is implemented via rules and the percentage values come from a local webservice.

This works flawlessly for the first 24 hours. But then it starts acting weird. The initial tap on works - it goes to 35%. But the subsequent taps don’t. This morning I’m seeing it in my Family Room and the Nursery. Yesterday it was in the Family Room/Kitchen/Dining Room. So it’s not consistent based on switch.

I’ve got logs, and it looks like a race condition. The first tap always works flawlessly, the subsequent taps are the issues. I’ll include the full logs, but here’s a breakdown from when the second tap starts.

Working Lights - Kitchen

  1. Starting from 08:04:40
  2. Scene Notification & update that scene 1 was tapped
  3. Rule is triggered to get current state which sends a status request?
  4. Receive the current state via SWITCH_MULTILEVEL_REPORT
  5. Updates internal state to 31 (current state)
  6. Send Command to change light to 85 (new state)
  7. Receive ACK

Failing Lights - Family Room

  1. Starting from 08:07:24
  2. Scene Notification & update that scene 1 was tapped
  3. Rule is triggered to get current state which sends a status request?
  4. Send Command to change light to 85 (new state)
  5. Receive the current state via SWITCH_MULTILEVEL_REPORT (31, the old state)
  6. Updates internal state to 31 (current state)
  7. Ack Received

So this one updates out of order and leaves OpenHab confused about what the current state actually is.

My current solution is to restart the binding every morning. Clearly I’d like to find a fix but it’s hard to debug anything since this only happens after the binding has been running for a while. I’ve looked at the code very briefly but thought I’d post here in case someone had a clue.

Any thoughts on where to look?

The debug log is always the best place to look. You can then use the online viewer to see what’s happening.

That’s how I broke down what was going on. Debug logs are linked

Where? I can’t see them in your message :confused:.

I’m too clever. The headings are linked:

Working:

Failed:

So looking at the problem log, here’s my view on what’s happening.

I don’t see any problem with what the binding is doing, but I might not completely understand your rule. I certainly don’t see any race condition…

So…

We see the scene notification come in - this triggers the rule and you set the level to 85. The binding received a state saying the switch is at 35. This is a bit naughty as the switch shouldn’t send this status unsolicited. The binding then updates the value with 35% - all good as far as the binding goes.

I’m assuming that you expect it to update (or stay) at 85%?

So, the issue as far as I can see is that the device is sending an incorrect state saying it’s at 35% when you just changed it to 85%. Given that the device is sending this incorrect state, there’s no way to resolve it completely unless there’s a way to stop the device sending the reports.

I would suggest you request an REFRESH update at the end of the rule - then the invalid state would only persist for a short period of time - not ideal, but unless you can stop the invalid response from the device, I don’t think there’s another option.