"scheduled_action_handle()" is executed many times

[a.da]

Hello.

I am developing using nRF5340DK and nRF Connect SDK v2.9.0.
I am checking the operation of "Scheduler Server".
The action was executed, and the date and time are correct.
However, it was executed many times, not just once.
Extract my log.

1. Receive "Scheduler Action Set"
   Turn off lights at 10:55:00AM every day.
   Target uptime: 329954. Current uptime: 99680.
   

   [00:01:39.680,175] <dbg> bt_mesh_scheduler_srv: action_set: Rx: scheduler server action index 0 set, ack 1
   [00:01:39.680,267] <dbg> bt_mesh_scheduler_srv: schedule_action: Current uptime 99680
   [00:01:39.680,267] <dbg> bt_mesh_scheduler_srv: schedule_action: Current time:
   [00:01:39.680,267] <dbg> bt_mesh_scheduler_srv: schedule_action:         year: 124
   [00:01:39.680,297] <dbg> bt_mesh_scheduler_srv: schedule_action:        month: 11
   [00:01:39.680,297] <dbg> bt_mesh_scheduler_srv: schedule_action:          day: 25
   [00:01:39.680,328] <dbg> bt_mesh_scheduler_srv: schedule_action:         hour: 10
   [00:01:39.680,328] <dbg> bt_mesh_scheduler_srv: schedule_action:       minute: 51
   [00:01:39.680,328] <dbg> bt_mesh_scheduler_srv: schedule_action:       second: 9
   [00:01:39.680,419] <dbg> bt_mesh_scheduler_srv: schedule_action: Scheduled time:
   [00:01:39.680,450] <dbg> bt_mesh_scheduler_srv: schedule_action:           year: 124
   [00:01:39.680,450] <dbg> bt_mesh_scheduler_srv: schedule_action:          month: 11
   [00:01:39.680,480] <dbg> bt_mesh_scheduler_srv: schedule_action:            day: 25
   [00:01:39.680,480] <dbg> bt_mesh_scheduler_srv: schedule_action:           hour: 10
   [00:01:39.680,511] <dbg> bt_mesh_scheduler_srv: schedule_action:         minute: 55
   [00:01:39.680,511] <dbg> bt_mesh_scheduler_srv: schedule_action:         second: 0
   [00:01:39.680,572] <dbg> bt_mesh_scheduler_srv: run_scheduler: Scheduler started. Target uptime: 329954. Current uptime: 99680.
   [00:01:39.696,289] <dbg> bt_mesh_scheduler_srv: encode_action_status: Tx: scheduler server action status:
   [00:01:39.696,289] <dbg> bt_mesh_scheduler_srv: encode_action_status:         index: 0
   [00:01:39.696,319] <dbg> bt_mesh_scheduler_srv: encode_action_status:          year: 100
   [00:01:39.696,319] <dbg> bt_mesh_scheduler_srv: encode_action_status:         month: 0xfff
   [00:01:39.696,350] <dbg> bt_mesh_scheduler_srv: encode_action_status:           day: 0
   [00:01:39.696,350] <dbg> bt_mesh_scheduler_srv: encode_action_status:          wday: 0x7f
   [00:01:39.696,380] <dbg> bt_mesh_scheduler_srv: encode_action_status:          hour: 10
   [00:01:39.696,380] <dbg> bt_mesh_scheduler_srv: encode_action_status:        minute: 55
   [00:01:39.696,380] <dbg> bt_mesh_scheduler_srv: encode_action_status:        second: 0
   [00:01:39.696,411] <dbg> bt_mesh_scheduler_srv: encode_action_status:        action: 0
   [00:01:39.696,411] <dbg> bt_mesh_scheduler_srv: encode_action_status:    transition: 0
   [00:01:39.696,441] <dbg> bt_mesh_scheduler_srv: encode_action_status:         scene: 0
   [00:01:39.696,441] <dbg> bt_mesh_scheduler_srv: encode_action_status: Tx: scheduler server action status:
   [00:01:39.696,472] <dbg> bt_mesh_scheduler_srv: encode_action_status:         index: 0
   [00:01:39.696,472] <dbg> bt_mesh_scheduler_srv: encode_action_status:          year: 100
   [00:01:39.696,472] <dbg> bt_mesh_scheduler_srv: encode_action_status:         month: 0xfff
   [00:01:39.696,502] <dbg> bt_mesh_scheduler_srv: encode_action_status:           day: 0
   [00:01:39.696,502] <dbg> bt_mesh_scheduler_srv: encode_action_status:          wday: 0x7f
   [00:01:39.696,533] <dbg> bt_mesh_scheduler_srv: encode_action_status:          hour: 10
   [00:01:39.696,533] <dbg> bt_mesh_scheduler_srv: encode_action_status:        minute: 55
   [00:01:39.696,563] <dbg> bt_mesh_scheduler_srv: encode_action_status:        second: 0
   [00:01:39.696,563] <dbg> bt_mesh_scheduler_srv: encode_action_status:        action: 0
   [00:01:39.696,563] <dbg> bt_mesh_scheduler_srv: encode_action_status:    transition: 0
   [00:01:39.696,594] <dbg> bt_mesh_scheduler_srv: encode_action_status:         scene: 0

2. 1st Execution
   Target uptime: 329954. Current uptime: 330498.
   (CONFIG_LOG_BUFFER_SIZE is at maximum but some messages dropped.)
   

   [00:05:30.497,985] <dbg> bt_mesh_scheduler_srv: schedule_action:           hour: 10
   --- 9999 messages dropped ---
   [00:05:30.498,016] <dbg> bt_mesh_scheduler_srv: schedule_action:         minute: 55
   [00:05:30.498,016] <dbg> bt_mesh_scheduler_srv: schedule_action:         second: 0
   [00:05:30.498,107] <dbg> bt_mesh_scheduler_srv: run_scheduler: Scheduler started. Target uptime: 329954. Current uptime: 330498.

