GPIOTE interrupts with around 30us latency?

[Fernando Fontes]

Hi guys,

I've been working with the NRF52832 in the past days and I'm having issues with the GPIOTE interrupts.

It seems that there a latency of around 30us until the interrupt handler is called? 

To give a bit of context I'm working with the TDC1000 which is an Ultrasonic Sensing Analog Front End that will return the distance by triggering an interrupt on the stop pin. To calculate the distance I need to have the start interrupt time and use it to subtract with the stop interrupt time. Since it's an 1MHz transducer, it means that 10us is equal to 7mm (10 * 1450 / 2). That's why I really need the interrupts to work with zero latency. In theory if the latency is always the same it should still work since it will compensate when subtracting, but I'm afraid that is not the case. To measure the time I'm using a timer running at 16MHz which should give me enough accuracy (1/16).

The way I've code the interrupts was:

#define TIMER_INST_IDX 0

static const struct gpio_dt_spec tdc1000_en = GPIO_DT_SPEC_GET_OR(DT_ALIAS(tdc1000_en), gpios, {0});
static const struct gpio_dt_spec tdc1000_rst = GPIO_DT_SPEC_GET_OR(DT_ALIAS(tdc1000_rst), gpios, {0});
static const struct gpio_dt_spec tdc1000_trigger = GPIO_DT_SPEC_GET_OR(DT_ALIAS(tdc1000_trigger), gpios, {0});
static const struct gpio_dt_spec tdc1000_chsel = GPIO_DT_SPEC_GET_OR(DT_ALIAS(tdc1000_chsel), gpios, {0});
static const struct gpio_dt_spec tdc1000_start = GPIO_DT_SPEC_GET_OR(DT_ALIAS(tdc1000_start), gpios, {0});
static const struct gpio_dt_spec tdc1000_stop = GPIO_DT_SPEC_GET_OR(DT_ALIAS(tdc1000_stop), gpios, {0});
static const struct gpio_dt_spec tdc1000_errb = GPIO_DT_SPEC_GET_OR(DT_ALIAS(tdc1000_errb), gpios, {0});

static const struct gpio_dt_spec *required_gpios_ins[3] = {&tdc1000_start, &tdc1000_stop, &tdc1000_errb};
static const gpio_flags_t gpio_ins_flags[3] = {GPIO_INPUT | GPIO_PULL_DOWN, GPIO_INPUT | GPIO_PULL_DOWN, GPIO_INPUT};
static const gpio_flags_t gpio_ins_int_flags[3] = {GPIO_INT_EDGE_TO_ACTIVE, GPIO_INT_EDGE_TO_ACTIVE, GPIO_INT_EDGE_TO_INACTIVE};

K_MSGQ_DEFINE(gpio_interrupt_q, sizeof(gpio_int_context_t), INT_QUEUE_SIZE, 4);

static nrfx_timer_t tof_timer_inst = NRFX_TIMER_INSTANCE(TIMER_INST_IDX);

uint8_t tank_reader_init(void)
{
    int err;
        for (uint8_t i = 0; i < sizeof(required_gpios_ins) / sizeof(struct gpio_dt_spec *); i++)
    {
        if (!gpio_is_ready_dt(required_gpios_ins[i]))
        {
            LOG_ERR("One of the required GPIO's port is not ready.\n");
            return EXIT_FAILURE;
        }

        err = gpio_pin_configure_dt(required_gpios_ins[i], gpio_ins_flags[i]);
        if (err != 0)
        {
            LOG_ERR("Error %d: failed to configure %s pin %d",
                    err, required_gpios_ins[i]->port->name, required_gpios_ins[i]->pin);
            return EXIT_FAILURE;
        }

        err = gpio_pin_interrupt_configure_dt(required_gpios_ins[i], gpio_ins_int_flags[i]);
        if (err != 0)
        {
            LOG_ERR("Error %d: failed to configure interrupt on %s pin %d",
                    err, required_gpios_ins[i]->port->name, required_gpios_ins[i]->pin);
            return EXIT_FAILURE;
        }

        gpio_init_callback(gpio_cb_data[i], gpio_interrupt_handler, BIT(required_gpios_ins[i]->pin));

        gpio_add_callback(required_gpios_ins[i]->port, gpio_cb_data[i]);
    }

    // Configure timer that will later be used for measuring the ToF
    nrfx_err_t status;
    uint32_t base_frequency = NRF_TIMER_BASE_FREQUENCY_GET(tof_timer_inst.p_reg);
    LOG_INF("Base frequency: %u", base_frequency); // 16000000
    nrfx_timer_config_t config = NRFX_TIMER_DEFAULT_CONFIG(base_frequency);
    config.mode = NRF_TIMER_MODE_TIMER;
    config.bit_width = TIMER_BITMODE_BITMODE_32Bit; // approx. 4.4 min
    config.p_context = &tof_timer_inst;
    status = nrfx_timer_init(&tof_timer_inst, &config, NULL);
    if (status != NRFX_SUCCESS)
    {
        LOG_ERR("Error while configuring timer for ToF reading!");
        return EXIT_FAILURE;
    }

    NVIC_SetPriority(GPIOTE_IRQn, IRQ_PRIO_LOWEST);
    NVIC_SetPriority(TIMER0_IRQn, IRQ_PRIO_LOWEST);

    return EXIT_SUCCESS;
}

uint8_t tank_reader_get_level() {
    // flush
    k_msgq_purge(&gpio_interrupt_q);

    LOG_INF("Triggering TDC");

    // enables 16Mhz timer ()
    nrfx_timer_enable(&tof_timer_inst);
    if (!nrfx_timer_is_enabled(&tof_timer_inst))
    {
        LOG_ERR("Timer is not working. Unable to calculate ToF!");
        return EXIT_FAILURE;
    }
    nrfx_timer_clear(&tof_timer_inst); // reset

    uint32_t triggered_timer_value = nrfx_timer_capture(&tof_timer_inst, NRF_TIMER_CC_CHANNEL0);
    tank_reader_drive_trigger_tdc(1);
    tank_reader_drive_trigger_tdc(0);

    // wait for trigger start
    if ((k_msgq_get(&gpio_interrupt_q, &interrupt_context, K_MSEC(1)) == 0) && (interrupt_context.pin == TDC1000_START_PIN))
    {
        uint32_t timeout_count_start = (uint32_t)k_uptime_get();
        uint32_t elapsed = 0;

        LOG_INF("TX pulses transmitted after: %.2f usec.", (double)((interrupt_context.cycle_count - triggered_timer_value) * 0.0625f));

        uint32_t stop_cycle_count[INT_QUEUE_SIZE] = {0};
        uint32_t start_cycle_count = interrupt_context.cycle_count;
        uint8_t stop_cycles_detected = 0;

        // wait for reply
        while ((timeout > elapsed) && (k_msgq_get(&gpio_interrupt_q, &interrupt_context, K_MSEC(timeout - elapsed)) == 0))
        {
            // update elapsed for timeout calculation
            elapsed = (uint32_t)k_uptime_get() - timeout_count_start;

            if (interrupt_context.pin == TDC1000_ERRB_PIN)
            {
                LOG_ERR("ERRB pin triggered! Timeout...");
                break;
            }
            else if (interrupt_context.pin == TDC1000_STOP_PIN)
            {
                stop_cycle_count[stop_cycles_detected++] = interrupt_context.cycle_count;
            }
        }

        // stop the timer now
        nrfx_timer_disable(&tof_timer_inst);
    }
}

static void gpio_interrupt_handler(const struct device *dev, struct gpio_callback *cb, uint32_t pins)
{
    static gpio_int_context_t int_context = {0};

    int_context.cycle_count = nrfx_timer_capture(&tof_timer_inst, NRF_TIMER_CC_CHANNEL0);

    if (cb == &tdc1000_start_cb_data)
    {
        int_context.pin = TDC1000_START_PIN;
        // LOG_INF("Interrupt from START pin at %" PRIu32 "\n", int_context.cycle_count);
    }
    else if (cb == &tdc1000_stop_cb_data)
    {
        int_context.pin = TDC1000_STOP_PIN;
        // LOG_INF("Interrupt from STOP pin at %" PRIu32 "\n", int_context.cycle_count);
    }
    else if (cb == &tdc1000_errb_cb_data)
    {
        int_context.pin = TDC1000_ERRB_PIN;
        // LOG_INF("Interrupt from ERRB pin at %" PRIu32 "\n", int_context.cycle_count);
    }
    else
    {
        // Nothing to do
        return;
    }

    // add to the queue
    k_msgq_put(&gpio_interrupt_q, &int_context, K_NO_WAIT);
}

my prj.conf

CONFIG_SENSOR=y
CONFIG_LIS2DH=y
CONFIG_I2C=y
CONFIG_GPIO=y
CONFIG_LOG=y
CONFIG_USE_SEGGER_RTT=y
CONFIG_CONSOLE=y
CONFIG_RTT_CONSOLE=y
CONFIG_UART_CONSOLE=n
CONFIG_SERIAL=y
CONFIG_UART_INTERRUPT_DRIVEN=y
CONFIG_ADC=y
CONFIG_MCP970X=y
CONFIG_BT=y
CONFIG_PWM=y
CONFIG_CLOCK_CONTROL=y
CONFIG_SPI=y

CONFIG_WDT_LOG_LEVEL_INF=n
CONFIG_WATCHDOG=n
CONFIG_WDT_DISABLE_AT_BOOT=n

CONFIG_REQUIRES_FLOAT_PRINTF=y
CONFIG_BT_DEVICE_NAME="Beacon"

CONFIG_MAIN_THREAD_PRIORITY=10

CONFIG_LIS2DH_TRIGGER_OWN_THREAD=n
CONFIG_LIS2DH_ACCEL_RANGE_2G=y
CONFIG_LIS2DH_OPER_MODE_LOW_POWER=y
CONFIG_LIS2DH_ODR_1=y

CONFIG_NRFX_TIMER0=y

CONFIG_ZERO_LATENCY_IRQS=y

overlay:

&gpiote0 {
    interrupts = <6 0>;
};

The very first print (elapsed time since the trigger signal and the start interrupt): "TX pulses transmitted after: 30.2 usec" is wrong. I've used the oscilloscope to measure it and it reports 4.4us instead. 

But then the stop pulses seem to match the reality which let me think that the latency is always the same which still makes the code to work but it's not ideal. 

Calling NVIC_SetPriority seems to have no effect.

NVIC_SetPriority(GPIOTE_IRQn, IRQ_PRIO_LOWEST);

NVIC_SetPriority(TIMER0_IRQn, IRQ_PRIO_LOWEST);

Any other suggestions? Is this an expected behaviour when using Zephyr OS or is this something that can be fixable? I guess that I can try to have a counter instead of the timer, and use the stop and start pins to start and stop the counter? 

Thank you for the ongoing support,

Best regards,

Fernando Fontes

[Einar Thorsrud]

Hi,

I suggest you do this measurement with PPI instead of software, by hooking the TIMER to GPIOTE via PPI, similarily to whta is done here (this use GPIO as output so some changes are needed, but it shows how you can hook things up). With this, you can do the measurements in hardware and interrupt latency will not affect th emeasurment results.

[Fernando Fontes]

Hi Thorsrud,

Thank you for the response. Using PPI would require to set CONFIG_GPIO to 'n' which would then make everything else to stop working. 

I have other sensors on the board, a modem and they also require the GPIO lib to work. 

Is there any other way?

Best regards,

Fernando

[Fernando Fontes]

But I think I will have issues when trying to attach an interrupt to GPIOTE since when GPIO is enabled on zephyr it already does that. 

Is it possible to count the time between two pulses on different pins without having to enable interrupts to start/stop the timers from counting?

[Fernando Fontes]

Ok, I've done the following:

#if defined(__ZEPHYR__)
    IRQ_DIRECT_CONNECT(NRFX_IRQ_NUMBER_GET(NRF_TIMER_INST_GET(TIMER_INST_IDX)), IRQ_PRIO_LOWEST,
                       NRFX_TIMER_INST_HANDLER_GET(TIMER_INST_IDX), 0);
    IRQ_DIRECT_CONNECT(NRFX_IRQ_NUMBER_GET(NRF_GPIOTE), IRQ_PRIO_LOWEST, NRFX_GPIOTE_INST_HANDLER_GET(GPIOTE_INST_IDX),
                       0);
#endif

    nrfx_gpiote_t const gpiote_inst = NRFX_GPIOTE_INSTANCE(GPIOTE_INST_IDX);
    status = nrfx_gpiote_init(&gpiote_inst, IRQ_PRIO_LOWEST);
    if (status != NRFX_SUCCESS && status != NRFX_ERROR_ALREADY_INITIALIZED)
    {
        LOG_ERR("Error while configuring gpiote for ToF reading: %d", status);
        return EXIT_FAILURE;
    }

    uint8_t start_pin_ch, stop_pin_ch, errb_pin_ch;
    status = nrfx_gpiote_channel_alloc(&gpiote_inst, &start_pin_ch);
    if (status != NRFX_SUCCESS)
    {
        LOG_ERR("Error while alloc channel for ToF reading!");
        return EXIT_FAILURE;
    }

    status = nrfx_gpiote_channel_alloc(&gpiote_inst, &stop_pin_ch);
    if (status != NRFX_SUCCESS)
    {
        LOG_ERR("Error while alloc channel for ToF reading!");
        return EXIT_FAILURE;
    }

    status = nrfx_gpiote_channel_alloc(&gpiote_inst, &errb_pin_ch);
    if (status != NRFX_SUCCESS)
    {
        LOG_ERR("Error while alloc channel for ToF reading!");
        return EXIT_FAILURE;
    }

    static const nrf_gpio_pin_pull_t rising_input_config = NRF_GPIO_PIN_PULLDOWN;
    static const nrf_gpio_pin_pull_t falling_input_config = NRF_GPIO_PIN_PULLUP;

    const nrfx_gpiote_trigger_config_t start_rising_trigger_config = {
        .trigger = NRFX_GPIOTE_TRIGGER_LOTOHI,
        .p_in_channel = &start_pin_ch,
    };
    const nrfx_gpiote_trigger_config_t stop_rising_trigger_config = {
        .trigger = NRFX_GPIOTE_TRIGGER_LOTOHI,
        .p_in_channel = &stop_pin_ch,
    };
    const nrfx_gpiote_trigger_config_t errb_falling_trigger_config = {
        .trigger = NRFX_GPIOTE_TRIGGER_HITOLO,
        .p_in_channel = &errb_pin_ch,
    };
    static const nrfx_gpiote_handler_config_t handler_config = {
        .handler = gpiote_event_handler,
    };

    static nrfx_gpiote_input_pin_config_t start_cfg;
    start_cfg.p_handler_config = &handler_config;
    start_cfg.p_pull_config = &rising_input_config;
    start_cfg.p_trigger_config = &start_rising_trigger_config;

    static nrfx_gpiote_input_pin_config_t stop_cfg;
    stop_cfg.p_handler_config = &handler_config;
    stop_cfg.p_pull_config = &rising_input_config;
    stop_cfg.p_trigger_config = &stop_rising_trigger_config;

    static nrfx_gpiote_input_pin_config_t errb_cfg;
    errb_cfg.p_handler_config = &handler_config;
    errb_cfg.p_pull_config = &falling_input_config;
    errb_cfg.p_trigger_config = &errb_falling_trigger_config;

    status = nrfx_gpiote_input_configure(&gpiote_inst,
                                         tdc1000_start.pin,
                                         &start_cfg);

    status = nrfx_gpiote_input_configure(&gpiote_inst,
                                         tdc1000_stop.pin,
                                         &stop_cfg);

    status = nrfx_gpiote_input_configure(&gpiote_inst,
                                         tdc1000_errb.pin,
                                         &errb_cfg);

    nrfx_gpiote_trigger_enable(&gpiote_inst, tdc1000_start.pin, 1);
    nrfx_gpiote_trigger_enable(&gpiote_inst, tdc1000_stop.pin, 1);
    nrfx_gpiote_trigger_enable(&gpiote_inst, tdc1000_errb.pin, 1);

    uint8_t gppi_channel1, gppi_channel2, gppi_channel3;
    status = nrfx_gppi_channel_alloc(&gppi_channel1);

    status = nrfx_gppi_channel_alloc(&gppi_channel2);

    status = nrfx_gppi_channel_alloc(&gppi_channel3);

    nrfx_gppi_channel_endpoints_setup(gppi_channel1,
        nrfx_gpiote_in_event_address_get(&gpiote_inst, tdc1000_start.pin),
        nrfx_timer_task_address_get(&tof_timer_inst, NRF_TIMER_TASK_CAPTURE0));

    nrfx_gppi_channel_endpoints_setup(gppi_channel2,
        nrfx_gpiote_in_event_address_get(&gpiote_inst, tdc1000_stop.pin),
        nrfx_timer_task_address_get(&tof_timer_inst, NRF_TIMER_TASK_CAPTURE0));

    nrfx_gppi_channel_endpoints_setup(gppi_channel3,
        nrfx_gpiote_in_event_address_get(&gpiote_inst, tdc1000_errb.pin),
        nrfx_timer_task_address_get(&tof_timer_inst, NRF_TIMER_TASK_CAPTURE0));

    nrfx_gppi_channels_enable(BIT(gppi_channel1));
    nrfx_gppi_channels_enable(BIT(gppi_channel2));
    nrfx_gppi_channels_enable(BIT(gppi_channel3));
    

static void gpiote_event_handler(nrfx_gpiote_pin_t pin, nrfx_gpiote_trigger_t action, void *unused)
{
    // LOG_INF("INT on pin: %u", pin);

    static gpio_int_context_t int_context = {0};

    int_context.cycle_count = nrf_timer_cc_get(tof_timer_inst.p_reg, NRF_TIMER_CC_CHANNEL0);
    
    if (pin == tdc1000_start.pin) {
        int_context.pin = TDC1000_START_PIN;
    }
    else if (pin == tdc1000_stop.pin) {
        int_context.pin = TDC1000_STOP_PIN;
    }
    else if (pin == tdc1000_errb.pin) {
        int_context.pin = TDC1000_ERRB_PIN;
    }
    else {
        return;
    }

    // add to the queue
    k_msgq_put(&gpio_interrupt_q, &int_context, K_NO_WAIT);
}

This seems indeed to improve a lot the timing. Can you just take a look to make sure that I'm doing everything ok? 

My take was, since I want to read the time that it takes between the trigger command (writing to gpio) and the start interrupt followed by the echos (stop pin interrupt) i've configured ppi to NRF_TIMER_TASK_CAPTURE0. Then on the interrupt handler I'm retrieving the captured value. 

Best regards,

Fernando Fontes

[Einar Thorsrud]

Hi Fernando,

Yes, this is what I had in mind, and it looks good. With this, the interrupt latency does not affect the measurements. Note that depending on what fits best, you can also clear the timer like this so you will get an absolute cycle count between each event and not have to handle the timer wraping around.

[Fernando Fontes]

Hi Einar,

Yes, I could do that, but I'm cleaning the timer before starting the reading and the time of flight should not exceed 1ms. So, there turn around is not an issue with the 32 bit counter. 

I only have one question left. If I understood correctly ppi will capture the timer value and store it in the timer.p_reg register. Since I'm doing NRF_TIMER_TASK_CAPTURE0, the result will be on CHANNEL0 right? Is it possible that gpiote_event_handler is not fast enough and I could have the ppi capturing the value between two pulses and overwriting the register?

Best regards,

Fernando Fontes

[Einar Thorsrud]

Hi Fernando,

Yes, that is right. If you trigger NRF_TIMER_TASK_CAPTURE0, the result will be in the CC register for channel 0, and the next time you capture on the same channel, it will be overwritten. There are several channels though, so you could map different events to different capture tasks via PPI (in this case you could map each of the three GPIOTE events to separate capture tasks).