timeout due to delayed camera init

Hi,

Currently we are able to perform video capture using a Gstreamer pipeline with nvcamerasrc, but due to project requirements sometimes we require to start the pipeline and the video source will provide buffers later, this is causing timeouts being reported by the kernel, nvcamerasrc daemon crash and making capture not possible. We are using a Tx2 with JetPack 3.2.1, video source is controlled via i2c and information is provided by MIPI.

Is it possible to increase the amount of time for the timeouts to happen in order to avoid them?

These are some of the messages that I get when the cameras are delayed providing buffers:


[ 103.912406] fence timeout on [ffffffc1a326b600] after 1500ms
[ 103.912836] fence timeout on [ffffffc1cb185c00] after 1500ms
[ 103.912854] name=[nvhost_sync:58], current value=548 waiting value=549
[ 103.912866] ---- mlocks ----
[ 103.912886] 8: locked by channel 7

[ 103.912913] ---- syncpts ----
[ 103.912936] id 4 (disp_d) min 118 max 118 refs 1 (previous client : )
[ 103.912947] id 5 (disp_e) min 2 max 2 refs 1 (previous client : )
[ 103.912960] id 7 (vblank1) min 5894 max 0 refs 1 (previous client : )

[ 103.914369] ffffffc1a2523400: JOB, syncpt_id=22, syncpt_val=6604, first_get=00000448, timeout=10000, num_slots=19

[ 103.914621] ffffffc1b1f58c00: JOB, syncpt_id=39, syncpt_val=686, first_get=000007a8, timeout=0, num_slots=6

[ 103.915096] ---- host syncpt irq status ----

[ 103.915103] syncpt_thresh_cpu0_int_status(0) = 0x00000000
[ 103.915110] syncpt_thresh_cpu0_int_status(1) = 0x00000000

[ 104.890237] name=[nvhost_sync:60], current value=498 waiting value=499
[ 104.900593] ---- mlocks ----
[ 104.903526] 8: locked by channel 7

[ 104.909979] ---- syncpts ----
[ 104.913358] id 4 (disp_d) min 118 max 118 refs 1 (previous client : )
[ 104.920229] id 5 (disp_e) min 2 max 2 refs 1 (previous client : )


Thank you for your time.
Regards,
Carlos A

hello Carlos001,

we had some implementation to handle the streaming issue.
could you please apply the patches from Topic 1037809
thanks

Hi Jerry,

I’m part of the team working on the project Carlos mentioned. I tested the patches you provided but no positive results, still have more or less the same log (basically some error related to the syncpoint timeout issue). Additionally, while displaying the streaming I noticed that the fps are know being affected (specifically when the sensor gain is adjusted the fps drop abruptly).

We require that the pipelines set up in a specific order, we’ve managed to solve this but the problem we have is that if the set up of the pipeline for the last camera (configured to give a broadcast initialization signal) takes too long, the daemon ends crashing due to this timeout. We’ve noticed that the timeout is more likely to happen the more pipelines we set up, currently we’re using 6 cameras with a resolution of 2028x1520@60fps. I’ll append some log. Any suggestions are well appreciated.

Log from successful run

