Kernel output (1 libargus stream) with our carrier board:
kworker/1:0-8528 [001] .... 2596.548347: rtcpu_vinotify_event: tstamp:81530016627 tag:ISPBUF_FS channel:0x00 frame:135 vi_tstamp:81530016219 data:0x00000000
kworker/1:0-8528 [001] .... 2596.548350: rtcpu_vinotify_event: tstamp:81530028609 tag:CHANSEL_PXL_SOF channel:0x00 frame:135 vi_tstamp:81530028218 data:0x00000001
kworker/1:0-8528 [001] .... 2596.604344: rtos_queue_peek_from_isr_failed: tstamp:81530441663 queue:0x0b4b4500
kworker/1:0-8528 [001] .... 2596.604356: rtcpu_vinotify_event: tstamp:81531028848 tag:CHANSEL_PXL_EOF channel:0x00 frame:135 vi_tstamp:81531028088 data:0x04370002
kworker/1:0-8528 [001] .... 2596.604359: rtcpu_vinotify_event: tstamp:81531029003 tag:ISPBUF_FE channel:0x00 frame:135 vi_tstamp:81531028194 data:0x00000000
kworker/1:0-8528 [001] .... 2596.604361: rtcpu_vinotify_event: tstamp:81531578656 tag:ISPBUF_FS channel:0x00 frame:136 vi_tstamp:81531578248 data:0x00000000
kworker/1:0-8528 [001] .... 2596.604364: rtcpu_vinotify_event: tstamp:81531590635 tag:CHANSEL_PXL_SOF channel:0x00 frame:136 vi_tstamp:81531590245 data:0x00000001
kworker/1:0-8528 [001] .... 2596.660387: rtcpu_vinotify_event: tstamp:81532590875 tag:CHANSEL_PXL_EOF channel:0x00 frame:136 vi_tstamp:81532590117 data:0x04370002
kworker/1:0-8528 [001] .... 2596.660396: rtcpu_vinotify_event: tstamp:81532591028 tag:ISPBUF_FE channel:0x00 frame:136 vi_tstamp:81532590223 data:0x00000000
kworker/1:0-8528 [001] .... 2596.660398: rtcpu_vinotify_event: tstamp:81533140684 tag:ISPBUF_FS channel:0x00 frame:137 vi_tstamp:81533140277 data:0x00000000
kworker/1:0-8528 [001] .... 2596.660400: rtcpu_vinotify_event: tstamp:81533152666 tag:CHANSEL_PXL_SOF channel:0x00 frame:137 vi_tstamp:81533152273 data:0x00000001
kworker/1:0-8528 [001] .... 2596.716332: rtcpu_vinotify_event: tstamp:81534152906 tag:CHANSEL_PXL_EOF channel:0x00 frame:137 vi_tstamp:81534152146 data:0x04370002
kworker/1:0-8528 [001] .... 2596.716342: rtcpu_vinotify_event: tstamp:81534153026 tag:ISPBUF_FE channel:0x00 frame:137 vi_tstamp:81534152252 data:0x00000000
kworker/1:0-8528 [001] .... 2596.716345: rtcpu_vinotify_event: tstamp:81534702676 tag:ISPBUF_FS channel:0x00 frame:138 vi_tstamp:81534702305 data:0x00000000
kworker/1:0-8528 [001] .... 2596.716348: rtcpu_vinotify_event: tstamp:81534714661 tag:CHANSEL_PXL_SOF channel:0x00 frame:138 vi_tstamp:81534714302 data:0x00000001
kworker/1:0-8528 [001] .... 2596.716353: rtos_queue_peek_from_isr_failed: tstamp:81535441682 queue:0x0b4b4500
kworker/1:0-8528 [001] .... 2596.772344: rtcpu_vinotify_event: tstamp:81535714948 tag:CHANSEL_PXL_EOF channel:0x00 frame:138 vi_tstamp:81535714175 data:0x04370002
kworker/1:0-8528 [001] .... 2596.772353: rtcpu_vinotify_event: tstamp:81535715101 tag:ISPBUF_FE channel:0x00 frame:138 vi_tstamp:81535714280 data:0x00000000
kworker/1:0-8528 [001] .... 2596.772356: rtcpu_vinotify_event: tstamp:81536264743 tag:ISPBUF_FS channel:0x00 frame:139 vi_tstamp:81536264335 data:0x00000000
kworker/1:0-8528 [001] .... 2596.772358: rtcpu_vinotify_event: tstamp:81536276722 tag:CHANSEL_PXL_SOF channel:0x00 frame:139 vi_tstamp:81536276331 data:0x00000001
kworker/1:0-8528 [001] .... 2596.772361: rtcpu_vinotify_event: tstamp:81537276962 tag:CHANSEL_PXL_EOF channel:0x00 frame:139 vi_tstamp:81537276204 data:0x04370002
kworker/1:0-8528 [001] .... 2596.772363: rtcpu_vinotify_event: tstamp:81537277148 tag:ISPBUF_FE channel:0x00 frame:139 vi_tstamp:81537276309 data:0x00000000
kworker/1:0-8528 [001] .... 2596.828331: rtcpu_vinotify_event: tstamp:81537826734 tag:ISPBUF_FS channel:0x00 frame:140 vi_tstamp:81537826363 data:0x00000000
kworker/1:0-8528 [001] .... 2596.828338: rtcpu_vinotify_event: tstamp:81537838719 tag:CHANSEL_PXL_SOF channel:0x00 frame:140 vi_tstamp:81537838360 data:0x00000001
kworker/1:0-8528 [001] .... 2596.828340: rtcpu_vinotify_event: tstamp:81538838969 tag:CHANSEL_PXL_EOF channel:0x00 frame:140 vi_tstamp:81538838232 data:0x04370002
kworker/1:0-8528 [001] .... 2596.828343: rtcpu_vinotify_event: tstamp:81538839089 tag:ISPBUF_FE channel:0x00 frame:140 vi_tstamp:81538838338 data:0x00000000
kworker/1:0-8528 [001] .... 2596.884324: rtos_queue_peek_from_isr_failed: tstamp:81540441691 queue:0x0b4b4500
kworker/1:0-8528 [001] .... 2597.052338: rtos_queue_peek_from_isr_failed: tstamp:81545441688 queue:0x0b4b4500
kworker/1:0-8528 [001] .... 2597.220317: rtos_queue_peek_from_isr_failed: tstamp:81550441694 queue:0x0b4b4500
kworker/1:0-8528 [001] .... 2597.388315: rtos_queue_peek_from_isr_failed: tstamp:81555441701 queue:0x0b4b4500
kworker/1:0-8528 [001] .... 2597.556331: rtos_queue_peek_from_isr_failed: tstamp:81560441708 queue:0x0b4b4500
kworker/1:0-8528 [001] .... 2597.724321: rtos_queue_peek_from_isr_failed: tstamp:81565441713 queue:0x0b4b4500
kworker/1:0-8528 [001] .... 2597.836345: rtos_queue_peek_from_isr_failed: tstamp:81570441710 queue:0x0b4b4500
kworker/1:0-8528 [001] .... 2598.004431: rtos_queue_peek_from_isr_failed: tstamp:81575441727 queue:0x0b4b4500
kworker/1:0-8528 [001] .... 2598.172428: rtos_queue_peek_from_isr_failed: tstamp:81580441735 queue:0x0b4b4500
kworker/1:0-8528 [001] .... 2598.340423: rtos_queue_peek_from_isr_failed: tstamp:81585441743 queue:0x0b4b4500
kworker/1:0-8528 [001] .... 2598.508435: rtos_queue_peek_from_isr_failed: tstamp:81590441748 queue:0x0b4b4500
kworker/1:0-8528 [001] .... 2598.676424: rtos_queue_peek_from_isr_failed: tstamp:81595441755 queue:0x0b4b4500
kworker/1:0-8528 [001] .... 2598.844321: rtos_queue_peek_from_isr_failed: tstamp:81600441764 queue:0x0b4b4500
It looks like related to the number of buffers given in EGLStream::FrameConsumer::create. When using 20 buffers/stream (libargus 4 streams) it does not give this problem.
But more then about 50 as well.
I get similar problem with TX2 Development board and modified 09_camera_jpeg_capture sample:
Code changes:
line 50: CAPTURE_TIME = 300
line 108: change to: m_consumer = UniqueObj(FrameConsumer::create(m_stream,800));
After about 20 secs running the application halts and error shows:
lux in Statsupdate: isAohdrEnable=0 currentSceneLux 296.567
SYNC_IOC_FENCE_INFO ioctl failed with 9
SCF: Error IoctlFailed: (propagating from src/services/capture/NvViCsiHw.cpp, function startCapture(), line 463)
SCF: Error IoctlFailed: (propagating from src/services/capture/DeviceRecordNv.cpp, function doCSItoISPCapture(), line 110)
SCF: Error IoctlFailed: (propagating from src/services/capture/CaptureRecord.cpp, function doCSItoISPCapture(), line 547)
SCF: Error IoctlFailed: (propagating from src/services/capture/CaptureRecord.cpp, function issueCapture(), line 460)
SCF: Error IoctlFailed: (propagating from src/services/capture/CaptureServiceDevice.cpp, function issueCaptures(), line 1276)
SCF: Error IoctlFailed: (propagating from src/services/capture/CaptureServiceDevice.cpp, function issueCaptures(), line 1107)
FiberScheduler: cc 556, session 0, fiber 0x7f38000f70 aborted in async operation
FiberScheduler: fiber 0x7f38000f70 exiting
SCF: Error IoctlFailed: (propagating from src/common/Utils.cpp, function workerThread(), line 116)
SCF: Error IoctlFailed: Worker thread CaptureScheduler frameStart failed (in src/common/Utils.cpp, function workerThread(), line 133)
CC 554 session 0 completed step 11 in fiber 0x7f38000dd0
CC 554 session 0 completed step 12 in fiber 0x7f38000dd0disposing CC 556 Session 0
SCF: Error Timeout: (propagating from src/api/Buffer.cpp, function waitForUnlock(), line 637)
SCF: Error Timeout: (propagating from src/components/CaptureContainerImpl.cpp, function returnBuffer(), line 358)
SCF: Error Timeout: (propagating from src/api/Buffer.cpp, function waitForUnlock(), line 637)
SCF: Error Timeout: (propagating from src/components/CaptureContainerImpl.cpp, function returnBuffer(), line 358)
SCF: Error Timeout: (propagating from src/api/Buffer.cpp, function waitForUnlock(), line 637)
SCF: Error Timeout: (propagating from src/components/CaptureContainerImpl.cpp, function returnBuffer(), line 358)
SCF: Error Timeout: (propagating from src/api/Buffer.cpp, function waitForUnlock(), line 637)
SCF: Error Timeout: (propagating from src/components/CaptureContainerImpl.cpp, function returnBuffer(), line 358)
Thread 3 is waiting
FiberScheduler: cc 555, session 0, fiber 0x7f38000b20 succeeded async operation
CC 554 session 0 completed step 13 in fiber 0x7f38000dd0
Thread 5 is working on CC 555 session 0 globalID 6434 step 11
CC 554 session 0 completed step 14 in fiber 0x7f38000dd0
NV AF analysis algorithm is active.
AfAnalysis cc 554 push FK_ISP_RUN_NUMBER=454.
CC 554 session 0 completed step 15 in fiber 0x7f38000dd0
PowerServiceHw:updateRequests: table size: before: 2, after:2
request table for ISP 0:
req[0]: output1 width=320, output1 height=200, output1 Bpp=16
req[0]: output2 width=320, output2 height=200, output2 Bpp=16
req[0]: input width=2592, input height=1944, input Bpp=10
exposureTime=0.030000 analogGain=2.305575 digitalGain=1.000000 commonGain=0.069167 expComp=1.000000
lux in Statsupdate: isAohdrEnable=0 currentSceneLux 296.483
CC 555 session 0 completed step 11 in fiber 0x7f38000b20
CC 555 session 0 completed step 12 in fiber 0x7f38000b20
CC 555 session 0 completed step 13 in fiber 0x7f38000b20
CC 555 session 0 completed step 14 in fiber 0x7f38000b20
NV AF analysis algorithm is active.
AfAnalysis cc 555 push FK_ISP_RUN_NUMBER=455.
CC 555 session 0 completed step 15 in fiber 0x7f38000b20
req[0]: output width=174, output height=130, output Bpp=16
req[0]: input fps=30
req[0]: guID=0, stage type=SensorIspCapture
req[0]: clock=0 Hz, iso bw=113498 KB/s, non-iso bw=0 KB/s
req[0]: timeout=0
req[1]: output1 width=648, output1 height=486, output1 Bpp=12
req[1]: output2 width=640, output2 height=480, output2 Bpp=13
req[1]: input width=2592, input height=1944, input Bpp=10
req[1]: output width=2592, output height=1944, output Bpp=12
req[1]: input fps=30
req[1]: guID=0, stage type=SensorIspCapture
req[1]: clock=0 Hz, iso bw=483145 KB/s, non-iso bw=0 KB/s
req[0]: timeout=0CC 554 session 0 completed step 16 in fiber 0x7f38000dd0
PowerServiceHwIsp:setLaBw: m_bwVal_Iso=0 and m_bwVal_NonIso=0 KBpS
PowerServiceCore:setCameraBw: totalIsoBw=0
CC 555 session 0 completed step 16 in fiber 0x7f38000b20
CC 554 session 0 completed step 17 in fiber 0x7f38000dd0
CC 554 session 0 completed step 18 in fiber 0x7f38000dd0
CC 554 session 0 completed step 19 in fiber 0x7f38000dd0
CC 554 session 0 completed step 20 in fiber 0x7f38000dd0
CC 554 session 0 completed step 21 in fiber 0x7f38000dd0
CC 554 session 0 completed step 22 in fiber 0x7f38000dd0
CC 555 session 0 completed step 17 in fiber 0x7f38000b20
CC 555 session 0 completed step 18 in fiber 0x7f38000b20
CC 555 session 0 completed step 19 in fiber 0x7f38000b20
CC 555 session 0 completed step 20 in fiber 0x7f38000b20
CC 555 session 0 completed step 21 in fiber 0x7f38000b20
CC 555 session 0 completed step 22 in fiber 0x7f38000b20
CC 555 session 0 completed step 23 in fiber 0x7f38000b20
CC 554 session 0 completed step 23 in fiber 0x7f38000dd0
CC 555 session 0 completed step 24 in fiber 0x7f38000b20
CC 554 session 0 completed step 24 in fiber 0x7f38000dd0
CC 554 session 0 completed step 25 in fiber 0x7f38000dd0
PerfStatsStageStage[sensorId=0][cc=554], sensorStart_ms=22979014, captureDone_ms=22979047, now_ms=22979458, frameDuration_ms=444, framerate=2.3
NvPHSSendThroughputHints: sensorId=0, m_usecase=4, m_type=20, m_value=2743247302, m_timeout_ms=1000
CC 554 session 0 completed step 26 in fiber 0x7f38000dd0
FiberScheduler: cc 554, session 0, fiber 0x7f38000dd0 complete
FiberScheduler: fiber 0x7f38000dd0 exiting
Thread 10 getting next capture
disposing CC 554 Session 0
Thread 2 is waiting
Thread 1 is waiting
Thread 10 is waiting
CC 555 session 0 completed step 25 in fiber 0x7f38000b20
NvPHSSendThroughputHints: sensorId=0, m_usecase=4, m_type=20, m_value=2743308605, m_timeout_ms=1000
CC 555 session 0 completed step 26 in fiber 0x7f38000b20
FiberScheduler: cc 555, session 0, fiber 0x7f38000b20 complete
FiberScheduler: fiber 0x7f38000b20 exiting
Thread 5 getting next capture
disposing CC 555 Session 0
Thread 6 is waiting
Thread 4 is waiting
Thread 5 is waiting
SCF: Error Timeout: ISP Stats timed out! (in src/services/capture/NvIspHw.cpp, function waitIspStatsFinished(), line 561)
SCF: Error Timeout: Sending critical error event (in src/api/Session.cpp, function sendErrorEvent(), line 990)
SCF: Error BadParameter: CC has already been disposed (in src/components/CaptureContainerManager.cpp, function dispose(), line 161)
SCF: Error Timeout: ISP port 0 timed out! (in src/services/capture/NvIspHw.cpp, function waitIspFrameEnd(), line 478)
SCF: Error Timeout: ISP port 1 timed out! (in src/services/capture/NvIspHw.cpp, function waitIspFrameEnd(), line 501)
SCF: Error Timeout: ISP port 2 timed out! (in src/services/capture/NvIspHw.cpp, function waitIspFrameEnd(), line 512)
SCF: Error Timeout: (propagating from src/services/capture/NvIspHw.cpp, function waitIspFrameEnd(), line 519)
SCF: Error Timeout: (propagating from src/common/Utils.cpp, function workerThread(), line 116)
SCF: Error Timeout: Worker thread IspHw frameComplete failed (in src/common/Utils.cpp, function workerThread(), line 133)
SCF: Error Timeout: (propagating from src/services/capture/CaptureServiceEvent.cpp, function wait(), line 59)
Error: Camera HwEvents wait, this may indicate a hardware timeout occured,abort current/incoming cc
Created fiber 0x7f38001a90 for CC 559 globalID 6438 session 0
Thread 9 is working on CC 559 session 0 globalID 6438 step 0
Fiber 0x7f38001a90 is aborting in CC 559 Session 0
FiberScheduler: cc 559 session 0, fiber 0x7f38001a90 aborted
FiberScheduler: fiber 0x7f38001a90 exiting
Thread 9 getting next capture
Thread 12 is waiting
Thread 8 is waiting