OH2-online_2.0.0~*4422 doesn't start

erland_lestander · January 3, 2017, 12:35pm

Hi, I had a week of well working OH2, and then did apt-get upgrade

Preparing to replace openhab2-online 2.0.0~20170103034422 (using .../openhab2-online_2.0.0~20170103034422_all.deb) ...
Unpacking replacement openhab2-online ...
Setting up openhab2-online (2.0.0~20170103034422) ...
[ ok ] Starting openHAB2 server: openhab2.

In the openhab.log I see:

2017-01-03 13:18:40.418 [INFO ] [internal.service.FeaturesServiceImpl] - Adding features: instance/[4.0.8,4.0.8], package/[4.0.8,4.0.8], log/[4.0.8,4.0.8], ssh/[4.0.8,4.0.8], system/[4.0.8,4.0.8], feature/[4.0.8,4.0.8], shell/[4.0.8,4.0.8], service/[4.0.8,4.0.8], jaas/[4.0.8,4.0.8], openhab-runtime-base/[2.0.0.SNAPSHOT,2.0.0.SNAPSHOT], deployer/[4.0.8,4.0.8], diagnostic/[4.0.8,4.0.8], openhab-runtime-updates/[2.0.0.SNAPSHOT,2.0.0.SNAPSHOT], bundle/[4.0.8,4.0.8], config/[4.0.8,4.0.8]
2017-01-03 13:18:46.881 [INFO ] [internal.service.FeaturesServiceImpl] - Changes to perform:
2017-01-03 13:18:46.883 [INFO ] [internal.service.FeaturesServiceImpl] - Region: root
2017-01-03 13:18:46.885 [INFO ] [internal.service.FeaturesServiceImpl] - Bundles to install:
2017-01-03 13:18:46.887 [INFO ] [internal.service.FeaturesServiceImpl] - mvn:com.eclipsesource.jaxrs/provider-gson/2.3

2017-01-03 13:19:02.390 [INFO ] [org.eclipse.equinox.registry ] - FrameworkEvent INFO - org.eclipse.equinox.registry
org.osgi.framework.BundleException: The bundle class path entry “runtime_registry_compatibility.jar” could not be found for the bundle “osgi.identity; osgi.identity=“org.eclipse.equinox.registry”; type=“osgi.bundle”; version:Version=“3.6.0.v20150318-1503”; singleton:=“true””

> 2017-01-03 13:19:16.548 [INFO ] [g.apache.aries.spifly.dynamic.bundle] - No 'SPI-Provider' Manifest header. Skipping bundle: org.eclipse.osgi
> 2017-01-03 13:19:16.550 [INFO ] [g.apache.aries.spifly.dynamic.bundle] - Bundle Considered for SPI providers: org.ops4j.pax.logging.pax-logging-api
> 2017-01-03 13:19:16.551 [INFO ] [g.apache.aries.spifly.dynamic.bundle] - No 'SPI-Provider' Manifest header. Skipping bundle: org.ops4j.pax.logging.pax-logging-api
> 2017-01-03 13:19:16.553 [INFO ] [g.apache.aries.spifly.dynamic.bundle] - Bundle Considered for SPI providers: org.ops4j.pax.logging.pax-logging-service
> 2017-01-03 13:19:16.554 [INFO ] [g.apache.aries.spifly.dynamic.bundle] - No 'SPI-Provider' Manifest header. Skipping bundle: org.ops4j.pax.logging.pax-logging-service

> org.osgi.framework.BundleException: The bundle class path entry "runtime_registry_compatibility.jar" could not be found for the bundle "osgi.identity; osgi.identity="org.eclipse.equinox.registry"; type="osgi.bundle"; version:Version="3.6.0.v20150318-1503"; singleton:="true""
>         at org.eclipse.osgi.internal.loader.classpath.ClasspathManager.findClassPathEntry(ClasspathManager.java:176)[org.eclipse.osgi-3.10.101.v20150820-1432.jar:]
>         at org.eclipse.osgi.internal.loader.classpath.ClasspathManager.buildClasspath(ClasspathManager.java:154)[org.eclipse.osgi-3.10.101.v20150820-1432.jar:]
>         at org.eclipse.osgi.internal.loader.classpath.ClasspathManager.<init>(ClasspathManager.java:83)[org.eclipse.osgi-3.10.101.v20150820-1432.jar:]
>         at org.eclipse.osgi.internal.loader.EquinoxClassLoader.<init>(EquinoxClassLoader.java:57)[org.eclipse.osgi-3.10.101.v20150820-1432.jar:]
>         at org.eclipse.osgi.internal.loader.BundleLoader.createClassLoaderPrivledged(BundleLoader.java:277)[org.eclipse.osgi-3.10.101.v20150820-1432.jar:]
>         at org.eclipse.osgi.internal.loader.BundleLoader.getModuleClassLoader(BundleLoader.java:224)[org.eclipse.osgi-3.10.101.v20150820-1432.jar:]
>         at org.eclipse.osgi.internal.loader.BundleLoader.findEntries(BundleLoader.java:777)[org.eclipse.osgi-3.10.101.v20150820-1432.jar:]
>         at org.eclipse.osgi.container.ModuleWiring.findEntries(ModuleWiring.java:289)[org.eclipse.osgi-3.10.101.v20150820-1432.jar:]
>         at org.eclipse.osgi.storage.ManifestLocalization.findResource(ManifestLocalization.java:200)[org.eclipse.osgi-3.10.101.v20150820-1432.jar:]
>         at org.eclipse.osgi.storage.ManifestLocalization.lookupResourceBundle(ManifestLocalization.java:131)[org.eclipse.osgi-3.10.101.v20150820-1432.jar:]
>         at org.eclipse.osgi.storage.ManifestLocalization.getResourceBundle(ManifestLocalization.java:102)[org.eclipse.osgi-3.10.101.v20150820-1432.jar:]
>         at org.eclipse.osgi.storage.ManifestLocalization.getHeaders(ManifestLocalization.java:63)[org.eclipse.osgi-3.10.101.v20150820-1432.jar:]
>         at org.eclipse.osgi.internal.framework.EquinoxBundle.privGetHeaders(EquinoxBundle.java:471)[org.eclipse.osgi-3.10.101.v20150820-1432.jar:]
>         at org.eclipse.osgi.internal.framework.EquinoxBundle.getHeaders(EquinoxBundle.java:466)[org.eclipse.osgi-3.10.101.v20150820-1432.jar:]
>         at org.eclipse.osgi.internal.framework.EquinoxBundle.getHeaders(EquinoxBundle.java:460)[org.eclipse.osgi-3.10.101.v20150820-1432.jar:]
>         at org.apache.karaf.features.internal.service.Deployer.deploy(Deployer.java:850)[8:org.apache.karaf.features.core:4.0.8]
>         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)[:1.8.0]
>         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)[:1.8.0]
>         at java.lang.Thread.run(Thread.java:744)[:1.8.0]
>   Scheduler class: 'org.quartz.core.QuartzScheduler' - running locally.
>   Currently in standby mode.

