Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

miflora sensors reported as 'Unavailable'. #30275

Closed
eeepsylon opened this issue Dec 29, 2019 · 86 comments · Fixed by #31156
Closed

miflora sensors reported as 'Unavailable'. #30275

eeepsylon opened this issue Dec 29, 2019 · 86 comments · Fixed by #31156
Assignees

Comments

@eeepsylon
Copy link

Home Assistant release with the issue:

0.103.4

Last working Home Assistant release (if known):
0.102

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

raspbian/virtualenv on pi4
python_version 3.7.3

Integration:

https://www.home-assistant.io/integrations/miflora/

Description of problem:
Since #29276, miflora sensors are now displayed as 'Unavailable' when they can't be reached. Since BtLE is quite unreliable, even with a good connection they are frequently displayed as 'Unavailable'.

As values tend to change slowly, a day-old stale value is preferable to 'Unavailable'.

image

All six of my devices are within 4m of the pi4 which runs home-assistant. Even the closest devices have gaps in the graphs where they are 'Unavailable'.
image
image
image

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

Traceback (if applicable):


Additional information:

Suggestion: Allow users to set a threshold after which the sensor is considered 'Unavailable'. Only mark the sensor 'Unavailable' if the user has configured a threshold.

@probot-home-assistant
Copy link

Hey there @Danielhiversen, @ChristianKuehnel, mind taking a look at this issue as its been labeled with a integration (miflora) you are listed as a codeowner for? Thanks!

@talondnb
Copy link

I have this too, I've also noticed that this issue came about with 0.103.

Some findings:

  • sensors will remain in Unavailable until a host reboot is performed
  • when attempting to run a bluetooth scan from cli using bluetoothctl > scan on command, returns the following:

image

workaround in cli:

  • running a bluetoothctl > power off, then power on will allow a scan to be performed again although I've not yet verified if the sensors come back online yet, will update when/if this occurs.

I'm facing this issue on Hassio 0.103.4 on a Raspberry Pi 3b.

@ChristianKuehnel
Copy link
Contributor

This is related to the change #29276 by @ferbar. I suppose this was his intention.

@ferbar I would recommend only showing the error message after several attempts have failed or after not data for several hours. The current implementation seems a bit confusing...

@ferbar
Copy link
Contributor

ferbar commented Dec 30, 2019

@ChristianKuehnel I was asking for help in the forum if there are intended ways of solving this no success until now.
https://community.home-assistant.io/t/entity-remember-last-state-for-an-hour-and-then-go-to-unavailable-if-update-fails-for-a-long-period/153351

