Hello,
I’m using Openhab 2.3 with the openhab Panel, based on the Matrix theme .
When I open the Habpanel, half of the time it becomes unresponsive, and got a connecting messages.
In the logging I see that the Karaf is reloading.
As far I can see is nog the complete system rebooting but only Karaf, but have no idea why.
I only have no idea why and how to trouble shoot this proble or resolve this.
I there anyone who has some idea’s?
Thank you.
Regards,
Edwin
Please post your logs
Hello,
Today I had some time to work on my installation.
Around 14.09 the karaf restarted again, I have added the openhab log form around that time but can’t see anything that triggered the restart.
De log is below:
Done in 0.316480875015 seconds
2018-10-26 14:08:40.924 [INFO ] [lipse.smarthome.model.script.Spotify] - Successfully got state from OpenHab: e[0;37mspotify_client_ide[0m
Successfully got state from OpenHab: e[0;37mspotify_client_secrete[0m
Successfully got state from OpenHab: e[0;37mspotify_access_tokene[0m
Successfully got state from OpenHab: e[0;37mspotify_refresh_tokene[0m
Successfully got state from OpenHab: e[0;37mspotify_token_issuede[0m
Successfully got state from OpenHab: e[0;37mspotify_token_expirye[0m
-- Calling Service: Update
-> Failure: <type 'exceptions.ValueError'>
Successfully posted state to OpenHab: e[0;37mspotify_lastConnectionDateTime e[0m= e[0;36m2018-10-26T12:08:40.000+0000e[0m
Done in 0.326762914658 seconds
2018-10-26 14:08:50.830 [INFO ] [lipse.smarthome.model.script.Spotify] - Successfully got state from OpenHab: e[0;37mspotify_client_ide[0m
Successfully got state from OpenHab: e[0;37mspotify_client_secrete[0m
Successfully got state from OpenHab: e[0;37mspotify_access_tokene[0m
Successfully got state from OpenHab: e[0;37mspotify_refresh_tokene[0m
Successfully got state from OpenHab: e[0;37mspotify_token_issuede[0m
Successfully got state from OpenHab: e[0;37mspotify_token_expirye[0m
-- Calling Service: Update
-> Failure: <type 'exceptions.ValueError'>
Successfully posted state to OpenHab: e[0;37mspotify_lastConnectionDateTime e[0m= e[0;36m2018-10-26T12:08:50.000+0000e[0m
Done in 0.276077032089 seconds
2018-10-26 14:08:52.506 [TRACE] [.internal.InfluxDBPersistenceService] - Tried to get item from item class class org.openhab.core.library.items.NumberItem, state is 9.0
2018-10-26 14:08:52.513 [TRACE] [.internal.InfluxDBPersistenceService] - found fractional part
2018-10-26 14:08:52.520 [DEBUG] [.internal.InfluxDBPersistenceService] - got DecimalType value 9.0
2018-10-26 14:08:52.525 [TRACE] [.internal.InfluxDBPersistenceService] - storing CPU_Load in influxdb value 9.0, CPU_Load (Type=NumberItem, State=9.0)
2018-10-26 14:08:52.564 [TRACE] [.internal.InfluxDBPersistenceService] - Tried to get item from item class class org.openhab.core.library.items.NumberItem, state is 56.9
2018-10-26 14:08:52.573 [TRACE] [.internal.InfluxDBPersistenceService] - found fractional part
2018-10-26 14:08:52.575 [DEBUG] [.internal.InfluxDBPersistenceService] - got DecimalType value 56.9
2018-10-26 14:08:52.589 [TRACE] [.internal.InfluxDBPersistenceService] - storing Sensor_CPUTemp in influxdb value 56.9, Sensor_CPUTemp (Type=NumberItem, State=56.9)
2018-10-26 14:09:00.884 [INFO ] [lipse.smarthome.model.script.Spotify] - Successfully got state from OpenHab: e[0;37mspotify_client_ide[0m
Successfully got state from OpenHab: e[0;37mspotify_client_secrete[0m
Successfully got state from OpenHab: e[0;37mspotify_access_tokene[0m
Successfully got state from OpenHab: e[0;37mspotify_refresh_tokene[0m
Successfully got state from OpenHab: e[0;37mspotify_token_issuede[0m
Successfully got state from OpenHab: e[0;37mspotify_token_expirye[0m
-- Calling Service: Update
-> Failure: <type 'exceptions.ValueError'>
Successfully posted state to OpenHab: e[0;37mspotify_lastConnectionDateTime e[0m= e[0;36m2018-10-26T12:09:00.000+0000e[0m
Done in 0.30086183548 seconds
2018-10-26 14:09:00.994 [INFO ] [lipse.smarthome.model.script.Spotify] - Successfully got state from OpenHab: e[0;37mspotify_client_ide[0m
Successfully got state from OpenHab: e[0;37mspotify_client_secrete[0m
Successfully got state from OpenHab: e[0;37mspotify_access_tokene[0m
Successfully got state from OpenHab: e[0;37mspotify_refresh_tokene[0m
Successfully got state from OpenHab: e[0;37mspotify_token_issuede[0m
Successfully got state from OpenHab: e[0;37mspotify_token_expirye[0m
-- Calling Service: Update
-> Failure: <type 'exceptions.ValueError'>
Successfully posted state to OpenHab: e[0;37mspotify_lastConnectionDateTime e[0m= e[0;36m2018-10-26T12:09:00.000+0000e[0m
Done in 0.321431159973 seconds
2018-10-26 14:09:01.613 [INFO ] [panel.internal.HABPanelDashboardTile] - Stopped HABPanel
2018-10-26 14:09:01.616 [INFO ] [vice.internal.HttpServiceFactoryImpl] - Unbinding bundle: [org.openhab.ui.habpanel_2.3.0 [223]]
2018-10-26 14:09:01.639 [INFO ] [.jetty.server.handler.ContextHandler] - Stopped HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.ui.habpanel_2.3.0 [223], contextID=default]}
2018-10-26 14:09:01.654 [INFO ] [vice.internal.HttpServiceFactoryImpl] - Binding bundle: [org.openhab.ui.habpanel_2.3.0 [223]] to http service
2018-10-26 14:09:01.714 [INFO ] [rg.ops4j.pax.web.utils.ClassPathUtil] - Ignoring bundle scan for /META-INF/services javax.servlet.ServletContainerInitializer.
2018-10-26 14:09:01.720 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering context DefaultHttpContext [bundle=org.openhab.ui.habpanel_2.3.0 [223], contextID=default], with context-name:
2018-10-26 14:09:01.744 [INFO ] [.jetty.server.handler.ContextHandler] - Started HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.ui.habpanel_2.3.0 [223], contextID=default]}
2018-10-26 14:09:01.756 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel
2018-10-26 14:09:43.985 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.shell.commands/4.1.5
2018-10-26 14:09:44.016 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.deployer.kar/4.1.5
2018-10-26 14:09:44.022 [INFO ] [af.shell.impl.console.osgi.Activator] - Not starting local console. To activate set karaf.startLocalConsole=true
2018-10-26 14:09:44.118 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.wrapper.core/4.1.5
2018-10-26 14:09:44.574 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.bundle.core/4.1.5
2018-10-26 14:09:44.680 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.config.core/4.1.5
2018-10-26 14:09:46.936 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.diagnostic.core/4.1.5
2018-10-26 14:09:47.005 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.features.command/4.1.5
2018-10-26 14:09:47.038 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.http.core/4.1.5
2018-10-26 14:09:47.144 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.instance.core/4.1.5
2018-10-26 14:09:47.207 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.jaas.command/4.1.5
2018-10-26 14:09:47.214 [INFO ] [ll.impl.action.osgi.CommandExtension] - Updating commands for bundle org.apache.karaf.jaas.command/4.1.5
2018-10-26 14:09:47.219 [INFO ] [ll.impl.action.osgi.CommandExtension] - Updating commands for bundle org.apache.karaf.jaas.command/4.1.5
2018-10-26 14:09:47.296 [INFO ] [ll.impl.action.osgi.CommandExtension] - Updating commands for bundle org.apache.karaf.jaas.command/4.1.5
2018-10-26 14:09:47.305 [INFO ] [ll.impl.action.osgi.CommandExtension] - Updating commands for bundle org.apache.karaf.jaas.command/4.1.5
2018-10-26 14:09:47.318 [INFO ] [ll.impl.action.osgi.CommandExtension] - Updating commands for bundle org.apache.karaf.jaas.command/4.1.5
2018-10-26 14:09:47.375 [INFO ] [ll.impl.action.osgi.CommandExtension] - Command registration delayed for bundle org.apache.karaf.kar.core/4.1.5. Missing dependencies: [org.apache.karaf.kar.KarService]
2018-10-26 14:09:47.386 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.kar.core/4.1.5
2018-10-26 14:09:47.437 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.log.core/4.1.5
2018-10-26 14:09:47.475 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.package.core/4.1.5
2018-10-26 14:09:47.498 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.scr.command/4.1.5
2018-10-26 14:09:47.522 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.scr.state/4.1.5
2018-10-26 14:09:47.577 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.service.core/4.1.5
2018-10-26 14:09:47.746 [INFO ] [ll.impl.action.osgi.CommandExtension] - Command registration delayed for bundle org.apache.karaf.shell.ssh/4.1.5. Missing dependencies: [org.apache.sshd.server.SshServer]
2018-10-26 14:09:47.795 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.system.core/4.1.5
2018-10-26 14:09:47.909 [INFO ] [org.eclipse.jetty.util.log ] - Logging initialized @12775ms
2018-10-26 14:09:47.977 [INFO ] [j.pax.web.service.internal.Activator] - EventAdmin support enabled, servlet events will be postet to topics.
2018-10-26 14:09:47.986 [INFO ] [j.pax.web.service.internal.Activator] - LogService support enabled, log events will be created.
2018-10-26 14:09:47.997 [INFO ] [j.pax.web.service.internal.Activator] - Pax Web started
2018-10-26 14:09:48.282 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.shell.ssh/4.1.5
2018-10-26 14:09:48.790 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.openhab.core.karaf/2.3.0
2018-10-26 14:09:49.222 [INFO ] [rvice.jetty.internal.JettyServerImpl] - Pax Web available at [0.0.0.0]:[8443]
2018-10-26 14:09:49.303 [INFO ] [vice.jetty.internal.JettyFactoryImpl] - No ALPN class available
2018-10-26 14:09:49.305 [INFO ] [vice.jetty.internal.JettyFactoryImpl] - HTTP/2 not available, creating standard ServerConnector for Http
2018-10-26 14:09:49.309 [INFO ] [rvice.jetty.internal.JettyServerImpl] - Pax Web available at [0.0.0.0]:[8080]
2018-10-26 14:09:49.384 [INFO ] [vice.internal.HttpServiceFactoryImpl] - Binding bundle: [org.openhab.ui.homebuilder_2.3.0 [224]] to http service
2018-10-26 14:09:49.573 [INFO ] [rg.ops4j.pax.web.utils.ClassPathUtil] - Ignoring bundle scan for /META-INF/services javax.servlet.ServletContainerInitializer.
2018-10-26 14:09:49.712 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering context DefaultHttpContext [bundle=org.openhab.ui.homebuilder_2.3.0 [224], contextID=default], with context-name:
2018-10-26 14:09:49.774 [INFO ] [.jetty.server.handler.ContextHandler] - Started HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.ui.homebuilder_2.3.0 [224], contextID=default]}
2018-10-26 14:09:49.784 [INFO ] [org.eclipse.jetty.server.Server ] - jetty-9.3.21.v20170918
2018-10-26 14:09:49.825 [INFO ] [.jetty.server.handler.ContextHandler] - Started o.e.j.s.h.ContextHandler@15549b3{/static,null,AVAILABLE}
2018-10-26 14:09:49.854 [INFO ] [pse.jetty.util.ssl.SslContextFactory] - x509=X509@1c1094c(mykey,h=[openhab.org],w=[]) for SslContextFactory@e65460(file:///var/lib/openhab2/etc/keystore,file:///var/lib/openhab2/etc/keystore)
2018-10-26 14:09:49.923 [INFO ] [lipse.jetty.server.AbstractConnector] - Started 0.0.0.0:8443@1bfa3f6{SSL,[ssl, http/1.1]}{0.0.0.0:8443}
2018-10-26 14:09:49.929 [INFO ] [lipse.jetty.server.AbstractConnector] - Started default@14879b1{HTTP/1.1,[http/1.1]}{0.0.0.0:8080}
2018-10-26 14:09:49.934 [INFO ] [org.eclipse.jetty.server.Server ] - Started @14800ms
2018-10-26 14:09:49.939 [INFO ] [er.internal.HomeBuilderDashboardTile] - Started Home Builder at /homebuilder
2018-10-26 14:09:50.040 [INFO ] [vice.internal.HttpServiceFactoryImpl] - Binding bundle: [org.openhab.io.rest.docs_2.3.0 [235]] to http service
2018-10-26 14:09:50.068 [INFO ] [rg.ops4j.pax.web.utils.ClassPathUtil] - Ignoring bundle scan for /META-INF/services javax.servlet.ServletContainerInitializer.
2018-10-26 14:09:50.074 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering context DefaultHttpContext [bundle=org.openhab.io.rest.docs_2.3.0 [235], contextID=default], with context-name:
2018-10-26 14:09:50.082 [INFO ] [.jetty.server.handler.ContextHandler] - Started HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.io.rest.docs_2.3.0 [235], contextID=default]}
2018-10-26 14:09:50.240 [ERROR] [org.openhab.binding.zigbee ] - FrameworkEvent ERROR - org.openhab.binding.zigbee
org.osgi.framework.BundleException: Could not resolve module: org.openhab.binding.zigbee [286]
Another singleton bundle selected: osgi.identity; type="osgi.bundle"; version:Version="2.3.0"; osgi.identity="org.openhab.binding.zigbee"; singleton:="true"
at org.eclipse.osgi.container.Module.start(Module.java:444) [?:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1634) [?:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1613) [?:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.doContainerStartLevel(ModuleContainer.java:1585) [?:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1528) [?:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1) [?:?]
at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) [?:?]
at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:340) [?:?]
2018-10-26 14:09:50.263 [INFO ] [vice.internal.HttpServiceFactoryImpl] - Binding bundle: [com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [15]] to http service
2018-10-26 14:09:50.868 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.event/4.1.5
2018-10-26 14:09:52.204 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Time zone set to 'Europe/Amsterdam'.
2018-10-26 14:09:52.214 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Location set to '53.019333,5.667822'.
2018-10-26 14:09:52.221 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Locale set to 'nl_NL'.
2018-10-26 14:09:54.175 [INFO ] [vice.internal.HttpServiceFactoryImpl] - Binding bundle: [org.openhab.ui.dashboard_2.3.0 [181]] to http service
2018-10-26 14:09:54.227 [INFO ] [rg.ops4j.pax.web.utils.ClassPathUtil] - Ignoring bundle scan for /META-INF/services javax.servlet.ServletContainerInitializer.
2018-10-26 14:09:54.231 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering context DefaultHttpContext [bundle=org.openhab.ui.dashboard_2.3.0 [181], contextID=default], with context-name:
2018-10-26 14:09:54.272 [INFO ] [.jetty.server.handler.ContextHandler] - Started HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.ui.dashboard_2.3.0 [181], contextID=default]}
2018-10-26 14:09:54.283 [INFO ] [.dashboard.internal.DashboardService] - Started Dashboard at http://192.168.99.225:8080
2018-10-26 14:09:54.286 [INFO ] [.dashboard.internal.DashboardService] - Started Dashboard at https://192.168.99.225:8443
2018-10-26 14:09:54.401 [INFO ] [vice.internal.HttpServiceFactoryImpl] - Binding bundle: [org.eclipse.smarthome.core.audio_0.10.0.oh230 [102]] to http service
2018-10-26 14:09:54.410 [INFO ] [rg.ops4j.pax.web.utils.ClassPathUtil] - Ignoring bundle scan for /META-INF/services javax.servlet.ServletContainerInitializer.
2018-10-26 14:09:54.414 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering context DefaultHttpContext [bundle=org.eclipse.smarthome.core.audio_0.10.0.oh230 [102], contextID=default], with context-name:
2018-10-26 14:09:54.426 [INFO ] [.jetty.server.handler.ContextHandler] - Started HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.core.audio_0.10.0.oh230 [102], contextID=default]}
2018-10-26 14:09:54.633 [INFO ] [rg.ops4j.pax.web.utils.ClassPathUtil] - Ignoring bundle scan for /META-INF/services javax.servlet.ServletContainerInitializer.
2018-10-26 14:09:54.649 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering context DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [15], contextID=default], with context-name:
2018-10-26 14:09:54.659 [INFO ] [.jetty.server.handler.ContextHandler] - Started HttpServiceContext{httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [15], contextID=default]}
2018-10-26 14:09:54.985 [INFO ] [io.openhabcloud.internal.CloudClient] - Connected to the openHAB Cloud service (UUID = 3d072cc9-0eef-436a-973c-c90757f71482, base URL = http://localhost:8080)
2018-10-26 14:09:55.304 [INFO ] [org.quartz.impl.StdSchedulerFactory ] - Using default implementation for ThreadExecutor
2018-10-26 14:09:55.392 [INFO ] [rg.quartz.core.SchedulerSignalerImpl] - Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl
2018-10-26 14:09:55.395 [INFO ] [org.quartz.core.QuartzScheduler ] - Quartz Scheduler v.2.2.1 created.
2018-10-26 14:09:55.400 [INFO ] [org.quartz.simpl.RAMJobStore ] - RAMJobStore initialized.
2018-10-26 14:09:55.410 [INFO ] [org.quartz.core.QuartzScheduler ] - Scheduler meta-data: Quartz Scheduler (v2.2.1) 'openHAB-job-scheduler' with instanceId 'NON_CLUSTERED'
Scheduler class: 'org.quartz.core.QuartzScheduler' - running locally.
Anyone any ideas?
Kind regard,
Edwin