GStreamer pipeline not cleans up if started as a service

pettair · July 24, 2021, 3:15pm

Hi all,

We are facing a very strange issue, what Im cannot really figure out, so this is the time ask for the wisdom of the collective mind :D !

We have are using two camera inputs on our Jetson Nanos adding some overlay on the screen and sending it through UDP to the consumers. Example pipeline for the first instance:

gst-launch-1.0 -e\
 nvarguscamerasrc sensor-id="0" sensor-mode=0 gainrange="1 16" ispdigitalgainrange="1 1" name="camera_pipeline_overrides_0"\
    ! "video/x-raw(memory:NVMM), width=(int)1920, height=(int)1080, format=(string)NV12, framerate=(fraction)30/1"\
    ! nvvidconv ! nvivafilter cuda-process=true customer-lib-name="libdcd_overlay_1080p.so" ! 'video/x-raw(memory:NVMM), format=(string)NV12'\
    ! nvvidconv ! nvv4l2vp8enc bitrate="8000000" control-rate=1 ! rtpvp8pay mtu=1400\
    ! udpsink auto-multicast=true clients="127.0.0.1:56000,127.0.0.1:56001"

If I start this pipeline in terminal I can stop and restart it for the end of the time without any issues (for stopping I simply hit CTRL-C).

But we wrote a simple service around it:
dcd_camerasource.service (441 Bytes)

Which starts shell script, what would fill out the params for the pipeline and start it:
dcd_camerasource (1.8 KB)

And when we restart the service we see these errors in the nvargus-daemon log:

Jan 28 16:07:30 dcd-398f9dee nvargus-daemon[4998]: === gst-launch-1.0[6785]: Connection closed (7F77AB11D0)=== gst-launch-1.0[6785]: WARNING: CameraProvider was not destroyed before client connection terminated.=== gst-launch-1.0[6785]:          The client may have abnormally terminated. Destroying CameraProvider...=== gst-launch-1.0[6785]: CameraProvider destroyed (0x7f70b5c4c0)=== gst-launch-1.0[6785]: WARNING: Cleaning up 1 outstanding requests...=== gst-launch-1.0[6785]: WARNING: Cleaning up 1 outstanding streams...SCF: Error InvalidState: 5 buffers still pending during EGLStreamProducer destruction (propagating from src/services/gl/EGLStreamProducer.cpp, function freeBuffers(), line 306)
Jan 28 16:07:30 dcd-398f9dee nvargus-daemon[4998]: SCF: Error InvalidState:  (propagating from src/services/gl/EGLStreamProducer.cpp, function ~EGLStreamProducer(), line 50)
Jan 28 16:07:30 dcd-398f9dee nvargus-daemon[4998]: === gst-launch-1.0[6785]: WARNING: Cleaning up 1 outstanding stream settings...=== gst-launch-1.0[6785]: WARNING: Cleaning up 1 outstanding sessions...(NvCameraUtils) Error InvalidState: Mutex not initialized (/dvs/git/dirty/git-master_linux/camera/core_scf/src/services/gl/EGLStreamProducer.cpp:498) (in Mutex.cpp, function lock(), line 79)
Jan 28 16:07:30 dcd-398f9dee nvargus-daemon[4998]: SCF: Error BadParameter: Buffer is not pending (in src/services/gl/EGLStreamProducer.cpp, function presentBufferInternal(), line 502)
Jan 28 16:07:30 dcd-398f9dee nvargus-daemon[4998]: (NvCameraUtils) Error InvalidState: Mutex has not been initialized (in Mutex.cpp, function unlock(), line 88)
Jan 28 16:07:30 dcd-398f9dee nvargus-daemon[4998]: SCF: Error BadParameter:  (propagating from src/services/gl/EGLStreamProducer.cpp, function presentBuffer(), line 487)
Jan 28 16:07:30 dcd-398f9dee nvargus-daemon[4998]: SCF: Error BadParameter:  (propagating from src/components/CaptureContainerImpl.cpp, function returnBuffer(), line 447)
Jan 28 16:07:30 dcd-398f9dee nvargus-daemon[4998]: SCF: Error BadParameter:  (propagating from src/components/stages/BufferReturnStage.h, function doExecute(), line 43)
Jan 28 16:07:30 dcd-398f9dee nvargus-daemon[4998]: SCF: Error BadParameter: Sending critical error event (in src/api/Session.cpp, function sendErrorEvent(), line 990)
Jan 28 16:07:30 dcd-398f9dee nvargus-daemon[4998]: (NvCameraUtils) Error InvalidState: Mutex not initialized (/dvs/git/dirty/git-master_linux/camera/core_scf/src/services/gl/EGLStreamProducer.cpp:498) (in Mutex.cpp, function lock(), line 79)
Jan 28 16:07:30 dcd-398f9dee nvargus-daemon[4998]: (NvCameraUtils) Error InvalidState: Mutex has not been initialized (in Mutex.cpp, function unlock(), line 88)

And this will end up in a nvargus-daemon restart. I will attach a the whole log:
nvargus-daemon.log (10.4 KB)

If in the meantime the service gets restarted the we some more error in the nvargu-daemon log:

Jan 28 16:12:59 dcd-398f9dee nvargus-daemon[28296]: SCF: Error Timeout: ISP port 0 timed out! (in src/services/capture/NvIspHw.cpp, function waitIspFrameEnd(), line 478)

Jan 28 16:12:59 dcd-398f9dee nvargus-daemon[28296]: SCF: Error Timeout: (propagating from src/services/capture/NvIspHw.cpp, function waitIspFrameEnd(), line 519)

Jan 28 16:12:59 dcd-398f9dee nvargus-daemon[28296]: SCF: Error Timeout: (propagating from src/common/Utils.cpp, function workerThread(), line 116)

