Currently doing bring-up of our custom Xavier board to produce video from a IMX377 sensor. When recording through gstreamer (gst-launch-1.0 nvarguscamerasrc | fakesink
) I see the following logs in the trace:
kworker/0:1-787 [000] .... 70.386619: rtcpu_string: tstamp:2690857768 id:0x04010000 str:"Configuring VI GoS.
"
kworker/0:1-787 [000] .... 70.386659: rtcpu_string: tstamp:2690857957 id:0x04010000 str:"VM GOS[#0] addr=0xc2100000
"
kworker/0:1-787 [000] .... 70.386664: rtcpu_string: tstamp:2690858219 id:0x04010000 str:"VM GOS[#1] addr=0xc2101000
"
kworker/0:1-787 [000] .... 70.386686: rtcpu_string: tstamp:2690858502 id:0x04010000 str:"VM GOS[#2] addr=0xc2102000
"
kworker/0:1-787 [000] .... 70.386690: rtcpu_string: tstamp:2690858743 id:0x04010000 str:"VM GOS[#3] addr=0xc2103000
"
kworker/0:1-787 [000] .... 70.386694: rtcpu_string: tstamp:2690858984 id:0x04010000 str:"VM GOS[#4] addr=0xc2104000
"
kworker/0:1-787 [000] .... 70.386698: rtcpu_string: tstamp:2690859227 id:0x04010000 str:"VM GOS[#5] addr=0xc2105000
"
kworker/0:1-787 [000] .... 70.386717: rtcpu_string: tstamp:2690867738 id:0x04010000 str:"vi5_hwinit: firmware CL2018101701 protocol versi"
kworker/0:1-787 [000] .... 70.386729: rtcpu_string: tstamp:2690867869 id:0x04010000 str:"on 2.2
"
kworker/0:1-787 [000] .... 70.386734: rtos_queue_send_from_isr_failed: tstamp:2690883485 queue:0x0bcb41f8
kworker/0:1-787 [000] .... 70.386735: rtos_queue_send_from_isr_failed: tstamp:2690883651 queue:0x0bcb8a60
kworker/0:1-787 [000] .... 70.386736: rtos_queue_send_from_isr_failed: tstamp:2690883817 queue:0x0bcba5e0
kworker/0:1-787 [000] .... 70.386737: rtos_queue_send_from_isr_failed: tstamp:2690883974 queue:0x0bcbb3a0
kworker/0:1-787 [000] .... 70.386738: rtos_queue_send_from_isr_failed: tstamp:2690884130 queue:0x0bcbc160
**kworker/0:1-787 [000] .... 70.386740: rtcpu_nvcsi_intr: tstamp:2690886575 class:GLOBAL type:PHY_INTR0 phy:0 cil:0 st:0 vc:0 status:0x00000089**
**kworker/0:1-787 [000] .... 70.386757: rtcpu_nvcsi_intr: tstamp:2690886575 class:GLOBAL type:PHY_INTR0 phy:0 cil:1 st:0 vc:0 status:0x00000088**
kworker/0:1-787 [000] .... 70.498706: rtos_queue_peek_from_isr_failed: tstamp:2695440618 queue:0x0bcbcf78
CaptureSchedule-5478 [001] .... 70.506901: tegra_channel_open: vi-output, IMX377 1-001a
CaptureSchedule-5478 [001] .... 70.506950: tegra_channel_set_power: IMX377 1-001a : 0x1
CaptureSchedule-5478 [001] .... 70.506959: camera_common_s_power: status : 0x1
CaptureSchedule-5478 [001] .... 70.507052: tegra_channel_set_power: 15a00000.nvcsi--4 : 0x1
CaptureSchedule-5478 [001] .... 70.507055: csi_s_power: enable : 0x1
CaptureSchedule-5478 [001] .... 70.531721: tegra_channel_set_stream: enable : 0x1
CaptureSchedule-5478 [001] .... 70.533408: tegra_channel_set_stream: 15a00000.nvcsi--4 : 0x1
CaptureSchedule-5478 [001] .... 70.533412: csi_s_stream: enable : 0x1
CaptureSchedule-5478 [001] .... 70.533414: tegra_channel_set_stream: IMX377 1-001a : 0x1
kworker/0:1-787 [000] .... 70.554721: rtos_queue_send_from_isr_failed: tstamp:2695864456 queue:0x0bcb41f8
kworker/0:1-787 [000] .... 70.554726: rtos_queue_send_from_isr_failed: tstamp:2695864617 queue:0x0bcb8a60
kworker/0:1-787 [000] .... 70.554727: rtos_queue_send_from_isr_failed: tstamp:2695864778 queue:0x0bcba5e0
kworker/0:1-787 [000] .... 70.554751: rtos_queue_send_from_isr_failed: tstamp:2695864935 queue:0x0bcbb3a0
kworker/0:1-787 [000] .... 70.554752: rtos_queue_send_from_isr_failed: tstamp:2695865091 queue:0x0bcbc160
kworker/0:1-787 [000] .... 70.554753: rtos_queue_send_from_isr_failed: tstamp:2695865307 queue:0x0bcb4190
kworker/0:1-787 [000] .... 70.554754: rtos_queue_send_from_isr_failed: tstamp:2695865456 queue:0x0bcb41f8
kworker/0:1-787 [000] .... 70.554755: rtos_queue_send_from_isr_failed: tstamp:2695865601 queue:0x0bcb89f8
kworker/0:1-787 [000] .... 70.554756: rtos_queue_send_from_isr_failed: tstamp:2695865747 queue:0x0bcb8a60
kworker/0:1-787 [000] .... 70.554756: rtos_queue_send_from_isr_failed: tstamp:2695865896 queue:0x0bcba578
kworker/0:1-787 [000] .... 70.554757: rtos_queue_send_from_isr_failed: tstamp:2695866038 queue:0x0bcba5e0
kworker/0:1-787 [000] .... 70.554758: rtos_queue_send_from_isr_failed: tstamp:2695866185 queue:0x0bcbb338
kworker/0:1-787 [000] .... 70.554759: rtos_queue_send_from_isr_failed: tstamp:2695866326 queue:0x0bcbb3a0
kworker/0:1-787 [000] .... 70.554781: rtos_queue_send_from_isr_failed: tstamp:2695866470 queue:0x0bcbc0f8
kworker/0:1-787 [000] .... 70.554782: rtos_queue_send_from_isr_failed: tstamp:2695866613 queue:0x0bcbc160
kworker/0:1-787 [000] .... 70.554783: rtos_queue_send_from_isr_failed: tstamp:2695902192 queue:0x0bcb41f8
kworker/0:1-787 [000] .... 70.554784: rtos_queue_send_from_isr_failed: tstamp:2695902353 queue:0x0bcb8a60
kworker/0:1-787 [000] .... 70.554784: rtos_queue_send_from_isr_failed: tstamp:2695902514 queue:0x0bcba5e0
kworker/0:1-787 [000] .... 70.554785: rtos_queue_send_from_isr_failed: tstamp:2695902670 queue:0x0bcbb3a0
kworker/0:1-787 [000] .... 70.554786: rtos_queue_send_from_isr_failed: tstamp:2695902825 queue:0x0bcbc160
kworker/0:1-787 [000] .... 70.554787: rtos_queue_send_from_isr_failed: tstamp:2695906287 queue:0x0bcb41f8
kworker/0:1-787 [000] .... 70.554788: rtos_queue_send_from_isr_failed: tstamp:2695906444 queue:0x0bcb8a60
kworker/0:1-787 [000] .... 70.554789: rtos_queue_send_from_isr_failed: tstamp:2695906606 queue:0x0bcba5e0
kworker/0:1-787 [000] .... 70.554789: rtos_queue_send_from_isr_failed: tstamp:2695906763 queue:0x0bcbb3a0
kworker/0:1-787 [000] .... 70.554790: rtos_queue_send_from_isr_failed: tstamp:2695906920 queue:0x0bcbc160
kworker/0:1-787 [000] .... 70.554791: rtos_queue_send_from_isr_failed: tstamp:2696013349 queue:0x0bcb41f8
kworker/0:1-787 [000] .... 70.554792: rtos_queue_send_from_isr_failed: tstamp:2696013510 queue:0x0bcb8a60
kworker/0:1-787 [000] .... 70.554793: rtos_queue_send_from_isr_failed: tstamp:2696013671 queue:0x0bcba5e0
We don’t get any other interrupts other than these two, and we are not getting any frame starts like I’m expecting.
I checked the TRM and from the status it looks like these are NVCSI_INTR_FLAG_CIL_INTR_DPHY_ERR_CLK_LANE_CTRL
, NVCSI_INTR_FLAG_CIL_INTR_DATA_LANE_ERR0_CTRL
and
NVCSI_INTR_FLAG_CIL_INTR_DATA_LANE_ERR1_CTRL
(for 0x00000089, last two for 0x00000088).
Interestingly enough, when using v4l2-ctl, everything seems to work fine. I have validated a raw dump and it looks good. Commands I used are below:
v4l2-ctl --device /dev/video0 --stream-mmap --stream-to=frame.raw --stream-count=1 --verbose
v4l2-ctl --device /dev/video0 --stream-mmap --stream-count=30
In the trace I see the same statuses, but then it seems to correct them and continue as normal.
kworker/0:4-1831 [000] .... 67.801574: rtcpu_nvcsi_intr: tstamp:2611551623 class:GLOBAL type:PHY_INTR0 phy:0 cil:0 st:0 vc:0 status:0x00000089
kworker/0:4-1831 [000] .... 67.801575: rtcpu_nvcsi_intr: tstamp:2611551623 class:GLOBAL type:PHY_INTR0 phy:0 cil:1 st:0 vc:0 status:0x00000088
kworker/0:4-1831 [000] .... 67.801577: rtcpu_vinotify_error: tstamp:2611558647 tag:CSIMUX_STREAM channel:0x00 frame:0 vi_tstamp:2611555850 data:0x00000001
kworker/0:4-1831 [000] .... 67.801580: rtcpu_vinotify_event: tstamp:2612011559 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:1963135168 data:0x10000000
kworker/0:4-1831 [000] .... 67.801581: rtcpu_vinotify_event: tstamp:2612011712 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:1963143520 data:0x31000001
kworker/0:4-1831 [000] .... 67.801582: rtcpu_vinotify_event: tstamp:2612011883 tag:RESERVED_19 channel:0x23 frame:0 vi_tstamp:1963145696 data:0x07020001
kworker/0:4-1831 [000] .... 67.801583: rtcpu_vinotify_event: tstamp:2612012030 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:1963186368 data:0x10000000
kworker/0:4-1831 [000] .... 67.801584: rtcpu_vinotify_event: tstamp:2612012201 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:1963194848 data:0x31000002
kworker/0:4-1831 [000] .... 67.801585: rtcpu_vinotify_event: tstamp:2612012355 tag:CSIMUX_STREAM channel:0x00 frame:0 vi_tstamp:2611555850 data:0x00000001
kworker/0:4-1831 [000] .... 67.801607: rtcpu_vinotify_event: tstamp:2612554487 tag:FS channel:0x00 frame:0 vi_tstamp:2612432801 data:0x00000010
kworker/0:4-1831 [000] .... 67.801608: rtcpu_vinotify_event: tstamp:2612554640 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:2612432804 data:0x00000000
kworker/0:4-1831 [000] .... 67.801608: rtcpu_vinotify_event: tstamp:2612554814 tag:CHANSEL_EMBED_SOF channel:0x23 frame:0 vi_tstamp:2612433096 data:0x00000004
kworker/0:4-1831 [000] .... 67.801609: rtcpu_vinotify_event: tstamp:2612554960 tag:CHANSEL_EMBED_EOF channel:0x23 frame:0 vi_tstamp:2612433441 data:0x00010008
kworker/0:4-1831 [000] .... 67.801610: rtcpu_vinotify_event: tstamp:2612555130 tag:ATOMP_EMB_DATA_DONE channel:0x23 frame:0 vi_tstamp:2612433468 data:0x00000000
kworker/0:4-1831 [000] .... 67.801611: rtcpu_vinotify_event: tstamp:2612555279 tag:RESERVED_19 channel:0x23 frame:0 vi_tstamp:1993499360 data:0x03020001
kworker/0:4-1831 [000] .... 67.801612: rtcpu_vinotify_event: tstamp:2612555453 tag:CHANSEL_NOMATCH channel:0x01 frame:0 vi_tstamp:2612433748 data:0x000006e9
kworker/0:4-1831 [000] .... 67.801613: rtcpu_vinotify_event: tstamp:2612555600 tag:CHANSEL_PXL_SOF channel:0x23 frame:0 vi_tstamp:2612438956 data:0x00000001
kworker/0:4-1831 [000] .... 67.801614: rtcpu_vinotify_event: tstamp:2612555772 tag:RESERVED_19 channel:0x23 frame:0 vi_tstamp:1993672224 data:0x08020001
kworker/0:4-1831 [000] .... 67.857552: rtcpu_vinotify_event: tstamp:2613435353 tag:CHANSEL_PXL_EOF channel:0x23 frame:0 vi_tstamp:2613430409 data:0x0be50002
kworker/0:4-1831 [000] .... 67.857565: rtcpu_vinotify_event: tstamp:2613488835 tag:ATOMP_FRAME_DONE channel:0x23 frame:0 vi_tstamp:2613430437 data:0x00000000
kworker/0:4-1831 [000] .... 67.857591: rtcpu_vinotify_event: tstamp:2613488985 tag:RESERVED_19 channel:0x23 frame:0 vi_tstamp:2025408256 data:0x02020001
kworker/0:4-1831 [000] .... 67.857592: rtcpu_vinotify_event: tstamp:2613489158 tag:FE channel:0x00 frame:0 vi_tstamp:2613430452 data:0x00000020
kworker/0:4-1831 [000] .... 67.857593: rtcpu_vinotify_event: tstamp:2613489311 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:2613430455 data:0x00000000
kworker/0:4-1831 [000] .... 67.857594: rtcpu_vinotify_event: tstamp:2613489481 tag:RESERVED_19 channel:0x23 frame:0 vi_tstamp:2025433728 data:0x00020001
kworker/0:4-1831 [000] .... 67.857594: rtcpu_vinotify_event: tstamp:2613489627 tag:RESERVED_19 channel:0x23 frame:0 vi_tstamp:2025456192 data:0x07020002
Other things I have tried:
- I have tried boosting the clocks of the vi/nvcsi/isp, but that didn’t seem to help.
- We use the same sensor mode settings (pix_clk_hz, etc) as on the TX2, where we did get the same sensor working through gstreamer.
After we have tried to record with gstreamer (which fails), v4l2-ctl stalls.
I’m unsure where to go from here, can you give me some pointers? Its confusing to me that the v4l2-ctl seems to produce valid images (so the MIPI signal seems to be fine?), but through nvarguscamerasrc we don’t seem to get any frame starts.
If you have more information about the DATA_LANE_ERR0_CTRL errors and what causes those, that would be appreciated!
Thanks in advance!
(Jetpack 4.3 → L4T 32.3.1)