[NRF MESH SDK5] Unable to send more than 50 bytes payload

Hi,

I have modify the payload of the Light Switch example of the NRF MESH SDK. When I send 50 bytes or less, all works fines : the server nodes received all the bytes but when I send more than 50 bytes, nothing append, the message isn't received by the node (I got an ack timeout on the client node).

I have changed the timeout to 60s for the Ack and I am sure that the message memory field is available during all the sending process.

Log for 49 bytes or less :

<t:     199893>, main.c,  236, Button 1 pressed
<t:     199896>, main.c,  260, Sending msg: ONOFF SET 1
<t:     199932>, access.c,  425, TX: [aop: 0x8202] 
<t:     199935>, access.c,  426, TX: Msg: 820242000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000FF
<t:     199984>, access.c,  253, RX: [aop: 0x8202]
<t:     199988>, access.c,  276, RX: Msg: 42000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000FF
<t:     211612>, access.c,  253, RX: [aop: 0x8204]
<t:     211614>, access.c,  276, RX: Msg: 01
<t:     211618>, main.c,  170, Acknowledged transfer success.
<t:     211620>, main.c,  200, OnOff server: 0x0014, Present OnOff: 1
<t:     628641>, main.c,  236, Button 1 pressed
<t:     628643>, main.c,  260, Sending msg: ONOFF SET 1
<t:     628679>, access.c,  425, TX: [aop: 0x8202] 
<t:     628682>, access.c,  426, TX: Msg: 820242000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000FF
<t:     628731>, access.c,  253, RX: [aop: 0x8202]
<t:     628734>, access.c,  276, RX: Msg: 42000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000FF
<t:     641033>, access.c,  253, RX: [aop: 0x8204]
<t:     641036>, access.c,  276, RX: Msg: 01
<t:     641039>, main.c,  170, Acknowledged transfer success.
<t:     641042>, main.c,  200, OnOff server: 0x0014, Present OnOff: 1

Logs for 51 bytes or more :

<t:     131570>, main.c,  236, Button 1 pressed
<t:     131572>, main.c,  260, Sending msg: ONOFF SET 1
<t:     131613>, access.c,  425, TX: [aop: 0x8202] 
<t:     131617>, access.c,  426, TX: Msg: 8202420000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000FF
<t:     131673>, access.c,  253, RX: [aop: 0x8202]
<t:     131676>, access.c,  276, RX: Msg: 420000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000FF
<t:     167668>, access_reliable.c,  131, [er8] <= access_model_publish()
<t:     203712>, access_reliable.c,  131, [er8] <= access_model_publish()
<t:     275840>, access.c,  425, TX: [aop: 0x8202] 
<t:     275843>, access.c,  426, TX: Msg: 8202420000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000FF
<t:     275899>, access.c,  253, RX: [aop: 0x8202]
<t:     275903>, access.c,  276, RX: Msg: 420000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000FF
<t:     420018>, access.c,  425, TX: [aop: 0x8202] 
<t:     420022>, access.c,  426, TX: Msg: 8202420000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000FF
<t:     420077>, access.c,  253, RX: [aop: 0x8202]
<t:     420080>, access.c,  276, RX: Msg: 420000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000FF
<t:     708377>, access.c,  425, TX: [aop: 0x8202] 
<t:     708381>, access.c,  426, TX: Msg: 8202420000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000FF
<t:     708436>, access.c,  253, RX: [aop: 0x8202]
<t:     708439>, access.c,  276, RX: Msg: 420000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000FF
<t:    1285093>, access.c,  425, TX: [aop: 0x8202] 
<t:    1285097>, access.c,  426, TX: Msg: 8202420000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000FF
<t:    1285151>, access.c,  253, RX: [aop: 0x8202]
<t:    1285155>, access.c,  276, RX: Msg: 420000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000FF
<t:    2097703>, main.c,  175, Acknowledged transfer timeout.

Can you help me please ?

Regards

Top Replies

Parents

0 Kenneth over 4 years ago

Hi,

We will look into these questions in the next few days.