Jan 28 16:12:59 dcd-398f9dee nvargus-daemon[28296]: SCF: Error Timeout: Worker thread IspHw frameComplete failed (in src/common/Utils.cpp, function workerThread(), line 133)

Jan 28 16:13:00 dcd-398f9dee nvargus-daemon[28296]: SCF: Error Timeout: ISP Stats timed out! (in src/services/capture/NvIspHw.cpp, function waitIspStatsFinished(), line 561)

Jan 28 16:13:00 dcd-398f9dee nvargus-daemon[28296]: Error: waitCsiFrameStart timeout guid 1

Jan 28 16:13:00 dcd-398f9dee nvargus-daemon[28296]: ************VI/CSI Debug Registers**********

Jan 28 16:13:00 dcd-398f9dee nvargus-daemon[28296]: VI_CFG_INTERRUPT_MASK_0 = 0x00000000

Jan 28 16:13:00 dcd-398f9dee nvargus-daemon[28296]: VI_CFG_INTERRUPT_STATUS_0 = 0x00000000

Jan 28 16:13:00 dcd-398f9dee nvargus-daemon[28296]: VI_CSI_0_ERROR_STATUS_0 = 0x00000001

Jan 28 16:13:00 dcd-398f9dee nvargus-daemon[28296]: VI_CSI_0_ERROR_INT_MASK_0 = 0x0000001f

Jan 28 16:13:00 dcd-398f9dee nvargus-daemon[28296]: VI_CSI_1_ERROR_STATUS_0 = 0x00000000

Jan 28 16:13:00 dcd-398f9dee nvargus-daemon[28296]: VI_CSI_1_ERROR_INT_MASK_0 = 0x00000000

whole log:
nvargus-daemon_with_crash.log (3.9 KB)

And in the kernel log:

Jan 28 16:12:59 dcd-398f9dee kernel: [  884.690604] fence timeout on [ffffffc08b1016c0] after 1500ms
Jan 28 16:12:59 dcd-398f9dee kernel: [  884.690613] name=[nvhost_sync:21], current value=24 waiting value=25
Jan 28 16:12:59 dcd-398f9dee kernel: [  884.690618] fence timeout on [ffffffc08b101780] after 1500ms
Jan 28 16:12:59 dcd-398f9dee kernel: [  884.690619] ---- mlocks ----
Jan 28 16:12:59 dcd-398f9dee kernel: [  884.690624] name=[nvhost_sync:22], current value=23206 waiting value=23207
Jan 28 16:12:59 dcd-398f9dee kernel: [  884.690628] ---- mlocks ----
Jan 28 16:12:59 dcd-398f9dee kernel: [  884.690628] 
Jan 28 16:12:59 dcd-398f9dee kernel: [  884.690630] ---- syncpts ----
Jan 28 16:12:59 dcd-398f9dee kernel: [  884.690638] 
Jan 28 16:12:59 dcd-398f9dee kernel: [  884.690640] ---- syncpts ----
Jan 28 16:12:59 dcd-398f9dee kernel: [  884.690641] id 7 (54340000.vic_0) min 680631 max 680631 refs 1 (previous client : )
Jan 28 16:12:59 dcd-398f9dee kernel: [  884.690644] id 8 (gm20b_507) min 300 max 300 refs 1 (previous client : )
Jan 28 16:12:59 dcd-398f9dee kernel: [  884.690648] id 9 (gm20b_506) min 18 max 18 refs 1 (previous client : )
Jan 28 16:12:59 dcd-398f9dee kernel: [  884.690653] id 11 (gm20b_505) min 34 max 34 refs 1 (previous client : gm20b_505)
Jan 28 16:12:59 dcd-398f9dee kernel: [  884.690657] id 12 (gm20b_495) min 48508 max 48508 refs 1 (previous client : gm20b_489)
Jan 28 16:12:59 dcd-398f9dee kernel: [  884.690660] id 13 (gm20b_504) min 45536 max 45536 refs 1 (previous client : gm20b_488)
Jan 28 16:12:59 dcd-398f9dee kernel: [  884.690664] id 14 (gm20b_479) min 10 max 10 refs 1 (previous client : gm20b_487)
Jan 28 16:12:59 dcd-398f9dee kernel: [  884.690668] id 15 (gm20b_502) min 10 max 10 refs 1 (previous client : gm20b_482)
Jan 28 16:12:59 dcd-398f9dee kernel: [  884.690672] id 16 (gm20b_501) min 30 max 30 refs 1 (previous client : gm20b_480)

full log:
kern.log (10.0 KB)

and the Nano get rebooted.

But I guess this crash is just the result of the issue that the GStreamer pipeline is not stopped and cleaned up poprely.

Do you have any idea what am I doing wrong here? How could I stop the pipeline properly?

Thanks in advance!

Bests,
Peter

pettair · July 24, 2021, 5:35pm

One thing I forgot to mention is that I also tried to send a SIGINT directly to the gst-launch-1.0 process (to simulate hitting CTRL-C the best I can) with:

kill -SIGINT <pid>

But the same error happens.

However if I start the wrapper script directly and send a SIGINT to the gst-launch-1.0 process from a separate session it stops properly.

So it seems to be connected to that it is started as a service somehow.

DaneLLL · July 26, 2021, 1:28am

Hi,
If you use Jetpack 4.5.1(r32.5.1), please apply the prebuilt lib and give it a try:
Jetson/L4T/r32.5.x patches - eLinux.org
[camera] 3rdparty application fails to open with USB camera

pettair · July 26, 2021, 7:12am

Hi DaneLLL,

Thanks! Unfortunately I forgott to mention that we stuck with 4.4.1 since our camera driver. We are using AP-IMX290-SerDes from Appropho. Im not sure if the root cause can be the same as the title mentions USB camera. Is there any option to backport the patch to 4.4.1?