[   54.605864] imx477 43-001a: imx477_power_on: power on
[   54.612447] imx477 43-001a: imx477_set_frame_length: val: 2145
[   54.619774] imx477 43-001a: imx477_set_frame_length: vmax: 2145
[   54.634647] imx477 43-001a: imx477_set_coarse_time: val: 2135
[   54.685459] misc tegra_camera_ctrl: ISO BW req 2147483647 > 3925327 (max) capping to max
[   54.693574] misc tegra_camera_ctrl: vi_v4l2_update_isobw: requested iso bw is larger than max
[   54.704628] imx477 42-001a: imx477_power_on: power on
[   54.713103] imx477 43-001a: imx477_s_stream: enable 1 mode 3
[   54.718852] imx477 42-001a: imx477_set_frame_length: val: 2145
[   54.727047] imx477 42-001a: imx477_set_frame_length: vmax: 2145
[   54.733357] imx477 42-001a: imx477_set_coarse_time: val: 2135
[   54.803640] misc tegra_camera_ctrl: ISO BW req 4294967294 > 3925327 (max) capping to max
[   54.811943] misc tegra_camera_ctrl: vi_v4l2_update_isobw: requested iso bw is larger than max
[   54.823506] imx477 41-001a: imx477_power_on: power on
[   54.829196] imx477 41-001a: imx477_set_frame_length: val: 2145
[   54.831539] imx477 42-001a: imx477_s_stream: enable 1 mode 3
[   54.844038] imx477 41-001a: imx477_set_frame_length: vmax: 2145
[   54.850501] imx477 41-001a: imx477_set_coarse_time: val: 2135
[   54.891125] imx477 43-001a: imx477_s_stream: slave xvs setting
[   54.903422] imx477 43-001a: imx477_s_stream:i2c table write success
[   54.909771] imx477 43-001a: imx477_s_stream: s_data->mode 3
[   54.926822] misc tegra_camera_ctrl: ISO BW req 6442450941 > 3925327 (max) capping to max
[   54.935027] misc tegra_camera_ctrl: vi_v4l2_update_isobw: requested iso bw is larger than max
[   54.954197] imx477 41-001a: imx477_s_stream: enable 1 mode 3
[   54.966591] imx477 40-0010: imx477_power_on: power on
[   54.972275] imx477 40-0010: imx477_set_frame_length: val: 2145
[   54.982457] imx477 40-0010: imx477_set_frame_length: vmax: 2145
[   54.988555] imx477 40-0010: imx477_set_coarse_time: val: 2135
[   55.042584] imx477 43-001a:  Write-> RegName:(IMX477_SLAVE_ADD_EN_2ND_ADDR), Addr:0x(3010), OldValue:(1), NewValue:(1) 
[   55.053954] misc tegra_camera_ctrl: ISO BW req 8589934588 > 3925327 (max) capping to max
[   55.054313] imx477 43-001a:  Write-> RegName:(IMX477_SLAVE_ADD_ACKEN_2ND_ADDR), Addr:0x(3011), OldValue:(0), NewValue:(0) 
[   55.054315] imx477 43-001a: imx477_s_stream: 2nd slave address enabled
[   55.054320] imx477 43-001a: imx477_set_gain :val = 256, digital gain = 256, analog gain = 256
[   55.058295] imx477 43-001a: imx477_set_frame_length: val: 2145
[   55.060169] imx477 43-001a: imx477_set_frame_length: vmax: 2145
[   55.060175] imx477 43-001a: imx477_set_coarse_time: val: 2135
[   55.062103] imx477 43-001a: imx477_s_stream: s_stream finished 
[   55.111688] misc tegra_camera_ctrl: vi_v4l2_update_isobw: requested iso bw is larger than max
[   55.130467] imx477 40-0010: imx477_s_stream: enable 1 mode 3
[   55.142592] imx477 42-001a: imx477_s_stream: slave xvs setting
[   55.159314] imx477 42-001a: imx477_s_stream:i2c table write success
[   55.165626] imx477 42-001a: imx477_s_stream: s_data->mode 3
[   55.262803] imx477 41-001a: imx477_s_stream: slave xvs setting
[   55.281157] imx477 41-001a: imx477_s_stream:i2c table write success
[   55.287501] imx477 41-001a: imx477_s_stream: s_data->mode 3
[   55.295147] imx477 42-001a:  Write-> RegName:(IMX477_SLAVE_ADD_EN_2ND_ADDR), Addr:0x(3010), OldValue:(1), NewValue:(1) 
[   55.307440] imx477 42-001a:  Write-> RegName:(IMX477_SLAVE_ADD_ACKEN_2ND_ADDR), Addr:0x(3011), OldValue:(0), NewValue:(0) 
[   55.318684] imx477 42-001a: imx477_s_stream: 2nd slave address enabled
[   55.325294] imx477 42-001a: imx477_set_gain :val = 256, digital gain = 256, analog gain = 256
[   55.339211] imx477 42-001a: imx477_set_frame_length: val: 2145
[   55.347891] imx477 42-001a: imx477_set_frame_length: vmax: 2145
[   55.353992] imx477 42-001a: imx477_set_coarse_time: val: 2135
[   55.362309] imx477 42-001a: imx477_s_stream: s_stream finished 
[   55.433293] imx477 41-001a:  Write-> RegName:(IMX477_SLAVE_ADD_EN_2ND_ADDR), Addr:0x(3010), OldValue:(1), NewValue:(1) 
[   55.444831] imx477 41-001a:  Write-> RegName:(IMX477_SLAVE_ADD_ACKEN_2ND_ADDR), Addr:0x(3011), OldValue:(0), NewValue:(0) 
[   55.456005] imx477 41-001a: imx477_s_stream: 2nd slave address enabled
[   55.458492] imx477 40-0010: imx477_s_stream: xvs master setting 
[   55.461916] imx477 40-0010: imx477_s_stream:i2c table write success
[   55.461922] imx477 40-0010: imx477_s_stream: s_data->mode 3
[   55.480593] imx477 41-001a: imx477_set_gain :val = 256, digital gain = 256, analog gain = 256
[   55.492300] imx477 41-001a: imx477_set_frame_length: val: 2145
[   55.499732] imx477 41-001a: imx477_set_frame_length: vmax: 2145
[   55.505716] imx477 41-001a: imx477_set_coarse_time: val: 2135
[   55.512654] imx477 41-001a: imx477_s_stream: s_stream finished 
[   55.514878] imx477 40-0010:  Write-> RegName:(IMX477_SLAVE_ADD_EN_2ND_ADDR), Addr:0x(3010), OldValue:(1), NewValue:(1) 
[   55.515220] imx477 40-0010:  Write-> RegName:(IMX477_SLAVE_ADD_ACKEN_2ND_ADDR), Addr:0x(3011), OldValue:(1), NewValue:(1) 
[   55.515225] imx477 40-0010: imx477_s_stream: 2nd slave address enabled
[   55.515278] imx477 40-0010: imx477_s_stream: Getting I2C broadcast client
[   55.515282] imx477 40-0010: imx477_s_stream: Initial setting for common (broadcast)
[   55.515293] pca954x 2-0077: Broadcast
[   55.515638] imx477 40-0010: imx477_s_stream: Standby -> Streaming (broadcast)
[   55.515646] imx477 40-0010: imx477_set_gain :val = 256, digital gain = 256, analog gain = 256
[   55.516980] imx477 40-0010: imx477_set_frame_length: val: 2145
[   55.517648] imx477 40-0010: imx477_set_frame_length: vmax: 2145
[   55.517652] imx477 40-0010: imx477_set_coarse_time: val: 2135
[   55.518321] imx477 40-0010: imx477_s_stream: s_stream finished 
[   55.611484] misc tegra_camera_ctrl: ISO BW req 4298248544 > 3925327 (max) capping to max
[   55.619671] misc tegra_camera_ctrl: vi_v4l2_update_isobw: requested iso bw is larger than max
[   55.706872] misc tegra_camera_ctrl: ISO BW req 2152405522 > 3925327 (max) capping to max
[   55.715043] misc tegra_camera_ctrl: vi_v4l2_update_isobw: requested iso bw is larger than max
[   55.740989] imx477 43-001a: imx477_set_gain :val = 315, digital gain = 256, analog gain = 315
[   55.750976] imx477 42-001a: imx477_set_gain :val = 315, digital gain = 256, analog gain = 315
[   55.761762] imx477 43-001a: imx477_set_gain :val = 388, digital gain = 256, analog gain = 388
[   55.771835] imx477 42-001a: imx477_set_gain :val = 388, digital gain

Log from unsuccesful run

[  701.383792] imx477 45-001a: imx477_power_on: power on
[  701.389826] imx477 45-001a: imx477_set_frame_length: val: 2145
[  701.396765] imx477 45-001a: imx477_set_frame_length: vmax: 2145
[  701.402815] imx477 45-001a: imx477_set_coarse_time: val: 2135
[  701.453953] misc tegra_camera_ctrl: ISO BW req 2147483647 > 3925327 (max) capping to max
[  701.462104] misc tegra_camera_ctrl: vi_v4l2_update_isobw: requested iso bw is larger than max
[  701.481343] imx477 45-001a: imx477_s_stream: enable 1 mode 3
[  701.509893] imx477 44-001a: imx477_power_on: power on
[  701.522179] imx477 44-001a: imx477_set_gain :val = 256, digital gain = 256, analog gain = 256
[  701.583853] imx477 43-001a: imx477_power_on: power on
[  701.591684] imx477 43-001a: imx477_set_gain :val = 256, digital gain = 256, analog gain = 256
[  701.607192] misc tegra_camera_ctrl: ISO BW req 4294967294 > 3925327 (max) capping to max
[  701.615440] misc tegra_camera_ctrl: vi_v4l2_update_isobw: requested iso bw is larger than max
[  701.634242] imx477 44-001a: imx477_s_stream: enable 1 mode 3
[  701.658996] misc tegra_camera_ctrl: ISO BW req 6442450941 > 3925327 (max) capping to max
[  701.667215] misc tegra_camera_ctrl: vi_v4l2_update_isobw: requested iso bw is larger than max
[  701.685959] imx477 43-001a: imx477_s_stream: enable 1 mode 3
[  701.698416] imx477 42-001a: imx477_power_on: power on
[  701.718617] imx477 42-001a: imx477_set_gain :val = 256, digital gain = 256, analog gain = 256
[  701.770167] imx477 45-001a: imx477_s_stream: slave xvs setting
[  701.779415] imx477 41-001a: imx477_power_on: power on
[  701.785305] imx477 41-001a: imx477_set_gain :val = 256, digital gain = 256, analog gain = 256
[  701.794470] misc tegra_camera_ctrl: ISO BW req 8589934588 > 3925327 (max) capping to max
[  701.803049] misc tegra_camera_ctrl: vi_v4l2_update_isobw: requested iso bw is larger than max
[  701.820034] imx477 45-001a: imx477_s_stream:i2c table write success
[  701.821787] imx477 42-001a: imx477_s_stream: enable 1 mode 3
[  701.832087] imx477 45-001a: imx477_s_stream: s_data->mode 3
[  701.865630] misc tegra_camera_ctrl: ISO BW req 10737418235 > 3925327 (max) capping to max
[  701.873934] misc tegra_camera_ctrl: vi_v4l2_update_isobw: requested iso bw is larger than max
[  701.882762] imx477 40-0010: imx477_power_on: power on
[  701.888400] imx477 40-0010: imx477_set_gain :val = 256, digital gain = 256, analog gain = 256
[  701.897053] imx477 41-001a: imx477_s_stream: enable 1 mode 3
[  701.947909] misc tegra_camera_ctrl: ISO BW req 12884901882 > 3925327 (max) capping to max
[  701.956114] misc tegra_camera_ctrl: vi_v4l2_update_isobw: requested iso bw is larger than max
[  701.975009] imx477 40-0010: imx477_s_stream: enable 1 mode 3
[  702.077720] imx477 45-001a:  Write-> RegName:(IMX477_SLAVE_ADD_EN_2ND_ADDR), Addr:0x(3010), OldValue:(1), NewValue:(1) 
[  702.090816] imx477 45-001a:  Write-> RegName:(IMX477_SLAVE_ADD_ACKEN_2ND_ADDR), Addr:0x(3011), OldValue:(0), NewValue:(0) 
[  702.102036] imx477 45-001a: imx477_s_stream: 2nd slave address enabled
[  702.108654] imx477 45-001a: imx477_set_gain :val = 256, digital gain = 256, analog gain = 256
[  702.126458] imx477 45-001a: imx477_set_frame_length: val: 2145
[  702.137026] imx477 45-001a: imx477_set_frame_length: vmax: 2145
[  702.143007] imx477 45-001a: imx477_set_coarse_time: val: 2135
[  702.153446] imx477 45-001a: imx477_s_stream: s_stream finished 
[  702.366129] imx477 44-001a: imx477_s_stream: slave xvs setting
[  702.397905] imx477 44-001a: imx477_s_stream:i2c table write success
[  702.404381] imx477 44-001a: imx477_s_stream: s_data->mode 3
[  702.528954] imx477 43-001a: imx477_s_stream: slave xvs setting
[  702.560312] imx477 43-001a: imx477_s_stream:i2c table write success
[  702.566654] imx477 43-001a: imx477_s_stream: s_data->mode 3
[  702.652473] imx477 42-001a: imx477_s_stream: slave xvs setting
[  702.684243] imx477 42-001a: imx477_s_stream:i2c table write success
[  702.690614] imx477 42-001a: imx477_s_stream: s_data->mode 3
[  702.705574] imx477 44-001a:  Write-> RegName:(IMX477_SLAVE_ADD_EN_2ND_ADDR), Addr:0x(3010), OldValue:(1), NewValue:(1) 
[  702.711271] imx477 41-001a: imx477_s_stream: slave xvs setting
[  702.726425] imx477 44-001a:  Write-> RegName:(IMX477_SLAVE_ADD_ACKEN_2ND_ADDR), Addr:0x(3011), OldValue:(0), NewValue:(0) 
[  702.734090] imx477 41-001a: imx477_s_stream:i2c table write success
[  702.734104] imx477 41-001a: imx477_s_stream: s_data->mode 3
[  702.749525] imx477 44-001a: imx477_s_stream: 2nd slave address enabled
[  702.756174] imx477 44-001a: imx477_set_gain :val = 256, digital gain = 256, analog gain = 256
[  702.774476] imx477 44-001a: imx477_set_frame_length: val: 2145
[  702.785455] imx477 44-001a: imx477_set_frame_length: vmax: 2145
[  702.791561] imx477 44-001a: imx477_set_coarse_time: val: 2135
[  702.802182] imx477 44-001a: imx477_s_stream: s_stream finished 
[  702.836153] imx477 40-0010: imx477_s_stream: xvs master setting 
[  702.861826] imx477 40-0010: imx477_s_stream:i2c table write success
[  702.862348] imx477 43-001a:  Write-> RegName:(IMX477_SLAVE_ADD_EN_2ND_ADDR), Addr:0x(3010), OldValue:(1), NewValue:(1) 
[  702.863917] imx477 43-001a:  Write-> RegName:(IMX477_SLAVE_ADD_ACKEN_2ND_ADDR), Addr:0x(3011), OldValue:(0), NewValue:(0) 
[  702.863928] imx477 43-001a: imx477_s_stream: 2nd slave address enabled
[  702.863946] imx477 43-001a: imx477_set_gain :val = 256, digital gain = 256, analog gain = 256
[  702.870121] imx477 43-001a: imx477_set_frame_length: val: 2145
[  702.873162] imx477 43-001a: imx477_set_frame_length: vmax: 2145
[  702.873175] imx477 43-001a: imx477_set_coarse_time: val: 2135
[  702.876245] imx477 43-001a: imx477_s_stream: s_stream finished 
[  702.928898] imx477 40-0010: imx477_s_stream: s_data->mode 3
[  702.937169] imx477 42-001a:  Write-> RegName:(IMX477_SLAVE_ADD_EN_2ND_ADDR), Addr:0x(3010), OldValue:(1), NewValue:(1) 
[  702.949557] imx477 42-001a:  Write-> RegName:(IMX477_SLAVE_ADD_ACKEN_2ND_ADDR), Addr:0x(3011), OldValue:(0), NewValue:(0) 
[  702.960775] imx477 42-001a: imx477_s_stream: 2nd slave address enabled
[  702.967492] imx477 42-001a: imx477_set_gain :val = 256, digital gain = 256, analog gain = 256
[  702.980525] imx477 42-001a: imx477_set_frame_length: val: 2145
[  702.988798] imx477 42-001a: imx477_set_frame_length: vmax: 2145
[  702.994866] imx477 42-001a: imx477_set_coarse_time: val: 2135
[  703.002741] imx477 42-001a: imx477_s_stream: s_stream finished 
[  703.018104] imx477 41-001a:  Write-> RegName:(IMX477_SLAVE_ADD_EN_2ND_ADDR), Addr:0x(3010), OldValue:(1), NewValue:(1) 
[  703.030204] imx477 41-001a:  Write-> RegName:(IMX477_SLAVE_ADD_ACKEN_2ND_ADDR), Addr:0x(3011), OldValue:(0), NewValue:(0) 
[  703.034971] misc tegra_camera_ctrl: ISO BW req 8593215838 > 3925327 (max) capping to max
[  703.034985] misc tegra_camera_ctrl: vi_v4l2_update_isobw: requested iso bw is larger than max
[  703.058014] imx477 41-001a: imx477_s_stream: 2nd slave address enabled
[  703.064634] imx477 41-001a: imx477_set_gain :val = 256, digital gain = 256, analog gain = 256
[  703.072387] imx477 40-0010:  Write-> RegName:(IMX477_SLAVE_ADD_EN_2ND_ADDR), Addr:0x(3010), OldValue:(1), NewValue:(1) 
[  703.072752] imx477 40-0010:  Write-> RegName:(IMX477_SLAVE_ADD_ACKEN_2ND_ADDR), Addr:0x(3011), OldValue:(1), NewValue:(1) 
[  703.072757] imx477 40-0010: imx477_s_stream: 2nd slave address enabled
[  703.072761] imx477 40-0010: imx477_s_stream: Initial setting for common (broadcast)
[  703.072769] pca954x 2-0077: Broadcast
[  703.073131] imx477 40-0010: imx477_s_stream: Standby -> Streaming (broadcast)
[  703.073140] imx477 40-0010: imx477_set_gain :val = 256, digital gain = 256, analog gain = 256
[  703.074859] imx477 40-0010: imx477_set_frame_length: val: 2145
[  703.075576] imx477 40-0010: imx477_set_frame_length: vmax: 2145
[  703.075583] imx477 40-0010: imx477_set_coarse_time: val: 2135
[  703.076300] imx477 40-0010: imx477_s_stream: s_stream finished 
[  703.153506] imx477 41-001a: imx477_set_frame_length: val: 2145
[  703.160054] imx477 41-001a: imx477_set_frame_length: vmax: 2145
[  703.166023] imx477 41-001a: imx477_set_coarse_time: val: 2135
[  703.171992] misc tegra_camera_ctrl: ISO BW req 6447372816 > 3925327 (max) capping to max
[  703.172746] imx477 41-001a: imx477_s_stream: s_stream finished 
[  703.190536] misc tegra_camera_ctrl: vi_v4l2_update_isobw: requested iso bw is larger than max
[  703.221159] misc tegra_camera_ctrl: ISO BW req 4301529794 > 3925327 (max) capping to max
[  703.229655] misc tegra_camera_ctrl: vi_v4l2_update_isobw: requested iso bw is larger than max
[  703.345379] misc tegra_camera_ctrl: ISO BW req 2155686772 > 3925327 (max) capping to max
[  703.353585] misc tegra_camera_ctrl: vi_v4l2_update_isobw: requested iso bw is larger than max
[  703.354535] imx477 45-001a: imx477_set_gain :val = 315, digital gain = 256, analog gain = 315
[  703.372750] imx477 42-001a: imx477_set_gain :val = 315, digital gain = 256, analog gain = 315

