mapDB: problem with restoreOnStartup

Add-ons Persistence Services
1

I use persistence to store scene values.
Everything seems to work fine, with the exeception of restoreOnStartup.
Here is what I’ve done:

file.items - extract

Number Salontafel_scene1 (gScenes)
Number Salontafel_scene2 (gScenes)
Number Salontafel_scene3 (gScenes)
Number Salontafel_scene4 (gScenes)
Number Schemerlamp_scene1 (gScenes)
Number Schemerlamp_scene2 (gScenes)
…

file.rules

Persistence is defined for the group gScenes the following way:
Items {
gScenes*: strategy = restoreOnStartup, everyChange_
}

openhab.log

Debugging has been activated in the logback.xml file with the following result
pi@pi3 /var/log/openhab $ tail -f openhab.log | grep -i mapdb
2016-06-28 17:01:32.997 [DEBUG] [.p.m.i.MapDBPersistenceService] - Stored ‘Schemerlamp_scene3’ with state ‘35’ in mapdb database
2016-06-28 17:01:33.142 [DEBUG] [.p.m.i.MapDBPersistenceService] - store called for SpotKast_scene3
2016-06-28 17:01:33.146 [DEBUG] [.p.m.i.MapDBPersistenceService] - Stored ‘SpotKast_scene3’ with state ‘14’ in mapdb database
2016-06-28 17:01:33.289 [DEBUG] [.p.m.i.MapDBPersistenceService] - store called for SpotsBank_scene3
2016-06-28 17:01:33.292 [DEBUG] [.p.m.i.MapDBPersistenceService] - Stored ‘SpotsBank_scene3’ with state ‘14’ in mapdb database
2016-06-28 17:01:33.433 [DEBUG] [.p.m.i.MapDBPersistenceService] - store called for Piano_scene3
2016-06-28 17:01:33.438 [DEBUG] [.p.m.i.MapDBPersistenceService] - Stored ‘Piano_scene3’ with state ‘ON’ in mapdb database
2016-06-28 17:01:33.603 [DEBUG] [.p.m.i.MapDBPersistenceService] - store called for Eettafel_scene3
2016-06-28 17:01:33.607 [DEBUG] [.p.m.i.MapDBPersistenceService] - Stored ‘Eettafel_scene3’ with state ‘1’ in mapdb database
====> HERE OPENHAB SERVICE IS MANUALLY RESTARTED
2016-06-28 17:03:20.353 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'mapdb.persist’
2016-06-28 17:03:31.052 [DEBUG] [.m.i.MapDBPersistenceActivator] - MapDB persistence bundle has been started.
2016-06-28 17:03:31.086 [DEBUG] [.p.m.i.MapDBPersistenceService] - mapdb persistence service activated
2016-06-28 17:03:31.660 [DEBUG] [.p.m.i.MapDBPersistenceService] - Scheduled Commit-Job with interval 5sec.

restoreOnStartup

I would expect to see some DEBUG line(s) related to the restoreOnStartup setting.
When now a rule uses one of the settings, it is reported as “Uninitialized” (by one of the LogDebug lines I have added to keep track):

2016-06-29 09:06:58.882 [DEBUG] [org.openhab.model.script.EvG ] - recallScene: Schemerlamp_scene3: Uninitialized

PS: the files in /var/lib/openhab/persistence/mapdb seem to be correctly updated after each “store” activity.

Question

Anyone a clue how to get this working?

2

The definition for persistence should look like

File name: ./configurations/persistence/mapdb.persist

Items {
    gScenes* : strategy = everyChange, restoreOnStartup
}

If you want to use the persisted values in a rule triggered by “System started”, be aware, that openHAB is asynchronous and therefore maybe the rule will be started before the values are restored. I use a simple delay to catch this pitfall:

rule "System_started"
when
    System started
then
    createTimer(now.plusSeconds(30), [|
        var Calendar cal = Calendar::getInstance()
        cal.setTime(Caller.lastUpdate("mysql"))
        Calltime.postUpdate(new DateTimeType(cal))
    ])
end

after 30 seconds, the connection to mysql should already be established. This example does not use restoreOnStartup, though.

3

Udo, tnx for your quick response.

The .persist filename & content is (and was) corresponding to your definition.
Only my message contained some corruption due tot copy/past/formatting issues.
Fact that mapdb storage side is working as expected, should be a proof of a (at least partially) proper persistence definition.

My “recallScene” rule is manually invoked through the user i/f (not automatically @ system_started) so it should not affected by the concurrency/asynchronicity between rules and persistence definitions after startup.

Question remains (as this is my first persistence experience with openHAB):
is my expectation correct that this persistence definition itself should be sufficient for the “restoreOnStartup” to be successful?

