search

openhab / openhab1-addons

Add-ons for openHAB 1.x
Eclipse Public License 2.0
3.43k stars 1.71k forks source link

Binding sometimes not starting correctly. #4452

Closed gumulka closed 7 years ago

gumulka commented 8 years ago

Expected Behavior

A binding should always start the same way. Not be broken on one startup and running on the next.

Current Behavior

Sometimes, when rebooting the system, the weather binding does not start correctly. If I enable debug in the logback.xml I see the following lines in the openhab.log:

2016-06-07 09:39:50.234 [DEBUG] [o.o.b.w.i.bus.WeatherActivator] - Weather binding has been started. 2016-06-07 09:39:50.353 [DEBUG] [.WeatherGenericBindingProvider] - Adding item Outside_Temperature with WeatherBindingConfig[locationId=home,type=temperature,property=current,roundingMode=HALF_UP,scale=2] 2016-06-07 09:39:50.689 [DEBUG] [.w.internal.gfx.WeatherServlet] - Starting up weather servlet at /weather

but the Item is never updated nor are there any more log messages from the Weather binding.

Sometimes a reboot fixes it. Sometimes I have to reboot 4-5 times until the weather starts working and I see the complete: 2016-06-07 09:48:23.575 [DEBUG] [o.o.b.w.i.bus.WeatherActivator] - Weather binding has been started. 2016-06-07 09:48:23.833 [DEBUG] [.WeatherGenericBindingProvider] - Adding item Outside_Temperature with WeatherBindingConfig[locationId=home,type=temperature,property=current,roundingMode=HALF_UP,scale=2] 2016-06-07 09:48:24.226 [DEBUG] [.w.internal.gfx.WeatherServlet] - Starting up weather servlet at /weather ... 2016-06-07 09:48:26.469 [INFO ] [o.o.b.w.i.common.WeatherConfig] - ProviderConfig[providerName=OPENWEATHERMAP,apiKey=4baa2919d793e505728fd9bd5d061220] 2016-06-07 09:48:26.484 [INFO ] [o.o.b.w.i.common.WeatherConfig] - LocationConfig[providerName=OPENWEATHERMAP,language=de,updateInterval=20,latitude=52.370522,longitude=9.73322,woeid=,locationId=home,name=zuhause]

The same behavior can also be found with the network health binding. The complete log of two consecuative reboots without any changes in the system can be found here: openhab.log.txt (pulled 10 minutes after last write to it)

Sometimes I get even bizarrer logiles like these: openhab.log2.txt

Possible Solution

I am guessing on some race conditions on startup, which are sometimes met and sometimes don't. But I don't see any errors in the logfile.

Steps to Reproduce (for bugs)

Has been like this since installation.

Context

N/A

Your Environment

System: Raspberry Pi 3 with raspbian 8 (jessie) Linux OpenHab 4.4.11-v7+ #888 SMP Mon May 23 20:10:33 BST 2016 armv7l GNU/Linux Firmware version faf071dd4885c5ac1a89483d35a5326e7f69495f (clean) (release)

Openhab 1.8.3 installed via apt-get Java(TM) SE Runtime Environment (build 1.8.0_65-b17)

Installed bindings: org.openhab.action.telegram-1.8.3.jar org.openhab.binding.exec-1.8.3.jar org.openhab.binding.maxcube-1.8.3.jar org.openhab.binding.weather-1.8.3.jar org.openhab.io.myopenhab-1.8.3.jar org.openhab.action.xbmc-1.8.3.jar org.openhab.binding.gpio-1.9.0-SNAPSHOT.jar org.openhab.binding.networkhealth-1.8.3.jar org.openhab.binding.xbmc-1.8.3.jar org.openhab.persistence.mysql-1.8.3.jar org.openhab.binding.astro-1.8.3.jar org.openhab.binding.hue-1.8.3.jar org.openhab.binding.pioneeravr-1.8.3.jar org.openhab.io.gpio-1.9.0-SNAPSHOT.jar

9037568 commented 8 years ago

I've been working on fixing some silent failure issues in the weather binding (see #4337), but this sounds a bit different from that...

To narrow down the problem, it would be a good idea to try running with only the "failing" binding installed and see if the behaviour remains the same. If it doesn't, then one of the other bindings may be causing issues...

I noticed in your "2 Consecutive Runs" log that the astro binding didn't start in the first run.

gumulka commented 8 years ago

I've read your Issue, but since mine is correctly configured, I thought this to be two different Problems.

Yeah, this could be the case, the problem could be in many more bindings, but since I plot a temperature graph, for this binding it is the most obvious for me. I've also written, that this is frequently the problem with network health binding, but the list might also be longer.