[  704.830876] fence timeout on [ffffffc049bf9200] after 1500ms
[  704.836683] name=[nvhost_sync:125], current value=20 waiting value=21
[  704.837171] imx477 44-001a: imx477_set_gain :val = 1720, digital gain = 256, analog gain = 1720
[  704.838852] fence timeout on [ffffffc049bf9000] after 1500ms
[  704.838857] name=[nvhost_sync:126], current value=20 waiting value=21
[  704.838861] ---- mlocks ----
[  704.838887] 
[  704.838889] ---- syncpts ----
[  704.838899] id 4 (disp_d) min 105 max 105 refs 1 (previous client : )
[  704.838903] id 5 (disp_e) min 19376 max 19376 refs 1 (previous client : )
[  704.838908] id 7 (vblank1) min 41949 max 0 refs 1 (previous client : )
[  704.838923] id 18 (17000000.gp10b_507) min 8932 max 8932 refs 1 (previous client : )
[  704.838927] id 19 (17000000.gp10b_506) min 22 max 22 refs 1 (previous client : )

[  704.839937] ffffffc07ae0b800: JOB, syncpt_id=54, syncpt_val=1693, first_get=00000ad8, timeout=0, num_slots=6

[  704.840007] ffffffc1e29c0400: JOB, syncpt_id=74, syncpt_val=2630, first_get=00000700, timeout=0, num_slots=6

hello jafet,

according to your logs, 4-camera use-case works but it failed by 6-camera use-case.
may I know how longs does it take to set-up the pipeline?
also, the patches from Topic 1037809 should recover the error. could you please also check if the error handling mechanism works as expect?
thanks

Thanks for the swift response.

I isolated some log that can be used to measured the time it takes to set up, as you can see this time isn’t constant, ranging from 0,007376 s to 0,426378 s.

Aug 30 17:03:16 tegra-ubuntu kernel: [   79.342420] imx477 45-001a: imx477_s_stream: s_stream finished 
Aug 30 17:03:16 tegra-ubuntu kernel: [   79.768798] imx477 44-001a: imx477_s_stream: s_stream finished 
Aug 30 17:03:16 tegra-ubuntu kernel: [   79.917834] imx477 41-001a: imx477_s_stream: s_stream finished 
Aug 30 17:03:16 tegra-ubuntu kernel: [   79.925210] imx477 40-0010: imx477_s_stream: s_stream finished 
Aug 30 17:03:16 tegra-ubuntu kernel: [   80.084219] imx477 42-001a: imx477_s_stream: s_stream finished

Here are some error messages related to the nvcamera-daemon