3. 2nd Execution
   Target uptime: 329954. Current uptime: 330498.
   

   [00:05:30.498,229] <dbg> bt_mesh_scheduler_srv: scheduled_action_handle: Scheduler action fired: 0
   [00:05:30.498,291] <dbg> bt_mesh_scheduler_srv: scheduled_action_handle: Onoff srv addr: 163 set: 0
   [00:05:30.498,382] <dbg> bt_mesh_scheduler_srv: scheduled_action_handle: Onoff srv addr: 164 set: 0
   [00:05:30.498,413] <dbg> bt_mesh_scheduler_srv: scheduled_action_handle: Onoff srv addr: 165 set: 0
   [00:05:30.498,504] <dbg> bt_mesh_scheduler_srv: schedule_action: Current uptime 330498
   [00:05:30.498,504] <dbg> bt_mesh_scheduler_srv: schedule_action: Current time:
   [00:05:30.498,535] <dbg> bt_mesh_scheduler_srv: schedule_action:         year: 124
   [00:05:30.498,565] <dbg> bt_mesh_scheduler_srv: schedule_action:        month: 11
   [00:05:30.498,565] <dbg> bt_mesh_scheduler_srv: schedule_action:          day: 25
   [00:05:30.498,596] <dbg> bt_mesh_scheduler_srv: schedule_action:         hour: 10
   [00:05:30.498,626] <dbg> bt_mesh_scheduler_srv: schedule_action:       minute: 54
   [00:05:30.498,657] <dbg> bt_mesh_scheduler_srv: schedule_action:       second: 59
   [00:05:30.498,748] <dbg> bt_mesh_scheduler_srv: schedule_action: Scheduled time:
   [00:05:30.498,779] <dbg> bt_mesh_scheduler_srv: schedule_action:           year: 124
   [00:05:30.498,779] <dbg> bt_mesh_scheduler_srv: schedule_action:          month: 11
   [00:05:30.498,809] <dbg> bt_mesh_scheduler_srv: schedule_action:            day: 25
   [00:05:30.498,840] <dbg> bt_mesh_scheduler_srv: schedule_action:           hour: 10
   [00:05:30.498,870] <dbg> bt_mesh_scheduler_srv: schedule_action:         minute: 55
   [00:05:30.498,901] <dbg> bt_mesh_scheduler_srv: schedule_action:         second: 0
   [00:05:30.498,962] <dbg> bt_mesh_scheduler_srv: run_scheduler: Scheduler started. Target uptime: 329954. Current uptime: 330498.

4. Last Execution
   Target uptime: 86729954. Current uptime: 330580.
   

   [00:05:30.579,406] <dbg> bt_mesh_scheduler_srv: scheduled_action_handle: Scheduler action fired: 0
   [00:05:30.579,437] <dbg> bt_mesh_scheduler_srv: scheduled_action_handle: Onoff srv addr: 163 set: 0
   [00:05:30.579,498] <dbg> bt_mesh_scheduler_srv: scheduled_action_handle: Onoff srv addr: 164 set: 0
   [00:05:30.579,559] <dbg> bt_mesh_scheduler_srv: scheduled_action_handle: Onoff srv addr: 165 set: 0
   [00:05:30.579,650] <dbg> bt_mesh_scheduler_srv: schedule_action: Current uptime 330579
   [00:05:30.579,650] <dbg> bt_mesh_scheduler_srv: schedule_action: Current time:
   [00:05:30.579,681] <dbg> bt_mesh_scheduler_srv: schedule_action:         year: 124
   [00:05:30.579,711] <dbg> bt_mesh_scheduler_srv: schedule_action:        month: 11
   [00:05:30.579,742] <dbg> bt_mesh_scheduler_srv: schedule_action:          day: 25
   [00:05:30.579,742] <dbg> bt_mesh_scheduler_srv: schedule_action:         hour: 10
   [00:05:30.579,772] <dbg> bt_mesh_scheduler_srv: schedule_action:       minute: 55
   [00:05:30.579,803] <dbg> bt_mesh_scheduler_srv: schedule_action:       second: 0
   [00:05:30.579,925] <dbg> bt_mesh_scheduler_srv: schedule_action: Scheduled time:
   [00:05:30.579,956] <dbg> bt_mesh_scheduler_srv: schedule_action:           year: 124
   [00:05:30.579,986] <dbg> bt_mesh_scheduler_srv: schedule_action:          month: 11
   [00:05:30.579,986] <dbg> bt_mesh_scheduler_srv: schedule_action:            day: 26
   [00:05:30.580,017] <dbg> bt_mesh_scheduler_srv: schedule_action:           hour: 10
   [00:05:30.580,047] <dbg> bt_mesh_scheduler_srv: schedule_action:         minute: 55
   [00:05:30.580,078] <dbg> bt_mesh_scheduler_srv: schedule_action:         second: 0
   [00:05:30.580,169] <dbg> bt_mesh_scheduler_srv: run_scheduler: Scheduler started. Target uptime: 86729954. Current uptime: 330580.

During the first execution, "Current uptime" exceeded "Target uptime".
Also, "Current uptime" was converted to 10:54:59AM instead of 10:55:00AM.
As a result, "scheduled_action_handle()" was executed immediately. 
This continued until "Current uptime" was converted to 10:55:00AM.
What could be the cause of this discrepancy in "Current uptime"(k_uptime_get())?
scheduler_srv.c

static void run_scheduler(struct bt_mesh_scheduler_srv *srv)
{
	struct tm sched_time;
	int64_t current_uptime = k_uptime_get();
	uint8_t planned_idx = get_least_time_index(srv);

	if (planned_idx == BT_MESH_SCHEDULER_ACTION_ENTRY_COUNT) {
		return;
	}

	tai_to_ts(&srv->sched_tai[planned_idx], &sched_time);
	int64_t scheduled_uptime = bt_mesh_time_srv_mktime(srv->time_srv,
			&sched_time);

	if (scheduled_uptime < 0) {
		LOG_WRN("Scheduler not started. Error: %lld.", scheduled_uptime);
		return;
	}

	srv->idx = planned_idx;
	k_work_reschedule(&srv->delayed_work,
			  K_MSEC(MAX(scheduled_uptime - current_uptime, 0)));
	LOG_DBG("Scheduler started. Target uptime: %lld. Current uptime: %lld.",
			scheduled_uptime, current_uptime);
}

This is my full log.
241225_scheduler_105500.log

Thanks for reading.

[Hung Bui]

Hi A.da,

I'm not so familiar with the mesh scheduler server so you may need to explain the issue a little bit more clear. 
Was the problem showed in the first log that "scheduler server action status" is executed 2 times  ? 

