Trying to understand the Bytes of a message sent, during a connection.

[Higo]

Hi dear, I'm make the tests with send and receive informations using the code base mesh.
I need help to better understand the transport of this data

---

Initially I set my BUF to 26 Bytes, with OP_ONOFF_SET_UNACK
BT_MESH_MODEL_BUF_DEFINE(buf, OP_ONOFF_SET_UNACK, 26);

I'm using the net_buf_simple_add_u8() method 26 times to add 26 Bytes in the buf

static uint8_t tid;
bool var = val_led;
net_buf_simple_add_u8(&buf, tid++);
net_buf_simple_add_u8(&buf, val_led);

for (i = 0; i < 24; i++) {
  uint8_t new_byte = 1;
  net_buf_simple_add_u8( &buf, new_byte);
}

I'm sending the buf with bt_mesh_model_send method
bt_mesh_model_send(&models[3], &ctx, &buf, NULL, NULL);

I can receive every bytes if net_buf_simple_pull_u8()

unt8_t tid = net_buf_simple_pull_u8(buf);
uint8_t val = net_buf_simple_pull_u8(buf);
for (i = 0; i < 24; i++) {
  uint8_t new_byte = net_buf_simple_pull_u8(buf);
  printk("\n%zu bytes : Value: %d", sizeof(new_byte), new_byte);
}

I print the buf before sending and after receiving in the bt_mesh_access.c file
I realized that the length of buf when I send is every 2 Bytes lager than the buf when I receive.

My Log, When I send 26 Bytes
[00:00:03.138,336] <dbg> bt_mesh_access: bt_mesh_access_send: --> Tx (len 28) (siz 32): 82030001010101010101010101010101010101010101010101010101
[00:00:50.232,147] <dbg> bt_mesh_access: bt_mesh_model_recv: --> Tx (len 26) (siz 28): 0100010101010101010101010101010101010101010101010101

My Log, When I send 2 Bytes
[00:00:43.658,538] <dbg> bt_mesh_access: bt_mesh_access_send: --> Tx (len 4) (siz 32): 82030001
[00:00:48.075,256] <dbg> bt_mesh_access: bt_mesh_model_recv: --> Tx (len 2) (siz 11): 0001

System Log, When I send 2 Bytes
SEND
[00:00:28.784,790] <dbg> bt_mesh_transport_legacy: bt_mesh_trans_recv: src 0x5bf0 dst 0xffff seq 0x00000004 friend_match 0
[00:00:28.784,820] <dbg> bt_mesh_transport_legacy: bt_mesh_trans_recv: Payload 7883531e2dcf6c5067
[00:00:28.784,851] <dbg> bt_mesh_transport_legacy: trans_unseg: AFK 1 AID 0x38

RECEIVE
[00:00:25.634,307] <dbg> bt_mesh_transport_legacy: sdu_recv: AKF 1 AID 0x38
[00:00:25.634,460] <dbg> bt_mesh_transport_legacy: sdu_recv: Decrypted (AppIdx: 0x000)
[00:00:25.634,490] <dbg> bt_mesh_access: bt_mesh_model_recv: app_idx 0x0000 src 0x5bf0 dst 0xffff
[00:00:25.634,521] <dbg> bt_mesh_access: bt_mesh_model_recv: len 4: 82030401

1.1) Are these 2 Bytes that I mentioned previously the header? What would they be headers? Is it the PDU header? Should the MIC bytes not appear?

1.2) What would this Payload be?
[00:00:28.784,820] <dbg> bt_mesh_transport_legacy: bt_mesh_trans_recv: Payload 7883531e2dcf6c5067

---

From what I read here, in the link below
academy.nordicsemi.com/.../
"MTU has a default value of 23 bytes, and data length has a default value of 27 bytes." -> Bluetooth 4.2
"Data Length Extension (DLE) was introduced to allow the data length to be increased from the default 27 bytes to up to 251 bytes"

2) Is there any method I can use to know if the "data length" is set to 27 bytes or 251 bytes?

--------------------

3)

When I increased it to 10 Bytes, I noticed that in the logs of the transport_legacy.c file, different messages started to appear,
I would like to understand some messages.

3.1) Does this log mean that the message was broken into 2 parts?
[00:04:28.040,252] <dbg> bt_mesh_transport_legacy: send_seg: SeqZero 0x0028 (segs: 2)

3.2) Does this log mean that the first part is being sent?
[00:04:28.040,405] <dbg> bt_mesh_transport_legacy: seg_tx_send_unacked: Sending 0/1

3.3) what content is this?
[00:04:28.040,283] <dbg> bt_mesh_transport_legacy: send_seg: seg 0: 87df25f0ff7f237ea4c8770e
[00:04:28.040,344] <dbg> bt_mesh_transport_legacy: send_seg: seg 1: 9ac0f04d47e48947

3.4) What would this account be? result 20
[00:04:28.105,285] <dbg> bt_mesh_transport_legacy: trans_seg: Target len 1 * 12 + 8 = 20

Complete log of the Node you sent (Mesh)

[00:04:28.040,069] <dbg> bt_mesh_transport_legacy: bt_mesh_trans_send: net_idx 0x0000 app_idx 0x0000 dst 0xffff
[00:04:28.040,100] <dbg> bt_mesh_transport_legacy: bt_mesh_trans_send: len 12: 820308010101010101010101
[00:04:28.040,222] <dbg> bt_mesh_transport_legacy: send_seg: src 0x5bf0 dst 0xffff app_idx 0x0000 aszmic 1 sdu_len 20
[00:04:28.040,252] <dbg> bt_mesh_transport_legacy: send_seg: SeqZero 0x0028 (segs: 2)
[00:04:28.040,283] <dbg> bt_mesh_transport_legacy: send_seg: seg 0: 87df25f0ff7f237ea4c8770e
[00:04:28.040,344] <dbg> bt_mesh_transport_legacy: send_seg: seg 1: 9ac0f04d47e48947
[00:04:28.040,374] <dbg> bt_mesh_transport_legacy: seg_tx_send_unacked: SeqZero: 0x0028 Attempts: 4
[00:04:28.040,405] <dbg> bt_mesh_transport_legacy: seg_tx_send_unacked: Sending 0/1
[00:04:28.040,649] <dbg> bt_mesh_transport_legacy: bt_mesh_trans_recv: src 0x5bf0 dst 0xffff seq 0x00000028 friend_match 0
[00:04:28.040,679] <dbg> bt_mesh_transport_legacy: bt_mesh_trans_recv: Payload f880a00187df25f0ff7f237ea4c8770e
[00:04:28.040,710] <dbg> bt_mesh_transport_legacy: trans_seg: ASZMIC 1 AKF 1 AID 0x38
[00:04:28.040,710] <dbg> bt_mesh_transport_legacy: trans_seg: SeqZero 0x0028 SegO 0 SegN 1
[00:04:28.040,740] <dbg> bt_mesh_transport_legacy: seg_rx_alloc: New RX context. Block Complete 0x00000003
[00:04:28.040,771] <dbg> bt_mesh_transport_legacy: trans_seg: Received 0/1
[00:04:28.104,797] <dbg> bt_mesh_transport_legacy: schedule_retransmit:
[00:04:28.104,919] <dbg> bt_mesh_transport_legacy: seg_tx_send_unacked: SeqZero: 0x0028 Attempts: 4
[00:04:28.105,010] <dbg> bt_mesh_transport_legacy: seg_tx_send_unacked: Sending 1/1
[00:04:28.105,163] <dbg> bt_mesh_transport_legacy: bt_mesh_trans_recv: src 0x5bf0 dst 0xffff seq 0x00000029 friend_match 0
[00:04:28.105,224] <dbg> bt_mesh_transport_legacy: bt_mesh_trans_recv: Payload f880a0219ac0f04d47e48947
[00:04:28.105,224] <dbg> bt_mesh_transport_legacy: trans_seg: ASZMIC 1 AKF 1 AID 0x38
[00:04:28.105,255] <dbg> bt_mesh_transport_legacy: trans_seg: SeqZero 0x0028 SegO 1 SegN 1
[00:04:28.105,255] <dbg> bt_mesh_transport_legacy: trans_seg: Existing RX context. Block 0x00000001
[00:04:28.105,285] <dbg> bt_mesh_transport_legacy: trans_seg: Target len 1 * 12 + 8 = 20
[00:04:28.105,316] <dbg> bt_mesh_transport_legacy: trans_seg: Received 1/1
[00:04:28.105,316] <dbg> bt_mesh_transport_legacy: trans_seg: Complete SDU
[00:04:28.105,346] <dbg> bt_mesh_transport_legacy: send_ack: SeqZero 0x0028 Block 0x00000003 OBO 0
[00:04:28.105,346] <dbg> bt_mesh_transport_legacy: send_ack: Not sending ack for non-unicast address
[00:04:28.105,377] <dbg> bt_mesh_transport_legacy: sdu_recv: AKF 1 AID 0x38
[00:04:28.105,468] <dbg> bt_mesh_transport_legacy: sdu_recv: Decrypted (AppIdx: 0x000)
[00:04:28.105,499] <dbg> bt_mesh_access: bt_mesh_model_recv: app_idx 0x0000 src 0x5bf0 dst 0xffff
[00:04:28.105,529] <dbg> bt_mesh_access: bt_mesh_model_recv: len 12: 820308010101010101010101
[00:04:28.105,560] <dbg> bt_mesh_access: bt_mesh_model_recv: OpCode 0x00008203
[00:04:28.105,590] <err> bt_mesh_access: No OpCode 0x00008203 for elem 0x5bf0
[00:04:28.105,621] <dbg> bt_mesh_access: bt_mesh_model_recv: --> Tx (len 10) (siz 12): 08010101010101010101
[00:04:28.105,651] <dbg> bt_mesh_transport_legacy: seg_rx_reset: rx 0x200053c0
[00:04:28.187,225] <dbg> bt_mesh_transport_legacy: schedule_retransmit:
[00:04:28.187,316] <dbg> bt_mesh_transport_legacy: seg_tx_send_unacked: SeqZero: 0x0028 Attempts: 4
[00:04:28.237,457] <dbg> bt_mesh_transport_legacy: seg_tx_send_unacked: SeqZero: 0x0028 Attempts: 3
[00:04:28.237,487] <dbg> bt_mesh_transport_legacy: seg_tx_send_unacked: Sending 0/1
[00:04:28.237,701] <dbg> bt_mesh_transport_legacy: bt_mesh_trans_recv: src 0x5bf0 dst 0xffff seq 0x0000002a friend_match 0
[00:04:28.237,762] <dbg> bt_mesh_transport_legacy: bt_mesh_trans_recv: Payload f880a00187df25f0ff7f237ea4c8770e
[00:04:28.237,762] <dbg> bt_mesh_transport_legacy: trans_seg: ASZMIC 1 AKF 1 AID 0x38
[00:04:28.237,792] <dbg> bt_mesh_transport_legacy: trans_seg: SeqZero 0x0028 SegO 0 SegN 1
[00:04:28.237,792] <dbg> bt_mesh_transport_legacy: trans_seg: Got segment for already complete SDU
[00:04:28.237,823] <dbg> bt_mesh_transport_legacy: send_ack: SeqZero 0x0028 Block 0x00000003 OBO 0
[00:04:28.237,823] <dbg> bt_mesh_transport_legacy: send_ack: Not sending ack for non-unicast address
[00:04:28.297,821] <dbg> bt_mesh_transport_legacy: schedule_retransmit:
[00:04:28.297,912] <dbg> bt_mesh_transport_legacy: seg_tx_send_unacked: SeqZero: 0x0028 Attempts: 3
[00:04:28.298,004] <dbg> bt_mesh_transport_legacy: seg_tx_send_unacked: Sending 1/1
[00:04:28.298,187] <dbg> bt_mesh_transport_legacy: bt_mesh_trans_recv: src 0x5bf0 dst 0xffff seq 0x0000002b friend_match 0
[00:04:28.298,217] <dbg> bt_mesh_transport_legacy: bt_mesh_trans_recv: Payload f880a0219ac0f04d47e48947
[00:04:28.298,248] <dbg> bt_mesh_transport_legacy: trans_seg: ASZMIC 1 AKF 1 AID 0x38
[00:04:28.298,248] <dbg> bt_mesh_transport_legacy: trans_seg: SeqZero 0x0028 SegO 1 SegN 1
[00:04:28.298,278] <dbg> bt_mesh_transport_legacy: trans_seg: Got segment for already complete SDU
[00:04:28.298,278] <dbg> bt_mesh_transport_legacy: send_ack: SeqZero 0x0028 Block 0x00000003 OBO 0
[00:04:28.298,309] <dbg> bt_mesh_transport_legacy: send_ack: Not sending ack for non-unicast address
[00:04:28.375,183] <dbg> bt_mesh_transport_legacy: schedule_retransmit:
[00:04:28.375,305] <dbg> bt_mesh_transport_legacy: seg_tx_send_unacked: SeqZero: 0x0028 Attempts: 3
[00:04:28.425,384] <dbg> bt_mesh_transport_legacy: seg_tx_send_unacked: SeqZero: 0x0028 Attempts: 2
[00:04:28.425,415] <dbg> bt_mesh_transport_legacy: seg_tx_send_unacked: Sending 0/1
[00:04:28.425,628] <dbg> bt_mesh_transport_legacy: bt_mesh_trans_recv: src 0x5bf0 dst 0xffff seq 0x0000002c friend_match 0
[00:04:28.425,689] <dbg> bt_mesh_transport_legacy: bt_mesh_trans_recv: Payload f880a00187df25f0ff7f237ea4c8770e
[00:04:28.425,689] <dbg> bt_mesh_transport_legacy: trans_seg: ASZMIC 1 AKF 1 AID 0x38
[00:04:28.425,720] <dbg> bt_mesh_transport_legacy: trans_seg: SeqZero 0x0028 SegO 0 SegN 1
[00:04:28.425,720] <dbg> bt_mesh_transport_legacy: trans_seg: Got segment for already complete SDU
[00:04:28.425,750] <dbg> bt_mesh_transport_legacy: send_ack: SeqZero 0x0028 Block 0x00000003 OBO 0
[00:04:28.425,750] <dbg> bt_mesh_transport_legacy: send_ack: Not sending ack for non-unicast address
[00:04:28.487,091] <dbg> bt_mesh_transport_legacy: schedule_retransmit:
[00:04:28.487,213] <dbg> bt_mesh_transport_legacy: seg_tx_send_unacked: SeqZero: 0x0028 Attempts: 2
[00:04:28.487,274] <dbg> bt_mesh_transport_legacy: seg_tx_send_unacked: Sending 1/1
[00:04:28.487,457] <dbg> bt_mesh_transport_legacy: bt_mesh_trans_recv: src 0x5bf0 dst 0xffff seq 0x0000002d friend_match 0
[00:04:28.487,487] <dbg> bt_mesh_transport_legacy: bt_mesh_trans_recv: Payload f880a0219ac0f04d47e48947
[00:04:28.487,518] <dbg> bt_mesh_transport_legacy: trans_seg: ASZMIC 1 AKF 1 AID 0x38
[00:04:28.487,518] <dbg> bt_mesh_transport_legacy: trans_seg: SeqZero 0x0028 SegO 1 SegN 1
[00:04:28.487,548] <dbg> bt_mesh_transport_legacy: trans_seg: Got segment for already complete SDU
[00:04:28.487,548] <dbg> bt_mesh_transport_legacy: send_ack: SeqZero 0x0028 Block 0x00000003 OBO 0
[00:04:28.487,579] <dbg> bt_mesh_transport_legacy: send_ack: Not sending ack for non-unicast address
[00:04:28.562,133] <dbg> bt_mesh_transport_legacy: schedule_retransmit:
[00:04:28.562,225] <dbg> bt_mesh_transport_legacy: seg_tx_send_unacked: SeqZero: 0x0028 Attempts: 2
[00:04:28.612,365] <dbg> bt_mesh_transport_legacy: seg_tx_send_unacked: SeqZero: 0x0028 Attempts: 1
[00:04:28.612,396] <dbg> bt_mesh_transport_legacy: seg_tx_send_unacked: Sending 0/1
[00:04:28.612,609] <dbg> bt_mesh_transport_legacy: bt_mesh_trans_recv: src 0x5bf0 dst 0xffff seq 0x0000002e friend_match 0
[00:04:28.612,701] <dbg> bt_mesh_transport_legacy: bt_mesh_trans_recv: Payload f880a00187df25f0ff7f237ea4c8770e
[00:04:28.612,701] <dbg> bt_mesh_transport_legacy: trans_seg: ASZMIC 1 AKF 1 AID 0x38
[00:04:28.612,731] <dbg> bt_mesh_transport_legacy: trans_seg: SeqZero 0x0028 SegO 0 SegN 1
[00:04:28.612,731] <dbg> bt_mesh_transport_legacy: trans_seg: Got segment for already complete SDU
[00:04:28.612,762] <dbg> bt_mesh_transport_legacy: send_ack: SeqZero 0x0028 Block 0x00000003 OBO 0
[00:04:28.612,762] <dbg> bt_mesh_transport_legacy: send_ack: Not sending ack for non-unicast address
[00:04:28.673,400] <dbg> bt_mesh_transport_legacy: schedule_retransmit:
[00:04:28.673,492] <dbg> bt_mesh_transport_legacy: seg_tx_send_unacked: SeqZero: 0x0028 Attempts: 1
[00:04:28.673,583] <dbg> bt_mesh_transport_legacy: seg_tx_send_unacked: Sending 1/1
[00:04:28.673,736] <dbg> bt_mesh_transport_legacy: bt_mesh_trans_recv: src 0x5bf0 dst 0xffff seq 0x0000002f friend_match 0
[00:04:28.673,797] <dbg> bt_mesh_transport_legacy: bt_mesh_trans_recv: Payload f880a0219ac0f04d47e48947
[00:04:28.673,858] <dbg> bt_mesh_transport_legacy: trans_seg: ASZMIC 1 AKF 1 AID 0x38
[00:04:28.673,889] <dbg> bt_mesh_transport_legacy: trans_seg: SeqZero 0x0028 SegO 1 SegN 1
[00:04:28.673,889] <dbg> bt_mesh_transport_legacy: trans_seg: Got segment for already complete SDU
[00:04:28.673,919] <dbg> bt_mesh_transport_legacy: send_ack: SeqZero 0x0028 Block 0x00000003 OBO 0
[00:04:28.673,919] <dbg> bt_mesh_transport_legacy: send_ack: Not sending ack for non-unicast address
[00:04:28.748,992] <dbg> bt_mesh_transport_legacy: schedule_retransmit:
[00:04:28.749,114] <dbg> bt_mesh_transport_legacy: seg_tx_send_unacked: SeqZero: 0x0028 Attempts: 1

