RTCPU Crashes - while image streaming is being stopped

Robotics & Edge Computing Jetson & Embedded Systems Jetson Xavier NX
,
1

RTCPU crashes while stopping the image streaming at the end of the application.

Details:

  1. libargus examples - argus_userautoexposure, argus_eglimage (even happens with V4L2 capture but much lesser compared to argus application)
  2. IMX392 Image sensor module - 1920x1200@30fps - Bayer RG10 format - 4 Lanes.
  3. Pixel clock: 74.25MHz
  4. Have enabled max speed for ISP and NVCSI as per the below commands

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

RTCPU crash dmesg log:

[  101.050707] CPU:0, Error:rce-noc@0xbe00000,irq=21
[  101.050879] **************************************
[  101.051035] CPU:0, Error:rce-noc
[  101.051121] 	Error Logger		: 0
[  101.051238] 	ErrLog0			: 0x80030000
[  101.051329] 	  Transaction Type	: RD  - Read, Incrementing
[  101.051440] 	  Error Code		: SLV
[  101.051516] 	  Error Source		: Target
[  101.051591] 	  Error Description	: Target error detected by CBB slave
[  101.051769] 	  Packet header Lock	: 0
[  101.051844] 	  Packet header Len1	: 3
[  101.051919] 	  NOC protocol version	: version >= 2.7
[  101.052019] 	ErrLog1			: 0x157600
[  101.052089] 	ErrLog2			: 0x0
[  101.052151] 	  RouteId		: 0x157600
[  101.052221] 	  InitFlow		: cpu_p_i/I/0
[  101.052301] 	  Targflow		: cbb_t/T/0
[  101.053248] 	  TargSubRange		: 27
[  101.053807] 	  SeqId			: 0
[  101.056952] 	ErrLog3			: 0x5c01814
[  101.059930] 	ErrLog4			: 0x0
[  101.062905] 	  Address accessed	: 0x15c01814
[  101.067021] 	ErrLog5			: 0x387e31
[  101.070516] 	  Master ID		: RCE
[  101.073664] 	  Security Group(GRPSEC): 0x3f
[  101.077434] 	  Cache			: 0x1 -- Bufferable 
[  101.081636] 	  Protection		: 0x1 -- Privileged, Secure, Data Access
[  101.087846] 	  FALCONSEC		: 0x0
[  101.090995] 	  Virtual Queuing Channel(VQC): 0x0
[  101.095729] 	**************************************
[  101.101145] CPU:0, Error:cbb-noc@0x2300000,irq=15
[  101.105606] **************************************
[  101.110591] CPU:0, Error:cbb-noc
[  101.113830] 	Error Logger		: 0
[  101.116898] 	ErrLog0			: 0x80030000
[  101.120478] 	  Transaction Type	: RD  - Read, Incrementing
[  101.125813] 	  Error Code		: SLV
[  101.128969] 	  Error Source		: Target
[  101.132902] 	  Error Description	: Target error detected by CBB slave
[  101.138952] 	  AXI2APB_5 bridge error: RDFIFOF - Read Response FIFO Full interrupt
[  101.146561] 	  Packet header Lock	: 0
[  101.150502] 	  Packet header Len1	: 3
[  101.154164] 	  NOC protocol version	: version >= 2.7
[  101.158894] 	ErrLog1			: 0x9528aa
[  101.162476] 	ErrLog2			: 0x0
[  101.165106] 	  RouteId		: 0x9528aa
[  101.168432] 	  InitFlow		: rce_p2ps/I/rce_p2ps
[  101.173152] 	  Targflow		: host1x_p2pm/T/host1x_p2pm
[  101.177964] 	  TargSubRange		: 20
[  101.181202] 	  SeqId			: 0
[  101.184002] 	ErrLog3			: 0x1814
[  101.186718] 	ErrLog4			: 0x0
[  101.189867] 	  Address accessed	: 0x15c01814
[  101.194327] 	ErrLog5			: 0x2af0fc71
[  101.197826] 	  Non-Modify		: 0x1
[  101.201240] 	  AXI ID		: 0x55
[  101.204131] 	  Master ID		: RCE
[  101.207196] 	  Security Group(GRPSEC): 0x3f
[  101.211652] 	  Cache			: 0x1 -- Bufferable 
[  101.215594] 	  Protection		: 0x3 -- Privileged, Non-Secure, Data Access
[  101.222677] 	  FALCONSEC		: 0x0
[  101.225827] 	  Virtual Queuing Channel(VQC): 0x0
[  101.230209] 	**************************************
[  101.235613] Host read timeout at address 1814
[  101.240368] [RCE] VM0 deactivating.VM0 activating.VM0 deactivating.VM0 activating.VM0 deactivating.*** DATA ABORT EXCEPTION ***
[  101.240383] [RCE] R0:	15c00000	R1:	00001814	R2:	00008010	R3:	00000000
[  101.240394] [RCE] R4:	0bcd0188	R5:	00000000	R6:	00000000	R7:	799ce800
[  101.240404] [RCE] R8:	0bcc27b0	R9:	0bcc27b2	R10:	0bcc27a8	R11:	0003f310
[  101.240415] [RCE] R12:	0000ed45	SP:	0bcc2768	LR:	0bcaaa2c	PC:	0bcaaa48
[  101.240423] [RCE] SPSR:	6000011f
[  101.240449] [RCE] DFSR:	00001008	DFAR:	15c01814	ADFSR:	00500000
[  101.240459] [RCE] IFSR:	00000000	IFAR:	00000000	AIFSR:	0000000

Trace log:


   kworker/0:5-478     [000] ....    94.735641: rtcpu_vinotify_event: tstamp:3562814093 cch:1 vi:0 tag:CHANSEL_PXL_SOF channel:0x23 frame:2400 vi_tstamp:114001598272 data:0x0000000000000001
     kworker/0:5-478     [000] ....    94.735641: rtcpu_vinotify_event: tstamp:3562814253 cch:1 vi:0 tag:VIFALC_ACTIONLST channel:0x23 frame:2400 vi_tstamp:114001600960 data:0x00000000080203f3
     kworker/0:5-478     [000] ....    94.735642: rtcpu_vinotify_event: tstamp:3563152516 cch:1 vi:0 tag:ATOMP_FRAME_NLINES_DONE channel:0x23 frame:2400 vi_tstamp:114016316160 data:0x0000000000000000
     kworker/0:5-478     [000] ....    94.735642: rtcpu_vinotify_event: tstamp:3563152677 cch:1 vi:0 tag:VIFALC_ACTIONLST channel:0x23 frame:2400 vi_tstamp:114016318720 data:0x00000000020203f3
     kworker/0:5-478     [000] ....    94.735643: rtcpu_vinotify_event: tstamp:3563491412 cch:1 vi:0 tag:ATOMP_FRAME_NLINES_DONE channel:0x23 frame:2400 vi_tstamp:114031045248 data:0x0000000000000000
     kworker/0:5-478     [000] ....    94.735643: rtcpu_vinotify_event: tstamp:3563491577 cch:1 vi:0 tag:VIFALC_ACTIONLST channel:0x23 frame:2400 vi_tstamp:114031047808 data:0x00000000020203f3
     kworker/0:5-478     [000] ....    94.735645: rtcpu_vinotify_event: tstamp:3563609671 cch:1 vi:0 tag:CHANSEL_PXL_EOF channel:0x23 frame:2400 vi_tstamp:114034685600 data:0x0000000004af0002
     kworker/0:5-478     [000] ....    94.735645: rtcpu_vinotify_event: tstamp:3563609834 cch:1 vi:0 tag:ATOMP_FRAME_DONE channel:0x23 frame:2400 vi_tstamp:114034686112 data:0x0000000000000000
     kworker/0:5-478     [000] ....    94.735646: rtcpu_vinotify_event: tstamp:3563609976 cch:1 vi:0 tag:VIFALC_ACTIONLST channel:0x23 frame:2400 vi_tstamp:114034690912 data:0x00000000020203f3
     kworker/0:5-478     [000] ....    94.735646: rtcpu_vinotify_event: tstamp:3563610136 cch:1 vi:0 tag:FE channel:0x00 frame:2400 vi_tstamp:114035414080 data:0x0000000000000020
     kworker/0:5-478     [000] ....    94.735647: rtcpu_vinotify_event: tstamp:3563610283 cch:1 vi:0 tag:ATOMP_FE channel:0x00 frame:2400 vi_tstamp:114035414080 data:0x0000000800000000
     kworker/0:5-478     [000] ....    94.735647: rtcpu_vinotify_event: tstamp:3563932377 cch:1 vi:0 tag:VIFALC_ACTIONLST channel:0x23 frame:2400 vi_tstamp:114035425344 data:0x00000000000203f3
     kworker/0:5-478     [000] ....    94.735653: rtcpu_nvcsi_intr: tstamp:3563942574 class:GLOBAL type:PHY_INTR0 phy:0 cil:0 st:0 vc:0 status:0x00000008
     kworker/0:5-478     [000] ....    94.735654: rtcpu_nvcsi_intr: tstamp:3563942574 class:CORRECTABLE_ERR type:PHY_INTR phy:0 cil:0 st:0 vc:0 status:0x00000008
 CaptureSchedule-2293    [001] ....    94.735661: csi_s_stream: enable : 0x0
 CaptureSchedule-2293    [001] ....    94.736786: tegra_channel_set_power: vc_mipi 9-001a : 0x0
 CaptureSchedule-2293    [001] ....    94.736799: camera_common_s_power: status : 0x0
 CaptureSchedule-2293    [001] ....    94.736830: tegra_channel_set_power: 13e10000.host1x:nvcsi@15a00000- : 0x0
 CaptureSchedule-2293    [001] ....    94.736832: csi_s_power: enable : 0x0
  nvargus-daemon-2277    [002] ....    94.792193: tegra_channel_close: vi-output, vc_mipi 9-001a
     kworker/0:5-478     [000] ....    94.847630: rtcpu_isp_falcon_task_start: tstamp:3565931685 ch:0 task:HANDLE_EVENT
     kworker/0:5-478     [000] ....    94.847635: rtcpu_isp_falcon_task_end: tstamp:3565931756 task:HANDLE_EVENT
     kworker/0:5-478     [000] ....   101.240342: rtcpu_string: tstamp:3761243274 id:0x04010000 str:"VM0 deactivating."
     kworker/0:5-478     [000] ....   101.240346: rtcpu_string: tstamp:3761607850 id:0x04010000 str:"*** DATA ABORT EXCEPTION ***