Aug 30 17:03:16 tegra-ubuntu kernel: [   79.912234] imx477 41-001a:  Write-> RegName:(IMX477_SLAVE_ADD_EN_2ND_ADDR), Addr:0x(3010), OldValue:(1), NewValue:(1) 
Aug 30 17:03:16 tegra-ubuntu kernel: [   79.912857] imx477 41-001a:  Write-> RegName:(IMX477_SLAVE_ADD_ACKEN_2ND_ADDR), Addr:0x(3011), OldValue:(0), NewValue:(0) 
Aug 30 17:03:16 tegra-ubuntu kernel: [   79.912861] imx477 41-001a: imx477_s_stream: 2nd slave address enabled
Aug 30 17:03:16 tegra-ubuntu kernel: [   79.912867] imx477 41-001a: imx477_set_gain :val = 256, digital gain = 256, analog gain = 256
Aug 30 17:03:16 tegra-ubuntu kernel: [   79.915337] imx477 41-001a: imx477_set_frame_length: val: 2145
Aug 30 17:03:16 tegra-ubuntu kernel: [   79.916576] imx477 41-001a: imx477_set_frame_length: vmax: 2145
Aug 30 17:03:16 tegra-ubuntu kernel: [   79.916581] imx477 41-001a: imx477_set_coarse_time: val: 2135
Aug 30 17:03:16 tegra-ubuntu kernel: [   79.917834] imx477 41-001a: imx477_s_stream: s_stream finished 
Aug 30 17:03:16 tegra-ubuntu kernel: [   79.922141] imx477 40-0010:  Write-> RegName:(IMX477_SLAVE_ADD_EN_2ND_ADDR), Addr:0x(3010), OldValue:(1), NewValue:(1) 
Aug 30 17:03:16 tegra-ubuntu kernel: [   79.922449] imx477 40-0010:  Write-> RegName:(IMX477_SLAVE_ADD_ACKEN_2ND_ADDR), Addr:0x(3011), OldValue:(1), NewValue:(1) 
Aug 30 17:03:16 tegra-ubuntu kernel: [   79.922451] imx477 40-0010: imx477_s_stream: 2nd slave address enabled
Aug 30 17:03:16 tegra-ubuntu kernel: [   79.922453] imx477 40-0010: imx477_s_stream: Initial setting for common (broadcast)
Aug 30 17:03:16 tegra-ubuntu kernel: [   79.922458] pca954x 2-0077: Broadcast
Aug 30 17:03:16 tegra-ubuntu kernel: [   79.922761] imx477 40-0010: imx477_s_stream: Standby -> Streaming (broadcast)
Aug 30 17:03:16 tegra-ubuntu kernel: [   79.922766] imx477 40-0010: imx477_set_gain :val = 256, digital gain = 256, analog gain = 256
Aug 30 17:03:16 tegra-ubuntu kernel: [   79.923967] imx477 40-0010: imx477_set_frame_length: val: 2145
Aug 30 17:03:16 tegra-ubuntu kernel: [   79.924569] imx477 40-0010: imx477_set_frame_length: vmax: 2145
Aug 30 17:03:16 tegra-ubuntu kernel: [   79.924572] imx477 40-0010: imx477_set_coarse_time: val: 2135
Aug 30 17:03:16 tegra-ubuntu kernel: [   79.925210] imx477 40-0010: imx477_s_stream: s_stream finished 
Aug 30 17:03:16 tegra-ubuntu kernel: [   79.989086] misc tegra_camera_ctrl: ISO BW req 4296607919 > 3925327 (max) capping to max
Aug 30 17:03:16 tegra-ubuntu kernel: [   79.989093] misc tegra_camera_ctrl: vi_v4l2_update_isobw: requested iso bw is larger than max
Aug 30 17:03:16 tegra-ubuntu kernel: [   80.068511] imx477 42-001a: imx477_set_frame_length: vmax: 2145
Aug 30 17:03:16 tegra-ubuntu kernel: [   80.077790] imx477 42-001a: imx477_set_coarse_time: val: 2135
Aug 30 17:03:16 tegra-ubuntu kernel: [   80.084219] imx477 42-001a: imx477_s_stream: s_stream finished 
Aug 30 17:03:16 tegra-ubuntu nvcamera-daemon[1192]: (545792205280) New Resolution W = 2028 H = 1520
Aug 30 17:03:16 tegra-ubuntu nvcamera-daemon[1192]: RECEIVED REGISTER_BUFFER_BAYER fd = 374
Aug 30 17:03:16 tegra-ubuntu nvcamera-daemon[1192]: RECEIVED REGISTER_BUFFER_META fd = 377
Aug 30 17:03:16 tegra-ubuntu nvcamera-daemon[1192]: RECEIVED REGISTER_BUFFER_BAYER fd = 391
Aug 30 17:03:16 tegra-ubuntu nvcamera-daemon[1192]: RECEIVED REGISTER_BUFFER_META fd = 393
Aug 30 17:03:16 tegra-ubuntu nvcamera-daemon[1192]: RECEIVED REGISTER_BUFFER_BAYER fd = 384
Aug 30 17:03:16 tegra-ubuntu nvcamera-daemon[1192]: RECEIVED REGISTER_BUFFER_META fd = 398
Aug 30 17:03:16 tegra-ubuntu nvcamera-daemon[1192]: RECEIVED REGISTER_BUFFER_BAYER fd = 403
Aug 30 17:03:16 tegra-ubuntu nvcamera-daemon[1192]: RECEIVED REGISTER_BUFFER_META fd = 404
Aug 30 17:03:16 tegra-ubuntu nvcamera-daemon[1192]: RECEIVED REGISTER_BUFFER_BAYER fd = 416
Aug 30 17:03:16 tegra-ubuntu nvcamera-daemon[1192]: RECEIVED REGISTER_BUFFER_META fd = 417
Aug 30 17:03:16 tegra-ubuntu nvcamera-daemon[1192]: RECEIVED REGISTER_BUFFER_BAYER fd = 419
Aug 30 17:03:16 tegra-ubuntu nvcamera-daemon[1192]: RECEIVED REGISTER_BUFFER_META fd = 420
Aug 30 17:03:16 tegra-ubuntu nvcamera-daemon[1192]: RECEIVED REGISTER_BUFFER_BAYER fd = 422
Aug 30 17:03:16 tegra-ubuntu nvcamera-daemon[1192]: RECEIVED REGISTER_BUFFER_META fd = 423
Aug 30 17:03:16 tegra-ubuntu nvcamera-daemon[1192]: RECEIVED REGISTER_BUFFER_BAYER fd = 426
Aug 30 17:03:16 tegra-ubuntu nvcamera-daemon[1192]: RECEIVED REGISTER_BUFFER_META fd = 427
Aug 30 17:03:16 tegra-ubuntu nvcamera-daemon[1192]: RECEIVED REGISTER_BUFFER_BAYER fd = 429
Aug 30 17:03:16 tegra-ubuntu nvcamera-daemon[1192]: RECEIVED REGISTER_BUFFER_META fd = 430
Aug 30 17:03:16 tegra-ubuntu nvcamera-daemon[1192]: RECEIVED REGISTER_BUFFER_BAYER fd = 432
Aug 30 17:03:16 tegra-ubuntu nvcamera-daemon[1192]: RECEIVED REGISTER_BUFFER_META fd = 433
Aug 30 17:03:16 tegra-ubuntu nvcamera-daemon[1192]: (545792205280) REQ_NVCAM_ENABLE_METADATA Enabled=0
Aug 30 17:03:17 tegra-ubuntu kernel: [   80.100109] misc tegra_camera_ctrl: ISO BW req 4298248544 > 3925327 (max) capping to max
Aug 30 17:03:17 tegra-ubuntu kernel: [   80.108243] misc tegra_camera_ctrl: vi_v4l2_update_isobw: requested iso bw is larger than max
Aug 30 17:03:17 tegra-ubuntu kernel: [   80.117489] misc tegra_camera_ctrl: ISO BW req 2152405522 > 3925327 (max) capping to max
Aug 30 17:03:17 tegra-ubuntu kernel: [   80.125652] misc tegra_camera_ctrl: vi_v4l2_update_isobw: requested iso bw is larger than max
Aug 30 17:03:17 tegra-ubuntu kernel: [   80.131855] imx477 40-0010: imx477_set_gain :val = 315, digital gain = 256, analog gain = 315
Aug 30 17:03:17 tegra-ubuntu kernel: [   80.149248] imx477 40-0010: imx477_set_gain :val = 388, digital gain = 256, analog gain = 388
Aug 30 17:03:17 tegra-ubuntu nvcamera-daemon[1192]: (544772977120) Error in calling capture= 13 result= 8
Aug 30 17:03:17 tegra-ubuntu nvcamera-daemon[1192]: message repeated 3 times: [ (544772977120) Error in calling capture= 13 result= 8]
Aug 30 17:03:17 tegra-ubuntu nvcamera-daemon[1192]: (544781365728) Error in calling capture= 3 result= 5
Aug 30 17:03:17 tegra-ubuntu kernel: [   80.917074] fence timeout on [ffffffc17b909400] after 1500ms
Aug 30 17:03:17 tegra-ubuntu kernel: [   80.922917] fence timeout on [ffffffc17b909200] after 1500ms

