ShaneCCC:
Below message show the PIXEL_SHORT_LINE that could be the width is’t as expect.
kworker/5:2-217 [005] …1 1396.593844: rtcpu_vinotify_handle_msg: tstamp:43946060227 tag:CHANSEL_FAULT_FE channel:0x01 frame:0 vi_tstamp:996384232 data:0x00000001
thanks for your response, and happy new year ^_^
During this holiday, we have made colorbar test mode from tc358748, image size is 384 x 228 with raw10 (we use MEDIA_BUS_FMT_SBGGR10_1X10 for testing purpose), we could get the data from tc358748 correctly, with v4l2-ctrl, and trace shows bunch of these messages
kworker/0:3-894 [000] ...1 1940.060976: rtcpu_vinotify_handle_msg: tstamp:60929085318 tag:CHANSEL_PXL_EOF channel:0x00 frame:0 vi_tstamp:799542262 data:0x011f0002
kworker/0:3-894 [000] ...1 1940.060979: rtcpu_vinotify_handle_msg: tstamp:60929087621 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:799544506 data:0x00000000
kworker/0:3-894 [000] ...1 1940.113052: rtcpu_vinotify_handle_msg: tstamp:60929458323 tag:CHANSEL_PXL_SOF channel:0x00 frame:0 vi_tstamp:799915598 data:0x00000001
kworker/0:3-894 [000] ...1 1940.113093: rtcpu_vinotify_handle_msg: tstamp:60929458571 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:799915615 data:0x00000000
kworker/0:3-894 [000] ...1 1940.113103: rtcpu_vinotify_handle_msg: tstamp:60929464887 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:0 vi_tstamp:799922297 data:0x08000000
according to parker_trm, system is happy with image data from tc358748
Now, we are moving to tc358748 parallel data capture config, we met new issues
Here are the dmesg info
[ 2185.424599] tegra-vi4 15700000.vi: vi4_power_on:vi4 power on is called with tc358748
[ 2185.434245] nvcsi 150c0000.nvcsi: tegra_csi_power set csi power 1 with tc358748
[ 2185.441706] nvcsi 150c0000.nvcsi: tegra_csi_s_power set csi subdevice power 1 with tc358748
[ 2185.450120] tc358748 0-000e: camera_common_mclk_enable: enable MCLK with 24000000 Hz
[ 2185.457924] tc358748 0-000e: camera_common_dpd_disable: csi 0
[ 2185.463724] tc358748 0-000e: tc358748_power_on: power on
[ 2185.469393] tc358748 0-000e: tc358748_s_ctrl: going to set ctrl
[ 2185.475378] tc358748 0-000e: tc358748_s_ctrl: setting config height 288
[ 2185.482038] tc358748 0-000e: tc358748_s_ctrl: going to set ctrl
[ 2185.487977] tc358748 0-000e: tc358748_s_ctrl: setting config write mode 4
[ 2185.495518] video4linux video0: vi4_channel_start_streaming:vi4 start streaming with tc358748
[ 2185.504091] tc358748 0-000e: camera_common_g_fmt++
[ 2185.508919] video4linux video0: vi4_channel_start_streaming:height and width from s_data 384 288
[ 2185.521085] tegra-vi4 15700000.vi: Create Surface with imgW=384, imgH=288, memFmt=32
[ 2185.531901] tegra-vi4 15700000.vi: WAR:Calculation not precise.Ignore BW request failure
[ 2185.540324] nvcsi 150c0000.nvcsi: tegra_csi_s_stream going to set streaming 1 with tc358748
[ 2185.550771] nvcsi 150c0000.nvcsi: csi port:0
[ 2185.555062] nvcsi 150c0000.nvcsi: csi4_mipi_cal mipi calibrated suceessfully
[ 2186.059574] tegra_mipi_cal 3990000.mipical: Mipi cal timeout,val:107861, lanes:300000
[ 2186.067602] tegra_mipi_cal 3990000.mipical: MIPI_CAL_CTRL 0x04 0x2a000010
[ 2186.076031] tegra_mipi_cal 3990000.mipical: CIL_MIPI_CAL_STATUS 0x0c 0x00107861
[ 2186.084702] tegra_mipi_cal 3990000.mipical: CIL_MIPI_CAL_STATUS_2 0x10 0x00000000
[ 2186.093185] tegra_mipi_cal 3990000.mipical: CILA_MIPI_CAL_CONFIG 0x18 0x00200000
[ 2186.101633] tegra_mipi_cal 3990000.mipical: CILB_MIPI_CAL_CONFIG 0x1c 0x00200000
[ 2186.110113] tegra_mipi_cal 3990000.mipical: CILC_MIPI_CAL_CONFIG 0x20 0x00000000
[ 2186.118464] tegra_mipi_cal 3990000.mipical: CILD_MIPI_CAL_CONFIG 0x24 0x00000000
[ 2186.126820] tegra_mipi_cal 3990000.mipical: CILE_MIPI_CAL_CONFIG 0x28 0x00000000
[ 2186.135168] tegra_mipi_cal 3990000.mipical: CILF_MIPI_CAL_CONFIG 0x2c 0x00000000
[ 2186.143511] tegra_mipi_cal 3990000.mipical: DSIA_MIPI_CAL_CONFIG 0x3c 0x00000200
[ 2186.151816] tegra_mipi_cal 3990000.mipical: DSIB_MIPI_CAL_CONFIG 0x40 0x00000200
[ 2186.160126] tegra_mipi_cal 3990000.mipical: DSIC_MIPI_CAL_CONFIG 0x44 0x00000200
[ 2186.168432] tegra_mipi_cal 3990000.mipical: DSID_MIPI_CAL_CONFIG 0x48 0x00000200
[ 2186.176741] tegra_mipi_cal 3990000.mipical: MIPI_BIAS_PAD_CFG0 0x5c 0x00000000
[ 2186.185051] tegra_mipi_cal 3990000.mipical: MIPI_BIAS_PAD_CFG1 0x60 0x00000000
[ 2186.193379] tegra_mipi_cal 3990000.mipical: MIPI_BIAS_PAD_CFG2 0x64 0x00010010
[ 2186.201736] tegra_mipi_cal 3990000.mipical: DSIA_MIPI_CAL_CONFIG_2 0x68 0x00000002
[ 2186.210062] tegra_mipi_cal 3990000.mipical: DSIB_MIPI_CAL_CONFIG_2 0x6c 0x00000002
[ 2186.218363] tegra_mipi_cal 3990000.mipical: DSIC_MIPI_CAL_CONFIG_2 0x74 0x00000002
[ 2186.226668] tegra_mipi_cal 3990000.mipical: DSID_MIPI_CAL_CONFIG_2 0x78 0x00000002
[ 2186.234965] nvcsi 150c0000.nvcsi: tegra_csi_start_streaming going to start streaming 0 with tc358748
[ 2186.244111] nvcsi 150c0000.nvcsi: csi4_start_streaming ports index=0, lanes=1
[ 2186.251269] nvcsi 150c0000.nvcsi: csi4_stream_init
[ 2186.256095] nvcsi 150c0000.nvcsi: csi4_stream_config
[ 2186.261085] nvcsi 150c0000.nvcsi: csi4_stream_config (0) read VC0_DPCM_CTRL = 00000000
[ 2186.269015] nvcsi 150c0000.nvcsi: csi4_phy_config port 0 lanes 1 status 1
[ 2186.275816] nvcsi 150c0000.nvcsi: NVCSI_CIL_CONFIG = 00000000
[ 2186.532670] tegra-vi4 15700000.vi: Status: 4 channel:00 frame:0000
[ 2186.538983] tegra-vi4 15700000.vi: timestamp sof 2196202530272 eof 2196211840480 data 0x01200040
[ 2186.548606] tegra-vi4 15700000.vi: capture_id 1170 stream 0 vchan 0
[ 2186.556169] video4linux video0: vi4_channel_stop_streaming:vi2 stop streaming with tc358748
[ 2187.520157] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! 8748 mod err = -11
[ 2188.527859] tegra-vi4 15700000.vi: ATOMP_FE syncpt timeout!
[ 2188.739897] nvcsi 150c0000.nvcsi: tegra_csi_s_stream going to set streaming 0 with tc358748
[ 2188.748414] nvcsi 150c0000.nvcsi: tegra_csi_stop_streaming going to stop streaming 0 with tc358748
[ 2188.757372] nvcsi 150c0000.nvcsi: csi4_stop_streaming ports index=0, lanes=1
[ 2188.764433] nvcsi 150c0000.nvcsi: csi4_phy_config port 0 lanes 1 status 0
[ 2188.771221] nvcsi 150c0000.nvcsi: NVCSI_CIL_CONFIG = 00000001
[ 2188.776971] nvcsi 150c0000.nvcsi: csi4_stream_check_status
[ 2188.782460] nvcsi 150c0000.nvcsi: csi4_stream_check_status (0) ERROR_STATUS2VI_VC2 = 0x00000008
[ 2188.791237] nvcsi 150c0000.nvcsi: csi4_stream_check_status (0) INTR_STATUS 0x00000800
[ 2188.800120] nvcsi 150c0000.nvcsi: csi4_stream_check_status (0) ERR_INTR_STATUS 0x00000800
[ 2188.808494] nvcsi 150c0000.nvcsi: csi4_cil_check_status 277
[ 2188.831413] tegra-vi4 15700000.vi: WAR:Calculation not precise.Ignore BW request failure
[ 2188.848477] tegra-vi4 15700000.vi: vi4_power_off:vi2 power off is called with tc358748
[ 2188.856419] tc358748 0-000e: tc358748_power_off: power off
[ 2188.861962] tc358748 0-000e: camera_common_dpd_enable: csi 0
[ 2188.867648] tc358748 0-000e: camera_common_mclk_disable: disable MCLK
[ 2188.874417] nvcsi 150c0000.nvcsi: tegra_csi_power set csi power 0 with tc358748
[ 2188.881744] nvcsi 150c0000.nvcsi: tegra_csi_s_power set csi subdevice power 0 with tc358748
Here are the trace info:
kworker/0:3-894 [000] ...1 2775.987369: rtos_queue_peek_from_isr_failed: tstamp:87051644203 queue:0x0b4a3c58
kworker/0:3-894 [000] ...1 2775.987373: rtcpu_start: tstamp:87051646134
kworker/0:3-894 [000] ...1 2776.143488: rtos_queue_peek_from_isr_failed: tstamp:87056645558 queue:0x0b4a3c58
kworker/0:3-894 [000] ...1 2776.299390: rtos_queue_peek_from_isr_failed: tstamp:87061645617 queue:0x0b4a3c58
kworker/0:3-894 [000] ...1 2776.455392: rtos_queue_peek_from_isr_failed: tstamp:87066646107 queue:0x0b4a3c58
kworker/0:3-894 [000] ...1 2776.623483: rtos_queue_peek_from_isr_failed: tstamp:87071646595 queue:0x0b4a3c58
kworker/0:3-894 [000] ...1 2776.734449: rtcpu_vinotify_handle_msg: tstamp:87075233333 tag:CSIMUX_STREAM channel:0xff frame:0 vi_tstamp:1175886999 data:0x00000001
kworker/0:3-894 [000] ...1 2776.783370: rtos_queue_peek_from_isr_failed: tstamp:87076647085 queue:0x0b4a3c58
kworker/0:3-894 [000] ...1 2776.939432: rtos_queue_peek_from_isr_failed: tstamp:87081647590 queue:0x0b4a3c58
kworker/0:3-894 [000] ...1 2776.991402: rtcpu_vinotify_handle_msg: tstamp:87082681482 tag:CHANSEL_PXL_SOF channel:0x00 frame:0 vi_tstamp:1183335009 data:0x00000001
kworker/0:3-894 [000] ...1 2776.991406: rtcpu_vinotify_handle_msg: tstamp:87082681628 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:1183335027 data:0x00000000
kworker/0:3-894 [000] ...1 2776.991409: rtcpu_vinotify_handle_msg: tstamp:87082685023 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:0 vi_tstamp:1183338691 data:0x08000000
kworker/0:3-894 [000] ...1 2776.991411: rtcpu_vinotify_handle_msg: tstamp:87082966908 tag:CHANSEL_PXL_EOF channel:0x00 frame:0 vi_tstamp:1183620441 data:0x011f0002
kworker/0:3-894 [000] ...1 2776.991414: rtcpu_vinotify_handle_msg: tstamp:87082967006 tag:CHANSEL_FAULT channel:0x00 frame:0 vi_tstamp:1183620489 data:0x01200040
kworker/0:3-894 [000] ...1 2776.991416: rtcpu_vinotify_handle_msg: tstamp:87082967508 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:0 vi_tstamp:1183621214 data:0x08000000
kworker/0:3-894 [000] ...1 2776.991418: rtcpu_vinotify_handle_msg: tstamp:87082971891 tag:CHANSEL_FAULT_FE channel:0x01 frame:0 vi_tstamp:1183625384 data:0x00000001
kworker/0:3-894 [000] ...1 2776.991421: rtcpu_vinotify_handle_msg: tstamp:87082972018 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:1183625387 data:0x00000000
kworker/0:3-894 [000] ...1 2777.095406: rtos_queue_peek_from_isr_failed: tstamp:87086648103 queue:0x0b4a3c58
kworker/0:3-894 [000] ...1 2777.303400: rtos_queue_peek_from_isr_failed: tstamp:87091648603 queue:0x0b4a3c58
kworker/0:3-894 [000] ...1 2777.459423: rtos_queue_peek_from_isr_failed: tstamp:87096649120 queue:0x0b4a3c58
kworker/0:3-894 [000] ...1 2777.615401: rtos_queue_peek_from_isr_failed: tstamp:87101649619 queue:0x0b4a3c58
With colorbar test, if I set active_h smaller than correct value, I will get almost same error, especially this one:
CHANSEL_FAULT channel:0x00 frame:0 vi_tstamp:423072523 data:0x011f0040
Image config is also 384 x 288 with raw 10;
So, I tried adjust active_h, with values <= 288; I get same trace result. When I set active_h > 288, I get this
kworker/0:3-894 [000] ...1 2825.741924: rtos_queue_peek_from_isr_failed: tstamp:88605594035 queue:0x0b4a3c58
kworker/0:3-894 [000] ...1 2825.843467: rtcpu_vinotify_handle_msg: tstamp:88609415987 tag:CSIMUX_STREAM channel:0xff frame:0 vi_tstamp:2710069644 data:0x00000001
kworker/0:3-894 [000] ...1 2825.894928: rtos_queue_peek_from_isr_failed: tstamp:88610594492 queue:0x0b4a3c58
kworker/0:3-894 [000] ...1 2826.050928: rtos_queue_peek_from_isr_failed: tstamp:88615594997 queue:0x0b4a3c58
<idle>-0 [000] d.h1 2826.078905: arm_smmu_context_fault: Unhandled context fault: iova=0x5a5b6000, fsynr=0x13, cb=19, sid=4(0x4 - VI), pgd=26c2f9003 pud=26c2f9003, pmd=26c2fa003, pte=0
<idle>-0 [000] dnH1 2826.079000: tegra_mcerr_hard_irq: MCERR detected.
irq/55-mc_statu-40 [005] .... 2826.079048: log_fault.part.1: (255) csw_viw: MC request violates VPR requirements
<idle>-0 [000] dnH1 2826.079051: tegra_mcerr_hard_irq: MCERR detected.
<idle>-0 [000] dnH1 2826.079066: tegra_mcerr_hard_irq: MCERR detected.
<idle>-0 [000] dnH1 2826.079070: tegra_mcerr_hard_irq: MCERR detected.
irq/55-mc_statu-40 [005] .... 2826.079071: log_fault.part.1: status = 0x00337072; addr = 0x3ffffffc0
<idle>-0 [000] dnH1 2826.079076: tegra_mcerr_hard_irq: MCERR detected.
<idle>-0 [000] dnH1 2826.079081: tegra_mcerr_hard_irq: MCERR detected.
irq/55-mc_statu-40 [005] .... 2826.079085: log_fault.part.1: secure: yes, access-type: write
<idle>-0 [000] dnH1 2826.079106: tegra_mcerr_hard_irq: MCERR detected.
<idle>-0 [000] dnH1 2826.079111: tegra_mcerr_hard_irq: MCERR detected.
<idle>-0 [000] dnH1 2826.079138: tegra_mcerr_hard_irq: MCERR detected.
<idle>-0 [000] dnH1 2826.079144: tegra_mcerr_hard_irq: MCERR detected.
irq/55-mc_statu-40 [005] .... 2826.079146: tegra_mcerr_thread: Too many MC errors; throttling prints
<idle>-0 [000] dnH1 2826.079152: tegra_mcerr_hard_irq: MCERR detected.
<idle>-0 [000] dnH1 2826.079157: tegra_mcerr_hard_irq: MCERR detected.
kworker/0:3-894 [000] ...1 2826.102927: rtcpu_vinotify_handle_msg: tstamp:88616695508 tag:CHANSEL_PXL_SOF channel:0x00 frame:0 vi_tstamp:2717349039 data:0x00000001
kworker/0:3-894 [000] ...1 2826.102931: rtcpu_vinotify_handle_msg: tstamp:88616695656 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:2717349056 data:0x00000000
kworker/0:3-894 [000] ...1 2826.102934: rtcpu_vinotify_handle_msg: tstamp:88616698952 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:0 vi_tstamp:2717352611 data:0x08000000
kworker/0:3-894 [000] ...1 2826.102936: rtcpu_vinotify_handle_msg: tstamp:88616981423 tag:CHANSEL_PXL_EOF channel:0x00 frame:0 vi_tstamp:2717635097 data:0x01200002
kworker/0:3-894 [000] ...1 2826.102939: rtcpu_vinotify_handle_msg: tstamp:88616985696 tag:CHANSEL_FAULT channel:0x00 frame:0 vi_tstamp:2717639358 data:0x01210040
kworker/0:3-894 [000] ...1 2826.102941: rtcpu_vinotify_handle_msg: tstamp:88616986584 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:0 vi_tstamp:2717639903 data:0x08000000
kworker/0:3-894 [000] ...1 2826.102943: rtcpu_vinotify_handle_msg: tstamp:88616986693 tag:CHANSEL_FAULT_FE channel:0x01 frame:0 vi_tstamp:2717639907 data:0x00000001
kworker/0:3-894 [000] ...1 2826.102946: rtcpu_vinotify_handle_msg: tstamp:88616986820 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:2717639910 data:0x00000000
kworker/0:3-894 [000] ...1 2826.206925: rtos_queue_peek_from_isr_failed: tstamp:88620595506 queue:0x0b4a3c58
kworker/0:3-894 [000] ...1 2826.362934: rtos_queue_peek_from_isr_failed: tstamp:88625596011 queue:0x0b4a3c58
When I set active_h larger enough like 900, I will get this: