search

openhab / openhab-distro

The binary distribution of openHAB
https://www.openhab.org/
Eclipse Public License 2.0
1.3k stars 391 forks source link

Model loader/JDBC Service crash on startup until loading *.items file. #153

Closed steand closed 8 years ago

steand commented 8 years ago

The startup crash until reading the .items File. The model loader dies (No more .items files are loaded)

2016-03-06 13:56:02.044 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /ui
2016-03-06 13:56:02.337 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at /start
2016-03-06 13:56:02.876 [INFO ] [ding.astro.internal.bus.AstroBinding] - AstroConfig[latitude=49.726654,longitude=6.914786,interval=300,systemTimezone=Europe/Berlin (MEZ +0100),daylightSavings=false]
2016-03-06 13:56:03.085 [INFO ] [ematic.internal.bus.HomematicBinding] - HomematicConfig[host=rpi2,timeout=15,callbackHost=192.168.2.116,callbackPort=9123,aliveInterval=300,reconnectInterval=disabled]
2016-03-06 13:56:03.087 [INFO ] [l.communicator.HomematicCommunicator] - Starting Homematic communicator
2016-03-06 13:56:03.194 [INFO ] [l.communicator.HomematicCommunicator] - Homematic ServerId[name=Homegear,version=0.6.0-1248]
2016-03-06 13:56:03.208 [INFO ] [l.communicator.client.HomegearClient] - Starting HomegearClient
2016-03-06 13:56:03.211 [INFO ] [ic.internal.communicator.StateHolder] - Loading Homematic datapoints
2016-03-06 13:56:03.465 [INFO ] [persistence.jdbc.internal.JdbcMapper] - JDBC::openConnection: Driver is available::Yank setupDataSource
2016-03-06 13:56:03.821 [INFO ] [ic.internal.communicator.StateHolder] - Finished loading 409 Homematic datapoints
2016-03-06 13:56:03.826 [INFO ] [ic.internal.communicator.StateHolder] - Loading Homematic Server variables
2016-03-06 13:56:03.856 [INFO ] [ic.internal.communicator.StateHolder] - Finished loading 0 Homematic server variables
2016-03-06 13:56:03.858 [INFO ] [unicator.server.BinRpcCallbackServer] - Starting BinRpcCallbackServer at port 9123
2016-03-06 13:56:03.872 [INFO ] [l.communicator.HomematicCommunicator] - Scheduling one datapoint reload job in one minute
2016-03-06 13:56:03.879 [INFO ] [b.core.service.AbstractActiveService] - Homematic server connection tracker has been started
2016-03-06 13:56:05.983 [INFO ] [ding.astro.internal.job.JobScheduler] - Scheduled a daily job at midnight for astro calculation
2016-03-06 13:56:09.805 [INFO ] [ab.ui.cometvisu.servlet.CometVisuApp] - Started CometVisu UI at /cometvisu serving /home/openhab/CometVisu/src/
2016-03-06 13:56:09.980 [INFO ] [basic.internal.servlet.WebAppServlet] - Started Basic UI at /basicui/app
2016-03-06 13:56:10.033 [INFO ] [assic.internal.servlet.WebAppServlet] - Started Classic UI at /classicui/app
2016-03-06 13:56:10.589 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'eg.sitemap'
2016-03-06 13:56:11.336 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'jdbc.persist'
2016-03-06 13:56:11.526 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'eg_rolladen.rules'
2016-03-06 13:56:12.731 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'eg_heizung.rules'
2016-03-06 13:56:13.001 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'max.items'
2016-03-06 13:56:13.294 [ERROR] [org.apache.felix.configadmin        ] - [org.osgi.service.cm.ManagedService, id=273, bundle=106/mvn:org.eclipse.smarthome.model/org.eclipse.smarthome.model.core/0.8.0-SNAPSHOT]: Unexpected problem updating configuration org.eclipse.smarthome.folder
java.lang.ClassCastException: java.lang.String cannot be cast to java.lang.Number
    at org.openhab.persistence.jdbc.db.JdbcBaseDAO.getState(JdbcBaseDAO.java:419)[154:org.openhab.persistence.jdbc:1.9.0.201603040213]
    at org.openhab.persistence.jdbc.db.JdbcBaseDAO.doGetHistItemFilterQuery(JdbcBaseDAO.java:287)[154:org.openhab.persistence.jdbc:1.9.0.201603040213]
    at org.openhab.persistence.jdbc.internal.JdbcMapper.getHistItemFilterQuery(JdbcMapper.java:147)[154:org.openhab.persistence.jdbc:1.9.0.201603040213]
    at org.openhab.persistence.jdbc.internal.JdbcPersistenceService.query(JdbcPersistenceService.java:199)[154:org.openhab.persistence.jdbc:1.9.0.201603040213]
    at org.openhab.core.persistence.internal.QueryablePersistenceServiceDelegate.query(QueryablePersistenceServiceDelegate.java:49)[150:org.openhab.core.compat1x:2.0.0.201603021555]
    at org.eclipse.smarthome.model.persistence.internal.PersistenceManager.initialize(PersistenceManager.java:374)[109:org.eclipse.smarthome.model.persistence:0.8.0.201603021108]
    at org.eclipse.smarthome.model.persistence.internal.PersistenceManager.added(PersistenceManager.java:347)[109:org.eclipse.smarthome.model.persistence:0.8.0.201603021108]
    at org.eclipse.smarthome.model.persistence.internal.PersistenceManager.added(PersistenceManager.java:1)[109:org.eclipse.smarthome.model.persistence:0.8.0.201603021108]
    at org.eclipse.smarthome.core.internal.items.ItemRegistryImpl.allItemsChanged(ItemRegistryImpl.java:98)[88:org.eclipse.smarthome.core:0.8.0.201603021108]
    at org.eclipse.smarthome.model.item.internal.GenericItemProvider.modelChanged(GenericItemProvider.java:407)[107:org.eclipse.smarthome.model.item:0.8.0.201603021108]
    at org.eclipse.smarthome.model.core.internal.ModelRepositoryImpl.notifyListeners(ModelRepositoryImpl.java:200)[106:org.eclipse.smarthome.model.core:0.8.0.201603021108]
    at org.eclipse.smarthome.model.core.internal.ModelRepositoryImpl.addOrRefreshModel(ModelRepositoryImpl.java:97)[106:org.eclipse.smarthome.model.core:0.8.0.201603021108]
    at org.eclipse.smarthome.model.core.internal.folder.FolderObserver.checkFile(FolderObserver.java:240)[106:org.eclipse.smarthome.model.core:0.8.0.201603021108]
    at org.eclipse.smarthome.model.core.internal.folder.FolderObserver.notifyUpdateToModelRepo(FolderObserver.java:169)[106:org.eclipse.smarthome.model.core:0.8.0.201603021108]
    at org.eclipse.smarthome.model.core.internal.folder.FolderObserver.updated(FolderObserver.java:150)[106:org.eclipse.smarthome.model.core:0.8.0.201603021108]
    at org.apache.felix.cm.impl.helper.ManagedServiceTracker.updated(ManagedServiceTracker.java:189)[7:org.apache.felix.configadmin:1.8.8]
    at org.apache.felix.cm.impl.helper.ManagedServiceTracker.updateService(ManagedServiceTracker.java:152)[7:org.apache.felix.configadmin:1.8.8]
    at org.apache.felix.cm.impl.helper.ManagedServiceTracker.provideConfiguration(ManagedServiceTracker.java:85)[7:org.apache.felix.configadmin:1.8.8]
    at org.apache.felix.cm.impl.ConfigurationManager$ManagedServiceUpdate.provide(ConfigurationManager.java:1444)[7:org.apache.felix.configadmin:1.8.8]
    at org.apache.felix.cm.impl.ConfigurationManager$ManagedServiceUpdate.run(ConfigurationManager.java:1400)[7:org.apache.felix.configadmin:1.8.8]
    at org.apache.felix.cm.impl.UpdateThread.run0(UpdateThread.java:143)[7:org.apache.felix.configadmin:1.8.8]
    at org.apache.felix.cm.impl.UpdateThread.run(UpdateThread.java:110)[7:org.apache.felix.configadmin:1.8.8]
    at java.lang.Thread.run(Thread.java:745)[:1.8.0_65]
