search

sputnikdev / eclipse-smarthome-bluetooth-binding

Eclipse SmartHome Bluetooth Binding
46 stars 10 forks source link

TinyB doesnt discover generic adapter. #50

Open alexeinz opened 6 years ago

alexeinz commented 6 years ago

Hi, I have an issue with tinyB not discovering my adapter I am on debian jesse ( arm ) bluetooth is 5.43 ( last available stable - downgraded from 5.49 because of the notes)

bluetoothctl

[NEW] Controller 00:1A:7D:DA:71:13 openhabserver [default] [bluetooth]# show
Controller 00:1A:7D:DA:71:13
Name: openhabserver
Alias: openhabserver
Class: 0x000000
Powered: yes
Discoverable: no
Pairable: yes
UUID: Generic Attribute Profile (00001801-0000-1000-8000-00805f9b34fb)
UUID: A/V Remote Control (0000110e-0000-1000-8000-00805f9b34fb)
UUID: PnP Information (00001200-0000-1000-8000-00805f9b34fb)
UUID: Generic Access Profile (00001800-0000-1000-8000-00805f9b34fb)
UUID: A/V Remote Control Target (0000110c-0000-1000-8000-00805f9b34fb)
Modalias: usb:v1D6Bp0246d052B
Discovering: no

328 │ Active │ 80 │ 1.1.4 │ org.sputnikdev:org.eclipse.smarthome.binding.bluetooth
330 │ Active │ 80 │ 1.1.1 │ org.sputnikdev:org.eclipse.smarthome.binding.bluetooth.transport.tinyb

