search

home-assistant / core

:house_with_garden: Open source home automation that puts local control and privacy first.
https://www.home-assistant.io
Apache License 2.0
70.15k stars 29.18k forks source link

Bluetooth tracker LE setting up error #16698

Closed Molodax closed 2 years ago

Molodax commented 5 years ago

Home Assistant release with the issue:

0.78.0

Last working Home Assistant release (if known):

Operating environment (Hass.io/Docker/Windows/etc.):

hassio (HassOS 1.10) rpi 3

Component/platform:

Bluetooth tracker LE https://www.home-assistant.io/components/device_tracker.bluetooth_le_tracker/

Description of problem: Error in setting up the platform.

Problem-relevant configuration.yaml entries and (fill out even if it seems unimportant):

device_tracker:
  - platform: bluetooth_le_tracker

Traceback (if applicable):

2018-09-18 19:57:05 WARNING (SyncWorker_13) [homeassistant.components.device_tracker.bluetooth_le_tracker] No Bluetooth LE devices to track!
2018-09-18 19:57:05 ERROR (MainThread) [homeassistant.components.device_tracker] Error setting up platform bluetooth_le_tracker

Additional information: Nothing more in log. I also have Mi Flora Plant component that works with Bluetooth LE.

flechaig commented 5 years ago

Home Assistant release with the issue:

0.78.0

Last working Home Assistant release (if known):

Operating environment (Hass.io/Docker/Windows/etc.):

Docker on Ubuntu Server 18.04

Component/platform:

Bluetooth tracker LE https://www.home-assistant.io/components/device_tracker.bluetooth_le_tracker/

Description of problem: Error in setting up the platform. Classic Bluetooth (not LE) is working well on the same instance in the same Docker container. hcitool lescan works well in the container. hcitool dev show device hci0 up and running.

Problem-relevant configuration.yaml entries and (fill out even if it seems unimportant):

device_tracker:
  - platform: bluetooth_le_tracker

Traceback (if applicable):

2018-09-19 08:27:58 WARNING (SyncWorker_11) [homeassistant.components.device_tracker.bluetooth_le_tracker] No Bluetooth LE devices to track!
2018-09-19 08:27:58 ERROR (MainThread) [homeassistant.components.device_tracker] Error setting up platform bluetooth_le_tracker
LordBoos commented 5 years ago

I have exactly the same problem. Anybody figured a way to make it work?

Molodax commented 5 years ago

It is interesting that when I added a mockup ble_mac address to known_devices.yaml, it started to discover real BLE devices but I got the following errors in the log:

2018-09-19 20:50:08 DEBUG (SyncWorker_2) [homeassistant.components.device_tracker.bluetooth_le_tracker] Adding BLE_34:1F:5F:BC:34:29 to BLE tracker
2018-09-19 20:50:08 DEBUG (SyncWorker_2) [homeassistant.components.device_tracker.bluetooth_le_tracker] Discovering Bluetooth LE devices
2018-09-19 20:50:12 ERROR (SyncWorker_2) [pygatt.backends.gatttool.gatttool] Unexpected error when scanning: LE Scan ...
C4:7C:8D:62:7A:D9 (unknown)
C4:7C:8D:62:7A:D9 Flower care
04:69:F8:B3:BE:DC (unknown)
04:69:F8:B3:BE:DC (unknown)
80:E6:5A:14:9B:10 (unknown)
80:E6:5A:14:9B:10 (unknown)
68:D9:3C:9F:A9:67 (unknown)
C4:7C:8A:92:B6:BF (unknown)
Disable scan failed: I/O error

2018-09-19 20:50:12 ERROR (MainThread) [homeassistant.components.device_tracker] Error setting up platform bluetooth_le_tracker
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/pexpect/spawnbase.py", line 166, in read_nonblocking
    s = os.read(self.child_fd, size)
OSError: [Errno 5] I/O error

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/pexpect/expect.py", line 111, in expect_loop
    incoming = spawn.read_nonblocking(spawn.maxread, timeout)
  File "/usr/local/lib/python3.6/site-packages/pexpect/pty_spawn.py", line 485, in read_nonblocking
    return super(spawn, self).read_nonblocking(size)
  File "/usr/local/lib/python3.6/site-packages/pexpect/spawnbase.py", line 171, in read_nonblocking
    raise EOF('End Of File (EOF). Exception style platform.')
pexpect.exceptions.EOF: End Of File (EOF). Exception style platform.

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/pygatt/backends/gatttool/gatttool.py", line 315, in scan
    scan.expect('foooooo', timeout=timeout)
  File "/usr/local/lib/python3.6/site-packages/pexpect/spawnbase.py", line 341, in expect
    timeout, searchwindowsize, async_)
  File "/usr/local/lib/python3.6/site-packages/pexpect/spawnbase.py", line 369, in expect_list
    return exp.expect_loop(timeout)
  File "/usr/local/lib/python3.6/site-packages/pexpect/expect.py", line 117, in expect_loop
    return self.eof(e)
  File "/usr/local/lib/python3.6/site-packages/pexpect/expect.py", line 63, in eof
    raise EOF(msg)
