Sometimes rules don't get executed?

Dear Community!

I have found that sometimes my rules won’t get executed. For example right now, I’m using @rlkoshak method to calculate the time of the day. It worked for weeks now without a problem, but today morning it stopped executing. Now the time of day should be evening, but it stuck at Morning. However this was not the first time when I experienced this.

For example I have a rule which turns the LEDs on at night when motion is detected.

rule "Night Light in Kitchen and Living Room"
	Item Zone4 changed
	logInfo("wifiled.rules", "Night Light rule started!")
	if(Zone4.state.toString == "ON" && (vTimeOfDay.state == "BED" || vTimeOfDay.state == "NIGHT") && CurrentActivityHub.state.toString == "PowerOff" && (Sonoff.state.toString == "OFF" || Sonoff.state.toString == "UNDEF" || Sonoff.state.toString == "NULL")) {
		// LED on -- Reset timer or start it, if it was turned on before...
		if(gKitchenLedLight.state.toString == "ON") {
			logInfo("wifiled.rules", "Reset timer")

		// Turn everything on
		else {
			logInfo("wifiled.rules", "Turning on the LEDs...")

As you can see I have a logInfo at the beginning which should get executed every time this rule fires. However I logged this at one night when it stopped working… I was able to see in the log that my Item Zone4 changed from OFF to ON, but the rule don’t even wrote that logInfo into the logs…

Anyone experienced something similar? Which might be the cause of this? I can’t narrow down the problem, because it happens very randomly and after a little time it starts working again (without restart or anything)

It could be related to Why have my Rules stopped running? Why Thread::sleep is a bad idea.

The time of day may be a problem with the Astro binding. I’ve been helping one other person with an issue where Astro is not rescheduling the sunrize/sunset events every day. What are you triggering the Rule with?

Use karaf console to enable debug debugging level for

The first one should get you a debug line in openhab.log whenever your rule is called, the 2nd will ensure your logInfo(…) lines will result in log lines. Add some more logInfo() or logDebug() lines to output the triggering item (Zone4) and find out how far into the rule it’s working.
If that does not show anything, it’s likely related to the triggering item (Zone4) not changing.

I don’t really use Thread::sleep, only 1-2 times in all my rules and only for 1-2 seconds and these rules are only run a few times a day. Or this can also cause this?

I can’t really understand your question (sorry :frowning: ) but I’ll try to provide some info…
I almost copied your solution. The rule is triggered by astro events, just seen in your solution. Then the calculated time of day is written to a String item

Any sendHttp*Request calls or executeCommandLine calls? Do you have any feedback loops that may have been unnoticed until now?

The Rule triggers are defined between the when and then.

Is the Rule ONLY failing to trigger for the Thing channel triggers or cron Time triggers too?

Sorry this is what I thought… I’ll log when it fails, because since morning there was no cron trigger (it triggers 1min after midnight, 6am, and 23am).

I have only one sendHttpGetRequest (a rule which uses Google API to get postal address from geocode), and the timeout is defined to 20s, which is really big, but I had problems with this rule as well and I left it like that. Should I decrease this? (That rule is working right now…)

As long as that Rule never gets executed faster than every 20 seconds it should be OK.

This is triggered by multiple Location (more phones), and the iCloud binding refreshes periodically, so I think it might be sometimes triggered within 20 secs… what happens if it is triggered multiple times in 20 sec?

See my link posted above about Why have my Rules Stopped running?

Thanks I’ll read it carefully. Maybe if you have a little time I wanted to ask you something.
Also in this rule (where is a sendHttpGetRequest) sometimes I get a ‘null’ response. I wanted to deal with this, so I compared the the output with “null”. However it seems that doesn’t really matters… I don’t really see that an old location is sent to the item with a ! in the beginning.

    if(formattedAddress !== "null") {
      postUpdate(triggeringiPhoneName, formattedAddress)
    else {
      val locationItem = gPhoneLocationString.members.findFirst[i | == triggeringiPhoneName]
      val String oldFormatAddress = "! " + locationItem.state
      postUpdate(triggeringiPhoneName, oldFormatAddress)

What should be wrong? Tried first with ‘!=’ but then I somewhere read that you should compare it with ‘!==’. However I was right, this doesn’t really compare by content, but by memory address (in Java), am I right? Tried comparing it with equals, no success…

Are you certain that the sendHttpGetRequest returns null or does it timeout and throw an exception/error in the log?

I’m sure that it returns null, because before this if clause I was able to see sometimes ‘null’ on my sitemap at the regarding item state.
Some week ago I have bundled the sendHttpGetRequest around with a try and catch, but I wasn’t able to grab a TimeoutException.

val geocodeURL = "" + Latitude + "," + Longitude + "&sensor=true&key=" + GoogleAPIKey
    var String gecodeResponse

    // Trying to get the location
    try {
      gecodeResponse = sendHttpGetRequest(geocodeURL, 20000)
    catch(java.util.concurrent.TimeoutException e) {
      logWarn("LocationToString.rules", "Received timeout exception, skipping item update")

null is not the same thing as NULL. When an Item first comes up or when one attempts to set an Item to an invalid value, that Item’s state becomes NULL.

null is something that only exists in Rules.

TimeoutException may not be the top level Exception that gets thrown .Try just catching Exception. Beyond that add some logging to verify that it is returning null when it does time out.

Thanks for your help! I’ll try to narrow down this problem
This is what it looks like now, I think I should be able to see the json respone when it times out…

    catch(Exception e) {
      logWarn("LocationToString.rules", "Received timeout exception, skipping item update ->" + gecodeResponse)

Just two things to mention:

  • Now somehow the time of day is updated to represent the current state.
2018-09-10 19:06:00.036 [INFO ] [arthome.model.script.day_state.rules] - Calculating time of day...
2018-09-10 19:06:00.192 [INFO ] [arthome.model.script.day_state.rules] - Calculated time of day is EVENING
2018-09-10 19:06:12.206 [WARN ] [rm.AbstractFileTransformationService] - Could not transform 'UNDEF' with the file '' : Target value not found in map for 'UNDEF'

There is an item which is undefined… why?

Also I wanted to mention that when this day_state.rule runs, I sometimes get error like:

2018-09-10 19:13:15.221 [ERROR] [ntime.internal.engine.RuleEngineImpl] - Error during the execution of startup rule 'LocationString': cannot invoke method public abstract org.eclipse.smarthome.core.types.State org.eclipse.smarthome.core.items.Item.getState() on null

Which is the rule we talked about now (handling the postal code conversion). But I only get this kind of error when the day_state rule runs or just after reboot.

Which Item?

If it is only during reboot it is a known bug that occurs when Rules start running before all the Items are loaded. If it is every time this Rule runs I’d ask if that Item exists or if you may have a typo in the name.

I’ll look into which item is undef. The strange thing that this rule works fine (without errors), just throws this error upon startup (so it surely because what you said) and when the day_state rule runs. It seems like when day_state rule is executed this rule also gets executed (don’t know why) and thatks why it can’t call that function because the triggeringItem is different

Ps: if I can remember right, this happens since I have added System started trigger to the LocationString rule.

Because the day_state Rule is posting an update or sending a command to an Item that triggers the Rule.

That certainly points to the aforementioned bug.


I have tried to decrease the timeout in the rule to 2000ms, but it is not enough to get a response from Google. Now I’m trying it with 10000ms. And this rule is triggered by 4 Location item which updates (almost) together, so that means I use min. 4 Rule execution thread just by this rule for seconds…

You can put the sendHttpRequest and everything that follows it into a Timer and that will at least move the problem to a different thread pool.