The name 'NULL' cannot be resolved to an item or type


(Paul Lambert) #1
  • Platform information:
    • RaspberryPi 2
    • Raspbian
    • Java: java version “1.8.0_161”
      Java™ SE Runtime Environment (build 1.8.0_161-b12)
      Java HotSpot™ Client VM (build 25.161-b12, mixed mode)
    • 2.3

I’m getting issues in my rules, which were all working in 2.1. I think there was an openhab upgrade when I did some other upgrades last night after which I started getting issues, I upgraded again today through to 2.3.

I’m getting problems with items not recognised when they clearly are recognised as they were used earlier in the logs - including a debug print of the values. I also get a problem where NULL is not found, which is very bizarre, and had a problem earlier where ON was not found. It sort of looks like different threads are working or not working, but that wouldn’t make much sense.

For examples, consider this log file snippet:

2018-07-08 17:45:23.217 [INFO ] [lipse.smarthome.model.script.weather] - Not running accumulation rule - initialisation not done
2018-07-08 17:45:23.227 [ERROR] [ntime.internal.engine.RuleEngineImpl] - Rule 'Modify Time - adjust minutes': The name 'NULL' cannot be resolved to an item or type; line 40, column 38, length 4
2018-07-08 17:45:31.991 [INFO ] [clipse.smarthome.model.script.boiler] - swInitialisation swInitialisationDone (Type=SwitchItem, State=NULL, Label=Initialisation Done, Category=null, Groups=[InternalFlags])
2018-07-08 17:45:31.992 [INFO ] [lipse.smarthome.model.script.devices] - Not running zone setpoint change rule - initialisation not done
2018-07-08 17:45:31.995 [INFO ] [clipse.smarthome.model.script.boiler] - Not running heating state rule - initialisation not done
2018-07-08 17:45:31.998 [INFO ] [lipse.smarthome.model.script.devices] - Not running zone setpoint change rule - initialisation not done
2018-07-08 17:45:32.000 [INFO ] [marthome.model.script.initialisation] - Turning off switch swHeating (Type=SwitchItem, State=ON, Label=Heating, Category=null,
 Groups=[InternalFlags, Switches, InitSwitchesCycle, PersistGroup])
2018-07-08 17:45:32.006 [INFO ] [marthome.model.script.initialisation] - Turning off switch swDHW (Type=SwitchItem, State=ON, Label=Hot Water Cylinder, Category=null, Groups=[InternalFlags, Switches, InitSwitchesCycle, PersistGroup])
2018-07-08 17:45:32.004 [INFO ] [g.eclipse.smarthome.model.script.fan] - Not running WallMasterTemp changed rule - initialisation not done
2018-07-08 17:45:32.009 [INFO ] [g.eclipse.smarthome.model.script.fan] - Not running WallLoungeTemp changed rule - initialisation not done
2018-07-08 17:45:32.007 [INFO ] [lipse.smarthome.model.script.weather] - Not running weather changed rule - initialisation not done
2018-07-08 17:45:32.034 [INFO ] [g.eclipse.smarthome.model.script.fan] - Not running swHeating changed rule - initialisation not done
2018-07-08 17:45:32.365 [INFO ] [marthome.model.script.initialisation] - Finished initialising relevant items
2018-07-08 17:45:32.395 [INFO ] [ipse.smarthome.model.script.watering] - Program 4 triggering 
2018-07-08 17:45:32.410 [ERROR] [ntime.internal.engine.RuleEngineImpl] - Rule 'DHW mode changed': The name 'swInitialisationDone' cannot be resolved to an item or type; line 454, column 8, length 20
2018-07-08 17:45:32.418 [ERROR] [ntime.internal.engine.RuleEngineImpl] - Rule 'Heating mode changed': The name 'swInitialisationDone' cannot be resolved to an item or type; line 259, column 8, length 20

So we can see it’s saying that swInitialisationDone cannot be found, but earlier in the same log file it printed out the status of that same item. And earlier in the file it claims that NULL cannot be found.

