i.MX93 rpmsg_send failed issue

NZP · ‎05-06-2024

Hello Experts,

I am working on i.mx93 rpmsg_lite_str_echo_rtos example code given in SDK_2_14_2_MIMX9352xxxxM.

Here my use case is that I am sending some periodic data (10,1,0,0) from i.mx93's cortex-M33 to cortex-A55 at every 10 second.

At Linux side in c application, I am able to read this data using /dev/ttyRPMSG30, but after some time I am not getting any data in my c application.

After Checking dmesg log I found below errors,

[  310.280524] imx_rpmsg_tty virtio1.rpmsg-virtual-tty-channel.-1.30: timeout waiting for a tx buffer
[  310.300143] imx_rpmsg_tty virtio1.rpmsg-virtual-tty-channel.-1.30: rpmsg_send failed: -512

below is code snippet of the modified function to send data from cortex-M33 on rpmsg

void app_task(void *param)
{
    volatile uint32_t remote_addr;
    void *rx_buf;
    uint32_t len;
    int32_t result;
    void *tx_buf;
    uint32_t size;

#ifdef MCMGR_USED
    uint32_t startupData;

    /* Get the startup data */
    (void)MCMGR_GetStartupData(kMCMGR_Core1, &startupData);

    my_rpmsg = rpmsg_lite_remote_init((void *)startupData, RPMSG_LITE_LINK_ID, RL_NO_FLAGS);

    /* Signal the other core we are ready */
    (void)MCMGR_SignalReady(kMCMGR_Core1);
#else
    my_rpmsg = rpmsg_lite_remote_init((void *)RPMSG_LITE_SHMEM_BASE, RPMSG_LITE_LINK_ID, RL_NO_FLAGS);
#endif /* MCMGR_USED */

    rpmsg_lite_wait_for_link_up(my_rpmsg, RL_BLOCK);

    my_queue = rpmsg_queue_create(my_rpmsg);
    my_ept   = rpmsg_lite_create_ept(my_rpmsg, LOCAL_EPT_ADDR, rpmsg_queue_rx_cb, my_queue);
    (void)rpmsg_ns_announce(my_rpmsg, my_ept, RPMSG_LITE_NS_ANNOUNCE_STRING, RL_NS_CREATE);

    /* Get RPMsg rx buffer with message */
    result = rpmsg_queue_recv_nocopy(my_rpmsg, my_queue, (uint32_t *)&remote_addr, (char **)&rx_buf, &len, RL_BLOCK);
    if (result != 0)
    {
        assert(false);
    }

    /* Release held RPMsg rx buffer */
    result = rpmsg_queue_nocopy_free(my_rpmsg, rx_buf);
    if (result != 0)
    {
        assert(false);
    }

    for (;;)
    {
        if(rpmsg_send)  // this flag will become true at every 10 second
        {
            rpmsg_send = 0;

            // convert to string
            len = snprintf(app_buf, sizeof(app_buf), "%d,%d,%d,%d\r\n", voltage, 0, 0, 0);

            if(len>0 && len<sizeof(app_buf))
            {
                
                tx_buf = rpmsg_lite_alloc_tx_buffer(my_rpmsg, &size, RL_BLOCK);
                assert(tx_buf);
               
                memcpy(tx_buf, app_buf, len);
                
                result = rpmsg_lite_send_nocopy(my_rpmsg, my_ept, remote_addr, tx_buf, len);
                if (result != 0)
                {
                    assert(false);
                }
            }
        }
    }
}

PS: However, My C application stops receiving data from /dev/ttyRPMSG30, still I am able to see data sent by cortex-M33 to cortex-A55 in dmesg logs.

