Possible bug on first start?

juelicher · January 16, 2017, 8:55pm

Hi,

currently I am trying to migrate my openhab test installation from my desktop to my test server (booth macOS 10.12.2, Oracle Java 8 Update 111 build 14).

On the test server I freshly extracted all folders from the openHAB 2 offline installation zip file (version from January 3rd, same as on my desktop). All the configuration was copied from my desktop. All pathes are the same, the user permissions are correct).

On my desktop OH2 starts without an error. On my test server I get the following exception on the first start of OH2:

1:28:32.349 [ERROR] [org.openhab.io.homekit              ] - FrameworkEvent ERROR - org.openhab.io.homekit
java.io.IOException: Exception in opening zip file: /srv/openHAB/userdata/cache/org.eclipse.osgi/202/0/bundleFile
	at org.eclipse.osgi.framework.util.SecureAction.getZipFile(SecureAction.java:305)[org.eclipse.osgi-3.10.101.v20150820-1432.jar:]
	at org.eclipse.osgi.storage.bundlefile.ZipBundleFile.basicOpen(ZipBundleFile.java:85)[org.eclipse.osgi-3.10.101.v20150820-1432.jar:]
	at org.eclipse.osgi.storage.bundlefile.ZipBundleFile.getZipFile(ZipBundleFile.java:98)[org.eclipse.osgi-3.10.101.v20150820-1432.jar:]
	at org.eclipse.osgi.storage.bundlefile.ZipBundleFile.checkedOpen(ZipBundleFile.java:65)[org.eclipse.osgi-3.10.101.v20150820-1432.jar:]
	at org.eclipse.osgi.storage.bundlefile.ZipBundleFile.getEntry(ZipBundleFile.java:232)[org.eclipse.osgi-3.10.101.v20150820-1432.jar:]
	at org.eclipse.osgi.internal.loader.classpath.ClasspathManager.findClassImpl(ClasspathManager.java:562)[org.eclipse.osgi-3.10.101.v20150820-1432.jar:]
	at org.eclipse.osgi.internal.loader.classpath.ClasspathManager.findLocalClassImpl(ClasspathManager.java:540)[org.eclipse.osgi-3.10.101.v20150820-1432.jar:]
	at org.eclipse.osgi.internal.loader.classpath.ClasspathManager.findLocalClass(ClasspathManager.java:527)[org.eclipse.osgi-3.10.101.v20150820-1432.jar:]
	at org.eclipse.osgi.internal.loader.ModuleClassLoader.findLocalClass(ModuleClassLoader.java:324)[org.eclipse.osgi-3.10.101.v20150820-1432.jar:]
	at org.eclipse.osgi.internal.loader.BundleLoader.findLocalClass(BundleLoader.java:327)[org.eclipse.osgi-3.10.101.v20150820-1432.jar:]
	at org.eclipse.osgi.internal.loader.BundleLoader.findClassInternal(BundleLoader.java:402)[org.eclipse.osgi-3.10.101.v20150820-1432.jar:]
	at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:352)[org.eclipse.osgi-3.10.101.v20150820-1432.jar:]
	at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:344)[org.eclipse.osgi-3.10.101.v20150820-1432.jar:]
	at org.eclipse.osgi.internal.loader.ModuleClassLoader.loadClass(ModuleClassLoader.java:160)[org.eclipse.osgi-3.10.101.v20150820-1432.jar:]
	at java.lang.ClassLoader.loadClass(ClassLoader.java:357)[:1.8.0_101]
	at io.netty.util.concurrent.DefaultPromise.notifyListeners(DefaultPromise.java:589)[202:org.openhab.io.homekit:2.0.0.201701032212]
	at io.netty.util.concurrent.DefaultPromise.setSuccess(DefaultPromise.java:397)[202:org.openhab.io.homekit:2.0.0.201701032212]
	at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:151)[202:org.openhab.io.homekit:2.0.0.201701032212]
	at io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:137)[202:org.openhab.io.homekit:2.0.0.201701032212]
	at java.lang.Thread.run(Thread.java:745)[:1.8.0_101]
