UART/FS Logging Backend with GRTC-driven EGU Interrupt slows down logging output

[br_adams_01]

Hello,

I am working on incorporating flash logging into an application that has a GRTC-driven EGU interrupt (capture/compare event). Here is where I am setting up the EGU and connecting it to the GRTC Capture/Compare event with a PPI channel. The GRTC is used for timed interrupts so that I do not have to use the Zephyr timer module (uses more energy).

Called from main upon application startup

void init_ppi_egu() {
#if defined(__ZEPHYR__)
	IRQ_CONNECT(NRFX_IRQ_NUMBER_GET(NRF_EGU_INST_GET(10)), IRQ_PRIO_LOWEST,
				NRFX_EGU_INST_HANDLER_GET(10), 0, 0);
#endif
    nrfx_err_t status;
    int err;
	nrf_egu_task_t egu_event = NRF_EGU_TASK_TRIGGER0;
	uint8_t ppi_chan_grtc_int;
    nrfx_egu_t egu_inst = NRFX_EGU_INSTANCE(10);
    void * p_context = "Some context";
    status = nrfx_egu_init(&egu_inst, 5, egu_handler, p_context);
    nrfx_egu_int_enable(&egu_inst, (uint32_t)1);
    if (nrfx_gppi_channel_alloc(&ppi_chan_grtc_int) != NRFX_SUCCESS) {
		printk("Failed allocating PPI chan for grtc interrupt\n");
	}
    nrfx_gppi_channel_endpoints_setup(ppi_chan_grtc_int,
					  nrf_grtc_event_address_get(NRF_GRTC, nrf_grtc_sys_counter_compare_event_get(grtc_channel)),
					  nrfx_egu_task_address_get(&egu_inst, egu_event));
    nrfx_gppi_channels_enable(BIT(ppi_chan_grtc_int));
}

In a separate config file, flash_logging.conf:

CONFIG_FLASH=y
CONFIG_FLASH_MAP=y
CONFIG_FLASH_PAGE_LAYOUT=y
CONFIG_FLASH_LOG_LEVEL_DBG=y

CONFIG_LOG_BACKEND_FS=y

CONFIG_FILE_SYSTEM=y
CONFIG_FILE_SYSTEM_LITTLEFS=y
CONFIG_LOG_MAX_LEVEL=3
CONFIG_LOG_TIMESTAMP_64BIT=n
CONFIG_LOG_RUNTIME_FILTERING=y
CONFIG_LOG_BACKEND_UART=y
CONFIG_SHELL_LOG_BACKEND=n

# Log backend config
CONFIG_LOG_BACKEND_FS_FILE_SIZE=40960
CONFIG_LOG_BACKEND_FS_FILES_LIMIT=3

If both flash logging AND the EGU interrupt is used, the UART output is only giving me ~1 log line every second in the log, but the EGU interrupt is working.

If I don't call the init_ppi_egu function out of main, and I just run the application as normal, the logging outputs at normal speed (for flash logging enabled).

Also, if I disable flash logging, and leave the EGU interrupt as is, the logging outputs at normal speed (for flash logging disabled).

I already tried messing with the egu10 peripheral interrupt priority and set it lower to see if maybe that was the issue, but it did not help.

Is there anything that I may be doing wrong?


Many thanks!

[br_adams_01]

I'm glad you mentioned the first point (#1), because I found something I may could try.

According to that integration note, it is stated that reconfiguring the interrupts for the GRTC while MPSL is enabled is not allowed. However, I could try to set the following Kconfig to true, which would allow me to reconfigure the interrupts:

CONFIG_MPSL_DYNAMIC_INTERRUPTS

I have not tried thought #2 yet.

For #3, I have not measured the current consumption in this state.

For #4, if I only use the window size and interval, apparently the RX mode is still enabled, and I get ~5 mA of constant average current as a result. So I have to enable and disable scanning with periodic interrupts to achieve the same effect, but by disabling RX as a result.

For #5, EGU triggers 1 second after program start to turn scanning on, and then EGU triggers again 30 seconds later to turn scanning off. After that, I stop scanning for 30 minutes (1800 seconds) before I trigger the EGU to turn scanning on again, and this happens in a cycle.

I am going to try the above Kconfig and see what happens.

UPDATE: The above Kconfig did not work. However, I will try to change to the Zephyr timer module to see the result.

[Vidar Berg]

br_adams_01 said:

For #4, if I only use the window size and interval, apparently the RX mode is still enabled, and I get ~5 mA of constant average current as a result. So I have to enable and disable scanning with periodic interrupts to achieve the same effect, but by disabling RX as a result.

This should be about as expected if you are scanning with a 100 % duty cycle @ 1.8v (scan window == scan interval) -  Online Power Profiler for Bluetooth LE  . The timeout/duration can be specified via the timeout field of the bt_le_scan_param struct.

br_adams_01 said:

For #5, EGU triggers 1 second after program start to turn scanning on, and then EGU triggers again 30 seconds later to turn scanning off. After that, I stop scanning for 30 minutes (1800 seconds) before I trigger the EGU to turn scanning on again, and this happens in a cycle.

There must be a bug somewhere if using a zephyr timer instance with this interval (https://docs.zephyrproject.org/latest/kernel/services/timing/timers.html#defining-a-timer) leads to a measurable increase in current consumption.  How to make the Intermittent application with GRTC and LFXO while asleep. 

br_adams_01 said:

However, I will try to change to the Zephyr timer module to see the result.

Please let me know when you've had a chance to try this.