If everybody agrees I will implement the timeout in the miflora code (sry, I'm thinking this is the wrong place)
An other workaround would be to create a template sensor which always returns "available"

@ferbar
Copy link
Contributor

ferbar commented Dec 30, 2019

@ChristianKuehnel: please have a look at:
ferbar@b8704f5

@xPhantomNL
Copy link

xPhantomNL commented Jan 4, 2020

I'm facing the exact same issues ("Failed to start discovery: org.bluez.Error.InProgress") as @talondnb.
Running 0.103.4 in docker, and added the miflora debugging to my logger with;
logger: default: info logs: homeassistant.components.sensor.miflora: debug btlewrap: debug miflora: debug

In my Home Assistant container logs via portainer I see the following information;
2020-01-04 12:06:41 INFO (SyncWorker_2) [homeassistant.components.miflora.sensor] Polling error BluetoothBackendException: Could not read data from Mi Flora sensor C4:7C:8D:66:19:4D, 2020-01-04 12:06:41 DEBUG (SyncWorker_15) [btlewrap.bluepy] Call to <function BluepyBackend.connect at 0x715a6540> failed, try 1 of 3, 2020-01-04 12:06:41 DEBUG (SyncWorker_15) [btlewrap.bluepy] Call to <function BluepyBackend.connect at 0x715a6540> failed, try 2 of 3, 2020-01-04 12:06:41 DEBUG (SyncWorker_15) [btlewrap.bluepy] Call to <function BluepyBackend.connect at 0x715a6540> failed, try 3 of 3, 2020-01-04 12:06:41 INFO (SyncWorker_15) [homeassistant.components.miflora.sensor] Polling error BluetoothBackendException: , 2020-01-04 12:06:41 DEBUG (SyncWorker_4) [miflora.miflora_poller] Using cache (0:15:00.432023 < 0:20:00), 2020-01-04 12:06:41 INFO (SyncWorker_4) [homeassistant.components.miflora.sensor] Polling error BluetoothBackendException: Could not read data from Mi Flora sensor C4:7C:8D:66:19:4D, 2020-01-04 12:06:41 DEBUG (SyncWorker_12) [miflora.miflora_poller] Using cache (0:15:00.441903 < 0:20:00), 2020-01-04 12:06:41 INFO (SyncWorker_12) [homeassistant.components.miflora.sensor] Polling error BluetoothBackendException: Could not read data from Mi Flora sensor C4:7C:8D:66:19:4D, 2020-01-04 12:16:52 INFO (MainThread) [hacs.factory] Prosessing 11 tasks, 2020-01-04 12:17:00 INFO (MainThread) [hacs.factory] Task prosessing of 11 tasks completed in 8 seconds, 2020-01-04 12:23:27 ERROR (MainThread) [metno] https://aa015h6buqvih86i1.api.met.no/weatherapi/locationforecast/1.9/ returned , 2020-01-04 12:23:27 ERROR (MainThread) [homeassistant.components.met.weather] Retrying in 15 minutes, 2020-01-04 12:26:42 DEBUG (SyncWorker_10) [miflora.miflora_poller] Filling cache with new sensor data., 2020-01-04 12:26:42 DEBUG (SyncWorker_10) [btlewrap.bluepy] Call to <function BluepyBackend.connect at 0x715a6540> failed, try 1 of 3, 2020-01-04 12:26:42 DEBUG (SyncWorker_10) [btlewrap.bluepy] Call to <function BluepyBackend.connect at 0x715a6540> failed, try 2 of 3, 2020-01-04 12:26:42 DEBUG (SyncWorker_10) [btlewrap.bluepy] Call to <function BluepyBackend.connect at 0x715a6540> failed, try 3 of 3, 2020-01-04 12:26:42 INFO (SyncWorker_10) [homeassistant.components.miflora.sensor] Polling error BluetoothBackendException: , 2020-01-04 12:26:42 DEBUG (SyncWorker_19) [miflora.miflora_poller] Using cache (0:15:00.019490 < 0:20:00), 2020-01-04 12:26:42 INFO (SyncWorker_19) [homeassistant.components.miflora.sensor] Polling error BluetoothBackendException: Could not read data from Mi Flora sensor C4:7C:8D:66:19:4D, 2020-01-04 12:26:42 DEBUG (SyncWorker_8) [btlewrap.bluepy] Call to <function BluepyBackend.connect at 0x715a6540> failed, try 1 of 3, 2020-01-04 12:26:42 DEBUG (SyncWorker_8) [btlewrap.bluepy] Call to <function BluepyBackend.connect at 0x715a6540> failed, try 2 of 3, 2020-01-04 12:26:42 DEBUG (SyncWorker_8) [btlewrap.bluepy] Call to <function BluepyBackend.connect at 0x715a6540> failed, try 3 of 3, 2020-01-04 12:26:42 INFO (SyncWorker_8) [homeassistant.components.miflora.sensor] Polling error BluetoothBackendException: , 2020-01-04 12:26:42 DEBUG (SyncWorker_4) [miflora.miflora_poller] Using cache (0:15:00.476614 < 0:20:00), 2020-01-04 12:26:42 INFO (SyncWorker_4) [homeassistant.components.miflora.sensor] Polling error BluetoothBackendException: Could not read data from Mi Flora sensor C4:7C:8D:66:19:4D, 2020-01-04 12:26:42 DEBUG (SyncWorker_14) [miflora.miflora_poller] Using cache (0:15:00.489555 < 0:20:00), 2020-01-04 12:26:42 INFO (SyncWorker_14) [homeassistant.components.miflora.sensor] Polling error BluetoothBackendException: Could not read data from Mi Flora sensor C4:7C:8D:66:19:4D, 2020-01-04 12:46:43 DEBUG (SyncWorker_14) [btlewrap.bluepy] Call to <function BluepyBackend.connect at 0x715a6540> failed, try 1 of 3, 2020-01-04 12:46:43 DEBUG (SyncWorker_14) [btlewrap.bluepy] Call to <function BluepyBackend.connect at 0x715a6540> failed, try 2 of 3, 2020-01-04 12:46:43 DEBUG (SyncWorker_14) [btlewrap.bluepy] Call to <function BluepyBackend.connect at 0x715a6540> failed, try 3 of 3, 2020-01-04 12:46:43 INFO (SyncWorker_14) [homeassistant.components.miflora.sensor] Polling error BluetoothBackendException: , 2020-01-04 12:46:43 DEBUG (SyncWorker_0) [miflora.miflora_poller] Filling cache with new sensor data., 2020-01-04 12:46:43 DEBUG (SyncWorker_0) [btlewrap.bluepy] Call to <function BluepyBackend.connect at 0x715a6540> failed, try 1 of 3, 2020-01-04 12:46:43 DEBUG (SyncWorker_0) [btlewrap.bluepy] Call to <function BluepyBackend.connect at 0x715a6540> failed, try 2 of 3, 2020-01-04 12:46:43 DEBUG (SyncWorker_0) [btlewrap.bluepy] Call to <function BluepyBackend.connect at 0x715a6540> failed, try 3 of 3, 2020-01-04 12:46:43 INFO (SyncWorker_0) [homeassistant.components.miflora.sensor] Polling error BluetoothBackendException: , 2020-01-04 12:46:43 DEBUG (SyncWorker_8) [miflora.miflora_poller] Using cache (0:15:00.013403 < 0:20:00), 2020-01-04 12:46:43 INFO (SyncWorker_8) [homeassistant.components.miflora.sensor] Polling error BluetoothBackendException: Could not read data from Mi Flora sensor C4:7C:8D:66:19:4D, 2020-01-04 12:46:43 DEBUG (SyncWorker_13) [miflora.miflora_poller] Using cache (0:15:00.035718 < 0:20:00), 2020-01-04 12:46:43 INFO (SyncWorker_13) [homeassistant.components.miflora.sensor] Polling error BluetoothBackendException: Could not read data from Mi Flora sensor C4:7C:8D:66:19:4D, 2020-01-04 12:46:43 DEBUG (SyncWorker_12) [miflora.miflora_poller] Using cache (0:15:00.047539 < 0:20:00), 2020-01-04 12:46:43 INFO (SyncWorker_12) [homeassistant.components.miflora.sensor] Polling error BluetoothBackendException: Could not read data from Mi Flora sensor C4:7C:8D:66:19:4D, 2020-01-04 12:46:53 INFO (MainThread) [hacs.factory] Prosessing 11 tasks, 2020-01-04 12:47:01 INFO (MainThread) [hacs.factory] Task prosessing of 11 tasks completed in 9 seconds, 2020-01-04 13:06:44 DEBUG (SyncWorker_6) [miflora.miflora_poller] Filling cache with new sensor data., 2020-01-04 13:06:44 DEBUG (SyncWorker_6) [btlewrap.bluepy] Call to <function BluepyBackend.connect at 0x715a6540> failed, try 1 of 3, 2020-01-04 13:06:44 DEBUG (SyncWorker_6) [btlewrap.bluepy] Call to <function BluepyBackend.connect at 0x715a6540> failed, try 2 of 3, 2020-01-04 13:06:44 DEBUG (SyncWorker_6) [btlewrap.bluepy] Call to <function BluepyBackend.connect at 0x715a6540> failed, try 3 of 3, 2020-01-04 13:06:44 INFO (SyncWorker_6) [homeassistant.components.miflora.sensor] Polling error BluetoothBackendException: , 2020-01-04 13:06:44 DEBUG (SyncWorker_13) [miflora.miflora_poller] Using cache (0:15:00.013333 < 0:20:00), 2020-01-04 13:06:44 INFO (SyncWorker_13) [homeassistant.components.miflora.sensor] Polling error BluetoothBackendException: Could not read data from Mi Flora sensor C4:7C:8D:66:19:4D, 2020-01-04 13:06:44 DEBUG (SyncWorker_3) [btlewrap.bluepy] Call to <function BluepyBackend.connect at 0x715a6540> failed, try 1 of 3, 2020-01-04 13:06:44 DEBUG (SyncWorker_3) [btlewrap.bluepy] Call to <function BluepyBackend.connect at 0x715a6540> failed, try 2 of 3, 2020-01-04 13:06:44 DEBUG (SyncWorker_3) [btlewrap.bluepy] Call to <function BluepyBackend.connect at 0x715a6540> failed, try 3 of 3, 2020-01-04 13:06:44 INFO (SyncWorker_3) [homeassistant.components.miflora.sensor] Polling error BluetoothBackendException: , 2020-01-04 13:06:44 DEBUG (SyncWorker_7) [miflora.miflora_poller] Using cache (0:15:00.475562 < 0:20:00), 2020-01-04 13:06:44 INFO (SyncWorker_7) [homeassistant.components.miflora.sensor] Polling error BluetoothBackendException: Could not read data from Mi Flora sensor C4:7C:8D:66:19:4D, 2020-01-04 13:06:45 DEBUG (SyncWorker_4) [miflora.miflora_poller] Using cache (0:15:00.485941 < 0:20:00), 2020-01-04 13:06:45 INFO (SyncWorker_4) [homeassistant.components.miflora.sensor] Polling error BluetoothBackendException: Could not read data from Mi Flora sensor C4:7C:8D:66:19:4D, 2020-01-04 13:16:54 INFO (MainThread) [hacs.factory] Prosessing 11 tasks, 2020-01-04 13:17:02 INFO (MainThread) [hacs.factory] Task prosessing of 11 tasks completed in 9 seconds, 2020-01-04 13:26:44 DEBUG (SyncWorker_4) [miflora.miflora_poller] Filling cache with new sensor data., 2020-01-04 13:26:44 DEBUG (SyncWorker_4) [btlewrap.bluepy] Call to <function BluepyBackend.connect at 0x715a6540> failed, try 1 of 3, 2020-01-04 13:26:44 DEBUG (SyncWorker_4) [btlewrap.bluepy] Call to <function BluepyBackend.connect at 0x715a6540> failed, try 2 of 3, 2020-01-04 13:26:44 DEBUG (SyncWorker_4) [btlewrap.bluepy] Call to <function BluepyBackend.connect at 0x715a6540> failed, try 3 of 3, 2020-01-04 13:26:44 INFO (SyncWorker_4) [homeassistant.components.miflora.sensor] Polling error BluetoothBackendException: , 2020-01-04 13:26:44 DEBUG (SyncWorker_4) [btlewrap.bluepy] Call to <function BluepyBackend.connect at 0x715a6540> failed, try 1 of 3, 2020-01-04 13:26:44 DEBUG (SyncWorker_4) [btlewrap.bluepy] Call to <function BluepyBackend.connect at 0x715a6540> failed, try 2 of 3, 2020-01-04 13:26:44 DEBUG (SyncWorker_4) [btlewrap.bluepy] Call to <function BluepyBackend.connect at 0x715a6540> failed, try 3 of 3, 2020-01-04 13:26:44 INFO (SyncWorker_4) [homeassistant.components.miflora.sensor] Polling error BluetoothBackendException: , 2020-01-04 13:26:44 DEBUG (SyncWorker_15) [miflora.miflora_poller] Using cache (0:15:00.455645 < 0:20:00), 2020-01-04 13:26:44 INFO (SyncWorker_15) [homeassistant.components.miflora.sensor] Polling error BluetoothBackendException: Could not read data from Mi Flora sensor C4:7C:8D:66:19:4D, 2020-01-04 13:26:44 DEBUG (SyncWorker_12) [miflora.miflora_poller] Using cache (0:15:00.466251 < 0:20:00), 2020-01-04 13:26:44 INFO (SyncWorker_12) [homeassistant.components.miflora.sensor] Polling error BluetoothBackendException: Could not read data from Mi Flora sensor C4:7C:8D:66:19:4D, 2020-01-04 13:26:44 DEBUG (SyncWorker_18) [miflora.miflora_poller] Using cache (0:15:00.473421 < 0:20:00), 2020-01-04 13:26:44 INFO (SyncWorker_18) [homeassistant.components.miflora.sensor] Polling error BluetoothBackendException: Could not read data from Mi Flora sensor C4:7C:8D:66:19:4D, 2020-01-04 13:46:45 DEBUG (SyncWorker_15) [btlewrap.bluepy] Call to <function BluepyBackend.connect at 0x715a6540> failed, try 1 of 3, 2020-01-04 13:46:45 DEBUG (SyncWorker_15) [btlewrap.bluepy] Call to <function BluepyBackend.connect at 0x715a6540> failed, try 2 of 3, 2020-01-04 13:46:45 DEBUG (SyncWorker_15) [btlewrap.bluepy] Call to <function BluepyBackend.connect at 0x715a6540> failed, try 3 of 3, 2020-01-04 13:46:45 INFO (SyncWorker_15) [homeassistant.components.miflora.sensor] Polling error BluetoothBackendException: , 2020-01-04 13:46:45 DEBUG (SyncWorker_16) [miflora.miflora_poller] Filling cache with new sensor data., 2020-01-04 13:46:45 DEBUG (SyncWorker_16) [btlewrap.bluepy] Call to <function BluepyBackend.connect at 0x715a6540> failed, try 1 of 3, 2020-01-04 13:46:45 DEBUG (SyncWorker_16) [btlewrap.bluepy] Call to <function BluepyBackend.connect at 0x715a6540> failed, try 2 of 3, 2020-01-04 13:46:45 DEBUG (SyncWorker_16) [btlewrap.bluepy] Call to <function BluepyBackend.connect at 0x715a6540> failed, try 3 of 3, 2020-01-04 13:46:45 INFO (SyncWorker_16) [homeassistant.components.miflora.sensor] Polling error BluetoothBackendException: , 2020-01-04 13:46:45 DEBUG (SyncWorker_2) [miflora.miflora_poller] Using cache (0:15:00.013082 < 0:20:00), 2020-01-04 13:46:45 INFO (SyncWorker_2) [homeassistant.components.miflora.sensor] Polling error BluetoothBackendException: Could not read data from Mi Flora sensor C4:7C:8D:66:19:4D, 2020-01-04 13:46:45 DEBUG (SyncWorker_5) [miflora.miflora_poller] Using cache (0:15:00.081467 < 0:20:00), 2020-01-04 13:46:45 INFO (SyncWorker_5) [homeassistant.components.miflora.sensor] Polling error BluetoothBackendException: Could not read data from Mi Flora sensor C4:7C:8D:66:19:4D, 2020-01-04 13:46:45 DEBUG (SyncWorker_11) [miflora.miflora_poller] Using cache (0:15:00.090209 < 0:20:00), 2020-01-04 13:46:45 INFO (SyncWorker_11) [homeassistant.components.miflora.sensor] Polling error BluetoothBackendException: Could not read data from Mi Flora sensor C4:7C:8D:66:19:4D, 2020-01-04 13:46:55 INFO (MainThread) [hacs.factory] Prosessing 11 tasks, 2020-01-04 13:47:03 INFO (MainThread) [hacs.factory] Task prosessing of 11 tasks completed in 9 seconds, 2020-01-04 14:06:46 DEBUG (SyncWorker_0) [miflora.miflora_poller] Filling cache with new sensor data., 2020-01-04 14:06:48 DEBUG (SyncWorker_0) [miflora.miflora_poller] Received result for handle 56: 62 2A 33 2E 32 2E 31, 2020-01-04 14:06:49 DEBUG (SyncWorker_0) [miflora.miflora_poller] Received result for handle 53: B1 00 00 15 00 00 00 10 1E 00 02 3C 00 FB 34 9B, 2020-01-04 14:06:49 DEBUG (SyncWorker_7) [miflora.miflora_poller] Using cache (0:00:00.015156 < 0:20:00), 2020-01-04 14:06:49 DEBUG (SyncWorker_17) [miflora.miflora_poller] Using cache (0:00:00.025710 < 0:20:00), 2020-01-04 14:06:49 DEBUG (SyncWorker_13) [miflora.miflora_poller] Using cache (0:00:00.035413 < 0:20:00),

With the Flower Care app, I can still sync the data between the sensor and my phone so I'm positive the battery isn't dead. The sensor is running on firmware 3.2.1 (latest).

Edit;
Can confirm running power off and power on via bluetoothctl does indeed work and my sensor is reporting data again (for now, at least)

Edit 2;
14:06 it synced new data (after turning bluetooth off and back on)
14:26 it synced new data
14:46 it failed to sync new data (same issue as above)

@talondnb
Copy link

Anyone running https://github.com/home-assistant/hassos/releases/tag/3.8 yet?
It has an update to BlueZ package, maybe a fix?

@KendallWhitman
Copy link

KendallWhitman commented Jan 23, 2020

I'm also getting this after updating to the latest docker image of Home Assistant v0.104.3
I tried restarting my controller via bluetoothctl from what others suggested but wasn't able to get a reading. I restarted the docker container and was able to get one of three sensors to read for a few minutes before it went back to unavailable.
The only error I'm getting in the logs is about the sensors taking longer than 10 seconds to connect.

Edit: 24 hours later, and everything has started working on it's own...? 🤷‍♂️

@ferbar
Copy link
Contributor

ferbar commented Jan 26, 2020

The PR above will not fix any bad-connection-problems. It will only make it less worse because you can tell HA to report values even if they are 24 hours old. Before HA 0.103 you have seen the last value received forever, even if the battery was empty for days/weeks.

You can check the following:
in configuration.yaml - miflora set
scan_interval: 30
(don't forgett to revert this later on)
Remove the battery of the miflora sensor. restart HA. The led of the BT dongle will be blinking all the time because HA tries to refresh the values all the time.

root@home-assistant:~# gatttool --device=C4:7C:8D:AA:BB:CC --char-read -a 0x35
connect: Device or resource busy (16)

Set scan_interval: 3600 so HA will only try to scan every hour and the BT dongle led will stop flashing.

root@home-assistant:~# time gatttool --device=C4:7C:8D:AA:BB:CC --char-read -a 0x35

the BT dongle led will start flashing

connect error: Connection refused (111)

real    0m42.017s
user    0m0.005s
sys     0m0.012s

Compare the behavior with the battery inserted and the flower sensor next to the BT dongle or a longer range.

@Molodax
Copy link

Molodax commented Feb 4, 2020

Anyone running https://github.com/home-assistant/hassos/releases/tag/3.8 yet?
It has an update to BlueZ package, maybe a fix?

Actually, I believe that this is a culprit of the issue in Hass.io.
Before I updated to 0.104.x and HassOS 3.8, my miFlora worked good enough for almost a year. I had a small automation that was controlling whether the values were up-to-date, so didn't need @ferbar update either. Now everything related to miFlora is broken which is quite annoying.

@xPhantomNL
Copy link

I think my issues started with 0.104.x as well, I lowered the baudrate of my Pi 3B last sunday and no issues so far (about 56 hours later), still receiving data which matches with the values from the Flower Care app.

Found it here;
raspberrypi/linux#2264 (comment)

@Martinvdm
Copy link

My miflora issues started 104 as well, before that it was working well, now it is broken

@ferbar
Copy link
Contributor

ferbar commented Feb 10, 2020

@Martinvdm @xPhantomNL @Molodax which hardware do you use? HassOS or something else?

@Martinvdm
Copy link

Using intel nuc with docker

@aronsky
Copy link
Contributor

aronsky commented Feb 20, 2020

@xPhantomNL your suggestion definitely helped (on an RPi 3Brev1.2)!

@talondnb
Copy link

talondnb commented Mar 2, 2020

Anyone running https://github.com/home-assistant/hassos/releases/tag/3.8 yet?
It has an update to BlueZ package, maybe a fix?

Actually, I believe that this is a culprit of the issue in Hass.io.
Before I updated to 0.104.x and HassOS 3.8, my miFlora worked good enough for almost a year. I had a small automation that was controlling whether the values were up-to-date, so didn't need @ferbar update either. Now everything related to miFlora is broken which is quite annoying.

Have you had any luck getting them working again yet?

@CodeFinder2
Copy link

CodeFinder2 commented Mar 7, 2020

Same issues here, very annoying (5 sensors, some with new batteries after less than a year)...

Edit: I completely agree with #30275 (comment)

@talondnb
Copy link

talondnb commented Mar 7, 2020

Same issues here, very annoying (5 sensors, some with new batteries after less than a year)...

I've made this crude workaround which should function until a fix is in place. I'm using a Pi 3B and have had this issue since around 0.103, currently running 0.106.5. Still testing but worth trying.

## Shell Command
shell_command:
  bluetooth_off: 'hciconfig hci0 down'
  bluetooth_on: 'hciconfig hci0 up'

## Automations
automation:
  # Bluetooth Power toggle every 15 minutes (workaround for bluetooth pi 3 issue)
  - alias: 'Toggle bluetooth power every 15 minutes'
    trigger:
      platform: time_pattern
      minutes: "/15"
    action:
      - service: shell_command.bluetooth_off
      - delay: '00:00:05'
      - service: shell_command.bluetooth_on

Edit: working well so far

@CodeFinder2
Copy link

CodeFinder2 commented Mar 7, 2020

@talondnb thanks for the workaround! I tried it by logging in via the hassio ssh addon but the command couldn't be found (which makes sense). I then applied it on my server directly (ubuntu 18.04, via ssh) 'sudo hciconfig down/up' but my sensors are still being reported as unavailable. 😕 How do I apply these commands correctly? 🙈

PS: I can poll all my sensors very quickly and without any issues from my laptop using the miflora python lib which is also used by this component. So it MUST be related to this component and the way how it interacts with Home Assistant. 🤷‍♂️

@talondnb
Copy link

talondnb commented Mar 8, 2020

@talondnb thanks for the workaround! I tried it by logging in via the hassio ssh addon but the command couldn't be found (which makes sense). I then applied it on my server directly (ubuntu 18.04, via ssh) 'sudo hciconfig down/up' but my sensors are still being reported as unavailable. 😕 How do I apply these commands correctly? 🙈

PS: I can poll all my sensors very quickly and without any issues from my laptop using the miflora python lib which is also used by this component. So it MUST be related to this component and the way how it interacts with Home Assistant. 🤷‍♂️

The hciconfig command doesn't exist within the hassio ssh addon and the shell_command integration runs commands within the hassio docker host itself. To get to the host, disable protection mode in the SSH addon (the one by Frenck) and run 'docker exec -it homeassistant /bin/bash' within a ssh session.

If you want to perform the same within the hassio ssh addon, simply run 'bluetoothctl power off' then 'bluetoothctl power on'. This 'reboots' the bluetooth controller and the sensors will come back within 20 minutes or so - it is not instant unfortunately.

It's definitely relating to the software on homeassistant/pi.

@talondnb
Copy link

talondnb commented Mar 8, 2020

BTW, it looks like a 'hciconfig hci0 reset' might be simpler and unless it was a coincidence, brought my sensors back sooner:

## Shell Command
shell_command:
  bluetooth_reset: 'hciconfig hci0 reset'

## Automations
automation:
  # Bluetooth Power toggle every 15 minutes (workaround for bluetooth pi 3 issue)
  - alias: 'Toggle bluetooth power every 15 minutes'
    trigger:
      platform: time_pattern
      minutes: "/15"
    action:
      - service: shell_command.bluetooth_reset

@aronsky
Copy link
Contributor

aronsky commented Mar 8, 2020

BTW, it looks like a 'hciconfig hci0 reset' might be simpler and unless it was a coincidence, brought my sensors back sooner:

It's a trick I used for a while, and it was better than nothing, but the Bluetooth would eventually lock up and I would have to reboot the Pi (as in, the hci0 reset would be stuck as well, so nothing could be done). Sorry to be a downer, but I wouldn't get my hopes up.

@talondnb
Copy link

talondnb commented Mar 8, 2020

Ahh, didn't realise. Thanks for the insight though, I think for those like myself this is probably the best workaround for now, sigh.

@CodeFinder2
Copy link

@talondnb thanks for clarifying but I can simply log into my host since it runs normal Ubuntu (and Hassio + docker on top of it). However, a sudo bluetoothctl followed by power off, power on does not help (it seems to power cycle the adapter correctly but als miflora sensors are still unavailable).

@CodeFinder2
Copy link

CodeFinder2 commented Mar 8, 2020

I just realized after a restart of HA (v106.5) that I just have this (wrt. miflora) in my log (I have 6 sensors):

2020-03-08 20:15:05 INFO (SyncWorker_33) [homeassistant.loader] Loaded miflora from homeassistant.components.miflora
[...]
2020-03-08 20:15:08 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.miflora
2020-03-08 20:15:08 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.miflora
2020-03-08 20:15:08 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.miflora
2020-03-08 20:15:08 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.miflora
2020-03-08 20:15:08 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.miflora
2020-03-08 20:15:08 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.miflora
[...]
2020-03-08 20:15:08 DEBUG (MainThread) [homeassistant.components.miflora.sensor] Miflora is using BluepyBackend backend.
2020-03-08 20:15:08 DEBUG (MainThread) [homeassistant.components.miflora.sensor] Miflora is using BluepyBackend backend.
2020-03-08 20:15:08 DEBUG (MainThread) [homeassistant.components.miflora.sensor] Miflora is using BluepyBackend backend.
2020-03-08 20:15:08 DEBUG (MainThread) [homeassistant.components.miflora.sensor] Miflora is using BluepyBackend backend.
2020-03-08 20:15:08 DEBUG (MainThread) [homeassistant.components.miflora.sensor] Miflora is using BluepyBackend backend.
2020-03-08 20:15:08 DEBUG (MainThread) [homeassistant.components.miflora.sensor] Miflora is using BluepyBackend backend.
[...]
2020-03-08 20:15:24 DEBUG (SyncWorker_21) [homeassistant.components.miflora.sensor] Polling data for spathiphyllum Conductivity

That's it and according to the code, it seems to be stall in https://github.com/home-assistant/core/blob/0.106.5/homeassistant/components/miflora/sensor.py#L164 because every other cflow case has an output. For me it seems to be stuck at polling the first sensor but the question is why. Does anyone know (maybe @ChristianKuehnel ?) if there's a timeout for polling and to what value it is set to?

According to my investigations, parameter_value() will be called which will have a cache miss, so it will invoke self.fill_cache(). In that method, there is no loop but a comment saying "wait 5 minutes before retrying": where does this (wait+retry) happen?

To continue, I assume the work is done in connection.write_handle() which calls BluetoothInterface.connect() -> self._backend.connect() -> BluepyBackend.connect() (at least in my case of bluepy). I don't know what Peripheral does (and don't want to track it further down) but at least up to here, there's no waiting or retrying ... 🤔 🆘

Edit: I now also tried to do a scan and polled every sensor from the server itself (running HA and the miflora component) and that worked flawlessly. Again, it must be an issue in the HA component.

@CodeFinder2
Copy link

Hass.io over Ubuntu 18.04 using an USB Bluetooth stick 🤔

@aronsky
Copy link
Contributor

aronsky commented Mar 10, 2020

I'm not sure how USB Bluetooth sticks are configured, and even whether the underlying problem is the same... However, did you go over the commands I recommended to @talondnb in the other thread, starting at #31657 (comment)?

If the problem is an overflow due to the lack of hardware flow control, we should be able to figure out where the baud rate is set in order to lower it.

@CodeFinder2
Copy link

@aronsky thanks for your super quick support! Both ps -ef | grep hciattach and ps -ef | grep btattach are empty. However, dmesg contains (among a lot of other stuff):

[149364.467729] usb usb2-port1: disabled by hub (EMI?), re-enabling...                                          [149364.472994] usb 2-1: USB disconnect, device number 2
[149365.579310] usb 2-1: new full-speed USB device number 3 using exynos-ohci
[149365.814584] usb 2-1: New USB device found, idVendor=0a5c, idProduct=21e8
[149365.814613] usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[149365.814629] usb 2-1: Product: BCM20702A0
[149365.814646] usb 2-1: Manufacturer: Broadcom Corp    [149365.814661] usb 2-1: SerialNumber: 5CF37081D855
[149365.935536] Bluetooth: hci0: BCM: chip id 63
[149365.937530] Bluetooth: hci0: BCM: features 0x07     [149365.954531] Bluetooth: hci0: hassio
[149365.956629] Bluetooth: hci0: BCM20702A1 (001.002.014) build 0000
[149365.962390] bluetooth hci0: Direct firmware load for brcm/BCM20702A1-0a5c-21e8.hcd failed with error -2
[149365.962402] Bluetooth: hci0: BCM: Patch brcm/BCM20702A1-0a5c-21e8.hcd not found                             [149366.941727] usb usb2-port1: disabled by hub (EMI?), re-enabling...
[149366.946838] usb 2-1: USB disconnect, device number 3[149367.671265] usb 2-1: new full-speed USB device number 4 using exynos-ohci                                   [149367.906499] usb 2-1: New USB device found, idVendor=0a5c, idProduct=21e8                                    [149367.906533] usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3                               [149367.906550] usb 2-1: Product: BCM20702A0            [149367.906566] usb 2-1: Manufacturer: Broadcom Corp
[149367.906582] usb 2-1: SerialNumber: 5CF37081D855     [149368.027453] Bluetooth: hci0: BCM: chip id 63
[149368.029435] Bluetooth: hci0: BCM: features 0x07     [149368.046475] Bluetooth: hci0: hassio                 [149368.048518] Bluetooth: hci0: BCM20702A1 (001.002.014) build 0000
[149368.048629] bluetooth hci0: Direct firmware load for brcm/BCM20702A1-0a5c-21e8.hcd failed with error -2
[149368.048652] Bluetooth: hci0: BCM: Patch brcm/BCM20702A1-0a5c-21e8.hcd not found
[152662.441493] usb usb2-port1: disabled by hub (EMI?), re-enabling...
[152662.446492] usb 2-1: USB disconnect, device number 4[152663.554320] usb 2-1: new full-speed USB device number 5 using exynos-ohci                                   [152663.793503] usb 2-1: New USB device found, idVendor=0a5c, idProduct=21e8                                    [152663.793533] usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3                               [152663.793549] usb 2-1: Product: BCM20702A0
[152663.793565] usb 2-1: Manufacturer: Broadcom Corp    [152663.793581] usb 2-1: SerialNumber: 5CF37081D855
[152663.914614] Bluetooth: hci0: BCM: chip id 63        [152663.916557] Bluetooth: hci0: BCM: features 0x07     [152663.933547] Bluetooth: hci0: hassio                 [152663.935538] Bluetooth: hci0: BCM20702A1 (001.002.014) build 0000                                            [152663.935617] bluetooth hci0: Direct firmware load for brcm/BCM20702A1-0a5c-21e8.hcd failed with error -2     [152663.935634] Bluetooth: hci0: BCM: Patch brcm/BCM20702A1-0a5c-21e8.hcd not found
[152665.430069] usb usb2-port1: disabled by hub (EMI?), re-enabling...
[152665.435381] usb 2-1: USB disconnect, device number 5[152665.782533] usb 2-1: new full-speed USB device number 6 using exynos-ohci
[152669.494421] usb 2-1: new full-speed USB device number 7 using exynos-ohci
[152669.729383] usb 2-1: New USB device found, idVendor=0a5c, idProduct=21e8
[152669.729405] usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[152669.729418] usb 2-1: Product: BCM20702A0            [152669.729431] usb 2-1: Manufacturer: Broadcom Corp    [152669.729444] usb 2-1: SerialNumber: 5CF37081D855     [152669.846516] Bluetooth: hci0: BCM: chip id 63
[152669.848452] Bluetooth: hci0: BCM: features 0x07
[152669.866388] Bluetooth: hci0: BCM20702A              [152669.868379] Bluetooth: hci0: BCM20702A1 (001.002.014) build 0000
[152669.868428] bluetooth hci0: Direct firmware load for brcm/BCM20702A1-0a5c-21e8.hcd failed with error -2
[152669.868439] Bluetooth: hci0: BCM: Patch brcm/BCM20702A1-0a5c-21e8.hcd not found
[152671.063984] usb usb2-port1: disabled by hub (EMI?), re-enabling...
[152671.069079] usb 2-1: USB disconnect, device number 7
[152675.122480] usb 2-1: new full-speed USB device number 8 using exynos-ohci
[152675.357478] usb 2-1: New USB device found, idVendor=0a5c, idProduct=21e8
[152675.357500] usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3                               [152675.357514] usb 2-1: Product: BCM20702A0
[152675.357527] usb 2-1: Manufacturer: Broadcom Corp    [152675.357540] usb 2-1: SerialNumber: 5CF37081D855     [152675.474595] Bluetooth: hci0: BCM: chip id 63
[152675.476549] Bluetooth: hci0: BCM: features 0x07     [152675.493467] Bluetooth: hci0: BCM20702A
[152675.495535] Bluetooth: hci0: BCM20702A1 (001.002.014) build 0000
[152675.495673] bluetooth hci0: Direct firmware load for brcm/BCM20702A1-0a5c-21e8.hcd failed with error -2     [152675.495702] Bluetooth: hci0: BCM: Patch brcm/BCM20702A1-0a5c-21e8.hcd not found                             [154025.510408] udevd[6]: starting version 3.2.8
[154025.534759] udevd[7]: starting eudev-3.2.8          [162350.040770] NET: Registered protocol family 38
[164907.714263] udevd[6]: starting version 3.2.8        [164907.735232] udevd[7]: starting eudev-3.2.8          [172025.250963] udevd[6]: starting version 3.2.8
[172025.274289] udevd[7]: starting eudev-3.2.8          [237749.901263] hassio: port 10(vethdd86874) entered disabled state
[237749.901810] vethe7cad98: renamed from eth0

Don't know why but the formatting of the log got screwed up somehow 🤔

Does this help?

@aronsky
Copy link
Contributor

aronsky commented Mar 10, 2020

Can't find anything helpful there. Do you have the output of systemctl status?

@CodeFinder2
Copy link

Do you want the entire output (which is quite a lot: 264 lines)? 🙈

Here's already the output for systemctl status bluetooth:

● bluetooth.service - Bluetooth service
   Loaded: loaded (/lib/systemd/system/bluetooth.service; enabled; vendor preset: enabled)                         Active: active (running) since Sat 2020-03-07 00:27:56 UTC; 3 days ago
     Docs: man:bluetoothd(8)                             Main PID: 349 (bluetoothd)
   Status: "Running"                                       CGroup: /system.slice/bluetooth.service
           └─349 /usr/lib/bluetooth/bluetoothd          
Mar 07 00:27:56 hassio systemd[1]: Starting Bluetooth service...                                                Mar 07 00:27:56 hassio bluetoothd[349]: Bluetooth daemon 5.48
Mar 07 00:27:56 hassio bluetoothd[349]: Starting SDP server
Mar 07 00:27:56 hassio bluetoothd[349]: Bluetooth management interface 1.14 initialized                         Mar 07 00:27:56 hassio systemd[1]: Started Bluetooth service.                                                   Mar 09 00:00:05 hassio bluetoothd[349]: No cache for C4:7C:8D:6B:22:5E                                          Mar 09 00:00:10 hassio bluetoothd[349]: No cache for C4:7C:8D:65:5C:6A
Mar 09 00:00:15 hassio bluetoothd[349]: No cache for C4:7C:8D:65:5C:33

@aronsky
Copy link
Contributor

aronsky commented Mar 10, 2020

Nah, the Bluetooth service itself isn't the one that's interesting to me - are there any other interesting entries there regarding it? For example, in the previously posted output, the service of interest to me was bluetooth-bcm43xx.service - but I suppose you won't have that.

@CodeFinder2
Copy link

CodeFinder2 commented Mar 10, 2020

A bit complicated as I am connected from my mobile phone via Termux and a VPN 😆

I searched for "blue" and just found

├─bluetooth.service
│ └─349 /usr/lib/bluetooth/bluetoothd

Nothing else about "blue" / "bluetooth", especially no bluetooth-bcm43xx.service :-(

EDIT: Anything specific you want me to search for? 🙈

@aronsky
Copy link
Contributor

aronsky commented Mar 10, 2020

Based on a few searches I made, it looks like Bluetooth over USB works differently - not via serial, so baud rate and flow control are probably irrelevant... I'm afraid that might be a different problem, maybe within miflora itself (since as you mentioned earlier, the adapter itself works).

One option you could consider, in case you have a spare ESP8266/ESP32 laying around, is to flash it with ESPHome and let it handle all the BLE connections with miflora, while reporting to Home Assistant over WiFI.

@CodeFinder2
Copy link

CodeFinder2 commented Mar 10, 2020

Thanks for your support anyway! The strange thing is that it used to work for nearly a year without issues (with the same adapter), previously on a RPi2 (with that adapter as well due to the lack of bluetooth). I thought about running a script on the system, periodically resetting the bluetooth adapter (power off -> power on) which seemed to work for me (see my post above).

But yes, using dedicated hardware as bluetooth/plant gateway would be another option althought this would require running another device permanently (which I would like to avoid due to power consumption, already having a lot of devices around and my ODROID is still close enough to my mi flora sensors) 🙈 .

@aronsky
Copy link
Contributor

aronsky commented Mar 10, 2020

If resetting the adapter works for you, it's a good workaround.

@Swiftnesses
Copy link

Same issue here, worked perfect for 1 year +, now broken.

Debian, Docker, HASS (USB Bluetooth).

@Swiftnesses
Copy link

Can we await confirmation of the fix before closing the issue please?

@CodeFinder2
Copy link

I am also very sceptical whether #31156 really solves this issue...

@ferbar
Copy link
Contributor

ferbar commented Mar 22, 2020

IMHO there are two different bugs:

  1. since HA 0.103: bad connection which results in the graph described in the original bug message. This should be solved with Add Miflora go_unavailable_timeout #31156
  2. since HA 0.104: bluetooth crashes and doesn't recover even if HA is stopped (please correct me if it started in 0.103) This will probably not be solved by my patch. I bet this is caused thru:
    a) Update BlueZ 5.52 see: https://github.com/home-assistant/operating-system/releases/tag/3.8
    b) Some changes either in the miflora code or in HA resulting in multiple queries at the same time or too many queries are breaking bluez. related to: Error communicating with local bluetooth adapter (RPi3) #30147