3

Hi,
Please try the gstreamer command and see if the issue is still present:

$ gst-launch-1.0 nvarguscamerasrc num-buffers=150 ! fakesink

To see if it can exit gracefully when setting num-buffers. And do you use Jetpack 4.6.3 or 5.1?

4

I am using Jetpack 5.0.2 and kernel version 5.10.104-tegra

The crash doesn’t happen all the time. It happens spuriously and only way to recover is to power cycle the board.

Will check this and get back to you.

5

@DaneLLL ,

It does happen with the gst-launch-1.0 as well.
Attaching log for you reference.

  368.575666] CPU:0, Error:rce-noc@0xbe00000,irq=21
[  368.575792] **************************************
[  368.575917] CPU:0, Error:rce-noc
[  368.576031] 	Error Logger		: 0
[  368.576110] 	ErrLog0			: 0x80030000
[  368.576190] 	  Transaction Type	: RD  - Read, Incrementing
[  368.576299] 	  Error Code		: SLV
[  368.576370] 	  Error Source		: Target
[  368.576445] 	  Error Description	: Target error detected by CBB slave
[  368.576576] 	  Packet header Lock	: 0
[  368.576652] 	  Packet header Len1	: 3
[  368.576740] 	  NOC protocol version	: version >= 2.7
[  368.576843] 	ErrLog1			: 0x157600
[  368.576916] 	ErrLog2			: 0x0
[  368.577004] 	  RouteId		: 0x157600
[  368.577076] 	  InitFlow		: cpu_p_i/I/0
[  368.577155] 	  Targflow		: cbb_t/T/0
[  368.583881] 	  TargSubRange		: 27
[  368.587033] 	  SeqId			: 0
[  368.589923] 	ErrLog3			: 0x5c01814
[  368.593417] 	ErrLog4			: 0x0
[  368.596129] 	  Address accessed	: 0x15c01814
[  368.600503] 	ErrLog5			: 0x387e31
[  368.603741] 	  Master ID		: RCE
[  368.606634] 	  Security Group(GRPSEC): 0x3f
[  368.610918] 	  Cache			: 0x1 -- Bufferable 
[  368.614859] 	  Protection		: 0x1 -- Privileged, Secure, Data Access
[  368.621329] 	  FALCONSEC		: 0x0
[  368.624478] 	  Virtual Queuing Channel(VQC): 0x0
[  368.628975] 	**************************************
[  368.634155] CPU:0, Error:cbb-noc@0x2300000,irq=15
[  368.638574] **************************************
[  368.643560] CPU:0, Error:cbb-noc
[  368.646824] 	Error Logger		: 0
[  368.650124] 	ErrLog0			: 0x80030000
[  368.653703] 	  Transaction Type	: RD  - Read, Incrementing
[  368.659041] 	  Error Code		: SLV
[  368.662453] 	  Error Source		: Target
[  368.665870] 	  Error Description	: Target error detected by CBB slave
[  368.672180] 	  AXI2APB_5 bridge error: RDFIFOF - Read Response FIFO Full interrupt
[  368.679817] 	  Packet header Lock	: 0
[  368.683717] 	  Packet header Len1	: 3
[  368.687394] 	  NOC protocol version	: version >= 2.7
[  368.692380] 	ErrLog1			: 0x9528aa
[  368.695704] 	ErrLog2			: 0x0
[  368.698334] 	  RouteId		: 0x9528aa
[  368.701917] 	  InitFlow		: rce_p2ps/I/rce_p2ps
[  368.706122] 	  Targflow		: host1x_p2pm/T/host1x_p2pm
[  368.710957] 	  TargSubRange		: 20
[  368.714171] 	  SeqId			: 0
[  368.716970] 	ErrLog3			: 0x1814
[  368.720204] 	ErrLog4			: 0x0
[  368.722835] 	  Address accessed	: 0x15c01814
[  368.727297] 	ErrLog5			: 0x2af0fc71
[  368.731054] 	  Non-Modify		: 0x1
[  368.734232] 	  AXI ID		: 0x55
[  368.737359] 	  Master ID		: RCE
[  368.740422] 	  Security Group(GRPSEC): 0x3f
[  368.744879] 	  Cache			: 0x1 -- Bufferable 
[  368.749101] 	  Protection		: 0x3 -- Privileged, Non-Secure, Data Access
[  368.755903] 	  FALCONSEC		: 0x0
[  368.759053] 	  Virtual Queuing Channel(VQC): 0x0
[  368.763694] 	**************************************
[  368.769212] Host read timeout at address 1814
[  368.773254] [RCE] VM0 deactivating.VM0 activating.VM0 deactivating.VM0 activating.VM0 deactivating.VM0 activating.VM0 deactivating.VM0 activating.VM0 deactivating.*** DATA ABORT EXCEPTION ***
[  368.773266] [RCE] R0:	15c00000	R1:	00001814	R2:	00008010	R3:	00000002
[  368.773300] [RCE] R4:	0bcd0188	R5:	00000000	R6:	00000000	R7:	799ce800
[  368.773309] [RCE] R8:	0bcc27b0	R9:	0bcc27b2	R10:	0bcc27a8	R11:	00009c10
[  368.773317] [RCE] R12:	0000ed44	SP:	0bcc2768	LR:	0bcaaa2c	PC:	0bcaaa48
[  368.773325] [RCE] SPSR:	6000011f
[  368.773332] [RCE] DFSR:	00001008	DFAR:	15c01814	ADFSR:	00500000
[  368.773338] [RCE] IFSR:	00000000	IFAR:	00000000	AIFSR:	00000000
[  368.773359] tegra186-cam-rtcpu bc00000.rtcpu: Alert: Camera RTCPU gone bad! restoring it immediately!!
[  370.592923]  bc00000.rtcpu:hsp-vm1: request 0x43000000: response timeout
[  370.593156]  bc00000.rtcpu:hsp-vm1: PM_SUSPEND failed: 0xffffff92
[  370.593165] tegra186-cam-rtcpu bc00000.rtcpu: RTCPU suspend failed, resetting it
[  371.319215] CPU:0, Error:rce-noc@0xbe00000,irq=20
[  371.319351] **************************************
[  371.319467] CPU:0, Error:rce-noc
[  371.319545] 	Error Logger		: 1
[  371.319659] 	ErrLog0			: 0x801f0602
[  371.319737] 	  Transaction Type	: RDW - Read, Wrap
[  371.319833] 	  Error Code		: TMO
[  371.319905] 	  Error Source		: Target NIU
[  371.319988] 	  Error Description	: Target time-out error
[  371.320095] 	  Packet header Lock	: 0
[  371.320184] 	  Packet header Len1	: 31
[  371.320264] 	  NOC protocol version	: version >= 2.7
[  371.320362] 	ErrLog1			: 0xcc006
[  371.320430] 	ErrLog2			: 0x0
[  371.320490] 	  RouteId		: 0xcc006
[  371.320560] 	  InitFlow		: cpu_m_i/I/0
[  371.320640] 	  Targflow		: ast0_t/T/0
[  371.320714] 	  TargSubRange		: 0
[  371.320781] 	  SeqId			: 0
[  371.320840] 	ErrLog3			: 0x47000
[  371.320911] 	ErrLog4			: 0x0
[  371.320972] 	  Address accessed	: 0x40047000
[  371.321278] 	ErrLog5			: 0x387e3f
[  371.321540] 	  Master ID		: RCE
[  371.321734] 	  Security Group(GRPSEC): 0x3f
[  371.322120] 	  Cache			: 0xf -- Bufferable Modifiable Read-Allocate Write-Allocate
[  371.329564] 	  Protection		: 0xf -- Privileged, Non-Secure, Instruction Access
[  371.336480] 	  FALCONSEC		: 0x0
[  371.339707] 	  Virtual Queuing Channel(VQC): 0x0
[  371.344195] 	**************************************
[  371.431819] CPU:0, Error:rce-noc@0xbe00000,irq=20
[  371.431960] **************************************
[  371.432060] CPU:0, Error:rce-noc
[  371.432132] 	Error Logger		: 1
[  371.432207] 	ErrLog0			: 0x801f0600
[  371.432284] 	  Transaction Type	: RD  - Read, Incrementing
[  371.432396] 	  Error Code		: TMO
[  371.432469] 	  Error Source		: Target NIU
[  371.432556] 	  Error Description	: Target time-out error
[  371.432664] 	  Packet header Lock	: 0
[  371.432738] 	  Packet header Len1	: 31
[  371.432819] 	  NOC protocol version	: version >= 2.7
[  371.432916] 	ErrLog1			: 0xcc002
[  371.432996] 	ErrLog2			: 0x0
[  371.433062] 	  RouteId		: 0xcc002
[  371.433132] 	  InitFlow		: cpu_m_i/I/0
[  371.433212] 	  Targflow		: ast0_t/T/0
[  371.433287] 	  TargSubRange		: 0
[  371.433356] 	  SeqId			: 0
[  371.433418] 	ErrLog3			: 0x30000060
[  371.433494] 	ErrLog4			: 0x0
[  371.433592] 	  Address accessed	: 0x70000060
[  371.433899] 	ErrLog5			: 0x387e73
[  371.436598] 	  Master ID		: RCE
[  371.439720] 	  Security Group(GRPSEC): 0x3f
[  371.443746] 	  Cache			: 0x3 -- Bufferable Modifiable 
[  371.448823] 	  Protection		: 0x3 -- Privileged, Non-Secure, Data Access
[  371.455471] 	  FALCONSEC		: 0x0
[  371.458618] 	  Virtual Queuing Channel(VQC): 0x0
[  371.462913] 	**************************************
[  372.608923]  bc00000.rtcpu:hsp-vm1: request 0x40489991: response timeout
[  374.632875]  bc00000.rtcpu:hsp-vm1: request 0x4009e096: response timeout
[  374.633112] tegra186-cam-rtcpu bc00000.rtcpu: rce full reset, retry 2/3
[  374.633637] CPU:0, Error:rce-noc@0xbe00000,irq=20
[  374.633748] **************************************
[  374.633858] CPU:0, Error:rce-noc
[  374.633959] 	Error Logger		: 1
[  374.634038] 	ErrLog0			: 0x801f0600
[  374.634119] 	  Transaction Type	: RD  - Read, Incrementing
[  374.634232] 	  Error Code		: TMO
[  374.634301] 	  Error Source		: Target NIU
[  374.634386] 	  Error Description	: Target time-out error
[  374.634505] 	  Packet header Lock	: 0
[  374.634605] 	  Packet header Len1	: 31
[  374.634687] 	  NOC protocol version	: version >= 2.7
[  374.634789] 	ErrLog1			: 0xcc002
[  374.634859] 	ErrLog2			: 0x0
[  374.634920] 	  RouteId		: 0xcc002
[  374.634991] 	  InitFlow		: cpu_m_i/I/0
[  374.635072] 	  Targflow		: ast0_t/T/0
[  374.635147] 	  TargSubRange		: 0
[  374.635216] 	  SeqId			: 0
[  374.635276] 	ErrLog3			: 0x30000060
[  374.635378] 	ErrLog4			: 0x0
[  374.635583] 	  Address accessed	: 0x70000060
[  374.639711] 	ErrLog5			: 0x387e73
[  374.642949] 	  Master ID		: RCE
[  374.645841] 	  Security Group(GRPSEC): 0x3f
[  374.649867] 	  Cache			: 0x3 -- Bufferable Modifiable 
[  374.655199] 	  Protection		: 0x3 -- Privileged, Non-Secure, Data Access
[  374.661851] 	  FALCONSEC		: 0x0
[  374.664998] 	  Virtual Queuing Channel(VQC): 0x0
[  374.669295] 	**************************************
[  376.640890]  bc00000.rtcpu:hsp-vm1: request 0x40cf016d: response timeout
[  378.656862]  bc00000.rtcpu:hsp-vm1: request 0x408c7772: response timeout
[  378.657128] tegra186-cam-rtcpu bc00000.rtcpu: rce full reset, retry 2/3
[  378.657924] CPU:0, Error:rce-noc@0xbe00000,irq=20
[  378.658050] **************************************
[  378.658154] CPU:0, Error:rce-noc
[  378.658229] 	Error Logger		: 1
[  378.658343] 	ErrLog0			: 0x801f0600
[  378.658421] 	  Transaction Type	: RD  - Read, Incrementing
[  378.658528] 	  Error Code		: TMO
[  378.658615] 	  Error Source		: Target NIU
[  378.658704] 	  Error Description	: Target time-out error
[  378.658816] 	  Packet header Lock	: 0
[  378.658892] 	  Packet header Len1	: 31
[  378.658972] 	  NOC protocol version	: version >= 2.7
[  378.659071] 	ErrLog1			: 0xcc002
[  378.659142] 	ErrLog2			: 0x0
[  378.659203] 	  RouteId		: 0xcc002
[  378.659303] 	  InitFlow		: cpu_m_i/I/0
[  378.659384] 	  Targflow		: ast0_t/T/0
[  378.659459] 	  TargSubRange		: 0
[  378.659528] 	  SeqId			: 0
[  378.659587] 	ErrLog3			: 0x30000060
[  378.659672] 	ErrLog4			: 0x0
[  378.659757] 	  Address accessed	: 0x70000060
[  378.663433] 	ErrLog5			: 0x387e73
[  378.666925] 	  Master ID		: RCE
[  378.670073] 	  Security Group(GRPSEC): 0x3f
[  378.674100] 	  Cache			: 0x3 -- Bufferable Modifiable 
[  378.678918] 	  Protection		: 0x3 -- Privileged, Non-Secure, Data Access
[  378.685568] 	  FALCONSEC		: 0x0
[  378.688717] 	  Virtual Queuing Channel(VQC): 0x0
[  378.693527] 	**************************************
[  380.672860]  bc00000.rtcpu:hsp-vm1: request 0x404dcfac: response timeout
[  380.673074] tegra186-cam-rtcpu bc00000.rtcpu: rce full reset, retry 3/3
[  380.673584] CPU:0, Error:rce-noc@0xbe00000,irq=20
[  380.673685] **************************************
[  380.673785] CPU:0, Error:rce-noc
[  380.673858] 	Error Logger		: 1
[  380.673939] 	ErrLog0			: 0x801f0600
[  380.674014] 	  Transaction Type	: RD  - Read, Incrementing
[  380.674123] 	  Error Code		: TMO
[  380.674192] 	  Error Source		: Target NIU
[  380.674277] 	  Error Description	: Target time-out error
[  380.674387] 	  Packet header Lock	: 0
[  380.674464] 	  Packet header Len1	: 31
[  380.674543] 	  NOC protocol version	: version >= 2.7
[  380.674639] 	ErrLog1			: 0xcc002
[  380.674733] 	ErrLog2			: 0x0
[  380.674799] 	  RouteId		: 0xcc002
[  380.674869] 	  InitFlow		: cpu_m_i/I/0
[  380.674964] 	  Targflow		: ast0_t/T/0
[  380.675037] 	  TargSubRange		: 0
[  380.675106] 	  SeqId			: 0
[  380.675168] 	ErrLog3			: 0x30000060
[  380.675379] 	ErrLog4			: 0x0
[  380.675614] 	  Address accessed	: 0x70000060
[  380.679444] 	ErrLog5			: 0x387e73
[  380.682940] 	  Master ID		: RCE
[  380.686088] 	  Security Group(GRPSEC): 0x3f
[  380.690115] 	  Cache			: 0x3 -- Bufferable Modifiable 
[  380.694954] 	  Protection		: 0x3 -- Privileged, Non-Secure, Data Access
[  380.701838] 	  FALCONSEC		: 0x0
[  380.704988] 	  Virtual Queuing Channel(VQC): 0x0
[  380.709543] 	**************************************
[  382.688906]  bc00000.rtcpu:hsp-vm1: request 0x400f1a65: response timeout
[  382.689124] tegra186-cam-rtcpu bc00000.rtcpu: rce full reset, retry 3/3
[  382.689650] CPU:0, Error:rce-noc@0xbe00000,irq=20
[  382.689756] **************************************
[  382.689856] CPU:0, Error:rce-noc
[  382.689939] 	Error Logger		: 1
[  382.690036] 	ErrLog0			: 0x801f0600
[  382.690112] 	  Transaction Type	: RD  - Read, Incrementing
[  382.690220] 	  Error Code		: TMO
[  382.690288] 	  Error Source		: Target NIU
[  382.690370] 	  Error Description	: Target time-out error
[  382.690479] 	  Packet header Lock	: 0
[  382.690553] 	  Packet header Len1	: 31
[  382.690631] 	  NOC protocol version	: version >= 2.7
[  382.690728] 	ErrLog1			: 0xcc002
[  382.690796] 	ErrLog2			: 0x0
[  382.690855] 	  RouteId		: 0xcc002
[  382.690925] 	  InitFlow		: cpu_m_i/I/0
[  382.691018] 	  Targflow		: ast0_t/T/0
[  382.691094] 	  TargSubRange		: 0
[  382.691163] 	  SeqId			: 0
[  382.691221] 	ErrLog3			: 0x30000060
[  382.691438] 	ErrLog4			: 0x0
[  382.691639] 	  Address accessed	: 0x70000060
[  382.695743] 	ErrLog5			: 0x387e73
[  382.698724] 	  Master ID		: RCE
[  382.701873] 	  Security Group(GRPSEC): 0x3f
[  382.706157] 	  Cache			: 0x3 -- Bufferable Modifiable 
[  382.710974] 	  Protection		: 0x3 -- Privileged, Non-Secure, Data Access
[  382.717623] 	  FALCONSEC		: 0x0
[  382.720773] 	  Virtual Queuing Channel(VQC): 0x0
[  382.725325] 	**************************************
6

