fstorage hang at sd_app_evt_wait()

Nordic DevZone
Nordic DevZone

I try to using nrf_fstorage_write() to write data to fstorage and then waiting writting finish. But it hang at sd_app_evt_wait().fstorage.h

#include "app_timer.h"
#include "error.h"
#include "fds_flash.h"
#include "fstorage.h"
#include "nrf_delay.h"
#include "nrf_fstorage.h"
#include "nrf_fstorage_sd.h"
#include "nrf_fstorage_nvmc.h"
#include "nrf_log.h"
#include "nrf_soc.h"
#include "spi_flash.h"

#define FSTORAGE_PAGE_NUM    3
#define FSTORAGE_WAIT_CNT    1000



static bool _gFstorageInitialized = false;
static bool _gFstorageEraseDone   = true;
static bool _gFstorageWriteDone   = true;
static bool _gFstoragePageDirty   = true;

static void _fstorageEvtHandler(nrf_fstorage_evt_t * p_evt);

NRF_FSTORAGE_DEF(nrf_fstorage_t _gFstorage) =
{
    /* Set a handler for fstorage events. */
    .evt_handler = _fstorageEvtHandler,

    /* These below are the boundaries of the flash space assigned to this instance of fstorage.
     * You must set these manually, even at runtime, before nrf_fstorage_init() is called.
     * The function nrf5_flash_end_addr_get() can be used to retrieve the last address on the
     * last page of flash available to write data. */
    .start_addr = 0x7D000,
    .end_addr   = 0x80000,
};

static void _fstorageEvtHandler(nrf_fstorage_evt_t * pEvt) {
    NRF_LOG_DEBUG("Evt e\n");
    switch (pEvt->id) {
        case NRF_FSTORAGE_EVT_WRITE_RESULT:
        {
            NRF_LOG_DEBUG("Evt w\n");
            _gFstorageWriteDone = true;
            if (pEvt->result != NRF_SUCCESS) {
               NRF_LOG_WARNING("fstorage writing failed %d bytes at address 0x%x.",
                            pEvt->len, pEvt->addr);
            } else {
                NRF_LOG_DEBUG("NRF_FSTORAGE_EVT_WRITE_RESULT ok");
                _gFstoragePageDirty = true;
            }
        } break;

        case NRF_FSTORAGE_EVT_ERASE_RESULT:
        {
            NRF_LOG_DEBUG("Evt er\n");
            _gFstorageEraseDone = true;
            if (pEvt->result != NRF_SUCCESS) {
                NRF_LOG_WARNING("fstorage erased failed %d page from address 0x%x.",
                                 pEvt->len, pEvt->addr);
            } else {
                NRF_LOG_DEBUG("NRF_FSTORAGE_EVT_ERASE_RESULT ok");
                _gFstoragePageDirty = false;
            }
        } break;

        default:
            break;
    }
     NRF_LOG_DEBUG("Evt x\n");
}

static uint32_t _fstorageGetEndAddr(void) {
    const uint32_t bootloaderAddr = BOOTLOADER_ADDRESS;
    const uint32_t pageSz         = NRF_FICR->CODEPAGESIZE;
    const uint32_t codeSz         = NRF_FICR->CODESIZE;

    return (bootloaderAddr != 0xFFFFFFFF ?
            bootloaderAddr : (codeSz * pageSz));
}

static uint32_t _fstorageGetStartAddr(void) {
    const uint32_t eraseUnit = _gFstorage.p_flash_info->erase_unit;
    const uint32_t endAddr = _fstorageGetEndAddr();
    const uint32_t bootloaderAddr = BOOTLOADER_ADDRESS;
    uint32_t startAddr;
    if (bootloaderAddr == 0xFFFFFFFF) {
        startAddr = endAddr - FDS_VIRTUAL_PAGES * eraseUnit; 
    } else {
        startAddr = bootloaderAddr - FSTORAGE_PAGE_NUM * eraseUnit;
    }

    NRF_LOG_DEBUG("endAddr=0x%x", endAddr);
    NRF_LOG_DEBUG("startAddr=0x%x", startAddr);
    return startAddr;
}
static bool _fstorageIsEraseNeeded(void) {
    return _gFstoragePageDirty;
}    

static uint32_t _fstorageRoundUpU32(const uint32_t len) {
    if (len % sizeof(uint32_t)) {
        return (len + sizeof(uint32_t) - (len % sizeof(uint32_t)));
    }

    return len;
}

static void power_manage(void)
{
#ifdef SOFTDEVICE_PRESENT
    (void) sd_app_evt_wait();
#else
    __WFE();
#endif
}

int _fstorageWait(const uint32_t timeOutCnt) {
#if 0
    NRF_LOG_DEBUG("timeOutCnt=%u\n", timeOutCnt);
    const uint32_t startCnt   = app_timer_cnt_get();
    NRF_LOG_DEBUG("startCnt=%u\n", startCnt);
    uint32_t endCnt;
    uint32_t diffCnt;

    do {
        endCnt           = app_timer_cnt_get();
        diffCnt          = app_timer_cnt_diff_compute(endCnt, startCnt);
        if (diffCnt >= timeOutCnt) {
            NRF_LOG_WARNING("_fstorage wait timeout\n");
            return ERROR_FSTORAGE_WAIT_TIMEOUT;
        }

        if (_gFstorageEraseDone && _gFstorageWriteDone) {
            break;
        }
    } while (true);

    NRF_LOG_DEBUG("endCnt=%u\n", endCnt);
#else
    while (nrf_fstorage_is_busy(&_gFstorage))
    {
        power_manage();
    }
#endif
		return 0;
    
}

int _fstorageRead(const uint32_t addr, const uint32_t len, uint8_t* data) {
    if (!_gFstorageInitialized) {
        return ERROR_FSTORAGE_UNINITIALIZED;
    }   

    const ret_code_t errCode = nrf_fstorage_read(&_gFstorage, addr, data, len);
    if (errCode != NRF_SUCCESS) {
        NRF_LOG_WARNING("nrf_fstorage_read() failed 0x%x\n", errCode);
        return ERROR_FSTORAGE_READ_FAIL;
    }

    return 0;
}

int _fstorageWrite(const uint32_t addr, const uint32_t len, void const* pData) {
    if (!_gFstorageInitialized) {
        return ERROR_FSTORAGE_UNINITIALIZED;
    }

    if (!_gFstorageEraseDone) {
        return ERROR_FSTORAGE_ERASE_ON_GOING;
    }

    if (!_gFstorageWriteDone) {
        return ERROR_FSTORAGE_WRITE_ON_GOING;
    }

    _gFstorageWriteDone = false;
    
    const uint32_t wlen = _fstorageRoundUpU32(len);
    const ret_code_t retCode = nrf_fstorage_write(&_gFstorage, addr, pData, wlen, NULL);
    if (retCode != NRF_SUCCESS) {
        NRF_LOG_WARNING("nrf_fstorage_write() failed 0x%x", retCode);
        return ERROR_FSTORAGE_WRITE_FAIL;
    }

    _fstorageWait(FSTORAGE_WAIT_CNT);

    return 0;
}


int fstorageInit(void) {
    _gFstorageInitialized = false;
    const ret_code_t errCode = nrf_fstorage_init(&_gFstorage, &nrf_fstorage_sd, NULL);
    if (errCode != NRF_SUCCESS) {
        NRF_LOG_WARNING("nrf_fstorage_init() failed 0x%x", errCode);
        return ERROR_FSTORAGE_INITIALIZE_FAIL;
    }

    _gFstorageInitialized = true;

    return 0;
}    

int fstorageErase(const uint32_t addr, const uint32_t pagesCnt) {
    if (!_gFstorageInitialized) {
        return ERROR_FSTORAGE_UNINITIALIZED;
    }

    if (!_gFstorageEraseDone) {
        return ERROR_FSTORAGE_ERASE_ON_GOING;
    }

    if (!_gFstorageWriteDone) {
        return ERROR_FSTORAGE_WRITE_ON_GOING;
    }    

    _gFstorageEraseDone = false;
    const ret_code_t errCode = nrf_fstorage_erase(&_gFstorage, addr, pagesCnt, NULL);
    if (errCode != NRF_SUCCESS) { 
        NRF_LOG_WARNING("nrf_fstorage_erase() failed 0x%x", errCode);
        return ERROR_FSTORAGE_ERASE_FAIL;
    }

    _fstorageWait(FSTORAGE_WAIT_CNT);
    
    return 0;
}

/*
int fstorageEraseFDS(void) {
    const uint32_t eraseUnit = _gFstorage.p_flash_info->erase_unit;
    const uint32_t endAddr = _fstorageGetEndAddr();
    const uint32_t bootloaderAddr = BOOTLOADER_ADDRESS;
    uint32_t addr;
    if (bootloaderAddr == 0xFFFFFFFF) {
        addr = endAddr - FDS_VIRTUAL_PAGES * eraseUnit; 
    } else {
        addr = bootloaderAddr - FDS_VIRTUAL_PAGES * eraseUnit;
    }
    
    const uint32_t pagesCnt  = FDS_VIRTUAL_PAGES;
    const ret_code_t errCode =  nrf_fstorage_erase(&_gFstorage, addr, pagesCnt, NULL);
    if (errCode != NRF_SUCCESS) { 
        NRF_LOG_WARNING("nrf_fstorage_erase() failed 0x%x\n", errCode);
        return ERROR_FSTORAGE_ERASE_FAIL;
    }

    return 0;
}
*/

int fstorageReadRecord(const uint32_t addr, record_t* pRecord) {
    uint8_t data[RECORD_LEN] = {0};
    if (_fstorageRead(addr, RECORD_LEN, data) != 0) {
        return ERROR_FDS_READ_FAIL;
    }

    data2Record(data, pRecord);

    return 0;
}    

int fstorageUpdateRecord(const record_data_type_t type, const record_t* pRecord) {
    const uint32_t addr = _fstorageGetStartAddr();
    NRF_LOG_DEBUG("type=%d, add=0x%x\n", type, addr);
    switch (type) {
        case RECORD_DATA_TYPE_START:
        {  
            NRF_LOG_DEBUG("RECORD_DATA_TYPE_START E\n");
            if (_fstorageIsEraseNeeded()) {
                NRF_LOG_DEBUG("fstorageErase() E\n");
                fstorageErase(addr, 1);
            }    
            NRF_LOG_DEBUG("fstorageWriteRecord() E\n");
            record_t record;
            record.offsetStart = 0;
            record.offsetEnd   = 0;
            fstorageWriteRecord(addr, &record);
            NRF_LOG_DEBUG("RECORD_DATA_TYPE_START x\n");
        }    
        break;

        case RECORD_DATA_TYPE_END:
        {
            NRF_LOG_DEBUG("RECORD_DATA_TYPE_END E\n");
            record_t record;
            NRF_LOG_DEBUG("fstorageReadRecord() E\n");
            if (fstorageReadRecord(addr, &record) != 0) {
                return ERROR_FSTORAGE_READ_FAIL;
            }
            NRF_LOG_DEBUG("fstorageReadRecord() x\n");
            NRF_LOG_DEBUG("record.offsetStart=0x%x", record.offsetStart);
            NRF_LOG_DEBUG("record.offsetEnd=0x%x",   record.offsetEnd);

            if (_fstorageIsEraseNeeded()) {
                NRF_LOG_DEBUG("fstorageErase() E\n");
                fstorageErase(addr, 1);
            }
            record.offsetEnd = pRecord->offsetEnd;
            NRF_LOG_DEBUG("record.offsetEnd=0x%x",   record.offsetEnd);
            NRF_LOG_DEBUG("fstorageWriteRecord() E\n");
            fstorageWriteRecord(addr, &record);
            NRF_LOG_DEBUG("RECORD_DATA_TYPE_END X");
        }   
        break;    
    }    

    return 0;
}

int fstorageWriteRecord(const uint32_t addr, record_t* pRecord) {
    uint8_t data[RECORD_LEN] = {0};
    record2Data(pRecord, data);
    if (_fstorageWrite(addr, RECORD_LEN, data) != 0) {
        return ERROR_FSTORAGE_WRITE_FAIL;
    }

    return 0;
}

