Mesh time server not responding to bt_mesh_time_cli_time_set (zephyr)

[bursztyn12]

Hello everybody,

I'm trying to develop simple time synchronization system upon mesh time model, but after sending bt_mesh_time_cli_time_set, first of all my time_update_cb in time_server model is not invoked by handle_time_set function, and then time_status handler should be called after my time_client receives a time status message, but again there's no such action, so i don't really get why it's behaving that way.

This is client model_handler code, where I think whole client init routine is set up properly, same for bt_mesh_time_status struct in set_tai function:

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

#include <bluetooth/bluetooth.h>
#include <bluetooth/mesh/models.h>
#include <dk_buttons_and_leds.h>
#include "model_handler.h"

#define GET_DATA_INTERVAL 3000

static struct bt_mesh_time_status bt_time_status;
static struct bt_mesh_time_tai tai;
static struct tm timeptr = {
    .tm_year = 2021-1900,
    .tm_mon = 05,
    .tm_mday = 24,
    .tm_hour = 23,
    .tm_min = 51,
    .tm_sec = 59,
};

static void time_status(struct bt_mesh_time_cli *cli, struct bt_mesh_msg_ctx *ctx, const struct bt_mesh_time_status *status){
    printk("time_status");
    printk("Tai sec: %"PRId64"\n", status->tai.sec);
    printk("Tai subsec: %"PRId64"\n", status->tai.subsec);
}

static const struct bt_mesh_time_cli_handlers bt_mesh_time_cli_handlers = {
    .time_status = time_status,
};

static struct bt_mesh_time_cli time_cli = BT_MESH_TIME_CLI_INIT(&bt_mesh_time_cli_handlers);

static void set_tai(struct k_work *work){
    printk("set_tai\n");
    int err;

    err = ts_to_tai(&tai, &timeptr);
    if(err){
        printk("ts_to_tai err (%d)", err);
    }

    printk("Tai sec: %"PRId64"\n", tai.sec);
    printk("Tai subsec: %"PRId64"\n", tai.subsec);

    bt_time_status.tai = tai;
    bt_time_status.is_authority = true;

    err = bt_mesh_time_cli_time_set(&time_cli, NULL, &bt_time_status, NULL);
    if(err){
        printk("Error setting server time (%d)\n", err);
    }
    printk("Server time set (%d)\n", err);
}

K_WORK_DEFINE(set_tai_work, set_tai);

/* Set up a repeating delayed work to blink the DK's LEDs when attention is
 * requested.
 */
static struct k_delayed_work attention_blink_work;

static void attention_blink(struct k_work *work){
    static int idx;
    const uint8_t pattern[] = {
	BIT(0) | BIT(1),
	BIT(1) | BIT(2),
	BIT(2) | BIT(3),
	BIT(3) | BIT(0),
    };

    dk_set_leds(pattern[idx++ % ARRAY_SIZE(pattern)]);
    k_delayed_work_submit(&attention_blink_work, K_MSEC(30));
}

static void attention_on(struct bt_mesh_model *mod){
    k_delayed_work_submit(&attention_blink_work, K_NO_WAIT);
}

static void attention_off(struct bt_mesh_model *mod){
    k_delayed_work_cancel(&attention_blink_work);
    dk_set_leds(DK_NO_LEDS_MSK);
}

static const struct bt_mesh_health_srv_cb health_srv_cb = {
    .attn_on = attention_on,
    .attn_off = attention_off,
};

static struct bt_mesh_health_srv health_srv = {
    .cb = &health_srv_cb,
};

BT_MESH_HEALTH_PUB_DEFINE(health_pub, 0);

static struct bt_mesh_elem elements[] = {
    BT_MESH_ELEM(1, BT_MESH_MODEL_LIST(BT_MESH_MODEL_CFG_SRV, BT_MESH_MODEL_HEALTH_SRV(&health_srv, &health_pub), 
                    BT_MESH_MODEL_TIME_CLI(&time_cli)), BT_MESH_MODEL_NONE),
};

static const struct bt_mesh_comp comp = {
    .cid = CONFIG_BT_COMPANY_ID,
    .elem = elements,
    .elem_count = ARRAY_SIZE(elements),
};

static void button_handler_cb(uint32_t pressed, uint32_t changed){
    printk("button_handler_cb\n");
    int err = bt_mesh_time_cli_time_get(&time_cli, NULL, NULL);

    if(err){
      printk("Error time get (%d)\n", err);
    }else{
      printk("Time get ok\n");
    }
    if ((pressed & BIT(0))) {
        k_work_submit(&set_tai_work);
    }
}

static struct button_handler button_handler = {
	.cb = button_handler_cb,
};

const struct bt_mesh_comp *model_handler_init(void){
    k_delayed_work_init(&attention_blink_work, attention_blink);

    dk_button_handler_add(&button_handler);

    return &comp;
}

Time_server:

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

#include <bluetooth/bluetooth.h>
#include <bluetooth/mesh/models.h>
#include <dk_buttons_and_leds.h>
#include "model_handler.h"
#include <sys/util.h>
#include <sys/printk.h>
#include <stdio.h>
#include <inttypes.h>
#include <stdint.h>

static void time_update_cb(struct bt_mesh_time_srv *srv, struct bt_mesh_msg_ctx *ctx, enum bt_mesh_time_update_types type);

static struct bt_mesh_time_srv time_srv = BT_MESH_TIME_SRV_INIT(&time_update_cb);

static void start_led(struct k_timer *dummy);
K_TIMER_DEFINE(my_led_timer, start_led, NULL);

const uint8_t pattern[] = {
	BIT(0) | BIT(1),
	BIT(1) | BIT(2),
	BIT(2) | BIT(3),
	BIT(3) | BIT(0),
};

static int32_t prev_pres;
/* The columns (temperature ranges) for relative
 * runtime in a chip temperature
 */
static const struct bt_mesh_sensor_column columns[] = {
	{ { 0 }, { 20 } },
	{ { 20 }, { 25 } },
	{ { 25 }, { 30 } },
	{ { 30 }, { 100 } },
};

static const struct device *dev;
static uint32_t tot_temp_samps;
static uint32_t col_samps[ARRAY_SIZE(columns)];

static int chip_temp_get(struct bt_mesh_sensor *sensor,struct bt_mesh_msg_ctx *ctx, struct sensor_value *rsp){
    int err;

    sensor_sample_fetch(dev);
    
    err = sensor_channel_get(dev, SENSOR_CHAN_DIE_TEMP, rsp);

    if (err) {
        printk("Error getting temperature sensor data (%d)\n", err);
    }

    for (int i = 0; i < ARRAY_SIZE(columns); ++i) {
        if (bt_mesh_sensor_value_in_column(rsp, &columns[i])) {
            col_samps[i]++;
            break;
        }
    }

    tot_temp_samps++;

    return err;
}

static struct bt_mesh_sensor chip_temp = {
	.type = &bt_mesh_sensor_present_dev_op_temp,
	.get = chip_temp_get,
};

static int relative_runtime_in_chip_temp_get(struct bt_mesh_sensor *sensor, struct bt_mesh_msg_ctx *ctx,const struct bt_mesh_sensor_column *column, struct sensor_value *value){
    if (tot_temp_samps) {
	int32_t index = column - &columns[0];
	uint8_t percent_steps =	(200 * col_samps[index]) / tot_temp_samps;

	value[0].val1 = percent_steps / 2;
	value[0].val2 = (percent_steps % 2) * 500000;
    } else {
	value[0].val1 = 0;
        value[0].val2 = 0;
    }

    value[1] = column->start;
    value[2] = column->end;

    return 0;
}

static struct bt_mesh_sensor rel_chip_temp_runtime = {
    .type = &bt_mesh_sensor_rel_runtime_in_a_dev_op_temp_range,
    .series = {columns,
		ARRAY_SIZE(columns),
		relative_runtime_in_chip_temp_get,
              },
};

static struct bt_mesh_sensor presence_sensor = {
	.type = &bt_mesh_sensor_presence_detected,
};

static int time_since_presence_detected_get(struct bt_mesh_sensor *sensor,struct bt_mesh_msg_ctx *ctx,struct sensor_value *rsp){
    if (prev_pres) {
	rsp->val1 = (k_uptime_get_32() - prev_pres) / MSEC_PER_SEC;
    } else {
	rsp->val1 = 0;
    }

    return 0;
}

