search

pybricks / support

Pybricks support and general discussion
MIT License
108 stars 6 forks source link

Cannot connect to Powered Up Remote #397

Closed laurensvalk closed 2 years ago

laurensvalk commented 3 years ago

I'm using https://beta.pybricks.com/ and I've installed the (I assume) latest firmware though the interface.

When trying the Remote example code, the hub LED begins to pulse and the remote LED blinks white, but it doesn't appear to connect and then I get Traceback (most recent call last): File "main.py", line 6, in OSError: [Errno 116] ETIMEDOUT

I'm using the City hub by the way

I press the "Download and run this program" button and the green button on my remote at the same time. The remote blinks white and the hub pulses but it doesn't appear to connect. The remote stops blinking roughly the same time as the timeout.

Originally posted by @pqhf5kd in https://github.com/pybricks/support/issues/186#issuecomment-884387174

laurensvalk commented 3 years ago

Could you share the script you used?

Can you also add the following to your code, and share the output?

from pybricks import version
print(version)
pqhf5kd commented 3 years ago 
from pybricks.pupdevices import Remote
from pybricks.parameters import Button
from pybricks.tools import wait

# Connect to the remote.
my_remote = Remote()

while True:
    # Check which buttons are pressed.
    pressed = my_remote.buttons.pressed()

    # Show the result.
    print("pressed:", pressed)

    # Check a specific button.
    if Button.CENTER in pressed:
        print("You pressed the center button!")

    # Wait so we can see the result.
    wait(100)
pqhf5kd commented 3 years ago

('cityhub', '3.1.0a3', 'v3.1.0a3 on 2021-07-19')

dlech commented 3 years ago

It is working for me with the same firmware version. They only way I know to troubleshoot would be to connect the defective remote to a computer and log the Bluetooth packets. Maybe the remote has different firmware or something like that?

dlech commented 3 years ago

Also, try turning on the remote later after the program is already started instead of pressing the buttons at the same time.

pqhf5kd commented 3 years ago

I'm on a 2021 MacBook Air. The remote doesn't appear in the bluetooth list when in pairing mode, nor does it on iOS. It does appear in the bluetooth list on iOS after connect through the PUP app. Is that normal?

It connects through the app quickly, without any issues.

dlech commented 3 years ago

You would need to use a program like pybricksdev that knows how to connect to the remote.

laurensvalk commented 3 years ago

Maybe the remote has different firmware or something like that?

Do you remember roughly when this remote was purchased? Was it purchased separately or as part of a train set?

laurensvalk commented 3 years ago

Someone on our Facebook page has reported a similar issue.

@dlech, if more people run into this, perhaps we can share a firmware zip here that prints out relevant debug info during the connection process, so people can try it without Pybricksdev.

pqhf5kd commented 3 years ago

Someone on our Facebook page has reported a similar issue.

@dlech, if more people run into this, perhaps we can share a firmware zip here that prints out relevant debug info during the connection process, so people can try it without Pybricksdev.

That was me on Facebook, sorry!

The remote came from a 60198 set that I purchased sealed, but from a private seller, in December 2020. I had a look on the box, but it doesn't look like there's a date code.

The remote has the following under the battery box:

The following is moulded:

dlech commented 3 years ago

I just had another idea. If you have iOS or Android, you can install nRF Connect and sniff the adverting data from the remote.

We are looking for the raw advertising data like this: Screenshot_20210726-125115

pqhf5kd commented 3 years ago

Thanks Dlech. Unfortunately I'm away from home until the end of August, but I'll try this as soon as I get back.

pqhf5kd commented 3 years ago

It looks like nRF Connect doesn't show raw advertising data on iOS. I'll try and get an Android device for testing in the next few days.

dlech commented 3 years ago

FYI, we've made some changes that could affect this issue. Could you try again with the v3.1.0a4 firmware from https://beta.pybricks.com?

pqhf5kd commented 3 years ago

V3.1.0a34 makes no difference unfortunately

BertLindeman commented 3 years ago

Completely different environment, but this combo works: My remote coded 26I0 on win10 MS-edge 92.0.902.84 shows

('cityhub', '3.1.0a4', 'v3.1.0a4 on 2021-08-30')
pressed: (Button.LEFT_MINUS, Button.RIGHT_MINUS, Button.LEFT, Button.RIGHT, Button.LEFT_PLUS, Button.RIGHT_PLUS)
pressed: ()

