search

openhab / openhab-addons

Add-ons for openHAB
https://www.openhab.org/
Eclipse Public License 2.0
1.9k stars 3.6k forks source link

Bluetooth BlueZ Binding fails as Native Libraries not deployed #5680

Closed communig8-public closed 4 years ago

communig8-public commented 5 years ago

Working with the current snapshot, after installing the Bluetooth BlueZ Binding and attempting to configure a new Bluetooth BlueZ Adapter, the Thing displays "Status: UNINITIALIZED - HANDLER_INITIALIZING_ERROR BlueZ JNI connection cannot be established.”. The log shows Caused by: java.lang.UnsatisfiedLinkError: tinyb.BluetoothManager.getNativeAPIVersion()Ljava/lang/String;" On checking the code, this error is thrown if there is a problem using the Native Libraries included in the Binding bundle.

Expected Behavior

That the Thing initialise correctly, without error.

Current Behavior

When the binding is installed, the included Native Libraries libtinyb.so and libjavatinyb.so are not deployed leading to the error when a Bluetooth BlueZ Adapter is added/configured.

Steps to Reproduce

  1. Install the Bluetooth BlueZ Binding.
  2. Add a Bluetooth BlueZ Adapter Thing configured with its MAC.

Context

The problem prevents a Bluetooth BlueZ Adapter being configured and so prevents any other Things being created that need to use a Bluetooth BlueZ Adapter as a Bridge.

Environment

J-N-K commented 5 years ago

I had a quick look and I think this is similar to #5643. I‘ll provide a test-bundle ASAP.

J-N-K commented 5 years ago

Sorry for the delay. Please replace the installed tinyb bundle:

bundle:update <number> https://janessa.me/esh/intel-iot-devkit.tinyb-0.5.1.jar
communig8-public commented 5 years ago

What is the procedure for installing this update? I just want to be 100% certain.

J-N-K commented 5 years ago

Got to the karaf console (usually openhab-cli console).

Get the bundle number with bundle:list | grep -i tinyb. There should be a three-digit number in the first column of the output. Then use that number and type the command above. Could be that you need to start the bundle with bundle:start <number>. If that does not help, try restarting OH.

communig8-public commented 5 years ago

Still getting the same problem... java.lang.UnsatisfiedLinkError: tinyb.BluetoothManager.getNativeAPIVersion()Ljava/lang/String; I did notice that only the libtinyb.so library was deployed, the libjavatinyb.so library is not there...

find / -name tinyb /var/lib/openhab2/cache/org.eclipse.osgi/232/1/.cp/lib/armv6hf/libtinyb.so /var/lib/openhab2/tmp/a57b1ee9-bluetooth-manager-tinyb-1.3.3.jar /var/lib/openhab2/tmp/kar/openhab-addons-2.5.0-SNAPSHOT/org/sputnikdev/bluetooth-manager-tinyb /var/lib/openhab2/tmp/kar/openhab-addons-2.5.0-SNAPSHOT/org/sputnikdev/bluetooth-manager-tinyb/1.3.3/bluetooth-manager-tinyb-1.3.3.jar /srv/openhab2-userdata/cache/org.eclipse.osgi/232/1/.cp/lib/armv6hf/libtinyb.so /srv/openhab2-userdata/tmp/a57b1ee9-bluetooth-manager-tinyb-1.3.3.jar /srv/openhab2-userdata/tmp/kar/openhab-addons-2.5.0-SNAPSHOT/org/sputnikdev/bluetooth-manager-tinyb /srv/openhab2-userdata/tmp/kar/openhab-addons-2.5.0-SNAPSHOT/org/sputnikdev/bluetooth-manager-tinyb/1.3.3/bluetooth-manager-tinyb-1.3.3.jar

J-N-K commented 5 years ago

So it‘s better than before. I‘ll check why the other one is not deployed.

J-N-K commented 5 years ago

Can you show bundle:list? Just to make sure the wrong lib is not used any longer.

communig8-public commented 5 years ago

