Astro Sunset Start and End same values

It appears that the start and end channels of the sunset element in the astro binding are reporting the same value. This is not the case for the sunrise element.

Things:

DateTime  Astro_Sunrise_Start  <sunrise>  (AstroSun)  {channel="astro:sun:local:rise#start"}
DateTime  Astro_Sunrise_End    <sunrise>  (AstroSun)  {channel="astro:sun:local:rise#end"}

DateTime  Astro_Noon_Start     <sun>      (AstroSun)  {channel="astro:sun:local:noon#start"}
DateTime  Astro_Noon_End       <sun>      (AstroSun)  {channel="astro:sun:local:noon#end"}

DateTime  Astro_Sunset_Start   <sunset>   (AstroSun)  {channel="astro:sun:local:set#start"}
DateTime  Astro_Sunset_End     <sunset>   (AstroSun)  {channel="astro:sun:local:set#end"}

Sitemap:

Default item=Astro_Sunrise_Start icon="sunrise"	label="Sunrise start [%1$tH:%1$tM]"
Default item=Astro_Sunrise_End   icon="sunrise"	label="Sunrise end [%1$tH:%1$tM]"
Default item=Astro_Noon_Start    icon="sun"     label="Noon start [%1$tH:%1$tM]"
Default item=Astro_Noon_End      icon="sun"     label="Noon end [%1$tH:%1$tM]"
Default item=Astro_Sunset_Start  icon="sunset"  label="Sunset start [%1$tH:%1$tM]"
Default item=Astro_Sunset_End    icon="sunset"  label="Sunset end [%1$tH:%1$tM]"

Result:

Item Value
Sunrise start 08:01
Sunrise end 08:05
Noon start 12:58
Noon end 12:59
Sunset start 17:54
Sunset end 17:54

I suppose the double sunset value is a mistake (I’d expect similar timings between start and end of sunrise and sunset events).

I also notice there is only 1 minute between start and end of noon, but that’s probably due to rounding to the closest minute.

Indeed, formatting the time as %1$tH:%1$tM (or the equivalent shorthand %1$tR) or as %1$tT doesn’t give second-accuracy values (every value is rounded to the nearest minute). Just in case, if you need your timezone, you should use %1$tZ.

In the event log, right after midnight I see:

2019-02-14 00:00:30.713 [vent.ItemStateChangedEvent] - Astro_Sunrise_Start changed from 2019-02-13T08:01:00.000+0100 to 2019-02-14T07:59:00.000+0100
2019-02-14 00:00:30.715 [vent.ItemStateChangedEvent] - Astro_Sunrise_End changed from 2019-02-13T08:05:00.000+0100 to 2019-02-14T08:03:00.000+0100
2019-02-14 00:00:30.758 [vent.ItemStateChangedEvent] - Astro_Sunset_Start changed from 2019-02-13T17:54:00.000+0100 to 2019-02-14T17:52:00.000+0100
2019-02-14 00:00:30.779 [vent.ItemStateChangedEvent] - Astro_Sunset_End changed from 2019-02-13T17:54:00.000+0100 to 2019-02-14T17:56:00.000+0100

From then on I get every 5 minutes the following event log entry (filtered to see only sunrise and sunset related events):

2019-02-14 00:00:30.780 [vent.ItemStateChangedEvent] - Astro_ Sunset _Start changed from 2019-02-14T17:52:00.000+0100 to 2019-02-14T17:56:00.000+0100
2019-02-14 00:04:01.007 [vent.ItemStateChangedEvent] - Astro_ Sunset _Start changed from 2019-02-14T17:56:00.000+0100 to 2019-02-14T17:52:00.000+0100
2019-02-14 00:04:01.033 [vent.ItemStateChangedEvent] - Astro_ Sunset _Start changed from 2019-02-14T17:52:00.000+0100 to 2019-02-14T17:56:00.000+0100
2019-02-14 00:09:00.991 [vent.ItemStateChangedEvent] - Astro_ Sunset _Start changed from 2019-02-14T17:56:00.000+0100 to 2019-02-14T17:52:00.000+0100

In the openhab log, I see the following messages around the same time (off by 1 minute):

2019-02-14 00:00:30.333 [INFO ] [thome.binding.astro.internal.job.Job] - Scheduled Astro event-jobs for thing astro:moon:local
2019-02-14 00:00:30.722 [INFO ] [thome.binding.astro.internal.job.Job] - Scheduled Astro event-jobs for thing astro:sun:local
2019-02-14 00:05:00.333 [ERROR] [e.internal.WriterInterceptorExecutor] - MessageBodyWriter not found for media type=text/event-stream, type=class org.glassfish.jersey.media.sse.OutboundEvent, genericType=class org.glassfish.jersey.media.sse.OutboundEvent.
2019-02-14 00:10:00.333 [ERROR] [e.internal.WriterInterceptorExecutor] - MessageBodyWriter not found for media type=text/event-stream, type=class org.glassfish.jersey.media.sse.OutboundEvent, genericType=class org.glassfish.jersey.media.sse.OutboundEvent.
2019-02-14 00:15:00.333 [ERROR] [e.internal.WriterInterceptorExecutor] - MessageBodyWriter not found for media type=text/event-stream, type=class org.glassfish.jersey.media.sse.OutboundEvent, genericType=class org.glassfish.jersey.media.sse.OutboundEvent.
2019-02-14 00:20:00.333 [ERROR] [e.internal.WriterInterceptorExecutor] - MessageBodyWriter not found for media type=text/event-stream, type=class org.glassfish.jersey.media.sse.OutboundEvent, genericType=class org.glassfish.jersey.media.sse.OutboundEvent.
2019-02-14 00:25:00.333 [ERROR] [e.internal.WriterInterceptorExecutor] - MessageBodyWriter not found for media type=text/event-stream, type=class org.glassfish.jersey.media.sse.OutboundEvent, genericType=class org.glassfish.jersey.media.sse.OutboundEvent.

Looking more closely at the event log, I see the following (unfiltered) log entries:

2019-02-10 00:01:15.751 [vent.ItemStateChangedEvent] - astro_moon_local_phase_ageDegree changed from 61.388823356643364 ° to 61.395207832167834 °
2019-02-10 00:01:15.752 [vent.ItemStateChangedEvent] - astro_moon_local_phase_agePercent changed from 17.052450932400934 % to 17.0542243978244 %
2019-02-10 00:01:15.753 [vent.ItemStateChangedEvent] - astro_moon_local_phase_illumination changed from 21.748130305537998 % to 21.75237435456608 %
2019-02-10 00:01:15.753 [vent.ItemStateChangedEvent] - astro_moon_local_distance_date changed from 2019-02-10T00:00:30.087+0100 to 2019-02-10T00:01:15.736+0100
2019-02-10 00:01:15.755 [vent.ItemStateChangedEvent] - astro_moon_local_distance_distance changed from 399024.21048672224 km to 399022.3604295172 km
2019-02-10 00:01:15.756 [vent.ItemStateChangedEvent] - astro_moon_local_position_azimuth changed from 288.71076003048614 ° to 288.8641721718961 °
2019-02-10 00:01:15.756 [vent.ItemStateChangedEvent] - astro_moon_local_position_elevation changed from -13.165320515049142 ° to -13.272783262713583 °
2019-02-10 00:01:16.748 [vent.ItemStateChangedEvent] - astro_sun_local_position_azimuth changed from 337.6138484485739 ° to 337.9090614278761 °
2019-02-10 00:01:16.750 [vent.ItemStateChangedEvent] - astro_sun_local_position_elevation changed from -51.78774597897857 ° to -51.83379157079161 °
2019-02-10 00:01:54.325 [vent.ItemStateChangedEvent] - ntp_ntp_local_dateTime changed from 2019-02-10T00:00:54.319+0100 to 2019-02-10T00:01:54.320+0100
2019-02-10 00:01:54.327 [vent.ItemStateChangedEvent] - ntp_ntp_local_string changed from 2019-02-10 00:00:54 CET to 2019-02-10 00:01:54 CET
2019-02-10 00:02:54.326 [vent.ItemStateChangedEvent] - ntp_ntp_local_dateTime changed from 2019-02-10T00:01:54.320+0100 to 2019-02-10T00:02:54.321+0100
2019-02-10 00:02:54.327 [vent.ItemStateChangedEvent] - ntp_ntp_local_string changed from 2019-02-10 00:01:54 CET to 2019-02-10 00:02:54 CET
2019-02-10 00:03:54.328 [vent.ItemStateChangedEvent] - ntp_ntp_local_dateTime changed from 2019-02-10T00:02:54.321+0100 to 2019-02-10T00:03:54.323+0100
2019-02-10 00:03:54.329 [vent.ItemStateChangedEvent] - ntp_ntp_local_string changed from 2019-02-10 00:02:54 CET to 2019-02-10 00:03:54 CET
2019-02-10 00:04:54.339 [vent.ItemStateChangedEvent] - ntp_ntp_local_dateTime changed from 2019-02-10T00:03:54.323+0100 to 2019-02-10T00:04:54.324+0100
2019-02-10 00:04:54.339 [vent.ItemStateChangedEvent] - ntp_ntp_local_string changed from 2019-02-10 00:03:54 CET to 2019-02-10 00:04:54 CET
2019-02-10 00:05:54.330 [vent.ItemStateChangedEvent] - ntp_ntp_local_dateTime changed from 2019-02-10T00:04:54.324+0100 to 2019-02-10T00:05:54.325+0100
2019-02-10 00:05:54.332 [vent.ItemStateChangedEvent] - ntp_ntp_local_string changed from 2019-02-10 00:04:54 CET to 2019-02-10 00:05:54 CET
2019-02-10 00:06:15.756 [vent.ItemStateChangedEvent] - astro_moon_local_phase_ageDegree changed from 61.395207832167834 ° to 61.43716587412588 °

Just in case this helps finding the problem.