[QUESTION] Fail to stop KVS

[liugongqx]

I integrated KVS with gi/GST framework and it works fine. However, even I sent out EOS, it can not terminate KVS properly.

** Logging **

2022-10-13T21:18:51.654Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. 2022-10-13 14:18:51 [140641650566720] DEBUG - postReadCallback()INFO:Camera:End of stream received. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-13T21:18:51.676Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. INFO:Camera:Stop capturing from camera.. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-13T21:18:51.678Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. INFO:Camera:Saved timestamp file.. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-13T21:19:22.148Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. : Wrote 14122 bytes to Kinesis Video. Upload stream handle: 0. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-13T21:19:22.148Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. 2022-10-13 14:18:51 [140641650566720] INFO - stopKinesisVideoStreamSync(): Synchronously stopping Kinesis Video Stream 0000558d2f4b93b0.. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-13T21:19:22.148Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. 2022-10-13 14:18:51 [140643222574656] INFO - getStreamData(): Handle 0 waiting for last persisted ack with ts 16656959319170000. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-13T21:19:22.148Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. 2022-10-13 14:18:51 [140641650566720] DEBUG - postReadCallback(): Wrote 9857 bytes to Kinesis Video. Upload stream handle: 0. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-13T21:19:22.149Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. 2022-10-13 14:18:51 [140641650566720] DEBUG - postReadCallback(): Pausing CURL read for upload handle: 0 waiting for last ack.. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-13T21:19:22.149Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. 2022-10-13 14:18:51 [140641650566720] DEBUG - postWriteCallback(): Curl post body write function for stream with handle: c9cac44b-a1ed-4216-a938-683cedf37378 and upload handle: 0 returned: {"EventType":"RECEIVED","FragmentTimecode":1665695931917,"FragmentNumber":"91343852333181452392841337343644777997702132350"}. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-13T21:19:22.149Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-13T21:19:22.149Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. 2022-10-13 14:18:51 [140641650566720] DEBUG - fragmentAckReceivedHandler invoked. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-13T21:19:22.149Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. 2022-10-13 14:18:51 [140641650566720] DEBUG - postWriteCallback(): Curl post body write function for stream with handle: c9cac44b-a1ed-4216-a938-683cedf37378 and upload handle: 0 returned: {"EventType":"PERSISTED","FragmentTimecode":1665695930584,"FragmentNumber":"91343852333181452387889577186503256687374790467"}. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-13T21:19:22.149Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-13T21:19:22.149Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. 2022-10-13 14:18:51 [140641650566720] DEBUG - fragmentAckReceivedHandler invoked. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-13T21:19:22.149Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. 2022-10-13 14:18:51 [140641650566720] DEBUG - postReadCallback(): Pausing CURL read for upload handle: 0 waiting for last ack.. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-13T21:19:22.149Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. 2022-10-13 14:18:51 [140641650566720] DEBUG - postWriteCallback(): Curl post body write function for stream with handle: c9cac44b-a1ed-4216-a938-683cedf37378 and upload handle: 0 returned: {"EventType":"PERSISTED","FragmentTimecode":1665695931917,"FragmentNumber":"91343852333181452392841337343644777997702132350"}. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-13T21:19:22.149Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-13T21:19:22.149Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. 2022-10-13 14:18:51 [140641650566720] DEBUG - fragmentAckReceivedHandler invoked. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-13T21:19:22.149Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. 2022-10-13 14:18:51 [140641650566720] INFO - getStreamData(): Indicating an EOS after last persisted ACK is received for stream upload handle 0. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-13T21:19:22.149Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. 2022-10-13 14:18:51 [140641650566720] DEBUG - streamClosedHandler invoked for upload handle: 0. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-13T21:19:22.149Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. 2022-10-13 14:18:51 [140641650566720] DEBUG - Reported streamClosed callback for stream handle 94064872231856. Upload handle 0. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-13T21:19:22.149Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. 2022-10-13 14:18:51 [140641650566720] INFO - postReadCallback(): Reported end-of-stream for stream c9cac44b-a1ed-4216-a938-683cedf37378. Upload handle: 0. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-13T21:19:22.149Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. 2022-10-13 14:18:51 [140641650566720] DEBUG - postReadCallback(): Wrote 0 bytes to Kinesis Video. Upload stream handle: 0. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-13T21:19:22.149Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. 2022-10-13 14:18:51 [140641650566720] INFO - Sending eos. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-13T21:19:22.149Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. 2022-10-13 14:18:51 [140643222574656] DEBUG - putStreamCurlHandler(): Network thread for Kinesis Video stream: c9cac44b-a1ed-4216-a938-683cedf37378 with upload handle: 0 exited. http status: 200. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-13T21:19:22.149Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. 2022-10-13 14:18:54 [140641650566720] WARN - putKinesisVideoFrame(): Failed to submit frame to Kinesis Video client. status: 0x52000052 decoding timestamp: 0 presentation timestamp: 0. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-13T21:19:22.149Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. 2022-10-13 14:19:12 [140643247941184] WARN - checkIntermittentProducerCallback(): Failed to submit auto eofr with 0x52000052, for stream name: c9cac44b-a1ed-4216-a938-683cedf37378. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-13T21:19:22.149Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. 2022-10-13 14:19:12 [140643247941184] ERROR - checkIntermittentProducerCallback(): operation returned status code: 0x52000052. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-13T21:19:22.149Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. 2022-10-13 14:19:12 [140643247941184] ERROR - timerQueueExecutor(): operation returned status code: 0x52000052. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}

