New earliest/latest channel features not working in Astro2 binding

sihui · March 14, 2017, 11:08am

Since snapshot build #837 the new channel properties for earliest/latest and offsets are available:

However, I cannot get it to work properly.

I defined via PaperUI a thing and linked an item:

I would expect now a channel trigger available at 08:30 in the morning to open my rollershutters, but nothings happens (astro2 in debug):

events.log:

2017-03-13 06:16:00.136 [ChannelTriggeredEvent     ] - astro:sun:shutter:civilDawn#event triggered START
2017-03-13 06:50:00.208 [ChannelTriggeredEvent     ] - astro:sun:shutter:civilDawn#event triggered END
2017-03-14 06:13:00.163 [ChannelTriggeredEvent     ] - astro:sun:shutter:civilDawn#event triggered START
2017-03-14 06:48:00.112 [ChannelTriggeredEvent     ] - astro:sun:shutter:civilDawn#event triggered END

openhab.log:

2017-03-14 06:13:00.097 [DEBUG] [g.astro.internal.job.AbstractBaseJob] - Starting astro job-event-start-civilDawn#event for thing astro:sun:shutter
2017-03-14 06:13:00.102 [DEBUG] [g.astro.internal.job.AbstractBaseJob] - Starting astro job-sunPhase-civil_dawn for thing astro:sun:shutter

but not one single entry on any log for earliest=08:30.

Are my expectations how the binding should work wrong?

gerrieg · March 14, 2017, 1:49pm

You only set the start time channel, that’s only for displaying the value. If you want a channel trigger, you have to use range event

sihui · March 14, 2017, 2:09pm

Ahh, thanks
Will try again and report back …

sihui · March 15, 2017, 10:16am

Okay, got it working now.
Thanks a lot @gerrieg for those additional features, it makes the astro2 binding one of the most important bindings for many users …
One last question if you don’t mind:

Earliest/Latest: For each trigger channel and start, end datetime value, you can optionally configure the earliest and latest time of the day.

e.g sun#rise earliest=18:00, latest=20:00

I tried all combinations I could think of in the thing and rule files to make that textual config work, but I was not successful.
It works fine while doing it through PaperUI, but I always like the old fashioned way through manual config files.

Any hint on that? I’m looking to add it to the channel trigger … not the DateTime.

gerrieg · March 15, 2017, 6:01pm

example things file:

astro:sun:home [ geolocation="xx.xxxxxx,xx.xxxxxx", altitude=100, interval=60 ] {
    Channels:
        Type rangeEvent : rise#event [
            offset=-30,
            latest="08:00"
        ]
}

Olymp · March 17, 2017, 6:59am

Good afternoon, Gerhard!
I want to ask you personally for help, because I already asked the community twice, I did not receive an answer.
I have 3 servers openHab (Ubuntu). On all three, the same problem.
The problem occurs when loading OpenHAB, but not at every boot, but at random. Right now, I restarted openHab 4 times and only for the fourth time there was this problem, and sometimes all 4 times in a row.
Here is the fragment of the log file at boot:

2017-03-17 14:36:23.863 [INFO ] [ding.astro.handler.AstroThingHandler] - Scheduled astro job-daily-sun at midnight for thing astro:sun:local
2017-03-17 14:36:23.876 [INFO ] [ding.astro.handler.AstroThingHandler] - Scheduled astro job-positional with interval of 300 seconds for thing astro:sun:local
2017-03-17 14:36:23.886 [INFO ] [ding.astro.handler.AstroThingHandler] - Scheduled astro job-daily-sun at midnight for thing astro:sun:local
2017-03-17 14:36:23.889 [INFO ] [ding.astro.handler.AstroThingHandler] - Scheduled astro job-positional with interval of 300 seconds for thing astro:sun:local
2017-03-17 14:36:24.318 [ERROR] [.astro.internal.job.AbstractDailyJob] - Unable to store Job : 'astro:sun:local.job-event-start-set#event', because one already exists with this identification.
org.quartz.ObjectAlreadyExistsException: Unable to store Job : 'astro:sun:local.job-event-start-set#event', because one already exists with this identification.
	at org.quartz.simpl.RAMJobStore.storeJob(RAMJobStore.java:279)[106:org.eclipse.smarthome.core.scheduler:0.9.0.201703131829]
	at org.quartz.simpl.RAMJobStore.storeJobAndTrigger(RAMJobStore.java:251)[106:org.eclipse.smarthome.core.scheduler:0.9.0.201703131829]
	at org.quartz.core.QuartzScheduler.scheduleJob(QuartzScheduler.java:886)[106:org.eclipse.smarthome.core.scheduler:0.9.0.201703131829]
	at org.quartz.impl.StdScheduler.scheduleJob(StdScheduler.java:249)[106:org.eclipse.smarthome.core.scheduler:0.9.0.201703131829]
	at org.openhab.binding.astro.internal.job.AbstractDailyJob.schedule(AbstractDailyJob.java:103)[209:org.openhab.binding.astro:2.1.0.201702121957]
	at org.openhab.binding.astro.internal.job.AbstractDailyJob.scheduleEvent(AbstractDailyJob.java:70)[209:org.openhab.binding.astro:2.1.0.201702121957]
	at org.openhab.binding.astro.internal.job.AbstractDailyJob.scheduleRange(AbstractDailyJob.java:58)[209:org.openhab.binding.astro:2.1.0.201702121957]
	at org.openhab.binding.astro.internal.job.DailyJobSun.schedulePlanetEvents(DailyJobSun.java:33)[209:org.openhab.binding.astro:2.1.0.201702121957]
	at org.openhab.binding.astro.internal.job.AbstractDailyJob.executeJob(AbstractDailyJob.java:47)[209:org.openhab.binding.astro:2.1.0.201702121957]
	at org.openhab.binding.astro.internal.job.AbstractBaseJob.execute(AbstractBaseJob.java:40)[209:org.openhab.binding.astro:2.1.0.201702121957]
	at org.quartz.core.JobRunShell.run(JobRunShell.java:202)[106:org.eclipse.smarthome.core.scheduler:0.9.0.201703131829]
	at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573)[106:org.eclipse.smarthome.core.scheduler:0.9.0.201703131829]
2017-03-17 14:36:24.438 [ERROR] [.astro.internal.job.AbstractDailyJob] - Unable to store Job : 'astro:sun:local.job-event-end-set#event', because one already exists with this identification.
org.quartz.ObjectAlreadyExistsException: Unable to store Job : 'astro:sun:local.job-event-end-set#event', because one already exists with this identification.
	at org.quartz.simpl.RAMJobStore.storeJob(RAMJobStore.java:279)[106:org.eclipse.smarthome.core.scheduler:0.9.0.201703131829]
	at org.quartz.simpl.RAMJobStore.storeJobAndTrigger(RAMJobStore.java:251)[106:org.eclipse.smarthome.core.scheduler:0.9.0.201703131829]
	at org.quartz.core.QuartzScheduler.scheduleJob(QuartzScheduler.java:886)[106:org.eclipse.smarthome.core.scheduler:0.9.0.201703131829]
	at org.quartz.impl.StdScheduler.scheduleJob(StdScheduler.java:249)[106:org.eclipse.smarthome.core.scheduler:0.9.0.201703131829]
	at org.openhab.binding.astro.internal.job.AbstractDailyJob.schedule(AbstractDailyJob.java:103)[209:org.openhab.binding.astro:2.1.0.201702121957]
	at org.openhab.binding.astro.internal.job.AbstractDailyJob.scheduleEvent(AbstractDailyJob.java:70)[209:org.openhab.binding.astro:2.1.0.201702121957]
	at org.openhab.binding.astro.internal.job.AbstractDailyJob.scheduleRange(AbstractDailyJob.java:59)[209:org.openhab.binding.astro:2.1.0.201702121957]
	at org.openhab.binding.astro.internal.job.DailyJobSun.schedulePlanetEvents(DailyJobSun.java:33)[209:org.openhab.binding.astro:2.1.0.201702121957]
	at org.openhab.binding.astro.internal.job.AbstractDailyJob.executeJob(AbstractDailyJob.java:47)[209:org.openhab.binding.astro:2.1.0.201702121957]
	at org.openhab.binding.astro.internal.job.AbstractBaseJob.execute(AbstractBaseJob.java:40)[209:org.openhab.binding.astro:2.1.0.201702121957]
	at org.quartz.core.JobRunShell.run(JobRunShell.java:202)[106:org.eclipse.smarthome.core.scheduler:0.9.0.201703131829]
	at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573)[106:org.eclipse.smarthome.core.scheduler:0.9.0.201703131829]