static struct bt_mesh_sensor time_since_presence_detected = {
	.type = &bt_mesh_sensor_time_since_presence_detected,
	.get = time_since_presence_detected_get,
};

static struct bt_mesh_sensor *const sensors[] = {
	&chip_temp,
	&rel_chip_temp_runtime,
	&presence_sensor,
	&time_since_presence_detected,
};

static struct bt_mesh_sensor_srv sensor_srv = BT_MESH_SENSOR_SRV_INIT(sensors, ARRAY_SIZE(sensors));

struct k_timer my_led_timer;
static struct k_delayed_work attention_blink_work;

void my_work_handler(struct k_work *work){
    printk("start_led\n");
    int err;

    /* This sensor value must be boolean -
    * .val1 can only be '0' or '1' */
    struct sensor_value val = {
        .val1 = 1,
    };

    err = bt_mesh_sensor_srv_pub(&sensor_srv, NULL,&presence_sensor, &val);

    if (err) {
        printk("Error publishing presence (%d)\n", err);
    }
    //printk("publishing presence\n");
}

K_WORK_DEFINE(my_work, my_work_handler);

static void start_led(struct k_timer *dummy){
    k_work_submit(&my_work);
}

static void time_update_cb(struct bt_mesh_time_srv *srv, struct bt_mesh_msg_ctx *ctx, enum bt_mesh_time_update_types type){
    printk("time_update_cb\n");

    time_srv.data.sync.status.tai = srv->data.sync.status.tai;
    k_delayed_work_submit(&attention_blink_work, K_MSEC(30));


    /*struct tm *today = bt_mesh_time_srv_localtime(&time_srv, k_uptime_get());
    if (!today) {
      return;
    }

    const char *weekdays[] = {
      "Sunday",
      "Monday",
      "Tuesday",
      "Wednesday",
      "Thursday",
      "Friday",
      "Saturday",
    };

    struct tm action = {
      .tm_year = today->tm_year,
      .tm_mon = today->tm_mon,
      .tm_mday = today->tm_mday,
      .tm_hour = today->tm_hour,
      .tm_min = today->tm_min + 1,
      .tm_sec = 59,
    };

    int64_t uptime = bt_mesh_time_srv_mktime(&time_srv, &action);
    struct tm *a = bt_mesh_time_srv_localtime(&time_srv, uptime);

    //printk("tm_year: %d, tm_mon: %d, tm_mday: %d, tm_hour: %d, tm_min: %d, tm_sec: %d\n", a->tm_year, a->tm_mon, a->tm_mday, a->tm_hour, a->tm_min, a->tm_sec);

    int64_t period = uptime - k_uptime_get();
    printk("Period: %"PRId64"\n", period);
    if (uptime < 0) {
      printk("uptime < 0\n");
      return;
    }*/

    k_timer_start(&my_led_timer, K_SECONDS(59), K_NO_WAIT);
}

static void schedule_led(){
    k_timer_start(&my_led_timer, K_SECONDS(59), K_NO_WAIT);
}

static struct k_delayed_work end_of_presence_work;

static void end_of_presence(struct k_work *work){
    int err;

    /* This sensor value must be boolean -
    * .val1 can only be '0' or '1'
    */
    struct sensor_value val = {
	.val1 = 0,
    };

    err = bt_mesh_sensor_srv_pub(&sensor_srv, NULL, &presence_sensor, &val);

    if (err) {
	printk("Error publishing end of presence (%d)\n", err);
    }
}

static void button_handler_cb(uint32_t pressed, uint32_t changed){
    if ((pressed & BIT(0))) {
	int err;

	/* This sensor value must be boolean -
	 * .val1 can only be '0' or '1' */
	struct sensor_value val = {
		.val1 = 1,
	};

	err = bt_mesh_sensor_srv_pub(&sensor_srv, NULL,&presence_sensor, &val);

        err = bt_mesh_time_srv_time_status_send(&time_srv, NULL);

	if (err) {
            printk("Error publishing presence (%d)\n", err);
	}

	prev_pres = k_uptime_get_32();

	k_delayed_work_submit(&end_of_presence_work, K_MSEC(2000));
    }
}