I get following error in DEBUG 14:15:50.853 [DEBUG] [oth.manager.impl.BluetoothManagerImpl] - Register tinyb transport
14:15:50.960 [WARN ] [oth.manager.impl.BluetoothManagerImpl] - Adapter discovery job error java.lang.RuntimeException: Error getting object manager client: GDBus.Error:org.freedesktop.DBus.Error.AccessDenied: Rejected send message, 2 matche d rules; type="method_call", sender=":1.466" (uid=1000 pid=8464 comm="/usr/lib/jvm/zulu-embedded-8-armhf/bin/java -Dopen") interface="org.freedesktop .DBus.ObjectManager" member="GetManagedObjects" error name="(unset)" requested_reply="0" destination=":1.1" (uid=0 pid=1764 comm="/usr/sbin/bluetooth d ") at tinyb.BluetoothManager.getNativeAPIVersion(Native Method) ~[?:?] at tinyb.BluetoothManager.getBluetoothManager(BluetoothManager.java:304) ~[?:?] at org.sputnikdev.bluetooth.manager.transport.tinyb.TinyBFactory.getDiscoveredAdapters(TinyBFactory.java:153) ~[?:?] at org.sputnikdev.bluetooth.manager.impl.BluetoothManagerImpl$AdapterDiscoveryJob.discoverAdapters(BluetoothManagerImpl.java:762) ~[?:?] at org.sputnikdev.bluetooth.manager.impl.BluetoothManagerImpl$AdapterDiscoveryJob.run(BluetoothManagerImpl.java:755) ~[?:?] at org.sputnikdev.bluetooth.manager.impl.BluetoothManagerImpl.scheduleDiscovery(BluetoothManagerImpl.java:798) ~[?:?] at org.sputnikdev.bluetooth.manager.impl.BluetoothManagerImpl.lambda$registerFactory$1(BluetoothManagerImpl.java:126) ~[?:?] at java.util.concurrent.ConcurrentHashMap.computeIfAbsent(ConcurrentHashMap.java:1660) ~[?:?] at org.sputnikdev.bluetooth.manager.impl.BluetoothManagerImpl.registerFactory(BluetoothManagerImpl.java:124) ~[?:?] at org.sputnikdev.esh.binding.bluetooth.internal.BluetoothHandlerFactory.registerBluetoothObjectFactory(BluetoothHandlerFactory.java:102) ~[? :?] 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.apache.felix.scr.impl.inject.BaseMethod.invokeMethod(BaseMethod.java:229) ~[?:?] at org.apache.felix.scr.impl.inject.BaseMethod.access$500(BaseMethod.java:39) ~[?:?] at org.apache.felix.scr.impl.inject.BaseMethod$Resolved.invoke(BaseMethod.java:650) ~[?:?] at org.apache.felix.scr.impl.inject.BaseMethod.invoke(BaseMethod.java:506) ~[?:?] at org.apache.felix.scr.impl.inject.BindMethod.invoke(BindMethod.java:658) ~[?:?] at org.apache.felix.scr.impl.manager.DependencyManager.doInvokeBindMethod(DependencyManager.java:1722) ~[?:?] at org.apache.felix.scr.impl.manager.DependencyManager.invokeBindMethod(DependencyManager.java:1699) ~[?:?] at org.apache.felix.scr.impl.manager.SingleComponentManager.invokeBindMethod(SingleComponentManager.java:372) ~[?:?] at org.apache.felix.scr.impl.manager.DependencyManager$MultipleDynamicCustomizer.addedService(DependencyManager.java:320) ~[?:?] at org.apache.felix.scr.impl.manager.DependencyManager$MultipleDynamicCustomizer.addedService(DependencyManager.java:291) ~[?:?] at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1215) ~[?:?] at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1136) ~[?:?] at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.trackAdding(ServiceTracker.java:945) ~[?:?] at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.track(ServiceTracker.java:881) ~[?:?] at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1167) ~[?:?] at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:127) ~[?:?] at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:109) ~[?:?] at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:915) ~[?:?] at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) ~[?:?] at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148) ~[?:?] at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:862) ~[?:?] at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:801) ~[?:?] at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.register(ServiceRegistrationImpl.java:127) ~[?:?] at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.registerService(ServiceRegistry.java:225) ~[?:?] at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:464) ~[?:?] at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:482) ~[?:?] at org.sputnikdev.esh.binding.bluetooth.transport.tinyb.activator.TinyBActivator.activate(TinyBActivator.java:22) ~[?:?] 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.apache.felix.scr.impl.inject.BaseMethod.invokeMethod(BaseMethod.java:229) ~[?:?] at org.apache.felix.scr.impl.inject.BaseMethod.access$500(BaseMethod.java:39) ~[?:?] at org.apache.felix.scr.impl.inject.BaseMethod$Resolved.invoke(BaseMethod.java:650) ~[?:?] at org.apache.felix.scr.impl.inject.BaseMethod.invoke(BaseMethod.java:506) ~[?:?] at org.apache.felix.scr.impl.inject.ActivateMethod.invoke(ActivateMethod.java:307) ~[?:?] at org.apache.felix.scr.impl.inject.ActivateMethod.invoke(ActivateMethod.java:299) ~[?:?] at org.apache.felix.scr.impl.manager.SingleComponentManager.createImplementationObject(SingleComponentManager.java:298) ~[?:?] at org.apache.felix.scr.impl.manager.SingleComponentManager.createComponent(SingleComponentManager.java:109) ~[?:?] at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:906) ~[?:?] at org.apache.felix.scr.impl.manager.SingleComponentManager.getServiceInternal(SingleComponentManager.java:879) ~[?:?] at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:749) ~[?:?] at org.apache.felix.scr.impl.manager.AbstractComponentManager.enableInternal(AbstractComponentManager.java:675) ~[?:?] at org.apache.felix.scr.impl.manager.AbstractComponentManager.enable(AbstractComponentManager.java:430) ~[?:?] at org.apache.felix.scr.impl.manager.ConfigurableComponentHolder.enableComponents(ConfigurableComponentHolder.java:657) ~[?:?] at org.apache.felix.scr.impl.BundleComponentActivator.initialEnable(BundleComponentActivator.java:341) ~[?:?] at org.apache.felix.scr.impl.Activator.loadComponents(Activator.java:390) ~[?:?] at org.apache.felix.scr.impl.Activator.access$200(Activator.java:54) ~[?:?] at org.apache.felix.scr.impl.Activator$ScrExtension.start(Activator.java:265) ~[?:?] at org.apache.felix.utils.extender.AbstractExtender.createExtension(AbstractExtender.java:254) ~[?:?] at org.apache.felix.utils.extender.AbstractExtender.modifiedBundle(AbstractExtender.java:227) ~[?:?] at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:482) ~[?:?] at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:415) ~[?:?] at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:232) ~[?:?] at org.osgi.util.tracker.BundleTracker$Tracked.bundleChanged(BundleTracker.java:444) ~[?:?] at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:903) ~[?:?] at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) ~[?:?] at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148) ~[?:?] at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEventPrivileged(EquinoxEventPublisher.java:213) ~[?:?] at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:120) ~[?:?] at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:112) ~[?:?] at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor.publishModuleEvent(EquinoxContainerAdaptor.java:156) ~[?:?] at org.eclipse.osgi.container.Module.publishEvent(Module.java:476) ~[?:?] at org.eclipse.osgi.container.Module.start(Module.java:467) ~[?:?] at org.eclipse.osgi.internal.framework.EquinoxBundle.start(EquinoxBundle.java:383) ~[?:?] at org.eclipse.osgi.internal.framework.EquinoxBundle.start(EquinoxBundle.java:402) ~[?:?] at org.eclipse.smarthome.extensionservice.marketplace.internal.BindingExtensionHandler.install(BindingExtensionHandler.java:82) ~[?:?] at org.eclipse.smarthome.extensionservice.marketplace.internal.MarketplaceExtensionService.install(MarketplaceExtensionService.java:222) ~[?: ?] at org.eclipse.smarthome.io.rest.core.internal.extensions.ExtensionResource.lambda$0(ExtensionResource.java:157) ~[?:?] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?] 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) [?:?]

