Not connecting to Expert&Milk despite being picked up in Bluetoothctl

[Jamdoog]

Describe The Bug: Homebridge instance with brewer is unable to connect to Nespresso Expert&Milk.

To Reproduce: Configure as described, extract key and input details

Expected behavior: Connects successfully

Logs (Homebridge)

[24/08/2023, 16:22:00] [Brewer] [WATCH] Machine Expert&Milk_F61AD08F571A unreachable, still scanning
[24/08/2023, 16:23:00] [Brewer] [WATCH] Unreachable, this seems unintended try to move your hombridge server closer to the machine!

Logs (Bluetoothctl)

root@raspberrypi:~# systemctl status bluetooth
● bluetooth.service - Bluetooth service
     Loaded: loaded (/lib/systemd/system/bluetooth.service; enabled; vendor preset: enabled)
     Active: active (running) since Thu 2023-08-24 16:02:38 BST; 2min 44s ago
       Docs: man:bluetoothd(8)
   Main PID: 809 (bluetoothd)
     Status: "Running"
      Tasks: 1 (limit: 779)
        CPU: 260ms
     CGroup: /system.slice/bluetooth.service
             └─809 /usr/libexec/bluetooth/bluetoothd

Aug 24 16:02:36 raspberrypi systemd[1]: Starting Bluetooth service...
Aug 24 16:02:38 raspberrypi bluetoothd[809]: Bluetooth daemon 5.55
Aug 24 16:02:38 raspberrypi systemd[1]: Started Bluetooth service.
Aug 24 16:02:38 raspberrypi bluetoothd[809]: Starting SDP server
Aug 24 16:02:39 raspberrypi bluetoothd[809]: Bluetooth management interface 1.22 initialized
Aug 24 16:02:39 raspberrypi bluetoothd[809]: profiles/sap/server.c:sap_server_register() Sap driver initialization failed.
Aug 24 16:02:39 raspberrypi bluetoothd[809]: sap-server: Operation not permitted (1)
Aug 24 16:02:39 raspberrypi bluetoothd[809]: Failed to set privacy: Rejected (0x0b)
Aug 24 16:03:26 raspberrypi bluetoothd[809]: Endpoint registered: sender=:1.34 path=/MediaEndpoint/A2DPSink/sbc
Aug 24 16:03:26 raspberrypi bluetoothd[809]: Endpoint registered: sender=:1.34 path=/MediaEndpoint/A2DPSource/sbc
root@raspberrypi:~# hciconfig -a
hci0:   Type: Primary  Bus: UART
    BD Address: B8:27:EB:45:D8:2C  ACL MTU: 1021:8  SCO MTU: 64:1
    UP RUNNING 
    RX bytes:547598 acl:0 sco:0 events:14563 errors:0
    TX bytes:3651 acl:0 sco:0 commands:113 errors:0
    Features: 0xbf 0xfe 0xcf 0xfe 0xdb 0xff 0x7b 0x87
    Packet type: DM1 DM3 DM5 DH1 DH3 DH5 HV1 HV2 HV3 
    Link policy: RSWITCH SNIFF 
    Link mode: SLAVE ACCEPT 
    Name: 'raspberrypi'
    Class: 0x2c0000
    Service Classes: Rendering, Capturing, Audio
    Device Class: Miscellaneous, 
    HCI Version: 5.0 (0x9)  Revision: 0x17e
    LMP Version: 5.0 (0x9)  Subversion: 0x6119
    Manufacturer: Cypress Semiconductor (305)

root@raspberrypi:~# bluetoothctl
Agent registered
[CHG] Controller B8:27:EB:45:D8:2C Pairable: yes
[bluetooth]# scan on
Discovery started
[CHG] Controller B8:27:EB:45:D8:2C Discovering: yes
...
...
[CHG] Device F6:1A:D0:8F:57:1A RSSI: -61
[CHG] Device F6:1A:D0:8F:57:1A TxPower: 4
[CHG] Device F6:1A:D0:8F:57:1A Name: Expert&Milk_F61AD08F571A
[CHG] Device F6:1A:D0:8F:57:1A Alias: Expert&Milk_F61AD08F571A

Hexdump Log:

jam@Jamess-MacBook-ProDesktop % hexdump -v -e '/1 "%02X "' btsnoop_hci.log | grep -o '0B 00 04 00 12 14 00 \<.. .. .. .. .. .. .. ..\>'
0B 00 04 00 12 14 00 88 74 2D 7B 96 90 14 F4

Plugin Config:

        {
            "machines": [
                {
                    "name": "Expert&Milk_F61AD08F571A",
                    "token": "88-74-2D-7B-96-90-14-F4",
                    "temperature": "Medium"
                }
            ],
            "platform": "Brewer"
        }

Screenshots: N/A

Environment:

• Plugin Version: 2.1.1
• Homebridge Version: 1.6.1
• Node.js Version: 18.17.1
• NPM Version: 9.8.1
• Operating System: Raspbian / Debian 11

[Jamdoog]

I've also noticed this weird "19" output?