bundle:list START LEVEL 100 , List Threshold: 50 ID │ State │ Lvl │ Version │ Name ────┼────────┼─────┼───────────────────────┼────────────────────────────────────────────────────────────────────────────────────────────── 20 │ Active │ 80 │ 5.3.1.201602281253 │ OSGi JAX-RS Connector 21 │ Active │ 80 │ 2.8.2.v20180104-1110 │ Gson: Google Json Library for Java 22 │ Active │ 80 │ 18.0.0 │ Guava: Google Core Libraries for Java 23 │ Active │ 80 │ 21.0.0 │ Guava: Google Core Libraries for Java 24 │ Active │ 80 │ 2.5.0.201906031912 │ openHAB Add-ons :: Bundles :: Rfxcom Binding 25 │ Active │ 80 │ 3.0.0.v201312141243 │ Google Guice (No AOP) 26 │ Active │ 80 │ 3.18.1.GA │ Javassist 29 │ Active │ 80 │ 3.5.5 │ JmDNS 31 │ Active │ 80 │ 1.0.0 │ Units of Measurement API 33 │ Active │ 80 │ 1.1.0.Final │ Bean Validation API 35 │ Active │ 80 │ 2.0.1 │ javax.ws.rs-api 36 │ Active │ 80 │ 2.9.2 │ Joda-Time 37 │ Active │ 80 │ 3.2.0.v201101311130 │ ANTLR Runtime 39 │ Active │ 80 │ 3.2.1 │ Commons Collections 40 │ Active │ 80 │ 1.1 │ Commons Exec 41 │ Active │ 80 │ 2.2.0 │ Commons IO 42 │ Active │ 80 │ 2.6 │ Commons Lang 51 │ Active │ 80 │ 4.2.4 │ Apache Karaf :: OSGi Services :: Event 66 │ Active │ 80 │ 1.4.7.1 │ Apache ServiceMix :: Bundles :: xstream 68 │ Active │ 80 │ 4.12.0 │ Apache XBean OSGI Bundle Utilities 69 │ Active │ 80 │ 4.12.0 │ Apache XBean :: Classpath Resource Finder 70 │ Active │ 80 │ 2.12.0.v20160420-0247 │ EMF Common 71 │ Active │ 80 │ 2.12.0.v20160420-0247 │ EMF Ecore 72 │ Active │ 80 │ 2.11.0.v20160420-0247 │ EMF Change Model 73 │ Active │ 80 │ 2.12.0.v20160420-0247 │ EMF XML/XMI Persistence 74 │ Active │ 80 │ 3.9.0.v20170207-1454 │ Common Eclipse Runtime 79 │ Active │ 80 │ 9.4.11.v20180605 │ Jetty :: Http Utility 86 │ Active │ 80 │ 9.4.12.v20180830 │ Jetty :: Proxy 98 │ Active │ 80 │ 9.4.11.v20180605 │ Jetty :: Websocket :: Common 105 │ Active │ 80 │ 0.6.0.v20181130-0903 │ org.eclipse.lsp4j 106 │ Active │ 80 │ 0.6.0.v20181130-0903 │ org.eclipse.lsp4j.jsonrpc 107 │ Active │ 80 │ 2.17.0.v20190304-0518 │ Xtend Runtime Library 108 │ Active │ 80 │ 2.17.0.v20190304-0518 │ Xtend Macro Interfaces 109 │ Active │ 80 │ 2.17.0.v20190304-0545 │ Xtext 110 │ Active │ 80 │ 2.17.0.v20190304-0626 │ Xtext Common Types 111 │ Active │ 80 │ 2.17.0.v20190304-0545 │ Xtext IDE Core 112 │ Active │ 80 │ 2.17.0.v20190304-0545 │ Xtext Utility 113 │ Active │ 80 │ 2.17.0.v20190304-0626 │ Xbase Model 114 │ Active │ 80 │ 2.17.0.v20190304-0626 │ Xbase Generic IDE Services 115 │ Active │ 80 │ 2.17.0.v20190304-0518 │ Xbase Runtime Library 130 │ Active │ 80 │ 1.9.6 │ MIME streaming extension 132 │ Active │ 80 │ 7.0.0 │ org.objectweb.asm.commons 133 │ Active │ 80 │ 7.0.0 │ org.objectweb.asm.tree 134 │ Active │ 80 │ 2.5.0.201906040301 │ openHAB Core :: Bundles :: Core 135 │ Active │ 80 │ 2.5.0.201906040307 │ openHAB Core :: Bundles :: Audio 136 │ Active │ 80 │ 2.5.0.201906040317 │ openHAB Core :: Bundles :: OAuth2Client 137 │ Active │ 80 │ 2.5.0.201906040315 │ openHAB Core :: Bundles :: Binding XML 138 │ Active │ 90 │ 2.5.0.201906040312 │ openHAB Core :: Bundles :: Boot 139 │ Active │ 80 │ 2.5.0.201906040302 │ openHAB Core :: Bundles :: Configuration Core 140 │ Active │ 80 │ 2.5.0.201906040304 │ openHAB Core :: Bundles :: Configuration Discovery 141 │ Active │ 80 │ 2.5.0.201906040322 │ openHAB Core :: Bundles :: Configuration mDNS Discovery 142 │ Active │ 80 │ 2.5.0.201906040323 │ openHAB Core :: Bundles :: Configuration Dispatcher 143 │ Active │ 75 │ 2.5.0.201906040314 │ openHAB Core :: Bundles :: Configuration XML 144 │ Active │ 80 │ 2.5.0.201906040315 │ openHAB Core :: Bundles :: ID 145 │ Active │ 80 │ 2.5.0.201906040303 │ openHAB Core :: Bundles :: Console 146 │ Active │ 80 │ 2.5.0.201906040318 │ openHAB Core :: Bundles :: Console for OSGi runtime Karaf 147 │ Active │ 80 │ 2.5.0.201906040307 │ openHAB Core :: Bundles :: HTTP Interface 149 │ Active │ 80 │ 2.5.0.201906040319 │ openHAB Core :: Bundles :: Monitor 150 │ Active │ 80 │ 2.5.0.201906040304 │ openHAB Core :: Bundles :: Network I/O 151 │ Active │ 80 │ 2.5.0.201906040315 │ openHAB Core :: Bundles :: REST Interface 152 │ Active │ 80 │ 2.5.0.201906040319 │ openHAB Core :: Bundles :: REST Interface 153 │ Active │ 80 │ 2.5.0.201906040320 │ openHAB Core :: Bundles :: REST mDNS Announcer 154 │ Active │ 80 │ 2.5.0.201906040320 │ openHAB Core :: Bundles :: REST JAX-RS Optimizations 155 │ Active │ 80 │ 2.5.0.201906040320 │ openHAB Core :: Bundles :: Sitemap REST Interface 156 │ Active │ 80 │ 2.5.0.201906040320 │ openHAB Core :: Bundles :: SSE Interface 157 │ Active │ 80 │ 2.5.0.201906040321 │ openHAB Core :: Bundles :: Voice REST Interface 158 │ Active │ 80 │ 2.5.0.201906040317 │ openHAB Core :: Bundles :: mDNS Service 159 │ Active │ 80 │ 2.5.0.201906040314 │ openHAB Core :: Bundles :: Karaf Integration 160 │ Active │ 80 │ 2.5.0.201906040305 │ openHAB Core :: Bundles :: Model Core 161 │ Active │ 80 │ 2.5.0.201906040313 │ openHAB Core :: Bundles :: Model Items 162 │ Active │ 80 │ 2.5.0.201906040325 │ openHAB Core :: Bundles :: Model Item IDE 163 │ Active │ 80 │ 2.5.0.201906040325 │ openHAB Core :: Bundles :: Model Items Runtime 164 │ Active │ 80 │ 2.5.0.201906040329 │ openHAB Core :: Bundles :: Language Server 165 │ Active │ 80 │ 2.5.0.201906040306 │ openHAB Core :: Bundles :: Model Persistence 166 │ Active │ 80 │ 2.5.0.201906040326 │ openHAB Core :: Bundles :: Model Persistence IDE 167 │ Active │ 80 │ 2.5.0.201906040329 │ openHAB Core :: Bundles :: Model Persistence Runtime 168 │ Active │ 80 │ 2.5.0.201906040310 │ openHAB Core :: Bundles :: Model Rules 169 │ Active │ 80 │ 2.5.0.201906040326 │ openHAB Core :: Bundles :: Model Rule IDE 170 │ Active │ 80 │ 2.5.0.201906040310 │ openHAB Core :: Bundles :: Model Rules Runtime 171 │ Active │ 80 │ 2.5.0.201906040308 │ openHAB Core :: Bundles :: Model Script 172 │ Active │ 80 │ 2.5.0.201906040327 │ openHAB Core :: Bundles :: Model Script IDE 173 │ Active │ 80 │ 2.5.0.201906040330 │ openHAB Core :: Bundles :: Model Script Runtime 174 │ Active │ 80 │ 2.5.0.201906040312 │ openHAB Core :: Bundles :: Model Sitemap 175 │ Active │ 80 │ 2.5.0.201906040327 │ openHAB Core :: Bundles :: Model Sitemap IDE 176 │ Active │ 80 │ 2.5.0.201906040330 │ openHAB Core :: Bundles :: Model Sitemap Runtime 177 │ Active │ 80 │ 2.5.0.201906040328 │ openHAB Core :: Bundles :: Model Thing 178 │ Active │ 80 │ 2.5.0.201906040329 │ openHAB Core :: Bundles :: Model Thing IDE 179 │ Active │ 80 │ 2.5.0.201906040330 │ openHAB Core :: Bundles :: Model Thing Runtime 180 │ Active │ 80 │ 2.5.0.201906040306 │ openHAB Core :: Bundles :: Persistence 181 │ Active │ 80 │ 2.5.0.201906040304 │ openHAB Core :: Bundles :: Scheduler Service 182 │ Active │ 80 │ 2.5.0.201906040316 │ openHAB Core :: Bundles :: Semantics 183 │ Active │ 80 │ 2.5.0.201906040331 │ openHAB Core :: Bundles :: JSON Storage 184 │ Active │ 80 │ 2.5.0.201906040303 │ openHAB Core :: Bundles :: Thing 185 │ Active │ 75 │ 2.5.0.201906040316 │ openHAB Core :: Bundles :: Thing XML 186 │ Active │ 80 │ 2.5.0.201906040307 │ openHAB Core :: Bundles :: Transformation Service 187 │ Active │ 80 │ 2.5.0.201906040313 │ openHAB Core :: Bundles :: UI 188 │ Active │ 80 │ 2.5.0.201906040330 │ openHAB Core :: Bundles :: UI Icon Support 189 │ Active │ 80 │ 2.5.0.201906040307 │ openHAB Core :: Bundles :: Voice 199 │ Active │ 80 │ 1.0.2 │ Units of Measurement Common Library 200 │ Active │ 80 │ 1.0.8 │ Units of Measurement Implementation for Java SE 204 │ Active │ 80 │ 3.15.0.OH2 │ nrjavaserial 205 │ Active │ 80 │ 1.0.1 │ JLayer 206 │ Active │ 80 │ 3.3.0 │ Commons Net 207 │ Active │ 80 │ 2.5.2 │ JUPnP Library 208 │ Active │ 80 │ 2.5.0.201906041542 │ openHAB Add-ons :: Bundles :: Amazon Echo Control Binding 209 │ Active │ 80 │ 2.5.0.201906041545 │ openHAB Add-ons :: Bundles :: CM11A Binding 210 │ Active │ 80 │ 2.5.0.201906041551 │ openHAB Add-ons :: Bundles :: Kodi Binding 211 │ Active │ 80 │ 2.5.0.201906041559 │ openHAB Add-ons :: Bundles :: Rfxcom Binding 212 │ Active │ 80 │ 2.5.0.201906040323 │ openHAB Core :: Bundles :: Configuration UPnP Discovery 213 │ Active │ 80 │ 2.5.0.201906040323 │ openHAB Core :: Bundles :: Configuration USB-Serial Discovery 214 │ Active │ 80 │ 2.5.0.201906040323 │ openHAB Core :: Bundles :: Configuration USB-Serial Discovery for Linux using sysfs scanning 215 │ Active │ 80 │ 2.5.0.201906040324 │ openHAB Core :: Bundles :: Configuration Serial 216 │ Active │ 80 │ 2.5.0.201906040317 │ openHAB Core :: Bundles :: Serial Transport 217 │ Active │ 80 │ 2.5.0.201906040321 │ openHAB Core :: Bundles :: Serial Transport for RXTX 218 │ Active │ 80 │ 2.5.0.201906040322 │ openHAB Core :: Bundles :: Serial Transport for RFC2217 219 │ Active │ 80 │ 2.5.0.201906040322 │ openHAB Core :: Bundles :: UPnP Transport 220 │ Active │ 80 │ 2.5.0.201906041606 │ openHAB Add-ons :: Bundles :: IO :: Java Sound Support 221 │ Active │ 80 │ 2.5.0.201906032234 │ openHAB UI :: Basic UI 222 │ Active │ 80 │ 2.5.0.201906032228 │ openHAB UI :: Dashboard UI 223 │ Active │ 80 │ 2.5.0.201906032242 │ openHAB UI :: HomeBuilder UI 224 │ Active │ 80 │ 2.5.0.201906032246 │ openHAB UI :: Classic Icon Set 225 │ Active │ 80 │ 2.5.0.201906032246 │ openHAB UI :: Paper UI 226 │ Active │ 80 │ 2.5.0.201906032240 │ openHAB UI :: HABPanel user interface 227 │ Active │ 80 │ 2.5.0.201906041543 │ openHAB Add-ons :: Bundles :: Bluetooth Binding 228 │ Active │ 80 │ 2.5.0.201906041543 │ openHAB Add-ons :: Bundles :: BlueGiga Bluetooth Adapter 229 │ Active │ 80 │ 2.5.0.201906041543 │ openHAB Add-ons :: Bundles :: BlueZ Bluetooth Adapter 230 │ Active │ 80 │ 2.5.0.201906041543 │ openHAB Add-ons :: Bundles :: Blukii Bluetooth Adapter 231 │ Active │ 80 │ 2.5.0.201906041543 │ openHAB Add-ons :: Bundles :: RuuviTag Bluetooth Adapter 232 │ Active │ 80 │ 0.5.1 │ TinyB