Also what I really cannot deal with is that the pipeline is working fine if I start it from the terminal directly it cleans up properly and I can restart it without any issues as many times I want. It only fails when it is started as a linux service. I tried to go after every strange corner case (most of them just witch hunting) about what can make it wrong and compare the environment variables, paths etc… but the look the same in both cases.

DaneLLL · July 26, 2021, 8:59am

Hi,
So the issue is you can start the pipeline but cannot stop it? Does it work if you run like

$ gst-launch-1.0 nvarguscamerasrc ! fakesink

pettair · July 26, 2021, 10:57am

Hi

Actually the gst pipeline is stopped, but as I see it is not cleaning up after itself and messes up the state of nvargus-daemon (since it does not closes the connection properly I guess).

I tried you suggestion and it is producing the same issue. This is how my sources files are looking now:

$ cat /etc/systemd/system/dcd_camerasource_0.service
[Unit]
Description=Dual Channel Dashcam Camera Source
After=network.target syslog.target dcd.service dcd_gps.service dcd_radar.service nvargus-daemon.service
StartLimitIntervalSec=5

[Service]
Type=simple
Restart=always
RestartSec=5
User=dcd
Group=dcd
WorkingDirectory=/opt/dcd
ExecStart=/bin/bash /opt/dcd/bin/dcd_camerasource.sh 0
ExecStop=/bin/kill -s SIGINT -$MAINPID 
TimeoutStopSec=3

[Install]
WantedBy=multi-user.target

$ cat /opt/dcd/bin/dcd_camerasource.sh
#!/bin/bash

gst-launch-1.0 nvarguscamerasrc sensor-id="$1" sensor-mode=0 ! fakesink

So the situation is exactly the same as before, if start and stop the bash script directly with:

/opt/dcd/bin/dcd_camerasource.sh 0
CRTl-C
/opt/dcd/bin/dcd_camerasource.sh 0
CRTl-C
.
.
.

/opt/dcd/bin/dcd_camerasource.sh 0
CRTl-C

it works properly, but if I start/stop it as a service:

systemctl start dcd_camerasource_0
systemctl stop dcd_camerasource_0

The nvargus-daemon goes into this error state:

Jan 29 05:22:25 dcd-398f9dee nvargus-daemon[2938]: CAM: serial no file already exists, skips storing again=== gst-launch-1.0[4093]: CameraProvider initialized (0x7f6cb5c5c0)CAM: serial no file already exists, skips storing again=== gst-launch-1.0[4093]: Connection closed (7F722011D0)=== gst-launch-1.0[4093]: WARNING: CameraProvider was not destroyed before client connection terminated.=== gst-launch-1.0[4093]:          The client may have abnormally terminated. Destroying CameraProvider...=== gst-launch-1.0[4093]: CameraProvider destroyed (0x7f6cb5c5c0)=== gst-launch-1.0[4093]: WARNING: Cleaning up 1 outstanding requests...=== gst-launch-1.0[4093]: WARNING: Cleaning up 1 outstanding streams...SCF: Error InvalidState: 5 buffers still pending during EGLStreamProducer destruction (propagating from src/services/gl/EGLStreamProducer.cpp, function freeBuffers(), line 306)
Jan 29 05:22:25 dcd-398f9dee nvargus-daemon[2938]: SCF: Error InvalidState:  (propagating from src/services/gl/EGLStreamProducer.cpp, function ~EGLStreamProducer(), line 50)
Jan 29 05:22:25 dcd-398f9dee nvargus-daemon[2938]: === gst-launch-1.0[4093]: WARNING: Cleaning up 1 outstanding stream settings...=== gst-launch-1.0[4093]: WARNING: Cleaning up 1 outstanding sessions...(NvCameraUtils) Error InvalidState: Mutex not initialized (/dvs/git/dirty/git-master_linux/camera/core_scf/src/services/gl/EGLStreamProducer.cpp:498) (in Mutex.cpp, function lock(), line 79)
Jan 29 05:22:25 dcd-398f9dee nvargus-daemon[2938]: SCF: Error BadParameter: Buffer is not pending (in src/services/gl/EGLStreamProducer.cpp, function presentBufferInternal(), line 502)
Jan 29 05:22:25 dcd-398f9dee nvargus-daemon[2938]: (NvCameraUtils) Error InvalidState: Mutex has not been initialized (in Mutex.cpp, function unlock(), line 88)
Jan 29 05:22:25 dcd-398f9dee nvargus-daemon[2938]: SCF: Error BadParameter:  (propagating from src/services/gl/EGLStreamProducer.cpp, function presentBuffer(), line 487)
Jan 29 05:22:25 dcd-398f9dee nvargus-daemon[2938]: SCF: Error BadParameter:  (propagating from src/components/CaptureContainerImpl.cpp, function returnBuffer(), line 447)
Jan 29 05:22:25 dcd-398f9dee nvargus-daemon[2938]: SCF: Error BadParameter:  (propagating from src/components/stages/BufferReturnStage.h, function doExecute(), line 43)
Jan 29 05:22:25 dcd-398f9dee nvargus-daemon[2938]: SCF: Error BadParameter: Sending critical error event (in src/api/Session.cpp, function sendErrorEvent(), line 990)
Jan 29 05:22:25 dcd-398f9dee nvargus-daemon[2938]: (NvCameraUtils) Error InvalidState: Mutex not initialized (/dvs/git/dirty/git-master_linux/camera/core_scf/src/services/gl/EGLStreamProducer.cpp:498) (in Mutex.cpp, function lock(), line 79)
Jan 29 05:22:25 dcd-398f9dee nvargus-daemon[2938]: (NvCameraUtils) Error InvalidState: Mutex has not been initialized (in Mutex.cpp, function unlock(), line 88)
Jan 29 05:22:25 dcd-398f9dee nvargus-daemon[2938]: (NvCameraUtils) Error InvalidState: Mutex not initialized (/dvs/git/dirty/git-master_linux/camera/core_scf/src/services/gl/EGLStreamProducer.cpp:534) (in Mutex.cpp, function lock(), line 79)
Jan 29 05:22:25 dcd-398f9dee nvargus-daemon[2938]: SCF: Error BadParameter:  (propagating from src/services/gl/EGLStreamProducer.cpp, function presentBufferInternal(), line 539)
Jan 29 05:22:25 dcd-398f9dee nvargus-daemon[2938]: (NvCameraUtils) Error InvalidState: Mutex has not been initialized (in Mutex.cpp, function unlock(), line 88)
Jan 29 05:22:25 dcd-398f9dee nvargus-daemon[2938]: (NvCameraUtils) Error InvalidState: Mutex not initialized (/dvs/git/dirty/git-master_linux/camera/core_scf/src/services/gl/EGLStreamProducer.cpp:552) (in Mutex.cpp, function lock(), line 79)
Jan 29 05:22:25 dcd-398f9dee nvargus-daemon[2938]: (NvCameraUtils) Error InvalidState: Mutex has not been initialized (in Mutex.cpp, function unlock(), line 88)
Jan 29 05:22:25 dcd-398f9dee nvargus-daemon[2938]: (NvCameraUtils) Error InvalidState: Mutex not initialized (/dvs/git/dirty/git-master_linux/camera/core_scf/src/services/gl/EGLStreamProducer.cpp:498) (in Mutex.cpp, function lock(), line 79)
Jan 29 05:22:25 dcd-398f9dee nvargus-daemon[2938]: (NvCameraUtils) Error InvalidState: Mutex has not been initialized (in Mutex.cpp, function unlock(), line 88)
Jan 29 05:22:25 dcd-398f9dee nvargus-daemon[2938]: (NvCameraUtils) Error InvalidState: Mutex not initialized (/dvs/git/dirty/git-master_linux/camera/core_scf/src/services/gl/EGLStreamProducer.cpp:534) (in Mutex.cpp, function lock(), line 79)
Jan 29 05:22:25 dcd-398f9dee nvargus-daemon[2938]: SCF: Error BadParameter:  (propagating from src/services/gl/EGLStreamProducer.cpp, function presentBufferInternal(), line 539)
Jan 29 05:22:25 dcd-398f9dee nvargus-daemon[2938]: (NvCameraUtils) Error InvalidState: Mutex has not been initialized (in Mutex.cpp, function unlock(), line 88)
Jan 29 05:22:25 dcd-398f9dee nvargus-daemon[2938]: (NvCameraUtils) Error InvalidState: Mutex not initialized (/dvs/git/dirty/git-master_linux/camera/core_scf/src/services/gl/EGLStreamProducer.cpp:552) (in Mutex.cpp, function lock(), line 79)
Jan 29 05:22:25 dcd-398f9dee nvargus-daemon[2938]: (NvCameraUtils) Error InvalidState: Mutex has not been initialized (in Mutex.cpp, function unlock(), line 88)
Jan 29 05:22:25 dcd-398f9dee nvargus-daemon[2938]: (NvCameraUtils) Error InvalidState: Mutex not initialized (/dvs/git/dirty/git-master_linux/camera/core_scf/src/services/gl/EGLStreamProducer.cpp:498) (in Mutex.cpp, function lock(), line 79)
Jan 29 05:22:25 dcd-398f9dee nvargus-daemon[2938]: (NvCameraUtils) Error InvalidState: Mutex has not been initialized (in Mutex.cpp, function unlock(), line 88)
Jan 29 05:22:25 dcd-398f9dee nvargus-daemon[2938]: (NvCameraUtils) Error InvalidState: Mutex not initialized (/dvs/git/dirty/git-master_linux/camera/core_scf/src/services/gl/EGLStreamProducer.cpp:534) (in Mutex.cpp, function lock(), line 79)
Jan 29 05:22:25 dcd-398f9dee nvargus-daemon[2938]: SCF: Error BadParameter:  (propagating from src/services/gl/EGLStreamProducer.cpp, function presentBufferInternal(), line 539)
Jan 29 05:22:25 dcd-398f9dee nvargus-daemon[2938]: (NvCameraUtils) Error InvalidState: Mutex has not been initialized (in Mutex.cpp, function unlock(), line 88)
Jan 29 05:22:25 dcd-398f9dee nvargus-daemon[2938]: (NvCameraUtils) Error InvalidState: Mutex not initialized (/dvs/git/dirty/git-master_linux/camera/core_scf/src/services/gl/EGLStreamProducer.cpp:552) (in Mutex.cpp, function lock(), line 79)
Jan 29 05:22:25 dcd-398f9dee nvargus-daemon[2938]: (NvCameraUtils) Error InvalidState: Mutex has not been initialized (in Mutex.cpp, function unlock(), line 88)
Jan 29 05:22:25 dcd-398f9dee nvargus-daemon[2938]: (NvCameraUtils) Error InvalidState: Mutex not initialized (/dvs/git/dirty/git-master_linux/camera/core_scf/src/services/gl/EGLStreamProducer.cpp:498) (in Mutex.cpp, function lock(), line 79)
Jan 29 05:22:25 dcd-398f9dee nvargus-daemon[2938]: (NvCameraUtils) Error InvalidState: Mutex has not been initialized (in Mutex.cpp, function unlock(), line 88)
Jan 29 05:22:25 dcd-398f9dee nvargus-daemon[2938]: (NvCameraUtils) Error InvalidState: Mutex not initialized (/dvs/git/dirty/git-master_linux/camera/core_scf/src/services/gl/EGLStreamProducer.cpp:534) (in Mutex.cpp, function lock(), line 79)
Jan 29 05:22:25 dcd-398f9dee nvargus-daemon[2938]: SCF: Error BadParameter:  (propagating from src/services/gl/EGLStreamProducer.cpp, function presentBufferInternal(), line 539)
Jan 29 05:22:25 dcd-398f9dee nvargus-daemon[2938]: (NvCameraUtils) Error InvalidState: Mutex has not been initialized (in Mutex.cpp, function unlock(), line 88)
Jan 29 05:22:25 dcd-398f9dee nvargus-daemon[2938]: (NvCameraUtils) Error InvalidState: Mutex not initialized (/dvs/git/dirty/git-master_linux/camera/core_scf/src/services/gl/EGLStreamProducer.cpp:552) (in Mutex.cpp, function lock(), line 79)
Jan 29 05:22:25 dcd-398f9dee nvargus-daemon[2938]: (NvCameraUtils) Error InvalidState: Mutex has not been initialized (in Mutex.cpp, function unlock(), line 88)
Jan 29 05:22:30 dcd-398f9dee nvargus-daemon[2938]: waitForIdleLocked remaining request 235
Jan 29 05:22:30 dcd-398f9dee nvargus-daemon[2938]: waitForIdleLocked remaining request 234
Jan 29 05:22:30 dcd-398f9dee nvargus-daemon[2938]: waitForIdleLocked remaining request 233
Jan 29 05:22:30 dcd-398f9dee nvargus-daemon[2938]: waitForIdleLocked remaining request 232
Jan 29 05:22:30 dcd-398f9dee nvargus-daemon[2938]: SCF: Error Timeout: waitForIdle() timed out (in src/api/Session.cpp, function waitForIdleLocked(), line 920)
Jan 29 05:22:30 dcd-398f9dee nvargus-daemon[2938]: (Argus) Error Timeout:  (propagating from src/api/CaptureSessionImpl.cpp, function destroy(), line 166)
Jan 29 05:22:35 dcd-398f9dee nvargus-daemon[2938]: waitForIdleLocked remaining request 235
Jan 29 05:22:35 dcd-398f9dee nvargus-daemon[2938]: waitForIdleLocked remaining request 234
Jan 29 05:22:35 dcd-398f9dee nvargus-daemon[2938]: waitForIdleLocked remaining request 233
Jan 29 05:22:35 dcd-398f9dee nvargus-daemon[2938]: waitForIdleLocked remaining request 232
Jan 29 05:22:35 dcd-398f9dee nvargus-daemon[2938]: SCF: Error Timeout: waitForIdle() timed out (in src/api/Session.cpp, function waitForIdleLocked(), line 920)
Jan 29 05:22:35 dcd-398f9dee nvargus-daemon[2938]: SCF: Error Timeout:  (propagating from src/api/Session.cpp, function abortCaptures(), line 886)
Jan 29 05:22:35 dcd-398f9dee nvargus-daemon[2938]: SCF: Error Timeout:  (propagating from src/api/Session.cpp, function shutdown(), line 400)
Jan 29 05:22:35 dcd-398f9dee nvargus-daemon[2938]: PowerServiceCore:handleRequests: timePassed = 5040
Jan 29 05:22:35 dcd-398f9dee nvargus-daemon[2938]: SCF: Error Timeout:  (propagating from src/api/Session.cpp, function shutdown(), line 500)
Jan 29 05:22:35 dcd-398f9dee nvargus-daemon[2938]: SCF: Error Timeout:  (propagating from src/api/CameraDriver.cpp, function deleteSession(), line 619)
Jan 29 05:22:35 dcd-398f9dee nvargus-daemon[2938]: (Argus) Error Timeout:  (propagating from src/api/CaptureSessionImpl.cpp, function destroy(), line 191)
Jan 29 05:22:35 dcd-398f9dee nvargus-daemon[2938]: === gst-launch-1.0[4093]: NOTE: Destroy all libargus objects before destroying the CameraProvider to avoid these warnings.FiberScheduler: 4 fibers still exist!
Jan 29 05:22:35 dcd-398f9dee nvargus-daemon[2938]: === gst-launch-1.0[4093]: Connection cleaned up (7F722011D0)free(): invalid size
Jan 29 05:22:35 dcd-398f9dee systemd[1]: nvargus-daemon.service: Main process exited, code=killed, status=6/ABRT
Jan 29 05:22:35 dcd-398f9dee systemd[1]: nvargus-daemon.service: Failed with result 'signal'.
Jan 29 05:22:36 dcd-398f9dee systemd[1]: nvargus-daemon.service: Service hold-off time over, scheduling restart.
Jan 29 05:22:36 dcd-398f9dee systemd[1]: nvargus-daemon.service: Scheduled restart job, restart counter is at 2.
Jan 29 05:22:36 dcd-398f9dee systemd[1]: Stopped Argus daemon.
Jan 29 05:22:36 dcd-398f9dee systemd[1]: Started Argus daemon.

