Flic 2 takes multiple clicks before connecting

[I-am-not-a-number]

Hi there,

I'm turning my lights on and off with flic2 buttons connected to a Raspberry Pi 4, using the onboard Bluetooth. My problem is, that it often only works after three clicks.

first click : red flic2 led
second click : orange flic2 led
third click : green flic2 led, light is toggled two times (I think the click with the orange led was queued)

I already tried to reduce the baud rate (see Issue #90)

root 519 1 0 08:23 ? 00:00:00 /usr/bin/hciattach /dev/serial1 bcm43xx 230400 flow -

Any ideas?

Many thanks :-)
Markus

btmon shows:

        Status: Success (0x00)
        Handle: 66
        Reason: Connection Timeout (0x08)
< HCI Command: LE Create Connection Cancel (0x08|0x000e) plen 0                           #33 [hci0] 5115.188455
> HCI Event: Command Complete (0x0e) plen 4                                               #34 [hci0] 5115.191522
      LE Create Connection Cancel (0x08|0x000e) ncmd 1
        Status: Success (0x00)
> HCI Event: LE Meta Event (0x3e) plen 19                                                 #35 [hci0] 5115.192271
      LE Connection Complete (0x01)
        Status: Unknown Connection Identifier (0x02)
        Handle: 68
        Role: Master (0x00)
        Peer address type: Public (0x00)
        Peer address: 00:00:00:00:00:00 (OUI 00-00-00)
        Connection interval: 22.50 msec (0x0012)
        Connection latency: 0 (0x0000)
        Supervision timeout: 200 msec (0x0014)
        Master clock accuracy: 0x00
< HCI Command: LE Add Device To White List (0x08|0x0011) plen 7                           #36 [hci0] 5115.192419
        Address type: Public (0x00)
        Address: xx:xx:xx_flic2_button (OUI 80-E4-DA)
> HCI Event: Command Complete (0x0e) plen 4                                               #37 [hci0] 5115.193762
      LE Add Device To White List (0x08|0x0011) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Create Connection (0x08|0x000d) plen 25                                 #38 [hci0] 5115.193913
        Scan interval: 60.000 msec (0x0060)
        Scan window: 30.000 msec (0x0030)
        Filter policy: White list is used (0x01)
        Peer address type: Public (0x00)
        Peer address: 00:00:00:00:00:00 (OUI 00-00-00)
        Own address type: Public (0x00)
        Min connection interval: 20.00 msec (0x0010)
        Max connection interval: 25.00 msec (0x0014)
        Connection latency: 0 (0x0000)
        Supervision timeout: 200 msec (0x0014)
        Min connection length: 0.000 msec (0x0000)
        Max connection length: 0.000 msec (0x0000)
> HCI Event: Command Status (0x0f) plen 4                                                 #39 [hci0] 5115.196674
      LE Create Connection (0x08|0x000d) ncmd 1
        Status: Success (0x00)
> HCI Event: LE Meta Event (0x3e) plen 19                                                 #40 [hci0] 5115.225565
      LE Connection Complete (0x01)
        Status: Success (0x00)
        Handle: 66
        Role: Master (0x00)
        Peer address type: Public (0x00)
        Peer address: xx:xx:xx_flic2_button (OUI 80-E4-DA)
        Connection interval: 22.50 msec (0x0012)
        Connection latency: 0 (0x0000)
        Supervision timeout: 200 msec (0x0014)
        Master clock accuracy: 0x00
< ACL Data TX: Handle 66 flags 0x00 dlen 25                                               #41 [hci0] 5115.225734
      ATT: Write Command (0x52) len 20
        Handle: 0x0010
          Data: 0005f59627919dd0e30000000000f9de6ba4
< ACL Data TX: Handle 66 flags 0x00 dlen 7                                                #42 [hci0] 5115.225856
      ATT: Exchange MTU Request (0x02) len 2
        Client RX MTU: 239
< HCI Command: LE Remove Device From White List (0x08|0x0012) plen 7                      #43 [hci0] 5115.225970
        Address type: Public (0x00)
        Address: xx:xx:xx_flic2_button (OUI 80-E4-DA)
> HCI Event: Command Complete (0x0e) plen 4                                               #44 [hci0] 5115.228775
      LE Remove Device From White List (0x08|0x0012) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Create Connection (0x08|0x000d) plen 25                                 #45 [hci0] 5115.228922
        Scan interval: 60.000 msec (0x0060)
        Scan window: 30.000 msec (0x0030)
        Filter policy: White list is used (0x01)
        Peer address type: Public (0x00)
        Peer address: 00:00:00:00:00:00 (OUI 00-00-00)
        Own address type: Public (0x00)
        Min connection interval: 20.00 msec (0x0010)
        Max connection interval: 25.00 msec (0x0014)
        Connection latency: 0 (0x0000)
        Supervision timeout: 200 msec (0x0014)
        Min connection length: 0.000 msec (0x0000)
        Max connection length: 0.000 msec (0x0000)
