Cron Triggers for rules not working

Well I’m stumped! I have been running openHAB 2.1 for about 3 months now and in the last couple weeks I have made some rules that use cron triggers. For the life of me I cannot get them to work, nor can I find anything online on in these forums to help me.

I am working with several rules that fire once a minute, some of which also fire when sensor inputs receive updates. The ‘received update’ triggers are working fine.

I have found older posts of people with issues of identical cron triggers on multiple rules not working, so I tried switching each one to a different second. That did not work.
I have found older posts of people with issues having multiple cron triggers in the rule, but I am only using one cron trigger in each rule. I also tried commenting out the other triggers and using only the cron trigger, to no avail.
I have turned on logging for the rule engine and can see it register each and every one of my cron triggers at startup, and every time I save a rules file. Most of the rules will run once, sometimes twice, via the cron trigger after a restart, but not all of them. Yet all of the astro binding cron events run normally (perhaps because the are outside the rule engine?)

Here is the simplest of the rules, copied directly from my rules file. When the setpoint ‘offsets’ are changed, the rule fires, and once when the system is restarted the cron trigger fires, but never again.

rule "Viv Lighting Automation"
when
	//System started or
	//Item light_viv_sunrise_offset changed or
	//Item light_viv_sunset_offset changed or
	Time cron "4 * * * * ? *"

then
	logInfo("MIKE", "DEBUG - viv lighting automation running")
	// updates the commanded state for the lights based on current time,
	// sunrise/sunset time, and sunrise/sunset offset
	
	// guard against multiple concurrent runs
	viv_light_automation_lock.lock()
	try {
	
	// pull in settings from items
	val on_time = new DateTime((astro_sun_rise_start.state as DateTimeType).calendar.timeInMillis + ((light_viv_sunrise_offset.state as DecimalType).longValue * 60 * 1000))
	light_viv_turn_on_time.postUpdate(on_time.toString)
	val off_time = new DateTime((astro_sun_set_start.state as DateTimeType).calendar.timeInMillis + ((light_viv_sunset_offset.state as DecimalType).longValue * 60 * 1000))
	light_viv_turn_off_time.postUpdate(off_time.toString)
	
	// compare current time to sunrise and sunset, including offsets
	if(now.isAfter(off_time)) {					// past sunset turn off time
		light_viv_commanded.postUpdate(OFF)
	} else {
	if(now.isAfter(on_time)) {					// past sunrise turn on time
		light_viv_commanded.postUpdate(ON)
	} else {									// before sunrise turn on time
		light_viv_commanded.postUpdate(OFF)
	}}
	
	} finally { viv_light_automation_lock.unlock() }
end

If you could point me in the right direction, an idea of where to look, anything would be helpful at this point.

Thanks,
Mike

Try using the 2.2 SNAPSHOT and see if that makes a difference. There have been some fixes with cron triggers in the past that have been fixed in the latest.

But from what I see the cron trigger you currently have should be triggering the rule every fourth second of each minute. (e.g. 10:36:04).

Do you see any errors in the logs?

Is the rule truly not triggering or could there be a problem with your lock not being unlocked properly? Do you really need the lock?

I’ll look into migrating to the snapshot tonight when I get home.

I can also find no reason these rules shouldn’t be working.

I see the cron triggers being scheduled without any errors when the rules are loaded.
No log entries about errors, the rules engine is not receiving any triggers (I have debug logging on for the rule engine).

Even if I did not see the debug log entry of the rule, the very first line is a log entry (outside the lock). I am using the locks to avoid spamming the MQTT broker with duplicate messages. This rule in particular should not have much chance of concurrent runs, but some of the sensor related ones do.

EDIT:
Here I just forced a reload of the rules file that contains the rule in my original post and we see these log entries:
(the parsing error is because OH does not recognise the MQTT ‘publish’ keyword, there are not other errors in the designer)

12:49:11.852 [INFO ] [el.core.internal.ModelRepositoryImpl] - Refreshing model 'viv.rules'
12:49:11.879 [WARN ] [el.core.internal.ModelRepositoryImpl] - Configuration model 'viv.rules' is either empty or cannot be parsed correctly!
12:49:11.887 [DEBUG] [e.internal.engine.RuleTriggerManager] - Removed scheduled cron job 'viv.rules#Viv Lighting Automation#4 * * * * ? *'
12:49:27.420 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'viv.rules'
12:49:27.690 [DEBUG] [e.internal.engine.RuleTriggerManager] - Scheduled rule 'Viv Lighting Automation' with cron expression '4 * * * * ? *'

Well I switched over to the 2.2 SNAPSHOT this evening and so far everything is working. I don’t know what was wrong, which bothers me a bit, but I’m glad it’s working.

Thanks for the tip Rich