@DaneLLL ,

Is there any update on this? Should I try anything else? We are sort of stuck on this issue as we need to power cycle the system every time this happens.

7

Hi,
Do you observe the issue on Xavier NX developer kit or your custom board? It seems like the system is not stable in the condition and the hardware capture crashes.

8

@DaneLLL

This happens in DevKit as well as our custom board.

9

Hi,
Xavier NX developer kit + Raspberry Pi v2 camera is in our test coverage so it is supposed to work. Ideally this should not happen on developer kit, but we will set up and test again.

10

Hi,

WIth Raspberry Pi camera, this doesn’t happen. This happens with Sony IMX392 camera from Vision Components which has SubLVDS to MIPI conversion via FPGA.

11

Hi,
Are you able to upgrade to Jetpack 5.1 and try? There are certain fixes for Argus between 5.0.2 and 5.1 and it is better to use 5.1.

12

@DaneLLL ,

That’ll be some work for us as we have all our applications targeted on JP 5.0.2. Is there anything else we can try with JP 5.0.2 or JP 5.1 is the only way?

Also, the issue happens without Argus. i.e with v4l2 application.

13

Hi,

For this description, do you mean it works well with Argus software stacks, and fails in capturing RAW frames in v4l2-ctl commands? And what’s the failure rate?