pexpect.exceptions.EOF: End Of File (EOF). Exception style platform.
<pexpect.pty_spawn.spawn object at 0x6fc1d4f0>
command: /usr/bin/hcitool
args: ['/usr/bin/hcitool', '-i', 'hci0', 'lescan']
buffer (last 100 chars): b''
before (last 100 chars): b'unknown)\r\n68:D9:3C:9F:A9:67 (unknown)\r\nC4:7C:8A:92:B6:BF (unknown)\r\nDisable scan failed: I/O error\r\n'
after: <class 'pexpect.exceptions.EOF'>
match: None
match_index: None
exitstatus: None
flag_eof: True
pid: 91
child_fd: 36
closed: False
timeout: 30
delimiter: <class 'pexpect.exceptions.EOF'>
logfile: None
logfile_read: None
logfile_send: None
maxread: 2000
ignorecase: False
searchwindowsize: None
delaybeforesend: 0.05
delayafterclose: 0.1
delayafterterminate: 0.1
searcher: searcher_re:
    0: re.compile(b'foooooo')

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/homeassistant/components/device_tracker/__init__.py", line 183, in async_setup_platform
    disc_info)
  File "/usr/local/lib/python3.6/concurrent/futures/thread.py", line 56, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/local/lib/python3.6/site-packages/homeassistant/components/device_tracker/bluetooth_le_tracker.py", line 111, in setup_scanner
    update_ble(dt_util.utcnow())
  File "/usr/local/lib/python3.6/site-packages/homeassistant/components/device_tracker/bluetooth_le_tracker.py", line 93, in update_ble
    devs = discover_ble_devices()
  File "/usr/local/lib/python3.6/site-packages/homeassistant/components/device_tracker/bluetooth_le_tracker.py", line 55, in discover_ble_devices
    devs = adapter.scan()
  File "/usr/local/lib/python3.6/site-packages/pygatt/backends/gatttool/gatttool.py", line 326, in scan
    raise BLEError(message)
pygatt.exceptions.BLEError: Unexpected error when scanning: LE Scan ...
C4:7C:8D:62:7A:D9 (unknown)
C4:7C:8D:62:7A:D9 Flower care
04:69:F8:B3:BE:DC (unknown)
04:69:F8:B3:BE:DC (unknown)
80:E6:5A:14:9B:10 (unknown)
80:E6:5A:14:9B:10 (unknown)
68:D9:3C:9F:A9:67 (unknown)
C4:7C:8A:92:B6:BF (unknown)
Disable scan failed: I/O error
Molodax commented 5 years ago

After disabling Mi Plant Flora component, the tracker started to discover devices, however, it didn't end up in any new records in known_devices.yaml The log:

2018-09-19 21:11:55 DEBUG (SyncWorker_9) [homeassistant.components.device_tracker.bluetooth_le_tracker] Adding BLE_34:1F:5F:BC:34:29 to BLE tracker
2018-09-19 21:11:55 DEBUG (SyncWorker_9) [homeassistant.components.device_tracker.bluetooth_le_tracker] Discovering Bluetooth LE devices
2018-09-19 21:12:07 DEBUG (SyncWorker_9) [homeassistant.components.device_tracker.bluetooth_le_tracker] Bluetooth LE devices discovered = {'C4:7C:8D:62:7A:D9': 'Flower care', 'AC:8F:90:2E:28:61': None, '68:D9:3C:9F:A9:67': None, '80:E6:5A:14:9B:10': None, 'C4:7C:8A:92:B6:BF': 'Flower care', '1C:56:A7:42:F8:F9': None, '68:64:4B:3B:17:0E': None, 'C4:7C:8D:62:1D:60': 'Flower care', '04:69:F8:B3:BE:DC': None, 'C0:69:75:91:AA:F0': 'Max Buzz', '72:26:3C:A1:DB:3A': None, 'C4:7C:8D:62:1C:F7': 'Flower mate', 'C4:7C:8D:62:79:E5': 'Flower care', '3B:60:53:21:1C:9F': None, '70:73:CB:DC:E8:53': None, '42:31:07:2E:F9:71': None}
2018-09-19 21:12:20 DEBUG (SyncWorker_12) [homeassistant.components.device_tracker.bluetooth_le_tracker] Discovering Bluetooth LE devices
2018-09-19 21:12:31 DEBUG (SyncWorker_12) [homeassistant.components.device_tracker.bluetooth_le_tracker] Bluetooth LE devices discovered = {'AC:8F:90:2E:28:61': None, '80:E6:5A:14:9B:10': None, '04:69:F8:B3:BE:DC': None, '1C:56:A7:42:F8:F9': None, '3B:60:53:21:1C:9F': None, 'C4:7C:8D:62:1C:F7': 'Flower mate', 'C4:7C:8D:62:79:E5': 'Flower care', 'C4:7C:8A:92:B6:BF': 'Flower care', 'C4:7C:8D:62:1D:60': 'Flower care', '68:64:4B:3B:17:0E': None, 'C4:7C:8D:62:7A:D9': 'Flower care', '68:D9:3C:9F:A9:67': None, 'C0:69:75:91:AA:F0': 'Max Buzz', '51:C8:84:1F:E8:CC': None, '42:31:07:2E:F9:71': None, '72:26:3C:A1:DB:3A': None}
2018-09-19 21:12:44 DEBUG (SyncWorker_7) [homeassistant.components.device_tracker.bluetooth_le_tracker] Discovering Bluetooth LE devices
2018-09-19 21:12:55 DEBUG (SyncWorker_7) [homeassistant.components.device_tracker.bluetooth_le_tracker] Bluetooth LE devices discovered = {'04:69:F8:B3:BE:DC': None, 'AC:8F:90:2E:28:61': None, '3B:60:53:21:1C:9F': None, '1C:56:A7:42:F8:F9': None, '80:E6:5A:14:9B:10': None, 'C0:69:75:91:AA:F0': 'Max Buzz', 'C4:7C:8D:62:79:E5': 'Flower care', 'C4:7C:8D:62:7A:D9': 'Flower care', 'C4:7C:8D:62:1C:F7': 'Flower mate', '68:64:4B:3B:17:0E': None, 'C4:7C:8A:92:B6:BF': 'Flower care', '72:26:3C:A1:DB:3A': None, '68:D9:3C:9F:A9:67': None, '70:73:CB:DC:E8:53': None, '42:31:07:2E:F9:71': None, 'C4:7C:8D:62:1D:60': 'Flower care', 'DC:E4:35:A5:70:FF': 'vívosport'}
LordBoos commented 5 years ago

I do not have Mi Plant Flora component enabled and I'm getting the above error as well after adding mock BLE_mac address to know devices. Without any BLE_mac address the BLE component won't load at all.

2018-09-20 11:05:00 ERROR (SyncWorker_0) [pygatt.backends.gatttool.gatttool] Unexpected error when scanning: 
2018-09-20 11:05:00 ERROR (MainThread) [homeassistant.core] Error doing job: Future exception was never retrieved
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/pexpect/spawnbase.py", line 166, in read_nonblocking
    s = os.read(self.child_fd, size)
OSError: [Errno 5] I/O error

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/pexpect/expect.py", line 111, in expect_loop
    incoming = spawn.read_nonblocking(spawn.maxread, timeout)
  File "/usr/local/lib/python3.6/site-packages/pexpect/pty_spawn.py", line 485, in read_nonblocking
    return super(spawn, self).read_nonblocking(size)
  File "/usr/local/lib/python3.6/site-packages/pexpect/spawnbase.py", line 171, in read_nonblocking
    raise EOF('End Of File (EOF). Exception style platform.')
pexpect.exceptions.EOF: End Of File (EOF). Exception style platform.

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/pygatt/backends/gatttool/gatttool.py", line 315, in scan
    scan.expect('foooooo', timeout=timeout)
  File "/usr/local/lib/python3.6/site-packages/pexpect/spawnbase.py", line 341, in expect
    timeout, searchwindowsize, async_)
  File "/usr/local/lib/python3.6/site-packages/pexpect/spawnbase.py", line 369, in expect_list
    return exp.expect_loop(timeout)
  File "/usr/local/lib/python3.6/site-packages/pexpect/expect.py", line 117, in expect_loop
    return self.eof(e)
  File "/usr/local/lib/python3.6/site-packages/pexpect/expect.py", line 63, in eof
    raise EOF(msg)
pexpect.exceptions.EOF: End Of File (EOF). Exception style platform.
<pexpect.pty_spawn.spawn object at 0x6ec26610>
command: /usr/bin/hcitool
args: ['/usr/bin/hcitool', '-i', 'hci0', 'lescan']
buffer (last 100 chars): b''

after: <class 'pexpect.exceptions.EOF'>
match: None
match_index: None
exitstatus: None
flag_eof: True
pid: 746
child_fd: 36
closed: False
timeout: 30
delimiter: <class 'pexpect.exceptions.EOF'>
logfile: None
logfile_read: None
logfile_send: None
maxread: 2000
ignorecase: False
searchwindowsize: None
delaybeforesend: 0.05
delayafterclose: 0.1
delayafterterminate: 0.1
searcher: searcher_re:
    0: re.compile(b'foooooo')

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.6/concurrent/futures/thread.py", line 56, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/local/lib/python3.6/site-packages/homeassistant/components/device_tracker/bluetooth_le_tracker.py", line 93, in update_ble
    devs = discover_ble_devices()
  File "/usr/local/lib/python3.6/site-packages/homeassistant/components/device_tracker/bluetooth_le_tracker.py", line 55, in discover_ble_devices
    devs = adapter.scan()
  File "/usr/local/lib/python3.6/site-packages/pygatt/backends/gatttool/gatttool.py", line 326, in scan
    raise BLEError(message)
pygatt.exceptions.BLEError: Unexpected error when scanning:
Molodax commented 5 years ago

Should @pvizeli review this issue since he made the latest promising update https://github.com/home-assistant/home-assistant/pull/16592 on this component?

idfxken commented 5 years ago

Was able to reproduce the error by restarting home assistant while it was scanning.

When HA gets restarted while a scan is being done, the HCI0 interface is not being disconnected gracefully:

2018-09-23 13:27:17 DEBUG (Thread-14) [homeassistant.components.device_tracker.bluetooth_le_tracker] Discovering Bluetooth LE devices 2018-09-23 13:27:17 INFO (Thread-14) [pygatt.backends.gatttool.gatttool] Starting BLE scan 2018-09-23 13:27:18 ERROR (Thread-14) [pygatt.backends.gatttool.gatttool] Unexpected error when scanning: LE Scan ... 14:BB:6E:D3:3F:C2 (unknown) 14:BB:6E:D3:3F:C2 [TV] Samsung 6 Series (40) 7C:2F:80:CE:F0:D6 (unknown) 7C:2F:80:CE:F0:D6 Gigaset G-tag

The interface is left in a dirty state, on start or restart a 'hciconfig hci0 reset' should be called to clean the interface.

Could @boosik and @Molodax test this by stopping HA, call 'hciconfig hci0 reset' and start HA again to see if it runs?

2 other issues are apparent on a fresh install:

1) It doesn’t create known_devices.yaml. It errors out saying it's not there:

EDIT: This is default behavior that can be fixed by adding: (ty @qubik)

device_tracker:
  - platform: ble
    track_new_devices: True

2) the python ‘pexpect’ library needs to be manually installed, HA seems to forget installing it.

LordBoos commented 5 years ago

@idfxken I cannot run that command, because I'm using hass.io

Molodax commented 5 years ago

@idfxken, thank you for debugging the issue, unfortunately, I'm using hassio and therefore cannot call 'hciconfig hci0 reset'.

danielsjf commented 5 years ago

Same problem here. Not a single mi flora sensor is working. In my log, the miflora setup times out after 120s.

gubiq commented 5 years ago

Traceback (if applicable):

2018-09-18 19:57:05 WARNING (SyncWorker_13) [homeassistant.components.device_tracker.bluetooth_le_tracker] No Bluetooth LE devices to track!
2018-09-18 19:57:05 ERROR (MainThread) [homeassistant.components.device_tracker] Error setting up platform bluetooth_le_tracker

There is a problem with setting the default track_new_devices, you have to activate it yourself:

device_tracker:
  - platform: bluetooth_le_tracker
    track_new_devices: True

Now works for me.

LordBoos commented 5 years ago

@gubiq nice find! I'm now getting new devices in known_devices.yaml But I have found new problem.

Looks like some devices doesn't have names and component throws exception when that happens, because it is trying to strip some symbols from it.

Traceback (most recent call last):
  File "/usr/local/lib/python3.6/concurrent/futures/thread.py", line 56, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/local/lib/python3.6/site-packages/homeassistant/components/device_tracker/bluetooth_le_tracker.py", line 107, in update_ble
    see_device(address, devs[address], new_device=True)
  File "/usr/local/lib/python3.6/site-packages/homeassistant/components/device_tracker/bluetooth_le_tracker.py", line 47, in see_device
    see(mac=BLE_PREFIX + address, host_name=name.strip("\x00"),
AttributeError: 'NoneType' object has no attribute 'strip'
Molodax commented 5 years ago

Thank you @gubiq it helps to some extent now, howere, I have the same issue as @Boosik As well as I had to disable Mi Flora Plant component, otherwise, the Ble tracker didn't start.

LordBoos commented 5 years ago

I've managed to workaround the issue. Create a file "/config/custom_components/device_tracker/ble.py" Paste following code to that file (only change is None check near line 47):

"""
Tracking for bluetooth low energy devices.
For more details about this platform, please refer to the documentation at
https://home-assistant.io/components/device_tracker.bluetooth_le_tracker/
"""
import logging

from homeassistant.helpers.event import track_point_in_utc_time
from homeassistant.components.device_tracker import (
    YAML_DEVICES, CONF_TRACK_NEW, CONF_SCAN_INTERVAL, DEFAULT_SCAN_INTERVAL,
    load_config, SOURCE_TYPE_BLUETOOTH_LE
)
import homeassistant.util.dt as dt_util

_LOGGER = logging.getLogger(__name__)

REQUIREMENTS = ['pygatt==3.2.0']

BLE_PREFIX = 'BLE_'
MIN_SEEN_NEW = 5

def setup_scanner(hass, config, see, discovery_info=None):
    """Set up the Bluetooth LE Scanner."""
    # pylint: disable=import-error
    import pygatt
    new_devices = {}

    def see_device(address, name, new_device=False):
        """Mark a device as seen."""
        if new_device:
            if address in new_devices:
                _LOGGER.debug(
                    "Seen %s %s times", address, new_devices[address])
                new_devices[address] += 1
                if new_devices[address] >= MIN_SEEN_NEW:
                    _LOGGER.debug("Adding %s to tracked devices", address)
                    devs_to_track.append(address)
                else:
                    return
            else:
                _LOGGER.debug("Seen %s for the first time", address)
                new_devices[address] = 1
                return

        if name is None:
            see(mac=BLE_PREFIX + address, host_name=BLE_PREFIX + address,
                source_type=SOURCE_TYPE_BLUETOOTH_LE)
        else:
            see(mac=BLE_PREFIX + address, host_name=name.strip("\x00"),
                source_type=SOURCE_TYPE_BLUETOOTH_LE)

    def discover_ble_devices():
        """Discover Bluetooth LE devices."""
        _LOGGER.debug("Discovering Bluetooth LE devices")
        try:
            adapter = pygatt.GATTToolBackend()
            devs = adapter.scan()

            devices = {x['address']: x['name'] for x in devs}
            _LOGGER.debug("Bluetooth LE devices discovered = %s", devices)
        except RuntimeError as error:
            _LOGGER.error("Error during Bluetooth LE scan: %s", error)
            return {}
        return devices

    yaml_path = hass.config.path(YAML_DEVICES)
    devs_to_track = []
    devs_donot_track = []

    # Load all known devices.
    # We just need the devices so set consider_home and home range
    # to 0
    for device in load_config(yaml_path, hass, 0):
        # check if device is a valid bluetooth device
        if device.mac and device.mac[:4].upper() == BLE_PREFIX:
            if device.track:
                _LOGGER.debug("Adding %s to BLE tracker", device.mac)
                devs_to_track.append(device.mac[4:])
            else:
                _LOGGER.debug("Adding %s to BLE do not track", device.mac)
                devs_donot_track.append(device.mac[4:])

    # if track new devices is true discover new devices
    # on every scan.
    track_new = config.get(CONF_TRACK_NEW)

    if not devs_to_track and not track_new:
        _LOGGER.warning("No Bluetooth LE devices to track!")
        return False

    interval = config.get(CONF_SCAN_INTERVAL, DEFAULT_SCAN_INTERVAL)

    def update_ble(now):
        """Lookup Bluetooth LE devices and update status."""
        devs = discover_ble_devices()
        for mac in devs_to_track:
            if mac not in devs:
                continue

            if devs[mac] is None:
                devs[mac] = mac
            see_device(mac, devs[mac])

        if track_new:
            for address in devs:
                if address not in devs_to_track and \
                        address not in devs_donot_track:
                    _LOGGER.info("Discovered Bluetooth LE device %s", address)
                    see_device(address, devs[address], new_device=True)

        track_point_in_utc_time(hass, update_ble, dt_util.utcnow() + interval)

    update_ble(dt_util.utcnow())
    return True

Now use this configuration.yaml:

device_tracker:
  - platform: ble
    track_new_devices: True

I have not tested it with miflora component because I have zero miflora devices.

Molodax commented 5 years ago

Unfortunately, it doesn't work with Mi Flora nicely

2018-09-27 22:26:14 ERROR (SyncWorker_15) [pygatt.backends.gatttool.gatttool] Unexpected error when scanning: LE Scan ...
C4:7C:8D:62:1C:F7 (unknown)
Disable scan failed: I/O error

2018-09-27 22:26:14 ERROR (MainThread) [homeassistant.components.device_tracker] Error setting up platform ble
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/pexpect/spawnbase.py", line 166, in read_nonblocking
    s = os.read(self.child_fd, size)
OSError: [Errno 5] I/O error

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/pexpect/expect.py", line 111, in expect_loop
    incoming = spawn.read_nonblocking(spawn.maxread, timeout)
  File "/usr/local/lib/python3.6/site-packages/pexpect/pty_spawn.py", line 485, in read_nonblocking
    return super(spawn, self).read_nonblocking(size)
  File "/usr/local/lib/python3.6/site-packages/pexpect/spawnbase.py", line 171, in read_nonblocking
    raise EOF('End Of File (EOF). Exception style platform.')
pexpect.exceptions.EOF: End Of File (EOF). Exception style platform.

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/pygatt/backends/gatttool/gatttool.py", line 315, in scan
    scan.expect('foooooo', timeout=timeout)
  File "/usr/local/lib/python3.6/site-packages/pexpect/spawnbase.py", line 341, in expect
    timeout, searchwindowsize, async_)
  File "/usr/local/lib/python3.6/site-packages/pexpect/spawnbase.py", line 369, in expect_list
    return exp.expect_loop(timeout)
  File "/usr/local/lib/python3.6/site-packages/pexpect/expect.py", line 117, in expect_loop
    return self.eof(e)
  File "/usr/local/lib/python3.6/site-packages/pexpect/expect.py", line 63, in eof
    raise EOF(msg)
pexpect.exceptions.EOF: End Of File (EOF). Exception style platform.
<pexpect.pty_spawn.spawn object at 0x6fb831d0>
command: /usr/bin/hcitool
args: ['/usr/bin/hcitool', '-i', 'hci0', 'lescan']
buffer (last 100 chars): b''
before (last 100 chars): b'LE Scan ...\r\nC4:7C:8D:62:1C:F7 (unknown)\r\nDisable scan failed: I/O error\r\n'
after: <class 'pexpect.exceptions.EOF'>
match: None
match_index: None
exitstatus: 1
flag_eof: True
pid: 92
child_fd: 38
closed: False
timeout: 30
delimiter: <class 'pexpect.exceptions.EOF'>
logfile: None
logfile_read: None
logfile_send: None
maxread: 2000
ignorecase: False
searchwindowsize: None
delaybeforesend: 0.05
delayafterclose: 0.1
delayafterterminate: 0.1
searcher: searcher_re:
    0: re.compile(b'foooooo')

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/homeassistant/components/device_tracker/__init__.py", line 183, in async_setup_platform
    disc_info)
  File "/usr/local/lib/python3.6/concurrent/futures/thread.py", line 56, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/config/custom_components/device_tracker/ble.py", line 114, in setup_scanner
    update_ble(dt_util.utcnow())
  File "/config/custom_components/device_tracker/ble.py", line 96, in update_ble
    devs = discover_ble_devices()
  File "/config/custom_components/device_tracker/ble.py", line 58, in discover_ble_devices
    devs = adapter.scan()
  File "/usr/local/lib/python3.6/site-packages/pygatt/backends/gatttool/gatttool.py", line 326, in scan
    raise BLEError(message)
pygatt.exceptions.BLEError: Unexpected error when scanning: LE Scan ...
C4:7C:8D:62:1C:F7 (unknown)
Disable scan failed: I/O error
idfxken commented 5 years ago

@Molodax, I don't think the bluetooth device can be shared between 2 different processes. So what you are trying to do is imho impossible, did this work before? One workaround would to add a usb ble dongle and point the components to different interfaces

Molodax commented 5 years ago

@idfxken, I don't see why it is not possible. There is ongoing connectivity issue that was introduced in Mi Flora Plant component in 0.78.0

danielsjf commented 5 years ago