Kenneth
Cancel
Vote Up +1 Vote Down

Sign in to reply

Verify Answer

Cancel

Reply

0 Kenneth over 4 years ago

Hi,

We will look into these questions in the next few days.

Kenneth
Cancel
Vote Up +1 Vote Down

Sign in to reply

Verify Answer

Cancel

Children

0 neicureuil over 4 years ago in reply to Kenneth

After putting few logs, i got this on the server node which received the message :

<t:    5941702>, transport.c,  931, Got segment 0
<t:    5941705>, transport.c,  990, Block ACK 1  -  Full : 63
<t:    5944070>, transport.c,  931, Got segment 1
<t:    5944072>, transport.c,  990, Block ACK 3  -  Full : 63
<t:    5946586>, transport.c,  931, Got segment 2
<t:    5946589>, transport.c,  990, Block ACK 7  -  Full : 63
<t:    5948795>, transport.c,  931, Got segment 3
<t:    5948798>, transport.c,  990, Block ACK 15  -  Full : 63
<t:    5951531>, transport.c,  931, Got segment 5
<t:    5951534>, transport.c,  990, Block ACK 47  -  Full : 63
<t:    5958155>, transport.c,  931, Got segment 0
<t:    5960497>, transport.c,  931, Got segment 1
<t:    5962674>, transport.c,  931, Got segment 2
<t:    5965805>, transport.c,  931, Got segment 3
<t:    5967325>, transport.c,  931, Got segment 5
<t:    5974666>, transport.c,  931, Got segment 0
<t:    5978224>, transport.c,  931, Got segment 1
<t:    5979938>, transport.c,  931, Got segment 2
<t:    5982579>, transport.c,  931, Got segment 3
<t:    5985069>, transport.c,  931, Got segment 5
<t:    5991002>, transport.c,  931, Got segment 0
<t:    5993409>, transport.c,  931, Got segment 1
<t:    5995828>, transport.c,  931, Got segment 2
<t:    5998353>, transport.c,  931, Got segment 3
<t:    6000818>, transport.c,  931, Got segment 5
<t:    6007532>, transport.c,  931, Got segment 0
<t:    6010109>, transport.c,  931, Got segment 1
<t:    6012393>, transport.c,  931, Got segment 2
<t:    6014798>, transport.c,  931, Got segment 3
<t:    6017270>, transport.c,  931, Got segment 5
<t:    6344953>, transport.c,  499, Dropped SAR session 0, reason 0

I put my logs here in transport.c :

