NFC and enforcing L4 security

I want to get the peripheral side of my dual-role gateway device to accept ONLY NFC (LESC) pairing from my Android phone.

I have had NFC working but it seems I keep breaking it with configurations for other things.

The issue seems to come and go, so I've gone back to the original peripheral_nfc_pairing example, but now even that fails the pairing connection. It apparently tries 3-times as the nRF Connect app shows the "NOT BONDED" text change quickly 3-times and then fails pairing. It's as if the keys don't match.

Q:How can I debug this. I can't seem to find what configuration to enable to debug the NFC/TNEP/OOB.

When it WAS working, the app was able to discover services during the time it was waiting for confirmation of whether to try pairing. Another BLE Scanner will discover and populate all the services during that same period. I had been testing where to place bt_conn_disconnect(conn, BT_HCI_ERR_AUTH_FAIL); calls to more quickly avoid that discovery. Calling it from the security_changed and the pairing_failed callbacks.
Is this correct?

Q: Is there a way to force NFC-ONLY pairing? It seems the default security level is 1 when the connect callback occurs, at which point I set_security to L4, but that still leaves the connection active for a time in low security such that it allows discovery to happen.

Q: Is there a way to force the connection to only use high-security and to allow connections if-and-only-if NFC has succeeded?

Parents

0 Sigurd over 4 years ago
Hi,

Try to delete the keys on both phone and nrF device(try do a nrfjprog --eraseall, before programming the sample again). For debugging this, try to set these:

CONFIG_BT_LOG_LEVEL_DBG=y CONFIG_BT_DEBUG_SMP=yCONFIG_BT_DEBUG_LOG=y
CONFIG_BT_DEBUG_CONN=y

CONFIG_DEBUG=y CONFIG_LOG=y CONFIG_LOG_BUFFER_SIZE=8192

Also try to set:

CONFIG_BT_SMP_SC_ONLY

There is a "Secure Connections Only mode" sample in zephyr you can have a look at:

https://github.com/nrfconnect/sdk-zephyr/tree/main/samples/bluetooth/peripheral_sc_only
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel

0 Caycee over 4 years ago in reply to Sigurd

Still no joy... (and I always use --chiperase when programming)

The peripheral_sc_only example connects without asking for PassKey. At first it may disconnect, but it will connect on second or third try and the terminal displays "Security failed: <mac-address> (random) level 1 err 5"

Here's a log of the peripheral_nfc_pairing attempt with NFC with all the above configs enabled...