@idfxken I used 4 different Bluetooth devices on version 0.77 (and before). Since 0.78, none of them are working. On both versions I didn't use any other Bluetooth devices.

danielsjf commented 5 years ago

@pvizeli, since you made a modification in the Bluetooth implementation, do you know what could be going wrong?

danielsjf commented 5 years ago

Actually, it seems to be different after every start. Earlier I had one, now I have two. There is an error related to a time out so that might be a clue as well.

flechaig commented 5 years ago

It seems that this configuration is now (0.79.3) working (docker on linux) :

   - platform: bluetooth_le_tracker
     device_id: hci0
     scan_interval: 60
     track_new_devices: True
danielsjf commented 5 years ago

Miflora works again on 79.3 and 133 supervisor.

pvizeli commented 5 years ago

The problem is that Bluetooth and python are not the best friends. Most of exists library are very old I don't work with our fast moving.

The old gatttlib library was to broken. I port it to a library they use the cmd line tool like Miflora. Look like that's difficult that two library use the same command line tool.

I try to port this platform to https://github.com/pybluez/pygattlib. Maybe some one will help on it instead to workaround it ;)

pvizeli commented 5 years ago

Will some one test this? https://github.com/home-assistant/home-assistant/blob/ble_v2/homeassistant/components/device_tracker/bluetooth_le_tracker.py

Molodax commented 5 years ago

I wish I could help to fix the issue but I have too little knowledge in Python. Nevertheless, I can and I will test the code this evening since, IMHO, it would be great to make this tracker work.

Molodax commented 5 years ago

I set up the tracker from the link above from @pvizeli as a custome component, here is a very short log:

2018-10-04 18:39:25 ERROR (SyncWorker_11) [homeassistant.util.package] Unable to install package pygattlib==0.0.4: Command "python setup.py egg_info" failed with error code 1 in /tmp/pip-install-whdi6i7a/pygattlib/
You are using pip version 10.0.1, however version 18.0 is available.
You should consider upgrading via the 'pip install --upgrade pip' command.
2018-10-04 18:39:25 ERROR (MainThread) [homeassistant.requirements] Not initializing device_tracker.ble because could not install requirement pygattlib==0.0.4
braddo99 commented 5 years ago

Bump, very interested in the outcome here!

rafaalbelda commented 5 years ago

Will some one test this? https://github.com/home-assistant/home-assistant/blob/ble_v2/homeassistant/components/device_tracker/bluetooth_le_tracker.py

@pvizeli, I tried your v2 component. Initially I had the same problem that @Molodax had ("Unable to install package pygattlib==0.0.4").

I found that some libraries and packages where required:

sudo apt-get install libglib2.0-dev
sudo apt-get install libboost-python-dev
sudo apt-get install libboost-thread-dev
pip3 install boost

After installing those requisites, the component started working like a charm, detecting BLE devices and storing them in the known_devices.yaml

I have a Mi Flora, I´ll try to use both components to see if there are problems

rafaalbelda commented 5 years ago

I tested Mi Flora sensor in a raspberry pi 3 and it works fine with ble v2 component. I´m using the included bluetooth service (not an external dongle)

braddo99 commented 5 years ago

will this work on the homeassistant docker container? That thing seems to run a stripped down (Alpine?) Linux which doesn't have any of these libraries in it's repositories. libboost etc.

Molodax commented 5 years ago

@pvizeli is there any chance that you will fix it for Hassio? It seems like your fix is working but the only problem is an inability to install all required dependencies for hassio.

braddo99 commented 5 years ago

Hey, v 0.82 seems to have fixed bluetooth in the docker! Thanks folks.

njbuch commented 5 years ago

I am experiencing similar problems doing ble tracking. When will this fix be included in a new version of HA?

raccettura commented 5 years ago

I seem to be having issues with this as well. both bluetooth*_tracker and mi flora bluetooth sensors are all dead.

njbuch commented 5 years ago

Yup, I took the 0.82 for a spin, and things has improved slightly. I skipped the docker setup as its too clumsy when stuff like this happens. But I can see that one of my bluetooth devices are now popping in and out of the zone. But one that one. And I see some errors in the log like this:

Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.6/site-packages/bluetooth/bluez.py", line 31, in discover_devices
    lookup_class=lookup_class, device_id=device_id)
_bluetooth.error: (16, 'Device or resource busy')

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/components/device_tracker/bluetooth_tracker.py", line 93, in update_bluetooth_once
    for dev in discover_devices():
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/components/device_tracker/bluetooth_tracker.py", line 51, in discover_devices
    lookup_class=False)
  File "/srv/homeassistant/lib/python3.6/site-packages/bluetooth/bluez.py", line 34, in discover_devices
    raise BluetoothError ("error communicating with local "
bluetooth.btcommon.BluetoothError: error communicating with local bluetooth adapter
imist commented 5 years ago

Hey, v 0.82 seems to have fixed bluetooth in the docker! Thanks folks.

Yup, my Mi Flora sensors finally started to work for me too in Hassio with the 0.82 update! :-)

braddo99 commented 5 years ago

Can now get to a state where all BLE devices detected correctly but after a while, typically hours, they will all go to "away" and not return. Most of the time this can be fixed with hciconfig reset and docker restart Hass but sometimes requires full machine reboot. As @njbuch said above I've seen errors where it appears some other process is grabbing the bt dongle. Investigating with debug logs.

njbuch commented 5 years ago

Let me know if you want testing assistance.

braddo99 commented 5 years ago

