OV2311 Custom Driver Issues

kaz.khaki · January 30, 2024, 5:43pm

OV2311 Custom Driver Issues

We have connected an OV2311 sensor to an Orin NX 16GB dev kit from waveshare

Custom kernel is built with Jetson Linux 35.4.1, and overlay is applied. Driver, overlay, and other files used are here public.zip (23.3 KB)

ov2311 has been tried on CAM0 and CAM1 slot, and results are the same.

Running the following:

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

v4l2-ctl -V
v4l2-ctl -d /dev/video0 --list-formats
v4l2-ctl -d /dev/video0 --list-formats-ext

gst-launch-1.0 -v \
nvarguscamerasrc do-timestamp=true awblock=true aelock=true sensor-id=0 \
 ! 'video/x-raw(memory:NVMM), width=(int)1600, height=(int)1300, framerate=(fraction)60/1' \
 ! nvvidconv \
 ! nvv4l2h264enc \
 ! h264parse \
 ! qtmux \
 ! filesink location=test_2311.mp4 -e

Gives:

832000000
1011200000
642900000

Format Video Capture:
        Width/Height      : 1600/1300
        Pixel Format      : 'RG10' (10-bit Bayer RGRG/GBGB)
        Field             : None
        Bytes per Line    : 3200
        Size Image        : 4160000
        Colorspace        : sRGB
        Transfer Function : Default (maps to sRGB)
        YCbCr/HSV Encoding: Default (maps to ITU-R 601)
        Quantization      : Default (maps to Full Range)
        Flags             : 
ioctl: VIDIOC_ENUM_FMT
        Type: Video Capture

        [0]: 'RG10' (10-bit Bayer RGRG/GBGB)
ioctl: VIDIOC_ENUM_FMT
        Type: Video Capture

        [0]: 'RG10' (10-bit Bayer RGRG/GBGB)
                Size: Discrete 1600x1300
                        Interval: Discrete 0.017s (60.000 fps)

Setting pipeline to PAUSED ...
Opening in BLOCKING MODE 
Pipeline is live and does not need PREROLL ...
Setting pipeline to PLAYING ...
New clock: GstSystemClock
/GstPipeline:pipeline0/GstNvArgusCameraSrc:nvarguscamerasrc0.GstPad:src: caps = video/x-raw(memory:NVMM), width=(int)1600, height=(int)1300, format=(string)NV12, framerate=(fraction)60/1
/GstPipeline:pipeline0/GstCapsFilter:capsfilter0.GstPad:src: caps = video/x-raw(memory:NVMM), width=(int)1600, height=(int)1300, format=(string)NV12, framerate=(fraction)60/1
/GstPipeline:pipeline0/Gstnvvconv:nvvconv0.GstPad:src: caps = video/x-raw(memory:NVMM), width=(int)1600, height=(int)1300, format=(string)NV12, framerate=(fraction)60/1
/GstPipeline:pipeline0/nvv4l2h264enc:nvv4l2h264enc0.GstPad:src: caps = video/x-h264, stream-format=(string)byte-stream, alignment=(string)au, profile=(string)NULL, level=(string)NULL, width=(int)1600, height=(int)1300, pixel-aspect-ratio=(fraction)1/1, framerate=(fraction)60/1, interlace-mode=(string)progressive, colorimetry=(string)bt709, chroma-site=(string)mpeg2
/GstPipeline:pipeline0/GstH264Parse:h264parse0.GstPad:sink: caps = video/x-h264, stream-format=(string)byte-stream, alignment=(string)au, profile=(string)NULL, level=(string)NULL, width=(int)1600, height=(int)1300, pixel-aspect-ratio=(fraction)1/1, framerate=(fraction)60/1, interlace-mode=(string)progressive, colorimetry=(string)bt709, chroma-site=(string)mpeg2
Redistribute latency...
NvMMLiteOpen : Block : BlockType = 4 
===== NvVideo: NVENC =====
NvMMLiteBlockCreate : Block : BlockType = 4 
/GstPipeline:pipeline0/nvv4l2h264enc:nvv4l2h264enc0.GstPad:sink: caps = video/x-raw(memory:NVMM), width=(int)1600, height=(int)1300, format=(string)NV12, framerate=(fraction)60/1
/GstPipeline:pipeline0/Gstnvvconv:nvvconv0.GstPad:sink: caps = video/x-raw(memory:NVMM), width=(int)1600, height=(int)1300, format=(string)NV12, framerate=(fraction)60/1
/GstPipeline:pipeline0/GstCapsFilter:capsfilter0.GstPad:sink: caps = video/x-raw(memory:NVMM), width=(int)1600, height=(int)1300, format=(string)NV12, framerate=(fraction)60/1
GST_ARGUS: Creating output stream
CONSUMER: Waiting until producer is connected...
GST_ARGUS: Available Sensor modes :
GST_ARGUS: 1600 x 1300 FR = 59.999999 fps Duration = 16666667 ; Analog Gain range min 1.000000, max 31.000000; Exposure Range min 10000, max 16440000;

GST_ARGUS: Running with following settings:
   Camera index = 0 
   Camera mode  = 0 
   Output Stream W = 1600 H = 1300 
   seconds to Run    = 0 
   Frame Rate = 59.999999 