Could you tell me how to reproduce the issue ? Which sample you based your test on ? 

[a.da]

Additional information:

I found something concerning in the nRF Connect SDK.
There is a function that converts "uptime" to "TAI Time."
time_srv.c / tai_at()
However, it seems that "subsec" is not being used for carrying over to "sec."
As a result, the conversion to "TAI Time" appears to be inaccurate.
After making the modification as shown in the attached file, the function "scheduled_action_handle()" was executed only once at the scheduled time.
The at symbol (@) indicates the areas that have been edited.

Cote:

static inline struct bt_mesh_time_tai
tai_at(const struct bt_mesh_time_srv *srv, int64_t uptime)
{
	const struct bt_mesh_time_tai *sync = &srv->data.sync.status.tai;
	int64_t steps = (SUBSEC_STEPS * (uptime - srv->data.sync.uptime)) /
			MSEC_PER_SEC;
	uint64_t sec    = 0;				// @@@ Add
	uint64_t subsec = 0;				// @@@ Add

	if (tai_is_unknown(sync)) {
		return *sync;
	}

	// @@@ Delete
//	return (struct bt_mesh_time_tai) {
//		.sec = sync->sec + (steps / SUBSEC_STEPS),
//		.subsec = sync->subsec + steps,
//	};

	// @@@ Add
	subsec = sync->subsec + steps;
	sec    = sync->sec    + (subsec / SUBSEC_STEPS);

	if (subsec >= SUBSEC_STEPS) {
		subsec %= SUBSEC_STEPS;
	}

	return (struct bt_mesh_time_tai) {
		.sec    = sec   ,
		.subsec = subsec,
	};
}

Fullscreen time_srv.c Download

/*
 * Copyright (c) 2020 Nordic Semiconductor ASA
 *
 * SPDX-License-Identifier: LicenseRef-Nordic-5-Clause
 */

#include <bluetooth/mesh/time_srv.h>
#include "time_internal.h"
#include "model_utils.h"
#include "time_util.h"

#define LOG_LEVEL 4						// @@@
#include "zephyr/logging/log.h"			// @@@
LOG_MODULE_REGISTER(bt_mesh_time_srv);	// @@@

#define SUBSEC_STEPS 256U
#define STATUS_INTERVAL_MIN 30000ll

struct bt_mesh_time_srv_settings_data {
	uint8_t role;
	int16_t time_zone_offset_new;
	int16_t tai_utc_delta_new;
	uint64_t tai_of_zone_change;
	uint64_t tai_of_delta_change;
};

static inline int64_t zone_offset_to_sec(int16_t raw_zone)
{
	return raw_zone * 15 * SEC_PER_MIN;
}

static inline uint64_t tai_to_ms(const struct bt_mesh_time_tai *tai)
{
	return MSEC_PER_SEC * tai->sec +
	       (MSEC_PER_SEC * tai->subsec) / SUBSEC_STEPS;
}

static inline bool tai_is_unknown(const struct bt_mesh_time_tai *tai)
{
	return !tai->sec && !tai->subsec;
}

static inline struct bt_mesh_time_tai
tai_at(const struct bt_mesh_time_srv *srv, int64_t uptime)
{
	const struct bt_mesh_time_tai *sync = &srv->data.sync.status.tai;
	int64_t steps = (SUBSEC_STEPS * (uptime - srv->data.sync.uptime)) /
			MSEC_PER_SEC;
	uint64_t sec    = 0;				// @@@ Add
	uint64_t subsec = 0;				// @@@ Add

	if (tai_is_unknown(sync)) {
		return *sync;
	}

	// @@@ Delete
//	return (struct bt_mesh_time_tai) {
//		.sec = sync->sec + (steps / SUBSEC_STEPS),
//		.subsec = sync->subsec + steps,
//	};

	// @@@ Add
	subsec = sync->subsec + steps;
	sec    = sync->sec    + (subsec / SUBSEC_STEPS);

	if (subsec >= SUBSEC_STEPS) {
		subsec %= SUBSEC_STEPS;
	}

	return (struct bt_mesh_time_tai) {
		.sec    = sec   ,
		.subsec = subsec,
	};
}

static int store_state(struct bt_mesh_time_srv *srv)
{
	if (!IS_ENABLED(CONFIG_BT_SETTINGS)) {
		return 0;
	}

	struct bt_mesh_time_srv_settings_data data = {
		.role = srv->data.role,
		.time_zone_offset_new = srv->data.time_zone_change.new_offset,
		.tai_of_zone_change = srv->data.time_zone_change.timestamp,
		.tai_utc_delta_new = srv->data.tai_utc_change.delta_new,
		.tai_of_delta_change = srv->data.tai_utc_change.timestamp,
	};

	return bt_mesh_model_data_store(srv->model, false, NULL, &data, sizeof(data));
}

static uint64_t get_uncertainty_ms(const struct bt_mesh_time_srv *srv,
				   int64_t uptime)
{
	uint64_t drift = ((uptime - srv->data.sync.uptime) *
			  CONFIG_BT_MESH_TIME_SRV_CLOCK_ACCURACY) /
			 USEC_PER_SEC;

	return srv->data.sync.status.uncertainty + drift;
}

static int16_t get_zone_offset(const struct bt_mesh_time_srv *srv,
			       int64_t uptime)
{
	struct bt_mesh_time_tai tai = tai_at(srv, uptime);

	if (srv->data.time_zone_change.timestamp &&
	    tai.sec >= srv->data.time_zone_change.timestamp) {
		return srv->data.time_zone_change.new_offset;
	}

	return srv->data.sync.status.time_zone_offset;
}

static int16_t get_utc_delta(const struct bt_mesh_time_srv *srv, int64_t uptime)
{
	struct bt_mesh_time_tai tai = tai_at(srv, uptime);

	if (srv->data.tai_utc_change.timestamp &&
	    tai.sec >= srv->data.tai_utc_change.timestamp) {
		return srv->data.tai_utc_change.delta_new;
	}

	return srv->data.sync.status.tai_utc_delta;
}