DaneLLL · July 26, 2021, 12:10pm

Hi,
Is end of stream(EoS) sent in the stop command?

We have tried killall and see EoS being sent. Please try this command.

Gst-launch-1.0 nvcompositor bug in tegra-l4t-r32.5.1? - #20 by DaneLLL

pettair · July 26, 2021, 12:20pm

Hi,

You mean to pass the ‘-e’ flag to the gst-launch-1.0 command?

I did that:

$ cat /opt/dcd/bin/dcd_camerasource.sh
#!/bin/bash

gst-launch-1.0 -e nvarguscamerasrc sensor-id="$1" sensor-mode=0 ! fakesink

but the same error happens after I stop it with systemctl:

Jan 29 07:10:35 dcd-398f9dee nvargus-daemon[14242]: CAM: serial no file already exists, skips storing again=== gst-launch-1.0[14710]: CameraProvider initialized (0x7f94b5c4b0)CAM: serial no file already exists, skips storing again=== gst-launch-1.0[14710]: Connection closed (7F9A4B11D0)=== gst-launch-1.0[14710]: WARNING: CameraProvider was not destroyed before client connection terminated.=== gst-launch-1.0[14710]:          The client may have abnormally terminated. Destroying CameraProvider...=== gst-launch-1.0[14710]: CameraProvider destroyed (0x7f94b5c4b0)=== gst-launch-1.0[14710]: WARNING: Cleaning up 1 outstanding requests...=== gst-launch-1.0[14710]: WARNING: Cleaning up 1 outstanding streams...SCF: Error InvalidState: 5 buffers still pending during EGLStreamProducer destruction (propagating from src/services/gl/EGLStreamProducer.cpp, function freeBuffers(), line 306)
Jan 29 07:10:35 dcd-398f9dee nvargus-daemon[14242]: SCF: Error InvalidState:  (propagating from src/services/gl/EGLStreamProducer.cpp, function ~EGLStreamProducer(), line 50)
Jan 29 07:10:35 dcd-398f9dee nvargus-daemon[14242]: === gst-launch-1.0[14710]: WARNING: Cleaning up 1 outstanding stream settings...=== gst-launch-1.0[14710]: WARNING: Cleaning up 1 outstanding sessions...(NvCameraUtils) Error InvalidState: Mutex not initialized (/dvs/git/dirty/git-master_linux/camera/core_scf/src/services/gl/EGLStreamProducer.cpp:498) (in Mutex.cpp, function lock(), line 79)
Jan 29 07:10:35 dcd-398f9dee nvargus-daemon[14242]: SCF: Error BadParameter: Buffer is not pending (in src/services/gl/EGLStreamProducer.cpp, function presentBufferInternal(), line 502)
Jan 29 07:10:35 dcd-398f9dee nvargus-daemon[14242]: (NvCameraUtils) Error InvalidState: Mutex has not been initialized (in Mutex.cpp, function unlock(), line 88)
Jan 29 07:10:35 dcd-398f9dee nvargus-daemon[14242]: SCF: Error BadParameter:  (propagating from src/services/gl/EGLStreamProducer.cpp, function presentBuffer(), line 487)
Jan 29 07:10:35 dcd-398f9dee nvargus-daemon[14242]: SCF: Error BadParameter:  (propagating from src/components/CaptureContainerImpl.cpp, function returnBuffer(), line 447)
Jan 29 07:10:35 dcd-398f9dee nvargus-daemon[14242]: SCF: Error BadParameter:  (propagating from src/components/stages/BufferReturnStage.h, function doExecute(), line 43)
Jan 29 07:10:35 dcd-398f9dee nvargus-daemon[14242]: SCF: Error BadParameter: Sending critical error event (in src/api/Session.cpp, function sendErrorEvent(), line 990)
Jan 29 07:10:35 dcd-398f9dee nvargus-daemon[14242]: (NvCameraUtils) Error InvalidState: Mutex not initialized (/dvs/git/dirty/git-master_linux/camera/core_scf/src/services/gl/EGLStreamProducer.cpp:498) (in Mutex.cpp, function lock(), line 79)
Jan 29 07:10:35 dcd-398f9dee nvargus-daemon[14242]: (NvCameraUtils) Error InvalidState: Mutex has not been initialized (in Mutex.cpp, function unlock(), line 88)
Jan 29 07:10:35 dcd-398f9dee nvargus-daemon[14242]: (NvCameraUtils) Error InvalidState: Mutex not initialized (/dvs/git/dirty/git-master_linux/camera/core_scf/src/services/gl/EGLStreamProducer.cpp:534) (in Mutex.cpp, function lock(), line 79)
Jan 29 07:10:35 dcd-398f9dee nvargus-daemon[14242]: SCF: Error BadParameter:  (propagating from src/services/gl/EGLStreamProducer.cpp, function presentBufferInternal(), line 539)
Jan 29 07:10:35 dcd-398f9dee nvargus-daemon[14242]: (NvCameraUtils) Error InvalidState: Mutex has not been initialized (in Mutex.cpp, function unlock(), line 88)
Jan 29 07:10:35 dcd-398f9dee nvargus-daemon[14242]: (NvCameraUtils) Error InvalidState: Mutex not initialized (/dvs/git/dirty/git-master_linux/camera/core_scf/src/services/gl/EGLStreamProducer.cpp:552) (in Mutex.cpp, function lock(), line 79)
Jan 29 07:10:35 dcd-398f9dee nvargus-daemon[14242]: (NvCameraUtils) Error InvalidState: Mutex has not been initialized (in Mutex.cpp, function unlock(), line 88)
Jan 29 07:10:35 dcd-398f9dee nvargus-daemon[14242]: (NvCameraUtils) Error InvalidState: Mutex not initialized (/dvs/git/dirty/git-master_linux/camera/core_scf/src/services/gl/EGLStreamProducer.cpp:498) (in Mutex.cpp, function lock(), line 79)
Jan 29 07:10:35 dcd-398f9dee nvargus-daemon[14242]: (NvCameraUtils) Error InvalidState: Mutex has not been initialized (in Mutex.cpp, function unlock(), line 88)
Jan 29 07:10:35 dcd-398f9dee nvargus-daemon[14242]: (NvCameraUtils) Error InvalidState: Mutex not initialized (/dvs/git/dirty/git-master_linux/camera/core_scf/src/services/gl/EGLStreamProducer.cpp:534) (in Mutex.cpp, function lock(), line 79)
Jan 29 07:10:35 dcd-398f9dee nvargus-daemon[14242]: SCF: Error BadParameter:  (propagating from src/services/gl/EGLStreamProducer.cpp, function presentBufferInternal(), line 539)
Jan 29 07:10:35 dcd-398f9dee nvargus-daemon[14242]: (NvCameraUtils) Error InvalidState: Mutex has not been initialized (in Mutex.cpp, function unlock(), line 88)
Jan 29 07:10:35 dcd-398f9dee nvargus-daemon[14242]: (NvCameraUtils) Error InvalidState: Mutex not initialized (/dvs/git/dirty/git-master_linux/camera/core_scf/src/services/gl/EGLStreamProducer.cpp:552) (in Mutex.cpp, function lock(), line 79)
Jan 29 07:10:35 dcd-398f9dee nvargus-daemon[14242]: (NvCameraUtils) Error InvalidState: Mutex has not been initialized (in Mutex.cpp, function unlock(), line 88)
Jan 29 07:10:36 dcd-398f9dee nvargus-daemon[14242]: (NvCameraUtils) Error InvalidState: Mutex not initialized (/dvs/git/dirty/git-master_linux/camera/core_scf/src/services/gl/EGLStreamProducer.cpp:498) (in Mutex.cpp, function lock(), line 79)
Jan 29 07:10:36 dcd-398f9dee nvargus-daemon[14242]: (NvCameraUtils) Error InvalidState: Mutex has not been initialized (in Mutex.cpp, function unlock(), line 88)
Jan 29 07:10:36 dcd-398f9dee nvargus-daemon[14242]: (NvCameraUtils) Error InvalidState: Mutex not initialized (/dvs/git/dirty/git-master_linux/camera/core_scf/src/services/gl/EGLStreamProducer.cpp:534) (in Mutex.cpp, function lock(), line 79)
Jan 29 07:10:36 dcd-398f9dee nvargus-daemon[14242]: SCF: Error BadParameter:  (propagating from src/services/gl/EGLStreamProducer.cpp, function presentBufferInternal(), line 539)
Jan 29 07:10:36 dcd-398f9dee nvargus-daemon[14242]: (NvCameraUtils) Error InvalidState: Mutex has not been initialized (in Mutex.cpp, function unlock(), line 88)
Jan 29 07:10:36 dcd-398f9dee nvargus-daemon[14242]: (NvCameraUtils) Error InvalidState: Mutex not initialized (/dvs/git/dirty/git-master_linux/camera/core_scf/src/services/gl/EGLStreamProducer.cpp:552) (in Mutex.cpp, function lock(), line 79)
Jan 29 07:10:36 dcd-398f9dee nvargus-daemon[14242]: (NvCameraUtils) Error InvalidState: Mutex has not been initialized (in Mutex.cpp, function unlock(), line 88)
Jan 29 07:10:36 dcd-398f9dee nvargus-daemon[14242]: (NvCameraUtils) Error InvalidState: Mutex not initialized (/dvs/git/dirty/git-master_linux/camera/core_scf/src/services/gl/EGLStreamProducer.cpp:498) (in Mutex.cpp, function lock(), line 79)
Jan 29 07:10:36 dcd-398f9dee nvargus-daemon[14242]: (NvCameraUtils) Error InvalidState: Mutex has not been initialized (in Mutex.cpp, function unlock(), line 88)
Jan 29 07:10:36 dcd-398f9dee nvargus-daemon[14242]: (NvCameraUtils) Error InvalidState: Mutex not initialized (/dvs/git/dirty/git-master_linux/camera/core_scf/src/services/gl/EGLStreamProducer.cpp:534) (in Mutex.cpp, function lock(), line 79)
Jan 29 07:10:36 dcd-398f9dee nvargus-daemon[14242]: SCF: Error BadParameter:  (propagating from src/services/gl/EGLStreamProducer.cpp, function presentBufferInternal(), line 539)
Jan 29 07:10:36 dcd-398f9dee nvargus-daemon[14242]: (NvCameraUtils) Error InvalidState: Mutex has not been initialized (in Mutex.cpp, function unlock(), line 88)
Jan 29 07:10:36 dcd-398f9dee nvargus-daemon[14242]: (NvCameraUtils) Error InvalidState: Mutex not initialized (/dvs/git/dirty/git-master_linux/camera/core_scf/src/services/gl/EGLStreamProducer.cpp:552) (in Mutex.cpp, function lock(), line 79)
Jan 29 07:10:36 dcd-398f9dee nvargus-daemon[14242]: (NvCameraUtils) Error InvalidState: Mutex has not been initialized (in Mutex.cpp, function unlock(), line 88)
Jan 29 07:10:40 dcd-398f9dee nvargus-daemon[14242]: waitForIdleLocked remaining request 371
Jan 29 07:10:40 dcd-398f9dee nvargus-daemon[14242]: waitForIdleLocked remaining request 370
Jan 29 07:10:40 dcd-398f9dee nvargus-daemon[14242]: waitForIdleLocked remaining request 368
Jan 29 07:10:40 dcd-398f9dee nvargus-daemon[14242]: waitForIdleLocked remaining request 369
Jan 29 07:10:40 dcd-398f9dee nvargus-daemon[14242]: SCF: Error Timeout: waitForIdle() timed out (in src/api/Session.cpp, function waitForIdleLocked(), line 920)
Jan 29 07:10:40 dcd-398f9dee nvargus-daemon[14242]: (Argus) Error Timeout:  (propagating from src/api/CaptureSessionImpl.cpp, function destroy(), line 166)
Jan 29 07:10:45 dcd-398f9dee nvargus-daemon[14242]: waitForIdleLocked remaining request 371
Jan 29 07:10:45 dcd-398f9dee nvargus-daemon[14242]: waitForIdleLocked remaining request 370
Jan 29 07:10:45 dcd-398f9dee nvargus-daemon[14242]: waitForIdleLocked remaining request 368
Jan 29 07:10:45 dcd-398f9dee nvargus-daemon[14242]: waitForIdleLocked remaining request 369
Jan 29 07:10:45 dcd-398f9dee nvargus-daemon[14242]: SCF: Error Timeout: waitForIdle() timed out (in src/api/Session.cpp, function waitForIdleLocked(), line 920)
Jan 29 07:10:45 dcd-398f9dee nvargus-daemon[14242]: SCF: Error Timeout:  (propagating from src/api/Session.cpp, function abortCaptures(), line 886)
Jan 29 07:10:45 dcd-398f9dee nvargus-daemon[14242]: SCF: Error Timeout:  (propagating from src/api/Session.cpp, function shutdown(), line 400)
Jan 29 07:10:45 dcd-398f9dee nvargus-daemon[14242]: PowerServiceCore:handleRequests: timePassed = 5036
Jan 29 07:10:45 dcd-398f9dee nvargus-daemon[14242]: SCF: Error Timeout:  (propagating from src/api/Session.cpp, function shutdown(), line 500)
Jan 29 07:10:45 dcd-398f9dee nvargus-daemon[14242]: SCF: Error Timeout:  (propagating from src/api/CameraDriver.cpp, function deleteSession(), line 619)
Jan 29 07:10:45 dcd-398f9dee nvargus-daemon[14242]: (Argus) Error Timeout:  (propagating from src/api/CaptureSessionImpl.cpp, function destroy(), line 191)
Jan 29 07:10:45 dcd-398f9dee nvargus-daemon[14242]: === gst-launch-1.0[14710]: NOTE: Destroy all libargus objects before destroying the CameraProvider to avoid these warnings.FiberScheduler: 4 fibers still exist!
Jan 29 07:10:45 dcd-398f9dee nvargus-daemon[14242]: === gst-launch-1.0[14710]: Connection cleaned up (7F9A4B11D0)free(): invalid size
Jan 29 07:10:46 dcd-398f9dee systemd[1]: nvargus-daemon.service: Main process exited, code=killed, status=6/ABRT
Jan 29 07:10:46 dcd-398f9dee systemd[1]: nvargus-daemon.service: Failed with result 'signal'.
Jan 29 07:10:46 dcd-398f9dee systemd[1]: nvargus-daemon.service: Service hold-off time over, scheduling restart.
Jan 29 07:10:46 dcd-398f9dee systemd[1]: nvargus-daemon.service: Scheduled restart job, restart counter is at 1.
Jan 29 07:10:46 dcd-398f9dee systemd[1]: Stopped Argus daemon.
Jan 29 07:10:46 dcd-398f9dee systemd[1]: Started Argus daemon

pettair · July 26, 2021, 12:50pm

Im guessing that this is independent from the actual command since it is working fine when I start it from terminal, it is rather connected to somehow that this is started as a service. But I cannot get any grip on it. I mean it should work just as if it is started as a simple terminal command but it acts different or it uses some different configuration.

DaneLLL · July 28, 2021, 3:06am

Hi,
Are you able to try

$ killall -2 gst-launch-1.0

pettair · July 28, 2021, 6:53pm

Hi DaneLLL,

Sorry for the late response!

So the command what you gave is working, but it will stop all gstreamer processing pipelines.

If I send the SIGINT to only one of the processes(basically thats the same thing I did originally):

kill -2 <pid>

I get back to the same error and the Jetson Nano crashes and restarts.

I did some more testing to so how things are interacting when I have two simultaneous streams(in my original test I only had one):

I started one pipeline as service
the other one from a terminal session

and then to stop the second pipeline:

hit CTRL-C directly
use the kill command from and other session

and restart the second pipeline. It was always worked out of more than ten tries. Also I got a continuous feed from the pipeline started as a service, no interruption happened on that stream.

so Im wondering what could be the conclusion of this, I mean if I use the killall command to kill all of the gstreamer pipelines at once with your command the error does not happen. I do not see what could be different if I have only one processing pipeline and send it a kill -SIGINT or do a killall -2 for all of the pipelines. But this may be the answer to the issue when I have multiple simultaneous pipelines.