GST_ARGUS: Setup Complete, Starting captures for 0 seconds
GST_ARGUS: Starting repeat capture requests.
CONSUMER: Producer has connected; continuing.
nvbuf_utils: dmabuf_fd -1 mapped entry NOT found
Error generated. /dvs/git/dirty/git-master_linux/multimedia/nvgstreamer/gst-nvarguscamera/gstnvarguscamerasrc.cpp, threadExecute:694 NvBufSurfaceFromFd Failed.
Error generated. /dvs/git/dirty/git-master_linux/multimedia/nvgstreamer/gst-nvarguscamera/gstnvarguscamerasrc.cpp, threadFunction:247 (propagating)
ERROR: from element /GstPipeline:pipeline0/GstNvArgusCameraSrc:nvarguscamerasrc0: CANCELLED
Additional debug info:
Argus Error Status
EOS on shutdown enabled -- waiting for EOS after Error
Waiting for EOS...
/GstPipeline:pipeline0/GstQTMux:qtmux0.GstPad:src: caps = video/quicktime, variant=(string)apple
/GstPipeline:pipeline0/GstFileSink:filesink0.GstPad:sink: caps = video/quicktime, variant=(string)apple
^Chandling interrupt.
Interrupt: Stopping pipeline ...
Interrupt while waiting for EOS - stopping pipeline...
Execution ended after 0:00:35.316775955
Setting pipeline to NULL ...
GST_ARGUS: Cleaning up
Freeing pipeline ...

cat /sys/kernel/debug/tracing/trace gives:

# tracer: nop
#
# entries-in-buffer/entries-written: 572586/572586   #P:8
#
#                                _-----=> irqs-off
#                               / _----=> need-resched
#                              | / _---=> hardirq/softirq
#                              || / _--=> preempt-depth
#                              ||| /     delay
#           TASK-PID     CPU#  ||||   TIMESTAMP  FUNCTION
#              | |         |   ||||      |         |
        v4l2-ctl-4797    [000] ....   352.125908: tegra_channel_open: vi-output, ov2311 10-0060
        v4l2-ctl-4797    [000] ....   352.126191: tegra_channel_close: vi-output, ov2311 10-0060
        v4l2-ctl-4798    [003] ....   352.128643: tegra_channel_open: vi-output, ov2311 10-0060
        v4l2-ctl-4798    [003] ....   352.128791: tegra_channel_close: vi-output, ov2311 10-0060
        v4l2-ctl-4799    [004] ....   352.132557: tegra_channel_open: vi-output, ov2311 10-0060
        v4l2-ctl-4799    [004] ....   352.132772: tegra_channel_close: vi-output, ov2311 10-0060
  nvargus-daemon-4802    [004] ....   352.254195: tegra_channel_open: vi-output, ov2311 10-0060
  nvargus-daemon-4802    [004] ....   352.254254: tegra_channel_close: vi-output, ov2311 10-0060
  nvargus-daemon-4802    [004] ....   352.254972: tegra_channel_open: vi-output, ov2311 10-0060
  nvargus-daemon-4802    [004] ....   352.255002: tegra_channel_close: vi-output, ov2311 10-0060
  nvargus-daemon-4802    [004] ....   352.270869: tegra_channel_open: vi-output, ov2311 10-0060
  nvargus-daemon-4802    [004] ....   352.270879: tegra_channel_close: vi-output, ov2311 10-0060
  nvargus-daemon-4802    [004] ....   352.271122: tegra_channel_open: vi-output, ov2311 10-0060
  nvargus-daemon-4802    [004] ....   352.271128: tegra_channel_close: vi-output, ov2311 10-0060
  nvargus-daemon-4802    [004] ....   352.271135: tegra_channel_open: vi-output, ov2311 10-0060
  nvargus-daemon-4802    [004] ....   352.271161: tegra_channel_close: vi-output, ov2311 10-0060
  nvargus-daemon-4802    [004] ....   352.271171: tegra_channel_open: vi-output, ov2311 10-0060
  nvargus-daemon-4802    [004] ....   352.271206: tegra_channel_close: vi-output, ov2311 10-0060
 CaptureSchedule-4818    [004] ....   352.390007: tegra_channel_open: vi-output, ov2311 10-0060
 CaptureSchedule-4818    [004] ....   352.390146: tegra_channel_set_power: ov2311 10-0060 : 0x1
 CaptureSchedule-4818    [004] ....   352.390150: camera_common_s_power: status : 0x1
 CaptureSchedule-4818    [004] ....   352.690797: tegra_channel_set_power: 13e40000.host1x:nvcsi@15a00000- : 0x1
 CaptureSchedule-4818    [004] ....   352.690805: csi_s_power: enable : 0x1
 CaptureSchedule-4818    [004] ....   352.691087: tegra_channel_set_stream: enable : 0x1
 CaptureSchedule-4818    [004] ....   352.700283: tegra_channel_set_stream: 13e40000.host1x:nvcsi@15a00000- : 0x1
 CaptureSchedule-4818    [004] ....   352.700286: csi_s_stream: enable : 0x1
 CaptureSchedule-4818    [004] ....   352.700288: tegra_channel_set_stream: ov2311 10-0060 : 0x1
     kworker/4:1-71      [004] ....   352.763451: rtcpu_vinotify_event: tstamp:11705452841 cch:1 vi:1 tag:VIFALC_TDSTATE channel:0x0b frame:0 vi_tstamp:374574346880 data:0x759da00010000000
     kworker/4:1-71      [004] ....   352.763453: rtcpu_vinotify_event: tstamp:11705453002 cch:1 vi:1 tag:VIFALC_TDSTATE channel:0x0b frame:0 vi_tstamp:374574353376 data:0x0000000031000001
     kworker/4:1-71      [004] ....   352.763454: rtcpu_vinotify_event: tstamp:11706128994 cch:1 vi:1 tag:VIFALC_TDSTATE channel:0x0b frame:0 vi_tstamp:374594901984 data:0x759d9d0010000000
     kworker/4:1-71      [004] ....   352.763455: rtcpu_vinotify_event: tstamp:11706129130 cch:1 vi:1 tag:VIFALC_TDSTATE channel:0x0b frame:0 vi_tstamp:374594908480 data:0x0000000031000002
     kworker/4:1-71      [004] ....   352.763457: rtcpu_nvcsi_intr: tstamp:11706227671 class:GLOBAL type:PHY_INTR0 phy:1 cil:0 st:0 vc:0 status:0x02000040
     kworker/4:1-71      [004] ....   352.763458: rtcpu_nvcsi_intr: tstamp:11706227671 class:CORRECTABLE_ERR type:PHY_INTR phy:1 cil:0 st:0 vc:0 status:0x00000240
     kworker/4:1-71      [004] ....   352.763458: rtcpu_nvcsi_intr: tstamp:11706242411 class:GLOBAL type:PHY_INTR0 phy:1 cil:0 st:0 vc:0 status:0x10000044
     kworker/4:1-71      [004] ....   352.763459: rtcpu_nvcsi_intr: tstamp:11706242411 class:CORRECTABLE_ERR type:PHY_INTR phy:1 cil:0 st:0 vc:0 status:0x00001044
     kworker/4:1-71      [004] ....   352.763460: rtcpu_nvcsi_intr: tstamp:11706242914 class:GLOBAL type:PHY_INTR0 phy:1 cil:0 st:0 vc:0 status:0x00000044
     kworker/4:1-71      [004] ....   352.763460: rtcpu_nvcsi_intr: tstamp:11706242914 class:CORRECTABLE_ERR type:PHY_INTR phy:1 cil:0 st:0 vc:0 status:0x00000044
     kworker/4:1-71      [004] ....   352.763461: rtcpu_nvcsi_intr: tstamp:11706243409 class:GLOBAL type:PHY_INTR0 phy:1 cil:0 st:0 vc:0 status:0x00000044
     kworker/4:1-71      [004] ....   352.763462: rtcpu_nvcsi_intr: tstamp:11706243409 class:CORRECTABLE_ERR type:PHY_INTR phy:1 cil:0 st:0 vc:0 status:0x00000044
     kworker/4:1-71      [004] ....   352.763462: rtcpu_nvcsi_intr: tstamp:11706243916 class:GLOBAL type:PHY_INTR0 phy:1 cil:0 st:0 vc:0 status:0x00000044
     kworker/4:1-71      [004] ....   358.285870: rtcpu_nvcsi_intr: tstamp:11879013217 class:CORRECTABLE_ERR type:PHY_INTR phy:1 cil:0 st:0 vc:0 status:0x00000044
     kworker/4:1-71      [004] ....   358.285870: rtcpu_nvcsi_intr: tstamp:11879013719 class:GLOBAL type:PHY_INTR0 phy:1 cil:0 st:0 vc:0 status:0x00000044
     kworker/4:1-71      [004] ....   358.285871: rtcpu_nvcsi_intr: tstamp:11879013719 class:CORRECTABLE_ERR type:PHY_INTR phy:1 cil:0 st:0 vc:0 status:0x00000044
 CaptureSchedule-4818    [005] ....   358.311523: tegra_channel_set_stream: enable : 0x0
 CaptureSchedule-4818    [005] ....   358.311525: tegra_channel_set_stream: ov2311 10-0060 : 0x0
 CaptureSchedule-4818    [005] ....   358.311730: tegra_channel_set_stream: 13e40000.host1x:nvcsi@15a00000- : 0x0
 CaptureSchedule-4818    [005] ....   358.311732: csi_s_stream: enable : 0x0
 CaptureSchedule-4818    [000] ....   358.321255: tegra_channel_set_power: ov2311 10-0060 : 0x0
 CaptureSchedule-4818    [000] ....   358.321269: camera_common_s_power: status : 0x0
 CaptureSchedule-4818    [000] ....   358.330338: tegra_channel_set_power: 13e40000.host1x:nvcsi@15a00000- : 0x0
 CaptureSchedule-4818    [000] ....   358.330342: csi_s_power: enable : 0x0
     kworker/4:1-71      [004] ....   358.339275: rtcpu_nvcsi_intr: tstamp:11879014240 class:GLOBAL type:PHY_INTR0 phy:1 cil:0 st:0 vc:0 status:0x00000044
     kworker/4:1-71      [004] ....   358.339276: rtcpu_nvcsi_intr: tstamp:11879014240 class:CORRECTABLE_ERR type:PHY_INTR phy:1 cil:0 st:0 vc:0 status:0x00000044
     kworker/4:1-71      [004] ....   358.339277: rtcpu_nvcsi_intr: tstamp:11879014742 class:GLOBAL type:PHY_INTR0 phy:1 cil:0 st:0 vc:0 status:0x00000044
     kworker/4:1-71      [004] ....   358.339277: rtcpu_nvcsi_intr: tstamp:11879014742 class:CORRECTABLE_ERR type:PHY_INTR phy:1 cil:0 st:0 vc:0 status:0x00000044
     kworker/4:1-71      [004] ....   358.339278: rtcpu_nvcsi_intr: tstamp:11879015241 class:GLOBAL type:PHY_INTR0 phy:1 cil:0 st:0 vc:0 status:0x00000044
     kworker/4:1-71      [004] ....   358.340453: rtcpu_nvcsi_intr: tstamp:11879902028 class:CORRECTABLE_ERR type:PHY_INTR phy:1 cil:0 st:0 vc:0 status:0x00000044
     kworker/4:1-71      [004] ....   358.340454: rtcpu_nvcsi_intr: tstamp:11879902522 class:GLOBAL type:PHY_INTR0 phy:1 cil:0 st:0 vc:0 status:0x00000044
     kworker/4:1-71      [004] ....   358.340454: rtcpu_nvcsi_intr: tstamp:11879902522 class:CORRECTABLE_ERR type:PHY_INTR phy:1 cil:0 st:0 vc:0 status:0x00000044
  nvargus-daemon-4802    [003] ....   387.703912: tegra_channel_close: vi-output, ov2311 10-0060
     kworker/4:1-71      [004] ....   387.726371: rtcpu_isp_falcon_task_start: tstamp:4208436986 ch:0 task:HANDLE_EVENT
     kworker/4:1-71      [004] ....   387.726377: rtcpu_isp_falcon_task_end: tstamp:4208437027 task:HANDLE_EVENT
     kworker/4:1-71      [004] ....   393.858227: rtcpu_string: tstamp:12989014223 id:0x04010000 str:"VM0 deactivating."
        v4l2-ctl-5194    [005] ....   438.621572: tegra_channel_open: vi-output, ov2311 10-0060
        v4l2-ctl-5194    [005] ....   438.625819: tegra_channel_set_power: ov2311 10-0060 : 0x1
        v4l2-ctl-5194    [005] ....   438.625830: camera_common_s_power: status : 0x1
        v4l2-ctl-5194    [005] ....   438.926599: tegra_channel_set_power: 13e40000.host1x:nvcsi@15a00000- : 0x1
        v4l2-ctl-5194    [005] ....   438.926605: csi_s_power: enable : 0x1
        v4l2-ctl-5194    [005] ....   438.927396: tegra_channel_set_stream: enable : 0x1
        v4l2-ctl-5194    [005] ....   438.929680: tegra_channel_set_stream: 13e40000.host1x:nvcsi@15a00000- : 0x1
        v4l2-ctl-5194    [005] ....   438.929682: csi_s_stream: enable : 0x1
        v4l2-ctl-5194    [005] ....   438.929683: tegra_channel_set_stream: ov2311 10-0060 : 0x1
        v4l2-ctl-5194    [007] ....   453.246501: tegra_channel_close: vi-output, ov2311 10-0060
        v4l2-ctl-5194    [007] ....   453.246509: tegra_channel_set_stream: enable : 0x0
        v4l2-ctl-5194    [007] ....   453.246511: tegra_channel_set_stream: ov2311 10-0060 : 0x0
        v4l2-ctl-5194    [007] ....   453.246741: tegra_channel_set_stream: 13e40000.host1x:nvcsi@15a00000- : 0x0
        v4l2-ctl-5194    [007] ....   453.246743: csi_s_stream: enable : 0x0
        v4l2-ctl-5194    [005] ....   453.255782: tegra_channel_set_power: ov2311 10-0060 : 0x0
        v4l2-ctl-5194    [005] ....   453.255796: camera_common_s_power: status : 0x0
        v4l2-ctl-5194    [007] ....   453.264733: tegra_channel_set_power: 13e40000.host1x:nvcsi@15a00000- : 0x0
        v4l2-ctl-5194    [007] ....   453.264740: csi_s_power: enable : 0x0

What would you suggest to try next?

kaz.khaki · January 30, 2024, 5:47pm

Also, tried v4l2-ctl --device /dev/video0 --stream-mmap

Results on UART are:

tegra-camrtc-capture-vi tegra-capture-vi: uncorr_err: request timed out after 2500 ms
[   93.125647] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel
[   93.136524] (NULL device *): vi_capture_control_message: NULL VI channel received
[   93.144242] t194-nvcsi 13e40000.host1x:nvcsi@15a00000: csi5_stream_close: Error in closing stream_id=2, csi_port=2
[   93.154907] (NULL device *): vi_capture_control_message: NULL VI channel received
[   93.162622] t194-nvcsi 13e40000.host1x:nvcsi@15a00000: csi5_stream_open: VI channel not found for stream- 2 vc- 0
[   93.173854] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: successfully reset the capture channel

enrique.ramirez · January 30, 2024, 8:00pm

Hi @kaz.khaki

I noticed in your device-tree you set discontinuous_clk = "true", this field should be set to "yes" or "no". Could you try both to see if you have better results?

Also, did you get the same VI trace when running the v4l2-ctl command?

Best Regards,

Enrique Ramirez
Embedded SW Engineer at RidgeRun
Contact us: support@ridgerun.com
Developers wiki: https://developer.ridgerun.com
Website: www.ridgerun.com

ShaneCCC · January 31, 2024, 3:44am

This message tell the multiple bit of SOT(Start Of Transfer) error.
That could be the sensor settle time problem.

kaz.khaki · January 31, 2024, 12:11pm

Thank you @enrique.ramirez and @ShaneCCC for your suggestions.

I changed discontinuous clock to "yes" as that is what the ov2311 datasheet states and the outcome was the same.

