Olen / solar-monitor

GNU General Public License v3.0
54 stars 21 forks source link

Renogy BT-1 Disconnects after polling once. #33

Open glynastill opened 12 months ago

glynastill commented 12 months ago

I've recently upgraded my home-assistant server on a raspberry pi3 from bullseye to bookworm, and with it I upgraded solar-monitor to the current head of master as I was getting a bunch of python errors. (Old version was at 928a8ccad9c1212ef580e3a53335de70b3fa4543 / Tue Aug 16)

Whilst previously I always saw the following error solar-monitor continued polling happily:

WARNING: [regulator] Write to characteristic failed for: [0000ffd1-0000-1000-8000-00805f9b34fb] with error [In Progress]

Now I'm seeing similar messages, however solar-monitor disconnects after a single poll of all the metrics. I now see this:

INFO: Adapter status - Powered: True
INFO: Starting discovery...
INFO: Found 1 BLE-devices
INFO: Trying to connect to ac:4d:16:1a:a5:ee...
INFO: Successfully imported SolarLink.
INFO: [regulator] Connecting to ac:4d:16:1a:a5:ee
INFO: Terminate with Ctrl+C
INFO: [ac:4d:16:1a:a5:ee] Discovered, alias = BT-TH-161AA5EE
INFO: [regulator] Connected to BT-TH-161AA5EE
INFO: [ac:4d:16:1a:a5:ee] Discovered, alias = BT-TH-161AA5EE
INFO: [ac:4d:16:1a:a5:ee] Discovered, alias = BT-TH-161AA5EE
INFO: [regulator] Connected to BT-TH-161AA5EE
INFO: [regulator] Resolved services
INFO: [regulator]  Service [f000ffd0-0451-4000-b000-000000000000]
INFO: [regulator]    Characteristic [f000ffd1-0451-4000-b000-000000000000]
INFO: [regulator]  Service [0000fff0-0000-1000-8000-00805f9b34fb]
INFO: [regulator]  - Found dev notify service [0000fff0-0000-1000-8000-00805f9b34fb]
INFO: [regulator]    Characteristic [0000fff1-0000-1000-8000-00805f9b34fb]
INFO: [regulator]  Service [0000ffd0-0000-1000-8000-00805f9b34fb]
INFO: [regulator]  - Found dev write service [0000ffd0-0000-1000-8000-00805f9b34fb]
INFO: [regulator]    Characteristic [0000ffd5-0000-1000-8000-00805f9b34fb]
INFO: [regulator]    Characteristic [0000ffd4-0000-1000-8000-00805f9b34fb]
INFO: [regulator]    Characteristic [0000ffd3-0000-1000-8000-00805f9b34fb]
INFO: [regulator]    Characteristic [0000ffd2-0000-1000-8000-00805f9b34fb]
INFO: [regulator]    Characteristic [0000ffd1-0000-1000-8000-00805f9b34fb]
INFO: [regulator]  Service [0000180a-0000-1000-8000-00805f9b34fb]
INFO: [regulator]    Characteristic [00002a50-0000-1000-8000-00805f9b34fb]
INFO: [regulator]    Characteristic [00002a2a-0000-1000-8000-00805f9b34fb]
INFO: [regulator]    Characteristic [00002a29-0000-1000-8000-00805f9b34fb]
INFO: [regulator]    Characteristic [00002a28-0000-1000-8000-00805f9b34fb]
INFO: [regulator]    Characteristic [00002a27-0000-1000-8000-00805f9b34fb]
INFO: [regulator]    Characteristic [00002a26-0000-1000-8000-00805f9b34fb]
INFO: [regulator]    Characteristic [00002a25-0000-1000-8000-00805f9b34fb]
INFO: [regulator]    Characteristic [00002a24-0000-1000-8000-00805f9b34fb]
INFO: [regulator]    Characteristic [00002a23-0000-1000-8000-00805f9b34fb]
INFO: [regulator] Found dev notify char [0000fff1-0000-1000-8000-00805f9b34fb]
INFO: [regulator] Subscribing to notify char [0000fff1-0000-1000-8000-00805f9b34fb]
INFO: [regulator] Found dev write polling char [0000ffd1-0000-1000-8000-00805f9b34fb]
INFO: [regulator] Found dev write polling char [0000ffd1-0000-1000-8000-00805f9b34fb]
INFO: [regulator] Starting new thread Device-poller-thread regulator
INFO: [regulator] Starting new thread MQTT-poller-thread regulator
INFO: [regulator] MQTT-poller-thread regulator Waiting for event...
INFO: [regulator] Notifications enabled for: [0000fff1-0000-1000-8000-00805f9b34fb]
INFO: [regulator] Sending new data current: 0.0
INFO: [regulator] Sending new data input_current: 0.0
INFO: [regulator] Sending new data charge_current: 0.0
INFO: [regulator] Sending new data voltage: 0.0
INFO: [regulator] Sending new data input_voltage: 0.0
INFO: [regulator] Sending new data charge_voltage: 12.8
INFO: [regulator] Sending new data power: 0.0
INFO: [regulator] Sending new data input_power: 0.0
INFO: [regulator] Sending new data charge_power: 0.0
INFO: [regulator] Sending new data soc: 82.0
INFO: [regulator] Sending new data capacity: 0.0
INFO: [regulator] Sending new data power_switch: 0
INFO: Creating MQTT-listener shed_solar/regulator/power_switch/set
INFO: [regulator] Sending new data temperature: 22.0
INFO: [regulator] Sending new data battery_temperature: 0.0
WARNING: [regulator] Write to characteristic failed for: [0000ffd1-0000-1000-8000-00805f9b34fb] with error [In Progress]
WARNING: [regulator] Write to characteristic failed for: [0000ffd1-0000-1000-8000-00805f9b34fb] with error [In Progress]
WARNING: [regulator] Write to characteristic failed for: [0000ffd1-0000-1000-8000-00805f9b34fb] with error [In Progress]
WARNING: [regulator] Write to characteristic failed for: [0000ffd1-0000-1000-8000-00805f9b34fb] with error [In Progress]
WARNING: [regulator] Write to characteristic failed for: [0000ffd1-0000-1000-8000-00805f9b34fb] with error [In Progress]
INFO: [ac:4d:16:1a:a5:ee] Discovered, alias = BT-TH-161AA5EE
INFO: [regulator] Disconnected
INFO: [regulator] Stopping poller-thread
INFO: [regulator] Stopping command-thread
INFO: [regulator] MQTT-poller-thread regulator Event happened...
WARNING: [regulator] Write to characteristic failed for: [0000ffd1-0000-1000-8000-00805f9b34fb] with error [Operation failed with ATT error: 0x0e]
INFO: [regulator] Ending thread MQTT-poller-thread regulator
INFO: [regulator] Ending thread Device-poller-thread regulator

