[SOLVED] OH2 rule failing in OH3

I also suffer from that issue, however even when starting the startup rule manually to assign values to those items, I continue to get the error. Strictly looking at the below converted rule, does anything stand out?

triggers:
  - id: "0"
    configuration:
      groupName: gHneed
    type: core.GroupStateChangeTrigger
conditions: []
actions:
  - inputs: {}
    id: script
    configuration:
      type: application/vnd.openhab.dsl.rule
      script: |
        // context: heating_mode-4
        BF_Heating_Pump.sendCommand(gHneed.state)
        GF_Heating_Pump.sendCommand(GF_Heat_Need.state)
        FF_Heating_Pump.sendCommand(FF_Heat_Need.state)
    type: script.ScriptAction

The below error message seems to indicate that the instance that is the target of sendCommand is null, no? Am I interpreting it wrong?

2020-11-29 10:40:43.734 [ERROR] [internal.handler.ScriptActionHandler] - Script execution of rule with UID 'heating_mode-4' failed: An error occurred during the script execution: Could not invoke method: org.openhab.core.model.script.actions.BusEvent.sendCommand(org.openhab.core.items.Item,java.lang.String) on instance: null in heating_mode

I am not sure but my interpretation is that the Item name to receive the command is null

The items exist (I copied my config from 2.5) - also when you set the ground floor or the first floor to ON, the basement floor pump is set as ON as well (because that turns on the gas heater) still there is always 1 error message not more. Additionally I can update them manually, but I need to check if that also updates the relays - stay tuned.

Are those groups defined as switches? I think they need to be for that to function reliably.

The error is coming from the script action. And the rule is triggering so we can assume that gHneed is working properly.

But what state is gHneed? it could be NULL. It could be UNDEF. In either case, you cannot send those as commands to another item. Add logging to see if that’s occurring. Also, add a conditional (but only if) so the rule doesn’t even try to run if Any of those three need Items are NULL or UNDEF.

It’s helpful to know that null errors like that almost always are caused when the rule interpreter cannot convert an Object to a usable type. In this case perhaps it cannot convert NULL to a command.

Let me add here the relevant item definitions:

Switch  BF_Heat_Need    "Basement heat need"            <heating>       (gHneed)
Switch  GF_Heat_Need    "Ground floor heat need"        <heating>       (gHneed)
Switch  FF_Heat_Need    "First floor heat need"         <heating>       (gHneed)
Group:Switch:OR(ON, OFF)        gHneed  "Heat need"     <heating>       (Home)

Switch                  GF_Heating_Pump                 "Groundfloor heating pump"      <faucet>                (GF, gFaucet)                                          ["Switch","Switchable"]                  {autoupdate="false", channel="souliss:t11:77:0-15:onoff"}
Switch                  FF_Heating_Pump                 "First floor heating pump"      <faucet>                (FF, gFaucet)                                          ["Switch","Switchable"]                  {autoupdate="false", channel="souliss:t11:77:0-16:onoff"}
Switch                  BF_Heating_Pump                 "Basement heating pump" <faucet>                        (BF, gFaucet)                                          ["Switch","Switchable"]                  {autoupdate="false", channel="souliss:t11:77:0-17:onoff"}

I have created this rule with your help @rlkoshak a few months ago - this is the one that controls the heating. The logic was simple: whenever one of the 3 floors needs heating, basement also turns on (because the basement switch turns on the heating) and when nothing needs heating, basement also switches off. Here’s the old thread with the old rule: [SOLVED] Control underfloor heating for multiple floors (OH as thermostat)

The startup rule (either run automatically or by hand) should populate the values for the Heat_Need variables which in turn should assign the value to gHneed.

I wonder if this is similar to https://github.com/openhab/openhab-core/issues/1734

All of that sounds fine but the question remains, what state is gHneed in when the rule runs? Let’s find that out (log it out) first and then when backwards from there. when you have an error never assume you know what’s really happening. If you’re assumptions were right the rule would be working in the first place.

1 Like

Does this screenshot help? It shows gHneed state is OFF when I ran the rule (also you can notice in the logs that the startup rule did run, so the xx_Heat_Need values should’ve been propagated).