static int send_zone_status(const struct bt_mesh_model *model,
			    struct bt_mesh_msg_ctx *ctx)
{
	struct bt_mesh_time_srv *srv = model->rt->user_data;
	struct bt_mesh_time_zone_status resp = {
		.current_offset = get_zone_offset(srv, k_uptime_get()),
		.time_zone_change = srv->data.time_zone_change,
	};
	BT_MESH_MODEL_BUF_DEFINE(msg, BT_MESH_TIME_OP_TIME_ZONE_STATUS,
				 BT_MESH_TIME_MSG_LEN_TIME_ZONE_STATUS);
	bt_mesh_model_msg_init(&msg, BT_MESH_TIME_OP_TIME_ZONE_STATUS);

	net_buf_simple_add_u8(
		&msg, (uint8_t)(resp.current_offset + ZONE_CHANGE_ZERO_POINT));
	net_buf_simple_add_u8(&msg, (uint8_t)(resp.time_zone_change.new_offset +
					   ZONE_CHANGE_ZERO_POINT));
	bt_mesh_time_buf_put_tai_sec(&msg, resp.time_zone_change.timestamp);

	return bt_mesh_model_send(model, ctx, &msg, NULL, NULL);
}

static int send_tai_utc_delta_status(const struct bt_mesh_model *model,
				     struct bt_mesh_msg_ctx *ctx)
{
	struct bt_mesh_time_srv *srv = model->rt->user_data;
	struct bt_mesh_time_tai_utc_delta_status resp = {
		.delta_current = get_utc_delta(srv, k_uptime_get()),
		.tai_utc_change = srv->data.tai_utc_change,
	};
	BT_MESH_MODEL_BUF_DEFINE(msg, BT_MESH_TIME_OP_TAI_UTC_DELTA_STATUS,
				 BT_MESH_TIME_MSG_LEN_TAI_UTC_DELTA_STATUS);
	bt_mesh_model_msg_init(&msg, BT_MESH_TIME_OP_TAI_UTC_DELTA_STATUS);
	net_buf_simple_add_le16(
		&msg, (uint16_t)(resp.delta_current + UTC_CHANGE_ZERO_POINT));
	net_buf_simple_add_le16(&msg, (uint16_t)(resp.tai_utc_change.delta_new +
					      UTC_CHANGE_ZERO_POINT));
	bt_mesh_time_buf_put_tai_sec(&msg, resp.tai_utc_change.timestamp);

	return bt_mesh_model_send(model, ctx, &msg, NULL, NULL);
}

static int send_role_status(const struct bt_mesh_model *model,
			    struct bt_mesh_msg_ctx *ctx)
{
	struct bt_mesh_time_srv *srv = model->rt->user_data;
	uint8_t resp = srv->data.role;

	BT_MESH_MODEL_BUF_DEFINE(msg, BT_MESH_TIME_OP_TIME_ROLE_STATUS,
				 BT_MESH_TIME_MSG_LEN_TIME_ROLE_STATUS);
	bt_mesh_model_msg_init(&msg, BT_MESH_TIME_OP_TIME_ROLE_STATUS);

	net_buf_simple_add_u8(&msg, resp);

	return bt_mesh_model_send(model, ctx, &msg, NULL, NULL);
}

static int send_time_status(const struct bt_mesh_model *model,
			    struct bt_mesh_msg_ctx *ctx, int64_t uptime)
{
	struct bt_mesh_time_srv *srv = model->rt->user_data;
	struct bt_mesh_time_status status;
	int err;

	BT_MESH_MODEL_BUF_DEFINE(msg, BT_MESH_TIME_OP_TIME_STATUS,
				 BT_MESH_TIME_MSG_MAXLEN_TIME_STATUS);
	bt_mesh_model_msg_init(&msg, BT_MESH_TIME_OP_TIME_STATUS);

	err = bt_mesh_time_srv_status(srv, uptime, &status);
	if (err) {
		/* MshMDLv1.1: 5.2.1.3: If the TAI Seconds field is
		 * 0, all other fields shall be omitted
		 */
		bt_mesh_time_buf_put_tai_sec(&msg, 0);
	} else {
		/* Account for delay in TX processing: */
		status.uncertainty += CONFIG_BT_MESH_TIME_MESH_HOP_UNCERTAINTY;
		bt_mesh_time_encode_time_params(&msg, &status);
	}

	return bt_mesh_msg_send(model, ctx, &msg);
}

static void time_status_send_after_delay(struct k_work *work)
{
	struct k_work_delayable *tmp = k_work_delayable_from_work(work);
	struct bt_mesh_time_srv *srv = CONTAINER_OF(tmp, struct bt_mesh_time_srv, status_delay);

	(void)bt_mesh_time_srv_time_status_send(srv, NULL);
}

static int handle_time_status(const struct bt_mesh_model *model, struct bt_mesh_msg_ctx *ctx,
			      struct net_buf_simple *buf)
{
	struct bt_mesh_time_srv *srv = model->rt->user_data;

	if ((srv->data.role != BT_MESH_TIME_CLIENT) &&
	    (srv->data.role != BT_MESH_TIME_RELAY)) {
		/* Not relevant for this role, ignore. */
		return 0;
	}

	struct bt_mesh_time_status status;

	bt_mesh_time_decode_time_params(buf, &status);

	if (status.is_authority <= srv->data.sync.status.is_authority &&
	    srv->data.sync.status.uncertainty < status.uncertainty) {
		/* The new time status is not an improvement, ignore. */
		return 0;
	}

	srv->data.sync.uptime = k_uptime_get();
	srv->data.sync.status.tai = status.tai;
	srv->data.sync.status.uncertainty = status.uncertainty;
	srv->data.sync.status.time_zone_offset = status.time_zone_offset;
	srv->data.sync.status.tai_utc_delta = status.tai_utc_delta;
	if (srv->time_update_cb != NULL) {
		srv->time_update_cb(srv, ctx, BT_MESH_TIME_SRV_STATUS_UPDATE);
	}

	if (srv->data.role == BT_MESH_TIME_RELAY) {
		/* The time server shouldn't send out statuses more often than every 30 seconds. */
		if (srv->data.sync.uptime < (srv->data.timestamp + STATUS_INTERVAL_MIN)) {
			return 0;
		}

		/* Random delay has been already scheduled. */
		if (k_work_delayable_is_pending(&srv->status_delay)) {
			return 0;
		}

		uint8_t rnd;

		bt_rand(&rnd, sizeof(uint8_t));
		rnd = 20 + rnd % 30;
		srv->data.sync.status.uncertainty += rnd;
		k_work_schedule(&srv->status_delay, K_MSEC(rnd));
	}