J-N-K commented 5 years ago

I think I used the wrong syntax for the native code. The bundle above has been update, could you check if it is better now?

communig8-public commented 5 years ago

Both libraries are now deploying but things just got worse...

2019-06-08 08:55:12.227 [ERROR] [org.openhab.binding.bluetooth.bluez ] - bundle org.openhab.binding.bluetooth.bluez:2.5.0.201906041543 (229)[org.openhab.binding.bluetooth.bluez.internal.discovery.BlueZDiscoveryService(233)] : The activate method has thrown an exception java.lang.NullPointerException: null

2019-06-08 08:55:12.315 [WARN ] [org.openhab.binding.bluetooth.bluez ] - FrameworkEvent WARNING - org.openhab.binding.bluetooth.bluez org.osgi.framework.ServiceException: org.apache.felix.scr.impl.manager.SingleComponentManager.getService() returned a null service object

2019-06-08 08:55:12.310 [ERROR] [org.openhab.binding.bluetooth.bluez ] - bundle org.openhab.binding.bluetooth.bluez:2.5.0.201906041543 (229)[org.openhab.binding.bluetooth.bluez.internal.discovery.BlueZDiscoveryService(233)] : The activate method has thrown an exception java.lang.NullPointerException: null

2019-06-08 08:55:12.461 [WARN ] [org.openhab.binding.bluetooth.bluez ] - FrameworkEvent WARNING - org.openhab.binding.bluetooth.bluez org.osgi.framework.ServiceException: org.apache.felix.scr.impl.manager.SingleComponentManager.getService() returned a null service object

2019-06-08 08:55:12.495 [ERROR] [org.openhab.binding.bluetooth.bluez ] - bundle org.openhab.binding.bluetooth.bluez:2.5.0.201906041543 (229)[org.openhab.binding.bluetooth.bluez.internal.discovery.BlueZDiscoveryService(233)] : The activate method has thrown an exception java.lang.NullPointerException: null

2019-06-08 08:55:12.991 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'ThingHandler.initialize()' on 'org.openhab.binding.bluetooth.bluez.handler.BlueZBridgeHandler@14f929': null java.lang.NullPointerException: null

2019-06-08 08:55:13.055 [ERROR] [core.thing.internal.ThingManagerImpl] - Exception occurred while initializing handler of thing 'bluetooth:bluez:a07c6635': null java.lang.NullPointerException: null

2019-06-08 08:55:13.328 [hingStatusInfoChangedEvent] - 'bluetooth:bluez:a07c6635' changed from INITIALIZING to UNINITIALIZED (HANDLER_INITIALIZING_ERROR)

J-N-K commented 5 years ago

Thanks. I‘ll check if I can do something about hat.

J-N-K commented 5 years ago

Can you enable debug-logging?

J-N-K commented 5 years ago

And please update the bluez-bundle with:

bundle:update <number> https://janessa.me/esh/org.openhab.binding.bluetooth.bluez-2.5.0-SNAPSHOT.jar
communig8-public commented 5 years ago

After updating the bundle, and adding the Thing for the Bluez adapter, still getting...

2019-06-08 13:29:16.974 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'ThingHandler.initialize()' on 'org.openhab.binding.bluetooth.bluez.handler.BlueZBridgeHandler@49d3a7': null java.lang.NullPointerException: null

2019-06-08 13:29:16.999 [ERROR] [core.thing.internal.ThingManagerImpl] - Exception occurred while initializing handler of thing 'bluetooth:bluez:1a299271': null java.lang.NullPointerException: null

J-N-K commented 5 years ago

I updated the bundle. And please show the full debug log.

communig8-public commented 5 years ago

Do you mean you want debugging set on org.openhab.binding.bluetooth.bluez ?

communig8-public commented 5 years ago

Assuming you do, it looks like this when adding the Adapter...

2019-06-08 15:34:44.637 [DEBUG] [org.openhab.binding.bluetooth.bluez ] - ServiceEvent REGISTERED - {org.openhab.binding.bluetooth.BluetoothAdapter}={service.id=404, service.bundleid=235, service.scope=singleton} - org.openhab.binding.bluetooth.bluez

2019-06-08 15:34:44.710 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'ThingHandler.initialize()' on 'org.openhab.binding.bluetooth.bluez.handler.BlueZBridgeHandler@13bf98d': null

java.lang.NullPointerException: null

at org.openhab.binding.bluetooth.bluez.handler.BlueZBridgeHandler.initialize(BlueZBridgeHandler.java:103) ~[?:?]

at sun.reflect.GeneratedMethodAccessor29.invoke(Unknown Source) ~[?:?]

at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]

at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?]

at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:153) [134:org.openhab.core:2.5.0.201906040301]

at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:53) [134:org.openhab.core:2.5.0.201906040301]

at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]

at java.lang.Thread.run(Thread.java:748) [?:?]

2019-06-08 15:34:44.735 [ERROR] [core.thing.internal.ThingManagerImpl] - Exception occurred while initializing handler of thing 'bluetooth:bluez:0646642a': null

java.lang.NullPointerException: null

at org.openhab.binding.bluetooth.bluez.handler.BlueZBridgeHandler.initialize(BlueZBridgeHandler.java:103) ~[?:?]

at sun.reflect.GeneratedMethodAccessor29.invoke(Unknown Source) ~[?:?]

at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]

at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?]

at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:153) [134:org.openhab.core:2.5.0.201906040301]

at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:53) [134:org.openhab.core:2.5.0.201906040301]

at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]

at java.lang.Thread.run(Thread.java:748) [?:?]
J-N-K commented 5 years ago

That looks really weird. I get:

15:16:27.783 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'bluetooth:bluez:a721b1dd' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
15:16:32.781 [WARN ] [.core.thing.internal.ThingManagerImpl] - Initializing handler for thing 'bluetooth:bluez:a721b1dd' takes more than 5000ms.
15:16:52.796 [ERROR] [rnal.common.AbstractInvocationHandler] - An error occurred while calling method 'ThingHandler.initialize()' on 'org.openhab.binding.bluetooth.bluez.handler.BlueZBridgeHandler@769761d4': Cannot access BlueZ layer.
java.lang.IllegalStateException: Cannot access BlueZ layer.
        at org.openhab.binding.bluetooth.bluez.handler.BlueZBridgeHandler.initialize(BlueZBridgeHandler.java:105) ~[?:?]
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
        at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?]
        at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:153) [133:org.openhab.core:2.5.0.201906040301]
        at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:53) [133:org.openhab.core:2.5.0.201906040301]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
        at java.lang.Thread.run(Thread.java:748) [?:?]
Caused by: java.lang.RuntimeException: Error getting object manager client: Fehler beim Aufruf von StartServiceByName für org.bluez: Zeitüberschreitung wurde erreicht
        at tinyb.BluetoothManager.getNativeAPIVersion(Native Method) ~[?:?]
        at tinyb.BluetoothManager.getBluetoothManager(BluetoothManager.java:304) ~[?:?]
        at org.openhab.binding.bluetooth.bluez.handler.BlueZBridgeHandler.initialize(BlueZBridgeHandler.java:93) ~[?:?]
        ... 10 more
15:16:52.816 [ERROR] [.core.thing.internal.ThingManagerImpl] - Exception occurred while initializing handler of thing 'bluetooth:bluez:a721b1dd': Cannot access BlueZ layer.
java.lang.IllegalStateException: Cannot access BlueZ layer.
        at org.openhab.binding.bluetooth.bluez.handler.BlueZBridgeHandler.initialize(BlueZBridgeHandler.java:105) ~[?:?]
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
        at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?]
        at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:153) [133:org.openhab.core:2.5.0.201906040301]
        at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:53) [133:org.openhab.core:2.5.0.201906040301]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
        at java.lang.Thread.run(Thread.java:748) [?:?]
Caused by: java.lang.RuntimeException: Error getting object manager client: Fehler beim Aufruf von StartServiceByName für org.bluez: Zeitüberschreitung wurde erreicht
        at tinyb.BluetoothManager.getNativeAPIVersion(Native Method) ~[?:?]
        at tinyb.BluetoothManager.getBluetoothManager(BluetoothManager.java:304) ~[?:?]
        at org.openhab.binding.bluetooth.bluez.handler.BlueZBridgeHandler.initialize(BlueZBridgeHandler.java:93) ~[?:?]
        ... 10 more