Aug 30 17:03:27 tegra-ubuntu kernel: [   90.429791] ---- host general irq ----
Aug 30 17:03:27 tegra-ubuntu kernel: [   90.429791] 
Aug 30 17:03:27 tegra-ubuntu kernel: [   90.436514] sync_intc0mask = 0x00000001
Aug 30 17:03:27 tegra-ubuntu nvcamera-daemon[1192]: (545385345504) Error in calling capture= 3 result= 5
Aug 30 17:03:27 tegra-ubuntu nvcamera-daemon[1192]: (545792205280) Error in calling capture= 5 result= 5
Aug 30 17:03:27 tegra-ubuntu nvcamera-daemon[1192]: (546995958240) Error in calling capture= 3 result= 5
Aug 30 17:03:27 tegra-ubuntu nvcamera-daemon[1192]: (545385345504) Error in calling capture= 3 result= 5
Aug 30 17:03:27 tegra-ubuntu nvcamera-daemon[1192]: (545792205280) Error in calling capture= 5 result= 5
Aug 30 17:03:27 tegra-ubuntu nvcamera-daemon[1192]: (546995958240) Error in calling capture= 3 result= 5
Aug 30 17:03:27 tegra-ubuntu nvcamera-daemon[1192]: (545385345504) Error in calling capture= 3 result= 5
Aug 30 17:03:27 tegra-ubuntu kernel: [   90.440368] sync_intmask = 0x50000003
Aug 30 17:03:27 tegra-ubuntu kernel: [   90.444023] 
Aug 30 17:03:27 tegra-ubuntu kernel: [   90.444023] ---- host syncpt irq mask ----
Aug 30 17:03:27 tegra-ubuntu kernel: [   90.444023] 
Aug 30 17:03:27 tegra-ubuntu kernel: [   90.451084] 
Aug 30 17:03:27 tegra-ubuntu kernel: [   90.451084] ---- host syncpt irq status ----
Aug 30 17:03:27 tegra-ubuntu kernel: [   90.451084] 
Aug 30 17:03:27 tegra-ubuntu nvcamera-daemon[1192]: (545792205280) Error in calling capture= 5 result= 5
Aug 30 17:03:27 tegra-ubuntu nvcamera-daemon[1192]: (546995958240) Error in calling capture= 3 result= 5
Aug 30 17:03:27 tegra-ubuntu nvcamera-daemon[1192]: (545385345504) Error in calling capture= 3 result= 5
Aug 30 17:03:27 tegra-ubuntu nvcamera-daemon[1192]: (545792205280) Error in calling capture= 5 result= 5
Aug 30 17:03:27 tegra-ubuntu kernel: [   90.458324] syncpt_thresh_cpu0_int_status(0) = 0x00000000
Aug 30 17:03:27 tegra-ubuntu kernel: [   90.463739] syncpt_thresh_cpu0_int_status(1) = 0x00000000
Aug 30 17:03:27 tegra-ubuntu nvcamera-daemon[1192]: (546995958240) Error in calling capture= 3 result= 5
Aug 30 17:03:27 tegra-ubuntu kernel: [   90.469161] syncpt_thresh_cpu0_int_status(2) = 0x00000000
Aug 30 17:03:27 tegra-ubuntu nvcamera-daemon[1192]: (545385345504) Error in calling capture= 3 result= 5
Aug 30 17:03:27 tegra-ubuntu nvcamera-daemon[1192]: (545792205280) Error in calling capture= 5 result= 5
Aug 30 17:03:27 tegra-ubuntu nvcamera-daemon[1192]: (546995958240) Error in calling capture= 3 result= 5
Aug 30 17:03:27 tegra-ubuntu nvcamera-daemon[1192]: (545385345504) Error in calling capture= 3 result= 5
Aug 30 17:03:27 tegra-ubuntu kernel: [   90.474575] syncpt_thresh_cpu0_int_status(3) = 0x00000000
Aug 30 17:03:27 tegra-ubuntu kernel: [   90.479990] syncpt_thresh_cpu0_int_status(4) = 0x00000000
Aug 30 17:03:27 tegra-ubuntu nvcamera-daemon[1192]: (545792205280) Error in calling capture= 5 result= 5
Aug 30 17:03:27 tegra-ubuntu nvcamera-daemon[1192]: (546995958240) Error in calling capture= 3 result= 5
Aug 30 17:03:27 tegra-ubuntu kernel: [   90.485405] syncpt_thresh_cpu0_int_status(5) = 0x00000000
Aug 30 17:03:27 tegra-ubuntu nvcamera-daemon[1192]: (545385345504) Error in calling capture= 3 result= 5
Aug 30 17:03:27 tegra-ubuntu nvcamera-daemon[1192]: (545792205280) Error in calling capture= 5 result= 5
Aug 30 17:03:27 tegra-ubuntu nvcamera-daemon[1192]: (546995958240) Error in calling capture= 3 result= 5
Aug 30 17:03:27 tegra-ubuntu kernel: [   90.490830] syncpt_thresh_cpu0_int_status(6) = 0x00000000
Aug 30 17:03:27 tegra-ubuntu kernel: [   90.496242] syncpt_thresh_cpu0_int_status(7) = 0x00000000
Aug 30 17:03:27 tegra-ubuntu nvcamera-daemon[1192]: (545385345504) Error in calling capture= 3 result= 5
Aug 30 17:03:27 tegra-ubuntu nvcamera-daemon[1192]: (545792205280) Error in calling capture= 5 result= 5
Aug 30 17:03:27 tegra-ubuntu nvcamera-daemon[1192]: (546995958240) Error in calling capture= 3 result= 5
Aug 30 17:03:27 tegra-ubuntu kernel: [   90.501654] syncpt_thresh_cpu0_int_status(8) = 0x00000000
Aug 30 17:03:27 tegra-ubuntu kernel: [   90.507077] syncpt_thresh_cpu0_int_status(9) = 0x00000000
Aug 30 17:03:27 tegra-ubuntu nvcamera-daemon[1192]: (545385345504) Error in calling capture= 3 result= 5
Aug 30 17:03:27 tegra-ubuntu nvcamera-daemon[1192]: (545792205280) Error in calling capture= 5 result= 5
Aug 30 17:03:27 tegra-ubuntu nvcamera-daemon[1192]: (546995958240) Error in calling capture= 3 result= 5
Aug 30 17:03:27 tegra-ubuntu nvcamera-daemon[1192]: (545385345504) Error in calling capture= 3 result= 5
Aug 30 17:03:27 tegra-ubuntu kernel: [   90.512487] syncpt_thresh_cpu0_int_status(10) = 0x00000000
Aug 30 17:03:27 tegra-ubuntu kernel: [   90.517984] syncpt_thresh_cpu0_int_status(11) = 0x00000000
Aug 30 17:03:27 tegra-ubuntu nvcamera-daemon[1192]: (545792205280) Error in calling capture= 5 result= 5
Aug 30 17:03:27 tegra-ubuntu nvcamera-daemon[1192]: (546995958240) Error in calling capture= 3 result= 5
Aug 30 17:03:27 tegra-ubuntu nvcamera-daemon[1192]: (545385345504) Error in calling capture= 3 result= 5
Aug 30 17:03:27 tegra-ubuntu nvcamera-daemon[1192]: (545792205280) Error in calling capture= 5 result= 5
Aug 30 17:03:27 tegra-ubuntu kernel: [   90.523486] syncpt_thresh_cpu0_int_status(12) = 0x00000000
Aug 30 17:03:27 tegra-ubuntu kernel: [   90.528992] syncpt_thresh_cpu0_int_status(13) = 0x00000000
Aug 30 17:03:27 tegra-ubuntu nvcamera-daemon[1192]: (546995958240) Error in calling capture= 3 result= 5
Aug 30 17:03:27 tegra-ubuntu nvcamera-daemon[1192]: (545385345504) Error in calling capture= 3 result= 5
Aug 30 17:03:27 tegra-ubuntu nvcamera-daemon[1192]: (545792205280) Error in calling capture= 5 result= 5
Aug 30 17:03:27 tegra-ubuntu kernel: [   90.534492] syncpt_thresh_cpu0_int_status(14) = 0x00000000
Aug 30 17:03:27 tegra-ubuntu kernel: [   90.539991] syncpt_thresh_cpu0_int_status(15) = 0x00000000
Aug 30 17:03:27 tegra-ubuntu nvcamera-daemon[1192]: (546995958240) Error in calling capture= 3 result= 5
Aug 30 17:03:27 tegra-ubuntu nvcamera-daemon[1192]: (545385345504) Error in calling capture= 3 result= 5
Aug 30 17:03:27 tegra-ubuntu nvcamera-daemon[1192]: (545792205280) Error in calling capture= 5 result= 5
Aug 30 17:03:27 tegra-ubuntu nvcamera-daemon[1192]: (546995958240) Error in calling capture= 3 result= 5
Aug 30 17:03:27 tegra-ubuntu kernel: [   90.545508] syncpt_thresh_cpu0_int_status(16) = 0x00000000
Aug 30 17:03:27 tegra-ubuntu kernel: [   90.551012] syncpt_thresh_cpu0_int_status(17) = 0x00000000
Aug 30 17:03:27 tegra-ubuntu nvcamera-daemon[1192]: (545385345504) Error in calling capture= 3 result= 5

