After upgrading from 2.5 M3 to RC1 (basically since M4) I’m struggeling with the Astro binding. In the log I see the events being scheduled, but these are not triggered. Whenever I do an update to the Astro thing or after midnite, I see the events are triggered in the logs.
Following steps I did to reproduce the issue / ensure it is not related to another issue:
- Openhab 2.5.RC1 fresh install a docker (compose) stack (AMD64 architecture), see configuration below
- Items and Sitemaps copied across
- No other json db restored
- Installed all used addons (ASTRO, LCN, TELEGRAM, DECONZ, MAIL BINDING, NEXT GEN RULES)
When adding a new ASTRO thing, the events are triggered. After updating one ranged event channel, in my case sun:rise, with earliest & latest times, I see in the event log ASTRO schedules the event, see log below, but no event is triggered at the same time.
Is something wrong with my configuration or is there any bug in the ASTRO binding? I couldn’t find anything related by using the search.
Docker:
version: '3'
services:
openhab_yaml:
container_name: "openhab-yaml"
image: "openhab/openhab:2.5.0.RC1"
restart: always
network_mode: bridge
volumes:
- "/etc/localtime:/etc/localtime:ro"
- "/etc/timezone:/etc/timezone:ro"
- "./openhab_addons:/openhab/addons"
- "./openhab_conf:/openhab/conf"
- "./openhab_userdata:/openhab/userdata"
ports:
- "50881:50880"
- "50444:50443"
- "5008:5007"
- "50004:50003"
environment:
OPENHAB_HTTP_PORT: "50880"
OPENHAB_HTTPS_PORT: "50443"
EXTRA_JAVA_OPTS: "-Duser.timezone=Europe/Amsterdam"
USER_ID: "9001"
GROUP_ID: "9001"
LC_ALL: "de_DE.UTF-8"
LANG: "de_DE.UTF-8"
LANGUAGE: "de_DE.UTF-8"
CRYPTO_POLICY: "unlimited"
Log:
2019-12-13 09:26:01.678 [DEBUG] [o.internal.handler.AstroThingHandler] - Restarting jobs for thing astro:sun:local
2019-12-13 09:26:01.681 [DEBUG] [o.internal.handler.AstroThingHandler] - Stopping scheduled jobs for thing astro:sun:local
2019-12-13 09:26:01.689 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled org.eclipse.smarthome.core.internal.scheduler.SchedulerImpl$ScheduledCompletableFutureRecurring@6331744a[Not completed, 2 dependents] at midnight
2019-12-13 09:26:01.703 [DEBUG] [o.internal.handler.AstroThingHandler] - Publishing planet Sun for thing astro:sun:local
2019-12-13 09:26:01.706 [INFO ] [enhab.binding.astro.internal.job.Job] - Scheduled Astro event-jobs for thing astro:sun:local
2019-12-13 09:26:01.708 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:local/rise#event/START + Event job astro:sun:local/rise#event/END in 238292ms (at 2019-12-13T09:30:00)
2019-12-13 09:26:01.711 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:local/set#event/START in 24778290ms (at 2019-12-13T16:19:00)
2019-12-13 09:26:01.713 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:local/set#event/END in 25018288ms (at 2019-12-13T16:23:00)
2019-12-13 09:26:01.715 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:local/noon#event/START in 10798286ms (at 2019-12-13T12:26:00)
2019-12-13 09:26:01.717 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:local/noon#event/END in 10858283ms (at 2019-12-13T12:27:00)
2019-12-13 09:26:01.719 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:local/night#event/START in 32458281ms (at 2019-12-13T18:27:00)
2019-12-13 09:26:01.722 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:local/astroDusk#event/START in 29998278ms (at 2019-12-13T17:46:00)
2019-12-13 09:26:01.724 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:local/astroDusk#event/END in 32458276ms (at 2019-12-13T18:27:00)
2019-12-13 09:26:01.725 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:local/nauticDusk#event/START in 27418275ms (at 2019-12-13T17:03:00)
2019-12-13 09:26:01.727 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:local/nauticDusk#event/END in 29998273ms (at 2019-12-13T17:46:00)
2019-12-13 09:26:01.729 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:local/civilDusk#event/START in 25018271ms (at 2019-12-13T16:23:00)
2019-12-13 09:26:01.731 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:local/civilDusk#event/END in 27418269ms (at 2019-12-13T17:03:00)
2019-12-13 09:26:01.741 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:local/eveningNight#event/START in 32458259ms (at 2019-12-13T18:27:00)
2019-12-13 09:26:01.745 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:local/daylight#event/END in 24778255ms (at 2019-12-13T16:19:00)
2019-12-13 09:26:01.749 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Sun phase job astro:sun:local/SUN_SET in 24778252ms (at 2019-12-13T16:19:00)
2019-12-13 09:26:01.750 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Sun phase job astro:sun:local/NIGHT in 32458250ms (at 2019-12-13T18:27:00)
2019-12-13 09:26:01.752 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Sun phase job astro:sun:local/ASTRO_DUSK in 29998248ms (at 2019-12-13T17:46:00)
2019-12-13 09:26:01.754 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Sun phase job astro:sun:local/NAUTIC_DUSK in 27418247ms (at 2019-12-13T17:03:00)
2019-12-13 09:26:01.755 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Sun phase job astro:sun:local/CIVIL_DUSK in 25018245ms (at 2019-12-13T16:23:00)
2019-12-13 09:26:01.759 [DEBUG] [o.internal.handler.AstroThingHandler] - Thing astro:sun:local initialized ONLINE