OH2 on restart is forgetting all binding and loading the demo binding

[rallek (Ralf Köster)]

• Platform information:
  • Hardware: raspberry3
  • OS: openhabian
  • openHAB version: 2.2
• Issue of the topic:
  I restartet openHAB2 via console with sudo restart now.
  First the restart looks pretty good. All my items are showing up in the logfile. But suddenly several things are deleted. After comming back the default bindings are installed where most of them I deinstalled via PaperUI before. But my MAXbinding was not installed anymore.

The part of the logfile is more than 600 lines. I now try to post the most relevant:

2018-01-31 19:24:01.499 [vent.ItemStateChangedEvent] - maxValveBuero changed from 16 to 0
2018-01-31 19:24:01.519 [vent.ItemStateChangedEvent] - maxActualTempBuero changed from 23.7 to 24.7
2018-01-31 19:24:01.530 [vent.ItemStateChangedEvent] - max_thermostat_NEQ0101554_NEQ0100856_actual_temp changed from 23.7 to 24.7
2018-01-31 19:24:54.843 [vent.ItemStateChangedEvent] - ntp_ntp_local_dateTime changed from 2018-01-31T19:23:54.810+0100 to 2018-01-31T19:24:54.823+0100
2018-01-31 19:24:54.849 [vent.ItemStateChangedEvent] - ntp_ntp_local_string changed from 2018-01-31 19:23:54 CET to 2018-01-31 19:24:54 CET
2018-01-31 19:25:18.556 [hingStatusInfoChangedEvent] - 'ntp:ntp:forstweg' changed from ONLINE to UNINITIALIZED
2018-01-31 19:25:18.562 [hingStatusInfoChangedEvent] - 'ntp:ntp:forstweg' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
2018-01-31 19:25:18.566 [hingStatusInfoChangedEvent] - 'ntp:ntp:local' changed from ONLINE to UNINITIALIZED
2018-01-31 19:25:18.575 [hingStatusInfoChangedEvent] - 'ntp:ntp:local' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
2018-01-31 19:25:18.644 [hingStatusInfoChangedEvent] - 'max:thermostat:NEQ0101554:NEQ0100856' changed from ONLINE to UNINITIALIZED
2018-01-31 19:25:18.652 [hingStatusInfoChangedEvent] - 'max:thermostat:NEQ0101554:NEQ0100856' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
...

around 19:25 I restarted the system

...
2018-01-31 19:25:19.576 [temChannelLinkRemovedEvent] - Link 'maxModeBuero => max:thermostat:NEQ0101554:NEQ0100856:mode' has been removed.
2018-01-31 19:25:19.578 [temChannelLinkRemovedEvent] - Link 'maxSetTempBuero => max:thermostat:NEQ0101554:NEQ0100856:set_temp' has been removed.
...

all channnels have been removed

...
2018-01-31 19:25:53.583 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Locale set to de_DE, Location set to null, Time zone set to Europe/Berlin
2018-01-31 19:26:14.035 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'themostate.items'
2018-01-31 19:26:16.091 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'rrd4j.persist'
2018-01-31 19:26:21.790 [ERROR] [org.apache.felix.scr                ] - Circular reference detected trying to get service {org.openhab.ui.dashboard.DashboardTile}={component.name=org.openhab.io.rest.docs.dashboardtile, component.id=139, service.id=238, service.bundleid=261, service.scope=bundle}
 stack of references: ServiceReference: {org.openhab.ui.dashboard.DashboardTile}={component.name=org.openhab.io.rest.docs.dashboardtile, component.id=139, service.id=238, service.bundleid=261, service.scope=bundle}
...

thermostate.items and rrd4j.persist are reloded. Than an error was showing (I do not understand). After that a lott of numbers and letters. I guess some not readable data plus at the end a long stack trace…

After that we can see the following:

2018-01-31 19:26:22.376 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at http://192.168.1.110:8080
2018-01-31 19:26:22.295 [WARN ] [org.openhab.io.rest.docs            ] - FrameworkEvent WARNING - org.openhab.io.rest.docs
org.osgi.framework.ServiceException: org.apache.felix.scr.impl.manager.SingleComponentManager.getService() returned a null service object

no idea if relevant

