Date time synchronization fails after nRF Connect SDK and modem firmware update

[Sebastian Stein]

Dear Nordic Support Team,

After I updated the nRF Connect SDK (1.4.0 to 1.5.1) and the Modem firmware (1.2.2 to 1.2.3) on my nrf9160 DK devices, the date time isn't synchronized anymore.

After the modem successfully connects to the LTE network (lte_lc_psm_req(.) and lte_lc_init_and_connect() return 0), I initiate the date time synchronization with date_time_update_async(). I wait until date_time_is_valid() returns true. This however never happens and printing the current system time obviously shows wrong results. Please note that I used the same application code before and after the SDK and Modem firmware update (except for the new date_time_is_valid() function). Before the update, the date time synchronization was not an issue.

I flashed the Asset Tracker v2 sample onto one of my devices to tackle the problem. The sample failed and issued a reboot on the first run. In the second run, the sample worked properly and the data sent to the nRF Connect Cloud had a correct time stamp. Thereafter I again flashed my application code to the very same device on which I had the Asset Tracker v2 running. Surprisingly, now the date time synchronization was working on that device. I have a second device on which the date time synchronization still fails. I never had the Asset Tracker v2 sample running on this second device.

I would like to understand what causes this behavior and how I can get my devices to synchronize their system time again without utilizing the Asset-Tracker-v2-workaround.

Thank you very much for you help!

PS: You find my prj.conf attached.

EDIT: updated prj.conf, added dateTimeError.log, added minimalExample.c

6560.prj.conf

Fullscreen 7140.dateTimeError.log Download

*** Booting Zephyr OS build v2.4.99-ncs2  ***

I am running!

Init modem

        lte_lc_psm_req returned: 0

        lte_lc_init_and_connect returned: 0

Fetch date time

        d[00:00:13.057,067] <wrn> date_time: getaddrinfo, error: -11

a[00:00:13.063,476] <wrn> date_time: getaddrinfo, error: -11

te[00:00:13.070,037] <wrn> date_time: getaddrinfo, error: -11

_[00:00:13.076,477] <wrn> date_time: getaddrinfo, error: -11

tim[00:00:13.083,068] <wrn> date_time: getaddrinfo, error: -11

[00:00:13.089,294] <wrn> date_time: Not getting time from any NTP server

e_update_async returned: 0

*** Booting Zephyr OS build v2.4.99-ncs2  ***

I am running!

Init modem

        lte_lc_psm_req returned: 0

        lte_lc_init_and_connect returned: 0

Fetch date time

        d[00:00:11.937,042] <wrn> date_time: getaddrinfo, error: -11

a[00:00:11.943,481] <wrn> date_time: getaddrinfo, error: -11

te[00:00:11.950,042] <wrn> date_time: getaddrinfo, error: -11

_[00:00:11.956,451] <wrn> date_time: getaddrinfo, error: -11

tim[00:00:11.963,043] <wrn> date_time: getaddrinfo, error: -11

[00:00:11.969,299] <wrn> date_time: Not getting time from any NTP server

e_update_async returned: 0

Fullscreen 7450.minimalExample.c Download

// Zephyr
#include <zephyr.h>

// Nordic
#include <date_time.h>
#include <modem/lte_lc.h>

// Local
#include "Hardware/lmWatchdog.h"



// Macro
//=============================================================================
//=============================================================================



// Declaration
//=============================================================================
//=============================================================================



// Interface
//=============================================================================
/**
 * @brief Directly called in main.c
 */
void lmControlProtoApp_initialize(void) {
    int error = 0;

    printk("Init modem\n");

    error = lte_lc_psm_req(true);
    printk("\tlte_lc_psm_req returned: %d\n", error);

    error = lte_lc_init_and_connect();
    printk("\tlte_lc_init_and_connect returned: %d\n", error);


    printk("Fetch date time\n");

    error = date_time_update_async(NULL);
    printk("\tdate_time_update_async returned: %d\n", error);
    
    LmWatchdog watchdog;
    lmWatchdog_initialize(&watchdog, 1000*10);
    lmWatchdog_start(&watchdog);
    while (!date_time_is_valid()) {
        k_msleep(1000);
    }
    lmWatchdog_stop(&watchdog);

    printk("Init done\n");
}


/**
 * @brief Directly called in main.c after initialize is complete
 */
void lmControlProtoApp_run(void) {
    int64_t unixStamp;
    
    while (true)
    {
        date_time_now(&unixStamp);
        printk("unix time stamp: &lld\n", unixStamp);
        k_msleep(1000*5);
    }
}
//=============================================================================



// Definition
//=============================================================================
//=============================================================================

[simensr]

