Rule being triggered twice?

[kriznik]

For some strange reason DP TimeOfDay is doing this

2019-09-24 18:55:00.004 [INFO ] [e.smarthome.model.script.Time Of Day] - Calculating time of day...
2019-09-24 18:55:00.012 [INFO ] [e.smarthome.model.script.Time Of Day] - Calculating time of day...
2019-09-24 18:55:00.015 [INFO ] [e.smarthome.model.script.Time Of Day] - Calculated time of day is EVENING
2019-09-24 18:55:00.017 [INFO ] [e.smarthome.model.script.Time Of Day] - Calculated time of day is EVENING

18:55 equals to Sunset
which is being triggered by

  Channel 'astro:sun:local:set#event'   triggered START or

But why it’s running twice is bit of mystery. It’s doing it everyday at Sunset. And on evening trigger (which is sunset -90min)

Is astrobinding boardcasting sunset twice or something?

similar story is with Day

2019-09-23 06:50:00.005 [INFO ] [e.smarthome.model.script.Time Of Day] - Calculating time of day...
2019-09-23 06:50:00.018 [INFO ] [e.smarthome.model.script.Time Of Day] - Calculated time of day is DAY
2019-09-23 10:29:37.890 [INFO ] [e.smarthome.model.script.Time Of Day] - Calculating time of day...
2019-09-23 10:29:41.738 [INFO ] [e.smarthome.model.script.Time Of Day] - Calculated time of day is DAY
2019-09-23 10:29:49.401 [INFO ] [e.smarthome.model.script.Time Of Day] - Calculating time of day...
2019-09-23 10:29:49.406 [INFO ] [e.smarthome.model.script.Time Of Day] - Calculated time of day is DAY
2019-09-23 10:30:52.969 [INFO ] [e.smarthome.model.script.Time Of Day] - Calculating time of day...
2019-09-23 10:30:52.975 [INFO ] [e.smarthome.model.script.Time Of Day] - Calculated time of day is DAY
2019-09-23 10:31:01.300 [INFO ] [e.smarthome.model.script.Time Of Day] - Calculating time of day...
2019-09-23 10:31:04.312 [INFO ] [e.smarthome.model.script.Time Of Day] - Calculated time of day is DAY
2019-09-23 10:48:41.728 [INFO ] [e.smarthome.model.script.Time Of Day] - Calculating time of day...
2019-09-23 10:48:41.736 [INFO ] [e.smarthome.model.script.Time Of Day] - Calculated time of day is DAY
2019-09-23 14:48:27.153 [INFO ] [e.smarthome.model.script.Time Of Day] - Calculating time of day...
2019-09-23 14:48:29.996 [INFO ] [e.smarthome.model.script.Time Of Day] - Calculated time of day is DAY

but triggers are not calling it at these hours

  System started or // run at system start in case the time changed when OH was offline
  Channel 'astro:sun:local:rise#event'  triggered START or
  Channel 'astro:sun:local:set#event'   triggered START or
  Channel 'astro:sun:minus90:set#event' triggered START or
  Time cron "0 1 0 * * ? *" or // one minute after midnight so give Astro time to calculate the new day's times
  Time cron "0 0 6 * * ? *" or
  Time cron "0 0 23 * * ? *"

[rlkoshak (Rich Koshak)]

@kriznik

But why it’s running twice is bit of mystery. It’s doing it everyday at Sunset. And on evening trigger (which is sunset -90min)

Is astrobinding boardcasting sunset twice or something?

You should see the events from Astro in events.log. Look there to see if it’s generating two events at that time.

Is the .rules file being reloaded at those times? Any time the file reloads (e.g. you made a change and saved it) the Rule will trigger (System started).

[kriznik]

nope files is not being reloaded (and i know it will re-trigger them)

