Rules not firing for astro events

will_stewart1a · July 27, 2018, 12:55am

OS: Ubuntu 16:04
OH version: 2.3.0

Having read the prior troubles people were having and their fixes, I’m perplexed that I cannot use astro to fire rules successfully.

I am trying to turn lights on at sunset or civilDusk (and off again in the morning).

I set up a geolocation in PaperUI.

The various event times are being calculated;

2018-07-25 00:00:30.013 [INFO ] [thome.binding.astro.internal.job.Job] - Scheduled Astro event-jobs for thing astro:moon:local
2018-07-25 00:00:30.016 [INFO ] [thome.binding.astro.internal.job.Job] - Scheduled Astro event-jobs for thing astro:sun:local

I am receiving properly scheduled events, such as the following;

2018-07-26 20:27:00.000 [vent.ChannelTriggeredEvent] - astro:sun:local:daylight#event triggered END
2018-07-26 20:27:00.001 [vent.ChannelTriggeredEvent] - astro:sun:local:set#event triggered START
2018-07-26 20:27:45.989 [vent.ItemStateChangedEvent] - ntp_ntp_local_dateTime changed from ...
2018-07-26 20:30:00.000 [vent.ChannelTriggeredEvent] - astro:sun:local:civilDusk#event triggered START
2018-07-26 20:30:00.001 [vent.ChannelTriggeredEvent] - astro:sun:local:set#event triggered END

I now have two versions of the rule set up, in case one is incorrect;

rule "Sheep  Light on at Sunset"
when
    Channel 'astro:sun:home:civilDusk#event' triggered START or
    Channel 'astro:sun:home:set#event' triggered START 
then
        logInfo("openhab", "Civil Dusk or sunset triggers Sheep Light to come on")
        BackPorchLight.sendCommand(ON)

end

and

rule "Sheep Outside Light on at Sunset"
when
    Channel "astro:sun:home:civilDusk#event" triggered START or
    Channel "astro:sun:home:set#event" triggered START 
then
    BackPorchLight.sendCommand(ON)
    logInfo("openhab", "Civil Dusk triggers Sheep Outside Light to come on")
end

However, nothing shows up in the log when the rules are supposed to be firing, nor does the light come on;

2018-07-26 20:26:53.349 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 6: Transaction not completed: node address inconsistent.  lastSent=6, incoming=255
2018-07-26 20:28:52.239 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Polling...

and

2018-07-26 20:29:33.799 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 2: Transaction not completed: node address inconsistent.  lastSent=2, incoming=255
2018-07-26 20:31:53.285 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 04 03 80 03 64 12

I note that there is an odd problem message in the code editor;

“The type SheepOutsideLightOnAtSunsetRules is already defined in SheepOutsideLightOnAtSunset.rules.”

rlkoshak · July 27, 2018, 1:30am

The triggers look ok to me. Here is one of my working triggers.

Channel 'astro:sun:home:rise#event'    triggered START

Make sure your Thing is defined and you have no typo in the name in the rule.

The error I think it’s caused by having more than one rule with the same name. Make sure the stuff in quotes after rule is unique.

Udo_Hartmann · July 27, 2018, 3:17am

According to your log, your trigger channel should be

astro:sun:local:set#event

and not

astro:sun:home:set#event

will_stewart1a · July 27, 2018, 1:23pm

Thanks Udo, good catch.

I have been trying lots of different variations, and saw where some people got it to work by using :home:, so I’d thought I’d try that too. I reverted back to :local: last night, though there still was no success at dusk or at sunrise this morning.

Here’s an image of my geoloc info in PaperUI (this location within 10 miles of the actual residence).

will_stewart1a · July 27, 2018, 1:35pm

Thanks Rich, the Thing is defined and responding to commands otherwise. I’m also using the editor, so that’s spellchecking names for me.

and I’m assuming " t u po" means “typo”

will_stewart1a · July 27, 2018, 8:47pm

Otherwise, I’m certainly generating solar events (and this particular lunar event):

2018-07-27 16:23:00.000 [vent.ChannelTriggeredEvent] - astro:moon:local:eclipse#event triggered TOTAL

rlkoshak · July 27, 2018, 9:55pm

I think you missed the last part of my post above.

The actual error you posted in your logs indicates that you have more than one Rule with the same name. That may not be something that is caught by VSCode.

This is the name of one of the Rules you posted (with the spaces removed). If you have a rule by this same name in this or any other .rules file it is an error.

Also, I’m pretty sure that VSCode doesn’t catch typos in Channel type triggers either (nor does the OH Rules parser). If you have a typo in the Channel trigger that rule will simply never fire.

will_stewart1a · July 28, 2018, 1:45pm

Thanks Rich

I did go through and rename any files in a subdirectory called “Archives” where I left earlier versions with “.backup” appended to the file names. Apparently the rules engine looks at subdirectories and any file with .rules in the filename.

Lo and behold, the outside light controls work now. Thanks much for your help!

rlkoshak · July 28, 2018, 3:19pm

It didn’t used to do that. It used to only load the files that end in .rules so it should have ignored the .backup ones. I wonder when that changed.

I’m glad you got it working!

Udo_Hartmann · July 29, 2018, 6:21pm

I’m pretty sure @will_stewart1a did rename the files yesterday

will_stewart1a · July 30, 2018, 11:49am

Now the sun events are not being triggered.

After restarting OH2, there is this line;

2018-07-30 07:15:52.219 [WARN ] [ore.common.registry.AbstractRegistry] - Could not add element: The specified name of the item 'astro_sun_local_set#start' is not valid!
java.lang.IllegalArgumentException: The specified name of the item 'astro_sun_local_set#start' is not valid!

Event log though has;

2018-07-30 07:15:54.467 [vent.ItemStateChangedEvent] - LocalSun_Set_ changed from NULL to 2018-07-30T20:23:00.000-0400
2018-07-30 07:15:54.468 [vent.ItemStateChangedEvent] - astro_sun_local_rise_Start changed from NULL to 2018-07-30T06:10:00.000-0400
2018-07-30 07:15:54.468 [vent.ItemStateChangedEvent] - LocalSun_Rise_ changed from NULL to 2018-07-30T06:10:00.000-0400
2018-07-30 07:15:54.469 [vent.ItemStateChangedEvent] - LocalSun_CivilDusk_ changed from NULL to 2018-07-30T20:26:00.000-0400
2018-07-30 07:15:54.469 [vent.ItemStateChangedEvent] - LocalSun_CivilDawn_ changed from NULL to 2018-07-30T05:40:00.000-0400

Previously I had added some links to the astro sun events thinking that might help solve the issue I had before. I don’t know if they are causing issues now;

2018-07-30 07:15:52.373 [.ItemChannelLinkAddedEvent] - Link 'astro_sun_local_set_end-astro:sun:local:set' has been added.

I’m tempted to uninstall and reinstall the Astro binding, unless that will cause even greater issues. Will it?

This started yesterday

rlkoshak · July 30, 2018, 3:48pm

This is not a valid Item name. If you are trying to use Astro events as a trigger to your Rule you do not use Items. You use Channel triggers in which case you need to use the Channel ID. Channel IDs use : instead of _.

Channel 'astro:sun:local:set#start' triggered START

If you have simple mode enabled, you would have an Item named astro_sun_local_set_Start which will contain the date time of the start of the Sunset event. But there will be no #start as part of the Item name.

will_stewart1a · August 1, 2018, 4:57pm

Reinstalling the Astro binding and restarting OH2 seems to have solved the problem.