smp.py: invalid SMP command during pairing

[jakubwitowski]

The following problem was discovered when writing pairing-related pytests. The DUT is a Zephyr-based device that supports BT_SMP_IO_DISPLAY_ONLY and BT_SMP_IO_DISPLAY_YESNO I/O capabilities, meaning the corresponding static struct bt_conn_auth_cb definitions are provided:

static struct bt_conn_auth_cb conn_auth_callbacks = {
	.cancel = auth_canceled,
	.passkey_display = auth_passkey_display,
	.passkey_confirm = auth_passkey_confirm,
};

The test scenario looks as follows:

@pytest.mark.asyncio
async def test_pairing_dut_has_display_and_yesno_button(
    dut_bt_address: str,
    bumble_device: bumble.device.Device,
):
    pairing_cfg = PairingConfig(
        sc=True,
        mitm=True,
        bonding=False,
        delegate=PairingDelegate(
            PairingDelegate.IoCapability.DISPLAY_OUTPUT_AND_KEYBOARD_INPUT,
            PairingDelegate.KeyDistribution.DISTRIBUTE_ENCRYPTION_KEY
            | PairingDelegate.KeyDistribution.DISTRIBUTE_IDENTITY_KEY
            | PairingDelegate.KeyDistribution.DISTRIBUTE_SIGNING_KEY
            | PairingDelegate.KeyDistribution.DISTRIBUTE_LINK_KEY,
        ),
    )
    bumble_device.pairing_config_factory = lambda connection: pairing_cfg

    logger.info(f"=== Connecting to {dut_bt_address}...")
    async with bumble_device.connect_as_gatt(dut_bt_address) as peer:
        logger.info(f"=== Connected to {peer}")

        await peer.connection.pair()
        logger.info(f"=== Paired with {peer}")

When SMP pairing is initiated (BT_SMP_CMD_PAIRING_REQ) by the bumble, the I/O capabilities are exchanged and BT_SMP_CMD_PUBLIC_KEY is sent by the bumble as well. Then, for some reason the SMP_PAIRING_CONFIRM_COMMAND is sent, followed by SMP_PAIRING_RANDOM_COMMAND.

From my investigation, the SMP_PAIRING_CONFIRM_COMMAND is invalid here and only the SMP_PAIRING_RANDOM_COMMAND shall be sent instead.

This is the shortened log, where the described problem occurs:

• pairing initiator -> bumble used in the pytest
• DUT -> Zephyr based device

[00:00:17.536,529] <dbg> bt_smp: Received SMP code 0x01 len 6
[00:00:17.536,529] <dbg> bt_smp: BT_SMP_CMD_PAIRING_REQ
[00:00:17.536,529] <dbg> bt_smp: smp_pairing_req: req: io_capability 0x04, oob_flag 0x00, auth_req 0x0C, max_key_size 0x10, init_key_dist 0x0F, resp_key_dist 0x03
[00:00:17.537,719] <dbg> bt_smp: smp_init: prnd 35238b5f001588ea86549bb97955a2f4
[00:00:17.537,719] <dbg> bt_smp: smp_pairing_req: rsp: io_capability 0x01, oob_flag 0x00, auth_req 0x0C, max_key_size 0x10, init_key_dist 0x00, resp_key_dist 0x00
[00:00:17.717,529] <dbg> bt_smp: Received SMP code 0x0c len 64
[00:00:17.717,529] <dbg> bt_smp: BT_SMP_CMD_PUBLIC_KEY
[00:00:17.717,529] <dbg> bt_smp: smp_public_key: 
[00:00:17.717,529] <dbg> bt_smp: SMP METHOD 3
[00:00:17.717,529] <dbg> bt_smp: bt_smp_dhkey_ready: 0x812f9e7
[00:00:17.836,547] <dbg> bt_smp: Received SMP code 0x03 len 16
[00:00:17.836,547] <dbg> bt_smp: BT_SMP_CMD_PAIRING_CONFIRM -> The SMP_PAIRING_RANDOM_COMMAND shall be sent instead
[00:00:17.836,547] <wrn> bt_smp: Unexpected SMP code 0x03

Then the SMP_PAIRING_RANDOM_COMMAND is sent by the bumble, but the pairing is already
failed due to reception of unexpeted SMP command (BT_SMP_CMD_PAIRING_CONFIRM)

This is the shortened log, where everything works as expected:

• pairing initiator -> Android-based smartphone
• DUT -> Zephyr based device

[00:00:03.423,431] <err> bt_smp: Received SMP code 0x01 len 6
[00:00:03.423,461] <err> bt_smp: BT_SMP_CMD_PAIRING_REQ
[00:00:03.423,492] <dbg> bt_smp: smp_pairing_req: req: io_capability 0x04, oob_flag 0x00, auth_req 0x2D, max_key_size 0x10, init_key_dist 0x0F, resp_key_dist 0x0F
[00:00:03.423,706] <dbg> bt_smp: smp_init: prnd 32a05f18349f948ad48af2b75e3f0cd1
[00:00:03.423,736] <dbg> bt_smp: smp_pairing_req: rsp: io_capability 0x01, oob_flag 0x00, auth_req 0x0C, max_key_size 0x10, init_key_dist 0x00, resp_key_dist 0x00
[00:00:03.694,061] <err> bt_smp: Received SMP code 0x0c len 64
[00:00:03.694,091] <err> bt_smp: BT_SMP_CMD_PUBLIC_KEY
[00:00:03.694,122] <dbg> bt_smp: smp_public_key: 
[00:00:03.694,183] <err> bt_smp: SMP METHOD 3
[00:00:03.720,855] <dbg> bt_smp: bt_smp_dhkey_ready: 0x2000fad5
[00:00:03.873,504] <err> bt_smp: Received SMP code 0x04 len 16
[00:00:03.873,535] <err> bt_smp: BT_SMP_CMD_PAIRING_RANDOM
[00:00:03.873,565] <dbg> bt_smp: smp_pairing_random: 
[00:00:03.875,061] <inf> pairing: Confirm passkey for bt_conn_id=0: 662289

I am also attaching the full twister log: twister.log

[barbibulle]

Thanks for reporting this. You are right, the BT_SMP_CMD_PAIRING_CONFIRM message should not have been sent here. Interestingly, we never noticed before, because this message didn't cause any issues with iOS and Android (both just ignored it).
PR #582 fixes the issue. Can you verify that on your end?

[jakubwitowski]

@barbibulle thanks a lot. I will verify it today and let You know about the results :)

[jakubwitowski]

It is working as expected now. Thanks !