Late bloomer - migrating from 2.5 to 3.3

[bdm (Ben)]

Hello all,
I have (mostly) migrated from 2.5 to 3.3, and am trying to get a few things working.
I had been largely text-based for items files and rules, with the items having been added in PaperUI.
I do have a bunch of dummy switches defined in the default.items file that don’t seem to be visible to OH3.3 (for example, switches to keep track of if certain automation are to be enabled)

Also, none of my DSL rules seem to be running.
Using my old method of troubleshooting, I went into one file (lights.rules), and made an insignificant change. The log then shows that the changed file was recognized (…[el.core.internal.ModelRepositoryImpl] - Loading model ‘lights.rules’), however I don’t get the usual second message. (Can’t recall what my logging level was on my old 2.5 system).
If I add an item, I also don’t get a message, but if there is a validation issue (unused variable), then I do get a message.

openhab.log:

2022-10-31 16:24:51.455 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'lights.rules'

2022-10-31 16:35:07.650 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'TOD.rules'

2022-10-31 16:35:39.465 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'locks.rules'

2022-10-31 16:35:40.876 [INFO ] [el.core.internal.ModelRepositoryImpl] - Validation issues found in configuration model 'locks.rules', using it anyway:

The value of the local variable mailBen is not used

2022-10-31 16:39:35.629 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'default.items'

2022-10-31 16:41:12.328 [INFO ] [ng.zwave.internal.protocol.ZWaveNode] - NODE 24: Maximum Awake time period reached, state SUC_ROUTE count 20, messages 2

2022-10-31 16:44:38.357 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'RF433.rules'

my locks.rules rule, of note, sends lots of log messages if locks are unlocked, locked, etc. The validation message seems to imply that the rule was processed, but yet it doesn’t seem to run when I aggressively and repeatedly lock/unlock my doors.

I have 15 different rule files, some of which are relatively complicated/involved. While some could be easily migrated to other formats, several don’t seem as intuitive to do so (scene handlers), and others seem near impossible (bathroom fan humidity rules that vary the targets based on the past average humidity and average humidity of the given floor).

My questions:
Is this a known issue for dummy switches (not connected to any physical device) in items files not working / not being visible in OH3.3? Is there a newer or better way of accomplishing this in OH3?

If I were to move (most) of my items over to OH3 web interface, using the same name (delete from items file first, then create in OH3 to avoid name conflict), would the persistence in influxdb continue uninterrupted?

Is there something I’m missing for my dsl .rules files to run in OH3? Is there a different way of debugging this?

default.items, with some example dummy switches

// snip
Switch   FF_Front_Porch_Accessory_Outlet  "Front Porch Accessory Switch"   <light>               (FF_Entryway)           ["Lighting", "Switchable"]   {channel="zwave:device:a204e4d4:node2:switch_binary"}
Number	 FF_Front_Porch_Accessory_Scene        "Front Porch Accessory Scene"	                   (SceneSwitch)		    		{channel="zwave:device:a204e4d4:node2:scene_number"}

Switch TTS_WeatherAnnounce   "Announce Weather"	       <sun>		(gFakeSwitch)		
Switch Lights_AutoBoysLights   "Automated Lights in Boys Bedroom"	       <sun>	(gFakeSwitch)
Switch Party "Party mode modification of rules" <none> (gFakeSwitch)
Switch ShutItDown "Shut it Down"  <none> (gFakeSwitch)
Switch HallwayAlert "Hallway Alert" <none> (gFakeSwitch)
Switch secReport "Security Report"  <none> (gFakeSwitch)
Switch twinklyTree "Twinkly Christmas Tree" <light> (gFakeSwitch)
Switch masterBedLights "Master Bed Lights" <light> (gFakeSwitch)
Dimmer masterBedLightsBrightness "Master Bed Light Brightness" <light>
String masterBedLightsProgram "Master Bed Lights Program"
String masterBedLightsCustom "Master Bed Lights Custom"
Color masterBedColor "Master Bed Lights Color"
Switch Dummy2 "Second Dummy" <none> (gFakeSwitch)

Log levels:

openhab> log:list
Logger                                             │ Level
───────────────────────────────────────────────────┼──────
ROOT                                               │ WARN
javax.jmdns                                        │ ERROR
javax.mail                                         │ ERROR
openhab.event                                      │ INFO
openhab.event.AddonEvent                           │ ERROR
openhab.event.ChannelDescriptionChangedEvent       │ ERROR
openhab.event.InboxUpdatedEvent                    │ ERROR
openhab.event.ItemAddedEvent                       │ ERROR
openhab.event.ItemChannelLinkAddedEvent            │ ERROR
openhab.event.ItemChannelLinkRemovedEvent          │ ERROR
openhab.event.ItemRemovedEvent                     │ ERROR
openhab.event.ItemStateEvent                       │ ERROR
openhab.event.RuleAddedEvent                       │ INFO
openhab.event.RuleRemovedEvent                     │ INFO
openhab.event.RuleStatusInfoEvent                  │ INFO
openhab.event.StartlevelEvent                      │ ERROR
openhab.event.ThingAddedEvent                      │ INFO
openhab.event.ThingRemovedEvent                    │ INFO
openhab.event.ThingStatusInfoEvent                 │ ERROR
openhab.event.ThingUpdatedEvent                    │ ERROR
org.apache.cxf.jaxrs.sse.SseEventSinkImpl          │ ERROR
org.apache.cxf.phase.PhaseInterceptorChain         │ ERROR
org.apache.karaf.jaas.modules.audit                │ INFO
org.apache.karaf.kar.internal.KarServiceImpl       │ ERROR
org.apache.karaf.shell.ssh.SshUtils                │ ERROR
org.apache.karaf.shell.support                     │ OFF
org.apache.sshd                                    │ WARN
org.eclipse.lsp4j                                  │ OFF
org.jupnp                                          │ ERROR
org.openhab                                        │ INFO
org.openhab.binding.zwave                          │ INFO
org.ops4j.pax.url.mvn.internal.AetherBasedResolver │ ERROR
org.ops4j.pax.web.pax-web-runtime                  │ OFF
su.litvak.chromecast.api.v2.Channel                │ ERROR

Thanks!

[Wolfgang_S]

Logging level INFO for org.openhab should be sufficient for DSL rules.
Due to a test that I did yesterday for an other thread I see:

2022-10-31 17:14:10.781 [INFO ] [org.openhab.core.model.script.Rules ] - Reformation day

Doing:

log:get org.openhab.core.model.script.Rules

up to level

log:get org.openhab

I get: INFO
This is in sync with your log levels

‘Dummy’ switches have to work…
I would expect to see error message in case they are not configured right.
What I do not know is if is valid ( I did not check the docs ).
The easiest what you can do is to go to the karaf console ( as you already did for the log level ) and run

openhab:items list

or to limit the number of returned entries use it together with a pattern like

openhab:items list Ga*

which then will return something like

Gateway_Sensor_LastSeen (Type=DateTimeItem, State=2022-11-01T07:04:24.057192+0100, Label=Last seen, Category=null)
Gateway_Sensor (Type=ContactItem, State=CLOSED, Label=Einfahrt, Category=sensor)
GateDoorBell (Type=SwitchItem, State=OFF, Label=Klingel am Tor, Category=null, Tags=[Point], Groups=[gEINFAHRT])

You can use the web UI to import your text .items files into items that are managed by the web UI.
You need to go to settings in the web UI. Go to items. Clicking on the + symbol you can select to import items from text files.

Check the events.log file for state changes of your items/things.

After a restart of the OH service I would expect to see error messages in case complete set of items from an .items files are missing.

[rlkoshak (Rich Koshak)]

@bdm

I had been largely text-based for items files and rules, with the items having been added in PaperUI.

This needs clarification. There’s no PaperUI in OH 3. Do you mean MainUI or are you referring to PaperUI on your OH 2.5 instance?

@bdm

I do have a bunch of dummy switches defined in the default.items file that don’t seem to be visible to OH3.3 (for example, switches to keep track of if certain automation are to be enabled)

Where are you looking? It’s not clear yet whether these Items were created in MainUI or are still in .items files.

@bdm

however I don’t get the usual second message.

What usual second message? Do you see the rules listed in MainUI? Even if they are loaded from .rules files they will be shown there.

@bdm

I have 15 different rule files, some of which are relatively complicated/involved. While some could be easily migrated to other formats, several don’t seem as intuitive to do so (scene handlers), and others seem near impossible (bathroom fan humidity rules that vary the targets based on the past average humidity and average humidity of the given floor).

I’m not saying that you should migrate if you are happy with what you have now. But there is nothing that you cannot accomplish in .rules files that you cannot accomplish in any of the other Rules Languages and/or by defining your rules in the UI. It would not be impossible to move those more complicated rules should you choose to do so.

@bdm

Is this a known issue for dummy switches (not connected to any physical device) in items files not working / not being visible in OH3.3? Is there a newer or better way of accomplishing this in OH3?

No but it matters where you are looking for these Items to appear. If they do not have semantic tags they won’t appear in the Model view. But they should appear in the Items view.

@bdm

If I were to move (most) of my items over to OH3 web interface, using the same name (delete from items file first, then create in OH3 to avoid name conflict), would the persistence in influxdb continue uninterrupted?

If the names are the same then yes. If you change the names of the Items a new time series will be created.

@bdm

Is there something I’m missing for my dsl .rules files to run in OH3? Is there a different way of debugging this?

Look in MainUI’s Rules view to see if your rules exist. If so add some logging to the rules. Look in your events log. Are your Things and links between Channels and Things working (i.e. are your Items changing as expected)?

You can use the event feed in the Developer Sideboard (alt-shift-d in MainUI) to see all the events occurring in OH, including rule creation and running events.

[bdm (Ben)]

Thanks Wolfgang.
My specific initial dummy switch I had been looking for was Lights_AutoBoysLights - which controls an automatic turning on lights in my kids rooms in the morning (well, it’s expanded to the whole house now). The corn rule runs, checks if it is a weekday and if the switch is enabled, then runs.
When trying to create the rule I can find physical objects such as lights or switches, but cannot find this dummy switch.
Running openhab:items list Lights_Auto*
I get
Lights_AutoBoysLights (Type=SwitchItem, State=ON, Label=Automated Lights in Boys Bedroom, Category=sun, Groups=[gFakeSwitch])

So it looks like the item was recognized…
I plan on importing the items files as you suggest, as that will allow me to modify them within the UI.

I do have the logging set up to info, as you note - it is good to see the commands for how to pull specific log levels, though.

[bdm (Ben)]

Rich, thanks for your reply.
Yes, I created the items in OH 2.x PaperUI a few years ago before migrating from 2.5 to 3 recently.

For not finding the dummy items, I was looking to move my lights on at 6:50AM weekdays from the rule (which isn’t running successfully) to the Schedule option.
I can set up the cron term: 0 55 6 ? * MON-FRI
I then look to add a condition, and see ‘Pick from Model’, and expand all of the details (Our Home, First Floor, Second Floor, and some uncategorized items within it), and can’t find the dummy switch.
…
This being said, as I look through that list carefully and compare it against my items file, it appears it is only displaying the room groups, not the individual lights themselves.
These items were created by the items files, not MainUI.
I do see all of the expected items under the Items tab in MainUI, however. Of note, I do see the dummy switches in here - including “Automated Lights in Boys Bedroom” Lights_AutoBoysLights.
I do NOT see them under the Model tab (yet). Is this required to be able to use them in rules?

For the logs’ second message, my apologies for being vague. I looked through my old logs and it appears I haven’t updated my rules in a long time, so they weren’t contained in them, and backing up logs was not part of my practice.
It was something to the extent to recognizing the rules changed, then implementing them. If there was an error, I would get the error message rather than implementing the rules. If I saw the second message, I knew the rules file didn’t have an obvious error, and should be active to some extent.

In browsing through MainUI, in the Rules section, I see that I have 109 rules, listed by the title in the rules files, so it looks like they were parsed successfully. None of these (that I can find) are working, however. For what it’s worth, they all state ‘IDLE’ on them - but I am not sure if this means that they are not currently triggered, or if they are not active for some reason.

For example, the above-mentioned lights on rule (which also turns on the Christmas tree once that is set up):
from MainUI:

// Triggers:
// - At 06:55, Monday through Friday

// context: lights-10
if (Lights_AutoBoysLights.state == ON) {
    FF_LivingRoom_Dimmer.sendCommand(100)
    F2_BoysBedroom_Dimmer.sendCommand(100)
	  F2_SilasBedroom_Light.sendCommand(ON)
	  gDownCentralLights.sendCommand(ON)
	  
	  logInfo("lights.rules", "Weekday morning, boys bedroom lights and downstairs central lights turned on")
	  twinklyTree.sendCommand(ON)
	  executeCommandLine("python3 PBScript.py 192.168.1.111 sunrise")  // turn the bed lights on to the sunrise pattern (which turns them on, then sets the pattern)
}

Missing from that display in MAiN UI is the when statement:

when
    Time cron "0 55 6 ? * MON-FRI"

Also listed in MainUI, but not running are rules such as my RF 433 parsing:

// Triggers:
// - When mqtt_topic_tasmotaRFBridge_RFResult was updated

// context: RF433-1
logInfo("RF433.rules", "Starting to parse the RF signal")
logInfo("RF433.rules",mqtt_topic_tasmotaRFBridge_RFResult.state.toString)

switch (transform("JSONPATH","$.RfReceived.Data",mqtt_topic_tasmotaRFBridge_RFResult.state.toString)) {
	// Bar light colour
	case "4E23A1" : {
	  logInfo("RF433.rules", "Received data from Triple 1 Left.  Setting bar light colour to the first option")
	  Bar1ColourLight.sendCommand(BarColour1.state)
	  Bar2ColourLight.sendCommand(BarColour1.state)
  }
  case "4E23A4" : {
	  logInfo("RF433.rules", "Received data from Triple 1 Middle.  Setting bar light colour to white.")
	  Bar1WhiteTemp.sendCommand(DefaultBarWhiteTemp.state) 
	  Bar2WhiteTemp.sendCommand(DefaultBarWhiteTemp.state)
	  
  }
  case "4E23A2" : {
	  logInfo("RF433.rules", "Received data from Triple 1 Right.  Toggling bar light colour.")
	  toggleBarColour.sendCommand(ON)
  }

	
  case "1DB481" : {
	  logInfo("RF433.rules", "Received data from Double 1 Left.  Sending signal to toggle driveway gate.")
    DrivewayGate_Command.sendCommand("TOGGLE")
  }	
  case "1DB482" : {
	  logInfo("RF433.rules", "Received data from Double 1 Right.  Sending signal for driveway gate to enter party mode.")
    DrivewayGate_Command.sendCommand("PARTY")
  }	
	
	
	
	
	case "10ECA1" : {
	  logInfo("RF433.rules", "Received data from Little Circle 1.  Toggling guest bathroom fan.")
	  if (FF_GuestBathFanLight.state==OFF) {
	    FF_GuestBathFanLight.sendCommand(ON)
		logInfo("RF433.rules", "Turning guest bathroom fan ON")
	  }
	  else {
	    FF_GuestBathFanLight.sendCommand(OFF)
		logInfo("RF433.rules", "Turning guest bathroom fan OFF")
	  }	  
	  
  }
	case "075D21" : {
	  logInfo("RF433.rules", "Received data from Little Circle 2.  Toggling outdoor z-wave outlet.")
	  if (FF_Front_Porch_Accessory_Outlet.state==OFF) {
	    FF_Front_Porch_Accessory_Outlet.sendCommand(ON)
		twinklyTree.sendCommand(ON)  // turn christmas tree off
		logInfo("RF433.rules", "Turning accessory outlet ON")
	  }
	  else {
	    FF_Front_Porch_Accessory_Outlet.sendCommand(OFF)
		twinklyTree.sendCommand(OFF)  // turn christmas tree off
		logInfo("RF433.rules", "Turning accessory outlet OFF")
	  }
	  
  }
}

it’s when statement is:

when
	Item mqtt_topic_tasmotaRFBridge_RFResult received update

The mqtt thing Tasmota RF Bridge does appear to be running per the Things Tab,with appropriately linked RFState and Result channels.
I can look up that MQTT channel in MQTT explorer, and see the RF signal being correctly passed on from my tasmota bridge in the correct mqtt path as was referenced in the thing channels (result and state)

Probably the simplest (doesn’t require members of groups, RF433 bridges, telegram, scene management, etc) is a rule that if the shower fan was turned on, it turns the bathroom fan on as well, then set a dummy switch (StillShowering) to on.
In MainUI:

// Triggers:
// - When FF_EnsuiteShowerFan was updated

// context: bathroomFans-1
// automatically turn on toilet fan when shower fan turned on.  Also, set the still showering flag to prevent the shower light/fan from being turned off.
  if (FF_EnsuiteShowerFan.state == ON) {
    logInfo("BathroomFans.rules", "Shower fan turned on, also turning on toilet fan")
	FF_EnsuiteToiletFan.sendCommand(ON)
	StillShowering.sendCommand(ON)
  }

The trigger:

when
    Item FF_EnsuiteShowerFan received update

I can turn this switch on, and the rule doesn’t run, with the message not published in the log.

Thanks for the clarification about persistence and names.

I have looked at the event viewer - this looks like it can be quite helpful!
With regards to the shower light fan rule, I can see the event viewer recognize the shower light was turned on (zwave device state changed to on). The rule doesn’t run.
I can turn both the shower fan and the toilet fan on and off via MainUI, so the zwave item side seems to be working OK. I haven’t done any configuration within MainUI for these items at all, and their definitions are in items files as:

Group gFans
Group gMainHouseFans

Switch   FF_EnsuiteShowerFan       "Light"          <fan>              (FF_Ensuite, gLight, gFans, gMainHouseFans, gDownLights, Indoor_Lights)  ["Lighting", "Switchable"]   {channel="zwave:device:a204e4d4:node18:switch_binary"}
Switch   FF_EnsuiteToiletFan       "Fan"            <fan>              (FF_Ensuite, gLight, gFans, gMainHouseFans)                 ["Lighting", "Switchable"]   {channel="zwave:device:a204e4d4:node19:switch_binary"}

Looking in MainUI, I can see the channel switch zwave:device:…node10:switch_binary is linked to Item Fan: Switch: FF_EnsuiteToiletFan, showing direct parent groups of FF_Ensuite, Light, gFans, gMainHouseFans, as I’d expect.

I have a feeling that I am missing something fundamental about the change to OH3 here, and despite seeing that breaking changes for ‘members of’ type rules may affect me, can’t see anything that would cause even the simple shower fan rule to not run (if switch A turns on, then also turn on switch B). Thanks for any direction you may be able to give here!

[rossko57]

@bdm

I then look to add a condition, and see ‘Pick from Model’,

There was no Semantic Model in OH2. It follows that legacy Items carried forward from OH2 will not be included in the Model. They don’t have to be, ever. “Dummy” Items very often are not wanted there, as it is supposedly modelling real devices and their physical locations.

[rlkoshak (Rich Koshak)]

tl;dr: Please please please go through the Getting Started Tutorial. Far to many users of OH 2 struggle because they skip that thinking “I already know how to use OH, I don’t need that.” If you want to use MainUI then yes, yes you do need that.

@bdm

For not finding the dummy items, I was looking to move my lights on at 6:50AM weekdays from the rule (which isn’t running successfully) to the Schedule option.

There may be some confusion here. The “Schedule option” is just a view of your regular old rules. It just shows your time triggered rules that have the “Schedule” tag applied on a calendar. But it’s just a rule like any other. It’s really no different.

@bdm

I then look to add a condition, and see ‘Pick from Model’, and expand all of the details (Our Home, First Floor, Second Floor, and some uncategorized items within it), and can’t find the dummy switch.

Like I said, if your Item doesn’t have any semantic tags, it won’t appear. However, there is usually a check box somewhere to “show non-semantic items”.

That will show all of your Items.

And there is a little trick which I think it still in place. You could choose any random Item from that dialog. And then when you go back to change that selected Item, you’ll get a different dialog that shows all your Items in a flat list.

But the important thing is knowing that the first dialog only shows Items that have semantic tags unless you check the box.

@bdm

This being said, as I look through that list carefully and compare it against my items file, it appears it is only displaying the room groups, not the individual lights themselves.

Sounds like you’ve not set up the semantic model at all beyond creating the Locations.

@bdm

I do see all of the expected items under the Items tab in MainUI, however.