Screen shots are almost useless. They can’t be searched and are almost impossible to make anything out of on a phone. Copy and paste the logs and use code fences.

You didn’t add a log statement to log out the state of gHneed so the log is also not useful. But I do see a lot of Item doesn’t exist errors. Do those Items actually exist? If so there is likely something else going on. It’s also complaining about an Item names “toString”. That is almost certainly an error somewhere in your code.

Sorry, those entries are from the developer sidebar as I was using that to show that gHneed has indeed got a value assigned (see the =items.gHneed.state value on the top right and the “OFF” below, but the widget expression tester of the developer sidebar logs every character as you type them). I will add more logging to the rule and share that later.

It’s important to know what the rule thinks the state is. So adding the logging is required. When you add the logging, add a statement before each of the lines so we can see which of the three sendCommands it’s failing on.

OK, we’re getting somewhere. This is the rule with the debug statements:

rule "Process heating need"
when
        Member of gHneed changed
then
    logInfo("ghneed.debug", "gHneed state is: {}", gHneed.state)
    logInfo("ghneed.debug", "BF_Heat_need state is: {}", BF_Heat_Need.state)
    logInfo("ghneed.debug", "BF_Heating_Pump state is: {}", BF_Heating_Pump.state)
    logInfo("ghneed.debug", "GF_Heat_need state is: {}", GF_Heat_Need.state)
    logInfo("ghneed.debug", "GF_Heating_Pump state is: {}", GF_Heating_Pump.state)
    logInfo("ghneed.debug", "FF_Heat_need state is: {}", FF_Heat_Need.state)
    logInfo("ghneed.debug", "FF_Heating_Pump state is: {}", FF_Heating_Pump.state)
    BF_Heating_Pump.sendCommand(gHneed.state)
    GF_Heating_Pump.sendCommand(GF_Heat_Need.state)
    FF_Heating_Pump.sendCommand(FF_Heat_Need.state)
end

And this is what I see in the logs:

2020-11-30 22:40:11.047 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'heating_mode.rules'

2020-11-30 22:40:26.813 [INFO ] [enhab.core.model.script.ghneed.debug] - gHneed state is: OFF

2020-11-30 22:40:26.814 [INFO ] [enhab.core.model.script.ghneed.debug] - BF_Heat_need state is: OFF

2020-11-30 22:40:26.815 [INFO ] [enhab.core.model.script.ghneed.debug] - BF_Heating_Pump state is: ON

2020-11-30 22:40:26.816 [INFO ] [enhab.core.model.script.ghneed.debug] - GF_Heat_need state is: OFF

2020-11-30 22:40:26.817 [INFO ] [enhab.core.model.script.ghneed.debug] - GF_Heating_Pump state is: ON

2020-11-30 22:40:26.817 [INFO ] [enhab.core.model.script.ghneed.debug] - FF_Heat_need state is: OFF

2020-11-30 22:40:26.818 [INFO ] [enhab.core.model.script.ghneed.debug] - FF_Heating_Pump state is: ON

2020-11-30 22:40:26.819 [ERROR] [internal.handler.ScriptActionHandler] - Script execution of rule with UID 'heating_mode-4' failed: An error occurred during the script execution: Could not invoke method: org.openhab.core.model.script.actions.BusEvent.sendCommand(org.openhab.core.items.Item,java.lang.Number) on instance: null in heating_mode

It seems the problem happens during the first sendCommand part but the variables are all defined.

No, we don’t necessarily know that because you don’t have any log statements after the first sendCommand statement. BF_Heating_Pump is already OFF so you wouldn’t see it changing as a response to the command.

But we do know that all of these Items have a non-NULL/UNDEF state which is good and eliminates some possibilities.

Looking at the error again it becomes even more odd. Everything is a Switch. So why is it trying to call sendCommand(org.openhab.core.items.Item,java.lang.Number)?

Out of curiosity, what happens when you send the state as a String?

BF_Heating_Pump.sendCommand(gHneed.state.toString)

This seemed to work on the first try, then I saw that M4 is out so I decided to give it a try with that one as well - interesting results:

The sendCommand lines now look like this:

	BF_Heating_Pump.sendCommand(gHneed.state.toString)
	GF_Heating_Pump.sendCommand(GF_Heat_Need.state.toString)
	FF_Heating_Pump.sendCommand(FF_Heat_Need.state.toString)

