[SOLVED] Cron in rules not working anymore

[Sascha_Billian]

Hello everybody,

for some reason my cron triggered rules stopped working. I would think that might be connected after updating packages with openhabian-config, but i can’t verify it.

However even if I have the simplest rule:

rule Testrule

when
	Time cron "* 0/1 * * * ?"
then
	logInfo("Test", "Test")
end

i just see the following entries in the logfiles:

2017-12-02 14:24:27.929 [INFO ] [el.core.internal.ModelRepositoryImpl] - Refreshing model ‘test.rules’
2017-12-02 14:24:32.991 [INFO ] [org.quartz.core.QuartzScheduler ] - Scheduler openHAB-job-scheduler_$_NON_CLUSTERED started.

and that’s it.
org.quartz.core is already set to DEBUG

other rules that trigger via an item change work fine.
I’ve read similar topics but couldn’t find my solution there.
The above rule currently is the only active rule in my setup. I’ve disabled all other rules.
I also rebooted my system but this hasn’t changed anything.

What puzzles me is the fact that it was running and now it isn’t anymore.

Can anybody help me where to look further?

• Platform information:
  • Hardware: Raspi3
  • OS: Raspbian 8
  • Java Runtime Environment: 1.8.0_152
  • openHAB version: 2.1 release build

[Sascha_Billian]

Ok, some good news without actually knowing what happened.
After the above mentioned rule still didn’t work, I’ve rebootet the system only with this one rule.

After reboot it was working and now i’m enabling the other rules step by step.
Maybe i’ve had two rules with the same name, but only disabling them didn’t help and hence a reboot did the trick.

[Sascha_Billian]

Hey Folks,

sorry to bother you again. Been away for a week i realized that the rules stopped working again.
I’ve found the following issue: https://github.com/eclipse/smarthome/issues/4130
This exactly describes my error but still there isn’t any solution and it seems that it is anything else than trivial to find out.

So if anybody did find a workaround for this that would really help me a lot.

Br
Sascha

[KevinHab]

I see your rule is wrong syntax.

Your rule must be :

rule “Testrule” => ( name of rule must be in “name_of_rule” )

when
Time cron "* 0/1 * ? * * *"
then
logInfo(“Test”, “Test”)
end

[Sascha_Billian]

Thanks for your response, @KevinHab. I initially thought the same, but even with

rule "testrule"

when
        Time cron "* 0/1 * * * ?"
then
        logInfo("Test", "Test")
end

it is not working.
So currently i am running out of options. Rebooting OpenHab results in the rules working again but suddenly they just keep stopping.
What makes me puzzle is the fact that it used to work and the only thing I did was

• Install lates packages with openhab-config

My Items or things else hasn’t changed since yet.

[Udo_Hartmann]

@KevinHab

rule “Testrule” => ( name of rule must be in “name_of_rule” )

This is not correct. As long as the Name of the rule is only one word, you don’t need the quotes. So

rule Testrule

should be ok just as

rule "Testrule"

[Udo_Hartmann]

Please keep in Mind that this rule will trigger every Second. This will cause an impact when other rules trigger at the same time.

[Sascha_Billian]

I’ve already changed it to run every minute.
This rule was only for testing and to find out why the other rules are not working.
Will there be a problem if two rules fire at the same time?

I have one rule that checks the online state of my Things each 30min. And i’ve got two rules that enable disable certain things at 6:30/7:30/16:30/17:clock1030:
So they definitely will interfere with the other rule.

tbh - that could be the problem.
I will change so that the won’t interfere with each other.

Thanks for this hint - I will get back to you if it works (or not)

[KevinHab]

@Udo_Hartmann

rule “Testrule” => ( name of rule must be in “name_of_rule” )

This is not correct. As long as the Name of the rule is only one word, you don’t need the quotes. So

rule Testrule

should be ok just as

rule “Testrule”

Well, now I know it.
Thanks @Udo_Hartmann.

[imhofa (Andreas Imhof)]

There is not a problem with triggered rules at the same time in general, but for every triggered rule a new task is created. So if you have many rules triggered at the same time your machine will have a performance issue for this moment to create all these tasks. And if you trigger every second…

Andreas

[Sascha_Billian]

OK this also explains why changing the times in a way that they never interfere with each other didn’t have any effect.
I’ve switched on the debugging of quartz
log:set DEBUG org.quartz.core

The last entries i’ve seen were