I then re-calculated and changed the timings (trying to ensure settle time is auto calculated):

line_length = "1808"; 
mclk_multiplier = "8.34"; 
pix_clk_hz = "200000000";

After running this on CAM0 and CAM1, the results are very different than before, but it still doesn’t work.

gst-launch-1 command now shows

Setting pipeline to PAUSED ...
Opening in BLOCKING MODE 
Pipeline is live and does not need PREROLL ...
Setting pipeline to PLAYING ...
New clock: GstSystemClock
/GstPipeline:pipeline0/GstNvArgusCameraSrc:nvarguscamerasrc0.GstPad:src: caps = video/x-raw(memory:NVMM), width=(int)1600, height=(int)1300, format=(string)NV12, framerate=(fraction)60/1
/GstPipeline:pipeline0/GstCapsFilter:capsfilter0.GstPad:src: caps = video/x-raw(memory:NVMM), width=(int)1600, height=(int)1300, format=(string)NV12, framerate=(fraction)60/1
/GstPipeline:pipeline0/Gstnvvconv:nvvconv0.GstPad:src: caps = video/x-raw(memory:NVMM), width=(int)1600, height=(int)1300, format=(string)NV12, framerate=(fraction)60/1
/GstPipeline:pipeline0/nvv4l2h264enc:nvv4l2h264enc0.GstPad:src: caps = video/x-h264, stream-format=(string)byte-stream, alignment=(string)au, profile=(string)NULL, level=(string)NULL, width=(int)1600, height=(int)1300, pixel-aspect-ratio=(fraction)1/1, framerate=(fraction)60/1, interlace-mode=(string)progressive, colorimetry=(string)bt709, chroma-site=(string)mpeg2
/GstPipeline:pipeline0/GstH264Parse:h264parse0.GstPad:sink: caps = video/x-h264, stream-format=(string)byte-stream, alignment=(string)au, profile=(string)NULL, level=(string)NULL, width=(int)1600, height=(int)1300, pixel-aspect-ratio=(fraction)1/1, framerate=(fraction)60/1, interlace-mode=(string)progressive, colorimetry=(string)bt709, chroma-site=(string)mpeg2
Redistribute latency...
NvMMLiteOpen : Block : BlockType = 4 
===== NvVideo: NVENC =====
NvMMLiteBlockCreate : Block : BlockType = 4 
/GstPipeline:pipeline0/nvv4l2h264enc:nvv4l2h264enc0.GstPad:sink: caps = video/x-raw(memory:NVMM), width=(int)1600, height=(int)1300, format=(string)NV12, framerate=(fraction)60/1
/GstPipeline:pipeline0/Gstnvvconv:nvvconv0.GstPad:sink: caps = video/x-raw(memory:NVMM), width=(int)1600, height=(int)1300, format=(string)NV12, framerate=(fraction)60/1
/GstPipeline:pipeline0/GstCapsFilter:capsfilter0.GstPad:sink: caps = video/x-raw(memory:NVMM), width=(int)1600, height=(int)1300, format=(string)NV12, framerate=(fraction)60/1
GST_ARGUS: Creating output stream
CONSUMER: Waiting until producer is connected...
GST_ARGUS: Available Sensor modes :
GST_ARGUS: 1600 x 1300 FR = 59.999999 fps Duration = 16666667 ; Analog Gain range min 1.000000, max 31.000000; Exposure Range min 10000, max 16440000;

GST_ARGUS: Running with following settings:
   Camera index = 0 
   Camera mode  = 0 
   Output Stream W = 1600 H = 1300 
   seconds to Run    = 0 
   Frame Rate = 59.999999 