Just to be complete, I have included the full mapdb.persist file below:
#mapdb.persist

Strategies {
everyMinute : "0 * * * * ?"
everyHour : "0 0 * * * ?"
everyDay : “0 0 0 * * ?”

default = everyChange, restoreOnStartup

}

Items {
gScenes* : strategy = everyChange, restoreOnStartup
}

4

Yes, that should be sufficient. Here is my mapdb.persist. I only use MapDB for restoreOnStartup and I restore everything.

Strategies {
        default = everyUpdate
}

Items {
        // persist all items on every change and restore them from the db at startup
        * : strategy = everyChange, restoreOnStartup
}
4 Likes
5

Used your mapdb.persist file.
Looking at the openhab.log file with DEBUG activated, I notice storage activities for all items that change state. Nevertheless after a reboot, I don’t see any “restore” activities in the log file and I notice that states of items have not been restored.

Could you drop me the output your logfile after a reboot to see how mapdb restore activities look like.
PS: debugging activated by adding following line in your /etc/openhab/logback.xml file.

#logback.xml

6

< logger name=“org.openhab.persistence.mapdb” level=“DEBUG” />

7

Here is what MapDB prints out. I don’t see any restore logs but my Items none of my Items come up as undefined meaning their values are being restored.

 2016-06-29 10:09:53.943 [DEBUG] [.m.i.MapDBPersistenceActivator] - MapDB persistence bundle has been started.
 2016-06-29 10:09:53.962 [DEBUG] [.p.m.i.MapDBPersistenceService] - mapdb persistence service activated
 2016-06-29 10:09:54.303 [DEBUG] [.p.m.i.MapDBPersistenceService] - Scheduled Commit-Job with interval 5sec.
 2016-06-29 10:09:56.389 [DEBUG] [.p.m.i.MapDBPersistenceService] - store called for Weather_Precip_Today
 2016-06-29 10:09:56.416 [DEBUG] [.p.m.i.MapDBPersistenceService] - Stored 'Weather_Precip_Today' with state '0.00' in mapdb database
 2016-06-29 10:09:56.580 [DEBUG] [.p.m.i.MapDBPersistenceService] - store called for gJennPresent
 2016-06-29 10:09:56.582 [DEBUG] [.p.m.i.MapDBPersistenceService] - Stored 'gJennPresent' with state 'ON' in mapdb database
 2016-06-29 10:09:56.589 [DEBUG] [.p.m.i.MapDBPersistenceService] - store called for gChimeraSensors
 2016-06-29 10:09:56.591 [DEBUG] [.p.m.i.MapDBPersistenceService] - Stored 'gChimeraSensors' with state 'OFF' in mapdb database
 2016-06-29 10:09:56.601 [DEBUG] [.p.m.i.MapDBPersistenceService] - store called for gJennPresent
 2016-06-29 10:09:56.589 [DEBUG] [.p.m.i.MapDBPersistenceService] - store called for gChimeraSensors
 2016-06-29 10:09:56.591 [DEBUG] [.p.m.i.MapDBPersistenceService] - Stored 'gChimeraSensors' with state 'OFF' in mapdb database
 2016-06-29 10:09:56.601 [DEBUG] [.p.m.i.MapDBPersistenceService] - store called for gJennPresent
 2016-06-29 10:09:56.602 [DEBUG] [.p.m.i.MapDBPersistenceService] - Stored 'gJennPresent' with state 'OFF' in mapdb database
 2016-06-29 10:09:56.674 [DEBUG] [.p.m.i.MapDBPersistenceService] - store called for gWeatherLights
 2016-06-29 10:09:56.675 [DEBUG] [.p.m.i.MapDBPersistenceService] - Stored 'gWeatherLights' with state 'OFF' in mapdb database
 2016-06-29 10:09:56.679 [DEBUG] [.p.m.i.MapDBPersistenceService] - store called for gTwilightLightsON
 2016-06-29 10:09:56.680 [DEBUG] [.p.m.i.MapDBPersistenceService] - Stored 'gTwilightLightsON' with state 'OFF' in mapdb database
 2016-06-29 10:09:56.693 [DEBUG] [.p.m.i.MapDBPersistenceService] - store called for gEveningLightsOFF
 2016-06-29 10:09:56.695 [DEBUG] [.p.m.i.MapDBPersistenceService] - Stored 'gEveningLightsOFF' with state 'OFF' in mapdb database
 2016-06-29 10:09:56.701 [DEBUG] [.p.m.i.MapDBPersistenceService] - store called for gLightsOverride
 2016-06-29 10:09:56.703 [DEBUG] [.p.m.i.MapDBPersistenceService] - Stored 'gLightsOverride' with state 'OFF' in mapdb database
 2016-06-29 10:09:56.799 [DEBUG] [.p.m.i.MapDBPersistenceService] - store called for gRemindDoorSensors
 2016-06-29 10:09:56.800 [DEBUG] [.p.m.i.MapDBPersistenceService] - Stored 'gRemindDoorSensors' with state 'CLOSED' in mapdb database
 2016-06-29 10:09:56.808 [DEBUG] [.p.m.i.MapDBPersistenceService] - store called for gCOSmoke_Battery
 2016-06-29 10:09:56.830 [DEBUG] [.p.m.i.MapDBPersistenceService] - Stored 'gCOSmoke_Battery' with state '86' in mapdb database
 2016-06-29 10:09:56.845 [DEBUG] [.p.m.i.MapDBPersistenceService] - store called for gBattery
 2016-06-29 10:09:56.855 [DEBUG] [.p.m.i.MapDBPersistenceService] - Stored 'gBattery' with state '86' in mapdb database
 2016-06-29 10:09:56.866 [DEBUG] [.p.m.i.MapDBPersistenceService] - store called for gCOSmoke_Battery
 2016-06-29 10:09:56.869 [DEBUG] [.p.m.i.MapDBPersistenceService] - Stored 'gCOSmoke_Battery' with state '85' in mapdb database
 2016-06-29 10:09:56.872 [DEBUG] [.p.m.i.MapDBPersistenceService] - store called for gBattery
 2016-06-29 10:09:56.876 [DEBUG] [.p.m.i.MapDBPersistenceService] - Stored 'gBattery' with state '85' in mapdb database
 2016-06-29 10:09:57.014 [DEBUG] [.p.m.i.MapDBPersistenceService] - store called for gCerberosNet
 2016-06-29 10:09:57.016 [DEBUG] [.p.m.i.MapDBPersistenceService] - Stored 'gCerberosNet' with state 'ON' in mapdb database
 2016-06-29 10:09:57.051 [DEBUG] [.p.m.i.MapDBPersistenceService] - store called for gHydraNet
 2016-06-29 10:09:57.062 [DEBUG] [.p.m.i.MapDBPersistenceService] - Stored 'gHydraNet' with state 'ON' in mapdb database
 2016-06-29 10:09:57.065 [DEBUG] [.p.m.i.MapDBPersistenceService] - store called for gRemoteSensors
 2016-06-29 10:09:57.074 [DEBUG] [.p.m.i.MapDBPersistenceService] - Stored 'gRemoteSensors' with state 'ON' in mapdb database
 2016-06-29 10:10:08.791 [DEBUG] [.p.m.i.MapDBPersistenceService] - store called for PreviousTimeOfDay
 2016-06-29 10:10:08.793 [DEBUG] [.p.m.i.MapDBPersistenceService] - Stored 'PreviousTimeOfDay' with state 'Morning' in mapdb database
 2016-06-29 10:10:51.725 [DEBUG] [.p.m.i.MapDBPersistenceService] - store called for S_L_Front_Override
 2016-06-29 10:10:51.730 [DEBUG] [.p.m.i.MapDBPersistenceService] - Stored 'S_L_Front_Override' with state 'ON' in mapdb database