** Any design considerations/constraints **
We use Gst.parse_launch(command) to trigger command line. I didn't add any pad for prob when adding kvssink
How we add kvssink:

            new_command = 'v4l2src device=/dev/video2 name=video_src ! video/x-raw,width=1920,height=1080,framerate=30/1 ! jpegenc  ! tee name=video_out ! queue ! avimux ! filesink location=/home/secparedge/Videos/capture.avi video_out. ! queue ! multifilesink location=/home/secparedge/Videos/snapshot.jpeg max-files=1 alsasrc device="hw:2,0" name=audio_src ! level ! audioconvert ! audio/x-raw,rate=44100,channels=1 ! tee name=audio_out ! queue ! wavenc ! filesink location=/home/secparedge/Videos/capture.wav video_out. ! queue ! merge. audio_out. ! queue ! merge. avimux name=merge ! filesink location=/home/secparedge/Videos/merged_capture.avi video_out. ! queue ! jpegdec ! videoscale ! videorate ! video/x-raw,framerate=30/1,width=1080,height=720 ! x264enc bframes=0 key-int-max=45 bitrate=4096 ! video/x-h264,stream-format=avc,alignment=au,profile=baseline ! kvssink stream-name="test" storage-size=512 access-key="somekey" secret-key="somekey"'

            self.pipeline = Gst.parse_launch(command)  # pylint: disable=assignment-from-no-return

How we clean up:

        if self.pipeline:
            # Force a End-of-stream signal to end the streaming
            self.pipeline.send_event(Gst.Event.new_eos())

            # Wait for EOS signal. If EOS signal doesn't come within the timeout, still exit.
            self.eos.wait(TERMINATE_TIME_LIMIT_IN_SECOND)

            # Terminate all the resources regardless whether EOS is received or not.
            self.pipeline.set_state(Gst.State.NULL)
            if self.main_loop:
                self.main_loop.quit()
            self.logger.info('Stop capturing from camera.')

            # Cleanup by removing all the callbacks
            for src_pad, handler_id in self.src_pad_info.items():
                src_pad.remove_probe(handler_id)
            if self.bus:
                for handler_id in self.bus_signal_handler_ids:
                    self.bus.disconnect(handler_id)
                self.bus.remove_signal_watch()

** If you would not like to open an issue to discuss your solution in open-platform, please email your question to kinesis-video-support@amazon.com **

[liugongqx]

Attached debug trace after enabling trace level debugging.