	return 0;
}

static int handle_time_get(const struct bt_mesh_model *model, struct bt_mesh_msg_ctx *ctx,
			   struct net_buf_simple *buf)
{
	send_time_status(model, ctx, k_uptime_get());

	return 0;
}

static int handle_time_set(const struct bt_mesh_model *model, struct bt_mesh_msg_ctx *ctx,
			   struct net_buf_simple *buf)
{
	struct bt_mesh_time_srv *srv = model->rt->user_data;

	bt_mesh_time_decode_time_params(buf, &srv->data.sync.status);
	srv->data.sync.uptime = k_uptime_get();
	LOG_DBG("tai sec         : %llu", srv->data.sync.status.tai.sec         );	// @@@
	LOG_DBG("tai subsec      : %u"  , srv->data.sync.status.tai.subsec      );	// @@@
	LOG_DBG("uncertainty     : %llu", srv->data.sync.status.uncertainty     );	// @@@
	LOG_DBG("tai_utc_delta   : %u"  , srv->data.sync.status.tai_utc_delta   );	// @@@
	LOG_DBG("time_zone_offset: %u"  , srv->data.sync.status.time_zone_offset);	// @@@
	LOG_DBG("is_authority    : %u"  , srv->data.sync.status.is_authority    );	// @@@
	LOG_DBG("uptime          : %llu", srv->data.sync.uptime                 );	// @@@

	if (srv->time_update_cb != NULL) {
		srv->time_update_cb(srv, ctx, BT_MESH_TIME_SRV_SET_UPDATE);
	}

	/* publish state changing */
	(void)bt_mesh_time_srv_time_status_send(srv, NULL);

	send_time_status(model, ctx, srv->data.sync.uptime);

	return 0;
}

static int handle_zone_get(const struct bt_mesh_model *model, struct bt_mesh_msg_ctx *ctx,
			   struct net_buf_simple *buf)
{
	send_zone_status(model, ctx);

	return 0;
}

static int handle_zone_set(const struct bt_mesh_model *model, struct bt_mesh_msg_ctx *ctx,
			   struct net_buf_simple *buf)
{
	struct bt_mesh_time_srv *srv = model->rt->user_data;

	srv->data.time_zone_change.new_offset =
		net_buf_simple_pull_u8(buf) - ZONE_CHANGE_ZERO_POINT;
	srv->data.time_zone_change.timestamp =
		bt_mesh_time_buf_pull_tai_sec(buf);
	store_state(srv);
	if (srv->time_update_cb != NULL) {
		srv->time_update_cb(srv, ctx, BT_MESH_TIME_SRV_ZONE_UPDATE);
	}

	send_zone_status(model, ctx);

	return 0;
}

static int handle_tai_utc_delta_get(const struct bt_mesh_model *model, struct bt_mesh_msg_ctx *ctx,
				    struct net_buf_simple *buf)
{
	send_tai_utc_delta_status(model, ctx);

	return 0;
}

static int handle_tai_utc_delta_set(const struct bt_mesh_model *model, struct bt_mesh_msg_ctx *ctx,
				    struct net_buf_simple *buf)
{
	struct bt_mesh_time_srv *srv = model->rt->user_data;

	srv->data.tai_utc_change.delta_new =
		net_buf_simple_pull_le16(buf) - UTC_CHANGE_ZERO_POINT;
	srv->data.tai_utc_change.timestamp = bt_mesh_time_buf_pull_tai_sec(buf);
	store_state(srv);
	if (srv->time_update_cb != NULL) {
		srv->time_update_cb(srv, ctx, BT_MESH_TIME_SRV_UTC_UPDATE);
	}

	send_tai_utc_delta_status(model, ctx);

	return 0;
}

static int handle_role_get(const struct bt_mesh_model *model, struct bt_mesh_msg_ctx *ctx,
			   struct net_buf_simple *buf)
{
	send_role_status(model, ctx);

	return 0;
}

static int handle_role_set(const struct bt_mesh_model *model, struct bt_mesh_msg_ctx *ctx,
			   struct net_buf_simple *buf)
{
	struct bt_mesh_time_srv *srv = model->rt->user_data;
	enum bt_mesh_time_role role;

	role = net_buf_simple_pull_u8(buf);
	if (role != BT_MESH_TIME_NONE && role != BT_MESH_TIME_AUTHORITY &&
	    role != BT_MESH_TIME_RELAY && role != BT_MESH_TIME_CLIENT) {
		return -EINVAL;
	}

	srv->data.role = role;

	store_state(srv);
	send_role_status(model, ctx);

	return 0;
}

const struct bt_mesh_model_op _bt_mesh_time_srv_op[] = {
	{
		BT_MESH_TIME_OP_TIME_GET,
		BT_MESH_LEN_EXACT(BT_MESH_TIME_MSG_LEN_GET),
		handle_time_get,
	},
	{
		BT_MESH_TIME_OP_TIME_STATUS,
		BT_MESH_LEN_MIN(BT_MESH_TIME_MSG_MINLEN_TIME_STATUS),
		handle_time_status,
	},
	{
		BT_MESH_TIME_OP_TIME_ZONE_GET,
		BT_MESH_LEN_EXACT(BT_MESH_TIME_MSG_LEN_GET),
		handle_zone_get,
	},
	{
		BT_MESH_TIME_OP_TAI_UTC_DELTA_GET,
		BT_MESH_LEN_EXACT(BT_MESH_TIME_MSG_LEN_GET),
		handle_tai_utc_delta_get,
	},
	BT_MESH_MODEL_OP_END,
};

