search

openhab / openhab-addons

Add-ons for openHAB
https://www.openhab.org/
Eclipse Public License 2.0
1.9k stars 3.59k forks source link

[astro] Elevation Cannot Be Float #7082

Closed always-depends closed 4 years ago

always-depends commented 4 years ago

Expected Behavior

The things file for the Astro binding should allow a float type for the elevation.

Current Behavior

Please see this thread in the openHAB community forum: https://community.openhab.org/t/astro-elevation-type-of-integer/93769

I noticed my Astro updates were "stuck". No updates were coming. As I was debugging, I noticed that the elevation parameter in the things file must be an integer and cannot be a float. I previously had it as a float. Once I changed it to an integer and saved the things file, Astro updates started coming in as expected.

I noticed that Astro was stuck on February 28. The stale data dated back to February 13. I'm guessing an update (openHAB and/or Astro) came in on the 12th or 13th of Feb. My logs rotate out after 10 days so unfortunately I'm not sure what may have happened on Feb 13. When I rotate my logs, I also restart openhab2.service (daily at midnight). I'm fairly confident an update broke this since I've had the elevation set as a float for a long time.

Possible Solution

Allow float type for elevation.

Steps to Reproduce (for Bugs)

  1. Enter a float for the elevation in Astro things file: Thing astro:sun:home [ geolocation=",,128.5", interval=1200 ]
  2. Observe that Astro updates stop happening. A restart of the openhab2.service may be needed.
  3. Reverting the setting to an integer fixes the problem: Thing astro:sun:home [ geolocation=",,128", interval=1200 ]

Context

Astro updates stopped and I had very old/stale data.

Your Environment

J-N-K commented 4 years ago

Please "log:set DEBUG org.openhab.binding.astro" and show what the configuration looks like when the thing is initialized.

always-depends commented 4 years ago

Where/How is this command issued? Do I use openhab-cli or...? Thanks.

5iver commented 4 years ago

https://www.openhab.org/docs/administration/logging.html.

always-depends commented 4 years ago

Here's the sequence you request with the elevation as a float:

2020-03-01 08:40:31.402 [INFO ] [el.core.internal.ModelRepositoryImpl] - Refreshing model 'astro.things'
2020-03-01 08:40:31.487 [DEBUG] [o.internal.handler.AstroThingHandler] - Disposing thing astro:sun:home
2020-03-01 08:40:31.488 [DEBUG] [o.internal.handler.AstroThingHandler] - Stopping scheduled jobs for thing astro:sun:home
2020-03-01 08:40:31.489 [DEBUG] [o.internal.handler.AstroThingHandler] - Thing astro:sun:home disposed
2020-03-01 08:40:31.490 [DEBUG] [o.internal.handler.AstroThingHandler] - Initializing thing astro:sun:home
2020-03-01 08:40:31.492 [DEBUG] [o.internal.handler.AstroThingHandler] - AstroThingConfig[thing=astro:sun:home,geolocation=OBFUSCATED,OBFUSCATED,128.5,altitude=128.5,interval=1200,systemTimezone=America/L
os_Angeles (PST -0800),daylightSavings=false]
2020-03-01 08:40:31.493 [DEBUG] [o.internal.handler.AstroThingHandler] - Restarting jobs for thing astro:sun:home
2020-03-01 08:40:31.494 [DEBUG] [o.internal.handler.AstroThingHandler] - Stopping scheduled jobs for thing astro:sun:home
2020-03-01 08:40:31.498 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled org.eclipse.smarthome.core.internal.scheduler.SchedulerImpl$ScheduledCompletableFutureRecurring@600e40[Not completed, 2 dependents] at midnight
2020-03-01 08:40:31.516 [DEBUG] [o.internal.handler.AstroThingHandler] - Publishing planet Sun for thing astro:sun:home
2020-03-01 08:40:31.541 [DEBUG] [enhab.binding.astro.internal.job.Job] - Scheduled Astro event-jobs for thing astro:sun:home
2020-03-01 08:40:31.543 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:home/set#event/START in 32608457ms (at 2020-03-01T17:44:00)
2020-03-01 08:40:31.545 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:home/set#event/END in 32728456ms (at 2020-03-01T17:46:00)
2020-03-01 08:40:31.546 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:home/noon#event/START in 12028454ms (at 2020-03-01T12:01:00)
2020-03-01 08:40:31.551 [INFO ] [e.smarthome.model.script.astro.rules] - {SolarRadiationHighAndLow} Previous state for numSolarRadiationTotal: 320.1777929235619
2020-03-01 08:40:31.552 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:home/noon#event/END in 12088448ms (at 2020-03-01T12:02:00)
2020-03-01 08:40:31.555 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:home/night#event/START in 37648446ms (at 2020-03-01T19:08:00)
2020-03-01 08:40:31.562 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:home/astroDusk#event/START in 35968438ms (at 2020-03-01T18:40:00)
2020-03-01 08:40:31.564 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:home/astroDusk#event/END in 37648436ms (at 2020-03-01T19:08:00)
2020-03-01 08:40:31.566 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:home/nauticDusk#event/START in 34228434ms (at 2020-03-01T18:11:00)
2020-03-01 08:40:31.568 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:home/nauticDusk#event/END in 35968432ms (at 2020-03-01T18:40:00)
2020-03-01 08:40:31.578 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:home/civilDusk#event/START in 32728430ms (at 2020-03-01T17:46:00)
2020-03-01 08:40:31.581 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:home/civilDusk#event/END in 34228419ms (at 2020-03-01T18:11:00)
2020-03-01 08:40:31.583 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:home/eveningNight#event/START in 37648418ms (at 2020-03-01T19:08:00)
2020-03-01 08:40:31.585 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:home/daylight#event/END in 32608416ms (at 2020-03-01T17:44:00)
2020-03-01 08:40:31.587 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Sun phase job astro:sun:home/SUN_SET in 32608414ms (at 2020-03-01T17:44:00)
2020-03-01 08:40:31.588 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Sun phase job astro:sun:home/NIGHT in 37648413ms (at 2020-03-01T19:08:00)
2020-03-01 08:40:31.589 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Sun phase job astro:sun:home/ASTRO_DUSK in 35968411ms (at 2020-03-01T18:40:00)
2020-03-01 08:40:31.590 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Sun phase job astro:sun:home/NAUTIC_DUSK in 34228410ms (at 2020-03-01T18:11:00)
2020-03-01 08:40:31.591 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Sun phase job astro:sun:home/CIVIL_DUSK in 32728409ms (at 2020-03-01T17:46:00)
2020-03-01 08:40:31.592 [INFO ] [o.internal.handler.AstroThingHandler] - Scheduled Positional job astro:sun:home every 1200 seconds
2020-03-01 08:40:31.593 [DEBUG] [o.internal.handler.AstroThingHandler] - Thing astro:sun:home initialized ONLINE
2020-03-01 08:40:31.601 [DEBUG] [o.internal.handler.AstroThingHandler] - Publishing planet Sun for thing astro:sun:home
2020-03-01 08:40:31.614 [DEBUG] [o.internal.handler.AstroThingHandler] - Disposing thing astro:moon:home
2020-03-01 08:40:31.615 [DEBUG] [o.internal.handler.AstroThingHandler] - Stopping scheduled jobs for thing astro:moon:home
2020-03-01 08:40:31.617 [DEBUG] [o.internal.handler.AstroThingHandler] - Thing astro:moon:home disposed
2020-03-01 08:40:31.618 [DEBUG] [o.internal.handler.AstroThingHandler] - Initializing thing astro:moon:home
2020-03-01 08:40:31.620 [DEBUG] [o.internal.handler.AstroThingHandler] - AstroThingConfig[thing=astro:moon:home,geolocation=OBFUSCATED,OBFUSCATED,128.5,altitude=128.5,interval=1200,systemTimezone=America/Los_Angeles (PST -0800),daylightSavings=false]
2020-03-01 08:40:31.621 [DEBUG] [o.internal.handler.AstroThingHandler] - Restarting jobs for thing astro:moon:home
2020-03-01 08:40:31.622 [DEBUG] [o.internal.handler.AstroThingHandler] - Stopping scheduled jobs for thing astro:moon:home
2020-03-01 08:40:31.625 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled org.eclipse.smarthome.core.internal.scheduler.SchedulerImpl$ScheduledCompletableFutureRecurring@143ab9[Not completed, 2 dependents] at midnight
2020-03-01 08:40:31.635 [DEBUG] [o.internal.handler.AstroThingHandler] - Publishing planet Moon for thing astro:moon:home
2020-03-01 08:40:31.638 [DEBUG] [enhab.binding.astro.internal.job.Job] - Scheduled Astro event-jobs for thing astro:moon:home
2020-03-01 08:40:31.640 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:moon:home/rise#event/START in 5548361ms (at 2020-03-01T10:13:00)
2020-03-01 08:40:31.642 [INFO ] [o.internal.handler.AstroThingHandler] - Scheduled Positional job astro:moon:home every 1200 seconds
2020-03-01 08:40:31.643 [DEBUG] [o.internal.handler.AstroThingHandler] - Thing astro:moon:home initialized ONLINE
2020-03-01 08:40:31.647 [DEBUG] [o.internal.handler.AstroThingHandler] - Publishing planet Moon for thing astro:moon:home

I imagine this looks normal, and strangely now I cannot reproduce it.

I restart openhab2.service every day at midnight due to logrotate rotating the logs. You'd assume the stale data issue would only linger until the next restart, but instead it lingered for 15 days. In my troubleshooting, I purged the cache (rm -rf /var/lib/openhab2/cache/*) and restarted openhab2.service and still had stale Astro data. It was not until I changed the elevation to an integer that it started updating the data as expected.

always-depends commented 4 years ago

I see that solar radiation is updating with the expiration of each interval, as expected. I'm not sure how to proceed with this and will yield to your advice.

J-N-K commented 4 years ago

Obviously the altitude is parsed correctly. Maybe leave it at DEBUG for some days and if it happens again, post the last log entries you got from the astro binding.

always-depends commented 4 years ago

Update: The stale Astro data issue came back today. Unfortunately, I had to reboot my Raspberry Pi because of other issues and openHAB came up fine after the reboot. It looks like I will be able to replicate the issue in the next couple of days so please keep this ticket open a while longer. Thanks!

always-depends commented 4 years ago

I see both openHAB and Astro have updated to 2.5.3. I haven't seen the problem for the last 21 days. I'll leave it up to you, but I think we can close this. I'm not terribly familiar with GitHub's bug tracking, but we can either reopen it if that's an option, or file a new one and reference this one should the issue happen again.