2017-03-17 14:36:24.477 [ERROR] [.astro.internal.job.AbstractDailyJob] - Unable to store Job : 'astro:sun:local.job-event-start-night#event', because one already exists with this identification.
org.quartz.ObjectAlreadyExistsException: Unable to store Job : 'astro:sun:local.job-event-start-night#event', because one already exists with this identification.
	at org.quartz.simpl.RAMJobStore.storeJob(RAMJobStore.java:279)[106:org.eclipse.smarthome.core.scheduler:0.9.0.201703131829]
	at org.quartz.simpl.RAMJobStore.storeJobAndTrigger(RAMJobStore.java:251)[106:org.eclipse.smarthome.core.scheduler:0.9.0.201703131829]
	at org.quartz.core.QuartzScheduler.scheduleJob(QuartzScheduler.java:886)[106:org.eclipse.smarthome.core.scheduler:0.9.0.201703131829]
	at org.quartz.impl.StdScheduler.scheduleJob(StdScheduler.java:249)[106:org.eclipse.smarthome.core.scheduler:0.9.0.201703131829]
	at org.openhab.binding.astro.internal.job.AbstractDailyJob.schedule(AbstractDailyJob.java:103)[209:org.openhab.binding.astro:2.1.0.201702121957]
	at org.openhab.binding.astro.internal.job.AbstractDailyJob.scheduleEvent(AbstractDailyJob.java:70)[209:org.openhab.binding.astro:2.1.0.201702121957]
	at org.openhab.binding.astro.internal.job.AbstractDailyJob.scheduleRange(AbstractDailyJob.java:58)[209:org.openhab.binding.astro:2.1.0.201702121957]
	at org.openhab.binding.astro.internal.job.DailyJobSun.schedulePlanetEvents(DailyJobSun.java:35)[209:org.openhab.binding.astro:2.1.0.201702121957]
	at org.openhab.binding.astro.internal.job.AbstractDailyJob.executeJob(AbstractDailyJob.java:47)[209:org.openhab.binding.astro:2.1.0.201702121957]
	at org.openhab.binding.astro.internal.job.AbstractBaseJob.execute(AbstractBaseJob.java:40)[209:org.openhab.binding.astro:2.1.0.201702121957]
	at org.quartz.core.JobRunShell.run(JobRunShell.java:202)[106:org.eclipse.smarthome.core.scheduler:0.9.0.201703131829]
	at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573)[106:org.eclipse.smarthome.core.scheduler:0.9.0.201703131829]
2017-03-17 14:36:24.531 [ERROR] [.astro.internal.job.AbstractDailyJob] - Unable to store Job : 'astro:sun:local.job-event-start-astroDusk#event', because one already exists with this identification.
org.quartz.ObjectAlreadyExistsException: Unable to store Job : 'astro:sun:local.job-event-start-astroDusk#event', because one already exists with this identification.
	at org.quartz.simpl.RAMJobStore.storeJob(RAMJobStore.java:279)[106:org.eclipse.smarthome.core.scheduler:0.9.0.201703131829]
	at org.quartz.simpl.RAMJobStore.storeJobAndTrigger(RAMJobStore.java:251)[106:org.eclipse.smarthome.core.scheduler:0.9.0.201703131829]
	at org.quartz.core.QuartzScheduler.scheduleJob(QuartzScheduler.java:886)[106:org.eclipse.smarthome.core.scheduler:0.9.0.201703131829]

......
......