and so on.

pqhf5kd commented 3 years ago

I grabbed the advertising data using an Android device today signal-2021-09-05-172826_001 0x020106110723D1BCEA5F782316DEEF12122316000009FF970300420A004100140948616E64736574000000000000000000000000051210002000020A00

pqhf5kd commented 3 years ago

Was this any use?

dlech commented 3 years ago

It matches the advertising data from my hub (other than the hub name, which should not be relevant), so it rules out the possibility that LEGO changed the advertising data layout. However, that doesn't get us any closer to a solution.

We did have one other report of not being able to connect to a different LWP3 device: https://github.com/pybricks/support/issues/442#issuecomment-908672496. Not sure if this might be related or not.

pqhf5kd commented 3 years ago

I installed pybricksdev on an older, Intel MacBook and my remote connects without issue.

I'm unable to connect my city hub, although that might be my fault. I'll read the documentation further.

dlech commented 3 years ago

It the city hub currently has Pybricks firmware on it instead of LEGO firmware, then that would explain why it doesn't connect in the same way as the remote.

pqhf5kd commented 3 years ago

I tried again with the Lego firmware and it connects.

Is there some diagnostics I can do with pybricksdev?

dlech commented 3 years ago

Since it is connecting properly with pybricksdev, there probably isn't much to be learned there. If you really want to, you can log the Bluetooth packets (instructions).

But what we really need is the Bluetooth traffic going between the city hub running Pybricks firmware and the remote handset. However, that requires a sniffer.

mateusz commented 3 years ago

Hi, just ran into seemingly similar issue on CityHub :)

Remote never shows up in beta.pybricks.com (neither flashing mode, nor the regular connection), but I can connect to it using pybricksdev lwp3 repl. Here is nRF adv dump:

remote

So if the remote can connect ok with TechnicHub, is it something special to do with cityhub? My CityHub is:

cityhub

dlech commented 3 years ago

If you can connect the remote/handset with pybricksdev lwp3 repl what is the output if you run the following commands:

Type message and press ENTER to send. Press CTRL+D to exit.
>>> HubPropertyRequestUpdate(HubProperty.FW_VERSION)
[11:27:43.744] INFO: sending: HubPropertyRequestUpdate(<HubProperty.FW_VERSION: 3>)
[11:27:43.876] INFO: received: HubPropertyUpdate(<HubProperty.FW_VERSION: 3>, Version(0x10000004))
>>> HubPropertyRequestUpdate(HubProperty.RADIO_FW_VERSION)
[11:27:49.278] INFO: sending: HubPropertyRequestUpdate(<HubProperty.RADIO_FW_VERSION: 9>)
[11:27:49.396] INFO: received: HubPropertyUpdate(<HubProperty.RADIO_FW_VERSION: 9>, '2.2.1')

It would also be interesting to see the radio firmware version on the City hub (will have to flash LEGO firmware on the hub to do this).

pqhf5kd commented 3 years ago

Remote:

`Type message and press ENTER to send. Press CTRL+D to exit.

HubPropertyRequestUpdate(HubProperty.FW_VERSION) [18:37:22.465] INFO: sending: HubPropertyRequestUpdate(<HubProperty.FW_VERSION: 3>) [18:37:22.518] INFO: received: HubPropertyUpdate(<HubProperty.FW_VERSION: 3>, Version(0x10000004)) HubPropertyRequestUpdate(HubProperty.RADIO_FW_VERSION) [18:37:29.247] INFO: sending: HubPropertyRequestUpdate(<HubProperty.RADIO_FW_VERSION: 9>) [18:37:29.298] INFO: received: HubPropertyUpdate(<HubProperty.RADIO_FW_VERSION: 9>, '2.2.1')`

Hub:

`Type message and press ENTER to send. Press CTRL+D to exit.

HubPropertyRequestUpdate(HubProperty.FW_VERSION) [18:38:34.954] INFO: sending: HubPropertyRequestUpdate(<HubProperty.FW_VERSION: 3>) [18:38:34.983] INFO: received: HubPropertyUpdate(<HubProperty.FW_VERSION: 3>, Version(0x11020000)) HubPropertyRequestUpdate(HubProperty.RADIO_FW_VERSION) [18:38:40.649] INFO: sending: HubPropertyRequestUpdate(<HubProperty.RADIO_FW_VERSION: 9>) [18:38:40.683] INFO: received: HubPropertyUpdate(<HubProperty.RADIO_FW_VERSION: 9>, '2_02_01')`