Relevant snippets of rules files:

Line 40 of adjust minutes - the one with the NULL check

rule "Modify Time - adjust minutes"
when
  Item zoneSettingsTimes changed
then
  if ( swInitialisationDone.state == NULL || swInitialisationDone.state != ON ){
    logInfo( 'zones', 'Not running zoneSettings changed time normaliser rule - initialisation not done')
  } else {
    zoneSettingsTimes.members.forEach( time | {
      normaliseMinutes.apply( time )
    })
  }
end

Line 454 of DHW mode changed:

rule "DHW mode changed"
when
  Item stringDHWMode changed
then
  if ( swInitialisationDone.state == NULL || swInitialisationDone.state != ON ){
    logInfo( 'boiler', 'Not running DHW state rule - initialisation not done')
  } else {
  switch stringDHWMode.state {  
      case "ON": {
        logInfo( 'boiler', 'DHW mode changed to ON')

Again the NULL check is the culprit, as it is in the other examples.

I’ve cleared the cache and temp files, any other tips as to what may be going on?


(SiHui) #2

(Harry) #3

If you use a other sd-card, I would save your conf-files (items,rules,sitemaps,etc) and test openHABian


(Paul Lambert) #4

OK, but I think that’s what I’m doing - I’m testing for a state of uninitialized. So I recognize that null and NULL are different, and I think I’m using the right one?

Importantly, that line of code works fine most of the time, then occasionally I get an error. If I had the wrong syntax it would never work, when it just doesn’t work sometimes that looks like a problem in Openhab to me.


(Paul Lambert) #5

Is there a reason openhabian would fix my problem? I’ve been using raspbian with openhab for about 3 years, so not clear to me that this specific problem relates to which distro I’m using.


(Harry) #6

It’s a try with a standard environment.


(Rich Koshak) #7

Do these problems persist after OH has finished starting up or is it only a problem while OH is starting up?

The errors look a whole lot like you have Rules triggering while your Items are being loaded resulting in Items being in a funky state or not yet existing when your Rules are trying to use them.

This has been a problem since 2.1 but it might be the case that something changed the timing for your specific config after the upgrade and have caused you to experience this problem.

If this if the case, then the error is actually doing the same thing that your if statement is doing anyway so functionally nothing should be working differently. It is just filling up your logs with errors which should go away once OH has finished loading.

There is an open issue for this (been open for quite some time) so it’s a known problem awaiting a dev to implement a fix.

However, if the errors persist after OH has finished starting up there might be something else going on.


(Paul Lambert) #8

Thanks, that’s really helpful. Yes, they seem to be mostly during startup, it’s interesting that there’s obviously a thread that’s already processed that same item, but I guess I can see that somehow the loaded items need to be referenced by each thread. I’m triggering the initialisation step from a timer, so I could just extend the timer - I guess it leads on to why Openhab takes so long to load these days - I think that timer is already at 1 minute (it is on my dev system, production isn’t accessible to me at the moment but they normally match), and the timer itself doesn’t fire till the initialisation rules file loads - so more like 90 seconds after starting Openhab. Is that normal on a Pi 2/3?


(Rich Koshak) #9

I don’t run on an RPi so I don’t know what is normal. However I have seen reports of very extended startup times (1 hour reported by one person). In his case it appears to be the Rules parser that is slowing things down. I’m helping him reduce his line count to ease this pain some.

I just ran a reboot of my system to see how long it takes and I too am seeing these errors.

2018-07-09 13:18:36.177 [ERROR] [ntime.internal.engine.RuleEngineImpl] - Rule 'Copy the conditions icon': The name 'triggeringItem' cannot be resolved to an item or type; line 77, column 6, length 14
2018-07-09 13:18:36.178 [ERROR] [ntime.internal.engine.RuleEngineImpl] - Rule 'Update min and max temps': The name 'vWeather_Temp_Min' cannot be resolved to an item or type; line 55, column 5, length 17
2018-07-09 13:18:36.180 [ERROR] [ntime.internal.engine.RuleEngineImpl] - Rule 'Is it cloudy outside?': The name 'logDebug' cannot be resolved to an item or type; line 63, column 2, length 82
2018-07-09 13:18:36.181 [ERROR] [ntime.internal.engine.RuleEngineImpl] - Rule 'Copy the conditions icon': The name 'triggeringItem' cannot be resolved to an item or type; line 77, column 6, length 14
2018-07-09 13:18:36.192 [INFO ] [clipse.smarthome.model.script.lights] - Turning on lights for gLights_ON_DAY
2018-07-09 13:18:38.157 [INFO ] [clipse.smarthome.model.script.lights] - It is DAY and cloudy changed: OFF, adjusting lighting
2018-07-09 13:18:38.159 [ERROR] [ntime.internal.engine.RuleEngineImpl] - Rule 'Turn on lights when it is cloudy': The name 'gLights_ON_WEATHER' cannot be resolved to an item or type; line 41, column 3, length 18
2018-07-09 13:18:38.160 [ERROR] [ntime.internal.engine.RuleEngineImpl] - Rule 'Turn on lights when it is cloudy': The name 'logName' cannot be resolved to an item or type; line 38, column 11, length 7
2018-07-09 13:18:38.217 [ERROR] [ntime.internal.engine.RuleEngineImpl] - Rule 'Update Heating Switch': The name 'vNest_State' cannot be resolved to an item or type; line 52, column 5, length 11
2018-07-09 13:18:38.473 [ERROR] [ntime.internal.engine.RuleEngineImpl] - Rule 'Turn on the fan when necessary': The name 'vNest_Fan_LastChange' cannot be resolved to an item or type; line 8, column 8, length 20

Notice the error on logName. That is a global variable. triggeringItem is an implicit variable.

It is looking like the rules are starting to execute before the .rules file it exists in is done being parsed.

But on my system (VM with 2 CPUs, 8gig RAM) it takes 45 seconds. I don’t know if that is longer or shorter than usual.

The errors occur about 20 seconds after the last file is loaded. One interesting thing I notice is on this boot at least (it isn’t always the same) my .items files started loading first, followed by persistence, then .rules and finally .things.

My Rules started executing about 33 seconds in from the start of the boot, just over 10 seconds after the last “Loading model” line.

I’m not sure what it all means, but it is one data point to go off of.


(Paul Lambert) #10

That is also very useful thank you. If a well powered system is taking 45 seconds, then I probably shouldn’t expect an rPi to boot in less than a minute. I may push my initialisation flag out to 2 or 3 minutes - I don’t have a massive number of rules, I have 11 files and 2000 lines total, but the genuine LOC in there is probably more like 1000, I like verbose commenting and whitespace.

I did look at the ticket regarding things running before the boot sequence is finished https://github.com/eclipse/smarthome/issues/1896, and it looks a bit like these things often do - there’s a specific problem that someone has generalised, and then realised that making a generalised “these dependencies are complete you can now do your thing” is really hard. And the thing that 80% of people might need is therefore undone - what I imagine to be less hard, which is working out when all your item files and rule files have been parsed and are ready.

I did see this ticket which suggests a workaround to delay rule loading: Delay Rule loading after Startup in OH2?, and also says moving from “update received” to “command received” means that a bunch of rules aren’t triggered on startup, of course I need to change many of my “sendUpdate” instructions to “sendCommand”, but that’s not an unreasonable chore.

Anyway, a timer works, I’ve already done the code for it, I just need to pick a longer value for the time.


(Rich Koshak) #11

I just learned, literally seconds ago on another thread, that heavy use of primitives can have a large impact on the amount of time the Rules take to parse. Look through your Rules and see if you have a bunch of .intValue, .doubleValue, et. al. calls to convert Numbers to primitives. Apparently they are hard on the Rules parser.

Something to consider that could be making the initial load longer.


(Paul Lambert) #12

I actually do quite a lot of that, code like:

if( ( DeviceValves.state as DecimalType ).intValue < ( numberHeatingMinimumThresholdOff.state as DecimalType ).intValue )

or

 var int waitRatio = 60 * ( ( DeviceValves.state as DecimalType ).intValue - 
                             ( numberHeatingMinimumThresholdOn.state as DecimalType ).intValue ) / 
                           ( ( numberHeatingAutoRunThreshold.state as DecimalType ).intValue - 
                             ( numberHeatingMinimumThresholdOn.state as DecimalType ).intValue ) 
  var int heatingWaitSeconds = ( numberHeatingWaitMinutes.state as DecimalType ).intValue * (60 - waitRatio)
  if( heatingWaitSeconds < ( numberHeatingWaitBaseMinutes.state as DecimalType ).intValue * 60 ) {
    heatingWaitSeconds = ( numberHeatingWaitBaseMinutes.state as DecimalType ).intValue * 60
  }

I can’t recall why I got in the habit of doing this, I think I had problems with the implicit type conversions at some point in time and started doing it explicitly. It definitely makes the code much more verbose and cumbersome, so it would be tidier if removed.

Would it be likely to a) work correctly, and b) parse faster if I just removed all the conversions and used the state directly?


(Rich Koshak) #13

I can’t say definitely yes to either a or b but I can say if you cast to Number instead of DecimalType you should not run into any problems except in the rate case where you call a method that requires a primitive like the now.plusX and now.minusX methods.

Most of the time you don’t even need to cast to Number.

if( DeviceValves.state < numberHeatingMinimumThresholdOff.state )

Should work.

Similarly

var waitRatio = 60 * ( ( DeviceValves.state as Number) - 
                             ( numberHeatingMinimumThresholdOn.state as Number )) / 
                           ( ( numberHeatingAutoRunThreshold.state as Number ) - 
                             ( numberHeatingMinimumThresholdOn.state as Number ) ) 
  var heatingWaitSeconds = ( numberHeatingWaitMinutes.state as Number) * (60 - waitRatio)
  if( heatingWaitSeconds < ( numberHeatingWaitBaseMinutes.state as Number ) * 60 ) {
    heatingWaitSeconds = ( numberHeatingWaitBaseMinutes.state as Number ) * 60
  }

The results if the calculations will be a Number (technically a BigDecimal object).

Like with the previous case, you probably don’t even need the “as Number”. Over the versions the Rules DSL had become better at determining type.


(Micha Mueller) #14

That sounds interesting.
I also have lots of primitive conversions in my rules.
Will the “xxx.state as Number” or even “xxx.state” also work for non-integer types like PercentType, doubleValue, DateTimeType, DecimalType?


(Vincent Regaud) #15

Yes definitely for the PercentType, doubleValue and DecimalType
No for the DateTimeType as it is not a number


(Micha Mueller) #16

Okay, I will try to clean up my rules, then.


(Paul Lambert) #17

I tried to remove all the cast statements, and generally that doesn’t work - so for example:

if( DeviceValves.state < numberHeatingMinimumThresholdOff.state )  {

Gives a validation error in XCode of “Type Mismatch, cannot convert from State to Number”, however I was successful moving most of my code to use Number instead of int, and with an explicit cast to Number:

if( DeviceValves.state < numberHeatingMinimumThresholdOff.state as Number)  {

This seems to make the rules load faster (at least on my laptop, which is where I’m testing), I’m not home near the raspberrypi for a couple of weeks, I’ll try it then.


(Rich Koshak) #18

I think I see the pattern now.

If one of the operands is explicitly a Number or a primitive then the Rules DSL knows enough to case the state of the Item to a Number. (Really something else is going on but it would take too long to explain, this explanation is close enough). However, when both operands are the State of an Item, it doesn’t have enough information to figure out both support the comparison operators.

So you will have to carry at least one of the states to Number to compare the states of to Items in this way.


(Paul Lambert) #19

Interesting. It is much cleaner using “as Number” than “as DecimalType).intValue”, so my code readability has improved quite a bit from the change, as well as potentially a parse time improvement that I’ll see when I’m back home.