15:16:52.833 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'bluetooth:bluez:a721b1dd' changed from INITIALIZING to UNINITIALIZED (HANDLER_INITIALIZING_ERROR): Cannot access BlueZ layer.

which shows that the initialization code is evil because it blocks for more than 5s but also works. I don't understand why you get a NPE on calling initialize(). The only difference I see is that you are on arm while my VM is x86. Not sure how I should debug that.

Can you show bundle:list -s once more and try what happens if you restart OH?

communig8-public commented 5 years ago

Restarted and I get...

2019-06-08 16:55:11.874 [DEBUG] [org.openhab.binding.bluetooth.bluez ] - ServiceEvent REGISTERED - {org.openhab.binding.bluetooth.BluetoothAdapter}={service.id=395, service.bundleid=254, service.scope=singleton} - org.openhab.binding.bluetooth.bluez

2019-06-08 16:55:11.926 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'ThingHandler.initialize()' on 'org.openhab.binding.bluetooth.bluez.handler.BlueZBridgeHandler@151da5a': null

java.lang.NullPointerException: null

at org.openhab.binding.bluetooth.bluez.handler.BlueZBridgeHandler.initialize(BlueZBridgeHandler.java:103) ~[?:?]

at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]

at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]

at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]

at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?]

at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:153) [134:org.openhab.core:2.5.0.201906040301]

at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:53) [134:org.openhab.core:2.5.0.201906040301]

at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]

at java.lang.Thread.run(Thread.java:748) [?:?]

2019-06-08 16:55:11.942 [ERROR] [core.thing.internal.ThingManagerImpl] - Exception occurred while initializing handler of thing 'bluetooth:bluez:6692a5df': null

java.lang.NullPointerException: null

at org.openhab.binding.bluetooth.bluez.handler.BlueZBridgeHandler.initialize(BlueZBridgeHandler.java:103) ~[?:?]

at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]

at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]

at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]

at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?]

at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:153) [134:org.openhab.core:2.5.0.201906040301]

at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:53) [134:org.openhab.core:2.5.0.201906040301]

at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]

at java.lang.Thread.run(Thread.java:748) [?:?]
communig8-public commented 5 years ago