And here are the logs, first time everything looked fine:

...
2020-12-01 09:08:50.624 [INFO ] [org.openhab.ui.internal.UIService   ] - Started UI on port 8081

2020-12-01 09:08:50.676 [INFO ] [al.discovery.SoulissGatewayDiscovery] - Starting org.openhab.binding.souliss - Version: 3.0.0.202010181638

2020-12-01 09:08:50.677 [INFO ] [al.discovery.SoulissGatewayDiscovery] - Starting Servers
...
2020-12-01 09:10:03.554 [INFO ] [core.model.script.heating_mode.rules] - Executing 'System started' rule for Heating

2020-12-01 09:32:50.477 [INFO ] [enhab.core.model.script.ghneed.debug] - gHneed state is: OFF

2020-12-01 09:32:50.478 [INFO ] [enhab.core.model.script.ghneed.debug] - BF_Heat_need state is: OFF

2020-12-01 09:32:50.479 [INFO ] [enhab.core.model.script.ghneed.debug] - BF_Heating_Pump state is: ON

2020-12-01 09:32:50.480 [INFO ] [enhab.core.model.script.ghneed.debug] - GF_Heat_need state is: OFF

2020-12-01 09:32:50.481 [INFO ] [enhab.core.model.script.ghneed.debug] - GF_Heating_Pump state is: ON

2020-12-01 09:32:50.481 [INFO ] [enhab.core.model.script.ghneed.debug] - FF_Heat_need state is: OFF

2020-12-01 09:32:50.482 [INFO ] [enhab.core.model.script.ghneed.debug] - FF_Heating_Pump state is: ON

2020-12-01 09:32:50.526 [INFO ] [liss.handler.SoulissGatewayJobHealty] - Packet Execution timeout - Removed

2020-12-01 09:32:51.537 [INFO ] [liss.handler.SoulissGatewayJobHealty] - Packet Execution timeout - Removed

Then I decided to disable OH2.5 and replace with OH3 now that “everything works” and faced this with M4:

2020-12-01 09:37:45.545 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'heating_mode.rules'

2020-12-01 09:37:46.469 [INFO ] [el.core.internal.ModelRepositoryImpl] - Validation issues found in configuration model 'heating_mode.rules', using it anyway:

There is no context to infer the closure's argument types from. Consider typing the arguments or put the closures into a typed context.

There is no context to infer the closure's argument types from. Consider typing the arguments or put the closures into a typed context.

There is no context to infer the closure's argument types from. Consider typing the arguments or put the closures into a typed context.

...
2020-12-01 09:37:47.462 [WARN ] [org.apache.felix.fileinstall        ] - Error while starting bundle: file:/openhab/addons/org.openhab.binding.souliss-3.0.0-SNAPSHOT.jar

org.osgi.framework.BundleException: Could not resolve module: org.openhab.binding.souliss [208]

  Unresolved requirement: Import-Package: org.apache.commons.lang; version="[2.6.0,3.0.0)"

	at org.eclipse.osgi.container.Module.start(Module.java:444) ~[org.eclipse.osgi-3.12.100.jar:?]

	at org.eclipse.osgi.internal.framework.EquinoxBundle.start(EquinoxBundle.java:383) ~[org.eclipse.osgi-3.12.100.jar:?]

	at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundle(DirectoryWatcher.java:1260) [bundleFile:3.6.4]

	at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundles(DirectoryWatcher.java:1233) [bundleFile:3.6.4]

	at org.apache.felix.fileinstall.internal.DirectoryWatcher.doProcess(DirectoryWatcher.java:520) [bundleFile:3.6.4]

	at org.apache.felix.fileinstall.internal.DirectoryWatcher.process(DirectoryWatcher.java:365) [bundleFile:3.6.4]

	at org.apache.felix.fileinstall.internal.DirectoryWatcher.run(DirectoryWatcher.java:316) [bundleFile:3.6.4]

...
2020-12-01 09:38:52.729 [INFO ] [enhab.core.model.script.ghneed.debug] - gHneed state is: NULL