2017-12-11 23:55:25.409 [DEBUG] [rg.quartz.core.QuartzSchedulerThread] - batch acquisition of 0 triggers
2017-12-11 23:55:54.848 [DEBUG] [rg.quartz.core.QuartzSchedulerThread] - batch acquisition of 0 triggers
2017-12-11 23:56:19.655 [DEBUG] [rg.quartz.core.QuartzSchedulerThread] - batch acquisition of 0 triggers
2017-12-11 23:56:49.306 [DEBUG] [rg.quartz.core.QuartzSchedulerThread] - batch acquisition of 0 triggers
2017-12-11 23:57:13.922 [DEBUG] [rg.quartz.core.QuartzSchedulerThread] - batch acquisition of 0 triggers
2017-12-11 23:57:43.677 [DEBUG] [rg.quartz.core.QuartzSchedulerThread] - batch acquisition of 0 triggers
2017-12-11 23:58:06.768 [DEBUG] [rg.quartz.core.QuartzSchedulerThread] - batch acquisition of 0 triggers
2017-12-11 23:58:36.055 [DEBUG] [rg.quartz.core.QuartzSchedulerThread] - batch acquisition of 0 triggers
2017-12-11 23:59:04.160 [DEBUG] [rg.quartz.core.QuartzSchedulerThread] - batch acquisition of 0 triggers
2017-12-11 23:59:32.945 [DEBUG] [rg.quartz.core.QuartzSchedulerThread] - batch acquisition of 1 triggers
2017-12-12 00:00:00.005 [DEBUG] [org.quartz.core.JobRunShell         ] - Calling execute on job DEFAULT.Devicestate.rules#DeviceState#0 0/30 * * * ?
2017-12-12 00:02:14.472 [WARN ] [l.serialmessage.SendDataMessageClass] - NODE 12: Already processed another send data request for this callback Id, ignoring.

After that no log entries that refer to quartz or my rules. The last entry above is caused by a ZWave device and shouldn’t interfere with the rules. I just copied it in here to show that there really is no other log entry pointing me to the rootcause.

I’ve got six rules, five of them are only active once in the morning (around 6am, the others in the evening around 6pm). They mainly switch only one or two items - nothing more.
So in the case of the error they weren’t triggering.
The only rule that really was active has got the following cron:

rule "DeviceState"
when
	Time cron  "0 0/30 * * * ?"	//every 30 minutes
then

So unfortunately i’m stuck again.
Any help is heavily appreciated.

[Sascha_Billian]

Ok, my testrule was running throughout the whole day without any issues. So it seems that one of my other rules is causing this problem.

That means i’m enabling one rule after another to see which one causes the error.
If i’ve found the faulty one, i think i need some assistance debugging it.

Since the quartz DEBUG doesn’t throw any errors i think the error resides in the rule itself. However it seems to be an error that happens during runtime.
Is there a possibility to enable logging that only applies to the rule stuff? If not, which logger should I modify?

[Udo_Hartmann]

Why not showing the test rule?

[Sascha_Billian]

Hi @Udo_Hartmann
The test rule which is working:

rule "testrule"

	when
		Time cron "0 0/1 * * * ?"
	then
		logInfo("Test", "Test")
	end

I’ve narrowed it down to the following rule being the root cause for my problem:

import java.util.HashMap

val HashMap<String, Object> ThingsMap = newHashMap (
										"zwave:device:86910632:node21" -> Plug_Garden_TerraceRight_Ping, 				//Plug_Garden_TerraceRight
										"zwave:device:86910632:node5"  -> Illumination_Garden_Blind_Ping,				//Illumination_Garden_Blind
										"zwave:device:86910632:node11" -> Illumination_GroundFloor_LivingRoom_Ping,		//illumination_GroundFloor_LivingRoom
										"zwave:device:86910632:node10" -> Plug_Garden_TerraceLeft_Ping,					//Plug_Garden_TerraceLeft
										"zwave:device:86910632:node6"  -> Pump_Basement_Circulation_Ping,				//Pump_Basement_Circulation
										"zwave:device:86910632:node19" -> SmokeDetector_2ndFloor_Entrance_Ping,			//SmokeDetector_2ndFloor_Entrance
										"zwave:device:86910632:node12" -> SmokeDetector_2ndFloor_KidsRoom_Ping,			//SmokeDetector_2ndFloor_KidsRoom
										"zwave:device:86910632:node18" -> SmokeDetector_2ndFloor_SleepingRoom_Ping,		//SmokeDetector_2ndFloor_SleepingRoom
										"zwave:device:86910632:node3"  -> SmokeDetector_GroundFloor_Entrance_Ping,		//SmokeDetector_GroundFloor_Entrance
										"zwave:device:86910632:node2"  -> SmokeDetector_GroundFloor_LivingRoom_Ping,	//SmokeDetector_GroundFloor_LivingRoom
										"zwave:device:86910632:node9"  -> Valve_Garden_Left_Ping,						//Valve_Garden_Left
										"zwave:device:86910632:node4"  -> Valve_Garden_Right_Ping,						//Valve_Garden_Right
										"zwave:device:86910632:node8"  -> Door_GroundFloor_Terrace_Ping	 				//Door_GroundFloor_Terrace
										)