bundle:list -s
START LEVEL 100 , List Threshold: 50 ID │ State │ Lvl │ Version │ Symbolic name ────┼─────────┼─────┼───────────────────────┼───────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────── 20 │ Active │ 80 │ 5.3.1.201602281253 │ com.eclipsesource.jaxrs.publisher 21 │ Active │ 80 │ 2.8.2.v20180104-1110 │ com.google.gson 22 │ Active │ 80 │ 18.0.0 │ com.google.guava 23 │ Active │ 80 │ 21.0.0 │ com.google.guava 24 │ Active │ 80 │ 2.5.0.201906031912 │ org.openhab.binding.rfxcom 25 │ Active │ 80 │ 3.0.0.v201312141243 │ com.google.inject 26 │ Active │ 80 │ 3.18.1.GA │ javassist 29 │ Active │ 80 │ 3.5.5 │ javax.jmdns 31 │ Active │ 80 │ 1.0.0 │ javax.measure.unit-api 33 │ Active │ 80 │ 1.1.0.Final │ javax.validation.api 35 │ Active │ 80 │ 2.0.1 │ javax.ws.rs-api 36 │ Active │ 80 │ 2.9.2 │ joda-time 37 │ Active │ 80 │ 3.2.0.v201101311130 │ org.antlr.runtime 39 │ Active │ 80 │ 3.2.1 │ org.apache.commons.collections 40 │ Active │ 80 │ 1.1 │ org.apache.commons.exec 41 │ Active │ 80 │ 2.2.0 │ org.apache.commons.io 42 │ Active │ 80 │ 2.6 │ org.apache.commons.lang 51 │ Active │ 80 │ 4.2.4 │ org.apache.karaf.event 66 │ Active │ 80 │ 1.4.7.1 │ org.apache.servicemix.bundles.xstream 68 │ Active │ 80 │ 4.12.0 │ org.apache.xbean.bundleutils 69 │ Active │ 80 │ 4.12.0 │ org.apache.xbean.finder 70 │ Active │ 80 │ 2.12.0.v20160420-0247 │ org.eclipse.emf.common 71 │ Active │ 80 │ 2.12.0.v20160420-0247 │ org.eclipse.emf.ecore 72 │ Active │ 80 │ 2.11.0.v20160420-0247 │ org.eclipse.emf.ecore.change 73 │ Active │ 80 │ 2.12.0.v20160420-0247 │ org.eclipse.emf.ecore.xmi 74 │ Active │ 80 │ 3.9.0.v20170207-1454 │ org.eclipse.equinox.common 79 │ Active │ 80 │ 9.4.11.v20180605 │ org.eclipse.jetty.http 86 │ Active │ 80 │ 9.4.12.v20180830 │ org.eclipse.jetty.proxy 98 │ Active │ 80 │ 9.4.11.v20180605 │ org.eclipse.jetty.websocket.common 105 │ Active │ 80 │ 0.6.0.v20181130-0903 │ org.eclipse.lsp4j 106 │ Active │ 80 │ 0.6.0.v20181130-0903 │ org.eclipse.lsp4j.jsonrpc 107 │ Active │ 80 │ 2.17.0.v20190304-0518 │ org.eclipse.xtend.lib 108 │ Active │ 80 │ 2.17.0.v20190304-0518 │ org.eclipse.xtend.lib.macro 109 │ Active │ 80 │ 2.17.0.v20190304-0545 │ org.eclipse.xtext 110 │ Active │ 80 │ 2.17.0.v20190304-0626 │ org.eclipse.xtext.common.types 111 │ Active │ 80 │ 2.17.0.v20190304-0545 │ org.eclipse.xtext.ide 112 │ Active │ 80 │ 2.17.0.v20190304-0545 │ org.eclipse.xtext.util 113 │ Active │ 80 │ 2.17.0.v20190304-0626 │ org.eclipse.xtext.xbase 114 │ Active │ 80 │ 2.17.0.v20190304-0626 │ org.eclipse.xtext.xbase.ide 115 │ Active │ 80 │ 2.17.0.v20190304-0518 │ org.eclipse.xtext.xbase.lib 130 │ Active │ 80 │ 1.9.6 │ org.jvnet.mimepull 132 │ Active │ 80 │ 7.0.0 │ org.objectweb.asm.commons 133 │ Active │ 80 │ 7.0.0 │ org.objectweb.asm.tree 134 │ Active │ 80 │ 2.5.0.201906040301 │ org.openhab.core 135 │ Active │ 80 │ 2.5.0.201906040307 │ org.openhab.core.audio 136 │ Active │ 80 │ 2.5.0.201906040317 │ org.openhab.core.auth.oauth2client 137 │ Active │ 80 │ 2.5.0.201906040315 │ org.openhab.core.binding.xml 138 │ Active │ 90 │ 2.5.0.201906040312 │ org.openhab.core.boot 139 │ Active │ 80 │ 2.5.0.201906040302 │ org.openhab.core.config.core 140 │ Active │ 80 │ 2.5.0.201906040304 │ org.openhab.core.config.discovery 141 │ Active │ 80 │ 2.5.0.201906040322 │ org.openhab.core.config.discovery.mdns 142 │ Active │ 80 │ 2.5.0.201906040323 │ org.openhab.core.config.dispatch 143 │ Active │ 75 │ 2.5.0.201906040314 │ org.openhab.core.config.xml 144 │ Active │ 80 │ 2.5.0.201906040315 │ org.openhab.core.id 145 │ Active │ 80 │ 2.5.0.201906040303 │ org.openhab.core.io.console 146 │ Active │ 80 │ 2.5.0.201906040318 │ org.openhab.core.io.console.karaf 147 │ Active │ 80 │ 2.5.0.201906040307 │ org.openhab.core.io.http 149 │ Active │ 80 │ 2.5.0.201906040319 │ org.openhab.core.io.monitor 150 │ Active │ 80 │ 2.5.0.201906040304 │ org.openhab.core.io.net 151 │ Active │ 80 │ 2.5.0.201906040315 │ org.openhab.core.io.rest 152 │ Active │ 80 │ 2.5.0.201906040319 │ org.openhab.core.io.rest.core 153 │ Active │ 80 │ 2.5.0.201906040320 │ org.openhab.core.io.rest.mdns 154 │ Active │ 80 │ 2.5.0.201906040320 │ org.openhab.core.io.rest.optimize 155 │ Active │ 80 │ 2.5.0.201906040320 │ org.openhab.core.io.rest.sitemap 156 │ Active │ 80 │ 2.5.0.201906040320 │ org.openhab.core.io.rest.sse 157 │ Active │ 80 │ 2.5.0.201906040321 │ org.openhab.core.io.rest.voice 158 │ Active │ 80 │ 2.5.0.201906040317 │ org.openhab.core.io.transport.mdns 159 │ Active │ 80 │ 2.5.0.201906040314 │ org.openhab.core.karaf 160 │ Active │ 80 │ 2.5.0.201906040305 │ org.openhab.core.model.core 161 │ Active │ 80 │ 2.5.0.201906040313 │ org.openhab.core.model.item 162 │ Active │ 80 │ 2.5.0.201906040325 │ org.openhab.core.model.item.ide 163 │ Active │ 80 │ 2.5.0.201906040325 │ org.openhab.core.model.item.runtime 164 │ Active │ 80 │ 2.5.0.201906040329 │ org.openhab.core.model.lsp 165 │ Active │ 80 │ 2.5.0.201906040306 │ org.openhab.core.model.persistence 166 │ Active │ 80 │ 2.5.0.201906040326 │ org.openhab.core.model.persistence.ide 167 │ Active │ 80 │ 2.5.0.201906040329 │ org.openhab.core.model.persistence.runtime 168 │ Active │ 80 │ 2.5.0.201906040310 │ org.openhab.core.model.rule 169 │ Active │ 80 │ 2.5.0.201906040326 │ org.openhab.core.model.rule.ide 170 │ Active │ 80 │ 2.5.0.201906040310 │ org.openhab.core.model.rule.runtime 171 │ Active │ 80 │ 2.5.0.201906040308 │ org.openhab.core.model.script 172 │ Active │ 80 │ 2.5.0.201906040327 │ org.openhab.core.model.script.ide 173 │ Active │ 80 │ 2.5.0.201906040330 │ org.openhab.core.model.script.runtime 174 │ Active │ 80 │ 2.5.0.201906040312 │ org.openhab.core.model.sitemap 175 │ Active │ 80 │ 2.5.0.201906040327 │ org.openhab.core.model.sitemap.ide 176 │ Active │ 80 │ 2.5.0.201906040330 │ org.openhab.core.model.sitemap.runtime 177 │ Active │ 80 │ 2.5.0.201906040328 │ org.openhab.core.model.thing 178 │ Active │ 80 │ 2.5.0.201906040329 │ org.openhab.core.model.thing.ide 179 │ Active │ 80 │ 2.5.0.201906040330 │ org.openhab.core.model.thing.runtime 180 │ Active │ 80 │ 2.5.0.201906040306 │ org.openhab.core.persistence 181 │ Active │ 80 │ 2.5.0.201906040304 │ org.openhab.core.scheduler 182 │ Active │ 80 │ 2.5.0.201906040316 │ org.openhab.core.semantics 183 │ Active │ 80 │ 2.5.0.201906040331 │ org.openhab.core.storage.json 184 │ Active │ 80 │ 2.5.0.201906040303 │ org.openhab.core.thing 185 │ Active │ 75 │ 2.5.0.201906040316 │ org.openhab.core.thing.xml 186 │ Active │ 80 │ 2.5.0.201906040307 │ org.openhab.core.transform 187 │ Active │ 80 │ 2.5.0.201906040313 │ org.openhab.core.ui 188 │ Active │ 80 │ 2.5.0.201906040330 │ org.openhab.core.ui.icon 189 │ Active │ 80 │ 2.5.0.201906040307 │ org.openhab.core.voice 199 │ Active │ 80 │ 1.0.2 │ tec.uom.lib.uom-lib-common 200 │ Active │ 80 │ 1.0.8 │ tec.uom.se 204 │ Active │ 80 │ 3.15.0.OH2 │ com.neuronrobotics.nrjavaserial 205 │ Active │ 80 │ 1.0.1 │ javazoom.jlayer 206 │ Active │ 80 │ 3.3.0 │ org.apache.commons.net 207 │ Active │ 80 │ 2.5.2 │ org.jupnp 209 │ Active │ 80 │ 2.5.0.201906041545 │ org.openhab.binding.cm11a 210 │ Active │ 80 │ 2.5.0.201906041551 │ org.openhab.binding.kodi 211 │ Active │ 80 │ 2.5.0.201906041559 │ org.openhab.binding.rfxcom 212 │ Active │ 80 │ 2.5.0.201906040323 │ org.openhab.core.config.discovery.upnp 213 │ Active │ 80 │ 2.5.0.201906040323 │ org.openhab.core.config.discovery.usbserial 214 │ Active │ 80 │ 2.5.0.201906040323 │ org.openhab.core.config.discovery.usbserial.linuxsysfs 215 │ Active │ 80 │ 2.5.0.201906040324 │ org.openhab.core.config.serial 216 │ Active │ 80 │ 2.5.0.201906040317 │ org.openhab.core.io.transport.serial 217 │ Active │ 80 │ 2.5.0.201906040321 │ org.openhab.core.io.transport.serial.rxtx 218 │ Active │ 80 │ 2.5.0.201906040322 │ org.openhab.core.io.transport.serial.rxtx.rfc2217 219 │ Active │ 80 │ 2.5.0.201906040322 │ org.openhab.core.io.transport.upnp 220 │ Active │ 80 │ 2.5.0.201906041606 │ org.openhab.io.javasound 221 │ Active │ 80 │ 2.5.0.201906032234 │ org.openhab.ui.basic 222 │ Active │ 80 │ 2.5.0.201906032228 │ org.openhab.ui.dashboard 223 │ Active │ 80 │ 2.5.0.201906032242 │ org.openhab.ui.homebuilder 224 │ Active │ 80 │ 2.5.0.201906032246 │ org.openhab.ui.iconset.classic 225 │ Active │ 80 │ 2.5.0.201906032246 │ org.openhab.ui.paper 226 │ Active │ 80 │ 2.5.0.201906032240 │ org.openhab.ui.reactor.bundles 252 │ Active │ 80 │ 2.5.0.201906041543 │ org.openhab.binding.bluetooth 253 │ Active │ 80 │ 2.5.0.201906041543 │ org.openhab.binding.bluetooth.bluegiga 254 │ Waiting │ 80 │ 2.5.0.201906081323 │ org.openhab.binding.bluetooth.bluez 255 │ Active │ 80 │ 2.5.0.201906041543 │ org.openhab.binding.bluetooth.blukii 256 │ Active │ 80 │ 2.5.0.201906041543 │ org.openhab.binding.bluetooth.ruuvitag 257 │ Active │ 80 │ 0.5.1 │ intel-iot-devkit.tinyb

communig8-public commented 5 years ago

Hi, any progress on this?

J-N-K commented 5 years ago

No. I found a Raspi, but either the SD card or the reader was broken. I ordered a new one, they should arrive today.

communig8-public commented 5 years ago

Ok so you're looking at this as a Pi specific issue then.

J-N-K commented 5 years ago

I think it‘s a problem with the native code. Since I get different errors (which are probably related to missing hardware) on my x86 machine.

J-N-K commented 5 years ago

Can you confirm that this worked before? Which platform are you using exactly?

communig8-public commented 5 years ago

Can you confirm that this worked before? Which platform are you using exactly?

I am using OpenHabian on a Raspberry Pi 3B. It worked ok using the stable release and the testing 2.4.0 release but not on the snapshot.

J-N-K commented 5 years ago

Ok, so we are using the same hardware I ordered. I can confirm your problem and will check what needs to be done.

communig8-public commented 5 years ago

OK thanks

J-N-K commented 5 years ago

I have updated the link to the bluez bundle above. Can you check if this works for you?

communig8-public commented 5 years ago

That's done it :-) I can see my RuuviTags too. Thanks very much.

tomasz-kos commented 5 years ago

I have same problem, on stable release 2.4.0 (openhabian on RPi2B) bluetooth binding works ok - BT dongle was detected and I could detect beacons. But I wanted to use RuuviTags binding so I switched to testing release 2.5.0M3. My BT dongle doesn't show up in Inbox. Messages similar as in thread above:

2019-10-16 11:55:54.321 [ERROR] [org.openhab.binding.bluetooth.bluez ] - bundle org.openhab.binding.bluetooth.bluez:2.5.0.M3 (268)[org.openhab.binding.bluetooth.bluez.internal.discovery.BlueZDiscoveryService(312)] : The activate method has thrown an exception
java.lang.NullPointerException: null

2019-10-16 11:55:54.530 [WARN ] [org.openhab.binding.bluetooth.bluez ] - FrameworkEvent WARNING - org.openhab.binding.bluetooth.bluez
org.osgi.framework.ServiceException: org.apache.felix.scr.impl.manager.SingleComponentManager.getService() returned a null service object

2019-10-16 11:55:54.537 [ERROR] [org.openhab.binding.bluetooth.bluez ] - bundle org.openhab.binding.bluetooth.bluez:2.5.0.M3 (268)[org.openhab.binding.bluetooth.bluez.internal.discovery.BlueZDiscoveryService(312)] : The activate method has thrown an exception
java.lang.NullPointerException: null