[Amanda Hsieh]

Hi, 

1.1) Are these 2 Bytes that I mentioned previously the header? What would they be headers? Is it the PDU header? Should the MIC bytes not appear?

The two extra bytes seem likely the opcode of the message. In Bluetooth Mesh, each message is associated with an opcode that identifies the type of the message. Here, you're using OP_ONOFF_SET_UNACK as the opcode. This opcode is added to the message when you call bt_mesh_model_msg_init().

When you receive the message, the opcode is extracted from the message by the Mesh stack before it's passed to your application, so you only see the payload of the message, not the opcode or the MIC (Message Integrity Check).

1.2) What would this Payload be?
[00:00:28.784,820] <dbg> bt_mesh_transport_legacy: bt_mesh_trans_recv: Payload 7883531e2dcf6c5067

The received data. See this line. 

2) Is there any method I can use to know if the "data length" is set to 27 bytes or 251 bytes?

You can check the CONFIG_BT_CTLR_DATA_LENGTH_MAX value in the .config under build/zephyr

3.1) Does this log mean that the message was broken into 2 parts?

Yes, as the log indicated seg 0 and seg 1:

[00:04:28.040,252] <dbg> bt_mesh_transport_legacy: send_seg: SeqZero 0x0028 (segs: 2)
[00:04:28.040,283] <dbg> bt_mesh_transport_legacy: send_seg: seg 0: 87df25f0ff7f237ea4c8770e
[00:04:28.040,344] <dbg> bt_mesh_transport_legacy: send_seg: seg 1: 9ac0f04d47e48947