That’s the “ground truth” for Items. If they are there, they exist. Everything else is a filtered view.

@bdm

I do NOT see them under the Model tab (yet). Is this required to be able to use them in rules?

No, the semantic model is not required. I think that if you didn’t have the start of a semantic model (i.e. those Location Group Items) MainUI will show the “flat” list of all your Items without needing to check the box at the bottom.

The getting started tutorial has a great page on the semantic model.

@bdm

For the logs’ second message, my apologies for being vague. I looked through my old logs and it appears I haven’t updated my rules in a long time, so they weren’t contained in them, and backing up logs was not part of my practice.
It was something to the extent to recognizing the rules changed, then implementing them. If there was an error, I would get the error message rather than implementing the rules. If I saw the second message, I knew the rules file didn’t have an obvious error, and should be active to some extent.

It’s been years since I’ve used OH 2 and even more years since I’ve used Rules DSL. But I’m pretty sure OH 3 only tells you it’s loaded the “model” and will only have more if there was an error.

Error reporting in OH 3 is greatly improved over OH 2. If there’s a problem with the rule, it’ll tell you what.

@bdm

For what it’s worth, they all state ‘IDLE’ on them - but I am not sure if this means that they are not currently triggered, or if they are not active for some reason.

It just means they are not actively running. When one gets triggered and is executing it’ll show RUNNING. IDLE means loaded and waiting to be triggered.

@bdm

Missing from that display in MAiN UI is the when statement:

Out of curiosity, is there a “Code” tab and does it show the full rule there? It’ll be different though from what’s in your .rules file. It’ll look something like:

configuration: {}
triggers:
  - id: "1"
    configuration:
      cronExpression: 0 0 0 9 * ? *
    type: timer.GenericCronTrigger
conditions: []
actions:
  - inputs: {}
    id: "3"
    configuration:
      type: application/javascript;version=ECMAScript-2021
      script: >
        var logger = log('Reset Power Estimate');


        logger.info("It's the first day of the electricity billing period, time to reset the running total.");


        items.getItem('HomeEnergyMeter_LastMonthBillEstimate').postUpdate(items.getItem('HomeEnergyMeter_CurrentBillEstimate').state);

        items.getItem('HomeEnergyMeter_ResetMeter').sendCommand('ON');

        items.getItem('HomeEnergyMeter_CurrentBillEstimate').postUpdate(items.getItem('HomeEnergyMeter_Access').state);
    type: script.ScriptAction

@bdm

When mqtt_topic_tasmotaRFBridge_RFResult was updated

Using the developer sidebar’s event stream, do you see this Item updating?

@bdm

I can look up that MQTT channel in MQTT explorer, and see the RF signal being correctly passed on from my tasmota bridge in the correct mqtt path as was referenced in the thing channels (result and state)

If you go to the Thing and look at the Channel, does it show as being linked to the appropriate Item?

There is nothing obvious to explain why the rules are not triggering, or perhaps they are triggering and we just are not seeing them run.

[bdm (Ben)]

Thanks Rich for your detailed reply.
I have been in and out of the getting started tutorials - it had been tough to keep my attention on in when going through the self evident parts. The semantic models has been good reading, though, and I’m paying attention to the comments you’ve had on other posts about the utility of the semantic model for areas we wish the end user to be exposed, and not much else.
I have a bare-bones pages system set up that gives me 80% of what I want for user interface, just with no polish yet.

I’ve done a fair bit further poking around in my rules, using the log and the event stream. It looks like none of the trigger conditions were preserved. This is reflected in what I posted above. The first posting with the commented out //Triggers: … was seen when I click on the rule in the MainUI settings and see the code. There isn’t a ‘code tab’ explicitly labeled in this settings>rules section that I can see, and not one that formats it in the way that you posted. It does display a lock icon as it was provisioned from a .rule file - perhaps that is why there isn’t a code tab?

In my post, in the ‘code box’ below, I have what the .rules file had instead.
It appears that in processing these files, openhab converted the trigger to a comment, which it placed at the top of the displayed code.

Another example:
from battery.rules :

rule "Living Room Sensor Battery Low"
when
    Item Livingroom_BatteryLevel changed
then
    if (Livingroom_BatteryLevel.state < 11 ){
		val StringBuilder message = new StringBuilder("Living Room Sensor - Low Battery - ")
		val StringBuilder messageSubject = new StringBuilder("Living Room Sensor - Low Battery")
		message.append(Livingroom_BatteryLevel.state)
		
		message.append(" percent  Battery type: Two AAA batteries")
        logInfo("battery.rules", message.toString)
		
		val telegramAction = getActions("telegram","telegram:telegramBot:MartSmart_bot")
		telegramAction.sendTelegram(messageSubject.toString)
		telegramAction.sendTelegram(message.toString)
	}
end

And from MainUI Settings > Rules > rule code box/display

// Triggers:
// - When Laundry_BatteryLevel changed

// context: battery-6
if (Laundry_BatteryLevel.state < 11 ){
		val StringBuilder message = new StringBuilder("Laundry Room Sensor - Low Battery - ")
		val StringBuilder messageSubject = new StringBuilder("Laundry Room Sensor - Low Battery")
		message.append(Laundry_BatteryLevel.state)
		
		message.append(" percent  Battery type: CR123A - 3V")
    logInfo("battery.rules", message.toString)
		val telegramAction = getActions("telegram","telegram:telegramBot:MartSmart_bot")
		telegramAction.sendTelegram(messageSubject.toString)
		telegramAction.sendTelegram(message.toString)
	}

Note the change in comment for the trigger condition.
Every example I look at in the rules section of MainUI, the trigger has been commented out.
I found one other post from 2019 mentioning on this as well, with no posted closure.

Interestingly, when I manually run the rules, as long as they don’t depend a members of group clause (lock state handling, light switch scene manager), or a few other isolated examples, they seem to run OK. This includes sending a message out on telegram or mqtt.

Currently, it seems that other than rule triggering, I should have fairly identifiable and fixable problems based on what was suggested to be breaking features in the migration docs.

Any suggestions on where to go next?

[rlkoshak (Rich Koshak)]

@bdm

This is reflected in what I posted above. The first posting with the commented out //Triggers: … was seen when I click on the rule in the MainUI settings and see the code.

No, that’s just how the rule is presented. The comment there is showing you that the triggers are there. In the UI (and internally in memory) the rule gets broken up into parts, 0 to N triggers, 1 to N actions, and 0 to N conditions. Each is stored and maintained separately as part of the rule.

The stuff between the “when” and “then” of your Rule is the 0 to N triggers part. The stuff between the “then” and “end” of the rule is the action. There is no concept of more than one action nor of conditions for rules defined in .rules files.

So when you are looking at your rules loaded from the .rules files in the UI, it makes no sense to show the triggers as part of the action. They are completely separate.

@bdm

It does display a lock icon as it was provisioned from a .rule file - perhaps that is why there isn’t a code tab?

