Hi Trond,

On further testing, it now works.

I must have not properly flashed my board.

Sorry for the noise and thanks for the fix.

Steve

On Tue, 2020-11-03 at 08:21 +0000, Snekvik, Trond wrote:
> Hi,
>
> Looks like this is caused by a discrepancy between what MIC length
> was passed into the encryption function and packet assembly when the
> MIC length is 8 (which just happens in segmented messages).
>
> I have made PR:
> https://eur03.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgithub.com%2Fzephyrproject-rtos%2Fzephyr%2Fpull%2F29739&data=04%7C01%7CTrond.Einar.Snekvik%40nordicsemi.no%7C3e56da8edf5a40e8722908d87fdf281a%7C28e5afa2bf6f419a8cf6b31c6e9e5e8d%7C0%7C0%7C637399944054389517%7CUnknown%7CTWFpbGZsb3d8eyJWIjoiMC4wLjAwMDAiLCJQIjoiV2luMzIiLCJBTiI6Ik1haWwiLCJXVCI6Mn0%3D%7C3000&sdata=9AyTQRjqqyA50x6ElnFbQN1gyOj8c1a5fxGXV4%2FOEOM%3D&reserved=0
>
> Please test it and provide feedback if you can.
>
> Thanks for the detailed bug report!
>
> Trond
>
> From: Steve Brown <sbrown@...>
> Sent: Monday, November 2, 2020 18:13
> To: zephyr-devel@... <
> zephyr-devel@...>
> Cc: Snekvik, Trond <Trond.Einar.Snekvik@...>
> Subject: Bluez' mesh-cfgclient fails to retrieve composition data
> from onoff-app sample
> 
> I bisected this to eca014115
> Bluetooth: Mesh: Isolate cryptographic material
>
> I suspect segmented messages. The successful sequence number starts
> at
> 2 whereas the failing one starts at 1.
>
> I'm not familiar enough with the code to go further than this.
>
> Nothing appears in the meshd debug log with the failing case.
>
> Provisioning succeeds and configuration commands that return
> unsegmented messages, like ttl-get, work.
>
> Steve
>
> FAILING TRACE
> [00:00:44.745,727] <dbg> bt_mesh_access.model_send: net_idx 0x0000
> app_idx 0xfffe dst 0x0001
> [00:00:44.745,758] <dbg> bt_mesh_access.model_send: len 50:
> 0200f105000000000a0003000000050~
> [00:00:44.745,788] <dbg> bt_mesh_transport.bt_mesh_trans_send:
> net_idx 0x0000 app_idx 0xfffe dst 0x0001
> [00:00:44.745,819] <dbg> bt_mesh_transport.bt_mesh_trans_send: len
> 50: 0200f105000000000a0003000000050~
> [00:00:44.745,971] <dbg> bt_mesh_transport.send_seg: src 0x0116 dst
> 0x0001 app_idx 0xfffe aszmic 1 sdu_len 54
> [00:00:44.745,971] <dbg> bt_mesh_transport.send_seg: SeqZero 0x0001
> (segs: 5)
> [00:00:44.746,002] <dbg> bt_mesh_transport.send_seg: seg 0:
> 581b6de7e895153634729e5a
> [00:00:44.746,032] <dbg> bt_mesh_transport.send_seg: seg 1:
> 78298189c7f317ef0d1bf4c0
> [00:00:44.746,032] <dbg> bt_mesh_transport.send_seg: seg 2:
> 3def2b3f3ff14af374b4cda1
> [00:00:44.746,063] <dbg> bt_mesh_transport.send_seg: seg 3:
> ce9fa72cb97cf05f4986433d
> [00:00:44.746,063] <dbg> bt_mesh_transport.send_seg: seg 4:
> b4e6c4dc7c54
> [00:00:44.746,093] <dbg> bt_mesh_transport.seg_tx_send_unacked:
> SeqZero: 0x0001 Attempts: 4
> [00:00:44.746,093] <dbg> bt_mesh_transport.seg_tx_send_unacked:
> Sending 0/4
> [00:00:44.746,124] <dbg> bt_mesh_net.bt_mesh_net_send: src 0x0116 dst
> 0x0001 len 16 headroom 9 tailroom 4
> [00:00:44.746,124] <dbg> bt_mesh_net.bt_mesh_net_send: Payload len
> 16: 80800404581b6de7e895153634729e5~
> [00:00:44.746,124] <dbg> bt_mesh_net.bt_mesh_net_send: Seq 0x000001
> [00:00:44.746,154] <dbg> bt_mesh_net.net_header_encode: src 0x0116
> dst 0x0001 ctl 0 seq 0x000001
> [00:00:44.746,307] <dbg> bt_mesh_transport.seg_tx_send_unacked:
> Sending 1/4
> [00:00:44.746,307] <dbg> bt_mesh_net.bt_mesh_net_send: src 0x0116 dst
> 0x0001 len 16 headroom 9 tailroom 4
> [00:00:44.746,337] <dbg> bt_mesh_net.bt_mesh_net_send: Payload len
> 16: 8080042478298189c7f317ef0d1bf4c~
> [00:00:44.746,337] <dbg> bt_mesh_net.bt_mesh_net_send: Seq 0x000002
> [00:00:44.746,337] <dbg> bt_mesh_net.net_header_encode: src 0x0116
> dst 0x0001 ctl 0 seq 0x000002
> [00:00:44.746,490] <dbg> bt_mesh_transport.seg_tx_send_unacked:
> Sending 2/4
> [00:00:44.746,520] <dbg> bt_mesh_net.bt_mesh_net_send: src 0x0116 dst
> 0x0001 len 16 headroom 9 tailroom 4
> [00:00:44.746,520] <dbg> bt_mesh_net.bt_mesh_net_send: Payload len
> 16: 808004443def2b3f3ff14af374b4cda~
> [00:00:44.746,551] <dbg> bt_mesh_net.bt_mesh_net_send: Seq 0x000003
> [00:00:44.746,551] <dbg> bt_mesh_net.net_header_encode: src 0x0116
> dst 0x0001 ctl 0 seq 0x000003
> [00:00:44.746,704] <dbg> bt_mesh_transport.seg_tx_send_unacked:
> Sending 3/4
> [00:00:44.746,704] <dbg> bt_mesh_net.bt_mesh_net_send: src 0x0116 dst
> 0x0001 len 16 headroom 9 tailroom 4
> [00:00:44.746,734] <dbg> bt_mesh_net.bt_mesh_net_send: Payload len
> 16: 80800464ce9fa72cb97cf05f4986433~
> [00:00:44.746,734] <dbg> bt_mesh_net.bt_mesh_net_send: Seq 0x000004
> [00:00:44.746,765] <dbg> bt_mesh_net.net_header_encode: src 0x0116
> dst 0x0001 ctl 0 seq 0x000004
> [00:00:44.746,917] <dbg> bt_mesh_transport.seg_tx_send_unacked:
> Sending 4/4
> [00:00:44.746,917] <dbg> bt_mesh_net.bt_mesh_net_send: src 0x0116 dst
> 0x0001 len 10 headroom 9 tailroom 10
> [00:00:44.746,917] <dbg> bt_mesh_net.bt_mesh_net_send: Payload len
> 10: <log_strdup alloc failed>
> [00:00:44.746,917] <dbg> bt_mesh_net.bt_mesh_net_send: Seq 0x000005
> [00:00:44.746,948] <dbg> bt_mesh_net.net_header_encode: src 0x0116
> dst 0x0001 ctl 0 seq 0x000005
>
> SUCCESS
> [00:00:50.364,929] <dbg> bt_mesh_cfg_srv.dev_comp_data_get: net_idx
> 0x0000 app_idx 0xfffe src 0x0001 len 1: 00
> [00:00:50.364,959] <dbg> bt_mesh_access.model_send: net_idx 0x0000
> app_idx 0xfffe dst 0x0001
> [00:00:50.364,990] <dbg> bt_mesh_access.model_send: len 50:
> 0200f105000000000a0003000000050~
> [00:00:50.364,990] <dbg> bt_mesh_transport.bt_mesh_trans_send:
> net_idx 0x0000 app_idx 0xfffe dst 0x0001
> [00:00:50.365,051] <dbg> bt_mesh_transport.bt_mesh_trans_send: len
> 50: 0200f105000000000a0003000000050~
> [00:00:50.365,203] <dbg> bt_mesh_transport.send_seg: src 0x011a dst
> 0x0001 app_idx 0xfffe aszmic 1 sdu_len 58
> [00:00:50.365,203] <dbg> bt_mesh_transport.send_seg: SeqZero 0x0002
> (segs: 5)
> [00:00:50.365,234] <dbg> bt_mesh_transport.send_seg: seg 0:
> 0c0139ab229a128ab4d9da66
> [00:00:50.365,264] <dbg> bt_mesh_transport.send_seg: seg 1:
> 7911abbd986ab5cc2ba3a7fd
> [00:00:50.365,264] <dbg> bt_mesh_transport.send_seg: seg 2:
> b9460beeec1aca3c73012043
> [00:00:50.365,295] <dbg> bt_mesh_transport.send_seg: seg 3:
> 254d22b179271b62687efbed
> [00:00:50.365,325] <dbg> bt_mesh_transport.send_seg: seg 4:
> 6c7b29d675eb290476cd
> [00:00:50.365,325] <dbg> bt_mesh_transport.seg_tx_send_unacked:
> SeqZero: 0x0002 Attempts: 4
> [00:00:50.365,325] <dbg> bt_mesh_transport.seg_tx_send_unacked:
> Sending 0/4
> [00:00:50.365,356] <dbg> bt_mesh_net.bt_mesh_net_send: src 0x011a dst
> 0x0001 len 16 headroom 9 tailroom 4
> [00:00:50.365,356] <dbg> bt_mesh_net.bt_mesh_net_send: Payload len
> 16: 808008040c0139ab229a128ab4d9da6~
> [00:00:50.365,386] <dbg> bt_mesh_net.bt_mesh_net_send: Seq 0x000002
> [00:00:50.365,386] <dbg> bt_mesh_net.net_header_encode: src 0x011a
> dst 0x0001 ctl 0 seq 0x000002
> [00:00:50.365,539] <dbg> bt_mesh_transport.seg_tx_send_unacked:
> Sending 1/4
> [00:00:50.365,539] <dbg> bt_mesh_net.bt_mesh_net_send: src 0x011a dst
> 0x0001 len 16 headroom 9 tailroom 4
> [00:00:50.365,570] <dbg> bt_mesh_net.bt_mesh_net_send: Payload len
> 16: 808008247911abbd986ab5cc2ba3a7f~
> [00:00:50.365,570] <dbg> bt_mesh_net.bt_mesh_net_send: Seq 0x000003
> [00:00:50.365,600] <dbg> bt_mesh_net.net_header_encode: src 0x011a
> dst 0x0001 ctl 0 seq 0x000003
> [00:00:50.365,722] <dbg> bt_mesh_transport.seg_tx_send_unacked:
> Sending 2/4
> [00:00:50.365,753] <dbg> bt_mesh_net.bt_mesh_net_send: src 0x011a dst
> 0x0001 len 16 headroom 9 tailroom 4
> [00:00:50.365,783] <dbg> bt_mesh_net.bt_mesh_net_send: Payload len
> 16: 80800844b9460beeec1aca3c7301204~
> [00:00:50.365,783] <dbg> bt_mesh_net.bt_mesh_net_send: Seq 0x000004
> [00:00:50.365,783] <dbg> bt_mesh_net.net_header_encode: src 0x011a
> dst 0x0001 ctl 0 seq 0x000004
> [00:00:50.365,936] <dbg> bt_mesh_transport.seg_tx_send_unacked:
> Sending 3/4
> [00:00:50.365,936] <dbg> bt_mesh_net.bt_mesh_net_send: src 0x011a dst
> 0x0001 len 16 headroom 9 tailroom 4
> [00:00:50.365,966] <dbg> bt_mesh_net.bt_mesh_net_send: Payload len
> 16: <log_strdup alloc failed>
> [00:00:50.365,966] <dbg> bt_mesh_net.bt_mesh_net_send: Seq 0x000005
> [00:00:50.365,966] <dbg> bt_mesh_net.net_header_encode: src 0x011a
> dst 0x0001 ctl 0 seq 0x000005
> [00:00:50.366,119] <dbg> bt_mesh_transport.seg_tx_send_unacked:
> Sending 4/4
> [00:00:50.366,149] <dbg> bt_mesh_net.bt_mesh_net_send: src 0x011a dst
> 0x0001 len 14 headroom 9 tailroom 6
> [00:00:50.366,149] <dbg> bt_mesh_net.bt_mesh_net_send: Payload len
> 14: <log_strdup alloc failed>
> [00:00:50.366,149] <dbg> bt_mesh_net.bt_mesh_net_send: Seq 0x000006
> [00:00:50.366,149] <dbg> bt_mesh_net.net_header_encode: src 0x011a
> dst 0x0001 ctl 0 seq 0x000006
>
>