2019-10-16 11:55:54.920 [WARN ] [org.openhab.binding.bluetooth.bluez ] - FrameworkEvent WARNING - org.openhab.binding.bluetooth.bluez
org.osgi.framework.ServiceException: org.apache.felix.scr.impl.manager.SingleComponentManager.getService() returned a null service object

2019-10-16 11:55:54.927 [ERROR] [org.openhab.binding.bluetooth.bluez ] - bundle org.openhab.binding.bluetooth.bluez:2.5.0.M3 (268)[org.openhab.binding.bluetooth.bluez.internal.discovery.BlueZDiscoveryService(312)] : The activate method has thrown an exception
java.lang.NullPointerException: null

2019-10-16 11:55:55.308 [thome.event.ExtensionEvent] - Extension 'binding-bluetooth' has been installed.

2019-10-16 11:55:55.370 [hingStatusInfoChangedEvent] - 'bluetooth:bluez:hci0' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2019-10-16 11:55:55.409 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'ThingHandler.initialize()' on 'org.openhab.binding.bluetooth.bluez.handler.BlueZBridgeHandler@100a96c': null
java.lang.NullPointerException: null

2019-10-16 11:55:55.421 [ERROR] [core.thing.internal.ThingManagerImpl] - Exception occurred while initializing handler of thing 'bluetooth:bluez:hci0': null
java.lang.NullPointerException: null

2019-10-16 11:55:55.436 [hingStatusInfoChangedEvent] - 'bluetooth:bluez:hci0' changed from INITIALIZING to UNINITIALIZED (HANDLER_INITIALIZING_ERROR)

But in my case results of bundle:list | grep -i tinyb is empty. I tried bundle:install https://janessa.me/esh/intel-iot-devkit.tinyb-0.5.1.jar but results is: Error executing command: Error installing bundles: Unable to install bundle https://janessa.me/esh/intel-iot-devkit.tinyb-0.5.1.jar: org.osgi.framework.BundleException: Error occurred installing a bundle. When I returned to 2.4.0 BT starts working again. Switch to 2.5.0 SNAPSHOT results as for M3.

jpalo commented 5 years ago

Same issue as tomasz also on 2.5.0 M4.

ssalonen commented 5 years ago

@j-n-k do you what could explain the issues people are still seeing with 2.5.0M4?

cirolaferrara commented 5 years ago

@J-N-K do you what could explain the issues people are still seeing with 2.5.0M4?

Paper UI -> Add Bluetooth BlueZ Adapter -> Insert mac address

2019-10-29 20:56:22.575 [hingStatusInfoChangedEvent] - 'bluetooth:bluez:e138f672' changed from UNINITIALIZED to INITIALIZING 2019-10-29 20:56:22.582 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'ThingHandler.initialize()' on 'org.openhab.binding.bluetooth.bluez.handler.BlueZBridgeHandler@1270f08': BlueZ JNI connection cannot be established. java.lang.IllegalStateException: BlueZ JNI connection cannot be established. at org.openhab.binding.bluetooth.bluez.handler.BlueZBridgeHandler.initialize(BlueZBridgeHandler.java:98) ~[?:?] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?] at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?] at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:152) [133:org.openhab.core:2.5.0.M4] at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:52) [133:org.openhab.core:2.5.0.M4] at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?] at java.lang.Thread.run(Thread.java:748) [?:?] Caused by: java.lang.UnsatisfiedLinkError: tinyb.BluetoothManager.getNativeAPIVersion()Ljava/lang/String; at tinyb.BluetoothManager.getNativeAPIVersion(Native Method) ~[?:?] at tinyb.BluetoothManager.getBluetoothManager(BluetoothManager.java:304) ~[?:?] at org.openhab.binding.bluetooth.bluez.handler.BlueZBridgeHandler.initialize(BlueZBridgeHandler.java:93) ~[?:?] ... 10 more 2019-10-29 20:56:22.588 [hingStatusInfoChangedEvent] - 'bluetooth:bluez:e138f672' changed from INITIALIZING to UNINITIALIZED (HANDLER_INITIALIZING_ERROR): BlueZ JNI connection cannot be established. 2019-10-29 20:56:22.589 [ERROR] [core.thing.internal.ThingManagerImpl] - Exception occurred while initializing handler of thing 'bluetooth:bluez:e138f672': BlueZ JNI connection cannot be established. java.lang.IllegalStateException: BlueZ JNI connection cannot be established. at org.openhab.binding.bluetooth.bluez.handler.BlueZBridgeHandler.initialize(BlueZBridgeHandler.java:98) ~[?:?] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?] at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?] at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:152) [133:org.openhab.core:2.5.0.M4] at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:52) [133:org.openhab.core:2.5.0.M4] at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?] at java.lang.Thread.run(Thread.java:748) [?:?] Caused by: java.lang.UnsatisfiedLinkError: tinyb.BluetoothManager.getNativeAPIVersion()Ljava/lang/String; at tinyb.BluetoothManager.getNativeAPIVersion(Native Method) ~[?:?] at tinyb.BluetoothManager.getBluetoothManager(BluetoothManager.java:304) ~[?:?] at org.openhab.binding.bluetooth.bluez.handler.BlueZBridgeHandler.initialize(BlueZBridgeHandler.java:93) ~[?:?] ... 10 more

J-N-K commented 5 years ago

Please describe your hardware setup. Impossible to fix otherwise.

cirolaferrara commented 5 years ago 
$ uname -a
Linux domotic 4.15.0-66-generic #75-Ubuntu SMP Tue Oct 1 05:24:09 UTC 2019 x86_64 x86_64 x86_64 GNU/Linux
[bluetooth]# version
Version 5.43
$ lsusb
Bus 001 Device 008: ID 0a12:0001 Cambridge Silicon Radio, Ltd Bluetooth Dongle (HCI mode)
$ groups openhab
openhab : openhab tty dialout audio bluetooth
openhab> bundle:list | grep Blue
223 x Active x  80 x 2.5.0.M4              x openHAB Add-ons :: Bundles :: Bluetooth Binding
224 x Active x  80 x 2.5.0.M4              x openHAB Add-ons :: Bundles :: BlueGiga Bluetooth Adapter
225 x Active x  80 x 2.5.0.M4              x openHAB Add-ons :: Bundles :: BlueZ Bluetooth Adapter
226 x Active x  80 x 2.5.0.M4              x openHAB Add-ons :: Bundles :: Blukii Bluetooth Adapter
227 x Active x  80 x 2.5.0.M4              x openHAB Add-ons :: Bundles :: RuuviTag Bluetooth Adapter
$ cat /etc/dbus-1/system.d/bluetooth.conf
...
  <policy group="bluetooth">
    <allow own="org.bluez"/>
    <allow send_destination="org.bluez"/>
    <allow send_interface="org.bluez.Agent1"/>
    <allow send_interface="org.bluez.MediaEndpoint1"/>
    <allow send_interface="org.bluez.MediaPlayer1"/>
    <allow send_interface="org.bluez.ThermometerWatcher1"/>
    <allow send_interface="org.bluez.AlertAgent1"/>
    <allow send_interface="org.bluez.Profile1"/>
    <allow send_interface="org.bluez.HeartRateWatcher1"/>
    <allow send_interface="org.bluez.CyclingSpeedWatcher1"/>
    <allow send_interface="org.bluez.GattCharacteristic1"/>
    <allow send_interface="org.bluez.GattDescriptor1"/>
    <allow send_interface="org.freedesktop.DBus.ObjectManager"/>
    <allow send_interface="org.freedesktop.DBus.Properties"/>
  </policy>
...
J-N-K commented 5 years ago

Interesting. The fix is already on my harddisk. It seems I did create a test branch and did not receive feedback.

stefanheijnen commented 5 years ago

@J-N-K I just upgraded from M4 to openHAB 2.5.0~S1748-1. Should this fix be included? Issue is still not resolved for me.

openhab> bundle:list | grep -i blue
237 │ Active    │  80 │ 2.5.0.201911090329      │ openHAB Add-ons :: Bundles :: Bluetooth Binding
238 │ Active    │  80 │ 2.5.0.201911090329      │ openHAB Add-ons :: Bundles :: BlueGiga Bluetooth Adapter
239 │ Waiting   │  80 │ 2.5.0.201911090329      │ openHAB Add-ons :: Bundles :: BlueZ Bluetooth Adapter
240 │ Active    │  80 │ 2.5.0.201911090329      │ openHAB Add-ons :: Bundles :: Blukii Bluetooth Adapter
241 │ Active    │  80 │ 2.5.0.201911090329      │ openHAB Add-ons :: Bundles :: RuuviTag Bluetooth Adapter

TinyB is still missing and not install-able through your link.