[24/08/2023, 16:50:26] [Brewer] [WATCH] Machine Expert&Milk_F61AD08F571A unreachable, still scanning [24/08/2023, 16:51:26] [Brewer] [WATCH] Machine Expert&Milk_F61AD08F571A unreachable, still scanning [24/08/2023, 16:52:26] [Brewer] [WATCH] Machine Expert&Milk_F61AD08F571A unreachable, still scanning [24/08/2023, 16:53:26] [Brewer] [WATCH] Machine Expert&Milk_F61AD08F571A unreachable, still scanning [24/08/2023, 16:54:26] [Brewer] [WATCH] Machine Expert&Milk_F61AD08F571A unreachable, still scanning [24/08/2023, 16:55:26] [Brewer] [WATCH] Machine Expert&Milk_F61AD08F571A unreachable, still scanning [24/08/2023, 16:58:07] [Brewer] 19

[Jamdoog]

[24/08/2023, 17:00:03] [Brewer] Initializing Brewer platform... [24/08/2023, 17:00:03] [Brewer] Finished initializing platform [24/08/2023, 17:00:03] [Brewer] Loading accessory from cache: Expert&Milk_F61AD08F571A [24/08/2023, 17:00:03] [Brewer] Start discovery [24/08/2023, 17:00:03] [Brewer] Configured machines: 1 [24/08/2023, 17:00:03] [Brewer] Restoring existing accessory from cache: Expert&Milk_F61AD08F571A [24/08/2023, 17:00:03] [Brewer] Adding coffee type 0 [24/08/2023, 17:00:03] [Brewer] Adding coffee type 1 [24/08/2023, 17:00:03] [Brewer] Adding coffee type 2 [24/08/2023, 17:00:03] [Brewer] Adding coffee type 5 [24/08/2023, 17:00:03] [Brewer] Adding coffee type 4 [24/08/2023, 17:00:03] [Brewer] [WATCH] Start connection [24/08/2023, 17:00:03] [Brewer] Disconnecting... [24/08/2023, 17:00:03] [Brewer] Disconnecting... [24/08/2023, 17:00:03] [Brewer] Start scan... [24/08/2023, 17:00:05] [Brewer] Device not connected! [24/08/2023, 17:00:05] [Brewer] Device not connected! [24/08/2023, 17:00:05] [Brewer] Device not connected! [24/08/2023, 17:00:05] [Brewer] Device not connected! [24/08/2023, 17:00:05] [Brewer] Device not connected! [24/08/2023, 17:01:03] [Brewer] [WATCH] Machine Expert&Milk_F61AD08F571A unreachable, still scanning [24/08/2023, 17:02:03] [Brewer] [WATCH] Machine Expert&Milk_F61AD08F571A unreachable, still scanning [24/08/2023, 17:03:03] [Brewer] [WATCH] Machine Expert&Milk_F61AD08F571A unreachable, still scanning

[Jamdoog]

I managed to get this working ONCE.

I'm not sure what I did.

I appended DisablePlugins=pnat to /etc/bluetooth/main.conf and rebooted. It worked after this.

But after another reboot it's no longer working.

I also moved the Pi further away during this, so it could be that.

But keeping the Pi in the same position of where it worked, it's no longer working.

[Jamdoog]

Put the Pi further away and its apparently connecting but any actions show:

[25/08/2023, 16:47:28] [Brewer] No status [25/08/2023, 16:47:28] [Brewer] Cancel command [25/08/2023, 16:47:28] [Brewer] Brew failed, no coffee... [25/08/2023, 16:47:30] [Brewer] Writing cancel command

[Jamdoog]

Not sure if this is related but sometimes I also see:

[Jamdoog]

[25/08/2023, 16:59:42] [Brewer] No status [25/08/2023, 16:59:42] [Brewer] Cancel command [25/08/2023, 16:59:42] [Brewer] Brew failed, no coffee... [25/08/2023, 16:59:43] [Brewer] Writing cancel command [25/08/2023, 16:59:48] [Brewer] Cancel command noble: unknown peripheral f61ad08f571a, 06aa1920f22a11e39daa0002a5d5c51b, 06aa3a12f22a11e39daa0002a5d5c51b read! noble: unknown peripheral f61ad08f571a, 06aa1950f22a11e39daa0002a5d5c51b, 06aa3a15f22a11e39daa0002a5d5c51b read! noble: unknown peripheral f61ad08f571a, 06aa1920f22a11e39daa0002a5d5c51b, 06aa3a22f22a11e39daa0002a5d5c51b read! noble: unknown peripheral f61ad08f571a, 06aa1910f22a11e39daa0002a5d5c51b, 06aa3a41f22a11e39daa0002a5d5c51b write! [25/08/2023, 16:59:50] [Brewer] Writing cancel command [25/08/2023, 16:59:52] [Brewer] No status [25/08/2023, 16:59:52] [Brewer] Cancel command [25/08/2023, 16:59:52] [Brewer] Brew failed, no coffee... [25/08/2023, 16:59:53] [Brewer] Writing cancel command

[Jamdoog]

Also noticed occasional: [25/08/2023, 16:59:34] [Brewer] 22