rule "DeviceState"
when
	Time cron  "0 0/30 * * * ?"	//every 30 minutes
then
	
	//enumerate all things and check status
	ThingsMap.forEach[key, value|

		//get status of thing		
		var status = ThingAction.getThingStatusInfo(key.toString)
		//logInfo("Devicestate", (value as GenericItem).toString + status.toString)
		//check if status is online
		if(status.toString == 'ONLINE')
		{
			//only if the previous state reports offline switch on
			if((value as GenericItem).previousState(true) == OFF)
			{
				(value as GenericItem).sendCommand(ON)
				sendMail("---", "OpenHab Thing ONLINE", "The following device changed from OFFLINE to ONLINE:"+ "\n\r" + (value as GenericItem).label.toString + "\n\r" + now.toString)
			}
		}
		else //status is anything else than online
		{
			//only if the previous state reports online switch on
			if((value as GenericItem).previousState(true) == ON)
			{
				(value as GenericItem).sendCommand(OFF)
				sendMail("---", "OpenHab Thing OFFLINE", "The following device changed from ONLINE to OFFLINE:"+ "\n\r" + (value as GenericItem).label.toString + "\n\r" + now.toString)
			}
		}
	]
end

This rule should on send me an email (i’ve removed my e-mail adress in sendMail(…)) when a thing state changed (OFFLINE, ONLINE, …) and in addition change the state of an item that is displayed on the BasicUI.
I am using the Hashmap to link the state of the things to items.

This rule is working in the beginning, but it also seems to cause all the cron triggered rules to stop after a few hours.
I do not think that sendMail is causing this since all of my current ZWave things are running quite stable and i’ve never faced one thing going OFFLINE and thus no email is sent since the state of the thing is not changing.

Any Ideas?
I am really new to XTend, so I could imagine that my code messes something up which I am not aware of.

[Udo_Hartmann]

Hmmm.
Not sure, but should the if clause not be like

if((value as GenericItem).previousState(true).state == OFF)

as previousState would be <timestamp> <state>

I have no idea why this rule should cause cron triggers to stop working.

[KevinHab]

@Sascha_Billian

Hi @Udo_Hartmann

The test rule which is working:

rule “testrule”

when
	Time cron "0 0/1 * * * ?"
then
	logInfo("Test", "Test")
end

I’ve narrowed it down to the following rule being the root cause for my problem:

import java.util.HashMap

val HashMap<String, Object> ThingsMap = newHashMap (
“zwave:device:86910632:node21” -> Plug_Garden_TerraceRight_Ping, //Plug_Garden_TerraceRight
“zwave:device:86910632:node5” -> Illumination_Garden_Blind_Ping, //Illumination_Garden_Blind
“zwave:device:86910632:node11” -> Illumination_GroundFloor_LivingRoom_Ping, //illumination_GroundFloor_LivingRoom
“zwave:device:86910632:node10” -> Plug_Garden_TerraceLeft_Ping, //Plug_Garden_TerraceLeft
“zwave:device:86910632:node6” -> Pump_Basement_Circulation_Ping, //Pump_Basement_Circulation
“zwave:device:86910632:node19” -> SmokeDetector_2ndFloor_Entrance_Ping, //SmokeDetector_2ndFloor_Entrance
“zwave:device:86910632:node12” -> SmokeDetector_2ndFloor_KidsRoom_Ping, //SmokeDetector_2ndFloor_KidsRoom
“zwave:device:86910632:node18” -> SmokeDetector_2ndFloor_SleepingRoom_Ping, //SmokeDetector_2ndFloor_SleepingRoom
“zwave:device:86910632:node3” -> SmokeDetector_GroundFloor_Entrance_Ping, //SmokeDetector_GroundFloor_Entrance
“zwave:device:86910632:node2” -> SmokeDetector_GroundFloor_LivingRoom_Ping, //SmokeDetector_GroundFloor_LivingRoom
“zwave:device:86910632:node9” -> Valve_Garden_Left_Ping, //Valve_Garden_Left
“zwave:device:86910632:node4” -> Valve_Garden_Right_Ping, //Valve_Garden_Right
“zwave:device:86910632:node8” -> Door_GroundFloor_Terrace_Ping //Door_GroundFloor_Terrace
)