15

Hi @DaneLLL ,

No. You had mentioned that there are improvements in LibArgus from JP5.0.2 to JP5.1 and that might solve the problem. For that, I added that even without the libargus application (with v4l2-ctl utils) the issue happens.

Regarding v4l2-ctl raw capture, the failure rate little lesser than Argus application.
e.g
with argus, it’s once in 3 or 4 capture cycles
with v4l2-ctl, it’s once in 5 or 6 capture cycles.

I am trying to flash JP5.1 and check.

16

Hi,
Please use this firmware to get further information while replicating the issue:

Jetson/L4T/r35.1.x patches - eLinux.org

[RCE] JetPack-5.0.2/l4t-r35.1 camera firmware with debug flag enabled

1 Like
17

Hi @DaneLLL ,

This is with debug flag enabled RTCPU firmware logs. (this is with JP 5.0.2. Will share the logs for JP5.1 sooner).

Dmesg logs:

[   92.623063] [RCE] VM0 deactivating.VM0 activating.NVCSILP clock rate = 204000000 Hz.
[   92.623077] [RCE] tegra_nvcsi_stream_set_config(vm0, stream=0, csi=0)
[   92.623087] [RCE] MIPI clock = 185625 kHz, tHS-SETTLE = 0, tCLK-SETTLE = 0
[   92.623095] [RCE] ===== NVCSI Stream Configuration =====
[   92.623102] [RCE] stream_id: PP 0, csi_port: PORT A
[   92.623108] [RCE] Brick: PHY 0, Mode: D-PHY
[   92.623115] [RCE] Partition: CIL A, LP bypass: Enabled, Lanes: 2
[   92.623122] [RCE] Clock information:
[   92.623129] [RCE] MIPI clock rate: 185.62 MHz
[   92.623136] [RCE] T_HS settle: 0, T_CLK settle: 0
[   92.623143] [RCE] ======================================
[   92.623150] [RCE] tegra_nvcsi_stream_open(vm0, stream=0, csi=0)
[   92.623157] [RCE] nvcsi_calc_ths_settle ths_settle 22
[   92.623164] [RCE] nvcsi_calc_ths_settle ths_settle 22
[   92.623171] [RCE] nvcsi_calc_tclk_settle tclk_settle 33
[   93.219209] vc_mipi 9-001a: vc_sen_set_roi(): Set sensor roi: (left: 0, top: 0, width: 1920, height: 1200)
[   93.222661] vc_mipi 9-001a: vc_sen_set_exposure(): Set sensor exposure: 10000 us
[   93.225567] vc_mipi 9-001a: vc_sen_set_gain(): Set sensor gain: 0
[   93.227624] vc_mipi 9-001a: vc_sen_set_blacklevel(): Set sensor black level: 60
[   93.229639] vc_mipi 9-001a: vc_sen_start_stream(): Start streaming
[  103.467141] vc_mipi 9-001a: vc_sen_stop_stream(): Stop streaming
[  103.559065] [RCE] tegra_nvcsi_stream_close(vm0, stream=0, csi=0)
[  109.772567] CPU:0, Error:rce-noc@0xbe00000,irq=21
[  109.774387] **************************************
[  109.776074] CPU:0, Error:rce-noc
[  109.777631] 	Error Logger		: 0
[  109.779250] 	ErrLog0			: 0x80030000
[  109.780826] 	  Transaction Type	: RD  - Read, Incrementing
[  109.782440] 	  Error Code		: SLV
[  109.783975] 	  Error Source		: Target
[  109.785544] 	  Error Description	: Target error detected by CBB slave
[  109.787199] 	  Packet header Lock	: 0
[  109.788759] 	  Packet header Len1	: 3
[  109.790315] 	  NOC protocol version	: version >= 2.7
[  109.791912] 	ErrLog1			: 0x157600
[  109.793461] 	ErrLog2			: 0x0
[  109.794995] 	  RouteId		: 0x157600
[  109.796526] 	  InitFlow		: cpu_p_i/I/0
[  109.798129] 	  Targflow		: cbb_t/T/0
[  109.799707] 	  TargSubRange		: 27
[  109.801251] 	  SeqId			: 0
[  109.802791] 	ErrLog3			: 0x5c01814
[  109.804322] 	ErrLog4			: 0x0
[  109.805866] 	  Address accessed	: 0x15c01814
[  109.807394] 	ErrLog5			: 0x387e31
[  109.809300] 	  Master ID		: RCE
[  109.812979] 	  Security Group(GRPSEC): 0x3f
[  109.817795] 	  Cache			: 0x1 -- Bufferable 
[  109.822693] 	  Protection		: 0x1 -- Privileged, Secure, Data Access
[  109.829693] 	  FALCONSEC		: 0x0
[  109.833799] 	  Virtual Queuing Channel(VQC): 0x0
[  109.839070] 	**************************************
[  109.845012] CPU:0, Error:cbb-noc@0x2300000,irq=15
[  109.849994] **************************************
[  109.855412] CPU:0, Error:cbb-noc
[  109.859350] 	Error Logger		: 0
[  109.863208] 	ErrLog0			: 0x80030000
[  109.867313] 	  Transaction Type	: RD  - Read, Incrementing
[  109.873612] 	  Error Code		: SLV
[  109.877118] 	  Error Source		: Target
[  109.881492] 	  Error Description	: Target error detected by CBB slave
[  109.888934] 	  AXI2APB_5 bridge error: RDFIFOF - Read Response FIFO Full interrupt
[  109.897242] 	  Packet header Lock	: 0
[  109.901611] 	  Packet header Len1	: 3
[  109.905900] 	  NOC protocol version	: version >= 2.7
[  109.911243] 	ErrLog1			: 0x9528aa
[  109.915613] 	ErrLog2			: 0x0
[  109.919290] 	  RouteId		: 0x9528aa
[  109.923487] 	  InitFlow		: rce_p2ps/I/rce_p2ps
[  109.928479] 	  Targflow		: host1x_p2pm/T/host1x_p2pm
[  109.934337] 	  TargSubRange		: 20
[  109.938536] 	  SeqId			: 0
[  109.941862] 	ErrLog3			: 0x1814
[  109.945798] 	ErrLog4			: 0x0
[  109.949389] 	  Address accessed	: 0x15c01814
[  109.954374] 	ErrLog5			: 0x2af0fc71
[  109.958141] 	  Non-Modify		: 0x1
[  109.962079] 	  AXI ID		: 0x55
[  109.965923] 	  Master ID		: RCE
[  109.969518] 	  Security Group(GRPSEC): 0x3f
[  109.974676] 	  Cache			: 0x1 -- Bufferable 
[  109.979318] 	  Protection		: 0x3 -- Privileged, Non-Secure, Data Access
[  109.986405] 	  FALCONSEC		: 0x0
[  109.990255] 	  Virtual Queuing Channel(VQC): 0x0
[  109.995938] 	**************************************
[  110.001644] Host read timeout at address 1814
[  110.007144] [RCE] VM0 deactivating.*** DATA ABORT EXCEPTION ***
[  110.007161] [RCE] R0:	15c00000	R1:	00001814	R2:	00008010	R3:	00000000
[  110.007177] [RCE] R4:	0bcd1988	R5:	00000000	R6:	00000000	R7:	799ce800
[  110.007191] [RCE] R8:	0bcc3fb0	R9:	0bcc3fb2	R10:	0bcc3fa8	R11:	0002f240
[  110.007203] [RCE] R12:	00006d19	SP:	0bcc3f68	LR:	0bcab9e8	PC:	0bcaba04
[  110.007212] [RCE] SPSR:	6000011f
[  110.007221] [RCE] DFSR:	00001008	DFAR:	15c01814	ADFSR:	00500000
[  110.007229] [RCE] IFSR:	00000000	IFAR:	00000000	AIFSR:	00000000