2018-01-31 19:26:22.475 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at https://192.168.1.110:8443
2018-01-31 19:26:24.212 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel
2018-01-31 19:26:25.858 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui
2018-01-31 19:26:29.997 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'demo.script'
2018-01-31 19:26:30.330 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'forstweg.sitemap'
2018-01-31 19:26:32.334 [INFO ] [basic.internal.servlet.WebAppServlet] - Started Basic UI at /basicui/app
2018-01-31 19:26:32.662 [vent.ItemStateChangedEvent] - maxSetTempBuero changed from NULL to 21.5
2018-01-31 19:26:32.676 [vent.ItemStateChangedEvent] - maxActualTempBuero changed from NULL to 24.699999999999999289457264239899814128875732421875
2018-01-31 19:26:32.701 [vent.ItemStateChangedEvent] - maxValveBuero changed from NULL to 0
2018-01-31 19:26:32.717 [vent.ItemStateChangedEvent] - maxWandBuero changed from NULL to 22.89999999999999857891452847979962825775146484375
2018-01-31 19:26:32.725 [vent.ItemStateChangedEvent] - maxWandSollBuero changed from NULL to 21.5
2018-01-31 19:26:32.761 [vent.ItemStateChangedEvent] - maxWandBadOben changed from NULL to 18.10000000000000142108547152020037174224853515625
...

Now all values are restored (great! That I was testing by the way)

2018-01-31 19:26:39.204 [vent.ItemStateChangedEvent] - ntp_ntp_local_string changed from NULL to 2018-01-31 19:26:38 CET
2018-01-31 19:26:39.521 [hingStatusInfoChangedEvent] - 'yahooweather:weather:bd6a79ad' changed from INITIALIZING to ONLINE
2018-01-31 19:26:39.527 [vent.ItemStateChangedEvent] - yahooweather_weather_bd6a79ad_temperature changed from NULL to 4
2018-01-31 19:26:39.538 [vent.ItemStateChangedEvent] - yahooweather_weather_bd6a79ad_humidity changed from NULL to 92
2018-01-31 19:26:39.546 [vent.ItemStateChangedEvent] - yahooweather_weather_bd6a79ad_pressure changed from NULL to 985.00
2018-01-31 19:26:39.624 [home.event.InboxAddedEvent] - Discovery Result with UID 'avmfritz:fritzbox:192_168_1_1' has been added.
2018-01-31 19:26:39.614 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'avmfritz:fritzbox:192_168_1_1' to inbox.
...

the above log is the rest of restoring. But stop! Why the FritzBox is added? I did not have had this configured I selected for my FritzBox to be hidden.

2018-01-31 19:26:45.081 [INFO ] [assic.internal.servlet.WebAppServlet] - Started Classic UI at /classicui/app
2018-01-31 19:26:45.259 [INFO ] [ulation.internal.HueEmulationServlet] - Started Hue Emulation service at /api

Why suddenly the Hue Emulation was started? I deleted the Hue Binding in PaperUI before!

2018-01-31 19:26:45.374 [INFO ] [ui.habmin.internal.servlet.HABminApp] - Started HABmin servlet at /habmin
2018-01-31 19:26:45.431 [ERROR] [core.karaf.internal.FeatureInstaller] - Failed installing 'openhab-binding-hue, openhab-binding-ipp, openhab-misc-homekit, openhab-misc-restdocs, openhab-binding-astro, openhab-binding-wemo, openhab-binding-sonos, openhab-misc-hueemulation': Error restarting bundles:

	Unable to acquire the state change lock for the module: osgi.identity; type="osgi.bundle"; version:Version="0.10.0.b1"; osgi.identity="org.eclipse.smarthome.model.script.runtime"; singleton:="true" [id=147] STARTED [STARTED]

All these bindings I deleted already. Why they do apear here?