rule “DeviceState”
when
Time cron “0 0/30 * * * ?” //every 30 minutes
then

//enumerate all things and check status
ThingsMap.forEach[key, value|

	//get status of thing		
	var status = ThingAction.getThingStatusInfo(key.toString)
	//logInfo("Devicestate", (value as GenericItem).toString + status.toString)
	//check if status is online
	if(status.toString == 'ONLINE')
	{
		//only if the previous state reports offline switch on
		if((value as GenericItem).previousState(true) == OFF)
		{
			(value as GenericItem).sendCommand(ON)
			sendMail("---", "OpenHab Thing ONLINE", "The following device changed from OFFLINE to ONLINE:"+ "\n\r" + (value as GenericItem).label.toString + "\n\r" + now.toString)
		}
	}
	else //status is anything else than online
	{
		//only if the previous state reports online switch on
		if((value as GenericItem).previousState(true) == ON)
		{
			(value as GenericItem).sendCommand(OFF)
			sendMail("---", "OpenHab Thing OFFLINE", "The following device changed from ONLINE to OFFLINE:"+ "\n\r" + (value as GenericItem).label.toString + "\n\r" + now.toString)
		}
	}
]

end

This rule should on send me an email (i’ve removed my e-mail adress in sendMail(…)) when a thing state changed (OFFLINE, ONLINE, …) and in addition change the state of an item that is displayed on the BasicUI.

I am using the Hashmap to link the state of the things to items.

This rule is working in the beginning, but it also seems to cause all the cron triggered rules to stop after a few hours.

I do not think that sendMail is causing this since all of my current ZWave things are running quite stable and i’ve never faced one thing going OFFLINE and thus no email is sent since the state of the thing is not changing.

Any Ideas?

I am really new to XTend, so I could imagine that my code messes something up which I am not aware of.

You want to check your zwave devices status ?
If yes , could you create thing for each zwave device node ?
Ex:

Thing zwave:device:86910632:node21 “Plug_Garden_TerraceRight_Ping” (zwave:serial_zstick:controller) [node_id=21]

Then, you create rule to check status of thing.

rule “Check Thing State”
when
Thing “zwave:device:86910632:node21” changed or
Time cron “0 0 * ? * * *” // check every hour
then
var Status = ThingAction.getThingStatusInfo(“zwave:device:86910632:node21”).getStatus()
logInfo(“Thing”, " zwave:device:86910632:node21 " + Status)
if (Status.toString() == “ONLINE”) {
if((value as GenericItem).previousState(true) == OFF)
{
(value as GenericItem).sendCommand(ON)
sendMail(“—”, “OpenHab Thing ONLINE”, “The following device changed from OFFLINE to ONLINE:”+ “\n\r” + (value as GenericItem).label.toString + “\n\r” + now.toString)
}
}
else {
if((value as GenericItem).previousState(true) == ON)
{
(value as GenericItem).sendCommand(OFF)
sendMail(“—”, “OpenHab Thing OFFLINE”, “The following device changed from ONLINE to OFFLINE:”+ “\n\r” + (value as GenericItem).label.toString + “\n\r” + now.toString)
}
}
end

It work for me. I think it also work for you

[Sascha_Billian]

Thanks for the Info, @KevinHab but then i would need to create a rule for each thing which i try to avoid.
But if there’s no other way i think i would go with this (but you could also created a thing-based trigger for a rule instead, correct?)

I’ve found out that my persistence is not working with the above created items, so previous state always reports null.
So i will let my rule run some time without reading the previous state to check if it messes up anything.

[KevinHab]

Hi @Sascha_Billian ,
I have an idea for you :

Create items :

Switch check_previous_state

rule file :

rule “Check Thing State"
when
Thing “zwave:device:86910632:node21” changed or
Time cron “0 0 * ? * * *” // check every hour
then
var Status = ThingAction.getThingStatusInfo(“zwave:device:86910632:node21”).getStatus()
logInfo(“Thing”, " zwave:device:86910632:node21 " + Status)

