Buttonless DFU service does not start when NRF_LOG_ENABLED is set 0

[AntonHellbe]

Hi all,

I have a very strange problem with the Buttonless DFU service. For my project we have two different builds, one debug and one "release" build. The debug build sets the following SDK config defines to 1, and the release build sets them to 0.

• NRF_SDH_BLE_LOG_ENABLED
• NRF_SDH_SOC_LOG_ENABLED
• NRF_SDH_LOG_ENABLED
• NRF_LOG_BACKEND_RTT_ENABLED
• NRF_LOG_ENABLED

When I compile the project and flash the debug build (application + softdevice + bootloader) the application starts up and I can access the DFU service. However when I compile and flash the "release" build the application does not start. If I remove the DFU service the application starts up with both builds, so there's something happening when I disable the logs with the DFU service. Its very hard to debug since everything works the logs are enabled.

I've had some issues before with observers being optimized way since the source code from the libs is not being directly referenced from my code. Could it be something similar going on here? https://devzone.nordicsemi.com/support/224969 (Private ticket)

All help is appreciated, this is a very annoying problem!

[Hadi Deknache]

Hi Vidar,

I am Anton's colleague, I have tried to debug the application through gdb and notice that the application seems to be stuck in a function that is called log_skip().

I get the following message when I halt the application to check: Program received signal SIGTRAP, Trace, breakpoint trap. Log_skip().

I have set a breakpoint in main but seem that it never reaches main when nrf_log is disabled, however, when I enable nrf_log this error never occurs.

Any idea why the application is stuck in log_skip, is it triggered by a Hardfault?

/Hadi

[Vidar Berg]

Hi Hadi,

Do you do any logging in the hardfault handler? Can you run "info registers" and "bt"  in GDB to check where the program is stuck?

[Hadi Deknache]

Hi again, 

I have run the commands you asked me to and got the following output:

r0             0x1	1
r1             0x2000fe58	536936024
r2             0x200055dc	536892892
r3             0x2000fe58	536936024
r4             0x2000ffd0	536936400
r5             0x3a030	237616
r6             0x7e000	516096
r7             0x2000fe48	536936008
r8             0x0	0
r9             0x0	0
r10            0x20000000	536870912
r11            0x0	0
r12            0x20006da4	536898980
sp             0x2000fe48	0x2000fe48
lr             0x32d7d	208253
pc             0x32d76	0x32d76 <log_skip+58>
xpsr           0x1000000	16777216
msp            0x2000fe48	536936008
psp            0x0	0
primask        0x0	0
basepri        0x0	0
faultmask      0x0	0
control        0x0	0
(gdb) bt
#0  0x00032d76 in log_skip ()
    at /xx/xx/xx/xx/sdk_files/components/libraries/experimental_log/src/nrf_log_frontend.c:360
#1  0x00032f52 in buf_prealloc (content_len=1, p_wr_idx=0x2000fec8, std=true)
    at /xx/xx/xx/xx/sdk_files/components/libraries/experimental_log/src/nrf_log_frontend.c:464
#2  0x0003303a in std_n (severity_mid=3, 
    p_str=0x3a3ec "Setting vector table to bootloader: 0x%08x", 
    args=0x2000fef4, nargs=1)
    at /xx/xx/xx/xx/sdk_files/components/libraries/experimental_log/src/nrf_log_frontend.c:585
#3  0x000330e8 in nrf_log_frontend_std_1 (severity_mid=3, 
    p_str=0x3a3ec "Setting vector table to bootloader: 0x%08x", val0=466944)
    at /xx/xx/xx/xx/sdk_files/components/libraries/experimental_log/src/nrf_log_frontend.c:615
#4  0x00032b4c in nrf_dfu_svci_vector_table_set ()
    at /xx/xx/xx/xx/sdk_files/components/libraries/bootloader/dfu/nrf_dfu_svci.c:56
#5  0x0002c26e in ble_dfu_buttonless_async_svci_init ()
    at /xx/xx/xx/xx/sdk_files/components/ble/ble_services/ble_dfu/ble_dfu_bonded.c:210
#6  0x00026b9e in dfu_service_init () at dfu.c:125
#7  0x00026798 in main () at main.c:319

[Vidar Berg]

There's no hardfault, but the stack trace confirms that the program starts executing log_skip() as you said, and log_skip() should not be invoked as long as NRF_LOG_ENABLED==0. What SDK version are you on? 

[Hadi Deknache]

We are currently using SDK version 15.0. I have noticed that when we hard code the Enable_logging=0 flag in the sdk_config.h file, the application works fine, however, the application get stuck in log_skip() when changing the flag in the makefile.