@njbuch would love that. I do see this in some home-assistant.log files: 2018-12-01 22:44:28 ERROR (SyncWorker_16) [pygatt.backends.gatttool.gatttool] BLE adapter requires reset after a scan as root- call adapter.reset()

Which, as I said, I can reset the device and sometimes it will get back in touch. It's a bit tough to capture the moment when the device drops in debug logs but still working on it. However, maybe it's some other system log that will tell what is grabbing the bluetooth controller.

njbuch commented 5 years ago

@njbuch would love that.

Can you clarify the setup you ended up running, the above thread is unclear in terms of best route to go, and also show me the part of your conf file that sets up the bluetooth part.

stemelkov commented 5 years ago

Here's the traceback I get:

Sun Dec 02 2018 22:08:30 GMT+0200 (Eastern European Standard Time)

Error doing job: Future exception was never retrieved
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/pexpect/spawnbase.py", line 166, in read_nonblocking
    s = os.read(self.child_fd, size)
OSError: [Errno 5] I/O error

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/pexpect/expect.py", line 111, in expect_loop
    incoming = spawn.read_nonblocking(spawn.maxread, timeout)
  File "/usr/local/lib/python3.6/site-packages/pexpect/pty_spawn.py", line 485, in read_nonblocking
    return super(spawn, self).read_nonblocking(size)
  File "/usr/local/lib/python3.6/site-packages/pexpect/spawnbase.py", line 171, in read_nonblocking
    raise EOF('End Of File (EOF). Exception style platform.')
pexpect.exceptions.EOF: End Of File (EOF). Exception style platform.

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/pygatt/backends/gatttool/gatttool.py", line 315, in scan
    scan.expect('foooooo', timeout=timeout)
  File "/usr/local/lib/python3.6/site-packages/pexpect/spawnbase.py", line 341, in expect
    timeout, searchwindowsize, async_)
  File "/usr/local/lib/python3.6/site-packages/pexpect/spawnbase.py", line 369, in expect_list
    return exp.expect_loop(timeout)
  File "/usr/local/lib/python3.6/site-packages/pexpect/expect.py", line 117, in expect_loop
    return self.eof(e)
  File "/usr/local/lib/python3.6/site-packages/pexpect/expect.py", line 63, in eof
    raise EOF(msg)
pexpect.exceptions.EOF: End Of File (EOF). Exception style platform.
<pexpect.pty_spawn.spawn object at 0x6ee8d290>
command: /usr/bin/hcitool
args: ['/usr/bin/hcitool', '-i', 'hci0', 'lescan']
buffer (last 100 chars): b''

after: <class 'pexpect.exceptions.EOF'>
match: None
match_index: None
exitstatus: None
flag_eof: True
pid: 4582
child_fd: 35
closed: False
timeout: 30
delimiter: <class 'pexpect.exceptions.EOF'>
logfile: None
logfile_read: None
logfile_send: None
maxread: 2000
ignorecase: False
searchwindowsize: None
delaybeforesend: 0.05
delayafterclose: 0.1
delayafterterminate: 0.1
searcher: searcher_re:
    0: re.compile(b'foooooo')

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.6/concurrent/futures/thread.py", line 56, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/local/lib/python3.6/site-packages/homeassistant/components/device_tracker/bluetooth_le_tracker.py", line 96, in update_ble
    devs = discover_ble_devices()
  File "/usr/local/lib/python3.6/site-packages/homeassistant/components/device_tracker/bluetooth_le_tracker.py", line 58, in discover_ble_devices
    devs = adapter.scan()
  File "/usr/local/lib/python3.6/site-packages/pygatt/backends/gatttool/gatttool.py", line 326, in scan
    raise BLEError(message)
pygatt.exceptions.BLEError: Unexpected error when scanning:

Config is simply:

device_tracker:
  - platform: bluetooth_le_tracker
    track_new_devices: False
scottyphillips commented 5 years ago

For all those still encountering this BLEError issue I have created a workaround ble_tracker.py which may work for you (works fine for me). All it simply does is correctly intercept the problematic BLEError and basically ignores it. Seems to work because each time because the ble_device_tracker module invokes a new pygatt backend instance from scratch every time it polls for new BLE devices... So if you get an error in a single poll, who cares try again next time. this tracker module seems pretty crude (which is exactly how I would have coded it lol).

Install into custom_components/device_tracker/ble_tracker.py

"""
Tracking for bluetooth low energy devices.
For more details about this platform, please refer to the documentation at
https://home-assistant.io/components/device_tracker.bluetooth_le_tracker/
"""
import logging

from homeassistant.helpers.event import track_point_in_utc_time
from homeassistant.components.device_tracker import (
    YAML_DEVICES, CONF_TRACK_NEW, CONF_SCAN_INTERVAL, DEFAULT_SCAN_INTERVAL,
    load_config, SOURCE_TYPE_BLUETOOTH_LE
)
import homeassistant.util.dt as dt_util

_LOGGER = logging.getLogger(__name__)

REQUIREMENTS = ['pygatt==3.2.0']

BLE_PREFIX = 'BLE_'
MIN_SEEN_NEW = 5