static void trs_seg_packet_in(const packet_mesh_trs_packet_t * p_packet,
                              uint32_t packet_len,
                              const transport_packet_metadata_t * p_metadata,
                              const nrf_mesh_rx_metadata_t * p_rx_metadata)
{
    trs_sar_ctx_t * p_sar_ctx = sar_rx_ctx_get(p_metadata);

    if (p_sar_ctx == NULL)
    {
        return;
    }
    __LOG(LOG_SRC_TRANSPORT, LOG_LEVEL_INFO, "Got segment %u\n", p_metadata->segmentation.segment_offset);

    /* In a friendship, the Friend shall put segments in its Friend Queue when the message has been
     * fully received/assembled (ref. @tagMeshSp section 3.5.5). If we still have an active RX
     * context on NRF_MESH_EVT_LPN_FRIEND_POLL_COMPLETE, we regard the session as failed. Thus no
     * need to start the incomplete timer. */
    if (!is_in_lpn_role())
    {
        /* Reset timers, even if we already received this segment. */
        rx_incomplete_timer_reset(p_sar_ctx);

        if (p_sar_ctx->metadata.net.dst.type == NRF_MESH_ADDRESS_TYPE_UNICAST &&
            p_sar_ctx->session.params.rx.ack_state == SAR_ACK_STATE_IDLE)
        {
            ack_timer_reset(p_sar_ctx);
        }
    }

    if (p_sar_ctx->session.block_ack & (1u << p_metadata->segmentation.segment_offset))
    {
        /* Segment already received. */
        return;
    }

    p_sar_ctx->session.block_ack |= (1u << p_metadata->segmentation.segment_offset);

    uint32_t segment_len    = packet_len - PACKET_MESH_TRS_SEG_PDU_OFFSET;
    uint32_t segment_offset = p_metadata->segmentation.segment_offset *
                              TRANSPORT_SAR_PDU_LEN(p_metadata->net.control_packet);
    if (p_metadata->segmentation.segment_offset == p_sar_ctx->metadata.segmentation.last_segment)
    {
        /* Last segment might not be the full length of a normal segment, update total length */
        p_sar_ctx->session.length = segment_offset + segment_len;
    }
    else if (segment_len != TRANSPORT_SAR_PDU_LEN(p_metadata->net.control_packet))
    {
        /* Got a non-conformant segment length, discard the packet. */
        sar_ctx_cancel(p_sar_ctx, NRF_MESH_SAR_CANCEL_REASON_INVALID_FORMAT);
        return;
    }

    /* Adopt the network metadata of the segment that was sent last to maintain the correct sequence
     * number order in upper transport. This also ensures that once the packet is added to the
     * replay list, the entry covers them all. */
    if (p_sar_ctx->metadata.net.internal.sequence_number < p_metadata->net.internal.sequence_number)
    {
        p_sar_ctx->metadata.net = p_metadata->net;
    }

    memcpy(&p_sar_ctx->payload[segment_offset], packet_mesh_trs_seg_payload_get(p_packet), segment_len);

#if MESH_FEATURE_FRIEND_ENABLED
    // Now that all sanitizing checks have passed, we can send the packet to the friend module
    if (p_metadata->receivers & TRANSPORT_PACKET_RECEIVER_FRIEND)
    {
        friend_packet_in(p_packet, packet_len, p_metadata, CORE_TX_ROLE_RELAY);
    }
#endif

    __LOG(LOG_SRC_TRANSPORT, LOG_LEVEL_INFO, "Block ACK %u  -  Full : %u\n", p_sar_ctx->session.block_ack, block_ack_full(&p_sar_ctx->metadata));
    /* All packets have arrived */
    if (p_sar_ctx->session.block_ack == block_ack_full(&p_sar_ctx->metadata))
    {
        if (!is_in_lpn_role())
        {
            /* Final ack. If it fails, we'll recover when the sender resends a segment. We'll find
             * the cached session and respond. */
            (void) sar_ack_send(&p_sar_ctx->metadata, p_sar_ctx->session.block_ack);
        }

#if MESH_FEATURE_FRIEND_ENABLED
        // Give the packet to the friend first, in case the app decides to send something as a response
        if (p_metadata->receivers & TRANSPORT_PACKET_RECEIVER_FRIEND)
        {
            friend_sar_complete(p_metadata->net.src, p_metadata->segmentation.seq_zero, true);
        }
#endif

        upper_transport_packet_in(p_sar_ctx->payload,
                                  p_sar_ctx->session.length,
                                  &p_sar_ctx->metadata,
                                  p_rx_metadata);

        sar_ctx_free(p_sar_ctx);
    }
}

Maybe all segment not received or a metadata error ?

Why the packet number 4 never received ?

0 neicureuil over 4 years ago in reply to Kenneth

I made an other experience :

- I send a message of 10 bytes and I force the ACK size upper 50 (I test with 60 and 150), and the ack is received correctly but when I try to increase the message size upper 50, I got the same issue as before.

- I try to enable intraburst but I got the same issue.

- I try to downgrade the mesh sdk from 5.0.0 to 4.2.0 and I got the same behavior.
Cancel
Vote Up +2 Vote Down

Sign in to reply

Verify Answer

Cancel
0 neicureuil over 4 years ago in reply to Kenneth

Always no news ?
Cancel
Vote Up +2 Vote Down

Sign in to reply

Verify Answer

Cancel
0 tesc over 4 years ago in reply to neicureuil

Hi,

I am sorry for the delay.

I will look at this and provide a response today.

Regards,
Terje
Cancel
Vote Up +1 Vote Down

Sign in to reply

Verify Answer

Cancel