Mesh shell errors enabling publication on a custom model

[AndyM]

Hello 

I added the mesh shell module to my app running on nRF52480 custom board and I am trying to provision and enable publication on the custom model I have

This produces multiple errors. See session log below. Any suggestions? Some of the errors are probably related to the memory allocation to various mesh/bt stack buffers -I can provide the proj.conf  if needed. 

Another question - is the health client really needed? From what I can tell it just provides info about the faults - is it required?

Note

I know my custom model works - I can provision it with nRF Mesh app and configure publish parameters

I need to be able to do the same via the mesh shell

Thanks
-----------------------------------------

mesh init
Mesh shell initialized

mesh provision 0 0x123

mesh dst 

Destination address: 0x0000 (local) <--I expected it to be 0x123 that I used in provision

In general this dst parameter is confusing . What does it represent? The node address? If so - it should be set during provisioning, no?

mesh get-comp -error -116 (ETIMEDOUT)
Debug output:
[00:01:20.006,103] <dbg> bt_mesh_net: bt_mesh_net_send: Seq 0x000002
[00:01:20.006,103] <dbg> bt_mesh_net: net_header_encode: src 0x0123 dst 0x0123 ctl 0 seq 0x000002
[00:01:20.006,164] <dbg> bt_mesh_net: bt_mesh_net_send: src 0x0123 dst 0x0123 len 16 headroom 9 tailroom 4
[00:01:20.006,225] <dbg> bt_mesh_net: bt_mesh_net_send: Payload len 16: 80800443a2c4dccbf6fe4f0a46d7c07f
[00:01:20.006,225] <dbg> bt_mesh_net: bt_mesh_net_send: Seq 0x000003
[00:01:20.006,256] <dbg> bt_mesh_net: net_header_encode: src 0x0123 dst 0x0123 ctl 0 seq 0x000003
[00:01:20.006,256] <wrn> bt_mesh_net: Unable to allocate loopback
[00:01:20.006,286] <dbg> bt_mesh_net: bt_mesh_net_local: src: 0x0123 dst: 0x0123 seq 0x000001 sub 0x20000980
[00:01:20.006,317] <err> bt_mesh_transport: Too big incoming SDU length
[00:01:20.006,347] <dbg> bt_mesh_net: bt_mesh_net_send: src 0x0123 dst 0x0123 len 7 headroom 9 tailroom 13
[00:01:20.006,408] <dbg> bt_mesh_net: bt_mesh_net_send: Payload len 7: 00000400000000
[00:01:20.006,408] <dbg> bt_mesh_net: bt_mesh_net_send: Seq 0x000004
[00:01:20.006,439] <dbg> bt_mesh_net: net_header_encode: src 0x0123 dst 0x0123 ctl 1 seq 0x000004
[00:01:20.006,469] <dbg> bt_mesh_net: bt_mesh_net_local: src: 0x0123 dst: 0x0123 seq 0x000002 sub 0x20000980
[00:01:20.006,500] <err> bt_mesh_transport: Too big incoming SDU length
[00:01:20.006,530] <dbg> bt_mesh_net: bt_mesh_net_send: src 0x0123 dst 0x0123 len 7 headroom 9 tailroom 13
[00:01:20.006,561] <dbg> bt_mesh_net: bt_mesh_net_send: Payload len 7: 00000400000000
[00:01:20.006,591] <dbg> bt_mesh_net: bt_mesh_net_send: Seq 0x000005
[00:01:20.006,591] <dbg> bt_mesh_net: net_header_encode: src 0x0123 dst 0x0123 ctl 1 seq 0x000005
[00:01:20.006,652] <dbg> bt_mesh_net: bt_mesh_net_local: src: 0x0123 dst: 0x0123 seq 0x000004 sub 0x20000980
[00:01:20.006,652] <wrn> bt_mesh_transport: SDU canceled
[00:01:20.006,683] <dbg> bt_mesh_net: bt_mesh_net_local: src: 0x0123 dst: 0x0123 seq 0x000005 sub 0x20000980
[00:01:20.006,713] <wrn> bt_mesh_transport: No matching TX context for ack

NOTE. I get this error only when I set mesh dst to a value other than 0x0001.