static struct button_handler button_handler = {
	.cb = button_handler_cb,
};

/* Set up a repeating delayed work to blink the DK's LEDs when attention is
 * requested.
 */

static void attention_blink(struct k_work *work){
    static int idx;
  
    dk_set_leds(pattern[idx++ % ARRAY_SIZE(pattern)]);
    k_delayed_work_submit(&attention_blink_work, K_MSEC(30));
}

static void attention_on(struct bt_mesh_model *mod){
    k_delayed_work_submit(&attention_blink_work, K_NO_WAIT);
}

static void attention_off(struct bt_mesh_model *mod){
    k_delayed_work_cancel(&attention_blink_work);
    dk_set_leds(DK_NO_LEDS_MSK);
}

static const struct bt_mesh_health_srv_cb health_srv_cb = {
    .attn_on = attention_on,
    .attn_off = attention_off,
};

static struct bt_mesh_health_srv health_srv = {
    .cb = &health_srv_cb,
};

BT_MESH_HEALTH_PUB_DEFINE(health_pub, 0);

static struct bt_mesh_elem elements[] = {
    BT_MESH_ELEM(1,BT_MESH_MODEL_LIST(BT_MESH_MODEL_CFG_SRV, BT_MESH_MODEL_HEALTH_SRV(&health_srv,&health_pub), BT_MESH_MODEL_SENSOR_SRV(&sensor_srv)),
                    BT_MESH_MODEL_NONE),
    BT_MESH_ELEM(2, BT_MESH_MODEL_LIST(BT_MESH_MODEL_TIME_SRV(&time_srv)),BT_MESH_MODEL_NONE),
};

static const struct bt_mesh_comp comp = {
    .cid = CONFIG_BT_COMPANY_ID,
    .elem = elements,
    .elem_count = ARRAY_SIZE(elements),
};

const struct bt_mesh_comp *model_handler_init(void){
    //SENSOR
    k_delayed_work_init(&attention_blink_work, attention_blink);
    k_delayed_work_init(&end_of_presence_work, end_of_presence);

    dev = device_get_binding(DT_PROP(DT_NODELABEL(temp), label));

    if (dev == NULL) {
         printk("Could not initiate temperature sensor\n");
    } else {
	printk("Temperature sensor (%s) initiated\n", dev->name);
    }

    dk_button_handler_add(&button_handler);

    time_srv.data.sync.status.tai.sec = 677807519;
    time_srv.data.sync.status.tai.subsec = 17716744536;
    time_srv.data.sync.uptime = k_uptime_get();

    //schedule_led();

    return &comp;
}

Additional infos:

- I'm using dongle as time_server and nrf52840dk as client

- Ncs v1.5.1

- Client was configured to publish to all nodes, same server

So if you have any ideas what's wrong/see any bugs in my code or have other sugestions, I'm appreciate them.

[Hung Bui]

Hi Bursz, 

For debugging I would suggest to configure the client to send to the exact server you want to control. Just to check if the packet is received by the server or not. There could be an issue with the all nodes address. 

Please turn on the debug logging or add a breakpoint inside bt_mesh_model_recv() on the time server side . In that function, you can find all the packet coming to access level before it's forwarded to the model. 

On the client's side, you can have a look inside the model_send() function, to check if the packet is getting to the access layer and later down to the transport layer. 

Could you send your projects source so we can test here ? 

[bursztyn12]

Hi,

So I changed the all node address to the specifiic unicast address of that element but it didn't help.

Client's side looks as it should be, I could see that packet was in a transport layer, didin't get any errors or other messages/logs indicating it stucked there.

Regarding server side, here debugging for me is getting a bit tricky, because I don't have any j-link debug device to work with dongle, also if I'm doing everything correctly, dongle itself doesn't work as a client (at least after programming, it doesn't show as a unprovisioned device) so I can't switch roles and use it to generate set messages for DK time server to see what's going on there, and as far as I know nRF Mesh app doesn't fully supports Time model or I'm doing something wrong and there's no set or get activities/handles like for Gen OnnOff to use it as a client.

Yeah sure, here's server 1346.src.zip, and client 0247.src.zip.

[Hung Bui]

Hi Bursztyn, 

Could you give some more info about the server node ? 
Have you provisioned the node ? You mentioned that after programming it doesn't show as a unprovisioned device. 
It actually should show up as an unprovisioned device and you would need to provision it as fas as I know. 

The nRF Mesh app doesn't have specific support for the Time service. That's why you don't see Set or Get button but it should still be able to set the app key, subscription, publication addresses. 

I would suggest to test and make sure the dongle and the DK works as it should with simple model, for example generic on off, after that you can add extra models into the node. 

[bursztyn12]

Ok maybe I didn't explain it well, I'll try again.

1. So for the DK both client and server works fine, there are no problems or anything, same for the dongle but only when I program server examples (I can provisioned it, get/set values from/to it), except time server functionality that I described.

2. This 'I can't see it as a unprovisioned device' problem occurs only when I program the dongle with a client example (I tested this on every available client example with the same result), after all zephyr programming steps, nrfutil says "device programmed', but I can only see that it's flashing both leds but the light itself is very poor/hardly visible, like it would use only 1 pixel, so I don't know if it's a advertising signal or a way to say that something's wrong, basically I have no access to/can't provisioned it when the dongle acts as a client, so I can't switch them, use the dongle to be a time client and send time set message to the time server DK on which I could see the debug logs, and potentialy determine the problem/ where the packet is stuck on server side.

3. To clarify, when time server is set up on the dongle I can provisioned it, and also in Mesh app, set publish address, bind app key, but I'm not getting from it any response to get or set messages.

4. Yes that's correct for time service I can set/change app key, subscription, publication addresses in app, but I was only saying because of that I can't use nRF Mesh app to control DK to check the logs and determine why I'm not getting any status response from time server (as I should to bt_mesh_time_cli_time_set message).

5. As I mentioned in the first and second point, the DK works fine with all examples (server/client gen onoff, switch, sensor), the dongle only with server side (again I tested following srv's gen onoff, switch, sensor, and there are no problems, which would probably indicate that it's my fault that time server doesn't work properly but I can't tell where I made a mistake in setting up this model).

[Hung Bui]

Thanks for the explanation. Do you have any other DK to test with or only have one DK and one Dongle ? 
I would suggest to get hold of an extra DK to test with. Doing development on the dongle is not recommended since it's very hard to debug. 

It  would save you lots of time by develop on DKs and when the firmware ready you can port it to the dongle. 

[bursztyn12]

I mean yes, I have one DK but three dongles, because I had this concept of having an immitation of a "larger" network, do more experiments and I thought if I needed any debbugging, dongles and DK are veristale enough that I could substitute the dongle with DK and check/debug what's going on, but it didin't entirely work that way.

So for now, because even if I order new DK, it would still take aboute 2 weeks for shipment and like you said, I will waste even more time doing nothing, it's still possible that you or other Nordic team member could check out this problem as you mentioned earlier, to even determinate and confirm that e.g mesh time model functionality is one of these that the dongle doesn't support, and if that would be the case, do you know if the dongle doesn't have such problems with custom models?(fully works with them) If I would implement my own basic time model with only tai timestapms, because for now that's all I really need, to get around this issue.

[Hung Bui]

Hi, 

I think getting to be able to debug the dongle is important. 

Please try to test  the following: 

- Turn on logging on the Dongle (you can test on the DK first), and use the log to check if mesh working or not. Please try to test on a working example, check if you can printout the log on access layer as I suggested. It's very important. 

- Try to add the time server to a working example. This way you can at the same time test if you can send some command from the phone app or from the client to control the light switch server for example (check the packet when it arrives in access layer)  then try to send command to the time server (should receive something in the access layer). 

We will try to have a look on your code. 

[bursztyn12]

Sorry for causing unnecessary problem, I overlooked that time setup server handles BT_MESH_TIME_OP_TIME_SET, not time_server, which I took for grantend and didin't initialize properly (key binding e.g) setup_srv, again sorry for bothering and thank you very much for your time and help.

[Hung Bui]

Great, thanks for the info. Glad that it works for you now :)