2019-09-24 18:55:00.002 [vent.ChannelTriggeredEvent] - astro:sun:minus90:set#event triggered START
2019-09-24 18:55:00.002 [vent.ChannelTriggeredEvent] - astro:sun:local:set#event triggered START
2019-09-24 18:58:00.001 [vent.ChannelTriggeredEvent] - astro:sun:minus90:set#event triggered END
2019-09-24 18:58:00.002 [vent.ChannelTriggeredEvent] - astro:sun:local:set#event triggered END

so minus90 is triggered at same time, well … crap
(@rlkoshak btw if astro is triggered at same time local and minu90 it means TimeOfDay is never at state AFTERNOON …)

this behaviour explains EVENING but does not explain DAY

[rlkoshak (Rich Koshak)]

If they are occurring at the same time there is something wrong with the minus90. There is an offset defined on the minus90 causing that event to trigger 90 minutes before the actual set.

[kriznik]

checked it twice, does not look wrong to me …

I have it like this

Thing astro:sun:minus90 [ geolocation="xxx,yyy",interval=300]{
    Channels:
        Type rangeEvent : set#event [
            offset=-90
        ]
}

Not sure what is ,100 in astro example for

astro:sun:home [ geolocation="52.5200066,13.4049540,100", interval=60 ] {
    Channels:
        Type rangeEvent : rise#event [
            offset=-30
        ]
}

havent found explanation for “,100” in geolocation part

[rlkoshak (Rich Koshak)]

@kriznik

does not look wrong to me …

It may not look wrong, but the offsets are not being used so there is something wrong. I don’t use .things files so I’ve no recommendations for a fix. Either your minus90 Thing is triggering at actual sunset or your home Thing is triggering 90 minutes before sunset, causing them both to occur at the same time.

[kriznik]

will try to define it via paperUI see if it helps.

but still that DAY recalculation is quite strange as there is no trigger

[rlkoshak (Rich Koshak)]

All I can suggest is that the file was changing somehow to cause OH to reload it (you would see reloads in openhab.log) or some other event was occurring at those times to cause the Rule to trigger. Look in events.log at those times to see if there is a correlation.

[rossko57]

@kriznik

will try to define it via paperUI see if it helps.

I would first look to see what you can in PaperUI, this feels like you have defined both from xxx.things and PaperUI

@kriznik

havent found explanation for “,100” in geolocation part

Altitude

[kriznik]

@rossko57

I would first look to see what you can in PaperUI, this feels like you have defined both from xxx.things and PaperUI

nope, defined once only in files
I’ll let you know if tomorrow it will occur again, as now i’ve defined both of them in paperui

@rossko57

Altitude

thanks!

[rlkoshak (Rich Koshak)]

@kriznik

nope, defined once only in files

The Astro binding will automatically put a Thing in the Inbox based on your configured Lat/Long. Did you by chance accidentally accept that Thing? That could cause a duplicate.

[kriznik]

nope, really i do have just one of each

btw @rlkoshak have you set offset for start/end or for event only or all three of them? I had it as whole event with start/stop at 0, wondering if that might be an issue.

My thinking was if I set offset for whole event, start/end will shift as well, or … maybe not?

[rlkoshak (Rich Koshak)]

I only apply the offset to the START Channel. I only use the START event so I don’t know if it also moves the END event too. The Rule triggers on the START event. I don’t use the Range Event Channel.

[kriznik]

I\ve done some tests and this trigger

Channel 'astro:sun:m90:set#event'   triggered START

works on range event shift, but somehow start was not affected

If you change it to this:

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

it does not matter if you shift range event, but shift start is enough

dunno if that’s expected or not, but it seems it does matters if you are shifting start or whole event and which trigger you actually use as it seems set#start START may differ from set#event START if shift is used

[rlkoshak (Rich Koshak)]

@kriznik

set#start START

You can’t use that event to trigger a Rule. It’s not an event trigger. You can only trigger the Rule using the #event trigger.

In my working config, I have only applied an offset to the start Channel and the #event Channel triggers at the appropriate time.

[kriznik]

strange, it works for me
maybe i need to restart OH if some old rules are still used, happened before