2022-10-17T05:40:56.123Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. INFO:Camera:Stop capturing from camera.. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-17T05:40:56.125Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. INFO:Camera:Saved timestamp file.. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-17T05:41:31.596Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. 10-2022 05:40:56:098.859 GMT] streamDataAvailableHandler invoked for stream: c9cac44b-a1ed-4216-a938-683cedf37378 and stream upload handle: 0. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-17T05:41:31.596Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. [TRACE] [17-10-2022 05:40:56:098.898 GMT] notifyDataAvailable(): Note data received: duration(100ns): 0 bytes 0 for stream handle 0. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-17T05:41:31.596Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. [DEBUG] [17-10-2022 05:40:56:098.905 GMT] fragmentAckReceivedHandler invoked. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-17T05:41:31.596Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. [TRACE] [17-10-2022 05:40:56:098.912 GMT] postWriteCallback(): Processed ACK OK.. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-17T05:41:31.596Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. [TRACE] [17-10-2022 05:40:56:098.927 GMT] postReadCallback(): postBodyStreamingReadFunc (curl callback) invoked. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-17T05:41:31.596Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. [INFO ] [17-10-2022 05:40:56:098.935 GMT] getStreamData(): Indicating an EOS after last persisted ACK is received for stream upload handle 0. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-17T05:41:31.596Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. [DEBUG] [17-10-2022 05:40:56:098.941 GMT] streamClosedHandler invoked for upload handle: 0. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-17T05:41:31.596Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. [DEBUG] [17-10-2022 05:40:56:098.948 GMT] Reported streamClosed callback for stream handle 94750600028464. Upload handle 0. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-17T05:41:31.596Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. [TRACE] [17-10-2022 05:40:56:098.963 GMT] postReadCallback(): Get Stream data returned: buffer size: 65524 written bytes: 0 for upload handle: 0 current stream handle: 94750600028464. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-17T05:41:31.596Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. [INFO ] [17-10-2022 05:40:56:098.969 GMT] postReadCallback(): Reported end-of-stream for stream c9cac44b-a1ed-4216-a938-683cedf37378. Upload handle: 0. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-17T05:41:31.596Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. [DEBUG] [17-10-2022 05:40:56:098.975 GMT] postReadCallback(): Wrote 0 bytes to Kinesis Video. Upload stream handle: 0. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-17T05:41:31.596Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. [TRACE] [17-10-2022 05:40:56:099.002 GMT] stopStreamSync(): Kinesis Video Stream is Closed.. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-17T05:41:31.596Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. [INFO ] [17-10-2022 05:40:56:099.021 GMT] Sending eos. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-17T05:41:31.596Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. [DEBUG] [17-10-2022 05:40:59:112.632 GMT] putStreamCurlHandler(): Network thread for Kinesis Video stream: c9cac44b-a1ed-4216-a938-683cedf37378 with upload handle: 0 exited. http status: 200. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-17T05:41:31.596Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. [TRACE] [17-10-2022 05:41:16:595.517 GMT] putKinesisVideoFrame(): debug frame info pts: 0, dts: 0, duration: 0, size: 0, trackId: 0, isKey 0. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-17T05:41:31.596Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. [WARN ] [17-10-2022 05:41:16:595.670 GMT] putKinesisVideoFrame(): Failed to submit frame to Kinesis Video client. status: 0x52000052 decoding timestamp: 0 presentation timestamp: 0. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}
2022-10-17T05:41:31.596Z [INFO] (Copier) com.amazon.CaptureComponent: stdout. [WARN ] [17-10-2022 05:41:16:595.692 GMT] checkIntermittentProducerCallback(): Failed to submit auto eofr with 0x52000052, for stream name: c9cac44b-a1ed-4216-a938-683cedf37378. {scriptName=services.com.amazon.CaptureComponent.lifecycle.Run.Script, serviceName=com.amazon.CaptureComponent, currentState=RUNNING}

[niyatim23]

Hi @liugongqx, 0x52000052 is STATUS_STREAM_HAS_BEEN_STOPPED. I see stopStreamSync(): Kinesis Video Stream is Closed.. Could it be the case you are trying to send an EOS after the stream is closed. Do you want intend to close the stream or the gstreamer pipeline?

[niyatim23]

Closing due to no response. Feel free to open a new issue in case of further issues / questions

[pwolfe1]

Do you want intend to close the stream or the gstreamer pipeline?

Hey @niyatim23, sorry to bump this but I have a quick question about this comment. Is there a good way to close / terminate a stream from the producer side without terminating the GStreamer pipeline? Specifically, I am asking about a case where you want to start and stop the stream in an intermittent fashion.

Thanks!

[niyatim23]

@pwolfe1, you mean to say the pipeline will be open but you will start and stop the stream associated with the pipeline intermittently?

[pwolfe1]

@pwolfe1, you mean to say the pipeline will be open but you will start and stop the stream associated with the pipeline intermittently?

Yeah exactly. What I am currently doing is deleting and reconstructing the pipeline as needed. This is totally sufficient for our use case but I am curious if there is a better way to go about this.

[pwolfe1]

Bumping this as I am still looking for a good way to implement intermittent streaming via kvssink

[gem-aniketyadav]

Hi @pwolfe1 , can you share the command that you used to resolve the issue. Like all the frames should be send before the gstreamer command ends. So that 0x52000052 error code is resolved