Aug 30 17:03:17 tegra-ubuntu kernel: [   80.929040] id 39 (15700000.vi_1) min 394 max 397 refs 5 (previous client : 150c0000.nvcsi_0)
Aug 30 17:03:17 tegra-ubuntu kernel: [   80.929114] id 52 (150c0000.nvcsi_0) min 398 max 398 refs 2 (previous client : 150c0000.nvcsi_0)
Aug 30 17:03:17 tegra-ubuntu kernel: [   80.930330] channel 5 - 150c0000.nvcsi
Aug 30 17:03:25 tegra-ubuntu kernel: [   81.320129] id 39 (15700000.vi_1) min 394 max 397 refs 5 (previous client : 150c0000.nvcsi_0)
Aug 30 17:03:25 tegra-ubuntu kernel: [   81.320201] id 52 (150c0000.nvcsi_0) min 398 max 398 refs 2 (previous client : 150c0000.nvcsi_0)
Aug 30 17:03:25 tegra-ubuntu kernel: [   81.321453] id 39 (15700000.vi_1) min 394 max 397 refs 5 (previous client : 150c0000.nvcsi_0)
Aug 30 17:03:25 tegra-ubuntu kernel: [   81.321458] channel 5 - 150c0000.nvcsi
Aug 30 17:03:25 tegra-ubuntu kernel: [   81.321524] id 52 (150c0000.nvcsi_0) min 398 max 398 refs 2 (previous client : 150c0000.nvcsi_0)
Aug 30 17:03:25 tegra-ubuntu kernel: [   81.322768] channel 5 - 150c0000.nvcsi
Aug 30 17:03:25 tegra-ubuntu kernel: [   81.493094] id 39 (15700000.vi_1) min 394 max 397 refs 5 (previous client : 150c0000.nvcsi_0)
Aug 30 17:03:25 tegra-ubuntu kernel: [   81.493167] id 52 (150c0000.nvcsi_0) min 398 max 398 refs 2 (previous client : 150c0000.nvcsi_0)
Aug 30 17:03:25 tegra-ubuntu kernel: [   81.494374] channel 5 - 150c0000.nvcsi
Aug 30 17:03:25 tegra-ubuntu kernel: [   81.501085] id 39 (15700000.vi_1) min 394 max 397 refs 5 (previous client : 150c0000.nvcsi_0)
Aug 30 17:03:25 tegra-ubuntu kernel: [   81.501155] id 52 (150c0000.nvcsi_0) min 398 max 398 refs 2 (previous client : 150c0000.nvcsi_0)
Aug 30 17:03:25 tegra-ubuntu kernel: [   81.502335] channel 5 - 150c0000.nvcsi
Aug 30 17:03:25 tegra-ubuntu kernel: [   88.772528] id 39 (15700000.vi_1) min 394 max 397 refs 5 (previous client : 150c0000.nvcsi_0)
Aug 30 17:03:25 tegra-ubuntu kernel: [   88.850433] id 52 (150c0000.nvcsi_0) min 398 max 398 refs 2 (previous client : 150c0000.nvcsi_0)
Aug 30 17:03:26 tegra-ubuntu kernel: [   89.986943] channel 5 - 150c0000.nvcsi