2017-03-17 14:36:24.687 [ERROR] [.astro.internal.job.AbstractDailyJob] - Unable to store Job : 'astro:sun:local.job-sunPhase-civil_dusk', because one already exists with this identification.
org.quartz.ObjectAlreadyExistsException: Unable to store Job : 'astro:sun:local.job-sunPhase-civil_dusk', because one already exists with this identification.
	at org.quartz.simpl.RAMJobStore.storeJob(RAMJobStore.java:279)[106:org.eclipse.smarthome.core.scheduler:0.9.0.201703131829]
	at org.quartz.simpl.RAMJobStore.storeJobAndTrigger(RAMJobStore.java:251)[106:org.eclipse.smarthome.core.scheduler:0.9.0.201703131829]
	at org.quartz.core.QuartzScheduler.scheduleJob(QuartzScheduler.java:886)[106:org.eclipse.smarthome.core.scheduler:0.9.0.201703131829]
	at org.quartz.impl.StdScheduler.scheduleJob(StdScheduler.java:249)[106:org.eclipse.smarthome.core.scheduler:0.9.0.201703131829]
	at org.openhab.binding.astro.internal.job.AbstractDailyJob.schedule(AbstractDailyJob.java:103)[209:org.openhab.binding.astro:2.1.0.201702121957]
	at org.openhab.binding.astro.internal.job.AbstractDailyJob.scheduleSunPhase(AbstractDailyJob.java:87)[209:org.openhab.binding.astro:2.1.0.201702121957]
	at org.openhab.binding.astro.internal.job.DailyJobSun.schedulePlanetEvents(DailyJobSun.java:66)[209:org.openhab.binding.astro:2.1.0.201702121957]
	at org.openhab.binding.astro.internal.job.AbstractDailyJob.executeJob(AbstractDailyJob.java:47)[209:org.openhab.binding.astro:2.1.0.201702121957]
	at org.openhab.binding.astro.internal.job.AbstractBaseJob.execute(AbstractBaseJob.java:40)[209:org.openhab.binding.astro:2.1.0.201702121957]
	at org.quartz.core.JobRunShell.run(JobRunShell.java:202)[106:org.eclipse.smarthome.core.scheduler:0.9.0.201703131829]
	at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573)[106:org.eclipse.smarthome.core.scheduler:0.9.0.201703131829]
2017-03-17 14:36:24.691 [INFO ] [.astro.internal.job.AbstractDailyJob] - Scheduled astro event-jobs for thing astro:sun:local

Note that the first and second lines are repeated twice. With normal loading, these lines only once.
I reinstalled the add-on, it did not help. Previously, I used a tnings file, now I tried to add through paperi, the result is one.
I hope you’ll help me get rid of this trouble.
Thank you!

sihui · March 17, 2017, 5:58pm

It looks like you have some old entries, maybe from your textual config, in your setup.
I would delete all astro things from PaperUI, delete all textual configs, restart openHAB and then take a look in your json db files (/userdata/jsondb).

If you find entries with astro:sun:local (also check just astro:sun to be sure) delete them and restart openHAB.
I hope that should do it …

gerrieg · March 18, 2017, 8:32am

you can try to clear all configs:

links clear
items clear
things clear
inbox clear

Olymp · March 20, 2017, 9:46am

Hello! Thank you for trying to help me! I deleted everything related to the astro. Reboot openHAB. I checked all the files * .json, the contents of all the same: {}
In the paperUI added an thing astro:sun.
Added file astro.items:

Group gAstro

Number		sun_elevation	"elevation [%.2f °]"						<sun>		(gAstro)	{ channel="astro:sun:local:position#elevation" }
DateTime	sun_astrodawn	"astrodawn[%1$tH:%1$tM]"					<sunrise>	(gAstro)	{ channel="astro:sun:local:astroDawn#start" }
DateTime	sun_rise		"rise[%1$tH:%1$tM]"							<sunrise>	(gAstro)	{ channel="astro:sun:local:rise#start" }
DateTime	sun_noon		"noon[%1$tH:%1$tM]"							<sun>		(gAstro)	{ channel="astro:sun:local:noon#start" }
DateTime	sun_set			"set[%1$tH:%1$tM]"							<sunset>	(gAstro)	{ channel="astro:sun:local:set#start" }
DateTime	sun_night		"night[%1$tH:%1$tM]"						<moon>		(gAstro)	{ channel="astro:sun:local:night#start" }

String		season_name		"season_name [MAP(season.map):%s]"						(gAstro)	{ channel="astro:sun:local:season#name" }
DateTime	season_spring	"spring [%1$td.%1$tm.%1$tY %1$tH:%1$tM]"	<rain>		(gAstro)	{ channel="astro:sun:local:season#spring" }
DateTime	season_summer	"summer [%1$td.%1$tm.%1$tY %1$tH:%1$tM]"	<garden>	(gAstro)	{ channel="astro:sun:local:season#summer" }
DateTime	season_autumn	"autumn [%1$td.%1$tm.%1$tY %1$tH:%1$tM]"	<wind>		(gAstro)	{ channel="astro:sun:local:season#autumn" }
DateTime	season_winter	"winter [%1$td.%1$tm.%1$tY %1$tH:%1$tM]"	<climate-on>(gAstro)	{ channel="astro:sun:local:season#winter" }

Reboot openHAB first time, everything is fine, the second one is good, the third one is again the same error.
When adding a thing, the geolocation parameters were substituted by mine, from where did they come from?
Thank you!

Olymp · March 20, 2017, 9:49am

Hello!
I tried this. I removed everything from the paper, cleaned everything in the console as you taught, restarted OpenHAB. It did not get any better.

sihui · March 20, 2017, 11:50am

Did you use the astro1 binding before and have your /conf/services/astro.cfg still in place?

Olymp · March 20, 2017, 11:17pm

Once upon a time, but long ago already removed.

gerrieg · March 21, 2017, 4:37pm

from where did they come from

The astro binding automatically detects your location at startup via http://ip-api.com/json/?fields=lat,lon and adds a local sun and moon thing. Did you also specify a sun or moon thing in a things file with the same name (local)?

you can try to enable full debugging

log:set DEBUG org.eclipse.smarthome

shutdown and start. Maybe you find something in the (big) logfile

Olymp · March 22, 2017, 12:26am

I am 100% sure that it is not as accurate as I set up.

Initially, I did, through the file astro.things
But when errors appeared, I deleted the file and added it through the paperUI.
It is alarming that this does not always happen. Now, when loading, there may be errors, but at the next reboot there is no, or vice versa.

OK, I’ll try to do so, after I report.
Thank you for helping me!

Olymp · March 24, 2017, 9:47am

I did so, information is very much, I do not understand what is happening there, my knowledge is not enough to understand this
I deleted openHAB2 completely (http://docs.openhab.org/installation/linux.html#uninstall).
I installed it again - Build #850 (http://docs.openhab.org/installation/linux.html#installation).

The paperUI installed an addon - Astro.
In the paperUI, I added a thing Local Sun.
Added the file /etc/openhab2/items/astro.items
Restarted openHAB - no errors.
I restarted again - errors.
Here are the statistics of ten restarts:
No errors: 1,4,8,9
Errors: 2,3,5,6,7,10

sihui · March 24, 2017, 4:27pm

From what you have done so far the problem can only be in your items file.
For testing, set up everything through PaperUI, don’t use any manually created items files and see if you still get that error (I guess not, because otherwise I would have that error too).

Olymp · March 25, 2017, 2:10am

Group gAstro

Number		sun_elevation	"elevation [%.2f °]"						<sun>		(gAstro)	{ channel="astro:sun:local:position#elevation" }
DateTime	sun_astrodawn	"astrodawn[%1$tH:%1$tM]"					<sunrise>	(gAstro)	{ channel="astro:sun:local:astroDawn#start" }
DateTime	sun_rise		"rise[%1$tH:%1$tM]"							<sunrise>	(gAstro)	{ channel="astro:sun:local:rise#start" }
DateTime	sun_noon		"noon[%1$tH:%1$tM]"							<sun>		(gAstro)	{ channel="astro:sun:local:noon#start" }
DateTime	sun_set			"set[%1$tH:%1$tM]"							<sunset>	(gAstro)	{ channel="astro:sun:local:set#start" }
DateTime	sun_night		"night[%1$tH:%1$tM]"						<moon>		(gAstro)	{ channel="astro:sun:local:night#start" }

String		season_name		"season_name [MAP(season.map):%s]"						(gAstro)	{ channel="astro:sun:local:season#name" }
DateTime	season_spring	"spring [%1$td.%1$tm.%1$tY %1$tH:%1$tM]"	<rain>		(gAstro)	{ channel="astro:sun:local:season#spring" }
DateTime	season_summer	"summer [%1$td.%1$tm.%1$tY %1$tH:%1$tM]"	<garden>	(gAstro)	{ channel="astro:sun:local:season#summer" }
DateTime	season_autumn	"autumn [%1$td.%1$tm.%1$tY %1$tH:%1$tM]"	<wind>		(gAstro)	{ channel="astro:sun:local:season#autumn" }
DateTime	season_winter	"winter [%1$td.%1$tm.%1$tY %1$tH:%1$tM]"	<climate-on>(gAstro)	{ channel="astro:sun:local:season#winter" }

Thank you! I’ll try, I’ll tell you the result.

sihui · March 25, 2017, 7:29am

… and do an upload of that file somewhere so we can take a look at it, e.g. pastebin or whatever service you prefer.

I cannot see any wrong syntax in your items file, the only problem is the missing space between <climate-on>(gAstro), but I guess that is a copy/paste problem …

Olymp · March 26, 2017, 1:18am

Yes it is!

sihui · March 26, 2017, 6:06am

[quote=“Olymp, post:19, topic:24981, full:true”]
https://mega.nz/#!9ZkGAQ5L!LRqSCNTEggOfNUg3dgs7-vEocRY0gSPb1MX0Yl4_ii4[/quote]

Sorry, no idea why the jobs are loading twice. I extracted the relevant astro lines, maybe another user is able to find the solution for an Ubuntu system.

2017-03-26 08:58:16.078 [DEBUG] [el.item.internal.GenericItemProvider] - Start processing binding configuration of Item 'sun_elevation (Type=NumberItem, State=NULL, Label=Elevation, Category=sun)' with 'GenericItemChannelLinkProvider' reader.
2017-03-26 08:58:16.084 [DEBUG] [el.item.internal.GenericItemProvider] - Start processing binding configuration of Item 'sun_astrodawn (Type=DateTimeItem, State=NULL, Label=AstroDawn, Category=sunrise)' with 'GenericItemChannelLinkProvider' reader.
2017-03-26 08:58:16.086 [DEBUG] [el.item.internal.GenericItemProvider] - Start processing binding configuration of Item 'sun_rise (Type=DateTimeItem, State=NULL, Label=SunRise, Category=sunrise)' with 'GenericItemChannelLinkProvider' reader.
2017-03-26 08:58:16.089 [DEBUG] [el.item.internal.GenericItemProvider] - Start processing binding configuration of Item 'sun_noon (Type=DateTimeItem, State=NULL, Label=Noon, Category=sun)' with 'GenericItemChannelLinkProvider' reader.
2017-03-26 08:58:16.091 [DEBUG] [el.item.internal.GenericItemProvider] - Start processing binding configuration of Item 'sun_set (Type=DateTimeItem, State=NULL, Label=SunSet, Category=sunset)' with 'GenericItemChannelLinkProvider' reader.
2017-03-26 08:58:16.094 [DEBUG] [el.item.internal.GenericItemProvider] - Start processing binding configuration of Item 'sun_night (Type=DateTimeItem, State=NULL, Label=Night, Category=moon)' with 'GenericItemChannelLinkProvider' reader.
2017-03-26 08:58:16.097 [DEBUG] [el.item.internal.GenericItemProvider] - Start processing binding configuration of Item 'season_name (Type=StringItem, State=NULL, Label=Season name, Category=null)' with 'GenericItemChannelLinkProvider' reader.
2017-03-26 08:58:16.100 [DEBUG] [el.item.internal.GenericItemProvider] - Start processing binding configuration of Item 'season_spring (Type=DateTimeItem, State=NULL, Label=Spring, Category=rain)' with 'GenericItemChannelLinkProvider' reader.
2017-03-26 08:58:16.102 [DEBUG] [el.item.internal.GenericItemProvider] - Start processing binding configuration of Item 'season_summer (Type=DateTimeItem, State=NULL, Label=Summer, Category=garden)' with 'GenericItemChannelLinkProvider' reader.
2017-03-26 08:58:16.106 [DEBUG] [el.item.internal.GenericItemProvider] - Start processing binding configuration of Item 'season_autumn (Type=DateTimeItem, State=NULL, Label=Autumn, Category=wind)' with 'GenericItemChannelLinkProvider' reader.
2017-03-26 08:58:16.109 [DEBUG] [el.item.internal.GenericItemProvider] - Start processing binding configuration of Item 'season_winter (Type=DateTimeItem, State=NULL, Label=Winter, Category=climate-on)' with 'GenericItemChannelLinkProvider' reader.
2017-03-26 08:58:17.127 [DEBUG] [ome.core.thing.internal.ThingManager] - Thing 'astro:sun:local' is tracked by ThingManager.
2017-03-26 08:58:17.128 [DEBUG] [ome.core.thing.internal.ThingManager] - Not registering a handler at this point since no handler factory for thing 'astro:sun:local' found.
2017-03-26 08:58:20.964 [DEBUG] [ome.core.thing.internal.ThingManager] - Thing handler factory 'AstroHandlerFactory' added
2017-03-26 08:58:20.966 [DEBUG] [nfig.core.BundleProcessorVetoManager] - Meta-data of bundle 'org.openhab.binding.astro' is not fully loaded ([org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker$1@5eccced9(/ESH-INF/thing/)]), deferring action for 'org.eclipse.smarthome.core.thing.internal.ThingImpl@dc6e3bbb'
2017-03-26 08:58:21.345 [DEBUG] [nfig.core.BundleProcessorVetoManager] - Finished loading meta-data of bundle 'org.openhab.binding.astro'.
2017-03-26 08:58:21.348 [DEBUG] [ome.core.thing.internal.ThingManager] - Calling 'AstroHandlerFactory.registerHandler()' for thing 'astro:sun:local'.
2017-03-26 08:58:21.350 [DEBUG] [rthome.core.common.ThreadPoolManager] - Created scheduled thread pool 'thingHandler' of size 3
2017-03-26 08:58:21.499 [DEBUG] [nfig.core.BundleProcessorVetoManager] - Finished loading meta-data of bundle 'org.openhab.binding.astro'.
2017-03-26 08:58:21.500 [DEBUG] [ome.core.thing.internal.ThingManager] - Calling initialize handler for thing 'astro:sun:local' at 'org.openhab.binding.astro.handler.SunHandler@5fa053ce'.
2017-03-26 08:58:21.533 [DEBUG] [.smarthome.config.core.Configuration] - Setting value (String) xxxxxxx,yyyyyyy to field 'geolocation' in configuration class org.openhab.binding.astro.internal.config.AstroThingConfig
2017-03-26 08:58:21.609 [DEBUG] [.smarthome.config.core.Configuration] - Setting value (Integer) 300 to field 'interval' in configuration class org.openhab.binding.astro.internal.config.AstroThingConfig
2017-03-26 08:58:23.777 [INFO ] [ding.astro.handler.AstroThingHandler] - Scheduled astro job-daily-sun at midnight for thing astro:sun:local
2017-03-26 08:58:23.795 [INFO ] [ding.astro.handler.AstroThingHandler] - Scheduled astro job-positional with interval of 300 seconds for thing astro:sun:local
2017-03-26 08:58:23.818 [INFO ] [ding.astro.handler.AstroThingHandler] - Scheduled astro job-daily-sun at midnight for thing astro:sun:local
2017-03-26 08:58:23.821 [INFO ] [ding.astro.handler.AstroThingHandler] - Scheduled astro job-positional with interval of 300 seconds for thing astro:sun:local
2017-03-26 08:58:24.043 [DEBUG] [rthome.core.common.ThreadPoolManager] - Created thread pool 'items' with size 5
2017-03-26 08:58:24.222 [DEBUG] [.smarthome.config.core.Configuration] - Setting value (Integer) 0 to field 'offset' in configuration class org.openhab.binding.astro.internal.config.AstroChannelConfig
2017-03-26 08:58:24.225 [DEBUG] [.smarthome.config.core.Configuration] - Setting value (Integer) 0 to field 'offset' in configuration class org.openhab.binding.astro.internal.config.AstroChannelConfig
2017-03-26 08:58:24.227 [DEBUG] [.smarthome.config.core.Configuration] - Setting value (Integer) 0 to field 'offset' in configuration class org.openhab.binding.astro.internal.config.AstroChannelConfig
2017-03-26 08:58:24.230 [DEBUG] [.smarthome.config.core.Configuration] - Setting value (Integer) 0 to field 'offset' in configuration class org.openhab.binding.astro.internal.config.AstroChannelConfig
2017-03-26 08:58:24.233 [DEBUG] [.smarthome.config.core.Configuration] - Setting value (Integer) 0 to field 'offset' in configuration class org.openhab.binding.astro.internal.config.AstroChannelConfig
2017-03-26 08:58:24.241 [DEBUG] [.smarthome.config.core.Configuration] - Setting value (Integer) 0 to field 'offset' in configuration class org.openhab.binding.astro.internal.config.AstroChannelConfig
2017-03-26 08:58:24.247 [ERROR] [.astro.internal.job.AbstractDailyJob] - Unable to store Job : 'astro:sun:local.job-event-start-set#event', because one already exists with this identification.
org.quartz.ObjectAlreadyExistsException: Unable to store Job : 'astro:sun:local.job-event-start-set#event', because one already exists with this identification.
	at org.quartz.simpl.RAMJobStore.storeJob(RAMJobStore.java:279)[105:org.eclipse.smarthome.core.scheduler:0.9.0.201703201701]
	at org.quartz.simpl.RAMJobStore.storeJobAndTrigger(RAMJobStore.java:251)[105:org.eclipse.smarthome.core.scheduler:0.9.0.201703201701]
	at org.quartz.core.QuartzScheduler.scheduleJob(QuartzScheduler.java:886)[105:org.eclipse.smarthome.core.scheduler:0.9.0.201703201701]
	at org.quartz.impl.StdScheduler.scheduleJob(StdScheduler.java:249)[105:org.eclipse.smarthome.core.scheduler:0.9.0.201703201701]
	at org.openhab.binding.astro.internal.job.AbstractDailyJob.schedule(AbstractDailyJob.java:105)[179:org.openhab.binding.astro:2.1.0.201703251201]
	at org.openhab.binding.astro.internal.job.AbstractDailyJob.scheduleEvent(AbstractDailyJob.java:72)[179:org.openhab.binding.astro:2.1.0.201703251201]
	at org.openhab.binding.astro.internal.job.AbstractDailyJob.scheduleRange(AbstractDailyJob.java:58)[179:org.openhab.binding.astro:2.1.0.201703251201]
	at org.openhab.binding.astro.internal.job.DailyJobSun.schedulePlanetEvents(DailyJobSun.java:33)[179:org.openhab.binding.astro:2.1.0.201703251201]
	at org.openhab.binding.astro.internal.job.AbstractDailyJob.executeJob(AbstractDailyJob.java:47)[179:org.openhab.binding.astro:2.1.0.201703251201]
	at org.openhab.binding.astro.internal.job.AbstractBaseJob.execute(AbstractBaseJob.java:40)[179:org.openhab.binding.astro:2.1.0.201703251201]
	at org.quartz.core.JobRunShell.run(JobRunShell.java:202)[105:org.eclipse.smarthome.core.scheduler:0.9.0.201703201701]
	at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573)[105:org.eclipse.smarthome.core.scheduler:0.9.0.201703201701]