8

Rich, good to know restoreOnStartup doesn’t show up in openhab.log.

In order to further trace my problem, I did two things:
a) mapdb.rules: reduced restoreOnStartup strategy to one group (gScenes)
filename.items: included 1 items with binding to gScenes group
b) filename.rules: added rule that prints out values 30 seconds after system startup, of all items belonging to group gScenes

=> This works OK :slight_smile:

After undoing above changes, restoreOnStartup behaviour is still OK
(even after removing /var/lib/openhab/mapdb/storage.mapdb* file, assigning values for scenes through user i/f, then restart openhab)!

Although I still do not understand why it didn’t work before, I am happy to have come this far with help from this community!

9

I have a similar problem. I use openhab2 with the mapdb persistence to restore state on startup. However although I can see that the state is written on every change the restore is ignored. After restarting openhab all the items have a value of NULL.

Any ideas?

My mapdb.persistence looks like:

Items {
g_persist_restore_startup*: strategy=everyChange, restoreOnStartup

}

If i turn on debug logging I get the following log on startup where I can see that the mapdb service is started but nothing about restore

2016-07-23 13:16:58.065 [DEBUG] [org.openhab.io.jetty.certificate ] - BundleEvent STARTING - org.openhab.io.jetty.certificate
2016-07-23 13:16:58.095 [DEBUG] [ficate.internal.CertificateGenerator] - Keystore found. Trying to load /opt/openhab/userdata/etc/keystore
2016-07-23 13:16:58.099 [DEBUG] [ficate.internal.CertificateGenerator] - mykey alias found. Do nothing.
2016-07-23 13:16:58.101 [DEBUG] [org.openhab.io.jetty.certificate ] - BundleEvent STARTED - org.openhab.io.jetty.certificate
2016-07-23 13:17:12.009 [ERROR] [org.eclipse.smarthome.model.script ] - [org.eclipse.smarthome.action.transformation.action(82)] Circular reference detected, getService returning null
2016-07-23 13:17:12.077 [WARN ] [org.eclipse.smarthome.model.script ] - FrameworkEvent WARNING - org.eclipse.smarthome.model.script
org.osgi.framework.ServiceException: org.apache.felix.scr.impl.manager.SingleComponentManager.getService() returned a null service object
at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:232)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.getService(ServiceFactoryUse.java:111)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
at org.eclipse.osgi.internal.serviceregistry.ServiceConsumer$2.getService(ServiceConsumer.java:45)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:496)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.getService(ServiceRegistry.java:461)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
at org.eclipse.osgi.internal.framework.BundleContextImpl.getService(BundleContextImpl.java:619)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
at org.osgi.util.tracker.ServiceTracker.addingService(ServiceTracker.java:414)[org.osgi.core-6.0.0.jar:]
at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:941)[org.osgi.core-6.0.0.jar:]
at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:870)[org.osgi.core-6.0.0.jar:]
at org.osgi.util.tracker.AbstractTracked.trackAdding(AbstractTracked.java:256)[org.osgi.core-6.0.0.jar:]
at org.osgi.util.tracker.AbstractTracked.trackInitial(AbstractTracked.java:183)[org.osgi.core-6.0.0.jar:]
at org.osgi.util.tracker.ServiceTracker.open(ServiceTracker.java:318)[org.osgi.core-6.0.0.jar:]
at org.osgi.util.tracker.ServiceTracker.open(ServiceTracker.java:261)[org.osgi.core-6.0.0.jar:]
at org.eclipse.smarthome.model.script.internal.ScriptActivator.start(ScriptActivator.java:38)
at org.eclipse.osgi.internal.framework.BundleContextImpl$3.run(BundleContextImpl.java:771)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
at org.eclipse.osgi.internal.framework.BundleContextImpl$3.run(BundleContextImpl.java:1)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
at java.security.AccessController.doPrivileged(Native Method)[:1.8.0_65]
[… part of stacktrace removed…]