openhabian@openhab:~$ sudo find / -name tinyb
openhabian@openhab:~$ 
openhab> bundle:list | grep -i tinyb                                                                                                                                                                               
openhab> bundle:install https://janessa.me/esh/intel-iot-devkit.tinyb-0.5.1.jar
Bundle IDs: 
Error executing command: Error installing bundles:
        Unable to install bundle https://janessa.me/esh/intel-iot-devkit.tinyb-0.5.1.jar: org.osgi.framework.BundleException: Error occurred installing a bundle.

When manually adding a thing through PaperUI:

2019-11-09 12:16:03.282 [hingStatusInfoChangedEvent] - 'bluetooth:bluez:d80d8fa8' changed from UNINITIALIZED to INITIALIZING

==> /var/log/openhab2/openhab.log <==
2019-11-09 12:16:03.314 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'ThingHandler.initialize()' on 'org.openhab.binding.bluetooth.bluez.handler.BlueZBridgeHandler@994008': Cannot access BlueZ layer.
java.lang.IllegalStateException: Cannot access BlueZ layer.
        at org.openhab.binding.bluetooth.bluez.handler.BlueZBridgeHandler.initialize(BlueZBridgeHandler.java:105) ~[?:?]
        at sun.reflect.GeneratedMethodAccessor32.invoke(Unknown Source) ~[?:?]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
        at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?]
        at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:152) [134:org.openhab.core:2.5.0.201911090301]
        at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:52) [134:org.openhab.core:2.5.0.201911090301]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
        at java.lang.Thread.run(Thread.java:748) [?:?]
Caused by: java.lang.NullPointerException
        at tinyb.BluetoothManager.getBluetoothManager(BluetoothManager.java:306) ~[?:?]
        at org.openhab.binding.bluetooth.bluez.handler.BlueZBridgeHandler.initialize(BlueZBridgeHandler.java:93) ~[?:?]
        ... 9 more

==> /var/log/openhab2/events.log <==
2019-11-09 12:16:03.335 [hingStatusInfoChangedEvent] - 'bluetooth:bluez:d80d8fa8' changed from INITIALIZING to UNINITIALIZED (HANDLER_INITIALIZING_ERROR): Cannot access BlueZ layer.

==> /var/log/openhab2/openhab.log <==
2019-11-09 12:16:03.336 [ERROR] [core.thing.internal.ThingManagerImpl] - Exception occurred while initializing handler of thing 'bluetooth:bluez:d80d8fa8': Cannot access BlueZ layer.
java.lang.IllegalStateException: Cannot access BlueZ layer.
        at org.openhab.binding.bluetooth.bluez.handler.BlueZBridgeHandler.initialize(BlueZBridgeHandler.java:105) ~[?:?]
        at sun.reflect.GeneratedMethodAccessor32.invoke(Unknown Source) ~[?:?]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
        at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?]
        at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:152) [134:org.openhab.core:2.5.0.201911090301]
        at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:52) [134:org.openhab.core:2.5.0.201911090301]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
        at java.lang.Thread.run(Thread.java:748) [?:?]
Caused by: java.lang.NullPointerException
        at tinyb.BluetoothManager.getBluetoothManager(BluetoothManager.java:306) ~[?:?]
        at org.openhab.binding.bluetooth.bluez.handler.BlueZBridgeHandler.initialize(BlueZBridgeHandler.java:93) ~[?:?]
        ... 9 more

This is an openHABian install:

###############################################################################
###############  openhab  #####################################################
###############################################################################
##        Ip = 10.0.0.153
##   Release = Raspbian GNU/Linux 9 (stretch)
##    Kernel = Linux 4.19.66-v7+
##  Platform = Raspberry Pi 3 Model B Plus Rev 1.3
##    Uptime = 0 day(s). 0:28:14
##   Updates = 0 apt updates available.
##  Sessions = 3 sessions
## Processes = 141 running processes of 32768 maximum processes
###############################################################################
J-N-K commented 5 years ago

You don't need tinyb. It's included in the binding bundle. It was only necessary before.

The question is why is that bundle still in waiting state. Can you check which version of bluez is installed? apt list | grep bluez from bash console. And also please show system:property | grep proc from the karaf console.

stefanheijnen commented 5 years ago

apt list | grep bluez :

bluez/stable,now 5.43-2+rpt2+deb9u2 armhf [installed]
bluez-cups/stable 5.43-2+rpt2+deb9u2 armhf
bluez-dbg/stable 5.43-2+rpt2+deb9u2 armhf
bluez-firmware/stable,now 1.2-3+rpt7 all [installed,automatic]
bluez-hcidump/stable 5.43-2+rpt2+deb9u2 armhf
bluez-obexd/stable 5.43-2+rpt2+deb9u2 armhf
bluez-test-scripts/stable 5.43-2+rpt2+deb9u2 all
bluez-test-tools/stable 5.43-2+rpt2+deb9u2 armhf
bluez-tools/oldstable 0.2.0~20140808-5 armhf
libkf5bluezqt-data/oldstable 5.28.0-1 all
libkf5bluezqt-dev/oldstable 5.28.0-1 armhf
libkf5bluezqt6/oldstable 5.28.0-1 armhf
python-bluez/oldstable,now 0.22-1 armhf [installed]
qml-module-org-kde-bluezqt/oldstable 5.28.0-1 armhf

system:property | grep proc :