> HCI Event: Command Status (0x0f) plen 4                                                 #46 [hci0] 5115.231728
      LE Create Connection (0x08|0x000d) ncmd 1
        Status: Success (0x00)
> ACL Data RX: Handle 66 flags 0x02 dlen 27                                               #47 [hci0] 5115.286853
      ATT: Handle Value Notification (0x1b) len 22
        Handle: 0x0012
          Data: 2108964c19341b099e28000000000023ce84b933
< ACL Data TX: Handle 66 flags 0x00 dlen 27                                               #48 [hci0] 5115.287015
      ATT: Write Command (0x52) len 22
        Handle: 0x0010
          Data: 010f1d0000001ad56c6affffffff0398aca09baa
> HCI Event: Number of Completed Packets (0x13) plen 5                                    #49 [hci0] 5115.287624
        Num handles: 1
        Handle: 66
        Count: 2
> ACL Data RX: Handle 66 flags 0x02 dlen 7                                                #50 [hci0] 5115.287948
      ATT: Exchange MTU Response (0x03) len 2
        Server RX MTU: 140
> ACL Data RX: Handle 66 flags 0x02 dlen 27                                               #51 [hci0] 5115.376628
> ACL Data RX: Handle 66 flags 0x01 dlen 1                                                #52 [hci0] 5115.397289
      ATT: Handle Value Notification (0x1b) len 23
        Handle: 0x0012
          Data: 010ac1f104000000000000000a897b91ee488ad468
< HCI Command: LE Connection Update (0x08|0x0013) plen 14                                 #53 [hci0] 5115.398480
        Handle: 66
        Min connection interval: 87.50 msec (0x0046)
        Max connection interval: 100.00 msec (0x0050)
        Connection latency: 19 (0x0013)
        Supervision timeout: 5010 msec (0x01f5)
        Min connection length: 0.000 msec (0x0000)
        Max connection length: 0.000 msec (0x0000)
> HCI Event: Command Status (0x0f) plen 4                                                 #54 [hci0] 5115.400008
      LE Connection Update (0x08|0x0013) ncmd 1
        Status: Success (0x00)
> ACL Data RX: Handle 66 flags 0x02 dlen 39                                               #55 [hci0] 5115.421790
      ATT: Handle Value Notification (0x1b) len 34
        Handle: 0x0012
          Data: 010c040000003d120100000011ba2901000000183d52010000003248b0954f53
< ACL Data TX: Handle 66 flags 0x00 dlen 18                                               #56 [hci0] 5115.422892
      ATT: Write Command (0x52) len 13
        Handle: 0x0010
          Data: 011004000000712a711893
< ACL Data TX: Handle 66 flags 0x00 dlen 26                                               #57 [hci0] 5115.423027
      ATT: Write Command (0x52) len 21
        Handle: 0x0010
          Data: 011b01000100a00000328051010021803c61ed
> HCI Event: Number of Completed Packets (0x13) plen 5                                    #58 [hci0] 5115.465238
        Num handles: 1
        Handle: 66
        Count: 2
> ACL Data RX: Handle 66 flags 0x02 dlen 14                                               #59 [hci0] 5115.466968
      ATT: Handle Value Notification (0x1b) len 9
        Handle: 0x0012
          Data: 0119d06feb6051
> HCI Event: LE Meta Event (0x3e) plen 10                                                 #60 [hci0] 5115.634149
      LE Connection Update Complete (0x03)
        Status: Success (0x00)
        Handle: 66
        Connection interval: 90.00 msec (0x0048)
        Connection latency: 19 (0x0013)
        Supervision timeout: 5010 msec (0x01f5)
> HCI Event: Number of Completed Packets (0x13) plen 5                                    #61 [hci0] 5115.648697
        Num handles: 1
        Handle: 66
        Count: 1
> ACL Data RX: Handle 66 flags 0x02 dlen 25                                               #62 [hci0] 5116.535394
      ATT: Handle Value Notification (0x1b) len 20
        Handle: 0x0012
          Data: 010c0500000041020300000001739d6b3947
> ACL Data RX: Handle 66 flags 0x02 dlen 25                                               #63 [hci0] 5116.625363
      ATT: Handle Value Notification (0x1b) len 20
        Handle: 0x0012
          Data: 010c070000009e1703000000081426e3e0a7