mesh net-key-add 0 2870A43ADE4745D5F471CE29E6FFC0F2

NetKeyAdd failed with status 0x06 <--- where is this defined??
Debug output:
[00:04:11.208,740] <dbg> bt_mesh_net: bt_mesh_net_send: Payload len 16: 80002801468f989757e9afc82db6b474
--- 1 messages dropped ---
[00:04:11.208,770] <dbg> bt_mesh_net: bt_mesh_net_send: Seq 0x00000a
[00:04:11.208,770] <dbg> bt_mesh_net: net_header_encode: src 0x0123 dst 0x0123 ctl 0 seq 0x00000a
[00:04:11.208,831] <dbg> bt_mesh_net: bt_mesh_net_local: src: 0x0123 dst: 0x0123 seq 0x00000a sub 0x20000980
[00:04:11.208,923] <dbg> bt_mesh_net: bt_mesh_net_send: src 0x0123 dst 0x0123 len 16 headroom 9 tailroom 4
[00:04:11.208,953] <dbg> bt_mesh_net: bt_mesh_net_send: Payload len 16: 80002821c71db5939fa6c66af0798203
[00:04:11.208,984] <dbg> bt_mesh_net: bt_mesh_net_send: Seq 0x00000b
[00:04:11.208,984] <dbg> bt_mesh_net: net_header_encode: src 0x0123 dst 0x0123 ctl 0 seq 0x00000b
[00:04:11.209,045] <dbg> bt_mesh_net: bt_mesh_net_local: src: 0x0123 dst: 0x0123 seq 0x00000b sub 0x20000980
[00:04:11.209,106] <dbg> bt_mesh_net: bt_mesh_net_send: src 0x0123 dst 0x0123 len 7 headroom 9 tailroom 13
[00:04:11.209,136] <dbg> bt_mesh_net: bt_mesh_net_send: Payload len 7: 00002800000003
[00:04:11.209,167] <dbg> bt_mesh_net: bt_mesh_net_send: Seq 0x00000c
[00:04:11.209,167] <dbg> bt_mesh_net: net_header_encode: src 0x0123 dst 0x0123 ctl 1 seq 0x00000c
[00:04:11.209,320] <dbg> bt_mesh_cfg_srv: net_key_add: idx 0x0000
[00:04:11.209,320] <dbg> bt_mesh_net_keys: bt_mesh_subnet_add: 0x000
[00:04:11.209,411] <dbg> bt_mesh_net: bt_mesh_net_send: src 0x0123 dst 0x0123 len 10 headroom 9 tailroom 10
[00:04:11.209,472] <dbg> bt_mesh_net: bt_mesh_net_send: Payload len 10: 006545f5ee661b34c1c2
[00:04:11.209,472] <dbg> bt_mesh_net: bt_mesh_net_send: Seq 0x00000d
[00:04:11.209,472] <dbg> bt_mesh_net: net_header_encode: src 0x0123 dst 0x0123 ctl 0 seq 0x00000d
[00:04:11.209,533] <dbg> bt_mesh_net: bt_mesh_net_local: src: 0x0123 dst: 0x0123 seq 0x00000c sub 0x20000980
[00:04:11.209,564] <dbg> bt_mesh_net: bt_mesh_net_local: src: 0x0123 dst: 0x0123 seq 0x00000d sub 0x20000980
[00:04:11.209,716] <dbg> bt_mesh_cfg_cli: net_key_status: net_idx 0x0000 app_idx 0xfffe src 0x0123 len 3:

I can do mesh net-key-upd without errors

mesh app-key-add 0 0 522975C06BCADCBBF4A402DF2F895226
AppKey added, NetKeyIndex 0x0000 AppKeyIndex 0x0000