hello jafet,

since your sensor streaming are launch individually, there’re such REQ_NVCAM_CAPTURE_FRAME_NEW failure as below,

tegra-ubuntu nvcamera-daemon[1192]: (544772977120) Error in calling capture= 13 result= 8

could you please have some experiments to do the error-handling from the nvcamera-daemon side to re-init the capture request.
thanks

Hi,

Just to be sure by “experiments to do the error handling” you mean, checking if the function added by the patches for error handling is being called and used correctly? Check return value and others?

For example check if functions like “csi4_error_recover” are being called and used.

At this moment after the timeout the daemon crashes and we need to restart the hardware, we are going to be checking actions happening at functions added by the patches, but not completely sure what can we check or modify from nvcamera-daemon to do error handling. Could you please provide more information?

Regards,
Carlos A.

hello Carlos001,

correct, please check the functions added by the patches is being called and works as expect.
from nvcamera-daemon side, you may add some handling for REQ_NVCAM_CAPTURE_FRAME_NEW failures.
thanks

Hi,

We’ve run tests to check if the error recovery functions added by the patches are being called, we found out that functions are not being called. We are sure that messages are being printed because we added some debug messages throughout vi4_ops.c, csi.c and csi4_ops.c, these messages are printed, but messages at functions related to error recovery are not. We added messages to:

  • tegra_channel_error_recovery()
  • tegra_csi_error_recovery()
  • tegra_csi_sync_event()
  • csi4_error_recover()

Do you know any special reason for this behaviour?
What could cause the fence timeout to happen but the recovery funtions not being called?

Regards

Hi,

About adding a handler for REQ_NVCAM_CAPTURE_FRAME_NEW, as far as I know (correct me if I am wrong) but the nvcamera-daemon cant be modified, source code for nvcamera-daemon is not provided, this makes adding a handling for “REQ_NVCAM_CAPTURE_FRAME_NEW” not possible, correct?

The definition REQ_NVCAM_CAPTURE_FRAME_NEW is not available at kernel, only at nvcamera-daemon.

Additionally I have been checking how to obtain more debug data by following this webpage: Jetson TX2 Camera BringUp - eLinux.org

I was able to obtain this log from /sys/kernel/debug/tracing/trace when the timeout occurs:

 kworker/0:1-51    [000] ...1   139.847800: rtcpu_vinotify_handle_msg: tstamp:4706553913 tag:ATOMP_FE channel:0x00 frame:203 vi_tstamp:411585947 data:0x00000000
 kworker/0:1-51    [000] ...1   139.907848: rtos_queue_peek_from_isr_failed: tstamp:4707880403 queue:0x0b4a3c58
 kworker/0:1-51    [000] ...1   140.079807: rtos_queue_peek_from_isr_failed: tstamp:4712880913 queue:0x0b4a3c58
 kworker/0:1-51    [000] ...1   140.191814: rtos_queue_peek_from_isr_failed: tstamp:4717881430 queue:0x0b4a3c58

Now I have also tried to activate nvcamera-daemon logs as indicated at the webpage (Jetson TX2 Camera BringUp - eLinux.org) and error seems to not happen, I did a test for about 12 hours and no timeouts are happening, could be a race condition at nvcamera-daemon? Will continue checking, all these tests have been done using a patched kernel with:

  1. 0001-drivers-camera-fix-FE-syncpt-wait.patch
  2. 0002-media-tegra-fix-missing-timestamp-for-vi4.patch
  3. 0003-media-tegra-revert-two-thread-VI-improvements.patch
  4. 0004-media-tegra-camera-t18x-vi-mode-error-recovery.patch

Regards and thank you for your time,
Carlos A.

hello Carlos001,

  1. you’re right that we don’t public the source code of nvcamera-daemon, sorry for the mistake.

  2. please have a try to increase the timeout range in the VI kernel driver as below,
    /kernel/kernel-4.4/drivers/media/platform/tegra/camera/vi/vi4_fops.c

nvhost_syncpt_wait_timeout_ext(...)
  1. thanks for sharing the tracing message, but the output via rtcpu_vinotify_handle_msg looks normally. it would be better to attach the whole tracing result for double confirm the status.

Hi,

Ok, thanks for the clarification about not public nvcamera-daemon.

About the timeout increase, we tried that approach, modified the nvhost_syncpt_wait_timeout_ext timeout, but no difference about the timeout, also modified other timeouts just to be sure, but no success.

About the tracing message I am using these patches on the kernel as indicated before: https://devtalk.nvidia.com/default/topic/1037809/jetson-tx2/jetpack3-2-1-tx2-csi-mipi-can-only-get-the-the-first-frame-of-image-but-tx1-works-fine-/post/5272855/#5272855 Jul26_topic1037809.tar.gz

I have noticed a pattern:
two-cams 2028x1520 failing (log available 2.7MB)
three-cams 2028x1520 working (log available 23MB)
four-cams 2028x1520 working
two-cams 640x480 failing (log available 2.8MB)
three-cams 640x480 failing (log available 41MB, had to interrupt)

I can provide the log, but since debug was activated log files are huge, file are at drive for now:
[url]https://drive.google.com/file/d/1JXRlhR6j-9YoAGXTMzHNu07NqMk7ZgHI/view?usp=sharing[/url]
[url]https://drive.google.com/file/d/1bwdwQC4MPBf7WbsVeh2yoSyd3hrz9FQY/view?usp=sharing[/url]
[url]https://drive.google.com/file/d/1SJ1sB6xVX1KHC7QCxjbWUIjXeT1vjGiE/view?usp=sharing[/url]
[url]https://drive.google.com/file/d/1xEjnKhHkvH2qayl6oc609nxiUWZYijX-/view?usp=sharing[/url]

Regards,
Carlos A.

Hi,

Just wondering if the logs has been useful for checking the timeout issue.

Regards and thank you for your time.
Carlos A.

Hello guys.

I updated to the latest version of L4T. Now the .deb file that has the IMX477 driver doesn’t want to install due to some dependency issues. Now I have a few questions.

  1. Is it possible to downgrade a kernel?
  2. If I just choose to use a webcam, Can I just any webcam or there a specific ones that are supported. I’m planning to buy Logitech C310/C270 webcam.
    Thanks

Hi Mpura,

Please help to oepn a new topic. Thanks