This post is older than 2 years and might not be relevant anymore
More Info: Consider searching for newer posts

NRF_LOG_INIT HardFault in balloc. The bootloader also uses logging, is that a problem?

NRF_LOG_INIT HardFault in balloc (see stack trace below).

(gdb) bt
#0  HardFault_HandlerC (hardfault_args=0x2000fed8) at /home/anne/workspace/bluenet/bart-source/src/util/cs_Error.cpp:74
#1  <signal handler called>
Reading 64 bytes @ address 0x2000FEC0
Read 4 bytes @ address 0x00039142 (Data = 0xD1026822)
Read 4 bytes @ address 0x000394A8 (Data = 0xB9104604)
#2  0x00039142 in nrf_balloc_init (p_pool=0x461ac <log_mempool>) at /home/anne/software/nrf5_sdk/nRF5_SDK_15.2.0_9412b96/components/libraries/balloc/nrf_balloc.c:280
Reading 64 bytes @ address 0x2000FF00
Read 4 bytes @ address 0x0003617E (Data = 0xF8B1F003)
#3  0x000394a8 in nrf_log_init (timestamp_func=<optimized out>, timestamp_freq=<optimized out>)
    at /home/anne/software/nrf5_sdk/nRF5_SDK_15.2.0_9412b96/components/libraries/log/src/nrf_log_frontend.c:133
#4  0x0003617e in main () at /home/anne/workspace/bluenet/bart-source/src/cs_Crownstone.cpp:983
Reading 64 bytes @ address 0x2000FFC0
Read 4 bytes @ address 0x0002628E (Data = 0xFA2DF016)
Reading 64 bytes @ address 0x00026240
Read 4 bytes @ address 0x00026298 (Data = 0x20010000)
Read 4 bytes @ address 0x00026296 (Data = 0x00000008)
Read 4 bytes @ address 0x000262A4 (Data = 0x20002598)
Read 4 bytes @ address 0x000262AA (Data = 0xC6A92000)
#5  0x0002628e in _start ()
Backtrace stopped: previous frame inner to this frame (corrupt stack?)

Code works perfectly without bootloader. However, when the bootloader is present it seems to already have initialized things? Or what exactly is happening here? Should we not call  
    NRF_LOG_INIT(NULL);                                                                                                 
    NRF_LOG_DEFAULT_BACKENDS_INIT();       

If this is already done in the bootloader? Or should we "clean up" the bootloader in some way?

More info:

133	    ret_code_t err_code = nrf_memobj_pool_init(&log_mempool);
(gdb) p m_log_data
Reading 1060 bytes @ address 0x20004AAC
$11 = {
  wr_idx = 0, 
  rd_idx = 0, 
  mask = 255, 
  buffer = {0 <repeats 256 times>}, 
  timestamp_func = 0x0, 
  p_backend_head = 0x0, 
  log_skipping = 0, 
  log_skipped = 0, 
  log_dropped_cnt = 0, 
  autoflush = false
}
(gdb) p log_mempool
Reading 20 bytes @ address 0x0004619C
$12 = {
  p_cb = 0xffffffff, 
Read 1 bytes @ address 0xFFFFFFFF (Data = 0x00)
  p_stack_base = 0xffffffff "", 
Read 1 bytes @ address 0xFFFFFFFF (Data = 0x00)
  p_stack_limit = 0xffffffff "", 
  p_memory_begin = 0xffffffff, 
  block_size = 65535
}

  • HI Anne, 

    there should not be any issues with calling 

        NRF_LOG_INIT(NULL);                                                                                                 
        NRF_LOG_DEFAULT_BACKENDS_INIT();      

    in both the application and in the bootloader, we do this in our SDK examples( i.e. bootlaoder and buttonless DFU application)

    So the Hardfault must be caused by something else. Have you changed any of the logging related defines in sdk_config.h?

    Best regards

    Bjørn

  • Hi Bjørn,

    What do you mean by "changed"?

    With "changed" do you mean changed in the application compared to the bootloader? Do you mean that all logging settings have to be the same in bootloader and application?

  • By changed I mean if you have modified(i.e. set them to non-default values) any of the definitions used by the Logging module in the sdk.config.h file, i.e.

    // <e> NRF_LOG_ENABLED - nrf_log - Logger
    //==========================================================
    #ifndef NRF_LOG_ENABLED
    #define NRF_LOG_ENABLED 1
    #endif
    // <h> Log message pool - Configuration of log message pool
    
    //==========================================================
    // <o> NRF_LOG_MSGPOOL_ELEMENT_SIZE - Size of a single element in the pool of memory objects. 
    // <i> If a small value is set, then performance of logs processing
    // <i> is degraded because data is fragmented. Bigger value impacts
    // <i> RAM memory utilization. The size is set to fit a message with
    // <i> a timestamp and up to 2 arguments in a single memory object.
    
    #ifndef NRF_LOG_MSGPOOL_ELEMENT_SIZE
    #define NRF_LOG_MSGPOOL_ELEMENT_SIZE 20
    #endif
    
    // <o> NRF_LOG_MSGPOOL_ELEMENT_COUNT - Number of elements in the pool of memory objects 
    // <i> If a small value is set, then it may lead to a deadlock
    // <i> in certain cases if backend has high latency and holds
    // <i> multiple messages for long time. Bigger value impacts
    // <i> RAM memory usage.
    
    #ifndef NRF_LOG_MSGPOOL_ELEMENT_COUNT
    #define NRF_LOG_MSGPOOL_ELEMENT_COUNT 8
    #endif
    
    // </h> 
    //==========================================================
    
    // <q> NRF_LOG_ALLOW_OVERFLOW  - Configures behavior when circular buffer is full.
     
    
    // <i> If set then oldest logs are overwritten. Otherwise a 
    // <i> marker is injected informing about overflow.
    
    #ifndef NRF_LOG_ALLOW_OVERFLOW
    #define NRF_LOG_ALLOW_OVERFLOW 1
    #endif
    
    // <o> NRF_LOG_BUFSIZE  - Size of the buffer for storing logs (in bytes).
     
    
    // <i> Must be power of 2 and multiple of 4.
    // <i> If NRF_LOG_DEFERRED = 0 then buffer size can be reduced to minimum.
    // <128=> 128 
    // <256=> 256 
    // <512=> 512 
    // <1024=> 1024 
    // <2048=> 2048 
    // <4096=> 4096 
    // <8192=> 8192 
    // <16384=> 16384 
    
    #ifndef NRF_LOG_BUFSIZE
    #define NRF_LOG_BUFSIZE 1024
    #endif
    
    // <q> NRF_LOG_CLI_CMDS  - Enable CLI commands for the module.
     
    
    #ifndef NRF_LOG_CLI_CMDS
    #define NRF_LOG_CLI_CMDS 0
    #endif
    
    // <o> NRF_LOG_DEFAULT_LEVEL  - Default Severity level
     
    // <0=> Off 
    // <1=> Error 
    // <2=> Warning 
    // <3=> Info 
    // <4=> Debug 
    
    #ifndef NRF_LOG_DEFAULT_LEVEL
    #define NRF_LOG_DEFAULT_LEVEL 3
    #endif
    
    // <q> NRF_LOG_DEFERRED  - Enable deffered logger.
     
    
    // <i> Log data is buffered and can be processed in idle.
    
    #ifndef NRF_LOG_DEFERRED
    #define NRF_LOG_DEFERRED 1
    #endif
    
    // <q> NRF_LOG_FILTERS_ENABLED  - Enable dynamic filtering of logs.
     
    
    #ifndef NRF_LOG_FILTERS_ENABLED
    #define NRF_LOG_FILTERS_ENABLED 0
    #endif
    
    // <o> NRF_LOG_STR_PUSH_BUFFER_SIZE  - Size of the buffer dedicated for strings stored using @ref NRF_LOG_PUSH.
     
    // <16=> 16 
    // <32=> 32 
    // <64=> 64 
    // <128=> 128 
    // <256=> 256 
    // <512=> 512 
    // <1024=> 1024 
    
    #ifndef NRF_LOG_STR_PUSH_BUFFER_SIZE
    #define NRF_LOG_STR_PUSH_BUFFER_SIZE 128
    #endif
    
    // <o> NRF_LOG_STR_PUSH_BUFFER_SIZE  - Size of the buffer dedicated for strings stored using @ref NRF_LOG_PUSH.
     
    // <16=> 16 
    // <32=> 32 
    // <64=> 64 
    // <128=> 128 
    // <256=> 256 
    // <512=> 512 
    // <1024=> 1024 
    
    #ifndef NRF_LOG_STR_PUSH_BUFFER_SIZE
    #define NRF_LOG_STR_PUSH_BUFFER_SIZE 128
    #endif

    The log settings does not necessarily need to be identical, but if the log settings are different and one is working and the other isnt, then please post the relevant sections from the sdk_config files. 

    Best regards

    Bjørn 

  • By changed I mean if you have modified(i.e. set them to non-default values) any of the definitions used by the Logging module in the sdk.config.h file, i.e.

    // <e> NRF_LOG_ENABLED - nrf_log - Logger
    //==========================================================
    #ifndef NRF_LOG_ENABLED
    #define NRF_LOG_ENABLED 1
    #endif
    // <h> Log message pool - Configuration of log message pool
    
    //==========================================================
    // <o> NRF_LOG_MSGPOOL_ELEMENT_SIZE - Size of a single element in the pool of memory objects. 
    // <i> If a small value is set, then performance of logs processing
    // <i> is degraded because data is fragmented. Bigger value impacts
    // <i> RAM memory utilization. The size is set to fit a message with
    // <i> a timestamp and up to 2 arguments in a single memory object.
    
    #ifndef NRF_LOG_MSGPOOL_ELEMENT_SIZE
    #define NRF_LOG_MSGPOOL_ELEMENT_SIZE 20
    #endif
    
    // <o> NRF_LOG_MSGPOOL_ELEMENT_COUNT - Number of elements in the pool of memory objects 
    // <i> If a small value is set, then it may lead to a deadlock
    // <i> in certain cases if backend has high latency and holds
    // <i> multiple messages for long time. Bigger value impacts
    // <i> RAM memory usage.
    
    #ifndef NRF_LOG_MSGPOOL_ELEMENT_COUNT
    #define NRF_LOG_MSGPOOL_ELEMENT_COUNT 8
    #endif
    
    // </h> 
    //==========================================================
    
    // <q> NRF_LOG_ALLOW_OVERFLOW  - Configures behavior when circular buffer is full.
     
    
    // <i> If set then oldest logs are overwritten. Otherwise a 
    // <i> marker is injected informing about overflow.
    
    #ifndef NRF_LOG_ALLOW_OVERFLOW
    #define NRF_LOG_ALLOW_OVERFLOW 1
    #endif
    
    // <o> NRF_LOG_BUFSIZE  - Size of the buffer for storing logs (in bytes).
     
    
    // <i> Must be power of 2 and multiple of 4.
    // <i> If NRF_LOG_DEFERRED = 0 then buffer size can be reduced to minimum.
    // <128=> 128 
    // <256=> 256 
    // <512=> 512 
    // <1024=> 1024 
    // <2048=> 2048 
    // <4096=> 4096 
    // <8192=> 8192 
    // <16384=> 16384 
    
    #ifndef NRF_LOG_BUFSIZE
    #define NRF_LOG_BUFSIZE 1024
    #endif
    
    // <q> NRF_LOG_CLI_CMDS  - Enable CLI commands for the module.
     
    
    #ifndef NRF_LOG_CLI_CMDS
    #define NRF_LOG_CLI_CMDS 0
    #endif
    
    // <o> NRF_LOG_DEFAULT_LEVEL  - Default Severity level
     
    // <0=> Off 
    // <1=> Error 
    // <2=> Warning 
    // <3=> Info 
    // <4=> Debug 
    
    #ifndef NRF_LOG_DEFAULT_LEVEL
    #define NRF_LOG_DEFAULT_LEVEL 3
    #endif
    
    // <q> NRF_LOG_DEFERRED  - Enable deffered logger.
     
    
    // <i> Log data is buffered and can be processed in idle.
    
    #ifndef NRF_LOG_DEFERRED
    #define NRF_LOG_DEFERRED 1
    #endif
    
    // <q> NRF_LOG_FILTERS_ENABLED  - Enable dynamic filtering of logs.
     
    
    #ifndef NRF_LOG_FILTERS_ENABLED
    #define NRF_LOG_FILTERS_ENABLED 0
    #endif
    
    // <o> NRF_LOG_STR_PUSH_BUFFER_SIZE  - Size of the buffer dedicated for strings stored using @ref NRF_LOG_PUSH.
     
    // <16=> 16 
    // <32=> 32 
    // <64=> 64 
    // <128=> 128 
    // <256=> 256 
    // <512=> 512 
    // <1024=> 1024 
    
    #ifndef NRF_LOG_STR_PUSH_BUFFER_SIZE
    #define NRF_LOG_STR_PUSH_BUFFER_SIZE 128
    #endif
    
    // <o> NRF_LOG_STR_PUSH_BUFFER_SIZE  - Size of the buffer dedicated for strings stored using @ref NRF_LOG_PUSH.
     
    // <16=> 16 
    // <32=> 32 
    // <64=> 64 
    // <128=> 128 
    // <256=> 256 
    // <512=> 512 
    // <1024=> 1024 
    
    #ifndef NRF_LOG_STR_PUSH_BUFFER_SIZE
    #define NRF_LOG_STR_PUSH_BUFFER_SIZE 128
    #endif

    The log settings does not necessarily need to be identical, but if the log settings are different and one is working and the other isnt, then please post the relevant sections from the sdk_config files. 

    Best regards

    Bjørn 

  • Hi Bjorn, they are both working. If I just run the bootloader it just works. If I just run the application it works. The only time it goes wrong is if the bootloader starts the application. Hence, I would be very surprised if using the sdk_config.h from some example would help very much. I think it leads you into a tangent, but you can check the particular config at https://github.com/crownstone/bluenet/tree/sdk15 namely https://github.com/crownstone/bluenet/blob/sdk15/include/third/nrf/sdk_config.h for the application and https://github.com/crownstone/bluenet/blob/sdk15/bootloader/sdk_config.h for the bootloader.

    It is not a matter of log settings "being different". It is only a matter of the context. When the bootloader starts the application I'm afraid the SoftDevice is again allocating something or does something else it is not supposed to do again. I don't have access to the properietary parts of the SoftDevice so I'm not certain if it frees everything properly after the bootloader stopped doing its thing. I'm assuming there is a bug there.

Related