int _fstorageWrite(const uint32_t addr, const uint32_t len, void const* pData) {
if (!_gFstorageInitialized) {
return ERROR_FSTORAGE_UNINITIALIZED;
}

if (!_gFstorageEraseDone) {
return ERROR_FSTORAGE_ERASE_ON_GOING;
}

if (!_gFstorageWriteDone) {
return ERROR_FSTORAGE_WRITE_ON_GOING;
}

_gFstorageWriteDone = false;

const uint32_t wlen = _fstorageRoundUpU32(len);
const ret_code_t retCode = nrf_fstorage_write(&_gFstorage, addr, pData, wlen, NULL);
if (retCode != NRF_SUCCESS) {
NRF_LOG_WARNING("nrf_fstorage_write() failed 0x%x", retCode);
return ERROR_FSTORAGE_WRITE_FAIL;
}

_fstorageWait(FSTORAGE_WAIT_CNT);

return 0;
}

Parents
  • The following log messages show that fatal error occur in sd_app_evt_wait(). Where "pm e" means entering sd_app_evt_wait() function and  "pm x" means leaving sd_app_evt_wait() function

    # SEGGER J-Link RTT Viewer V6.32i Terminal Log File
    # Compiled: 15:22:50 on Jul 24 2018
    # Logging started @ 24 Jun 2022 09:07:20
     0> <debug> nrf_ble_gatt: Requesting to update ATT MTU to 185 bytes on connection 0x0.
     0> <info> app: Connected.
     0> <debug> nrf_ble_gatt: Peer on connection 0x0 requested a data length of 251 bytes.
     0> <debug> nrf_ble_gatt: Updating data length to 27 on connection 0x0.
     0> <debug> nrf_ble_gatt: Data length updated to 27 on connection 0x0.
     0> <debug> nrf_ble_gatt: max_rx_octets: 27
     0> <debug> nrf_ble_gatt: max_tx_octets: 27
     0> <debug> nrf_ble_gatt: max_rx_time: 2120
     0> <debug> nrf_ble_gatt: max_tx_time: 2120
     0> <debug> nrf_ble_gatt: Peer on connection 0x0 requested an ATT MTU of 527 bytes.
     0> <debug> nrf_ble_gatt: Updating ATT MTU to 185 bytes (desired: 185) on connection 0x0.
     0> <debug> nrf_ble_gatt: ATT MTU updated to 185 bytes on connection 0x0 (response).
     0> <info> app: Received data from BLE NUS. Writing data on UART.
     0> <debug> app:  4D                     |M       
     0> <info> app: M
     0> <debug> app: length=1
     0> <debug> app: data[0]=0x4D
     0> <debug> app: data[1]=0x0
     0> <debug> app: data[2]=0x0
     0> <debug> app: data[3]=0x0
     0> <debug> app: data[4]=0x0
     0> <debug> app: data[5]=0x0
     0> <debug> app: data[6]=0x0
     0> <info> app: 
     0> 
     0> <info> app: Received data from BLE NUS. Writing data on UART.
     0> <debug> app:  45                     |E       
     0> <info> app: E
     0> <debug> app: length=1
     0> <debug> app: data[0]=0x4D
     0> <debug> app: data[1]=0x45
     0> <debug> app: data[2]=0x0
     0> <debug> app: data[3]=0x0
     0> <debug> app: data[4]=0x0
     0> <debug> app: data[5]=0x0
     0> <debug> app: data[6]=0x0
     0> <info> app: 
     0> 
     0> <info> app: Received data from BLE NUS. Writing data on UART.
     0> <debug> app:  41                     |A       
     0> <info> app: A
     0> <debug> app: length=1
     0> <debug> app: data[0]=0x4D
     0> <debug> app: data[1]=0x45
     0> <debug> app: data[2]=0x41
     0> <debug> app: data[3]=0x0
     0> <debug> app: data[4]=0x0
     0> <debug> app: data[5]=0x0
     0> <debug> app: data[6]=0x0
     0> <info> app: 
     0> 
     0> <info> app: Received data from BLE NUS. Writing data on UART.
     0> <debug> app:  53                     |S       
     0> <info> app: S
     0> <debug> app: length=1
     0> <debug> app: data[0]=0x4D
     0> <debug> app: data[1]=0x45
     0> <debug> app: data[2]=0x41
     0> <debug> app: data[3]=0x53
     0> <debug> app: data[4]=0x0
     0> <debug> app: data[5]=0x0
     0> <debug> app: data[6]=0x0
     0> <info> app: 
     0> 
     0> <info> app: Received data from BLE NUS. Writing data on UART.
     0> <debug> app:  55                     |U       
     0> <info> app: U
     0> <debug> app: length=1
     0> <debug> app: data[0]=0x4D
     0> <debug> app: data[1]=0x45
     0> <debug> app: data[2]=0x41
     0> <debug> app: data[3]=0x53
     0> <debug> app: data[4]=0x55
     0> <debug> app: data[5]=0x0
     0> <debug> app: data[6]=0x0
     0> <info> app: 
     0> 
     0> <info> app: Received data from BLE NUS. Writing data on UART.
     0> <debug> app:  52                     |R       
     0> <info> app: R
     0> <debug> app: length=1
     0> <debug> app: data[0]=0x4D
     0> <debug> app: data[1]=0x45
     0> <debug> app: data[2]=0x41
     0> <debug> app: data[3]=0x53
     0> <debug> app: data[4]=0x55
     0> <debug> app: data[5]=0x52
     0> <debug> app: data[6]=0x0
     0> <info> app: 
     0> 
     0> <info> app: Received data from BLE NUS. Writing data on UART.
     0> <debug> app:  45                     |E       
     0> <info> app: E
     0> <debug> app: length=1
     0> <debug> app: data[0]=0x4D
     0> <debug> app: data[1]=0x45
     0> <debug> app: data[2]=0x41
     0> <debug> app: data[3]=0x53
     0> <debug> app: data[4]=0x55
     0> <debug> app: data[5]=0x52
     0> <debug> app: data[6]=0x45
     0> <info> app: 
     0> 
     0> <debug> app: endAddr=0x80000
     0> <debug> app: startAddr=0x7D000
     0> <debug> app: type=0, add=0x7D000
     0> 
     0> <debug> app: state=0
     0> 
     0> <debug> app: START E
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <error> app: Fatal error
    
    .

    0> <debug> app: pm e
     0>
     0> <debug> app: pm x
     0>
     0> <debug> app: pm x
     0>
     0> <debug> app: pm e
     0>
     0> <error> app: Fatal error

  • Thanks for your reply! The following is error messages after defining define "DEBUG" and "DEBUG_NRF". But I can't find useful information.

     0> <debug> app: pm e
     0>
     0> <debug> app: pm x
     0>
     0> <debug> app: pm e
     0>
     0> <error> app: End of error report

  • /**
     * Copyright (c) 2018 - 2019, Nordic Semiconductor ASA
     *
     * All rights reserved.
     *
     * Redistribution and use in source and binary forms, with or without modification,
     * are permitted provided that the following conditions are met:
     *
     * 1. Redistributions of source code must retain the above copyright notice, this
     *    list of conditions and the following disclaimer.
     *
     * 2. Redistributions in binary form, except as embedded into a Nordic
     *    Semiconductor ASA integrated circuit in a product or a software update for
     *    such product, must reproduce the above copyright notice, this list of
     *    conditions and the following disclaimer in the documentation and/or other
     *    materials provided with the distribution.
     *
     * 3. Neither the name of Nordic Semiconductor ASA nor the names of its
     *    contributors may be used to endorse or promote products derived from this
     *    software without specific prior written permission.
     *
     * 4. This software, with or without modification, must only be used with a
     *    Nordic Semiconductor ASA integrated circuit.
     *
     * 5. Any software provided in binary form under this license must not be reverse
     *    engineered, decompiled, modified and/or disassembled.
     *
     * THIS SOFTWARE IS PROVIDED BY NORDIC SEMICONDUCTOR ASA "AS IS" AND ANY EXPRESS
     * OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE IMPLIED WARRANTIES
     * OF MERCHANTABILITY, NONINFRINGEMENT, AND FITNESS FOR A PARTICULAR PURPOSE ARE
     * DISCLAIMED. IN NO EVENT SHALL NORDIC SEMICONDUCTOR ASA OR CONTRIBUTORS BE
     * LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR
     * CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE
     * GOODS OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION)
     * HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT
     * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT
     * OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
     *
     */
    #include "app_timer.h"
    #include "nrf_atfifo.h"
    #include "nrf_sortlist.h"
    #include "nrf_delay.h"
    #if APP_TIMER_WITH_PROFILER
    #include "app_util_platform.h"
    #endif
    #if APP_TIMER_CONFIG_USE_SCHEDULER
    #include "app_scheduler.h"
    #endif
    #include <stddef.h>
    #define NRF_LOG_MODULE_NAME APP_TIMER_LOG_NAME
    #if APP_TIMER_CONFIG_LOG_ENABLED
    #define NRF_LOG_LEVEL       APP_TIMER_CONFIG_LOG_LEVEL
    #define NRF_LOG_INFO_COLOR  APP_TIMER_CONFIG_INFO_COLOR
    #define NRF_LOG_DEBUG_COLOR APP_TIMER_CONFIG_DEBUG_COLOR
    #else //APP_TIMER_CONFIG_LOG_ENABLED
    #define NRF_LOG_LEVEL       0
    #endif //APP_TIMER_CONFIG_LOG_ENABLED
    #include "nrf_log.h"
    NRF_LOG_MODULE_REGISTER();
    
    #include "drv_rtc.h"
    
    /**
     * Maximum possible relative value is limited by safe window to detect cases when requested
     * compare event has already occured.
     */
    #define APP_TIMER_SAFE_WINDOW APP_TIMER_TICKS(APP_TIMER_SAFE_WINDOW_MS)
    
    #define APP_TIMER_RTC_MAX_VALUE   (DRV_RTC_MAX_CNT - APP_TIMER_SAFE_WINDOW)
    
    static drv_rtc_t m_rtc_inst = DRV_RTC_INSTANCE(1);
    
    #if APP_TIMER_WITH_PROFILER
    static uint8_t m_max_user_op_queue_utilization;     /**< Maximum observed timer user operations queue utilization. */
    static uint8_t m_current_user_op_queue_utilization; /**< Currently observed timer user operations queue utilization. */
    #endif /* APP_TIMER_WITH_PROFILER */
    
    /**
     * @brief Timer requests types.
     */
    typedef enum
    {
        TIMER_REQ_START,
        TIMER_REQ_STOP,
        TIMER_REQ_STOP_ALL
    } app_timer_req_type_t;
    
    /**
     * @brief Operation request structure.
     */
    typedef struct
    {
        app_timer_req_type_t type;    /**< Request type. */
        app_timer_t *        p_timer; /**< Timer instance. */
    } timer_req_t;
    
    static app_timer_t * volatile mp_active_timer; /**< Timer currently handled by RTC driver. */
    static bool                   m_global_active; /**< Flag used to globally disable all timers. */
    static uint64_t m_base_counter;
    static uint64_t m_stamp64;
    
    /* Request FIFO instance. */
    NRF_ATFIFO_DEF(m_req_fifo, timer_req_t, APP_TIMER_CONFIG_OP_QUEUE_SIZE);
    
    /* Sortlist instance. */
    static bool compare_func(nrf_sortlist_item_t * p_item0, nrf_sortlist_item_t *p_item1);
    NRF_SORTLIST_DEF(m_app_timer_sortlist, compare_func); /**< Sortlist used for storing queued timers. */
    
    /**
     * @brief Return current 64 bit timestamp
     */
    static uint64_t get_now(void)
    {
        uint64_t now = m_base_counter + drv_rtc_counter_get(&m_rtc_inst);
    
        /* it is possible that base was not updated and overflow occured, in that case 'now' will be
         * 24bit value behind. Additional timestamp updated on every 24 bit period is used to detect
         * that case. Apart from that 'now' should never be behind previously read timestamp.
         */
        if (now < m_stamp64) {
            now += (DRV_RTC_MAX_CNT + 1);
        }
    
        return now;
    }
    /**
     * @brief Function used for comparing items in sorted list.
     */
    static inline bool compare_func(nrf_sortlist_item_t * p_item0, nrf_sortlist_item_t *p_item1)
    {
        app_timer_t * p0 = CONTAINER_OF(p_item0, app_timer_t, list_item);
        app_timer_t * p1 = CONTAINER_OF(p_item1, app_timer_t, list_item);
    
        uint64_t p0_end = p0->end_val;
        uint64_t p1_end = p1->end_val;
        return (p0_end <= p1_end) ? true : false;
    }
    
    #if APP_TIMER_CONFIG_USE_SCHEDULER
    static void scheduled_timeout_handler(void * p_event_data, uint16_t event_size)
    {
        ASSERT(event_size == sizeof(app_timer_event_t));
        app_timer_event_t const * p_timer_event = (app_timer_event_t *)p_event_data;
    
        p_timer_event->timeout_handler(p_timer_event->p_context);
    }
    #endif
    
    /**
     * @brief Function called on timer expiration
     * If end value is not reached it is assumed that it was partial expiration and time is put back
     * into the list. Otherwise function calls user handler if timer was not stopped before. If timer
     * is in repeated mode then timer is rescheduled.
     *
     * @param p_timer Timer instance.
     *
     * @return True if reevaluation of sortlist needed (becasue it was updated).
     */
    static bool timer_expire(app_timer_t * p_timer)
    {
        ASSERT(p_timer->handler);
        bool ret = false;
    
        if ((m_global_active == true) && (p_timer != NULL) && (p_timer->active))
        {
            if (get_now() >= p_timer->end_val) {
                /* timer expired */
                if (p_timer->repeat_period == 0)
                {
                    p_timer->active = false;
                }
        #if APP_TIMER_CONFIG_USE_SCHEDULER
                app_timer_event_t timer_event;
    
                timer_event.timeout_handler = p_timer->handler;
                timer_event.p_context       = p_timer->p_context;
                uint32_t err_code = app_sched_event_put(&timer_event,
                                                        sizeof(timer_event),
                                                        scheduled_timeout_handler);
                APP_ERROR_CHECK(err_code);
        #else
                NRF_LOG_DEBUG("Timer expired (context: %d)", (uint32_t)p_timer->p_context)
                p_timer->handler(p_timer->p_context);
        #endif
                /* check active flag as it may have been stopped in the user handler */
                if ((p_timer->repeat_period) && (p_timer->active))
                {
                    p_timer->end_val += p_timer->repeat_period;
                    nrf_sortlist_add(&m_app_timer_sortlist, &p_timer->list_item);
                    ret = true;
                }
            }
            else
            {
                nrf_sortlist_add(&m_app_timer_sortlist, &p_timer->list_item);
                ret = true;
            }
        }
        return ret;
    }
    
    /**
     * @brief Function is configuring RTC driver to trigger timeout interrupt for given timer.
     *
     * It is possible that RTC driver will indicate that timeout already occured. In that case timer
     * expires and function indicates that RTC was not configured.
     *
     * @param          p_timer Timer instance.
     * @param [in,out] p_rerun Flag indicating that sortlist reevaluation is required.
     *
     * @return True if RTC was successfully configured, false if timer already expired and RTC was not
     *         configured.
     *
     */
    static bool rtc_schedule(app_timer_t * p_timer, bool * p_rerun)
    {
        ret_code_t ret = NRF_ERROR_TIMEOUT;
        *p_rerun = false;
        int64_t remaining = (int64_t)(p_timer->end_val - get_now());
    
        if (remaining > 0) {
            uint32_t cc_val = ((uint32_t)remaining > APP_TIMER_RTC_MAX_VALUE) ?
                    (app_timer_cnt_get() + APP_TIMER_RTC_MAX_VALUE) : p_timer->end_val;
    
            ret = drv_rtc_windowed_compare_set(&m_rtc_inst, 0, cc_val, APP_TIMER_SAFE_WINDOW);
            NRF_LOG_DEBUG("Setting CC to 0x%08x (err: %d)", cc_val & DRV_RTC_MAX_CNT, ret);
            if (ret == NRF_SUCCESS)
            {
                return true;
            }
        }
        else
        {
            drv_rtc_compare_disable(&m_rtc_inst, 0);
        }
    
        if (ret == NRF_ERROR_TIMEOUT)
        {
            *p_rerun = timer_expire(p_timer);
        }
        else
        {
            NRF_LOG_ERROR("Unexpected error: %d", ret);
            ASSERT(0);
        }
    
        return false;
    }
    
    static inline app_timer_t * sortlist_pop(void)
    {
        nrf_sortlist_item_t * p_next_item = nrf_sortlist_pop(&m_app_timer_sortlist);
        return p_next_item ? CONTAINER_OF(p_next_item, app_timer_t, list_item) : NULL;
    }
    
    static inline app_timer_t * sortlist_peek(void)
    {
        nrf_sortlist_item_t const * p_next_item = nrf_sortlist_peek(&m_app_timer_sortlist);
        return p_next_item ? CONTAINER_OF(p_next_item, app_timer_t, list_item) : NULL;
    }
    
    /**
     * @brief Function for deactivating all timers which are in the sorted list (active timers).
     */
    static void sorted_list_stop_all(void)
    {
        app_timer_t * p_next;
        do
        {
            p_next = sortlist_pop();
            if (p_next)
            {
                p_next->active = false;
            }
        } while (p_next);
    }
    
    /**
     * @brief Function for handling RTC counter overflow.
     *
     * Increment base counter used to calculate 64 bit timestamp.
     */
    static void on_overflow_evt(void)
    {
        NRF_LOG_DEBUG("Overflow EVT");
        m_base_counter += (DRV_RTC_MAX_CNT + 1);
    }
    
    /**
     * #brief Function for handling RTC compare event - active timer expiration.
     */
    static void on_compare_evt(drv_rtc_t const * const  p_instance)
    {
        if (mp_active_timer)
        {
            /* If assert fails it suggests that safe window should be increased. */
            ASSERT(app_timer_cnt_diff_compute(drv_rtc_counter_get(p_instance),
                                              mp_active_timer->end_val & RTC_COUNTER_COUNTER_Msk) < APP_TIMER_SAFE_WINDOW);
    
            NRF_LOG_INST_DEBUG(mp_active_timer->p_log, "Compare EVT");
            UNUSED_RETURN_VALUE(timer_expire(mp_active_timer));
            mp_active_timer = NULL;
        }
        else
        {
            NRF_LOG_WARNING("Compare event but no active timer (already stopped?)");
        }
    }
    
    /**
     * @brief Channel 1 is triggered in the middle of 24 bit period to updated control timestamp in
     * place where there is no risk of overflow.
     */
    static void on_compare1_evt(drv_rtc_t const * const  p_instance)
    {
        m_stamp64 = get_now();
    }
    
    /**
     * @brief Function updates RTC.
     *
     * Function is called at the end of RTC interrupt when all new user request and/or timer expiration
     * occured. It configures RTC if there is any pending timer, reconfigures if the are timers with
     * shorted timeout than active one or stops RTC if there is no active timers.
     */
    static void rtc_update(drv_rtc_t const * const  p_instance)
    {
        while(1)
        {
            app_timer_t * p_next = sortlist_peek();
            bool rtc_reconf = false;
            if (p_next) //Candidate for active timer
            {
                if (mp_active_timer == NULL)
                {
                    //There is no active timer so candidate will become active timer.
                    rtc_reconf = true;
                }
                else if (p_next->end_val < mp_active_timer->end_val)
                {
                    //Candidate has shorter timeout than current active timer. Candidate will replace active timer.
                    //Active timer is put back into sorted list.
                    rtc_reconf = true;
                    if (mp_active_timer->active)
                    {
                        NRF_LOG_INST_DEBUG(mp_active_timer->p_log, "Timer preempted.");
                        nrf_sortlist_add(&m_app_timer_sortlist, &mp_active_timer->list_item);
                    }
                }
    
                if (rtc_reconf)
                {
                    bool rerun;
                    p_next = sortlist_pop();
                    NRF_LOG_INST_DEBUG(p_next->p_log, "Activating timer (CC:%d/%08x).", p_next->end_val, p_next->end_val);
                    if (rtc_schedule(p_next, &rerun))
                    {
                        if (!APP_TIMER_KEEPS_RTC_ACTIVE && (mp_active_timer == NULL))
                        {
                            drv_rtc_start(p_instance);
                        }
                        mp_active_timer = p_next;
    
                        if (rerun == false)
                        {
                            //RTC was successfully updated and sortlist was not updated. Function can be terminated.
                            break;
                        }
                    }
                    else
                    {
                        //If RTC driver indicated that timeout already occured a new candidate will be taken from sorted list.
                        NRF_LOG_INST_DEBUG(p_next->p_log,"Timer expired before scheduled to RTC.");
                        mp_active_timer = NULL;
                    }
                }
                else
                {
                    //RTC will not be updated. Function can terminate.
                    break;
                }
            }
            else //No candidate for active timer.
            {
                if (!APP_TIMER_KEEPS_RTC_ACTIVE && (mp_active_timer == NULL))
                {
                    drv_rtc_stop(p_instance);
                }
                break;
            }
        }
    }
    
    /**
     * @brief Function for processing user requests.
     *
     * Function is called only in the context of RTC interrupt.
     */
    static void timer_req_process(drv_rtc_t const * const  p_instance)
    {
        nrf_atfifo_item_get_t fifo_ctx;
        timer_req_t *         p_req = nrf_atfifo_item_get(m_req_fifo, &fifo_ctx);
    
        while (p_req)
        {
            switch (p_req->type)
            {
                case TIMER_REQ_START:
                    if (!p_req->p_timer->active)
                    {
                        p_req->p_timer->active = true;
                        nrf_sortlist_add(&m_app_timer_sortlist, &(p_req->p_timer->list_item));
                        NRF_LOG_INST_DEBUG(p_req->p_timer->p_log,"Start request (expiring at %d/0x%08x).",
                                                      p_req->p_timer->end_val, p_req->p_timer->end_val);
                    }
                    break;
                case TIMER_REQ_STOP:
                    if (p_req->p_timer == mp_active_timer)
                    {
                        mp_active_timer = NULL;
                    }
                    else
                    {
                        bool found = nrf_sortlist_remove(&m_app_timer_sortlist, &(p_req->p_timer->list_item));
                        if (!found)
                        {
                             NRF_LOG_INFO("Timer not found on sortlist (stopping expired timer).");
                        }
                    }
                    NRF_LOG_INST_DEBUG(p_req->p_timer->p_log,"Stop request.");
                    break;
                case TIMER_REQ_STOP_ALL:
                    sorted_list_stop_all();
                    m_global_active = true;
                    NRF_LOG_INFO("Stop all request.");
                    break;
                default:
                    break;
            }
    #if APP_TIMER_WITH_PROFILER
            CRITICAL_REGION_ENTER();
    #endif
            UNUSED_RETURN_VALUE(nrf_atfifo_item_free(m_req_fifo, &fifo_ctx));
    #if APP_TIMER_WITH_PROFILER
            if (m_max_user_op_queue_utilization < m_current_user_op_queue_utilization)
            {
                m_max_user_op_queue_utilization = m_current_user_op_queue_utilization;
            }
            --m_current_user_op_queue_utilization;
            CRITICAL_REGION_EXIT();
    #endif /* APP_TIMER_WITH_PROFILER */
            p_req = nrf_atfifo_item_get(m_req_fifo, &fifo_ctx);
        }
    }
    
    static void rtc_irq(drv_rtc_t const * const  p_instance)
    {
        if (drv_rtc_overflow_pending(p_instance))
        {
            on_overflow_evt();
        }
        if (drv_rtc_compare_pending(p_instance, 0))
        {
            on_compare_evt(p_instance);
        }
        if (drv_rtc_compare_pending(p_instance, 1))
        {
            on_compare1_evt(p_instance);
        }
    
        timer_req_process(p_instance);
        rtc_update(p_instance);
    }
    
    /**
     * @brief Function for triggering processing user requests.
     *
     * @note All user requests are processed in a single context - RTC interrupt.
     */
    static inline void timer_request_proc_trigger(void)
    {
        drv_rtc_irq_trigger(&m_rtc_inst);
    }
    
    /**
     * @brief Function for putting user request into the request queue
     */
    static ret_code_t timer_req_schedule(app_timer_req_type_t type, app_timer_t * p_timer)
    {
        nrf_atfifo_item_put_t fifo_ctx;
        timer_req_t * p_req;
    #if APP_TIMER_WITH_PROFILER
        CRITICAL_REGION_ENTER();
    #endif
        p_req = nrf_atfifo_item_alloc(m_req_fifo, &fifo_ctx);
    #if APP_TIMER_WITH_PROFILER
        if (p_req)
        {
            ++m_current_user_op_queue_utilization;
        }
        CRITICAL_REGION_EXIT();
    #endif /* APP_TIMER_WITH_PROFILER */
        if (p_req)
        {
            p_req->type    = type;
            p_req->p_timer = p_timer;
            if (nrf_atfifo_item_put(m_req_fifo, &fifo_ctx))
            {
                timer_request_proc_trigger();
            }
            else
            {
                NRF_LOG_WARNING("Scheduling interrupted another scheduling.");
            }
            return NRF_SUCCESS;
        }
        else
        {
            return NRF_ERROR_NO_MEM;
        }
    }
    
    ret_code_t app_timer_init(void)
    {
        ret_code_t err_code;
        drv_rtc_config_t config = {
            .prescaler          = APP_TIMER_CONFIG_RTC_FREQUENCY,
            .interrupt_priority = APP_TIMER_CONFIG_IRQ_PRIORITY
        };
    
        err_code = NRF_ATFIFO_INIT(m_req_fifo);
        if (err_code != NRFX_SUCCESS)
        {
            return err_code;
        }
    
        err_code = drv_rtc_init(&m_rtc_inst, &config, rtc_irq);
        if (err_code != NRFX_SUCCESS)
        {
            return err_code;
        }
        drv_rtc_overflow_enable(&m_rtc_inst, true);
        drv_rtc_compare_set(&m_rtc_inst, 1, DRV_RTC_MAX_CNT >> 1, true);
        if (APP_TIMER_KEEPS_RTC_ACTIVE)
        {
            drv_rtc_start(&m_rtc_inst);
        }
    
        m_global_active = true;
        return err_code;
    }
    
    ret_code_t app_timer_create(app_timer_id_t const *      p_timer_id,
                                app_timer_mode_t            mode,
                                app_timer_timeout_handler_t timeout_handler)
    {
        ASSERT(p_timer_id);
        ASSERT(timeout_handler);
    
        if (timeout_handler == NULL)
        {
            return NRF_ERROR_INVALID_PARAM;
        }
    
        app_timer_t * p_t = (app_timer_t *) *p_timer_id;
        p_t->handler = timeout_handler;
        p_t->repeat_period = (mode == APP_TIMER_MODE_REPEATED) ? 1 : 0;
        return NRF_SUCCESS;
    }
    
    ret_code_t app_timer_start(app_timer_t * p_timer, uint32_t timeout_ticks, void * p_context)
    {
        ASSERT(p_timer);
        app_timer_t * p_t = (app_timer_t *) p_timer;
    
        if (p_t->active)
        {
            return NRF_SUCCESS;
        }
    
        p_t->p_context = p_context;
        p_t->end_val = get_now() + timeout_ticks;
    
        if (p_t->repeat_period)
        {
            p_t->repeat_period = timeout_ticks;
        }
    
        return timer_req_schedule(TIMER_REQ_START, p_t);
    }
    
    
    ret_code_t app_timer_stop(app_timer_t * p_timer)
    {
        ASSERT(p_timer);
        app_timer_t * p_t = (app_timer_t *) p_timer;
        p_t->active = false;
    
        return timer_req_schedule(TIMER_REQ_STOP, p_t);
    }
    
    ret_code_t app_timer_stop_all(void)
    {
        //block timer globally
        m_global_active = false;
    
        return timer_req_schedule(TIMER_REQ_STOP_ALL, NULL);
    }
    
    #if APP_TIMER_WITH_PROFILER
    uint8_t app_timer_op_queue_utilization_get(void)
    {
        return m_max_user_op_queue_utilization;
    }
    #endif /* APP_TIMER_WITH_PROFILER */
    
    uint32_t app_timer_cnt_diff_compute(uint32_t   ticks_to,
                                        uint32_t   ticks_from)
    {
        return ((ticks_to - ticks_from) & RTC_COUNTER_COUNTER_Msk);
    }
    
    uint32_t app_timer_cnt_get(void)
    {
        return drv_rtc_counter_get(&m_rtc_inst);
    }
    
    void app_timer_pause(void)
    {
        drv_rtc_stop(&m_rtc_inst);
    }
    
    void app_timer_resume(void)
    {
        drv_rtc_start(&m_rtc_inst);
    }
    

  • # SEGGER J-Link RTT Viewer V6.32i Terminal Log File
    # Compiled: 15:22:50 on Jul 24 2018
    # Logging started @ 24 Jun 2022 17:31:09
     0> <debug> nrf_ble_gatt: Requesting to update ATT MTU to 185 bytes on connection 0x0.
     0> <info> app: Connected.
     0> <debug> nrf_ble_gatt: Peer on connection 0x0 requested an ATT MTU of 527 bytes.
     0> <debug> nrf_ble_gatt: Updating ATT MTU to 185 bytes (desired: 185) on connection 0x0.
     0> <debug> nrf_ble_gatt: ATT MTU updated to 185 bytes on connection 0x0 (response).
     0> <debug> nrf_ble_gatt: Peer on connection 0x0 requested a data length of 251 bytes.
     0> <debug> nrf_ble_gatt: Updating data length to 27 on connection 0x0.
     0> <debug> nrf_ble_gatt: Data length updated to 27 on connection 0x0.
     0> <debug> nrf_ble_gatt: max_rx_octets: 27
     0> <debug> nrf_ble_gatt: max_tx_octets: 27
     0> <debug> nrf_ble_gatt: max_rx_time: 2120
     0> <debug> nrf_ble_gatt: max_tx_time: 2120
     0> <info> app: Received data from BLE NUS. Writing data on UART.
     0> <debug> app:  4D                     |M       
     0> <info> app: M
     0> <debug> app: length=1
     0> <debug> app: data[0]=0x4D
     0> <debug> app: data[1]=0x0
     0> <debug> app: data[2]=0x0
     0> <debug> app: data[3]=0x0
     0> <debug> app: data[4]=0x0
     0> <debug> app: data[5]=0x0
     0> <debug> app: data[6]=0x0
     0> <info> app: 
     0> 
     0> <info> app: Received data from BLE NUS. Writing data on UART.
     0> <debug> app:  45                     |E       
     0> <info> app: E
     0> <debug> app: length=1
     0> <debug> app: data[0]=0x4D
     0> <debug> app: data[1]=0x45
     0> <debug> app: data[2]=0x0
     0> <debug> app: data[3]=0x0
     0> <debug> app: data[4]=0x0
     0> <debug> app: data[5]=0x0
     0> <debug> app: data[6]=0x0
     0> <info> app: 
     0> 
     0> <info> app: Received data from BLE NUS. Writing data on UART.
     0> <debug> app:  41                     |A       
     0> <info> app: A
     0> <debug> app: length=1
     0> <debug> app: data[0]=0x4D
     0> <debug> app: data[1]=0x45
     0> <debug> app: data[2]=0x41
     0> <debug> app: data[3]=0x0
     0> <debug> app: data[4]=0x0
     0> <debug> app: data[5]=0x0
     0> <debug> app: data[6]=0x0
     0> <info> app: 
     0> 
     0> <info> app: Received data from BLE NUS. Writing data on UART.
     0> <debug> app:  53                     |S       
     0> <info> app: S
     0> <debug> app: length=1
     0> <debug> app: data[0]=0x4D
     0> <debug> app: data[1]=0x45
     0> <debug> app: data[2]=0x41
     0> <debug> app: data[3]=0x53
     0> <debug> app: data[4]=0x0
     0> <debug> app: data[5]=0x0
     0> <debug> app: data[6]=0x0
     0> <info> app: 
     0> 
     0> <info> app: Received data from BLE NUS. Writing data on UART.
     0> <debug> app:  55                     |U       
     0> <info> app: U
     0> <debug> app: length=1
     0> <debug> app: data[0]=0x4D
     0> <debug> app: data[1]=0x45
     0> <debug> app: data[2]=0x41
     0> <debug> app: data[3]=0x53
     0> <debug> app: data[4]=0x55
     0> <debug> app: data[5]=0x0
     0> <debug> app: data[6]=0x0
     0> <info> app: 
     0> 
     0> <info> app: Received data from BLE NUS. Writing data on UART.
     0> <debug> app:  52                     |R       
     0> <info> app: R
     0> <debug> app: length=1
     0> <debug> app: data[0]=0x4D
     0> <debug> app: data[1]=0x45
     0> <debug> app: data[2]=0x41
     0> <debug> app: data[3]=0x53
     0> <debug> app: data[4]=0x55
     0> <debug> app: data[5]=0x52
     0> <debug> app: data[6]=0x0
     0> <info> app: 
     0> 
     0> <info> app: Received data from BLE NUS. Writing data on UART.
     0> <debug> app:  45                     |E       
     0> <info> app: E
     0> <debug> app: length=1
     0> <debug> app: data[0]=0x4D
     0> <debug> app: data[1]=0x45
     0> <debug> app: data[2]=0x41
     0> <debug> app: data[3]=0x53
     0> <debug> app: data[4]=0x55
     0> <debug> app: data[5]=0x52
     0> <debug> app: data[6]=0x45
     0> <info> app: 
     0> 
     0> <debug> app: endAddr=0x7FFFF
     0> <debug> app: startAddr=0x7F000
     0> <debug> app: type=0, addr=0x7F000
     0> 
     0> <debug> app: state=0
     0> 
     0> <debug> app: START E
     0> 
     0> <warning> app: nrf_fstorage_erase() e
     0> 
     0> <warning> app: nrf_fstorage_erase() x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> <debug> app: pm x
     0> 
     0> <debug> app: pm e
     0> 
     0> ponents\libraries\timer\app_timer2.c:181
     0> PC at: 0x000346AF
     0> <error> app: End of error report
    

  • Good, now we know where the return code came from (app_sched_event_put() from line 176 in app_timer2.c). Can you also check what the return code was? Either by trying to fix logging (for instance increasing log buffers or similar), or check with a debugger in the error handler as I suggested in my previous post?

    Also, which SDK version are you using, and can you share your app timer configuration from sdk_config.h? Have you done any changes to the SDK libaries, like fstorage, app_timer2 or app_scheduler? If so, which?

  • The return code came from (app_sched_event_put() ERROR 4 [NRF_ERROR_NO_MEM]. I don't change SDK libaries, like fstorage, app_timer2, and app_scheduler.7624.sdk_config.h

Reply Children
  • Hi,

    I see. app_sched_event_put() will return NRF_ERROR_NO_MEM when the queue is full. So you either need to ensure that you process the queue more efficiently, or increase the queue size.

    Regarding processing the queue efficiently I notice that while waiting for fstorage operations to complete you have a waiting loop there where you call power_manage(), in our _fstorageWait(). This means that other work that could have been done is not doen, like processing the app scheduler queue. This is generally not a good idea, and without having the full picture, it could be related. It would be better to wait in your main loop, and ensure the queue is processed there. Then when you get an event indicating that the flash operation has completed you can do the next, etc.

  • You decide that where you call APP_SCHED_INIT(). For the As you ask the question, I wonder - do you use the app scheduler intentionally or is it by accident? There are good reasons to use it, but if you enabled it in the app_timer by accident and do not actually process the queue, then it will not work and this is expected. If the latter is the case, then you should modify your sdk_config.h to not use the scheduler by setting APP_TIMER_CONFIG_USE_SCHEDULER to 0.

  • If I setting APP_TIMER_CONFIG_USE_SCHEDULER to 0, _norDataHandler() is not called for handling fstorage read/write/erase.

    errCode = app_timer_create(&gNorDataTimerID, APP_TIMER_MODE_REPEATED, _norDataHandler);

    if (errCode != NRF_SUCCESS) {
            NRF_LOG_WARNING("app_timer_create(gNorDataTimerID) failed\n");
            return ERROR_TIMER_CREATE_FAIL;
    }

  • Hi,

    I do not have enough context to understand much from this. What is _norDataHandler()? Do you use the app scheduler in your firmware? (my comment about setting APP_TIMER_CONFIG_USE_SCHEDULER to 0 was just that if you don't use it and just accidentally set it to 1, that could also explain what you are seeing). But if you use the scheduler, the error you got initially is because the scheduler queue is full, either because it is not processed fast enough or that it is too small (or a combination).

Related