simple gpio to control external FEM in NCS 2.7.0 & nrf5340

[lincoln-lu]

Hi Nordic team,

I am facing an issue about using simple gpio to control external FEM(custom FEM model) in NCS 2.7.0 & nrf5340.

Here is background:
1. Our project is using nRF5340, and based on NCS version before 2.7.0
2. For the network core, we copied NCS 2.6.1\zephyr\samples\bluetooth\hci_ipc, and modified a bit of code in oder to support simple gpio to control external FEM. by adding       macros and functions below:

CONFIG_MPSL_FEM=y

CONFIG_MPSL_FEM_POWER_MODEL=y

CONFIG_MPSL_FEM_SIMPLE_GPIO=y

CONFIG_MPSL_FEM_DEVICE_CONFIG_254=n

mpsl_fem_power_model_to_use_get()

model_fetch()

model_init()

3. it works fine on NCS 2.6.1, but it failed when I migrated it to NCS to 2.7.0 (still use 'no sysbuild', so net core child image is built from zephyr\samples\bluetooth\hci_ipc ). 
    The netcore always gets BUS Fault and crashes when app core wants to set RF power. see the UART log from net core

[00:00:16.316,131] ^[[0m<inf> hci_ipc: Sent message of 12 bytes.^[[0m
[00:00:16.319,763] ^[[0m<inf> hci_ipc: Received message of 6 bytes.^[[0m
[00:00:16.320,068] ^[[0m<inf> hci_ipc: Sent message of 7 bytes.^[[0m
[00:00:16.340,515] ^[[0m<inf> hci_ipc: Received message of 8 bytes.^[[0m
[00:00:16.340,606] ^[[1;31m<err> os: ***** BUS FAULT *****^[[0m
[00:00:16.340,637] ^[[1;31m<err> os:   Precise data bus error^[[0m
[00:00:16.340,637] ^[[1;31m<err> os:   BFAR Address: 0x1^[[0m
[00:00:16.340,667] ^[[1;31m<err> os: r0/a1:  0x0000000d  r1/a2:  0x80000000  r2/a3:  0x00000001^[[0m
[00:00:16.340,728] ^[[1;31m<err> os: r3/a4:  0x00000000 r12/ip:  0x0101ea1d r14/lr:  0x0101d1c9^[[0m
[00:00:16.340,728] ^[[1;31m<err> os:  xpsr:  0x81004400^[[0m
[00:00:16.340,728] ^[[1;31m<err> os: Faulting instruction address (r15/pc): 0x0101d1d4^[[0m
[00:00:16.340,789] ^[[1;31m<err> os: >>> ZEPHYR FATAL ERROR 25: Unknown error on CPU 0^[[0m
[00:00:16.340,820] ^[[1;31m<err> os: Current thread: 0x21002210 (HCI ipc TX)^[[0m
[00:00:16.439,147] ^[[1;31m<err> os: Halting system^[[0m

In oder to simplify the problem, I tried the NCS sample code under C:\ncs\v2.7.0\zephyr\samples\bluetooth\hci_pwr_ctrl on 5340DK, because in this sample, application code is also sending HCI cmd to net core to get/set RF power.  I observed lots of errors about the HCI command sending thru IPC  in function bt_hci_cmd_send_sync(),

Below is the UART log printed out from 5340DK app core:

*** Booting nRF Connect SDK v2.7.0-5cb85570ca43 ***
*** Using Zephyr OS v3.6.99-100befc70c74 ***
Starting Dynamic Tx Power Beacon Demo
Get Tx power level ->[00:00:00.445,922] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x0c03 timeout with err 0
--- 10 messages dropped ---
[00:00:00.451,751] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x2018 timeout with err 0
[00:00:00.452,362] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x2018 timeout with err 0
[00:00:00.454,895] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x0c33 timeout with err 0
[00:00:00.455,291] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x0c31 timeout with err 0
[00:00:00.455,657] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x2003 timeout with err 0
[00:00:00.456,024] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x2002 timeout with err 0
[00:00:00.456,390] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x201c timeout with err 0
[00:00:00.456,756] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x202f timeout with err 0
[00:00:00.457,122] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x2024 timeout with err 0
[00:00:00.457,519] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x2001 timeout with err 0
[00:00:00.457,885] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x0c01 timeout with err 0
[00:00:00.458,251] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc01 timeout with err 0
[00:00:00.458,282] <inf> bt_hci_core: HW Platform: Nordic Semiconductor (0x0002)
[00:00:00.458,312] <inf> bt_hci_core: HW Variant: nRF53x (0x0003)
[00:00:00.458,312] <inf> bt_hci_core: Firmware: Standard Bluetooth controller (0x00) Version 214.51162 Build 1926957230
[00:00:00.458,709] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc02 timeout with err 0
[00:00:00.459,106] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x1009 timeout with err 0
[00:00:00.459,472] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc09 timeout with err 0
[00:00:00.459,869] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x2005 timeout with err 0
[00:00:00.460,021] <inf> bt_hci_core: Identity: F2:D1:8F:D5:69:8A (random)
[00:00:00.460,052] <inf> bt_hci_core: HCI: version 5.4 (0x0d) revision 0x21fb, manufacturer 0x0059
[00:00:00.460,083] <inf> bt_hci_core: LMP: version 5.4 (0x0d) subver 0x21fb
Bluetooth initialized
[00:00:00.460,540] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x2006 timeout with err 0
[00:00:00.460,968] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x2008 timeout with err 0
[00:00:00.461,364] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x2009 timeout with err 0
[00:00:00.461,914] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x200a timeout with err 0
Dynamic Tx power Beacon started
Set Tx power level to 4
[00:00:05.446,838] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc0e timeout with err 0
[00:00:05.446,868] <wrn> bt_hci_core: opcode 0xfc0e status 0x01
Set Tx power err: -5 reason 0x00
Get Tx power level -> [00:00:10.447,357] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc0f timeout with err 0
[00:00:10.447,387] <wrn> bt_hci_core: opcode 0xfc0f status 0x01
Read Tx power err: -5 reason 0x00
TXP = -1
Set Tx power level to 0
[00:00:10.447,814] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc0e timeout with err 0
[00:00:10.447,814] <wrn> bt_hci_core: opcode 0xfc0e status 0x01
Set Tx power err: -5 reason 0x00
Get Tx power level -> [00:00:15.448,364] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc0f timeout with err 0
[00:00:15.448,364] <wrn> bt_hci_core: opcode 0xfc0f status 0x01
Read Tx power err: -5 reason 0x00
TXP = -1
Set Tx power level to -3
[00:00:15.448,791] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc0e timeout with err 0
[00:00:15.448,822] <wrn> bt_hci_core: opcode 0xfc0e status 0x01
Set Tx power err: -5 reason 0x00
Get Tx power level -> [00:00:20.449,310] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc0f timeout with err 0
[00:00:20.449,340] <wrn> bt_hci_core: opcode 0xfc0f status 0x01
Read Tx power err: -5 reason 0x00
TXP = -1
Set Tx power level to -8
[00:00:20.449,829] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc0e timeout with err 0
[00:00:20.449,829] <wrn> bt_hci_core: opcode 0xfc0e status 0x01
Set Tx power err: -5 reason 0x00

Note: I used 'No sysbuild' in VsCode when building this sample so that net core child image is built from zephyr\samples\bluetooth\hci_ipc

Can you look at this issue?
If you need any more info, please let me know.

Thanks

[Sigurd Hellesvik]

In oder to simplify the problem, I tried the NCS sample code under C:\ncs\v2.7.0\zephyr\samples\bluetooth\hci_pwr_ctrl on 5340DK, because in this sample, application code is also sending HCI cmd to net core to get/set RF power

Did you make any changes to the sample before testing it?

Regards,
Sigurd Hellesvik

[lincoln-lu]

No, I did not change anything, it is the AS-IS sample code

[lincoln-lu]

  Sigurd Hellesvik 
You know, in C:\ncs\v2.7.0\zephyr\samples\bluetooth\hci_pwr_ctrl folder, there is no sysbuild.conf or Kconfig.sysbuild.
so in order make it support sysbuild, I add these two files manually, as below:

Here is the sysbuild.conf that was added by me:

#
# Copyright (c) 2024 Nordic Semiconductor
#
# SPDX-License-Identifier: LicenseRef-Nordic-5-Clause
#

SB_CONFIG_NETCORE_HCI_IPC=y

And here is the Kconfig.sysbuild that was added by me, please note I set CONFIG_NRF_DEFAULT_BLUETOOTH=y to use "zephyr\samples\bluetooth\hci_ipc" for net core, isntead of the new ipc_radio firmware from Nordic.

#
# Copyright (c) 2023 Nordic Semiconductor
#
# SPDX-License-Identifier: LicenseRef-Nordic-5-Clause
#

source "${ZEPHYR_BASE}/share/sysbuild/Kconfig"

config NRF_DEFAULT_BLUETOOTH
	default y

Besides, I aslo copied sysbuild/hci_rpmsg.conf -> sysbuild/hci_ipc.conf as you said above,

By these changes, the sysbuild will generate hci_ipc for net core and hci_pwr_ctrl for app core as below:



Here is the uart log of 5340DK, does it mean tx power is get/set succussfully although there are still lots of timeout WARNINGs in bt_hci_core: bt_hci_cmd_send_sync ? Are these warning expected?

*** Booting nRF Connect SDK v2.7.0-5cb85570ca43 ***
*** Using Zephyr OS v3.6.99-100befc70c74 ***
Starting Dynamic Tx Power Beacon Demo
Get Tx power level ->[00:00:00.269,561] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x0c03 timeout with err 0^[[0m
^[[1;31m--- 8 messages dropped ---
^[[0m[00:00:00.275,482] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x2018 timeout with err 0^[[0m
[00:00:00.276,062] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x2018 timeout with err 0^[[0m
[00:00:00.278,625] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x0c33 timeout with err 0^[[0m
[00:00:00.278,991] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x0c31 timeout with err 0^[[0m
[00:00:00.279,357] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x2003 timeout with err 0^[[0m
[00:00:00.279,724] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x2002 timeout with err 0^[[0m
[00:00:00.280,090] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x201c timeout with err 0^[[0m
[00:00:00.280,456] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x202f timeout with err 0^[[0m
[00:00:00.280,853] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x2024 timeout with err 0^[[0m
[00:00:00.281,219] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x2001 timeout with err 0^[[0m
[00:00:00.281,585] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x0c01 timeout with err 0^[[0m
[00:00:00.281,951] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc01 timeout with err 0^[[0m
[00:00:00.281,982] ^[[0m<inf> bt_hci_core: HW Platform: Nordic Semiconductor (0x0002)^[[0m
[00:00:00.282,012] ^[[0m<inf> bt_hci_core: HW Variant: nRF53x (0x0003)^[[0m
[00:00:00.282,012] ^[[0m<inf> bt_hci_core: Firmware: Standard Bluetooth controller (0x00) Version 214.51162 Build 1926957230^[[0m
[00:00:00.282,409] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc02 timeout with err 0^[[0m
[00:00:00.282,806] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x1009 timeout with err 0^[[0m
[00:00:00.283,172] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc09 timeout with err 0^[[0m
[00:00:00.283,569] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x2005 timeout with err 0^[[0m
[00:00:00.283,691] ^[[0m<inf> bt_hci_core: Identity: F2:D1:8F:D5:69:8A (random)^[[0m
[00:00:00.283,752] ^[[0m<inf> bt_hci_core: HCI: version 5.4 (0x0d) revision 0x21fb, manufacturer 0x0059^[[0m
[00:00:00.283,782] ^[[0m<inf> bt_hci_core: LMP: version 5.4 (0x0d) subver 0x21fb^[[0m
Bluetooth initialized
[00:00:00.284,210] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x2006 timeout with err 0^[[0m
[00:00:00.284,637] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x2008 timeout with err 0^[[0m
[00:00:00.285,034] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x2009 timeout with err 0^[[0m
[00:00:00.285,583] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x200a timeout with err 0^[[0m
Dynamic Tx power Beacon started
Set Tx power level to 4
[00:00:05.270,507] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc0e timeout with err 0^[[0m
Actual Tx Power: 3
Get Tx power level -> [00:00:10.270,996] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc0f timeout with err 0^[[0m
TXP = 3
Set Tx power level to 0
[00:00:10.271,545] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc0e timeout with err 0^[[0m
Actual Tx Power: 0
Get Tx power level -> [00:00:15.272,094] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc0f timeout with err 0^[[0m
TXP = 0
Set Tx power level to -3
[00:00:15.272,521] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc0e timeout with err 0^[[0m
Actual Tx Power: -3
Get Tx power level -> [00:00:20.273,040] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc0f timeout with err 0^[[0m
TXP = -3
Set Tx power level to -8
[00:00:20.273,468] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc0e timeout with err 0^[[0m
Actual Tx Power: -8
Get Tx power level -> [00:00:25.273,986] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc0f timeout with err 0^[[0m
TXP = -8
Set Tx power level to -15
[00:00:25.274,414] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc0e timeout with err 0^[[0m
Actual Tx Power: -16
Get Tx power level -> [00:00:30.274,932] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc0f timeout with err 0^[[0m
TXP = -16
Set Tx power level to -18
[00:00:30.275,360] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc0e timeout with err 0^[[0m
Actual Tx Power: -20
Get Tx power level -> [00:00:35.275,878] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc0f timeout with err 0^[[0m
TXP = -20
Set Tx power level to -23
[00:00:35.276,306] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc0e timeout with err 0^[[0m
Actual Tx Power: -40
Get Tx power level -> [00:00:40.276,794] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc0f timeout with err 0^[[0m
TXP = -40
Set Tx power level to -30
[00:00:40.277,252] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc0e timeout with err 0^[[0m
Actual Tx Power: -40
Get Tx power level -> [00:00:45.277,770] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc0f timeout with err 0^[[0m
TXP = -40
Set Tx power level to 4
[00:00:45.278,198] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc0e timeout with err 0^[[0m
Actual Tx Power: 3
Get Tx power level -> [00:00:50.278,686] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc0f timeout with err 0^[[0m
TXP = 3
Set Tx power level to 0
[00:00:50.279,144] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc0e timeout with err 0^[[0m
Actual Tx Power: 0
Get Tx power level -> [00:00:55.279,663] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc0f timeout with err 0^[[0m
TXP = 0
Set Tx power level to -3
[00:00:55.280,090] ^[[1;33m<wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc0e timeout with err 0^[[0m
Actual Tx Power: -3

Meanwhile I will try this without sysbuild, i.e. using the old child-parent building method under NCS 2.7.0, as variant  mentioned.

[lincoln-lu]

Well, I swicthed to use child-parent building method for the same project, the UART log are the same: tx power seems beit got/set succussfully although there are still lots of timeout WARNINGs in bt_hci_core: bt_hci_cmd_send_sync ? Question again, are these warning expected?

*** Booting nRF Connect SDK v2.7.0-5cb85570ca43 ***
*** Using Zephyr OS v3.6.99-100befc70c74 ***
Starting Dynamic Tx Power Beacon Demo
Get Tx power level ->[00:00:00.269,561] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x0c03 timeout with err 0
--- 8 messages dropped ---
[00:00:00.275,451] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x2018 timeout with err 0
[00:00:00.276,062] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x2018 timeout with err 0
[00:00:00.278,594] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x0c33 timeout with err 0
[00:00:00.278,961] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x0c31 timeout with err 0
[00:00:00.279,327] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x2003 timeout with err 0
[00:00:00.279,693] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x2002 timeout with err 0
[00:00:00.280,090] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x201c timeout with err 0
[00:00:00.280,456] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x202f timeout with err 0
[00:00:00.280,822] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x2024 timeout with err 0
[00:00:00.281,188] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x2001 timeout with err 0
[00:00:00.281,555] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x0c01 timeout with err 0
[00:00:00.281,921] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc01 timeout with err 0
[00:00:00.281,951] <inf> bt_hci_core: HW Platform: Nordic Semiconductor (0x0002)
[00:00:00.281,982] <inf> bt_hci_core: HW Variant: nRF53x (0x0003)
[00:00:00.282,012] <inf> bt_hci_core: Firmware: Standard Bluetooth controller (0x00) Version 214.51162 Build 1926957230
[00:00:00.282,409] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc02 timeout with err 0
[00:00:00.282,775] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x1009 timeout with err 0
[00:00:00.283,142] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc09 timeout with err 0
[00:00:00.283,538] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x2005 timeout with err 0
[00:00:00.283,691] <inf> bt_hci_core: Identity: F2:D1:8F:D5:69:8A (random)
[00:00:00.283,721] <inf> bt_hci_core: HCI: version 5.4 (0x0d) revision 0x21fb, manufacturer 0x0059
[00:00:00.283,752] <inf> bt_hci_core: LMP: version 5.4 (0x0d) subver 0x21fb
Bluetooth initialized
[00:00:00.284,210] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x2006 timeout with err 0
[00:00:00.284,606] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x2008 timeout with err 0
[00:00:00.285,003] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x2009 timeout with err 0
[00:00:00.285,583] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0x200a timeout with err 0
Dynamic Tx power Beacon started
Set Tx power level to 4
[00:00:05.270,446] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc0e timeout with err 0
Actual Tx Power: 3
Get Tx power level -> [00:00:10.270,965] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc0f timeout with err 0
TXP = 3
Set Tx power level to 0
[00:00:10.271,453] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc0e timeout with err 0
Actual Tx Power: 0
Get Tx power level -> [00:00:15.272,003] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc0f timeout with err 0
TXP = 0
Set Tx power level to -3
[00:00:15.272,430] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc0e timeout with err 0
Actual Tx Power: -3
Get Tx power level -> [00:00:20.272,979] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc0f timeout with err 0
TXP = -3
Set Tx power level to -8
[00:00:20.273,406] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc0e timeout with err 0
Actual Tx Power: -8
Get Tx power level -> [00:00:25.273,925] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc0f timeout with err 0
TXP = -8
Set Tx power level to -15
[00:00:25.274,353] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc0e timeout with err 0
Actual Tx Power: -16
Get Tx power level -> [00:00:30.274,871] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc0f timeout with err 0
TXP = -16
Set Tx power level to -18
[00:00:30.275,299] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc0e timeout with err 0
Actual Tx Power: -20
Get Tx power level -> [00:00:35.275,817] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc0f timeout with err 0
TXP = -20
Set Tx power level to -23
[00:00:35.276,245] <wrn> bt_hci_core: bt_hci_cmd_send_sync: command opcode 0xfc0e timeout with err 0
Actual Tx Power: -40

I am thinking why the firmware of last child-parent build failed to get/set tx power.

Please note that: the only change I made this time is: I renamed child_image/hci_rpmsg.conf -> child_image/hci_ipc.conf under folder C:\ncs\v2.7.0\zephyr\samples\bluetooth\hci_pwr_ctr.

so I guess the 2.7.0 building script is looking for hci_ipc.conf, instead of hci_rpmsg.conf, because in NCS 2.7.0 hci_rpmgs has been renamed to hci_ipc by Zephyr, so it failed to find it and thus CONFIG_BT_CTLR_TX_PWR_DYNAMIC_CONTROL  was not set finally.
so this should be an issue in NCS 2.7.0.

[Sigurd Hellesvik]

variant said:

Shouldn't we able to get this to work without sysbuild when using NCS 2.7?

Yes you should.

I was confused because the sysbuild/ folder was there as a leftover after I had used v2.9.0 before.

lincoln-lu said:

although there are still lots of timeout WARNINGs in bt_hci_core: bt_hci_cmd_send_sync ? Question again, are these warning expected?

I do not get those warnings when I run the sample on my side, hmm.

Do you by chance have a DK that you can also try the sample on? Just to compare

[variant]

variant said:

Also, did you enable CONFIG_LOG=y and CONFIG_BT_LOG_LEVEL_DBG=y  so as to be able to see the warnings lincoln-lu showed in his log?

[lincoln-lu]

Sigurd Hellesvik said:

I do not get those warnings when I run the sample on my side, hmm.

Hi Sigurd Hellesvik  variant 
I see why I could see lots of warnnings in hci_core.c, I modified the code in function bt_hci_cmd_send_sync() as below to avoid the ASSERT and chip reset

You know af first I always see chip is reset by BT_ASSERT_MSG(err == 0, "command opcode 0x%04x timeout with err %d", opcode, err); 

so I changed BT_ASSERT_MSG to LOG_WRN.

But anyway, there is TIMEOUT FATAL error in NCS 2.7.0 for HCI command communication. that will cause chip reset.