bluetooth icon indicating copy to clipboard operation
bluetooth copied to clipboard

dbus/decode high memory use/leak

Open AndyRN opened this issue 1 year ago • 3 comments

Using pprof, the following was generated from a Golang application running on Linux (arm64). The application is quite simple, and mirrors mostly what the heartrate-monitor example portrays:

  • Starts an advertisement payload scanning loop.
  • Connects to a device that is relevant to the application.
  • Enables notifications on the device's characteristic, retrieved through the required discovery operations.
  • Decodes the payload of notification callback.
  • Disconnects from the device.

pprof

Over time, memory usage will slowly climb as the loop continues to accept connections, decode payloads, and disconnect from devices - which can be reconnected each time they advertise an update.

Possibly related issues:

  • https://github.com/tinygo-org/bluetooth/issues/252
  • https://github.com/tinygo-org/bluetooth/issues/260
  • https://github.com/tinygo-org/bluetooth/issues/291

AndyRN avatar Oct 08 '24 17:10 AndyRN

After some investigation, it appears to be this block of code: https://github.com/tinygo-org/bluetooth/blob/release/gap_linux.go#L362

err := device.device.Call("org.bluez.Device1.Connect", 0).Err
if err != nil {
	return Device{}, fmt.Errorf("bluetooth: failed to connect: %w", err)
}

The call to the bluez device has the potential to hang indefinitely if there is an issue with the bluetooth device, and my particular device is proving to be quite flakey.

Really this needs to make use of the ConnectionTimeout parameters that are passed into the Connect() call, unless I'm misunderstanding where they're meant to be referenced.

Testing the change below seems to solve it for me, though unsure what wider impact this may have on the rest of the library:

ctx, ctxCancel := context.WithCancel(context.Background())
ctxTimer := time.AfterFunc(params.ConnectionTimeout.AsTimeDuration(), ctxCancel)
err := device.device.CallWithContext(ctx, "org.bluez.Device1.Connect", 0).Err
if err != nil {
	return Device{}, fmt.Errorf("bluetooth: failed to connect: %w", err)
}
ctxTimer.Stop()
  • params.ConnectionTimeout was defaulted to NewDuration(30 * time.Second) if not provided as part of the ConnectionParams.
  • AsTimeDuration() was added to convert a Duration to a time.Duration so that "real" times can be utilised where necessary.
    func (d Duration) AsTimeDuration() time.Duration {
        	return time.Duration(d) * (625 * time.Microsecond)
    }
    
  • Alternatively, ConnectionParams could be updated to directly use time.Duration, although it appears to be related to part of the BLE spec, so I avoided changing this for the sake of focusing on testing the issue in question.

Would appreciate any thoughts/opinions on this, and if anyone can see if there's a reason to not timeout the connection attempts?

AndyRN avatar Oct 24 '24 13:10 AndyRN

@aykevl any thoughts on this?

deadprogram avatar Oct 25 '24 10:10 deadprogram

goroutines

Related to the high memory usage, but potentially unrelated to the connection issue detailed above, there is a high number of goroutines being continuously started without being cleaned up which I believe is related to the scanning.

After some experimentation, restarting the scan callback on the adapter every hour or so prevents this steady climb of goroutines, which somewhat confirms the theory, however doesn't explain where the misbehaving code lies in the library (or any underlying dependency).

AndyRN avatar Oct 28 '24 11:10 AndyRN