T4 field Off
T4 field Off
[00:01:34.606,384] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
[00:01:35.117,126] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
T4 field Off
T4 field Off
[00:01:35.627,624] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
[00:01:36.138,092] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
T4 field Off
T4 field Off
T4 field Off
T4 field ON
T4 field Off
T4 field Off
T4 field Off
T4 field Off
T4 field ON
T4 field ON
T4 field READ
Regular advertising started
[00:01:36.648,559] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
[00:01:37.159,088] [0m<dbg> nfc_tnep_tag: tnep_sm_service_readyT4 field Off
: TNEP Service Ready[0m
[00:01:37.172,027] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0mT4 field Off

[00:01:37.189,117] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
[00:037.472,198] [0m<dbg> sdc_hci_driver: event_packet_process: Command Complete (0x2005) status: 0x00, ncmd: 1, len 4[0m
[00:01:37.472,229] [0m<dbg> bt_hci_core: bt_recv: buf 0x2000aaf4 len 6[0m
[00:01:37.472,259] [0m<dbg> bt_hci_core: hci_cmd_complete: opcode 0x2005[0m
[00:01:37.472,259] [0m<dbg> bt_hci_core: hci_cmd_done: opcode 0x20alling sem_take_wait[0m
[00:01:37.472,717] [0m<dbg> bt_hci_core: send_cmd: Sending command 0x2006 (buf 0x2000aaf4) to driver[0m
[00:01:37.472,747] [0m<dbg> bt_hci_core: bt_send: buf 0x2000aaf4 len 18 type 0[0m
[00:01:37.472,747] [0m<dbg> sdc_hci_driver: hci_driver_send: [0m
[00:01:37.472,778] [0m<dbg> sdc_hci_driver: cmd_handle: [0m
[00:01:37.472,869] [0m<dbg> sdc_hci_driver: hci_driver_send: Exit: 0[0m
[00:01:37.472,869] [0m<dbg> bt_hci_core: process_events: ev->state 0[0m
[00:01:37.4: opcode 0x2009 param_len 32[0m
[00:01:37.473,999] [0m<dbg> bt_hci_core: bt_hci_cmd_create: buf 0x2000aaf4[0m
[00:01:37.474,029] [0m<dbg> bt_hci_core: bt_hci_cmd_send_sync: buf 0x2000aaf4 opcode 0x2009 len 35[0m
[00:01:37.474,090] [0m<dbg> bt_hci_core: process_events: count 2[0m
[00:01:37.474,121] [0m<dbg> bt_hci_core: process_events: ev->state 4[0m
[00:01:37.474,121] [0m<dbg> bt_hci_core: send_cmd: calling net_buf_get[0m
[00:01:37.474,151] [0m<dbg> bt_hci_core: send_cmd: calling sem_take_wait[0m
[00:01:37.474,151] [0m<dbg> bt_hci_core: send_cmd: Sending command 0x2009 (buf 0x2000aaf4) to driver[0m
[00:01:37.474,182] [0m<dbg> bt_hci_core: bt_send: buf 0x2000aaf4 len 35 type 0[0m
[00:01:37.474,182] [0m<dbg> sdc_hci_driver: hci_driver_send: [0m
[00:01:37.474,212] [0m<dbg> sdc_hci_driver: cmd_handle: [0m
[00:01:37.474,273] [0m<dbg> sdc_hci_driver: hci_driver_send: Exit: 0[0m
[00:01:37.474,304] [0m<dbg> bt_hci_core: process_events: ev->state 0[0m
[00:01:37.474,365] [0m<dbg> sdc_hci_driver: event_packet_process: Command Complete (0x2009) status: 0x00, ncmd: 1, len 4[0m
[00:01:37.474,365] [0m<dbg> bt_hci_core: bt_recv: buf 0x2000aaf4 len 6[0m
[00:01:37.474,395] [0m<dbg> bt_hci_core: hci_cmd_complete: opcode 0x2009[0m
[00:01:37.474,395] [0m<dbg> bt_hci_core: hci_cmd_done: opcode 0x2009 status 0x00 buf 0x2000aaf4[0m
[00:01:37.474,578] [0m<dbg> bt_conn: bt_conn_prepare_events: [0m
[00:01:37.474,609] [0m<dbg> bt_hci_core: hci_tx_thread: Calling k_poll with 2 events[0m
[00:01:37.474,639] [0m<dbg> bt_hci_core: bt_hci_cmd_send_sync: rsp 0x2000aaf4 opcode 0x2009 len 1[0m
[00:01:37.474,700] [0m<dbg> bt_conn: bt_conn_set_state: disconnected -> connecting-adv[0m
[00:01:37.474,700] [0m<dbg> bt_conn: bt_conn_ref: handle 0 ref 1 -> 2[0m
[00:01:37.474,731] [0m<dbg> bt_hci_core: bt_hci_cmd_create: opcode 0x200a param_len 1[0m
[00:01:37.474,761] [0m<dbg> bt_hci_core: bt_hci_cmd_create: buf 0x2000aaf4[0m
[00:01:37.474,761] [0m<dbg> bt_hci_core: bt_hci_cmd_send_sync: buf 0x2000aaf4 opcode 0x200a len 4[0m
[00:01:37.474,853] [0m<dbg> bt_hci_core: process_events: count 2[0m
[00:01:37.474,853] [0m<dbg> bt_hci_core: process_events: ev->state 4[0m
[00:01:37.474,884] [0m<dbg> bt_hci_core: send_cmd: calling net_buf_get[0m
[00:01:37.474,914] [0m<dbg> bt_hci_core: send_cmd: calling sem_take_wait[0m
[00:01:37.474,914] [0m<dbg> bt_hci_core: send_cmd: Sending command 0x200a (buf 0x2000aaf4) to driver[0m
[00:01:37.474,945] [0m<dbg> bt_hci_core: bt_send: buf 0x2000aaf4 len 4 type 0[0m
[00:01:37.474,945] [0m<dbg> sdc_hci_driver: hci_driver_send: [0m
[00:01:37.474,975] [0m<dbg> sdc_hci_driver: cmd_handle: [0m
[00:01:37.475,128] [0m<dbg> sdc_hci_driver: hci_driver_send: Exit: 0[0m
[00:01:37.475,158] [0m<dbg> bt_hci_core: process_events: ev->state 0[0m
[00:01:37.475,189] [0m<dbg> sdc_hci_driver: event_packet_process: Command Complete (0x200a) status: 0x00, ncmd: 1, len 4[0m
[00:01:37.475,219] [0m<dbg> bt_hci_core: bt_recv: buf 0x2000aaf4 len 6[0m
[00:01:37.475,250] [0m<dbg> bt_hci_core: hci_cmd_complete: opcode 0x200a[0m
[00:01:37.475,250] [0m<dbg> bt_hci_core: hci_cmd_done: opcode 0x200a status 0x00 buf 0x2000aaf4[0m
[00:01:37.475,463] [0m<dbg> bt_conn: bt_conn_prepare_events: [0m
[00:01:37.475,463] [0m<dbg> bt_hci_core: hci_tx_thread: Calling k_poll with 2 events[0m
[00:01:37.475,524] [0m<dbg> bt_hci_core: bt_hci_cmd_send_sync: rsp 0x2000aaf4 opcode 0x200a len 1[0m
[00:01:37.475,524] [0m<dbg> bt_conn: bt_conn_unref: handle 0 ref 2 -> 1[0m
[00:01:37.493,164] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
[00:01:37.504,638] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
[00:01:37.517,852] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
[00:01:37.534,973] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
[00:01:37.881,072] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
cting-adv[0m
[00:01:37.474,700] [0m<dbg> bt_conn: bt_conn_ref: handle 0 ref 1 -> 2[0m
[00:01:37.474,731] [0m<dbg> bt_hci_core: bt_hci_cmd_create: opcode 0x200a param_len 1[0m
[00:01:37.474,761] [0m<dbg> bt_hci_core: bt_hci_cmd_create: buf 0x2000aaf4[0m
[00:01:37.474,761] [0m<dbg> bt_hci_core: bt_hci_cmd_send_sync: buf 0x2000aaf4 opcode 0x200a len 4[0m
[00:01:37.474,853] [0m<dbg> bt_hci_core: process_events: count 2[0m
[00:01:37.474,853] [0m<dbg> bt_hci_core: process_events: ev->state 4[0m
[0cting-adv[0m
[00:01:37.474,700] [0m<dbg> bt_conn: bt_conn_ref: handle 0 ref 1 -> 2[0m
[00:01:37.474,731] [0m<dbg> bt_hci_core: bt_hci_cmd_create: opcode 0x200a param_len 1[0m
[00:01:37.474,761] [0m<dbg> bt_hci_core: bt_hci_cmd_create: buf 0x2000aaf4[0m
[00:01:37.474,761] [0m<dbg> bt_hci_core: bt_hci_cmd_send_sync: buf 0x2000aaf4 opcode 0x200a len 4[0m
[00:01:37.474,853] [0m<dbg> bt_hci_core: process_events: count 2[0m
[00:01:37.474,853] [0m<dbg> bt_hci_core: process_events: ev->state 4[0m
[00:01:37.474,884] [0m<dbg> bt_hci_core: send_cmd: calling net_buf_get[0m
[00:01:37.474,914] [0m<dbg> bt_hci_core: send_cmd: calling sem_take_wait[0m
[00:01:37.474,914] [0m<dbg> bt_hci_core: send_cmd: Sending command 0x200a (buf 0x2000aaf4) to driver[0m
[00:01:37.474,945] [0m<dbg> bt_hci_core: bt_send: buf 0x2000aaf4 len 4 type 0[0m
[00:01:37.474,945] [0m<dbg> sdc_hci_driver: hci_driver_send: [0m
[00:01:37.474,975] [0m<dbg> sdc_hci_driver: cmd_handle: [0m
[00:01:37.475,128] [0m<dbg> sdc_hci_driver: hci_driver_send: Exit: 0[0m
[00:01:37.475,158] [0m<dbg> bt_hci_core: process_events: ev->state 0[0m
[00:01:37.475,189] [0m<dbg> sdc_hci_driver: event_packet_process: Command Complete (0x200a) status: 0x00, ncmd: 1, len 4[0m
[00:01:37.475,219] [0m<dbg> bt_hci_core: bt_recv: buf 0x2000aaf4 len 6[0m
[00:01:37.475,250] [0m<dbg> bt_hci_core: hci_cmd_complete: opcode 0x200a[0m
[00:01:37.475,250] [0m<dbg> bt_hci_core: hci_cmd_done: opcode 0x200a status 0x00 buf 0x2000aaf4[0m
[00:01:37.475,463] [0m<dbg> bt_conn: bt_conn_prepare_events: [0m
[00:01:37.475,463] [0m<dbg> bt_hci_core: hci_tx_thread: Calling k_poll with 2 events[0m
[00:01:37.475,524] [0m<dbg> bt_hci_core: bt_hci_cmd_send_sync: rsp 0x2000aaf4 opcode 0x200a len 1[0m
[00:01:37.475,524] [0m<dbg> bt_conn: bt_conn_unref: handle 0 ref 2 -> 1[0m
[00:01:37.493,164] [0m<dbg>cting-adv[0m
[00:01:37.474,700] [0m<dbg> bt_conn: bt_conn_ref: handle 0 ref 1 -> 2[0m
[00:01:37.474,731] [0m<dbg> bt_hci_core: bt_hci_cmd_create: opcode 0x200a param_len 1[0m
[00:01:37.474,761] [0m<dbg> bt_hci_core: bt_hci_cmd_create: buf 0x2000aaf4[0m
[00:01:37.474,761] [0m<dbg> bt_hci_core: bt_hci_cmd_send_sync: buf 0x2000aaf4 opcode 0x200a len 4[0m
[00:01:37.474,853] [0m<dbg> bt_hci_core: process_events: count 2[0m
[00:01:37.474,853] [0m<dbg> bt_hci_core: process_events: ev->state 4[0m
[00:01:37.474,884] [0m<dbg> bt_hci_core: send_cmd: calling net_buf_get[0m
[00:01:37.474,914] [0m<dbg> bt_hci_core: send_cmd: calling sem_take_wait[0m
[00:01:37.474,914] [0m<dbg> bt_hci_core: send_cmd: Sending command 0x200a (buf 0x2000aaf4) to driver[0m
[00:01:37.474,945] [0m<dbg> bt_hci_core: bt_send: buf 0x2000aaf4 len 4 typecting-adv[0m
[00:01:37.474,700] [0m<dbg> bt_conn: bt_conn_ref: handle 0 ref 1 -> 2[0m
[00:01:37.474,731] [0m<dbg> bt_hci_core: bt_hci_cmd_create: opcode 0x200a param_len 1[0m
[00:01:37.474,761] [0m<dbg> bt_hci_core: bt_hci_cmd_create: buf 0x2000aaf4[0m
[00:01:37.474,761] [0m<dbg> bt_hci_core: bt_hci_cmd_send_sync: buf 0x2000aaf4 opcode 0x200a len 4[0m
[00:01:37.474,853] [0m<dbg> bt_hci_core: process_events: count 2[0m
[00:01:37.474,853] [0m<dbg> bt_hci_core: process_events: ev->scting-adv[0m
[00:01:37.474,700] [0m<dbg> bt_conn: bt_conn_ref: handle 0 ref 1 -> 2[0m
[00:01:37.474,731] [0m<dbg> bt_hci_core: bt_hci_cmd_create: opcode 0x200a param_len 1[0m
[00:01:37.474,761] [0m<dbg> bt_hci_core: bt_hci_cmd_create: buf 0x2000aaf4[0m
[00:01:37.474,761] [0m<dbg> bt_hci_core: bt_hci_cmd_send_sync: buf 0x2000aaf4 opcode 0x200a len 4[0m
[00:01:37.474,853] [0m<dbg> bt_hci_core: process_events: count 2[0m
[00:01:37.474,853] [0m<dbg> bt_hci_core: process_events: ev->state 4[0m
[00:01:37.474,884] [0m<dbg> bt_hci_core: send_cmd: calling net_buf_get[0m
[00:01:37.474,914] [0m<dbg> bt_hci_core: send_cmd: calling sem_take_wait[0m
[00:01:37.474,914] [0m<dbg> bt_hci_core: send_cmd: Sending command 0x200a (buf 0x2000aaf4) to driver[0m
[00:01:37.474,945] [0m<dbg> bt_hci_core: bt_send: buf 0x2000aaf4 len 4 type 0[0m
[00:01:37.474,945] [0m<dbg> sdc_hci_driver: hci_driver_send: [0m
[00:01:37.474,975] [0m<dbg> sdc_hci_driver: cmd_handle: [0m
[00:01:37.475,128] [0m<dbg> sdc_hci_driver: hci_driver_send: Exit: 0[0m
[00:01:37.475,158] [0m<dbg> bt_hci_core: process_events: ev->state 0[0m
[00:01:37.475,189] [0m<dbg> sdc_hci_driver: event_packT4 field Off
T4 field Off
T4 field Off
T4 field ON
T4 field Off
T4 field Off
T4 field Off
T4 field Off
T4 field ON
T4 field ON
T4 field READ
Regular advertising started
T4 field ON
[00:01:46.558,624] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
[00:01:46.583,862] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
[00:01:46.597,045] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
[00:01:46.614,196] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
[00:01:46.620,117] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
[00:01:46.654,724] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
[00:01:46.793,090] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
[00:01:46.806,243] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
[00:01:46.823,364] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
[00:01:46.840,209] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
[00:01:46.900,360] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
T4 field Off
[00:01:47.226,715] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m

T4 field Off

Reply

0 Caycee over 4 years ago in reply to Sigurd

Still no joy... (and I always use --chiperase when programming)

Here's a log of the peripheral_nfc_pairing attempt with NFC with all the above configs enabled...

T4 field Off
T4 field Off
[00:01:34.606,384] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
[00:01:35.117,126] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
T4 field Off
T4 field Off
[00:01:35.627,624] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
[00:01:36.138,092] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
T4 field Off
T4 field Off
T4 field Off
T4 field ON
T4 field Off
T4 field Off
T4 field Off
T4 field Off
T4 field ON
T4 field ON
T4 field READ
Regular advertising started
[00:01:36.648,559] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
[00:01:37.159,088] [0m<dbg> nfc_tnep_tag: tnep_sm_service_readyT4 field Off
: TNEP Service Ready[0m
[00:01:37.172,027] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0mT4 field Off

[00:01:37.189,117] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
[00:037.472,198] [0m<dbg> sdc_hci_driver: event_packet_process: Command Complete (0x2005) status: 0x00, ncmd: 1, len 4[0m
[00:01:37.472,229] [0m<dbg> bt_hci_core: bt_recv: buf 0x2000aaf4 len 6[0m
[00:01:37.472,259] [0m<dbg> bt_hci_core: hci_cmd_complete: opcode 0x2005[0m
[00:01:37.472,259] [0m<dbg> bt_hci_core: hci_cmd_done: opcode 0x20alling sem_take_wait[0m
[00:01:37.472,717] [0m<dbg> bt_hci_core: send_cmd: Sending command 0x2006 (buf 0x2000aaf4) to driver[0m
[00:01:37.472,747] [0m<dbg> bt_hci_core: bt_send: buf 0x2000aaf4 len 18 type 0[0m
[00:01:37.472,747] [0m<dbg> sdc_hci_driver: hci_driver_send: [0m
[00:01:37.472,778] [0m<dbg> sdc_hci_driver: cmd_handle: [0m
[00:01:37.472,869] [0m<dbg> sdc_hci_driver: hci_driver_send: Exit: 0[0m
[00:01:37.472,869] [0m<dbg> bt_hci_core: process_events: ev->state 0[0m
[00:01:37.4: opcode 0x2009 param_len 32[0m
[00:01:37.473,999] [0m<dbg> bt_hci_core: bt_hci_cmd_create: buf 0x2000aaf4[0m
[00:01:37.474,029] [0m<dbg> bt_hci_core: bt_hci_cmd_send_sync: buf 0x2000aaf4 opcode 0x2009 len 35[0m
[00:01:37.474,090] [0m<dbg> bt_hci_core: process_events: count 2[0m
[00:01:37.474,121] [0m<dbg> bt_hci_core: process_events: ev->state 4[0m
[00:01:37.474,121] [0m<dbg> bt_hci_core: send_cmd: calling net_buf_get[0m
[00:01:37.474,151] [0m<dbg> bt_hci_core: send_cmd: calling sem_take_wait[0m
[00:01:37.474,151] [0m<dbg> bt_hci_core: send_cmd: Sending command 0x2009 (buf 0x2000aaf4) to driver[0m
[00:01:37.474,182] [0m<dbg> bt_hci_core: bt_send: buf 0x2000aaf4 len 35 type 0[0m
[00:01:37.474,182] [0m<dbg> sdc_hci_driver: hci_driver_send: [0m
[00:01:37.474,212] [0m<dbg> sdc_hci_driver: cmd_handle: [0m
[00:01:37.474,273] [0m<dbg> sdc_hci_driver: hci_driver_send: Exit: 0[0m
[00:01:37.474,304] [0m<dbg> bt_hci_core: process_events: ev->state 0[0m
[00:01:37.474,365] [0m<dbg> sdc_hci_driver: event_packet_process: Command Complete (0x2009) status: 0x00, ncmd: 1, len 4[0m
[00:01:37.474,365] [0m<dbg> bt_hci_core: bt_recv: buf 0x2000aaf4 len 6[0m
[00:01:37.474,395] [0m<dbg> bt_hci_core: hci_cmd_complete: opcode 0x2009[0m
[00:01:37.474,395] [0m<dbg> bt_hci_core: hci_cmd_done: opcode 0x2009 status 0x00 buf 0x2000aaf4[0m
[00:01:37.474,578] [0m<dbg> bt_conn: bt_conn_prepare_events: [0m
[00:01:37.474,609] [0m<dbg> bt_hci_core: hci_tx_thread: Calling k_poll with 2 events[0m
[00:01:37.474,639] [0m<dbg> bt_hci_core: bt_hci_cmd_send_sync: rsp 0x2000aaf4 opcode 0x2009 len 1[0m
[00:01:37.474,700] [0m<dbg> bt_conn: bt_conn_set_state: disconnected -> connecting-adv[0m
[00:01:37.474,700] [0m<dbg> bt_conn: bt_conn_ref: handle 0 ref 1 -> 2[0m
[00:01:37.474,731] [0m<dbg> bt_hci_core: bt_hci_cmd_create: opcode 0x200a param_len 1[0m
[00:01:37.474,761] [0m<dbg> bt_hci_core: bt_hci_cmd_create: buf 0x2000aaf4[0m
[00:01:37.474,761] [0m<dbg> bt_hci_core: bt_hci_cmd_send_sync: buf 0x2000aaf4 opcode 0x200a len 4[0m
[00:01:37.474,853] [0m<dbg> bt_hci_core: process_events: count 2[0m
[00:01:37.474,853] [0m<dbg> bt_hci_core: process_events: ev->state 4[0m
[00:01:37.474,884] [0m<dbg> bt_hci_core: send_cmd: calling net_buf_get[0m
[00:01:37.474,914] [0m<dbg> bt_hci_core: send_cmd: calling sem_take_wait[0m
[00:01:37.474,914] [0m<dbg> bt_hci_core: send_cmd: Sending command 0x200a (buf 0x2000aaf4) to driver[0m
[00:01:37.474,945] [0m<dbg> bt_hci_core: bt_send: buf 0x2000aaf4 len 4 type 0[0m
[00:01:37.474,945] [0m<dbg> sdc_hci_driver: hci_driver_send: [0m
[00:01:37.474,975] [0m<dbg> sdc_hci_driver: cmd_handle: [0m
[00:01:37.475,128] [0m<dbg> sdc_hci_driver: hci_driver_send: Exit: 0[0m
[00:01:37.475,158] [0m<dbg> bt_hci_core: process_events: ev->state 0[0m
[00:01:37.475,189] [0m<dbg> sdc_hci_driver: event_packet_process: Command Complete (0x200a) status: 0x00, ncmd: 1, len 4[0m
[00:01:37.475,219] [0m<dbg> bt_hci_core: bt_recv: buf 0x2000aaf4 len 6[0m
[00:01:37.475,250] [0m<dbg> bt_hci_core: hci_cmd_complete: opcode 0x200a[0m
[00:01:37.475,250] [0m<dbg> bt_hci_core: hci_cmd_done: opcode 0x200a status 0x00 buf 0x2000aaf4[0m
[00:01:37.475,463] [0m<dbg> bt_conn: bt_conn_prepare_events: [0m
[00:01:37.475,463] [0m<dbg> bt_hci_core: hci_tx_thread: Calling k_poll with 2 events[0m
[00:01:37.475,524] [0m<dbg> bt_hci_core: bt_hci_cmd_send_sync: rsp 0x2000aaf4 opcode 0x200a len 1[0m
[00:01:37.475,524] [0m<dbg> bt_conn: bt_conn_unref: handle 0 ref 2 -> 1[0m
[00:01:37.493,164] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
[00:01:37.504,638] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
[00:01:37.517,852] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
[00:01:37.534,973] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
[00:01:37.881,072] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
cting-adv[0m
[00:01:37.474,700] [0m<dbg> bt_conn: bt_conn_ref: handle 0 ref 1 -> 2[0m
[00:01:37.474,731] [0m<dbg> bt_hci_core: bt_hci_cmd_create: opcode 0x200a param_len 1[0m
[00:01:37.474,761] [0m<dbg> bt_hci_core: bt_hci_cmd_create: buf 0x2000aaf4[0m
[00:01:37.474,761] [0m<dbg> bt_hci_core: bt_hci_cmd_send_sync: buf 0x2000aaf4 opcode 0x200a len 4[0m
[00:01:37.474,853] [0m<dbg> bt_hci_core: process_events: count 2[0m
[00:01:37.474,853] [0m<dbg> bt_hci_core: process_events: ev->state 4[0m
[0cting-adv[0m
[00:01:37.474,700] [0m<dbg> bt_conn: bt_conn_ref: handle 0 ref 1 -> 2[0m
[00:01:37.474,731] [0m<dbg> bt_hci_core: bt_hci_cmd_create: opcode 0x200a param_len 1[0m
[00:01:37.474,761] [0m<dbg> bt_hci_core: bt_hci_cmd_create: buf 0x2000aaf4[0m
[00:01:37.474,761] [0m<dbg> bt_hci_core: bt_hci_cmd_send_sync: buf 0x2000aaf4 opcode 0x200a len 4[0m
[00:01:37.474,853] [0m<dbg> bt_hci_core: process_events: count 2[0m
[00:01:37.474,853] [0m<dbg> bt_hci_core: process_events: ev->state 4[0m
[00:01:37.474,884] [0m<dbg> bt_hci_core: send_cmd: calling net_buf_get[0m
[00:01:37.474,914] [0m<dbg> bt_hci_core: send_cmd: calling sem_take_wait[0m
[00:01:37.474,914] [0m<dbg> bt_hci_core: send_cmd: Sending command 0x200a (buf 0x2000aaf4) to driver[0m
[00:01:37.474,945] [0m<dbg> bt_hci_core: bt_send: buf 0x2000aaf4 len 4 type 0[0m
[00:01:37.474,945] [0m<dbg> sdc_hci_driver: hci_driver_send: [0m
[00:01:37.474,975] [0m<dbg> sdc_hci_driver: cmd_handle: [0m
[00:01:37.475,128] [0m<dbg> sdc_hci_driver: hci_driver_send: Exit: 0[0m
[00:01:37.475,158] [0m<dbg> bt_hci_core: process_events: ev->state 0[0m
[00:01:37.475,189] [0m<dbg> sdc_hci_driver: event_packet_process: Command Complete (0x200a) status: 0x00, ncmd: 1, len 4[0m
[00:01:37.475,219] [0m<dbg> bt_hci_core: bt_recv: buf 0x2000aaf4 len 6[0m
[00:01:37.475,250] [0m<dbg> bt_hci_core: hci_cmd_complete: opcode 0x200a[0m
[00:01:37.475,250] [0m<dbg> bt_hci_core: hci_cmd_done: opcode 0x200a status 0x00 buf 0x2000aaf4[0m
[00:01:37.475,463] [0m<dbg> bt_conn: bt_conn_prepare_events: [0m
[00:01:37.475,463] [0m<dbg> bt_hci_core: hci_tx_thread: Calling k_poll with 2 events[0m
[00:01:37.475,524] [0m<dbg> bt_hci_core: bt_hci_cmd_send_sync: rsp 0x2000aaf4 opcode 0x200a len 1[0m
[00:01:37.475,524] [0m<dbg> bt_conn: bt_conn_unref: handle 0 ref 2 -> 1[0m
[00:01:37.493,164] [0m<dbg>cting-adv[0m
[00:01:37.474,700] [0m<dbg> bt_conn: bt_conn_ref: handle 0 ref 1 -> 2[0m
[00:01:37.474,731] [0m<dbg> bt_hci_core: bt_hci_cmd_create: opcode 0x200a param_len 1[0m
[00:01:37.474,761] [0m<dbg> bt_hci_core: bt_hci_cmd_create: buf 0x2000aaf4[0m
[00:01:37.474,761] [0m<dbg> bt_hci_core: bt_hci_cmd_send_sync: buf 0x2000aaf4 opcode 0x200a len 4[0m
[00:01:37.474,853] [0m<dbg> bt_hci_core: process_events: count 2[0m
[00:01:37.474,853] [0m<dbg> bt_hci_core: process_events: ev->state 4[0m
[00:01:37.474,884] [0m<dbg> bt_hci_core: send_cmd: calling net_buf_get[0m
[00:01:37.474,914] [0m<dbg> bt_hci_core: send_cmd: calling sem_take_wait[0m
[00:01:37.474,914] [0m<dbg> bt_hci_core: send_cmd: Sending command 0x200a (buf 0x2000aaf4) to driver[0m
[00:01:37.474,945] [0m<dbg> bt_hci_core: bt_send: buf 0x2000aaf4 len 4 typecting-adv[0m
[00:01:37.474,700] [0m<dbg> bt_conn: bt_conn_ref: handle 0 ref 1 -> 2[0m
[00:01:37.474,731] [0m<dbg> bt_hci_core: bt_hci_cmd_create: opcode 0x200a param_len 1[0m
[00:01:37.474,761] [0m<dbg> bt_hci_core: bt_hci_cmd_create: buf 0x2000aaf4[0m
[00:01:37.474,761] [0m<dbg> bt_hci_core: bt_hci_cmd_send_sync: buf 0x2000aaf4 opcode 0x200a len 4[0m
[00:01:37.474,853] [0m<dbg> bt_hci_core: process_events: count 2[0m
[00:01:37.474,853] [0m<dbg> bt_hci_core: process_events: ev->scting-adv[0m
[00:01:37.474,700] [0m<dbg> bt_conn: bt_conn_ref: handle 0 ref 1 -> 2[0m
[00:01:37.474,731] [0m<dbg> bt_hci_core: bt_hci_cmd_create: opcode 0x200a param_len 1[0m
[00:01:37.474,761] [0m<dbg> bt_hci_core: bt_hci_cmd_create: buf 0x2000aaf4[0m
[00:01:37.474,761] [0m<dbg> bt_hci_core: bt_hci_cmd_send_sync: buf 0x2000aaf4 opcode 0x200a len 4[0m
[00:01:37.474,853] [0m<dbg> bt_hci_core: process_events: count 2[0m
[00:01:37.474,853] [0m<dbg> bt_hci_core: process_events: ev->state 4[0m
[00:01:37.474,884] [0m<dbg> bt_hci_core: send_cmd: calling net_buf_get[0m
[00:01:37.474,914] [0m<dbg> bt_hci_core: send_cmd: calling sem_take_wait[0m
[00:01:37.474,914] [0m<dbg> bt_hci_core: send_cmd: Sending command 0x200a (buf 0x2000aaf4) to driver[0m
[00:01:37.474,945] [0m<dbg> bt_hci_core: bt_send: buf 0x2000aaf4 len 4 type 0[0m
[00:01:37.474,945] [0m<dbg> sdc_hci_driver: hci_driver_send: [0m
[00:01:37.474,975] [0m<dbg> sdc_hci_driver: cmd_handle: [0m
[00:01:37.475,128] [0m<dbg> sdc_hci_driver: hci_driver_send: Exit: 0[0m
[00:01:37.475,158] [0m<dbg> bt_hci_core: process_events: ev->state 0[0m
[00:01:37.475,189] [0m<dbg> sdc_hci_driver: event_packT4 field Off
T4 field Off
T4 field Off
T4 field ON
T4 field Off
T4 field Off
T4 field Off
T4 field Off
T4 field ON
T4 field ON
T4 field READ
Regular advertising started
T4 field ON
[00:01:46.558,624] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
[00:01:46.583,862] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
[00:01:46.597,045] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
[00:01:46.614,196] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
[00:01:46.620,117] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
[00:01:46.654,724] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
[00:01:46.793,090] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
[00:01:46.806,243] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
[00:01:46.823,364] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
[00:01:46.840,209] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
[00:01:46.900,360] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m
T4 field Off
[00:01:47.226,715] [0m<dbg> nfc_tnep_tag: tnep_sm_service_ready: TNEP Service Ready[0m

T4 field Off

Children

0 Caycee over 4 years ago in reply to Caycee

So now I've tried with v2.02 but still nothing. The touching of the NFC tag produced lots of debug messages as above, but once the "Pair the device" message comes up, after hitting YES, no debug messages appear at all.

None of the key exchange and data transfer which apparently goes on doesn't provide ANY feedback. The only indication is the "NOT BONDED" -> "BONDED" ->"NOT BONDED" display on the nRF App.

Is a sniffer the only way to find out what's going on here? (I have two DK boards which act identically)
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel