I am using Jetson Orin Nano Super Dev Kit.
Kernel version 5.15.148.
L4T R36.64
I am working on imx296 driver using tegracam lib. I am currently facing issues related to streaming.
Using command
v4l2-ctl --stream-mmap=3 --stream-count=10 -d /dev/video0 --stream-to=/dev/null
During streaming I am constantly getting following error in dmesg
[ 614.367825] imx296 9-001a: >> TRACE [imx296_set_mode]: sensor dev
[ 614.401572] [RCE] ERROR: camera-ip/nvcsi/nvcsi.c:2015 [nvcsi_stream_set_config] "MIPI clock rate not known. Using 750000 kHz
[ 614.401583] [RCE] "
[ 614.919406] imx296 9-001a: init reg write failed idx=19 addr=0x3541 ret=-5
[ 614.920427] imx296 9-001a: init reg write failed idx=20 addr=0x3516 ret=-5
[ 614.921438] imx296 9-001a: init reg write failed idx=21 addr=0x350b ret=-5
[ 614.922467] imx296 9-001a: init reg write failed idx=22 addr=0x3758 ret=-5
[ 614.923496] imx296 9-001a: init reg write failed idx=23 addr=0x3759 ret=-5
[ 614.924520] imx296 9-001a: init reg write failed idx=24 addr=0x375a ret=-5
[ 614.925585] imx296 9-001a: init reg write failed idx=25 addr=0x375b ret=-5
[ 614.926615] imx296 9-001a: init reg write failed idx=26 addr=0x3832 ret=-5
[ 614.927640] imx296 9-001a: init reg write failed idx=27 addr=0x3833 ret=-5
[ 614.928656] imx296 9-001a: init reg write failed idx=28 addr=0x38a2 ret=-5
[ 614.929544] imx296 9-001a: init reg write failed idx=29 addr=0x38a3 ret=-5
[ 614.930555] imx296 9-001a: init reg write failed idx=30 addr=0x3a00 ret=-5
[ 614.931772] imx296 9-001a: init reg write failed idx=31 addr=0x3d48 ret=-5
[ 614.932804] imx296 9-001a: init reg write failed idx=32 addr=0x3d49 ret=-5
[ 614.934022] imx296 9-001a: init reg write failed idx=33 addr=0x3d4a ret=-5
[ 614.934631] imx296 9-001a: init reg write failed idx=34 addr=0x3d4b ret=-5
[ 614.935209] imx296 9-001a: init reg write failed idx=35 addr=0x400e ret=-5
[ 614.935774] imx296 9-001a: init reg write failed idx=36 addr=0x4014 ret=-5
[ 614.936382] imx296 9-001a: init reg write failed idx=37 addr=0x4041 ret=-5
[ 614.936908] imx296 9-001a: init reg write failed idx=38 addr=0x40a2 ret=-5
[ 614.937662] imx296 9-001a: init reg write failed idx=39 addr=0x40c1 ret=-5
[ 614.938698] imx296 9-001a: init reg write failed idx=40 addr=0x40c7 ret=-5
[ 614.939727] imx296 9-001a: init reg write failed idx=41 addr=0x40c8 ret=-5
[ 614.940752] imx296 9-001a: init reg write failed idx=42 addr=0x4174 ret=-5
[ 614.947524] >> TRACE [imx296_start_streaming]: Releasing standby to start streaming 13000
[ 615.473966] >> TRACE [imx296_start_streaming]: Return val - 0
[ 616.913507] tegra-camrtc-capture-vi tegra-capture-vi: uncorr_err: request timed out after 2500 ms
[ 616.913534] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel
[ 616.914594] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: successfully reset the capture channel
[ 619.473500] tegra-camrtc-capture-vi tegra-capture-vi: uncorr_err: request timed out after 2500 ms
[ 619.473525] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel
[ 619.474625] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: successfully reset the capture channel
[ 622.001396] tegra-camrtc-capture-vi tegra-capture-vi: uncorr_err: request timed out after 2500 ms
[ 622.001420] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel
[ 622.002741] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: successfully reset the capture channel
[ 622.002775] imx296 9-001a: >> TRACE [imx296_stop_streaming]: Stopping streaming...
[ 622.513971] >> TRACE [imx296_power_off]: in power off
[ 623.025358] imx296 9-001a: >> TRACE [imx296_power_off]: Disabling regulators
[ 623.537342] imx296 9-001a: >> TRACE [imx296_stop_streaming]: Streaming stopped
[ 624.054999] >> TRACE [imx296_power_off]: in power off
Also after some looking around i found the following
root@ubuntu:/home/ashish# cat /sys/kernel/debug/bpmp/debug/clk/nvcsi/refcount
0
root@ubuntu:/home/ashish# cat /sys/kernel/debug/bpmp/debug/clk/nvcsi/max_rate
214300000
root@ubuntu:/home/ashish# cat /sys/kernel/debug/bpmp/debug/clk/nvcsi/rate
214300000
root@ubuntu:/home/ashish# cat /sys/kernel/debug/bpmp/debug/clk/nvcsi/min_rate
10045312
root@ubuntu:/home/ashish# cat /sys/kernel/debug/bpmp/debug/clk/nvcsi/
dvfs hz_off mrq_rate_locked rate
dvfs_table max_rate parent refcount
flags min_rate possible_parents state
fmon/ mrqcount pto_counter vdd_core/
root@ubuntu:/home/ashish# cat /sys/kernel/debug/bpmp/debug/clk/nvcsi/parent
pll_nvcsi
root@ubuntu:/home/ashish# cat /sys/kernel/debug/bpmp/debug/clk/nvcsi/possible_parents
pllp_out0 pll_nvcsi clk_m
So my current two issues are
1. I2C particular commands fail
2. NVCSI clock error.
To resolve the clock error, i tried modifying the link-frequencies in dtsi. No change
In case of i2c fails, the same commands when sent via user space tools like i2ctransfer and i2cset, it does not give any error.
Can someone suggest any changes to be done?
Get the trace log to check.
sudo su
modprobe rtcpu_debug
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 3 > /sys/kernel/debug/camrtc/log-level
echo 1 > /sys/kernel/debug/tracing/events/camera_common/enable
echo > /sys/kernel/debug/tracing/trace
v4l2-ctl --stream-mmap -c bypass_mode=0
cat /sys/kernel/debug/tracing/trace
Hello @ShaneCCC
Here is the trace log as you suggested above
# cat /sys/kernel/debug/tracing/trace
# tracer: nop
#
# entries-in-buffer/entries-written: 67/67 #P:6
#
# _-------=> irqs-off
# / _------=> need-resched
# | / _-----=> need-resched-lazy
# || / _----=> hardirq/softirq
# ||| / _---=> preempt-depth
# |||| / _--=> preempt-lazy-depth
# ||||| / _-=> migrate-disable
# |||||| / delay
# TASK-PID CPU# ||||||| TIMESTAMP FUNCTION
# | | | ||||||| | |
kworker/3:1-49 [003] ....... 126.578803: rtcpu_string: tstamp:4776657578 id:0x04010000 str:"VM0 deactivating."
v4l_id-6375 [005] ....... 136.650098: tegra_channel_open: vi-output, imx296 9-001a
v4l_id-6375 [005] ....... 136.650200: tegra_channel_close: vi-output, imx296 9-001a
pipewire-media--2597 [004] ....... 136.682915: tegra_channel_open: vi-output, imx296 9-001a
pipewire-media--2597 [004] ....... 136.683037: tegra_channel_close: vi-output, imx296 9-001a
pipewire-media--2597 [003] ....... 136.684971: tegra_channel_open: vi-output, imx296 9-001a
pipewire-media--2597 [003] ....... 136.685371: tegra_channel_close: vi-output, imx296 9-001a
pipewire-2596 [005] ....... 136.690222: tegra_channel_open: vi-output, imx296 9-001a
pipewire-2596 [005] ....... 136.690270: tegra_channel_close: vi-output, imx296 9-001a
pipewire-2596 [005] ....... 136.691237: tegra_channel_open: vi-output, imx296 9-001a
pipewire-2596 [005] ....... 136.691376: tegra_channel_close: vi-output, imx296 9-001a
pipewire-2596 [005] ....... 136.691404: tegra_channel_open: vi-output, imx296 9-001a
pipewire-2596 [005] ....... 136.691442: tegra_channel_close: vi-output, imx296 9-001a
v4l2-ctl-6387 [005] ....... 138.888558: tegra_channel_open: vi-output, imx296 9-001a
v4l2-ctl-6387 [005] ....... 138.905193: tegra_channel_set_power: imx296 9-001a : 0x1
v4l2-ctl-6387 [005] ....... 138.905294: camera_common_s_power: status : 0x1
v4l2-ctl-6387 [005] ....... 139.118992: tegra_channel_set_power: 13e00000.host1x:nvcsi@15a00000- : 0x1
v4l2-ctl-6387 [005] ....... 139.118998: csi_s_power: enable : 0x1
v4l2-ctl-6387 [005] ....... 139.119635: tegra_channel_capture_setup: vnc_id 0 W 1440 H 1080 fmt c4
vi-output, imx2-6388 [004] ....... 139.128530: vi_task_submit: class_id:48 ch:0 syncpt_id:22 syncpt_thresh:220 pid:6388 tid:6388
vi-output, imx2-6388 [004] ....... 139.128540: vi_task_submit: class_id:48 ch:0 syncpt_id:22 syncpt_thresh:220 pid:6388 tid:6388
vi-output, imx2-6388 [004] ....... 139.128541: vi_task_submit: class_id:48 ch:0 syncpt_id:22 syncpt_thresh:220 pid:6388 tid:6388
vi-output, imx2-6388 [004] ....... 139.128543: vi_task_submit: class_id:48 ch:0 syncpt_id:22 syncpt_thresh:220 pid:6388 tid:6388
v4l2-ctl-6387 [005] ....... 139.128558: tegra_channel_set_stream: enable : 0x1
kworker/3:1-49 [003] ....... 139.130750: rtcpu_string: tstamp:5169046193 id:0x04010000 str:"VM0 activating."
v4l2-ctl-6387 [005] ....... 139.131319: tegra_channel_set_stream: 13e00000.host1x:nvcsi@15a00000- : 0x1
v4l2-ctl-6387 [005] ....... 139.131323: csi_s_stream: enable : 0x1
v4l2-ctl-6387 [005] ....... 139.131719: tegra_channel_set_stream: imx296 9-001a : 0x1
kworker/3:1-49 [003] ....... 139.186786: rtcpu_vinotify_event: tstamp:5169688480 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:165414849600 data:0x799e300010000000
kworker/3:1-49 [003] ....... 139.186790: rtcpu_vinotify_event: tstamp:5169688706 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:165414859232 data:0x0000000031000001
kworker/3:1-49 [003] ....... 139.186790: rtcpu_vinotify_event: tstamp:5169688952 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:165414863808 data:0x0000000007020001
kworker/3:1-49 [003] ....... 139.186791: rtcpu_vinotify_event: tstamp:5169689166 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:165414950464 data:0x799e2d0010000000
kworker/3:1-49 [003] ....... 139.186791: rtcpu_vinotify_event: tstamp:5169689405 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:165414960256 data:0x0000000031000002
vi-output, imx2-6389 [000] ....... 141.787540: tegra_channel_capture_setup: vnc_id 0 W 1440 H 1080 fmt c4
vi-output, imx2-6388 [003] ....... 141.787761: vi_task_submit: class_id:48 ch:0 syncpt_id:22 syncpt_thresh:220 pid:6388 tid:6388
vi-output, imx2-6388 [003] ....... 141.787772: vi_task_submit: class_id:48 ch:0 syncpt_id:22 syncpt_thresh:220 pid:6388 tid:6388
vi-output, imx2-6388 [003] ....... 141.787774: vi_task_submit: class_id:48 ch:0 syncpt_id:22 syncpt_thresh:220 pid:6388 tid:6388
vi-output, imx2-6388 [003] ....... 141.787775: vi_task_submit: class_id:48 ch:0 syncpt_id:22 syncpt_thresh:220 pid:6388 tid:6388
kworker/3:1-49 [003] ....... 141.838695: rtcpu_vinotify_event: tstamp:5252697261 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:168074209728 data:0x799e300010000000
kworker/3:1-49 [003] ....... 141.838699: rtcpu_vinotify_event: tstamp:5252697512 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:168074266656 data:0x0000000031000001
kworker/3:1-49 [003] ....... 141.838700: rtcpu_vinotify_event: tstamp:5252697735 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:168074284832 data:0x799e2d0010000000
kworker/3:1-49 [003] ....... 141.838700: rtcpu_vinotify_event: tstamp:5252697974 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:168074305184 data:0x0000000007020001
kworker/3:1-49 [003] ....... 141.838701: rtcpu_vinotify_event: tstamp:5252698190 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:168074347584 data:0x0000000031000002
vi-output, imx2-6389 [001] ....... 144.351433: tegra_channel_capture_setup: vnc_id 0 W 1440 H 1080 fmt c4
vi-output, imx2-6388 [004] ....... 144.351600: vi_task_submit: class_id:48 ch:0 syncpt_id:22 syncpt_thresh:220 pid:6388 tid:6388
vi-output, imx2-6388 [004] ....... 144.351619: vi_task_submit: class_id:48 ch:0 syncpt_id:22 syncpt_thresh:220 pid:6388 tid:6388
vi-output, imx2-6388 [004] ....... 144.351621: vi_task_submit: class_id:48 ch:0 syncpt_id:22 syncpt_thresh:220 pid:6388 tid:6388
vi-output, imx2-6388 [004] ....... 144.351622: vi_task_submit: class_id:48 ch:0 syncpt_id:22 syncpt_thresh:220 pid:6388 tid:6388
kworker/3:1-49 [003] ....... 144.378580: rtcpu_vinotify_event: tstamp:5332450332 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:170638037664 data:0x799e300010000000
kworker/3:1-49 [003] ....... 144.378584: rtcpu_vinotify_event: tstamp:5332450556 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:170638094592 data:0x0000000031000001
kworker/3:1-49 [003] ....... 144.378585: rtcpu_vinotify_event: tstamp:5332450801 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:170638112768 data:0x799e2d0010000000
kworker/3:1-49 [003] ....... 144.378585: rtcpu_vinotify_event: tstamp:5332451015 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:170638133088 data:0x0000000007020001
kworker/3:1-49 [003] ....... 144.378586: rtcpu_vinotify_event: tstamp:5332451255 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:170638175488 data:0x0000000031000002
v4l2-ctl-6387 [003] ....... 144.488848: tegra_channel_close: vi-output, imx296 9-001a
vi-output, imx2-6389 [001] ....... 146.907558: tegra_channel_capture_setup: vnc_id 0 W 1440 H 1080 fmt c4
v4l2-ctl-6387 [003] ....... 146.907746: tegra_channel_set_stream: enable : 0x0
v4l2-ctl-6387 [003] ....... 146.907750: tegra_channel_set_stream: imx296 9-001a : 0x0
v4l2-ctl-6387 [003] ....... 146.934461: tegra_channel_set_stream: 13e00000.host1x:nvcsi@15a00000- : 0x0
v4l2-ctl-6387 [003] ....... 146.934468: csi_s_stream: enable : 0x0
v4l2-ctl-6387 [003] ....... 146.937361: tegra_channel_set_power: imx296 9-001a : 0x0
v4l2-ctl-6387 [003] ....... 146.937373: camera_common_s_power: status : 0x0
v4l2-ctl-6387 [004] ....... 146.962464: tegra_channel_set_power: 13e00000.host1x:nvcsi@15a00000- : 0x0
v4l2-ctl-6387 [004] ....... 146.962470: csi_s_power: enable : 0x0
kworker/3:1-49 [003] ....... 146.970463: rtcpu_nvcsi_intr: tstamp:5412649498 class:GLOBAL type:PHY_INTR0 phy:1 cil:0 st:0 vc:0 status:0x00000001
kworker/3:1-49 [003] ....... 146.970467: rtcpu_nvcsi_intr: tstamp:5412649498 class:GLOBAL type:PHY_INTR1 phy:1 cil:0 st:0 vc:0 status:0x00000020
kworker/3:1-49 [003] ....... 146.970468: rtcpu_nvcsi_intr: tstamp:5412649498 class:CORRECTABLE_ERR type:PHY_INTR phy:1 cil:0 st:0 vc:0 status:0x00000001
kworker/3:1-49 [003] ....... 153.218226: rtcpu_string: tstamp:5608514009 id:0x04010000 str:"VM0 deactivating."
Please also check the below debug output from dmesg too, when v4l2-ctl --stream-mmap -c bypass_mode=0 is run
[ 138.906752] imx296 9-001a: Enabling clock on power on
[ 139.131913] imx296 9-001a: >> TRACE [imx296_set_mode]: sensor dev 0
[ 139.147004] imx296 9-001a: >> TRACE [imx296_set_mode]: hmax ret - 0 1760
[ 139.158789] imx296 9-001a: >> TRACE [imx296_set_mode]: Vmax 883
[ 139.171084] imx296 9-001a: >> TRACE [imx296_set_mode]: Vmax ret - 0
[ 139.186981] imx296 9-001a: >> TRACE [imx296_set_mode]: 0x3089 ret - 0
[ 139.203004] imx296 9-001a: >> TRACE [imx296_set_mode]: 0x308a ret - 0
[ 139.218941] imx296 9-001a: >> TRACE [imx296_set_mode]: 0x308b ret - 0
[ 139.234989] imx296 9-001a: >> TRACE [imx296_set_mode]: 0x308c ret - 0
[ 139.258785] >> TRACE [imx296_start_streaming]: Return val - 0, clock - 37090910, parent-clk - 408000000
[ 141.786712] tegra-camrtc-capture-vi tegra-capture-vi: uncorr_err: request timed out after 2500 ms
[ 141.786742] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel
[ 141.787757] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: successfully reset the capture channel
[ 144.350600] tegra-camrtc-capture-vi tegra-capture-vi: uncorr_err: request timed out after 2500 ms
[ 144.350634] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel
[ 144.351594] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: successfully reset the capture channel
[ 146.906469] tegra-camrtc-capture-vi tegra-capture-vi: uncorr_err: request timed out after 2500 ms
[ 146.906491] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel
[ 146.907701] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: successfully reset the capture channel
[ 146.907767] imx296 9-001a: >> TRACE [imx296_stop_streaming]: Stopping streaming...
[ 146.918825] imx296 9-001a: >> TRACE [imx296_stop_streaming]: Streaming stopped
[ 146.937382] >> TRACE [imx296_power_off]: in power off
[ 146.946497] imx296 9-001a: >> TRACE [imx296_power_off]: Disabling regulators
Do you have correct port-index?
Add the lane_polarity = 6 and port-index = 1 if you are using CSI-0 2 lanes config.
Hello @ShaneCCC
I am using Jetson Orin Nano Super Dev Kit.
I have connected the camera to the CAM1
So I have put the in the dtsi.
I have put
port-index = <2>;
bus-width = <1>;
data-lanes = <1>;
....
mclk_khz = "37125";
num_lanes = "1";
active_w = "1440";
active_h = "1080";
csi_pixel_bit_depth = "10";
readout_orientation = "0";
pix_clk_hz = "118060800"; // 1760 * 1118 * 60
tegra_sinterface = "serial_c";
...
// link-frequencies = /bits/ 64 <1188000000>; // commented the link-frequency
From the trace log shows NVCSI doesn’t receive any validate data from the sensor.
You may probe the sensor out signal by scope and review the HW for it.
Thanks
Hello @ShaneCCC
I did check the waveform by oscilloscope. It confirmed that camera starts streaming when the followng command is used
v4l2-ctl --stream-mmap=3 --stream-count=10 -d /dev/video0 --stream-to=/dev/null
According to that did some changes to dtsi and driver to set the correct values to the hmax and vmax taking care of endianess.
Now the new issue that I am facing is the following,
- Trying to set the freqeuncy of inck to 37.125MHz but the clock (
EXTPERIPHERAL1) is being set to 31.09MHz. And It gives following errors 262144, 131072, 512 and mostly 262144.
- I tried changing the parent of
EXTPERIPHERAL1 to vpll0 but it did not work
What should be my next step? I have tried to adjust the values of hmax and vmax and cil_settletime etc to remove these errors but it did not work it just changed the order of above errors and sometimes also gave 256 error no.
There is no update from you for a period, assuming this is not an issue anymore.
Hence, we are closing this topic. If need further support, please open a new one.
Thanks ~0310
Does the trace log still the same?