A total of 200k of log and 10k of eventlog:

> pi@homeauto /var/log/openhab2 $ ll
> total 228
> drwxr-xr-x 11 root    root      4096 Jan  3 06:25 ..
> drwxr-xr-x  2 openhab openhab   4096 Jan  3 13:18 .
> -rw-rw-r--  1 openhab openhab 209942 Jan  3 13:21 openhab.log
> -rw-rw-r--  1 openhab openhab   9649 Jan  3 13:21 events.log

And then it dies.
Anyone have any hints where I should focus my attention?

erland_lestander · January 4, 2017, 12:02pm

No one else having problems starting the *4422 apt package?

erland_lestander · January 6, 2017, 3:02pm

Now starts, but still not functional,

shutdown is slow (or doesn’t work):

2017-01-06 15:06:53.025 [INFO ] [ache.karaf.main.ShutdownSocketThread] - Karaf shutdown socket: received shutdown command. Stopping framework...
2017-01-06 15:35:55.382 [INFO ] [pache.karaf.main.lock.SimpleFileLock] - Releasing lock /var/lib/openhab2/tmp/lock

Lot’s of leftover files in

pi@homeauto /var/lib/openhab2/tmp $ ll
total 48
drwxr-xr-x 11 openhab openhab 4096 Jan  6 11:21 ..
-rw-rw-r--  1 openhab openhab    0 Jan  6 11:22 lock
drwxrwxr-x  2 openhab openhab 4096 Jan  6 11:22 fileinstall--4655704924186944154
drwxrwxr-x  2 openhab openhab 4096 Jan  6 11:22 bundles
drwxrwxr-x  2 openhab openhab 4096 Jan  6 11:23 .paxweb8270408118287138986
drwxrwxr-x  6 openhab openhab 4096 Jan  6 11:24 mvn
drwxrwxr-x  2 openhab openhab 4096 Jan  6 11:25 libNRJavaSerial_HF_openhab_0
-rw-rw-r--  1 openhab openhab    4 Jan  6 12:10 karaf.pid
-rw-rw-r--  1 openhab openhab    5 Jan  6 12:10 port
drwxrwxr-x  2 openhab openhab 4096 Jan  6 12:10 fileinstall--5825308577805934846
drwxrwxr-x  2 openhab openhab 4096 Jan  6 12:10 .paxweb5028292986836876948
drwxrwxr-x 10 openhab openhab 4096 Jan  6 12:10 .
drwxrwxr-x  2 openhab openhab 4096 Jan  6 12:11 jna--1263185921

I only get Classic and Paper UI.

I’m lost …

erland_lestander · January 7, 2017, 10:42am

Still fighting this one.

My openhab.log is spammed with this:

2017-01-07 11:17:52.033 [INFO ] [g.apache.aries.spifly.dynamic.bundle] - Bundle Considered for SPI providers: org.eclipse.osgi
2017-01-07 11:17:52.102 [INFO ] [g.apache.aries.spifly.dynamic.bundle] - No 'SPI-Provider' Manifest header. Skipping bundle: org.eclipse.osgi
2017-01-07 11:17:52.104 [INFO ] [g.apache.aries.spifly.dynamic.bundle] - Bundle Considered for SPI providers: org.ops4j.pax.logging.pax-logging-api
2017-01-07 11:17:52.110 [INFO ] [g.apache.aries.spifly.dynamic.bundle] - No 'SPI-Provider' Manifest header. Skipping bundle: org.ops4j.pax.logging.pax-logging-api
2017-01-07 11:17:52.113 [INFO ] [g.apache.aries.spifly.dynamic.bundle] - Bundle Considered for SPI providers: org.ops4j.pax.logging.pax-logging-service
2017-01-07 11:17:52.117 [INFO ] [g.apache.aries.spifly.dynamic.bundle] - No 'SPI-Provider' Manifest header. Skipping bundle: org.ops4j.pax.logging.pax-logging-service
2017-01-07 11:17:52.120 [INFO ] [g.apache.aries.spifly.dynamic.bundle] - Bundle Considered for SPI providers: org.apache.felix.configadmin
2017-01-07 11:17:52.126 [INFO ] [g.apache.aries.spifly.dynamic.bundle] - No 'SPI-Provider' Manifest header. Skipping bundle: org.apache.felix.configadmin

at a glance it seems related to this:
https://issues.apache.org/jira/browse/ARIES-1584

Is it something old that have come back?