Can't connect BS444 bluetooth

Caroga commented 4 years ago

Hi there! I've been trying to connect the medisana scale and I keep getting "timeouts" while testing the Bluetooth connecting. I was hoping you might be able to give more insight into debugging this as I am currently at a loss.

I've installed Bluez by compiling the latest binaries: bluez-5.54 I'm using it on an RPI zero W.

I can find the Bluetooth mac address but connecting to it will eventually timeout and return a Error: connect error: Connection refused (111). You've stated that this probably would be because of not running in LE mode but it is. If I try to connect to it with LE off it will disconnect immediately.

Do you have any pointers or do you know how to debug this? Any help would be greatly appreciated. Bedankt!

keptenkurk commented 4 years ago

Hi @Caroga I will be away from my PI for the next week and a half. Will try to get an answer by then.

Caroga commented 4 years ago

No worries, I'm very glad you are willing to help. Also, I found some older issues "kinda" addressing the same thing so I'll be going through that too.

Caroga commented 4 years ago

Hi there, I will be trying to connect this setup again tomorrow, are you available to help me with some debugging?

keptenkurk commented 4 years ago

I was just looking into it. Are you trying to connect to the scale manually (with gatttool) ? If so: Make sure that the scale is in the state where it is accepting connections (just after weighing and when values are stored, see youtube). I also ran into this page: https://crownstone.rocks/nl/2014/07/23/linux-and-ble where they set the adapter to ignore it's own address by sudo hcitool -i hci1 lecc --random [MAC address]
Or are you running the BS440.py and getting the error in the debug log..?

Caroga commented 4 years ago

Thank you for your time! What video are you referencing? I did make sure that when using gattool I was doing so after weighing. I didn't know if I had to first register the device with the app on my phone so I've done this but haven't gotten the time to check again. I will do so this morning.

The error I get is from using gattool, but when running BS440.py I remember it stating that it was searching, connecting but then failed and reset after a short while. I will post this tomorrow again.

keptenkurk commented 4 years ago

The one in the first part of the blog. But i now realise that you need to step up on the scale to even be able to see it in a scan...

keptenkurk commented 4 years ago

https://youtu.be/2Px-D8Ye_u0

Caroga commented 4 years ago

So I just finally got time to get to this. This is the logs from BS440.

Sat, 26 Sep 2020 19:59:56 INFO     <module> BS440 Started
Sat, 26 Sep 2020 19:59:56 INFO     init_ble_mode hci0 Set Low Energy complete, settings: powered ssp br/edr le secure-conn

Sat, 26 Sep 2020 19:59:57 DEBUG    start gatttool_cmd=gatttool -i hci0 -I
Sat, 26 Sep 2020 19:59:58 INFO     scan Starting BLE scan
Sat, 26 Sep 2020 19:59:58 INFO     run Running...
Sat, 26 Sep 2020 20:00:08 INFO     scan Discovered 00:09:B0:36:62:60 (None)
Sat, 26 Sep 2020 20:00:08 INFO     scan Discovered 5D:DD:DD:FE:E5:A0 (None)
Sat, 26 Sep 2020 20:00:08 INFO     scan Discovered 56:9D:F8:60:64:0C (None)
Sat, 26 Sep 2020 20:00:08 INFO     scan Discovered 5E:42:8C:61:67:8D (None)
Sat, 26 Sep 2020 20:00:08 INFO     scan Discovered 19:DD:6F:F8:1F:AF (None)
Sat, 26 Sep 2020 20:00:08 INFO     scan Discovered 4E:69:63:3B:9C:6C (None)
Sat, 26 Sep 2020 20:00:08 INFO     scan Found 6 BLE devices
Sat, 26 Sep 2020 20:00:08 INFO     scan Starting BLE scan
Sat, 26 Sep 2020 20:00:18 INFO     scan Discovered 00:09:B0:36:62:60 (None)
Sat, 26 Sep 2020 20:00:18 INFO     scan Discovered 56:9D:F8:60:64:0C (None)
Sat, 26 Sep 2020 20:00:18 INFO     scan Discovered 5D:DD:DD:FE:E5:A0 (None)
Sat, 26 Sep 2020 20:00:18 INFO     scan Discovered A4:C1:38:3C:43:0E (0131980E433C38C1A4)
Sat, 26 Sep 2020 20:00:18 INFO     scan Discovered 5E:42:8C:61:67:8D (None)
Sat, 26 Sep 2020 20:00:18 INFO     scan Discovered 4E:69:63:3B:9C:6C (None)
Sat, 26 Sep 2020 20:00:18 INFO     scan Discovered 19:DD:6F:F8:1F:AF (None)
Sat, 26 Sep 2020 20:00:18 INFO     scan Found 7 BLE devices
Sat, 26 Sep 2020 20:00:18 INFO     connect Connecting to A4:C1:38:3C:43:0E with timeout=5
Sat, 26 Sep 2020 20:00:23 ERROR    connect Timed out connecting to A4:C1:38:3C:43:0E after 5 seconds.
Sat, 26 Sep 2020 20:00:23 INFO     connect Connecting to A4:C1:38:3C:43:0E with timeout=5
Sat, 26 Sep 2020 20:00:28 ERROR    connect Timed out connecting to A4:C1:38:3C:43:0E after 5 seconds.
Sat, 26 Sep 2020 20:00:28 INFO     connect Connecting to A4:C1:38:3C:43:0E with timeout=5
Sat, 26 Sep 2020 20:00:33 ERROR    connect Timed out connecting to A4:C1:38:3C:43:0E after 5 seconds.
Sat, 26 Sep 2020 20:00:33 INFO     scan Starting BLE scan
Sat, 26 Sep 2020 20:00:33 ERROR    scan BLE adapter requires reset after a scan as root- call adapter.reset()
Sat, 26 Sep 2020 20:00:40 INFO     scan Starting BLE scan
Sat, 26 Sep 2020 20:00:50 INFO     scan Discovered 5D:DD:DD:FE:E5:A0 (None)
Sat, 26 Sep 2020 20:00:50 INFO     scan Discovered A4:C1:38:3C:43:0E (0131980E433C38C1A4)
Sat, 26 Sep 2020 20:00:50 INFO     scan Discovered 00:09:B0:36:62:60 (None)
Sat, 26 Sep 2020 20:00:50 INFO     scan Discovered 56:9D:F8:60:64:0C (None)
Sat, 26 Sep 2020 20:00:50 INFO     scan Discovered 5E:42:8C:61:67:8D (None)
Sat, 26 Sep 2020 20:00:50 INFO     scan Discovered 4E:69:63:3B:9C:6C (None)
Sat, 26 Sep 2020 20:00:50 INFO     scan Discovered 19:DD:6F:F8:1F:AF (None)
Sat, 26 Sep 2020 20:00:50 INFO     scan Found 7 BLE devices

