core: Problem with Mi Flora in 0.94.1

Home Assistant release with the issue: from 0.94.0b0 to 0.94.1

Last working Home Assistant release (if known): 0.93.2

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

Component/platform: https://www.home-assistant.io/components/miflora/

Description of problem: Not updating and showing Unknown sensors value.

Rolled back to 0.93.2 and all working fine.

(similar problem that this with Xiaomi BLE Temperature and Humidity sensor: https://github.com/home-assistant/home-assistant/issues/24313)

I could see that in version 0.93.2 Bluepy was used and in version 0.94 Gatttool. Why?

Traceback (if applicable):

0.93.2:

2019-06-10 12:00:15 INFO (SyncWorker_9) [homeassistant.loader] Loaded miflora from homeassistant.components.miflora
2019-06-10 12:00:22 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.miflora
2019-06-10 12:00:22 DEBUG (MainThread) [homeassistant.components.miflora.sensor] Miflora is using BluepyBackend backend.

0.94.1:

2019-06-10 12:45:41 INFO (SyncWorker_7) [homeassistant.loader] Loaded miflora from homeassistant.components.miflora
2019-06-10 12:46:09 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.miflora
2019-06-10 12:46:09 DEBUG (MainThread) [homeassistant.components.miflora.sensor] Miflora is using GatttoolBackend backend.

About this issue

  • Original URL
  • State: closed
  • Created 5 years ago
  • Comments: 42 (7 by maintainers)

Most upvoted comments

I have also updated the bluepy dependency in my docker image but still get “unknown”. Previously it would at least connect for a bit.

@ChristianKuehnel - this error occurs whenever there is a temporary problem communicating with a sensor (perhaps some Bluetooth radio interference?). Ideally, the error should be ignored and the sensor polled again at the next specified interval (most of us have 1200 or 1800 refresh interval configured), however once one sensor fails to respond correctly, the whole home assistant stack stops polling ALL sensors until it has been rebooted.

Here’s a suggestion about how the error could be reliably reproduced:

  1. Create a debugging version of the miflora components that always throw the connection error. For example, if name = “debugging sensor” then throw this error: 2019-08-05 16:17:42 INFO (SyncWorker_8) [homeassistant.components.miflora.sensor] Polling error [Errno 32] Broken pipe

  2. Install and run the miflora debugging sensor. Notice how everything crashes and no further polling occurs.

Note - the error seems to exist in the polling logic somewhere, as other sensors (such as the temperature and humidity one) are also experiencing exactly the same problems as us: https://github.com/home-assistant/home-assistant/issues/19326#issuecomment-487835712

As promised, here’s detailed logs from when the sensors stop working:

2019-08-05 15:37:36 DEBUG (SyncWorker_13) [miflora.miflora_poller] Filling cache with new sensor data.
2019-08-05 15:37:42 DEBUG (SyncWorker_13) [miflora.miflora_poller] Received result for handle 53: FE 00 00 EE 00 00 00 24 38 03 02 3C 00 FB 34 9B
2019-08-05 15:37:42 DEBUG (SyncWorker_2) [miflora.miflora_poller] Filling cache with new sensor data.
2019-08-05 15:37:44 DEBUG (SyncWorker_2) [miflora.miflora_poller] Received result for handle 53: FB 00 00 C6 00 00 00 26 AF 05 02 3C 00 FB 34 9B
2019-08-05 15:37:44 DEBUG (SyncWorker_6) [miflora.miflora_poller] Filling cache with new sensor data.
2019-08-05 15:37:47 DEBUG (SyncWorker_6) [miflora.miflora_poller] Received result for handle 53: F3 00 00 5A 00 00 00 12 64 01 02 3C 00 FB 34 9B
2019-08-05 15:37:47 DEBUG (SyncWorker_16) [miflora.miflora_poller] Using cache (0:00:00.010995 < 0:20:00)
2019-08-05 15:37:47 DEBUG (SyncWorker_17) [miflora.miflora_poller] Using cache (0:00:00.022043 < 0:20:00)
2019-08-05 15:37:47 DEBUG (SyncWorker_11) [miflora.miflora_poller] Filling cache with new sensor data.
2019-08-05 15:37:51 DEBUG (SyncWorker_11) [miflora.miflora_poller] Received result for handle 53: 00 01 00 CE 00 00 00 15 02 05 02 3C 00 FB 34 9B
2019-08-05 15:37:51 DEBUG (SyncWorker_12) [miflora.miflora_poller] Using cache (0:00:07.149638 < 0:20:00)
2019-08-05 15:37:51 DEBUG (SyncWorker_2) [miflora.miflora_poller] Using cache (0:00:08.864595 < 0:20:00)
2019-08-05 15:37:51 DEBUG (SyncWorker_1) [miflora.miflora_poller] Using cache (0:00:07.165023 < 0:20:00)
2019-08-05 15:37:51 DEBUG (SyncWorker_17) [miflora.miflora_poller] Using cache (0:00:03.721934 < 0:20:00)
2019-08-05 15:37:51 DEBUG (SyncWorker_15) [miflora.miflora_poller] Using cache (0:00:07.192641 < 0:20:00)
2019-08-05 15:37:51 DEBUG (SyncWorker_3) [miflora.miflora_poller] Using cache (0:00:08.901800 < 0:20:00)
2019-08-05 15:37:51 DEBUG (SyncWorker_16) [miflora.miflora_poller] Using cache (0:00:08.917443 < 0:20:00)
2019-08-05 15:37:51 DEBUG (SyncWorker_10) [miflora.miflora_poller] Using cache (0:00:00.077761 < 0:20:00)
2019-08-05 15:37:51 DEBUG (SyncWorker_12) [miflora.miflora_poller] Using cache (0:00:00.086036 < 0:20:00)
2019-08-05 15:37:51 DEBUG (SyncWorker_4) [miflora.miflora_poller] Using cache (0:00:00.090698 < 0:20:00)
2019-08-05 15:57:37 DEBUG (SyncWorker_3) [miflora.miflora_poller] Using cache (0:19:54.703271 < 0:20:00)
2019-08-05 15:57:37 DEBUG (SyncWorker_19) [miflora.miflora_poller] Using cache (0:19:49.546958 < 0:20:00)
2019-08-05 15:57:37 DEBUG (SyncWorker_14) [miflora.miflora_poller] Using cache (0:19:45.887923 < 0:20:00)
2019-08-05 15:57:37 DEBUG (SyncWorker_17) [miflora.miflora_poller] Using cache (0:19:53.042237 < 0:20:00)
2019-08-05 15:57:37 DEBUG (SyncWorker_13) [miflora.miflora_poller] Using cache (0:19:54.758556 < 0:20:00)
2019-08-05 15:57:37 DEBUG (SyncWorker_3) [miflora.miflora_poller] Using cache (0:19:45.922754 < 0:20:00)
2019-08-05 15:57:37 DEBUG (SyncWorker_0) [miflora.miflora_poller] Using cache (0:19:45.930966 < 0:20:00)
2019-08-05 15:57:37 DEBUG (SyncWorker_14) [miflora.miflora_poller] Using cache (0:19:54.787378 < 0:20:00)
2019-08-05 15:57:37 DEBUG (SyncWorker_10) [miflora.miflora_poller] Using cache (0:19:49.626010 < 0:20:00)
2019-08-05 15:57:37 DEBUG (SyncWorker_8) [miflora.miflora_poller] Using cache (0:19:45.961244 < 0:20:00)
2019-08-05 15:57:37 DEBUG (SyncWorker_1) [miflora.miflora_poller] Using cache (0:19:53.105975 < 0:20:00)
2019-08-05 15:57:37 DEBUG (SyncWorker_14) [miflora.miflora_poller] Using cache (0:19:49.646391 < 0:20:00)
2019-08-05 15:57:37 DEBUG (SyncWorker_9) [miflora.miflora_poller] Using cache (0:19:49.661411 < 0:20:00)
2019-08-05 15:57:37 DEBUG (SyncWorker_8) [miflora.miflora_poller] Using cache (0:19:53.130622 < 0:20:00)
2019-08-05 15:57:37 DEBUG (SyncWorker_6) [miflora.miflora_poller] Using cache (0:19:53.135761 < 0:20:00)
2019-08-05 15:57:37 DEBUG (SyncWorker_15) [miflora.miflora_poller] Using cache (0:19:54.854235 < 0:20:00)
2019-08-05 16:17:38 DEBUG (SyncWorker_15) [miflora.miflora_poller] Filling cache with new sensor data.
2019-08-05 16:17:42 DEBUG (SyncWorker_15) [miflora.miflora_poller] Received result for handle 53: F6 00 00 94 00 00 00 12 62 01 02 3C 00 FB 34 9B
2019-08-05 16:17:42 DEBUG (SyncWorker_8) [miflora.miflora_poller] Filling cache with new sensor data.
2019-08-05 16:17:42 INFO (SyncWorker_8) [homeassistant.components.miflora.sensor] Polling error [Errno 32] Broken pipe
2019-08-05 16:17:42 DEBUG (SyncWorker_16) [miflora.miflora_poller] Filling cache with new sensor data.
2019-08-05 16:17:52 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.white_orchid_temperature is taking over 10 seconds
2019-08-05 16:37:39 WARNING (MainThread) [homeassistant.components.sensor] Updating miflora sensor took longer than the scheduled update interval 0:20:00
2019-08-05 16:57:40 WARNING (MainThread) [homeassistant.components.sensor] Updating miflora sensor took longer than the scheduled update interval 0:20:00
2019-08-05 17:17:41 WARNING (MainThread) [homeassistant.components.sensor] Updating miflora sensor took longer than the scheduled update interval 0:20:00
2019-08-05 17:37:42 WARNING (MainThread) [homeassistant.components.sensor] Updating miflora sensor took longer than the scheduled update interval 0:20:00
2019-08-05 17:57:43 WARNING (MainThread) [homeassistant.components.sensor] Updating miflora sensor took longer than the scheduled update interval 0:20:00
2019-08-05 18:17:44 WARNING (MainThread) [homeassistant.components.sensor] Updating miflora sensor took longer than the scheduled update interval 0:20:00
2019-08-05 18:37:45 WARNING (MainThread) [homeassistant.components.sensor] Updating miflora sensor took longer than the scheduled update interval 0:20:00

Ist seems bluepy has a Problem with Python 3.7.3 https://github.com/IanHarvey/bluepy/issues/364

I’d be happy to help creating debug logs. I have a similar problem, where my miflora sensors (I have 4 of them) work fine for a couple of hours, then just stop reporting until i restart homeassistant (docker restart container), after which they spring back to life and work again for a few hours.

I tried migrating over to brand new install (from a Pi3-B to a Pi4), the only configuration that I copied was the sensor configuration in my configuration.yaml, otherwise it was a brand new install (to try eliminate configuration as the cause of the problem).

My HA version: 0.97.0b1

I’ve enabled debug logging, and will report back with any findings tomorrow once the issue occurs again:

logger:
  default: info
  logs:
   miflora: debug
   btlewrap: debug

Here’s my sensor config:

# Sensors
sensor:
  # Weather prediction
  - platform: yr

  # Pink Orchid
  - platform: miflora
    mac: 'C4:7C:8D:63:EC:05'
    name: Pink Orchid
    force_update: true
    scan_interval: 1200
    #median: 3
    monitored_conditions:
      - moisture
      - light
      - temperature
      - conductivity
      - battery

  # Purple Orchid
  - platform: miflora
    mac: 'C4:7C:8D:63:FA:B4'
    name: Purple Orchid
    force_update: true
    scan_interval: 1200
    #median: 3
    monitored_conditions:
      - moisture
      - light
      - temperature
      - conductivity
      - battery

  # White Orchid
  - platform: miflora
    mac: 'C4:7C:8D:63:FA:C8'
    name: White Orchid
    force_update: true
    scan_interval: 1200
    #median: 3
    monitored_conditions:
      - moisture
      - light
      - temperature
      - conductivity
      - battery

  # Mini Orchid
  - platform: miflora
    mac: 'C4:7C:8D:64:01:37'
    name: Mini Orchid
    force_update: true
    scan_interval: 1200
    #median: 3
    monitored_conditions:
      - moisture
      - light
      - temperature
      - conductivity
      - battery

Oh, I also seem to have the correct bluetooth library? Here’s what my homeassistant is reporting:

bash-5.0# pip3 show bluepy
Name: bluepy
Version: 1.3.0
Summary: Python module for interfacing with BLE devices through Bluez
Home-page: https://github.com/IanHarvey/bluepy
Author: Ian Harvey
Author-email: website-contact@fenditton.org
License: UNKNOWN
Location: /usr/local/lib/python3.7/site-packages
Requires:
Required-by: avea

(Accessed it through Portainer > Container console)