openhab> system:property | grep proc                                                                                                                                                                               
org.osgi.framework.processor=ARM
org.osgi.framework.system.packages=org.osgi.dto;version="1.0",org.osgi.resource;version="1.0",org.osgi.resource.dto;version="1.0";uses:="org.osgi.dto",org.osgi.framework;version="1.8",org.osgi.framework.dto;version="1.8";uses:="org.osgi.dto",org.osgi.framework.hooks.bundle;version="1.1";uses:="org.osgi.framework",org.osgi.framework.hooks.resolver;version="1.0";uses:="org.osgi.framework.wiring",org.osgi.framework.hooks.service;version="1.1";uses:="org.osgi.framework",org.osgi.framework.hooks.weaving;version="1.1";uses:="org.osgi.framework.wiring",org.osgi.framework.launch;version="1.2";uses:="org.osgi.framework",org.osgi.framework.namespace;version="1.1";uses:="org.osgi.resource",org.osgi.framework.startlevel;version="1.0";uses:="org.osgi.framework",org.osgi.framework.startlevel.dto;version="1.0";uses:="org.osgi.dto",org.osgi.framework.wiring;version="1.2";uses:="org.osgi.framework,org.osgi.resource",org.osgi.framework.wiring.dto;version="1.2";uses:="org.osgi.dto,org.osgi.resource.dto",org.osgi.service.condpermadmin;version="1.1.1";uses:="org.osgi.framework,org.osgi.service.permissionadmin",org.osgi.service.packageadmin;version="1.2";uses:="org.osgi.framework",org.osgi.service.permissionadmin;version="1.2",org.osgi.service.resolver;version="1.0";uses:="org.osgi.resource",org.osgi.service.startlevel;version="1.1";uses:="org.osgi.framework",org.osgi.service.url;version="1.0",org.osgi.util.tracker;version="1.5.1";uses:="org.osgi.framework",org.apache.karaf.version;version="4.2.6",org.apache.karaf.jaas.boot.principal;uses:=javax.security.auth;version="4.2.6",org.apache.karaf.jaas.boot;uses:="javax.security.auth,javax.security.auth.callback,javax.security.auth.login,javax.security.auth.spi,org.osgi.framework";version="4.2.6",org.apache.karaf.info;version="4.2.6",javax.accessibility, javax.activity, javax.annotation;version="1.0", javax.annotation.processing;version="1.0", javax.crypto, javax.crypto.interfaces, javax.crypto.spec, javax.imageio, javax.imageio.event, javax.imageio.metadata, javax.imageio.plugins.bmp, javax.imageio.plugins.jpeg, javax.imageio.spi, javax.imageio.stream, javax.jws, javax.jws.soap, javax.lang.model, javax.lang.model.element, javax.lang.model.type, javax.lang.model.util, javax.management, javax.management.loading, javax.management.modelmbean, javax.management.monitor, javax.management.openmbean, javax.management.relation, javax.management.remote, javax.management.remote.rmi, javax.management.timer, javax.naming, javax.naming.directory, javax.naming.event, javax.naming.ldap, javax.naming.spi, javax.net, javax.net.ssl, javax.print, javax.print.attribute, javax.print.attribute.standard, javax.print.event, javax.rmi, javax.rmi.CORBA, javax.rmi.ssl, javax.script, javax.security.auth, javax.security.auth.callback, javax.security.auth.kerberos, javax.security.auth.login, javax.security.auth.spi, javax.security.auth.x500, javax.security.cert, javax.security.sasl, javax.sound.midi, javax.sound.midi.spi, javax.sound.sampled, javax.sound.sampled.spi, javax.sql, javax.sql.rowset, javax.sql.rowset.serial, javax.sql.rowset.spi, javax.swing, javax.swing.border, javax.swing.colorchooser, javax.swing.event, javax.swing.filechooser, javax.swing.plaf, javax.swing.plaf.basic, javax.swing.plaf.metal, javax.swing.plaf.multi, javax.swing.plaf.synth, javax.swing.table, javax.swing.text, javax.swing.text.html, javax.swing.text.html.parser, javax.swing.text.rtf, javax.swing.tree, javax.swing.undo, javax.tools, javax.transaction; javax.transaction.xa; partial=true; mandatory:=partial, javax.xml, javax.xml.bind;version="2.2.8", javax.xml.bind.annotation;version="2.2.8", javax.xml.bind.annotation.adapters;version="2.2.8", javax.xml.bind.attachment;version="2.2.8", javax.xml.bind.helpers;version="2.2.8", javax.xml.bind.util;version="2.2.8", javax.xml.crypto, javax.xml.crypto.dom, javax.xml.crypto.dsig, javax.xml.crypto.dsig.dom, javax.xml.crypto.dsig.keyinfo, javax.xml.crypto.dsig.spec, javax.xml.datatype, javax.xml.namespace, javax.xml.parsers, javax.xml.stream;version="1.2", javax.xml.stream.events;version="1.2", javax.xml.stream.util;version="1.2", javax.xml.transform, javax.xml.transform.dom, javax.xml.transform.sax, javax.xml.transform.stax, javax.xml.transform.stream, javax.xml.validation, javax.xml.ws;version="2.2", javax.xml.ws.handler;version="2.2", javax.xml.ws.handler.soap;version="2.2", javax.xml.ws.http;version="2.2", javax.xml.ws.soap;version="2.2", javax.xml.ws.spi;version="2.2", javax.xml.ws.wsaddressing;version="2.2", javax.xml.ws.spi.http;version="2.2", javax.xml.xpath, javafx.animation, javafx.application, javafx.beans, javafx.beans.binding, javafx.beans.property, javafx.beans.property.adapter, javafx.beans.value, javafx.collections, javafx.collections.transform, javafx.concurrent, javafx.css, javafx.embed.swing, javafx.embed.swt, javafx.event, javafx.fxml, javafx.geometry, javafx.print, javafx.scene, javafx.scene.canvas, javafx.scene.chart, javafx.scene.control, javafx.scene.control.cell, javafx.scene.effect, javafx.scene.image, javafx.scene.input, javafx.scene.layout, javafx.scene.media, javafx.scene.paint, javafx.scene.shape, javafx.scene.text, javafx.scene.transform, javafx.scene.web, javafx.stage, javafx.util, javafx.util.converter, netscape.javascript, org.ietf.jgss, org.omg.CORBA, org.omg.CORBA_2_3, org.omg.CORBA_2_3.portable, org.omg.CORBA.DynAnyPackage, org.omg.CORBA.ORBPackage, org.omg.CORBA.portable, org.omg.CORBA.TypeCodePackage, org.omg.CosNaming, org.omg.CosNaming.NamingContextExtPackage, org.omg.CosNaming.NamingContextPackage, org.omg.Dynamic, org.omg.DynamicAny, org.omg.DynamicAny.DynAnyFactoryPackage, org.omg.DynamicAny.DynAnyPackage, org.omg.IOP, org.omg.IOP.CodecFactoryPackage, org.omg.IOP.CodecPackage, org.omg.Messaging, org.omg.PortableInterceptor, org.omg.PortableInterceptor.ORBInitInfoPackage, org.omg.PortableServer, org.omg.PortableServer.CurrentPackage, org.omg.PortableServer.POAManagerPackage, org.omg.PortableServer.POAPackage, org.omg.PortableServer.portable, org.omg.PortableServer.ServantLocatorPackage, org.omg.SendingContext, org.omg.stub.java.rmi, org.omg.stub.javax.management.remote.rmi, org.w3c.dom, org.w3c.dom.bootstrap, org.w3c.dom.css, org.w3c.dom.events, org.w3c.dom.html, org.w3c.dom.ls, org.w3c.dom.ranges, org.w3c.dom.stylesheets, org.w3c.dom.traversal, org.w3c.dom.views, org.w3c.dom.xpath, org.xml.sax, org.xml.sax.ext, org.xml.sax.helpers, com.sun.nio.sctp

For now I'm back at vkolotov BT binding. It has also issues, but it is working more or less. A bit unstable. BT devices frequently disappear. Are both online and offline, depending if you look in paperui or basicui.

J-N-K commented 5 years ago

I can reproduce the problem, but it's not because of a missing native library. I get a different message ("Unsatisfied Link") if I remove them, so they get deployed. The problem is that the library tries to check some "specificationVersion". I don't know why that fails.

stefanheijnen commented 5 years ago

Thnx for checking. I'll stick with the other BT binding for now.

J-N-K commented 5 years ago

There should be a fix on the way with #6369

BobSilent commented 4 years ago

is this fix now in?

Im on openHAB 2.5.0.M6 Milestone Build - openhabian (raspberry pi 4b) and get this error



java.lang.IllegalStateException: BlueZ JNI connection cannot be established.
    at org.openhab.binding.bluetooth.bluez.handler.BlueZBridgeHandler.initialize(BlueZBridgeHandler.java:98) ~[?:?]
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_222]
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:1.8.0_222]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_222]
    at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_222]
    at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:152) [bundleFile:?]
    at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:52) [bundleFile:?]
    at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_222]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_222]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_222]
    at java.lang.Thread.run(Thread.java:748) [?:1.8.0_222]
Caused by: java.lang.UnsatisfiedLinkError: tinyb.BluetoothManager.getNativeAPIVersion()Ljava/lang/String;
    at tinyb.BluetoothManager.getNativeAPIVersion(Native Method) ~[?:?]
    at tinyb.BluetoothManager.getBluetoothManager(BluetoothManager.java:304) ~[?:?]
    at org.openhab.binding.bluetooth.bluez.handler.BlueZBridgeHandler.initialize(BlueZBridgeHandler.java:93) ~[?:?]
    ... 10 more```
schorfi commented 4 years ago

i tried all versions up to snapshot and still receive the same error as before when i start (2.5.0-SNAPSHOT Build #1771) it I get 

openhab> Native code library failed to load.                                                                                                                                                                                                                                        
java.lang.UnsatisfiedLinkError: no tinyb in java.library.path

... after a while

openhab> bundle:list | grep -i blue                                                                                                                                                                                                    
212 │ Active │  80 │ 2.5.0.201912061818      │ openHAB Add-ons :: Bundles :: Bluetooth Binding
213 │ Active │  80 │ 2.5.0.201912061818      │ openHAB Add-ons :: Bundles :: BlueGiga Bluetooth Adapter
214 │ Active │  80 │ 2.5.0.201912061818      │ openHAB Add-ons :: Bundles :: BlueZ Bluetooth Adapter
215 │ Active │  80 │ 2.5.0.201912061818      │ openHAB Add-ons :: Bundles :: Blukii Bluetooth Adapter
216 │ Active │  80 │ 2.5.0.201912061819      │ openHAB Add-ons :: Bundles :: RuuviTag Bluetooth Adapter

on a side note:

bundle:install https://janessa.me/esh/intel-iot-devkit.tinyb-0.5.1.jar

cant work, as the jar behind it disappeared

the error in the log 

[...]
Caused by: java.lang.UnsatisfiedLinkError: tinyb.BluetoothManager.getNativeAPIVersion()Ljava/lang/String;
[...]

is still present, what can I/we do to fix it?

kaikreuzer commented 4 years ago

@J-N-K Any idea? Did https://github.com/openhab/openhab2-addons/pull/6369 really fix it for you?

schorfi commented 4 years ago

@J-N-K Any idea? Did #6369 really fix it for you?

on the issue it states

 wborn added this to the 2.5 milestone 11 hours ago

I dont know what this means in detail, but if this is no automatic action, the fix was not present in the snapshots yet?

J-N-K commented 4 years ago

I have no bluetooth devices. I have two test instances: a VirtualBox running debian and a windows machine. I did not get errors on the VirtualBox (and a RasPi I tested additonally)

The problem with debugging the native code issues is that you only see them on the same platform. So it's impossible find out what is going on if the platform is not provided.

BobSilent commented 4 years ago

@J-N-K what do you need exactly? I am running openhabian on a raspberry pi 4b

I can provide you more details or test something of you tell me what exactly you want to have. I checked the bundles list, tinyb is not listed. But I did not pay much attention to it, because you wrote it's included.

I checked Bluetooth status, logs shows one issues I fixed it with this https://raspberrypi.stackexchange.com/a/46660

J-N-K commented 4 years ago

https://github.com/openhab/openhab2-addons/issues/5680#issuecomment-552094286