The above is the MAC address from the device as found by the hcitool lescan

A4:C1:38:3C:43:0E 0131980E433C38C1A4
A4:C1:38:3C:43:0E (unknown)

I keep checking my device and it does show a Bluetooth icon but very short and not as steady as shown on your video. Syncing with my phone does seem to work though.

I copied a segment from the log that shows the inability to connect but in case it would be helpful I could post more.

keptenkurk commented 4 years ago

@Caroga Two questions pop up when reading your log:

What version of BS440.py are you using? The default timeout for connecting devices is set to 8 seconds since the commits following the very informative thread in #56 Your log shows a timeout of 5 seconds which seems to be a bit too short in the experience of BS444 users.
Have you set the scale type to BS444 in the BS440.ini file? This changes the addresstype to "random" (as opposed to "public") and handles the difference in timestamps between scale versions.

Then a general advise is to have the RPI zero very close to the scale (1m max). The scale will be detected over a longer distance but connecting to it requires it to be very close. From #80 : be sure to not use latest pygatt but stick to 3.1.1 if possible (never checked if later ones do work...).

If this still doesn't give any joy we'll need to remove some exception lines in the code temporarily and get some more details of what's happening.

Caroga commented 4 years ago

Hi @keptenkurk , let me respond in order:

I have downloaded BS440-2.0 from github, I've double checked my history which shows wget https://github.com/keptenkurk/BS440/archive/2.0.zip
I did not change any scale types, could you explain to me what configuration this should be and where? Would it be type: BS444 in the scale segment?

Below is a cat of the configuration file:

$ cat BS440.ini

# BS440.ini
# Initialization file for BS440.py
# Change to your preference
# Store this file in the working folder of BS440.py

# Scale properties
[Scale]
ble_address: A4:C1:38:3C:43:0E
device_name: 0131980E433C38C1A4

# Program behaviour
# Loglevel: debug | info | critical | error
[Program]
loglevel: debug
logfile: BS440.log

I checked pygatt and I have version 4.x installed, I will downgrade this after fixing the scale type setting and confirming I have the right version installed of BS440. This way I can check for you if the newest version is working or not.

I think I will download the git repository now and try again.

Caroga commented 4 years ago

After posting I checked: the 2.0 release does not contain the same contents as the current master, the difference is in the configuration file. I will download the repository version now.

Caroga commented 4 years ago

I've downloaded the repository and configured the following .ini file:

r# cat BS440.ini
# BS440.ini
# Initialization file for BS440.py
# Change to your preference
# Store this file in the working folder of BS440.py

# Scale properties
# Model: BS410, BS430, BS440, BS444
[Scale]
ble_address: A4:C1:38:3C:43:0E
device_name: 0131980E433C38C1A4
device_model: BS444

# Program behaviour
# Loglevel: debug | info | critical | error
[Program]
loglevel: debug
logfile: BS440.log
# Enable your plugins here, use the comma separated basename from the plugins/
# Example:
# plugins: BS440csv, BS440mail

I've also downgraded pygatt:

# pip show pygatt
Name: pygatt
Version: 3.1.1
Summary: Python Bluetooth LE (Low Energy) and GATT Library
Home-page: https://github.com/peplin/pygatt
Author: Chris Peplin <github@rhubarbtech.com>
Author-email: github@rhubarbtech.com
License: Apache 2.0 and MIT
Location: /usr/local/lib/python2.7/dist-packages
Requires: pyserial, enum34
Required-by:

I've done a testrun but am unable to connect.

Sun, 27 Sep 2020 11:37:57 INFO     <module> No plugins configured.
Sun, 27 Sep 2020 11:37:57 INFO     <module> BS440 Started
Sun, 27 Sep 2020 11:37:57 INFO     init_ble_mode hci0 Set Low Energy complete, settings: powered ssp br/edr le secure-conn
Sun, 27 Sep 2020 11:37:59 DEBUG    start gatttool_cmd=gatttool -i hci0 -I
Sun, 27 Sep 2020 11:37:59 INFO     scan Starting BLE scan
Sun, 27 Sep 2020 11:37:59 INFO     run Running...
Sun, 27 Sep 2020 11:38:09 INFO     scan Discovered 00:09:B0:36:62:60 (None)
Sun, 27 Sep 2020 11:38:09 INFO     scan Discovered 77:8F:D3:F1:84:8A (None)
Sun, 27 Sep 2020 11:38:09 INFO     scan Discovered 0E:A4:DB:0B:13:0A (None)
Sun, 27 Sep 2020 11:38:09 INFO     scan Discovered 71:B1:B1:36:0E:F5 (None)
Sun, 27 Sep 2020 11:38:09 INFO     scan Discovered 78:BA:6B:F7:45:FD (None)
Sun, 27 Sep 2020 11:38:09 INFO     scan Discovered 43:86:BC:4D:6B:C0 (None)
Sun, 27 Sep 2020 11:38:09 INFO     scan Found 6 BLE devices
Sun, 27 Sep 2020 11:38:09 INFO     scan Starting BLE scan
Sun, 27 Sep 2020 11:38:19 INFO     scan Discovered 0E:A4:DB:0B:13:0A (None)
Sun, 27 Sep 2020 11:38:19 INFO     scan Discovered A4:C1:38:3C:43:0E (0131980E433C38C1A4)
Sun, 27 Sep 2020 11:38:19 INFO     scan Discovered 00:09:B0:36:62:60 (None)
Sun, 27 Sep 2020 11:38:19 INFO     scan Discovered 78:BA:6B:F7:45:FD (None)
Sun, 27 Sep 2020 11:38:19 INFO     scan Discovered 71:B1:B1:36:0E:F5 (None)
Sun, 27 Sep 2020 11:38:19 INFO     scan Discovered 77:8F:D3:F1:84:8A (None)
Sun, 27 Sep 2020 11:38:19 INFO     scan Discovered 43:86:BC:4D:6B:C0 (None)
Sun, 27 Sep 2020 11:38:19 INFO     scan Found 7 BLE devices
Sun, 27 Sep 2020 11:38:19 INFO     connect Connecting to A4:C1:38:3C:43:0E with timeout=8
Sun, 27 Sep 2020 11:38:27 ERROR    connect Timed out connecting to A4:C1:38:3C:43:0E after 8 seconds.
Sun, 27 Sep 2020 11:38:27 INFO     connect Connecting to A4:C1:38:3C:43:0E with timeout=8
Sun, 27 Sep 2020 11:38:35 ERROR    connect Timed out connecting to A4:C1:38:3C:43:0E after 8 seconds.
Sun, 27 Sep 2020 11:38:35 INFO     connect Connecting to A4:C1:38:3C:43:0E with timeout=8
Sun, 27 Sep 2020 11:38:43 ERROR    connect Timed out connecting to A4:C1:38:3C:43:0E after 8 seconds.
Sun, 27 Sep 2020 11:38:43 INFO     scan Starting BLE scan
Sun, 27 Sep 2020 11:38:44 ERROR    scan BLE adapter requires reset after a scan as root- call adapter.reset()
Sun, 27 Sep 2020 11:38:50 INFO     scan Starting BLE scan