Hi @Sebastian Stein. I struggle to identify the exact issue at hand. Could you provide some log output to further support your case? The date time library supports registering a handler that provides callbacks when date time has been obtained (In asset tracker v1 main.c the handler name is date_time_event_handler. I recommend depending on that with a semaphore in stead of blocking on date_time_is_valid().

[Sebastian Stein]

Hi simensr,

thank you for your response.

I edited the attached files of my first post. I added the log file dateTimeError.log and a minimal example with which I am able to reproduce the issue. To generate the log messages I have set CONFIG_LOG_DEFAULT_LEVEL=4 and CONFIG_LOG_IMMEDIATE=y.

[simensr]

/**
 * @brief Directly called in main.c after initialize is complete
 */
void lmControlProtoApp_run(void) {
    int64_t unixStamp;

    while (true)
    {
        date_time_now(&unixStamp);
        printk("unix time stamp: %lld\n", unixStamp);
        k_msleep(1000*5);
    }
}
//=============================================================================

// Interface
//=============================================================================
/**
 * @brief Directly called in main.c
 */
void main(void) {
    int error = 0;

    printk("Init modem\n");

    error = lte_lc_psm_req(true);
    printk("\tlte_lc_psm_req returned: %d\n", error);

    error = lte_lc_init_and_connect();
    printk("\tlte_lc_init_and_connect returned: %d\n", error);

    printk("Fetch date time\n");

    error = date_time_update_async(NULL);
    printk("\tdate_time_update_async returned: %d\n", error);

    while (!date_time_is_valid()) {
        k_msleep(1000);
    }

    printk("Init done\n");

    lmControlProtoApp_run();
}

Made a few changes. This works at my end. I can provide an alternative if the code above does not work using the callback handler for the date time library in combination with a semaphore:

static K_SEM_DEFINE(date_time_sem, 0, 1);

static void date_time_event_handler(const struct date_time_evt *evt)
{
	switch (evt->type) {
	case DATE_TIME_OBTAINED_MODEM:
	case DATE_TIME_OBTAINED_NTP:
	case DATE_TIME_OBTAINED_EXT:
		printk("Date time is obtained\n");
		k_sem_give(&date_time_sem);
		break;
	case DATE_TIME_NOT_OBTAINED:
		break;
	default:
		break;
	}
}

/**
 * @brief Directly called in main.c after initialize is complete
 */
void lmControlProtoApp_run(void) {
    int64_t unixStamp;

    while (true)
    {
        date_time_now(&unixStamp);
        printk("unix time stamp: %lld\n", unixStamp);
        k_msleep(1000*5);
    }
}
//=============================================================================

// Interface
//=============================================================================
/**
 * @brief Directly called in main.c
 */
void main(void) {
    int error = 0;

    printk("Init modem\n");

    error = lte_lc_psm_req(true);
    printk("\tlte_lc_psm_req returned: %d\n", error);

    error = lte_lc_init_and_connect();
    printk("\tlte_lc_init_and_connect returned: %d\n", error);

    printk("Fetch date time\n");

    error = date_time_update_async(date_time_event_handler);
    printk("\tdate_time_update_async returned: %d\n", error);

    k_sem_take(&date_time_sem, K_FOREVER);

    printk("Init done\n");

    lmControlProtoApp_run();
}

[Sebastian Stein]

Hi,

thank you for your examples. I had let them run on my device but at my end they have exactly the same issue in synchronizing the date time. I will attach both log files at the end of this post.

Note that I edited the second example of yours by printing a message for the DATE_TIME_NOT_OBTAINED event:

static void date_time_event_handler(const struct date_time_evt *evt)
{
	switch (evt->type) {
	case DATE_TIME_OBTAINED_MODEM:
	case DATE_TIME_OBTAINED_NTP:
	case DATE_TIME_OBTAINED_EXT:
		printk("Date time is obtained\n");
		k_sem_give(&date_time_sem);
		break;
	case DATE_TIME_NOT_OBTAINED:
		printk("Date time was NOT obtained");
	default:
		break;
	}
}

As I mentioned in my initial post, I had the exactly same problem with another device and it was miraculously solved after I flashed the Asset Tracker v2 sample. But I am a little reluctant to do the same thing with this device because then, I will not be able to reproduce the error at hand anymore.

The log messages seem to indicate that the url of the ntp server cannot be resolved. Does the Asset Tracker v2 sample change some persistent modem settings in this regard?

Log of first example:

Fullscreen firstExample.log Download

*** Booting Zephyr OS build v2.4.99-ncs2  ***

Init modem

        lte_lc_psm_req returned: 0

        lte_lc_init_and_connect returned: 0

Fetch date time

        [00:00:12.649,749] <wrn> date_time: getaddrinfo, error: -11

d[00:00:12.656,188] <wrn> date_time: getaddrinfo, error: -11

at[00:00:12.662,719] <wrn> date_time: getaddrinfo, error: -11

e[00:00:12.669,189] <wrn> date_time: getaddrinfo, error: -11

_t[00:00:12.675,750] <wrn> date_time: getaddrinfo, error: -11

[00:00:12.682,006] <wrn> date_time: Not getting time from any NTP server

ime_update_async returned: 0

Log of second example (with semaphore):

Fullscreen secondExample_withSemaphore.log Download

*** Booting Zephyr OS build v2.4.99-ncs2  ***

Init modem

        lte_lc_psm_req returned: 0

        lte_lc_init_and_connect returned: 0

Fetch date time

        [00:00:13.105,163] <wrn> date_time: getaddrinfo, error: -11

d[00:00:13.111,572] <wrn> date_time: getaddrinfo, error: -11

at[00:00:13.118,133] <wrn> date_time: getaddrinfo, error: -11

e[00:00:13.124,572] <wrn> date_time: getaddrinfo, error: -11

_ti[00:00:13.131,164] <wrn> date_time: getaddrinfo, error: -11

[00:00:13.137,390] <wrn> date_time: Not getting time from any NTP server

me_update_async returned: 0

Date time was NOT obtained

[Hakon]

Hello, I'll be taking care of this case as Simen has other issues to attend to. I tried to reproduce the issue as well, but it doesn't run in to any errors. Have you made sure your SIM card is activated on your device?