2016-03-06 13:56:13.309 [INFO ] [marthome.event.ItemStateChangedEvent] - EG_Buero_Temperatur changed from NULL to 21
2016-03-06 13:56:13.321 [INFO ] [marthome.event.ItemStateChangedEvent] - EG_Buero_default_Temperatur changed from NULL to 21
2016-03-06 13:56:13.331 [INFO ] [marthome.event.ItemStateChangedEvent] - EG_Buero_eco_Temperatur changed from NULL to 16
2016-03-06 13:56:16.234 [INFO ] [marthome.event.ItemStateChangedEvent] - EG_Buero_Fenster changed from NULL to CLOSED

In the max.items i have define 4 Items for storing in a mysql Database:

/* Erdgeschoss */

Contact EG_Buero_Fenster             {homematic="address=IEQ0490424, channel=1, parameter=STATE"} 

Number EG_Buero_Temperatur
Number EG_Buero_default_Temperatur
Number EG_Buero_eco_Temperatur
Number EG_Buero_mode 

Number EG_Buero_Heizkoerper_Temperatur         {homematic="address=JEQ0133878, channel=1, parameter=SET_TEMPERATURE"}
Number EG_Buero_Heizkoerper_fensterTemperatur  {homematic="address=JEQ0133878, channel=1, parameter=WINDOW_OPEN_TEMPERATURE"}