What lines should I enable for more debugging? Also: the devices are well within 1m from each other. I have previously synced with my phone, I assume this should not be a problem or should I need to reset the device?

keptenkurk commented 4 years ago

Ok let's see. Connecting is done by pygatt calling "gatttool" with the proper commandline parameters. Gatttool is executed through "pexpect" which fires the command and waits for the response. This response should fit one of the predefined patterns. In case of connecting it will wait for the a response from gatttool which exactly matches the regular expression r'Connection successful.*[LE]>' So far i failed to get the actual response of the gatttool command visible (which will worst case show error 111, or if we're lucky a Connect message which doesn't match the pattern). Hopefully some of the other BS444 users will bump in with some advice...

keptenkurk commented 4 years ago

I've never used the Phone app but think that using that would interfere...

awillems commented 4 years ago

Yes, definitely, If the app is open on the phone, the scale will connect to the phone faster then the rpi. And the rpi will be unable to connect. I cannot actually speak to much to the BS440 though I am using "Etekcity Digital Body" https://www.amazon.com/gp/product/B07D7R25JV/ref=ppx_yo_dt_b_search_asin_title?ie=UTF8&psc=1 had to modify a decent amount. But when I was testing with gatttool I had some issues. This might only apply to my scale but here are some thing to try maybe.

close app on phone make sure its not connecting to your phones BL maybe turn BL off on your phone for testing
try rebooting your pi
a lot of people have suggested using "-t random" flag if having connecting issues, when connecting with "sudo gatttool -t random -b xx:xx:xx:xx:xx:xx -I" I did this at the start and was never able to connect but the minute I removed the "-t random" flag it connected that might be an issue not sure.

Caroga commented 4 years ago

Thank you @awillems, by removing the -t random from the gattool command I was able to connect to the device by using gatttool -b A4:C1:38:3C:43:0E -I and typing in connect.

# gatttool -b A4:C1:38:3C:43:0E -I 
[A4:C1:38:3C:43:0E][LE]> connect
Attempting to connect to A4:C1:38:3C:43:0E
Connection successful
[A4:C1:38:3C:43:0E][LE]>

That's already a good step forward!

Did you have to make any other additions to the script for it to connect by BS440.py?

keptenkurk commented 4 years ago

@awillems Thanks for bumping in! To change connecting to public you could change line 242 of BS440.py: addresstype = pygatt.BLEAddressType.random into addresstype = pygatt.BLEAddressType.public (if the -t option is not set gatttool will take public as the default addresstype)

Caroga commented 4 years ago

Thanks to this addition and some extensive testing I got the setup to work. I even got the MQTT plugin working. The log file does state some messages like Unreliable data received. Unable to process during the process. I don't know what to make from this but the software does work eventually.