2020-12-01 09:38:52.730 [INFO ] [enhab.core.model.script.ghneed.debug] - BF_Heat_need state is: OFF

2020-12-01 09:38:52.731 [INFO ] [enhab.core.model.script.ghneed.debug] - BF_Heating_Pump state is: NULL

2020-12-01 09:38:52.732 [INFO ] [enhab.core.model.script.ghneed.debug] - GF_Heat_need state is: NULL

2020-12-01 09:38:52.732 [INFO ] [enhab.core.model.script.ghneed.debug] - GF_Heating_Pump state is: NULL

2020-12-01 09:38:52.733 [INFO ] [enhab.core.model.script.ghneed.debug] - FF_Heat_need state is: NULL

2020-12-01 09:38:52.734 [INFO ] [enhab.core.model.script.ghneed.debug] - FF_Heating_Pump state is: NULL

2020-12-01 09:38:52.738 [WARN ] [b.core.model.script.actions.BusEvent] - Cannot convert 'NULL' to a command type which item 'BF_Heating_Pump' accepts: [OnOffType, RefreshType].

2020-12-01 09:38:52.740 [WARN ] [b.core.model.script.actions.BusEvent] - Cannot convert 'NULL' to a command type which item 'GF_Heating_Pump' accepts: [OnOffType, RefreshType].

2020-12-01 09:38:52.746 [WARN ] [b.core.model.script.actions.BusEvent] - Cannot convert 'NULL' to a command type which item 'FF_Heating_Pump' accepts: [OnOffType, RefreshType].

