hello Tim On 9/13/23 03:11, Tim Blechmann wrote: > On 9/13/23 09:07, Tim Blechmann wrote: >>>> virtio emits a few times: >>>> [ 404.XXXXXX] No more buffers in queue >>>> and then >>>> [ 404.588722] remoteproc remoteproc0: vq index 1 is interrupted >>>> [ 404.597249] virtqueue interrupt with no work for 6d53f13a >>> >>> Difficult to understand the scheduling with your trace. Could you enable >>> ftrace to >>> observe it (mailbox interrupts,rpmsg and virtio functions) > > full trace, that my worker did (quite large, so i zipped it): > https://fileservice.klingt.org/downloads/15526951694567393180-tracefull.zip please find below an extract of your trace with my analysis: stm32mp1_bulk_p-390 [001] ..... 907.241226: rpmsg_send <-rpmsg_intercore_send_buffer.constprop.0 stm32mp1_bulk_p-390 [001] ..... 907.241228: virtio_rpmsg_send <-rpmsg_send stm32mp1_bulk_p-390 [001] ..... 907.241237: virtqueue_enable_cb <-rpmsg_send_offchannel_raw stm32mp1_bulk_p-390 [001] ..... 907.241239: virtqueue_enable_cb_prepare At this point seems that no more TX-buffer <-rpmsg_recv_single kworker/0:4-67 [000] ..... 907.242533: vring_interrupt <-rproc_vq_interrupt kworker/0:4-67 [000] ..... 907.242536: rpmsg_xmit_done Here you receive an interrupt indicating that TX buffer has been released by the remote. that's the expected behavior. <-rpmsg_send_offchannel_raw stm32mp1_bulk_p-390 [000] ..... 984.054941: rpmsg_send <-rpmsg_intercore_send_buffer.constprop.0 stm32mp1_bulk_p-390 [000] ..... 984.054943: virtio_rpmsg_send <-rpmsg_send stm32mp1_bulk_p-390 [000] ..... 984.054956: virtqueue_enable_cb <-rpmsg_send_offchannel_raw stm32mp1_bulk_p-390 [000] ..... 984.054958: virtqueue_enable_cb_prepare <-virtqueue_enable_cb stm32mp1_bulk_p-390 [000] ..... 999.398667: virtqueue_disable_cb <-rpmsg_send_offchannel_raw stm32mp1_bulk_p-390 [000] ..... 999.414840: rpmsg_send <-rpmsg_intercore_send_buffer.constprop.0 stm32mp1_bulk_p-390 [000] ..... 999.414843: virtio_rpmsg_send <-rpmsg_send stm32mp1_bulk_p-390 [000] ..... 999.414855: virtqueue_enable_cb <-rpmsg_send_offchannel_raw stm32mp1_bulk_p-390 [000] ..... 999.414857: virtqueue_enable_cb_prepare Here you have again no more TX buffer. From this point there is no more activity neither in TX nor in RX until the timeout of 15 seconds. If you have a look to rproc_vq_interrupt the last one occurs at 907.242533 As you have no more virtqueue interrupts call for both directions, the issue is probably either in the Cortex-M firmware, which seems to be stalled, or due to a disable of the IRQs in Linux. <-virtqueue_enable_cb stm32mp1_bulk_p-390 [000] ..... 1014.758678: virtqueue_disable_cb <-rpmsg_send_offchannel_raw stm32mp1_bulk_p-390 [000] ..... 1014.774802: rpmsg_send <-rpmsg_intercore_send_buffer.constprop.0 stm32mp1_bulk_p-390 [000] ..... 1014.774804: virtio_rpmsg_send <-rpmsg_send stm32mp1_bulk_p-390 [000] ..... 1014.774815: virtqueue_enable_cb Regards, Arnaud > > the interesting part starts at 907.2244250 > > many thanks, > tim