> ACL Data RX: Handle 66 flags 0x02 dlen 25                                               #64 [hci0] 5116.985371
      ATT: Handle Value Notification (0x1b) len 20
        Handle: 0x0012
          Data: 010c08000000404203000000024e66da03fb
< ACL Data TX: Handle 66 flags 0x00 dlen 18                                               #65 [hci0] 5116.986513
      ATT: Write Command (0x52) len 13
        Handle: 0x0010
          Data: 0110080000008cd5a71396
> HCI Event: Number of Completed Packets (0x13) plen 5                                    #66 [hci0] 5117.273711
        Num handles: 1
        Handle: 66
        Count: 1

[webash]

ugh, I also experience this - did you find resolution?

[Emill]

@webash Could you show the btmon hci log as well? Do you have a rpi 4?

[I-am-not-a-number]

Not sure I remember it all but I did replace the battery and used an external USB BT dongle. Both solved some issues, I'm just not sure which ;-)

[webash]

@webash Could you show the btmon hci log as well? Do you have a rpi 4?

I'm using a RPI3. Do you mean the btmon logs? I'm getting a lot of output from that - like it fills the whole terminal buffer within a minute or so.

> HCI Event: LE Meta Event (0x3e) plen 39                                                        #1062 [hci0] 29.384735
      LE Advertising Report (0x02)
        Num reports: 1
        Event type: Connectable undirected - ADV_IND (0x00)
        Address type: Public (0x00)
        Address: C0:28:8D:36:5B:B3 (Logitech, Inc)
        Data length: 27
        Flags: 0x1a
          LE General Discoverable Mode
          Simultaneous LE and BR/EDR (Controller)
          Simultaneous LE and BR/EDR (Host)
        Name (short):
        16-bit Service UUIDs (complete): 1 entry
          Logitech International SA  (0xfe61)
        Company: IBM Corp. (3)
          Data: 00605100000a242934851a3c32
        RSSI: -62 dBm (0xc2)
> HCI Event: LE Meta Event (0x3e) plen 30                                                        #1063 [hci0] 29.398635
      LE Advertising Report (0x02)
        Num reports: 1
        Event type: Connectable undirected - ADV_IND (0x00)
        Address type: Random (0x01)
        Address: DB:57:E3:75:58:60 (Static)
        Data length: 18
        Flags: 0x06
          LE General Discoverable Mode
          BR/EDR Not Supported
        Company: not assigned (2409)
          Data: db57e3755860320e001132
        RSSI: -55 dBm (0xc9)
> HCI Event: LE Meta Event (0x3e) plen 39                                                        #1064 [hci0] 29.471238
      LE Advertising Report (0x02)
        Num reports: 1
        Event type: Connectable undirected - ADV_IND (0x00)
        Address type: Public (0x00)
        Address: C0:28:8D:36:5B:B3 (Logitech, Inc)
        Data length: 27
        Flags: 0x1a
          LE General Discoverable Mode
          Simultaneous LE and BR/EDR (Controller)
          Simultaneous LE and BR/EDR (Host)
        Name (short):
        16-bit Service UUIDs (complete): 1 entry
          Logitech International SA  (0xfe61)
        Company: IBM Corp. (3)
          Data: 00605100000a242934851a3c32
        RSSI: -63 dBm (0xc1)
> HCI Event: LE Meta Event (0x3e) plen 30                                                        #1065 [hci0] 29.481133
      LE Advertising Report (0x02)
        Num reports: 1
        Event type: Connectable undirected - ADV_IND (0x00)
        Address type: Random (0x01)
        Address: F4:87:C1:D1:45:CD (Static)
        Data length: 18
        Flags: 0x06
          LE General Discoverable Mode
          BR/EDR Not Supported
        Company: not assigned (2409)
          Data: f487c1d145cdf60b361105
        RSSI: -60 dBm (0xc4)
> HCI Event: LE Meta Event (0x3e) plen 30                                                        #1066 [hci0] 29.499548
      LE Advertising Report (0x02)
        Num reports: 1
        Event type: Connectable undirected - ADV_IND (0x00)
        Address type: Random (0x01)
        Address: DB:57:E3:75:58:60 (Static)
        Data length: 18
        Flags: 0x06
          LE General Discoverable Mode
          BR/EDR Not Supported
        Company: not assigned (2409)
          Data: db57e3755860320e001132
        RSSI: -55 dBm (0xc9)