This works for me:
odroid xu4 + usb bt dongle
HA 0.105
dietpi / kernel 4.14.66+ / bluez 5.43-2+deb9u1
1 miflora sensor 2meter away, so good connection. I have a 2nd one with a hardware/firmware bug. it takes one new battery every 4 weeks... I will buy another one.

@Molodax
Copy link

Molodax commented Apr 14, 2020

#31156 did not resolve the issue. I'm running "former HASSIO" on RPI 4.

@Swiftnesses
Copy link

Still broken here too :(

@Dreamoffice
Copy link

i have the same issues :-(

@DanielXYZ2000
Copy link

I also hat the issue yesterday and then did a update to 0.108.5 and supervisor 217
using the terminal bluetoothctl works with scan on works.
So it seemst to be fixed...

@Swiftnesses
Copy link

Yes, the issue isn't with the BLE controller in my case (it's always worked), it's the fact that the MiFlora integration does not appear to work.

@Dreamoffice
Copy link

@DanielXYZ2000
i never used terminal in HA.
when i type i bluetoothctl
just this message comes on:
Bild 2

@DanielXYZ2000
Copy link

@Dreamoffice Which terminal add-on are you using? use the communitiy one:
SSH & Web Terminal
that should contain this command

@Dreamoffice
Copy link

im using this :-(
Bild 3

@Dreamoffice
Copy link

Dreamoffice commented Apr 19, 2020

ok. perfect with the other terminal it is working, but the sensors are still unavailbale.
how looks your mac adress of the sensor.
did you also add the BLE?
like: BLE_XX:XX:XX:XX?

@Dreamoffice
Copy link

Dreamoffice commented Apr 19, 2020

@DanielXYZ2000
- platform: miflora mac: C4:7C:8F:61:2C:2A
like this?

@DanielXYZ2000
Copy link

on the console you should get:
`
~bluetoothctrl

Agent registered
[CHG] Controller ..... XX:XX:... Discovering: yes
[bluetooth]# scan on
Discovery started
[CHG] ....
[NEW] Device C4:X:XX:...XX:AC Flower care`

in my config it looks like

sensor: 
  - platform:   
    mac: 'C4:XX:XX:XX:XX:AC' #nr: 1
    name: Palme
    force_update: true 
    median: 1
    adapter: hci0
    monitored_conditions:
    - moisture
    - light
    - temperature
    - conductivity
    - battery

You don't need BLE_ as prefix

@Dreamoffice
Copy link

@DanielXYZ2000
is this working in your setup
`sensor:

  • platform: `
    nothing after platform?

@Dreamoffice
Copy link

i don t know why but i can receive the values. they are still unavailable.
in the flower care app i see all values.
in the bluetooth scan i see the sensors
but not in Home Assistant

@DanielXYZ2000
Copy link

Ups, yes platform should be miflora
`
sensor:

  • platform: miflora
    mac: 'C4:XX:XX:XX:XX:AC' #nr: 1
    ....
    `
    I also use the plant component -
    I also know that it can take a while till the sensor shows up

# https://home-assistant.io/components/plant/ plant: Palme: sensors: moisture: sensor.palme_moisture battery: sensor.palme_battery temperature: sensor.palme_temperature conductivity: sensor.palme_conductivity brightness: sensor.palme_brightness min_moisture: 20 max_moisture: 55 min_battery: 10 min_conductivity: 100 min_temperature: 11

@FNPeter
Copy link

FNPeter commented Apr 23, 2020

I am running hass.io on an RPi 3 and also encountered my miflora sensors to be unavailable afte 104 a few minutes after hass.io was rebooted. With 0.108.3 I am still having the problem.
@xPhantomNL as far as I understood lowering the baudrate worked for you. I read the entire thread, but could not spot how to lower the baudrate in hass.io. Is there an edit I could make to the configuration.yaml?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging a pull request may close this issue.