DaneLLL · July 29, 2021, 2:01am

Hi,
So it looks like if you execute kill -SIGINT, it does not send EoS to exit gst-launch-1.0 command gracefully. Maybe you can try to implement like:
GStreamer freeze when using qtmux and NVIDIA-accelerated h264/h265 encoding - #7 by DaneLLL

In the sample there is g_usleep(30usec)*. May replace it with infinite wait and wait for SIGINT signal. Once the signal is issued, send EoS, wait for EoS, switch to NULL state, and unref the pipeline.

pettair · August 2, 2021, 5:10pm

Hi,

Sorry for the late response!

So is there no way to get to the same result by sending the required signals to the native gst-launch-1.0 command? I mean to implement a C++ application just for that is a bit overkill.

Thanks!

DaneLLL · August 3, 2021, 2:32am

Hi,
Or you may try to restart nvargus-daemon along with gst-launch-1.0 command like:

$ sudo service nvargus-daemon stop
$ sudo service nvargus-daemon start

pettair · August 15, 2021, 7:48pm

Hi,

Sorry for the late response, so to restart the nvargus daemon after each stop would prevent the device to restart (we did that before), but it is not feasible to us since we need to maintain the other video feeds while we restart one of them (we are aiming to implement a highly available system but unfortunately the nvargus-daemon seems to be a single point of failure).

In the meantime we found a workaround. What we do now is starting the pipeline in a screen session:

screen -d -m -S <UNIQ_SESSION_ID> gst-launch-1.0 -e\
....

and when we want to stop it we send the session a CTRL-C keycombo:

screen -S <UNIQ_SESSION_ID> -p 0 -X stuff "^C"

Its a very barefoot “solution”, and im not sure why it is working and signal sending way is not (it is maybe connected to when we start the pipeline as a service there is no TTY attached and GStreamer not handling the signals in a proper way but its just all theory from my side)