def setup_scanner(hass, config, see, discovery_info=None):
    """Set up the Bluetooth LE Scanner."""
    # pylint: disable=import-error
    import pygatt
    from pygatt.exceptions import BLEError
    new_devices = {}

    def see_device(address, name, new_device=False):
        """Mark a device as seen."""
        if new_device:
            if address in new_devices:
                _LOGGER.debug(
                    "Seen %s %s times", address, new_devices[address])
                new_devices[address] += 1
                if new_devices[address] >= MIN_SEEN_NEW:
                    _LOGGER.debug("Adding %s to tracked devices", address)
                    devs_to_track.append(address)
                else:
                    return
            else:
                _LOGGER.debug("Seen %s for the first time", address)
                new_devices[address] = 1
                return

        if name is not None:
            name = name.strip("\x00")

        see(mac=BLE_PREFIX + address, host_name=name,
            source_type=SOURCE_TYPE_BLUETOOTH_LE)

    def discover_ble_devices():
        """Discover Bluetooth LE devices."""
        _LOGGER.debug("Discovering Bluetooth LE devices")
        try:
            adapter = pygatt.GATTToolBackend()
            devs = adapter.scan()

            devices = {x['address']: x['name'] for x in devs}
            _LOGGER.debug("Bluetooth LE devices discovered = %s", devices)
        except BLEError as error:
            _LOGGER.error("Caught pygatt BLE Error: %s - will try again later", error)
            return {}
        except RuntimeError as error:
            _LOGGER.error("Error during Bluetooth LE scan: %s", error)
            return {}
        return devices

    yaml_path = hass.config.path(YAML_DEVICES)
    devs_to_track = []
    devs_donot_track = []

    # Load all known devices.
    # We just need the devices so set consider_home and home range
    # to 0
    for device in load_config(yaml_path, hass, 0):
        # check if device is a valid bluetooth device
        if device.mac and device.mac[:4].upper() == BLE_PREFIX:
            if device.track:
                _LOGGER.debug("Adding %s to BLE tracker", device.mac)
                devs_to_track.append(device.mac[4:])
            else:
                _LOGGER.debug("Adding %s to BLE do not track", device.mac)
                devs_donot_track.append(device.mac[4:])

    # if track new devices is true discover new devices
    # on every scan.
    track_new = config.get(CONF_TRACK_NEW)

    if not devs_to_track and not track_new:
        _LOGGER.warning("No Bluetooth LE devices to track!")
        return False

    interval = config.get(CONF_SCAN_INTERVAL, DEFAULT_SCAN_INTERVAL)

    def update_ble(now):
        """Lookup Bluetooth LE devices and update status."""
        devs = discover_ble_devices()
        for mac in devs_to_track:
            if mac not in devs:
                continue

            if devs[mac] is None:
                devs[mac] = mac
            see_device(mac, devs[mac])

        if track_new:
            for address in devs:
                if address not in devs_to_track and \
                        address not in devs_donot_track:
                    _LOGGER.info("Discovered Bluetooth LE device %s", address)
                    see_device(address, devs[address], new_device=True)

        track_point_in_utc_time(hass, update_ble, dt_util.utcnow() + interval)

    update_ble(dt_util.utcnow())
    return True

My config is:

device_tracker:
  - platform: bluetooth_tracker
  - platform: ble_tracker
stemelkov commented 5 years ago

I've installed the solution of @scottyphillips and can confirm that it works for me. Thanks a lot!

gsotiriou commented 5 years ago

Doesn't work for me the above solution - any official fix on this?

eloo commented 5 years ago

if tested the workaround from @scottyphillips and it looks like its working (don't stop trying) but it looks like i'm getting nearly everytime this i/o error..

at least some devices are popping up in my known devices list

scottyphillips commented 5 years ago

It would appear that the core implementation is very buggy (which is more the fault of a lack of native support for BLE in Python then with this module or HA). To be honest I have stopped using it for now..

Scott

On 22 Jan 2019, at 8:16 am, Joseph Weigl notifications@github.com<mailto:notifications@github.com> wrote:

if tested the workaround from @scottyphillipshttps://github.com/scottyphillips and it looks like its working (don't stop trying) but it looks like i'm getting nearly everytime this i/o error..

at least some devices are popping up in my known devices list

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHubhttps://github.com/home-assistant/home-assistant/issues/16698#issuecomment-456201001, or mute the threadhttps://github.com/notifications/unsubscribe-auth/AY8GjJ8LSKZ7Ke4d7zwy4rJrKWs3RS79ks5vFi5FgaJpZM4Wuep5.

nbarrientos commented 5 years ago 
hass[1187]: 2019-02-06 21:18:28 WARNING (Thread-5) [homeassistant.components.device_tracker.bluetooth_le_tracker] No Bluetooth LE devices to track!
hass[1187]: 2019-02-06 21:18:28 ERROR (MainThread) [homeassistant.components.device_tracker] Error setting up platform bluetooth_le_tracker

hcitool lescan working fine as the same user that's running HA.

HA 0.86.4

nbarrientos commented 5 years ago

What I'm seeing is that here the value of track_new is None regardless of having

- platform: bluetooth_le_tracker
  new_devices_defaults:
    track_new_devices: true

in my config, therefore bluetooth_le_tracker never scans for devices.

nbarrientos commented 5 years ago

I've monkey patched the code to set the variable above to True by hand and now HA scans for devices.

INFO (Thread-2) [pygatt.backends.gatttool.gatttool] Starting BLE scan

There has to be a bug in the configuration parsing somewhere.

braddo99 commented 5 years ago

@nbarrientos Hey, I think "track_new_devices" means track i.e. monitor if they are home or not, this setting I don't think should impact scanning (and filling up of known devices with whatever is seen more than a few times).