2018-01-31 19:26:51.088 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'EG_Buero_thermostate.rules'
2018-01-31 19:26:54.398 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'sarah_thermostate.rules'
2018-01-31 19:26:55.160 [INFO ] [thome.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007

until now I am not unhappy. But now I am confused:

2018-01-31 19:26:57.509 [INFO ] [core.karaf.internal.FeatureInstaller] - Uninstalled 'openhab-persistence-mapdb'
==> /var/log/openhab2/events.log <==
2018-01-31 19:26:57.526 [thome.event.ExtensionEvent] - Extension 'persistence-mapdb' has been uninstalled.
==> /var/log/openhab2/openhab.log <==
2018-01-31 19:27:04.057 [INFO ] [me.model.script.OG_Buero_thermostate] - Büro Temperatur mit tempMid initialisiert: 21.5 Fenster CLOSED
2018-01-31 19:27:04.057 [INFO ] [me.model.script.OG_Buero_thermostate] - Büro 21.5 vs Thermostat  21.5 Fenster CLOSED 0
2018-01-31 19:27:07.549 [INFO ] [core.karaf.internal.FeatureInstaller] - Uninstalled 'openhab-binding-silvercrestwifisocket'
==> /var/log/openhab2/events.log <==
2018-01-31 19:27:07.557 [thome.event.ExtensionEvent] - Extension 'binding-silvercrestwifisocket' has been uninstalled.
==> /var/log/openhab2/openhab.log <==
2018-01-31 19:27:12.926 [INFO ] [assic.internal.servlet.WebAppServlet] - Stopped Classic UI
2018-01-31 19:27:13.020 [INFO ] [core.karaf.internal.FeatureInstaller] - Uninstalled 'openhab-ui-classic'
==> /var/log/openhab2/events.log <==
2018-01-31 19:27:13.025 [thome.event.ExtensionEvent] - Extension 'ui-classic' has been uninstalled.
==> /var/log/openhab2/openhab.log <==
2018-01-31 19:27:19.144 [INFO ] [ui.habmin.internal.servlet.HABminApp] - Stopped HABmin servlet
2018-01-31 19:27:19.235 [INFO ] [core.karaf.internal.FeatureInstaller] - Uninstalled 'openhab-ui-habmin'
==> /var/log/openhab2/events.log <==
2018-01-31 19:27:19.239 [thome.event.ExtensionEvent] - Extension 'ui-habmin' has been uninstalled.
==> /var/log/openhab2/openhab.log <==
2018-01-31 19:27:26.207 [INFO ] [core.karaf.internal.FeatureInstaller] - Uninstalled 'openhab-binding-network'
...

Now all the installed getting uninstalled! Why?

...
2018-01-31 19:27:33.697 [hingStatusInfoChangedEvent] - 'max:shuttercontact:NEQ0101554:NEQ0100026' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
2018-01-31 19:27:33.705 [hingStatusInfoChangedEvent] - 'max:bridge:NEQ0101554' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
==> /var/log/openhab2/openhab.log <==
2018-01-31 19:27:33.744 [INFO ] [core.karaf.internal.FeatureInstaller] - Uninstalled 'openhab-binding-max'
...

at the end my MAX binding got uninstalled as well.

After reinstalling the MAX binding via PaperUI all items are reinstalled.

What did I wrong? All demo binding are again there but I unistalled them before my restart (days ago). My important MAX Binding was missing.
How can I make my installation more robust?
Is it me or is it a bug?

[rlkoshak (Rich Koshak)]

Ave you edited at any time addons.cfg?

[rallek (Ralf Köster)]

no. Nothing of cfg files I edited.

[rallek (Ralf Köster)]

I think shorty707’s comment gets close to what I think could be a viable solution to making text files and other confuration mechanisms coexistst, as Kai Kreuzer puts it. A key issue in this discussion so far has been the fact that config files are read-only (and I think they should be), which makes overriding anything they specify difficult to do, if you don’t want to either confuse your users and at the same time make the system accessible. Hence, the two (read-only config files + dynamic co…

Have to read this in detail. Might be I found my answer there.

[rallek (Ralf Köster)]

I found another addon.config file: \OPENHABIANPI\openHAB-share\openhab2-userdata\config\org\openhab\addons.config

This do have the content:

binding="yahooweather,astro,ntp,max,network,fsinternetradio"
felix.fileinstall.filename="file:/var/lib/openhab2/etc/org.openhab.addons.cfg"
misc="restdocs,homekit,hueemulation"
package="demo"
persistence="rrd4j"
service.pid="org.openhab.addons"
transformation="map"
ui="basic,paper,habpanel,habmin"

Is that relevant?

[job (Joachim Boeddeker)]

I think so. In my opinion the double quotes are wrong.

Have look here, different symptoms but similar problem.

Feature-Installer: Failed installing 'openhab-package-"expert"

I started over with a clean installation of openHAB 2.1 a few days ago, but everytime the system starts i get the following error message: [ERROR] [core.karaf.internal.FeatureInstaller] - Failed installing 'openhab-package-"expert"': No matching features for openhab-package-"expert"/0.0.0 It looks like a leftover from the initial install. Apart from the message i do not see any related problems. How do i get rid of this error message? Thanks for any info.

[rallek (Ralf Köster)]

Hi Job,

that config I never touched. It was comming together with my installation.

[job (Joachim Boeddeker)]

I didn’t say you inserted the double quotes, just that these are wrong in my opinion.

Try the following:

• remove the double quotes (on the package names first, the filename may be ok)
• remove unused bindings
• install used bindings again
• restart openHAB

What happens now?

[rallek (Ralf Köster)]

I am very new to openHAB. Therfore some question:

• remove the double quotes -> clear to me
• remove unused bindings -> via PaperUI? or in addons.config?
• install unused binding -> via PaperUI? They are already deleted
• restart openHAB -> What is the correct way? Via ssh restart of the rasPi?

Sorry for these beginner questions

[rallek (Ralf Köster)]

I removed the quotes. Than I went to PaperUI to delete the misc entries. After saving the quotes are back!

[job (Joachim Boeddeker)]

I always use PaperUI for adding or removing addons, never used the config for that.
Before removing the quotes, it would be best to stop openHAB. (Maybe some config is still in memory and is saved before the stopping.)

stop:

sudo systemctl stop openhab2.service

start:

sudo systemctl start openhab2.service

restart (works like start if openHAB is stopped):

sudo systemctl restart openhab2.service

[rallek (Ralf Köster)]

followed your instruction. The restart went well. No side effects like the first restart. But the quotes are back

Will now simulate a power blackout.

One Question I do have from the restart:
what does the entry package = "demo" mean?

I changed that before restart to package = standard but it is now switched back to demo after restart.

[job (Joachim Boeddeker)]

Did you change the quotes in this file?

/var/lib/openhab2/etc/org.openhab.addons.cfg

or in this (i have no idea where this points to, maybe /usr/share/openhab2/…)?

\OPENHABIANPI\openHAB-share\openhab2-userdata\config\org\openhab\addons.config

please change in both, on is the source of the other, no idea which is which.

[rallek (Ralf Köster)]

here my addons.cfg:

# The installation package of this openHAB instance
# Note: This is only regarded at the VERY FIRST START of openHAB
# Note: If you want to specify your add-ons yourself through entries below, set the package to "minimal"
# as otherwise your definition might be in conflict with what the installation package defines.
#
# Optional. If not set, the dashboard (https://<yourserver>:8080/) will ask you to choose a package.
#
# Valid options:
#   - minimal  : Installation only with dashboard, but no UIs or other add-ons. Use this for custom setups.
#   - simple   : Setup for using openHAB purely through UIs - you need to expect MANY constraints in functionality!
#   - standard : Default setup for normal users, best for textual setup
#   - expert   : Setup for expert users, especially for people migrating from openHAB 1.x
#   - demo     : A demo setup which includes UIs, a few bindings, config files etc.
#
# See http://docs.openhab.org/configuration/packages.html for a detailed explanation of these packages.
#
#package = minimal

# Access Remote Add-on Repository
# Defines whether the remote openHAB add-on repository should be used for browsing and installing add-ons.
# This not only makes latest snapshots of add-ons available, it is also required for the installation of
# any legacy 1.x add-on. (default is true)
#
#remote = true

# Include legacy 1.x bindings. If set to true, it also allows the installation of 1.x bindings for which there is 
# already a 2.x version available (requires remote repo access, see above). (default is false)
#
#legacy = true

# A comma-separated list of bindings to install (e.g. "sonos,knx,zwave")
#binding = 

# A comma-separated list of UIs to install (e.g. "basic,paper")
#ui = 

# A comma-separated list of persistence services to install (e.g. "rrd4j,jpa")
#persistence = 

# A comma-separated list of actions to install (e.g. "mail,pushover")
#action = 

# A comma-separated list of transformation services to install (e.g. "map,jsonpath")
#transformation = 

# A comma-separated list of voice services to install (e.g. "marytts,freetts")
#voice = 

# A comma-separated list of miscellaneous services to install (e.g. "myopenhab")
#misc = 

That is empty.

If I install the bindings etc via PaperUI the configuration should be in the jsondb (I guess).

[rallek (Ralf Köster)]

My answer about package I could found via the link inside addions.cfg.

I am comming to the conclusion I will backup my current configuration and restart with a new setup with standard. there seems to be some issues with the demo configuration.

Thank you for helping so far.

[job (Joachim Boeddeker)]

Maybe that’s the best you can do. Something is strange. Good luck. (i started several times over)