3.2) Does this log mean that the first part is being sent?
[00:04:28.040,405] <dbg> bt_mesh_transport_legacy: seg_tx_send_unacked: Sending 0/1

Correct. 

3.3) what content is this?
[00:04:28.040,283] <dbg> bt_mesh_transport_legacy: send_seg: seg 0: 87df25f0ff7f237ea4c8770e
[00:04:28.040,344] <dbg> bt_mesh_transport_legacy: send_seg: seg 1: 9ac0f04d47e48947

The content in these logs is the encrypted payload of each segment of the message. In Bluetooth Mesh, each message is encrypted before it's sent over the air. The content you're seeing is the result of this encryption. When you receive the message, the Mesh stack decrypts the payload before it's passed to your application, so you see the original, unencrypted payload.

3.4) What would this account be? result 20
[00:04:28.105,285] <dbg> bt_mesh_transport_legacy: trans_seg: Target len 1 * 12 + 8 = 20

Set the expected final buffer length. See this line. 

Regards,
Amanda H.

[Higo]

Hi Amanda Hsieh, thanks for your information. I feel like I'm evolving

1.1)

I do not define the CONFIG_BT_CTLR_DATA_LENGTH_MAX macro in my tests. 

So I believe it is the default for 27 Bytes.

But I was able to send 26 Bytes (uint8_t) from one Node to another Node, plus the two bytes of the OPCODE that you mentioned previously, a total of 28 Bytes.

