Hi,
I have an orin devkit with jetpack 5.1.2/jetlinux 35.4.1 (latest) and 3 attached cameras:
- IMX492 (4 lanes) as /dev/video0 → capture working
- IMX492 (4 lanes) as /dev/video1 → capture working
- IMX415 (2 lanes) as /dev/video2 → I2C OK, but capture hanging
$ v4l2-ctl --set-fmt-video=width=3840,height=2160,pixelformat=RG10 --set-ctrl sensor_mode=0,bypass_mode=0 --stream-mmap -d2
^C
looking at dmesg, I see an error message I have already encountered (Capture not working on second camera):
(NULL device *): vi_capture_control_message: NULL VI channel received
The fix was to ensure that “vc-id” was set to zero in the device tree.
I checked my device tree, and it seems just fine:
- device tree dumped from /proc/device-tree:
fs_dts.txt (452.5 KB) - device tree dumped from /boot/dtb/kernel_tegra234-p3701-0000-as-p3701-0004-p3737-0000.dtb:
dtb_dts.txt (455.7 KB)
I enabled some log in the tegra code and pasted it below. I don’t see anything obviously wrong:
[ 56.731901] tegra-camrtc-capture-vi tegra-capture-vi: tegra_channel_get_selection: type: 0x1, target: 0x0, flags: 0x0, left: 0, top: 0, width: 3840, height: 2160
[ 56.732075] tegra-camrtc-capture-vi tegra-capture-vi: __tegra_channel_set_frame_size vi-output, vc_mipi 32-001a: alain, 3840x2160 -> 3840x2160
[ 56.732083] vc_mipi 32-001a: camera_common_try_fmt: size 3840 x 2160
[ 56.732089] vc_mipi 32-001a: camera_common_s_fmt(12303) size 3840 x 2160
[ 56.732092] vc_mipi 32-001a: camera_common_try_fmt: size 3840 x 2160
[ 56.732098] video4linux video2: tegra_channel_update_format: Resolution= 3840x2160 bytesperline=7680
[ 56.732134] tegra-camrtc-capture-vi tegra-capture-vi: tegra_channel_get_selection: type: 0x2, target: 0x0, flags: 0x0, left: 0, top: 0, width: 3840, height: 2160
[ 56.749349] vc_mipi 32-001a: camera_common_mclk_enable: enable MCLK with 24000000 Hz
[ 56.749617] vc_mipi 32-001a: camera_common_dpd_disable: csi 4
[ 56.750130] tegra-camrtc-capture-vi tegra-capture-vi: vi_capture_init++
[ 56.750258] tegra194-vi5 13e40000.host1x:vi0@15c00000: chan flags 4163
[ 56.750260] tegra194-vi5 13e40000.host1x:vi0@15c00000: chan mask ffffffffffffffff
[ 56.750261] tegra194-vi5 13e40000.host1x:vi0@15c00000: queue depth 4
[ 56.750262] tegra194-vi5 13e40000.host1x:vi0@15c00000: request size 384
[ 56.750263] tegra194-vi5 13e40000.host1x:vi0@15c00000: csi_stream_id 4
[ 56.750265] tegra194-vi5 13e40000.host1x:vi0@15c00000: vi unit id 0
[ 56.750266] tegra194-vi5 13e40000.host1x:vi0@15c00000: vi2 chan mask ffffffffffffffff
[ 56.756075] tegra194-vi5 13e40000.host1x:vi0@15c00000: 0 GoS tables configured.
[ 56.756080] tegra194-vi5 13e40000.host1x:vi0@15c00000: vi_capture_ivc_send_control: sending chan_id 64 msg_id 30
[ 56.756540] tegra194-vi5 13e40000.host1x:vi0@15c00000: vi_capture_ivc_send_control: response chan_id 64 msg_id 17
[ 56.756833] tegra194-vi5 13e40000.host1x:vi0@15c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:0
[ 56.756839] tegra194-vi5 13e40000.host1x:vi0@15c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:1
[ 56.756842] tegra194-vi5 13e40000.host1x:vi0@15c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:2
[ 56.756844] tegra194-vi5 13e40000.host1x:vi0@15c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:3
[ 56.757214] tegra_channel_set_stream: on=1
[ 56.757216] tegra194-vi5 13e40000.host1x:vi0@15c00000: vi_capture_status: waiting for status, timeout:5000 ms
[ 56.757219] vi_channel_id[]: 0 0 0
[ 56.757221] port[]: 4 255 255
[ 56.757222] virtual_channel: 0
[ 56.757224] timeout: 0
[ 56.757225] stride_align: 1
[ 56.757226] preferred_stride: 0
[ 56.757228] width_align: 1
[ 56.757229] height_align: 1
[ 56.757230] size_align: 1
[ 56.757232] valid_ports: 1
[ 56.757233] total_ports: 1
[ 56.757234] numlanes: 2
[ 56.757235] io_id: 0
[ 56.757236] num_subdevs: 2
[ 56.757238] sequence: 0
[ 56.757239] bypass 0, write isp 1, lowlat 0, state 1
[ 56.757240] vnc_id[]: 0 0 0
[ 56.757242] link_status 1, is_slvsec 0, is_interlaced 0
[ 56.757243] num_channels 3
[ 56.757245] num_subdevs 0
[ 56.757246] bypass 0
[ 56.760257] bwmgr API not supported
[ 56.770053] tegra194-vi5 13e40000.host1x:vi0@15c00000: vi_capture_ivc_send_control: sending chan_id 0 msg_id 64
[ 56.770216] tegra194-vi5 13e40000.host1x:vi0@15c00000: vi_capture_ivc_send_control: response chan_id 0 msg_id 65
[ 56.770220] tegra194-vi5 13e40000.host1x:vi0@15c00000: vi_capture_ivc_send_control: sending chan_id 0 msg_id 54
[ 56.770466] tegra194-vi5 13e40000.host1x:vi0@15c00000: vi_capture_ivc_send_control: response chan_id 0 msg_id 55
[ 56.770475] vc_mipi 32-001a: vc_core_set_format(): Set format 0x300f (RG10)
[ 56.770674] vc_mipi 32-001a: vc_core_try_format(): Try format 0x300f (RG10, format: 0x2b)
[ 56.770678] vc_mipi 32-001a: vc_update_image_size_from_mode(): Update image size from mode0 (l: 0, t: 0, w: 3840, h: 2160)
[ 56.770989] vc_mipi 32-001a: vc_update_tegra_image_size: 3840 x 2160, line_length=7768
[ 56.770990] vc_mipi 32-001a: vc_update_tegra_image_size: set line_length 0 replaced with 7768
[ 56.770992] vc_mipi 32-001a: vc_update_tegra_image_size: 0, 0, 3840, 2160, 7768, 808535890, 1
[ 56.771000] vc_mipi 32-001a: vc_start_streaming:422 alain: 200 200
[ 56.771004] i2c 32-0010: vc_mod_set_mode(): Set module mode: 0 (lanes: 2, format: RG10, type: STREAM)
[ 56.771260] i2c 32-0010: vc_mod_set_power(): Set module power: down
[ 56.771535] i2c 32-0010: vc_mod_set_power(): Set module power: up
[ 57.172124] vc_mipi 32-001a: vc_start_streaming:427, alain: 0, reset=1
[ 57.172132] vc_mipi 32-001a: vc_start_streaming:430, alain reset 487
[ 57.172168] vc_mipi 32-001a: vc_start_streaming:437, alain reset low
[ 57.172231] vc_mipi 32-001a: vc_sen_set_roi(): Set sensor roi: (left: 0, top: 0, width: 3840, height: 2160)
[ 57.173550] vc_mipi 32-001a: vc_start_streaming:443, alain: 0
[ 57.173553] vc_mipi 32-001a: vc_sen_set_exposure(): Set sensor exposure: 10000 us
[ 57.174505] vc_mipi 32-001a: vc_start_streaming:445, alain: 0
[ 57.174508] vc_mipi 32-001a: vc_sen_set_gain(): Set sensor gain: 0
[ 57.174933] vc_mipi 32-001a: vc_start_streaming:448, alain: 0
[ 57.174936] vc_mipi 32-001a: vc_sen_set_blacklevel(): Set sensor black level: 50
[ 57.175407] vc_mipi 32-001a: vc_start_streaming:450, alain: 0
[ 57.175410] vc_mipi 32-001a: vc_sen_start_stream(): Start streaming
[ 57.175989] vc_mipi 32-001a: vc_start_streaming:453, alain: 0
[ 61.919786] tegra194-vi5 13e40000.host1x:vi0@15c00000: capture status timed out
[ 61.919795] tegra-camrtc-capture-vi tegra-capture-vi: uncorr_err: request timed out after 5000 ms
[ 61.920056] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel
[ 61.920332] tegra194-vi5 13e40000.host1x:vi0@15c00000: vi_capture_ivc_send_control: sending chan_id 0 msg_id 20
[ 61.921340] tegra194-vi5 13e40000.host1x:vi0@15c00000: vi_capture_ivc_send_control: response chan_id 0 msg_id 21
[ 61.921386] tegra194-vi5 13e40000.host1x:vi0@15c00000: vi_capture_shutdown--
[ 61.921394] (NULL device *): vi_capture_control_message: NULL VI channel received
[ 61.921601] t194-nvcsi 13e40000.host1x:nvcsi@15a00000: csi5_stream_close: Error in closing stream_id=4, csi_port=4
[ 61.921873] (NULL device *): vi_capture_control_message: NULL VI channel received
[ 61.922078] t194-nvcsi 13e40000.host1x:nvcsi@15a00000: csi5_stream_open: VI channel not found for stream- 4 vc- 0
[ 61.922360] tegra-camrtc-capture-vi tegra-capture-vi: vi_capture_init++
[ 61.922415] tegra194-vi5 13e40000.host1x:vi0@15c00000: chan flags 4163
[ 61.922417] tegra194-vi5 13e40000.host1x:vi0@15c00000: chan mask ffffffffffffffff
[ 61.922419] tegra194-vi5 13e40000.host1x:vi0@15c00000: queue depth 4
[ 61.922420] tegra194-vi5 13e40000.host1x:vi0@15c00000: request size 384
[ 61.922421] tegra194-vi5 13e40000.host1x:vi0@15c00000: csi_stream_id 4
[ 61.922423] tegra194-vi5 13e40000.host1x:vi0@15c00000: vi unit id 0
[ 61.922424] tegra194-vi5 13e40000.host1x:vi0@15c00000: vi2 chan mask ffffffffffffffff
[ 61.922443] tegra194-vi5 13e40000.host1x:vi0@15c00000: 0 GoS tables configured.
[ 61.922445] tegra194-vi5 13e40000.host1x:vi0@15c00000: vi_capture_ivc_send_control: sending chan_id 65 msg_id 30
[ 61.922523] tegra194-vi5 13e40000.host1x:vi0@15c00000: vi_capture_ivc_send_control: response chan_id 65 msg_id 17
[ 61.922537] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: successfully reset the capture channel
[ 61.922835] tegra_channel_set_stream: on=0
[ 61.922841] vi_channel_id[]: 0 0 0
[ 61.922845] port[]: 4 255 255
[ 61.922848] virtual_channel: 0
[ 61.922850] timeout: 0
[ 61.922853] stride_align: 1
[ 61.922855] preferred_stride: 0
[ 61.922858] width_align: 1
[ 61.922860] height_align: 1
[ 61.922862] size_align: 1
[ 61.922864] valid_ports: 1
[ 61.922867] total_ports: 1
[ 61.922869] numlanes: 2
[ 61.922871] io_id: 0
[ 61.922873] num_subdevs: 2
[ 61.922876] sequence: 0
[ 61.922879] bypass 0, write isp 1, lowlat 0, state 0
[ 61.922881] vnc_id[]: 0 0 0
[ 61.922884] link_status 1, is_slvsec 0, is_interlaced 0
[ 61.922887] num_channels 3
[ 61.922889] num_subdevs 0
[ 61.922892] bypass 0
[ 61.922906] vc_mipi 32-001a: vc_sen_stop_stream(): Stop streaming
[ 61.973543] vc_mipi 32-001a: vc_stop_streaming:474, alain reset gpio 487
[ 61.973579] vc_mipi 32-001a: vc_stop_streaming:481, alain reset hi
[ 61.973589] tegra194-vi5 13e40000.host1x:vi0@15c00000: vi_capture_control_send_message: NVCSI stream is already closed for this VI channel
[ 61.976552] bwmgr API not supported
[ 61.986745] tegra194-vi5 13e40000.host1x:vi0@15c00000: vi_capture_ivc_send_control: sending chan_id 0 msg_id 20
[ 61.987538] tegra194-vi5 13e40000.host1x:vi0@15c00000: vi_capture_ivc_send_control: response chan_id 0 msg_id 21
[ 61.987608] tegra194-vi5 13e40000.host1x:vi0@15c00000: vi_capture_shutdown--
[ 61.987628] vc_mipi 32-001a: camera_common_dpd_enable: csi 4
[ 61.987634] vc_mipi 32-001a: camera_common_mclk_disable: disable MCLK
I tried maxing out the clocks but that didn’t help and camera still hangs:
sudo su
echo 1 > /sys/kernel/debug/bpmp/debug/clk/vi/mrq_rate_locked
echo 1 > /sys/kernel/debug/bpmp/debug/clk/isp/mrq_rate_locked
echo 1 > /sys/kernel/debug/bpmp/debug/clk/nvcsi/mrq_rate_locked
cat /sys/kernel/debug/bpmp/debug/clk/vi/max_rate |tee /sys/kernel/debug/bpmp/debug/clk/vi/rate
cat /sys/kernel/debug/bpmp/debug/clk/isp/max_rate | tee /sys/kernel/debug/bpmp/debug/clk/isp/rate
cat /sys/kernel/debug/bpmp/debug/clk/nvcsi/max_rate | tee /sys/kernel/debug/bpmp/debug/clk/nvcsi/rate
Last, I tried capturing a trace:
$ sudo su
# echo 1 > /sys/kernel/debug/tracing/tracing_on
# echo 30720 > /sys/kernel/debug/tracing/buffer_size_kb
# echo 1 > /sys/kernel/debug/tracing/events/tegra_rtcpu/enable
# echo 1 > /sys/kernel/debug/tracing/events/freertos/enable
# echo 2 > /sys/kernel/debug/camrtc/log-level
# echo 1 > /sys/kernel/debug/tracing/events/camera_common/enable
# echo > /sys/kernel/debug/tracing/trace
^D
v4l2-ctl --set-fmt-video=width=3840,height=2160,pixelformat=RG10 --set-ctrl sensor_mode=0,bypass_mode=0 --stream-mmap -d2
^C
Below is the trace I’m getting:
nvidia@sdj-orindk-02:~/misc$ sudo cat /sys/kernel/debug/tracing/trace
# tracer: nop
#
# entries-in-buffer/entries-written: 36/36 #P:8
#
# _-----=> irqs-off
# / _----=> need-resched
# | / _---=> hardirq/softirq
# || / _--=> preempt-depth
# ||| / delay
# TASK-PID CPU# |||| TIMESTAMP FUNCTION
# | | | |||| | |
kworker/2:2-120 [002] .... 753.988979: rtcpu_string: tstamp:24181865135 id:0x04010000 str:"VM0 deactivating."
v4l2-ctl-2971 [000] .... 778.106666: tegra_channel_open: vi-output, vc_mipi 32-001a
v4l2-ctl-2971 [000] .... 778.123376: tegra_channel_set_power: vc_mipi 32-001a : 0x1
v4l2-ctl-2971 [000] .... 778.123389: camera_common_s_power: status : 0x1
v4l2-ctl-2971 [000] .... 778.123680: tegra_channel_set_power: 13e40000.host1x:nvcsi@15a00000- : 0x1
v4l2-ctl-2971 [000] .... 778.123682: csi_s_power: enable : 0x1
v4l2-ctl-2971 [000] .... 778.124280: tegra_channel_capture_setup: vnc_id 0 W 3840 H 2160 fmt c4
kworker/2:2-120 [002] .... 778.128560: rtcpu_string: tstamp:24937543142 id:0x04010000 str:"VM0 activating."
v4l2-ctl-2971 [002] .... 778.131171: tegra_channel_set_stream: enable : 0x1
v4l2-ctl-2971 [002] .... 778.144034: tegra_channel_set_stream: 13e40000.host1x:nvcsi@15a00000- : 0x1
v4l2-ctl-2971 [002] .... 778.144036: csi_s_stream: enable : 0x1
v4l2-ctl-2971 [002] .... 778.144465: tegra_channel_set_stream: vc_mipi 32-001a : 0x1
kworker/2:2-120 [002] .... 778.184557: rtcpu_vinotify_event: tstamp:24938174671 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:798005723200 data:0x359d580010000000
kworker/2:2-120 [002] .... 778.184558: rtcpu_vinotify_event: tstamp:24938174829 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:798005729728 data:0x0000000031000001
kworker/2:2-120 [002] .... 778.184558: rtcpu_vinotify_event: tstamp:24938174985 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:798005775520 data:0x359d550010000000
kworker/2:2-120 [002] .... 778.184558: rtcpu_vinotify_event: tstamp:24938175117 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:798005782176 data:0x0000000031000002
kworker/2:2-120 [002] .... 778.184560: rtcpu_nvcsi_intr: tstamp:24938683002 class:GLOBAL type:PHY_INTR0 phy:2 cil:0 st:0 vc:0 status:0x00000044
vi-output, vc_m-2973 [001] .... 783.322558: tegra_channel_capture_setup: vnc_id 0 W 3840 H 2160 fmt c4
kworker/2:2-120 [002] .... 783.392513: rtcpu_vinotify_event: tstamp:25100394899 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:803198156160 data:0x359d580010000000
kworker/2:2-120 [002] .... 783.392515: rtcpu_vinotify_event: tstamp:25100395042 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:803198198848 data:0x0000000031000001
kworker/2:2-120 [002] .... 783.392516: rtcpu_vinotify_event: tstamp:25100395196 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:803198216416 data:0x359d550010000000
kworker/2:2-120 [002] .... 783.392516: rtcpu_vinotify_event: tstamp:25100395330 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:803198276800 data:0x0000000031000002
v4l2-ctl-2971 [002] .... 783.683120: tegra_channel_close: vi-output, vc_mipi 32-001a
vi-output, vc_m-2973 [001] .... 788.442512: tegra_channel_capture_setup: vnc_id 0 W 3840 H 2160 fmt c4
v4l2-ctl-2971 [002] .... 788.443088: tegra_channel_set_stream: enable : 0x0
v4l2-ctl-2971 [002] .... 788.443154: tegra_channel_set_stream: vc_mipi 32-001a : 0x0
kworker/2:2-120 [002] .... 788.488478: rtcpu_nvcsi_intr: tstamp:25259957608 class:GLOBAL type:PHY_INTR0 phy:2 cil:0 st:0 vc:0 status:0x00000001
kworker/2:2-120 [002] .... 788.488480: rtcpu_nvcsi_intr: tstamp:25259957966 class:GLOBAL type:PHY_INTR1 phy:2 cil:0 st:0 vc:0 status:0x00000120
v4l2-ctl-2971 [002] .... 788.493860: tegra_channel_set_stream: 13e40000.host1x:nvcsi@15a00000- : 0x0
v4l2-ctl-2971 [002] .... 788.493863: csi_s_stream: enable : 0x0
v4l2-ctl-2971 [003] .... 788.508419: tegra_channel_set_power: vc_mipi 32-001a : 0x0
v4l2-ctl-2971 [003] .... 788.508429: camera_common_s_power: status : 0x0
v4l2-ctl-2971 [003] .... 788.508471: tegra_channel_set_power: 13e40000.host1x:nvcsi@15a00000- : 0x0
v4l2-ctl-2971 [003] .... 788.508474: csi_s_power: enable : 0x0
kworker/2:2-120 [002] .... 788.544470: rtcpu_nvcsi_intr: tstamp:25261978373 class:GLOBAL type:PHY_INTR0 phy:2 cil:0 st:0 vc:0 status:0x00180000
kworker/2:2-120 [002] .... 793.808616: rtcpu_string: tstamp:25426488673 id:0x04010000 str:"VM0 deactivating."
is there anything wrong showing in this trace?
I’m running out of ideas. Any recommendation how to proceed?
Thanks,
Alain