nrfx_gpiote interrupt causing hard fault

[aplatts]

Hi

Using the nrf52840-dk with SD S140 and nrfx_gpiote, everything runs fund (BLE, TWI etc) but interrup on pin 0,28 causes a Hard Fault. I can not get any sensible logs to diagnose the issue (I'm using VSC and not familiar with Debug).

//IMU Interrup PIN Handler
    nrfx_gpiote_in_config_t in_config = NRFX_GPIOTE_CONFIG_IN_SENSE_HITOLO(true);
    in_config.pull = NRF_GPIO_PIN_PULLDOWN; //NRF_GPIO_PIN_NOPULL;
    in_config.hi_accuracy = true;
    err_code = nrfx_gpiote_in_init(MPU_INT_PIN, &in_config, in_pin_handler);
    APP_ERROR_CHECK(err_code);
    nrfx_gpiote_in_event_enable(MPU_INT_PIN, true);

Any ideas?

Thanks

[Håkon Alseth]

Hi,

 

Could you try to increment the define sdk_config.h::GPIOTE_CONFIG_NUM_OF_LOW_POWER_EVENTS and see if this helps?

 

Kind regards,

Håkon

[aplatts]

Hi

Currently set to 6, fault still present:

#ifndef NRFX_GPIOTE_CONFIG_NUM_OF_LOW_POWER_EVENTS

#define NRFX_GPIOTE_CONFIG_NUM_OF_LOW_POWER_EVENTS 6

#endif

Less than 4 causes a Mem Fault in GPIOTE.

As I am using bsp_btn_ble, will this conflict?

Thanks

[aplatts]

Hi

This is the output from arm-none-eabi-gdb:

c
Continuing.
{"token":33,"outOfBandRecord":[],"resultRecords":{"resultClass":"running","results":[]}}

Program
 received signal SIGTRAP, Trace/breakpoint trap.
0x00028a10 in app_error_fault_handler (id=id@entry=16385, pc=pc@entry=0, info=info@entry=537132804) at ../../../../nRF5SDK160098a08e2/components/libraries/util/app_error_weak.c:100
100	    NRF_BREAKPOINT_COND;
bt full
#0  0x00028a10 in app_error_fault_handler (id=id@entry=16385, pc=pc@entry=0, info=info@entry=537132804) at ../../../../nRF5SDK160098a08e2/components/libraries/util/app_error_weak.c:100
No locals.
#1  0x000289dc in app_error_handler_bare (error_code=<optimized out>) at ../../../../nRF5SDK160098a08e2/components/libraries/util/app_error.c:73
        error_info = {line_num = 0
, p_file_name = 0x0
, err_code = 537132796
}

#2  0x000343d4 in ble_stack_init () at ../../../main.c:635
        LOCAL_ERR_CODE = <optimized out>
        err_code = <optimized out>
        ram_start = 785441024

[Håkon Alseth]

Hi,

 

Thank you for the stack trace. 

The compiler is optimizing a bit too much here, but I suspect this error is due to the amount of RAM that the stack is given.

Could you try to adjust the RAM start address in your linker script (.ld file in your armgcc folder) to see if this helps?

https://devzone.nordicsemi.com/nordic/short-range-guides/b/getting-started/posts/adjustment-of-ram-and-flash-memory

 

If you change the optimization level to "-Og -ggdb" in your makefile, and recompile/flash, you should see more symbols in the debug view. If you in addition, add the CFLAGS += -DDEBUG, you will enable blocking assertions with "error_info" struct above being populated with file name, line number, error code, so you can see exactly where the assert occurred.

 

Kind regards,

Håkon

[aplatts]

Hi

After a lot of stepping through, I've found that I receive the following error after receding and interrupt signal on P0,28:

"SOFTDEVICE: ASSERTION FAILED" which is followed by: NRF_BREAKPOINT_COND (On assert, the system can only recover with a reset.

This is the output I get from Debug Console:

0001431775: 5929-exec-continue --thread 1
0001431776: GDB -> App: {"token":5929,"outOfBandRecord":[],"resultRecords":{"resultClass":"running","results":[]}}
0001431776: GDB -> App: {"outOfBandRecord":[{"isStream":false,"type":"exec","asyncClass":"running","output":[["thread-id","all"]]}]}
0001442172: GDB -> App: {"outOfBandRecord":[{"isStream":true,"type":"console","content":"\nProgram"}]}
0001442172: 
Program
0001442172: GDB -> App: {"outOfBandRecord":[{"isStream":true,"type":"console","content":" received signal SIGTRAP, Trace/breakpoint trap.\n"}]}
0001442172:  received signal SIGTRAP, Trace/breakpoint trap.
0001442176: GDB -> App: {"outOfBandRecord":[{"isStream":true,"type":"console","content":"0x00028724 in app_error_fault_handler (id=1, pc=86108, info=0) at ../../../../nRF5SDK160098a08e2/components/libraries/util/app_error_weak.c:100\n"}]}
0001442176: 0x00028724 in app_error_fault_handler (id=1, pc=86108, info=0) at ../../../../nRF5SDK160098a08e2/components/libraries/util/app_error_weak.c:100
0001442176: GDB -> App: {"outOfBandRecord":[{"isStream":true,"type":"console","content":"100\t    NRF_BREAKPOINT_COND;\n"}]}
0001442176: 100	    NRF_BREAKPOINT_COND;

Thanks for your help. Any ideas?

[Håkon Alseth]

Hi,

 

There's no backtrack in your gdb trace.

if you break/continue/break with the softdevice enabled, it will assert inside the softdevice, as the debugger only halts the CPU core, not the peripherals (like RTC, Radio, and timers). This will then cause all events to occur at the same time when starting the CPU again, and the softdevice then gets interrupts out-of-order and asserts.

 

Every time you break, do a "mon reset" before continuing again to avoid this.

 

Kind regards,

Håkon

[aplatts]

Hi Hakon

Managed to get the Jlink GDB Server up and running.

Had to issue a CTRL-C in order to run 'bt full' as the'b HardFault_Handler' breakpoint wasn't hit. Output as follows:

(gdb) bt full
#0  0x0002749e in serial_tx (p_context=<optimized out>, p_buffer=<optimized out>, len=<optimized out>)
    at ../../../../nRF5SDK160098a08e2/components/libraries/log/src/nrf_log_backend_uart.c:88
        len8 = <optimized out>
        err_code = <optimized out>
#1  0x0002a61a in nrf_fprintf_buffer_flush (p_ctx=p_ctx@entry=0x2003fef0)
    at ../../../../nRF5SDK160098a08e2/external/fprintf/nrf_fprintf.c:56
No locals.
#2  0x00028184 in postfix_process (p_params=p_params@entry=0x2003fee4, p_ctx=p_ctx@entry=0x2003fef0, 
    newline=newline@entry=false) at ../../../../nRF5SDK160098a08e2/components/libraries/log/src/nrf_log_str_formatter.c:150
No locals.
#3  0x000281ee in nrf_log_std_entry_process (p_str=p_str@entry=0x37260 "Transfer type: %s.", p_args=p_args@entry=0x2003fec0, 
    nargs=nargs@entry=1, p_params=p_params@entry=0x2003fee4, p_ctx=p_ctx@entry=0x2003fef0)
    at ../../../../nRF5SDK160098a08e2/components/libraries/log/src/nrf_log_str_formatter.c:192
        auto_flush = false
#4  0x00027388 in nrf_log_backend_serial_put (p_backend=<optimized out>, p_msg=0x20002444 <log_mempool_nrf_balloc_pool_mem>, 
    p_buffer=p_buffer@entry=0x200023f8 <m_string_buff> "<info> TWI: Transfer type: XFER_RX.\r\r\nn_init, error code: NRF_SU", 
    length=length@entry=64, tx_func=tx_func@entry=0x27481 <serial_tx>)
    at ../../../../nRF5SDK160098a08e2/components/libraries/log/src/nrf_log_backend_serial.c:87
        p_log_str = 0x37260 "Transfer type: %s."
        nargs = 1
        args = {225872, 537132928, 537132880, 183151, 183141, 180577}
        fprintf_ctx = {
          p_io_buffer = 0x200023f8 <m_string_buff> "<info> TWI: Transfer type: XFER_RX.\r\r\nn_init, error code: NRF_SU", 
          io_buffer_size = 64, io_buffer_cnt = 38, auto_flush = false, p_user_ctx = 0x0, fwrite = 0x27481 <serial_tx>}
        params = {timestamp = 0, module_id = 5, dropped = 0, severity = NRF_LOG_SEVERITY_INFO, use_colors = 0 '\000'}
        header = {base = {generic = {type = 1, in_progress = 0, data = 28913675}, std = {type = 1, in_progress = 0, 
              severity = 3, nargs = 1, addr = 225888}, hexdump = {type = 1, in_progress = 0, severity = 3, offset = 513, 
              reserved = 9, len = 55}, raw = 231309401}, module_id = 5, dropped = 0, timestamp = 0}
        memobj_offset = 12
#5  0x00027470 in nrf_log_backend_uart_put (p_backend=<optimized out>, p_msg=<optimized out>)
    at ../../../../nRF5SDK160098a08e2/components/libraries/log/src/nrf_log_backend_uart.c:95
No locals.
#6  0x00027922 in nrf_log_backend_put (p_msg=0x20002444 <log_mempool_nrf_balloc_pool_mem>, 
    p_backend=0x37570 <uart_log_backend>)
    at ../../../../nRF5SDK160098a08e2/components/libraries/log/nrf_log_backend_interface.h:225
No locals.
--Type <RET> for more, q to quit, c to continue without paging--
#7  nrf_log_frontend_dequeue () at ../../../../nRF5SDK160098a08e2/components/libraries/log/src/nrf_log_frontend.c:862
        entry_accepted = true
        backend_id = <optimized out>
        p_module_filter = <optimized out>
        backend_lvl = <optimized out>
        p_backend = 0x37570 <uart_log_backend>
        rd_idx = 46
        mask = <optimized out>
        p_header = <optimized out>
        header = {base = {generic = {type = 1, in_progress = 0, data = 28913675}, std = {type = 1, in_progress = 0, severity = 3, nargs = 1, addr = 225888}, 
            hexdump = {type = 1, in_progress = 0, severity = 3, offset = 513, reserved = 9, len = 55}, raw = 231309401}, module_id = 5, dropped = 0, 
          timestamp = 0}
        p_msg_buf = 0x20002444 <log_mempool_nrf_balloc_pool_mem>
        memobj_offset = <optimized out>
        severity = <optimized out>
        i = <optimized out>
#8  0x00034456 in in_pin_handler (pin=<optimized out>, action=<optimized out>) at ../../../bno080-nrf-twi.c:114
No locals.
#9  0x0002bfae in GPIOTE_IRQHandler () at ../../../../nRF5SDK160098a08e2/modules/nrfx/drivers/src/nrfx_gpiote.c:716
        pin = <optimized out>
        polarity = <optimized out>
        handler = <optimized out>
        status = 1
        input = {0, 0}
        i = 0
        event = <optimized out>
        mask = 1
#10 <signal handler called>
No symbol table info available.
#11 0x000372d0 in delay_machine_code ()
No symbol table info available.
#12 0x000344a2 in nrfx_coredep_delay_us (time_us=500) at ../../../../nRF5SDK160098a08e2/modules/nrfx/soc/nrfx_coredep.h:173
        delay_cycles = 0x372d1 <delay_machine_code>
        cycles = 32000
        delay_machine_code = {14339, 55549, 18288}
        delay_cycles = <optimized out>
        cycles = <optimized out>
#13 BNO_080_set_mode () at ../../../bno080-nrf-twi.c:46
        err_code = <optimized out>
        reg = "\024\001"
        xfer_desc = {type = NRFX_TWI_XFER_RX, address = 75 'K', primary_length = 2, secondary_length = 524291, p_primary_buf = 0x2003ffe4 "\024\001", 
          p_secondary_buf = 0x10001000 '\377' <repeats 200 times>...}
#14 0x000336e4 in main () at ../../../main.c:838
        erase_bonds = false
(gdb) 

And this is the output without setting 'b HardFault_Handler' (again required CTR-C to obtain a 'bt full'):

(gdb) bt full
#0  0x000274a0 in serial_tx (p_context=<optimized out>, p_buffer=<optimized out>, len=<optimized out>)
    at ../../../../nRF5SDK160098a08e2/components/libraries/log/src/nrf_log_backend_uart.c:88
        len8 = <optimized out>
        err_code = <optimized out>
#1  0x0002a61a in nrf_fprintf_buffer_flush (p_ctx=p_ctx@entry=0x2003fef0) at ../../../../nRF5SDK160098a08e2/external/fprintf/nrf_fprintf.c:56
No locals.
#2  0x00028184 in postfix_process (p_params=p_params@entry=0x2003fee4, p_ctx=p_ctx@entry=0x2003fef0, newline=newline@entry=false)
    at ../../../../nRF5SDK160098a08e2/components/libraries/log/src/nrf_log_str_formatter.c:150
No locals.
#3  0x000281ee in nrf_log_std_entry_process (p_str=p_str@entry=0x37260 "Transfer type: %s.", p_args=p_args@entry=0x2003fec0, nargs=nargs@entry=1, 
    p_params=p_params@entry=0x2003fee4, p_ctx=p_ctx@entry=0x2003fef0) at ../../../../nRF5SDK160098a08e2/components/libraries/log/src/nrf_log_str_formatter.c:192
        auto_flush = false
#4  0x00027388 in nrf_log_backend_serial_put (p_backend=<optimized out>, p_msg=0x20002444 <log_mempool_nrf_balloc_pool_mem>, 
    p_buffer=p_buffer@entry=0x200023f8 <m_string_buff> "<info> TWI: Transfer type: XFER_RX.\r\r\nn_init, error code: NRF_SU", length=length@entry=64, 
    tx_func=tx_func@entry=0x27481 <serial_tx>) at ../../../../nRF5SDK160098a08e2/components/libraries/log/src/nrf_log_backend_serial.c:87
        p_log_str = 0x37260 "Transfer type: %s."
        nargs = 1
        args = {225872, 537132928, 537132880, 183151, 183141, 180577}
        fprintf_ctx = {p_io_buffer = 0x200023f8 <m_string_buff> "<info> TWI: Transfer type: XFER_RX.\r\r\nn_init, error code: NRF_SU", io_buffer_size = 64, 
          io_buffer_cnt = 38, auto_flush = false, p_user_ctx = 0x0, fwrite = 0x27481 <serial_tx>}
        params = {timestamp = 0, module_id = 5, dropped = 0, severity = NRF_LOG_SEVERITY_INFO, use_colors = 0 '\000'}
        header = {base = {generic = {type = 1, in_progress = 0, data = 28913675}, std = {type = 1, in_progress = 0, severity = 3, nargs = 1, addr = 225888}, hexdump = {
              type = 1, in_progress = 0, severity = 3, offset = 513, reserved = 9, len = 55}, raw = 231309401}, module_id = 5, dropped = 0, timestamp = 0}
--Type <RET> for more, q to quit, c to continue without paging--
        memobj_offset = 12
#5  0x00027470 in nrf_log_backend_uart_put (p_backend=<optimized out>, p_msg=<optimized out>)
    at ../../../../nRF5SDK160098a08e2/components/libraries/log/src/nrf_log_backend_uart.c:95
No locals.
#6  0x00027922 in nrf_log_backend_put (p_msg=0x20002444 <log_mempool_nrf_balloc_pool_mem>, p_backend=0x37570 <uart_log_backend>)
    at ../../../../nRF5SDK160098a08e2/components/libraries/log/nrf_log_backend_interface.h:225
No locals.
#7  nrf_log_frontend_dequeue () at ../../../../nRF5SDK160098a08e2/components/libraries/log/src/nrf_log_frontend.c:862
        entry_accepted = true
        backend_id = <optimized out>
        p_module_filter = <optimized out>
        backend_lvl = <optimized out>
        p_backend = 0x37570 <uart_log_backend>
        rd_idx = 46
        mask = <optimized out>
        p_header = <optimized out>
        header = {base = {generic = {type = 1, in_progress = 0, data = 28913675}, std = {type = 1, in_progress = 0, severity = 3, nargs = 1, addr = 225888}, hexdump = {
              type = 1, in_progress = 0, severity = 3, offset = 513, reserved = 9, len = 55}, raw = 231309401}, module_id = 5, dropped = 0, timestamp = 0}
        p_msg_buf = 0x20002444 <log_mempool_nrf_balloc_pool_mem>
        memobj_offset = <optimized out>
        severity = <optimized out>
        i = <optimized out>
#8  0x00034456 in in_pin_handler (pin=<optimized out>, action=<optimized out>) at ../../../bno080-nrf-twi.c:114
No locals.
#9  0x0002bfae in GPIOTE_IRQHandler () at ../../../../nRF5SDK160098a08e2/modules/nrfx/drivers/src/nrfx_gpiote.c:716
        pin = <optimized out>
        polarity = <optimized out>
        handler = <optimized out>
        status = 1
        input = {0, 0}
        i = 0
        event = <optimized out>
        mask = 1
#10 <signal handler called>
No symbol table info available.
#11 0x000372d2 in delay_machine_code ()
No symbol table info available.
#12 0x000344a2 in nrfx_coredep_delay_us (time_us=500) at ../../../../nRF5SDK160098a08e2/modules/nrfx/soc/nrfx_coredep.h:173
        delay_cycles = 0x372d1 <delay_machine_code>
        cycles = 32000
        delay_machine_code = {14339, 55549, 18288}
        delay_cycles = <optimized out>
        cycles = <optimized out>
#13 BNO_080_set_mode () at ../../../bno080-nrf-twi.c:46
        err_code = <optimized out>
--Type <RET> for more, q to quit, c to continue without paging--
        reg = "\024\201"
        xfer_desc = {type = NRFX_TWI_XFER_RX, address = 75 'K', primary_length = 2, secondary_length = 524291, p_primary_buf = 0x2003ffe4 "\024\201", 
          p_secondary_buf = 0x10001000 '\377' <repeats 200 times>...}
#14 0x000336e4 in main () at ../../../main.c:838
        erase_bonds = false

Thanks

Andrew

[Håkon Alseth]

Hi Andrew,

 

Is the device always stuck in this function? What is printed on the UART?

It seems that you are printing UART strings directly from the GPIOTE interrupt, which isn't recommended as you're blocking other processes in your firmware. Interrupts should be as short as possible in terms of processing. The GPIOTE interrupt seems to occur when you are communicating with the BNO080-sensor. Do these two functions share any status variables or similar?

 

Kind regards,

Håkon

[aplatts]

Hi Hakon

I noticed that too, that the interrupt function was printing to the UART so I offloaded that to a secondary function (see below).

//IMU Interrup PIn Handler
    nrfx_gpiote_in_config_t in_config = NRFX_GPIOTE_CONFIG_IN_SENSE_HITOLO(true);
    in_config.pull = NRF_GPIO_PIN_PULLDOWN; //NRF_GPIO_PIN_NOPULL;
    in_config.hi_accuracy = true;
    err_code = nrfx_gpiote_in_init(MPU_INT_PIN, &in_config, in_pin_handler);
    APP_ERROR_CHECK(err_code);
    nrfx_gpiote_in_event_enable(MPU_INT_PIN, true);


//Interrup Handling

void inpinoffload() {
    NRF_LOG_INFO("inpinoffload");
    NRF_LOG_FLUSH();
}
void in_pin_handler(nrfx_gpiote_pin_t pin, nrf_gpiote_polarity_t action)
{
    inpinoffload();
}

Re the interrupt itself, it is from the BNO080 itself. The interrupt indicates that :

1. Host asserts WAKE signal, requesting hub to become ready for a transfer.

2. Hub asserts HINT signal, indicating that it is ready for a transfer.

3. Hub deasserts HINT when transfer begins.

All this is over TWI.

Thanks

Andrew

[Håkon Alseth]

Hi,

 

You still execute the NRF_LOG_ function in the interrupt.

try setting a boolean flag in the in_pin_handler(), like this:

static volatile bool pin_int_has_occurred;

void in_pin_handler(nrfx_gpiote_pin_t pin, nrf_gpiote_polarity_t action)
{
  if (pin == MPU_INT_PIN) 
  {
    pin_int_has_occurred = true;
  }
}

...

in main:

if (pin_int_has_occurred == true)
{
  pin_int_has_occurred = false;
  /* Do rest of processing */
}

 

Kind regards,

Håkon

[aplatts]

Hi

Looks to be the issue, didn't realise how impactful the NRF_LOG_INFO command is. The blocking it was causing certainly was the issue.

Thanks for helping on this one.