Astro binding does not trigger: has no future executions anymore

On #975 everything works fine right now … :fu:

I updated to #976 today and though the sunset event did trigger, I’m still getting:

2017-07-01 21:04:00.007 [INFO ] [Manager$ExpressionThreadPoolExecutor] - Expression '0 4 21 1 7 ? 2017' has no future executions anymore
2017-07-01 21:04:00.008 [INFO ] [Manager$ExpressionThreadPoolExecutor] - Expression '0 4 21 1 7 ? 2017' has no future executions anymore

binding version is :

187 | Active   |  80 | 0.9.0.201706270841     | Astro Binding

I’m assuming the fix isn’t in yet, but that is just for the logging I’m assuming so the functionality should work now?

Looks like that is the case::

My system did not miss a trigger :fu:

I think that the fix hasn’t made it yet to the latest snapshot (976)

openhab> list -s |grep -i scheduler
104 | Active   |  80 | 0.9.0.201706270841     | Eclipse SmartHome Scheduler Service                    | org.eclipse.smarthome.core.scheduler

Just upgraded from OH 2.2.0 snapshot build #982 to #983
The org.eclipse.smarthome.core.scheduler is still the same version (0.9.0.201706270841) and I am still getting:

2017-07-10 05:06:00.008 [INFO ] [Manager$ExpressionThreadPoolExecutor] - Expression '0 6 5 10 7 ? 2017' has no future executions anymore
2017-07-10 05:06:00.008 [INFO ] [Manager$ExpressionThreadPoolExecutor] - Expression '0 6 5 10 7 ? 2017' has no future executions anymore
2017-07-10 05:06:00.010 [INFO ] [Manager$ExpressionThreadPoolExecutor] - Expression '0 6 5 10 7 ? 2017' has no future executions anymore
2017-07-10 05:42:00.006 [INFO ] [Manager$ExpressionThreadPoolExecutor] - Expression '0 42 5 10 7 ? 2017' has no future executions anymore
2017-07-10 05:42:00.009 [INFO ] [Manager$ExpressionThreadPoolExecutor] - Expression '0 42 5 10 7 ? 2017' has no future executions anymore
2017-07-10 05:42:00.013 [INFO ] [Manager$ExpressionThreadPoolExecutor] - Expression '0 42 5 10 7 ? 2017' has no future executions anymore
2017-07-10 05:45:00.012 [INFO ] [Manager$ExpressionThreadPoolExecutor] - Expression '0 45 5 10 7 ? 2017' has no future executions anymore
2017-07-10 05:45:00.013 [INFO ] [Manager$ExpressionThreadPoolExecutor] - Expression '0 45 5 10 7 ? 2017' has no future executions anymore
2017-07-10 05:45:00.016 [INFO ] [Manager$ExpressionThreadPoolExecutor] - Expression '0 45 5 10 7 ? 2017' has no future executions anymore
2017-07-10 06:49:00.009 [INFO ] [Manager$ExpressionThreadPoolExecutor] - Expression '0 49 6 10 7 ? 2017' has no future executions anymore

I guess the updated scheduler has not reached the snapshot yet :slight_smile:

Looks like that is the case:
https://hudson.eclipse.org/smarthome/job/SmartHomeDistribution-Stable/changes
:sweat_smile:

1 Like

Hi,

I noticed that our lights didn’t turn on in the evening (we’re using the astro and zwave bindings) and I spotted the “has no future executions anymore” messages in the log file and the problem looks similar to what’s discussed here. Turning on/off the lights manually and through cron rules works fine. I ran an apt upgrade a few days back.

I’m running an apt-installed version of openhab2 on a raspberry pi 3:

$ apt show openhab2
Package: openhab2
Source: openhab2
Version: 2.1.0-1
Section: java
Priority: optional
Depends: adduser
Conflicts: openhab2-online, openhab2-offline
Installed-Size: 60.2 MB
Maintainer: https://community.openhab.org
Homepage: www.openhab.org
Download-Size: 53.3 MB
APT-Manual-Installed: yes
APT-Sources: https://dl.bintray.com/openhab/apt-repo2/ stable/main armhf Packages
Description: openhab2
 Linux installation package for openHAB 2.

N: There is 1 additional record. Please use the '-a' switch to see it

Is that version affected by the problems discussed in this thread (checking to make sure I’m not having some other problem)?