> HCI Event: LE Meta Event (0x3e) plen 30                                                        #1067 [hci0] 29.582304
      LE Advertising Report (0x02)
        Num reports: 1
        Event type: Connectable undirected - ADV_IND (0x00)
        Address type: Random (0x01)
        Address: F4:87:C1:D1:45:CD (Static)
        Data length: 18
        Flags: 0x06
          LE General Discoverable Mode
          BR/EDR Not Supported
        Company: not assigned (2409)
          Data: f487c1d145cdf60b361105
        RSSI: -60 dBm (0xc4)
> HCI Event: LE Meta Event (0x3e) plen 30                                                        #1068 [hci0] 29.606041
      LE Advertising Report (0x02)
        Num reports: 1
        Event type: Connectable undirected - ADV_IND (0x00)
        Address type: Random (0x01)
        Address: DB:57:E3:75:58:60 (Static)
        Data length: 18
        Flags: 0x06
          LE General Discoverable Mode
          BR/EDR Not Supported
        Company: not assigned (2409)
          Data: db57e3755860320e001132
        RSSI: -58 dBm (0xc6)
> HCI Event: LE Meta Event (0x3e) plen 39                                                        #1069 [hci0] 29.641225
      LE Advertising Report (0x02)
        Num reports: 1
        Event type: Connectable undirected - ADV_IND (0x00)
        Address type: Public (0x00)
        Address: C0:28:8D:36:5B:B3 (Logitech, Inc)
        Data length: 27
        Flags: 0x1a
          LE General Discoverable Mode
          Simultaneous LE and BR/EDR (Controller)
          Simultaneous LE and BR/EDR (Host)
        Name (short):
        16-bit Service UUIDs (complete): 1 entry
          Logitech International SA  (0xfe61)
        Company: IBM Corp. (3)
          Data: 00605100000a242934851a3c32
        RSSI: -64 dBm (0xc0)
> HCI Event: LE Meta Event (0x3e) plen 30                                                        #1070 [hci0] 29.681646
      LE Advertising Report (0x02)
        Num reports: 1
        Event type: Connectable undirected - ADV_IND (0x00)
        Address type: Random (0x01)
        Address: F4:87:C1:D1:45:CD (Static)
        Data length: 18
        Flags: 0x06
          LE General Discoverable Mode
          BR/EDR Not Supported
        Company: not assigned (2409)
          Data: f487c1d145cdf60b361105
        RSSI: -59 dBm (0xc5)
> HCI Event: LE Meta Event (0x3e) plen 30                                                        #1071 [hci0] 29.708407
      LE Advertising Report (0x02)
        Num reports: 1
        Event type: Connectable undirected - ADV_IND (0x00)
        Address type: Random (0x01)
        Address: DB:57:E3:75:58:60 (Static)
        Data length: 18
        Flags: 0x06
          LE General Discoverable Mode
          BR/EDR Not Supported
        Company: not assigned (2409)
          Data: db57e3755860320e001132
        RSSI: -60 dBm (0xc4)

Not sure if any of this helps. I've truncated to just a few events. I have quite a few broadcasting bluetooth devices of my own, and live in an apartment building in London - so there's going to be noise. But all other bluetooth devices (like the Switchbot devices through the esp32 bt proxy) work fine.

This is now the third Raspberry Pi (v3) I've used for this over the years. Sometimes it works just fine for a while, and then suddenly it'll just stop and I'll have to reboot the Pi or restart flicd, and then typically I have to manually restart Home Assistant too - otherwise it doesn't reconnect properly - even if flicd has logged that a client has connected after restart.

I finally thought I'd replace the Pi with a fresh install and nothing else running on it - but still seeing the same behaviours.

[webash]

Not sure I remember it all but I did replace the battery and used an external USB BT dongle. Both solved some issues, I'm just not sure which ;-)

Any idea which adapter you've got? Thinking it must be the built-in Pi BT at this stage - it never has been great.

[Emill]

It seems like whatever integration you are running, it runs a scan continuously. Scanning should only be performed when pairing a new button, so try turn off this scanning.

Not sure but the Bluetooth controller (the cypress wifi/bt chip in a RPi) could be confused of all those advertisements maybe.

Also Flic buttons will not work reliably when the battery is low (they often drop connections in that case).

[webash]

It seems like whatever integration you are running, it runs a scan continuously. Scanning should only be performed when pairing a new button, so try turn off this scanning.

Understood; wasn't aware that discovery was quite that intensive. I might push a change to the HA documentation to make that clearer.

Not sure but the Bluetooth controller (the cypress wifi/bt chip in a RPi) could be confused of all those advertisements maybe.

Yeah very true.

Also Flic buttons will not work reliably when the battery is low (they often drop connections in that case).

Yep; changed some batteries just to be sure it wasn't only that.