alexeinz commented 6 years ago

I went thru the guide and now it has discovered the adapter, but I have a different problem now.

71:13
16:00:58.836 [DEBUG] [oth.manager.impl.BluetoothManagerImpl] - Matching adapter found amongst discovered adapters: /00:1A:7D:DA:71:13
16:00:58.859 [DEBUG] [.impl.AbstractBluetoothObjectGovernor] - A new native object has been acquired: /00:1A:7D:DA:71:13
16:00:58.868 [DEBUG] [.impl.AbstractBluetoothObjectGovernor] - Initializing governor with the new native object: /00:1A:7D:DA:71:13
16:00:58.878 [DEBUG] [ooth.manager.impl.AdapterGovernorImpl] - Initializing adapter governor: /00:1A:7D:DA:71:13
16:00:58.887 [DEBUG] [ooth.manager.impl.AdapterGovernorImpl] - Enabling powered notifications: /00:1A:7D:DA:71:13 : true
16:00:58.900 [DEBUG] [.manager.transport.tinyb.TinyBAdapter] - Enable powered notifications: tinyb://00:1A:7D:DA:71:13
16:00:58.920 [DEBUG] [ooth.manager.impl.AdapterGovernorImpl] - Enabling discovering notifications: /00:1A:7D:DA:71:13 : true
16:00:58.933 [DEBUG] [.manager.transport.tinyb.TinyBAdapter] - Enable discovering notifications: tinyb://00:1A:7D:DA:71:13
16:00:58.969 [DEBUG] [ooth.manager.impl.AdapterGovernorImpl] - Updating adapter governor: /00:1A:7D:DA:71:13
16:00:58.988 [DEBUG] [.impl.AbstractBluetoothObjectGovernor] - Governor has been updated: /00:1A:7D:DA:71:13
16:00:59.005 [DEBUG] [oth.manager.impl.BluetoothManagerImpl] - Notifying manager listeners (governor ready): 0 : true
16:00:59.053 [DEBUG] [manager.impl.CompletableFutureService] - Trying to complete futures: /00:1A:7D:DA:71:13 : 0
16:00:59.230 [DEBUG] [.manager.transport.tinyb.TinyBAdapter] - Set alias: tinyb://00:1A:7D:DA:71:13 : openhabserver
16:00:59.245 [DEBUG] [.manager.transport.tinyb.TinyBAdapter] - Set alias: tinyb://00:1A:7D:DA:71:13 : openhabserver
16:01:04.168 [DEBUG] [.impl.AbstractBluetoothObjectGovernor] - Updating governor. Trying to acquire lock: /00:1A:7D:DA:71:13
16:01:04.210 [DEBUG] [ooth.manager.impl.AdapterGovernorImpl] - Updating adapter governor: /00:1A:7D:DA:71:13
16:01:04.230 [DEBUG] [ooth.manager.impl.AdapterGovernorImpl] - Starting discovery: /00:1A:7D:DA:71:13
16:01:04.257 [DEBUG] [.manager.transport.tinyb.TinyBAdapter] - Starting discovery: tinyb://00:1A:7D:DA:71:13
16:01:04.305 [WARN ] [.impl.AbstractBluetoothObjectGovernor] - Error occurred while updating governor: /00:1A:7D:DA:71:13 / 10e87db : GDBus.Error:org .bluez.Error.NotSupported: Operation is not supported 16:01:04.325 [DEBUG] [.impl.AbstractBluetoothObjectGovernor] - Resetting governor. Descendants first: /00:1A:7D:DA:71:13 16:01:04.357 [DEBUG] [oth.manager.impl.BluetoothManagerImpl] - Transport [tinyb] reported 1 discovered adapters

vkolotov commented 6 years ago

Hi @alexeinz, can you please double check what version of bluez you are running? See here how to do this: https://github.com/sputnikdev/eclipse-smarthome-bluetooth-binding/issues/49#issuecomment-385550916

alexeinz commented 6 years ago

root@openhabserver /home/alexroot # bluetoothd -v
5.47

hciscan and other utils working fine

bt adapter is discovered and and constantly flipping on / off

vkolotov commented 6 years ago

do you have anything in the syslog?

vkolotov commented 6 years ago

you might want to enable verbose logging for bluez

alexeinz commented 6 years ago

nothing special... May 9 11:11:46 openhabserver avahi-daemon[1748]: Received packet from invalid interface. May 9 11:11:47 openhabserver dbus-daemon[1723]: [system] Reloaded configuration May 9 11:11:47 openhabserver dbus-daemon[1723]: [system] Reloaded configuration

I wonder, if the package is manually built, and I am using init.d for services, does bluetooth.conf still valid?

alexeinz commented 6 years ago

still nothing special... its starting and sending discovery May 9 11:27:36 openhabserver bluetoothd[22148]: src/adapter.c:set_discovery_filter() sender :1.12175

luetoothd[22509]: Bluetooth daemon 5.47
bluetoothd[22509]: src/main.c:parse_config() parsing /etc/bluetooth/main.conf
bluetoothd[22509]: src/main.c:parse_config() Key file does not have key “DiscoverableTimeout” in group “General”
bluetoothd[22509]: src/main.c:parse_config() Key file does not have key “PairableTimeout” in group “General”
bluetoothd[22509]: src/main.c:parse_config() Key file does not have key “AutoConnectTimeout” in group “General”
bluetoothd[22509]: src/main.c:parse_config() Key file does not have key “Privacy” in group “General”
bluetoothd[22509]: src/main.c:parse_config() Key file does not have key “Name” in group “General”
bluetoothd[22509]: src/main.c:parse_config() Key file does not have key “Class” in group “General”
bluetoothd[22509]: src/main.c:parse_config() Key file does not have key “DeviceID” in group “General”
bluetoothd[22509]: src/main.c:parse_config() Key file does not have key “ReverseServiceDiscovery” in group “General”
bluetoothd[22509]: src/adapter.c:adapter_init() sending read version command
bluetoothd[22509]: Starting SDP server
bluetoothd[22509]: src/sdpd-service.c:register_device_id() Adding device id record for 0002:1d6b:0246:052f
bluetoothd[22509]: src/plugin.c:plugin_init() Loading builtin plugins
bluetoothd[22509]: src/plugin.c:add_plugin() Loading hostname plugin
bluetoothd[22509]: src/plugin.c:add_plugin() Loading wiimote plugin
bluetoothd[22509]: src/plugin.c:add_plugin() Loading autopair plugin
bluetoothd[22509]: src/plugin.c:add_plugin() Loading policy plugin
bluetoothd[22509]: src/plugin.c:add_plugin() Loading a2dp plugin
bluetoothd[22509]: src/plugin.c:add_plugin() Loading avrcp plugin
bluetoothd[22509]: src/plugin.c:add_plugin() Loading network plugin
bluetoothd[22509]: src/plugin.c:add_plugin() Loading input plugin
bluetoothd[22509]: src/plugin.c:add_plugin() Loading hog plugin
bluetoothd[22509]: src/plugin.c:add_plugin() Loading gap plugin
bluetoothd[22509]: src/plugin.c:add_plugin() Loading scanparam plugin
bluetoothd[22509]: src/plugin.c:add_plugin() Loading deviceinfo plugin
bluetoothd[22509]: src/plugin.c:plugin_init() Loading plugins /usr/lib/bluetooth/plugins
bluetoothd[22509]: profiles/input/suspend-none.c:suspend_init()
bluetoothd[22509]: profiles/network/manager.c:read_config() Config options: Security=false
bluetoothd[22509]: src/main.c:main() Entering main loop
bluetoothd[22509]: src/rfkill.c:rfkill_event() RFKILL event idx 0 type 2 op 0 soft 0 hard 0
bluetoothd[22509]: Bluetooth management interface 1.0 initialized
bluetoothd[22509]: src/adapter.c:read_version_complete() sending read supported commands command
bluetoothd[22509]: src/adapter.c:read_version_complete() sending read index list command
bluetoothd[22509]: src/adapter.c:read_commands_complete() Number of commands: 37
bluetoothd[22509]: src/adapter.c:read_commands_complete() Number of events: 20
bluetoothd[22509]: src/adapter.c:read_index_list_complete() Number of controllers: 1
bluetoothd[22509]: src/adapter.c:read_index_list_complete() Found index 0
bluetoothd[22509]: src/adapter.c:index_added() index 0
bluetoothd[22509]: src/adapter.c:btd_adapter_new() System name: BlueZ 5.47
bluetoothd[22509]: src/adapter.c:btd_adapter_new() Major class: 0
bluetoothd[22509]: src/adapter.c:btd_adapter_new() Minor class: 0
bluetoothd[22509]: src/adapter.c:btd_adapter_new() Modalias: usb:v1D6Bp0246d052F
bluetoothd[22509]: src/adapter.c:btd_adapter_new() Discoverable timeout: 180 seconds
bluetoothd[22509]: src/adapter.c:btd_adapter_new() Pairable timeout: 0 seconds
bluetoothd[22509]: src/adapter.c:index_added() sending read info command for index 0
bluetoothd[22509]: src/adapter.c:read_info_complete() index 0 status 0x00
bluetoothd[22509]: src/adapter.c:clear_uuids() sending clear uuids command for index 0
bluetoothd[22509]: src/adapter.c:set_mode() sending set mode command for index 0
bluetoothd[22509]: src/gatt-database.c:btd_gatt_database_new() GATT Manager registered for adapter: /org/bluez/hci0
bluetoothd[22509]: src/adapter.c:adapter_service_add() /org/bluez/hci0
bluetoothd[22509]: src/sdpd-service.c:add_record_to_server() Adding record with handle 0x10001
bluetoothd[22509]: src/sdpd-service.c:add_record_to_server() Record pattern UUID 00000007-0000-1000-8000-00805f9
bluetoothd[22509]: src/sdpd-service.c:add_record_to_server() Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[22509]: src/sdpd-service.c:add_record_to_server() Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[22509]: src/sdpd-service.c:add_record_to_server() Record pattern UUID 00001800-0000-1000-8000-00805f9
bluetoothd[22509]: src/adapter.c:adapter_service_insert() /org/bluez/hci0
bluetoothd[22509]: src/adapter.c:add_uuid() sending add uuid command for index 0
bluetoothd[22509]: src/adapter.c:adapter_service_add() /org/bluez/hci0
bluetoothd[22509]: src/sdpd-service.c:add_record_to_server() Adding record with handle 0x10002
bluetoothd[22509]: src/sdpd-service.c:add_record_to_server() Record pattern UUID 00000007-0000-1000-8000-00805f9
bluetoothd[22509]: src/sdpd-service.c:add_record_to_server() Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[22509]: src/sdpd-service.c:add_record_to_server() Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[22509]: src/sdpd-service.c:add_record_to_server() Record pattern UUID 00001801-0000-1000-8000-00805f9
bluetoothd[22509]: src/adapter.c:adapter_service_insert() /org/bluez/hci0
bluetoothd[22509]: src/adapter.c:add_uuid() sending add uuid command for index 0
bluetoothd[22509]: profiles/audio/a2dp.c:media_server_probe() path /org/bluez/hci0
bluetoothd[22509]: plugins/policy.c:policy_adapter_probe()
bluetoothd[22509]: src/adapter.c:set_mode() sending set mode command for index 0
bluetoothd[22509]: plugins/hostname.c:hostname_probe()
bluetoothd[22509]: profiles/network/manager.c:panu_server_probe() path /org/bluez/hci0
bluetoothd[22509]: profiles/network/server.c:server_register() Registered interface org.bluez.NetworkServer1 on path /org/bluez/hci0
bluetoothd[22509]: profiles/network/manager.c:gn_server_probe() path /org/bluez/hci0
bluetoothd[22509]: profiles/network/manager.c:nap_server_probe() path /org/bluez/hci0
bluetoothd[22509]: profiles/audio/avrcp.c:avrcp_controller_server_probe() path /org/bluez/hci0
bluetoothd[22509]: src/adapter.c:adapter_service_add() /org/bluez/hci0
bluetoothd[22509]: src/sdpd-service.c:add_record_to_server() Adding record with handle 0x10003
bluetoothd[22509]: src/sdpd-service.c:add_record_to_server() Record pattern UUID 00000017-0000-1000-8000-00805f9
bluetoothd[22509]: src/sdpd-service.c:add_record_to_server() Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[22509]: src/sdpd-service.c:add_record_to_server() Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[22509]: src/sdpd-service.c:add_record_to_server() Record pattern UUID 0000110e-0000-1000-8000-00805f9
bluetoothd[22509]: src/sdpd-service.c:add_record_to_server() Record pattern UUID 0000110f-0000-1000-8000-00805f9
bluetoothd[22509]: src/adapter.c:adapter_service_insert() /org/bluez/hci0
bluetoothd[22509]: src/adapter.c:add_uuid() sending add uuid command for index 0
bluetoothd[22509]: profiles/audio/avrcp.c:avrcp_target_server_probe() path /org/bluez/hci0
bluetoothd[22509]: src/adapter.c:adapter_service_add() /org/bluez/hci0
bluetoothd[22509]: src/sdpd-service.c:add_record_to_server() Adding record with handle 0x10004
bluetoothd[22509]: src/sdpd-service.c:add_record_to_server() Record pattern UUID 00000017-0000-1000-8000-00805f9
bluetoothd[22509]: src/sdpd-service.c:add_record_to_server() Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[22509]: src/sdpd-service.c:add_record_to_server() Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[22509]: src/sdpd-service.c:add_record_to_server() Record pattern UUID 0000110c-0000-1000-8000-00805f9
bluetoothd[22509]: src/sdpd-service.c:add_record_to_server() Record pattern UUID 0000110e-0000-1000-8000-00805f9
bluetoothd[22509]: src/adapter.c:adapter_service_insert() /org/bluez/hci0
bluetoothd[22509]: src/adapter.c:add_uuid() sending add uuid command for index 0
bluetoothd[22509]: profiles/audio/a2dp.c:a2dp_sink_server_probe() path /org/bluez/hci0
bluetoothd[22509]: profiles/audio/a2dp.c:a2dp_source_server_probe() path /org/bluez/hci0
bluetoothd[22509]: src/adapter.c:btd_adapter_unblock_address() hci0 00:00:00:00:00:00
bluetoothd[22509]: src/adapter.c:load_link_keys() hci0 keys 0 debug_keys 0
bluetoothd[22509]: src/adapter.c:adapter_service_insert() /org/bluez/hci0
bluetoothd[22509]: src/adapter.c:add_uuid() sending add uuid command for index 0
bluetoothd[22509]: src/adapter.c:set_did() hci0 source 2 vendor 1d6b product 246 version 52f
bluetoothd[22509]: src/adapter.c:adapter_register() Adapter /org/bluez/hci0 registered
bluetoothd[22509]: src/adapter.c:set_dev_class() sending set device class command for index 0
bluetoothd[22509]: src/adapter.c:set_name() sending set local name command for index 0
bluetoothd[22509]: src/adapter.c:set_mode() sending set mode command for index 0
bluetoothd[22509]: Failed to set mode: Not Powered (0x0f)
bluetoothd[22509]: src/adapter.c:new_settings_callback() Settings: 0x000000d3
bluetoothd[22509]: src/adapter.c:settings_changed() Changed settings: 0x00000001
bluetoothd[22509]: src/adapter.c:adapter_start() adapter /org/bluez/hci0 has been enabled
bluetoothd[22509]: src/adapter.c:load_link_keys_complete() link keys loaded for hci0
bluetoothd[22509]: src/adapter.c:set_discovery_filter() sender :1.12175
bluetoothd[22509]: src/adapter.c:set_discovery_filter() sender :1.12175
bluetoothd[22509]: src/adapter.c:set_discovery_filter() sender :1.12175
bluetoothd[22509]: src/adapter.c:set_discovery_filter() sender :1.12175
bluetoothd[22509]: src/adapter.c:set_discovery_filter() sender :1.12175
bluetoothd[22509]: src/adapter.c:set_discovery_filter() sender :1.12175
bluetoothd[22509]: src/adapter.c:set_discovery_filter() sender :1.12175
bluetoothd[22509]: src/adapter.c:set_discovery_filter() sender :1.12175