GST_ARGUS: Setup Complete, Starting captures for 0 seconds
GST_ARGUS: Starting repeat capture requests.
CONSUMER: Producer has connected; continuing.
nvbuf_utils: dmabuf_fd -1 mapped entry NOT found
Error generated. /dvs/git/dirty/git-master_linux/multimedia/nvgstreamer/gst-nvarguscamera/gstnvarguscamerasrc.cpp, threadExecute:694 NvBufSurfaceFromFd Failed.
Error generated. /dvs/git/dirty/git-master_linux/multimedia/nvgstreamer/gst-nvarguscamera/gstnvarguscamerasrc.cpp, threadFunction:247 (propagating)
/GstPipeline:pipeline0/GstQTMux:qtmux0.GstPad:src: caps = video/quicktime, variant=(string)apple
/GstPipeline:pipeline0/GstFileSink:filesink0.GstPad:sink: caps = video/quicktime, variant=(string)apple
/GstPipeline:pipeline0/GstQTMux:qtmux0.GstPad:src: caps = video/quicktime, variant=(string)apple, streamheader=(buffer)< 000002446d6f6f760000006c6d76686400000000e1dfe430e1dfe43400000708000000000001000001000000000000000000000000010000000000000000000000000000000100000000000000000000000000004000000000000000000000000000000000000000000000000000000000000002000001937472616b0000005c746b686400000007e1dfe430e1dfe434000000010000000000000000000000000000000000000000000000000001000000000000000000000000000000010000000000000000000000000000400000000000000000000000000000f26d646961000000206d64686400000000e1dfe430e1dfe434000000000000000055c400000000002168646c7200000000000000000000000000000000000000000000000000000000a96d696e660000002168646c720000000064686c72616c6973000000000000000000000000000000002464696e660000001c6472656600000000000000010000000c616c6973000000010000005c7374626c000000107374736400000000000000000000001073747473000000000000000000000010737473630000000000000000000000147374737a000000000000000000000000000000107374636f00000000000000000000003d75647461000000356d657461000000000000002168646c72000000006d686c726d6469720000000000000000000000000000000008696c73740000003d75647461000000356d657461000000000000002168646c72000000006d686c726d6469720000000000000000000000000000000008696c7374 >
/GstPipeline:pipeline0/GstFileSink:filesink0.GstPad:sink: caps = video/quicktime, variant=(string)apple, streamheader=(buffer)< 000002446d6f6f760000006c6d76686400000000e1dfe430e1dfe43400000708000000000001000001000000000000000000000000010000000000000000000000000000000100000000000000000000000000004000000000000000000000000000000000000000000000000000000000000002000001937472616b0000005c746b686400000007e1dfe430e1dfe434000000010000000000000000000000000000000000000000000000000001000000000000000000000000000000010000000000000000000000000000400000000000000000000000000000f26d646961000000206d64686400000000e1dfe430e1dfe434000000000000000055c400000000002168646c7200000000000000000000000000000000000000000000000000000000a96d696e660000002168646c720000000064686c72616c6973000000000000000000000000000000002464696e660000001c6472656600000000000000010000000c616c6973000000010000005c7374626c000000107374736400000000000000000000001073747473000000000000000000000010737473630000000000000000000000147374737a000000000000000000000000000000107374636f00000000000000000000003d75647461000000356d657461000000000000002168646c72000000006d686c726d6469720000000000000000000000000000000008696c73740000003d75647461000000356d657461000000000000002168646c72000000006d686c726d6469720000000000000000000000000000000008696c7374 >
Got EOS from element "pipeline0".
Execution ended after 0:00:04.018130378
Setting pipeline to NULL ...
GST_ARGUS: Cleaning up
GST_ARGUS: Done Success
Freeing pipeline ...

cat /sys/kernel/debug/tracing/trace shows:

CaptureSchedule-4487    [000] ....   138.898443: tegra_channel_open: vi-output, ov2311 9-0060
 CaptureSchedule-4487    [000] ....   138.898601: tegra_channel_set_power: ov2311 9-0060 : 0x1
 CaptureSchedule-4487    [000] ....   138.898604: camera_common_s_power: status : 0x1
 CaptureSchedule-4487    [000] ....   139.199266: tegra_channel_set_power: 13e40000.host1x:nvcsi@15a00000- : 0x1
 CaptureSchedule-4487    [000] ....   139.199274: csi_s_power: enable : 0x1
 CaptureSchedule-4487    [000] ....   139.199537: tegra_channel_set_stream: enable : 0x1
 CaptureSchedule-4487    [000] ....   139.209026: tegra_channel_set_stream: 13e40000.host1x:nvcsi@15a00000- : 0x1
 CaptureSchedule-4487    [000] ....   139.209028: csi_s_stream: enable : 0x1
 CaptureSchedule-4487    [000] ....   139.209030: tegra_channel_set_stream: ov2311 9-0060 : 0x1
     kworker/3:3-101     [003] ....   139.292249: rtcpu_vinotify_event: tstamp:4957269010 cch:1 vi:0 tag:VIFALC_TDSTATE channel:0x0b frame:0 vi_tstamp:158632195136 data:0x759cc80010000000
     kworker/3:3-101     [003] ....   139.292251: rtcpu_vinotify_event: tstamp:4957269168 cch:1 vi:0 tag:VIFALC_TDSTATE channel:0x0b frame:0 vi_tstamp:158632201632 data:0x0000000031000001
     kworker/3:3-101     [003] ....   139.292251: rtcpu_vinotify_event: tstamp:4957945060 cch:1 vi:0 tag:VIFALC_TDSTATE channel:0x0b frame:0 vi_tstamp:158652546144 data:0x759cc50010000000
     kworker/3:3-101     [003] ....   139.292252: rtcpu_vinotify_event: tstamp:4957945198 cch:1 vi:0 tag:VIFALC_TDSTATE channel:0x0b frame:0 vi_tstamp:158652552640 data:0x0000000031000002
     kworker/3:3-101     [003] ....   139.292252: rtcpu_vinotify_event: tstamp:4958283048 cch:1 vi:0 tag:FS channel:0x00 frame:1 vi_tstamp:158661243040 data:0x0000000100000011
     kworker/3:3-101     [003] ....   139.292252: rtcpu_vinotify_event: tstamp:4958283185 cch:1 vi:0 tag:ATOMP_FS channel:0x00 frame:1 vi_tstamp:158661243040 data:0x0000000000000800
     kworker/3:3-101     [003] ....   139.292252: rtcpu_vinotify_event: tstamp:4958283338 cch:1 vi:0 tag:CHANSEL_PXL_SOF channel:0x0b frame:1 vi_tstamp:158661715072 data:0x0000000000000001
     kworker/3:3-101     [003] ....   139.292253: rtcpu_vinotify_event: tstamp:4958283470 cch:1 vi:0 tag:VIFALC_ACTIONLST channel:0x0b frame:1 vi_tstamp:158661716640 data:0x0000000008020001
     kworker/3:3-101     [003] ....   139.292253: rtcpu_vinotify_event: tstamp:4958621135 cch:1 vi:0 tag:ATOMP_FRAME_NLINES_DONE channel:0x0b frame:1 vi_tstamp:158667816320 data:0x0000000000000000
     kworker/3:3-101     [003] ....   139.292253: rtcpu_vinotify_event: tstamp:4958621269 cch:1 vi:0 tag:VIFALC_ACTIONLST channel:0x0b frame:1 vi_tstamp:158667817792 data:0x0000000002020001
     kworker/3:3-101     [003] ....   139.292253: rtcpu_vinotify_event: tstamp:4958621420 cch:1 vi:0 tag:ATOMP_FRAME_NLINES_DONE channel:0x0b frame:1 vi_tstamp:158673918336 data:0x0000000000000000
     kworker/3:3-101     [003] ....   139.292253: rtcpu_vinotify_event: tstamp:4958621552 cch:1 vi:0 tag:VIFALC_ACTIONLST channel:0x0b frame:1 vi_tstamp:158673919808 data:0x0000000002020001
     kworker/3:3-101     [003] ....   139.292253: rtcpu_vinotify_event: tstamp:4958640252 cch:1 vi:0 tag:CHANSEL_PXL_EOF channel:0x0b frame:1 vi_tstamp:158676403712 data:0x0000000005130002
     kworker/3:3-101     [003] ....   139.292253: rtcpu_vinotify_event: tstamp:4958640384 cch:1 vi:0 tag:FE channel:0x00 frame:1 vi_tstamp:158676404512 data:0x0000000100000021
     kworker/3:3-101     [003] ....   139.292254: rtcpu_vinotify_event: tstamp:4958640540 cch:1 vi:0 tag:CHANSEL_SHORT_FRAME channel:0x02 frame:1 vi_tstamp:158676404512 data:0x0000000000000800
     kworker/3:3-101     [003] ....   139.292254: rtcpu_vinotify_event: tstamp:4958640675 cch:1 vi:0 tag:VIFALC_ACTIONLST channel:0x0b frame:1 vi_tstamp:158676413280 data:0x0000000001020001
     kworker/3:3-101     [003] ....   139.348263: rtcpu_vinotify_event: tstamp:4958959168 cch:1 vi:0 tag:ATOMP_FE channel:0x00 frame:1 vi_tstamp:158676404512 data:0x0000000000000800
     kworker/3:3-101     [003] ....   139.348266: rtcpu_vinotify_event: tstamp:4958959304 cch:1 vi:0 tag:ATOMP_FRAME_DONE channel:0x0b frame:1 vi_tstamp:158676404640 data:0x0000000000000000
     kworker/3:3-101     [003] ....   139.348266: rtcpu_vinotify_event: tstamp:4958959457 cch:1 vi:0 tag:FS channel:0x00 frame:2 vi_tstamp:158682087904 data:0x0000000200000011
     kworker/3:3-101     [003] ....   139.348266: rtcpu_vinotify_event: tstamp:4958959593 cch:1 vi:0 tag:ATOMP_FS channel:0x00 frame:2 vi_tstamp:158682087936 data:0x0000000000000800
     kworker/3:3-101     [003] ....   139.348267: rtcpu_vinotify_event: tstamp:4958959746 cch:1 vi:0 tag:CHANSEL_PXL_SOF channel:0x0b frame:2 vi_tstamp:158682560416 data:0x0000000000000001
     kworker/3:3-101     [003] ....   139.348267: rtcpu_vinotify_event: tstamp:4959297241 cch:1 vi:0 tag:ATOMP_FRAME_NLINES_DONE channel:0x0b frame:2 vi_tstamp:158688661632 data:0x0000000000000000
     kworker/3:3-101     [003] ....   139.348267: rtcpu_vinotify_event: tstamp:4959297395 cch:1 vi:0 tag:ATOMP_FRAME_NLINES_DONE channel:0x0b frame:2 vi_tstamp:158694763616 data:0x0000000000000000
     kworker/3:3-101     [003] ....   139.348268: rtcpu_vinotify_event: tstamp:4959297529 cch:1 vi:0 tag:CHANSEL_PXL_EOF channel:0x0b frame:2 vi_tstamp:158697249056 data:0x0000000005130002
     kworker/3:3-101     [003] ....   139.348268: rtcpu_vinotify_event: tstamp:4959297683 cch:1 vi:0 tag:ATOMP_FRAME_DONE channel:0x0b frame:2 vi_tstamp:158697249632 data:0x0000000000000000
     kworker/3:3-101     [003] ....   139.348268: rtcpu_vinotify_event: tstamp:4959297814 cch:1 vi:0 tag:FE channel:0x00 frame:2 vi_tstamp:158697249824 data:0x0000000200000021
     kworker/3:3-101     [003] ....   139.348268: rtcpu_vinotify_event: tstamp:4959297966 cch:1 vi:0 tag:CHANSEL_SHORT_FRAME channel:0x02 frame:2 vi_tstamp:158697249824 data:0x0000000000000800
     kworker/3:3-101     [003] ....   139.348269: rtcpu_vinotify_event: tstamp:4959298100 cch:1 vi:0 tag:ATOMP_FE channel:0x00 frame:2 vi_tstamp:158697249824 data:0x0000000000000800
     kworker/3:3-101     [003] ....   139.348270: rtcpu_vinotify_error: tstamp:4959482211 cch:1 vi:0 tag:CHANSEL_NOMATCH channel:0x02 frame:3 vi_tstamp:158703405728 data:0x0000000000000569
     kworker/3:3-101     [003] ....   139.348270: rtcpu_vinotify_event: tstamp:4959635314 cch:1 vi:0 tag:FS channel:0x00 frame:3 vi_tstamp:158702933216 data:0x0000000300000011
     kworker/3:3-101     [003] ....   139.348271: rtcpu_vinotify_event: tstamp:4959635447 cch:1 vi:0 tag:CHANSEL_NOMATCH channel:0x02 frame:3 vi_tstamp:158703405728 data:0x0000000000000569
     kworker/3:3-101     [003] ....   139.348271: rtcpu_vinotify_event: tstamp:4959973343 cch:1 vi:0 tag:FE channel:0x00 frame:3 vi_tstamp:158718095168 data:0x0000000300000021
     kworker/3:3-101     [003] ....   139.348271: rtcpu_vinotify_event: tstamp:4960118762 cch:1 vi:0 tag:FS channel:0x00 frame:4 vi_tstamp:158723778560 data:0x0000000400000011
     kworker/3:3-101     [003] ....   139.348271: rtcpu_vinotify_error: tstamp:4960133626 cch:1 vi:0 tag:CHANSEL_NOMATCH channel:0x02 frame:4 vi_tstamp:158724251040 data:0x0000000000000569
     kworker/3:3-101     [003] ....   139.348272: rtcpu_vinotify_event: tstamp:4960446563 cch:1 vi:0 tag:CHANSEL_NOMATCH channel:0x02 frame:4 vi_tstamp:158724251040 data:0x0000000000000569
     kworker/3:3-101     [003] ....   139.408259: rtcpu_vinotify_error: tstamp:4960785048 cch:1 vi:0 tag:CHANSEL_NOMATCH channel:0x02 frame:5 vi_tstamp:158745096384 data:0x0000000000000569
     kworker/3:3-101     [003] ....   139.408262: rtcpu_vinotify_event: tstamp:4960785492 cch:1 vi:0 tag:FE channel:0x00 frame:4 vi_tstamp:158738940480 data:0x0000000400000021
     kworker/3:3-101     [003] ....   139.408263: rtcpu_vinotify_event: tstamp:4960785641 cch:1 vi:0 tag:FS channel:0x00 frame:5 vi_tstamp:158744623872 data:0x0000000500000011
     kworker/3:3-101     [003] ....   139.408263: rtcpu_vinotify_event: tstamp:4961122651 cch:1 vi:0 tag:CHANSEL_NOMATCH channel:0x02 frame:5 vi_tstamp:158745096384 data:0x0000000000000569
     kworker/3:3-101     [003] ....   139.408263: rtcpu_vinotify_error: tstamp:4961436455 cch:1 vi:0 tag:CHANSEL_NOMATCH channel:0x02 frame:6 vi_tstamp:158765941696 data:0x0000000000000569
     kworker/3:3-101     [003] ....   139.408263: rtcpu_vinotify_event: tstamp:4961460758 cch:1 vi:0 tag:FE channel:0x00 frame:5 vi_tstamp:158759785792 data:0x0000000500000021
     kworker/3:3-101     [003] ....   139.408264: rtcpu_vinotify_event: tstamp:4961460890 cch:1 vi:0 tag:FS channel:0x00 frame:6 vi_tstamp:158765469184 data:0x0000000600000011