Probably, and it’s probably why it’s displayed the way it is.

So let’s pivot. Go to Developer Tools → API Explorer and query for the rule. That will show you the rule’s JSON which should have a separate triggers section showing the triggers. Here’s the previous rule I posted above in that JSON format.

{
  "status": {
    "status": "IDLE",
    "statusDetail": "NONE"
  },
  "editable": true,
  "triggers": [
    {
      "id": "1",
      "configuration": {
        "cronExpression": "0 0 0 9 * ? *"
      },
      "type": "timer.GenericCronTrigger"
    }
  ],
  "conditions": [],
  "actions": [
    {
      "inputs": {},
      "id": "3",
      "configuration": {
        "type": "application/javascript;version=ECMAScript-2021",
        "script": "var logger = log('Reset Power Estimate');\n\nlogger.info(\"It's the first day of the electricity billing period, time to reset the running total.\");\n\nitems.getItem('HomeEnergyMeter_LastMonthBillEstimate').postUpdate(items.getItem('HomeEnergyMeter_CurrentBillEstimate').state);\nitems.getItem('HomeEnergyMeter_ResetMeter').sendCommand('ON');\nitems.getItem('HomeEnergyMeter_CurrentBillEstimate').postUpdate(items.getItem('HomeEnergyMeter_Access').state);\n"
      },
      "type": "script.ScriptAction"
    }
  ],
  "configuration": {},
  "configDescriptions": [],
  "uid": "reset_power",
  "name": "Reset Power Meter",
  "tags": [
    "Schedule",
    "Energy"
  ],
  "visibility": "VISIBLE",
  "description": "Resets the power meter when the billing period ends"
}

@bdm

It appears that in processing these files, openhab converted the trigger to a comment, which it placed at the top of the displayed code.

No, that’s just a side effect of the UI. The UI is, understandably enough, designed to present UI rules. The internal structure of the rule is also split up (see JSON above). So showing the triggers as a comment is an attempt to bridge between this broken up representation and the original .rules file representation.

But if there is something wrong with the triggers, we should see that in the JSON returned from the API. Look in the “triggers” section.

In short, the way the triggers are shown as commented out is a red herring. Our problem here is something else.

[bdm (Ben)]

Thanks Rich.
As it seems like the simplest rule, I pulled up the rule that “if the shower light/fan is turned on, then also turn on the toilet fan”. These z-wave switches appear to be correctly working, and are controllable from OH3 pages setup.

Using API-explorer, the rule looks like:

{
  "status": {
    "status": "IDLE",
    "statusDetail": "NONE"
  },
  "editable": false,
  "triggers": [
    {
      "id": "0",
      "configuration": {
        "itemName": "FF_EnsuiteShowerFan"
      },
      "type": "core.ItemStateUpdateTrigger"
    }
  ],
  "conditions": [],
  "actions": [
    {
      "inputs": {},
      "id": "script",
      "configuration": {
        "type": "application/vnd.openhab.dsl.rule",
        "script": "// context: bathroomFans-1\n// automatically turn on toilet fan when shower fan turned on.  Also, set the still showering flag to prevent the shower light/fan from being turned off.\n  if (FF_EnsuiteShowerFan.state == ON) {\n    logInfo(\"BathroomFans.rules\", \"Shower fan turned on, also turning on toilet fan.\")\n\tFF_EnsuiteToiletFan.sendCommand(ON)\n\tStillShowering.sendCommand(ON)\n  }\n"
      },
      "type": "script.ScriptAction"
    }
  ],
  "configuration": {},
  "configDescriptions": [],
  "uid": "bathroomFans-1",
  "name": "Ensuite Shower Fan On",
  "tags": [],
  "visibility": "VISIBLE"
}

and Response headers:

 content-type: application/json 
 date: Thu,03 Nov 2022 17:02:59 GMT 
 server: Jetty(9.4.46.v20220331) 
 transfer-encoding: chunked

Streaming events while turning the FF_EnsuiteShowerFan on:

* openhab/items/FF_EnsuiteShowerFan/state

ItemStateEvent

{"type":"OnOff","value":"ON"}

* openhab/items/FF_EnsuiteShowerFan/state

ItemStateEvent

{"type":"OnOff","value":"ON"}

* openhab/items/FF_EnsuiteShowerFan/statechanged

ItemStateChangedEvent

{"type":"OnOff","value":"ON","oldType":"OnOff","oldValue":"OFF"}

* openhab/items/FF_EnsuiteShowerFan/state

ItemStateEvent

{"type":"OnOff","value":"ON"}

* openhab/items/FF_EnsuiteShowerFan/statepredicted

ItemStatePredictedEvent

{"predictedType":"OnOff","predictedValue":"ON","isConfirmation":false}

* openhab/items/FF_EnsuiteShowerFan/command

ItemCommandEvent

{"type":"OnOff","value":"ON"}

And the log did not have any relevant entries, despite the loginfo line in my rule. My current logging levels, per the API explorer (nice to see it is available here as well):

{
  "loggers": [
    {
      "loggerName": "ROOT",
      "level": "WARN"
    },
    {
      "loggerName": "javax.jmdns",
      "level": "ERROR"
    },
    {
      "loggerName": "javax.mail",
      "level": "ERROR"
    },
    {
      "loggerName": "openhab.event",
      "level": "INFO"
    },
    {
      "loggerName": "openhab.event.AddonEvent",
      "level": "ERROR"
    },
    {
      "loggerName": "openhab.event.ChannelDescriptionChangedEvent",
      "level": "ERROR"
    },
    {
      "loggerName": "openhab.event.InboxUpdatedEvent",
      "level": "ERROR"
    },
    {
      "loggerName": "openhab.event.ItemAddedEvent",
      "level": "ERROR"
    },
    {
      "loggerName": "openhab.event.ItemChannelLinkAddedEvent",
      "level": "ERROR"
    },
    {
      "loggerName": "openhab.event.ItemChannelLinkRemovedEvent",
      "level": "ERROR"
    },
    {
      "loggerName": "openhab.event.ItemRemovedEvent",
      "level": "ERROR"
    },
    {
      "loggerName": "openhab.event.ItemStateEvent",
      "level": "ERROR"
    },
    {
      "loggerName": "openhab.event.RuleAddedEvent",
      "level": "INFO"
    },
    {
      "loggerName": "openhab.event.RuleRemovedEvent",
      "level": "INFO"
    },
    {
      "loggerName": "openhab.event.RuleStatusInfoEvent",
      "level": "INFO"
    },
    {
      "loggerName": "openhab.event.StartlevelEvent",
      "level": "ERROR"
    },
    {
      "loggerName": "openhab.event.ThingAddedEvent",
      "level": "INFO"
    },
    {
      "loggerName": "openhab.event.ThingRemovedEvent",
      "level": "INFO"
    },
    {
      "loggerName": "openhab.event.ThingStatusInfoEvent",
      "level": "ERROR"
    },
    {
      "loggerName": "openhab.event.ThingUpdatedEvent",
      "level": "ERROR"
    },
    {
      "loggerName": "org.apache.cxf.jaxrs.sse.SseEventSinkImpl",
      "level": "ERROR"
    },
    {
      "loggerName": "org.apache.cxf.phase.PhaseInterceptorChain",
      "level": "ERROR"
    },
    {
      "loggerName": "org.apache.karaf.jaas.modules.audit",
      "level": "INFO"
    },
    {
      "loggerName": "org.apache.karaf.kar.internal.KarServiceImpl",
      "level": "ERROR"
    },
    {
      "loggerName": "org.apache.karaf.shell.ssh.SshUtils",
      "level": "ERROR"
    },
    {
      "loggerName": "org.apache.karaf.shell.support",
      "level": "OFF"
    },
    {
      "loggerName": "org.apache.sshd",
      "level": "WARN"
    },
    {
      "loggerName": "org.eclipse.lsp4j",
      "level": "OFF"
    },
    {
      "loggerName": "org.jupnp",
      "level": "ERROR"
    },
    {
      "loggerName": "org.openhab",
      "level": "INFO"
    },
    {
      "loggerName": "org.openhab.binding.zwave",
      "level": "INFO"
    },
    {
      "loggerName": "org.ops4j.pax.url.mvn.internal.AetherBasedResolver",
      "level": "ERROR"
    },
    {
      "loggerName": "org.ops4j.pax.web.pax-web-runtime",
      "level": "OFF"
    },
    {
      "loggerName": "su.litvak.chromecast.api.v2.Channel",
      "level": "ERROR"
    }
  ]
}

I believe that given RuleStatusInfoEvent is at level:Info, that my rule script ‘logInfo’ command should work:
logInfo(“BathroomFans.rules”, “Shower fan turned on, also turning on toilet fan”)

Thanks for your help in this, and I appreciate your patience with me. I have been doing a lot of reading around this through both the forums and general googling, but it is hard to find the thing I’m not able to name…

[rlkoshak (Rich Koshak)]

@bdm

  "triggers": [
    {
      "id": "0",
      "configuration": {
        "itemName": "FF_EnsuiteShowerFan"
      },
      "type": "core.ItemStateUpdateTrigger"
    }
  ],

OK, that proves that the trigger is there. It will trigger when FF_EnsuiteShowerFan receives an update.

It’s status indicates it’s not disabled.

The event stream shows the the Item being updated.

@bdm

And the log did not have any relevant entries, despite the loginfo line in my rule.

Add a log statement outside the if statement so we can rule out the possibility that the rule is triggering but the if condition isn’t working.

@bdm

And the log did not have any relevant entries, despite the loginfo line in my rule. My current logging levels, per the API explorer (nice to see it is available here as well):

Hmmmm, I don’t see a logger for org.openhab.automation.script. Using the karaf console or by editing userdata/openhab/etc/log4j2.xml and adding a logger at level INFO for that namespace. Because you don’t have a logger defined, it inherits from org.openhab which is set to WARN so none of your INFO level logs will show up.

[bdm (Ben)]

Hi Rich,
I have updated the rule to:

rule "Ensuite Shower Fan On"
when
    Item FF_EnsuiteShowerFan received update
then
  logInfo("BathroomFans.rules", "EnsuiteShowerFan rule triggered")
// automatically turn on toilet fan when shower fan turned on.  Also, set the still showering flag to prevent the shower light/fan from being turned off.
  if (FF_EnsuiteShowerFan.state == ON) {
    logInfo("BathroomFans.rules", "Shower fan turned on, also turning on toilet fan.")
	FF_EnsuiteToiletFan.sendCommand(ON)
	StillShowering.sendCommand(ON)
  }
end

rule per API explorer:

{
  "status": {
    "status": "IDLE",
    "statusDetail": "NONE"
  },
  "editable": false,
  "triggers": [
    {
      "id": "0",
      "configuration": {
        "itemName": "FF_EnsuiteShowerFan"
      },
      "type": "core.ItemStateUpdateTrigger"
    }
  ],
  "conditions": [],
  "actions": [
    {
      "inputs": {},
      "id": "script",
      "configuration": {
        "type": "application/vnd.openhab.dsl.rule",
        "script": "// context: bathroomFans-1\nlogInfo(\"BathroomFans.rules\", \"EnsuiteShowerFan rule triggered\")\n// automatically turn on toilet fan when shower fan turned on.  Also, set the still showering flag to prevent the shower light/fan from being turned off.\nif (FF_EnsuiteShowerFan.state == ON) {\n  logInfo(\"BathroomFans.rules\", \"Shower fan turned on, also turning on toilet fan.\")\n\tFF_EnsuiteToiletFan.sendCommand(ON)\n\tStillShowering.sendCommand(ON)\n}\n"
      },
      "type": "script.ScriptAction"
    }
  ],
  "configuration": {},
  "configDescriptions": [],
  "uid": "bathroomFans-1",
  "name": "Ensuite Shower Fan On",
  "tags": [],
  "visibility": "VISIBLE"
}

I have manually added the logger, and still am not seeing any action.
logging levels:

org.openhab.automation.script                      │ DEBUG
org.openhab.binding.zwave                          │ INFO
org.openhab.core.model.script.Rules                │ DEBUG

I then set z-wave logging to DEBUG briefly and toggled the shower fan. The rule never triggered, and I see lots of z-wave node 18 (shower fan) activity. Of note, there is no node 19 (toilet fan) activity. The rule was never triggered.

Event monitor:

openhab/items/FF_EnsuiteShowerFan/state
ItemStateEvent
{"type":"OnOff","value":"ON"}
openhab/items/FF_EnsuiteShowerFan/state
ItemStateEvent
{"type":"OnOff","value":"ON"}

openhab/items/FF_EnsuiteShowerFan/statechanged
ItemStateChangedEvent
{"type":"OnOff","value":"ON","oldType":"OnOff","oldValue":"OFF"}
openhab/items/FF_EnsuiteShowerFan/state
ItemStateEvent
{"type":"OnOff","value":"ON"}
openhab/items/FF_EnsuiteShowerFan/statepredicted
ItemStatePredictedEvent
{"predictedType":"OnOff","predictedValue":"ON","isConfirmation":false}
openhab/items/FF_EnsuiteShowerFan/command
ItemCommandEvent
{"type":"OnOff","value":"ON"}

Log (tl:dr - not helpful. I filtered out the z-wave activity for other unrelated nodes, but left everything else which doesn’t seem to contribute much.)

2022-11-03 11:31:31.725 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 18: Command received zwave:device:a204e4d4:node18:switch_binary --> ON [OnOffType]

2022-11-03 11:31:31.728 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 18: Creating new message for application command SWITCH_BINARY_SET

2022-11-03 11:31:31.730 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 18: SECURITY NOT required on COMMAND_CLASS_SWITCH_BINARY