Trace logs:

203e7
 vi-output, vc_m-3229    [000] ....   103.456992: tegra_channel_capture_frame: sof:128.360358880
 vi-output, vc_m-3229    [000] ....   103.456994: tegra_channel_capture_frame: eof:128.368924480
 vi-output, vc_m-3229    [000] ....   103.467049: tegra_channel_capture_frame: sof:128.370423488
 vi-output, vc_m-3229    [000] ....   103.467051: tegra_channel_capture_frame: eof:128.378989024
        v4l2-ctl-3227    [001] ....   103.467092: tegra_channel_set_stream: enable : 0x0
        v4l2-ctl-3227    [001] ....   103.467108: tegra_channel_set_stream: vc_mipi 9-001a : 0x0
     kworker/0:2-85      [000] ....   103.503052: rtcpu_vinotify_event: tstamp:4011529132 cch:0 vi:0 tag:FE channel:0x00 frame:0 vi_tstamp:128358859872 data:0x0000000000000020
     kworker/0:2-85      [000] ....   103.503054: rtcpu_vinotify_event: tstamp:4011529285 cch:0 vi:0 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:128358859872 data:0x0000000800000000
     kworker/0:2-85      [000] ....   103.503055: rtcpu_vinotify_event: tstamp:4011529450 cch:0 vi:0 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:128358882048 data:0x00000000000203e7
     kworker/0:2-85      [000] ....   103.503055: rtcpu_vinotify_event: tstamp:4011529590 cch:0 vi:0 tag:FS channel:0x00 frame:0 vi_tstamp:128360280288 data:0x0000000000000010
     kworker/0:2-85      [000] ....   103.503057: rtcpu_vinotify_event: tstamp:4011531587 cch:0 vi:0 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:128360280288 data:0x0000000800000000
     kworker/0:2-85      [000] ....   103.503057: rtcpu_vinotify_event: tstamp:4011531731 cch:0 vi:0 tag:CHANSEL_PXL_SOF channel:0x23 frame:0 vi_tstamp:128360358880 data:0x0000000000000001
     kworker/0:2-85      [000] ....   103.503058: rtcpu_vinotify_event: tstamp:4011531894 cch:0 vi:0 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:128360361568 data:0x00000000080203e8
     kworker/0:2-85      [000] ....   103.503058: rtcpu_vinotify_event: tstamp:4011532033 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:128360457984 data:0xcd9ce50010000000
     kworker/0:2-85      [000] ....   103.503059: rtcpu_vinotify_event: tstamp:4011532195 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:128360469952 data:0x00000000310003e9
     kworker/0:2-85      [000] ....   103.503059: rtcpu_vinotify_event: tstamp:4011574337 cch:0 vi:0 tag:CHANSEL_PXL_EOF channel:0x23 frame:0 vi_tstamp:128368923776 data:0x0000000004af0002
     kworker/0:2-85      [000] ....   103.503060: rtcpu_vinotify_event: tstamp:4011574508 cch:0 vi:0 tag:ATOMP_FRAME_DONE channel:0x23 frame:0 vi_tstamp:128368924320 data:0x0000000000000000
     kworker/0:2-85      [000] ....   103.503060: rtcpu_vinotify_event: tstamp:4011574651 cch:0 vi:0 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:128368930912 data:0x00000000020203e8
     kworker/0:2-85      [000] ....   103.503061: rtcpu_vinotify_event: tstamp:4011574820 cch:0 vi:0 tag:FE channel:0x00 frame:0 vi_tstamp:128368924448 data:0x0000000000000020
     kworker/0:2-85      [000] ....   103.503061: rtcpu_vinotify_event: tstamp:4011574966 cch:0 vi:0 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:128368924480 data:0x0000000800000000
     kworker/0:2-85      [000] ....   103.503062: rtcpu_vinotify_event: tstamp:4011575126 cch:0 vi:0 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:128368942240 data:0x00000000000203e8
     kworker/0:2-85      [000] ....   103.503062: rtcpu_vinotify_event: tstamp:4011575267 cch:0 vi:0 tag:FS channel:0x00 frame:0 vi_tstamp:128370344832 data:0x0000000000000010
     kworker/0:2-85      [000] ....   103.503064: rtcpu_vinotify_event: tstamp:4011894245 cch:0 vi:0 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:128370344864 data:0x0000000800000000
     kworker/0:2-85      [000] ....   103.503065: rtcpu_vinotify_event: tstamp:4011894407 cch:0 vi:0 tag:CHANSEL_PXL_SOF channel:0x23 frame:0 vi_tstamp:128370423488 data:0x0000000000000001
     kworker/0:2-85      [000] ....   103.503065: rtcpu_vinotify_event: tstamp:4011894594 cch:0 vi:0 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:128370426176 data:0x00000000080203e9
     kworker/0:2-85      [000] ....   103.503066: rtcpu_vinotify_event: tstamp:4011894734 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:128370526592 data:0xcd9ce20010000000
     kworker/0:2-85      [000] ....   103.503066: rtcpu_vinotify_event: tstamp:4011894893 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:128370538528 data:0x00000000310003ea
     kworker/0:2-85      [000] ....   103.503067: rtcpu_vinotify_event: tstamp:4011895034 cch:0 vi:0 tag:CHANSEL_PXL_EOF channel:0x23 frame:0 vi_tstamp:128378988352 data:0x0000000004af0002
     kworker/0:2-85      [000] ....   103.503067: rtcpu_vinotify_event: tstamp:4011895192 cch:0 vi:0 tag:ATOMP_FRAME_DONE channel:0x23 frame:0 vi_tstamp:128378988896 data:0x0000000000000000
     kworker/0:2-85      [000] ....   103.503068: rtcpu_vinotify_event: tstamp:4011895333 cch:0 vi:0 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:128378994432 data:0x00000000020203e9
     kworker/0:2-85      [000] ....   103.503068: rtcpu_vinotify_event: tstamp:4011895504 cch:0 vi:0 tag:FE channel:0x00 frame:0 vi_tstamp:128378988992 data:0x0000000000000020
     kworker/0:2-85      [000] ....   103.503069: rtcpu_vinotify_event: tstamp:4011895649 cch:0 vi:0 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:128378989024 data:0x0000000800000000
     kworker/0:2-85      [000] ....   103.503069: rtcpu_vinotify_event: tstamp:4011895810 cch:0 vi:0 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:128379005728 data:0x00000000000203e9
     kworker/0:2-85      [000] ....   103.503070: rtcpu_vinotify_event: tstamp:4011895949 cch:0 vi:0 tag:FS channel:0x00 frame:0 vi_tstamp:128380409408 data:0x0000000000000010
     kworker/0:2-85      [000] ....   103.503070: rtcpu_vinotify_event: tstamp:4011896115 cch:0 vi:0 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:128380409408 data:0x0000000800000000
     kworker/0:2-85      [000] ....   103.503071: rtcpu_vinotify_event: tstamp:4011896256 cch:0 vi:0 tag:CHANSEL_PXL_SOF channel:0x23 frame:0 vi_tstamp:128380488032 data:0x0000000000000001
     kworker/0:2-85      [000] ....   103.503071: rtcpu_vinotify_event: tstamp:4011896414 cch:0 vi:0 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:128380490752 data:0x00000000080203ea
     kworker/0:2-85      [000] ....   103.503071: rtcpu_vinotify_event: tstamp:4011896553 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:128380586176 data:0xcd9ce50010000000
     kworker/0:2-85      [000] ....   103.503072: rtcpu_vinotify_event: tstamp:4012207217 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:128380624192 data:0x00000000310003eb
        v4l2-ctl-3227    [001] ....   103.519654: tegra_channel_set_stream: 13e10000.host1x:nvcsi@15a00000- : 0x0
        v4l2-ctl-3227    [001] ....   103.519659: csi_s_stream: enable : 0x0
        v4l2-ctl-3227    [000] ....   103.521902: tegra_channel_set_power: vc_mipi 9-001a : 0x0
        v4l2-ctl-3227    [000] ....   103.521914: camera_common_s_power: status : 0x0
        v4l2-ctl-3227    [000] ....   103.521922: tegra_channel_set_power: 13e10000.host1x:nvcsi@15a00000- : 0x0
        v4l2-ctl-3227    [000] ....   103.521925: csi_s_power: enable : 0x0
        v4l2-ctl-3227    [000] ....   103.530339: tegra_channel_close: vi-output, vc_mipi 9-001a
     kworker/0:2-85      [000] ....   103.559048: rtcpu_string: tstamp:4013493240 id:0x04010000 str:"tegra_nvcsi_stream_close(vm0, stream=0, csi=0)