If so, what’s the best way to try this out? Will there be a stable release soon with this fixed? Should I switch to the snapshot release from the jfrog.io apt source as described on http://docs.openhab.org/installation/linux.html (but I suppose I’ll get other changes that way which are not yet deemed stable)? Go back to an older version? I’d prefer to use something that’s stable, but possibly with a few parts in snapshot state (like the zwave binding) when needed.

Thanks,
Klas

That is a log message which currently goes to the WARN level, but should go to DEBUG level. It does not affect triggering the channels, so you will have to look for something else.
Maybe your problem is related to:

I am afraid that it is realted to astro 2.1 binding - had same issue at my installation. Log showed “… has no future executions anymore” and nothing was triggered. Helped switching to astro 1.x binding. Now i am waiting for OH 2.2 to check new version of binding

It may be worth checking the times of the astro events. I used to use the astroDusk time channel. Prior to 2.1, this would trigger at about 9.20pm. After the upgrade, I found that my dusk events were not triggering at the correct time - they were triggering at about 11.15pm as this was the new time being reported by the astroDusk channel.

As already said, you can easily check the times via http://suncalc.net:

@sihui Thanks for the hint. I see none of the “Queue full” messages in the log, so perhaps that’s not it.

I rebooted the raspberry pi 3 days ago and it worked fine until this morning. Looks like the sun rise event doesn’t trigger. It triggered on the 15:th and the 16:th but not on the 17:th. Same thing (no sun rise event) happened on the 13:th before the reboot.