2022-11-03 11:31:31.732 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 18: Command Class COMMAND_CLASS_SWITCH_BINARY is NOT required to be secured

2022-11-03 11:31:31.734 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 18: Adding to device queue

2022-11-03 11:31:31.736 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 18: Added 1260 to queue - size 33

2022-11-03 11:31:31.739 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2022-11-03 11:31:31.741 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 18: Polling initialised at 86400 seconds - start in 1500 milliseconds.

2022-11-03 11:31:33.241 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 18: Polling...

2022-11-03 11:31:33.243 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 18: Polling zwave:device:a204e4d4:node18:switch_binary

2022-11-03 11:31:33.244 [DEBUG] [converter.ZWaveBinarySwitchConverter] - NODE 18: Generating poll message for COMMAND_CLASS_SWITCH_BINARY, endpoint 0

2022-11-03 11:31:33.245 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 18: Creating new message for application command SWITCH_BINARY_GET

2022-11-03 11:31:33.246 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 18: SECURITY NOT required on COMMAND_CLASS_SWITCH_BINARY

2022-11-03 11:31:33.247 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 18: Command Class COMMAND_CLASS_SWITCH_BINARY is NOT required to be secured

2022-11-03 11:31:33.247 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 18: Polling skipped for zwave:device:a204e4d4:node18:switch_binary on COMMAND_CLASS_BASIC

2022-11-03 11:31:33.248 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 18: Adding to device queue

2022-11-03 11:31:33.249 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 18: Added 1261 to queue - size 34

2022-11-03 11:31:33.250 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

[snip]

2022-11-03 11:31:35.908 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 18: Sending REQUEST Message = 01 0A 00 13 12 03 25 01 FF 25 D7 DE 

[snip]

2022-11-03 11:31:35.917 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 

2022-11-03 11:31:35.917 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK

2022-11-03 11:31:35.918 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2022-11-03 11:31:35.946 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2022-11-03 11:31:35.948 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 1260: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 215

2022-11-03 11:31:35.950 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

[snip]

2022-11-03 11:31:36.409 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 18: Application Command Request (ALIVE:DONE)

2022-11-03 11:31:36.410 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 18: resetResendCount initComplete=true isDead=false

2022-11-03 11:31:36.410 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 18: Incoming command class COMMAND_CLASS_SWITCH_BINARY, endpoint 0

2022-11-03 11:31:36.411 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 18: SECURITY NOT required on COMMAND_CLASS_SWITCH_BINARY

2022-11-03 11:31:36.412 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 18: Received COMMAND_CLASS_SWITCH_BINARY V1 SWITCH_BINARY_REPORT

2022-11-03 11:31:36.413 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 18: Switch Binary report, value = 255

2022-11-03 11:31:36.414 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 18: Got an event from Z-Wave network: ZWaveCommandClassValueEvent

2022-11-03 11:31:36.415 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 18: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_SWITCH_BINARY, value=255

2022-11-03 11:31:36.415 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 18: Updating channel state zwave:device:a204e4d4:node18:switch_binary to ON [OnOffType]

2022-11-03 11:31:36.417 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 18: Commands processed 1.

2022-11-03 11:31:36.419 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 18: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1d350.

2022-11-03 11:31:36.420 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 18: Command NOT verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1d350.

2022-11-03 11:31:36.421 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1

2022-11-03 11:31:36.421 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1

2022-11-03 11:31:36.422 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2022-11-03 11:31:36.423 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2022-11-03 11:31:45.614 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0B 00 04 00 12 03 25 03 FF C1 00 F9 

2022-11-03 11:31:45.636 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=18, callback=0, payload=00 12 03 25 03 FF C1 00 

2022-11-03 11:31:45.637 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=18, callback=0, payload=00 12 03 25 03 FF C1 00 

2022-11-03 11:31:45.638 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 1262: [WAIT_DATA] priority=Controller, requiresResponse=true, callback: 0

2022-11-03 11:31:45.639 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 18: Application Command Request (ALIVE:DONE)

2022-11-03 11:31:45.640 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 18: resetResendCount initComplete=true isDead=false

2022-11-03 11:31:45.641 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 18: Incoming command class COMMAND_CLASS_SWITCH_BINARY, endpoint 0

2022-11-03 11:31:45.642 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 18: SECURITY NOT required on COMMAND_CLASS_SWITCH_BINARY

2022-11-03 11:31:45.643 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 18: Received COMMAND_CLASS_SWITCH_BINARY V1 SWITCH_BINARY_REPORT

2022-11-03 11:31:45.644 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 18: Switch Binary report, value = 255

2022-11-03 11:31:45.645 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 18: Got an event from Z-Wave network: ZWaveCommandClassValueEvent

2022-11-03 11:31:45.646 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 18: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_SWITCH_BINARY, value=255

2022-11-03 11:31:45.647 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 18: Updating channel state zwave:device:a204e4d4:node18:switch_binary to ON [OnOffType]

2022-11-03 11:31:45.648 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 18: Commands processed 1.

2022-11-03 11:31:45.650 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 18: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@155baa7.

2022-11-03 11:31:45.652 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 18: Command NOT verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@155baa7.

2022-11-03 11:31:45.653 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1

2022-11-03 11:31:45.654 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1

2022-11-03 11:31:45.655 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2022-11-03 11:31:45.656 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2022-11-03 11:31:45.677 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0E 00 04 00 17 06 31 05 01 42 06 D2 AE 00 E9 

2022-11-03 11:31:45.706 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=23, callback=0, payload=00 17 06 31 05 01 42 06 D2 AE 00 

2022-11-03 11:31:45.708 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=23, callback=0, payload=00 17 06 31 05 01 42 06 D2 AE 00 

2022-11-03 11:31:45.709 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 1262: [WAIT_DATA] priority=Controller, requiresResponse=true, callback: 0

Finally, to prove the rule can run, and the log logs, I manually ran the rule from OH3>Settings>Rules [rule] > Run Now.
It outputs the expected output, given that I had the shower fan running at the time:

2022-11-03 11:46:55.477 [INFO ] [core.model.script.BathroomFans.rules] - EnsuiteShowerFan rule triggered
2022-11-03 11:46:55.480 [INFO ] [core.model.script.BathroomFans.rules] - Shower fan turned on, also turning on toilet fan.

And from the MainUI, the FF_EnsuiteShowerFan item:

Any further suggestions on potential logging to enable or settings to check to see why this (and other) items are not triggering rules?

Ben

edit:
Updated logging, and still no log entries to clarify when I toggle the switch.

logging level:

Logger                                             │ Level
───────────────────────────────────────────────────┼──────
ROOT                                               │ WARN
javax.jmdns                                        │ ERROR
javax.mail                                         │ ERROR
openhab.event                                      │ INFO
openhab.event.AddonEvent                           │ INFO
openhab.event.ChannelDescriptionChangedEvent       │ INFO
openhab.event.InboxUpdatedEvent                    │ INFO
openhab.event.ItemAddedEvent                       │ INFO
openhab.event.ItemChannelLinkAddedEvent            │ INFO
openhab.event.ItemChannelLinkRemovedEvent          │ INFO
openhab.event.ItemRemovedEvent                     │ INFO
openhab.event.ItemStateEvent                       │ INFO
openhab.event.RuleAddedEvent                       │ INFO
openhab.event.RuleRemovedEvent                     │ INFO
openhab.event.RuleStatusInfoEvent                  │ INFO
openhab.event.StartlevelEvent                      │ INFO
openhab.event.ThingAddedEvent                      │ INFO
openhab.event.ThingRemovedEvent                    │ INFO
openhab.event.ThingStatusInfoEvent                 │ INFO
openhab.event.ThingUpdatedEvent                    │ INFO
org.apache.cxf.jaxrs.sse.SseEventSinkImpl          │ ERROR
org.apache.cxf.phase.PhaseInterceptorChain         │ ERROR
org.apache.karaf.jaas.modules.audit                │ INFO
org.apache.karaf.kar.internal.KarServiceImpl       │ ERROR
org.apache.karaf.shell.ssh.SshUtils                │ ERROR
org.apache.karaf.shell.support                     │ OFF
org.apache.sshd                                    │ WARN
org.eclipse.lsp4j                                  │ OFF
org.jupnp                                          │ ERROR
org.openhab                                        │ INFO
org.openhab.automation.script                      │ DEBUG
org.openhab.binding.zwave                          │ INFO
org.openhab.core.model.script.Rules                │ DEBUG
org.ops4j.pax.url.mvn.internal.AetherBasedResolver │ ERROR
org.ops4j.pax.web.pax-web-runtime                  │ OFF
su.litvak.chromecast.api.v2.Channel                │ ERROR

Event Monitor:

* openhab/items/FF_EnsuiteShowerFan/state

ItemStateEvent

{"type":"OnOff","value":"OFF"}

* openhab/items/FF_EnsuiteShowerFan/statechanged

ItemStateChangedEvent

{"type":"OnOff","value":"OFF","oldType":"OnOff","oldValue":"ON"}

* openhab/items/FF_EnsuiteShowerFan/state

ItemStateEvent

{"type":"OnOff","value":"OFF"}

* openhab/items/FF_EnsuiteShowerFan/statepredicted

ItemStatePredictedEvent

{"predictedType":"OnOff","predictedValue":"OFF","isConfirmation":false}

* openhab/items/FF_EnsuiteShowerFan/command

ItemCommandEvent

{"type":"OnOff","value":"OFF"}

* openhab/items/FF_EnsuiteShowerFan/state

ItemStateEvent

{"type":"OnOff","value":"ON"}

* openhab/items/FF_EnsuiteShowerFan/statechanged

ItemStateChangedEvent

{"type":"OnOff","value":"ON","oldType":"OnOff","oldValue":"OFF"}

* openhab/items/FF_EnsuiteShowerFan/state

ItemStateEvent

{"type":"OnOff","value":"ON"}

* openhab/items/FF_EnsuiteShowerFan/statepredicted

ItemStatePredictedEvent

{"predictedType":"OnOff","predictedValue":"ON","isConfirmation":false}

* openhab/items/FF_EnsuiteShowerFan/command

ItemCommandEvent

{"type":"OnOff","value":"ON"}

[bdm (Ben)]

I’m not sure if this is relevant:
I tried to create a new rule from the UI, and have been having some difficulty.

Settings>Rules> + icon
chose simple item name/label
choosing item from non-semantic items, found the shower fan

The first time I try this, clicking on the item gets an error page:

Sorry

Requested content not found.

Debug information

* **Url:** /settings/rules/add/module-config/pick-from-model
* **Path:** /settings/rules/add/module-config/pick-from-model
* **Hash:**
* **Params:**
* **Query:**
* **Route:** (.*)

(and nothing in the log to correspond with this)

The second time I try,
I am able to pick the item change, and the action to do.
“When FF_EnsuiteShowerFan changed from OFF to ON
Then Send command ON to FF_EnsuiteToiletFan”
I save the rule, and get a pop-up bottom-left message: “Error while saving rule: bad request”

Log stated:

2022-11-03 13:43:38.150 [WARN ] [utomation.rest.internal.RuleResource] - Creation of the rule is refused: null

I try again, given that it pops me back into the filled rule creation page. The first time it gives me an error as the unique ID is the same as my first attempt. I modify it slightly, and then I get the same “Error while saving rule: bad request” pop-up message.

logs:

2022-11-03 13:46:54.741 [WARN ] [utomation.rest.internal.RuleResource] - Creation of the rule is refused: Cannot add element, because an element with same UID (TestShower01) already exists.

2022-11-03 13:47:02.959 [WARN ] [utomation.rest.internal.RuleResource] - Creation of the rule is refused: null

nothing came up in the Event monitor with these tests.

I’m going to try this:

[SOLVED] OH3 Issue: unable to create rules, scripts, schedules

OK. Now I found a solution by my own. I did the following: (just if somebody gets someday the same issue) Stopped openhab sevice openhab-cli clean-cache I edited /var/lib/openhab/automation_rules.json an removed everything except the {}. Everything I tried during the last days was there, as well al some old rules I made with OH 2.5 and its Next-Gen Rule Engine. Restarted Openhab Voila, it works, now I am able to create rules in OH3 as expected. Seems that this is / was a migration issue in …

[rlkoshak (Rich Koshak)]

@bdm

I tried to create a new rule from the UI.

That was going to be my next suggestion. This rule in fact could be done using just the UI with no code.

The rule exists. It has the right trigger. It can log when you run it manually.

The only real clue we have is this most recent error. It would seem there might be something up with your Items. I’ve never seen that error before.

First restart OH just to make sure there isn’t some weirdness hanging about. Then test again. If that doesn’t work, create a brand new Item to trigger a rule and see if you can trigger a rule with that Item.

[bdm (Ben)]

This was the solution!

I cleared the cache and cleaned out the atomations.json file. My rules now work (or at least to some extent - I will need to sort some migration bugs out I imagine.
Lots of incidental learning.

What I did was:
stop openhab:

sudo systemctl stop openhab.service

then clean the cache and reset ownership to ensure there were no permissions issues:

sudo openhab-cli clean-cache
sudo openhab-cli reset ownership

edited automation_rules.json (in the userdata/jsondb directory - for me on an openhabian system, this was
/var/lib/openhab/jsondb/automation_rules.json
removing all the data, and leaving only

{
}

I then restarted openhab.

sudo systemctl start openhab.service

One of my old lessons from my early days with openhab was that when things didn’t seem to be working as expected, I should clear the cache and reset ownership. I even have scripts to do this. With the myriad of migration changes, I figured the problem was in a setting somewhere, completely forgetting my old lessons.

Thanks Rich for your help, and I expect I may have more for the community as I try re-create my system, but feel I have lots of material to work with for now.

Ben