alexeinz commented 6 years ago

I wonder why is this 11:33:46.203 [WARN ] [.impl.AbstractBluetoothObjectGovernor] - Error occurred while updating governor: /00:1A:7D:DA:71:13 / 13a509e : GDBus.Error:org .bluez.Error.NotSupported: Operation is not supported

vkolotov commented 6 years ago

Looks like this is it: 

bluetoothd[22509]: Failed to set mode: Not Powered (0x0f)

Are you using RPI? What hardware is it?

Can you please try to power off/on your adapter though bluetoothctl?

[bluetooth]# list
Controller 00:1A:7D:DA:71:04 AZIO - Entrance hall [default]
Controller 00:1A:7D:DA:71:05 AZIO - Kids room 
Controller B8:27:EB:60:0C:43 Internal Adapter - Kitchen

Select your adapter:

[bluetooth]# select B8:27:EB:60:0C:43
Controller B8:27:EB:60:0C:43 Internal Adapter - Kitchen [default]

Power it off:

[bluetooth]# power off
Changing power off succeeded
[CHG] Controller B8:27:EB:60:0C:43 Powered: no
[CHG] Controller B8:27:EB:60:0C:43 Discovering: no
alexeinz commented 6 years ago

yea its jesse debian on an arm and a standard generic dongle that line seems strange because both hcitool and blutoothctl can see my ble devices