Thu, 01 Oct 2020 23:12:24 INFO     scan Starting BLE scan
Thu, 01 Oct 2020 23:12:34 INFO     scan Discovered 64:8A:9D:18:B5:72 (None)
Thu, 01 Oct 2020 23:12:34 INFO     scan Discovered 65:A5:A5:DF:DB:76 (None)
Thu, 01 Oct 2020 23:12:34 INFO     scan Discovered 61:9F:04:88:CC:68 (None)
Thu, 01 Oct 2020 23:12:34 INFO     scan Discovered 00:09:B0:36:62:60 (None)
Thu, 01 Oct 2020 23:12:34 INFO     scan Discovered 36:D5:40:70:BF:DC (None)
Thu, 01 Oct 2020 23:12:34 INFO     scan Discovered 43:25:D9:A5:26:F7 (None)
Thu, 01 Oct 2020 23:12:34 INFO     scan Discovered A4:C1:38:3C:43:0E (0131980E433C38C1A4)
Thu, 01 Oct 2020 23:12:34 INFO     scan Found 7 BLE devices
Thu, 01 Oct 2020 23:12:35 INFO     connect Connecting to A4:C1:38:3C:43:0E with timeout=8
Thu, 01 Oct 2020 23:12:35 DEBUG    get_handle Looking up handle for characteristic 00008a22-0000-1000-8000-00805f9b34fb
Thu, 01 Oct 2020 23:12:36 DEBUG    _save_charecteristic_callback Found characteristic 00002a00-0000-1000-8000-00805f9b34fb, value handle: 0x3
Thu, 01 Oct 2020 23:12:36 DEBUG    _save_charecteristic_callback Found characteristic 00002a01-0000-1000-8000-00805f9b34fb, value handle: 0x5
Thu, 01 Oct 2020 23:12:36 DEBUG    _save_charecteristic_callback Found characteristic 00002a04-0000-1000-8000-00805f9b34fb, value handle: 0x7
Thu, 01 Oct 2020 23:12:36 DEBUG    _save_charecteristic_callback Found characteristic 00002a25-0000-1000-8000-00805f9b34fb, value handle: 0xb
Thu, 01 Oct 2020 23:12:36 DEBUG    _save_charecteristic_callback Found characteristic 00002a27-0000-1000-8000-00805f9b34fb, value handle: 0xd
Thu, 01 Oct 2020 23:12:36 DEBUG    _save_charecteristic_callback Found characteristic 00002a26-0000-1000-8000-00805f9b34fb, value handle: 0xf
Thu, 01 Oct 2020 23:12:36 DEBUG    _save_charecteristic_callback Found characteristic 00002a29-0000-1000-8000-00805f9b34fb, value handle: 0x11
Thu, 01 Oct 2020 23:12:36 DEBUG    _save_charecteristic_callback Found characteristic 00002a28-0000-1000-8000-00805f9b34fb, value handle: 0x13
Thu, 01 Oct 2020 23:12:36 DEBUG    _save_charecteristic_callback Found characteristic 00008a82-0000-1000-8000-00805f9b34fb, value handle: 0x16
Thu, 01 Oct 2020 23:12:36 DEBUG    _save_charecteristic_callback Found characteristic 00008a21-0000-1000-8000-00805f9b34fb, value handle: 0x19
Thu, 01 Oct 2020 23:12:36 DEBUG    _save_charecteristic_callback Found characteristic 00008a22-0000-1000-8000-00805f9b34fb, value handle: 0x1c
Thu, 01 Oct 2020 23:12:36 DEBUG    _save_charecteristic_callback Found characteristic 00008a20-0000-1000-8000-00805f9b34fb, value handle: 0x1f
Thu, 01 Oct 2020 23:12:36 DEBUG    _save_charecteristic_callback Found characteristic 00008a81-0000-1000-8000-00805f9b34fb, value handle: 0x21
Thu, 01 Oct 2020 23:12:37 DEBUG    get_handle Found <Characteristic uuid=00008a22-0000-1000-8000-00805f9b34fb handle=28>
Thu, 01 Oct 2020 23:12:37 DEBUG    get_handle Looking up handle for characteristic 00008a82-0000-1000-8000-00805f9b34fb
Thu, 01 Oct 2020 23:12:37 DEBUG    get_handle Found <Characteristic uuid=00008a82-0000-1000-8000-00805f9b34fb handle=22>
Thu, 01 Oct 2020 23:12:37 DEBUG    get_handle Looking up handle for characteristic 00008a21-0000-1000-8000-00805f9b34fb
Thu, 01 Oct 2020 23:12:37 DEBUG    get_handle Found <Characteristic uuid=00008a21-0000-1000-8000-00805f9b34fb handle=25>
Thu, 01 Oct 2020 23:12:37 DEBUG    get_handle Looking up handle for characteristic 00008a81-0000-1000-8000-00805f9b34fb
Thu, 01 Oct 2020 23:12:37 DEBUG    get_handle Found <Characteristic uuid=00008a81-0000-1000-8000-00805f9b34fb handle=33>
Thu, 01 Oct 2020 23:12:37 DEBUG    get_handle Looking up handle for characteristic 00008a21-0000-1000-8000-00805f9b34fb
Thu, 01 Oct 2020 23:12:37 DEBUG    get_handle Found <Characteristic uuid=00008a21-0000-1000-8000-00805f9b34fb handle=25>
Thu, 01 Oct 2020 23:12:37 DEBUG    char_write_handle Sending cmd=char-write-cmd 0x1a 0200
Thu, 01 Oct 2020 23:12:37 INFO     char_write_handle Sent cmd=char-write-cmd 0x1a 0200
Thu, 01 Oct 2020 23:12:37 INFO     subscribe Subscribed to uuid=00008a21-0000-1000-8000-00805f9b34fb
Thu, 01 Oct 2020 23:12:37 DEBUG    get_handle Looking up handle for characteristic 00008a22-0000-1000-8000-00805f9b34fb
Thu, 01 Oct 2020 23:12:37 DEBUG    get_handle Found <Characteristic uuid=00008a22-0000-1000-8000-00805f9b34fb handle=28>
Thu, 01 Oct 2020 23:12:37 DEBUG    char_write_handle Sending cmd=char-write-cmd 0x1d 0200
Thu, 01 Oct 2020 23:12:37 INFO     char_write_handle Sent cmd=char-write-cmd 0x1d 0200
Thu, 01 Oct 2020 23:12:37 INFO     subscribe Subscribed to uuid=00008a22-0000-1000-8000-00805f9b34fb
Thu, 01 Oct 2020 23:12:37 DEBUG    get_handle Looking up handle for characteristic 00008a82-0000-1000-8000-00805f9b34fb
Thu, 01 Oct 2020 23:12:37 DEBUG    get_handle Found <Characteristic uuid=00008a82-0000-1000-8000-00805f9b34fb handle=22>
Thu, 01 Oct 2020 23:12:37 DEBUG    char_write_handle Sending cmd=char-write-cmd 0x17 0200
Thu, 01 Oct 2020 23:12:37 INFO     char_write_handle Sent cmd=char-write-cmd 0x17 0200
Thu, 01 Oct 2020 23:12:37 INFO     subscribe Subscribed to uuid=00008a82-0000-1000-8000-00805f9b34fb
Thu, 01 Oct 2020 23:12:37 DEBUG    char_write_handle Sending cmd=char-write-req 0x21 0255193914
Thu, 01 Oct 2020 23:12:37 INFO     char_write_handle Sent cmd=char-write-req 0x21 0255193914
Thu, 01 Oct 2020 23:12:37 INFO     <module> Waiting for notifications for another 30 seconds
Thu, 01 Oct 2020 23:12:37 INFO     receive_notification Received notification on handle=0x16, value=0x8453ff80010000e0000000000000000000000000
Thu, 01 Oct 2020 23:12:37 INFO     processIndication {'gender': 'male', 'age': 0, 'person': 255, 'valid': True, 'activity': 'normal', 'size': 0}
Thu, 01 Oct 2020 23:13:07 INFO     <module> Could not disconnect...
Thu, 01 Oct 2020 23:13:07 INFO     <module> Done receiving data from scale
Thu, 01 Oct 2020 23:13:07 ERROR    <module> Unreliable data received. Unable to process
Thu, 01 Oct 2020 23:13:07 INFO     scan Starting BLE scan
Thu, 01 Oct 2020 23:13:17 INFO     scan Discovered 36:D5:40:70:BF:DC (None)
Thu, 01 Oct 2020 23:13:17 INFO     scan Discovered 61:9F:04:88:CC:68 (None)
Thu, 01 Oct 2020 23:13:17 INFO     scan Discovered A4:C1:38:3C:43:0E (0131980E433C38C1A4)
Thu, 01 Oct 2020 23:13:17 INFO     scan Discovered 00:09:B0:36:62:60 (None)
Thu, 01 Oct 2020 23:13:17 INFO     scan Discovered 43:25:D9:A5:26:F7 (None)
Thu, 01 Oct 2020 23:13:17 INFO     scan Discovered 65:A5:A5:DF:DB:76 (None)
Thu, 01 Oct 2020 23:13:17 INFO     scan Discovered 64:8A:9D:18:B5:72 (None)
Thu, 01 Oct 2020 23:13:17 INFO     scan Discovered 66:68:0F:4E:06:A6 (None)
Thu, 01 Oct 2020 23:13:17 INFO     scan Found 8 BLE devices
Thu, 01 Oct 2020 23:13:18 INFO     connect Connecting to A4:C1:38:3C:43:0E with timeout=8
Thu, 01 Oct 2020 23:13:18 DEBUG    get_handle Looking up handle for characteristic 00008a22-0000-1000-8000-00805f9b34fb
Thu, 01 Oct 2020 23:13:19 DEBUG    _save_charecteristic_callback Found characteristic 00002a00-0000-1000-8000-00805f9b34fb, value handle: 0x3
Thu, 01 Oct 2020 23:13:19 DEBUG    _save_charecteristic_callback Found characteristic 00002a01-0000-1000-8000-00805f9b34fb, value handle: 0x5
Thu, 01 Oct 2020 23:13:19 DEBUG    _save_charecteristic_callback Found characteristic 00002a04-0000-1000-8000-00805f9b34fb, value handle: 0x7
Thu, 01 Oct 2020 23:13:19 DEBUG    _save_charecteristic_callback Found characteristic 00002a25-0000-1000-8000-00805f9b34fb, value handle: 0xb
Thu, 01 Oct 2020 23:13:19 DEBUG    _save_charecteristic_callback Found characteristic 00002a27-0000-1000-8000-00805f9b34fb, value handle: 0xd
Thu, 01 Oct 2020 23:13:19 DEBUG    _save_charecteristic_callback Found characteristic 00002a26-0000-1000-8000-00805f9b34fb, value handle: 0xf
Thu, 01 Oct 2020 23:13:19 DEBUG    _save_charecteristic_callback Found characteristic 00002a29-0000-1000-8000-00805f9b34fb, value handle: 0x11
Thu, 01 Oct 2020 23:13:19 DEBUG    _save_charecteristic_callback Found characteristic 00002a28-0000-1000-8000-00805f9b34fb, value handle: 0x13
Thu, 01 Oct 2020 23:13:19 DEBUG    _save_charecteristic_callback Found characteristic 00008a82-0000-1000-8000-00805f9b34fb, value handle: 0x16
Thu, 01 Oct 2020 23:13:19 DEBUG    _save_charecteristic_callback Found characteristic 00008a21-0000-1000-8000-00805f9b34fb, value handle: 0x19
Thu, 01 Oct 2020 23:13:19 DEBUG    _save_charecteristic_callback Found characteristic 00008a22-0000-1000-8000-00805f9b34fb, value handle: 0x1c
Thu, 01 Oct 2020 23:13:19 DEBUG    _save_charecteristic_callback Found characteristic 00008a20-0000-1000-8000-00805f9b34fb, value handle: 0x1f
Thu, 01 Oct 2020 23:13:19 DEBUG    _save_charecteristic_callback Found characteristic 00008a81-0000-1000-8000-00805f9b34fb, value handle: 0x21
Thu, 01 Oct 2020 23:13:20 DEBUG    get_handle Found <Characteristic uuid=00008a22-0000-1000-8000-00805f9b34fb handle=28>
Thu, 01 Oct 2020 23:13:20 DEBUG    get_handle Looking up handle for characteristic 00008a82-0000-1000-8000-00805f9b34fb
Thu, 01 Oct 2020 23:13:20 DEBUG    get_handle Found <Characteristic uuid=00008a82-0000-1000-8000-00805f9b34fb handle=22>
Thu, 01 Oct 2020 23:13:20 DEBUG    get_handle Looking up handle for characteristic 00008a21-0000-1000-8000-00805f9b34fb
Thu, 01 Oct 2020 23:13:20 DEBUG    get_handle Found <Characteristic uuid=00008a21-0000-1000-8000-00805f9b34fb handle=25>
Thu, 01 Oct 2020 23:13:20 DEBUG    get_handle Looking up handle for characteristic 00008a81-0000-1000-8000-00805f9b34fb
Thu, 01 Oct 2020 23:13:20 DEBUG    get_handle Found <Characteristic uuid=00008a81-0000-1000-8000-00805f9b34fb handle=33>
Thu, 01 Oct 2020 23:13:20 DEBUG    get_handle Looking up handle for characteristic 00008a21-0000-1000-8000-00805f9b34fb
Thu, 01 Oct 2020 23:13:20 DEBUG    get_handle Found <Characteristic uuid=00008a21-0000-1000-8000-00805f9b34fb handle=25>
Thu, 01 Oct 2020 23:13:20 DEBUG    char_write_handle Sending cmd=char-write-cmd 0x1a 0200
Thu, 01 Oct 2020 23:13:20 INFO     char_write_handle Sent cmd=char-write-cmd 0x1a 0200
Thu, 01 Oct 2020 23:13:20 INFO     subscribe Subscribed to uuid=00008a21-0000-1000-8000-00805f9b34fb
Thu, 01 Oct 2020 23:13:20 DEBUG    get_handle Looking up handle for characteristic 00008a22-0000-1000-8000-00805f9b34fb
Thu, 01 Oct 2020 23:13:20 DEBUG    get_handle Found <Characteristic uuid=00008a22-0000-1000-8000-00805f9b34fb handle=28>
Thu, 01 Oct 2020 23:13:20 DEBUG    char_write_handle Sending cmd=char-write-cmd 0x1d 0200
Thu, 01 Oct 2020 23:13:20 INFO     char_write_handle Sent cmd=char-write-cmd 0x1d 0200
Thu, 01 Oct 2020 23:13:20 INFO     subscribe Subscribed to uuid=00008a22-0000-1000-8000-00805f9b34fb
Thu, 01 Oct 2020 23:13:20 DEBUG    get_handle Looking up handle for characteristic 00008a82-0000-1000-8000-00805f9b34fb
Thu, 01 Oct 2020 23:13:20 DEBUG    get_handle Found <Characteristic uuid=00008a82-0000-1000-8000-00805f9b34fb handle=22>
Thu, 01 Oct 2020 23:13:20 DEBUG    char_write_handle Sending cmd=char-write-cmd 0x17 0200
Thu, 01 Oct 2020 23:13:20 INFO     char_write_handle Sent cmd=char-write-cmd 0x17 0200
Thu, 01 Oct 2020 23:13:20 INFO     subscribe Subscribed to uuid=00008a82-0000-1000-8000-00805f9b34fb
Thu, 01 Oct 2020 23:13:20 DEBUG    char_write_handle Sending cmd=char-write-req 0x21 0280193914
Thu, 01 Oct 2020 23:13:20 INFO     receive_notification Received notification on handle=0x16, value=0x84530280011fa1e0000000000000000000000000
Thu, 01 Oct 2020 23:13:20 INFO     char_write_handle Sent cmd=char-write-req 0x21 0280193914
Thu, 01 Oct 2020 23:13:20 INFO     processIndication {'gender': 'male', 'age': 31, 'person': 2, 'valid': True, 'activity': 'normal', 'size': 161}
Thu, 01 Oct 2020 23:13:20 INFO     <module> Waiting for notifications for another 30 seconds
Thu, 01 Oct 2020 23:13:20 INFO     receive_notification Received notification on handle=0x19, value=0x1d362400fe15bc12144d1900ff020900000000
Thu, 01 Oct 2020 23:13:20 INFO     processIndication {'timestamp': 1599076117, 'valid': True, 'weight': 92.7, 'person': 2}
Thu, 01 Oct 2020 23:13:20 INFO     receive_notification Received notification on handle=0x1c, value=0x6f15bc121402900762f1ddf152f120f0000000
Thu, 01 Oct 2020 23:13:20 INFO     processIndication {'timestamp': 1599076117, 'tbw': 47.7, 'person': 2, 'valid': True, 'fat': 35.4, 'muscle': 33.8, 'kcal': 1936, 'bone': 3.2}
Thu, 01 Oct 2020 23:13:20 INFO     receive_notification Received notification on handle=0x19, value=0x1d362400fe68bc12145a1900ff020900000000
Thu, 01 Oct 2020 23:13:20 INFO     processIndication {'timestamp': 1599076200, 'valid': True, 'weight': 92.7, 'person': 2}
Thu, 01 Oct 2020 23:13:20 INFO     receive_notification Received notification on handle=0x1c, value=0x6f68bc121402900762f1ddf152f120f0000000
Thu, 01 Oct 2020 23:13:20 INFO     processIndication {'timestamp': 1599076200, 'tbw': 47.7, 'person': 2, 'valid': True, 'fat': 35.4, 'muscle': 33.8, 'kcal': 1936, 'bone': 3.2}
Thu, 01 Oct 2020 23:13:20 INFO     receive_notification Received notification on handle=0x19, value=0x1dc82300fec0533214f91700ff020900000000
Thu, 01 Oct 2020 23:13:20 INFO     processIndication {'timestamp': 1601146560, 'valid': True, 'weight': 91.6, 'person': 2}
Thu, 01 Oct 2020 23:13:20 INFO     receive_notification Received notification on handle=0x1c, value=0x6fc05332140281075af1e3f156f121f0000000
Thu, 01 Oct 2020 23:13:20 INFO     processIndication {'timestamp': 1601146560, 'tbw': 48.3, 'person': 2, 'valid': True, 'fat': 34.6, 'muscle': 34.2, 'kcal': 1921, 'bone': 3.3}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x19, value=0x1dc82300fe94543214a71700ff020900000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601146772, 'valid': True, 'weight': 91.6, 'person': 2}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x1c, value=0x6f945432140281075af1e3f156f121f0000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601146772, 'tbw': 48.3, 'person': 2, 'valid': True, 'fat': 34.6, 'muscle': 34.2, 'kcal': 1921, 'bone': 3.3}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x19, value=0x1dc82300fe2c553214de1600ff020900000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601146924, 'valid': True, 'weight': 91.6, 'person': 2}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x1c, value=0x6f2c55321402810759f1e3f157f121f0000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601146924, 'tbw': 48.3, 'person': 2, 'valid': True, 'fat': 34.5, 'muscle': 34.3, 'kcal': 1921, 'bone': 3.3}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x19, value=0x1dc82300fe665532140b1700ff020900000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601146982, 'valid': True, 'weight': 91.6, 'person': 2}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x1c, value=0x6f6655321402810759f1e3f157f121f0000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601146982, 'tbw': 48.3, 'person': 2, 'valid': True, 'fat': 34.5, 'muscle': 34.3, 'kcal': 1921, 'bone': 3.3}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x19, value=0x1dd22300fe265632149e1700ff020900000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601147174, 'valid': True, 'weight': 91.7, 'person': 2}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x1c, value=0x6f265632140282075af1e3f156f121f0000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601147174, 'tbw': 48.3, 'person': 2, 'valid': True, 'fat': 34.6, 'muscle': 34.2, 'kcal': 1922, 'bone': 3.3}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x19, value=0x1dd22300fe7c5832142e1900ff020900000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601147772, 'valid': True, 'weight': 91.7, 'person': 2}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x1c, value=0x6f7c5832140282075cf1e2f155f121f0000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601147772, 'tbw': 48.2, 'person': 2, 'valid': True, 'fat': 34.8, 'muscle': 34.1, 'kcal': 1922, 'bone': 3.3}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x19, value=0x1de62300fe325d32141d1700ff020900000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601148978, 'valid': True, 'weight': 91.9, 'person': 2}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x1c, value=0x6f325d32140285075bf1e2f156f121f0000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601148978, 'tbw': 48.2, 'person': 2, 'valid': True, 'fat': 34.7, 'muscle': 34.2, 'kcal': 1925, 'bone': 3.3}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x19, value=0x1dd22300fef85d3214c51800ff020900000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601149176, 'valid': True, 'weight': 91.7, 'person': 2}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x1c, value=0x6ff85d32140282075cf1e2f156f121f0000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601149176, 'tbw': 48.2, 'person': 2, 'valid': True, 'fat': 34.8, 'muscle': 34.2, 'kcal': 1922, 'bone': 3.3}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x19, value=0x1d6e2300fea82d33143c1900ff020900000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601202344, 'valid': True, 'weight': 90.7, 'person': 2}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x1c, value=0x6fa82d331402750756f1e6f159f121f0000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601202344, 'tbw': 48.6, 'person': 2, 'valid': True, 'fat': 34.2, 'muscle': 34.5, 'kcal': 1909, 'bone': 3.3}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x19, value=0x1d0e2400fe852e3314691a00ff020900000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601202565, 'valid': True, 'weight': 92.3, 'person': 2}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x1c, value=0x6f852e3314028b0761f1def153f120f0000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601202565, 'tbw': 47.8, 'person': 2, 'valid': True, 'fat': 35.3, 'muscle': 33.9, 'kcal': 1931, 'bone': 3.2}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x19, value=0x1d782300fe662f33142a1900ff020900000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601202790, 'valid': True, 'weight': 90.8, 'person': 2}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x1c, value=0x6f662f331402760757f1e6f158f121f0000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601202790, 'tbw': 48.6, 'person': 2, 'valid': True, 'fat': 34.3, 'muscle': 34.4, 'kcal': 1910, 'bone': 3.3}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x19, value=0x1d782300feb9303314b11a00ff020900000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601203129, 'valid': True, 'weight': 90.8, 'person': 2}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x1c, value=0x6fb930331402760759f1e5f158f121f0000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601203129, 'tbw': 48.5, 'person': 2, 'valid': True, 'fat': 34.5, 'muscle': 34.4, 'kcal': 1910, 'bone': 3.3}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x19, value=0x1d282300fef0283714f81900ff020900000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601463280, 'valid': True, 'weight': 90.0, 'person': 2}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x1c, value=0x6ff0283714026b0753f1e9f15af120f0000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601463280, 'tbw': 48.9, 'person': 2, 'valid': True, 'fat': 33.9, 'muscle': 34.6, 'kcal': 1899, 'bone': 3.2}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x19, value=0x1d1e2300fe544b3714941800ff020900000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601472084, 'valid': True, 'weight': 89.9, 'person': 2}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x1c, value=0x6f544b3714026a0751f1eaf15bf120f0000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601472084, 'tbw': 49.0, 'person': 2, 'valid': True, 'fat': 33.7, 'muscle': 34.7, 'kcal': 1898, 'bone': 3.2}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x19, value=0x1de22200fee04b3714491700ff020900000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601472224, 'valid': True, 'weight': 89.3, 'person': 2}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x1c, value=0x6fe04b37140261074cf1eef15ef120f0000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601472224, 'tbw': 49.4, 'person': 2, 'valid': True, 'fat': 33.2, 'muscle': 35.0, 'kcal': 1889, 'bone': 3.2}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x19, value=0x1dc42200fe30bf3814181900ff020900000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601567280, 'valid': True, 'weight': 89.0, 'person': 2}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x1c, value=0x6f30bf3814025d074cf1eef15ef120f0000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601567280, 'tbw': 49.4, 'person': 2, 'valid': True, 'fat': 33.2, 'muscle': 35.0, 'kcal': 1885, 'bone': 3.2}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x19, value=0x1d3c2300fe05053914351900ff020900000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601585157, 'valid': True, 'weight': 90.2, 'person': 2}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x1c, value=0x6f05053914026e0753f1e8f15af120f0000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601585157, 'tbw': 48.8, 'person': 2, 'valid': True, 'fat': 33.9, 'muscle': 34.6, 'kcal': 1902, 'bone': 3.2}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x19, value=0x1d3c2300fe52053914c81900ff020900000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601585234, 'valid': True, 'weight': 90.2, 'person': 2}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x1c, value=0x6f52053914026e0754f1e8f15af120f0000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601585234, 'tbw': 48.8, 'person': 2, 'valid': True, 'fat': 34.0, 'muscle': 34.6, 'kcal': 1902, 'bone': 3.2}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x19, value=0x1d3c2300fea6053914cd1900ff020900000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601585318, 'valid': True, 'weight': 90.2, 'person': 2}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x1c, value=0x6fa6053914026e0754f1e8f15af120f0000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601585318, 'tbw': 48.8, 'person': 2, 'valid': True, 'fat': 34.0, 'muscle': 34.6, 'kcal': 1902, 'bone': 3.2}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x19, value=0x1d3c2300fe03063914f61800ff020900000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601585411, 'valid': True, 'weight': 90.2, 'person': 2}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x1c, value=0x6f03063914026e0753f1e8f15af120f0000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601585411, 'tbw': 48.8, 'person': 2, 'valid': True, 'fat': 33.9, 'muscle': 34.6, 'kcal': 1902, 'bone': 3.2}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x19, value=0x1d3c2300fe58063914611800ff020900000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601585496, 'valid': True, 'weight': 90.2, 'person': 2}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x1c, value=0x6f58063914026e0752f1e9f15af120f0000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601585496, 'tbw': 48.9, 'person': 2, 'valid': True, 'fat': 33.8, 'muscle': 34.6, 'kcal': 1902, 'bone': 3.2}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x19, value=0x1d3c2300fecc063914761800ff020900000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601585612, 'valid': True, 'weight': 90.2, 'person': 2}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x1c, value=0x6fcc063914026e0752f1e9f15af120f0000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601585612, 'tbw': 48.9, 'person': 2, 'valid': True, 'fat': 33.8, 'muscle': 34.6, 'kcal': 1902, 'bone': 3.2}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x19, value=0x1d3c2300fe3b073914fc1900ff020900000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601585723, 'valid': True, 'weight': 90.2, 'person': 2}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x1c, value=0x6f3b073914026e0754f1e8f15af120f0000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601585723, 'tbw': 48.8, 'person': 2, 'valid': True, 'fat': 34.0, 'muscle': 34.6, 'kcal': 1902, 'bone': 3.2}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x19, value=0x1d282300fe370a39148c1900ff020900000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601586487, 'valid': True, 'weight': 90.0, 'person': 2}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x1c, value=0x6f370a3914026b0753f1e9f15bf120f0000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601586487, 'tbw': 48.9, 'person': 2, 'valid': True, 'fat': 33.9, 'muscle': 34.7, 'kcal': 1899, 'bone': 3.2}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x19, value=0x1d3c2300fef80a3914501800ff020900000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601586680, 'valid': True, 'weight': 90.2, 'person': 2}
Thu, 01 Oct 2020 23:13:21 INFO     receive_notification Received notification on handle=0x1c, value=0x6ff80a3914026e0752f1e9f15bf120f0000000
Thu, 01 Oct 2020 23:13:21 INFO     processIndication {'timestamp': 1601586680, 'tbw': 48.9, 'person': 2, 'valid': True, 'fat': 33.8, 'muscle': 34.7, 'kcal': 1902, 'bone': 3.2}
Thu, 01 Oct 2020 23:13:22 INFO     receive_notification Received notification on handle=0x19, value=0x1d3c2300fe5a0d39147c1800ff020900000000
Thu, 01 Oct 2020 23:13:22 INFO     processIndication {'timestamp': 1601587290, 'valid': True, 'weight': 90.2, 'person': 2}
Thu, 01 Oct 2020 23:13:22 INFO     receive_notification Received notification on handle=0x1c, value=0x6f5a0d3914026e0752f1e9f15af120f0000000
Thu, 01 Oct 2020 23:13:22 INFO     processIndication {'timestamp': 1601587290, 'tbw': 48.9, 'person': 2, 'valid': True, 'fat': 33.8, 'muscle': 34.6, 'kcal': 1902, 'bone': 3.2}
Thu, 01 Oct 2020 23:13:22 INFO     receive_notification Received notification on handle=0x19, value=0x1d3c2300fed00d3914550b00ff020900000000
Thu, 01 Oct 2020 23:13:22 INFO     processIndication {'timestamp': 1601587408, 'valid': True, 'weight': 90.2, 'person': 2}
Thu, 01 Oct 2020 23:13:22 INFO     receive_notification Received notification on handle=0x1c, value=0x6fd00d3914026e0748f1eef15ef120f0000000
Thu, 01 Oct 2020 23:13:22 INFO     processIndication {'timestamp': 1601587408, 'tbw': 49.4, 'person': 2, 'valid': True, 'fat': 32.8, 'muscle': 35.0, 'kcal': 1902, 'bone': 3.2}
Thu, 01 Oct 2020 23:13:22 INFO     receive_notification Received notification on handle=0x19, value=0x1df62200fe5c193914b71600ff020900000000
Thu, 01 Oct 2020 23:13:22 INFO     processIndication {'timestamp': 1601590364, 'valid': True, 'weight': 89.5, 'person': 2}
Thu, 01 Oct 2020 23:13:22 INFO     receive_notification Received notification on handle=0x1c, value=0x6f5c1939140264074cf1edf15df120f0000000
Thu, 01 Oct 2020 23:13:22 INFO     processIndication {'timestamp': 1601590364, 'tbw': 49.3, 'person': 2, 'valid': True, 'fat': 33.2, 'muscle': 34.9, 'kcal': 1892, 'bone': 3.2}
Thu, 01 Oct 2020 23:13:50 INFO     <module> Could not disconnect...
Thu, 01 Oct 2020 23:13:50 INFO     <module> Done receiving data from scale