When I run btmon, these are the final things I see:

< ACL Data TX: Handle 64 flags 0x00 dlen 27                                                                                                                                      #92 [hci0] 45.050247
< ACL Data TX: Handle 64 flags 0x01 dlen 1                                                                                                                                       #93 [hci0] 45.050355
      ATT: Write Request (0x12) len 23
        Handle: 0x001d Type: Unknown (0xffd1)
          Data: 6d61696e20726563762064612074615b66665d205b
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                                           #94 [hci0] 45.063714
        Num handles: 1
        Handle: 64 Address: AC:4D:16:1A:A5:EE (Texas Instruments)
        Count: 2
> ACL Data RX: Handle 64 flags 0x02 dlen 5                                                                                                                                       #95 [hci0] 45.081824
      ATT: Write Response (0x13) len 0
< ACL Data TX: Handle 64 flags 0x00 dlen 15                                                                                                                                      #96 [hci0] 51.804237
      ATT: Write Request (0x12) len 10
        Handle: 0x001d Type: Unknown (0xffd1)
          Data: ff0301000007102a
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                                           #97 [hci0] 53.332638
        Num handles: 1
        Handle: 64 Address: AC:4D:16:1A:A5:EE (Texas Instruments)
        Count: 1
> HCI Event: Disconnect Complete (0x05) plen 4                                                                                                                                   #98 [hci0] 53.332657
        Status: Success (0x00)
        Handle: 64 Address: AC:4D:16:1A:A5:EE (Texas Instruments)
        Reason: Connection Timeout (0x08)
@ MGMT Event: Device Disconnected (0x000c) plen 8                                                                                                                           {0x0001} [hci0] 53.332814
        LE Address: AC:4D:16:1A:A5:EE (Texas Instruments)
        Reason: Connection timeout (0x01)

I've only just started looking into this, but any pointers would be appreciated.

glynastill commented 12 months ago

Can anyone shine any light on what this means? WARNING: [regulator] Write to characteristic failed for: [0000ffd1-0000-1000-8000-00805f9b34fb] with error [Operation failed with ATT error: 0x0e]

Olen commented 12 months ago

WARNING: [regulator] Write to characteristic failed for: [0000ffd1-0000-1000-8000-00805f9b34fb] with error [In Progress]

Those are just warnings. Usually because another write operation has not completed yet. It will just retry the operation and go on.

WARNING: [regulator] Write to characteristic failed for: [0000ffd1-0000-1000-8000-00805f9b34fb] with error [Operation failed with ATT error: 0x0e]

No idea what 0x0e is but this does not look good.

> HCI Event: Disconnect Complete (0x05) plen 4                                                                                                                                   #98 [hci0] 53.332657
        Status: Success (0x00)
        Handle: 64 Address: AC:4D:16:1A:A5:EE (Texas Instruments)
        Reason: Connection Timeout (0x08)
@ MGMT Event: Device Disconnected (0x000c) plen 8                                                                                                                           {0x0001} [hci0] 53.332814
        LE Address: AC:4D:16:1A:A5:EE (Texas Instruments)
        Reason: Connection timeout (0x01)

Connection timeut sounds like a bad connection to the device.

Also, you have a lot of "discover" for the same device:

INFO: [regulator] Connecting to ac:4d:16:1a:a5:ee
INFO: Terminate with Ctrl+C
INFO: [ac:4d:16:1a:a5:ee] Discovered, alias = BT-TH-161AA5EE
INFO: [regulator] Connected to BT-TH-161AA5EE
INFO: [ac:4d:16:1a:a5:ee] Discovered, alias = BT-TH-161AA5EE
INFO: [ac:4d:16:1a:a5:ee] Discovered, alias = BT-TH-161AA5EE
(...)
INFO: [ac:4d:16:1a:a5:ee] Discovered, alias = BT-TH-161AA5EE

To me, this sounds like maybe the upgrade is causing some BT issues. You could try to add an external bluetooth-dongle, mabye connected through an extension cable, to improve the connection.

glynastill commented 11 months ago

Thanks @Olen - yes you are correct, it looks like I rolled this raspberry pi onto Bookworm way before it was ready, the pi-bluetooth module isn't even in the Bookworm repository.

I rolled the OS back last night and the head of master works fine - the Operation failed with ATT error: 0x0e message is related to bluetooth and has now gone away.

The additional discoveries still happen, though they don't seem to cause any issues.

Olen commented 6 months ago

I had some issues with bookworm myself, but after the latest updates, it seems to work fine again. I think they pushed some more BT fixes to Bookworm lately.