Sent from my cell

On May 9, 2018, at 17:38, Vlad Kolotov notifications@github.com wrote:

Looks like this is it:

bluetoothd[22509]: Failed to set mode: Not Powered (0x0f) Are you using RPI?

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub, or mute the thread.

alexeinz commented 6 years ago

[CHG] Controller 00:1A:7D:DA:71:13 Discovering: yes [bluetooth]# show

Controller 00:1A:7D:DA:71:13

    Name: openhabserver

    Alias: openhabserver

    Class: 0x000000

    Powered: yes

    Discoverable: no

    Pairable: yes

    UUID: Generic Attribute Profile

(00001801-0000-1000-8000-00805f9b34fb)

    UUID: A/V Remote Control

(0000110e-0000-1000-8000-00805f9b34fb)

    UUID: PnP Information

(00001200-0000-1000-8000-00805f9b34fb)

    UUID: A/V Remote Control Target

(0000110c-0000-1000-8000-00805f9b34fb)

    UUID: Generic Access Profile

(00001800-0000-1000-8000-00805f9b34fb)

    Modalias: usb:v1D6Bp0246d0530

    Discovering: yes

[bluetooth]#

On Wed, May 9, 2018 at 5:47 PM, Alex Einz dj@alexeinz.info wrote:

yea its jesse debian on an arm and a standard generic dongle that line seems strange because both hcitool and blutoothctl can see my ble devices

Sent from my cell

On May 9, 2018, at 17:38, Vlad Kolotov notifications@github.com wrote:

Looks like this is it:

bluetoothd[22509]: Failed to set mode: Not Powered (0x0f)

Are you using RPI?

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub, or mute the thread.

vkolotov commented 6 years ago

Hi @alexeinz , could you please try to power it on/off as I mentioned in my previous message? In that way we could understand if your dongle actually supports this operation?

The binding tries to power on your adapter when it starts to ensure that BT system is ready to be used. It seems to me that your adapter does not support this operation, hence a fix for the binding probably is required to workaround your issue.