(Solution found) Rules are not triggered by "Changed to ON"

I’m running build #463 and seeing similar behaviour. Here are my test rules:

rule “Light Test Updated”
when
Item Light_GF_Dining_Main received update
then
logInfo(“Dining Room”,“Light Updated”)
end

rule “Light Test On”
when
Item Light_GF_Dining_Main changed to ON
then
logInfo(“Dining Room”,“Light On”)
end

rule “Light Test Off”
when
Item Light_GF_Dining_Main changed to OFF
then
logInfo(“Dining Room”,“Light Off”)
end

I tested physically turning the switch on and off and using HABmin. The only time I get any log notification is if I use HABmin and then it only recognizes the “received update” but that also triggers even if I just do a HABmin refresh item.

The reported “solution” was not correct. See this thread of me https://community.openhab.org/t/sonos-binding-causes-problems-with-rules-after-a-reboot/13796/3

Thanks Jurgen, but that didn’t seem to be my issue. I double checked the item list ahead of installing build #465 and didn’t see any duplicate items. After #465, I’m getting the same issues. Wonder if I need to just go to a config file as well…

If you only have log-entries when using habmin it looks to me as if you only get item events and nothing from a thing. Are they connected at all? Can you switch anything with habmin?

I can control from HABmin or my sitemaps with no problems. Though they will only trigger a “received update” rule and not a “Changed to” rule when doing so from the UI (which is more then happens if I do a manual switch).

@opus Here is what I got from a debug log file with physically turning the dimmer on, setting a dim level and turning it off.

2016-09-05 14:44:41.761 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 3: Application update request. Node information received.
2016-09-05 14:44:41.762 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Starting initialisation from DONE
2016-09-05 14:44:41.762 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@8a8d9b already registered
2016-09-05 14:44:41.763 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Poll, dest=6, callback=120, payload=06 01 00 
2016-09-05 14:44:41.764 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=ApplicationUpdate[0x49], type=Request[0x00], priority=High, dest=255, callback=0, payload=84 03 11 04 11 04 26 27 75 86 70 71 85 77 2B 2C 72 73 82 87 
2016-09-05 14:44:41.764 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=ApplicationUpdate, callback id=120, expected=SendData, cancelled=false      MISMATCH
2016-09-05 14:45:25.364 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 17 00 49 84 03 11 04 11 04 26 27 75 86 70 71 85 77 2B 2C 72 73 82 87 24 
2016-09-05 14:45:25.375 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2016-09-05 14:45:25.379 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 17 00 49 84 03 11 04 11 04 26 27 75 86 70 71 85 77 2B 2C 72 73 82 87 24 
2016-09-05 14:45:25.384 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 17 00 49 84 03 11 04 11 04 26 27 75 86 70 71 85 77 2B 2C 72 73 82 87 24 
2016-09-05 14:45:25.388 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationUpdate[0x49], type=Request[0x00], priority=High, dest=255, callback=0, payload=84 03 11 04 11 04 26 27 75 86 70 71 85 77 2B 2C 72 73 82 87 
2016-09-05 14:45:25.389 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 3: Application update request. Node information received.
2016-09-05 14:45:25.390 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Starting initialisation from DONE
2016-09-05 14:45:25.391 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@8a8d9b already registered
2016-09-05 14:45:25.393 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Poll, dest=6, callback=120, payload=06 01 00 
2016-09-05 14:45:25.396 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=ApplicationUpdate[0x49], type=Request[0x00], priority=High, dest=255, callback=0, payload=84 03 11 04 11 04 26 27 75 86 70 71 85 77 2B 2C 72 73 82 87 
2016-09-05 14:45:25.397 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=ApplicationUpdate, callback id=120, expected=SendData, cancelled=false      MISMATCH

I’m sorry., but I do not use ZANE, therefore I can’t anything to those DEBUG messages.

Other questions from me:
Do you have all Item linking done by PaperUI, or do you have them in an .Items file?
Are you using the the “simple mode” for items linking?

No worries, thanks.

I have Paper set for simple and then create my items in HABmin. I did try a test item through my.items file but same results.

If you use the simple mode,PaperUI will automatically link channels for the detected things. By using habmin for the same ( which I don’t use ) those links might be created twice. Which could be the cause of the problem.
In simple mode OFF only those channels that are linked by habmin ( or an .items file) will be created.

Sorry, mispoke. I have simple mode off.

@chris I think there is something going on in how the zwave binding is passing state changes back to OH. I can see the physical changes in HABmin (sometimes requires a refresh) but I can’t get rules using either “received update” or “changed to” checks to pickup the changes. I remember seeing a while back a similar issue with Cooper dimmers (which I’m using), so it might be unique to them. Though I do have a couple of Linear’s that I was having issues with as well (though did not run the same full rule test I did above, but could do so if that would help).

Let me know your thoughts and/or any tests I can run to help narrow down if this is just my system or a broader issue.

The binding uses the standard channel update methods, so I don’t think there’s much I can do to influence this (as far as I know). What does the events log show (or even the main log)?

@chris

So I saw @Kai 's note about the rule bug fix - [Partly solved] Rules are not triggered as expected So I got hopeful that would solve my issue. I installed the latest build and reran my test. What I’m noticing is if I physically change the switch nothing is updating in HABmin or PaperUI for the light status. If I refresh the thing in HABmin then both register the new status and I get an item updated in my info file related to my rules above (still nothing from changed to registering).

So I ran a full test of:

  • Setting system into Debug
  • Turning on the switch (nothing registered in HABmin/Paper)
  • Doing a refresh in Habmin (now registering change in both)
  • Turning off the switch (nothing registered in HABmin/Paper)
  • Doing a refresh in Habmin (now registering change in both)
  • Turning off Debug

The log entries are here (too many characters, but not 33 meg this time :slight_smile: - https://drive.google.com/open?id=0B77VHtwPft8eVjJaVEgwaVVxcU0

So I noticed the 1800 polling and sure enough when I looked at the Thing Device Configuration, sure enough it’s set for an 1800 polling. Also, these are Cooper dimmers which should be broadcasting their status changes to OH I wouldn’t think it would matter on the polling?

Any thoughts or any other tests I should run?

Thanks.

Ok, solved the issue with OH not updating. When the Device was created it didn’t associate itself with the OH Controller in Group 1. Once I manually added the Controller to the Group 1 association I’m getting real time updates in HABmin and PaperUI. And I’m seeing the Log showing the device was Updated. Still not getting the rule to recognize “Changed to” but at least the first piece is solved.

Though interesting enough I have other versions of the same switch in the house and they reflect instantly w/o the need to add the Controller to the Group 1 association. So I tried removing it from the switch in question and it quit updating. The only other difference between the two switches is the one having issues is associated with an Aux switch (also Cooper) and the second one is a standalone setup…

So continuing to test / add on to this thread.

So I tested just using “Item XXXX Changed” as a condition state, and that triggers it just like “Received Update” What I can’t seem to get to work is if I try to include a condition state of “On” in either one. I also was trying to use an if(item.state=ON) and kept getting errors like:

An error occured during the script execution: Could not invoke method: org.eclipse.smarthome.model.script.actions.LogAction.logInfo(java.lang.String,java.lang.String,java.lang.Object[]) on instance: null

And in Eclipse designer it would tell me that the “The method or field item is undefined”

So it seems that there is no reported State for this dimmer switch and that might be why my rules that are State specific aren’t working.

Thoughts?

Try if(item.state==ON) instead of if(item.state=ON).

1 Like

@kai Thanks. I had tried both forms. Here is the exact rule:

rule "Light Test Updated"
when
    Item Light_GF_Dining_Main received update
then
	logInfo("Dining Room","Light Updated")
	if(Light_GF_Dining_Main.state==ON) {
		logInfo("Dining Room","On")	
	}
end

I get the Updated entry but not the state On entry in my log file. I’ve tested it both with a item created in HABmin and a manually defined item in my .items folder, same results.

I also reinstated my humidity / fan rule last night and it looks like that state check in that rule (checking humidity level) is triggering a similar null error

rule "Kids Bathroom Fan Controller"
when
    Item Sensor_SF_KidsBath_Humidity changed
    or
    Item Fan_SF_KidsBath changed from OFF to ON
then
  // This section controls the fan between a high and low set-point.
  if((Sensor_SF_KidsBath_Humidity.state > 60) && (Fan_SF_KidsBath.state = OFF)) {
	logInfo("Kids Bath Fan","On for humidity")
	Override = false
    sendCommand(Fan_SF_KidsBath, ON)
  }
  else if((Override == false) && (Sensor_SF_KidsBath_Humidity.state < 55) && (Fan_SF_KidsBath.state == ON)) {
    sendCommand(Fan_SF_KidsBath, OFF)
  }

  // This timer turns the fan off if it has been manually turned on.
  if((Fan_SF_KidsBath.state == ON) && (Sensor_SF_KidsBath_Humidity.state < 55)) {
    Override = true
    if(timerA == null) {
		timerA = createTimer(now.plusMinutes(15)) [
			Override = false
			sendCommand(Fan_SF_KidsBath, OFF)
		]
    }
  }
end

Gave me:

2016-09-07 06:55:40.722 [ERROR] [.script.engine.ScriptExecutionThread] - Rule 'Kids Bathroom Fan Controller': An error occured during the script execution: Could not invoke method: org.eclipse.xtext.xbase.lib.BooleanExtensions.operator_and(boolean,boolean) on instance: null

Could not invoke method: org.eclipse.xtext.xbase.lib.BooleanExtensions.operator_and(boolean,boolean) on instance: null

This is correct, because your rule still has Fan_SF_KidsBath.state = OFF instead of Fan_SF_KidsBath.state == OFF.

This is correct, because your rule still has Fan_SF_KidsBath.state = OFF instead of Fan_SF_KidsBath.state == OFF.

Interesting, did the parser get more picky on syntax in the last couple of months? That would explain why it worked in ~May and then quite working about a month back. I will test tonight/tomorrow so we can see if the state issue is limited to just the dimmer or a more general issue.

Thanks.

palm to forehead…

Finally dropped in a logInfo command to check the .state of the item and the dimmers are returning the % dim as a numeric value, not a on/off status. So now that I do a check to see if .state > 1 all works.

Thanks for all the patience and help.

2 Likes