$ egrep "astro:" /var/log/openhab2/events.log
...
2017-07-14 10:34:19.406 [ItemChannelLinkAddedEvent ] - Link 'MoonPhase-astro:moon:home:phase#name' has been added.
2017-07-14 10:34:19.450 [ItemChannelLinkAddedEvent ] - Link 'Elevation-astro:sun:home:position#elevation' has been added.
2017-07-14 10:34:19.492 [ItemChannelLinkAddedEvent ] - Link 'Sunset_Time-astro:sun:home:set#start' has been added.
2017-07-14 10:34:19.503 [ItemChannelLinkAddedEvent ] - Link 'Azimuth-astro:sun:home:position#azimuth' has been added.
2017-07-14 10:34:19.513 [ItemChannelLinkAddedEvent ] - Link 'Sunrise_Time-astro:sun:home:rise#start' has been added.
2017-07-14 10:34:19.536 [ItemChannelLinkAddedEvent ] - Link 'Total_Radiation-astro:sun:home:radiation#total' has been added.
2017-07-14 10:34:24.541 [ThingAddedEvent           ] - Thing 'astro:sun:home' has been added.
2017-07-14 10:34:24.572 [hingStatusInfoChangedEvent] - 'astro:sun:home' changed from UNINITIALIZED to INITIALIZING
2017-07-14 10:34:24.575 [hingStatusInfoChangedEvent] - 'astro:sun:home' changed from INITIALIZING to ONLINE
2017-07-14 10:34:26.112 [ThingAddedEvent           ] - Thing 'astro:moon:home' has been added.
2017-07-14 10:34:26.122 [hingStatusInfoChangedEvent] - 'astro:moon:home' changed from UNINITIALIZED to INITIALIZING
2017-07-14 10:34:26.568 [hingStatusInfoChangedEvent] - 'astro:moon:home' changed from INITIALIZING to ONLINE
2017-07-14 13:04:00.097 [ChannelTriggeredEvent     ] - astro:sun:home:noon#event triggered START
2017-07-14 13:05:00.113 [ChannelTriggeredEvent     ] - astro:sun:home:noon#event triggered END
2017-07-14 21:49:00.006 [ChannelTriggeredEvent     ] - astro:sun:home:daylight#event triggered END
2017-07-14 21:49:00.025 [ChannelTriggeredEvent     ] - astro:sun:home:set#event triggered START
2017-07-14 21:55:00.004 [ChannelTriggeredEvent     ] - astro:sun:home:civilDusk#event triggered START
2017-07-14 21:55:00.117 [ChannelTriggeredEvent     ] - astro:sun:home:set#event triggered END
2017-07-14 23:02:00.096 [ChannelTriggeredEvent     ] - astro:sun:home:civilDusk#event triggered END
2017-07-14 23:02:00.100 [ChannelTriggeredEvent     ] - astro:sun:home:nauticDusk#event triggered START
2017-07-14 23:49:00.109 [ChannelTriggeredEvent     ] - astro:moon:home:rise#event triggered START
2017-07-15 03:09:08.752 [ChannelTriggeredEvent     ] - astro:sun:home:nauticDawn#event triggered END
2017-07-15 03:09:08.784 [ChannelTriggeredEvent     ] - astro:sun:home:civilDawn#event triggered START
2017-07-15 04:16:08.756 [ChannelTriggeredEvent     ] - astro:sun:home:civilDawn#event triggered END
2017-07-15 04:16:08.849 [ChannelTriggeredEvent     ] - astro:sun:home:rise#event triggered START
2017-07-15 04:22:08.752 [ChannelTriggeredEvent     ] - astro:sun:home:rise#event triggered END
2017-07-15 04:22:08.785 [ChannelTriggeredEvent     ] - astro:sun:home:daylight#event triggered START
2017-07-15 11:43:08.771 [ChannelTriggeredEvent     ] - astro:moon:home:set#event triggered END
2017-07-15 13:05:08.769 [ChannelTriggeredEvent     ] - astro:sun:home:noon#event triggered START
2017-07-15 13:06:08.752 [ChannelTriggeredEvent     ] - astro:sun:home:noon#event triggered END
2017-07-15 21:47:08.754 [ChannelTriggeredEvent     ] - astro:sun:home:daylight#event triggered END
2017-07-15 21:47:08.870 [ChannelTriggeredEvent     ] - astro:sun:home:set#event triggered START
2017-07-15 21:53:08.749 [ChannelTriggeredEvent     ] - astro:sun:home:set#event triggered END
2017-07-15 21:53:08.784 [ChannelTriggeredEvent     ] - astro:sun:home:civilDusk#event triggered START
2017-07-15 23:00:08.749 [ChannelTriggeredEvent     ] - astro:sun:home:civilDusk#event triggered END
2017-07-15 23:00:08.783 [ChannelTriggeredEvent     ] - astro:sun:home:nauticDusk#event triggered START
2017-07-16 00:07:00.066 [ChannelTriggeredEvent     ] - astro:moon:home:rise#event triggered START
2017-07-16 03:12:00.016 [ChannelTriggeredEvent     ] - astro:sun:home:civilDawn#event triggered START
2017-07-16 03:12:00.021 [ChannelTriggeredEvent     ] - astro:sun:home:nauticDawn#event triggered END
2017-07-16 04:18:00.023 [ChannelTriggeredEvent     ] - astro:sun:home:civilDawn#event triggered END
2017-07-16 04:18:00.026 [ChannelTriggeredEvent     ] - astro:sun:home:rise#event triggered START
2017-07-16 04:24:00.013 [ChannelTriggeredEvent     ] - astro:sun:home:rise#event triggered END
2017-07-16 04:24:00.027 [ChannelTriggeredEvent     ] - astro:sun:home:daylight#event triggered START
2017-07-16 13:03:00.012 [ChannelTriggeredEvent     ] - astro:moon:home:set#event triggered END
2017-07-16 13:05:00.018 [ChannelTriggeredEvent     ] - astro:sun:home:noon#event triggered START
2017-07-16 13:06:00.065 [ChannelTriggeredEvent     ] - astro:sun:home:noon#event triggered END
2017-07-16 21:27:00.048 [ChannelTriggeredEvent     ] - astro:moon:home:phase#event triggered THIRD_QUARTER
2017-07-16 21:46:00.027 [ChannelTriggeredEvent     ] - astro:sun:home:daylight#event triggered END
2017-07-16 21:46:00.038 [ChannelTriggeredEvent     ] - astro:sun:home:set#event triggered START
2017-07-16 21:52:00.013 [ChannelTriggeredEvent     ] - astro:sun:home:set#event triggered END
2017-07-16 21:52:00.020 [ChannelTriggeredEvent     ] - astro:sun:home:civilDusk#event triggered START
2017-07-16 22:57:00.029 [ChannelTriggeredEvent     ] - astro:sun:home:nauticDusk#event triggered START
2017-07-16 22:57:00.031 [ChannelTriggeredEvent     ] - astro:sun:home:civilDusk#event triggered END

/Klas

That is what I noticed too, after upgrading the binding worked well for a few days, then the sunrise/sunset events stopped triggering. I restarted OH and they work again though I’m sure they will fail after a couple more days and I’ll have to restart.

Same Problem here - everything fine after reboot. I schedule a reboot every 2 days now :slight_smile:

I switched to the snapshot release (running a version from Sep 7) and that’s been working fine since then. Granted I could perhaps have gotten other stuff that’s not yet stable, but it looks like I’ve been lucky. Haven’t looked into when the change will be in the testing or stable versions.