keptenkurk commented 4 years ago

Real glad to see your progress! The line Thu, 01 Oct 2020 23:12:37 INFO char_write_handle Sent cmd=char-write-req 0x21 0255193914 sends the "magic" code to the scale to instruct it to send it's 30 measurement memory (each consisting of 2 data strings). Since there is no "i'm done" signal, the program waits for 30 seconds listening for any data. For some obscure reason this command is not always understood and not all data is received. Hence an "unreliable data received" message. But the good thing is: your weight was stored in the 30 measurement buffer associated with your "person#", so on the next go you will get it. This requires the receiving end to discard duplicates received. The magic code is 02 (hex) followed by the time (in seconds since 01/01/2010 presented in Hex, most significant last) like in the above log: 0255193914 --> hex 14391951 = 339286353 sec = Thursday, 01-Oct-20 22:12:33 UTC. This time is also used to sync the scale's realtime clock. Maybe the command is ignored when the deviation is too big? Who will tell. Talking about duplicates: The scale will sometimes send weighings twice which are filtered (shown in the log as duplicates). Cool to see the MQTT plugin in action! (never used it myself)

Caroga commented 4 years ago

Yeah I figured that would be the case. I am very glad that this is working, I am wondering about other BS444 users if they would have experienced this problem as well or that mine is a updated/outdated version of the hardware? Who knows.. If you like I could add an addition to the script and a wiki entry to cover this? Also it's very cool to use MQTT, however I feel like I would also send to Influx for the sake of history. Looking into this now as I use authenticated connections and the plugin doesn't account for username/password. I'll look into this.

What plugin do you use? Also, I'll close this issue as it has been resolved.

keptenkurk / BS440

Can't connect BS444 bluetooth #91