Number EG_Buero_Heizkoerper_Ventil             {homematic="address=JEQ0133878, channel=1, parameter=VALVE_STATE"}
Switch EG_Buero_Heizkoerper_Batterie           {homematic="address=JEQ0133878, channel=0, parameter=LOWBAT"}

Number EG_Buero_Heizkoerper_manTemperatur      {homematic="address=JEQ0133878, channel=1, parameter=MANU_MODE"}

The jdbc.persist:

Strategies {
    // if no strategy is specified for an item entry below, the default list will be used
    default = everyChange
}

/* 
 * Each line in this section defines for which item(s) which strategy(ies) should be applied.
 * You can list single items, use "*" for all items or "groupitem*" for all members of a group
 * item (excl. the group item itself).
 */
Items {
        EG_Buero_Temperatur: strategy=everyChange,restoreOnStartup
        EG_Buero_default_Temperatur: strategy=everyChange,restoreOnStartup
        EG_Buero_eco_Temperatur: strategy=everyChange,restoreOnStartup
        EG_Buero_mode: strategy=everyChange,restoreOnStartup
}

If I remove the 4 Items from the max.items the startup is successful. After startup I can put these 4 items in the max.items file, all Items will be load and restored from the mysql Database.

Runtime: RPI 2, OH2 Build from 2016-03-03 (Cloudbees), Rasbean Jessie

Want to back this issue? Post a bounty on it! We accept bounties via Bountysource.

steand commented 8 years ago

Second Test: After reloading the max.items no more changes of *.items File are be reloaded. It looks that the model loader hangs. I have checked the bundels. The needed bundles are "Active".

kaikreuzer commented 8 years ago

From the exception this seems to be a problem of the JDBC binding, so would it make more sense to report it at https://github.com/openhab/openhab/issues?

lewie commented 8 years ago

@steand, I have unfortunately overlooked this.

For further discussions here, please use: this https://github.com/openhab/openhab/issues/4303