2016-07-23 13:17:18.737 [DEBUG] [org.openhab.core.karaf ] - BundleEvent STARTING - org.openhab.core.karaf
2016-07-23 13:17:18.751 [DEBUG] [org.openhab.core.karaf ] - BundleEvent STARTED - org.openhab.core.karaf
2016-07-23 13:17:18.802 [DEBUG] [org.openhab.core.karaf ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.extension.ExtensionService}={component.name=org.openhab.core.karafextension, component.id=104, service.id=221, service.bundleid=161, service.scope=bundle} - org.openhab.core.karaf
2016-07-23 13:17:18.876 [DEBUG] [org.openhab.core.karaf ] - ServiceEvent REGISTERED - {org.openhab.core.karaf.internal.FeatureInstaller, org.osgi.service.cm.ConfigurationListener}={misc=, component.name=org.openhab.addons, service.config.category=system, action=, service.config.description.uri=system:addons, service.config.label=Extension Management, service.pid=org.openhab.addons, binding=knx, astro, ui=basic,paper, transformation=, persistence=rrd4j, mapdb, component.id=105, package=standard, tts=, service.id=223, service.bundleid=161, service.scope=bundle} - org.openhab.core.karaf
2016-07-23 13:17:21.321 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /ui
2016-07-23 13:17:23.401 [DEBUG] [org.openhab.io.rest.docs ] - BundleEvent STARTING - org.openhab.io.rest.docs
2016-07-23 13:17:23.405 [DEBUG] [org.openhab.io.rest.docs ] - BundleEvent STARTED - org.openhab.io.rest.docs
2016-07-23 13:17:23.437 [DEBUG] [org.openhab.io.rest.docs ] - ServiceEvent REGISTERED - {javax.servlet.ServletContext}={osgi.web.symbolicname=org.openhab.io.rest.docs, osgi.web.version=2.0.0.201607210102, osgi.web.contextpath=/, service.id=265, service.bundleid=181, service.scope=singleton} - org.openhab.io.rest.docs
2016-07-23 13:17:23.442 [DEBUG] [org.openhab.io.rest.docs ] - ServiceEvent REGISTERED - {org.openhab.ui.dashboard.DashboardTile}={component.name=org.openhab.io.rest.docs.dashboardtile, component.id=146, service.id=264, service.bundleid=181, service.scope=bundle} - org.openhab.io.rest.docs
2016-07-23 13:17:23.444 [DEBUG] [org.openhab.ui.classicui ] - BundleEvent STARTING - org.openhab.ui.classicui
2016-07-23 13:17:23.447 [DEBUG] [org.openhab.ui.classicui ] - BundleEvent STARTED - org.openhab.ui.classicui
2016-07-23 13:17:23.456 [DEBUG] [org.openhab.ui.classicui ] - ServiceEvent REGISTERED - {org.openhab.ui.dashboard.DashboardTile}={component.name=org.openhab.ui.classicui.dashboardtile, component.id=147, service.id=266, service.bundleid=183, service.scope=bundle} - org.openhab.ui.classicui
2016-07-23 13:17:23.457 [DEBUG] [org.openhab.ui.dashboard ] - BundleEvent STARTING - org.openhab.ui.dashboard
2016-07-23 13:17:23.464 [DEBUG] [org.openhab.ui.dashboard ] - BundleEvent STARTED - org.openhab.ui.dashboard
2016-07-23 13:17:23.495 [DEBUG] [org.openhab.ui.dashboard ] - ServiceEvent REGISTERED - {javax.servlet.ServletContext}={osgi.web.symbolicname=org.openhab.ui.dashboard, osgi.web.version=2.0.0.201607210102, osgi.web.contextpath=/, service.id=267, service.bundleid=184, service.scope=singleton} - org.openhab.ui.dashboard
2016-07-23 13:17:23.502 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at /start
2016-07-23 13:17:23.512 [DEBUG] [org.openhab.binding.knx ] - BundleEvent STARTING - org.openhab.binding.knx
2016-07-23 13:17:23.520 [DEBUG] [ab.binding.knx.internal.KNXActivator] - KNX binding has been started.
2016-07-23 13:17:23.533 [DEBUG] [org.openhab.binding.knx ] - BundleEvent STARTED - org.openhab.binding.knx
2016-07-23 13:17:23.652 [DEBUG] [org.openhab.binding.knx ] - ServiceEvent REGISTERED - {org.openhab.binding.knx.config.KNXTypeMapper}={component.name=org.openhab.binding.knx.typemapper, component.id=151, service.id=268, service.bundleid=188, service.scope=bundle} - org.openhab.binding.knx
2016-07-23 13:17:23.676 [DEBUG] [org.openhab.binding.knx ] - ServiceEvent REGISTERED - {org.openhab.model.item.binding.BindingConfigReader, org.openhab.binding.knx.config.KNXBindingProvider}={component.name=org.openhab.binding.knx.genericbindingprovider, component.id=152, service.id=269, service.bundleid=188, service.scope=bundle} - org.openhab.binding.knx
2016-07-23 13:17:23.678 [DEBUG] [org.openhab.core.compat1x ] - BundleEvent STARTING - org.openhab.core.compat1x
2016-07-23 13:17:23.702 [DEBUG] [org.openhab.core.compat1x ] - BundleEvent STARTED - org.openhab.core.compat1x
2016-07-23 13:17:23.769 [DEBUG] [.binding.knx.internal.bus.KNXBinding] - Calimero library version 2.2.0-alpha
2016-07-23 13:17:23.779 [DEBUG] [x.internal.bus.KNXBusReaderScheduler] - Starting reader task.
2016-07-23 13:17:23.785 [DEBUG] [x.internal.bus.KNXBusReaderScheduler] - Starting schedule executor.
2016-07-23 13:17:23.785 [DEBUG] [al.bus.KNXBindingDatapointReaderTask] - Autorefresh: Waiting for new item in reader queue
2016-07-23 13:17:23.799 [DEBUG] [nx.internal.connection.KNXConnection] - KNXBinding configuration present. Setting up KNX bus connection.
2016-07-23 13:17:23.801 [DEBUG] [nx.internal.connection.KNXConnection] - Not connected yet. Trying to connect.
2016-07-23 13:17:23.810 [DEBUG] [org.openhab.binding.knx ] - ServiceEvent REGISTERED - {org.osgi.service.cm.ManagedService}={service.pid=org.openhab.knx, component.name=org.openhab.binding.knx.config, component.id=149, service.id=272, service.bundleid=188, service.scope=bundle} - org.openhab.binding.knx
2016-07-23 13:17:23.814 [DEBUG] [org.openhab.binding.knx ] - ServiceEvent REGISTERED - {org.osgi.service.event.EventHandler, tuwien.auto.calimero.process.ProcessListener}={event.topics=openhab/, component.name=org.openhab.binding.knx, component.id=150, service.id=271, service.bundleid=188, service.scope=bundle} - org.openhab.binding.knx
2016-07-23 13:17:23.817 [DEBUG] [org.openhab.core.compat1x ] - ServiceEvent REGISTERED - {org.openhab.core.events.EventPublisher}={component.name=org.openhab.core.compat1x.eventpublisherdelegate, component.id=155, service.id=270, service.bundleid=189, service.scope=bundle} - org.openhab.core.compat1x
2016-07-23 13:17:23.836 [DEBUG] [org.openhab.core.compat1x ] - ServiceEvent REGISTERED - {org.openhab.core.items.ItemRegistry, org.openhab.ui.items.ItemUIRegistry}={component.name=org.openhab.core.compat1x.itemuiregistry, component.id=156, service.id=273, service.bundleid=189, service.scope=bundle} - org.openhab.core.compat1x
2016-07-23 13:17:23.846 [DEBUG] [org.openhab.core.compat1x ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.items.ItemFactory}={component.name=org.openhab.library.tel, component.id=157, service.id=274, service.bundleid=189, service.scope=bundle} - org.openhab.core.compat1x
2016-07-23 13:17:23.854 [DEBUG] [org.openhab.core.compat1x ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.autoupdate.AutoUpdateBindingConfigProvider}={component.name=org.openhab.core.compat1x.autoupdateproviderdelegate, component.id=158, service.id=275, service.bundleid=189, service.scope=bundle} - org.openhab.core.compat1x
2016-07-23 13:17:23.862 [DEBUG] [org.openhab.core.compat1x ] - ServiceEvent REGISTERED - {org.openhab.core.scriptengine.action.ActionService}={component.name=org.openhab.action.audio, component.id=159, service.id=276, service.bundleid=189, service.scope=bundle} - org.openhab.core.compat1x
2016-07-23 13:17:23.878 [DEBUG] [org.openhab.core.compat1x ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.model.item.BindingConfigReader}={service.id=277, service.bundleid=189, service.scope=singleton} - org.openhab.core.compat1x
2016-07-23 13:17:23.898 [DEBUG] [org.openhab.core.compat1x ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.model.script.engine.action.ActionService}={service.id=278, service.bundleid=189, service.scope=singleton} - org.openhab.core.compat1x
2016-07-23 13:17:23.908 [INFO ] [nx.internal.connection.KNXConnection] - Established connection to KNX bus on 192.168.178.39:3671 in mode TUNNEL.
2016-07-23 13:17:23.911 [DEBUG] [org.openhab.core.compat1x ] - ServiceEvent REGISTERED - {org.osgi.service.event.EventHandler, org.eclipse.smarthome.core.events.EventSubscriber}={event.topics=smarthome/, component.name=org.openhab.core.compat1x.eventbridge, component.id=163, service.id=279, service.bundleid=189, service.scope=bundle} - org.openhab.core.compat1x
2016-07-23 13:17:23.914 [DEBUG] [org.openhab.persistence.rrd4j ] - BundleEvent STARTING - org.openhab.persistence.rrd4j
2016-07-23 13:17:23.918 [DEBUG] [nx.internal.connection.KNXConnection] - Success: connected.
2016-07-23 13:17:23.918 [DEBUG] [stence.rrd4j.internal.RRD4jActivator] - RRD4j persistence bundle has been started.
2016-07-23 13:17:23.926 [DEBUG] [org.openhab.persistence.rrd4j ] - BundleEvent STARTED - org.openhab.persistence.rrd4j
2016-07-23 13:17:23.960 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Created default_other = GAUGE heartbeat = 3600 min/max = NaN/NaN step = 1 6 archives(s) = [ MAX xff = 0.999 steps = 1 rows = 3600 MAX xff = 0.999 steps = 10 rows = 1440 MAX xff = 0.999 steps = 60 rows = 1440 MAX xff = 0.999 steps = 900 rows = 2880 MAX xff = 0.999 steps = 21600 rows = 1460 MAX xff = 0.999 steps = 86400 rows = 3650] 0 items(s) = []
2016-07-23 13:17:24.004 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Created default_numeric = GAUGE heartbeat = 60 min/max = NaN/NaN step = 60 6 archives(s) = [ AVERAGE xff = 0.5 steps = 1 rows = 480 AVERAGE xff = 0.5 steps = 4 rows = 360 AVERAGE xff = 0.5 steps = 14 rows = 644 AVERAGE xff = 0.5 steps = 60 rows = 720 AVERAGE xff = 0.5 steps = 720 rows = 730 AVERAGE xff = 0.5 steps = 10080 rows = 520] 0 items(s) = []
2016-07-23 13:17:24.025 [DEBUG] [org.openhab.core.compat1x ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.persistence.PersistenceService}={service.id=281, service.bundleid=189, service.scope=singleton} - org.openhab.core.compat1x
2016-07-23 13:17:24.027 [DEBUG] [org.openhab.persistence.rrd4j ] - ServiceEvent REGISTERED - {org.openhab.core.persistence.PersistenceService}={component.name=org.openhab.persistence.rrd4j, component.id=164, service.id=280, service.bundleid=190, service.scope=bundle} - org.openhab.persistence.rrd4j
2016-07-23 13:17:24.049 [DEBUG] [4j.internal.charts.RRD4jChartServlet] - Starting up rrd chart servlet at /rrdchart.png
2016-07-23 13:17:24.073 [DEBUG] [org.openhab.persistence.rrd4j ] - ServiceEvent REGISTERED - {javax.servlet.ServletContext}={osgi.web.symbolicname=org.openhab.persistence.rrd4j, osgi.web.version=1.9.0.201607230110, osgi.web.contextpath=/, service.id=283, service.bundleid=190, service.scope=singleton} - org.openhab.persistence.rrd4j
2016-07-23 13:17:24.085 [DEBUG] [org.openhab.core.compat1x ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.ui.chart.ChartProvider}={service.id=284, service.bundleid=189, service.scope=singleton} - org.openhab.core.compat1x
2016-07-23 13:17:24.087 [DEBUG] [org.openhab.persistence.rrd4j ] - ServiceEvent REGISTERED - {org.openhab.ui.chart.ChartProvider}={component.name=org.openhab.persistence.rrd4j.chartservlet, component.id=165, service.id=282, service.bundleid=190, service.scope=bundle} - org.openhab.persistence.rrd4j
2016-07-23 13:17:24.090 [DEBUG] [org.openhab.persistence.mapdb ] - BundleEvent STARTING - org.openhab.persistence.mapdb
2016-07-23 13:17:24.094 [DEBUG] [b.internal.MapDBPersistenceActivator] - MapDB persistence bundle has been started.
2016-07-23 13:17:24.102 [DEBUG] [org.openhab.persistence.mapdb ] - BundleEvent STARTED - org.openhab.persistence.mapdb
2016-07-23 13:17:24.107 [DEBUG] [.binding.knx.internal.bus.KNXBinding] - Received groupWrite Event.
2016-07-23 13:17:24.114 [DEBUG] [.binding.knx.internal.bus.KNXBinding] - Received telegram for unknown group address 0/0/63
2016-07-23 13:17:24.124 [DEBUG] [pdb.internal.MapDBPersistenceService] - mapdb persistence service activated
2016-07-23 13:17:24.410 [DEBUG] [pdb.internal.MapDBPersistenceService] - Scheduled Commit-Job with interval 5sec.
2016-07-23 13:17:24.419 [DEBUG] [org.openhab.core.compat1x ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.persistence.PersistenceService}={service.id=286, service.bundleid=189, service.scope=singleton} - org.openhab.core.compat1x
2016-07-23 13:17:24.420 [DEBUG] [org.openhab.persistence.mapdb ] - ServiceEvent REGISTERED - {org.openhab.core.persistence.PersistenceService}={component.name=org.openhab.persistence.mapdb, component.id=166, service.id=285, service.bundleid=193, service.scope=bundle} - org.openhab.persistence.mapdb
2016-07-23 13:17:24.422 [DEBUG] [org.openhab.binding.astro ] - BundleEvent STARTING - org.openhab.binding.astro
2016-07-23 13:17:24.438 [DEBUG] [org.openhab.binding.astro ] - BundleEvent STARTED - org.openhab.binding.astro
2016-07-23 13:17:24.535 [DEBUG] [org.openhab.binding.astro ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandler}={thing.type=astro:moon, thing.id=astro:moon:local, service.id=288, service.bundleid=194, service.scope=singleton} - org.openhab.binding.astro
2016-07-23 13:17:24.547 [DEBUG] [org.openhab.binding.astro ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandler}={thing.type=astro:sun, thing.id=astro:sun:local, service.id=289, service.bundleid=194, service.scope=singleton} - org.openhab.binding.astro
2016-07-23 13:17:24.549 [DEBUG] [org.openhab.binding.astro ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={component.name=org.openhab.binding.astro.internal.AstroHandlerFactory, component.id=167, service.id=287, service.bundleid=194, service.scope=bundle} - org.openhab.binding.astro
2016-07-23 13:17:24.561 [DEBUG] [org.openhab.binding.astro ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.discovery.DiscoveryService}={component.name=org.eclipse.smarthome.binding.astro.discovery, component.id=168, service.id=290, service.bundleid=194, service.scope=bundle} - org.openhab.binding.astro
2016-07-23 13:17:24.597 [DEBUG] [org.openhab.ui.habmin ] - BundleEvent STARTING - org.openhab.ui.habmin
2016-07-23 13:17:24.621 [DEBUG] [org.openhab.ui.habmin ] - BundleEvent STARTED - org.openhab.ui.habmin
2016-07-23 13:17:24.654 [DEBUG] [org.openhab.ui.habmin ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.io.rest.RESTResource}={component.name=org.openhab.ui.habmin.charts, component.id=171, service.id=293, service.bundleid=196, service.scope=bundle} - org.openhab.ui.habmin
2016-07-23 13:17:24.668 [DEBUG] [org.openhab.ui.habmin ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.io.rest.RESTResource}={component.name=org.openhab.ui.habmin.dashboard, component.id=172, service.id=294, service.bundleid=196, service.scope=bundle} - org.openhab.ui.habmin
2016-07-23 13:17:24.673 [DEBUG] [org.openhab.ui.habmin ] - ServiceEvent REGISTERED - {org.openhab.ui.dashboard.DashboardTile}={component.name=org.openhab.ui.habmin.dashboardtile, component.id=173, service.id=295, service.bundleid=196, service.scope=bundle} - org.openhab.ui.habmin
2016-07-23 13:17:24.684 [DEBUG] [org.openhab.ui.habmin ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.io.rest.RESTResource}={component.name=org.openhab.ui.habmin.designer, component.id=174, service.id=296, service.bundleid=196, service.scope=bundle} - org.openhab.ui.habmin
2016-07-23 13:17:24.696 [DEBUG] [org.openhab.ui.habmin ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.io.rest.RESTResource}={component.name=org.openhab.ui.habmin.floorplan, component.id=175, service.id=297, service.bundleid=196, service.scope=bundle} - org.openhab.ui.habmin
2016-07-23 13:17:24.724 [DEBUG] [org.openhab.ui.habmin ] - ServiceEvent REGISTERED - {javax.servlet.ServletContext}={osgi.web.symbolicname=org.openhab.ui.habmin, osgi.web.version=0.8.0.201606191001, osgi.web.contextpath=/, service.id=298, service.bundleid=196, service.scope=singleton} - org.openhab.ui.habmin
2016-07-23 13:17:24.730 [INFO ] [ui.habmin.internal.servlet.HABminApp] - Started HABmin servlet at /habmin
2016-07-23 13:17:24.740 [DEBUG] [org.openhab.ui.habmin ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.io.rest.RESTResource}={component.name=org.openhab.ui.habmin.rules, component.id=177, service.id=299, service.bundleid=196, service.scope=bundle} - org.openhab.ui.habmin
2016-07-23 13:17:24.842 [INFO ] [basic.internal.servlet.WebAppServlet] - Started Basic UI at /basicui/app
2016-07-23 13:17:24.918 [DEBUG] [.binding.knx.internal.bus.KNXBinding] - Received groupWrite Event.
2016-07-23 13:17:24.918 [INFO ] [assic.internal.servlet.WebAppServlet] - Started Classic UI at /classicui/app
2016-07-23 13:17:24.919 [DEBUG] [.binding.knx.internal.bus.KNXBinding] - Received telegram for unknown group address 0/1/13
2016-07-23 13:17:24.989 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'default.sitemap’
2016-07-23 13:17:26.067 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'test.sitemap’
2016-07-23 13:17:26.150 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'my.things’
2016-07-23 13:17:27.520 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'mapdb.persist’
2016-07-23 13:17:27.566 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'rrd4j.persist’
2016-07-23 13:17:27.581 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'rain.rules’
2016-07-23 13:17:28.294 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'light.rules’
2016-07-23 13:17:28.429 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'test.rules’
2016-07-23 13:17:28.466 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'shutter.rules’
2016-07-23 13:17:28.612 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'astro.rules’
2016-07-23 13:17:28.743 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'misc.items’
2016-07-23 13:17:28.816 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'knx.items’
2016-07-23 13:17:29.058 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'astro.items’
2016-07-23 13:17:29.405 [DEBUG] [org.openhab.core ] - BundleEvent STARTING - org.openhab.core
2016-07-23 13:17:29.469 [DEBUG] [org.openhab.core ] - ServiceEvent REGISTERED - {javax.servlet.ServletContext}={osgi.web.symbolicname=org.openhab.core, osgi.web.version=2.0.0.201606271614, osgi.web.contextpath=/, service.id=314, service.bundleid=160, service.scope=singleton} - org.openhab.core
2016-07-23 13:17:29.489 [DEBUG] [org.openhab.core ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.model.sitemap.SitemapProvider}={component.name=org.openhab.defaultsitemapprovider, component.id=182, service.id=315, service.bundleid=160, service.scope=bundle} - org.openhab.core
2016-07-23 13:17:31.496 [DEBUG] [org.openhab.core ] - BundleEvent STARTED - org.openhab.core