[   45.085653] rpmsg_tty_cb39 2c 30 2c 30 2c 30 0d 0a                       9,0,0,0..
[   55.085541] rpmsg_tty_cb39 2c 30 2c 30 2c 30 0d 0a                       9,0,0,0..
[   65.085425] rpmsg_tty_cb39 2c 30 2c 30 2c 30 0d 0a                       9,0,0,0..
[   75.085237] rpmsg_tty_cb39 2c 30 2c 30 2c 30 0d 0a                       9,0,0,0..
[   78.585719] rpmsg_tty_cb36 2c 30 2c 30 2c 30 0d 0a                       6,0,0,0..
[   80.728381] systemd-journald[183]: Time jumped backwards, rotating.
[   85.085242] rpmsg_tty_cb36 2c 30 2c 30 2c 30 0d 0a                       6,0,0,0..
[   95.085240] rpmsg_tty_cb36 2c 30 2c 30 2c 30 0d 0a                       6,0,0,0..
[  105.085263] rpmsg_tty_cb36 2c 30 2c 30 2c 30 0d 0a                       6,0,0,0..
[  115.085799] rpmsg_tty_cb36 2c 30 2c 30 2c 30 0d 0a                       6,0,0,0..
[  125.085247] rpmsg_tty_cb36 2c 30 2c 30 2c 30 0d 0a                       6,0,0,0..
[  135.085248] rpmsg_tty_cb36 2c 30 2c 30 2c 30 0d 0a                       6,0,0,0..
[  140.678248] systemd-journald[183]: Time jumped backwards, rotating.
[  145.085823] rpmsg_tty_cb36 2c 30 2c 30 2c 30 0d 0a                       6,0,0,0..
[  155.085275] rpmsg_tty_cb36 2c 30 2c 30 2c 30 0d 0a                       6,0,0,0..
[  165.085317] rpmsg_tty_cb36 2c 30 2c 30 2c 30 0d 0a                       6,0,0,0..
[  175.085237] rpmsg_tty_cb36 2c 30 2c 30 2c 30 0d 0a                       6,0,0,0..
[  185.085252] rpmsg_tty_cb36 2c 30 2c 30 2c 30 0d 0a                       6,0,0,0..
[  195.085239] rpmsg_tty_cb36 2c 30 2c 30 2c 30 0d 0a                       6,0,0,0..
[  200.676232] systemd-journald[183]: Time jumped backwards, rotating.
[  205.085237] rpmsg_tty_cb36 2c 30 2c 30 2c 30 0d 0a                       6,0,0,0..
[  215.085240] rpmsg_tty_cb36 2c 30 2c 30 2c 30 0d 0a                       6,0,0,0..
[  225.085244] rpmsg_tty_cb36 2c 30 2c 30 2c 30 0d 0a                       6,0,0,0..
[  235.085269] rpmsg_tty_cb36 2c 30 2c 30 2c 30 0d 0a                       6,0,0,0..
[  245.085246] rpmsg_tty_cb36 2c 30 2c 30 2c 30 0d 0a                       6,0,0,0..
[  255.085242] rpmsg_tty_cb36 2c 30 2c 30 2c 30 0d 0a                       6,0,0,0..
[  260.672888] systemd-journald[183]: Time jumped backwards, rotating.
[  265.085242] rpmsg_tty_cb36 2c 30 2c 30 2c 30 0d 0a                       6,0,0,0..
[  275.085243] rpmsg_tty_cb36 2c 30 2c 30 2c 30 0d 0a                       6,0,0,0..
[  285.085332] rpmsg_tty_cb36 2c 30 2c 30 2c 30 0d 0a                       6,0,0,0..
[  295.085242] rpmsg_tty_cb36 2c 30 2c 30 2c 30 0d 0a                       6,0,0,0..
[  305.085237] rpmsg_tty_cb36 2c 30 2c 30 2c 30 0d 0a                       6,0,0,0..
[  310.280524] imx_rpmsg_tty virtio1.rpmsg-virtual-tty-channel.-1.30: timeout waiting for a tx buffer
[  310.300143] imx_rpmsg_tty virtio1.rpmsg-virtual-tty-channel.-1.30: rpmsg_send failed: -512
[  315.085240] rpmsg_tty_cb36 2c 30 2c 30 2c 30 0d 0a                       6,0,0,0..
[  320.668282] systemd-journald[183]: Time jumped backwards, rotating.
[  325.085250] rpmsg_tty_cb36 2c 30 2c 30 2c 30 0d 0a                       6,0,0,0..
[  325.359356] imx_rpmsg_tty virtio1.rpmsg-virtual-tty-channel.-1.30: timeout waiting for a tx buffer
[  325.372434] imx_rpmsg_tty virtio1.rpmsg-virtual-tty-channel.-1.30: rpmsg_send failed: -512
[  335.085252] rpmsg_tty_cb36 2c 30 2c 30 2c 30 0d 0a                       6,0,0,0..
[  340.431001] imx_rpmsg_tty virtio1.rpmsg-virtual-tty-channel.-1.30: timeout waiting for a tx buffer
[  340.456112] imx_rpmsg_tty virtio1.rpmsg-virtual-tty-channel.-1.30: rpmsg_send failed: -512
[  345.086076] rpmsg_tty_cb36 2c 30 2c 30 2c 30 0d 0a                       6,0,0,0..
[  355.085254] rpmsg_tty_cb36 2c 30 2c 30 2c 30 0d 0a                       6,0,0,0..
[  355.521789] imx_rpmsg_tty virtio1.rpmsg-virtual-tty-channel.-1.30: timeout waiting for a tx buffer
[  355.538391] imx_rpmsg_tty virtio1.rpmsg-virtual-tty-channel.-1.30: rpmsg_send failed: -512
[  365.085237] rpmsg_tty_cb36 2c 30 2c 30 2c 30 0d 0a                       6,0,0,0..
[  370.628025] imx_rpmsg_tty virtio1.rpmsg-virtual-tty-channel.-1.30: timeout waiting for a tx buffer
[  370.641824] imx_rpmsg_tty virtio1.rpmsg-virtual-tty-channel.-1.30: rpmsg_send failed: -512
[  375.085242] rpmsg_tty_cb36 2c 30 2c 30 2c 30 0d 0a                       6,0,0,0..