// check previous state
if (Status.toString() == “ONLINE”) {
if(check_previous_state == OFF)
{
(value as GenericItem).sendCommand(ON)
sendMail(”—“, “OpenHab Thing ONLINE”, “The following device changed from OFFLINE to ONLINE:”+ “\n\r” + (value as GenericItem).label.toString + “\n\r” + now.toString)
}
}
else {
if(check_previous_state == ON)
{
(value as GenericItem).sendCommand(OFF)
sendMail(”—", “OpenHab Thing OFFLINE”, “The following device changed from ONLINE to OFFLINE:”+ “\n\r” + (value as GenericItem).label.toString + “\n\r” + now.toString)
}
}

// set current state to check_previous_state item
if (Status.toString() == “ONLINE”) {
check_previous_state.postUpdate(ON)
}
else {
check_previous_state.postUpdate(OFF)
}

end

In persistence file config have : ( Ex : mapdb persistence, and set it is default persistence )

check_previous_state : strategy = everyChange, restoreOnStartup
// or * : strategy = everyChange, restoreOnStartup

[Sascha_Billian]

@KevinHab thanks for your help.

I think i’ve found some errors in my rule (plz don’t be mad at me for still trying to get my approach working )

previous state was not working hence i stored the items as strings in my hashmap. Therefore

(value as GenericItem).previousState().state

doesn’t point to the same persistence entry like e.g.

Valve_Garden_Left_Ping.previousState().state

So i switched my Hashmap to

val HashMap<String, GenericItem>

Now i can access directly the items and in addition persistence seems to work.

Without the previousState stuff it worked for days now. So i’m testing it now with my modified HashMap hoping that it will last forever

My complete code is now:

import java.util.HashMap

val HashMap<String, GenericItem> ThingsMap = newHashMap (
										"zwave:device:86910632:node21" -> Plug_Garden_TerraceRight_Ping, 				//Plug_Garden_TerraceRight
										"zwave:device:86910632:node5"  -> Illumination_Garden_Blind_Ping,				//Illumination_Garden_Blind
										"zwave:device:86910632:node11" -> Illumination_GroundFloor_LivingRoom_Ping,		//illumination_GroundFloor_LivingRoom
										"zwave:device:86910632:node10" -> Plug_Garden_TerraceLeft_Ping,					//Plug_Garden_TerraceLeft
										"zwave:device:86910632:node6"  -> Pump_Basement_Circulation_Ping,				//Pump_Basement_Circulation
										"zwave:device:86910632:node19" -> SmokeDetector_2ndFloor_Entrance_Ping,			//SmokeDetector_2ndFloor_Entrance
										"zwave:device:86910632:node12" -> SmokeDetector_2ndFloor_KidsRoom_Ping,			//SmokeDetector_2ndFloor_KidsRoom
										"zwave:device:86910632:node18" -> SmokeDetector_2ndFloor_SleepingRoom_Ping,		//SmokeDetector_2ndFloor_SleepingRoom
										"zwave:device:86910632:node3"  -> SmokeDetector_GroundFloor_Entrance_Ping,		//SmokeDetector_GroundFloor_Entrance
										"zwave:device:86910632:node2"  -> SmokeDetector_GroundFloor_LivingRoom_Ping,	//SmokeDetector_GroundFloor_LivingRoom
										"zwave:device:86910632:node9"  -> Valve_Garden_Left_Ping,						//Valve_Garden_Left
										"zwave:device:86910632:node4"  -> Valve_Garden_Right_Ping, 						//Valve_Garden_Right
										"zwave:device:86910632:node8"  -> Door_GroundFloor_Terrace_Ping	 				//Door_GroundFloor_Terrace
										)
										


rule "DeviceState"
when
	Time cron  "0 0/30 * * * ?"	//every 30 minutes
then
	
	//enumerate all things and check status
	ThingsMap.forEach[key, value|

		//get status of thing		
		var status = ThingAction.getThingStatusInfo(key.toString)
		//logInfo("DeviceState", value.toString + "Previous State: " + value.previousState().state + "Thing State:" + status.toString())
		
		//check if status is online
		if(status.toString == 'ONLINE')
		{
			logInfo("Devicestate", "Current state of " + key + ": ONLINE")
			
			//only if the previous state reports offline switch on
			if(value.previousState().state == OFF)
			{
				value.sendCommand(ON)
				sendMail("---", "OpenHab Thing ONLINE", "The following device changed from OFFLINE to ONLINE:"+ "\n\r" + value.label.toString + "\n\r" + now.toString)
			}
		}
		else //status is anything else than online
		{
			logInfo("Devicestate", "Current state of " + key + ": OFFLINE")
			//only if the previous state reports online switch off
			if(value.previousState().state == ON)
			{
				value.sendCommand(OFF)
				sendMail("---", "OpenHab Thing OFFLINE", "The following device changed from ONLINE to OFFLINE:"+ "\n\r" + value.label.toString + "\n\r" + now.toString)
			}
		}
	]
end

So if it is working - i’m really happy.
If not, I will try to get back to your approach.

[Sascha_Billian]

So finally my rule seems to be working without any issues.
However i cannot really tell why it randomly crashed the cron jobs - but it is working now.

Thanks to all of you, especially @KevinHab for taking the time and writing alternative solutions!