const struct bt_mesh_model_op _bt_mesh_time_setup_srv_op[] = {
	{
		BT_MESH_TIME_OP_TIME_SET,
		BT_MESH_LEN_EXACT(BT_MESH_TIME_MSG_LEN_TIME_SET),
		handle_time_set,
	},
	{
		BT_MESH_TIME_OP_TIME_ZONE_SET,
		BT_MESH_LEN_EXACT(BT_MESH_TIME_MSG_LEN_TIME_ZONE_SET),
		handle_zone_set,
	},
	{
		BT_MESH_TIME_OP_TAI_UTC_DELTA_SET,
		BT_MESH_LEN_EXACT(BT_MESH_TIME_MSG_LEN_TAI_UTC_DELTA_SET),
		handle_tai_utc_delta_set,
	},
	{
		BT_MESH_TIME_OP_TIME_ROLE_GET,
		BT_MESH_LEN_EXACT(BT_MESH_TIME_MSG_LEN_GET),
		handle_role_get,
	},
	{
		BT_MESH_TIME_OP_TIME_ROLE_SET,
		BT_MESH_LEN_EXACT(BT_MESH_TIME_MSG_LEN_TIME_ROLE_SET),
		handle_role_set,
	},
	BT_MESH_MODEL_OP_END,
};

static int bt_mesh_time_srv_init(const struct bt_mesh_model *model)
{
	struct bt_mesh_time_srv *srv = model->rt->user_data;

	srv->model = model;
	srv->data.timestamp = -STATUS_INTERVAL_MIN;
	net_buf_simple_init(srv->pub.msg, 0);
	srv->is_unsolicited = false;
	srv->cached_ttl = 0;

	k_work_init_delayable(&srv->status_delay, time_status_send_after_delay);

	return 0;
}

static void bt_mesh_time_srv_reset(const struct bt_mesh_model *model)
{
	struct bt_mesh_time_srv *srv = model->rt->user_data;
	struct bt_mesh_time_srv_data data = { .timestamp = -STATUS_INTERVAL_MIN };

	srv->data = data;
	net_buf_simple_reset(srv->pub.msg);
	srv->is_unsolicited = false;
	srv->cached_ttl = 0;
	(void)k_work_cancel_delayable(&srv->status_delay);

	if (IS_ENABLED(CONFIG_BT_SETTINGS)) {
		(void)bt_mesh_model_data_store(srv->model, false, NULL, NULL,
					       0);
	}
}

#ifdef CONFIG_BT_MESH_TIME_SRV_PERSISTENT
static int bt_mesh_time_srv_settings_set(const struct bt_mesh_model *model,
					 const char *name, size_t len_rd,
					 settings_read_cb read_cb, void *cb_arg)
{
	struct bt_mesh_time_srv *srv = model->rt->user_data;
	struct bt_mesh_time_srv_settings_data data;

	if (read_cb(cb_arg, &data, sizeof(data)) != sizeof(data)) {
		return -EINVAL;
	}

	srv->data.role = data.role;
	srv->data.time_zone_change.new_offset = data.time_zone_offset_new;
	srv->data.time_zone_change.timestamp = data.tai_of_zone_change;
	srv->data.tai_utc_change.delta_new = data.tai_utc_delta_new;
	srv->data.tai_utc_change.timestamp = data.tai_of_delta_change;

	return 0;
}
#endif

const struct bt_mesh_model_cb _bt_mesh_time_srv_cb = {
	.init = bt_mesh_time_srv_init,
	.reset = bt_mesh_time_srv_reset,
#ifdef CONFIG_BT_MESH_TIME_SRV_PERSISTENT
	.settings_set = bt_mesh_time_srv_settings_set,
#endif
};

static int bt_mesh_time_setup_srv_init(const struct bt_mesh_model *model)
{
	struct bt_mesh_time_srv *srv = model->rt->user_data;
#if defined(CONFIG_BT_MESH_COMP_PAGE_1)
	int err = bt_mesh_model_correspond(model, srv->model);

	if (err) {
		return err;
	}
#endif

	return bt_mesh_model_extend(model, srv->model);
}


const struct bt_mesh_model_cb _bt_mesh_time_setup_srv_cb = {
	.init = bt_mesh_time_setup_srv_init,
};

int _bt_mesh_time_srv_update_handler(const struct bt_mesh_model *model)
{
	struct bt_mesh_time_srv *srv = model->rt->user_data;
	struct bt_mesh_model_pub *pub = srv->model->pub;
	struct bt_mesh_time_status status;
	int64_t uptime;
	int err;

	if (srv->data.role != BT_MESH_TIME_AUTHORITY &&
	    srv->data.role != BT_MESH_TIME_RELAY) {
		return -EPERM;
	}

	uptime = k_uptime_get();
	err = bt_mesh_time_srv_status(srv, uptime, &status);
	if (err) {
		return err;
	}

	/* If sent as an unsolicited message, the Time Status message shall be sent
	 * with TTL=0 to avoid building up cumulative time errors resulting from delays
	 * in processing the messages by relays.
	 */
	if (!bt_mesh_model_pub_is_retransmission(pub->mod) && srv->is_unsolicited) {
		pub->ttl = srv->cached_ttl;
		srv->is_unsolicited = false;
	}

	srv->data.timestamp = uptime;
	/* Account for delay in TX processing: */
	status.uncertainty += CONFIG_BT_MESH_TIME_MESH_HOP_UNCERTAINTY;

	bt_mesh_model_msg_init(srv->pub.msg, BT_MESH_TIME_OP_TIME_STATUS);
	bt_mesh_time_encode_time_params(srv->pub.msg, &status);

	return 0;
}

int bt_mesh_time_srv_time_status_send(struct bt_mesh_time_srv *srv,
				      struct bt_mesh_msg_ctx *ctx)
{
	struct bt_mesh_model_pub *pub = srv->model->pub;
	int64_t uptime = k_uptime_get();
	int err;

	/** MshMDLv1.1: 5.3.1.2.2:
	 * The message (Time Status) may be sent as an unsolicited message at any time
	 * if the value of the Time Role state is 0x01 (Time Authority) or 0x02 (Time Relay).
	 */
	if ((srv->data.role != BT_MESH_TIME_AUTHORITY) && (srv->data.role != BT_MESH_TIME_RELAY)) {
		return -EOPNOTSUPP;
	}

	if (ctx) {
		ctx->send_ttl = 0;
		ctx->rnd_delay = false;
	} else {
		srv->cached_ttl = srv->is_unsolicited ? srv->cached_ttl : pub->ttl;
		srv->is_unsolicited = true;
		pub->ttl = 0;
	}

	err = send_time_status(srv->model, ctx, uptime);
	if (!err) {
		srv->data.timestamp = uptime;
	}

	return err;
}

int bt_mesh_time_srv_status(struct bt_mesh_time_srv *srv, uint64_t uptime,
			    struct bt_mesh_time_status *status)
{
	if ((srv->data.sync.uptime > uptime) ||
	    tai_is_unknown(&srv->data.sync.status.tai)) {
		return -EAGAIN;
	}

	status->tai = tai_at(srv, uptime),
	status->uncertainty = get_uncertainty_ms(srv, uptime);
	status->tai_utc_delta = get_utc_delta(srv, uptime);
	status->time_zone_offset = get_zone_offset(srv, uptime);
	status->is_authority = srv->data.sync.status.is_authority;
	return 0;
}

int64_t bt_mesh_time_srv_mktime(struct bt_mesh_time_srv *srv, struct tm *timeptr)
{
	int64_t curr_utc_delta = srv->data.sync.status.tai_utc_delta;
	int64_t curr_time_zone =
		zone_offset_to_sec(srv->data.sync.status.time_zone_offset);
	struct bt_mesh_time_tai tai;
	int64_t sec;
	int err;

	err = ts_to_tai(&tai, timeptr);
	if (err) {
		return err;
	}

	sec = tai.sec;

	int64_t new_time_zone =
		zone_offset_to_sec(srv->data.time_zone_change.new_offset);

	if (srv->data.time_zone_change.timestamp &&
	    sec >= srv->data.time_zone_change.timestamp + new_time_zone) {
		sec -= new_time_zone;
	} else {
		sec -= curr_time_zone;
	}

	int64_t new_utc_delta = srv->data.tai_utc_change.delta_new;

	if (srv->data.tai_utc_change.timestamp &&
	    sec >= srv->data.tai_utc_change.timestamp - new_utc_delta) {
		sec += new_utc_delta;
	} else {
		sec += curr_utc_delta;
	}

	if ((sec < 0) || (sec < srv->data.sync.status.tai.sec)) {
		return -EINVAL;
	}

	tai.sec = sec;

	return tai_to_ms(&tai) - tai_to_ms(&srv->data.sync.status.tai) +
	       srv->data.sync.uptime;
}

struct tm *bt_mesh_time_srv_localtime_r(struct bt_mesh_time_srv *srv,
					int64_t uptime, struct tm *timeptr)
{
	if (tai_is_unknown(&srv->data.sync.status.tai) ||
	    srv->data.sync.uptime > uptime) {
		return NULL;
	}

	struct bt_mesh_time_tai tai = tai_at(srv, uptime);

	tai.sec += zone_offset_to_sec(get_zone_offset(srv, uptime));
	tai.sec -= get_utc_delta(srv, uptime);

	tai_to_ts(&tai, timeptr);
	return timeptr;
}

struct tm *bt_mesh_time_srv_localtime(struct bt_mesh_time_srv *srv,
				      int64_t uptime)
{
	static struct tm timeptr;

	return bt_mesh_time_srv_localtime_r(srv, uptime, &timeptr);
}

uint64_t bt_mesh_time_srv_uncertainty_get(struct bt_mesh_time_srv *srv,
				       int64_t uptime)
{
	if ((uptime - srv->data.sync.uptime) < 0) {
		return -EAGAIN;
	}

	return get_uncertainty_ms(srv, uptime);
}

void bt_mesh_time_srv_time_set(struct bt_mesh_time_srv *srv, int64_t uptime,
			       const struct bt_mesh_time_status *status)
{
	srv->data.sync.uptime = uptime;
	srv->data.sync.status = *status;
}

void bt_mesh_time_srv_time_zone_change_set(
	struct bt_mesh_time_srv *srv,
	const struct bt_mesh_time_zone_change *data)
{
	srv->data.time_zone_change = *data;
	store_state(srv);
}

void bt_mesh_time_srv_tai_utc_change_set(
	struct bt_mesh_time_srv *srv,
	const struct bt_mesh_time_tai_utc_change *data)
{
	srv->data.tai_utc_change = *data;
	store_state(srv);
}

void bt_mesh_time_srv_role_set(struct bt_mesh_time_srv *srv,
			       enum bt_mesh_time_role role)
{
	srv->data.role = role;
	store_state(srv);
}

Log:

[00:00:34.988,891] <dbg> bt_mesh_time_srv: handle_time_set: tai sec         : 892473518822531
[00:00:34.988,922] <dbg> bt_mesh_time_srv: handle_time_set: tai subsec      : 42
[00:00:34.988,922] <dbg> bt_mesh_time_srv: handle_time_set: uncertainty     : 0
[00:00:34.988,952] <dbg> bt_mesh_time_srv: handle_time_set: tai_utc_delta   : 37
[00:00:34.988,952] <dbg> bt_mesh_time_srv: handle_time_set: time_zone_offset: 36
[00:00:34.988,983] <dbg> bt_mesh_time_srv: handle_time_set: is_authority    : 0
[00:00:34.988,983] <dbg> bt_mesh_time_srv: handle_time_set: uptime          : 34988
[00:01:00.609,008] <dbg> bt_mesh_scheduler_srv: action_set: Rx: scheduler server action index 0 set, ack 1
[00:01:00.609,100] <dbg> bt_mesh_scheduler_srv: schedule_action: Current uptime 60609
[00:01:00.609,100] <dbg> bt_mesh_scheduler_srv: schedule_action: Current time:
[00:01:00.609,100] <dbg> bt_mesh_scheduler_srv: schedule_action:         year: 125
[00:01:00.609,130] <dbg> bt_mesh_scheduler_srv: schedule_action:        month: 0
[00:01:00.609,130] <dbg> bt_mesh_scheduler_srv: schedule_action:          day: 7
[00:01:00.609,161] <dbg> bt_mesh_scheduler_srv: schedule_action:         hour: 16
[00:01:00.609,161] <dbg> bt_mesh_scheduler_srv: schedule_action:       minute: 29
[00:01:00.609,191] <dbg> bt_mesh_scheduler_srv: schedule_action:       second: 59
[00:01:00.609,252] <dbg> bt_mesh_scheduler_srv: schedule_action: Scheduled time:
[00:01:00.609,283] <dbg> bt_mesh_scheduler_srv: schedule_action:           year: 125
[00:01:00.609,283] <dbg> bt_mesh_scheduler_srv: schedule_action:          month: 0
[00:01:00.609,313] <dbg> bt_mesh_scheduler_srv: schedule_action:            day: 7
[00:01:00.609,313] <dbg> bt_mesh_scheduler_srv: schedule_action:           hour: 16
[00:01:00.609,344] <dbg> bt_mesh_scheduler_srv: schedule_action:         minute: 35
[00:01:00.609,344] <dbg> bt_mesh_scheduler_srv: schedule_action:         second: 0
[00:01:00.609,405] <dbg> bt_mesh_scheduler_srv: run_scheduler: Scheduler started. Target uptime: 360824. Current uptime: 60609.
[00:01:00.624,084] <dbg> bt_mesh_scheduler_srv: encode_action_status: Tx: scheduler server action status:
[00:01:00.624,114] <dbg> bt_mesh_scheduler_srv: encode_action_status:         index: 0
[00:01:00.624,145] <dbg> bt_mesh_scheduler_srv: encode_action_status:          year: 100
[00:01:00.624,145] <dbg> bt_mesh_scheduler_srv: encode_action_status:         month: 0xfff
[00:01:00.624,145] <dbg> bt_mesh_scheduler_srv: encode_action_status:           day: 0
[00:01:00.624,176] <dbg> bt_mesh_scheduler_srv: encode_action_status:          wday: 0x7f
[00:01:00.624,176] <dbg> bt_mesh_scheduler_srv: encode_action_status:          hour: 16
[00:01:00.624,206] <dbg> bt_mesh_scheduler_srv: encode_action_status:        minute: 35
[00:01:00.624,206] <dbg> bt_mesh_scheduler_srv: encode_action_status:        second: 0
[00:01:00.624,206] <dbg> bt_mesh_scheduler_srv: encode_action_status:        action: 0
[00:01:00.624,237] <dbg> bt_mesh_scheduler_srv: encode_action_status:    transition: 0
[00:01:00.624,237] <dbg> bt_mesh_scheduler_srv: encode_action_status:         scene: 0
[00:01:00.624,267] <dbg> bt_mesh_scheduler_srv: encode_action_status: Tx: scheduler server action status:
[00:01:00.624,267] <dbg> bt_mesh_scheduler_srv: encode_action_status:         index: 0
[00:01:00.624,298] <dbg> bt_mesh_scheduler_srv: encode_action_status:          year: 100
[00:01:00.624,298] <dbg> bt_mesh_scheduler_srv: encode_action_status:         month: 0xfff
[00:01:00.624,328] <dbg> bt_mesh_scheduler_srv: encode_action_status:           day: 0
[00:01:00.624,328] <dbg> bt_mesh_scheduler_srv: encode_action_status:          wday: 0x7f
[00:01:00.624,328] <dbg> bt_mesh_scheduler_srv: encode_action_status:          hour: 16
[00:01:00.624,359] <dbg> bt_mesh_scheduler_srv: encode_action_status:        minute: 35
[00:01:00.624,359] <dbg> bt_mesh_scheduler_srv: encode_action_status:        second: 0
[00:01:00.624,389] <dbg> bt_mesh_scheduler_srv: encode_action_status:        action: 0
[00:01:00.624,389] <dbg> bt_mesh_scheduler_srv: encode_action_status:    transition: 0
[00:01:00.624,420] <dbg> bt_mesh_scheduler_srv: encode_action_status:         scene: 0
[00:06:00.824,523] <dbg> bt_mesh_scheduler_srv: scheduled_action_handle: Scheduler action fired: 0
[00:06:00.824,584] <dbg> bt_mesh_scheduler_srv: scheduled_action_handle: Onoff srv addr: 486 set: 0
[00:06:00.824,645] <dbg> bt_mesh_scheduler_srv: scheduled_action_handle: Onoff srv addr: 487 set: 0
[00:06:00.824,645] <dbg> bt_mesh_scheduler_srv: scheduled_action_handle: Onoff srv addr: 488 set: 0
[00:06:00.824,737] <dbg> bt_mesh_scheduler_srv: schedule_action: Current uptime 360824
[00:06:00.824,737] <dbg> bt_mesh_scheduler_srv: schedule_action: Current time:
[00:06:00.824,737] <dbg> bt_mesh_scheduler_srv: schedule_action:         year: 125
[00:06:00.824,768] <dbg> bt_mesh_scheduler_srv: schedule_action:        month: 0
[00:06:00.824,768] <dbg> bt_mesh_scheduler_srv: schedule_action:          day: 7
[00:06:00.824,798] <dbg> bt_mesh_scheduler_srv: schedule_action:         hour: 16
[00:06:00.824,829] <dbg> bt_mesh_scheduler_srv: schedule_action:       minute: 35
[00:06:00.824,829] <dbg> bt_mesh_scheduler_srv: schedule_action:       second: 0
[00:06:00.824,951] <dbg> bt_mesh_scheduler_srv: schedule_action: Scheduled time:
[00:06:00.824,951] <dbg> bt_mesh_scheduler_srv: schedule_action:           year: 125
[00:06:00.824,951] <dbg> bt_mesh_scheduler_srv: schedule_action:          month: 0
[00:06:00.824,981] <dbg> bt_mesh_scheduler_srv: schedule_action:            day: 8
[00:06:00.824,981] <dbg> bt_mesh_scheduler_srv: schedule_action:           hour: 16
[00:06:00.825,012] <dbg> bt_mesh_scheduler_srv: schedule_action:         minute: 35
[00:06:00.825,012] <dbg> bt_mesh_scheduler_srv: schedule_action:         second: 0
[00:06:00.825,073] <dbg> bt_mesh_scheduler_srv: run_scheduler: Scheduler started. Target uptime: 86760824. Current uptime: 360825.

Could you please check and confirm?

[Hung Bui]

Hi a.da, 

Thanks for the report . I think you are right. But I'm checking with the mesh team to hear from them. I will keep you updated. 

[Hung Bui]

Hi A.da, 
A PR has been created following your suggestion: 
https://github.com/nrfconnect/sdk-nrf/pull/19805
Thanks for your report

[a.da]

Hi Hung,

Thank you for your quick response. I’m looking forward to the release.

a.da