mesh app-key-get 0
Unable to send AppKeyGet (err -116)
[00:08:22.455,139] <dbg> bt_mesh_net: bt_mesh_net_send: src 0x0123 dst 0x0123 len 9 headroom 9 tailroom 11
[00:08:22.455,169] <dbg> bt_mesh_net: bt_mesh_net_send: Payload len 9: 00e81169afbfecbebb
[00:08:22.455,200] <dbg> bt_mesh_net: bt_mesh_net_send: Seq 0x00001a
[00:08:22.455,200] <dbg> bt_mesh_net: net_header_encode: src 0x0123 dst 0x0123 ctl 0 seq 0x00001a
[00:08:22.455,261] <dbg> bt_mesh_net: bt_mesh_net_local: src: 0x0123 dst: 0x0123 seq 0x00001a sub 0x20000980
[00:08:22.455,322] <dbg> bt_mesh_cfg_srv: app_key_get: idx 0x0000
[00:08:22.455,413] <dbg> bt_mesh_net: bt_mesh_net_send: src 0x0123 dst 0x0123 len 12 headroom 9 tailroom 8
[00:08:22.455,474] <dbg> bt_mesh_net: bt_mesh_net_send: Payload len 12: 002841cedf6f494a30412ffe
[00:08:22.455,474] <dbg> bt_mesh_net: bt_mesh_net_send: Seq 0x00001b
[00:08:22.455,505] <dbg> bt_mesh_net: net_header_encode: src 0x0123 dst 0x0123 ctl 0 seq 0x00001b
[00:08:22.455,535] <dbg> bt_mesh_net: bt_mesh_net_local: src: 0x0123 dst: 0x0123 seq 0x00001b sub 0x20000980
[00:08:22.455,688] <dbg> bt_mesh_cfg_cli: app_key_list: net_idx 0x0000 app_idx 0xfffe src 0x0123 len 5: 0000000000
[00:08:22.455,718] <err> bt_mesh_cfg_cli: The message size for the application opcode is incorrect.

mesh mod-app-bind 0x123 0 0x1002 0x0059
AppKey successfully bound

$ mesh mod-pub 0x123 0x1002 0x0059 0xFFFF 0 0 5 72 2 200
Model Publication Set failed (err -116)

[00:14:41.373,016] <dbg> bt_mesh_net: bt_mesh_net_send: Seq 0x00001e
--- 3 messages dropped ---
[00:14:41.373,046] <dbg> bt_mesh_net: net_header_encode: src 0x0123 dst 0x0123 ctl 0 seq 0x00001e
[00:14:41.373,077] <dbg> bt_mesh_net: bt_mesh_net_local: src: 0x0123 dst: 0x0123 seq 0x00001e sub 0x20000980
[00:14:41.373,168] <dbg> bt_mesh_net: bt_mesh_net_send: src 0x0123 dst 0x0123 len 16 headroom 9 tailroom 4
[00:14:41.373,229] <dbg> bt_mesh_net: bt_mesh_net_send: Payload len 16: 800078220f280ba70aa05e6e2cd2e77d
[00:14:41.373,229] <dbg> bt_mesh_net: bt_mesh_net_send: Seq 0x00001f
[00:14:41.373,260] <dbg> bt_mesh_net: net_header_encode: src 0x0123 dst 0x0123 ctl 0 seq 0x00001f
[00:14:41.373,291] <dbg> bt_mesh_net: bt_mesh_net_local: src: 0x0123 dst: 0x0123 seq 0x00001f sub 0x20000980
[00:14:41.373,382] <dbg> bt_mesh_net: bt_mesh_net_send: src 0x0123 dst 0x0123 len 13 headroom 9 tailroom 7
[00:14:41.373,443] <dbg> bt_mesh_net: bt_mesh_net_send: Payload len 13: 800078426b8ea9bfb6f2f80b01
[00:14:41.373,443] <dbg> bt_mesh_net: bt_mesh_net_send: Seq 0x000020
[00:14:41.373,474] <dbg> bt_mesh_net: net_header_encode: src 0x0123 dst 0x0123 ctl 0 seq 0x000020
[00:14:41.373,504] <dbg> bt_mesh_net: bt_mesh_net_local: src: 0x0123 dst: 0x0123 seq 0x000020 sub 0x20000980
[00:14:41.373,565] <dbg> bt_mesh_net: bt_mesh_net_send: src 0x0123 dst 0x0123 len 7 headroom 9 tailroom 13
[00:14:41.373,596] <dbg> bt_mesh_net: bt_mesh_net_send: Payload len 7: 00007800000007
[00:14:41.373,626] <dbg> bt_mesh_net: bt_mesh_net_send: Seq 0x000021
[00:14:41.373,626] <dbg> bt_mesh_net: net_header_encode: src 0x0123 dst 0x0123 ctl 1 seq 0x000021
[00:14:41.373,779] <dbg> bt_mesh_cfg_srv: mod_pub_va_set: elem_addr 0x0123 cred_flag 0
[00:14:41.373,779] <dbg> bt_mesh_cfg_srv: mod_pub_va_set: pub_app_idx 0x000, pub_ttl 5 pub_period 0x48
[00:14:41.373,809] <dbg> bt_mesh_cfg_srv: mod_pub_va_set: retransmit 0x1a (count 2 interval 200ms)
[00:14:41.373,809] <dbg> bt_mesh_cfg_srv: get_model: Company 0x0059 ID 0x1002 addr 0x0123
[00:14:41.374,908] <err> bt_mesh_transport: No multi-segment message contexts available
[00:14:41.374,938] <err> bt_mesh_cfg_srv: Unable to send Model Publication Status
[00:14:41.374,969] <dbg> bt_mesh_net: bt_mesh_net_local: src: 0x0123 dst: 0x0123 seq 0x000021 sub 0x20000980