(sorry about the formatting)

mateusz commented 3 years ago

Mine looks the same as @pqhf5kd as far as I can see.

Remote:

>>> HubPropertyRequestUpdate(HubProperty.FW_VERSION)
[21:48:11.891] INFO: sending: HubPropertyRequestUpdate(<HubProperty.FW_VERSION: 3>)
[21:48:11.939] INFO: received: HubPropertyUpdate(<HubProperty.FW_VERSION: 3>, Version(0x10000004))
>>> HubPropertyRequestUpdate(HubProperty.RADIO_FW_VERSION)
[21:48:21.127] INFO: sending: HubPropertyRequestUpdate(<HubProperty.RADIO_FW_VERSION: 9>)
[21:48:21.201] INFO: received: HubPropertyUpdate(<HubProperty.RADIO_FW_VERSION: 9>, '2.2.1')

Hub (flashed back to LEGO fw):

>>> HubPropertyRequestUpdate(HubProperty.FW_VERSION)
[21:52:50.125] INFO: sending: HubPropertyRequestUpdate(<HubProperty.FW_VERSION: 3>)
[21:52:50.159] INFO: received: HubPropertyUpdate(<HubProperty.FW_VERSION: 3>, Version(0x11020000))
>>> HubPropertyRequestUpdate(HubProperty.RADIO_FW_VERSION)
[21:52:56.376] INFO: sending: HubPropertyRequestUpdate(<HubProperty.RADIO_FW_VERSION: 9>)
[21:52:56.399] INFO: received: HubPropertyUpdate(<HubProperty.RADIO_FW_VERSION: 9>, '2_02_01')
dlech commented 3 years ago

Here is my City hub (also looks the same):

>>> HubPropertyRequestUpdate(HubProperty.FW_VERSION)
[15:11:32.410] INFO: sending: HubPropertyRequestUpdate(<HubProperty.FW_VERSION: 3>)
[15:11:32.492] INFO: received: HubPropertyUpdate(<HubProperty.FW_VERSION: 3>, Version(0x11020000))
>>> HubPropertyRequestUpdate(HubProperty.RADIO_FW_VERSION)
[15:11:34.353] INFO: sending: HubPropertyRequestUpdate(<HubProperty.RADIO_FW_VERSION: 9>)
[15:11:34.437] INFO: received: HubPropertyUpdate(<HubProperty.RADIO_FW_VERSION: 9>, '2_02_01')

As a side note, this hub is sending a write response to write without response messages which causes BlueZ to disconnect. So I had to modify pybricksdev to make it work on Linux.

dlech commented 3 years ago

Thanks for all of the help so far. Sorry we aren't able to make any progress here. I'm not sure what else to do unless someone wants to ship me their hardware so I can reproduce the problem or wants to invest in a BLE sniffer to try to see if that can help diagnose the problem (and there are no guarantees that either will resolve the issue).

And just to be thorough, we should make sure there is not something we are physically doing differently, like pressing and holding a button while connecting, turning on devices in a different order, or something like that. And that there are not other BLE devices (phones/beacons/light bulbs/etc.) that could be advertising at the same time interfering with the connection process.

mateusz commented 3 years ago

Thanks for looking into it!

I tried charging the batteries too (no change). There was this weird quirk after I flashed it back to LEGO fw: the remote wouldn't connect at first try. I then connected both the remote and the hub to Powered UP app (in custom mode, without any flashing), and then after a reset they paired back ok.

I'm happy to try out your way of connecting if you care to write it down @dlech :) I think I might also walk out to open field to see if I can find a spot without bluetooth interference... head into the mountains ⛰️ hah

mateusz commented 3 years ago

Also do you think it's feasible to modify the FW to do some debug dumps? Is there any docs around working with the BT driver? I'm not really desperate, just wondering if it's something realistically tinkerable without bricking the hub and getting a lot of word-of-mouth explanation :)

dlech commented 3 years ago

Here is a video of me running the example program above. https://user-images.githubusercontent.com/963645/133943200-eacb36bd-cca4-4a69-9c04-532054cda1dc.mp4

dlech commented 3 years ago

Also do you think it's feasible to modify the FW to do some debug dumps?