Caused by: java.io.FileNotFoundException: /srv/openHAB/userdata/cache/org.eclipse.osgi/202/0/bundleFile (No such file or directory)
	at java.util.zip.ZipFile.open(Native Method)[:1.8.0_101]
	at java.util.zip.ZipFile.<init>(ZipFile.java:219)[:1.8.0_101]
	at java.util.zip.ZipFile.<init>(ZipFile.java:149)[:1.8.0_101]
	at java.util.zip.ZipFile.<init>(ZipFile.java:163)[:1.8.0_101]
	at org.eclipse.osgi.framework.util.SecureAction.getZipFile(SecureAction.java:288)[org.eclipse.osgi-3.10.101.v20150820-1432.jar:]
	... 19 more

I checkes, the mentioned file “/srv/openHAB/userdata/cache/org.eclipse.osgi/202/0/bundleFile” does not exist.

On the next start no such error is shown, although the file still does not exist. Homekit support is shown as installed in the Paper UI. But, as I have not used it, I can not test if it is functional.

Am I missing something or is this a bug in OH2?

Thanks for your help!

Juelicher

juelicher · January 16, 2017, 10:37pm

I did some more testing with the latest snapshot from openHAB.org.

With this version I don’t get the above mentioned error, but none of the transformations is installed, altthough I have package = expert in my addons.cfg. The following error is logged:

23:20:15.109 [ERROR] [core.karaf.internal.FeatureInstaller] - Failed installing 'openhab-transformation-xpath, openhab-transformation-map, openhab-transformation-javascript, openhab-transformation-xslt, openhab-transformation-regex, openhab-transformation-exec, openhab-transformation-scale, openhab-transformation-jsonpath': Unable to resolve root: missing requirement [root] osgi.identity; osgi.identity=openhab-binding-exec1; type=karaf.feature; version="[1.9.0.SNAPSHOT,1.9.0.SNAPSHOT]"; filter:="(&(osgi.identity=openhab-binding-exec1)(type=karaf.feature)(version>=1.9.0.SNAPSHOT)(version<=1.9.0.SNAPSHOT))"

Additionally openHAB tries to uninstall some bundles, which fails :

23:20:19.288 [ERROR] [core.karaf.internal.FeatureInstaller] - Failed uninstalling 'openhab-ui-cometvisu': Unable to resolve root: missing requirement [root] osgi.identity; osgi.identity=openhab-binding-exec1; type=karaf.feature; version="[1.9.0.SNAPSHOT,1.9.0.SNAPSHOT]"; filter:="(&(osgi.identity=openhab-binding-exec1)(type=karaf.feature)(version>=1.9.0.SNAPSHOT)(version<=1.9.0.SNAPSHOT))"


23:20:23.487 [ERROR] [core.karaf.internal.FeatureInstaller] - Failed uninstalling 'openhab-misc-homekit': Unable to resolve root: missing requirement [root] osgi.identity; osgi.identity=openhab-binding-exec1; type=karaf.feature; version="[1.9.0.SNAPSHOT,1.9.0.SNAPSHOT]"; filter:="(&(osgi.identity=openhab-binding-exec1)(type=karaf.feature)(version>=1.9.0.SNAPSHOT)(version<=1.9.0.SNAPSHOT))"

I have the following configuration in addons.cfg (all other entries are commented out):

package = expert

remote = true

legacy = true

experimental = true
binding = astro,caldav-command1,denon1,exec1,fritzboxtr0641,http1,hue,knx1,network,snmp1,tcp1,weather1,wol1

ui = basic, classic, cometvisu, habmin, habpanel, paper

persistence = db4o,jdbc-sqlite,mapdb,rrd4j

action = mail, prowl

misc = homekit, restdocs

I am sure I am missing something, but I just don’t find ist…

juelicher · January 16, 2017, 11:24pm

Some more testing:

Started a clean install of OH2, without modifying any of the configuration files
Stopped OH2 and copied my config files
Restarted OH2: Same behavior as above (transformations not installed, tried to uninstall homekit)
Stopped and restarted OH2. Only a warning regarding regex transformation:
00:02:31.051 [WARN ] [.core.transform.TransformationHelper] - Cannot get service reference for transformation service of type REGEX
00:02:31.051 [WARN ] [ab.binding.exec.internal.ExecBinding] - couldn’t transform response because transformationService of type ‘REGEX’ is unavailable
Stopped and restarted OH2: No more warnings.

So I am quite sure, that this is a bug in the startup behavior of OH2, I will fill a bug report tomorrow.