So, Experts Here I am requesting to please look into this and give me some guidance.

Alejandro_Salas · ‎05-08-2024

Hello @NZP

I am trying to replicate your issue.

Could you please tell me about the rpmsg_send and voltage variables?

Also the BSP version that you are using.

Best reagrds.

Salas.

NZP · ‎05-08-2024

Hi Salas,

Thanks for your reply,

1. Cortex M33 SDK version: SDK_2.14.2_MIMX9352xxxxM

2. Linux BSP version: i.MX Linux Yocto Project BSP 6.1.1_1.0.0 Release

Please find attached test program for cortex M33 to send rpmsg data and linux c++ app to receive rpmsg data.

P.S: what is my main problem is that my c++ application is able to receive data for some time but after certain period of time c++ application is not receiving any data from /dev/ttyRPMSG30, however I am able to see data sent from cortex-m33 in linux kernel dmesg logs.

Alejandro_Salas · ‎05-14-2024

Hello @NZP

I modified a little your code:

for (;;)
    {
        if(rpmsg_send)
        {
            rpmsg_send = 0;

            // convert to string
            len = snprintf(app_buf, sizeof(app_buf), "%d,%d,%d,%d\r\n", voltage++, 0, 0, 0);

            if(len>0 && len<sizeof(app_buf))
            {
                /* Get tx buffer from RPMsg */
                tx_buf = rpmsg_lite_alloc_tx_buffer(my_rpmsg, &size, RL_BLOCK);
                
                assert(tx_buf);
              
                /* Copy string to RPMsg tx buffer */
                memcpy(tx_buf, app_buf, len);
                result = rpmsg_lite_send_nocopy(my_rpmsg, my_ept, remote_addr, tx_buf, len);
                
                if (result != 0)
                {
                    assert(false);
                }

                result = rpmsg_queue_nocopy_free(my_rpmsg, tx_buf);
                if (result != 0)
                {
                    assert(false);
                }

            
            }
        }
    }
}

I added:

result = rpmsg_queue_nocopy_free(my_rpmsg, tx_buf);
                if (result != 0)
                {
                    assert(false);
                }

To free the tx buffer, and now you should not have the timeout waiting for a tx buffer rpmsg log.

Logs from dmesg:

Logs from your Linux application:

I modified the voltage variable to increment each iteration.

I can confirm that the cortex M is sending messages to cortex A by the dmesg command, but sometimes trying to read form the ttyRPMSG30 the cortex A freeze for a moment, then work normally and It can read the ttyRPMSG30.

I am still investigating this issue.

Best regards.

Salas.

NZP · ‎05-14-2024

Hi @Alejandro_Salas

Thanks for reply.

I can confirm that the cortex M is sending messages to cortex A by the dmesg command, but sometimes trying to read form the ttyRPMSG30 the cortex A freeze for a moment, then work normally and It can read the ttyRPMSG30.

In my case once ttyRPMSG30 freezes it is not coming out. So, waiting for your observation.

Alejandro_Salas · ‎05-15-2024

Hello @NZP

I tried with Linux 6.6.3 and it is working well.

Could you please try and let me know if the issue still is happening?

Best regards.

Salas.

NZP · ‎05-20-2024

Hi @Alejandro_Salas,

While testing I got one observation,

if I do screen /dev/ttyRPMSG30 it is working fine, and port is not freezing, but in c++ application port is still freezing.

NZP · ‎05-17-2024

Hi @Alejandro_Salas ,

After adding below at cortex-m33 side able to remove "timeout waiting for a tx buffer rpmsg log"

result = rpmsg_queue_nocopy_free(my_rpmsg, tx_buf);
                if (result != 0)
                {
                    assert(false);
                }

but still getting the issue of freezing ttyRPMSG30.

Can you please suggest other strategy to debug this issue.