"
     kworker/0:2-85      [000] ....   103.559076: rtcpu_vinotify_event: tstamp:4013563733 cch:-1 vi:0 tag:FE channel:0x00 frame:0 vi_tstamp:128433040288 data:0x0000000000000020
     kworker/0:2-85      [000] ....   103.559077: rtcpu_vinotify_event: tstamp:4013563895 cch:-1 vi:0 tag:CHANSEL_SHORT_FRAME channel:0x01 frame:0 vi_tstamp:128433040288 data:0x0000200001000000
     kworker/0:2-85      [000] ....   103.559077: rtcpu_vinotify_event: tstamp:4013564040 cch:-1 vi:0 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:128433040320 data:0x0000000800000000
    kworker/0:10-145     [000] ....   110.007114: rtcpu_string: tstamp:4208514568 id:0x04010000 str:"VM0 deactivating."
    kworker/0:10-145     [000] ....   110.007134: rtcpu_string: tstamp:4208895608 id:0x04010000 str:"*** DATA ABORT EXCEPTION ***
"
    kworker/0:10-145     [000] ....   110.007154: rtcpu_string: tstamp:4208909365 id:0x04010000 str:"R0:	15c00000	R1:	00001814	R2:	00008010	R3:	00000"
    kworker/0:10-145     [000] ....   110.007158: rtcpu_string: tstamp:4208911240 id:0x04010000 str:"000
"
    kworker/0:10-145     [000] ....   110.007168: rtcpu_string: tstamp:4208927151 id:0x04010000 str:"R4:	0bcd1988	R5:	00000000	R6:	00000000	R7:	799ce"
    kworker/0:10-145     [000] ....   110.007172: rtcpu_string: tstamp:4208928974 id:0x04010000 str:"800
"
    kworker/0:10-145     [000] ....   110.007185: rtcpu_string: tstamp:4208944951 id:0x04010000 str:"R8:	0bcc3fb0	R9:	0bcc3fb2	R10:	0bcc3fa8	R11:	000"
    kworker/0:10-145     [000] ....   110.007188: rtcpu_string: tstamp:4208946793 id:0x04010000 str:"2f240
"
    kworker/0:10-145     [000] ....   110.007197: rtcpu_string: tstamp:4208962666 id:0x04010000 str:"R12:	00006d19	SP:	0bcc3f68	LR:	0bcab9e8	PC:	0bca"
    kworker/0:10-145     [000] ....   110.007200: rtcpu_string: tstamp:4208964508 id:0x04010000 str:"ba04
"
    kworker/0:10-145     [000] ....   110.007210: rtcpu_string: tstamp:4208979033 id:0x04010000 str:"SPSR:	6000011f
"
    kworker/0:10-145     [000] ....   110.007218: rtcpu_string: tstamp:4208989541 id:0x04010000 str:"DFSR:	00001008	DFAR:	15c01814	ADFSR:	00500000
"
    kworker/0:10-145     [000] ....   110.007227: rtcpu_string: tstamp:4209028727 id:0x04010000 str:"IFSR:	00000000	IFAR:	00000000	AIFSR:	00000000
18

Hi @DaneLLL ,