[AndyM]

Update

I can now successfully provision and enable publication on a SIG  battery model ( battery server ) and see it publishing in the RTT log

1 .issue remain

1. Enabling publication on a custom model fails with status 0x07 E2BG - any ideas there?

I enabled all the logging I could think of - no errors reported.

Any ideas?
Thanks

[AndyM]

Update2

A problem provisioning a SIG model (battery server)

Here is the sequence I use

uart:~$ mesh provision 0 0x0001
uart:~$ mesh dst 0x0001
Destination address set to 0x0001

uart:~$ mesh get-comp
Got Composition Data for 0x0001:
CID 0x0a0a
PID 0x0000
VID 0x0000
CRPL 0x000a
Features 0x0007
Element @ 0x0001:
SIG Models:
0x0000
0x0002
0x100c
0x0001
Vendor Models:
Company 0x0059: 0x1002

uart:~$ mesh net-key-upd 0 2870A43ADE4745D5F471CE29E6FFC0F2
NetKey updated with NetKey Index 0x000
uart:~$ mesh app-key-add 0 0 522975C06BCADCBBF4A402DF2F895226
AppKey added, NetKeyIndex 0x0000 AppKeyIndex 0x0000
uart:~$ mesh mod-app-bind 0x0001 0 0x100c
AppKey successfully bound
uart:~$ mesh mod-pub 0x0001 0x100c 0xFFFF 0 0 5 74 2 200
Model Publication successfully set
uart:~$ mesh mod-pub 0x0001 0x100c
Model Publication for Element 0x0001, Model 0x100c:
Publish Address: 0x9751
AppKeyIndex: 0x0000
Credential Flag: 0
PublishTTL: 5
PublishPeriod: 0x4a
PublishRetransmitCount: 2
PublishRetransmitInterval: 200ms
uart:~$

Why the publish address is 0x9751?

The composition data is as follows

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_BATTERY_SRV(&_batt_ctx.srv),          

            BT_MESH_MODEL_CFG_CLI(&_config_client))

            ),                          

            vnd_models),        

};

And I still cannot enable publication on the custom model - status 0x07

[AndyM]

Update3

There are bugs in the mesh shell function 

1. When mod_pub_set() function is called from  cmd_mod_pub the is_va parameter is set to false

In mod_pub_se()t the uuid field of bt_mesh_cfg_mod_pub structure is left uninitialized if is_va is false.

Later in bt_mesh_cfg_mod_pub_set() function the pub->uuid field is examined and if it's not NULL mod_pub_va_set function is called 

Solution: memset the cmd_mod_pub  to clear all fields

2. cmd_mod_pub  period field is not encoded  with the BT_MESH_PUB_PERIOD_SEC macro

I modified the shell.c  in subsys/bluetooth/mesh/ an now I don't see the issue with the address described in update2. It is set to the value specified in the command parameters.

The problem with the custom model (status 0x07) still remains. 

[Mttrinh]

Hi, 

The team will take a look at this, I will come back to you when I have an update.

Can you provide which version of the SDK you are using?

[AndyM]

1.9.1