tinygo-org / bluetooth

Cross-platform Bluetooth API for Go and TinyGo. Supports Linux, macOS, Windows, and bare metal using Nordic SoftDevice or HCI
https://tinygo.org
Other
744 stars 137 forks source link

Fix several goroutine leaks #262

Open Elara6331 opened 7 months ago

Elara6331 commented 7 months ago

This PR fixes several goroutine leaks that I've found:

Fixes #260

jasday commented 7 months ago

I've done some testing on this branch and seem to be getting some interesting results:

This seems to only be a problem when the device is connected to repeatedly without another connection in between. If I connect to one device, receive notifications, disconnect, connect to different device, read notifications, disconnect, I am able to receive notifications from the original device again. Sometimes repeating to the same device repeatedly will result in a notification being read, but it seems to be slightly random when it will work.

This was tested on multiple devices, and occurred on both although not consistently. That being said, I get this on the release version, just not as often - so potentially a different problem that this fix is revealing?

Elara6331 commented 7 months ago

EnableNotifications no longer works on repeated connections

Hmm, that's weird. I've specifically tested that case several times and it seems to work for me. I also see no reason that this PR would break that, since the DBus match rules and signal channel are set up again when you re-enable notifications.

Here's a simplified reproduction that I used to test this:

main.go ```go package main import ( "log" "time" "tinygo.org/x/bluetooth" ) const address = "ED:47:AC:47:F4:FB" var ( serviceUUID = mustParse("00000000-78fc-48fe-8e23-433b3a1942d0") eventCharUUID = mustParse("00000001-78fc-48fe-8e23-433b3a1942d0") ) func main() { adapter := bluetooth.DefaultAdapter err := adapter.Enable() if err != nil { panic(err) } device := connectDevice(adapter) char := getChar(device) log.Println("First connection complete") err = char.EnableNotifications(func(buf []byte) { log.Printf("Received notification: %x\n", buf) }) if err != nil { panic(err) } log.Println("Notifications enabled") time.Sleep(2*time.Second) err = device.Disconnect() if err != nil { panic(err) } log.Println("Device disconnected") time.Sleep(2*time.Second) device = connectDevice(adapter) char = getChar(device) log.Println("Second connection complete") err = char.EnableNotifications(func(buf []byte) { log.Printf("Received notification: %x\n", buf) }) if err != nil { panic(err) } log.Println("Notifications re-enabled; sleeping forever") select {} } func connectDevice(adapter *bluetooth.Adapter) bluetooth.Device { var ( err error device bluetooth.Device ) err = adapter.Scan(func(adapter *bluetooth.Adapter, sr bluetooth.ScanResult) { if sr.Address.String() == address { device, err = adapter.Connect(sr.Address, bluetooth.ConnectionParams{}) if err != nil { panic(err) } adapter.StopScan() } }) if err != nil { panic(err) } return device } func getChar(device bluetooth.Device) bluetooth.DeviceCharacteristic { services, err := device.DiscoverServices([]bluetooth.UUID{serviceUUID}) if err != nil { panic(err) } chars, err := services[0].DiscoverCharacteristics([]bluetooth.UUID{eventCharUUID}) if err != nil { panic(err) } return chars[0] } func mustParse(s string) bluetooth.UUID { uuid, err := bluetooth.ParseUUID(s) if err != nil { panic(err) } return uuid } ```

After successfully connecting and disconnecting from a device, the next connection attempt often occurs in a le-connection-abort-by-local error.

I've also had this happen intermittently with muka/go-bluetooth and bluetoothctl (mostly on Intel Bluetooth adapters, but on others as well), so I don't think this is a problem with this library, it's most likely a bug in BlueZ or somewhere else in Linux's bluetooth stack

Elara6331 commented 7 months ago

I did find a different problem though:

https://github.com/tinygo-org/bluetooth/blob/4557b5d70cc04f25e7f8a533e583c73db0fc4472/gattc_linux.go#L239

The problem here is that the receiver is not a pointer, so the DeviceCharacteristic struct is copied. That means when EnableNotifications is called and it sets some struct fields here:

https://github.com/tinygo-org/bluetooth/blob/4557b5d70cc04f25e7f8a533e583c73db0fc4472/gattc_linux.go#L250-L253

those changes don't persist, which means running EnableNotifications(nil) later has no effect (though disconnect events do still have an effect because the goroutine captures the receiver variable), and c.property is always nil, so errDupNotif never gets returned if someone tries to add multiple notification handlers.

There are two ways to fix this. The cleaner way would be to change the EnableNotifications function to use a pointer receiver, but that would be a breaking change and it would be inconsistent with the other implementations. The other way, which I don't really like but would avoid a breaking change, is to store a pointer to another struct in DeviceCharacteristic, with all the fields that need to be changed.

I'm not sure which approach this library would rather go with, so I won't change this until a maintainer of the project weighs in.

jasday commented 7 months ago

Hmm, that's weird. I've specifically tested that case several times and it seems to work for me. I also see no reason that this PR would break that, since the DBus match rules and signal channel are set up again when you re-enable notifications.

Here's a simplified reproduction that I used to test this: main.go

That's interesting, I tried with your code and got this output log:

 First connection complete
 Notifications enabled
 Received notification: %x
 [6 109 1 0 255 219 7 1 21 20 27 0 1]
 Device disconnected
 Second connection complete
 Notifications re-enabled; sleeping forever

I was taking readings (using a health thermometer device) and expected notifications to appear after the second notification re-enabled, but received nothing. I'm assuming I should be seeing notifications appear here as long as the device is still active and taking measurements?

Doing a little more testing, I have two devices with the same service/characteristic and one different. On the first connection of one of the matching pair, I receive a single notification with value, and then no more. I can then connect the other of the pair, and get the same behavior. If I then connect a different type of device, with a different service/characteristic, I can get only the first values from that - however connecting this new service seems to do some type of 'reset' and I can then receive the first value from both the original devices again.

The only real difference I'm seeing between your example code and mine is that I don't stop scanning - I need to be able to listen for devices whilst I'm handling a scan result, but adding a stopScan to mine still produces the same results.

Elara6331 commented 6 months ago

That's interesting, I tried with your code and got this output log:

That's weird. It's been working consistently for me. I've tried it on Intel, MediaTek, and Realtek bluetooth adapters, and with different peripherals. Here's my log:

2024/04/09 09:41:30 First connection complete
2024/04/09 09:41:31 Notifications enabled
2024/04/09 09:41:33 Received notification: 03
2024/04/09 09:41:33 Received notification: 03
2024/04/09 09:41:33 Received notification: 01
2024/04/09 09:41:34 Received notification: 04
2024/04/09 09:41:35 Device disconnected
2024/04/09 09:41:38 Second connection complete
2024/04/09 09:41:38 Notifications re-enabled; sleeping forever
2024/04/09 09:41:39 Received notification: 01
2024/04/09 09:41:39 Received notification: 04
2024/04/09 09:41:40 Received notification: 03
2024/04/09 09:41:40 Received notification: 01
2024/04/09 09:41:41 Received notification: 01
jasday commented 6 months ago

I'm testing on an NXP IW416 chip - not sure if this would cause any differences though.

Firmware is up to date, and the code looks like it should be working. Could this specific chip be sending extra signals that is causing notifications to be disabled?

I've attached my bluez logs in case it's a possibility. The device I'm testing with is dev_C0_26_DA_1A_FE_1A

log.txt

jasday commented 6 months ago

I've done a bit of testing on a local branch, and seem to have got it to work on my device.

It only needs a small change to the nil case in the same switch statement, adding

err := c.characteristic.Call("org.bluez.GattCharacteristic1.StopNotify", 0).Err
        if err != nil {
            return err
        }

to make the entire case

case nil:
        if c.property == nil {
            return nil
        }

        err := c.characteristic.Call("org.bluez.GattCharacteristic1.StopNotify", 0).Err
        if err != nil {
            return err
        }

        err = c.adapter.bus.RemoveMatchSignal(c.propertiesChangedMatchOption)
        c.adapter.bus.RemoveSignal(c.property)
        close(c.property)
        c.property = nil
        return err

I'm not entirely sure the side affect of this, if we error when calling stop notify this may cause the signals to not be removed properly (or, on the other hand, will this mean that it will just try again if it fails?) - @Elara6331 do you have any thoughts?

If this change could be tested/confirmed and then added to the PR if proven working, that would be great.

Elara6331 commented 6 months ago

I do have a question about this:

https://github.com/tinygo-org/bluetooth/blob/4f54e74b090cdc58f86b6fcd30161fd2b67f062e/gattc_linux.go#L239

Since the method doesn't use a pointer receiver, the following lines operate on a copy of the characteristic and make EnableNotifications(nil) useless since those changes don't persist and c.property will always be nil:

https://github.com/tinygo-org/bluetooth/blob/4f54e74b090cdc58f86b6fcd30161fd2b67f062e/gattc_linux.go#L250

https://github.com/tinygo-org/bluetooth/blob/4f54e74b090cdc58f86b6fcd30161fd2b67f062e/gattc_linux.go#L252

I'm not sure what the best way to solve this would be, since making it a pointer receiver would be a breaking change and inconsistent with the other implementations.

deadprogram commented 4 months ago

Pinging @aykevl for an opinion on this, please.

jasday commented 2 months ago

Have there been any more thoughts on this? Along with the stop notifiy addition? @aykevl @Elara6331