Even with the JP 5.1, the problem exists. Unfortunately, the dmesg buffer overrun (over 1.1GB) and I had to power off the system. I will try to get the logs sooner. I want to just update that the problem still exists in JP5.1 and error logs are similar to JP 5.0.2.

19

Hi @DaneLLL ,

Logs with JP5.1

Dmesg logs


[  269.039711] vc_mipi 9-001a: vc_core_set_format(): Set format 0x300f (RG10)
[  269.039899] vc_mipi 9-001a: vc_core_try_format(): Try format 0x300f (RG10, format: 0x2b)
[  269.039930] vc_mipi 9-001a: clk pixel: 74250000
[  269.040035] vc_mipi 9-001a: clk pixel: 74250000
[  269.040143] vc_mipi 9-001a: vc_core_update_controls(): num_lanes: 2, format 43, exposure.max: 7484656 us, framerate.max: 111906 mHz
[  269.040399] vc_mipi 9-001a: selected mode is 0
[  269.040492] vc_mipi 9-001a: vc_update_image_size_from_mode(): Update image size from mode0 (l: 0, t: 0, w: 1920, h: 1200)
[  269.040706] vc_mipi 9-001a: selected mode is 0
[  269.040796] vc_mipi 9-001a: selected mode is 0
[  269.040922] vc_mipi 9-001a: Err: 0 111906 1 0
[  269.040931] vc_mipi 9-001a: vc_sen_set_roi(): Set sensor roi: (left: 0, top: 0, width: 1920, height: 1200)
[  269.042423] vc_mipi 9-001a: vc_sen_set_exposure(): Set sensor exposure: 10000 us
[  269.042622] vc_mipi 9-001a: clk pixel: 74250000
[  269.044468] vc_mipi 9-001a: vc_sen_start_stream(): Start streaming
[  269.051691] [RCE] VM0 deactivating.VM0 activating.NVCSILP clock rate = 204000000 Hz.
[  269.051701] [RCE] tegra_nvcsi_stream_set_config(vm0, stream=0, csi=0)
[  269.051706] [RCE] MIPI clock = 200000 kHz, tHS-SETTLE = 0, tCLK-SETTLE = 0
[  269.051711] [RCE] ===== NVCSI Stream Configuration =====
[  269.051715] [RCE] stream_id: PP 0, csi_port: PORT A
[  269.051720] [RCE] Brick: PHY 0, Mode: D-PHY
[  269.051725] [RCE] Partition: CIL A, LP bypass: Enabled, Lanes: 2
[  269.051729] [RCE] Clock information:
[  269.051733] [RCE] MIPI clock rate: 200.00 MHz
[  269.051738] [RCE] T_HS settle: 0, T_CLK settle: 0
[  269.051742] [RCE] ======================================
[  269.051747] [RCE] tegra_nvcsi_stream_open(vm0, stream=0, csi=0)
[  269.051756] [RCE] nvcsi_calc_ths_settle ths_settle 22
[  269.051761] [RCE] nvcsi_calc_ths_settle ths_settle 22
[  269.051765] [RCE] nvcsi_calc_tclk_settle tclk_settle 33
[  279.290689] vc_mipi 9-001a: vc_sen_stop_stream(): Stop streaming
[  279.387624] [RCE] tegra_nvcsi_stream_close(vm0, stream=0, csi=0)
[  284.455956] CPU:0, Error: rce-noc@be00000, irq=21
[  284.456096] **************************************
[  284.456228] CPU:0, Error:rce-noc
[  284.456307] 	Error Logger		: 0
[  284.456384] 	ErrLog0			: 0x80030000
[  284.456461] 	  Transaction Type	: RD  - Read, Incrementing
[  284.456571] 	  Error Code		: SLV
[  284.456641] 	  Error Source		: Target
[  284.456732] 	  Error Description	: Target error detected by CBB slave
[  284.456870] 	  AXI2APB_5 bridge error: RDFIFOF - Read Response FIFO Full interrupt
[  284.457034] 	  Packet header Lock	: 0
[  284.457107] 	  Packet header Len1	: 3
[  284.457182] 	  NOC protocol version	: version >= 2.7
[  284.457296] 	ErrLog1			: 0x157600
[  284.457366] 	ErrLog2			: 0x0
[  284.457428] 	  RouteId		: 0x157600
[  284.463888] 	  InitFlow		: cpu_p_i/I/0
[  284.468083] 	  Targflow		: cbb_t/T/0
[  284.471757] 	  TargSubRange		: 27
[  284.474737] 	  SeqId			: 0
[  284.477464] 	ErrLog3			: 0x5c01814
[  284.480776] 	ErrLog4			: 0x0
[  284.483491] 	  Address accessed	: 0x15c01814
[  284.487950] 	ErrLog5			: 0x387e31
[  284.491188] 	  Master ID		: RCE
[  284.494595] 	  Security Group(GRPSEC): 0x3f
[  284.498796] 	  Cache			: 0x1 -- Bufferable 
[  284.499620] [RCE] VM0 deactivating.*** DATA ABORT EXCEPTION ***
[  284.502649] 	  Protection		: 0x1 -- Privileged, Secure, Data Access
[  284.502657] 	  FALCONSEC		: 0x0
[  284.509003] [RCE] R0:	15c00000	R1:	00001814	R2:	00008010	R3:	00000002
[  284.512357] 	  Virtual Queuing Channel(VQC): 0x0
[  284.512363] 	**************************************
[  284.512476] CPU:0, Error: cbb-noc@2300000, irq=15
[  284.519699] [RCE] R4:	0bcd1988	R5:	00000000	R6:	00000000	R7:	799ce800
[  284.521812] **************************************
[  284.521815] CPU:0, Error:cbb-noc
[  284.521823] 	Error Logger		: 0
[  284.526494] [RCE] R8:	0bcc3fb0	R9:	0bcc3fb2	R10:	0bcc3fa8	R11:	0002f1e0
[  284.531699] 	ErrLog0			: 0x80030000
[  284.531703] 	  Transaction Type	: RD  - Read, Incrementing
[  284.531706] 	  Error Code		: SLV
[  284.531709] 	  Error Source		: Target
[  284.531712] 	  Error Description	: Target error detected by CBB slave
[  284.531722] 	  Packet header Lock	: 0
[  284.531730] 	  Packet header Len1	: 3
[  284.534954] [RCE] R12:	0000fa4c	SP:	0bcc3f68	LR:	0bcab9e8	PC:	0bcaba04
[  284.537993] 	  NOC protocol version	: version >= 2.7
[  284.537997] 	ErrLog1			: 0x9528aa
[  284.538001] 	ErrLog2			: 0x0
[  284.538004] 	  RouteId		: 0x9528aa
[  284.538007] 	  InitFlow		: rce_p2ps/I/rce_p2ps
[  284.538010] 	  Targflow		: host1x_p2pm/T/host1x_p2pm
[  284.538012] 	  TargSubRange		: 20
[  284.538015] 	  SeqId			: 0
[  284.538044] 	ErrLog3			: 0x1814
[  284.541621] [RCE] SPSR:	6000011f
[  284.546661] 	ErrLog4			: 0x0
[  284.546666] 	  Address accessed	: 0x15c01814
[  284.546669] 	ErrLog5			: 0x2af0fc71
[  284.546690] 	  Non-Modify		: 0x1
[  284.546701] 	  AXI ID		: 0x55
[  284.550362] [RCE] DFSR:	00001008	DFAR:	15c01814	ADFSR:	00500000
[  284.554005] 	  Master ID		: RCE
[  284.554008] 	  Security Group(GRPSEC): 0x3f
[  284.554011] 	  Cache			: 0x1 -- Bufferable 
[  284.554015] 	  Protection		: 0x3 -- Privileged, Non-Secure, Data Access
[  284.554018] 	  FALCONSEC		: 0x0
[  284.554021] 	  Virtual Queuing Channel(VQC): 0x0
[  284.554025] 	**************************************
[  284.554215] Host read timeout at address 1814
[  284.560101] [RCE] IFSR:	00000000	IFAR:	00000000	AIFSR:	00000000
[  284.653512] tegra186-cam-rtcpu bc00000.rtcpu: Alert: Camera RTCPU gone bad! restoring it immediately!!