We can try this. I've only had limited success with this due to the low memory on the devices and the fact that this tends to change timings and break things.

dlech commented 3 years ago

firmware.zip

Here is a firmware for City hub with some logging to try.

  1. Download the zip file (don't unzip)
  2. Drag and drop the file onto the firmware update button on https://beta.pybricks.com
  3. Continue with the firmware flashing processes as usual (press and hold the hub button on the hub, etc.)
  4. Run the sample program and let it timeout
  5. Copy the logs that are printed in the terminal and paste them here
mateusz commented 3 years ago

REPL output enough?

You reckon you could share the fw diff (even a dirty gist will do)? I'm super-curious to know where you dumping from, in case I wanted to take a leap :)

MicroPython v3.1.0a4-37-gaf4a1d78-dirty on 2021-09-19; Powered Up City Hub with STM32F030RC
Type "help()" for more information.
>>> remote = Remote()
07 01 04 FE 03 03 01 00 
0B 01 1B FD 07 00 00 00 18 00 0D 0A 
09 04 FF 06 7F 06 00 04 FE 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
04 01 05 FE 00 
09 04 FF 06 7F 06 00 05 FE 00 
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
OSError: [Errno 116] ETIMEDOUT
dlech commented 3 years ago

It is logging Bluetooth packets being sent and received during the connection process.

Here is the diff:

diff --git a/lib/pbio/drv/bluetooth/bluetooth_stm32_cc2640.c b/lib/pbio/drv/bluetooth/bluetooth_stm32_cc2640.c
index 61311098..10f211b9 100644
--- a/lib/pbio/drv/bluetooth/bluetooth_stm32_cc2640.c
+++ b/lib/pbio/drv/bluetooth/bluetooth_stm32_cc2640.c
@@ -424,11 +424,15 @@ void pbdrv_bluetooth_set_notification_handler(pbdrv_bluetooth_receive_handler_t
     notification_handler = handler;
 }

+static bool log_enabled;
+
 static PT_THREAD(scan_and_connect_task(struct pt *pt, pbio_task_t *task)) {
     pbdrv_bluetooth_scan_and_connect_context_t *context = task->context;

     PT_BEGIN(pt);

+    log_enabled = true;
+
     // start scanning
     PT_WAIT_WHILE(pt, write_xfer_size);
     GAP_DeviceDiscoveryRequest(GAP_DEVICE_DISCOVERY_MODE_ALL, 1, GAP_FILTER_POLICY_SCAN_ANY_CONNECT_ANY);
@@ -604,6 +608,7 @@ retry:

     task->status = PBIO_SUCCESS;

+    log_enabled = false;
     PT_EXIT(pt);

 disconnect:
@@ -613,6 +618,7 @@ disconnect:

     // task->status must be set before goto disconnect!

+    log_enabled = false;
     PT_EXIT(pt);

 cancel_connect:
@@ -629,6 +635,7 @@ cancel_discovery:

 end_cancel:
     task->status = PBIO_ERROR_CANCELED;
+    log_enabled = false;
     PT_END(pt);
 }

@@ -773,6 +780,31 @@ static void read_by_type_response_uuid128(uint16_t connection_handle,
     ATT_ReadByTypeRsp(connection_handle, &rsp);
 }

+#define LOG_NUM_ROWS 128
+#define LOG_ROW_SIZE 32
+
+static uint8_t log[LOG_NUM_ROWS][LOG_ROW_SIZE];
+
+uint8_t *get_ble_log(void) {
+    return (void*)log;
+}
+
+static void log_packet(uint8_t *packet) {
+    static int i = 0;
+
+    if (log_enabled) {
+        uint8_t size = packet[0];
+
+        memcpy(log[i], packet, size + 1);
+
+        if (++i >= LOG_NUM_ROWS) {
+            i = 0;
+        }
+
+        memset(log[i], 0, LOG_ROW_SIZE);
+    }
+}
+
 // processes an event received from the Bluetooth chip
 static void handle_event(uint8_t *packet) {
     uint8_t event = packet[0];
@@ -1670,6 +1702,8 @@ start:
         write_xfer_size = 0;

         if (read_xfer_size) {
+            log_packet(&read_buf[2]);
+
             // handle the received data
             if (read_buf[NPI_SPI_HEADER_LEN] == HCI_EVENT_PACKET) {
                 handle_event(&read_buf[NPI_SPI_HEADER_LEN + 1]);
@@ -1698,6 +1732,8 @@ HCI_StatusCodes_t HCI_sendHCICommand(uint16_t opcode, uint8_t *pData, uint8_t da
         memcpy(&write_buf[6], pData, dataLength);
     }

+    log_packet(&write_buf[1]);
+
     uint8_t checksum = 0;
     for (int i = 1; i < dataLength + 6; i++) {
         checksum ^= write_buf[i];
diff --git a/pybricks/util_pb/pb_task.c b/pybricks/util_pb/pb_task.c
index 73b58558..f47089b9 100644
--- a/pybricks/util_pb/pb_task.c
+++ b/pybricks/util_pb/pb_task.c
@@ -1,5 +1,6 @@
 // SPDX-License-Identifier: MIT
 // Copyright (c) 2021 The Pybricks Authors
+#include <stdio.h>

 #include <pbio/error.h>
 #include <pbio/task.h>
@@ -12,6 +13,29 @@

 #include <pybricks/util_pb/pb_error.h>

+#define LOG_NUM_ROWS 128
+#define LOG_ROW_SIZE 32
+
+uint8_t *get_ble_log(void);
+
+static void print_log(void) {
+    uint8_t *buf = get_ble_log();
+
+    for (int i = 0; i < LOG_NUM_ROWS; i++) {
+        uint8_t size = buf[i * LOG_ROW_SIZE] + 1;
+
+        if (size == 1) {
+            break;
+        }
+
+        for (int j = 0; j < size; j++) {
+            printf("%02X ", buf[i * LOG_ROW_SIZE + j]);
+        }
+
+        printf("\n");
+    }
+}
+
 /**
  * Waits for a task to complete.
  *
@@ -31,6 +55,11 @@ void pb_wait_task(pbio_task_t *task, mp_int_t timeout) {

             if (task->status != PBIO_ERROR_AGAIN) {
                 nlr_pop();
+
+                if (task->status != PBIO_SUCCESS) {
+                    print_log();
+                }
+
                 pb_assert(task->status);
                 return;
             }
@@ -44,6 +73,7 @@ void pb_wait_task(pbio_task_t *task, mp_int_t timeout) {
         while (task->status == PBIO_ERROR_AGAIN) {
             MICROPY_VM_HOOK_LOOP
         }
+        print_log();

         nlr_jump(nlr.ret_val);
     }
dlech commented 3 years ago

The first byte is the length of the packet, the 2nd byte is the packet type, 0x01 is a command to the Bluetooth chip and 0x04 is an event received. On 0x01, the next two bytes are the opcode in little-endian order, e.g. 0xFE04 (this is a TI vendor-specific command, see link below). On 0x04 packets, the next byte is the event type. 0xFF means a vendor-specific event. This is followed by a 1-byte length and a 2-byte opcode as before, e.g. 0x067F is a command status that indicates that the command was received.

Here is the guide for vendor specific commands: http://software-dl.ti.com/lprf/simplelink_cc2640r2_sdk/1.30.00.25/exports/docs/blestack/TI_BLE_Vendor_Specific_HCI_Guide.pdf

dlech commented 3 years ago

07 01 04 FE 03 03 01 00

GAP Device Discovery Request

0B 01 1B FD 07 00 00 00 18 00 0D 0A

ATT Handle Value Notification

09 04 FF 06 7F 06 00 04 FE 00

command status for GAP Device Discovery Request

09 04 FF 06 7F 06 00 1B FD 00

command status for ATT Handle Value Notification

0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00

ATT Handle Value Notification

...

Repeats

04 01 05 FE 00

GAP Device Discovery Cancel

09 04 FF 06 7F 06 00 05 FE 00

command status for GAP Device Discovery Cancel

dlech commented 3 years ago

So we are sending the command to start scanning, but no advertising data is ever received from the Bluetooth chip. The value notifications are status updates going to Pybricks Code every 0.5 seconds.

mateusz commented 3 years ago

I wonder if it's something to do with - the remote detects there is interference on some channels (is that how BLE works? no idea), and transmits on something unsaturated, which happens to not be supported by pybricks driver? Which would then be caused by whatever devices I have at home (and you don't). This is kind of supported by no apparent LEGO device differences between you and and me, and that it only affects the firmware (but not the pybricksdev, which presumably uses mac/win drivers). But then what doesn't fit is that it talks ok with the TechnicHub. Eek 🙈

I'll try to go out of range of BT devices later in the evening, to see if it changes anything.

dlech commented 3 years ago

If another device is advertising, there should be 0x060D messages like this (this one is probably my Android phone):

1D 04 FF 1A 0D 06 00 00 01 59 0E 8F 98 2E 4C CF 0D 02 01 02 03 03 50 FE 05 16 50 FE BB 30

So if you have any other BLE devices, you could try making them advertise while running this as well and see if they get picked up.

Even though the radio firmware versions say they are the same between our hubs, I'm still a little bit suspicious that they might actually not be exactly the same and that somehow the command to start scanning isn't actually working on your Bluetooth chip.

dlech commented 3 years ago

The fact that the official LEGO firmware can connect on the same hub though tells me there isn't any kind of interference issue or anything like that. Either we're missing some config command or doing things in the wrong order or have some timing issue that makes Pybricks different from the official LEGO firmware (or between my hub running Pybricks firmware and your hub running Pybricks firmware).

dlech commented 3 years ago

Here is the beginning of the log for my City hub. One difference I notice is it is missing 0B 01 1B FD 07 00 00 00 18 00 0D 0A.

07 01 04 FE 03 03 01 00 
09 04 FF 06 7F 06 00 1B FD 00 
09 04 FF 06 7F 06 00 04 FE 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00

0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 is the hub status message going to Pybricks Code that I already mentioned (writing 00 40 00 00 00 to attribute handle 0x0012), but 0B 01 1B FD 07 00 00 00 18 00 0D 0A is writing 0D 0A to attribute handle 0x0018. This is the Nordic UART Service (NUS) that is used by the terminal in Pybricks Code. 0D 0A is \r\n (newline). So make sure there are no print statements before Remote() in your program to eliminate this a a possible cause for the issue.

mateusz commented 3 years ago

Ok, this is weird. I've flashed your debug firmware, but flipped the "include current program" switch. The program is below. Then I started the hub's flashed program with the hub button (without connecting to beta.pybricks.com) and then confirming the LED is "breathing" on the hub, turned on the remote - and it paired immediately (the program keeps runnning indefinitely, so I presume it got to the infinite loop phase and it did not timeout. The LED is solid blue on the remote).

Connecting beta.pybricks.com to the hub, and running the same program with the "play" button, the remote does not connect as usual.

from pybricks.pupdevices import Remote

remote = Remote()

while True:
    pass
dlech commented 3 years ago

Connecting beta.pybricks.com to the hub, and running the same program with the "play" button, the remote does not connect as usual.

Is the debug log the same in this case?

mateusz commented 3 years ago

It actually works after flashing with both v3.1.0a4 and your doctored version... Dump below.

MicroPython v3.1.0a4-37-gaf4a1d78-dirty on 2021-09-19; Powered Up City Hub with STM32F030RC
Type "help()" for more information.
...
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 60 00 00 00 
04 01 05 FE 00 
09 04 FF 06 7F 06 00 1B FD 00 
09 04 FF 06 7F 06 00 05 FE 00 
07 01 04 FE 03 03 01 00 
09 04 FF 06 7F 06 00 1B FD 00 
09 04 FF 06 7F 06 00 04 FE 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
04 01 05 FE 00 
09 04 FF 06 7F 06 00 05 FE 00 
07 01 04 FE 03 03 01 00 
09 04 FF 06 7F 06 00 1B FD 00 
09 04 FF 06 7F 06 00 04 FE 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
0E 01 1B FD 0A 00 00 00 12 00 00 40 00 00 00 
09 04 FF 06 7F 06 00 1B FD 00 
04 01 05 FE 00 
09 04 FF 06 7F 06 00 05 FE 00
mateusz commented 3 years ago

I guess that means I can use it as long as I flash it in, instead of running from web IDE. That's great to know, and funny we've never actually tried that...

pqhf5kd commented 3 years ago

Well this is certainly strange. I had previously tested 'include current program' and had no luck connecting the remote.

I've just tried again after Matuesz comment and it's now working.

dlech commented 3 years ago

So to recap, is this correct?

dlech commented 3 years ago

It actually works after flashing with both v3.1.0a4 and your doctored version... Dump below.

Can you repeat this and end the program much earlier? The log buffer has a fixed size and loops when it gets full, so it looks like it wrote over the interesting part at the beginning.