And it repeats indefinitely, incrementing the frame number.

Any thoughts?

enrique.ramirez · January 31, 2024, 2:45pm

You are getting CHANSEL_SHORT_FRAME, which is usually related to a mismatch of the format/frame-size sent by the camera against what is configured on the driver to be received.
You also got the CHANSEL_NOMATCH, which is expecting RAW10, but looks like the data received is not matching.

Could you double-check that the camera mode is being configured correctly? Also, could you check if it’s sending more metadata-lines than the defined on the device-tree (embedded_metadata_height)

Regards,
-Enrique

kaz.khaki · January 31, 2024, 3:07pm

After setting embedded_metadata_height the data comes through, thank you.

system · February 14, 2024, 3:08pm

This topic was automatically closed 14 days after the last reply. New replies are no longer allowed.

Topic		Replies	Views
GMSL Camera fail on Orin JatPack 5.1.2 Jetson AGX Orin camera , board-design	4	330	March 20, 2024
Porting new camera sensor driver Jetson Orin NX camera	19	1228	February 15, 2024
Ov428 drives tegra-capture-vi timeout (jetpack 5.1.3-b29) Jetson Orin Nano camera	41	302	July 17, 2024
No frame from IMX415 on orin devkit Jetson AGX Orin camera	3	511	November 6, 2023
Dual imx708 cameras on Orin NX: Getting nvbuf_utils: dmabuf_fd -1 mapped entry NOT found Jetson Orin NX camera , gstreamer	12	533	May 21, 2024
JetPack 5.1.3: NULL VI channel received, IMX586 driver Jetson Orin NX camera	7	44	October 9, 2024
Timeout on /dev/video3 capture Jetson AGX Orin camera	9	464	February 1, 2024
Jetson_Linux 34.1 : vi_capture_control_message: NULL VI channel received Jetson AGX Xavier camera	47	2689	June 13, 2023
Camera fails to capture frames with VIFALC_TDSTATE error Jetson AGX Orin camera	25	964	February 14, 2024
Don't get stream from Onsemi AR0234 on CAM0 at Orin Nano Developer Kit. Get Error 0x10000000 at register NVCSI_PHY_1_CILA_INTR_0_STATUS_CILA_0 Jetson Orin Nano camera , kernel	16	1457	August 30, 2023

OV2311 Custom Driver Issues

Related topics