2020-12-01 09:38:52.909 [INFO ] [io.openhabcloud.internal.CloudClient] - Connected to the openHAB Cloud service (UUID = <redacted>, base URL = http://localhost:8080)

2020-12-01 09:38:52.964 [INFO ] [enhab.core.model.script.ghneed.debug] - gHneed state is: NULL

2020-12-01 09:38:52.966 [INFO ] [enhab.core.model.script.ghneed.debug] - BF_Heat_need state is: OFF

2020-12-01 09:38:52.966 [INFO ] [enhab.core.model.script.ghneed.debug] - BF_Heating_Pump state is: NULL

2020-12-01 09:38:52.968 [INFO ] [enhab.core.model.script.ghneed.debug] - GF_Heat_need state is: NULL

2020-12-01 09:38:52.969 [INFO ] [enhab.core.model.script.ghneed.debug] - GF_Heating_Pump state is: NULL

2020-12-01 09:38:52.970 [INFO ] [enhab.core.model.script.ghneed.debug] - FF_Heat_need state is: OFF

2020-12-01 09:38:52.970 [INFO ] [enhab.core.model.script.ghneed.debug] - FF_Heating_Pump state is: NULL

2020-12-01 09:38:52.972 [WARN ] [b.core.model.script.actions.BusEvent] - Cannot convert 'NULL' to a command type which item 'BF_Heating_Pump' accepts: [OnOffType, RefreshType].

2020-12-01 09:38:52.973 [WARN ] [b.core.model.script.actions.BusEvent] - Cannot convert 'NULL' to a command type which item 'GF_Heating_Pump' accepts: [OnOffType, RefreshType].

2020-12-01 09:38:53.432 [INFO ] [enhab.core.model.script.ghneed.debug] - gHneed state is: OFF

2020-12-01 09:38:53.434 [INFO ] [enhab.core.model.script.ghneed.debug] - BF_Heat_need state is: OFF

2020-12-01 09:38:53.436 [INFO ] [enhab.core.model.script.ghneed.debug] - BF_Heating_Pump state is: OFF

2020-12-01 09:38:53.437 [INFO ] [enhab.core.model.script.ghneed.debug] - GF_Heat_need state is: OFF

2020-12-01 09:38:53.438 [INFO ] [enhab.core.model.script.ghneed.debug] - GF_Heating_Pump state is: OFF

2020-12-01 09:38:53.439 [INFO ] [enhab.core.model.script.ghneed.debug] - FF_Heat_need state is: OFF

2020-12-01 09:38:53.440 [INFO ] [enhab.core.model.script.ghneed.debug] - FF_Heating_Pump state is: ON

2020-12-01 09:39:02.590 [INFO ] [core.model.script.heating_mode.rules] - Executing 'System started' rule for Heating

Then I decided to roll back to M3 but seems the souliss plugin no longer loads as I got the same error with M3 (souliss controls my relays)

2020-12-01 09:40:12.567 [WARN ] [org.apache.felix.fileinstall        ] - Error while starting bundle: file:/openhab/addons/org.openhab.binding.souliss-3.0.0-SNAPSHOT.jar

org.osgi.framework.BundleException: Could not resolve module: org.openhab.binding.souliss [208]

  Unresolved requirement: Import-Package: org.apache.commons.lang; version="[2.6.0,3.0.0)"

	at org.eclipse.osgi.container.Module.start(Module.java:444) ~[org.eclipse.osgi-3.12.100.jar:?]

	at org.eclipse.osgi.internal.framework.EquinoxBundle.start(EquinoxBundle.java:383) ~[org.eclipse.osgi-3.12.100.jar:?]

	at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundle(DirectoryWatcher.java:1260) [bundleFile:3.6.4]

	at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundles(DirectoryWatcher.java:1233) [bundleFile:3.6.4]

	at org.apache.felix.fileinstall.internal.DirectoryWatcher.doProcess(DirectoryWatcher.java:520) [bundleFile:3.6.4]

	at org.apache.felix.fileinstall.internal.DirectoryWatcher.process(DirectoryWatcher.java:365) [bundleFile:3.6.4]

	at org.apache.felix.fileinstall.internal.DirectoryWatcher.run(DirectoryWatcher.java:316) [bundleFile:3.6.4]
...
2020-12-01 09:41:16.917 [INFO ] [enhab.core.model.script.ghneed.debug] - gHneed state is: NULL

2020-12-01 09:41:16.918 [INFO ] [enhab.core.model.script.ghneed.debug] - BF_Heat_need state is: OFF

2020-12-01 09:41:16.919 [INFO ] [enhab.core.model.script.ghneed.debug] - BF_Heating_Pump state is: NULL

2020-12-01 09:41:16.920 [INFO ] [enhab.core.model.script.ghneed.debug] - GF_Heat_need state is: NULL

2020-12-01 09:41:16.922 [INFO ] [enhab.core.model.script.ghneed.debug] - GF_Heating_Pump state is: NULL

2020-12-01 09:41:16.923 [INFO ] [enhab.core.model.script.ghneed.debug] - FF_Heat_need state is: NULL

2020-12-01 09:41:16.924 [INFO ] [enhab.core.model.script.ghneed.debug] - FF_Heating_Pump state is: NULL

2020-12-01 09:41:16.926 [WARN ] [b.core.model.script.actions.BusEvent] - Cannot convert 'NULL' to a command type which item 'BF_Heating_Pump' accepts: [OnOffType, RefreshType].

2020-12-01 09:41:16.932 [WARN ] [b.core.model.script.actions.BusEvent] - Cannot convert 'NULL' to a command type which item 'GF_Heating_Pump' accepts: [OnOffType, RefreshType].

2020-12-01 09:41:16.938 [WARN ] [b.core.model.script.actions.BusEvent] - Cannot convert 'NULL' to a command type which item 'FF_Heating_Pump' accepts: [OnOffType, RefreshType].

2020-12-01 09:41:17.064 [INFO ] [enhab.core.model.script.ghneed.debug] - gHneed state is: NULL

2020-12-01 09:41:17.065 [INFO ] [enhab.core.model.script.ghneed.debug] - BF_Heat_need state is: OFF

2020-12-01 09:41:17.066 [INFO ] [enhab.core.model.script.ghneed.debug] - BF_Heating_Pump state is: NULL

2020-12-01 09:41:17.067 [INFO ] [enhab.core.model.script.ghneed.debug] - GF_Heat_need state is: NULL

2020-12-01 09:41:17.068 [INFO ] [enhab.core.model.script.ghneed.debug] - GF_Heating_Pump state is: NULL

2020-12-01 09:41:17.069 [INFO ] [enhab.core.model.script.ghneed.debug] - FF_Heat_need state is: OFF

2020-12-01 09:41:17.070 [INFO ] [enhab.core.model.script.ghneed.debug] - FF_Heating_Pump state is: NULL

2020-12-01 09:41:17.071 [WARN ] [b.core.model.script.actions.BusEvent] - Cannot convert 'NULL' to a command type which item 'BF_Heating_Pump' accepts: [OnOffType, RefreshType].

2020-12-01 09:41:17.073 [WARN ] [b.core.model.script.actions.BusEvent] - Cannot convert 'NULL' to a command type which item 'GF_Heating_Pump' accepts: [OnOffType, RefreshType].

2020-12-01 09:41:17.074 [ERROR] [org.openhab.core.items.GenericItem  ] - Tried to set invalid state 0.0 (DecimalType) on item gGShutter of type RollershutterItem, ignoring it

2020-12-01 09:41:17.118 [ERROR] [org.openhab.core.items.GenericItem  ] - Tried to set invalid state 0.0 (DecimalType) on item gDoor of type ContactItem, ignoring it

2020-12-01 09:41:17.123 [ERROR] [org.openhab.core.items.GenericItem  ] - Tried to set invalid state 0.0 (DecimalType) on item gHneed of type SwitchItem, ignoring it

2020-12-01 09:41:17.197 [ERROR] [org.openhab.core.items.GenericItem  ] - Tried to set invalid state 0.0 (DecimalType) on item gMotion of type SwitchItem, ignoring it

2020-12-01 09:41:17.441 [INFO ] [enhab.core.model.script.ghneed.debug] - gHneed state is: NULL

2020-12-01 09:41:17.443 [INFO ] [enhab.core.model.script.ghneed.debug] - BF_Heat_need state is: OFF

2020-12-01 09:41:17.444 [INFO ] [enhab.core.model.script.ghneed.debug] - BF_Heating_Pump state is: OFF

2020-12-01 09:41:17.445 [INFO ] [enhab.core.model.script.ghneed.debug] - GF_Heat_need state is: OFF

2020-12-01 09:41:17.446 [INFO ] [enhab.core.model.script.ghneed.debug] - GF_Heating_Pump state is: OFF

2020-12-01 09:41:17.447 [INFO ] [enhab.core.model.script.ghneed.debug] - FF_Heat_need state is: OFF

2020-12-01 09:41:17.448 [INFO ] [enhab.core.model.script.ghneed.debug] - FF_Heating_Pump state is: ON

2020-12-01 09:41:17.449 [WARN ] [b.core.model.script.actions.BusEvent] - Cannot convert 'NULL' to a command type which item 'BF_Heating_Pump' accepts: [OnOffType, RefreshType].

2020-12-01 09:41:17.479 [ERROR] [org.openhab.core.items.GenericItem  ] - Tried to set invalid state 1.0 (DecimalType) on item gFaucet of type SwitchItem, ignoring it

2020-12-01 09:41:27.329 [INFO ] [core.model.script.heating_mode.rules] - Executing 'System started' rule for Heating

2020-12-01 09:42:27.728 [INFO ] [liss.handler.SoulissGatewayJobHealty] - Packet Execution timeout - Removed

2020-12-01 09:42:32.864 [INFO ] [liss.handler.SoulissGatewayJobHealty] - Packet Execution timeout - Removed

Interestingly enough, the packet execution timeout messages mean that the souliss messages were sent (I see those timeouts everytime I change the state of the relay) but for now I rolled back to 2.5. Got a bit of work to do so most likely I’ll take another look with M4 on the weekend.

M4 has issues with rules text files, you should update to snapshot and test

1 Like

Could you please provide some kind of a source information for this?

See the general M4 Thread, where issues with rules files had been reported and @Kai and myself confirmed that this issue was solved with SNAPSHOTS after M4. I am actually on SNAPSHOT 2039 and my rules files are running fine.

2 Likes

Thanks Hans-Jörg

Just a quick update, it seems to work with the snapshot but watching yesterday’s presentation I’m thinking there may be better ways to get this done in OH3 so I’ll wait for the next milestone (and my winter time off from work) and spend some time to see how I could make this work with OH3 with the new scripts & possibilities. Having persistence by default will allow me to get rid of influxdb & grafana :slight_smile:

Thanks everyone for your help, especially @Bruce_Osborne and @rlkoshak!