Shouldn't I only be able to send 23 Bytes? which is the size of the MTU...

[00:00:10.793,060] <dbg> bt_mesh_transport_legacy: bt_mesh_trans_send: len 28: 82030001010101010101010101010101010101010101010101010101
[00:00:10.793,212] <dbg> bt_mesh_transport_legacy: send_seg: src 0x5bf0 dst 0xffff app_idx 0x0000 aszmic 1 sdu_len 36
[00:00:10.793,243] <dbg> bt_mesh_transport_legacy: send_seg: SeqZero 0x0000 (segs: 3)
[00:00:10.793,273] <dbg> bt_mesh_transport_legacy: send_seg: seg 0: ad9295f24dac37ad5ae5e4c5
[00:00:10.793,334] <dbg> bt_mesh_transport_legacy: send_seg: seg 1: 266e5bd5fce110ff95e0ce96
[00:00:10.793,395] <dbg> bt_mesh_transport_legacy: send_seg: seg 2: e84be52f3708cb620b7665b2

1.2) 

I still have doubts whether in this case that I showed above, a Bluetooth package was sent or 3 packages were sent?

And if it was segmented into 3 packets and sent, how would these bytes of each packet be organized?

2) 

I tried setting the CONFIG_BT_CTLR_DATA_LENGTH_MAX macro in the prj.conf file to 251Bytes, as shown below