Trace logs:

 vi-output, vc_m-2718    [000] ....   279.280589: tegra_channel_capture_frame: sof:302.688821856
 vi-output, vc_m-2718    [000] ....   279.280590: tegra_channel_capture_frame: eof:302.697387520
 vi-output, vc_m-2718    [000] ....   279.290616: tegra_channel_capture_frame: sof:302.698886560
 vi-output, vc_m-2718    [000] ....   279.290618: tegra_channel_capture_frame: eof:302.707452224
        v4l2-ctl-2716    [001] ....   279.290661: tegra_channel_set_stream: enable : 0x0
        v4l2-ctl-2716    [001] ....   279.290663: tegra_channel_set_stream: vc_mipi 9-001a : 0x0
     kworker/1:3-111     [001] ....   279.331633: rtcpu_vinotify_event: tstamp:9459296624 cch:0 vi:0 tag:CHANSEL_PXL_EOF channel:0x23 frame:0 vi_tstamp:302697386848 data:0x0000000004af0002
     kworker/1:3-111     [001] ....   279.331634: rtcpu_vinotify_event: tstamp:9459296777 cch:0 vi:0 tag:ATOMP_FRAME_DONE channel:0x23 frame:0 vi_tstamp:302697387424 data:0x0000000000000000
     kworker/1:3-111     [001] ....   279.331634: rtcpu_vinotify_event: tstamp:9459296965 cch:0 vi:0 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:302697392928 data:0x00000000020203e8
     kworker/1:3-111     [001] ....   279.331635: rtcpu_vinotify_event: tstamp:9459297113 cch:0 vi:0 tag:FE channel:0x00 frame:0 vi_tstamp:302697387488 data:0x0000000000000020
     kworker/1:3-111     [001] ....   279.331636: rtcpu_vinotify_event: tstamp:9459608337 cch:0 vi:0 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:302697387520 data:0x0000000800000000
     kworker/1:3-111     [001] ....   279.331636: rtcpu_vinotify_event: tstamp:9459608494 cch:0 vi:0 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:302697406464 data:0x00000000000203e8
     kworker/1:3-111     [001] ....   279.331637: rtcpu_vinotify_event: tstamp:9459608668 cch:0 vi:0 tag:FS channel:0x00 frame:0 vi_tstamp:302698807904 data:0x0000000000000010
     kworker/1:3-111     [001] ....   279.331638: rtcpu_vinotify_event: tstamp:9459610660 cch:0 vi:0 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:302698807936 data:0x0000000800000000
     kworker/1:3-111     [001] ....   279.331638: rtcpu_vinotify_event: tstamp:9459610836 cch:0 vi:0 tag:CHANSEL_PXL_SOF channel:0x23 frame:0 vi_tstamp:302698886560 data:0x0000000000000001
     kworker/1:3-111     [001] ....   279.331638: rtcpu_vinotify_event: tstamp:9459611023 cch:0 vi:0 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:302698889280 data:0x00000000080203e9
     kworker/1:3-111     [001] ....   279.331639: rtcpu_vinotify_event: tstamp:9459611195 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:302698987744 data:0xcd9ce20010000000
     kworker/1:3-111     [001] ....   279.331639: rtcpu_vinotify_event: tstamp:9459611344 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:302698999680 data:0x00000000310003ea
     kworker/1:3-111     [001] ....   279.331639: rtcpu_vinotify_event: tstamp:9459947511 cch:0 vi:0 tag:CHANSEL_PXL_EOF channel:0x23 frame:0 vi_tstamp:302707451552 data:0x0000000004af0002
     kworker/1:3-111     [001] ....   279.331639: rtcpu_vinotify_event: tstamp:9459947664 cch:0 vi:0 tag:ATOMP_FRAME_DONE channel:0x23 frame:0 vi_tstamp:302707452160 data:0x0000000000000000
     kworker/1:3-111     [001] ....   279.331640: rtcpu_vinotify_event: tstamp:9459947835 cch:0 vi:0 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:302707458848 data:0x00000000020203e9
     kworker/1:3-111     [001] ....   279.331640: rtcpu_vinotify_event: tstamp:9459947984 cch:0 vi:0 tag:FE channel:0x00 frame:0 vi_tstamp:302707452192 data:0x0000000000000020
     kworker/1:3-111     [001] ....   279.331640: rtcpu_vinotify_event: tstamp:9459948158 cch:0 vi:0 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:302707452224 data:0x0000000800000000
     kworker/1:3-111     [001] ....   279.331641: rtcpu_vinotify_event: tstamp:9459948307 cch:0 vi:0 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:302707471232 data:0x00000000000203e9
        v4l2-ctl-2716    [001] ....   279.341452: tegra_channel_set_stream: 13e10000.host1x:nvcsi@15a00000- : 0x0
        v4l2-ctl-2716    [001] ....   279.341455: csi_s_stream: enable : 0x0
        v4l2-ctl-2716    [001] ....   279.343781: tegra_channel_set_power: vc_mipi 9-001a : 0x0
        v4l2-ctl-2716    [001] ....   279.343789: camera_common_s_power: status : 0x0
        v4l2-ctl-2716    [001] ....   279.343795: tegra_channel_set_power: 13e10000.host1x:nvcsi@15a00000- : 0x0
        v4l2-ctl-2716    [001] ....   279.343797: csi_s_power: enable : 0x0
        v4l2-ctl-2716    [001] ....   279.346726: tegra_channel_close: vi-output, vc_mipi 9-001a
     kworker/1:3-111     [001] ....   279.387612: rtcpu_string: tstamp:9461201938 id:0x04010000 str:"tegra_nvcsi_stream_close(vm0, stream=0, csi=0)
"
     kworker/1:1-56      [001] ....   284.499598: rtcpu_string: tstamp:9620644378 id:0x04010000 str:"VM0 deactivating."
     kworker/1:1-56      [001] ....   284.499614: rtcpu_string: tstamp:9621027090 id:0x04010000 str:"*** DATA ABORT EXCEPTION ***
"
     kworker/1:1-56      [001] ....   284.508997: rtcpu_string: tstamp:9621029215 id:0x04010000 str:"R0:	15c00000	R1:	00001814	R2:	00008010	R3:	00000"
     kworker/1:1-56      [001] ....   284.508999: rtcpu_string: tstamp:9621029332 id:0x04010000 str:"002
"
     kworker/1:1-56      [001] ....   284.519693: rtcpu_string: tstamp:9621042939 id:0x04010000 str:"R4:	0bcd1988	R5:	00000000	R6:	00000000	R7:	799ce"
     kworker/1:1-56      [001] ....   284.519695: rtcpu_string: tstamp:9621043054 id:0x04010000 str:"800
"
     kworker/1:1-56      [001] ....   284.526483: rtcpu_string: tstamp:9621063258 id:0x04010000 str:"R8:	0bcc3fb0	R9:	0bcc3fb2	R10:	0bcc3fa8	R11:	000"
     kworker/1:1-56      [001] ....   284.526487: rtcpu_string: tstamp:9621063373 id:0x04010000 str:"2f1e0
"
     kworker/1:1-56      [001] ....   284.534949: rtcpu_string: tstamp:9621080609 id:0x04010000 str:"R12:	0000fa4c	SP:	0bcc3f68	LR:	0bcab9e8	PC:	0bca"
     kworker/1:1-56      [001] ....   284.534950: rtcpu_string: tstamp:9621080724 id:0x04010000 str:"ba04
"
     kworker/1:1-56      [001] ....   284.541617: rtcpu_string: tstamp:9621090421 id:0x04010000 str:"SPSR:	6000011f
"
     kworker/1:1-56      [001] ....   284.550359: rtcpu_string: tstamp:9621098739 id:0x04010000 str:"DFSR:	00001008	DFAR:	15c01814	ADFSR:	00500000
"
     kworker/1:1-56      [001] ....   284.560097: rtcpu_string: tstamp:9621103114 id:0x04010000 str:"IFSR:	00000000	IFAR:	00000000	AIFSR:	00000000
20

Hi,
We have checked it and this looks like a race condition between tracing and power down. Please disable trace log and give it a try.

21

Hi @DaneLLL ,

We have been testing without the trace and this issue hasn’t happened so far.

1 Like
23

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