CONFIG_BT_CTLR_DATA_LENGTH_MAX=251

but nothing has changed.

I expected that I would be able to send more bytes per message.

3) 

I am studying the access.c and transport_legacy.c methods to understand how the code considers having successfully received a message or not.

I see that there are many LOG_ERR checks until finally printing the content.

Do you have any suggestions on how I can check whether the message arrived complete at the destination node or not?

main.c
  bt_mesh_model_send() - access.c
  LOG_ERR("Model not bound to AppKey 0x%04x", ctx->app_idx);
    bt_mesh_access_send() - access.c
    LOG_ERR("Local node is not yet provisioned");
      bt_mesh_trans_send() - transport_legacy.c
      LOG_ERR("Zero-length SDU not allowed");
      LOG_ERR("Message too big: %u", msg->len);
      LOG_ERR("Insufficient tailroom for Transport MIC");
      LOG_ERR("TTL too large (max 127)");
      LOG_ERR("Invalid destination address");
         send_seg(tx, msg, cb, cb_data, NULL);
         send_unseg(tx, msg, cb, cb_data, NULL);

bt_mesh_trans_recv() - transport_legacy.c
   trans_seg() - transport_legacy.c
   or
   trans_unseg() - transport_legacy.c
      sdu_recv() - transport_legacy.c
          bt_mesh_model_recv() - access.c
             element_model_recv - access.c
                 LOG_ERR("No OpCode 0x%08x for elem 0x%02x", opcode, elem->addr);
                 LOG_ERR("Wrong key");
                 LOG_ERR("Invalid address 0x%02x", ctx->recv_dst);
                 LOG_ERR("Too short message for OpCode 0x%08x", opcode);
                 LOG_ERR("Invalid message size for OpCode 0x%08x", opcode);

4) 

I would like to print all bytes of a message, including protocol header bytes,

and not just OPCODE and PAYLOAD.

Would you have a suggestion for this?

Thanks for the support